2025-04-30 12:54:40,884 Generated random file: dncsduldcz of size: 1024 2025-04-30 12:54:40,884 Requests: https://server4:443/dncsduldcz 2025-04-30 12:54:40,943 2025-04-30 12:54:40,943 Command: WAITFORSERVER=server:443 CERTS=/tmp/certs_2yb3b2at/ TESTCASE_SERVER=handshake TESTCASE_CLIENT=handshake WWW=/tmp/www_q88irjpw/ DOWNLOADS=/tmp/download_v4pw0ezo/ SERVER_LOGS=/tmp/logs_server_cdge5y6u CLIENT_LOGS=/tmp/logs_client_hpi7nok1 SCENARIO="simple-p2p --delay=750ms --bandwidth=10Mbps --queue=25" CLIENT=ghcr.io/mozilla/neqo-qns:latest SERVER=aiortc/aioquic-qns:latest REQUESTS="https://server4:443/dncsduldcz" docker compose --env-file empty.env up --abort-on-container-exit --timeout 1 sim client server 2025-04-30 12:55:05,642 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 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 server | Setting up routes... server | Actual changes: server | tx-checksumming: off server | tx-checksum-ip-generic: off server | tx-checksum-sctp: off server | tcp-segmentation-offload: off server | tx-tcp-segmentation: off [requested on] server | tx-tcp-ecn-segmentation: off [requested on] server | tx-tcp-mangleid-segmentation: off [requested on] server | tx-tcp6-segmentation: off [requested on] server | tx-udp-segmentation: off [requested on] server | Endpoint's IPv4 address is 193.167.100.100 client | wait-for-it.sh: waiting 30 seconds for sim:57832 server | Endpoint's IPv6 address is fd00:cafe:cafe:100::100 server | Starting server sim | server:443 is available after 1.016676074s sim | Using scenario: simple-p2p --delay=750ms --bandwidth=10Mbps --queue=25 sim | tcpdump: listening on eth1tcpdump: , link-type EN10MB (Ethernet)listening on eth0, snapshot length 262144 bytes sim | , 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/dncsduldcz ']' 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/dncsduldcz 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:34682 -> 193.167.100.100:443 client | 0.001 DEBUG [CryptoStates] Creating initial cipher state v=Version1, role=Client dcid=dd313776e04a96d087df 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:34682->193.167.100.100:443] Make permanent client | 0.001 DEBUG [unv-path:dd313776e04a96d087df 0.0.0.0:34682->193.167.100.100:443] set as primary path client | 0.001 DEBUG [pri-unv-path:dd313776e04a96d087df 0.0.0.0:34682->193.167.100.100:443] Path validated Instant { tv_sec: 431, tv_nsec: 662456016 } client | 0.001 DEBUG [Client dd313776e04a96d087df] client_start client | 0.002 DEBUG Writing transport parameters, msg=1 client | 0.002 DEBUG [Agent 0x556673c27270] state -> InProgress client | 0.002 DEBUG [Client dd313776e04a96d087df] State change from Init -> WaitInitial client | 0.002 DEBUG [Client dd313776e04a96d087df] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.002 DEBUG Building Initial dcid Some(CID [10]: dd313776e04a96d087df) scid Some(CID [0]: ) client | 0.002 DEBUG CRYPTO for in offset=0, len=1211 client | 0.002 DEBUG [Client dd313776e04a96d087df] pn=0 type=Initial pri-path:dd313776e04a96d087df 0.0.0.0:34682->193.167.100.100:443 IpTos(Cs0, Ect0) len 1252 client | TX -> Crypto { offset: 0, len: 1211 } client | 0.002 DEBUG packet_sent this=0x556673c3a970, pn=0, ps=1252 client | 0.002 DEBUG ECN probing: sent 1 probes client | 0.002 DEBUG [Client dd313776e04a96d087df] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.002 DEBUG Building Initial dcid Some(CID [10]: dd313776e04a96d087df) scid Some(CID [0]: ) client | 0.002 DEBUG CRYPTO for in offset=1211, len=328 client | 0.002 DEBUG [Client dd313776e04a96d087df] pn=1 type=Initial pri-path:dd313776e04a96d087df 0.0.0.0:34682->193.167.100.100:443 IpTos(Cs0, Ect0) len 370 client | TX -> Crypto { offset: 1211, len: 328 } client | 0.002 DEBUG [Client dd313776e04a96d087df] pad Initial from 370 to PLPMTU 1252 client | 0.002 DEBUG packet_sent this=0x556673c3a970, pn=1, ps=1252 client | 0.002 DEBUG ECN probing: sent 2 probes client | 0.002 DEBUG [Client dd313776e04a96d087df] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } client | 0.002 DEBUG Building Initial dcid Some(CID [10]: dd313776e04a96d087df) 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 dd313776e04a96d087df] delay duration 3.872568ms client | 0.002 DEBUG Setting timeout of 3.872568ms client | 0.002 DEBUG StateChange(WaitInitial) client | 0.002 WARN Cannot create stream ConnectionState client | 0.002 DEBUG [Client dd313776e04a96d087df] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } client | 0.002 DEBUG Building Initial dcid Some(CID [10]: dd313776e04a96d087df) 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 dd313776e04a96d087df] delay duration 3.843103ms client | 0.002 DEBUG Setting timeout of 3.843103ms client | 0.007 DEBUG [Client dd313776e04a96d087df] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.007 DEBUG Building Initial dcid Some(CID [10]: dd313776e04a96d087df) 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 dd313776e04a96d087df] delay duration 294.802749ms client | 0.007 DEBUG Setting timeout of 294.802749ms client | 0.303 DEBUG [LossRecovery] PTO timer fired for Initial client | 0.303 DEBUG [Client dd313776e04a96d087df] Lost: Crypto(CryptoRecoveryToken { space: Initial, offset: 0, length: 1211 }) client | 0.303 INFO Lost crypto frame space=in offset=0 length=1211 client | 0.303 DEBUG [Client dd313776e04a96d087df] Lost: EcnEct0 client | 0.303 DEBUG [Client dd313776e04a96d087df] Lost: Crypto(CryptoRecoveryToken { space: Initial, offset: 1211, length: 328 }) client | 0.303 INFO Lost crypto frame space=in offset=1211 length=328 client | 0.303 DEBUG [Client dd313776e04a96d087df] Lost: EcnEct0 client | 0.303 DEBUG [Client dd313776e04a96d087df] output_path send_profile SendProfile { limit: 1252, pto: Some(Initial), probe: EnumSet(Initial), paced: false } client | 0.303 DEBUG Building Initial dcid Some(CID [10]: dd313776e04a96d087df) scid Some(CID [0]: ) client | 0.303 DEBUG CRYPTO for in offset=0, len=1211 client | 0.303 DEBUG [Client dd313776e04a96d087df] pn=2 type=Initial pri-path:dd313776e04a96d087df 0.0.0.0:34682->193.167.100.100:443 IpTos(Cs0, Ect0) len 1252 client | TX -> Crypto { offset: 0, len: 1211 } client | 0.303 DEBUG packet_sent this=0x556673c3a970, pn=2, ps=1252 client | 0.303 DEBUG ECN probing: sent 3 probes client | 0.304 DEBUG [Client dd313776e04a96d087df] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.304 DEBUG Building Initial dcid Some(CID [10]: dd313776e04a96d087df) scid Some(CID [0]: ) client | 0.304 DEBUG CRYPTO for in offset=1211, len=328 client | 0.304 DEBUG [Client dd313776e04a96d087df] pn=3 type=Initial pri-path:dd313776e04a96d087df 0.0.0.0:34682->193.167.100.100:443 IpTos(Cs0, Ect0) len 370 client | TX -> Crypto { offset: 1211, len: 328 } client | 0.304 DEBUG [Client dd313776e04a96d087df] pad Initial from 370 to PLPMTU 1252 client | 0.304 DEBUG packet_sent this=0x556673c3a970, pn=3, ps=1252 client | 0.304 DEBUG ECN probing: sent 4 probes client | 0.304 DEBUG [Client dd313776e04a96d087df] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.304 DEBUG Building Initial dcid Some(CID [10]: dd313776e04a96d087df) 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 dd313776e04a96d087df] delay duration 599.922294ms client | 0.304 DEBUG Setting timeout of 599.922294ms client | 0.904 DEBUG [LossRecovery] PTO timer fired for Initial client | 0.904 DEBUG [Client dd313776e04a96d087df] Lost: Crypto(CryptoRecoveryToken { space: Initial, offset: 0, length: 1211 }) client | 0.904 INFO Lost crypto frame space=in offset=0 length=1211 client | 0.904 DEBUG [Client dd313776e04a96d087df] Lost: EcnEct0 client | 0.904 DEBUG ECN validation failed, all 3 initial marked packets were lost client | 0.904 DEBUG [Client dd313776e04a96d087df] Lost: Crypto(CryptoRecoveryToken { space: Initial, offset: 1211, length: 328 }) client | 0.904 INFO Lost crypto frame space=in offset=1211 length=328 client | 0.904 DEBUG [Client dd313776e04a96d087df] Lost: EcnEct0 client | 0.904 DEBUG [Client dd313776e04a96d087df] output_path send_profile SendProfile { limit: 1252, pto: Some(Initial), probe: EnumSet(Initial), paced: false } client | 0.904 DEBUG Building Initial dcid Some(CID [10]: dd313776e04a96d087df) scid Some(CID [0]: ) client | 0.904 DEBUG CRYPTO for in offset=0, len=1211 client | 0.904 DEBUG [Client dd313776e04a96d087df] pn=4 type=Initial pri-path:dd313776e04a96d087df 0.0.0.0:34682->193.167.100.100:443 IpTos(Cs0, NotEct) len 1252 client | TX -> Crypto { offset: 0, len: 1211 } client | 0.905 DEBUG packet_sent this=0x556673c3a970, pn=4, ps=1252 client | 0.905 DEBUG [Client dd313776e04a96d087df] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.905 DEBUG Building Initial dcid Some(CID [10]: dd313776e04a96d087df) scid Some(CID [0]: ) client | 0.905 DEBUG CRYPTO for in offset=1211, len=328 client | 0.905 DEBUG [Client dd313776e04a96d087df] pn=5 type=Initial pri-path:dd313776e04a96d087df 0.0.0.0:34682->193.167.100.100:443 IpTos(Cs0, NotEct) len 370 client | TX -> Crypto { offset: 1211, len: 328 } client | 0.905 DEBUG [Client dd313776e04a96d087df] pad Initial from 370 to PLPMTU 1252 client | 0.905 DEBUG packet_sent this=0x556673c3a970, pn=5, ps=1252 client | 0.905 DEBUG [Client dd313776e04a96d087df] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.905 DEBUG Building Initial dcid Some(CID [10]: dd313776e04a96d087df) 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 dd313776e04a96d087df] delay duration 1.19990392s client | 0.905 DEBUG Setting timeout of 1.19990392s client | 1.510 DEBUG [Client dd313776e04a96d087df] pn=0 type=Initial pri-path:dd313776e04a96d087df 0.0.0.0:34682->193.167.100.100:443 IpTos(Cs0, NotEct) len 42 client | -> RX Ack { largest_acknowledged: 0, ack_delay: 170, first_ack_range: 0, ack_ranges: [], ecn_count: None } client | 1.510 DEBUG [Client dd313776e04a96d087df] Rx ACK space=in, ranges=[0..=0] client | 1.511 DEBUG [LossRecovery] ACK for Initial - largest_acked=0 client | 1.511 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.511 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 6260/13772 ssthresh 18446744073709551615] on_packets_acked this=0x556673c3a970, limited=0, bytes_in_flight=6260, cwnd=13772, state=SlowStart, new_acked=1252 client | 1.511 DEBUG Acked crypto frame space=in offset=0 length=1211 client | 1.511 DEBUG [Client dd313776e04a96d087df] Changing to use Server CID=b91b992dad54b394 client | 1.511 DEBUG [Client dd313776e04a96d087df] State change from WaitInitial -> WaitVersion client | 1.511 DEBUG [Client dd313776e04a96d087df] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 1.511 DEBUG Building Initial dcid Some(CID [8]: b91b992dad54b394) scid Some(CID [0]: ) client | 1.511 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 1.511 DEBUG [Client dd313776e04a96d087df] delay duration 3.921806902s client | 1.511 DEBUG Setting timeout of 3.921806902s client | 1.511 WARN Unhandled event StateChange(WaitVersion) client | 1.511 DEBUG [Client dd313776e04a96d087df] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 1.511 DEBUG Building Initial dcid Some(CID [8]: b91b992dad54b394) scid Some(CID [0]: ) client | 1.511 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 1.511 DEBUG [Client dd313776e04a96d087df] delay duration 3.921769252s client | 1.511 DEBUG Setting timeout of 3.921769252s client | 1.514 DEBUG [Client dd313776e04a96d087df] pn=1 type=Initial pri-path:b91b992dad54b394 0.0.0.0:34682->193.167.100.100:443 IpTos(Cs0, NotEct) len 136 client | -> RX Ack { largest_acknowledged: 1, ack_delay: 268, first_ack_range: 1, ack_ranges: [], ecn_count: None } client | -> RX Crypto { offset: 0, len: 90 } client | 1.514 DEBUG [Client dd313776e04a96d087df] Rx ACK space=in, ranges=[0..=1] client | 1.514 DEBUG [LossRecovery] ACK for Initial - largest_acked=1 client | 1.514 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.514 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 5008/15024 ssthresh 18446744073709551615] on_packets_acked this=0x556673c3a970, limited=0, bytes_in_flight=5008, cwnd=15024, state=SlowStart, new_acked=1252 client | 1.514 DEBUG Acked crypto frame space=in offset=1211 length=328 client | 1.514 DEBUG Read Ok(90) bytes client | 1.514 DEBUG Write secret available for Handshake: SymKey [48]: 986010b165708012247d78463faf38ca8380e0c9353b9ba2899ac6fff2d1d6521b032c3787b16dba0556b5838a81cbe5 client | 1.514 DEBUG Read secret available for Handshake: SymKey [48]: 9d896a637c03ba2a11fd16657951543b16418bfd6a9bba53b9ddeff5f7263f5e2933f1d3784dc8179b61e4fdb183cf18 client | 1.514 DEBUG [Agent 0x556673c27270] state -> InProgress client | 1.514 DEBUG Making Write Handshake CryptoDxState, v=Version1 cipher=4866 client | 1.514 DEBUG Making Read Handshake CryptoDxState, v=Version1 cipher=4866 client | 1.514 DEBUG [Crypto] Handshake keys installed client | 1.514 DEBUG [Recvd-in] Set ACK timer to Instant { tv_sec: 433, tv_nsec: 175456468 } client | 1.514 DEBUG [Client dd313776e04a96d087df] State change from WaitVersion -> Handshaking client | 1.514 DEBUG [Client dd313776e04a96d087df] pn=2 type=Handshake pri-path:b91b992dad54b394 0.0.0.0:34682->193.167.100.100:443 IpTos(Cs0, NotEct) len 775 client | -> RX Crypto { offset: 0, len: 736 } client | 1.514 DEBUG Read Ok(736) bytes client | 1.515 DEBUG [Agent 0x556673c27270] state -> AuthenticationPending client | 1.515 DEBUG [Recvd-hs] Set ACK timer to Instant { tv_sec: 433, tv_nsec: 175456468 } client | 1.515 DEBUG saving datagram of 289 bytes client | 1.515 DEBUG [Client dd313776e04a96d087df] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 1.515 DEBUG Building Initial dcid Some(CID [8]: b91b992dad54b394) scid Some(CID [0]: ) client | 1.515 DEBUG [Client dd313776e04a96d087df] pn=6 type=Initial pri-path:b91b992dad54b394 0.0.0.0:34682->193.167.100.100:443 IpTos(Cs0, NotEct) len 41 client | TX -> Ack { largest_acknowledged: 1, ack_delay: 174, first_ack_range: 1, ack_ranges: [], ecn_count: None } client | 1.515 DEBUG Building Handshake dcid Some(CID [8]: b91b992dad54b394) scid Some(CID [0]: ) client | 1.515 DEBUG [Client dd313776e04a96d087df] pn=0 type=Handshake pri-path:b91b992dad54b394 0.0.0.0:34682->193.167.100.100:443 IpTos(Cs0, NotEct) len 81 client | TX -> Ack { largest_acknowledged: 2, ack_delay: 174, first_ack_range: 0, ack_ranges: [], ecn_count: None } client | 1.515 DEBUG [Client dd313776e04a96d087df] Drop packet number space in client | 1.515 DEBUG [LossRecovery] Reset loss recovery state for Initial client | 1.515 WARN [LossRecovery] ignoring in-6 from dropped space client | 1.515 DEBUG [Client dd313776e04a96d087df] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 1.515 DEBUG Building Handshake dcid Some(CID [8]: b91b992dad54b394) scid Some(CID [0]: ) client | 1.515 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 1.515 DEBUG [Client dd313776e04a96d087df] delay duration 3.776034947s client | 1.515 DEBUG Setting timeout of 3.776034947s client | 1.515 DEBUG StateChange(Handshaking) client | 1.515 WARN Cannot create stream ConnectionState client | 1.515 DEBUG [Client dd313776e04a96d087df] Authenticated Ok client | 1.515 DEBUG Write secret available for ApplicationData: SymKey [48]: a0b30bce7fa497fb5777340715a14c0a7cde5390ac0e77dcb0a93b21508b142f18ae39b370d2bc336578f7e57428d90b client | 1.515 DEBUG Read secret available for ApplicationData: SymKey [48]: 13ca6d24f59ec45fd97b3b4b8f02ca3a3ee988374fcfef309a6651622b25e3927b5e25ed4b42d3b4e8e499e59bae2c28 client | 1.515 DEBUG [Agent 0x556673c27270] SSL_AuthCertificateComplete: Ok(()) client | 1.515 DEBUG [Agent 0x556673c27270] 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.515 DEBUG [Client dd313776e04a96d087df] TLS connection complete client | 1.515 DEBUG Making Write ApplicationData CryptoDxState, v=Version1 cipher=4866 client | 1.515 DEBUG [Crypto] Application write key installed client | 1.515 DEBUG Making Read ApplicationData CryptoDxState, v=Version1 cipher=4866 client | 1.516 DEBUG [Crypto] application read keys installed client | 1.516 DEBUG [Client dd313776e04a96d087df] State change from Handshaking -> Connected client | 1.516 INFO [Client dd313776e04a96d087df] Connection established client | 1.516 DEBUG [Client dd313776e04a96d087df] process saved for epoch ApplicationData client | 1.516 DEBUG [Client dd313776e04a96d087df] pn=3 type=Short pri-path:b91b992dad54b394 0.0.0.0:34682->193.167.100.100:443 IpTos(Cs0, NotEct) len 289 client | -> RX Crypto { offset: 0, len: 89 } client | -> RX Padding { len: 177 } client | 1.516 DEBUG Read Ok(89) bytes client | 1.516 DEBUG [0x556673c27270] Got resumption token [760]: 02000633fe6bd4d7..c9f5f2a01b343c52 client | 1.516 DEBUG [Agent 0x556673c27270] 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.516 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 433, tv_nsec: 175456468 } client | 1.516 DEBUG stream BiDi creatable client | 1.516 INFO Created stream 0 for https://server4/dncsduldcz client | 1.516 INFO Saving https://server4/dncsduldcz to "/downloads/dncsduldcz" client | 1.516 DEBUG stream UniDi creatable client | 1.516 DEBUG StateChange(Connected) client | 1.516 DEBUG stream 0 writable client | 1.516 DEBUG [Client dd313776e04a96d087df] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 1.516 DEBUG Building Handshake dcid Some(CID [8]: b91b992dad54b394) scid Some(CID [0]: ) client | 1.516 DEBUG CRYPTO for hs offset=0, len=52 client | 1.516 DEBUG [Client dd313776e04a96d087df] pn=1 type=Handshake pri-path:b91b992dad54b394 0.0.0.0:34682->193.167.100.100:443 IpTos(Cs0, NotEct) len 89 client | TX -> Crypto { offset: 0, len: 52 } client | 1.516 DEBUG packet_sent this=0x556673c3a970, pn=1, ps=89 client | 1.516 DEBUG Building Short dcid Some(CID [8]: b91b992dad54b394) client | 1.516 DEBUG [Client dd313776e04a96d087df] pn=0 type=Short pri-path:b91b992dad54b394 0.0.0.0:34682->193.167.100.100:443 IpTos(Cs0, NotEct) len 141 client | TX -> Ack { largest_acknowledged: 3, ack_delay: 265, first_ack_range: 0, ack_ranges: [], ecn_count: None } client | TX -> Stream { stream_id: 0, offset: 0, len: 17, fin: true } client | 1.516 DEBUG packet_sent this=0x556673c3a970, pn=0, ps=52 client | 1.516 DEBUG [Client dd313776e04a96d087df] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 1.516 DEBUG Building Handshake dcid Some(CID [8]: b91b992dad54b394) scid Some(CID [0]: ) client | 1.516 DEBUG Building Short dcid Some(CID [8]: b91b992dad54b394) client | 1.516 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 1.516 DEBUG [Client dd313776e04a96d087df] delay duration 3.776072548s client | 1.516 DEBUG Setting timeout of 3.776072548s client | 1.715 WARN [Client ...] Dropped received packet: Decryption failure; Total: 1 client | 1.715 DEBUG [Client dd313776e04a96d087df] pn=5 type=Handshake pri-path:b91b992dad54b394 0.0.0.0:34682->193.167.100.100:443 IpTos(Cs0, NotEct) len 775 client | -> RX Crypto { offset: 0, len: 736 } client | 1.715 DEBUG [Recvd-hs] Set ACK timer to Instant { tv_sec: 433, tv_nsec: 376593351 } client | 1.715 DEBUG [Client dd313776e04a96d087df] pn=6 type=Short pri-path:b91b992dad54b394 0.0.0.0:34682->193.167.100.100:443 IpTos(Cs0, NotEct) len 295 client | -> RX Crypto { offset: 0, len: 89 } client | -> RX Padding { len: 183 } client | 1.715 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 433, tv_nsec: 376593351 } client | 1.715 DEBUG [Client dd313776e04a96d087df] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 1.715 DEBUG Building Handshake dcid Some(CID [8]: b91b992dad54b394) scid Some(CID [0]: ) client | 1.715 DEBUG CRYPTO for hs offset=0, len=52 client | 1.715 DEBUG [Client dd313776e04a96d087df] pn=2 type=Handshake pri-path:b91b992dad54b394 0.0.0.0:34682->193.167.100.100:443 IpTos(Cs0, NotEct) len 96 client | TX -> Ack { largest_acknowledged: 5, ack_delay: 12, first_ack_range: 0, ack_ranges: [AckRange { gap: 1, range: 0 }], ecn_count: None } client | TX -> Crypto { offset: 0, len: 52 } client | 1.715 DEBUG packet_sent this=0x556673c3a970, pn=2, ps=96 client | 1.715 DEBUG Building Short dcid Some(CID [8]: b91b992dad54b394) client | 1.715 DEBUG [Client dd313776e04a96d087df] pn=1 type=Short pri-path:b91b992dad54b394 0.0.0.0:34682->193.167.100.100:443 IpTos(Cs0, NotEct) len 129 client | TX -> Ack { largest_acknowledged: 6, ack_delay: 12, first_ack_range: 0, ack_ranges: [AckRange { gap: 1, range: 0 }], ecn_count: None } client | 1.715 DEBUG [Client dd313776e04a96d087df] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 1.715 DEBUG Building Handshake dcid Some(CID [8]: b91b992dad54b394) scid Some(CID [0]: ) client | 1.715 DEBUG Building Short dcid Some(CID [8]: b91b992dad54b394) client | 1.715 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 1.715 DEBUG [Client dd313776e04a96d087df] delay duration 3.775903812s client | 1.715 DEBUG Setting timeout of 3.775903812s client | 1.715 DEBUG [Client dd313776e04a96d087df] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 1.715 DEBUG Building Handshake dcid Some(CID [8]: b91b992dad54b394) scid Some(CID [0]: ) client | 1.715 DEBUG Building Short dcid Some(CID [8]: b91b992dad54b394) client | 1.715 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 1.715 DEBUG [Client dd313776e04a96d087df] delay duration 3.775801029s client | 1.715 DEBUG Setting timeout of 3.775801029s client | 1.807 WARN [Client ...] Dropped received packet: Decryption failure; Total: 2 client | 1.807 DEBUG [Client dd313776e04a96d087df] pn=8 type=Handshake pri-path:b91b992dad54b394 0.0.0.0:34682->193.167.100.100:443 IpTos(Cs0, NotEct) len 775 client | -> RX Crypto { offset: 0, len: 736 } client | 1.807 DEBUG [Recvd-hs] Set ACK timer to Instant { tv_sec: 433, tv_nsec: 468900115 } client | 1.807 DEBUG [Client dd313776e04a96d087df] pn=9 type=Short pri-path:b91b992dad54b394 0.0.0.0:34682->193.167.100.100:443 IpTos(Cs0, NotEct) len 290 client | -> RX Crypto { offset: 0, len: 89 } client | -> RX Padding { len: 178 } client | 1.807 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 433, tv_nsec: 468900115 } client | 1.807 DEBUG [Client dd313776e04a96d087df] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 1.807 DEBUG Building Handshake dcid Some(CID [8]: b91b992dad54b394) scid Some(CID [0]: ) client | 1.807 DEBUG CRYPTO for hs offset=0, len=52 client | 1.807 DEBUG [Client dd313776e04a96d087df] pn=3 type=Handshake pri-path:b91b992dad54b394 0.0.0.0:34682->193.167.100.100:443 IpTos(Cs0, NotEct) len 98 client | TX -> Ack { largest_acknowledged: 8, ack_delay: 21, first_ack_range: 0, ack_ranges: [AckRange { gap: 1, range: 0 }, AckRange { gap: 1, range: 0 }], ecn_count: None } client | TX -> Crypto { offset: 0, len: 52 } client | 1.807 DEBUG packet_sent this=0x556673c3a970, pn=3, ps=98 client | 1.807 DEBUG Building Short dcid Some(CID [8]: b91b992dad54b394) client | 1.807 DEBUG [Client dd313776e04a96d087df] pn=2 type=Short pri-path:b91b992dad54b394 0.0.0.0:34682->193.167.100.100:443 IpTos(Cs0, NotEct) len 133 client | TX -> Ack { largest_acknowledged: 9, ack_delay: 21, first_ack_range: 0, ack_ranges: [AckRange { gap: 1, range: 0 }, AckRange { gap: 1, range: 0 }], ecn_count: None } client | 1.807 DEBUG [Client dd313776e04a96d087df] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 1.807 DEBUG Building Handshake dcid Some(CID [8]: b91b992dad54b394) scid Some(CID [0]: ) client | 1.807 DEBUG Building Short dcid Some(CID [8]: b91b992dad54b394) client | 1.807 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 1.807 DEBUG [Client dd313776e04a96d087df] delay duration 3.776014739s client | 1.807 DEBUG Setting timeout of 3.776014739s client | 1.807 WARN [Client ...] Dropped received packet: Decryption failure; Total: 3 client | 1.807 DEBUG [Client dd313776e04a96d087df] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 1.807 DEBUG Building Handshake dcid Some(CID [8]: b91b992dad54b394) scid Some(CID [0]: ) client | 1.807 DEBUG Building Short dcid Some(CID [8]: b91b992dad54b394) client | 1.807 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 1.807 DEBUG [Client dd313776e04a96d087df] delay duration 3.775971819s client | 1.807 DEBUG Setting timeout of 3.775971819s client | 1.807 DEBUG [Client dd313776e04a96d087df] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 1.807 DEBUG Building Handshake dcid Some(CID [8]: b91b992dad54b394) scid Some(CID [0]: ) client | 1.807 DEBUG Building Short dcid Some(CID [8]: b91b992dad54b394) client | 1.807 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 1.808 DEBUG [Client dd313776e04a96d087df] delay duration 3.775948325s client | 1.808 DEBUG Setting timeout of 3.775948325s client | 2.209 WARN [Client ...] Dropped received packet: Decryption failure; Total: 4 client | 2.209 DEBUG [Client dd313776e04a96d087df] pn=12 type=Handshake pri-path:b91b992dad54b394 0.0.0.0:34682->193.167.100.100:443 IpTos(Cs0, NotEct) len 775 client | -> RX Crypto { offset: 0, len: 736 } client | 2.209 DEBUG [Recvd-hs] Set ACK timer to Instant { tv_sec: 433, tv_nsec: 870480520 } client | 2.209 DEBUG [Client dd313776e04a96d087df] pn=13 type=Short pri-path:b91b992dad54b394 0.0.0.0:34682->193.167.100.100:443 IpTos(Cs0, NotEct) len 295 client | -> RX Crypto { offset: 0, len: 89 } client | -> RX Padding { len: 183 } client | 2.209 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 433, tv_nsec: 870480520 } client | 2.209 DEBUG [Client dd313776e04a96d087df] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 2.209 DEBUG Building Handshake dcid Some(CID [8]: b91b992dad54b394) scid Some(CID [0]: ) client | 2.209 DEBUG CRYPTO for hs offset=0, len=52 client | 2.209 DEBUG [Client dd313776e04a96d087df] pn=4 type=Handshake pri-path:b91b992dad54b394 0.0.0.0:34682->193.167.100.100:443 IpTos(Cs0, NotEct) len 100 client | TX -> Ack { largest_acknowledged: 12, ack_delay: 10, first_ack_range: 0, ack_ranges: [AckRange { gap: 2, range: 0 }, AckRange { gap: 1, range: 0 }, AckRange { gap: 1, range: 0 }], ecn_count: None } client | TX -> Crypto { offset: 0, len: 52 } client | 2.209 DEBUG packet_sent this=0x556673c3a970, pn=4, ps=100 client | 2.209 DEBUG Building Short dcid Some(CID [8]: b91b992dad54b394) client | 2.209 DEBUG [Client dd313776e04a96d087df] pn=3 type=Short pri-path:b91b992dad54b394 0.0.0.0:34682->193.167.100.100:443 IpTos(Cs0, NotEct) len 137 client | TX -> Ack { largest_acknowledged: 13, ack_delay: 10, first_ack_range: 0, ack_ranges: [AckRange { gap: 2, range: 0 }, AckRange { gap: 1, range: 0 }, AckRange { gap: 1, range: 0 }], ecn_count: None } client | 2.209 DEBUG [Client dd313776e04a96d087df] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 2.209 DEBUG Building Handshake dcid Some(CID [8]: b91b992dad54b394) scid Some(CID [0]: ) client | 2.209 DEBUG Building Short dcid Some(CID [8]: b91b992dad54b394) client | 2.209 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 2.209 DEBUG [Client dd313776e04a96d087df] delay duration 3.776023637s client | 2.209 DEBUG Setting timeout of 3.776023637s client | 2.209 DEBUG [Client dd313776e04a96d087df] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 2.209 DEBUG Building Handshake dcid Some(CID [8]: b91b992dad54b394) scid Some(CID [0]: ) client | 2.209 DEBUG Building Short dcid Some(CID [8]: b91b992dad54b394) client | 2.209 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 2.209 DEBUG [Client dd313776e04a96d087df] delay duration 3.775985375s client | 2.209 DEBUG Setting timeout of 3.775985375s client | 2.407 WARN [Client ...] Dropped received packet: Decryption failure; Total: 5 client | 2.407 DEBUG [Client dd313776e04a96d087df] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 2.407 DEBUG Building Handshake dcid Some(CID [8]: b91b992dad54b394) scid Some(CID [0]: ) client | 2.407 DEBUG Building Short dcid Some(CID [8]: b91b992dad54b394) client | 2.407 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 2.407 DEBUG [Client dd313776e04a96d087df] delay duration 3.57799456s client | 2.407 DEBUG Setting timeout of 3.57799456s client | 2.407 DEBUG [Client dd313776e04a96d087df] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 2.407 DEBUG Building Handshake dcid Some(CID [8]: b91b992dad54b394) scid Some(CID [0]: ) client | 2.407 DEBUG Building Short dcid Some(CID [8]: b91b992dad54b394) client | 2.407 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 2.407 DEBUG [Client dd313776e04a96d087df] delay duration 3.577962359s client | 2.407 DEBUG Setting timeout of 3.577962359s client | 2.407 WARN [Client ...] Dropped received packet: Decryption failure; Total: 6 client | 2.407 DEBUG [Client dd313776e04a96d087df] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 2.407 DEBUG Building Handshake dcid Some(CID [8]: b91b992dad54b394) scid Some(CID [0]: ) client | 2.407 DEBUG Building Short dcid Some(CID [8]: b91b992dad54b394) client | 2.407 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 2.407 DEBUG [Client dd313776e04a96d087df] delay duration 3.577586044s client | 2.407 DEBUG Setting timeout of 3.577586044s client | 2.407 DEBUG [Client dd313776e04a96d087df] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 2.407 DEBUG Building Handshake dcid Some(CID [8]: b91b992dad54b394) scid Some(CID [0]: ) client | 2.407 DEBUG Building Short dcid Some(CID [8]: b91b992dad54b394) client | 2.407 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 2.407 DEBUG [Client dd313776e04a96d087df] delay duration 3.577562961s client | 2.407 DEBUG Setting timeout of 3.577562961s client | 3.010 WARN [Client ...] Dropped received packet: Decryption failure; Total: 7 client | 3.010 DEBUG [Client dd313776e04a96d087df] pn=17 type=Handshake pri-path:b91b992dad54b394 0.0.0.0:34682->193.167.100.100:443 IpTos(Cs0, NotEct) len 775 client | -> RX Crypto { offset: 0, len: 736 } client | 3.010 DEBUG [Recvd-hs] Set ACK timer to Instant { tv_sec: 434, tv_nsec: 671566694 } client | 3.010 DEBUG [Client dd313776e04a96d087df] pn=18 type=Short pri-path:b91b992dad54b394 0.0.0.0:34682->193.167.100.100:443 IpTos(Cs0, NotEct) len 295 client | -> RX Crypto { offset: 0, len: 89 } client | -> RX Padding { len: 183 } client | 3.010 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 434, tv_nsec: 671566694 } client | 3.010 DEBUG [Client dd313776e04a96d087df] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 3.010 DEBUG Building Handshake dcid Some(CID [8]: b91b992dad54b394) scid Some(CID [0]: ) client | 3.010 DEBUG CRYPTO for hs offset=0, len=52 client | 3.010 DEBUG [Client dd313776e04a96d087df] pn=5 type=Handshake pri-path:b91b992dad54b394 0.0.0.0:34682->193.167.100.100:443 IpTos(Cs0, NotEct) len 102 client | TX -> Ack { largest_acknowledged: 17, ack_delay: 12, first_ack_range: 0, ack_ranges: [AckRange { gap: 3, range: 0 }, AckRange { gap: 2, range: 0 }, AckRange { gap: 1, range: 0 }, AckRange { gap: 1, range: 0 }], ecn_count: None } client | TX -> Crypto { offset: 0, len: 52 } client | 3.010 DEBUG packet_sent this=0x556673c3a970, pn=5, ps=102 client | 3.010 DEBUG Building Short dcid Some(CID [8]: b91b992dad54b394) client | 3.010 DEBUG [Client dd313776e04a96d087df] pn=4 type=Short pri-path:b91b992dad54b394 0.0.0.0:34682->193.167.100.100:443 IpTos(Cs0, NotEct) len 141 client | TX -> Ack { largest_acknowledged: 18, ack_delay: 12, first_ack_range: 0, ack_ranges: [AckRange { gap: 3, range: 0 }, AckRange { gap: 2, range: 0 }, AckRange { gap: 1, range: 0 }, AckRange { gap: 1, range: 0 }], ecn_count: None } client | 3.010 DEBUG [Client dd313776e04a96d087df] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 3.010 DEBUG Building Handshake dcid Some(CID [8]: b91b992dad54b394) scid Some(CID [0]: ) client | 3.010 DEBUG Building Short dcid Some(CID [8]: b91b992dad54b394) client | 3.010 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 3.010 DEBUG [Client dd313776e04a96d087df] delay duration 3.775952032s client | 3.010 DEBUG Setting timeout of 3.775952032s client | 3.010 DEBUG [Client dd313776e04a96d087df] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 3.010 DEBUG Building Handshake dcid Some(CID [8]: b91b992dad54b394) scid Some(CID [0]: ) client | 3.010 DEBUG Building Short dcid Some(CID [8]: b91b992dad54b394) client | 3.010 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 3.010 DEBUG [Client dd313776e04a96d087df] delay duration 3.775912738s client | 3.010 DEBUG Setting timeout of 3.775912738s client | 3.018 DEBUG [Client dd313776e04a96d087df] pn=19 type=Short pri-path:b91b992dad54b394 0.0.0.0:34682->193.167.100.100:443 IpTos(Cs0, NotEct) len 216 client | -> RX HandshakeDone client | -> RX NewConnectionId { sequence_number: 1, retire_prior: 0, connection_id: [16, 243, 34, 61, 154, 232, 133, 144], stateless_reset_token: [201, 17, 132, 159, 48, 192, 162, 181, 9, 0, 203, 201, 115, 175, 23, 182] } client | -> RX NewConnectionId { sequence_number: 2, retire_prior: 0, connection_id: [224, 86, 212, 198, 214, 125, 101, 193], stateless_reset_token: [129, 180, 100, 166, 91, 127, 136, 101, 249, 43, 47, 159, 99, 1, 226, 254] } client | -> RX NewConnectionId { sequence_number: 3, retire_prior: 0, connection_id: [25, 103, 198, 33, 98, 1, 61, 219], stateless_reset_token: [145, 130, 8, 104, 123, 71, 246, 103, 196, 54, 165, 38, 29, 124, 163, 28] } client | -> RX NewConnectionId { sequence_number: 4, retire_prior: 0, connection_id: [220, 226, 136, 39, 195, 149, 191, 126], stateless_reset_token: [96, 162, 240, 103, 35, 98, 208, 74, 243, 59, 1, 121, 64, 44, 106, 144] } client | -> RX NewConnectionId { sequence_number: 5, retire_prior: 0, connection_id: [4, 99, 107, 229, 250, 38, 119, 159], stateless_reset_token: [199, 57, 150, 250, 205, 50, 174, 153, 96, 235, 72, 185, 93, 40, 33, 142] } client | -> RX NewConnectionId { sequence_number: 6, retire_prior: 0, connection_id: [56, 240, 200, 101, 81, 36, 82, 64], stateless_reset_token: [144, 210, 224, 181, 75, 8, 216, 184, 176, 94, 145, 222, 159, 196, 131, 176] } client | -> RX NewConnectionId { sequence_number: 7, retire_prior: 0, connection_id: [212, 183, 160, 65, 54, 193, 48, 95], stateless_reset_token: [45, 11, 151, 237, 171, 221, 56, 13, 136, 63, 77, 204, 175, 76, 247, 80] } client | 3.018 DEBUG [Client dd313776e04a96d087df] State change from Connected -> Confirmed client | 3.018 DEBUG PMTUD started with probe size 1380 client | 3.018 DEBUG [Client dd313776e04a96d087df] Drop packet number space hs client | 3.018 DEBUG [LossRecovery] Reset loss recovery state for Handshake client | 3.018 DEBUG [Client dd313776e04a96d087df] No preferred address to migrate to client | 3.018 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 434, tv_nsec: 699516684 } client | 3.018 DEBUG [Client dd313776e04a96d087df] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 3.018 DEBUG Building Short dcid Some(CID [8]: b91b992dad54b394) client | 3.018 DEBUG Sending PMTUD probe of size 1380, count 1 client | 3.018 DEBUG [Client dd313776e04a96d087df] pn=5 type=Short pri-path:b91b992dad54b394 0.0.0.0:34682->193.167.100.100:443 IpTos(Cs0, NotEct) len 1352 client | TX -> Ping client | TX -> Padding { len: 1325 } client | 3.018 DEBUG packet_sent this=0x556673c3a970, pn=5, ps=1352 client | 3.018 DEBUG [Client dd313776e04a96d087df] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 3.018 DEBUG Building Short dcid Some(CID [8]: b91b992dad54b394) client | 3.018 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 3.018 DEBUG [Client dd313776e04a96d087df] delay duration 19.778474ms client | 3.018 DEBUG Setting timeout of 19.778474ms client | 3.018 WARN Unhandled event StateChange(Confirmed) client | 3.018 DEBUG [Client dd313776e04a96d087df] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 3.018 DEBUG Building Short dcid Some(CID [8]: b91b992dad54b394) client | 3.018 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 3.018 DEBUG [Client dd313776e04a96d087df] delay duration 19.743819ms client | 3.018 DEBUG Setting timeout of 19.743819ms client | 3.021 DEBUG [Client dd313776e04a96d087df] pn=20 type=Short pri-path:b91b992dad54b394 0.0.0.0:34682->193.167.100.100:443 IpTos(Cs0, NotEct) len 25 client | -> RX Ack { largest_acknowledged: 0, ack_delay: 517, first_ack_range: 0, ack_ranges: [], ecn_count: None } client | 3.021 DEBUG [Client dd313776e04a96d087df] Rx ACK space=ap, ranges=[0..=0] client | 3.021 DEBUG [LossRecovery] ACK for ApplicationData - largest_acked=0 client | 3.021 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 1352/15076 ssthresh 18446744073709551615] slow start += 52 client | 3.021 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 1352/15076 ssthresh 18446744073709551615] on_packets_acked this=0x556673c3a970, limited=0, bytes_in_flight=1352, cwnd=15076, state=SlowStart, new_acked=52 client | 3.021 DEBUG [Client dd313776e04a96d087df] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 3.021 DEBUG Building Short dcid Some(CID [8]: b91b992dad54b394) client | 3.021 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 3.021 DEBUG [Client dd313776e04a96d087df] delay duration 16.988635ms client | 3.021 DEBUG Setting timeout of 16.988635ms client | 3.021 DEBUG stream 0 complete client | 3.021 DEBUG [Client dd313776e04a96d087df] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 3.021 DEBUG Building Short dcid Some(CID [8]: b91b992dad54b394) client | 3.021 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 3.021 DEBUG [Client dd313776e04a96d087df] delay duration 16.963999ms client | 3.021 DEBUG Setting timeout of 16.963999ms client | 3.024 DEBUG [Client dd313776e04a96d087df] pn=21 type=Short pri-path:b91b992dad54b394 0.0.0.0:34682->193.167.100.100:443 IpTos(Cs0, NotEct) len 1047 client | -> RX Stream { stream_id: 0, offset: 0, len: 1024, fin: true } client | 3.024 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 434, tv_nsec: 686030353 } client | 3.024 DEBUG [Client dd313776e04a96d087df] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 3.024 DEBUG Building Short dcid Some(CID [8]: b91b992dad54b394) client | 3.024 DEBUG [Client dd313776e04a96d087df] pn=6 type=Short pri-path:b91b992dad54b394 0.0.0.0:34682->193.167.100.100:443 IpTos(Cs0, NotEct) len 37 client | TX -> Ack { largest_acknowledged: 21, ack_delay: 3, first_ack_range: 3, ack_ranges: [AckRange { gap: 3, range: 0 }, AckRange { gap: 2, range: 0 }, AckRange { gap: 1, range: 0 }], ecn_count: None } client | 3.024 DEBUG [Client dd313776e04a96d087df] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 3.024 DEBUG Building Short dcid Some(CID [8]: b91b992dad54b394) client | 3.024 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 3.024 DEBUG [Client dd313776e04a96d087df] delay duration 3.23212324s client | 3.024 DEBUG Setting timeout of 3.23212324s client | 3.024 DEBUG [Client dd313776e04a96d087df] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 3.024 DEBUG Building Short dcid Some(CID [8]: b91b992dad54b394) client | 3.024 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 3.024 DEBUG [Client dd313776e04a96d087df] delay duration 3.232055273s client | 3.024 DEBUG Setting timeout of 3.232055273s client | 3.024 DEBUG [Client dd313776e04a96d087df] State change from Confirmed -> Closing { error: Application(0), timeout: Instant { tv_sec: 444, tv_nsec: 402053450 } } client | 3.024 WARN Unhandled event StateChange(Closing { error: Application(0), timeout: Instant { tv_sec: 444, tv_nsec: 402053450 } }) client | 3.024 DEBUG [Client dd313776e04a96d087df] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 3.024 DEBUG Building Short dcid Some(CID [8]: b91b992dad54b394) client | 3.024 DEBUG [Recvd-ap] immediate_ack at Instant { tv_sec: 434, tv_nsec: 686239335 } client | 3.024 DEBUG [Client dd313776e04a96d087df] pn=7 type=Short pri-path:b91b992dad54b394 0.0.0.0:34682->193.167.100.100:443 IpTos(Cs0, NotEct) len 48 client | TX -> Ack { largest_acknowledged: 21, ack_delay: 26, first_ack_range: 3, ack_ranges: [AckRange { gap: 3, range: 0 }, AckRange { gap: 2, range: 0 }, AckRange { gap: 1, range: 0 }], ecn_count: None } client | TX -> ConnectionClose { error_code: Application(0), frame_type: 0, reason_phrase: "kthxbye!" } client | 3.025 DEBUG Setting timeout of 9.715722403s client | 3.225 DEBUG [Client dd313776e04a96d087df] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 3.225 DEBUG Building Short dcid Some(CID [8]: b91b992dad54b394) client | 3.225 DEBUG [Recvd-ap] immediate_ack at Instant { tv_sec: 434, tv_nsec: 886742251 } client | 3.225 DEBUG [Client dd313776e04a96d087df] pn=8 type=Short pri-path:b91b992dad54b394 0.0.0.0:34682->193.167.100.100:443 IpTos(Cs0, NotEct) len 51 client | TX -> Ack { largest_acknowledged: 21, ack_delay: 25088, first_ack_range: 3, ack_ranges: [AckRange { gap: 3, range: 0 }, AckRange { gap: 2, range: 0 }, AckRange { gap: 1, range: 0 }], ecn_count: None } client | TX -> ConnectionClose { error_code: Application(0), frame_type: 0, reason_phrase: "kthxbye!" } client | 3.225 DEBUG Setting timeout of 9.515175104s client | 3.225 DEBUG Setting timeout of 9.515158323s client | 3.626 DEBUG [Client dd313776e04a96d087df] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 3.626 DEBUG Building Short dcid Some(CID [8]: b91b992dad54b394) client | 3.626 DEBUG [Recvd-ap] immediate_ack at Instant { tv_sec: 435, tv_nsec: 287716835 } client | 3.626 DEBUG [Client dd313776e04a96d087df] pn=9 type=Short pri-path:b91b992dad54b394 0.0.0.0:34682->193.167.100.100:443 IpTos(Cs0, NotEct) len 51 client | TX -> Ack { largest_acknowledged: 21, ack_delay: 75210, first_ack_range: 3, ack_ranges: [AckRange { gap: 3, range: 0 }, AckRange { gap: 2, range: 0 }, AckRange { gap: 1, range: 0 }], ecn_count: None } client | TX -> ConnectionClose { error_code: Application(0), frame_type: 0, reason_phrase: "kthxbye!" } client | 3.626 DEBUG Setting timeout of 9.114196843s client | 3.626 DEBUG Setting timeout of 9.114181966s client | 4.428 DEBUG [Client dd313776e04a96d087df] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 4.428 DEBUG Building Short dcid Some(CID [8]: b91b992dad54b394) client | 4.428 DEBUG [Recvd-ap] immediate_ack at Instant { tv_sec: 436, tv_nsec: 89507278 } client | 4.428 DEBUG [Client dd313776e04a96d087df] pn=10 type=Short pri-path:b91b992dad54b394 0.0.0.0:34682->193.167.100.100:443 IpTos(Cs0, NotEct) len 51 client | TX -> Ack { largest_acknowledged: 21, ack_delay: 175434, first_ack_range: 3, ack_ranges: [AckRange { gap: 3, range: 0 }, AckRange { gap: 2, range: 0 }, AckRange { gap: 1, range: 0 }], ecn_count: None } client | TX -> ConnectionClose { error_code: Application(0), frame_type: 0, reason_phrase: "kthxbye!" } client | 4.428 DEBUG Setting timeout of 8.312364853s client | 4.428 DEBUG Setting timeout of 8.312352169s client | 4.521 DEBUG [Client dd313776e04a96d087df] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 4.521 DEBUG Building Short dcid Some(CID [8]: b91b992dad54b394) client | 4.521 DEBUG [Recvd-ap] immediate_ack at Instant { tv_sec: 436, tv_nsec: 183058061 } client | 4.521 DEBUG [Client dd313776e04a96d087df] pn=11 type=Short pri-path:b91b992dad54b394 0.0.0.0:34682->193.167.100.100:443 IpTos(Cs0, NotEct) len 51 client | TX -> Ack { largest_acknowledged: 21, ack_delay: 187128, first_ack_range: 3, ack_ranges: [AckRange { gap: 3, range: 0 }, AckRange { gap: 2, range: 0 }, AckRange { gap: 1, range: 0 }], ecn_count: None } client | TX -> ConnectionClose { error_code: Application(0), frame_type: 0, reason_phrase: "kthxbye!" } client | 4.521 DEBUG Setting timeout of 8.218855397s client | 4.521 DEBUG Setting timeout of 8.218839848s client | 12.741 DEBUG [Client dd313776e04a96d087df] State change from Closing { error: Application(0), timeout: Instant { tv_sec: 444, tv_nsec: 402053450 } } -> Closed(Application(0)) client | 12.741 INFO Closing timer expired client | 12.741 DEBUG Output::None client | 12.741 WARN Unhandled event StateChange(Closed(Application(0))) client | 12.741 DEBUG Timer fired while closed client | 12.741 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 12:55:05,737 Using the client's key log file. 2025-04-30 12:55:05,747 2025-04-30 12:55:05,748 Using the client's key log file. 2025-04-30 12:55:05,748 Using the client's key log file. 2025-04-30 12:55:05,757 2025-04-30 12:55:05,757 Using the client's key log file. 2025-04-30 12:55:06,055 Check of downloaded files succeeded. 2025-04-30 12:55:07,249 Check of downloaded files succeeded.