crossbario / crossbario/autobahn-python

ApplicationRunner doesn't shut down properly if connection fails before handshake completes

Open
#559 14 comments 0 reactions 0 assignees View on GitHub

Nobody has claimed this yet.

bug wamp
Dominant language
Python
Stars
2.5k
Forks
768
PR merge metrics
No merged PRs in 30d

Description

I have a crossbar.io instance running behind an nginx with the current config:

   upstream websocket {
      server 127.0.0.1:8080;
   }
   map $http_upgrade $connection_upgrade {
     default upgrade;
     ''      close;
   }
   server {
   ...
    location = /ws {
        # switch off logging
        access_log off;
        auth_basic off;

        # redirect all HTTP traffic to localhost:8080
        proxy_pass http://websocket;
        proxy_set_header X-Real-IP $remote_addr;
        proxy_set_header X-Forwarded-For $proxy_add_x_forwarded_for;
        proxy_set_header X-Scheme $scheme;
        proxy_set_header Host localhost:8080;

        # WebSocket support (nginx 1.4)
        proxy_http_version 1.1;
        proxy_set_header Upgrade $http_upgrade;
        proxy_set_header Connection $connection_upgrade;
    }
}

Taking as example https://github.com/crossbario/autobahn-python/blob/master/examples/twisted/wamp/app/hello/hello.py
with small modifications (changing the url port)

If crossbar.io is running before the application is started, everything works perfectly.

But if crossbar is down the moment the app begins I got the following response and the application never ends (the reactor is not stopped even if I add the onDisconnect event)

2015-12-01 16:38:16+0000 [-] Log opened.
2015-12-01 16:38:16+0000 [-] Starting factory <autobahn.twisted.websocket.WampWebSocketClientFactory object at 0x7f490d3f3110>
2015-12-01 16:38:16+0000 [-]
    [('debug', True, 'WampWebSocketClientFactory'),
     ('debugCodePaths', False, 'WampWebSocketClientFactory'),
     ('logOctets', True, 'WampWebSocketClientFactory'),
     ('logFrames', True, 'WampWebSocketClientFactory'),
     ('trackTimings', False, 'WampWebSocketClientFactory'),
     ('allowHixie76', 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 <lambda> at 0x7f490e2e9758>,
      'WampWebSocketClientFactory')]
2015-12-01 16:38:16+0000 [-] connection to tcp4:127.0.0.1:80 established
2015-12-01 16:38:16+0000 [-] TX Octets to tcp4:127.0.0.1:80 : sync = False, octets = 474554202f777320485454502f312e310d0a557365722d4167656e743a204175746f6261686e507974686f6e2f302e31302e390d0a486f73743a203132372e302e302e313a38300d0a557067726164653a20576562536f636b65740d0a436f6e6e656374696f6e3a20557067726164650d0a507261676d613a206e6f2d63616368650d0a43616368652d436f6e74726f6c3a206e6f2d63616368650d0a5365632d576562536f636b65742d4b65793a206d303477794f74706d307466774759564773567874513d3d0d0a5365632d576562536f636b65742d50726f746f636f6c3a2077616d702e322e6a736f6e2e626174636865642c77616d702e322e6a736f6e0d0a5365632d576562536f636b65742d56657273696f6e3a2031330d0a0d0a
2015-12-01 16:38:16+0000 [-] GET /ws HTTP/1.1
    User-Agent: AutobahnPython/0.10.9
    Host: 127.0.0.1:80
    Upgrade: WebSocket
    Connection: Upgrade
    Pragma: no-cache
    Cache-Control: no-cache
    Sec-WebSocket-Key: m04wyOtpm0tfwGYVGsVxtQ==
    Sec-WebSocket-Protocol: wamp.2.json.batched,wamp.2.json
    Sec-WebSocket-Version: 13


2015-12-01 16:38:16+0000 [-] RX Octets from tcp4:127.0.0.1:80 : octets = 485454502f312e31203530322042616420476174657761790d0a5365727665723a206e67696e782f312e362e320d0a446174653a205475652c2030312044656320323031352031363a33383a313620474d540d0a436f6e74656e742d547970653a20746578742f68746d6c0d0a436f6e74656e742d4c656e6774683a203137320d0a436f6e6e656374696f6e3a206b6565702d616c6976650d0a0d0a3c68746d6c3e0d0a3c686561643e3c7469746c653e3530322042616420476174657761793c2f7469746c653e3c2f686561643e0d0a3c626f6479206267636f6c6f723d227768697465223e0d0a3c63656e7465723e3c68313e3530322042616420476174657761793c2f68313e3c2f63656e7465723e0d0a3c68723e3c63656e7465723e6e67696e782f312e362e323c2f63656e7465723e0d0a3c2f626f64793e0d0a3c2f68746d6c3e0d0a
2015-12-01 16:38:16+0000 [-] received HTTP response:

    HTTP/1.1 502 Bad Gateway
    Server: nginx/1.6.2
    Date: Tue, 01 Dec 2015 16:38:16 GMT
    Content-Type: text/html
    Content-Length: 172
    Connection: keep-alive




2015-12-01 16:38:16+0000 [-] received HTTP status line in opening handshake : HTTP/1.1 502 Bad Gateway
2015-12-01 16:38:16+0000 [-] Unable to format event {'log_namespace': 'autobahn.twisted.websocket.WampWebSocketClientFactory', 'log_level': <LogLevel=debug>, 'format': '%(log_legacy)s', 'time': 1448987896.668816, 'log_source': <autobahn.twisted.websocket.WampWebSocketClientFactory object at 0x7f490d3f3110>, 'log_format': "received HTTP headers in opening handshake : {u'date': u'Tue, 01 Dec 2015 16:38:16 GMT', u'content-length': u'172', u'content-type': u'text/html', u'connection': u'keep-alive', u'server': u'nginx/1.6.2'}", 'system': '-', 'log_logger': <Logger 'autobahn.twisted.websocket.WampWebSocketClientFactory'>, 'message': (), 'log_time': 1448987896.668816}: u"u'date'"
2015-12-01 16:38:16+0000 [-] failing WebSocket opening handshake ('WebSocket connection upgrade failed (502 - BadGateway)')
2015-12-01 16:38:16+0000 [-] Connection to/from tcp4:127.0.0.1:80 was aborted locally
2015-12-01 16:38:16+0000 [-] Stopping factory <autobahn.twisted.websocket.WampWebSocketClientFactory object at 0x7f490d3f3110>

Contributor guide

Open the contributing guide

First steps

  1. Read the whole issue, then the project's contributing guide.
  2. Comment on the issue to say you are picking it up — it saves two people doing the same work.
  3. Fork the repository and make your change on a branch.
  4. Open a pull request that references the issue number.

Research direction

Start with the Twisted WAMP ApplicationRunner path shown by the hello.py example and reproduce the failure while Crossbar is unavailable. Trace the failed opening handshake and shutdown callbacks; done means the application terminates cleanly and the reactor stops after the connection failure.

Written by the indexing model from the issue text.

Assessment

Tech stack
python
Domain
backend, networking
Issue type
Bug
Difficulty
4/5
Estimated time
3-5 days
Activity status
Stale
Clarity
Needs clarification
Newbie friendliness
30/100

Get new issues in your inbox

A short digest of beginner-friendly GitHub issues.