Websocket connection failed(WSREJECT) in production. (Nginx, Gunicorn, Daphne)

KenWhitesell · January 11, 2024, 2:30pm

That is not correct. Please review the nginx docs at

Dannyblazer · January 11, 2024, 4:36pm

Okay,
wss://146.190.21.111/ws/some_path
wss://www.taskitly.com/ws/some_path
wss://api.taskitly.com/ws/some_path
wss://www.api.taskitly.com/ws/some_path
wss://taskitly.com/ws/some_path

will be forwarded to daphne

Tried connecting with these, here is the response:

-- request header ---
GET /ws/notification/ HTTP/1.1
Upgrade: websocket
Host: taskitly.com
Origin: https://taskitly.com
Sec-WebSocket-Key: 77GM6Sce63pvcQwSZMmYSA==
Sec-WebSocket-Version: 13
Connection: Upgrade


-----------------------
--- response header ---
HTTP/1.1 502 Bad Gateway
Server: nginx/1.24.0 (Ubuntu)
Date: Thu, 11 Jan 2024 16:38:23 GMT
Content-Type: text/html
Content-Length: 166
Connection: keep-alive
-----------------------
WebSocket error: Handshake status 502 Bad Gateway -+-+- {'server': 'nginx/1.24.0 (Ubuntu)', 'date': 'Thu, 11 Jan 2024 16:38:23 GMT', 'content-type': 'text/html', 'content-length': '166', 'connection': 'keep-alive'} -+-+- b'<html>\r\n<head><title>502 Bad Gateway</title></head>\r\n<body>\r\n<center><h1>502 Bad Gateway</h1></center>\r\n<hr><center>nginx/1.24.0 (Ubuntu)</center>\r\n</body>\r\n</html>\r\n'
Handshake status 502 Bad Gateway -+-+- {'server': 'nginx/1.24.0 (Ubuntu)', 'date': 'Thu, 11 Jan 2024 16:38:23 GMT', 'content-type': 'text/html', 'content-length': '166', 'connection': 'keep-alive'} -+-+- b'<html>\r\n<head><title>502 Bad Gateway</title></head>\r\n<body>\r\n<center><h1>502 Bad Gateway</h1></center>\r\n<hr><center>nginx/1.24.0 (Ubuntu)</center>\r\n</body>\r\n</html>\r\n' - goodbye
WebSocket closed

KenWhitesell · January 11, 2024, 5:02pm

And does your Channels router handle a url named /ws/notification/?

Dannyblazer · January 11, 2024, 6:58pm

Seems not, here’s the asgi router conf before:

application = ProtocolTypeRouter({
    "http": django_asgi_app,
    "websocket": AllowedHostsOriginValidator(  
        TokenAuthMiddleware(
            URLRouter([
                    re_path(r"chat/$", ChatConsumer.as_asgi()),
                    re_path(r"notification/$", NotificationConsumer.as_asgi()),
            ])
        )
    )
})

But I changed it to this:

application = ProtocolTypeRouter({
    "http": django_asgi_app,
    "websocket": AllowedHostsOriginValidator(  
        TokenAuthMiddleware(
            URLRouter([
                    re_path(r"ws/chat/$", ChatConsumer.as_asgi()),
                    re_path(r"ws/notification/$", NotificationConsumer.as_asgi()),
            ])
        )
    )
})

Got the same response

WebSocket error: Handshake status 502 Bad Gateway -+-+- {'server': 'nginx/1.24.0 (Ubuntu)', 'date': 'Thu, 11 Jan 2024 18:52:05 GMT', 'content-type': 'text/html', 'content-length': '166', 'connection': 'keep-alive'} -+-+- b'<html>\r\n<head><title>502 Bad Gateway</title></head>\r\n<body>\r\n<center><h1>502 Bad Gateway</h1></center>\r\n<hr><center>nginx/1.24.0 (Ubuntu)</center>\r\n</body>\r\n</html>\r\n'
Handshake status 502 Bad Gateway -+-+- {'server': 'nginx/1.24.0 (Ubuntu)', 'date': 'Thu, 11 Jan 2024 18:52:05 GMT', 'content-type': 'text/html', 'content-length': '166', 'connection': 'keep-alive'} -+-+- b'<html>\r\n<head><title>502 Bad Gateway</title></head>\r\n<body>\r\n<center><h1>502 Bad Gateway</h1></center>\r\n<hr><center>nginx/1.24.0 (Ubuntu)</center>\r\n</body>\r\n</html>\r\n' - goodbye
WebSocket closed

KenWhitesell · January 11, 2024, 7:05pm

There should be something in the nginx error logs for these requests.

Please confirm that Daphne is up and running and listening to the same port that nginx is going to proxy the requests through.

Also look at the Daphne logs to help determine whether the issue is in the nginx configuration or Daphne, or the application.

You may also want to set your nginx logging level to either info (or debug if it’s configured to provide it) for more detailed information. (See Configuring Logging | NGINX Documentation and Core functionality)

Dannyblazer · January 11, 2024, 8:02pm

here’s the error log from nginx:

2024/01/11 19:48:39 [error] 167986#167986: *2 upstream prematurely closed connection while reading response header from upstream, client: 105.120.130.4, server: 146.190.21.111, request: "GET /ws/notification/ HTTP/1.1", upstream: "http://127.0.0.1:8001/ws/notification/", host: "taskitly.com"
2024/01/11 19:49:56 [error] 167986#167986: *4 open() "/usr/share/nginx/html/.env" failed (2: No such file or directory), client: 54.37.79.75, server: 146.190.21.111, request: "GET /.env HTTP/1.1", host: "146.190.21.111"
2024/01/11 19:54:18 [error] 167986#167986: *12 upstream prematurely closed connection while reading response header from upstream, client: 105.120.130.4, server: 146.190.21.111, request: "GET /ws/notification/ HTTP/1.1", upstream: "http://127.0.0.1:8001/ws/notification/", host: "taskitly.com"
2024/01/11 19:55:00 [error] 167986#167986: *14 upstream prematurely closed connection while reading response header from upstream, client: 105.120.130.4, server: 146.190.21.111, request: "GET /ws/chat/ HTTP/1.1", upstream: "http://127.0.0.1:8001/ws/chat/", host: "taskitly.com"

Daphne is running and listening on 0.0.0.0.8001:

     Loaded: loaded (/etc/systemd/system/daphne.service; disabled; preset: enabled)
     Active: active (running) since Thu 2024-01-11 19:47:23 UTC; 9min ago
   Main PID: 167991 (python)
      Tasks: 2 (limit: 2308)
     Memory: 73.5M
        CPU: 1.473s
     CGroup: /system.slice/daphne.service
             └─167991 /home/taskitly/taskily/venv/bin/python /home/taskitly/taskily/venv/bin/daphne -e ssl:8001:privateKey=/etc/letsencrypt/live/api>

Jan 11 19:47:23 taskitly.com systemd[1]: Started daphne.service - WebSocket Daphne Service.
Jan 11 19:47:24 taskitly.com python[167991]: 2024-01-11 20:47:24,254 INFO     Starting server at ssl:8001:privateKey=/etc/letsencrypt/live/api.taski>
Jan 11 19:47:24 taskitly.com python[167991]: 2024-01-11 20:47:24,255 INFO     HTTP/2 support enabled
Jan 11 19:47:24 taskitly.com python[167991]: 2024-01-11 20:47:24,256 INFO     Configuring endpoint ssl:8001:privateKey=/etc/letsencrypt/live/api.tas>
Jan 11 19:47:24 taskitly.com python[167991]: 2024-01-11 20:47:24,262 INFO     Listening on TCP address 0.0.0.0:8001
root@taskitly:/home/taskitly/taskily#

I don’t know why Daphne doesn’t get any logs (Maybe nginx isn’t able to proxy requests to the running daphne.service)

After checking nginx conf , I stopped daphne.service and used daphne -b 0.0.0.0 -p 8001 taskitly.asgi:application
I was then able to connect using the python script and also through postman.

From nginx conf, it seems the proxypass is on not reaching daphne.service

Dannyblazer:

location / {
        include proxy_params;
        proxy_pass http://unix:/run/gunicorn.sock;
    }

    location /ws/ {                              
        proxy_http_version 1.1;
        proxy_set_header Upgrade $http_upgrade;
        proxy_set_header Connection "upgrade";
        proxy_redirect off;
        proxy_pass http://127.0.0.1:8001;
    }

Here’s daphne.service.

[Unit]
Description=WebSocket Daphne Service
After=network.target

[Service]
Type=simple
User=root
WorkingDirectory=/home/taskitly/taskily/src
ExecStart=/home/taskitly/taskily/venv/bin/python /home/taskitly/taskily/venv/bin/daphne -e ssl:8001:privateKey=/etc/letsencrypt/live/api.taskitly.co>
Restart=on-failure

[Install]
WantedBy=multi-user.target

KenWhitesell · January 11, 2024, 9:13pm

Daphne doesn’t need to handle ssl. You’re not proxying an ssl connection, you’re proxying a regular http.

You can remove the -e and its parameters.

Dannyblazer · January 11, 2024, 9:19pm

The connection was refused, from nginx error log;

2024/01/11 19:54:18 [error] 167986#167986: *12 upstream prematurely closed connection while reading response header from upstream, client: 105.120.130.4, server: 146.190.21.111, request: "GET /ws/notification/ HTTP/1.1", upstream: "http://127.0.0.1:8001/ws/notification/", host: "taskitly.com"
2024/01/11 19:55:00 [error] 167986#167986: *14 upstream prematurely closed connection while reading response header from upstream, client: 105.120.130.4, server: 146.190.21.111, request: "GET /ws/chat/ HTTP/1.1", upstream: "http://127.0.0.1:8001/ws/chat/", host: "taskitly.com"
2024/01/11 20:28:10 [error] 167986#167986: *53 open() "/usr/share/nginx/html/.env" failed (2: No such file or directory), client: 54.37.79.75, server: 146.190.21.111, request: "GET /.env HTTP/1.1", host: "146.190.21.111"
2024/01/11 20:49:44 [error] 167986#167986: *68 recv() failed (104: Connection reset by peer) while proxying upgraded connection, client: 105.120.131.196, server: 146.190.21.111, request: "GET /ws/notification/ HTTP/1.1", upstream: "http://127.0.0.1:8001/ws/notification/", host: "taskitly.com"
2024/01/11 20:59:34 [error] 167986#167986: *78 recv() failed (104: Connection reset by peer) while proxying upgraded connection, client: 105.120.131.196, server: 146.190.21.111, request: "GET /ws/notification/ HTTP/1.1", upstream: "http://127.0.0.1:8001/ws/notification/", host: "taskitly.com"
2024/01/11 20:59:47 [error] 167986#167986: *80 recv() failed (104: Connection reset by peer) while proxying upgraded connection, client: 105.120.131.196, server: 146.190.21.111, request: "GET /ws/notification/ HTTP/1.1", upstream: "http://127.0.0.1:8001/ws/notification/", host: "taskitly.com"
2024/01/11 21:02:10 [error] 167986#167986: *82 open() "/usr/share/nginx/html/.env" failed (2: No such file or directory), client: 95.214.235.169, server: 146.190.21.111, request: "GET /.env HTTP/1.1", host: "146.190.21.111"
2024/01/11 21:16:00 [error] 167986#167986: *90 connect() failed (111: Connection refused) while connecting to upstream, client: 105.120.131.196, server: 146.190.21.111, request: "GET /ws/chat/ HTTP/1.1", upstream: "http://127.0.0.1:8001/ws/chat/", host: "taskitly.com"
2024/01/11 21:16:33 [error] 167986#167986: *102 connect() failed (111: Connection refused) while connecting to upstream, client: 105.120.131.196, server: 146.190.21.111, request: "GET /ws/chat/ HTTP/1.1", upstream: "http://127.0.0.1:8001/ws/chat/", host: "taskitly.com"

Here’s the new daphne.service;

Unit]
Description=WebSocket Daphne Service
After=network.target

[Service]
Type=simple
User=root
WorkingDirectory=/home/taskitly/taskily/src
ExecStart=/home/taskitly/taskily/venv/bin/python /home/taskitly/taskily/venv/bin/daphne taskitly.asgi:application
Restart=on-failure

[Install]
WantedBy=multi-user.target

KenWhitesell · January 11, 2024, 9:22pm

What are you seeing from Daphne?

Dannyblazer · January 11, 2024, 9:24pm

here’s daphne.service log

● daphne.service - WebSocket Daphne Service
     Loaded: loaded (/etc/systemd/system/daphne.service; disabled; preset: enabled)
     Active: active (running) since Thu 2024-01-11 21:15:40 UTC; 8min ago
   Main PID: 171887 (python)
      Tasks: 1 (limit: 2308)
     Memory: 87.9M
        CPU: 1.836s
     CGroup: /system.slice/daphne.service
             └─171887 /home/taskitly/taskily/venv/bin/python /home/taskitly/taskily/venv/bin/daphne taskitly.asgi:application

Jan 11 21:15:40 taskitly.com systemd[1]: Started daphne.service - WebSocket Daphne Service.
Jan 11 21:15:42 taskitly.com python[171887]: 2024-01-11 22:15:42,982 INFO     Starting server at tcp:port=8000:interface=127.0.0.1
Jan 11 21:15:42 taskitly.com python[171887]: 2024-01-11 22:15:42,984 INFO     HTTP/2 support enabled
Jan 11 21:15:42 taskitly.com python[171887]: 2024-01-11 22:15:42,984 INFO     Configuring endpoint tcp:port=8000:interface=127.0.0.1
Jan 11 21:15:42 taskitly.com python[171887]: 2024-01-11 22:15:42,985 INFO     Listening on TCP address 127.0.0.1:8000

KenWhitesell · January 11, 2024, 9:27pm

What’s wrong with this picture?

Dannyblazer:

Jan 11 21:15:42 taskitly.com python[171887]: 2024-01-11 22:15:42,982 INFO     Starting server at tcp:port=8000:interface=127.0.0.1
Jan 11 21:15:42 taskitly.com python[171887]: 2024-01-11 22:15:42,984 INFO     HTTP/2 support enabled
Jan 11 21:15:42 taskitly.com python[171887]: 2024-01-11 22:15:42,984 INFO     Configuring endpoint tcp:port=8000:interface=127.0.0.1
Jan 11 21:15:42 taskitly.com python[171887]: 2024-01-11 22:15:42,985 INFO     Listening on TCP address 127.0.0.1:8000

and

Dannyblazer · January 11, 2024, 9:35pm

Had to bind daphne to 0.0.0.0:8001

[Unit]
Description=WebSocket Daphne Service
After=network.target

[Service]
Type=simple
User=root
WorkingDirectory=/home/taskitly/taskily/src
ExecStart=/home/taskitly/taskily/venv/bin/python /home/taskitly/taskily/venv/bin/daphne -u 0.0.0.0 -p 8001 taskitly.asgi:application
Restart=on-failure

[Install]
WantedBy=multi-user.target

here’s the new daphne log;

 daphne.service - WebSocket Daphne Service
     Loaded: loaded (/etc/systemd/system/daphne.service; disabled; preset: enabled)
     Active: active (running) since Thu 2024-01-11 21:32:15 UTC; 9s ago
   Main PID: 173375 (python)
      Tasks: 1 (limit: 2308)
     Memory: 70.3M
        CPU: 1.225s
     CGroup: /system.slice/daphne.service
             └─173375 /home/taskitly/taskily/venv/bin/python /home/taskitly/taskily/venv/bin/daphne -u 0.0.0.0 -p 8001 taskitly.asgi:application

Jan 11 21:32:15 taskitly.com systemd[1]: Started daphne.service - WebSocket Daphne Service.
Jan 11 21:32:16 taskitly.com python[173375]: 2024-01-11 22:32:16,637 INFO     Starting server at tcp:port=8001:interface=127.0.0.1, unix:0.0.0.0
Jan 11 21:32:16 taskitly.com python[173375]: 2024-01-11 22:32:16,638 INFO     HTTP/2 support enabled
Jan 11 21:32:16 taskitly.com python[173375]: 2024-01-11 22:32:16,638 INFO     Configuring endpoint tcp:port=8001:interface=127.0.0.1
Jan 11 21:32:16 taskitly.com python[173375]: 2024-01-11 22:32:16,639 INFO     Listening on TCP address 127.0.0.1:8001
Jan 11 21:32:16 taskitly.com python[173375]: 2024-01-11 22:32:16,640 INFO     Configuring endpoint unix:0.0.0.0

After this, I was able to connect to it.

Dannyblazer · January 11, 2024, 9:38pm

Finally get log reports from daphne.service

● daphne.service - WebSocket Daphne Service
     Loaded: loaded (/etc/systemd/system/daphne.service; disabled; preset: enabled)
     Active: active (running) since Thu 2024-01-11 21:32:15 UTC; 5min ago
   Main PID: 173375 (python)
      Tasks: 2 (limit: 2308)
     Memory: 75.1M
        CPU: 1.542s
     CGroup: /system.slice/daphne.service
             └─173375 /home/taskitly/taskily/venv/bin/python /home/taskitly/taskily/venv/bin/daphne -u 0.0.0.0 -p 8001 taskitly.asgi:application

Jan 11 21:33:03 taskitly.com python[173375]:            ^^^^^^^^^^^^^^^^^^^^^
Jan 11 21:33:03 taskitly.com python[173375]:   File "/usr/lib/python3.11/json/__init__.py", line 346, in loads
Jan 11 21:33:03 taskitly.com python[173375]:     return _default_decoder.decode(s)
Jan 11 21:33:03 taskitly.com python[173375]:            ^^^^^^^^^^^^^^^^^^^^^^^^^^
Jan 11 21:33:03 taskitly.com python[173375]:   File "/usr/lib/python3.11/json/decoder.py", line 337, in decode
Jan 11 21:33:03 taskitly.com python[173375]:     obj, end = self.raw_decode(s, idx=_w(s, 0).end())
Jan 11 21:33:03 taskitly.com python[173375]:                ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
Jan 11 21:33:03 taskitly.com python[173375]:   File "/usr/lib/python3.11/json/decoder.py", line 355, in raw_decode
Jan 11 21:33:03 taskitly.com python[173375]:     raise JSONDecodeError("Expecting value", s, err.value) from None
Jan 11 21:33:03 taskitly.com python[173375]: json.decoder.JSONDecodeError: Expecting value: line 1 column 1 (char 0)

Dannyblazer · January 11, 2024, 10:11pm

Thank you very much for your time.

Topic		Replies	Views
Websocket connection failed in production. (Nginx, Gunicorn, Daphne) (Django/React) Async/Channels	15	10027	March 15, 2024
Daphne: websocket works locally with ws protocol, but it connects and quickly disconnects in production Async/Channels	26	3024	February 17, 2024
Websocket + Django on production (https) Async/Channels	25	17623	February 26, 2025
django websocket not working properly using daphne and nginx Async/Channels	22	770	September 18, 2024
Django Websockets deployment issue Deployment	5	1540	September 28, 2023

Websocket connection failed(WSREJECT) in production. (Nginx, Gunicorn, Daphne)

Related topics