[Author Prev][Author Next][Thread Prev][Thread Next][Author Index][Thread Index]
[tor-bugs] #16844 [Tor]: Duplicate directory fetches when on high-latency connection
#16844: Duplicate directory fetches when on high-latency connection
------------------------+---------------------
Reporter: arma | Owner:
Type: defect | Status: new
Priority: normal | Milestone:
Component: Tor | Version:
Keywords: tor-client | Actual Points:
Parent ID: | Points:
------------------------+---------------------
If you start your Tor client with no cached directory info, and on a slow
(high latency) link, you get:
{{{
$ tail -f tordebug-log|grep connected
Aug 09 16:17:12.299 [info] circuit_handle_first_hop(): Next router is
$7EA6EAD6FD83083C538F44038BBFA077587DD755~7EA6EAD6FD83083C538 at
194.109.206.212: Not connected. Connecting.
Aug 09 16:17:12.826 [info] connection_edge_process_relay_cell_not_open():
'connected' received for circid 2747423797 streamid 16685 after 0 seconds.
Aug 09 16:21:57.298 [info] circuit_handle_first_hop(): Next router is
$9695DFC35FFEB861329B9F1AB04C46397020CE31~9695DFC35FFEB861329 at
128.31.0.39: Not connected. Connecting.
Aug 09 16:21:59.099 [info] connection_edge_process_relay_cell_not_open():
'connected' received for circid 4248917890 streamid 42612 after 1 seconds.
Aug 09 16:22:09.711 [info] circuit_handle_first_hop(): Next router is
$332CD489177F202570A7021328A17A91BF823889~332CD489177F202570A at
192.150.94.49: Not connected. Connecting.
Aug 09 16:22:09.711 [info] circuit_handle_first_hop(): Next router is
$90E9E44FD74B98F87F7573F917AE4AF651B86B4C~90E9E44FD74B98F87F7 at
5.102.146.106: Not connected. Connecting.
Aug 09 16:22:09.712 [info] circuit_handle_first_hop(): Next router is
$547C1CDB516798EC66A01F04A5884DCE1A151919~547C1CDB516798EC66A at
87.72.85.217: Not connected. Connecting.
Aug 09 16:22:12.499 [info] connection_edge_process_relay_cell_not_open():
'connected' received for circid 2850575558 streamid 43745 after 0 seconds.
Aug 09 16:23:33.901 [info] connection_edge_process_relay_cell():
'connected' received on circid 2850575558 for streamid 43746, no conn
attached anymore. Ignoring.
Aug 09 16:24:11.599 [info] connection_edge_process_relay_cell_not_open():
'connected' received for circid 4148503990 streamid 17036 after 0 seconds.
Aug 09 16:25:34.306 [info] connection_edge_process_relay_cell():
'connected' received on circid 4148503990 for streamid 17037, no conn
attached anymore. Ignoring.
Aug 09 16:26:29.559 [info] connection_edge_process_relay_cell_not_open():
'connected' received for circid 2948078868 streamid 42748 after 0 seconds.
[...]
}}}
Oh hey, what's this "no conn attached anymore" issue?
{{{
$ grep 43746 tordebug-log
Aug 09 16:22:12.302 [info] connection_ap_handshake_send_begin(): Sending
relay cell 1 on circ 2850575558 to begin stream 43746.
Aug 09 16:22:22.299 [debug] circuit_detach_stream(): Removing stream 43746
from circ 2850575558
Aug 09 16:23:33.901 [debug] connection_edge_process_relay_cell(): Now seen
1433 relay cells here (command 4, stream 43746).
Aug 09 16:23:33.901 [info] connection_edge_process_relay_cell():
'connected' received on circid 2850575558 for streamid 43746, no conn
attached anymore. Ignoring.
Aug 09 16:23:35.799 [debug] connection_edge_process_relay_cell(): Now seen
1434 relay cells here (command 2, stream 43746).
Aug 09 16:23:35.799 [info] connection_edge_process_relay_cell(): data cell
dropped, unknown stream (streamid 43746).
[...]
}}}
We're hitting the 10-second stream timeout in
connection_ap_expire_beginning(), and detaching the stream from the
circuit, and presumably trying it again elsewhere.
But that last line above, "data cell dropped", is especially bad news for
us -- we get the whole answer, and ignore it all, since we sent an 'end'
cell changing our mind but the answer was already coming at us.
This situation comes up because of the optimistic data feature -- we get
the answer to our request bundled with the 'connected' cell, which is a
feature except in the case where we canceled (and then forgot about) the
stream.
For people trying to bootstrap their Tor on a low-bandwidth high-latency
network connection, I bet this landmine will be especially frustrating,
since you will be clogging your network connection with directory
information that you will discard, which in turn will delay the receipt of
the other directory information.
You can reproduce the bug on your own, even if you have a great network
connection, by starting your Tor with "bandwidthrate 2000 bandwidthburst
5000".
--
Ticket URL: <https://trac.torproject.org/projects/tor/ticket/16844>
Tor Bug Tracker & Wiki <https://trac.torproject.org/>
The Tor Project: anonymity online
_______________________________________________
tor-bugs mailing list
tor-bugs@xxxxxxxxxxxxxxxxxxxx
https://lists.torproject.org/cgi-bin/mailman/listinfo/tor-bugs