2025-04-30 11:55:12,849 Generated random file: nawrinkwxk of size: 10240 2025-04-30 11:55:12,849 Requests: https://server4:443/nawrinkwxk 2025-04-30 11:55:12,909 2025-04-30 11:55:12,910 Command: WAITFORSERVER=server:443 CERTS=/tmp/certs_cfx4oh52/ TESTCASE_SERVER=retry TESTCASE_CLIENT=retry WWW=/tmp/www_a14_3_vk/ DOWNLOADS=/tmp/download_3ux_ap2j/ SERVER_LOGS=/tmp/logs_server_ywq5kvj3 CLIENT_LOGS=/tmp/logs_client__okrnbvr SCENARIO="simple-p2p --delay=15ms --bandwidth=10Mbps --queue=25" CLIENT=ghcr.io/mozilla/neqo-qns:latest SERVER=martenseemann/quic-go-interop:latest REQUESTS="https://server4:443/nawrinkwxk" docker compose --env-file empty.env up --abort-on-container-exit --timeout 1 sim client server 2025-04-30 11:55:25,226 Container sim Created Container client Recreate Container server Recreate Container server Recreated Container client Recreated Attaching to client, server, sim sim | waiting 10s for server:443 client | Setting up routes... server | 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 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 client | Endpoint's IPv4 address is 193.167.0.100 client | Endpoint's IPv6 address is fd00:cafe:cafe::100 server | Endpoint's IPv6 address is fd00:cafe:cafe:100::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 retry ']' client | + '[' -n /logs/qlog/ ']' client | + case "$ROLE" in client | + /wait-for-it.sh sim:57832 -s -t 30 server | Using commit: e4bb2dbd5557c9417b30cf9fcd9032fd6fea5366 server | Running QUIC server. client | wait-for-it.sh: waiting 30 seconds for sim:57832 sim | server:443 is available after 1.060687119s 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/nawrinkwxk ']' client | + mapfile -d ' ' -t URLS client | + OPTIONS+=("${URLS[@]}") client | + RUST_LOG=debug client | + RUST_BACKTRACE=1 client | + neqo-client --cc cubic --qns-test retry --qlog-dir /logs/qlog/ --output-dir /downloads 'https://server4:443/nawrinkwxk 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:49741 -> 193.167.100.100:443 client | 0.001 DEBUG [CryptoStates] Creating initial cipher state v=Version1, role=Client dcid=498cca7f57402074077ba9d452 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:49741->193.167.100.100:443] Make permanent client | 0.001 DEBUG [unv-path:498cca7f57402074077ba9d452 0.0.0.0:49741->193.167.100.100:443] set as primary path client | 0.001 DEBUG [pri-unv-path:498cca7f57402074077ba9d452 0.0.0.0:49741->193.167.100.100:443] Path validated Instant { tv_sec: 277, tv_nsec: 829136926 } client | 0.001 DEBUG [Client 498cca7f57402074077ba9d452] client_start client | 0.001 DEBUG Writing transport parameters, msg=1 client | 0.001 DEBUG [Agent 0x557f4c680270] state -> InProgress client | 0.002 DEBUG [Client 498cca7f57402074077ba9d452] State change from Init -> WaitInitial client | 0.002 DEBUG [Client 498cca7f57402074077ba9d452] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.002 DEBUG Building Initial dcid Some(CID [13]: 498cca7f57402074077ba9d452) scid Some(CID [0]: ) client | 0.002 DEBUG CRYPTO for in offset=0, len=1208 client | 0.002 DEBUG [Client 498cca7f57402074077ba9d452] pn=0 type=Initial pri-path:498cca7f57402074077ba9d452 0.0.0.0:49741->193.167.100.100:443 IpTos(Cs0, Ect0) len 1252 client | TX -> Crypto { offset: 0, len: 1208 } client | 0.002 DEBUG packet_sent this=0x557f4c693970, pn=0, ps=1252 client | 0.002 DEBUG ECN probing: sent 1 probes client | 0.002 DEBUG [Client 498cca7f57402074077ba9d452] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.002 DEBUG Building Initial dcid Some(CID [13]: 498cca7f57402074077ba9d452) scid Some(CID [0]: ) client | 0.002 DEBUG CRYPTO for in offset=1208, len=331 client | 0.002 DEBUG [Client 498cca7f57402074077ba9d452] pn=1 type=Initial pri-path:498cca7f57402074077ba9d452 0.0.0.0:49741->193.167.100.100:443 IpTos(Cs0, Ect0) len 376 client | TX -> Crypto { offset: 1208, len: 331 } client | 0.002 DEBUG [Client 498cca7f57402074077ba9d452] pad Initial from 376 to PLPMTU 1252 client | 0.002 DEBUG packet_sent this=0x557f4c693970, pn=1, ps=1252 client | 0.002 DEBUG ECN probing: sent 2 probes client | 0.002 DEBUG [Client 498cca7f57402074077ba9d452] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } client | 0.002 DEBUG Building Initial dcid Some(CID [13]: 498cca7f57402074077ba9d452) 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 498cca7f57402074077ba9d452] delay duration 3.899807ms client | 0.002 DEBUG Setting timeout of 3.899807ms client | 0.002 DEBUG StateChange(WaitInitial) client | 0.002 WARN Cannot create stream ConnectionState client | 0.002 DEBUG [Client 498cca7f57402074077ba9d452] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } client | 0.002 DEBUG Building Initial dcid Some(CID [13]: 498cca7f57402074077ba9d452) 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 498cca7f57402074077ba9d452] delay duration 3.87438ms client | 0.002 DEBUG Setting timeout of 3.87438ms client | 0.007 DEBUG [Client 498cca7f57402074077ba9d452] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.007 DEBUG Building Initial dcid Some(CID [13]: 498cca7f57402074077ba9d452) 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 498cca7f57402074077ba9d452] delay duration 294.82284ms client | 0.007 DEBUG Setting timeout of 294.82284ms client | 0.038 INFO [Client 498cca7f57402074077ba9d452] received Retry client | 0.039 INFO [Client 498cca7f57402074077ba9d452] Valid Retry received, token=839178b410606f4ac9908be7d720d79685340366b2c4aad95a188b2527d55a6f1ad822ae9a355cd0f122d25cb90a54b4a0f531fcafe7a3c1997e50ddb0215b155419b64cd2e246a780fd93f09207b9f8750c50fa093fe994e433d2c079bc7da9ee784f8f4f21d2 scid=0648baf7 client | 0.039 INFO [pri-path:0648baf7 0.0.0.0:49741->193.167.100.100:443] discarding a packet without an RTT estimate; guessing RTT=37.303188ms client | 0.039 DEBUG [Client 498cca7f57402074077ba9d452] Lost: Crypto(CryptoRecoveryToken { space: Initial, offset: 0, length: 1208 }) client | 0.039 INFO Lost crypto frame space=in offset=0 length=1208 client | 0.039 DEBUG [Client 498cca7f57402074077ba9d452] Lost: EcnEct0 client | 0.039 DEBUG [Client 498cca7f57402074077ba9d452] Lost: Crypto(CryptoRecoveryToken { space: Initial, offset: 1208, length: 331 }) client | 0.039 INFO Lost crypto frame space=in offset=1208 length=331 client | 0.039 DEBUG [Client 498cca7f57402074077ba9d452] Lost: EcnEct0 client | 0.039 DEBUG [CryptoStates] Creating initial cipher state v=Version1, role=Client dcid=0648baf7 client | 0.039 DEBUG Making Write Initial CryptoDxState, v=Version1 cipher=4865 client | 0.039 DEBUG Making Read Initial CryptoDxState, v=Version1 cipher=4865 client | 0.039 INFO [CryptoStates] Continue packet numbers for initial after retry (write is 0..0) client | 0.039 DEBUG [Client 498cca7f57402074077ba9d452] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.039 DEBUG Building Initial dcid Some(CID [4]: 0648baf7) scid Some(CID [0]: ) client | 0.039 DEBUG CRYPTO for in offset=0, len=1113 client | 0.039 DEBUG [Client 498cca7f57402074077ba9d452] pn=2 type=Initial pri-path:0648baf7 0.0.0.0:49741->193.167.100.100:443 IpTos(Cs0, Ect0) len 1252 client | TX -> Crypto { offset: 0, len: 1113 } client | 0.039 DEBUG packet_sent this=0x557f4c693970, pn=2, ps=1252 client | 0.039 DEBUG ECN probing: sent 3 probes client | 0.039 DEBUG [Client 498cca7f57402074077ba9d452] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.039 DEBUG Building Initial dcid Some(CID [4]: 0648baf7) scid Some(CID [0]: ) client | 0.039 DEBUG CRYPTO for in offset=1113, len=426 client | 0.039 DEBUG [Client 498cca7f57402074077ba9d452] pn=3 type=Initial pri-path:0648baf7 0.0.0.0:49741->193.167.100.100:443 IpTos(Cs0, Ect0) len 566 client | TX -> Crypto { offset: 1113, len: 426 } client | 0.039 DEBUG [Client 498cca7f57402074077ba9d452] pad Initial from 566 to PLPMTU 1252 client | 0.039 DEBUG packet_sent this=0x557f4c693970, pn=3, ps=1252 client | 0.039 DEBUG ECN probing: sent 4 probes client | 0.039 DEBUG [Client 498cca7f57402074077ba9d452] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.039 DEBUG Building Initial dcid Some(CID [4]: 0648baf7) 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 498cca7f57402074077ba9d452] delay duration 111.798067ms client | 0.039 DEBUG Setting timeout of 111.798067ms client | 0.039 INFO [Client 498cca7f57402074077ba9d452] received Retry client | 0.039 WARN [Client ...] Dropped received packet: Extra Retry; Total: 1 client | 0.039 DEBUG [Client 498cca7f57402074077ba9d452] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.039 DEBUG Building Initial dcid Some(CID [4]: 0648baf7) 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 498cca7f57402074077ba9d452] delay duration 111.755187ms client | 0.039 DEBUG Setting timeout of 111.755187ms client | 0.039 DEBUG [Client 498cca7f57402074077ba9d452] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.039 DEBUG Building Initial dcid Some(CID [4]: 0648baf7) 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 498cca7f57402074077ba9d452] delay duration 111.73562ms client | 0.039 DEBUG Setting timeout of 111.73562ms client | 0.071 DEBUG [Client 498cca7f57402074077ba9d452] pn=0 type=Initial pri-path:0648baf7 0.0.0.0:49741->193.167.100.100:443 IpTos(Cs0, NotEct) len 40 client | -> RX Ack { largest_acknowledged: 2, ack_delay: 0, first_ack_range: 0, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 1, Ce: 0})) } client | 0.071 DEBUG [Client 498cca7f57402074077ba9d452] Rx ACK space=in, ranges=[2..=2] client | 0.071 DEBUG [LossRecovery] ACK for Initial - largest_acked=2 client | 0.071 DEBUG on_packets_acked this=0x557f4c693970, limited=1, bytes_in_flight=1252, cwnd=12520, state=SlowStart, new_acked=1252 client | 0.071 DEBUG Acked crypto frame space=in offset=0 length=1113 client | 0.071 DEBUG [Client 498cca7f57402074077ba9d452] Changing to use Server CID=88389fc7 client | 0.071 DEBUG [Client 498cca7f57402074077ba9d452] State change from WaitInitial -> WaitVersion client | 0.071 DEBUG [Client 498cca7f57402074077ba9d452] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.071 DEBUG Building Initial dcid Some(CID [4]: 88389fc7) scid Some(CID [0]: ) client | 0.071 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.071 DEBUG [Client 498cca7f57402074077ba9d452] delay duration 65.890805ms client | 0.071 DEBUG Setting timeout of 65.890805ms client | 0.071 WARN Unhandled event StateChange(WaitVersion) client | 0.071 DEBUG [Client 498cca7f57402074077ba9d452] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.071 DEBUG Building Initial dcid Some(CID [4]: 88389fc7) scid Some(CID [0]: ) client | 0.071 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.071 DEBUG [Client 498cca7f57402074077ba9d452] delay duration 65.864536ms client | 0.071 DEBUG Setting timeout of 65.864536ms client | 0.073 DEBUG [Client 498cca7f57402074077ba9d452] pn=1 type=Initial pri-path:88389fc7 0.0.0.0:49741->193.167.100.100:443 IpTos(Cs0, NotEct) len 391 client | -> RX Ack { largest_acknowledged: 3, ack_delay: 0, first_ack_range: 1, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 2, Ce: 0})) } client | -> RX Padding { len: 257 } client | -> RX Crypto { offset: 0, len: 90 } client | 0.073 DEBUG [Client 498cca7f57402074077ba9d452] Rx ACK space=in, ranges=[2..=3] client | 0.073 DEBUG [LossRecovery] ACK for Initial - largest_acked=3 client | 0.073 DEBUG on_packets_acked this=0x557f4c693970, limited=1, bytes_in_flight=0, cwnd=12520, state=SlowStart, new_acked=1252 client | 0.073 DEBUG Acked crypto frame space=in offset=1113 length=426 client | 0.073 DEBUG Read Ok(90) bytes client | 0.073 DEBUG Write secret available for Handshake: SymKey [32]: 2d79ee6dfbd2aa488919ecf52989842d3bf30f9f6825044969d064c05624a0b9 client | 0.073 DEBUG Read secret available for Handshake: SymKey [32]: 0c92a12a489df849267ae603d4e1433358f4e9a394d299a4daac3664feca1228 client | 0.073 DEBUG [Agent 0x557f4c680270] state -> InProgress client | 0.073 DEBUG Making Write Handshake CryptoDxState, v=Version1 cipher=4865 client | 0.073 DEBUG Making Read Handshake CryptoDxState, v=Version1 cipher=4865 client | 0.073 DEBUG [Crypto] Handshake keys installed client | 0.073 DEBUG [Recvd-in] Set ACK timer to Instant { tv_sec: 277, tv_nsec: 901441256 } client | 0.073 DEBUG [Client 498cca7f57402074077ba9d452] State change from WaitVersion -> Handshaking client | 0.073 DEBUG [Client 498cca7f57402074077ba9d452] pn=0 type=Handshake pri-path:88389fc7 0.0.0.0:49741->193.167.100.100:443 IpTos(Cs0, NotEct) len 750 client | -> RX Crypto { offset: 0, len: 715 } client | 0.073 DEBUG Read Ok(715) bytes client | 0.074 DEBUG [Agent 0x557f4c680270] state -> AuthenticationPending client | 0.074 DEBUG [Recvd-hs] Set ACK timer to Instant { tv_sec: 277, tv_nsec: 901441256 } client | 0.074 DEBUG saving datagram of 139 bytes client | 0.074 DEBUG [Client 498cca7f57402074077ba9d452] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.074 DEBUG Building Initial dcid Some(CID [4]: 88389fc7) scid Some(CID [0]: ) client | 0.074 DEBUG [Client 498cca7f57402074077ba9d452] pn=4 type=Initial pri-path:88389fc7 0.0.0.0:49741->193.167.100.100:443 IpTos(Cs0, Ect0) len 141 client | TX -> Ack { largest_acknowledged: 1, ack_delay: 146, first_ack_range: 1, ack_ranges: [], ecn_count: None } client | 0.074 DEBUG Building Handshake dcid Some(CID [4]: 88389fc7) scid Some(CID [0]: ) client | 0.074 DEBUG [Client 498cca7f57402074077ba9d452] pn=0 type=Handshake pri-path:88389fc7 0.0.0.0:49741->193.167.100.100:443 IpTos(Cs0, Ect0) len 177 client | TX -> Ack { largest_acknowledged: 0, ack_delay: 146, first_ack_range: 0, ack_ranges: [], ecn_count: None } client | 0.074 DEBUG [Client 498cca7f57402074077ba9d452] Drop packet number space in client | 0.074 DEBUG [LossRecovery] Reset loss recovery state for Initial client | 0.074 WARN [LossRecovery] ignoring in-4 from dropped space client | 0.074 DEBUG ECN probing: sent 5 probes client | 0.074 DEBUG [Client 498cca7f57402074077ba9d452] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.074 DEBUG Building Handshake dcid Some(CID [4]: 88389fc7) scid Some(CID [0]: ) client | 0.074 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.074 DEBUG [Client 498cca7f57402074077ba9d452] delay duration 84.754828ms client | 0.074 DEBUG Setting timeout of 84.754828ms client | 0.074 DEBUG StateChange(Handshaking) client | 0.074 WARN Cannot create stream ConnectionState client | 0.074 DEBUG [Client 498cca7f57402074077ba9d452] Authenticated Ok client | 0.074 DEBUG Write secret available for ApplicationData: SymKey [32]: 1c8edf04601e5a647b2721accfa50578c1679d80633fcf1dc59ddfd8155d0a49 client | 0.074 DEBUG Read secret available for ApplicationData: SymKey [32]: 230963ae91c541dfbfaa565ff22e41a56525db1ab9af26a5dc19c2b165b4a4f2 client | 0.074 DEBUG [Agent 0x557f4c680270] SSL_AuthCertificateComplete: Ok(()) client | 0.074 DEBUG [Agent 0x557f4c680270] 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.074 DEBUG [Client 498cca7f57402074077ba9d452] TLS connection complete client | 0.074 DEBUG Making Write ApplicationData CryptoDxState, v=Version1 cipher=4865 client | 0.074 DEBUG [Crypto] Application write key installed client | 0.074 DEBUG Making Read ApplicationData CryptoDxState, v=Version1 cipher=4865 client | 0.074 DEBUG [Crypto] application read keys installed client | 0.074 DEBUG [Client 498cca7f57402074077ba9d452] State change from Handshaking -> Connected client | 0.074 INFO [Client 498cca7f57402074077ba9d452] Connection established client | 0.074 DEBUG [Client 498cca7f57402074077ba9d452] process saved for epoch ApplicationData client | 0.075 DEBUG [Client 498cca7f57402074077ba9d452] pn=0 type=Short pri-path:88389fc7 0.0.0.0:49741->193.167.100.100:443 IpTos(Cs0, NotEct) len 139 client | -> RX NewConnectionId { sequence_number: 1, retire_prior: 0, connection_id: [152, 165, 166, 109], stateless_reset_token: [88, 179, 133, 18, 7, 230, 52, 59, 246, 131, 200, 76, 7, 40, 110, 61] } client | -> RX NewConnectionId { sequence_number: 3, retire_prior: 0, connection_id: [19, 5, 123, 74], stateless_reset_token: [70, 41, 243, 7, 40, 18, 84, 90, 210, 221, 116, 211, 28, 192, 44, 227] } client | -> RX NewConnectionId { sequence_number: 2, retire_prior: 0, connection_id: [110, 233, 49, 171], stateless_reset_token: [1, 208, 75, 138, 28, 116, 157, 241, 165, 119, 40, 194, 55, 29, 244, 192] } client | -> RX NewConnectionId { sequence_number: 4, retire_prior: 0, connection_id: [120, 5, 216, 249], stateless_reset_token: [98, 74, 223, 187, 58, 152, 10, 110, 97, 155, 136, 203, 112, 188, 213, 89] } client | -> RX NewConnectionId { sequence_number: 5, retire_prior: 0, connection_id: [155, 225, 174, 59], stateless_reset_token: [94, 159, 110, 84, 180, 194, 7, 118, 134, 113, 56, 103, 40, 60, 238, 19] } client | 0.075 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 277, tv_nsec: 921441256 } client | 0.075 DEBUG stream BiDi creatable client | 0.075 INFO Created stream 0 for https://server4/nawrinkwxk client | 0.075 INFO Saving https://server4/nawrinkwxk to "/downloads/nawrinkwxk" client | 0.075 DEBUG stream UniDi creatable client | 0.075 DEBUG StateChange(Connected) client | 0.075 DEBUG stream 0 writable client | 0.075 DEBUG [Client 498cca7f57402074077ba9d452] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.075 DEBUG Building Handshake dcid Some(CID [4]: 88389fc7) scid Some(CID [0]: ) client | 0.075 DEBUG CRYPTO for hs offset=0, len=36 client | 0.075 DEBUG [Client 498cca7f57402074077ba9d452] pn=1 type=Handshake pri-path:88389fc7 0.0.0.0:49741->193.167.100.100:443 IpTos(Cs0, Ect0) len 69 client | TX -> Crypto { offset: 0, len: 36 } client | 0.075 DEBUG packet_sent this=0x557f4c693970, pn=1, ps=69 client | 0.075 DEBUG Building Short dcid Some(CID [4]: 88389fc7) client | 0.075 DEBUG [Client 498cca7f57402074077ba9d452] pn=0 type=Short pri-path:88389fc7 0.0.0.0:49741->193.167.100.100:443 IpTos(Cs0, Ect0) len 111 client | TX -> Stream { stream_id: 0, offset: 0, len: 17, fin: true } client | 0.075 DEBUG packet_sent this=0x557f4c693970, pn=0, ps=42 client | 0.075 DEBUG ECN probing: sent 6 probes client | 0.075 DEBUG [Client 498cca7f57402074077ba9d452] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.075 DEBUG Building Handshake dcid Some(CID [4]: 88389fc7) scid Some(CID [0]: ) client | 0.075 DEBUG Building Short dcid Some(CID [4]: 88389fc7) client | 0.075 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.075 DEBUG [Client 498cca7f57402074077ba9d452] delay duration 18.173925ms client | 0.075 DEBUG Setting timeout of 18.173925ms client | 0.094 DEBUG [Client 498cca7f57402074077ba9d452] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.094 DEBUG Building Handshake dcid Some(CID [4]: 88389fc7) scid Some(CID [0]: ) client | 0.094 DEBUG Building Short dcid Some(CID [4]: 88389fc7) client | 0.094 DEBUG [Client 498cca7f57402074077ba9d452] pn=1 type=Short pri-path:88389fc7 0.0.0.0:49741->193.167.100.100:443 IpTos(Cs0, Ect0) len 28 client | TX -> Ack { largest_acknowledged: 0, ack_delay: 2617, first_ack_range: 0, ack_ranges: [], ecn_count: None } client | 0.094 DEBUG ECN probing: sent 7 probes client | 0.094 DEBUG [Client 498cca7f57402074077ba9d452] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.094 DEBUG Building Handshake dcid Some(CID [4]: 88389fc7) scid Some(CID [0]: ) client | 0.094 DEBUG Building Short dcid Some(CID [4]: 88389fc7) client | 0.094 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.094 DEBUG [Client 498cca7f57402074077ba9d452] delay duration 65.533272ms client | 0.094 DEBUG Setting timeout of 65.533272ms client | 0.106 DEBUG [Client 498cca7f57402074077ba9d452] pn=1 type=Short pri-path:88389fc7 0.0.0.0:49741->193.167.100.100:443 IpTos(Cs0, Ect0) len 259 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 | -> RX HandshakeDone client | -> RX NewToken { token: [145, 213, 234, 243, 136, 172, 106, 135, 57, 157, 190, 103, 220, 195, 245, 101, 203, 87, 169, 27, 41, 66, 4, 150, 191, 49, 235, 3, 217, 147, 206, 128, 238, 39, 116, 72, 206, 211, 251, 18, 208, 23, 212, 7, 117, 52, 69, 95, 249, 245, 204, 187, 23, 56, 114, 225, 7, 148, 149, 120, 76, 84, 98, 59, 194, 152, 22, 157, 77, 39, 224, 125, 126, 176, 10, 221, 217, 8, 36, 35, 165, 49, 242, 221, 33, 108] } client | -> RX Crypto { offset: 0, len: 138 } client | 0.106 DEBUG [Client 498cca7f57402074077ba9d452] Rx ACK space=ap, ranges=[0..=0] client | 0.106 DEBUG [LossRecovery] ACK for ApplicationData - largest_acked=0 client | 0.106 DEBUG on_packets_acked this=0x557f4c693970, limited=1, bytes_in_flight=69, cwnd=12520, state=SlowStart, new_acked=42 client | 0.106 DEBUG [Client 498cca7f57402074077ba9d452] State change from Connected -> Confirmed client | 0.106 DEBUG PMTUD started with probe size 1380 client | 0.106 DEBUG [Client 498cca7f57402074077ba9d452] Drop packet number space hs client | 0.106 DEBUG [LossRecovery] Reset loss recovery state for Handshake client | 0.106 DEBUG [Client 498cca7f57402074077ba9d452] No preferred address to migrate to client | 0.106 DEBUG Read Ok(138) bytes client | 0.106 DEBUG [0x557f4c680270] Got resumption token [817]: 02000633fd97128e..6580a820fed94793 client | 0.106 DEBUG [Agent 0x557f4c680270] 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.106 DEBUG setting max_stream_data to 524288 client | 0.106 DEBUG resumption token [1005]: 0000000123405d00..6580a820fed94793 client | 0.106 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 277, tv_nsec: 954194357 } client | 0.106 DEBUG [Client 498cca7f57402074077ba9d452] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.106 DEBUG Building Short dcid Some(CID [4]: 88389fc7) client | 0.106 DEBUG Sending PMTUD probe of size 1380, count 1 client | 0.106 DEBUG [Client 498cca7f57402074077ba9d452] pn=2 type=Short pri-path:88389fc7 0.0.0.0:49741->193.167.100.100:443 IpTos(Cs0, Ect0) len 1352 client | TX -> Ping client | TX -> Padding { len: 1329 } client | 0.106 DEBUG packet_sent this=0x557f4c693970, pn=2, ps=1352 client | 0.106 DEBUG ECN probing: sent 8 probes client | 0.106 DEBUG [Client 498cca7f57402074077ba9d452] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.106 DEBUG Building Short dcid Some(CID [4]: 88389fc7) client | 0.106 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.106 DEBUG [Client 498cca7f57402074077ba9d452] delay duration 19.627623ms client | 0.106 DEBUG Setting timeout of 19.627623ms client | 0.106 DEBUG stream 0 complete client | 0.106 WARN Unhandled event StateChange(Confirmed) client | 0.106 DEBUG stream BiDi creatable client | 0.106 DEBUG stream UniDi creatable client | 0.106 DEBUG [Client 498cca7f57402074077ba9d452] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.106 DEBUG Building Short dcid Some(CID [4]: 88389fc7) client | 0.106 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.106 DEBUG [Client 498cca7f57402074077ba9d452] delay duration 19.585995ms client | 0.106 DEBUG Setting timeout of 19.585995ms client | 0.107 DEBUG [Client 498cca7f57402074077ba9d452] pn=2 type=Short pri-path:88389fc7 0.0.0.0:49741->193.167.100.100:443 IpTos(Cs0, Ect0) len 1280 client | -> RX Stream { stream_id: 0, offset: 0, len: >>1259, fin: false } client | 0.107 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 277, tv_nsec: 935441331 } client | 0.107 DEBUG [Client 498cca7f57402074077ba9d452] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.107 DEBUG Building Short dcid Some(CID [4]: 88389fc7) client | 0.107 DEBUG [Client 498cca7f57402074077ba9d452] pn=3 type=Short pri-path:88389fc7 0.0.0.0:49741->193.167.100.100:443 IpTos(Cs0, Ect0) len 30 client | TX -> Ack { largest_acknowledged: 2, ack_delay: 3, first_ack_range: 2, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 2, Ce: 0})) } client | 0.107 DEBUG ECN probing: sent 9 probes client | 0.107 DEBUG [Client 498cca7f57402074077ba9d452] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.107 DEBUG Building Short dcid Some(CID [4]: 88389fc7) client | 0.107 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.107 DEBUG [Client 498cca7f57402074077ba9d452] delay duration 102.285168ms client | 0.107 DEBUG Setting timeout of 102.285168ms client | 0.107 DEBUG [Client 498cca7f57402074077ba9d452] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.107 DEBUG Building Short dcid Some(CID [4]: 88389fc7) client | 0.107 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.107 DEBUG [Client 498cca7f57402074077ba9d452] delay duration 102.258969ms client | 0.107 DEBUG Setting timeout of 102.258969ms client | 0.108 DEBUG [Client 498cca7f57402074077ba9d452] pn=3 type=Short pri-path:88389fc7 0.0.0.0:49741->193.167.100.100:443 IpTos(Cs0, Ect0) len 1280 client | -> RX Stream { stream_id: 0, offset: 1259, len: >>1257, fin: false } client | 0.108 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 277, tv_nsec: 956475316 } client | 0.108 DEBUG [Client 498cca7f57402074077ba9d452] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.108 DEBUG Building Short dcid Some(CID [4]: 88389fc7) client | 0.108 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.108 DEBUG [Client 498cca7f57402074077ba9d452] delay duration 19.97358ms client | 0.108 DEBUG Setting timeout of 19.97358ms client | 0.108 DEBUG [Client 498cca7f57402074077ba9d452] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.108 DEBUG Building Short dcid Some(CID [4]: 88389fc7) client | 0.108 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.108 DEBUG [Client 498cca7f57402074077ba9d452] delay duration 19.952721ms client | 0.108 DEBUG Setting timeout of 19.952721ms client | 0.109 DEBUG [Client 498cca7f57402074077ba9d452] pn=4 type=Short pri-path:88389fc7 0.0.0.0:49741->193.167.100.100:443 IpTos(Cs0, Ect0) len 1280 client | -> RX Stream { stream_id: 0, offset: 2516, len: >>1257, fin: false } client | 0.109 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 277, tv_nsec: 937520022 } client | 0.109 DEBUG [Client 498cca7f57402074077ba9d452] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.109 DEBUG Building Short dcid Some(CID [4]: 88389fc7) client | 0.109 DEBUG [Client 498cca7f57402074077ba9d452] pn=4 type=Short pri-path:88389fc7 0.0.0.0:49741->193.167.100.100:443 IpTos(Cs0, Ect0) len 30 client | TX -> Ack { largest_acknowledged: 4, ack_delay: 7, first_ack_range: 4, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 4, Ce: 0})) } client | 0.109 DEBUG ECN probing: sent 10 probes client | 0.109 DEBUG ECN probing concluded with 10 probes sent client | 0.109 DEBUG [Client 498cca7f57402074077ba9d452] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.109 DEBUG Building Short dcid Some(CID [4]: 88389fc7) client | 0.109 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.109 DEBUG [Client 498cca7f57402074077ba9d452] delay duration 100.14843ms client | 0.109 DEBUG Setting timeout of 100.14843ms client | 0.109 DEBUG [Client 498cca7f57402074077ba9d452] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.109 DEBUG Building Short dcid Some(CID [4]: 88389fc7) client | 0.109 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.109 DEBUG [Client 498cca7f57402074077ba9d452] delay duration 100.118354ms client | 0.109 DEBUG Setting timeout of 100.118354ms client | 0.110 DEBUG [Client 498cca7f57402074077ba9d452] pn=5 type=Short pri-path:88389fc7 0.0.0.0:49741->193.167.100.100:443 IpTos(Cs0, Ect0) len 1280 client | -> RX Stream { stream_id: 0, offset: 3773, len: >>1257, fin: false } client | 0.110 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 277, tv_nsec: 958573722 } client | 0.110 DEBUG [Client 498cca7f57402074077ba9d452] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.110 DEBUG Building Short dcid Some(CID [4]: 88389fc7) client | 0.110 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.110 DEBUG [Client 498cca7f57402074077ba9d452] delay duration 19.972459ms client | 0.110 DEBUG Setting timeout of 19.972459ms client | 0.110 DEBUG [Client 498cca7f57402074077ba9d452] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.110 DEBUG Building Short dcid Some(CID [4]: 88389fc7) client | 0.110 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.110 DEBUG [Client 498cca7f57402074077ba9d452] delay duration 19.942002ms client | 0.110 DEBUG Setting timeout of 19.942002ms client | 0.111 DEBUG [Client 498cca7f57402074077ba9d452] pn=6 type=Short pri-path:88389fc7 0.0.0.0:49741->193.167.100.100:443 IpTos(Cs0, Ect0) len 1280 client | -> RX Stream { stream_id: 0, offset: 5030, len: >>1257, fin: false } client | 0.111 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 277, tv_nsec: 939619369 } client | 0.111 DEBUG [Client 498cca7f57402074077ba9d452] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.111 DEBUG Building Short dcid Some(CID [4]: 88389fc7) client | 0.111 DEBUG [Client 498cca7f57402074077ba9d452] pn=5 type=Short pri-path:88389fc7 0.0.0.0:49741->193.167.100.100:443 IpTos(Cs0, NotEct) len 30 client | TX -> Ack { largest_acknowledged: 6, ack_delay: 3, first_ack_range: 6, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 6, Ce: 0})) } client | 0.111 DEBUG [Client 498cca7f57402074077ba9d452] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.111 DEBUG Building Short dcid Some(CID [4]: 88389fc7) client | 0.111 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.111 DEBUG [Client 498cca7f57402074077ba9d452] delay duration 98.118892ms client | 0.111 DEBUG Setting timeout of 98.118892ms client | 0.111 DEBUG [Client 498cca7f57402074077ba9d452] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.111 DEBUG Building Short dcid Some(CID [4]: 88389fc7) client | 0.111 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.111 DEBUG [Client 498cca7f57402074077ba9d452] delay duration 98.093925ms client | 0.111 DEBUG Setting timeout of 98.093925ms client | 0.112 DEBUG [Client 498cca7f57402074077ba9d452] pn=7 type=Short pri-path:88389fc7 0.0.0.0:49741->193.167.100.100:443 IpTos(Cs0, Ect0) len 1280 client | -> RX Stream { stream_id: 0, offset: 6287, len: >>1257, fin: false } client | 0.112 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 277, tv_nsec: 960669494 } client | 0.112 DEBUG [Client 498cca7f57402074077ba9d452] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.112 DEBUG Building Short dcid Some(CID [4]: 88389fc7) client | 0.112 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.112 DEBUG [Client 498cca7f57402074077ba9d452] delay duration 19.971747ms client | 0.112 DEBUG Setting timeout of 19.971747ms client | 0.112 DEBUG [Client 498cca7f57402074077ba9d452] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.112 DEBUG Building Short dcid Some(CID [4]: 88389fc7) client | 0.112 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.112 DEBUG [Client 498cca7f57402074077ba9d452] delay duration 19.950387ms client | 0.112 DEBUG Setting timeout of 19.950387ms client | 0.113 DEBUG [Client 498cca7f57402074077ba9d452] pn=8 type=Short pri-path:88389fc7 0.0.0.0:49741->193.167.100.100:443 IpTos(Cs0, Ect0) len 1280 client | -> RX Stream { stream_id: 0, offset: 7544, len: >>1257, fin: false } client | 0.113 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 277, tv_nsec: 941715632 } client | 0.113 DEBUG [Client 498cca7f57402074077ba9d452] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.113 DEBUG Building Short dcid Some(CID [4]: 88389fc7) client | 0.113 DEBUG [Client 498cca7f57402074077ba9d452] pn=6 type=Short pri-path:88389fc7 0.0.0.0:49741->193.167.100.100:443 IpTos(Cs0, NotEct) len 30 client | TX -> Ack { largest_acknowledged: 8, ack_delay: 3, first_ack_range: 8, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 8, Ce: 0})) } client | 0.113 DEBUG [Client 498cca7f57402074077ba9d452] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.113 DEBUG Building Short dcid Some(CID [4]: 88389fc7) client | 0.113 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.113 DEBUG [Client 498cca7f57402074077ba9d452] delay duration 96.02338ms client | 0.113 DEBUG Setting timeout of 96.02338ms client | 0.113 DEBUG [Client 498cca7f57402074077ba9d452] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.113 DEBUG Building Short dcid Some(CID [4]: 88389fc7) client | 0.113 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.113 DEBUG [Client 498cca7f57402074077ba9d452] delay duration 95.991119ms client | 0.113 DEBUG Setting timeout of 95.991119ms client | 0.114 DEBUG [Client 498cca7f57402074077ba9d452] pn=9 type=Short pri-path:88389fc7 0.0.0.0:49741->193.167.100.100:443 IpTos(Cs0, Ect0) len 1280 client | -> RX Stream { stream_id: 0, offset: 8801, len: >>1257, fin: false } client | 0.114 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 277, tv_nsec: 962763545 } client | 0.114 DEBUG [Client 498cca7f57402074077ba9d452] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.114 DEBUG Building Short dcid Some(CID [4]: 88389fc7) client | 0.114 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.114 DEBUG [Client 498cca7f57402074077ba9d452] delay duration 19.974001ms client | 0.114 DEBUG Setting timeout of 19.974001ms client | 0.114 DEBUG [Client 498cca7f57402074077ba9d452] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.114 DEBUG Building Short dcid Some(CID [4]: 88389fc7) client | 0.114 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.114 DEBUG [Client 498cca7f57402074077ba9d452] delay duration 19.952591ms client | 0.114 DEBUG Setting timeout of 19.952591ms client | 0.114 DEBUG [Client 498cca7f57402074077ba9d452] pn=10 type=Short pri-path:88389fc7 0.0.0.0:49741->193.167.100.100:443 IpTos(Cs0, Ect0) len 205 client | -> RX Stream { stream_id: 0, offset: 10058, len: >>182, fin: true } client | 0.114 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 277, tv_nsec: 942964702 } client | 0.114 DEBUG [Client 498cca7f57402074077ba9d452] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.114 DEBUG Building Short dcid Some(CID [4]: 88389fc7) client | 0.114 DEBUG [Client 498cca7f57402074077ba9d452] pn=7 type=Short pri-path:88389fc7 0.0.0.0:49741->193.167.100.100:443 IpTos(Cs0, NotEct) len 30 client | TX -> Ack { largest_acknowledged: 10, ack_delay: 2, first_ack_range: 10, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 10, Ce: 0})) } client | 0.115 DEBUG [Client 498cca7f57402074077ba9d452] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.115 DEBUG Building Short dcid Some(CID [4]: 88389fc7) client | 0.115 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.115 DEBUG [Client 498cca7f57402074077ba9d452] delay duration 94.727673ms client | 0.115 DEBUG Setting timeout of 94.727673ms client | 0.115 DEBUG [Client 498cca7f57402074077ba9d452] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.115 DEBUG Building Short dcid Some(CID [4]: 88389fc7) client | 0.115 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.115 DEBUG [Client 498cca7f57402074077ba9d452] delay duration 94.66759ms client | 0.115 DEBUG Setting timeout of 94.66759ms client | 0.115 DEBUG [Client 498cca7f57402074077ba9d452] State change from Confirmed -> Closing { error: Application(0), timeout: Instant { tv_sec: 278, tv_nsec: 253193778 } } client | 0.115 WARN Unhandled event StateChange(Closing { error: Application(0), timeout: Instant { tv_sec: 278, tv_nsec: 253193778 } }) client | 0.115 DEBUG [Client 498cca7f57402074077ba9d452] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.115 DEBUG Building Short dcid Some(CID [4]: 88389fc7) client | 0.115 DEBUG [Recvd-ap] immediate_ack at Instant { tv_sec: 277, tv_nsec: 943175567 } client | 0.115 DEBUG [Client 498cca7f57402074077ba9d452] pn=8 type=Short pri-path:88389fc7 0.0.0.0:49741->193.167.100.100:443 IpTos(Cs0, NotEct) len 41 client | TX -> Ack { largest_acknowledged: 10, ack_delay: 26, first_ack_range: 10, 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.115 DEBUG Setting timeout of 309.960423ms client | 0.145 DEBUG [Client 498cca7f57402074077ba9d452] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.145 DEBUG Building Short dcid Some(CID [4]: 88389fc7) client | 0.145 DEBUG [Recvd-ap] immediate_ack at Instant { tv_sec: 277, tv_nsec: 973617954 } client | 0.145 DEBUG [Client 498cca7f57402074077ba9d452] pn=9 type=Short pri-path:88389fc7 0.0.0.0:49741->193.167.100.100:443 IpTos(Cs0, NotEct) len 42 client | TX -> Ack { largest_acknowledged: 10, ack_delay: 3831, first_ack_range: 10, 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.145 DEBUG Setting timeout of 279.459757ms client | 0.145 DEBUG Setting timeout of 279.446231ms client | 0.426 DEBUG [Client 498cca7f57402074077ba9d452] State change from Closing { error: Application(0), timeout: Instant { tv_sec: 278, tv_nsec: 253193778 } } -> Closed(Application(0)) client | 0.426 INFO Closing timer expired client | 0.426 DEBUG Output::None client | 0.426 WARN Unhandled event StateChange(Closed(Application(0))) client | 0.426 DEBUG Timer fired while closed client | 0.426 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:55:25,321 Using the client's key log file. 2025-04-30 11:55:25,330 2025-04-30 11:55:25,331 Using the client's key log file. 2025-04-30 11:55:25,331 Using the client's key log file. 2025-04-30 11:55:25,339 2025-04-30 11:55:25,339 Using the client's key log file. 2025-04-30 11:55:25,908 Check of downloaded files succeeded. 2025-04-30 11:55:26,489 Check of Retry succeeded. Token used: 839178b410606f4ac9908be7d720d79685340366b2c4aad95a188b2527d55a6f1ad822ae9a355cd0f122d25cb90a54b4a0f531fcafe7a3c1997e50ddb0215b155419b64cd2e246a780fd93f09207b9f8750c50fa093fe994e433d2c079bc7da9ee784f8f4f21d2