2025-04-30 09:39:22,943 Generated random file: ooxzygqsge of size: 5120 2025-04-30 09:39:22,944 Generated random file: inicrohhls of size: 10240 2025-04-30 09:39:22,944 Requests: https://server4:443/ooxzygqsge https://server4:443/inicrohhls 2025-04-30 09:39:23,005 2025-04-30 09:39:23,005 Command: WAITFORSERVER=server:443 CERTS=/tmp/certs_m28bqncj/ TESTCASE_SERVER=resumption TESTCASE_CLIENT=resumption WWW=/tmp/www_phht03r1/ DOWNLOADS=/tmp/download_pveomo9e/ SERVER_LOGS=/tmp/logs_server_4i446crl CLIENT_LOGS=/tmp/logs_client_s708ox2_ SCENARIO="simple-p2p --delay=15ms --bandwidth=10Mbps --queue=25" CLIENT=ghcr.io/mozilla/neqo-qns:latest SERVER=ghcr.io/nginx/nginx-quic-qns:latest REQUESTS="https://server4:443/ooxzygqsge https://server4:443/inicrohhls" docker compose --env-file empty.env up --abort-on-container-exit --timeout 1 sim client server 2025-04-30 09:39:35,760 Container sim Created Container server Recreate Container client Recreate Container client Recreated Container server Recreated Attaching to client, server, sim sim | waiting 10s for server:443 server | Setting up routes... server | Actual changes: server | tx-checksumming: off server | tx-checksum-ip-generic: off server | tx-checksum-sctp: off server | tcp-segmentation-offload: off server | tx-tcp-segmentation: off [requested on] server | tx-tcp-ecn-segmentation: off [requested on] server | tx-tcp-mangleid-segmentation: off [requested on] server | tx-tcp6-segmentation: off [requested on] server | tx-udp-segmentation: off [requested on] server | Endpoint's IPv4 address is 193.167.100.100 server | Endpoint's IPv6 address is fd00:cafe:cafe:100::100 server | >>> Starting nginx server... server | nginx version: nginx/1.27.0 (9270:d1b8568f3042) server | built by gcc 9.4.0 (Ubuntu 9.4.0-1ubuntu1~20.04.2) server | built with OpenSSL 1.1.1 (compatible; BoringSSL) (running with BoringSSL) server | TLS SNI support enabled server | configure arguments: --prefix=/etc/nginx --build=9270:d1b8568f3042 --sbin-path=/usr/sbin/nginx --modules-path=/usr/lib/nginx/modules --conf-path=/etc/nginx/nginx.conf --error-log-path=/var/log/nginx/error.log --http-log-path=/var/log/nginx/access.log --pid-path=/run/nginx.pid --lock-path=/run/nginx.lock --http-client-body-temp-path=/var/cache/nginx/client_temp --http-proxy-temp-path=/var/cache/nginx/proxy_temp --http-fastcgi-temp-path=/var/cache/nginx/fastcgi_temp --http-uwsgi-temp-path=/var/cache/nginx/uwsgi_temp --http-scgi-temp-path=/var/cache/nginx/scgi_temp --user=nginx --group=nginx --with-compat --with-debug --with-http_ssl_module --with-http_v2_module --with-http_v3_module --with-cc=c++ --with-cc-opt='-I/boringssl/include -O0 -fno-common -fno-omit-frame-pointer -DNGX_QUIC_DRAFT_VERSION=29 -DNGX_HTTP_V3_HQ=1 -x c' --with-ld-opt='-L/boringssl/build/ssl -L/boringssl/build/crypto' server | >>> Parameters: server | >>> Test case: resumption client | Setting up routes... client | Actual changes: client | tx-checksum-ip-generic: off client | tx-tcp-segmentation: off [not requested] client | tx-tcp-ecn-segmentation: off [not requested] client | tx-tcp-mangleid-segmentation: off [not requested] client | tx-tcp6-segmentation: off [not requested] client | tx-udp-segmentation: off [not requested] client | tx-checksum-sctp: off client | Endpoint's IPv4 address is 193.167.0.100 server | 2025/04/30 09:39:23 [debug] 21#0: bind() 0.0.0.0:443 #5 server | 2025/04/30 09:39:23 [debug] 21#0: bind() 0.0.0.0:443 #6 server | 2025/04/30 09:39:23 [debug] 21#0: bind() [::]:443 #7 server | 2025/04/30 09:39:23 [debug] 21#0: bind() [::]:443 #8 server | 2025/04/30 09:39:23 [debug] 21#0: add cleanup: 000055882F5D5750 server | 2025/04/30 09:39:23 [notice] 21#0: using the "epoll" event method server | 2025/04/30 09:39:23 [debug] 21#0: counter: 00007FFBCD511080, 1 server | 2025/04/30 09:39:23 [notice] 21#0: nginx/1.27.0 (9270:d1b8568f3042) server | 2025/04/30 09:39:23 [notice] 21#0: built by gcc 9.4.0 (Ubuntu 9.4.0-1ubuntu1~20.04.2) server | 2025/04/30 09:39:23 [notice] 21#0: OS: Linux 6.11.0-1012-azure server | 2025/04/30 09:39:23 [notice] 21#0: getrlimit(RLIMIT_NOFILE): 1048576:1048576 server | 2025/04/30 09:39:23 [debug] 21#0: write: 9, 00007FFDFBF4E4F0, 3, 0 server | 2025/04/30 09:39:23 [debug] 21#0: setproctitle: "nginx: master process /usr/sbin/nginx -c /etc/nginx/nginx.conf" server | 2025/04/30 09:39:23 [notice] 21#0: start worker processes server | 2025/04/30 09:39:23 [debug] 21#0: channel 3:9 server | 2025/04/30 09:39:23 [notice] 21#0: start worker process 22 server | 2025/04/30 09:39:23 [debug] 21#0: sigsuspend server | 2025/04/30 09:39:23 [debug] 22#0: add cleanup: 000055882F5D57D8 server | 2025/04/30 09:39:23 [debug] 22#0: malloc: 000055882F5D87D0:16 server | 2025/04/30 09:39:23 [debug] 22#0: add cleanup: 000055882F5D57F0 server | 2025/04/30 09:39:23 [debug] 22#0: malloc: 000055882F5D6AD0:16 server | 2025/04/30 09:39:23 [debug] 22#0: notify eventfd: 11 server | 2025/04/30 09:39:23 [debug] 22#0: testing the EPOLLRDHUP flag: success server | 2025/04/30 09:39:23 [debug] 22#0: malloc: 000055882F5BE430:6144 server | 2025/04/30 09:39:23 [debug] 22#0: malloc: 00007FFBCCE83010:253952 server | 2025/04/30 09:39:23 [debug] 22#0: malloc: 000055882F5DA890:98304 server | 2025/04/30 09:39:23 [debug] 22#0: malloc: 000055882F5F28A0:98304 server | 2025/04/30 09:39:23 [debug] 22#0: epoll add event: fd:5 op:1 ev:00002001 server | 2025/04/30 09:39:23 [debug] 22#0: epoll add event: fd:6 op:1 ev:00002001 server | 2025/04/30 09:39:23 [debug] 22#0: epoll add event: fd:7 op:1 ev:00002001 server | 2025/04/30 09:39:23 [debug] 22#0: epoll add event: fd:8 op:1 ev:00002001 server | 2025/04/30 09:39:23 [debug] 22#0: epoll add event: fd:9 op:1 ev:00002001 server | 2025/04/30 09:39:23 [debug] 22#0: setproctitle: "nginx: worker process" server | 2025/04/30 09:39:23 [debug] 22#0: worker cycle server | 2025/04/30 09:39:23 [debug] 22#0: epoll timer: -1 client | Endpoint's IPv6 address is fd00:cafe:cafe::100 client | + export PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/neqo/bin client | + PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/neqo/bin client | + '[' -n resumption ']' client | + '[' -n /logs/qlog/ ']' client | + case "$ROLE" in client | + /wait-for-it.sh sim:57832 -s -t 30 client | wait-for-it.sh: waiting 30 seconds for sim:57832 sim | server:443 is available after 1.058671875s server | 2025/04/30 09:39:24 [debug] 22#0: epoll: fd:6 ev:0001 d:00007FFBCCE83108 server | 2025/04/30 09:39:24 [debug] 22#0: quic recvmsg on 0.0.0.0:443, ready: 0 server | 2025/04/30 09:39:24 [debug] 22#0: posix_memalign: 000055882F5D6B30:512 @16 server | 2025/04/30 09:39:24 [debug] 22#0: malloc: 000055882F5D87F0:1207 server | 2025/04/30 09:39:24 [debug] 22#0: *1 quic recvmsg: 193.167.100.2:44715 fd:6 n:1207 server | 2025/04/30 09:39:24 [debug] 22#0: *1 quic run server | 2025/04/30 09:39:24 [debug] 22#0: *1 quic packet rx long flags:c0 version:57414954 server | 2025/04/30 09:39:24 [debug] 22#0: *1 quic packet rx dcid len:0 server | 2025/04/30 09:39:24 [debug] 22#0: *1 quic packet rx scid len:0 server | 2025/04/30 09:39:24 [debug] 22#0: *1 quic address validation token len:0 server | 2025/04/30 09:39:24 [debug] 22#0: *1 sending version negotiation packet server | 2025/04/30 09:39:24 [debug] 22#0: *1 sendmsg: 11 of 11 server | 2025/04/30 09:39:24 [debug] 22#0: *1 quic packet done rc:-4 level:init decr:0 pn:0 perr:0 server | 2025/04/30 09:39:24 [debug] 22#0: *1 quic packet rejected rc:-4, cleanup connection server | 2025/04/30 09:39:24 [debug] 22#0: *1 reusable connection: 0 server | 2025/04/30 09:39:24 [debug] 22#0: *1 free: 000055882F5D87F0 server | 2025/04/30 09:39:24 [debug] 22#0: *1 free: 000055882F5D6B30, unused: 24 server | 2025/04/30 09:39:24 [debug] 22#0: timer delta: 852 server | 2025/04/30 09:39:24 [debug] 22#0: worker cycle server | 2025/04/30 09:39:24 [debug] 22#0: epoll timer: -1 server | 2025/04/30 09:39:24 [debug] 22#0: epoll: fd:6 ev:0001 d:00007FFBCCE83108 server | 2025/04/30 09:39:24 [debug] 22#0: quic recvmsg on 0.0.0.0:443, ready: 0 server | 2025/04/30 09:39:24 [debug] 22#0: posix_memalign: 000055882F5D6B30:512 @16 server | 2025/04/30 09:39:24 [debug] 22#0: malloc: 000055882F5D87F0:1207 server | 2025/04/30 09:39:24 [debug] 22#0: *2 quic recvmsg: 193.167.100.2:44715 fd:6 n:1207 server | 2025/04/30 09:39:24 [debug] 22#0: *2 quic run server | 2025/04/30 09:39:24 [debug] 22#0: *2 quic packet rx long flags:c0 version:57414954 server | 2025/04/30 09:39:24 [debug] 22#0: *2 quic packet rx dcid len:0 server | 2025/04/30 09:39:24 [debug] 22#0: *2 quic packet rx scid len:0 server | 2025/04/30 09:39:24 [debug] 22#0: *2 quic address validation token len:0 server | 2025/04/30 09:39:24 [debug] 22#0: *2 sending version negotiation packet server | 2025/04/30 09:39:24 [debug] 22#0: *2 sendmsg: 11 of 11 server | 2025/04/30 09:39:24 [debug] 22#0: *2 quic packet done rc:-4 level:init decr:0 pn:0 perr:0 server | 2025/04/30 09:39:24 [debug] 22#0: *2 quic packet rejected rc:-4, cleanup connection server | 2025/04/30 09:39:24 [debug] 22#0: *2 reusable connection: 0 server | 2025/04/30 09:39:24 [debug] 22#0: *2 free: 000055882F5D87F0 server | 2025/04/30 09:39:24 [debug] 22#0: *2 free: 000055882F5D6B30, unused: 24 server | 2025/04/30 09:39:24 [debug] 22#0: timer delta: 0 server | 2025/04/30 09:39:24 [debug] 22#0: worker cycle server | 2025/04/30 09:39:24 [debug] 22#0: epoll timer: -1 server | 2025/04/30 09:39:24 [debug] 22#0: epoll: fd:6 ev:0001 d:00007FFBCCE83108 server | 2025/04/30 09:39:24 [debug] 22#0: quic recvmsg on 0.0.0.0:443, ready: 0 server | 2025/04/30 09:39:24 [debug] 22#0: posix_memalign: 000055882F5D6B30:512 @16 server | 2025/04/30 09:39:24 [debug] 22#0: malloc: 000055882F5D87F0:1207 server | 2025/04/30 09:39:24 [debug] 22#0: *3 quic recvmsg: 193.167.100.2:44715 fd:6 n:1207 server | 2025/04/30 09:39:24 [debug] 22#0: *3 quic run server | 2025/04/30 09:39:24 [debug] 22#0: *3 quic packet rx long flags:c0 version:57414954 server | 2025/04/30 09:39:24 [debug] 22#0: *3 quic packet rx dcid len:0 server | 2025/04/30 09:39:24 [debug] 22#0: *3 quic packet rx scid len:0 server | 2025/04/30 09:39:24 [debug] 22#0: *3 quic address validation token len:0 server | 2025/04/30 09:39:24 [debug] 22#0: *3 sending version negotiation packet server | 2025/04/30 09:39:24 [debug] 22#0: *3 sendmsg: 11 of 11 server | 2025/04/30 09:39:24 [debug] 22#0: *3 quic packet done rc:-4 level:init decr:0 pn:0 perr:0 server | 2025/04/30 09:39:24 [debug] 22#0: *3 quic packet rejected rc:-4, cleanup connection server | 2025/04/30 09:39:24 [debug] 22#0: *3 reusable connection: 0 server | 2025/04/30 09:39:24 [debug] 22#0: *3 free: 000055882F5D87F0 server | 2025/04/30 09:39:24 [debug] 22#0: *3 free: 000055882F5D6B30, unused: 24 server | 2025/04/30 09:39:24 [debug] 22#0: timer delta: 0 server | 2025/04/30 09:39:24 [debug] 22#0: worker cycle server | 2025/04/30 09:39:24 [debug] 22#0: epoll timer: -1 sim | Using scenario: simple-p2p --delay=15ms --bandwidth=10Mbps --queue=25 sim | tcpdump: listening on eth0, link-type EN10MB (Ethernet), snapshot length 262144 bytes sim | tcpdump: listening on eth1, link-type EN10MB (Ethernet), snapshot length 262144 bytes client | wait-for-it.sh: sim:57832 is available after 1 seconds client | + OPTIONS=(--cc cubic --qns-test "$TESTCASE" --qlog-dir "$QLOGDIR" --output-dir /downloads) client | + '[' 'https://server4:443/ooxzygqsge https://server4:443/inicrohhls' ']' client | + mapfile -d ' ' -t URLS client | + OPTIONS+=("${URLS[@]}") client | + RUST_LOG=debug client | + RUST_BACKTRACE=1 client | + neqo-client --cc cubic --qns-test resumption --qlog-dir /logs/qlog/ --output-dir /downloads https://server4:443/ooxzygqsge 'https://server4:443/inicrohhls client | ' client | ++ tee -i -a /logs/client.log client | 0.000 DEBUG Logging initialized client | 0.001 DEBUG Default socket send buffer size is 212992 client | 0.001 DEBUG Default socket receive buffer size is 1048576, not changing client | 0.001 INFO hq-interop Client connecting: 0.0.0.0:40520 -> 193.167.100.100:443 client | 0.001 DEBUG [CryptoStates] Creating initial cipher state v=Version1, role=Client dcid=d7099bd3b3032229ba73b1accd7a2a6c04 client | 0.001 DEBUG Making Write Initial CryptoDxState, v=Version1 cipher=4865 client | 0.001 DEBUG Making Read Initial CryptoDxState, v=Version1 cipher=4865 client | 0.001 DEBUG Outbound interface eth0 for destination 193.167.100.100 has MTU 1500 client | 0.001 DEBUG [unv-path 0.0.0.0:40520->193.167.100.100:443] Make permanent client | 0.001 DEBUG [unv-path:d7099bd3b3032229ba73b1accd7a2a6c04 0.0.0.0:40520->193.167.100.100:443] set as primary path client | 0.001 DEBUG [pri-unv-path:d7099bd3b3032229ba73b1accd7a2a6c04 0.0.0.0:40520->193.167.100.100:443] Path validated Instant { tv_sec: 334, tv_nsec: 17911855 } client | 0.001 DEBUG [Client d7099bd3b3032229ba73b1accd7a2a6c04] client_start client | 0.002 DEBUG Writing transport parameters, msg=1 client | 0.002 DEBUG [Agent 0x56335426bf20] state -> InProgress client | 0.002 DEBUG [Client d7099bd3b3032229ba73b1accd7a2a6c04] State change from Init -> WaitInitial client | 0.002 DEBUG [Client d7099bd3b3032229ba73b1accd7a2a6c04] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.002 DEBUG Building Initial dcid Some(CID [17]: d7099bd3b3032229ba73b1accd7a2a6c04) scid Some(CID [0]: ) client | 0.002 DEBUG CRYPTO for in offset=0, len=1204 client | 0.002 DEBUG [Client d7099bd3b3032229ba73b1accd7a2a6c04] pn=0 type=Initial pri-path:d7099bd3b3032229ba73b1accd7a2a6c04 0.0.0.0:40520->193.167.100.100:443 IpTos(Cs0, Ect0) len 1252 client | TX -> Crypto { offset: 0, len: 1204 } client | 0.002 DEBUG packet_sent this=0x56335427f630, pn=0, ps=1252 client | 0.002 DEBUG ECN probing: sent 1 probes client | 0.002 DEBUG [Client d7099bd3b3032229ba73b1accd7a2a6c04] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.002 DEBUG Building Initial dcid Some(CID [17]: d7099bd3b3032229ba73b1accd7a2a6c04) scid Some(CID [0]: ) client | 0.002 DEBUG CRYPTO for in offset=1204, len=335 client | 0.002 DEBUG [Client d7099bd3b3032229ba73b1accd7a2a6c04] pn=1 type=Initial pri-path:d7099bd3b3032229ba73b1accd7a2a6c04 0.0.0.0:40520->193.167.100.100:443 IpTos(Cs0, Ect0) len 384 client | TX -> Crypto { offset: 1204, len: 335 } client | 0.002 DEBUG [Client d7099bd3b3032229ba73b1accd7a2a6c04] pad Initial from 384 to PLPMTU 1252 client | 0.002 DEBUG packet_sent this=0x56335427f630, pn=1, ps=1252 client | 0.002 DEBUG ECN probing: sent 2 probes client | 0.002 DEBUG [Client d7099bd3b3032229ba73b1accd7a2a6c04] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } client | 0.002 DEBUG Building Initial dcid Some(CID [17]: d7099bd3b3032229ba73b1accd7a2a6c04) scid Some(CID [0]: ) client | 0.002 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } client | 0.002 DEBUG [Client d7099bd3b3032229ba73b1accd7a2a6c04] delay duration 3.866967ms client | 0.002 DEBUG Setting timeout of 3.866967ms client | 0.002 DEBUG StateChange(WaitInitial) client | 0.002 WARN Cannot create stream ConnectionState client | 0.002 DEBUG [Client d7099bd3b3032229ba73b1accd7a2a6c04] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } client | 0.002 DEBUG Building Initial dcid Some(CID [17]: d7099bd3b3032229ba73b1accd7a2a6c04) scid Some(CID [0]: ) client | 0.002 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } client | 0.002 DEBUG [Client d7099bd3b3032229ba73b1accd7a2a6c04] delay duration 3.840878ms client | 0.002 DEBUG Setting timeout of 3.840878ms client | 0.007 DEBUG [Client d7099bd3b3032229ba73b1accd7a2a6c04] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.007 DEBUG Building Initial dcid Some(CID [17]: d7099bd3b3032229ba73b1accd7a2a6c04) scid Some(CID [0]: ) client | 0.007 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.007 DEBUG [Client d7099bd3b3032229ba73b1accd7a2a6c04] delay duration 294.79822ms client | 0.007 DEBUG Setting timeout of 294.79822ms server | 2025/04/30 09:39:24 [debug] 22#0: epoll: fd:6 ev:0001 d:00007FFBCCE83108 server | 2025/04/30 09:39:24 [debug] 22#0: quic recvmsg on 0.0.0.0:443, ready: 0 server | 2025/04/30 09:39:24 [debug] 22#0: posix_memalign: 000055882F5D6B30:512 @16 server | 2025/04/30 09:39:24 [debug] 22#0: malloc: 000055882F5D87F0:1252 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic recvmsg: 193.167.0.100:40520 fd:6 n:1252 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic run server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic packet rx long flags:cf version:1 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic packet rx init len:1225 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic packet rx dcid len:17 d7099bd3b3032229ba73b1accd7a2a6c04 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic packet rx scid len:0 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic address validation token len:0 server | 2025/04/30 09:39:24 [debug] 22#0: *4 malloc: 000055882F5BFC40:2448 server | 2025/04/30 09:39:24 [debug] 22#0: *4 malloc: 000055882F5C05E0:1528 server | 2025/04/30 09:39:24 [debug] 22#0: *4 posix_memalign: 000055882F5D6D40:512 @16 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic ngx_quic_set_initial_secret server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic socket seq:0 listening at sid:000000000000200312a03f2c8e950b48c7adebc9 nsock:1 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic cid seq:0 received id:0::00000000000000000000000000000000 server | 2025/04/30 09:39:24 [debug] 22#0: *4 posix_memalign: 000055882F5C11E0:512 @16 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic path seq:0 created addr:193.167.0.100:40520 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic path seq:0 set active tx:0 rx:0 valid:0 st:0 mtu:1200 server | 2025/04/30 09:39:24 [debug] 22#0: *4 posix_memalign: 000055882F5C13F0:512 @16 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic socket seq:-1 listening at sid:d7099bd3b3032229ba73b1accd7a2a6c04 nsock:2 server | 2025/04/30 09:39:24 [debug] 22#0: *4 reusable connection: 1 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic connection created server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic packet rx clearflags:c0 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic packet rx number:0 len:1 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic packet len:1252 via sock seq:0 path seq:0 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic path seq:0 status tx:0 rx:1252 valid:0 st:0 mtu:1200 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic stateless reset token 6f4557eb16fd9db2e1c62734c1c8c006 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic frame rx init:0 CRYPTO len:1204 off:0 server | 2025/04/30 09:39:24 [debug] 22#0: *4 SSL_do_handshake: -1 server | 2025/04/30 09:39:24 [debug] 22#0: *4 SSL_get_error: 2 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic ngx_quic_ack_packet pn:0 largest -1 fr:0 nranges:0 server | 2025/04/30 09:39:24 [debug] 22#0: *4 post event 000055882F5C0248 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic packet done rc:0 level:init decr:1 pn:0 perr:0 server | 2025/04/30 09:39:24 [debug] 22#0: *4 event timer add: 6: 75000:409040 server | 2025/04/30 09:39:24 [debug] 22#0: *4 event timer add: 6: 60000:394040 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic state: read:75000 close:60000 server | 2025/04/30 09:39:24 [debug] 22#0: timer delta: 200 server | 2025/04/30 09:39:24 [debug] 22#0: posted event 000055882F5C0248 server | 2025/04/30 09:39:24 [debug] 22#0: *4 delete posted event 000055882F5C0248 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic push handler server | 2025/04/30 09:39:24 [debug] 22#0: *4 posix_memalign: 000055882F5B4F80:512 @16 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic output init packet max:1200 min:0 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic frame tx init:0 ACK n:0 delay:0 0 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic packet tx init bytes:5 need_ack:0 number:0 encoded nl:1 trunc:0x0 server | 2025/04/30 09:39:24 [debug] 22#0: *4 sendmsg: 51 of 51 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic congestion send if:0 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic congestion send if:0 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic congestion send if:0 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic state: read:75000 close:60000 server | 2025/04/30 09:39:24 [debug] 22#0: worker cycle server | 2025/04/30 09:39:24 [debug] 22#0: epoll timer: 60000 server | 2025/04/30 09:39:24 [debug] 22#0: epoll: fd:6 ev:0001 d:00007FFBCCE83108 server | 2025/04/30 09:39:24 [debug] 22#0: quic recvmsg on 0.0.0.0:443, ready: 0 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic recvmsg: fd:6 n:1252 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic input handler server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic packet rx long flags:c7 version:1 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic packet rx init len:357 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic packet rx dcid len:17 d7099bd3b3032229ba73b1accd7a2a6c04 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic packet rx scid len:0 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic address validation token len:0 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic packet rx clearflags:c0 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic packet rx number:1 len:1 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic packet len:1252 via sock seq:-1 path seq:0 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic path seq:0 status tx:51 rx:2504 valid:0 st:0 mtu:1200 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic frame rx init:1 CRYPTO len:335 off:1204 server | 2025/04/30 09:39:24 [debug] 22#0: *4 SSL server name: "server4" server | 2025/04/30 09:39:24 [debug] 22#0: *4 SSL ALPN supported by client: hq-interop server | 2025/04/30 09:39:24 [debug] 22#0: *4 SSL ALPN supported by client: �� server | 2025/04/30 09:39:24 [debug] 22#0: *4 SSL ALPN selected: hq-interop server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic ngx_quic_add_handshake_data server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic SSL_get_peer_quic_transport_params(): params_len:79 server | 2025/04/30 09:39:24 [info] 22#0: *4 quic unknown transport param id:0x11, skipped while handling frames, client: 193.167.0.100, server: 0.0.0.0:443 server | 2025/04/30 09:39:24 [info] 22#0: *4 quic unknown transport param id:0x2ab2, skipped while handling frames, client: 193.167.0.100, server: 0.0.0.0:443 server | 2025/04/30 09:39:24 [info] 22#0: *4 quic reserved transport param id:0xff02de1a, skipped while handling frames, client: 193.167.0.100, server: 0.0.0.0:443 server | 2025/04/30 09:39:24 [info] 22#0: *4 quic unknown transport param id:0x20, skipped while handling frames, client: 193.167.0.100, server: 0.0.0.0:443 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic transport parameters parsed ok server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic tp disable active migration: 0 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic tp idle_timeout:30000 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic tp max_udp_payload_size:65527 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic tp max_data:4611686018427387903 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic tp max_stream_data_bidi_local:1048576 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic tp max_stream_data_bidi_remote:1048576 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic tp max_stream_data_uni:1048576 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic tp initial_max_streams_bidi:16 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic tp initial_max_streams_uni:16 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic tp ack_delay_exponent:3 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic tp max_ack_delay:20 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic tp active_connection_id_limit:8 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic tp initial source_connection_id len:0 server | 2025/04/30 09:39:24 [debug] 22#0: *4 malloc: 000055882F5B56B0:4096 server | 2025/04/30 09:39:24 [debug] 22#0: *4 post event 000055882F5C0248 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic ngx_quic_set_write_secret() level:2 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic ngx_quic_add_handshake_data server | 2025/04/30 09:39:24 [debug] 22#0: *4 malloc: 000055882F60A8B0:4096 server | 2025/04/30 09:39:24 [debug] 22#0: *4 posix_memalign: 000055882F5B7A10:512 @16 server | 2025/04/30 09:39:24 [debug] 22#0: *4 update posted event 000055882F5C0248 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic ngx_quic_set_write_secret() level:3 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic ngx_quic_flush_flight() server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic ngx_quic_set_read_secret() level:2 server | 2025/04/30 09:39:24 [debug] 22#0: *4 SSL_do_handshake: -1 server | 2025/04/30 09:39:24 [debug] 22#0: *4 SSL_get_error: 2 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic ngx_quic_ack_packet pn:1 largest 0 fr:0 nranges:0 server | 2025/04/30 09:39:24 [debug] 22#0: *4 update posted event 000055882F5C0248 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic packet done rc:0 level:init decr:1 pn:1 perr:0 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic packet rx short flags:0 server | 2025/04/30 09:39:24 [info] 22#0: *4 quic fixed bit is not set while parsing quic packet, client: 193.167.0.100, server: 0.0.0.0:443 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic packet done rc:-5 parse failed server | 2025/04/30 09:39:24 [debug] 22#0: *4 event timer del: 6: 409040 server | 2025/04/30 09:39:24 [debug] 22#0: *4 event timer add: 6: 30000:364041 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic state: read:30000 close:59999 server | 2025/04/30 09:39:24 [debug] 22#0: timer delta: 1 server | 2025/04/30 09:39:24 [debug] 22#0: posted event 000055882F5C0248 server | 2025/04/30 09:39:24 [debug] 22#0: *4 delete posted event 000055882F5C0248 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic push handler server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic output init packet max:1200 min:0 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic frame tx init:1 ACK n:0 delay:0 1-0 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic frame tx init:1 CRYPTO len:90 off:0 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic packet tx init bytes:99 need_ack:1 number:1 encoded nl:1 trunc:0x1 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic output hs packet max:1054 min:1054 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic frame tx hs:0 CRYPTO len:728 off:0 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic packet tx hs bytes:1008 need_ack:1 number:0 encoded nl:1 trunc:0x0 server | 2025/04/30 09:39:24 [debug] 22#0: *4 sendmsg: 1200 of 1200 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic congestion send if:146 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic congestion send if:1200 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic congestion send if:1200 server | 2025/04/30 09:39:24 [debug] 22#0: *4 event timer: 6, old: 364041, new: 364041 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic lost timer pto:997 server | 2025/04/30 09:39:24 [debug] 22#0: *4 event timer add: 6: 997:335038 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic state: send:30000 pto:997 close:59999 server | 2025/04/30 09:39:24 [debug] 22#0: worker cycle server | 2025/04/30 09:39:24 [debug] 22#0: epoll timer: 997 client | 0.039 DEBUG [Client d7099bd3b3032229ba73b1accd7a2a6c04] pn=0 type=Initial pri-path:d7099bd3b3032229ba73b1accd7a2a6c04 0.0.0.0:40520->193.167.100.100:443 IpTos(Cs0, NotEct) len 51 client | -> RX Ack { largest_acknowledged: 0, ack_delay: 0, first_ack_range: 0, ack_ranges: [], ecn_count: None } client | 0.039 DEBUG [Client d7099bd3b3032229ba73b1accd7a2a6c04] Rx ACK space=in, ranges=[0..=0] client | 0.039 DEBUG [LossRecovery] ACK for Initial - largest_acked=0 client | 0.039 DEBUG on_packets_acked this=0x56335427f630, limited=1, bytes_in_flight=1252, cwnd=12520, state=SlowStart, new_acked=1252 client | 0.039 DEBUG Acked crypto frame space=in offset=0 length=1204 client | 0.039 DEBUG [Client d7099bd3b3032229ba73b1accd7a2a6c04] Changing to use Server CID=000000000000200312a03f2c8e950b48c7adebc9 client | 0.039 DEBUG [Client d7099bd3b3032229ba73b1accd7a2a6c04] State change from WaitInitial -> WaitVersion client | 0.039 DEBUG [Client d7099bd3b3032229ba73b1accd7a2a6c04] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.039 DEBUG Building Initial dcid Some(CID [20]: 000000000000200312a03f2c8e950b48c7adebc9) scid Some(CID [0]: ) client | 0.039 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.039 DEBUG [Client d7099bd3b3032229ba73b1accd7a2a6c04] delay duration 76.083482ms client | 0.039 DEBUG Setting timeout of 76.083482ms client | 0.039 WARN Unhandled event StateChange(WaitVersion) client | 0.039 DEBUG [Client d7099bd3b3032229ba73b1accd7a2a6c04] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.039 DEBUG Building Initial dcid Some(CID [20]: 000000000000200312a03f2c8e950b48c7adebc9) scid Some(CID [0]: ) client | 0.039 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.039 DEBUG [Client d7099bd3b3032229ba73b1accd7a2a6c04] delay duration 76.050791ms client | 0.039 DEBUG Setting timeout of 76.050791ms client | 0.041 DEBUG [Client d7099bd3b3032229ba73b1accd7a2a6c04] pn=1 type=Initial pri-path:000000000000200312a03f2c8e950b48c7adebc9 0.0.0.0:40520->193.167.100.100:443 IpTos(Cs0, NotEct) len 146 client | -> RX Ack { largest_acknowledged: 1, ack_delay: 0, first_ack_range: 1, ack_ranges: [], ecn_count: None } client | -> RX Crypto { offset: 0, len: 90 } client | 0.041 DEBUG [Client d7099bd3b3032229ba73b1accd7a2a6c04] Rx ACK space=in, ranges=[0..=1] client | 0.041 DEBUG [LossRecovery] ACK for Initial - largest_acked=1 client | 0.041 DEBUG on_packets_acked this=0x56335427f630, limited=1, bytes_in_flight=0, cwnd=12520, state=SlowStart, new_acked=1252 client | 0.041 DEBUG Acked crypto frame space=in offset=1204 length=335 client | 0.041 DEBUG Read Ok(90) bytes client | 0.042 DEBUG Write secret available for Handshake: SymKey [32]: 5b6b09051fdae413d7fa45c463330406f0cd3a5c35ce16243e2a8133a06986d6 client | 0.042 DEBUG Read secret available for Handshake: SymKey [32]: e2672cdbadc0192e1de9f2a044dc08fd9b6cf4cdb696438028293244fd9cbb67 client | 0.042 DEBUG [Agent 0x56335426bf20] state -> InProgress client | 0.042 DEBUG Making Write Handshake CryptoDxState, v=Version1 cipher=4865 client | 0.042 DEBUG Making Read Handshake CryptoDxState, v=Version1 cipher=4865 client | 0.042 DEBUG [Crypto] Handshake keys installed client | 0.042 DEBUG [Recvd-in] Set ACK timer to Instant { tv_sec: 334, tv_nsec: 58691724 } client | 0.042 DEBUG [Client d7099bd3b3032229ba73b1accd7a2a6c04] State change from WaitVersion -> Handshaking client | 0.042 DEBUG [Client d7099bd3b3032229ba73b1accd7a2a6c04] pn=0 type=Handshake pri-path:000000000000200312a03f2c8e950b48c7adebc9 0.0.0.0:40520->193.167.100.100:443 IpTos(Cs0, NotEct) len 1054 client | -> RX Crypto { offset: 0, len: 728 } client | -> RX Padding { len: 276 } client | 0.042 DEBUG Read Ok(728) bytes client | 0.043 DEBUG [Agent 0x56335426bf20] state -> AuthenticationPending client | 0.043 DEBUG [Recvd-hs] Set ACK timer to Instant { tv_sec: 334, tv_nsec: 58691724 } client | 0.043 DEBUG [Client d7099bd3b3032229ba73b1accd7a2a6c04] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.043 DEBUG Building Initial dcid Some(CID [20]: 000000000000200312a03f2c8e950b48c7adebc9) scid Some(CID [0]: ) client | 0.043 DEBUG [Client d7099bd3b3032229ba73b1accd7a2a6c04] pn=2 type=Initial pri-path:000000000000200312a03f2c8e950b48c7adebc9 0.0.0.0:40520->193.167.100.100:443 IpTos(Cs0, Ect0) len 53 client | TX -> Ack { largest_acknowledged: 1, ack_delay: 144, first_ack_range: 1, ack_ranges: [], ecn_count: None } client | 0.043 DEBUG Building Handshake dcid Some(CID [20]: 000000000000200312a03f2c8e950b48c7adebc9) scid Some(CID [0]: ) client | 0.043 DEBUG [Client d7099bd3b3032229ba73b1accd7a2a6c04] pn=0 type=Handshake pri-path:000000000000200312a03f2c8e950b48c7adebc9 0.0.0.0:40520->193.167.100.100:443 IpTos(Cs0, Ect0) len 105 client | TX -> Ack { largest_acknowledged: 0, ack_delay: 144, first_ack_range: 0, ack_ranges: [], ecn_count: None } client | 0.043 DEBUG [Client d7099bd3b3032229ba73b1accd7a2a6c04] Drop packet number space in client | 0.043 DEBUG [LossRecovery] Reset loss recovery state for Initial client | 0.043 WARN [LossRecovery] ignoring in-2 from dropped space client | 0.043 DEBUG ECN probing: sent 3 probes client | 0.043 DEBUG [Client d7099bd3b3032229ba73b1accd7a2a6c04] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.043 DEBUG Building Handshake dcid Some(CID [20]: 000000000000200312a03f2c8e950b48c7adebc9) scid Some(CID [0]: ) client | 0.043 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.043 DEBUG [Client d7099bd3b3032229ba73b1accd7a2a6c04] delay duration 96.622471ms client | 0.043 DEBUG Setting timeout of 96.622471ms client | 0.043 DEBUG StateChange(Handshaking) client | 0.043 WARN Cannot create stream ConnectionState client | 0.043 DEBUG [Client d7099bd3b3032229ba73b1accd7a2a6c04] Authenticated Ok client | 0.043 DEBUG Write secret available for ApplicationData: SymKey [32]: 29db7815b9af65d6c446c5c93a1b517891f0af7eaf332e07fe444433bd3ad743 client | 0.043 DEBUG Read secret available for ApplicationData: SymKey [32]: 67cfd9728291c0feb101684af8a73cd5e07be89896a8e7c54f0786c63cda13be client | 0.043 DEBUG [Agent 0x56335426bf20] SSL_AuthCertificateComplete: Ok(()) client | 0.043 DEBUG [Agent 0x56335426bf20] state -> Complete(SecretAgentInfo { version: 772, cipher: 4865, group: 29, resumed: false, early_data: false, ech_accepted: false, alpn: Some("hq-interop"), signature_scheme: 1027 }) client | 0.043 DEBUG [Client d7099bd3b3032229ba73b1accd7a2a6c04] TLS connection complete client | 0.043 DEBUG Making Write ApplicationData CryptoDxState, v=Version1 cipher=4865 client | 0.043 DEBUG [Crypto] Application write key installed client | 0.043 DEBUG Making Read ApplicationData CryptoDxState, v=Version1 cipher=4865 client | 0.043 DEBUG [Crypto] application read keys installed client | 0.043 DEBUG [Client d7099bd3b3032229ba73b1accd7a2a6c04] State change from Handshaking -> Connected client | 0.043 INFO [Client d7099bd3b3032229ba73b1accd7a2a6c04] Connection established client | 0.043 DEBUG stream BiDi creatable client | 0.043 INFO Created stream 0 for https://server4/ooxzygqsge client | 0.043 INFO Saving https://server4/ooxzygqsge to "/downloads/ooxzygqsge" client | 0.043 DEBUG stream UniDi creatable client | 0.043 DEBUG StateChange(Connected) client | 0.043 DEBUG stream 0 writable client | 0.043 DEBUG [Client d7099bd3b3032229ba73b1accd7a2a6c04] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.043 DEBUG Building Handshake dcid Some(CID [20]: 000000000000200312a03f2c8e950b48c7adebc9) scid Some(CID [0]: ) client | 0.043 DEBUG CRYPTO for hs offset=0, len=36 client | 0.043 DEBUG [Client d7099bd3b3032229ba73b1accd7a2a6c04] pn=1 type=Handshake pri-path:000000000000200312a03f2c8e950b48c7adebc9 0.0.0.0:40520->193.167.100.100:443 IpTos(Cs0, Ect0) len 85 client | TX -> Crypto { offset: 0, len: 36 } client | 0.043 DEBUG packet_sent this=0x56335427f630, pn=1, ps=85 client | 0.043 DEBUG Building Short dcid Some(CID [20]: 000000000000200312a03f2c8e950b48c7adebc9) client | 0.043 DEBUG [Client d7099bd3b3032229ba73b1accd7a2a6c04] pn=0 type=Short pri-path:000000000000200312a03f2c8e950b48c7adebc9 0.0.0.0:40520->193.167.100.100:443 IpTos(Cs0, Ect0) len 143 client | TX -> Stream { stream_id: 0, offset: 0, len: 17, fin: true } client | 0.043 DEBUG packet_sent this=0x56335427f630, pn=0, ps=58 client | 0.043 DEBUG ECN probing: sent 4 probes client | 0.043 DEBUG [Client d7099bd3b3032229ba73b1accd7a2a6c04] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.043 DEBUG Building Handshake dcid Some(CID [20]: 000000000000200312a03f2c8e950b48c7adebc9) scid Some(CID [0]: ) client | 0.043 DEBUG Building Short dcid Some(CID [20]: 000000000000200312a03f2c8e950b48c7adebc9) client | 0.043 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.043 DEBUG [Client d7099bd3b3032229ba73b1accd7a2a6c04] delay duration 96.62742ms client | 0.043 DEBUG Setting timeout of 96.62742ms server | 2025/04/30 09:39:24 [debug] 22#0: epoll: fd:6 ev:0001 d:00007FFBCCE83108 server | 2025/04/30 09:39:24 [debug] 22#0: quic recvmsg on 0.0.0.0:443, ready: 0 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic recvmsg: fd:6 n:105 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic input handler server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic packet rx long flags:c5 version:1 server | 2025/04/30 09:39:24 [info] 22#0: *4 quic UDP datagram is too small for initial packet while parsing quic long header, client: 193.167.0.100, server: 0.0.0.0:443 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic packet done rc:-5 parse failed server | 2025/04/30 09:39:24 [debug] 22#0: timer delta: 34 server | 2025/04/30 09:39:24 [debug] 22#0: worker cycle server | 2025/04/30 09:39:24 [debug] 22#0: epoll timer: 963 server | 2025/04/30 09:39:24 [debug] 22#0: epoll: fd:6 ev:0001 d:00007FFBCCE83108 server | 2025/04/30 09:39:24 [debug] 22#0: quic recvmsg on 0.0.0.0:443, ready: 0 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic recvmsg: fd:6 n:143 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic input handler server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic packet rx long flags:ed version:1 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic packet rx hs len:56 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic packet rx dcid len:20 000000000000200312a03f2c8e950b48c7adebc9 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic packet rx scid len:0 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic packet rx clearflags:e0 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic packet rx number:1 len:1 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic packet len:143 via sock seq:0 path seq:0 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic path seq:0 status tx:1251 rx:2647 valid:0 st:0 mtu:1200 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic congestion slow start win:131200 ss:-1 if:1054 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic socket seq:-1 closed nsock:1 server | 2025/04/30 09:39:24 [debug] 22#0: *4 event timer del: 6: 335038 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic lost timer pto:963 server | 2025/04/30 09:39:24 [debug] 22#0: *4 event timer add: 6: 963:335038 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic path seq:0 in handshake tx:1251 rx:2647 valid:1 st:0 mtu:1200 server | 2025/04/30 09:39:24 [debug] 22#0: *4 post event 000055882F5C0248 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic frame rx hs:1 CRYPTO len:36 off:0 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic ngx_quic_set_read_secret() level:3 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic ngx_quic_add_handshake_data server | 2025/04/30 09:39:24 [debug] 22#0: *4 update posted event 000055882F5C0248 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic ngx_quic_flush_flight() server | 2025/04/30 09:39:24 [debug] 22#0: *4 SSL_do_handshake: 1 server | 2025/04/30 09:39:24 [debug] 22#0: *4 SSL: TLSv1.3, cipher: "TLS_AES_128_GCM_SHA256 Kx=GENERIC Au=GENERIC Enc=AESGCM(128) Mac=AEAD" server | 2025/04/30 09:39:24 [debug] 22#0: *4 update posted event 000055882F5C0248 server | 2025/04/30 09:39:24 [debug] 22#0: *4 post event 000055882F5C03C8 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic congestion slow start win:132254 ss:-1 if:0 server | 2025/04/30 09:39:24 [debug] 22#0: *4 event timer del: 6: 335038 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic lost timer unset server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic path seq:0 schedule mtu:2400 server | 2025/04/30 09:39:24 [debug] 22#0: *4 event timer add: 6: 100:334175 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic create sockets has:1 max:8 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic socket seq:1 listening at sid:00000000000020035c1c3f48c8e3afbc915f637b nsock:2 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic stateless reset token 17720360f56752e33ddccf0f5281ebe9 server | 2025/04/30 09:39:24 [debug] 22#0: *4 update posted event 000055882F5C0248 server | 2025/04/30 09:39:24 [debug] 22#0: *4 posix_memalign: 000055882F5B4920:512 @16 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic socket seq:2 listening at sid:000000000000200389130f15350b94edf81a36f3 nsock:3 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic stateless reset token b6c7c54244407478685d0b577b20b46c server | 2025/04/30 09:39:24 [debug] 22#0: *4 update posted event 000055882F5C0248 server | 2025/04/30 09:39:24 [debug] 22#0: *4 posix_memalign: 000055882F5B4B30:512 @16 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic socket seq:3 listening at sid:000000000000200319b4b923faff1c741efb57a1 nsock:4 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic stateless reset token f4a6677cf31a200133445ba7c3f6ab19 server | 2025/04/30 09:39:24 [debug] 22#0: *4 update posted event 000055882F5C0248 server | 2025/04/30 09:39:24 [debug] 22#0: *4 posix_memalign: 000055882F5B4D40:512 @16 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic socket seq:4 listening at sid:000000000000200334413a46ffd926d1bd203101 nsock:5 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic stateless reset token 8575cd6cced83bb7571b7fcbbb7edf6c server | 2025/04/30 09:39:24 [debug] 22#0: *4 update posted event 000055882F5C0248 server | 2025/04/30 09:39:24 [debug] 22#0: *4 posix_memalign: 000055882F5B4210:512 @16 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic socket seq:5 listening at sid:0000000000002003e9d25bb201dea80691554d7b nsock:6 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic stateless reset token 31f194c0c1bf3f2a91a72e25bf60ee06 server | 2025/04/30 09:39:24 [debug] 22#0: *4 update posted event 000055882F5C0248 server | 2025/04/30 09:39:24 [debug] 22#0: *4 posix_memalign: 000055882F5B4420:512 @16 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic socket seq:6 listening at sid:0000000000002003712b22bee2286b56c3ac3060 nsock:7 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic stateless reset token 7f6e22d8e1073ce6ef32169a9b0e2459 server | 2025/04/30 09:39:24 [debug] 22#0: *4 update posted event 000055882F5C0248 server | 2025/04/30 09:39:24 [debug] 22#0: *4 posix_memalign: 000055882F5B4630:512 @16 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic socket seq:7 listening at sid:0000000000002003dba26c3b83bcd02fc81f1541 nsock:8 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic stateless reset token 3b812c48384c5c9db8facf05e09ed4b3 server | 2025/04/30 09:39:24 [debug] 22#0: *4 update posted event 000055882F5C0248 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic init streams server | 2025/04/30 09:39:24 [debug] 22#0: *4 http3 init server | 2025/04/30 09:39:24 [debug] 22#0: *4 http3 init session server | 2025/04/30 09:39:24 [debug] 22#0: *4 posix_memalign: 000055882F60BDF0:512 @16 server | 2025/04/30 09:39:24 [debug] 22#0: *4 add cleanup: 000055882F5B4AD8 server | 2025/04/30 09:39:24 [debug] 22#0: *4 event timer add: 6: 75000:409075 server | 2025/04/30 09:39:24 [debug] 22#0: *4 event timer del: 6: 394040 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic ngx_quic_ack_packet pn:1 largest -1 fr:0 nranges:0 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic packet done rc:0 level:hs decr:1 pn:1 perr:0 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic packet rx short flags:59 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic packet rx dcid len:20 000000000000200312a03f2c8e950b48c7adebc9 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic packet rx clearflags:40 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic packet rx number:0 len:1 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic frame rx app:0 STREAM id:0x0 len:17 fin:1 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic stream id:0x0 is missing server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic stream id:0x0 create server | 2025/04/30 09:39:24 [debug] 22#0: *4 posix_memalign: 000055882F60C000:512 @16 server | 2025/04/30 09:39:24 [debug] 22#0: *4 posix_memalign: 000055882F60C210:16384 @16 server | 2025/04/30 09:39:24 [debug] 22#0: *4 reusable connection: 0 server | 2025/04/30 09:39:24 [debug] 22#0: *5 add cleanup: 000055882F60C2D0 server | 2025/04/30 09:39:24 [debug] 22#0: *5 post event 000055882F5DAAD0 server | 2025/04/30 09:39:24 [debug] 22#0: *4 delete posted event 000055882F5C0248 server | 2025/04/30 09:39:24 [debug] 22#0: *4 post event 000055882F5C0248 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic stream id:0x0 flow control msd:17/65536 md:17/8585216 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic ngx_quic_ack_packet pn:0 largest -1 fr:0 nranges:0 server | 2025/04/30 09:39:24 [debug] 22#0: *4 update posted event 000055882F5C0248 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic packet done rc:0 level:app decr:1 pn:0 perr:0 server | 2025/04/30 09:39:24 [debug] 22#0: *4 event timer: 6, old: 364041, new: 364075 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic state: read:29966 server | 2025/04/30 09:39:24 [debug] 22#0: timer delta: 0 server | 2025/04/30 09:39:24 [debug] 22#0: posted event 000055882F5C03C8 server | 2025/04/30 09:39:24 [debug] 22#0: *4 delete posted event 000055882F5C03C8 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic key update server | 2025/04/30 09:39:24 [debug] 22#0: posted event 000055882F5DAAD0 server | 2025/04/30 09:39:24 [debug] 22#0: *5 delete posted event 000055882F5DAAD0 server | 2025/04/30 09:39:24 [debug] 22#0: *5 quic init stream server | 2025/04/30 09:39:24 [debug] 22#0: *5 http3 init request stream server | 2025/04/30 09:39:24 [debug] 22#0: *5 add cleanup: 000055882F60C340 server | 2025/04/30 09:39:24 [debug] 22#0: *4 event timer del: 6: 409075 server | 2025/04/30 09:39:24 [debug] 22#0: *5 http wait request handler server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic stream id:0x0 recv buf:1024 server | 2025/04/30 09:39:24 [debug] 22#0: *5 quic stream id:0x0 recv len:17 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic stream id:0x0 flow update 17 server | 2025/04/30 09:39:24 [debug] 22#0: *5 reusable connection: 0 server | 2025/04/30 09:39:24 [debug] 22#0: *5 posix_memalign: 000055882F610220:4096 @16 server | 2025/04/30 09:39:24 [debug] 22#0: *5 http process request line server | 2025/04/30 09:39:24 [debug] 22#0: *5 http request line: "GET /ooxzygqsge" server | 2025/04/30 09:39:24 [debug] 22#0: *5 http uri: "/ooxzygqsge" server | 2025/04/30 09:39:24 [debug] 22#0: *5 http args: "" server | 2025/04/30 09:39:24 [debug] 22#0: *5 http exten: "" server | 2025/04/30 09:39:24 [debug] 22#0: *5 rewrite phase: 0 server | 2025/04/30 09:39:24 [debug] 22#0: *5 test location: "/" server | 2025/04/30 09:39:24 [debug] 22#0: *5 using configuration "/" server | 2025/04/30 09:39:24 [debug] 22#0: *5 http cl:-1 max:1048576 server | 2025/04/30 09:39:24 [debug] 22#0: *5 rewrite phase: 2 server | 2025/04/30 09:39:24 [debug] 22#0: *5 post rewrite phase: 3 server | 2025/04/30 09:39:24 [debug] 22#0: *5 generic phase: 4 server | 2025/04/30 09:39:24 [debug] 22#0: *5 generic phase: 5 server | 2025/04/30 09:39:24 [debug] 22#0: *5 access phase: 6 server | 2025/04/30 09:39:24 [debug] 22#0: *5 access phase: 7 server | 2025/04/30 09:39:24 [debug] 22#0: *5 post access phase: 8 server | 2025/04/30 09:39:24 [debug] 22#0: *5 generic phase: 9 server | 2025/04/30 09:39:24 [debug] 22#0: *5 generic phase: 10 server | 2025/04/30 09:39:24 [debug] 22#0: *5 content phase: 11 server | 2025/04/30 09:39:24 [debug] 22#0: *5 content phase: 12 server | 2025/04/30 09:39:24 [debug] 22#0: *5 content phase: 13 server | 2025/04/30 09:39:24 [debug] 22#0: *5 http filename: "/www/ooxzygqsge" server | 2025/04/30 09:39:24 [debug] 22#0: *5 add cleanup: 000055882F610F58 server | 2025/04/30 09:39:24 [debug] 22#0: *5 http static fd: 3 server | 2025/04/30 09:39:24 [debug] 22#0: *5 http set discard body server | 2025/04/30 09:39:24 [debug] 22#0: *5 http output filter "/ooxzygqsge?" server | 2025/04/30 09:39:24 [debug] 22#0: *5 http copy filter: "/ooxzygqsge?" server | 2025/04/30 09:39:24 [debug] 22#0: *5 malloc: 000055882F611230:5120 server | 2025/04/30 09:39:24 [debug] 22#0: *5 read: 3, 000055882F611230, 5120, 0 server | 2025/04/30 09:39:24 [debug] 22#0: *5 http postpone filter "/ooxzygqsge?" 000055882F611170 server | 2025/04/30 09:39:24 [debug] 22#0: *5 write new buf t:1 f:0 000055882F611230, pos 000055882F611230, size: 5120 file: 0, size: 0 server | 2025/04/30 09:39:24 [debug] 22#0: *5 http write filter: l:1 f:0 s:5120 server | 2025/04/30 09:39:24 [debug] 22#0: *5 http write filter limit 2097152 server | 2025/04/30 09:39:24 [debug] 22#0: *4 malloc: 000055882F612640:4096 server | 2025/04/30 09:39:24 [debug] 22#0: *4 malloc: 000055882F613650:4096 server | 2025/04/30 09:39:24 [debug] 22#0: *5 quic send_chain sent:5120 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic stream id:0x0 flush limit:1048576 server | 2025/04/30 09:39:24 [debug] 22#0: *4 update posted event 000055882F5C0248 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic stream id:0x0 flush len:5120 last:0 server | 2025/04/30 09:39:24 [debug] 22#0: *5 http write filter 0000000000000000 server | 2025/04/30 09:39:24 [debug] 22#0: *5 http copy filter: 0 "/ooxzygqsge?" server | 2025/04/30 09:39:24 [debug] 22#0: *5 http finalize request: 0, "/ooxzygqsge?" a:1, c:1 server | 2025/04/30 09:39:24 [debug] 22#0: *5 http request count:1 blk:0 server | 2025/04/30 09:39:24 [debug] 22#0: *5 http close request server | 2025/04/30 09:39:24 [debug] 22#0: *5 http log handler server | 2025/04/30 09:39:24 [debug] 22#0: *5 posix_memalign: 000055882F614660:4096 @16 server | 193.167.0.100 - - [30/Apr/2025:09:39:24 +0000] "GET /ooxzygqsge" 200 5120 "-" "-" server | 2025/04/30 09:39:24 [debug] 22#0: *5 run cleanup: 000055882F610F58 server | 2025/04/30 09:39:24 [debug] 22#0: *5 file cleanup: fd:3 server | 2025/04/30 09:39:24 [debug] 22#0: *5 free: 000055882F611230 server | 2025/04/30 09:39:24 [debug] 22#0: *5 free: 000055882F610220, unused: 48 server | 2025/04/30 09:39:24 [debug] 22#0: *5 free: 000055882F614660, unused: 3949 server | 2025/04/30 09:39:24 [debug] 22#0: *5 close http connection: 6 server | 2025/04/30 09:39:24 [debug] 22#0: *5 reusable connection: 0 server | 2025/04/30 09:39:24 [debug] 22#0: *5 run cleanup: 000055882F60C340 server | 2025/04/30 09:39:24 [debug] 22#0: *4 event timer add: 6: 75000:409075 server | 2025/04/30 09:39:24 [debug] 22#0: *5 run cleanup: 000055882F60C2D0 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic stream id:0x0 cleanup server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic stream id:0x0 send shutdown server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic stream id:0x0 flush limit:1043456 server | 2025/04/30 09:39:24 [debug] 22#0: *4 posix_memalign: 000055882F610220:512 @16 server | 2025/04/30 09:39:24 [debug] 22#0: *4 update posted event 000055882F5C0248 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic stream id:0x0 flush len:0 last:1 server | 2025/04/30 09:39:24 [debug] 22#0: *5 free: 000055882F60C210, unused: 14952 server | 2025/04/30 09:39:24 [debug] 22#0: posted event 000055882F5C0248 server | 2025/04/30 09:39:24 [debug] 22#0: *4 delete posted event 000055882F5C0248 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic push handler server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic output app packet max:1200 min:0 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic frame tx app:0 ACK n:0 delay:0 0 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic frame tx app:0 CRYPTO len:572 off:0 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic frame tx app:0 HANDSHAKE DONE server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic frame tx app:0 NEW_CONNECTION_ID seq:1 retire:0 len:20 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic frame tx app:0 NEW_CONNECTION_ID seq:2 retire:0 len:20 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic frame tx app:0 NEW_CONNECTION_ID seq:3 retire:0 len:20 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic frame tx app:0 NEW_CONNECTION_ID seq:4 retire:0 len:20 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic frame tx app:0 NEW_CONNECTION_ID seq:5 retire:0 len:20 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic frame tx app:0 NEW_CONNECTION_ID seq:6 retire:0 len:20 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic frame tx app:0 NEW_CONNECTION_ID seq:7 retire:0 len:20 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic split frame now:5125 need:320 shrink:4805 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic frame tx app:0 STREAM id:0x0 off:0 len:315 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic packet tx app bytes:1182 need_ack:1 number:0 encoded nl:1 trunc:0x0 server | 2025/04/30 09:39:24 [debug] 22#0: *4 sendmsg: 1200 of 1200 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic congestion send if:0 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic congestion send if:0 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic congestion send if:1200 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic output app packet max:1200 min:0 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic split frame now:4811 need:1182 shrink:3629 server | 2025/04/30 09:39:24 [debug] 22#0: *4 posix_memalign: 000055882F610430:512 @16 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic frame tx app:1 STREAM id:0x0 off:315 len:1176 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic packet tx app bytes:1182 need_ack:1 number:1 encoded nl:1 trunc:0x1 server | 2025/04/30 09:39:24 [debug] 22#0: *4 sendmsg: 1200 of 1200 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic congestion send if:1200 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic congestion send if:1200 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic congestion send if:2400 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic output app packet max:1200 min:0 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic split frame now:3635 need:1182 shrink:2453 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic frame tx app:2 STREAM id:0x0 off:1491 len:1176 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic packet tx app bytes:1182 need_ack:1 number:2 encoded nl:1 trunc:0x2 server | 2025/04/30 09:39:24 [debug] 22#0: *4 sendmsg: 1200 of 1200 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic congestion send if:2400 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic congestion send if:2400 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic congestion send if:3600 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic output app packet max:1200 min:0 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic split frame now:2459 need:1182 shrink:1277 server | 2025/04/30 09:39:24 [debug] 22#0: *4 posix_memalign: 000055882F610640:512 @16 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic frame tx app:3 STREAM id:0x0 off:2667 len:1176 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic packet tx app bytes:1182 need_ack:1 number:3 encoded nl:1 trunc:0x3 server | 2025/04/30 09:39:24 [debug] 22#0: *4 sendmsg: 1200 of 1200 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic congestion send if:3600 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic congestion send if:3600 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic congestion send if:4800 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic output app packet max:1200 min:0 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic split frame now:1283 need:1182 shrink:101 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic frame tx app:4 STREAM id:0x0 off:3843 len:1176 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic packet tx app bytes:1182 need_ack:1 number:4 encoded nl:1 trunc:0x4 server | 2025/04/30 09:39:24 [debug] 22#0: *4 sendmsg: 1200 of 1200 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic congestion send if:4800 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic congestion send if:4800 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic congestion send if:6000 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic output app packet max:1200 min:0 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic frame tx app:5 STREAM id:0x0 off:5019 len:101 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic frame tx app:5 STREAM id:0x0 off:5120 len:0 fin:1 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic packet tx app bytes:112 need_ack:1 number:5 encoded nl:1 trunc:0x5 server | 2025/04/30 09:39:24 [debug] 22#0: *4 sendmsg: 130 of 130 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic congestion send if:6000 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic congestion send if:6000 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic congestion send if:6130 server | 2025/04/30 09:39:24 [debug] 22#0: *4 event timer: 6, old: 364041, new: 364075 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic lost timer pto:1017 server | 2025/04/30 09:39:24 [debug] 22#0: *4 event timer add: 6: 1017:335092 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic state: send:29966 pto:1017 server | 2025/04/30 09:39:24 [debug] 22#0: worker cycle server | 2025/04/30 09:39:24 [debug] 22#0: epoll timer: 100 client | 0.076 DEBUG [Client d7099bd3b3032229ba73b1accd7a2a6c04] pn=0 type=Short pri-path:000000000000200312a03f2c8e950b48c7adebc9 0.0.0.0:40520->193.167.100.100:443 IpTos(Cs0, NotEct) len 1200 client | -> RX Ack { largest_acknowledged: 0, ack_delay: 0, first_ack_range: 0, ack_ranges: [], ecn_count: None } client | -> RX Crypto { offset: 0, len: 572 } client | -> RX HandshakeDone client | -> RX NewConnectionId { sequence_number: 1, retire_prior: 0, connection_id: [0, 0, 0, 0, 0, 0, 32, 3, 92, 28, 63, 72, 200, 227, 175, 188, 145, 95, 99, 123], stateless_reset_token: [23, 114, 3, 96, 245, 103, 82, 227, 61, 220, 207, 15, 82, 129, 235, 233] } client | -> RX NewConnectionId { sequence_number: 2, retire_prior: 0, connection_id: [0, 0, 0, 0, 0, 0, 32, 3, 137, 19, 15, 21, 53, 11, 148, 237, 248, 26, 54, 243], stateless_reset_token: [182, 199, 197, 66, 68, 64, 116, 120, 104, 93, 11, 87, 123, 32, 180, 108] } client | -> RX NewConnectionId { sequence_number: 3, retire_prior: 0, connection_id: [0, 0, 0, 0, 0, 0, 32, 3, 25, 180, 185, 35, 250, 255, 28, 116, 30, 251, 87, 161], stateless_reset_token: [244, 166, 103, 124, 243, 26, 32, 1, 51, 68, 91, 167, 195, 246, 171, 25] } client | -> RX NewConnectionId { sequence_number: 4, retire_prior: 0, connection_id: [0, 0, 0, 0, 0, 0, 32, 3, 52, 65, 58, 70, 255, 217, 38, 209, 189, 32, 49, 1], stateless_reset_token: [133, 117, 205, 108, 206, 216, 59, 183, 87, 27, 127, 203, 187, 126, 223, 108] } client | -> RX NewConnectionId { sequence_number: 5, retire_prior: 0, connection_id: [0, 0, 0, 0, 0, 0, 32, 3, 233, 210, 91, 178, 1, 222, 168, 6, 145, 85, 77, 123], stateless_reset_token: [49, 241, 148, 192, 193, 191, 63, 42, 145, 167, 46, 37, 191, 96, 238, 6] } client | -> RX NewConnectionId { sequence_number: 6, retire_prior: 0, connection_id: [0, 0, 0, 0, 0, 0, 32, 3, 113, 43, 34, 190, 226, 40, 107, 86, 195, 172, 48, 96], stateless_reset_token: [127, 110, 34, 216, 225, 7, 60, 230, 239, 50, 22, 154, 155, 14, 36, 89] } client | -> RX NewConnectionId { sequence_number: 7, retire_prior: 0, connection_id: [0, 0, 0, 0, 0, 0, 32, 3, 219, 162, 108, 59, 131, 188, 208, 47, 200, 31, 21, 65], stateless_reset_token: [59, 129, 44, 72, 56, 76, 92, 157, 184, 250, 207, 5, 224, 158, 212, 179] } client | -> RX Stream { stream_id: 0, offset: 0, len: 315, fin: false } client | 0.076 DEBUG [Client d7099bd3b3032229ba73b1accd7a2a6c04] Rx ACK space=ap, ranges=[0..=0] client | 0.076 DEBUG [LossRecovery] ACK for ApplicationData - largest_acked=0 client | 0.076 DEBUG on_packets_acked this=0x56335427f630, limited=1, bytes_in_flight=85, cwnd=12520, state=SlowStart, new_acked=58 client | 0.076 DEBUG Read Ok(572) bytes client | 0.076 DEBUG [0x56335426bf20] Got resumption token [953]: 02000633fbb14c5a..068e1f55fefc36ed client | 0.076 DEBUG [0x56335426bf20] Got resumption token [953]: 02000633fbb14c5a..29d303bfbb77c8e1 client | 0.076 DEBUG [Agent 0x56335426bf20] state -> Complete(SecretAgentInfo { version: 772, cipher: 4865, group: 29, resumed: false, early_data: false, ech_accepted: false, alpn: Some("hq-interop"), signature_scheme: 1027 }) client | 0.076 DEBUG setting max_stream_data to 65536 client | 0.076 DEBUG [Client d7099bd3b3032229ba73b1accd7a2a6c04] State change from Connected -> Confirmed client | 0.076 DEBUG PMTUD started with probe size 1380 client | 0.076 DEBUG [Client d7099bd3b3032229ba73b1accd7a2a6c04] Drop packet number space hs client | 0.076 DEBUG [LossRecovery] Reset loss recovery state for Handshake client | 0.076 DEBUG [Client d7099bd3b3032229ba73b1accd7a2a6c04] No preferred address to migrate to client | 0.076 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 334, tv_nsec: 112977921 } client | 0.076 DEBUG [Client d7099bd3b3032229ba73b1accd7a2a6c04] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.076 DEBUG Building Short dcid Some(CID [20]: 000000000000200312a03f2c8e950b48c7adebc9) client | 0.076 DEBUG Sending PMTUD probe of size 1380, count 1 client | 0.076 DEBUG [Client d7099bd3b3032229ba73b1accd7a2a6c04] pn=1 type=Short pri-path:000000000000200312a03f2c8e950b48c7adebc9 0.0.0.0:40520->193.167.100.100:443 IpTos(Cs0, Ect0) len 1352 client | TX -> Ping client | TX -> Padding { len: 1313 } client | 0.076 DEBUG packet_sent this=0x56335427f630, pn=1, ps=1352 client | 0.076 DEBUG ECN probing: sent 5 probes client | 0.076 DEBUG [Client d7099bd3b3032229ba73b1accd7a2a6c04] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.076 DEBUG Building Short dcid Some(CID [20]: 000000000000200312a03f2c8e950b48c7adebc9) client | 0.076 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.076 DEBUG [Client d7099bd3b3032229ba73b1accd7a2a6c04] delay duration 19.646728ms client | 0.076 DEBUG Setting timeout of 19.646728ms client | 0.076 DEBUG stream 0 complete client | 0.076 DEBUG stream BiDi creatable client | 0.076 DEBUG stream UniDi creatable client | 0.076 WARN Unhandled event StateChange(Confirmed) client | 0.076 DEBUG [Client d7099bd3b3032229ba73b1accd7a2a6c04] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.076 DEBUG Building Short dcid Some(CID [20]: 000000000000200312a03f2c8e950b48c7adebc9) client | 0.076 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.076 DEBUG [Client d7099bd3b3032229ba73b1accd7a2a6c04] delay duration 19.613766ms client | 0.076 DEBUG Setting timeout of 19.613766ms client | 0.077 DEBUG [Client d7099bd3b3032229ba73b1accd7a2a6c04] pn=1 type=Short pri-path:000000000000200312a03f2c8e950b48c7adebc9 0.0.0.0:40520->193.167.100.100:443 IpTos(Cs0, NotEct) len 1200 client | -> RX Stream { stream_id: 0, offset: 315, len: 1176, fin: false } client | 0.077 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 334, tv_nsec: 93961475 } client | 0.077 DEBUG [Client d7099bd3b3032229ba73b1accd7a2a6c04] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.077 DEBUG Building Short dcid Some(CID [20]: 000000000000200312a03f2c8e950b48c7adebc9) client | 0.077 DEBUG [Client d7099bd3b3032229ba73b1accd7a2a6c04] pn=2 type=Short pri-path:000000000000200312a03f2c8e950b48c7adebc9 0.0.0.0:40520->193.167.100.100:443 IpTos(Cs0, Ect0) len 43 client | TX -> Ack { largest_acknowledged: 1, ack_delay: 3, first_ack_range: 1, ack_ranges: [], ecn_count: None } client | 0.077 DEBUG ECN probing: sent 6 probes client | 0.077 DEBUG [Client d7099bd3b3032229ba73b1accd7a2a6c04] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.077 DEBUG Building Short dcid Some(CID [20]: 000000000000200312a03f2c8e950b48c7adebc9) client | 0.077 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.077 DEBUG [Client d7099bd3b3032229ba73b1accd7a2a6c04] delay duration 111.011694ms client | 0.077 DEBUG Setting timeout of 111.011694ms client | 0.077 DEBUG [Client d7099bd3b3032229ba73b1accd7a2a6c04] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.077 DEBUG Building Short dcid Some(CID [20]: 000000000000200312a03f2c8e950b48c7adebc9) client | 0.077 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.077 DEBUG [Client d7099bd3b3032229ba73b1accd7a2a6c04] delay duration 110.984834ms client | 0.077 DEBUG Setting timeout of 110.984834ms client | 0.078 DEBUG [Client d7099bd3b3032229ba73b1accd7a2a6c04] pn=2 type=Short pri-path:000000000000200312a03f2c8e950b48c7adebc9 0.0.0.0:40520->193.167.100.100:443 IpTos(Cs0, NotEct) len 1200 client | -> RX Stream { stream_id: 0, offset: 1491, len: 1176, fin: false } client | 0.078 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 334, tv_nsec: 114928469 } client | 0.078 DEBUG [Client d7099bd3b3032229ba73b1accd7a2a6c04] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.078 DEBUG Building Short dcid Some(CID [20]: 000000000000200312a03f2c8e950b48c7adebc9) client | 0.078 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.078 DEBUG [Client d7099bd3b3032229ba73b1accd7a2a6c04] delay duration 19.974401ms client | 0.078 DEBUG Setting timeout of 19.974401ms client | 0.078 DEBUG [Client d7099bd3b3032229ba73b1accd7a2a6c04] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.078 DEBUG Building Short dcid Some(CID [20]: 000000000000200312a03f2c8e950b48c7adebc9) client | 0.078 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.078 DEBUG [Client d7099bd3b3032229ba73b1accd7a2a6c04] delay duration 19.950306ms client | 0.078 DEBUG Setting timeout of 19.950306ms client | 0.079 DEBUG [Client d7099bd3b3032229ba73b1accd7a2a6c04] pn=3 type=Short pri-path:000000000000200312a03f2c8e950b48c7adebc9 0.0.0.0:40520->193.167.100.100:443 IpTos(Cs0, NotEct) len 1200 client | -> RX Stream { stream_id: 0, offset: 2667, len: 1176, fin: false } client | 0.079 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 334, tv_nsec: 95917054 } client | 0.079 DEBUG [Client d7099bd3b3032229ba73b1accd7a2a6c04] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.079 DEBUG Building Short dcid Some(CID [20]: 000000000000200312a03f2c8e950b48c7adebc9) client | 0.079 DEBUG [Client d7099bd3b3032229ba73b1accd7a2a6c04] pn=3 type=Short pri-path:000000000000200312a03f2c8e950b48c7adebc9 0.0.0.0:40520->193.167.100.100:443 IpTos(Cs0, Ect0) len 43 client | TX -> Ack { largest_acknowledged: 3, ack_delay: 3, first_ack_range: 3, ack_ranges: [], ecn_count: None } client | 0.079 DEBUG ECN probing: sent 7 probes client | 0.079 DEBUG [Client d7099bd3b3032229ba73b1accd7a2a6c04] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.079 DEBUG Building Short dcid Some(CID [20]: 000000000000200312a03f2c8e950b48c7adebc9) client | 0.079 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.079 DEBUG [Client d7099bd3b3032229ba73b1accd7a2a6c04] delay duration 109.057779ms client | 0.079 DEBUG Setting timeout of 109.057779ms client | 0.079 DEBUG [Client d7099bd3b3032229ba73b1accd7a2a6c04] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.079 DEBUG Building Short dcid Some(CID [20]: 000000000000200312a03f2c8e950b48c7adebc9) client | 0.079 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.079 DEBUG [Client d7099bd3b3032229ba73b1accd7a2a6c04] delay duration 109.030027ms client | 0.079 DEBUG Setting timeout of 109.030027ms client | 0.080 DEBUG [Client d7099bd3b3032229ba73b1accd7a2a6c04] pn=4 type=Short pri-path:000000000000200312a03f2c8e950b48c7adebc9 0.0.0.0:40520->193.167.100.100:443 IpTos(Cs0, NotEct) len 1200 client | -> RX Stream { stream_id: 0, offset: 3843, len: 1176, fin: false } client | 0.080 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 334, tv_nsec: 116905829 } client | 0.080 DEBUG [Client d7099bd3b3032229ba73b1accd7a2a6c04] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.080 DEBUG Building Short dcid Some(CID [20]: 000000000000200312a03f2c8e950b48c7adebc9) client | 0.080 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.080 DEBUG [Client d7099bd3b3032229ba73b1accd7a2a6c04] delay duration 19.972258ms client | 0.080 DEBUG Setting timeout of 19.972258ms client | 0.080 DEBUG [Client d7099bd3b3032229ba73b1accd7a2a6c04] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.080 DEBUG Building Short dcid Some(CID [20]: 000000000000200312a03f2c8e950b48c7adebc9) client | 0.080 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.080 DEBUG [Client d7099bd3b3032229ba73b1accd7a2a6c04] delay duration 19.949896ms client | 0.080 DEBUG Setting timeout of 19.949896ms client | 0.080 DEBUG [Client d7099bd3b3032229ba73b1accd7a2a6c04] pn=5 type=Short pri-path:000000000000200312a03f2c8e950b48c7adebc9 0.0.0.0:40520->193.167.100.100:443 IpTos(Cs0, NotEct) len 130 client | -> RX Stream { stream_id: 0, offset: 5019, len: 101, fin: false } client | -> RX Stream { stream_id: 0, offset: 5120, len: 0, fin: true } client | 0.080 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 334, tv_nsec: 97100231 } client | 0.080 DEBUG [Client d7099bd3b3032229ba73b1accd7a2a6c04] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.080 DEBUG Building Short dcid Some(CID [20]: 000000000000200312a03f2c8e950b48c7adebc9) client | 0.080 DEBUG [Client d7099bd3b3032229ba73b1accd7a2a6c04] pn=4 type=Short pri-path:000000000000200312a03f2c8e950b48c7adebc9 0.0.0.0:40520->193.167.100.100:443 IpTos(Cs0, Ect0) len 43 client | TX -> Ack { largest_acknowledged: 5, ack_delay: 9, first_ack_range: 5, ack_ranges: [], ecn_count: None } client | 0.080 DEBUG ECN probing: sent 8 probes client | 0.080 DEBUG [Client d7099bd3b3032229ba73b1accd7a2a6c04] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.080 DEBUG Building Short dcid Some(CID [20]: 000000000000200312a03f2c8e950b48c7adebc9) client | 0.080 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.080 DEBUG [Client d7099bd3b3032229ba73b1accd7a2a6c04] delay duration 107.84133ms client | 0.080 DEBUG Setting timeout of 107.84133ms client | 0.080 DEBUG resumption token [1072]: 0000000125406f00..29d303bfbb77c8e1 client | 0.080 DEBUG [Client d7099bd3b3032229ba73b1accd7a2a6c04] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.080 DEBUG Building Short dcid Some(CID [20]: 000000000000200312a03f2c8e950b48c7adebc9) client | 0.080 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.080 DEBUG [Client d7099bd3b3032229ba73b1accd7a2a6c04] delay duration 107.779604ms client | 0.080 DEBUG Setting timeout of 107.779604ms client | 0.080 DEBUG [Client d7099bd3b3032229ba73b1accd7a2a6c04] State change from Confirmed -> Closing { error: Application(0), timeout: Instant { tv_sec: 334, tv_nsec: 432769276 } } client | 0.080 WARN Unhandled event StateChange(Closing { error: Application(0), timeout: Instant { tv_sec: 334, tv_nsec: 432769276 } }) client | 0.080 DEBUG [Client d7099bd3b3032229ba73b1accd7a2a6c04] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.080 DEBUG Building Short dcid Some(CID [20]: 000000000000200312a03f2c8e950b48c7adebc9) client | 0.080 DEBUG [Recvd-ap] immediate_ack at Instant { tv_sec: 334, tv_nsec: 97327206 } client | 0.080 DEBUG [Client d7099bd3b3032229ba73b1accd7a2a6c04] pn=5 type=Short pri-path:000000000000200312a03f2c8e950b48c7adebc9 0.0.0.0:40520->193.167.100.100:443 IpTos(Cs0, Ect0) len 54 client | TX -> Ack { largest_acknowledged: 5, ack_delay: 28, first_ack_range: 5, ack_ranges: [], ecn_count: None } client | TX -> ConnectionClose { error_code: Application(0), frame_type: 0, reason_phrase: "kthxbye!" } client | 0.080 DEBUG ECN probing: sent 9 probes client | 0.080 DEBUG Setting timeout of 335.37853ms server | 2025/04/30 09:39:24 [debug] 22#0: epoll: fd:6 ev:0001 d:00007FFBCCE83108 server | 2025/04/30 09:39:24 [debug] 22#0: quic recvmsg on 0.0.0.0:443, ready: 0 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic recvmsg: fd:6 n:1352 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic input handler server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic packet rx short flags:69 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic packet rx dcid len:20 000000000000200312a03f2c8e950b48c7adebc9 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic packet rx clearflags:60 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic packet rx number:1 len:1 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic packet len:1352 via sock seq:0 path seq:0 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic path seq:0 status tx:7381 rx:3999 valid:1 st:2 mtu:1200 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic frame rx app:1 PING server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic frame rx app:1 PADDING server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic ngx_quic_ack_packet pn:1 largest 0 fr:0 nranges:0 server | 2025/04/30 09:39:24 [debug] 22#0: *4 post event 000055882F5C0248 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic packet done rc:0 level:app decr:1 pn:1 perr:0 server | 2025/04/30 09:39:24 [debug] 22#0: *4 event timer: 6, old: 364041, new: 364109 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic state: read:29932 pto:983 server | 2025/04/30 09:39:24 [debug] 22#0: timer delta: 34 server | 2025/04/30 09:39:24 [debug] 22#0: posted event 000055882F5C0248 server | 2025/04/30 09:39:24 [debug] 22#0: *4 delete posted event 000055882F5C0248 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic push handler server | 2025/04/30 09:39:24 [debug] 22#0: *4 event timer add: 6: 25:334134 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic state: read:29932 push:25 pto:983 server | 2025/04/30 09:39:24 [debug] 22#0: worker cycle server | 2025/04/30 09:39:24 [debug] 22#0: epoll timer: 25 server | 2025/04/30 09:39:24 [debug] 22#0: epoll: fd:6 ev:0001 d:00007FFBCCE83108 server | 2025/04/30 09:39:24 [debug] 22#0: quic recvmsg on 0.0.0.0:443, ready: 0 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic recvmsg: fd:6 n:43 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic input handler server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic packet rx short flags:7d server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic packet rx dcid len:20 000000000000200312a03f2c8e950b48c7adebc9 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic packet rx clearflags:60 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic packet rx number:2 len:1 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic packet len:43 via sock seq:0 path seq:0 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic path seq:0 status tx:7381 rx:4042 valid:1 st:2 mtu:1200 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic frame rx app:2 ACK n:0 delay:3 1-0 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic ngx_quic_handle_ack_frame level:3 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic congestion slow start win:133454 ss:-1 if:4930 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic ngx_quic_drop_ack_ranges pn:0 largest:1 fr:1 nranges:0 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic stream id:0x0 ack len:315 fin:0 unacked:4805 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic congestion slow start win:134654 ss:-1 if:3730 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic stream id:0x0 ack len:1176 fin:0 unacked:3629 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic updated largest received ack:1 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic rtt sample latest:34 min:34 avg:34 var:17 server | 2025/04/30 09:39:24 [debug] 22#0: *4 event timer del: 6: 335092 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic lost timer pto:88 server | 2025/04/30 09:39:24 [debug] 22#0: *4 event timer add: 6: 88:334197 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic ngx_quic_ack_packet pn:2 largest 1 fr:0 nranges:0 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic packet done rc:0 level:app decr:1 pn:2 perr:0 server | 2025/04/30 09:39:24 [debug] 22#0: *4 event timer: 6, old: 364041, new: 364109 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic state: read:29932 push:25 pto:88 server | 2025/04/30 09:39:24 [debug] 22#0: timer delta: 0 server | 2025/04/30 09:39:24 [debug] 22#0: worker cycle server | 2025/04/30 09:39:24 [debug] 22#0: epoll timer: 25 server | 2025/04/30 09:39:24 [debug] 22#0: epoll: fd:6 ev:0001 d:00007FFBCCE83108 server | 2025/04/30 09:39:24 [debug] 22#0: quic recvmsg on 0.0.0.0:443, ready: 0 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic recvmsg: fd:6 n:43 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic input handler server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic packet rx short flags:72 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic packet rx dcid len:20 000000000000200312a03f2c8e950b48c7adebc9 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic packet rx clearflags:60 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic packet rx number:3 len:1 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic packet len:43 via sock seq:0 path seq:0 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic path seq:0 status tx:7381 rx:4085 valid:1 st:2 mtu:1200 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic frame rx app:3 ACK n:0 delay:3 3-0 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic ngx_quic_handle_ack_frame level:3 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic congestion slow start win:135854 ss:-1 if:2530 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic stream id:0x0 ack len:1176 fin:0 unacked:2453 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic congestion slow start win:137054 ss:-1 if:1330 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic stream id:0x0 ack len:1176 fin:0 unacked:1277 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic updated largest received ack:3 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic rtt sample latest:36 min:34 avg:34 var:13 server | 2025/04/30 09:39:24 [debug] 22#0: *4 event timer del: 6: 334197 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic lost timer pto:70 server | 2025/04/30 09:39:24 [debug] 22#0: *4 event timer add: 6: 70:334181 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic ngx_quic_ack_packet pn:3 largest 2 fr:1 nranges:0 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic packet done rc:0 level:app decr:1 pn:3 perr:0 server | 2025/04/30 09:39:24 [debug] 22#0: *4 event timer: 6, old: 364041, new: 364111 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic state: read:29930 push:23 pto:70 server | 2025/04/30 09:39:24 [debug] 22#0: timer delta: 2 server | 2025/04/30 09:39:24 [debug] 22#0: worker cycle server | 2025/04/30 09:39:24 [debug] 22#0: epoll timer: 23 server | 2025/04/30 09:39:24 [debug] 22#0: epoll: fd:6 ev:0001 d:00007FFBCCE83108 server | 2025/04/30 09:39:24 [debug] 22#0: quic recvmsg on 0.0.0.0:443, ready: 0 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic recvmsg: fd:6 n:43 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic input handler server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic packet rx short flags:58 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic packet rx dcid len:20 000000000000200312a03f2c8e950b48c7adebc9 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic packet rx clearflags:40 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic packet rx number:4 len:1 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic packet len:43 via sock seq:0 path seq:0 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic path seq:0 status tx:7381 rx:4128 valid:1 st:2 mtu:1200 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic frame rx app:4 ACK n:0 delay:9 5-0 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic ngx_quic_handle_ack_frame level:3 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic congestion slow start win:138254 ss:-1 if:130 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic stream id:0x0 ack len:1176 fin:0 unacked:101 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic congestion slow start win:138384 ss:-1 if:0 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic stream id:0x0 ack len:101 fin:0 unacked:0 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic stream id:0x0 ack len:0 fin:1 unacked:0 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic stream id:0x0 close server | 2025/04/30 09:39:24 [debug] 22#0: *4 reusable connection: 1 server | 2025/04/30 09:39:24 [debug] 22#0: *4 post event 000055882F5C0248 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic updated largest received ack:5 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic rtt sample latest:37 min:34 avg:34 var:10 server | 2025/04/30 09:39:24 [debug] 22#0: *4 event timer del: 6: 334181 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic lost timer unset server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic ngx_quic_ack_packet pn:4 largest 3 fr:2 nranges:0 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic packet done rc:0 level:app decr:1 pn:4 perr:0 server | 2025/04/30 09:39:24 [debug] 22#0: *4 event timer: 6, old: 364041, new: 364112 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic state: read:29929 push:22 server | 2025/04/30 09:39:24 [debug] 22#0: timer delta: 1 server | 2025/04/30 09:39:24 [debug] 22#0: posted event 000055882F5C0248 server | 2025/04/30 09:39:24 [debug] 22#0: *4 delete posted event 000055882F5C0248 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic push handler server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic output app packet max:1200 min:0 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic frame tx app:6 ACK n:0 delay:0 4-1 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic frame tx app:6 MAX_STREAMS limit:129 bidi:1 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic packet tx app bytes:8 need_ack:1 number:6 encoded nl:1 trunc:0x6 server | 2025/04/30 09:39:24 [debug] 22#0: *4 sendmsg: 26 of 26 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic congestion send if:0 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic congestion send if:0 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic congestion send if:26 server | 2025/04/30 09:39:24 [debug] 22#0: *4 event timer: 6, old: 364041, new: 364112 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic lost timer pto:94 server | 2025/04/30 09:39:24 [debug] 22#0: *4 event timer add: 6: 94:334206 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic state: send:29929 push:22 pto:94 server | 2025/04/30 09:39:24 [debug] 22#0: worker cycle server | 2025/04/30 09:39:24 [debug] 22#0: epoll timer: 22 server | 2025/04/30 09:39:24 [debug] 22#0: epoll: fd:6 ev:0001 d:00007FFBCCE83108 server | 2025/04/30 09:39:24 [debug] 22#0: quic recvmsg on 0.0.0.0:443, ready: 0 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic recvmsg: fd:6 n:54 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic input handler server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic packet rx short flags:69 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic packet rx dcid len:20 000000000000200312a03f2c8e950b48c7adebc9 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic packet rx clearflags:60 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic packet rx number:5 len:1 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic packet len:54 via sock seq:0 path seq:0 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic path seq:0 status tx:7407 rx:4182 valid:1 st:2 mtu:1200 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic frame rx app:5 ACK n:0 delay:28 5-0 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic ngx_quic_handle_ack_frame level:3 server | 2025/04/30 09:39:24 [debug] 22#0: *4 event timer del: 6: 334206 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic lost timer pto:94 server | 2025/04/30 09:39:24 [debug] 22#0: *4 event timer add: 6: 94:334206 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic frame rx app:5 CONNECTION_CLOSE_APP err:0 kthxbye! server | 2025/04/30 09:39:24 [debug] 22#0: *4 post event 000055882F5C0308 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic ngx_quic_ack_packet pn:5 largest 4 fr:3 nranges:0 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic packet done rc:0 level:app decr:1 pn:5 perr:0 server | 2025/04/30 09:39:24 [debug] 22#0: *4 event timer: 6, old: 364041, new: 364112 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic state: draining read:29929 push:22 pto:94 server | 2025/04/30 09:39:24 [debug] 22#0: timer delta: 0 server | 2025/04/30 09:39:24 [debug] 22#0: posted event 000055882F5C0308 server | 2025/04/30 09:39:24 [debug] 22#0: *4 delete posted event 000055882F5C0308 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic close handler server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic close initiated rc:0 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic close immediate term:0 drain:1 error:1 "" server | 2025/04/30 09:39:24 [debug] 22#0: *4 event timer add: 6: 282:334394 server | 2025/04/30 09:39:24 [debug] 22#0: *4 event timer del: 6: 334134 server | 2025/04/30 09:39:24 [debug] 22#0: *4 event timer del: 6: 334206 server | 2025/04/30 09:39:24 [debug] 22#0: *4 event timer del: 6: 334175 server | 2025/04/30 09:39:24 [debug] 22#0: worker cycle server | 2025/04/30 09:39:24 [debug] 22#0: epoll timer: 282 client | 0.111 DEBUG [Client d7099bd3b3032229ba73b1accd7a2a6c04] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.111 DEBUG Building Short dcid Some(CID [20]: 000000000000200312a03f2c8e950b48c7adebc9) client | 0.111 DEBUG [Recvd-ap] immediate_ack at Instant { tv_sec: 334, tv_nsec: 127801876 } client | 0.111 DEBUG [Client d7099bd3b3032229ba73b1accd7a2a6c04] pn=6 type=Short pri-path:000000000000200312a03f2c8e950b48c7adebc9 0.0.0.0:40520->193.167.100.100:443 IpTos(Cs0, Ect0) len 55 client | TX -> Ack { largest_acknowledged: 5, ack_delay: 3837, first_ack_range: 5, ack_ranges: [], ecn_count: None } client | TX -> ConnectionClose { error_code: Application(0), frame_type: 0, reason_phrase: "kthxbye!" } client | 0.111 DEBUG ECN probing: sent 10 probes client | 0.111 DEBUG ECN probing concluded with 10 probes sent client | 0.111 DEBUG Setting timeout of 304.891818ms client | 0.111 DEBUG Setting timeout of 304.881218ms server | 2025/04/30 09:39:24 [debug] 22#0: epoll: fd:6 ev:0001 d:00007FFBCCE83108 server | 2025/04/30 09:39:24 [debug] 22#0: quic recvmsg on 0.0.0.0:443, ready: 0 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic recvmsg: fd:6 n:55 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic input handler server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic packet rx short flags:56 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic packet rx dcid len:20 000000000000200312a03f2c8e950b48c7adebc9 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic packet rx clearflags:40 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic packet rx number:6 len:1 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic packet len:55 via sock seq:0 path seq:0 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic path seq:0 status tx:7407 rx:4237 valid:1 st:2 mtu:1200 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic packet done rc:0 level:app decr:1 pn:6 perr:0 server | 2025/04/30 09:39:24 [debug] 22#0: *4 event timer: 6, old: 364041, new: 364143 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic state: error:0 "connection is closing, packet discarded" closing draining read:29898 close:251 server | 2025/04/30 09:39:24 [debug] 22#0: timer delta: 31 server | 2025/04/30 09:39:24 [debug] 22#0: worker cycle server | 2025/04/30 09:39:24 [debug] 22#0: epoll timer: 251 server | 2025/04/30 09:39:24 [debug] 22#0: timer delta: 251 server | 2025/04/30 09:39:24 [debug] 22#0: *4 event timer del: 6: 334394 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic close handler server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic close resumed rc:0 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic socket seq:0 closed nsock:7 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic socket seq:1 closed nsock:6 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic socket seq:2 closed nsock:5 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic socket seq:3 closed nsock:4 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic socket seq:4 closed nsock:3 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic socket seq:5 closed nsock:2 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic socket seq:6 closed nsock:1 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic socket seq:7 closed nsock:0 server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic close completed server | 2025/04/30 09:39:24 [debug] 22#0: *4 quic ngx_quic_send_alert() level:app alert:0 server | 2025/04/30 09:39:24 [debug] 22#0: *4 SSL_shutdown: 1 server | 2025/04/30 09:39:24 [debug] 22#0: *4 event timer del: 6: 364041 server | 2025/04/30 09:39:24 [debug] 22#0: *4 reusable connection: 0 server | 2025/04/30 09:39:24 [debug] 22#0: *4 run cleanup: 000055882F5B4AD8 server | 2025/04/30 09:39:24 [debug] 22#0: *4 event timer del: -1: 409075 server | 2025/04/30 09:39:24 [debug] 22#0: *4 free: 000055882F613650 server | 2025/04/30 09:39:24 [debug] 22#0: *4 free: 000055882F612640 server | 2025/04/30 09:39:24 [debug] 22#0: *4 free: 000055882F60A8B0 server | 2025/04/30 09:39:24 [debug] 22#0: *4 free: 000055882F5B56B0 server | 2025/04/30 09:39:24 [debug] 22#0: *4 free: 000055882F5C05E0 server | 2025/04/30 09:39:24 [debug] 22#0: *4 free: 000055882F5BFC40 server | 2025/04/30 09:39:24 [debug] 22#0: *4 free: 000055882F5D87F0 server | 2025/04/30 09:39:24 [debug] 22#0: *4 free: 000055882F5D6B30, unused: 1 server | 2025/04/30 09:39:24 [debug] 22#0: *4 free: 000055882F5D6D40, unused: 8 server | 2025/04/30 09:39:24 [debug] 22#0: *4 free: 000055882F5C11E0, unused: 56 server | 2025/04/30 09:39:24 [debug] 22#0: *4 free: 000055882F5C13F0, unused: 9 server | 2025/04/30 09:39:24 [debug] 22#0: *4 free: 000055882F5B4F80, unused: 96 server | 2025/04/30 09:39:24 [debug] 22#0: *4 free: 000055882F5B7A10, unused: 48 server | 2025/04/30 09:39:24 [debug] 22#0: *4 free: 000055882F5B4920, unused: 48 server | 2025/04/30 09:39:24 [debug] 22#0: *4 free: 000055882F5B4B30, unused: 8 server | 2025/04/30 09:39:24 [debug] 22#0: *4 free: 000055882F5B4D40, unused: 40 server | 2025/04/30 09:39:24 [debug] 22#0: *4 free: 000055882F5B4210, unused: 40 server | 2025/04/30 09:39:24 [debug] 22#0: *4 free: 000055882F5B4420, unused: 56 server | 2025/04/30 09:39:24 [debug] 22#0: *4 free: 000055882F5B4630, unused: 56 server | 2025/04/30 09:39:24 [debug] 22#0: *4 free: 000055882F60BDF0, unused: 32 server | 2025/04/30 09:39:24 [debug] 22#0: *4 free: 000055882F60C000, unused: 0 server | 2025/04/30 09:39:24 [debug] 22#0: *4 free: 000055882F610220, unused: 48 server | 2025/04/30 09:39:24 [debug] 22#0: *4 free: 000055882F610430, unused: 32 server | 2025/04/30 09:39:24 [debug] 22#0: *4 free: 000055882F610640, unused: 32 server | 2025/04/30 09:39:24 [debug] 22#0: worker cycle server | 2025/04/30 09:39:24 [debug] 22#0: epoll timer: -1 client | 0.417 DEBUG [Client d7099bd3b3032229ba73b1accd7a2a6c04] State change from Closing { error: Application(0), timeout: Instant { tv_sec: 334, tv_nsec: 432769276 } } -> Closed(Application(0)) client | 0.417 INFO Closing timer expired client | 0.417 DEBUG Output::None client | 0.417 WARN Unhandled event StateChange(Closed(Application(0))) client | 0.417 DEBUG Timer fired while closed client | 0.417 DEBUG Output::None client | 0.417 DEBUG [CryptoStates] Creating initial cipher state v=Version1, role=Client dcid=0233a3281fbbec85 client | 0.417 DEBUG Making Write Initial CryptoDxState, v=Version1 cipher=4865 client | 0.417 DEBUG Making Read Initial CryptoDxState, v=Version1 cipher=4865 client | 0.418 DEBUG Outbound interface eth0 for destination 193.167.100.100 has MTU 1500 client | 0.418 DEBUG [unv-path 0.0.0.0:40520->193.167.100.100:443] Make permanent client | 0.418 DEBUG [unv-path:0233a3281fbbec85 0.0.0.0:40520->193.167.100.100:443] set as primary path client | 0.418 DEBUG [pri-unv-path:0233a3281fbbec85 0.0.0.0:40520->193.167.100.100:443] Path validated Instant { tv_sec: 334, tv_nsec: 434550210 } client | 0.418 INFO [Client 0233a3281fbbec85] resumption token [1072]: 0000000125406f00..29d303bfbb77c8e1 client | 0.418 DEBUG Overwrite initial version Version1 ==> Version1 client | 0.418 DEBUG Overwrite initial version Version1 ==> Version1 client | 0.418 DEBUG [Client 0233a3281fbbec85] client_start client | 0.418 DEBUG Writing transport parameters, msg=1 client | 0.418 DEBUG Write secret available for ZeroRtt: SymKey [32]: 981b014f08f69ae1603d839ad9cc09f87b6cad3ac0a2c478c0abf1090e125f68 client | 0.418 DEBUG [Agent 0x5633542af980] state -> InProgress client | 0.418 DEBUG [Client 0233a3281fbbec85] State change from Init -> WaitInitial client | 0.418 DEBUG Making Write ZeroRtt CryptoDxState, v=Version1 cipher=4865 client | 0.418 DEBUG [Client 0233a3281fbbec85] Enabled 0-RTT client | 0.418 DEBUG stream BiDi creatable client | 0.418 INFO Created stream 0 for https://server4/inicrohhls client | 0.418 INFO Saving https://server4/inicrohhls to "/downloads/inicrohhls" client | 0.419 DEBUG stream UniDi creatable client | 0.419 DEBUG StateChange(WaitInitial) client | 0.419 DEBUG stream 0 writable client | 0.419 DEBUG [Client 0233a3281fbbec85] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.419 DEBUG Building Initial dcid Some(CID [8]: 0233a3281fbbec85) scid Some(CID [0]: ) client | 0.419 DEBUG CRYPTO for in offset=0, len=1213 client | 0.419 DEBUG [Client 0233a3281fbbec85] pn=0 type=Initial pri-path:0233a3281fbbec85 0.0.0.0:40520->193.167.100.100:443 IpTos(Cs0, Ect0) len 1252 client | TX -> Crypto { offset: 0, len: 1213 } client | 0.419 DEBUG packet_sent this=0x56335427f630, pn=0, ps=1252 client | 0.419 DEBUG ECN probing: sent 1 probes client | 0.419 DEBUG [Client 0233a3281fbbec85] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.419 DEBUG Building Initial dcid Some(CID [8]: 0233a3281fbbec85) scid Some(CID [0]: ) client | 0.419 DEBUG CRYPTO for in offset=1213, len=633 client | 0.419 DEBUG [Client 0233a3281fbbec85] pn=1 type=Initial pri-path:0233a3281fbbec85 0.0.0.0:40520->193.167.100.100:443 IpTos(Cs0, Ect0) len 673 client | TX -> Crypto { offset: 1213, len: 633 } client | 0.419 DEBUG Building ZeroRtt dcid Some(CID [8]: 0233a3281fbbec85) scid Some(CID [0]: ) client | 0.419 DEBUG [Client 0233a3281fbbec85] pn=0 type=ZeroRtt pri-path:0233a3281fbbec85 0.0.0.0:40520->193.167.100.100:443 IpTos(Cs0, Ect0) len 727 client | TX -> Stream { stream_id: 0, offset: 0, len: 17, fin: true } client | 0.419 DEBUG packet_sent this=0x56335427f630, pn=0, ps=54 client | 0.419 DEBUG [Client 0233a3281fbbec85] pad Initial from 727 to PLPMTU 1252 client | 0.419 DEBUG packet_sent this=0x56335427f630, pn=1, ps=1198 client | 0.419 DEBUG ECN probing: sent 2 probes client | 0.419 DEBUG [Client 0233a3281fbbec85] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.419 DEBUG Building Initial dcid Some(CID [8]: 0233a3281fbbec85) scid Some(CID [0]: ) client | 0.419 DEBUG Building ZeroRtt dcid Some(CID [8]: 0233a3281fbbec85) scid Some(CID [0]: ) client | 0.419 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.419 DEBUG [Client 0233a3281fbbec85] delay duration 110.924378ms client | 0.419 DEBUG Setting timeout of 110.924378ms server | 2025/04/30 09:39:25 [debug] 22#0: epoll: fd:6 ev:0001 d:00007FFBCCE83108 server | 2025/04/30 09:39:25 [debug] 22#0: quic recvmsg on 0.0.0.0:443, ready: 0 server | 2025/04/30 09:39:25 [debug] 22#0: posix_memalign: 000055882F5B4920:512 @16 server | 2025/04/30 09:39:25 [debug] 22#0: malloc: 000055882F5D87F0:1252 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic recvmsg: 193.167.0.100:40520 fd:6 n:1252 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic run server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic packet rx long flags:cf version:1 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic packet rx init len:1234 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic packet rx dcid len:8 0233a3281fbbec85 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic packet rx scid len:0 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic address validation token len:0 server | 2025/04/30 09:39:25 [debug] 22#0: *6 malloc: 000055882F5BFC40:2448 server | 2025/04/30 09:39:25 [debug] 22#0: *6 malloc: 000055882F5C05E0:1528 server | 2025/04/30 09:39:25 [debug] 22#0: *6 posix_memalign: 000055882F5B7A10:512 @16 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic ngx_quic_set_initial_secret server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic socket seq:0 listening at sid:0000000000002003de2ddac5b5d2859d37d852d7 nsock:1 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic cid seq:0 received id:0::00000000000000000000000000000000 server | 2025/04/30 09:39:25 [debug] 22#0: *6 posix_memalign: 000055882F5B4F80:512 @16 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic path seq:0 created addr:193.167.0.100:40520 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic path seq:0 set active tx:0 rx:0 valid:0 st:0 mtu:1200 server | 2025/04/30 09:39:25 [debug] 22#0: *6 posix_memalign: 000055882F5C13F0:512 @16 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic socket seq:-1 listening at sid:0233a3281fbbec85 nsock:2 server | 2025/04/30 09:39:25 [debug] 22#0: *6 reusable connection: 1 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic connection created server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic packet rx clearflags:c0 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic packet rx number:0 len:1 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic packet len:1252 via sock seq:0 path seq:0 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic path seq:0 status tx:0 rx:1252 valid:0 st:0 mtu:1200 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic stateless reset token 32656cbb5ea300a6ad2dbf5a64418587 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic frame rx init:0 CRYPTO len:1213 off:0 server | 2025/04/30 09:39:25 [debug] 22#0: *6 SSL_do_handshake: -1 server | 2025/04/30 09:39:25 [debug] 22#0: *6 SSL_get_error: 2 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic ngx_quic_ack_packet pn:0 largest -1 fr:0 nranges:0 server | 2025/04/30 09:39:25 [debug] 22#0: *6 post event 000055882F5C0248 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic packet done rc:0 level:init decr:1 pn:0 perr:0 server | 2025/04/30 09:39:25 [debug] 22#0: *6 event timer add: 6: 75000:409452 server | 2025/04/30 09:39:25 [debug] 22#0: *6 event timer add: 6: 60000:394452 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic state: read:75000 close:60000 server | 2025/04/30 09:39:25 [debug] 22#0: timer delta: 58 server | 2025/04/30 09:39:25 [debug] 22#0: posted event 000055882F5C0248 server | 2025/04/30 09:39:25 [debug] 22#0: *6 delete posted event 000055882F5C0248 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic push handler server | 2025/04/30 09:39:25 [debug] 22#0: *6 posix_memalign: 000055882F5C11E0:512 @16 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic output init packet max:1200 min:0 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic frame tx init:0 ACK n:0 delay:0 0 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic packet tx init bytes:5 need_ack:0 number:0 encoded nl:1 trunc:0x0 server | 2025/04/30 09:39:25 [debug] 22#0: *6 sendmsg: 51 of 51 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic congestion send if:0 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic congestion send if:0 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic congestion send if:0 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic state: read:75000 close:60000 server | 2025/04/30 09:39:25 [debug] 22#0: worker cycle server | 2025/04/30 09:39:25 [debug] 22#0: epoll timer: 60000 server | 2025/04/30 09:39:25 [debug] 22#0: epoll: fd:6 ev:0001 d:00007FFBCCE83108 server | 2025/04/30 09:39:25 [debug] 22#0: quic recvmsg on 0.0.0.0:443, ready: 0 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic recvmsg: fd:6 n:1252 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic input handler server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic packet rx long flags:cb version:1 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic packet rx init len:655 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic packet rx dcid len:8 0233a3281fbbec85 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic packet rx scid len:0 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic address validation token len:0 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic packet rx clearflags:c0 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic packet rx number:1 len:1 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic packet len:1252 via sock seq:-1 path seq:0 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic path seq:0 status tx:51 rx:2504 valid:0 st:0 mtu:1200 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic frame rx init:1 CRYPTO len:633 off:1213 server | 2025/04/30 09:39:25 [debug] 22#0: *6 SSL server name: "server4" server | 2025/04/30 09:39:25 [debug] 22#0: *6 SSL ALPN supported by client: hq-interop server | 2025/04/30 09:39:25 [debug] 22#0: *6 SSL ALPN supported by client: ZZ server | 2025/04/30 09:39:25 [debug] 22#0: *6 SSL ALPN selected: hq-interop server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic ngx_quic_add_handshake_data server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic SSL_get_peer_quic_transport_params(): params_len:79 server | 2025/04/30 09:39:25 [info] 22#0: *6 quic unknown transport param id:0x11, skipped while handling frames, client: 193.167.0.100, server: 0.0.0.0:443 server | 2025/04/30 09:39:25 [info] 22#0: *6 quic unknown transport param id:0x2ab2, skipped while handling frames, client: 193.167.0.100, server: 0.0.0.0:443 server | 2025/04/30 09:39:25 [info] 22#0: *6 quic reserved transport param id:0xff02de1a, skipped while handling frames, client: 193.167.0.100, server: 0.0.0.0:443 server | 2025/04/30 09:39:25 [info] 22#0: *6 quic unknown transport param id:0x20, skipped while handling frames, client: 193.167.0.100, server: 0.0.0.0:443 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic transport parameters parsed ok server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic tp disable active migration: 0 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic tp idle_timeout:30000 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic tp max_udp_payload_size:65527 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic tp max_data:4611686018427387903 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic tp max_stream_data_bidi_local:1048576 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic tp max_stream_data_bidi_remote:1048576 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic tp max_stream_data_uni:1048576 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic tp initial_max_streams_bidi:16 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic tp initial_max_streams_uni:16 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic tp ack_delay_exponent:3 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic tp max_ack_delay:20 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic tp active_connection_id_limit:8 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic tp initial source_connection_id len:0 server | 2025/04/30 09:39:25 [debug] 22#0: *6 malloc: 000055882F5B56B0:4096 server | 2025/04/30 09:39:25 [debug] 22#0: *6 post event 000055882F5C0248 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic ngx_quic_set_write_secret() level:2 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic ngx_quic_add_handshake_data server | 2025/04/30 09:39:25 [debug] 22#0: *6 malloc: 000055882F60BDF0:4096 server | 2025/04/30 09:39:25 [debug] 22#0: *6 update posted event 000055882F5C0248 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic ngx_quic_set_write_secret() level:3 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic ngx_quic_add_handshake_data server | 2025/04/30 09:39:25 [debug] 22#0: *6 malloc: 000055882F60CE00:4096 server | 2025/04/30 09:39:25 [debug] 22#0: *6 posix_memalign: 000055882F5D6D40:512 @16 server | 2025/04/30 09:39:25 [debug] 22#0: *6 update posted event 000055882F5C0248 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic ngx_quic_flush_flight() server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic ngx_quic_set_read_secret() level:1 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic ngx_quic_set_read_secret() level:2 server | 2025/04/30 09:39:25 [debug] 22#0: *6 SSL_do_handshake: 1 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic init streams server | 2025/04/30 09:39:25 [debug] 22#0: *6 http3 init server | 2025/04/30 09:39:25 [debug] 22#0: *6 http3 init session server | 2025/04/30 09:39:25 [debug] 22#0: *6 posix_memalign: 000055882F5D6B30:512 @16 server | 2025/04/30 09:39:25 [debug] 22#0: *6 add cleanup: 000055882F5D6E40 server | 2025/04/30 09:39:25 [debug] 22#0: *6 event timer add: 6: 75000:409453 server | 2025/04/30 09:39:25 [debug] 22#0: *6 event timer del: 6: 394452 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic ngx_quic_ack_packet pn:1 largest 0 fr:0 nranges:0 server | 2025/04/30 09:39:25 [debug] 22#0: *6 update posted event 000055882F5C0248 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic packet done rc:0 level:init decr:1 pn:1 perr:0 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic packet rx long flags:dc version:1 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic packet rx early len:37 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic packet rx dcid len:8 0233a3281fbbec85 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic packet rx scid len:0 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic packet rx clearflags:d0 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic packet rx number:0 len:1 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic frame rx early:0 STREAM id:0x0 len:17 fin:1 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic stream id:0x0 is missing server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic stream id:0x0 create server | 2025/04/30 09:39:25 [debug] 22#0: *6 posix_memalign: 000055882F60B260:512 @16 server | 2025/04/30 09:39:25 [debug] 22#0: *6 posix_memalign: 000055882F60DE10:16384 @16 server | 2025/04/30 09:39:25 [debug] 22#0: *6 reusable connection: 0 server | 2025/04/30 09:39:25 [debug] 22#0: *7 add cleanup: 000055882F60DED0 server | 2025/04/30 09:39:25 [debug] 22#0: *7 post event 000055882F5DAAD0 server | 2025/04/30 09:39:25 [debug] 22#0: *6 delete posted event 000055882F5C0248 server | 2025/04/30 09:39:25 [debug] 22#0: *6 post event 000055882F5C0248 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic stream id:0x0 flow control msd:17/65536 md:17/8585216 server | 2025/04/30 09:39:25 [debug] 22#0: *6 malloc: 000055882F611E20:4096 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic ngx_quic_ack_packet pn:0 largest -1 fr:0 nranges:0 server | 2025/04/30 09:39:25 [debug] 22#0: *6 update posted event 000055882F5C0248 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic packet done rc:0 level:early decr:1 pn:0 perr:0 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic packet rx short flags:0 server | 2025/04/30 09:39:25 [info] 22#0: *6 quic fixed bit is not set while parsing quic packet, client: 193.167.0.100, server: 0.0.0.0:443 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic packet done rc:-5 parse failed server | 2025/04/30 09:39:25 [debug] 22#0: *6 event timer del: 6: 409452 server | 2025/04/30 09:39:25 [debug] 22#0: *6 event timer add: 6: 30000:364453 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic state: read:30000 server | 2025/04/30 09:39:25 [debug] 22#0: timer delta: 1 server | 2025/04/30 09:39:25 [debug] 22#0: posted event 000055882F5DAAD0 server | 2025/04/30 09:39:25 [debug] 22#0: *7 delete posted event 000055882F5DAAD0 server | 2025/04/30 09:39:25 [debug] 22#0: *7 quic init stream server | 2025/04/30 09:39:25 [debug] 22#0: *7 http3 init request stream server | 2025/04/30 09:39:25 [debug] 22#0: *7 add cleanup: 000055882F60DF40 server | 2025/04/30 09:39:25 [debug] 22#0: *6 event timer del: 6: 409453 server | 2025/04/30 09:39:25 [debug] 22#0: *7 http wait request handler server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic stream id:0x0 recv buf:1024 server | 2025/04/30 09:39:25 [debug] 22#0: *7 quic stream id:0x0 recv len:17 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic stream id:0x0 flow update 17 server | 2025/04/30 09:39:25 [debug] 22#0: *7 reusable connection: 0 server | 2025/04/30 09:39:25 [debug] 22#0: *7 posix_memalign: 000055882F612E30:4096 @16 server | 2025/04/30 09:39:25 [debug] 22#0: *7 http process request line server | 2025/04/30 09:39:25 [debug] 22#0: *7 http request line: "GET /inicrohhls" server | 2025/04/30 09:39:25 [debug] 22#0: *7 http uri: "/inicrohhls" server | 2025/04/30 09:39:25 [debug] 22#0: *7 http args: "" server | 2025/04/30 09:39:25 [debug] 22#0: *7 http exten: "" server | 2025/04/30 09:39:25 [debug] 22#0: *7 rewrite phase: 0 server | 2025/04/30 09:39:25 [debug] 22#0: *7 test location: "/" server | 2025/04/30 09:39:25 [debug] 22#0: *7 using configuration "/" server | 2025/04/30 09:39:25 [debug] 22#0: *7 http cl:-1 max:1048576 server | 2025/04/30 09:39:25 [debug] 22#0: *7 rewrite phase: 2 server | 2025/04/30 09:39:25 [debug] 22#0: *7 post rewrite phase: 3 server | 2025/04/30 09:39:25 [debug] 22#0: *7 generic phase: 4 server | 2025/04/30 09:39:25 [debug] 22#0: *7 generic phase: 5 server | 2025/04/30 09:39:25 [debug] 22#0: *7 access phase: 6 server | 2025/04/30 09:39:25 [debug] 22#0: *7 access phase: 7 server | 2025/04/30 09:39:25 [debug] 22#0: *7 post access phase: 8 server | 2025/04/30 09:39:25 [debug] 22#0: *7 generic phase: 9 server | 2025/04/30 09:39:25 [debug] 22#0: *7 generic phase: 10 server | 2025/04/30 09:39:25 [debug] 22#0: *7 content phase: 11 server | 2025/04/30 09:39:25 [debug] 22#0: *7 content phase: 12 server | 2025/04/30 09:39:25 [debug] 22#0: *7 content phase: 13 server | 2025/04/30 09:39:25 [debug] 22#0: *7 http filename: "/www/inicrohhls" server | 2025/04/30 09:39:25 [debug] 22#0: *7 add cleanup: 000055882F613B68 server | 2025/04/30 09:39:25 [debug] 22#0: *7 http static fd: 3 server | 2025/04/30 09:39:25 [debug] 22#0: *7 http set discard body server | 2025/04/30 09:39:25 [debug] 22#0: *7 http output filter "/inicrohhls?" server | 2025/04/30 09:39:25 [debug] 22#0: *7 http copy filter: "/inicrohhls?" server | 2025/04/30 09:39:25 [debug] 22#0: *7 malloc: 000055882F613E40:10240 server | 2025/04/30 09:39:25 [debug] 22#0: *7 read: 3, 000055882F613E40, 10240, 0 server | 2025/04/30 09:39:25 [debug] 22#0: *7 http postpone filter "/inicrohhls?" 000055882F613D80 server | 2025/04/30 09:39:25 [debug] 22#0: *7 write new buf t:1 f:0 000055882F613E40, pos 000055882F613E40, size: 10240 file: 0, size: 0 server | 2025/04/30 09:39:25 [debug] 22#0: *7 http write filter: l:1 f:0 s:10240 server | 2025/04/30 09:39:25 [debug] 22#0: *7 http write filter limit 2097152 server | 2025/04/30 09:39:25 [debug] 22#0: *6 malloc: 000055882F616650:4096 server | 2025/04/30 09:39:25 [debug] 22#0: *6 malloc: 000055882F617660:4096 server | 2025/04/30 09:39:25 [debug] 22#0: *6 malloc: 000055882F618670:4096 server | 2025/04/30 09:39:25 [debug] 22#0: *7 quic send_chain sent:10240 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic stream id:0x0 flush limit:1048576 server | 2025/04/30 09:39:25 [debug] 22#0: *6 posix_memalign: 000055882F60B470:512 @16 server | 2025/04/30 09:39:25 [debug] 22#0: *6 update posted event 000055882F5C0248 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic stream id:0x0 flush len:10240 last:0 server | 2025/04/30 09:39:25 [debug] 22#0: *7 http write filter 0000000000000000 server | 2025/04/30 09:39:25 [debug] 22#0: *7 http copy filter: 0 "/inicrohhls?" server | 2025/04/30 09:39:25 [debug] 22#0: *7 http finalize request: 0, "/inicrohhls?" a:1, c:1 server | 2025/04/30 09:39:25 [debug] 22#0: *7 http request count:1 blk:0 server | 2025/04/30 09:39:25 [debug] 22#0: *7 http close request server | 2025/04/30 09:39:25 [debug] 22#0: *7 http log handler server | 2025/04/30 09:39:25 [debug] 22#0: *7 posix_memalign: 000055882F619680:4096 @16 server | 193.167.0.100 - - [30/Apr/2025:09:39:25 +0000] "GET /inicrohhls" 200 10240 "-" "-" server | 2025/04/30 09:39:25 [debug] 22#0: *7 run cleanup: 000055882F613B68 server | 2025/04/30 09:39:25 [debug] 22#0: *7 file cleanup: fd:3 server | 2025/04/30 09:39:25 [debug] 22#0: *7 free: 000055882F613E40 server | 2025/04/30 09:39:25 [debug] 22#0: *7 free: 000055882F612E30, unused: 48 server | 2025/04/30 09:39:25 [debug] 22#0: *7 free: 000055882F619680, unused: 3949 server | 2025/04/30 09:39:25 [debug] 22#0: *7 close http connection: 6 server | 2025/04/30 09:39:25 [debug] 22#0: *7 reusable connection: 0 server | 2025/04/30 09:39:25 [debug] 22#0: *7 run cleanup: 000055882F60DF40 server | 2025/04/30 09:39:25 [debug] 22#0: *6 event timer add: 6: 75000:409453 server | 2025/04/30 09:39:25 [debug] 22#0: *7 run cleanup: 000055882F60DED0 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic stream id:0x0 cleanup server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic stream id:0x0 send shutdown server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic stream id:0x0 flush limit:1038336 server | 2025/04/30 09:39:25 [debug] 22#0: *6 update posted event 000055882F5C0248 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic stream id:0x0 flush len:0 last:1 server | 2025/04/30 09:39:25 [debug] 22#0: *7 free: 000055882F60DE10, unused: 14952 server | 2025/04/30 09:39:25 [debug] 22#0: posted event 000055882F5C0248 server | 2025/04/30 09:39:25 [debug] 22#0: *6 delete posted event 000055882F5C0248 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic push handler server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic output init packet max:1200 min:0 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic frame tx init:1 ACK n:0 delay:0 1-0 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic frame tx init:1 CRYPTO len:96 off:0 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic packet tx init bytes:105 need_ack:1 number:1 encoded nl:1 trunc:0x1 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic output hs packet max:1048 min:0 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic frame tx hs:0 CRYPTO len:169 off:0 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic packet tx hs bytes:173 need_ack:1 number:0 encoded nl:1 trunc:0x0 server | 2025/04/30 09:39:25 [debug] 22#0: *6 posix_memalign: 000055882F60B680:512 @16 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic output app packet max:829 min:829 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic frame tx app:0 ACK n:0 delay:0 0 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic frame tx app:0 CRYPTO len:572 off:0 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic split frame now:10245 need:230 shrink:10015 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic frame tx app:0 STREAM id:0x0 off:0 len:225 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic packet tx app bytes:811 need_ack:1 number:0 encoded nl:1 trunc:0x0 server | 2025/04/30 09:39:25 [debug] 22#0: *6 sendmsg: 1200 of 1200 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic congestion send if:152 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic congestion send if:371 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic congestion send if:1200 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic output app packet max:1200 min:0 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic split frame now:10021 need:1182 shrink:8839 server | 2025/04/30 09:39:25 [debug] 22#0: *6 posix_memalign: 000055882F612E30:512 @16 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic frame tx app:1 STREAM id:0x0 off:225 len:1176 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic packet tx app bytes:1182 need_ack:1 number:1 encoded nl:1 trunc:0x1 server | 2025/04/30 09:39:25 [debug] 22#0: *6 sendmsg: 1200 of 1200 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic congestion send if:1200 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic congestion send if:1200 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic congestion send if:2400 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic output app packet max:1200 min:0 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic split frame now:8845 need:1182 shrink:7663 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic frame tx app:2 STREAM id:0x0 off:1401 len:1176 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic packet tx app bytes:1182 need_ack:1 number:2 encoded nl:1 trunc:0x2 server | 2025/04/30 09:39:25 [debug] 22#0: *6 sendmsg: 1200 of 1200 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic congestion send if:2400 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic congestion send if:2400 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic congestion send if:3600 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic output app packet max:1200 min:0 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic split frame now:7669 need:1182 shrink:6487 server | 2025/04/30 09:39:25 [debug] 22#0: *6 posix_memalign: 000055882F613040:512 @16 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic frame tx app:3 STREAM id:0x0 off:2577 len:1176 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic packet tx app bytes:1182 need_ack:1 number:3 encoded nl:1 trunc:0x3 server | 2025/04/30 09:39:25 [debug] 22#0: *6 sendmsg: 1200 of 1200 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic congestion send if:3600 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic congestion send if:3600 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic congestion send if:4800 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic output app packet max:1200 min:0 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic split frame now:6493 need:1182 shrink:5311 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic frame tx app:4 STREAM id:0x0 off:3753 len:1176 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic packet tx app bytes:1182 need_ack:1 number:4 encoded nl:1 trunc:0x4 server | 2025/04/30 09:39:25 [debug] 22#0: *6 sendmsg: 1200 of 1200 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic congestion send if:4800 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic congestion send if:4800 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic congestion send if:6000 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic output app packet max:1200 min:0 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic split frame now:5317 need:1182 shrink:4135 server | 2025/04/30 09:39:25 [debug] 22#0: *6 posix_memalign: 000055882F613250:512 @16 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic frame tx app:5 STREAM id:0x0 off:4929 len:1176 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic packet tx app bytes:1182 need_ack:1 number:5 encoded nl:1 trunc:0x5 server | 2025/04/30 09:39:25 [debug] 22#0: *6 sendmsg: 1200 of 1200 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic congestion send if:6000 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic congestion send if:6000 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic congestion send if:7200 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic output app packet max:261 min:0 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic split frame now:4141 need:243 shrink:3898 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic frame tx app:6 STREAM id:0x0 off:6105 len:237 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic packet tx app bytes:243 need_ack:1 number:6 encoded nl:1 trunc:0x6 server | 2025/04/30 09:39:25 [debug] 22#0: *6 sendmsg: 261 of 261 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic congestion send if:7200 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic congestion send if:7200 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic congestion send if:7461 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic output app packet max:0 min:0 server | 2025/04/30 09:39:25 [debug] 22#0: *6 event timer: 6, old: 364453, new: 364453 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic lost timer pto:997 server | 2025/04/30 09:39:25 [debug] 22#0: *6 event timer add: 6: 997:335450 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic state: send:30000 pto:997 server | 2025/04/30 09:39:25 [debug] 22#0: worker cycle server | 2025/04/30 09:39:25 [debug] 22#0: epoll timer: 997 client | 0.451 DEBUG [Client 0233a3281fbbec85] pn=0 type=Initial pri-path:0233a3281fbbec85 0.0.0.0:40520->193.167.100.100:443 IpTos(Cs0, NotEct) len 51 client | -> RX Ack { largest_acknowledged: 0, ack_delay: 0, first_ack_range: 0, ack_ranges: [], ecn_count: None } client | 0.451 DEBUG [Client 0233a3281fbbec85] Rx ACK space=in, ranges=[0..=0] client | 0.451 DEBUG [LossRecovery] ACK for Initial - largest_acked=0 client | 0.451 DEBUG on_packets_acked this=0x56335427f630, limited=1, bytes_in_flight=1252, cwnd=12520, state=SlowStart, new_acked=1252 client | 0.451 DEBUG Acked crypto frame space=in offset=0 length=1213 client | 0.451 DEBUG [Client 0233a3281fbbec85] Changing to use Server CID=0000000000002003de2ddac5b5d2859d37d852d7 client | 0.451 DEBUG [Client 0233a3281fbbec85] State change from WaitInitial -> WaitVersion client | 0.451 DEBUG [Client 0233a3281fbbec85] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.451 DEBUG Building Initial dcid Some(CID [20]: 0000000000002003de2ddac5b5d2859d37d852d7) scid Some(CID [0]: ) client | 0.451 DEBUG Building ZeroRtt dcid Some(CID [20]: 0000000000002003de2ddac5b5d2859d37d852d7) scid Some(CID [0]: ) client | 0.451 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.451 DEBUG [Client 0233a3281fbbec85] delay duration 64.016873ms client | 0.451 DEBUG Setting timeout of 64.016873ms client | 0.451 WARN Unhandled event StateChange(WaitVersion) client | 0.451 DEBUG [Client 0233a3281fbbec85] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.451 DEBUG Building Initial dcid Some(CID [20]: 0000000000002003de2ddac5b5d2859d37d852d7) scid Some(CID [0]: ) client | 0.451 DEBUG Building ZeroRtt dcid Some(CID [20]: 0000000000002003de2ddac5b5d2859d37d852d7) scid Some(CID [0]: ) client | 0.451 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.451 DEBUG [Client 0233a3281fbbec85] delay duration 63.976577ms client | 0.451 DEBUG Setting timeout of 63.976577ms client | 0.454 DEBUG [Client 0233a3281fbbec85] pn=1 type=Initial pri-path:0000000000002003de2ddac5b5d2859d37d852d7 0.0.0.0:40520->193.167.100.100:443 IpTos(Cs0, NotEct) len 152 client | -> RX Ack { largest_acknowledged: 1, ack_delay: 0, first_ack_range: 1, ack_ranges: [], ecn_count: None } client | -> RX Crypto { offset: 0, len: 96 } client | 0.454 DEBUG [Client 0233a3281fbbec85] Rx ACK space=in, ranges=[0..=1] client | 0.454 DEBUG [LossRecovery] ACK for Initial - largest_acked=1 client | 0.454 DEBUG on_packets_acked this=0x56335427f630, limited=1, bytes_in_flight=54, cwnd=12520, state=SlowStart, new_acked=1198 client | 0.454 DEBUG Acked crypto frame space=in offset=1213 length=633 client | 0.454 DEBUG Read Ok(96) bytes client | 0.454 DEBUG Write secret available for Handshake: SymKey [32]: 86fd4314d8ff4577e397dca2ac671581d7df2a1a74c64b58b130b9258e20a15b client | 0.454 DEBUG Read secret available for Handshake: SymKey [32]: 43c660b510da8dc7d477723e7a180c8c922b5621282203d8dcc2bf92a54c607e client | 0.454 DEBUG [Agent 0x5633542af980] state -> InProgress client | 0.454 DEBUG Making Write Handshake CryptoDxState, v=Version1 cipher=4865 client | 0.454 DEBUG Making Read Handshake CryptoDxState, v=Version1 cipher=4865 client | 0.454 DEBUG [Crypto] Handshake keys installed client | 0.454 DEBUG [Recvd-in] Set ACK timer to Instant { tv_sec: 334, tv_nsec: 471103662 } client | 0.454 DEBUG [Client 0233a3281fbbec85] State change from WaitVersion -> Handshaking client | 0.454 DEBUG [Client 0233a3281fbbec85] pn=0 type=Handshake pri-path:0000000000002003de2ddac5b5d2859d37d852d7 0.0.0.0:40520->193.167.100.100:443 IpTos(Cs0, NotEct) len 219 client | -> RX Crypto { offset: 0, len: 169 } client | 0.454 DEBUG Read Ok(169) bytes client | 0.454 DEBUG Write secret available for ApplicationData: SymKey [32]: 00d8b73a97542f25e1075b412ac450e080b2cb018c4c193391d1a3d731b1fed7 client | 0.454 DEBUG Read secret available for ApplicationData: SymKey [32]: 9cd821791afb12744aeb23ea4593f6df56cc820e2f1f776788fc0545dfe8df29 client | 0.455 DEBUG [Agent 0x5633542af980] state -> Complete(SecretAgentInfo { version: 772, cipher: 4865, group: 29, resumed: true, early_data: true, ech_accepted: false, alpn: Some("hq-interop"), signature_scheme: 1027 }) client | 0.455 DEBUG [Client 0233a3281fbbec85] TLS connection complete client | 0.455 DEBUG Making Write ApplicationData CryptoDxState, v=Version1 cipher=4865 client | 0.455 DEBUG [Crypto] Application write key installed client | 0.455 DEBUG Making Read ApplicationData CryptoDxState, v=Version1 cipher=4865 client | 0.455 DEBUG [Crypto] application read keys installed client | 0.455 DEBUG setting max_stream_data to 65536 client | 0.455 DEBUG [Client 0233a3281fbbec85] State change from Handshaking -> Connected client | 0.455 INFO [Client 0233a3281fbbec85] Connection established client | 0.455 DEBUG setting max_stream_data to 65536 client | 0.455 DEBUG [Recvd-hs] Set ACK timer to Instant { tv_sec: 334, tv_nsec: 471103662 } client | 0.455 DEBUG [Client 0233a3281fbbec85] pn=0 type=Short pri-path:0000000000002003de2ddac5b5d2859d37d852d7 0.0.0.0:40520->193.167.100.100:443 IpTos(Cs0, NotEct) len 829 client | -> RX Ack { largest_acknowledged: 0, ack_delay: 0, first_ack_range: 0, ack_ranges: [], ecn_count: None } client | -> RX Crypto { offset: 0, len: 572 } client | -> RX Stream { stream_id: 0, offset: 0, len: 225, fin: false } client | 0.455 DEBUG [Client 0233a3281fbbec85] Rx ACK space=ap, ranges=[0..=0] client | 0.455 DEBUG [LossRecovery] ACK for ApplicationData - largest_acked=0 client | 0.455 DEBUG on_packets_acked this=0x56335427f630, limited=1, bytes_in_flight=0, cwnd=12520, state=SlowStart, new_acked=54 client | 0.455 DEBUG Read Ok(572) bytes client | 0.455 DEBUG [0x5633542af980] Got resumption token [953]: 02000633fbb1521f..ccaee372b9177952 client | 0.455 DEBUG [0x5633542af980] Got resumption token [953]: 02000633fbb1521f..9f793af9a3c15052 client | 0.455 DEBUG [Agent 0x5633542af980] state -> Complete(SecretAgentInfo { version: 772, cipher: 4865, group: 29, resumed: true, early_data: true, ech_accepted: false, alpn: Some("hq-interop"), signature_scheme: 1027 }) client | 0.455 DEBUG setting max_stream_data to 65536 client | 0.455 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 334, tv_nsec: 491103662 } client | 0.455 DEBUG [Client 0233a3281fbbec85] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.455 DEBUG Building Initial dcid Some(CID [20]: 0000000000002003de2ddac5b5d2859d37d852d7) scid Some(CID [0]: ) client | 0.455 DEBUG [Client 0233a3281fbbec85] pn=2 type=Initial pri-path:0000000000002003de2ddac5b5d2859d37d852d7 0.0.0.0:40520->193.167.100.100:443 IpTos(Cs0, Ect0) len 53 client | TX -> Ack { largest_acknowledged: 1, ack_delay: 122, first_ack_range: 1, ack_ranges: [], ecn_count: None } client | 0.455 DEBUG Building Handshake dcid Some(CID [20]: 0000000000002003de2ddac5b5d2859d37d852d7) scid Some(CID [0]: ) client | 0.455 DEBUG CRYPTO for hs offset=0, len=36 client | 0.455 DEBUG [Client 0233a3281fbbec85] pn=0 type=Handshake pri-path:0000000000002003de2ddac5b5d2859d37d852d7 0.0.0.0:40520->193.167.100.100:443 IpTos(Cs0, Ect0) len 144 client | TX -> Ack { largest_acknowledged: 0, ack_delay: 122, first_ack_range: 0, ack_ranges: [], ecn_count: None } client | TX -> Crypto { offset: 0, len: 36 } client | 0.455 DEBUG packet_sent this=0x56335427f630, pn=0, ps=91 client | 0.455 DEBUG [Client 0233a3281fbbec85] Drop packet number space in client | 0.455 DEBUG [LossRecovery] Reset loss recovery state for Initial client | 0.455 DEBUG Building Short dcid Some(CID [20]: 0000000000002003de2ddac5b5d2859d37d852d7) client | 0.455 WARN [LossRecovery] ignoring in-2 from dropped space client | 0.455 DEBUG ECN probing: sent 3 probes client | 0.455 DEBUG [Client 0233a3281fbbec85] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.455 DEBUG Building Handshake dcid Some(CID [20]: 0000000000002003de2ddac5b5d2859d37d852d7) scid Some(CID [0]: ) client | 0.455 DEBUG Building Short dcid Some(CID [20]: 0000000000002003de2ddac5b5d2859d37d852d7) client | 0.455 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.455 DEBUG [Client 0233a3281fbbec85] delay duration 18.906138ms client | 0.455 DEBUG Setting timeout of 18.906138ms client | 0.455 DEBUG [Client 0233a3281fbbec85] pn=1 type=Short pri-path:0000000000002003de2ddac5b5d2859d37d852d7 0.0.0.0:40520->193.167.100.100:443 IpTos(Cs0, NotEct) len 1200 client | -> RX Stream { stream_id: 0, offset: 225, len: 1176, fin: false } client | 0.455 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 334, tv_nsec: 472229935 } client | 0.455 DEBUG [Client 0233a3281fbbec85] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.455 DEBUG Building Handshake dcid Some(CID [20]: 0000000000002003de2ddac5b5d2859d37d852d7) scid Some(CID [0]: ) client | 0.455 DEBUG Building Short dcid Some(CID [20]: 0000000000002003de2ddac5b5d2859d37d852d7) client | 0.455 DEBUG [Client 0233a3281fbbec85] pn=1 type=Short pri-path:0000000000002003de2ddac5b5d2859d37d852d7 0.0.0.0:40520->193.167.100.100:443 IpTos(Cs0, Ect0) len 43 client | TX -> Ack { largest_acknowledged: 1, ack_delay: 2, first_ack_range: 1, ack_ranges: [], ecn_count: None } client | 0.455 DEBUG ECN probing: sent 4 probes client | 0.455 DEBUG [Client 0233a3281fbbec85] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.455 DEBUG Building Handshake dcid Some(CID [20]: 0000000000002003de2ddac5b5d2859d37d852d7) scid Some(CID [0]: ) client | 0.455 DEBUG Building Short dcid Some(CID [20]: 0000000000002003de2ddac5b5d2859d37d852d7) client | 0.455 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.455 DEBUG [Client 0233a3281fbbec85] delay duration 73.71507ms client | 0.455 DEBUG Setting timeout of 73.71507ms client | 0.455 DEBUG StateChange(Handshaking) client | 0.455 DEBUG stream BiDi creatable client | 0.455 DEBUG stream UniDi creatable client | 0.455 DEBUG StateChange(Connected) client | 0.455 DEBUG stream 0 complete client | 0.455 DEBUG [Client 0233a3281fbbec85] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.455 DEBUG Building Handshake dcid Some(CID [20]: 0000000000002003de2ddac5b5d2859d37d852d7) scid Some(CID [0]: ) client | 0.455 DEBUG Building Short dcid Some(CID [20]: 0000000000002003de2ddac5b5d2859d37d852d7) client | 0.455 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.455 DEBUG [Client 0233a3281fbbec85] delay duration 73.675366ms client | 0.455 DEBUG Setting timeout of 73.675366ms client | 0.456 DEBUG [Client 0233a3281fbbec85] pn=2 type=Short pri-path:0000000000002003de2ddac5b5d2859d37d852d7 0.0.0.0:40520->193.167.100.100:443 IpTos(Cs0, NotEct) len 1200 client | -> RX Stream { stream_id: 0, offset: 1401, len: 1176, fin: false } client | 0.456 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 334, tv_nsec: 493023884 } client | 0.456 DEBUG [Client 0233a3281fbbec85] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.456 DEBUG Building Handshake dcid Some(CID [20]: 0000000000002003de2ddac5b5d2859d37d852d7) scid Some(CID [0]: ) client | 0.456 DEBUG Building Short dcid Some(CID [20]: 0000000000002003de2ddac5b5d2859d37d852d7) client | 0.456 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.456 DEBUG [Client 0233a3281fbbec85] delay duration 19.969423ms client | 0.456 DEBUG Setting timeout of 19.969423ms client | 0.456 DEBUG [Client 0233a3281fbbec85] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.456 DEBUG Building Handshake dcid Some(CID [20]: 0000000000002003de2ddac5b5d2859d37d852d7) scid Some(CID [0]: ) client | 0.456 DEBUG Building Short dcid Some(CID [20]: 0000000000002003de2ddac5b5d2859d37d852d7) client | 0.456 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.456 DEBUG [Client 0233a3281fbbec85] delay duration 19.949976ms client | 0.456 DEBUG Setting timeout of 19.949976ms client | 0.457 DEBUG [Client 0233a3281fbbec85] pn=3 type=Short pri-path:0000000000002003de2ddac5b5d2859d37d852d7 0.0.0.0:40520->193.167.100.100:443 IpTos(Cs0, NotEct) len 1200 client | -> RX Stream { stream_id: 0, offset: 2577, len: 1176, fin: false } client | 0.457 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 334, tv_nsec: 474055329 } client | 0.457 DEBUG [Client 0233a3281fbbec85] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.457 DEBUG Building Handshake dcid Some(CID [20]: 0000000000002003de2ddac5b5d2859d37d852d7) scid Some(CID [0]: ) client | 0.457 DEBUG Building Short dcid Some(CID [20]: 0000000000002003de2ddac5b5d2859d37d852d7) client | 0.457 DEBUG [Client 0233a3281fbbec85] pn=2 type=Short pri-path:0000000000002003de2ddac5b5d2859d37d852d7 0.0.0.0:40520->193.167.100.100:443 IpTos(Cs0, Ect0) len 43 client | TX -> Ack { largest_acknowledged: 3, ack_delay: 2, first_ack_range: 3, ack_ranges: [], ecn_count: None } client | 0.457 DEBUG ECN probing: sent 5 probes client | 0.457 DEBUG [Client 0233a3281fbbec85] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.457 DEBUG Building Handshake dcid Some(CID [20]: 0000000000002003de2ddac5b5d2859d37d852d7) scid Some(CID [0]: ) client | 0.457 DEBUG Building Short dcid Some(CID [20]: 0000000000002003de2ddac5b5d2859d37d852d7) client | 0.457 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.457 DEBUG [Client 0233a3281fbbec85] delay duration 71.866304ms client | 0.457 DEBUG Setting timeout of 71.866304ms client | 0.457 DEBUG [Client 0233a3281fbbec85] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.457 DEBUG Building Handshake dcid Some(CID [20]: 0000000000002003de2ddac5b5d2859d37d852d7) scid Some(CID [0]: ) client | 0.457 DEBUG Building Short dcid Some(CID [20]: 0000000000002003de2ddac5b5d2859d37d852d7) client | 0.457 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.457 DEBUG [Client 0233a3281fbbec85] delay duration 71.835607ms client | 0.457 DEBUG Setting timeout of 71.835607ms client | 0.458 DEBUG [Client 0233a3281fbbec85] pn=4 type=Short pri-path:0000000000002003de2ddac5b5d2859d37d852d7 0.0.0.0:40520->193.167.100.100:443 IpTos(Cs0, NotEct) len 1200 client | -> RX Stream { stream_id: 0, offset: 3753, len: 1176, fin: false } client | 0.458 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 334, tv_nsec: 495016520 } client | 0.458 DEBUG [Client 0233a3281fbbec85] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.458 DEBUG Building Handshake dcid Some(CID [20]: 0000000000002003de2ddac5b5d2859d37d852d7) scid Some(CID [0]: ) client | 0.458 DEBUG Building Short dcid Some(CID [20]: 0000000000002003de2ddac5b5d2859d37d852d7) client | 0.458 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.458 DEBUG [Client 0233a3281fbbec85] delay duration 19.972138ms client | 0.458 DEBUG Setting timeout of 19.972138ms client | 0.458 DEBUG [Client 0233a3281fbbec85] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.458 DEBUG Building Handshake dcid Some(CID [20]: 0000000000002003de2ddac5b5d2859d37d852d7) scid Some(CID [0]: ) client | 0.458 DEBUG Building Short dcid Some(CID [20]: 0000000000002003de2ddac5b5d2859d37d852d7) client | 0.458 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.458 DEBUG [Client 0233a3281fbbec85] delay duration 19.945017ms client | 0.458 DEBUG Setting timeout of 19.945017ms client | 0.459 DEBUG [Client 0233a3281fbbec85] pn=5 type=Short pri-path:0000000000002003de2ddac5b5d2859d37d852d7 0.0.0.0:40520->193.167.100.100:443 IpTos(Cs0, NotEct) len 1200 client | -> RX Stream { stream_id: 0, offset: 4929, len: 1176, fin: false } client | 0.459 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 334, tv_nsec: 475992491 } client | 0.459 DEBUG [Client 0233a3281fbbec85] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.459 DEBUG Building Handshake dcid Some(CID [20]: 0000000000002003de2ddac5b5d2859d37d852d7) scid Some(CID [0]: ) client | 0.459 DEBUG Building Short dcid Some(CID [20]: 0000000000002003de2ddac5b5d2859d37d852d7) client | 0.459 DEBUG [Client 0233a3281fbbec85] pn=3 type=Short pri-path:0000000000002003de2ddac5b5d2859d37d852d7 0.0.0.0:40520->193.167.100.100:443 IpTos(Cs0, Ect0) len 43 client | TX -> Ack { largest_acknowledged: 5, ack_delay: 5, first_ack_range: 5, ack_ranges: [], ecn_count: None } client | 0.459 DEBUG ECN probing: sent 6 probes client | 0.459 DEBUG [Client 0233a3281fbbec85] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.459 DEBUG Building Handshake dcid Some(CID [20]: 0000000000002003de2ddac5b5d2859d37d852d7) scid Some(CID [0]: ) client | 0.459 DEBUG Building Short dcid Some(CID [20]: 0000000000002003de2ddac5b5d2859d37d852d7) client | 0.459 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.459 DEBUG [Client 0233a3281fbbec85] delay duration 69.921125ms client | 0.459 DEBUG Setting timeout of 69.921125ms client | 0.459 DEBUG [Client 0233a3281fbbec85] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.459 DEBUG Building Handshake dcid Some(CID [20]: 0000000000002003de2ddac5b5d2859d37d852d7) scid Some(CID [0]: ) client | 0.459 DEBUG Building Short dcid Some(CID [20]: 0000000000002003de2ddac5b5d2859d37d852d7) client | 0.459 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.459 DEBUG [Client 0233a3281fbbec85] delay duration 69.892772ms client | 0.459 DEBUG Setting timeout of 69.892772ms client | 0.459 DEBUG [Client 0233a3281fbbec85] pn=6 type=Short pri-path:0000000000002003de2ddac5b5d2859d37d852d7 0.0.0.0:40520->193.167.100.100:443 IpTos(Cs0, NotEct) len 261 client | -> RX Stream { stream_id: 0, offset: 6105, len: 237, fin: false } client | 0.459 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 334, tv_nsec: 496195111 } client | 0.459 DEBUG [Client 0233a3281fbbec85] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.459 DEBUG Building Handshake dcid Some(CID [20]: 0000000000002003de2ddac5b5d2859d37d852d7) scid Some(CID [0]: ) client | 0.459 DEBUG Building Short dcid Some(CID [20]: 0000000000002003de2ddac5b5d2859d37d852d7) client | 0.459 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.459 DEBUG [Client 0233a3281fbbec85] delay duration 19.975174ms client | 0.459 DEBUG Setting timeout of 19.975174ms client | 0.459 DEBUG [Client 0233a3281fbbec85] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.459 DEBUG Building Handshake dcid Some(CID [20]: 0000000000002003de2ddac5b5d2859d37d852d7) scid Some(CID [0]: ) client | 0.459 DEBUG Building Short dcid Some(CID [20]: 0000000000002003de2ddac5b5d2859d37d852d7) client | 0.459 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.459 DEBUG [Client 0233a3281fbbec85] delay duration 19.95195ms client | 0.459 DEBUG Setting timeout of 19.95195ms server | 2025/04/30 09:39:25 [debug] 22#0: epoll: fd:6 ev:0001 d:00007FFBCCE83108 server | 2025/04/30 09:39:25 [debug] 22#0: quic recvmsg on 0.0.0.0:443, ready: 0 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic recvmsg: fd:6 n:144 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic input handler server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic packet rx long flags:c8 version:1 server | 2025/04/30 09:39:25 [info] 22#0: *6 quic UDP datagram is too small for initial packet while parsing quic long header, client: 193.167.0.100, server: 0.0.0.0:443 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic packet done rc:-5 parse failed server | 2025/04/30 09:39:25 [debug] 22#0: timer delta: 34 server | 2025/04/30 09:39:25 [debug] 22#0: worker cycle server | 2025/04/30 09:39:25 [debug] 22#0: epoll timer: 963 server | 2025/04/30 09:39:25 [debug] 22#0: epoll: fd:6 ev:0001 d:00007FFBCCE83108 server | 2025/04/30 09:39:25 [debug] 22#0: quic recvmsg on 0.0.0.0:443, ready: 0 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic recvmsg: fd:6 n:43 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic input handler server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic packet rx short flags:54 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic packet rx dcid len:20 0000000000002003de2ddac5b5d2859d37d852d7 server | 2025/04/30 09:39:25 [info] 22#0: *6 quic no app keys, ignoring packet while decrypting packet, client: 193.167.0.100, server: 0.0.0.0:443 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic packet done rc:-5 level:app decr:0 pn:0 perr:0 server | 2025/04/30 09:39:25 [debug] 22#0: timer delta: 0 server | 2025/04/30 09:39:25 [debug] 22#0: worker cycle server | 2025/04/30 09:39:25 [debug] 22#0: epoll timer: 963 server | 2025/04/30 09:39:25 [debug] 22#0: epoll: fd:6 ev:0001 d:00007FFBCCE83108 server | 2025/04/30 09:39:25 [debug] 22#0: quic recvmsg on 0.0.0.0:443, ready: 0 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic recvmsg: fd:6 n:43 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic input handler server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic packet rx short flags:50 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic packet rx dcid len:20 0000000000002003de2ddac5b5d2859d37d852d7 server | 2025/04/30 09:39:25 [info] 22#0: *6 quic no app keys, ignoring packet while decrypting packet, client: 193.167.0.100, server: 0.0.0.0:443 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic packet done rc:-5 level:app decr:0 pn:0 perr:0 server | 2025/04/30 09:39:25 [debug] 22#0: timer delta: 2 server | 2025/04/30 09:39:25 [debug] 22#0: worker cycle server | 2025/04/30 09:39:25 [debug] 22#0: epoll timer: 961 server | 2025/04/30 09:39:25 [debug] 22#0: epoll: fd:6 ev:0001 d:00007FFBCCE83108 server | 2025/04/30 09:39:25 [debug] 22#0: quic recvmsg on 0.0.0.0:443, ready: 0 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic recvmsg: fd:6 n:43 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic input handler server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic packet rx short flags:4a server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic packet rx dcid len:20 0000000000002003de2ddac5b5d2859d37d852d7 server | 2025/04/30 09:39:25 [info] 22#0: *6 quic no app keys, ignoring packet while decrypting packet, client: 193.167.0.100, server: 0.0.0.0:443 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic packet done rc:-5 level:app decr:0 pn:0 perr:0 server | 2025/04/30 09:39:25 [debug] 22#0: timer delta: 2 server | 2025/04/30 09:39:25 [debug] 22#0: worker cycle server | 2025/04/30 09:39:25 [debug] 22#0: epoll timer: 959 client | 0.480 DEBUG [Client 0233a3281fbbec85] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.480 DEBUG Building Handshake dcid Some(CID [20]: 0000000000002003de2ddac5b5d2859d37d852d7) scid Some(CID [0]: ) client | 0.480 DEBUG Building Short dcid Some(CID [20]: 0000000000002003de2ddac5b5d2859d37d852d7) client | 0.480 DEBUG [Client 0233a3281fbbec85] pn=4 type=Short pri-path:0000000000002003de2ddac5b5d2859d37d852d7 0.0.0.0:40520->193.167.100.100:443 IpTos(Cs0, Ect0) len 44 client | TX -> Ack { largest_acknowledged: 6, ack_delay: 2642, first_ack_range: 6, ack_ranges: [], ecn_count: None } client | 0.480 DEBUG ECN probing: sent 7 probes client | 0.480 DEBUG [Client 0233a3281fbbec85] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.480 DEBUG Building Handshake dcid Some(CID [20]: 0000000000002003de2ddac5b5d2859d37d852d7) scid Some(CID [0]: ) client | 0.480 DEBUG Building Short dcid Some(CID [20]: 0000000000002003de2ddac5b5d2859d37d852d7) client | 0.480 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.480 DEBUG [Client 0233a3281fbbec85] delay duration 48.598627ms client | 0.480 DEBUG Setting timeout of 48.598627ms server | 2025/04/30 09:39:25 [debug] 22#0: epoll: fd:6 ev:0001 d:00007FFBCCE83108 server | 2025/04/30 09:39:25 [debug] 22#0: quic recvmsg on 0.0.0.0:443, ready: 0 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic recvmsg: fd:6 n:44 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic input handler server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic packet rx short flags:73 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic packet rx dcid len:20 0000000000002003de2ddac5b5d2859d37d852d7 server | 2025/04/30 09:39:25 [info] 22#0: *6 quic no app keys, ignoring packet while decrypting packet, client: 193.167.0.100, server: 0.0.0.0:443 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic packet done rc:-5 level:app decr:0 pn:0 perr:0 server | 2025/04/30 09:39:25 [debug] 22#0: timer delta: 21 server | 2025/04/30 09:39:25 [debug] 22#0: worker cycle server | 2025/04/30 09:39:25 [debug] 22#0: epoll timer: 938 client | 0.530 DEBUG [LossRecovery] PTO timer fired for Handshake client | 0.530 DEBUG [Client 0233a3281fbbec85] Lost: Ack(AckToken { space: Handshake, ranges: [PacketRange { largest: 0, smallest: 0, ack_needed: true }] }) client | 0.530 DEBUG [Recvd-hs] immediate_ack at Instant { tv_sec: 334, tv_nsec: 472087317 } client | 0.530 DEBUG [Client 0233a3281fbbec85] Lost: Crypto(CryptoRecoveryToken { space: Handshake, offset: 0, length: 36 }) client | 0.530 INFO Lost crypto frame space=hs offset=0 length=36 client | 0.530 DEBUG [Client 0233a3281fbbec85] output_path send_profile SendProfile { limit: 1252, pto: Some(Handshake), probe: EnumSet(Handshake), paced: false } client | 0.530 DEBUG Building Handshake dcid Some(CID [20]: 0000000000002003de2ddac5b5d2859d37d852d7) scid Some(CID [0]: ) client | 0.530 DEBUG CRYPTO for hs offset=0, len=36 client | 0.530 DEBUG [Client 0233a3281fbbec85] pn=1 type=Handshake pri-path:0000000000002003de2ddac5b5d2859d37d852d7 0.0.0.0:40520->193.167.100.100:443 IpTos(Cs0, Ect0) len 91 client | TX -> Ack { largest_acknowledged: 0, ack_delay: 9560, first_ack_range: 0, ack_ranges: [], ecn_count: None } client | TX -> Crypto { offset: 0, len: 36 } client | 0.530 DEBUG packet_sent this=0x56335427f630, pn=1, ps=91 client | 0.530 DEBUG Building Short dcid Some(CID [20]: 0000000000002003de2ddac5b5d2859d37d852d7) client | 0.530 DEBUG ECN probing: sent 8 probes client | 0.530 DEBUG [Client 0233a3281fbbec85] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.531 DEBUG Building Handshake dcid Some(CID [20]: 0000000000002003de2ddac5b5d2859d37d852d7) scid Some(CID [0]: ) client | 0.531 DEBUG Building Short dcid Some(CID [20]: 0000000000002003de2ddac5b5d2859d37d852d7) client | 0.531 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.531 DEBUG [Client 0233a3281fbbec85] delay duration 147.706749ms client | 0.531 DEBUG Setting timeout of 147.706749ms server | 2025/04/30 09:39:25 [debug] 22#0: epoll: fd:6 ev:0001 d:00007FFBCCE83108 server | 2025/04/30 09:39:25 [debug] 22#0: quic recvmsg on 0.0.0.0:443, ready: 0 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic recvmsg: fd:6 n:91 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic input handler server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic packet rx long flags:e3 version:1 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic packet rx hs len:62 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic packet rx dcid len:20 0000000000002003de2ddac5b5d2859d37d852d7 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic packet rx scid len:0 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic packet rx clearflags:e0 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic packet rx number:1 len:1 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic packet len:91 via sock seq:0 path seq:0 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic path seq:0 status tx:7512 rx:2595 valid:0 st:0 mtu:1200 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic congestion slow start win:131206 ss:-1 if:7309 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic socket seq:-1 closed nsock:1 server | 2025/04/30 09:39:25 [debug] 22#0: *6 event timer del: 6: 335450 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic lost timer pto:888 server | 2025/04/30 09:39:25 [debug] 22#0: *6 event timer add: 6: 888:335450 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic path seq:0 in handshake tx:7512 rx:2595 valid:1 st:0 mtu:1200 server | 2025/04/30 09:39:25 [debug] 22#0: *6 post event 000055882F5C0248 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic frame rx hs:1 ACK n:0 delay:9560 0 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic ngx_quic_handle_ack_frame level:2 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic congestion slow start win:131425 ss:-1 if:7090 server | 2025/04/30 09:39:25 [debug] 22#0: *6 update posted event 000055882F5C0248 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic updated largest received ack:0 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic rtt sample latest:109 min:109 avg:109 var:54 server | 2025/04/30 09:39:25 [debug] 22#0: *6 event timer del: 6: 335450 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic lost timer pto:216 server | 2025/04/30 09:39:25 [debug] 22#0: *6 event timer add: 6: 216:334778 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic frame rx hs:1 CRYPTO len:36 off:0 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic ngx_quic_set_read_secret() level:3 server | 2025/04/30 09:39:25 [debug] 22#0: *6 SSL_do_handshake: 1 server | 2025/04/30 09:39:25 [debug] 22#0: *6 SSL: TLSv1.3, cipher: "TLS_AES_128_GCM_SHA256 Kx=GENERIC Au=GENERIC Enc=AESGCM(128) Mac=AEAD" server | 2025/04/30 09:39:25 [debug] 22#0: *6 SSL reused session server | 2025/04/30 09:39:25 [debug] 22#0: *6 update posted event 000055882F5C0248 server | 2025/04/30 09:39:25 [debug] 22#0: *6 post event 000055882F5C03C8 server | 2025/04/30 09:39:25 [debug] 22#0: *6 event timer del: 6: 334778 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic lost timer pto:236 server | 2025/04/30 09:39:25 [debug] 22#0: *6 event timer add: 6: 236:334798 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic path seq:0 schedule mtu:2400 server | 2025/04/30 09:39:25 [debug] 22#0: *6 event timer add: 6: 100:334662 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic create sockets has:1 max:8 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic socket seq:1 listening at sid:0000000000002003fb3193c861a9375258b9a949 nsock:2 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic stateless reset token e089a3cb0868d9ce656acc6ad5cb8dfd server | 2025/04/30 09:39:25 [debug] 22#0: *6 update posted event 000055882F5C0248 server | 2025/04/30 09:39:25 [debug] 22#0: *6 posix_memalign: 000055882F5B4210:512 @16 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic socket seq:2 listening at sid:00000000000020036aa176c891273ce19ed2a778 nsock:3 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic stateless reset token 62c7eafa0cd15e7a9fb08de98e2d9e47 server | 2025/04/30 09:39:25 [debug] 22#0: *6 update posted event 000055882F5C0248 server | 2025/04/30 09:39:25 [debug] 22#0: *6 posix_memalign: 000055882F5B4420:512 @16 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic socket seq:3 listening at sid:000000000000200322549eea390021e8f60f2949 nsock:4 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic stateless reset token ddc3c96de75c1145f38e693f6a5f45d9 server | 2025/04/30 09:39:25 [debug] 22#0: *6 update posted event 000055882F5C0248 server | 2025/04/30 09:39:25 [debug] 22#0: *6 posix_memalign: 000055882F5B4630:512 @16 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic socket seq:4 listening at sid:00000000000020037a2b918e23e06c4e7889ea5f nsock:5 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic stateless reset token 29ec7d764be55a6a5e4651144f7182bf server | 2025/04/30 09:39:25 [debug] 22#0: *6 update posted event 000055882F5C0248 server | 2025/04/30 09:39:25 [debug] 22#0: *6 posix_memalign: 000055882F60A8B0:512 @16 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic socket seq:5 listening at sid:0000000000002003ffa25d33edcd3ca4969bdef9 nsock:6 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic stateless reset token c2e5182b42ef7d27ec4c4a6403ab35ba server | 2025/04/30 09:39:25 [debug] 22#0: *6 update posted event 000055882F5C0248 server | 2025/04/30 09:39:25 [debug] 22#0: *6 posix_memalign: 000055882F60AAC0:512 @16 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic socket seq:6 listening at sid:000000000000200361bf51dbcd0edd65dd9bc8cb nsock:7 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic stateless reset token c2f1304f167997de39429eef539b4bf0 server | 2025/04/30 09:39:25 [debug] 22#0: *6 update posted event 000055882F5C0248 server | 2025/04/30 09:39:25 [debug] 22#0: *6 posix_memalign: 000055882F60ACD0:512 @16 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic socket seq:7 listening at sid:00000000000020037eace3329b9fbdd7ffae3d74 nsock:8 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic stateless reset token 4325c467bafcc4fd4f2eeff15e5b44ba server | 2025/04/30 09:39:25 [debug] 22#0: *6 update posted event 000055882F5C0248 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic ngx_quic_ack_packet pn:1 largest -1 fr:0 nranges:0 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic packet done rc:0 level:hs decr:1 pn:1 perr:0 server | 2025/04/30 09:39:25 [debug] 22#0: *6 event timer: 6, old: 364453, new: 364562 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic state: read:29891 pto:236 server | 2025/04/30 09:39:25 [debug] 22#0: timer delta: 50 server | 2025/04/30 09:39:25 [debug] 22#0: posted event 000055882F5C0248 server | 2025/04/30 09:39:25 [debug] 22#0: *6 delete posted event 000055882F5C0248 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic push handler server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic output app packet max:1200 min:0 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic split frame now:3904 need:1182 shrink:2722 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic frame tx app:7 STREAM id:0x0 off:6342 len:1176 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic packet tx app bytes:1182 need_ack:1 number:7 encoded nl:1 trunc:0x7 server | 2025/04/30 09:39:25 [debug] 22#0: *6 sendmsg: 1200 of 1200 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic congestion send if:7090 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic congestion send if:7090 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic congestion send if:8290 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic output app packet max:1200 min:0 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic split frame now:2728 need:1182 shrink:1546 server | 2025/04/30 09:39:25 [debug] 22#0: *6 posix_memalign: 000055882F60AEE0:512 @16 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic frame tx app:8 STREAM id:0x0 off:7518 len:1176 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic packet tx app bytes:1182 need_ack:1 number:8 encoded nl:1 trunc:0x8 server | 2025/04/30 09:39:25 [debug] 22#0: *6 sendmsg: 1200 of 1200 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic congestion send if:8290 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic congestion send if:8290 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic congestion send if:9490 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic output app packet max:1200 min:0 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic split frame now:1552 need:1182 shrink:370 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic frame tx app:9 STREAM id:0x0 off:8694 len:1176 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic packet tx app bytes:1182 need_ack:1 number:9 encoded nl:1 trunc:0x9 server | 2025/04/30 09:39:25 [debug] 22#0: *6 sendmsg: 1200 of 1200 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic congestion send if:9490 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic congestion send if:9490 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic congestion send if:10690 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic output app packet max:1200 min:0 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic frame tx app:10 STREAM id:0x0 off:9870 len:370 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic frame tx app:10 STREAM id:0x0 off:10240 len:0 fin:1 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic frame tx app:10 HANDSHAKE DONE server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic frame tx app:10 NEW_CONNECTION_ID seq:1 retire:0 len:20 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic frame tx app:10 NEW_CONNECTION_ID seq:2 retire:0 len:20 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic frame tx app:10 NEW_CONNECTION_ID seq:3 retire:0 len:20 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic frame tx app:10 NEW_CONNECTION_ID seq:4 retire:0 len:20 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic frame tx app:10 NEW_CONNECTION_ID seq:5 retire:0 len:20 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic frame tx app:10 NEW_CONNECTION_ID seq:6 retire:0 len:20 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic frame tx app:10 NEW_CONNECTION_ID seq:7 retire:0 len:20 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic packet tx app bytes:662 need_ack:1 number:10 encoded nl:1 trunc:0xa server | 2025/04/30 09:39:25 [debug] 22#0: *6 sendmsg: 680 of 680 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic congestion send if:10690 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic congestion send if:10690 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic congestion send if:11370 server | 2025/04/30 09:39:25 [debug] 22#0: *6 event timer: 6, old: 364453, new: 364562 server | 2025/04/30 09:39:25 [debug] 22#0: *6 event timer del: 6: 334798 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic lost timer pto:345 server | 2025/04/30 09:39:25 [debug] 22#0: *6 event timer add: 6: 345:334907 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic state: send:29891 pto:345 server | 2025/04/30 09:39:25 [debug] 22#0: posted event 000055882F5C03C8 server | 2025/04/30 09:39:25 [debug] 22#0: *6 delete posted event 000055882F5C03C8 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic key update server | 2025/04/30 09:39:25 [debug] 22#0: worker cycle server | 2025/04/30 09:39:25 [debug] 22#0: epoll timer: 100 client | 0.563 DEBUG [Client 0233a3281fbbec85] pn=7 type=Short pri-path:0000000000002003de2ddac5b5d2859d37d852d7 0.0.0.0:40520->193.167.100.100:443 IpTos(Cs0, NotEct) len 1200 client | -> RX Stream { stream_id: 0, offset: 6342, len: 1176, fin: false } client | 0.563 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 334, tv_nsec: 599846469 } client | 0.563 DEBUG [Client 0233a3281fbbec85] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.563 DEBUG Building Handshake dcid Some(CID [20]: 0000000000002003de2ddac5b5d2859d37d852d7) scid Some(CID [0]: ) client | 0.563 DEBUG Building Short dcid Some(CID [20]: 0000000000002003de2ddac5b5d2859d37d852d7) client | 0.563 DEBUG [Client 0233a3281fbbec85] pn=5 type=Short pri-path:0000000000002003de2ddac5b5d2859d37d852d7 0.0.0.0:40520->193.167.100.100:443 IpTos(Cs0, Ect0) len 43 client | TX -> Ack { largest_acknowledged: 7, ack_delay: 5, first_ack_range: 7, ack_ranges: [], ecn_count: None } client | 0.563 DEBUG ECN probing: sent 9 probes client | 0.563 DEBUG [Client 0233a3281fbbec85] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.563 DEBUG Building Handshake dcid Some(CID [20]: 0000000000002003de2ddac5b5d2859d37d852d7) scid Some(CID [0]: ) client | 0.563 DEBUG Building Short dcid Some(CID [20]: 0000000000002003de2ddac5b5d2859d37d852d7) client | 0.563 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.563 DEBUG [Client 0233a3281fbbec85] delay duration 115.455107ms client | 0.563 DEBUG Setting timeout of 115.455107ms client | 0.563 DEBUG [Client 0233a3281fbbec85] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.563 DEBUG Building Handshake dcid Some(CID [20]: 0000000000002003de2ddac5b5d2859d37d852d7) scid Some(CID [0]: ) client | 0.563 DEBUG Building Short dcid Some(CID [20]: 0000000000002003de2ddac5b5d2859d37d852d7) client | 0.563 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.563 DEBUG [Client 0233a3281fbbec85] delay duration 115.389063ms client | 0.563 DEBUG Setting timeout of 115.389063ms client | 0.564 DEBUG [Client 0233a3281fbbec85] pn=8 type=Short pri-path:0000000000002003de2ddac5b5d2859d37d852d7 0.0.0.0:40520->193.167.100.100:443 IpTos(Cs0, NotEct) len 1200 client | -> RX Stream { stream_id: 0, offset: 7518, len: 1176, fin: false } client | 0.564 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 334, tv_nsec: 600766174 } client | 0.564 DEBUG [Client 0233a3281fbbec85] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.564 DEBUG Building Handshake dcid Some(CID [20]: 0000000000002003de2ddac5b5d2859d37d852d7) scid Some(CID [0]: ) client | 0.564 DEBUG Building Short dcid Some(CID [20]: 0000000000002003de2ddac5b5d2859d37d852d7) client | 0.564 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.564 DEBUG [Client 0233a3281fbbec85] delay duration 19.971226ms client | 0.564 DEBUG Setting timeout of 19.971226ms client | 0.564 DEBUG [Client 0233a3281fbbec85] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.564 DEBUG Building Handshake dcid Some(CID [20]: 0000000000002003de2ddac5b5d2859d37d852d7) scid Some(CID [0]: ) client | 0.564 DEBUG Building Short dcid Some(CID [20]: 0000000000002003de2ddac5b5d2859d37d852d7) client | 0.564 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.564 DEBUG [Client 0233a3281fbbec85] delay duration 19.922335ms client | 0.564 DEBUG Setting timeout of 19.922335ms client | 0.565 DEBUG [Client 0233a3281fbbec85] pn=9 type=Short pri-path:0000000000002003de2ddac5b5d2859d37d852d7 0.0.0.0:40520->193.167.100.100:443 IpTos(Cs0, NotEct) len 1200 client | -> RX Stream { stream_id: 0, offset: 8694, len: 1176, fin: false } client | 0.565 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 334, tv_nsec: 581755229 } client | 0.565 DEBUG [Client 0233a3281fbbec85] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.565 DEBUG Building Handshake dcid Some(CID [20]: 0000000000002003de2ddac5b5d2859d37d852d7) scid Some(CID [0]: ) client | 0.565 DEBUG Building Short dcid Some(CID [20]: 0000000000002003de2ddac5b5d2859d37d852d7) client | 0.565 DEBUG [Client 0233a3281fbbec85] pn=6 type=Short pri-path:0000000000002003de2ddac5b5d2859d37d852d7 0.0.0.0:40520->193.167.100.100:443 IpTos(Cs0, Ect0) len 43 client | TX -> Ack { largest_acknowledged: 9, ack_delay: 2, first_ack_range: 9, ack_ranges: [], ecn_count: None } client | 0.565 DEBUG ECN probing: sent 10 probes client | 0.565 DEBUG ECN probing concluded with 10 probes sent client | 0.565 DEBUG [Client 0233a3281fbbec85] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.565 DEBUG Building Handshake dcid Some(CID [20]: 0000000000002003de2ddac5b5d2859d37d852d7) scid Some(CID [0]: ) client | 0.565 DEBUG Building Short dcid Some(CID [20]: 0000000000002003de2ddac5b5d2859d37d852d7) client | 0.565 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.565 DEBUG [Client 0233a3281fbbec85] delay duration 113.612102ms client | 0.565 DEBUG Setting timeout of 113.612102ms client | 0.565 DEBUG [Client 0233a3281fbbec85] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.565 DEBUG Building Handshake dcid Some(CID [20]: 0000000000002003de2ddac5b5d2859d37d852d7) scid Some(CID [0]: ) client | 0.565 DEBUG Building Short dcid Some(CID [20]: 0000000000002003de2ddac5b5d2859d37d852d7) client | 0.565 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.565 DEBUG [Client 0233a3281fbbec85] delay duration 113.582386ms client | 0.565 DEBUG Setting timeout of 113.582386ms client | 0.565 DEBUG [Client 0233a3281fbbec85] pn=10 type=Short pri-path:0000000000002003de2ddac5b5d2859d37d852d7 0.0.0.0:40520->193.167.100.100:443 IpTos(Cs0, NotEct) len 680 client | -> RX Stream { stream_id: 0, offset: 9870, len: 370, fin: false } client | -> RX Stream { stream_id: 0, offset: 10240, len: 0, fin: true } client | -> RX HandshakeDone client | -> RX NewConnectionId { sequence_number: 1, retire_prior: 0, connection_id: [0, 0, 0, 0, 0, 0, 32, 3, 251, 49, 147, 200, 97, 169, 55, 82, 88, 185, 169, 73], stateless_reset_token: [224, 137, 163, 203, 8, 104, 217, 206, 101, 106, 204, 106, 213, 203, 141, 253] } client | -> RX NewConnectionId { sequence_number: 2, retire_prior: 0, connection_id: [0, 0, 0, 0, 0, 0, 32, 3, 106, 161, 118, 200, 145, 39, 60, 225, 158, 210, 167, 120], stateless_reset_token: [98, 199, 234, 250, 12, 209, 94, 122, 159, 176, 141, 233, 142, 45, 158, 71] } client | -> RX NewConnectionId { sequence_number: 3, retire_prior: 0, connection_id: [0, 0, 0, 0, 0, 0, 32, 3, 34, 84, 158, 234, 57, 0, 33, 232, 246, 15, 41, 73], stateless_reset_token: [221, 195, 201, 109, 231, 92, 17, 69, 243, 142, 105, 63, 106, 95, 69, 217] } client | -> RX NewConnectionId { sequence_number: 4, retire_prior: 0, connection_id: [0, 0, 0, 0, 0, 0, 32, 3, 122, 43, 145, 142, 35, 224, 108, 78, 120, 137, 234, 95], stateless_reset_token: [41, 236, 125, 118, 75, 229, 90, 106, 94, 70, 81, 20, 79, 113, 130, 191] } client | -> RX NewConnectionId { sequence_number: 5, retire_prior: 0, connection_id: [0, 0, 0, 0, 0, 0, 32, 3, 255, 162, 93, 51, 237, 205, 60, 164, 150, 155, 222, 249], stateless_reset_token: [194, 229, 24, 43, 66, 239, 125, 39, 236, 76, 74, 100, 3, 171, 53, 186] } client | -> RX NewConnectionId { sequence_number: 6, retire_prior: 0, connection_id: [0, 0, 0, 0, 0, 0, 32, 3, 97, 191, 81, 219, 205, 14, 221, 101, 221, 155, 200, 203], stateless_reset_token: [194, 241, 48, 79, 22, 121, 151, 222, 57, 66, 158, 239, 83, 155, 75, 240] } client | -> RX NewConnectionId { sequence_number: 7, retire_prior: 0, connection_id: [0, 0, 0, 0, 0, 0, 32, 3, 126, 172, 227, 50, 155, 159, 189, 215, 255, 174, 61, 116], stateless_reset_token: [67, 37, 196, 103, 186, 252, 196, 253, 79, 46, 239, 241, 94, 91, 68, 186] } client | 0.565 DEBUG [Client 0233a3281fbbec85] State change from Connected -> Confirmed client | 0.565 DEBUG PMTUD started with probe size 1380 client | 0.565 DEBUG [Client 0233a3281fbbec85] Drop packet number space hs client | 0.565 DEBUG [LossRecovery] Reset loss recovery state for Handshake client | 0.565 DEBUG [Client 0233a3281fbbec85] No preferred address to migrate to client | 0.565 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 334, tv_nsec: 602312374 } client | 0.565 DEBUG [Client 0233a3281fbbec85] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.565 DEBUG Building Short dcid Some(CID [20]: 0000000000002003de2ddac5b5d2859d37d852d7) client | 0.565 DEBUG Sending PMTUD probe of size 1380, count 1 client | 0.565 DEBUG [Client 0233a3281fbbec85] pn=7 type=Short pri-path:0000000000002003de2ddac5b5d2859d37d852d7 0.0.0.0:40520->193.167.100.100:443 IpTos(Cs0, NotEct) len 1352 client | TX -> Ping client | TX -> Padding { len: 1313 } client | 0.565 DEBUG packet_sent this=0x56335427f630, pn=7, ps=1352 client | 0.565 DEBUG [Client 0233a3281fbbec85] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.565 DEBUG Building Short dcid Some(CID [20]: 0000000000002003de2ddac5b5d2859d37d852d7) client | 0.565 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.565 DEBUG [Client 0233a3281fbbec85] delay duration 19.780919ms client | 0.565 DEBUG Setting timeout of 19.780919ms client | 0.565 WARN Unhandled event StateChange(Confirmed) client | 0.565 DEBUG resumption token [1063]: 0000000120406600..9f793af9a3c15052 client | 0.565 DEBUG [Client 0233a3281fbbec85] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.565 DEBUG Building Short dcid Some(CID [20]: 0000000000002003de2ddac5b5d2859d37d852d7) client | 0.565 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.565 DEBUG [Client 0233a3281fbbec85] delay duration 19.706629ms client | 0.565 DEBUG Setting timeout of 19.706629ms client | 0.565 DEBUG [Client 0233a3281fbbec85] State change from Confirmed -> Closing { error: Application(0), timeout: Instant { tv_sec: 334, tv_nsec: 879409580 } } client | 0.565 WARN Unhandled event StateChange(Closing { error: Application(0), timeout: Instant { tv_sec: 334, tv_nsec: 879409580 } }) client | 0.565 DEBUG [Client 0233a3281fbbec85] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.565 DEBUG Building Short dcid Some(CID [20]: 0000000000002003de2ddac5b5d2859d37d852d7) client | 0.565 DEBUG [Recvd-ap] immediate_ack at Instant { tv_sec: 334, tv_nsec: 582632925 } client | 0.565 DEBUG [Client 0233a3281fbbec85] pn=8 type=Short pri-path:0000000000002003de2ddac5b5d2859d37d852d7 0.0.0.0:40520->193.167.100.100:443 IpTos(Cs0, NotEct) len 54 client | TX -> Ack { largest_acknowledged: 10, ack_delay: 40, first_ack_range: 10, ack_ranges: [], ecn_count: None } client | TX -> ConnectionClose { error_code: Application(0), frame_type: 0, reason_phrase: "kthxbye!" } client | 0.565 DEBUG Setting timeout of 296.6997ms server | 2025/04/30 09:39:25 [debug] 22#0: epoll: fd:6 ev:0001 d:00007FFBCCE83108 server | 2025/04/30 09:39:25 [debug] 22#0: quic recvmsg on 0.0.0.0:443, ready: 0 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic recvmsg: fd:6 n:43 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic input handler server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic packet rx short flags:42 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic packet rx dcid len:20 0000000000002003de2ddac5b5d2859d37d852d7 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic packet rx clearflags:40 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic packet rx number:5 len:1 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic packet len:43 via sock seq:0 path seq:0 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic path seq:0 status tx:11792 rx:2638 valid:1 st:2 mtu:1200 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic frame rx app:5 ACK n:0 delay:5 7-0 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic ngx_quic_handle_ack_frame level:3 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic congestion slow start win:132254 ss:-1 if:10541 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic ngx_quic_drop_ack_ranges pn:0 largest:0 fr:0 nranges:0 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic stream id:0x0 ack len:225 fin:0 unacked:10015 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic congestion slow start win:133454 ss:-1 if:9341 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic stream id:0x0 ack len:1176 fin:0 unacked:8839 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic congestion slow start win:134654 ss:-1 if:8141 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic stream id:0x0 ack len:1176 fin:0 unacked:7663 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic congestion slow start win:135854 ss:-1 if:6941 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic stream id:0x0 ack len:1176 fin:0 unacked:6487 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic congestion slow start win:137054 ss:-1 if:5741 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic stream id:0x0 ack len:1176 fin:0 unacked:5311 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic congestion slow start win:138254 ss:-1 if:4541 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic stream id:0x0 ack len:1176 fin:0 unacked:4135 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic congestion slow start win:138515 ss:-1 if:4280 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic stream id:0x0 ack len:237 fin:0 unacked:3898 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic congestion slow start win:139715 ss:-1 if:3080 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic stream id:0x0 ack len:1176 fin:0 unacked:2722 server | 2025/04/30 09:39:25 [debug] 22#0: *6 post event 000055882F5C0248 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic updated largest received ack:7 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic rtt sample latest:33 min:33 avg:100 var:60 server | 2025/04/30 09:39:25 [debug] 22#0: *6 event timer del: 6: 334907 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic lost timer pto:327 server | 2025/04/30 09:39:25 [debug] 22#0: *6 event timer add: 6: 327:334922 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic ngx_quic_ack_packet pn:5 largest -1 fr:0 nranges:0 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic packet done rc:0 level:app decr:1 pn:5 perr:0 server | 2025/04/30 09:39:25 [debug] 22#0: *6 event timer: 6, old: 364453, new: 364595 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic state: read:29858 pto:327 server | 2025/04/30 09:39:25 [debug] 22#0: timer delta: 33 server | 2025/04/30 09:39:25 [debug] 22#0: posted event 000055882F5C0248 server | 2025/04/30 09:39:25 [debug] 22#0: *6 delete posted event 000055882F5C0248 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic push handler server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic state: read:29858 pto:327 server | 2025/04/30 09:39:25 [debug] 22#0: worker cycle server | 2025/04/30 09:39:25 [debug] 22#0: epoll timer: 67 server | 2025/04/30 09:39:25 [debug] 22#0: epoll: fd:6 ev:0001 d:00007FFBCCE83108 server | 2025/04/30 09:39:25 [debug] 22#0: quic recvmsg on 0.0.0.0:443, ready: 0 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic recvmsg: fd:6 n:43 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic input handler server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic packet rx short flags:70 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic packet rx dcid len:20 0000000000002003de2ddac5b5d2859d37d852d7 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic packet rx clearflags:60 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic packet rx number:6 len:1 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic packet len:43 via sock seq:0 path seq:0 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic path seq:0 status tx:11792 rx:2681 valid:1 st:2 mtu:1200 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic frame rx app:6 ACK n:0 delay:2 9-0 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic ngx_quic_handle_ack_frame level:3 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic congestion slow start win:140915 ss:-1 if:1880 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic stream id:0x0 ack len:1176 fin:0 unacked:1546 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic congestion slow start win:142115 ss:-1 if:680 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic stream id:0x0 ack len:1176 fin:0 unacked:370 server | 2025/04/30 09:39:25 [debug] 22#0: *6 post event 000055882F5C0248 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic updated largest received ack:9 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic rtt sample latest:35 min:33 avg:92 var:61 server | 2025/04/30 09:39:25 [debug] 22#0: *6 event timer del: 6: 334922 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic lost timer pto:321 server | 2025/04/30 09:39:25 [debug] 22#0: *6 event timer add: 6: 321:334918 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic ngx_quic_ack_packet pn:6 largest 5 fr:0 nranges:0 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic packet done rc:0 level:app decr:1 pn:6 perr:0 server | 2025/04/30 09:39:25 [debug] 22#0: *6 event timer: 6, old: 364453, new: 364597 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic state: read:29856 pto:321 server | 2025/04/30 09:39:25 [debug] 22#0: timer delta: 2 server | 2025/04/30 09:39:25 [debug] 22#0: posted event 000055882F5C0248 server | 2025/04/30 09:39:25 [debug] 22#0: *6 delete posted event 000055882F5C0248 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic push handler server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic state: read:29856 pto:321 server | 2025/04/30 09:39:25 [debug] 22#0: worker cycle server | 2025/04/30 09:39:25 [debug] 22#0: epoll timer: 65 server | 2025/04/30 09:39:25 [debug] 22#0: epoll: fd:6 ev:0001 d:00007FFBCCE83108 server | 2025/04/30 09:39:25 [debug] 22#0: quic recvmsg on 0.0.0.0:443, ready: 0 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic recvmsg: fd:6 n:1352 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic input handler server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic packet rx short flags:78 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic packet rx dcid len:20 0000000000002003de2ddac5b5d2859d37d852d7 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic packet rx clearflags:60 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic packet rx number:7 len:1 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic packet len:1352 via sock seq:0 path seq:0 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic path seq:0 status tx:11792 rx:4033 valid:1 st:2 mtu:1200 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic frame rx app:7 PING server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic frame rx app:7 PADDING server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic ngx_quic_ack_packet pn:7 largest 6 fr:1 nranges:0 server | 2025/04/30 09:39:25 [debug] 22#0: *6 post event 000055882F5C0248 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic packet done rc:0 level:app decr:1 pn:7 perr:0 server | 2025/04/30 09:39:25 [debug] 22#0: *6 event timer: 6, old: 364453, new: 364598 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic state: read:29855 pto:320 server | 2025/04/30 09:39:25 [debug] 22#0: timer delta: 1 server | 2025/04/30 09:39:25 [debug] 22#0: posted event 000055882F5C0248 server | 2025/04/30 09:39:25 [debug] 22#0: *6 delete posted event 000055882F5C0248 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic push handler server | 2025/04/30 09:39:25 [debug] 22#0: *6 event timer add: 6: 25:334623 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic state: read:29855 push:25 pto:320 server | 2025/04/30 09:39:25 [debug] 22#0: worker cycle server | 2025/04/30 09:39:25 [debug] 22#0: epoll timer: 25 server | 2025/04/30 09:39:25 [debug] 22#0: epoll: fd:6 ev:0001 d:00007FFBCCE83108 server | 2025/04/30 09:39:25 [debug] 22#0: quic recvmsg on 0.0.0.0:443, ready: 0 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic recvmsg: fd:6 n:54 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic input handler server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic packet rx short flags:5f server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic packet rx dcid len:20 0000000000002003de2ddac5b5d2859d37d852d7 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic packet rx clearflags:40 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic packet rx number:8 len:1 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic packet len:54 via sock seq:0 path seq:0 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic path seq:0 status tx:11792 rx:4087 valid:1 st:2 mtu:1200 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic frame rx app:8 ACK n:0 delay:40 10-0 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic ngx_quic_handle_ack_frame level:3 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic congestion slow start win:142795 ss:-1 if:0 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic stream id:0x0 ack len:370 fin:0 unacked:0 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic stream id:0x0 ack len:0 fin:1 unacked:0 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic stream id:0x0 close server | 2025/04/30 09:39:25 [debug] 22#0: *6 reusable connection: 1 server | 2025/04/30 09:39:25 [debug] 22#0: *6 post event 000055882F5C0248 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic updated largest received ack:10 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic rtt sample latest:36 min:33 avg:85 var:60 server | 2025/04/30 09:39:25 [debug] 22#0: *6 event timer del: 6: 334918 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic lost timer unset server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic frame rx app:8 CONNECTION_CLOSE_APP err:0 kthxbye! server | 2025/04/30 09:39:25 [debug] 22#0: *6 post event 000055882F5C0308 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic ngx_quic_ack_packet pn:8 largest 7 fr:2 nranges:0 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic packet done rc:0 level:app decr:1 pn:8 perr:0 server | 2025/04/30 09:39:25 [debug] 22#0: *6 event timer: 6, old: 364453, new: 364598 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic state: draining read:29855 push:25 server | 2025/04/30 09:39:25 [debug] 22#0: timer delta: 0 server | 2025/04/30 09:39:25 [debug] 22#0: posted event 000055882F5C0248 server | 2025/04/30 09:39:25 [debug] 22#0: *6 delete posted event 000055882F5C0248 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic push handler server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic output app packet max:1200 min:0 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic frame tx app:11 ACK n:0 delay:0 8-5 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic frame tx app:11 MAX_STREAMS limit:129 bidi:1 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic packet tx app bytes:8 need_ack:1 number:11 encoded nl:1 trunc:0xb server | 2025/04/30 09:39:25 [debug] 22#0: *6 sendmsg: 26 of 26 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic congestion send if:0 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic congestion send if:0 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic congestion send if:26 server | 2025/04/30 09:39:25 [debug] 22#0: *6 event timer: 6, old: 364453, new: 364598 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic lost timer pto:345 server | 2025/04/30 09:39:25 [debug] 22#0: *6 event timer add: 6: 345:334943 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic state: draining send:29855 push:25 pto:345 server | 2025/04/30 09:39:25 [debug] 22#0: posted event 000055882F5C0308 server | 2025/04/30 09:39:25 [debug] 22#0: *6 delete posted event 000055882F5C0308 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic close handler server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic close initiated rc:0 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic close immediate term:0 drain:1 error:1 "" server | 2025/04/30 09:39:25 [debug] 22#0: *6 event timer add: 6: 1035:335633 server | 2025/04/30 09:39:25 [debug] 22#0: *6 event timer del: 6: 334623 server | 2025/04/30 09:39:25 [debug] 22#0: *6 event timer del: 6: 334943 server | 2025/04/30 09:39:25 [debug] 22#0: *6 event timer del: 6: 334662 server | 2025/04/30 09:39:25 [debug] 22#0: worker cycle server | 2025/04/30 09:39:25 [debug] 22#0: epoll timer: 1035 client | 0.597 DEBUG [Client 0233a3281fbbec85] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.597 DEBUG Building Short dcid Some(CID [20]: 0000000000002003de2ddac5b5d2859d37d852d7) client | 0.597 DEBUG [Recvd-ap] immediate_ack at Instant { tv_sec: 334, tv_nsec: 614396590 } client | 0.597 DEBUG [Client 0233a3281fbbec85] pn=9 type=Short pri-path:0000000000002003de2ddac5b5d2859d37d852d7 0.0.0.0:40520->193.167.100.100:443 IpTos(Cs0, NotEct) len 55 client | TX -> Ack { largest_acknowledged: 10, ack_delay: 4010, first_ack_range: 10, ack_ranges: [], ecn_count: None } client | TX -> ConnectionClose { error_code: Application(0), frame_type: 0, reason_phrase: "kthxbye!" } client | 0.597 DEBUG Setting timeout of 264.901038ms client | 0.597 DEBUG Setting timeout of 264.890167ms server | 2025/04/30 09:39:25 [debug] 22#0: epoll: fd:6 ev:0001 d:00007FFBCCE83108 server | 2025/04/30 09:39:25 [debug] 22#0: quic recvmsg on 0.0.0.0:443, ready: 0 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic recvmsg: fd:6 n:55 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic input handler server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic packet rx short flags:51 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic packet rx dcid len:20 0000000000002003de2ddac5b5d2859d37d852d7 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic packet rx clearflags:40 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic packet rx number:9 len:1 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic packet len:55 via sock seq:0 path seq:0 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic path seq:0 status tx:11818 rx:4142 valid:1 st:2 mtu:1200 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic packet done rc:0 level:app decr:1 pn:9 perr:0 server | 2025/04/30 09:39:25 [debug] 22#0: *6 event timer: 6, old: 364453, new: 364629 server | 2025/04/30 09:39:25 [debug] 22#0: *6 quic state: error:0 "connection is closing, packet discarded" closing draining read:29824 close:1004 server | 2025/04/30 09:39:25 [debug] 22#0: timer delta: 31 server | 2025/04/30 09:39:25 [debug] 22#0: worker cycle server | 2025/04/30 09:39:25 [debug] 22#0: epoll timer: 1004 client | 0.863 DEBUG [Client 0233a3281fbbec85] State change from Closing { error: Application(0), timeout: Instant { tv_sec: 334, tv_nsec: 879409580 } } -> Closed(Application(0)) client | 0.863 INFO Closing timer expired client | 0.863 DEBUG Output::None client | 0.863 WARN Unhandled event StateChange(Closed(Application(0))) client | 0.863 DEBUG Timer fired while closed client | 0.863 DEBUG Output::None client exited with code 0 Aborting on container exit... Container client Stopping Container server Stopping Container client Stopped Container server Stopped Container sim Stopping Container sim Stopped 2025-04-30 09:39:35,859 Using the client's key log file. 2025-04-30 09:39:35,869 2025-04-30 09:39:35,869 Using the client's key log file. 2025-04-30 09:39:35,869 Using the client's key log file. 2025-04-30 09:39:35,878 2025-04-30 09:39:35,878 Using the client's key log file. 2025-04-30 09:39:35,878 Using the client's key log file. 2025-04-30 09:39:36,725 Check of downloaded files succeeded.