Setting up websocket communication with caddy

Help
1

1. The problem I’m having:

I am trying to setup a websocket connection between two endpoints with caddy in between. I am using socketio for my server-client communication and everything runs on same host. I already verified the issue is not with the endpoints since direct communication between them works, and they are able to exchange messages using websocket. I enabled debug logs on the client-server endpoints and on caddy. The only thing that I can see that looks like an error, is a streaming error coming from caddy. I tried playing around with the flush_interval, and stream_timeout directives but that didn’t help.
For reference, I use flask-socketio==5.4.1 on the server and python-socketio==5.11.4 on the client. They are compatible so the issue seems to be on caddy side.

2. Error messages and/or full log output:

{"level":"debug","ts":1729413823.2205856,"logger":"http.handlers.reverse_proxy","msg":"selected upstream","dial":"server:5000","total_upstreams":1}
{"level":"debug","ts":1729413823.2251806,"logger":"http.handlers.reverse_proxy","msg":"upstream roundtrip","upstream":"server:5000","duration":0.004468,"request":{"remote_ip":"192.168.65.1","remote_port":"25122","client_ip":"192.168.65.1","proto":"HTTP/1.1","method":"GET","host":"localhost","uri":"/socket.io/?transport=websocket&EIO=4&t=1729413823.186603","headers":{"Sec-Websocket-Version":["13"],"Upgrade":["websocket"],"X-Forwarded-For":["192.168.65.1"],"X-Forwarded-Proto":["http"],"Origin":["http://localhost"],"Sec-Websocket-Key":["WQ8YIfX7kTZnQtoX+Wz+4Q=="],"Connection":["Upgrade"],"User-Agent":[""],"X-Forwarded-Host":["localhost"]}},"headers":{"Upgrade":["websocket"],"Connection":["Upgrade"],"Sec-Websocket-Accept":["rY2qxKxQMRpb2SQPtbKvqd+dA9w="]},"status":101}
{"level":"debug","ts":1729413823.2252693,"logger":"http.handlers.reverse_proxy","msg":"upgrading connection","upstream":"server:5000","duration":0.004468,"request":{"remote_ip":"192.168.65.1","remote_port":"25122","client_ip":"192.168.65.1","proto":"HTTP/1.1","method":"GET","host":"localhost","uri":"/socket.io/?transport=websocket&EIO=4&t=1729413823.186603","headers":{"Sec-Websocket-Version":["13"],"Upgrade":["websocket"],"X-Forwarded-For":["192.168.65.1"],"X-Forwarded-Proto":["http"],"Origin":["http://localhost"],"Sec-Websocket-Key":["WQ8YIfX7kTZnQtoX+Wz+4Q=="],"Connection":["Upgrade"],"User-Agent":[""],"X-Forwarded-Host":["localhost"]}}}
{"level":"debug","ts":1729413823.2885013,"logger":"http.handlers.reverse_proxy","msg":"streaming error","upstream":"server:5000","duration":0.004468,"request":{"remote_ip":"192.168.65.1","remote_port":"25122","client_ip":"192.168.65.1","proto":"HTTP/1.1","method":"GET","host":"localhost","uri":"/socket.io/?transport=websocket&EIO=4&t=1729413823.186603","headers":{"Sec-Websocket-Version":["13"],"Upgrade":["websocket"],"X-Forwarded-For":["192.168.65.1"],"X-Forwarded-Proto":["http"],"Origin":["http://localhost"],"Sec-Websocket-Key":["WQ8YIfX7kTZnQtoX+Wz+4Q=="],"Connection":["Upgrade"],"User-Agent":[""],"X-Forwarded-Host":["localhost"]}}}
{"level":"debug","ts":1729413823.2887127,"logger":"http.handlers.reverse_proxy","msg":"connection closed","upstream":"server:5000","duration":0.004468,"request":{"remote_ip":"192.168.65.1","remote_port":"25122","client_ip":"192.168.65.1","proto":"HTTP/1.1","method":"GET","host":"localhost","uri":"/socket.io/?transport=websocket&EIO=4&t=1729413823.186603","headers":{"Sec-Websocket-Version":["13"],"Upgrade":["websocket"],"X-Forwarded-For":["192.168.65.1"],"X-Forwarded-Proto":["http"],"Origin":["http://localhost"],"Sec-Websocket-Key":["WQ8YIfX7kTZnQtoX+Wz+4Q=="],"Connection":["Upgrade"],"User-Agent":[""],"X-Forwarded-Host":["localhost"]}},"duration":0.063309333}

3. Caddy version:

v2.8.4 h1:q3pe0wpBj1OcHFZ3n/1nl4V4bxBrYoSoab7rL9BMYNk=

4. How I installed and ran Caddy:

a. System environment:

Server: Docker Desktop 4.29.0 (145265)
Engine:
Version: 26.0.0
API version: 1.45 (minimum version 1.24)
Go version: go1.21.8
OS/Arch: linux/arm64
Experimental: false

b. Command:

docker compose up

c. Service/unit/compose file:

services:
    caddy:
        container_name: "caddy"
        build:
          context: ./src/
          dockerfile: Dockerfile
          args:
            APP_URL: http://localhost
            BE_URL: server

docker image:

caddy:2.8.4-alpine

d. My complete Caddy config:

{
    debug
    admin :2019
	servers {
		metrics
	}
}

# Remove http:// to enable TLS
{$APP_URL}

# Set this path to your site's directory.
root * /html/

route {
        @notStatic {
                path /api/* /socket.io/*
        }
        root * static/
        reverse_proxy @notStatic {$BE_URL}:5000 {
            flush_interval -1
            stream_close_delay 5m
        }
        try_files {path} {path}.html html/{path}.html
        file_server

}
log {
        output file /var/log/access.log {
        roll_size       150mb
        roll_keep_for   48h
        roll_keep       5
        }
        format json
        level DEBUG
}

metrics /metrics

5. Links to relevant resources:

2

I recommend structuring your config like this:

{$APP_URL} {
	@notStatic path /api/* /socket.io/*
	handle @notStatic {
		reverse_proxy {$BE_URL}:5000 {
			stream_close_delay 5m
		}
	}

	handle /metrics {
		metrics
	}

	handle {
		root * /static
		try_files {path} {path}.html html/{path}.html
		file_server
	}

	log {
		output file /var/log/access.log {
			roll_size 150mb
			roll_keep_for 48h
			roll_keep 5
		}
	}
}

I think the issue is that the Python app is checking the proxy headers case sensitively instead of insensitively. We have a known issue where headers like Sec-WebSocket-Key are transformed to Sec-Websocket-Key (lowercase S in Socket) because Caddy (more specifically the Go stdlib) transforms header fields to their canonical form (uppercase first letter of each word) to standardize the header casing. This has been fixed in reverseproxy: Use correct cases for websocket related headers by WeidiDeng · Pull Request #6621 · caddyserver/caddy · GitHub so you could try a build from the master branch (or that specifically from commit 48ce47f) for now.

2 Likes
3

Thank you, I changed the Caddyfile as suggested.
I managed to run the latest caddy in my setup and the issue persists. I do get an additional log print now after the streaming error, which states: “hijack failed on protocol switch”.

Here’s the full log:
2024/10/21 08:17:26.350 DEBUG http.handlers.reverse_proxy hijack failed on protocol switch {"upstream": "host.docker.internal:5000", "duration": 0.003785041, "request": {"remote_ip": "192.168.65.1", "remote_port": "34993", "client_ip": "192.168.65.1", "proto": "HTTP/1.1", "method": "GET", "host": "localhost", "uri": "/socket.io/?transport=websocket&EIO=4&t=1729498646.3300722", "headers": {"Origin": ["http://localhost"], "Sec-WebSocket-Key": ["6VoRTCR6sKqAjXpEfSiIBw=="], "Sec-WebSocket-Version": ["13"], "Upgrade": ["websocket"], "User-Agent": [""], "X-Forwarded-Host": ["localhost"], "Connection": ["Upgrade"], "X-Forwarded-For": ["192.168.65.1"], "X-Forwarded-Proto": ["http"]}}, "duration": 0.0065925}

Not sure as to the meaning though.

4

I think think that’s a bug in the logger actually. It used to say “connection closed” – but was recently updated in a performance improvement and I think a copy+paste error was made. See perf: use zap's Check() to prevent useless allocs by dunglas · Pull Request #6560 · caddyserver/caddy · GitHub

I’m pushing a fixed message now.

But anyway, that’s not an error, just informational that the connection was closed after the printed duration.

2 Likes
5

Thank you @matt, I verified with the latest code that the log is gone, but I am still faced with the “streaming error” and closed connection. I compared the python server logs when working with and without caddy. They are identical until the point the websocket connection is established. Afterwards the server is supposed to receive a MESSAGE OPEN packet for connecting to a namespace. When working with a direct connection this step succeeds. So I am assuming caddy is failing to deliver this message, logs the streaming error and shuts down the connection.

These are the logs when caddy isn’t used:

{“asctime”: “2024-10-22 11:08:58,067”, “level”: “DEBUG”, “severity”: “DEBUG”, “thread”: 8396443456, “name”: “geventwebsocket.handler”, “filename”: “handler.py”, “lineno”: 230, “funcname”: “upgrade_connection”, “message”: “WebSocket request accepted, switching protocols”}
{“asctime”: “2024-10-22 11:08:58,068”, “level”: “INFO”, “severity”: “INFO”, “thread”: 8396443456, “name”: “Default”, “filename”: “socket.py”, “lineno”: 76, “funcname”: “send”, “message”: “EFMUIf-AttpE9gBJAAAK: Sending packet OPEN data {‘sid’: ‘EFMUIf-AttpE9gBJAAAK’, ‘upgrades’: , ‘pingTimeout’: 20000, ‘pingInterval’: 25000}”}
{“asctime”: “2024-10-22 11:08:58,068”, “level”: “INFO”, “severity”: “INFO”, “thread”: 8396443456, “name”: “Default”, “filename”: “socket.py”, “lineno”: 88, “funcname”: “handle_get_request”, “message”: “EFMUIf-AttpE9gBJAAAK: Received request to upgrade to websocket”}
{“asctime”: “2024-10-22 11:08:58,068”, “level”: “INFO”, “severity”: “INFO”, “thread”: 8396443456, “name”: “Default”, “filename”: “socket.py”, “lineno”: 215, “funcname”: “_websocket_handler”, “message”: “EFMUIf-AttpE9gBJAAAK: Upgrade to websocket successful”}
{“asctime”: “2024-10-22 11:08:58,069”, “level”: “INFO”, “severity”: “INFO”, “thread”: 8396443456, “name”: “Default”, “filename”: “socket.py”, “lineno”: 39, “funcname”: “receive”, “message”: “EFMUIf-AttpE9gBJAAAK: Received packet MESSAGE data 0/connect,{}”}
{“asctime”: “2024-10-22 11:08:58,070”, “level”: “INFO”, “severity”: “INFO”, “thread”: 8396443456, “name”: “Default”, “filename”: “socket.py”, “lineno”: 76, “funcname”: “send”, “message”: “EFMUIf-AttpE9gBJAAAK: Sending packet MESSAGE data 0/connect,{“sid”:“qkJ2sbGamP3ncQqcAAAL”}”}

These are the server logs when caddy is used. Note the MESSAGE OPEN packet is missing and the connection just closes (probably due to the streaming error on caddy side):

{“asctime”: “2024-10-22 11:11:08,790”, “level”: “DEBUG”, “severity”: “DEBUG”, “thread”: 8396443456, “name”: “geventwebsocket.handler”, “filename”: “handler.py”, “lineno”: 230, “funcname”: “upgrade_connection”, “message”: “WebSocket request accepted, switching protocols”}
{“asctime”: “2024-10-22 11:11:08,790”, “level”: “INFO”, “severity”: “INFO”, “thread”: 8396443456, “name”: “Default”, “filename”: “socket.py”, “lineno”: 76, “funcname”: “send”, “message”: “82hzaKFc_UthR9K-AAAT: Sending packet OPEN data {‘sid’: ‘82hzaKFc_UthR9K-AAAT’, ‘upgrades’: , ‘pingTimeout’: 20000, ‘pingInterval’: 25000}”}
{“asctime”: “2024-10-22 11:11:08,790”, “level”: “INFO”, “severity”: “INFO”, “thread”: 8396443456, “name”: “Default”, “filename”: “socket.py”, “lineno”: 88, “funcname”: “handle_get_request”, “message”: “82hzaKFc_UthR9K-AAAT: Received request to upgrade to websocket”}
{“asctime”: “2024-10-22 11:11:08,790”, “level”: “INFO”, “severity”: “INFO”, “thread”: 8396443456, “name”: “Default”, “filename”: “socket.py”, “lineno”: 215, “funcname”: “_websocket_handler”, “message”: “82hzaKFc_UthR9K-AAAT: Upgrade to websocket successful”}
{“asctime”: “2024-10-22 11:11:08,821”, “level”: “DEBUG”, “severity”: “DEBUG”, “thread”: 8396443456, “name”: “geventwebsocket.handler”, “filename”: “websocket.py”, “lineno”: 368, “funcname”: “close”, “message”: “Closed WebSocket”}

6

@maxamel

package main

import (
	"net/http"
	"net/http/httputil"
	"net/url"
)

func main() {
	u, _ := url.Parse("{$BE_URL}:5000")
	rp := httputil.NewSingleHostReverseProxy(u)
	panic(http.ListenAndServe("address:8080", rp))
}

Can you try something with golang stdlib reverse proxy? Caddy uses a modified version of stdlib reverse proxy. So if this happens with stdlib, stdlib is to blame. If not, caddy is doing something wrong.

1 Like
7

Thanks @WeidiDeng , I managed to reproduce this behavior using the above snippet. I’m not a Go programmer, but as I understand there is an infra issue with the http Go package …?
Also, is there a workaround you can suggest? At the moment, I’m not able to use websockets with Caddy.

8

Does nginx work? I don’t have time to debug this issue for now. I can and will get back to it several days later though.

1 Like
9

I haven’t checked nginx. Let me know when you get back to this and if I can be of any help. Thanks again!

10

@maxamel Can you send me the minimal client and server python codes that will trigger this problem? I tried the basic examples from your mentioned libraries and couldn’t reproduce, the client can connect just fine.

11

client:

import time

import socketio


def test():
    def callback(item):
        print(f'Called back with {item}')

    with socketio.SimpleClient() as sio:
        sio.connect(url='http://localhost/connect', namespace='/connect', transports=['websocket'])
        sio.client.emit('/hello', {}, namespace='/connect', callback=callback)
        time.sleep(5)


if __name__ == '__main__':
    test()

server:

from flask import Flask
from flask_socketio import SocketIO

app = Flask(__name__, template_folder='.')
socketio = SocketIO(app, cors_allowed_origins="*", manage_session=True, async_mode='gevent')


@socketio.on('/hello', namespace='/connect')
def hello(payload):
    print('Hello!')
    return 'OK'


if __name__ == '__main__':
    socketio.run(app, host='0.0.0.0')

This won’t work when traffic passes through caddy but will work when direct communication is used. You will have to install gevent + gevent-websocket in addition to flask and flask-socketio.

12

I tried it locally and it works. Both stdlib reverve proxy and caddy work.

Client side:

Called back with OK

Server side:

Hello!

The headers when passed through stdlib reverse proxy:

GET /socket.io/?transport=websocket&EIO=4&t=1729815723.8410258 HTTP/1.1
Host: localhost:5001
User-Agent: Go-http-client/1.1
Connection: Upgrade
Origin: http://localhost:5001
Sec-Websocket-Key: xM4XUPUS4rffndhgnKe7xw==
Sec-Websocket-Version: 13
Upgrade: websocket

What’s your output when something is wrong in this config?

13

I’m getting this stackstrace:

Traceback (most recent call last):
  File "/Users/mamelchenko/development/chessmine/src/backend/game_server/example_client.py", line 17, in <module>
    test()
  File "/Users/mamelchenko/development/chessmine/src/backend/game_server/example_client.py", line 11, in test
    sio.connect(url='http://localhost/', namespace='/connect', transports=['websocket'])
  File "/Users/mamelchenko/development/chessmine/chessmine/lib/python3.9/site-packages/socketio/simple_client.py", line 82, in connect
    self.client.connect(url, headers=headers, auth=auth,
  File "/Users/mamelchenko/development/chessmine/chessmine/lib/python3.9/site-packages/socketio/client.py", line 168, in connect
    raise exceptions.ConnectionError(
socketio.exceptions.ConnectionError: One or more namespaces failed to connect

Can you specify your python + go versions?
Also, can you make sure your reverse proxy is running on port 80?

14

You mean backend runs at port 5000? If clients directly connects to this port, it will connect successfully. But if a reverse proxy listens at port 80 and forwards request to the backend, the client will fail to connect?

15

Yes that’s correct

16

@maxamel :man_shrugging: not sure what to tell you, if we can’t replicate then we can’t do much here.

1 Like
17

That’s OK, I suspect this is related to my setup. Because it is occurring even with Go lib - it’s likely not a Caddy issue in any case.

18

This topic was automatically closed 30 days after the last reply. New replies are no longer allowed.