Skip to content

Traceback says line -1 when KeyboardInterrupt during minimal for-if-loop  #107901

Closed

Description

@pan324

More generally, the issue happens with all exceptions raised by other threads.

Run the code below and interrupt with ctrl+c.

# If part of a file, potentially more code before the loop. Traceback says -1 regardless.
for i in range(30000000):
  if not i%1000000:
      pass  # Or any other operation here that is faster than iterating a million i values.

With the following traceback:

Traceback (most recent call last):
 File "/home/panta/issue.py", line -1, in <module>
KeyboardInterrupt

The issue disappears as soon as we add just a bit more to the loop

for i in range(30000000):
  if not i%1000000:  # The 3.10 traceback points to this line.
      pass
  pass  # The 3.11 and 3.12 tracebacks point to this line.
Traceback (most recent call last):
File "/home/panta/issue.py", line 4, in <module>
  pass
KeyboardInterrupt

The issue persists whether running from the shell or as a file or even using exec. It works the same inside functions/methods. It exists in 3.11 and 3.12 but not 3.10, across Windows and Linux.

  • CPython versions tested on: 3.10.6 (no issue), 3.11.1 (issue), 3.11.4 (issue), 3.12.0rc1 (issue)
  • Operating system and architecture: Windows 10 and Ubuntu 22.04.2 LTS (WSL)

Linked PRs

Activity

  1. added
    type-bugAn unexpected behavior, bug, or error
    on Aug 12, 2023
  2. added
    3.11only security fixes
    3.12only security fixes
    3.13only security fixes
    on Aug 12, 2023
  3. sunmy2019 commented on Aug 13, 2023

    @sunmy2019
    Member

    @markshannon as an expert here.

    I investigated the -1 being set at Line 950 here.

    static void
    advance(PyCodeAddressRange *bounds)
    {
    ASSERT_VALID_BOUNDS(bounds);
    bounds->opaque.computed_line += get_line_delta(bounds->opaque.lo_next);
    if (is_no_line_marker(*bounds->opaque.lo_next)) {
    bounds->ar_line = -1;
    }
    else {
    bounds->ar_line = bounds->opaque.computed_line;
    }
    bounds->ar_start = bounds->ar_end;

    -1 set at

    *bounds = {ar_start = 42, ar_end = 46, ar_line = -1, opaque = {computed_line = 2, lo_next = ... , limit = ""}}
    

    during the call of

    _PyCode_CheckLineNumber (lasti=42, bounds=...)

    Also the disassembly here:

      0           0 RESUME                   0
    
      1           2 LOAD_NAME                0 (range)
                  4 PUSH_NULL
                  6 LOAD_CONST               0 (30000000000000)
                  8 CALL                     1
                 16 GET_ITER
            >>   18 FOR_ITER                14 (to 50)
                 22 STORE_NAME               1 (i)
    
      2          24 LOAD_NAME                1 (i)
                 26 LOAD_CONST               1 (1000000)
                 28 BINARY_OP                6 (%)
                 32 TO_BOOL
                 40 POP_JUMP_IF_FALSE        2 (to 46)
                 42 JUMP_BACKWARD           14 (to 18)
    
      3     >>   46 JUMP_BACKWARD           16 (to 18)
    
      1     >>   50 END_FOR
                 52 RETURN_CONST             2 (None)
    
  4. sweeneyde commented on Aug 13, 2023

    @sweeneyde
    Member

    cc @iritkatriel as well. I bisected to 4c72517, and I think this is the relevant line:

    basicblock_addop(backwards_jump, JUMP, target->b_label.id, NO_LOCATION);

    I assume we need every instruction that checks the eval breaker to also have a line number. It looks like propagate_line_numbers and duplicate_exits_without_lineno try to enforce something like this, but then normalize_jumps re-introduces an instruction with NO_LOCATION.

    Here's the disassembly showing a JUMP_BACKWARD with Positions(lineno=None, end_lineno=None, col_offset=None, end_col_offset=None):

    Disassembly of reproducer on main.
    def f():
        for i in range(30000000):
            if not i%1000000:
                pass
    
    import dis
    from pprint import pprint
    pprint(list(dis.get_instructions(f)))
    [Instruction(opname='RESUME', opcode=151, arg=0, argval=0, argrepr='', offset=0, start_offset=0, starts_line=1, is_jump_target=False, positions=Positions(lineno=1, end_lineno=1, col_offset=0, end_col_offset=0)),
     Instruction(opname='LOAD_GLOBAL', opcode=116, arg=1, argval='range', argrepr='range + NULL', offset=2, start_offset=2, starts_line=2, is_jump_target=False, positions=Positions(lineno=2, end_lineno=2, col_offset=13, end_col_offset=18)),
     Instruction(opname='LOAD_CONST', opcode=100, arg=1, argval=30000000, argrepr='30000000', offset=12, start_offset=12, starts_line=None, is_jump_target=False, positions=Positions(lineno=2, end_lineno=2, col_offset=19, end_col_offset=27)),
     Instruction(opname='CALL', opcode=171, arg=1, argval=1, argrepr='', offset=14, start_offset=14, starts_line=None, is_jump_target=False, positions=Positions(lineno=2, end_lineno=2, col_offset=13, end_col_offset=28)),
     Instruction(opname='GET_ITER', opcode=68, arg=None, argval=None, argrepr='', offset=22, start_offset=22, starts_line=None, is_jump_target=False, positions=Positions(lineno=2, end_lineno=4, col_offset=4, end_col_offset=16)),
     Instruction(opname='FOR_ITER', opcode=93, arg=14, argval=56, argrepr='to 56', offset=24, start_offset=24, starts_line=None, is_jump_target=True, positions=Positions(lineno=2, end_lineno=4, col_offset=4, end_col_offset=16)),
     Instruction(opname='STORE_FAST', opcode=125, arg=0, argval='i', argrepr='i', offset=28, start_offset=28, starts_line=None, is_jump_target=False, positions=Positions(lineno=2, end_lineno=2, col_offset=8, end_col_offset=9)),
     Instruction(opname='LOAD_FAST', opcode=124, arg=0, argval='i', argrepr='i', offset=30, start_offset=30, starts_line=3, is_jump_target=False, positions=Positions(lineno=3, end_lineno=3, col_offset=15, end_col_offset=16)),
     Instruction(opname='LOAD_CONST', opcode=100, arg=2, argval=1000000, argrepr='1000000', offset=32, start_offset=32, starts_line=None, is_jump_target=False, positions=Positions(lineno=3, end_lineno=3, col_offset=17, end_col_offset=24)),
     Instruction(opname='BINARY_OP', opcode=122, arg=6, argval=6, argrepr='%', offset=34, start_offset=34, starts_line=None, is_jump_target=False, positions=Positions(lineno=3, end_lineno=3, col_offset=15, end_col_offset=24)),
     Instruction(opname='TO_BOOL', opcode=6, arg=None, argval=None, argrepr='', offset=38, start_offset=38, starts_line=None, is_jump_target=False, positions=Positions(lineno=3, end_lineno=3, col_offset=15, end_col_offset=24)),
     Instruction(opname='POP_JUMP_IF_FALSE', opcode=114, arg=2, argval=52, argrepr='to 52', offset=46, start_offset=46, starts_line=None, is_jump_target=False, positions=Positions(lineno=3, end_lineno=3, col_offset=15, end_col_offset=24)),
     Instruction(opname='JUMP_BACKWARD', opcode=140, arg=14, argval=24, argrepr='to 24', offset=48, start_offset=48, starts_line=None, is_jump_target=False, positions=Positions(lineno=None, end_lineno=None, col_offset=None, end_col_offset=None)),
     Instruction(opname='JUMP_BACKWARD', opcode=140, arg=16, argval=24, argrepr='to 24', offset=52, start_offset=52, starts_line=4, is_jump_target=True, positions=Positions(lineno=4, end_lineno=4, col_offset=12, end_col_offset=16)),
     Instruction(opname='END_FOR', opcode=4, arg=None, argval=None, argrepr='', offset=56, start_offset=56, starts_line=2, is_jump_target=True, positions=Positions(lineno=2, end_lineno=4, col_offset=4, end_col_offset=16)),
     Instruction(opname='RETURN_CONST', opcode=121, arg=0, argval=None, argrepr='None', offset=58, start_offset=58, starts_line=None, is_jump_target=False, positions=Positions(lineno=2, end_lineno=4, col_offset=4, end_col_offset=16))]
    
  5. pan324 commented on Aug 13, 2023

    @pan324
    ContributorAuthor

    In case this helps with debugging, I've played around a bit more and found an even simpler test case:

    for i in q:  # Where q = [1]*int(3e7) or something similar.
        if i:
            pass
  6. sunmy2019 commented on Aug 13, 2023

    @sunmy2019
    Member

    I assume we need every instruction that checks the eval breaker to also have a line number.

    Agree.

  7. iritkatriel commented on Aug 13, 2023

    @iritkatriel
    Member

    I bisected to 4c72517, and I think this is the relevant line:

    basicblock_addop(backwards_jump, JUMP, target->b_label.id, NO_LOCATION);

    Looks plausible. It might be simply a matter of copying the location of the old (backward jump) to the new jump that we are adding in this line. Let me know if you would like to try, or would prefer I do.

  8. markshannon commented on Aug 14, 2023

    @markshannon
    Member

    Does the insertion of the extra jump take place before or after line number propagation?
    If it happens before, then simply copying the line number may not be insufficient, as the original jump may not have a line number.

  9. markshannon commented on Aug 14, 2023

    @markshannon
    Member

    This also happens in 3.11, which suggests that 4c72517 is not the root cause.
    I think line number propagation (or the lack of) is the issue.

    For the fix in 3.13 we might want to tag instructions that check the eval breaker (as well as raises and returns) as needing a line number, then make sure we propagate line numbers to those instructions.

    For the 3.11 and 3.12 maybe just backport the change to line propagation and not the metadata?

  10. iritkatriel commented on Aug 21, 2023

    @iritkatriel
    Member

    Does the insertion of the extra jump take place before or after line number propagation?
    If it happens before, then simply copying the line number may not be insufficient, as the original jump may not have a line number.

    It happens after line numbers are resolved.

  11. iritkatriel commented on Aug 21, 2023

    @iritkatriel
    Member

    I created a PR that fixes the case that was reported here.

    We will need to follow up with tests that ensure that all instructions that check the eval breaker have a line number. I tested and found that this is not the case, I saw some instructions in exception handlers that violated this (and they were not as straightforward to fix).

  12. added a commit that references this issue on Aug 21, 2023
  13. 23 remaining items

  14. added 4 commits that reference this issue on Jan 25, 2024
  15. added 5 commits that reference this issue on Feb 11, 2024
  16. added a commit that references this issue on Feb 14, 2024
  17. added 4 commits that reference this issue on Sep 2, 2024
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Metadata

Metadata

Assignees

Labels

3.11only security fixes3.12only security fixes3.13only security fixestype-bugAn unexpected behavior, bug, or error

Projects

No projects

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions