Regression caused by CALL_FUNCTION specialization for C function calls (test_urllib fails when run multiple times)

[vstinner]

BPO	46465
Nosy	@gvanrossum, @vstinner, @markshannon, @ericsnowcurrently, @corona10, @brandtbucher, @sobolevn, @Fidget-Spinner
PRs	bpo-46465: Check eval breaker in specialized CALL opcodes #30826 bpo-46709: check eval breaker in specialized CALL opcodes #31404
Files	bug.py

^{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 = None
closed_at = None
created_at = <Date 2022-01-22.01:30:09.079>
labels = ['release-blocker', 'tests', '3.11']
title = 'Regression caused by CALL_FUNCTION specialization for C function calls (test_urllib fails when run multiple times)'
updated_at = <Date 2022-02-18.11:00:24.942>
user = 'https://github.com/vstinner'

bugs.python.org fields:

activity = <Date 2022-02-18.11:00:24.942>
actor = 'sobolevn'
assignee = 'none'
closed = False
closed_date = None
closer = None
components = ['Tests']
creation = <Date 2022-01-22.01:30:09.079>
creator = 'vstinner'
dependencies = []
files = ['50575']
hgrepos = []
issue_num = 46465
keywords = ['patch', '3.11regression']
message_count = 14.0
messages = ['411217', '411219', '411220', '411288', '411348', '411349', '411364', '411366', '411367', '411369', '411370', '411371', '411461', '411652']
nosy_count = 8.0
nosy_names = ['gvanrossum', 'vstinner', 'Mark.Shannon', 'eric.snow', 'corona10', 'brandtbucher', 'sobolevn', 'kj']
pr_nums = ['30826', '31404']
priority = 'release blocker'
resolution = None
stage = 'patch review'
status = 'pending'
superseder = None
type = None
url = 'https://bugs.python.org/issue46465'
versions = ['Python 3.11']

[vstinner]

test_unittest: TestBreakSignalDefault.testInstallHandler() fails if run after TestBreak:
---------

$ ./python -m test -v test_unittest -R 3:3 -m '*TestBreak.testHandlerReplacedButCalled' -m '*TestBreak.testInstallHandler' -m '*TestBreakSignalDefault.testInstallHandler'
(...)
beginning 6 repetitions
123456
testHandlerReplacedButCalled (unittest.test.test_break.TestBreak) ... ok
testInstallHandler (unittest.test.test_break.TestBreak) ... ok
testInstallHandler (unittest.test.test_break.TestBreakSignalDefault) ... ok

---

Ran 3 tests in 0.003s

OK
(...)
.testHandlerReplacedButCalled (unittest.test.test_break.TestBreak) ... ok
testInstallHandler (unittest.test.test_break.TestBreak) ... ok
testInstallHandler (unittest.test.test_break.TestBreakSignalDefault) ... FAIL

======================================================================
FAIL: testInstallHandler (unittest.test.test_break.TestBreakSignalDefault)
----------------------------------------------------------------------

Traceback (most recent call last):
  File "/home/vstinner/python/main/Lib/unittest/test/test_break.py", line 38, in testInstallHandler
    self.assertTrue(unittest.signals._interrupt_handler.called)
    ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
AssertionError: False is not true
(...)

---

Or you can use a "bisect" file:
---
unittest.test.test_break.TestBreak.testHandlerReplacedButCalled
unittest.test.test_break.TestBreak.testInstallHandler
unittest.test.test_break.TestBreakSignalDefault.testInstallHandler
---

And the command:

./python -m test -v -F test_unittest --matchfile=bisect

Or the command:

./python -m test -v test_unittest -R 3:3 --matchfile=bisect

It fails starting at the 4th iteration.

[vstinner]

It's a regression introduced by the following change:

commit 3163e68
Author: Ken Jin <28750310+Fidget-Spinner@users.noreply.github.com>
Date: Wed Oct 20 07:16:36 2021 +0800

bpo-44525: Specialize ``CALL_FUNCTION`` for C function calls (GH-26934)

[vstinner]

Attached bug.py reproduces the bug without unittest, just run:

./python bug.py

On Python 3.10, it writes:
---
LOOP 0
LOOP 1
(...)
LOOP 14
LOOP 15
---

On the main branch, it fails with:
---

LOOP 0
LOOP 1
LOOP 2
LOOP 3
LOOP 4
LOOP 5
LOOP 6
LOOP 7
Traceback (most recent call last):
  File "/home/vstinner/bug.py", line 24, in <module>
    Bug().run()
    ^^^^^^^^^^^
  File "/home/vstinner/bug.py", line 19, in run
    raise Exception("bug")
    ^^^^^^^^^^^^^^^^^^^^^^
Exception: bug

---

[gvanrossum]

@kj, are you looking into this?

[vstinner]

The problem is that the optimization no longer checks for pending signals in TARGET(CALL_NO_KW_BUILTIN_FAST). The patch below fix my issue. I guess that other opcode needs an additional CHECK_EVAL_BREAKER().

diff --git a/Python/ceval.c b/Python/ceval.c
index 9aaddd99eda..7cc0f805366 100644
--- a/Python/ceval.c
+++ b/Python/ceval.c
@@ -4822,6 +4822,7 @@ _PyEval_EvalFrameDefault(PyThreadState *tstate, InterpreterFrame *frame, int thr
                 */
                 goto error;
             }
+            CHECK_EVAL_BREAKER();
             DISPATCH();
         }

[vstinner]

It seems like the following target miss CHECK_EVAL_BREAKER():

TARGET(CALL_NO_KW_METHOD_DESCRIPTOR_FAST) 
TARGET(CALL_NO_KW_METHOD_DESCRIPTOR_O)
TARGET(CALL_NO_KW_BUILTIN_FAST)
TARGET(CALL_NO_KW_BUILTIN_O)
TARGET(CALL_NO_KW_BUILTIN_CLASS_1)

CHECK_EVAL_BREAKER() matters for signals, but also multithreading (drop the GIL), asynchronous exception and pending calls.

[Fidget-Spinner]

Thanks @victor for catching this and figuring it out. I had a hard time narrowing this down since I'm on Windows which doesn't support signals :(.

I'll handle the required patch and tests.