classification
Title: bytecode<>line number mapping and f_lasti seem wrong in 3.10.0b2
Type: Stage: resolved
Components: C API Versions: Python 3.10
process
Status: closed Resolution:
Dependencies: Superseder:
Assigned To: Nosy List: Gabriele Tornetta, Mark.Shannon
Priority: normal Keywords:

Created on 2021-06-14 10:09 by Gabriele Tornetta, last changed 2021-06-14 17:25 by Gabriele Tornetta. This issue is now closed.

Messages (3)
msg395787 - (view) Author: Gabriele N Tornetta (Gabriele Tornetta) * Date: 2021-06-14 10:09
I was looking at how the new co_linetable works in order to add initial support for Python 3.10 to Austin (https://github.com/P403n1x87/austin) when I stumbled upon the following interesting output from the dis module. I am using the following test target:

https://github.com/P403n1x87/austin/blob/master/test/target34.py

When I call python3.10 -m dis target34.py using Python 3.10.0b2 I get

----

 25           0 LOAD_CONST               0 (0)
              2 LOAD_CONST               1 (None)
              4 IMPORT_NAME              0 (threading)
              6 STORE_NAME               0 (threading)

 28           8 LOAD_CONST               2 (<code object keep_cpu_busy at 0x7fb7cd750870, file "target34.py", line 28>)
             10 LOAD_CONST               3 ('keep_cpu_busy')
             12 MAKE_FUNCTION            0
             14 STORE_NAME               1 (keep_cpu_busy)

 36          16 LOAD_NAME                2 (__name__)
             18 LOAD_CONST               4 ('__main__')
             20 COMPARE_OP               2 (==)
             22 POP_JUMP_IF_FALSE       25 (to 50)

 37          24 LOAD_NAME                0 (threading)
             26 LOAD_ATTR                3 (Thread)
             28 LOAD_NAME                1 (keep_cpu_busy)
             30 LOAD_CONST               5 (('target',))
             32 CALL_FUNCTION_KW         1
             34 LOAD_METHOD              4 (start)
             36 CALL_METHOD              0
             38 POP_TOP

 38          40 LOAD_NAME                1 (keep_cpu_busy)
             42 CALL_FUNCTION            0
             44 POP_TOP
             46 LOAD_CONST               1 (None)
             48 RETURN_VALUE

 36     >>   50 LOAD_CONST               1 (None)
             52 RETURN_VALUE

Disassembly of <code object keep_cpu_busy at 0x7fb7cd750870, file "target34.py", line 28>:
 29           0 BUILD_LIST               0
              2 STORE_FAST               0 (a)

 30           4 LOAD_GLOBAL              0 (range)
              6 LOAD_CONST               1 (2000000)
              8 CALL_FUNCTION            1
             10 GET_ITER
        >>   12 FOR_ITER                21 (to 56)
             14 STORE_FAST               1 (i)

 31          16 LOAD_FAST                0 (a)
             18 LOAD_METHOD              1 (append)
             20 LOAD_FAST                1 (i)
             22 CALL_METHOD              1
             24 POP_TOP

 32          26 LOAD_FAST                1 (i)
             28 LOAD_CONST               2 (1000000)
             30 BINARY_MODULO
             32 LOAD_CONST               3 (0)
             34 COMPARE_OP               2 (==)
             36 POP_JUMP_IF_FALSE       27 (to 54)

 33          38 LOAD_GLOBAL              2 (print)
             40 LOAD_CONST               4 ('Unwanted output ')
             42 LOAD_GLOBAL              3 (str)
             44 LOAD_FAST                1 (i)
             46 CALL_FUNCTION            1
             48 BINARY_ADD
             50 CALL_FUNCTION            1
             52 POP_TOP
        >>   54 JUMP_ABSOLUTE            6 (to 12)

 30     >>   56 LOAD_CONST               0 (None)
             58 RETURN_VALUE

----

Note how the line number is not monotonic. Compare this to the output generated by Python 3.9.5

----
 25           0 LOAD_CONST               0 (0)
              2 LOAD_CONST               1 (None)
              4 IMPORT_NAME              0 (threading)
              6 STORE_NAME               0 (threading)

 28           8 LOAD_CONST               2 (<code object keep_cpu_busy at 0x7fa9c539cb30, file "target34.py", line 28>)
             10 LOAD_CONST               3 ('keep_cpu_busy')
             12 MAKE_FUNCTION            0
             14 STORE_NAME               1 (keep_cpu_busy)

 36          16 LOAD_NAME                2 (__name__)
             18 LOAD_CONST               4 ('__main__')
             20 COMPARE_OP               2 (==)
             22 POP_JUMP_IF_FALSE       46

 37          24 LOAD_NAME                0 (threading)
             26 LOAD_ATTR                3 (Thread)
             28 LOAD_NAME                1 (keep_cpu_busy)
             30 LOAD_CONST               5 (('target',))
             32 CALL_FUNCTION_KW         1
             34 LOAD_METHOD              4 (start)
             36 CALL_METHOD              0
             38 POP_TOP

 38          40 LOAD_NAME                1 (keep_cpu_busy)
             42 CALL_FUNCTION            0
             44 POP_TOP
        >>   46 LOAD_CONST               1 (None)
             48 RETURN_VALUE

Disassembly of <code object keep_cpu_busy at 0x7fa9c539cb30, file "target34.py", line 28>:
 29           0 BUILD_LIST               0
              2 STORE_FAST               0 (a)

 30           4 LOAD_GLOBAL              0 (range)
              6 LOAD_CONST               1 (2000000)
              8 CALL_FUNCTION            1
             10 GET_ITER
        >>   12 FOR_ITER                42 (to 56)
             14 STORE_FAST               1 (i)

 31          16 LOAD_FAST                0 (a)
             18 LOAD_METHOD              1 (append)
             20 LOAD_FAST                1 (i)
             22 CALL_METHOD              1
             24 POP_TOP

 32          26 LOAD_FAST                1 (i)
             28 LOAD_CONST               2 (1000000)
             30 BINARY_MODULO
             32 LOAD_CONST               3 (0)
             34 COMPARE_OP               2 (==)
             36 POP_JUMP_IF_FALSE       12

 33          38 LOAD_GLOBAL              2 (print)
             40 LOAD_CONST               4 ('Unwanted output ')
             42 LOAD_GLOBAL              3 (str)
             44 LOAD_FAST                1 (i)
             46 CALL_FUNCTION            1
             48 BINARY_ADD
             50 CALL_FUNCTION            1
             52 POP_TOP
             54 JUMP_ABSOLUTE           12
        >>   56 LOAD_CONST               0 (None)
             58 RETURN_VALUE
----

This problem seems to get reflected in the output generated by Austin. With Python 3.9 I do get the expected traceback:

P1539;T1539;/mnt/c/Users/Gabriele/Projects/austin/test/target34.py:<module>:38;/mnt/c/Users/Gabriele/Projects/austin/test/target34.py:keep_cpu_busy:32 101003

(note the correct path <module>:38 => keep_cpu_busy:32)

but with Python 3.10.0b2 I do get

P2064;T2064;/mnt/c/Users/Gabriele/Projects/austin/test/target34.py:<module>:36;/mnt/c/Users/Gabriele/Projects/austin/test/target34.py:keep_cpu_busy:32 100511

which is incorrect. What seems to be off is the value of the f_lasti field. The computation that I'm performing to map bytecode to line number produces the following "[start, end) => line number" triplets (the computation stops as soon as end > lasti):

<module> (lasti = 21)
  [0, 8) => 25
  [8, 16) => 28
  [16, 24) => 36

The computations within the code object for the keep_cpu_busy function look fine:

keep_cpu_busy (lasti = 27)
  [0, 4) => 29
  [4, 16) => 30
  [16, 26) => 31
  [26, 38) => 32
msg395795 - (view) Author: Mark Shannon (Mark.Shannon) * (Python committer) Date: 2021-06-14 13:19
What does "seem wrong" mean?
What exactly is the problem?
msg395818 - (view) Author: Gabriele N Tornetta (Gabriele Tornetta) * Date: 2021-06-14 17:25
I think I managed to find the source of the confusion. This seems to be due to https://github.com/python/cpython/commit/fcb55c0037baab6f98f91ee38ce84b6f874f034a, with the f_lasti from the C struct now being half of the value returned by the f_lasti attribute of the frame object (is this documented somewhere?).
History
Date User Action Args
2021-06-14 17:25:40Gabriele Tornettasetstatus: open -> closed

messages: + msg395818
stage: resolved
2021-06-14 13:19:13Mark.Shannonsetmessages: + msg395795
2021-06-14 12:23:05Gabriele Tornettasettitle: bytecode<>line number mapping seems wrong in 3.10.0b2 -> bytecode<>line number mapping and f_lasti seem wrong in 3.10.0b2
2021-06-14 11:52:07xtreaksetnosy: + Mark.Shannon
2021-06-14 10:09:16Gabriele Tornettacreate