2025-04-30 12:57:46,735 Generated random file: djzbynxffp of size: 5120 2025-04-30 12:57:46,735 Requests: https://server4:443/djzbynxffp 2025-04-30 12:57:47,121 2025-04-30 12:57:47,121 Command: WAITFORSERVER=server:443 CERTS=/tmp/certs_ebcewz03/ TESTCASE_SERVER=transfer TESTCASE_CLIENT=transfer WWW=/tmp/www_9xwchicy/ DOWNLOADS=/tmp/download_8ddjjbmg/ SERVER_LOGS=/tmp/logs_server_b8dztzsv CLIENT_LOGS=/tmp/logs_client_lnko419c SCENARIO="droplist --delay=15ms --bandwidth=10Mbps --queue=25 --drops_to_server=2,3,4,5,6,7" CLIENT=ghcr.io/mozilla/neqo-qns:latest SERVER=aiortc/aioquic-qns:latest REQUESTS="https://server4:443/djzbynxffp" docker compose --env-file empty.env up --abort-on-container-exit --timeout 1 sim client server 2025-04-30 12:58:06,847 Container sim Recreate Container sim Recreated Container client Recreate Container server Recreate Container client Recreated Container server Recreated Attaching to client, server, sim sim | waiting 10s for server:443 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 transfer ']' 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.038521763s sim | Using scenario: droplist --delay=15ms --bandwidth=10Mbps --queue=25 --drops_to_server=2,3,4,5,6,7 sim | tcpdump: listening on eth1, link-type EN10MB (Ethernet), snapshot length 262144 bytes sim | tcpdump: listening on eth0, link-type EN10MB (Ethernet), snapshot length 262144 bytes client | wait-for-it.sh: sim:57832 is available after 1 seconds client | + OPTIONS=(--cc cubic --qns-test "$TESTCASE" --qlog-dir "$QLOGDIR" --output-dir /downloads) client | + '[' https://server4:443/djzbynxffp ']' client | + mapfile -d ' ' -t URLS client | + OPTIONS+=("${URLS[@]}") client | + RUST_LOG=debug client | + RUST_BACKTRACE=1 client | + neqo-client --cc cubic --qns-test transfer --qlog-dir /logs/qlog/ --output-dir /downloads 'https://server4:443/djzbynxffp 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:34244 -> 193.167.100.100:443 client | 0.001 DEBUG [CryptoStates] Creating initial cipher state v=Version1, role=Client dcid=47025ea090491916d639dd959c906d 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:34244->193.167.100.100:443] Make permanent client | 0.001 DEBUG [unv-path:47025ea090491916d639dd959c906d 0.0.0.0:34244->193.167.100.100:443] set as primary path client | 0.001 DEBUG [pri-unv-path:47025ea090491916d639dd959c906d 0.0.0.0:34244->193.167.100.100:443] Path validated Instant { tv_sec: 617, tv_nsec: 757504620 } client | 0.001 DEBUG [Client 47025ea090491916d639dd959c906d] client_start client | 0.002 DEBUG Writing transport parameters, msg=1 client | 0.002 DEBUG [Agent 0x563fccdbb270] state -> InProgress client | 0.002 DEBUG [Client 47025ea090491916d639dd959c906d] State change from Init -> WaitInitial client | 0.002 DEBUG [Client 47025ea090491916d639dd959c906d] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.002 DEBUG Building Initial dcid Some(CID [15]: 47025ea090491916d639dd959c906d) scid Some(CID [0]: ) client | 0.002 DEBUG CRYPTO for in offset=0, len=1206 client | 0.002 DEBUG [Client 47025ea090491916d639dd959c906d] pn=0 type=Initial pri-path:47025ea090491916d639dd959c906d 0.0.0.0:34244->193.167.100.100:443 IpTos(Cs0, Ect0) len 1252 client | TX -> Crypto { offset: 0, len: 1206 } client | 0.002 DEBUG packet_sent this=0x563fccdce970, pn=0, ps=1252 client | 0.002 DEBUG ECN probing: sent 1 probes client | 0.002 DEBUG [Client 47025ea090491916d639dd959c906d] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.002 DEBUG Building Initial dcid Some(CID [15]: 47025ea090491916d639dd959c906d) scid Some(CID [0]: ) client | 0.002 DEBUG CRYPTO for in offset=1206, len=333 client | 0.002 DEBUG [Client 47025ea090491916d639dd959c906d] pn=1 type=Initial pri-path:47025ea090491916d639dd959c906d 0.0.0.0:34244->193.167.100.100:443 IpTos(Cs0, Ect0) len 380 client | TX -> Crypto { offset: 1206, len: 333 } client | 0.002 DEBUG [Client 47025ea090491916d639dd959c906d] pad Initial from 380 to PLPMTU 1252 client | 0.002 DEBUG packet_sent this=0x563fccdce970, pn=1, ps=1252 client | 0.002 DEBUG ECN probing: sent 2 probes client | 0.002 DEBUG [Client 47025ea090491916d639dd959c906d] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } client | 0.002 DEBUG Building Initial dcid Some(CID [15]: 47025ea090491916d639dd959c906d) 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 47025ea090491916d639dd959c906d] delay duration 3.907458ms client | 0.002 DEBUG Setting timeout of 3.907458ms client | 0.002 DEBUG StateChange(WaitInitial) client | 0.002 WARN Cannot create stream ConnectionState client | 0.002 DEBUG [Client 47025ea090491916d639dd959c906d] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } client | 0.002 DEBUG Building Initial dcid Some(CID [15]: 47025ea090491916d639dd959c906d) 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 47025ea090491916d639dd959c906d] delay duration 3.875759ms client | 0.002 DEBUG Setting timeout of 3.875759ms client | 0.007 DEBUG [Client 47025ea090491916d639dd959c906d] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.007 DEBUG Building Initial dcid Some(CID [15]: 47025ea090491916d639dd959c906d) 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 47025ea090491916d639dd959c906d] delay duration 294.81746ms client | 0.007 DEBUG Setting timeout of 294.81746ms sim | Dropping packet 2 (1252 bytes) from 193.167.0.100 client | 0.040 DEBUG [Client 47025ea090491916d639dd959c906d] pn=0 type=Initial pri-path:47025ea090491916d639dd959c906d 0.0.0.0:34244->193.167.100.100:443 IpTos(Cs0, NotEct) len 42 client | -> RX Ack { largest_acknowledged: 0, ack_delay: 182, first_ack_range: 0, ack_ranges: [], ecn_count: None } client | 0.040 DEBUG [Client 47025ea090491916d639dd959c906d] Rx ACK space=in, ranges=[0..=0] client | 0.040 DEBUG [LossRecovery] ACK for Initial - largest_acked=0 client | 0.040 DEBUG on_packets_acked this=0x563fccdce970, limited=1, bytes_in_flight=1252, cwnd=12520, state=SlowStart, new_acked=1252 client | 0.040 DEBUG Acked crypto frame space=in offset=0 length=1206 client | 0.040 DEBUG [Client 47025ea090491916d639dd959c906d] Changing to use Server CID=7e8fdd569f16e480 client | 0.040 DEBUG [Client 47025ea090491916d639dd959c906d] State change from WaitInitial -> WaitVersion client | 0.040 DEBUG [Client 47025ea090491916d639dd959c906d] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.040 DEBUG Building Initial dcid Some(CID [8]: 7e8fdd569f16e480) scid Some(CID [0]: ) client | 0.040 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.040 DEBUG [Client 47025ea090491916d639dd959c906d] delay duration 78.500507ms client | 0.040 DEBUG Setting timeout of 78.500507ms client | 0.040 WARN Unhandled event StateChange(WaitVersion) client | 0.040 DEBUG [Client 47025ea090491916d639dd959c906d] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.040 DEBUG Building Initial dcid Some(CID [8]: 7e8fdd569f16e480) scid Some(CID [0]: ) client | 0.040 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.040 DEBUG [Client 47025ea090491916d639dd959c906d] delay duration 78.470932ms client | 0.040 DEBUG Setting timeout of 78.470932ms client | 0.120 DEBUG [LossRecovery] PTO timer fired for Initial client | 0.120 DEBUG [Client 47025ea090491916d639dd959c906d] Lost: Crypto(CryptoRecoveryToken { space: Initial, offset: 1206, length: 333 }) client | 0.120 INFO Lost crypto frame space=in offset=1206 length=333 client | 0.120 DEBUG [Client 47025ea090491916d639dd959c906d] Lost: EcnEct0 client | 0.120 DEBUG [Client 47025ea090491916d639dd959c906d] output_path send_profile SendProfile { limit: 1252, pto: Some(Initial), probe: EnumSet(Initial), paced: false } client | 0.120 DEBUG Building Initial dcid Some(CID [8]: 7e8fdd569f16e480) scid Some(CID [0]: ) client | 0.120 DEBUG CRYPTO for in offset=1206, len=333 client | 0.120 DEBUG [Client 47025ea090491916d639dd959c906d] pn=2 type=Initial pri-path:7e8fdd569f16e480 0.0.0.0:34244->193.167.100.100:443 IpTos(Cs0, Ect0) len 373 client | TX -> Crypto { offset: 1206, len: 333 } client | 0.120 DEBUG [Client 47025ea090491916d639dd959c906d] pad Initial from 373 to PLPMTU 1252 client | 0.120 DEBUG packet_sent this=0x563fccdce970, pn=2, ps=1252 client | 0.120 DEBUG ECN probing: sent 3 probes client | 0.120 DEBUG [Client 47025ea090491916d639dd959c906d] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.120 DEBUG Building Initial dcid Some(CID [8]: 7e8fdd569f16e480) scid Some(CID [0]: ) client | 0.120 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.120 DEBUG [Client 47025ea090491916d639dd959c906d] delay duration 234.086351ms client | 0.120 DEBUG Setting timeout of 234.086351ms sim | Dropping packet 3 (1252 bytes) from 193.167.0.100 client | 0.355 DEBUG [LossRecovery] PTO timer fired for Initial client | 0.355 DEBUG [Client 47025ea090491916d639dd959c906d] Lost: Crypto(CryptoRecoveryToken { space: Initial, offset: 1206, length: 333 }) client | 0.355 INFO Lost crypto frame space=in offset=1206 length=333 client | 0.355 DEBUG [Client 47025ea090491916d639dd959c906d] Lost: EcnEct0 client | 0.355 DEBUG [Client 47025ea090491916d639dd959c906d] output_path send_profile SendProfile { limit: 1252, pto: Some(Initial), probe: EnumSet(Initial), paced: false } client | 0.355 DEBUG Building Initial dcid Some(CID [8]: 7e8fdd569f16e480) scid Some(CID [0]: ) client | 0.355 DEBUG CRYPTO for in offset=1206, len=333 client | 0.355 DEBUG [Client 47025ea090491916d639dd959c906d] pn=3 type=Initial pri-path:7e8fdd569f16e480 0.0.0.0:34244->193.167.100.100:443 IpTos(Cs0, Ect0) len 373 client | TX -> Crypto { offset: 1206, len: 333 } client | 0.355 DEBUG [Client 47025ea090491916d639dd959c906d] pad Initial from 373 to PLPMTU 1252 client | 0.355 DEBUG packet_sent this=0x563fccdce970, pn=3, ps=1252 client | 0.355 DEBUG ECN probing: sent 4 probes client | 0.355 DEBUG [Client 47025ea090491916d639dd959c906d] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.355 DEBUG Building Initial dcid Some(CID [8]: 7e8fdd569f16e480) scid Some(CID [0]: ) client | 0.355 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.355 DEBUG [Client 47025ea090491916d639dd959c906d] delay duration 468.239276ms client | 0.355 DEBUG Setting timeout of 468.239276ms sim | Dropping packet 4 (1252 bytes) from 193.167.0.100 client | 0.825 DEBUG [LossRecovery] PTO timer fired for Initial client | 0.825 DEBUG [Client 47025ea090491916d639dd959c906d] Lost: Crypto(CryptoRecoveryToken { space: Initial, offset: 1206, length: 333 }) client | 0.825 INFO Lost crypto frame space=in offset=1206 length=333 client | 0.825 DEBUG [Client 47025ea090491916d639dd959c906d] Lost: EcnEct0 client | 0.825 DEBUG [Client 47025ea090491916d639dd959c906d] output_path send_profile SendProfile { limit: 1252, pto: Some(Initial), probe: EnumSet(Initial), paced: false } client | 0.825 DEBUG Building Initial dcid Some(CID [8]: 7e8fdd569f16e480) scid Some(CID [0]: ) client | 0.825 DEBUG CRYPTO for in offset=1206, len=333 client | 0.825 DEBUG [Client 47025ea090491916d639dd959c906d] pn=4 type=Initial pri-path:7e8fdd569f16e480 0.0.0.0:34244->193.167.100.100:443 IpTos(Cs0, Ect0) len 373 client | TX -> Crypto { offset: 1206, len: 333 } client | 0.825 DEBUG [Client 47025ea090491916d639dd959c906d] pad Initial from 373 to PLPMTU 1252 client | 0.825 DEBUG packet_sent this=0x563fccdce970, pn=4, ps=1252 client | 0.825 DEBUG ECN probing: sent 5 probes client | 0.825 DEBUG [Client 47025ea090491916d639dd959c906d] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.825 DEBUG Building Initial dcid Some(CID [8]: 7e8fdd569f16e480) scid Some(CID [0]: ) client | 0.825 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.825 DEBUG [Client 47025ea090491916d639dd959c906d] delay duration 936.703514ms client | 0.825 DEBUG Setting timeout of 936.703514ms sim | Dropping packet 5 (1252 bytes) from 193.167.0.100 client | 1.763 DEBUG [LossRecovery] PTO timer fired for Initial client | 1.763 DEBUG [Client 47025ea090491916d639dd959c906d] Lost: Crypto(CryptoRecoveryToken { space: Initial, offset: 1206, length: 333 }) client | 1.763 INFO Lost crypto frame space=in offset=1206 length=333 client | 1.763 DEBUG [Client 47025ea090491916d639dd959c906d] Lost: EcnEct0 client | 1.763 DEBUG [Client 47025ea090491916d639dd959c906d] output_path send_profile SendProfile { limit: 1252, pto: Some(Initial), probe: EnumSet(Initial), paced: false } client | 1.763 DEBUG Building Initial dcid Some(CID [8]: 7e8fdd569f16e480) scid Some(CID [0]: ) client | 1.763 DEBUG CRYPTO for in offset=1206, len=333 client | 1.763 DEBUG [Client 47025ea090491916d639dd959c906d] pn=5 type=Initial pri-path:7e8fdd569f16e480 0.0.0.0:34244->193.167.100.100:443 IpTos(Cs0, Ect0) len 373 client | TX -> Crypto { offset: 1206, len: 333 } client | 1.763 DEBUG [Client 47025ea090491916d639dd959c906d] pad Initial from 373 to PLPMTU 1252 client | 1.763 DEBUG packet_sent this=0x563fccdce970, pn=5, ps=1252 client | 1.763 DEBUG ECN probing: sent 6 probes client | 1.763 DEBUG [Client 47025ea090491916d639dd959c906d] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 1.763 DEBUG Building Initial dcid Some(CID [8]: 7e8fdd569f16e480) scid Some(CID [0]: ) client | 1.763 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 1.763 DEBUG [Client 47025ea090491916d639dd959c906d] delay duration 1.873554255s client | 1.763 DEBUG Setting timeout of 1.873554255s sim | Dropping packet 6 (1252 bytes) from 193.167.0.100 client | 3.638 DEBUG [LossRecovery] PTO timer fired for Initial client | 3.638 DEBUG [Client 47025ea090491916d639dd959c906d] Lost: Crypto(CryptoRecoveryToken { space: Initial, offset: 1206, length: 333 }) client | 3.638 INFO Lost crypto frame space=in offset=1206 length=333 client | 3.638 DEBUG [Client 47025ea090491916d639dd959c906d] Lost: EcnEct0 client | 3.638 DEBUG [Client 47025ea090491916d639dd959c906d] output_path send_profile SendProfile { limit: 1252, pto: Some(Initial), probe: EnumSet(Initial), paced: false } client | 3.638 DEBUG Building Initial dcid Some(CID [8]: 7e8fdd569f16e480) scid Some(CID [0]: ) client | 3.638 DEBUG CRYPTO for in offset=1206, len=333 client | 3.638 DEBUG [Client 47025ea090491916d639dd959c906d] pn=6 type=Initial pri-path:7e8fdd569f16e480 0.0.0.0:34244->193.167.100.100:443 IpTos(Cs0, Ect0) len 373 client | TX -> Crypto { offset: 1206, len: 333 } client | 3.638 DEBUG [Client 47025ea090491916d639dd959c906d] pad Initial from 373 to PLPMTU 1252 client | 3.638 DEBUG packet_sent this=0x563fccdce970, pn=6, ps=1252 client | 3.638 DEBUG ECN probing: sent 7 probes client | 3.639 DEBUG [Client 47025ea090491916d639dd959c906d] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 3.639 DEBUG Building Initial dcid Some(CID [8]: 7e8fdd569f16e480) scid Some(CID [0]: ) client | 3.639 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 3.639 DEBUG [Client 47025ea090491916d639dd959c906d] delay duration 3.747400126s client | 3.639 DEBUG Setting timeout of 3.747400126s sim | Dropping packet 7 (1252 bytes) from 193.167.0.100 client | 7.387 DEBUG [LossRecovery] PTO timer fired for Initial client | 7.387 DEBUG [Client 47025ea090491916d639dd959c906d] Lost: Crypto(CryptoRecoveryToken { space: Initial, offset: 1206, length: 333 }) client | 7.387 INFO Lost crypto frame space=in offset=1206 length=333 client | 7.387 DEBUG [Client 47025ea090491916d639dd959c906d] Lost: EcnEct0 client | 7.387 DEBUG [Client 47025ea090491916d639dd959c906d] output_path send_profile SendProfile { limit: 1252, pto: Some(Initial), probe: EnumSet(Initial), paced: false } client | 7.387 DEBUG Building Initial dcid Some(CID [8]: 7e8fdd569f16e480) scid Some(CID [0]: ) client | 7.387 DEBUG CRYPTO for in offset=1206, len=333 client | 7.387 DEBUG [Client 47025ea090491916d639dd959c906d] pn=7 type=Initial pri-path:7e8fdd569f16e480 0.0.0.0:34244->193.167.100.100:443 IpTos(Cs0, Ect0) len 373 client | TX -> Crypto { offset: 1206, len: 333 } client | 7.387 DEBUG [Client 47025ea090491916d639dd959c906d] pad Initial from 373 to PLPMTU 1252 client | 7.387 DEBUG packet_sent this=0x563fccdce970, pn=7, ps=1252 client | 7.387 DEBUG ECN probing: sent 8 probes client | 7.387 DEBUG [Client 47025ea090491916d639dd959c906d] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.387 DEBUG Building Initial dcid Some(CID [8]: 7e8fdd569f16e480) scid Some(CID [0]: ) client | 7.387 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.387 DEBUG [Client 47025ea090491916d639dd959c906d] delay duration 7.494974339s client | 7.387 DEBUG Setting timeout of 7.494974339s client | 7.423 DEBUG [Client 47025ea090491916d639dd959c906d] pn=1 type=Initial pri-path:7e8fdd569f16e480 0.0.0.0:34244->193.167.100.100:443 IpTos(Cs0, NotEct) len 138 client | -> RX Ack { largest_acknowledged: 7, ack_delay: 343, first_ack_range: 0, ack_ranges: [AckRange { gap: 5, range: 0 }], ecn_count: None } client | -> RX Crypto { offset: 0, len: 90 } client | 7.423 DEBUG [Client 47025ea090491916d639dd959c906d] Rx ACK space=in, ranges=[7..=7, 0..=0] client | 7.423 DEBUG [LossRecovery] ACK for Initial - largest_acked=7 client | 7.423 DEBUG packet_lost this=0x563fccdce970, pn=1, ps=1252 client | 7.423 DEBUG packet_lost this=0x563fccdce970, pn=2, ps=1252 client | 7.423 DEBUG packet_lost this=0x563fccdce970, pn=3, ps=1252 client | 7.423 DEBUG packet_lost this=0x563fccdce970, pn=4, ps=1252 client | 7.423 DEBUG packet_lost this=0x563fccdce970, pn=5, ps=1252 client | 7.423 DEBUG packet_lost this=0x563fccdce970, pn=6, ps=1252 client | 7.423 DEBUG [Cubic [last_max_cwnd: 12520, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 1252/8764 ssthresh 8764] Cong event -> recovery; cwnd 8764, ssthresh 8764 client | 7.423 DEBUG [Cubic [last_max_cwnd: 12520, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 1252/8764 ssthresh 8764] state -> RecoveryStart client | 7.423 INFO [Cubic [last_max_cwnd: 12520, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 1252/8764 ssthresh 8764] persistent congestion client | 7.423 DEBUG [Cubic [last_max_cwnd: 12520, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 1252/2504 ssthresh 8764] state -> PersistentCongestion client | 7.423 DEBUG on_packets_lost this=0x563fccdce970, bytes_in_flight=1252, cwnd=2504, state=PersistentCongestion client | 7.423 DEBUG [Cubic [last_max_cwnd: 12520, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 0/2504 ssthresh 8764] slow start += 0 client | 7.423 DEBUG [Cubic [last_max_cwnd: 12520, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 0/2504 ssthresh 8764] on_packets_acked this=0x563fccdce970, limited=0, bytes_in_flight=0, cwnd=2504, state=PersistentCongestion, new_acked=0 client | 7.423 DEBUG Acked crypto frame space=in offset=1206 length=333 client | 7.423 DEBUG [Client 47025ea090491916d639dd959c906d] Lost: Crypto(CryptoRecoveryToken { space: Initial, offset: 1206, length: 333 }) client | 7.423 INFO Lost crypto frame space=in offset=1206 length=333 client | 7.423 DEBUG [Client 47025ea090491916d639dd959c906d] Lost: EcnEct0 client | 7.423 DEBUG [Client 47025ea090491916d639dd959c906d] Lost: Crypto(CryptoRecoveryToken { space: Initial, offset: 1206, length: 333 }) client | 7.423 INFO Lost crypto frame space=in offset=1206 length=333 client | 7.423 DEBUG [Client 47025ea090491916d639dd959c906d] Lost: EcnEct0 client | 7.423 DEBUG [Client 47025ea090491916d639dd959c906d] Lost: Crypto(CryptoRecoveryToken { space: Initial, offset: 1206, length: 333 }) client | 7.423 INFO Lost crypto frame space=in offset=1206 length=333 client | 7.423 DEBUG [Client 47025ea090491916d639dd959c906d] Lost: EcnEct0 client | 7.423 DEBUG [Client 47025ea090491916d639dd959c906d] Lost: Crypto(CryptoRecoveryToken { space: Initial, offset: 1206, length: 333 }) client | 7.423 INFO Lost crypto frame space=in offset=1206 length=333 client | 7.423 DEBUG [Client 47025ea090491916d639dd959c906d] Lost: EcnEct0 client | 7.423 DEBUG [Client 47025ea090491916d639dd959c906d] Lost: Crypto(CryptoRecoveryToken { space: Initial, offset: 1206, length: 333 }) client | 7.423 INFO Lost crypto frame space=in offset=1206 length=333 client | 7.423 DEBUG [Client 47025ea090491916d639dd959c906d] Lost: EcnEct0 client | 7.423 DEBUG [Client 47025ea090491916d639dd959c906d] Lost: Crypto(CryptoRecoveryToken { space: Initial, offset: 1206, length: 333 }) client | 7.423 INFO Lost crypto frame space=in offset=1206 length=333 client | 7.423 DEBUG [Client 47025ea090491916d639dd959c906d] Lost: EcnEct0 client | 7.423 DEBUG Read Ok(90) bytes client | 7.423 DEBUG Write secret available for Handshake: SymKey [48]: 828515089dab6b462ae6a54dad66ef0c6abcf56f0394ab2211f70de41aa7c28ba0841e7d5b7d21aeff821b6b70fcade1 client | 7.423 DEBUG Read secret available for Handshake: SymKey [48]: 1bd9950b92f6b7f8cfec3e30e29bea83e48a68ae150bde7774bdc0821da5be5d4112bf007b7145eefbf7694781d28c5d client | 7.423 DEBUG [Agent 0x563fccdbb270] state -> InProgress client | 7.423 DEBUG Making Write Handshake CryptoDxState, v=Version1 cipher=4866 client | 7.423 DEBUG Making Read Handshake CryptoDxState, v=Version1 cipher=4866 client | 7.423 DEBUG [Crypto] Handshake keys installed client | 7.423 DEBUG [Recvd-in] Set ACK timer to Instant { tv_sec: 625, tv_nsec: 179481989 } client | 7.423 DEBUG [Client 47025ea090491916d639dd959c906d] State change from WaitVersion -> Handshaking client | 7.423 DEBUG [Client 47025ea090491916d639dd959c906d] pn=2 type=Handshake pri-path:7e8fdd569f16e480 0.0.0.0:34244->193.167.100.100:443 IpTos(Cs0, NotEct) len 1062 client | -> RX Crypto { offset: 0, len: 1023 } client | 7.423 DEBUG Read Ok(1023) bytes client | 7.423 DEBUG [Agent 0x563fccdbb270] state -> InProgress client | 7.423 DEBUG [Recvd-hs] Set ACK timer to Instant { tv_sec: 625, tv_nsec: 179481989 } client | 7.423 DEBUG [Client 47025ea090491916d639dd959c906d] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.423 DEBUG Building Initial dcid Some(CID [8]: 7e8fdd569f16e480) scid Some(CID [0]: ) client | 7.423 DEBUG [Client 47025ea090491916d639dd959c906d] pn=8 type=Initial pri-path:7e8fdd569f16e480 0.0.0.0:34244->193.167.100.100:443 IpTos(Cs0, Ect0) len 41 client | TX -> Ack { largest_acknowledged: 1, ack_delay: 107, first_ack_range: 1, ack_ranges: [], ecn_count: None } client | 7.424 DEBUG Building Handshake dcid Some(CID [8]: 7e8fdd569f16e480) scid Some(CID [0]: ) client | 7.424 DEBUG [Client 47025ea090491916d639dd959c906d] pn=0 type=Handshake pri-path:7e8fdd569f16e480 0.0.0.0:34244->193.167.100.100:443 IpTos(Cs0, Ect0) len 81 client | TX -> Ack { largest_acknowledged: 2, ack_delay: 107, first_ack_range: 0, ack_ranges: [], ecn_count: None } client | 7.424 DEBUG [Client 47025ea090491916d639dd959c906d] Drop packet number space in client | 7.424 DEBUG [LossRecovery] Reset loss recovery state for Initial client | 7.424 WARN [LossRecovery] ignoring in-8 from dropped space client | 7.424 DEBUG ECN probing: sent 9 probes client | 7.424 DEBUG [Client 47025ea090491916d639dd959c906d] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.424 DEBUG Building Handshake dcid Some(CID [8]: 7e8fdd569f16e480) scid Some(CID [0]: ) client | 7.424 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.424 DEBUG [Client 47025ea090491916d639dd959c906d] delay duration 100.141856ms client | 7.424 DEBUG Setting timeout of 100.141856ms client | 7.424 DEBUG [Client 47025ea090491916d639dd959c906d] pn=3 type=Handshake pri-path:7e8fdd569f16e480 0.0.0.0:34244->193.167.100.100:443 IpTos(Cs0, NotEct) len 1200 client | -> RX Crypto { offset: 1023, len: 1160 } client | 7.424 DEBUG Read Ok(1160) bytes client | 7.424 DEBUG [Agent 0x563fccdbb270] state -> InProgress client | 7.424 DEBUG [Recvd-hs] Set ACK timer to Instant { tv_sec: 625, tv_nsec: 180503983 } client | 7.424 DEBUG [Client 47025ea090491916d639dd959c906d] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.424 DEBUG Building Handshake dcid Some(CID [8]: 7e8fdd569f16e480) scid Some(CID [0]: ) client | 7.424 DEBUG [Client 47025ea090491916d639dd959c906d] pn=1 type=Handshake pri-path:7e8fdd569f16e480 0.0.0.0:34244->193.167.100.100:443 IpTos(Cs0, Ect0) len 39 client | TX -> Ack { largest_acknowledged: 3, ack_delay: 3, first_ack_range: 1, ack_ranges: [], ecn_count: None } client | 7.424 DEBUG ECN probing: sent 10 probes client | 7.424 DEBUG ECN probing concluded with 10 probes sent client | 7.424 DEBUG [Client 47025ea090491916d639dd959c906d] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.424 DEBUG Building Handshake dcid Some(CID [8]: 7e8fdd569f16e480) scid Some(CID [0]: ) client | 7.424 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.424 DEBUG [Client 47025ea090491916d639dd959c906d] delay duration 100.021077ms client | 7.424 DEBUG Setting timeout of 100.021077ms client | 7.424 DEBUG StateChange(Handshaking) client | 7.424 WARN Cannot create stream ConnectionState client | 7.424 DEBUG stream BiDi creatable client | 7.424 WARN Cannot create stream ConnectionState client | 7.424 DEBUG stream UniDi creatable client | 7.424 DEBUG [Client 47025ea090491916d639dd959c906d] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.424 DEBUG Building Handshake dcid Some(CID [8]: 7e8fdd569f16e480) scid Some(CID [0]: ) client | 7.424 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.424 DEBUG [Client 47025ea090491916d639dd959c906d] delay duration 99.986402ms client | 7.424 DEBUG Setting timeout of 99.986402ms client | 7.425 DEBUG [Client 47025ea090491916d639dd959c906d] pn=4 type=Handshake pri-path:7e8fdd569f16e480 0.0.0.0:34244->193.167.100.100:443 IpTos(Cs0, NotEct) len 1200 client | -> RX Crypto { offset: 2183, len: 1160 } client | 7.425 DEBUG Read Ok(1160) bytes client | 7.425 DEBUG [Agent 0x563fccdbb270] state -> InProgress client | 7.425 DEBUG [Recvd-hs] Set ACK timer to Instant { tv_sec: 625, tv_nsec: 181387473 } client | 7.425 DEBUG [Client 47025ea090491916d639dd959c906d] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.425 DEBUG Building Handshake dcid Some(CID [8]: 7e8fdd569f16e480) scid Some(CID [0]: ) client | 7.425 DEBUG [Client 47025ea090491916d639dd959c906d] pn=2 type=Handshake pri-path:7e8fdd569f16e480 0.0.0.0:34244->193.167.100.100:443 IpTos(Cs0, NotEct) len 39 client | TX -> Ack { largest_acknowledged: 4, ack_delay: 4, first_ack_range: 2, ack_ranges: [], ecn_count: None } client | 7.425 DEBUG [Client 47025ea090491916d639dd959c906d] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.425 DEBUG Building Handshake dcid Some(CID [8]: 7e8fdd569f16e480) scid Some(CID [0]: ) client | 7.425 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.425 DEBUG [Client 47025ea090491916d639dd959c906d] delay duration 99.14318ms client | 7.425 DEBUG Setting timeout of 99.14318ms client | 7.425 DEBUG stream BiDi creatable client | 7.425 WARN Cannot create stream ConnectionState client | 7.425 DEBUG stream UniDi creatable client | 7.425 DEBUG [Client 47025ea090491916d639dd959c906d] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.425 DEBUG Building Handshake dcid Some(CID [8]: 7e8fdd569f16e480) scid Some(CID [0]: ) client | 7.425 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.425 DEBUG [Client 47025ea090491916d639dd959c906d] delay duration 99.115969ms client | 7.425 DEBUG Setting timeout of 99.115969ms client | 7.426 DEBUG [Client 47025ea090491916d639dd959c906d] pn=5 type=Handshake pri-path:7e8fdd569f16e480 0.0.0.0:34244->193.167.100.100:443 IpTos(Cs0, NotEct) len 1200 client | -> RX Crypto { offset: 3343, len: 1160 } client | 7.426 DEBUG Read Ok(1160) bytes client | 7.426 DEBUG [Agent 0x563fccdbb270] state -> InProgress client | 7.426 DEBUG [Recvd-hs] Set ACK timer to Instant { tv_sec: 625, tv_nsec: 182380486 } client | 7.426 DEBUG [Client 47025ea090491916d639dd959c906d] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.426 DEBUG Building Handshake dcid Some(CID [8]: 7e8fdd569f16e480) scid Some(CID [0]: ) client | 7.426 DEBUG [Client 47025ea090491916d639dd959c906d] pn=3 type=Handshake pri-path:7e8fdd569f16e480 0.0.0.0:34244->193.167.100.100:443 IpTos(Cs0, NotEct) len 39 client | TX -> Ack { largest_acknowledged: 5, ack_delay: 4, first_ack_range: 3, ack_ranges: [], ecn_count: None } client | 7.426 DEBUG [Client 47025ea090491916d639dd959c906d] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.426 DEBUG Building Handshake dcid Some(CID [8]: 7e8fdd569f16e480) scid Some(CID [0]: ) client | 7.426 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.426 DEBUG [Client 47025ea090491916d639dd959c906d] delay duration 98.138616ms client | 7.426 DEBUG Setting timeout of 98.138616ms client | 7.426 DEBUG stream BiDi creatable client | 7.426 WARN Cannot create stream ConnectionState client | 7.426 DEBUG stream UniDi creatable client | 7.426 DEBUG [Client 47025ea090491916d639dd959c906d] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.426 DEBUG Building Handshake dcid Some(CID [8]: 7e8fdd569f16e480) scid Some(CID [0]: ) client | 7.426 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.426 DEBUG [Client 47025ea090491916d639dd959c906d] delay duration 98.107447ms client | 7.426 DEBUG Setting timeout of 98.107447ms client | 7.426 DEBUG [Client 47025ea090491916d639dd959c906d] pn=6 type=Handshake pri-path:7e8fdd569f16e480 0.0.0.0:34244->193.167.100.100:443 IpTos(Cs0, NotEct) len 1200 client | -> RX Crypto { offset: 4503, len: 1160 } client | 7.427 DEBUG Read Ok(1160) bytes client | 7.427 DEBUG [Agent 0x563fccdbb270] state -> InProgress client | 7.427 DEBUG [Recvd-hs] Set ACK timer to Instant { tv_sec: 625, tv_nsec: 183349309 } client | 7.427 DEBUG [Client 47025ea090491916d639dd959c906d] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.427 DEBUG Building Handshake dcid Some(CID [8]: 7e8fdd569f16e480) scid Some(CID [0]: ) client | 7.427 DEBUG [Client 47025ea090491916d639dd959c906d] pn=4 type=Handshake pri-path:7e8fdd569f16e480 0.0.0.0:34244->193.167.100.100:443 IpTos(Cs0, NotEct) len 39 client | TX -> Ack { largest_acknowledged: 6, ack_delay: 9, first_ack_range: 4, ack_ranges: [], ecn_count: None } client | 7.427 DEBUG [Client 47025ea090491916d639dd959c906d] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.427 DEBUG Building Handshake dcid Some(CID [8]: 7e8fdd569f16e480) scid Some(CID [0]: ) client | 7.427 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.427 DEBUG [Client 47025ea090491916d639dd959c906d] delay duration 97.135328ms client | 7.427 DEBUG Setting timeout of 97.135328ms client | 7.427 DEBUG stream BiDi creatable client | 7.427 WARN Cannot create stream ConnectionState client | 7.427 DEBUG stream UniDi creatable client | 7.427 DEBUG [Client 47025ea090491916d639dd959c906d] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.427 DEBUG Building Handshake dcid Some(CID [8]: 7e8fdd569f16e480) scid Some(CID [0]: ) client | 7.427 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.427 DEBUG [Client 47025ea090491916d639dd959c906d] delay duration 97.105903ms client | 7.427 DEBUG Setting timeout of 97.105903ms client | 7.427 DEBUG [Client 47025ea090491916d639dd959c906d] pn=7 type=Handshake pri-path:7e8fdd569f16e480 0.0.0.0:34244->193.167.100.100:443 IpTos(Cs0, NotEct) len 1200 client | -> RX Crypto { offset: 5663, len: 1160 } client | 7.427 DEBUG Read Ok(1160) bytes client | 7.427 DEBUG [Agent 0x563fccdbb270] state -> InProgress client | 7.427 DEBUG [Recvd-hs] Set ACK timer to Instant { tv_sec: 625, tv_nsec: 184307490 } client | 7.427 DEBUG [Client 47025ea090491916d639dd959c906d] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.427 DEBUG Building Handshake dcid Some(CID [8]: 7e8fdd569f16e480) scid Some(CID [0]: ) client | 7.427 DEBUG [Client 47025ea090491916d639dd959c906d] pn=5 type=Handshake pri-path:7e8fdd569f16e480 0.0.0.0:34244->193.167.100.100:443 IpTos(Cs0, NotEct) len 39 client | TX -> Ack { largest_acknowledged: 7, ack_delay: 3, first_ack_range: 5, ack_ranges: [], ecn_count: None } client | 7.428 DEBUG [Client 47025ea090491916d639dd959c906d] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.428 DEBUG Building Handshake dcid Some(CID [8]: 7e8fdd569f16e480) scid Some(CID [0]: ) client | 7.428 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.428 DEBUG [Client 47025ea090491916d639dd959c906d] delay duration 96.187106ms client | 7.428 DEBUG Setting timeout of 96.187106ms client | 7.428 DEBUG stream BiDi creatable client | 7.428 WARN Cannot create stream ConnectionState client | 7.428 DEBUG stream UniDi creatable client | 7.428 DEBUG [Client 47025ea090491916d639dd959c906d] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.428 DEBUG Building Handshake dcid Some(CID [8]: 7e8fdd569f16e480) scid Some(CID [0]: ) client | 7.428 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.428 DEBUG [Client 47025ea090491916d639dd959c906d] delay duration 96.154555ms client | 7.428 DEBUG Setting timeout of 96.154555ms client | 7.428 DEBUG [Client 47025ea090491916d639dd959c906d] pn=8 type=Handshake pri-path:7e8fdd569f16e480 0.0.0.0:34244->193.167.100.100:443 IpTos(Cs0, NotEct) len 270 client | -> RX Crypto { offset: 6823, len: 230 } client | 7.428 DEBUG Read Ok(230) bytes client | 7.428 DEBUG [Agent 0x563fccdbb270] state -> InProgress client | 7.428 DEBUG [Recvd-hs] Set ACK timer to Instant { tv_sec: 625, tv_nsec: 184521658 } client | 7.428 DEBUG [Client 47025ea090491916d639dd959c906d] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.428 DEBUG Building Handshake dcid Some(CID [8]: 7e8fdd569f16e480) scid Some(CID [0]: ) client | 7.428 DEBUG [Client 47025ea090491916d639dd959c906d] pn=6 type=Handshake pri-path:7e8fdd569f16e480 0.0.0.0:34244->193.167.100.100:443 IpTos(Cs0, NotEct) len 39 client | TX -> Ack { largest_acknowledged: 8, ack_delay: 4, first_ack_range: 6, ack_ranges: [], ecn_count: None } client | 7.428 DEBUG [Client 47025ea090491916d639dd959c906d] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.428 DEBUG Building Handshake dcid Some(CID [8]: 7e8fdd569f16e480) scid Some(CID [0]: ) client | 7.428 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.428 DEBUG [Client 47025ea090491916d639dd959c906d] delay duration 96.004768ms client | 7.428 DEBUG Setting timeout of 96.004768ms client | 7.428 DEBUG stream BiDi creatable client | 7.428 WARN Cannot create stream ConnectionState client | 7.428 DEBUG stream UniDi creatable client | 7.428 DEBUG [Client 47025ea090491916d639dd959c906d] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.428 DEBUG Building Handshake dcid Some(CID [8]: 7e8fdd569f16e480) scid Some(CID [0]: ) client | 7.428 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.428 DEBUG [Client 47025ea090491916d639dd959c906d] delay duration 95.96865ms client | 7.428 DEBUG Setting timeout of 95.96865ms client | 7.455 DEBUG [Client 47025ea090491916d639dd959c906d] pn=9 type=Handshake pri-path:7e8fdd569f16e480 0.0.0.0:34244->193.167.100.100:443 IpTos(Cs0, NotEct) len 243 client | -> RX Crypto { offset: 7053, len: 203 } client | 7.455 DEBUG Read Ok(203) bytes client | 7.455 DEBUG [Agent 0x563fccdbb270] state -> InProgress client | 7.455 DEBUG [Recvd-hs] Set ACK timer to Instant { tv_sec: 625, tv_nsec: 211413065 } client | 7.455 DEBUG [Client 47025ea090491916d639dd959c906d] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.455 DEBUG Building Handshake dcid Some(CID [8]: 7e8fdd569f16e480) scid Some(CID [0]: ) client | 7.455 DEBUG [Client 47025ea090491916d639dd959c906d] pn=7 type=Handshake pri-path:7e8fdd569f16e480 0.0.0.0:34244->193.167.100.100:443 IpTos(Cs0, NotEct) len 39 client | TX -> Ack { largest_acknowledged: 9, ack_delay: 6, first_ack_range: 7, ack_ranges: [], ecn_count: None } client | 7.455 DEBUG [Client 47025ea090491916d639dd959c906d] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.455 DEBUG Building Handshake dcid Some(CID [8]: 7e8fdd569f16e480) scid Some(CID [0]: ) client | 7.455 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.455 DEBUG [Client 47025ea090491916d639dd959c906d] delay duration 69.077474ms client | 7.455 DEBUG Setting timeout of 69.077474ms client | 7.455 DEBUG stream BiDi creatable client | 7.455 WARN Cannot create stream ConnectionState client | 7.455 DEBUG stream UniDi creatable client | 7.455 DEBUG [Client 47025ea090491916d639dd959c906d] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.455 DEBUG Building Handshake dcid Some(CID [8]: 7e8fdd569f16e480) scid Some(CID [0]: ) client | 7.455 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.455 DEBUG [Client 47025ea090491916d639dd959c906d] delay duration 69.03802ms client | 7.455 DEBUG Setting timeout of 69.03802ms client | 7.456 DEBUG [Client 47025ea090491916d639dd959c906d] pn=10 type=Handshake pri-path:7e8fdd569f16e480 0.0.0.0:34244->193.167.100.100:443 IpTos(Cs0, NotEct) len 1200 client | -> RX Crypto { offset: 7256, len: 1160 } client | 7.456 DEBUG Read Ok(1160) bytes client | 7.456 DEBUG [Agent 0x563fccdbb270] state -> InProgress client | 7.456 DEBUG [Recvd-hs] Set ACK timer to Instant { tv_sec: 625, tv_nsec: 212863154 } client | 7.456 DEBUG [Client 47025ea090491916d639dd959c906d] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.456 DEBUG Building Handshake dcid Some(CID [8]: 7e8fdd569f16e480) scid Some(CID [0]: ) client | 7.456 DEBUG [Client 47025ea090491916d639dd959c906d] pn=8 type=Handshake pri-path:7e8fdd569f16e480 0.0.0.0:34244->193.167.100.100:443 IpTos(Cs0, NotEct) len 39 client | TX -> Ack { largest_acknowledged: 10, ack_delay: 4, first_ack_range: 8, ack_ranges: [], ecn_count: None } client | 7.456 DEBUG [Client 47025ea090491916d639dd959c906d] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.456 DEBUG Building Handshake dcid Some(CID [8]: 7e8fdd569f16e480) scid Some(CID [0]: ) client | 7.456 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.456 DEBUG [Client 47025ea090491916d639dd959c906d] delay duration 67.670836ms client | 7.456 DEBUG Setting timeout of 67.670836ms client | 7.456 DEBUG stream BiDi creatable client | 7.456 WARN Cannot create stream ConnectionState client | 7.456 DEBUG stream UniDi creatable client | 7.456 DEBUG [Client 47025ea090491916d639dd959c906d] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.456 DEBUG Building Handshake dcid Some(CID [8]: 7e8fdd569f16e480) scid Some(CID [0]: ) client | 7.456 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.456 DEBUG [Client 47025ea090491916d639dd959c906d] delay duration 67.641921ms client | 7.456 DEBUG Setting timeout of 67.641921ms client | 7.457 DEBUG [Client 47025ea090491916d639dd959c906d] pn=11 type=Handshake pri-path:7e8fdd569f16e480 0.0.0.0:34244->193.167.100.100:443 IpTos(Cs0, NotEct) len 1200 client | -> RX Crypto { offset: 8416, len: 1160 } client | 7.457 DEBUG Read Ok(1160) bytes client | 7.457 DEBUG [Agent 0x563fccdbb270] state -> InProgress client | 7.457 DEBUG [Recvd-hs] Set ACK timer to Instant { tv_sec: 625, tv_nsec: 213880041 } client | 7.457 DEBUG [Client 47025ea090491916d639dd959c906d] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.457 DEBUG Building Handshake dcid Some(CID [8]: 7e8fdd569f16e480) scid Some(CID [0]: ) client | 7.457 DEBUG [Client 47025ea090491916d639dd959c906d] pn=9 type=Handshake pri-path:7e8fdd569f16e480 0.0.0.0:34244->193.167.100.100:443 IpTos(Cs0, NotEct) len 39 client | TX -> Ack { largest_acknowledged: 11, ack_delay: 3, first_ack_range: 9, ack_ranges: [], ecn_count: None } client | 7.457 DEBUG [Client 47025ea090491916d639dd959c906d] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.457 DEBUG Building Handshake dcid Some(CID [8]: 7e8fdd569f16e480) scid Some(CID [0]: ) client | 7.457 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.457 DEBUG [Client 47025ea090491916d639dd959c906d] delay duration 66.661924ms client | 7.457 DEBUG Setting timeout of 66.661924ms client | 7.457 DEBUG stream BiDi creatable client | 7.457 WARN Cannot create stream ConnectionState client | 7.457 DEBUG stream UniDi creatable client | 7.457 DEBUG [Client 47025ea090491916d639dd959c906d] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.457 DEBUG Building Handshake dcid Some(CID [8]: 7e8fdd569f16e480) scid Some(CID [0]: ) client | 7.457 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.457 DEBUG [Client 47025ea090491916d639dd959c906d] delay duration 66.629993ms client | 7.457 DEBUG Setting timeout of 66.629993ms client | 7.457 DEBUG [Client 47025ea090491916d639dd959c906d] pn=12 type=Handshake pri-path:7e8fdd569f16e480 0.0.0.0:34244->193.167.100.100:443 IpTos(Cs0, NotEct) len 449 client | -> RX Crypto { offset: 9576, len: 409 } client | 7.458 DEBUG Read Ok(409) bytes client | 7.458 DEBUG [Agent 0x563fccdbb270] state -> AuthenticationPending client | 7.458 DEBUG [Recvd-hs] Set ACK timer to Instant { tv_sec: 625, tv_nsec: 214351565 } client | 7.458 DEBUG saving datagram of 112 bytes client | 7.458 DEBUG [Client 47025ea090491916d639dd959c906d] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.458 DEBUG Building Handshake dcid Some(CID [8]: 7e8fdd569f16e480) scid Some(CID [0]: ) client | 7.458 DEBUG [Client 47025ea090491916d639dd959c906d] pn=10 type=Handshake pri-path:7e8fdd569f16e480 0.0.0.0:34244->193.167.100.100:443 IpTos(Cs0, NotEct) len 40 client | TX -> Ack { largest_acknowledged: 12, ack_delay: 94, first_ack_range: 10, ack_ranges: [], ecn_count: None } client | 7.458 DEBUG [Client 47025ea090491916d639dd959c906d] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.458 DEBUG Building Handshake dcid Some(CID [8]: 7e8fdd569f16e480) scid Some(CID [0]: ) client | 7.458 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.458 DEBUG [Client 47025ea090491916d639dd959c906d] delay duration 65.455491ms client | 7.458 DEBUG Setting timeout of 65.455491ms client | 7.458 DEBUG [Client 47025ea090491916d639dd959c906d] Authenticated Ok client | 7.458 DEBUG Write secret available for ApplicationData: SymKey [48]: 7e237f1d360b4dd66c93e07499c640d2baf3c9d1cc0dfa79c10ab3777b53c0ef76581d885521113f14160c7efd4e6dae client | 7.458 DEBUG Read secret available for ApplicationData: SymKey [48]: 6cf130d3ad8e00ecb322f67e853887074dfce3d0fb14e11139516d32ac479350e336beb6633fb9f99c975d7b4d8a0366 client | 7.459 DEBUG [Agent 0x563fccdbb270] SSL_AuthCertificateComplete: Ok(()) client | 7.459 DEBUG [Agent 0x563fccdbb270] 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 | 7.459 DEBUG [Client 47025ea090491916d639dd959c906d] TLS connection complete client | 7.459 DEBUG Making Write ApplicationData CryptoDxState, v=Version1 cipher=4866 client | 7.459 DEBUG [Crypto] Application write key installed client | 7.459 DEBUG Making Read ApplicationData CryptoDxState, v=Version1 cipher=4866 client | 7.459 DEBUG [Crypto] application read keys installed client | 7.459 DEBUG [Client 47025ea090491916d639dd959c906d] State change from Handshaking -> Connected client | 7.459 INFO [Client 47025ea090491916d639dd959c906d] Connection established client | 7.459 DEBUG [Client 47025ea090491916d639dd959c906d] process saved for epoch ApplicationData client | 7.459 DEBUG [Client 47025ea090491916d639dd959c906d] pn=13 type=Short pri-path:7e8fdd569f16e480 0.0.0.0:34244->193.167.100.100:443 IpTos(Cs0, NotEct) len 112 client | -> RX Crypto { offset: 0, len: 89 } client | 7.459 DEBUG Read Ok(89) bytes client | 7.459 DEBUG [0x563fccdbb270] Got resumption token [5817]: 02000633fe77471f..76d02a321ff9127e client | 7.459 DEBUG [Agent 0x563fccdbb270] 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 | 7.459 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 625, tv_nsec: 214351565 } client | 7.459 DEBUG stream BiDi creatable client | 7.459 INFO Created stream 0 for https://server4/djzbynxffp client | 7.459 INFO Saving https://server4/djzbynxffp to "/downloads/djzbynxffp" client | 7.459 DEBUG stream UniDi creatable client | 7.459 DEBUG StateChange(Connected) client | 7.459 DEBUG stream 0 writable client | 7.459 DEBUG [Client 47025ea090491916d639dd959c906d] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.459 DEBUG Building Handshake dcid Some(CID [8]: 7e8fdd569f16e480) scid Some(CID [0]: ) client | 7.459 DEBUG CRYPTO for hs offset=0, len=52 client | 7.459 DEBUG [Client 47025ea090491916d639dd959c906d] pn=11 type=Handshake pri-path:7e8fdd569f16e480 0.0.0.0:34244->193.167.100.100:443 IpTos(Cs0, NotEct) len 89 client | TX -> Crypto { offset: 0, len: 52 } client | 7.459 DEBUG packet_sent this=0x563fccdce970, pn=11, ps=89 client | 7.459 DEBUG Building Short dcid Some(CID [8]: 7e8fdd569f16e480) client | 7.459 DEBUG [Client 47025ea090491916d639dd959c906d] pn=0 type=Short pri-path:7e8fdd569f16e480 0.0.0.0:34244->193.167.100.100:443 IpTos(Cs0, NotEct) len 141 client | TX -> Ack { largest_acknowledged: 13, ack_delay: 182, first_ack_range: 0, ack_ranges: [], ecn_count: None } client | TX -> Stream { stream_id: 0, offset: 0, len: 17, fin: true } client | 7.459 DEBUG packet_sent this=0x563fccdce970, pn=0, ps=52 client | 7.459 DEBUG [Client 47025ea090491916d639dd959c906d] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.459 DEBUG Building Handshake dcid Some(CID [8]: 7e8fdd569f16e480) scid Some(CID [0]: ) client | 7.459 DEBUG Building Short dcid Some(CID [8]: 7e8fdd569f16e480) client | 7.459 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.459 DEBUG [Client 47025ea090491916d639dd959c906d] delay duration 100.174696ms client | 7.459 DEBUG Setting timeout of 100.174696ms client | 7.491 DEBUG [Client 47025ea090491916d639dd959c906d] pn=14 type=Short pri-path:7e8fdd569f16e480 0.0.0.0:34244->193.167.100.100:443 IpTos(Cs0, NotEct) len 216 client | -> RX HandshakeDone client | -> RX NewConnectionId { sequence_number: 1, retire_prior: 0, connection_id: [152, 8, 122, 100, 76, 35, 71, 246], stateless_reset_token: [132, 244, 99, 252, 246, 104, 54, 114, 90, 101, 216, 177, 113, 185, 166, 194] } client | -> RX NewConnectionId { sequence_number: 2, retire_prior: 0, connection_id: [233, 173, 247, 157, 154, 171, 89, 47], stateless_reset_token: [177, 131, 122, 222, 220, 3, 104, 156, 215, 235, 213, 177, 219, 201, 113, 87] } client | -> RX NewConnectionId { sequence_number: 3, retire_prior: 0, connection_id: [72, 0, 93, 129, 177, 156, 63, 59], stateless_reset_token: [2, 42, 233, 133, 171, 175, 153, 165, 21, 191, 154, 240, 26, 0, 207, 149] } client | -> RX NewConnectionId { sequence_number: 4, retire_prior: 0, connection_id: [140, 138, 208, 187, 16, 42, 226, 116], stateless_reset_token: [7, 165, 68, 91, 75, 53, 233, 216, 226, 222, 84, 65, 51, 196, 188, 135] } client | -> RX NewConnectionId { sequence_number: 5, retire_prior: 0, connection_id: [141, 62, 247, 126, 216, 233, 158, 135], stateless_reset_token: [79, 129, 30, 216, 17, 184, 67, 247, 8, 178, 57, 133, 225, 189, 156, 129] } client | -> RX NewConnectionId { sequence_number: 6, retire_prior: 0, connection_id: [15, 83, 125, 38, 167, 20, 167, 158], stateless_reset_token: [89, 176, 249, 207, 252, 117, 200, 157, 139, 135, 80, 106, 177, 63, 53, 74] } client | -> RX NewConnectionId { sequence_number: 7, retire_prior: 0, connection_id: [192, 59, 58, 119, 49, 17, 44, 5], stateless_reset_token: [250, 198, 216, 98, 141, 210, 202, 165, 142, 211, 106, 248, 155, 192, 232, 7] } client | 7.491 DEBUG [Client 47025ea090491916d639dd959c906d] State change from Connected -> Confirmed client | 7.491 DEBUG PMTUD started with probe size 1380 client | 7.491 DEBUG [Client 47025ea090491916d639dd959c906d] Drop packet number space hs client | 7.491 DEBUG [LossRecovery] Reset loss recovery state for Handshake client | 7.491 DEBUG [Client 47025ea090491916d639dd959c906d] No preferred address to migrate to client | 7.491 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 625, tv_nsec: 267511745 } client | 7.491 DEBUG [Client 47025ea090491916d639dd959c906d] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.491 DEBUG Building Short dcid Some(CID [8]: 7e8fdd569f16e480) client | 7.491 DEBUG Sending PMTUD probe of size 1380, count 1 client | 7.491 DEBUG [Client 47025ea090491916d639dd959c906d] pn=1 type=Short pri-path:7e8fdd569f16e480 0.0.0.0:34244->193.167.100.100:443 IpTos(Cs0, NotEct) len 1352 client | TX -> Ping client | TX -> Padding { len: 1325 } client | 7.491 DEBUG packet_sent this=0x563fccdce970, pn=1, ps=1352 client | 7.491 DEBUG [Client 47025ea090491916d639dd959c906d] output_path send_profile SendProfile { limit: 1100, pto: None, probe: EnumSet(), paced: false } client | 7.491 DEBUG Building Short dcid Some(CID [8]: 7e8fdd569f16e480) client | 7.491 DEBUG TX blocked, profile=SendProfile { limit: 1100, pto: None, probe: EnumSet(), paced: false } client | 7.491 DEBUG [Client 47025ea090491916d639dd959c906d] delay duration 19.762655ms client | 7.491 DEBUG Setting timeout of 19.762655ms client | 7.491 WARN Unhandled event StateChange(Confirmed) client | 7.491 DEBUG [Client 47025ea090491916d639dd959c906d] output_path send_profile SendProfile { limit: 1100, pto: None, probe: EnumSet(), paced: false } client | 7.491 DEBUG Building Short dcid Some(CID [8]: 7e8fdd569f16e480) client | 7.491 DEBUG TX blocked, profile=SendProfile { limit: 1100, pto: None, probe: EnumSet(), paced: false } client | 7.491 DEBUG [Client 47025ea090491916d639dd959c906d] delay duration 19.729843ms client | 7.491 DEBUG Setting timeout of 19.729843ms client | 7.494 DEBUG [Client 47025ea090491916d639dd959c906d] pn=15 type=Short pri-path:7e8fdd569f16e480 0.0.0.0:34244->193.167.100.100:443 IpTos(Cs0, NotEct) len 25 client | -> RX Ack { largest_acknowledged: 0, ack_delay: 526, first_ack_range: 0, ack_ranges: [], ecn_count: None } client | 7.494 DEBUG [Client 47025ea090491916d639dd959c906d] Rx ACK space=ap, ranges=[0..=0] client | 7.494 DEBUG [LossRecovery] ACK for ApplicationData - largest_acked=0 client | 7.494 DEBUG [Cubic [last_max_cwnd: 12520, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 1352/2556 ssthresh 8764] slow start += 52 client | 7.494 DEBUG [Cubic [last_max_cwnd: 12520, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 1352/2556 ssthresh 8764] on_packets_acked this=0x563fccdce970, limited=0, bytes_in_flight=1352, cwnd=2556, state=SlowStart, new_acked=52 client | 7.494 DEBUG [Client 47025ea090491916d639dd959c906d] output_path send_profile SendProfile { limit: 1204, pto: None, probe: EnumSet(), paced: false } client | 7.494 DEBUG Building Short dcid Some(CID [8]: 7e8fdd569f16e480) client | 7.494 DEBUG TX blocked, profile=SendProfile { limit: 1204, pto: None, probe: EnumSet(), paced: false } client | 7.494 DEBUG [Client 47025ea090491916d639dd959c906d] delay duration 16.775272ms client | 7.494 DEBUG Setting timeout of 16.775272ms client | 7.494 DEBUG stream 0 complete client | 7.494 DEBUG [Client 47025ea090491916d639dd959c906d] output_path send_profile SendProfile { limit: 1204, pto: None, probe: EnumSet(), paced: false } client | 7.494 DEBUG Building Short dcid Some(CID [8]: 7e8fdd569f16e480) client | 7.494 DEBUG TX blocked, profile=SendProfile { limit: 1204, pto: None, probe: EnumSet(), paced: false } client | 7.494 DEBUG [Client 47025ea090491916d639dd959c906d] delay duration 16.749905ms client | 7.494 DEBUG Setting timeout of 16.749905ms client | 7.498 DEBUG [Client 47025ea090491916d639dd959c906d] pn=16 type=Short pri-path:7e8fdd569f16e480 0.0.0.0:34244->193.167.100.100:443 IpTos(Cs0, NotEct) len 1200 client | -> RX Stream { stream_id: 0, offset: 0, len: 1177, fin: false } client | 7.498 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 625, tv_nsec: 254514989 } client | 7.498 DEBUG [Client 47025ea090491916d639dd959c906d] output_path send_profile SendProfile { limit: 1204, pto: None, probe: EnumSet(), paced: false } client | 7.498 DEBUG Building Short dcid Some(CID [8]: 7e8fdd569f16e480) client | 7.498 DEBUG [Client 47025ea090491916d639dd959c906d] pn=2 type=Short pri-path:7e8fdd569f16e480 0.0.0.0:34244->193.167.100.100:443 IpTos(Cs0, NotEct) len 31 client | TX -> Ack { largest_acknowledged: 16, ack_delay: 3, first_ack_range: 3, ack_ranges: [], ecn_count: None } client | 7.498 DEBUG [Client 47025ea090491916d639dd959c906d] output_path send_profile SendProfile { limit: 1204, pto: None, probe: EnumSet(), paced: false } client | 7.498 DEBUG Building Short dcid Some(CID [8]: 7e8fdd569f16e480) client | 7.498 DEBUG TX blocked, profile=SendProfile { limit: 1204, pto: None, probe: EnumSet(), paced: false } client | 7.498 DEBUG [Client 47025ea090491916d639dd959c906d] delay duration 106.204909ms client | 7.498 DEBUG Setting timeout of 106.204909ms client | 7.498 DEBUG [Client 47025ea090491916d639dd959c906d] output_path send_profile SendProfile { limit: 1204, pto: None, probe: EnumSet(), paced: false } client | 7.498 DEBUG Building Short dcid Some(CID [8]: 7e8fdd569f16e480) client | 7.498 DEBUG TX blocked, profile=SendProfile { limit: 1204, pto: None, probe: EnumSet(), paced: false } client | 7.498 DEBUG [Client 47025ea090491916d639dd959c906d] delay duration 106.176866ms client | 7.498 DEBUG Setting timeout of 106.176866ms client | 7.499 DEBUG [Client 47025ea090491916d639dd959c906d] pn=17 type=Short pri-path:7e8fdd569f16e480 0.0.0.0:34244->193.167.100.100:443 IpTos(Cs0, NotEct) len 1200 client | -> RX Stream { stream_id: 0, offset: 1177, len: 1175, fin: false } client | 7.499 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 625, tv_nsec: 275488365 } client | 7.499 DEBUG [Client 47025ea090491916d639dd959c906d] output_path send_profile SendProfile { limit: 1204, pto: None, probe: EnumSet(), paced: false } client | 7.499 DEBUG Building Short dcid Some(CID [8]: 7e8fdd569f16e480) client | 7.499 DEBUG TX blocked, profile=SendProfile { limit: 1204, pto: None, probe: EnumSet(), paced: false } client | 7.499 DEBUG [Client 47025ea090491916d639dd959c906d] delay duration 19.976166ms client | 7.499 DEBUG Setting timeout of 19.976166ms client | 7.499 DEBUG [Client 47025ea090491916d639dd959c906d] output_path send_profile SendProfile { limit: 1204, pto: None, probe: EnumSet(), paced: false } client | 7.499 DEBUG Building Short dcid Some(CID [8]: 7e8fdd569f16e480) client | 7.499 DEBUG TX blocked, profile=SendProfile { limit: 1204, pto: None, probe: EnumSet(), paced: false } client | 7.499 DEBUG [Client 47025ea090491916d639dd959c906d] delay duration 19.949416ms client | 7.499 DEBUG Setting timeout of 19.949416ms client | 7.500 DEBUG [Client 47025ea090491916d639dd959c906d] pn=18 type=Short pri-path:7e8fdd569f16e480 0.0.0.0:34244->193.167.100.100:443 IpTos(Cs0, NotEct) len 1200 client | -> RX Stream { stream_id: 0, offset: 2352, len: 1175, fin: false } client | 7.500 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 625, tv_nsec: 256471929 } client | 7.500 DEBUG [Client 47025ea090491916d639dd959c906d] output_path send_profile SendProfile { limit: 1204, pto: None, probe: EnumSet(), paced: false } client | 7.500 DEBUG Building Short dcid Some(CID [8]: 7e8fdd569f16e480) client | 7.500 DEBUG [Client 47025ea090491916d639dd959c906d] pn=3 type=Short pri-path:7e8fdd569f16e480 0.0.0.0:34244->193.167.100.100:443 IpTos(Cs0, NotEct) len 31 client | TX -> Ack { largest_acknowledged: 18, ack_delay: 2, first_ack_range: 5, ack_ranges: [], ecn_count: None } client | 7.500 DEBUG [Client 47025ea090491916d639dd959c906d] output_path send_profile SendProfile { limit: 1204, pto: None, probe: EnumSet(), paced: false } client | 7.500 DEBUG Building Short dcid Some(CID [8]: 7e8fdd569f16e480) client | 7.500 DEBUG TX blocked, profile=SendProfile { limit: 1204, pto: None, probe: EnumSet(), paced: false } client | 7.500 DEBUG [Client 47025ea090491916d639dd959c906d] delay duration 104.251636ms client | 7.500 DEBUG Setting timeout of 104.251636ms client | 7.500 DEBUG [Client 47025ea090491916d639dd959c906d] output_path send_profile SendProfile { limit: 1204, pto: None, probe: EnumSet(), paced: false } client | 7.500 DEBUG Building Short dcid Some(CID [8]: 7e8fdd569f16e480) client | 7.500 DEBUG TX blocked, profile=SendProfile { limit: 1204, pto: None, probe: EnumSet(), paced: false } client | 7.500 DEBUG [Client 47025ea090491916d639dd959c906d] delay duration 104.224755ms client | 7.500 DEBUG Setting timeout of 104.224755ms client | 7.501 DEBUG [Client 47025ea090491916d639dd959c906d] pn=19 type=Short pri-path:7e8fdd569f16e480 0.0.0.0:34244->193.167.100.100:443 IpTos(Cs0, NotEct) len 1200 client | -> RX Stream { stream_id: 0, offset: 3527, len: 1175, fin: false } client | 7.501 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 625, tv_nsec: 277460914 } client | 7.501 DEBUG [Client 47025ea090491916d639dd959c906d] output_path send_profile SendProfile { limit: 1204, pto: None, probe: EnumSet(), paced: false } client | 7.501 DEBUG Building Short dcid Some(CID [8]: 7e8fdd569f16e480) client | 7.501 DEBUG TX blocked, profile=SendProfile { limit: 1204, pto: None, probe: EnumSet(), paced: false } client | 7.501 DEBUG [Client 47025ea090491916d639dd959c906d] delay duration 19.965365ms client | 7.501 DEBUG Setting timeout of 19.965365ms client | 7.501 DEBUG [Client 47025ea090491916d639dd959c906d] output_path send_profile SendProfile { limit: 1204, pto: None, probe: EnumSet(), paced: false } client | 7.501 DEBUG Building Short dcid Some(CID [8]: 7e8fdd569f16e480) client | 7.501 DEBUG TX blocked, profile=SendProfile { limit: 1204, pto: None, probe: EnumSet(), paced: false } client | 7.501 DEBUG [Client 47025ea090491916d639dd959c906d] delay duration 19.943214ms client | 7.501 DEBUG Setting timeout of 19.943214ms client | 7.501 DEBUG [Client 47025ea090491916d639dd959c906d] pn=20 type=Short pri-path:7e8fdd569f16e480 0.0.0.0:34244->193.167.100.100:443 IpTos(Cs0, NotEct) len 443 client | -> RX Stream { stream_id: 0, offset: 4702, len: 418, fin: true } client | 7.501 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 625, tv_nsec: 257840226 } client | 7.501 DEBUG [Client 47025ea090491916d639dd959c906d] output_path send_profile SendProfile { limit: 1204, pto: None, probe: EnumSet(), paced: false } client | 7.501 DEBUG Building Short dcid Some(CID [8]: 7e8fdd569f16e480) client | 7.501 DEBUG [Client 47025ea090491916d639dd959c906d] pn=4 type=Short pri-path:7e8fdd569f16e480 0.0.0.0:34244->193.167.100.100:443 IpTos(Cs0, NotEct) len 31 client | TX -> Ack { largest_acknowledged: 20, ack_delay: 4, first_ack_range: 7, ack_ranges: [], ecn_count: None } client | 7.501 DEBUG [Client 47025ea090491916d639dd959c906d] output_path send_profile SendProfile { limit: 1204, pto: None, probe: EnumSet(), paced: false } client | 7.501 DEBUG Building Short dcid Some(CID [8]: 7e8fdd569f16e480) client | 7.501 DEBUG TX blocked, profile=SendProfile { limit: 1204, pto: None, probe: EnumSet(), paced: false } client | 7.501 DEBUG [Client 47025ea090491916d639dd959c906d] delay duration 102.866197ms client | 7.501 DEBUG Setting timeout of 102.866197ms client | 7.501 DEBUG [Client 47025ea090491916d639dd959c906d] output_path send_profile SendProfile { limit: 1204, pto: None, probe: EnumSet(), paced: false } client | 7.501 DEBUG Building Short dcid Some(CID [8]: 7e8fdd569f16e480) client | 7.501 DEBUG TX blocked, profile=SendProfile { limit: 1204, pto: None, probe: EnumSet(), paced: false } client | 7.501 DEBUG [Client 47025ea090491916d639dd959c906d] delay duration 102.808909ms client | 7.501 DEBUG Setting timeout of 102.808909ms client | 7.501 DEBUG [Client 47025ea090491916d639dd959c906d] State change from Confirmed -> Closing { error: Application(0), timeout: Instant { tv_sec: 625, tv_nsec: 597526710 } } client | 7.501 WARN Unhandled event StateChange(Closing { error: Application(0), timeout: Instant { tv_sec: 625, tv_nsec: 597526710 } }) client | 7.501 DEBUG [Client 47025ea090491916d639dd959c906d] output_path send_profile SendProfile { limit: 1204, pto: None, probe: EnumSet(), paced: false } client | 7.501 DEBUG Building Short dcid Some(CID [8]: 7e8fdd569f16e480) client | 7.501 DEBUG [Recvd-ap] immediate_ack at Instant { tv_sec: 625, tv_nsec: 258037556 } client | 7.501 DEBUG [Client 47025ea090491916d639dd959c906d] pn=5 type=Short pri-path:7e8fdd569f16e480 0.0.0.0:34244->193.167.100.100:443 IpTos(Cs0, NotEct) len 42 client | TX -> Ack { largest_acknowledged: 20, ack_delay: 24, first_ack_range: 7, ack_ranges: [], ecn_count: None } client | TX -> ConnectionClose { error_code: Application(0), frame_type: 0, reason_phrase: "kthxbye!" } client | 7.501 DEBUG Setting timeout of 339.434782ms client | 7.524 DEBUG [Client 47025ea090491916d639dd959c906d] output_path send_profile SendProfile { limit: 1204, pto: None, probe: EnumSet(), paced: false } client | 7.524 DEBUG Building Short dcid Some(CID [8]: 7e8fdd569f16e480) client | 7.524 DEBUG [Recvd-ap] immediate_ack at Instant { tv_sec: 625, tv_nsec: 280736187 } client | 7.524 DEBUG [Client 47025ea090491916d639dd959c906d] pn=6 type=Short pri-path:7e8fdd569f16e480 0.0.0.0:34244->193.167.100.100:443 IpTos(Cs0, NotEct) len 43 client | TX -> Ack { largest_acknowledged: 20, ack_delay: 2861, first_ack_range: 7, ack_ranges: [], ecn_count: None } client | TX -> ConnectionClose { error_code: Application(0), frame_type: 0, reason_phrase: "kthxbye!" } client | 7.524 DEBUG Setting timeout of 316.694263ms client | 7.524 DEBUG Setting timeout of 316.680056ms client | 7.841 DEBUG [Client 47025ea090491916d639dd959c906d] State change from Closing { error: Application(0), timeout: Instant { tv_sec: 625, tv_nsec: 597526710 } } -> Closed(Application(0)) client | 7.841 INFO Closing timer expired client | 7.841 DEBUG Output::None client | 7.841 WARN Unhandled event StateChange(Closed(Application(0))) client | 7.841 DEBUG Timer fired while closed client | 7.841 DEBUG Output::None client exited with code 0 Aborting on container exit... Container server Stopping Container client Stopping Container client Stopped Container server Stopped Container sim Stopping Container sim Stopped 2025-04-30 12:58:06,954 Using the client's key log file. 2025-04-30 12:58:06,967 2025-04-30 12:58:06,967 Using the client's key log file. 2025-04-30 12:58:06,967 Using the client's key log file. 2025-04-30 12:58:06,979 2025-04-30 12:58:06,980 Using the client's key log file. 2025-04-30 12:58:06,980 Using the client's key log file. 2025-04-30 12:58:07,638 Check of downloaded files succeeded. 2025-04-30 12:58:07,963 Server sent 9985 bytes in Handshake CRYPTO frames. 2025-04-30 12:58:08,335 Received a 1252 byte Initial packet from the client. Amplification limit: 3756 2025-04-30 12:58:08,335 Received a 42 byte Handshake packet from the server. Total: 42 2025-04-30 12:58:08,335 Received a 1252 byte Initial packet from the client. Amplification limit: 7512 2025-04-30 12:58:08,335 Received a 1200 byte Handshake packet from the server. Total: 1242 2025-04-30 12:58:08,335 Received a 1200 byte Handshake packet from the server. Total: 2442 2025-04-30 12:58:08,336 Received a 1200 byte Handshake packet from the server. Total: 3642 2025-04-30 12:58:08,336 Received a 1200 byte Handshake packet from the server. Total: 4842 2025-04-30 12:58:08,336 Received a 1200 byte Handshake packet from the server. Total: 6042 2025-04-30 12:58:08,336 Received a 1200 byte Handshake packet from the server. Total: 7242 2025-04-30 12:58:08,336 Received a 270 byte Handshake packet from the server. Total: 7512 2025-04-30 12:58:08,336 Received a 81 byte Initial packet from the client. Amplification limit: 7755