When a return statement also executes a finally clause, the sequence of lines reported to the trace function is different in 3.8 than it has been before 3.8:

$ cat finally_trace.py
def return_from_finally():
    try:
        print("returning")
        return 17
    finally:
        print("finally")

def trace(frame, event, arg):
    print(frame.f_lineno, event)
    return trace

import sys
sys.settrace(trace)
return_from_finally()

$ python3.7 finally_trace.py
1 call
2 line
3 line
returning
4 line
6 line
finally
6 return

$ python3.8 finally_trace.py
1 call
2 line
3 line
returning
4 line
6 line
finally
4 line
4 return


Is this intentional? Is it a bug? Will it change back before 3.8 is shipped?

This affects coverage.py, as reported in this bug: https://github.com/nedbat/coveragepy/issues/707

This is a side effect of specific optimization. If the return value is constant, it is pushed on the stack after executing the finally code (see LOAD_CONST at offset 14 below). But other opcodes at this line (POP_BLOCK and CALL_FINALLY) are executed after executing the finally code. Thus it looks like the line 4 is executed twice, but actually different opcodes marked with the same line are executed before and after executing the finally code.

Disassembly of <code object return_from_finally at 0x7feff78897c0, file "<stdin>", line 1>:
  2           0 SETUP_FINALLY           16 (to 18)

  3           2 LOAD_GLOBAL              0 (print)
              4 LOAD_CONST               1 ('returning')
              6 CALL_FUNCTION            1
              8 POP_TOP

  4          10 POP_BLOCK
             12 CALL_FINALLY             4 (to 18)
             14 LOAD_CONST               2 (17)
             16 RETURN_VALUE

  6     >>   18 LOAD_GLOBAL              0 (print)
             20 LOAD_CONST               3 ('finally')
             22 CALL_FUNCTION            1
             24 POP_TOP
             26 END_FINALLY
             28 LOAD_CONST               0 (None)
             30 RETURN_VALUE

The benefit of this optimization is that it can make the stack smaller. This decreases the memory consumption of the Python function frame by one pointer and speeds up the Python function frame creation time (one pointer assignment less). It is tiny, but I think it is worth to keep it.

I don't know what is the right solution here.

Humm, the optimization is not related here. Even if it is not involved (replace 17 with []), the line 4 is reported twice, because RETURN_VALUE is executed after CALL_FINALLY.

  4          10 BUILD_LIST               0
             12 POP_BLOCK
             14 CALL_FINALLY             2 (to 18)
             16 RETURN_VALUE

In 3.7 RETURN_VALUE was the opcode executed at line 4. The stack of blocks was unwinded at interpreted loop implicitly when execute RETURN_VALUE. But in 3.8 calling the finally code is explicit.

I can't tell if you think this is something that should be fixed, or not? (Also, I'm not getting email notifications from bpo, sorry for the delay).

I think that this can be fixed. But this is not easy.

The new behaviour looks the more correct to me.

Arguably the sequence should not include the second "4 line", but is otherwise correct.

When I get a chance I'll see what happens with https://github.com/python/cpython/pull/6641

In master, the sequence of events is:

1 call
2 line
3 line
returning
4 line
6 line
finally
6 return

which is the same as 3.7.
I now believe this is the correct trace, as the language spec states:

When a return, break or continue statement is executed in the try suite of a try…finally statement, the finally clause is also executed ‘on the way out.’

So line 6 should be last line traced.