[issue42800] Traceback objects allow accessing frame objects without triggering audit hooks

[Ryan Hileman]

Ryan Hileman <lunixbochs at gmail.com> added the comment:

Oops, by tb_code I meant traceback.tb_frame.f_code. So you can get to a frame from traceback.tb_frame (without triggering audit) or sys._getframe (which has an audit hook already), and you can get to __code__ from a frame via frame.f_code (without triggering audit).

Here's a patch for both frame.f_code and traceback.tb_frame:
https://github.com/lunixbochs/cpython/commit/2334a00c833874b7a2427e88abc9b51315bb010c

---

Benchmarks follow this section, made using the commit I linked (and the parent commit without the patch for comparison). My takeaways from playing around:

1. You probably shouldn't install a Python audit hook if you care about performance.
2. C audit hook performance impact shows up in microbenchmarking but only have a small impact on real workloads (see the traceback.format_tb benchmark at the end).
3. Performance impact of this change when you _don't_ have an audit hook installed is very small.
4. This seems to mostly impact debugging and test code. A quick check of the stdlib shows:
- traceback.tb_frame usage seems to be entirely in debugger, traceback, and testing code: https://github.com/python/cpython/search?l=Python&p=3&q=tb_frame
- frame.f_code primarily has similar debug use (dis, warnings, profiling, inspect): https://github.com/python/cpython/search?l=Python&p=3&q=f_code

Attached (c_audit_ext.zip) is the empty C audit hook I used for the benchmarks. `python3 setup.py build_ext` builds a `c_audit` module which registers an empty audit hook on import.

################################################################################
#### frame.f_code object.__getattr__ audit hook

# Testing frame.f_code impact (no audit hook installed):
./python.exe -m timeit -s 'frame = sys._getframe()' -- 'frame.f_code'

with patch 2334a00c833874b7a2427e88abc9b51315bb010c
20000000 loops, best of 5: 19.1 nsec per loop
20000000 loops, best of 5: 18.7 nsec per loop
20000000 loops, best of 5: 19.1 nsec per loop

without patch 2334a00c833874b7a2427e88abc9b51315bb010c
20000000 loops, best of 5: 17 nsec per loop
20000000 loops, best of 5: 16.7 nsec per loop
20000000 loops, best of 5: 17 nsec per loop

# Testing frame.f_code impact (C audit hook installed):
python.exe -m timeit -s 'import c_audit; frame = sys._getframe()' -- 'frame.f_code'

with patch 2334a00c833874b7a2427e88abc9b51315bb010c
5000000 loops, best of 5: 66.1 nsec per loop
5000000 loops, best of 5: 66.1 nsec per loop
5000000 loops, best of 5: 66.5 nsec per loop

without patch 2334a00c833874b7a2427e88abc9b51315bb010c
20000000 loops, best of 5: 16.9 nsec per loop
20000000 loops, best of 5: 16.9 nsec per loop
20000000 loops, best of 5: 16.8 nsec per loop

# Testing frame.f_code impact (pure Python audit hook installed):
./python.exe -m timeit -s 'frame = sys._getframe(); sys.addaudithook(lambda *a: None)' -- 'frame.f_code'

with patch 2334a00c833874b7a2427e88abc9b51315bb010c
500000 loops, best of 5: 1.02 usec per loop
500000 loops, best of 5: 1.04 usec per loop
500000 loops, best of 5: 1.02 usec per loop

without patch 2334a00c833874b7a2427e88abc9b51315bb010c
20000000 loops, best of 5: 16.8 nsec per loop
20000000 loops, best of 5: 17.1 nsec per loop
20000000 loops, best of 5: 16.8 nsec per loop

################################################################################
#### tb.tb_frame object.__getattr__ audit hook

# Testing tb.tb_frame impact (no audit hook installed)
./python.exe -m timeit -s "$(echo -e "try: a\nexcept Exception as e: tb = e.__traceback__")" -- 'tb.tb_frame'

with patch 2334a00c833874b7a2427e88abc9b51315bb010c
20000000 loops, best of 5: 19.2 nsec per loop
20000000 loops, best of 5: 18.9 nsec per loop
20000000 loops, best of 5: 18.9 nsec per loop

without patch 2334a00c833874b7a2427e88abc9b51315bb010c
20000000 loops, best of 5: 17 nsec per loop
20000000 loops, best of 5: 16.7 nsec per loop
20000000 loops, best of 5: 16.8 nsec per loop

# Testing tb.tb_frame impact (C audit hook installed)
./python.exe -m timeit -s "$(echo -e "import c_audit\ntry: a\nexcept Exception as e: tb = e.__traceback__")" -- 'tb.tb_frame'

with patch 2334a00c833874b7a2427e88abc9b51315bb010c
5000000 loops, best of 5: 64.8 nsec per loop
5000000 loops, best of 5: 64.8 nsec per loop
5000000 loops, best of 5: 64.8 nsec per loop

without patch 2334a00c833874b7a2427e88abc9b51315bb010c
20000000 loops, best of 5: 16.7 nsec per loop
20000000 loops, best of 5: 16.9 nsec per loop
20000000 loops, best of 5: 16.9 nsec per loop

# Testing tb.tb_frame impact (pure Python audit hook installed)
./python.exe -m timeit -s "$(echo -e "sys.addaudithook(lambda *a: None)\ntry: a\nexcept Exception as e: tb = e.__traceback__")" -- 'tb.tb_frame'

with patch 2334a00c833874b7a2427e88abc9b51315bb010c
500000 loops, best of 5: 1.04 usec per loop
500000 loops, best of 5: 1.02 usec per loop
500000 loops, best of 5: 1.04 usec per loop

without patch 2334a00c833874b7a2427e88abc9b51315bb010c
20000000 loops, best of 5: 16.9 nsec per loop
20000000 loops, best of 5: 16.9 nsec per loop
20000000 loops, best of 5: 17.2 nsec per loop

################################################################################
#### tb.tb_frame object.__getattr__ audit hook, traceback.format_tb()

# Testing tb.tb_frame impact on traceback.format_tb (no audit hook installed)
with patch 2334a00c833874b7a2427e88abc9b51315bb010c
100000 loops, best of 5: 3 usec per loop
100000 loops, best of 5: 3.03 usec per loop
100000 loops, best of 5: 3 usec per loop

without patch 2334a00c833874b7a2427e88abc9b51315bb010c
100000 loops, best of 5: 2.99 usec per loop
100000 loops, best of 5: 3.02 usec per loop
100000 loops, best of 5: 2.99 usec per loop

# Testing tb.tb_frame impact on traceback.format_tb (C audit hook installed)
./python.exe -m timeit -s "$(echo -e "import c_audit\nimport traceback\ntry: a\nexcept Exception as e: tb = e.__traceback__")" -- 'traceback.format_tb(tb)'

with patch 2334a00c833874b7a2427e88abc9b51315bb010c
100000 loops, best of 5: 3.13 usec per loop
100000 loops, best of 5: 3.13 usec per loop
100000 loops, best of 5: 3.12 usec per loop

without patch 2334a00c833874b7a2427e88abc9b51315bb010c
100000 loops, best of 5: 3.06 usec per loop
100000 loops, best of 5: 3.06 usec per loop
100000 loops, best of 5: 3.05 usec per loop

# Testing tb.tb_frame impact on traceback.format_tb (pure Python audit hook installed)
./python.exe -m timeit -s "$(echo -e "sys.addaudithook(lambda *a: None)\nimport traceback\ntry: a\nexcept Exception as e: tb = e.__traceback__")" -- 'traceback.format_tb(tb)'

with patch 2334a00c833874b7a2427e88abc9b51315bb010c
50000 loops, best of 5: 5.1 usec per loop
50000 loops, best of 5: 5.18 usec per loop
50000 loops, best of 5: 5.06 usec per loop

without patch 2334a00c833874b7a2427e88abc9b51315bb010c
100000 loops, best of 5: 3 usec per loop
100000 loops, best of 5: 3 usec per loop
100000 loops, best of 5: 3 usec per loop

----------
Added file: https://bugs.python.org/file49729/c_audit_ext.zip

_______________________________________
Python tracker <report at bugs.python.org>
<https://bugs.python.org/issue42800>
_______________________________________