Firefox not always using http/3?

Forza · September 26, 2021, 2:31pm

Hi.

This is a little unrelated to Caddy perhaps, but I notice that it does not often connect to my site over HTTP/3, but uses HTTP/2 quite a lot. Using Opera browser (Chromium based) it always works. Strangely, sites like https://http3.is and https://quic.nginx.org/ show that FireFox uses HTTP/3.

Is this a known problem, or should I try to debug it and report it to Bugzilla?

ps. I’ve read about qlog. Is this something that I enable in FireFox, and how would I go about logging my session using it?

francislavoie · September 26, 2021, 7:11pm

I wouldn’t really be able to say, I don’t think Matt would know either. The HTTP/3 implementation isn’t maintained by us. We’re using this library:

Forza · September 26, 2021, 7:45pm

I’d say it’s s Firefox problem. Looking at their bugzilla there seems to be quite a few issues still.

One thing, which might be intended, is that the alt-svc cache is dropped so when you’re dev tools with no cache, only http2 can be used.

Forza · September 27, 2021, 5:31am

Hi again.

I take it all back

It seems that Caddy simply stops responding on http/3 after a while. Not even curl --http3 can connect. If I stop (ctrl-c) and start Cadd (caddy run) it works as expected again. I did not see any errors in the logs either. Though they are quite long, so I will dig some more.

matt · September 27, 2021, 6:44am

Ah, that is definitely a mystery. Please contribute any additional info here:

github.com/caddyserver/caddy

http/3 seems to stop working after any kind of reload

opened 05:31PM - 12 Sep 21 UTC

Zierhut-IT

bug

http/3 seems to stop working after any kind of reload. - http/3 works as expe…cted before reloading - I went as far as v2.0.0 back (thus the two Caddyfiles, see further down) and encountered this issue every time - Caddy seems to still listen on `udp/443` when it's happening: ```bash $ ss --listening --udp --processes # -lup UNCONN 0 0 *:https *:* users:(("caddy",pid=872477,fd=8)) ``` - Verbose `curl -vvv` logs: ```bash $ curl -vvv --http3 https://localhost * Trying ::1:443... * Connect socket 5 over QUIC to ::1:443 * Sent QUIC client Initial, ALPN: h3-29,h3-28,h3-27 * Trying 127.0.0.1:443... * Connect socket 6 over QUIC to 127.0.0.1:443 * Sent QUIC client Initial, ALPN: h3-29,h3-28,h3-27 * After 150000ms connect time, move on! * connect to ::1 port 443 failed: Connection timed out * After 150000ms connect time, move on! * connect to 127.0.0.1 port 443 failed: Connection timed out * Failed to connect to localhost port 443: Connection timed out * Closing connection 0 curl: (28) Failed to connect to localhost port 443: Connection timed out ``` - <details><summary>Verbose caddy logs from console with annotations (// 📌):</summary> ```json // 📌 start caddy {"level":"info","ts":1631424276.233273,"msg":"using adjacent Caddyfile"} {"level":"warn","ts":1631424276.233972,"msg":"input is not formatted with 'caddy fmt'","adapter":"caddyfile","file":"Caddyfile","line":2} {"level":"info","ts":1631424276.2348974,"logger":"admin","msg":"admin endpoint started","address":"tcp/localhost:2019","enforce_origin":false,"origins":["[::1]:2019","127.0.0.1:2019","localhost:2019"]} {"level":"info","ts":1631424276.2352147,"logger":"tls.cache.maintenance","msg":"started background certificate maintenance","cache":"0xc00045f030"} {"level":"info","ts":1631424276.235942,"logger":"http","msg":"server is listening only on the HTTPS port but has no TLS connection policies; adding one to enable TLS","server_name":"srv0","https_port":443} {"level":"info","ts":1631424276.2359629,"logger":"http","msg":"enabling automatic HTTP->HTTPS redirects","server_name":"srv0"} {"level":"info","ts":1631424276.2525249,"logger":"pki.ca.local","msg":"root certificate is already trusted by system","path":"storage:pki/authorities/local/root.crt"} {"level":"info","ts":1631424276.2526367,"logger":"http","msg":"enabling experimental HTTP/3 listener","addr":":443"} {"level":"info","ts":1631424276.2526562,"logger":"tls","msg":"cleaning storage unit","description":"FileStorage:/root/.local/share/caddy"} {"level":"debug","ts":1631424276.252672,"logger":"http","msg":"starting server loop","address":"[::]:443","http3":true,"tls":true} {"level":"debug","ts":1631424276.25269,"logger":"http","msg":"starting server loop","address":"[::]:80","http3":false,"tls":false} {"level":"info","ts":1631424276.252697,"logger":"http","msg":"enabling automatic TLS certificate management","domains":["localhost"]} {"level":"warn","ts":1631424276.2530873,"logger":"tls","msg":"stapling OCSP","error":"no OCSP stapling for [localhost]: no OCSP server specified in certificate"} {"level":"debug","ts":1631424276.2531059,"logger":"tls.cache","msg":"added certificate to cache","subjects":["localhost"],"expiration":1631461064,"managed":true,"issuer_key":"local","hash":"a186539e15337b0547621156c842d1502a09780d05eb5d36684496f530c1fb84"} {"level":"info","ts":1631424276.2532187,"msg":"autosaved config (load with --resume flag)","file":"/root/.local/share/caddy/autosave.json"} {"level":"info","ts":1631424276.2532284,"msg":"serving initial configuration"} {"level":"info","ts":1631424276.2536077,"logger":"tls","msg":"finished cleaning storage units"} // 📌 test http/3 connection via curl {"level":"debug","ts":1631424286.478527,"logger":"tls.handshake","msg":"choosing certificate","identifier":"localhost","num_choices":1} {"level":"debug","ts":1631424286.4785457,"logger":"tls.handshake","msg":"default certificate selection results","identifier":"localhost","subjects":["localhost"],"managed":true,"issuer_key":"local","hash":"a186539e15337b0547621156c842d1502a09780d05eb5d36684496f530c1fb84"} {"level":"debug","ts":1631424286.4785507,"logger":"tls.handshake","msg":"matched certificate in cache","subjects":["localhost"],"managed":true,"expiration":1631461064,"hash":"a186539e15337b0547621156c842d1502a09780d05eb5d36684496f530c1fb84"} // 📌 forcefully reload caddy config via curl {"level":"info","ts":1631424303.4187894,"logger":"admin.api","msg":"received request","method":"GET","host":"127.0.0.1:2019","uri":"/config/","remote_addr":"127.0.0.1:48794","headers":{"Accept":["*/*"],"User-Agent":["curl/7.78.0"]}} {"level":"info","ts":1631424303.4197412,"logger":"admin.api","msg":"received request","method":"POST","host":"127.0.0.1:2019","uri":"/load","remote_addr":"127.0.0.1:48796","headers":{"Accept":["*/*"],"Cache-Control":["must-revalidate"],"Content-Length":["399"],"Content-Type":["application/json"],"User-Agent":["curl/7.78.0"]}} {"level":"info","ts":1631424303.4200108,"logger":"admin","msg":"admin endpoint started","address":"tcp/localhost:2019","enforce_origin":false,"origins":["localhost:2019","[::1]:2019","127.0.0.1:2019"]} {"level":"info","ts":1631424303.4201722,"logger":"tls.cache.maintenance","msg":"started background certificate maintenance","cache":"0xc000276700"} {"level":"info","ts":1631424303.4203856,"logger":"http","msg":"server is listening only on the HTTPS port but has no TLS connection policies; adding one to enable TLS","server_name":"srv0","https_port":443} {"level":"info","ts":1631424303.4204006,"logger":"http","msg":"enabling automatic HTTP->HTTPS redirects","server_name":"srv0"} {"level":"debug","ts":1631424303.4204953,"logger":"http","msg":"starting server loop","address":"[::]:80","http3":false,"tls":false} {"level":"info","ts":1631424303.4205036,"logger":"http","msg":"enabling experimental HTTP/3 listener","addr":":443"} 2021/09/12 07:25:03 [DEBUG] udp/:443: Usage counter should not go above 2 or maybe 3, is now: 2 {"level":"debug","ts":1631424303.420539,"logger":"http","msg":"starting server loop","address":"[::]:443","http3":true,"tls":true} {"level":"info","ts":1631424303.420544,"logger":"http","msg":"enabling automatic TLS certificate management","domains":["localhost"]} {"level":"warn","ts":1631424303.4207737,"logger":"tls","msg":"stapling OCSP","error":"no OCSP stapling for [localhost]: no OCSP server specified in certificate"} {"level":"debug","ts":1631424303.4207897,"logger":"tls.cache","msg":"added certificate to cache","subjects":["localhost"],"expiration":1631461064,"managed":true,"issuer_key":"local","hash":"a186539e15337b0547621156c842d1502a09780d05eb5d36684496f530c1fb84"} {"level":"info","ts":1631424303.4208012,"logger":"pki.ca.local","msg":"root certificate is already trusted by system","path":"storage:pki/authorities/local/root.crt"} 2021/09/12 07:25:03 [DEBUG] Fake-closing underlying packet conn {"level":"info","ts":1631424303.4235258,"logger":"tls.cache.maintenance","msg":"stopped background certificate maintenance","cache":"0xc00045f030"} {"level":"info","ts":1631424303.423664,"msg":"autosaved config (load with --resume flag)","file":"/root/.local/share/caddy/autosave.json"} {"level":"info","ts":1631424303.4236767,"logger":"admin.api","msg":"load complete"} {"level":"info","ts":1631424303.427598,"logger":"admin","msg":"stopped previous server","address":"tcp/localhost:2019"} // 📌 test http/3 connection via curl (no result) ``` </details> --- <details open><summary>Caddyfile (v2.3.0+):</summary> ```Caddyfile { debug servers :443 { protocol { experimental_http3 } } } localhost { tls internal respond localhost } ``` </details> <details><summary>Caddyfile (v2.3.0+) as JSON:</summary> ```json { "logging": { "logs": { "default": { "level": "DEBUG" } } }, "apps": { "http": { "servers": { "srv0": { "listen": [ ":443" ], "routes": [ { "match": [ { "host": [ "localhost" ] } ], "handle": [ { "handler": "subroute", "routes": [ { "handle": [ { "body": "localhost", "handler": "static_response" } ] } ] } ], "terminal": true } ], "experimental_http3": true } } }, "tls": { "automation": { "policies": [ { "subjects": [ "localhost" ], "issuers": [ { "module": "internal" } ] } ] } } } } ``` </details> <details><summary>Caddyfile (pre v2.3.0):</summary> ```Caddyfile { debug experimental_http3 } localhost { tls internal respond localhost } ``` </details> --- Below are 3 different way to reproduce this issue: 1. <details open><summary>Case (collapse)</summary> - Copy example Caddyfile - ```bash $ caddy run ``` - Test http/3 connection via ```bash $ curl --http3 https://localhost # localhost ``` - Force reload same (json) config via API ```bash $ curl --silent 127.1:2019/config/ | curl -X POST 127.1:2019/load -H "Content-Type: application/json" -d @- -H "Cache-Control: must-revalidate" ``` - Test http/3 connection again via ```bash $ curl --http3 https://localhost # curl: (28) Failed to connect to localhost port 443: Connection timed out ``` </details> 1. <details><summary>Case (expand)</summary> - Copy example Caddyfile - ```bash $ caddy run ``` - Test http/3 connection via ```bash $ curl --http3 https://localhost # localhost ``` - Force reload same config via CLI ```bash $ caddy reload --force ``` - Test http/3 connection again via ```bash $ curl --http3 https://localhost # curl: (28) Failed to connect to localhost port 443: Connection timed out ``` </details> 1. <details><summary>Case (expand)</summary> - Copy example Caddyfile - ```bash $ caddy run --watch ``` - Test http/3 connection via ```bash $ curl --http3 https://localhost # localhost ``` - Edit config (e.g. `respond`) and save - Test http/3 connection again via ```bash $ curl --http3 https://localhost # curl: (28) Failed to connect to localhost port 443: Connection timed out ``` </details> Hope this is has not yet been reported. Otherwise feel free to close this issue. \ And despite this bug, Caddy is awesome! :) ~ @IndeedNotJames

We could use some help pinpointing that.

Forza · September 27, 2021, 7:49am

Thanks. I did. Hopefully we can debug och pinpoint the cause of the problems.

system · October 26, 2021, 2:31pm

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