被 Tornado coroutine 对异常的异常支持坑了

1
15
2014

被 Tornado coroutine 对异常的异常支持坑了

本文来自依云's Blog，转载请注明。

>>> python -m this | grep -A1 -F Errors
Errors should never pass silently.
Unless explicitly silenced.

因为要捕获子进程的标准输出、标准错误以及退出状态码，用 callback 写会非常麻烦，因为三者全部完成才能进行下一步操作。而使用 Tornado 的 coroutine 就很方便了，示例如下：

from tornado.gen import coroutine, Task
from tornado.process import Subprocess

@coroutine
def run_cmd(cmd):
    p = Subprocess(
        cmd,
        stdout = Subprocess.STREAM,
        stderr = Subprocess.STREAM,
    )
    out, err, code = yield [Task(p.stdout.read_until_close),
                            Task(p.stderr.read_until_close),
                            Task(p.set_exit_callback)]
    return out, err, code
    # For Python below 3.3, use
    # raise Return((out, err, code))

yield 一个 Task（或者 Future）的列表的话，它们会并发执行，全部执行完毕之后才会返回到这个 yield 位置继续执行。简洁干净。（不过我要吐槽一下为什么必须传列表，传元组就不对……）

于是乎，调用各种外部命令的部分被我由一堆回调改成了 coroutine，除了 yield 关键字有些别扭外，整个代码可读性好多了 :-)

可是后来，发生了这样的一件事：通过日志能看到一个 coroutine 前边的代码执行了，而后边的代码却没有执行，中间也没有 yield 到别的地方去！看上去非常诡异。

恰好前些天刚好看到一很不错的 Python 调试器 pudb。于是去执行中断的地方打断点（import pudb; pu.db），然后单步跟踪。这才发现原来是中间有个语句抛出了异常，然后这个异常被 coroutine「吃掉」了……示例代码如下：

#!/usr/bin/env python3

from tornado.gen import coroutine
from tornado.ioloop import IOLoop

@coroutine
def two():
  print('two entered')
  1 / 0
  print('two leaving')

@coroutine
def one():
  print('one entered')
  yield two()
  print('one leaving')

if __name__ == '__main__':
  one()
  IOLoop.current().start()

结果是：

one entered
two entered

执行从发生异常的那个位置中断了，并且没有任何错误消息被记录。（PS: 要是在 coroutine 里使用 try...except 的话是能抓到它的。）

以「tornado coroutine exception」为关键字找到了这个以及这个。原来 coroutine 的异常是被它返回的那个 Future 对象「吃掉」了。如果是在 Tornado 的 HTTP 服务里（RequestHandler），Tornado 的 web 模块会处理并记录这种异常。然而我是在 web 模块之外使用的，所以得自己来处理了：

#!/usr/bin/env python3

from tornado.gen import coroutine
from tornado.ioloop import IOLoop

@coroutine
def two():
  print('two entered')
  1 / 0
  print('two leaving')

@coroutine
def one():
  print('one entered')
  yield two()
  print('one leaving')

def _future_done(fu):
  fu.result()

if __name__ == '__main__':
  fu = one()
  fu.add_done_callback(_future_done)
  IOLoop.current().start()

这样就能看到有异常发生了：

one entered
two entered
ERROR:concurrent.futures:exception calling callback for <Future at 0x7f286c0bcf90 state=finished raised ZeroDivisionError>
  ...
  File "t.py", line 9, in two
    1 / 0
ZeroDivisionError: division by zero

那个异常的 Traceback 很长很长。没有原生的良好的协程支持的代价吧，不知道 Python 3.4 的 asyncio 里会不会好一些。

2014年8月2日更新：asyncio 在遇到这种情况时会打印错误日志，参见文档。

Category: python | Tags: python tornado coroutine | Read Count: 17344