Opened 6 years ago

Closed 6 years ago

#11769 closed defect (fixed)

Unexpected `NoneType` in obfs3

Reported by: asn Owned by: asn
Priority: Medium Milestone:
Component: Archived/Obfsproxy Version:
Severity: Keywords:
Cc: Actual Points:
Parent ID: Points:
Reviewer: Sponsor:

Description (last modified by asn)

Since my obfs3 bridge has gotten more popular, I decided to enable logging and I noticed that I've been getting these errors:

2014-05-06 14:47:51,643 [ERROR] Unhandled Error
Traceback (most recent call last):
  File "/usr/local/lib/python2.7/dist-packages/Twisted-13.2.0-py2.7-linux-x86_64.egg/twisted/python/log.py", line 88, in callWithLogger
    return callWithContext({"system": lp}, func, *args, **kw)
  File "/usr/local/lib/python2.7/dist-packages/Twisted-13.2.0-py2.7-linux-x86_64.egg/twisted/python/log.py", line 73, in callWithContext
    return context.call({ILogContext: newCtx}, func, *args, **kw)
  File "/usr/local/lib/python2.7/dist-packages/Twisted-13.2.0-py2.7-linux-x86_64.egg/twisted/python/context.py", line 118, in callWithContext
    return self.currentContext().callWithContext(ctx, func, *args, **kw)
  File "/usr/local/lib/python2.7/dist-packages/Twisted-13.2.0-py2.7-linux-x86_64.egg/twisted/python/context.py", line 81, in callWithContext
    return func(*args,**kw)
--- <exception caught here> ---
  File "/usr/local/lib/python2.7/dist-packages/Twisted-13.2.0-py2.7-linux-x86_64.egg/twisted/internet/posixbase.py", line 614, in _doReadOrWrite
    why = selectable.doRead()
  File "/usr/local/lib/python2.7/dist-packages/Twisted-13.2.0-py2.7-linux-x86_64.egg/twisted/internet/tcp.py", line 215, in doRead
    return self._dataReceived(data)
  File "/usr/local/lib/python2.7/dist-packages/Twisted-13.2.0-py2.7-linux-x86_64.egg/twisted/internet/tcp.py", line 221, in _dataReceived
    rval = self.protocol.dataReceived(data)
  File "/usr/local/lib/python2.7/dist-packages/obfsproxy-0.2.9_1_g4c41868-py2.7.egg/obfsproxy/network/extended_orport.py", line 189, in dataReceived
    self.circuit.dataReceived(self.buffer, self)
  File "/usr/local/lib/python2.7/dist-packages/obfsproxy-0.2.9_1_g4c41868-py2.7.egg/obfsproxy/network/network.py", line 157, in dataReceived
    self.transport.receivedUpstream(data)
  File "/usr/local/lib/python2.7/dist-packages/obfsproxy-0.2.9_1_g4c41868-py2.7.egg/obfsproxy/transports/obfs3.py", line 102, in receivedUpstream
    self.circuit.downstream.write(message)
exceptions.AttributeError: 'NoneType' object has no attribute 'downstream'

I get around 2-3 of them per day which means that it's not a very usual bug.

Child Tickets

Change History (5)

comment:1 Changed 6 years ago by asn

I suspect these two things might be different bugs. Here are some partially anonymized debug logs for the bug that crashes on self.circuit.downstream.write():

2014-05-06 22:12:33,689 [DEBUG] conn_0x21bb1d0: Connection was lost (Connection was closed cleanly.).
2014-05-06 22:12:33,690 [DEBUG] conn_0x21bb1d0: Closing connection.
2014-05-06 22:12:33,690 [DEBUG] circ_0x21b9518: Tearing down circuit.
2014-05-06 22:12:33,690 [DEBUG] ext_0x21bb2d0: Closing connection.
2014-05-06 22:12:33,724 [DEBUG] circ_0x21b9518: upstream: Received 565 bytes.
2014-05-06 22:12:33,731 [ERROR] Unhandled Error
Traceback (most recent call last):
  File "/usr/local/lib/python2.7/dist-packages/Twisted-13.2.0-py2.7-linux-x86_64.egg/twisted/python/log.py", line 88, in callWithLogger
    return callWithContext({"system": lp}, func, *args, **kw)
  File "/usr/local/lib/python2.7/dist-packages/Twisted-13.2.0-py2.7-linux-x86_64.egg/twisted/python/log.py", line 73, in callWithContext
    return context.call({ILogContext: newCtx}, func, *args, **kw)
  File "/usr/local/lib/python2.7/dist-packages/Twisted-13.2.0-py2.7-linux-x86_64.egg/twisted/python/context.py", line 118, in callWithContext
    return self.currentContext().callWithContext(ctx, func, *args, **kw)
  File "/usr/local/lib/python2.7/dist-packages/Twisted-13.2.0-py2.7-linux-x86_64.egg/twisted/python/context.py", line 81, in callWithContext
    return func(*args,**kw)
--- <exception caught here> ---
  File "/usr/local/lib/python2.7/dist-packages/Twisted-13.2.0-py2.7-linux-x86_64.egg/twisted/internet/posixbase.py", line 614, in _doReadOrWrite
    why = selectable.doRead()
  File "/usr/local/lib/python2.7/dist-packages/Twisted-13.2.0-py2.7-linux-x86_64.egg/twisted/internet/tcp.py", line 215, in doRead
    return self._dataReceived(data)
  File "/usr/local/lib/python2.7/dist-packages/Twisted-13.2.0-py2.7-linux-x86_64.egg/twisted/internet/tcp.py", line 221, in _dataReceived
    rval = self.protocol.dataReceived(data)
  File "/usr/local/lib/python2.7/dist-packages/obfsproxy-0.2.9_1_g0005192_dirty-py2.7.egg/obfsproxy/network/extended_orport.py", line 189, in dataReceived
    self.circuit.dataReceived(self.buffer, self)
  File "/usr/local/lib/python2.7/dist-packages/obfsproxy-0.2.9_1_g0005192_dirty-py2.7.egg/obfsproxy/network/network.py", line 157, in dataReceived
    self.transport.receivedUpstream(data)
  File "/usr/local/lib/python2.7/dist-packages/obfsproxy-0.2.9_1_g0005192_dirty-py2.7.egg/obfsproxy/transports/obfs3.py", line 102, in receivedUpstream
    self.circuit.downstream.write(message)
exceptions.AttributeError: 'NoneType' object has no attribute 'downstream'

2014-05-06 22:12:33,733 [DEBUG] ext_0x21bb2d0: Connection was lost ('NoneType' object has no attribute 'downstream').

So I think what's happening here is the following: The client disconnects and the connection is lost. The circuit gets destroyed (self.transport.circuit is set to None), and the ExtendedORPort connection also gets closed.
However, there were still some data on our ExtendedORport buffer that get flushed (apparently transport.loseConnection() does not work as I expected), so that reaches extended_orport.py:dataReceived(), and then it goes to self.circuit.dataReceived(self.buffer, self). self.circuit still exists because nothing cleared it, however the circuit attached to the transport is set to None, so when we reach the transport-specific receivedUpstream() that tries to write to self.circuit.downstream it crashes.

Guarding the dataReceived functions with a if self.closed: check seems to solve the problem in my bridge. However, the first crash still happens.

comment:2 Changed 6 years ago by asn

Description: modified (diff)

comment:3 Changed 6 years ago by asn

(FWIW, the other part of this bug was moved in #11820)

comment:4 Changed 6 years ago by asn

Status: newneeds_review

See branch bug11769 in my repo for a fix.

I might have been a bit overzealous in my self.closed guards.

comment:5 Changed 6 years ago by asn

Resolution: fixed
Status: needs_reviewclosed

Merged after review from Yawning.

Thanks!

Note: See TracTickets for help on using tickets.