Race: Tor declares controlport listener open before it has written its controlcookie to disk
When I start my Tor client, I see this in its logs:
Apr 17 00:49:35.238 [notice] Opening Control listener on 127.0.0.1:9051
In fact, controllers like txtorcon and nyx might imagine that they can use this log line as an indication that the control port is up and usable: https://github.com/meejah/txtorcon/blob/master/txtorcon/controller.py#L131
But looking through Tor's code, that log line comes from connection_listener_new() which comes from retry_listener_ports() which comes from retry_all_listeners() which comes from options_act_reversible(), which gets called before options_act(), which is where we call init_control_cookie_authentication().
A) Is there a recommendation we can make to controllers about how they can know when our control port is ready? I guess the answer right now is "when the control port is open and also when the control cookie file is there"? Is that accurate? Should we worry about races writing/reading the cookie file?
B) Should we rearrange the order of stuff in options_act*() so things are in place for the control port when we do the log message indicating that it's open?
C) We sure have a bunch of stuff we do at startup now, and the dependency graph of what has to happen before what is complicated, and I bet there are bugs in the current order of things. I've opened legacy/trac#21975 (moved) for this bigger refactor idea.