Repository navigation
White space causes inconsistent frame traversal in With blocks #121865
Description
Activity
Why do you think it's not right? The "format" will change the debugging(tracing) behavior because by default tracing is line based. If you have extra lines, you could have extra line events. In your second example, the
as fpart generates some bytecode to store the return value tof, which makes that line "relevant". If you remove theas f, that line won't be hit as there are no bytecode from that line. I don't think this is a bug.So the reported behavior is consistent when there are multiple statements on a line:
fun1();fun2() # 0
The trace only lists 0 once. It is inconsistent in broken up statements:
fun( # 0 0) # 1
Does 0, 1, 0
But with falls in the later camp. Back to
with open( # 0 a # 1 ) as b: # 2 pass # 3
It's one statement, the line breaks don't change that.
I agree with the relevant line statement, so 2, 3, 0 is correct.but shouldn't it be 0,1,0 here?
with open(a) as b: # 0 pass # 1
with open(a) as b: # 0 pass # 1
I believe this is
0, 1, 0.Could you be specific about which example you believe is wrong? I'm a bit confused. You gave plenty of examples and then you said some of them are good. The very last example that you did not like is not doing what you thought.
Again, the behavior of
sys.settraceis simple - if something happens on a new line (a bytecode is executed), it reports an event. If you follow that rule, you'll realize that the examples you gave kind of make sense.sys.settracedoes not care about the concept of statements or Python equivalents - it reports when a new line is executed.I realize this comes across as a little pedantic and annoying, so let me relate this to the actual bug it created.
Here's some more tracing:
import traceback import sys def build_trace(context): def trace(*args, **kwargs): stack = traceback.extract_stack() for frame in stack[::-1]: _filename, lineno, function_name, _code = frame if function_name in ("bar", "foo", "__init__"): print(context, function_name, "trace", frame.lineno) if args: parent_frame = args[0] if "f" not in parent_frame.f_locals: print("f not in locals, because the trace is inconsistent") return trace class Context(): def __init__(self): build_trace("init")() def __enter__(self): build_trace("enter")() frame = sys._getframe(1) self.old = frame.f_trace sys.settrace(lambda *_args, **_keys: None) frame.f_trace = build_trace("frame") print("enter has finished but f might not be available to the trace") def __exit__(self, *kwargs): sys.settrace(self.old)
def foo(): with Context() as f: stack = traceback.extract_stack() print("---") for frame in stack[::-1][:3]: _filename, lineno, function_name, _code = frame if function_name == "foo": print(frame.lineno, lineno) break print("Foo") foo()
Foo init __init__ trace 19 init foo trace 2 enter foo trace 2 enter has finished but f might not be available to the trace frame foo trace 3 frame foo trace 4 --- frame foo trace 5 frame foo trace 6 frame foo trace 7 frame foo trace 8 3 3 frame foo trace 9 frame foo trace 2def bar(): with Context( ) as f: stack = traceback.extract_stack() print("---") for frame in stack[::-1][:3]: _filename, lineno, function_name, _code = frame if function_name == "bar": print(frame.lineno, lineno) break print("Bar") bar()
Bar init __init__ trace 19 init bar trace 2 enter bar trace 2 enter has finished but f might not be available to the trace frame bar trace 3 f not in locals, because the trace is inconsistent frame bar trace 4 frame bar trace 5 --- frame bar trace 6 frame bar trace 7 frame bar trace 8 frame bar trace 9 4 4 frame bar trace 10 frame bar trace 2
WASM notebook: https://marimo.app/l/0aiv3o
Just looking for consistency. So expected behavior with the new output
To me:Foo init __init__ trace 19 init foo trace 2 enter foo trace 2 enter has finished but f is not available to the trace yet until after line 2 frame foo trace 2 <--- Added ! f is set here f is not in locals and this is expected and consistent with the line break case frame foo trace 3 frame foo trace 4 --- frame foo trace 5 frame foo trace 6 frame foo trace 7 frame foo trace 8 3 3 frame foo trace 9 frame foo trace 2Makes sense, or
Bar init __init__ trace 19 init bar trace 2 enter bar trace 3 <-- Changed from 2 to 3 since the `as` is on 3 enter has finished and f will be available to the trace frame bar trace 4 frame bar trace 5 --- frame bar trace 6 frame bar trace 7 frame bar trace 8 frame bar trace 9 4 4 frame bar trace 10 frame bar trace 2But the current behavior is unexpected
frame foo trace 2 <--- Added ! f is set hereNo, f is set on line 3 in
as f- like I mentioned above.The reason
f not in locals, because the trace is inconsistentIs because trace function runs before the line is executed, not after. Line 3 is about to execute, where
fwill be set to something, and you can't access it before it's set.No, f is set on line 3 in as f - like I mentioned above.
line 3 for
foois not theasstatementdef foo(): # 1 with Context() as f: # 2 stack = traceback.extract_stack() # 3
Using
fooandbarmight be muddying the conversation- so might my quickly thrown together code.trace function runs before the line is executed, not after. Line 3 is about to execute, where f will be set to something, and you can't access it before it's set.
Yes, I get that and why I suggested that
__enter__be associated with line 3 instead of line 2Oh, my bad. Your bar suggestion is not preferred either.
__enter__is called on line 2, withContext().as fis something extra. Consider the code astmp = Context() # __enter__ f = tmp
This is obviously not the same (tracing perspective) as
tmp = Context(); f = tmp
Again,
sys.settrace()does not care about the Python concept of "statement". It does not treatwith Context() as fas a whole. It does not consider other multi-line statement as a whole either. For example:lst = [ 1, 2, 3, 4, 5]
The code above will generate a line event each line. That's just how it is designed.
I get the multiline behavior, I agree.
Confused about your first case, doesn't:
tmp = Context() # Construction not enter f = tmp.__enter__() # f would be associated with line 2...
make more sense. If your example is what's currently happening, why is
__enter__implicitly done on 1? Did you meantmp = Context().__enter__() f = tmp # in which case this frame is never useful, since line 1 is also visited, and tmp has no accessible interface at this point.
and
tmp = Context().__enter__(); f = tmp
? Sure, this is consistent with current behavior, but I guess that's the crux of the bug report; it's not obvious that the assignment is disassociated from the
__enter__call, and creates a meaningless frame. I agree withtmp = Context(); f = tmp.__enter__() # f is associated with line 2, and trace only visits this once and skips, make sense
or with whitespace analogous to
tmp = Context(); ( f := tmp.__enter__()) # useful since before __enter__
or honestly any variation of a broken line (including separate lines like above).
It doesn't have anything to do with statements or shared lines; just the implementation detail which leaves an ambiguous state.
Oh sorry I made a mistake on my code.
with Context( ) as f
is equivalent to
ctx = Context(); tmp = ctx.__enter__() f = tmp
That has nothing to do with tracing, that's how the compiler sees it.
with open("input.txt" ) as f: pass
compiles to
0 RESUME 0 1 LOAD_NAME 0 (open) PUSH_NULL LOAD_CONST 0 ('input.txt') CALL 1 COPY 1 LOAD_SPECIAL 1 (__exit__) SWAP 2 SWAP 3 LOAD_SPECIAL 0 (__enter__) CALL 0 2 L1: STORE_NAME 1 (f) 3 L2: NOP 1 LOAD_CONST 1 (None) LOAD_CONST 1 (None) LOAD_CONST 1 (None) CALL 3 POP_TOP RETURN_CONST 1 (None) L3: PUSH_EXC_INFO WITH_EXCEPT_START TO_BOOL POP_JUMP_IF_TRUE 1 (to L4) RERAISE 2 L4: POP_TOP L5: POP_EXCEPT POP_TOP POP_TOP POP_TOP RETURN_CONST 1 (None) -- L6: COPY 3 POP_EXCEPT RERAISE 1 ExceptionTable: L1 to L2 -> L3 [2] lasti L3 to L5 -> L6 [4] lastias fis an optional addition towithstatement and__enter__()is obviously called before assigning tof. That's how Python sees it for a long time and I don't see a reason to change that.The current implementation
- does not contradict any documentation
- has been like this for a long time
So if you want to change it, you need a really good reason to justify it, because it would be a breaking change. Up until now, I did not see anything concrete other than the fact you feel that this is weird. I'm not saying you are wrong, anyone can have their own opinions about how Python works, but your idea has to be good to be adopted.
For now, because there's no evidence that this is a bug (crashing/does not follow documentation/is different than before), I would suggest you ask about this in disclosure. This looks like a feature request to me.
Ok, I found the implementation and read into the pep, the behavior is as expected: https://peps.python.org/pep-0343/#specification-the-with-statement
Sorry about that
FWIW, 3.14 alpha does change the behavior to trace on the expression and not the
with. This is good enough for meFWIW, 3.14 alpha does change the behavior to trace on the expression and not the
with. This is good enough for meCould you elaborate on that? Not sure if that's intended.
Definitely intended, as it provides a better stack trace:
https://github.com/python/cpython/blame/main/Python/compile.c#L6008
#120125In testing:
enter bar trace <line number of expression>
over
enter bar trace <line number of with>You can get the behavior I proposed with:
diff --git a/Python/compile.c b/Python/compile.c index ca64b5cd37..be17f68176 100644 --- a/Python/compile.c +++ b/Python/compile.c @@ -6011,8 +6011,13 @@ compiler_with(struct compiler *c, stmt_ty s, int pos) ADDOP_I(c, loc, SWAP, 2); ADDOP_I(c, loc, SWAP, 3); ADDOP_I(c, loc, LOAD_SPECIAL, SPECIAL___ENTER__); - ADDOP_I(c, loc, CALL, 0); - ADDOP_JUMP(c, loc, SETUP_WITH, final); + + location as_loc = loc; + if (item->optional_vars) { + as_loc = LOC(item->optional_vars); + } + ADDOP_I(c, as_loc, CALL, 0); + ADDOP_JUMP(c, as_loc, SETUP_WITH, final); /* SETUP_WITH pushes a finally block. */ USE_LABEL(c, block);
But it's marginal, and fine as is
Ah, I see what you meant. That's for the exception stack right? I don't think this has anything to do with tracing. The tracing examples you gave above still behave the same I think?
Tracing also leverages the same methods:
def bar(): with ( Context() as f):pass print("Bar") bar()
is
Bar init __init__ trace 19 init bar trace 3 enter bar trace 2and different with the newest version HEAD with
Bar init __init__ trace 19 init bar trace 3 enter bar trace 3Which I am happy with.
Okay, but this is because the line number is on
Context()now instead ofwith. This still has nothing to do withas f.
Bug report
Bug description:
White space causes inconsistent frame traversal in With blocks
Consider
frame order goes:
2, 3, 0
versus
frame order goes 1, 0
This doesn't seem right, many formatters will make this adjustment as an expected NoOp.
Code to reproduce the behaviour:
Expected behaviour
or maybe in the context of debuggers setting break points
Additional context
Please point me to where in the documentation if this is expected behavior,
The inconsistency seems like a bug to me.
Here's a wasm notebook, but I did test it locally as well: https://marimo.app/l/0eld5u
CPython versions tested on:
3.10, 3.11, 3.12
Operating systems tested on:
Linux, Other