Tor process hangs for about 3 minutes when configured with a pluggable transport
While testing bridge lines yesterday for our circumvention settings update, I noticed that the tor process hangs for several minutes when configured to launch PTs before logging the Bootstrapped 1%
message. I've reproduced this both with using the tor command on Debian and with Tor Browser on linux. Here are the logs:
From running tor-f torrc
for Snowflake:
Nov 05 09:19:56.762 [notice] Tor 0.4.8.13 running on Linux with Libevent 2.1.12-stable, OpenSSL 3.3.2, Zlib 1.3.1, Liblzma 5.6.3, Libzstd 1.5.6 and Glibc 2.40 as libc.
Nov 05 09:19:56.762 [notice] Tor can't help you if you use it wrong! Learn how to be safe at https://support.torproject.org/faq/staying-anonymous/
Nov 05 09:19:56.762 [notice] Read configuration file "/home/cecylia/Documents/tor/snowflake/client/torrc".
Nov 05 09:19:56.763 [warn] Path for DataDirectory (datadir) is relative and will resolve to /home/cecylia/Documents/tor/snowflake/client/datadir. Is this what you wanted?
Nov 05 09:19:56.764 [notice] Opening Socks listener on 127.0.0.1:0
Nov 05 09:19:56.764 [notice] Socks listener listening on port 36477.
Nov 05 09:19:56.764 [notice] Opened Socks listener connection (ready) on 127.0.0.1:36477
Nov 05 09:19:56.000 [notice] Parsing GEOIP IPv4 file /usr/share/tor/geoip.
Nov 05 09:19:56.000 [notice] Parsing GEOIP IPv6 file /usr/share/tor/geoip6.
Nov 05 09:19:57.000 [notice] Bootstrapped 0% (starting): Starting
Nov 05 09:19:57.000 [notice] Starting with guard context "bridges"
Nov 05 09:19:57.000 [notice] Delaying directory fetches: No running bridges
Nov 05 09:19:57.000 [notice] new bridge descriptor 'flakey5' (cached): $2B280B23E1107BB62ABFC40DDCC8824814F80A72~flakey5 [1zOHpg+FxqQfi/6jDLtCpHHqBTH8gjYmCKXkus1D5Ko] at 192.0.2.3
Nov 05 09:22:57.000 [notice] Bootstrapped 1% (conn_pt): Connecting to pluggable transport
From Tor Browser:
2024-11-05 14:16:30.346 [NOTICE] DisableNetwork is set. Tor will not make or accept non-control network connections. Shutting down all existing connections.
2024-11-05 14:16:43.123 [NOTICE] DisableNetwork is set. Tor will not make or accept non-control network connections. Shutting down all existing connections.
2024-11-05 14:16:43.124 [NOTICE] Switching to guard context "bridges" (was using "default")
2024-11-05 14:16:43.161 [NOTICE] Opening Socks listener on 127.0.0.1:9150
2024-11-05 14:16:43.161 [NOTICE] Opened Socks listener connection (ready) on 127.0.0.1:9150
2024-11-05 14:16:58.520 [NOTICE] Application request when we haven't used client functionality lately. Optimistically trying known bridges again.
2024-11-05 14:17:16.996 [NOTICE] Application request when we haven't used client functionality lately. Optimistically trying known bridges again.
2024-11-05 14:17:16.996 [NOTICE] Application request when we haven't used client functionality lately. Optimistically trying known bridges again.
2024-11-05 14:20:01.712 [NOTICE] Bootstrapped 1% (conn_pt): Connecting to pluggable transport
This seems to happen with all PTs, but it doesn't happen if you start the PT process separately and then configure the bridge line to connect to the PT's socks5 port as so:
ClientTransportPlugin snowflake socks5 127.0.0.1:9000
This makes me think it's a problem with launching the PT process.