2025-04-30 08:41:45,944 Generated random file: chnoeryysi of size: 1024
2025-04-30 08:41:45,944 Requests: https://server4:443/chnoeryysi
2025-04-30 08:41:46,002 
2025-04-30 08:41:46,003 Command: WAITFORSERVER=server:443 CERTS=/tmp/certs_6d2fip4g/ TESTCASE_SERVER=handshake TESTCASE_CLIENT=handshake WWW=/tmp/www_n1_asuzq/ DOWNLOADS=/tmp/download_8zptyw8u/ SERVER_LOGS=/tmp/logs_server_kv7iif6f CLIENT_LOGS=/tmp/logs_client_2qr6fldx SCENARIO="simple-p2p --delay=15ms --bandwidth=10Mbps --queue=25" CLIENT=ghcr.io/mozilla/neqo-qns:latest SERVER=ghcr.io/facebook/proxygen/mvfst-interop:latest REQUESTS="https://server4:443/chnoeryysi"  docker compose --env-file empty.env up --abort-on-container-exit --timeout 1 sim client server 
2025-04-30 08:41:58,472  Container sim  Recreate
 Container sim  Recreated
 Container server  Recreate
 Container client  Recreate
 Container server  Recreated
 Container client  Recreated
Attaching to client, server, sim
sim     | waiting 10s for server:443
server  | + set -o nounset
server  | + VERSION=1
server  | + HQ_CLI=/proxygen/_build/proxygen/bin/hq
server  | + PORT=443
server  | + LOGLEVEL=2
server  | + /setup.sh
client  | Setting up routes...
server  | Setting up routes...
client  | Actual changes:
client  | tx-checksum-ip-generic: off
client  | tx-tcp-segmentation: off [not requested]
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
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  | Endpoint's IPv4 address is 193.167.100.100
client  | Endpoint's IPv4 address is 193.167.0.100
server  | Endpoint's IPv6 address is fd00:cafe:cafe:100::100
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
server  | + PROTOCOL=hq-interop
server  | + HTTPVERSION=0.9
server  | + CONN_FLOW_CONTROL=107374182
server  | + STREAM_FLOW_CONTROL=107374182
server  | ./run_endpoint.sh: line 28: REQUESTS: unbound variable
server  | ++ awk -F / '{ print "/" $4 }'
server  | ++ tr ' ' '\n'
server  | ++ paste -sd,
server  | + INVOCATIONS=
server  | + EARLYDATA=false
server  | + PSK_FILE=
server  | + '[' -n handshake ']'
server  | + case "${TESTCASE}" in
server  | + '[' server == client ']'
server  | + '[' server == server ']'
server  | + echo 'Running QUIC server on [::]:443'
server  | Running QUIC server on [::]:443
server  | + /proxygen/_build/proxygen/bin/hq --mode=server --cert=/certs/cert.pem --key=/certs/priv.key --conn_flow_control=107374182 --stream_flow_control=107374182 --port=443 --httpversion=0.9 --h2port=443 --static_root=/www --logdir=/logs --qlogger_path=/logs --host=:: --congestion=bbr --pacing=true --v=2
server  | + tee /logs/server.log
client  | wait-for-it.sh: waiting 30 seconds for sim:57832
server  | W20250430 08:41:46.708011    25 QuicServerWorker.cpp:1234] HostId is already set to 0
server  | W20250430 08:41:46.708070    25 QuicServerWorker.cpp:1234] HostId is already set to 0
server  | W20250430 08:41:46.708077    25 QuicServerWorker.cpp:1234] HostId is already set to 0
server  | W20250430 08:41:46.708082    25 QuicServerWorker.cpp:1234] HostId is already set to 0
server  | I20250430 08:41:46.708340    25 HQServer.cpp:283] HQ server started at: [::]:443
sim     | server:443 is available after 1.037961801s
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/chnoeryysi ']'
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/chnoeryysi
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:41901 -> 193.167.100.100:443
client  | 0.001 DEBUG [CryptoStates] Creating initial cipher state v=Version1, role=Client dcid=8ef4a4e88c735ab9
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:41901->193.167.100.100:443] Make permanent
client  | 0.001 DEBUG [unv-path:8ef4a4e88c735ab9 0.0.0.0:41901->193.167.100.100:443] set as primary path
client  | 0.001 DEBUG [pri-unv-path:8ef4a4e88c735ab9 0.0.0.0:41901->193.167.100.100:443] Path validated Instant { tv_sec: 172, tv_nsec: 33350809 }
client  | 0.001 DEBUG [Client 8ef4a4e88c735ab9] client_start
client  | 0.001 DEBUG Writing transport parameters, msg=1
client  | 0.002 DEBUG [Agent 0x55b57cd78270] state -> InProgress
client  | 0.002 DEBUG [Client 8ef4a4e88c735ab9] State change from Init -> WaitInitial
client  | 0.002 DEBUG [Client 8ef4a4e88c735ab9] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.002 DEBUG Building Initial dcid Some(CID [8]: 8ef4a4e88c735ab9) scid Some(CID [0]: )
client  | 0.002 DEBUG CRYPTO for in offset=0, len=1213
client  | 0.002 DEBUG [Client 8ef4a4e88c735ab9] pn=0 type=Initial pri-path:8ef4a4e88c735ab9 0.0.0.0:41901->193.167.100.100:443 IpTos(Cs0, Ect0) len 1252
client  |   TX -> Crypto { offset: 0, len: 1213 }
client  | 0.002 DEBUG packet_sent this=0x55b57cd8b970, pn=0, ps=1252
client  | 0.002 DEBUG ECN probing: sent 1 probes
client  | 0.002 DEBUG [Client 8ef4a4e88c735ab9] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.002 DEBUG Building Initial dcid Some(CID [8]: 8ef4a4e88c735ab9) scid Some(CID [0]: )
client  | 0.002 DEBUG CRYPTO for in offset=1213, len=326
client  | 0.002 DEBUG [Client 8ef4a4e88c735ab9] pn=1 type=Initial pri-path:8ef4a4e88c735ab9 0.0.0.0:41901->193.167.100.100:443 IpTos(Cs0, Ect0) len 366
client  |   TX -> Crypto { offset: 1213, len: 326 }
client  | 0.002 DEBUG [Client 8ef4a4e88c735ab9] pad Initial from 366 to PLPMTU 1252
client  | 0.002 DEBUG packet_sent this=0x55b57cd8b970, pn=1, ps=1252
client  | 0.002 DEBUG ECN probing: sent 2 probes
client  | 0.002 DEBUG [Client 8ef4a4e88c735ab9] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
client  | 0.002 DEBUG Building Initial dcid Some(CID [8]: 8ef4a4e88c735ab9) 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 8ef4a4e88c735ab9] delay duration 3.893575ms
client  | 0.002 DEBUG Setting timeout of 3.893575ms
client  | 0.002 DEBUG StateChange(WaitInitial)
client  | 0.002 WARN Cannot create stream ConnectionState
client  | 0.002 DEBUG [Client 8ef4a4e88c735ab9] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
client  | 0.002 DEBUG Building Initial dcid Some(CID [8]: 8ef4a4e88c735ab9) 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 8ef4a4e88c735ab9] delay duration 3.866715ms
client  | 0.002 DEBUG Setting timeout of 3.866715ms
client  | 0.007 DEBUG [Client 8ef4a4e88c735ab9] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.007 DEBUG Building Initial dcid Some(CID [8]: 8ef4a4e88c735ab9) 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 8ef4a4e88c735ab9] delay duration 294.803634ms
client  | 0.007 DEBUG Setting timeout of 294.803634ms
client  | 0.040 DEBUG [Client 8ef4a4e88c735ab9] pn=7077874 type=Initial pri-path:8ef4a4e88c735ab9 0.0.0.0:41901->193.167.100.100:443 IpTos(Cs0, NotEct) len 1232
client  |   -> RX Crypto { offset: 0, len: 90 }
client  |   -> RX Ack { largest_acknowledged: 1, ack_delay: 99, first_ack_range: 1, ack_ranges: [], ecn_count: None }
client  |   -> RX Padding { len: 1095 }
client  | 0.040 DEBUG Read Ok(90) bytes
client  | 0.040 DEBUG Write secret available for Handshake: SymKey [32]: 7abc594eea4d4419b96847bc731a0e26f654d4cebe1906db1e6eaa2ac709ee3f
client  | 0.040 DEBUG Read secret available for Handshake: SymKey [32]: 1ba8bf2618cba081de5bef6ec61fca65f78302af94510388f38a5e74e5e0f170
client  | 0.040 DEBUG [Agent 0x55b57cd78270] state -> InProgress
client  | 0.040 DEBUG Making Write Handshake CryptoDxState, v=Version1 cipher=4865
client  | 0.040 DEBUG Making Read Handshake CryptoDxState, v=Version1 cipher=4865
client  | 0.041 DEBUG [Crypto] Handshake keys installed
client  | 0.041 DEBUG [Client 8ef4a4e88c735ab9] Rx ACK space=in, ranges=[0..=1]
client  | 0.041 DEBUG [LossRecovery] ACK for Initial - largest_acked=1
client  | 0.041 DEBUG on_packets_acked this=0x55b57cd8b970, limited=1, bytes_in_flight=0, cwnd=12520, state=SlowStart, new_acked=2504
client  | 0.041 DEBUG Acked crypto frame space=in offset=1213 length=326
client  | 0.041 DEBUG Acked crypto frame space=in offset=0 length=1213
client  | 0.041 DEBUG [Recvd-in] Set ACK timer to Instant { tv_sec: 172, tv_nsec: 72676850 }
client  | 0.041 DEBUG [Client 8ef4a4e88c735ab9] Changing to use Server CID=4000009f5a7513d6
client  | 0.041 DEBUG [Client 8ef4a4e88c735ab9] State change from WaitInitial -> Handshaking
client  | 0.041 DEBUG [Client 8ef4a4e88c735ab9] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.041 DEBUG Building Initial dcid Some(CID [8]: 4000009f5a7513d6) scid Some(CID [0]: )
client  | 0.041 DEBUG [Client 8ef4a4e88c735ab9] pn=2 type=Initial pri-path:4000009f5a7513d6 0.0.0.0:41901->193.167.100.100:443 IpTos(Cs0, Ect0) len 44
client  |   TX -> Ack { largest_acknowledged: 7077874, ack_delay: 81, first_ack_range: 0, ack_ranges: [], ecn_count: None }
client  | 0.041 DEBUG Building Handshake dcid Some(CID [8]: 4000009f5a7513d6) scid Some(CID [0]: )
client  | 0.041 DEBUG [Client 8ef4a4e88c735ab9] pad Initial from 44 to PLPMTU 1252
client  | 0.041 DEBUG ECN probing: sent 3 probes
client  | 0.041 DEBUG [Client 8ef4a4e88c735ab9] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.041 DEBUG Building Initial dcid Some(CID [8]: 4000009f5a7513d6) scid Some(CID [0]: )
client  | 0.041 DEBUG Building Handshake dcid Some(CID [8]: 4000009f5a7513d6) scid Some(CID [0]: )
client  | 0.041 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.041 DEBUG [Client 8ef4a4e88c735ab9] delay duration 75.868564ms
client  | 0.041 DEBUG Setting timeout of 75.868564ms
client  | 0.041 DEBUG [Client 8ef4a4e88c735ab9] pn=7077874 type=Handshake pri-path:4000009f5a7513d6 0.0.0.0:41901->193.167.100.100:443 IpTos(Cs0, NotEct) len 752
client  |   -> RX Crypto { offset: 0, len: 712 }
client  | 0.041 DEBUG Read Ok(712) bytes
client  | 0.041 DEBUG [Agent 0x55b57cd78270] state -> AuthenticationPending
client  | 0.041 DEBUG [Recvd-hs] Set ACK timer to Instant { tv_sec: 172, tv_nsec: 73456298 }
client  | 0.041 DEBUG [Client 8ef4a4e88c735ab9] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.041 DEBUG Building Initial dcid Some(CID [8]: 4000009f5a7513d6) scid Some(CID [0]: )
client  | 0.041 DEBUG Building Handshake dcid Some(CID [8]: 4000009f5a7513d6) scid Some(CID [0]: )
client  | 0.041 DEBUG [Client 8ef4a4e88c735ab9] pn=0 type=Handshake pri-path:4000009f5a7513d6 0.0.0.0:41901->193.167.100.100:443 IpTos(Cs0, Ect0) len 43
client  |   TX -> Ack { largest_acknowledged: 7077874, ack_delay: 88, first_ack_range: 0, ack_ranges: [], ecn_count: None }
client  | 0.041 DEBUG [Client 8ef4a4e88c735ab9] Drop packet number space in
client  | 0.041 DEBUG [LossRecovery] Reset loss recovery state for Initial
client  | 0.041 DEBUG ECN probing: sent 4 probes
client  | 0.042 DEBUG [Client 8ef4a4e88c735ab9] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.042 DEBUG Building Handshake dcid Some(CID [8]: 4000009f5a7513d6) scid Some(CID [0]: )
client  | 0.042 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.042 DEBUG [Client 8ef4a4e88c735ab9] delay duration 114.815685ms
client  | 0.042 DEBUG Setting timeout of 114.815685ms
client  | 0.042 DEBUG StateChange(Handshaking)
client  | 0.042 WARN Cannot create stream ConnectionState
client  | 0.042 DEBUG [Client 8ef4a4e88c735ab9] Authenticated Ok
client  | 0.042 DEBUG Write secret available for ApplicationData: SymKey [32]: 03fa66d30f8d7dc1ca75cdb182bc870bb4187f0647be85e9d67949f76bf4287e
client  | 0.042 DEBUG Read secret available for ApplicationData: SymKey [32]: a956e1a5d259f44ef7cd22c21c6c2add68139bc8b112a3eaced3da1aae55c2c8
client  | 0.042 DEBUG [Agent 0x55b57cd78270] SSL_AuthCertificateComplete: Ok(())
client  | 0.042 DEBUG [Agent 0x55b57cd78270] 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.042 DEBUG [Client 8ef4a4e88c735ab9] TLS connection complete
client  | 0.042 DEBUG Making Write ApplicationData CryptoDxState, v=Version1 cipher=4865
client  | 0.042 DEBUG [Crypto] Application write key installed
client  | 0.042 DEBUG Making Read ApplicationData CryptoDxState, v=Version1 cipher=4865
client  | 0.042 DEBUG [Crypto] application read keys installed
client  | 0.042 DEBUG [Client 8ef4a4e88c735ab9] State change from Handshaking -> Connected
client  | 0.042 INFO [Client 8ef4a4e88c735ab9] Connection established
client  | 0.042 DEBUG stream BiDi creatable
client  | 0.042 INFO Created stream 0 for https://server4/chnoeryysi
client  | 0.042 INFO Saving https://server4/chnoeryysi to "/downloads/chnoeryysi"
client  | 0.042 DEBUG stream UniDi creatable
client  | 0.042 DEBUG StateChange(Connected)
client  | 0.042 DEBUG stream 0 writable
client  | 0.042 DEBUG [Client 8ef4a4e88c735ab9] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.042 DEBUG Building Handshake dcid Some(CID [8]: 4000009f5a7513d6) scid Some(CID [0]: )
client  | 0.042 DEBUG CRYPTO for hs offset=0, len=36
client  | 0.042 DEBUG [Client 8ef4a4e88c735ab9] pn=1 type=Handshake pri-path:4000009f5a7513d6 0.0.0.0:41901->193.167.100.100:443 IpTos(Cs0, Ect0) len 73
client  |   TX -> Crypto { offset: 0, len: 36 }
client  | 0.042 DEBUG packet_sent this=0x55b57cd8b970, pn=1, ps=73
client  | 0.042 DEBUG Building Short dcid Some(CID [8]: 4000009f5a7513d6)
client  | 0.042 DEBUG [Client 8ef4a4e88c735ab9] pn=0 type=Short pri-path:4000009f5a7513d6 0.0.0.0:41901->193.167.100.100:443 IpTos(Cs0, Ect0) len 119
client  |   TX -> Stream { stream_id: 0, offset: 0, len: 17, fin: true }
client  | 0.042 DEBUG packet_sent this=0x55b57cd8b970, pn=0, ps=46
client  | 0.042 DEBUG ECN probing: sent 5 probes
client  | 0.042 DEBUG [Client 8ef4a4e88c735ab9] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.042 DEBUG Building Handshake dcid Some(CID [8]: 4000009f5a7513d6) scid Some(CID [0]: )
client  | 0.042 DEBUG Building Short dcid Some(CID [8]: 4000009f5a7513d6)
client  | 0.042 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.042 DEBUG [Client 8ef4a4e88c735ab9] delay duration 114.838949ms
client  | 0.042 DEBUG Setting timeout of 114.838949ms
client  | 0.073 DEBUG [Client 8ef4a4e88c735ab9] pn=7077875 type=Handshake pri-path:4000009f5a7513d6 0.0.0.0:41901->193.167.100.100:443 IpTos(Cs0, NotEct) len 38
client  |   -> RX Ack { largest_acknowledged: 1, ack_delay: 47, first_ack_range: 1, ack_ranges: [], ecn_count: None }
client  | 0.073 DEBUG [Client 8ef4a4e88c735ab9] Rx ACK space=hs, ranges=[0..=1]
client  | 0.073 DEBUG [LossRecovery] ACK for Handshake - largest_acked=1
client  | 0.073 DEBUG on_packets_acked this=0x55b57cd8b970, limited=1, bytes_in_flight=46, cwnd=12520, state=SlowStart, new_acked=73
client  | 0.073 DEBUG Acked crypto frame space=hs offset=0 length=36
client  | 0.073 DEBUG [Client 8ef4a4e88c735ab9] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.073 DEBUG Building Handshake dcid Some(CID [8]: 4000009f5a7513d6) scid Some(CID [0]: )
client  | 0.073 DEBUG Building Short dcid Some(CID [8]: 4000009f5a7513d6)
client  | 0.073 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.073 DEBUG [Client 8ef4a4e88c735ab9] delay duration 71.248871ms
client  | 0.073 DEBUG Setting timeout of 71.248871ms
client  | 0.073 DEBUG [Client 8ef4a4e88c735ab9] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.073 DEBUG Building Handshake dcid Some(CID [8]: 4000009f5a7513d6) scid Some(CID [0]: )
client  | 0.073 DEBUG Building Short dcid Some(CID [8]: 4000009f5a7513d6)
client  | 0.073 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.073 DEBUG [Client 8ef4a4e88c735ab9] delay duration 71.225317ms
client  | 0.073 DEBUG Setting timeout of 71.225317ms
client  | 0.073 DEBUG [Client 8ef4a4e88c735ab9] pn=7077874 type=Short pri-path:4000009f5a7513d6 0.0.0.0:41901->193.167.100.100:443 IpTos(Cs0, NotEct) len 400
client  |   -> RX Crypto { offset: 0, len: 250 }
client  |   -> RX Ack { largest_acknowledged: 0, ack_delay: 53, first_ack_range: 0, ack_ranges: [], ecn_count: None }
client  |   -> RX HandshakeDone
client  |   -> RX NewConnectionId { sequence_number: 1, retire_prior: 0, connection_id: [64, 0, 0, 137, 105, 49, 78, 67], stateless_reset_token: [23, 188, 129, 5, 190, 166, 248, 174, 187, 89, 58, 148, 147, 223, 13, 6] }
client  |   -> RX NewConnectionId { sequence_number: 2, retire_prior: 0, connection_id: [64, 0, 0, 158, 211, 151, 140, 47], stateless_reset_token: [251, 124, 96, 31, 247, 144, 124, 189, 181, 228, 136, 102, 241, 72, 72, 104] }
client  |   -> RX NewConnectionId { sequence_number: 3, retire_prior: 0, connection_id: [64, 0, 0, 128, 73, 23, 145, 61], stateless_reset_token: [101, 213, 162, 92, 206, 50, 80, 69, 216, 156, 209, 224, 99, 141, 245, 0] }
client  |   -> RX NewConnectionId { sequence_number: 4, retire_prior: 0, connection_id: [64, 0, 0, 154, 209, 15, 95, 210], stateless_reset_token: [186, 19, 154, 91, 143, 180, 125, 169, 33, 250, 36, 39, 214, 235, 188, 25] }
client  |   -> RX Padding { len: 8 }
client  | 0.073 DEBUG Read Ok(250) bytes
client  | 0.073 DEBUG [0x55b57cd78270] Got resumption token [921]: 02000633fae340d2..c26ff90381f3f8f7
client  | 0.073 DEBUG [Agent 0x55b57cd78270] 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.073 DEBUG setting max_stream_data to 107374182
client  | 0.073 DEBUG [Client 8ef4a4e88c735ab9] Rx ACK space=ap, ranges=[0..=0]
client  | 0.073 DEBUG [LossRecovery] ACK for ApplicationData - largest_acked=0
client  | 0.073 DEBUG on_packets_acked this=0x55b57cd8b970, limited=1, bytes_in_flight=0, cwnd=12520, state=SlowStart, new_acked=46
client  | 0.073 DEBUG [Client 8ef4a4e88c735ab9] State change from Connected -> Confirmed
client  | 0.073 DEBUG PMTUD started with probe size 1380
client  | 0.073 DEBUG [Client 8ef4a4e88c735ab9] Drop packet number space hs
client  | 0.073 DEBUG [LossRecovery] Reset loss recovery state for Handshake
client  | 0.073 DEBUG [Client 8ef4a4e88c735ab9] No preferred address to migrate to
client  | 0.073 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 172, tv_nsec: 105955239 }
client  | 0.073 DEBUG [Client 8ef4a4e88c735ab9] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.073 DEBUG Building Short dcid Some(CID [8]: 4000009f5a7513d6)
client  | 0.073 DEBUG Sending PMTUD probe of size 1380, count 1
client  | 0.073 DEBUG [Client 8ef4a4e88c735ab9] pn=1 type=Short pri-path:4000009f5a7513d6 0.0.0.0:41901->193.167.100.100:443 IpTos(Cs0, Ect0) len 1352
client  |   TX -> Ack { largest_acknowledged: 7077874, ack_delay: 25, first_ack_range: 0, ack_ranges: [], ecn_count: None }
client  |   TX -> Ping
client  |   TX -> Padding { len: 1317 }
client  | 0.073 DEBUG packet_sent this=0x55b57cd8b970, pn=1, ps=1352
client  | 0.073 DEBUG ECN probing: sent 6 probes
client  | 0.073 DEBUG [Client 8ef4a4e88c735ab9] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.073 DEBUG Building Short dcid Some(CID [8]: 4000009f5a7513d6)
client  | 0.074 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.074 DEBUG [Client 8ef4a4e88c735ab9] delay duration 116.279481ms
client  | 0.074 DEBUG Setting timeout of 116.279481ms
client  | 0.074 DEBUG stream BiDi creatable
client  | 0.074 DEBUG stream UniDi creatable
client  | 0.074 DEBUG stream 0 complete
client  | 0.074 WARN Unhandled event StateChange(Confirmed)
client  | 0.074 DEBUG [Client 8ef4a4e88c735ab9] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.074 DEBUG Building Short dcid Some(CID [8]: 4000009f5a7513d6)
client  | 0.074 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.074 DEBUG [Client 8ef4a4e88c735ab9] delay duration 116.248103ms
client  | 0.074 DEBUG Setting timeout of 116.248103ms
client  | 0.074 DEBUG [Client 8ef4a4e88c735ab9] pn=7077875 type=Short pri-path:4000009f5a7513d6 0.0.0.0:41901->193.167.100.100:443 IpTos(Cs0, NotEct) len 1072
client  |   -> RX Stream { stream_id: 0, offset: 0, len: 1024, fin: true }
client  |   -> RX Padding { len: 24 }
client  | 0.074 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 172, tv_nsec: 126825258 }
client  | 0.074 DEBUG [Client 8ef4a4e88c735ab9] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.074 DEBUG Building Short dcid Some(CID [8]: 4000009f5a7513d6)
client  | 0.074 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.074 DEBUG [Client 8ef4a4e88c735ab9] delay duration 19.970925ms
client  | 0.074 DEBUG Setting timeout of 19.970925ms
client  | 0.074 DEBUG [Client 8ef4a4e88c735ab9] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.074 DEBUG Building Short dcid Some(CID [8]: 4000009f5a7513d6)
client  | 0.074 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.074 DEBUG [Client 8ef4a4e88c735ab9] delay duration 19.920962ms
client  | 0.074 DEBUG Setting timeout of 19.920962ms
client  | 0.074 DEBUG [Client 8ef4a4e88c735ab9] State change from Confirmed -> Closing { error: Application(0), timeout: Instant { tv_sec: 172, tv_nsec: 455979151 } }
client  | 0.074 WARN Unhandled event StateChange(Closing { error: Application(0), timeout: Instant { tv_sec: 172, tv_nsec: 455979151 } })
client  | 0.074 DEBUG [Client 8ef4a4e88c735ab9] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.074 DEBUG Building Short dcid Some(CID [8]: 4000009f5a7513d6)
client  | 0.074 DEBUG [Recvd-ap] immediate_ack at Instant { tv_sec: 172, tv_nsec: 106933951 }
client  | 0.074 DEBUG [Client 8ef4a4e88c735ab9] pn=2 type=Short pri-path:4000009f5a7513d6 0.0.0.0:41901->193.167.100.100:443 IpTos(Cs0, Ect0) len 45
client  |   TX -> Ack { largest_acknowledged: 7077875, ack_delay: 13, first_ack_range: 1, ack_ranges: [], ecn_count: None }
client  |   TX -> ConnectionClose { error_code: Application(0), frame_type: 0, reason_phrase: "kthxbye!" }
client  | 0.074 DEBUG ECN probing: sent 7 probes
client  | 0.074 DEBUG Setting timeout of 348.988243ms
server  | I20250430 08:41:47.797494    34 H1QDownstreamSession.h:84] onConnectionEnd
client  | 0.105 DEBUG [Client 8ef4a4e88c735ab9] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.105 DEBUG Building Short dcid Some(CID [8]: 4000009f5a7513d6)
client  | 0.105 DEBUG [Recvd-ap] immediate_ack at Instant { tv_sec: 172, tv_nsec: 137867976 }
client  | 0.105 DEBUG [Client 8ef4a4e88c735ab9] pn=3 type=Short pri-path:4000009f5a7513d6 0.0.0.0:41901->193.167.100.100:443 IpTos(Cs0, Ect0) len 46
client  |   TX -> Ack { largest_acknowledged: 7077875, ack_delay: 3880, first_ack_range: 1, ack_ranges: [], ecn_count: None }
client  |   TX -> ConnectionClose { error_code: Application(0), frame_type: 0, reason_phrase: "kthxbye!" }
client  | 0.105 DEBUG ECN probing: sent 8 probes
client  | 0.105 DEBUG Setting timeout of 317.990011ms
client  | 0.105 DEBUG Setting timeout of 317.955677ms
client  | 0.424 DEBUG [Client 8ef4a4e88c735ab9] State change from Closing { error: Application(0), timeout: Instant { tv_sec: 172, tv_nsec: 455979151 } } -> Closed(Application(0))
client  | 0.424 INFO Closing timer expired
client  | 0.424 DEBUG Output::None
client  | 0.424 WARN Unhandled event StateChange(Closed(Application(0)))
client  | 0.424 DEBUG Timer fired while closed
client  | 0.424 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 08:41:58,564 Using the client's key log file.
2025-04-30 08:41:58,573 
2025-04-30 08:41:58,574 Using the client's key log file.
2025-04-30 08:41:58,574 Using the client's key log file.
2025-04-30 08:41:58,582 
2025-04-30 08:41:58,583 Using the client's key log file.
2025-04-30 08:41:58,583 Using selector: EpollSelector
2025-04-30 08:41:58,863 Check of downloaded files succeeded.