autobahn-python: Auto reconnection stop after "skipping opening handshake timeout: WebSocket connection is already closed"

Hi, in my application with (autobahn v19.3.3: but I noticed the same “issue” also in v18.10.1 and I don’t know in the others) I notice that the auto-reconnection procedures stop working after these events, in particular after

2019-03-25 15:30:08.191 13776 DEBUG autobahn.asyncio.websocket.WebSocketClientProtocol [-] _connectionLost: [Errno 104] Connection reset by peer _log /usr/local/lib/python3.5/dist-packages/txaio/aio.py:201
2019-03-25 15:30:12.311 13776 DEBUG autobahn.asyncio.websocket.WebSocketClientProtocol [-] skipping opening handshake timeout: WebSocket connection is already closed _log /usr/local/lib/python3.5/dist-packages/txaio/aio.py:201

Is it normal? is there a solution to continue/start the reconnection procedures?

Crossbar v18.9.2

Full report logs:

2019-03-25 15:29:00.597 13776 DEBUG autobahn.asyncio.component.Component [-] component failed: TransportLost: failed to complete connection _log /usr/local/lib/python3.5/dist-packages/txaio/aio.py:201
2019-03-25 15:29:00.609 13776 DEBUG autobahn.asyncio.component.Component [-] Traceback (most recent call last):
  File "/usr/local/lib/python3.5/dist-packages/txaio/aio.py", line 514, in done
    res = f.result()
  File "/usr/lib/python3.5/asyncio/futures.py", line 293, in result
    raise self._exception
  File "/usr/local/lib/python3.5/dist-packages/txaio/aio.py", line 514, in done
    res = f.result()
  File "/usr/lib/python3.5/asyncio/futures.py", line 293, in result
    raise self._exception
autobahn.wamp.exception.TransportLost: failed to complete connection
 _log /usr/local/lib/python3.5/dist-packages/txaio/aio.py:201
2019-03-25 15:29:00.615 13776 ERROR autobahn.asyncio.component.Component [-] Connection failed: TransportLost: failed to complete connection: autobahn.wamp.exception.TransportLost: failed to complete connection
2019-03-25 15:29:00.624 13776 DEBUG autobahn.asyncio.component.Component [-] Entering re-connect loop _log /usr/local/lib/python3.5/dist-packages/txaio/aio.py:201
2019-03-25 15:29:00.631 13776 DEBUG autobahn.asyncio.component.Component [-] trying transport 0 using connect delay 25.279705208019543 _log /usr/local/lib/python3.5/dist-packages/txaio/aio.py:201
2019-03-25 15:29:25.946 13776 INFO autobahn.asyncio.component.Component [-] connecting once using transport type "websocket" over endpoint "tcp"
2019-03-25 15:29:29.403 13776 DEBUG autobahn.asyncio.component.Component [-] component failed: ConnectionResetError: [Errno 104] Connection reset by peer _log /usr/local/lib/python3.5/dist-packages/txaio/aio.py:201
2019-03-25 15:29:29.448 13776 DEBUG autobahn.asyncio.component.Component [-] Traceback (most recent call last):
  File "/usr/local/lib/python3.5/dist-packages/txaio/aio.py", line 514, in done
    res = f.result()
  File "/usr/lib/python3.5/asyncio/futures.py", line 293, in result
    raise self._exception
  File "/usr/local/lib/python3.5/dist-packages/txaio/aio.py", line 514, in done
    res = f.result()
  File "/usr/lib/python3.5/asyncio/futures.py", line 293, in result
    raise self._exception
  File "/usr/local/lib/python3.5/dist-packages/txaio/aio.py", line 514, in done
    res = f.result()
  File "/usr/lib/python3.5/asyncio/futures.py", line 293, in result
    raise self._exception
  File "/usr/local/lib/python3.5/dist-packages/txaio/aio.py", line 514, in done
    res = f.result()
  File "/usr/lib/python3.5/asyncio/futures.py", line 293, in result
    raise self._exception
  File "/usr/local/lib/python3.5/dist-packages/txaio/aio.py", line 514, in done
    res = f.result()
  File "/usr/lib/python3.5/asyncio/futures.py", line 293, in result
    raise self._exception
  File "/usr/lib/python3.5/asyncio/tasks.py", line 239, in _step
    result = coro.send(None)
  File "/usr/lib/python3.5/asyncio/tasks.py", line 400, in wait_for
    return fut.result()
  File "/usr/lib/python3.5/asyncio/futures.py", line 293, in result
    raise self._exception
  File "/usr/lib/python3.5/asyncio/tasks.py", line 241, in _step
    result = coro.throw(exc)
  File "/usr/lib/python3.5/asyncio/base_events.py", line 801, in create_connection
    sock, protocol_factory, ssl, server_hostname)
  File "/usr/lib/python3.5/asyncio/base_events.py", line 827, in _create_connection_transport
    yield from waiter
  File "/usr/lib/python3.5/asyncio/futures.py", line 380, in __iter__
    yield self  # This tells Task to wait for completion.
  File "/usr/lib/python3.5/asyncio/tasks.py", line 304, in _wakeup
    future.result()
  File "/usr/lib/python3.5/asyncio/futures.py", line 293, in result
    raise self._exception
  File "/usr/lib/python3.5/asyncio/selector_events.py", line 723, in _read_ready
    data = self._sock.recv(self.max_size)
ConnectionResetError: [Errno 104] Connection reset by peer
 _log /usr/local/lib/python3.5/dist-packages/txaio/aio.py:201
2019-03-25 15:29:29.454 13776 INFO autobahn.asyncio.component.Component [-] Connection failed: ConnectionResetError: [Errno 104] Connection reset by peer
2019-03-25 15:29:29.471 13776 DEBUG autobahn.asyncio.component.Component [-] Entering re-connect loop _log /usr/local/lib/python3.5/dist-packages/txaio/aio.py:201
2019-03-25 15:29:29.480 13776 DEBUG autobahn.asyncio.component.Component [-] trying transport 0 using connect delay 34.52392114857189 _log /usr/local/lib/python3.5/dist-packages/txaio/aio.py:201
2019-03-25 15:30:04.060 13776 INFO autobahn.asyncio.component.Component [-] connecting once using transport type "websocket" over endpoint "tcp"
2019-03-25 15:30:08.150 13776 DEBUG autobahn.asyncio.websocket.WebSocketClientProtocol [-] 
[('logOctets', False, 'WampWebSocketClientFactory'),
 ('logFrames', False, 'WampWebSocketClientFactory'),
 ('trackTimings', False, 'WampWebSocketClientFactory'),
 ('utf8validateIncoming', True, 'WampWebSocketClientFactory'),
 ('applyMask', True, 'WampWebSocketClientFactory'),
 ('maxFramePayloadSize', 0, 'WampWebSocketClientFactory'),
 ('maxMessagePayloadSize', 0, 'WampWebSocketClientFactory'),
 ('autoFragmentSize', 0, 'WampWebSocketClientFactory'),
 ('failByDrop', True, 'WampWebSocketClientFactory'),
 ('echoCloseCodeReason', False, 'WampWebSocketClientFactory'),
 ('openHandshakeTimeout', 5, 'WampWebSocketClientFactory'),
 ('closeHandshakeTimeout', 1, 'WampWebSocketClientFactory'),
 ('tcpNoDelay', True, 'WampWebSocketClientFactory'),
 ('autoPingInterval', 0, 'WampWebSocketClientFactory'),
 ('autoPingTimeout', 0, 'WampWebSocketClientFactory'),
 ('autoPingSize', 4, 'WampWebSocketClientFactory'),
 ('version', 18, 'WampWebSocketClientFactory'),
 ('acceptMaskedServerFrames', False, 'WampWebSocketClientFactory'),
 ('maskClientFrames', True, 'WampWebSocketClientFactory'),
 ('serverConnectionDropTimeout', 1, 'WampWebSocketClientFactory'),
 ('perMessageCompressionOffers', [], 'WampWebSocketClientFactory'),
 ('perMessageCompressionAccept',
  <function WebSocketClientFactory.resetProtocolOptions.<locals>.<lambda> at 0xb3d51300>,
  'WampWebSocketClientFactory')] _log /usr/local/lib/python3.5/dist-packages/txaio/aio.py:201
2019-03-25 15:30:08.163 13776 DEBUG autobahn.asyncio.websocket.WebSocketClientProtocol [-] connection to tcp:51.75.29.206:8181 established _log /usr/local/lib/python3.5/dist-packages/txaio/aio.py:201
2019-03-25 15:30:08.180 13776 DEBUG autobahn.asyncio.websocket.WebSocketClientProtocol [-] GET / HTTP/1.1
User-Agent: AutobahnPython/19.3.3
Host: <OUR-CROSSBAR-SERVER-IP>:8181
Upgrade: WebSocket
Connection: Upgrade
Pragma: no-cache
Cache-Control: no-cache
Sec-WebSocket-Key: 8eiSBL+/0+X97Hz9R5+JhQ==
Sec-WebSocket-Protocol: wamp.2.json
Sec-WebSocket-Version: 13

 _log /usr/local/lib/python3.5/dist-packages/txaio/aio.py:201
2019-03-25 15:30:08.191 13776 DEBUG autobahn.asyncio.websocket.WebSocketClientProtocol [-] _connectionLost: [Errno 104] Connection reset by peer _log /usr/local/lib/python3.5/dist-packages/txaio/aio.py:201
2019-03-25 15:30:12.311 13776 DEBUG autobahn.asyncio.websocket.WebSocketClientProtocol [-] skipping opening handshake timeout: WebSocket connection is already closed _log /usr/local/lib/python3.5/dist-packages/txaio/aio.py:201

About this issue

  • Original URL
  • State: closed
  • Created 5 years ago
  • Comments: 18 (17 by maintainers)

Most upvoted comments

During these days we noticed a great improvement in wamp connection stability. So for me, if you agree, you can publish a new release or let me know when it will be possible. Thank you guys!

Also “for the record” the way I was testing this was to give the client-side a very short opening handshake timeout. Less than one second “always fails” for my local tests, and 1 second “sometimes worked” locally.

"options": {
    "openHandshakeTimeout": 0.1
}

Note, as a consequence I think there are other cases where the “correct error-reason string from onClose” will be propagated too. Yay 😃