BUG (?): line data not reported when exception raised #355
Description
Motivation
I was checking for incompatibilities in pytest-autoprofile after the recent round of PR merges, and my doctest stuff keeps failing on Python 3.13 – which immediately signaled to me that something went south in a sys.monitoring-related PR.
And indeed, it was PR #352 which changed the behavior when an exception is raised:
Examples
Note that no timing data are reported for the raise my_error(10) line on main:
|
|
|
|---|---|
(py3.13) $ kernprof -lv -c "
def my_error(n: int) -> ValueError:
x = 0
for n in range(1, n + 1):
x += n
return ValueError(str(x))
def main() -> None:
print('foo')
raise my_error(10)
print('bar')
main()
"
foo
Wrote profile results to '/Users/terence/Scripts/python-projects/pytest-autoprofile/kernprof-command-r4nw9ash.lprof'
Timer unit: 1e-06 s
Total time: 5e-06 s
File: /var/folders/5b/44kj9cdn7gngz2k1z1wxt0240000gp/T/tmpoco1kb2f/kernprof-command.py
Function: my_error at line 2
Line # Hits Time Per Hit % Time Line Contents
==============================================================
2 def my_error(n: int) -> ValueError:
3 1 0.0 0.0 0.0 x = 0
4 11 3.0 0.3 60.0 for n in range(1, n + 1):
5 10 1.0 0.1 20.0 x += n
6 1 1.0 1.0 20.0 return ValueError(str(x))
Total time: 2.4e-05 s
File: /var/folders/5b/44kj9cdn7gngz2k1z1wxt0240000gp/T/tmpoco1kb2f/kernprof-command.py
Function: main at line 8
Line # Hits Time Per Hit % Time Line Contents
==============================================================
8 def main() -> None:
9 1 11.0 11.0 45.8 print('foo')
10 1 13.0 13.0 54.2 raise my_error(10)
11 print('bar')
Traceback (most recent call last):
...
File "/var/folders/5b/44kj9cdn7gngz2k1z1wxt0240000gp/T/tmpoco1kb2f/kernprof-command.py", line 10, in main
raise my_error(10)
ValueError: 55 |
(py3.13) $ kernprof -lv -c "
def my_error(n: int) -> ValueError:
x = 0
for n in range(1, n + 1):
x += n
return ValueError(str(x))
def main() -> None:
print('foo')
raise my_error(10)
print('bar')
main()
"
foo
Wrote profile results to '/Users/terence/Scripts/python-projects/pytest-autoprofile/kernprof-command-d3rdiqlt.lprof'
Timer unit: 1e-06 s
Total time: 4e-06 s
File: /var/folders/5b/44kj9cdn7gngz2k1z1wxt0240000gp/T/tmpekt1l7q8/kernprof-command.py
Function: my_error at line 2
Line # Hits Time Per Hit % Time Line Contents
==============================================================
2 def my_error(n: int) -> ValueError:
3 1 0.0 0.0 0.0 x = 0
4 11 4.0 0.4 100.0 for n in range(1, n + 1):
5 10 0.0 0.0 0.0 x += n
6 1 0.0 0.0 0.0 return ValueError(str(x))
Total time: 9e-06 s
File: /var/folders/5b/44kj9cdn7gngz2k1z1wxt0240000gp/T/tmpekt1l7q8/kernprof-command.py
Function: main at line 8
Line # Hits Time Per Hit % Time Line Contents
==============================================================
8 def main() -> None:
9 1 9.0 9.0 100.0 print('foo')
10 raise my_error(10)
11 print('bar')
Traceback (most recent call last):
...
File "/var/folders/5b/44kj9cdn7gngz2k1z1wxt0240000gp/T/tmpekt1l7q8/kernprof-command.py", line 10, in main
raise my_error(10)
ValueError: 55 |
Likewise, for the following code
def main():
try:
raise Exception
finally:
print(1)No profiling data are gathered for the print(1) line on main.
Explanation
Since #352 we're handling the following sys.monitoring events in Python 3.12+:
sys.monitoring.events.PY_RETURNand.PY_YIELD: corresponding toPyTrace_RETURNin the "legacy" system.sys.monitoring.events.LINE: corresponding toPyTrace_LINE.
As is evident from the above, the new system is more fine-grained, and thus something might have (and must have, given the changes in behavior) been lost in translation.
Remedy
Adding handling for the sys.monitoring.events.RAISE and .RERAISE events seems to restore the previous behavior, which I suppose should be the preferred one for completeness. Now the question remains if we should just fix this in a separate small PR, or if it can be rolled into #334 since that PR also made substantial changes to the Cython code.