2025-04-30 11:41:53,516 Generated random file: zxldalzuhy of size: 5120 2025-04-30 11:41:53,516 Generated random file: boytjvewgy of size: 10240 2025-04-30 11:41:53,516 Requests: https://server6:443/zxldalzuhy https://server6:443/boytjvewgy 2025-04-30 11:41:53,577 2025-04-30 11:41:53,577 Command: WAITFORSERVER=server:443 CERTS=/tmp/certs_pw6fno2y/ TESTCASE_SERVER=transfer TESTCASE_CLIENT=transfer WWW=/tmp/www_7ogu4y05/ DOWNLOADS=/tmp/download_42_0j0zs/ SERVER_LOGS=/tmp/logs_server_iw8vst5a CLIENT_LOGS=/tmp/logs_client_5klr88nq SCENARIO="simple-p2p --delay=15ms --bandwidth=10Mbps --queue=25" CLIENT=ghcr.io/mozilla/neqo-qns:latest SERVER=privateoctopus/picoquic:latest REQUESTS="https://server6:443/zxldalzuhy https://server6:443/boytjvewgy" docker compose --env-file empty.env up --abort-on-container-exit --timeout 1 sim client server 2025-04-30 11:42:05,917 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 the simulation with setup.sh server | Setting up routes... server | Actual changes: server | tx-checksum-ip-generic: off server | tx-tcp-segmentation: off [not requested] server | tx-tcp-ecn-segmentation: off [not requested] server | tx-tcp-mangleid-segmentation: off [not requested] server | tx-tcp6-segmentation: off [not requested] server | tx-udp-segmentation: off [not requested] server | tx-checksum-sctp: off server | Endpoint's IPv4 address is 193.167.100.100 server | Endpoint's IPv6 address is fd00:cafe:cafe:100::100 server | Setup.sh completed server | Starting picoquic server for test: transfer server | boytjvewgy zxldalzuhy server | Starting picoquic server ... server | TEST_PARAMS: -8 -w ./www -L -l /logs/server_log.txt -q /logs/qlog -k /certs/priv.key -c /certs/cert.pem -p 443 -V -0 -d 180000 server | Starting Picoquic server (v1.1.26.1) on port 443, server name = ::, just_once = 0, do_retry = 0 server | No token file present. Will create one as . server | Accept enable multipath: 0. server | Waiting for packets. client | Setting up routes... client | Actual changes: client | tx-checksum-ip-generic: off client | tx-tcp-segmentation: off [not requested] client | tx-tcp-ecn-segmentation: off [not requested] client | tx-tcp-mangleid-segmentation: off [not requested] client | tx-tcp6-segmentation: off [not requested] client | tx-udp-segmentation: off [not requested] client | tx-checksum-sctp: off client | Endpoint's IPv4 address is 193.167.0.100 client | Endpoint's IPv6 address is fd00:cafe:cafe::100 client | + export PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/neqo/bin client | + PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/neqo/bin client | + '[' -n transfer ']' client | + '[' -n /logs/qlog/ ']' client | + case "$ROLE" in client | + /wait-for-it.sh sim:57832 -s -t 30 client | wait-for-it.sh: waiting 30 seconds for sim:57832 sim | server:443 is available after 1.056623208s sim | Using scenario: simple-p2p --delay=15ms --bandwidth=10Mbps --queue=25 sim | tcpdump: listening on eth0, link-type EN10MB (Ethernet)tcpdump: , snapshot length 262144 bytes sim | 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://server6:443/zxldalzuhy https://server6:443/boytjvewgy' ']' 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/zxldalzuhy 'https://server6:443/boytjvewgy 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: [::]:33310 -> [fd00:cafe:cafe:100::100]:443 client | 0.001 DEBUG [CryptoStates] Creating initial cipher state v=Version1, role=Client dcid=000c4e1729b170d7 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 [::]:33310->[fd00:cafe:cafe:100::100]:443] Make permanent client | 0.001 DEBUG [unv-path:000c4e1729b170d7 [::]:33310->[fd00:cafe:cafe:100::100]:443] set as primary path client | 0.001 DEBUG [pri-unv-path:000c4e1729b170d7 [::]:33310->[fd00:cafe:cafe:100::100]:443] Path validated Instant { tv_sec: 899, tv_nsec: 511496933 } client | 0.001 DEBUG [Client 000c4e1729b170d7] client_start client | 0.001 DEBUG Writing transport parameters, msg=1 client | 0.001 DEBUG [Agent 0x557171c18ed0] state -> InProgress client | 0.001 DEBUG [Client 000c4e1729b170d7] State change from Init -> WaitInitial client | 0.001 DEBUG [Client 000c4e1729b170d7] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } client | 0.001 DEBUG Building Initial dcid Some(CID [8]: 000c4e1729b170d7) scid Some(CID [0]: ) client | 0.001 DEBUG CRYPTO for in offset=0, len=1193 client | 0.002 DEBUG [Client 000c4e1729b170d7] pn=0 type=Initial pri-path:000c4e1729b170d7 [::]:33310->[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=0x557171c2c6d0, pn=0, ps=1232 client | 0.002 DEBUG ECN probing: sent 1 probes client | 0.002 DEBUG [Client 000c4e1729b170d7] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } client | 0.002 DEBUG Building Initial dcid Some(CID [8]: 000c4e1729b170d7) scid Some(CID [0]: ) client | 0.002 DEBUG CRYPTO for in offset=1193, len=346 client | 0.002 DEBUG [Client 000c4e1729b170d7] pn=1 type=Initial pri-path:000c4e1729b170d7 [::]:33310->[fd00:cafe:cafe:100::100]:443 IpTos(Cs0, Ect0) len 386 client | TX -> Crypto { offset: 1193, len: 346 } client | 0.002 DEBUG [Client 000c4e1729b170d7] pad Initial from 386 to PLPMTU 1232 client | 0.002 DEBUG packet_sent this=0x557171c2c6d0, pn=1, ps=1232 client | 0.002 DEBUG ECN probing: sent 2 probes client | 0.002 DEBUG [Client 000c4e1729b170d7] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } client | 0.002 DEBUG Building Initial dcid Some(CID [8]: 000c4e1729b170d7) 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 000c4e1729b170d7] delay duration 3.873911ms client | 0.002 DEBUG Setting timeout of 3.873911ms client | 0.002 DEBUG StateChange(WaitInitial) client | 0.002 WARN Cannot create stream ConnectionState client | 0.002 DEBUG [Client 000c4e1729b170d7] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } client | 0.002 DEBUG Building Initial dcid Some(CID [8]: 000c4e1729b170d7) 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 000c4e1729b170d7] delay duration 3.823917ms client | 0.002 DEBUG Setting timeout of 3.823917ms client | 0.007 DEBUG [Client 000c4e1729b170d7] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } client | 0.007 DEBUG Building Initial dcid Some(CID [8]: 000c4e1729b170d7) 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 000c4e1729b170d7] delay duration 294.759511ms client | 0.007 DEBUG Setting timeout of 294.759511ms client | 0.042 DEBUG [Client 000c4e1729b170d7] pn=113466 type=Initial pri-path:000c4e1729b170d7 [::]:33310->[fd00:cafe:cafe:100::100]:443 IpTos(Cs0, Ect1) len 141 client | -> RX Ack { largest_acknowledged: 1, ack_delay: 66, 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.042 DEBUG [Client 000c4e1729b170d7] Rx ACK space=in, ranges=[0..=1] client | 0.042 DEBUG [LossRecovery] ACK for Initial - largest_acked=1 client | 0.042 DEBUG on_packets_acked this=0x557171c2c6d0, limited=1, bytes_in_flight=0, cwnd=12320, state=SlowStart, new_acked=2464 client | 0.042 DEBUG Acked crypto frame space=in offset=1193 length=346 client | 0.042 DEBUG Acked crypto frame space=in offset=0 length=1193 client | 0.042 DEBUG Read Ok(90) bytes client | 0.042 DEBUG Write secret available for Handshake: SymKey [32]: 40f513288152d190624b581f26a6d1b43494c8897159455790b3ebc4ce59c9a3 client | 0.042 DEBUG Read secret available for Handshake: SymKey [32]: 27bfda89d31ef24d56eef9bf3ed859a968a3617e6c2659038d6f91a85f861053 client | 0.042 DEBUG [Agent 0x557171c18ed0] state -> InProgress client | 0.042 DEBUG Making Write Handshake CryptoDxState, v=Version1 cipher=4865 client | 0.042 DEBUG Making Read Handshake CryptoDxState, v=Version1 cipher=4865 client | 0.042 DEBUG [Crypto] Handshake keys installed client | 0.042 DEBUG [Recvd-in] Set ACK timer to Instant { tv_sec: 899, tv_nsec: 552745361 } client | 0.042 DEBUG [Client 000c4e1729b170d7] Changing to use Server CID=3faf070c4a001bae client | 0.042 DEBUG [Client 000c4e1729b170d7] State change from WaitInitial -> Handshaking client | 0.042 DEBUG [Client 000c4e1729b170d7] pn=0 type=Handshake pri-path:3faf070c4a001bae [::]:33310->[fd00:cafe:cafe:100::100]:443 IpTos(Cs0, Ect1) len 806 client | -> RX Crypto { offset: 0, len: 765 } client | 0.042 DEBUG Read Ok(765) bytes client | 0.043 DEBUG [Agent 0x557171c18ed0] state -> AuthenticationPending client | 0.043 DEBUG [Recvd-hs] Set ACK timer to Instant { tv_sec: 899, tv_nsec: 552745361 } client | 0.043 DEBUG [Client 000c4e1729b170d7] pn=1 type=Handshake pri-path:3faf070c4a001bae [::]:33310->[fd00:cafe:cafe:100::100]:443 IpTos(Cs0, Ect1) len 285 client | -> RX Ping client | -> RX Padding { len: 247 } client | 0.043 DEBUG unmark 0-length range at 0 client | 0.043 DEBUG [Recvd-hs] immediate_ack at Instant { tv_sec: 899, tv_nsec: 552745361 } client | 0.043 DEBUG [Recvd-hs] Set ACK timer to Instant { tv_sec: 899, tv_nsec: 552745361 } client | 0.043 DEBUG [Client 000c4e1729b170d7] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } client | 0.043 DEBUG Building Initial dcid Some(CID [8]: 3faf070c4a001bae) scid Some(CID [0]: ) client | 0.043 DEBUG [Client 000c4e1729b170d7] pn=2 type=Initial pri-path:3faf070c4a001bae [::]:33310->[fd00:cafe:cafe:100::100]:443 IpTos(Cs0, Ect0) len 47 client | TX -> Ack { largest_acknowledged: 113466, ack_delay: 159, first_ack_range: 0, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 1, Ect0: 0, Ce: 0})) } client | 0.043 DEBUG Building Handshake dcid Some(CID [8]: 3faf070c4a001bae) scid Some(CID [0]: ) client | 0.043 DEBUG [Client 000c4e1729b170d7] pn=0 type=Handshake pri-path:3faf070c4a001bae [::]:33310->[fd00:cafe:cafe:100::100]:443 IpTos(Cs0, Ect0) len 90 client | TX -> Ack { largest_acknowledged: 1, ack_delay: 159, first_ack_range: 1, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 2, Ect0: 0, Ce: 0})) } client | 0.043 DEBUG [Client 000c4e1729b170d7] Drop packet number space in client | 0.043 DEBUG [LossRecovery] Reset loss recovery state for Initial client | 0.043 WARN [LossRecovery] ignoring in-2 from dropped space client | 0.043 DEBUG ECN probing: sent 3 probes client | 0.043 DEBUG [Client 000c4e1729b170d7] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } client | 0.043 DEBUG Building Handshake dcid Some(CID [8]: 3faf070c4a001bae) scid Some(CID [0]: ) client | 0.043 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } client | 0.043 DEBUG [Client 000c4e1729b170d7] delay duration 120.594065ms client | 0.043 DEBUG Setting timeout of 120.594065ms client | 0.043 DEBUG saving datagram of 439 bytes client | 0.043 DEBUG [Client 000c4e1729b170d7] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } client | 0.043 DEBUG Building Handshake dcid Some(CID [8]: 3faf070c4a001bae) scid Some(CID [0]: ) client | 0.043 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } client | 0.043 DEBUG [Client 000c4e1729b170d7] delay duration 120.563038ms client | 0.043 DEBUG Setting timeout of 120.563038ms client | 0.043 DEBUG StateChange(Handshaking) client | 0.043 WARN Cannot create stream ConnectionState client | 0.043 DEBUG [Client 000c4e1729b170d7] Authenticated Ok client | 0.043 DEBUG Write secret available for ApplicationData: SymKey [32]: d300889e5ba502158a95d3d7da28d43439bb428fcba57916a1154a3bf9b630fb client | 0.043 DEBUG Read secret available for ApplicationData: SymKey [32]: 58dd77f3e7e9476506fe7e12f2e27726177877a6da59a6efed97ae56a88e80a7 client | 0.043 DEBUG [Agent 0x557171c18ed0] SSL_AuthCertificateComplete: Ok(()) client | 0.043 DEBUG [Agent 0x557171c18ed0] state -> Complete(SecretAgentInfo { version: 772, cipher: 4865, group: 29, resumed: false, early_data: false, ech_accepted: false, alpn: Some("hq-interop"), signature_scheme: 1027 }) client | 0.043 DEBUG [Client 000c4e1729b170d7] TLS connection complete client | 0.043 DEBUG Making Write ApplicationData CryptoDxState, v=Version1 cipher=4865 client | 0.043 DEBUG [Crypto] Application write key installed client | 0.043 DEBUG Making Read ApplicationData CryptoDxState, v=Version1 cipher=4865 client | 0.043 DEBUG [Crypto] application read keys installed client | 0.044 DEBUG [Client 000c4e1729b170d7] State change from Handshaking -> Connected client | 0.044 INFO [Client 000c4e1729b170d7] Connection established client | 0.044 DEBUG [Client 000c4e1729b170d7] process saved for epoch ApplicationData client | 0.044 DEBUG [Client 000c4e1729b170d7] pn=0 type=Short pri-path:3faf070c4a001bae [::]:33310->[fd00:cafe:cafe:100::100]:443 IpTos(Cs0, Ect1) len 439 client | -> RX Crypto { offset: 0, len: 133 } client | -> RX NewToken { token: [196, 82, 6, 239, 174, 19, 125, 25, 215, 227, 133, 243, 217, 103, 109, 181, 106, 34, 184, 207, 116, 114, 199, 136, 61, 29, 105, 87, 143, 149, 33, 92, 119, 236, 203, 159, 222, 173, 109, 195, 248, 142, 158, 200, 144, 167, 64, 139, 173, 217] } client | -> RX NewConnectionId { sequence_number: 1, retire_prior: 0, connection_id: [94, 124, 9, 235, 78, 19, 4, 139], stateless_reset_token: [23, 241, 99, 216, 252, 174, 71, 1, 137, 95, 132, 213, 210, 196, 92, 55] } client | -> RX NewConnectionId { sequence_number: 2, retire_prior: 0, connection_id: [215, 179, 47, 89, 238, 102, 202, 165], stateless_reset_token: [210, 110, 232, 175, 249, 59, 248, 45, 23, 184, 191, 153, 23, 242, 181, 40] } client | -> RX NewConnectionId { sequence_number: 3, retire_prior: 0, connection_id: [105, 45, 78, 212, 219, 62, 170, 214], stateless_reset_token: [199, 245, 155, 141, 241, 132, 158, 55, 108, 24, 182, 189, 145, 103, 41, 218] } client | -> RX NewConnectionId { sequence_number: 4, retire_prior: 0, connection_id: [215, 188, 84, 71, 174, 94, 192, 163], stateless_reset_token: [228, 87, 205, 229, 236, 70, 78, 98, 34, 17, 57, 102, 205, 253, 79, 222] } client | -> RX NewConnectionId { sequence_number: 5, retire_prior: 0, connection_id: [184, 95, 50, 22, 68, 45, 54, 125], stateless_reset_token: [210, 158, 227, 253, 58, 102, 38, 119, 209, 14, 172, 177, 127, 99, 84, 41] } client | -> RX NewConnectionId { sequence_number: 6, retire_prior: 0, connection_id: [14, 170, 223, 193, 118, 117, 172, 178], stateless_reset_token: [72, 103, 235, 144, 173, 254, 16, 141, 154, 255, 186, 64, 203, 208, 15, 80] } client | -> RX NewConnectionId { sequence_number: 7, retire_prior: 0, connection_id: [28, 230, 68, 65, 32, 129, 97, 95], stateless_reset_token: [88, 149, 102, 159, 227, 99, 113, 134, 32, 125, 78, 89, 174, 18, 243, 152] } client | -> RX Padding { len: 36 } client | 0.044 DEBUG Read Ok(133) bytes client | 0.044 DEBUG [0x557171c18ed0] Got resumption token [804]: 02000633fd676cf0..68ab95cbc7008b81 client | 0.044 DEBUG [Agent 0x557171c18ed0] 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.044 DEBUG resumption token [1009]: 0000000128409300..68ab95cbc7008b81 client | 0.044 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 899, tv_nsec: 574137721 } client | 0.044 DEBUG stream BiDi creatable client | 0.044 INFO Created stream 0 for https://server6/zxldalzuhy client | 0.044 INFO Saving https://server6/zxldalzuhy to "/downloads/zxldalzuhy" client | 0.044 INFO Created stream 4 for https://server6/boytjvewgy client | 0.044 INFO Saving https://server6/boytjvewgy to "/downloads/boytjvewgy" client | 0.044 DEBUG stream UniDi creatable client | 0.044 DEBUG StateChange(Connected) client | 0.044 DEBUG stream 0 writable client | 0.044 DEBUG stream 4 writable client | 0.044 DEBUG [Client 000c4e1729b170d7] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } client | 0.044 DEBUG Building Handshake dcid Some(CID [8]: 3faf070c4a001bae) scid Some(CID [0]: ) client | 0.044 DEBUG CRYPTO for hs offset=0, len=36 client | 0.044 DEBUG [Client 000c4e1729b170d7] pn=1 type=Handshake pri-path:3faf070c4a001bae [::]:33310->[fd00:cafe:cafe:100::100]:443 IpTos(Cs0, Ect0) len 73 client | TX -> Crypto { offset: 0, len: 36 } client | 0.044 DEBUG packet_sent this=0x557171c2c6d0, pn=1, ps=73 client | 0.044 DEBUG Building Short dcid Some(CID [8]: 3faf070c4a001bae) client | 0.044 DEBUG [Client 000c4e1729b170d7] pn=0 type=Short pri-path:3faf070c4a001bae [::]:33310->[fd00:cafe:cafe:100::100]:443 IpTos(Cs0, Ect0) len 139 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.044 DEBUG packet_sent this=0x557171c2c6d0, pn=0, ps=66 client | 0.044 DEBUG ECN probing: sent 4 probes client | 0.044 DEBUG [Client 000c4e1729b170d7] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } client | 0.044 DEBUG Building Handshake dcid Some(CID [8]: 3faf070c4a001bae) scid Some(CID [0]: ) client | 0.044 DEBUG Building Short dcid Some(CID [8]: 3faf070c4a001bae) client | 0.044 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } client | 0.044 DEBUG [Client 000c4e1729b170d7] delay duration 19.313929ms client | 0.044 DEBUG Setting timeout of 19.313929ms client | 0.044 DEBUG [Client 000c4e1729b170d7] pn=1 type=Short pri-path:3faf070c4a001bae [::]:33310->[fd00:cafe:cafe:100::100]:443 IpTos(Cs0, Ect1) len 1440 client | -> RX Ping client | -> RX Padding { len: 1421 } client | 0.044 DEBUG [Recvd-ap] immediate_ack at Instant { tv_sec: 899, tv_nsec: 554862685 } client | 0.044 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 899, tv_nsec: 554862685 } client | 0.044 DEBUG [Client 000c4e1729b170d7] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } client | 0.044 DEBUG Building Handshake dcid Some(CID [8]: 3faf070c4a001bae) scid Some(CID [0]: ) client | 0.044 DEBUG Building Short dcid Some(CID [8]: 3faf070c4a001bae) client | 0.044 DEBUG [Client 000c4e1729b170d7] pn=1 type=Short pri-path:3faf070c4a001bae [::]:33310->[fd00:cafe:cafe:100::100]:443 IpTos(Cs0, Ect0) len 34 client | TX -> Ack { largest_acknowledged: 1, ack_delay: 3, first_ack_range: 1, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 2, Ect0: 0, Ce: 0})) } client | 0.044 DEBUG ECN probing: sent 5 probes client | 0.044 DEBUG [Client 000c4e1729b170d7] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } client | 0.044 DEBUG Building Handshake dcid Some(CID [8]: 3faf070c4a001bae) scid Some(CID [0]: ) client | 0.044 DEBUG Building Short dcid Some(CID [8]: 3faf070c4a001bae) client | 0.044 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } client | 0.044 DEBUG [Client 000c4e1729b170d7] delay duration 120.46785ms client | 0.044 DEBUG Setting timeout of 120.46785ms client | 0.044 DEBUG [Client 000c4e1729b170d7] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } client | 0.044 DEBUG Building Handshake dcid Some(CID [8]: 3faf070c4a001bae) scid Some(CID [0]: ) client | 0.044 DEBUG Building Short dcid Some(CID [8]: 3faf070c4a001bae) client | 0.044 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } client | 0.044 DEBUG [Client 000c4e1729b170d7] delay duration 120.446981ms client | 0.044 DEBUG Setting timeout of 120.446981ms client | 0.081 DEBUG [Client 000c4e1729b170d7] pn=2 type=Short pri-path:3faf070c4a001bae [::]:33310->[fd00:cafe:cafe:100::100]:443 IpTos(Cs0, Ect1) len 1440 client | -> RX Ack { largest_acknowledged: 1, ack_delay: 631, first_ack_range: 1, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 2, Ce: 0})) } client | -> RX HandshakeDone client | -> RX Stream { stream_id: 0, offset: 0, len: >>1410, fin: false } client | 0.081 DEBUG [Client 000c4e1729b170d7] Rx ACK space=ap, ranges=[0..=1] client | 0.081 DEBUG [LossRecovery] ACK for ApplicationData - largest_acked=1 client | 0.081 DEBUG on_packets_acked this=0x557171c2c6d0, limited=1, bytes_in_flight=73, cwnd=12320, state=SlowStart, new_acked=66 client | 0.081 DEBUG [Client 000c4e1729b170d7] State change from Connected -> Confirmed client | 0.081 DEBUG PMTUD started with probe size 1380 client | 0.081 DEBUG [Client 000c4e1729b170d7] Drop packet number space hs client | 0.081 DEBUG [LossRecovery] Reset loss recovery state for Handshake client | 0.081 DEBUG [Client 000c4e1729b170d7] No preferred address to migrate to client | 0.081 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 899, tv_nsec: 611735860 } client | 0.081 DEBUG [Client 000c4e1729b170d7] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } client | 0.081 DEBUG Building Short dcid Some(CID [8]: 3faf070c4a001bae) client | 0.081 DEBUG Sending PMTUD probe of size 1380, count 1 client | 0.081 DEBUG [Client 000c4e1729b170d7] pn=2 type=Short pri-path:3faf070c4a001bae [::]:33310->[fd00:cafe:cafe:100::100]:443 IpTos(Cs0, Ect0) len 1332 client | TX -> Ping client | TX -> Padding { len: 1305 } client | 0.081 DEBUG packet_sent this=0x557171c2c6d0, pn=2, ps=1332 client | 0.081 DEBUG ECN probing: sent 6 probes client | 0.081 DEBUG [Client 000c4e1729b170d7] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } client | 0.081 DEBUG Building Short dcid Some(CID [8]: 3faf070c4a001bae) client | 0.081 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } client | 0.081 DEBUG [Client 000c4e1729b170d7] delay duration 19.78576ms client | 0.081 DEBUG Setting timeout of 19.78576ms client | 0.081 DEBUG stream 0 complete client | 0.081 DEBUG stream 4 complete client | 0.081 WARN Unhandled event StateChange(Confirmed) client | 0.081 DEBUG [Client 000c4e1729b170d7] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } client | 0.081 DEBUG Building Short dcid Some(CID [8]: 3faf070c4a001bae) client | 0.081 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } client | 0.081 DEBUG [Client 000c4e1729b170d7] delay duration 19.706211ms client | 0.081 DEBUG Setting timeout of 19.706211ms client | 0.087 DEBUG [Client 000c4e1729b170d7] pn=3 type=Short pri-path:3faf070c4a001bae [::]:33310->[fd00:cafe:cafe:100::100]:443 IpTos(Cs0, Ect1) len 1440 client | -> RX Stream { stream_id: 0, offset: 1410, len: >>1418, fin: false } client | 0.087 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 899, tv_nsec: 597527476 } client | 0.087 DEBUG [Client 000c4e1729b170d7] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } client | 0.087 DEBUG Building Short dcid Some(CID [8]: 3faf070c4a001bae) client | 0.087 DEBUG [Client 000c4e1729b170d7] pn=3 type=Short pri-path:3faf070c4a001bae [::]:33310->[fd00:cafe:cafe:100::100]:443 IpTos(Cs0, Ect0) len 34 client | TX -> Ack { largest_acknowledged: 3, ack_delay: 2, first_ack_range: 3, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 4, Ect0: 0, Ce: 0})) } client | 0.087 DEBUG ECN probing: sent 7 probes client | 0.087 DEBUG [Client 000c4e1729b170d7] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } client | 0.087 DEBUG Building Short dcid Some(CID [8]: 3faf070c4a001bae) client | 0.087 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } client | 0.087 DEBUG [Client 000c4e1729b170d7] delay duration 107.74931ms client | 0.087 DEBUG Setting timeout of 107.74931ms client | 0.087 DEBUG [Client 000c4e1729b170d7] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } client | 0.087 DEBUG Building Short dcid Some(CID [8]: 3faf070c4a001bae) client | 0.087 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } client | 0.087 DEBUG [Client 000c4e1729b170d7] delay duration 107.72263ms client | 0.087 DEBUG Setting timeout of 107.72263ms client | 0.092 DEBUG [Client 000c4e1729b170d7] pn=4 type=Short pri-path:3faf070c4a001bae [::]:33310->[fd00:cafe:cafe:100::100]:443 IpTos(Cs0, Ect1) len 1440 client | -> RX Stream { stream_id: 0, offset: 2828, len: >>1418, fin: false } client | 0.092 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 899, tv_nsec: 623382644 } client | 0.092 DEBUG [Client 000c4e1729b170d7] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } client | 0.092 DEBUG Building Short dcid Some(CID [8]: 3faf070c4a001bae) client | 0.092 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } client | 0.092 DEBUG [Client 000c4e1729b170d7] delay duration 19.971447ms client | 0.092 DEBUG Setting timeout of 19.971447ms client | 0.093 DEBUG [Client 000c4e1729b170d7] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } client | 0.093 DEBUG Building Short dcid Some(CID [8]: 3faf070c4a001bae) client | 0.093 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } client | 0.093 DEBUG [Client 000c4e1729b170d7] delay duration 19.936251ms client | 0.093 DEBUG Setting timeout of 19.936251ms client | 0.098 DEBUG [Client 000c4e1729b170d7] pn=5 type=Short pri-path:3faf070c4a001bae [::]:33310->[fd00:cafe:cafe:100::100]:443 IpTos(Cs0, Ect1) len 1440 client | -> RX Stream { stream_id: 0, offset: 4246, len: 874, fin: true } client | -> RX Stream { stream_id: 4, offset: 0, len: >>540, fin: false } client | 0.098 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 899, tv_nsec: 609248970 } client | 0.098 DEBUG [Client 000c4e1729b170d7] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } client | 0.098 DEBUG Building Short dcid Some(CID [8]: 3faf070c4a001bae) client | 0.098 DEBUG [Client 000c4e1729b170d7] pn=4 type=Short pri-path:3faf070c4a001bae [::]:33310->[fd00:cafe:cafe:100::100]:443 IpTos(Cs0, Ect0) len 34 client | TX -> Ack { largest_acknowledged: 5, ack_delay: 8, first_ack_range: 5, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 6, Ect0: 0, Ce: 0})) } client | 0.098 DEBUG ECN probing: sent 8 probes client | 0.098 DEBUG [Client 000c4e1729b170d7] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } client | 0.098 DEBUG Building Short dcid Some(CID [8]: 3faf070c4a001bae) client | 0.098 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } client | 0.098 DEBUG [Client 000c4e1729b170d7] delay duration 95.966281ms client | 0.098 DEBUG Setting timeout of 95.966281ms client | 0.099 DEBUG [Client 000c4e1729b170d7] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } client | 0.099 DEBUG Building Short dcid Some(CID [8]: 3faf070c4a001bae) client | 0.099 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } client | 0.099 DEBUG [Client 000c4e1729b170d7] delay duration 95.904426ms client | 0.099 DEBUG Setting timeout of 95.904426ms client | 0.104 DEBUG [Client 000c4e1729b170d7] pn=6 type=Short pri-path:3faf070c4a001bae [::]:33310->[fd00:cafe:cafe:100::100]:443 IpTos(Cs0, Ect1) len 1440 client | -> RX Stream { stream_id: 4, offset: 540, len: >>1418, fin: false } client | 0.104 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 899, tv_nsec: 635070663 } client | 0.104 DEBUG [Client 000c4e1729b170d7] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } client | 0.104 DEBUG Building Short dcid Some(CID [8]: 3faf070c4a001bae) client | 0.104 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } client | 0.104 DEBUG [Client 000c4e1729b170d7] delay duration 19.971958ms client | 0.104 DEBUG Setting timeout of 19.971958ms client | 0.104 DEBUG [Client 000c4e1729b170d7] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } client | 0.104 DEBUG Building Short dcid Some(CID [8]: 3faf070c4a001bae) client | 0.104 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } client | 0.104 DEBUG [Client 000c4e1729b170d7] delay duration 19.948113ms client | 0.104 DEBUG Setting timeout of 19.948113ms client | 0.110 DEBUG [Client 000c4e1729b170d7] pn=7 type=Short pri-path:3faf070c4a001bae [::]:33310->[fd00:cafe:cafe:100::100]:443 IpTos(Cs0, Ect1) len 1440 client | -> RX Stream { stream_id: 4, offset: 1958, len: >>1418, fin: false } client | 0.110 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 899, tv_nsec: 620923674 } client | 0.110 DEBUG [Client 000c4e1729b170d7] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } client | 0.110 DEBUG Building Short dcid Some(CID [8]: 3faf070c4a001bae) client | 0.110 DEBUG [Client 000c4e1729b170d7] pn=5 type=Short pri-path:3faf070c4a001bae [::]:33310->[fd00:cafe:cafe:100::100]:443 IpTos(Cs0, Ect0) len 34 client | TX -> Ack { largest_acknowledged: 7, ack_delay: 2, first_ack_range: 7, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 8, Ect0: 0, Ce: 0})) } client | 0.110 DEBUG ECN probing: sent 9 probes client | 0.110 DEBUG [Client 000c4e1729b170d7] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } client | 0.110 DEBUG Building Short dcid Some(CID [8]: 3faf070c4a001bae) client | 0.110 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } client | 0.110 DEBUG [Client 000c4e1729b170d7] delay duration 84.320713ms client | 0.110 DEBUG Setting timeout of 84.320713ms client | 0.110 DEBUG [Client 000c4e1729b170d7] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } client | 0.110 DEBUG Building Short dcid Some(CID [8]: 3faf070c4a001bae) client | 0.110 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } client | 0.110 DEBUG [Client 000c4e1729b170d7] delay duration 84.287552ms client | 0.110 DEBUG Setting timeout of 84.287552ms client | 0.116 DEBUG [Client 000c4e1729b170d7] pn=8 type=Short pri-path:3faf070c4a001bae [::]:33310->[fd00:cafe:cafe:100::100]:443 IpTos(Cs0, Ect1) len 1440 client | -> RX Stream { stream_id: 4, offset: 3376, len: >>1418, fin: false } client | 0.116 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 899, tv_nsec: 646772976 } client | 0.116 DEBUG [Client 000c4e1729b170d7] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } client | 0.116 DEBUG Building Short dcid Some(CID [8]: 3faf070c4a001bae) client | 0.116 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } client | 0.116 DEBUG [Client 000c4e1729b170d7] delay duration 19.973169ms client | 0.116 DEBUG Setting timeout of 19.973169ms client | 0.116 DEBUG [Client 000c4e1729b170d7] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } client | 0.116 DEBUG Building Short dcid Some(CID [8]: 3faf070c4a001bae) client | 0.116 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } client | 0.116 DEBUG [Client 000c4e1729b170d7] delay duration 19.95215ms client | 0.116 DEBUG Setting timeout of 19.95215ms client | 0.122 DEBUG [Client 000c4e1729b170d7] pn=9 type=Short pri-path:3faf070c4a001bae [::]:33310->[fd00:cafe:cafe:100::100]:443 IpTos(Cs0, Ect1) len 1440 client | -> RX Ack { largest_acknowledged: 3, ack_delay: 434, first_ack_range: 1, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 4, Ce: 0})) } client | -> RX Stream { stream_id: 4, offset: 4794, len: >>1409, fin: false } client | 0.122 DEBUG [Client 000c4e1729b170d7] Rx ACK space=ap, ranges=[2..=3] client | 0.122 DEBUG [LossRecovery] ACK for ApplicationData - largest_acked=3 client | 0.122 DEBUG on_packets_acked this=0x557171c2c6d0, limited=1, bytes_in_flight=0, cwnd=12320, state=SlowStart, new_acked=1332 client | 0.122 DEBUG PMTUD probe of size 1380 succeeded client | 0.122 DEBUG PMTUD started with probe size 1420 client | 0.122 DEBUG PLPMTU changed from 1232 to 1332, updating pacer client | 0.122 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 899, tv_nsec: 632653750 } client | 0.122 DEBUG [Client 000c4e1729b170d7] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } client | 0.122 DEBUG Building Short dcid Some(CID [8]: 3faf070c4a001bae) client | 0.122 DEBUG Sending PMTUD probe of size 1420, count 1 client | 0.122 DEBUG [Client 000c4e1729b170d7] pn=6 type=Short pri-path:3faf070c4a001bae [::]:33310->[fd00:cafe:cafe:100::100]:443 IpTos(Cs0, Ect0) len 1372 client | TX -> Ack { largest_acknowledged: 9, ack_delay: 7, first_ack_range: 9, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 10, Ect0: 0, Ce: 0})) } client | TX -> Ping client | TX -> Padding { len: 1337 } client | 0.122 DEBUG packet_sent this=0x557171c2c6d0, pn=6, ps=1372 client | 0.122 DEBUG ECN probing: sent 10 probes client | 0.122 DEBUG ECN probing concluded with 10 probes sent client | 0.122 DEBUG [Client 000c4e1729b170d7] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } client | 0.122 DEBUG Building Short dcid Some(CID [8]: 3faf070c4a001bae) client | 0.122 DEBUG TX blocked, profile=SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } client | 0.122 DEBUG [Client 000c4e1729b170d7] delay duration 101.632925ms client | 0.122 DEBUG Setting timeout of 101.632925ms client | 0.122 DEBUG [Client 000c4e1729b170d7] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } client | 0.122 DEBUG Building Short dcid Some(CID [8]: 3faf070c4a001bae) client | 0.122 DEBUG TX blocked, profile=SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } client | 0.122 DEBUG [Client 000c4e1729b170d7] delay duration 101.59787ms client | 0.122 DEBUG Setting timeout of 101.59787ms client | 0.128 DEBUG [Client 000c4e1729b170d7] pn=10 type=Short pri-path:3faf070c4a001bae [::]:33310->[fd00:cafe:cafe:100::100]:443 IpTos(Cs0, Ect1) len 1440 client | -> RX Stream { stream_id: 4, offset: 6203, len: >>1418, fin: false } client | 0.128 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 899, tv_nsec: 658472908 } client | 0.128 DEBUG [Client 000c4e1729b170d7] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } client | 0.128 DEBUG Building Short dcid Some(CID [8]: 3faf070c4a001bae) client | 0.128 DEBUG TX blocked, profile=SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } client | 0.128 DEBUG [Client 000c4e1729b170d7] delay duration 19.973972ms client | 0.128 DEBUG Setting timeout of 19.973972ms client | 0.128 DEBUG [Client 000c4e1729b170d7] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } client | 0.128 DEBUG Building Short dcid Some(CID [8]: 3faf070c4a001bae) client | 0.128 DEBUG TX blocked, profile=SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } client | 0.128 DEBUG [Client 000c4e1729b170d7] delay duration 19.947843ms client | 0.128 DEBUG Setting timeout of 19.947843ms client | 0.133 DEBUG [Client 000c4e1729b170d7] pn=11 type=Short pri-path:3faf070c4a001bae [::]:33310->[fd00:cafe:cafe:100::100]:443 IpTos(Cs0, Ect1) len 1440 client | -> RX Stream { stream_id: 4, offset: 7621, len: >>1418, fin: false } client | 0.133 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 899, tv_nsec: 643672078 } client | 0.133 DEBUG [Client 000c4e1729b170d7] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } client | 0.133 DEBUG Building Short dcid Some(CID [8]: 3faf070c4a001bae) client | 0.133 DEBUG [Client 000c4e1729b170d7] pn=7 type=Short pri-path:3faf070c4a001bae [::]:33310->[fd00:cafe:cafe:100::100]:443 IpTos(Cs0, NotEct) len 34 client | TX -> Ack { largest_acknowledged: 11, ack_delay: 3, first_ack_range: 11, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 12, Ect0: 0, Ce: 0})) } client | 0.133 DEBUG [Client 000c4e1729b170d7] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } client | 0.133 DEBUG Building Short dcid Some(CID [8]: 3faf070c4a001bae) client | 0.133 DEBUG TX blocked, profile=SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } client | 0.133 DEBUG [Client 000c4e1729b170d7] delay duration 90.666734ms client | 0.133 DEBUG Setting timeout of 90.666734ms client | 0.133 DEBUG [Client 000c4e1729b170d7] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } client | 0.133 DEBUG Building Short dcid Some(CID [8]: 3faf070c4a001bae) client | 0.133 DEBUG TX blocked, profile=SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } client | 0.133 DEBUG [Client 000c4e1729b170d7] delay duration 90.633813ms client | 0.133 DEBUG Setting timeout of 90.633813ms client | 0.138 DEBUG [Client 000c4e1729b170d7] pn=12 type=Short pri-path:3faf070c4a001bae [::]:33310->[fd00:cafe:cafe:100::100]:443 IpTos(Cs0, Ect1) len 1335 client | -> RX Stream { stream_id: 4, offset: 9039, len: 1201, fin: true } client | -> RX Padding { len: 110 } client | 0.138 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 899, tv_nsec: 668811246 } client | 0.138 DEBUG [Client 000c4e1729b170d7] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } client | 0.138 DEBUG Building Short dcid Some(CID [8]: 3faf070c4a001bae) client | 0.138 DEBUG TX blocked, profile=SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } client | 0.138 DEBUG [Client 000c4e1729b170d7] delay duration 19.965826ms client | 0.138 DEBUG Setting timeout of 19.965826ms client | 0.138 DEBUG [Client 000c4e1729b170d7] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } client | 0.138 DEBUG Building Short dcid Some(CID [8]: 3faf070c4a001bae) client | 0.138 DEBUG TX blocked, profile=SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } client | 0.138 DEBUG [Client 000c4e1729b170d7] delay duration 19.907667ms client | 0.138 DEBUG Setting timeout of 19.907667ms client | 0.138 DEBUG [Client 000c4e1729b170d7] State change from Confirmed -> Closing { error: Application(0), timeout: Instant { tv_sec: 899, tv_nsec: 954055035 } } client | 0.138 WARN Unhandled event StateChange(Closing { error: Application(0), timeout: Instant { tv_sec: 899, tv_nsec: 954055035 } }) client | 0.138 DEBUG [Client 000c4e1729b170d7] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } client | 0.138 DEBUG Building Short dcid Some(CID [8]: 3faf070c4a001bae) client | 0.138 DEBUG [Recvd-ap] immediate_ack at Instant { tv_sec: 899, tv_nsec: 648937442 } client | 0.138 DEBUG [Client 000c4e1729b170d7] pn=8 type=Short pri-path:3faf070c4a001bae [::]:33310->[fd00:cafe:cafe:100::100]:443 IpTos(Cs0, NotEct) len 45 client | TX -> Ack { largest_acknowledged: 12, ack_delay: 15, first_ack_range: 12, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 13, Ect0: 0, Ce: 0})) } client | TX -> ConnectionClose { error_code: Application(0), frame_type: 0, reason_phrase: "kthxbye!" } client | 0.138 DEBUG Setting timeout of 305.059404ms client | 0.142 DEBUG [Client 000c4e1729b170d7] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } client | 0.142 DEBUG Building Short dcid Some(CID [8]: 3faf070c4a001bae) client | 0.142 DEBUG [Recvd-ap] immediate_ack at Instant { tv_sec: 899, tv_nsec: 652670173 } client | 0.142 DEBUG [Client 000c4e1729b170d7] pn=9 type=Short pri-path:3faf070c4a001bae [::]:33310->[fd00:cafe:cafe:100::100]:443 IpTos(Cs0, NotEct) len 46 client | TX -> Ack { largest_acknowledged: 12, ack_delay: 482, first_ack_range: 12, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 13, Ect0: 0, Ce: 0})) } client | TX -> ConnectionClose { error_code: Application(0), frame_type: 0, reason_phrase: "kthxbye!" } client | 0.142 DEBUG Setting timeout of 301.309531ms client | 0.142 DEBUG Setting timeout of 301.301065ms client | 0.146 DEBUG [Client 000c4e1729b170d7] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } client | 0.146 DEBUG Building Short dcid Some(CID [8]: 3faf070c4a001bae) client | 0.146 DEBUG [Recvd-ap] immediate_ack at Instant { tv_sec: 899, tv_nsec: 656858826 } client | 0.146 DEBUG [Client 000c4e1729b170d7] pn=10 type=Short pri-path:3faf070c4a001bae [::]:33310->[fd00:cafe:cafe:100::100]:443 IpTos(Cs0, NotEct) len 46 client | TX -> Ack { largest_acknowledged: 12, ack_delay: 1005, first_ack_range: 12, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 13, Ect0: 0, Ce: 0})) } client | TX -> ConnectionClose { error_code: Application(0), frame_type: 0, reason_phrase: "kthxbye!" } client | 0.146 DEBUG Setting timeout of 297.130627ms client | 0.146 DEBUG Setting timeout of 297.122051ms client | 0.150 DEBUG [Client 000c4e1729b170d7] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } client | 0.150 DEBUG Building Short dcid Some(CID [8]: 3faf070c4a001bae) client | 0.150 DEBUG [Recvd-ap] immediate_ack at Instant { tv_sec: 899, tv_nsec: 660944356 } client | 0.150 DEBUG [Client 000c4e1729b170d7] pn=11 type=Short pri-path:3faf070c4a001bae [::]:33310->[fd00:cafe:cafe:100::100]:443 IpTos(Cs0, NotEct) len 46 client | TX -> Ack { largest_acknowledged: 12, ack_delay: 1516, first_ack_range: 12, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 13, Ect0: 0, Ce: 0})) } client | TX -> ConnectionClose { error_code: Application(0), frame_type: 0, reason_phrase: "kthxbye!" } client | 0.150 DEBUG Setting timeout of 293.029157ms client | 0.150 DEBUG Setting timeout of 293.018216ms client | 0.153 DEBUG [Client 000c4e1729b170d7] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } client | 0.153 DEBUG Building Short dcid Some(CID [8]: 3faf070c4a001bae) client | 0.153 DEBUG [Recvd-ap] immediate_ack at Instant { tv_sec: 899, tv_nsec: 664394700 } client | 0.153 DEBUG [Client 000c4e1729b170d7] pn=12 type=Short pri-path:3faf070c4a001bae [::]:33310->[fd00:cafe:cafe:100::100]:443 IpTos(Cs0, NotEct) len 46 client | TX -> Ack { largest_acknowledged: 12, ack_delay: 1947, first_ack_range: 12, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 13, Ect0: 0, Ce: 0})) } client | TX -> ConnectionClose { error_code: Application(0), frame_type: 0, reason_phrase: "kthxbye!" } client | 0.154 DEBUG Setting timeout of 289.581907ms client | 0.154 DEBUG Setting timeout of 289.572088ms client | 0.160 DEBUG [Client 000c4e1729b170d7] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } client | 0.160 DEBUG Building Short dcid Some(CID [8]: 3faf070c4a001bae) client | 0.160 DEBUG [Recvd-ap] immediate_ack at Instant { tv_sec: 899, tv_nsec: 671035374 } client | 0.160 DEBUG [Client 000c4e1729b170d7] pn=13 type=Short pri-path:3faf070c4a001bae [::]:33310->[fd00:cafe:cafe:100::100]:443 IpTos(Cs0, NotEct) len 46 client | TX -> Ack { largest_acknowledged: 12, ack_delay: 2778, first_ack_range: 12, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 13, Ect0: 0, Ce: 0})) } client | TX -> ConnectionClose { error_code: Application(0), frame_type: 0, reason_phrase: "kthxbye!" } client | 0.160 DEBUG Setting timeout of 282.9271ms client | 0.160 DEBUG Setting timeout of 282.916239ms client | 0.169 DEBUG [Client 000c4e1729b170d7] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } client | 0.169 DEBUG Building Short dcid Some(CID [8]: 3faf070c4a001bae) client | 0.169 DEBUG [Recvd-ap] immediate_ack at Instant { tv_sec: 899, tv_nsec: 679494671 } client | 0.169 DEBUG [Client 000c4e1729b170d7] pn=14 type=Short pri-path:3faf070c4a001bae [::]:33310->[fd00:cafe:cafe:100::100]:443 IpTos(Cs0, NotEct) len 46 client | TX -> Ack { largest_acknowledged: 12, ack_delay: 3835, first_ack_range: 12, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 13, Ect0: 0, Ce: 0})) } client | TX -> ConnectionClose { error_code: Application(0), frame_type: 0, reason_phrase: "kthxbye!" } client | 0.169 DEBUG Setting timeout of 274.488309ms client | 0.169 DEBUG Setting timeout of 274.474063ms client | 0.444 DEBUG [Client 000c4e1729b170d7] State change from Closing { error: Application(0), timeout: Instant { tv_sec: 899, tv_nsec: 954055035 } } -> Closed(Application(0)) client | 0.444 INFO Closing timer expired client | 0.444 DEBUG Output::None client | 0.444 WARN Unhandled event StateChange(Closed(Application(0))) client | 0.444 DEBUG Timer fired while closed client | 0.444 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:42:06,017 Using the client's key log file. 2025-04-30 11:42:06,028 2025-04-30 11:42:06,028 Using the client's key log file. 2025-04-30 11:42:06,029 Using the client's key log file. 2025-04-30 11:42:06,039 2025-04-30 11:42:06,039 Using the client's key log file. 2025-04-30 11:42:06,604 Check of downloaded files succeeded. 2025-04-30 11:42:07,175 Check of downloaded files succeeded.