问题背景介绍
这个问题是cpython项目门禁中发现的一个问题，具体的表现就是子编译器相关的两个用例（test_still_running, test_already_running，用例代码详情）会高概率出现失败，尤其是并行测试数量多于300时，基本在10小时内就能再次捕捉到相关错误。问题单详情
此问题可以用./python -m test test__xxsubinterpreters -v -F -j300来执行并捕捉相关错误。
错误输出日志为：
test_already_running (test.test__xxsubinterpreters.RunStringTests) ... FAIL
======================================================================
FAIL: test_already_running (test.test__xxsubinterpreters.RunStringTests)
----------------------------------------------------------------------
Traceback (most recent call last):
File "/home/shihai/cpython/Lib/test/test__xxsubinterpreters.py", line 834, in test_already_running
with self.assertRaises(RuntimeError):
AssertionError: RuntimeError not raised
----------------------------------------------------------------------
Ran 123 tests in 71.761s
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 48, in run
interpreters.run_string(interp, dedent(f"""
RuntimeError: unrecognized interpreter ID 60
test test__xxsubinterpreters failed
定位过程梳理
1.线程未及时获取GIL锁导致 上面的错误日志中可以看到的是interpreter ID 60未找到，当时的第一反应是thread线程没有获取到GIL，导致C层面的线程在测试用例完成测试并清理完interpreter ID 60导致的。
为什么我会提出这个可能性呢？因为./python -m test test__xxsubinterpreters -v -F -j300的300并发量是通过启用线程来实现的。基于这点的考虑我想如果能在thread过程能引入一个锁来确保thread是及时获取GIL并运行的。因此我提了PR-26598想解决这个问题。我用这个PR来运行原有的失败测试时有13小时没有复现此问题，就暗自庆幸解决了这个问题。但是这个PR一提出来就被Pablo Galindo Salgado质疑此PR的有效性。
因此我继续回到本地环境重新执行测试用例监控，结果在19小时的时候继续捕捉到了此问题。所以PR-26598没有彻底解决此问题，但是延长了偶现出现的时间间隔。这个PR也从侧面否定了这个推测是错误的。
为什么这个推测是错误的？因为j300虽然开始是启动了300个线程来触发并发量，但实际thread线程运行过程中是用subprocess来执行测试用例(单元测试的核心触发逻辑请点击这里)，如果测试用例都用进程来隔离了，那GIL就不会彼此相互影响了。
2.python代码在ceval过程执行字节码过程中跳过因为某种资源竞争跳过了字节码的执行(用./python -m dis ./Lib/test/test__xxsubinterpreters.py来分析自编译器相关代码对应的字节码序列)。
Disassembly of <code object test_already_running at 0x7faf152bc190, file "./Lib/test/test__xxsubinterpreters.py", line 838>:
839 0 LOAD_GLOBAL 0 (_running)
2 LOAD_FAST 0 (self)
4 LOAD_ATTR 1 (id)
6 CALL_FUNCTION 1
8 SETUP_WITH 72 (to 82)
10 POP_TOP
840 12 LOAD_FAST 0 (self)
14 LOAD_METHOD 2 (assertRaises)
16 LOAD_GLOBAL 3 (RuntimeError)
18 CALL_METHOD 1
20 SETUP_WITH 30 (to 52)
22 POP_TOP
841 24 LOAD_GLOBAL 4 (interpreters)
26 LOAD_METHOD 5 (run_string)
28 LOAD_FAST 0 (self)
30 LOAD_ATTR 1 (id)
32 LOAD_CONST 1 ('print("spam")')
34 CALL_METHOD 2
36 POP_TOP
38 POP_BLOCK
40 LOAD_CONST 0 (None)
42 DUP_TOP
44 DUP_TOP
46 CALL_FUNCTION 3
48 POP_TOP
50 JUMP_FORWARD 16 (to 68)
>> 52 WITH_EXCEPT_START
54 POP_JUMP_IF_TRUE 58
56 RERAISE
>> 58 POP_TOP
60 POP_TOP
62 POP_TOP
64 POP_EXCEPT
66 POP_TOP
>> 68 POP_BLOCK
70 LOAD_CONST 0 (None)
72 DUP_TOP
74 DUP_TOP
76 CALL_FUNCTION 3
78 POP_TOP
80 JUMP_FORWARD 16 (to 98)
>> 82 WITH_EXCEPT_START
84 POP_JUMP_IF_TRUE 88
86 RERAISE
>> 88 POP_TOP
90 POP_TOP
92 POP_TOP
94 POP_EXCEPT
96 POP_TOP
>> 98 LOAD_CONST 0 (None)
100 RETURN_VALUE
我反复看了ceval逻辑过程，可以确认里面就是串行执行了字节码，没有任何资源的申请和竞争可能性存在。因此此推断可以被否决。
3.线程/进程执行过程中没有及时分配到足够的时间片（这个是事后调试折腾出来的解决，开始压根没想到这个点！） 当推测1和推测2持续在两周内都被否定后，这个问题陷入了僵局，没有任何新的思路，也想过放弃这个问题，换一个简单的题目练练脑子，但转念一想都用简单题练脑子，技能怎么能提高呢，咬咬牙还是得继续。
实在没思路那怎么往前走？实在没有好思路，那用笨办法，在可能或者疑似有风险的地方输出相关日志，靠后期日志分析再找找感觉。我就在子编译器相关的操作前后打印了此时的线程状态以及操作日志。patch详情请点击
通过这个patch，我获得了非常关键的日志输出，这个日志有两部分：i. 上半部分是成功的用例执行日志; ii. 下半部分是失败的用例执行日志。
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
从这段日志比对可以发现，失败的测试用例比正常用例少了一个执行操作，这个操作就是在_running()函数中的thread.start()晚执行了。那thread除了因为GIL可能导致thread晚执行，还有可能什么原因导致thread会推迟执行？问题又回到了推测一了吗？
因此我继续在打印subinterpreter操作日志的patch中加入了PR-26598。然后还是继续发现有失败用例出现。但通过这个patch我们其实在缩小可疑的代码范围。在这个patch中，我们可以看到thread.Event()是一个阻塞操作，如果thread.Event().set()未执行,那整个_running()就会一直阻塞等待Event.set()执行完继续。所以可能的原因只有一个，那就是interpreters.run_string()执行慢了。但当我详细走读这个函数时也没有发现可以怀疑的风险点。
至此，我想可能的一个原因就是用例执行过程中的线程在执行过程没有获得足够多的cpu时间片导致interpreters.run_string()未执行。然后我立马提了一个确保子编译是已经运行的判断的逻辑来确保自编译已经获得了cpu时间片，PR-27240在本地执行29小时没有出问题，也顺利被python项目经理Łukasz Langa合入了。他没给任何检视意见，一把就合入了。我到现在内心其实还是很慌的，因为这个问题我是用排除法来解决的。万一还有我没考虑到的场景呢？所以暂且假设自己的推测是成立的，以后如果继续发生我再继续更新，哈哈。
再在心里默念一遍计算机进程的基础概念：进程是操作系统资源调度的基本单位，线程是任务的调度执行的基本单位；线程被称为轻量级进程，每个进程至少有一个线程。
