_unused.MustUse: add optional stack trace capturing
The unused MustUse warnings are only emitted with some delay after the relevant scope with the issue has been left. A single stack frame may not be enough to correctly identify the source of the issue if for example an Elaboratable, in common code shared between a few tests, goes unused based on factors external to the scope it is created and would be used in.
Python tracemalloc with a depth of at least 3 (in _unused, object creator, caller) prints a trace, but without function names and with a not insignificant slowing of execution, listing also locations that are not helpful to finding the problem.
_Whether that makes it worth adding more code for amaranth to do its own tracing I'll leave for you to decide. I admittedly fumbled a bit and managed to believe for a bit that even with `PYTHONTRACEMALLOC` set to something greater than 1 I got only one frame printed... not quite sure how, in collecting sample output for this PR I found tracemalloc to produce an okay-ish trace importantly up into the test function that actually caused the issue._
Optionally capture a stack trace of MustUsed object creation, printing that alongside the warning to aid in correctly identifying the context the warning was emitted for.
Setting AMARANTH_TRACE_UNUSED to a truthy value will print a stack trace filtered for some python/unittest internal locations that are unlikely to help. Setting AMARANTH_TRACE_UNUSED=full will print an unfiltered stack trace.
WIP: how this stack trace fits together with the rest of the python warn_explicit syntax still feels unpolished.
See https://github.com/GlasgowEmbedded/glasgow/pull/1098 for the context in which I stumbled upon the problem of a warning not being obviously associated with the test that caused it.
Sample outputs from the glasgow PR above (prior to the commit disabling the warning for that glasgow internal file):
<details>
<summary>Before, no tracemalloc (click to expand)</summary>
```console
$ pdm test -v glasgow.simulation.test.SimulationAssemblyTestCase
test_jumper (glasgow.simulation.test.SimulationAssemblyTestCase.test_jumper) ... /nix/store/22za3gaj3sx55pll86mz71wsshx0nl4x-python3.13-amaranth-0.6+unstable-nicer-anon-subfragment-names/lib/python3.13/site-packages/amaranth/sim/core.py:123: DeprecationWarning: Per RFC 66, the `period` argument of `add_clock()` will only accept a `Period` in the future.
warnings.warn(
/nix/store/22za3gaj3sx55pll86mz71wsshx0nl4x-python3.13-amaranth-0.6+unstable-nicer-anon-subfragment-names/lib/python3.13/site-packages/amaranth/sim/_async.py:79: DeprecationWarning: Per RFC 66, the `interval` argument of `DelayTrigger()` will only accept a `Period` in the future.
warnings.warn(
ok
test_jumper_conflicting_pulls (glasgow.simulation.test.SimulationAssemblyTestCase.test_jumper_conflicting_pulls) ... ok
test_jumper_contention (glasgow.simulation.test.SimulationAssemblyTestCase.test_jumper_contention) ... ok
test_jumper_non_conflicting_pulls (glasgow.simulation.test.SimulationAssemblyTestCase.test_jumper_non_conflicting_pulls) ... /[...]/glasgow/software/glasgow/simulation/assembly.py:323: UnusedElaboratable: <amaranth.hdl._dsl.Module object at 0x7efc4d481ba0> created but never used
m = Module()
UnusedElaboratable: Enable tracemalloc to get the object allocation traceback
ok
test_jumper_pin_invert (glasgow.simulation.test.SimulationAssemblyTestCase.test_jumper_pin_invert) ... ok
test_jumper_pull_up (glasgow.simulation.test.SimulationAssemblyTestCase.test_jumper_pull_up) ... ok
test_jumper_transitivity (glasgow.simulation.test.SimulationAssemblyTestCase.test_jumper_transitivity) ... ok
----------------------------------------------------------------------
Ran 7 tests in 0.045s
OK
```
</details>
<details>
<summary>Before, 3-deep tracemalloc (click to expand)</summary>
```console
$ PYTHONTRACEMALLOC=3 pdm test -v glasgow.simulation.test.SimulationAssemblyTestCase
test_jumper (glasgow.simulation.test.SimulationAssemblyTestCase.test_jumper) ... /nix/store/22za3gaj3sx55pll86mz71wsshx0nl4x-python3.13-amaranth-0.6+unstable-nicer-anon-subfragment-names/lib/python3.13/site-packages/amaranth/sim/core.py:123: DeprecationWarning: Per RFC 66, the `period` argument of `add_clock()` will only accept a `Period` in the future.
warnings.warn(
/nix/store/22za3gaj3sx55pll86mz71wsshx0nl4x-python3.13-amaranth-0.6+unstable-nicer-anon-subfragment-names/lib/python3.13/site-packages/amaranth/sim/_async.py:79: DeprecationWarning: Per RFC 66, the `interval` argument of `DelayTrigger()` will only accept a `Period` in the future.
warnings.warn(
ok
test_jumper_conflicting_pulls (glasgow.simulation.test.SimulationAssemblyTestCase.test_jumper_conflicting_pulls) ... ok
test_jumper_contention (glasgow.simulation.test.SimulationAssemblyTestCase.test_jumper_contention) ... ok
test_jumper_non_conflicting_pulls (glasgow.simulation.test.SimulationAssemblyTestCase.test_jumper_non_conflicting_pulls) ... /[...]/glasgow/software/glasgow/simulation/assembly.py:323: UnusedElaboratable: <amaranth.hdl._dsl.Module object at 0x7fadca06ed70> created but never used
m = Module()
Object allocated at (most recent call last):
File "/[...]/glasgow/software/glasgow/simulation/test.py", lineno 207
assembly.run(tb)
File "/[...]/glasgow/software/glasgow/simulation/assembly.py", lineno 323
m = Module()
File "/nix/store/22za3gaj3sx55pll86mz71wsshx0nl4x-python3.13-amaranth-0.6+unstable-nicer-anon-subfragment-names/lib/python3.13/site-packages/amaranth/_unused.py", lineno 20
self = super().__new__(cls)
ok
test_jumper_pin_invert (glasgow.simulation.test.SimulationAssemblyTestCase.test_jumper_pin_invert) ... ok
test_jumper_pull_up (glasgow.simulation.test.SimulationAssemblyTestCase.test_jumper_pull_up) ... ok
test_jumper_transitivity (glasgow.simulation.test.SimulationAssemblyTestCase.test_jumper_transitivity) ... ok
----------------------------------------------------------------------
Ran 7 tests in 0.492s
OK
```
</details>
<details>
<summary>After, no trace (click to expand)</summary>
```console
$ pdm test -v glasgow.simulation.test.SimulationAssemblyTestCase
test_jumper (glasgow.simulation.test.SimulationAssemblyTestCase.test_jumper) ... /nix/store/7fa7pwmhvrvnlf0k1b864wbby88vg5h8-python3.13-amaranth-0.6+unstable-nicer-anon-subfragment-names/lib/python3.13/site-packages/amaranth/sim/core.py:123: DeprecationWarning: Per RFC 66, the `period` argument of `add_clock()` will only accept a `Period` in the future.
warnings.warn(
/nix/store/7fa7pwmhvrvnlf0k1b864wbby88vg5h8-python3.13-amaranth-0.6+unstable-nicer-anon-subfragment-names/lib/python3.13/site-packages/amaranth/sim/_async.py:79: DeprecationWarning: Per RFC 66, the `interval` argument of `DelayTrigger()` will only accept a `Period` in the future.
warnings.warn(
ok
test_jumper_conflicting_pulls (glasgow.simulation.test.SimulationAssemblyTestCase.test_jumper_conflicting_pulls) ... ok
test_jumper_contention (glasgow.simulation.test.SimulationAssemblyTestCase.test_jumper_contention) ... ok
test_jumper_non_conflicting_pulls (glasgow.simulation.test.SimulationAssemblyTestCase.test_jumper_non_conflicting_pulls) ... /[...]/glasgow/software/glasgow/simulation/assembly.py:323: UnusedElaboratable: <amaranth.hdl._dsl.Module object at 0x7f5d4dda2d70> created but never used
Trace of Module (MustUse) creation not available, set AMARANTH_TRACE_UNUSED=1 (or =full for unfiltered) and rerun
m = Module()
UnusedElaboratable: Enable tracemalloc to get the object allocation traceback
ok
test_jumper_pin_invert (glasgow.simulation.test.SimulationAssemblyTestCase.test_jumper_pin_invert) ... ok
test_jumper_pull_up (glasgow.simulation.test.SimulationAssemblyTestCase.test_jumper_pull_up) ... ok
test_jumper_transitivity (glasgow.simulation.test.SimulationAssemblyTestCase.test_jumper_transitivity) ... ok
----------------------------------------------------------------------
Ran 7 tests in 0.048s
OK
```
</details>
<details>
<summary>After, filtered trace (click to expand)</summary>
```console
$ AMARANTH_TRACE_UNUSED=1 pdm test -v glasgow.simulation.test.SimulationAssemblyTestCase
test_jumper (glasgow.simulation.test.SimulationAssemblyTestCase.test_jumper) ... /nix/store/7fa7pwmhvrvnlf0k1b864wbby88vg5h8-python3.13-amaranth-0.6+unstable-nicer-anon-subfragment-names/lib/python3.13/site-packages/amaranth/sim/core.py:123: DeprecationWarning: Per RFC 66, the `period` argument of `add_clock()` will only accept a `Period` in the future.
warnings.warn(
/nix/store/7fa7pwmhvrvnlf0k1b864wbby88vg5h8-python3.13-amaranth-0.6+unstable-nicer-anon-subfragment-names/lib/python3.13/site-packages/amaranth/sim/_async.py:79: DeprecationWarning: Per RFC 66, the `interval` argument of `DelayTrigger()` will only accept a `Period` in the future.
warnings.warn(
ok
test_jumper_conflicting_pulls (glasgow.simulation.test.SimulationAssemblyTestCase.test_jumper_conflicting_pulls) ... ok
test_jumper_contention (glasgow.simulation.test.SimulationAssemblyTestCase.test_jumper_contention) ... ok
test_jumper_non_conflicting_pulls (glasgow.simulation.test.SimulationAssemblyTestCase.test_jumper_non_conflicting_pulls) ... /[...]/glasgow/software/glasgow/simulation/assembly.py:323: UnusedElaboratable: <amaranth.hdl._dsl.Module object at 0x7fa9457f36f0> created but never used
Filtered trace of Module (MustUse) creation (set AMARANTH_TRACE_UNUSED=full for unfiltered):
File "/[...]/glasgow/software/glasgow/simulation/test.py", line 207, in test_jumper_conflicting_pulls
assembly.run(tb)
File "/[...]/glasgow/software/glasgow/simulation/assembly.py", line 323, in run
m = Module()
m = Module()
UnusedElaboratable: Enable tracemalloc to get the object allocation traceback
ok
test_jumper_pin_invert (glasgow.simulation.test.SimulationAssemblyTestCase.test_jumper_pin_invert) ... ok
test_jumper_pull_up (glasgow.simulation.test.SimulationAssemblyTestCase.test_jumper_pull_up) ... ok
test_jumper_transitivity (glasgow.simulation.test.SimulationAssemblyTestCase.test_jumper_transitivity) ... ok
----------------------------------------------------------------------
Ran 7 tests in 0.053s
OK
```
</details>
<details>
<summary>After, full trace (click to expand)</summary>
```console
$ AMARANTH_TRACE_UNUSED=full pdm test -v glasgow.simulation.test.SimulationAssemblyTestCase
test_jumper (glasgow.simulation.test.SimulationAssemblyTestCase.test_jumper) ... /nix/store/7fa7pwmhvrvnlf0k1b864wbby88vg5h8-python3.13-amaranth-0.6+unstable-nicer-anon-subfragment-names/lib/python3.13/site-packages/amaranth/sim/core.py:123: DeprecationWarning: Per RFC 66, the `period` argument of `add_clock()` will only accept a `Period` in the future.
warnings.warn(
/nix/store/7fa7pwmhvrvnlf0k1b864wbby88vg5h8-python3.13-amaranth-0.6+unstable-nicer-anon-subfragment-names/lib/python3.13/site-packages/amaranth/sim/_async.py:79: DeprecationWarning: Per RFC 66, the `interval` argument of `DelayTrigger()` will only accept a `Period` in the future.
warnings.warn(
ok
test_jumper_conflicting_pulls (glasgow.simulation.test.SimulationAssemblyTestCase.test_jumper_conflicting_pulls) ... ok
test_jumper_contention (glasgow.simulation.test.SimulationAssemblyTestCase.test_jumper_contention) ... ok
test_jumper_non_conflicting_pulls (glasgow.simulation.test.SimulationAssemblyTestCase.test_jumper_non_conflicting_pulls) ... /[...]/glasgow/software/glasgow/simulation/assembly.py:323: UnusedElaboratable: <amaranth.hdl._dsl.Module object at 0x7fb43011b5c0> created but never used
Full trace of Module (MustUse) creation:
File "<frozen runpy>", line 198, in _run_module_as_main
File "<frozen runpy>", line 88, in _run_code
File "/nix/store/3lll9y925zz9393sa59h653xik66srjb-python3-3.13.9/lib/python3.13/unittest/__main__.py", line 18, in <module>
main(module=None)
File "/nix/store/3lll9y925zz9393sa59h653xik66srjb-python3-3.13.9/lib/python3.13/unittest/main.py", line 104, in __init__
self.runTests()
File "/nix/store/3lll9y925zz9393sa59h653xik66srjb-python3-3.13.9/lib/python3.13/unittest/main.py", line 270, in runTests
self.result = testRunner.run(self.test)
File "/nix/store/3lll9y925zz9393sa59h653xik66srjb-python3-3.13.9/lib/python3.13/unittest/runner.py", line 240, in run
test(result)
File "/nix/store/3lll9y925zz9393sa59h653xik66srjb-python3-3.13.9/lib/python3.13/unittest/suite.py", line 84, in __call__
return self.run(*args, **kwds)
File "/nix/store/3lll9y925zz9393sa59h653xik66srjb-python3-3.13.9/lib/python3.13/unittest/suite.py", line 122, in run
test(result)
File "/nix/store/3lll9y925zz9393sa59h653xik66srjb-python3-3.13.9/lib/python3.13/unittest/suite.py", line 84, in __call__
return self.run(*args, **kwds)
File "/nix/store/3lll9y925zz9393sa59h653xik66srjb-python3-3.13.9/lib/python3.13/unittest/suite.py", line 122, in run
test(result)
File "/nix/store/3lll9y925zz9393sa59h653xik66srjb-python3-3.13.9/lib/python3.13/unittest/case.py", line 707, in __call__
return self.run(*args, **kwds)
File "/nix/store/3lll9y925zz9393sa59h653xik66srjb-python3-3.13.9/lib/python3.13/unittest/case.py", line 651, in run
self._callTestMethod(testMethod)
File "/nix/store/3lll9y925zz9393sa59h653xik66srjb-python3-3.13.9/lib/python3.13/unittest/case.py", line 606, in _callTestMethod
if method() is not None:
File "/[...]/glasgow/software/glasgow/simulation/test.py", line 207, in test_jumper_conflicting_pulls
assembly.run(tb)
File "/[...]/glasgow/software/glasgow/simulation/assembly.py", line 323, in run
m = Module()
m = Module()
UnusedElaboratable: Enable tracemalloc to get the object allocation traceback
ok
test_jumper_pin_invert (glasgow.simulation.test.SimulationAssemblyTestCase.test_jumper_pin_invert) ... ok
test_jumper_pull_up (glasgow.simulation.test.SimulationAssemblyTestCase.test_jumper_pull_up) ... ok
test_jumper_transitivity (glasgow.simulation.test.SimulationAssemblyTestCase.test_jumper_transitivity) ... ok
----------------------------------------------------------------------
Ran 7 tests in 0.053s
OK
```
</details>
合并状态:未合并 1 条评论