On 03:12 pm, poalman@gmail.com wrote:
I've still not been able to reproduce this on demand.. the least amount of request I've seen before getting the error is 6500 :/
I've also seen this stack trace which I didn't notice before
2013-02-08 10:07:28+0000 [HTTP11ClientProtocol,client] Unhandled Error Traceback (most recent call last): File "/usr/local/lib/python2.7/dist- packages/Twisted-12.2.0-py2.7-linux- x86_64.egg/twisted/application/app.py", line 323, in runReactorWithLogging reactor.run() File "/usr/local/lib/python2.7/dist- packages/Twisted-12.2.0-py2.7-linux- x86_64.egg/twisted/internet/base.py", line 1169, in run self.mainLoop() File "/usr/local/lib/python2.7/dist- packages/Twisted-12.2.0-py2.7-linux- x86_64.egg/twisted/internet/base.py", line 1181, in mainLoop self.doIteration(t) File "/usr/local/lib/python2.7/dist- packages/Twisted-12.2.0-py2.7-linux- x86_64.egg/twisted/internet/epollreactor.py", line 379, in doPoll log.callWithLogger(selectable, _drdw, selectable, fd, event) --- <exception caught here> --- File "/usr/local/lib/python2.7/dist- packages/Twisted-12.2.0-py2.7-linux-x86_64.egg/twisted/python/log.py", line 84, in callWithLogger return callWithContext({"system": lp}, func, *args, **kw) File "/usr/local/lib/python2.7/dist- packages/Twisted-12.2.0-py2.7-linux-x86_64.egg/twisted/python/log.py", line 69, in callWithContext return context.call({ILogContext: newCtx}, func, *args, **kw) File "/usr/local/lib/python2.7/dist- packages/Twisted-12.2.0-py2.7-linux- x86_64.egg/twisted/python/context.py", line 118, in callWithContext return self.currentContext().callWithContext(ctx, func, *args, **kw) File "/usr/local/lib/python2.7/dist- packages/Twisted-12.2.0-py2.7-linux- x86_64.egg/twisted/python/context.py", line 81, in callWithContext return func(*args,**kw) File "/usr/local/lib/python2.7/dist- packages/Twisted-12.2.0-py2.7-linux- x86_64.egg/twisted/internet/posixbase.py", line 639, in _doReadOrWrite self._disconnectSelectable(selectable, why, inRead) File "/usr/local/lib/python2.7/dist- packages/Twisted-12.2.0-py2.7-linux- x86_64.egg/twisted/internet/posixbase.py", line 258, in _disconnectSelectable selectable.readConnectionLost(f) File "/usr/local/lib/python2.7/dist- packages/Twisted-12.2.0-py2.7-linux- x86_64.egg/twisted/internet/tcp.py", line 267, in readConnectionLost self.connectionLost(reason) File "/usr/local/lib/python2.7/dist- packages/Twisted-12.2.0-py2.7-linux- x86_64.egg/twisted/internet/tcp.py", line 473, in connectionLost self._commonConnection.connectionLost(self, reason) File "/usr/local/lib/python2.7/dist- packages/Twisted-12.2.0-py2.7-linux- x86_64.egg/twisted/internet/tcp.py", line 281, in connectionLost abstract.FileDescriptor.connectionLost(self, reason) File "/usr/local/lib/python2.7/dist- packages/Twisted-12.2.0-py2.7-linux- x86_64.egg/twisted/internet/abstract.py", line 182, in connectionLost self.producer.stopProducing() File "/usr/local/lib/python2.7/dist- packages/Twisted-12.2.0-py2.7-linux-x86_64.egg/twisted/web/client.py", line 760, in stopProducing self._task.stop() File "/usr/local/lib/python2.7/dist- packages/Twisted-12.2.0-py2.7-linux- x86_64.egg/twisted/internet/task.py", line 460, in stop self._completeWith(TaskStopped(), Failure(TaskStopped())) File "/usr/local/lib/python2.7/dist- packages/Twisted-12.2.0-py2.7-linux- x86_64.egg/twisted/internet/task.py", line 439, in _completeWith self._cooperator._removeTask(self) File "/usr/local/lib/python2.7/dist- packages/Twisted-12.2.0-py2.7-linux- x86_64.egg/twisted/internet/task.py", line 578, in _removeTask self._delayedCall.cancel() File "/usr/local/lib/python2.7/dist- packages/Twisted-12.2.0-py2.7-linux- x86_64.egg/twisted/internet/base.py", line 89, in cancel raise error.AlreadyCalled twisted.internet.error.AlreadyCalled: Tried to cancel an already-called event.
I'll keep trying to work out the issue, any suggestions on what I might try to reproduce it or guesses at causes?
Since it seems to be related to handling of lost connections, you may be able to reproduce it more easily if you issue your requests to an HTTP server which drops connections more often. Presumably the production service you're issuing requests too tries pretty hard to properly serve responses to every request. If you point `Agent` at a worse HTTP server (eg, one you write using twisted.web and implement to close connections prematurely at various points during the response) this may produce the issue more quickly. You could also try hooking `Agent` up to one of the in-memory reactors/transports. The advantage of this is that it will be much easier to "close" the connection at a specific point (deterministically). The disadvantage is that the in-memory reactor/transport may not exactly replicate the real reactor/transport behavior and so fail to reproduce the issue entirely. Jean-Paul