avoid calling req.finish() on closed HTTP connections #1366

New Issue

warner · 2011-02-21T05:49:15Z

warner commented

2011-02-21 05:49:15 +00:00

While reviewing #393 MDMF, I ran into some test failures which were related to an HTTP "GET" connection being closed by the client before the tahoe server had a chance to close it itself. I think it only occurs during the new tests added as part of the #393 patch, but it's not MDMF-specific.

Here's a patch to fix it. Note that Twisted-9.0 was the first version which started raising an error when you call request.finish() on a request that's already been closed, and it was also the first version to offer request.notifyFinish() to tell you when it's been closed. So this patch has to switch on hasattr(req, "notifyFinish") until the time we raise our dependency on Twisted to 9.0 or later.

While reviewing #393 MDMF, I ran into some test failures which were related to an HTTP "GET" connection being closed by the client before the tahoe server had a chance to close it itself. I think it only occurs during the new tests added as part of the #393 patch, but it's not MDMF-specific. Here's a patch to fix it. Note that Twisted-9.0 was the first version which started raising an error when you call `request.finish()` on a request that's already been closed, and it was also the first version to offer `request.notifyFinish()` to tell you when it's been closed. So this patch has to switch on `hasattr(req, "notifyFinish")` until the time we raise our dependency on Twisted to 9.0 or later.

warner added the

labels 2011-02-21 05:49:15 +00:00

warner added this to the undecided milestone 2011-02-21 05:49:15 +00:00

warner commented

2011-02-21 05:52:10 +00:00

Attachment 1366.dpatch (3485 bytes) added

patch to avoid test failures with the #393 tests, but appropriate for trunk

**Attachment** 1366.dpatch (3485 bytes) added patch to avoid test failures with the #393 tests, but appropriate for trunk

1366.dpatch

3.4 KiB

zooko self-assigned this 2011-02-21 05:53:15 +00:00

zooko commented

2011-02-21 05:54:43 +00:00

Could this have been related to #1278 (gateway won't serve any page; variety of interesting error messages in twistd.log)?

davidsarah commented

2011-02-21 05:56:10 +00:00

Looks good to me. (I only eyeballed it, I didn't run it.)

davidsarah commented

2011-02-21 05:58:36 +00:00

Replying to zooko:

Could this have been related to #1278 (gateway won't serve any page; variety of interesting error messages in twistd.log)?

That does look likely given the log message on #1278:

exceptions.RuntimeError: Request.finish called on a request after its
connection was lost; use Request.notifyFinish to keep track of this.

Replying to [zooko](/tahoe-lafs/trac-2024-07-25/issues/1366#issuecomment-82797): > Could this have been related to #1278 (gateway won't serve any page; variety of interesting error messages in twistd.log)? That does look likely given the log message on #1278: ``` exceptions.RuntimeError: Request.finish called on a request after its connection was lost; use Request.notifyFinish to keep track of this. ```

zooko commented

2011-02-21 06:00:48 +00:00

+1 on 1366.dpatch . I would appreciate it if you could investigate #1278. Hopefully this fixes it! I seem to recall that it would happen when there were failures e.g. due to insufficient servers, and it looks like that might have gotten the Tahoe-LAFS web code into a bad state when Twisted >= 9.0 raised an exception from the Tahoe-LAFS web code's attempt to finish an already-finished connection, and that then the Tahoe-LAFS web code might have been unable to serve other requests after that.

Again, please remove the reviewed tag once you've pushed this patch to trunk (or suggest a different way to track that information).

+1 on [1366.dpatch](/tahoe-lafs/trac-2024-07-25/attachments/000078ac-f29f-a043-b3ea-ee14e369b8a8) . I would appreciate it if you could investigate #1278. Hopefully this fixes it! I seem to recall that it would happen when there were failures e.g. due to insufficient servers, and it looks like that might have gotten the Tahoe-LAFS web code into a bad state when Twisted >= 9.0 raised an exception from the Tahoe-LAFS web code's attempt to finish an already-finished connection, and that then the Tahoe-LAFS web code might have been unable to serve other requests after that. Again, please remove the `reviewed` tag once you've pushed this patch to trunk (or suggest a different way to track that information).

zooko commented

2011-02-21 06:02:12 +00:00

Replying to [davidsarah]comment:5:

Replying to zooko:

Could this have been related to #1278 (gateway won't serve any page; variety of interesting error messages in twistd.log)?

That does look likely given the log message on #1278:
exceptions.RuntimeError: Request.finish called on a request after its
connection was lost; use Request.notifyFinish to keep track of this.

If my theory from comment:82800 looks sufficiently likely to you then perhaps we should close #1278 as "MIA--presumed dead". It wasn't very reproducible by me -- perhaps there is an element of race condition between Twisted finishing the connection and Tahoe-LAFS finishing it ?

Replying to [davidsarah]comment:5: > Replying to [zooko](/tahoe-lafs/trac-2024-07-25/issues/1366#issuecomment-82797): > > Could this have been related to #1278 (gateway won't serve any page; variety of interesting error messages in twistd.log)? > > That does look likely given the log message on #1278: > ``` > exceptions.RuntimeError: Request.finish called on a request after its > connection was lost; use Request.notifyFinish to keep track of this. > ``` If my theory from [comment:82800](/tahoe-lafs/trac-2024-07-25/issues/1366#issuecomment-82800) looks sufficiently likely to you then perhaps we should close #1278 as "MIA--presumed dead". It wasn't very reproducible by me -- perhaps there is an element of race condition between Twisted finishing the connection and Tahoe-LAFS finishing it ?

"Brian Warner <warner@lothar.com>" commented

2011-02-21 06:16:33 +00:00

In changeset:44466fbb1bad4ba0:

web/filenode.py: avoid calling req.finish() on closed HTTP connections. Closes #1366

In changeset:44466fbb1bad4ba0: ``` web/filenode.py: avoid calling req.finish() on closed HTTP connections. Closes #1366 ```

tahoe-lafs added the

fixed

label 2011-02-21 06:16:33 +00:00

"Brian Warner <warner@lothar.com>" closed this issue

2011-02-21 06:16:33 +00:00

davidsarah commented

2011-09-25 04:10:34 +00:00

The main bug in this ticket is fixed for 1.9. However since the Twisted dependency has been raised to >= 10.1, the hasattr switch is no longer needed.

The main bug in this ticket is fixed for 1.9. However since the Twisted dependency has been raised to >= 10.1, the `hasattr` switch is no longer needed.

tahoe-lafs added

minor

and removed

major

fixed

labels 2011-09-25 04:10:34 +00:00

tahoe-lafs modified the milestone from undecided to 1.9.0

2011-09-25 04:10:34 +00:00

davidsarah reopened this issue

2011-09-25 04:10:34 +00:00

davidsarah commented

2011-10-13 20:07:17 +00:00

Attachment 1366-no-hasattr.darcs.patch (7596 bytes) added

web/filenode.py: since we depend on Twisted >= 10.1, there is no need to check for the existence of 'req.notifyFinish', which was added in Twisted 9.0. closes #1366

**Attachment** 1366-no-hasattr.darcs.patch (7596 bytes) added web/filenode.py: since we depend on Twisted >= 10.1, there is no need to check for the existence of 'req.notifyFinish', which was added in Twisted 9.0. closes #1366

1366-no-hasattr.darcs.patch

7.4 KiB

zooko was unassigned by tahoe-lafs

2011-10-13 20:08:23 +00:00

warner was assigned by tahoe-lafs

2011-10-13 20:08:23 +00:00

Brian Warner <warner@lothar.com> commented

2011-10-13 20:12:43 +00:00

In changeset:587e31a8cf486031:

web/filenode.py: rely on Request.notifyFinish. Closes #1366.

This is safe now that tahoe depends upon Twisted>=10.1, since notifyFinish
first appeared in Twisted-9.0

In changeset:587e31a8cf486031: ``` web/filenode.py: rely on Request.notifyFinish. Closes #1366. This is safe now that tahoe depends upon Twisted>=10.1, since notifyFinish first appeared in Twisted-9.0 ```

tahoe-lafs added the

fixed

label 2011-10-13 20:12:43 +00:00

Brian Warner <warner@lothar.com> closed this issue

2011-10-13 20:12:43 +00:00

Brian Warner <warner@lothar.com> commented

2011-10-20 20:24:29 +00:00

In [5507/ticket999-S3-backend]:

web/filenode.py: rely on Request.notifyFinish. Closes #1366.

This is safe now that tahoe depends upon Twisted>=10.1, since notifyFinish
first appeared in Twisted-9.0

In [5507/ticket999-S3-backend]: ``` web/filenode.py: rely on Request.notifyFinish. Closes #1366. This is safe now that tahoe depends upon Twisted>=10.1, since notifyFinish first appeared in Twisted-9.0 ```

nejucomo commented

2012-01-22 00:14:19 +00:00

I see similar behavior, but after briefly skimming the patches and assuming that filenode.py was specific to only some HTTP requests, I filed a new ticket: #1664

I see similar behavior, but after *briefly* skimming the patches and assuming that `filenode.py` was specific to only some HTTP requests, I filed a new ticket: #1664

Sign in to join this conversation.