webapi fails to handle all TCP disconnects: "Request.finish called on a request after its connection was lost; use Request.notifyFinish to keep track of this." #1664

New Issue

nejucomo · 2012-01-22T00:08:44Z

nejucomo commented

2012-01-22 00:08:44 +00:00

Symptoms: While running a gateway which has haproxy as a webapi client which I frequently restart, I see exceptions like this:

2012-01-21 14:35:15-0800 [-] Unhandled error in Deferred:
2012-01-21 14:35:15-0800 [-] Unhandled Error
        Traceback (most recent call last):
          File "/home/n/virtualenvs/default/lib/python2.7/site-packages/nevow/flat/twist.py", line 42, in cb
            _drive(iterable, finished)
          File "/home/n/virtualenvs/default/lib/python2.7/site-packages/nevow/flat/twist.py", line 26, in _drive
            finished.callback('')
          File "/home/n/virtualenvs/default/lib/python2.7/site-packages/twisted/internet/defer.py", line 362, in callback
            self._startRunCallbacks(result)
          File "/home/n/virtualenvs/default/lib/python2.7/site-packages/twisted/internet/defer.py", line 458, in _startRunCallbacks
            self._runCallbacks()
        --- <exception caught here> ---
          File "/home/n/virtualenvs/default/lib/python2.7/site-packages/twisted/internet/defer.py", line 545, in _runCallbacks
            current.result = callback(current.result, *args, **kw)
          File "/home/n/virtualenvs/default/lib/python2.7/site-packages/nevow/appserver.py", line 181, in _cbFinishRender
            self.finishRequest(  True )
          File "/home/n/virtualenvs/default/lib/python2.7/site-packages/nevow/appserver.py", line 176, in finishRequest
            server.Request.finish(self)
          File "/home/n/virtualenvs/default/lib/python2.7/site-packages/twisted/web/http.py", line 866, in finish
            "Request.finish called on a request after its connection was lost; "
        exceptions.RuntimeError: Request.finish called on a request after its connection was lost; use Request.notifyFinish to keep track of this.

Resolution: Handle early/exceptional TCP disconnects.

Related Issues:

It looks like a closed ticket purports to fix this issue, at least for some cases: #1366 -also see: #1278
haproxy may behave unlike browsers. For instance, it may treat the connection to the gateway as Keep-Alive, even when the browser clients do not. I am using default configuration for this kind of behavior, and in generaly I expect haproxy to "play well" with many different http server implementations.

**Symptoms**: While running a gateway which has haproxy as a webapi client which I frequently restart, I see exceptions like this: ``` 2012-01-21 14:35:15-0800 [-] Unhandled error in Deferred: 2012-01-21 14:35:15-0800 [-] Unhandled Error Traceback (most recent call last): File "/home/n/virtualenvs/default/lib/python2.7/site-packages/nevow/flat/twist.py", line 42, in cb _drive(iterable, finished) File "/home/n/virtualenvs/default/lib/python2.7/site-packages/nevow/flat/twist.py", line 26, in _drive finished.callback('') File "/home/n/virtualenvs/default/lib/python2.7/site-packages/twisted/internet/defer.py", line 362, in callback self._startRunCallbacks(result) File "/home/n/virtualenvs/default/lib/python2.7/site-packages/twisted/internet/defer.py", line 458, in _startRunCallbacks self._runCallbacks() --- <exception caught here> --- File "/home/n/virtualenvs/default/lib/python2.7/site-packages/twisted/internet/defer.py", line 545, in _runCallbacks current.result = callback(current.result, *args, **kw) File "/home/n/virtualenvs/default/lib/python2.7/site-packages/nevow/appserver.py", line 181, in _cbFinishRender self.finishRequest( True ) File "/home/n/virtualenvs/default/lib/python2.7/site-packages/nevow/appserver.py", line 176, in finishRequest server.Request.finish(self) File "/home/n/virtualenvs/default/lib/python2.7/site-packages/twisted/web/http.py", line 866, in finish "Request.finish called on a request after its connection was lost; " exceptions.RuntimeError: Request.finish called on a request after its connection was lost; use Request.notifyFinish to keep track of this. ``` **Resolution**: Handle early/exceptional TCP disconnects. **Related Issues**: * It looks like a closed ticket purports to fix this issue, at least for some cases: #1366 -also see: #1278 * haproxy may behave unlike browsers. For instance, it may treat the connection to the gateway as Keep-Alive, even when the browser clients do not. I am using default configuration for this kind of behavior, and in generaly I expect haproxy to "play well" with many different http server implementations.

nejucomo added the

labels 2012-01-22 00:08:44 +00:00

nejucomo added this to the undecided milestone 2012-01-22 00:08:44 +00:00

tahoe-lafs added

code-frontend-web

and removed

unknown

labels 2012-03-12 19:27:24 +00:00

tahoe-lafs modified the milestone from undecided to 1.11.0

2012-04-01 23:07:29 +00:00

nejucomo commented

2012-04-02 03:24:25 +00:00

After some more experience with twisted.web, this seems to be a very common bug. For instance, this query shows twisted made the same mistake internally in three different components:

Twisted trac query for "Request.finish called on a request after its connection was lost"

After some more experience with twisted.web, this seems to be a very common bug. For instance, this query shows twisted made the same mistake internally in three different components: [Twisted trac query for "Request.finish called on a request after its connection was lost"](http://twistedmatrix.com/trac/query?status=assigned&status=closed&status=new&status=reopened&description=~Request.finish+called+on+a+request+after+its+connection+was+lost&order=priority&col=id&col=summary&col=status&col=type&col=priority&col=milestone&col=component)

nejucomo commented

2012-04-02 03:31:35 +00:00

I am somewhat confident this behavior is benign; the web server will continue processing other requests without being affected. For this reason I'd lower the priority.

There's only two possible drawbacks I now brainstorm:

The exception may scare users.
The process generating the response may be wasting resources; especially if this is a very long-running request which consumes many resources.

There could be a bug if a failure for the client to receive a request result leads to corruption. I doubt that is the case, at least for the RESTful storage APIs.

I am somewhat confident this behavior is benign; the web server will continue processing other requests without being affected. For this reason I'd lower the priority. There's only two possible drawbacks I now brainstorm: * The exception may scare users. * The process generating the response may be wasting resources; especially if this is a very long-running request which consumes many resources. There *could* be a bug if a failure for the client to receive a request result leads to corruption. I doubt that is the case, at least for the RESTful storage APIs.

davidsarah commented

2012-04-02 18:00:41 +00:00

Replying to nejucomo:

For instance, this query shows twisted made the same mistake internally in three different components [...]

Actually at least five; the query didn't catch https://twistedmatrix.com/trac/ticket/4901 or https://twistedmatrix.com/trac/ticket/5132 (found by searching for just notifyFinish).

Replying to [nejucomo](/tahoe-lafs/trac-2024-07-25/issues/1664#issuecomment-87250): > For instance, this query shows twisted made the same mistake internally in three different components [...] Actually at least five; the query didn't catch <https://twistedmatrix.com/trac/ticket/4901> or <https://twistedmatrix.com/trac/ticket/5132> (found by searching for just `notifyFinish`).

Sign in to join this conversation.