Channels: WebSocket is closed before the connection is established.

[RamezIssac]

Hello ,

This issue is regarding troubleshooting channels deployment behind Nginx.

When code executes the websocket connect , browser developer console logs :
WebSocket connection to 'ws://mydomain/ws-conversation/' failed: WebSocket is closed before the connection is established.
and it keeps on repeating.

runserver output pattern looks like this

2016-07-24 15:21:24,822 - DEBUG - runserver - Worker thread running
2016-07-24 15:21:24,823 - INFO - worker - Listening on channels http.request, websocket.connect, websocket.disconnect, websocket.receive
2016-07-24 15:21:24,823 - DEBUG - runserver - Daphne running, listening on 127.0.0.1:8008
2016-07-24 15:21:24,830 - DEBUG - runserver - Worker thread running
2016-07-24 15:21:24,830 - INFO - worker - Listening on channels http.request, websocket.connect, websocket.disconnect, websocket.receive
2016-07-24 15:22:07,778 - DEBUG - ws_protocol - WebSocket open for websocket.send!HyxutRQa
[2016/07/24 15:22:07] WebSocket CONNECT /ws-conversation/ [127.0.0.1:55202]
2016-07-24 15:22:07,780 - DEBUG - worker - Got message on websocket.connect (reply websocket.send!HyxutRQa)
2016-07-24 15:22:07,781 - DEBUG - worker - Dispatching message on websocket.connect to channels.auth.inner
2016-07-24 15:22:07,787 - DEBUG - http_protocol - Upgraded connection http.response!UcYwJRBL to WebSocket websocket.send!HyxutRQa
2016-07-24 15:22:09,352 - DEBUG - ws_protocol - WebSocket closed for websocket.send!HyxutRQa
[2016/07/24 15:22:09] WebSocket DISCONNECT /ws-conversation/ [127.0.0.1:55202]
2016-07-24 15:22:09,357 - DEBUG - worker - Got message on websocket.disconnect (reply websocket.send!HyxutRQa)
2016-07-24 15:22:09,358 - DEBUG - worker - Dispatching message on websocket.disconnect to conversations.consumers.ws_disconnect
2016-07-24 15:22:40,976 - DEBUG - ws_protocol - WebSocket open for websocket.send!uinbgbns
[2016/07/24 15:22:40] WebSocket CONNECT /ws-conversation/ [127.0.0.1:55203]
2016-07-24 15:22:40,978 - DEBUG - http_protocol - Upgraded connection http.response!mFuNtCCl to WebSocket websocket.send!uinbgbns
2016-07-24 15:22:40,980 - DEBUG - worker - Got message on websocket.connect (reply websocket.send!uinbgbns)
2016-07-24 15:22:40,981 - DEBUG - worker - Dispatching message on websocket.connect to channels.auth.inner
2016-07-24 15:23:11,784 - DEBUG - ws_protocol - WebSocket open for websocket.send!PjtLvmxT
[2016/07/24 15:23:11] WebSocket CONNECT /ws-conversation/ [127.0.0.1:55204]
2016-07-24 15:23:11,785 - DEBUG - http_protocol - Upgraded connection http.response!dQdBXPPt to WebSocket websocket.send!PjtLvmxT
2016-07-24 15:23:11,791 - DEBUG - worker - Got message on websocket.connect (reply websocket.send!PjtLvmxT)
2016-07-24 15:23:11,792 - DEBUG - worker - Dispatching message on websocket.connect to channels.auth.inner
2016-07-24 15:23:13,359 - DEBUG - ws_protocol - WebSocket closed for websocket.send!PjtLvmxT
[2016/07/24 15:23:13] WebSocket DISCONNECT /ws-conversation/ [127.0.0.1:55204]

My nginx configuration looks like this

_/etc/nginx/nginx.conf_

http {
          map $http_upgrade $connection_upgrade {
        default upgrade;
        ''      close;
        }
 ..
server {
    listen 80;
    server_name mydomain;
    location /static {
        alias /var/www/mydomain/collected_static;
    }
    location /media {
        alias /var/www/mydomain/media;
    }
    location / {
        proxy_http_version 1.1;
        proxy_set_header Upgrade $http_upgrade;
        proxy_set_header Connection $connection_upgrade;
        proxy_pass http://127.0.0.1:8008;
    }
}

I tried both
1- proxy_pass to daphne (with workers running of course, all from supervisord)
2- proxy_pass to runserver ip

I also tried to change the channels layer backend from asgi_redis.RedisChannelLayer to asgiref.inmemory.ChannelLayer, didn't help.
I also upgraded Nginx (from 1.4.6 to 1.11.2) and is running on Ubuntu 14.04
pip freeze :

channels==0.17.0
daphne==0.14.3
Django==1.9.8
...

Any thoughts / help on why this is happening ?!

Thank you so much .

---

Update:
I've been using reconnecting-websocket; I dropped it for "natural" socket (used in the docs) , minimized the code in consumers to be just ws_message (the docs message round trip test)
Sadly, problem still occurs,
The developer console log

Failed to execute 'send' on 'WebSocket': Still in CONNECTING state.

[andrewgodwin]

Have you tried connecting to Daphne directly to see if that works? I'd like to rule out the proxy setup if possible.

[RamezIssac]

Not yet , will do right away
How this can be done ? :) Just a lead

[andrewgodwin]

Well, just have Daphne listen on a port and connect to that, e.g.

daphne -b 0.0.0.0 -p 8000 and then connect the websocket to ws://yourhostname:8000.

[RamezIssac]

Ok, did connect directly to daphne and to runserver
Sadly, problem still occurs

The difference between local environment and the staging now is that upgrade response 101 is never actually sent back to the client (though it is visible in the daphne log / runserver log )

2016-07-25 13:53:49,196 - DEBUG - http_protocol - Upgraded connection http.response!XtLABrfCDmAQ to WebSocket websocket.send!ANTmJkvZQBee

[andrewgodwin]

Could you get the close code from the websocket object for me? That might help work out what the browser is seeing. It's event.code on the event passed to the onClose handler.

Also, confirm that this only fails in staging, and not in your local environment?

[RamezIssac]

Ok, as this problem got really un-logic; I created another server, deployed on it, and directly connecting works no problem !!
i'll re-setup nginx proxy and feed you back with the results and with the onClose event.code from the old staging server.

Thank you so much for your support and patience.