#710 closed defect (fixed)

exception from binascii.unhexlify when handling announcements on Python 2.4.1

Reported by: exarkun Owned by: somebody
Priority: major Milestone: undecided
Component: code Version: 1.4.1
Keywords: error logging Cc:
Launchpad Bug:

Description

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.

Change History (7)

comment:1 Changed at 2009-05-19T02:45:13Z by zooko

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?

comment:2 Changed at 2009-05-19T03:42:42Z by warner

  • Summary changed 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

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

comment:3 Changed at 2009-05-19T03:43:17Z by warner

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

comment:4 Changed at 2009-05-19T20:03:53Z by zooko

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

comment:5 Changed at 2009-07-11T11:24:22Z by warner

  • Component changed from unknown to code
  • Owner changed from nobody to somebody

comment:6 Changed at 2010-04-13T00:54:34Z by davidsarah

  • Keywords error logging added

comment:7 Changed at 2010-04-13T04:25:49Z by zooko

  • Resolution set to fixed
  • Status changed from new to closed

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

Note: See TracTickets for help on using tickets.