2025-04-30 08:46:04,556 Generated random file: xzokwuzpkt of size: 5120 2025-04-30 08:46:04,556 Requests: https://server4:443/xzokwuzpkt 2025-04-30 08:46:04,956 2025-04-30 08:46:04,957 Command: WAITFORSERVER=server:443 CERTS=/tmp/certs_cpruxhkh/ TESTCASE_SERVER=transfer TESTCASE_CLIENT=transfer WWW=/tmp/www_zm79kcly/ DOWNLOADS=/tmp/download_7zw21374/ SERVER_LOGS=/tmp/logs_server_y1rj3nv4 CLIENT_LOGS=/tmp/logs_client_t6j0smc_ 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=ghcr.io/ngtcp2/ngtcp2-interop:latest REQUESTS="https://server4:443/xzokwuzpkt" docker compose --env-file empty.env up --abort-on-container-exit --timeout 1 sim client server 2025-04-30 08:46:24,708 Container sim Recreate Container sim Recreated Container client Recreate Container server Recreate Container client Recreated Container server Recreated Attaching to client, server, sim sim | waiting 10s for server:443 server | Setting up routes... client | Setting up routes... server | Actual changes: server | tx-checksum-ip-generic: off server | tx-tcp-segmentation: off [not requested] server | tx-tcp-ecn-segmentation: off [not requested] server | tx-tcp-mangleid-segmentation: off [not requested] server | tx-tcp6-segmentation: off [not requested] server | tx-udp-segmentation: off [not requested] server | tx-checksum-sctp: off client | Actual changes: client | tx-checksum-ip-generic: off client | tx-tcp-segmentation: off [not requested] client | tx-tcp-ecn-segmentation: off [not requested] client | tx-tcp-mangleid-segmentation: off [not requested] client | tx-tcp6-segmentation: off [not requested] client | tx-udp-segmentation: off [not requested] client | tx-checksum-sctp: off server | Endpoint's IPv4 address is 193.167.100.100 client | Endpoint's IPv4 address is 193.167.0.100 server | Endpoint's IPv6 address is fd00:cafe:cafe:100::100 client | Endpoint's IPv6 address is fd00:cafe:cafe::100 client | + export PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/neqo/bin client | + PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/neqo/bin client | + '[' -n transfer ']' client | + '[' -n /logs/qlog/ ']' client | + case "$ROLE" in client | + /wait-for-it.sh sim:57832 -s -t 30 client | wait-for-it.sh: waiting 30 seconds for sim:57832 sim | server:443 is available after 1.030311139s sim | Using scenario: droplist --delay=15ms --bandwidth=10Mbps --queue=25 --drops_to_server=2,3,4,5,6,7 sim | tcpdump: listening on eth0, link-type EN10MB (Ethernet), snapshot length 262144 bytes sim | tcpdump: listening on eth1, link-type EN10MB (Ethernet), snapshot length 262144 bytes client | wait-for-it.sh: sim:57832 is available after 1 seconds client | + OPTIONS=(--cc cubic --qns-test "$TESTCASE" --qlog-dir "$QLOGDIR" --output-dir /downloads) client | + '[' https://server4:443/xzokwuzpkt ']' 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/xzokwuzpkt 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:40067 -> 193.167.100.100:443 client | 0.001 DEBUG [CryptoStates] Creating initial cipher state v=Version1, role=Client dcid=e69b8b1a7fdf0af1 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:40067->193.167.100.100:443] Make permanent client | 0.001 DEBUG [unv-path:e69b8b1a7fdf0af1 0.0.0.0:40067->193.167.100.100:443] set as primary path client | 0.001 DEBUG [pri-unv-path:e69b8b1a7fdf0af1 0.0.0.0:40067->193.167.100.100:443] Path validated Instant { tv_sec: 428, tv_nsec: 940317841 } client | 0.001 DEBUG [Client e69b8b1a7fdf0af1] client_start client | 0.002 DEBUG Writing transport parameters, msg=1 client | 0.002 DEBUG [Agent 0x558ba5b04270] state -> InProgress client | 0.002 DEBUG [Client e69b8b1a7fdf0af1] State change from Init -> WaitInitial client | 0.002 DEBUG [Client e69b8b1a7fdf0af1] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.002 DEBUG Building Initial dcid Some(CID [8]: e69b8b1a7fdf0af1) scid Some(CID [0]: ) client | 0.002 DEBUG CRYPTO for in offset=0, len=1213 client | 0.002 DEBUG [Client e69b8b1a7fdf0af1] pn=0 type=Initial pri-path:e69b8b1a7fdf0af1 0.0.0.0:40067->193.167.100.100:443 IpTos(Cs0, Ect0) len 1252 client | TX -> Crypto { offset: 0, len: 1213 } client | 0.002 DEBUG packet_sent this=0x558ba5b17970, pn=0, ps=1252 client | 0.002 DEBUG ECN probing: sent 1 probes client | 0.002 DEBUG [Client e69b8b1a7fdf0af1] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.002 DEBUG Building Initial dcid Some(CID [8]: e69b8b1a7fdf0af1) scid Some(CID [0]: ) client | 0.002 DEBUG CRYPTO for in offset=1213, len=326 client | 0.002 DEBUG [Client e69b8b1a7fdf0af1] pn=1 type=Initial pri-path:e69b8b1a7fdf0af1 0.0.0.0:40067->193.167.100.100:443 IpTos(Cs0, Ect0) len 366 client | TX -> Crypto { offset: 1213, len: 326 } client | 0.002 DEBUG [Client e69b8b1a7fdf0af1] pad Initial from 366 to PLPMTU 1252 client | 0.002 DEBUG packet_sent this=0x558ba5b17970, pn=1, ps=1252 client | 0.002 DEBUG ECN probing: sent 2 probes client | 0.002 DEBUG [Client e69b8b1a7fdf0af1] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } client | 0.002 DEBUG Building Initial dcid Some(CID [8]: e69b8b1a7fdf0af1) 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 e69b8b1a7fdf0af1] delay duration 3.727123ms client | 0.002 DEBUG Setting timeout of 3.727123ms client | 0.002 DEBUG StateChange(WaitInitial) client | 0.002 WARN Cannot create stream ConnectionState client | 0.002 DEBUG [Client e69b8b1a7fdf0af1] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } client | 0.002 DEBUG Building Initial dcid Some(CID [8]: e69b8b1a7fdf0af1) 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 e69b8b1a7fdf0af1] delay duration 3.686327ms client | 0.002 DEBUG Setting timeout of 3.686327ms client | 0.007 DEBUG [Client e69b8b1a7fdf0af1] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.007 DEBUG Building Initial dcid Some(CID [8]: e69b8b1a7fdf0af1) 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 e69b8b1a7fdf0af1] delay duration 294.794915ms client | 0.007 DEBUG Setting timeout of 294.794915ms sim | Dropping packet 2 (1252 bytes) from 193.167.0.100 client | 0.040 DEBUG [Client e69b8b1a7fdf0af1] pn=1271349739 type=Initial pri-path:e69b8b1a7fdf0af1 0.0.0.0:40067->193.167.100.100:443 IpTos(Cs0, NotEct) len 58 client | -> RX Ack { largest_acknowledged: 0, ack_delay: 0, first_ack_range: 0, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 1, Ce: 0})) } client | 0.040 DEBUG [Client e69b8b1a7fdf0af1] 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=0x558ba5b17970, 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=1213 client | 0.040 DEBUG [Client e69b8b1a7fdf0af1] Changing to use Server CID=694be942507619380ea239b13cf13a602f97 client | 0.040 DEBUG [Client e69b8b1a7fdf0af1] State change from WaitInitial -> WaitVersion client | 0.040 DEBUG [Client e69b8b1a7fdf0af1] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.040 DEBUG Building Initial dcid Some(CID [18]: 694be942507619380ea239b13cf13a602f97) 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 e69b8b1a7fdf0af1] delay duration 77.569045ms client | 0.040 DEBUG Setting timeout of 77.569045ms client | 0.040 WARN Unhandled event StateChange(WaitVersion) client | 0.040 DEBUG [Client e69b8b1a7fdf0af1] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.040 DEBUG Building Initial dcid Some(CID [18]: 694be942507619380ea239b13cf13a602f97) 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 e69b8b1a7fdf0af1] delay duration 77.533298ms client | 0.040 DEBUG Setting timeout of 77.533298ms client | 0.119 DEBUG [LossRecovery] PTO timer fired for Initial client | 0.119 DEBUG [Client e69b8b1a7fdf0af1] Lost: Crypto(CryptoRecoveryToken { space: Initial, offset: 1213, length: 326 }) client | 0.119 INFO Lost crypto frame space=in offset=1213 length=326 client | 0.119 DEBUG [Client e69b8b1a7fdf0af1] Lost: EcnEct0 client | 0.119 DEBUG [Client e69b8b1a7fdf0af1] output_path send_profile SendProfile { limit: 1252, pto: Some(Initial), probe: EnumSet(Initial), paced: false } client | 0.119 DEBUG Building Initial dcid Some(CID [18]: 694be942507619380ea239b13cf13a602f97) scid Some(CID [0]: ) client | 0.119 DEBUG CRYPTO for in offset=1213, len=326 client | 0.119 DEBUG [Client e69b8b1a7fdf0af1] pn=2 type=Initial pri-path:694be942507619380ea239b13cf13a602f97 0.0.0.0:40067->193.167.100.100:443 IpTos(Cs0, Ect0) len 376 client | TX -> Crypto { offset: 1213, len: 326 } client | 0.119 DEBUG [Client e69b8b1a7fdf0af1] pad Initial from 376 to PLPMTU 1252 client | 0.119 DEBUG packet_sent this=0x558ba5b17970, pn=2, ps=1252 client | 0.119 DEBUG ECN probing: sent 3 probes client | 0.119 DEBUG [Client e69b8b1a7fdf0af1] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.119 DEBUG Building Initial dcid Some(CID [18]: 694be942507619380ea239b13cf13a602f97) scid Some(CID [0]: ) client | 0.119 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.119 DEBUG [Client e69b8b1a7fdf0af1] delay duration 230.977077ms client | 0.119 DEBUG Setting timeout of 230.977077ms sim | Dropping packet 3 (1252 bytes) from 193.167.0.100 client | 0.352 DEBUG [LossRecovery] PTO timer fired for Initial client | 0.352 DEBUG [Client e69b8b1a7fdf0af1] Lost: Crypto(CryptoRecoveryToken { space: Initial, offset: 1213, length: 326 }) client | 0.352 INFO Lost crypto frame space=in offset=1213 length=326 client | 0.352 DEBUG [Client e69b8b1a7fdf0af1] Lost: EcnEct0 client | 0.352 DEBUG [Client e69b8b1a7fdf0af1] output_path send_profile SendProfile { limit: 1252, pto: Some(Initial), probe: EnumSet(Initial), paced: false } client | 0.352 DEBUG Building Initial dcid Some(CID [18]: 694be942507619380ea239b13cf13a602f97) scid Some(CID [0]: ) client | 0.352 DEBUG CRYPTO for in offset=1213, len=326 client | 0.352 DEBUG [Client e69b8b1a7fdf0af1] pn=3 type=Initial pri-path:694be942507619380ea239b13cf13a602f97 0.0.0.0:40067->193.167.100.100:443 IpTos(Cs0, Ect0) len 376 client | TX -> Crypto { offset: 1213, len: 326 } client | 0.352 DEBUG [Client e69b8b1a7fdf0af1] pad Initial from 376 to PLPMTU 1252 client | 0.352 DEBUG packet_sent this=0x558ba5b17970, pn=3, ps=1252 client | 0.352 DEBUG ECN probing: sent 4 probes client | 0.352 DEBUG [Client e69b8b1a7fdf0af1] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.352 DEBUG Building Initial dcid Some(CID [18]: 694be942507619380ea239b13cf13a602f97) scid Some(CID [0]: ) client | 0.352 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.352 DEBUG [Client e69b8b1a7fdf0af1] delay duration 462.174115ms client | 0.352 DEBUG Setting timeout of 462.174115ms sim | Dropping packet 4 (1252 bytes) from 193.167.0.100 client | 0.816 DEBUG [LossRecovery] PTO timer fired for Initial client | 0.816 DEBUG [Client e69b8b1a7fdf0af1] Lost: Crypto(CryptoRecoveryToken { space: Initial, offset: 1213, length: 326 }) client | 0.816 INFO Lost crypto frame space=in offset=1213 length=326 client | 0.816 DEBUG [Client e69b8b1a7fdf0af1] Lost: EcnEct0 client | 0.816 DEBUG [Client e69b8b1a7fdf0af1] output_path send_profile SendProfile { limit: 1252, pto: Some(Initial), probe: EnumSet(Initial), paced: false } client | 0.816 DEBUG Building Initial dcid Some(CID [18]: 694be942507619380ea239b13cf13a602f97) scid Some(CID [0]: ) client | 0.816 DEBUG CRYPTO for in offset=1213, len=326 client | 0.816 DEBUG [Client e69b8b1a7fdf0af1] pn=4 type=Initial pri-path:694be942507619380ea239b13cf13a602f97 0.0.0.0:40067->193.167.100.100:443 IpTos(Cs0, Ect0) len 376 client | TX -> Crypto { offset: 1213, len: 326 } client | 0.816 DEBUG [Client e69b8b1a7fdf0af1] pad Initial from 376 to PLPMTU 1252 client | 0.816 DEBUG packet_sent this=0x558ba5b17970, pn=4, ps=1252 client | 0.816 DEBUG ECN probing: sent 5 probes client | 0.816 DEBUG [Client e69b8b1a7fdf0af1] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.816 DEBUG Building Initial dcid Some(CID [18]: 694be942507619380ea239b13cf13a602f97) scid Some(CID [0]: ) client | 0.816 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.816 DEBUG [Client e69b8b1a7fdf0af1] delay duration 924.555189ms client | 0.816 DEBUG Setting timeout of 924.555189ms sim | Dropping packet 5 (1252 bytes) from 193.167.0.100 client | 1.742 DEBUG [LossRecovery] PTO timer fired for Initial client | 1.742 DEBUG [Client e69b8b1a7fdf0af1] Lost: Crypto(CryptoRecoveryToken { space: Initial, offset: 1213, length: 326 }) client | 1.742 INFO Lost crypto frame space=in offset=1213 length=326 client | 1.742 DEBUG [Client e69b8b1a7fdf0af1] Lost: EcnEct0 client | 1.742 DEBUG [Client e69b8b1a7fdf0af1] output_path send_profile SendProfile { limit: 1252, pto: Some(Initial), probe: EnumSet(Initial), paced: false } client | 1.742 DEBUG Building Initial dcid Some(CID [18]: 694be942507619380ea239b13cf13a602f97) scid Some(CID [0]: ) client | 1.742 DEBUG CRYPTO for in offset=1213, len=326 client | 1.742 DEBUG [Client e69b8b1a7fdf0af1] pn=5 type=Initial pri-path:694be942507619380ea239b13cf13a602f97 0.0.0.0:40067->193.167.100.100:443 IpTos(Cs0, Ect0) len 376 client | TX -> Crypto { offset: 1213, len: 326 } client | 1.742 DEBUG [Client e69b8b1a7fdf0af1] pad Initial from 376 to PLPMTU 1252 client | 1.742 DEBUG packet_sent this=0x558ba5b17970, pn=5, ps=1252 client | 1.742 DEBUG ECN probing: sent 6 probes client | 1.742 DEBUG [Client e69b8b1a7fdf0af1] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 1.742 DEBUG Building Initial dcid Some(CID [18]: 694be942507619380ea239b13cf13a602f97) scid Some(CID [0]: ) client | 1.742 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 1.742 DEBUG [Client e69b8b1a7fdf0af1] delay duration 1.849282509s client | 1.742 DEBUG Setting timeout of 1.849282509s sim | Dropping packet 6 (1252 bytes) from 193.167.0.100 client | 3.593 DEBUG [LossRecovery] PTO timer fired for Initial client | 3.593 DEBUG [Client e69b8b1a7fdf0af1] Lost: Crypto(CryptoRecoveryToken { space: Initial, offset: 1213, length: 326 }) client | 3.593 INFO Lost crypto frame space=in offset=1213 length=326 client | 3.593 DEBUG [Client e69b8b1a7fdf0af1] Lost: EcnEct0 client | 3.593 DEBUG [Client e69b8b1a7fdf0af1] output_path send_profile SendProfile { limit: 1252, pto: Some(Initial), probe: EnumSet(Initial), paced: false } client | 3.593 DEBUG Building Initial dcid Some(CID [18]: 694be942507619380ea239b13cf13a602f97) scid Some(CID [0]: ) client | 3.593 DEBUG CRYPTO for in offset=1213, len=326 client | 3.593 DEBUG [Client e69b8b1a7fdf0af1] pn=6 type=Initial pri-path:694be942507619380ea239b13cf13a602f97 0.0.0.0:40067->193.167.100.100:443 IpTos(Cs0, Ect0) len 376 client | TX -> Crypto { offset: 1213, len: 326 } client | 3.593 DEBUG [Client e69b8b1a7fdf0af1] pad Initial from 376 to PLPMTU 1252 client | 3.593 DEBUG packet_sent this=0x558ba5b17970, pn=6, ps=1252 client | 3.593 DEBUG ECN probing: sent 7 probes client | 3.593 DEBUG [Client e69b8b1a7fdf0af1] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 3.593 DEBUG Building Initial dcid Some(CID [18]: 694be942507619380ea239b13cf13a602f97) scid Some(CID [0]: ) client | 3.593 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 3.593 DEBUG [Client e69b8b1a7fdf0af1] delay duration 3.698745394s client | 3.594 DEBUG Setting timeout of 3.698745394s sim | Dropping packet 7 (1252 bytes) from 193.167.0.100 client | 7.293 DEBUG [LossRecovery] PTO timer fired for Initial client | 7.293 DEBUG [Client e69b8b1a7fdf0af1] Lost: Crypto(CryptoRecoveryToken { space: Initial, offset: 1213, length: 326 }) client | 7.293 INFO Lost crypto frame space=in offset=1213 length=326 client | 7.293 DEBUG [Client e69b8b1a7fdf0af1] Lost: EcnEct0 client | 7.293 DEBUG [Client e69b8b1a7fdf0af1] output_path send_profile SendProfile { limit: 1252, pto: Some(Initial), probe: EnumSet(Initial), paced: false } client | 7.293 DEBUG Building Initial dcid Some(CID [18]: 694be942507619380ea239b13cf13a602f97) scid Some(CID [0]: ) client | 7.293 DEBUG CRYPTO for in offset=1213, len=326 client | 7.293 DEBUG [Client e69b8b1a7fdf0af1] pn=7 type=Initial pri-path:694be942507619380ea239b13cf13a602f97 0.0.0.0:40067->193.167.100.100:443 IpTos(Cs0, Ect0) len 376 client | TX -> Crypto { offset: 1213, len: 326 } client | 7.293 DEBUG [Client e69b8b1a7fdf0af1] pad Initial from 376 to PLPMTU 1252 client | 7.294 DEBUG packet_sent this=0x558ba5b17970, pn=7, ps=1252 client | 7.294 DEBUG ECN probing: sent 8 probes client | 7.294 DEBUG [Client e69b8b1a7fdf0af1] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.294 DEBUG Building Initial dcid Some(CID [18]: 694be942507619380ea239b13cf13a602f97) scid Some(CID [0]: ) client | 7.294 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.294 DEBUG [Client e69b8b1a7fdf0af1] delay duration 7.397740106s client | 7.294 DEBUG Setting timeout of 7.397740106s client | 7.328 DEBUG [Client e69b8b1a7fdf0af1] pn=1271349740 type=Initial pri-path:694be942507619380ea239b13cf13a602f97 0.0.0.0:40067->193.167.100.100:443 IpTos(Cs0, Ect0) len 154 client | -> RX Ack { largest_acknowledged: 7, ack_delay: 0, first_ack_range: 0, ack_ranges: [AckRange { gap: 5, range: 0 }], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 2, Ce: 0})) } client | -> RX Crypto { offset: 0, len: 90 } client | 7.328 DEBUG [Client e69b8b1a7fdf0af1] Rx ACK space=in, ranges=[7..=7, 0..=0] client | 7.328 DEBUG [LossRecovery] ACK for Initial - largest_acked=7 client | 7.328 DEBUG packet_lost this=0x558ba5b17970, pn=1, ps=1252 client | 7.328 DEBUG packet_lost this=0x558ba5b17970, pn=2, ps=1252 client | 7.328 DEBUG packet_lost this=0x558ba5b17970, pn=3, ps=1252 client | 7.328 DEBUG packet_lost this=0x558ba5b17970, pn=4, ps=1252 client | 7.328 DEBUG packet_lost this=0x558ba5b17970, pn=5, ps=1252 client | 7.328 DEBUG packet_lost this=0x558ba5b17970, pn=6, ps=1252 client | 7.328 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.328 DEBUG [Cubic [last_max_cwnd: 12520, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 1252/8764 ssthresh 8764] state -> RecoveryStart client | 7.328 INFO [Cubic [last_max_cwnd: 12520, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 1252/8764 ssthresh 8764] persistent congestion client | 7.328 DEBUG [Cubic [last_max_cwnd: 12520, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 1252/2504 ssthresh 8764] state -> PersistentCongestion client | 7.328 DEBUG on_packets_lost this=0x558ba5b17970, bytes_in_flight=1252, cwnd=2504, state=PersistentCongestion client | 7.328 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.328 DEBUG [Cubic [last_max_cwnd: 12520, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 0/2504 ssthresh 8764] on_packets_acked this=0x558ba5b17970, limited=0, bytes_in_flight=0, cwnd=2504, state=PersistentCongestion, new_acked=0 client | 7.328 DEBUG Acked crypto frame space=in offset=1213 length=326 client | 7.328 DEBUG [Client e69b8b1a7fdf0af1] Lost: Crypto(CryptoRecoveryToken { space: Initial, offset: 1213, length: 326 }) client | 7.328 INFO Lost crypto frame space=in offset=1213 length=326 client | 7.328 DEBUG [Client e69b8b1a7fdf0af1] Lost: EcnEct0 client | 7.328 DEBUG [Client e69b8b1a7fdf0af1] Lost: Crypto(CryptoRecoveryToken { space: Initial, offset: 1213, length: 326 }) client | 7.328 INFO Lost crypto frame space=in offset=1213 length=326 client | 7.328 DEBUG [Client e69b8b1a7fdf0af1] Lost: EcnEct0 client | 7.328 DEBUG [Client e69b8b1a7fdf0af1] Lost: Crypto(CryptoRecoveryToken { space: Initial, offset: 1213, length: 326 }) client | 7.328 INFO Lost crypto frame space=in offset=1213 length=326 client | 7.328 DEBUG [Client e69b8b1a7fdf0af1] Lost: EcnEct0 client | 7.328 DEBUG [Client e69b8b1a7fdf0af1] Lost: Crypto(CryptoRecoveryToken { space: Initial, offset: 1213, length: 326 }) client | 7.328 INFO Lost crypto frame space=in offset=1213 length=326 client | 7.328 DEBUG [Client e69b8b1a7fdf0af1] Lost: EcnEct0 client | 7.328 DEBUG [Client e69b8b1a7fdf0af1] Lost: Crypto(CryptoRecoveryToken { space: Initial, offset: 1213, length: 326 }) client | 7.328 INFO Lost crypto frame space=in offset=1213 length=326 client | 7.328 DEBUG [Client e69b8b1a7fdf0af1] Lost: EcnEct0 client | 7.328 DEBUG [Client e69b8b1a7fdf0af1] Lost: Crypto(CryptoRecoveryToken { space: Initial, offset: 1213, length: 326 }) client | 7.328 INFO Lost crypto frame space=in offset=1213 length=326 client | 7.328 DEBUG [Client e69b8b1a7fdf0af1] Lost: EcnEct0 client | 7.328 DEBUG Read Ok(90) bytes client | 7.328 DEBUG Write secret available for Handshake: SymKey [32]: d5aeb2cdacfe55e326d7b9b35cc558d4af6d7cc68ef9e205177debf6fd6c6c7e client | 7.328 DEBUG Read secret available for Handshake: SymKey [32]: 817c0c8732440b8bdc2623a6c03fbc5c7bfe38034677ccc526eb2182e197c9ca client | 7.328 DEBUG [Agent 0x558ba5b04270] state -> InProgress client | 7.328 DEBUG Making Write Handshake CryptoDxState, v=Version1 cipher=4865 client | 7.328 DEBUG Making Read Handshake CryptoDxState, v=Version1 cipher=4865 client | 7.328 DEBUG [Crypto] Handshake keys installed client | 7.328 DEBUG [Recvd-in] Set ACK timer to Instant { tv_sec: 436, tv_nsec: 267127431 } client | 7.328 DEBUG [Client e69b8b1a7fdf0af1] State change from WaitVersion -> Handshaking client | 7.328 DEBUG [Client e69b8b1a7fdf0af1] pn=1271349739 type=Handshake pri-path:694be942507619380ea239b13cf13a602f97 0.0.0.0:40067->193.167.100.100:443 IpTos(Cs0, Ect0) len 1046 client | -> RX Crypto { offset: 0, len: 993 } client | 7.328 DEBUG Read Ok(993) bytes client | 7.328 DEBUG [Agent 0x558ba5b04270] state -> InProgress client | 7.328 DEBUG [Recvd-hs] Set ACK timer to Instant { tv_sec: 436, tv_nsec: 267127431 } client | 7.328 DEBUG [Client e69b8b1a7fdf0af1] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.328 DEBUG Building Initial dcid Some(CID [18]: 694be942507619380ea239b13cf13a602f97) scid Some(CID [0]: ) client | 7.328 DEBUG [Client e69b8b1a7fdf0af1] pn=8 type=Initial pri-path:694be942507619380ea239b13cf13a602f97 0.0.0.0:40067->193.167.100.100:443 IpTos(Cs0, Ect0) len 61 client | TX -> Ack { largest_acknowledged: 1271349740, ack_delay: 114, first_ack_range: 1, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 1, Ce: 0})) } client | 7.328 DEBUG Building Handshake dcid Some(CID [18]: 694be942507619380ea239b13cf13a602f97) scid Some(CID [0]: ) client | 7.328 DEBUG [Client e69b8b1a7fdf0af1] pn=0 type=Handshake pri-path:694be942507619380ea239b13cf13a602f97 0.0.0.0:40067->193.167.100.100:443 IpTos(Cs0, Ect0) len 121 client | TX -> Ack { largest_acknowledged: 1271349739, ack_delay: 114, first_ack_range: 0, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 1, Ce: 0})) } client | 7.329 DEBUG [Client e69b8b1a7fdf0af1] Drop packet number space in client | 7.329 DEBUG [LossRecovery] Reset loss recovery state for Initial client | 7.329 WARN [LossRecovery] ignoring in-8 from dropped space client | 7.329 DEBUG ECN probing: sent 9 probes client | 7.329 DEBUG [Client e69b8b1a7fdf0af1] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.329 DEBUG Building Handshake dcid Some(CID [18]: 694be942507619380ea239b13cf13a602f97) scid Some(CID [0]: ) client | 7.329 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.329 DEBUG [Client e69b8b1a7fdf0af1] delay duration 100.040176ms client | 7.329 DEBUG Setting timeout of 100.040176ms client | 7.329 DEBUG [Client e69b8b1a7fdf0af1] pn=1271349740 type=Handshake pri-path:694be942507619380ea239b13cf13a602f97 0.0.0.0:40067->193.167.100.100:443 IpTos(Cs0, Ect0) len 1200 client | -> RX Crypto { offset: 993, len: 1146 } client | 7.329 DEBUG Read Ok(1146) bytes client | 7.329 DEBUG [Agent 0x558ba5b04270] state -> InProgress client | 7.329 DEBUG [Recvd-hs] Set ACK timer to Instant { tv_sec: 436, tv_nsec: 268218995 } client | 7.329 DEBUG [Client e69b8b1a7fdf0af1] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.329 DEBUG Building Handshake dcid Some(CID [18]: 694be942507619380ea239b13cf13a602f97) scid Some(CID [0]: ) client | 7.329 DEBUG [Client e69b8b1a7fdf0af1] pn=1 type=Handshake pri-path:694be942507619380ea239b13cf13a602f97 0.0.0.0:40067->193.167.100.100:443 IpTos(Cs0, Ect0) len 59 client | TX -> Ack { largest_acknowledged: 1271349740, ack_delay: 5, first_ack_range: 1, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 2, Ce: 0})) } client | 7.329 DEBUG ECN probing: sent 10 probes client | 7.329 DEBUG ECN probing concluded with 10 probes sent client | 7.329 DEBUG [Client e69b8b1a7fdf0af1] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.329 DEBUG Building Handshake dcid Some(CID [18]: 694be942507619380ea239b13cf13a602f97) scid Some(CID [0]: ) client | 7.329 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.329 DEBUG [Client e69b8b1a7fdf0af1] delay duration 99.889885ms client | 7.329 DEBUG Setting timeout of 99.889885ms client | 7.329 DEBUG StateChange(Handshaking) client | 7.329 WARN Cannot create stream ConnectionState client | 7.329 DEBUG stream BiDi creatable client | 7.329 WARN Cannot create stream ConnectionState client | 7.329 DEBUG [Client e69b8b1a7fdf0af1] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.329 DEBUG Building Handshake dcid Some(CID [18]: 694be942507619380ea239b13cf13a602f97) scid Some(CID [0]: ) client | 7.329 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.329 DEBUG [Client e69b8b1a7fdf0af1] delay duration 99.853727ms client | 7.329 DEBUG Setting timeout of 99.853727ms client | 7.329 DEBUG [Client e69b8b1a7fdf0af1] pn=1271349741 type=Handshake pri-path:694be942507619380ea239b13cf13a602f97 0.0.0.0:40067->193.167.100.100:443 IpTos(Cs0, Ect0) len 1200 client | -> RX Crypto { offset: 2139, len: 1146 } client | 7.329 DEBUG Read Ok(1146) bytes client | 7.329 DEBUG [Agent 0x558ba5b04270] state -> InProgress client | 7.329 DEBUG [Recvd-hs] Set ACK timer to Instant { tv_sec: 436, tv_nsec: 269072878 } client | 7.330 DEBUG [Client e69b8b1a7fdf0af1] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.330 DEBUG Building Handshake dcid Some(CID [18]: 694be942507619380ea239b13cf13a602f97) scid Some(CID [0]: ) client | 7.330 DEBUG [Client e69b8b1a7fdf0af1] pn=2 type=Handshake pri-path:694be942507619380ea239b13cf13a602f97 0.0.0.0:40067->193.167.100.100:443 IpTos(Cs0, NotEct) len 59 client | TX -> Ack { largest_acknowledged: 1271349741, ack_delay: 3, first_ack_range: 2, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 3, Ce: 0})) } client | 7.330 DEBUG [Client e69b8b1a7fdf0af1] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.330 DEBUG Building Handshake dcid Some(CID [18]: 694be942507619380ea239b13cf13a602f97) scid Some(CID [0]: ) client | 7.330 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.330 DEBUG [Client e69b8b1a7fdf0af1] delay duration 99.057072ms client | 7.330 DEBUG Setting timeout of 99.057072ms client | 7.330 DEBUG stream BiDi creatable client | 7.330 WARN Cannot create stream ConnectionState client | 7.330 DEBUG [Client e69b8b1a7fdf0af1] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.330 DEBUG Building Handshake dcid Some(CID [18]: 694be942507619380ea239b13cf13a602f97) scid Some(CID [0]: ) client | 7.330 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.330 DEBUG [Client e69b8b1a7fdf0af1] delay duration 99.01319ms client | 7.330 DEBUG Setting timeout of 99.01319ms client | 7.330 DEBUG [Client e69b8b1a7fdf0af1] pn=1271349742 type=Handshake pri-path:694be942507619380ea239b13cf13a602f97 0.0.0.0:40067->193.167.100.100:443 IpTos(Cs0, Ect0) len 1200 client | -> RX Crypto { offset: 3285, len: 1146 } client | 7.331 DEBUG Read Ok(1146) bytes client | 7.331 DEBUG [Agent 0x558ba5b04270] state -> InProgress client | 7.331 DEBUG [Recvd-hs] Set ACK timer to Instant { tv_sec: 436, tv_nsec: 270072742 } client | 7.331 DEBUG [Client e69b8b1a7fdf0af1] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.331 DEBUG Building Handshake dcid Some(CID [18]: 694be942507619380ea239b13cf13a602f97) scid Some(CID [0]: ) client | 7.331 DEBUG [Client e69b8b1a7fdf0af1] pn=3 type=Handshake pri-path:694be942507619380ea239b13cf13a602f97 0.0.0.0:40067->193.167.100.100:443 IpTos(Cs0, NotEct) len 59 client | TX -> Ack { largest_acknowledged: 1271349742, ack_delay: 8, first_ack_range: 3, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 4, Ce: 0})) } client | 7.331 DEBUG [Client e69b8b1a7fdf0af1] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.331 DEBUG Building Handshake dcid Some(CID [18]: 694be942507619380ea239b13cf13a602f97) scid Some(CID [0]: ) client | 7.331 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.331 DEBUG [Client e69b8b1a7fdf0af1] delay duration 98.02118ms client | 7.331 DEBUG Setting timeout of 98.02118ms client | 7.331 DEBUG stream BiDi creatable client | 7.331 WARN Cannot create stream ConnectionState client | 7.331 DEBUG [Client e69b8b1a7fdf0af1] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.331 DEBUG Building Handshake dcid Some(CID [18]: 694be942507619380ea239b13cf13a602f97) scid Some(CID [0]: ) client | 7.331 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.331 DEBUG [Client e69b8b1a7fdf0af1] delay duration 97.992065ms client | 7.331 DEBUG Setting timeout of 97.992065ms client | 7.331 DEBUG [Client e69b8b1a7fdf0af1] pn=1271349743 type=Handshake pri-path:694be942507619380ea239b13cf13a602f97 0.0.0.0:40067->193.167.100.100:443 IpTos(Cs0, Ect0) len 1200 client | -> RX Crypto { offset: 4431, len: 1146 } client | 7.331 DEBUG Read Ok(1146) bytes client | 7.331 DEBUG [Agent 0x558ba5b04270] state -> InProgress client | 7.331 DEBUG [Recvd-hs] Set ACK timer to Instant { tv_sec: 436, tv_nsec: 271030936 } client | 7.331 DEBUG [Client e69b8b1a7fdf0af1] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.331 DEBUG Building Handshake dcid Some(CID [18]: 694be942507619380ea239b13cf13a602f97) scid Some(CID [0]: ) client | 7.331 DEBUG [Client e69b8b1a7fdf0af1] pn=4 type=Handshake pri-path:694be942507619380ea239b13cf13a602f97 0.0.0.0:40067->193.167.100.100:443 IpTos(Cs0, NotEct) len 59 client | TX -> Ack { largest_acknowledged: 1271349743, ack_delay: 3, first_ack_range: 4, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 5, Ce: 0})) } client | 7.332 DEBUG [Client e69b8b1a7fdf0af1] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.332 DEBUG Building Handshake dcid Some(CID [18]: 694be942507619380ea239b13cf13a602f97) scid Some(CID [0]: ) client | 7.332 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.332 DEBUG [Client e69b8b1a7fdf0af1] delay duration 97.102631ms client | 7.332 DEBUG Setting timeout of 97.102631ms client | 7.332 DEBUG stream BiDi creatable client | 7.332 WARN Cannot create stream ConnectionState client | 7.332 DEBUG [Client e69b8b1a7fdf0af1] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.332 DEBUG Building Handshake dcid Some(CID [18]: 694be942507619380ea239b13cf13a602f97) scid Some(CID [0]: ) client | 7.332 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.332 DEBUG [Client e69b8b1a7fdf0af1] delay duration 97.074949ms client | 7.332 DEBUG Setting timeout of 97.074949ms client | 7.332 DEBUG [Client e69b8b1a7fdf0af1] pn=1271349744 type=Handshake pri-path:694be942507619380ea239b13cf13a602f97 0.0.0.0:40067->193.167.100.100:443 IpTos(Cs0, Ect0) len 1200 client | -> RX Crypto { offset: 5577, len: 1146 } client | 7.332 DEBUG Read Ok(1146) bytes client | 7.332 DEBUG [Agent 0x558ba5b04270] state -> InProgress client | 7.332 DEBUG [Recvd-hs] Set ACK timer to Instant { tv_sec: 436, tv_nsec: 272021467 } client | 7.332 DEBUG [Client e69b8b1a7fdf0af1] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.332 DEBUG Building Handshake dcid Some(CID [18]: 694be942507619380ea239b13cf13a602f97) scid Some(CID [0]: ) client | 7.332 DEBUG [Client e69b8b1a7fdf0af1] pn=5 type=Handshake pri-path:694be942507619380ea239b13cf13a602f97 0.0.0.0:40067->193.167.100.100:443 IpTos(Cs0, NotEct) len 59 client | TX -> Ack { largest_acknowledged: 1271349744, ack_delay: 3, first_ack_range: 5, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 6, Ce: 0})) } client | 7.333 DEBUG [Client e69b8b1a7fdf0af1] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.333 DEBUG Building Handshake dcid Some(CID [18]: 694be942507619380ea239b13cf13a602f97) scid Some(CID [0]: ) client | 7.333 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.333 DEBUG [Client e69b8b1a7fdf0af1] delay duration 96.117159ms client | 7.333 DEBUG Setting timeout of 96.117159ms client | 7.333 DEBUG stream BiDi creatable client | 7.333 WARN Cannot create stream ConnectionState client | 7.333 DEBUG [Client e69b8b1a7fdf0af1] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.333 DEBUG Building Handshake dcid Some(CID [18]: 694be942507619380ea239b13cf13a602f97) scid Some(CID [0]: ) client | 7.333 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.333 DEBUG [Client e69b8b1a7fdf0af1] delay duration 96.088575ms client | 7.333 DEBUG Setting timeout of 96.088575ms client | 7.333 DEBUG [Client e69b8b1a7fdf0af1] pn=1271349745 type=Handshake pri-path:694be942507619380ea239b13cf13a602f97 0.0.0.0:40067->193.167.100.100:443 IpTos(Cs0, Ect0) len 254 client | -> RX Crypto { offset: 6723, len: 200 } client | 7.333 DEBUG Read Ok(200) bytes client | 7.333 DEBUG [Agent 0x558ba5b04270] state -> InProgress client | 7.333 DEBUG [Recvd-hs] Set ACK timer to Instant { tv_sec: 436, tv_nsec: 272206176 } client | 7.333 DEBUG [Client e69b8b1a7fdf0af1] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.333 DEBUG Building Handshake dcid Some(CID [18]: 694be942507619380ea239b13cf13a602f97) scid Some(CID [0]: ) client | 7.333 DEBUG [Client e69b8b1a7fdf0af1] pn=6 type=Handshake pri-path:694be942507619380ea239b13cf13a602f97 0.0.0.0:40067->193.167.100.100:443 IpTos(Cs0, NotEct) len 59 client | TX -> Ack { largest_acknowledged: 1271349745, ack_delay: 4, first_ack_range: 6, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 7, Ce: 0})) } client | 7.333 DEBUG [Client e69b8b1a7fdf0af1] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.333 DEBUG Building Handshake dcid Some(CID [18]: 694be942507619380ea239b13cf13a602f97) scid Some(CID [0]: ) client | 7.333 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.333 DEBUG [Client e69b8b1a7fdf0af1] delay duration 95.92195ms client | 7.333 DEBUG Setting timeout of 95.92195ms client | 7.333 DEBUG stream BiDi creatable client | 7.333 WARN Cannot create stream ConnectionState client | 7.333 DEBUG [Client e69b8b1a7fdf0af1] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.333 DEBUG Building Handshake dcid Some(CID [18]: 694be942507619380ea239b13cf13a602f97) scid Some(CID [0]: ) client | 7.333 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.333 DEBUG [Client e69b8b1a7fdf0af1] delay duration 95.897505ms client | 7.333 DEBUG Setting timeout of 95.897505ms client | 7.361 DEBUG [Client e69b8b1a7fdf0af1] pn=1271349746 type=Handshake pri-path:694be942507619380ea239b13cf13a602f97 0.0.0.0:40067->193.167.100.100:443 IpTos(Cs0, Ect0) len 1200 client | -> RX Crypto { offset: 6923, len: 1149 } client | 7.361 DEBUG Read Ok(1149) bytes client | 7.361 DEBUG [Agent 0x558ba5b04270] state -> InProgress client | 7.361 DEBUG [Recvd-hs] Set ACK timer to Instant { tv_sec: 436, tv_nsec: 300690408 } client | 7.361 DEBUG [Client e69b8b1a7fdf0af1] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.361 DEBUG Building Handshake dcid Some(CID [18]: 694be942507619380ea239b13cf13a602f97) scid Some(CID [0]: ) client | 7.361 DEBUG [Client e69b8b1a7fdf0af1] pn=7 type=Handshake pri-path:694be942507619380ea239b13cf13a602f97 0.0.0.0:40067->193.167.100.100:443 IpTos(Cs0, NotEct) len 59 client | TX -> Ack { largest_acknowledged: 1271349746, ack_delay: 3, first_ack_range: 7, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 8, Ce: 0})) } client | 7.361 DEBUG [Client e69b8b1a7fdf0af1] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.361 DEBUG Building Handshake dcid Some(CID [18]: 694be942507619380ea239b13cf13a602f97) scid Some(CID [0]: ) client | 7.361 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.361 DEBUG [Client e69b8b1a7fdf0af1] delay duration 67.441745ms client | 7.361 DEBUG Setting timeout of 67.441745ms client | 7.361 DEBUG stream BiDi creatable client | 7.361 WARN Cannot create stream ConnectionState client | 7.361 DEBUG [Client e69b8b1a7fdf0af1] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.361 DEBUG Building Handshake dcid Some(CID [18]: 694be942507619380ea239b13cf13a602f97) scid Some(CID [0]: ) client | 7.361 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.361 DEBUG [Client e69b8b1a7fdf0af1] delay duration 67.412641ms client | 7.361 DEBUG Setting timeout of 67.412641ms client | 7.362 DEBUG [Client e69b8b1a7fdf0af1] pn=1271349747 type=Handshake pri-path:694be942507619380ea239b13cf13a602f97 0.0.0.0:40067->193.167.100.100:443 IpTos(Cs0, Ect0) len 1200 client | -> RX Crypto { offset: 8072, len: 1149 } client | 7.362 DEBUG Read Ok(1149) bytes client | 7.362 DEBUG [Agent 0x558ba5b04270] state -> InProgress client | 7.362 DEBUG [Recvd-hs] Set ACK timer to Instant { tv_sec: 436, tv_nsec: 301704757 } client | 7.362 DEBUG [Client e69b8b1a7fdf0af1] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.362 DEBUG Building Handshake dcid Some(CID [18]: 694be942507619380ea239b13cf13a602f97) scid Some(CID [0]: ) client | 7.362 DEBUG [Client e69b8b1a7fdf0af1] pn=8 type=Handshake pri-path:694be942507619380ea239b13cf13a602f97 0.0.0.0:40067->193.167.100.100:443 IpTos(Cs0, NotEct) len 59 client | TX -> Ack { largest_acknowledged: 1271349747, ack_delay: 3, first_ack_range: 8, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 9, Ce: 0})) } client | 7.362 DEBUG [Client e69b8b1a7fdf0af1] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.362 DEBUG Building Handshake dcid Some(CID [18]: 694be942507619380ea239b13cf13a602f97) scid Some(CID [0]: ) client | 7.362 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.362 DEBUG [Client e69b8b1a7fdf0af1] delay duration 66.431695ms client | 7.362 DEBUG Setting timeout of 66.431695ms client | 7.362 DEBUG stream BiDi creatable client | 7.362 WARN Cannot create stream ConnectionState client | 7.362 DEBUG [Client e69b8b1a7fdf0af1] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.362 DEBUG Building Handshake dcid Some(CID [18]: 694be942507619380ea239b13cf13a602f97) scid Some(CID [0]: ) client | 7.362 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.362 DEBUG [Client e69b8b1a7fdf0af1] delay duration 66.401077ms client | 7.362 DEBUG Setting timeout of 66.401077ms client | 7.363 DEBUG [Client e69b8b1a7fdf0af1] pn=1271349748 type=Handshake pri-path:694be942507619380ea239b13cf13a602f97 0.0.0.0:40067->193.167.100.100:443 IpTos(Cs0, Ect0) len 780 client | -> RX Crypto { offset: 9221, len: 729 } client | 7.363 DEBUG Read Ok(729) bytes client | 7.364 DEBUG [Agent 0x558ba5b04270] state -> AuthenticationPending client | 7.364 DEBUG [Recvd-hs] Set ACK timer to Instant { tv_sec: 436, tv_nsec: 302791892 } client | 7.364 DEBUG saving datagram of 420 bytes client | 7.364 DEBUG [Client e69b8b1a7fdf0af1] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.364 DEBUG Building Handshake dcid Some(CID [18]: 694be942507619380ea239b13cf13a602f97) scid Some(CID [0]: ) client | 7.364 DEBUG [Client e69b8b1a7fdf0af1] pn=9 type=Handshake pri-path:694be942507619380ea239b13cf13a602f97 0.0.0.0:40067->193.167.100.100:443 IpTos(Cs0, NotEct) len 60 client | TX -> Ack { largest_acknowledged: 1271349748, ack_delay: 87, first_ack_range: 9, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 10, Ce: 0})) } client | 7.364 DEBUG [Client e69b8b1a7fdf0af1] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.364 DEBUG Building Handshake dcid Some(CID [18]: 694be942507619380ea239b13cf13a602f97) scid Some(CID [0]: ) client | 7.364 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.364 DEBUG [Client e69b8b1a7fdf0af1] delay duration 64.668043ms client | 7.364 DEBUG Setting timeout of 64.668043ms client | 7.364 DEBUG [Client e69b8b1a7fdf0af1] Authenticated Ok client | 7.364 DEBUG Write secret available for ApplicationData: SymKey [32]: f2f5e6f0cebcb9cca76a643fe5512b30bb5195c5e3902615d42566af2edbd429 client | 7.364 DEBUG Read secret available for ApplicationData: SymKey [32]: af8c5340bcbf5928a8e232ab76c87f668391fa8d399503b2b75cd712b186f90e client | 7.364 DEBUG [Agent 0x558ba5b04270] SSL_AuthCertificateComplete: Ok(()) client | 7.364 DEBUG [Agent 0x558ba5b04270] state -> Complete(SecretAgentInfo { version: 772, cipher: 4865, group: 29, resumed: false, early_data: false, ech_accepted: false, alpn: Some("hq-interop"), signature_scheme: 1027 }) client | 7.364 DEBUG [Client e69b8b1a7fdf0af1] TLS connection complete client | 7.364 DEBUG Making Write ApplicationData CryptoDxState, v=Version1 cipher=4865 client | 7.364 DEBUG [Crypto] Application write key installed client | 7.364 DEBUG Making Read ApplicationData CryptoDxState, v=Version1 cipher=4865 client | 7.364 DEBUG [Crypto] application read keys installed client | 7.364 DEBUG [Client e69b8b1a7fdf0af1] State change from Handshaking -> Connected client | 7.364 INFO [Client e69b8b1a7fdf0af1] Connection established client | 7.364 DEBUG [Client e69b8b1a7fdf0af1] process saved for epoch ApplicationData client | 7.364 DEBUG [Client e69b8b1a7fdf0af1] pn=1271349739 type=Short pri-path:694be942507619380ea239b13cf13a602f97 0.0.0.0:40067->193.167.100.100:443 IpTos(Cs0, Ect0) len 420 client | -> RX NewConnectionId { sequence_number: 7, retire_prior: 0, connection_id: [231, 238, 24, 191, 53, 14, 176, 212, 169, 166, 123, 47, 206, 96, 70, 226, 73, 78], stateless_reset_token: [190, 92, 208, 131, 102, 7, 68, 179, 21, 29, 221, 68, 208, 168, 174, 17] } client | -> RX NewConnectionId { sequence_number: 6, retire_prior: 0, connection_id: [150, 208, 1, 108, 192, 114, 216, 125, 36, 54, 163, 222, 80, 34, 255, 171, 112, 90], stateless_reset_token: [14, 28, 81, 220, 25, 239, 176, 240, 231, 17, 27, 214, 110, 163, 22, 237] } client | -> RX NewConnectionId { sequence_number: 5, retire_prior: 0, connection_id: [37, 61, 236, 70, 102, 1, 15, 197, 116, 128, 165, 223, 104, 232, 165, 156, 144, 97], stateless_reset_token: [171, 63, 255, 46, 201, 229, 123, 187, 43, 211, 144, 18, 147, 48, 69, 194] } client | -> RX NewConnectionId { sequence_number: 4, retire_prior: 0, connection_id: [158, 64, 32, 14, 175, 123, 23, 140, 129, 167, 18, 112, 191, 228, 16, 219, 207, 51], stateless_reset_token: [104, 75, 241, 200, 35, 116, 203, 177, 70, 98, 124, 33, 126, 137, 192, 171] } client | -> RX NewConnectionId { sequence_number: 3, retire_prior: 0, connection_id: [23, 65, 121, 214, 22, 138, 75, 32, 136, 176, 137, 47, 139, 6, 6, 26, 173, 152], stateless_reset_token: [228, 244, 166, 82, 154, 152, 66, 12, 203, 202, 0, 213, 71, 235, 44, 225] } client | -> RX NewConnectionId { sequence_number: 2, retire_prior: 0, connection_id: [153, 245, 157, 206, 179, 199, 156, 65, 65, 42, 48, 95, 23, 131, 60, 159, 234, 100], stateless_reset_token: [101, 196, 190, 5, 169, 127, 175, 139, 20, 44, 20, 70, 181, 142, 70, 175] } client | -> RX NewConnectionId { sequence_number: 1, retire_prior: 0, connection_id: [117, 102, 34, 11, 69, 69, 56, 112, 219, 4, 244, 140, 86, 166, 114, 8, 96, 32], stateless_reset_token: [144, 113, 4, 133, 160, 158, 102, 13, 165, 213, 243, 128, 144, 128, 5, 216] } client | -> RX Padding { len: 133 } client | 7.364 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 436, tv_nsec: 302791892 } client | 7.364 DEBUG stream BiDi creatable client | 7.364 INFO Created stream 0 for https://server4/xzokwuzpkt client | 7.364 INFO Saving https://server4/xzokwuzpkt to "/downloads/xzokwuzpkt" client | 7.364 DEBUG StateChange(Connected) client | 7.364 DEBUG stream 0 writable client | 7.365 DEBUG [Client e69b8b1a7fdf0af1] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.365 DEBUG Building Handshake dcid Some(CID [18]: 694be942507619380ea239b13cf13a602f97) scid Some(CID [0]: ) client | 7.365 DEBUG CRYPTO for hs offset=0, len=36 client | 7.365 DEBUG [Client e69b8b1a7fdf0af1] pn=10 type=Handshake pri-path:694be942507619380ea239b13cf13a602f97 0.0.0.0:40067->193.167.100.100:443 IpTos(Cs0, NotEct) len 83 client | TX -> Crypto { offset: 0, len: 36 } client | 7.365 DEBUG packet_sent this=0x558ba5b17970, pn=10, ps=83 client | 7.365 DEBUG Building Short dcid Some(CID [18]: 694be942507619380ea239b13cf13a602f97) client | 7.365 DEBUG [Client e69b8b1a7fdf0af1] pn=0 type=Short pri-path:694be942507619380ea239b13cf13a602f97 0.0.0.0:40067->193.167.100.100:443 IpTos(Cs0, NotEct) len 155 client | TX -> Ack { largest_acknowledged: 1271349739, ack_delay: 164, first_ack_range: 0, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 1, Ce: 0})) } client | TX -> Stream { stream_id: 0, offset: 0, len: 17, fin: true } client | 7.365 DEBUG packet_sent this=0x558ba5b17970, pn=0, ps=72 client | 7.365 DEBUG [Client e69b8b1a7fdf0af1] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.365 DEBUG Building Handshake dcid Some(CID [18]: 694be942507619380ea239b13cf13a602f97) scid Some(CID [0]: ) client | 7.365 DEBUG Building Short dcid Some(CID [18]: 694be942507619380ea239b13cf13a602f97) client | 7.365 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.365 DEBUG [Client e69b8b1a7fdf0af1] delay duration 100.083869ms client | 7.365 DEBUG Setting timeout of 100.083869ms client | 7.397 DEBUG [Client e69b8b1a7fdf0af1] pn=1271349740 type=Short pri-path:694be942507619380ea239b13cf13a602f97 0.0.0.0:40067->193.167.100.100:443 IpTos(Cs0, Ect0) len 1406 client | -> RX Ping client | -> RX Padding { len: 1387 } client | 7.397 DEBUG [Recvd-ap] immediate_ack at Instant { tv_sec: 436, tv_nsec: 336445111 } client | 7.397 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 436, tv_nsec: 336445111 } client | 7.397 DEBUG [Client e69b8b1a7fdf0af1] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.397 DEBUG Building Handshake dcid Some(CID [18]: 694be942507619380ea239b13cf13a602f97) scid Some(CID [0]: ) client | 7.397 DEBUG Building Short dcid Some(CID [18]: 694be942507619380ea239b13cf13a602f97) client | 7.397 DEBUG [Client e69b8b1a7fdf0af1] pn=1 type=Short pri-path:694be942507619380ea239b13cf13a602f97 0.0.0.0:40067->193.167.100.100:443 IpTos(Cs0, NotEct) len 51 client | TX -> Ack { largest_acknowledged: 1271349740, ack_delay: 5, first_ack_range: 1, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 2, Ce: 0})) } client | 7.397 DEBUG [Client e69b8b1a7fdf0af1] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.397 DEBUG Building Handshake dcid Some(CID [18]: 694be942507619380ea239b13cf13a602f97) scid Some(CID [0]: ) client | 7.397 DEBUG Building Short dcid Some(CID [18]: 694be942507619380ea239b13cf13a602f97) client | 7.397 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.397 DEBUG [Client e69b8b1a7fdf0af1] delay duration 67.69709ms client | 7.397 DEBUG Setting timeout of 67.69709ms client | 7.397 DEBUG [Client e69b8b1a7fdf0af1] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.397 DEBUG Building Handshake dcid Some(CID [18]: 694be942507619380ea239b13cf13a602f97) scid Some(CID [0]: ) client | 7.397 DEBUG Building Short dcid Some(CID [18]: 694be942507619380ea239b13cf13a602f97) client | 7.397 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.397 DEBUG [Client e69b8b1a7fdf0af1] delay duration 67.660191ms client | 7.397 DEBUG Setting timeout of 67.660191ms client | 7.398 DEBUG [Client e69b8b1a7fdf0af1] pn=1271349741 type=Short pri-path:694be942507619380ea239b13cf13a602f97 0.0.0.0:40067->193.167.100.100:443 IpTos(Cs0, Ect0) len 1200 client | -> RX HandshakeDone client | -> RX NewToken { token: [54, 227, 200, 11, 50, 92, 228, 101, 7, 216, 135, 156, 34, 222, 229, 62, 18, 161, 226, 183, 207, 35, 140, 61, 189, 223, 162, 250, 92, 34, 192, 249, 169, 216, 240, 158, 166, 41, 117, 65, 245] } client | -> RX Crypto { offset: 0, len: 237 } client | -> RX Stream { stream_id: 0, offset: 0, len: 893, fin: false } client | 7.398 DEBUG [Client e69b8b1a7fdf0af1] State change from Connected -> Confirmed client | 7.398 DEBUG PMTUD started with probe size 1380 client | 7.398 DEBUG [Client e69b8b1a7fdf0af1] Drop packet number space hs client | 7.398 DEBUG [LossRecovery] Reset loss recovery state for Handshake client | 7.398 DEBUG [Client e69b8b1a7fdf0af1] No preferred address to migrate to client | 7.398 DEBUG Read Ok(237) bytes client | 7.398 DEBUG [0x558ba5b04270] Got resumption token [5964]: 02000633faf31f33..0000000000000000 client | 7.398 DEBUG [Agent 0x558ba5b04270] state -> Complete(SecretAgentInfo { version: 772, cipher: 4865, group: 29, resumed: false, early_data: false, ech_accepted: false, alpn: Some("hq-interop"), signature_scheme: 1027 }) client | 7.398 DEBUG setting max_stream_data to 262144 client | 7.398 DEBUG resumption token [6105]: 0000000125405c00..0000000000000000 client | 7.398 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 436, tv_nsec: 357442348 } client | 7.398 DEBUG [Client e69b8b1a7fdf0af1] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.398 DEBUG Building Short dcid Some(CID [18]: 694be942507619380ea239b13cf13a602f97) client | 7.398 DEBUG Sending PMTUD probe of size 1380, count 1 client | 7.398 DEBUG [Client e69b8b1a7fdf0af1] pn=2 type=Short pri-path:694be942507619380ea239b13cf13a602f97 0.0.0.0:40067->193.167.100.100:443 IpTos(Cs0, NotEct) len 1352 client | TX -> Ping client | TX -> Padding { len: 1315 } client | 7.398 DEBUG packet_sent this=0x558ba5b17970, pn=2, ps=1352 client | 7.398 DEBUG [Client e69b8b1a7fdf0af1] output_path send_profile SendProfile { limit: 1080, pto: None, probe: EnumSet(), paced: false } client | 7.398 DEBUG Building Short dcid Some(CID [18]: 694be942507619380ea239b13cf13a602f97) client | 7.398 DEBUG TX blocked, profile=SendProfile { limit: 1080, pto: None, probe: EnumSet(), paced: false } client | 7.398 DEBUG [Client e69b8b1a7fdf0af1] delay duration 19.633371ms client | 7.398 DEBUG Setting timeout of 19.633371ms client | 7.398 WARN Unhandled event StateChange(Confirmed) client | 7.398 DEBUG stream BiDi creatable client | 7.398 DEBUG [Client e69b8b1a7fdf0af1] output_path send_profile SendProfile { limit: 1080, pto: None, probe: EnumSet(), paced: false } client | 7.398 DEBUG Building Short dcid Some(CID [18]: 694be942507619380ea239b13cf13a602f97) client | 7.398 DEBUG TX blocked, profile=SendProfile { limit: 1080, pto: None, probe: EnumSet(), paced: false } client | 7.398 DEBUG [Client e69b8b1a7fdf0af1] delay duration 19.594227ms client | 7.398 DEBUG Setting timeout of 19.594227ms client | 7.399 DEBUG [Client e69b8b1a7fdf0af1] pn=1271349742 type=Short pri-path:694be942507619380ea239b13cf13a602f97 0.0.0.0:40067->193.167.100.100:443 IpTos(Cs0, Ect0) len 1200 client | -> RX Stream { stream_id: 0, offset: 893, len: 1176, fin: false } client | 7.399 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 436, tv_nsec: 338368044 } client | 7.399 DEBUG [Client e69b8b1a7fdf0af1] output_path send_profile SendProfile { limit: 1080, pto: None, probe: EnumSet(), paced: false } client | 7.399 DEBUG Building Short dcid Some(CID [18]: 694be942507619380ea239b13cf13a602f97) client | 7.399 DEBUG [Client e69b8b1a7fdf0af1] pn=3 type=Short pri-path:694be942507619380ea239b13cf13a602f97 0.0.0.0:40067->193.167.100.100:443 IpTos(Cs0, NotEct) len 51 client | TX -> Ack { largest_acknowledged: 1271349742, ack_delay: 4, first_ack_range: 3, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 4, Ce: 0})) } client | 7.399 DEBUG [Client e69b8b1a7fdf0af1] output_path send_profile SendProfile { limit: 1080, pto: None, probe: EnumSet(), paced: false } client | 7.399 DEBUG Building Short dcid Some(CID [18]: 694be942507619380ea239b13cf13a602f97) client | 7.399 DEBUG TX blocked, profile=SendProfile { limit: 1080, pto: None, probe: EnumSet(), paced: false } client | 7.399 DEBUG [Client e69b8b1a7fdf0af1] delay duration 124.450283ms client | 7.399 DEBUG Setting timeout of 124.450283ms client | 7.399 DEBUG [Client e69b8b1a7fdf0af1] output_path send_profile SendProfile { limit: 1080, pto: None, probe: EnumSet(), paced: false } client | 7.399 DEBUG Building Short dcid Some(CID [18]: 694be942507619380ea239b13cf13a602f97) client | 7.399 DEBUG TX blocked, profile=SendProfile { limit: 1080, pto: None, probe: EnumSet(), paced: false } client | 7.399 DEBUG [Client e69b8b1a7fdf0af1] delay duration 124.424695ms client | 7.399 DEBUG Setting timeout of 124.424695ms client | 7.400 DEBUG [Client e69b8b1a7fdf0af1] pn=1271349743 type=Short pri-path:694be942507619380ea239b13cf13a602f97 0.0.0.0:40067->193.167.100.100:443 IpTos(Cs0, Ect0) len 1200 client | -> RX Stream { stream_id: 0, offset: 2069, len: 1176, fin: false } client | 7.400 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 436, tv_nsec: 359387472 } client | 7.400 DEBUG [Client e69b8b1a7fdf0af1] output_path send_profile SendProfile { limit: 1080, pto: None, probe: EnumSet(), paced: false } client | 7.400 DEBUG Building Short dcid Some(CID [18]: 694be942507619380ea239b13cf13a602f97) client | 7.400 DEBUG TX blocked, profile=SendProfile { limit: 1080, pto: None, probe: EnumSet(), paced: false } client | 7.400 DEBUG [Client e69b8b1a7fdf0af1] delay duration 19.960285ms client | 7.400 DEBUG Setting timeout of 19.960285ms client | 7.400 DEBUG [Client e69b8b1a7fdf0af1] output_path send_profile SendProfile { limit: 1080, pto: None, probe: EnumSet(), paced: false } client | 7.400 DEBUG Building Short dcid Some(CID [18]: 694be942507619380ea239b13cf13a602f97) client | 7.400 DEBUG TX blocked, profile=SendProfile { limit: 1080, pto: None, probe: EnumSet(), paced: false } client | 7.400 DEBUG [Client e69b8b1a7fdf0af1] delay duration 19.937432ms client | 7.400 DEBUG Setting timeout of 19.937432ms client | 7.400 DEBUG [Client e69b8b1a7fdf0af1] pn=1271349744 type=Short pri-path:694be942507619380ea239b13cf13a602f97 0.0.0.0:40067->193.167.100.100:443 IpTos(Cs0, Ect0) len 40 client | -> RX Ack { largest_acknowledged: 0, ack_delay: 637, first_ack_range: 0, ack_ranges: [], ecn_count: None } client | -> RX Padding { len: 16 } client | 7.400 DEBUG [Client e69b8b1a7fdf0af1] Rx ACK space=ap, ranges=[0..=0] client | 7.400 DEBUG [LossRecovery] ACK for ApplicationData - largest_acked=0 client | 7.400 DEBUG [Cubic [last_max_cwnd: 12520, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 1352/2576 ssthresh 8764] slow start += 72 client | 7.400 DEBUG [Cubic [last_max_cwnd: 12520, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 1352/2576 ssthresh 8764] on_packets_acked this=0x558ba5b17970, limited=0, bytes_in_flight=1352, cwnd=2576, state=SlowStart, new_acked=72 client | 7.400 DEBUG [Client e69b8b1a7fdf0af1] output_path send_profile SendProfile { limit: 1224, pto: None, probe: EnumSet(), paced: false } client | 7.400 DEBUG Building Short dcid Some(CID [18]: 694be942507619380ea239b13cf13a602f97) client | 7.400 DEBUG TX blocked, profile=SendProfile { limit: 1224, pto: None, probe: EnumSet(), paced: false } client | 7.400 DEBUG [Client e69b8b1a7fdf0af1] delay duration 19.463596ms client | 7.400 DEBUG Setting timeout of 19.463596ms client | 7.400 DEBUG stream 0 complete client | 7.400 DEBUG [Client e69b8b1a7fdf0af1] output_path send_profile SendProfile { limit: 1224, pto: None, probe: EnumSet(), paced: false } client | 7.400 DEBUG Building Short dcid Some(CID [18]: 694be942507619380ea239b13cf13a602f97) client | 7.400 DEBUG TX blocked, profile=SendProfile { limit: 1224, pto: None, probe: EnumSet(), paced: false } client | 7.400 DEBUG [Client e69b8b1a7fdf0af1] delay duration 19.441284ms client | 7.400 DEBUG Setting timeout of 19.441284ms client | 7.420 DEBUG [Client e69b8b1a7fdf0af1] output_path send_profile SendProfile { limit: 1224, pto: None, probe: EnumSet(), paced: false } client | 7.420 DEBUG Building Short dcid Some(CID [18]: 694be942507619380ea239b13cf13a602f97) client | 7.420 DEBUG [Client e69b8b1a7fdf0af1] pn=4 type=Short pri-path:694be942507619380ea239b13cf13a602f97 0.0.0.0:40067->193.167.100.100:443 IpTos(Cs0, NotEct) len 52 client | TX -> Ack { largest_acknowledged: 1271349744, ack_delay: 2520, first_ack_range: 5, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 6, Ce: 0})) } client | 7.421 DEBUG [Client e69b8b1a7fdf0af1] output_path send_profile SendProfile { limit: 1224, pto: None, probe: EnumSet(), paced: false } client | 7.421 DEBUG Building Short dcid Some(CID [18]: 694be942507619380ea239b13cf13a602f97) client | 7.421 DEBUG TX blocked, profile=SendProfile { limit: 1224, pto: None, probe: EnumSet(), paced: false } client | 7.421 DEBUG [Client e69b8b1a7fdf0af1] delay duration 89.187767ms client | 7.421 DEBUG Setting timeout of 89.187767ms client | 7.429 DEBUG [Client e69b8b1a7fdf0af1] pn=1271349745 type=Short pri-path:694be942507619380ea239b13cf13a602f97 0.0.0.0:40067->193.167.100.100:443 IpTos(Cs0, Ect0) len 1444 client | -> RX Ping client | -> RX Padding { len: 1425 } client | 7.429 DEBUG [Recvd-ap] immediate_ack at Instant { tv_sec: 436, tv_nsec: 368460367 } client | 7.429 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 436, tv_nsec: 368460367 } client | 7.429 DEBUG [Client e69b8b1a7fdf0af1] output_path send_profile SendProfile { limit: 1224, pto: None, probe: EnumSet(), paced: false } client | 7.429 DEBUG Building Short dcid Some(CID [18]: 694be942507619380ea239b13cf13a602f97) client | 7.429 DEBUG [Client e69b8b1a7fdf0af1] pn=5 type=Short pri-path:694be942507619380ea239b13cf13a602f97 0.0.0.0:40067->193.167.100.100:443 IpTos(Cs0, NotEct) len 51 client | TX -> Ack { largest_acknowledged: 1271349745, ack_delay: 5, first_ack_range: 6, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 7, Ce: 0})) } client | 7.429 DEBUG [Client e69b8b1a7fdf0af1] output_path send_profile SendProfile { limit: 1224, pto: None, probe: EnumSet(), paced: false } client | 7.429 DEBUG Building Short dcid Some(CID [18]: 694be942507619380ea239b13cf13a602f97) client | 7.429 DEBUG TX blocked, profile=SendProfile { limit: 1224, pto: None, probe: EnumSet(), paced: false } client | 7.429 DEBUG [Client e69b8b1a7fdf0af1] delay duration 80.719814ms client | 7.429 DEBUG Setting timeout of 80.719814ms client | 7.429 DEBUG [Client e69b8b1a7fdf0af1] output_path send_profile SendProfile { limit: 1224, pto: None, probe: EnumSet(), paced: false } client | 7.429 DEBUG Building Short dcid Some(CID [18]: 694be942507619380ea239b13cf13a602f97) client | 7.429 DEBUG TX blocked, profile=SendProfile { limit: 1224, pto: None, probe: EnumSet(), paced: false } client | 7.429 DEBUG [Client e69b8b1a7fdf0af1] delay duration 80.690048ms client | 7.429 DEBUG Setting timeout of 80.690048ms client | 7.430 DEBUG [Client e69b8b1a7fdf0af1] pn=1271349746 type=Short pri-path:694be942507619380ea239b13cf13a602f97 0.0.0.0:40067->193.167.100.100:443 IpTos(Cs0, Ect0) len 1406 client | -> RX Stream { stream_id: 0, offset: 3245, len: 1382, fin: false } client | 7.430 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 436, tv_nsec: 389616131 } client | 7.430 DEBUG [Client e69b8b1a7fdf0af1] output_path send_profile SendProfile { limit: 1224, pto: None, probe: EnumSet(), paced: false } client | 7.430 DEBUG Building Short dcid Some(CID [18]: 694be942507619380ea239b13cf13a602f97) client | 7.430 DEBUG TX blocked, profile=SendProfile { limit: 1224, pto: None, probe: EnumSet(), paced: false } client | 7.430 DEBUG [Client e69b8b1a7fdf0af1] delay duration 19.969133ms client | 7.430 DEBUG Setting timeout of 19.969133ms client | 7.430 DEBUG [Client e69b8b1a7fdf0af1] output_path send_profile SendProfile { limit: 1224, pto: None, probe: EnumSet(), paced: false } client | 7.430 DEBUG Building Short dcid Some(CID [18]: 694be942507619380ea239b13cf13a602f97) client | 7.430 DEBUG TX blocked, profile=SendProfile { limit: 1224, pto: None, probe: EnumSet(), paced: false } client | 7.430 DEBUG [Client e69b8b1a7fdf0af1] delay duration 19.943995ms client | 7.430 DEBUG Setting timeout of 19.943995ms client | 7.431 DEBUG [Client e69b8b1a7fdf0af1] pn=1271349747 type=Short pri-path:694be942507619380ea239b13cf13a602f97 0.0.0.0:40067->193.167.100.100:443 IpTos(Cs0, Ect0) len 1406 client | -> RX Stream { stream_id: 0, offset: 4627, len: 493, fin: true } client | -> RX Padding { len: 889 } client | 7.431 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 436, tv_nsec: 370750624 } client | 7.431 DEBUG [Client e69b8b1a7fdf0af1] output_path send_profile SendProfile { limit: 1224, pto: None, probe: EnumSet(), paced: false } client | 7.431 DEBUG Building Short dcid Some(CID [18]: 694be942507619380ea239b13cf13a602f97) client | 7.431 DEBUG [Client e69b8b1a7fdf0af1] pn=6 type=Short pri-path:694be942507619380ea239b13cf13a602f97 0.0.0.0:40067->193.167.100.100:443 IpTos(Cs0, NotEct) len 51 client | TX -> Ack { largest_acknowledged: 1271349747, ack_delay: 4, first_ack_range: 8, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 9, Ce: 0})) } client | 7.431 DEBUG [Client e69b8b1a7fdf0af1] output_path send_profile SendProfile { limit: 1224, pto: None, probe: EnumSet(), paced: false } client | 7.431 DEBUG Building Short dcid Some(CID [18]: 694be942507619380ea239b13cf13a602f97) client | 7.431 DEBUG TX blocked, profile=SendProfile { limit: 1224, pto: None, probe: EnumSet(), paced: false } client | 7.431 DEBUG [Client e69b8b1a7fdf0af1] delay duration 78.455245ms client | 7.431 DEBUG Setting timeout of 78.455245ms client | 7.431 DEBUG [Client e69b8b1a7fdf0af1] output_path send_profile SendProfile { limit: 1224, pto: None, probe: EnumSet(), paced: false } client | 7.431 DEBUG Building Short dcid Some(CID [18]: 694be942507619380ea239b13cf13a602f97) client | 7.431 DEBUG TX blocked, profile=SendProfile { limit: 1224, pto: None, probe: EnumSet(), paced: false } client | 7.431 DEBUG [Client e69b8b1a7fdf0af1] delay duration 78.377369ms client | 7.431 DEBUG Setting timeout of 78.377369ms client | 7.431 DEBUG [Client e69b8b1a7fdf0af1] State change from Confirmed -> Closing { error: Application(0), timeout: Instant { tv_sec: 436, tv_nsec: 705655928 } } client | 7.431 WARN Unhandled event StateChange(Closing { error: Application(0), timeout: Instant { tv_sec: 436, tv_nsec: 705655928 } }) client | 7.431 DEBUG [Client e69b8b1a7fdf0af1] output_path send_profile SendProfile { limit: 1224, pto: None, probe: EnumSet(), paced: false } client | 7.431 DEBUG Building Short dcid Some(CID [18]: 694be942507619380ea239b13cf13a602f97) client | 7.431 DEBUG [Recvd-ap] immediate_ack at Instant { tv_sec: 436, tv_nsec: 370958333 } client | 7.431 DEBUG [Client e69b8b1a7fdf0af1] pn=7 type=Short pri-path:694be942507619380ea239b13cf13a602f97 0.0.0.0:40067->193.167.100.100:443 IpTos(Cs0, NotEct) len 62 client | TX -> Ack { largest_acknowledged: 1271349747, ack_delay: 25, first_ack_range: 8, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 9, Ce: 0})) } client | TX -> ConnectionClose { error_code: Application(0), frame_type: 0, reason_phrase: "kthxbye!" } client | 7.431 DEBUG Setting timeout of 334.610712ms client | 7.434 DEBUG [Client e69b8b1a7fdf0af1] output_path send_profile SendProfile { limit: 1224, pto: None, probe: EnumSet(), paced: false } client | 7.434 DEBUG Building Short dcid Some(CID [18]: 694be942507619380ea239b13cf13a602f97) client | 7.434 DEBUG [Recvd-ap] immediate_ack at Instant { tv_sec: 436, tv_nsec: 373778918 } client | 7.434 DEBUG [Client e69b8b1a7fdf0af1] pn=8 type=Short pri-path:694be942507619380ea239b13cf13a602f97 0.0.0.0:40067->193.167.100.100:443 IpTos(Cs0, NotEct) len 63 client | TX -> Ack { largest_acknowledged: 1271349747, ack_delay: 378, first_ack_range: 8, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 9, Ce: 0})) } client | TX -> ConnectionClose { error_code: Application(0), frame_type: 0, reason_phrase: "kthxbye!" } client | 7.434 DEBUG Setting timeout of 331.799675ms client | 7.434 DEBUG Setting timeout of 331.789125ms client | 7.463 DEBUG [Client e69b8b1a7fdf0af1] output_path send_profile SendProfile { limit: 1224, pto: None, probe: EnumSet(), paced: false } client | 7.463 DEBUG Building Short dcid Some(CID [18]: 694be942507619380ea239b13cf13a602f97) client | 7.463 DEBUG [Recvd-ap] immediate_ack at Instant { tv_sec: 436, tv_nsec: 402524741 } client | 7.463 DEBUG [Client e69b8b1a7fdf0af1] pn=9 type=Short pri-path:694be942507619380ea239b13cf13a602f97 0.0.0.0:40067->193.167.100.100:443 IpTos(Cs0, NotEct) len 63 client | TX -> Ack { largest_acknowledged: 1271349747, ack_delay: 3971, first_ack_range: 8, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 9, Ce: 0})) } client | TX -> ConnectionClose { error_code: Application(0), frame_type: 0, reason_phrase: "kthxbye!" } client | 7.463 DEBUG Setting timeout of 303.067167ms client | 7.463 DEBUG Setting timeout of 303.056628ms client | 7.766 DEBUG [Client e69b8b1a7fdf0af1] State change from Closing { error: Application(0), timeout: Instant { tv_sec: 436, tv_nsec: 705655928 } } -> Closed(Application(0)) client | 7.766 INFO Closing timer expired client | 7.766 DEBUG Output::None client | 7.766 WARN Unhandled event StateChange(Closed(Application(0))) client | 7.766 DEBUG Timer fired while closed client | 7.766 DEBUG Output::None client exited with code 0 Aborting on container exit... Container server Stopping Container client Stopping Container client Stopped Container server Stopped Container sim Stopping Container sim Stopped 2025-04-30 08:46:24,818 Using the client's key log file. 2025-04-30 08:46:24,831 2025-04-30 08:46:24,832 Using the client's key log file. 2025-04-30 08:46:24,832 Using the client's key log file. 2025-04-30 08:46:24,844 2025-04-30 08:46:24,845 Using the client's key log file. 2025-04-30 08:46:24,845 Using the client's key log file. 2025-04-30 08:46:25,507 Check of downloaded files succeeded. 2025-04-30 08:46:25,844 Server sent 9950 bytes in Handshake CRYPTO frames. 2025-04-30 08:46:26,244 Received a 1252 byte Initial packet from the client. Amplification limit: 3756 2025-04-30 08:46:26,244 Received a 58 byte Handshake packet from the server. Total: 58 2025-04-30 08:46:26,244 Received a 1252 byte Initial packet from the client. Amplification limit: 7512 2025-04-30 08:46:26,244 Received a 1200 byte Handshake packet from the server. Total: 1258 2025-04-30 08:46:26,244 Received a 1200 byte Handshake packet from the server. Total: 2458 2025-04-30 08:46:26,244 Received a 1200 byte Handshake packet from the server. Total: 3658 2025-04-30 08:46:26,244 Received a 1200 byte Handshake packet from the server. Total: 4858 2025-04-30 08:46:26,244 Received a 1200 byte Handshake packet from the server. Total: 6058 2025-04-30 08:46:26,244 Received a 1200 byte Handshake packet from the server. Total: 7258 2025-04-30 08:46:26,244 Received a 254 byte Handshake packet from the server. Total: 7512 2025-04-30 08:46:26,244 Received a 121 byte Initial packet from the client. Amplification limit: 7875