[needs test] Capability of interrupted downloads is logged in twistd.log #685

New Issue

zooko · 2009-04-23T22:28:00Z

zooko commented

2009-04-23 22:28:00 +00:00

I happened to see this in the twisted.log of a Tahoe-1.3.0 node (the testgrid web gateway):

2009-04-22 17:05:34.866Z [-] Unhandled Error
        Traceback (most recent call last):
        Failure: exceptions.RuntimeError: Producer was not unregistered for /uri/URI%3ADIR2%3Adjrdkfawoqihigoett4g6auz6a%3Ajx5mplfpwexnoqff7y5e4zjus4lidm76dcuarpct7cckorh2dpgq/Axe_Versus_Laptop-theora-videoquality5-audioquality3.ogv

As far as I can tell, the register/unregister producer code in source:src/allmydata/immutable/download.py hasn't changed since before the v1.3.0 release, so I suspect this bug is still here in trunk. I assume that it doesn't cause any actual trouble beyond noise in the twistd.log... Or does it? Maybe it wastes some memory? I guess the next step is to find this error message in the Twisted code base (Twisted v2.5.0 was used here).

This is part of a cluster of tickets including: #562, #563, #685, #887, #1008, and #1904.

I happened to see this in the twisted.log of a Tahoe-1.3.0 node (the testgrid web gateway): ``` 2009-04-22 17:05:34.866Z [-] Unhandled Error Traceback (most recent call last): Failure: exceptions.RuntimeError: Producer was not unregistered for /uri/URI%3ADIR2%3Adjrdkfawoqihigoett4g6auz6a%3Ajx5mplfpwexnoqff7y5e4zjus4lidm76dcuarpct7cckorh2dpgq/Axe_Versus_Laptop-theora-videoquality5-audioquality3.ogv ``` As far as I can tell, the register/unregister producer code in source:src/allmydata/immutable/download.py hasn't changed since before the v1.3.0 release, so I suspect this bug is still here in trunk. I assume that it doesn't cause any actual trouble beyond noise in the `twistd.log`... Or does it? Maybe it wastes some memory? I guess the next step is to find this error message in the Twisted code base (Twisted v2.5.0 was used here). This is part of a cluster of tickets including: #562, #563, #685, #887, #1008, and #1904.

zooko added the

labels 2009-04-23 22:28:00 +00:00

zooko added this to the eventually milestone 2009-04-23 22:28:00 +00:00

warner commented

2009-04-26 20:55:46 +00:00

is this happening when somebody is downloading the file and stops their browser before the download has completed?

I suspect that I added that exception, since I used to be in the habit of raising RuntimeError as a sort of assertion. I suspect that the only consequences of this problem would be that we'd keep the tahoe-side download going even though nobody's left on the HTTP side to receive the data. But it might also mean that I don't understand producers and consumers (and twisted.web) as well as I thought I did.

(similar code is used in the FTP and SFTP servers, so we should make sure we know what sort of access was being used for that particular operation)

is this happening when somebody is downloading the file and stops their browser before the download has completed? I suspect that I added that exception, since I used to be in the habit of raising `RuntimeError` as a sort of assertion. I suspect that the only consequences of this problem would be that we'd keep the tahoe-side download going even though nobody's left on the HTTP side to receive the data. But it might also mean that I don't understand producers and consumers (and twisted.web) as well as I thought I did. (similar code is used in the FTP and SFTP servers, so we should make sure we know what sort of access was being used for that particular operation)

zooko commented

2010-01-09 04:41:34 +00:00

The fact that this leads to caps and filenames being written into twistd.log is a privacy and confidentiality issue: #887 (twisted.web logs the uri on some exceptional conditions, leading to a privacy leak in logfiles)

The fact that this leads to caps and filenames being written into `twistd.log` is a privacy and confidentiality issue: #887 (twisted.web logs the uri on some exceptional conditions, leading to a privacy leak in logfiles)

warner commented

2010-01-10 08:20:16 +00:00

This looks like it's coming from Twisted directly, rather than from something which I wrote: twisted/web/http.py Request._cleanup (about line 591).

davidsarah commented

2010-08-06 01:52:23 +00:00

Not sure why this was priority 'minor'.

tahoe-lafs added

major

and removed

minor

labels 2010-08-06 01:52:23 +00:00

tahoe-lafs modified the milestone from eventually to soon

2010-08-06 01:52:23 +00:00

davidsarah commented

2010-08-06 02:10:53 +00:00

#1155 was a duplicate.

Here's the Request._cleanup method in Twisted 10.1.0. I can't immediately see how to fix this, short of replacing the logging sink and filtering strings containing "URI:" in all log messages.

#1155 was a duplicate. [Here](http://twistedmatrix.com/trac/browser/tags/releases/twisted-10.1.0/twisted/web/http.py#L650)'s the `Request._cleanup` method in Twisted 10.1.0. I can't immediately see how to fix this, short of replacing the logging sink and filtering strings containing "`URI:`" in all log messages.

tahoe-lafs changed title from ~~RuntimeError: Producer was not unregistered~~ to Capability of interrupted downloads is logged in twistd.log

2010-08-06 02:29:05 +00:00

warner commented

2010-08-06 07:39:04 +00:00

This should be fixed in changeset:4b7c94ece074ede2, pushed a few hours after the release of 1.8.0b2 . The fix is to make sure we call unregisterProducer in all cases, even when the connection is dropped (which calls our stopProducing method). At least, this stops the log message in my experiments.

This should be fixed in changeset:4b7c94ece074ede2, pushed a few hours after the release of 1.8.0b2 . The fix is to make sure we call `unregisterProducer` in all cases, even when the connection is dropped (which calls our `stopProducing` method). At least, this stops the log message in my experiments.

davidsarah commented

2011-01-22 00:26:09 +00:00

We need a test for this, that would have failed before changeset:4b7c94ece074ede2.

tahoe-lafs modified the milestone from soon to 1.9.0

2011-01-22 00:26:09 +00:00

warner commented

2011-10-13 17:04:24 +00:00

not making it into 1.9

warner modified the milestone from 1.9.0 to 1.10.0

2011-10-13 17:04:24 +00:00

warner changed title from ~~Capability of interrupted downloads is logged in twistd.log~~ to [needs test] Capability of interrupted downloads is logged in twistd.log

2011-10-13 17:04:24 +00:00

tahoe-lafs modified the milestone from 1.11.0 to soon

2012-04-01 00:28:19 +00:00

zooko commented

2013-01-14 09:04:56 +00:00

#887 was a duplicate of this.

Sign in to join this conversation.