[tor-bugs] #22881 [Core Tor/Tor]: Unreachable relays launch multiple testing circuits per second

[Tor Bug Tracker & Wiki]

#22881: Unreachable relays launch multiple testing circuits per second
------------------------------+---------------------------------------
     Reporter:  teor          |      Owner:
         Type:  defect        |     Status:  new
     Priority:  Medium        |  Milestone:  Tor: 0.3.2.x-final
    Component:  Core Tor/Tor  |    Version:  Tor: 0.3.1.4-alpha
     Severity:  Normal        |   Keywords:  tor-relay, technical-debt
Actual Points:                |  Parent ID:
       Points:                |   Reviewer:
      Sponsor:                |
------------------------------+---------------------------------------
 When I start a relay behind a NAT with:
 {{{
 tor ORPort 12345 PublishServerDescriptor 0 Log "info stderr"
 }}}

 I see it launch multiple testing circuits every second.
 This places a lot of load on the network: it should use exponential
 backoff instead.

 We wanted to fix things like this as part of #4580 or #8625, but it seems
 we missed this case. Maybe we need to do exponential backoff at a lower
 level than directory requests?

 Here are the log messages for one second:
 {{{
 Jul 11 19:07:20.000 [info] circuit_finish_handshake: Finished building
 circuit hop:
 Jul 11 19:07:20.000 [info] internal circ (length 3, last hop Unnamed):
 $3E13E2EB87CCF5690564EE33E9F9F9F80B229FBB(open)
 $34D2E3C853C6C60A5CCD93E363CD524BA962D3D6(open)
 $4345CA43B1F4E1C08271F8FA907B4AE890591111(closed)
 Jul 11 19:07:20.000 [info] circuit_send_next_onion_skin: Sending extend
 relay cell.
 Jul 11 19:07:20.000 [info] consider_testing_reachability: Testing
 reachability of my ORPort: 124.171.199.202:12345.
 Jul 11 19:07:20.000 [info] onion_pick_cpath_exit: Using requested exit
 node '$4345CA43B1F4E1C08271F8FA907B4AE890591111~Unnamed at
 124.171.199.202'
 Jul 11 19:07:20.000 [info] extend_info_from_node: Not including the
 ed25519 ID for $7202A9449EC084A305EB19A2A2A0E245FA8C111E~jonasBebe2 at
 193.200.241.195, since it won't  be able to authenticate it.
 Jul 11 19:07:20.000 [info] extend_info_from_node: Not including the
 ed25519 ID for $CA618B8FB8FDF1C670BA7139B1E3EFCE25771551~bentleywashere3
 at 198.199.90.205, since it won't  be able to authenticate it.
 Jul 11 19:07:20.000 [info] circuit_handle_first_hop: Next router is
 [scrubbed]: Not connected. Connecting.
 Jul 11 19:07:20.000 [info] connection_or_set_identity_digest: Set identity
 digest for 0x7fcefb6f1cd0 ([scrubbed]):
 7202A9449EC084A305EB19A2A2A0E245FA8C111E <unset>.
 Jul 11 19:07:20.000 [info] connection_or_set_identity_digest:
 (Previously: 0000000000000000000000000000000000000000 <unset>)
 Jul 11 19:07:20.000 [info] channel_tls_process_versions_cell: Negotiated
 version 4 with [scrubbed]:443; Sending cells: CERTS
 Jul 11 19:07:20.000 [info] connection_or_client_learned_peer_id: learned
 peer id for 0x7fcefaf87090 ([scrubbed]):
 650ABAB06345EEC29BB0B5322C27DC6E5E888019, <null>
 Jul 11 19:07:20.000 [info] channel_tls_process_certs_cell: Got some good
 certificates from [scrubbed]:443: Authenticated it with RSA
 Jul 11 19:07:20.000 [info] channel_tls_process_auth_challenge_cell: Got an
 AUTH_CHALLENGE cell from [scrubbed]:443: Sending authentication type 1
 Jul 11 19:07:20.000 [info] circuit_send_next_onion_skin: First hop:
 finished sending CREATE cell to
 '$650ABAB06345EEC29BB0B5322C27DC6E5E888019~supc0re at 217.160.15.198'
 Jul 11 19:07:20.000 [info] channel_tls_process_netinfo_cell: Got good
 NETINFO cell from [scrubbed]:443; OR connection is now open, using
 protocol version 4. Its ID digest is
 650ABAB06345EEC29BB0B5322C27DC6E5E888019. Our address is apparently
 124.171.199.202.
 Jul 11 19:07:20.000 [info] circuit_expire_building: Abandoning circ 198
 37.187.3.106:443:3622949943 (state 0,0:doing handshakes, purpose 18, len
 3)
 Jul 11 19:07:20.000 [info] internal circ (length 3, last hop Unnamed):
 $597422ADDADAF5FB2727369B7EFC7AA76B89D613(open)
 $E7578F3484C8ABD5FB3130E31F30C167206BCA7E(open)
 $4345CA43B1F4E1C08271F8FA907B4AE890591111(waiting for keys)
 Jul 11 19:07:20.000 [info] circuit_testing_failed: Our testing circuit (to
 see if your ORPort is reachable) has failed. I'll try again later.
 Jul 11 19:07:20.000 [info] circuit_finish_handshake: Finished building
 circuit hop:
 Jul 11 19:07:20.000 [info] internal circ (length 3, last hop Unnamed):
 $650ABAB06345EEC29BB0B5322C27DC6E5E888019(open)
 $45D6A70CAEC4A2C2FCE46A127E461FF852A41280(closed)
 $4345CA43B1F4E1C08271F8FA907B4AE890591111(closed)
 Jul 11 19:07:20.000 [info] circuit_send_next_onion_skin: Sending extend
 relay cell.
 }}}

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