[tor-bugs] #9239 [Obfsproxy]: fail to make a connection because of 'upstream data before doing handshake'

Tor Bug Tracker & Wiki blackhole at torproject.org
Thu Jul 11 08:48:31 UTC 2013

#9239: fail to make a connection because of  'upstream data before doing
 Reporter:  c95517     |          Owner:  asn
     Type:  defect     |         Status:  new
 Priority:  normal     |      Milestone:     
Component:  Obfsproxy  |        Version:     
 Keywords:             |         Parent:     
   Points:             |   Actualpoints:     
 on HOST A(Obfsproxy version: 0.2.2_5), which is a remote machine, the
 configuration as following
 /usr/local/bin/obfsproxy --log-file /var/log/obfsproxy/obfsproxy.log
 --log-min-severity=debug obfs2 --shared-secret
 24aee8abd7c8f7b6cab862331f82b27e --dest= server

 on HOST B(Obfsproxy version: 0.2.2), which is a local machine, the
 configuration as following():
 /usr/local/bin/obfsproxy --log-file /var/log/obfsproxy/obfsproxy.log
 --log-min-severity=debug obfs2 --shared-secret
 24aee8abd7c8f7b6cab862331f82b27e socks

 on HOST B, make a ssh tunnel with the command:
 ssh -vvv -o ProxyCommand='nc -X 4 -x %h %p'  -l tunnel -i
 ~/.ssh/tunnel -p 80 HOSTA

 if I capture packets on HOST A with the command:
 tcpdump -i eth0 port 80

 I will fail to build a tunnel, the log in HOST B :

 2013-07-11 16:34:24,129 [DEBUG] Starting obfs2 with shared secret:
 2013-07-11 16:34:24,129 [DEBUG] socks_up_0x1076cef90: Received SOCKS
 handshake data.
 2013-07-11 16:34:24,997 [DEBUG] socks_down_0x1076cef50: Received 2703
       ... ... ... ...

 2013-07-11 16:34:24,997 [ERROR] Unhandled Error
 Traceback (most recent call last):
   File "/usr/bin/python/python27/lib/python2.7/site-
 packages/twisted/python/log.py", line 88, in callWithLogger
     return callWithContext({"system": lp}, func, *args, **kw)
   File "/usr/bin/python/python27/lib/python2.7/site-
 packages/twisted/python/log.py", line 73, in callWithContext
     return context.call({ILogContext: newCtx}, func, *args, **kw)
   File "/usr/bin/python/python27/lib/python2.7/site-
 packages/twisted/python/context.py", line 118, in callWithContext
     return self.currentContext().callWithContext(ctx, func, *args, **kw)
   File "/usr/bin/python/python27/lib/python2.7/site-
 packages/twisted/python/context.py", line 81, in callWithContext
     return func(*args,**kw)
 --- <exception caught here> ---
   File "/usr/bin/python/python27/lib/python2.7/site-
 packages/twisted/internet/selectreactor.py", line 151, in _doReadOrWrite
     why = getattr(selectable, method)()
   File "/usr/bin/python/python27/lib/python2.7/site-
 packages/twisted/internet/tcp.py", line 215, in doRead
     return self._dataReceived(data)
   File "/usr/bin/python/python27/lib/python2.7/site-
 packages/twisted/internet/tcp.py", line 221, in _dataReceived
     rval = self.protocol.dataReceived(data)
   File "/usr/bin/python/python27/lib/python2.7/site-
 packages/obfsproxy/network/socks.py", line 52, in dataReceived
     assert(self.circuit.circuitIsReady()) # XXX Is this always true?

 2013-07-11 16:34:24,998 [DEBUG] socks_down_0x1076cef50: Connection was
 lost ().
 2013-07-11 16:34:24,998 [DEBUG] socks_down_0x1076cef50: Closing

 the log in HOST A:

 2013-07-11 16:34:24,376 [DEBUG] conn_0xa1242cc: connectionMade (server):
 Setting it as upstream on our circuit.
 2013-07-11 16:34:24,376 [DEBUG] circ_0xa12422c: Setting upstream
 connection (conn_0xa1242cc).
 2013-07-11 16:34:24,377 [DEBUG] circ_0xa12422c: Circuit completed.
 2013-07-11 16:34:24,859 [DEBUG] obfs2 handshake: responder queued 2703
 bytes (padding_length: 2679).
 2013-07-11 16:34:24,859 [DEBUG] conn_0xa12430c: Writing 2703 bytes.
 2013-07-11 16:34:24,862 [DEBUG] circ_0xa12422c: upstream: Received 41
 2013-07-11 16:34:24,862 [DEBUG] Got upstream data before doing handshake.
 2013-07-11 16:34:24,869 [DEBUG] conn_0xa12430c: dataReceived called
 without a reason.
 2013-07-11 16:34:25,059 [DEBUG] conn_0xa12430c: Connection was lost
 (Connection was closed cleanly.).
 2013-07-11 16:34:25,059 [DEBUG] conn_0xa12430c: Closing connection.
 2013-07-11 16:34:25,059 [DEBUG] circ_0xa12422c: Tearing down circuit.
 2013-07-11 16:34:25,059 [DEBUG] conn_0xa1242cc: Closing connection.
 2013-07-11 16:34:25,060 [DEBUG] conn_0xa1242cc: Connection was lost
 (Connection was closed cleanly.).
 2013-07-11 16:34:25,060 [INFO] Stopping factory
 <obfsproxy.network.network.StaticDestinationClientFactory instance at

Ticket URL: <https://trac.torproject.org/projects/tor/ticket/9239>
Tor Bug Tracker & Wiki <https://trac.torproject.org/>
The Tor Project: anonymity online

More information about the tor-bugs mailing list