2025-09-12 05:44:27,039 Generated random file: fqhsqhtolo of size: 1024
2025-09-12 05:44:27,039 Requests: https://server4:443/fqhsqhtolo
2025-09-12 05:44:27,096 
2025-09-12 05:44:27,096 Command: WAITFORSERVER=server:443 CERTS=/tmp/certs_u93sb23_/ TESTCASE_SERVER=handshake TESTCASE_CLIENT=handshake WWW=/tmp/www_4nb01s0w/ DOWNLOADS=/tmp/download_sf2pd48x/ SERVER_LOGS=/tmp/logs_server_ebbrdk7d CLIENT_LOGS=/tmp/logs_client_qnv001en SCENARIO="simple-p2p --delay=15ms --bandwidth=10Mbps --queue=25" CLIENT=ghcr.io/mozilla/neqo-qns:latest SERVER=haproxytech/haproxy-qns:latest REQUESTS="https://server4:443/fqhsqhtolo"  docker compose --env-file empty.env up --abort-on-container-exit --timeout 1 sim client server 
2025-09-12 05:44:39,596  Container sim  Recreate
 Container sim  Recreated
 Container client  Recreate
 Container server  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-checksum-ip-generic: off
server  | tx-tcp-segmentation: off [not requested]
server  | tx-tcp-ecn-segmentation: off [not requested]
server  | tx-tcp-mangleid-segmentation: off [not requested]
server  | tx-tcp6-segmentation: off [not requested]
server  | tx-udp-segmentation: off [not requested]
server  | tx-checksum-sctp: off
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
client  | Endpoint's IPv4 address is 193.167.0.100
server  | starting lighttpd server
client  | Endpoint's IPv6 address is fd00:cafe:cafe::100
client  | + export PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/neqo/bin
client  | + PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/neqo/bin
client  | + '[' -n handshake ']'
client  | + '[' -n /logs/qlog/ ']'
client  | + case "$ROLE" in
client  | + /wait-for-it.sh sim:57832 -s -t 30
client  | wait-for-it.sh: waiting 30 seconds for sim:57832
server  | haproxy version HAProxy version 0678d0a69b1a2a903781e33153630ae203a72aa7 2025/09/05 - https://haproxy.org/
server  | Status: development branch - not safe for use in production.
server  | Known bugs: https://github.com/haproxy/haproxy/issues?q=is:issue+is:open
server  | Running on: Linux 6.11.0-1018-azure #18~24.04.1-Ubuntu SMP Sat Jun 28 04:46:03 UTC 2025 x86_64
server  | starting haproxy...
sim     | server:443 is available after 501.649878ms
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/fqhsqhtolo ']'
client  | + mapfile -d ' ' -t URLS
client  | + OPTIONS+=("${URLS[@]}")
client  | + RUST_LOG=debug
client  | + RUST_BACKTRACE=1
client  | + neqo-client --cc cubic --qns-test handshake --qlog-dir /logs/qlog/ --output-dir /downloads 'https://server4:443/fqhsqhtolo
client  | '
client  | ++ tee -i -a /logs/client.log
client  | 0.000 DEBUG Logging initialized
client  | 0.001 DEBUG Default socket send buffer size is Ok(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:47472 -> 193.167.100.100:443
client  | 0.001 DEBUG [CryptoStates] Creating initial cipher state v=Version1, role=Client dcid=2d9655066d044d67aa38
client  | 0.001 DEBUG Making Write Initial CryptoDxState, v=Version1 cipher=4865 min_pn=17
client  | 0.001 DEBUG Making Read Initial CryptoDxState, v=Version1 cipher=4865 min_pn=0
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:47472->193.167.100.100:443] Make permanent
client  | 0.001 DEBUG [unv-path:2d9655066d044d67aa38 0.0.0.0:47472->193.167.100.100:443] set as primary path
client  | 0.001 DEBUG [pri-unv-path:2d9655066d044d67aa38 0.0.0.0:47472->193.167.100.100:443] Path validated Instant { tv_sec: 214, tv_nsec: 713830996 }
client  | 0.001 DEBUG [Client 2d9655066d044d67aa38] client_start
client  | 0.001 DEBUG Writing transport parameters, msg=1
client  | 0.002 DEBUG [Agent 0x55e424dae500] state -> InProgress
client  | 0.002 DEBUG [Client 2d9655066d044d67aa38] State change from Init -> WaitInitial
client  | 0.002 DEBUG [Client 2d9655066d044d67aa38] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.002 DEBUG Building Initial dcid Some(CID [10]: 2d9655066d044d67aa38) scid Some(CID [0]: )
client  | 0.002 DEBUG CRYPTO for in offset=0, len=1211
client  | 0.002 DEBUG [Client 2d9655066d044d67aa38] pn=17 type=Initial pri-path:2d9655066d044d67aa38 0.0.0.0:47472->193.167.100.100:443 Tos(Cs0, NotEct) len 1252
client  |   TX -> Crypto { offset: 0, len: 1211 }
client  | 0.002 DEBUG packet_sent this=0x55e424dc1af0, pn=17, ps=1252
client  | 0.002 DEBUG [Client 2d9655066d044d67aa38] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.002 DEBUG Building Initial dcid Some(CID [10]: 2d9655066d044d67aa38) scid Some(CID [0]: )
client  | 0.002 DEBUG CRYPTO for in offset=1211, len=329
client  | 0.002 DEBUG [Client 2d9655066d044d67aa38] pn=18 type=Initial pri-path:2d9655066d044d67aa38 0.0.0.0:47472->193.167.100.100:443 Tos(Cs0, NotEct) len 371
client  |   TX -> Crypto { offset: 1211, len: 329 }
client  | 0.002 DEBUG [Client 2d9655066d044d67aa38] pad Initial from 371 to PLPMTU 1252
client  | 0.002 DEBUG packet_sent this=0x55e424dc1af0, pn=18, ps=1252
client  | 0.002 DEBUG [Client 2d9655066d044d67aa38] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
client  | 0.002 DEBUG Building Initial dcid Some(CID [10]: 2d9655066d044d67aa38) 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 2d9655066d044d67aa38] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
client  | 0.002 DEBUG Building Initial dcid Some(CID [10]: 2d9655066d044d67aa38) 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 2d9655066d044d67aa38] delay duration 3.871419ms
client  | 0.002 DEBUG Setting timeout of 3.871419ms
client  | 0.002 DEBUG StateChange(WaitInitial)
client  | 0.002 WARN Cannot create stream ConnectionState
client  | 0.002 DEBUG [Client 2d9655066d044d67aa38] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
client  | 0.002 DEBUG Building Initial dcid Some(CID [10]: 2d9655066d044d67aa38) 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 2d9655066d044d67aa38] delay duration 3.842024ms
client  | 0.002 DEBUG Setting timeout of 3.842024ms
client  | 0.007 DEBUG [Client 2d9655066d044d67aa38] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.007 DEBUG Building Initial dcid Some(CID [10]: 2d9655066d044d67aa38) 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 2d9655066d044d67aa38] delay duration 294.293259ms
client  | 0.007 DEBUG Setting timeout of 294.293259ms
client  | 0.042 DEBUG [Client 2d9655066d044d67aa38] pn=0 type=Initial pri-path:2d9655066d044d67aa38 0.0.0.0:47472->193.167.100.100:443 Tos(Cs0, NotEct) len 135
client  |   -> RX Ack { largest_acknowledged: 18, ack_delay: 250, first_ack_range: 1, ack_ranges: [], ecn_count: None }
client  |   -> RX Crypto { offset: 0, len: 90 }
client  | 0.042 DEBUG [Client 2d9655066d044d67aa38] Rx ACK space=in, ranges=[17..=18]
client  | 0.042 DEBUG [recovery::Loss] ACK for Initial - largest_acked=18
client  | 0.042 DEBUG on_packets_acked this=0x55e424dc1af0, limited=1, bytes_in_flight=0, cwnd=12520, state=SlowStart, new_acked=2504
client  | 0.042 DEBUG Acked crypto frame space=in offset=1211 length=329
client  | 0.042 DEBUG Acked crypto frame space=in offset=0 length=1211
client  | 0.043 DEBUG Write secret available for Handshake: SymKey [48]: 4e7e01d76728475ba92c364fadd506dadd9560d164c1930c60b6b5673978adbefc315698a4e29315a6d53aadc946fe03
client  | 0.043 DEBUG Read secret available for Handshake: SymKey [48]: a01834b5dfcbf5596452ceaf3092505c83da475eb48bd57dbbf41d25abc800c721d83f43b2585c9fd422ef06e3f0e03f
client  | 0.043 DEBUG [Agent 0x55e424dae500] state -> InProgress
client  | 0.043 DEBUG Making Write Handshake CryptoDxState, v=Version1 cipher=4866 min_pn=0
client  | 0.043 DEBUG Making Read Handshake CryptoDxState, v=Version1 cipher=4866 min_pn=0
client  | 0.043 DEBUG [Crypto] Handshake keys installed
client  | 0.043 DEBUG [Recvd-in] Set ACK timer to Instant { tv_sec: 214, tv_nsec: 755543756 }
client  | 0.043 DEBUG [Client 2d9655066d044d67aa38] Changing to use Server CID=b3313a146509ff78
client  | 0.043 DEBUG [Client 2d9655066d044d67aa38] State change from WaitInitial -> Handshaking
client  | 0.043 DEBUG [Client 2d9655066d044d67aa38] pn=0 type=Handshake pri-path:b3313a146509ff78 0.0.0.0:47472->193.167.100.100:443 Tos(Cs0, NotEct) len 1065
client  |   -> RX Crypto { offset: 0, len: 732 }
client  |   -> RX Padding { len: 295 }
client  | 0.044 DEBUG [Agent 0x55e424dae500] state -> AuthenticationPending
client  | 0.044 DEBUG [Recvd-hs] Set ACK timer to Instant { tv_sec: 214, tv_nsec: 755543756 }
client  | 0.044 DEBUG [Client 2d9655066d044d67aa38] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.044 DEBUG Building Initial dcid Some(CID [8]: b3313a146509ff78) scid Some(CID [0]: )
client  | 0.044 DEBUG [Client 2d9655066d044d67aa38] pn=19 type=Initial pri-path:b3313a146509ff78 0.0.0.0:47472->193.167.100.100:443 Tos(Cs0, NotEct) len 41
client  |   TX -> Ack { largest_acknowledged: 0, ack_delay: 184, first_ack_range: 0, ack_ranges: [], ecn_count: None }
client  | 0.044 DEBUG Building Handshake dcid Some(CID [8]: b3313a146509ff78) scid Some(CID [0]: )
client  | 0.044 DEBUG [Client 2d9655066d044d67aa38] pn=0 type=Handshake pri-path:b3313a146509ff78 0.0.0.0:47472->193.167.100.100:443 Tos(Cs0, NotEct) len 81
client  |   TX -> Ack { largest_acknowledged: 0, ack_delay: 184, first_ack_range: 0, ack_ranges: [], ecn_count: None }
client  | 0.044 DEBUG [Client 2d9655066d044d67aa38] Drop packet number space in
client  | 0.044 DEBUG [recovery::Loss] Reset loss recovery state for Initial
client  | 0.044 INFO [recovery::Loss] ignoring in-19 from dropped space
client  | 0.044 DEBUG [Client 2d9655066d044d67aa38] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.044 DEBUG Building Handshake dcid Some(CID [8]: b3313a146509ff78) scid Some(CID [0]: )
client  | 0.044 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.044 DEBUG [Client 2d9655066d044d67aa38] delay duration 123.340393ms
client  | 0.044 DEBUG Setting timeout of 123.340393ms
client  | 0.044 DEBUG StateChange(Handshaking)
client  | 0.044 WARN Cannot create stream ConnectionState
client  | 0.044 DEBUG [Client 2d9655066d044d67aa38] Authenticated Ok
client  | 0.044 DEBUG Write secret available for ApplicationData: SymKey [48]: 10ab76edccf9108096c79433f9fec6990b842e5def7f4ef9d27989fbc13eb764104d022ba24bce0dc40bba14afd69274
client  | 0.044 DEBUG Read secret available for ApplicationData: SymKey [48]: 3eab2b79a3db96a045009755f1c3fa64ef58c88fdde36eeeafb44abbd6a20fcee381cf9179ef11a2847092a66293033e
client  | 0.044 DEBUG [Agent 0x55e424dae500] SSL_AuthCertificateComplete: Ok(())
client  | 0.044 DEBUG [Agent 0x55e424dae500] state -> Complete(SecretAgentInfo { version: 772, cipher: 4866, group: 29, resumed: false, early_data: false, ech_accepted: false, alpn: Some("hq-interop"), signature_scheme: 1027 })
client  | 0.044 DEBUG [Client 2d9655066d044d67aa38] TLS connection complete
client  | 0.044 DEBUG Making Write ApplicationData CryptoDxState, v=Version1 cipher=4866 min_pn=0
client  | 0.044 DEBUG [Crypto] Application write key installed
client  | 0.044 DEBUG Making Read ApplicationData CryptoDxState, v=Version1 cipher=4866 min_pn=0
client  | 0.044 DEBUG [Crypto] application read keys installed
client  | 0.044 DEBUG [Client 2d9655066d044d67aa38] State change from Handshaking -> Connected
client  | 0.044 INFO [Client 2d9655066d044d67aa38] Connection established
client  | 0.044 DEBUG stream BiDi creatable
client  | 0.044 INFO Created stream 0 for https://server4/fqhsqhtolo
client  | 0.044 INFO Saving https://server4/fqhsqhtolo to "/downloads/fqhsqhtolo"
client  | 0.044 DEBUG stream UniDi creatable
client  | 0.044 DEBUG StateChange(Connected)
client  | 0.044 DEBUG stream 0 writable
client  | 0.044 DEBUG [Client 2d9655066d044d67aa38] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.044 DEBUG Building Handshake dcid Some(CID [8]: b3313a146509ff78) scid Some(CID [0]: )
client  | 0.044 DEBUG CRYPTO for hs offset=0, len=52
client  | 0.044 DEBUG [Client 2d9655066d044d67aa38] pn=1 type=Handshake pri-path:b3313a146509ff78 0.0.0.0:47472->193.167.100.100:443 Tos(Cs0, NotEct) len 89
client  |   TX -> Crypto { offset: 0, len: 52 }
client  | 0.044 DEBUG packet_sent this=0x55e424dc1af0, pn=1, ps=89
client  | 0.044 DEBUG Building Short dcid Some(CID [8]: b3313a146509ff78)
client  | 0.044 DEBUG [Client 2d9655066d044d67aa38] pn=0 type=Short pri-path:b3313a146509ff78 0.0.0.0:47472->193.167.100.100:443 Tos(Cs0, NotEct) len 135
client  |   TX -> Stream { stream_id: 0, offset: 0, len: 17, fin: true }
client  | 0.044 DEBUG packet_sent this=0x55e424dc1af0, pn=0, ps=46
client  | 0.044 DEBUG [Client 2d9655066d044d67aa38] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.044 DEBUG Building Handshake dcid Some(CID [8]: b3313a146509ff78) scid Some(CID [0]: )
client  | 0.044 DEBUG Building Short dcid Some(CID [8]: b3313a146509ff78)
client  | 0.044 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.044 DEBUG [Client 2d9655066d044d67aa38] delay duration 123.33188ms
client  | 0.044 DEBUG Setting timeout of 123.33188ms
client  | 0.077 DEBUG [Client 2d9655066d044d67aa38] pn=1 type=Handshake pri-path:b3313a146509ff78 0.0.0.0:47472->193.167.100.100:443 Tos(Cs0, NotEct) len 38
client  |   -> RX Ack { largest_acknowledged: 1, ack_delay: 0, first_ack_range: 1, ack_ranges: [], ecn_count: None }
client  | 0.077 DEBUG [Client 2d9655066d044d67aa38] Rx ACK space=hs, ranges=[0..=1]
client  | 0.077 DEBUG [recovery::Loss] ACK for Handshake - largest_acked=1
client  | 0.077 DEBUG on_packets_acked this=0x55e424dc1af0, limited=1, bytes_in_flight=46, cwnd=12520, state=SlowStart, new_acked=89
client  | 0.077 DEBUG Acked crypto frame space=hs offset=0 length=52
client  | 0.077 DEBUG [Client 2d9655066d044d67aa38] pn=0 type=Short pri-path:b3313a146509ff78 0.0.0.0:47472->193.167.100.100:443 Tos(Cs0, NotEct) len 568
client  |   -> RX Crypto { offset: 0, len: 546 }
client  | 0.077 DEBUG [0x55e424dae500] Got resumption token [936]: 0200063e9425b2d6..4d6755728eb35972
client  | 0.077 DEBUG [0x55e424dae500] Got resumption token [936]: 0200063e9425b2d6..483a58f997c903ef
client  | 0.077 DEBUG [Agent 0x55e424dae500] state -> Complete(SecretAgentInfo { version: 772, cipher: 4866, group: 29, resumed: false, early_data: false, ech_accepted: false, alpn: Some("hq-interop"), signature_scheme: 1027 })
client  | 0.077 DEBUG setting max_stream_data to 1474200
client  | 0.077 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 214, tv_nsec: 810058015 }
client  | 0.077 DEBUG [Client 2d9655066d044d67aa38] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.077 DEBUG Building Handshake dcid Some(CID [8]: b3313a146509ff78) scid Some(CID [0]: )
client  | 0.077 DEBUG Building Short dcid Some(CID [8]: b3313a146509ff78)
client  | 0.077 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.077 DEBUG [Client 2d9655066d044d67aa38] delay duration 19.826795ms
client  | 0.077 DEBUG Setting timeout of 19.826795ms
client  | 0.077 DEBUG stream BiDi creatable
client  | 0.077 DEBUG stream UniDi creatable
client  | 0.077 DEBUG [Client 2d9655066d044d67aa38] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.077 DEBUG Building Handshake dcid Some(CID [8]: b3313a146509ff78) scid Some(CID [0]: )
client  | 0.077 DEBUG Building Short dcid Some(CID [8]: b3313a146509ff78)
client  | 0.077 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.077 DEBUG [Client 2d9655066d044d67aa38] delay duration 19.727829ms
client  | 0.077 DEBUG Setting timeout of 19.727829ms
client  | 0.078 DEBUG [Client 2d9655066d044d67aa38] pn=1 type=Short pri-path:b3313a146509ff78 0.0.0.0:47472->193.167.100.100:443 Tos(Cs0, NotEct) len 147
client  |   -> RX Ack { largest_acknowledged: 0, ack_delay: 0, first_ack_range: 0, ack_ranges: [], ecn_count: None }
client  |   -> RX HandshakeDone
client  |   -> RX NewToken { token: [183, 197, 76, 59, 213, 107, 146, 188, 159, 225, 27, 35, 191, 110, 33, 217, 201, 248, 199, 181, 169, 219, 35, 25, 154, 14, 30, 60, 201, 216, 29, 229, 58, 195, 234, 249, 195] }
client  |   -> RX NewConnectionId { sequence_number: 1, retire_prior: 0, connection_id: [203, 72, 15, 80, 187, 1, 20, 252], stateless_reset_token: [26, 118, 181, 56, 53, 231, 238, 64, 185, 207, 244, 223, 1, 125, 86, 72] }
client  |   -> RX NewConnectionId { sequence_number: 2, retire_prior: 0, connection_id: [89, 225, 27, 131, 78, 47, 209, 106], stateless_reset_token: [60, 225, 210, 192, 142, 29, 31, 162, 20, 57, 49, 13, 240, 41, 193, 56] }
client  |   -> RX NewConnectionId { sequence_number: 3, retire_prior: 0, connection_id: [200, 125, 37, 52, 29, 71, 93, 179], stateless_reset_token: [86, 171, 160, 196, 72, 30, 39, 122, 9, 193, 170, 129, 68, 254, 150, 144] }
client  | 0.078 DEBUG [Client 2d9655066d044d67aa38] Rx ACK space=ap, ranges=[0..=0]
client  | 0.078 DEBUG [recovery::Loss] ACK for ApplicationData - largest_acked=0
client  | 0.078 DEBUG on_packets_acked this=0x55e424dc1af0, limited=1, bytes_in_flight=0, cwnd=12520, state=SlowStart, new_acked=46
client  | 0.078 DEBUG [Client 2d9655066d044d67aa38] State change from Connected -> Confirmed
client  | 0.078 DEBUG PMTUD started with probe size 1380
client  | 0.078 DEBUG [Client 2d9655066d044d67aa38] Drop packet number space hs
client  | 0.078 DEBUG [recovery::Loss] Reset loss recovery state for Handshake
client  | 0.078 DEBUG [Client 2d9655066d044d67aa38] No preferred address to migrate to
client  | 0.078 DEBUG resumption token [1081]: 0000000127406400..483a58f997c903ef
client  | 0.078 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 214, tv_nsec: 790783494 }
client  | 0.078 DEBUG [Client 2d9655066d044d67aa38] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.078 DEBUG Building Short dcid Some(CID [8]: b3313a146509ff78)
client  | 0.078 DEBUG Sending PMTUD probe of size 1380, count 1
client  | 0.078 DEBUG [Client 2d9655066d044d67aa38] pn=1 type=Short pri-path:b3313a146509ff78 0.0.0.0:47472->193.167.100.100:443 Tos(Cs0, Ect0) len 1352
client  |   TX -> Ack { largest_acknowledged: 1, ack_delay: 12, first_ack_range: 1, ack_ranges: [], ecn_count: None }
client  |   TX -> Ping
client  |   TX -> Padding { len: 1320 }
client  | 0.078 DEBUG packet_sent this=0x55e424dc1af0, pn=1, ps=1352
client  | 0.078 DEBUG [Client 2d9655066d044d67aa38] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.078 DEBUG Building Short dcid Some(CID [8]: b3313a146509ff78)
client  | 0.078 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.078 DEBUG ECN probing: sent 1 probes
client  | 0.078 DEBUG [Client 2d9655066d044d67aa38] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.078 DEBUG Building Short dcid Some(CID [8]: b3313a146509ff78)
client  | 0.078 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.078 DEBUG [Client 2d9655066d044d67aa38] delay duration 123.793941ms
client  | 0.078 DEBUG Setting timeout of 123.793941ms
client  | 0.078 DEBUG stream 0 complete
client  | 0.078 WARN Unhandled event StateChange(Confirmed)
client  | 0.078 DEBUG [Client 2d9655066d044d67aa38] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.078 DEBUG Building Short dcid Some(CID [8]: b3313a146509ff78)
client  | 0.078 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.078 DEBUG [Client 2d9655066d044d67aa38] delay duration 123.767561ms
client  | 0.078 DEBUG Setting timeout of 123.767561ms
client  | 0.079 DEBUG [Client 2d9655066d044d67aa38] pn=2 type=Short pri-path:b3313a146509ff78 0.0.0.0:47472->193.167.100.100:443 Tos(Cs0, NotEct) len 1046
client  |   -> RX Stream { stream_id: 0, offset: 0, len: 1024, fin: true }
client  | 0.079 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 214, tv_nsec: 812683583 }
client  | 0.079 DEBUG [Client 2d9655066d044d67aa38] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.079 DEBUG Building Short dcid Some(CID [8]: b3313a146509ff78)
client  | 0.079 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.079 DEBUG [Client 2d9655066d044d67aa38] delay duration 19.975294ms
client  | 0.079 DEBUG Setting timeout of 19.975294ms
client  | 0.080 DEBUG [Client 2d9655066d044d67aa38] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.080 DEBUG Building Short dcid Some(CID [8]: b3313a146509ff78)
client  | 0.080 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.080 DEBUG [Client 2d9655066d044d67aa38] delay duration 19.926502ms
client  | 0.080 DEBUG Setting timeout of 19.926502ms
client  | 0.080 DEBUG [Client 2d9655066d044d67aa38] State change from Confirmed -> Closing { error: Application(0), timeout: Instant { tv_sec: 215, tv_nsec: 164377490 } }
client  | 0.080 WARN Unhandled event StateChange(Closing { error: Application(0), timeout: Instant { tv_sec: 215, tv_nsec: 164377490 } })
client  | 0.080 DEBUG [Client 2d9655066d044d67aa38] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.080 DEBUG Building Short dcid Some(CID [8]: b3313a146509ff78)
client  | 0.080 DEBUG [Recvd-ap] immediate_ack at Instant { tv_sec: 214, tv_nsec: 792788730 }
client  | 0.080 DEBUG [Client 2d9655066d044d67aa38] pn=2 type=Short pri-path:b3313a146509ff78 0.0.0.0:47472->193.167.100.100:443 Tos(Cs0, Ect0) len 42
client  |   TX -> Ack { largest_acknowledged: 2, ack_delay: 13, first_ack_range: 2, ack_ranges: [], ecn_count: None }
client  |   TX -> ConnectionClose { error_code: Application(0), frame_type: 0, reason_phrase: "kthxbye!" }
client  | 0.080 DEBUG ECN probing: sent 2 probes
client  | 0.080 DEBUG Setting timeout of 371.502168ms
client  | 0.111 DEBUG [Client 2d9655066d044d67aa38] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.111 DEBUG Building Short dcid Some(CID [8]: b3313a146509ff78)
client  | 0.111 DEBUG [Recvd-ap] immediate_ack at Instant { tv_sec: 214, tv_nsec: 823800015 }
client  | 0.111 DEBUG [Client 2d9655066d044d67aa38] pn=3 type=Short pri-path:b3313a146509ff78 0.0.0.0:47472->193.167.100.100:443 Tos(Cs0, Ect0) len 43
client  |   TX -> Ack { largest_acknowledged: 2, ack_delay: 3889, first_ack_range: 2, ack_ranges: [], ecn_count: None }
client  |   TX -> ConnectionClose { error_code: Application(0), frame_type: 0, reason_phrase: "kthxbye!" }
client  | 0.111 DEBUG ECN probing: sent 3 probes
client  | 0.111 DEBUG Setting timeout of 340.517032ms
client  | 0.111 DEBUG Setting timeout of 340.507795ms
client  | 0.452 DEBUG [Client 2d9655066d044d67aa38] State change from Closing { error: Application(0), timeout: Instant { tv_sec: 215, tv_nsec: 164377490 } } -> Closed(Application(0))
client  | 0.452 INFO Closing timer expired
client  | 0.452 DEBUG Output::None
client  | 0.452 WARN Unhandled event StateChange(Closed(Application(0)))
client  | 0.452 DEBUG Timer fired while closed
client  | 0.452 DEBUG Output::None

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

2025-09-12 05:44:39,674 Using the client's key log file.
2025-09-12 05:44:39,683 
2025-09-12 05:44:39,683 Using the client's key log file.
2025-09-12 05:44:39,683 Using the client's key log file.
2025-09-12 05:44:39,691 
2025-09-12 05:44:39,691 Using the client's key log file.
2025-09-12 05:44:39,692 Using selector: EpollSelector
2025-09-12 05:44:39,920 Check of downloaded files succeeded.