Test failures when running with Tier 2 enabled

[mdboom]

Bug report

Bug description:

Over the last two weeks, some test failures were introduced when the Tier 2 compiler is turned on, such that building with --pgo and Tier 2 fails.

I am going to bisect to see if I can find the moment at which the failures were introduced and will report back.

Full build log

./python -m test --pgo --timeout=
Using random seed: 3445139140
0:00:00 load avg: 1.94 Run 44 tests sequentially
0:00:00 load avg: 1.94 [ 1/44] test_array
0:00:01 load avg: 1.94 [ 2/44] test_base64
0:00:02 load avg: 1.94 [ 3/44] test_binascii
0:00:02 load avg: 1.94 [ 4/44] test_binop
0:00:02 load avg: 1.94 [ 5/44] test_bisect
0:00:02 load avg: 1.94 [ 6/44] test_bytes
0:00:12 load avg: 1.79 [ 7/44] test_bz2
0:00:13 load avg: 1.73 [ 8/44] test_cmath
0:00:14 load avg: 1.73 [ 9/44] test_codecs
0:00:16 load avg: 1.73 [10/44] test_collections
0:00:19 load avg: 1.67 [11/44] test_complex
0:00:19 load avg: 1.67 [12/44] test_dataclasses
0:00:20 load avg: 1.67 [13/44] test_datetime -- test_dataclasses failed (uncaught exception)
0:00:26 load avg: 1.62 [14/44] test_decimal
test test_decimal failed
0:00:35 load avg: 1.52 [15/44] test_difflib -- test_decimal failed (2 errors)
0:00:38 load avg: 1.48 [16/44] test_embed
0:00:51 load avg: 1.41 [17/44] test_float
0:00:52 load avg: 1.41 [18/44] test_fstring
0:00:53 load avg: 1.37 [19/44] test_functools
test test_functools failed
0:00:55 load avg: 1.37 [20/44] test_generators -- test_functools failed (4 errors)
0:00:55 load avg: 1.37 [21/44] test_hashlib
0:00:56 load avg: 1.37 [22/44] test_heapq
0:00:57 load avg: 1.37 [23/44] test_int
0:00:58 load avg: 1.34 [24/44] test_itertools
0:01:08 load avg: 1.29 [25/44] test_json
0:01:15 load avg: 1.19 [26/44] test_long
0:01:21 load avg: 1.17 [27/44] test_lzma
0:01:22 load avg: 1.17 [28/44] test_math
0:01:29 load avg: 1.14 [29/44] test_memoryview
test test_memoryview failed
0:01:29 load avg: 1.14 [30/44] test_operator -- test_memoryview failed (4 errors)
0:01:29 load avg: 1.14 [31/44] test_ordered_dict
0:01:31 load avg: 1.14 [32/44] test_patma
0:01:31 load avg: 1.14 [33/44] test_pickle -- test_patma failed (uncaught exception)
0:01:43 load avg: 1.11 [34/44] test_pprint
0:01:43 load avg: 1.11 [35/44] test_re -- test_pprint failed (uncaught exception)
0:01:45 load avg: 1.11 [36/44] test_set
0:01:57 load avg: 1.09 [37/44] test_sqlite3
0:01:58 load avg: 1.09 [38/44] test_statistics
0:02:03 load avg: 1.08 [39/44] test_str
0:02:08 load avg: 1.07 [40/44] test_struct
0:02:10 load avg: 1.07 [41/44] test_tabnanny
0:02:10 load avg: 1.07 [42/44] test_time
0:02:13 load avg: 1.07 [43/44] test_xml_etree
0:02:13 load avg: 1.07 [44/44] test_xml_etree_c

Total duration: 2 min 15 sec
Total tests: run=8,409 skipped=199
Total test files: run=44/44 failed=6
make: *** [Makefile:842: profile-run-stamp] Error 2
Result: FAILURE

CPython versions tested on:

CPython main branch

Operating systems tested on:

Linux

Linked PRs

• GH-113657: Add back missing _SET_IP uops in tier two #113662

[mdboom]

e96f260 is the first bad commit. Cc: @markshannon

[brandtbucher]

This is blocking JIT stuff too: #113465 (comment)

I’ll see if I can figure out what’s causing it today.

[brandtbucher]

It appears that exceptions aren't being caught by some try or with blocks in tier two. Still not sure why... probably because the instruction pointer is wrong?

[brandtbucher]

Minimal reproducer (needs tier two enabled):

>>> for _ in range(18):
...     try:
...         0 / 0
...     except:
...         pass
... 
Traceback (most recent call last):
  File "<stdin>", line 1, in <module>
    for _ in range(18):
        ^
ZeroDivisionError: division by zero

Note that the line shown in the traceback is wrong, supporting the idea that the instruction pointer is off (which is why the exception isn't getting caught).

[brandtbucher]

Here is the __lltrace__ log (set __lltrace__ = None before running):

   0: uop _SET_IP, oparg 9, operand 0, target 9, stack_level 1
   1: uop _ITER_CHECK_RANGE, oparg 10, operand 0, target 9, stack_level 1
   2: uop _GUARD_NOT_EXHAUSTED_RANGE, oparg 10, operand 0, target 9, stack_level 1
   3: uop _ITER_NEXT_RANGE, oparg 10, operand 0, target 9, stack_level 1
   4: uop _SET_IP, oparg 11, operand 0, target 11, stack_level 2
   5: uop _CHECK_VALIDITY, oparg 0, operand 0, target 11, stack_level 2
   6: uop _STORE_NAME, oparg 1, operand 0, target 11, stack_level 2
   7: uop _CHECK_VALIDITY, oparg 0, operand 0, target 12, stack_level 1
   8: uop _LOAD_CONST, oparg 1, operand 0, target 13, stack_level 1
   9: uop _LOAD_CONST, oparg 1, operand 0, target 14, stack_level 2
  10: uop _BINARY_OP, oparg 11, operand 0, target 15, stack_level 3
Error: [UOp 372 (_BINARY_OP), oparg 11, operand 0, target 15 @ 10 -> STORE_NAME]

It looks like we're missing a _SET_IP before _BINARY_OP, so either the flags are wrong or the optimizer is broken.

[brandtbucher]

Found it. This fixes things:

diff --git a/Python/optimizer_analysis.c b/Python/optimizer_analysis.c
index 8b471d70a1..52d0217a7a 100644
--- a/Python/optimizer_analysis.c
+++ b/Python/optimizer_analysis.c
@@ -4,6 +4,7 @@
 #include "pycore_opcode_metadata.h"
 #include "pycore_opcode_utils.h"
 #include "pycore_pystate.h"       // _PyInterpreterState_GET()
+#include "pycore_uop_metadata.h"
 #include "pycore_uops.h"
 #include "pycore_long.h"
 #include "cpython/optimizer.h"
@@ -35,13 +36,13 @@ remove_unneeded_uops(_PyUOpInstruction *buffer, int buffer_size)
             break;
         }
         else {
-            if (OPCODE_HAS_ESCAPES(opcode)) {
+            if (_PyUop_Flags[opcode] & HAS_ESCAPES_FLAG) {
                 maybe_invalid = true;
                 if (last_set_ip >= 0) {
                     buffer[last_set_ip].opcode = _SET_IP;
                 }
             }
-            if (OPCODE_HAS_ERROR(opcode) || opcode == _PUSH_FRAME) {
+            if (_PyUop_Flags[opcode] & HAS_ERROR_FLAG || opcode == _PUSH_FRAME) {
                 if (last_set_ip >= 0) {
                     buffer[last_set_ip].opcode = _SET_IP;
                 }

I'll open a PR soon.