2025-09-12 05:45:04,956 Generated random file: wlbcporear of size: 1024 2025-09-12 05:45:04,956 Requests: https://server4:443/wlbcporear 2025-09-12 05:45:05,013 2025-09-12 05:45:05,013 Command: WAITFORSERVER=server:443 CERTS=/tmp/certs_jo64fn9y/ TESTCASE_SERVER=handshake TESTCASE_CLIENT=handshake WWW=/tmp/www_bcqc17ts/ DOWNLOADS=/tmp/download_uk5x6sqp/ SERVER_LOGS=/tmp/logs_server_i67vo3bl CLIENT_LOGS=/tmp/logs_client_hrwp6i8i SCENARIO="simple-p2p --delay=750ms --bandwidth=10Mbps --queue=25" CLIENT=ghcr.io/mozilla/neqo-qns:latest SERVER=haproxytech/haproxy-qns:latest REQUESTS="https://server4:443/wlbcporear" docker compose --env-file empty.env up --abort-on-container-exit --timeout 1 sim client server 2025-09-12 05:45:30,272 Container sim Recreate Container sim Recreated Container client Recreate Container server Recreate Container client Recreated Container server Recreated Attaching to client, server, sim sim | waiting 10s for server:443 server | Setting up routes... server | Actual changes: server | tx-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 server | starting lighttpd server client | Endpoint's IPv4 address is 193.167.0.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 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.336304ms sim | Using scenario: simple-p2p --delay=750ms --bandwidth=10Mbps --queue=25 sim | tcpdump: tcpdump: listening on eth1listening on eth0, link-type EN10MB (Ethernet), link-type EN10MB (Ethernet), snapshot length 262144 bytes sim | , 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/wlbcporear ']' 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/wlbcporear 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:42147 -> 193.167.100.100:443 client | 0.001 DEBUG [CryptoStates] Creating initial cipher state v=Version1, role=Client dcid=510e2f46d5223375 client | 0.001 DEBUG Making Write Initial CryptoDxState, v=Version1 cipher=4865 min_pn=13 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:42147->193.167.100.100:443] Make permanent client | 0.001 DEBUG [unv-path:510e2f46d5223375 0.0.0.0:42147->193.167.100.100:443] set as primary path client | 0.001 DEBUG [pri-unv-path:510e2f46d5223375 0.0.0.0:42147->193.167.100.100:443] Path validated Instant { tv_sec: 253, tv_nsec: 61326655 } client | 0.001 DEBUG [Client 510e2f46d5223375] client_start client | 0.002 DEBUG Writing transport parameters, msg=1 client | 0.002 DEBUG [Agent 0x5579190f0500] state -> InProgress client | 0.002 DEBUG [Client 510e2f46d5223375] State change from Init -> WaitInitial client | 0.002 DEBUG [Client 510e2f46d5223375] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.002 DEBUG Building Initial dcid Some(CID [8]: 510e2f46d5223375) scid Some(CID [0]: ) client | 0.002 DEBUG CRYPTO for in offset=0, len=1213 client | 0.002 DEBUG [Client 510e2f46d5223375] pn=13 type=Initial pri-path:510e2f46d5223375 0.0.0.0:42147->193.167.100.100:443 Tos(Cs0, NotEct) len 1252 client | TX -> Crypto { offset: 0, len: 1213 } client | 0.002 DEBUG packet_sent this=0x557919103af0, pn=13, ps=1252 client | 0.002 DEBUG [Client 510e2f46d5223375] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.002 DEBUG Building Initial dcid Some(CID [8]: 510e2f46d5223375) scid Some(CID [0]: ) client | 0.002 DEBUG CRYPTO for in offset=1213, len=327 client | 0.002 DEBUG [Client 510e2f46d5223375] pn=14 type=Initial pri-path:510e2f46d5223375 0.0.0.0:42147->193.167.100.100:443 Tos(Cs0, NotEct) len 367 client | TX -> Crypto { offset: 1213, len: 327 } client | 0.002 DEBUG [Client 510e2f46d5223375] pad Initial from 367 to PLPMTU 1252 client | 0.002 DEBUG packet_sent this=0x557919103af0, pn=14, ps=1252 client | 0.002 DEBUG [Client 510e2f46d5223375] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } client | 0.002 DEBUG Building Initial dcid Some(CID [8]: 510e2f46d5223375) 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 510e2f46d5223375] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } client | 0.002 DEBUG Building Initial dcid Some(CID [8]: 510e2f46d5223375) 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 510e2f46d5223375] delay duration 3.901885ms client | 0.002 DEBUG Setting timeout of 3.901885ms client | 0.002 DEBUG StateChange(WaitInitial) client | 0.002 WARN Cannot create stream ConnectionState client | 0.002 DEBUG [Client 510e2f46d5223375] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } client | 0.002 DEBUG Building Initial dcid Some(CID [8]: 510e2f46d5223375) 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 510e2f46d5223375] delay duration 3.869324ms client | 0.002 DEBUG Setting timeout of 3.869324ms client | 0.007 DEBUG [Client 510e2f46d5223375] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.007 DEBUG Building Initial dcid Some(CID [8]: 510e2f46d5223375) 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 510e2f46d5223375] delay duration 294.316423ms client | 0.007 DEBUG Setting timeout of 294.316423ms client | 0.302 DEBUG [recovery::Loss] PTO timer fired for Initial client | 0.302 DEBUG [Client 510e2f46d5223375] Lost: Crypto(CryptoRecoveryToken { space: Initial, offset: 0, length: 1213 }) client | 0.302 INFO Lost crypto frame space=in offset=0 length=1213 client | 0.302 DEBUG [Client 510e2f46d5223375] Lost: Crypto(CryptoRecoveryToken { space: Initial, offset: 1213, length: 327 }) client | 0.302 INFO Lost crypto frame space=in offset=1213 length=327 client | 0.302 DEBUG [Client 510e2f46d5223375] output_path send_profile SendProfile { limit: 1252, pto: Some(Initial), probe: EnumSet(Initial), paced: false } client | 0.302 DEBUG Building Initial dcid Some(CID [8]: 510e2f46d5223375) scid Some(CID [0]: ) client | 0.302 DEBUG CRYPTO for in offset=0, len=1213 client | 0.302 DEBUG [Client 510e2f46d5223375] pn=15 type=Initial pri-path:510e2f46d5223375 0.0.0.0:42147->193.167.100.100:443 Tos(Cs0, NotEct) len 1252 client | TX -> Crypto { offset: 0, len: 1213 } client | 0.302 DEBUG packet_sent this=0x557919103af0, pn=15, ps=1252 client | 0.302 DEBUG [Client 510e2f46d5223375] output_path send_profile SendProfile { limit: 1252, pto: Some(Initial), probe: EnumSet(), paced: false } client | 0.302 DEBUG Building Initial dcid Some(CID [8]: 510e2f46d5223375) scid Some(CID [0]: ) client | 0.302 DEBUG CRYPTO for in offset=1213, len=327 client | 0.302 DEBUG [Client 510e2f46d5223375] pn=16 type=Initial pri-path:510e2f46d5223375 0.0.0.0:42147->193.167.100.100:443 Tos(Cs0, NotEct) len 367 client | TX -> Crypto { offset: 1213, len: 327 } client | 0.302 DEBUG [Client 510e2f46d5223375] pad Initial from 367 to PLPMTU 1252 client | 0.302 DEBUG packet_sent this=0x557919103af0, pn=16, ps=1252 client | 0.302 DEBUG [Client 510e2f46d5223375] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.302 DEBUG Building Initial dcid Some(CID [8]: 510e2f46d5223375) scid Some(CID [0]: ) client | 0.302 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.303 DEBUG [Client 510e2f46d5223375] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.303 DEBUG Building Initial dcid Some(CID [8]: 510e2f46d5223375) scid Some(CID [0]: ) client | 0.303 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.303 DEBUG [Client 510e2f46d5223375] delay duration 599.742046ms client | 0.303 DEBUG Setting timeout of 599.742046ms client | 0.903 DEBUG [recovery::Loss] PTO timer fired for Initial client | 0.903 DEBUG [Client 510e2f46d5223375] Lost: Crypto(CryptoRecoveryToken { space: Initial, offset: 0, length: 1213 }) client | 0.903 INFO Lost crypto frame space=in offset=0 length=1213 client | 0.903 DEBUG [Client 510e2f46d5223375] Lost: Crypto(CryptoRecoveryToken { space: Initial, offset: 1213, length: 327 }) client | 0.903 INFO Lost crypto frame space=in offset=1213 length=327 client | 0.903 DEBUG [Client 510e2f46d5223375] output_path send_profile SendProfile { limit: 1252, pto: Some(Initial), probe: EnumSet(Initial), paced: false } client | 0.903 DEBUG Building Initial dcid Some(CID [8]: 510e2f46d5223375) scid Some(CID [0]: ) client | 0.903 DEBUG CRYPTO for in offset=0, len=1213 client | 0.903 DEBUG [Client 510e2f46d5223375] pn=17 type=Initial pri-path:510e2f46d5223375 0.0.0.0:42147->193.167.100.100:443 Tos(Cs0, NotEct) len 1252 client | TX -> Crypto { offset: 0, len: 1213 } client | 0.903 DEBUG packet_sent this=0x557919103af0, pn=17, ps=1252 client | 0.903 DEBUG [Client 510e2f46d5223375] output_path send_profile SendProfile { limit: 1252, pto: Some(Initial), probe: EnumSet(), paced: false } client | 0.903 DEBUG Building Initial dcid Some(CID [8]: 510e2f46d5223375) scid Some(CID [0]: ) client | 0.903 DEBUG CRYPTO for in offset=1213, len=327 client | 0.903 DEBUG [Client 510e2f46d5223375] pn=18 type=Initial pri-path:510e2f46d5223375 0.0.0.0:42147->193.167.100.100:443 Tos(Cs0, NotEct) len 367 client | TX -> Crypto { offset: 1213, len: 327 } client | 0.903 DEBUG [Client 510e2f46d5223375] pad Initial from 367 to PLPMTU 1252 client | 0.903 DEBUG packet_sent this=0x557919103af0, pn=18, ps=1252 client | 0.903 DEBUG [Client 510e2f46d5223375] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.903 DEBUG Building Initial dcid Some(CID [8]: 510e2f46d5223375) scid Some(CID [0]: ) client | 0.903 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.904 DEBUG [Client 510e2f46d5223375] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.904 DEBUG Building Initial dcid Some(CID [8]: 510e2f46d5223375) scid Some(CID [0]: ) client | 0.904 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.904 DEBUG [Client 510e2f46d5223375] delay duration 1.199771942s client | 0.904 DEBUG Setting timeout of 1.199771942s client | 1.513 DEBUG [Client 510e2f46d5223375] pn=0 type=Initial pri-path:510e2f46d5223375 0.0.0.0:42147->193.167.100.100:443 Tos(Cs0, NotEct) len 135 client | -> RX Ack { largest_acknowledged: 14, ack_delay: 250, first_ack_range: 1, ack_ranges: [], ecn_count: None } client | -> RX Crypto { offset: 0, len: 90 } client | 1.513 DEBUG [Client 510e2f46d5223375] Rx ACK space=in, ranges=[13..=14] client | 1.513 DEBUG [recovery::Loss] ACK for Initial - largest_acked=14 client | 1.513 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 5008/15024 ssthresh 18446744073709551615] slow start += 2504 client | 1.513 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 5008/15024 ssthresh 18446744073709551615] on_packets_acked this=0x557919103af0, limited=0, bytes_in_flight=5008, cwnd=15024, state=SlowStart, new_acked=2504 client | 1.513 DEBUG Acked crypto frame space=in offset=1213 length=327 client | 1.513 DEBUG Acked crypto frame space=in offset=0 length=1213 client | 1.513 DEBUG Write secret available for Handshake: SymKey [48]: e4cb968aeae3a0fd912cad6fb42ccf77d0e56b60df8f9af6fbecf3cf302e0c2cabe666102c20fa6ba96a11016ce10090 client | 1.513 DEBUG Read secret available for Handshake: SymKey [48]: a7909e5c2c0a84f7df2e72f98f49d92de9804cd04c78adbc15a581e071707ab557009dcb77f11479c408ec930a08c0d7 client | 1.513 DEBUG [Agent 0x5579190f0500] state -> InProgress client | 1.513 DEBUG Making Write Handshake CryptoDxState, v=Version1 cipher=4866 min_pn=0 client | 1.513 DEBUG Making Read Handshake CryptoDxState, v=Version1 cipher=4866 min_pn=0 client | 1.513 DEBUG [Crypto] Handshake keys installed client | 1.513 DEBUG [Recvd-in] Set ACK timer to Instant { tv_sec: 254, tv_nsec: 573315214 } client | 1.513 DEBUG [Client 510e2f46d5223375] Changing to use Server CID=e121423d7bd0591f client | 1.513 DEBUG [Client 510e2f46d5223375] State change from WaitInitial -> Handshaking client | 1.513 DEBUG [Client 510e2f46d5223375] pn=0 type=Handshake pri-path:e121423d7bd0591f 0.0.0.0:42147->193.167.100.100:443 Tos(Cs0, NotEct) len 1065 client | -> RX Crypto { offset: 0, len: 729 } client | -> RX Padding { len: 298 } client | 1.514 DEBUG [Agent 0x5579190f0500] state -> AuthenticationPending client | 1.514 DEBUG [Recvd-hs] Set ACK timer to Instant { tv_sec: 254, tv_nsec: 573315214 } client | 1.514 DEBUG [Client 510e2f46d5223375] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 1.514 DEBUG Building Initial dcid Some(CID [8]: e121423d7bd0591f) scid Some(CID [0]: ) client | 1.514 DEBUG [Client 510e2f46d5223375] pn=19 type=Initial pri-path:e121423d7bd0591f 0.0.0.0:42147->193.167.100.100:443 Tos(Cs0, NotEct) len 41 client | TX -> Ack { largest_acknowledged: 0, ack_delay: 169, first_ack_range: 0, ack_ranges: [], ecn_count: None } client | 1.514 DEBUG Building Handshake dcid Some(CID [8]: e121423d7bd0591f) scid Some(CID [0]: ) client | 1.514 DEBUG [Client 510e2f46d5223375] pn=0 type=Handshake pri-path:e121423d7bd0591f 0.0.0.0:42147->193.167.100.100:443 Tos(Cs0, NotEct) len 81 client | TX -> Ack { largest_acknowledged: 0, ack_delay: 169, first_ack_range: 0, ack_ranges: [], ecn_count: None } client | 1.514 DEBUG [Client 510e2f46d5223375] Drop packet number space in client | 1.514 DEBUG [recovery::Loss] Reset loss recovery state for Initial client | 1.514 INFO [recovery::Loss] ignoring in-19 from dropped space client | 1.514 DEBUG [Client 510e2f46d5223375] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 1.514 DEBUG Building Handshake dcid Some(CID [8]: e121423d7bd0591f) scid Some(CID [0]: ) client | 1.514 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 1.514 DEBUG [Client 510e2f46d5223375] delay duration 4.534251998s client | 1.514 DEBUG Setting timeout of 4.534251998s client | 1.514 DEBUG StateChange(Handshaking) client | 1.514 WARN Cannot create stream ConnectionState client | 1.514 DEBUG [Client 510e2f46d5223375] Authenticated Ok client | 1.514 DEBUG Write secret available for ApplicationData: SymKey [48]: 3762ecb12a5fbd266ca8e9b31db58fc9e35c9d43240aa1d04ea60366f5eb746e566a781838ec393e963dba88c6797033 client | 1.514 DEBUG Read secret available for ApplicationData: SymKey [48]: cc55611039a67b02b617290b296ef21225a8ae65a116cd3c5dfce95a67563aebc71dc8c9f6bd3e7bd5fba9266d1ebd2f client | 1.514 DEBUG [Agent 0x5579190f0500] SSL_AuthCertificateComplete: Ok(()) client | 1.514 DEBUG [Agent 0x5579190f0500] 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 | 1.514 DEBUG [Client 510e2f46d5223375] TLS connection complete client | 1.514 DEBUG Making Write ApplicationData CryptoDxState, v=Version1 cipher=4866 min_pn=0 client | 1.514 DEBUG [Crypto] Application write key installed client | 1.514 DEBUG Making Read ApplicationData CryptoDxState, v=Version1 cipher=4866 min_pn=0 client | 1.514 DEBUG [Crypto] application read keys installed client | 1.514 DEBUG [Client 510e2f46d5223375] State change from Handshaking -> Connected client | 1.514 INFO [Client 510e2f46d5223375] Connection established client | 1.514 DEBUG stream BiDi creatable client | 1.514 INFO Created stream 0 for https://server4/wlbcporear client | 1.514 INFO Saving https://server4/wlbcporear to "/downloads/wlbcporear" client | 1.515 DEBUG stream UniDi creatable client | 1.515 DEBUG StateChange(Connected) client | 1.515 DEBUG stream 0 writable client | 1.515 DEBUG [Client 510e2f46d5223375] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 1.515 DEBUG Building Handshake dcid Some(CID [8]: e121423d7bd0591f) scid Some(CID [0]: ) client | 1.515 DEBUG CRYPTO for hs offset=0, len=52 client | 1.515 DEBUG [Client 510e2f46d5223375] pn=1 type=Handshake pri-path:e121423d7bd0591f 0.0.0.0:42147->193.167.100.100:443 Tos(Cs0, NotEct) len 89 client | TX -> Crypto { offset: 0, len: 52 } client | 1.515 DEBUG packet_sent this=0x557919103af0, pn=1, ps=89 client | 1.515 DEBUG Building Short dcid Some(CID [8]: e121423d7bd0591f) client | 1.515 DEBUG [Client 510e2f46d5223375] pn=0 type=Short pri-path:e121423d7bd0591f 0.0.0.0:42147->193.167.100.100:443 Tos(Cs0, NotEct) len 135 client | TX -> Stream { stream_id: 0, offset: 0, len: 17, fin: true } client | 1.515 DEBUG packet_sent this=0x557919103af0, pn=0, ps=46 client | 1.515 DEBUG [Client 510e2f46d5223375] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 1.515 DEBUG Building Handshake dcid Some(CID [8]: e121423d7bd0591f) scid Some(CID [0]: ) client | 1.515 DEBUG Building Short dcid Some(CID [8]: e121423d7bd0591f) client | 1.515 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 1.515 DEBUG [Client 510e2f46d5223375] delay duration 4.534262288s client | 1.515 DEBUG Setting timeout of 4.534262288s client | 1.806 DEBUG [Client ...] Dropped received packet: Decryption failure; Total: 1 client | 1.806 DEBUG [Client 510e2f46d5223375] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 1.806 DEBUG Building Handshake dcid Some(CID [8]: e121423d7bd0591f) scid Some(CID [0]: ) client | 1.806 DEBUG Building Short dcid Some(CID [8]: e121423d7bd0591f) client | 1.806 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 1.806 DEBUG [Client 510e2f46d5223375] delay duration 4.243124642s client | 1.806 DEBUG Setting timeout of 4.243124642s client | 1.806 DEBUG [Client 510e2f46d5223375] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 1.806 DEBUG Building Handshake dcid Some(CID [8]: e121423d7bd0591f) scid Some(CID [0]: ) client | 1.806 DEBUG Building Short dcid Some(CID [8]: e121423d7bd0591f) client | 1.806 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 1.806 DEBUG [Client 510e2f46d5223375] delay duration 4.243082412s client | 1.806 DEBUG Setting timeout of 4.243082412s client | 1.806 DEBUG [Client ...] Dropped received packet: Decryption failure; Total: 2 client | 1.806 DEBUG [Client 510e2f46d5223375] pn=1 type=Handshake pri-path:e121423d7bd0591f 0.0.0.0:42147->193.167.100.100:443 Tos(Cs0, NotEct) len 767 client | -> RX Crypto { offset: 0, len: 729 } client | 1.806 DEBUG [Recvd-hs] Set ACK timer to Instant { tv_sec: 254, tv_nsec: 867080442 } client | 1.806 DEBUG [Client 510e2f46d5223375] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 1.806 DEBUG Building Handshake dcid Some(CID [8]: e121423d7bd0591f) scid Some(CID [0]: ) client | 1.806 DEBUG CRYPTO for hs offset=0, len=52 client | 1.806 DEBUG [Client 510e2f46d5223375] pn=2 type=Handshake pri-path:e121423d7bd0591f 0.0.0.0:42147->193.167.100.100:443 Tos(Cs0, NotEct) len 94 client | TX -> Ack { largest_acknowledged: 1, ack_delay: 7, first_ack_range: 1, ack_ranges: [], ecn_count: None } client | TX -> Crypto { offset: 0, len: 52 } client | 1.806 DEBUG packet_sent this=0x557919103af0, pn=2, ps=94 client | 1.806 DEBUG Building Short dcid Some(CID [8]: e121423d7bd0591f) client | 1.807 DEBUG [Client 510e2f46d5223375] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 1.807 DEBUG Building Handshake dcid Some(CID [8]: e121423d7bd0591f) scid Some(CID [0]: ) client | 1.807 DEBUG Building Short dcid Some(CID [8]: e121423d7bd0591f) client | 1.807 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 1.807 DEBUG [Client 510e2f46d5223375] delay duration 4.53426885s client | 1.807 DEBUG Setting timeout of 4.53426885s client | 1.807 DEBUG [Client ...] Dropped received packet: Decryption failure; Total: 3 client | 1.807 DEBUG [Client 510e2f46d5223375] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 1.807 DEBUG Building Handshake dcid Some(CID [8]: e121423d7bd0591f) scid Some(CID [0]: ) client | 1.807 DEBUG Building Short dcid Some(CID [8]: e121423d7bd0591f) client | 1.807 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 1.807 DEBUG [Client 510e2f46d5223375] delay duration 4.534228214s client | 1.807 DEBUG Setting timeout of 4.534228214s client | 1.807 DEBUG [Client 510e2f46d5223375] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 1.807 DEBUG Building Handshake dcid Some(CID [8]: e121423d7bd0591f) scid Some(CID [0]: ) client | 1.807 DEBUG Building Short dcid Some(CID [8]: e121423d7bd0591f) client | 1.807 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 1.807 DEBUG [Client 510e2f46d5223375] delay duration 4.534206683s client | 1.807 DEBUG Setting timeout of 4.534206683s client | 2.406 DEBUG [Client ...] Dropped received packet: Decryption failure; Total: 4 client | 2.406 DEBUG [Client 510e2f46d5223375] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 2.406 DEBUG Building Handshake dcid Some(CID [8]: e121423d7bd0591f) scid Some(CID [0]: ) client | 2.406 DEBUG Building Short dcid Some(CID [8]: e121423d7bd0591f) client | 2.406 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 2.406 DEBUG [Client 510e2f46d5223375] delay duration 3.935018939s client | 2.406 DEBUG Setting timeout of 3.935018939s client | 2.406 DEBUG [Client 510e2f46d5223375] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 2.406 DEBUG Building Handshake dcid Some(CID [8]: e121423d7bd0591f) scid Some(CID [0]: ) client | 2.406 DEBUG Building Short dcid Some(CID [8]: e121423d7bd0591f) client | 2.406 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 2.406 DEBUG [Client 510e2f46d5223375] delay duration 3.934959888s client | 2.406 DEBUG Setting timeout of 3.934959888s client | 2.406 DEBUG [Client ...] Dropped received packet: Decryption failure; Total: 5 client | 2.406 DEBUG [Client 510e2f46d5223375] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 2.406 DEBUG Building Handshake dcid Some(CID [8]: e121423d7bd0591f) scid Some(CID [0]: ) client | 2.406 DEBUG Building Short dcid Some(CID [8]: e121423d7bd0591f) client | 2.406 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 2.406 DEBUG [Client 510e2f46d5223375] delay duration 3.934462034s client | 2.406 DEBUG Setting timeout of 3.934462034s client | 2.406 DEBUG [Client 510e2f46d5223375] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 2.406 DEBUG Building Handshake dcid Some(CID [8]: e121423d7bd0591f) scid Some(CID [0]: ) client | 2.406 DEBUG Building Short dcid Some(CID [8]: e121423d7bd0591f) client | 2.406 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 2.406 DEBUG [Client 510e2f46d5223375] delay duration 3.934430625s client | 2.406 DEBUG Setting timeout of 3.934430625s client | 2.510 DEBUG [Client ...] Dropped received packet: Decryption failure; Total: 6 client | 2.510 DEBUG [Client 510e2f46d5223375] pn=2 type=Handshake pri-path:e121423d7bd0591f 0.0.0.0:42147->193.167.100.100:443 Tos(Cs0, NotEct) len 1071 client | -> RX Crypto { offset: 0, len: 729 } client | -> RX Padding { len: 304 } client | 2.510 DEBUG [Recvd-hs] Set ACK timer to Instant { tv_sec: 255, tv_nsec: 570742569 } client | 2.510 DEBUG [Client 510e2f46d5223375] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 2.510 DEBUG Building Handshake dcid Some(CID [8]: e121423d7bd0591f) scid Some(CID [0]: ) client | 2.510 DEBUG CRYPTO for hs offset=0, len=52 client | 2.510 DEBUG [Client 510e2f46d5223375] pn=3 type=Handshake pri-path:e121423d7bd0591f 0.0.0.0:42147->193.167.100.100:443 Tos(Cs0, NotEct) len 94 client | TX -> Ack { largest_acknowledged: 2, ack_delay: 8, first_ack_range: 2, ack_ranges: [], ecn_count: None } client | TX -> Crypto { offset: 0, len: 52 } client | 2.510 DEBUG packet_sent this=0x557919103af0, pn=3, ps=94 client | 2.510 DEBUG Building Short dcid Some(CID [8]: e121423d7bd0591f) client | 2.510 DEBUG [Client 510e2f46d5223375] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 2.510 DEBUG Building Handshake dcid Some(CID [8]: e121423d7bd0591f) scid Some(CID [0]: ) client | 2.510 DEBUG Building Short dcid Some(CID [8]: e121423d7bd0591f) client | 2.510 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 2.510 DEBUG [Client 510e2f46d5223375] delay duration 4.534268459s client | 2.510 DEBUG Setting timeout of 4.534268459s client | 2.510 DEBUG [Client 510e2f46d5223375] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 2.510 DEBUG Building Handshake dcid Some(CID [8]: e121423d7bd0591f) scid Some(CID [0]: ) client | 2.510 DEBUG Building Short dcid Some(CID [8]: e121423d7bd0591f) client | 2.510 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 2.510 DEBUG [Client 510e2f46d5223375] delay duration 4.534233644s client | 2.510 DEBUG Setting timeout of 4.534233644s client | 2.511 DEBUG [Client ...] Dropped received packet: Decryption failure; Total: 7 client | 2.511 DEBUG [Client 510e2f46d5223375] pn=3 type=Handshake pri-path:e121423d7bd0591f 0.0.0.0:42147->193.167.100.100:443 Tos(Cs0, NotEct) len 1071 client | -> RX Crypto { offset: 0, len: 729 } client | -> RX Padding { len: 304 } client | 2.511 DEBUG [Recvd-hs] Set ACK timer to Instant { tv_sec: 255, tv_nsec: 571668269 } client | 2.511 DEBUG [Client 510e2f46d5223375] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 2.511 DEBUG Building Handshake dcid Some(CID [8]: e121423d7bd0591f) scid Some(CID [0]: ) client | 2.511 DEBUG CRYPTO for hs offset=0, len=52 client | 2.511 DEBUG [Client 510e2f46d5223375] pn=4 type=Handshake pri-path:e121423d7bd0591f 0.0.0.0:42147->193.167.100.100:443 Tos(Cs0, NotEct) len 94 client | TX -> Ack { largest_acknowledged: 3, ack_delay: 3, first_ack_range: 3, ack_ranges: [], ecn_count: None } client | TX -> Crypto { offset: 0, len: 52 } client | 2.511 DEBUG packet_sent this=0x557919103af0, pn=4, ps=94 client | 2.511 DEBUG Building Short dcid Some(CID [8]: e121423d7bd0591f) client | 2.511 DEBUG [Client 510e2f46d5223375] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 2.511 DEBUG Building Handshake dcid Some(CID [8]: e121423d7bd0591f) scid Some(CID [0]: ) client | 2.511 DEBUG Building Short dcid Some(CID [8]: e121423d7bd0591f) client | 2.511 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 2.511 DEBUG [Client 510e2f46d5223375] delay duration 4.534259341s client | 2.511 DEBUG Setting timeout of 4.534259341s client | 2.511 DEBUG [Client 510e2f46d5223375] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 2.511 DEBUG Building Handshake dcid Some(CID [8]: e121423d7bd0591f) scid Some(CID [0]: ) client | 2.511 DEBUG Building Short dcid Some(CID [8]: e121423d7bd0591f) client | 2.511 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 2.511 DEBUG [Client 510e2f46d5223375] delay duration 4.53423179s client | 2.511 DEBUG Setting timeout of 4.53423179s client | 3.018 DEBUG [Client 510e2f46d5223375] pn=4 type=Handshake pri-path:e121423d7bd0591f 0.0.0.0:42147->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 | 3.018 DEBUG [Client 510e2f46d5223375] Rx ACK space=hs, ranges=[0..=1] client | 3.018 DEBUG [recovery::Loss] ACK for Handshake - largest_acked=1 client | 3.018 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 328/15113 ssthresh 18446744073709551615] slow start += 89 client | 3.018 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 328/15113 ssthresh 18446744073709551615] on_packets_acked this=0x557919103af0, limited=0, bytes_in_flight=328, cwnd=15113, state=SlowStart, new_acked=89 client | 3.018 DEBUG Acked crypto frame space=hs offset=0 length=52 client | 3.018 DEBUG [Client 510e2f46d5223375] pn=0 type=Short pri-path:e121423d7bd0591f 0.0.0.0:42147->193.167.100.100:443 Tos(Cs0, NotEct) len 568 client | -> RX Crypto { offset: 0, len: 546 } client | 3.018 DEBUG [0x5579190f0500] Got resumption token [936]: 0200063e942828d9..239026f5ffac5375 client | 3.018 DEBUG [0x5579190f0500] Got resumption token [936]: 0200063e942828d9..5a3915ffd71fb338 client | 3.018 DEBUG [Agent 0x5579190f0500] 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 | 3.018 DEBUG setting max_stream_data to 1474200 client | 3.018 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 256, tv_nsec: 98318832 } client | 3.018 DEBUG [Client 510e2f46d5223375] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 3.018 DEBUG Building Handshake dcid Some(CID [8]: e121423d7bd0591f) scid Some(CID [0]: ) client | 3.018 DEBUG Building Short dcid Some(CID [8]: e121423d7bd0591f) client | 3.018 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 3.018 DEBUG [Client 510e2f46d5223375] delay duration 19.683146ms client | 3.018 DEBUG Setting timeout of 19.683146ms client | 3.018 DEBUG stream BiDi creatable client | 3.018 DEBUG stream UniDi creatable client | 3.018 DEBUG [Client 510e2f46d5223375] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 3.018 DEBUG Building Handshake dcid Some(CID [8]: e121423d7bd0591f) scid Some(CID [0]: ) client | 3.018 DEBUG Building Short dcid Some(CID [8]: e121423d7bd0591f) client | 3.018 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 3.018 DEBUG [Client 510e2f46d5223375] delay duration 19.64267ms client | 3.018 DEBUG Setting timeout of 19.64267ms client | 3.018 DEBUG [Client 510e2f46d5223375] pn=1 type=Short pri-path:e121423d7bd0591f 0.0.0.0:42147->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, 131, 136, 106, 226, 155, 114, 203, 138, 253, 26, 120, 60, 85, 203, 122, 80, 59, 91, 204, 194, 140, 104, 146, 111, 226, 244, 61, 73, 149, 50, 6, 254, 193, 51, 243, 214] } client | -> RX NewConnectionId { sequence_number: 1, retire_prior: 0, connection_id: [48, 147, 252, 195, 111, 30, 108, 193], stateless_reset_token: [176, 83, 54, 17, 6, 142, 246, 242, 191, 242, 30, 226, 207, 30, 91, 133] } client | -> RX NewConnectionId { sequence_number: 2, retire_prior: 0, connection_id: [112, 244, 9, 249, 140, 187, 223, 241], stateless_reset_token: [190, 208, 44, 2, 124, 20, 110, 5, 127, 9, 148, 62, 140, 116, 195, 99] } client | -> RX NewConnectionId { sequence_number: 3, retire_prior: 0, connection_id: [218, 92, 228, 83, 40, 167, 156, 164], stateless_reset_token: [71, 76, 74, 114, 116, 125, 158, 74, 177, 34, 189, 135, 29, 61, 18, 92] } client | 3.018 DEBUG [Client 510e2f46d5223375] Rx ACK space=ap, ranges=[0..=0] client | 3.018 DEBUG [recovery::Loss] ACK for ApplicationData - largest_acked=0 client | 3.018 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 282/15159 ssthresh 18446744073709551615] slow start += 46 client | 3.018 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 282/15159 ssthresh 18446744073709551615] on_packets_acked this=0x557919103af0, limited=0, bytes_in_flight=282, cwnd=15159, state=SlowStart, new_acked=46 client | 3.018 DEBUG [Client 510e2f46d5223375] State change from Connected -> Confirmed client | 3.018 DEBUG PMTUD started with probe size 1380 client | 3.018 DEBUG [Client 510e2f46d5223375] Drop packet number space hs client | 3.018 DEBUG [recovery::Loss] Reset loss recovery state for Handshake client | 3.018 DEBUG [Client 510e2f46d5223375] No preferred address to migrate to client | 3.018 DEBUG resumption token [1080]: 0000000145e54062..5a3915ffd71fb338 client | 3.018 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 256, tv_nsec: 78988699 } client | 3.018 DEBUG [Client 510e2f46d5223375] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 3.018 DEBUG Building Short dcid Some(CID [8]: e121423d7bd0591f) client | 3.018 DEBUG Sending PMTUD probe of size 1380, count 1 client | 3.018 DEBUG [Client 510e2f46d5223375] pn=1 type=Short pri-path:e121423d7bd0591f 0.0.0.0:42147->193.167.100.100:443 Tos(Cs0, Ect0) len 1352 client | TX -> Ack { largest_acknowledged: 1, ack_delay: 22, first_ack_range: 1, ack_ranges: [], ecn_count: None } client | TX -> Ping client | TX -> Padding { len: 1320 } client | 3.018 DEBUG packet_sent this=0x557919103af0, pn=1, ps=1352 client | 3.018 DEBUG [Client 510e2f46d5223375] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 3.018 DEBUG Building Short dcid Some(CID [8]: e121423d7bd0591f) client | 3.018 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 3.018 DEBUG ECN probing: sent 1 probes client | 3.019 DEBUG [Client 510e2f46d5223375] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 3.019 DEBUG Building Short dcid Some(CID [8]: e121423d7bd0591f) client | 3.019 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 3.019 DEBUG [Client 510e2f46d5223375] delay duration 3.24787272s client | 3.019 DEBUG Setting timeout of 3.24787272s client | 3.019 DEBUG stream 0 complete client | 3.019 WARN Unhandled event StateChange(Confirmed) client | 3.019 DEBUG [Client 510e2f46d5223375] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 3.019 DEBUG Building Short dcid Some(CID [8]: e121423d7bd0591f) client | 3.019 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 3.019 DEBUG [Client 510e2f46d5223375] delay duration 3.247841992s client | 3.019 DEBUG Setting timeout of 3.247841992s client | 3.020 DEBUG [Client 510e2f46d5223375] pn=2 type=Short pri-path:e121423d7bd0591f 0.0.0.0:42147->193.167.100.100:443 Tos(Cs0, NotEct) len 1046 client | -> RX Stream { stream_id: 0, offset: 0, len: 1024, fin: true } client | 3.020 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 256, tv_nsec: 100867395 } client | 3.020 DEBUG [Client 510e2f46d5223375] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 3.020 DEBUG Building Short dcid Some(CID [8]: e121423d7bd0591f) client | 3.020 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 3.020 DEBUG [Client 510e2f46d5223375] delay duration 19.968831ms client | 3.020 DEBUG Setting timeout of 19.968831ms client | 3.020 DEBUG [Client 510e2f46d5223375] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 3.020 DEBUG Building Short dcid Some(CID [8]: e121423d7bd0591f) client | 3.020 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 3.020 DEBUG [Client 510e2f46d5223375] delay duration 19.922675ms client | 3.020 DEBUG Setting timeout of 19.922675ms client | 3.020 DEBUG [Client 510e2f46d5223375] State change from Confirmed -> Closing { error: Application(0), timeout: Instant { tv_sec: 265, tv_nsec: 824885588 } } client | 3.020 WARN Unhandled event StateChange(Closing { error: Application(0), timeout: Instant { tv_sec: 265, tv_nsec: 824885588 } }) client | 3.020 DEBUG [Client 510e2f46d5223375] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 3.020 DEBUG Building Short dcid Some(CID [8]: e121423d7bd0591f) client | 3.020 DEBUG [Recvd-ap] immediate_ack at Instant { tv_sec: 256, tv_nsec: 80975378 } client | 3.020 DEBUG [Client 510e2f46d5223375] pn=2 type=Short pri-path:e121423d7bd0591f 0.0.0.0:42147->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 | 3.020 DEBUG ECN probing: sent 2 probes client | 3.020 DEBUG Setting timeout of 9.743841341s client | 4.522 DEBUG [Client 510e2f46d5223375] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 4.522 DEBUG Building Short dcid Some(CID [8]: e121423d7bd0591f) client | 4.522 DEBUG [Recvd-ap] immediate_ack at Instant { tv_sec: 257, tv_nsec: 582572571 } client | 4.522 DEBUG [Client 510e2f46d5223375] pn=3 type=Short pri-path:e121423d7bd0591f 0.0.0.0:42147->193.167.100.100:443 Tos(Cs0, Ect0) len 45 client | TX -> Ack { largest_acknowledged: 2, ack_delay: 187713, first_ack_range: 2, ack_ranges: [], ecn_count: None } client | TX -> ConnectionClose { error_code: Application(0), frame_type: 0, reason_phrase: "kthxbye!" } client | 4.522 DEBUG ECN probing: sent 3 probes client | 4.522 DEBUG Setting timeout of 8.242195727s client | 4.522 DEBUG Setting timeout of 8.242183244s client | 6.023 DEBUG [Client 510e2f46d5223375] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 6.023 DEBUG Building Short dcid Some(CID [8]: e121423d7bd0591f) client | 6.023 DEBUG [Recvd-ap] immediate_ack at Instant { tv_sec: 259, tv_nsec: 83638651 } client | 6.023 DEBUG [Client 510e2f46d5223375] pn=4 type=Short pri-path:e121423d7bd0591f 0.0.0.0:42147->193.167.100.100:443 Tos(Cs0, Ect0) len 45 client | TX -> Ack { largest_acknowledged: 2, ack_delay: 375346, first_ack_range: 2, ack_ranges: [], ecn_count: None } client | TX -> ConnectionClose { error_code: Application(0), frame_type: 0, reason_phrase: "kthxbye!" } client | 6.023 DEBUG ECN probing: sent 4 probes client | 6.023 DEBUG Setting timeout of 6.74108323s client | 6.023 DEBUG Setting timeout of 6.741069123s client | 7.524 DEBUG [Client 510e2f46d5223375] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.524 DEBUG Building Short dcid Some(CID [8]: e121423d7bd0591f) client | 7.524 DEBUG [Recvd-ap] immediate_ack at Instant { tv_sec: 260, tv_nsec: 584720213 } client | 7.524 DEBUG [Client 510e2f46d5223375] pn=5 type=Short pri-path:e121423d7bd0591f 0.0.0.0:42147->193.167.100.100:443 Tos(Cs0, Ect0) len 45 client | TX -> Ack { largest_acknowledged: 2, ack_delay: 562981, first_ack_range: 2, ack_ranges: [], ecn_count: None } client | TX -> ConnectionClose { error_code: Application(0), frame_type: 0, reason_phrase: "kthxbye!" } client | 7.524 DEBUG ECN probing: sent 5 probes client | 7.524 DEBUG Setting timeout of 5.2400348s client | 7.524 DEBUG Setting timeout of 5.240020713s client | 9.025 DEBUG [Client 510e2f46d5223375] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 9.025 DEBUG Building Short dcid Some(CID [8]: e121423d7bd0591f) client | 9.025 DEBUG [Recvd-ap] immediate_ack at Instant { tv_sec: 262, tv_nsec: 85799493 } client | 9.025 DEBUG [Client 510e2f46d5223375] pn=6 type=Short pri-path:e121423d7bd0591f 0.0.0.0:42147->193.167.100.100:443 Tos(Cs0, Ect0) len 45 client | TX -> Ack { largest_acknowledged: 2, ack_delay: 750616, first_ack_range: 2, ack_ranges: [], ecn_count: None } client | TX -> ConnectionClose { error_code: Application(0), frame_type: 0, reason_phrase: "kthxbye!" } client | 9.025 DEBUG ECN probing: sent 6 probes client | 9.025 DEBUG Setting timeout of 3.738970318s client | 9.025 DEBUG Setting timeout of 3.738961s client | 10.526 DEBUG [Client 510e2f46d5223375] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 10.526 DEBUG Building Short dcid Some(CID [8]: e121423d7bd0591f) client | 10.526 DEBUG [Recvd-ap] immediate_ack at Instant { tv_sec: 263, tv_nsec: 586943815 } client | 10.526 DEBUG [Client 510e2f46d5223375] pn=7 type=Short pri-path:e121423d7bd0591f 0.0.0.0:42147->193.167.100.100:443 Tos(Cs0, Ect0) len 45 client | TX -> Ack { largest_acknowledged: 2, ack_delay: 938259, first_ack_range: 2, ack_ranges: [], ecn_count: None } client | TX -> ConnectionClose { error_code: Application(0), frame_type: 0, reason_phrase: "kthxbye!" } client | 10.526 DEBUG ECN probing: sent 7 probes client | 10.526 DEBUG Setting timeout of 2.237788686s client | 10.526 DEBUG Setting timeout of 2.23777471s client | 12.027 DEBUG [Client 510e2f46d5223375] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 12.027 DEBUG Building Short dcid Some(CID [8]: e121423d7bd0591f) client | 12.027 DEBUG [Recvd-ap] immediate_ack at Instant { tv_sec: 265, tv_nsec: 87991465 } client | 12.027 DEBUG [Client 510e2f46d5223375] pn=8 type=Short pri-path:e121423d7bd0591f 0.0.0.0:42147->193.167.100.100:443 Tos(Cs0, Ect0) len 45 client | TX -> Ack { largest_acknowledged: 2, ack_delay: 1125890, first_ack_range: 2, ack_ranges: [], ecn_count: None } client | TX -> ConnectionClose { error_code: Application(0), frame_type: 0, reason_phrase: "kthxbye!" } client | 12.027 DEBUG ECN probing: sent 8 probes client | 12.027 DEBUG Setting timeout of 736.754591ms client | 12.027 DEBUG Setting timeout of 736.745374ms client | 12.765 DEBUG [Client 510e2f46d5223375] State change from Closing { error: Application(0), timeout: Instant { tv_sec: 265, tv_nsec: 824885588 } } -> Closed(Application(0)) client | 12.765 INFO Closing timer expired client | 12.765 DEBUG Output::None client | 12.765 WARN Unhandled event StateChange(Closed(Application(0))) client | 12.765 DEBUG Timer fired while closed client | 12.765 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:45:30,354 Using the client's key log file. 2025-09-12 05:45:30,363 2025-09-12 05:45:30,363 Using the client's key log file. 2025-09-12 05:45:30,363 Using the client's key log file. 2025-09-12 05:45:30,371 2025-09-12 05:45:30,371 Using the client's key log file. 2025-09-12 05:45:30,588 Check of downloaded files succeeded. 2025-09-12 05:45:31,488 Check of downloaded files succeeded.