RestServer: investigate and fix http3 problems #382
Description
We've identified some problems with HTTP/3, where requests would sometimes stall instead of returning the expected result. As a quick workaround #381 removes the upgrade Headers, so clients will stick with HTTP2 while still being able to investigate HTTP3 by forcing the upgrade, but we need http3 to be re-enabled. The failing requests could be reproduced in curl and firefox (probably also chrome, but there it's more complicated - albeit documented in the README - to force http3 with certificate). In the following I've added some output from opendigitizer-service using http3 and -DOPENCMW_DEBUG_HTTP=ON cmake option and curl as a client:
I00000000 0x5a0c9a9977a363a42186e7d8a1e13141ec13 con next skip pkn=49
I2178528939 0x5a0c9a9977a363a42186e7d8a1e13141ec13 con recv packet len=1200
I2178528939 0x5a0c9a9977a363a42186e7d8a1e13141ec13 pkt rx pkn=0 dcid=0x095316168109d650cca31392cbb7658abadcfff2 scid=0xe94fa4557c9b11ca853e7d999274844bc2dc8a4e version=0x00000001 type=Initial len=1148
I2178528939 0x5a0c9a9977a363a42186e7d8a1e13141ec13 frm rx 0 Initial CRYPTO(0x06) offset=0 len=512
I2178528939 0x5a0c9a9977a363a42186e7d8a1e13141ec13 con the negotiated version is 0x00000001
I2178528939 0x5a0c9a9977a363a42186e7d8a1e13141ec13 cry remote transport_parameters initial_source_connection_id=0xe94fa4557c9b11ca853e7d999274844bc2dc8a4e
I2178528939 0x5a0c9a9977a363a42186e7d8a1e13141ec13 cry remote transport_parameters initial_max_stream_data_bidi_local=131072
I2178528939 0x5a0c9a9977a363a42186e7d8a1e13141ec13 cry remote transport_parameters initial_max_stream_data_bidi_remote=131072
I2178528939 0x5a0c9a9977a363a42186e7d8a1e13141ec13 cry remote transport_parameters initial_max_stream_data_uni=131072
I2178528939 0x5a0c9a9977a363a42186e7d8a1e13141ec13 cry remote transport_parameters initial_max_data=1310720
I2178528939 0x5a0c9a9977a363a42186e7d8a1e13141ec13 cry remote transport_parameters initial_max_streams_bidi=262144
I2178528939 0x5a0c9a9977a363a42186e7d8a1e13141ec13 cry remote transport_parameters initial_max_streams_uni=262144
I2178528939 0x5a0c9a9977a363a42186e7d8a1e13141ec13 cry remote transport_parameters max_idle_timeout=120000
I2178528939 0x5a0c9a9977a363a42186e7d8a1e13141ec13 cry remote transport_parameters max_udp_payload_size=65527
I2178528939 0x5a0c9a9977a363a42186e7d8a1e13141ec13 cry remote transport_parameters ack_delay_exponent=3
I2178528939 0x5a0c9a9977a363a42186e7d8a1e13141ec13 cry remote transport_parameters max_ack_delay=25
I2178528939 0x5a0c9a9977a363a42186e7d8a1e13141ec13 cry remote transport_parameters active_connection_id_limit=2
I2178528939 0x5a0c9a9977a363a42186e7d8a1e13141ec13 cry remote transport_parameters disable_active_migration=0
I2178528939 0x5a0c9a9977a363a42186e7d8a1e13141ec13 cry remote transport_parameters max_datagram_frame_size=0
I2178528939 0x5a0c9a9977a363a42186e7d8a1e13141ec13 cry remote transport_parameters grease_quic_bit=0
I2178528939 0x5a0c9a9977a363a42186e7d8a1e13141ec13 cry remote transport_parameters version_information.chosen_version=0x00000001
I2178528939 0x5a0c9a9977a363a42186e7d8a1e13141ec13 cry remote transport_parameters version_information.available_versions[0]=0x00000001
I2178528939 0x5a0c9a9977a363a42186e7d8a1e13141ec13 frm rx 0 Initial PADDING(0x00) len=615
I2178528939 0x5a0c9a9977a363a42186e7d8a1e13141ec13 pkt read packet 1200 left 0
I2178528940 0x5a0c9a9977a363a42186e7d8a1e13141ec13 pkt tx pkn=0 dcid=0xe94fa4557c9b11ca853e7d999274844bc2dc8a4e scid=0x5a0c9a9977a363a42186e7d8a1e13141ec13 version=0x00000001 type=Initial len=0
I2178528940 0x5a0c9a9977a363a42186e7d8a1e13141ec13 frm tx 0 Initial ACK(0x02) largest_ack=0 ack_delay=0(0) ack_range_count=0
I2178528940 0x5a0c9a9977a363a42186e7d8a1e13141ec13 frm tx 0 Initial ACK(0x02) range=[0..0] len=0
I2178528940 0x5a0c9a9977a363a42186e7d8a1e13141ec13 frm tx 0 Initial CRYPTO(0x06) offset=0 len=90
I2178528940 0x5a0c9a9977a363a42186e7d8a1e13141ec13 ldc loss_detection_timer=2178529939919116 timeout=999
I2178528940 0x5a0c9a9977a363a42186e7d8a1e13141ec13 pkt tx pkn=0 dcid=0xe94fa4557c9b11ca853e7d999274844bc2dc8a4e scid=0x5a0c9a9977a363a42186e7d8a1e13141ec13 version=0x00000001 type=Handshake len=0
I2178528940 0x5a0c9a9977a363a42186e7d8a1e13141ec13 frm tx 0 Handshake CRYPTO(0x06) offset=0 len=964
I2178528940 0x5a0c9a9977a363a42186e7d8a1e13141ec13 ldc loss_detection_timer=2178529939919116 timeout=999
I2178528940 0x5a0c9a9977a363a42186e7d8a1e13141ec13 pkt tx pkn=1 dcid=0xe94fa4557c9b11ca853e7d999274844bc2dc8a4e scid=0x5a0c9a9977a363a42186e7d8a1e13141ec13 version=0x00000001 type=Handshake len=0
I2178528940 0x5a0c9a9977a363a42186e7d8a1e13141ec13 frm tx 1 Handshake CRYPTO(0x06) offset=964 len=331
I2178528940 0x5a0c9a9977a363a42186e7d8a1e13141ec13 ldc loss_detection_timer=2178529939919116 timeout=999
I2178528940 0x5a0c9a9977a363a42186e7d8a1e13141ec13 pkt tx pkn=0 dcid=0xe94fa4557c9b11ca853e7d999274844bc2dc8a4e type=1RTT k=0
I2178528940 0x5a0c9a9977a363a42186e7d8a1e13141ec13 frm tx 0 1RTT NEW_CONNECTION_ID(0x18) seq=1 cid=0xc3df727f7383ec8bf48269ebdf5906885c7a retire_prior_to=0 stateless_reset_token=0x95cf30392ead1521c6c00c114bbbf171
I2178528940 0x5a0c9a9977a363a42186e7d8a1e13141ec13 frm tx 0 1RTT STREAM(0x0a) id=0x3 fin=0 offset=0 len=18 uni=1
I2178528940 0x5a0c9a9977a363a42186e7d8a1e13141ec13 frm tx 0 1RTT STREAM(0x0a) id=0xb fin=0 offset=0 len=1 uni=1
I2178528940 0x5a0c9a9977a363a42186e7d8a1e13141ec13 frm tx 0 1RTT STREAM(0x0a) id=0x7 fin=0 offset=0 len=1 uni=1
I2178528940 0x5a0c9a9977a363a42186e7d8a1e13141ec13 ldc loss_detection_timer=2178529939919116 timeout=999
I2178529943 0x5a0c9a9977a363a42186e7d8a1e13141ec13 con recv packet len=1200
I2178529943 0x5a0c9a9977a363a42186e7d8a1e13141ec13 pkt rx pkn=1 dcid=0x095316168109d650cca31392cbb7658abadcfff2 scid=0xe94fa4557c9b11ca853e7d999274844bc2dc8a4e version=0x00000001 type=Initial len=1148
I2178529943 0x5a0c9a9977a363a42186e7d8a1e13141ec13 frm rx 1 Initial CRYPTO(0x06) offset=0 len=512
I2178529943 0x5a0c9a9977a363a42186e7d8a1e13141ec13 frm rx 1 Initial PADDING(0x00) len=615
I2178529943 0x5a0c9a9977a363a42186e7d8a1e13141ec13 pkt read packet 1200 left 0
I2178529943 0x5a0c9a9977a363a42186e7d8a1e13141ec13 con processing buffered handshake packet
I2178529943 0x5a0c9a9977a363a42186e7d8a1e13141ec13 pkt tx pkn=1 dcid=0xe94fa4557c9b11ca853e7d999274844bc2dc8a4e scid=0x5a0c9a9977a363a42186e7d8a1e13141ec13 version=0x00000001 type=Initial len=0
I2178529943 0x5a0c9a9977a363a42186e7d8a1e13141ec13 frm tx 1 Initial ACK(0x02) largest_ack=1 ack_delay=0(0) ack_range_count=0
I2178529943 0x5a0c9a9977a363a42186e7d8a1e13141ec13 frm tx 1 Initial ACK(0x02) range=[1..0] len=1
I2178529943 0x5a0c9a9977a363a42186e7d8a1e13141ec13 frm tx 1 Initial CRYPTO(0x06) offset=0 len=90
I2178529943 0x5a0c9a9977a363a42186e7d8a1e13141ec13 ldc loss_detection_timer=2178529939919116 timeout=0
I2178529943 0x5a0c9a9977a363a42186e7d8a1e13141ec13 pkt tx pkn=2 dcid=0xe94fa4557c9b11ca853e7d999274844bc2dc8a4e scid=0x5a0c9a9977a363a42186e7d8a1e13141ec13 version=0x00000001 type=Handshake len=0
I2178529943 0x5a0c9a9977a363a42186e7d8a1e13141ec13 frm tx 2 Handshake CRYPTO(0x06) offset=0 len=964
I2178529943 0x5a0c9a9977a363a42186e7d8a1e13141ec13 ldc loss_detection_timer=2178529964919116 timeout=21
I2178531945 0x5a0c9a9977a363a42186e7d8a1e13141ec13 con recv packet len=1200
I2178531945 0x5a0c9a9977a363a42186e7d8a1e13141ec13 pkt rx pkn=2 dcid=0x095316168109d650cca31392cbb7658abadcfff2 scid=0xe94fa4557c9b11ca853e7d999274844bc2dc8a4e version=0x00000001 type=Initial len=1148
I2178531945 0x5a0c9a9977a363a42186e7d8a1e13141ec13 frm rx 2 Initial CRYPTO(0x06) offset=0 len=512
I2178531945 0x5a0c9a9977a363a42186e7d8a1e13141ec13 frm rx 2 Initial PADDING(0x00) len=615
I2178531945 0x5a0c9a9977a363a42186e7d8a1e13141ec13 pkt read packet 1200 left 0
I2178531945 0x5a0c9a9977a363a42186e7d8a1e13141ec13 con processing buffered handshake packet
I2178531945 0x5a0c9a9977a363a42186e7d8a1e13141ec13 pkt tx pkn=2 dcid=0xe94fa4557c9b11ca853e7d999274844bc2dc8a4e scid=0x5a0c9a9977a363a42186e7d8a1e13141ec13 version=0x00000001 type=Initial len=0
I2178531945 0x5a0c9a9977a363a42186e7d8a1e13141ec13 frm tx 2 Initial ACK(0x02) largest_ack=2 ack_delay=0(0) ack_range_count=0
I2178531945 0x5a0c9a9977a363a42186e7d8a1e13141ec13 frm tx 2 Initial ACK(0x02) range=[2..0] len=2
I2178535946 0x5a0c9a9977a363a42186e7d8a1e13141ec13 con recv packet len=1200
I2178535946 0x5a0c9a9977a363a42186e7d8a1e13141ec13 pkt rx pkn=3 dcid=0x095316168109d650cca31392cbb7658abadcfff2 scid=0xe94fa4557c9b11ca853e7d999274844bc2dc8a4e version=0x00000001 type=Initial len=1148
I2178535946 0x5a0c9a9977a363a42186e7d8a1e13141ec13 frm rx 3 Initial CRYPTO(0x06) offset=0 len=512
I2178535946 0x5a0c9a9977a363a42186e7d8a1e13141ec13 frm rx 3 Initial PADDING(0x00) len=615
I2178535946 0x5a0c9a9977a363a42186e7d8a1e13141ec13 pkt read packet 1200 left 0
I2178535946 0x5a0c9a9977a363a42186e7d8a1e13141ec13 con processing buffered handshake packet
I2178535946 0x5a0c9a9977a363a42186e7d8a1e13141ec13 pkt tx pkn=3 dcid=0xe94fa4557c9b11ca853e7d999274844bc2dc8a4e scid=0x5a0c9a9977a363a42186e7d8a1e13141ec13 version=0x00000001 type=Initial len=0
I2178535946 0x5a0c9a9977a363a42186e7d8a1e13141ec13 frm tx 3 Initial ACK(0x02) largest_ack=3 ack_delay=0(0) ack_range_count=0
I2178535946 0x5a0c9a9977a363a42186e7d8a1e13141ec13 frm tx 3 Initial ACK(0x02) range=[3..0] len=3
I2178535946 0x5a0c9a9977a363a42186e7d8a1e13141ec13 frm tx 3 Initial PING(0x01)
I2178535946 0x5a0c9a9977a363a42186e7d8a1e13141ec13 ldc loss_detection_timer=2178529964919116 timeout=0
I2178535946 0x5a0c9a9977a363a42186e7d8a1e13141ec13 frm tx 1 1RTT PADDING(0x00) len=1089
I2178535946 0x5a0c9a9977a363a42186e7d8a1e13141ec13 ldc loss_detection_timer=2178529964919116 timeout=0
$ curl -k -vvvv "https://syspc008.gsi.de:8443/dashboards" --http3-only
16:57:22.411021 [0-x] == Info: [MULTI] [INIT] added, transfers=1
16:57:22.411163 [0-x] == Info: [MULTI] [INIT] multi_perform(running=1)
16:57:22.411275 [0-x] == Info: [MULTI] [INIT] -> [SETUP]
16:57:22.411370 [0-x] == Info: [MULTI] [SETUP] -> [CONNECT]
16:57:22.411463 [0-x] == Info: [READ] client_reset, clear readers
16:57:22.411592 [0-0] == Info: [MULTI] [CONNECT] [CPOOL] added connection 0. The cache now contains 1 members
16:57:22.411834 [0-0] == Info: [MULTI] [CONNECT] -> [RESOLVING]
16:57:22.411942 [0-0] == Info: [MULTI] [RESOLVING] multi_wait pollset[fd=4 IN], timeouts=1
16:57:22.412562 [0-0] == Info: [MULTI] [RESOLVING] multi_perform(running=1)
16:57:22.412690 [0-0] == Info: [MULTI] [RESOLVING] Curl_multi_will_close fd=4
16:57:22.412817 [0-0] == Info: Host syspc008.gsi.de:8443 was resolved.
16:57:22.412929 [0-0] == Info: IPv6: (none)
16:57:22.412999 [0-0] == Info: IPv4: 140.181.95.179
16:57:22.413085 [0-0] == Info: [HTTPS-CONNECT] adding wanted h3
16:57:22.413194 [0-0] == Info: [HTTPS-CONNECT] added
16:57:22.413284 [0-0] == Info: [MULTI] [RESOLVING] -> [CONNECTING]
16:57:22.413405 [0-0] == Info: [HTTPS-CONNECT] connect, init
16:57:22.413495 [0-0] == Info: [HAPPY-EYEBALLS] created ipv4 (timeout 299998ms)
16:57:22.413620 [0-0] == Info: [HAPPY-EYEBALLS] ipv4 starting (timeout=299998ms)
16:57:22.413752 [0-0] == Info: Trying 140.181.95.179:8443...
16:57:22.413849 [0-0] == Info: [UDP] cf_socket_open() -> 0, fd=4
16:57:22.413966 [0-0] == Info: [UDP] QUIC socket 4 connected: [140.181.95.179:34406] -> [140.181.95.179:8443]
16:57:22.414203 [0-0] == Info: [UDP] cf_udp_connect(), opened socket=4 (140.181.95.179:34406)
16:57:22.415662 [0-0] == Info: [SSLS] find peer slot for syspc008.gsi.de:8443:QUIC:NO-VRFY-PEER:NO-VRFY-HOST:IMPL-quictls/3.3.0:G among 25 slots
16:57:22.415911 [0-0] == Info: [SSLS] peer not found for syspc008.gsi.de:8443:QUIC:NO-VRFY-PEER:NO-VRFY-HOST:IMPL-quictls/3.3.0:G
16:57:22.416123 [0-0] == Info: [SSLS] no cached session for syspc008.gsi.de:8443:QUIC:NO-VRFY-PEER:NO-VRFY-HOST:IMPL-quictls/3.3.0:G
16:57:22.416617 [0-0] == Info: [HTTP/3] vquic_send(len=1200, gso=1200) -> 0, sent=1200
16:57:22.416755 [0-0] == Info: [HAPPY-EYEBALLS] ipv4 connect -> 0, connected=0
16:57:22.416874 [0-0] == Info: [HTTPS-CONNECT] connect -> 0, done=0
16:57:22.416979 [0-0] == Info: [HTTPS-CONNECT] Curl_conn_connect(block=0) -> 0, done=0
16:57:22.417131 [0-0] == Info: [UDP] adjust_pollset, !active, POLLIN fd=4
16:57:22.417248 [0-0] == Info: [HAPPY-EYEBALLS] adjust_pollset -> 1 socks
16:57:22.417361 [0-0] == Info: [HTTPS-CONNECT] adjust_pollset -> 1 socks
16:57:22.417474 [0-0] == Info: [MULTI] [CONNECTING] multi_wait pollset[fd=4 IN], timeouts=2
16:57:22.417603 [0-0] == Info: [MULTI] [CONNECTING] multi_perform(running=1)
16:57:22.417710 [0-0] == Info: [HTTP/3] ossl_populate_x509_store, path=none, blob=0
16:57:22.417842 [0-0] == Info: [HTTP/3] ingress, recvmmsg -> EAGAIN
16:57:22.417931 [0-0] == Info: [HAPPY-EYEBALLS] ipv4 connect -> 0, connected=0
16:57:22.418062 [0-0] == Info: [HTTPS-CONNECT] connect -> 0, done=0
16:57:22.418171 [0-0] == Info: [HTTPS-CONNECT] Curl_conn_connect(block=0) -> 0, done=0
16:57:22.418302 [0-0] == Info: [UDP] adjust_pollset, !active, POLLIN fd=4
16:57:22.418424 [0-0] == Info: [HAPPY-EYEBALLS] adjust_pollset -> 1 socks
16:57:22.418531 [0-0] == Info: [HTTPS-CONNECT] adjust_pollset -> 1 socks
16:57:22.418649 [0-0] == Info: [MULTI] [CONNECTING] multi_wait pollset[fd=4 IN], timeouts=1
16:57:23.418350 [0-0] == Info: [MULTI] [CONNECTING] multi_perform(running=1)
16:57:23.418502 [0-0] == Info: [HTTP/3] ingress, recvmmsg -> EAGAIN
16:57:23.418596 [0-0] == Info: [HTTP/3] ingress, recvmmsg -> EAGAIN
16:57:23.418727 [0-0] == Info: [HTTP/3] vquic_send(len=1200, gso=1200) -> 0, sent=1200
16:57:23.418906 [0-0] == Info: [HAPPY-EYEBALLS] ipv4 connect -> 0, connected=0
16:57:23.419102 [0-0] == Info: [HTTPS-CONNECT] connect -> 0, done=0
16:57:23.419297 [0-0] == Info: [HTTPS-CONNECT] Curl_conn_connect(block=0) -> 0, done=0
16:57:23.419533 [0-0] == Info: [UDP] adjust_pollset, !active, POLLIN fd=4
16:57:23.419723 [0-0] == Info: [HAPPY-EYEBALLS] adjust_pollset -> 1 socks
16:57:23.419934 [0-0] == Info: [HTTPS-CONNECT] adjust_pollset -> 1 socks
16:57:23.420143 [0-0] == Info: [MULTI] [CONNECTING] multi_wait pollset[fd=4 IN], timeouts=1
16:57:24.421344 [0-0] == Info: [MULTI] [CONNECTING] multi_perform(running=1)
16:57:24.421507 [0-0] == Info: [HTTP/3] ingress, recvmmsg -> EAGAIN
16:57:24.421615 [0-0] == Info: [HAPPY-EYEBALLS] ipv4 connect -> 0, connected=0
16:57:24.421721 [0-0] == Info: [HTTPS-CONNECT] connect -> 0, done=0
16:57:24.421907 [0-0] == Info: [HTTPS-CONNECT] Curl_conn_connect(block=0) -> 0, done=0
16:57:24.422120 [0-0] == Info: [UDP] adjust_pollset, !active, POLLIN fd=4
16:57:24.422220 [0-0] == Info: [HAPPY-EYEBALLS] adjust_pollset -> 1 socks
16:57:24.422434 [0-0] == Info: [HTTPS-CONNECT] adjust_pollset -> 1 socks
16:57:24.422614 [0-0] == Info: [MULTI] [CONNECTING] multi_wait pollset[fd=4 IN], timeouts=1
16:57:25.419335 [0-0] == Info: [MULTI] [CONNECTING] multi_perform(running=1)
16:57:25.419519 [0-0] == Info: [HTTP/3] ingress, recvmmsg -> EAGAIN
16:57:25.419636 [0-0] == Info: [HTTP/3] ingress, recvmmsg -> EAGAIN
16:57:25.419801 [0-0] == Info: [HTTP/3] vquic_send(len=1200, gso=1200) -> 0, sent=1200
16:57:25.419988 [0-0] == Info: [HAPPY-EYEBALLS] ipv4 connect -> 0, connected=0
16:57:25.420147 [0-0] == Info: [HTTPS-CONNECT] connect -> 0, done=0
16:57:25.420269 [0-0] == Info: [HTTPS-CONNECT] Curl_conn_connect(block=0) -> 0, done=0
16:57:25.420471 [0-0] == Info: [UDP] adjust_pollset, !active, POLLIN fd=4
16:57:25.420605 [0-0] == Info: [HAPPY-EYEBALLS] adjust_pollset -> 1 socks
16:57:25.420754 [0-0] == Info: [HTTPS-CONNECT] adjust_pollset -> 1 socks
16:57:25.420903 [0-0] == Info: [MULTI] [CONNECTING] multi_wait pollset[fd=4 IN], timeouts=1
16:57:26.422122 [0-0] == Info: [MULTI] [CONNECTING] multi_perform(running=1)
16:57:26.422266 [0-0] == Info: [HTTP/3] ingress, recvmmsg -> EAGAIN
16:57:26.422384 [0-0] == Info: [HAPPY-EYEBALLS] ipv4 connect -> 0, connected=0
16:57:26.422499 [0-0] == Info: [HTTPS-CONNECT] connect -> 0, done=0
16:57:26.422602 [0-0] == Info: [HTTPS-CONNECT] Curl_conn_connect(block=0) -> 0, done=0
16:57:26.422794 [0-0] == Info: [UDP] adjust_pollset, !active, POLLIN fd=4
16:57:26.422971 [0-0] == Info: [HAPPY-EYEBALLS] adjust_pollset -> 1 socks
16:57:26.423113 [0-0] == Info: [HTTPS-CONNECT] adjust_pollset -> 1 socks
16:57:26.423293 [0-0] == Info: [MULTI] [CONNECTING] multi_wait pollset[fd=4 IN], timeouts=1
16:57:27.424523 [0-0] == Info: [MULTI] [CONNECTING] multi_perform(running=1)
16:57:27.424659 [0-0] == Info: [HTTP/3] ingress, recvmmsg -> EAGAIN
16:57:27.424759 [0-0] == Info: [HAPPY-EYEBALLS] ipv4 connect -> 0, connected=0
16:57:27.424865 [0-0] == Info: [HTTPS-CONNECT] connect -> 0, done=0
16:57:27.424958 [0-0] == Info: [HTTPS-CONNECT] Curl_conn_connect(block=0) -> 0, done=0
16:57:27.425077 [0-0] == Info: [UDP] adjust_pollset, !active, POLLIN fd=4
16:57:27.425177 [0-0] == Info: [HAPPY-EYEBALLS] adjust_pollset -> 1 socks
16:57:27.425278 [0-0] == Info: [HTTPS-CONNECT] adjust_pollset -> 1 socks
16:57:27.425402 [0-0] == Info: [MULTI] [CONNECTING] multi_wait pollset[fd=4 IN], timeouts=1
16:57:28.426559 [0-0] == Info: [MULTI] [CONNECTING] multi_perform(running=1)
16:57:28.426735 [0-0] == Info: [HTTP/3] ingress, recvmmsg -> EAGAIN
16:57:28.426837 [0-0] == Info: [HAPPY-EYEBALLS] ipv4 connect -> 0, connected=0
16:57:28.426944 [0-0] == Info: [HTTPS-CONNECT] connect -> 0, done=0
16:57:28.427094 [0-0] == Info: [HTTPS-CONNECT] Curl_conn_connect(block=0) -> 0, done=0
16:57:28.427279 [0-0] == Info: [UDP] adjust_pollset, !active, POLLIN fd=4
16:57:28.427453 [0-0] == Info: [HAPPY-EYEBALLS] adjust_pollset -> 1 socks
16:57:28.427593 [0-0] == Info: [HTTPS-CONNECT] adjust_pollset -> 1 socks
16:57:28.427748 [0-0] == Info: [MULTI] [CONNECTING] multi_wait pollset[fd=4 IN], timeouts=1
16:57:29.418958 [0-0] == Info: [MULTI] [CONNECTING] multi_perform(running=1)
16:57:29.419127 [0-0] == Info: [HTTP/3] ingress, recvmmsg -> EAGAIN
16:57:29.419247 [0-0] == Info: [HTTP/3] ingress, recvmmsg -> EAGAIN
16:57:29.419428 [0-0] == Info: [HTTP/3] vquic_send(len=1200, gso=1200) -> 0, sent=1200
16:57:29.419629 [0-0] == Info: [HAPPY-EYEBALLS] ipv4 connect -> 0, connected=0
16:57:29.419832 [0-0] == Info: [HTTPS-CONNECT] connect -> 0, done=0
16:57:29.419984 [0-0] == Info: [HTTPS-CONNECT] Curl_conn_connect(block=0) -> 0, done=0
16:57:29.420171 [0-0] == Info: [UDP] adjust_pollset, !active, POLLIN fd=4
16:57:29.420377 [0-0] == Info: [HAPPY-EYEBALLS] adjust_pollset -> 1 socks
16:57:29.420568 [0-0] == Info: [HTTPS-CONNECT] adjust_pollset -> 1 socks
16:57:29.420695 [0-0] == Info: [MULTI] [CONNECTING] multi_wait pollset[fd=4 IN], timeouts=1
16:57:30.421882 [0-0] == Info: [MULTI] [CONNECTING] multi_perform(running=1)
16:57:30.422012 [0-0] == Info: [HTTP/3] ingress, recvmmsg -> EAGAIN
16:57:30.422118 [0-0] == Info: [HAPPY-EYEBALLS] ipv4 connect -> 0, connected=0
16:57:30.422226 [0-0] == Info: [HTTPS-CONNECT] connect -> 0, done=0
16:57:30.422355 [0-0] == Info: [HTTPS-CONNECT] Curl_conn_connect(block=0) -> 0, done=0
16:57:30.422435 [0-0] == Info: [UDP] adjust_pollset, !active, POLLIN fd=4
16:57:30.422502 [0-0] == Info: [HAPPY-EYEBALLS] adjust_pollset -> 1 socks
16:57:30.422569 [0-0] == Info: [HTTPS-CONNECT] adjust_pollset -> 1 socks
16:57:30.422636 [0-0] == Info: [MULTI] [CONNECTING] multi_wait pollset[fd=4 IN], timeouts=1
16:57:31.423342 [0-0] == Info: [MULTI] [CONNECTING] multi_perform(running=1)
16:57:31.423468 [0-0] == Info: [HTTP/3] ingress, recvmmsg -> EAGAIN
16:57:31.423567 [0-0] == Info: [HAPPY-EYEBALLS] ipv4 connect -> 0, connected=0
16:57:31.423674 [0-0] == Info: [HTTPS-CONNECT] connect -> 0, done=0
16:57:31.423765 [0-0] == Info: [HTTPS-CONNECT] Curl_conn_connect(block=0) -> 0, done=0
16:57:31.423887 [0-0] == Info: [UDP] adjust_pollset, !active, POLLIN fd=4
16:57:31.423986 [0-0] == Info: [HAPPY-EYEBALLS] adjust_pollset -> 1 socks
16:57:31.424086 [0-0] == Info: [HTTPS-CONNECT] adjust_pollset -> 1 socks
16:57:31.424184 [0-0] == Info: [MULTI] [CONNECTING] multi_wait pollset[fd=4 IN], timeouts=1
16:57:32.417337 [0-0] == Info: [MULTI] [CONNECTING] multi_perform(running=1)
16:57:32.417475 [0-0] == Info: [HTTP/3] ingress, recvmmsg -> EAGAIN
16:57:32.417590 [0-0] == Info: ngtcp2_conn_handle_expiry returned error: ERR_HANDSHAKE_TIMEOUT
16:57:32.417719 [0-0] == Info: [HTTP/3] connect -> 55, done=0
16:57:32.417857 [0-0] == Info: [HAPPY-EYEBALLS] ipv4 connect -> 55, connected=0
16:57:32.417966 [0-0] == Info: [HAPPY-EYEBALLS] ipv4 done
16:57:32.418097 [0-0] == Info: [HAPPY-EYEBALLS] all eyeballers failed
16:57:32.418194 [0-0] == Info: [HAPPY-EYEBALLS] ipv4 assess started=1, result=55
16:57:32.418378 [0-0] == Info: Failed to connect to syspc008.gsi.de port 8443 after 10005 ms: Failed sending data to the peer
16:57:32.418552 [0-0] == Info: [HTTPS-CONNECT] connect, all attempts failed
16:57:32.418658 [0-0] == Info: [HTTPS-CONNECT] connect -> 55, done=0
16:57:32.418753 [0-0] == Info: [HTTPS-CONNECT] Curl_conn_connect(block=0) -> 55, done=0
16:57:32.418873 [0-0] == Info: [HTTPS-CONNECT] Curl_conn_connect(), filter returned 55
16:57:32.418992 [0-0] == Info: [MULTI] [CONNECTING] multi_done: status: 55 prem: 1 done: 0
16:57:32.419114 [0-0] == Info: [WRITE] [OUT] done
16:57:32.419201 [0-0] == Info: [MULTI] [CONNECTING] multi_done, not reusing connection=0, forbid=0, close=0, premature=1, conn_multiplex=0
16:57:32.419418 [0-0] == Info: closing connection #0
16:57:32.419625 [0-0] == Info: [MULTI] [CONNECTING] -> [COMPLETED]
16:57:32.419744 [0-0] == Info: [MULTI] [COMPLETED] Expire cleared
16:57:32.419845 [0-0] == Info: [MULTI] [COMPLETED] -> [MSGSENT]
16:57:32.419944 [0-0] == Info: [MULTI] [COMPLETED] removed, transfers=0
curl: (55) ngtcp2_conn_handle_expiry returned error: ERR_HANDSHAKE_TIMEOUTTo test in firefox, set in about::config:
network.http.http3.disable_when_third_party_roots_found = false
network.http.http3.alt-svc-mapping-for-testing=opencmw-service.example.com;h3=":443";h3-29=":443"