This issue tracker has been migrated to GitHub, and is currently read-only.
For more information, see the GitHub FAQs in the Python's Developer Guide.

classification
Title: Weird behavior when setting f_trace in a context manager
Type: behavior Stage: resolved
Components: Versions: Python 3.6, Python 3.4, Python 3.5, Python 2.7
process
Status: closed Resolution: not a bug
Dependencies: Superseder:
Assigned To: Nosy List: Fred Gansevles, ncoghlan, terry.reedy, xdegaye
Priority: normal Keywords:

Created on 2015-10-25 12:04 by Fred Gansevles, last changed 2022-04-11 14:58 by admin. This issue is now closed.

Files
File name Uploaded Description Edit
as_context.py Fred Gansevles, 2015-10-25 12:04 reproduce weird 'with' behaviour
as_context_dis.py xdegaye, 2015-11-01 21:53
Messages (7)
msg253426 - (view) Author: Fred Gansevles (Fred Gansevles) * Date: 2015-10-25 12:04
I'm playing with the idea of making a DSL based on anonynous code blocks

I discovered that the behaviour of the context manager is different in some cases if there are line-continuations in the 'with' command

I've attached a script that reproduces this behaviour.

With both Python 2.7.6 and Python 3.4.3 I get the same results.


Fred.
msg253765 - (view) Author: Terry J. Reedy (terry.reedy) * (Python committer) Date: 2015-10-30 22:11
ZERO <__main__.Context object at 0x000000874AF3E0B8>
ONE <__main__.Context object at 0x000000874AF326D8>
Traceback (most recent call last):
  File "F:\Python\mypy\tem.py", line 45, in <module>
    print ('TWO', two)
NameError: name 'two' is not defined
Traceback (most recent call last):
  File "F:\Python\mypy\tem.py", line 53, in <module>
    print ('THREE', three)
NameError: name 'three' is not defined
FOUR <__main__.Context object at 0x000000874AF32748>
FIVE <__main__.Context object at 0x000000874B157EB8>
msg253880 - (view) Author: Xavier de Gaye (xdegaye) * (Python triager) Date: 2015-11-01 21:53
This is an artefact that occurs as the result of raising an exception in the local trace function.

Disassembling the first case of failure of as_context.py with the attached script gives the following:

  9           0 LOAD_GLOBAL              0 (context)
              3 CALL_FUNCTION            0 (0 positional, 0 keyword pair)
              6 SETUP_WITH              20 (to 29)

 10           9 STORE_FAST               0 (two)

 11          12 LOAD_GLOBAL              1 (print)
             15 LOAD_CONST               1 ('two')
             18 LOAD_FAST                0 (two)
             21 CALL_FUNCTION            2 (2 positional, 0 keyword pair)
             24 POP_TOP
             25 POP_BLOCK
             26 LOAD_CONST               0 (None)
        >>   29 WITH_CLEANUP
             30 END_FINALLY

 12          31 LOAD_GLOBAL              1 (print)
             34 LOAD_CONST               2 ('TWO')
             37 LOAD_FAST                0 (two)
             40 CALL_FUNCTION            2 (2 positional, 0 keyword pair)
             43 POP_TOP
             44 LOAD_CONST               0 (None)
             47 RETURN_VALUE

The __raise() local trace function is invoked on line 10 upon executing the STORE_FAST bytecode (this can be confirmed by running foo() under the control of pdb).  The exception raised by __raise() causes the assignement to 'two' to fail, hence the tracebacks in as_context.py.  This does not seem to be a bug in python.
msg253900 - (view) Author: Fred Gansevles (Fred Gansevles) * Date: 2015-11-02 08:03
Xavier, thanks for looking at my post.
But, since all six invocations of the context manager are the same
- I did an 'ast.parse' and 'ast.dump' and the the six calls were *exactly* the same (save lineno and col_offset) - why does 'zero', 'one', 'four' and 'five' get assigned but 'two' and 'three' not ?
msg253923 - (view) Author: Xavier de Gaye (xdegaye) * (Python triager) Date: 2015-11-02 15:11
The difference lies in the line numbers. When tracing lines, the interpreter operates on the basis of physical lines, not logical lines (https://docs.python.org/3/reference/lexical_analysis.html#line-structure).  The local trace function is called on the first instruction of each physical line (see the comment in maybe_call_line_trace() in Python/ceval.c).

In the first case of as_context.py, the 'zero' case, we have:

 25          74 SETUP_EXCEPT            49 (to 126)

 27          77 LOAD_NAME                6 (Context)
             80 CALL_FUNCTION            0 (0 positional, 0 keyword pair)
             83 SETUP_WITH              20 (to 106)
             86 STORE_NAME               7 (zero)

 28          89 LOAD_NAME                8 (print)
             92 LOAD_CONST               5 ('zero')
             95 LOAD_NAME                7 (zero)
             ...

After 'CALL_FUNCTION' has been run and the trace function set up, the __raise() local trace function is invoked for the first time upon running the 'LOAD_NAME' instruction, since 'SETUP_WITH' and 'STORE_NAME' are not the first instruction of line 27.

In the 'two' case, we have:

 41     >>  214 SETUP_EXCEPT            49 (to 266)

 42         217 LOAD_NAME                6 (Context)
            220 CALL_FUNCTION            0 (0 positional, 0 keyword pair)
            223 SETUP_WITH              20 (to 246)

 43         226 STORE_NAME              11 (two)

 44         229 LOAD_NAME                8 (print)
            232 LOAD_CONST               9 ('two')
            235 LOAD_NAME               11 (two)
            ....

Here the __raise() local trace function is invoked for the first time upon running the 'STORE_NAME' instruction.
msg253929 - (view) Author: Fred Gansevles (Fred Gansevles) * Date: 2015-11-02 15:52
Xavier, thanks! you found it.
If I look the code again, I see that with zero, one, four and five
the context-manager (i.e. Context()) and the target (one .. five) are on
the same code-line
In the case of two and three they are on a different line.

Now, with the dependency of the trace function on the *physical line* it all make sense.

Fred.
msg253952 - (view) Author: Terry J. Reedy (terry.reedy) * (Python committer) Date: 2015-11-02 23:47
Thank you Xavier.  I guess the lesson is that physical line tracing works best (and most as one would hope or expect) when physical lines are logical lines (or compound statement header lines).
History
Date User Action Args
2022-04-11 14:58:23adminsetgithub: 69660
2015-11-02 23:47:42terry.reedysetresolution: not a bug
messages: + msg253952
stage: test needed -> resolved
2015-11-02 15:52:13Fred Gansevlessetstatus: open -> closed

messages: + msg253929
2015-11-02 15:11:43xdegayesetmessages: + msg253923
2015-11-02 08:03:57Fred Gansevlessetmessages: + msg253900
2015-11-01 21:53:55xdegayesetfiles: + as_context_dis.py
nosy: + xdegaye
messages: + msg253880

2015-10-30 22:11:45terry.reedysetversions: + Python 2.7, Python 3.4, Python 3.5, Python 3.6
nosy: + terry.reedy, ncoghlan

messages: + msg253765

stage: test needed
2015-10-25 12:04:58Fred Gansevlescreate