2025-04-30 10:48:05,212 Generated random file: niudqrspwh of size: 1024 2025-04-30 10:48:05,212 Requests: https://server4:443/niudqrspwh 2025-04-30 10:48:05,271 2025-04-30 10:48:05,271 Command: WAITFORSERVER=server:443 CERTS=/tmp/certs_ckaqb0m8/ TESTCASE_SERVER=handshake TESTCASE_CLIENT=handshake WWW=/tmp/www_oc2ximkk/ DOWNLOADS=/tmp/download_g45cepbn/ SERVER_LOGS=/tmp/logs_server_wijq0yit CLIENT_LOGS=/tmp/logs_client_yt6r1v9w SCENARIO="simple-p2p --delay=750ms --bandwidth=10Mbps --queue=25" CLIENT=ghcr.io/mozilla/neqo-qns:latest SERVER=peterdoornbosch/kwik_n_flupke-interop REQUESTS="https://server4:443/niudqrspwh" docker compose --env-file empty.env up --abort-on-container-exit --timeout 1 sim client server 2025-04-30 10:48:31,891 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 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 | Importing keystore /server.p12 to /server.keystore... server | running kwik server version 0.10.2 server | Old Flupke plugin not found sim | server:443 is available after 1.017951894s sim | Using scenario: simple-p2p --delay=750ms --bandwidth=10Mbps --queue=25 sim | tcpdump: listening on eth0, link-type EN10MB (Ethernet), snapshot length 262144 bytes sim | tcpdump: listening on eth1, link-type EN10MB (Ethernet), snapshot length 262144 bytes client | wait-for-it.sh: sim:57832 is available after 1 seconds client | + OPTIONS=(--cc cubic --qns-test "$TESTCASE" --qlog-dir "$QLOGDIR" --output-dir /downloads) client | + '[' https://server4:443/niudqrspwh ']' 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/niudqrspwh 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:50656 -> 193.167.100.100:443 client | 0.001 DEBUG [CryptoStates] Creating initial cipher state v=Version1, role=Client dcid=f0334a851369bd5f22 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:50656->193.167.100.100:443] Make permanent client | 0.001 DEBUG [unv-path:f0334a851369bd5f22 0.0.0.0:50656->193.167.100.100:443] set as primary path client | 0.001 DEBUG [pri-unv-path:f0334a851369bd5f22 0.0.0.0:50656->193.167.100.100:443] Path validated Instant { tv_sec: 301, tv_nsec: 580064836 } client | 0.001 DEBUG [Client f0334a851369bd5f22] client_start client | 0.002 DEBUG Writing transport parameters, msg=1 client | 0.002 DEBUG [Agent 0x55cf93c90270] state -> InProgress client | 0.002 DEBUG [Client f0334a851369bd5f22] State change from Init -> WaitInitial client | 0.002 DEBUG [Client f0334a851369bd5f22] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.002 DEBUG Building Initial dcid Some(CID [9]: f0334a851369bd5f22) scid Some(CID [0]: ) client | 0.002 DEBUG CRYPTO for in offset=0, len=1212 client | 0.002 DEBUG [Client f0334a851369bd5f22] pn=0 type=Initial pri-path:f0334a851369bd5f22 0.0.0.0:50656->193.167.100.100:443 IpTos(Cs0, Ect0) len 1252 client | TX -> Crypto { offset: 0, len: 1212 } client | 0.002 DEBUG packet_sent this=0x55cf93ca3970, pn=0, ps=1252 client | 0.002 DEBUG ECN probing: sent 1 probes client | 0.002 DEBUG [Client f0334a851369bd5f22] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.002 DEBUG Building Initial dcid Some(CID [9]: f0334a851369bd5f22) scid Some(CID [0]: ) client | 0.002 DEBUG CRYPTO for in offset=1212, len=327 client | 0.002 DEBUG [Client f0334a851369bd5f22] pn=1 type=Initial pri-path:f0334a851369bd5f22 0.0.0.0:50656->193.167.100.100:443 IpTos(Cs0, Ect0) len 368 client | TX -> Crypto { offset: 1212, len: 327 } client | 0.002 DEBUG [Client f0334a851369bd5f22] pad Initial from 368 to PLPMTU 1252 client | 0.002 DEBUG packet_sent this=0x55cf93ca3970, pn=1, ps=1252 client | 0.002 DEBUG ECN probing: sent 2 probes client | 0.002 DEBUG [Client f0334a851369bd5f22] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } client | 0.002 DEBUG Building Initial dcid Some(CID [9]: f0334a851369bd5f22) 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 f0334a851369bd5f22] delay duration 3.869738ms client | 0.002 DEBUG Setting timeout of 3.869738ms client | 0.002 DEBUG StateChange(WaitInitial) client | 0.002 WARN Cannot create stream ConnectionState client | 0.002 DEBUG [Client f0334a851369bd5f22] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } client | 0.002 DEBUG Building Initial dcid Some(CID [9]: f0334a851369bd5f22) 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 f0334a851369bd5f22] delay duration 3.840935ms client | 0.002 DEBUG Setting timeout of 3.840935ms client | 0.007 DEBUG [Client f0334a851369bd5f22] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.007 DEBUG Building Initial dcid Some(CID [9]: f0334a851369bd5f22) 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 f0334a851369bd5f22] delay duration 294.815111ms client | 0.007 DEBUG Setting timeout of 294.815111ms client | 0.303 DEBUG [LossRecovery] PTO timer fired for Initial client | 0.303 DEBUG [Client f0334a851369bd5f22] Lost: Crypto(CryptoRecoveryToken { space: Initial, offset: 0, length: 1212 }) client | 0.303 INFO Lost crypto frame space=in offset=0 length=1212 client | 0.303 DEBUG [Client f0334a851369bd5f22] Lost: EcnEct0 client | 0.303 DEBUG [Client f0334a851369bd5f22] Lost: Crypto(CryptoRecoveryToken { space: Initial, offset: 1212, length: 327 }) client | 0.303 INFO Lost crypto frame space=in offset=1212 length=327 client | 0.303 DEBUG [Client f0334a851369bd5f22] Lost: EcnEct0 client | 0.303 DEBUG [Client f0334a851369bd5f22] output_path send_profile SendProfile { limit: 1252, pto: Some(Initial), probe: EnumSet(Initial), paced: false } client | 0.303 DEBUG Building Initial dcid Some(CID [9]: f0334a851369bd5f22) scid Some(CID [0]: ) client | 0.303 DEBUG CRYPTO for in offset=0, len=1212 client | 0.303 DEBUG [Client f0334a851369bd5f22] pn=2 type=Initial pri-path:f0334a851369bd5f22 0.0.0.0:50656->193.167.100.100:443 IpTos(Cs0, Ect0) len 1252 client | TX -> Crypto { offset: 0, len: 1212 } client | 0.303 DEBUG packet_sent this=0x55cf93ca3970, pn=2, ps=1252 client | 0.303 DEBUG ECN probing: sent 3 probes client | 0.304 DEBUG [Client f0334a851369bd5f22] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.304 DEBUG Building Initial dcid Some(CID [9]: f0334a851369bd5f22) scid Some(CID [0]: ) client | 0.304 DEBUG CRYPTO for in offset=1212, len=327 client | 0.304 DEBUG [Client f0334a851369bd5f22] pn=3 type=Initial pri-path:f0334a851369bd5f22 0.0.0.0:50656->193.167.100.100:443 IpTos(Cs0, Ect0) len 368 client | TX -> Crypto { offset: 1212, len: 327 } client | 0.304 DEBUG [Client f0334a851369bd5f22] pad Initial from 368 to PLPMTU 1252 client | 0.304 DEBUG packet_sent this=0x55cf93ca3970, pn=3, ps=1252 client | 0.304 DEBUG ECN probing: sent 4 probes client | 0.304 DEBUG [Client f0334a851369bd5f22] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.304 DEBUG Building Initial dcid Some(CID [9]: f0334a851369bd5f22) scid Some(CID [0]: ) client | 0.304 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.304 DEBUG [Client f0334a851369bd5f22] delay duration 599.866751ms client | 0.304 DEBUG Setting timeout of 599.866751ms client | 0.904 DEBUG [LossRecovery] PTO timer fired for Initial client | 0.904 DEBUG [Client f0334a851369bd5f22] Lost: Crypto(CryptoRecoveryToken { space: Initial, offset: 0, length: 1212 }) client | 0.904 INFO Lost crypto frame space=in offset=0 length=1212 client | 0.904 DEBUG [Client f0334a851369bd5f22] Lost: EcnEct0 client | 0.904 DEBUG ECN validation failed, all 3 initial marked packets were lost client | 0.904 DEBUG [Client f0334a851369bd5f22] Lost: Crypto(CryptoRecoveryToken { space: Initial, offset: 1212, length: 327 }) client | 0.904 INFO Lost crypto frame space=in offset=1212 length=327 client | 0.904 DEBUG [Client f0334a851369bd5f22] Lost: EcnEct0 client | 0.905 DEBUG [Client f0334a851369bd5f22] output_path send_profile SendProfile { limit: 1252, pto: Some(Initial), probe: EnumSet(Initial), paced: false } client | 0.905 DEBUG Building Initial dcid Some(CID [9]: f0334a851369bd5f22) scid Some(CID [0]: ) client | 0.905 DEBUG CRYPTO for in offset=0, len=1212 client | 0.905 DEBUG [Client f0334a851369bd5f22] pn=4 type=Initial pri-path:f0334a851369bd5f22 0.0.0.0:50656->193.167.100.100:443 IpTos(Cs0, NotEct) len 1252 client | TX -> Crypto { offset: 0, len: 1212 } client | 0.905 DEBUG packet_sent this=0x55cf93ca3970, pn=4, ps=1252 client | 0.905 DEBUG [Client f0334a851369bd5f22] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.905 DEBUG Building Initial dcid Some(CID [9]: f0334a851369bd5f22) scid Some(CID [0]: ) client | 0.905 DEBUG CRYPTO for in offset=1212, len=327 client | 0.905 DEBUG [Client f0334a851369bd5f22] pn=5 type=Initial pri-path:f0334a851369bd5f22 0.0.0.0:50656->193.167.100.100:443 IpTos(Cs0, NotEct) len 368 client | TX -> Crypto { offset: 1212, len: 327 } client | 0.905 DEBUG [Client f0334a851369bd5f22] pad Initial from 368 to PLPMTU 1252 client | 0.905 DEBUG packet_sent this=0x55cf93ca3970, pn=5, ps=1252 client | 0.905 DEBUG [Client f0334a851369bd5f22] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.905 DEBUG Building Initial dcid Some(CID [9]: f0334a851369bd5f22) scid Some(CID [0]: ) client | 0.905 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.905 DEBUG [Client f0334a851369bd5f22] delay duration 1.199917205s client | 0.905 DEBUG Setting timeout of 1.199917205s client | 1.646 DEBUG [Client f0334a851369bd5f22] pn=0 type=Initial pri-path:f0334a851369bd5f22 0.0.0.0:50656->193.167.100.100:443 IpTos(Cs0, NotEct) len 1201 client | -> RX Ack { largest_acknowledged: 0, ack_delay: 0, first_ack_range: 0, ack_ranges: [], ecn_count: None } client | -> RX Padding { len: 1161 } client | 1.646 DEBUG [Client f0334a851369bd5f22] Rx ACK space=in, ranges=[0..=0] client | 1.646 DEBUG [LossRecovery] ACK for Initial - largest_acked=0 client | 1.646 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 6260/13772 ssthresh 18446744073709551615] slow start += 1252 client | 1.646 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 6260/13772 ssthresh 18446744073709551615] on_packets_acked this=0x55cf93ca3970, limited=0, bytes_in_flight=6260, cwnd=13772, state=SlowStart, new_acked=1252 client | 1.646 DEBUG Acked crypto frame space=in offset=0 length=1212 client | 1.646 DEBUG [Client f0334a851369bd5f22] Changing to use Server CID=6e46e5378fc7ac47 client | 1.646 DEBUG [Client f0334a851369bd5f22] State change from WaitInitial -> WaitVersion client | 1.646 DEBUG [Client f0334a851369bd5f22] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 1.646 DEBUG Building Initial dcid Some(CID [8]: 6e46e5378fc7ac47) scid Some(CID [0]: ) client | 1.646 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 1.646 DEBUG [Client f0334a851369bd5f22] delay duration 4.19283578s client | 1.646 DEBUG Setting timeout of 4.19283578s client | 1.646 WARN Unhandled event StateChange(WaitVersion) client | 1.646 DEBUG [Client f0334a851369bd5f22] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 1.646 DEBUG Building Initial dcid Some(CID [8]: 6e46e5378fc7ac47) scid Some(CID [0]: ) client | 1.646 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 1.646 DEBUG [Client f0334a851369bd5f22] delay duration 4.192784915s client | 1.646 DEBUG Setting timeout of 4.192784915s client | 1.782 DEBUG [Client f0334a851369bd5f22] pn=1 type=Initial pri-path:6e46e5378fc7ac47 0.0.0.0:50656->193.167.100.100:443 IpTos(Cs0, NotEct) len 463 client | -> RX Ack { largest_acknowledged: 1, ack_delay: 0, first_ack_range: 1, ack_ranges: [], ecn_count: None } client | -> RX Crypto { offset: 0, len: 90 } client | -> RX Padding { len: 329 } client | 1.782 DEBUG [Client f0334a851369bd5f22] Rx ACK space=in, ranges=[0..=1] client | 1.782 DEBUG [LossRecovery] ACK for Initial - largest_acked=1 client | 1.782 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 5008/15024 ssthresh 18446744073709551615] slow start += 1252 client | 1.782 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 5008/15024 ssthresh 18446744073709551615] on_packets_acked this=0x55cf93ca3970, limited=0, bytes_in_flight=5008, cwnd=15024, state=SlowStart, new_acked=1252 client | 1.782 DEBUG Acked crypto frame space=in offset=1212 length=327 client | 1.782 DEBUG Read Ok(90) bytes client | 1.782 DEBUG Write secret available for Handshake: SymKey [32]: 4d6d3be437c36bf3c48022a41e9c8e8ee8b138fef7375efc8bcedf5637b7d401 client | 1.782 DEBUG Read secret available for Handshake: SymKey [32]: 0eec69c3baa8d4862814426a19df7045a04519e4cdde79bfb39f794bf17f3e57 client | 1.782 DEBUG [Agent 0x55cf93c90270] state -> InProgress client | 1.782 DEBUG Making Write Handshake CryptoDxState, v=Version1 cipher=4865 client | 1.782 DEBUG Making Read Handshake CryptoDxState, v=Version1 cipher=4865 client | 1.782 DEBUG [Crypto] Handshake keys installed client | 1.782 DEBUG [Recvd-in] Set ACK timer to Instant { tv_sec: 303, tv_nsec: 360868306 } client | 1.782 DEBUG [Client f0334a851369bd5f22] State change from WaitVersion -> Handshaking client | 1.782 DEBUG [Client f0334a851369bd5f22] pn=0 type=Handshake pri-path:6e46e5378fc7ac47 0.0.0.0:50656->193.167.100.100:443 IpTos(Cs0, NotEct) len 737 client | -> RX Crypto { offset: 0, len: 699 } client | 1.782 DEBUG Read Ok(699) bytes client | 1.783 DEBUG [Agent 0x55cf93c90270] state -> AuthenticationPending client | 1.783 DEBUG [Recvd-hs] Set ACK timer to Instant { tv_sec: 303, tv_nsec: 360868306 } client | 1.783 DEBUG [Client f0334a851369bd5f22] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 1.783 DEBUG Building Initial dcid Some(CID [8]: 6e46e5378fc7ac47) scid Some(CID [0]: ) client | 1.783 DEBUG [Client f0334a851369bd5f22] pn=6 type=Initial pri-path:6e46e5378fc7ac47 0.0.0.0:50656->193.167.100.100:443 IpTos(Cs0, NotEct) len 41 client | TX -> Ack { largest_acknowledged: 1, ack_delay: 176, first_ack_range: 1, ack_ranges: [], ecn_count: None } client | 1.783 DEBUG Building Handshake dcid Some(CID [8]: 6e46e5378fc7ac47) scid Some(CID [0]: ) client | 1.783 DEBUG [Client f0334a851369bd5f22] pn=0 type=Handshake pri-path:6e46e5378fc7ac47 0.0.0.0:50656->193.167.100.100:443 IpTos(Cs0, NotEct) len 81 client | TX -> Ack { largest_acknowledged: 0, ack_delay: 176, first_ack_range: 0, ack_ranges: [], ecn_count: None } client | 1.783 DEBUG [Client f0334a851369bd5f22] Drop packet number space in client | 1.783 DEBUG [LossRecovery] Reset loss recovery state for Initial client | 1.783 WARN [LossRecovery] ignoring in-6 from dropped space client | 1.783 DEBUG [Client f0334a851369bd5f22] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 1.783 DEBUG Building Handshake dcid Some(CID [8]: 6e46e5378fc7ac47) scid Some(CID [0]: ) client | 1.783 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 1.783 DEBUG [Client f0334a851369bd5f22] delay duration 4.263651051s client | 1.783 DEBUG Setting timeout of 4.263651051s client | 1.783 DEBUG StateChange(Handshaking) client | 1.783 WARN Cannot create stream ConnectionState client | 1.783 DEBUG [Client f0334a851369bd5f22] Authenticated Ok client | 1.783 DEBUG Write secret available for ApplicationData: SymKey [32]: 9cbf92080cd8f320f005de7640efac6846e50e73ecf95a2a459810ecdbeb4873 client | 1.783 DEBUG Read secret available for ApplicationData: SymKey [32]: 3e986ad1a6b92b4917353a1515c619700a3d1da278de4914e5bfb2c3e2bd9a99 client | 1.783 DEBUG [Agent 0x55cf93c90270] SSL_AuthCertificateComplete: Ok(()) client | 1.783 DEBUG [Agent 0x55cf93c90270] 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 | 1.783 DEBUG [Client f0334a851369bd5f22] TLS connection complete client | 1.783 DEBUG Making Write ApplicationData CryptoDxState, v=Version1 cipher=4865 client | 1.783 DEBUG [Crypto] Application write key installed client | 1.783 DEBUG Making Read ApplicationData CryptoDxState, v=Version1 cipher=4865 client | 1.783 DEBUG [Crypto] application read keys installed client | 1.783 DEBUG [Client f0334a851369bd5f22] State change from Handshaking -> Connected client | 1.783 INFO [Client f0334a851369bd5f22] Connection established client | 1.783 DEBUG stream BiDi creatable client | 1.783 INFO Created stream 0 for https://server4/niudqrspwh client | 1.783 INFO Saving https://server4/niudqrspwh to "/downloads/niudqrspwh" client | 1.783 DEBUG StateChange(Connected) client | 1.783 DEBUG stream 0 writable client | 1.783 DEBUG [Client f0334a851369bd5f22] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 1.783 DEBUG Building Handshake dcid Some(CID [8]: 6e46e5378fc7ac47) scid Some(CID [0]: ) client | 1.783 DEBUG CRYPTO for hs offset=0, len=36 client | 1.783 DEBUG [Client f0334a851369bd5f22] pn=1 type=Handshake pri-path:6e46e5378fc7ac47 0.0.0.0:50656->193.167.100.100:443 IpTos(Cs0, NotEct) len 73 client | TX -> Crypto { offset: 0, len: 36 } client | 1.783 DEBUG packet_sent this=0x55cf93ca3970, pn=1, ps=73 client | 1.783 DEBUG Building Short dcid Some(CID [8]: 6e46e5378fc7ac47) client | 1.783 DEBUG [Client f0334a851369bd5f22] pn=0 type=Short pri-path:6e46e5378fc7ac47 0.0.0.0:50656->193.167.100.100:443 IpTos(Cs0, NotEct) len 119 client | TX -> Stream { stream_id: 0, offset: 0, len: 17, fin: true } client | 1.783 DEBUG packet_sent this=0x55cf93ca3970, pn=0, ps=46 client | 1.784 DEBUG [Client f0334a851369bd5f22] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 1.784 DEBUG Building Handshake dcid Some(CID [8]: 6e46e5378fc7ac47) scid Some(CID [0]: ) client | 1.784 DEBUG Building Short dcid Some(CID [8]: 6e46e5378fc7ac47) client | 1.784 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 1.784 DEBUG [Client f0334a851369bd5f22] delay duration 4.263671648s client | 1.784 DEBUG Setting timeout of 4.263671648s client | 1.813 WARN [Client ...] Dropped received packet: Decryption failure; Total: 1 client | 1.813 DEBUG [Client f0334a851369bd5f22] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 1.813 DEBUG Building Handshake dcid Some(CID [8]: 6e46e5378fc7ac47) scid Some(CID [0]: ) client | 1.813 DEBUG Building Short dcid Some(CID [8]: 6e46e5378fc7ac47) client | 1.813 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 1.813 DEBUG [Client f0334a851369bd5f22] delay duration 4.234382322s client | 1.813 DEBUG Setting timeout of 4.234382322s client | 1.813 DEBUG [Client f0334a851369bd5f22] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 1.813 DEBUG Building Handshake dcid Some(CID [8]: 6e46e5378fc7ac47) scid Some(CID [0]: ) client | 1.813 DEBUG Building Short dcid Some(CID [8]: 6e46e5378fc7ac47) client | 1.813 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 1.813 DEBUG [Client f0334a851369bd5f22] delay duration 4.234352597s client | 1.813 DEBUG Setting timeout of 4.234352597s client | 1.814 WARN [Client ...] Dropped received packet: Decryption failure; Total: 2 client | 1.814 DEBUG [Client f0334a851369bd5f22] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 1.814 DEBUG Building Handshake dcid Some(CID [8]: 6e46e5378fc7ac47) scid Some(CID [0]: ) client | 1.814 DEBUG Building Short dcid Some(CID [8]: 6e46e5378fc7ac47) client | 1.814 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 1.814 DEBUG [Client f0334a851369bd5f22] delay duration 4.233404684s client | 1.814 DEBUG Setting timeout of 4.233404684s client | 1.814 DEBUG [Client f0334a851369bd5f22] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 1.814 DEBUG Building Handshake dcid Some(CID [8]: 6e46e5378fc7ac47) scid Some(CID [0]: ) client | 1.814 DEBUG Building Short dcid Some(CID [8]: 6e46e5378fc7ac47) client | 1.814 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 1.814 DEBUG [Client f0334a851369bd5f22] delay duration 4.233380779s client | 1.814 DEBUG Setting timeout of 4.233380779s client | 1.984 WARN [Client ...] Dropped received packet: Decryption failure; Total: 3 client | 1.984 DEBUG [Client f0334a851369bd5f22] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 1.984 DEBUG Building Handshake dcid Some(CID [8]: 6e46e5378fc7ac47) scid Some(CID [0]: ) client | 1.984 DEBUG Building Short dcid Some(CID [8]: 6e46e5378fc7ac47) client | 1.984 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 1.984 DEBUG [Client f0334a851369bd5f22] delay duration 4.063002477s client | 1.984 DEBUG Setting timeout of 4.063002477s client | 1.984 DEBUG [Client f0334a851369bd5f22] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 1.984 DEBUG Building Handshake dcid Some(CID [8]: 6e46e5378fc7ac47) scid Some(CID [0]: ) client | 1.984 DEBUG Building Short dcid Some(CID [8]: 6e46e5378fc7ac47) client | 1.984 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 1.984 DEBUG [Client f0334a851369bd5f22] delay duration 4.062959296s client | 1.984 DEBUG Setting timeout of 4.062959296s client | 2.183 DEBUG [Client f0334a851369bd5f22] pn=1 type=Handshake pri-path:6e46e5378fc7ac47 0.0.0.0:50656->193.167.100.100:443 IpTos(Cs0, NotEct) len 737 client | -> RX Crypto { offset: 0, len: 699 } client | 2.183 DEBUG [Recvd-hs] Set ACK timer to Instant { tv_sec: 303, tv_nsec: 762416154 } client | 2.183 DEBUG [Client f0334a851369bd5f22] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 2.183 DEBUG Building Handshake dcid Some(CID [8]: 6e46e5378fc7ac47) scid Some(CID [0]: ) client | 2.183 DEBUG CRYPTO for hs offset=0, len=36 client | 2.183 DEBUG [Client f0334a851369bd5f22] pn=2 type=Handshake pri-path:6e46e5378fc7ac47 0.0.0.0:50656->193.167.100.100:443 IpTos(Cs0, NotEct) len 78 client | TX -> Ack { largest_acknowledged: 1, ack_delay: 8, first_ack_range: 1, ack_ranges: [], ecn_count: None } client | TX -> Crypto { offset: 0, len: 36 } client | 2.183 DEBUG packet_sent this=0x55cf93ca3970, pn=2, ps=78 client | 2.183 DEBUG Building Short dcid Some(CID [8]: 6e46e5378fc7ac47) client | 2.183 DEBUG [Client f0334a851369bd5f22] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 2.183 DEBUG Building Handshake dcid Some(CID [8]: 6e46e5378fc7ac47) scid Some(CID [0]: ) client | 2.183 DEBUG Building Short dcid Some(CID [8]: 6e46e5378fc7ac47) client | 2.183 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 2.183 DEBUG [Client f0334a851369bd5f22] delay duration 4.263654888s client | 2.183 DEBUG Setting timeout of 4.263654888s client | 2.183 DEBUG [Client f0334a851369bd5f22] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 2.183 DEBUG Building Handshake dcid Some(CID [8]: 6e46e5378fc7ac47) scid Some(CID [0]: ) client | 2.183 DEBUG Building Short dcid Some(CID [8]: 6e46e5378fc7ac47) client | 2.183 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 2.183 DEBUG [Client f0334a851369bd5f22] delay duration 4.26361851s client | 2.183 DEBUG Setting timeout of 4.26361851s client | 2.184 DEBUG [Client f0334a851369bd5f22] pn=2 type=Handshake pri-path:6e46e5378fc7ac47 0.0.0.0:50656->193.167.100.100:443 IpTos(Cs0, NotEct) len 737 client | -> RX Crypto { offset: 0, len: 699 } client | 2.184 DEBUG [Recvd-hs] Set ACK timer to Instant { tv_sec: 303, tv_nsec: 763034430 } client | 2.184 DEBUG [Client f0334a851369bd5f22] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 2.184 DEBUG Building Handshake dcid Some(CID [8]: 6e46e5378fc7ac47) scid Some(CID [0]: ) client | 2.184 DEBUG CRYPTO for hs offset=0, len=36 client | 2.184 DEBUG [Client f0334a851369bd5f22] pn=3 type=Handshake pri-path:6e46e5378fc7ac47 0.0.0.0:50656->193.167.100.100:443 IpTos(Cs0, NotEct) len 78 client | TX -> Ack { largest_acknowledged: 2, ack_delay: 3, first_ack_range: 2, ack_ranges: [], ecn_count: None } client | TX -> Crypto { offset: 0, len: 36 } client | 2.184 DEBUG packet_sent this=0x55cf93ca3970, pn=3, ps=78 client | 2.184 DEBUG Building Short dcid Some(CID [8]: 6e46e5378fc7ac47) client | 2.184 DEBUG [Client f0334a851369bd5f22] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 2.184 DEBUG Building Handshake dcid Some(CID [8]: 6e46e5378fc7ac47) scid Some(CID [0]: ) client | 2.184 DEBUG Building Short dcid Some(CID [8]: 6e46e5378fc7ac47) client | 2.184 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 2.184 DEBUG [Client f0334a851369bd5f22] delay duration 4.263715031s client | 2.184 DEBUG Setting timeout of 4.263715031s client | 2.184 DEBUG [Client f0334a851369bd5f22] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 2.184 DEBUG Building Handshake dcid Some(CID [8]: 6e46e5378fc7ac47) scid Some(CID [0]: ) client | 2.184 DEBUG Building Short dcid Some(CID [8]: 6e46e5378fc7ac47) client | 2.184 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 2.184 DEBUG [Client f0334a851369bd5f22] delay duration 4.263685877s client | 2.184 DEBUG Setting timeout of 4.263685877s client | 2.409 WARN [Client ...] Dropped received packet: Decryption failure; Total: 4 client | 2.409 DEBUG [Client f0334a851369bd5f22] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 2.409 DEBUG Building Handshake dcid Some(CID [8]: 6e46e5378fc7ac47) scid Some(CID [0]: ) client | 2.409 DEBUG Building Short dcid Some(CID [8]: 6e46e5378fc7ac47) client | 2.409 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 2.409 DEBUG [Client f0334a851369bd5f22] delay duration 4.038761788s client | 2.409 DEBUG Setting timeout of 4.038761788s client | 2.409 DEBUG [Client f0334a851369bd5f22] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 2.409 DEBUG Building Handshake dcid Some(CID [8]: 6e46e5378fc7ac47) scid Some(CID [0]: ) client | 2.409 DEBUG Building Short dcid Some(CID [8]: 6e46e5378fc7ac47) client | 2.409 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 2.409 DEBUG [Client f0334a851369bd5f22] delay duration 4.038723857s client | 2.409 DEBUG Setting timeout of 4.038723857s client | 2.410 WARN [Client ...] Dropped received packet: Decryption failure; Total: 5 client | 2.410 DEBUG [Client f0334a851369bd5f22] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 2.410 DEBUG Building Handshake dcid Some(CID [8]: 6e46e5378fc7ac47) scid Some(CID [0]: ) client | 2.410 DEBUG Building Short dcid Some(CID [8]: 6e46e5378fc7ac47) client | 2.410 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 2.410 DEBUG [Client f0334a851369bd5f22] delay duration 4.037693079s client | 2.410 DEBUG Setting timeout of 4.037693079s client | 2.410 DEBUG [Client f0334a851369bd5f22] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 2.410 DEBUG Building Handshake dcid Some(CID [8]: 6e46e5378fc7ac47) scid Some(CID [0]: ) client | 2.410 DEBUG Building Short dcid Some(CID [8]: 6e46e5378fc7ac47) client | 2.410 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 2.410 DEBUG [Client f0334a851369bd5f22] delay duration 4.037676128s client | 2.410 DEBUG Setting timeout of 4.037676128s client | 2.785 WARN [Client ...] Dropped received packet: Decryption failure; Total: 6 client | 2.785 DEBUG [Client f0334a851369bd5f22] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 2.785 DEBUG Building Handshake dcid Some(CID [8]: 6e46e5378fc7ac47) scid Some(CID [0]: ) client | 2.785 DEBUG Building Short dcid Some(CID [8]: 6e46e5378fc7ac47) client | 2.785 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 2.785 DEBUG [Client f0334a851369bd5f22] delay duration 3.662471429s client | 2.785 DEBUG Setting timeout of 3.662471429s client | 2.785 DEBUG [Client f0334a851369bd5f22] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 2.785 DEBUG Building Handshake dcid Some(CID [8]: 6e46e5378fc7ac47) scid Some(CID [0]: ) client | 2.785 DEBUG Building Short dcid Some(CID [8]: 6e46e5378fc7ac47) client | 2.785 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 2.785 DEBUG [Client f0334a851369bd5f22] delay duration 3.662419441s client | 2.785 DEBUG Setting timeout of 3.662419441s client | 2.786 WARN [Client ...] Dropped received packet: Decryption failure; Total: 7 client | 2.786 DEBUG [Client f0334a851369bd5f22] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 2.786 DEBUG Building Handshake dcid Some(CID [8]: 6e46e5378fc7ac47) scid Some(CID [0]: ) client | 2.786 DEBUG Building Short dcid Some(CID [8]: 6e46e5378fc7ac47) client | 2.786 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 2.786 DEBUG [Client f0334a851369bd5f22] delay duration 3.661618363s client | 2.786 DEBUG Setting timeout of 3.661618363s client | 2.786 DEBUG [Client f0334a851369bd5f22] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 2.786 DEBUG Building Handshake dcid Some(CID [8]: 6e46e5378fc7ac47) scid Some(CID [0]: ) client | 2.786 DEBUG Building Short dcid Some(CID [8]: 6e46e5378fc7ac47) client | 2.786 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 2.786 DEBUG [Client f0334a851369bd5f22] delay duration 3.661600169s client | 2.786 DEBUG Setting timeout of 3.661600169s client | 3.292 DEBUG [Client f0334a851369bd5f22] pn=3 type=Handshake pri-path:6e46e5378fc7ac47 0.0.0.0:50656->193.167.100.100:443 IpTos(Cs0, NotEct) len 737 client | -> RX Crypto { offset: 0, len: 699 } client | 3.292 DEBUG [Recvd-hs] Set ACK timer to Instant { tv_sec: 304, tv_nsec: 871507695 } client | 3.292 DEBUG [Client f0334a851369bd5f22] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 3.292 DEBUG Building Handshake dcid Some(CID [8]: 6e46e5378fc7ac47) scid Some(CID [0]: ) client | 3.292 DEBUG CRYPTO for hs offset=0, len=36 client | 3.292 DEBUG [Client f0334a851369bd5f22] pn=4 type=Handshake pri-path:6e46e5378fc7ac47 0.0.0.0:50656->193.167.100.100:443 IpTos(Cs0, NotEct) len 78 client | TX -> Ack { largest_acknowledged: 3, ack_delay: 8, first_ack_range: 3, ack_ranges: [], ecn_count: None } client | TX -> Crypto { offset: 0, len: 36 } client | 3.292 DEBUG packet_sent this=0x55cf93ca3970, pn=4, ps=78 client | 3.292 DEBUG Building Short dcid Some(CID [8]: 6e46e5378fc7ac47) client | 3.292 DEBUG [Client f0334a851369bd5f22] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 3.292 DEBUG Building Handshake dcid Some(CID [8]: 6e46e5378fc7ac47) scid Some(CID [0]: ) client | 3.292 DEBUG Building Short dcid Some(CID [8]: 6e46e5378fc7ac47) client | 3.292 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 3.292 DEBUG [Client f0334a851369bd5f22] delay duration 4.263676199s client | 3.292 DEBUG Setting timeout of 4.263676199s client | 3.292 DEBUG [Client f0334a851369bd5f22] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 3.292 DEBUG Building Handshake dcid Some(CID [8]: 6e46e5378fc7ac47) scid Some(CID [0]: ) client | 3.292 DEBUG Building Short dcid Some(CID [8]: 6e46e5378fc7ac47) client | 3.292 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 3.292 DEBUG [Client f0334a851369bd5f22] delay duration 4.263635312s client | 3.292 DEBUG Setting timeout of 4.263635312s client | 3.299 DEBUG [Client f0334a851369bd5f22] pn=0 type=Short pri-path:6e46e5378fc7ac47 0.0.0.0:50656->193.167.100.100:443 IpTos(Cs0, NotEct) len 204 client | -> RX HandshakeDone client | -> RX NewConnectionId { sequence_number: 1, retire_prior: 0, connection_id: [188, 3, 143, 47, 173, 175, 50, 32], stateless_reset_token: [249, 108, 77, 44, 150, 66, 238, 105, 159, 135, 208, 60, 238, 43, 110, 205] } client | -> RX NewConnectionId { sequence_number: 2, retire_prior: 0, connection_id: [50, 29, 8, 9, 85, 50, 237, 133], stateless_reset_token: [139, 73, 167, 204, 154, 52, 140, 133, 151, 142, 87, 124, 162, 130, 95, 42] } client | -> RX NewConnectionId { sequence_number: 3, retire_prior: 0, connection_id: [93, 112, 73, 240, 226, 14, 166, 58], stateless_reset_token: [114, 105, 82, 121, 212, 188, 41, 226, 67, 90, 236, 202, 49, 131, 58, 115] } client | -> RX NewConnectionId { sequence_number: 4, retire_prior: 0, connection_id: [144, 216, 253, 217, 6, 254, 5, 123], stateless_reset_token: [31, 211, 137, 49, 44, 54, 124, 125, 216, 119, 170, 112, 252, 17, 102, 70] } client | -> RX NewConnectionId { sequence_number: 5, retire_prior: 0, connection_id: [58, 143, 81, 127, 196, 92, 163, 245], stateless_reset_token: [173, 8, 0, 177, 137, 152, 166, 209, 224, 211, 91, 194, 195, 91, 88, 131] } client | -> RX Crypto { offset: 0, len: 42 } client | 3.299 DEBUG [Client f0334a851369bd5f22] State change from Connected -> Confirmed client | 3.299 DEBUG PMTUD started with probe size 1380 client | 3.299 DEBUG [Client f0334a851369bd5f22] Drop packet number space hs client | 3.299 DEBUG [LossRecovery] Reset loss recovery state for Handshake client | 3.299 DEBUG [Client f0334a851369bd5f22] No preferred address to migrate to client | 3.299 DEBUG Read Ok(42) bytes client | 3.299 DEBUG [0x55cf93c90270] Got resumption token [712]: 02000633fca7346a..ba59cd03179eb648 client | 3.299 DEBUG [Agent 0x55cf93c90270] 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 | 3.299 DEBUG setting max_stream_data to 1000000 client | 3.299 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 304, tv_nsec: 897862139 } client | 3.299 DEBUG [Client f0334a851369bd5f22] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 3.299 DEBUG Building Short dcid Some(CID [8]: 6e46e5378fc7ac47) client | 3.299 DEBUG Sending PMTUD probe of size 1380, count 1 client | 3.299 DEBUG [Client f0334a851369bd5f22] pn=1 type=Short pri-path:6e46e5378fc7ac47 0.0.0.0:50656->193.167.100.100:443 IpTos(Cs0, NotEct) len 1352 client | TX -> Ping client | TX -> Padding { len: 1325 } client | 3.299 DEBUG packet_sent this=0x55cf93ca3970, pn=1, ps=1352 client | 3.299 DEBUG [Client f0334a851369bd5f22] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 3.299 DEBUG Building Short dcid Some(CID [8]: 6e46e5378fc7ac47) client | 3.299 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 3.299 DEBUG [Client f0334a851369bd5f22] delay duration 19.68973ms client | 3.299 DEBUG Setting timeout of 19.68973ms client | 3.299 WARN Unhandled event StateChange(Confirmed) client | 3.299 DEBUG stream BiDi creatable client | 3.299 DEBUG [Client f0334a851369bd5f22] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 3.299 DEBUG Building Short dcid Some(CID [8]: 6e46e5378fc7ac47) client | 3.299 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 3.299 DEBUG [Client f0334a851369bd5f22] delay duration 19.660435ms client | 3.299 DEBUG Setting timeout of 19.660435ms client | 3.308 DEBUG [Client f0334a851369bd5f22] pn=1 type=Short pri-path:6e46e5378fc7ac47 0.0.0.0:50656->193.167.100.100:443 IpTos(Cs0, NotEct) len 1056 client | -> RX Stream { stream_id: 0, offset: 0, len: 1024, fin: true } client | -> RX Ack { largest_acknowledged: 0, ack_delay: 125, first_ack_range: 0, ack_ranges: [], ecn_count: None } client | -> RX MaxStreams { stream_type: BiDi, maximum_streams: 101 } client | 3.308 DEBUG [Client f0334a851369bd5f22] Rx ACK space=ap, ranges=[0..=0] client | 3.308 DEBUG [LossRecovery] ACK for ApplicationData - largest_acked=0 client | 3.308 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 1352/15070 ssthresh 18446744073709551615] slow start += 46 client | 3.308 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 1352/15070 ssthresh 18446744073709551615] on_packets_acked this=0x55cf93ca3970, limited=0, bytes_in_flight=1352, cwnd=15070, state=SlowStart, new_acked=46 client | 3.308 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 304, tv_nsec: 887024364 } client | 3.308 DEBUG [Client f0334a851369bd5f22] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 3.308 DEBUG Building Short dcid Some(CID [8]: 6e46e5378fc7ac47) client | 3.308 DEBUG [Client f0334a851369bd5f22] pn=2 type=Short pri-path:6e46e5378fc7ac47 0.0.0.0:50656->193.167.100.100:443 IpTos(Cs0, NotEct) len 31 client | TX -> Ack { largest_acknowledged: 1, ack_delay: 5, first_ack_range: 1, ack_ranges: [], ecn_count: None } client | 3.308 DEBUG [Client f0334a851369bd5f22] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 3.308 DEBUG Building Short dcid Some(CID [8]: 6e46e5378fc7ac47) client | 3.308 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 3.308 DEBUG [Client f0334a851369bd5f22] delay duration 3.749479284s client | 3.308 DEBUG Setting timeout of 3.749479284s client | 3.308 DEBUG stream 0 complete client | 3.308 DEBUG stream BiDi creatable client | 3.308 DEBUG [Client f0334a851369bd5f22] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 3.308 DEBUG Building Short dcid Some(CID [8]: 6e46e5378fc7ac47) client | 3.308 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 3.308 DEBUG [Client f0334a851369bd5f22] delay duration 3.749416036s client | 3.308 DEBUG Setting timeout of 3.749416036s client | 3.308 DEBUG [Client f0334a851369bd5f22] State change from Confirmed -> Closing { error: Application(0), timeout: Instant { tv_sec: 316, tv_nsec: 162718168 } } client | 3.308 WARN Unhandled event StateChange(Closing { error: Application(0), timeout: Instant { tv_sec: 316, tv_nsec: 162718168 } }) client | 3.308 DEBUG [Client f0334a851369bd5f22] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 3.308 DEBUG Building Short dcid Some(CID [8]: 6e46e5378fc7ac47) client | 3.308 DEBUG [Recvd-ap] immediate_ack at Instant { tv_sec: 304, tv_nsec: 887216062 } client | 3.308 DEBUG [Client f0334a851369bd5f22] pn=3 type=Short pri-path:6e46e5378fc7ac47 0.0.0.0:50656->193.167.100.100:443 IpTos(Cs0, NotEct) len 42 client | TX -> Ack { largest_acknowledged: 1, ack_delay: 23, first_ack_range: 1, ack_ranges: [], ecn_count: None } client | TX -> ConnectionClose { error_code: Application(0), frame_type: 0, reason_phrase: "kthxbye!" } client | 3.308 DEBUG Setting timeout of 11.275428578s client | 3.527 DEBUG [Client f0334a851369bd5f22] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 3.527 DEBUG Building Short dcid Some(CID [8]: 6e46e5378fc7ac47) client | 3.528 DEBUG [Recvd-ap] immediate_ack at Instant { tv_sec: 305, tv_nsec: 106847782 } client | 3.528 DEBUG [Client f0334a851369bd5f22] pn=4 type=Short pri-path:6e46e5378fc7ac47 0.0.0.0:50656->193.167.100.100:443 IpTos(Cs0, NotEct) len 45 client | TX -> Ack { largest_acknowledged: 1, ack_delay: 27477, first_ack_range: 1, ack_ranges: [], ecn_count: None } client | TX -> ConnectionClose { error_code: Application(0), frame_type: 0, reason_phrase: "kthxbye!" } client | 3.528 DEBUG Setting timeout of 11.055723892s client | 3.528 DEBUG Setting timeout of 11.055689347s client | 3.968 DEBUG [Client f0334a851369bd5f22] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 3.968 DEBUG Building Short dcid Some(CID [8]: 6e46e5378fc7ac47) client | 3.968 DEBUG [Recvd-ap] immediate_ack at Instant { tv_sec: 305, tv_nsec: 546911151 } client | 3.968 DEBUG [Client f0334a851369bd5f22] pn=5 type=Short pri-path:6e46e5378fc7ac47 0.0.0.0:50656->193.167.100.100:443 IpTos(Cs0, NotEct) len 45 client | TX -> Ack { largest_acknowledged: 1, ack_delay: 82485, first_ack_range: 1, ack_ranges: [], ecn_count: None } client | TX -> ConnectionClose { error_code: Application(0), frame_type: 0, reason_phrase: "kthxbye!" } client | 3.968 DEBUG Setting timeout of 10.615638472s client | 3.968 DEBUG Setting timeout of 10.615623473s client | 3.968 DEBUG [Client f0334a851369bd5f22] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 3.968 DEBUG Building Short dcid Some(CID [8]: 6e46e5378fc7ac47) client | 3.968 DEBUG [Recvd-ap] immediate_ack at Instant { tv_sec: 305, tv_nsec: 547637309 } client | 3.968 DEBUG [Client f0334a851369bd5f22] pn=6 type=Short pri-path:6e46e5378fc7ac47 0.0.0.0:50656->193.167.100.100:443 IpTos(Cs0, NotEct) len 45 client | TX -> Ack { largest_acknowledged: 1, ack_delay: 82576, first_ack_range: 1, ack_ranges: [], ecn_count: None } client | TX -> ConnectionClose { error_code: Application(0), frame_type: 0, reason_phrase: "kthxbye!" } client | 3.968 DEBUG Setting timeout of 10.614991532s client | 3.968 DEBUG Setting timeout of 10.614984178s client | 4.815 DEBUG [Client f0334a851369bd5f22] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 4.815 DEBUG Building Short dcid Some(CID [8]: 6e46e5378fc7ac47) client | 4.815 DEBUG [Recvd-ap] immediate_ack at Instant { tv_sec: 306, tv_nsec: 394598893 } client | 4.815 DEBUG [Client f0334a851369bd5f22] pn=7 type=Short pri-path:6e46e5378fc7ac47 0.0.0.0:50656->193.167.100.100:443 IpTos(Cs0, NotEct) len 45 client | TX -> Ack { largest_acknowledged: 1, ack_delay: 188446, first_ack_range: 1, ack_ranges: [], ecn_count: None } client | TX -> ConnectionClose { error_code: Application(0), frame_type: 0, reason_phrase: "kthxbye!" } client | 4.815 DEBUG Setting timeout of 9.767973443s client | 4.815 DEBUG Setting timeout of 9.767958154s client | 4.821 DEBUG [Client f0334a851369bd5f22] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 4.821 DEBUG Building Short dcid Some(CID [8]: 6e46e5378fc7ac47) client | 4.821 DEBUG [Recvd-ap] immediate_ack at Instant { tv_sec: 306, tv_nsec: 400746219 } client | 4.821 DEBUG [Client f0334a851369bd5f22] pn=8 type=Short pri-path:6e46e5378fc7ac47 0.0.0.0:50656->193.167.100.100:443 IpTos(Cs0, NotEct) len 45 client | TX -> Ack { largest_acknowledged: 1, ack_delay: 189215, first_ack_range: 1, ack_ranges: [], ecn_count: None } client | TX -> ConnectionClose { error_code: Application(0), frame_type: 0, reason_phrase: "kthxbye!" } client | 4.821 DEBUG Setting timeout of 9.761890186s client | 4.821 DEBUG Setting timeout of 9.761876781s client | 4.823 DEBUG [Client f0334a851369bd5f22] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 4.823 DEBUG Building Short dcid Some(CID [8]: 6e46e5378fc7ac47) client | 4.823 DEBUG [Recvd-ap] immediate_ack at Instant { tv_sec: 306, tv_nsec: 402465545 } client | 4.823 DEBUG [Client f0334a851369bd5f22] pn=9 type=Short pri-path:6e46e5378fc7ac47 0.0.0.0:50656->193.167.100.100:443 IpTos(Cs0, NotEct) len 45 client | TX -> Ack { largest_acknowledged: 1, ack_delay: 189430, first_ack_range: 1, ack_ranges: [], ecn_count: None } client | TX -> ConnectionClose { error_code: Application(0), frame_type: 0, reason_phrase: "kthxbye!" } client | 4.823 DEBUG Setting timeout of 9.760182893s client | 4.823 DEBUG Setting timeout of 9.760171993s client | 14.585 DEBUG [Client f0334a851369bd5f22] State change from Closing { error: Application(0), timeout: Instant { tv_sec: 316, tv_nsec: 162718168 } } -> Closed(Application(0)) client | 14.585 INFO Closing timer expired client | 14.585 DEBUG Output::None client | 14.585 WARN Unhandled event StateChange(Closed(Application(0))) client | 14.585 DEBUG Timer fired while closed client | 14.585 DEBUG Output::None client exited with code 0 Aborting on container exit... Container client Stopping Container server Stopping Container client Stopped Container server Stopped Container sim Stopping Container sim Stopped 2025-04-30 10:48:31,984 Using the client's key log file. 2025-04-30 10:48:31,993 2025-04-30 10:48:31,994 Using the client's key log file. 2025-04-30 10:48:31,994 Using the client's key log file. 2025-04-30 10:48:32,001 2025-04-30 10:48:32,002 Using the client's key log file. 2025-04-30 10:48:32,300 Check of downloaded files succeeded. 2025-04-30 10:48:33,518 Check of downloaded files succeeded.