[tor-bugs] #27066 [Core Tor/Tor]: circuit_build_times_update_alpha(): Bug: Could not determine largest build time

Sun Aug 12 11:25:56 UTC 2018

#27066: circuit_build_times_update_alpha(): Bug: Could not determine largest build
time
---------------------------------------+-----------------------------------
 Reporter:  cstest                     |          Owner:  (none)
     Type:  defect                     |         Status:  new
 Priority:  Medium                     |      Milestone:  Tor:
                                       |  0.3.5.x-final
Component:  Core Tor/Tor               |        Version:  Tor: 0.3.3.9
 Severity:  Normal                     |     Resolution:
 Keywords:  034-backport 033-backport  |  Actual Points:
Parent ID:                             |         Points:
 Reviewer:                             |        Sponsor:
---------------------------------------+-----------------------------------

Comment (by cstest):

 Prior to CBT bug line here are warning lines that happened after enabling
 v3 domains.

 {{{
 Aug 07 00:02:15.000 [notice] Our hidden services received 41808 v2 and 18
 v3 INTRODUCE2 cells and attempted to launch 42259 rendezvous circuits.
 (this is almost exact time when I have enabled v3 domains and for several
 hours both v3 and v2 domains were working together)

 Aug 07 03:01:23.000 [warn] Error launching circuit to node
 $E0EAA536856FBD3C3AB46C2BAA398E7CDFDAFF5D~as44194a36s01 at 77.87.50.6 for
 service v2domain...
 Aug 07 03:01:23.000 [warn] Error launching circuit to node
 $B247BA9E0AEA93E6D7BF4080CFBB964034AF2B28~kitten2 at 163.172.218.10 for
 service v2domain...
 Aug 07 03:01:23.000 [warn] Error launching circuit to node
 $C793A33F28826D1F184504312C668EA8157AEF28~Unnamed at 217.182.95.221 for
 service v2domain...
 Aug 07 03:01:23.000 [warn] Error launching circuit to node
 $71DA45C2AF1551F32CA83E2AD2D5ADA684505391~Unnamed at 34.241.138.212 for
 service v2domain...
 Aug 07 03:01:23.000 [warn] Error launching circuit to node
 $F3FA0D45D35E987484848345F8D92AB1D883889B~Hermes at 86.29.190.220 for
 service v2domain...
 Aug 07 03:01:23.000 [warn] Error launching circuit to node
 $4204C1B166CCE784CF38B02E4A0C94640A2BECA2~TheEpTic2 at 51.15.51.36 for
 service v2domain...
 Aug 07 03:01:23.000 [warn] Error launching circuit to node
 $DB510E2AA40A462AD77DB83617F6F340E234D952~Unnamed at 206.189.24.66 for
 service v2domain...
 Aug 07 03:01:23.000 [warn] Error launching circuit to node
 $74D6D1E8BF5159066768F48C1EA4951C9C97BEF9~lara at 148.251.42.164 for
 service v2domain...
 (above lines are just for one v2 domain but they have been repeated for
 other v2 domains too)

 Aug 07 03:01:41.000 [notice] Your network connection speed appears to have
 changed. Resetting timeout to 60s after 18 timeouts and 409 buildtimes.
 Aug 07 03:01:43.000 [warn] Failed to find node for hop #1 of our path.
 Discarding this circuit.
 Aug 07 03:01:44.000 [notice] Our circuit 0 (id: 641032) died due to an
 invalid selected path, purpose Hidden service: Establishing introduction
 point. This may be a torrc configuration issue, or a bug.
 (all lines in torrc are simple except one line "MaxClientCircuitsPending
 256")

 Aug 07 03:12:39.000 [notice] Your Guard loki
 ($5A6451D4E4B4FFDE0B2682D8D8DAA0D10A500066) is failing more circuits than
 usual. Most likely this means the Tor network is overloaded. Success
 counts are 184/267. Use counts are 132/132. 184 circuits completed, 0 were
 unusable, 0 collapsed, and 2 timed out. For reference, your timeout cutoff
 is 463 seconds.
 Aug 07 03:13:43.000 [warn] Giving up launching first hop of circuit to
 rendezvous point
 $5FA794BF301AF35E4AED185E939CBA9D2CFC2360~$5FA794BF301AF35E4A at
 192.42.132.106 for service v2....
 Aug 07 03:13:43.000 [warn] Giving up launching first hop of circuit to
 rendezvous point
 $7961C9991F022C8A363FD440CA395D47DB5D44D5~$7961C9991F022C8A36 at
 51.254.35.151 for service v2..
 Aug 07 03:13:43.000 [warn] Giving up on launching a rendezvous circuit to
 $DBAD17D706E2B6D5D917C2077961750513BDF879~ at 109.236.90.209 for hidden
 service v3....
 Aug 07 03:13:43.000 [warn] Giving up on launching a rendezvous circuit to
 $C13D13DE33C2DAB4AF849014ECAB962A328D6806~ at 85.10.216.118 for hidden
 service v3....
 Aug 07 03:13:44.000 [warn] Giving up on launching a rendezvous circuit to
 $372082F3E01DE6A6333D30329C6903A19D0E8E87~ at 176.193.113.234 for hidden
 service v3....
 ("giving up" lines were repeating aprox 50 times for the same 4-5 v3
 domains and 2 v2 domains)

 Aug 07 03:15:31.000 [warn] Failed to find node for hop #1 of our path.
 Discarding this circuit.
 Aug 07 03:15:37.000 [notice] Extremely large value for circuit build
 timeout: 157s. Assuming clock jump. Purpose 14 (Measuring circuit timeout)
 Aug 07 03:15:37.000 [notice] Extremely large value for circuit build
 timeout: 147s. Assuming clock jump. Purpose 14 (Measuring circuit timeout)
 Aug 07 03:15:37.000 [notice] Extremely large value for circuit build
 timeout: 157s. Assuming clock jump. Purpose 14 (Measuring circuit timeout)
 Aug 07 03:15:37.000 [notice] Extremely large value for circuit build
 timeout: 154s. Assuming clock jump. Purpose 14 (Measuring circuit timeout)
 (105 lines of "Extremely large value for circuit build timeout")
 Aug 07 03:15:37.000 [notice] Your network connection speed appears to have
 changed. Resetting timeout to 60s after 18 timeouts and 1000 buildtimes.

 Aug 07 04:45:49.000 [warn] circuit_build_times_update_alpha(): Bug: Could
 not determine largest build time (0). Xm is 7525ms and we've abandoned 996
 out of 1000 circuits. (on Tor 0.3.3.9 )
 }}}

 There are no log lines as in #27049. No "Tor has not observed any network
 activity" lines.

 I do not know what triggers this bug so I can't repeat it but this
 happened two times.

 Could that "MaxClientCircuitsPending 256" in torrc have any influence on
 this?

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