GitLab

If a stream is attached to a circuit with purpose CIRCUIT_PURPOSE_CONTROLLER, a RELAY_BEGIN cell will be sent with an empty address. This is because of a bug in connection_ap_handshake_send_begin().

tor_snprintf(payload,RELAY_PAYLOAD_SIZE, "%s:%d",
             (circ->base_.purpose == CIRCUIT_PURPOSE_C_GENERAL) ?
               ap_conn->socks_request->address : "",
             ap_conn->socks_request->port);

The function seems to assume that if it's not a general purpose circuit, then it is a rendezvous circuit. This was added in commit 5b6099e8.

There is a similar error in a logging statement in link_apconn_to_circ() which logs that a controller circuit is to a "hidden service", even if the circuit is actually to an exit.

log_info(LD_APP, "Looks like completed circuit to %s %s allow "
         "optimistic data for connection to %s",
         circ->base_.purpose == CIRCUIT_PURPOSE_C_GENERAL ?
           /* node_describe() does the right thing if exitnode is NULL */
           safe_str_client(node_describe(exitnode)) :
           "hidden service",
         apconn->may_use_optimistic_data ? "does" : "doesn't",
         safe_str_client(apconn->socks_request->address));

And another example is in connection_ap_expire_beginning() which logs the warning:

[warn] connection_ap_expire_beginning(): Bug: circuit->purpose == CIRCUIT_PURPOSE_C_GENERAL failed. The purpose on the circuit was Circuit made by controller; it was in state open, path_state new. (on Tor 0.4.2.5 )

The relay which receives the RELAY_BEGIN cell will then make a dns request for the address "". Libevent will eventually give up after 3 tries (global_timeout.tv_sec = 5 seconds per try).

Feb 01 01:11:41.369 [info] launch_resolve(): Launching eventdns request for ""
Feb 01 01:11:41.369 [info] evdns_log_cb(): eventdns: Resolve requested.
...
Feb 01 01:11:56.378 [info] eventdns: Giving up on request 0x5565c825ac80; tx_count==3

Back at the tor client, the streams detach (reason=timeout, remote_reason=none) after some time, then the controller circuits close a few seconds later (a total of 25 seconds after the streams were first attached) with:

[info] circuit_mark_for_close_(): Circuit 2262666673 (id: 15) marked for close at src/core/or/circuituse.c:1507 (orig reason: 9, new reason: 0)

Finally a SOCKS error code 0x5b is returned to the application after some long amount of time.

In summary, the main problems are:

(1) Tor has checks for only CIRCUIT_PURPOSE_C_GENERAL when it should be checking for other circuit purposes like CIRCUIT_PURPOSE_CONTROLLER. (2) Tor attempts to resolve the address of an empty string. (3) (Maybe?) It takes a long time before the application is notified that the SOCKS connection was unsuccessful.

Thanks to arma for help debugging this.