前言
最近用 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
信号。