[[399719]]

本文轉載自微信公眾號「crossoverJie」，作者crossoverJie。轉載本文請聯系crossoverJie公眾號。

前言

最近用 Python 寫了幾個簡單的腳本來處理一些數據，因為只是簡單功能所以我就直接使用 print 來打印日志。

任務運行時偶爾會出現一些異常：

因為我在不同地方都有打印日志，導致每次報錯的地方都不太一樣，從而導致程序運行結果非常詭異;有時候是這段代碼沒有運行，下一次就可能是另外一段代碼沒有觸發。

雖說當時有注意到 Broken pipe 這個關鍵異常，但沒有特別在意，因為代碼中也有一些發送 http 請求的地方，一直以為是網絡 IO 出現了問題，壓根沒往 print 這個最基本的打印函數上思考??。

直到這個問題反復出現我才認真看了這個異常，定睛一看 print 不也是 IO 操作嘛，難道真的是自帶的 print 函數都出問題了?

但在本地、測試環境我運行無數次也沒能發現異常;于是我找運維拿到了線上的運行方式。

原來為了方便維護大家提交上來的腳本任務，運維自己有維護一個統一的腳本，在這個腳本中使用：

cmd = 'python /xxx/test.py' 
os.popen(cmd) 

來觸發任務，這也是與我在本地、開發環境的唯一區別。

popen 原理

為此我在開發環境模擬出了異常：

test.py:

import time 
if __name__ == '__main__': 
    time.sleep(20) 
    print '1000'*1024 

task.py:

import os 
import time 
if __name__ == '__main__': 
    start = int(time.time()) 
    cmd = 'python test.py' 
    os.popen(cmd) 
    end = int(time.time()) 
    print 'end****{}s'.format(end-start) 

運行:

python task.py 

等待 20s 必然會復現這個異常：

Traceback (most recent call last): 
  File "test.py", line 4, in <module> 
    print '1000'*1024 
IOError: [Errno 32] Broken pipe 

為什么會出現這個異常呢?

首先得了解 os.popen(command[, mode[, bufsize]]) 這個函數的運行原理。

根據官方文檔的解釋，該函數會執行 fork 一個子進程執行 command 這個命令，同時將子進程的標準輸出通過管道連接到父進程;

也就該方法返回的文件描述符。

這里畫個圖能更好地理解其中的原理：

在這里的使用場景中并沒有獲取 popen() 的返回值，所以 command 的執行本質上是異步的;

也就是說當 task.py 執行完畢后會自動關閉讀取端的管道。

如圖所示，關閉之后子進程會向 pipe 中輸出 print '1000'*1024，由于這里輸出的內容較多會一下子填滿管道的緩沖區;

于是寫入端會收到 SIGPIPE 信號，從而導致 Broken pipe 的異常。

從維基百科中我們也可以看出這個異常產生的一些條件：

其中也提到了 SIGPIPE 信號。

解決辦法

既然知道了問題原因，那解決起來就比較簡單了，主要有以下幾個方案：

使用 read() 函數讀取管道中的數據，全部讀取之后再關閉。

如果不需要子進程中的輸出時，也可以將 command 的標準輸出重定向到 /dev/null。

也可以使用 Python3 的 subprocess.Popen 模塊來運行。

這里使用第一種方案進行演示：

 

import os 
import time 
if __name__ == '__main__': 
    start = int(time.time()) 
    cmd = 'python test.py' 
    with os.popen(cmd) as p: 
        print p.read() 
    end = int(time.time()) 
    print 'end****{}s'.format(end-start) 

運行 task.py 之后不會再拋異常，同時也將 command 的輸出打印出來。

線上修復時我沒有采用這個方案，為了方便查看日志，還是使用標準的日志框架將日志輸出到了 es 中，方便統一在 kibana 中進行查看。

由于日志框架并沒有使用到管道，所以自然也不會有這個問題。

更多內容

問題雖然是解決了，其中還是涉及到了一些咱們平時不太注意的知識點，這次我們就來一起回顧一下。

首先是父子進程的內容，這個在 c/c++/python 中比較常見，在 Java/golang 中直接使用多線程、協程會更多一些。

比如這次提到的 Python 中的 os.popen() 就是創建了一個子進程，既然是子進程那肯定是需要和父進程進行通信才能達到協同工作的目的。

很容易想到，父子進程之間可以通過上文提到的管道(匿名管道)來進行通信。

還是以剛才的 Python 程序為例，當運行 task.py 后會生成兩個進程：

分別進入這兩個程序的/proc/pid/fd 目錄可以看到這兩個進程所打開的文件描述符。

父進程：

子進程：

可以看到子進程的標準輸出與父進程關聯，也就是 popen() 所返回的那個文件描述符。

這里的 0 1 2 分別對應一個進程的stdin(標準輸入)/stdout(標準輸出)/stderr(標準錯誤)。

還有一點需要注意的是，當我們在父進程中打開的文件描述符，子進程也會繼承過去;

比如在 task.py 中新增一段代碼：

x = open("1.txt", "w") 

之后查看文件描述符時會發現父子進程都會有這個文件：

但相反的，子進程中打開的文件父進程是不會有的，這個應該很容易理解。

總結

一些基礎知識在排查一些詭異問題時顯得尤為重要，比如本次涉及到的父子進程的管道通信，最后來總結一下：

os.popen() 函數是異步執行的，如果需要拿到子進程的輸出，需要自行調用 read() 函數。

父子進程是通過匿名管道進行通信的，當讀取端關閉時，寫入端輸出到達管道最大緩存時會收到 SIGPIPE 信號，從而拋出 Broken pipe 異常。

 

子進程會繼承父進程的文件描述符。