| msg325484 - (view) |
Author: Ned Batchelder (nedbat) *  |
Date: 2018-09-16 13:15 |
| 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? |
|
|
| msg325485 - (view) |
Author: Ned Batchelder (nedbat) * |
Date: 2018-09-16 13:16 |
| This affects coverage.py, as reported in this bug: https://github.com/nedbat/coveragepy/issues/707 |
|
|
| msg325489 - (view) |
Author: Serhiy Storchaka (serhiy.storchaka) *  |
Date: 2018-09-16 14:28 |
| 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 "", 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. |
|
|
| msg325490 - (view) |
Author: Serhiy Storchaka (serhiy.storchaka) * |
Date: 2018-09-16 14:39 |
| 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. |
|
|
| msg326180 - (view) |
Author: Ned Batchelder (nedbat) * |
Date: 2018-09-23 20:36 |
| 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). |
|
|
| msg326185 - (view) |
Author: Serhiy Storchaka (serhiy.storchaka) * |
Date: 2018-09-23 21:22 |
| I think that this can be fixed. But this is not easy. |
|
|
| msg326215 - (view) |
Author: Mark Shannon (Mark.Shannon) * |
Date: 2018-09-24 09:58 |
| The new behaviour looks the more correct to me. Arguably the sequence should not include the second "4 line", but is otherwise correct. |
|
|
| msg326216 - (view) |
Author: Mark Shannon (Mark.Shannon) * |
Date: 2018-09-24 10:01 |
| When I get a chance I'll see what happens with https://github.com/python/cpython/pull/6641 |
|
|
| msg385047 - (view) |
Author: Mark Shannon (Mark.Shannon) * |
Date: 2021-01-13 16:20 |
| 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. |
|
|