2025-04-30 08:44:12,547 Generated random file: bnxjvrxqrx of size: 5120 2025-04-30 08:44:12,547 Generated random file: wswmqsgfzs of size: 10240 2025-04-30 08:44:12,547 Requests: https://server4:443/bnxjvrxqrx https://server4:443/wswmqsgfzs 2025-04-30 08:44:12,607 2025-04-30 08:44:12,607 Command: WAITFORSERVER=server:443 CERTS=/tmp/certs_7emwo_44/ TESTCASE_SERVER=resumption TESTCASE_CLIENT=resumption WWW=/tmp/www_6qhwxovb/ DOWNLOADS=/tmp/download_mekxpqoj/ SERVER_LOGS=/tmp/logs_server_3pjisdxq CLIENT_LOGS=/tmp/logs_client_icpc8jh4 SCENARIO="simple-p2p --delay=15ms --bandwidth=10Mbps --queue=25" CLIENT=ghcr.io/mozilla/neqo-qns:latest SERVER=ghcr.io/ngtcp2/ngtcp2-interop:latest REQUESTS="https://server4:443/bnxjvrxqrx https://server4:443/wswmqsgfzs" docker compose --env-file empty.env up --abort-on-container-exit --timeout 1 sim client server 2025-04-30 08:44:25,269 Container sim Created 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... server | Actual changes: server | tx-checksum-ip-generic: off server | tx-tcp-segmentation: off [not requested] server | tx-tcp-ecn-segmentation: off [not requested] server | tx-tcp-mangleid-segmentation: off [not requested] server | tx-tcp6-segmentation: off [not requested] server | tx-udp-segmentation: off [not requested] server | tx-checksum-sctp: off server | Endpoint's IPv4 address is 193.167.100.100 server | Endpoint's IPv6 address is fd00:cafe:cafe:100::100 client | Setting up routes... client | Actual changes: client | tx-checksum-ip-generic: off client | tx-tcp-segmentation: off [not requested] client | tx-tcp-ecn-segmentation: off [not requested] client | tx-tcp-mangleid-segmentation: off [not requested] client | tx-tcp6-segmentation: off [not requested] client | tx-udp-segmentation: off [not requested] client | tx-checksum-sctp: off client | Endpoint's IPv4 address is 193.167.0.100 client | Endpoint's IPv6 address is fd00:cafe:cafe::100 client | + export PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/neqo/bin client | + PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/neqo/bin client | + '[' -n resumption ']' 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.049972426s sim | Using scenario: simple-p2p --delay=15ms --bandwidth=10Mbps --queue=25 sim | tcpdump: listening on eth0, link-type EN10MB (Ethernet), snapshot length 262144 bytes sim | tcpdump: listening on eth1, link-type EN10MB (Ethernet), snapshot length 262144 bytes client | wait-for-it.sh: sim:57832 is available after 1 seconds client | + OPTIONS=(--cc cubic --qns-test "$TESTCASE" --qlog-dir "$QLOGDIR" --output-dir /downloads) client | + '[' 'https://server4:443/bnxjvrxqrx https://server4:443/wswmqsgfzs' ']' client | + mapfile -d ' ' -t URLS client | + OPTIONS+=("${URLS[@]}") client | + RUST_LOG=debug client | + RUST_BACKTRACE=1 client | + neqo-client --cc cubic --qns-test resumption --qlog-dir /logs/qlog/ --output-dir /downloads https://server4:443/bnxjvrxqrx 'https://server4:443/wswmqsgfzs 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:38559 -> 193.167.100.100:443 client | 0.001 DEBUG [CryptoStates] Creating initial cipher state v=Version1, role=Client dcid=473f2b2bb837abe194514cd0c6174c 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:38559->193.167.100.100:443] Make permanent client | 0.001 DEBUG [unv-path:473f2b2bb837abe194514cd0c6174c 0.0.0.0:38559->193.167.100.100:443] set as primary path client | 0.001 DEBUG [pri-unv-path:473f2b2bb837abe194514cd0c6174c 0.0.0.0:38559->193.167.100.100:443] Path validated Instant { tv_sec: 316, tv_nsec: 529187785 } client | 0.001 DEBUG [Client 473f2b2bb837abe194514cd0c6174c] client_start client | 0.001 DEBUG Writing transport parameters, msg=1 client | 0.002 DEBUG [Agent 0x556122a9ef20] state -> InProgress client | 0.002 DEBUG [Client 473f2b2bb837abe194514cd0c6174c] State change from Init -> WaitInitial client | 0.002 DEBUG [Client 473f2b2bb837abe194514cd0c6174c] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.002 DEBUG Building Initial dcid Some(CID [15]: 473f2b2bb837abe194514cd0c6174c) scid Some(CID [0]: ) client | 0.002 DEBUG CRYPTO for in offset=0, len=1206 client | 0.002 DEBUG [Client 473f2b2bb837abe194514cd0c6174c] pn=0 type=Initial pri-path:473f2b2bb837abe194514cd0c6174c 0.0.0.0:38559->193.167.100.100:443 IpTos(Cs0, Ect0) len 1252 client | TX -> Crypto { offset: 0, len: 1206 } client | 0.002 DEBUG packet_sent this=0x556122ab2630, pn=0, ps=1252 client | 0.002 DEBUG ECN probing: sent 1 probes client | 0.002 DEBUG [Client 473f2b2bb837abe194514cd0c6174c] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.002 DEBUG Building Initial dcid Some(CID [15]: 473f2b2bb837abe194514cd0c6174c) scid Some(CID [0]: ) client | 0.002 DEBUG CRYPTO for in offset=1206, len=333 client | 0.002 DEBUG [Client 473f2b2bb837abe194514cd0c6174c] pn=1 type=Initial pri-path:473f2b2bb837abe194514cd0c6174c 0.0.0.0:38559->193.167.100.100:443 IpTos(Cs0, Ect0) len 380 client | TX -> Crypto { offset: 1206, len: 333 } client | 0.002 DEBUG [Client 473f2b2bb837abe194514cd0c6174c] pad Initial from 380 to PLPMTU 1252 client | 0.002 DEBUG packet_sent this=0x556122ab2630, pn=1, ps=1252 client | 0.002 DEBUG ECN probing: sent 2 probes client | 0.002 DEBUG [Client 473f2b2bb837abe194514cd0c6174c] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } client | 0.002 DEBUG Building Initial dcid Some(CID [15]: 473f2b2bb837abe194514cd0c6174c) 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 473f2b2bb837abe194514cd0c6174c] delay duration 3.886684ms client | 0.002 DEBUG Setting timeout of 3.886684ms client | 0.002 DEBUG StateChange(WaitInitial) client | 0.002 WARN Cannot create stream ConnectionState client | 0.002 DEBUG [Client 473f2b2bb837abe194514cd0c6174c] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } client | 0.002 DEBUG Building Initial dcid Some(CID [15]: 473f2b2bb837abe194514cd0c6174c) 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 473f2b2bb837abe194514cd0c6174c] delay duration 3.861046ms client | 0.002 DEBUG Setting timeout of 3.861046ms client | 0.007 DEBUG [Client 473f2b2bb837abe194514cd0c6174c] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.007 DEBUG Building Initial dcid Some(CID [15]: 473f2b2bb837abe194514cd0c6174c) 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 473f2b2bb837abe194514cd0c6174c] delay duration 294.818256ms client | 0.007 DEBUG Setting timeout of 294.818256ms client | 0.039 DEBUG [Client 473f2b2bb837abe194514cd0c6174c] pn=1158336535 type=Initial pri-path:473f2b2bb837abe194514cd0c6174c 0.0.0.0:38559->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.039 DEBUG [Client 473f2b2bb837abe194514cd0c6174c] Rx ACK space=in, ranges=[0..=0] client | 0.039 DEBUG [LossRecovery] ACK for Initial - largest_acked=0 client | 0.039 DEBUG on_packets_acked this=0x556122ab2630, limited=1, bytes_in_flight=1252, cwnd=12520, state=SlowStart, new_acked=1252 client | 0.039 DEBUG Acked crypto frame space=in offset=0 length=1206 client | 0.039 DEBUG [Client 473f2b2bb837abe194514cd0c6174c] Changing to use Server CID=efb2441f5266164f1888d2a4ef00fd4f7d64 client | 0.039 DEBUG [Client 473f2b2bb837abe194514cd0c6174c] State change from WaitInitial -> WaitVersion client | 0.039 DEBUG [Client 473f2b2bb837abe194514cd0c6174c] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.039 DEBUG Building Initial dcid Some(CID [18]: efb2441f5266164f1888d2a4ef00fd4f7d64) scid Some(CID [0]: ) client | 0.039 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.039 DEBUG [Client 473f2b2bb837abe194514cd0c6174c] delay duration 76.188799ms client | 0.039 DEBUG Setting timeout of 76.188799ms client | 0.039 WARN Unhandled event StateChange(WaitVersion) client | 0.039 DEBUG [Client 473f2b2bb837abe194514cd0c6174c] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.039 DEBUG Building Initial dcid Some(CID [18]: efb2441f5266164f1888d2a4ef00fd4f7d64) scid Some(CID [0]: ) client | 0.039 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.039 DEBUG [Client 473f2b2bb837abe194514cd0c6174c] delay duration 76.159555ms client | 0.039 DEBUG Setting timeout of 76.159555ms client | 0.041 DEBUG [Client 473f2b2bb837abe194514cd0c6174c] pn=1158336536 type=Initial pri-path:efb2441f5266164f1888d2a4ef00fd4f7d64 0.0.0.0:38559->193.167.100.100:443 IpTos(Cs0, Ect0) len 152 client | -> RX Ack { largest_acknowledged: 1, ack_delay: 0, first_ack_range: 1, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 2, Ce: 0})) } client | -> RX Crypto { offset: 0, len: 90 } client | 0.041 DEBUG [Client 473f2b2bb837abe194514cd0c6174c] Rx ACK space=in, ranges=[0..=1] client | 0.041 DEBUG [LossRecovery] ACK for Initial - largest_acked=1 client | 0.041 DEBUG on_packets_acked this=0x556122ab2630, limited=1, bytes_in_flight=0, cwnd=12520, state=SlowStart, new_acked=1252 client | 0.041 DEBUG Acked crypto frame space=in offset=1206 length=333 client | 0.041 DEBUG Read Ok(90) bytes client | 0.042 DEBUG Write secret available for Handshake: SymKey [32]: 841df83514be7fb358d29e7502850a7fddcd4e89c18587c86c88a89ebebde5b5 client | 0.042 DEBUG Read secret available for Handshake: SymKey [32]: a3538a36bb248b4ec0103831c68598e8b38b5d9ae875320e9e1930235cce47b4 client | 0.042 DEBUG [Agent 0x556122a9ef20] state -> InProgress client | 0.042 DEBUG Making Write Handshake CryptoDxState, v=Version1 cipher=4865 client | 0.042 DEBUG Making Read Handshake CryptoDxState, v=Version1 cipher=4865 client | 0.042 DEBUG [Crypto] Handshake keys installed client | 0.042 DEBUG [Recvd-in] Set ACK timer to Instant { tv_sec: 316, tv_nsec: 569777589 } client | 0.042 DEBUG [Client 473f2b2bb837abe194514cd0c6174c] State change from WaitVersion -> Handshaking client | 0.042 DEBUG [Client 473f2b2bb837abe194514cd0c6174c] pn=1158336535 type=Handshake pri-path:efb2441f5266164f1888d2a4ef00fd4f7d64 0.0.0.0:38559->193.167.100.100:443 IpTos(Cs0, Ect0) len 764 client | -> RX Crypto { offset: 0, len: 711 } client | 0.042 DEBUG Read Ok(711) bytes client | 0.042 DEBUG [Agent 0x556122a9ef20] state -> AuthenticationPending client | 0.042 DEBUG [Recvd-hs] Set ACK timer to Instant { tv_sec: 316, tv_nsec: 569777589 } client | 0.042 DEBUG saving datagram of 284 bytes client | 0.042 DEBUG [Client 473f2b2bb837abe194514cd0c6174c] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.042 DEBUG Building Initial dcid Some(CID [18]: efb2441f5266164f1888d2a4ef00fd4f7d64) scid Some(CID [0]: ) client | 0.042 DEBUG [Client 473f2b2bb837abe194514cd0c6174c] pn=2 type=Initial pri-path:efb2441f5266164f1888d2a4ef00fd4f7d64 0.0.0.0:38559->193.167.100.100:443 IpTos(Cs0, Ect0) len 61 client | TX -> Ack { largest_acknowledged: 1158336536, ack_delay: 148, first_ack_range: 1, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 1, Ce: 0})) } client | 0.042 DEBUG Building Handshake dcid Some(CID [18]: efb2441f5266164f1888d2a4ef00fd4f7d64) scid Some(CID [0]: ) client | 0.042 DEBUG [Client 473f2b2bb837abe194514cd0c6174c] pn=0 type=Handshake pri-path:efb2441f5266164f1888d2a4ef00fd4f7d64 0.0.0.0:38559->193.167.100.100:443 IpTos(Cs0, Ect0) len 121 client | TX -> Ack { largest_acknowledged: 1158336535, ack_delay: 148, first_ack_range: 0, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 1, Ce: 0})) } client | 0.042 DEBUG [Client 473f2b2bb837abe194514cd0c6174c] Drop packet number space in client | 0.042 DEBUG [LossRecovery] Reset loss recovery state for Initial client | 0.042 WARN [LossRecovery] ignoring in-2 from dropped space client | 0.042 DEBUG ECN probing: sent 3 probes client | 0.043 DEBUG [Client 473f2b2bb837abe194514cd0c6174c] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.043 DEBUG Building Handshake dcid Some(CID [18]: efb2441f5266164f1888d2a4ef00fd4f7d64) scid Some(CID [0]: ) client | 0.043 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.043 DEBUG [Client 473f2b2bb837abe194514cd0c6174c] delay duration 96.446789ms client | 0.043 DEBUG Setting timeout of 96.446789ms client | 0.043 DEBUG saving datagram of 1200 bytes client | 0.043 DEBUG [Client 473f2b2bb837abe194514cd0c6174c] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.043 DEBUG Building Handshake dcid Some(CID [18]: efb2441f5266164f1888d2a4ef00fd4f7d64) scid Some(CID [0]: ) client | 0.043 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.043 DEBUG [Client 473f2b2bb837abe194514cd0c6174c] delay duration 96.413767ms client | 0.043 DEBUG Setting timeout of 96.413767ms client | 0.043 DEBUG StateChange(Handshaking) client | 0.043 WARN Cannot create stream ConnectionState client | 0.043 DEBUG [Client 473f2b2bb837abe194514cd0c6174c] Authenticated Ok client | 0.043 DEBUG Write secret available for ApplicationData: SymKey [32]: 26ac0a3d6da2f1c25ab203460f0517867c62c50f59bb89a2dc110dfaee9b09b9 client | 0.043 DEBUG Read secret available for ApplicationData: SymKey [32]: 6d0cb86197c83e56b8e8e49fe6b30da4dbf648b4001a4e8304eca770f9388684 client | 0.043 DEBUG [Agent 0x556122a9ef20] SSL_AuthCertificateComplete: Ok(()) client | 0.043 DEBUG [Agent 0x556122a9ef20] 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 | 0.043 DEBUG [Client 473f2b2bb837abe194514cd0c6174c] TLS connection complete client | 0.043 DEBUG Making Write ApplicationData CryptoDxState, v=Version1 cipher=4865 client | 0.043 DEBUG [Crypto] Application write key installed client | 0.043 DEBUG Making Read ApplicationData CryptoDxState, v=Version1 cipher=4865 client | 0.043 DEBUG [Crypto] application read keys installed client | 0.043 DEBUG [Client 473f2b2bb837abe194514cd0c6174c] State change from Handshaking -> Connected client | 0.043 INFO [Client 473f2b2bb837abe194514cd0c6174c] Connection established client | 0.043 DEBUG [Client 473f2b2bb837abe194514cd0c6174c] process saved for epoch ApplicationData client | 0.043 DEBUG [Client 473f2b2bb837abe194514cd0c6174c] pn=1158336535 type=Short pri-path:efb2441f5266164f1888d2a4ef00fd4f7d64 0.0.0.0:38559->193.167.100.100:443 IpTos(Cs0, Ect0) len 284 client | -> RX NewConnectionId { sequence_number: 7, retire_prior: 0, connection_id: [72, 175, 21, 160, 151, 48, 88, 175, 148, 4, 89, 88, 249, 3, 194, 138, 38, 62], stateless_reset_token: [74, 119, 162, 161, 99, 27, 137, 128, 36, 33, 206, 255, 26, 121, 119, 223] } client | -> RX NewConnectionId { sequence_number: 6, retire_prior: 0, connection_id: [9, 253, 229, 245, 134, 55, 239, 121, 164, 62, 14, 201, 34, 242, 196, 168, 132, 136], stateless_reset_token: [27, 38, 162, 108, 206, 205, 161, 207, 252, 58, 187, 159, 193, 104, 49, 129] } client | -> RX NewConnectionId { sequence_number: 5, retire_prior: 0, connection_id: [45, 78, 81, 90, 89, 64, 137, 196, 223, 101, 206, 22, 208, 2, 193, 94, 242, 78], stateless_reset_token: [63, 96, 202, 52, 56, 24, 193, 90, 126, 181, 91, 100, 9, 15, 175, 212] } client | -> RX NewConnectionId { sequence_number: 4, retire_prior: 0, connection_id: [17, 188, 157, 236, 207, 8, 45, 221, 179, 96, 237, 198, 95, 33, 182, 39, 20, 188], stateless_reset_token: [239, 170, 201, 113, 202, 255, 135, 137, 173, 85, 38, 33, 174, 203, 37, 223] } client | -> RX NewConnectionId { sequence_number: 3, retire_prior: 0, connection_id: [28, 224, 102, 57, 41, 254, 120, 143, 186, 31, 104, 7, 249, 187, 242, 151, 36, 26], stateless_reset_token: [7, 4, 186, 74, 43, 175, 198, 248, 220, 49, 239, 159, 32, 64, 114, 80] } client | -> RX NewConnectionId { sequence_number: 2, retire_prior: 0, connection_id: [10, 107, 97, 51, 174, 62, 80, 67, 14, 52, 87, 179, 249, 122, 48, 152, 47, 148], stateless_reset_token: [42, 240, 147, 108, 194, 164, 78, 193, 49, 58, 158, 126, 213, 171, 173, 103] } client | -> RX Padding { len: 35 } client | 0.043 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 316, tv_nsec: 569777589 } client | 0.043 DEBUG [Client 473f2b2bb837abe194514cd0c6174c] pn=1158336536 type=Short pri-path:efb2441f5266164f1888d2a4ef00fd4f7d64 0.0.0.0:38559->193.167.100.100:443 IpTos(Cs0, Ect0) len 1200 client | -> RX NewConnectionId { sequence_number: 1, retire_prior: 0, connection_id: [196, 184, 194, 174, 73, 154, 237, 90, 7, 62, 229, 15, 65, 123, 28, 200, 40, 174], stateless_reset_token: [202, 72, 246, 36, 53, 253, 18, 157, 122, 1, 56, 230, 115, 210, 29, 250] } client | -> RX Padding { len: 1141 } client | 0.043 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 316, tv_nsec: 571126004 } client | 0.043 DEBUG stream BiDi creatable client | 0.043 INFO Created stream 0 for https://server4/bnxjvrxqrx client | 0.043 INFO Saving https://server4/bnxjvrxqrx to "/downloads/bnxjvrxqrx" client | 0.043 DEBUG StateChange(Connected) client | 0.043 DEBUG stream 0 writable client | 0.043 DEBUG [Client 473f2b2bb837abe194514cd0c6174c] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.043 DEBUG Building Handshake dcid Some(CID [18]: efb2441f5266164f1888d2a4ef00fd4f7d64) scid Some(CID [0]: ) client | 0.043 DEBUG CRYPTO for hs offset=0, len=36 client | 0.043 DEBUG [Client 473f2b2bb837abe194514cd0c6174c] pn=1 type=Handshake pri-path:efb2441f5266164f1888d2a4ef00fd4f7d64 0.0.0.0:38559->193.167.100.100:443 IpTos(Cs0, Ect0) len 83 client | TX -> Crypto { offset: 0, len: 36 } client | 0.043 DEBUG packet_sent this=0x556122ab2630, pn=1, ps=83 client | 0.043 DEBUG Building Short dcid Some(CID [18]: efb2441f5266164f1888d2a4ef00fd4f7d64) client | 0.043 DEBUG [Client 473f2b2bb837abe194514cd0c6174c] pn=0 type=Short pri-path:efb2441f5266164f1888d2a4ef00fd4f7d64 0.0.0.0:38559->193.167.100.100:443 IpTos(Cs0, Ect0) len 154 client | TX -> Ack { largest_acknowledged: 1158336536, ack_delay: 60, first_ack_range: 1, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 2, Ce: 0})) } client | TX -> Stream { stream_id: 0, offset: 0, len: 17, fin: true } client | 0.043 DEBUG packet_sent this=0x556122ab2630, pn=0, ps=71 client | 0.043 DEBUG ECN probing: sent 4 probes client | 0.043 DEBUG [Client 473f2b2bb837abe194514cd0c6174c] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.043 DEBUG Building Handshake dcid Some(CID [18]: efb2441f5266164f1888d2a4ef00fd4f7d64) scid Some(CID [0]: ) client | 0.043 DEBUG Building Short dcid Some(CID [18]: efb2441f5266164f1888d2a4ef00fd4f7d64) client | 0.043 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.043 DEBUG [Client 473f2b2bb837abe194514cd0c6174c] delay duration 96.442761ms client | 0.043 DEBUG Setting timeout of 96.442761ms client | 0.075 DEBUG [Client 473f2b2bb837abe194514cd0c6174c] pn=1158336537 type=Short pri-path:efb2441f5266164f1888d2a4ef00fd4f7d64 0.0.0.0:38559->193.167.100.100:443 IpTos(Cs0, Ect0) len 1406 client | -> RX Ping client | -> RX Padding { len: 1387 } client | 0.075 DEBUG [Recvd-ap] immediate_ack at Instant { tv_sec: 316, tv_nsec: 603987162 } client | 0.075 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 316, tv_nsec: 603987162 } client | 0.075 DEBUG [Client 473f2b2bb837abe194514cd0c6174c] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.075 DEBUG Building Handshake dcid Some(CID [18]: efb2441f5266164f1888d2a4ef00fd4f7d64) scid Some(CID [0]: ) client | 0.075 DEBUG Building Short dcid Some(CID [18]: efb2441f5266164f1888d2a4ef00fd4f7d64) client | 0.075 DEBUG [Client 473f2b2bb837abe194514cd0c6174c] pn=1 type=Short pri-path:efb2441f5266164f1888d2a4ef00fd4f7d64 0.0.0.0:38559->193.167.100.100:443 IpTos(Cs0, Ect0) len 51 client | TX -> Ack { largest_acknowledged: 1158336537, ack_delay: 7, first_ack_range: 2, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 3, Ce: 0})) } client | 0.075 DEBUG ECN probing: sent 5 probes client | 0.076 DEBUG [Client 473f2b2bb837abe194514cd0c6174c] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.076 DEBUG Building Handshake dcid Some(CID [18]: efb2441f5266164f1888d2a4ef00fd4f7d64) scid Some(CID [0]: ) client | 0.076 DEBUG Building Short dcid Some(CID [18]: efb2441f5266164f1888d2a4ef00fd4f7d64) client | 0.076 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.076 DEBUG [Client 473f2b2bb837abe194514cd0c6174c] delay duration 64.062073ms client | 0.076 DEBUG Setting timeout of 64.062073ms client | 0.076 DEBUG [Client 473f2b2bb837abe194514cd0c6174c] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.076 DEBUG Building Handshake dcid Some(CID [18]: efb2441f5266164f1888d2a4ef00fd4f7d64) scid Some(CID [0]: ) client | 0.076 DEBUG Building Short dcid Some(CID [18]: efb2441f5266164f1888d2a4ef00fd4f7d64) client | 0.076 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.076 DEBUG [Client 473f2b2bb837abe194514cd0c6174c] delay duration 64.026997ms client | 0.076 DEBUG Setting timeout of 64.026997ms client | 0.076 DEBUG [Client 473f2b2bb837abe194514cd0c6174c] pn=1158336538 type=Short pri-path:efb2441f5266164f1888d2a4ef00fd4f7d64 0.0.0.0:38559->193.167.100.100:443 IpTos(Cs0, Ect0) len 1200 client | -> RX HandshakeDone client | -> RX NewToken { token: [54, 58, 213, 60, 73, 125, 122, 0, 110, 63, 2, 159, 220, 181, 77, 139, 22, 33, 209, 173, 67, 231, 56, 159, 132, 135, 72, 97, 98, 13, 200, 120, 38, 244, 2, 224, 115, 91, 123, 255, 34] } client | -> RX Crypto { offset: 0, len: 237 } client | -> RX Stream { stream_id: 0, offset: 0, len: 893, fin: false } client | 0.076 DEBUG [Client 473f2b2bb837abe194514cd0c6174c] State change from Connected -> Confirmed client | 0.076 DEBUG PMTUD started with probe size 1380 client | 0.076 DEBUG [Client 473f2b2bb837abe194514cd0c6174c] Drop packet number space hs client | 0.076 DEBUG [LossRecovery] Reset loss recovery state for Handshake client | 0.076 DEBUG [Client 473f2b2bb837abe194514cd0c6174c] No preferred address to migrate to client | 0.076 DEBUG Read Ok(237) bytes client | 0.077 DEBUG [0x556122a9ef20] Got resumption token [907]: 02000633faebfc3a..0000000000000000 client | 0.077 DEBUG [Agent 0x556122a9ef20] 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 | 0.077 DEBUG setting max_stream_data to 262144 client | 0.077 DEBUG resumption token [1055]: 0000000126406300..0000000000000000 client | 0.077 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 316, tv_nsec: 624955947 } client | 0.077 DEBUG [Client 473f2b2bb837abe194514cd0c6174c] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.077 DEBUG Building Short dcid Some(CID [18]: efb2441f5266164f1888d2a4ef00fd4f7d64) client | 0.077 DEBUG Sending PMTUD probe of size 1380, count 1 client | 0.077 DEBUG [Client 473f2b2bb837abe194514cd0c6174c] pn=2 type=Short pri-path:efb2441f5266164f1888d2a4ef00fd4f7d64 0.0.0.0:38559->193.167.100.100:443 IpTos(Cs0, Ect0) len 1352 client | TX -> Ping client | TX -> Padding { len: 1315 } client | 0.077 DEBUG packet_sent this=0x556122ab2630, pn=2, ps=1352 client | 0.077 DEBUG ECN probing: sent 6 probes client | 0.077 DEBUG [Client 473f2b2bb837abe194514cd0c6174c] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.077 DEBUG Building Short dcid Some(CID [18]: efb2441f5266164f1888d2a4ef00fd4f7d64) client | 0.077 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.077 DEBUG [Client 473f2b2bb837abe194514cd0c6174c] delay duration 19.691894ms client | 0.077 DEBUG Setting timeout of 19.691894ms client | 0.077 WARN Unhandled event StateChange(Confirmed) client | 0.077 DEBUG stream BiDi creatable client | 0.077 DEBUG [Client 473f2b2bb837abe194514cd0c6174c] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.077 DEBUG Building Short dcid Some(CID [18]: efb2441f5266164f1888d2a4ef00fd4f7d64) client | 0.077 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.077 DEBUG [Client 473f2b2bb837abe194514cd0c6174c] delay duration 19.658421ms client | 0.077 DEBUG Setting timeout of 19.658421ms client | 0.077 DEBUG [Client 473f2b2bb837abe194514cd0c6174c] pn=1158336539 type=Short pri-path:efb2441f5266164f1888d2a4ef00fd4f7d64 0.0.0.0:38559->193.167.100.100:443 IpTos(Cs0, Ect0) len 1200 client | -> RX Stream { stream_id: 0, offset: 893, len: 1176, fin: false } client | 0.077 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 316, tv_nsec: 605906316 } client | 0.077 DEBUG [Client 473f2b2bb837abe194514cd0c6174c] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.077 DEBUG Building Short dcid Some(CID [18]: efb2441f5266164f1888d2a4ef00fd4f7d64) client | 0.077 DEBUG [Client 473f2b2bb837abe194514cd0c6174c] pn=3 type=Short pri-path:efb2441f5266164f1888d2a4ef00fd4f7d64 0.0.0.0:38559->193.167.100.100:443 IpTos(Cs0, Ect0) len 51 client | TX -> Ack { largest_acknowledged: 1158336539, ack_delay: 3, first_ack_range: 4, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 5, Ce: 0})) } client | 0.077 DEBUG ECN probing: sent 7 probes client | 0.077 DEBUG [Client 473f2b2bb837abe194514cd0c6174c] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.077 DEBUG Building Short dcid Some(CID [18]: efb2441f5266164f1888d2a4ef00fd4f7d64) client | 0.077 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.077 DEBUG [Client 473f2b2bb837abe194514cd0c6174c] delay duration 120.722232ms client | 0.077 DEBUG Setting timeout of 120.722232ms client | 0.077 DEBUG [Client 473f2b2bb837abe194514cd0c6174c] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.077 DEBUG Building Short dcid Some(CID [18]: efb2441f5266164f1888d2a4ef00fd4f7d64) client | 0.077 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.077 DEBUG [Client 473f2b2bb837abe194514cd0c6174c] delay duration 120.69425ms client | 0.077 DEBUG Setting timeout of 120.69425ms client | 0.078 DEBUG [Client 473f2b2bb837abe194514cd0c6174c] pn=1158336540 type=Short pri-path:efb2441f5266164f1888d2a4ef00fd4f7d64 0.0.0.0:38559->193.167.100.100:443 IpTos(Cs0, Ect0) len 1200 client | -> RX Stream { stream_id: 0, offset: 2069, len: 1176, fin: false } client | 0.078 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 316, tv_nsec: 626924701 } client | 0.078 DEBUG [Client 473f2b2bb837abe194514cd0c6174c] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.078 DEBUG Building Short dcid Some(CID [18]: efb2441f5266164f1888d2a4ef00fd4f7d64) client | 0.078 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.078 DEBUG [Client 473f2b2bb837abe194514cd0c6174c] delay duration 19.97325ms client | 0.078 DEBUG Setting timeout of 19.97325ms client | 0.078 DEBUG [Client 473f2b2bb837abe194514cd0c6174c] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.078 DEBUG Building Short dcid Some(CID [18]: efb2441f5266164f1888d2a4ef00fd4f7d64) client | 0.078 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.078 DEBUG [Client 473f2b2bb837abe194514cd0c6174c] delay duration 19.951259ms client | 0.078 DEBUG Setting timeout of 19.951259ms client | 0.079 DEBUG [Client 473f2b2bb837abe194514cd0c6174c] pn=1158336541 type=Short pri-path:efb2441f5266164f1888d2a4ef00fd4f7d64 0.0.0.0:38559->193.167.100.100:443 IpTos(Cs0, Ect0) len 1200 client | -> RX Stream { stream_id: 0, offset: 3245, len: 1176, fin: false } client | 0.079 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 316, tv_nsec: 607908162 } client | 0.079 DEBUG [Client 473f2b2bb837abe194514cd0c6174c] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.079 DEBUG Building Short dcid Some(CID [18]: efb2441f5266164f1888d2a4ef00fd4f7d64) client | 0.079 DEBUG [Client 473f2b2bb837abe194514cd0c6174c] pn=4 type=Short pri-path:efb2441f5266164f1888d2a4ef00fd4f7d64 0.0.0.0:38559->193.167.100.100:443 IpTos(Cs0, Ect0) len 51 client | TX -> Ack { largest_acknowledged: 1158336541, ack_delay: 4, first_ack_range: 6, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 7, Ce: 0})) } client | 0.079 DEBUG ECN probing: sent 8 probes client | 0.079 DEBUG [Client 473f2b2bb837abe194514cd0c6174c] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.079 DEBUG Building Short dcid Some(CID [18]: efb2441f5266164f1888d2a4ef00fd4f7d64) client | 0.079 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.079 DEBUG [Client 473f2b2bb837abe194514cd0c6174c] delay duration 118.768667ms client | 0.079 DEBUG Setting timeout of 118.768667ms client | 0.079 DEBUG [Client 473f2b2bb837abe194514cd0c6174c] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.079 DEBUG Building Short dcid Some(CID [18]: efb2441f5266164f1888d2a4ef00fd4f7d64) client | 0.079 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.079 DEBUG [Client 473f2b2bb837abe194514cd0c6174c] delay duration 118.723222ms client | 0.079 DEBUG Setting timeout of 118.723222ms client | 0.080 DEBUG [Client 473f2b2bb837abe194514cd0c6174c] pn=1158336542 type=Short pri-path:efb2441f5266164f1888d2a4ef00fd4f7d64 0.0.0.0:38559->193.167.100.100:443 IpTos(Cs0, Ect0) len 1200 client | -> RX Stream { stream_id: 0, offset: 4421, len: 699, fin: true } client | -> RX Padding { len: 477 } client | 0.080 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 316, tv_nsec: 628887286 } client | 0.080 DEBUG [Client 473f2b2bb837abe194514cd0c6174c] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.080 DEBUG Building Short dcid Some(CID [18]: efb2441f5266164f1888d2a4ef00fd4f7d64) client | 0.080 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.080 DEBUG [Client 473f2b2bb837abe194514cd0c6174c] delay duration 19.970745ms client | 0.080 DEBUG Setting timeout of 19.970745ms client | 0.080 DEBUG [Client 473f2b2bb837abe194514cd0c6174c] pn=1158336543 type=Short pri-path:efb2441f5266164f1888d2a4ef00fd4f7d64 0.0.0.0:38559->193.167.100.100:443 IpTos(Cs0, Ect0) len 40 client | -> RX Ack { largest_acknowledged: 0, ack_delay: 638, first_ack_range: 0, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 1, Ce: 0})) } client | -> RX Padding { len: 13 } client | 0.080 DEBUG [Client 473f2b2bb837abe194514cd0c6174c] Rx ACK space=ap, ranges=[0..=0] client | 0.080 DEBUG [LossRecovery] ACK for ApplicationData - largest_acked=0 client | 0.080 DEBUG on_packets_acked this=0x556122ab2630, limited=1, bytes_in_flight=1352, cwnd=12520, state=SlowStart, new_acked=71 client | 0.080 DEBUG [Client 473f2b2bb837abe194514cd0c6174c] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.080 DEBUG Building Short dcid Some(CID [18]: efb2441f5266164f1888d2a4ef00fd4f7d64) client | 0.080 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.080 DEBUG [Client 473f2b2bb837abe194514cd0c6174c] delay duration 19.915953ms client | 0.080 DEBUG Setting timeout of 19.915953ms client | 0.080 DEBUG stream 0 complete client | 0.080 DEBUG [Client 473f2b2bb837abe194514cd0c6174c] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.080 DEBUG Building Short dcid Some(CID [18]: efb2441f5266164f1888d2a4ef00fd4f7d64) client | 0.080 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.080 DEBUG [Client 473f2b2bb837abe194514cd0c6174c] delay duration 19.84477ms client | 0.080 DEBUG Setting timeout of 19.84477ms client | 0.080 DEBUG [Client 473f2b2bb837abe194514cd0c6174c] State change from Confirmed -> Closing { error: Application(0), timeout: Instant { tv_sec: 316, tv_nsec: 931924271 } } client | 0.080 WARN Unhandled event StateChange(Closing { error: Application(0), timeout: Instant { tv_sec: 316, tv_nsec: 931924271 } }) client | 0.080 DEBUG [Client 473f2b2bb837abe194514cd0c6174c] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.080 DEBUG Building Short dcid Some(CID [18]: efb2441f5266164f1888d2a4ef00fd4f7d64) client | 0.080 DEBUG [Recvd-ap] immediate_ack at Instant { tv_sec: 316, tv_nsec: 609070599 } client | 0.080 DEBUG [Client 473f2b2bb837abe194514cd0c6174c] pn=5 type=Short pri-path:efb2441f5266164f1888d2a4ef00fd4f7d64 0.0.0.0:38559->193.167.100.100:443 IpTos(Cs0, Ect0) len 62 client | TX -> Ack { largest_acknowledged: 1158336543, ack_delay: 16, 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 | 0.081 DEBUG ECN probing: sent 9 probes client | 0.081 DEBUG Setting timeout of 322.792548ms client | 0.107 DEBUG [Client 473f2b2bb837abe194514cd0c6174c] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.107 DEBUG Building Short dcid Some(CID [18]: efb2441f5266164f1888d2a4ef00fd4f7d64) client | 0.107 DEBUG [Recvd-ap] immediate_ack at Instant { tv_sec: 316, tv_nsec: 635889923 } client | 0.107 DEBUG [Client 473f2b2bb837abe194514cd0c6174c] pn=6 type=Short pri-path:efb2441f5266164f1888d2a4ef00fd4f7d64 0.0.0.0:38559->193.167.100.100:443 IpTos(Cs0, Ect0) len 63 client | TX -> Ack { largest_acknowledged: 1158336543, ack_delay: 3368, 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 | 0.107 DEBUG ECN probing: sent 10 probes client | 0.107 DEBUG ECN probing concluded with 10 probes sent client | 0.107 DEBUG Setting timeout of 295.949609ms client | 0.107 DEBUG Setting timeout of 295.93938ms client | 0.405 DEBUG [Client 473f2b2bb837abe194514cd0c6174c] State change from Closing { error: Application(0), timeout: Instant { tv_sec: 316, tv_nsec: 931924271 } } -> Closed(Application(0)) client | 0.405 INFO Closing timer expired client | 0.405 DEBUG Output::None client | 0.405 WARN Unhandled event StateChange(Closed(Application(0))) client | 0.405 DEBUG Timer fired while closed client | 0.405 DEBUG Output::None client | 0.405 DEBUG [CryptoStates] Creating initial cipher state v=Version1, role=Client dcid=fcd39234b2189549 client | 0.405 DEBUG Making Write Initial CryptoDxState, v=Version1 cipher=4865 client | 0.405 DEBUG Making Read Initial CryptoDxState, v=Version1 cipher=4865 client | 0.405 DEBUG Outbound interface eth0 for destination 193.167.100.100 has MTU 1500 client | 0.405 DEBUG [unv-path 0.0.0.0:38559->193.167.100.100:443] Make permanent client | 0.406 DEBUG [unv-path:fcd39234b2189549 0.0.0.0:38559->193.167.100.100:443] set as primary path client | 0.406 DEBUG [pri-unv-path:fcd39234b2189549 0.0.0.0:38559->193.167.100.100:443] Path validated Instant { tv_sec: 316, tv_nsec: 933781815 } client | 0.406 INFO [Client fcd39234b2189549] resumption token [1055]: 0000000126406300..0000000000000000 client | 0.406 DEBUG Overwrite initial version Version1 ==> Version1 client | 0.406 DEBUG Overwrite initial version Version1 ==> Version1 client | 0.406 DEBUG [Client fcd39234b2189549] client_start client | 0.406 DEBUG Writing transport parameters, msg=1 client | 0.406 DEBUG Write secret available for ZeroRtt: SymKey [32]: fcf92020f23244d3947db0d35f591c282130bd7f685e6e8d24f751dc5a32a6d5 client | 0.406 DEBUG [Agent 0x556122ae25a0] state -> InProgress client | 0.406 DEBUG [Client fcd39234b2189549] State change from Init -> WaitInitial client | 0.406 DEBUG Making Write ZeroRtt CryptoDxState, v=Version1 cipher=4865 client | 0.406 DEBUG [Client fcd39234b2189549] Enabled 0-RTT client | 0.406 DEBUG stream BiDi creatable client | 0.406 INFO Created stream 0 for https://server4/wswmqsgfzs client | 0.406 INFO Saving https://server4/wswmqsgfzs to "/downloads/wswmqsgfzs" client | 0.406 DEBUG StateChange(WaitInitial) client | 0.406 DEBUG stream 0 writable client | 0.406 DEBUG [Client fcd39234b2189549] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.406 DEBUG Building Initial dcid Some(CID [8]: fcd39234b2189549) scid Some(CID [0]: ) client | 0.406 DEBUG CRYPTO for in offset=0, len=1172 client | 0.406 DEBUG [Client fcd39234b2189549] pn=0 type=Initial pri-path:fcd39234b2189549 0.0.0.0:38559->193.167.100.100:443 IpTos(Cs0, Ect0) len 1252 client | TX -> Crypto { offset: 0, len: 1172 } client | 0.406 DEBUG packet_sent this=0x556122ab2630, pn=0, ps=1252 client | 0.406 DEBUG ECN probing: sent 1 probes client | 0.407 DEBUG [Client fcd39234b2189549] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.407 DEBUG Building Initial dcid Some(CID [8]: fcd39234b2189549) scid Some(CID [0]: ) client | 0.407 DEBUG CRYPTO for in offset=1172, len=629 client | 0.407 DEBUG [Client fcd39234b2189549] pn=1 type=Initial pri-path:fcd39234b2189549 0.0.0.0:38559->193.167.100.100:443 IpTos(Cs0, Ect0) len 710 client | TX -> Crypto { offset: 1172, len: 629 } client | 0.407 DEBUG Building ZeroRtt dcid Some(CID [8]: fcd39234b2189549) scid Some(CID [0]: ) client | 0.407 DEBUG [Client fcd39234b2189549] pn=0 type=ZeroRtt pri-path:fcd39234b2189549 0.0.0.0:38559->193.167.100.100:443 IpTos(Cs0, Ect0) len 764 client | TX -> Stream { stream_id: 0, offset: 0, len: 17, fin: true } client | 0.407 DEBUG packet_sent this=0x556122ab2630, pn=0, ps=54 client | 0.407 DEBUG [Client fcd39234b2189549] pad Initial from 764 to PLPMTU 1252 client | 0.407 DEBUG packet_sent this=0x556122ab2630, pn=1, ps=1198 client | 0.407 DEBUG ECN probing: sent 2 probes client | 0.407 DEBUG [Client fcd39234b2189549] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.407 DEBUG Building Initial dcid Some(CID [8]: fcd39234b2189549) scid Some(CID [0]: ) client | 0.407 DEBUG Building ZeroRtt dcid Some(CID [8]: fcd39234b2189549) scid Some(CID [0]: ) client | 0.407 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.407 DEBUG [Client fcd39234b2189549] delay duration 113.905774ms client | 0.407 DEBUG Setting timeout of 113.905774ms client | 0.439 DEBUG [Client fcd39234b2189549] pn=1318825226 type=Initial pri-path:fcd39234b2189549 0.0.0.0:38559->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.439 DEBUG [Client fcd39234b2189549] Rx ACK space=in, ranges=[0..=0] client | 0.439 DEBUG [LossRecovery] ACK for Initial - largest_acked=0 client | 0.439 DEBUG on_packets_acked this=0x556122ab2630, limited=1, bytes_in_flight=1252, cwnd=12520, state=SlowStart, new_acked=1252 client | 0.439 DEBUG Acked crypto frame space=in offset=0 length=1172 client | 0.439 DEBUG [Client fcd39234b2189549] Changing to use Server CID=d24ab146fd203916ad50b9ba8652ea19b769 client | 0.439 DEBUG [Client fcd39234b2189549] State change from WaitInitial -> WaitVersion client | 0.439 DEBUG [Client fcd39234b2189549] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.439 DEBUG Building Initial dcid Some(CID [18]: d24ab146fd203916ad50b9ba8652ea19b769) scid Some(CID [0]: ) client | 0.439 DEBUG Building ZeroRtt dcid Some(CID [18]: d24ab146fd203916ad50b9ba8652ea19b769) scid Some(CID [0]: ) client | 0.439 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.439 DEBUG [Client fcd39234b2189549] delay duration 64.938445ms client | 0.439 DEBUG Setting timeout of 64.938445ms client | 0.439 WARN Unhandled event StateChange(WaitVersion) client | 0.439 DEBUG [Client fcd39234b2189549] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.439 DEBUG Building Initial dcid Some(CID [18]: d24ab146fd203916ad50b9ba8652ea19b769) scid Some(CID [0]: ) client | 0.439 DEBUG Building ZeroRtt dcid Some(CID [18]: d24ab146fd203916ad50b9ba8652ea19b769) scid Some(CID [0]: ) client | 0.439 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.439 DEBUG [Client fcd39234b2189549] delay duration 64.896036ms client | 0.439 DEBUG Setting timeout of 64.896036ms client | 0.441 DEBUG [Client fcd39234b2189549] pn=1318825227 type=Initial pri-path:d24ab146fd203916ad50b9ba8652ea19b769 0.0.0.0:38559->193.167.100.100:443 IpTos(Cs0, Ect0) len 158 client | -> RX Ack { largest_acknowledged: 1, ack_delay: 0, first_ack_range: 1, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 2, Ce: 0})) } client | -> RX Crypto { offset: 0, len: 96 } client | 0.441 DEBUG [Client fcd39234b2189549] Rx ACK space=in, ranges=[0..=1] client | 0.441 DEBUG [LossRecovery] ACK for Initial - largest_acked=1 client | 0.441 DEBUG on_packets_acked this=0x556122ab2630, limited=1, bytes_in_flight=54, cwnd=12520, state=SlowStart, new_acked=1198 client | 0.441 DEBUG Acked crypto frame space=in offset=1172 length=629 client | 0.441 DEBUG Read Ok(96) bytes client | 0.441 DEBUG Write secret available for Handshake: SymKey [32]: 99b80816f0e10e015412f699dbab273373f998095d7cb67a2a0f136c438f1654 client | 0.441 DEBUG Read secret available for Handshake: SymKey [32]: 2781d9cefb858975e2ced4a3284671b7b8a60dd2fcb13e596482771e3b2370ef client | 0.441 DEBUG [Agent 0x556122ae25a0] state -> InProgress client | 0.442 DEBUG Making Write Handshake CryptoDxState, v=Version1 cipher=4865 client | 0.442 DEBUG Making Read Handshake CryptoDxState, v=Version1 cipher=4865 client | 0.442 DEBUG [Crypto] Handshake keys installed client | 0.442 DEBUG [Recvd-in] Set ACK timer to Instant { tv_sec: 316, tv_nsec: 969703790 } client | 0.442 DEBUG [Client fcd39234b2189549] State change from WaitVersion -> Handshaking client | 0.442 DEBUG [Client fcd39234b2189549] pn=1318825226 type=Handshake pri-path:d24ab146fd203916ad50b9ba8652ea19b769 0.0.0.0:38559->193.167.100.100:443 IpTos(Cs0, Ect0) len 212 client | -> RX Crypto { offset: 0, len: 159 } client | 0.442 DEBUG Read Ok(159) bytes client | 0.442 DEBUG Write secret available for ApplicationData: SymKey [32]: 60d1786475588d047ba6976977fe9c19f22045daf06c877a093b3a7c6bf50494 client | 0.442 DEBUG Read secret available for ApplicationData: SymKey [32]: 3d8b3a76e234ac18067ea34ae51b762e66eb405ecad818c09344086011d8f0ff client | 0.442 DEBUG [Agent 0x556122ae25a0] state -> Complete(SecretAgentInfo { version: 772, cipher: 4865, group: 29, resumed: true, early_data: true, ech_accepted: false, alpn: Some("hq-interop"), signature_scheme: 1027 }) client | 0.442 DEBUG [Client fcd39234b2189549] TLS connection complete client | 0.442 DEBUG Making Write ApplicationData CryptoDxState, v=Version1 cipher=4865 client | 0.442 DEBUG [Crypto] Application write key installed client | 0.442 DEBUG Making Read ApplicationData CryptoDxState, v=Version1 cipher=4865 client | 0.442 DEBUG [Crypto] application read keys installed client | 0.442 DEBUG setting max_stream_data to 262144 client | 0.442 DEBUG [Client fcd39234b2189549] State change from Handshaking -> Connected client | 0.442 INFO [Client fcd39234b2189549] Connection established client | 0.442 DEBUG setting max_stream_data to 262144 client | 0.442 DEBUG [Recvd-hs] Set ACK timer to Instant { tv_sec: 316, tv_nsec: 969703790 } client | 0.442 DEBUG [Client fcd39234b2189549] pn=1318825226 type=Short pri-path:d24ab146fd203916ad50b9ba8652ea19b769 0.0.0.0:38559->193.167.100.100:443 IpTos(Cs0, Ect0) len 830 client | -> RX NewConnectionId { sequence_number: 7, retire_prior: 0, connection_id: [201, 136, 215, 7, 211, 158, 40, 32, 151, 78, 101, 38, 70, 138, 155, 79, 62, 38], stateless_reset_token: [216, 143, 251, 186, 62, 166, 29, 128, 82, 220, 195, 245, 62, 186, 230, 28] } client | -> RX NewConnectionId { sequence_number: 6, retire_prior: 0, connection_id: [189, 226, 60, 174, 4, 22, 84, 147, 151, 16, 181, 218, 45, 156, 156, 5, 15, 123], stateless_reset_token: [210, 178, 49, 228, 253, 147, 248, 13, 210, 123, 188, 16, 117, 106, 91, 214] } client | -> RX NewConnectionId { sequence_number: 5, retire_prior: 0, connection_id: [122, 212, 225, 150, 69, 237, 215, 218, 192, 249, 133, 251, 180, 200, 3, 13, 112, 203], stateless_reset_token: [235, 175, 8, 221, 110, 126, 32, 86, 141, 127, 64, 137, 42, 253, 178, 73] } client | -> RX NewConnectionId { sequence_number: 4, retire_prior: 0, connection_id: [12, 38, 75, 29, 3, 200, 55, 169, 250, 90, 188, 66, 187, 198, 186, 114, 141, 75], stateless_reset_token: [94, 181, 201, 102, 233, 70, 200, 246, 13, 80, 66, 181, 145, 78, 124, 109] } client | -> RX NewConnectionId { sequence_number: 3, retire_prior: 0, connection_id: [236, 24, 18, 34, 177, 106, 186, 226, 118, 94, 48, 109, 246, 177, 5, 119, 198, 147], stateless_reset_token: [21, 76, 218, 252, 16, 218, 98, 220, 73, 13, 249, 193, 81, 250, 120, 32] } client | -> RX NewConnectionId { sequence_number: 2, retire_prior: 0, connection_id: [91, 231, 113, 105, 150, 31, 176, 182, 214, 221, 223, 41, 64, 16, 123, 106, 234, 4], stateless_reset_token: [124, 121, 241, 192, 229, 202, 223, 123, 7, 238, 29, 185, 130, 131, 213, 52] } client | -> RX NewConnectionId { sequence_number: 1, retire_prior: 0, connection_id: [185, 84, 216, 226, 136, 54, 85, 175, 68, 89, 110, 128, 112, 25, 95, 141, 105, 94], stateless_reset_token: [30, 33, 140, 114, 159, 132, 155, 151, 145, 6, 148, 16, 204, 50, 199, 98] } client | -> RX Stream { stream_id: 0, offset: 0, len: 539, fin: false } client | 0.442 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 316, tv_nsec: 969703790 } client | 0.442 DEBUG [Client fcd39234b2189549] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.442 DEBUG Building Initial dcid Some(CID [18]: d24ab146fd203916ad50b9ba8652ea19b769) scid Some(CID [0]: ) client | 0.442 DEBUG [Client fcd39234b2189549] pn=2 type=Initial pri-path:d24ab146fd203916ad50b9ba8652ea19b769 0.0.0.0:38559->193.167.100.100:443 IpTos(Cs0, Ect0) len 102 client | TX -> Ack { largest_acknowledged: 1318825227, ack_delay: 128, first_ack_range: 1, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 1, Ce: 0})) } client | 0.442 DEBUG Building Handshake dcid Some(CID [18]: d24ab146fd203916ad50b9ba8652ea19b769) scid Some(CID [0]: ) client | 0.442 DEBUG CRYPTO for hs offset=0, len=36 client | 0.442 DEBUG [Client fcd39234b2189549] pn=0 type=Handshake pri-path:d24ab146fd203916ad50b9ba8652ea19b769 0.0.0.0:38559->193.167.100.100:443 IpTos(Cs0, Ect0) len 201 client | TX -> Ack { largest_acknowledged: 1318825226, ack_delay: 128, first_ack_range: 0, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 1, Ce: 0})) } client | TX -> Crypto { offset: 0, len: 36 } client | 0.442 DEBUG packet_sent this=0x556122ab2630, pn=0, ps=99 client | 0.442 DEBUG [Client fcd39234b2189549] Drop packet number space in client | 0.442 DEBUG [LossRecovery] Reset loss recovery state for Initial client | 0.442 DEBUG Building Short dcid Some(CID [18]: d24ab146fd203916ad50b9ba8652ea19b769) client | 0.442 DEBUG [Client fcd39234b2189549] pn=1 type=Short pri-path:d24ab146fd203916ad50b9ba8652ea19b769 0.0.0.0:38559->193.167.100.100:443 IpTos(Cs0, Ect0) len 253 client | TX -> Ack { largest_acknowledged: 1318825226, ack_delay: 128, first_ack_range: 0, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 1, Ce: 0})) } client | 0.442 WARN [LossRecovery] ignoring in-2 from dropped space client | 0.442 DEBUG ECN probing: sent 3 probes client | 0.442 DEBUG [Client fcd39234b2189549] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.442 DEBUG Building Handshake dcid Some(CID [18]: d24ab146fd203916ad50b9ba8652ea19b769) scid Some(CID [0]: ) client | 0.442 DEBUG Building Short dcid Some(CID [18]: d24ab146fd203916ad50b9ba8652ea19b769) client | 0.442 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.442 DEBUG [Client fcd39234b2189549] delay duration 83.305271ms client | 0.442 DEBUG Setting timeout of 83.305271ms client | 0.442 DEBUG [Client fcd39234b2189549] pn=1318825227 type=Short pri-path:d24ab146fd203916ad50b9ba8652ea19b769 0.0.0.0:38559->193.167.100.100:443 IpTos(Cs0, Ect0) len 1200 client | -> RX Stream { stream_id: 0, offset: 539, len: 1173, fin: false } client | 0.442 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 316, tv_nsec: 990912954 } client | 0.442 DEBUG [Client fcd39234b2189549] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.442 DEBUG Building Handshake dcid Some(CID [18]: d24ab146fd203916ad50b9ba8652ea19b769) scid Some(CID [0]: ) client | 0.442 DEBUG Building Short dcid Some(CID [18]: d24ab146fd203916ad50b9ba8652ea19b769) client | 0.442 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.442 DEBUG [Client fcd39234b2189549] delay duration 19.981275ms client | 0.442 DEBUG Setting timeout of 19.981275ms client | 0.442 DEBUG StateChange(Handshaking) client | 0.442 DEBUG stream BiDi creatable client | 0.442 DEBUG StateChange(Connected) client | 0.442 DEBUG [Client fcd39234b2189549] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.442 DEBUG Building Handshake dcid Some(CID [18]: d24ab146fd203916ad50b9ba8652ea19b769) scid Some(CID [0]: ) client | 0.442 DEBUG Building Short dcid Some(CID [18]: d24ab146fd203916ad50b9ba8652ea19b769) client | 0.442 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.442 DEBUG [Client fcd39234b2189549] delay duration 19.948153ms client | 0.442 DEBUG Setting timeout of 19.948153ms client | 0.443 DEBUG [Client fcd39234b2189549] pn=1318825228 type=Short pri-path:d24ab146fd203916ad50b9ba8652ea19b769 0.0.0.0:38559->193.167.100.100:443 IpTos(Cs0, Ect0) len 1200 client | -> RX Stream { stream_id: 0, offset: 1712, len: 1173, fin: false } client | 0.443 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 316, tv_nsec: 971693789 } client | 0.443 DEBUG [Client fcd39234b2189549] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.443 DEBUG Building Handshake dcid Some(CID [18]: d24ab146fd203916ad50b9ba8652ea19b769) scid Some(CID [0]: ) client | 0.443 DEBUG Building Short dcid Some(CID [18]: d24ab146fd203916ad50b9ba8652ea19b769) client | 0.443 DEBUG [Client fcd39234b2189549] pn=2 type=Short pri-path:d24ab146fd203916ad50b9ba8652ea19b769 0.0.0.0:38559->193.167.100.100:443 IpTos(Cs0, Ect0) len 51 client | TX -> Ack { largest_acknowledged: 1318825228, ack_delay: 3, first_ack_range: 2, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 3, Ce: 0})) } client | 0.443 DEBUG ECN probing: sent 4 probes client | 0.443 DEBUG [Client fcd39234b2189549] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.443 DEBUG Building Handshake dcid Some(CID [18]: d24ab146fd203916ad50b9ba8652ea19b769) scid Some(CID [0]: ) client | 0.443 DEBUG Building Short dcid Some(CID [18]: d24ab146fd203916ad50b9ba8652ea19b769) client | 0.443 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.443 DEBUG [Client fcd39234b2189549] delay duration 82.409772ms client | 0.443 DEBUG Setting timeout of 82.409772ms client | 0.443 DEBUG [Client fcd39234b2189549] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.443 DEBUG Building Handshake dcid Some(CID [18]: d24ab146fd203916ad50b9ba8652ea19b769) scid Some(CID [0]: ) client | 0.443 DEBUG Building Short dcid Some(CID [18]: d24ab146fd203916ad50b9ba8652ea19b769) client | 0.443 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.443 DEBUG [Client fcd39234b2189549] delay duration 82.379846ms client | 0.443 DEBUG Setting timeout of 82.379846ms client | 0.444 DEBUG [Client fcd39234b2189549] pn=1318825229 type=Short pri-path:d24ab146fd203916ad50b9ba8652ea19b769 0.0.0.0:38559->193.167.100.100:443 IpTos(Cs0, Ect0) len 1200 client | -> RX Stream { stream_id: 0, offset: 2885, len: 1173, fin: false } client | 0.444 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 316, tv_nsec: 992679845 } client | 0.444 DEBUG [Client fcd39234b2189549] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.444 DEBUG Building Handshake dcid Some(CID [18]: d24ab146fd203916ad50b9ba8652ea19b769) scid Some(CID [0]: ) client | 0.444 DEBUG Building Short dcid Some(CID [18]: d24ab146fd203916ad50b9ba8652ea19b769) client | 0.444 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.444 DEBUG [Client fcd39234b2189549] delay duration 19.97337ms client | 0.444 DEBUG Setting timeout of 19.97337ms client | 0.444 DEBUG [Client fcd39234b2189549] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.444 DEBUG Building Handshake dcid Some(CID [18]: d24ab146fd203916ad50b9ba8652ea19b769) scid Some(CID [0]: ) client | 0.444 DEBUG Building Short dcid Some(CID [18]: d24ab146fd203916ad50b9ba8652ea19b769) client | 0.444 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.444 DEBUG [Client fcd39234b2189549] delay duration 19.947862ms client | 0.444 DEBUG Setting timeout of 19.947862ms client | 0.445 DEBUG [Client fcd39234b2189549] pn=1318825230 type=Short pri-path:d24ab146fd203916ad50b9ba8652ea19b769 0.0.0.0:38559->193.167.100.100:443 IpTos(Cs0, Ect0) len 1200 client | -> RX Stream { stream_id: 0, offset: 4058, len: 1173, fin: false } client | 0.445 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 316, tv_nsec: 973667174 } client | 0.445 DEBUG [Client fcd39234b2189549] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.445 DEBUG Building Handshake dcid Some(CID [18]: d24ab146fd203916ad50b9ba8652ea19b769) scid Some(CID [0]: ) client | 0.445 DEBUG Building Short dcid Some(CID [18]: d24ab146fd203916ad50b9ba8652ea19b769) client | 0.445 DEBUG [Client fcd39234b2189549] pn=3 type=Short pri-path:d24ab146fd203916ad50b9ba8652ea19b769 0.0.0.0:38559->193.167.100.100:443 IpTos(Cs0, Ect0) len 51 client | TX -> Ack { largest_acknowledged: 1318825230, ack_delay: 3, first_ack_range: 4, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 5, Ce: 0})) } client | 0.445 DEBUG ECN probing: sent 5 probes client | 0.445 DEBUG [Client fcd39234b2189549] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.445 DEBUG Building Handshake dcid Some(CID [18]: d24ab146fd203916ad50b9ba8652ea19b769) scid Some(CID [0]: ) client | 0.445 DEBUG Building Short dcid Some(CID [18]: d24ab146fd203916ad50b9ba8652ea19b769) client | 0.445 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.445 DEBUG [Client fcd39234b2189549] delay duration 80.433691ms client | 0.445 DEBUG Setting timeout of 80.433691ms client | 0.445 DEBUG [Client fcd39234b2189549] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.445 DEBUG Building Handshake dcid Some(CID [18]: d24ab146fd203916ad50b9ba8652ea19b769) scid Some(CID [0]: ) client | 0.445 DEBUG Building Short dcid Some(CID [18]: d24ab146fd203916ad50b9ba8652ea19b769) client | 0.445 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.445 DEBUG [Client fcd39234b2189549] delay duration 80.397844ms client | 0.445 DEBUG Setting timeout of 80.397844ms client | 0.446 DEBUG [Client fcd39234b2189549] pn=1318825231 type=Short pri-path:d24ab146fd203916ad50b9ba8652ea19b769 0.0.0.0:38559->193.167.100.100:443 IpTos(Cs0, Ect0) len 1200 client | -> RX Stream { stream_id: 0, offset: 5231, len: 1173, fin: false } client | 0.446 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 316, tv_nsec: 994644484 } client | 0.446 DEBUG [Client fcd39234b2189549] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.446 DEBUG Building Handshake dcid Some(CID [18]: d24ab146fd203916ad50b9ba8652ea19b769) scid Some(CID [0]: ) client | 0.446 DEBUG Building Short dcid Some(CID [18]: d24ab146fd203916ad50b9ba8652ea19b769) client | 0.446 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.446 DEBUG [Client fcd39234b2189549] delay duration 19.977367ms client | 0.446 DEBUG Setting timeout of 19.977367ms client | 0.446 DEBUG [Client fcd39234b2189549] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.446 DEBUG Building Handshake dcid Some(CID [18]: d24ab146fd203916ad50b9ba8652ea19b769) scid Some(CID [0]: ) client | 0.446 DEBUG Building Short dcid Some(CID [18]: d24ab146fd203916ad50b9ba8652ea19b769) client | 0.446 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.446 DEBUG [Client fcd39234b2189549] delay duration 19.959524ms client | 0.446 DEBUG Setting timeout of 19.959524ms client | 0.447 DEBUG [Client fcd39234b2189549] pn=1318825232 type=Short pri-path:d24ab146fd203916ad50b9ba8652ea19b769 0.0.0.0:38559->193.167.100.100:443 IpTos(Cs0, Ect0) len 1200 client | -> RX Stream { stream_id: 0, offset: 6404, len: 1173, fin: false } client | 0.447 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 316, tv_nsec: 975640983 } client | 0.447 DEBUG [Client fcd39234b2189549] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.447 DEBUG Building Handshake dcid Some(CID [18]: d24ab146fd203916ad50b9ba8652ea19b769) scid Some(CID [0]: ) client | 0.447 DEBUG Building Short dcid Some(CID [18]: d24ab146fd203916ad50b9ba8652ea19b769) client | 0.447 DEBUG [Client fcd39234b2189549] pn=4 type=Short pri-path:d24ab146fd203916ad50b9ba8652ea19b769 0.0.0.0:38559->193.167.100.100:443 IpTos(Cs0, Ect0) len 51 client | TX -> Ack { largest_acknowledged: 1318825232, ack_delay: 3, first_ack_range: 6, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 7, Ce: 0})) } client | 0.447 DEBUG ECN probing: sent 6 probes client | 0.447 DEBUG [Client fcd39234b2189549] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.447 DEBUG Building Handshake dcid Some(CID [18]: d24ab146fd203916ad50b9ba8652ea19b769) scid Some(CID [0]: ) client | 0.447 DEBUG Building Short dcid Some(CID [18]: d24ab146fd203916ad50b9ba8652ea19b769) client | 0.447 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.447 DEBUG [Client fcd39234b2189549] delay duration 78.450605ms client | 0.447 DEBUG Setting timeout of 78.450605ms client | 0.447 DEBUG [Client fcd39234b2189549] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.447 DEBUG Building Handshake dcid Some(CID [18]: d24ab146fd203916ad50b9ba8652ea19b769) scid Some(CID [0]: ) client | 0.447 DEBUG Building Short dcid Some(CID [18]: d24ab146fd203916ad50b9ba8652ea19b769) client | 0.447 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.447 DEBUG [Client fcd39234b2189549] delay duration 78.420799ms client | 0.447 DEBUG Setting timeout of 78.420799ms client | 0.448 DEBUG [Client fcd39234b2189549] pn=1318825233 type=Short pri-path:d24ab146fd203916ad50b9ba8652ea19b769 0.0.0.0:38559->193.167.100.100:443 IpTos(Cs0, Ect0) len 1200 client | -> RX Stream { stream_id: 0, offset: 7577, len: 1173, fin: false } client | 0.448 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 316, tv_nsec: 996620738 } client | 0.448 DEBUG [Client fcd39234b2189549] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.448 DEBUG Building Handshake dcid Some(CID [18]: d24ab146fd203916ad50b9ba8652ea19b769) scid Some(CID [0]: ) client | 0.448 DEBUG Building Short dcid Some(CID [18]: d24ab146fd203916ad50b9ba8652ea19b769) client | 0.448 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.448 DEBUG [Client fcd39234b2189549] delay duration 19.972799ms client | 0.448 DEBUG Setting timeout of 19.972799ms client | 0.448 DEBUG [Client fcd39234b2189549] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.448 DEBUG Building Handshake dcid Some(CID [18]: d24ab146fd203916ad50b9ba8652ea19b769) scid Some(CID [0]: ) client | 0.448 DEBUG Building Short dcid Some(CID [18]: d24ab146fd203916ad50b9ba8652ea19b769) client | 0.448 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.448 DEBUG [Client fcd39234b2189549] delay duration 19.942102ms client | 0.448 DEBUG Setting timeout of 19.942102ms client | 0.449 DEBUG [Client fcd39234b2189549] pn=1318825234 type=Short pri-path:d24ab146fd203916ad50b9ba8652ea19b769 0.0.0.0:38559->193.167.100.100:443 IpTos(Cs0, Ect0) len 1200 client | -> RX Stream { stream_id: 0, offset: 8750, len: 1173, fin: false } client | 0.449 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 316, tv_nsec: 977595153 } client | 0.449 DEBUG [Client fcd39234b2189549] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.449 DEBUG Building Handshake dcid Some(CID [18]: d24ab146fd203916ad50b9ba8652ea19b769) scid Some(CID [0]: ) client | 0.449 DEBUG Building Short dcid Some(CID [18]: d24ab146fd203916ad50b9ba8652ea19b769) client | 0.449 DEBUG [Client fcd39234b2189549] pn=5 type=Short pri-path:d24ab146fd203916ad50b9ba8652ea19b769 0.0.0.0:38559->193.167.100.100:443 IpTos(Cs0, Ect0) len 51 client | TX -> Ack { largest_acknowledged: 1318825234, ack_delay: 7, first_ack_range: 8, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 9, Ce: 0})) } client | 0.449 DEBUG ECN probing: sent 7 probes client | 0.449 DEBUG [Client fcd39234b2189549] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.449 DEBUG Building Handshake dcid Some(CID [18]: d24ab146fd203916ad50b9ba8652ea19b769) scid Some(CID [0]: ) client | 0.449 DEBUG Building Short dcid Some(CID [18]: d24ab146fd203916ad50b9ba8652ea19b769) client | 0.449 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.449 DEBUG [Client fcd39234b2189549] delay duration 76.449891ms client | 0.449 DEBUG Setting timeout of 76.449891ms client | 0.449 DEBUG [Client fcd39234b2189549] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.449 DEBUG Building Handshake dcid Some(CID [18]: d24ab146fd203916ad50b9ba8652ea19b769) scid Some(CID [0]: ) client | 0.449 DEBUG Building Short dcid Some(CID [18]: d24ab146fd203916ad50b9ba8652ea19b769) client | 0.449 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.449 DEBUG [Client fcd39234b2189549] delay duration 76.418462ms client | 0.449 DEBUG Setting timeout of 76.418462ms client | 0.450 DEBUG [Client fcd39234b2189549] pn=1318825235 type=Short pri-path:d24ab146fd203916ad50b9ba8652ea19b769 0.0.0.0:38559->193.167.100.100:443 IpTos(Cs0, Ect0) len 1200 client | -> RX Stream { stream_id: 0, offset: 9923, len: 317, fin: true } client | -> RX Padding { len: 856 } client | 0.450 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 316, tv_nsec: 998574574 } client | 0.450 DEBUG [Client fcd39234b2189549] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.450 DEBUG Building Handshake dcid Some(CID [18]: d24ab146fd203916ad50b9ba8652ea19b769) scid Some(CID [0]: ) client | 0.450 DEBUG Building Short dcid Some(CID [18]: d24ab146fd203916ad50b9ba8652ea19b769) client | 0.450 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.450 DEBUG [Client fcd39234b2189549] delay duration 19.971337ms client | 0.450 DEBUG Setting timeout of 19.971337ms client | 0.450 DEBUG [Client fcd39234b2189549] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.450 DEBUG Building Handshake dcid Some(CID [18]: d24ab146fd203916ad50b9ba8652ea19b769) scid Some(CID [0]: ) client | 0.450 DEBUG Building Short dcid Some(CID [18]: d24ab146fd203916ad50b9ba8652ea19b769) client | 0.450 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.450 DEBUG [Client fcd39234b2189549] delay duration 19.919479ms client | 0.450 DEBUG Setting timeout of 19.919479ms client | 0.450 DEBUG [Client fcd39234b2189549] State change from Connected -> Closing { error: Application(0), timeout: Instant { tv_sec: 317, tv_nsec: 229053110 } } client | 0.450 WARN Unhandled event StateChange(Closing { error: Application(0), timeout: Instant { tv_sec: 317, tv_nsec: 229053110 } }) client | 0.450 DEBUG [Client fcd39234b2189549] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.450 DEBUG Building Handshake dcid Some(CID [18]: d24ab146fd203916ad50b9ba8652ea19b769) scid Some(CID [0]: ) client | 0.450 DEBUG [Recvd-hs] immediate_ack at Instant { tv_sec: 316, tv_nsec: 978690280 } client | 0.450 DEBUG [Client fcd39234b2189549] pn=1 type=Handshake pri-path:d24ab146fd203916ad50b9ba8652ea19b769 0.0.0.0:38559->193.167.100.100:443 IpTos(Cs0, Ect0) len 64 client | TX -> Ack { largest_acknowledged: 1318825226, ack_delay: 1123, first_ack_range: 0, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 1, Ce: 0})) } client | TX -> ConnectionClose { error_code: Transport(12), frame_type: 0, reason_phrase: "" } client | 0.450 DEBUG Building Short dcid Some(CID [18]: d24ab146fd203916ad50b9ba8652ea19b769) client | 0.450 DEBUG [Recvd-ap] immediate_ack at Instant { tv_sec: 316, tv_nsec: 978690280 } client | 0.450 DEBUG [Client fcd39234b2189549] pn=6 type=Short pri-path:d24ab146fd203916ad50b9ba8652ea19b769 0.0.0.0:38559->193.167.100.100:443 IpTos(Cs0, Ect0) len 126 client | TX -> Ack { largest_acknowledged: 1318825235, ack_delay: 14, first_ack_range: 9, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 10, Ce: 0})) } client | TX -> ConnectionClose { error_code: Application(0), frame_type: 0, reason_phrase: "kthxbye!" } client | 0.450 DEBUG ECN probing: sent 8 probes client | 0.450 DEBUG Setting timeout of 250.246472ms client | 0.451 DEBUG [Client fcd39234b2189549] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.452 DEBUG Building Handshake dcid Some(CID [18]: d24ab146fd203916ad50b9ba8652ea19b769) scid Some(CID [0]: ) client | 0.452 DEBUG [Recvd-hs] immediate_ack at Instant { tv_sec: 316, tv_nsec: 980081796 } client | 0.452 DEBUG [Client fcd39234b2189549] pn=2 type=Handshake pri-path:d24ab146fd203916ad50b9ba8652ea19b769 0.0.0.0:38559->193.167.100.100:443 IpTos(Cs0, Ect0) len 64 client | TX -> Ack { largest_acknowledged: 1318825226, ack_delay: 1297, first_ack_range: 0, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 1, Ce: 0})) } client | TX -> ConnectionClose { error_code: Transport(12), frame_type: 0, reason_phrase: "" } client | 0.452 DEBUG Building Short dcid Some(CID [18]: d24ab146fd203916ad50b9ba8652ea19b769) client | 0.452 DEBUG [Recvd-ap] immediate_ack at Instant { tv_sec: 316, tv_nsec: 980081796 } client | 0.452 DEBUG [Client fcd39234b2189549] pn=7 type=Short pri-path:d24ab146fd203916ad50b9ba8652ea19b769 0.0.0.0:38559->193.167.100.100:443 IpTos(Cs0, Ect0) len 127 client | TX -> Ack { largest_acknowledged: 1318825235, ack_delay: 188, first_ack_range: 9, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 10, Ce: 0})) } client | TX -> ConnectionClose { error_code: Application(0), frame_type: 0, reason_phrase: "kthxbye!" } client | 0.452 DEBUG ECN probing: sent 9 probes client | 0.452 DEBUG Setting timeout of 248.892276ms client | 0.452 DEBUG Setting timeout of 248.880574ms client | 0.702 DEBUG [Client fcd39234b2189549] State change from Closing { error: Application(0), timeout: Instant { tv_sec: 317, tv_nsec: 229053110 } } -> Closed(Application(0)) client | 0.702 INFO Closing timer expired client | 0.702 DEBUG Output::None client | 0.702 WARN Unhandled event StateChange(Closed(Application(0))) client | 0.702 DEBUG Timer fired while closed client | 0.702 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:44:25,373 Using the client's key log file. 2025-04-30 08:44:25,383 2025-04-30 08:44:25,384 Using the client's key log file. 2025-04-30 08:44:25,384 Using the client's key log file. 2025-04-30 08:44:25,393 2025-04-30 08:44:25,394 Using the client's key log file. 2025-04-30 08:44:25,394 Using the client's key log file. 2025-04-30 08:44:26,296 Check of downloaded files succeeded.