[2025-04-30T11:02:45.630942850Z TRACE mio::poll] registering event source with poller: token=Token(0), interests=READABLE [2025-04-30T11:02:45.631245646Z INFO quiche_apps::client] connecting to [fd00:cafe:cafe:100::100]:443 from [::]:34630 with scid cec065775e3f4d142918d49c5a4464bf32372780 [2025-04-30T11:02:45.631288316Z TRACE quiche::tls] cec065775e3f4d142918d49c5a4464bf32372780 write message lvl=Initial len=266 [2025-04-30T11:02:45.631304135Z TRACE quiche] cec065775e3f4d142918d49c5a4464bf32372780 tx pkt Initial version=1 dcid=b9a6a0b4515fddbf374250a292fb136d scid=cec065775e3f4d142918d49c5a4464bf32372780 len=270 pn=0 [2025-04-30T11:02:45.631307642Z TRACE quiche] cec065775e3f4d142918d49c5a4464bf32372780 tx frm CRYPTO off=0 len=266 [2025-04-30T11:02:45.631321297Z TRACE quiche::recovery::congestion::recovery] cec065775e3f4d142918d49c5a4464bf32372780 timer=998.933065ms 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: 694, tv_nsec: 532270455 }, first_sent_time: Instant { tv_sec: 694, tv_nsec: 532270455 }, end_of_app_limited: 1, last_sent_packet: 0, largest_acked: 0, rate_sample: RateSample { delivery_rate: 0, 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: 694, tv_nsec: 532270455 }, next_time: Instant { tv_sec: 694, tv_nsec: 532270455 }, 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-04-30T11:02:45.631366121Z TRACE quiche_apps::client] written 1200 [2025-04-30T11:02:45.671621569Z TRACE quiche_apps::client] got 1232 bytes from [fd00:cafe:cafe:100::100]:443 to [::]:34630 [2025-04-30T11:02:45.671642267Z TRACE quiche] cec065775e3f4d142918d49c5a4464bf32372780 rx pkt Initial version=1 dcid=cec065775e3f4d142918d49c5a4464bf32372780 scid=c79f6736ae6e57ac token= len=120 pn=72998 [2025-04-30T11:02:45.671653318Z TRACE quiche] cec065775e3f4d142918d49c5a4464bf32372780 rx frm ACK delay=92 blocks=[0..0] ecn_counts=None [2025-04-30T11:02:45.671658898Z TRACE quiche::recovery::congestion::recovery] cec065775e3f4d142918d49c5a4464bf32372780 packet newly acked 0 [2025-04-30T11:02:45.671664499Z TRACE quiche] cec065775e3f4d142918d49c5a4464bf32372780 rx frm CRYPTO off=0 len=90 [2025-04-30T11:02:45.671764145Z TRACE quiche::tls] cec065775e3f4d142918d49c5a4464bf32372780 set write secret lvl=Handshake [2025-04-30T11:02:45.671773913Z TRACE quiche::tls] cec065775e3f4d142918d49c5a4464bf32372780 set read secret lvl=Handshake [2025-04-30T11:02:45.671802627Z TRACE quiche] cec065775e3f4d142918d49c5a4464bf32372780 rx pkt Handshake version=1 dcid=cec065775e3f4d142918d49c5a4464bf32372780 scid=c79f6736ae6e57ac len=727 pn=0 [2025-04-30T11:02:45.671809109Z TRACE quiche] cec065775e3f4d142918d49c5a4464bf32372780 rx frm CRYPTO off=0 len=703 [2025-04-30T11:02:45.672074475Z TRACE quiche::tls] cec065775e3f4d142918d49c5a4464bf32372780 write message lvl=Handshake len=36 [2025-04-30T11:02:45.672082570Z TRACE quiche::tls] cec065775e3f4d142918d49c5a4464bf32372780 set write secret lvl=OneRTT [2025-04-30T11:02:45.672091627Z TRACE quiche::tls] cec065775e3f4d142918d49c5a4464bf32372780 set read secret lvl=OneRTT [2025-04-30T11:02:45.672109600Z TRACE quiche] cec065775e3f4d142918d49c5a4464bf32372780 connection established: proto=Ok("h3") cipher=Some(AES128_GCM) curve=Some("X25519") sigalg=Some("ecdsa_secp256r1_sha256") resumed=false TransportParams { original_destination_connection_id: Some(b9a6a0b4515fddbf374250a292fb136d), max_idle_timeout: 180000, stateless_reset_token: Some(50851466848857395917598127862216146767), max_udp_payload_size: 1440, initial_max_data: 1048576, initial_max_stream_data_bidi_local: 2097152, initial_max_stream_data_bidi_remote: 65635, initial_max_stream_data_uni: 65535, initial_max_streams_bidi: 512, initial_max_streams_uni: 512, ack_delay_exponent: 3, max_ack_delay: 10, disable_active_migration: false, active_conn_id_limit: 8, initial_source_connection_id: Some(c79f6736ae6e57ac), retry_source_connection_id: None, max_datagram_frame_size: None, unknown_params: None } [2025-04-30T11:02:45.672142682Z TRACE quiche] cec065775e3f4d142918d49c5a4464bf32372780 rx pkt Handshake version=1 dcid=cec065775e3f4d142918d49c5a4464bf32372780 scid=c79f6736ae6e57ac len=273 pn=1 [2025-04-30T11:02:45.672149525Z TRACE quiche] cec065775e3f4d142918d49c5a4464bf32372780 rx frm PING mtu_probe=None [2025-04-30T11:02:45.672153933Z TRACE quiche] cec065775e3f4d142918d49c5a4464bf32372780 rx frm PADDING len=252 [2025-04-30T11:02:45.672161087Z TRACE quiche_apps::client] [::]:34630: processed 1232 bytes [2025-04-30T11:02:45.672169022Z TRACE quiche_apps::client] got 439 bytes from [fd00:cafe:cafe:100::100]:443 to [::]:34630 [2025-04-30T11:02:45.672173460Z TRACE quiche] cec065775e3f4d142918d49c5a4464bf32372780 rx pkt Short dcid=cec065775e3f4d142918d49c5a4464bf32372780 key_phase=false len=418 pn=0 [2025-04-30T11:02:45.672178780Z TRACE quiche] cec065775e3f4d142918d49c5a4464bf32372780 rx frm CRYPTO off=0 len=125 [2025-04-30T11:02:45.672195291Z TRACE quiche] cec065775e3f4d142918d49c5a4464bf32372780 rx frm NEW_TOKEN len=50 [2025-04-30T11:02:45.672200089Z TRACE quiche] cec065775e3f4d142918d49c5a4464bf32372780 rx frm NEW_CONNECTION_ID seq_num=1 retire_prior_to=0 conn_id=[dc, 6d, 16, ac, 6c, 06, b7, 00] reset_token=[43, cc, 4d, a8, 7b, 7f, 85, c3, 95, 01, 6a, e1, b4, 52, b1, 91] [2025-04-30T11:02:45.672207904Z TRACE quiche] cec065775e3f4d142918d49c5a4464bf32372780 rx frm NEW_CONNECTION_ID seq_num=2 retire_prior_to=0 conn_id=[92, 75, b4, e7, 09, eb, 06, 19] reset_token=[ca, be, 1a, 1a, 90, 11, 8d, ef, 20, 2d, f4, 0c, 4a, b8, dc, ea] [2025-04-30T11:02:45.672213945Z TRACE quiche] cec065775e3f4d142918d49c5a4464bf32372780 rx frm NEW_CONNECTION_ID seq_num=3 retire_prior_to=0 conn_id=[ba, c9, de, ab, 26, fc, 07, fa] reset_token=[c3, 43, ab, 2c, ca, 37, 29, f5, 38, ed, 96, 1d, ab, 28, 16, 7f] [2025-04-30T11:02:45.672219536Z TRACE quiche] cec065775e3f4d142918d49c5a4464bf32372780 rx frm NEW_CONNECTION_ID seq_num=4 retire_prior_to=0 conn_id=[e0, dd, 43, 03, 2c, ac, 13, 5a] reset_token=[34, f9, 0f, 3d, c4, 77, ff, 04, 8b, 85, 40, 46, 69, 42, ad, 0b] [2025-04-30T11:02:45.672225497Z TRACE quiche] cec065775e3f4d142918d49c5a4464bf32372780 rx frm NEW_CONNECTION_ID seq_num=5 retire_prior_to=0 conn_id=[50, d3, 45, 13, 94, da, 2b, 9e] reset_token=[96, 2f, 43, 29, 1e, 01, 14, 43, d5, 81, f9, 46, 95, 4c, 71, 6c] [2025-04-30T11:02:45.672230957Z TRACE quiche] cec065775e3f4d142918d49c5a4464bf32372780 rx frm NEW_CONNECTION_ID seq_num=6 retire_prior_to=0 conn_id=[66, 04, 0d, 71, 85, 92, f7, 7a] reset_token=[de, 8e, 27, c1, db, e5, fc, be, 96, 4b, e1, 4b, 2c, e1, 08, a7] [2025-04-30T11:02:45.672236678Z TRACE quiche] cec065775e3f4d142918d49c5a4464bf32372780 rx frm NEW_CONNECTION_ID seq_num=7 retire_prior_to=0 conn_id=[61, 54, f2, 75, 74, 54, c4, 5a] reset_token=[72, 89, d0, b6, 1e, 66, e5, cd, 07, 9c, 1a, d3, 40, 0f, 78, 40] [2025-04-30T11:02:45.672241407Z TRACE quiche] cec065775e3f4d142918d49c5a4464bf32372780 rx frm STREAM id=3 off=0 len=9 fin=false [2025-04-30T11:02:45.672246075Z TRACE quiche] cec065775e3f4d142918d49c5a4464bf32372780 rx frm STREAM id=7 off=0 len=1 fin=false [2025-04-30T11:02:45.672249792Z TRACE quiche] cec065775e3f4d142918d49c5a4464bf32372780 rx frm STREAM id=11 off=0 len=1 fin=false [2025-04-30T11:02:45.672253269Z TRACE quiche] cec065775e3f4d142918d49c5a4464bf32372780 rx frm PADDING len=4 [2025-04-30T11:02:45.672264380Z TRACE quiche_apps::client] [::]:34630: processed 439 bytes [2025-04-30T11:02:45.672268788Z TRACE quiche_apps::client] [::]:34630: recv() would block [2025-04-30T11:02:45.672271683Z TRACE quiche_apps::client] done reading [2025-04-30T11:02:45.672287623Z TRACE quiche::h3] cec065775e3f4d142918d49c5a4464bf32372780 tx frm SETTINGS stream=2 len=18 [2025-04-30T11:02:45.672306839Z TRACE quiche::h3] cec065775e3f4d142918d49c5a4464bf32372780 open GREASE stream 14 [2025-04-30T11:02:45.672317288Z TRACE quiche::h3] cec065775e3f4d142918d49c5a4464bf32372780 tx frm GREASE stream=0 len=0 [2025-04-30T11:02:45.672324251Z TRACE quiche::h3] cec065775e3f4d142918d49c5a4464bf32372780 tx frm GREASE stream=0 len=18 [2025-04-30T11:02:45.672332166Z TRACE quiche::h3] cec065775e3f4d142918d49c5a4464bf32372780 tx frm HEADERS stream=0 len=29 fin=true [2025-04-30T11:02:45.672356852Z DEBUG quiche_apps::common] Sent HTTP request [":method: GET", ":scheme: https", ":authority: server6", ":path: /xjutbaeosk", "user-agent: quiche"] [2025-04-30T11:02:45.672409961Z TRACE quiche::h3] cec065775e3f4d142918d49c5a4464bf32372780 tx frm HEADERS stream=4 len=30 fin=true [2025-04-30T11:02:45.672417616Z DEBUG quiche_apps::common] Sent HTTP request [":method: GET", ":scheme: https", ":authority: server6", ":path: /ipuukkrkrj", "user-agent: quiche"] [2025-04-30T11:02:45.672446189Z TRACE quiche::h3] cec065775e3f4d142918d49c5a4464bf32372780 stream id 3 is readable [2025-04-30T11:02:45.672452030Z TRACE quiche::h3::stream] cec065775e3f4d142918d49c5a4464bf32372780 read 1 bytes on stream 3 [2025-04-30T11:02:45.672456629Z TRACE quiche::h3] cec065775e3f4d142918d49c5a4464bf32372780 open peer's control stream 3 [2025-04-30T11:02:45.672460646Z TRACE quiche::h3::stream] cec065775e3f4d142918d49c5a4464bf32372780 read 1 bytes on stream 3 [2025-04-30T11:02:45.672465205Z TRACE quiche::h3::stream] cec065775e3f4d142918d49c5a4464bf32372780 read 1 bytes on stream 3 [2025-04-30T11:02:45.672469363Z TRACE quiche::h3::stream] cec065775e3f4d142918d49c5a4464bf32372780 read 6 bytes on stream 3 [2025-04-30T11:02:45.672472809Z TRACE quiche::h3] cec065775e3f4d142918d49c5a4464bf32372780 rx frm SETTINGS max_field_section=None, qpack_max_table=Some(0), qpack_blocked=Some(0) raw=Some([(1, 0), (7, 0), (8, 1)]), additional_settings=None stream=3 payload_len=6 [2025-04-30T11:02:45.672481044Z TRACE quiche::h3] cec065775e3f4d142918d49c5a4464bf32372780 stream id 7 is readable [2025-04-30T11:02:45.672485783Z TRACE quiche::h3::stream] cec065775e3f4d142918d49c5a4464bf32372780 read 1 bytes on stream 7 [2025-04-30T11:02:45.672489991Z TRACE quiche::h3] cec065775e3f4d142918d49c5a4464bf32372780 stream id 11 is readable [2025-04-30T11:02:45.672493989Z TRACE quiche::h3::stream] cec065775e3f4d142918d49c5a4464bf32372780 read 1 bytes on stream 11 [2025-04-30T11:02:45.672520428Z TRACE quiche] cec065775e3f4d142918d49c5a4464bf32372780 tx pkt Initial version=1 dcid=c79f6736ae6e57ac scid=cec065775e3f4d142918d49c5a4464bf32372780 len=9 pn=1 [2025-04-30T11:02:45.672524054Z TRACE quiche] cec065775e3f4d142918d49c5a4464bf32372780 tx frm ACK delay=109 blocks=[72998..72998] ecn_counts=None [2025-04-30T11:02:45.672533913Z TRACE quiche::recovery::congestion::recovery] cec065775e3f4d142918d49c5a4464bf32372780 timer=120.258624ms latest_rtt=40.384519ms srtt=40.384519ms min_rtt=40.384519ms rttvar=20.192259ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=0 app_limited=true congestion_recovery_start_time=None Rate { delivered: 333, delivered_time: Instant { tv_sec: 694, tv_nsec: 573123439 }, first_sent_time: Instant { tv_sec: 694, tv_nsec: 573123439 }, end_of_app_limited: 1, last_sent_packet: 1, largest_acked: 0, rate_sample: RateSample { delivery_rate: 8245, is_app_limited: true, interval: 40.384519ms, delivered: 333, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 694, tv_nsec: 532270455 }), send_elapsed: 0ns, ack_elapsed: 40.384519ms, rtt: 40.384519ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 417858, last_update: Instant { tv_sec: 694, tv_nsec: 573123399 }, next_time: Instant { tv_sec: 694, tv_nsec: 573123439 }, 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-04-30T11:02:45.672559551Z TRACE quiche] cec065775e3f4d142918d49c5a4464bf32372780 tx pkt Handshake version=1 dcid=c79f6736ae6e57ac scid=cec065775e3f4d142918d49c5a4464bf32372780 len=45 pn=2 [2025-04-30T11:02:45.672562997Z TRACE quiche] cec065775e3f4d142918d49c5a4464bf32372780 tx frm ACK delay=52 blocks=[0..1] ecn_counts=None [2025-04-30T11:02:45.672566243Z TRACE quiche] cec065775e3f4d142918d49c5a4464bf32372780 tx frm CRYPTO off=0 len=36 [2025-04-30T11:02:45.672573737Z TRACE quiche::recovery::congestion::recovery] cec065775e3f4d142918d49c5a4464bf32372780 timer=121.092772ms latest_rtt=40.384519ms srtt=40.384519ms min_rtt=40.384519ms rttvar=20.192259ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=99 app_limited=true congestion_recovery_start_time=None Rate { delivered: 333, delivered_time: Instant { tv_sec: 694, tv_nsec: 573123439 }, first_sent_time: Instant { tv_sec: 694, tv_nsec: 573123439 }, end_of_app_limited: 1, last_sent_packet: 2, largest_acked: 0, rate_sample: RateSample { delivery_rate: 8245, is_app_limited: true, interval: 40.384519ms, delivered: 333, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 694, tv_nsec: 532270455 }), send_elapsed: 0ns, ack_elapsed: 40.384519ms, rtt: 40.384519ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 417858, last_update: Instant { tv_sec: 694, tv_nsec: 573528756 }, next_time: Instant { tv_sec: 694, tv_nsec: 573123439 }, max_datagram_size: 1350, last_packet_size: None, iv: 236.923µ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-04-30T11:02:45.672586922Z TRACE quiche] cec065775e3f4d142918d49c5a4464bf32372780 dropped epoch 0 state [2025-04-30T11:02:45.672591901Z TRACE quiche] cec065775e3f4d142918d49c5a4464bf32372780 pmtud probe status false hs_con=false hs_sent=false cwnd_avail=13401 out_len=1187 left=1156 [2025-04-30T11:02:45.672604785Z TRACE quiche] cec065775e3f4d142918d49c5a4464bf32372780 tx pkt Short dcid=c79f6736ae6e57ac key_phase=false len=1161 pn=3 [2025-04-30T11:02:45.672608152Z TRACE quiche] cec065775e3f4d142918d49c5a4464bf32372780 tx frm ACK delay=52 blocks=[0..0] ecn_counts=None [2025-04-30T11:02:45.672611428Z TRACE quiche] cec065775e3f4d142918d49c5a4464bf32372780 tx frm NEW_CONNECTION_ID seq_num=1 retire_prior_to=0 conn_id=[b0, c5, cc, 26, 22, b8, b7, 89, b5, 3a, bd, b6, 20, db, 9f, 74, 92, 3f, 5b, 32] reset_token=[7d, 5a, 66, df, 57, 85, 00, 00, 6c, b5, 6a, 98, 96, 09, 5f, 50] [2025-04-30T11:02:45.672618751Z TRACE quiche] cec065775e3f4d142918d49c5a4464bf32372780 tx frm NEW_CONNECTION_ID seq_num=2 retire_prior_to=0 conn_id=[6e, 17, c4, fa, bf, 48, 63, 75, bb, 6d, 44, 3f, f5, fe, ef, 29, 81, fb, 98, ee] reset_token=[4b, 12, 31, f3, 65, 1d, 2e, c4, d3, 40, 63, 51, fc, 8c, a4, 00] [2025-04-30T11:02:45.672625043Z TRACE quiche] cec065775e3f4d142918d49c5a4464bf32372780 tx frm NEW_CONNECTION_ID seq_num=3 retire_prior_to=0 conn_id=[59, dc, 5b, 80, 90, 4b, a4, 3b, be, d6, b2, 8d, c6, 14, df, 4c, fc, aa, 82, 58] reset_token=[67, 29, d3, 1d, 0d, f1, d7, 3d, fa, 3a, 31, 7a, 2c, 29, 7a, 21] [2025-04-30T11:02:45.672631165Z TRACE quiche] cec065775e3f4d142918d49c5a4464bf32372780 tx frm NEW_CONNECTION_ID seq_num=4 retire_prior_to=0 conn_id=[c3, 79, 86, 56, 3d, 08, b4, 34, 44, ca, ac, 72, 12, 04, 03, 40, 76, cb, 60, 35] reset_token=[09, 26, a5, a1, 48, fc, 94, fb, e9, c9, a5, a6, e6, 6e, 55, 91] [2025-04-30T11:02:45.672637517Z TRACE quiche] cec065775e3f4d142918d49c5a4464bf32372780 tx frm NEW_CONNECTION_ID seq_num=5 retire_prior_to=0 conn_id=[e6, 78, 46, 64, 20, fd, 7c, 4f, 45, a5, 71, 06, 7d, 4d, 7f, be, bd, 63, 93, b4] reset_token=[77, 23, 99, df, 35, 9c, a2, 52, 5e, 2c, 67, 4f, cc, 8d, e2, 3c] [2025-04-30T11:02:45.672643608Z TRACE quiche] cec065775e3f4d142918d49c5a4464bf32372780 tx frm NEW_CONNECTION_ID seq_num=6 retire_prior_to=0 conn_id=[2d, 51, f9, 36, 83, 3b, 79, 6e, aa, 63, cf, 59, 74, 00, 6c, 19, 50, f2, ea, 81] reset_token=[bd, 19, d3, 16, 31, 6c, d1, b6, 94, 1c, a1, e9, 89, 18, 7a, 1b] [2025-04-30T11:02:45.672653366Z TRACE quiche] cec065775e3f4d142918d49c5a4464bf32372780 tx frm NEW_CONNECTION_ID seq_num=7 retire_prior_to=0 conn_id=[d8, 37, b0, 89, 4b, 95, 38, bc, b9, 95, 7f, 1c, 1b, 9e, 6b, 67, 0d, 4f, 97, a8] reset_token=[52, 2b, 79, df, ff, 88, 4a, de, b3, 76, b2, 2e, 47, 40, 38, 0f] [2025-04-30T11:02:45.672659507Z TRACE quiche] cec065775e3f4d142918d49c5a4464bf32372780 tx frm STREAM id=2 off=0 len=19 fin=false [2025-04-30T11:02:45.672662754Z TRACE quiche] cec065775e3f4d142918d49c5a4464bf32372780 tx frm PADDING len=852 [2025-04-30T11:02:45.672673744Z TRACE quiche::recovery::congestion::recovery] cec065775e3f4d142918d49c5a4464bf32372780 timer=120.992815ms latest_rtt=40.384519ms srtt=40.384519ms min_rtt=40.384519ms rttvar=20.192259ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=1286 app_limited=true congestion_recovery_start_time=None Rate { delivered: 333, delivered_time: Instant { tv_sec: 694, tv_nsec: 573123439 }, first_sent_time: Instant { tv_sec: 694, tv_nsec: 573123439 }, end_of_app_limited: 2, last_sent_packet: 3, largest_acked: 0, rate_sample: RateSample { delivery_rate: 8245, is_app_limited: true, interval: 40.384519ms, delivered: 333, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 694, tv_nsec: 532270455 }), send_elapsed: 0ns, ack_elapsed: 40.384519ms, rtt: 40.384519ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 1187, rate: 417858, last_update: Instant { tv_sec: 694, tv_nsec: 573528756 }, next_time: Instant { tv_sec: 694, tv_nsec: 573765679 }, max_datagram_size: 1350, last_packet_size: Some(1187), 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-04-30T11:02:45.672712557Z TRACE quiche_apps::client] written 1350 bytes from [::]:34630 to [fd00:cafe:cafe:100::100]:443 [2025-04-30T11:02:45.672720381Z TRACE quiche] cec065775e3f4d142918d49c5a4464bf32372780 pmtud probe status false hs_con=false hs_sent=false cwnd_avail=12214 out_len=1350 left=1324 [2025-04-30T11:02:45.672724679Z TRACE quiche] cec065775e3f4d142918d49c5a4464bf32372780 tx pkt Short dcid=c79f6736ae6e57ac key_phase=false len=6 pn=4 [2025-04-30T11:02:45.672727725Z TRACE quiche] cec065775e3f4d142918d49c5a4464bf32372780 tx frm STREAM id=6 off=0 len=1 fin=false [2025-04-30T11:02:45.672734237Z TRACE quiche::recovery::congestion::recovery] cec065775e3f4d142918d49c5a4464bf32372780 timer=120.932252ms latest_rtt=40.384519ms srtt=40.384519ms min_rtt=40.384519ms rttvar=20.192259ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=1318 app_limited=true congestion_recovery_start_time=None Rate { delivered: 333, delivered_time: Instant { tv_sec: 694, tv_nsec: 573123439 }, first_sent_time: Instant { tv_sec: 694, tv_nsec: 573123439 }, end_of_app_limited: 3, last_sent_packet: 4, largest_acked: 0, rate_sample: RateSample { delivery_rate: 8245, is_app_limited: true, interval: 40.384519ms, delivered: 333, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 694, tv_nsec: 532270455 }), send_elapsed: 0ns, ack_elapsed: 40.384519ms, rtt: 40.384519ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 417858, last_update: Instant { tv_sec: 694, tv_nsec: 573733057 }, next_time: Instant { tv_sec: 694, tv_nsec: 573765679 }, max_datagram_size: 1350, last_packet_size: None, iv: 2.917259ms, 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-04-30T11:02:45.672764824Z TRACE quiche_apps::client] written 32 bytes from [::]:34630 to [fd00:cafe:cafe:100::100]:443 [2025-04-30T11:02:45.672782157Z TRACE quiche] cec065775e3f4d142918d49c5a4464bf32372780 pmtud probe status false hs_con=false hs_sent=false cwnd_avail=12182 out_len=1350 left=1324 [2025-04-30T11:02:45.672789731Z TRACE quiche] cec065775e3f4d142918d49c5a4464bf32372780 tx pkt Short dcid=c79f6736ae6e57ac key_phase=false len=6 pn=5 [2025-04-30T11:02:45.672794920Z TRACE quiche] cec065775e3f4d142918d49c5a4464bf32372780 tx frm STREAM id=10 off=0 len=1 fin=false [2025-04-30T11:02:45.672806472Z TRACE quiche::recovery::congestion::recovery] cec065775e3f4d142918d49c5a4464bf32372780 timer=120.859476ms latest_rtt=40.384519ms srtt=40.384519ms min_rtt=40.384519ms rttvar=20.192259ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=1350 app_limited=true congestion_recovery_start_time=None Rate { delivered: 333, delivered_time: Instant { tv_sec: 694, tv_nsec: 573123439 }, first_sent_time: Instant { tv_sec: 694, tv_nsec: 573123439 }, end_of_app_limited: 4, last_sent_packet: 5, largest_acked: 0, rate_sample: RateSample { delivery_rate: 8245, is_app_limited: true, interval: 40.384519ms, delivered: 333, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 694, tv_nsec: 532270455 }), send_elapsed: 0ns, ack_elapsed: 40.384519ms, rtt: 40.384519ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 32, rate: 417858, last_update: Instant { tv_sec: 694, tv_nsec: 573733057 }, next_time: Instant { tv_sec: 694, tv_nsec: 576710980 }, max_datagram_size: 1350, last_packet_size: Some(32), 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-04-30T11:02:45.672856025Z TRACE quiche_apps::client] written 32 bytes from [::]:34630 to [fd00:cafe:cafe:100::100]:443 [2025-04-30T11:02:45.672864861Z TRACE quiche] cec065775e3f4d142918d49c5a4464bf32372780 pmtud probe status false hs_con=false hs_sent=false cwnd_avail=12150 out_len=1350 left=1324 [2025-04-30T11:02:45.672871794Z TRACE quiche] cec065775e3f4d142918d49c5a4464bf32372780 tx pkt Short dcid=c79f6736ae6e57ac key_phase=false len=72 pn=6 [2025-04-30T11:02:45.672877565Z TRACE quiche] cec065775e3f4d142918d49c5a4464bf32372780 tx frm STREAM id=0 off=0 len=67 fin=true [2025-04-30T11:02:45.672889808Z TRACE quiche::recovery::congestion::recovery] cec065775e3f4d142918d49c5a4464bf32372780 timer=120.77609ms latest_rtt=40.384519ms srtt=40.384519ms min_rtt=40.384519ms rttvar=20.192259ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=1448 app_limited=true congestion_recovery_start_time=None Rate { delivered: 333, delivered_time: Instant { tv_sec: 694, tv_nsec: 573123439 }, first_sent_time: Instant { tv_sec: 694, tv_nsec: 573123439 }, end_of_app_limited: 5, last_sent_packet: 6, largest_acked: 0, rate_sample: RateSample { delivery_rate: 8245, is_app_limited: true, interval: 40.384519ms, delivered: 333, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 694, tv_nsec: 532270455 }), send_elapsed: 0ns, ack_elapsed: 40.384519ms, rtt: 40.384519ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 417858, last_update: Instant { tv_sec: 694, tv_nsec: 573876886 }, next_time: Instant { tv_sec: 694, tv_nsec: 576710980 }, max_datagram_size: 1350, last_packet_size: None, iv: 311.11µ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-04-30T11:02:45.672938489Z TRACE quiche_apps::client] written 98 bytes from [::]:34630 to [fd00:cafe:cafe:100::100]:443 [2025-04-30T11:02:45.672946343Z TRACE quiche] cec065775e3f4d142918d49c5a4464bf32372780 pmtud probe status false hs_con=false hs_sent=false cwnd_avail=12052 out_len=1350 left=1324 [2025-04-30T11:02:45.672952846Z TRACE quiche] cec065775e3f4d142918d49c5a4464bf32372780 tx pkt Short dcid=c79f6736ae6e57ac key_phase=false len=37 pn=7 [2025-04-30T11:02:45.672965679Z TRACE quiche] cec065775e3f4d142918d49c5a4464bf32372780 tx frm STREAM id=4 off=0 len=32 fin=true [2025-04-30T11:02:45.672978824Z TRACE quiche::recovery::congestion::recovery] cec065775e3f4d142918d49c5a4464bf32372780 timer=120.687114ms latest_rtt=40.384519ms srtt=40.384519ms min_rtt=40.384519ms rttvar=20.192259ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=1511 app_limited=true congestion_recovery_start_time=None Rate { delivered: 333, delivered_time: Instant { tv_sec: 694, tv_nsec: 573123439 }, first_sent_time: Instant { tv_sec: 694, tv_nsec: 573123439 }, end_of_app_limited: 6, last_sent_packet: 7, largest_acked: 0, rate_sample: RateSample { delivery_rate: 8245, is_app_limited: true, interval: 40.384519ms, delivered: 333, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 694, tv_nsec: 532270455 }), send_elapsed: 0ns, ack_elapsed: 40.384519ms, rtt: 40.384519ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 63, rate: 417858, last_update: Instant { tv_sec: 694, tv_nsec: 573876886 }, next_time: Instant { tv_sec: 694, tv_nsec: 577022090 }, max_datagram_size: 1350, last_packet_size: Some(63), 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-04-30T11:02:45.673043996Z TRACE quiche_apps::client] written 63 bytes from [::]:34630 to [fd00:cafe:cafe:100::100]:443 [2025-04-30T11:02:45.673054986Z TRACE quiche] cec065775e3f4d142918d49c5a4464bf32372780 pmtud probe status false hs_con=false hs_sent=false cwnd_avail=11989 out_len=1350 left=1324 [2025-04-30T11:02:45.673061438Z TRACE quiche] cec065775e3f4d142918d49c5a4464bf32372780 tx pkt Short dcid=c79f6736ae6e57ac key_phase=false len=31 pn=8 [2025-04-30T11:02:45.673065456Z TRACE quiche] cec065775e3f4d142918d49c5a4464bf32372780 tx frm STREAM id=14 off=0 len=26 fin=true [2025-04-30T11:02:45.673075224Z TRACE quiche::recovery::congestion::recovery] cec065775e3f4d142918d49c5a4464bf32372780 timer=120.590854ms latest_rtt=40.384519ms srtt=40.384519ms min_rtt=40.384519ms rttvar=20.192259ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=1568 app_limited=true congestion_recovery_start_time=None Rate { delivered: 333, delivered_time: Instant { tv_sec: 694, tv_nsec: 573123439 }, first_sent_time: Instant { tv_sec: 694, tv_nsec: 573123439 }, end_of_app_limited: 7, last_sent_packet: 8, largest_acked: 0, rate_sample: RateSample { delivery_rate: 8245, is_app_limited: true, interval: 40.384519ms, delivered: 333, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 694, tv_nsec: 532270455 }), send_elapsed: 0ns, ack_elapsed: 40.384519ms, rtt: 40.384519ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 417858, last_update: Instant { tv_sec: 694, tv_nsec: 574066149 }, next_time: Instant { tv_sec: 694, tv_nsec: 577022090 }, max_datagram_size: 1350, last_packet_size: None, iv: 287.179µ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-04-30T11:02:45.673111201Z TRACE quiche_apps::client] written 57 bytes from [::]:34630 to [fd00:cafe:cafe:100::100]:443 [2025-04-30T11:02:45.673115800Z TRACE quiche_apps::client] [::]:34630 -> [fd00:cafe:cafe:100::100]:443: done writing [2025-04-30T11:02:45.673126971Z TRACE quiche_apps::client] got 1350 bytes from [fd00:cafe:cafe:100::100]:443 to [::]:34630 [2025-04-30T11:02:45.673133152Z TRACE quiche] cec065775e3f4d142918d49c5a4464bf32372780 rx pkt Short dcid=cec065775e3f4d142918d49c5a4464bf32372780 key_phase=false len=1329 pn=1 [2025-04-30T11:02:45.673141618Z TRACE quiche] cec065775e3f4d142918d49c5a4464bf32372780 rx frm PING mtu_probe=None [2025-04-30T11:02:45.673159922Z TRACE quiche] cec065775e3f4d142918d49c5a4464bf32372780 rx frm PADDING len=1311 [2025-04-30T11:02:45.673169039Z TRACE quiche_apps::client] [::]:34630: processed 1350 bytes [2025-04-30T11:02:45.673173267Z TRACE quiche_apps::client] [::]:34630: recv() would block [2025-04-30T11:02:45.673175622Z TRACE quiche_apps::client] done reading [2025-04-30T11:02:45.673182725Z TRACE quiche] cec065775e3f4d142918d49c5a4464bf32372780 pmtud probe status false hs_con=false hs_sent=false cwnd_avail=11932 out_len=1350 left=1319 [2025-04-30T11:02:45.673185891Z TRACE quiche] cec065775e3f4d142918d49c5a4464bf32372780 tx pkt Short dcid=c79f6736ae6e57ac key_phase=false len=5 pn=9 [2025-04-30T11:02:45.673188265Z TRACE quiche] cec065775e3f4d142918d49c5a4464bf32372780 tx frm ACK delay=6 blocks=[0..1] ecn_counts=None [2025-04-30T11:02:45.673194657Z TRACE quiche::recovery::congestion::recovery] cec065775e3f4d142918d49c5a4464bf32372780 timer=120.471872ms latest_rtt=40.384519ms srtt=40.384519ms min_rtt=40.384519ms rttvar=20.192259ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=1568 app_limited=true congestion_recovery_start_time=None Rate { delivered: 333, delivered_time: Instant { tv_sec: 694, tv_nsec: 573123439 }, first_sent_time: Instant { tv_sec: 694, tv_nsec: 573123439 }, end_of_app_limited: 7, last_sent_packet: 9, largest_acked: 0, rate_sample: RateSample { delivery_rate: 8245, is_app_limited: true, interval: 40.384519ms, delivered: 333, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 694, tv_nsec: 532270455 }), send_elapsed: 0ns, ack_elapsed: 40.384519ms, rtt: 40.384519ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 417858, last_update: Instant { tv_sec: 694, tv_nsec: 574066149 }, next_time: Instant { tv_sec: 694, tv_nsec: 577309269 }, 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-04-30T11:02:45.673221417Z TRACE quiche_apps::client] written 31 bytes from [::]:34630 to [fd00:cafe:cafe:100::100]:443 [2025-04-30T11:02:45.673225295Z TRACE quiche_apps::client] [::]:34630 -> [fd00:cafe:cafe:100::100]:443: done writing [2025-04-30T11:02:45.705843799Z TRACE quiche_apps::client] got 1350 bytes from [fd00:cafe:cafe:100::100]:443 to [::]:34630 [2025-04-30T11:02:45.705863826Z TRACE quiche] cec065775e3f4d142918d49c5a4464bf32372780 rx pkt Short dcid=cec065775e3f4d142918d49c5a4464bf32372780 key_phase=false len=1329 pn=2 [2025-04-30T11:02:45.705872212Z TRACE quiche] cec065775e3f4d142918d49c5a4464bf32372780 rx frm ACK delay=2 blocks=[3..9] ecn_counts=None [2025-04-30T11:02:45.705876890Z TRACE quiche::recovery::congestion::recovery] cec065775e3f4d142918d49c5a4464bf32372780 packet newly acked 3 [2025-04-30T11:02:45.705881038Z TRACE quiche::recovery::congestion::recovery] cec065775e3f4d142918d49c5a4464bf32372780 packet newly acked 4 [2025-04-30T11:02:45.705884294Z TRACE quiche::recovery::congestion::recovery] cec065775e3f4d142918d49c5a4464bf32372780 packet newly acked 5 [2025-04-30T11:02:45.705887060Z TRACE quiche::recovery::congestion::recovery] cec065775e3f4d142918d49c5a4464bf32372780 packet newly acked 6 [2025-04-30T11:02:45.705890215Z TRACE quiche::recovery::congestion::recovery] cec065775e3f4d142918d49c5a4464bf32372780 packet newly acked 7 [2025-04-30T11:02:45.705892920Z TRACE quiche::recovery::congestion::recovery] cec065775e3f4d142918d49c5a4464bf32372780 packet newly acked 8 [2025-04-30T11:02:45.705895555Z TRACE quiche::recovery::congestion::recovery] cec065775e3f4d142918d49c5a4464bf32372780 packet newly acked 9 [2025-04-30T11:02:45.705899793Z TRACE quiche] cec065775e3f4d142918d49c5a4464bf32372780 rx frm HANDSHAKE_DONE [2025-04-30T11:02:45.705904101Z TRACE quiche] cec065775e3f4d142918d49c5a4464bf32372780 dropped epoch 1 state [2025-04-30T11:02:45.705907447Z TRACE quiche] cec065775e3f4d142918d49c5a4464bf32372780 rx frm STREAM id=0 off=0 len=23 fin=false [2025-04-30T11:02:45.705919620Z TRACE quiche] cec065775e3f4d142918d49c5a4464bf32372780 rx frm STREAM id=0 off=23 len=1277 fin=false [2025-04-30T11:02:45.705947893Z TRACE quiche_apps::client] [::]:34630: processed 1350 bytes [2025-04-30T11:02:45.705951961Z TRACE quiche_apps::client] [::]:34630: recv() would block [2025-04-30T11:02:45.705954345Z TRACE quiche_apps::client] done reading [2025-04-30T11:02:45.705957020Z TRACE quiche::h3] cec065775e3f4d142918d49c5a4464bf32372780 stream id 0 is readable [2025-04-30T11:02:45.705960837Z TRACE quiche::h3::stream] cec065775e3f4d142918d49c5a4464bf32372780 read 1 bytes on stream 0 [2025-04-30T11:02:45.705964384Z TRACE quiche::h3::stream] cec065775e3f4d142918d49c5a4464bf32372780 read 1 bytes on stream 0 [2025-04-30T11:02:45.705967370Z TRACE quiche::h3::stream] cec065775e3f4d142918d49c5a4464bf32372780 read 1 bytes on stream 0 [2025-04-30T11:02:45.705970556Z TRACE quiche::h3::stream] cec065775e3f4d142918d49c5a4464bf32372780 read 17 bytes on stream 0 [2025-04-30T11:02:45.705973140Z TRACE quiche::h3] cec065775e3f4d142918d49c5a4464bf32372780 rx frm HEADERS stream=0 payload_len=17 [2025-04-30T11:02:45.705976036Z TRACE quiche::h3::qpack::decoder] Header count=0 base=0 [2025-04-30T11:02:45.705978550Z TRACE quiche::h3::qpack::decoder] Indexed index=25 static=true [2025-04-30T11:02:45.705981225Z TRACE quiche::h3::qpack::decoder] Literal name_idx=92 static=true value=[72, 51, 90, 101, 114, 111, 47, 49, 46, 48] [2025-04-30T11:02:45.705984562Z TRACE quiche::h3::qpack::decoder] Indexed index=53 static=true [2025-04-30T11:02:45.706012604Z DEBUG quiche_apps::common] got response headers [(":status", "200"), ("server", "H3Zero/1.0"), ("content-type", "text/plain")] on stream id 0 [2025-04-30T11:02:45.706017212Z TRACE quiche::h3] cec065775e3f4d142918d49c5a4464bf32372780 stream id 0 is readable [2025-04-30T11:02:45.706020398Z TRACE quiche::h3::stream] cec065775e3f4d142918d49c5a4464bf32372780 read 1 bytes on stream 0 [2025-04-30T11:02:45.706023464Z TRACE quiche::h3::stream] cec065775e3f4d142918d49c5a4464bf32372780 read 1 bytes on stream 0 [2025-04-30T11:02:45.706026700Z TRACE quiche::h3::stream] cec065775e3f4d142918d49c5a4464bf32372780 read 1 bytes on stream 0 [2025-04-30T11:02:45.706028974Z TRACE quiche::h3] cec065775e3f4d142918d49c5a4464bf32372780 rx frm DATA stream=0 wire_payload_len=5120 [2025-04-30T11:02:45.706034425Z DEBUG quiche_apps::common] got 1277 bytes of response data on stream 0 [2025-04-30T11:02:45.706042330Z TRACE quiche] cec065775e3f4d142918d49c5a4464bf32372780 pmtud probe status false hs_con=true hs_sent=false cwnd_avail=13500 out_len=1350 left=1319 [2025-04-30T11:02:45.706045786Z TRACE quiche] cec065775e3f4d142918d49c5a4464bf32372780 tx pkt Short dcid=c79f6736ae6e57ac key_phase=false len=5 pn=10 [2025-04-30T11:02:45.706048321Z TRACE quiche] cec065775e3f4d142918d49c5a4464bf32372780 tx frm ACK delay=22 blocks=[2..2] ecn_counts=None [2025-04-30T11:02:45.706054763Z TRACE quiche::recovery::congestion::recovery] cec065775e3f4d142918d49c5a4464bf32372780 timer=none latest_rtt=29.568325ms srtt=39.032494ms min_rtt=29.568325ms rttvar=17.848242ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=0 app_limited=true congestion_recovery_start_time=None Rate { delivered: 1802, delivered_time: Instant { tv_sec: 694, tv_nsec: 607054304 }, first_sent_time: Instant { tv_sec: 694, tv_nsec: 607054304 }, end_of_app_limited: 9, last_sent_packet: 10, largest_acked: 9, rate_sample: RateSample { delivery_rate: 43520, is_app_limited: true, interval: 33.754155ms, delivered: 1469, prior_delivered: 333, prior_time: Some(Instant { tv_sec: 694, tv_nsec: 573123439 }), send_elapsed: 642.24µs, ack_elapsed: 33.754155ms, rtt: 33.111915ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 432332, last_update: Instant { tv_sec: 694, tv_nsec: 607054304 }, next_time: Instant { tv_sec: 694, tv_nsec: 607054304 }, 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-04-30T11:02:45.706089528Z TRACE quiche_apps::client] written 31 bytes from [::]:34630 to [fd00:cafe:cafe:100::100]:443 [2025-04-30T11:02:45.706093926Z TRACE quiche_apps::client] [::]:34630 -> [fd00:cafe:cafe:100::100]:443: done writing [2025-04-30T11:02:45.706937061Z TRACE quiche_apps::client] got 1350 bytes from [fd00:cafe:cafe:100::100]:443 to [::]:34630 [2025-04-30T11:02:45.706944755Z TRACE quiche] cec065775e3f4d142918d49c5a4464bf32372780 rx pkt Short dcid=cec065775e3f4d142918d49c5a4464bf32372780 key_phase=false len=1329 pn=3 [2025-04-30T11:02:45.706951618Z TRACE quiche] cec065775e3f4d142918d49c5a4464bf32372780 rx frm STREAM id=0 off=1300 len=1308 fin=false [2025-04-30T11:02:45.706959242Z TRACE quiche_apps::client] [::]:34630: processed 1350 bytes [2025-04-30T11:02:45.706962709Z TRACE quiche_apps::client] [::]:34630: recv() would block [2025-04-30T11:02:45.706965023Z TRACE quiche_apps::client] done reading [2025-04-30T11:02:45.706967698Z TRACE quiche::h3] cec065775e3f4d142918d49c5a4464bf32372780 stream id 0 is readable [2025-04-30T11:02:45.706972487Z DEBUG quiche_apps::common] got 1308 bytes of response data on stream 0 [2025-04-30T11:02:45.706979430Z TRACE quiche] cec065775e3f4d142918d49c5a4464bf32372780 pmtud probe status false hs_con=true hs_sent=false cwnd_avail=13500 out_len=1350 left=1319 [2025-04-30T11:02:45.706982736Z TRACE quiche] cec065775e3f4d142918d49c5a4464bf32372780 tx pkt Short dcid=c79f6736ae6e57ac key_phase=false len=5 pn=11 [2025-04-30T11:02:45.707004206Z TRACE quiche] cec065775e3f4d142918d49c5a4464bf32372780 tx frm ACK delay=4 blocks=[2..3] ecn_counts=None [2025-04-30T11:02:45.707016208Z TRACE quiche::recovery::congestion::recovery] cec065775e3f4d142918d49c5a4464bf32372780 timer=none latest_rtt=29.568325ms srtt=39.032494ms min_rtt=29.568325ms rttvar=17.848242ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=0 app_limited=true congestion_recovery_start_time=None Rate { delivered: 1802, delivered_time: Instant { tv_sec: 694, tv_nsec: 607054304 }, first_sent_time: Instant { tv_sec: 694, tv_nsec: 607054304 }, end_of_app_limited: 9, last_sent_packet: 11, largest_acked: 9, rate_sample: RateSample { delivery_rate: 43520, is_app_limited: true, interval: 33.754155ms, delivered: 1469, prior_delivered: 333, prior_time: Some(Instant { tv_sec: 694, tv_nsec: 573123439 }), send_elapsed: 642.24µs, ack_elapsed: 33.754155ms, rtt: 33.111915ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 432332, last_update: Instant { tv_sec: 694, tv_nsec: 607054304 }, next_time: Instant { tv_sec: 694, tv_nsec: 607054304 }, 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-04-30T11:02:45.707044010Z TRACE quiche_apps::client] written 31 bytes from [::]:34630 to [fd00:cafe:cafe:100::100]:443 [2025-04-30T11:02:45.707048028Z TRACE quiche_apps::client] [::]:34630 -> [fd00:cafe:cafe:100::100]:443: done writing [2025-04-30T11:02:45.713791455Z TRACE quiche_apps::client] got 1350 bytes from [fd00:cafe:cafe:100::100]:443 to [::]:34630 [2025-04-30T11:02:45.713802746Z TRACE quiche] cec065775e3f4d142918d49c5a4464bf32372780 rx pkt Short dcid=cec065775e3f4d142918d49c5a4464bf32372780 key_phase=false len=1329 pn=4 [2025-04-30T11:02:45.713809869Z TRACE quiche] cec065775e3f4d142918d49c5a4464bf32372780 rx frm STREAM id=0 off=2608 len=1308 fin=false [2025-04-30T11:02:45.713817694Z TRACE quiche_apps::client] [::]:34630: processed 1350 bytes [2025-04-30T11:02:45.713821210Z TRACE quiche_apps::client] [::]:34630: recv() would block [2025-04-30T11:02:45.713823565Z TRACE quiche_apps::client] done reading [2025-04-30T11:02:45.713831670Z TRACE quiche::h3] cec065775e3f4d142918d49c5a4464bf32372780 stream id 0 is readable [2025-04-30T11:02:45.713836840Z DEBUG quiche_apps::common] got 1308 bytes of response data on stream 0 [2025-04-30T11:02:45.713843983Z TRACE quiche] cec065775e3f4d142918d49c5a4464bf32372780 pmtud probe status false hs_con=true hs_sent=false cwnd_avail=13500 out_len=1350 left=1319 [2025-04-30T11:02:45.713847399Z TRACE quiche] cec065775e3f4d142918d49c5a4464bf32372780 tx pkt Short dcid=c79f6736ae6e57ac key_phase=false len=5 pn=12 [2025-04-30T11:02:45.713849904Z TRACE quiche] cec065775e3f4d142918d49c5a4464bf32372780 tx frm ACK delay=5 blocks=[2..4] ecn_counts=None [2025-04-30T11:02:45.713856737Z TRACE quiche::recovery::congestion::recovery] cec065775e3f4d142918d49c5a4464bf32372780 timer=none latest_rtt=29.568325ms srtt=39.032494ms min_rtt=29.568325ms rttvar=17.848242ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=0 app_limited=true congestion_recovery_start_time=None Rate { delivered: 1802, delivered_time: Instant { tv_sec: 694, tv_nsec: 607054304 }, first_sent_time: Instant { tv_sec: 694, tv_nsec: 607054304 }, end_of_app_limited: 9, last_sent_packet: 12, largest_acked: 9, rate_sample: RateSample { delivery_rate: 43520, is_app_limited: true, interval: 33.754155ms, delivered: 1469, prior_delivered: 333, prior_time: Some(Instant { tv_sec: 694, tv_nsec: 573123439 }), send_elapsed: 642.24µs, ack_elapsed: 33.754155ms, rtt: 33.111915ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 432332, last_update: Instant { tv_sec: 694, tv_nsec: 607054304 }, next_time: Instant { tv_sec: 694, tv_nsec: 607054304 }, 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-04-30T11:02:45.713885681Z TRACE quiche_apps::client] written 31 bytes from [::]:34630 to [fd00:cafe:cafe:100::100]:443 [2025-04-30T11:02:45.713889688Z TRACE quiche_apps::client] [::]:34630 -> [fd00:cafe:cafe:100::100]:443: done writing [2025-04-30T11:02:45.721775077Z TRACE quiche_apps::client] got 1350 bytes from [fd00:cafe:cafe:100::100]:443 to [::]:34630 [2025-04-30T11:02:45.721788472Z TRACE quiche] cec065775e3f4d142918d49c5a4464bf32372780 rx pkt Short dcid=cec065775e3f4d142918d49c5a4464bf32372780 key_phase=false len=1329 pn=5 [2025-04-30T11:02:45.721796908Z TRACE quiche] cec065775e3f4d142918d49c5a4464bf32372780 rx frm STREAM id=0 off=3916 len=1227 fin=true [2025-04-30T11:02:45.721801306Z TRACE quiche] cec065775e3f4d142918d49c5a4464bf32372780 rx frm STREAM id=4 off=0 len=23 fin=false [2025-04-30T11:02:45.721804762Z TRACE quiche] cec065775e3f4d142918d49c5a4464bf32372780 rx frm STREAM id=4 off=23 len=50 fin=false [2025-04-30T11:02:45.721813949Z TRACE quiche_apps::client] [::]:34630: processed 1350 bytes [2025-04-30T11:02:45.721818208Z TRACE quiche_apps::client] [::]:34630: recv() would block [2025-04-30T11:02:45.721821073Z TRACE quiche_apps::client] done reading [2025-04-30T11:02:45.721824329Z TRACE quiche::h3] cec065775e3f4d142918d49c5a4464bf32372780 stream id 0 is readable [2025-04-30T11:02:45.721831212Z DEBUG quiche_apps::common] got 1227 bytes of response data on stream 0 [2025-04-30T11:02:45.721834568Z DEBUG quiche_apps::common] 1/2 responses received [2025-04-30T11:02:45.721837594Z TRACE quiche::h3] cec065775e3f4d142918d49c5a4464bf32372780 stream id 4 is readable [2025-04-30T11:02:45.721841621Z TRACE quiche::h3::stream] cec065775e3f4d142918d49c5a4464bf32372780 read 1 bytes on stream 4 [2025-04-30T11:02:45.721845709Z TRACE quiche::h3::stream] cec065775e3f4d142918d49c5a4464bf32372780 read 1 bytes on stream 4 [2025-04-30T11:02:45.721849396Z TRACE quiche::h3::stream] cec065775e3f4d142918d49c5a4464bf32372780 read 1 bytes on stream 4 [2025-04-30T11:02:45.721853674Z TRACE quiche::h3::stream] cec065775e3f4d142918d49c5a4464bf32372780 read 17 bytes on stream 4 [2025-04-30T11:02:45.721864023Z TRACE quiche::h3] cec065775e3f4d142918d49c5a4464bf32372780 rx frm HEADERS stream=4 payload_len=17 [2025-04-30T11:02:45.721867560Z TRACE quiche::h3::qpack::decoder] Header count=0 base=0 [2025-04-30T11:02:45.721870395Z TRACE quiche::h3::qpack::decoder] Indexed index=25 static=true [2025-04-30T11:02:45.721873541Z TRACE quiche::h3::qpack::decoder] Literal name_idx=92 static=true value=[72, 51, 90, 101, 114, 111, 47, 49, 46, 48] [2025-04-30T11:02:45.721877348Z TRACE quiche::h3::qpack::decoder] Indexed index=53 static=true [2025-04-30T11:02:45.721884411Z DEBUG quiche_apps::common] got response headers [(":status", "200"), ("server", "H3Zero/1.0"), ("content-type", "text/plain")] on stream id 4 [2025-04-30T11:02:45.721888990Z TRACE quiche::h3] cec065775e3f4d142918d49c5a4464bf32372780 stream id 4 is readable [2025-04-30T11:02:45.721892667Z TRACE quiche::h3::stream] cec065775e3f4d142918d49c5a4464bf32372780 read 1 bytes on stream 4 [2025-04-30T11:02:45.721896303Z TRACE quiche::h3::stream] cec065775e3f4d142918d49c5a4464bf32372780 read 1 bytes on stream 4 [2025-04-30T11:02:45.721900010Z TRACE quiche::h3::stream] cec065775e3f4d142918d49c5a4464bf32372780 read 1 bytes on stream 4 [2025-04-30T11:02:45.721902855Z TRACE quiche::h3] cec065775e3f4d142918d49c5a4464bf32372780 rx frm DATA stream=4 wire_payload_len=10240 [2025-04-30T11:02:45.721908075Z DEBUG quiche_apps::common] got 50 bytes of response data on stream 4 [2025-04-30T11:02:45.721916781Z TRACE quiche] cec065775e3f4d142918d49c5a4464bf32372780 pmtud probe status false hs_con=true hs_sent=false cwnd_avail=13500 out_len=1350 left=1319 [2025-04-30T11:02:45.721921020Z TRACE quiche] cec065775e3f4d142918d49c5a4464bf32372780 tx pkt Short dcid=c79f6736ae6e57ac key_phase=false len=5 pn=13 [2025-04-30T11:02:45.721924185Z TRACE quiche] cec065775e3f4d142918d49c5a4464bf32372780 tx frm ACK delay=16 blocks=[2..5] ecn_counts=None [2025-04-30T11:02:45.721932180Z TRACE quiche::recovery::congestion::recovery] cec065775e3f4d142918d49c5a4464bf32372780 timer=none latest_rtt=29.568325ms srtt=39.032494ms min_rtt=29.568325ms rttvar=17.848242ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=0 app_limited=true congestion_recovery_start_time=None Rate { delivered: 1802, delivered_time: Instant { tv_sec: 694, tv_nsec: 607054304 }, first_sent_time: Instant { tv_sec: 694, tv_nsec: 607054304 }, end_of_app_limited: 9, last_sent_packet: 13, largest_acked: 9, rate_sample: RateSample { delivery_rate: 43520, is_app_limited: true, interval: 33.754155ms, delivered: 1469, prior_delivered: 333, prior_time: Some(Instant { tv_sec: 694, tv_nsec: 573123439 }), send_elapsed: 642.24µs, ack_elapsed: 33.754155ms, rtt: 33.111915ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 432332, last_update: Instant { tv_sec: 694, tv_nsec: 607054304 }, next_time: Instant { tv_sec: 694, tv_nsec: 607054304 }, 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-04-30T11:02:45.721967556Z TRACE quiche_apps::client] written 31 bytes from [::]:34630 to [fd00:cafe:cafe:100::100]:443 [2025-04-30T11:02:45.721971975Z TRACE quiche_apps::client] [::]:34630 -> [fd00:cafe:cafe:100::100]:443: done writing [2025-04-30T11:02:45.729682035Z TRACE quiche_apps::client] got 1350 bytes from [fd00:cafe:cafe:100::100]:443 to [::]:34630 [2025-04-30T11:02:45.729691212Z TRACE quiche] cec065775e3f4d142918d49c5a4464bf32372780 rx pkt Short dcid=cec065775e3f4d142918d49c5a4464bf32372780 key_phase=false len=1329 pn=6 [2025-04-30T11:02:45.729698265Z TRACE quiche] cec065775e3f4d142918d49c5a4464bf32372780 rx frm STREAM id=4 off=73 len=1308 fin=false [2025-04-30T11:02:45.729706000Z TRACE quiche_apps::client] [::]:34630: processed 1350 bytes [2025-04-30T11:02:45.729709406Z TRACE quiche_apps::client] [::]:34630: recv() would block [2025-04-30T11:02:45.729717551Z TRACE quiche_apps::client] done reading [2025-04-30T11:02:45.729720396Z TRACE quiche::h3] cec065775e3f4d142918d49c5a4464bf32372780 stream id 4 is readable [2025-04-30T11:02:45.729725256Z DEBUG quiche_apps::common] got 1308 bytes of response data on stream 4 [2025-04-30T11:02:45.729732359Z TRACE quiche] cec065775e3f4d142918d49c5a4464bf32372780 pmtud probe status false hs_con=true hs_sent=false cwnd_avail=13500 out_len=1350 left=1319 [2025-04-30T11:02:45.729735685Z TRACE quiche] cec065775e3f4d142918d49c5a4464bf32372780 tx pkt Short dcid=c79f6736ae6e57ac key_phase=false len=5 pn=14 [2025-04-30T11:02:45.729739111Z TRACE quiche] cec065775e3f4d142918d49c5a4464bf32372780 tx frm ACK delay=5 blocks=[2..6] ecn_counts=None [2025-04-30T11:02:45.729751575Z TRACE quiche::recovery::congestion::recovery] cec065775e3f4d142918d49c5a4464bf32372780 timer=none latest_rtt=29.568325ms srtt=39.032494ms min_rtt=29.568325ms rttvar=17.848242ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=0 app_limited=true congestion_recovery_start_time=None Rate { delivered: 1802, delivered_time: Instant { tv_sec: 694, tv_nsec: 607054304 }, first_sent_time: Instant { tv_sec: 694, tv_nsec: 607054304 }, end_of_app_limited: 9, last_sent_packet: 14, largest_acked: 9, rate_sample: RateSample { delivery_rate: 43520, is_app_limited: true, interval: 33.754155ms, delivered: 1469, prior_delivered: 333, prior_time: Some(Instant { tv_sec: 694, tv_nsec: 573123439 }), send_elapsed: 642.24µs, ack_elapsed: 33.754155ms, rtt: 33.111915ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 432332, last_update: Instant { tv_sec: 694, tv_nsec: 607054304 }, next_time: Instant { tv_sec: 694, tv_nsec: 607054304 }, 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-04-30T11:02:45.729781541Z TRACE quiche_apps::client] written 31 bytes from [::]:34630 to [fd00:cafe:cafe:100::100]:443 [2025-04-30T11:02:45.729785408Z TRACE quiche_apps::client] [::]:34630 -> [fd00:cafe:cafe:100::100]:443: done writing [2025-04-30T11:02:45.737670105Z TRACE quiche_apps::client] got 1350 bytes from [fd00:cafe:cafe:100::100]:443 to [::]:34630 [2025-04-30T11:02:45.737683239Z TRACE quiche] cec065775e3f4d142918d49c5a4464bf32372780 rx pkt Short dcid=cec065775e3f4d142918d49c5a4464bf32372780 key_phase=false len=1329 pn=7 [2025-04-30T11:02:45.737691455Z TRACE quiche] cec065775e3f4d142918d49c5a4464bf32372780 rx frm STREAM id=4 off=1381 len=1308 fin=false [2025-04-30T11:02:45.737701022Z TRACE quiche_apps::client] [::]:34630: processed 1350 bytes [2025-04-30T11:02:45.737705270Z TRACE quiche_apps::client] [::]:34630: recv() would block [2025-04-30T11:02:45.737708126Z TRACE quiche_apps::client] done reading [2025-04-30T11:02:45.737711402Z TRACE quiche::h3] cec065775e3f4d142918d49c5a4464bf32372780 stream id 4 is readable [2025-04-30T11:02:45.737717203Z DEBUG quiche_apps::common] got 1308 bytes of response data on stream 4 [2025-04-30T11:02:45.737725618Z TRACE quiche] cec065775e3f4d142918d49c5a4464bf32372780 pmtud probe status false hs_con=true hs_sent=false cwnd_avail=13500 out_len=1350 left=1319 [2025-04-30T11:02:45.737729676Z TRACE quiche] cec065775e3f4d142918d49c5a4464bf32372780 tx pkt Short dcid=c79f6736ae6e57ac key_phase=false len=5 pn=15 [2025-04-30T11:02:45.737732712Z TRACE quiche] cec065775e3f4d142918d49c5a4464bf32372780 tx frm ACK delay=5 blocks=[2..7] ecn_counts=None [2025-04-30T11:02:45.737740526Z TRACE quiche::recovery::congestion::recovery] cec065775e3f4d142918d49c5a4464bf32372780 timer=none latest_rtt=29.568325ms srtt=39.032494ms min_rtt=29.568325ms rttvar=17.848242ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=0 app_limited=true congestion_recovery_start_time=None Rate { delivered: 1802, delivered_time: Instant { tv_sec: 694, tv_nsec: 638737513 }, first_sent_time: Instant { tv_sec: 694, tv_nsec: 638737513 }, end_of_app_limited: 9, last_sent_packet: 15, largest_acked: 9, rate_sample: RateSample { delivery_rate: 43520, is_app_limited: true, interval: 33.754155ms, delivered: 1469, prior_delivered: 333, prior_time: Some(Instant { tv_sec: 694, tv_nsec: 573123439 }), send_elapsed: 642.24µs, ack_elapsed: 33.754155ms, rtt: 33.111915ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 432332, last_update: Instant { tv_sec: 694, tv_nsec: 638737513 }, next_time: Instant { tv_sec: 694, tv_nsec: 638737513 }, 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-04-30T11:02:45.737787143Z TRACE quiche_apps::client] written 31 bytes from [::]:34630 to [fd00:cafe:cafe:100::100]:443 [2025-04-30T11:02:45.737792313Z TRACE quiche_apps::client] [::]:34630 -> [fd00:cafe:cafe:100::100]:443: done writing [2025-04-30T11:02:45.743906022Z TRACE quiche_apps::client] got 1350 bytes from [fd00:cafe:cafe:100::100]:443 to [::]:34630 [2025-04-30T11:02:45.743916963Z TRACE quiche] cec065775e3f4d142918d49c5a4464bf32372780 rx pkt Short dcid=cec065775e3f4d142918d49c5a4464bf32372780 key_phase=false len=1329 pn=8 [2025-04-30T11:02:45.743923825Z TRACE quiche] cec065775e3f4d142918d49c5a4464bf32372780 rx frm STREAM id=4 off=2689 len=1308 fin=false [2025-04-30T11:02:45.743931500Z TRACE quiche_apps::client] [::]:34630: processed 1350 bytes [2025-04-30T11:02:45.743934956Z TRACE quiche_apps::client] [::]:34630: recv() would block [2025-04-30T11:02:45.743937221Z TRACE quiche_apps::client] done reading [2025-04-30T11:02:45.743939865Z TRACE quiche::h3] cec065775e3f4d142918d49c5a4464bf32372780 stream id 4 is readable [2025-04-30T11:02:45.743944484Z DEBUG quiche_apps::common] got 1308 bytes of response data on stream 4 [2025-04-30T11:02:45.743951377Z TRACE quiche] cec065775e3f4d142918d49c5a4464bf32372780 pmtud probe status false hs_con=true hs_sent=false cwnd_avail=13500 out_len=1350 left=1319 [2025-04-30T11:02:45.743954543Z TRACE quiche] cec065775e3f4d142918d49c5a4464bf32372780 tx pkt Short dcid=c79f6736ae6e57ac key_phase=false len=5 pn=16 [2025-04-30T11:02:45.743957027Z TRACE quiche] cec065775e3f4d142918d49c5a4464bf32372780 tx frm ACK delay=4 blocks=[2..8] ecn_counts=None [2025-04-30T11:02:45.743963329Z TRACE quiche::recovery::congestion::recovery] cec065775e3f4d142918d49c5a4464bf32372780 timer=none latest_rtt=29.568325ms srtt=39.032494ms min_rtt=29.568325ms rttvar=17.848242ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=0 app_limited=true congestion_recovery_start_time=None Rate { delivered: 1802, delivered_time: Instant { tv_sec: 694, tv_nsec: 638737513 }, first_sent_time: Instant { tv_sec: 694, tv_nsec: 638737513 }, end_of_app_limited: 9, last_sent_packet: 16, largest_acked: 9, rate_sample: RateSample { delivery_rate: 43520, is_app_limited: true, interval: 33.754155ms, delivered: 1469, prior_delivered: 333, prior_time: Some(Instant { tv_sec: 694, tv_nsec: 573123439 }), send_elapsed: 642.24µs, ack_elapsed: 33.754155ms, rtt: 33.111915ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 432332, last_update: Instant { tv_sec: 694, tv_nsec: 638737513 }, next_time: Instant { tv_sec: 694, tv_nsec: 638737513 }, 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-04-30T11:02:45.744012040Z TRACE quiche_apps::client] written 31 bytes from [::]:34630 to [fd00:cafe:cafe:100::100]:443 [2025-04-30T11:02:45.744017470Z TRACE quiche_apps::client] [::]:34630 -> [fd00:cafe:cafe:100::100]:443: done writing [2025-04-30T11:02:45.749092978Z TRACE quiche_apps::client] got 1350 bytes from [fd00:cafe:cafe:100::100]:443 to [::]:34630 [2025-04-30T11:02:45.749106343Z TRACE quiche] cec065775e3f4d142918d49c5a4464bf32372780 rx pkt Short dcid=cec065775e3f4d142918d49c5a4464bf32372780 key_phase=false len=1329 pn=9 [2025-04-30T11:02:45.749114659Z TRACE quiche] cec065775e3f4d142918d49c5a4464bf32372780 rx frm STREAM id=4 off=3997 len=1308 fin=false [2025-04-30T11:02:45.749124217Z TRACE quiche_apps::client] [::]:34630: processed 1350 bytes [2025-04-30T11:02:45.749128454Z TRACE quiche_apps::client] [::]:34630: recv() would block [2025-04-30T11:02:45.749131320Z TRACE quiche_apps::client] done reading [2025-04-30T11:02:45.749134586Z TRACE quiche::h3] cec065775e3f4d142918d49c5a4464bf32372780 stream id 4 is readable [2025-04-30T11:02:45.749140256Z DEBUG quiche_apps::common] got 1308 bytes of response data on stream 4 [2025-04-30T11:02:45.749148742Z TRACE quiche] cec065775e3f4d142918d49c5a4464bf32372780 pmtud probe status false hs_con=true hs_sent=false cwnd_avail=13500 out_len=1350 left=1319 [2025-04-30T11:02:45.749152780Z TRACE quiche] cec065775e3f4d142918d49c5a4464bf32372780 tx pkt Short dcid=c79f6736ae6e57ac key_phase=false len=5 pn=17 [2025-04-30T11:02:45.749155886Z TRACE quiche] cec065775e3f4d142918d49c5a4464bf32372780 tx frm ACK delay=5 blocks=[2..9] ecn_counts=None [2025-04-30T11:02:45.749163820Z TRACE quiche::recovery::congestion::recovery] cec065775e3f4d142918d49c5a4464bf32372780 timer=none latest_rtt=29.568325ms srtt=39.032494ms min_rtt=29.568325ms rttvar=17.848242ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=0 app_limited=true congestion_recovery_start_time=None Rate { delivered: 1802, delivered_time: Instant { tv_sec: 694, tv_nsec: 638737513 }, first_sent_time: Instant { tv_sec: 694, tv_nsec: 638737513 }, end_of_app_limited: 9, last_sent_packet: 17, largest_acked: 9, rate_sample: RateSample { delivery_rate: 43520, is_app_limited: true, interval: 33.754155ms, delivered: 1469, prior_delivered: 333, prior_time: Some(Instant { tv_sec: 694, tv_nsec: 573123439 }), send_elapsed: 642.24µs, ack_elapsed: 33.754155ms, rtt: 33.111915ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 432332, last_update: Instant { tv_sec: 694, tv_nsec: 638737513 }, next_time: Instant { tv_sec: 694, tv_nsec: 638737513 }, 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-04-30T11:02:45.749197804Z TRACE quiche_apps::client] written 31 bytes from [::]:34630 to [fd00:cafe:cafe:100::100]:443 [2025-04-30T11:02:45.749202673Z TRACE quiche_apps::client] [::]:34630 -> [fd00:cafe:cafe:100::100]:443: done writing [2025-04-30T11:02:45.753691297Z TRACE quiche_apps::client] got 1350 bytes from [fd00:cafe:cafe:100::100]:443 to [::]:34630 [2025-04-30T11:02:45.753702588Z TRACE quiche] cec065775e3f4d142918d49c5a4464bf32372780 rx pkt Short dcid=cec065775e3f4d142918d49c5a4464bf32372780 key_phase=false len=1329 pn=10 [2025-04-30T11:02:45.753709501Z TRACE quiche] cec065775e3f4d142918d49c5a4464bf32372780 rx frm STREAM id=4 off=5305 len=1308 fin=false [2025-04-30T11:02:45.753729298Z TRACE quiche_apps::client] [::]:34630: processed 1350 bytes [2025-04-30T11:02:45.753732945Z TRACE quiche_apps::client] [::]:34630: recv() would block [2025-04-30T11:02:45.753735229Z TRACE quiche_apps::client] done reading [2025-04-30T11:02:45.753737854Z TRACE quiche::h3] cec065775e3f4d142918d49c5a4464bf32372780 stream id 4 is readable [2025-04-30T11:02:45.753742643Z DEBUG quiche_apps::common] got 1308 bytes of response data on stream 4 [2025-04-30T11:02:45.753749606Z TRACE quiche] cec065775e3f4d142918d49c5a4464bf32372780 pmtud probe status false hs_con=true hs_sent=false cwnd_avail=13500 out_len=1350 left=1319 [2025-04-30T11:02:45.753755577Z TRACE quiche] cec065775e3f4d142918d49c5a4464bf32372780 tx pkt Short dcid=c79f6736ae6e57ac key_phase=false len=5 pn=18 [2025-04-30T11:02:45.753758062Z TRACE quiche] cec065775e3f4d142918d49c5a4464bf32372780 tx frm ACK delay=5 blocks=[2..10] ecn_counts=None [2025-04-30T11:02:45.753768641Z TRACE quiche::recovery::congestion::recovery] cec065775e3f4d142918d49c5a4464bf32372780 timer=none latest_rtt=29.568325ms srtt=39.032494ms min_rtt=29.568325ms rttvar=17.848242ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=0 app_limited=true congestion_recovery_start_time=None Rate { delivered: 1802, delivered_time: Instant { tv_sec: 694, tv_nsec: 638737513 }, first_sent_time: Instant { tv_sec: 694, tv_nsec: 638737513 }, end_of_app_limited: 9, last_sent_packet: 18, largest_acked: 9, rate_sample: RateSample { delivery_rate: 43520, is_app_limited: true, interval: 33.754155ms, delivered: 1469, prior_delivered: 333, prior_time: Some(Instant { tv_sec: 694, tv_nsec: 573123439 }), send_elapsed: 642.24µs, ack_elapsed: 33.754155ms, rtt: 33.111915ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 432332, last_update: Instant { tv_sec: 694, tv_nsec: 638737513 }, next_time: Instant { tv_sec: 694, tv_nsec: 638737513 }, 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-04-30T11:02:45.753803477Z TRACE quiche_apps::client] written 31 bytes from [::]:34630 to [fd00:cafe:cafe:100::100]:443 [2025-04-30T11:02:45.753807494Z TRACE quiche_apps::client] [::]:34630 -> [fd00:cafe:cafe:100::100]:443: done writing [2025-04-30T11:02:45.758330452Z TRACE quiche_apps::client] got 1350 bytes from [fd00:cafe:cafe:100::100]:443 to [::]:34630 [2025-04-30T11:02:45.758341833Z TRACE quiche] cec065775e3f4d142918d49c5a4464bf32372780 rx pkt Short dcid=cec065775e3f4d142918d49c5a4464bf32372780 key_phase=false len=1329 pn=11 [2025-04-30T11:02:45.758348666Z TRACE quiche] cec065775e3f4d142918d49c5a4464bf32372780 rx frm STREAM id=4 off=6613 len=1308 fin=false [2025-04-30T11:02:45.758356521Z TRACE quiche_apps::client] [::]:34630: processed 1350 bytes [2025-04-30T11:02:45.758359947Z TRACE quiche_apps::client] [::]:34630: recv() would block [2025-04-30T11:02:45.758362241Z TRACE quiche_apps::client] done reading [2025-04-30T11:02:45.758364836Z TRACE quiche::h3] cec065775e3f4d142918d49c5a4464bf32372780 stream id 4 is readable [2025-04-30T11:02:45.758369525Z DEBUG quiche_apps::common] got 1308 bytes of response data on stream 4 [2025-04-30T11:02:45.758376668Z TRACE quiche] cec065775e3f4d142918d49c5a4464bf32372780 pmtud probe status false hs_con=true hs_sent=false cwnd_avail=13500 out_len=1350 left=1319 [2025-04-30T11:02:45.758380035Z TRACE quiche] cec065775e3f4d142918d49c5a4464bf32372780 tx pkt Short dcid=c79f6736ae6e57ac key_phase=false len=5 pn=19 [2025-04-30T11:02:45.758382569Z TRACE quiche] cec065775e3f4d142918d49c5a4464bf32372780 tx frm ACK delay=4 blocks=[2..11] ecn_counts=None [2025-04-30T11:02:45.758389252Z TRACE quiche::recovery::congestion::recovery] cec065775e3f4d142918d49c5a4464bf32372780 timer=none latest_rtt=29.568325ms srtt=39.032494ms min_rtt=29.568325ms rttvar=17.848242ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=0 app_limited=true congestion_recovery_start_time=None Rate { delivered: 1802, delivered_time: Instant { tv_sec: 694, tv_nsec: 638737513 }, first_sent_time: Instant { tv_sec: 694, tv_nsec: 638737513 }, end_of_app_limited: 9, last_sent_packet: 19, largest_acked: 9, rate_sample: RateSample { delivery_rate: 43520, is_app_limited: true, interval: 33.754155ms, delivered: 1469, prior_delivered: 333, prior_time: Some(Instant { tv_sec: 694, tv_nsec: 573123439 }), send_elapsed: 642.24µs, ack_elapsed: 33.754155ms, rtt: 33.111915ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 432332, last_update: Instant { tv_sec: 694, tv_nsec: 638737513 }, next_time: Instant { tv_sec: 694, tv_nsec: 638737513 }, 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-04-30T11:02:45.758424037Z TRACE quiche_apps::client] written 31 bytes from [::]:34630 to [fd00:cafe:cafe:100::100]:443 [2025-04-30T11:02:45.758428245Z TRACE quiche_apps::client] [::]:34630 -> [fd00:cafe:cafe:100::100]:443: done writing [2025-04-30T11:02:45.762588926Z TRACE quiche_apps::client] got 1350 bytes from [fd00:cafe:cafe:100::100]:443 to [::]:34630 [2025-04-30T11:02:45.762599676Z TRACE quiche] cec065775e3f4d142918d49c5a4464bf32372780 rx pkt Short dcid=cec065775e3f4d142918d49c5a4464bf32372780 key_phase=false len=1329 pn=12 [2025-04-30T11:02:45.762606468Z TRACE quiche] cec065775e3f4d142918d49c5a4464bf32372780 rx frm STREAM id=4 off=7921 len=1308 fin=false [2025-04-30T11:02:45.762614253Z TRACE quiche_apps::client] [::]:34630: processed 1350 bytes [2025-04-30T11:02:45.762617629Z TRACE quiche_apps::client] [::]:34630: recv() would block [2025-04-30T11:02:45.762619893Z TRACE quiche_apps::client] done reading [2025-04-30T11:02:45.762622498Z TRACE quiche::h3] cec065775e3f4d142918d49c5a4464bf32372780 stream id 4 is readable [2025-04-30T11:02:45.762627127Z DEBUG quiche_apps::common] got 1308 bytes of response data on stream 4 [2025-04-30T11:02:45.762650381Z TRACE quiche] cec065775e3f4d142918d49c5a4464bf32372780 pmtud probe status false hs_con=true hs_sent=false cwnd_avail=13500 out_len=1350 left=1319 [2025-04-30T11:02:45.762653877Z TRACE quiche] cec065775e3f4d142918d49c5a4464bf32372780 tx pkt Short dcid=c79f6736ae6e57ac key_phase=false len=5 pn=20 [2025-04-30T11:02:45.762656342Z TRACE quiche] cec065775e3f4d142918d49c5a4464bf32372780 tx frm ACK delay=6 blocks=[2..12] ecn_counts=None [2025-04-30T11:02:45.762662884Z TRACE quiche::recovery::congestion::recovery] cec065775e3f4d142918d49c5a4464bf32372780 timer=none latest_rtt=29.568325ms srtt=39.032494ms min_rtt=29.568325ms rttvar=17.848242ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=0 app_limited=true congestion_recovery_start_time=None Rate { delivered: 1802, delivered_time: Instant { tv_sec: 694, tv_nsec: 638737513 }, first_sent_time: Instant { tv_sec: 694, tv_nsec: 638737513 }, end_of_app_limited: 9, last_sent_packet: 20, largest_acked: 9, rate_sample: RateSample { delivery_rate: 43520, is_app_limited: true, interval: 33.754155ms, delivered: 1469, prior_delivered: 333, prior_time: Some(Instant { tv_sec: 694, tv_nsec: 573123439 }), send_elapsed: 642.24µs, ack_elapsed: 33.754155ms, rtt: 33.111915ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 432332, last_update: Instant { tv_sec: 694, tv_nsec: 638737513 }, next_time: Instant { tv_sec: 694, tv_nsec: 638737513 }, 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-04-30T11:02:45.762691918Z TRACE quiche_apps::client] written 31 bytes from [::]:34630 to [fd00:cafe:cafe:100::100]:443 [2025-04-30T11:02:45.762696006Z TRACE quiche_apps::client] [::]:34630 -> [fd00:cafe:cafe:100::100]:443: done writing [2025-04-30T11:02:45.766665129Z TRACE quiche_apps::client] got 1079 bytes from [fd00:cafe:cafe:100::100]:443 to [::]:34630 [2025-04-30T11:02:45.766676370Z TRACE quiche] cec065775e3f4d142918d49c5a4464bf32372780 rx pkt Short dcid=cec065775e3f4d142918d49c5a4464bf32372780 key_phase=false len=1058 pn=13 [2025-04-30T11:02:45.766683133Z TRACE quiche] cec065775e3f4d142918d49c5a4464bf32372780 rx frm STREAM id=4 off=9229 len=1034 fin=true [2025-04-30T11:02:45.766691759Z TRACE quiche] cec065775e3f4d142918d49c5a4464bf32372780 rx frm PADDING len=1 [2025-04-30T11:02:45.766699023Z TRACE quiche_apps::client] [::]:34630: processed 1079 bytes [2025-04-30T11:02:45.766702499Z TRACE quiche_apps::client] [::]:34630: recv() would block [2025-04-30T11:02:45.766704773Z TRACE quiche_apps::client] done reading [2025-04-30T11:02:45.766707348Z TRACE quiche::h3] cec065775e3f4d142918d49c5a4464bf32372780 stream id 4 is readable [2025-04-30T11:02:45.766712628Z DEBUG quiche_apps::common] got 1034 bytes of response data on stream 4 [2025-04-30T11:02:45.766715273Z DEBUG quiche_apps::common] 2/2 responses received [2025-04-30T11:02:45.766717787Z INFO quiche_apps::common] 2/2 response(s) received in 135.34821ms, closing... [2025-04-30T11:02:45.766724440Z TRACE quiche] cec065775e3f4d142918d49c5a4464bf32372780 pmtud probe status false hs_con=true hs_sent=false cwnd_avail=13500 out_len=1350 left=1324 [2025-04-30T11:02:45.766727806Z TRACE quiche] cec065775e3f4d142918d49c5a4464bf32372780 tx pkt Short dcid=c79f6736ae6e57ac key_phase=false len=11 pn=21 [2025-04-30T11:02:45.766730251Z TRACE quiche] cec065775e3f4d142918d49c5a4464bf32372780 tx frm APPLICATION_CLOSE err=100 reason=[6b, 74, 68, 78, 62, 79, 65] [2025-04-30T11:02:45.766737424Z TRACE quiche::recovery::congestion::recovery] cec065775e3f4d142918d49c5a4464bf32372780 timer=120.409793ms latest_rtt=29.568325ms srtt=39.032494ms min_rtt=29.568325ms rttvar=17.848242ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=37 app_limited=true congestion_recovery_start_time=None Rate { delivered: 1802, delivered_time: Instant { tv_sec: 694, tv_nsec: 638737513 }, first_sent_time: Instant { tv_sec: 694, tv_nsec: 638737513 }, end_of_app_limited: 20, last_sent_packet: 21, largest_acked: 9, rate_sample: RateSample { delivery_rate: 43520, is_app_limited: true, interval: 33.754155ms, delivered: 1469, prior_delivered: 333, prior_time: Some(Instant { tv_sec: 694, tv_nsec: 573123439 }), send_elapsed: 642.24µs, ack_elapsed: 33.754155ms, rtt: 33.111915ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 432332, last_update: Instant { tv_sec: 694, tv_nsec: 667737517 }, next_time: Instant { tv_sec: 694, tv_nsec: 638737513 }, max_datagram_size: 1350, last_packet_size: None, iv: 85.582µ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-04-30T11:02:45.766767240Z TRACE quiche_apps::client] written 37 bytes from [::]:34630 to [fd00:cafe:cafe:100::100]:443 [2025-04-30T11:02:45.766770817Z TRACE quiche_apps::client] [::]:34630 -> [fd00:cafe:cafe:100::100]:443: done writing [2025-04-30T11:02:45.769355474Z TRACE quiche_apps::client] got 1350 bytes from [fd00:cafe:cafe:100::100]:443 to [::]:34630 [2025-04-30T11:02:45.769367126Z TRACE quiche_apps::client] [::]:34630: processed 1350 bytes [2025-04-30T11:02:45.769371183Z TRACE quiche_apps::client] [::]:34630: recv() would block [2025-04-30T11:02:45.769373959Z TRACE quiche_apps::client] done reading [2025-04-30T11:02:45.769378858Z TRACE quiche_apps::client] [::]:34630 -> [fd00:cafe:cafe:100::100]:443: done writing [2025-04-30T11:02:45.770749460Z TRACE quiche_apps::client] got 1350 bytes from [fd00:cafe:cafe:100::100]:443 to [::]:34630 [2025-04-30T11:02:45.770767584Z TRACE quiche_apps::client] [::]:34630: processed 1350 bytes [2025-04-30T11:02:45.770774767Z TRACE quiche_apps::client] [::]:34630: recv() would block [2025-04-30T11:02:45.770779626Z TRACE quiche_apps::client] done reading [2025-04-30T11:02:45.770787120Z TRACE quiche_apps::client] [::]:34630 -> [fd00:cafe:cafe:100::100]:443: done writing [2025-04-30T11:02:45.776748324Z TRACE quiche_apps::client] got 1079 bytes from [fd00:cafe:cafe:100::100]:443 to [::]:34630 [2025-04-30T11:02:45.776762581Z TRACE quiche_apps::client] [::]:34630: processed 1079 bytes [2025-04-30T11:02:45.776767700Z TRACE quiche_apps::client] [::]:34630: recv() would block [2025-04-30T11:02:45.776777910Z TRACE quiche_apps::client] done reading [2025-04-30T11:02:45.776783229Z TRACE quiche_apps::client] [::]:34630 -> [fd00:cafe:cafe:100::100]:443: done writing [2025-04-30T11:02:45.779731907Z TRACE quiche_apps::client] got 55 bytes from [fd00:cafe:cafe:100::100]:443 to [::]:34630 [2025-04-30T11:02:45.779746264Z TRACE quiche_apps::client] [::]:34630: processed 55 bytes [2025-04-30T11:02:45.779751404Z TRACE quiche_apps::client] [::]:34630: recv() would block [2025-04-30T11:02:45.779754550Z TRACE quiche_apps::client] done reading [2025-04-30T11:02:45.779759589Z TRACE quiche_apps::client] [::]:34630 -> [fd00:cafe:cafe:100::100]:443: done writing [2025-04-30T11:02:45.786825326Z TRACE quiche_apps::client] got 1079 bytes from [fd00:cafe:cafe:100::100]:443 to [::]:34630 [2025-04-30T11:02:45.786839562Z TRACE quiche_apps::client] [::]:34630: processed 1079 bytes [2025-04-30T11:02:45.786844692Z TRACE quiche_apps::client] [::]:34630: recv() would block [2025-04-30T11:02:45.786847828Z TRACE quiche_apps::client] done reading [2025-04-30T11:02:45.786852867Z TRACE quiche_apps::client] [::]:34630 -> [fd00:cafe:cafe:100::100]:443: done writing [2025-04-30T11:02:45.796849709Z TRACE quiche_apps::client] got 1079 bytes from [fd00:cafe:cafe:100::100]:443 to [::]:34630 [2025-04-30T11:02:45.796861441Z TRACE quiche_apps::client] [::]:34630: processed 1079 bytes [2025-04-30T11:02:45.796865499Z TRACE quiche_apps::client] [::]:34630: recv() would block [2025-04-30T11:02:45.796868014Z TRACE quiche_apps::client] done reading [2025-04-30T11:02:45.796872331Z TRACE quiche_apps::client] [::]:34630 -> [fd00:cafe:cafe:100::100]:443: done writing [2025-04-30T11:02:45.797259124Z TRACE quiche_apps::client] got 43 bytes from [fd00:cafe:cafe:100::100]:443 to [::]:34630 [2025-04-30T11:02:45.797265626Z TRACE quiche_apps::client] [::]:34630: processed 43 bytes [2025-04-30T11:02:45.797268762Z TRACE quiche_apps::client] [::]:34630: recv() would block [2025-04-30T11:02:45.797270946Z TRACE quiche_apps::client] done reading [2025-04-30T11:02:45.797274182Z TRACE quiche_apps::client] [::]:34630 -> [fd00:cafe:cafe:100::100]:443: done writing [2025-04-30T11:02:46.098637479Z TRACE quiche_apps::client] timed out [2025-04-30T11:02:46.098669649Z TRACE quiche] cec065775e3f4d142918d49c5a4464bf32372780 draining timeout expired [2025-04-30T11:02:46.098716026Z TRACE quiche_apps::client] done reading [2025-04-30T11:02:46.098720815Z INFO quiche_apps::client] connection closed, recv=17 sent=22 lost=0 retrans=0 sent_bytes=2374 recv_bytes=18950 lost_bytes=0 [local_addr=[::]:34630 peer_addr=[fd00:cafe:cafe:100::100]:443 validation_state=Validated active=true recv=17 sent=22 lost=0 retrans=0 rtt=39.032494ms min_rtt=Some(29.568325ms) rttvar=17.848242ms cwnd=13500 sent_bytes=2374 recv_bytes=18950 lost_bytes=0 stream_retrans_bytes=0 pmtu=1350 delivery_rate=43520]