MongoProtocol.connectionLost uses single shared AutoReconnect instance to fail many different Deferreds. It took me a day of debugging and not a single gray hair to figure out that logged stack traces of unhandled failures may be very weird in this case.
Proof:
import sys
from twisted.internet.defer import Deferred, inlineCallbacks
from twisted.python import log
log.startLogging(sys.stdout)
@inlineCallbacks
def task1(d):
try:
yield d
except ZeroDivisionError as e:
print('task cought')
@inlineCallbacks
def task2(d):
yield d
d1 = Deferred()
d2 = Deferred()
task1(d1)
task2(d2)
error = ZeroDivisionError('boom')
d1.errback(error)
d2.errback(error)
This prints:
2018-03-16 16:20:28+0300 [-] Log opened.
2018-03-16 16:20:28+0300 [-] task cought
2018-03-16 16:20:28+0300 [-] Unhandled error in Deferred:
2018-03-16 16:20:28+0300 [-] Unhandled Error
Traceback (most recent call last):
File "/home/ilya/txmongo/venv3/lib/python3.6/site-packages/twisted/internet/defer.py", line 500, in errback
self._startRunCallbacks(fail)
File "/home/ilya/txmongo/venv3/lib/python3.6/site-packages/twisted/internet/defer.py", line 567, in _startRunCallbacks
self._runCallbacks()
File "/home/ilya/txmongo/venv3/lib/python3.6/site-packages/twisted/internet/defer.py", line 653, in _runCallbacks
current.result = callback(current.result, *args, **kw)
File "/home/ilya/txmongo/venv3/lib/python3.6/site-packages/twisted/internet/defer.py", line 1442, in gotResult
_inlineCallbacks(r, g, deferred)
--- <exception caught here> ---
File "/home/ilya/txmongo/venv3/lib/python3.6/site-packages/twisted/internet/defer.py", line 1384, in _inlineCallbacks
result = result.throwExceptionIntoGenerator(g)
File "/home/ilya/txmongo/venv3/lib/python3.6/site-packages/twisted/python/failure.py", line 408, in throwExceptionIntoGenerator
return g.throw(self.type, self.value, self.tb)
File "exc-demo.py", line 17, in task2
yield d
File "exc-demo.py", line 11, in task1
yield d
builtins.ZeroDivisionError: boom
Note that stack trace points out on that task1 is the source of exception although it was successfully caught there. Add some more complexity and twisted callback chains in between and you will have fun time realizing where exception is from :)
Coverage decreased (-0.003%) to 95.195% when pulling c45caae8ce8dfc12ddcbc9710e1757362e0633a6 on IlyaSkriblovsky:distinct-autoreconnect-instances into fcae7d7de48fddce198bad55da73caa639fd989f on twisted:master.
MongoProtocol.connectionLost
uses single sharedAutoReconnect
instance to fail many different Deferreds. It took me a day of debugging and not a single gray hair to figure out that logged stack traces of unhandled failures may be very weird in this case.Proof:
This prints:
Note that stack trace points out on that
task1
is the source of exception although it was successfully caught there. Add some more complexity and twisted callback chains in between and you will have fun time realizing where exception is from :)