2025-04-30 10:49:22,406 Generated random file: bfkvvhzxgp of size: 5120 2025-04-30 10:49:22,407 Generated random file: zlnticzqlq of size: 10240 2025-04-30 10:49:22,407 Requests: https://server4:443/bfkvvhzxgp https://server4:443/zlnticzqlq 2025-04-30 10:49:22,466 2025-04-30 10:49:22,466 Command: WAITFORSERVER=server:443 CERTS=/tmp/certs_g44x4yoo/ TESTCASE_SERVER=resumption TESTCASE_CLIENT=resumption WWW=/tmp/www_foxj1wpx/ DOWNLOADS=/tmp/download_2gs4y9gi/ SERVER_LOGS=/tmp/logs_server_2pvp0ff0 CLIENT_LOGS=/tmp/logs_client_9i6fvaaz SCENARIO="simple-p2p --delay=15ms --bandwidth=10Mbps --queue=25" CLIENT=ghcr.io/mozilla/neqo-qns:latest SERVER=peterdoornbosch/kwik_n_flupke-interop REQUESTS="https://server4:443/bfkvvhzxgp https://server4:443/zlnticzqlq" docker compose --env-file empty.env up --abort-on-container-exit --timeout 1 sim client server 2025-04-30 10:49:36,844 Container sim Created Container client Recreate Container server Recreate Container client Recreated Container server Recreated Attaching to client, server, sim sim | waiting 10s for server:443 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 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 client | + export PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/neqo/bin client | + PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/neqo/bin client | + '[' -n resumption ']' client | + '[' -n /logs/qlog/ ']' client | + case "$ROLE" in client | + /wait-for-it.sh sim:57832 -s -t 30 server | Endpoint's IPv4 address is 193.167.100.100 server | Endpoint's IPv6 address is fd00:cafe:cafe:100::100 client | wait-for-it.sh: waiting 30 seconds for sim:57832 server | Importing keystore /server.p12 to /server.keystore... server | running kwik server version 0.10.2 server | Old Flupke plugin not found sim | server:443 is available after 1.014982398s sim | Using scenario: simple-p2p --delay=15ms --bandwidth=10Mbps --queue=25 sim | tcpdump: listening on eth1, link-type EN10MB (Ethernet), snapshot length 262144 bytes sim | tcpdump: listening on eth0, link-type EN10MB (Ethernet), snapshot length 262144 bytes client | wait-for-it.sh: sim:57832 is available after 2 seconds client | + OPTIONS=(--cc cubic --qns-test "$TESTCASE" --qlog-dir "$QLOGDIR" --output-dir /downloads) client | + '[' 'https://server4:443/bfkvvhzxgp https://server4:443/zlnticzqlq' ']' client | + mapfile -d ' ' -t URLS client | + OPTIONS+=("${URLS[@]}") client | + RUST_LOG=debug client | + RUST_BACKTRACE=1 client | + neqo-client --cc cubic --qns-test resumption --qlog-dir /logs/qlog/ --output-dir /downloads https://server4:443/bfkvvhzxgp 'https://server4:443/zlnticzqlq client | ' client | ++ tee -i -a /logs/client.log client | 0.000 DEBUG Logging initialized client | 0.001 DEBUG Default socket send buffer size is 212992 client | 0.001 DEBUG Default socket receive buffer size is 1048576, not changing client | 0.001 INFO hq-interop Client connecting: 0.0.0.0:48671 -> 193.167.100.100:443 client | 0.001 DEBUG [CryptoStates] Creating initial cipher state v=Version1, role=Client dcid=3ea232698cea7cf2 client | 0.001 DEBUG Making Write Initial CryptoDxState, v=Version1 cipher=4865 client | 0.001 DEBUG Making Read Initial CryptoDxState, v=Version1 cipher=4865 client | 0.001 DEBUG Outbound interface eth0 for destination 193.167.100.100 has MTU 1500 client | 0.001 DEBUG [unv-path 0.0.0.0:48671->193.167.100.100:443] Make permanent client | 0.001 DEBUG [unv-path:3ea232698cea7cf2 0.0.0.0:48671->193.167.100.100:443] set as primary path client | 0.001 DEBUG [pri-unv-path:3ea232698cea7cf2 0.0.0.0:48671->193.167.100.100:443] Path validated Instant { tv_sec: 378, tv_nsec: 617301071 } client | 0.001 DEBUG [Client 3ea232698cea7cf2] client_start client | 0.002 DEBUG Writing transport parameters, msg=1 client | 0.002 DEBUG [Agent 0x55896abbff20] state -> InProgress client | 0.002 DEBUG [Client 3ea232698cea7cf2] State change from Init -> WaitInitial client | 0.002 DEBUG [Client 3ea232698cea7cf2] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.002 DEBUG Building Initial dcid Some(CID [8]: 3ea232698cea7cf2) scid Some(CID [0]: ) client | 0.002 DEBUG CRYPTO for in offset=0, len=1213 client | 0.002 DEBUG [Client 3ea232698cea7cf2] pn=0 type=Initial pri-path:3ea232698cea7cf2 0.0.0.0:48671->193.167.100.100:443 IpTos(Cs0, Ect0) len 1252 client | TX -> Crypto { offset: 0, len: 1213 } client | 0.002 DEBUG packet_sent this=0x55896abd3630, pn=0, ps=1252 client | 0.002 DEBUG ECN probing: sent 1 probes client | 0.002 DEBUG [Client 3ea232698cea7cf2] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.002 DEBUG Building Initial dcid Some(CID [8]: 3ea232698cea7cf2) scid Some(CID [0]: ) client | 0.002 DEBUG CRYPTO for in offset=1213, len=326 client | 0.002 DEBUG [Client 3ea232698cea7cf2] pn=1 type=Initial pri-path:3ea232698cea7cf2 0.0.0.0:48671->193.167.100.100:443 IpTos(Cs0, Ect0) len 366 client | TX -> Crypto { offset: 1213, len: 326 } client | 0.002 DEBUG [Client 3ea232698cea7cf2] pad Initial from 366 to PLPMTU 1252 client | 0.002 DEBUG packet_sent this=0x55896abd3630, pn=1, ps=1252 client | 0.002 DEBUG ECN probing: sent 2 probes client | 0.002 DEBUG [Client 3ea232698cea7cf2] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } client | 0.002 DEBUG Building Initial dcid Some(CID [8]: 3ea232698cea7cf2) 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 3ea232698cea7cf2] delay duration 3.972832ms client | 0.002 DEBUG Setting timeout of 3.972832ms client | 0.002 DEBUG StateChange(WaitInitial) client | 0.002 WARN Cannot create stream ConnectionState client | 0.002 DEBUG [Client 3ea232698cea7cf2] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } client | 0.002 DEBUG Building Initial dcid Some(CID [8]: 3ea232698cea7cf2) 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 3ea232698cea7cf2] delay duration 3.953075ms client | 0.002 DEBUG Setting timeout of 3.953075ms client | 0.007 DEBUG [Client 3ea232698cea7cf2] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.007 DEBUG Building Initial dcid Some(CID [8]: 3ea232698cea7cf2) scid Some(CID [0]: ) client | 0.007 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.007 DEBUG [Client 3ea232698cea7cf2] delay duration 294.833847ms client | 0.007 DEBUG Setting timeout of 294.833847ms client | 0.158 DEBUG [Client 3ea232698cea7cf2] pn=0 type=Initial pri-path:3ea232698cea7cf2 0.0.0.0:48671->193.167.100.100:443 IpTos(Cs0, NotEct) len 1201 client | -> RX Ack { largest_acknowledged: 0, ack_delay: 0, first_ack_range: 0, ack_ranges: [], ecn_count: None } client | -> RX Padding { len: 1161 } client | 0.158 DEBUG [Client 3ea232698cea7cf2] Rx ACK space=in, ranges=[0..=0] client | 0.158 DEBUG [LossRecovery] ACK for Initial - largest_acked=0 client | 0.158 DEBUG on_packets_acked this=0x55896abd3630, limited=1, bytes_in_flight=1252, cwnd=12520, state=SlowStart, new_acked=1252 client | 0.158 DEBUG Acked crypto frame space=in offset=0 length=1213 client | 0.158 DEBUG [Client 3ea232698cea7cf2] Changing to use Server CID=49510664717a232e client | 0.158 DEBUG [Client 3ea232698cea7cf2] State change from WaitInitial -> WaitVersion client | 0.158 DEBUG [Client 3ea232698cea7cf2] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.158 DEBUG Building Initial dcid Some(CID [8]: 49510664717a232e) scid Some(CID [0]: ) client | 0.158 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.158 DEBUG [Client 3ea232698cea7cf2] delay duration 312.871681ms client | 0.158 DEBUG Setting timeout of 312.871681ms client | 0.158 WARN Unhandled event StateChange(WaitVersion) client | 0.158 DEBUG [Client 3ea232698cea7cf2] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.158 DEBUG Building Initial dcid Some(CID [8]: 49510664717a232e) scid Some(CID [0]: ) client | 0.158 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.158 DEBUG [Client 3ea232698cea7cf2] delay duration 312.836676ms client | 0.158 DEBUG Setting timeout of 312.836676ms client | 0.264 DEBUG [Client 3ea232698cea7cf2] pn=1 type=Initial pri-path:49510664717a232e 0.0.0.0:48671->193.167.100.100:443 IpTos(Cs0, NotEct) len 463 client | -> RX Ack { largest_acknowledged: 1, ack_delay: 0, first_ack_range: 1, ack_ranges: [], ecn_count: None } client | -> RX Crypto { offset: 0, len: 90 } client | -> RX Padding { len: 329 } client | 0.264 DEBUG [Client 3ea232698cea7cf2] Rx ACK space=in, ranges=[0..=1] client | 0.264 DEBUG [LossRecovery] ACK for Initial - largest_acked=1 client | 0.264 DEBUG on_packets_acked this=0x55896abd3630, limited=1, bytes_in_flight=0, cwnd=12520, state=SlowStart, new_acked=1252 client | 0.264 DEBUG Acked crypto frame space=in offset=1213 length=326 client | 0.264 DEBUG Read Ok(90) bytes client | 0.264 DEBUG Write secret available for Handshake: SymKey [32]: ef0adc909776835265c137608b34a4a8175ea2f3a54c001bde5f3e4c65f729bd client | 0.264 DEBUG Read secret available for Handshake: SymKey [32]: 68da8fa308b2cc8233ac2d3fadc2020aa851cf2ee52251bcfb7cea9100ce6383 client | 0.264 DEBUG [Agent 0x55896abbff20] state -> InProgress client | 0.264 DEBUG Making Write Handshake CryptoDxState, v=Version1 cipher=4865 client | 0.264 DEBUG Making Read Handshake CryptoDxState, v=Version1 cipher=4865 client | 0.264 DEBUG [Crypto] Handshake keys installed client | 0.264 DEBUG [Recvd-in] Set ACK timer to Instant { tv_sec: 378, tv_nsec: 880595584 } client | 0.264 DEBUG [Client 3ea232698cea7cf2] State change from WaitVersion -> Handshaking client | 0.264 DEBUG [Client 3ea232698cea7cf2] pn=0 type=Handshake pri-path:49510664717a232e 0.0.0.0:48671->193.167.100.100:443 IpTos(Cs0, NotEct) len 737 client | -> RX Crypto { offset: 0, len: 699 } client | 0.264 DEBUG Read Ok(699) bytes client | 0.265 DEBUG [Agent 0x55896abbff20] state -> AuthenticationPending client | 0.265 DEBUG [Recvd-hs] Set ACK timer to Instant { tv_sec: 378, tv_nsec: 880595584 } client | 0.265 DEBUG [Client 3ea232698cea7cf2] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.265 DEBUG Building Initial dcid Some(CID [8]: 49510664717a232e) scid Some(CID [0]: ) client | 0.265 DEBUG [Client 3ea232698cea7cf2] pn=2 type=Initial pri-path:49510664717a232e 0.0.0.0:48671->193.167.100.100:443 IpTos(Cs0, Ect0) len 41 client | TX -> Ack { largest_acknowledged: 1, ack_delay: 124, first_ack_range: 1, ack_ranges: [], ecn_count: None } client | 0.265 DEBUG Building Handshake dcid Some(CID [8]: 49510664717a232e) scid Some(CID [0]: ) client | 0.265 DEBUG [Client 3ea232698cea7cf2] pn=0 type=Handshake pri-path:49510664717a232e 0.0.0.0:48671->193.167.100.100:443 IpTos(Cs0, Ect0) len 81 client | TX -> Ack { largest_acknowledged: 0, ack_delay: 124, first_ack_range: 0, ack_ranges: [], ecn_count: None } client | 0.265 DEBUG [Client 3ea232698cea7cf2] Drop packet number space in client | 0.265 DEBUG [LossRecovery] Reset loss recovery state for Initial client | 0.265 WARN [LossRecovery] ignoring in-2 from dropped space client | 0.265 DEBUG ECN probing: sent 3 probes client | 0.265 DEBUG [Client 3ea232698cea7cf2] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.265 DEBUG Building Handshake dcid Some(CID [8]: 49510664717a232e) scid Some(CID [0]: ) client | 0.265 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.265 DEBUG [Client 3ea232698cea7cf2] delay duration 509.867213ms client | 0.265 DEBUG Setting timeout of 509.867213ms client | 0.265 DEBUG StateChange(Handshaking) client | 0.265 WARN Cannot create stream ConnectionState client | 0.265 DEBUG [Client 3ea232698cea7cf2] Authenticated Ok client | 0.265 DEBUG Write secret available for ApplicationData: SymKey [32]: 924f840f93684909405ad6d76114a952a0574cd27cfcfede670cb4e9e5fce14a client | 0.265 DEBUG Read secret available for ApplicationData: SymKey [32]: 3cd3b88d97c98a41ba7f6e615197afc4ce6caf011607e89c3c108080241decc6 client | 0.265 DEBUG [Agent 0x55896abbff20] SSL_AuthCertificateComplete: Ok(()) client | 0.265 DEBUG [Agent 0x55896abbff20] 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.265 DEBUG [Client 3ea232698cea7cf2] TLS connection complete client | 0.265 DEBUG Making Write ApplicationData CryptoDxState, v=Version1 cipher=4865 client | 0.265 DEBUG [Crypto] Application write key installed client | 0.265 DEBUG Making Read ApplicationData CryptoDxState, v=Version1 cipher=4865 client | 0.265 DEBUG [Crypto] application read keys installed client | 0.265 DEBUG [Client 3ea232698cea7cf2] State change from Handshaking -> Connected client | 0.265 INFO [Client 3ea232698cea7cf2] Connection established client | 0.265 DEBUG stream BiDi creatable client | 0.265 INFO Created stream 0 for https://server4/bfkvvhzxgp client | 0.265 INFO Saving https://server4/bfkvvhzxgp to "/downloads/bfkvvhzxgp" client | 0.266 DEBUG StateChange(Connected) client | 0.266 DEBUG stream 0 writable client | 0.266 DEBUG [Client 3ea232698cea7cf2] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.266 DEBUG Building Handshake dcid Some(CID [8]: 49510664717a232e) scid Some(CID [0]: ) client | 0.266 DEBUG CRYPTO for hs offset=0, len=36 client | 0.266 DEBUG [Client 3ea232698cea7cf2] pn=1 type=Handshake pri-path:49510664717a232e 0.0.0.0:48671->193.167.100.100:443 IpTos(Cs0, Ect0) len 73 client | TX -> Crypto { offset: 0, len: 36 } client | 0.266 DEBUG packet_sent this=0x55896abd3630, pn=1, ps=73 client | 0.266 DEBUG Building Short dcid Some(CID [8]: 49510664717a232e) client | 0.266 DEBUG [Client 3ea232698cea7cf2] pn=0 type=Short pri-path:49510664717a232e 0.0.0.0:48671->193.167.100.100:443 IpTos(Cs0, Ect0) len 119 client | TX -> Stream { stream_id: 0, offset: 0, len: 17, fin: true } client | 0.266 DEBUG packet_sent this=0x55896abd3630, pn=0, ps=46 client | 0.266 DEBUG ECN probing: sent 4 probes client | 0.266 DEBUG [Client 3ea232698cea7cf2] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.266 DEBUG Building Handshake dcid Some(CID [8]: 49510664717a232e) scid Some(CID [0]: ) client | 0.266 DEBUG Building Short dcid Some(CID [8]: 49510664717a232e) client | 0.266 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.266 DEBUG [Client 3ea232698cea7cf2] delay duration 509.876802ms client | 0.266 DEBUG Setting timeout of 509.876802ms client | 0.313 DEBUG [Client 3ea232698cea7cf2] pn=0 type=Short pri-path:49510664717a232e 0.0.0.0:48671->193.167.100.100:443 IpTos(Cs0, NotEct) len 204 client | -> RX HandshakeDone client | -> RX NewConnectionId { sequence_number: 1, retire_prior: 0, connection_id: [219, 131, 121, 158, 213, 186, 229, 105], stateless_reset_token: [38, 242, 34, 24, 49, 130, 124, 209, 41, 66, 30, 254, 30, 122, 162, 161] } client | -> RX NewConnectionId { sequence_number: 2, retire_prior: 0, connection_id: [101, 156, 38, 26, 229, 108, 30, 201], stateless_reset_token: [58, 145, 41, 8, 95, 99, 235, 106, 115, 51, 216, 165, 228, 51, 183, 225] } client | -> RX NewConnectionId { sequence_number: 3, retire_prior: 0, connection_id: [52, 48, 225, 156, 1, 221, 71, 23], stateless_reset_token: [155, 94, 135, 115, 213, 1, 22, 213, 211, 16, 202, 109, 88, 249, 24, 11] } client | -> RX NewConnectionId { sequence_number: 4, retire_prior: 0, connection_id: [53, 38, 232, 198, 126, 101, 78, 80], stateless_reset_token: [24, 144, 57, 152, 145, 143, 60, 67, 209, 151, 96, 87, 158, 178, 241, 36] } client | -> RX NewConnectionId { sequence_number: 5, retire_prior: 0, connection_id: [29, 125, 22, 208, 183, 102, 237, 128], stateless_reset_token: [0, 191, 68, 87, 100, 34, 30, 139, 214, 56, 235, 235, 102, 4, 245, 125] } client | -> RX Crypto { offset: 0, len: 42 } client | 0.314 DEBUG [Client 3ea232698cea7cf2] State change from Connected -> Confirmed client | 0.314 DEBUG PMTUD started with probe size 1380 client | 0.314 DEBUG [Client 3ea232698cea7cf2] Drop packet number space hs client | 0.314 DEBUG [LossRecovery] Reset loss recovery state for Handshake client | 0.314 DEBUG [Client 3ea232698cea7cf2] No preferred address to migrate to client | 0.314 DEBUG Read Ok(42) bytes client | 0.314 DEBUG [0x55896abbff20] Got resumption token [712]: 02000633fcab9e5c..84f4a0acfaaeb35f client | 0.314 DEBUG [Agent 0x55896abbff20] 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.314 DEBUG setting max_stream_data to 1000000 client | 0.314 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 378, tv_nsec: 949953091 } client | 0.314 DEBUG [Client 3ea232698cea7cf2] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.314 DEBUG Building Short dcid Some(CID [8]: 49510664717a232e) client | 0.314 DEBUG Sending PMTUD probe of size 1380, count 1 client | 0.314 DEBUG [Client 3ea232698cea7cf2] pn=1 type=Short pri-path:49510664717a232e 0.0.0.0:48671->193.167.100.100:443 IpTos(Cs0, Ect0) len 1352 client | TX -> Ping client | TX -> Padding { len: 1325 } client | 0.314 DEBUG packet_sent this=0x55896abd3630, pn=1, ps=1352 client | 0.314 DEBUG ECN probing: sent 5 probes client | 0.314 DEBUG [Client 3ea232698cea7cf2] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.314 DEBUG Building Short dcid Some(CID [8]: 49510664717a232e) client | 0.314 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.314 DEBUG [Client 3ea232698cea7cf2] delay duration 19.477303ms client | 0.314 DEBUG Setting timeout of 19.477303ms client | 0.314 WARN Unhandled event StateChange(Confirmed) client | 0.314 DEBUG stream BiDi creatable client | 0.314 DEBUG [Client 3ea232698cea7cf2] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.315 DEBUG Building Short dcid Some(CID [8]: 49510664717a232e) client | 0.315 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.315 DEBUG [Client 3ea232698cea7cf2] delay duration 18.928196ms client | 0.315 DEBUG Setting timeout of 18.928196ms client | 0.324 DEBUG [Client 3ea232698cea7cf2] pn=1 type=Short pri-path:49510664717a232e 0.0.0.0:48671->193.167.100.100:443 IpTos(Cs0, NotEct) len 1252 client | -> RX Stream { stream_id: 0, offset: 0, len: 1223, fin: false } client | -> RX Ack { largest_acknowledged: 0, ack_delay: 250, first_ack_range: 0, ack_ranges: [], ecn_count: None } client | 0.324 DEBUG [Client 3ea232698cea7cf2] Rx ACK space=ap, ranges=[0..=0] client | 0.324 DEBUG [LossRecovery] ACK for ApplicationData - largest_acked=0 client | 0.324 DEBUG on_packets_acked this=0x55896abd3630, limited=1, bytes_in_flight=1352, cwnd=12520, state=SlowStart, new_acked=46 client | 0.324 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 378, tv_nsec: 940578656 } client | 0.324 DEBUG [Client 3ea232698cea7cf2] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.324 DEBUG Building Short dcid Some(CID [8]: 49510664717a232e) client | 0.324 DEBUG [Client 3ea232698cea7cf2] pn=2 type=Short pri-path:49510664717a232e 0.0.0.0:48671->193.167.100.100:443 IpTos(Cs0, Ect0) len 31 client | TX -> Ack { largest_acknowledged: 1, ack_delay: 7, first_ack_range: 1, ack_ranges: [], ecn_count: None } client | 0.324 DEBUG ECN probing: sent 6 probes client | 0.324 DEBUG [Client 3ea232698cea7cf2] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.324 DEBUG Building Short dcid Some(CID [8]: 49510664717a232e) client | 0.324 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.324 DEBUG [Client 3ea232698cea7cf2] delay duration 536.506844ms client | 0.324 DEBUG Setting timeout of 536.506844ms client | 0.324 DEBUG stream 0 complete client | 0.324 DEBUG [Client 3ea232698cea7cf2] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.324 DEBUG Building Short dcid Some(CID [8]: 49510664717a232e) client | 0.324 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.324 DEBUG [Client 3ea232698cea7cf2] delay duration 536.484672ms client | 0.324 DEBUG Setting timeout of 536.484672ms client | 0.325 DEBUG [Client 3ea232698cea7cf2] pn=2 type=Short pri-path:49510664717a232e 0.0.0.0:48671->193.167.100.100:443 IpTos(Cs0, NotEct) len 1252 client | -> RX Stream { stream_id: 0, offset: 1223, len: 1223, fin: false } client | -> RX Ack { largest_acknowledged: 0, ack_delay: 0, first_ack_range: 0, ack_ranges: [], ecn_count: None } client | 0.325 DEBUG [Client 3ea232698cea7cf2] Rx ACK space=ap, ranges=[0..=0] client | 0.325 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 378, tv_nsec: 961714561 } client | 0.325 DEBUG [Client 3ea232698cea7cf2] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.325 DEBUG Building Short dcid Some(CID [8]: 49510664717a232e) client | 0.325 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.325 DEBUG [Client 3ea232698cea7cf2] delay duration 19.965926ms client | 0.325 DEBUG Setting timeout of 19.965926ms client | 0.325 DEBUG [Client 3ea232698cea7cf2] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.325 DEBUG Building Short dcid Some(CID [8]: 49510664717a232e) client | 0.325 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.325 DEBUG [Client 3ea232698cea7cf2] delay duration 19.940289ms client | 0.325 DEBUG Setting timeout of 19.940289ms client | 0.326 DEBUG [Client 3ea232698cea7cf2] pn=3 type=Short pri-path:49510664717a232e 0.0.0.0:48671->193.167.100.100:443 IpTos(Cs0, NotEct) len 1252 client | -> RX Stream { stream_id: 0, offset: 2446, len: 1223, fin: false } client | -> RX Ack { largest_acknowledged: 0, ack_delay: 0, first_ack_range: 0, ack_ranges: [], ecn_count: None } client | 0.326 DEBUG [Client 3ea232698cea7cf2] Rx ACK space=ap, ranges=[0..=0] client | 0.326 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 378, tv_nsec: 942814057 } client | 0.326 DEBUG [Client 3ea232698cea7cf2] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.326 DEBUG Building Short dcid Some(CID [8]: 49510664717a232e) client | 0.326 DEBUG [Client 3ea232698cea7cf2] pn=3 type=Short pri-path:49510664717a232e 0.0.0.0:48671->193.167.100.100:443 IpTos(Cs0, Ect0) len 31 client | TX -> Ack { largest_acknowledged: 3, ack_delay: 4, first_ack_range: 3, ack_ranges: [], ecn_count: None } client | 0.326 DEBUG ECN probing: sent 7 probes client | 0.326 DEBUG [Client 3ea232698cea7cf2] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.326 DEBUG Building Short dcid Some(CID [8]: 49510664717a232e) client | 0.326 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.326 DEBUG [Client 3ea232698cea7cf2] delay duration 534.306008ms client | 0.326 DEBUG Setting timeout of 534.306008ms client | 0.326 DEBUG [Client 3ea232698cea7cf2] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.326 DEBUG Building Short dcid Some(CID [8]: 49510664717a232e) client | 0.326 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.326 DEBUG [Client 3ea232698cea7cf2] delay duration 534.287703ms client | 0.326 DEBUG Setting timeout of 534.287703ms client | 0.327 DEBUG [Client 3ea232698cea7cf2] pn=4 type=Short pri-path:49510664717a232e 0.0.0.0:48671->193.167.100.100:443 IpTos(Cs0, NotEct) len 1252 client | -> RX Stream { stream_id: 0, offset: 3669, len: 1223, fin: false } client | -> RX Ack { largest_acknowledged: 0, ack_delay: 0, first_ack_range: 0, ack_ranges: [], ecn_count: None } client | 0.327 DEBUG [Client 3ea232698cea7cf2] Rx ACK space=ap, ranges=[0..=0] client | 0.327 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 378, tv_nsec: 963841539 } client | 0.327 DEBUG [Client 3ea232698cea7cf2] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.327 DEBUG Building Short dcid Some(CID [8]: 49510664717a232e) client | 0.327 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.327 DEBUG [Client 3ea232698cea7cf2] delay duration 19.961258ms client | 0.327 DEBUG Setting timeout of 19.961258ms client | 0.327 DEBUG [Client 3ea232698cea7cf2] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.327 DEBUG Building Short dcid Some(CID [8]: 49510664717a232e) client | 0.327 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.327 DEBUG [Client 3ea232698cea7cf2] delay duration 19.942032ms client | 0.327 DEBUG Setting timeout of 19.942032ms client | 0.328 DEBUG [Client 3ea232698cea7cf2] pn=5 type=Short pri-path:49510664717a232e 0.0.0.0:48671->193.167.100.100:443 IpTos(Cs0, NotEct) len 260 client | -> RX Stream { stream_id: 0, offset: 4892, len: 228, fin: true } client | -> RX Ack { largest_acknowledged: 0, ack_delay: 0, first_ack_range: 0, ack_ranges: [], ecn_count: None } client | -> RX MaxStreams { stream_type: BiDi, maximum_streams: 101 } client | 0.328 DEBUG [Client 3ea232698cea7cf2] Rx ACK space=ap, ranges=[0..=0] client | 0.328 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 378, tv_nsec: 944107426 } client | 0.328 DEBUG [Client 3ea232698cea7cf2] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.328 DEBUG Building Short dcid Some(CID [8]: 49510664717a232e) client | 0.328 DEBUG [Client 3ea232698cea7cf2] pn=4 type=Short pri-path:49510664717a232e 0.0.0.0:48671->193.167.100.100:443 IpTos(Cs0, Ect0) len 31 client | TX -> Ack { largest_acknowledged: 5, ack_delay: 37, first_ack_range: 5, ack_ranges: [], ecn_count: None } client | 0.328 DEBUG ECN probing: sent 8 probes client | 0.328 DEBUG [Client 3ea232698cea7cf2] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.328 DEBUG Building Short dcid Some(CID [8]: 49510664717a232e) client | 0.328 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.328 DEBUG [Client 3ea232698cea7cf2] delay duration 532.729669ms client | 0.328 DEBUG Setting timeout of 532.729669ms client | 0.328 DEBUG stream BiDi creatable client | 0.328 DEBUG resumption token [807]: 00000001409b4056..84f4a0acfaaeb35f client | 0.328 DEBUG [Client 3ea232698cea7cf2] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.328 DEBUG Building Short dcid Some(CID [8]: 49510664717a232e) client | 0.328 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.328 DEBUG [Client 3ea232698cea7cf2] delay duration 532.658085ms client | 0.328 DEBUG Setting timeout of 532.658085ms client | 0.328 DEBUG [Client 3ea232698cea7cf2] State change from Confirmed -> Closing { error: Application(0), timeout: Instant { tv_sec: 380, tv_nsec: 585489825 } } client | 0.328 WARN Unhandled event StateChange(Closing { error: Application(0), timeout: Instant { tv_sec: 380, tv_nsec: 585489825 } }) client | 0.328 DEBUG [Client 3ea232698cea7cf2] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.328 DEBUG Building Short dcid Some(CID [8]: 49510664717a232e) client | 0.328 DEBUG [Recvd-ap] immediate_ack at Instant { tv_sec: 378, tv_nsec: 944590119 } client | 0.328 DEBUG [Client 3ea232698cea7cf2] pn=5 type=Short pri-path:49510664717a232e 0.0.0.0:48671->193.167.100.100:443 IpTos(Cs0, Ect0) len 42 client | TX -> Ack { largest_acknowledged: 5, ack_delay: 60, first_ack_range: 5, ack_ranges: [], ecn_count: None } client | TX -> ConnectionClose { error_code: Application(0), frame_type: 0, reason_phrase: "kthxbye!" } client | 0.328 DEBUG ECN probing: sent 9 probes client | 0.328 DEBUG Setting timeout of 1.640840966s client | 0.367 DEBUG [Client 3ea232698cea7cf2] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.367 DEBUG Building Short dcid Some(CID [8]: 49510664717a232e) client | 0.367 DEBUG [Recvd-ap] immediate_ack at Instant { tv_sec: 378, tv_nsec: 983503441 } client | 0.367 DEBUG [Client 3ea232698cea7cf2] pn=6 type=Short pri-path:49510664717a232e 0.0.0.0:48671->193.167.100.100:443 IpTos(Cs0, Ect0) len 43 client | TX -> Ack { largest_acknowledged: 5, ack_delay: 4924, first_ack_range: 5, ack_ranges: [], ecn_count: None } client | TX -> ConnectionClose { error_code: Application(0), frame_type: 0, reason_phrase: "kthxbye!" } client | 0.367 DEBUG ECN probing: sent 10 probes client | 0.367 DEBUG ECN probing concluded with 10 probes sent client | 0.367 DEBUG Setting timeout of 1.601858044s client | 0.367 DEBUG Setting timeout of 1.601849217s client | 0.375 DEBUG [Client 3ea232698cea7cf2] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.375 DEBUG Building Short dcid Some(CID [8]: 49510664717a232e) client | 0.375 DEBUG [Recvd-ap] immediate_ack at Instant { tv_sec: 378, tv_nsec: 992027363 } client | 0.376 DEBUG [Client 3ea232698cea7cf2] pn=7 type=Short pri-path:49510664717a232e 0.0.0.0:48671->193.167.100.100:443 IpTos(Cs0, NotEct) len 43 client | TX -> Ack { largest_acknowledged: 5, ack_delay: 5989, first_ack_range: 5, ack_ranges: [], ecn_count: None } client | TX -> ConnectionClose { error_code: Application(0), frame_type: 0, reason_phrase: "kthxbye!" } client | 0.376 DEBUG Setting timeout of 1.593382823s client | 0.376 DEBUG Setting timeout of 1.593376902s server | QLog: done with 3ea232698cea7cf2.qlog client | 1.970 DEBUG [Client 3ea232698cea7cf2] State change from Closing { error: Application(0), timeout: Instant { tv_sec: 380, tv_nsec: 585489825 } } -> Closed(Application(0)) client | 1.970 INFO Closing timer expired client | 1.970 DEBUG Output::None client | 1.970 WARN Unhandled event StateChange(Closed(Application(0))) client | 1.970 DEBUG Timer fired while closed client | 1.970 DEBUG Output::None client | 1.971 DEBUG [CryptoStates] Creating initial cipher state v=Version1, role=Client dcid=c65d6e2d106695e4347d576b6c10 client | 1.971 DEBUG Making Write Initial CryptoDxState, v=Version1 cipher=4865 client | 1.971 DEBUG Making Read Initial CryptoDxState, v=Version1 cipher=4865 client | 1.971 DEBUG Outbound interface eth0 for destination 193.167.100.100 has MTU 1500 client | 1.971 DEBUG [unv-path 0.0.0.0:48671->193.167.100.100:443] Make permanent client | 1.971 DEBUG [unv-path:c65d6e2d106695e4347d576b6c10 0.0.0.0:48671->193.167.100.100:443] set as primary path client | 1.971 DEBUG [pri-unv-path:c65d6e2d106695e4347d576b6c10 0.0.0.0:48671->193.167.100.100:443] Path validated Instant { tv_sec: 380, tv_nsec: 587041882 } client | 1.971 INFO [Client c65d6e2d106695e4347d576b6c10] resumption token [807]: 00000001409b4056..84f4a0acfaaeb35f client | 1.971 DEBUG Overwrite initial version Version1 ==> Version1 client | 1.971 DEBUG Overwrite initial version Version1 ==> Version1 client | 1.971 DEBUG [Client c65d6e2d106695e4347d576b6c10] client_start client | 1.971 DEBUG Writing transport parameters, msg=1 client | 1.971 DEBUG Write secret available for ZeroRtt: SymKey [32]: d2cff06ee4f15a70c5921a9bea08212615c1070efb99a665a0682d541649272e client | 1.971 DEBUG [Agent 0x55896ac06ad0] state -> InProgress client | 1.971 DEBUG [Client c65d6e2d106695e4347d576b6c10] State change from Init -> WaitInitial client | 1.971 DEBUG Making Write ZeroRtt CryptoDxState, v=Version1 cipher=4865 client | 1.971 DEBUG [Client c65d6e2d106695e4347d576b6c10] Enabled 0-RTT client | 1.971 DEBUG stream BiDi creatable client | 1.972 INFO Created stream 0 for https://server4/zlnticzqlq client | 1.972 INFO Saving https://server4/zlnticzqlq to "/downloads/zlnticzqlq" client | 1.972 DEBUG StateChange(WaitInitial) client | 1.972 DEBUG stream 0 writable client | 1.972 DEBUG [Client c65d6e2d106695e4347d576b6c10] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 1.972 DEBUG Building Initial dcid Some(CID [14]: c65d6e2d106695e4347d576b6c10) scid Some(CID [0]: ) client | 1.972 DEBUG CRYPTO for in offset=0, len=1207 client | 1.972 DEBUG [Client c65d6e2d106695e4347d576b6c10] pn=0 type=Initial pri-path:c65d6e2d106695e4347d576b6c10 0.0.0.0:48671->193.167.100.100:443 IpTos(Cs0, Ect0) len 1252 client | TX -> Crypto { offset: 0, len: 1207 } client | 1.972 DEBUG packet_sent this=0x55896abd3630, pn=0, ps=1252 client | 1.972 DEBUG ECN probing: sent 1 probes client | 1.972 DEBUG [Client c65d6e2d106695e4347d576b6c10] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 1.972 DEBUG Building Initial dcid Some(CID [14]: c65d6e2d106695e4347d576b6c10) scid Some(CID [0]: ) client | 1.972 DEBUG CRYPTO for in offset=1207, len=399 client | 1.972 DEBUG [Client c65d6e2d106695e4347d576b6c10] pn=1 type=Initial pri-path:c65d6e2d106695e4347d576b6c10 0.0.0.0:48671->193.167.100.100:443 IpTos(Cs0, Ect0) len 445 client | TX -> Crypto { offset: 1207, len: 399 } client | 1.972 DEBUG Building ZeroRtt dcid Some(CID [14]: c65d6e2d106695e4347d576b6c10) scid Some(CID [0]: ) client | 1.972 DEBUG [Client c65d6e2d106695e4347d576b6c10] pn=0 type=ZeroRtt pri-path:c65d6e2d106695e4347d576b6c10 0.0.0.0:48671->193.167.100.100:443 IpTos(Cs0, Ect0) len 505 client | TX -> Stream { stream_id: 0, offset: 0, len: 17, fin: true } client | 1.972 DEBUG packet_sent this=0x55896abd3630, pn=0, ps=60 client | 1.972 DEBUG [Client c65d6e2d106695e4347d576b6c10] pad Initial from 505 to PLPMTU 1252 client | 1.972 DEBUG packet_sent this=0x55896abd3630, pn=1, ps=1192 client | 1.972 DEBUG ECN probing: sent 2 probes client | 1.972 DEBUG [Client c65d6e2d106695e4347d576b6c10] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } client | 1.972 DEBUG Building Initial dcid Some(CID [14]: c65d6e2d106695e4347d576b6c10) scid Some(CID [0]: ) client | 1.972 DEBUG Building ZeroRtt dcid Some(CID [14]: c65d6e2d106695e4347d576b6c10) scid Some(CID [0]: ) client | 1.972 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } client | 1.972 DEBUG [Client c65d6e2d106695e4347d576b6c10] delay duration 6.451732ms client | 1.972 DEBUG Setting timeout of 6.451732ms client | 1.980 DEBUG [Client c65d6e2d106695e4347d576b6c10] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 1.980 DEBUG Building Initial dcid Some(CID [14]: c65d6e2d106695e4347d576b6c10) scid Some(CID [0]: ) client | 1.980 DEBUG Building ZeroRtt dcid Some(CID [14]: c65d6e2d106695e4347d576b6c10) scid Some(CID [0]: ) client | 1.980 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 1.980 DEBUG [Client c65d6e2d106695e4347d576b6c10] delay duration 456.825452ms client | 1.980 DEBUG Setting timeout of 456.825452ms client | 2.011 DEBUG [Client c65d6e2d106695e4347d576b6c10] pn=0 type=Initial pri-path:c65d6e2d106695e4347d576b6c10 0.0.0.0:48671->193.167.100.100:443 IpTos(Cs0, NotEct) len 1201 client | -> RX Ack { largest_acknowledged: 0, ack_delay: 0, first_ack_range: 0, ack_ranges: [], ecn_count: None } client | -> RX Padding { len: 1161 } client | 2.011 DEBUG [Client c65d6e2d106695e4347d576b6c10] Rx ACK space=in, ranges=[0..=0] client | 2.011 DEBUG [LossRecovery] ACK for Initial - largest_acked=0 client | 2.011 DEBUG on_packets_acked this=0x55896abd3630, limited=1, bytes_in_flight=1252, cwnd=12520, state=SlowStart, new_acked=1252 client | 2.011 DEBUG Acked crypto frame space=in offset=0 length=1207 client | 2.011 DEBUG [Client c65d6e2d106695e4347d576b6c10] Changing to use Server CID=c38289b00c69af26 client | 2.011 DEBUG [Client c65d6e2d106695e4347d576b6c10] State change from WaitInitial -> WaitVersion client | 2.011 DEBUG [Client c65d6e2d106695e4347d576b6c10] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 2.011 DEBUG Building Initial dcid Some(CID [8]: c38289b00c69af26) scid Some(CID [0]: ) client | 2.011 DEBUG Building ZeroRtt dcid Some(CID [8]: c38289b00c69af26) scid Some(CID [0]: ) client | 2.011 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 2.011 DEBUG [Client c65d6e2d106695e4347d576b6c10] delay duration 78.015566ms client | 2.011 DEBUG Setting timeout of 78.015566ms client | 2.011 WARN Unhandled event StateChange(WaitVersion) client | 2.011 DEBUG [Client c65d6e2d106695e4347d576b6c10] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 2.011 DEBUG Building Initial dcid Some(CID [8]: c38289b00c69af26) scid Some(CID [0]: ) client | 2.011 DEBUG Building ZeroRtt dcid Some(CID [8]: c38289b00c69af26) scid Some(CID [0]: ) client | 2.011 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 2.011 DEBUG [Client c65d6e2d106695e4347d576b6c10] delay duration 77.980871ms client | 2.011 DEBUG Setting timeout of 77.980871ms client | 2.018 DEBUG [Client c65d6e2d106695e4347d576b6c10] pn=1 type=Initial pri-path:c38289b00c69af26 0.0.0.0:48671->193.167.100.100:443 IpTos(Cs0, NotEct) len 1003 client | -> RX Ack { largest_acknowledged: 1, ack_delay: 0, first_ack_range: 1, ack_ranges: [], ecn_count: None } client | -> RX Crypto { offset: 0, len: 96 } client | -> RX Padding { len: 863 } client | 2.018 DEBUG [Client c65d6e2d106695e4347d576b6c10] Rx ACK space=in, ranges=[0..=1] client | 2.018 DEBUG [LossRecovery] ACK for Initial - largest_acked=1 client | 2.018 DEBUG on_packets_acked this=0x55896abd3630, limited=1, bytes_in_flight=60, cwnd=12520, state=SlowStart, new_acked=1192 client | 2.018 DEBUG Acked crypto frame space=in offset=1207 length=399 client | 2.018 DEBUG Read Ok(96) bytes client | 2.018 DEBUG Write secret available for Handshake: SymKey [32]: bcbff9fb50d0329afd473619be98de9bc6b5843f222a8173e3fcba414ec332e0 client | 2.018 DEBUG Read secret available for Handshake: SymKey [32]: dbd63b8e7210e3512ac386da35aa18cb72eae65f939969c376f2259c3243b4c5 client | 2.018 DEBUG [Agent 0x55896ac06ad0] state -> InProgress client | 2.018 DEBUG Making Write Handshake CryptoDxState, v=Version1 cipher=4865 client | 2.018 DEBUG Making Read Handshake CryptoDxState, v=Version1 cipher=4865 client | 2.018 DEBUG [Crypto] Handshake keys installed client | 2.018 DEBUG [Recvd-in] Set ACK timer to Instant { tv_sec: 380, tv_nsec: 634286450 } client | 2.018 DEBUG [Client c65d6e2d106695e4347d576b6c10] State change from WaitVersion -> Handshaking client | 2.018 DEBUG [Client c65d6e2d106695e4347d576b6c10] pn=0 type=Handshake pri-path:c38289b00c69af26 0.0.0.0:48671->193.167.100.100:443 IpTos(Cs0, NotEct) len 197 client | -> RX Crypto { offset: 0, len: 159 } client | 2.018 DEBUG Read Ok(159) bytes client | 2.018 DEBUG Write secret available for ApplicationData: SymKey [32]: 3ebf0f3b6f38d8ea54a9a63e476e94803a6dc4a7aed4fdc6cd7d1f566fbe1b8d client | 2.018 DEBUG Read secret available for ApplicationData: SymKey [32]: 9e69d0461af2343f61d1d56aa608938b5cc25ee30490d8d3eba8cbdf4b8d8b3b client | 2.019 DEBUG [Agent 0x55896ac06ad0] state -> Complete(SecretAgentInfo { version: 772, cipher: 4865, group: 29, resumed: true, early_data: true, ech_accepted: false, alpn: Some("hq-interop"), signature_scheme: 1027 }) client | 2.019 DEBUG [Client c65d6e2d106695e4347d576b6c10] TLS connection complete client | 2.019 DEBUG Making Write ApplicationData CryptoDxState, v=Version1 cipher=4865 client | 2.019 DEBUG [Crypto] Application write key installed client | 2.019 DEBUG Making Read ApplicationData CryptoDxState, v=Version1 cipher=4865 client | 2.019 DEBUG [Crypto] application read keys installed client | 2.019 DEBUG setting max_stream_data to 1000000 client | 2.019 DEBUG [Client c65d6e2d106695e4347d576b6c10] State change from Handshaking -> Connected client | 2.019 INFO [Client c65d6e2d106695e4347d576b6c10] Connection established client | 2.019 DEBUG setting max_stream_data to 1000000 client | 2.019 DEBUG [Recvd-hs] Set ACK timer to Instant { tv_sec: 380, tv_nsec: 634286450 } client | 2.019 DEBUG [Client c65d6e2d106695e4347d576b6c10] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 2.019 DEBUG Building Initial dcid Some(CID [8]: c38289b00c69af26) scid Some(CID [0]: ) client | 2.019 DEBUG [Client c65d6e2d106695e4347d576b6c10] pn=2 type=Initial pri-path:c38289b00c69af26 0.0.0.0:48671->193.167.100.100:443 IpTos(Cs0, Ect0) len 41 client | TX -> Ack { largest_acknowledged: 1, ack_delay: 117, first_ack_range: 1, ack_ranges: [], ecn_count: None } client | 2.019 DEBUG Building Handshake dcid Some(CID [8]: c38289b00c69af26) scid Some(CID [0]: ) client | 2.019 DEBUG CRYPTO for hs offset=0, len=36 client | 2.019 DEBUG [Client c65d6e2d106695e4347d576b6c10] pn=0 type=Handshake pri-path:c38289b00c69af26 0.0.0.0:48671->193.167.100.100:443 IpTos(Cs0, Ect0) len 120 client | TX -> Ack { largest_acknowledged: 0, ack_delay: 117, first_ack_range: 0, ack_ranges: [], ecn_count: None } client | TX -> Crypto { offset: 0, len: 36 } client | 2.019 DEBUG packet_sent this=0x55896abd3630, pn=0, ps=79 client | 2.019 DEBUG [Client c65d6e2d106695e4347d576b6c10] Drop packet number space in client | 2.019 DEBUG [LossRecovery] Reset loss recovery state for Initial client | 2.019 DEBUG Building Short dcid Some(CID [8]: c38289b00c69af26) client | 2.019 WARN [LossRecovery] ignoring in-2 from dropped space client | 2.019 DEBUG ECN probing: sent 3 probes client | 2.019 DEBUG [Client c65d6e2d106695e4347d576b6c10] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 2.019 DEBUG Building Handshake dcid Some(CID [8]: c38289b00c69af26) scid Some(CID [0]: ) client | 2.019 DEBUG Building Short dcid Some(CID [8]: c38289b00c69af26) client | 2.019 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 2.019 DEBUG [Client c65d6e2d106695e4347d576b6c10] delay duration 105.176237ms client | 2.019 DEBUG Setting timeout of 105.176237ms client | 2.019 DEBUG StateChange(Handshaking) client | 2.019 DEBUG stream BiDi creatable client | 2.019 DEBUG StateChange(Connected) client | 2.019 DEBUG [Client c65d6e2d106695e4347d576b6c10] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 2.019 DEBUG Building Handshake dcid Some(CID [8]: c38289b00c69af26) scid Some(CID [0]: ) client | 2.019 DEBUG Building Short dcid Some(CID [8]: c38289b00c69af26) client | 2.019 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 2.019 DEBUG [Client c65d6e2d106695e4347d576b6c10] delay duration 105.142093ms client | 2.019 DEBUG Setting timeout of 105.142093ms client | 2.125 DEBUG [LossRecovery] PTO timer fired for Handshake client | 2.125 DEBUG [LossRecovery] PTO timer fired for ApplicationData client | 2.125 DEBUG [Client c65d6e2d106695e4347d576b6c10] Lost: Ack(AckToken { space: Handshake, ranges: [PacketRange { largest: 0, smallest: 0, ack_needed: true }] }) client | 2.125 DEBUG [Recvd-hs] immediate_ack at Instant { tv_sec: 380, tv_nsec: 635230105 } client | 2.125 DEBUG [Client c65d6e2d106695e4347d576b6c10] Lost: Crypto(CryptoRecoveryToken { space: Handshake, offset: 0, length: 36 }) client | 2.125 INFO Lost crypto frame space=hs offset=0 length=36 client | 2.125 DEBUG [Client c65d6e2d106695e4347d576b6c10] Lost: Stream(Stream(SendStreamRecoveryToken { id: StreamId(0), offset: 0, length: 17, fin: true })) client | 2.125 DEBUG [Client c65d6e2d106695e4347d576b6c10] output_path send_profile SendProfile { limit: 1252, pto: Some(Handshake), probe: EnumSet(Handshake | ApplicationData), paced: false } client | 2.125 DEBUG Building Handshake dcid Some(CID [8]: c38289b00c69af26) scid Some(CID [0]: ) client | 2.125 DEBUG CRYPTO for hs offset=0, len=36 client | 2.125 DEBUG [Client c65d6e2d106695e4347d576b6c10] pn=1 type=Handshake pri-path:c38289b00c69af26 0.0.0.0:48671->193.167.100.100:443 IpTos(Cs0, Ect0) len 79 client | TX -> Ack { largest_acknowledged: 0, ack_delay: 13424, first_ack_range: 0, ack_ranges: [], ecn_count: None } client | TX -> Crypto { offset: 0, len: 36 } client | 2.125 DEBUG packet_sent this=0x55896abd3630, pn=1, ps=79 client | 2.125 DEBUG Building Short dcid Some(CID [8]: c38289b00c69af26) client | 2.125 DEBUG [Client c65d6e2d106695e4347d576b6c10] pn=1 type=Short pri-path:c38289b00c69af26 0.0.0.0:48671->193.167.100.100:443 IpTos(Cs0, Ect0) len 125 client | TX -> Stream { stream_id: 0, offset: 0, len: 17, fin: true } client | 2.125 DEBUG packet_sent this=0x55896abd3630, pn=1, ps=46 client | 2.125 DEBUG ECN probing: sent 4 probes client | 2.125 DEBUG [Client c65d6e2d106695e4347d576b6c10] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 2.125 DEBUG Building Handshake dcid Some(CID [8]: c38289b00c69af26) scid Some(CID [0]: ) client | 2.125 DEBUG Building Short dcid Some(CID [8]: c38289b00c69af26) client | 2.125 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 2.125 DEBUG [Client c65d6e2d106695e4347d576b6c10] delay duration 210.629362ms client | 2.125 DEBUG Setting timeout of 210.629362ms client | 2.159 DEBUG [Client c65d6e2d106695e4347d576b6c10] pn=0 type=Short pri-path:c38289b00c69af26 0.0.0.0:48671->193.167.100.100:443 IpTos(Cs0, NotEct) len 1252 client | -> RX Ack { largest_acknowledged: 0, ack_delay: 17500, first_ack_range: 0, ack_ranges: [], ecn_count: None } client | -> RX Stream { stream_id: 0, offset: 0, len: 1221, fin: false } client | 2.159 DEBUG [Client c65d6e2d106695e4347d576b6c10] Rx ACK space=ap, ranges=[0..=0] client | 2.159 DEBUG [LossRecovery] ACK for ApplicationData - largest_acked=0 client | 2.159 DEBUG on_packets_acked this=0x55896abd3630, limited=1, bytes_in_flight=204, cwnd=12520, state=SlowStart, new_acked=60 client | 2.159 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 380, tv_nsec: 795788689 } client | 2.159 DEBUG [Client c65d6e2d106695e4347d576b6c10] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 2.159 DEBUG Building Handshake dcid Some(CID [8]: c38289b00c69af26) scid Some(CID [0]: ) client | 2.159 DEBUG Building Short dcid Some(CID [8]: c38289b00c69af26) client | 2.159 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 2.159 DEBUG [Client c65d6e2d106695e4347d576b6c10] delay duration 19.928837ms client | 2.159 DEBUG Setting timeout of 19.928837ms client | 2.159 DEBUG stream 0 complete client | 2.159 DEBUG [Client c65d6e2d106695e4347d576b6c10] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 2.159 DEBUG Building Handshake dcid Some(CID [8]: c38289b00c69af26) scid Some(CID [0]: ) client | 2.159 DEBUG Building Short dcid Some(CID [8]: c38289b00c69af26) client | 2.159 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 2.159 DEBUG [Client c65d6e2d106695e4347d576b6c10] delay duration 19.892429ms client | 2.159 DEBUG Setting timeout of 19.892429ms client | 2.160 DEBUG [Client c65d6e2d106695e4347d576b6c10] pn=1 type=Short pri-path:c38289b00c69af26 0.0.0.0:48671->193.167.100.100:443 IpTos(Cs0, NotEct) len 1252 client | -> RX HandshakeDone client | -> RX Ack { largest_acknowledged: 1, ack_delay: 0, first_ack_range: 1, ack_ranges: [], ecn_count: None } client | -> RX Stream { stream_id: 0, offset: 1221, len: 1222, fin: false } client | 2.160 DEBUG [Client c65d6e2d106695e4347d576b6c10] State change from Connected -> Confirmed client | 2.160 DEBUG PMTUD started with probe size 1380 client | 2.160 DEBUG [Client c65d6e2d106695e4347d576b6c10] Drop packet number space hs client | 2.160 DEBUG [LossRecovery] Reset loss recovery state for Handshake client | 2.160 DEBUG [Client c65d6e2d106695e4347d576b6c10] No preferred address to migrate to client | 2.160 DEBUG [Client c65d6e2d106695e4347d576b6c10] Rx ACK space=ap, ranges=[0..=1] client | 2.160 DEBUG [LossRecovery] ACK for ApplicationData - largest_acked=1 client | 2.160 DEBUG on_packets_acked this=0x55896abd3630, limited=1, bytes_in_flight=0, cwnd=12520, state=SlowStart, new_acked=46 client | 2.160 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 380, tv_nsec: 776780953 } client | 2.160 DEBUG [Client c65d6e2d106695e4347d576b6c10] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 2.160 DEBUG Building Short dcid Some(CID [8]: c38289b00c69af26) client | 2.160 DEBUG Sending PMTUD probe of size 1380, count 1 client | 2.160 DEBUG [Client c65d6e2d106695e4347d576b6c10] pn=2 type=Short pri-path:c38289b00c69af26 0.0.0.0:48671->193.167.100.100:443 IpTos(Cs0, Ect0) len 1352 client | TX -> Ack { largest_acknowledged: 1, ack_delay: 11, first_ack_range: 1, ack_ranges: [], ecn_count: None } client | TX -> Ping client | TX -> Padding { len: 1320 } client | 2.160 DEBUG packet_sent this=0x55896abd3630, pn=2, ps=1352 client | 2.160 DEBUG ECN probing: sent 5 probes client | 2.160 DEBUG [Client c65d6e2d106695e4347d576b6c10] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 2.160 DEBUG Building Short dcid Some(CID [8]: c38289b00c69af26) client | 2.160 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 2.160 DEBUG [Client c65d6e2d106695e4347d576b6c10] delay duration 113.352594ms client | 2.160 DEBUG Setting timeout of 113.352594ms client | 2.160 WARN Unhandled event StateChange(Confirmed) client | 2.160 DEBUG [Client c65d6e2d106695e4347d576b6c10] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 2.160 DEBUG Building Short dcid Some(CID [8]: c38289b00c69af26) client | 2.160 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 2.160 DEBUG [Client c65d6e2d106695e4347d576b6c10] delay duration 113.319542ms client | 2.160 DEBUG Setting timeout of 113.319542ms client | 2.161 DEBUG [Client c65d6e2d106695e4347d576b6c10] pn=2 type=Short pri-path:c38289b00c69af26 0.0.0.0:48671->193.167.100.100:443 IpTos(Cs0, NotEct) len 1252 client | -> RX NewConnectionId { sequence_number: 1, retire_prior: 0, connection_id: [155, 52, 77, 65, 143, 14, 36, 119], stateless_reset_token: [179, 154, 93, 53, 249, 180, 173, 245, 222, 29, 71, 32, 148, 226, 39, 138] } client | -> RX Ack { largest_acknowledged: 1, ack_delay: 0, first_ack_range: 1, ack_ranges: [], ecn_count: None } client | -> RX NewConnectionId { sequence_number: 2, retire_prior: 0, connection_id: [114, 100, 173, 142, 38, 67, 59, 230], stateless_reset_token: [118, 176, 209, 125, 21, 180, 39, 79, 108, 104, 167, 189, 35, 41, 188, 28] } client | -> RX NewConnectionId { sequence_number: 3, retire_prior: 0, connection_id: [27, 108, 33, 2, 82, 33, 108, 252], stateless_reset_token: [135, 92, 148, 218, 32, 156, 156, 219, 190, 218, 206, 183, 70, 95, 146, 0] } client | -> RX NewConnectionId { sequence_number: 4, retire_prior: 0, connection_id: [41, 20, 58, 186, 75, 148, 151, 199], stateless_reset_token: [113, 56, 1, 246, 227, 106, 73, 115, 66, 96, 158, 141, 208, 8, 114, 134] } client | -> RX NewConnectionId { sequence_number: 5, retire_prior: 0, connection_id: [102, 151, 51, 160, 161, 65, 83, 4], stateless_reset_token: [161, 154, 38, 98, 146, 233, 94, 224, 72, 41, 31, 247, 212, 41, 43, 86] } client | -> RX Crypto { offset: 0, len: 42 } client | -> RX Stream { stream_id: 0, offset: 2443, len: 1038, fin: false } client | 2.161 DEBUG [Client c65d6e2d106695e4347d576b6c10] Rx ACK space=ap, ranges=[0..=1] client | 2.161 DEBUG Read Ok(42) bytes client | 2.161 DEBUG [0x55896ac06ad0] Got resumption token [712]: 02000633fcabba8e..f853de471288fdaf client | 2.161 DEBUG [Agent 0x55896ac06ad0] state -> Complete(SecretAgentInfo { version: 772, cipher: 4865, group: 29, resumed: true, early_data: true, ech_accepted: false, alpn: Some("hq-interop"), signature_scheme: 1027 }) client | 2.161 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 380, tv_nsec: 797784580 } client | 2.161 DEBUG [Client c65d6e2d106695e4347d576b6c10] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 2.161 DEBUG Building Short dcid Some(CID [8]: c38289b00c69af26) client | 2.161 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 2.161 DEBUG [Client c65d6e2d106695e4347d576b6c10] delay duration 19.85046ms client | 2.161 DEBUG Setting timeout of 19.85046ms client | 2.161 DEBUG stream BiDi creatable client | 2.161 DEBUG [Client c65d6e2d106695e4347d576b6c10] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 2.161 DEBUG Building Short dcid Some(CID [8]: c38289b00c69af26) client | 2.161 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 2.161 DEBUG [Client c65d6e2d106695e4347d576b6c10] delay duration 19.826866ms client | 2.161 DEBUG Setting timeout of 19.826866ms client | 2.162 DEBUG [Client c65d6e2d106695e4347d576b6c10] pn=3 type=Short pri-path:c38289b00c69af26 0.0.0.0:48671->193.167.100.100:443 IpTos(Cs0, NotEct) len 1252 client | -> RX Stream { stream_id: 0, offset: 3481, len: 1223, fin: false } client | -> RX Ack { largest_acknowledged: 1, ack_delay: 0, first_ack_range: 1, ack_ranges: [], ecn_count: None } client | 2.162 DEBUG [Client c65d6e2d106695e4347d576b6c10] Rx ACK space=ap, ranges=[0..=1] client | 2.162 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 380, tv_nsec: 778841286 } client | 2.162 DEBUG [Client c65d6e2d106695e4347d576b6c10] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 2.162 DEBUG Building Short dcid Some(CID [8]: c38289b00c69af26) client | 2.162 DEBUG [Client c65d6e2d106695e4347d576b6c10] pn=3 type=Short pri-path:c38289b00c69af26 0.0.0.0:48671->193.167.100.100:443 IpTos(Cs0, Ect0) len 31 client | TX -> Ack { largest_acknowledged: 3, ack_delay: 3, first_ack_range: 3, ack_ranges: [], ecn_count: None } client | 2.162 DEBUG ECN probing: sent 6 probes client | 2.162 DEBUG [Client c65d6e2d106695e4347d576b6c10] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 2.162 DEBUG Building Short dcid Some(CID [8]: c38289b00c69af26) client | 2.162 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 2.162 DEBUG [Client c65d6e2d106695e4347d576b6c10] delay duration 111.381757ms client | 2.162 DEBUG Setting timeout of 111.381757ms client | 2.162 DEBUG [Client c65d6e2d106695e4347d576b6c10] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 2.162 DEBUG Building Short dcid Some(CID [8]: c38289b00c69af26) client | 2.162 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 2.162 DEBUG [Client c65d6e2d106695e4347d576b6c10] delay duration 111.355839ms client | 2.162 DEBUG Setting timeout of 111.355839ms client | 2.163 DEBUG [Client c65d6e2d106695e4347d576b6c10] pn=4 type=Short pri-path:c38289b00c69af26 0.0.0.0:48671->193.167.100.100:443 IpTos(Cs0, NotEct) len 1252 client | -> RX Stream { stream_id: 0, offset: 4704, len: 1223, fin: false } client | -> RX Ack { largest_acknowledged: 1, ack_delay: 0, first_ack_range: 1, ack_ranges: [], ecn_count: None } client | 2.163 DEBUG [Client c65d6e2d106695e4347d576b6c10] Rx ACK space=ap, ranges=[0..=1] client | 2.163 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 380, tv_nsec: 799868848 } client | 2.163 DEBUG [Client c65d6e2d106695e4347d576b6c10] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 2.163 DEBUG Building Short dcid Some(CID [8]: c38289b00c69af26) client | 2.163 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 2.163 DEBUG [Client c65d6e2d106695e4347d576b6c10] delay duration 19.933315ms client | 2.163 DEBUG Setting timeout of 19.933315ms client | 2.163 DEBUG [Client c65d6e2d106695e4347d576b6c10] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 2.163 DEBUG Building Short dcid Some(CID [8]: c38289b00c69af26) client | 2.163 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 2.163 DEBUG [Client c65d6e2d106695e4347d576b6c10] delay duration 19.910683ms client | 2.163 DEBUG Setting timeout of 19.910683ms client | 2.164 DEBUG [Client c65d6e2d106695e4347d576b6c10] pn=5 type=Short pri-path:c38289b00c69af26 0.0.0.0:48671->193.167.100.100:443 IpTos(Cs0, NotEct) len 1252 client | -> RX Stream { stream_id: 0, offset: 5927, len: 1223, fin: false } client | -> RX Ack { largest_acknowledged: 1, ack_delay: 0, first_ack_range: 1, ack_ranges: [], ecn_count: None } client | 2.164 DEBUG [Client c65d6e2d106695e4347d576b6c10] Rx ACK space=ap, ranges=[0..=1] client | 2.164 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 380, tv_nsec: 780887443 } client | 2.164 DEBUG [Client c65d6e2d106695e4347d576b6c10] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 2.164 DEBUG Building Short dcid Some(CID [8]: c38289b00c69af26) client | 2.164 DEBUG [Client c65d6e2d106695e4347d576b6c10] pn=4 type=Short pri-path:c38289b00c69af26 0.0.0.0:48671->193.167.100.100:443 IpTos(Cs0, Ect0) len 31 client | TX -> Ack { largest_acknowledged: 5, ack_delay: 3, first_ack_range: 5, ack_ranges: [], ecn_count: None } client | 2.164 DEBUG ECN probing: sent 7 probes client | 2.164 DEBUG [Client c65d6e2d106695e4347d576b6c10] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 2.164 DEBUG Building Short dcid Some(CID [8]: c38289b00c69af26) client | 2.164 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 2.164 DEBUG [Client c65d6e2d106695e4347d576b6c10] delay duration 109.33541ms client | 2.164 DEBUG Setting timeout of 109.33541ms client | 2.164 DEBUG [Client c65d6e2d106695e4347d576b6c10] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 2.164 DEBUG Building Short dcid Some(CID [8]: c38289b00c69af26) client | 2.164 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 2.164 DEBUG [Client c65d6e2d106695e4347d576b6c10] delay duration 109.287771ms client | 2.164 DEBUG Setting timeout of 109.287771ms client | 2.165 DEBUG [Client c65d6e2d106695e4347d576b6c10] pn=6 type=Short pri-path:c38289b00c69af26 0.0.0.0:48671->193.167.100.100:443 IpTos(Cs0, NotEct) len 1252 client | -> RX Stream { stream_id: 0, offset: 7150, len: 1223, fin: false } client | -> RX Ack { largest_acknowledged: 1, ack_delay: 0, first_ack_range: 1, ack_ranges: [], ecn_count: None } client | 2.165 DEBUG [Client c65d6e2d106695e4347d576b6c10] Rx ACK space=ap, ranges=[0..=1] client | 2.165 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 380, tv_nsec: 801915606 } client | 2.165 DEBUG [Client c65d6e2d106695e4347d576b6c10] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 2.165 DEBUG Building Short dcid Some(CID [8]: c38289b00c69af26) client | 2.165 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 2.165 DEBUG [Client c65d6e2d106695e4347d576b6c10] delay duration 19.972609ms client | 2.165 DEBUG Setting timeout of 19.972609ms client | 2.165 DEBUG [Client c65d6e2d106695e4347d576b6c10] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 2.165 DEBUG Building Short dcid Some(CID [8]: c38289b00c69af26) client | 2.165 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 2.165 DEBUG [Client c65d6e2d106695e4347d576b6c10] delay duration 19.958302ms client | 2.165 DEBUG Setting timeout of 19.958302ms client | 2.166 DEBUG [Client c65d6e2d106695e4347d576b6c10] pn=7 type=Short pri-path:c38289b00c69af26 0.0.0.0:48671->193.167.100.100:443 IpTos(Cs0, NotEct) len 1252 client | -> RX Stream { stream_id: 0, offset: 8373, len: 1223, fin: false } client | -> RX Ack { largest_acknowledged: 1, ack_delay: 0, first_ack_range: 1, ack_ranges: [], ecn_count: None } client | 2.166 DEBUG [Client c65d6e2d106695e4347d576b6c10] Rx ACK space=ap, ranges=[0..=1] client | 2.166 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 380, tv_nsec: 782940874 } client | 2.166 DEBUG [Client c65d6e2d106695e4347d576b6c10] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 2.166 DEBUG Building Short dcid Some(CID [8]: c38289b00c69af26) client | 2.166 DEBUG [Client c65d6e2d106695e4347d576b6c10] pn=5 type=Short pri-path:c38289b00c69af26 0.0.0.0:48671->193.167.100.100:443 IpTos(Cs0, Ect0) len 31 client | TX -> Ack { largest_acknowledged: 7, ack_delay: 3, first_ack_range: 7, ack_ranges: [], ecn_count: None } client | 2.166 DEBUG ECN probing: sent 8 probes client | 2.166 DEBUG [Client c65d6e2d106695e4347d576b6c10] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 2.166 DEBUG Building Short dcid Some(CID [8]: c38289b00c69af26) client | 2.167 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 2.167 DEBUG [Client c65d6e2d106695e4347d576b6c10] delay duration 107.27159ms client | 2.167 DEBUG Setting timeout of 107.27159ms client | 2.167 DEBUG [Client c65d6e2d106695e4347d576b6c10] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 2.167 DEBUG Building Short dcid Some(CID [8]: c38289b00c69af26) client | 2.167 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 2.167 DEBUG [Client c65d6e2d106695e4347d576b6c10] delay duration 107.24447ms client | 2.167 DEBUG Setting timeout of 107.24447ms client | 2.167 DEBUG [Client c65d6e2d106695e4347d576b6c10] pn=8 type=Short pri-path:c38289b00c69af26 0.0.0.0:48671->193.167.100.100:443 IpTos(Cs0, NotEct) len 676 client | -> RX Stream { stream_id: 0, offset: 9596, len: 644, fin: true } client | -> RX Ack { largest_acknowledged: 1, ack_delay: 0, first_ack_range: 1, ack_ranges: [], ecn_count: None } client | -> RX MaxStreams { stream_type: BiDi, maximum_streams: 101 } client | 2.167 DEBUG [Client c65d6e2d106695e4347d576b6c10] Rx ACK space=ap, ranges=[0..=1] client | 2.167 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 380, tv_nsec: 803508708 } client | 2.167 DEBUG [Client c65d6e2d106695e4347d576b6c10] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 2.167 DEBUG Building Short dcid Some(CID [8]: c38289b00c69af26) client | 2.167 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 2.167 DEBUG [Client c65d6e2d106695e4347d576b6c10] delay duration 19.969854ms client | 2.167 DEBUG Setting timeout of 19.969854ms client | 2.167 DEBUG stream BiDi creatable client | 2.167 DEBUG resumption token [812]: 0000000128405c00..f853de471288fdaf client | 2.167 DEBUG [Client c65d6e2d106695e4347d576b6c10] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 2.167 DEBUG Building Short dcid Some(CID [8]: c38289b00c69af26) client | 2.167 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 2.167 DEBUG [Client c65d6e2d106695e4347d576b6c10] delay duration 19.901817ms client | 2.167 DEBUG Setting timeout of 19.901817ms client | 2.167 DEBUG [Client c65d6e2d106695e4347d576b6c10] State change from Confirmed -> Closing { error: Application(0), timeout: Instant { tv_sec: 381, tv_nsec: 123921371 } } client | 2.167 WARN Unhandled event StateChange(Closing { error: Application(0), timeout: Instant { tv_sec: 381, tv_nsec: 123921371 } }) client | 2.167 DEBUG [Client c65d6e2d106695e4347d576b6c10] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 2.167 DEBUG Building Short dcid Some(CID [8]: c38289b00c69af26) client | 2.167 DEBUG [Recvd-ap] immediate_ack at Instant { tv_sec: 380, tv_nsec: 783631727 } client | 2.167 DEBUG [Client c65d6e2d106695e4347d576b6c10] pn=6 type=Short pri-path:c38289b00c69af26 0.0.0.0:48671->193.167.100.100:443 IpTos(Cs0, Ect0) len 42 client | TX -> Ack { largest_acknowledged: 8, ack_delay: 15, first_ack_range: 8, ack_ranges: [], ecn_count: None } client | TX -> ConnectionClose { error_code: Application(0), frame_type: 0, reason_phrase: "kthxbye!" } client | 2.167 DEBUG ECN probing: sent 9 probes client | 2.167 DEBUG Setting timeout of 340.229211ms client | 2.199 DEBUG [Client c65d6e2d106695e4347d576b6c10] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 2.199 DEBUG Building Short dcid Some(CID [8]: c38289b00c69af26) client | 2.199 DEBUG [Recvd-ap] immediate_ack at Instant { tv_sec: 380, tv_nsec: 815451717 } client | 2.199 DEBUG [Client c65d6e2d106695e4347d576b6c10] pn=7 type=Short pri-path:c38289b00c69af26 0.0.0.0:48671->193.167.100.100:443 IpTos(Cs0, Ect0) len 43 client | TX -> Ack { largest_acknowledged: 8, ack_delay: 3992, first_ack_range: 8, ack_ranges: [], ecn_count: None } client | TX -> ConnectionClose { error_code: Application(0), frame_type: 0, reason_phrase: "kthxbye!" } client | 2.199 DEBUG ECN probing: sent 10 probes client | 2.199 DEBUG ECN probing concluded with 10 probes sent client | 2.199 DEBUG Setting timeout of 308.339428ms client | 2.199 DEBUG Setting timeout of 308.325663ms client | 2.509 DEBUG [Client c65d6e2d106695e4347d576b6c10] State change from Closing { error: Application(0), timeout: Instant { tv_sec: 381, tv_nsec: 123921371 } } -> Closed(Application(0)) client | 2.509 INFO Closing timer expired client | 2.509 DEBUG Output::None client | 2.509 WARN Unhandled event StateChange(Closed(Application(0))) client | 2.509 DEBUG Timer fired while closed client | 2.509 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 10:49:36,941 Using the client's key log file. 2025-04-30 10:49:36,951 2025-04-30 10:49:36,951 Using the client's key log file. 2025-04-30 10:49:36,951 Using the client's key log file. 2025-04-30 10:49:36,959 2025-04-30 10:49:36,960 Using the client's key log file. 2025-04-30 10:49:36,960 Using the client's key log file. 2025-04-30 10:49:37,819 Check of downloaded files succeeded.