id	summary	reporter	owner	description	type	status	priority	milestone	component	version	resolution	keywords	cc
55	log_gatherer.furl can be used too early	Brian Warner		"I observed a traceback in Tahoe as it started up.. it looks like it managed
to connect to the log gatherer (running on the same host) extremely quickly,
before the Tahoe node had managed to do a Tub.setLocation. As a result, the
getLogPortFURL call failed, and the node never gave its logport to the
introducer:


{{{
  File ""/usr/lib/python2.5/site-packages/foolscap/reconnector.py"", line 95, in _connected
    cb(rref, *args, **kwargs)
  File ""/usr/lib/python2.5/site-packages/foolscap/pb.py"", line 376, in _log_gatherer_connected
    ignored = self.getLogPortFURL()
  File ""/usr/lib/python2.5/site-packages/foolscap/pb.py"", line 410, in getLogPortFURL
    furlFile=furlfile)
  File ""/usr/lib/python2.5/site-packages/foolscap/pb.py"", line 660, in registerReference
    raise RuntimeError(""you must setLocation() before ""
exceptions.RuntimeError: you must setLocation() before you can registerReference()
}}}

One event later, Tub.setLocation was called.

I think this is partly the result of Tahoe's setup sequence: in Node.__init__
it creates the Tub, setServiceParent's it to the node, then does the
setOption that triggers the use of log_gatherer.furl . This results in the
gatherer code doing Tub.connectTo before Tub.startService is even called.

Once startService happens, the connection occurs quickly. Here are a few
lines of the trace:

{{{
# 18:59:05 0.7869 [0]: UNUSUAL Tub.connectTo((log-gatherer.furl)) queued until Tub.startService called
# 18:59:06 0.4523 [8]: Node.startService
# 18:59:06 0.4527 [9]: Node._startService
# 18:59:06 0.4645 [12]: TubConnector created from ... to log-gatherer..
# [52]: duplicate connection closed
# [64]: negotiationComplete
# [67]: the exception shown above
# [68]: Tub location set
}}}

(some events are missing, this trace was gathered half an hour afterwards
using flogtool tail --catch-up).

I need to examine the sequencing and figure out how the connection managed to
complete before the setLocation was called. It might be a good idea to stall
the gatherer connection until.. what, after setLocation happens? If it ever
happens?
"	defect	closed	major	0.3.0	logging	0.2.4	fixed