2025-04-30 13:42:48,478 Generated random file: juznrwjmeg of size: 5120 2025-04-30 13:42:48,478 Generated random file: eoutpvnkpu of size: 10240 2025-04-30 13:42:48,478 Requests: https://server6:443/juznrwjmeg https://server6:443/eoutpvnkpu 2025-04-30 13:42:48,539 2025-04-30 13:42:48,539 Command: WAITFORSERVER=server:443 CERTS=/tmp/certs_dc6s055z/ TESTCASE_SERVER=transfer TESTCASE_CLIENT=transfer WWW=/tmp/www_kamoclr6/ DOWNLOADS=/tmp/download_w6vtbb4i/ SERVER_LOGS=/tmp/logs_server_9u59n9bv CLIENT_LOGS=/tmp/logs_client_2_sbe425 SCENARIO="simple-p2p --delay=15ms --bandwidth=10Mbps --queue=25" CLIENT=ghcr.io/mozilla/neqo-qns:latest SERVER=ghcr.io/aws/s2n-quic/s2n-quic-qns:latest REQUESTS="https://server6:443/juznrwjmeg https://server6:443/eoutpvnkpu" docker compose --env-file empty.env up --abort-on-container-exit --timeout 1 sim client server 2025-04-30 13:43:00,940 Container sim Recreate Container sim Recreated Container client Recreate Container server Recreate Container server Recreated Container client Recreated Attaching to client, server, sim sim | waiting 10s for server:443 server | Setting up routes... client | Setting up routes... server | Actual changes: server | tx-checksum-ip-generic: off client | Actual changes: server | tx-tcp-segmentation: off [not requested] server | tx-tcp-ecn-segmentation: off [not requested] server | tx-tcp-mangleid-segmentation: off [not requested] client | tx-checksum-ip-generic: off server | tx-tcp6-segmentation: off [not requested] client | tx-tcp-segmentation: off [not requested] client | tx-tcp-ecn-segmentation: off [not requested] client | tx-tcp-mangleid-segmentation: off [not requested] client | tx-tcp6-segmentation: off [not requested] client | tx-udp-segmentation: off [not requested] client | tx-checksum-sctp: off server | tx-udp-segmentation: off [not requested] server | tx-checksum-sctp: off client | Endpoint's IPv4 address is 193.167.0.100 server | Endpoint's IPv4 address is 193.167.100.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 transfer ']' client | + '[' -n /logs/qlog/ ']' client | + case "$ROLE" in client | + /wait-for-it.sh sim:57832 -s -t 30 server | x86_64 client | wait-for-it.sh: waiting 30 seconds for sim:57832 server | Server listening on port 443 sim | server:443 is available after 1.007347995s sim | Using scenario: simple-p2p --delay=15ms --bandwidth=10Mbps --queue=25 sim | tcpdump: tcpdump: listening on eth0listening on eth1, link-type EN10MB (Ethernet), link-type EN10MB (Ethernet), snapshot length 262144 bytes sim | , 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://server6:443/juznrwjmeg https://server6:443/eoutpvnkpu' ']' client | + mapfile -d ' ' -t URLS client | + OPTIONS+=("${URLS[@]}") client | + RUST_LOG=debug client | + RUST_BACKTRACE=1 client | + neqo-client --cc cubic --qns-test transfer --qlog-dir /logs/qlog/ --output-dir /downloads https://server6:443/juznrwjmeg 'https://server6:443/eoutpvnkpu 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: [::]:34623 -> [fd00:cafe:cafe:100::100]:443 client | 0.001 DEBUG [CryptoStates] Creating initial cipher state v=Version1, role=Client dcid=ef491e0089af75a0 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 fd00:cafe:cafe:100::100 has MTU 1500 client | 0.001 DEBUG [unv-path [::]:34623->[fd00:cafe:cafe:100::100]:443] Make permanent client | 0.001 DEBUG [unv-path:ef491e0089af75a0 [::]:34623->[fd00:cafe:cafe:100::100]:443] set as primary path client | 0.001 DEBUG [pri-unv-path:ef491e0089af75a0 [::]:34623->[fd00:cafe:cafe:100::100]:443] Path validated Instant { tv_sec: 732, tv_nsec: 465333362 } client | 0.001 DEBUG [Client ef491e0089af75a0] client_start client | 0.001 DEBUG Writing transport parameters, msg=1 client | 0.001 DEBUG [Agent 0x560fc1313ed0] state -> InProgress client | 0.001 DEBUG [Client ef491e0089af75a0] State change from Init -> WaitInitial client | 0.001 DEBUG [Client ef491e0089af75a0] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } client | 0.001 DEBUG Building Initial dcid Some(CID [8]: ef491e0089af75a0) scid Some(CID [0]: ) client | 0.001 DEBUG CRYPTO for in offset=0, len=1193 client | 0.002 DEBUG [Client ef491e0089af75a0] pn=0 type=Initial pri-path:ef491e0089af75a0 [::]:34623->[fd00:cafe:cafe:100::100]:443 IpTos(Cs0, Ect0) len 1232 client | TX -> Crypto { offset: 0, len: 1193 } client | 0.002 DEBUG packet_sent this=0x560fc13276d0, pn=0, ps=1232 client | 0.002 DEBUG ECN probing: sent 1 probes client | 0.002 DEBUG [Client ef491e0089af75a0] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } client | 0.002 DEBUG Building Initial dcid Some(CID [8]: ef491e0089af75a0) scid Some(CID [0]: ) client | 0.002 DEBUG CRYPTO for in offset=1193, len=346 client | 0.002 DEBUG [Client ef491e0089af75a0] pn=1 type=Initial pri-path:ef491e0089af75a0 [::]:34623->[fd00:cafe:cafe:100::100]:443 IpTos(Cs0, Ect0) len 386 client | TX -> Crypto { offset: 1193, len: 346 } client | 0.002 DEBUG [Client ef491e0089af75a0] pad Initial from 386 to PLPMTU 1232 client | 0.002 DEBUG packet_sent this=0x560fc13276d0, pn=1, ps=1232 client | 0.002 DEBUG ECN probing: sent 2 probes client | 0.002 DEBUG [Client ef491e0089af75a0] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } client | 0.002 DEBUG Building Initial dcid Some(CID [8]: ef491e0089af75a0) 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 ef491e0089af75a0] delay duration 3.848772ms client | 0.002 DEBUG Setting timeout of 3.848772ms client | 0.002 DEBUG StateChange(WaitInitial) client | 0.002 WARN Cannot create stream ConnectionState client | 0.002 DEBUG [Client ef491e0089af75a0] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } client | 0.002 DEBUG Building Initial dcid Some(CID [8]: ef491e0089af75a0) 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 ef491e0089af75a0] delay duration 3.82128ms client | 0.002 DEBUG Setting timeout of 3.82128ms client | 0.007 DEBUG [Client ef491e0089af75a0] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } client | 0.007 DEBUG Building Initial dcid Some(CID [8]: ef491e0089af75a0) scid Some(CID [0]: ) client | 0.007 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } client | 0.007 DEBUG [Client ef491e0089af75a0] delay duration 294.665452ms client | 0.007 DEBUG Setting timeout of 294.665452ms client | 0.044 DEBUG [Client ef491e0089af75a0] pn=0 type=Initial pri-path:ef491e0089af75a0 [::]:34623->[fd00:cafe:cafe:100::100]:443 IpTos(Cs0, Ect0) len 146 client | -> RX Ack { largest_acknowledged: 1, ack_delay: 1754, 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.044 DEBUG [Client ef491e0089af75a0] Rx ACK space=in, ranges=[0..=1] client | 0.044 DEBUG [LossRecovery] ACK for Initial - largest_acked=1 client | 0.044 DEBUG on_packets_acked this=0x560fc13276d0, limited=1, bytes_in_flight=0, cwnd=12320, state=SlowStart, new_acked=2464 client | 0.044 DEBUG Acked crypto frame space=in offset=1193 length=346 client | 0.044 DEBUG Acked crypto frame space=in offset=0 length=1193 client | 0.044 DEBUG Read Ok(90) bytes client | 0.044 DEBUG Write secret available for Handshake: SymKey [32]: bf7a63c593173ad2fdcca68743de9a00cb6d35a92698740ce2b2b8b1ad6cb795 client | 0.044 DEBUG Read secret available for Handshake: SymKey [32]: 44bf4a1766f1db8258aca42e16ebc7f4018f7fa636b22bbc52418adecf86d743 client | 0.044 DEBUG [Agent 0x560fc1313ed0] state -> InProgress client | 0.044 DEBUG Making Write Handshake CryptoDxState, v=Version1 cipher=4865 client | 0.044 DEBUG Making Read Handshake CryptoDxState, v=Version1 cipher=4865 client | 0.044 DEBUG [Crypto] Handshake keys installed client | 0.044 DEBUG [Recvd-in] Set ACK timer to Instant { tv_sec: 732, tv_nsec: 508343777 } client | 0.044 DEBUG [Client ef491e0089af75a0] Changing to use Server CID=39f726792670847def54700a8a89049c client | 0.044 DEBUG [Client ef491e0089af75a0] State change from WaitInitial -> Handshaking client | 0.044 DEBUG [Client ef491e0089af75a0] pn=0 type=Handshake pri-path:39f726792670847def54700a8a89049c [::]:34623->[fd00:cafe:cafe:100::100]:443 IpTos(Cs0, Ect0) len 1086 client | -> RX Crypto { offset: 0, len: 683 } client | -> RX Padding { len: 357 } client | 0.044 DEBUG Read Ok(683) bytes client | 0.045 DEBUG [Agent 0x560fc1313ed0] state -> AuthenticationPending client | 0.045 DEBUG [Recvd-hs] Set ACK timer to Instant { tv_sec: 732, tv_nsec: 508343777 } client | 0.045 DEBUG [Client ef491e0089af75a0] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } client | 0.045 DEBUG Building Initial dcid Some(CID [16]: 39f726792670847def54700a8a89049c) scid Some(CID [0]: ) client | 0.045 DEBUG [Client ef491e0089af75a0] pn=2 type=Initial pri-path:39f726792670847def54700a8a89049c [::]:34623->[fd00:cafe:cafe:100::100]:443 IpTos(Cs0, Ect0) len 52 client | TX -> Ack { largest_acknowledged: 0, ack_delay: 141, first_ack_range: 0, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 1, Ce: 0})) } client | 0.045 DEBUG Building Handshake dcid Some(CID [16]: 39f726792670847def54700a8a89049c) scid Some(CID [0]: ) client | 0.045 DEBUG [Client ef491e0089af75a0] pn=0 type=Handshake pri-path:39f726792670847def54700a8a89049c [::]:34623->[fd00:cafe:cafe:100::100]:443 IpTos(Cs0, Ect0) len 103 client | TX -> Ack { largest_acknowledged: 0, ack_delay: 141, first_ack_range: 0, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 1, Ce: 0})) } client | 0.045 DEBUG [Client ef491e0089af75a0] Drop packet number space in client | 0.045 DEBUG [LossRecovery] Reset loss recovery state for Initial client | 0.045 WARN [LossRecovery] ignoring in-2 from dropped space client | 0.045 DEBUG ECN probing: sent 3 probes client | 0.045 DEBUG [Client ef491e0089af75a0] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } client | 0.045 DEBUG Building Handshake dcid Some(CID [16]: 39f726792670847def54700a8a89049c) scid Some(CID [0]: ) client | 0.045 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } client | 0.045 DEBUG [Client ef491e0089af75a0] delay duration 125.753665ms client | 0.045 DEBUG Setting timeout of 125.753665ms client | 0.045 DEBUG StateChange(Handshaking) client | 0.045 WARN Cannot create stream ConnectionState client | 0.045 DEBUG [Client ef491e0089af75a0] Authenticated Ok client | 0.045 DEBUG Write secret available for ApplicationData: SymKey [32]: 93fd005e864f125d2a29a49cf94b243738578a18c3511161ff1af4a4a666468a client | 0.045 DEBUG Read secret available for ApplicationData: SymKey [32]: 7d91d6d093786eb4ed4736ffc6a381bce67f572917e0e0457cd7f69d598732a3 client | 0.045 DEBUG [Agent 0x560fc1313ed0] SSL_AuthCertificateComplete: Ok(()) client | 0.045 DEBUG [Agent 0x560fc1313ed0] 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.045 DEBUG [Client ef491e0089af75a0] TLS connection complete client | 0.045 DEBUG Making Write ApplicationData CryptoDxState, v=Version1 cipher=4865 client | 0.045 DEBUG [Crypto] Application write key installed client | 0.045 DEBUG Making Read ApplicationData CryptoDxState, v=Version1 cipher=4865 client | 0.045 DEBUG [Crypto] application read keys installed client | 0.045 DEBUG [Client ef491e0089af75a0] State change from Handshaking -> Connected client | 0.045 INFO [Client ef491e0089af75a0] Connection established client | 0.045 DEBUG stream BiDi creatable client | 0.045 INFO Created stream 0 for https://server6/juznrwjmeg client | 0.045 INFO Saving https://server6/juznrwjmeg to "/downloads/juznrwjmeg" client | 0.045 INFO Created stream 4 for https://server6/eoutpvnkpu client | 0.045 INFO Saving https://server6/eoutpvnkpu to "/downloads/eoutpvnkpu" client | 0.045 DEBUG stream UniDi creatable client | 0.045 DEBUG StateChange(Connected) client | 0.045 DEBUG stream 0 writable client | 0.045 DEBUG stream 4 writable client | 0.045 DEBUG [Client ef491e0089af75a0] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } client | 0.045 DEBUG Building Handshake dcid Some(CID [16]: 39f726792670847def54700a8a89049c) scid Some(CID [0]: ) client | 0.045 DEBUG CRYPTO for hs offset=0, len=36 client | 0.045 DEBUG [Client ef491e0089af75a0] pn=1 type=Handshake pri-path:39f726792670847def54700a8a89049c [::]:34623->[fd00:cafe:cafe:100::100]:443 IpTos(Cs0, Ect0) len 81 client | TX -> Crypto { offset: 0, len: 36 } client | 0.045 DEBUG packet_sent this=0x560fc13276d0, pn=1, ps=81 client | 0.045 DEBUG Building Short dcid Some(CID [16]: 39f726792670847def54700a8a89049c) client | 0.045 DEBUG [Client ef491e0089af75a0] pn=0 type=Short pri-path:39f726792670847def54700a8a89049c [::]:34623->[fd00:cafe:cafe:100::100]:443 IpTos(Cs0, Ect0) len 155 client | TX -> Stream { stream_id: 0, offset: 0, len: 17, fin: true } client | TX -> Stream { stream_id: 4, offset: 0, len: 17, fin: true } client | 0.045 DEBUG packet_sent this=0x560fc13276d0, pn=0, ps=74 client | 0.045 DEBUG ECN probing: sent 4 probes client | 0.045 DEBUG [Client ef491e0089af75a0] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } client | 0.045 DEBUG Building Handshake dcid Some(CID [16]: 39f726792670847def54700a8a89049c) scid Some(CID [0]: ) client | 0.045 DEBUG Building Short dcid Some(CID [16]: 39f726792670847def54700a8a89049c) client | 0.045 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } client | 0.045 DEBUG [Client ef491e0089af75a0] delay duration 125.747564ms client | 0.045 DEBUG Setting timeout of 125.747564ms client | 0.078 DEBUG [Client ef491e0089af75a0] pn=0 type=Short pri-path:39f726792670847def54700a8a89049c [::]:34623->[fd00:cafe:cafe:100::100]:443 IpTos(Cs0, Ect0) len 1452 client | -> RX Ping client | -> RX Padding { len: 1433 } client | 0.078 DEBUG [Recvd-ap] immediate_ack at Instant { tv_sec: 732, tv_nsec: 543249520 } client | 0.078 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 732, tv_nsec: 543249520 } client | 0.078 DEBUG [Client ef491e0089af75a0] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } client | 0.078 DEBUG Building Handshake dcid Some(CID [16]: 39f726792670847def54700a8a89049c) scid Some(CID [0]: ) client | 0.078 DEBUG Building Short dcid Some(CID [16]: 39f726792670847def54700a8a89049c) client | 0.079 DEBUG [Client ef491e0089af75a0] pn=1 type=Short pri-path:39f726792670847def54700a8a89049c [::]:34623->[fd00:cafe:cafe:100::100]:443 IpTos(Cs0, Ect0) len 42 client | TX -> Ack { largest_acknowledged: 0, ack_delay: 4, first_ack_range: 0, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 1, Ce: 0})) } client | 0.079 DEBUG ECN probing: sent 5 probes client | 0.079 DEBUG [Client ef491e0089af75a0] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } client | 0.079 DEBUG Building Handshake dcid Some(CID [16]: 39f726792670847def54700a8a89049c) scid Some(CID [0]: ) client | 0.079 DEBUG Building Short dcid Some(CID [16]: 39f726792670847def54700a8a89049c) client | 0.079 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } client | 0.079 DEBUG [Client ef491e0089af75a0] delay duration 92.537152ms client | 0.079 DEBUG Setting timeout of 92.537152ms client | 0.079 DEBUG [Client ef491e0089af75a0] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } client | 0.079 DEBUG Building Handshake dcid Some(CID [16]: 39f726792670847def54700a8a89049c) scid Some(CID [0]: ) client | 0.079 DEBUG Building Short dcid Some(CID [16]: 39f726792670847def54700a8a89049c) client | 0.079 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } client | 0.079 DEBUG [Client ef491e0089af75a0] delay duration 92.503298ms client | 0.079 DEBUG Setting timeout of 92.503298ms client | 0.079 DEBUG [Client ef491e0089af75a0] pn=1 type=Short pri-path:39f726792670847def54700a8a89049c [::]:34623->[fd00:cafe:cafe:100::100]:443 IpTos(Cs0, Ect0) len 136 client | -> RX Ack { largest_acknowledged: 0, ack_delay: 75, first_ack_range: 0, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 1, Ce: 0})) } client | -> RX HandshakeDone client | -> RX NewConnectionId { sequence_number: 1, retire_prior: 1, connection_id: [104, 195, 243, 99, 44, 210, 191, 249, 88, 121, 100, 52, 50, 125, 231, 140], stateless_reset_token: [15, 62, 224, 191, 86, 45, 205, 177, 52, 93, 151, 151, 82, 97, 17, 230] } client | -> RX NewConnectionId { sequence_number: 2, retire_prior: 1, connection_id: [248, 7, 118, 169, 102, 123, 101, 109, 142, 224, 114, 189, 191, 97, 117, 37], stateless_reset_token: [225, 164, 255, 239, 17, 20, 234, 118, 74, 72, 103, 162, 219, 71, 234, 201] } client | -> RX NewConnectionId { sequence_number: 3, retire_prior: 1, connection_id: [38, 83, 92, 132, 73, 105, 19, 171, 164, 104, 167, 218, 171, 212, 149, 42], stateless_reset_token: [42, 60, 223, 103, 198, 134, 212, 102, 163, 211, 121, 195, 24, 162, 89, 202] } client | 0.079 DEBUG [Client ef491e0089af75a0] Rx ACK space=ap, ranges=[0..=0] client | 0.079 DEBUG [LossRecovery] ACK for ApplicationData - largest_acked=0 client | 0.079 DEBUG on_packets_acked this=0x560fc13276d0, limited=1, bytes_in_flight=81, cwnd=12320, state=SlowStart, new_acked=74 client | 0.079 DEBUG [Client ef491e0089af75a0] State change from Connected -> Confirmed client | 0.079 DEBUG PMTUD started with probe size 1380 client | 0.079 DEBUG [Client ef491e0089af75a0] Drop packet number space hs client | 0.079 DEBUG [LossRecovery] Reset loss recovery state for Handshake client | 0.079 DEBUG [Client ef491e0089af75a0] No preferred address to migrate to client | 0.079 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 732, tv_nsec: 563529096 } client | 0.079 DEBUG [Client ef491e0089af75a0] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } client | 0.079 DEBUG Building Short dcid Some(CID [16]: 68c3f3632cd2bff958796434327de78c) client | 0.079 DEBUG Sending PMTUD probe of size 1380, count 1 client | 0.079 DEBUG [Client ef491e0089af75a0] pn=2 type=Short pri-path:68c3f3632cd2bff958796434327de78c [::]:34623->[fd00:cafe:cafe:100::100]:443 IpTos(Cs0, Ect0) len 1332 client | TX -> Ping client | TX -> RetireConnectionId { sequence_number: 0 } client | TX -> Padding { len: 1295 } client | 0.079 DEBUG packet_sent this=0x560fc13276d0, pn=2, ps=1332 client | 0.079 DEBUG ECN probing: sent 6 probes client | 0.079 DEBUG [Client ef491e0089af75a0] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } client | 0.079 DEBUG Building Short dcid Some(CID [16]: 68c3f3632cd2bff958796434327de78c) client | 0.079 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } client | 0.079 DEBUG [Client ef491e0089af75a0] delay duration 19.648422ms client | 0.079 DEBUG Setting timeout of 19.648422ms client | 0.079 DEBUG stream 0 complete client | 0.079 DEBUG stream 4 complete client | 0.079 WARN Unhandled event StateChange(Confirmed) client | 0.079 DEBUG [Client ef491e0089af75a0] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } client | 0.079 DEBUG Building Short dcid Some(CID [16]: 68c3f3632cd2bff958796434327de78c) client | 0.079 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } client | 0.079 DEBUG [Client ef491e0089af75a0] delay duration 19.612916ms client | 0.079 DEBUG Setting timeout of 19.612916ms client | 0.080 DEBUG [Client ef491e0089af75a0] pn=2 type=Short pri-path:68c3f3632cd2bff958796434327de78c [::]:34623->[fd00:cafe:cafe:100::100]:443 IpTos(Cs0, Ect0) len 1232 client | -> RX HandshakeDone client | -> RX Stream { stream_id: 4, offset: 0, len: >>1211, fin: false } client | 0.080 DEBUG PMTUD started with probe size 1420 client | 0.080 DEBUG [Client ef491e0089af75a0] No preferred address to migrate to client | 0.080 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 732, tv_nsec: 544614520 } client | 0.080 DEBUG [Client ef491e0089af75a0] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } client | 0.080 DEBUG Building Short dcid Some(CID [16]: 68c3f3632cd2bff958796434327de78c) client | 0.080 DEBUG Sending PMTUD probe of size 1420, count 1 client | 0.080 DEBUG [Client ef491e0089af75a0] pn=3 type=Short pri-path:68c3f3632cd2bff958796434327de78c [::]:34623->[fd00:cafe:cafe:100::100]:443 IpTos(Cs0, Ect0) len 1372 client | TX -> Ack { largest_acknowledged: 2, ack_delay: 3, first_ack_range: 2, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 3, Ce: 0})) } client | TX -> Ping client | TX -> Padding { len: 1329 } client | 0.080 DEBUG packet_sent this=0x560fc13276d0, pn=3, ps=1372 client | 0.080 DEBUG ECN probing: sent 7 probes client | 0.080 DEBUG [Client ef491e0089af75a0] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } client | 0.080 DEBUG Building Short dcid Some(CID [16]: 68c3f3632cd2bff958796434327de78c) client | 0.080 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } client | 0.080 DEBUG [Client ef491e0089af75a0] delay duration 997.488µs client | 0.080 DEBUG Setting timeout of 997.488µs client | 0.080 DEBUG [Client ef491e0089af75a0] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } client | 0.080 DEBUG Building Short dcid Some(CID [16]: 68c3f3632cd2bff958796434327de78c) client | 0.080 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } client | 0.080 DEBUG [Client ef491e0089af75a0] delay duration 971.89µs client | 0.080 DEBUG Setting timeout of 971.89µs client | 0.081 DEBUG [Client ef491e0089af75a0] pn=3 type=Short pri-path:68c3f3632cd2bff958796434327de78c [::]:34623->[fd00:cafe:cafe:100::100]:443 IpTos(Cs0, Ect0) len 1232 client | -> RX HandshakeDone client | -> RX Stream { stream_id: 4, offset: 1211, len: >>1209, fin: false } client | 0.081 DEBUG PMTUD started with probe size 1470 client | 0.081 DEBUG [Client ef491e0089af75a0] No preferred address to migrate to client | 0.081 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 732, tv_nsec: 565599930 } client | 0.081 DEBUG [Client ef491e0089af75a0] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } client | 0.081 DEBUG Building Short dcid Some(CID [16]: 68c3f3632cd2bff958796434327de78c) client | 0.081 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } client | 0.081 DEBUG [Client ef491e0089af75a0] delay duration 105.345µs client | 0.081 DEBUG Setting timeout of 105.345µs client | 0.081 DEBUG [Client ef491e0089af75a0] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } client | 0.081 DEBUG Building Short dcid Some(CID [16]: 68c3f3632cd2bff958796434327de78c) client | 0.081 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } client | 0.081 DEBUG [Client ef491e0089af75a0] delay duration 91.99µs client | 0.081 DEBUG Setting timeout of 91.99µs client | 0.082 DEBUG [Client ef491e0089af75a0] pn=4 type=Short pri-path:68c3f3632cd2bff958796434327de78c [::]:34623->[fd00:cafe:cafe:100::100]:443 IpTos(Cs0, Ect0) len 1232 client | -> RX HandshakeDone client | -> RX Stream { stream_id: 4, offset: 2420, len: >>1209, fin: false } client | 0.082 DEBUG PMTUD started with probe size 1500 client | 0.082 DEBUG [Client ef491e0089af75a0] No preferred address to migrate to client | 0.082 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 732, tv_nsec: 546657875 } client | 0.082 DEBUG [Client ef491e0089af75a0] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } client | 0.082 DEBUG Building Short dcid Some(CID [16]: 68c3f3632cd2bff958796434327de78c) client | 0.082 DEBUG Sending PMTUD probe of size 1500, count 1 client | 0.082 DEBUG [Client ef491e0089af75a0] pn=4 type=Short pri-path:68c3f3632cd2bff958796434327de78c [::]:34623->[fd00:cafe:cafe:100::100]:443 IpTos(Cs0, Ect0) len 1452 client | TX -> Ack { largest_acknowledged: 4, ack_delay: 4, first_ack_range: 4, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 5, Ce: 0})) } client | TX -> Ping client | TX -> Padding { len: 1409 } client | 0.082 DEBUG packet_sent this=0x560fc13276d0, pn=4, ps=1452 client | 0.082 DEBUG ECN probing: sent 8 probes client | 0.082 DEBUG [Client ef491e0089af75a0] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } client | 0.082 DEBUG Building Short dcid Some(CID [16]: 68c3f3632cd2bff958796434327de78c) client | 0.082 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } client | 0.082 DEBUG [Client ef491e0089af75a0] delay duration 1.387024ms client | 0.082 DEBUG Setting timeout of 1.387024ms client | 0.082 DEBUG [Client ef491e0089af75a0] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } client | 0.082 DEBUG Building Short dcid Some(CID [16]: 68c3f3632cd2bff958796434327de78c) client | 0.082 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } client | 0.082 DEBUG [Client ef491e0089af75a0] delay duration 1.358561ms client | 0.082 DEBUG Setting timeout of 1.358561ms client | 0.082 DEBUG [Client ef491e0089af75a0] pn=5 type=Short pri-path:68c3f3632cd2bff958796434327de78c [::]:34623->[fd00:cafe:cafe:100::100]:443 IpTos(Cs0, Ect0) len 492 client | -> RX HandshakeDone client | -> RX Stream { stream_id: 4, offset: 3629, len: 467, fin: false } client | 0.082 INFO PMTUD stopped, PLPMTU is now 1500, raise timer Some(Instant { tv_sec: 1332, tv_nsec: 547094654 }) client | 0.082 DEBUG [Client ef491e0089af75a0] No preferred address to migrate to client | 0.082 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 732, tv_nsec: 567094654 } client | 0.082 DEBUG PLPMTU changed from 1232 to 1452, updating pacer client | 0.082 DEBUG [Client ef491e0089af75a0] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } client | 0.082 DEBUG Building Short dcid Some(CID [16]: 68c3f3632cd2bff958796434327de78c) client | 0.082 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } client | 0.082 DEBUG [Client ef491e0089af75a0] delay duration 1.380177ms client | 0.082 DEBUG Setting timeout of 1.380177ms client | 0.082 DEBUG [Client ef491e0089af75a0] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } client | 0.082 DEBUG Building Short dcid Some(CID [16]: 68c3f3632cd2bff958796434327de78c) client | 0.082 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } client | 0.082 DEBUG [Client ef491e0089af75a0] delay duration 1.359899ms client | 0.082 DEBUG Setting timeout of 1.359899ms client | 0.083 DEBUG [Client ef491e0089af75a0] pn=6 type=Short pri-path:68c3f3632cd2bff958796434327de78c [::]:34623->[fd00:cafe:cafe:100::100]:443 IpTos(Cs0, Ect0) len 1232 client | -> RX HandshakeDone client | -> RX Stream { stream_id: 0, offset: 0, len: >>1211, fin: false } client | 0.083 INFO PMTUD stopped, PLPMTU is now 1500, raise timer Some(Instant { tv_sec: 1332, tv_nsec: 548087792 }) client | 0.083 DEBUG [Client ef491e0089af75a0] No preferred address to migrate to client | 0.083 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 732, tv_nsec: 548087792 } client | 0.083 DEBUG [Client ef491e0089af75a0] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } client | 0.083 DEBUG Building Short dcid Some(CID [16]: 68c3f3632cd2bff958796434327de78c) client | 0.083 DEBUG [Client ef491e0089af75a0] pn=5 type=Short pri-path:68c3f3632cd2bff958796434327de78c [::]:34623->[fd00:cafe:cafe:100::100]:443 IpTos(Cs0, Ect0) len 42 client | TX -> Ack { largest_acknowledged: 6, ack_delay: 3, first_ack_range: 6, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 7, Ce: 0})) } client | 0.083 DEBUG ECN probing: sent 9 probes client | 0.083 DEBUG [Client ef491e0089af75a0] output_path send_profile SendProfile { limit: 1452, pto: None, probe: EnumSet(), paced: false } client | 0.083 DEBUG Building Short dcid Some(CID [16]: 68c3f3632cd2bff958796434327de78c) client | 0.083 DEBUG TX blocked, profile=SendProfile { limit: 1452, pto: None, probe: EnumSet(), paced: false } client | 0.083 DEBUG [Client ef491e0089af75a0] delay duration 135.808801ms client | 0.083 DEBUG Setting timeout of 135.808801ms client | 0.083 DEBUG [Client ef491e0089af75a0] output_path send_profile SendProfile { limit: 1452, pto: None, probe: EnumSet(), paced: false } client | 0.083 DEBUG Building Short dcid Some(CID [16]: 68c3f3632cd2bff958796434327de78c) client | 0.083 DEBUG TX blocked, profile=SendProfile { limit: 1452, pto: None, probe: EnumSet(), paced: false } client | 0.083 DEBUG [Client ef491e0089af75a0] delay duration 135.779887ms client | 0.083 DEBUG Setting timeout of 135.779887ms client | 0.084 DEBUG [Client ef491e0089af75a0] pn=7 type=Short pri-path:68c3f3632cd2bff958796434327de78c [::]:34623->[fd00:cafe:cafe:100::100]:443 IpTos(Cs0, Ect0) len 1232 client | -> RX HandshakeDone client | -> RX Stream { stream_id: 0, offset: 1211, len: >>1209, fin: false } client | 0.084 INFO PMTUD stopped, PLPMTU is now 1500, raise timer Some(Instant { tv_sec: 1332, tv_nsec: 549148060 }) client | 0.084 DEBUG [Client ef491e0089af75a0] No preferred address to migrate to client | 0.084 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 732, tv_nsec: 569148060 } client | 0.084 DEBUG [Client ef491e0089af75a0] output_path send_profile SendProfile { limit: 1452, pto: None, probe: EnumSet(), paced: false } client | 0.084 DEBUG Building Short dcid Some(CID [16]: 68c3f3632cd2bff958796434327de78c) client | 0.084 DEBUG TX blocked, profile=SendProfile { limit: 1452, pto: None, probe: EnumSet(), paced: false } client | 0.084 DEBUG [Client ef491e0089af75a0] delay duration 19.942842ms client | 0.084 DEBUG Setting timeout of 19.942842ms client | 0.084 DEBUG [Client ef491e0089af75a0] output_path send_profile SendProfile { limit: 1452, pto: None, probe: EnumSet(), paced: false } client | 0.084 DEBUG Building Short dcid Some(CID [16]: 68c3f3632cd2bff958796434327de78c) client | 0.084 DEBUG TX blocked, profile=SendProfile { limit: 1452, pto: None, probe: EnumSet(), paced: false } client | 0.084 DEBUG [Client ef491e0089af75a0] delay duration 19.92034ms client | 0.084 DEBUG Setting timeout of 19.92034ms client | 0.085 DEBUG [Client ef491e0089af75a0] pn=8 type=Short pri-path:68c3f3632cd2bff958796434327de78c [::]:34623->[fd00:cafe:cafe:100::100]:443 IpTos(Cs0, NotEct) len 1232 client | -> RX HandshakeDone client | -> RX Stream { stream_id: 0, offset: 2420, len: >>1209, fin: false } client | 0.085 INFO PMTUD stopped, PLPMTU is now 1500, raise timer Some(Instant { tv_sec: 1332, tv_nsec: 550183092 }) client | 0.085 DEBUG [Client ef491e0089af75a0] No preferred address to migrate to client | 0.085 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 732, tv_nsec: 550183092 } client | 0.085 DEBUG [Client ef491e0089af75a0] output_path send_profile SendProfile { limit: 1452, pto: None, probe: EnumSet(), paced: false } client | 0.085 DEBUG Building Short dcid Some(CID [16]: 68c3f3632cd2bff958796434327de78c) client | 0.085 DEBUG [Client ef491e0089af75a0] pn=6 type=Short pri-path:68c3f3632cd2bff958796434327de78c [::]:34623->[fd00:cafe:cafe:100::100]:443 IpTos(Cs0, Ect0) len 42 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.085 DEBUG ECN probing: sent 10 probes client | 0.085 DEBUG ECN probing concluded with 10 probes sent client | 0.085 DEBUG [Client ef491e0089af75a0] output_path send_profile SendProfile { limit: 1452, pto: None, probe: EnumSet(), paced: false } client | 0.085 DEBUG Building Short dcid Some(CID [16]: 68c3f3632cd2bff958796434327de78c) client | 0.085 DEBUG TX blocked, profile=SendProfile { limit: 1452, pto: None, probe: EnumSet(), paced: false } client | 0.085 DEBUG [Client ef491e0089af75a0] delay duration 133.712148ms client | 0.085 DEBUG Setting timeout of 133.712148ms client | 0.085 DEBUG [Client ef491e0089af75a0] output_path send_profile SendProfile { limit: 1452, pto: None, probe: EnumSet(), paced: false } client | 0.085 DEBUG Building Short dcid Some(CID [16]: 68c3f3632cd2bff958796434327de78c) client | 0.085 DEBUG TX blocked, profile=SendProfile { limit: 1452, pto: None, probe: EnumSet(), paced: false } client | 0.085 DEBUG [Client ef491e0089af75a0] delay duration 133.682172ms client | 0.086 DEBUG Setting timeout of 133.682172ms client | 0.086 DEBUG [Client ef491e0089af75a0] pn=9 type=Short pri-path:68c3f3632cd2bff958796434327de78c [::]:34623->[fd00:cafe:cafe:100::100]:443 IpTos(Cs0, NotEct) len 492 client | -> RX HandshakeDone client | -> RX Stream { stream_id: 0, offset: 3629, len: 467, fin: false } client | 0.086 INFO PMTUD stopped, PLPMTU is now 1500, raise timer Some(Instant { tv_sec: 1332, tv_nsec: 550615027 }) client | 0.086 DEBUG [Client ef491e0089af75a0] No preferred address to migrate to client | 0.086 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 732, tv_nsec: 570615027 } client | 0.086 DEBUG [Client ef491e0089af75a0] output_path send_profile SendProfile { limit: 1452, pto: None, probe: EnumSet(), paced: false } client | 0.086 DEBUG Building Short dcid Some(CID [16]: 68c3f3632cd2bff958796434327de78c) client | 0.086 DEBUG TX blocked, profile=SendProfile { limit: 1452, pto: None, probe: EnumSet(), paced: false } client | 0.086 DEBUG [Client ef491e0089af75a0] delay duration 19.972669ms client | 0.086 DEBUG Setting timeout of 19.972669ms client | 0.086 DEBUG [Client ef491e0089af75a0] output_path send_profile SendProfile { limit: 1452, pto: None, probe: EnumSet(), paced: false } client | 0.086 DEBUG Building Short dcid Some(CID [16]: 68c3f3632cd2bff958796434327de78c) client | 0.086 DEBUG TX blocked, profile=SendProfile { limit: 1452, pto: None, probe: EnumSet(), paced: false } client | 0.086 DEBUG [Client ef491e0089af75a0] delay duration 19.957551ms client | 0.086 DEBUG Setting timeout of 19.957551ms client | 0.087 DEBUG [Client ef491e0089af75a0] pn=10 type=Short pri-path:68c3f3632cd2bff958796434327de78c [::]:34623->[fd00:cafe:cafe:100::100]:443 IpTos(Cs0, NotEct) len 1232 client | -> RX HandshakeDone client | -> RX Stream { stream_id: 4, offset: 4096, len: >>1209, fin: false } client | 0.087 INFO PMTUD stopped, PLPMTU is now 1500, raise timer Some(Instant { tv_sec: 1332, tv_nsec: 551633978 }) client | 0.087 DEBUG [Client ef491e0089af75a0] No preferred address to migrate to client | 0.087 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 732, tv_nsec: 551633978 } client | 0.087 DEBUG [Client ef491e0089af75a0] output_path send_profile SendProfile { limit: 1452, pto: None, probe: EnumSet(), paced: false } client | 0.087 DEBUG Building Short dcid Some(CID [16]: 68c3f3632cd2bff958796434327de78c) client | 0.087 DEBUG [Client ef491e0089af75a0] pn=7 type=Short pri-path:68c3f3632cd2bff958796434327de78c [::]:34623->[fd00:cafe:cafe:100::100]:443 IpTos(Cs0, NotEct) len 42 client | TX -> Ack { largest_acknowledged: 10, ack_delay: 3, first_ack_range: 10, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 8, Ce: 0})) } client | 0.087 DEBUG [Client ef491e0089af75a0] output_path send_profile SendProfile { limit: 1452, pto: None, probe: EnumSet(), paced: false } client | 0.087 DEBUG Building Short dcid Some(CID [16]: 68c3f3632cd2bff958796434327de78c) client | 0.087 DEBUG TX blocked, profile=SendProfile { limit: 1452, pto: None, probe: EnumSet(), paced: false } client | 0.087 DEBUG [Client ef491e0089af75a0] delay duration 132.267093ms client | 0.087 DEBUG Setting timeout of 132.267093ms client | 0.087 DEBUG [Client ef491e0089af75a0] output_path send_profile SendProfile { limit: 1452, pto: None, probe: EnumSet(), paced: false } client | 0.087 DEBUG Building Short dcid Some(CID [16]: 68c3f3632cd2bff958796434327de78c) client | 0.087 DEBUG TX blocked, profile=SendProfile { limit: 1452, pto: None, probe: EnumSet(), paced: false } client | 0.087 DEBUG [Client ef491e0089af75a0] delay duration 132.240964ms client | 0.087 DEBUG Setting timeout of 132.240964ms client | 0.088 DEBUG [Client ef491e0089af75a0] pn=11 type=Short pri-path:68c3f3632cd2bff958796434327de78c [::]:34623->[fd00:cafe:cafe:100::100]:443 IpTos(Cs0, NotEct) len 1232 client | -> RX HandshakeDone client | -> RX Stream { stream_id: 4, offset: 5305, len: >>1209, fin: false } client | 0.088 INFO PMTUD stopped, PLPMTU is now 1500, raise timer Some(Instant { tv_sec: 1332, tv_nsec: 552658099 }) client | 0.088 DEBUG [Client ef491e0089af75a0] No preferred address to migrate to client | 0.088 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 732, tv_nsec: 572658099 } client | 0.088 DEBUG [Client ef491e0089af75a0] output_path send_profile SendProfile { limit: 1452, pto: None, probe: EnumSet(), paced: false } client | 0.088 DEBUG Building Short dcid Some(CID [16]: 68c3f3632cd2bff958796434327de78c) client | 0.088 DEBUG TX blocked, profile=SendProfile { limit: 1452, pto: None, probe: EnumSet(), paced: false } client | 0.088 DEBUG [Client ef491e0089af75a0] delay duration 19.974412ms client | 0.088 DEBUG Setting timeout of 19.974412ms client | 0.088 DEBUG [Client ef491e0089af75a0] output_path send_profile SendProfile { limit: 1452, pto: None, probe: EnumSet(), paced: false } client | 0.088 DEBUG Building Short dcid Some(CID [16]: 68c3f3632cd2bff958796434327de78c) client | 0.088 DEBUG TX blocked, profile=SendProfile { limit: 1452, pto: None, probe: EnumSet(), paced: false } client | 0.088 DEBUG [Client ef491e0089af75a0] delay duration 19.960295ms client | 0.088 DEBUG Setting timeout of 19.960295ms client | 0.109 DEBUG [Client ef491e0089af75a0] output_path send_profile SendProfile { limit: 1452, pto: None, probe: EnumSet(), paced: false } client | 0.109 DEBUG Building Short dcid Some(CID [16]: 68c3f3632cd2bff958796434327de78c) client | 0.109 DEBUG [Client ef491e0089af75a0] pn=8 type=Short pri-path:68c3f3632cd2bff958796434327de78c [::]:34623->[fd00:cafe:cafe:100::100]:443 IpTos(Cs0, NotEct) len 43 client | TX -> Ack { largest_acknowledged: 11, ack_delay: 2640, first_ack_range: 11, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 8, Ce: 0})) } client | 0.109 DEBUG [Client ef491e0089af75a0] output_path send_profile SendProfile { limit: 1452, pto: None, probe: EnumSet(), paced: false } client | 0.109 DEBUG Building Short dcid Some(CID [16]: 68c3f3632cd2bff958796434327de78c) client | 0.109 DEBUG TX blocked, profile=SendProfile { limit: 1452, pto: None, probe: EnumSet(), paced: false } client | 0.109 DEBUG [Client ef491e0089af75a0] delay duration 110.115764ms client | 0.109 DEBUG Setting timeout of 110.115764ms client | 0.114 DEBUG [Client ef491e0089af75a0] pn=13 type=Short pri-path:68c3f3632cd2bff958796434327de78c [::]:34623->[fd00:cafe:cafe:100::100]:443 IpTos(Cs0, Ect0) len 1452 client | -> RX Ack { largest_acknowledged: 3, ack_delay: 38, first_ack_range: 2, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 4, Ce: 0})) } client | -> RX Stream { stream_id: 0, offset: 4096, len: 1024, fin: true } client | -> RX Stream { stream_id: 4, offset: 6514, len: >>392, fin: false } client | 0.114 DEBUG [Client ef491e0089af75a0] Rx ACK space=ap, ranges=[1..=3] client | 0.114 DEBUG [LossRecovery] ACK for ApplicationData - largest_acked=3 client | 0.114 INFO ECN validation succeeded, path is capable client | 0.114 DEBUG on_packets_acked this=0x560fc13276d0, limited=1, bytes_in_flight=1452, cwnd=12320, state=SlowStart, new_acked=2704 client | 0.114 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 732, tv_nsec: 578369655 } client | 0.114 DEBUG [Client ef491e0089af75a0] output_path send_profile SendProfile { limit: 1452, pto: None, probe: EnumSet(), paced: false } client | 0.114 DEBUG Building Short dcid Some(CID [16]: 68c3f3632cd2bff958796434327de78c) client | 0.114 DEBUG [Client ef491e0089af75a0] pn=9 type=Short pri-path:68c3f3632cd2bff958796434327de78c [::]:34623->[fd00:cafe:cafe:100::100]:443 IpTos(Cs0, Ect0) len 44 client | TX -> Ack { largest_acknowledged: 13, ack_delay: 5, first_ack_range: 0, ack_ranges: [AckRange { gap: 0, range: 11 }], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 9, Ce: 0})) } client | 0.114 DEBUG [Client ef491e0089af75a0] output_path send_profile SendProfile { limit: 1452, pto: None, probe: EnumSet(), paced: false } client | 0.114 DEBUG Building Short dcid Some(CID [16]: 68c3f3632cd2bff958796434327de78c) client | 0.114 DEBUG TX blocked, profile=SendProfile { limit: 1452, pto: None, probe: EnumSet(), paced: false } client | 0.114 DEBUG [Client ef491e0089af75a0] delay duration 93.908234ms client | 0.114 DEBUG Setting timeout of 93.908234ms client | 0.114 DEBUG [Client ef491e0089af75a0] output_path send_profile SendProfile { limit: 1452, pto: None, probe: EnumSet(), paced: false } client | 0.114 DEBUG Building Short dcid Some(CID [16]: 68c3f3632cd2bff958796434327de78c) client | 0.114 DEBUG TX blocked, profile=SendProfile { limit: 1452, pto: None, probe: EnumSet(), paced: false } client | 0.114 DEBUG [Client ef491e0089af75a0] delay duration 93.840978ms client | 0.114 DEBUG Setting timeout of 93.840978ms client | 0.115 DEBUG [Client ef491e0089af75a0] pn=14 type=Short pri-path:68c3f3632cd2bff958796434327de78c [::]:34623->[fd00:cafe:cafe:100::100]:443 IpTos(Cs0, Ect0) len 1452 client | -> RX Stream { stream_id: 4, offset: 6906, len: >>1430, fin: false } client | 0.115 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 732, tv_nsec: 599570939 } client | 0.115 DEBUG [Client ef491e0089af75a0] output_path send_profile SendProfile { limit: 1452, pto: None, probe: EnumSet(), paced: false } client | 0.115 DEBUG Building Short dcid Some(CID [16]: 68c3f3632cd2bff958796434327de78c) client | 0.115 DEBUG TX blocked, profile=SendProfile { limit: 1452, pto: None, probe: EnumSet(), paced: false } client | 0.115 DEBUG [Client ef491e0089af75a0] delay duration 19.97343ms client | 0.115 DEBUG Setting timeout of 19.97343ms client | 0.115 DEBUG [Client ef491e0089af75a0] output_path send_profile SendProfile { limit: 1452, pto: None, probe: EnumSet(), paced: false } client | 0.115 DEBUG Building Short dcid Some(CID [16]: 68c3f3632cd2bff958796434327de78c) client | 0.115 DEBUG TX blocked, profile=SendProfile { limit: 1452, pto: None, probe: EnumSet(), paced: false } client | 0.115 DEBUG [Client ef491e0089af75a0] delay duration 19.95186ms client | 0.115 DEBUG Setting timeout of 19.95186ms client | 0.116 DEBUG [Client ef491e0089af75a0] pn=15 type=Short pri-path:68c3f3632cd2bff958796434327de78c [::]:34623->[fd00:cafe:cafe:100::100]:443 IpTos(Cs0, Ect0) len 1452 client | -> RX Ack { largest_acknowledged: 4, ack_delay: 41, first_ack_range: 3, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 5, Ce: 0})) } client | -> RX Stream { stream_id: 4, offset: 8336, len: >>1422, fin: false } client | 0.116 DEBUG [Client ef491e0089af75a0] Rx ACK space=ap, ranges=[1..=4] client | 0.116 DEBUG [LossRecovery] ACK for ApplicationData - largest_acked=4 client | 0.116 DEBUG on_packets_acked this=0x560fc13276d0, limited=1, bytes_in_flight=0, cwnd=12320, state=SlowStart, new_acked=1452 client | 0.116 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 732, tv_nsec: 580770719 } client | 0.116 DEBUG [Client ef491e0089af75a0] output_path send_profile SendProfile { limit: 1452, pto: None, probe: EnumSet(), paced: false } client | 0.116 DEBUG Building Short dcid Some(CID [16]: 68c3f3632cd2bff958796434327de78c) client | 0.116 DEBUG [Client ef491e0089af75a0] pn=10 type=Short pri-path:68c3f3632cd2bff958796434327de78c [::]:34623->[fd00:cafe:cafe:100::100]:443 IpTos(Cs0, Ect0) len 44 client | TX -> Ack { largest_acknowledged: 15, ack_delay: 5, first_ack_range: 2, ack_ranges: [AckRange { gap: 0, range: 11 }], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 11, Ce: 0})) } client | 0.116 DEBUG [Client ef491e0089af75a0] output_path send_profile SendProfile { limit: 1452, pto: None, probe: EnumSet(), paced: false } client | 0.116 DEBUG Building Short dcid Some(CID [16]: 68c3f3632cd2bff958796434327de78c) client | 0.116 DEBUG TX blocked, profile=SendProfile { limit: 1452, pto: None, probe: EnumSet(), paced: false } client | 0.116 DEBUG [Client ef491e0089af75a0] delay duration 29.99988809s client | 0.116 DEBUG Setting timeout of 29.99988809s client | 0.116 DEBUG [Client ef491e0089af75a0] output_path send_profile SendProfile { limit: 1452, pto: None, probe: EnumSet(), paced: false } client | 0.116 DEBUG Building Short dcid Some(CID [16]: 68c3f3632cd2bff958796434327de78c) client | 0.116 DEBUG TX blocked, profile=SendProfile { limit: 1452, pto: None, probe: EnumSet(), paced: false } client | 0.116 DEBUG [Client ef491e0089af75a0] delay duration 29.999862923s client | 0.116 DEBUG Setting timeout of 29.999862923s client | 0.116 DEBUG [Client ef491e0089af75a0] pn=16 type=Short pri-path:68c3f3632cd2bff958796434327de78c [::]:34623->[fd00:cafe:cafe:100::100]:443 IpTos(Cs0, Ect0) len 506 client | -> RX Stream { stream_id: 4, offset: 9758, len: 482, fin: true } client | 0.116 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 732, tv_nsec: 601220763 } client | 0.116 DEBUG [Client ef491e0089af75a0] output_path send_profile SendProfile { limit: 1452, pto: None, probe: EnumSet(), paced: false } client | 0.116 DEBUG Building Short dcid Some(CID [16]: 68c3f3632cd2bff958796434327de78c) client | 0.116 DEBUG TX blocked, profile=SendProfile { limit: 1452, pto: None, probe: EnumSet(), paced: false } client | 0.116 DEBUG [Client ef491e0089af75a0] delay duration 19.974342ms client | 0.116 DEBUG Setting timeout of 19.974342ms client | 0.117 DEBUG [Client ef491e0089af75a0] output_path send_profile SendProfile { limit: 1452, pto: None, probe: EnumSet(), paced: false } client | 0.117 DEBUG Building Short dcid Some(CID [16]: 68c3f3632cd2bff958796434327de78c) client | 0.117 DEBUG TX blocked, profile=SendProfile { limit: 1452, pto: None, probe: EnumSet(), paced: false } client | 0.117 DEBUG [Client ef491e0089af75a0] delay duration 19.913608ms client | 0.117 DEBUG Setting timeout of 19.913608ms client | 0.117 DEBUG [Client ef491e0089af75a0] State change from Confirmed -> Closing { error: Application(0), timeout: Instant { tv_sec: 732, tv_nsec: 929284920 } } client | 0.117 WARN Unhandled event StateChange(Closing { error: Application(0), timeout: Instant { tv_sec: 732, tv_nsec: 929284920 } }) client | 0.117 DEBUG [Client ef491e0089af75a0] output_path send_profile SendProfile { limit: 1452, pto: None, probe: EnumSet(), paced: false } client | 0.117 DEBUG Building Short dcid Some(CID [16]: 68c3f3632cd2bff958796434327de78c) client | 0.117 DEBUG [Recvd-ap] immediate_ack at Instant { tv_sec: 732, tv_nsec: 581337793 } client | 0.117 DEBUG [Client ef491e0089af75a0] pn=11 type=Short pri-path:68c3f3632cd2bff958796434327de78c [::]:34623->[fd00:cafe:cafe:100::100]:443 IpTos(Cs0, Ect0) len 55 client | TX -> Ack { largest_acknowledged: 16, ack_delay: 14, first_ack_range: 3, ack_ranges: [AckRange { gap: 0, range: 11 }], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 12, Ce: 0})) } client | TX -> ConnectionClose { error_code: Application(0), frame_type: 0, reason_phrase: "kthxbye!" } client | 0.117 DEBUG Setting timeout of 347.866556ms server | error while accepting stream: The connection was closed on the application level with error application::Error(0) by the remote endpoint client | 0.466 DEBUG [Client ef491e0089af75a0] State change from Closing { error: Application(0), timeout: Instant { tv_sec: 732, tv_nsec: 929284920 } } -> Closed(Application(0)) client | 0.466 INFO Closing timer expired client | 0.466 DEBUG Output::None client | 0.466 WARN Unhandled event StateChange(Closed(Application(0))) client | 0.466 DEBUG Timer fired while closed client | 0.466 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 13:43:01,041 Using the client's key log file. 2025-04-30 13:43:01,052 2025-04-30 13:43:01,053 Using the client's key log file. 2025-04-30 13:43:01,053 Using the client's key log file. 2025-04-30 13:43:01,063 2025-04-30 13:43:01,063 Using the client's key log file. 2025-04-30 13:43:01,624 Check of downloaded files succeeded. 2025-04-30 13:43:02,196 Check of downloaded files succeeded.