caddyserver / caddy

Fast and extensible multi-platform HTTP/1-2-3 web server with automatic HTTPS
https://caddyserver.com
Apache License 2.0
58.4k stars 4.04k forks source link

HTTP3 response payload missing from the packet capture #6478

Open marcindulak opened 3 months ago

marcindulak commented 3 months ago

I'm not sure this is caddy issue, however I don't experience this problem against nginx.

To reproduce

  1. Create Caddyfile in the current working directory

    localhost:443 {
    tls internal {
        insecure_secrets_log /mnt/SSLKEYLOGFILE
    }
    handle / {
        respond "Hello, HTTP version {http.request.proto}!"
    }
    }
  2. Configure caddy on debian:unstable, which currently provides curl with http3 support 8.9.0. Note: this is downloading caddy for Mac M? arm64, otherwise use amd64

    docker run --detach --rm -v $PWD:/mnt --name caddy debian:unstable sh -c "sleep infinity"
    docker exec -it caddy sh -c "apt-get update && DEBIAN_FRONTEND=noninteractive apt-get install -y curl tcpdump wireshark-common tshark"
    docker exec -it caddy sh -c "curl -sLO https://github.com/caddyserver/caddy/releases/download/v2.8.4/caddy_2.8.4_linux_arm64.deb && dpkg -i caddy_2.8.4_linux_arm64.deb"
    docker cp Caddyfile caddy:/etc/caddy/Caddyfile
    docker exec -it caddy sh -c "caddy start --config /etc/caddy/Caddyfile"
  3. Start packet capture with tcpdump

    docker exec -it caddy sh -c "tcpdump -i lo -w /tmp/test.pcap '(tcp or udp) and port 443'"
  4. In other terminal, make curl HTTP3 request. Note that the server returns the expected response Hello, HTTP version HTTP/3.0!

    docker exec -it caddy sh -c "curl -v --http3 https://localhost"
  5. Stop the packet capture and decrypt the traffic

    docker exec -it caddy sh -c "cp /tmp/test.pcap /mnt"
    docker exec -it caddy sh -c "cd /mnt && editcap --inject-secrets tls,SSLKEYLOGFILE test.pcap test.pcapng"

Result

The caddy server (v2.8.4 h1:q3pe0wpBj1OcHFZ3n/1nl4V4bxBrYoSoab7rL9BMYNk=) response is successful according to the curl output

* Host localhost:443 was resolved.
* IPv6: ::1
* IPv4: 127.0.0.1
*   Trying [::1]:443...
* Immediate connect fail for ::1: Cannot assign requested address
*   Trying 127.0.0.1:443...
* GnuTLS ciphers: NORMAL:-VERS-ALL:+VERS-TLS1.3:-CIPHER-ALL:+AES-128-GCM:+AES-256-GCM:+CHACHA20-POLY1305:+AES-128-CCM:-GROUP-ALL:+GROUP-SECP256R1:+GROUP-X25519:+GROUP-SECP384R1:+GROUP-SECP521R1:%DISABLE_TLS13_COMPAT_MODE
* found 147 certificates in /etc/ssl/certs/ca-certificates.crt
* found 441 certificates in /etc/ssl/certs
* SSL connection using TLS1.3 / ECDHE_RSA_AES_128_GCM_SHA256
*   server certificate verification OK
*   server certificate status verification SKIPPED
* error fetching CN from cert:The requested data were not available.
*   common name:  (matched)
*   server certificate expiration date OK
*   server certificate activation date OK
*   certificate public key: EC/ECDSA
*   certificate version: #3
* Failed to get certificate name
*   issuer: CN=Caddy Local Authority - ECC Intermediate
* Connected to localhost (127.0.0.1) port 443
* using HTTP/3
* [HTTP/3] [0] OPENED stream for https://localhost/
* [HTTP/3] [0] [:method: GET]
* [HTTP/3] [0] [:scheme: https]
* [HTTP/3] [0] [:authority: localhost]
* [HTTP/3] [0] [:path: /]
* [HTTP/3] [0] [user-agent: curl/8.9.0]
* [HTTP/3] [0] [accept: */*]
> GET / HTTP/3
> Host: localhost
> User-Agent: curl/8.9.0
> Accept: */*
> 
* Request completely sent off
< HTTP/3 200 
< server: Caddy
< content-type: text/plain; charset=utf-8
< date: Fri, 26 Jul 2024 18:49:34 GMT
< content-length: 29
< 
* Connection #0 to host localhost left intact
Hello, HTTP version HTTP/3.0!%                            

However, there seems to be no HTTP3 response containing the actual HTML body. This is shown by reading the packet capture with docker exec -it caddy sh -c "cd /mnt && tshark -r test.pcapng", where HTTP3 stops at HEADERS

    1   0.000000    127.0.0.1 ? 127.0.0.1    QUIC 1242 Initial, DCID=2a4cbab33a2aaa299483ac8b8c0c8dd7fddfc091, SCID=6b71db4b43c67e58f7d7293b72333b4c1c80c916, PKN: 0, CRYPTO, PADDING
    2   0.008311    127.0.0.1 ? 127.0.0.1    QUIC 1322 Handshake, DCID=6b71db4b43c67e58f7d7293b72333b4c1c80c916, SCID=f9c4f3f5, PKN: 0, CRYPTO
    3   0.008327    127.0.0.1 ? 127.0.0.1    QUIC 254 Protected Payload (KP0), DCID=6b71db4b43c67e58f7d7293b72333b4c1c80c916, PKN: 0, NCI
    4   0.008483    127.0.0.1 ? 127.0.0.1    HTTP3 88 Protected Payload (KP0), DCID=6b71db4b43c67e58f7d7293b72333b4c1c80c916, PKN: 1, STREAM(3), SETTINGS
    5   0.041878    127.0.0.1 ? 127.0.0.1    QUIC 1242 Handshake, DCID=f9c4f3f5, SCID=6b71db4b43c67e58f7d7293b72333b4c1c80c916, PKN: 0, ACK, CRYPTO
    6   0.042037    127.0.0.1 ? 127.0.0.1    QUIC 1448 Protected Payload (KP0), DCID=f9c4f3f5, PKN: 1, PING, PADDING
    7   0.042594    127.0.0.1 ? 127.0.0.1    QUIC 315 Protected Payload (KP0)
    8   0.043030    127.0.0.1 ? 127.0.0.1    QUIC 1486 Protected Payload (KP0), DCID=f9c4f3f5, PKN: 2, PING, PADDING
    9   0.043102    127.0.0.1 ? 127.0.0.1    HTTP3 139 Protected Payload (KP0), DCID=f9c4f3f5, PKN: 3, ACK, NCI, STREAM(0), HEADERS: GET /
   10   0.043450    127.0.0.1 ? 127.0.0.1    QUIC 86 Protected Payload (KP0)
   11   0.043960    127.0.0.1 ? 127.0.0.1    QUIC 176 Protected Payload (KP0)
   12   0.044069    127.0.0.1 ? 127.0.0.1    QUIC 84 Protected Payload (KP0), DCID=f9c4f3f5, PKN: 4, CC, PADDING

Compare this with a similar (though performed between two containers instead of localhost) packet capture obtained from nginx/1.27.0 (built with OpenSSL 3.0.11 19 Sep 2023 (running with OpenSSL 3.0.13 30 Jan 2024), which also contains DATA

    1   0.000000 192.168.32.5 ? 192.168.32.3 QUIC 1242 Initial, DCID=68a52fd3e2efafce2df22f4bde4c4992725e831e, SCID=b174858cd11fa0066e57e2b1bb2f342ef083f1a0, PKN: 0, CRYPTO, PADDING
    2   0.003507 192.168.32.3 ? 192.168.32.5 QUIC 1242 Handshake, DCID=b174858cd11fa0066e57e2b1bb2f342ef083f1a0, SCID=000000000000100227898379a204dc700cc97d33, PKN: 0, CRYPTO, CRYPTO
    3   0.003546 192.168.32.3 ? 192.168.32.5 QUIC 673 Handshake, DCID=b174858cd11fa0066e57e2b1bb2f342ef083f1a0, SCID=000000000000100227898379a204dc700cc97d33, PKN: 1, CRYPTO, CRYPTO, CRYPTO
    4   0.006121 192.168.32.5 ? 192.168.32.3 QUIC 1242 Handshake, DCID=000000000000100227898379a204dc700cc97d33, SCID=b174858cd11fa0066e57e2b1bb2f342ef083f1a0, PKN: 0, ACK, CRYPTO
    5   0.006186 192.168.32.5 ? 192.168.32.3 QUIC 1448 Protected Payload (KP0), DCID=000000000000100227898379a204dc700cc97d33, PKN: 1, PING, PADDING
    6   0.006321 192.168.32.5 ? 192.168.32.3 HTTP3 113 Protected Payload (KP0), DCID=000000000000100227898379a204dc700cc97d33, PKN: 2, STREAM(0), HEADERS: GET /
    7   0.006577 192.168.32.3 ? 192.168.32.5 HTTP3 655 Protected Payload (KP0), DCID=b174858cd11fa0066e57e2b1bb2f342ef083f1a0, PKN: 0, ACK, CRYPTO, CRYPTO, DONE, NCI, STREAM(3), STREAM(3), SETTINGS, STREAM(7)
    8   0.006925 192.168.32.3 ? 192.168.32.5 HTTP3 827 Protected Payload (KP0), DCID=b174858cd11fa0066e57e2b1bb2f342ef083f1a0, PKN: 1, ACK, STREAM(0), HEADERS: 200 OK, DATA, STREAM(0)
    9   0.007204 192.168.32.5 ? 192.168.32.3 QUIC 1486 Protected Payload (KP0), DCID=000000000000100227898379a204dc700cc97d33, PKN: 3, PING, PADDING
   10   0.007234 192.168.32.5 ? 192.168.32.3 QUIC 85 Protected Payload (KP0), DCID=000000000000100227898379a204dc700cc97d33, PKN: 4, ACK
   11   0.007280 192.168.32.5 ? 192.168.32.3 QUIC 84 Protected Payload (KP0), DCID=000000000000100227898379a204dc700cc97d33, PKN: 5, CC
   12   0.007406 192.168.32.3 ? 192.168.32.5 QUIC 88 Protected Payload (KP0), DCID=b174858cd11fa0066e57e2b1bb2f342ef083f1a0, PKN: 2, ACK, MS

The pcapng files are attached.

caddy.pcapng.gz nginx.pcapng.gz

francislavoie commented 3 months ago

/cc @marten-seemann do you know how tls.Config.KeyLogWriter interacts with quic-go? Should we expect any kind of problem?

marten-seemann commented 3 months ago

Sorry for the late reply. quic-go passes the tls.Config.KeyLogWriter through to crypto/tls, so it should work exactly as expected.

marten-seemann commented 3 months ago

There appears to be an issue with Wireshark though that prevents it to decrypt certain quic-go QUIC transfers, presumable because it doesn't like how quic-go is switching QUIC connection IDs. I just debugged this and filed a Wireshark issue: https://gitlab.com/wireshark/wireshark/-/issues/19977.