[tor-bugs] #24367 [Core Tor/Tor]: Changing pluggable transports (during start-up) in Tor Browser is broken

Thu Dec 14 14:33:51 UTC 2017

#24367: Changing pluggable transports (during start-up) in Tor Browser is broken
-------------------------------------------------+-------------------------
 Reporter:  gk                                   |          Owner:  (none)
     Type:  defect                               |         Status:
                                                 |  needs_information
 Priority:  Medium                               |      Milestone:  Tor:
                                                 |  0.3.2.x-final
Component:  Core Tor/Tor                         |        Version:  Tor:
                                                 |  0.3.0.1-alpha
 Severity:  Normal                               |     Resolution:
 Keywords:  030-backport, 031-backport,          |  Actual Points:
  regression, tor-bridge-client, s8-errors,      |
  tbb-wants                                      |
Parent ID:                                       |         Points:  0.5
 Reviewer:                                       |        Sponsor:
                                                 |  Sponsor8-can
-------------------------------------------------+-------------------------

Comment (by nickm):

 Okay!  Let's look through these logs to see what happens to our favorite
 bridge, A09D536DD1752D542E1FBB3C9CE4449D51298239, at 82.212.101.3.

 {{{
 Dec 14 11:46:18.000 [info] get_transport_by_bridge_addrport(): Looked up
 transport for 83.212.101.3:80: found obfs3.
 ...
 Dec 14 11:46:19.000 [info] make_guard_confirmed(): Marking [bridge]
 ($A09D536DD1752D542E1FBB3C9CE4449D51298239) at 83.212.101.3:80 as a
 confirmed guard (index 0)
 Dec 14 11:46:19.000 [info] entry_guards_update_primary(): Primary entry
 guards have changed. New primary guard list is:
 Dec 14 11:46:19.000 [info] entry_guards_update_primary():   1/3: [bridge]
 ($A09D536DD1752D542E1FBB3C9CE4449D51298239) at 83.212.101.3:80 (confirmed)
 Dec 14 11:46:19.000 [info] entry_guards_update_primary():   2/3: [bridge]
 ($4C331FA9B3D1D6D8FB0D8FBBF0C259C360D97E6A) at 109.105.109.163:47779
 Dec 14 11:46:19.000 [info] entry_guards_update_primary():   3/3: [bridge]
 ($1E05F577A0EC0213F971D81BF4D86A9E4E8229ED) at 109.105.109.163:38980
 ...
 Dec 14 11:46:19.000 [notice] new bridge descriptor 'LeifEricson' (fresh):
 $A09D536DD1752D542E1FBB3C9CE4449D51298239~LeifEricson at 83.212.101.3
 ... (time passes; tor bootstraps; we change the options) ...
 Dec 14 11:46:31.000 [info] options_act(): Changed to using entry guards or
 bridges, or changed preferred or excluded node lists. Abandoning previous
 circuits.
 Dec 14 11:46:31.000 [info] sampled_guards_update_from_consensus():
 Updating sampled guard status based on received consensus.
 ...
 Dec 14 11:46:31.000 [info] sampled_guards_update_from_consensus(): Sampled
 guard [bridge] ($A09D536DD1752D542E1FBB3C9CE4449D51298239) at
 83.212.101.3:80 is now unlisted.
 ...
 Dec 14 11:46:31.000 [info] entry_guards_update_primary(): Primary entry
 guards have changed. New primary guard list is:
 Dec 14 11:46:31.000 [info] entry_guards_update_primary():   1/3: [bridge]
 ($91A6354697E6B02A386312F68D82CF86824D3606) at 85.31.186.26:443
 Dec 14 11:46:31.000 [info] entry_guards_update_primary():   2/3: [bridge]
 ($C73ADBAC8ADFDBF0FC0F3F4E8091C0107D093716) at 154.35.22.9:12166
 Dec 14 11:46:31.000 [info] entry_guards_update_primary():   3/3: [bridge]
 ($A832D176ECD5C7C6B58825AE22FC4C90FA249637) at 154.35.22.11:80
 ...
 Dec 14 11:46:33.000 [info] sample_reachable_filtered_entry_guards():
 Trying to sample a reachable guard: We know of 20 in the USABLE_FILTERED
 set.
 Dec 14 11:46:33.000 [info] sample_reachable_filtered_entry_guards():
 (After filters [17], we have 1 guards to consider.)
 Dec 14 11:46:33.000 [info] sample_reachable_filtered_entry_guards():
 (Selected [bridge] ($A09D536DD1752D542E1FBB3C9CE4449D51298239) at
 83.212.101.3:50002.)
 Dec 14 11:46:33.000 [info] select_entry_guard_for_circuit(): No primary or
 confirmed guards available. Selected random guard [bridge]
 ($A09D536DD1752D542E1FBB3C9CE4449D51298239) at 83.212.101.3:50002 for
 circuit. Will try other guards before using this circuit.
 Dec 14 11:46:33.000 [info] get_transport_by_bridge_addrport(): Looked up
 transport for 83.212.101.3:80: no such bridge found.
 ...
 Dec 14 11:46:33.000 [info] connection_or_note_state_when_broken():
 Connection died in state 'handshaking (TLS) with SSL state SSLv3/TLS write
 client hello in HANDSHAKE'
 Dec 14 11:46:33.000 [warn] Problem bootstrapping. Stuck at 85%: Finishing
 handshake with first hop. (DONE; DONE; count 1; recommendation warn; host
 A09D536DD1752D542E1FBB3C9CE4449D51298239 at 83.212.101.3:80)
 }}}

 So, two interesting things here:

 1. Why did we pick LeifEricson for our connection the second time, after
 we had chosen 3 other primary guards?  The line `After filters [17], we
 have 1 guards to consider.` is suggestive here.  Note that 17 is hex here,
 so we are setting every SAMPLE_EXCLUDE_CONFIRMED, SAMPLE_EXCLUDE_PRIMARY,
 SAMPLE_EXCLUDE_PENDING, and SAMPLE_EXCLUDE_NO_DESCRIPTOR.  This means
 we're calling `sample_reachable_filtered_entry_guards()` from
 select_entry_guard_for_circuit with GUARD_USAGE_TRAFFIC set.  But we have
 no descriptors for any of our primary guards, so we're not using any of
 them.  Whoops!

 2. When we connect to LeifEricson, we decide that it doesn't have a
 transport.  But look what's happening here.  We say that we've selected
 `83.212.101.3:50002` for the circuit, but when we look up the transport,
 we say `Looked up transport for 83.212.101.3:80`.  So we're looking up the
 wrong transport entirely.

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