[tor-bugs] #21974 [Core Tor/Tor]: Race: Tor declares controlport listener open before it has written its controlcookie to disk

[Tor Bug Tracker & Wiki]

#21974: Race: Tor declares controlport listener open before it has written its
controlcookie to disk
--------------------------+---------------------
 Reporter:  arma          |          Owner:
     Type:  defect        |         Status:  new
 Priority:  Medium        |      Milestone:
Component:  Core Tor/Tor  |        Version:
 Severity:  Normal        |     Resolution:
 Keywords:                |  Actual Points:
Parent ID:                |         Points:
 Reviewer:                |        Sponsor:
--------------------------+---------------------
Description changed by arma:

Old description:

> 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().
>
> So:
>
> 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
> of graph of what has to happen before what is complicated, and I bet
> there are bugs in the current order of things. It would be a swell
> project for somebody to make a list of all the things we do at startup,
> and figure out their dependencies, and sort them into "waves" or
> something, and then refactor the stuff in config.c so it matches the new
> world order. I'll make a new ticket for that one.

New description:

 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().

 So:

 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 #21975 for this
 bigger refactor idea.

--

--
Ticket URL: <https://trac.torproject.org/projects/tor/ticket/21974#comment:2>
Tor Bug Tracker & Wiki <https://trac.torproject.org/>
The Tor Project: anonymity online