Twisted Deferred 在没有 errback 的情况下不显示未处理的异常

Question

我正在阅读 McKellar 和 Fettig 的 Twisted Network Programming Essentials, 2nd Ed.

我在 Windows 7 上的 Python 2.7.10 上运行 Twisted 15.5.0。

在关于Deferred 的部分中，有一个示例应该引发Unhandled Error in Deferred - 但是当我运行下面的最小示例时，我只会从控制台获得完全静音：

小例子

from twisted.internet.defer import Deferred

def raiseErr(err):
    raise Exception(err)

d = Deferred()
d.addCallback(raiseErr)
d.callback("oh no")

$ python test.py (no output)

来自实际书籍文本的最小示例

书中的实际例子是这样的：

from twisted.internet.defer import Deferred

def callback1(result):
    print "Callback 1 said:", result
    return result

def callback2(result):
    print "Callback 2 said:", result

def callback3(result):
    raise Exception("Callback 3")

def errback1(failure):
    print "Errback 1 had an an error on", failure
    return failure

d = Deferred()
d.addCallback(callback1)
d.addCallback(callback2)
d.addCallback(callback3)
d.callback("Test")

并且预期的输出在书中列出为：

callback3 引发Exception，并且由于没有注册的errback 来处理Exception，程序终止并向用户报告Unhandled Error。结果是：

Callback 1 said: Test
Callback 2 said: Test
Unhandled error in Deferred:
Unhandled Error
Traceback (most recent call last):
File "/tmp/test.py", line 33, in <module>
d.callback("Test")
<...>
File "/tmp/test.py", line 11, in callback3
raise Exception("Callback 3")
exceptions.Exception: Callback 3

我做错了吗？

编辑：

我的机器上正确显示错误。

要在没有Deferred 对象上的errback 处理程序的情况下启用错误记录，我需要将以下内容添加到我的sn-p：

import sys
from twisted.python import log

log.startLogging(sys.stdout)

# rest of the code goes here

现在，当我从问题中的第一个代码 sn-p 运行我的最小示例时，我得到以下输出：

2016-02-05 09:45:43-0600 [-] Log opened.
2016-02-05 09:45:43-0600 [-] Invalid format string or unformattable object in log message: '%(log_legacy)s', {'format': '%(log_legacy)s', 'log_legacy': <twisted.logger._stdlib.StringifiableFromEvent object at 0x038913F0>, 'time': 1454687143.778, 'message': (), 'log_time': 1454687143.778, 'log_namespace': 'twisted.internet.defer', 'log_level': <LogLevel=critical>, 'log_source': None, 'system': '-', 'isError': True, 'log_logger': <Logger 'twisted.internet.defer'>, 'log_format': 'Unhandled error in Deferred:'}
2016-02-05 09:45:43-0600 [-] Unhandled Error
        Traceback (most recent call last):
          File "testd.py", line 13, in <module>
            d.callback("oh no")
          File "C:\Swat\.virtualenvs\twisted\lib\site-packages\twisted\internet\defer.py", line 393, in callback
            self._startRunCallbacks(result)
          File "C:\Swat\.virtualenvs\twisted\lib\site-packages\twisted\internet\defer.py", line 501, in _startRunCallbacks
            self._runCallbacks()
        --- <exception caught here> ---
          File "C:\Swat\.virtualenvs\twisted\lib\site-packages\twisted\internet\defer.py", line 588, in _runCallbacks
            current.result = callback(current.result, *args, **kw)
          File "testd.py", line 9, in raiseErr
            raise Exception(err)
        exceptions.Exception: oh no

所以，现在我可以验证 Twisted 确实引发了一个错误，因为它只是出于某种原因不想告诉我。如果有人能详细说明为什么这将是处理没有定义 errback 的异常的默认情况，我很想知道。

我已更改标题以反映我的新问题。

Answer 1

我在通过 Dave Perticola 的出色 Twisted Introduction 特别是在 Part 9: A Second Interlude, Deferred 中遇到了一个非常相似的问题后发现了这个问题，他的 example 与您发布的类似：

from twisted.internet.defer import Deferred
def callback(res):
    raise Exception('oops')
d = Deferred()
d.addCallback(callback)
d.callback('Here is your result.')
print "Finished"

就像你一样，我没有得到建议的输出：

Finished
Unhandled error in Deferred:
Traceback (most recent call last):
 ...
--- <exception caught here> ---
 ...
exceptions.Exception: oops

我最初认为是版本控制问题，Twisted 16 with PyPy 5.0.1 on EL6，但研究把我带到了这里；然后在打开日志记录时，正如另一个答案中所建议的那样，对我认为的实际答案没有影响。

我的答案的线索是在我正在使用的教程中，并声明：

“Finished”排在第一位的原因是“Unhandled”消息直到延迟被垃圾收集才真正打印出来。

出于某种原因，对你和我来说，当垃圾收集器开始做它的事情时，它不再有任何地方可以输出。如果你想看到这是真的，这是我修改后的代码：

import gc
from twisted.internet.defer import Deferred
def callback(res):
    raise Exception('oops call')
d = Deferred()
d.addCallback(callback)
d.callback('Here is your result.')
d = None
gc.collect()
print "Finished"

我想真正的答案是在垃圾收集器到达它们之前处理你的异常，但也许这些信息会让你睡得更轻松，即使我们不知道为什么它对某些人有效，我们知道是什么导致我们预期的错误消息消失。

Answer 2

我认为我们的代码没有问题。

我在这里尝试运行：

$ python deferred.py

输出是：

Unhandled error in Deferred:


Traceback (most recent call last):
  File "deferred.py", line 8, in <module>
    d.callback("oh no")
  File "/home/vagrant/.virtualenvs/asyncproxy/local/lib/python2.7/site-packages/twisted/internet/defer.py", line 393, in callback
    self._startRunCallbacks(result)
  File "/home/vagrant/.virtualenvs/asyncproxy/local/lib/python2.7/site-packages/twisted/internet/defer.py", line 501, in _startRunCallbacks
    self._runCallbacks()
--- <exception caught here> ---
  File "/home/vagrant/.virtualenvs/asyncproxy/local/lib/python2.7/site-packages/twisted/internet/defer.py", line 588, in _runCallbacks
    current.result = callback(current.result, *args, **kw)
  File "deferred.py", line 4, in raiseErr
    raise Exception(err)
exceptions.Exception: oh no

我正在使用 Twisted 15.5.0 和 Python 2.7.6。

P.S: 不需要初始化日志。没有它也能正常工作。

Answer 3

这段代码在我测试过的所有 Windows 机器上都给出了相同的结果，而在任何 Linux 机器上都没有。我的结论是，这是与 Windows、twisted 或 pywin32 有关的问题。