exception from binascii.unhexlify when handling announcements on Python 2.4.1 #710

New Issue

exarkun · 2009-05-19T02:30:54Z

exarkun commented

2009-05-19 02:30:54 +00:00

When I start up a node on Python 2.4, if I insert some additional logging, then I can see this unhandled exception happening partway through processing the initial announcements list:

2009-05-18 22:24:17-0400 [-] Unhandled Error
        Traceback (most recent call last):
          File "/c/home/tahoe/allmydata-tahoe-1.4.1/Twisted-8.1.0-py2.4-linux-padre.egg/twisted/internet/defer.py", line 328, in _runCallbacks
            self.result = callback(self.result, *args, **kw)
          File "/c/home/tahoe/allmydata-tahoe-1.4.1/support/lib/python2.4/site-packages/foolscap-0.3.2-py2.4.egg/foolscap/broker.py", line 536, 
in <lambda>
            d.addCallback(lambda res: self._doCall(delivery))
          File "/c/home/tahoe/allmydata-tahoe-1.4.1/support/lib/python2.4/site-packages/foolscap-0.3.2-py2.4.egg/foolscap/broker.py", line 571, 
in _doCall
            return obj.doRemoteCall(delivery.methodname, args, kwargs)
          File "/c/home/tahoe/allmydata-tahoe-1.4.1/support/lib/python2.4/site-packages/foolscap-0.3.2-py2.4.egg/foolscap/referenceable.py", lin
e 59, in doRemoteCall
            res = meth(*args, **kwargs)
        --- <exception caught here> ---
          File "/c/home/tahoe/allmydata-tahoe-1.4.1/src/allmydata/introducer/client.py", line 252, in remote_announce
            self._new_announcement(ann)
          File "/c/home/tahoe/allmydata-tahoe-1.4.1/src/allmydata/introducer/client.py", line 258, in _new_announcement
            index = make_index(announcement)
          File "/c/home/tahoe/allmydata-tahoe-1.4.1/src/allmydata/introducer/common.py", line 9, in make_index
            nodeid = b32decode(m.group(1).upper())
          File "/usr/lib/python2.4/base64.py", line 224, in b32decode
            parts.append(binascii.unhexlify(hex(acc)[2:-1]))
        exceptions.TypeError: Odd-length string

A related issue may be that this sort of exception isn't being reported at all, as far as I can tell. It manifest as a mysterious shortness in the known peers list on the welcome page. To discover the problem, I had to edit the code to insert a try/except/log.err call.

When I start up a node on Python 2.4, if I insert some additional logging, then I can see this unhandled exception happening partway through processing the initial announcements list: ``` 2009-05-18 22:24:17-0400 [-] Unhandled Error Traceback (most recent call last): File "/c/home/tahoe/allmydata-tahoe-1.4.1/Twisted-8.1.0-py2.4-linux-padre.egg/twisted/internet/defer.py", line 328, in _runCallbacks self.result = callback(self.result, *args, **kw) File "/c/home/tahoe/allmydata-tahoe-1.4.1/support/lib/python2.4/site-packages/foolscap-0.3.2-py2.4.egg/foolscap/broker.py", line 536, in <lambda> d.addCallback(lambda res: self._doCall(delivery)) File "/c/home/tahoe/allmydata-tahoe-1.4.1/support/lib/python2.4/site-packages/foolscap-0.3.2-py2.4.egg/foolscap/broker.py", line 571, in _doCall return obj.doRemoteCall(delivery.methodname, args, kwargs) File "/c/home/tahoe/allmydata-tahoe-1.4.1/support/lib/python2.4/site-packages/foolscap-0.3.2-py2.4.egg/foolscap/referenceable.py", lin e 59, in doRemoteCall res = meth(*args, **kwargs) --- <exception caught here> --- File "/c/home/tahoe/allmydata-tahoe-1.4.1/src/allmydata/introducer/client.py", line 252, in remote_announce self._new_announcement(ann) File "/c/home/tahoe/allmydata-tahoe-1.4.1/src/allmydata/introducer/client.py", line 258, in _new_announcement index = make_index(announcement) File "/c/home/tahoe/allmydata-tahoe-1.4.1/src/allmydata/introducer/common.py", line 9, in make_index nodeid = b32decode(m.group(1).upper()) File "/usr/lib/python2.4/base64.py", line 224, in b32decode parts.append(binascii.unhexlify(hex(acc)[2:-1])) exceptions.TypeError: Odd-length string ``` A related issue may be that this sort of exception isn't being reported at all, as far as I can tell. It manifest as a mysterious shortness in the known peers list on the welcome page. To discover the problem, I had to edit the code to insert a try/except/log.err call.

exarkun added the

labels 2009-05-19 02:30:54 +00:00

exarkun added this to the undecided milestone 2009-05-19 02:30:54 +00:00

zooko commented

2009-05-19 02:45:13 +00:00

Thank you for the bug report! I appreciate that you debugged Tahoe yourself in order to figure out more precisely what is going wrong.

Is this Python 2.4.0 or 2.4.1? There was a known bug in the base64.py of those releases which (I think) could cause this behavior. Please try with Python 2.4.2 or higher (<3).

If that turns out to be the issue, then don't close this ticket -- Tahoe needs to do something, or two somethings, to make this kind of thing not happen again. The first something is make it really clear that Python 2.4.0 and 2.4.1 won't work, perhaps by testing for this bug in base64.py at start-up and quitting with a useful error message. The second something is make sure exceptions aren't mysteriously disappearing. Perhaps they are going into the logs/incidents directory and the documentation doesn't make it clear enough that you should look there?

Thank you for the bug report! I appreciate that you debugged Tahoe yourself in order to figure out more precisely what is going wrong. Is this Python 2.4.0 or 2.4.1? There was a known bug in the base64.py of those releases which (I think) could cause this behavior. Please try with Python 2.4.2 or higher (<3). If that turns out to be the issue, then don't close this ticket -- Tahoe needs to do something, or two somethings, to make this kind of thing not happen again. The first something is make it really clear that Python 2.4.0 and 2.4.1 won't work, perhaps by testing for this bug in base64.py at start-up and quitting with a useful error message. The second something is make sure exceptions aren't mysteriously disappearing. Perhaps they are going into the `logs/incidents` directory and the documentation doesn't make it clear enough that you should look there?

warner commented

2009-05-19 03:42:42 +00:00

I just added a test case that ought to exercise the base64.b32decode behavior we need (in changeset:9f0bc04d32248d66). It ought to fail on py2.4.0 and 2.4.1, and pass on py2.4.2 .

warner changed title from ~~exception from binascii.unhexlify when handling announcements on Python 2.4~~ to exception from binascii.unhexlify when handling announcements on Python 2.4.1

2009-05-19 03:42:42 +00:00

warner commented

2009-05-19 03:43:17 +00:00

For reference, here is the known bug and its upstream patch: http://bugs.python.org/issue1171487

For reference, here is the known bug and its upstream patch: <http://bugs.python.org/issue1171487>

zooko commented

2009-05-19 20:03:53 +00:00

Okay, so changeset:8df5fc8d81f69c2a, changeset:18be10ceebd0d8c3, changeset:a664c1699fd5c496 make it so that Tahoe detects this bug on startup and reports it clearly. Now what about the Mystery of the Disappearing Exception?

warner added

code

and removed

unknown

labels 2009-07-11 11:24:22 +00:00

zooko commented

2010-04-13 04:25:49 +00:00

This ticket is fixed -- the part about the bug in binascii.unhexlify. The part about an exception at startup not getting logged property is potentially a serious issue but isn't this ticket. Perhaps it is part of #529? See also #807 which has a similar issue. Perhaps we need a new ticket for this issue: Report All Exceptions. #1021

This ticket is fixed -- the part about the bug in `binascii.unhexlify`. The part about an exception at startup not getting logged property is potentially a serious issue but isn't this ticket. Perhaps it is part of #529? See also #807 which has a similar issue. Perhaps we need a new ticket for this issue: Report All Exceptions. #1021

zooko added the

fixed

label 2010-04-13 04:25:49 +00:00

zooko closed this issue

2010-04-13 04:25:49 +00:00

Sign in to join this conversation.