[tor-qa] Meek stalls at 50%

[David Fifield]

On Tue, Jun 17, 2014 at 10:03:23AM -0700, Christopher Lucko wrote:
> I wanted to test the meek pluggable transport. It can't connect. The standard
> Tor browser works on this PC (Windows 8.1, 64-bit) without problems but not the
> meek version.
> Below is the log:
> 
> 6/17/2014 9:57:15.623 [NOTICE] DisableNetwork is set. Tor will not make or accept non-control network connections. Shutting down all existing connections.
> 6/17/2014 9:57:15.623 [NOTICE] Pluggable transport proxy (fte exec Tor\PluggableTransports\fteproxy --managed) does not provide any needed transports and will not be launched.
> 6/17/2014 9:57:15.623 [NOTICE] Pluggable transport proxy (obfs2,obfs3 exec Tor\PluggableTransports\obfsproxy managed) does not provide any needed transports and will not be launched.
> 6/17/2014 9:57:15.623 [NOTICE] Pluggable transport proxy (flashproxy exec Tor\PluggableTransports\flashproxy-client --register :0 :9000) does not provide any needed transports and will not be launched.
> 6/17/2014 9:57:15.623 [NOTICE] Opening Socks listener on [1]127.0.0.1:9150
> 6/17/2014 9:57:15.623 [NOTICE] Pluggable transport proxy (fte exec Tor\PluggableTransports\fteproxy --managed) does not provide any needed transports and will not be launched.
> 6/17/2014 9:57:15.623 [NOTICE] Pluggable transport proxy (obfs2,obfs3 exec Tor\PluggableTransports\obfsproxy managed) does not provide any needed transports and will not be launched.
> 6/17/2014 9:57:15.623 [NOTICE] Pluggable transport proxy (flashproxy exec Tor\PluggableTransports\flashproxy-client --register :0 :9000) does not provide any needed transports and will not be launched.
> 6/17/2014 9:57:18.679 [NOTICE] Pluggable transport proxy (fte exec Tor\PluggableTransports\fteproxy --managed) does not provide any needed transports and will not be launched.
> 6/17/2014 9:57:18.679 [NOTICE] Pluggable transport proxy (obfs2,obfs3 exec Tor\PluggableTransports\obfsproxy managed) does not provide any needed transports and will not be launched.
> 6/17/2014 9:57:18.679 [NOTICE] Pluggable transport proxy (flashproxy exec Tor\PluggableTransports\flashproxy-client --register :0 :9000) does not provide any needed transports and will not be launched.
> 6/17/2014 9:57:22.143 [NOTICE] Bootstrapped 5%: Connecting to directory server.
> 6/17/2014 9:57:22.147 [NOTICE] Bootstrapped 10%: Finishing handshake with directory server.
> 6/17/2014 9:57:23.249 [NOTICE] Learned fingerprint 4D6C0DF6DEC9398A4DEF07084F3CD395A96DD2AD for bridge [2]0.0.2.0:1 (with transport 'meek').
> 6/17/2014 9:57:23.249 [NOTICE] Bootstrapped 15%: Establishing an encrypted directory connection.
> 6/17/2014 9:57:23.777 [NOTICE] Bootstrapped 20%: Asking for networkstatus consensus.
> 6/17/2014 9:57:24.136 [NOTICE] Bootstrapped 50%: Loading relay descriptors.
> 6/17/2014 9:57:24.514 [NOTICE] new bridge descriptor 'giygas' (fresh): $4D6C0DF6DEC9398A4DEF07084F3CD395A96DD2AD~giygas at 0.0.2.0
> 6/17/2014 9:57:24.514 [NOTICE] I learned some more directory information, but not enough to build a circuit: We have no usable consensus.
> 6/17/2014 9:57:29.970 [NOTICE] I learned some more directory information, but not enough to build a circuit: We need more microdescriptors: we have 1935/5617, and can only build 6% of likely paths. (We have 38% of guards bw, 37% of midpoint bw, and 43% of exit bw.)
> 6/17/2014 9:57:31.386 [NOTICE] I learned some more directory information, but not enough to build a circuit: We need more microdescriptors: we have 1935/5617, and can only build 6% of likely paths. (We have 38% of guards bw, 37% of midpoint bw, and 43% of exit bw.)
> 6/17/2014 9:57:40.662 [NOTICE] Application request when we haven't used client functionality lately. Optimistically trying directory fetches again.
> 6/17/2014 9:58:05.676 [NOTICE] Application request when we haven't used client functionality lately. Optimistically trying directory fetches again.
> 6/17/2014 9:58:24.514 [WARN] parse error: Malformed object: missing object end line
> 6/17/2014 9:58:24.514 [WARN] Unparseable microdescriptor
> 6/17/2014 9:58:30.692 [NOTICE] Application request when we haven't used client functionality lately. Optimistically trying directory fetches again.
> 6/17/2014 9:59:20.714 [NOTICE] Application request when we haven't used client functionality lately. Optimistically trying directory fetches again.
> 6/17/2014 9:59:45.726 [NOTICE] Application request when we haven't used client functionality lately. Optimistically trying directory fetches again.

Thanks so much for taking the time to test and write this report. What
you describe sounds like this ticket:

"tbb bundle with meek takes (literally) hours to connect"
https://trac.torproject.org/projects/tor/ticket/11612

I wasn't able to reproduce the problem, and the reporter hasn't replied
back yet.

What version were you using? Was it version 3.6.2-meek-1, or another
version?

The first thing we should try is to enable logging in meek-client. Edit
the file Data\Tor\torrc-defaults. This line is at the bottom:

ClientTransportPlugin meek exec ./Tor/PluggableTransports/terminateprocess-buffer ./Tor/PluggableTransports/meek-client-torbrowser --exit-on-stdin-eof -- ./Tor/PluggableTransports/meek-client --url=https://meek-reflect.appspot.com/ --front=www.google.com

Add "--log meek-client.txt" to the end of the line, so it looks like
this:

ClientTransportPlugin meek exec ./Tor/PluggableTransports/terminateprocess-buffer ./Tor/PluggableTransports/meek-client-torbrowser --exit-on-stdin-eof -- ./Tor/PluggableTransports/meek-client --url=https://meek-reflect.appspot.com/ --front=www.google.com --log meek-client.txt

Then try running the browser again. It will create a file called
meek-client.txt. Send that file to me. You can of course check what's
inside it. What we're looking for is lots of "error in handling request:
EOF" like in https://trac.torproject.org/projects/tor/ticket/11612#comment:2.

Then, if you feel up to it, please try following the steps in
https://trac.torproject.org/projects/tor/ticket/11612#comment:1 to
increase the internal timeouts.

David Fifield