Opened 5 years ago

Last modified 19 months ago

#7960 defect new

Race condition in t.c.s.c.SSHConnection sendClose can expect remote connection before it's opened

Reported by: tommyvn Owned by:
Priority: normal Milestone:
Component: conch Keywords: conch, race condition, sendClose
Cc: z3p Branch:
Author:

Description

I'm seeing very occasional exceptions on connections to a reverse conch tunnel that connects and disconnects potentially very quickly:

2015-07-03 08:26:45+0000 [SSHForwardingClient,0,127.0.0.1] Unhandled Error
        Traceback (most recent call last):
          File "/opt/pypy-2.6.0-linux64/site-packages/ruppells/sockets/sshin.py", line 304, in start
            reactor.run()
          File "/opt/pypy-2.6.0-linux64/site-packages/twisted/internet/base.py", line 1192, in run
            self.mainLoop()
          File "/opt/pypy-2.6.0-linux64/site-packages/twisted/internet/base.py", line 1204, in mainLoop
            self.doIteration(t)
          File "/opt/pypy-2.6.0-linux64/site-packages/twisted/internet/epollreactor.py", line 396, in doPoll
            log.callWithLogger(selectable, _drdw, selectable, fd, event)
        --- <exception caught here> ---
          File "/opt/pypy-2.6.0-linux64/site-packages/twisted/python/log.py", line 88, in callWithLogger
            return callWithContext({"system": lp}, func, *args, **kw)
          File "/opt/pypy-2.6.0-linux64/site-packages/twisted/python/log.py", line 73, in callWithContext
            return context.call({ILogContext: newCtx}, func, *args, **kw)
          File "/opt/pypy-2.6.0-linux64/site-packages/twisted/python/context.py", line 118, in callWithContext
            return self.currentContext().callWithContext(ctx, func, *args, **kw)
          File "/opt/pypy-2.6.0-linux64/site-packages/twisted/python/context.py", line 81, in callWithContext
            return func(*args,**kw)
          File "/opt/pypy-2.6.0-linux64/site-packages/twisted/internet/posixbase.py", line 627, in _doReadOrWrite
            self._disconnectSelectable(selectable, why, inRead)
          File "/opt/pypy-2.6.0-linux64/site-packages/twisted/internet/posixbase.py", line 260, in _disconnectSelectable
            selectable.connectionLost(f)
          File "/opt/pypy-2.6.0-linux64/site-packages/twisted/internet/tcp.py", line 299, in connectionLost
            protocol.connectionLost(reason)
          File "/opt/pypy-2.6.0-linux64/site-packages/twisted/conch/ssh/forwarding.py", line 129, in connectionLost
            self.channel.loseConnection()
          File "/opt/pypy-2.6.0-linux64/site-packages/twisted/conch/ssh/channel.py", line 253, in loseConnection
            self.conn.sendClose(self)
          File "/opt/pypy-2.6.0-linux64/site-packages/twisted/conch/ssh/connection.py", line 510, in sendClose
            self.channelsToRemoteChannel[channel]))
        exceptions.KeyError: <ruppells.sockets.sshin.SSHListenServerForwardingChannel2 instance at 0x00007f8eb6aa02c0>

It seems that the following code can be called on a connection that doesn't yet have the remote channel:

self.transport.sendPacket(MSG_CHANNEL_CLOSE, struct.pack('>L',
                self.channelsToRemoteChannel[channel]))

I've worked around it with a sub-class that overrides the sendClose method with one that wraps that statement in a check to see if channel is indeed in self.channelsToRemoteChannel but I've not confirmed that that dict isn't getting filled in from a deferred somewhere so I might be simply masking the problem. I've also not made a http://sscce.org/ yet, I'll get that on here when I start work on a patch.

If no one's looked into this when I've got more time I'll follow the calls and see if the fix is that simple and send a patch.

Change History (3)

comment:1 Changed 5 years ago by DefaultCC Plugin

Cc: z3p added

comment:2 Changed 2 years ago by Adrian Fiergolski

I confirm the bug still exists in twisted 17.9.0

comment:3 Changed 19 months ago by Adrian Fiergolski

I confirm the bug still exists in twisted 18.7.0.

Note: See TracTickets for help on using tickets.