unhandled errors due to "bad connection hint '<IP address>' (hostname, but no port)"

[daira]

The public grid introducer was for a time logging unhandled errors to twistd.log that appear to be due to bad connection hints.

This happened for connections from one IP continuously between 2013-03-01 18:58:06-0500 and 2013-04-09 18:56:33-0400, and then for a different IP for a short time at 2013-05-12 10:54:40-0400. Every two seconds the following is logged:

2013-04-09 18:11:43-0400 [-] Unhandled Error
Traceback (most recent call last):
File "C:\Users\PRabahy\Downloads\allmydata-tahoe-1.9.2\support\Lib\site-packages\twisted-11.0.0-py2.7-win32.egg\twisted\internet\defer.py", line 542, in _runCallbacks
 current.result = callback(current.result, *args, **kw)
File "C:\Users\PRabahy\Downloads\allmydata-tahoe-1.9.2\support\Lib\site-packages\foolscap-0.6.4-py2.7.egg\foolscap\broker.py", line 554, in <lambda>
 d.addCallback(lambda res: self._doCall(delivery))
File "C:\Users\PRabahy\Downloads\allmydata-tahoe-1.9.2\support\Lib\site-packages\foolscap-0.6.4-py2.7.egg\foolscap\broker.py", line 589, in _doCall
 return obj.doRemoteCall(delivery.methodname, args, kwargs)
File "C:\Users\PRabahy\Downloads\allmydata-tahoe-1.9.2\support\Lib\site-packages\foolscap-0.6.4-py2.7.egg\foolscap\referenceable.py", line 60, in doRemoteCall
 res = meth(*args, **kwargs)
--- <exception caught here> ---
File "c:\users\prabahy\downloads\allmydata-tahoe-1.9.2\src\allmydata\introducer\server.py", line 86, in remote_publish
 self._publish(announcement)
File "c:\users\prabahy\downloads\allmydata-tahoe-1.9.2\src\allmydata\introducer\server.py", line 97, in _publish
 nodeid = b32decode(SturdyRef(furl).tubID.upper())
File "C:\Users\PRabahy\Downloads\allmydata-tahoe-1.9.2\support\Lib\site-packages\foolscap-0.6.4-py2.7.egg\foolscap\referenceable.py", line 875, in __init__
 decode_furl(url)
File "C:\Users\PRabahy\Downloads\allmydata-tahoe-1.9.2\support\Lib\site-packages\foolscap-0.6.4-py2.7.egg\foolscap\referenceable.py", line 828, in decode_furl
 location_hints = decode_location_hints(hints)
File "C:\Users\PRabahy\Downloads\allmydata-tahoe-1.9.2\support\Lib\site-packages\foolscap-0.6.4-py2.7.egg\foolscap\referenceable.py", line 787, in decode_location_hints
 "(hostname, but no port)" % hint_s)
foolscap.referenceable.BadFURLError: bad connection hint '<IP redacted>'
 (hostname, but no port)
[The above entry is sometimes repeated. The actual IP is logged.]

2013-04-09 18:11:43-0400 [Negotiation,85508,<IP redacted>]
Banana.reportReceiveError: an error occured during receive

2013-04-09 18:11:43-0400 [Negotiation,85508,<IP redacted>]
Unhandled Error Traceback (most recent call last):
File "C:\Users\PRabahy\Downloads\allmydata-tahoe-1.9.2\support\Lib\site-packages\twisted-11.0.0-py2.7-win32.egg\twisted\python\context.py", line 81, in callWithContext
 return func(*args,**kw)
File "C:\Users\PRabahy\Downloads\allmydata-tahoe-1.9.2\support\Lib\site-packages\twisted-11.0.0-py2.7-win32.egg\twisted\internet\selectreactor.py", line 146, in _doReadOrWrite
 why = getattr(selectable, method)()
File "C:\Users\PRabahy\Downloads\allmydata-tahoe-1.9.2\support\Lib\site-packages\twisted-11.0.0-py2.7-win32.egg\twisted\internet\tcp.py", line 137, in doRead
 return Connection.doRead(self)
File "C:\Users\PRabahy\Downloads\allmydata-tahoe-1.9.2\support\Lib\site-packages\twisted-11.0.0-py2.7-win32.egg\twisted\internet\tcp.py", line 460, in doRead
 rval = self.protocol.dataReceived(data)
--- <exception caught here> ---
File "C:\Users\PRabahy\Downloads\allmydata-tahoe-1.9.2\support\Lib\site-packages\foolscap-0.6.4-py2.7.egg\foolscap\banana.py", line 639, in dataReceived
 self.handleData(chunk)
File "C:\Users\PRabahy\Downloads\allmydata-tahoe-1.9.2\support\Lib\site-packages\foolscap-0.6.4-py2.7.egg\foolscap\banana.py", line 870, in handleData
 self.handleClose(count)
File "C:\Users\PRabahy\Downloads\allmydata-tahoe-1.9.2\support\Lib\site-packages\foolscap-0.6.4-py2.7.egg\foolscap\banana.py", line 1068, in handleClose
 obj, ready_deferred = child.receiveClose()
File "C:\Users\PRabahy\Downloads\allmydata-tahoe-1.9.2\support\Lib\site-packages\foolscap-0.6.4-py2.7.egg\foolscap\referenceable.py", line 249, in receiveClose
 self.url)
File "C:\Users\PRabahy\Downloads\allmydata-tahoe-1.9.2\support\Lib\site-packages\foolscap-0.6.4-py2.7.egg\foolscap\broker.py", line 351, in getTrackerForYourReference
 tracker = trackerclass(self, clid, url, interfaceName)
File "C:\Users\PRabahy\Downloads\allmydata-tahoe-1.9.2\support\Lib\site-packages\foolscap-0.6.4-py2.7.egg\foolscap\referenceable.py", line 292, in __init__
 url_tubid = SturdyRef(url).getTubRef().getTubID()
File "C:\Users\PRabahy\Downloads\allmydata-tahoe-1.9.2\support\Lib\site-packages\foolscap-0.6.4-py2.7.egg\foolscap\referenceable.py", line 875, in __init__
 decode_furl(url)
File "C:\Users\PRabahy\Downloads\allmydata-tahoe-1.9.2\support\Lib\site-packages\foolscap-0.6.4-py2.7.egg\foolscap\referenceable.py", line 828, in decode_furl
 location_hints = decode_location_hints(hints)
File "C:\Users\PRabahy\Downloads\allmydata-tahoe-1.9.2\support\Lib\site-packages\foolscap-0.6.4-py2.7.egg\foolscap\referenceable.py", line 787, in decode_location_hints
 "(hostname, but no port)" % hint_s)
foolscap.referenceable.BadFURLError: bad connection hint '<IP redacted>'
 (hostname, but no port)

The same error is also seen by two users in this tahoe-dev thread: ​https://tahoe-lafs.org/pipermail/tahoe-dev/2012-December/007893.html (continued at ​https://tahoe-lafs.org/pipermail/tahoe-dev/2013-January/007913.html). From that thread, it seems to be due to a bug or a misconfiguration that is less obvious than just omitting the port in tahoe.cfg.

[daira]

There are two problems here: whatever is causing the invalid connection hints, and the spamming of twistd.log (the pubgrid introducer's logs directory grew to "almost 3 GB"). #1927 is another case where we end up doing the latter.

[PRabahy]

Example log file