fail to make a connection because of 'upstream data before doing handshake'
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=127.0.0.1:22 server 0.0.0.0:80
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 127.0.0.1:9999
on HOST B, make a ssh tunnel with the command: ssh -vvv -o ProxyCommand='nc -X 4 -x 127.0.0.1:9999 %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: 24aee8abd7c8f7b6cab862331f82b27e 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 bytes: ... ... ... ...
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) --- --- 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? exceptions.AssertionError:
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 connection.
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 bytes. 2013-07-11 16:34:24,862 [DEBUG] Got upstream data before doing handshake. Caching. 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 0xa12424c>
Trac:
Username: c95517