Caddy: v2&v1: HTTP/3 breaks support of getting remote IP and port

[qwqVictor]

The version of caddy is 1.0.4 and 2.0beta14.

Config of caddy 2:

{
    "admin": {
        "disabled": true,
        "listen": "",
        "enforce_origin": false,
        "origins": [""],
        "config": {
            "persist": false
        }
    },
    "apps": {
        "http": {
            "servers": {
                "h3-proxy": {
                    "listen": [":2"],
                    "routes": [{
                        "match": [{
                            "host": ["qwq.ren", "*.qwq.ren", "imvictor.tech", "*.imvictor.tech"]
                        }],
                        "handle": [{
                            "handler": "subroute",
                            "routes": [{
                                "handle": [{
                                    "encodings": {
                                        "brotli": {},
                                        "gzip": {}
                                    },
                                    "handler": "encode"
                                }, {
                                    "handler": "reverse_proxy",
                                    "headers": {
                                        "request": {
                                            "set": {
                                                "Host": ["{http.request.host}"],
                                                "X-Forwarded-For": ["{http.request.remote.host}"],
                                                "X-Forwarded-Proto": ["{http.request.scheme}"],
                                                "X-Real-IP": ["{http.request.remote.host}"],
                                                "X-Victors-Test1": ["passed"]
                                            }
                                        }
                                    },
                                    "upstreams": [{
                                        "dial": "127.0.0.1:80"
                                    }]
                                }]
                            }]
                        }],
                        "terminal": true
                    }],
                    "tls_connection_policies": [{
                        "match": {
                            "sni": ["*.imvictor.tech", "qwq.ren", "*.qwq.ren", "imvictor.tech"]
                        },
                        "certificate_selection": {
                            "policy": "custom",
                            "tag": "main-cert"
                        }
                    }, {}],
                    "experimental_http3": true,
                    "automatic_https": {
                        "disable": true
                    }
                }
            }
        },
        "tls": {
            "certificates": {
                "load_files": [{
                    "certificate": "[HIDDEN].cer",
                    "key": "[HIDDEN].key",
                    "tags": ["main-cert"]
                }]
            }
        }
    }
}

Config of caddy 1.0.4:

https://qwq.ren:2 https://*.qwq.ren:2 https://imvictor.tech:2 https://*.imvictor.tech:2 {
    gzip
    proxy / http://127.0.0.1:80 {
        header_upstream Host {host}
        header_upstream X-Forwarded-Proto {scheme}
        header_upstream X-Forwarded-Port {port}
        header_upstream X-Forwarded-For {remote}
        header_upstream X-Real-IP {remote}
        header_upstream X-Victors-Test1 "passed"
        insecure_skip_verify
    }
    tls [HIDDEN].cer [HIDDEN].key
}

Test HTTP/3 with curl 7.69.0-dev, it shows that some headers like X-Forwarded-For or X-Real-IP cannot be passed to the backend,

Victor@Victor-Mac:/tmp » curl-h3 -6 --http3 https://dns-main.imvictor.tech:2/__test/dump -H 'X-Victors-Test0: test'
Port: 80
Remote Addr: 127.0.0.1
Proxy Protocol Addr: 
X-Forwarded-For Header: 
X-Real-IP Header: 
X-Forwarded-Proto Header: https
X-Forwarded-Port Header: 
X-Victors-Test0 Header: test
X-Victors-Test1 Header: passed

while HTTP/2 and HTTP/1.1 both work:

Victor@Victor-Mac:/tmp » curl-h3 -6 --http2 https://dns-main.imvictor.tech:2/__test/dump -H 'X-Victors-Test0: test'
Port: 80
Remote Addr: 2409:8a3c:5b7c:2300:[HIDDEN]
Proxy Protocol Addr: 
X-Forwarded-For Header: 2409:8a3c:5b7c:2300:[HIDDEN]
X-Real-IP Header: 2409:8a3c:5b7c:2300:[HIDDEN]
X-Forwarded-Proto Header: https
X-Forwarded-Port Header: 54881
X-Victors-Test0 Header: test
X-Victors-Test1 Header: passed
Victor@Victor-Mac:/tmp » curl-h3 -6 --http1.1 https://dns-main.imvictor.tech:2/__test/dump -H 'X-Victors-Test0: test'
Port: 80
Remote Addr: 2409:8a3c:5b7c:2300:[HIDDEN]
Proxy Protocol Addr: 
X-Forwarded-For Header: 2409:8a3c:5b7c:2300:[HIDDEN]
X-Real-IP Header: 2409:8a3c:5b7c:2300:[HIDDEN]
X-Forwarded-Proto Header: https
X-Forwarded-Port Header: 55544
X-Victors-Test0 Header: test
X-Victors-Test1 Header: passed

Now I have no idea to make a workaround.

[mholt]

Thanks for the great report, that's very interesting! So it works if experimental_http3 is not enabled, for both Caddy 1 and 2. Since Caddy 1 and 2 have totally different code bases, I'm guessing the problem is in a common denominator.

I'm not sure off-hand, so, pinging @marten-seemann if he has any ideas off the top of his head. Does the quic-go library set or clear the client's address? Specifically, req.RemoteAddr.

[marten-seemann]

@mholt Yes, quic-go does that: https://github.com/lucas-clemente/quic-go/blob/9899be3a06a168f36768cc4a89cc9df6077b3ac7/http3/server.go#L242

Is there anything else that needs to be set for this to work?

[mholt]

Cool, thanks for the link.

Is there anything else that needs to be set for this to work?

Nope, that should be all: https://github.com/caddyserver/caddy/blob/57c6f22684e74191814a30f9de83a05c11ac4b78/modules/caddyhttp/replacer.go#L84-L89

@qwqVictor Let's try debugging this with Caddy 2. Would you mind enabling access logging in your JSON config? All you have to do is set "logs": {} in your server struct: https://caddyserver.com/docs/json/apps/http/servers/logs/

That should output details of HTTP requests to the console when you make requests, including the request header values.

You can also try replacing your reverse_proxy handler with a static_response, like:

{
    "handler": "static_response",
    "body": "Client remote: {http.request.remote} {http.request.remote.host}"
}

Then can you report back with a log and HTTP response?

[qwqVictor]

Cool, thanks for the link.

Is there anything else that needs to be set for this to work?

Nope, that should be all:

https://github.com/caddyserver/caddy/blob/57c6f22684e74191814a30f9de83a05c11ac4b78/modules/caddyhttp/replacer.go#L84-L89

@qwqVictor Let's try debugging this with Caddy 2. Would you mind enabling access logging in your JSON config? All you have to do is set "logs": {} in your server struct: https://caddyserver.com/docs/json/apps/http/servers/logs/

That should output details of HTTP requests to the console when you make requests, including the request header values.

You can also try replacing your reverse_proxy handler with a static_response, like:

{
    "handler": "static_response",
    "body": "Client remote: {http.request.remote} {http.request.remote.host}"
}

Then can you report back with a log and HTTP response?

Sure, I'll enable it. Since HTTP/3 is not widely supported, the access log won't be very large.

[mholt]

@qwqVictor Thanks. To clarify, I mean, enable the log, then make an HTTP/3 request, and let's see what that particular request's log entry looks like. (And the HTTP response body too.)

[qwqVictor]

@qwqVictor Thanks. To clarify, I mean, enable the log, then make an HTTP/3 request, and let's see what that particular request's log entry looks like. (And the HTTP response body too.)

Yes I know, I'm going to enable the log. But I'm not very familiar with Caddy 2, so I might need some time to read the docs.

[mholt]

No problem. It literally would just be "logs": {} next to "experimental_http3": true. That should be all you need, then the access log will be printed to stderr.

[qwqVictor]

I have got the log and formatted it. It suggests that Caddy is unable to get a remote_addr value. @mholt

{
    "request": {
        "method": "GET",
        "uri": "/__test/dump",
        "proto": "HTTP/3",
        "remote_addr": "",
        "host": "qwq.ren:2",
        "headers": {
            "User-Agent": ["curl/7.69.0-DEV"],
            "Accept": ["*/*"]
        },
        "tls": {
            "resumed": false,
            "version": 0,
            "ciphersuite": 0,
            "proto": "",
            "proto_mutual": false,
            "server_name": ""
        }
    },
    "common_log": "- - -- [18/Feb/2020:10:36:18 +0800] \"GET /__test/dump HTTP/3\" 200 294",
    "latency": 0.001040343,
    "size": 294,
    "status": 200,
    "resp_headers": {
        "Server": ["Caddy", "nginx/1.17.8"],
        "Alt-Svc": ["h3-24=\":2\"; ma=2592000"],
        "Date": ["Tue, 18 Feb 2020 02:36:18 GMT"],
        "Content-Type": ["application/octet-stream", "text/plain"],
        "Content-Length": ["294"]
    }
}

[mholt]

@qwqVictor Awesome, thanks!

@marten-seemann For reasons I can't explain, the req.RemoteAddr field is empty on HTTP/3 requests. According to the logs, it is empty even at the very entry point of Caddy's ServeHTTP. Do you think you could help us investigate when you have a chance?

Edit: I just noticed that the tls information is all empty, too. (Not sure if that's related.)

[marten-seemann]

@mholt Sure, let me see what's going on.

[qwqVictor]

@qwqVictor Awesome, thanks!

@marten-seemann For reasons I can't explain, the req.RemoteAddr field is empty on HTTP/3 requests. According to the logs, it is empty even at the very entry point of Caddy's ServeHTTP. Do you think you could help us investigate when you have a chance?

Edit: I just noticed that the tls information is all empty, too. (Not sure if that's related.)

To make sure if it's related to HTTP/3, there is a piece of log dumped from a HTTP/1.1 request. All parameters except HTTP version are the same.

{
    "request": {
        "method": "GET",
        "uri": "/__test/dump",
        "proto": "HTTP/1.1",
        "remote_addr": "[2409:8a3c:5b7a:bb50:HIDDEN_FOR_SEC_REASON]:56631",
        "host": "qwq.ren:2",
        "headers": {
            "User-Agent": ["curl/7.69.0-DEV"],
            "Accept": ["*/*"]
        },
        "tls": {
            "resumed": false,
            "version": 772,
            "ciphersuite": 4867,
            "proto": "http/1.1",
            "proto_mutual": true,
            "server_name": "qwq.ren"
        }
    },
    "common_log": "2409:8a3c:5b7a:bb50:HIDDEN_FOR_SEC_REASON - -- [18/Feb/2020:10:43:51 +0800] \"GET /__test/dump HTTP/1.1\" 200 402",
    "latency": 0.00044381,
    "size": 402,
    "status": 200,
    "resp_headers": {
        "Server": ["Caddy", "nginx/1.17.8"],
        "Alt-Svc": ["h3-24=\":2\"; ma=2592000"],
        "Date": ["Tue, 18 Feb 2020 02:43:51 GMT"],
        "Content-Type": ["application/octet-stream", "text/plain"],
        "Content-Length": ["402"]
    }
}

Hope it could help.

[marten-seemann]

@mholt That's weird. If you want to reproduce my test, here's what I did: I went to the HTTP/3 integration tests in quic-go and added a log line here in the handler:
https://github.com/lucas-clemente/quic-go/blob/9899be3a06a168f36768cc4a89cc9df6077b3ac7/integrationtests/self/http_test.go#L44-L47

And then ran this test https://github.com/lucas-clemente/quic-go/blob/9899be3a06a168f36768cc4a89cc9df6077b3ac7/integrationtests/self/http_test.go#L121-L128. (Replace It by FIt if you just want to run this one test. Then do go test or ginkgo).

The http.Request.RemoteAddr is properly set.
We don't set the TLS field, since this would break 0-RTT request handling (TLS uses a tls.ConnectionState, and the standard library TLS implementation only allows you to get the ConnectionState after the handshake completes).

[mholt]

@qwqVictor Does this happen with an IPv4 address as well?

@marten-seemann

The http.Request.RemoteAddr is properly set.

Seems to be the case... there's gotta be some other factor we aren't considering yet then.

We do call SetQuicHeaders(), but that couldn't possibly affect the request, right? https://github.com/caddyserver/caddy/blob/57c6f22684e74191814a30f9de83a05c11ac4b78/modules/caddyhttp/server.go#L120-L125

I'm out of ideas for right now...

[marten-seemann]

SetQuicHeaders() just takes the http.Header, and adds some values to it. It doesn't even have access to the http.Request struct.

[qwqVictor]

@qwqVictor Does this happen with an IPv4 address as well?

@marten-seemann

The http.Request.RemoteAddr is properly set.

Seems to be the case... there's gotta be some other factor we aren't considering yet then.

We do call SetQuicHeaders(), but that couldn't possibly affect the request, right?

https://github.com/caddyserver/caddy/blob/57c6f22684e74191814a30f9de83a05c11ac4b78/modules/caddyhttp/server.go#L120-L125

I'm out of ideas for right now...

As a matter of fact, it's also broken with IPv4.

[mholt]

@marten-seemann That's what I figured too. Just spitballing here.

@qwqVictor Thanks for checking!

Hmm. This is odd...

[mholt]

@marten-seemann Does the RemoteAddr field ever get cleared or changed after it is initially set?

[marten-seemann]

@mholt It doesn’t. The request gets passed to the handler just a few lines after the remote address is set: https://github.com/lucas-clemente/quic-go/blob/9899be3a06a168f36768cc4a89cc9df6077b3ac7/http3/server.go#L270

[qwqVictor]

I think bug and v2 labels can be added to this issue. Looks like that it's a strange bug, which needs more attention.

[mholt]

FWIW, I'm currently convinced that the bug is upstream. Can't prove it either way yet, so I might be wrong, but from what I know of the Caddy code base, that's my current suspicion. I don't have the time or funding to spend more time on this right now (especially since the HTTP/3 integration is still experimental), but feel free to drill down more if you want a quicker fix! It will help a lot.

[francislavoie]

I'm just going through old issues, @qwqVictor could you confirm if this is still an issue on the latest build from master? No rush at all, but I think we could close this unless some new information arises.

[qwqVictor]

I'm going to confirm this. But as version goes, the structure of config seems to have changed. I have to find out the right way to configure it before I can confirm it.

[francislavoie]

Sure, let us know if you need help with validating your config.

[qwqVictor]

I'm very glad to see the problem fixed. Thank you all for your hard work.