一個Reentrant Error引發(fā)的對Python信號機制的探索和思考
寫在前面
前幾天工作時遇到了一個匪夷所思的問題。經(jīng)過幾次嘗試后問題得以解決，但問題產(chǎn)生的原因卻仍令人費解。查找 SO 無果，我決定翻看 Python 的源碼。斷斷續(xù)續(xù)地研究了幾天，終于恍然大悟。撰此文以記。
本文環(huán)境：
- Ubuntu 16.04 (64 bit)
- Python 3.6.2
使用的 C 源碼可以從 Python 官網(wǎng) 獲取。
起因
工作時用到了 celery 作為異步任務(wù)隊列，為方便調(diào)試，我寫了一個腳本用以啟動/關(guān)閉 celery 主進(jìn)程。代碼簡化后如下：
- import sys
- import subprocess
- # ...
- celery_process = subprocess.Popen(
- ['celery', '-A', 'XXX', 'worker'],
- stdout=subprocess.PIPE,
- stderr=sys.stderr
- )
- try:
- # Start and wait for server process
- except KeyboardInterrupt:
- # Ctrl + C pressed
- celery_process.terminate()
- celery_process.wait()
代碼啟動了 celery worker，并嘗試在捕獲到 KeyboardInterrupt 異常時將其熱關(guān)閉。
初看上去沒什么問題。然而實際測試時卻發(fā)生了十分詭異的事情：按下 Ctrl+C 后，程序 偶爾 會拋出這樣的異常：RuntimeError: reentrant call inside <_io.BufferedWriter name='<stdout>’>。詭異之處有兩點：
異常發(fā)生的時機有隨機性
異常的 traceback 指向 celery 包，也就是說這是在 celery 主進(jìn)程內(nèi)部發(fā)生的異常
這個結(jié)果大大出乎了我的意料。隨機性異常是眾多最難纏的問題之一，因為這常常意味著并發(fā)問題，涉及底層知識，病灶隱蔽，調(diào)試難度大，同時沒有有效的手段判斷問題是否徹底解決(可能只是降低了頻率)。
解決
異常信息中有兩個詞很關(guān)鍵：reentrant 和 stdout。reentrant call 說明有一個不可重入的函數(shù)被遞歸調(diào)用了;stdout 則指明了發(fā)生的地點和時機。初步可以判定：由于某種原因，有兩股控制流在同時操控 stdout。
“可重入”是什么?根據(jù) Wikipedia 的定義：如果一個子程序能在執(zhí)行時被中斷并在之后被正確地、安全地喚起，它就被稱為可重入的。依賴于全局?jǐn)?shù)據(jù)的過程是不可重入的，如 printf(依賴于全局文件描述符)、malloc(依賴與和堆相關(guān)的一系列數(shù)據(jù)結(jié)構(gòu))等函數(shù)。需要注意的是，可重入性(reentrant)與 線程安全性(thread-safe)并不等價，甚至不存在包含關(guān)系，Wikipedia 中給出了相關(guān)的反例。
多次嘗試后，出現(xiàn)了一條線索：有時候 worker: Warm shutdown (MainProcess) 這個字符串會被二次打印，時機不確定。這句話是 celery 將要熱關(guān)閉時的提示語，二次出現(xiàn)只可能是主進(jìn)程收到了第二個信號。閱讀 celery 的文檔 可知，SIGINT 和 SIGTERM 信號可以引發(fā)熱關(guān)閉?；仡^瀏覽我的代碼，其中只有一處發(fā)送了 SIGTERM 信號(celery_process.terminate())，至于另一個神秘的信號，我懷疑是 SIGINT。
SO 一下，結(jié)果印證了我的猜想：
If you are generating the SIGINT with Ctrl-C on a Unix system, then the signal is being sent to the entire process group.
— via StackOverflow
SIGINT 信號不僅會發(fā)送到父進(jìn)程，而是會發(fā)到整個進(jìn)程組，默認(rèn)情況下包括了所有子進(jìn)程。也就是說——在攔截了 KeyboardInterrupt 之后執(zhí)行的 celery_process.terminate() 是多此一舉，因為 SIGINT 信號也會被發(fā)送至 celery 主進(jìn)程，同樣會引起熱關(guān)閉。代碼稍作修改即可正常運行：
- # ...
- try:
- # Start and wait for server process
- except KeyboardInterrupt:
- # Ctrl + C pressed
- pass
- else:
- # Signal SIGTERM if no exception raised
- celery_process.terminate()
- finally:
- # Wait for it to avoid it becoming orphan
- celery_process.wait()
猜測
UNIX 信號處理是一個相當(dāng)奇葩的過程——當(dāng)進(jìn)程收到一個信號時，內(nèi)核會選擇一條線程(以一定的規(guī)則)，中斷其當(dāng)前控制流，將控制流強行轉(zhuǎn)給信號處理函數(shù)，待其執(zhí)行完畢后再將控制流交還給原線程。時序圖如下：
由于控制流轉(zhuǎn)換發(fā)生在同一條線程上，許多線程間同步機制會失效甚至報錯。因此信號處理函數(shù)的編寫要比線程函數(shù)更加嚴(yán)格，對同一個文件輸出是被禁止并且無解的，因為很可能會發(fā)生這樣的事情：
而且這個問題不能通過加鎖來解決(因為是在同一個線程中，會死鎖)。
因此，我猜測異常發(fā)生時的事件時序是這樣的：在 print 未執(zhí)行完時中斷，又在信號處理函數(shù)中調(diào)用 print，觸發(fā)了重入檢測，引起 RuntimeError：
疑云又起
不幸的是，我的猜想很快被推翻了。
在翻看 Python signal 模塊的官方文檔，我看到了如下敘述：
A Python signal handler does not get executed inside the low-level (C) signal handler. Instead, the low-level signal handler sets a flag which tells the virtual machine to execute the corresponding Python signal handler at a later point(for example at the next bytecode instruction).
— via Python Documentation
也就是說，Python 中使用 signal.signal 注冊的信號處理函數(shù)并不會在收到信號時立即執(zhí)行，而只是簡單做一個標(biāo)記，將其延遲至之后的某個時機。這么做可以盡量快地結(jié)束異常控制流，減少其對被阻斷進(jìn)程的影響。
這番表述可以說是推翻了我的猜想，因為 Signal Handler 中的 print 并沒有在異?？刂屏髦袌?zhí)行。那異常又是怎么產(chǎn)生的呢?
文檔說 Python Signal Handler 會被延后至某個時機進(jìn)行，但并沒有明示是什么時候。對于這個疑問，這個提問的被采納回答 則斬釘截鐵地將其具體化到了“某兩個 Python 字節(jié)碼之間”。
我們知道，Python 程序在執(zhí)行前會被編譯成 Python 內(nèi)定的字節(jié)碼
(bytecode),Python 虛擬機實際執(zhí)行的正是這些字節(jié)碼。倘若該回答是正確的，則立即有如下推論：在處理信號的過程中，字節(jié)碼具有原子性(atomic)。也就是說，主線程總是在兩個字節(jié)碼之間決定是否轉(zhuǎn)移控制流， 而 不會 出現(xiàn)以下情況：
這很顯然與我的程序結(jié)果相悖：print 與 print 所調(diào)用的 io.BufferedWriter.write 和 io.BufferedWriter.flush 都是用純 C 代碼編寫的，對其的調(diào)用只消耗一條字節(jié)碼(CALL_FUNCTION 或 CALL_FUNCTION_KW)，在信號中斷的影響下，這幾個函數(shù)仍保持原子性，在時序圖上互不重疊，更不會發(fā)生重入。
因此，除了在兩個字節(jié)碼之間，應(yīng)該還有其他時機喚起了 Python Signal Handler。
至此，問題已觸及 Python 的地板了，需向更底層挖掘才能找到答案。
深入源碼
信號注冊邏輯位于 Modules/signalmodule.c 文件中。 313 行的 signal_handler 是信號處理函數(shù)的最外層包裝，由系統(tǒng)調(diào)用 signal 或 sigaction 注冊至內(nèi)核，并在信號發(fā)生時被內(nèi)核回調(diào)，是異常控制流的入口。signal_handler 主要調(diào)用了 239 行處的 trip_signal 函數(shù)，其中有這樣一段代碼：
- Handlers[sig_num].tripped = 1;
- if (!is_tripped) {
- is_tripped = 1;
- Py_AddPendingCall(checksignals_witharg, NULL);
- }
這段代碼便是文檔中所說的邏輯：做標(biāo)記并延后 Python Signal Handler。其中 checksignals_witharg 即為被延后調(diào)用的函數(shù)，位于 192 行，核心代碼只有一句：
- static int
- checksignals_witharg(void * unused)
- {
- return PyErr_CheckSignals();
- }
- r_CheckSignals 位于 1511 行：
- int
- PyErr_CheckSignals(void)
- {
- int i;
- PyObject *f;
- if (!is_tripped)
- return 0;
- #ifdef WITH_THREAD
- if (PyThread_get_thread_ident() != main_thread)
- return 0;
- #endif
- is_tripped = 0;
- if (!(f = (PyObject *)PyEval_GetFrame()))
- f = Py_None;
- for (i = 1; i < NSIG; i++) {
- if (Handlers[i].tripped) {
- PyObject *result = NULL;
- PyObject *arglist = Py_BuildValue("(iO)", i, f);
- Handlers[i].tripped = 0;
- if (arglist) {
- result = PyEval_CallObject(Handlers[i].func, arglist);
- Py_DECREF(arglist);
- }
- if (!result)
- return -1;
- Py_DECREF(result);
- }
- }
- return 0;
- }
可見，這個函數(shù)便是異步回調(diào)的最里層，包含了執(zhí)行 Python Signal Handler 的邏輯。
至此我們可以發(fā)現(xiàn)，整個 Python 中有兩個辦法可以喚起 Python Signal Handler，一個是調(diào)用 checksignals_witharg，另一個是調(diào)用 PyErr_CheckSignals。前者只是后者的簡單封包。
checksignals_witharg 在 Python 源碼中只出現(xiàn)了一次(不包括定義，下同)，沒有被直接調(diào)用的跡象。但需要注意的是，checksignals_witharg 曾被當(dāng)做 Py_AddPendingCall 的參數(shù)，Py_AddPendingCall 所做的工作時將其加入到一個全局隊列中。與之對應(yīng)的出隊操作是 Py_MakePendingCalls，位于 Python/ceval.c 的 464 行。此函數(shù)會間接調(diào)用 checksignals_witharg，在 Python 源碼中被調(diào)用了 3 次：
- Modules/_threadmodule.c 52 行的 acquire_timed
- Modules/main.c 310 行的 run_file
- Python/ceval.c 722 行的 _PyEval_EvalFrameDefault
值得注意的是，_PyEval_EvalFrameDefault 是一個長達(dá) 2600 多行的狀態(tài)機，是解析字節(jié)碼的核心邏輯所在。此處調(diào)用出現(xiàn)于狀態(tài)機主循環(huán)開始處——這印證了上面回答中的部分說法，即 Python 會在兩個字節(jié)碼中間喚起 Python Signal Hanlder。
而 PyErr_CheckSignals 在 Python 源碼中出現(xiàn)了 80 多處，遍布 Python 的各個模塊中——這說明該回答的另一半說法是錯誤的：除了在兩個字節(jié)碼之間，Python 還可能在其他角落喚起 Python Signal Handler。其中有兩處值得注意，它們都位于 Modules/_io/bufferedio.c 中：
- 1884 行的 _bufferedwriter_flush_unlocked
- 1939 行的 _io_BufferedWriter_write_impl
這兩個函數(shù)是 io.BufferedWriter 類的底層實現(xiàn)，會被 print 間接調(diào)用。仔細(xì)觀察可以發(fā)現(xiàn)，它們都有著相似的結(jié)構(gòu)：
- ENTER_BUFFERED(self)
- // ...
- PyErr_CheckSignals();
- // ...
- LEAVE_BUFFERED(self)
ENTER_BUFFERED 是一個宏，會嘗試申請無阻塞線程鎖以保證函數(shù)不會被重入：
- #define ENTER_BUFFERED(self) \
- ( (PyThread_acquire_lock(self->lock, 0) ? \
- 1 : _enter_buffered_busy(self)) \
- && (self->owner = PyThread_get_thread_ident(), 1) )
至此，真相已經(jīng)大白了。
真相
當(dāng)信號中斷發(fā)生在 _bufferedwriter_flush_unlocked 或 _io_BufferedWriter_write_impl 中時，這兩個函數(shù)中的 PyErr_CheckSignals 會直接喚起 Python Signal Handler，而此時由 ENTER_BUFFERED 上的鎖尚未解開，若 Python Signal Handler 中又有 print 函數(shù)調(diào)用，則會導(dǎo)致再次 ENTER_BUFFERED 上鎖失敗，從而拋出異常。時序圖如下：
思考
為什么不將 Python Signal Handler 調(diào)用的地點統(tǒng)一在一個地方，而是散布在程序的各處呢?閱讀相關(guān)代碼，我認(rèn)為有兩點原因：
信號中斷會使某些系統(tǒng)調(diào)用行為異常，從而使系統(tǒng)調(diào)用的調(diào)用者不知如何處理，此時需要調(diào)用 Signal Handler 進(jìn)行可能的狀態(tài)恢復(fù)。一個例子是 write 系統(tǒng)調(diào)用，信號中斷會導(dǎo)致數(shù)據(jù)部分寫回，與此相關(guān)的一大批 I/O 函數(shù)(包括出問題的 _bufferedwriter_flush_unlocked 和 _io_BufferedWriter_write_impl)便只能相應(yīng)地調(diào)用 PyErr_CheckSignals。
某些函數(shù)需要做計算密集型任務(wù)，為了防止 Python Signal Handler 的調(diào)用被過長地延后(其實主要是為了及時響應(yīng)鍵盤中斷，防止程序無法從前臺結(jié)束)，必須適時地檢查并調(diào)用 Python Signal Handler。一個例子是 Objects/longobject.c 中的諸函數(shù)，longobject.c 定義了 Python 特有的無限長整型，其相關(guān)的運算可能耗時相當(dāng)長，必須做這樣的處理。
總結(jié)
Python Signal Handler 的調(diào)用會被延后，但時機不止在兩個字節(jié)碼之間，而是可能出現(xiàn)在任何地方。
由于第一條，Python Signal Handler 中盡量都使用 可重入的 的函數(shù)，以避免奇怪的問題?？芍厝胄钥梢詮奈臋n獲知，也可以結(jié)合定義由源碼推斷出來。
有疑問，翻源碼。人會說謊，代碼不會。
