[tor-dev] Opening new SOCKS to client plugin for new circuit?

David Fifield david at bamsoftware.com
Mon Dec 3 17:20:04 UTC 2012

I noticed a change in behavior in cb62a0b69a7d67b427224ca4c3075b49853a3a1f
or thereabouts. tor opens a new SOCKS connection to a client transport
plugin while bootstrapping at 50% (if descriptors are not cached) or at
85% (if descriptors are not cached). The upshot is that the flash proxy
transport, for which new connections are not free, needs two connected
browser proxies in order to bootstrap. Earlier revisions permit
bootstrapping and circuit creation with just one connection to the

I start an external proxy thus:
	$ ./flashproxy-client --external --unsafe-logging
	2012-12-03 09:02:05 Listening remote on
	2012-12-03 09:02:05 Listening remote on [::]:9000.
	2012-12-03 09:02:05 Listening local on
	2012-12-03 09:02:05 Listening local on [::1]:9001.
The "remote" listener is waiting for WebSocket connections from a
browser. The "local" listener is waiting for SOCKS connections from Tor.
Then I start Tor to use the proxy:
	$ ./src/or/tor ClientTransportPlugin "websocket socks4" UseBridges 1 Bridge "websocket" LearnCircuitBuildTimeout 0 CircuitBuildTimeout 60 Log "info stderr"
	Dec 03 09:02:13.000 [notice] Bootstrapped 10%: Finishing handshake with directory server.
flashproxy-client notices Tor's pending SOCKS connection:
	2012-12-03 09:02:13 Local connection from
	2012-12-03 09:02:13 SOCKS request from
	2012-12-03 09:02:13 Got SOCKS request for
	2012-12-03 09:02:13 locals  (1): [u'']
	2012-12-03 09:02:13 remotes (0): []
	2012-12-03 09:02:13 Data from unlinked local (217 bytes).
	2012-12-03 09:02:13 locals  (1): [u'']
	2012-12-03 09:02:13 remotes (0): []
Then I open a browser to make a single WebSocket connection which will
appear as one of the pluggable transport's "remotes".
flashproxy-client sees the new remote and starts proxying data.
	2012-12-03 09:02:17 Remote connection from
	2012-12-03 09:02:17 Data from WebSocket-pending
	2012-12-03 09:02:17 locals  (1): [u'']
	2012-12-03 09:02:17 remotes (1): [u'']
	2012-12-03 09:02:17 Linking and
Now bootstrapping continues (over the WebSocket channel) until reaching
85%, and then it says "connections all too old, or too non-canonical"
and makes a new SOCKS request:
	Dec 03 09:02:18.000 [notice] new bridge descriptor '3VXRyxz67OeRoqHn' (fresh): $7C03D29CA58BE8EED5F483F31A2DEDF6FD7CC444~3VXRyxz67OeRoqHn at
	Dec 03 09:02:18.000 [notice] We now have enough directory information to build circuits.
	Dec 03 09:02:18.000 [notice] Bootstrapped 80%: Connecting to the Tor network.
	Dec 03 09:02:18.000 [info] circuit_handle_first_hop(): Next router is [scrubbed]: Connections all too old, or too non-canonical.  Launching a new one.
	Dec 03 09:02:18.000 [notice] Bootstrapped 85%: Finishing handshake with first hop.
	Dec 03 09:02:18.000 [info] connection_read_proxy_handshake(): Proxy Client: connection to successful
flashproxy-client sees the SOCKS request, but because there are no more
browser connections forthcoming, everything stalls at this point.
	2012-12-03 09:02:18 Local connection from
	2012-12-03 09:02:18 SOCKS request from
	2012-12-03 09:02:18 Got SOCKS request for
	2012-12-03 09:02:18 locals  (2): [u'', u'']
	2012-12-03 09:02:18 remotes (1): [u'']
	2012-12-03 09:02:18 Data from unlinked local (231 bytes).

I've verified this failure to bootstrap with recent
190c1d4981e5751aabd3d894095851c830f1d570. After bisecting, I think the
last commit with the old behavior (boostrapped 100%) was
751b3aabb5ab88fca16834e559a8d9835831b05f. There were some compile errors
during bisecting so I couldn't narrow it to a specific revision; git
	There are only 'skip'ped commits left to test.
	The first bad commit could be any of:
	We cannot bisect more!
Based on the log, cb62a0b69a7d67b427224ca4c3075b49853a3a1f seems a
likely cause of the change: "Use channel_is_bad_for_new_circs(),
connection_or_get_num_circs() in main.c".

I thought I would be able to reproduce this with another transport or
with a simple SOCKS proxy, showing two connections where there used to
be one, but I can't. I see two connections even with the old code. For
example with an ssh SOCKS proxy (ssh -v -D 9001 -N localhost):
	debug1: Connection to port 9001 forwarding to socks port 0 requested.
	debug1: channel 2: new [dynamic-tcpip]
	debug1: Connection to port 9001 forwarding to socks port 0 requested.
	debug1: channel 3: new [dynamic-tcpip]
I guess that the difference is that previously, the second connection
happens after bootstrapping is complete, while now it happens at 85%.
(That is only a guess, I haven't verified it.)

David Fifield

More information about the tor-dev mailing list