[2025-09-12T11:50:54.769250178Z TRACE mio::poll] registering event source with poller: token=Token(0), interests=READABLE [2025-09-12T11:50:54.769568648Z INFO quiche_apps::client] connecting to [fd00:cafe:cafe:100::100]:443 from [::]:40940 with scid 6d823fccec3bbdb25adfa335a323f4958c2aab2b [2025-09-12T11:50:54.769612600Z TRACE quiche::tls] 6d823fccec3bbdb25adfa335a323f4958c2aab2b write message lvl=Initial len=266 [2025-09-12T11:50:54.769628830Z TRACE quiche] 6d823fccec3bbdb25adfa335a323f4958c2aab2b tx pkt Initial version=1 dcid=b8c5a9bdb8a3897778386480d0d41d7b scid=6d823fccec3bbdb25adfa335a323f4958c2aab2b len=270 pn=0 [2025-09-12T11:50:54.769632156Z TRACE quiche] 6d823fccec3bbdb25adfa335a323f4958c2aab2b tx frm CRYPTO off=0 len=266 [2025-09-12T11:50:54.769649468Z TRACE quiche::recovery::congestion::recovery] 6d823fccec3bbdb25adfa335a323f4958c2aab2b timer=998.929299ms latest_rtt=0ns srtt=333ms min_rtt=333ms rttvar=166.5ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=333 app_limited=true congestion_recovery_start_time=None Rate { delivered: 0, delivered_time: Instant { tv_sec: 895, tv_nsec: 865045104 }, first_sent_time: Instant { tv_sec: 895, tv_nsec: 865045104 }, end_of_app_limited: 1, last_sent_packet: 0, largest_acked: 0, rate_sample: RateSample { bandwidth: 0.00 Kbps, is_app_limited: false, interval: 0ns, delivered: 0, prior_delivered: 0, prior_time: None, send_elapsed: 0ns, ack_elapsed: 0ns, rtt: 0ns } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 0, last_update: Instant { tv_sec: 895, tv_nsec: 865045104 }, next_time: Instant { tv_sec: 895, tv_nsec: 865045104 }, max_datagram_size: 1350, last_packet_size: None, iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } [2025-09-12T11:50:54.769696215Z TRACE quiche_apps::client] written 1200 [2025-09-12T11:50:54.809613170Z TRACE quiche_apps::client] got 1200 bytes from [fd00:cafe:cafe:100::100]:443 to [::]:40940 [2025-09-12T11:50:54.809640480Z TRACE quiche] 6d823fccec3bbdb25adfa335a323f4958c2aab2b rx pkt Initial version=1 dcid=6d823fccec3bbdb25adfa335a323f4958c2aab2b scid=3916f5df6d26917f token= len=116 pn=0 [2025-09-12T11:50:54.809654807Z TRACE quiche] 6d823fccec3bbdb25adfa335a323f4958c2aab2b rx frm ACK delay=46 blocks=[0..0] ecn_counts=None [2025-09-12T11:50:54.809661870Z TRACE quiche::recovery::congestion::recovery] 6d823fccec3bbdb25adfa335a323f4958c2aab2b packet newly acked 0 [2025-09-12T11:50:54.809668693Z TRACE quiche] 6d823fccec3bbdb25adfa335a323f4958c2aab2b rx frm CRYPTO off=0 len=90 [2025-09-12T11:50:54.809782834Z TRACE quiche::tls] 6d823fccec3bbdb25adfa335a323f4958c2aab2b set write secret lvl=Handshake [2025-09-12T11:50:54.809794236Z TRACE quiche::tls] 6d823fccec3bbdb25adfa335a323f4958c2aab2b set read secret lvl=Handshake [2025-09-12T11:50:54.809833969Z TRACE quiche] 6d823fccec3bbdb25adfa335a323f4958c2aab2b rx pkt Handshake version=1 dcid=6d823fccec3bbdb25adfa335a323f4958c2aab2b scid=3916f5df6d26917f len=1009 pn=0 [2025-09-12T11:50:54.809840762Z TRACE quiche] 6d823fccec3bbdb25adfa335a323f4958c2aab2b rx frm CRYPTO off=0 len=732 [2025-09-12T11:50:54.810066861Z TRACE quiche::tls] 6d823fccec3bbdb25adfa335a323f4958c2aab2b write message lvl=Handshake len=36 [2025-09-12T11:50:54.810071920Z TRACE quiche::tls] 6d823fccec3bbdb25adfa335a323f4958c2aab2b set write secret lvl=OneRTT [2025-09-12T11:50:54.810080436Z TRACE quiche::tls] 6d823fccec3bbdb25adfa335a323f4958c2aab2b set read secret lvl=OneRTT [2025-09-12T11:50:54.810099481Z TRACE quiche] 6d823fccec3bbdb25adfa335a323f4958c2aab2b connection established: proto=Ok("hq-interop") cipher=Some(AES128_GCM) curve=Some("X25519") sigalg=Some("ecdsa_secp256r1_sha256") resumed=false TransportParams { original_destination_connection_id: Some(b8c5a9bdb8a3897778386480d0d41d7b), max_idle_timeout: 30000, stateless_reset_token: Some(186271429104501134100203415783873686640), max_udp_payload_size: 1472, initial_max_data: 4611686018427387903, initial_max_stream_data_bidi_local: 1250000, initial_max_stream_data_bidi_remote: 1250000, initial_max_stream_data_uni: 1250000, initial_max_streams_bidi: 100, initial_max_streams_uni: 100, ack_delay_exponent: 3, max_ack_delay: 25, disable_active_migration: false, active_conn_id_limit: 5, initial_source_connection_id: Some(3916f5df6d26917f), retry_source_connection_id: None, max_datagram_frame_size: Some(65535), unknown_params: None } [2025-09-12T11:50:54.810121472Z TRACE quiche] 6d823fccec3bbdb25adfa335a323f4958c2aab2b rx frm PADDING len=256 [2025-09-12T11:50:54.810137832Z TRACE quiche_apps::client] [::]:40940: processed 1200 bytes [2025-09-12T11:50:54.810144585Z TRACE quiche_apps::client] got 234 bytes from [fd00:cafe:cafe:100::100]:443 to [::]:40940 [2025-09-12T11:50:54.810149404Z TRACE quiche] 6d823fccec3bbdb25adfa335a323f4958c2aab2b rx pkt Short dcid=6d823fccec3bbdb25adfa335a323f4958c2aab2b key_phase=false len=213 pn=0 [2025-09-12T11:50:54.810156307Z TRACE quiche] 6d823fccec3bbdb25adfa335a323f4958c2aab2b rx frm NEW_CONNECTION_ID seq_num=1 retire_prior_to=0 conn_id=[c7, be, d3, 09, 44, 82, 15, 7b] reset_token=[b9, 63, 7c, aa, 5e, 28, a3, 89, e3, 6f, 6f, 30, db, 1b, 66, 8c] [2025-09-12T11:50:54.810164351Z TRACE quiche] 6d823fccec3bbdb25adfa335a323f4958c2aab2b rx frm NEW_CONNECTION_ID seq_num=2 retire_prior_to=0 conn_id=[5c, 8e, 15, 7d, ae, e5, f1, bf] reset_token=[c4, 12, ed, 66, 48, cc, 74, fc, 7c, d2, 0b, 01, ac, ce, 30, 38] [2025-09-12T11:50:54.810170012Z TRACE quiche] 6d823fccec3bbdb25adfa335a323f4958c2aab2b rx frm NEW_CONNECTION_ID seq_num=3 retire_prior_to=0 conn_id=[aa, 25, 90, 1a, f8, 5c, 2e, 48] reset_token=[3e, f1, 6b, fd, 01, 6c, 4c, 38, f7, a7, 35, 2a, 42, 5d, aa, fd] [2025-09-12T11:50:54.810175352Z TRACE quiche] 6d823fccec3bbdb25adfa335a323f4958c2aab2b rx frm NEW_CONNECTION_ID seq_num=4 retire_prior_to=0 conn_id=[56, 24, 48, 12, 22, a9, 7b, 89] reset_token=[74, e3, 3a, 4d, 4f, 17, 1f, d1, 92, 43, 90, 4c, da, 96, cd, 64] [2025-09-12T11:50:54.810181233Z TRACE quiche] 6d823fccec3bbdb25adfa335a323f4958c2aab2b rx frm NEW_CONNECTION_ID seq_num=5 retire_prior_to=0 conn_id=[b9, 67, 77, de, c4, d2, 3f, 91] reset_token=[60, 61, dc, ae, 40, 01, 7a, 4a, ca, ad, 6a, 26, 65, 45, 2c, c0] [2025-09-12T11:50:54.810186563Z TRACE quiche] 6d823fccec3bbdb25adfa335a323f4958c2aab2b rx frm NEW_CONNECTION_ID seq_num=6 retire_prior_to=0 conn_id=[56, d7, 40, b6, 7f, 4c, 85, f4] reset_token=[9f, 8d, 72, 22, eb, 97, 35, f1, f7, cd, 41, 2d, 69, 5d, c1, aa] [2025-09-12T11:50:54.810191853Z TRACE quiche] 6d823fccec3bbdb25adfa335a323f4958c2aab2b rx frm NEW_CONNECTION_ID seq_num=7 retire_prior_to=0 conn_id=[ca, 94, 3e, 08, a8, e4, a2, 90] reset_token=[a1, 82, 89, e3, 2a, b8, 28, 68, 94, 60, 66, 45, c2, 52, bc, 5e] [2025-09-12T11:50:54.810201721Z TRACE quiche_apps::client] [::]:40940: processed 234 bytes [2025-09-12T11:50:54.810206089Z TRACE quiche_apps::client] [::]:40940: recv() would block [2025-09-12T11:50:54.810209094Z TRACE quiche_apps::client] done reading [2025-09-12T11:50:54.810218302Z DEBUG quiche_apps::common] sending HTTP request "GET /crhykohymj\r\n" [2025-09-12T11:50:54.810278683Z DEBUG quiche_apps::common] sending HTTP request "GET /hqerkbqbgm\r\n" [2025-09-12T11:50:54.810324398Z TRACE quiche] 6d823fccec3bbdb25adfa335a323f4958c2aab2b tx pkt Initial version=1 dcid=3916f5df6d26917f scid=6d823fccec3bbdb25adfa335a323f4958c2aab2b len=6 pn=1 [2025-09-12T11:50:54.810328816Z TRACE quiche] 6d823fccec3bbdb25adfa335a323f4958c2aab2b tx frm ACK delay=85 blocks=[0..0] ecn_counts=None [2025-09-12T11:50:54.810339396Z TRACE quiche::recovery::congestion::recovery] 6d823fccec3bbdb25adfa335a323f4958c2aab2b timer=119.458682ms latest_rtt=40.05478ms srtt=40.05478ms min_rtt=40.05478ms rttvar=20.02739ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=0 app_limited=true congestion_recovery_start_time=None Rate { delivered: 333, delivered_time: Instant { tv_sec: 895, tv_nsec: 905563413 }, first_sent_time: Instant { tv_sec: 895, tv_nsec: 905563413 }, end_of_app_limited: 1, last_sent_packet: 1, largest_acked: 0, rate_sample: RateSample { bandwidth: 66.50 Kbps, is_app_limited: true, interval: 40.05478ms, delivered: 333, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 895, tv_nsec: 865045104 }), send_elapsed: 0ns, ack_elapsed: 40.05478ms, rtt: 40.05478ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 421298, last_update: Instant { tv_sec: 895, tv_nsec: 905563373 }, next_time: Instant { tv_sec: 895, tv_nsec: 905563413 }, max_datagram_size: 1350, last_packet_size: Some(0), iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } [2025-09-12T11:50:54.810364833Z TRACE quiche] 6d823fccec3bbdb25adfa335a323f4958c2aab2b tx pkt Handshake version=1 dcid=3916f5df6d26917f scid=6d823fccec3bbdb25adfa335a323f4958c2aab2b len=46 pn=2 [2025-09-12T11:50:54.810367788Z TRACE quiche] 6d823fccec3bbdb25adfa335a323f4958c2aab2b tx frm ACK delay=66 blocks=[0..0] ecn_counts=None [2025-09-12T11:50:54.810370393Z TRACE quiche] 6d823fccec3bbdb25adfa335a323f4958c2aab2b tx frm CRYPTO off=0 len=36 [2025-09-12T11:50:54.810376395Z TRACE quiche::recovery::congestion::recovery] 6d823fccec3bbdb25adfa335a323f4958c2aab2b timer=120.101945ms latest_rtt=40.05478ms srtt=40.05478ms min_rtt=40.05478ms rttvar=20.02739ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=100 app_limited=true congestion_recovery_start_time=None Rate { delivered: 333, delivered_time: Instant { tv_sec: 895, tv_nsec: 905563413 }, first_sent_time: Instant { tv_sec: 895, tv_nsec: 905563413 }, end_of_app_limited: 1, last_sent_packet: 2, largest_acked: 0, rate_sample: RateSample { bandwidth: 66.50 Kbps, is_app_limited: true, interval: 40.05478ms, delivered: 333, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 895, tv_nsec: 865045104 }), send_elapsed: 0ns, ack_elapsed: 40.05478ms, rtt: 40.05478ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 421298, last_update: Instant { tv_sec: 895, tv_nsec: 905779935 }, next_time: Instant { tv_sec: 895, tv_nsec: 905563413 }, max_datagram_size: 1350, last_packet_size: None, iv: 237.362µs, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } [2025-09-12T11:50:54.810387555Z TRACE quiche] 6d823fccec3bbdb25adfa335a323f4958c2aab2b dropped epoch 0 state [2025-09-12T11:50:54.810400689Z TRACE quiche] 6d823fccec3bbdb25adfa335a323f4958c2aab2b tx pkt Short dcid=3916f5df6d26917f key_phase=false len=1163 pn=3 [2025-09-12T11:50:54.810403555Z TRACE quiche] 6d823fccec3bbdb25adfa335a323f4958c2aab2b tx frm ACK delay=30 blocks=[0..0] ecn_counts=None [2025-09-12T11:50:54.810406059Z TRACE quiche] 6d823fccec3bbdb25adfa335a323f4958c2aab2b tx frm NEW_CONNECTION_ID seq_num=1 retire_prior_to=0 conn_id=[d4, 77, 95, a4, 37, 89, cd, a7, d8, 64, c8, 4b, f6, 43, a9, 58, 66, b5, f0, 8b] reset_token=[6a, aa, 9e, ad, 2a, ae, 10, 4f, ee, ae, 95, fe, cb, 0b, 4b, 96] [2025-09-12T11:50:54.810411760Z TRACE quiche] 6d823fccec3bbdb25adfa335a323f4958c2aab2b tx frm NEW_CONNECTION_ID seq_num=2 retire_prior_to=0 conn_id=[a9, d3, ab, b8, ea, da, 5e, 40, cb, 99, 21, f0, ad, 45, e6, f0, 3e, 6e, 45, 4f] reset_token=[7d, 6f, 67, 83, 4d, 22, bd, ce, 0f, b9, 48, 77, 98, 75, b9, d8] [2025-09-12T11:50:54.810417060Z TRACE quiche] 6d823fccec3bbdb25adfa335a323f4958c2aab2b tx frm NEW_CONNECTION_ID seq_num=3 retire_prior_to=0 conn_id=[58, 75, a3, 66, d3, 94, 32, 39, 24, cb, ff, a4, 70, 1b, 90, 2c, 79, c1, de, 13] reset_token=[12, 20, 71, 50, 9e, 62, 7b, 63, a3, 8b, c1, 85, 02, b1, 22, f2] [2025-09-12T11:50:54.810422169Z TRACE quiche] 6d823fccec3bbdb25adfa335a323f4958c2aab2b tx frm NEW_CONNECTION_ID seq_num=4 retire_prior_to=0 conn_id=[65, 7e, b4, 07, 0e, 10, 21, 01, c6, 07, 09, d4, 16, 3e, 60, 0b, 14, 74, 0f, b7] reset_token=[e4, 0a, 2b, a2, 2c, e9, 22, 3a, 80, 41, 97, 2a, d9, 0a, 39, 80] [2025-09-12T11:50:54.810431046Z TRACE quiche] 6d823fccec3bbdb25adfa335a323f4958c2aab2b tx frm STREAM id=0 off=0 len=17 fin=true [2025-09-12T11:50:54.810433691Z TRACE quiche] 6d823fccec3bbdb25adfa335a323f4958c2aab2b tx frm PADDING len=976 [2025-09-12T11:50:54.810441495Z TRACE quiche::recovery::congestion::recovery] 6d823fccec3bbdb25adfa335a323f4958c2aab2b timer=120.036854ms latest_rtt=40.05478ms srtt=40.05478ms min_rtt=40.05478ms rttvar=20.02739ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=1289 app_limited=true congestion_recovery_start_time=None Rate { delivered: 333, delivered_time: Instant { tv_sec: 895, tv_nsec: 905563413 }, first_sent_time: Instant { tv_sec: 895, tv_nsec: 905563413 }, end_of_app_limited: 2, last_sent_packet: 3, largest_acked: 0, rate_sample: RateSample { bandwidth: 66.50 Kbps, is_app_limited: true, interval: 40.05478ms, delivered: 333, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 895, tv_nsec: 865045104 }), send_elapsed: 0ns, ack_elapsed: 40.05478ms, rtt: 40.05478ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 1189, rate: 421298, last_update: Instant { tv_sec: 895, tv_nsec: 905779935 }, next_time: Instant { tv_sec: 895, tv_nsec: 906017297 }, max_datagram_size: 1350, last_packet_size: Some(1189), iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } [2025-09-12T11:50:54.810477001Z TRACE quiche_apps::client] written 1350 bytes from [::]:40940 to [fd00:cafe:cafe:100::100]:443 [2025-09-12T11:50:54.810484034Z TRACE quiche] 6d823fccec3bbdb25adfa335a323f4958c2aab2b tx pkt Short dcid=3916f5df6d26917f key_phase=false len=22 pn=4 [2025-09-12T11:50:54.810486528Z TRACE quiche] 6d823fccec3bbdb25adfa335a323f4958c2aab2b tx frm STREAM id=4 off=0 len=17 fin=true [2025-09-12T11:50:54.810491668Z TRACE quiche::recovery::congestion::recovery] 6d823fccec3bbdb25adfa335a323f4958c2aab2b timer=119.986711ms latest_rtt=40.05478ms srtt=40.05478ms min_rtt=40.05478ms rttvar=20.02739ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=1337 app_limited=true congestion_recovery_start_time=None Rate { delivered: 333, delivered_time: Instant { tv_sec: 895, tv_nsec: 905563413 }, first_sent_time: Instant { tv_sec: 895, tv_nsec: 905563413 }, end_of_app_limited: 3, last_sent_packet: 4, largest_acked: 0, rate_sample: RateSample { bandwidth: 66.50 Kbps, is_app_limited: true, interval: 40.05478ms, delivered: 333, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 895, tv_nsec: 865045104 }), send_elapsed: 0ns, ack_elapsed: 40.05478ms, rtt: 40.05478ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 421298, last_update: Instant { tv_sec: 895, tv_nsec: 905946613 }, next_time: Instant { tv_sec: 895, tv_nsec: 906017297 }, max_datagram_size: 1350, last_packet_size: None, iv: 2.936164ms, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } [2025-09-12T11:50:54.810513449Z TRACE quiche_apps::client] written 48 bytes from [::]:40940 to [fd00:cafe:cafe:100::100]:443 [2025-09-12T11:50:54.810517276Z TRACE quiche_apps::client] [::]:40940 -> [fd00:cafe:cafe:100::100]:443: done writing [2025-09-12T11:50:54.842462119Z TRACE quiche_apps::client] got 406 bytes from [fd00:cafe:cafe:100::100]:443 to [::]:40940 [2025-09-12T11:50:54.842492565Z TRACE quiche] 6d823fccec3bbdb25adfa335a323f4958c2aab2b rx pkt Short dcid=d47795a43789cda7d864c84bf643a95866b5f08b key_phase=false len=385 pn=1 [2025-09-12T11:50:54.842503726Z TRACE quiche] 6d823fccec3bbdb25adfa335a323f4958c2aab2b path ID 0 now see SCID with seq num 1 [2025-09-12T11:50:54.842522901Z TRACE quiche] 6d823fccec3bbdb25adfa335a323f4958c2aab2b rx frm HANDSHAKE_DONE [2025-09-12T11:50:54.842531467Z TRACE quiche] 6d823fccec3bbdb25adfa335a323f4958c2aab2b dropped epoch 1 state [2025-09-12T11:50:54.842555853Z TRACE quiche] 6d823fccec3bbdb25adfa335a323f4958c2aab2b rx frm ACK delay=17 blocks=[3..4] ecn_counts=None [2025-09-12T11:50:54.842563286Z TRACE quiche::recovery::congestion::recovery] 6d823fccec3bbdb25adfa335a323f4958c2aab2b packet newly acked 3 [2025-09-12T11:50:54.842567524Z TRACE quiche::recovery::congestion::recovery] 6d823fccec3bbdb25adfa335a323f4958c2aab2b packet newly acked 4 [2025-09-12T11:50:54.842574487Z TRACE quiche] 6d823fccec3bbdb25adfa335a323f4958c2aab2b rx frm CRYPTO off=0 len=356 [2025-09-12T11:50:54.842615934Z TRACE quiche] 6d823fccec3bbdb25adfa335a323f4958c2aab2b rx frm RETIRE_CONNECTION_ID seq_num=0 [2025-09-12T11:50:54.842664795Z TRACE quiche_apps::client] [::]:40940: processed 406 bytes [2025-09-12T11:50:54.842670335Z TRACE quiche_apps::client] [::]:40940: recv() would block [2025-09-12T11:50:54.842673411Z TRACE quiche_apps::client] done reading [2025-09-12T11:50:54.842677418Z INFO quiche_apps::client] Retiring source CID 6d823fccec3bbdb25adfa335a323f4958c2aab2b [2025-09-12T11:50:54.842696133Z TRACE quiche] 6d823fccec3bbdb25adfa335a323f4958c2aab2b tx pkt Short dcid=3916f5df6d26917f key_phase=false len=45 pn=5 [2025-09-12T11:50:54.842700270Z TRACE quiche] 6d823fccec3bbdb25adfa335a323f4958c2aab2b tx frm ACK delay=25 blocks=[1..1] ecn_counts=None [2025-09-12T11:50:54.842703987Z TRACE quiche] 6d823fccec3bbdb25adfa335a323f4958c2aab2b tx frm NEW_CONNECTION_ID seq_num=5 retire_prior_to=1 conn_id=[cb, aa, 5e, a9, 17, ab, 59, bb, 38, 6e, 64, 06, c3, f2, 9f, 2b, 47, 88, 8c, e8] reset_token=[9b, fe, 64, 2b, b0, b9, 82, 37, 26, 3f, 37, 49, a5, ba, 33, 24] [2025-09-12T11:50:54.842719977Z TRACE quiche::recovery::congestion::recovery] 6d823fccec3bbdb25adfa335a323f4958c2aab2b timer=132.207433ms latest_rtt=31.935694ms srtt=39.039893ms min_rtt=31.935694ms rttvar=17.050313ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=71 app_limited=true congestion_recovery_start_time=None Rate { delivered: 1570, delivered_time: Instant { tv_sec: 895, tv_nsec: 941088695 }, first_sent_time: Instant { tv_sec: 895, tv_nsec: 941088695 }, end_of_app_limited: 4, last_sent_packet: 5, largest_acked: 4, rate_sample: RateSample { bandwidth: 305.53 Kbps, is_app_limited: true, interval: 32.389578ms, delivered: 1237, prior_delivered: 333, prior_time: Some(Instant { tv_sec: 895, tv_nsec: 905563413 }), send_elapsed: 453.884µs, ack_elapsed: 32.389578ms, rtt: 31.935694ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 71, rate: 432250, last_update: Instant { tv_sec: 895, tv_nsec: 938152531 }, next_time: Instant { tv_sec: 895, tv_nsec: 941088695 }, max_datagram_size: 1350, last_packet_size: Some(71), iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } [2025-09-12T11:50:54.842775440Z TRACE quiche_apps::client] written 71 bytes from [::]:40940 to [fd00:cafe:cafe:100::100]:443 [2025-09-12T11:50:54.842781441Z TRACE quiche_apps::client] [::]:40940 -> [fd00:cafe:cafe:100::100]:443: done writing [2025-09-12T11:50:54.843522875Z TRACE quiche_apps::client] got 1350 bytes from [fd00:cafe:cafe:100::100]:443 to [::]:40940 [2025-09-12T11:50:54.843527824Z TRACE quiche] 6d823fccec3bbdb25adfa335a323f4958c2aab2b rx pkt Short dcid=d47795a43789cda7d864c84bf643a95866b5f08b key_phase=false len=1329 pn=2 [2025-09-12T11:50:54.843534196Z TRACE quiche] 6d823fccec3bbdb25adfa335a323f4958c2aab2b rx frm STREAM id=4 off=0 len=1310 fin=false [2025-09-12T11:50:54.843559793Z TRACE quiche_apps::client] [::]:40940: processed 1350 bytes [2025-09-12T11:50:54.843563440Z TRACE quiche_apps::client] [::]:40940: recv() would block [2025-09-12T11:50:54.843565724Z TRACE quiche_apps::client] done reading [2025-09-12T11:50:54.843575422Z TRACE quiche_apps::common] received 1310 bytes [2025-09-12T11:50:54.843577997Z TRACE quiche_apps::common] stream 4 has 1310 bytes (fin? false) [2025-09-12T11:50:54.843585321Z TRACE quiche] 6d823fccec3bbdb25adfa335a323f4958c2aab2b tx pkt Short dcid=3916f5df6d26917f key_phase=false len=5 pn=6 [2025-09-12T11:50:54.843587946Z TRACE quiche] 6d823fccec3bbdb25adfa335a323f4958c2aab2b tx frm ACK delay=7 blocks=[1..2] ecn_counts=None [2025-09-12T11:50:54.843594438Z TRACE quiche::recovery::congestion::recovery] 6d823fccec3bbdb25adfa335a323f4958c2aab2b timer=131.333193ms latest_rtt=31.935694ms srtt=39.039893ms min_rtt=31.935694ms rttvar=17.050313ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=71 app_limited=true congestion_recovery_start_time=None Rate { delivered: 1570, delivered_time: Instant { tv_sec: 895, tv_nsec: 941088695 }, first_sent_time: Instant { tv_sec: 895, tv_nsec: 941088695 }, end_of_app_limited: 4, last_sent_packet: 6, largest_acked: 4, rate_sample: RateSample { bandwidth: 305.53 Kbps, is_app_limited: true, interval: 32.389578ms, delivered: 1237, prior_delivered: 333, prior_time: Some(Instant { tv_sec: 895, tv_nsec: 905563413 }), send_elapsed: 453.884µs, ack_elapsed: 32.389578ms, rtt: 31.935694ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 432250, last_update: Instant { tv_sec: 895, tv_nsec: 939047409 }, next_time: Instant { tv_sec: 895, tv_nsec: 941088695 }, max_datagram_size: 1350, last_packet_size: None, iv: 164.257µs, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } [2025-09-12T11:50:54.843621728Z TRACE quiche_apps::client] written 31 bytes from [::]:40940 to [fd00:cafe:cafe:100::100]:443 [2025-09-12T11:50:54.843625936Z TRACE quiche_apps::client] [::]:40940 -> [fd00:cafe:cafe:100::100]:443: done writing [2025-09-12T11:50:54.844667076Z TRACE quiche_apps::client] got 1350 bytes from [fd00:cafe:cafe:100::100]:443 to [::]:40940 [2025-09-12T11:50:54.844679569Z TRACE quiche] 6d823fccec3bbdb25adfa335a323f4958c2aab2b rx pkt Short dcid=d47795a43789cda7d864c84bf643a95866b5f08b key_phase=false len=1329 pn=3 [2025-09-12T11:50:54.844686832Z TRACE quiche] 6d823fccec3bbdb25adfa335a323f4958c2aab2b rx frm STREAM id=4 off=1310 len=1308 fin=false [2025-09-12T11:50:54.844694096Z TRACE quiche_apps::client] [::]:40940: processed 1350 bytes [2025-09-12T11:50:54.844697612Z TRACE quiche_apps::client] [::]:40940: recv() would block [2025-09-12T11:50:54.844699827Z TRACE quiche_apps::client] done reading [2025-09-12T11:50:54.844703984Z TRACE quiche_apps::common] received 1308 bytes [2025-09-12T11:50:54.844706379Z TRACE quiche_apps::common] stream 4 has 1308 bytes (fin? false) [2025-09-12T11:50:54.844714023Z TRACE quiche] 6d823fccec3bbdb25adfa335a323f4958c2aab2b tx pkt Short dcid=3916f5df6d26917f key_phase=false len=5 pn=7 [2025-09-12T11:50:54.844716607Z TRACE quiche] 6d823fccec3bbdb25adfa335a323f4958c2aab2b tx frm ACK delay=4 blocks=[1..3] ecn_counts=None [2025-09-12T11:50:54.844723190Z TRACE quiche::recovery::congestion::recovery] 6d823fccec3bbdb25adfa335a323f4958c2aab2b timer=130.20445ms latest_rtt=31.935694ms srtt=39.039893ms min_rtt=31.935694ms rttvar=17.050313ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=71 app_limited=true congestion_recovery_start_time=None Rate { delivered: 1570, delivered_time: Instant { tv_sec: 895, tv_nsec: 941088695 }, first_sent_time: Instant { tv_sec: 895, tv_nsec: 941088695 }, end_of_app_limited: 4, last_sent_packet: 7, largest_acked: 4, rate_sample: RateSample { bandwidth: 305.53 Kbps, is_app_limited: true, interval: 32.389578ms, delivered: 1237, prior_delivered: 333, prior_time: Some(Instant { tv_sec: 895, tv_nsec: 905563413 }), send_elapsed: 453.884µs, ack_elapsed: 32.389578ms, rtt: 31.935694ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 432250, last_update: Instant { tv_sec: 895, tv_nsec: 939047409 }, next_time: Instant { tv_sec: 895, tv_nsec: 941252952 }, max_datagram_size: 1350, last_packet_size: Some(0), iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } [2025-09-12T11:50:54.844763444Z TRACE quiche_apps::client] written 31 bytes from [::]:40940 to [fd00:cafe:cafe:100::100]:443 [2025-09-12T11:50:54.844769245Z TRACE quiche_apps::client] [::]:40940 -> [fd00:cafe:cafe:100::100]:443: done writing [2025-09-12T11:50:54.845755393Z TRACE quiche_apps::client] got 1350 bytes from [fd00:cafe:cafe:100::100]:443 to [::]:40940 [2025-09-12T11:50:54.845762386Z TRACE quiche] 6d823fccec3bbdb25adfa335a323f4958c2aab2b rx pkt Short dcid=d47795a43789cda7d864c84bf643a95866b5f08b key_phase=false len=1329 pn=4 [2025-09-12T11:50:54.845768066Z TRACE quiche] 6d823fccec3bbdb25adfa335a323f4958c2aab2b rx frm STREAM id=4 off=2618 len=1308 fin=false [2025-09-12T11:50:54.845774248Z TRACE quiche_apps::client] [::]:40940: processed 1350 bytes [2025-09-12T11:50:54.845777534Z TRACE quiche_apps::client] [::]:40940: recv() would block [2025-09-12T11:50:54.845779758Z TRACE quiche_apps::client] done reading [2025-09-12T11:50:54.845783415Z TRACE quiche_apps::common] received 1308 bytes [2025-09-12T11:50:54.845785669Z TRACE quiche_apps::common] stream 4 has 1308 bytes (fin? false) [2025-09-12T11:50:54.845792031Z TRACE quiche] 6d823fccec3bbdb25adfa335a323f4958c2aab2b tx pkt Short dcid=3916f5df6d26917f key_phase=false len=5 pn=8 [2025-09-12T11:50:54.845794576Z TRACE quiche] 6d823fccec3bbdb25adfa335a323f4958c2aab2b tx frm ACK delay=3 blocks=[1..4] ecn_counts=None [2025-09-12T11:50:54.845800306Z TRACE quiche::recovery::congestion::recovery] 6d823fccec3bbdb25adfa335a323f4958c2aab2b timer=129.127344ms latest_rtt=31.935694ms srtt=39.039893ms min_rtt=31.935694ms rttvar=17.050313ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=71 app_limited=true congestion_recovery_start_time=None Rate { delivered: 1570, delivered_time: Instant { tv_sec: 895, tv_nsec: 941088695 }, first_sent_time: Instant { tv_sec: 895, tv_nsec: 941088695 }, end_of_app_limited: 4, last_sent_packet: 8, largest_acked: 4, rate_sample: RateSample { bandwidth: 305.53 Kbps, is_app_limited: true, interval: 32.389578ms, delivered: 1237, prior_delivered: 333, prior_time: Some(Instant { tv_sec: 895, tv_nsec: 905563413 }), send_elapsed: 453.884µs, ack_elapsed: 32.389578ms, rtt: 31.935694ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 432250, last_update: Instant { tv_sec: 895, tv_nsec: 939047409 }, next_time: Instant { tv_sec: 895, tv_nsec: 941252952 }, max_datagram_size: 1350, last_packet_size: Some(0), iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } [2025-09-12T11:50:54.845825863Z TRACE quiche_apps::client] written 31 bytes from [::]:40940 to [fd00:cafe:cafe:100::100]:443 [2025-09-12T11:50:54.845829590Z TRACE quiche_apps::client] [::]:40940 -> [fd00:cafe:cafe:100::100]:443: done writing [2025-09-12T11:50:54.846872253Z TRACE quiche_apps::client] got 1350 bytes from [fd00:cafe:cafe:100::100]:443 to [::]:40940 [2025-09-12T11:50:54.846878845Z TRACE quiche] 6d823fccec3bbdb25adfa335a323f4958c2aab2b rx pkt Short dcid=d47795a43789cda7d864c84bf643a95866b5f08b key_phase=false len=1329 pn=5 [2025-09-12T11:50:54.846884325Z TRACE quiche] 6d823fccec3bbdb25adfa335a323f4958c2aab2b rx frm STREAM id=4 off=3926 len=1308 fin=false [2025-09-12T11:50:54.846890176Z TRACE quiche_apps::client] [::]:40940: processed 1350 bytes [2025-09-12T11:50:54.846893422Z TRACE quiche_apps::client] [::]:40940: recv() would block [2025-09-12T11:50:54.846895616Z TRACE quiche_apps::client] done reading [2025-09-12T11:50:54.846911255Z TRACE quiche_apps::common] received 1308 bytes [2025-09-12T11:50:54.846913590Z TRACE quiche_apps::common] stream 4 has 1308 bytes (fin? false) [2025-09-12T11:50:54.846920102Z TRACE quiche] 6d823fccec3bbdb25adfa335a323f4958c2aab2b tx pkt Short dcid=3916f5df6d26917f key_phase=false len=5 pn=9 [2025-09-12T11:50:54.846922727Z TRACE quiche] 6d823fccec3bbdb25adfa335a323f4958c2aab2b tx frm ACK delay=5 blocks=[1..5] ecn_counts=None [2025-09-12T11:50:54.846928948Z TRACE quiche::recovery::congestion::recovery] 6d823fccec3bbdb25adfa335a323f4958c2aab2b timer=127.998702ms latest_rtt=31.935694ms srtt=39.039893ms min_rtt=31.935694ms rttvar=17.050313ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=71 app_limited=true congestion_recovery_start_time=None Rate { delivered: 1570, delivered_time: Instant { tv_sec: 895, tv_nsec: 941088695 }, first_sent_time: Instant { tv_sec: 895, tv_nsec: 941088695 }, end_of_app_limited: 4, last_sent_packet: 9, largest_acked: 4, rate_sample: RateSample { bandwidth: 305.53 Kbps, is_app_limited: true, interval: 32.389578ms, delivered: 1237, prior_delivered: 333, prior_time: Some(Instant { tv_sec: 895, tv_nsec: 905563413 }), send_elapsed: 453.884µs, ack_elapsed: 32.389578ms, rtt: 31.935694ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 432250, last_update: Instant { tv_sec: 895, tv_nsec: 939047409 }, next_time: Instant { tv_sec: 895, tv_nsec: 941252952 }, max_datagram_size: 1350, last_packet_size: Some(0), iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } [2025-09-12T11:50:54.846954025Z TRACE quiche_apps::client] written 31 bytes from [::]:40940 to [fd00:cafe:cafe:100::100]:443 [2025-09-12T11:50:54.846957872Z TRACE quiche_apps::client] [::]:40940 -> [fd00:cafe:cafe:100::100]:443: done writing [2025-09-12T11:50:54.847985206Z TRACE quiche_apps::client] got 1350 bytes from [fd00:cafe:cafe:100::100]:443 to [::]:40940 [2025-09-12T11:50:54.847992169Z TRACE quiche] 6d823fccec3bbdb25adfa335a323f4958c2aab2b rx pkt Short dcid=d47795a43789cda7d864c84bf643a95866b5f08b key_phase=false len=1329 pn=6 [2025-09-12T11:50:54.847997709Z TRACE quiche] 6d823fccec3bbdb25adfa335a323f4958c2aab2b rx frm STREAM id=4 off=5234 len=1308 fin=false [2025-09-12T11:50:54.848003650Z TRACE quiche_apps::client] [::]:40940: processed 1350 bytes [2025-09-12T11:50:54.848006906Z TRACE quiche_apps::client] [::]:40940: recv() would block [2025-09-12T11:50:54.848009120Z TRACE quiche_apps::client] done reading [2025-09-12T11:50:54.848012717Z TRACE quiche_apps::common] received 1308 bytes [2025-09-12T11:50:54.848014961Z TRACE quiche_apps::common] stream 4 has 1308 bytes (fin? false) [2025-09-12T11:50:54.848021283Z TRACE quiche] 6d823fccec3bbdb25adfa335a323f4958c2aab2b tx pkt Short dcid=3916f5df6d26917f key_phase=false len=5 pn=10 [2025-09-12T11:50:54.848023817Z TRACE quiche] 6d823fccec3bbdb25adfa335a323f4958c2aab2b tx frm ACK delay=3 blocks=[1..6] ecn_counts=None [2025-09-12T11:50:54.848029358Z TRACE quiche::recovery::congestion::recovery] 6d823fccec3bbdb25adfa335a323f4958c2aab2b timer=126.898293ms latest_rtt=31.935694ms srtt=39.039893ms min_rtt=31.935694ms rttvar=17.050313ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=71 app_limited=true congestion_recovery_start_time=None Rate { delivered: 1570, delivered_time: Instant { tv_sec: 895, tv_nsec: 941088695 }, first_sent_time: Instant { tv_sec: 895, tv_nsec: 941088695 }, end_of_app_limited: 4, last_sent_packet: 10, largest_acked: 4, rate_sample: RateSample { bandwidth: 305.53 Kbps, is_app_limited: true, interval: 32.389578ms, delivered: 1237, prior_delivered: 333, prior_time: Some(Instant { tv_sec: 895, tv_nsec: 905563413 }), send_elapsed: 453.884µs, ack_elapsed: 32.389578ms, rtt: 31.935694ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 432250, last_update: Instant { tv_sec: 895, tv_nsec: 939047409 }, next_time: Instant { tv_sec: 895, tv_nsec: 941252952 }, max_datagram_size: 1350, last_packet_size: Some(0), iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } [2025-09-12T11:50:54.848059123Z TRACE quiche_apps::client] written 31 bytes from [::]:40940 to [fd00:cafe:cafe:100::100]:443 [2025-09-12T11:50:54.848063180Z TRACE quiche_apps::client] [::]:40940 -> [fd00:cafe:cafe:100::100]:443: done writing [2025-09-12T11:50:54.849172156Z TRACE quiche_apps::client] got 1350 bytes from [fd00:cafe:cafe:100::100]:443 to [::]:40940 [2025-09-12T11:50:54.849178988Z TRACE quiche] 6d823fccec3bbdb25adfa335a323f4958c2aab2b rx pkt Short dcid=d47795a43789cda7d864c84bf643a95866b5f08b key_phase=false len=1329 pn=7 [2025-09-12T11:50:54.849184468Z TRACE quiche] 6d823fccec3bbdb25adfa335a323f4958c2aab2b rx frm STREAM id=4 off=6542 len=1308 fin=false [2025-09-12T11:50:54.849190520Z TRACE quiche_apps::client] [::]:40940: processed 1350 bytes [2025-09-12T11:50:54.849193776Z TRACE quiche_apps::client] [::]:40940: recv() would block [2025-09-12T11:50:54.849195950Z TRACE quiche_apps::client] done reading [2025-09-12T11:50:54.849199616Z TRACE quiche_apps::common] received 1308 bytes [2025-09-12T11:50:54.849201821Z TRACE quiche_apps::common] stream 4 has 1308 bytes (fin? false) [2025-09-12T11:50:54.849207862Z TRACE quiche] 6d823fccec3bbdb25adfa335a323f4958c2aab2b tx pkt Short dcid=3916f5df6d26917f key_phase=false len=5 pn=11 [2025-09-12T11:50:54.849210407Z TRACE quiche] 6d823fccec3bbdb25adfa335a323f4958c2aab2b tx frm ACK delay=3 blocks=[1..7] ecn_counts=None [2025-09-12T11:50:54.849215977Z TRACE quiche::recovery::congestion::recovery] 6d823fccec3bbdb25adfa335a323f4958c2aab2b timer=125.711683ms latest_rtt=31.935694ms srtt=39.039893ms min_rtt=31.935694ms rttvar=17.050313ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=71 app_limited=true congestion_recovery_start_time=None Rate { delivered: 1570, delivered_time: Instant { tv_sec: 895, tv_nsec: 941088695 }, first_sent_time: Instant { tv_sec: 895, tv_nsec: 941088695 }, end_of_app_limited: 4, last_sent_packet: 11, largest_acked: 4, rate_sample: RateSample { bandwidth: 305.53 Kbps, is_app_limited: true, interval: 32.389578ms, delivered: 1237, prior_delivered: 333, prior_time: Some(Instant { tv_sec: 895, tv_nsec: 905563413 }), send_elapsed: 453.884µs, ack_elapsed: 32.389578ms, rtt: 31.935694ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 432250, last_update: Instant { tv_sec: 895, tv_nsec: 939047409 }, next_time: Instant { tv_sec: 895, tv_nsec: 941252952 }, max_datagram_size: 1350, last_packet_size: Some(0), iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } [2025-09-12T11:50:54.849240532Z TRACE quiche_apps::client] written 31 bytes from [::]:40940 to [fd00:cafe:cafe:100::100]:443 [2025-09-12T11:50:54.849244279Z TRACE quiche_apps::client] [::]:40940 -> [fd00:cafe:cafe:100::100]:443: done writing [2025-09-12T11:50:54.849420085Z TRACE quiche_apps::client] got 386 bytes from [fd00:cafe:cafe:100::100]:443 to [::]:40940 [2025-09-12T11:50:54.849424463Z TRACE quiche] 6d823fccec3bbdb25adfa335a323f4958c2aab2b rx pkt Short dcid=d47795a43789cda7d864c84bf643a95866b5f08b key_phase=false len=365 pn=8 [2025-09-12T11:50:54.849429152Z TRACE quiche] 6d823fccec3bbdb25adfa335a323f4958c2aab2b rx frm STREAM id=4 off=7850 len=342 fin=false [2025-09-12T11:50:54.849434783Z TRACE quiche_apps::client] [::]:40940: processed 386 bytes [2025-09-12T11:50:54.849437978Z TRACE quiche_apps::client] [::]:40940: recv() would block [2025-09-12T11:50:54.849440173Z TRACE quiche_apps::client] done reading [2025-09-12T11:50:54.849448538Z TRACE quiche_apps::common] received 342 bytes [2025-09-12T11:50:54.849450802Z TRACE quiche_apps::common] stream 4 has 342 bytes (fin? false) [2025-09-12T11:50:54.849457294Z TRACE quiche] 6d823fccec3bbdb25adfa335a323f4958c2aab2b tx pkt Short dcid=3916f5df6d26917f key_phase=false len=5 pn=12 [2025-09-12T11:50:54.849459849Z TRACE quiche] 6d823fccec3bbdb25adfa335a323f4958c2aab2b tx frm ACK delay=4 blocks=[1..8] ecn_counts=None [2025-09-12T11:50:54.849465399Z TRACE quiche::recovery::congestion::recovery] 6d823fccec3bbdb25adfa335a323f4958c2aab2b timer=125.462261ms latest_rtt=31.935694ms srtt=39.039893ms min_rtt=31.935694ms rttvar=17.050313ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=71 app_limited=true congestion_recovery_start_time=None Rate { delivered: 1570, delivered_time: Instant { tv_sec: 895, tv_nsec: 941088695 }, first_sent_time: Instant { tv_sec: 895, tv_nsec: 941088695 }, end_of_app_limited: 4, last_sent_packet: 12, largest_acked: 4, rate_sample: RateSample { bandwidth: 305.53 Kbps, is_app_limited: true, interval: 32.389578ms, delivered: 1237, prior_delivered: 333, prior_time: Some(Instant { tv_sec: 895, tv_nsec: 905563413 }), send_elapsed: 453.884µs, ack_elapsed: 32.389578ms, rtt: 31.935694ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 432250, last_update: Instant { tv_sec: 895, tv_nsec: 939047409 }, next_time: Instant { tv_sec: 895, tv_nsec: 941252952 }, max_datagram_size: 1350, last_packet_size: Some(0), iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } [2025-09-12T11:50:54.849489644Z TRACE quiche_apps::client] written 31 bytes from [::]:40940 to [fd00:cafe:cafe:100::100]:443 [2025-09-12T11:50:54.849493491Z TRACE quiche_apps::client] [::]:40940 -> [fd00:cafe:cafe:100::100]:443: done writing [2025-09-12T11:50:54.850588501Z TRACE quiche_apps::client] got 1350 bytes from [fd00:cafe:cafe:100::100]:443 to [::]:40940 [2025-09-12T11:50:54.850595334Z TRACE quiche] 6d823fccec3bbdb25adfa335a323f4958c2aab2b rx pkt Short dcid=d47795a43789cda7d864c84bf643a95866b5f08b key_phase=false len=1329 pn=9 [2025-09-12T11:50:54.850600744Z TRACE quiche] 6d823fccec3bbdb25adfa335a323f4958c2aab2b rx frm STREAM id=0 off=0 len=1310 fin=false [2025-09-12T11:50:54.850606815Z TRACE quiche_apps::client] [::]:40940: processed 1350 bytes [2025-09-12T11:50:54.850610081Z TRACE quiche_apps::client] [::]:40940: recv() would block [2025-09-12T11:50:54.850612265Z TRACE quiche_apps::client] done reading [2025-09-12T11:50:54.850616002Z TRACE quiche_apps::common] received 1310 bytes [2025-09-12T11:50:54.850618186Z TRACE quiche_apps::common] stream 0 has 1310 bytes (fin? false) [2025-09-12T11:50:54.850624207Z TRACE quiche] 6d823fccec3bbdb25adfa335a323f4958c2aab2b tx pkt Short dcid=3916f5df6d26917f key_phase=false len=5 pn=13 [2025-09-12T11:50:54.850626702Z TRACE quiche] 6d823fccec3bbdb25adfa335a323f4958c2aab2b tx frm ACK delay=3 blocks=[1..9] ecn_counts=None [2025-09-12T11:50:54.850632683Z TRACE quiche::recovery::congestion::recovery] 6d823fccec3bbdb25adfa335a323f4958c2aab2b timer=124.295017ms latest_rtt=31.935694ms srtt=39.039893ms min_rtt=31.935694ms rttvar=17.050313ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=71 app_limited=true congestion_recovery_start_time=None Rate { delivered: 1570, delivered_time: Instant { tv_sec: 895, tv_nsec: 941088695 }, first_sent_time: Instant { tv_sec: 895, tv_nsec: 941088695 }, end_of_app_limited: 4, last_sent_packet: 13, largest_acked: 4, rate_sample: RateSample { bandwidth: 305.53 Kbps, is_app_limited: true, interval: 32.389578ms, delivered: 1237, prior_delivered: 333, prior_time: Some(Instant { tv_sec: 895, tv_nsec: 905563413 }), send_elapsed: 453.884µs, ack_elapsed: 32.389578ms, rtt: 31.935694ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 432250, last_update: Instant { tv_sec: 895, tv_nsec: 939047409 }, next_time: Instant { tv_sec: 895, tv_nsec: 941252952 }, max_datagram_size: 1350, last_packet_size: Some(0), iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } [2025-09-12T11:50:54.850662548Z TRACE quiche_apps::client] written 31 bytes from [::]:40940 to [fd00:cafe:cafe:100::100]:443 [2025-09-12T11:50:54.850666936Z TRACE quiche_apps::client] [::]:40940 -> [fd00:cafe:cafe:100::100]:443: done writing [2025-09-12T11:50:54.851692868Z TRACE quiche_apps::client] got 1350 bytes from [fd00:cafe:cafe:100::100]:443 to [::]:40940 [2025-09-12T11:50:54.851699550Z TRACE quiche] 6d823fccec3bbdb25adfa335a323f4958c2aab2b rx pkt Short dcid=d47795a43789cda7d864c84bf643a95866b5f08b key_phase=false len=1329 pn=10 [2025-09-12T11:50:54.851704950Z TRACE quiche] 6d823fccec3bbdb25adfa335a323f4958c2aab2b rx frm STREAM id=0 off=1310 len=1308 fin=false [2025-09-12T11:50:54.851711071Z TRACE quiche_apps::client] [::]:40940: processed 1350 bytes [2025-09-12T11:50:54.851714428Z TRACE quiche_apps::client] [::]:40940: recv() would block [2025-09-12T11:50:54.851716612Z TRACE quiche_apps::client] done reading [2025-09-12T11:50:54.851720268Z TRACE quiche_apps::common] received 1308 bytes [2025-09-12T11:50:54.851722493Z TRACE quiche_apps::common] stream 0 has 1308 bytes (fin? false) [2025-09-12T11:50:54.851728614Z TRACE quiche] 6d823fccec3bbdb25adfa335a323f4958c2aab2b tx pkt Short dcid=3916f5df6d26917f key_phase=false len=5 pn=14 [2025-09-12T11:50:54.851731088Z TRACE quiche] 6d823fccec3bbdb25adfa335a323f4958c2aab2b tx frm ACK delay=3 blocks=[1..10] ecn_counts=None [2025-09-12T11:50:54.851736719Z TRACE quiche::recovery::congestion::recovery] 6d823fccec3bbdb25adfa335a323f4958c2aab2b timer=123.190951ms latest_rtt=31.935694ms srtt=39.039893ms min_rtt=31.935694ms rttvar=17.050313ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=71 app_limited=true congestion_recovery_start_time=None Rate { delivered: 1570, delivered_time: Instant { tv_sec: 895, tv_nsec: 941088695 }, first_sent_time: Instant { tv_sec: 895, tv_nsec: 941088695 }, end_of_app_limited: 4, last_sent_packet: 14, largest_acked: 4, rate_sample: RateSample { bandwidth: 305.53 Kbps, is_app_limited: true, interval: 32.389578ms, delivered: 1237, prior_delivered: 333, prior_time: Some(Instant { tv_sec: 895, tv_nsec: 905563413 }), send_elapsed: 453.884µs, ack_elapsed: 32.389578ms, rtt: 31.935694ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 432250, last_update: Instant { tv_sec: 895, tv_nsec: 939047409 }, next_time: Instant { tv_sec: 895, tv_nsec: 941252952 }, max_datagram_size: 1350, last_packet_size: Some(0), iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } [2025-09-12T11:50:54.851760874Z TRACE quiche_apps::client] written 31 bytes from [::]:40940 to [fd00:cafe:cafe:100::100]:443 [2025-09-12T11:50:54.851764661Z TRACE quiche_apps::client] [::]:40940 -> [fd00:cafe:cafe:100::100]:443: done writing [2025-09-12T11:50:54.875124227Z TRACE quiche_apps::client] got 1350 bytes from [fd00:cafe:cafe:100::100]:443 to [::]:40940 [2025-09-12T11:50:54.875155004Z TRACE quiche] 6d823fccec3bbdb25adfa335a323f4958c2aab2b rx pkt Short dcid=d47795a43789cda7d864c84bf643a95866b5f08b key_phase=false len=1329 pn=11 [2025-09-12T11:50:54.875170503Z TRACE quiche] 6d823fccec3bbdb25adfa335a323f4958c2aab2b rx frm STREAM id=0 off=2618 len=1308 fin=false [2025-09-12T11:50:54.875187584Z TRACE quiche_apps::client] [::]:40940: processed 1350 bytes [2025-09-12T11:50:54.875192203Z TRACE quiche_apps::client] [::]:40940: recv() would block [2025-09-12T11:50:54.875195118Z TRACE quiche_apps::client] done reading [2025-09-12T11:50:54.875214725Z TRACE quiche_apps::common] received 1308 bytes [2025-09-12T11:50:54.875218151Z TRACE quiche_apps::common] stream 0 has 1308 bytes (fin? false) [2025-09-12T11:50:54.875232478Z TRACE quiche] 6d823fccec3bbdb25adfa335a323f4958c2aab2b tx pkt Short dcid=3916f5df6d26917f key_phase=false len=5 pn=15 [2025-09-12T11:50:54.875236004Z TRACE quiche] 6d823fccec3bbdb25adfa335a323f4958c2aab2b tx frm ACK delay=9 blocks=[1..11] ecn_counts=None [2025-09-12T11:50:54.875247916Z TRACE quiche::recovery::congestion::recovery] 6d823fccec3bbdb25adfa335a323f4958c2aab2b timer=99.679423ms latest_rtt=31.935694ms srtt=39.039893ms min_rtt=31.935694ms rttvar=17.050313ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=71 app_limited=true congestion_recovery_start_time=None Rate { delivered: 1570, delivered_time: Instant { tv_sec: 895, tv_nsec: 941088695 }, first_sent_time: Instant { tv_sec: 895, tv_nsec: 941088695 }, end_of_app_limited: 4, last_sent_packet: 15, largest_acked: 4, rate_sample: RateSample { bandwidth: 305.53 Kbps, is_app_limited: true, interval: 32.389578ms, delivered: 1237, prior_delivered: 333, prior_time: Some(Instant { tv_sec: 895, tv_nsec: 905563413 }), send_elapsed: 453.884µs, ack_elapsed: 32.389578ms, rtt: 31.935694ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 432250, last_update: Instant { tv_sec: 895, tv_nsec: 970689126 }, next_time: Instant { tv_sec: 895, tv_nsec: 970689126 }, max_datagram_size: 1350, last_packet_size: Some(0), iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } [2025-09-12T11:50:54.875296136Z TRACE quiche_apps::client] written 31 bytes from [::]:40940 to [fd00:cafe:cafe:100::100]:443 [2025-09-12T11:50:54.875301546Z TRACE quiche_apps::client] [::]:40940 -> [fd00:cafe:cafe:100::100]:443: done writing [2025-09-12T11:50:54.876227715Z TRACE quiche_apps::client] got 1350 bytes from [fd00:cafe:cafe:100::100]:443 to [::]:40940 [2025-09-12T11:50:54.876237643Z TRACE quiche] 6d823fccec3bbdb25adfa335a323f4958c2aab2b rx pkt Short dcid=d47795a43789cda7d864c84bf643a95866b5f08b key_phase=false len=1329 pn=12 [2025-09-12T11:50:54.876245337Z TRACE quiche] 6d823fccec3bbdb25adfa335a323f4958c2aab2b rx frm STREAM id=4 off=8192 len=1308 fin=false [2025-09-12T11:50:54.876254003Z TRACE quiche_apps::client] [::]:40940: processed 1350 bytes [2025-09-12T11:50:54.876257580Z TRACE quiche_apps::client] [::]:40940: recv() would block [2025-09-12T11:50:54.876259944Z TRACE quiche_apps::client] done reading [2025-09-12T11:50:54.876264342Z TRACE quiche_apps::common] received 1308 bytes [2025-09-12T11:50:54.876266757Z TRACE quiche_apps::common] stream 4 has 1308 bytes (fin? false) [2025-09-12T11:50:54.876298907Z TRACE quiche] 6d823fccec3bbdb25adfa335a323f4958c2aab2b tx pkt Short dcid=3916f5df6d26917f key_phase=false len=5 pn=16 [2025-09-12T11:50:54.876302173Z TRACE quiche] 6d823fccec3bbdb25adfa335a323f4958c2aab2b tx frm ACK delay=7 blocks=[1..12] ecn_counts=None [2025-09-12T11:50:54.876309626Z TRACE quiche::recovery::congestion::recovery] 6d823fccec3bbdb25adfa335a323f4958c2aab2b timer=98.617963ms latest_rtt=31.935694ms srtt=39.039893ms min_rtt=31.935694ms rttvar=17.050313ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=71 app_limited=true congestion_recovery_start_time=None Rate { delivered: 1570, delivered_time: Instant { tv_sec: 895, tv_nsec: 941088695 }, first_sent_time: Instant { tv_sec: 895, tv_nsec: 941088695 }, end_of_app_limited: 4, last_sent_packet: 16, largest_acked: 4, rate_sample: RateSample { bandwidth: 305.53 Kbps, is_app_limited: true, interval: 32.389578ms, delivered: 1237, prior_delivered: 333, prior_time: Some(Instant { tv_sec: 895, tv_nsec: 905563413 }), send_elapsed: 453.884µs, ack_elapsed: 32.389578ms, rtt: 31.935694ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 432250, last_update: Instant { tv_sec: 895, tv_nsec: 970689126 }, next_time: Instant { tv_sec: 895, tv_nsec: 970689126 }, max_datagram_size: 1350, last_packet_size: Some(0), iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } [2025-09-12T11:50:54.876347787Z TRACE quiche_apps::client] written 31 bytes from [::]:40940 to [fd00:cafe:cafe:100::100]:443 [2025-09-12T11:50:54.876355021Z TRACE quiche_apps::client] [::]:40940 -> [fd00:cafe:cafe:100::100]:443: done writing [2025-09-12T11:50:54.877340908Z TRACE quiche_apps::client] got 1350 bytes from [fd00:cafe:cafe:100::100]:443 to [::]:40940 [2025-09-12T11:50:54.877350155Z TRACE quiche] 6d823fccec3bbdb25adfa335a323f4958c2aab2b rx pkt Short dcid=d47795a43789cda7d864c84bf643a95866b5f08b key_phase=false len=1329 pn=13 [2025-09-12T11:50:54.877356737Z TRACE quiche] 6d823fccec3bbdb25adfa335a323f4958c2aab2b rx frm STREAM id=0 off=3926 len=1194 fin=true [2025-09-12T11:50:54.877360314Z TRACE quiche] 6d823fccec3bbdb25adfa335a323f4958c2aab2b rx frm STREAM id=4 off=9500 len=108 fin=false [2025-09-12T11:50:54.877367046Z TRACE quiche_apps::client] [::]:40940: processed 1350 bytes [2025-09-12T11:50:54.877370453Z TRACE quiche_apps::client] [::]:40940: recv() would block [2025-09-12T11:50:54.877372717Z TRACE quiche_apps::client] done reading [2025-09-12T11:50:54.877378468Z TRACE quiche_apps::common] received 1194 bytes [2025-09-12T11:50:54.877380822Z TRACE quiche_apps::common] stream 0 has 1194 bytes (fin? true) [2025-09-12T11:50:54.877383307Z DEBUG quiche_apps::common] 1/2 responses received [2025-09-12T11:50:54.877386553Z TRACE quiche_apps::common] received 108 bytes [2025-09-12T11:50:54.877388737Z TRACE quiche_apps::common] stream 4 has 108 bytes (fin? false) [2025-09-12T11:50:54.877396010Z TRACE quiche] 6d823fccec3bbdb25adfa335a323f4958c2aab2b tx pkt Short dcid=3916f5df6d26917f key_phase=false len=5 pn=17 [2025-09-12T11:50:54.877398705Z TRACE quiche] 6d823fccec3bbdb25adfa335a323f4958c2aab2b tx frm ACK delay=5 blocks=[1..13] ecn_counts=None [2025-09-12T11:50:54.877418301Z TRACE quiche::recovery::congestion::recovery] 6d823fccec3bbdb25adfa335a323f4958c2aab2b timer=97.509268ms latest_rtt=31.935694ms srtt=39.039893ms min_rtt=31.935694ms rttvar=17.050313ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=71 app_limited=true congestion_recovery_start_time=None Rate { delivered: 1570, delivered_time: Instant { tv_sec: 895, tv_nsec: 941088695 }, first_sent_time: Instant { tv_sec: 895, tv_nsec: 941088695 }, end_of_app_limited: 4, last_sent_packet: 17, largest_acked: 4, rate_sample: RateSample { bandwidth: 305.53 Kbps, is_app_limited: true, interval: 32.389578ms, delivered: 1237, prior_delivered: 333, prior_time: Some(Instant { tv_sec: 895, tv_nsec: 905563413 }), send_elapsed: 453.884µs, ack_elapsed: 32.389578ms, rtt: 31.935694ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 432250, last_update: Instant { tv_sec: 895, tv_nsec: 970689126 }, next_time: Instant { tv_sec: 895, tv_nsec: 970689126 }, max_datagram_size: 1350, last_packet_size: Some(0), iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } [2025-09-12T11:50:54.877449539Z TRACE quiche_apps::client] written 31 bytes from [::]:40940 to [fd00:cafe:cafe:100::100]:443 [2025-09-12T11:50:54.877457294Z TRACE quiche_apps::client] [::]:40940 -> [fd00:cafe:cafe:100::100]:443: done writing [2025-09-12T11:50:54.877909732Z TRACE quiche_apps::client] got 676 bytes from [fd00:cafe:cafe:100::100]:443 to [::]:40940 [2025-09-12T11:50:54.877917136Z TRACE quiche] 6d823fccec3bbdb25adfa335a323f4958c2aab2b rx pkt Short dcid=d47795a43789cda7d864c84bf643a95866b5f08b key_phase=false len=655 pn=14 [2025-09-12T11:50:54.877927255Z TRACE quiche] 6d823fccec3bbdb25adfa335a323f4958c2aab2b rx frm STREAM id=4 off=9608 len=632 fin=true [2025-09-12T11:50:54.877934358Z TRACE quiche_apps::client] [::]:40940: processed 676 bytes [2025-09-12T11:50:54.877937744Z TRACE quiche_apps::client] [::]:40940: recv() would block [2025-09-12T11:50:54.877940048Z TRACE quiche_apps::client] done reading [2025-09-12T11:50:54.877944527Z TRACE quiche_apps::common] received 632 bytes [2025-09-12T11:50:54.877946761Z TRACE quiche_apps::common] stream 4 has 632 bytes (fin? true) [2025-09-12T11:50:54.877949105Z DEBUG quiche_apps::common] 2/2 responses received [2025-09-12T11:50:54.877951329Z INFO quiche_apps::common] 2/2 response(s) received in 108.251828ms, closing... [2025-09-12T11:50:54.877958342Z TRACE quiche] 6d823fccec3bbdb25adfa335a323f4958c2aab2b tx pkt Short dcid=3916f5df6d26917f key_phase=false len=10 pn=18 [2025-09-12T11:50:54.877960867Z TRACE quiche] 6d823fccec3bbdb25adfa335a323f4958c2aab2b tx frm APPLICATION_CLOSE err=0 reason=[6b, 74, 68, 78, 62, 79, 65] [2025-09-12T11:50:54.877968782Z TRACE quiche::recovery::congestion::recovery] 6d823fccec3bbdb25adfa335a323f4958c2aab2b timer=132.227409ms latest_rtt=31.935694ms srtt=39.039893ms min_rtt=31.935694ms rttvar=17.050313ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=107 app_limited=true congestion_recovery_start_time=None Rate { delivered: 1570, delivered_time: Instant { tv_sec: 895, tv_nsec: 941088695 }, first_sent_time: Instant { tv_sec: 895, tv_nsec: 941088695 }, end_of_app_limited: 17, last_sent_packet: 18, largest_acked: 4, rate_sample: RateSample { bandwidth: 305.53 Kbps, is_app_limited: true, interval: 32.389578ms, delivered: 1237, prior_delivered: 333, prior_time: Some(Instant { tv_sec: 895, tv_nsec: 905563413 }), send_elapsed: 453.884µs, ack_elapsed: 32.389578ms, rtt: 31.935694ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 432250, last_update: Instant { tv_sec: 895, tv_nsec: 973421092 }, next_time: Instant { tv_sec: 895, tv_nsec: 970689126 }, max_datagram_size: 1350, last_packet_size: None, iv: 83.285µs, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } [2025-09-12T11:50:54.877998898Z TRACE quiche_apps::client] written 36 bytes from [::]:40940 to [fd00:cafe:cafe:100::100]:443 [2025-09-12T11:50:54.878004919Z TRACE quiche_apps::client] [::]:40940 -> [fd00:cafe:cafe:100::100]:443: done writing [2025-09-12T11:50:54.899306551Z TRACE quiche_apps::client] got 44 bytes from [fd00:cafe:cafe:100::100]:443 to [::]:40940 [2025-09-12T11:50:54.899325907Z TRACE quiche_apps::client] [::]:40940: processed 44 bytes [2025-09-12T11:50:54.899330425Z TRACE quiche_apps::client] [::]:40940: recv() would block [2025-09-12T11:50:54.899333271Z TRACE quiche_apps::client] done reading [2025-09-12T11:50:54.899338951Z TRACE quiche_apps::client] [::]:40940 -> [fd00:cafe:cafe:100::100]:443: done writing [2025-09-12T11:50:54.908456193Z TRACE quiche_apps::client] got 47 bytes from [fd00:cafe:cafe:100::100]:443 to [::]:40940 [2025-09-12T11:50:54.908468386Z TRACE quiche_apps::client] [::]:40940: processed 47 bytes [2025-09-12T11:50:54.908472303Z TRACE quiche_apps::client] [::]:40940: recv() would block [2025-09-12T11:50:54.908475048Z TRACE quiche_apps::client] done reading [2025-09-12T11:50:54.908478855Z TRACE quiche_apps::client] [::]:40940 -> [fd00:cafe:cafe:100::100]:443: done writing [2025-09-12T11:50:55.200854390Z TRACE quiche_apps::client] timed out [2025-09-12T11:50:55.200891028Z TRACE quiche] 6d823fccec3bbdb25adfa335a323f4958c2aab2b draining timeout expired [2025-09-12T11:50:55.200936242Z TRACE quiche_apps::client] done reading [2025-09-12T11:50:55.200942142Z INFO quiche_apps::client] connection closed, recv=17 sent=19 lost=0 retrans=0 sent_bytes=2210 recv_bytes=17752 lost_bytes=0 [local_addr=[::]:40940 peer_addr=[fd00:cafe:cafe:100::100]:443 validation_state=Validated active=true recv=17 sent=19 lost=0 retrans=0 rtt=39.039893ms min_rtt=Some(31.935694ms) rttvar=17.050313ms cwnd=13500 sent_bytes=2210 recv_bytes=17752 lost_bytes=0 stream_retrans_bytes=0 pmtu=1350 delivery_rate=38191]