Regression in python3.10 with traceback frame having lineno of -1

[asottile]

BPO	43933
Nosy	@gvanrossum, @vstinner, @nedbat, @encukou, @markshannon, @asottile, @pablogsal
PRs	bpo-43933: Show frame.f_lineno as None, rather than -1, if there is no line number. #25717 bpo-43933: Set frame.f_lineno during call to __exit__ #25719 bpo-43933: Force RETURN_VALUE bytecodes to have line numbers #26054 [3.10] bpo-43933: Force RETURN_VALUE bytecodes to have line numbers #26061

^{Note: these values reflect the state of the issue at the time it was migrated and might not reflect the current state.}

Show more details

GitHub fields:

assignee = 'https://github.com/markshannon'
closed_at = <Date 2021-04-30.13:34:44.252>
created_at = <Date 2021-04-24.19:56:33.908>
labels = ['release-blocker', '3.10', '3.11']
title = 'Regression in python3.10 with traceback frame having lineno of -1'
updated_at = <Date 2021-06-07.20:58:11.753>
user = 'https://github.com/asottile'

bugs.python.org fields:

activity = <Date 2021-06-07.20:58:11.753>
actor = 'vstinner'
assignee = 'Mark.Shannon'
closed = True
closed_date = <Date 2021-04-30.13:34:44.252>
closer = 'Mark.Shannon'
components = []
creation = <Date 2021-04-24.19:56:33.908>
creator = 'Anthony Sottile'
dependencies = []
files = []
hgrepos = []
issue_num = 43933
keywords = ['patch']
message_count = 27.0
messages = ['391795', '391798', '391799', '391893', '391897', '391908', '391915', '392066', '392303', '392343', '392431', '392432', '392448', '392463', '392604', '392605', '392888', '392895', '392897', '392915', '392916', '392970', '393376', '393481', '393579', '393596', '395286']
nosy_count = 7.0
nosy_names = ['gvanrossum', 'vstinner', 'nedbat', 'petr.viktorin', 'Mark.Shannon', 'Anthony Sottile', 'pablogsal']
pr_nums = ['25717', '25719', '26054', '26061']
priority = 'release blocker'
resolution = 'fixed'
stage = 'resolved'
status = 'closed'
superseder = None
type = None
url = 'https://bugs.python.org/issue43933'
versions = ['Python 3.10', 'Python 3.11']

[asottile]

This is breaking pytest for failed assertions: pytest-dev/pytest#8227

It also breaks the traceback in the output below

Here's a minimal example:

class Boom:
    def __enter__(self):
        return self
    def __exit__(self, *_):
        raise AssertionError('boom!')


def main() -> int:
    with Boom():
        raise AssertionError('hi')


if __name__ == '__main__':
    exit(main())

On python3.9 you get this:

Traceback (most recent call last):
  File "/home/asottile/workspace/cpython/t.py", line 10, in main
    raise AssertionError('hi')
AssertionError: hi

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/home/asottile/workspace/cpython/t.py", line 14, in <module>
    exit(main())
  File "/home/asottile/workspace/cpython/t.py", line 10, in main
    raise AssertionError('hi')
  File "/home/asottile/workspace/cpython/t.py", line 5, in __exit__
    raise AssertionError('boom!')
AssertionError: boom!

output in python3.10:

Traceback (most recent call last):
  File "/home/asottile/workspace/cpython/t.py", line 10, in main
    raise AssertionError('hi')
AssertionError: hi

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/home/asottile/workspace/cpython/t.py", line 14, in <module>
    exit(main())
  File "/home/asottile/workspace/cpython/t.py", line -1, in main
  File "/home/asottile/workspace/cpython/t.py", line 5, in __exit__
    raise AssertionError('boom!')
AssertionError: boom!

Notice the second to last frame is now missing and invalid (line -1)

I bisected this and found this is the culprit:

3bd6035
#24202

3bd6035b6baf1a7d51b7cc2c6bb2c81886236b67 is the first bad commit
commit 3bd6035b6baf1a7d51b7cc2c6bb2c81886236b67
Author: Mark Shannon <mark@hotpy.org>
Date:   Wed Jan 13 12:05:43 2021 +0000

    bpo-42908: Mark cleanup code at end of try-except and with artificial (#24202)
    
    * Mark bytecodes at end of try-except as artificial.
    
    * Make sure that the CFG is consistent throughout optimiization.
    
    * Extend line-number propagation logic so that implicit returns after 'try-except' or 'with' have the correct line numbers.
    
    * Update importlib

 Lib/test/test_dis.py          |    2 +-
 Lib/test/test_sys_settrace.py |   40 +
 Python/compile.c              |  135 +-
 Python/importlib.h            | 3153 ++++++++++++++---------------
 Python/importlib_external.h   | 4489 ++++++++++++++++++++---------------------
 Python/importlib_zipimport.h  | 1013 +++++-----
 6 files changed, 4473 insertions(+), 4359 deletions(-)
bisect run success

which appears to be due to bpo-42908

[pablogsal]

Marking as release blocker since is breaking pytest

[pablogsal]

Thanks for the bisection, Anthony

[markshannon]

What exactly is the issue here?
That the line number is -1, or that is different from 3.9?

The -1 should be None. I can fix that, but there is the issue of whether the cleanup code in a with statement should have a line number or not.

The traceback for 3.9 is incorrect, the program is not on line 10 when __exit__ is called.

Currently we mark the cleanup code for the with statement as artificial meaning that it has no line number.
We could give it the line number of the with keyword, but that might break coverage and profiling tools.

PEP-626 says that the "with" keyword is executable, and should be traced, but nothing about whether that includes the cleanup call to __exit__.

[nedbat]

Mark, you say:

The traceback for 3.9 is incorrect, the program is not on line 10 when __exit__ is called.

It's kind of not on any line in main(), but line 10 is the most useful line to indicate. It's the last bit of the user's code that was running, and it is the reason for leaving the with statement.

[markshannon]

In this case, if happens that line 10 was the last line of code executing in the body of the with statement.
But the reason it was listed, was that it was statically the last line of code in the body.

If the body is something like:

1. if TRUE:

2. ...
   

3. else:

4. ...
   

Then the reported last line will be 4, even though it is never executed.
We can fix this, at the cost of extra compiler complexity and increased bytecode size for the non-exceptional case, but it is very difficult for the exceptional case, because we don't know statically where the exception has come from.

[markshannon]

This test case was added for 3.10.
In 3.9 it reports that the pass statement executes, even though it is unreachable.

https://github.com/python/cpython/blob/master/Lib/test/test_sys_settrace.py#L919