Repository navigation
NOTRACE_DISPATCH breaks tracing #96636
Description
Most of our quickened instructions start by asserting that tracing isn't enabled, and end by calling NOTRACE_DISPATCH(), which skips tracing checks. This is safe for many of our specializations (like those for BINARY_OP and COMPARE_OP, which operate on known safe types), but not all of them. The problem is that any time we decref an unknown object, arbitrary finalizers could run and enable tracing.
It seems that our current practice is predicated on the idea that it's okay for tracing to start "sometime in the future", since we make no guarantees about when finalizers run. There are two issues with this:
- Trace functions may temporarily trace some frames, but not others.
- As mentioned, the interpreter loop is littered with asserts that will fail if this happens.
Here's a sort-of-minimal reproducer of what this can look like on debug builds:
Python 3.11.0rc1+ (heads/3.11:bb0dab5c48, Sep 6 2022, 22:29:10) [GCC 9.3.0] on linux
Type "help", "copyright", "credits" or "license" for more information.
>>> class C:
... def __init__(self, x):
... self.x = x
... def __del__(self):
... if self.x:
... breakpoint()
...
>>> def f(x):
... C(x).x, C
...
>>> for _ in range(8):
... f(False)
...
>>> f(True)
--Return--
> <stdin>(6)__del__()->None
(Pdb) next
python: Python/ceval.c:3076: _PyEval_EvalFrameDefault: Assertion `cframe.use_tracing == 0' failed.
AbortedIn this case LOAD_ATTR_INSTANCE_VALUE's NOTRACE_DISPATCH() invalidates LOAD_GLOBAL_MODULE's assert(cframe.use_tracing == 0).
One option is to just rip out the asserts, which solves the more serious issue of crashing debug builds. However, I think that the best solution may be to stop using NOTRACE_DISPATCH() altogether. It's really hard to get right, and only saves us a single memory load and bitwise |. I benchmarked a branch that uses DISPATCH() for all instructions, and the result was "1.00x slower" than main. @markshannon tried the same thing, and got "1.01x slower". So going this route isn't free, but also not a huge penalty for correctness and peace-of-mind.
Flagging as a release blocker, since 3.11 is affected.
Activity
markshannon commentedon Sep 7, 2022
We can keep
NOTRACE_DISPATCH()for theLOAD_FASTandLOAD_CONSTANTsuperinstructions. That was the original use ofNOTRACE_DISPATCH()and is correct.I agree, the other uses are just too risky.
We can fix this more efficiently for 3.12 using PEP 669 (or a similar approach internally if the PEP is rejected).
markshannon commentedon Sep 7, 2022
Thinking about this a bit more, the
LOAD_FASTmay not be safe either.(C(0).x, local1, local2)would translate into:which has the same problem.
brandtbucher commentedon Sep 7, 2022
Hm, I don't see how, since
LOAD_ATTR_WHATEVER; LOAD_FAST__LOAD_FASTwill deopt toLOAD_ATTR; LOAD_FAST; LOAD_FASTunder tracing. AndLOAD_FAST__LOAD_FASTcan't run arbitrary code.Regardless, I think that the fact that we're having trouble proving the correctness of even simple instructions like these is a strong point in favor of just using
DISPATCH()everywhere.GH-96636: Remove all uses of NOTRACE_DISPATCH (GH-96643)
pythonGH-96636: Remove all uses of NOTRACE_DISPATCH (pythonGH-96643)
sweeneyde commentedon Sep 8, 2022
A question about the removal of
NOTRACE_DISPATCH_SAME_OPARG: couldn't that lead to duplicate traces for a single instruction? As in, the adaptive instruction attempts to specialize and fails, does DO_TRACING, then re-does the adaptive instruction, then does DO_TRACING again in the same spot?brandtbucher commentedon Sep 8, 2022
I don't think so, since
DO_TRACINGdeopts the next instruction. So the execution would goBINARY_OP_ADAPTIVE; DO_TRACING; BINARY_OP, for example.sweeneyde commentedon Sep 8, 2022
Okay I see. I was thinking that something like
BINARY_OP_ADAPTIVE; DO_TRACING; BINARY_OP; DO_TRACINGcould be problematic and duplicate a line trace, but if I'm understanding right:BINARY_OP_ADAPTIVE; DO_TRACING; BINARY_OP; DO_TRACINGcould happen is if_Py_Specialize_BinaryOp(...)itself somehow calledsys.settrace(), which looks to be impossible.BINARY_OP_ADAPTIVE; DO_TRACING; BINARY_OP; DO_TRACINGwould trace the BINARY_OP and trace whatever comes next.So I believe it impossible for an adaptive instruction to be followed by
DO_TRACING. (?)brandtbucher commentedon Sep 8, 2022
In practice, yeah, it doesn't really happen, since the specialization code needs to be extremely careful not to change the state of the program it's currently trying to optimize.
But it's not impossible, and catching it is really tricky (as we've seen). For example, the
LOAD_ATTRspecialization can callPyType_Ready, which can do all sorts of nonsense (like enable tracing). So I think it's safest to just useDISPATCH().gvanrossum commentedon Sep 8, 2022
There seem to be only three people who understand DO_TRACING. I can't find any docs for it, not even a single comment explaining it. Maybe we should have a write-up somewhere? I would volunteer but I don't think I understand enough of it.
So far I believe this: when tracing is turned on (in quickened code only?) the opcode variable (but not the opcode byte in the bytecode string) is OR-ed with 255, and that makes us hit the
case DO_TRACING:in the switch (which is reallycase 255:). The actual logic is mostly obscured by macros. The OR-ing happens inDISPATCH()and inPREDICT()usingopcode |= cframe.use_tracing OR_DTRACE_LINE. When tracing is turned on,cframe.use_tracingis set to 255, in_PyThreadState_UpdateTracingState(), and when it's turned off, that variable is set to 0 again. There are also numerous macros namedTRACE_FUNCTION_*()that check forcframe.use_tracing.brandtbucher commentedon Sep 8, 2022
The path is the same for both quickened and unquickened code.
DO_TRACINGcalls trace functions, then re-dispatches to the vanilla, un-quickened version of the actual opcode. So it doesn't matter if code has been quickened - when tracing, only the un-quickened version of each instruction will run. See below for a walkthrough of what happens.Yep. This or-ing is done to avoid branching on the tracing flag, and just using the normal instruction dispatch mechanism instead with a branchless modification.
So, to give a concrete example, let's assume that I have the quickened instructions
LOAD_ATTR_INSTANCE_VALUE; BINARY_OP_ADD_INT. While executingLOAD_ATTR_INSTANCE_VALUE, tracing is turned on. This is what happens during the nextDISPATCH():opcodeandopargare loaded, andopcode == BINARY_OP_ADD_INT.opcodeis or-ed withcframe.use_tracing. Nowopcode == 255 == DO_TRACING.DO_TRACINGcase, and fire off some tracing events.DO_TRACING, inTRACING_NEXTOPARG(), we load the next opcode and oparg, which is really the current opcode and oparg, sinceDO_TRACINGdoesn't get theINSTRUCTION_STARTheader that advances the instruction pointer. At this point,opcode == BINARY_OP_ADD_INTagain.EXTENDED_ARGhistorically skips doing tracing checks for the next instruction, so we never need to care about extended opargs here.TRACING_NEXTOPARGthen deoptimizes the opcode (this is theopcode = _PyOpcode_Deopt[opcode];move it performs), andopcode == BINARY_OP.PRE_DISPATCH_GOTO()andDISPATCH_GOTO(). This is equivalent to normal instruction dispatch, except we skip the part where we|the result withcframe.use_tracing(which would put us in an infinite loop where we just keep tracing the current instruction until the trace function disables itself).BINARY_OP, the instruction pointer gets advanced like normal, and, if tracing is still active, the whole dance happens again for the next opcode on the nextDISPATCH().So you can really think of tracing as executing two opcode cases per instruction: first
DO_TRACING, then whatever the real, un-quickened instruction is.Those are for more "predictable" tracing events like
call,return, andexception.DO_TRACINGis only used for thelineandopcodeevents, since those can happen literally anywhere (or, in the case ofopcode, everywhere).gvanrossum commentedon Sep 9, 2022
Thanks! Let’s put that in a file and check it in.
[3.11] GH-96636: Remove all uses of NOTRACE_DISPATCH (GH-96643) (#96688)