1
15
2014
12

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

>>> 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

Mastodon | Theme: Aeros 2.0 by TheBuckmaker.com