nginx not upgraded to websocket

i have a Kubernetes cluster in which nginx:1.21.6 is running as a proxy.

Nginx should upgrade the connection to websocket at path /ws/ and forward it to the service http://dev-websocket:8000.

Since some changes, however, the dev-websocket service seems to receive an HTTP connection. But I can’t find the problem.
Everything works in my local development environment.

django channels runs on dev-websocket behind daphne. The logs in the dev-websocket service should actually look like this:

10.2.0.22:12345 - - [09/Feb/2024:11:00:00] "WSCONNECTING /ws/notifications/" - -
10.2.0.22:12345 - - [09/Feb/2024:11:00:00] "WSCONNECT /ws/notifications/" - -

However, the output is currently:

10.2.0.22:12345 - - [09/Feb/2024:11:00:00] "GET /ws/notifications/" 302 -

My nginx.conf currently looks like this:

pid /tmp/nginx.pid;
worker_processes  1;
events {
  worker_connections  10240;
}
http {
  include /etc/nginx/mime.types;
  client_max_body_size 20m;
  
  gzip on; 
  gzip_vary on; 
  gzip_min_length 1024; 
  gzip_proxied expired no-cache no-store private auth; 
  gzip_types text/plain text/css text/xml text/javascript application/x-javascript application/xml; 
  gzip_disable "MSIE [1-6]\.";

  server {
      listen 8080 default_server;
      server_name _;

      location / {
        proxy_pass http://dev-normalservice:8000/;
      }
      
      location /ws/ {
        proxy_pass http://dev-websocket:8000;
      
        proxy_http_version 1.1;
        proxy_set_header Upgrade $http_upgrade;
        proxy_set_header Connection "Upgrade";
        proxy_set_header Host $host;
        
        proxy_redirect off;
        proxy_set_header X-Real-IP $remote_addr;
        proxy_set_header X-Forwarded-For $proxy_add_x_forwarded_for;
        proxy_set_header X-Forwarded-Host $server_name;
      }

      location /files/static/ {
        alias /files/static/;
        try_files $uri =404;
      }
      
      location /internal/ {
        internal;
        alias /files/private/;
        try_files $uri =404;
      }
      
      location /healthcheck/ {
        access_log off;
        add_header 'Content-Type' 'text/plain';
        return 200;
      }
  }
}

Why does nginx not seem to switch the connection to websocket and forwards the request as http to the dev-websocket service?

The only thing I see materially different between what you have and what I use is that you have:

but I use:

(I have “upgrade” as lower case, not capitalized.)

Now, having said that, it does appear to me that RFC 2616 identifies “Upgrade” as being the proper form. However, the example in the nginx docs at WebSocket proxying show it as lowercase.

Also, a very casual browsing through some of the websocket code in Twisted, it appears to me that it may also be looking for the lowercase version.

Whether this is the root cause of the issue you’re facing, I don’t know.

What asgi container are you using at dev-websocket? (Daphne, uvicorn, something else?)

I have already tried this, but without success.
Daphne runs on dev-websocket.

But my reasoning is basically correct, that nginx upgrades the connection to websocket and only then forwards it to dev-websocket, right?
According to the logs, an HTTP connection obviously arrives at dev-websocket. This means that the error must definitely lie with nginx, right?

That’s not my understanding.

From the blog post at Using NGINX as a WebSocket Proxy

NGINX supports WebSocket by allowing a tunnel to be set up between a client and a backend server. For NGINX to send the Upgrade request from the client to the backend server, the Upgrade and Connection headers must be set explicitly, as in this example:

I read this as saying that Nginx passes the connection request through to the back end, allowing it to handle the connection. It also seem to be to be the case because Daphne itself serves websocket connections.

In fact, I don’t even see any requests logged by nginx when a websocket is being established. A tcpdump of the connection between nginx and daphne shows the request and response. (Logging nginx in debug mode doesn’t really clarify the situation for me. I’m not understanding what I’m seeing there.)

Edited tcpdump:

nginx → daphne

10:17:16.197364 IP 127.0.0.1.51936 > 127.0.0.1.8008: Flags [P.], seq 1:603, ack 1, win 512, options [nop,nop,TS val 1455774365 ecr 1455774365], length 602
E.....@.@.R............H.i..m. *...........
V.Z.V.Z.GET /ws/chat/lobby/ HTTP/1.1
Upgrade: websocket
Connection: upgrade
Host: localhost
X-Real-IP: 127.0.0.1
X-Forwarded-For: 127.0.0.1
Pragma: no-cache
Cache-Control: no-cache
User-Agent: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/121.0.0.0 Safari/537.36
Origin: http://localhost:8000
Sec-WebSocket-Version: 13
Accept-Encoding: gzip, deflate, br
Accept-Language: en-US,en;q=0.9
Cookie: csrftoken=KkMyY54BLHJbixtXtGme2HeehxGOP3EC
Sec-WebSocket-Key: N3hfJEOcGPYMleyZwTq8fg==
Sec-WebSocket-Extensions: permessage-deflate; client_max_window_bits


daphne → nginx

10:17:16.215741 IP 127.0.0.1.8008 > 127.0.0.1.51936: Flags [P.], seq 1:270, ack 603, win 512, options [nop,nop,TS val 1455774383 ecr 1455774365], length 269
E..A..@.@............H..m. *.i.n.....5.....
V.Z.V.Z.HTTP/1.1 101 Switching Protocols
Server: daphne
Upgrade: WebSocket
Connection: Upgrade
Sec-WebSocket-Accept: hw53kSMEiMIPzWppTu2zbvhq9Rw=

.z{"rtc": {"type": "connect", "channel_name": "specific.a39d265bd46d47a1852e09e98b815456!0a19d22a7aca497884f53f4edcb3b2ca"}}

The corresponding daphne log:

127.0.0.1:51936 - - [11/Feb/2024:15:17:16] "WSCONNECTING /ws/chat/lobby/" - -
2024-02-11 15:17:16,198 DEBUG    Upgraded connection ['127.0.0.1', 51936] to WebSocket
2024-02-11 15:17:16,203 DEBUG    <asyncio.TransportSocket fd=14, family=2, type=1, proto=6, laddr=('127.0.0.1', 59810), raddr=('127.0.0.1', 6379)> connected to 127.0.0.1:6379: (<_SelectorSocketTransport fd=14 read=polling write=<idle, bufsize=0>>, <asyncio.streams.StreamReaderProtocol object at 0x7f4cd73a5a60>)
2024-02-11 15:17:16,215 DEBUG    WebSocket ['127.0.0.1', 51936] open and established
127.0.0.1:51936 - - [11/Feb/2024:15:17:16] "WSCONNECT /ws/chat/lobby/" - -
2024-02-11 15:17:16,215 DEBUG    WebSocket ['127.0.0.1', 51936] accepted by application
2024-02-11 15:17:16,215 INFO     ChatConsumer connected
2024-02-11 15:17:16,215 INFO     specific.a39d265bd46d47a1852e09e98b815456!0a19d22a7aca497884f53f4edcb3b2ca
2024-02-11 15:17:16,215 DEBUG    Sent WebSocket packet to client for ['127.0.0.1', 51936]

It may be instructive if you ran daphne with -v 3 to see what it captures.

1 Like