twisted: unhelpful "AlreadyCalled" error

Question

My twisted python program keeps spewing this message ever so often:

Unhandled error in Deferred:

Traceback (most recent call last):
  File "c:\python25\lib\site-packages\twisted\internet\defer.py", line 757, in gotResult
    _inlineCallbacks(r, g, deferred)
  File "c:\python25\lib\site-packages\twisted\internet\defer.py", line 747, in _inlineCallbacks
    deferred.errback()
  File "c:\python25\lib\site-packages\twisted\internet\defer.py", line 269, in errback
    self._startRunCallbacks(fail)
  File "c:\python25\lib\site-packages\twisted\internet\defer.py", line 312, in _startRunCallbacks
    self._runCallbacks()
--- <exception caught here> ---
  File "c:\python25\lib\site-packages\twisted\internet\defer.py", line 328, in _runCallbacks
    self.result = callback(self.result, *args, **kw)
  File "c:\python25\lib\site-packages\twisted\internet\defer.py", line 243, in callback
    self._startRunCallbacks(result)
  File "c:\python25\lib\site-packages\twisted\internet\defer.py", line 298, in _startRunCallbacks
    raise AlreadyCalledError
twisted.internet.defer.AlreadyCalledError:

It's not too helpful, as it has no reference to my source code... I also happen to be using defer.inlineCallbacks. Any idea what might have gone wrong?

Answer 1

If you don't have any other hints about what's going wrong (like your unit tests pointing out the specific cases which cause this, or if pyfunc's answer doesn't make it obvious why this would be happening) then enable Deferred debugging to get information about where the first (and only allowed) result of the Deferred is being specified:

from twisted.internet import defer
defer.setDebugging(True)

Or

twistd --debug [...]

Or

trial --debug [...]

You'll get extra stack traces with error reports like the one you've encountered. The extra stack traces will tell you where the Deferred in question was created and where it was first invoked (had .callback() or .errback() called on it).

Since you're using inlineCallbacks, you don't get a nice stack trace about where the actual error is occurring, but the information about where the Deferred is first triggered might give you a hint about where the subsequent activation might come from.

Unfortunately the added obscurity is just a cost of using inlineCallbacks at the moment. It's probably surmountable, but someone needs to take on that task.

Answer 2

I guess some where in your code, you are explicitly calling the callback of deferred. This is also happening multiple times. A deferred callback can be fired only once which indicates the completion of a long awaited task resulting in a error or positive result. Twisted has a mechanism to throw the above exception, if you tried to fire a deferred more than once.

Consider the following code:

from twisted.internet.defer import Deferred
def func(x): print x
d = Deferred()
d.addCallbacks(func, func)
d.callback('First fire')
d.callback('Second fire')

This will result in the following error:

    raise AlreadyCalledError
twisted.internet.defer.AlreadyCalledError

Check out in your code the possibility of such multiple firings. This might be the issue.