crossbario / autobahn-python

WebSocket and WAMP in Python for Twisted and asyncio
https://crossbar.io/autobahn
MIT License
2.48k stars 766 forks source link

traceback in callee on hard killing of a caller #1127

Open oberstet opened 5 years ago

oberstet commented 5 years ago

hard killing a caller results in a callee traceback (on container components over rawsocket):

2019-03-02T16:34:36+0100 [Container   25923] Traceback (most recent call last):
  File "/home/oberstet/scm/crossbario/autobahn-python/autobahn/wamp/websocket.py", line 95, in onMessage
    self._session.onMessage(msg)
  File "/home/oberstet/scm/crossbario/autobahn-python/autobahn/wamp/protocol.py", line 1027, in onMessage
    raise ProtocolError("INTERRUPT received for non-pending invocation {0}".format(msg.request))
autobahn.wamp.exception.ProtocolError: INTERRUPT received for non-pending invocation 2601

2019-03-02T16:34:36+0100 [Container   25923] dropping connection to peer tcp4:127.0.0.1:8080 with abort=True: I dropped the WebSocket TCP connection: WAMP Protocol Error (INTERRUPT received for non-pending invocation 2601)
2019-03-02T16:34:36+0100 [Container   25923] session closed with reason wamp.close.transport_lost [WAMP transport was lost without closing the session before]
2019-03-02T16:34:36+0100 [Container   25923] Lost connection to component 'component001' uncleanly
2019-03-02T16:34:36+0100 [Container   25923] Container is hosting no more components: continue running in exit mode <shutdown-manual>
2019-03-02T16:34:36+0100 [Container   25935] Traceback (most recent call last):
  File "/home/oberstet/scm/crossbario/autobahn-python/autobahn/wamp/websocket.py", line 95, in onMessage
    self._session.onMessage(msg)
  File "/home/oberstet/scm/crossbario/autobahn-python/autobahn/wamp/protocol.py", line 1027, in onMessage
    raise ProtocolError("INTERRUPT received for non-pending invocation {0}".format(msg.request))
autobahn.wamp.exception.ProtocolError: INTERRUPT received for non-pending invocation 2602

2019-03-02T16:34:36+0100 [Container   25935] dropping connection to peer tcp4:127.0.0.1:8080 with abort=True: I dropped the WebSocket TCP connection: WAMP Protocol Error (INTERRUPT received for non-pending invocation 2602)
2019-03-02T16:34:36+0100 [Container   25935] session closed with reason wamp.close.transport_lost [WAMP transport was lost without closing the session before]
2019-03-02T16:34:36+0100 [Container   25935] Lost connection to component 'component002' uncleanly
2019-03-02T16:34:36+0100 [Container   25935] Container is hosting no more components: continue running in exit mode <shutdown-manual>
asodeur commented 5 years ago

I bumped into this with long blocking callees last week. If you cancel the call while the callee is blocking you are getting the ProtocolError as well.

Reproducer looks like this (sorry, still contains some bits of our testing infrastructure ...), sessions are running over websocket.

@pytest.mark.asyncio
async def test_autobahn_issue_1127(event_loop, session):
    """reproducer for issue 1127

       Seems like cancelling calls into blocking callees is causing ProtocolError

       Steps to reproduce
        - Start a session for the callee on a separate subprocess and registers a long blocking (time.sleep(long_time))
          procedure.
        - call the long blocking procedure with a timeout << long_time
    """

    # start helper session with long blocking procedure, any long blocking procedure should do ...
    session_with_long_blocking_procedure = await create_subprocess_exec(
        sys.executable,
        _autobahn_issue1127.__file__
    )
    blocking_component_ready = event_loop.create_future()
    session.subscribe(blocking_component_ready.set_result, 'autobahn.issue1127.long_blocking')
    await blocking_component_ready
    # helper session is up and running

    try:
        await wait_for(session.call('autobahn.issue1127.long_blocking'), 1)  # impatient caller
    except TimeoutError:
        pass

    # wait for the helper session to shut-down (exception is raised when the callee returns)
    await session_with_long_blocking_procedure.wait()