[issue37224] [subinterpreters] test__xxsubinterpreters fails randomly

[hai shi]

hai shi <shihai1991 at 126.com> added the comment:

I use this add_printf_to_get_details_from_race_condition.patch to get some details of the running subinterpreter.

The successful output of test_already_running:
test_already_running (test.test__xxsubinterpreters.RunStringTests) ... In interp_create, the current state is: 0x23ee8f0
In interp_list_all, the current state is: 0x23ee8f0 # Entering _running().
Before interp runs, the current state is: 0x2489590 # Running the interp  in thread.
In interp_list_all, the current state is: 0x23ee8f0 # Running interpreters.list() in _running().
Before interp runs, the current state is: 0x23ee8f0 # Running the interp in test_already_running().
After interp runs, the current state is: 0x25cf0e0 # Running the interp in thread.
In interp_list_all, the current state is: 0x23ee8f0 # Clearing the created interps.

The failed output of test_already_running:
test_already_running (test.test__xxsubinterpreters.RunStringTests) ... In interp_create, the current state is: 0x23e58f0
In interp_list_all, the current state is: 0x23e58f0
In interp_list_all, the current state is: 0x23e58f0 # Compared to the successful output of test_already_running, the interp doesn't run in time. 
Before interp runs, the current state is: 0x23e58f0
spam
After interp runs, the current state is: 0x24fdfc0
In interp_list_all, the current state is: 0x23e58f0
FAIL

======================================================================
FAIL: test_already_running (test.test__xxsubinterpreters.RunStringTests)
----------------------------------------------------------------------
Traceback (most recent call last):
  File "/home/shihai/cpython/Lib/test/test__xxsubinterpreters.py", line 835, in test_already_running
    with self.assertRaises(RuntimeError):
AssertionError: RuntimeError not raised

----------------------------------------------------------------------

Ran 123 tests in 71.968s

FAILED (failures=1, skipped=6)
Warning -- Uncaught thread exception: RuntimeError
Exception in thread Thread-8 (run):
Traceback (most recent call last):
  File "/home/shihai/cpython/Lib/threading.py", line 1009, in _bootstrap_inner
    self.run()
    ^^^^^^^^^^
  File "/home/shihai/cpython/Lib/threading.py", line 946, in run
    self._target(*self._args, **self._kwargs)
    ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/home/shihai/cpython/Lib/test/test__xxsubinterpreters.py", line 49, in run
    interpreters.run_string(interp, dedent(f"""
RuntimeError: unrecognized interpreter ID 60
test test__xxsubinterpreters failed.


According to above details, there are several possible explanations:
1.Some race condition break the opcode execution order.
  I checked the eval function. I didn't find that any condition will disrupt the execution order.
2.The running thread hasn't get the GIL in time.
  "RuntimeError: unrecognized interpreter ID 60" proves that the interp has been executed in _running(), but later than the test_already_running. So I creates PR 26598. But I catch the error again with PR 26598.
3.the running thread can't get the time slice of CPU.
  By running python with add_printf_to_get_details_from_race_condition.patch, I find that the thread created in _running() has be executed, but the interp hasn't been executed immediately in run(). At the same time, the done.set() has been executed in run(), so I guess the real reason is the thread created in _running() hasn't get the time slice of CPU to run interp in run() in multiprocess.

Pls correct me if I am wrong.

----------
Added file: https://bugs.python.org/file50160/add_printf_to_get_details_from_race_condition.patch

_______________________________________
Python tracker <report at bugs.python.org>
<https://bugs.python.org/issue37224>
_______________________________________