2025-04-30 09:39:09,314 Generated random file: hmmczrvgta of size: 10240
2025-04-30 09:39:09,314 Requests: https://server4:443/hmmczrvgta
2025-04-30 09:39:09,373 
2025-04-30 09:39:09,373 Command: WAITFORSERVER=server:443 CERTS=/tmp/certs_3p8it250/ TESTCASE_SERVER=retry TESTCASE_CLIENT=retry WWW=/tmp/www_2y9bcn9o/ DOWNLOADS=/tmp/download_n2g_zk5d/ SERVER_LOGS=/tmp/logs_server_w42n0d60 CLIENT_LOGS=/tmp/logs_client_ym_lvpx7 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/hmmczrvgta"  docker compose --env-file empty.env up --abort-on-container-exit --timeout 1 sim client server 
2025-04-30 09:39:21,682  Container sim  Created
 Container server  Recreate
 Container client  Recreate
 Container server  Recreated
 Container client  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
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
server  | >>> Starting nginx server...
client  | Endpoint's IPv4 address is 193.167.0.100
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: retry
client  | Endpoint's IPv6 address is fd00:cafe:cafe::100
server  | 2025/04/30 09:39:09 [debug] 21#0: bind() 0.0.0.0:443 #5 
server  | 2025/04/30 09:39:09 [debug] 21#0: bind() 0.0.0.0:443 #6 
server  | 2025/04/30 09:39:09 [debug] 21#0: bind() [::]:443 #7 
server  | 2025/04/30 09:39:09 [debug] 21#0: bind() [::]:443 #8 
server  | 2025/04/30 09:39:09 [debug] 21#0: add cleanup: 0000555A885B9780
server  | 2025/04/30 09:39:09 [notice] 21#0: using the "epoll" event method
server  | 2025/04/30 09:39:09 [debug] 21#0: counter: 00007FE76C89F080, 1
server  | 2025/04/30 09:39:09 [notice] 21#0: nginx/1.27.0 (9270:d1b8568f3042)
server  | 2025/04/30 09:39:09 [notice] 21#0: built by gcc 9.4.0 (Ubuntu 9.4.0-1ubuntu1~20.04.2) 
server  | 2025/04/30 09:39:09 [notice] 21#0: OS: Linux 6.11.0-1012-azure
server  | 2025/04/30 09:39:09 [notice] 21#0: getrlimit(RLIMIT_NOFILE): 1048576:1048576
server  | 2025/04/30 09:39:09 [debug] 21#0: write: 9, 00007FFDF88F7890, 3, 0
server  | 2025/04/30 09:39:09 [debug] 21#0: setproctitle: "nginx: master process /usr/sbin/nginx -c /etc/nginx/nginx.conf.retry"
server  | 2025/04/30 09:39:09 [notice] 21#0: start worker processes
server  | 2025/04/30 09:39:09 [debug] 21#0: channel 3:9
server  | 2025/04/30 09:39:09 [notice] 21#0: start worker process 22
server  | 2025/04/30 09:39:09 [debug] 21#0: sigsuspend
server  | 2025/04/30 09:39:09 [debug] 22#0: add cleanup: 0000555A885B9808
server  | 2025/04/30 09:39:09 [debug] 22#0: malloc: 0000555A885BC7D0:16
client  | + export PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/neqo/bin
server  | 2025/04/30 09:39:09 [debug] 22#0: add cleanup: 0000555A885B9820
client  | + PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/neqo/bin
client  | + '[' -n retry ']'
server  | 2025/04/30 09:39:09 [debug] 22#0: malloc: 0000555A885BAAD0:16
server  | 2025/04/30 09:39:09 [debug] 22#0: notify eventfd: 11
server  | 2025/04/30 09:39:09 [debug] 22#0: testing the EPOLLRDHUP flag: success
server  | 2025/04/30 09:39:09 [debug] 22#0: malloc: 0000555A885A2430:6144
server  | 2025/04/30 09:39:09 [debug] 22#0: malloc: 00007FE76C211010:253952
client  | + '[' -n /logs/qlog/ ']'
client  | + case "$ROLE" in
client  | + /wait-for-it.sh sim:57832 -s -t 30
server  | 2025/04/30 09:39:09 [debug] 22#0: malloc: 0000555A885BE890:98304
server  | 2025/04/30 09:39:09 [debug] 22#0: malloc: 0000555A885D68A0:98304
server  | 2025/04/30 09:39:09 [debug] 22#0: epoll add event: fd:5 op:1 ev:00002001
server  | 2025/04/30 09:39:09 [debug] 22#0: epoll add event: fd:6 op:1 ev:00002001
server  | 2025/04/30 09:39:09 [debug] 22#0: epoll add event: fd:7 op:1 ev:00002001
server  | 2025/04/30 09:39:09 [debug] 22#0: epoll add event: fd:8 op:1 ev:00002001
server  | 2025/04/30 09:39:09 [debug] 22#0: epoll add event: fd:9 op:1 ev:00002001
server  | 2025/04/30 09:39:09 [debug] 22#0: setproctitle: "nginx: worker process"
server  | 2025/04/30 09:39:09 [debug] 22#0: worker cycle
server  | 2025/04/30 09:39:09 [debug] 22#0: epoll timer: -1
client  | wait-for-it.sh: waiting 30 seconds for sim:57832
server  | 2025/04/30 09:39:10 [debug] 22#0: epoll: fd:6 ev:0001 d:00007FE76C211108
server  | 2025/04/30 09:39:10 [debug] 22#0: quic recvmsg on 0.0.0.0:443, ready: 0
server  | 2025/04/30 09:39:10 [debug] 22#0: posix_memalign: 0000555A885BAB30:512 @16
server  | 2025/04/30 09:39:10 [debug] 22#0: malloc: 0000555A885BC7F0:1207
server  | 2025/04/30 09:39:10 [debug] 22#0: *1 quic recvmsg: 193.167.100.2:43480 fd:6 n:1207
server  | 2025/04/30 09:39:10 [debug] 22#0: *1 quic run
server  | 2025/04/30 09:39:10 [debug] 22#0: *1 quic packet rx long flags:c0 version:57414954
server  | 2025/04/30 09:39:10 [debug] 22#0: *1 quic packet rx dcid len:0 
server  | 2025/04/30 09:39:10 [debug] 22#0: *1 quic packet rx scid len:0 
server  | 2025/04/30 09:39:10 [debug] 22#0: *1 quic address validation token len:0 
server  | 2025/04/30 09:39:10 [debug] 22#0: *1 sending version negotiation packet
sim     | server:443 is available after 1.06003101s
server  | 2025/04/30 09:39:10 [debug] 22#0: *1 sendmsg: 11 of 11
server  | 2025/04/30 09:39:10 [debug] 22#0: *1 quic packet done rc:-4 level:init decr:0 pn:0 perr:0
server  | 2025/04/30 09:39:10 [debug] 22#0: *1 quic packet rejected rc:-4, cleanup connection
server  | 2025/04/30 09:39:10 [debug] 22#0: *1 reusable connection: 0
server  | 2025/04/30 09:39:10 [debug] 22#0: *1 free: 0000555A885BC7F0
server  | 2025/04/30 09:39:10 [debug] 22#0: *1 free: 0000555A885BAB30, unused: 24
server  | 2025/04/30 09:39:10 [debug] 22#0: timer delta: 847
server  | 2025/04/30 09:39:10 [debug] 22#0: worker cycle
server  | 2025/04/30 09:39:10 [debug] 22#0: epoll timer: -1
server  | 2025/04/30 09:39:10 [debug] 22#0: epoll: fd:6 ev:0001 d:00007FE76C211108
server  | 2025/04/30 09:39:10 [debug] 22#0: quic recvmsg on 0.0.0.0:443, ready: 0
server  | 2025/04/30 09:39:10 [debug] 22#0: posix_memalign: 0000555A885BAB30:512 @16
server  | 2025/04/30 09:39:10 [debug] 22#0: malloc: 0000555A885BC7F0:1207
server  | 2025/04/30 09:39:10 [debug] 22#0: *2 quic recvmsg: 193.167.100.2:43480 fd:6 n:1207
server  | 2025/04/30 09:39:10 [debug] 22#0: *2 quic run
server  | 2025/04/30 09:39:10 [debug] 22#0: *2 quic packet rx long flags:c0 version:57414954
server  | 2025/04/30 09:39:10 [debug] 22#0: *2 quic packet rx dcid len:0 
server  | 2025/04/30 09:39:10 [debug] 22#0: *2 quic packet rx scid len:0 
server  | 2025/04/30 09:39:10 [debug] 22#0: *2 quic address validation token len:0 
server  | 2025/04/30 09:39:10 [debug] 22#0: *2 sending version negotiation packet
server  | 2025/04/30 09:39:10 [debug] 22#0: *2 sendmsg: 11 of 11
server  | 2025/04/30 09:39:10 [debug] 22#0: *2 quic packet done rc:-4 level:init decr:0 pn:0 perr:0
server  | 2025/04/30 09:39:10 [debug] 22#0: *2 quic packet rejected rc:-4, cleanup connection
server  | 2025/04/30 09:39:10 [debug] 22#0: *2 reusable connection: 0
server  | 2025/04/30 09:39:10 [debug] 22#0: *2 free: 0000555A885BC7F0
server  | 2025/04/30 09:39:10 [debug] 22#0: *2 free: 0000555A885BAB30, unused: 24
server  | 2025/04/30 09:39:10 [debug] 22#0: timer delta: 0
server  | 2025/04/30 09:39:10 [debug] 22#0: worker cycle
server  | 2025/04/30 09:39:10 [debug] 22#0: epoll timer: -1
server  | 2025/04/30 09:39:10 [debug] 22#0: epoll: fd:6 ev:0001 d:00007FE76C211108
server  | 2025/04/30 09:39:10 [debug] 22#0: quic recvmsg on 0.0.0.0:443, ready: 0
server  | 2025/04/30 09:39:10 [debug] 22#0: posix_memalign: 0000555A885BAB30:512 @16
server  | 2025/04/30 09:39:10 [debug] 22#0: malloc: 0000555A885BC7F0:1207
server  | 2025/04/30 09:39:10 [debug] 22#0: *3 quic recvmsg: 193.167.100.2:43480 fd:6 n:1207
server  | 2025/04/30 09:39:10 [debug] 22#0: *3 quic run
server  | 2025/04/30 09:39:10 [debug] 22#0: *3 quic packet rx long flags:c0 version:57414954
server  | 2025/04/30 09:39:10 [debug] 22#0: *3 quic packet rx dcid len:0 
server  | 2025/04/30 09:39:10 [debug] 22#0: *3 quic packet rx scid len:0 
server  | 2025/04/30 09:39:10 [debug] 22#0: *3 quic address validation token len:0 
server  | 2025/04/30 09:39:10 [debug] 22#0: *3 sending version negotiation packet
server  | 2025/04/30 09:39:10 [debug] 22#0: *3 sendmsg: 11 of 11
server  | 2025/04/30 09:39:10 [debug] 22#0: *3 quic packet done rc:-4 level:init decr:0 pn:0 perr:0
server  | 2025/04/30 09:39:10 [debug] 22#0: *3 quic packet rejected rc:-4, cleanup connection
server  | 2025/04/30 09:39:10 [debug] 22#0: *3 reusable connection: 0
server  | 2025/04/30 09:39:10 [debug] 22#0: *3 free: 0000555A885BC7F0
server  | 2025/04/30 09:39:10 [debug] 22#0: *3 free: 0000555A885BAB30, unused: 24
server  | 2025/04/30 09:39:10 [debug] 22#0: timer delta: 0
server  | 2025/04/30 09:39:10 [debug] 22#0: worker cycle
server  | 2025/04/30 09:39:10 [debug] 22#0: epoll timer: -1
sim     | Using scenario: simple-p2p --delay=15ms --bandwidth=10Mbps --queue=25
sim     | tcpdump: listening on eth1, link-type EN10MB (Ethernet), snapshot length 262144 bytes
sim     | tcpdump: listening on eth0, 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/hmmczrvgta ']'
client  | + mapfile -d ' ' -t URLS
client  | + OPTIONS+=("${URLS[@]}")
client  | + RUST_LOG=debug
client  | + RUST_BACKTRACE=1
client  | + neqo-client --cc cubic --qns-test retry --qlog-dir /logs/qlog/ --output-dir /downloads 'https://server4:443/hmmczrvgta
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:46696 -> 193.167.100.100:443
client  | 0.001 DEBUG [CryptoStates] Creating initial cipher state v=Version1, role=Client dcid=9d08d5a9a63faab47bd435f7aec130267c
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:46696->193.167.100.100:443] Make permanent
client  | 0.001 DEBUG [unv-path:9d08d5a9a63faab47bd435f7aec130267c 0.0.0.0:46696->193.167.100.100:443] set as primary path
client  | 0.001 DEBUG [pri-unv-path:9d08d5a9a63faab47bd435f7aec130267c 0.0.0.0:46696->193.167.100.100:443] Path validated Instant { tv_sec: 320, tv_nsec: 383602425 }
client  | 0.001 DEBUG [Client 9d08d5a9a63faab47bd435f7aec130267c] client_start
client  | 0.001 DEBUG Writing transport parameters, msg=1
client  | 0.001 DEBUG [Agent 0x55a08ab67270] state -> InProgress
client  | 0.002 DEBUG [Client 9d08d5a9a63faab47bd435f7aec130267c] State change from Init -> WaitInitial
client  | 0.002 DEBUG [Client 9d08d5a9a63faab47bd435f7aec130267c] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.002 DEBUG Building Initial dcid Some(CID [17]: 9d08d5a9a63faab47bd435f7aec130267c) scid Some(CID [0]: )
client  | 0.002 DEBUG CRYPTO for in offset=0, len=1204
client  | 0.002 DEBUG [Client 9d08d5a9a63faab47bd435f7aec130267c] pn=0 type=Initial pri-path:9d08d5a9a63faab47bd435f7aec130267c 0.0.0.0:46696->193.167.100.100:443 IpTos(Cs0, Ect0) len 1252
client  |   TX -> Crypto { offset: 0, len: 1204 }
client  | 0.002 DEBUG packet_sent this=0x55a08ab7a970, pn=0, ps=1252
client  | 0.002 DEBUG ECN probing: sent 1 probes
client  | 0.002 DEBUG [Client 9d08d5a9a63faab47bd435f7aec130267c] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.002 DEBUG Building Initial dcid Some(CID [17]: 9d08d5a9a63faab47bd435f7aec130267c) scid Some(CID [0]: )
client  | 0.002 DEBUG CRYPTO for in offset=1204, len=335
client  | 0.002 DEBUG [Client 9d08d5a9a63faab47bd435f7aec130267c] pn=1 type=Initial pri-path:9d08d5a9a63faab47bd435f7aec130267c 0.0.0.0:46696->193.167.100.100:443 IpTos(Cs0, Ect0) len 384
client  |   TX -> Crypto { offset: 1204, len: 335 }
client  | 0.002 DEBUG [Client 9d08d5a9a63faab47bd435f7aec130267c] pad Initial from 384 to PLPMTU 1252
client  | 0.002 DEBUG packet_sent this=0x55a08ab7a970, pn=1, ps=1252
client  | 0.002 DEBUG ECN probing: sent 2 probes
client  | 0.002 DEBUG [Client 9d08d5a9a63faab47bd435f7aec130267c] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
client  | 0.002 DEBUG Building Initial dcid Some(CID [17]: 9d08d5a9a63faab47bd435f7aec130267c) 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 9d08d5a9a63faab47bd435f7aec130267c] delay duration 3.897982ms
client  | 0.002 DEBUG Setting timeout of 3.897982ms
client  | 0.002 DEBUG StateChange(WaitInitial)
client  | 0.002 WARN Cannot create stream ConnectionState
client  | 0.002 DEBUG [Client 9d08d5a9a63faab47bd435f7aec130267c] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
client  | 0.002 DEBUG Building Initial dcid Some(CID [17]: 9d08d5a9a63faab47bd435f7aec130267c) 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 9d08d5a9a63faab47bd435f7aec130267c] delay duration 3.868587ms
client  | 0.002 DEBUG Setting timeout of 3.868587ms
client  | 0.007 DEBUG [Client 9d08d5a9a63faab47bd435f7aec130267c] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.007 DEBUG Building Initial dcid Some(CID [17]: 9d08d5a9a63faab47bd435f7aec130267c) 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 9d08d5a9a63faab47bd435f7aec130267c] delay duration 294.821353ms
client  | 0.007 DEBUG Setting timeout of 294.821353ms
server  | 2025/04/30 09:39:10 [debug] 22#0: epoll: fd:6 ev:0001 d:00007FE76C211108
server  | 2025/04/30 09:39:10 [debug] 22#0: quic recvmsg on 0.0.0.0:443, ready: 0
server  | 2025/04/30 09:39:10 [debug] 22#0: posix_memalign: 0000555A885BAB30:512 @16
server  | 2025/04/30 09:39:10 [debug] 22#0: malloc: 0000555A885BC7F0:1252
server  | 2025/04/30 09:39:10 [debug] 22#0: *4 quic recvmsg: 193.167.0.100:46696 fd:6 n:1252
server  | 2025/04/30 09:39:10 [debug] 22#0: *4 quic run
server  | 2025/04/30 09:39:10 [debug] 22#0: *4 quic packet rx long flags:cc version:1
server  | 2025/04/30 09:39:10 [debug] 22#0: *4 quic packet rx init len:1225
server  | 2025/04/30 09:39:10 [debug] 22#0: *4 quic packet rx dcid len:17 9d08d5a9a63faab47bd435f7aec130267c
server  | 2025/04/30 09:39:10 [debug] 22#0: *4 quic packet rx scid len:0 
server  | 2025/04/30 09:39:10 [debug] 22#0: *4 quic address validation token len:0 
server  | 2025/04/30 09:39:10 [debug] 22#0: *4 sendmsg: 118 of 118
server  | 2025/04/30 09:39:10 [debug] 22#0: *4 quic retry packet sent to 
server  | 2025/04/30 09:39:10 [debug] 22#0: *4 quic packet done rc:-4 level:init decr:0 pn:0 perr:0
server  | 2025/04/30 09:39:10 [debug] 22#0: *4 quic packet rejected rc:-4, cleanup connection
server  | 2025/04/30 09:39:10 [debug] 22#0: *4 reusable connection: 0
server  | 2025/04/30 09:39:10 [debug] 22#0: *4 free: 0000555A885BC7F0
server  | 2025/04/30 09:39:10 [debug] 22#0: *4 free: 0000555A885BAB30, unused: 24
server  | 2025/04/30 09:39:10 [debug] 22#0: timer delta: 197
server  | 2025/04/30 09:39:10 [debug] 22#0: worker cycle
server  | 2025/04/30 09:39:10 [debug] 22#0: epoll timer: -1
server  | 2025/04/30 09:39:10 [debug] 22#0: epoll: fd:6 ev:0001 d:00007FE76C211108
server  | 2025/04/30 09:39:10 [debug] 22#0: quic recvmsg on 0.0.0.0:443, ready: 0
server  | 2025/04/30 09:39:10 [debug] 22#0: posix_memalign: 0000555A885BAB30:512 @16
server  | 2025/04/30 09:39:10 [debug] 22#0: malloc: 0000555A885BC7F0:1252
server  | 2025/04/30 09:39:10 [debug] 22#0: *5 quic recvmsg: 193.167.0.100:46696 fd:6 n:1252
server  | 2025/04/30 09:39:10 [debug] 22#0: *5 quic run
server  | 2025/04/30 09:39:10 [debug] 22#0: *5 quic packet rx long flags:cd version:1
server  | 2025/04/30 09:39:10 [debug] 22#0: *5 quic packet rx init len:357
server  | 2025/04/30 09:39:10 [debug] 22#0: *5 quic packet rx dcid len:17 9d08d5a9a63faab47bd435f7aec130267c
server  | 2025/04/30 09:39:10 [debug] 22#0: *5 quic packet rx scid len:0 
server  | 2025/04/30 09:39:10 [debug] 22#0: *5 quic address validation token len:0 
server  | 2025/04/30 09:39:10 [debug] 22#0: *5 sendmsg: 118 of 118
server  | 2025/04/30 09:39:10 [debug] 22#0: *5 quic retry packet sent to 
server  | 2025/04/30 09:39:10 [debug] 22#0: *5 quic packet done rc:-4 level:init decr:0 pn:0 perr:0
server  | 2025/04/30 09:39:10 [debug] 22#0: *5 quic packet rejected rc:-4, cleanup connection
server  | 2025/04/30 09:39:10 [debug] 22#0: *5 reusable connection: 0
server  | 2025/04/30 09:39:10 [debug] 22#0: *5 free: 0000555A885BC7F0
server  | 2025/04/30 09:39:10 [debug] 22#0: *5 free: 0000555A885BAB30, unused: 24
server  | 2025/04/30 09:39:10 [debug] 22#0: timer delta: 1
server  | 2025/04/30 09:39:10 [debug] 22#0: worker cycle
server  | 2025/04/30 09:39:10 [debug] 22#0: epoll timer: -1
client  | 0.039 INFO [Client 9d08d5a9a63faab47bd435f7aec130267c] received Retry
client  | 0.039 INFO [Client 9d08d5a9a63faab47bd435f7aec130267c] Valid Retry received, token=31ca79d51f7af89abcea27b28efe94375ec1ff96ec54927b40195972b2eb4ea8a35c0b7cfc597c1e02395a6ef1bc4e9e9a0144c41e8ab840e187cb8697e6bb87b8da79185aa459b8c5720b scid=c120bf1d397593708b1125b44b7b32a8cd3d832e
client  | 0.039 INFO [pri-path:c120bf1d397593708b1125b44b7b32a8cd3d832e 0.0.0.0:46696->193.167.100.100:443] discarding a packet without an RTT estimate; guessing RTT=37.362755ms
client  | 0.039 DEBUG [Client 9d08d5a9a63faab47bd435f7aec130267c] Lost: Crypto(CryptoRecoveryToken { space: Initial, offset: 0, length: 1204 })
client  | 0.039 INFO Lost crypto frame space=in offset=0 length=1204
client  | 0.039 DEBUG [Client 9d08d5a9a63faab47bd435f7aec130267c] Lost: EcnEct0
client  | 0.039 DEBUG [Client 9d08d5a9a63faab47bd435f7aec130267c] Lost: Crypto(CryptoRecoveryToken { space: Initial, offset: 1204, length: 335 })
client  | 0.039 INFO Lost crypto frame space=in offset=1204 length=335
client  | 0.039 DEBUG [Client 9d08d5a9a63faab47bd435f7aec130267c] Lost: EcnEct0
client  | 0.039 DEBUG [CryptoStates] Creating initial cipher state v=Version1, role=Client dcid=c120bf1d397593708b1125b44b7b32a8cd3d832e
client  | 0.039 DEBUG Making Write Initial CryptoDxState, v=Version1 cipher=4865
client  | 0.039 DEBUG Making Read Initial CryptoDxState, v=Version1 cipher=4865
client  | 0.039 INFO [CryptoStates] Continue packet numbers for initial after retry (write is 0..0)
client  | 0.039 DEBUG [Client 9d08d5a9a63faab47bd435f7aec130267c] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.039 DEBUG Building Initial dcid Some(CID [20]: c120bf1d397593708b1125b44b7b32a8cd3d832e) scid Some(CID [0]: )
client  | 0.039 DEBUG CRYPTO for in offset=0, len=1125
client  | 0.039 DEBUG [Client 9d08d5a9a63faab47bd435f7aec130267c] pn=2 type=Initial pri-path:c120bf1d397593708b1125b44b7b32a8cd3d832e 0.0.0.0:46696->193.167.100.100:443 IpTos(Cs0, Ect0) len 1252
client  |   TX -> Crypto { offset: 0, len: 1125 }
client  | 0.039 DEBUG packet_sent this=0x55a08ab7a970, pn=2, ps=1252
client  | 0.039 DEBUG ECN probing: sent 3 probes
client  | 0.039 DEBUG [Client 9d08d5a9a63faab47bd435f7aec130267c] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.039 DEBUG Building Initial dcid Some(CID [20]: c120bf1d397593708b1125b44b7b32a8cd3d832e) scid Some(CID [0]: )
client  | 0.039 DEBUG CRYPTO for in offset=1125, len=414
client  | 0.039 DEBUG [Client 9d08d5a9a63faab47bd435f7aec130267c] pn=3 type=Initial pri-path:c120bf1d397593708b1125b44b7b32a8cd3d832e 0.0.0.0:46696->193.167.100.100:443 IpTos(Cs0, Ect0) len 542
client  |   TX -> Crypto { offset: 1125, len: 414 }
client  | 0.039 DEBUG [Client 9d08d5a9a63faab47bd435f7aec130267c] pad Initial from 542 to PLPMTU 1252
client  | 0.039 DEBUG packet_sent this=0x55a08ab7a970, pn=3, ps=1252
client  | 0.039 DEBUG ECN probing: sent 4 probes
client  | 0.039 DEBUG [Client 9d08d5a9a63faab47bd435f7aec130267c] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.039 DEBUG Building Initial dcid Some(CID [20]: c120bf1d397593708b1125b44b7b32a8cd3d832e) 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 9d08d5a9a63faab47bd435f7aec130267c] delay duration 111.957249ms
client  | 0.039 DEBUG Setting timeout of 111.957249ms
client  | 0.039 INFO [Client 9d08d5a9a63faab47bd435f7aec130267c] received Retry
client  | 0.039 WARN [Client ...] Dropped received packet: Extra Retry; Total: 1
client  | 0.039 DEBUG [Client 9d08d5a9a63faab47bd435f7aec130267c] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.039 DEBUG Building Initial dcid Some(CID [20]: c120bf1d397593708b1125b44b7b32a8cd3d832e) 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 9d08d5a9a63faab47bd435f7aec130267c] delay duration 111.912605ms
client  | 0.039 DEBUG Setting timeout of 111.912605ms
client  | 0.039 DEBUG [Client 9d08d5a9a63faab47bd435f7aec130267c] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.039 DEBUG Building Initial dcid Some(CID [20]: c120bf1d397593708b1125b44b7b32a8cd3d832e) 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 9d08d5a9a63faab47bd435f7aec130267c] delay duration 111.865677ms
client  | 0.039 DEBUG Setting timeout of 111.865677ms
server  | 2025/04/30 09:39:10 [debug] 22#0: epoll: fd:6 ev:0001 d:00007FE76C211108
server  | 2025/04/30 09:39:10 [debug] 22#0: quic recvmsg on 0.0.0.0:443, ready: 0
server  | 2025/04/30 09:39:10 [debug] 22#0: posix_memalign: 0000555A885BAB30:512 @16
server  | 2025/04/30 09:39:10 [debug] 22#0: malloc: 0000555A885BC7F0:1252
server  | 2025/04/30 09:39:10 [debug] 22#0: *6 quic recvmsg: 193.167.0.100:46696 fd:6 n:1252
server  | 2025/04/30 09:39:10 [debug] 22#0: *6 quic run
server  | 2025/04/30 09:39:10 [debug] 22#0: *6 quic packet rx long flags:c8 version:1
server  | 2025/04/30 09:39:10 [debug] 22#0: *6 quic packet rx init len:1146
server  | 2025/04/30 09:39:10 [debug] 22#0: *6 quic packet rx dcid len:20 c120bf1d397593708b1125b44b7b32a8cd3d832e
server  | 2025/04/30 09:39:10 [debug] 22#0: *6 quic packet rx scid len:0 
server  | 2025/04/30 09:39:10 [debug] 22#0: *6 quic address validation token len:75 31ca79d51f7af89abcea27b28efe94375ec1ff96ec54927b40195972b2eb4ea8a35c0b7cfc597c1e02395a6ef1bc4e9e9a0144c41e8ab840e187cb8697e6bb87b8da79185aa459b8c5720b
server  | 2025/04/30 09:39:10 [debug] 22#0: *6 malloc: 0000555A885A3EA0:2448
server  | 2025/04/30 09:39:10 [debug] 22#0: *6 malloc: 0000555A885A4840:1528
server  | 2025/04/30 09:39:10 [debug] 22#0: *6 posix_memalign: 0000555A885A4E40:512 @16
server  | 2025/04/30 09:39:10 [debug] 22#0: *6 quic ngx_quic_set_initial_secret
server  | 2025/04/30 09:39:10 [debug] 22#0: *6 quic socket seq:0 listening at sid:00000000000020026fcefba6ae8b3b98c592f6ab nsock:1
server  | 2025/04/30 09:39:10 [debug] 22#0: *6 quic cid seq:0 received id:0::00000000000000000000000000000000
server  | 2025/04/30 09:39:10 [debug] 22#0: *6 posix_memalign: 0000555A885979A0:512 @16
server  | 2025/04/30 09:39:10 [debug] 22#0: *6 quic path seq:0 created addr:193.167.0.100:46696
server  | 2025/04/30 09:39:10 [debug] 22#0: *6 quic path seq:0 set active tx:0 rx:0 valid:1 st:0 mtu:1200
server  | 2025/04/30 09:39:10 [debug] 22#0: *6 posix_memalign: 0000555A88597BB0:512 @16
server  | 2025/04/30 09:39:10 [debug] 22#0: *6 quic socket seq:-1 listening at sid:c120bf1d397593708b1125b44b7b32a8cd3d832e nsock:2
server  | 2025/04/30 09:39:10 [debug] 22#0: *6 reusable connection: 1
server  | 2025/04/30 09:39:10 [debug] 22#0: *6 quic connection created
server  | 2025/04/30 09:39:10 [debug] 22#0: *6 quic packet rx clearflags:c0
server  | 2025/04/30 09:39:10 [debug] 22#0: *6 quic packet rx number:2 len:1
server  | 2025/04/30 09:39:10 [debug] 22#0: *6 quic packet len:1252 via sock seq:0 path seq:0
server  | 2025/04/30 09:39:10 [debug] 22#0: *6 quic path seq:0 status tx:0 rx:1252 valid:1 st:0 mtu:1200
server  | 2025/04/30 09:39:10 [debug] 22#0: *6 quic stateless reset token a3b4bd481ea027907a54358de328e183
server  | 2025/04/30 09:39:10 [debug] 22#0: *6 posix_memalign: 0000555A88598CE0:512 @16
server  | 2025/04/30 09:39:10 [debug] 22#0: *6 quic frame rx init:2 CRYPTO len:1125 off:0
server  | 2025/04/30 09:39:10 [debug] 22#0: *6 SSL_do_handshake: -1
server  | 2025/04/30 09:39:10 [debug] 22#0: *6 SSL_get_error: 2
server  | 2025/04/30 09:39:10 [debug] 22#0: *6 quic ngx_quic_ack_packet pn:2 largest -1 fr:0 nranges:0
server  | 2025/04/30 09:39:10 [debug] 22#0: *6 post event 0000555A885A44A8
server  | 2025/04/30 09:39:10 [debug] 22#0: *6 quic packet done rc:0 level:init decr:1 pn:2 perr:0
server  | 2025/04/30 09:39:10 [debug] 22#0: *6 event timer add: 6: 75000:395438
server  | 2025/04/30 09:39:10 [debug] 22#0: *6 event timer add: 6: 60000:380438
server  | 2025/04/30 09:39:10 [debug] 22#0: *6 quic state: read:75000 close:60000
server  | 2025/04/30 09:39:10 [debug] 22#0: timer delta: 32
server  | 2025/04/30 09:39:10 [debug] 22#0: posted event 0000555A885A44A8
server  | 2025/04/30 09:39:10 [debug] 22#0: *6 delete posted event 0000555A885A44A8
server  | 2025/04/30 09:39:10 [debug] 22#0: *6 quic push handler
server  | 2025/04/30 09:39:10 [debug] 22#0: *6 quic output init packet max:1200 min:0
server  | 2025/04/30 09:39:10 [debug] 22#0: *6 quic frame tx init:0 ACK n:0 delay:0 2
server  | 2025/04/30 09:39:10 [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:10 [debug] 22#0: *6 sendmsg: 51 of 51
server  | 2025/04/30 09:39:10 [debug] 22#0: *6 quic congestion send if:0
server  | 2025/04/30 09:39:10 [debug] 22#0: *6 quic congestion send if:0
server  | 2025/04/30 09:39:10 [debug] 22#0: *6 quic congestion send if:0
server  | 2025/04/30 09:39:10 [debug] 22#0: *6 quic state: read:75000 close:60000
server  | 2025/04/30 09:39:10 [debug] 22#0: worker cycle
server  | 2025/04/30 09:39:10 [debug] 22#0: epoll timer: 60000
server  | 2025/04/30 09:39:10 [debug] 22#0: epoll: fd:6 ev:0001 d:00007FE76C211108
server  | 2025/04/30 09:39:10 [debug] 22#0: quic recvmsg on 0.0.0.0:443, ready: 0
server  | 2025/04/30 09:39:10 [debug] 22#0: *6 quic recvmsg: fd:6 n:1252
server  | 2025/04/30 09:39:10 [debug] 22#0: *6 quic input handler
server  | 2025/04/30 09:39:10 [debug] 22#0: *6 quic packet rx long flags:c0 version:1
server  | 2025/04/30 09:39:10 [debug] 22#0: *6 quic packet rx init len:436
server  | 2025/04/30 09:39:10 [debug] 22#0: *6 quic packet rx dcid len:20 c120bf1d397593708b1125b44b7b32a8cd3d832e
server  | 2025/04/30 09:39:10 [debug] 22#0: *6 quic packet rx scid len:0 
server  | 2025/04/30 09:39:10 [debug] 22#0: *6 quic address validation token len:75 31ca79d51f7af89abcea27b28efe94375ec1ff96ec54927b40195972b2eb4ea8a35c0b7cfc597c1e02395a6ef1bc4e9e9a0144c41e8ab840e187cb8697e6bb87b8da79185aa459b8c5720b
server  | 2025/04/30 09:39:10 [debug] 22#0: *6 quic packet rx clearflags:c0
server  | 2025/04/30 09:39:10 [debug] 22#0: *6 quic packet rx number:3 len:1
server  | 2025/04/30 09:39:10 [debug] 22#0: *6 quic packet len:1252 via sock seq:-1 path seq:0
server  | 2025/04/30 09:39:10 [debug] 22#0: *6 quic path seq:0 status tx:51 rx:2504 valid:1 st:0 mtu:1200
server  | 2025/04/30 09:39:10 [debug] 22#0: *6 quic frame rx init:3 CRYPTO len:414 off:1125
server  | 2025/04/30 09:39:10 [debug] 22#0: *6 SSL server name: "server4"
server  | 2025/04/30 09:39:10 [debug] 22#0: *6 SSL ALPN supported by client: hq-interop
server  | 2025/04/30 09:39:10 [debug] 22#0: *6 SSL ALPN supported by client: JJ
server  | 2025/04/30 09:39:10 [debug] 22#0: *6 SSL ALPN selected: hq-interop
server  | 2025/04/30 09:39:10 [debug] 22#0: *6 quic ngx_quic_add_handshake_data
server  | 2025/04/30 09:39:10 [debug] 22#0: *6 quic SSL_get_peer_quic_transport_params(): params_len:79
server  | 2025/04/30 09:39:10 [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:10 [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:10 [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:10 [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:10 [debug] 22#0: *6 quic transport parameters parsed ok
server  | 2025/04/30 09:39:10 [debug] 22#0: *6 quic tp disable active migration: 0
server  | 2025/04/30 09:39:10 [debug] 22#0: *6 quic tp idle_timeout:30000
server  | 2025/04/30 09:39:10 [debug] 22#0: *6 quic tp max_udp_payload_size:65527
server  | 2025/04/30 09:39:10 [debug] 22#0: *6 quic tp max_data:4611686018427387903
server  | 2025/04/30 09:39:10 [debug] 22#0: *6 quic tp max_stream_data_bidi_local:1048576
server  | 2025/04/30 09:39:10 [debug] 22#0: *6 quic tp max_stream_data_bidi_remote:1048576
server  | 2025/04/30 09:39:10 [debug] 22#0: *6 quic tp max_stream_data_uni:1048576
server  | 2025/04/30 09:39:10 [debug] 22#0: *6 quic tp initial_max_streams_bidi:16
server  | 2025/04/30 09:39:10 [debug] 22#0: *6 quic tp initial_max_streams_uni:16
server  | 2025/04/30 09:39:10 [debug] 22#0: *6 quic tp ack_delay_exponent:3
server  | 2025/04/30 09:39:10 [debug] 22#0: *6 quic tp max_ack_delay:20
server  | 2025/04/30 09:39:10 [debug] 22#0: *6 quic tp active_connection_id_limit:8
server  | 2025/04/30 09:39:10 [debug] 22#0: *6 quic tp initial source_connection_id len:0 
server  | 2025/04/30 09:39:10 [debug] 22#0: *6 malloc: 0000555A88599E10:4096
server  | 2025/04/30 09:39:10 [debug] 22#0: *6 post event 0000555A885A44A8
server  | 2025/04/30 09:39:10 [debug] 22#0: *6 quic ngx_quic_set_write_secret() level:2
server  | 2025/04/30 09:39:10 [debug] 22#0: *6 quic ngx_quic_add_handshake_data
server  | 2025/04/30 09:39:10 [debug] 22#0: *6 malloc: 0000555A885EE8B0:4096
server  | 2025/04/30 09:39:10 [debug] 22#0: *6 posix_memalign: 0000555A8859C0C0:512 @16
server  | 2025/04/30 09:39:10 [debug] 22#0: *6 update posted event 0000555A885A44A8
server  | 2025/04/30 09:39:10 [debug] 22#0: *6 quic ngx_quic_set_write_secret() level:3
server  | 2025/04/30 09:39:10 [debug] 22#0: *6 quic ngx_quic_flush_flight()
server  | 2025/04/30 09:39:10 [debug] 22#0: *6 quic ngx_quic_set_read_secret() level:2
server  | 2025/04/30 09:39:10 [debug] 22#0: *6 SSL_do_handshake: -1
server  | 2025/04/30 09:39:10 [debug] 22#0: *6 SSL_get_error: 2
server  | 2025/04/30 09:39:10 [debug] 22#0: *6 quic ngx_quic_ack_packet pn:3 largest 2 fr:0 nranges:0
server  | 2025/04/30 09:39:10 [debug] 22#0: *6 update posted event 0000555A885A44A8
server  | 2025/04/30 09:39:10 [debug] 22#0: *6 quic packet done rc:0 level:init decr:1 pn:3 perr:0
server  | 2025/04/30 09:39:10 [debug] 22#0: *6 quic packet rx short flags:0
server  | 2025/04/30 09:39:10 [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:10 [debug] 22#0: *6 quic packet done rc:-5 parse failed
server  | 2025/04/30 09:39:10 [debug] 22#0: *6 event timer del: 6: 395438
server  | 2025/04/30 09:39:10 [debug] 22#0: *6 event timer add: 6: 30000:350439
server  | 2025/04/30 09:39:10 [debug] 22#0: *6 quic state: read:30000 close:59999
server  | 2025/04/30 09:39:10 [debug] 22#0: timer delta: 1
server  | 2025/04/30 09:39:10 [debug] 22#0: posted event 0000555A885A44A8
server  | 2025/04/30 09:39:10 [debug] 22#0: *6 delete posted event 0000555A885A44A8
server  | 2025/04/30 09:39:10 [debug] 22#0: *6 quic push handler
server  | 2025/04/30 09:39:10 [debug] 22#0: *6 quic output init packet max:1200 min:0
server  | 2025/04/30 09:39:10 [debug] 22#0: *6 quic frame tx init:1 ACK n:0 delay:0 3-2
server  | 2025/04/30 09:39:10 [debug] 22#0: *6 quic frame tx init:1 CRYPTO len:90 off:0
server  | 2025/04/30 09:39:10 [debug] 22#0: *6 quic packet tx init bytes:99 need_ack:1 number:1 encoded nl:1 trunc:0x1
server  | 2025/04/30 09:39:10 [debug] 22#0: *6 quic output hs packet max:1054 min:1054
server  | 2025/04/30 09:39:10 [debug] 22#0: *6 quic frame tx hs:0 CRYPTO len:749 off:0
server  | 2025/04/30 09:39:10 [debug] 22#0: *6 quic packet tx hs bytes:1008 need_ack:1 number:0 encoded nl:1 trunc:0x0
server  | 2025/04/30 09:39:10 [debug] 22#0: *6 sendmsg: 1200 of 1200
server  | 2025/04/30 09:39:10 [debug] 22#0: *6 quic congestion send if:146
server  | 2025/04/30 09:39:10 [debug] 22#0: *6 quic congestion send if:1200
server  | 2025/04/30 09:39:10 [debug] 22#0: *6 quic congestion send if:1200
server  | 2025/04/30 09:39:10 [debug] 22#0: *6 event timer: 6, old: 350439, new: 350439
server  | 2025/04/30 09:39:10 [debug] 22#0: *6 quic lost timer pto:997
server  | 2025/04/30 09:39:10 [debug] 22#0: *6 event timer add: 6: 997:321436
server  | 2025/04/30 09:39:10 [debug] 22#0: *6 quic state: send:30000 pto:997 close:59999
server  | 2025/04/30 09:39:10 [debug] 22#0: worker cycle
server  | 2025/04/30 09:39:10 [debug] 22#0: epoll timer: 997
client  | 0.071 DEBUG [Client 9d08d5a9a63faab47bd435f7aec130267c] pn=0 type=Initial pri-path:c120bf1d397593708b1125b44b7b32a8cd3d832e 0.0.0.0:46696->193.167.100.100:443 IpTos(Cs0, NotEct) len 51
client  |   -> RX Ack { largest_acknowledged: 2, ack_delay: 0, first_ack_range: 0, ack_ranges: [], ecn_count: None }
client  | 0.071 DEBUG [Client 9d08d5a9a63faab47bd435f7aec130267c] Rx ACK space=in, ranges=[2..=2]
client  | 0.071 DEBUG [LossRecovery] ACK for Initial - largest_acked=2
client  | 0.071 DEBUG on_packets_acked this=0x55a08ab7a970, limited=1, bytes_in_flight=1252, cwnd=12520, state=SlowStart, new_acked=1252
client  | 0.071 DEBUG Acked crypto frame space=in offset=0 length=1125
client  | 0.071 DEBUG [Client 9d08d5a9a63faab47bd435f7aec130267c] Changing to use Server CID=00000000000020026fcefba6ae8b3b98c592f6ab
client  | 0.071 DEBUG [Client 9d08d5a9a63faab47bd435f7aec130267c] State change from WaitInitial -> WaitVersion
client  | 0.071 DEBUG [Client 9d08d5a9a63faab47bd435f7aec130267c] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.071 DEBUG Building Initial dcid Some(CID [20]: 00000000000020026fcefba6ae8b3b98c592f6ab) scid Some(CID [0]: )
client  | 0.071 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.071 DEBUG [Client 9d08d5a9a63faab47bd435f7aec130267c] delay duration 65.990066ms
client  | 0.071 DEBUG Setting timeout of 65.990066ms
client  | 0.071 WARN Unhandled event StateChange(WaitVersion)
client  | 0.071 DEBUG [Client 9d08d5a9a63faab47bd435f7aec130267c] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.071 DEBUG Building Initial dcid Some(CID [20]: 00000000000020026fcefba6ae8b3b98c592f6ab) scid Some(CID [0]: )
client  | 0.071 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.071 DEBUG [Client 9d08d5a9a63faab47bd435f7aec130267c] delay duration 65.957666ms
client  | 0.071 DEBUG Setting timeout of 65.957666ms
client  | 0.074 DEBUG [Client 9d08d5a9a63faab47bd435f7aec130267c] pn=1 type=Initial pri-path:00000000000020026fcefba6ae8b3b98c592f6ab 0.0.0.0:46696->193.167.100.100:443 IpTos(Cs0, NotEct) len 146
client  |   -> RX Ack { largest_acknowledged: 3, ack_delay: 0, first_ack_range: 1, ack_ranges: [], ecn_count: None }
client  |   -> RX Crypto { offset: 0, len: 90 }
client  | 0.074 DEBUG [Client 9d08d5a9a63faab47bd435f7aec130267c] Rx ACK space=in, ranges=[2..=3]
client  | 0.074 DEBUG [LossRecovery] ACK for Initial - largest_acked=3
client  | 0.074 DEBUG on_packets_acked this=0x55a08ab7a970, limited=1, bytes_in_flight=0, cwnd=12520, state=SlowStart, new_acked=1252
client  | 0.074 DEBUG Acked crypto frame space=in offset=1125 length=414
client  | 0.074 DEBUG Read Ok(90) bytes
client  | 0.074 DEBUG Write secret available for Handshake: SymKey [32]: a9170817c39fba7010eddf48961732ade34ac87e1a8cd9c1e9c40af77b73649e
client  | 0.074 DEBUG Read secret available for Handshake: SymKey [32]: ab7533b74c2030d9ff73de58b491aba15905b0e9ba94e5fe768951af287fb782
client  | 0.074 DEBUG [Agent 0x55a08ab67270] state -> InProgress
client  | 0.074 DEBUG Making Write Handshake CryptoDxState, v=Version1 cipher=4865
client  | 0.074 DEBUG Making Read Handshake CryptoDxState, v=Version1 cipher=4865
client  | 0.074 DEBUG [Crypto] Handshake keys installed
client  | 0.074 DEBUG [Recvd-in] Set ACK timer to Instant { tv_sec: 320, tv_nsec: 456809619 }
client  | 0.074 DEBUG [Client 9d08d5a9a63faab47bd435f7aec130267c] State change from WaitVersion -> Handshaking
client  | 0.074 DEBUG [Client 9d08d5a9a63faab47bd435f7aec130267c] pn=0 type=Handshake pri-path:00000000000020026fcefba6ae8b3b98c592f6ab 0.0.0.0:46696->193.167.100.100:443 IpTos(Cs0, NotEct) len 1054
client  |   -> RX Crypto { offset: 0, len: 749 }
client  |   -> RX Padding { len: 255 }
client  | 0.074 DEBUG Read Ok(749) bytes
client  | 0.075 DEBUG [Agent 0x55a08ab67270] state -> AuthenticationPending
client  | 0.075 DEBUG [Recvd-hs] Set ACK timer to Instant { tv_sec: 320, tv_nsec: 456809619 }
client  | 0.075 DEBUG [Client 9d08d5a9a63faab47bd435f7aec130267c] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.075 DEBUG Building Initial dcid Some(CID [20]: 00000000000020026fcefba6ae8b3b98c592f6ab) scid Some(CID [0]: )
client  | 0.075 DEBUG [Client 9d08d5a9a63faab47bd435f7aec130267c] pn=4 type=Initial pri-path:00000000000020026fcefba6ae8b3b98c592f6ab 0.0.0.0:46696->193.167.100.100:443 IpTos(Cs0, Ect0) len 129
client  |   TX -> Ack { largest_acknowledged: 1, ack_delay: 135, first_ack_range: 1, ack_ranges: [], ecn_count: None }
client  | 0.075 DEBUG Building Handshake dcid Some(CID [20]: 00000000000020026fcefba6ae8b3b98c592f6ab) scid Some(CID [0]: )
client  | 0.075 DEBUG [Client 9d08d5a9a63faab47bd435f7aec130267c] pn=0 type=Handshake pri-path:00000000000020026fcefba6ae8b3b98c592f6ab 0.0.0.0:46696->193.167.100.100:443 IpTos(Cs0, Ect0) len 181
client  |   TX -> Ack { largest_acknowledged: 0, ack_delay: 135, first_ack_range: 0, ack_ranges: [], ecn_count: None }
client  | 0.075 DEBUG [Client 9d08d5a9a63faab47bd435f7aec130267c] Drop packet number space in
client  | 0.075 DEBUG [LossRecovery] Reset loss recovery state for Initial
client  | 0.075 WARN [LossRecovery] ignoring in-4 from dropped space
client  | 0.075 DEBUG ECN probing: sent 5 probes
client  | 0.075 DEBUG [Client 9d08d5a9a63faab47bd435f7aec130267c] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.075 DEBUG Building Handshake dcid Some(CID [20]: 00000000000020026fcefba6ae8b3b98c592f6ab) scid Some(CID [0]: )
client  | 0.075 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.075 DEBUG [Client 9d08d5a9a63faab47bd435f7aec130267c] delay duration 84.195896ms
client  | 0.075 DEBUG Setting timeout of 84.195896ms
client  | 0.075 DEBUG StateChange(Handshaking)
client  | 0.075 WARN Cannot create stream ConnectionState
client  | 0.075 DEBUG [Client 9d08d5a9a63faab47bd435f7aec130267c] Authenticated Ok
client  | 0.075 DEBUG Write secret available for ApplicationData: SymKey [32]: fff0710010ed0b7abcd0e5924a195369b99d9a5f4e5a7556883a3412754fd608
client  | 0.075 DEBUG Read secret available for ApplicationData: SymKey [32]: 7b8143202d0dea4e1ab596b35c408fc82fe4540dc1ad99dbdb623e974adb71a4
client  | 0.075 DEBUG [Agent 0x55a08ab67270] SSL_AuthCertificateComplete: Ok(())
client  | 0.075 DEBUG [Agent 0x55a08ab67270] 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.075 DEBUG [Client 9d08d5a9a63faab47bd435f7aec130267c] TLS connection complete
client  | 0.075 DEBUG Making Write ApplicationData CryptoDxState, v=Version1 cipher=4865
client  | 0.075 DEBUG [Crypto] Application write key installed
client  | 0.075 DEBUG Making Read ApplicationData CryptoDxState, v=Version1 cipher=4865
client  | 0.075 DEBUG [Crypto] application read keys installed
client  | 0.075 DEBUG [Client 9d08d5a9a63faab47bd435f7aec130267c] State change from Handshaking -> Connected
client  | 0.075 INFO [Client 9d08d5a9a63faab47bd435f7aec130267c] Connection established
client  | 0.075 DEBUG stream BiDi creatable
client  | 0.075 INFO Created stream 0 for https://server4/hmmczrvgta
client  | 0.075 INFO Saving https://server4/hmmczrvgta to "/downloads/hmmczrvgta"
client  | 0.075 DEBUG stream UniDi creatable
client  | 0.075 DEBUG StateChange(Connected)
client  | 0.075 DEBUG stream 0 writable
client  | 0.075 DEBUG [Client 9d08d5a9a63faab47bd435f7aec130267c] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.075 DEBUG Building Handshake dcid Some(CID [20]: 00000000000020026fcefba6ae8b3b98c592f6ab) scid Some(CID [0]: )
client  | 0.075 DEBUG CRYPTO for hs offset=0, len=36
client  | 0.075 DEBUG [Client 9d08d5a9a63faab47bd435f7aec130267c] pn=1 type=Handshake pri-path:00000000000020026fcefba6ae8b3b98c592f6ab 0.0.0.0:46696->193.167.100.100:443 IpTos(Cs0, Ect0) len 85
client  |   TX -> Crypto { offset: 0, len: 36 }
client  | 0.075 DEBUG packet_sent this=0x55a08ab7a970, pn=1, ps=85
client  | 0.075 DEBUG Building Short dcid Some(CID [20]: 00000000000020026fcefba6ae8b3b98c592f6ab)
client  | 0.075 DEBUG [Client 9d08d5a9a63faab47bd435f7aec130267c] pn=0 type=Short pri-path:00000000000020026fcefba6ae8b3b98c592f6ab 0.0.0.0:46696->193.167.100.100:443 IpTos(Cs0, Ect0) len 143
client  |   TX -> Stream { stream_id: 0, offset: 0, len: 17, fin: true }
client  | 0.075 DEBUG packet_sent this=0x55a08ab7a970, pn=0, ps=58
client  | 0.075 DEBUG ECN probing: sent 6 probes
client  | 0.076 DEBUG [Client 9d08d5a9a63faab47bd435f7aec130267c] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.076 DEBUG Building Handshake dcid Some(CID [20]: 00000000000020026fcefba6ae8b3b98c592f6ab) scid Some(CID [0]: )
client  | 0.076 DEBUG Building Short dcid Some(CID [20]: 00000000000020026fcefba6ae8b3b98c592f6ab)
client  | 0.076 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.076 DEBUG [Client 9d08d5a9a63faab47bd435f7aec130267c] delay duration 84.16995ms
client  | 0.076 DEBUG Setting timeout of 84.16995ms
server  | 2025/04/30 09:39:11 [debug] 22#0: epoll: fd:6 ev:0001 d:00007FE76C211108
server  | 2025/04/30 09:39:11 [debug] 22#0: quic recvmsg on 0.0.0.0:443, ready: 0
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic recvmsg: fd:6 n:181
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic input handler
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic packet rx long flags:c0 version:1
server  | 2025/04/30 09:39:11 [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:11 [debug] 22#0: *6 quic packet done rc:-5 parse failed
server  | 2025/04/30 09:39:11 [debug] 22#0: timer delta: 34
server  | 2025/04/30 09:39:11 [debug] 22#0: worker cycle
server  | 2025/04/30 09:39:11 [debug] 22#0: epoll timer: 963
server  | 2025/04/30 09:39:11 [debug] 22#0: epoll: fd:6 ev:0001 d:00007FE76C211108
server  | 2025/04/30 09:39:11 [debug] 22#0: quic recvmsg on 0.0.0.0:443, ready: 0
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic recvmsg: fd:6 n:143
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic input handler
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic packet rx long flags:ee version:1
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic packet rx hs len:56
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic packet rx dcid len:20 00000000000020026fcefba6ae8b3b98c592f6ab
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic packet rx scid len:0 
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic packet rx clearflags:e0
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic packet rx number:1 len:1
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic packet len:143 via sock seq:0 path seq:0
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic path seq:0 status tx:1251 rx:2647 valid:1 st:0 mtu:1200
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic congestion slow start win:131200 ss:-1 if:1054
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic socket seq:-1 closed nsock:1
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 event timer del: 6: 321436
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic lost timer pto:963
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 event timer add: 6: 963:321436
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic frame rx hs:1 CRYPTO len:36 off:0
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic ngx_quic_set_read_secret() level:3
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic ngx_quic_add_handshake_data
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 post event 0000555A885A44A8
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic ngx_quic_flush_flight()
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 SSL_do_handshake: 1
server  | 2025/04/30 09:39:11 [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:11 [debug] 22#0: *6 update posted event 0000555A885A44A8
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 malloc: 0000555A885F0200:4096
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 posix_memalign: 0000555A88598670:512 @16
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 update posted event 0000555A885A44A8
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 post event 0000555A885A4628
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic congestion slow start win:132254 ss:-1 if:0
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 event timer del: 6: 321436
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic lost timer unset
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic path seq:0 schedule mtu:2400
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 event timer add: 6: 100:320573
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic create sockets has:1 max:8
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic socket seq:1 listening at sid:0000000000002002ba304c2a8d370d070fe19a3b nsock:2
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic stateless reset token c95cf890e50ee07a5b52a8e6f73cce6e
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 update posted event 0000555A885A44A8
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic socket seq:2 listening at sid:000000000000200260fc27656631e1218b39033a nsock:3
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 posix_memalign: 0000555A88598880:512 @16
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic stateless reset token 0a9c8fe3c0b6107b7e50a012010ef919
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 update posted event 0000555A885A44A8
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic socket seq:3 listening at sid:0000000000002002d6f2aa5097e30792f5a6a3cf nsock:4
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 posix_memalign: 0000555A88598A90:512 @16
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic stateless reset token 6d6dc02acc3169809d361a2ccf85df80
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 update posted event 0000555A885A44A8
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic socket seq:4 listening at sid:00000000000020026523f1b2bb154b5a8542204c nsock:5
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 posix_memalign: 0000555A885995F0:512 @16
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic stateless reset token d3754ab75ab08c47190a33fc0252c4cb
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 update posted event 0000555A885A44A8
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic socket seq:5 listening at sid:0000000000002002bc8c12fa457df1c20822212b nsock:6
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 posix_memalign: 0000555A88599800:512 @16
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic stateless reset token d938df7a51b088566bd384cd28814c77
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 update posted event 0000555A885A44A8
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic socket seq:6 listening at sid:00000000000020023122045bc9caf905f7bb7c9c nsock:7
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 posix_memalign: 0000555A88599A10:512 @16
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic stateless reset token 21e783a02c054c594081fe9ef06726db
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 update posted event 0000555A885A44A8
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic socket seq:7 listening at sid:0000000000002002a39813cfa7c29486024a632b nsock:8
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 posix_memalign: 0000555A885F1210:512 @16
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic stateless reset token 6634d9396deaddd3b509d0e4b612ea63
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 update posted event 0000555A885A44A8
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic init streams
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 http3 init
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 http3 init session
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 posix_memalign: 0000555A885F1420:512 @16
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 add cleanup: 0000555A88598A38
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 event timer add: 6: 75000:395473
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 event timer del: 6: 380438
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic ngx_quic_ack_packet pn:1 largest -1 fr:0 nranges:0
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic packet done rc:0 level:hs decr:1 pn:1 perr:0
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic packet rx short flags:5e
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic packet rx dcid len:20 00000000000020026fcefba6ae8b3b98c592f6ab
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic packet rx clearflags:40
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic packet rx number:0 len:1
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic frame rx app:0 STREAM id:0x0 len:17 fin:1
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic stream id:0x0 is missing
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic stream id:0x0 create
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 posix_memalign: 0000555A885F1630:16384 @16
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 reusable connection: 0
server  | 2025/04/30 09:39:11 [debug] 22#0: *7 add cleanup: 0000555A885F16F0
server  | 2025/04/30 09:39:11 [debug] 22#0: *7 post event 0000555A885BEAD0
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 delete posted event 0000555A885A44A8
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 post event 0000555A885A44A8
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic stream id:0x0 flow control msd:17/65536 md:17/8585216
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic ngx_quic_ack_packet pn:0 largest -1 fr:0 nranges:0
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 update posted event 0000555A885A44A8
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic packet done rc:0 level:app decr:1 pn:0 perr:0
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 event timer: 6, old: 350439, new: 350473
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic state: read:29966
server  | 2025/04/30 09:39:11 [debug] 22#0: timer delta: 0
server  | 2025/04/30 09:39:11 [debug] 22#0: posted event 0000555A885A4628
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 delete posted event 0000555A885A4628
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic key update
server  | 2025/04/30 09:39:11 [debug] 22#0: posted event 0000555A885BEAD0
server  | 2025/04/30 09:39:11 [debug] 22#0: *7 delete posted event 0000555A885BEAD0
server  | 2025/04/30 09:39:11 [debug] 22#0: *7 quic init stream
server  | 2025/04/30 09:39:11 [debug] 22#0: *7 http3 init request stream
server  | 2025/04/30 09:39:11 [debug] 22#0: *7 add cleanup: 0000555A885F1760
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 event timer del: 6: 395473
server  | 2025/04/30 09:39:11 [debug] 22#0: *7 http wait request handler
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic stream id:0x0 recv buf:1024
server  | 2025/04/30 09:39:11 [debug] 22#0: *7 quic stream id:0x0 recv len:17
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic stream id:0x0 flow update 17
server  | 2025/04/30 09:39:11 [debug] 22#0: *7 reusable connection: 0
server  | 2025/04/30 09:39:11 [debug] 22#0: *7 posix_memalign: 0000555A885F5640:4096 @16
server  | 2025/04/30 09:39:11 [debug] 22#0: *7 http process request line
server  | 2025/04/30 09:39:11 [debug] 22#0: *7 http request line: "GET /hmmczrvgta"
server  | 2025/04/30 09:39:11 [debug] 22#0: *7 http uri: "/hmmczrvgta"
server  | 2025/04/30 09:39:11 [debug] 22#0: *7 http args: ""
server  | 2025/04/30 09:39:11 [debug] 22#0: *7 http exten: ""
server  | 2025/04/30 09:39:11 [debug] 22#0: *7 rewrite phase: 0
server  | 2025/04/30 09:39:11 [debug] 22#0: *7 test location: "/"
server  | 2025/04/30 09:39:11 [debug] 22#0: *7 using configuration "/"
server  | 2025/04/30 09:39:11 [debug] 22#0: *7 http cl:-1 max:1048576
server  | 2025/04/30 09:39:11 [debug] 22#0: *7 rewrite phase: 2
server  | 2025/04/30 09:39:11 [debug] 22#0: *7 post rewrite phase: 3
server  | 2025/04/30 09:39:11 [debug] 22#0: *7 generic phase: 4
server  | 2025/04/30 09:39:11 [debug] 22#0: *7 generic phase: 5
server  | 2025/04/30 09:39:11 [debug] 22#0: *7 access phase: 6
server  | 2025/04/30 09:39:11 [debug] 22#0: *7 access phase: 7
server  | 2025/04/30 09:39:11 [debug] 22#0: *7 post access phase: 8
server  | 2025/04/30 09:39:11 [debug] 22#0: *7 generic phase: 9
server  | 2025/04/30 09:39:11 [debug] 22#0: *7 generic phase: 10
server  | 2025/04/30 09:39:11 [debug] 22#0: *7 content phase: 11
server  | 2025/04/30 09:39:11 [debug] 22#0: *7 content phase: 12
server  | 2025/04/30 09:39:11 [debug] 22#0: *7 content phase: 13
server  | 2025/04/30 09:39:11 [debug] 22#0: *7 http filename: "/www/hmmczrvgta"
server  | 2025/04/30 09:39:11 [debug] 22#0: *7 add cleanup: 0000555A885F6378
server  | 2025/04/30 09:39:11 [debug] 22#0: *7 http static fd: 3
server  | 2025/04/30 09:39:11 [debug] 22#0: *7 http set discard body
server  | 2025/04/30 09:39:11 [debug] 22#0: *7 http output filter "/hmmczrvgta?"
server  | 2025/04/30 09:39:11 [debug] 22#0: *7 http copy filter: "/hmmczrvgta?"
server  | 2025/04/30 09:39:11 [debug] 22#0: *7 malloc: 0000555A885F6650:10240
server  | 2025/04/30 09:39:11 [debug] 22#0: *7 read: 3, 0000555A885F6650, 10240, 0
server  | 2025/04/30 09:39:11 [debug] 22#0: *7 http postpone filter "/hmmczrvgta?" 0000555A885F6590
server  | 2025/04/30 09:39:11 [debug] 22#0: *7 write new buf t:1 f:0 0000555A885F6650, pos 0000555A885F6650, size: 10240 file: 0, size: 0
server  | 2025/04/30 09:39:11 [debug] 22#0: *7 http write filter: l:1 f:0 s:10240
server  | 2025/04/30 09:39:11 [debug] 22#0: *7 http write filter limit 2097152
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 malloc: 0000555A885F8E60:4096
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 malloc: 0000555A885F9E70:4096
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 posix_memalign: 0000555A885FAE80:512 @16
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 malloc: 0000555A885FB090:4096
server  | 2025/04/30 09:39:11 [debug] 22#0: *7 quic send_chain sent:10240
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic stream id:0x0 flush limit:1048576
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 update posted event 0000555A885A44A8
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic stream id:0x0 flush len:10240 last:0
server  | 2025/04/30 09:39:11 [debug] 22#0: *7 http write filter 0000000000000000
server  | 2025/04/30 09:39:11 [debug] 22#0: *7 http copy filter: 0 "/hmmczrvgta?"
server  | 2025/04/30 09:39:11 [debug] 22#0: *7 http finalize request: 0, "/hmmczrvgta?" a:1, c:1
server  | 2025/04/30 09:39:11 [debug] 22#0: *7 http request count:1 blk:0
server  | 2025/04/30 09:39:11 [debug] 22#0: *7 http close request
server  | 2025/04/30 09:39:11 [debug] 22#0: *7 http log handler
server  | 2025/04/30 09:39:11 [debug] 22#0: *7 posix_memalign: 0000555A885FC0A0:4096 @16
server  | 193.167.0.100 - - [30/Apr/2025:09:39:11 +0000] "GET /hmmczrvgta" 200 10240 "-" "-"
server  | 2025/04/30 09:39:11 [debug] 22#0: *7 run cleanup: 0000555A885F6378
server  | 2025/04/30 09:39:11 [debug] 22#0: *7 file cleanup: fd:3
server  | 2025/04/30 09:39:11 [debug] 22#0: *7 free: 0000555A885F6650
server  | 2025/04/30 09:39:11 [debug] 22#0: *7 free: 0000555A885F5640, unused: 48
server  | 2025/04/30 09:39:11 [debug] 22#0: *7 free: 0000555A885FC0A0, unused: 3949
server  | 2025/04/30 09:39:11 [debug] 22#0: *7 close http connection: 6
server  | 2025/04/30 09:39:11 [debug] 22#0: *7 reusable connection: 0
server  | 2025/04/30 09:39:11 [debug] 22#0: *7 run cleanup: 0000555A885F1760
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 event timer add: 6: 75000:395473
server  | 2025/04/30 09:39:11 [debug] 22#0: *7 run cleanup: 0000555A885F16F0
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic stream id:0x0 cleanup
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic stream id:0x0 send shutdown
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic stream id:0x0 flush limit:1038336
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 update posted event 0000555A885A44A8
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic stream id:0x0 flush len:0 last:1
server  | 2025/04/30 09:39:11 [debug] 22#0: *7 free: 0000555A885F1630, unused: 14952
server  | 2025/04/30 09:39:11 [debug] 22#0: posted event 0000555A885A44A8
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 delete posted event 0000555A885A44A8
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic push handler
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 posix_memalign: 0000555A885F1630:512 @16
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic output app packet max:1200 min:0
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic frame tx app:0 ACK n:0 delay:0 0
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic frame tx app:0 CRYPTO len:572 off:0
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic frame tx app:0 HANDSHAKE DONE
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic frame tx app:0 NEW_TOKEN
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic frame tx app:0 NEW_CONNECTION_ID seq:1 retire:0 len:20
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic frame tx app:0 NEW_CONNECTION_ID seq:2 retire:0 len:20
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic frame tx app:0 NEW_CONNECTION_ID seq:3 retire:0 len:20
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic frame tx app:0 NEW_CONNECTION_ID seq:4 retire:0 len:20
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic frame tx app:0 NEW_CONNECTION_ID seq:5 retire:0 len:20
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic frame tx app:0 NEW_CONNECTION_ID seq:6 retire:0 len:20
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic frame tx app:0 NEW_CONNECTION_ID seq:7 retire:0 len:20
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic split frame now:10245 need:260 shrink:9985
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic frame tx app:0 STREAM id:0x0 off:0 len:255
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic packet tx app bytes:1182 need_ack:1 number:0 encoded nl:1 trunc:0x0
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 sendmsg: 1200 of 1200
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic congestion send if:0
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic congestion send if:0
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic congestion send if:1200
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic output app packet max:1200 min:0
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic split frame now:9991 need:1182 shrink:8809
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 posix_memalign: 0000555A885F1840:512 @16
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic frame tx app:1 STREAM id:0x0 off:255 len:1176
server  | 2025/04/30 09:39:11 [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:11 [debug] 22#0: *6 sendmsg: 1200 of 1200
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic congestion send if:1200
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic congestion send if:1200
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic congestion send if:2400
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic output app packet max:1200 min:0
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic split frame now:8815 need:1182 shrink:7633
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic frame tx app:2 STREAM id:0x0 off:1431 len:1176
server  | 2025/04/30 09:39:11 [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:11 [debug] 22#0: *6 sendmsg: 1200 of 1200
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic congestion send if:2400
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic congestion send if:2400
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic congestion send if:3600
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic output app packet max:1200 min:0
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic split frame now:7639 need:1182 shrink:6457
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 posix_memalign: 0000555A885F1A50:512 @16
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic frame tx app:3 STREAM id:0x0 off:2607 len:1176
server  | 2025/04/30 09:39:11 [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:11 [debug] 22#0: *6 sendmsg: 1200 of 1200
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic congestion send if:3600
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic congestion send if:3600
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic congestion send if:4800
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic output app packet max:1200 min:0
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic split frame now:6463 need:1182 shrink:5281
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic frame tx app:4 STREAM id:0x0 off:3783 len:1176
server  | 2025/04/30 09:39:11 [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:11 [debug] 22#0: *6 sendmsg: 1200 of 1200
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic congestion send if:4800
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic congestion send if:4800
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic congestion send if:6000
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic output app packet max:1200 min:0
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic split frame now:5287 need:1182 shrink:4105
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 posix_memalign: 0000555A885F1C60:512 @16
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic frame tx app:5 STREAM id:0x0 off:4959 len:1176
server  | 2025/04/30 09:39:11 [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:11 [debug] 22#0: *6 sendmsg: 1200 of 1200
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic congestion send if:6000
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic congestion send if:6000
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic congestion send if:7200
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic output app packet max:1200 min:0
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic split frame now:4111 need:1182 shrink:2929
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic frame tx app:6 STREAM id:0x0 off:6135 len:1176
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic packet tx app bytes:1182 need_ack:1 number:6 encoded nl:1 trunc:0x6
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 sendmsg: 1200 of 1200
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic congestion send if:7200
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic congestion send if:7200
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic congestion send if:8400
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic output app packet max:1200 min:0
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic split frame now:2935 need:1182 shrink:1753
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 posix_memalign: 0000555A885F1E70:512 @16
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic frame tx app:7 STREAM id:0x0 off:7311 len:1176
server  | 2025/04/30 09:39:11 [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:11 [debug] 22#0: *6 sendmsg: 1200 of 1200
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic congestion send if:8400
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic congestion send if:8400
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic congestion send if:9600
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic output app packet max:1200 min:0
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic split frame now:1759 need:1182 shrink:577
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic frame tx app:8 STREAM id:0x0 off:8487 len:1176
server  | 2025/04/30 09:39:11 [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:11 [debug] 22#0: *6 sendmsg: 1200 of 1200
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic congestion send if:9600
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic congestion send if:9600
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic congestion send if:10800
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic output app packet max:1200 min:0
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic frame tx app:9 STREAM id:0x0 off:9663 len:577
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic frame tx app:9 STREAM id:0x0 off:10240 len:0 fin:1
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic packet tx app bytes:588 need_ack:1 number:9 encoded nl:1 trunc:0x9
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 sendmsg: 606 of 606
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic congestion send if:10800
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic congestion send if:10800
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic congestion send if:11406
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 event timer: 6, old: 350439, new: 350473
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic lost timer pto:1017
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 event timer add: 6: 1017:321490
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic state: send:29966 pto:1017
server  | 2025/04/30 09:39:11 [debug] 22#0: worker cycle
server  | 2025/04/30 09:39:11 [debug] 22#0: epoll timer: 100
client  | 0.108 DEBUG [Client 9d08d5a9a63faab47bd435f7aec130267c] pn=0 type=Short pri-path:00000000000020026fcefba6ae8b3b98c592f6ab 0.0.0.0:46696->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 NewToken { token: [1, 135, 14, 150, 84, 242, 129, 247, 119, 221, 157, 130, 133, 0, 111, 212, 88, 143, 190, 227, 14, 149, 138, 229, 248, 241, 228, 80, 109, 36, 50, 151, 178, 92, 110, 84, 102, 147, 35, 31, 213, 204, 183, 74, 212, 110, 225, 202, 218, 164, 234, 78, 173, 114, 254, 50, 248, 244] }
client  |   -> RX NewConnectionId { sequence_number: 1, retire_prior: 0, connection_id: [0, 0, 0, 0, 0, 0, 32, 2, 186, 48, 76, 42, 141, 55, 13, 7, 15, 225, 154, 59], stateless_reset_token: [201, 92, 248, 144, 229, 14, 224, 122, 91, 82, 168, 230, 247, 60, 206, 110] }
client  |   -> RX NewConnectionId { sequence_number: 2, retire_prior: 0, connection_id: [0, 0, 0, 0, 0, 0, 32, 2, 96, 252, 39, 101, 102, 49, 225, 33, 139, 57, 3, 58], stateless_reset_token: [10, 156, 143, 227, 192, 182, 16, 123, 126, 80, 160, 18, 1, 14, 249, 25] }
client  |   -> RX NewConnectionId { sequence_number: 3, retire_prior: 0, connection_id: [0, 0, 0, 0, 0, 0, 32, 2, 214, 242, 170, 80, 151, 227, 7, 146, 245, 166, 163, 207], stateless_reset_token: [109, 109, 192, 42, 204, 49, 105, 128, 157, 54, 26, 44, 207, 133, 223, 128] }
client  |   -> RX NewConnectionId { sequence_number: 4, retire_prior: 0, connection_id: [0, 0, 0, 0, 0, 0, 32, 2, 101, 35, 241, 178, 187, 21, 75, 90, 133, 66, 32, 76], stateless_reset_token: [211, 117, 74, 183, 90, 176, 140, 71, 25, 10, 51, 252, 2, 82, 196, 203] }
client  |   -> RX NewConnectionId { sequence_number: 5, retire_prior: 0, connection_id: [0, 0, 0, 0, 0, 0, 32, 2, 188, 140, 18, 250, 69, 125, 241, 194, 8, 34, 33, 43], stateless_reset_token: [217, 56, 223, 122, 81, 176, 136, 86, 107, 211, 132, 205, 40, 129, 76, 119] }
client  |   -> RX NewConnectionId { sequence_number: 6, retire_prior: 0, connection_id: [0, 0, 0, 0, 0, 0, 32, 2, 49, 34, 4, 91, 201, 202, 249, 5, 247, 187, 124, 156], stateless_reset_token: [33, 231, 131, 160, 44, 5, 76, 89, 64, 129, 254, 158, 240, 103, 38, 219] }
client  |   -> RX NewConnectionId { sequence_number: 7, retire_prior: 0, connection_id: [0, 0, 0, 0, 0, 0, 32, 2, 163, 152, 19, 207, 167, 194, 148, 134, 2, 74, 99, 43], stateless_reset_token: [102, 52, 217, 57, 109, 234, 221, 211, 181, 9, 208, 228, 182, 18, 234, 99] }
client  |   -> RX Stream { stream_id: 0, offset: 0, len: 255, fin: false }
client  | 0.108 DEBUG [Client 9d08d5a9a63faab47bd435f7aec130267c] Rx ACK space=ap, ranges=[0..=0]
client  | 0.108 DEBUG [LossRecovery] ACK for ApplicationData - largest_acked=0
client  | 0.108 DEBUG on_packets_acked this=0x55a08ab7a970, limited=1, bytes_in_flight=85, cwnd=12520, state=SlowStart, new_acked=58
client  | 0.108 DEBUG Read Ok(572) bytes
client  | 0.109 DEBUG [0x55a08ab67270] Got resumption token [951]: 02000633fbb07ccf..8e99b767b480e9bf
client  | 0.109 DEBUG [0x55a08ab67270] Got resumption token [951]: 02000633fbb07ccf..56574995177b509b
client  | 0.109 DEBUG [Agent 0x55a08ab67270] 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.109 DEBUG setting max_stream_data to 65536
client  | 0.109 DEBUG [Client 9d08d5a9a63faab47bd435f7aec130267c] State change from Connected -> Confirmed
client  | 0.109 DEBUG PMTUD started with probe size 1380
client  | 0.109 DEBUG [Client 9d08d5a9a63faab47bd435f7aec130267c] Drop packet number space hs
client  | 0.109 DEBUG [LossRecovery] Reset loss recovery state for Handshake
client  | 0.109 DEBUG [Client 9d08d5a9a63faab47bd435f7aec130267c] No preferred address to migrate to
client  | 0.109 DEBUG resumption token [1150]: 0000000124408500..56574995177b509b
client  | 0.109 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 320, tv_nsec: 511389448 }
client  | 0.109 DEBUG [Client 9d08d5a9a63faab47bd435f7aec130267c] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.109 DEBUG Building Short dcid Some(CID [20]: 00000000000020026fcefba6ae8b3b98c592f6ab)
client  | 0.109 DEBUG Sending PMTUD probe of size 1380, count 1
client  | 0.109 DEBUG [Client 9d08d5a9a63faab47bd435f7aec130267c] pn=1 type=Short pri-path:00000000000020026fcefba6ae8b3b98c592f6ab 0.0.0.0:46696->193.167.100.100:443 IpTos(Cs0, Ect0) len 1352
client  |   TX -> Ping
client  |   TX -> Padding { len: 1313 }
client  | 0.109 DEBUG packet_sent this=0x55a08ab7a970, pn=1, ps=1352
client  | 0.109 DEBUG ECN probing: sent 7 probes
client  | 0.109 DEBUG [Client 9d08d5a9a63faab47bd435f7aec130267c] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.109 DEBUG Building Short dcid Some(CID [20]: 00000000000020026fcefba6ae8b3b98c592f6ab)
client  | 0.109 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.109 DEBUG [Client 9d08d5a9a63faab47bd435f7aec130267c] delay duration 19.665161ms
client  | 0.109 DEBUG Setting timeout of 19.665161ms
client  | 0.109 DEBUG stream 0 complete
client  | 0.109 DEBUG stream BiDi creatable
client  | 0.109 DEBUG stream UniDi creatable
client  | 0.109 WARN Unhandled event StateChange(Confirmed)
client  | 0.109 DEBUG [Client 9d08d5a9a63faab47bd435f7aec130267c] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.109 DEBUG Building Short dcid Some(CID [20]: 00000000000020026fcefba6ae8b3b98c592f6ab)
client  | 0.109 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.109 DEBUG [Client 9d08d5a9a63faab47bd435f7aec130267c] delay duration 19.630045ms
client  | 0.109 DEBUG Setting timeout of 19.630045ms
client  | 0.109 DEBUG [Client 9d08d5a9a63faab47bd435f7aec130267c] pn=1 type=Short pri-path:00000000000020026fcefba6ae8b3b98c592f6ab 0.0.0.0:46696->193.167.100.100:443 IpTos(Cs0, NotEct) len 1200
client  |   -> RX Stream { stream_id: 0, offset: 255, len: 1176, fin: false }
client  | 0.109 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 320, tv_nsec: 492378935 }
client  | 0.109 DEBUG [Client 9d08d5a9a63faab47bd435f7aec130267c] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.109 DEBUG Building Short dcid Some(CID [20]: 00000000000020026fcefba6ae8b3b98c592f6ab)
client  | 0.109 DEBUG [Client 9d08d5a9a63faab47bd435f7aec130267c] pn=2 type=Short pri-path:00000000000020026fcefba6ae8b3b98c592f6ab 0.0.0.0:46696->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.109 DEBUG ECN probing: sent 8 probes
client  | 0.109 DEBUG [Client 9d08d5a9a63faab47bd435f7aec130267c] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.109 DEBUG Building Short dcid Some(CID [20]: 00000000000020026fcefba6ae8b3b98c592f6ab)
client  | 0.109 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.109 DEBUG [Client 9d08d5a9a63faab47bd435f7aec130267c] delay duration 99.601894ms
client  | 0.109 DEBUG Setting timeout of 99.601894ms
client  | 0.109 DEBUG [Client 9d08d5a9a63faab47bd435f7aec130267c] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.109 DEBUG Building Short dcid Some(CID [20]: 00000000000020026fcefba6ae8b3b98c592f6ab)
client  | 0.109 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.109 DEBUG [Client 9d08d5a9a63faab47bd435f7aec130267c] delay duration 99.573751ms
client  | 0.109 DEBUG Setting timeout of 99.573751ms
client  | 0.110 DEBUG [Client 9d08d5a9a63faab47bd435f7aec130267c] pn=2 type=Short pri-path:00000000000020026fcefba6ae8b3b98c592f6ab 0.0.0.0:46696->193.167.100.100:443 IpTos(Cs0, NotEct) len 1200
client  |   -> RX Stream { stream_id: 0, offset: 1431, len: 1176, fin: false }
client  | 0.110 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 320, tv_nsec: 513344739 }
client  | 0.110 DEBUG [Client 9d08d5a9a63faab47bd435f7aec130267c] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.110 DEBUG Building Short dcid Some(CID [20]: 00000000000020026fcefba6ae8b3b98c592f6ab)
client  | 0.110 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.110 DEBUG [Client 9d08d5a9a63faab47bd435f7aec130267c] delay duration 19.932563ms
client  | 0.110 DEBUG Setting timeout of 19.932563ms
client  | 0.110 DEBUG [Client 9d08d5a9a63faab47bd435f7aec130267c] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.110 DEBUG Building Short dcid Some(CID [20]: 00000000000020026fcefba6ae8b3b98c592f6ab)
client  | 0.110 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.110 DEBUG [Client 9d08d5a9a63faab47bd435f7aec130267c] delay duration 19.908508ms
client  | 0.110 DEBUG Setting timeout of 19.908508ms
client  | 0.111 DEBUG [Client 9d08d5a9a63faab47bd435f7aec130267c] pn=3 type=Short pri-path:00000000000020026fcefba6ae8b3b98c592f6ab 0.0.0.0:46696->193.167.100.100:443 IpTos(Cs0, NotEct) len 1200
client  |   -> RX Stream { stream_id: 0, offset: 2607, len: 1176, fin: false }
client  | 0.111 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 320, tv_nsec: 494338333 }
client  | 0.111 DEBUG [Client 9d08d5a9a63faab47bd435f7aec130267c] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.111 DEBUG Building Short dcid Some(CID [20]: 00000000000020026fcefba6ae8b3b98c592f6ab)
client  | 0.111 DEBUG [Client 9d08d5a9a63faab47bd435f7aec130267c] pn=3 type=Short pri-path:00000000000020026fcefba6ae8b3b98c592f6ab 0.0.0.0:46696->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.111 DEBUG ECN probing: sent 9 probes
client  | 0.111 DEBUG [Client 9d08d5a9a63faab47bd435f7aec130267c] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.111 DEBUG Building Short dcid Some(CID [20]: 00000000000020026fcefba6ae8b3b98c592f6ab)
client  | 0.111 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.111 DEBUG [Client 9d08d5a9a63faab47bd435f7aec130267c] delay duration 97.643568ms
client  | 0.111 DEBUG Setting timeout of 97.643568ms
client  | 0.111 DEBUG [Client 9d08d5a9a63faab47bd435f7aec130267c] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.111 DEBUG Building Short dcid Some(CID [20]: 00000000000020026fcefba6ae8b3b98c592f6ab)
client  | 0.111 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.111 DEBUG [Client 9d08d5a9a63faab47bd435f7aec130267c] delay duration 97.615635ms
client  | 0.111 DEBUG Setting timeout of 97.615635ms
client  | 0.112 DEBUG [Client 9d08d5a9a63faab47bd435f7aec130267c] pn=4 type=Short pri-path:00000000000020026fcefba6ae8b3b98c592f6ab 0.0.0.0:46696->193.167.100.100:443 IpTos(Cs0, NotEct) len 1200
client  |   -> RX Stream { stream_id: 0, offset: 3783, len: 1176, fin: false }
client  | 0.112 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 320, tv_nsec: 515317060 }
client  | 0.112 DEBUG [Client 9d08d5a9a63faab47bd435f7aec130267c] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.112 DEBUG Building Short dcid Some(CID [20]: 00000000000020026fcefba6ae8b3b98c592f6ab)
client  | 0.112 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.112 DEBUG [Client 9d08d5a9a63faab47bd435f7aec130267c] delay duration 19.973741ms
client  | 0.112 DEBUG Setting timeout of 19.973741ms
client  | 0.112 DEBUG [Client 9d08d5a9a63faab47bd435f7aec130267c] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.112 DEBUG Building Short dcid Some(CID [20]: 00000000000020026fcefba6ae8b3b98c592f6ab)
client  | 0.112 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.112 DEBUG [Client 9d08d5a9a63faab47bd435f7aec130267c] delay duration 19.939417ms
client  | 0.112 DEBUG Setting timeout of 19.939417ms
client  | 0.113 DEBUG [Client 9d08d5a9a63faab47bd435f7aec130267c] pn=5 type=Short pri-path:00000000000020026fcefba6ae8b3b98c592f6ab 0.0.0.0:46696->193.167.100.100:443 IpTos(Cs0, NotEct) len 1200
client  |   -> RX Stream { stream_id: 0, offset: 4959, len: 1176, fin: false }
client  | 0.113 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 320, tv_nsec: 496306927 }
client  | 0.113 DEBUG [Client 9d08d5a9a63faab47bd435f7aec130267c] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.113 DEBUG Building Short dcid Some(CID [20]: 00000000000020026fcefba6ae8b3b98c592f6ab)
client  | 0.113 DEBUG [Client 9d08d5a9a63faab47bd435f7aec130267c] pn=4 type=Short pri-path:00000000000020026fcefba6ae8b3b98c592f6ab 0.0.0.0:46696->193.167.100.100:443 IpTos(Cs0, Ect0) len 43
client  |   TX -> Ack { largest_acknowledged: 5, ack_delay: 3, first_ack_range: 5, ack_ranges: [], ecn_count: None }
client  | 0.113 DEBUG ECN probing: sent 10 probes
client  | 0.113 DEBUG ECN probing concluded with 10 probes sent
client  | 0.113 DEBUG [Client 9d08d5a9a63faab47bd435f7aec130267c] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.113 DEBUG Building Short dcid Some(CID [20]: 00000000000020026fcefba6ae8b3b98c592f6ab)
client  | 0.113 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.113 DEBUG [Client 9d08d5a9a63faab47bd435f7aec130267c] delay duration 95.66125ms
client  | 0.113 DEBUG Setting timeout of 95.66125ms
client  | 0.113 DEBUG [Client 9d08d5a9a63faab47bd435f7aec130267c] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.113 DEBUG Building Short dcid Some(CID [20]: 00000000000020026fcefba6ae8b3b98c592f6ab)
client  | 0.113 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.113 DEBUG [Client 9d08d5a9a63faab47bd435f7aec130267c] delay duration 95.631715ms
client  | 0.113 DEBUG Setting timeout of 95.631715ms
client  | 0.114 DEBUG [Client 9d08d5a9a63faab47bd435f7aec130267c] pn=6 type=Short pri-path:00000000000020026fcefba6ae8b3b98c592f6ab 0.0.0.0:46696->193.167.100.100:443 IpTos(Cs0, NotEct) len 1200
client  |   -> RX Stream { stream_id: 0, offset: 6135, len: 1176, fin: false }
client  | 0.114 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 320, tv_nsec: 517288388 }
client  | 0.114 DEBUG [Client 9d08d5a9a63faab47bd435f7aec130267c] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.114 DEBUG Building Short dcid Some(CID [20]: 00000000000020026fcefba6ae8b3b98c592f6ab)
client  | 0.114 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.114 DEBUG [Client 9d08d5a9a63faab47bd435f7aec130267c] delay duration 19.971917ms
client  | 0.114 DEBUG Setting timeout of 19.971917ms
client  | 0.114 DEBUG [Client 9d08d5a9a63faab47bd435f7aec130267c] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.114 DEBUG Building Short dcid Some(CID [20]: 00000000000020026fcefba6ae8b3b98c592f6ab)
client  | 0.114 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.114 DEBUG [Client 9d08d5a9a63faab47bd435f7aec130267c] delay duration 19.942632ms
client  | 0.114 DEBUG Setting timeout of 19.942632ms
client  | 0.115 DEBUG [Client 9d08d5a9a63faab47bd435f7aec130267c] pn=7 type=Short pri-path:00000000000020026fcefba6ae8b3b98c592f6ab 0.0.0.0:46696->193.167.100.100:443 IpTos(Cs0, NotEct) len 1200
client  |   -> RX Stream { stream_id: 0, offset: 7311, len: 1176, fin: false }
client  | 0.115 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 320, tv_nsec: 498269687 }
client  | 0.115 DEBUG [Client 9d08d5a9a63faab47bd435f7aec130267c] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.115 DEBUG Building Short dcid Some(CID [20]: 00000000000020026fcefba6ae8b3b98c592f6ab)
client  | 0.115 DEBUG [Client 9d08d5a9a63faab47bd435f7aec130267c] pn=5 type=Short pri-path:00000000000020026fcefba6ae8b3b98c592f6ab 0.0.0.0:46696->193.167.100.100:443 IpTos(Cs0, NotEct) len 43
client  |   TX -> Ack { largest_acknowledged: 7, ack_delay: 3, first_ack_range: 7, ack_ranges: [], ecn_count: None }
client  | 0.115 DEBUG [Client 9d08d5a9a63faab47bd435f7aec130267c] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.115 DEBUG Building Short dcid Some(CID [20]: 00000000000020026fcefba6ae8b3b98c592f6ab)
client  | 0.115 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.115 DEBUG [Client 9d08d5a9a63faab47bd435f7aec130267c] delay duration 93.712414ms
client  | 0.115 DEBUG Setting timeout of 93.712414ms
client  | 0.115 DEBUG [Client 9d08d5a9a63faab47bd435f7aec130267c] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.115 DEBUG Building Short dcid Some(CID [20]: 00000000000020026fcefba6ae8b3b98c592f6ab)
client  | 0.115 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.115 DEBUG [Client 9d08d5a9a63faab47bd435f7aec130267c] delay duration 93.681837ms
client  | 0.115 DEBUG Setting timeout of 93.681837ms
client  | 0.116 DEBUG [Client 9d08d5a9a63faab47bd435f7aec130267c] pn=8 type=Short pri-path:00000000000020026fcefba6ae8b3b98c592f6ab 0.0.0.0:46696->193.167.100.100:443 IpTos(Cs0, NotEct) len 1200
client  |   -> RX Stream { stream_id: 0, offset: 8487, len: 1176, fin: false }
client  | 0.116 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 320, tv_nsec: 519251349 }
client  | 0.116 DEBUG [Client 9d08d5a9a63faab47bd435f7aec130267c] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.116 DEBUG Building Short dcid Some(CID [20]: 00000000000020026fcefba6ae8b3b98c592f6ab)
client  | 0.116 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.116 DEBUG [Client 9d08d5a9a63faab47bd435f7aec130267c] delay duration 19.974642ms
client  | 0.116 DEBUG Setting timeout of 19.974642ms
client  | 0.116 DEBUG [Client 9d08d5a9a63faab47bd435f7aec130267c] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.116 DEBUG Building Short dcid Some(CID [20]: 00000000000020026fcefba6ae8b3b98c592f6ab)
client  | 0.116 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.116 DEBUG [Client 9d08d5a9a63faab47bd435f7aec130267c] delay duration 19.952591ms
client  | 0.116 DEBUG Setting timeout of 19.952591ms
client  | 0.117 DEBUG [Client 9d08d5a9a63faab47bd435f7aec130267c] pn=9 type=Short pri-path:00000000000020026fcefba6ae8b3b98c592f6ab 0.0.0.0:46696->193.167.100.100:443 IpTos(Cs0, NotEct) len 606
client  |   -> RX Stream { stream_id: 0, offset: 9663, len: 577, fin: false }
client  |   -> RX Stream { stream_id: 0, offset: 10240, len: 0, fin: true }
client  | 0.117 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 320, tv_nsec: 499762659 }
client  | 0.117 DEBUG [Client 9d08d5a9a63faab47bd435f7aec130267c] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.117 DEBUG Building Short dcid Some(CID [20]: 00000000000020026fcefba6ae8b3b98c592f6ab)
client  | 0.117 DEBUG [Client 9d08d5a9a63faab47bd435f7aec130267c] pn=6 type=Short pri-path:00000000000020026fcefba6ae8b3b98c592f6ab 0.0.0.0:46696->193.167.100.100:443 IpTos(Cs0, NotEct) len 43
client  |   TX -> Ack { largest_acknowledged: 9, ack_delay: 3, first_ack_range: 9, ack_ranges: [], ecn_count: None }
client  | 0.117 DEBUG [Client 9d08d5a9a63faab47bd435f7aec130267c] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.117 DEBUG Building Short dcid Some(CID [20]: 00000000000020026fcefba6ae8b3b98c592f6ab)
client  | 0.117 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.117 DEBUG [Client 9d08d5a9a63faab47bd435f7aec130267c] delay duration 92.219974ms
client  | 0.117 DEBUG Setting timeout of 92.219974ms
client  | 0.117 DEBUG [Client 9d08d5a9a63faab47bd435f7aec130267c] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.117 DEBUG Building Short dcid Some(CID [20]: 00000000000020026fcefba6ae8b3b98c592f6ab)
client  | 0.117 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.117 DEBUG [Client 9d08d5a9a63faab47bd435f7aec130267c] delay duration 92.162726ms
client  | 0.117 DEBUG Setting timeout of 92.162726ms
client  | 0.117 DEBUG [Client 9d08d5a9a63faab47bd435f7aec130267c] State change from Confirmed -> Closing { error: Application(0), timeout: Instant { tv_sec: 320, tv_nsec: 801150336 } }
client  | 0.117 WARN Unhandled event StateChange(Closing { error: Application(0), timeout: Instant { tv_sec: 320, tv_nsec: 801150336 } })
client  | 0.117 DEBUG [Client 9d08d5a9a63faab47bd435f7aec130267c] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.117 DEBUG Building Short dcid Some(CID [20]: 00000000000020026fcefba6ae8b3b98c592f6ab)
client  | 0.117 DEBUG [Recvd-ap] immediate_ack at Instant { tv_sec: 320, tv_nsec: 499930864 }
client  | 0.117 DEBUG [Client 9d08d5a9a63faab47bd435f7aec130267c] pn=7 type=Short pri-path:00000000000020026fcefba6ae8b3b98c592f6ab 0.0.0.0:46696->193.167.100.100:443 IpTos(Cs0, NotEct) len 54
client  |   TX -> Ack { largest_acknowledged: 9, ack_delay: 21, first_ack_range: 9, ack_ranges: [], ecn_count: None }
client  |   TX -> ConnectionClose { error_code: Application(0), frame_type: 0, reason_phrase: "kthxbye!" }
client  | 0.117 DEBUG Setting timeout of 301.163416ms
server  | 2025/04/30 09:39:11 [debug] 22#0: epoll: fd:6 ev:0001 d:00007FE76C211108
server  | 2025/04/30 09:39:11 [debug] 22#0: quic recvmsg on 0.0.0.0:443, ready: 0
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic recvmsg: fd:6 n:1352
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic input handler
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic packet rx short flags:6a
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic packet rx dcid len:20 00000000000020026fcefba6ae8b3b98c592f6ab
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic packet rx clearflags:60
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic packet rx number:1 len:1
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic packet len:1352 via sock seq:0 path seq:0
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic path seq:0 status tx:12657 rx:3999 valid:1 st:2 mtu:1200
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic frame rx app:1 PING
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic frame rx app:1 PADDING
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic ngx_quic_ack_packet pn:1 largest 0 fr:0 nranges:0
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 post event 0000555A885A44A8
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic packet done rc:0 level:app decr:1 pn:1 perr:0
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 event timer: 6, old: 350439, new: 350507
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic state: read:29932 pto:983
server  | 2025/04/30 09:39:11 [debug] 22#0: timer delta: 34
server  | 2025/04/30 09:39:11 [debug] 22#0: posted event 0000555A885A44A8
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 delete posted event 0000555A885A44A8
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic push handler
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 event timer add: 6: 25:320532
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic state: read:29932 push:25 pto:983
server  | 2025/04/30 09:39:11 [debug] 22#0: worker cycle
server  | 2025/04/30 09:39:11 [debug] 22#0: epoll timer: 25
server  | 2025/04/30 09:39:11 [debug] 22#0: epoll: fd:6 ev:0001 d:00007FE76C211108
server  | 2025/04/30 09:39:11 [debug] 22#0: quic recvmsg on 0.0.0.0:443, ready: 0
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic recvmsg: fd:6 n:43
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic input handler
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic packet rx short flags:62
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic packet rx dcid len:20 00000000000020026fcefba6ae8b3b98c592f6ab
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic packet rx clearflags:60
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic packet rx number:2 len:1
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic packet len:43 via sock seq:0 path seq:0
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic path seq:0 status tx:12657 rx:4042 valid:1 st:2 mtu:1200
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic frame rx app:2 ACK n:0 delay:3 1-0
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic ngx_quic_handle_ack_frame level:3
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic congestion slow start win:133454 ss:-1 if:10206
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic ngx_quic_drop_ack_ranges pn:0 largest:1 fr:1 nranges:0
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic stream id:0x0 ack len:255 fin:0 unacked:9985
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic congestion slow start win:134654 ss:-1 if:9006
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic stream id:0x0 ack len:1176 fin:0 unacked:8809
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic updated largest received ack:1
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic rtt sample latest:35 min:35 avg:35 var:17
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 event timer del: 6: 321490
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic lost timer pto:88
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 event timer add: 6: 88:320596
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic ngx_quic_ack_packet pn:2 largest 1 fr:0 nranges:0
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic packet done rc:0 level:app decr:1 pn:2 perr:0
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 event timer: 6, old: 350439, new: 350508
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic state: read:29931 push:24 pto:88
server  | 2025/04/30 09:39:11 [debug] 22#0: timer delta: 1
server  | 2025/04/30 09:39:11 [debug] 22#0: worker cycle
server  | 2025/04/30 09:39:11 [debug] 22#0: epoll timer: 24
server  | 2025/04/30 09:39:11 [debug] 22#0: epoll: fd:6 ev:0001 d:00007FE76C211108
server  | 2025/04/30 09:39:11 [debug] 22#0: quic recvmsg on 0.0.0.0:443, ready: 0
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic recvmsg: fd:6 n:43
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic input handler
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic packet rx short flags:56
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic packet rx dcid len:20 00000000000020026fcefba6ae8b3b98c592f6ab
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic packet rx clearflags:40
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic packet rx number:3 len:1
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic packet len:43 via sock seq:0 path seq:0
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic path seq:0 status tx:12657 rx:4085 valid:1 st:2 mtu:1200
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic frame rx app:3 ACK n:0 delay:3 3-0
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic ngx_quic_handle_ack_frame level:3
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic congestion slow start win:135854 ss:-1 if:7806
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic stream id:0x0 ack len:1176 fin:0 unacked:7633
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic congestion slow start win:137054 ss:-1 if:6606
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic stream id:0x0 ack len:1176 fin:0 unacked:6457
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic updated largest received ack:3
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic rtt sample latest:36 min:35 avg:35 var:13
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 event timer del: 6: 320596
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic lost timer pto:71
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 event timer add: 6: 71:320580
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic ngx_quic_ack_packet pn:3 largest 2 fr:1 nranges:0
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic packet done rc:0 level:app decr:1 pn:3 perr:0
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 event timer: 6, old: 350439, new: 350509
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic state: read:29930 push:23 pto:71
server  | 2025/04/30 09:39:11 [debug] 22#0: timer delta: 1
server  | 2025/04/30 09:39:11 [debug] 22#0: worker cycle
server  | 2025/04/30 09:39:11 [debug] 22#0: epoll timer: 23
server  | 2025/04/30 09:39:11 [debug] 22#0: epoll: fd:6 ev:0001 d:00007FE76C211108
server  | 2025/04/30 09:39:11 [debug] 22#0: quic recvmsg on 0.0.0.0:443, ready: 0
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic recvmsg: fd:6 n:43
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic input handler
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic packet rx short flags:56
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic packet rx dcid len:20 00000000000020026fcefba6ae8b3b98c592f6ab
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic packet rx clearflags:40
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic packet rx number:4 len:1
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic packet len:43 via sock seq:0 path seq:0
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic path seq:0 status tx:12657 rx:4128 valid:1 st:2 mtu:1200
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic frame rx app:4 ACK n:0 delay:3 5-0
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic ngx_quic_handle_ack_frame level:3
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic congestion slow start win:138254 ss:-1 if:5406
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic stream id:0x0 ack len:1176 fin:0 unacked:5281
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic congestion slow start win:139454 ss:-1 if:4206
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic stream id:0x0 ack len:1176 fin:0 unacked:4105
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic updated largest received ack:5
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic rtt sample latest:38 min:35 avg:35 var:10
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 event timer del: 6: 320580
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic lost timer pto:57
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 event timer add: 6: 57:320568
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic ngx_quic_ack_packet pn:4 largest 3 fr:2 nranges:0
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic packet done rc:0 level:app decr:1 pn:4 perr:0
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 event timer: 6, old: 350439, new: 350511
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic state: read:29928 push:21 pto:57
server  | 2025/04/30 09:39:11 [debug] 22#0: timer delta: 2
server  | 2025/04/30 09:39:11 [debug] 22#0: worker cycle
server  | 2025/04/30 09:39:11 [debug] 22#0: epoll timer: 21
server  | 2025/04/30 09:39:11 [debug] 22#0: epoll: fd:6 ev:0001 d:00007FE76C211108
server  | 2025/04/30 09:39:11 [debug] 22#0: quic recvmsg on 0.0.0.0:443, ready: 0
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic recvmsg: fd:6 n:43
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic input handler
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic packet rx short flags:79
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic packet rx dcid len:20 00000000000020026fcefba6ae8b3b98c592f6ab
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic packet rx clearflags:60
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic packet rx number:5 len:1
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic packet len:43 via sock seq:0 path seq:0
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic path seq:0 status tx:12657 rx:4171 valid:1 st:2 mtu:1200
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic frame rx app:5 ACK n:0 delay:3 7-0
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic ngx_quic_handle_ack_frame level:3
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic congestion slow start win:140654 ss:-1 if:3006
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic stream id:0x0 ack len:1176 fin:0 unacked:2929
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic congestion slow start win:141854 ss:-1 if:1806
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic stream id:0x0 ack len:1176 fin:0 unacked:1753
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic updated largest received ack:7
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic rtt sample latest:40 min:35 avg:36 var:9
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 event timer del: 6: 320568
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic lost timer pto:52
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 event timer add: 6: 52:320565
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic ngx_quic_ack_packet pn:5 largest 4 fr:3 nranges:0
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic packet done rc:0 level:app decr:1 pn:5 perr:0
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 event timer: 6, old: 350439, new: 350513
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic state: read:29926 push:19 pto:52
server  | 2025/04/30 09:39:11 [debug] 22#0: timer delta: 2
server  | 2025/04/30 09:39:11 [debug] 22#0: worker cycle
server  | 2025/04/30 09:39:11 [debug] 22#0: epoll timer: 19
server  | 2025/04/30 09:39:11 [debug] 22#0: epoll: fd:6 ev:0001 d:00007FE76C211108
server  | 2025/04/30 09:39:11 [debug] 22#0: quic recvmsg on 0.0.0.0:443, ready: 0
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic recvmsg: fd:6 n:43
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic input handler
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic packet rx short flags:5b
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic packet rx dcid len:20 00000000000020026fcefba6ae8b3b98c592f6ab
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic packet rx clearflags:40
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic packet rx number:6 len:1
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic packet len:43 via sock seq:0 path seq:0
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic path seq:0 status tx:12657 rx:4214 valid:1 st:2 mtu:1200
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic frame rx app:6 ACK n:0 delay:3 9-0
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic ngx_quic_handle_ack_frame level:3
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic congestion slow start win:143054 ss:-1 if:606
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic stream id:0x0 ack len:1176 fin:0 unacked:577
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic congestion slow start win:143660 ss:-1 if:0
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic stream id:0x0 ack len:577 fin:0 unacked:0
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic stream id:0x0 ack len:0 fin:1 unacked:0
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic stream id:0x0 close
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 reusable connection: 1
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 post event 0000555A885A44A8
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic updated largest received ack:9
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic rtt sample latest:42 min:35 avg:37 var:8
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 event timer del: 6: 320565
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic lost timer unset
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic ngx_quic_ack_packet pn:6 largest 5 fr:4 nranges:0
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic packet done rc:0 level:app decr:1 pn:6 perr:0
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 event timer: 6, old: 350439, new: 350515
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic state: read:29924 push:17
server  | 2025/04/30 09:39:11 [debug] 22#0: timer delta: 2
server  | 2025/04/30 09:39:11 [debug] 22#0: posted event 0000555A885A44A8
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 delete posted event 0000555A885A44A8
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic push handler
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic output app packet max:1200 min:0
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic frame tx app:10 ACK n:0 delay:0 6-1
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic frame tx app:10 MAX_STREAMS limit:129 bidi:1
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic packet tx app bytes:8 need_ack:1 number:10 encoded nl:1 trunc:0xa
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 sendmsg: 26 of 26
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic congestion send if:0
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic congestion send if:0
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic congestion send if:26
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 event timer: 6, old: 350439, new: 350515
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic lost timer pto:89
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 event timer add: 6: 89:320604
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic state: send:29924 push:17 pto:89
server  | 2025/04/30 09:39:11 [debug] 22#0: worker cycle
server  | 2025/04/30 09:39:11 [debug] 22#0: epoll timer: 17
server  | 2025/04/30 09:39:11 [debug] 22#0: epoll: fd:6 ev:0001 d:00007FE76C211108
server  | 2025/04/30 09:39:11 [debug] 22#0: quic recvmsg on 0.0.0.0:443, ready: 0
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic recvmsg: fd:6 n:54
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic input handler
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic packet rx short flags:7c
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic packet rx dcid len:20 00000000000020026fcefba6ae8b3b98c592f6ab
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic packet rx clearflags:60
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic packet rx number:7 len:1
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic packet len:54 via sock seq:0 path seq:0
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic path seq:0 status tx:12683 rx:4268 valid:1 st:2 mtu:1200
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic frame rx app:7 ACK n:0 delay:21 9-0
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic ngx_quic_handle_ack_frame level:3
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 event timer del: 6: 320604
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic lost timer pto:89
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 event timer add: 6: 89:320604
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic frame rx app:7 CONNECTION_CLOSE_APP err:0 kthxbye!
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 post event 0000555A885A4568
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic ngx_quic_ack_packet pn:7 largest 6 fr:5 nranges:0
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic packet done rc:0 level:app decr:1 pn:7 perr:0
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 event timer: 6, old: 350439, new: 350515
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic state: draining read:29924 push:17 pto:89
server  | 2025/04/30 09:39:11 [debug] 22#0: timer delta: 0
server  | 2025/04/30 09:39:11 [debug] 22#0: posted event 0000555A885A4568
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 delete posted event 0000555A885A4568
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic close handler
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic close initiated rc:0
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic close immediate term:0 drain:1 error:1 ""
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 event timer add: 6: 267:320782
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 event timer del: 6: 320532
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 event timer del: 6: 320604
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 event timer del: 6: 320573
server  | 2025/04/30 09:39:11 [debug] 22#0: worker cycle
server  | 2025/04/30 09:39:11 [debug] 22#0: epoll timer: 267
client  | 0.147 DEBUG [Client 9d08d5a9a63faab47bd435f7aec130267c] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.147 DEBUG Building Short dcid Some(CID [20]: 00000000000020026fcefba6ae8b3b98c592f6ab)
client  | 0.147 DEBUG [Recvd-ap] immediate_ack at Instant { tv_sec: 320, tv_nsec: 530480576 }
client  | 0.147 DEBUG [Client 9d08d5a9a63faab47bd435f7aec130267c] pn=8 type=Short pri-path:00000000000020026fcefba6ae8b3b98c592f6ab 0.0.0.0:46696->193.167.100.100:443 IpTos(Cs0, NotEct) len 55
client  |   TX -> Ack { largest_acknowledged: 9, ack_delay: 3839, first_ack_range: 9, ack_ranges: [], ecn_count: None }
client  |   TX -> ConnectionClose { error_code: Application(0), frame_type: 0, reason_phrase: "kthxbye!" }
client  | 0.148 DEBUG Setting timeout of 270.577407ms
client  | 0.148 DEBUG Setting timeout of 270.564964ms
server  | 2025/04/30 09:39:11 [debug] 22#0: epoll: fd:6 ev:0001 d:00007FE76C211108
server  | 2025/04/30 09:39:11 [debug] 22#0: quic recvmsg on 0.0.0.0:443, ready: 0
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic recvmsg: fd:6 n:55
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic input handler
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic packet rx short flags:6d
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic packet rx dcid len:20 00000000000020026fcefba6ae8b3b98c592f6ab
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic packet rx clearflags:60
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic packet rx number:8 len:1
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic packet len:55 via sock seq:0 path seq:0
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic path seq:0 status tx:12683 rx:4323 valid:1 st:2 mtu:1200
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic packet done rc:0 level:app decr:1 pn:8 perr:0
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 event timer: 6, old: 350439, new: 350545
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic state: error:0 "connection is closing, packet discarded" closing draining read:29894 close:237
server  | 2025/04/30 09:39:11 [debug] 22#0: timer delta: 30
server  | 2025/04/30 09:39:11 [debug] 22#0: worker cycle
server  | 2025/04/30 09:39:11 [debug] 22#0: epoll timer: 237
server  | 2025/04/30 09:39:11 [debug] 22#0: timer delta: 238
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 event timer del: 6: 320782
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic close handler
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic close resumed rc:0
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic socket seq:0 closed nsock:7
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic socket seq:1 closed nsock:6
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic socket seq:2 closed nsock:5
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic socket seq:3 closed nsock:4
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic socket seq:4 closed nsock:3
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic socket seq:5 closed nsock:2
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic socket seq:6 closed nsock:1
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic socket seq:7 closed nsock:0
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic close completed
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 quic ngx_quic_send_alert() level:app alert:0
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 SSL_shutdown: 1
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 event timer del: 6: 350439
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 reusable connection: 0
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 run cleanup: 0000555A88598A38
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 event timer del: -1: 395473
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 free: 0000555A885FB090
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 free: 0000555A885F9E70
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 free: 0000555A885F8E60
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 free: 0000555A885F0200
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 free: 0000555A885EE8B0
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 free: 0000555A88599E10
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 free: 0000555A885A4840
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 free: 0000555A885A3EA0
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 free: 0000555A885BC7F0
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 free: 0000555A885BAB30, unused: 1
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 free: 0000555A885A4E40, unused: 8
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 free: 0000555A885979A0, unused: 8
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 free: 0000555A88597BB0, unused: 40
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 free: 0000555A88598CE0, unused: 40
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 free: 0000555A8859C0C0, unused: 112
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 free: 0000555A88598670, unused: 72
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 free: 0000555A88598880, unused: 0
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 free: 0000555A88598A90, unused: 24
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 free: 0000555A885995F0, unused: 40
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 free: 0000555A88599800, unused: 40
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 free: 0000555A88599A10, unused: 40
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 free: 0000555A885F1210, unused: 0
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 free: 0000555A885F1420, unused: 0
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 free: 0000555A885FAE80, unused: 16
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 free: 0000555A885F1630, unused: 32
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 free: 0000555A885F1840, unused: 32
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 free: 0000555A885F1A50, unused: 32
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 free: 0000555A885F1C60, unused: 32
server  | 2025/04/30 09:39:11 [debug] 22#0: *6 free: 0000555A885F1E70, unused: 112
server  | 2025/04/30 09:39:11 [debug] 22#0: worker cycle
server  | 2025/04/30 09:39:11 [debug] 22#0: epoll timer: -1
client  | 0.419 DEBUG [Client 9d08d5a9a63faab47bd435f7aec130267c] State change from Closing { error: Application(0), timeout: Instant { tv_sec: 320, tv_nsec: 801150336 } } -> Closed(Application(0))
client  | 0.419 INFO Closing timer expired
client  | 0.419 DEBUG Output::None
client  | 0.419 WARN Unhandled event StateChange(Closed(Application(0)))
client  | 0.419 DEBUG Timer fired while closed
client  | 0.419 DEBUG Output::None

client exited with code 0
Aborting on container exit...
 Container server  Stopping
 Container client  Stopping
 Container client  Stopped
 Container server  Stopped
 Container sim  Stopping
 Container sim  Stopped

2025-04-30 09:39:21,778 Using the client's key log file.
2025-04-30 09:39:21,788 
2025-04-30 09:39:21,788 Using the client's key log file.
2025-04-30 09:39:21,788 Using the client's key log file.
2025-04-30 09:39:21,797 
2025-04-30 09:39:21,797 Using the client's key log file.
2025-04-30 09:39:22,364 Check of downloaded files succeeded.
2025-04-30 09:39:22,940 Check of Retry succeeded. Token used: 31ca79d51f7af89abcea27b28efe94375ec1ff96ec54927b40195972b2eb4ea8a35c0b7cfc597c1e02395a6ef1bc4e9e9a0144c41e8ab840e187cb8697e6bb87b8da79185aa459b8c5720b