Differing behavior for sys.setrace between 3.12 and 3.13

[markshannon]

Bug report

Bug description:

def gen():
    print(2)
    yield 3
    print(4)

print(next(gen()))

3.12 events

call 14: def gen():
line 15:     print(2)
line 16:     yield 3
retu 16:     yield 3
call 16:     yield 3
exce 16:     yield 3
retu 16:     yield 3

main:

call 14: def gen():
line 15:     print(2)
line 16:     yield 3
retu 16:     yield 3

Note the extra except and return events for 3.12.

Originally discovered by @nedbat #113680 (comment)

CPython versions tested on:

3.12, 3.13

Operating systems tested on:

No response

[markshannon]

This is a sys.monitoring change. sys.settrace merely reflects that.
For

events = []
with record_events(events):
    next(gen())
print(events)

3.12:

['call', 'start', 'call', 'yield', 'raise', 'exception_handled', 'unwind']

3.13:

['call', 'start', 'call', 'yield']

The events for 3.13 look to be correct. The additional 'raise', 'exception_handled', 'unwind' events for 3.12 seem spurious.
Even if 3.13 is now correct we should at the very least document the change.

[markshannon]

This has nothing to do with monitoring or tracing. It is about the lifetime of generators.
If we change

with record_events(events):
    next(gen())

to

g = gen()
with record_events(events):
    next(g)

The events recorded are the same for 3.12 and 3.13. The additional events in 3.12 are from the generator being closed.

[markshannon]

Bisected to #111069

[markshannon]

So what's happening is this:

In 3.12 the generator is closed by calling throw() which causes the 'raise', 'exception_handled', 'unwind' sequence of events.
However, that isn't necessary for a simple generator, so we simply close it in 3.13.

@nedbat is this a problem for coverage?

[nedbat]

@markshannon I think this and other sys.monitoring changes are going to require me to do a bit of a re-think. There are tests in the coverage.py test suite that check data based on the raw events. The final user-visible coverage data might come out the same, but the tests are failing now because of changes like this. I'll be working on this.

[markshannon]

This isn't a sys.monitoring change.

The change is that we no longer throw into generators to close them.
The events that you were seeing in 3.12 happened in the __del__() method of the generator, which is no longer called in 3.13.

[nedbat]

This isn't a sys.monitoring change.

I understand. I meant to say, this and also sys.monitoring changes are changing the way I collect data, and therefore the way I test.

[gvanrossum]

So... There's nothing to see here, move along, and close the issue?

[nedbat]

I will re-open if needed.

[nedbat]

Investigating other generator tracing failures in the coverage.py test suite, I find that the trace function is invoked slightly differently for the return event when yielding. The frame.last_i value is pointing to YIELD_VALUE in Python 3.12, but points to RESUME in 3.13. Is this intentional? Will it stay this way?

Test program:

import dis, linecache, sys

print(sys.version)

def trace(frame, event, arg):
    # The weird globals here is to avoid a NameError on shutdown...
    if frame.f_code.co_filename == globals().get("__file__"):
        lineno = frame.f_lineno
        line = linecache.getline(__file__, lineno).rstrip()
        print("{} {}: {}".format(event[:4], lineno, line))
    if event == "return":
        code = frame.f_code.co_code
        lasti = frame.f_lasti
        print(f"code[{lasti=}] is {dis.opname[code[lasti]]}")
    return trace

def gen():
    yield 3

dis.dis(gen)

sys.settrace(trace)

print(next(gen()))

Running on 3.12:

3.12.1 (main, Dec  8 2023, 20:58:19) [Clang 15.0.0 (clang-1500.0.40.1)]
 17           0 RETURN_GENERATOR
              2 POP_TOP
              4 RESUME                   0

 18           6 LOAD_CONST               1 (3)
              8 YIELD_VALUE              1
             10 RESUME                   1
             12 POP_TOP
             14 RETURN_CONST             0 (None)
        >>   16 CALL_INTRINSIC_1         3 (INTRINSIC_STOPITERATION_ERROR)
             18 RERAISE                  1
ExceptionTable:
  4 to 14 -> 16 [0] lasti
call 17: def gen():
line 18:     yield 3
retu 18:     yield 3
code[lasti=8] is YIELD_VALUE
call 18:     yield 3
exce 18:     yield 3
retu 18:     yield 3
code[lasti=8] is YIELD_VALUE
3

Running on 3.13.0a2:

3.13.0a2 (main, Nov 24 2023, 14:53:47) [Clang 15.0.0 (clang-1500.0.40.1)]
  17           0 RETURN_GENERATOR
               2 POP_TOP
               4 RESUME                   0

  18           6 LOAD_CONST               1 (3)
               8 YIELD_VALUE              0
              10 RESUME                   5
              12 POP_TOP
              14 RETURN_CONST             0 (None)

None     >>   16 CALL_INTRINSIC_1         3 (INTRINSIC_STOPITERATION_ERROR)
              18 RERAISE                  1
ExceptionTable:
  4 to 14 -> 16 [0] lasti
call 17: def gen():
line 18:     yield 3
retu 18:     yield 3
code[lasti=10] is RESUME
3

Running on the tip of 3.13:

3.13.0a2+ (heads/main:2e17cad2b8, Jan  9 2024, 05:00:41) [Clang 15.0.0 (clang-1500.1.0.2.5)]
  17           RETURN_GENERATOR
               POP_TOP
       L1:     RESUME                   0

  18           LOAD_CONST               1 (3)
               YIELD_VALUE              0
               RESUME                   5
               POP_TOP
               RETURN_CONST             0 (None)

  --   L2:     CALL_INTRINSIC_1         3 (INTRINSIC_STOPITERATION_ERROR)
               RERAISE                  1
ExceptionTable:
  L1 to L2 -> L2 [0] lasti
call 17: def gen():
line 18:     yield 3
retu 18:     yield 3
code[lasti=10] is RESUME
3

[markshannon]

tl;dr:
Yes, you can rely the semantics of last_i not changing from from now. But we do reserve the right to mess around with the bytecode (although it should be a lot more stable now that PEPs 659 and 669 are done).

Long answer:

The semantics of last_i were less than ideal for 3.11 and 3.12.
Historically (up to 3.10) last_i referred to the last instruction, except when set by frame.f_lineno = and a couple of other corner cases.
In 3.11, some instructions became larger, so that last_i no longer referred to the last instruction, but the last code unit within the last instruction. This meant that the expression dis.opname[code[lasti]] could be gibberish if the previous instruction was a CALL, LOAD_ATTR or other instruction containing more than one code unit.

@iritkatriel fixed all that in #109094 replacing the internal "previous code unit pointer" with a more understandable "instruction pointer". last_i inherits this behavior.
Now the instruction pointer (and last_i) points to the start of the last instruction that started executing, except during a call to a Python function or a send to a generator, when it points to the return/resume address. This is much like an instruction pointer that you might be familiar with from hardware.

@iritkatriel is this summary correct?

[nedbat]

Thanks for the detail. It's a bit odd to have f_lasti pointing to the next instruction to execute. I wonder if there's a way to document this? The frame object docs say "the precise instruction", which is ambiguous about next or last.

[iritkatriel]

Now the instruction pointer (and last_i) points to the start of the last instruction that started executing, except during a call to a Python function or a send to a generator, when it points to the return/resume address.

During a call the lasti of the calling frame points to the beginning of the CALL instruction. Same with SEND.

[markshannon]

I think this is all sorted.
@nedbat feel to reopen if there is anything else to be done.