foolscap.test.test_logging.IncidentGatherer.test_emit sometimes fails badly

[Brian Warner]

trial -r poll foolscap.test.test_logging.IncidentGatherer.test_emit sometimes hangs for a long time (two minutes) and then fails with an error about "maximum recursion depth exceeded". I believe this is happening in the error-handling path, specifically in Twisted as it attempts to display whatever unhandled error was in the logs:

[ERROR]: foolscap.test.test_logging.IncidentGatherer.test_emit

Traceback (most recent call last):
  File "/usr/lib/python2.5/site-packages/twisted/internet/defer.py", line 289, in _continue
    self.unpause()
  File "/usr/lib/python2.5/site-packages/twisted/internet/defer.py", line 285, in unpause
    self._runCallbacks()
  File "/usr/lib/python2.5/site-packages/twisted/internet/defer.py", line 344, in _runCallbacks
    self.result = failure.Failure()
  File "/usr/lib/python2.5/site-packages/twisted/python/failure.py", line 265, in __init__
    parentCs = reflect.allYourBase(self.type)
  File "/usr/lib/python2.5/site-packages/twisted/python/reflect.py", line 542, in allYourBase
    accumulateBases(classObj, l, baseClass)
  File "/usr/lib/python2.5/site-packages/twisted/python/reflect.py", line 550, in accumulateBases
    accumulateBases(base, l, baseClass)
  File "/usr/lib/python2.5/site-packages/twisted/python/reflect.py", line 550, in accumulateBases
    accumulateBases(base, l, baseClass)
  File "/usr/lib/python2.5/site-packages/twisted/python/reflect.py", line 550, in accumulateBases
    accumulateBases(base, l, baseClass)
  File "/usr/lib/python2.5/site-packages/twisted/python/reflect.py", line 550, in accumulateBases
    accumulateBases(base, l, baseClass)
exceptions.RuntimeError: maximum recursion depth exceeded

I spent a couple of frustrated hours looking at this and wasn't able to figure it out. It seems like any error that occurs during certain tests will trigger this, which is really annoying as it doesn't make it easy to find out what the real error is.

[Brian Warner]

Hm, I think this has to do with the way foolscap.test.common.PollMixin uses a series of chained Deferreds. I can make the failure occur more frequently by speeding up the poll() call (polling once every 1ms), and less frequently by slowing it down (polling once every 100ms). The default poll() time is once every 10ms.

With faster polling, the number of Deferreds that are chained up by the time the condition is met is larger, and if it crosses some threshold (about 600, it seems) then we get a recursion-depth-exceeded error, which tends to erase all the useful information about its cause.

The solution will be to rewrite poll() to not use this chained-Deferreds pattern.

[Brian Warner]

[6af9acdb1976ed87edae71e5e4ba196c9054cd4f] fixes this, by copying the improved task.LoopingCall-based PollMixin from tahoe.