[tor-commits] [flashproxy/master] Use "LearnCircuitBuildTimeout 0" in exercise-flashproxy.
dcf at torproject.org
dcf at torproject.org
Sun Feb 12 19:07:44 UTC 2012
commit a1bf13ae243428224fa49afc85add3e1b4d31e29
Author: David Fifield <david at bamsoftware.com>
Date: Sun Feb 12 10:54:49 2012 -0800
Use "LearnCircuitBuildTimeout 0" in exercise-flashproxy.
flashproxy-exercise, despite getting a proxy in over 99% of cases, only
bootstraps in about 75% of them. I suspect this is because of too-short
timeouts. 75% is close to the designed-for 80% described here (2.4.1):
https://gitweb.torproject.org/torspec.git?a=blob_plain;hb=HEAD;f=path-spec.txt
Here are sample logs with extra circuit_expire_building debugging added
by me. A successful run (note "it's still young"):
Feb 12 00:13:21.000 [info] circuit_build_times_set_timeout(): Based on 1000 circuit times, it looks like we don't need to wait so long for circuits to finish. We will now assume a circuit is too slow to use after waiting 5 seconds.
Feb 12 00:13:21.000 [info] circuit_build_times_set_timeout(): Circuit timeout data: 5051.643548ms, 60000.000000ms, Xm: 3092, a: 3.278575, r: 0.223000
...
Feb 12 00:13:23.000 [notice] Bootstrapped 10%: Finishing handshake with directory server.
Feb 12 00:13:23.000 [info] connection_edge_process_inbuf(): data from edge while in 'waiting for circuit' state. Leaving it on buffer.
Feb 12 00:13:23.000 [info] connection_edge_process_inbuf(): data from edge while in 'waiting for circuit' state. Leaving it on buffer.
Feb 12 00:13:23.000 [info] connection_read_proxy_handshake(): Proxy Client: connection to 127.0.0.1:9001 successful
Feb 12 00:13:23.000 [info] connection_tls_continue_handshake(): Client got a v3 cert! Moving on to v3 handshake.
Feb 12 00:13:24.000 [info] circuit_expire_building(): created is 1329030803.139067; cutoff is 1329030801.611628 (2.526000).
Feb 12 00:13:24.000 [info] circuit_expire_building(): it's still young (1.527439 seconds remain).
Feb 12 00:13:24.000 [info] command_process_versions_cell(): Negotiated version 3 with [scrubbed]:9001; Sending cells: NETINFO
Feb 12 00:13:24.000 [info] connection_or_client_learned_peer_id(): Connected to router $7C03D29CA58BE8EED5F483F31A2DEDF6FD7CC444 at 127.0.0.1:9001 without knowing its key. Hoping for the best.
Feb 12 00:13:24.000 [notice] Learned fingerprint 7C03D29CA58BE8EED5F483F31A2DEDF6FD7CC444 for bridge 127.0.0.1:9001
Feb 12 00:13:24.000 [info] command_process_certs_cell(): Got some good certificates from [scrubbed]:9001: Authenticated it.
Feb 12 00:13:24.000 [notice] Bootstrapped 15%: Establishing an encrypted directory connection.
Feb 12 00:13:24.000 [info] circuit_send_next_onion_skin(): First hop: finished sending CREATE_FAST cell to '<unnamed>'
Feb 12 00:13:24.000 [info] command_process_netinfo_cell(): Got good NETINFO cell from [scrubbed]:9001; OR connection is now open, using protocol version 3. Its ID digest is 7C03D29CA58BE8EED5F483F31A2DEDF6FD7CC444
Feb 12 00:13:25.000 [info] circuit_finish_handshake(): Finished building fast circuit hop:
Feb 12 00:13:25.000 [info] exit circ (length 1, last hop 0000000000000000000000000000000000000000): $0000000000000000000000000000000000000000(open)
Feb 12 00:13:25.000 [info] circuit_send_next_onion_skin(): circuit built!
Feb 12 00:13:25.000 [notice] Bootstrapped 20%: Asking for networkstatus consensus.
And an unsuccessful run (note "too old"→"Abandoning circ"→"no running bridges
known"):
Feb 12 03:13:21.000 [info] circuit_build_times_set_timeout(): Based on 1000 circuit times, it looks like we don't need to wait so long for circuits to finish. We will now assume a circuit is too slow to use after waiting 5 seconds.
Feb 12 03:13:21.000 [info] circuit_build_times_set_timeout(): Circuit timeout data: 5056.857311ms, 60000.000000ms, Xm: 3193, a: 3.500420, r: 0.219000
...
Feb 12 03:13:23.000 [notice] Bootstrapped 10%: Finishing handshake with directory server.
Feb 12 03:13:23.000 [info] connection_edge_process_inbuf(): data from edge while in 'waiting for circuit' state. Leaving it on buffer.
Feb 12 03:13:23.000 [info] connection_edge_process_inbuf(): data from edge while in 'waiting for circuit' state. Leaving it on buffer.
Feb 12 03:13:23.000 [info] connection_read_proxy_handshake(): Proxy Client: connection to 127.0.0.1:9001 successful
Feb 12 03:13:24.000 [info] circuit_expire_building(): created is 1329041603.765838; cutoff is 1329041602.236589 (2.528000).
Feb 12 03:13:24.000 [info] circuit_expire_building(): it's still young (1.529249 seconds remain).
Feb 12 03:13:25.000 [info] connection_tls_continue_handshake(): Client got a v3 cert! Moving on to v3 handshake.
Feb 12 03:13:25.000 [info] circuit_expire_building(): created is 1329041603.765838; cutoff is 1329041603.237411 (2.528000).
Feb 12 03:13:25.000 [info] circuit_expire_building(): it's still young (0.528427 seconds remain).
Feb 12 03:13:26.000 [info] command_process_versions_cell(): Negotiated version 3 with [scrubbed]:9001; Sending cells: NETINFO
Feb 12 03:13:26.000 [info] connection_or_client_learned_peer_id(): Connected to router $7C03D29CA58BE8EED5F483F31A2DEDF6FD7CC444 at 127.0.0.1:9001 without knowing its key. Hoping for the best.
Feb 12 03:13:26.000 [notice] Learned fingerprint 7C03D29CA58BE8EED5F483F31A2DEDF6FD7CC444 for bridge 127.0.0.1:9001
Feb 12 03:13:26.000 [info] command_process_certs_cell(): Got some good certificates from [scrubbed]:9001: Authenticated it.
Feb 12 03:13:26.000 [notice] Bootstrapped 15%: Establishing an encrypted directory connection.
Feb 12 03:13:26.000 [info] circuit_send_next_onion_skin(): First hop: finished sending CREATE_FAST cell to '<unnamed>'
Feb 12 03:13:26.000 [info] command_process_netinfo_cell(): Got good NETINFO cell from [scrubbed]:9001; OR connection is now open, using protocol version 3. Its ID digest is 7C03D29CA58BE8EED5F483F31A2DEDF6FD7CC444
Feb 12 03:13:26.000 [info] circuit_expire_building(): created is 1329041603.765838; cutoff is 1329041604.238231 (2.528000).
Feb 12 03:13:26.000 [info] circuit_expire_building(): too old (0.472393 seconds).
Feb 12 03:13:26.000 [info] circuit_expire_building(): Abandoning circ 127.0.0.1:9001:14929 (state 0:doing handshakes, purpose 5)
Feb 12 03:13:26.000 [info] exit circ (length 1, last hop 0000000000000000000000000000000000000000): $0000000000000000000000000000000000000000(waiting for keys)
Feb 12 03:13:26.000 [info] circuit_build_failed(): Our circuit failed to get a response from the first hop (127.0.0.1:9001). I'm going to try to rotate to a better connection.
Feb 12 03:13:26.000 [info] connection_ap_fail_onehop(): Closing one-hop stream to '$0000000000000000000000000000000000000000/127.0.0.1' because the OR conn just failed.
Feb 12 03:13:26.000 [info] smartlist_choose_node_by_bandwidth_weights(): Empty routerlist passed in to consensus weight node selection for rule weight as guard
Feb 12 03:13:26.000 [info] smartlist_choose_node_by_bandwidth(): Empty routerlist passed in to old node selection for rule weight as guard
Feb 12 03:13:26.000 [info] should_delay_dir_fetches(): delaying dir fetches (no running bridges known)
Feb 12 03:13:26.000 [notice] no known bridge descriptors running yet; stalling
Feb 12 03:13:26.000 [info] _connection_free(): Freeing linked Socks connection [waiting for circuit] with 62 bytes on inbuf, 0 on outbuf.
---
experiments/exercise/exercise.sh | 2 +-
1 files changed, 1 insertions(+), 1 deletions(-)
diff --git a/experiments/exercise/exercise.sh b/experiments/exercise/exercise.sh
index 834bd48..0557062 100755
--- a/experiments/exercise/exercise.sh
+++ b/experiments/exercise/exercise.sh
@@ -25,7 +25,7 @@ PIDS_TO_KILL+=($!)
sleep 20
-"$TOR" UseBridges 1 Bridge 127.0.0.1:9001 Socks4Proxy 127.0.0.1:$LOCAL_PORT &
+"$TOR" UseBridges 1 Bridge 127.0.0.1:9001 Socks4Proxy 127.0.0.1:$LOCAL_PORT LearnCircuitBuildTimeout 0 &
PIDS_TO_KILL+=($!)
sleep 60
More information about the tor-commits
mailing list