2025-04-30 11:35:52,432 Generated random file: pescrcjysj of size: 5120 2025-04-30 11:35:52,432 Requests: https://server4:443/pescrcjysj 2025-04-30 11:35:52,809 2025-04-30 11:35:52,810 Command: WAITFORSERVER=server:443 CERTS=/tmp/certs_cydrqjp8/ TESTCASE_SERVER=transfer TESTCASE_CLIENT=transfer WWW=/tmp/www_m0_drmlp/ DOWNLOADS=/tmp/download_l7wdqe7o/ SERVER_LOGS=/tmp/logs_server_dcih8kwz CLIENT_LOGS=/tmp/logs_client_ky3614mx 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=privateoctopus/picoquic:latest REQUESTS="https://server4:443/pescrcjysj" docker compose --env-file empty.env up --abort-on-container-exit --timeout 1 sim client server 2025-04-30 11:36:12,114 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 the simulation with setup.sh client | Setting up routes... server | Setting up routes... client | Actual changes: server | 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 | tx-checksum-ip-generic: off server | tx-tcp-segmentation: off [not requested] server | tx-tcp-ecn-segmentation: off [not requested] server | tx-tcp-mangleid-segmentation: off [not requested] server | tx-tcp6-segmentation: off [not requested] server | tx-udp-segmentation: off [not requested] server | tx-checksum-sctp: off server | Endpoint's IPv4 address is 193.167.100.100 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 server | Setup.sh completed server | Starting picoquic server for test: transfer 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 | pescrcjysj server | Starting picoquic server ... server | TEST_PARAMS: -8 -w ./www -L -l /logs/server_log.txt -q /logs/qlog -k /certs/priv.key -c /certs/cert.pem -p 443 -V -0 -d 180000 server | Starting Picoquic server (v1.1.26.1) on port 443, server name = ::, just_once = 0, do_retry = 0 server | No token file present. Will create one as . server | Accept enable multipath: 0. server | Waiting for packets. client | wait-for-it.sh: waiting 30 seconds for sim:57832 sim | server:443 is available after 1.00864401s 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/pescrcjysj ']' 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/pescrcjysj 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:53152 -> 193.167.100.100:443 client | 0.001 DEBUG [CryptoStates] Creating initial cipher state v=Version1, role=Client dcid=5ed761c3c24f6307d7 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:53152->193.167.100.100:443] Make permanent client | 0.001 DEBUG [unv-path:5ed761c3c24f6307d7 0.0.0.0:53152->193.167.100.100:443] set as primary path client | 0.001 DEBUG [pri-unv-path:5ed761c3c24f6307d7 0.0.0.0:53152->193.167.100.100:443] Path validated Instant { tv_sec: 538, tv_nsec: 716975772 } client | 0.001 DEBUG [Client 5ed761c3c24f6307d7] client_start client | 0.001 DEBUG Writing transport parameters, msg=1 client | 0.001 DEBUG [Agent 0x5653c396c270] state -> InProgress client | 0.001 DEBUG [Client 5ed761c3c24f6307d7] State change from Init -> WaitInitial client | 0.001 DEBUG [Client 5ed761c3c24f6307d7] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.001 DEBUG Building Initial dcid Some(CID [9]: 5ed761c3c24f6307d7) scid Some(CID [0]: ) client | 0.001 DEBUG CRYPTO for in offset=0, len=1212 client | 0.001 DEBUG [Client 5ed761c3c24f6307d7] pn=0 type=Initial pri-path:5ed761c3c24f6307d7 0.0.0.0:53152->193.167.100.100:443 IpTos(Cs0, Ect0) len 1252 client | TX -> Crypto { offset: 0, len: 1212 } client | 0.002 DEBUG packet_sent this=0x5653c397f970, pn=0, ps=1252 client | 0.002 DEBUG ECN probing: sent 1 probes client | 0.002 DEBUG [Client 5ed761c3c24f6307d7] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.002 DEBUG Building Initial dcid Some(CID [9]: 5ed761c3c24f6307d7) scid Some(CID [0]: ) client | 0.002 DEBUG CRYPTO for in offset=1212, len=327 client | 0.002 DEBUG [Client 5ed761c3c24f6307d7] pn=1 type=Initial pri-path:5ed761c3c24f6307d7 0.0.0.0:53152->193.167.100.100:443 IpTos(Cs0, Ect0) len 368 client | TX -> Crypto { offset: 1212, len: 327 } client | 0.002 DEBUG [Client 5ed761c3c24f6307d7] pad Initial from 368 to PLPMTU 1252 client | 0.002 DEBUG packet_sent this=0x5653c397f970, pn=1, ps=1252 client | 0.002 DEBUG ECN probing: sent 2 probes client | 0.002 DEBUG [Client 5ed761c3c24f6307d7] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } client | 0.002 DEBUG Building Initial dcid Some(CID [9]: 5ed761c3c24f6307d7) 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 5ed761c3c24f6307d7] delay duration 3.895969ms client | 0.002 DEBUG Setting timeout of 3.895969ms client | 0.002 DEBUG StateChange(WaitInitial) client | 0.002 WARN Cannot create stream ConnectionState client | 0.002 DEBUG [Client 5ed761c3c24f6307d7] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } client | 0.002 DEBUG Building Initial dcid Some(CID [9]: 5ed761c3c24f6307d7) 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 5ed761c3c24f6307d7] delay duration 3.871052ms client | 0.002 DEBUG Setting timeout of 3.871052ms client | 0.007 DEBUG [Client 5ed761c3c24f6307d7] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.007 DEBUG Building Initial dcid Some(CID [9]: 5ed761c3c24f6307d7) 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 5ed761c3c24f6307d7] delay duration 294.806442ms client | 0.007 DEBUG Setting timeout of 294.806442ms sim | Dropping packet 2 (1252 bytes) from 193.167.0.100 client | 0.038 DEBUG [Client 5ed761c3c24f6307d7] pn=69800 type=Initial pri-path:5ed761c3c24f6307d7 0.0.0.0:53152->193.167.100.100:443 IpTos(Cs0, Ect1) len 46 client | -> RX Ack { largest_acknowledged: 0, ack_delay: 26, first_ack_range: 0, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 1, Ce: 0})) } client | 0.038 DEBUG [Client 5ed761c3c24f6307d7] Rx ACK space=in, ranges=[0..=0] client | 0.038 DEBUG [LossRecovery] ACK for Initial - largest_acked=0 client | 0.038 DEBUG on_packets_acked this=0x5653c397f970, limited=1, bytes_in_flight=1252, cwnd=12520, state=SlowStart, new_acked=1252 client | 0.038 DEBUG Acked crypto frame space=in offset=0 length=1212 client | 0.038 DEBUG [Client 5ed761c3c24f6307d7] Changing to use Server CID=6a03fd9d9c04f334 client | 0.038 DEBUG [Client 5ed761c3c24f6307d7] State change from WaitInitial -> WaitVersion client | 0.038 DEBUG [Client 5ed761c3c24f6307d7] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.038 DEBUG Building Initial dcid Some(CID [8]: 6a03fd9d9c04f334) scid Some(CID [0]: ) client | 0.038 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.038 DEBUG [Client 5ed761c3c24f6307d7] delay duration 74.811965ms client | 0.038 DEBUG Setting timeout of 74.811965ms client | 0.038 WARN Unhandled event StateChange(WaitVersion) client | 0.038 DEBUG [Client 5ed761c3c24f6307d7] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.038 DEBUG Building Initial dcid Some(CID [8]: 6a03fd9d9c04f334) scid Some(CID [0]: ) client | 0.038 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.038 DEBUG [Client 5ed761c3c24f6307d7] delay duration 74.781699ms client | 0.038 DEBUG Setting timeout of 74.781699ms client | 0.114 DEBUG [LossRecovery] PTO timer fired for Initial client | 0.114 DEBUG [Client 5ed761c3c24f6307d7] Lost: Crypto(CryptoRecoveryToken { space: Initial, offset: 1212, length: 327 }) client | 0.114 INFO Lost crypto frame space=in offset=1212 length=327 client | 0.114 DEBUG [Client 5ed761c3c24f6307d7] Lost: EcnEct0 client | 0.114 DEBUG [Client 5ed761c3c24f6307d7] output_path send_profile SendProfile { limit: 1252, pto: Some(Initial), probe: EnumSet(Initial), paced: false } client | 0.114 DEBUG Building Initial dcid Some(CID [8]: 6a03fd9d9c04f334) scid Some(CID [0]: ) client | 0.114 DEBUG CRYPTO for in offset=1212, len=327 client | 0.114 DEBUG [Client 5ed761c3c24f6307d7] pn=2 type=Initial pri-path:6a03fd9d9c04f334 0.0.0.0:53152->193.167.100.100:443 IpTos(Cs0, Ect0) len 367 client | TX -> Crypto { offset: 1212, len: 327 } client | 0.114 DEBUG [Client 5ed761c3c24f6307d7] pad Initial from 367 to PLPMTU 1252 client | 0.114 DEBUG packet_sent this=0x5653c397f970, pn=2, ps=1252 client | 0.114 DEBUG ECN probing: sent 3 probes client | 0.114 DEBUG [Client 5ed761c3c24f6307d7] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.114 DEBUG Building Initial dcid Some(CID [8]: 6a03fd9d9c04f334) scid Some(CID [0]: ) client | 0.114 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.114 DEBUG [Client 5ed761c3c24f6307d7] delay duration 223.077501ms client | 0.114 DEBUG Setting timeout of 223.077501ms sim | Dropping packet 3 (1252 bytes) from 193.167.0.100 client | 0.338 DEBUG [LossRecovery] PTO timer fired for Initial client | 0.338 DEBUG [Client 5ed761c3c24f6307d7] Lost: Crypto(CryptoRecoveryToken { space: Initial, offset: 1212, length: 327 }) client | 0.338 INFO Lost crypto frame space=in offset=1212 length=327 client | 0.338 DEBUG [Client 5ed761c3c24f6307d7] Lost: EcnEct0 client | 0.338 DEBUG [Client 5ed761c3c24f6307d7] output_path send_profile SendProfile { limit: 1252, pto: Some(Initial), probe: EnumSet(Initial), paced: false } client | 0.338 DEBUG Building Initial dcid Some(CID [8]: 6a03fd9d9c04f334) scid Some(CID [0]: ) client | 0.338 DEBUG CRYPTO for in offset=1212, len=327 client | 0.338 DEBUG [Client 5ed761c3c24f6307d7] pn=3 type=Initial pri-path:6a03fd9d9c04f334 0.0.0.0:53152->193.167.100.100:443 IpTos(Cs0, Ect0) len 367 client | TX -> Crypto { offset: 1212, len: 327 } client | 0.338 DEBUG [Client 5ed761c3c24f6307d7] pad Initial from 367 to PLPMTU 1252 client | 0.338 DEBUG packet_sent this=0x5653c397f970, pn=3, ps=1252 client | 0.338 DEBUG ECN probing: sent 4 probes client | 0.338 DEBUG [Client 5ed761c3c24f6307d7] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.338 DEBUG Building Initial dcid Some(CID [8]: 6a03fd9d9c04f334) scid Some(CID [0]: ) client | 0.338 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.338 DEBUG [Client 5ed761c3c24f6307d7] delay duration 446.208462ms client | 0.338 DEBUG Setting timeout of 446.208462ms sim | Dropping packet 4 (1252 bytes) from 193.167.0.100 client | 0.786 DEBUG [LossRecovery] PTO timer fired for Initial client | 0.786 DEBUG [Client 5ed761c3c24f6307d7] Lost: Crypto(CryptoRecoveryToken { space: Initial, offset: 1212, length: 327 }) client | 0.786 INFO Lost crypto frame space=in offset=1212 length=327 client | 0.786 DEBUG [Client 5ed761c3c24f6307d7] Lost: EcnEct0 client | 0.786 DEBUG [Client 5ed761c3c24f6307d7] output_path send_profile SendProfile { limit: 1252, pto: Some(Initial), probe: EnumSet(Initial), paced: false } client | 0.786 DEBUG Building Initial dcid Some(CID [8]: 6a03fd9d9c04f334) scid Some(CID [0]: ) client | 0.786 DEBUG CRYPTO for in offset=1212, len=327 client | 0.786 DEBUG [Client 5ed761c3c24f6307d7] pn=4 type=Initial pri-path:6a03fd9d9c04f334 0.0.0.0:53152->193.167.100.100:443 IpTos(Cs0, Ect0) len 367 client | TX -> Crypto { offset: 1212, len: 327 } client | 0.786 DEBUG [Client 5ed761c3c24f6307d7] pad Initial from 367 to PLPMTU 1252 client | 0.786 DEBUG packet_sent this=0x5653c397f970, pn=4, ps=1252 client | 0.786 DEBUG ECN probing: sent 5 probes client | 0.786 DEBUG [Client 5ed761c3c24f6307d7] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.786 DEBUG Building Initial dcid Some(CID [8]: 6a03fd9d9c04f334) scid Some(CID [0]: ) client | 0.786 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.786 DEBUG [Client 5ed761c3c24f6307d7] delay duration 892.619832ms client | 0.786 DEBUG Setting timeout of 892.619832ms sim | Dropping packet 5 (1252 bytes) from 193.167.0.100 client | 1.680 DEBUG [LossRecovery] PTO timer fired for Initial client | 1.680 DEBUG [Client 5ed761c3c24f6307d7] Lost: Crypto(CryptoRecoveryToken { space: Initial, offset: 1212, length: 327 }) client | 1.680 INFO Lost crypto frame space=in offset=1212 length=327 client | 1.680 DEBUG [Client 5ed761c3c24f6307d7] Lost: EcnEct0 client | 1.680 DEBUG [Client 5ed761c3c24f6307d7] output_path send_profile SendProfile { limit: 1252, pto: Some(Initial), probe: EnumSet(Initial), paced: false } client | 1.680 DEBUG Building Initial dcid Some(CID [8]: 6a03fd9d9c04f334) scid Some(CID [0]: ) client | 1.680 DEBUG CRYPTO for in offset=1212, len=327 client | 1.680 DEBUG [Client 5ed761c3c24f6307d7] pn=5 type=Initial pri-path:6a03fd9d9c04f334 0.0.0.0:53152->193.167.100.100:443 IpTos(Cs0, Ect0) len 367 client | TX -> Crypto { offset: 1212, len: 327 } client | 1.680 DEBUG [Client 5ed761c3c24f6307d7] pad Initial from 367 to PLPMTU 1252 client | 1.680 DEBUG packet_sent this=0x5653c397f970, pn=5, ps=1252 client | 1.680 DEBUG ECN probing: sent 6 probes client | 1.680 DEBUG [Client 5ed761c3c24f6307d7] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 1.680 DEBUG Building Initial dcid Some(CID [8]: 6a03fd9d9c04f334) scid Some(CID [0]: ) client | 1.680 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 1.680 DEBUG [Client 5ed761c3c24f6307d7] delay duration 1.785411536s client | 1.680 DEBUG Setting timeout of 1.785411536s sim | Dropping packet 6 (1252 bytes) from 193.167.0.100 client | 3.467 DEBUG [LossRecovery] PTO timer fired for Initial client | 3.467 DEBUG [Client 5ed761c3c24f6307d7] Lost: Crypto(CryptoRecoveryToken { space: Initial, offset: 1212, length: 327 }) client | 3.467 INFO Lost crypto frame space=in offset=1212 length=327 client | 3.467 DEBUG [Client 5ed761c3c24f6307d7] Lost: EcnEct0 client | 3.467 DEBUG [Client 5ed761c3c24f6307d7] output_path send_profile SendProfile { limit: 1252, pto: Some(Initial), probe: EnumSet(Initial), paced: false } client | 3.467 DEBUG Building Initial dcid Some(CID [8]: 6a03fd9d9c04f334) scid Some(CID [0]: ) client | 3.467 DEBUG CRYPTO for in offset=1212, len=327 client | 3.467 DEBUG [Client 5ed761c3c24f6307d7] pn=6 type=Initial pri-path:6a03fd9d9c04f334 0.0.0.0:53152->193.167.100.100:443 IpTos(Cs0, Ect0) len 367 client | TX -> Crypto { offset: 1212, len: 327 } client | 3.467 DEBUG [Client 5ed761c3c24f6307d7] pad Initial from 367 to PLPMTU 1252 client | 3.467 DEBUG packet_sent this=0x5653c397f970, pn=6, ps=1252 client | 3.467 DEBUG ECN probing: sent 7 probes client | 3.468 DEBUG [Client 5ed761c3c24f6307d7] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 3.468 DEBUG Building Initial dcid Some(CID [8]: 6a03fd9d9c04f334) scid Some(CID [0]: ) client | 3.468 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 3.468 DEBUG [Client 5ed761c3c24f6307d7] delay duration 3.570993399s client | 3.468 DEBUG Setting timeout of 3.570993399s sim | Dropping packet 7 (1252 bytes) from 193.167.0.100 client | 7.043 DEBUG [LossRecovery] PTO timer fired for Initial client | 7.043 DEBUG [Client 5ed761c3c24f6307d7] Lost: Crypto(CryptoRecoveryToken { space: Initial, offset: 1212, length: 327 }) client | 7.043 INFO Lost crypto frame space=in offset=1212 length=327 client | 7.043 DEBUG [Client 5ed761c3c24f6307d7] Lost: EcnEct0 client | 7.043 DEBUG [Client 5ed761c3c24f6307d7] output_path send_profile SendProfile { limit: 1252, pto: Some(Initial), probe: EnumSet(Initial), paced: false } client | 7.043 DEBUG Building Initial dcid Some(CID [8]: 6a03fd9d9c04f334) scid Some(CID [0]: ) client | 7.043 DEBUG CRYPTO for in offset=1212, len=327 client | 7.043 DEBUG [Client 5ed761c3c24f6307d7] pn=7 type=Initial pri-path:6a03fd9d9c04f334 0.0.0.0:53152->193.167.100.100:443 IpTos(Cs0, Ect0) len 367 client | TX -> Crypto { offset: 1212, len: 327 } client | 7.043 DEBUG [Client 5ed761c3c24f6307d7] pad Initial from 367 to PLPMTU 1252 client | 7.043 DEBUG packet_sent this=0x5653c397f970, pn=7, ps=1252 client | 7.043 DEBUG ECN probing: sent 8 probes client | 7.043 DEBUG [Client 5ed761c3c24f6307d7] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.043 DEBUG Building Initial dcid Some(CID [8]: 6a03fd9d9c04f334) scid Some(CID [0]: ) client | 7.043 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.043 DEBUG [Client 5ed761c3c24f6307d7] delay duration 7.142204865s client | 7.043 DEBUG Setting timeout of 7.142204865s client | 7.077 DEBUG [Client 5ed761c3c24f6307d7] pn=69801 type=Initial pri-path:6a03fd9d9c04f334 0.0.0.0:53152->193.167.100.100:443 IpTos(Cs0, Ect1) len 143 client | -> RX Ack { largest_acknowledged: 7, ack_delay: 75, 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.077 DEBUG [Client 5ed761c3c24f6307d7] Rx ACK space=in, ranges=[7..=7, 0..=0] client | 7.077 DEBUG [LossRecovery] ACK for Initial - largest_acked=7 client | 7.077 DEBUG packet_lost this=0x5653c397f970, pn=1, ps=1252 client | 7.077 DEBUG packet_lost this=0x5653c397f970, pn=2, ps=1252 client | 7.077 DEBUG packet_lost this=0x5653c397f970, pn=3, ps=1252 client | 7.077 DEBUG packet_lost this=0x5653c397f970, pn=4, ps=1252 client | 7.077 DEBUG packet_lost this=0x5653c397f970, pn=5, ps=1252 client | 7.077 DEBUG packet_lost this=0x5653c397f970, pn=6, ps=1252 client | 7.077 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.077 DEBUG [Cubic [last_max_cwnd: 12520, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 1252/8764 ssthresh 8764] state -> RecoveryStart client | 7.077 INFO [Cubic [last_max_cwnd: 12520, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 1252/8764 ssthresh 8764] persistent congestion client | 7.077 DEBUG [Cubic [last_max_cwnd: 12520, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 1252/2504 ssthresh 8764] state -> PersistentCongestion client | 7.077 DEBUG on_packets_lost this=0x5653c397f970, bytes_in_flight=1252, cwnd=2504, state=PersistentCongestion client | 7.077 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.077 DEBUG [Cubic [last_max_cwnd: 12520, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 0/2504 ssthresh 8764] on_packets_acked this=0x5653c397f970, limited=0, bytes_in_flight=0, cwnd=2504, state=PersistentCongestion, new_acked=0 client | 7.077 DEBUG Acked crypto frame space=in offset=1212 length=327 client | 7.077 DEBUG [Client 5ed761c3c24f6307d7] Lost: Crypto(CryptoRecoveryToken { space: Initial, offset: 1212, length: 327 }) client | 7.077 INFO Lost crypto frame space=in offset=1212 length=327 client | 7.077 DEBUG [Client 5ed761c3c24f6307d7] Lost: EcnEct0 client | 7.077 DEBUG [Client 5ed761c3c24f6307d7] Lost: Crypto(CryptoRecoveryToken { space: Initial, offset: 1212, length: 327 }) client | 7.077 INFO Lost crypto frame space=in offset=1212 length=327 client | 7.077 DEBUG [Client 5ed761c3c24f6307d7] Lost: EcnEct0 client | 7.077 DEBUG [Client 5ed761c3c24f6307d7] Lost: Crypto(CryptoRecoveryToken { space: Initial, offset: 1212, length: 327 }) client | 7.077 INFO Lost crypto frame space=in offset=1212 length=327 client | 7.077 DEBUG [Client 5ed761c3c24f6307d7] Lost: EcnEct0 client | 7.077 DEBUG [Client 5ed761c3c24f6307d7] Lost: Crypto(CryptoRecoveryToken { space: Initial, offset: 1212, length: 327 }) client | 7.077 INFO Lost crypto frame space=in offset=1212 length=327 client | 7.077 DEBUG [Client 5ed761c3c24f6307d7] Lost: EcnEct0 client | 7.077 DEBUG [Client 5ed761c3c24f6307d7] Lost: Crypto(CryptoRecoveryToken { space: Initial, offset: 1212, length: 327 }) client | 7.077 INFO Lost crypto frame space=in offset=1212 length=327 client | 7.077 DEBUG [Client 5ed761c3c24f6307d7] Lost: EcnEct0 client | 7.077 DEBUG [Client 5ed761c3c24f6307d7] Lost: Crypto(CryptoRecoveryToken { space: Initial, offset: 1212, length: 327 }) client | 7.077 INFO Lost crypto frame space=in offset=1212 length=327 client | 7.077 DEBUG [Client 5ed761c3c24f6307d7] Lost: EcnEct0 client | 7.077 DEBUG Read Ok(90) bytes client | 7.077 DEBUG Write secret available for Handshake: SymKey [32]: d1aad754315588445dd540d6bbf22b33613501baa9d59a0b6532890d1498b367 client | 7.077 DEBUG Read secret available for Handshake: SymKey [32]: 382a60c49900da0fce6c13552f3c1bfd40eedf41be5f36f4a8f8e7a8eaa36c87 client | 7.077 DEBUG [Agent 0x5653c396c270] state -> InProgress client | 7.077 DEBUG Making Write Handshake CryptoDxState, v=Version1 cipher=4865 client | 7.077 DEBUG Making Read Handshake CryptoDxState, v=Version1 cipher=4865 client | 7.077 DEBUG [Crypto] Handshake keys installed client | 7.077 DEBUG [Recvd-in] Set ACK timer to Instant { tv_sec: 545, tv_nsec: 792989525 } client | 7.077 DEBUG [Client 5ed761c3c24f6307d7] State change from WaitVersion -> Handshaking client | 7.077 DEBUG [Client 5ed761c3c24f6307d7] pn=0 type=Handshake pri-path:6a03fd9d9c04f334 0.0.0.0:53152->193.167.100.100:443 IpTos(Cs0, Ect1) len 1109 client | -> RX Crypto { offset: 0, len: 1068 } client | 7.077 DEBUG Read Ok(1068) bytes client | 7.077 DEBUG [Agent 0x5653c396c270] state -> InProgress client | 7.077 DEBUG [Recvd-hs] Set ACK timer to Instant { tv_sec: 545, tv_nsec: 792989525 } client | 7.077 DEBUG [Client 5ed761c3c24f6307d7] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.077 DEBUG Building Initial dcid Some(CID [8]: 6a03fd9d9c04f334) scid Some(CID [0]: ) client | 7.077 DEBUG [Client 5ed761c3c24f6307d7] pn=8 type=Initial pri-path:6a03fd9d9c04f334 0.0.0.0:53152->193.167.100.100:443 IpTos(Cs0, Ect0) len 47 client | TX -> Ack { largest_acknowledged: 69801, ack_delay: 100, first_ack_range: 1, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 2, Ect0: 0, Ce: 0})) } client | 7.077 DEBUG Building Handshake dcid Some(CID [8]: 6a03fd9d9c04f334) scid Some(CID [0]: ) client | 7.077 DEBUG [Client 5ed761c3c24f6307d7] pn=0 type=Handshake pri-path:6a03fd9d9c04f334 0.0.0.0:53152->193.167.100.100:443 IpTos(Cs0, Ect0) len 90 client | TX -> Ack { largest_acknowledged: 0, ack_delay: 100, first_ack_range: 0, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 1, Ect0: 0, Ce: 0})) } client | 7.077 DEBUG [Client 5ed761c3c24f6307d7] Drop packet number space in client | 7.077 DEBUG [LossRecovery] Reset loss recovery state for Initial client | 7.077 WARN [LossRecovery] ignoring in-8 from dropped space client | 7.077 DEBUG ECN probing: sent 9 probes client | 7.078 DEBUG [Client 5ed761c3c24f6307d7] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.078 DEBUG Building Handshake dcid Some(CID [8]: 6a03fd9d9c04f334) scid Some(CID [0]: ) client | 7.078 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.078 DEBUG [Client 5ed761c3c24f6307d7] delay duration 96.250047ms client | 7.078 DEBUG Setting timeout of 96.250047ms client | 7.078 DEBUG StateChange(Handshaking) client | 7.078 WARN Cannot create stream ConnectionState client | 7.078 DEBUG stream BiDi creatable client | 7.078 WARN Cannot create stream ConnectionState client | 7.078 DEBUG stream UniDi creatable client | 7.078 DEBUG [Client 5ed761c3c24f6307d7] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.078 DEBUG Building Handshake dcid Some(CID [8]: 6a03fd9d9c04f334) scid Some(CID [0]: ) client | 7.078 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.078 DEBUG [Client 5ed761c3c24f6307d7] delay duration 96.21448ms client | 7.078 DEBUG Setting timeout of 96.21448ms client | 7.078 DEBUG [Client 5ed761c3c24f6307d7] pn=1 type=Handshake pri-path:6a03fd9d9c04f334 0.0.0.0:53152->193.167.100.100:443 IpTos(Cs0, Ect1) len 1252 client | -> RX Crypto { offset: 1068, len: 1210 } client | 7.078 DEBUG Read Ok(1210) bytes client | 7.078 DEBUG [Agent 0x5653c396c270] state -> InProgress client | 7.078 DEBUG [Recvd-hs] Set ACK timer to Instant { tv_sec: 545, tv_nsec: 794086637 } client | 7.078 DEBUG [Client 5ed761c3c24f6307d7] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.078 DEBUG Building Handshake dcid Some(CID [8]: 6a03fd9d9c04f334) scid Some(CID [0]: ) client | 7.078 DEBUG [Client 5ed761c3c24f6307d7] pn=1 type=Handshake pri-path:6a03fd9d9c04f334 0.0.0.0:53152->193.167.100.100:443 IpTos(Cs0, Ect0) len 42 client | TX -> Ack { largest_acknowledged: 1, ack_delay: 6, first_ack_range: 1, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 2, Ect0: 0, Ce: 0})) } client | 7.078 DEBUG ECN probing: sent 10 probes client | 7.078 DEBUG ECN probing concluded with 10 probes sent client | 7.078 DEBUG [Client 5ed761c3c24f6307d7] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.078 DEBUG Building Handshake dcid Some(CID [8]: 6a03fd9d9c04f334) scid Some(CID [0]: ) client | 7.078 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.078 DEBUG [Client 5ed761c3c24f6307d7] delay duration 95.962206ms client | 7.078 DEBUG Setting timeout of 95.962206ms client | 7.078 DEBUG stream BiDi creatable client | 7.078 WARN Cannot create stream ConnectionState client | 7.078 DEBUG stream UniDi creatable client | 7.078 DEBUG [Client 5ed761c3c24f6307d7] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.078 DEBUG Building Handshake dcid Some(CID [8]: 6a03fd9d9c04f334) scid Some(CID [0]: ) client | 7.078 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.078 DEBUG [Client 5ed761c3c24f6307d7] delay duration 95.93803ms client | 7.078 DEBUG Setting timeout of 95.93803ms client | 7.079 DEBUG [Client 5ed761c3c24f6307d7] pn=2 type=Handshake pri-path:6a03fd9d9c04f334 0.0.0.0:53152->193.167.100.100:443 IpTos(Cs0, Ect1) len 1252 client | -> RX Crypto { offset: 2278, len: 1210 } client | 7.079 DEBUG Read Ok(1210) bytes client | 7.079 DEBUG [Agent 0x5653c396c270] state -> InProgress client | 7.079 DEBUG [Recvd-hs] Set ACK timer to Instant { tv_sec: 545, tv_nsec: 794988890 } client | 7.079 DEBUG [Client 5ed761c3c24f6307d7] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.079 DEBUG Building Handshake dcid Some(CID [8]: 6a03fd9d9c04f334) scid Some(CID [0]: ) client | 7.079 DEBUG [Client 5ed761c3c24f6307d7] pn=2 type=Handshake pri-path:6a03fd9d9c04f334 0.0.0.0:53152->193.167.100.100:443 IpTos(Cs0, NotEct) len 42 client | TX -> Ack { largest_acknowledged: 2, ack_delay: 6, first_ack_range: 2, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 3, Ect0: 0, Ce: 0})) } client | 7.079 DEBUG [Client 5ed761c3c24f6307d7] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.079 DEBUG Building Handshake dcid Some(CID [8]: 6a03fd9d9c04f334) scid Some(CID [0]: ) client | 7.079 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.079 DEBUG [Client 5ed761c3c24f6307d7] delay duration 95.070152ms client | 7.079 DEBUG Setting timeout of 95.070152ms client | 7.079 DEBUG stream BiDi creatable client | 7.079 WARN Cannot create stream ConnectionState client | 7.079 DEBUG stream UniDi creatable client | 7.079 DEBUG [Client 5ed761c3c24f6307d7] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.079 DEBUG Building Handshake dcid Some(CID [8]: 6a03fd9d9c04f334) scid Some(CID [0]: ) client | 7.079 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.079 DEBUG [Client 5ed761c3c24f6307d7] delay duration 95.041819ms client | 7.079 DEBUG Setting timeout of 95.041819ms client | 7.080 DEBUG [Client 5ed761c3c24f6307d7] pn=3 type=Handshake pri-path:6a03fd9d9c04f334 0.0.0.0:53152->193.167.100.100:443 IpTos(Cs0, Ect1) len 1252 client | -> RX Crypto { offset: 3488, len: 1210 } client | 7.080 DEBUG Read Ok(1210) bytes client | 7.080 DEBUG [Agent 0x5653c396c270] state -> InProgress client | 7.080 DEBUG [Recvd-hs] Set ACK timer to Instant { tv_sec: 545, tv_nsec: 796046957 } client | 7.080 DEBUG [Client 5ed761c3c24f6307d7] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.080 DEBUG Building Handshake dcid Some(CID [8]: 6a03fd9d9c04f334) scid Some(CID [0]: ) client | 7.080 DEBUG [Client 5ed761c3c24f6307d7] pn=3 type=Handshake pri-path:6a03fd9d9c04f334 0.0.0.0:53152->193.167.100.100:443 IpTos(Cs0, NotEct) len 42 client | TX -> Ack { largest_acknowledged: 3, ack_delay: 4, first_ack_range: 3, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 4, Ect0: 0, Ce: 0})) } client | 7.080 DEBUG [Client 5ed761c3c24f6307d7] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.080 DEBUG Building Handshake dcid Some(CID [8]: 6a03fd9d9c04f334) scid Some(CID [0]: ) client | 7.080 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.080 DEBUG [Client 5ed761c3c24f6307d7] delay duration 94.004451ms client | 7.080 DEBUG Setting timeout of 94.004451ms client | 7.080 DEBUG stream BiDi creatable client | 7.080 WARN Cannot create stream ConnectionState client | 7.080 DEBUG stream UniDi creatable client | 7.080 DEBUG [Client 5ed761c3c24f6307d7] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.080 DEBUG Building Handshake dcid Some(CID [8]: 6a03fd9d9c04f334) scid Some(CID [0]: ) client | 7.080 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.080 DEBUG [Client 5ed761c3c24f6307d7] delay duration 93.972451ms client | 7.080 DEBUG Setting timeout of 93.972451ms client | 7.081 DEBUG [Client 5ed761c3c24f6307d7] pn=4 type=Handshake pri-path:6a03fd9d9c04f334 0.0.0.0:53152->193.167.100.100:443 IpTos(Cs0, Ect1) len 1252 client | -> RX Crypto { offset: 4698, len: 1210 } client | 7.081 DEBUG Read Ok(1210) bytes client | 7.081 DEBUG [Agent 0x5653c396c270] state -> InProgress client | 7.081 DEBUG [Recvd-hs] Set ACK timer to Instant { tv_sec: 545, tv_nsec: 797068816 } client | 7.081 DEBUG [Client 5ed761c3c24f6307d7] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.081 DEBUG Building Handshake dcid Some(CID [8]: 6a03fd9d9c04f334) scid Some(CID [0]: ) client | 7.081 DEBUG [Client 5ed761c3c24f6307d7] pn=4 type=Handshake pri-path:6a03fd9d9c04f334 0.0.0.0:53152->193.167.100.100:443 IpTos(Cs0, NotEct) len 42 client | TX -> Ack { largest_acknowledged: 4, ack_delay: 3, first_ack_range: 4, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 5, Ect0: 0, Ce: 0})) } client | 7.081 DEBUG [Client 5ed761c3c24f6307d7] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.081 DEBUG Building Handshake dcid Some(CID [8]: 6a03fd9d9c04f334) scid Some(CID [0]: ) client | 7.081 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.081 DEBUG [Client 5ed761c3c24f6307d7] delay duration 93.01355ms client | 7.081 DEBUG Setting timeout of 93.01355ms client | 7.081 DEBUG stream BiDi creatable client | 7.081 WARN Cannot create stream ConnectionState client | 7.081 DEBUG stream UniDi creatable client | 7.081 DEBUG [Client 5ed761c3c24f6307d7] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.081 DEBUG Building Handshake dcid Some(CID [8]: 6a03fd9d9c04f334) scid Some(CID [0]: ) client | 7.081 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.081 DEBUG [Client 5ed761c3c24f6307d7] delay duration 92.985006ms client | 7.081 DEBUG Setting timeout of 92.985006ms client | 7.082 DEBUG [Client 5ed761c3c24f6307d7] pn=5 type=Handshake pri-path:6a03fd9d9c04f334 0.0.0.0:53152->193.167.100.100:443 IpTos(Cs0, Ect1) len 1252 client | -> RX Crypto { offset: 5908, len: 1210 } client | 7.082 DEBUG Read Ok(1210) bytes client | 7.082 DEBUG [Agent 0x5653c396c270] state -> InProgress client | 7.082 DEBUG [Recvd-hs] Set ACK timer to Instant { tv_sec: 545, tv_nsec: 798077521 } client | 7.082 DEBUG [Client 5ed761c3c24f6307d7] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.082 DEBUG Building Handshake dcid Some(CID [8]: 6a03fd9d9c04f334) scid Some(CID [0]: ) client | 7.082 DEBUG [Client 5ed761c3c24f6307d7] pn=5 type=Handshake pri-path:6a03fd9d9c04f334 0.0.0.0:53152->193.167.100.100:443 IpTos(Cs0, NotEct) len 42 client | TX -> Ack { largest_acknowledged: 5, ack_delay: 4, first_ack_range: 5, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 6, Ect0: 0, Ce: 0})) } client | 7.082 DEBUG [Client 5ed761c3c24f6307d7] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.082 DEBUG Building Handshake dcid Some(CID [8]: 6a03fd9d9c04f334) scid Some(CID [0]: ) client | 7.082 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.082 DEBUG [Client 5ed761c3c24f6307d7] delay duration 91.997902ms client | 7.082 DEBUG Setting timeout of 91.997902ms client | 7.082 DEBUG stream BiDi creatable client | 7.082 WARN Cannot create stream ConnectionState client | 7.082 DEBUG stream UniDi creatable client | 7.082 DEBUG [Client 5ed761c3c24f6307d7] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.082 DEBUG Building Handshake dcid Some(CID [8]: 6a03fd9d9c04f334) scid Some(CID [0]: ) client | 7.082 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.082 DEBUG [Client 5ed761c3c24f6307d7] delay duration 91.969459ms client | 7.082 DEBUG Setting timeout of 91.969459ms client | 7.083 DEBUG [Client 5ed761c3c24f6307d7] pn=6 type=Handshake pri-path:6a03fd9d9c04f334 0.0.0.0:53152->193.167.100.100:443 IpTos(Cs0, Ect1) len 1252 client | -> RX Crypto { offset: 7118, len: 1210 } client | 7.083 DEBUG Read Ok(1210) bytes client | 7.083 DEBUG [Agent 0x5653c396c270] state -> InProgress client | 7.083 DEBUG [Recvd-hs] Set ACK timer to Instant { tv_sec: 545, tv_nsec: 799110902 } client | 7.083 DEBUG [Client 5ed761c3c24f6307d7] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.083 DEBUG Building Handshake dcid Some(CID [8]: 6a03fd9d9c04f334) scid Some(CID [0]: ) client | 7.083 DEBUG [Client 5ed761c3c24f6307d7] pn=6 type=Handshake pri-path:6a03fd9d9c04f334 0.0.0.0:53152->193.167.100.100:443 IpTos(Cs0, NotEct) len 42 client | TX -> Ack { largest_acknowledged: 6, ack_delay: 4, first_ack_range: 6, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 7, Ect0: 0, Ce: 0})) } client | 7.083 DEBUG [Client 5ed761c3c24f6307d7] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.083 DEBUG Building Handshake dcid Some(CID [8]: 6a03fd9d9c04f334) scid Some(CID [0]: ) client | 7.083 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.083 DEBUG [Client 5ed761c3c24f6307d7] delay duration 90.96397ms client | 7.083 DEBUG Setting timeout of 90.96397ms client | 7.083 DEBUG stream BiDi creatable client | 7.083 WARN Cannot create stream ConnectionState client | 7.083 DEBUG stream UniDi creatable client | 7.083 DEBUG [Client 5ed761c3c24f6307d7] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.083 DEBUG Building Handshake dcid Some(CID [8]: 6a03fd9d9c04f334) scid Some(CID [0]: ) client | 7.083 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.083 DEBUG [Client 5ed761c3c24f6307d7] delay duration 90.935597ms client | 7.083 DEBUG Setting timeout of 90.935597ms client | 7.084 DEBUG [Client 5ed761c3c24f6307d7] pn=7 type=Handshake pri-path:6a03fd9d9c04f334 0.0.0.0:53152->193.167.100.100:443 IpTos(Cs0, Ect1) len 1252 client | -> RX Crypto { offset: 8328, len: 1210 } client | 7.084 DEBUG Read Ok(1210) bytes client | 7.084 DEBUG [Agent 0x5653c396c270] state -> InProgress client | 7.084 DEBUG [Recvd-hs] Set ACK timer to Instant { tv_sec: 545, tv_nsec: 800129455 } client | 7.084 DEBUG [Client 5ed761c3c24f6307d7] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.084 DEBUG Building Handshake dcid Some(CID [8]: 6a03fd9d9c04f334) scid Some(CID [0]: ) client | 7.084 DEBUG [Client 5ed761c3c24f6307d7] pn=7 type=Handshake pri-path:6a03fd9d9c04f334 0.0.0.0:53152->193.167.100.100:443 IpTos(Cs0, NotEct) len 42 client | TX -> Ack { largest_acknowledged: 7, ack_delay: 4, first_ack_range: 7, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 8, Ect0: 0, Ce: 0})) } client | 7.084 DEBUG [Client 5ed761c3c24f6307d7] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.084 DEBUG Building Handshake dcid Some(CID [8]: 6a03fd9d9c04f334) scid Some(CID [0]: ) client | 7.084 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.084 DEBUG [Client 5ed761c3c24f6307d7] delay duration 89.944054ms client | 7.084 DEBUG Setting timeout of 89.944054ms client | 7.084 DEBUG stream BiDi creatable client | 7.084 WARN Cannot create stream ConnectionState client | 7.084 DEBUG stream UniDi creatable client | 7.084 DEBUG [Client 5ed761c3c24f6307d7] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.084 DEBUG Building Handshake dcid Some(CID [8]: 6a03fd9d9c04f334) scid Some(CID [0]: ) client | 7.084 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.084 DEBUG [Client 5ed761c3c24f6307d7] delay duration 89.917655ms client | 7.084 DEBUG Setting timeout of 89.917655ms client | 7.085 DEBUG [Client 5ed761c3c24f6307d7] pn=8 type=Handshake pri-path:6a03fd9d9c04f334 0.0.0.0:53152->193.167.100.100:443 IpTos(Cs0, Ect1) len 513 client | -> RX Crypto { offset: 9538, len: 471 } client | 7.085 DEBUG Read Ok(471) bytes client | 7.085 DEBUG [Agent 0x5653c396c270] state -> AuthenticationPending client | 7.085 DEBUG [Recvd-hs] Set ACK timer to Instant { tv_sec: 545, tv_nsec: 800924493 } client | 7.085 DEBUG saving datagram of 439 bytes client | 7.085 DEBUG [Client 5ed761c3c24f6307d7] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.085 DEBUG Building Handshake dcid Some(CID [8]: 6a03fd9d9c04f334) scid Some(CID [0]: ) client | 7.085 DEBUG [Client 5ed761c3c24f6307d7] pn=8 type=Handshake pri-path:6a03fd9d9c04f334 0.0.0.0:53152->193.167.100.100:443 IpTos(Cs0, NotEct) len 43 client | TX -> Ack { largest_acknowledged: 8, ack_delay: 85, first_ack_range: 8, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 9, Ect0: 0, Ce: 0})) } client | 7.085 DEBUG [Client 5ed761c3c24f6307d7] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.085 DEBUG Building Handshake dcid Some(CID [8]: 6a03fd9d9c04f334) scid Some(CID [0]: ) client | 7.085 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.085 DEBUG [Client 5ed761c3c24f6307d7] delay duration 88.49861ms client | 7.085 DEBUG Setting timeout of 88.49861ms client | 7.085 DEBUG [Client 5ed761c3c24f6307d7] Authenticated Ok client | 7.085 DEBUG Write secret available for ApplicationData: SymKey [32]: b943e71fcb70fe6cfcee0f3813f8bb675fec1d78e228fbb2215e51a076986c1c client | 7.085 DEBUG Read secret available for ApplicationData: SymKey [32]: 551f7fa703cec9102c5b666155bcf4922d93bc15cfc9d6bc0da7c7071b14027c client | 7.085 DEBUG [Agent 0x5653c396c270] SSL_AuthCertificateComplete: Ok(()) client | 7.085 DEBUG [Agent 0x5653c396c270] 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.085 DEBUG [Client 5ed761c3c24f6307d7] TLS connection complete client | 7.085 DEBUG Making Write ApplicationData CryptoDxState, v=Version1 cipher=4865 client | 7.085 DEBUG [Crypto] Application write key installed client | 7.085 DEBUG Making Read ApplicationData CryptoDxState, v=Version1 cipher=4865 client | 7.086 DEBUG [Crypto] application read keys installed client | 7.086 DEBUG [Client 5ed761c3c24f6307d7] State change from Handshaking -> Connected client | 7.086 INFO [Client 5ed761c3c24f6307d7] Connection established client | 7.086 DEBUG [Client 5ed761c3c24f6307d7] process saved for epoch ApplicationData client | 7.086 DEBUG [Client 5ed761c3c24f6307d7] pn=0 type=Short pri-path:6a03fd9d9c04f334 0.0.0.0:53152->193.167.100.100:443 IpTos(Cs0, Ect1) len 439 client | -> RX Crypto { offset: 0, len: 133 } client | -> RX NewToken { token: [192, 162, 117, 28, 44, 87, 2, 89, 87, 70, 87, 129, 43, 205, 73, 127, 196, 218, 9, 21, 245, 10, 161, 37, 129, 88, 252, 195, 241, 9, 188, 65, 216, 127, 79, 141, 125, 150, 62, 79, 149, 211, 99, 88, 209, 104, 246, 244, 208, 37] } client | -> RX NewConnectionId { sequence_number: 1, retire_prior: 0, connection_id: [127, 249, 98, 188, 193, 41, 85, 223], stateless_reset_token: [214, 5, 11, 125, 95, 116, 223, 8, 98, 148, 143, 206, 81, 227, 252, 142] } client | -> RX NewConnectionId { sequence_number: 2, retire_prior: 0, connection_id: [113, 196, 114, 64, 197, 233, 220, 169], stateless_reset_token: [156, 51, 203, 162, 101, 85, 218, 82, 148, 200, 216, 177, 203, 218, 131, 156] } client | -> RX NewConnectionId { sequence_number: 3, retire_prior: 0, connection_id: [103, 69, 118, 70, 14, 143, 167, 111], stateless_reset_token: [108, 247, 63, 18, 168, 97, 9, 173, 239, 138, 68, 39, 119, 95, 109, 99] } client | -> RX NewConnectionId { sequence_number: 4, retire_prior: 0, connection_id: [206, 145, 30, 193, 6, 92, 191, 27], stateless_reset_token: [135, 118, 95, 197, 210, 239, 2, 156, 1, 236, 57, 75, 75, 75, 241, 87] } client | -> RX NewConnectionId { sequence_number: 5, retire_prior: 0, connection_id: [28, 191, 131, 193, 148, 164, 39, 138], stateless_reset_token: [189, 47, 180, 180, 212, 205, 228, 41, 56, 30, 36, 135, 116, 247, 176, 243] } client | -> RX NewConnectionId { sequence_number: 6, retire_prior: 0, connection_id: [48, 204, 248, 202, 214, 60, 200, 101], stateless_reset_token: [30, 250, 253, 228, 141, 13, 127, 173, 54, 82, 76, 142, 18, 82, 241, 217] } client | -> RX NewConnectionId { sequence_number: 7, retire_prior: 0, connection_id: [239, 165, 32, 196, 58, 2, 171, 226], stateless_reset_token: [242, 176, 126, 58, 55, 82, 40, 56, 185, 16, 2, 16, 103, 188, 150, 162] } client | -> RX Padding { len: 36 } client | 7.086 DEBUG Read Ok(133) bytes client | 7.086 DEBUG [0x5653c396c270] Got resumption token [5862]: 02000633fd525718..3a395409d159a490 client | 7.086 DEBUG [Agent 0x5653c396c270] 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.086 DEBUG resumption token [6068]: 0000000124409400..3a395409d159a490 client | 7.086 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 545, tv_nsec: 820924493 } client | 7.086 DEBUG stream BiDi creatable client | 7.086 INFO Created stream 0 for https://server4/pescrcjysj client | 7.086 INFO Saving https://server4/pescrcjysj to "/downloads/pescrcjysj" client | 7.086 DEBUG stream UniDi creatable client | 7.086 DEBUG StateChange(Connected) client | 7.086 DEBUG stream 0 writable client | 7.086 DEBUG [Client 5ed761c3c24f6307d7] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.086 DEBUG Building Handshake dcid Some(CID [8]: 6a03fd9d9c04f334) scid Some(CID [0]: ) client | 7.086 DEBUG CRYPTO for hs offset=0, len=36 client | 7.086 DEBUG [Client 5ed761c3c24f6307d7] pn=9 type=Handshake pri-path:6a03fd9d9c04f334 0.0.0.0:53152->193.167.100.100:443 IpTos(Cs0, NotEct) len 73 client | TX -> Crypto { offset: 0, len: 36 } client | 7.086 DEBUG packet_sent this=0x5653c397f970, pn=9, ps=73 client | 7.086 DEBUG Building Short dcid Some(CID [8]: 6a03fd9d9c04f334) client | 7.086 DEBUG [Client 5ed761c3c24f6307d7] pn=0 type=Short pri-path:6a03fd9d9c04f334 0.0.0.0:53152->193.167.100.100:443 IpTos(Cs0, NotEct) len 119 client | TX -> Stream { stream_id: 0, offset: 0, len: 17, fin: true } client | 7.086 DEBUG packet_sent this=0x5653c397f970, pn=0, ps=46 client | 7.086 DEBUG [Client 5ed761c3c24f6307d7] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.086 DEBUG Building Handshake dcid Some(CID [8]: 6a03fd9d9c04f334) scid Some(CID [0]: ) client | 7.086 DEBUG Building Short dcid Some(CID [8]: 6a03fd9d9c04f334) client | 7.086 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.086 DEBUG [Client 5ed761c3c24f6307d7] delay duration 18.582611ms client | 7.086 DEBUG Setting timeout of 18.582611ms client | 7.086 DEBUG [Client 5ed761c3c24f6307d7] pn=1 type=Short pri-path:6a03fd9d9c04f334 0.0.0.0:53152->193.167.100.100:443 IpTos(Cs0, Ect1) len 1440 client | -> RX Ping client | -> RX Padding { len: 1421 } client | 7.086 DEBUG [Recvd-ap] immediate_ack at Instant { tv_sec: 545, tv_nsec: 802374713 } client | 7.086 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 545, tv_nsec: 802374713 } client | 7.086 DEBUG [Client 5ed761c3c24f6307d7] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.086 DEBUG Building Handshake dcid Some(CID [8]: 6a03fd9d9c04f334) scid Some(CID [0]: ) client | 7.086 DEBUG Building Short dcid Some(CID [8]: 6a03fd9d9c04f334) client | 7.086 DEBUG [Client 5ed761c3c24f6307d7] pn=1 type=Short pri-path:6a03fd9d9c04f334 0.0.0.0:53152->193.167.100.100:443 IpTos(Cs0, NotEct) len 34 client | TX -> Ack { largest_acknowledged: 1, ack_delay: 3, first_ack_range: 1, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 2, Ect0: 0, Ce: 0})) } client | 7.086 DEBUG [Client 5ed761c3c24f6307d7] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.086 DEBUG Building Handshake dcid Some(CID [8]: 6a03fd9d9c04f334) scid Some(CID [0]: ) client | 7.086 DEBUG Building Short dcid Some(CID [8]: 6a03fd9d9c04f334) client | 7.086 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.086 DEBUG [Client 5ed761c3c24f6307d7] delay duration 96.170708ms client | 7.086 DEBUG Setting timeout of 96.170708ms client | 7.086 DEBUG [Client 5ed761c3c24f6307d7] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.086 DEBUG Building Handshake dcid Some(CID [8]: 6a03fd9d9c04f334) scid Some(CID [0]: ) client | 7.086 DEBUG Building Short dcid Some(CID [8]: 6a03fd9d9c04f334) client | 7.086 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.086 DEBUG [Client 5ed761c3c24f6307d7] delay duration 96.147484ms client | 7.086 DEBUG Setting timeout of 96.147484ms client | 7.117 DEBUG [Client 5ed761c3c24f6307d7] pn=2 type=Short pri-path:6a03fd9d9c04f334 0.0.0.0:53152->193.167.100.100:443 IpTos(Cs0, Ect1) len 1252 client | -> RX Ack { largest_acknowledged: 0, ack_delay: 11, first_ack_range: 0, ack_ranges: [], ecn_count: None } client | -> RX HandshakeDone client | -> RX Stream { stream_id: 0, offset: 0, len: >>1226, fin: false } client | 7.117 DEBUG [Client 5ed761c3c24f6307d7] Rx ACK space=ap, ranges=[0..=0] client | 7.117 DEBUG [LossRecovery] ACK for ApplicationData - largest_acked=0 client | 7.118 DEBUG [Cubic [last_max_cwnd: 12520, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 73/2550 ssthresh 8764] slow start += 46 client | 7.118 DEBUG [Cubic [last_max_cwnd: 12520, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 73/2550 ssthresh 8764] on_packets_acked this=0x5653c397f970, limited=0, bytes_in_flight=73, cwnd=2550, state=SlowStart, new_acked=46 client | 7.118 DEBUG [Client 5ed761c3c24f6307d7] State change from Connected -> Confirmed client | 7.118 DEBUG PMTUD started with probe size 1380 client | 7.118 DEBUG [Client 5ed761c3c24f6307d7] Drop packet number space hs client | 7.118 DEBUG [LossRecovery] Reset loss recovery state for Handshake client | 7.118 DEBUG [Client 5ed761c3c24f6307d7] No preferred address to migrate to client | 7.118 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 545, tv_nsec: 853875290 } client | 7.118 DEBUG [Client 5ed761c3c24f6307d7] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.118 DEBUG Building Short dcid Some(CID [8]: 6a03fd9d9c04f334) client | 7.118 DEBUG Sending PMTUD probe of size 1380, count 1 client | 7.118 DEBUG [Client 5ed761c3c24f6307d7] pn=2 type=Short pri-path:6a03fd9d9c04f334 0.0.0.0:53152->193.167.100.100:443 IpTos(Cs0, NotEct) len 1352 client | TX -> Ping client | TX -> Padding { len: 1325 } client | 7.118 DEBUG packet_sent this=0x5653c397f970, pn=2, ps=1352 client | 7.118 DEBUG [Client 5ed761c3c24f6307d7] output_path send_profile SendProfile { limit: 1198, pto: None, probe: EnumSet(), paced: false } client | 7.118 DEBUG Building Short dcid Some(CID [8]: 6a03fd9d9c04f334) client | 7.118 DEBUG TX blocked, profile=SendProfile { limit: 1198, pto: None, probe: EnumSet(), paced: false } client | 7.118 DEBUG [Client 5ed761c3c24f6307d7] delay duration 19.824151ms client | 7.118 DEBUG Setting timeout of 19.824151ms client | 7.118 DEBUG stream 0 complete client | 7.118 WARN Unhandled event StateChange(Confirmed) client | 7.118 DEBUG [Client 5ed761c3c24f6307d7] output_path send_profile SendProfile { limit: 1198, pto: None, probe: EnumSet(), paced: false } client | 7.118 DEBUG Building Short dcid Some(CID [8]: 6a03fd9d9c04f334) client | 7.118 DEBUG TX blocked, profile=SendProfile { limit: 1198, pto: None, probe: EnumSet(), paced: false } client | 7.118 DEBUG [Client 5ed761c3c24f6307d7] delay duration 19.787883ms client | 7.118 DEBUG Setting timeout of 19.787883ms client | 7.123 DEBUG [Client 5ed761c3c24f6307d7] pn=3 type=Short pri-path:6a03fd9d9c04f334 0.0.0.0:53152->193.167.100.100:443 IpTos(Cs0, Ect1) len 1440 client | -> RX Stream { stream_id: 0, offset: 1226, len: >>1418, fin: false } client | 7.123 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 545, tv_nsec: 839436611 } client | 7.123 DEBUG [Client 5ed761c3c24f6307d7] output_path send_profile SendProfile { limit: 1198, pto: None, probe: EnumSet(), paced: false } client | 7.123 DEBUG Building Short dcid Some(CID [8]: 6a03fd9d9c04f334) client | 7.123 DEBUG [Client 5ed761c3c24f6307d7] pn=3 type=Short pri-path:6a03fd9d9c04f334 0.0.0.0:53152->193.167.100.100:443 IpTos(Cs0, NotEct) len 34 client | TX -> Ack { largest_acknowledged: 3, ack_delay: 2, first_ack_range: 3, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 4, Ect0: 0, Ce: 0})) } client | 7.123 DEBUG [Client 5ed761c3c24f6307d7] output_path send_profile SendProfile { limit: 1198, pto: None, probe: EnumSet(), paced: false } client | 7.123 DEBUG Building Short dcid Some(CID [8]: 6a03fd9d9c04f334) client | 7.123 DEBUG TX blocked, profile=SendProfile { limit: 1198, pto: None, probe: EnumSet(), paced: false } client | 7.123 DEBUG [Client 5ed761c3c24f6307d7] delay duration 90.369909ms client | 7.123 DEBUG Setting timeout of 90.369909ms client | 7.123 DEBUG [Client 5ed761c3c24f6307d7] output_path send_profile SendProfile { limit: 1198, pto: None, probe: EnumSet(), paced: false } client | 7.123 DEBUG Building Short dcid Some(CID [8]: 6a03fd9d9c04f334) client | 7.123 DEBUG TX blocked, profile=SendProfile { limit: 1198, pto: None, probe: EnumSet(), paced: false } client | 7.123 DEBUG [Client 5ed761c3c24f6307d7] delay duration 90.344652ms client | 7.123 DEBUG Setting timeout of 90.344652ms client | 7.130 DEBUG [Client 5ed761c3c24f6307d7] pn=4 type=Short pri-path:6a03fd9d9c04f334 0.0.0.0:53152->193.167.100.100:443 IpTos(Cs0, Ect1) len 1440 client | -> RX Stream { stream_id: 0, offset: 2644, len: >>1418, fin: false } client | 7.130 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 545, tv_nsec: 866795380 } client | 7.130 DEBUG [Client 5ed761c3c24f6307d7] output_path send_profile SendProfile { limit: 1198, pto: None, probe: EnumSet(), paced: false } client | 7.130 DEBUG Building Short dcid Some(CID [8]: 6a03fd9d9c04f334) client | 7.130 DEBUG TX blocked, profile=SendProfile { limit: 1198, pto: None, probe: EnumSet(), paced: false } client | 7.130 DEBUG [Client 5ed761c3c24f6307d7] delay duration 19.977538ms client | 7.130 DEBUG Setting timeout of 19.977538ms client | 7.130 DEBUG [Client 5ed761c3c24f6307d7] output_path send_profile SendProfile { limit: 1198, pto: None, probe: EnumSet(), paced: false } client | 7.130 DEBUG Building Short dcid Some(CID [8]: 6a03fd9d9c04f334) client | 7.130 DEBUG TX blocked, profile=SendProfile { limit: 1198, pto: None, probe: EnumSet(), paced: false } client | 7.130 DEBUG [Client 5ed761c3c24f6307d7] delay duration 19.96312ms client | 7.130 DEBUG Setting timeout of 19.96312ms client | 7.138 DEBUG [Client 5ed761c3c24f6307d7] pn=5 type=Short pri-path:6a03fd9d9c04f334 0.0.0.0:53152->193.167.100.100:443 IpTos(Cs0, Ect1) len 1207 client | -> RX Stream { stream_id: 0, offset: 4062, len: 1058, fin: true } client | -> RX Padding { len: 125 } client | 7.138 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 545, tv_nsec: 854026351 } client | 7.138 DEBUG [Client 5ed761c3c24f6307d7] output_path send_profile SendProfile { limit: 1198, pto: None, probe: EnumSet(), paced: false } client | 7.138 DEBUG Building Short dcid Some(CID [8]: 6a03fd9d9c04f334) client | 7.138 DEBUG [Client 5ed761c3c24f6307d7] pn=4 type=Short pri-path:6a03fd9d9c04f334 0.0.0.0:53152->193.167.100.100:443 IpTos(Cs0, NotEct) len 34 client | TX -> Ack { largest_acknowledged: 5, ack_delay: 3, first_ack_range: 5, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 6, Ect0: 0, Ce: 0})) } client | 7.138 DEBUG [Client 5ed761c3c24f6307d7] output_path send_profile SendProfile { limit: 1198, pto: None, probe: EnumSet(), paced: false } client | 7.138 DEBUG Building Short dcid Some(CID [8]: 6a03fd9d9c04f334) client | 7.138 DEBUG TX blocked, profile=SendProfile { limit: 1198, pto: None, probe: EnumSet(), paced: false } client | 7.138 DEBUG [Client 5ed761c3c24f6307d7] delay duration 75.774298ms client | 7.138 DEBUG Setting timeout of 75.774298ms client | 7.138 DEBUG [Client 5ed761c3c24f6307d7] output_path send_profile SendProfile { limit: 1198, pto: None, probe: EnumSet(), paced: false } client | 7.138 DEBUG Building Short dcid Some(CID [8]: 6a03fd9d9c04f334) client | 7.138 DEBUG TX blocked, profile=SendProfile { limit: 1198, pto: None, probe: EnumSet(), paced: false } client | 7.138 DEBUG [Client 5ed761c3c24f6307d7] delay duration 75.713434ms client | 7.138 DEBUG Setting timeout of 75.713434ms client | 7.138 DEBUG [Client 5ed761c3c24f6307d7] State change from Confirmed -> Closing { error: Application(0), timeout: Instant { tv_sec: 546, tv_nsec: 141943561 } } client | 7.138 WARN Unhandled event StateChange(Closing { error: Application(0), timeout: Instant { tv_sec: 546, tv_nsec: 141943561 } }) client | 7.138 DEBUG [Client 5ed761c3c24f6307d7] output_path send_profile SendProfile { limit: 1198, pto: None, probe: EnumSet(), paced: false } client | 7.138 DEBUG Building Short dcid Some(CID [8]: 6a03fd9d9c04f334) client | 7.138 DEBUG [Recvd-ap] immediate_ack at Instant { tv_sec: 545, tv_nsec: 854191960 } client | 7.138 DEBUG [Client 5ed761c3c24f6307d7] pn=5 type=Short pri-path:6a03fd9d9c04f334 0.0.0.0:53152->193.167.100.100:443 IpTos(Cs0, NotEct) len 45 client | TX -> Ack { largest_acknowledged: 5, ack_delay: 20, first_ack_range: 5, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 6, Ect0: 0, Ce: 0})) } client | TX -> ConnectionClose { error_code: Application(0), frame_type: 0, reason_phrase: "kthxbye!" } client | 7.138 DEBUG Setting timeout of 287.671892ms client | 7.144 DEBUG [Client 5ed761c3c24f6307d7] output_path send_profile SendProfile { limit: 1198, pto: None, probe: EnumSet(), paced: false } client | 7.144 DEBUG Building Short dcid Some(CID [8]: 6a03fd9d9c04f334) client | 7.144 DEBUG [Recvd-ap] immediate_ack at Instant { tv_sec: 545, tv_nsec: 860385563 } client | 7.144 DEBUG [Client 5ed761c3c24f6307d7] pn=6 type=Short pri-path:6a03fd9d9c04f334 0.0.0.0:53152->193.167.100.100:443 IpTos(Cs0, NotEct) len 46 client | TX -> Ack { largest_acknowledged: 5, ack_delay: 794, first_ack_range: 5, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 6, Ect0: 0, Ce: 0})) } client | TX -> ConnectionClose { error_code: Application(0), frame_type: 0, reason_phrase: "kthxbye!" } client | 7.144 DEBUG Setting timeout of 281.491293ms client | 7.144 DEBUG Setting timeout of 281.477968ms client | 7.150 DEBUG [Client 5ed761c3c24f6307d7] output_path send_profile SendProfile { limit: 1198, pto: None, probe: EnumSet(), paced: false } client | 7.150 DEBUG Building Short dcid Some(CID [8]: 6a03fd9d9c04f334) client | 7.150 DEBUG [Recvd-ap] immediate_ack at Instant { tv_sec: 545, tv_nsec: 866578244 } client | 7.150 DEBUG [Client 5ed761c3c24f6307d7] pn=7 type=Short pri-path:6a03fd9d9c04f334 0.0.0.0:53152->193.167.100.100:443 IpTos(Cs0, NotEct) len 46 client | TX -> Ack { largest_acknowledged: 5, ack_delay: 1568, first_ack_range: 5, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 6, Ect0: 0, Ce: 0})) } client | TX -> ConnectionClose { error_code: Application(0), frame_type: 0, reason_phrase: "kthxbye!" } client | 7.150 DEBUG Setting timeout of 275.310295ms client | 7.150 DEBUG Setting timeout of 275.301478ms client | 7.151 DEBUG [Client 5ed761c3c24f6307d7] output_path send_profile SendProfile { limit: 1198, pto: None, probe: EnumSet(), paced: false } client | 7.151 DEBUG Building Short dcid Some(CID [8]: 6a03fd9d9c04f334) client | 7.151 DEBUG [Recvd-ap] immediate_ack at Instant { tv_sec: 545, tv_nsec: 867784968 } client | 7.151 DEBUG [Client 5ed761c3c24f6307d7] pn=8 type=Short pri-path:6a03fd9d9c04f334 0.0.0.0:53152->193.167.100.100:443 IpTos(Cs0, NotEct) len 46 client | TX -> Ack { largest_acknowledged: 5, ack_delay: 1719, first_ack_range: 5, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 6, Ect0: 0, Ce: 0})) } client | TX -> ConnectionClose { error_code: Application(0), frame_type: 0, reason_phrase: "kthxbye!" } client | 7.151 DEBUG Setting timeout of 274.099202ms client | 7.151 DEBUG Setting timeout of 274.08782ms client | 7.158 DEBUG [Client 5ed761c3c24f6307d7] output_path send_profile SendProfile { limit: 1198, pto: None, probe: EnumSet(), paced: false } client | 7.158 DEBUG Building Short dcid Some(CID [8]: 6a03fd9d9c04f334) client | 7.158 DEBUG [Recvd-ap] immediate_ack at Instant { tv_sec: 545, tv_nsec: 874181780 } client | 7.158 DEBUG [Client 5ed761c3c24f6307d7] pn=9 type=Short pri-path:6a03fd9d9c04f334 0.0.0.0:53152->193.167.100.100:443 IpTos(Cs0, NotEct) len 46 client | TX -> Ack { largest_acknowledged: 5, ack_delay: 2519, first_ack_range: 5, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 6, Ect0: 0, Ce: 0})) } client | TX -> ConnectionClose { error_code: Application(0), frame_type: 0, reason_phrase: "kthxbye!" } client | 7.158 DEBUG Setting timeout of 267.684627ms client | 7.158 DEBUG Setting timeout of 267.670871ms client | 7.165 DEBUG [Client 5ed761c3c24f6307d7] output_path send_profile SendProfile { limit: 1198, pto: None, probe: EnumSet(), paced: false } client | 7.165 DEBUG Building Short dcid Some(CID [8]: 6a03fd9d9c04f334) client | 7.165 DEBUG [Recvd-ap] immediate_ack at Instant { tv_sec: 545, tv_nsec: 881355274 } client | 7.165 DEBUG [Client 5ed761c3c24f6307d7] pn=10 type=Short pri-path:6a03fd9d9c04f334 0.0.0.0:53152->193.167.100.100:443 IpTos(Cs0, NotEct) len 46 client | TX -> Ack { largest_acknowledged: 5, ack_delay: 3416, first_ack_range: 5, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 6, Ect0: 0, Ce: 0})) } client | TX -> ConnectionClose { error_code: Application(0), frame_type: 0, reason_phrase: "kthxbye!" } client | 7.165 DEBUG Setting timeout of 260.508168ms client | 7.165 DEBUG Setting timeout of 260.494602ms client | 7.168 DEBUG [Client 5ed761c3c24f6307d7] output_path send_profile SendProfile { limit: 1198, pto: None, probe: EnumSet(), paced: false } client | 7.168 DEBUG Building Short dcid Some(CID [8]: 6a03fd9d9c04f334) client | 7.168 DEBUG [Recvd-ap] immediate_ack at Instant { tv_sec: 545, tv_nsec: 884666330 } client | 7.168 DEBUG [Client 5ed761c3c24f6307d7] pn=11 type=Short pri-path:6a03fd9d9c04f334 0.0.0.0:53152->193.167.100.100:443 IpTos(Cs0, NotEct) len 46 client | TX -> Ack { largest_acknowledged: 5, ack_delay: 3829, first_ack_range: 5, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 6, Ect0: 0, Ce: 0})) } client | TX -> ConnectionClose { error_code: Application(0), frame_type: 0, reason_phrase: "kthxbye!" } client | 7.168 DEBUG Setting timeout of 257.219683ms client | 7.168 DEBUG Setting timeout of 257.209194ms client | 7.427 DEBUG [Client 5ed761c3c24f6307d7] State change from Closing { error: Application(0), timeout: Instant { tv_sec: 546, tv_nsec: 141943561 } } -> Closed(Application(0)) client | 7.427 INFO Closing timer expired client | 7.427 DEBUG Output::None client | 7.427 WARN Unhandled event StateChange(Closed(Application(0))) client | 7.427 DEBUG Timer fired while closed client | 7.427 DEBUG Output::None client exited with code 0 Aborting on container exit... Container client Stopping Container server Stopping Container client Stopped Container server Stopped Container sim Stopping Container sim Stopped 2025-04-30 11:36:12,213 Using the client's key log file. 2025-04-30 11:36:12,225 2025-04-30 11:36:12,225 Using the client's key log file. 2025-04-30 11:36:12,226 Using the client's key log file. 2025-04-30 11:36:12,236 2025-04-30 11:36:12,236 Using the client's key log file. 2025-04-30 11:36:12,236 Using the client's key log file. 2025-04-30 11:36:12,867 Check of downloaded files succeeded. 2025-04-30 11:36:13,189 Server sent 10009 bytes in Handshake CRYPTO frames. 2025-04-30 11:36:13,568 Received a 1252 byte Initial packet from the client. Amplification limit: 3756 2025-04-30 11:36:13,568 Received a 46 byte Handshake packet from the server. Total: 46 2025-04-30 11:36:13,568 Received a 1252 byte Initial packet from the client. Amplification limit: 7512 2025-04-30 11:36:13,568 Received a 1252 byte Handshake packet from the server. Total: 1298 2025-04-30 11:36:13,568 Received a 1252 byte Handshake packet from the server. Total: 2550 2025-04-30 11:36:13,568 Received a 1252 byte Handshake packet from the server. Total: 3802 2025-04-30 11:36:13,569 Received a 1252 byte Handshake packet from the server. Total: 5054 2025-04-30 11:36:13,569 Received a 1252 byte Handshake packet from the server. Total: 6306 2025-04-30 11:36:13,569 Received a 1252 byte Handshake packet from the server. Total: 7558 2025-04-30 11:36:13,569 Server violated the amplification limit, but stayed within 3-4x amplification. Letting it slide. 2025-04-30 11:36:13,569 Received a 1252 byte Handshake packet from the server. Total: 8810 2025-04-30 11:36:13,569 Server violated the amplification limit, but stayed within 3-4x amplification. Letting it slide. 2025-04-30 11:36:13,569 Received a 1252 byte Handshake packet from the server. Total: 10062 2025-04-30 11:36:13,569 Server violated the amplification limit.