[2025-04-30T18:36:42.452783287Z TRACE mio::poll] registering event source with poller: token=Token(0), interests=READABLE [2025-04-30T18:36:42.453107514Z INFO quiche_apps::client] connecting to [fd00:cafe:cafe:100::100]:443 from [::]:46880 with scid ee7808f5aacbda14644368dc2911f360a1552160 [2025-04-30T18:36:42.453151045Z TRACE quiche::tls] ee7808f5aacbda14644368dc2911f360a1552160 write message lvl=Initial len=266 [2025-04-30T18:36:42.453166594Z TRACE quiche] ee7808f5aacbda14644368dc2911f360a1552160 tx pkt Initial version=1 dcid=65b130298718c193ed90077c3d291c3d scid=ee7808f5aacbda14644368dc2911f360a1552160 len=270 pn=0 [2025-04-30T18:36:42.453169710Z TRACE quiche] ee7808f5aacbda14644368dc2911f360a1552160 tx frm CRYPTO off=0 len=266 [2025-04-30T18:36:42.453184037Z TRACE quiche::recovery::congestion::recovery] ee7808f5aacbda14644368dc2911f360a1552160 timer=998.932774ms 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: 954, tv_nsec: 603141374 }, first_sent_time: Instant { tv_sec: 954, tv_nsec: 603141374 }, 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: 954, tv_nsec: 603141374 }, next_time: Instant { tv_sec: 954, tv_nsec: 603141374 }, 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-30T18:36:42.453242656Z TRACE quiche_apps::client] written 1200 [2025-04-30T18:36:42.493496035Z TRACE quiche_apps::client] got 1200 bytes from [fd00:cafe:cafe:100::100]:443 to [::]:46880 [2025-04-30T18:36:42.493525570Z TRACE quiche] ee7808f5aacbda14644368dc2911f360a1552160 rx pkt Initial version=1 dcid=ee7808f5aacbda14644368dc2911f360a1552160 scid=2e6d4629edf9c25318b454b516a2f148a9234bae token= len=116 pn=0 [2025-04-30T18:36:42.493542091Z TRACE quiche] ee7808f5aacbda14644368dc2911f360a1552160 rx frm ACK delay=48 blocks=[0..0] ecn_counts=None [2025-04-30T18:36:42.493549415Z TRACE quiche::recovery::congestion::recovery] ee7808f5aacbda14644368dc2911f360a1552160 packet newly acked 0 [2025-04-30T18:36:42.493556368Z TRACE quiche] ee7808f5aacbda14644368dc2911f360a1552160 rx frm CRYPTO off=0 len=90 [2025-04-30T18:36:42.493669640Z TRACE quiche::tls] ee7808f5aacbda14644368dc2911f360a1552160 set write secret lvl=Handshake [2025-04-30T18:36:42.493682203Z TRACE quiche::tls] ee7808f5aacbda14644368dc2911f360a1552160 set read secret lvl=Handshake [2025-04-30T18:36:42.493719423Z TRACE quiche] ee7808f5aacbda14644368dc2911f360a1552160 rx pkt Handshake version=1 dcid=ee7808f5aacbda14644368dc2911f360a1552160 scid=2e6d4629edf9c25318b454b516a2f148a9234bae len=719 pn=1 [2025-04-30T18:36:42.493726606Z TRACE quiche] ee7808f5aacbda14644368dc2911f360a1552160 rx frm CRYPTO off=0 len=698 [2025-04-30T18:36:42.493961966Z TRACE quiche::tls] ee7808f5aacbda14644368dc2911f360a1552160 write message lvl=Handshake len=36 [2025-04-30T18:36:42.493966675Z TRACE quiche::tls] ee7808f5aacbda14644368dc2911f360a1552160 set write secret lvl=OneRTT [2025-04-30T18:36:42.493974851Z TRACE quiche::tls] ee7808f5aacbda14644368dc2911f360a1552160 set read secret lvl=OneRTT [2025-04-30T18:36:42.494025174Z TRACE quiche] ee7808f5aacbda14644368dc2911f360a1552160 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(65b130298718c193ed90077c3d291c3d), max_idle_timeout: 30000, stateless_reset_token: None, max_udp_payload_size: 1350, initial_max_data: 10000000, initial_max_stream_data_bidi_local: 1000000, initial_max_stream_data_bidi_remote: 1000000, initial_max_stream_data_uni: 1000000, initial_max_streams_bidi: 100, initial_max_streams_uni: 100, ack_delay_exponent: 3, max_ack_delay: 25, disable_active_migration: true, active_conn_id_limit: 8, initial_source_connection_id: Some(2e6d4629edf9c25318b454b516a2f148a9234bae), retry_source_connection_id: None, max_datagram_frame_size: None, unknown_params: None } [2025-04-30T18:36:42.494064167Z TRACE quiche] ee7808f5aacbda14644368dc2911f360a1552160 rx pkt Short dcid=0000000000000000000000000000000000000000 key_phase=true len=245 pn=3692690425 [2025-04-30T18:36:42.494070930Z TRACE quiche] ee7808f5aacbda14644368dc2911f360a1552160 dropped invalid packet [2025-04-30T18:36:42.494074216Z TRACE quiche_apps::client] [::]:46880: processed 1200 bytes [2025-04-30T18:36:42.494079607Z TRACE quiche_apps::client] [::]:46880: recv() would block [2025-04-30T18:36:42.494082742Z TRACE quiche_apps::client] done reading [2025-04-30T18:36:42.494100696Z TRACE quiche::h3] ee7808f5aacbda14644368dc2911f360a1552160 tx frm SETTINGS stream=2 len=18 [2025-04-30T18:36:42.494116185Z TRACE quiche::h3] ee7808f5aacbda14644368dc2911f360a1552160 open GREASE stream 14 [2025-04-30T18:36:42.494125923Z TRACE quiche::h3] ee7808f5aacbda14644368dc2911f360a1552160 tx frm GREASE stream=0 len=0 [2025-04-30T18:36:42.494132756Z TRACE quiche::h3] ee7808f5aacbda14644368dc2911f360a1552160 tx frm GREASE stream=0 len=18 [2025-04-30T18:36:42.494141031Z TRACE quiche::h3] ee7808f5aacbda14644368dc2911f360a1552160 tx frm HEADERS stream=0 len=30 fin=true [2025-04-30T18:36:42.494148806Z DEBUG quiche_apps::common] Sent HTTP request [":method: GET", ":scheme: https", ":authority: server6", ":path: /qwyhvbhaqw", "user-agent: quiche"] [2025-04-30T18:36:42.494212846Z TRACE quiche::h3] ee7808f5aacbda14644368dc2911f360a1552160 tx frm HEADERS stream=4 len=30 fin=true [2025-04-30T18:36:42.494219899Z DEBUG quiche_apps::common] Sent HTTP request [":method: GET", ":scheme: https", ":authority: server6", ":path: /gbyaipazka", "user-agent: quiche"] [2025-04-30T18:36:42.494274130Z TRACE quiche] ee7808f5aacbda14644368dc2911f360a1552160 tx pkt Initial version=1 dcid=2e6d4629edf9c25318b454b516a2f148a9234bae scid=ee7808f5aacbda14644368dc2911f360a1552160 len=6 pn=1 [2025-04-30T18:36:42.494278238Z TRACE quiche] ee7808f5aacbda14644368dc2911f360a1552160 tx frm ACK delay=94 blocks=[0..0] ecn_counts=None [2025-04-30T18:36:42.494288958Z TRACE quiche::recovery::congestion::recovery] ee7808f5aacbda14644368dc2911f360a1552160 timer=120.435548ms latest_rtt=40.401926ms srtt=40.401926ms min_rtt=40.401926ms rttvar=20.200963ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=0 app_limited=true congestion_recovery_start_time=None Rate { delivered: 333, delivered_time: Instant { tv_sec: 954, tv_nsec: 644046982 }, first_sent_time: Instant { tv_sec: 954, tv_nsec: 644046982 }, end_of_app_limited: 1, last_sent_packet: 1, largest_acked: 0, rate_sample: RateSample { delivery_rate: 8242, is_app_limited: true, interval: 40.401926ms, delivered: 333, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 954, tv_nsec: 603141374 }), send_elapsed: 0ns, ack_elapsed: 40.401926ms, rtt: 40.401926ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 417678, last_update: Instant { tv_sec: 954, tv_nsec: 644046942 }, next_time: Instant { tv_sec: 954, tv_nsec: 644046982 }, 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-30T18:36:42.494313113Z TRACE quiche] ee7808f5aacbda14644368dc2911f360a1552160 tx pkt Handshake version=1 dcid=2e6d4629edf9c25318b454b516a2f148a9234bae scid=ee7808f5aacbda14644368dc2911f360a1552160 len=46 pn=2 [2025-04-30T18:36:42.494316590Z TRACE quiche] ee7808f5aacbda14644368dc2911f360a1552160 tx frm ACK delay=74 blocks=[1..1] ecn_counts=None [2025-04-30T18:36:42.494325977Z TRACE quiche] ee7808f5aacbda14644368dc2911f360a1552160 tx frm CRYPTO off=0 len=36 [2025-04-30T18:36:42.494333371Z TRACE quiche::recovery::congestion::recovery] ee7808f5aacbda14644368dc2911f360a1552160 timer=121.136248ms latest_rtt=40.401926ms srtt=40.401926ms min_rtt=40.401926ms rttvar=20.200963ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=112 app_limited=true congestion_recovery_start_time=None Rate { delivered: 333, delivered_time: Instant { tv_sec: 954, tv_nsec: 644046982 }, first_sent_time: Instant { tv_sec: 954, tv_nsec: 644046982 }, end_of_app_limited: 1, last_sent_packet: 2, largest_acked: 0, rate_sample: RateSample { delivery_rate: 8242, is_app_limited: true, interval: 40.401926ms, delivered: 333, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 954, tv_nsec: 603141374 }), send_elapsed: 0ns, ack_elapsed: 40.401926ms, rtt: 40.401926ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 417678, last_update: Instant { tv_sec: 954, tv_nsec: 644288153 }, next_time: Instant { tv_sec: 954, tv_nsec: 644046982 }, max_datagram_size: 1350, last_packet_size: None, iv: 268.149µ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-30T18:36:42.494346676Z TRACE quiche] ee7808f5aacbda14644368dc2911f360a1552160 dropped epoch 0 state [2025-04-30T18:36:42.494352637Z TRACE quiche] ee7808f5aacbda14644368dc2911f360a1552160 pmtud probe status false hs_con=false hs_sent=false cwnd_avail=13388 out_len=1165 left=1127 [2025-04-30T18:36:42.494366553Z TRACE quiche] ee7808f5aacbda14644368dc2911f360a1552160 tx pkt Short dcid=2e6d4629edf9c25318b454b516a2f148a9234bae key_phase=false len=1127 pn=3 [2025-04-30T18:36:42.494369709Z TRACE quiche] ee7808f5aacbda14644368dc2911f360a1552160 tx frm NEW_CONNECTION_ID seq_num=1 retire_prior_to=0 conn_id=[23, 4e, aa, 70, 68, bb, 0b, be, 03, 41, 34, 44, 99, fd, 51, 79, cc, 62, 94, 5e] reset_token=[af, 00, 7d, 84, 70, 09, 52, 35, 1b, 22, 43, 96, b5, c0, bd, e6] [2025-04-30T18:36:42.494377994Z TRACE quiche] ee7808f5aacbda14644368dc2911f360a1552160 tx frm NEW_CONNECTION_ID seq_num=2 retire_prior_to=0 conn_id=[6f, 1c, 91, a6, 14, 4e, af, 70, 87, 3d, 9c, 7e, a2, 8c, 58, 79, 37, 36, 58, 2b] reset_token=[5c, 58, 8e, c4, a3, 66, 10, cc, ac, 34, 07, 90, bc, d0, c7, 94] [2025-04-30T18:36:42.494384266Z TRACE quiche] ee7808f5aacbda14644368dc2911f360a1552160 tx frm NEW_CONNECTION_ID seq_num=3 retire_prior_to=0 conn_id=[9b, 3a, 0e, f6, 4f, 53, 3f, 04, 9e, 21, a7, 04, cf, 91, 60, 6a, 91, c5, 93, 0b] reset_token=[05, 74, 7a, 26, dc, aa, cc, 92, 2a, a9, 0b, 8b, a6, 26, de, 7d] [2025-04-30T18:36:42.494390728Z TRACE quiche] ee7808f5aacbda14644368dc2911f360a1552160 tx frm NEW_CONNECTION_ID seq_num=4 retire_prior_to=0 conn_id=[aa, 0e, db, 0d, 7c, c5, 22, e0, 0e, 27, f5, 04, af, 25, 6a, 8b, 27, 58, 84, 7c] reset_token=[4b, 26, 01, 06, 30, 6b, bc, 51, b2, 87, f1, f8, dd, f3, 1c, 66] [2025-04-30T18:36:42.494397160Z TRACE quiche] ee7808f5aacbda14644368dc2911f360a1552160 tx frm NEW_CONNECTION_ID seq_num=5 retire_prior_to=0 conn_id=[70, d9, 09, 4c, fc, 5e, f9, a6, e8, f7, 23, 65, 3a, 0d, 22, fe, a4, 43, c2, a1] reset_token=[83, 72, 0b, 21, 0d, a2, 24, a1, 57, ec, 87, 48, 5d, 90, e6, 7e] [2025-04-30T18:36:42.494403302Z TRACE quiche] ee7808f5aacbda14644368dc2911f360a1552160 tx frm NEW_CONNECTION_ID seq_num=6 retire_prior_to=0 conn_id=[70, 9e, 54, 28, 25, ba, 3d, de, 6c, 9e, fb, e1, e1, 73, c6, d4, 2b, d3, 92, 38] reset_token=[dd, a6, 22, 4b, 17, 10, 61, b3, 5c, a1, a1, 35, 68, 3c, 18, a1] [2025-04-30T18:36:42.494409243Z TRACE quiche] ee7808f5aacbda14644368dc2911f360a1552160 tx frm NEW_CONNECTION_ID seq_num=7 retire_prior_to=0 conn_id=[51, 69, 3b, 5e, 9e, 7f, 18, 05, 92, 6f, 6a, 06, 87, a5, 28, 80, a6, 52, c6, 2c] reset_token=[b4, a6, 26, 0b, 76, f4, 29, 32, a8, ac, 83, 8d, 72, f1, 57, c9] [2025-04-30T18:36:42.494419151Z TRACE quiche] ee7808f5aacbda14644368dc2911f360a1552160 tx frm STREAM id=2 off=0 len=19 fin=false [2025-04-30T18:36:42.494422408Z TRACE quiche] ee7808f5aacbda14644368dc2911f360a1552160 tx frm PADDING len=823 [2025-04-30T18:36:42.494450600Z TRACE quiche::recovery::congestion::recovery] ee7808f5aacbda14644368dc2911f360a1552160 timer=121.018908ms latest_rtt=40.401926ms srtt=40.401926ms min_rtt=40.401926ms rttvar=20.200963ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=1277 app_limited=true congestion_recovery_start_time=None Rate { delivered: 333, delivered_time: Instant { tv_sec: 954, tv_nsec: 644046982 }, first_sent_time: Instant { tv_sec: 954, tv_nsec: 644046982 }, end_of_app_limited: 2, last_sent_packet: 3, largest_acked: 0, rate_sample: RateSample { delivery_rate: 8242, is_app_limited: true, interval: 40.401926ms, delivered: 333, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 954, tv_nsec: 603141374 }), send_elapsed: 0ns, ack_elapsed: 40.401926ms, rtt: 40.401926ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 1165, rate: 417678, last_update: Instant { tv_sec: 954, tv_nsec: 644288153 }, next_time: Instant { tv_sec: 954, tv_nsec: 644556302 }, max_datagram_size: 1350, last_packet_size: Some(1165), 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-30T18:36:42.494495945Z TRACE quiche_apps::client] written 1350 bytes from [::]:46880 to [fd00:cafe:cafe:100::100]:443 [2025-04-30T18:36:42.494504431Z TRACE quiche] ee7808f5aacbda14644368dc2911f360a1552160 pmtud probe status false hs_con=false hs_sent=false cwnd_avail=12223 out_len=1350 left=1312 [2025-04-30T18:36:42.494508669Z TRACE quiche] ee7808f5aacbda14644368dc2911f360a1552160 tx pkt Short dcid=2e6d4629edf9c25318b454b516a2f148a9234bae key_phase=false len=6 pn=4 [2025-04-30T18:36:42.494512015Z TRACE quiche] ee7808f5aacbda14644368dc2911f360a1552160 tx frm STREAM id=6 off=0 len=1 fin=false [2025-04-30T18:36:42.494518778Z TRACE quiche::recovery::congestion::recovery] ee7808f5aacbda14644368dc2911f360a1552160 timer=120.950901ms latest_rtt=40.401926ms srtt=40.401926ms min_rtt=40.401926ms rttvar=20.200963ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=1321 app_limited=true congestion_recovery_start_time=None Rate { delivered: 333, delivered_time: Instant { tv_sec: 954, tv_nsec: 644046982 }, first_sent_time: Instant { tv_sec: 954, tv_nsec: 644046982 }, end_of_app_limited: 3, last_sent_packet: 4, largest_acked: 0, rate_sample: RateSample { delivery_rate: 8242, is_app_limited: true, interval: 40.401926ms, delivered: 333, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 954, tv_nsec: 603141374 }), send_elapsed: 0ns, ack_elapsed: 40.401926ms, rtt: 40.401926ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 417678, last_update: Instant { tv_sec: 954, tv_nsec: 644524996 }, next_time: Instant { tv_sec: 954, tv_nsec: 644556302 }, max_datagram_size: 1350, last_packet_size: None, iv: 2.894574ms, 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-30T18:36:42.494546199Z TRACE quiche_apps::client] written 44 bytes from [::]:46880 to [fd00:cafe:cafe:100::100]:443 [2025-04-30T18:36:42.494552361Z TRACE quiche] ee7808f5aacbda14644368dc2911f360a1552160 pmtud probe status false hs_con=false hs_sent=false cwnd_avail=12179 out_len=1350 left=1312 [2025-04-30T18:36:42.494556348Z TRACE quiche] ee7808f5aacbda14644368dc2911f360a1552160 tx pkt Short dcid=2e6d4629edf9c25318b454b516a2f148a9234bae key_phase=false len=6 pn=5 [2025-04-30T18:36:42.494559364Z TRACE quiche] ee7808f5aacbda14644368dc2911f360a1552160 tx frm STREAM id=10 off=0 len=1 fin=false [2025-04-30T18:36:42.494570144Z TRACE quiche::recovery::congestion::recovery] ee7808f5aacbda14644368dc2911f360a1552160 timer=120.899495ms latest_rtt=40.401926ms srtt=40.401926ms min_rtt=40.401926ms rttvar=20.200963ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=1365 app_limited=true congestion_recovery_start_time=None Rate { delivered: 333, delivered_time: Instant { tv_sec: 954, tv_nsec: 644046982 }, first_sent_time: Instant { tv_sec: 954, tv_nsec: 644046982 }, end_of_app_limited: 4, last_sent_packet: 5, largest_acked: 0, rate_sample: RateSample { delivery_rate: 8242, is_app_limited: true, interval: 40.401926ms, delivered: 333, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 954, tv_nsec: 603141374 }), send_elapsed: 0ns, ack_elapsed: 40.401926ms, rtt: 40.401926ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 44, rate: 417678, last_update: Instant { tv_sec: 954, tv_nsec: 644524996 }, next_time: Instant { tv_sec: 954, tv_nsec: 647468471 }, max_datagram_size: 1350, last_packet_size: Some(44), 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-30T18:36:42.494596213Z TRACE quiche_apps::client] written 44 bytes from [::]:46880 to [fd00:cafe:cafe:100::100]:443 [2025-04-30T18:36:42.494602234Z TRACE quiche] ee7808f5aacbda14644368dc2911f360a1552160 pmtud probe status false hs_con=false hs_sent=false cwnd_avail=12135 out_len=1350 left=1312 [2025-04-30T18:36:42.494606201Z TRACE quiche] ee7808f5aacbda14644368dc2911f360a1552160 tx pkt Short dcid=2e6d4629edf9c25318b454b516a2f148a9234bae key_phase=false len=73 pn=6 [2025-04-30T18:36:42.494609337Z TRACE quiche] ee7808f5aacbda14644368dc2911f360a1552160 tx frm STREAM id=0 off=0 len=68 fin=true [2025-04-30T18:36:42.494615358Z TRACE quiche::recovery::congestion::recovery] ee7808f5aacbda14644368dc2911f360a1552160 timer=120.85426ms latest_rtt=40.401926ms srtt=40.401926ms min_rtt=40.401926ms rttvar=20.200963ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=1476 app_limited=true congestion_recovery_start_time=None Rate { delivered: 333, delivered_time: Instant { tv_sec: 954, tv_nsec: 644046982 }, first_sent_time: Instant { tv_sec: 954, tv_nsec: 644046982 }, end_of_app_limited: 5, last_sent_packet: 6, largest_acked: 0, rate_sample: RateSample { delivery_rate: 8242, is_app_limited: true, interval: 40.401926ms, delivered: 333, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 954, tv_nsec: 603141374 }), send_elapsed: 0ns, ack_elapsed: 40.401926ms, rtt: 40.401926ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 417678, last_update: Instant { tv_sec: 954, tv_nsec: 644623851 }, next_time: Instant { tv_sec: 954, tv_nsec: 647468471 }, max_datagram_size: 1350, last_packet_size: None, iv: 371.099µ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-30T18:36:42.494639604Z TRACE quiche_apps::client] written 111 bytes from [::]:46880 to [fd00:cafe:cafe:100::100]:443 [2025-04-30T18:36:42.494645334Z TRACE quiche] ee7808f5aacbda14644368dc2911f360a1552160 pmtud probe status false hs_con=false hs_sent=false cwnd_avail=12024 out_len=1350 left=1312 [2025-04-30T18:36:42.494649122Z TRACE quiche] ee7808f5aacbda14644368dc2911f360a1552160 tx pkt Short dcid=2e6d4629edf9c25318b454b516a2f148a9234bae key_phase=false len=37 pn=7 [2025-04-30T18:36:42.494652177Z TRACE quiche] ee7808f5aacbda14644368dc2911f360a1552160 tx frm STREAM id=4 off=0 len=32 fin=true [2025-04-30T18:36:42.494658089Z TRACE quiche::recovery::congestion::recovery] ee7808f5aacbda14644368dc2911f360a1552160 timer=120.81156ms latest_rtt=40.401926ms srtt=40.401926ms min_rtt=40.401926ms rttvar=20.200963ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=1551 app_limited=true congestion_recovery_start_time=None Rate { delivered: 333, delivered_time: Instant { tv_sec: 954, tv_nsec: 644046982 }, first_sent_time: Instant { tv_sec: 954, tv_nsec: 644046982 }, end_of_app_limited: 6, last_sent_packet: 7, largest_acked: 0, rate_sample: RateSample { delivery_rate: 8242, is_app_limited: true, interval: 40.401926ms, delivered: 333, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 954, tv_nsec: 603141374 }), send_elapsed: 0ns, ack_elapsed: 40.401926ms, rtt: 40.401926ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 75, rate: 417678, last_update: Instant { tv_sec: 954, tv_nsec: 644623851 }, next_time: Instant { tv_sec: 954, tv_nsec: 647839570 }, max_datagram_size: 1350, last_packet_size: Some(75), 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-30T18:36:42.494688105Z TRACE quiche_apps::client] written 75 bytes from [::]:46880 to [fd00:cafe:cafe:100::100]:443 [2025-04-30T18:36:42.494694386Z TRACE quiche] ee7808f5aacbda14644368dc2911f360a1552160 pmtud probe status false hs_con=false hs_sent=false cwnd_avail=11949 out_len=1350 left=1312 [2025-04-30T18:36:42.494698213Z TRACE quiche] ee7808f5aacbda14644368dc2911f360a1552160 tx pkt Short dcid=2e6d4629edf9c25318b454b516a2f148a9234bae key_phase=false len=31 pn=8 [2025-04-30T18:36:42.494701329Z TRACE quiche] ee7808f5aacbda14644368dc2911f360a1552160 tx frm STREAM id=14 off=0 len=26 fin=true [2025-04-30T18:36:42.494707281Z TRACE quiche::recovery::congestion::recovery] ee7808f5aacbda14644368dc2911f360a1552160 timer=120.762328ms latest_rtt=40.401926ms srtt=40.401926ms min_rtt=40.401926ms rttvar=20.200963ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=1620 app_limited=true congestion_recovery_start_time=None Rate { delivered: 333, delivered_time: Instant { tv_sec: 954, tv_nsec: 644046982 }, first_sent_time: Instant { tv_sec: 954, tv_nsec: 644046982 }, end_of_app_limited: 7, last_sent_packet: 8, largest_acked: 0, rate_sample: RateSample { delivery_rate: 8242, is_app_limited: true, interval: 40.401926ms, delivered: 333, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 954, tv_nsec: 603141374 }), send_elapsed: 0ns, ack_elapsed: 40.401926ms, rtt: 40.401926ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 417678, last_update: Instant { tv_sec: 954, tv_nsec: 644715873 }, next_time: Instant { tv_sec: 954, tv_nsec: 647839570 }, max_datagram_size: 1350, last_packet_size: None, iv: 344.763µ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-30T18:36:42.494731185Z TRACE quiche_apps::client] written 69 bytes from [::]:46880 to [fd00:cafe:cafe:100::100]:443 [2025-04-30T18:36:42.494735303Z TRACE quiche_apps::client] [::]:46880 -> [fd00:cafe:cafe:100::100]:443: done writing [2025-04-30T18:36:42.527786561Z TRACE quiche_apps::client] got 748 bytes from [fd00:cafe:cafe:100::100]:443 to [::]:46880 [2025-04-30T18:36:42.527820184Z TRACE quiche] ee7808f5aacbda14644368dc2911f360a1552160 rx pkt Short dcid=ee7808f5aacbda14644368dc2911f360a1552160 key_phase=false len=727 pn=2 [2025-04-30T18:36:42.527836785Z TRACE quiche] ee7808f5aacbda14644368dc2911f360a1552160 rx frm ACK delay=4 blocks=[3..8] ecn_counts=None [2025-04-30T18:36:42.527844199Z TRACE quiche::recovery::congestion::recovery] ee7808f5aacbda14644368dc2911f360a1552160 packet newly acked 3 [2025-04-30T18:36:42.527849258Z TRACE quiche::recovery::congestion::recovery] ee7808f5aacbda14644368dc2911f360a1552160 packet newly acked 4 [2025-04-30T18:36:42.527852595Z TRACE quiche::recovery::congestion::recovery] ee7808f5aacbda14644368dc2911f360a1552160 packet newly acked 5 [2025-04-30T18:36:42.527865048Z TRACE quiche::recovery::congestion::recovery] ee7808f5aacbda14644368dc2911f360a1552160 packet newly acked 6 [2025-04-30T18:36:42.527868545Z TRACE quiche::recovery::congestion::recovery] ee7808f5aacbda14644368dc2911f360a1552160 packet newly acked 7 [2025-04-30T18:36:42.527871250Z TRACE quiche::recovery::congestion::recovery] ee7808f5aacbda14644368dc2911f360a1552160 packet newly acked 8 [2025-04-30T18:36:42.527880507Z TRACE quiche] ee7808f5aacbda14644368dc2911f360a1552160 rx frm NEW_CONNECTION_ID seq_num=1 retire_prior_to=0 conn_id=[c7, 16, e5, c0, e4, 80, a5, ee, e3, 4a, 5f, 64, 86, cb, 8c, 85, a8, 2f, d2, c9] reset_token=[13, 27, 64, db, 55, 50, eb, 2c, 46, 48, d6, 96, 97, 4d, 39, d1] [2025-04-30T18:36:42.527891408Z TRACE quiche] ee7808f5aacbda14644368dc2911f360a1552160 rx frm NEW_CONNECTION_ID seq_num=2 retire_prior_to=0 conn_id=[4a, 44, e8, 3d, a6, 5f, 31, ea, a3, dd, fe, ec, 5a, c4, 3d, ce, b4, 6d, c1, a5] reset_token=[0d, 26, c7, fa, d2, 79, 3f, 83, 91, b4, 08, 2c, 7a, a1, 2d, fc] [2025-04-30T18:36:42.527898521Z TRACE quiche] ee7808f5aacbda14644368dc2911f360a1552160 rx frm NEW_CONNECTION_ID seq_num=3 retire_prior_to=0 conn_id=[36, 30, 3d, de, 85, cd, d2, d8, c2, 16, 16, ed, 2d, db, ce, 25, 76, e9, 6f, 2f] reset_token=[85, 59, 51, 58, 85, 09, 54, b4, c7, 41, cd, c1, 25, 00, 95, c4] [2025-04-30T18:36:42.527905293Z TRACE quiche] ee7808f5aacbda14644368dc2911f360a1552160 rx frm NEW_CONNECTION_ID seq_num=4 retire_prior_to=0 conn_id=[ff, bd, a7, 96, d6, 3f, 4d, 48, 5c, 4a, 73, 33, c6, 77, 0e, 99, 20, a4, a4, 61] reset_token=[a9, e3, 97, 5f, cd, 14, 56, 14, 1e, cc, 17, 39, e3, 6a, ad, 22] [2025-04-30T18:36:42.527912026Z TRACE quiche] ee7808f5aacbda14644368dc2911f360a1552160 rx frm NEW_CONNECTION_ID seq_num=5 retire_prior_to=0 conn_id=[61, 92, 76, 9c, 49, b4, bb, 00, a1, bd, d1, 75, 60, ca, b8, 0f, c6, 5c, dc, 24] reset_token=[a8, 2d, da, 73, b5, df, c4, 1a, 33, fe, 33, 90, 4a, d3, 37, fd] [2025-04-30T18:36:42.527918438Z TRACE quiche] ee7808f5aacbda14644368dc2911f360a1552160 rx frm NEW_CONNECTION_ID seq_num=6 retire_prior_to=0 conn_id=[76, e1, b4, 39, 71, 34, 92, f0, d7, 1e, d5, 0d, 88, 1c, 78, f8, 4e, eb, 63, 4b] reset_token=[14, 22, d5, 7f, a4, 1d, f3, ad, 75, 35, fb, 08, b7, a4, 2e, 58] [2025-04-30T18:36:42.527924870Z TRACE quiche] ee7808f5aacbda14644368dc2911f360a1552160 rx frm NEW_CONNECTION_ID seq_num=7 retire_prior_to=0 conn_id=[09, 1f, 04, 9d, 25, e3, 91, 69, 4b, d3, 55, 08, 00, 75, b2, 21, 17, 09, 6a, 1c] reset_token=[af, 9f, d8, 3a, 00, 9e, ec, 6f, da, 4b, 89, 05, ed, de, 57, 82] [2025-04-30T18:36:42.527930200Z TRACE quiche] ee7808f5aacbda14644368dc2911f360a1552160 rx frm HANDSHAKE_DONE [2025-04-30T18:36:42.527936592Z TRACE quiche] ee7808f5aacbda14644368dc2911f360a1552160 dropped epoch 1 state [2025-04-30T18:36:42.527940649Z TRACE quiche] ee7808f5aacbda14644368dc2911f360a1552160 rx frm CRYPTO off=0 len=396 [2025-04-30T18:36:42.527973762Z TRACE quiche] ee7808f5aacbda14644368dc2911f360a1552160 rx frm STREAM id=3 off=0 len=19 fin=false [2025-04-30T18:36:42.528043662Z TRACE quiche_apps::client] [::]:46880: processed 748 bytes [2025-04-30T18:36:42.528052469Z TRACE quiche_apps::client] got 44 bytes from [fd00:cafe:cafe:100::100]:443 to [::]:46880 [2025-04-30T18:36:42.528057518Z TRACE quiche] ee7808f5aacbda14644368dc2911f360a1552160 rx pkt Short dcid=ee7808f5aacbda14644368dc2911f360a1552160 key_phase=false len=23 pn=3 [2025-04-30T18:36:42.528063138Z TRACE quiche] ee7808f5aacbda14644368dc2911f360a1552160 rx frm STREAM id=7 off=0 len=1 fin=false [2025-04-30T18:36:42.528069450Z TRACE quiche_apps::client] [::]:46880: processed 44 bytes [2025-04-30T18:36:42.528074710Z TRACE quiche_apps::client] got 44 bytes from [fd00:cafe:cafe:100::100]:443 to [::]:46880 [2025-04-30T18:36:42.528078357Z TRACE quiche] ee7808f5aacbda14644368dc2911f360a1552160 rx pkt Short dcid=ee7808f5aacbda14644368dc2911f360a1552160 key_phase=false len=23 pn=4 [2025-04-30T18:36:42.528082595Z TRACE quiche] ee7808f5aacbda14644368dc2911f360a1552160 rx frm STREAM id=11 off=0 len=1 fin=false [2025-04-30T18:36:42.528095770Z TRACE quiche_apps::client] [::]:46880: processed 44 bytes [2025-04-30T18:36:42.528100248Z TRACE quiche_apps::client] [::]:46880: recv() would block [2025-04-30T18:36:42.528103354Z TRACE quiche_apps::client] done reading [2025-04-30T18:36:42.528107452Z TRACE quiche::h3] ee7808f5aacbda14644368dc2911f360a1552160 stream id 3 is readable [2025-04-30T18:36:42.528114414Z TRACE quiche::h3::stream] ee7808f5aacbda14644368dc2911f360a1552160 read 1 bytes on stream 3 [2025-04-30T18:36:42.528121127Z TRACE quiche::h3] ee7808f5aacbda14644368dc2911f360a1552160 open peer's control stream 3 [2025-04-30T18:36:42.528125455Z TRACE quiche::h3::stream] ee7808f5aacbda14644368dc2911f360a1552160 read 1 bytes on stream 3 [2025-04-30T18:36:42.528129342Z TRACE quiche::h3::stream] ee7808f5aacbda14644368dc2911f360a1552160 read 1 bytes on stream 3 [2025-04-30T18:36:42.528133390Z TRACE quiche::h3::stream] ee7808f5aacbda14644368dc2911f360a1552160 read 16 bytes on stream 3 [2025-04-30T18:36:42.528137287Z TRACE quiche::h3] ee7808f5aacbda14644368dc2911f360a1552160 rx frm SETTINGS max_field_section=None, qpack_max_table=None, qpack_blocked=None raw=Some([(4375190826257594162, 3659943718188453302)]), additional_settings=Some([(4375190826257594162, 3659943718188453302)]) stream=3 payload_len=16 [2025-04-30T18:36:42.528146925Z TRACE quiche::h3] ee7808f5aacbda14644368dc2911f360a1552160 stream id 7 is readable [2025-04-30T18:36:42.528151804Z TRACE quiche::h3::stream] ee7808f5aacbda14644368dc2911f360a1552160 read 1 bytes on stream 7 [2025-04-30T18:36:42.528156243Z TRACE quiche::h3] ee7808f5aacbda14644368dc2911f360a1552160 stream id 11 is readable [2025-04-30T18:36:42.528160360Z TRACE quiche::h3::stream] ee7808f5aacbda14644368dc2911f360a1552160 read 1 bytes on stream 11 [2025-04-30T18:36:42.528172714Z TRACE quiche] ee7808f5aacbda14644368dc2911f360a1552160 pmtud probe status false hs_con=true hs_sent=false cwnd_avail=13500 out_len=1350 left=1307 [2025-04-30T18:36:42.528178935Z TRACE quiche] ee7808f5aacbda14644368dc2911f360a1552160 tx pkt Short dcid=2e6d4629edf9c25318b454b516a2f148a9234bae key_phase=false len=5 pn=9 [2025-04-30T18:36:42.528182091Z TRACE quiche] ee7808f5aacbda14644368dc2911f360a1552160 tx frm ACK delay=11 blocks=[2..4] ecn_counts=None [2025-04-30T18:36:42.528191238Z TRACE quiche::recovery::congestion::recovery] ee7808f5aacbda14644368dc2911f360a1552160 timer=none latest_rtt=29.998885ms srtt=39.101545ms min_rtt=29.998885ms rttvar=17.751482ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=0 app_limited=true congestion_recovery_start_time=None Rate { delivered: 1841, delivered_time: Instant { tv_sec: 954, tv_nsec: 678535817 }, first_sent_time: Instant { tv_sec: 954, tv_nsec: 678535817 }, end_of_app_limited: 8, last_sent_packet: 9, largest_acked: 8, rate_sample: RateSample { delivery_rate: 44626, is_app_limited: true, interval: 33.791473ms, delivered: 1508, prior_delivered: 333, prior_time: Some(Instant { tv_sec: 954, tv_nsec: 644046982 }), send_elapsed: 509.32µs, ack_elapsed: 33.791473ms, rtt: 33.282153ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 431568, last_update: Instant { tv_sec: 954, tv_nsec: 678191054 }, next_time: Instant { tv_sec: 954, tv_nsec: 678535817 }, 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-30T18:36:42.528245730Z TRACE quiche_apps::client] written 43 bytes from [::]:46880 to [fd00:cafe:cafe:100::100]:443 [2025-04-30T18:36:42.528251601Z TRACE quiche_apps::client] [::]:46880 -> [fd00:cafe:cafe:100::100]:443: done writing [2025-04-30T18:36:42.528997466Z TRACE quiche_apps::client] got 1350 bytes from [fd00:cafe:cafe:100::100]:443 to [::]:46880 [2025-04-30T18:36:42.529007946Z TRACE quiche] ee7808f5aacbda14644368dc2911f360a1552160 rx pkt Short dcid=ee7808f5aacbda14644368dc2911f360a1552160 key_phase=false len=1329 pn=5 [2025-04-30T18:36:42.529020008Z TRACE quiche] ee7808f5aacbda14644368dc2911f360a1552160 rx frm STREAM id=0 off=0 len=1307 fin=false [2025-04-30T18:36:42.529038172Z TRACE quiche_apps::client] [::]:46880: processed 1350 bytes [2025-04-30T18:36:42.529041919Z TRACE quiche_apps::client] [::]:46880: recv() would block [2025-04-30T18:36:42.529044173Z TRACE quiche_apps::client] done reading [2025-04-30T18:36:42.529046808Z TRACE quiche::h3] ee7808f5aacbda14644368dc2911f360a1552160 stream id 0 is readable [2025-04-30T18:36:42.529050766Z TRACE quiche::h3::stream] ee7808f5aacbda14644368dc2911f360a1552160 read 1 bytes on stream 0 [2025-04-30T18:36:42.529054072Z TRACE quiche::h3::stream] ee7808f5aacbda14644368dc2911f360a1552160 read 7 bytes on stream 0 [2025-04-30T18:36:42.529057088Z TRACE quiche::h3::stream] ee7808f5aacbda14644368dc2911f360a1552160 read 1 bytes on stream 0 [2025-04-30T18:36:42.529059662Z TRACE quiche::h3] ee7808f5aacbda14644368dc2911f360a1552160 rx frm UNKNOWN raw_type=3055430620091918287 stream=0 payload_len=0 [2025-04-30T18:36:42.529064371Z TRACE quiche::h3::stream] ee7808f5aacbda14644368dc2911f360a1552160 read 1 bytes on stream 0 [2025-04-30T18:36:42.529067337Z TRACE quiche::h3::stream] ee7808f5aacbda14644368dc2911f360a1552160 read 7 bytes on stream 0 [2025-04-30T18:36:42.529070312Z TRACE quiche::h3::stream] ee7808f5aacbda14644368dc2911f360a1552160 read 1 bytes on stream 0 [2025-04-30T18:36:42.529073669Z TRACE quiche::h3::stream] ee7808f5aacbda14644368dc2911f360a1552160 read 18 bytes on stream 0 [2025-04-30T18:36:42.529076063Z TRACE quiche::h3] ee7808f5aacbda14644368dc2911f360a1552160 rx frm UNKNOWN raw_type=4231112224256253921 stream=0 payload_len=18 [2025-04-30T18:36:42.529079860Z TRACE quiche::h3::stream] ee7808f5aacbda14644368dc2911f360a1552160 read 1 bytes on stream 0 [2025-04-30T18:36:42.529082836Z TRACE quiche::h3::stream] ee7808f5aacbda14644368dc2911f360a1552160 read 1 bytes on stream 0 [2025-04-30T18:36:42.529085761Z TRACE quiche::h3::stream] ee7808f5aacbda14644368dc2911f360a1552160 read 16 bytes on stream 0 [2025-04-30T18:36:42.529088106Z TRACE quiche::h3] ee7808f5aacbda14644368dc2911f360a1552160 rx frm HEADERS stream=0 payload_len=16 [2025-04-30T18:36:42.529091081Z TRACE quiche::h3::qpack::decoder] Header count=0 base=0 [2025-04-30T18:36:42.529093666Z TRACE quiche::h3::qpack::decoder] Indexed index=25 static=true [2025-04-30T18:36:42.529097603Z TRACE quiche::h3::qpack::decoder] Literal name_idx=92 static=true value=[113, 117, 105, 99, 104, 101] [2025-04-30T18:36:42.529101320Z TRACE quiche::h3::qpack::decoder] Literal name_idx=4 static=true value=[53, 49, 50, 48] [2025-04-30T18:36:42.529108153Z DEBUG quiche_apps::common] got response headers [(":status", "200"), ("server", "quiche"), ("content-length", "5120")] on stream id 0 [2025-04-30T18:36:42.529112641Z TRACE quiche::h3] ee7808f5aacbda14644368dc2911f360a1552160 stream id 0 is readable [2025-04-30T18:36:42.529115507Z TRACE quiche::h3::stream] ee7808f5aacbda14644368dc2911f360a1552160 read 1 bytes on stream 0 [2025-04-30T18:36:42.529118442Z TRACE quiche::h3::stream] ee7808f5aacbda14644368dc2911f360a1552160 read 1 bytes on stream 0 [2025-04-30T18:36:42.529121308Z TRACE quiche::h3::stream] ee7808f5aacbda14644368dc2911f360a1552160 read 1 bytes on stream 0 [2025-04-30T18:36:42.529123552Z TRACE quiche::h3] ee7808f5aacbda14644368dc2911f360a1552160 rx frm DATA stream=0 wire_payload_len=5120 [2025-04-30T18:36:42.529128170Z DEBUG quiche_apps::common] got 1250 bytes of response data on stream 0 [2025-04-30T18:36:42.529135454Z TRACE quiche] ee7808f5aacbda14644368dc2911f360a1552160 pmtud probe status false hs_con=true hs_sent=false cwnd_avail=13500 out_len=1350 left=1307 [2025-04-30T18:36:42.529138590Z TRACE quiche] ee7808f5aacbda14644368dc2911f360a1552160 tx pkt Short dcid=2e6d4629edf9c25318b454b516a2f148a9234bae key_phase=false len=5 pn=10 [2025-04-30T18:36:42.529141055Z TRACE quiche] ee7808f5aacbda14644368dc2911f360a1552160 tx frm ACK delay=16 blocks=[2..5] ecn_counts=None [2025-04-30T18:36:42.529150512Z TRACE quiche::recovery::congestion::recovery] ee7808f5aacbda14644368dc2911f360a1552160 timer=none latest_rtt=29.998885ms srtt=39.101545ms min_rtt=29.998885ms rttvar=17.751482ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=0 app_limited=true congestion_recovery_start_time=None Rate { delivered: 1841, delivered_time: Instant { tv_sec: 954, tv_nsec: 678535817 }, first_sent_time: Instant { tv_sec: 954, tv_nsec: 678535817 }, end_of_app_limited: 8, last_sent_packet: 10, largest_acked: 8, rate_sample: RateSample { delivery_rate: 44626, is_app_limited: true, interval: 33.791473ms, delivered: 1508, prior_delivered: 333, prior_time: Some(Instant { tv_sec: 954, tv_nsec: 644046982 }), send_elapsed: 509.32µs, ack_elapsed: 33.791473ms, rtt: 33.282153ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 431568, last_update: Instant { tv_sec: 954, tv_nsec: 678191054 }, next_time: Instant { tv_sec: 954, tv_nsec: 678535817 }, 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-30T18:36:42.529179877Z TRACE quiche_apps::client] written 43 bytes from [::]:46880 to [fd00:cafe:cafe:100::100]:443 [2025-04-30T18:36:42.529183985Z TRACE quiche_apps::client] [::]:46880 -> [fd00:cafe:cafe:100::100]:443: done writing [2025-04-30T18:36:42.530090470Z TRACE quiche_apps::client] got 1350 bytes from [fd00:cafe:cafe:100::100]:443 to [::]:46880 [2025-04-30T18:36:42.530097964Z TRACE quiche] ee7808f5aacbda14644368dc2911f360a1552160 rx pkt Short dcid=ee7808f5aacbda14644368dc2911f360a1552160 key_phase=false len=1329 pn=6 [2025-04-30T18:36:42.530104456Z TRACE quiche] ee7808f5aacbda14644368dc2911f360a1552160 rx frm STREAM id=0 off=1307 len=1306 fin=false [2025-04-30T18:36:42.530111259Z TRACE quiche_apps::client] [::]:46880: processed 1350 bytes [2025-04-30T18:36:42.530114716Z TRACE quiche_apps::client] [::]:46880: recv() would block [2025-04-30T18:36:42.530117010Z TRACE quiche_apps::client] done reading [2025-04-30T18:36:42.530119675Z TRACE quiche::h3] ee7808f5aacbda14644368dc2911f360a1552160 stream id 0 is readable [2025-04-30T18:36:42.530123973Z DEBUG quiche_apps::common] got 1306 bytes of response data on stream 0 [2025-04-30T18:36:42.530130515Z TRACE quiche] ee7808f5aacbda14644368dc2911f360a1552160 pmtud probe status false hs_con=true hs_sent=false cwnd_avail=13500 out_len=1350 left=1307 [2025-04-30T18:36:42.530133441Z TRACE quiche] ee7808f5aacbda14644368dc2911f360a1552160 tx pkt Short dcid=2e6d4629edf9c25318b454b516a2f148a9234bae key_phase=false len=5 pn=11 [2025-04-30T18:36:42.530135845Z TRACE quiche] ee7808f5aacbda14644368dc2911f360a1552160 tx frm ACK delay=4 blocks=[2..6] ecn_counts=None [2025-04-30T18:36:42.530141556Z TRACE quiche::recovery::congestion::recovery] ee7808f5aacbda14644368dc2911f360a1552160 timer=none latest_rtt=29.998885ms srtt=39.101545ms min_rtt=29.998885ms rttvar=17.751482ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=0 app_limited=true congestion_recovery_start_time=None Rate { delivered: 1841, delivered_time: Instant { tv_sec: 954, tv_nsec: 678535817 }, first_sent_time: Instant { tv_sec: 954, tv_nsec: 678535817 }, end_of_app_limited: 8, last_sent_packet: 11, largest_acked: 8, rate_sample: RateSample { delivery_rate: 44626, is_app_limited: true, interval: 33.791473ms, delivered: 1508, prior_delivered: 333, prior_time: Some(Instant { tv_sec: 954, tv_nsec: 644046982 }), send_elapsed: 509.32µs, ack_elapsed: 33.791473ms, rtt: 33.282153ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 431568, last_update: Instant { tv_sec: 954, tv_nsec: 678191054 }, next_time: Instant { tv_sec: 954, tv_nsec: 678535817 }, 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-30T18:36:42.530173005Z TRACE quiche_apps::client] written 43 bytes from [::]:46880 to [fd00:cafe:cafe:100::100]:443 [2025-04-30T18:36:42.530177002Z TRACE quiche_apps::client] [::]:46880 -> [fd00:cafe:cafe:100::100]:443: done writing [2025-04-30T18:36:42.531208972Z TRACE quiche_apps::client] got 1350 bytes from [fd00:cafe:cafe:100::100]:443 to [::]:46880 [2025-04-30T18:36:42.531216096Z TRACE quiche] ee7808f5aacbda14644368dc2911f360a1552160 rx pkt Short dcid=ee7808f5aacbda14644368dc2911f360a1552160 key_phase=false len=1329 pn=7 [2025-04-30T18:36:42.531221906Z TRACE quiche] ee7808f5aacbda14644368dc2911f360a1552160 rx frm STREAM id=0 off=2613 len=1306 fin=false [2025-04-30T18:36:42.531228048Z TRACE quiche_apps::client] [::]:46880: processed 1350 bytes [2025-04-30T18:36:42.531231384Z TRACE quiche_apps::client] [::]:46880: recv() would block [2025-04-30T18:36:42.531233648Z TRACE quiche_apps::client] done reading [2025-04-30T18:36:42.531236143Z TRACE quiche::h3] ee7808f5aacbda14644368dc2911f360a1552160 stream id 0 is readable [2025-04-30T18:36:42.531240181Z DEBUG quiche_apps::common] got 1306 bytes of response data on stream 0 [2025-04-30T18:36:42.531246532Z TRACE quiche] ee7808f5aacbda14644368dc2911f360a1552160 pmtud probe status false hs_con=true hs_sent=false cwnd_avail=13500 out_len=1350 left=1307 [2025-04-30T18:36:42.531249488Z TRACE quiche] ee7808f5aacbda14644368dc2911f360a1552160 tx pkt Short dcid=2e6d4629edf9c25318b454b516a2f148a9234bae key_phase=false len=5 pn=12 [2025-04-30T18:36:42.531251873Z TRACE quiche] ee7808f5aacbda14644368dc2911f360a1552160 tx frm ACK delay=3 blocks=[2..7] ecn_counts=None [2025-04-30T18:36:42.531257383Z TRACE quiche::recovery::congestion::recovery] ee7808f5aacbda14644368dc2911f360a1552160 timer=none latest_rtt=29.998885ms srtt=39.101545ms min_rtt=29.998885ms rttvar=17.751482ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=0 app_limited=true congestion_recovery_start_time=None Rate { delivered: 1841, delivered_time: Instant { tv_sec: 954, tv_nsec: 678535817 }, first_sent_time: Instant { tv_sec: 954, tv_nsec: 678535817 }, end_of_app_limited: 8, last_sent_packet: 12, largest_acked: 8, rate_sample: RateSample { delivery_rate: 44626, is_app_limited: true, interval: 33.791473ms, delivered: 1508, prior_delivered: 333, prior_time: Some(Instant { tv_sec: 954, tv_nsec: 644046982 }), send_elapsed: 509.32µs, ack_elapsed: 33.791473ms, rtt: 33.282153ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 431568, last_update: Instant { tv_sec: 954, tv_nsec: 678191054 }, next_time: Instant { tv_sec: 954, tv_nsec: 678535817 }, 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-30T18:36:42.531283231Z TRACE quiche_apps::client] written 43 bytes from [::]:46880 to [fd00:cafe:cafe:100::100]:443 [2025-04-30T18:36:42.531286938Z TRACE quiche_apps::client] [::]:46880 -> [fd00:cafe:cafe:100::100]:443: done writing [2025-04-30T18:36:42.532289984Z TRACE quiche_apps::client] got 1302 bytes from [fd00:cafe:cafe:100::100]:443 to [::]:46880 [2025-04-30T18:36:42.532296837Z TRACE quiche] ee7808f5aacbda14644368dc2911f360a1552160 rx pkt Short dcid=ee7808f5aacbda14644368dc2911f360a1552160 key_phase=false len=1281 pn=8 [2025-04-30T18:36:42.532302458Z TRACE quiche] ee7808f5aacbda14644368dc2911f360a1552160 rx frm STREAM id=0 off=3919 len=1258 fin=true [2025-04-30T18:36:42.532308559Z TRACE quiche_apps::client] [::]:46880: processed 1302 bytes [2025-04-30T18:36:42.532311905Z TRACE quiche_apps::client] [::]:46880: recv() would block [2025-04-30T18:36:42.532314129Z TRACE quiche_apps::client] done reading [2025-04-30T18:36:42.532321323Z TRACE quiche::h3] ee7808f5aacbda14644368dc2911f360a1552160 stream id 0 is readable [2025-04-30T18:36:42.532327364Z DEBUG quiche_apps::common] got 1258 bytes of response data on stream 0 [2025-04-30T18:36:42.532330009Z DEBUG quiche_apps::common] 1/2 responses received [2025-04-30T18:36:42.532336421Z TRACE quiche] ee7808f5aacbda14644368dc2911f360a1552160 pmtud probe status false hs_con=true hs_sent=false cwnd_avail=13500 out_len=1350 left=1307 [2025-04-30T18:36:42.532339336Z TRACE quiche] ee7808f5aacbda14644368dc2911f360a1552160 tx pkt Short dcid=2e6d4629edf9c25318b454b516a2f148a9234bae key_phase=false len=5 pn=13 [2025-04-30T18:36:42.532341711Z TRACE quiche] ee7808f5aacbda14644368dc2911f360a1552160 tx frm ACK delay=4 blocks=[2..8] ecn_counts=None [2025-04-30T18:36:42.532347331Z TRACE quiche::recovery::congestion::recovery] ee7808f5aacbda14644368dc2911f360a1552160 timer=none latest_rtt=29.998885ms srtt=39.101545ms min_rtt=29.998885ms rttvar=17.751482ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=0 app_limited=true congestion_recovery_start_time=None Rate { delivered: 1841, delivered_time: Instant { tv_sec: 954, tv_nsec: 678535817 }, first_sent_time: Instant { tv_sec: 954, tv_nsec: 678535817 }, end_of_app_limited: 8, last_sent_packet: 13, largest_acked: 8, rate_sample: RateSample { delivery_rate: 44626, is_app_limited: true, interval: 33.791473ms, delivered: 1508, prior_delivered: 333, prior_time: Some(Instant { tv_sec: 954, tv_nsec: 644046982 }), send_elapsed: 509.32µs, ack_elapsed: 33.791473ms, rtt: 33.282153ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 431568, last_update: Instant { tv_sec: 954, tv_nsec: 678191054 }, next_time: Instant { tv_sec: 954, tv_nsec: 678535817 }, 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-30T18:36:42.532373931Z TRACE quiche_apps::client] written 43 bytes from [::]:46880 to [fd00:cafe:cafe:100::100]:443 [2025-04-30T18:36:42.532377688Z TRACE quiche_apps::client] [::]:46880 -> [fd00:cafe:cafe:100::100]:443: done writing [2025-04-30T18:36:42.533430127Z TRACE quiche_apps::client] got 1350 bytes from [fd00:cafe:cafe:100::100]:443 to [::]:46880 [2025-04-30T18:36:42.533437851Z TRACE quiche] ee7808f5aacbda14644368dc2911f360a1552160 rx pkt Short dcid=ee7808f5aacbda14644368dc2911f360a1552160 key_phase=false len=1329 pn=9 [2025-04-30T18:36:42.533444503Z TRACE quiche] ee7808f5aacbda14644368dc2911f360a1552160 rx frm STREAM id=4 off=0 len=1307 fin=false [2025-04-30T18:36:42.533450775Z TRACE quiche_apps::client] [::]:46880: processed 1350 bytes [2025-04-30T18:36:42.533454092Z TRACE quiche_apps::client] [::]:46880: recv() would block [2025-04-30T18:36:42.533456326Z TRACE quiche_apps::client] done reading [2025-04-30T18:36:42.533458750Z TRACE quiche::h3] ee7808f5aacbda14644368dc2911f360a1552160 stream id 4 is readable [2025-04-30T18:36:42.533462357Z TRACE quiche::h3::stream] ee7808f5aacbda14644368dc2911f360a1552160 read 1 bytes on stream 4 [2025-04-30T18:36:42.533465463Z TRACE quiche::h3::stream] ee7808f5aacbda14644368dc2911f360a1552160 read 1 bytes on stream 4 [2025-04-30T18:36:42.533468809Z TRACE quiche::h3::stream] ee7808f5aacbda14644368dc2911f360a1552160 read 17 bytes on stream 4 [2025-04-30T18:36:42.533471304Z TRACE quiche::h3] ee7808f5aacbda14644368dc2911f360a1552160 rx frm HEADERS stream=4 payload_len=17 [2025-04-30T18:36:42.533473929Z TRACE quiche::h3::qpack::decoder] Header count=0 base=0 [2025-04-30T18:36:42.533476614Z TRACE quiche::h3::qpack::decoder] Indexed index=25 static=true [2025-04-30T18:36:42.533479499Z TRACE quiche::h3::qpack::decoder] Literal name_idx=92 static=true value=[113, 117, 105, 99, 104, 101] [2025-04-30T18:36:42.533483296Z TRACE quiche::h3::qpack::decoder] Literal name_idx=4 static=true value=[49, 48, 50, 52, 48] [2025-04-30T18:36:42.533494126Z DEBUG quiche_apps::common] got response headers [(":status", "200"), ("server", "quiche"), ("content-length", "10240")] on stream id 4 [2025-04-30T18:36:42.533497923Z TRACE quiche::h3] ee7808f5aacbda14644368dc2911f360a1552160 stream id 4 is readable [2025-04-30T18:36:42.533500779Z TRACE quiche::h3::stream] ee7808f5aacbda14644368dc2911f360a1552160 read 1 bytes on stream 4 [2025-04-30T18:36:42.533503684Z TRACE quiche::h3::stream] ee7808f5aacbda14644368dc2911f360a1552160 read 1 bytes on stream 4 [2025-04-30T18:36:42.533506550Z TRACE quiche::h3::stream] ee7808f5aacbda14644368dc2911f360a1552160 read 1 bytes on stream 4 [2025-04-30T18:36:42.533508814Z TRACE quiche::h3] ee7808f5aacbda14644368dc2911f360a1552160 rx frm DATA stream=4 wire_payload_len=10240 [2025-04-30T18:36:42.533513172Z DEBUG quiche_apps::common] got 1285 bytes of response data on stream 4 [2025-04-30T18:36:42.533520436Z TRACE quiche] ee7808f5aacbda14644368dc2911f360a1552160 pmtud probe status false hs_con=true hs_sent=false cwnd_avail=13500 out_len=1350 left=1307 [2025-04-30T18:36:42.533523631Z TRACE quiche] ee7808f5aacbda14644368dc2911f360a1552160 tx pkt Short dcid=2e6d4629edf9c25318b454b516a2f148a9234bae key_phase=false len=5 pn=14 [2025-04-30T18:36:42.533526006Z TRACE quiche] ee7808f5aacbda14644368dc2911f360a1552160 tx frm ACK delay=10 blocks=[2..9] ecn_counts=None [2025-04-30T18:36:42.533532027Z TRACE quiche::recovery::congestion::recovery] ee7808f5aacbda14644368dc2911f360a1552160 timer=none latest_rtt=29.998885ms srtt=39.101545ms min_rtt=29.998885ms rttvar=17.751482ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=0 app_limited=true congestion_recovery_start_time=None Rate { delivered: 1841, delivered_time: Instant { tv_sec: 954, tv_nsec: 678535817 }, first_sent_time: Instant { tv_sec: 954, tv_nsec: 678535817 }, end_of_app_limited: 8, last_sent_packet: 14, largest_acked: 8, rate_sample: RateSample { delivery_rate: 44626, is_app_limited: true, interval: 33.791473ms, delivered: 1508, prior_delivered: 333, prior_time: Some(Instant { tv_sec: 954, tv_nsec: 644046982 }), send_elapsed: 509.32µs, ack_elapsed: 33.791473ms, rtt: 33.282153ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 431568, last_update: Instant { tv_sec: 954, tv_nsec: 678191054 }, next_time: Instant { tv_sec: 954, tv_nsec: 678535817 }, 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-30T18:36:42.533561582Z TRACE quiche_apps::client] written 43 bytes from [::]:46880 to [fd00:cafe:cafe:100::100]:443 [2025-04-30T18:36:42.533565550Z TRACE quiche_apps::client] [::]:46880 -> [fd00:cafe:cafe:100::100]:443: done writing [2025-04-30T18:36:42.534530795Z TRACE quiche_apps::client] got 1350 bytes from [fd00:cafe:cafe:100::100]:443 to [::]:46880 [2025-04-30T18:36:42.534537919Z TRACE quiche] ee7808f5aacbda14644368dc2911f360a1552160 rx pkt Short dcid=ee7808f5aacbda14644368dc2911f360a1552160 key_phase=false len=1329 pn=10 [2025-04-30T18:36:42.534543669Z TRACE quiche] ee7808f5aacbda14644368dc2911f360a1552160 rx frm STREAM id=4 off=1307 len=1306 fin=false [2025-04-30T18:36:42.534549921Z TRACE quiche_apps::client] [::]:46880: processed 1350 bytes [2025-04-30T18:36:42.534553227Z TRACE quiche_apps::client] [::]:46880: recv() would block [2025-04-30T18:36:42.534555451Z TRACE quiche_apps::client] done reading [2025-04-30T18:36:42.534557886Z TRACE quiche::h3] ee7808f5aacbda14644368dc2911f360a1552160 stream id 4 is readable [2025-04-30T18:36:42.534561893Z DEBUG quiche_apps::common] got 1306 bytes of response data on stream 4 [2025-04-30T18:36:42.534568285Z TRACE quiche] ee7808f5aacbda14644368dc2911f360a1552160 pmtud probe status false hs_con=true hs_sent=false cwnd_avail=13500 out_len=1350 left=1307 [2025-04-30T18:36:42.534575749Z TRACE quiche] ee7808f5aacbda14644368dc2911f360a1552160 tx pkt Short dcid=2e6d4629edf9c25318b454b516a2f148a9234bae key_phase=false len=5 pn=15 [2025-04-30T18:36:42.534578214Z TRACE quiche] ee7808f5aacbda14644368dc2911f360a1552160 tx frm ACK delay=3 blocks=[2..10] ecn_counts=None [2025-04-30T18:36:42.534583784Z TRACE quiche::recovery::congestion::recovery] ee7808f5aacbda14644368dc2911f360a1552160 timer=none latest_rtt=29.998885ms srtt=39.101545ms min_rtt=29.998885ms rttvar=17.751482ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=0 app_limited=true congestion_recovery_start_time=None Rate { delivered: 1841, delivered_time: Instant { tv_sec: 954, tv_nsec: 678535817 }, first_sent_time: Instant { tv_sec: 954, tv_nsec: 678535817 }, end_of_app_limited: 8, last_sent_packet: 15, largest_acked: 8, rate_sample: RateSample { delivery_rate: 44626, is_app_limited: true, interval: 33.791473ms, delivered: 1508, prior_delivered: 333, prior_time: Some(Instant { tv_sec: 954, tv_nsec: 644046982 }), send_elapsed: 509.32µs, ack_elapsed: 33.791473ms, rtt: 33.282153ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 431568, last_update: Instant { tv_sec: 954, tv_nsec: 678191054 }, next_time: Instant { tv_sec: 954, tv_nsec: 678535817 }, 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-30T18:36:42.534611076Z TRACE quiche_apps::client] written 43 bytes from [::]:46880 to [fd00:cafe:cafe:100::100]:443 [2025-04-30T18:36:42.534614672Z TRACE quiche_apps::client] [::]:46880 -> [fd00:cafe:cafe:100::100]:443: done writing [2025-04-30T18:36:42.535653114Z TRACE quiche_apps::client] got 1350 bytes from [fd00:cafe:cafe:100::100]:443 to [::]:46880 [2025-04-30T18:36:42.535660118Z TRACE quiche] ee7808f5aacbda14644368dc2911f360a1552160 rx pkt Short dcid=ee7808f5aacbda14644368dc2911f360a1552160 key_phase=false len=1329 pn=11 [2025-04-30T18:36:42.535665708Z TRACE quiche] ee7808f5aacbda14644368dc2911f360a1552160 rx frm STREAM id=4 off=2613 len=1306 fin=false [2025-04-30T18:36:42.535671829Z TRACE quiche_apps::client] [::]:46880: processed 1350 bytes [2025-04-30T18:36:42.535675115Z TRACE quiche_apps::client] [::]:46880: recv() would block [2025-04-30T18:36:42.535677320Z TRACE quiche_apps::client] done reading [2025-04-30T18:36:42.535679784Z TRACE quiche::h3] ee7808f5aacbda14644368dc2911f360a1552160 stream id 4 is readable [2025-04-30T18:36:42.535683722Z DEBUG quiche_apps::common] got 1306 bytes of response data on stream 4 [2025-04-30T18:36:42.535690003Z TRACE quiche] ee7808f5aacbda14644368dc2911f360a1552160 pmtud probe status false hs_con=true hs_sent=false cwnd_avail=13500 out_len=1350 left=1307 [2025-04-30T18:36:42.535692899Z TRACE quiche] ee7808f5aacbda14644368dc2911f360a1552160 tx pkt Short dcid=2e6d4629edf9c25318b454b516a2f148a9234bae key_phase=false len=5 pn=16 [2025-04-30T18:36:42.535695253Z TRACE quiche] ee7808f5aacbda14644368dc2911f360a1552160 tx frm ACK delay=3 blocks=[2..11] ecn_counts=None [2025-04-30T18:36:42.535700493Z TRACE quiche::recovery::congestion::recovery] ee7808f5aacbda14644368dc2911f360a1552160 timer=none latest_rtt=29.998885ms srtt=39.101545ms min_rtt=29.998885ms rttvar=17.751482ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=0 app_limited=true congestion_recovery_start_time=None Rate { delivered: 1841, delivered_time: Instant { tv_sec: 954, tv_nsec: 678535817 }, first_sent_time: Instant { tv_sec: 954, tv_nsec: 678535817 }, end_of_app_limited: 8, last_sent_packet: 16, largest_acked: 8, rate_sample: RateSample { delivery_rate: 44626, is_app_limited: true, interval: 33.791473ms, delivered: 1508, prior_delivered: 333, prior_time: Some(Instant { tv_sec: 954, tv_nsec: 644046982 }), send_elapsed: 509.32µs, ack_elapsed: 33.791473ms, rtt: 33.282153ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 431568, last_update: Instant { tv_sec: 954, tv_nsec: 678191054 }, next_time: Instant { tv_sec: 954, tv_nsec: 678535817 }, 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-30T18:36:42.535730690Z TRACE quiche_apps::client] written 43 bytes from [::]:46880 to [fd00:cafe:cafe:100::100]:443 [2025-04-30T18:36:42.535734577Z TRACE quiche_apps::client] [::]:46880 -> [fd00:cafe:cafe:100::100]:443: done writing [2025-04-30T18:36:42.536771516Z TRACE quiche_apps::client] got 1350 bytes from [fd00:cafe:cafe:100::100]:443 to [::]:46880 [2025-04-30T18:36:42.536778439Z TRACE quiche] ee7808f5aacbda14644368dc2911f360a1552160 rx pkt Short dcid=ee7808f5aacbda14644368dc2911f360a1552160 key_phase=false len=1329 pn=12 [2025-04-30T18:36:42.536784049Z TRACE quiche] ee7808f5aacbda14644368dc2911f360a1552160 rx frm STREAM id=4 off=3919 len=1306 fin=false [2025-04-30T18:36:42.536790131Z TRACE quiche_apps::client] [::]:46880: processed 1350 bytes [2025-04-30T18:36:42.536793507Z TRACE quiche_apps::client] [::]:46880: recv() would block [2025-04-30T18:36:42.536795731Z TRACE quiche_apps::client] done reading [2025-04-30T18:36:42.536798166Z TRACE quiche::h3] ee7808f5aacbda14644368dc2911f360a1552160 stream id 4 is readable [2025-04-30T18:36:42.536813444Z DEBUG quiche_apps::common] got 1306 bytes of response data on stream 4 [2025-04-30T18:36:42.536820027Z TRACE quiche] ee7808f5aacbda14644368dc2911f360a1552160 pmtud probe status false hs_con=true hs_sent=false cwnd_avail=13500 out_len=1350 left=1307 [2025-04-30T18:36:42.536823033Z TRACE quiche] ee7808f5aacbda14644368dc2911f360a1552160 tx pkt Short dcid=2e6d4629edf9c25318b454b516a2f148a9234bae key_phase=false len=5 pn=17 [2025-04-30T18:36:42.536825537Z TRACE quiche] ee7808f5aacbda14644368dc2911f360a1552160 tx frm ACK delay=5 blocks=[2..12] ecn_counts=None [2025-04-30T18:36:42.536831949Z TRACE quiche::recovery::congestion::recovery] ee7808f5aacbda14644368dc2911f360a1552160 timer=none latest_rtt=29.998885ms srtt=39.101545ms min_rtt=29.998885ms rttvar=17.751482ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=0 app_limited=true congestion_recovery_start_time=None Rate { delivered: 1841, delivered_time: Instant { tv_sec: 954, tv_nsec: 678535817 }, first_sent_time: Instant { tv_sec: 954, tv_nsec: 678535817 }, end_of_app_limited: 8, last_sent_packet: 17, largest_acked: 8, rate_sample: RateSample { delivery_rate: 44626, is_app_limited: true, interval: 33.791473ms, delivered: 1508, prior_delivered: 333, prior_time: Some(Instant { tv_sec: 954, tv_nsec: 644046982 }), send_elapsed: 509.32µs, ack_elapsed: 33.791473ms, rtt: 33.282153ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 431568, last_update: Instant { tv_sec: 954, tv_nsec: 678191054 }, next_time: Instant { tv_sec: 954, tv_nsec: 678535817 }, 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-30T18:36:42.536858719Z TRACE quiche_apps::client] written 43 bytes from [::]:46880 to [fd00:cafe:cafe:100::100]:443 [2025-04-30T18:36:42.536862426Z TRACE quiche_apps::client] [::]:46880 -> [fd00:cafe:cafe:100::100]:443: done writing [2025-04-30T18:36:42.537913402Z TRACE quiche_apps::client] got 1350 bytes from [fd00:cafe:cafe:100::100]:443 to [::]:46880 [2025-04-30T18:36:42.537922779Z TRACE quiche] ee7808f5aacbda14644368dc2911f360a1552160 rx pkt Short dcid=ee7808f5aacbda14644368dc2911f360a1552160 key_phase=false len=1329 pn=13 [2025-04-30T18:36:42.537930233Z TRACE quiche] ee7808f5aacbda14644368dc2911f360a1552160 rx frm STREAM id=4 off=5225 len=1306 fin=false [2025-04-30T18:36:42.537944400Z TRACE quiche_apps::client] [::]:46880: processed 1350 bytes [2025-04-30T18:36:42.537948207Z TRACE quiche_apps::client] [::]:46880: recv() would block [2025-04-30T18:36:42.537950571Z TRACE quiche_apps::client] done reading [2025-04-30T18:36:42.537953246Z TRACE quiche::h3] ee7808f5aacbda14644368dc2911f360a1552160 stream id 4 is readable [2025-04-30T18:36:42.537958145Z DEBUG quiche_apps::common] got 1306 bytes of response data on stream 4 [2025-04-30T18:36:42.537966271Z TRACE quiche] ee7808f5aacbda14644368dc2911f360a1552160 pmtud probe status false hs_con=true hs_sent=false cwnd_avail=13500 out_len=1350 left=1307 [2025-04-30T18:36:42.537969787Z TRACE quiche] ee7808f5aacbda14644368dc2911f360a1552160 tx pkt Short dcid=2e6d4629edf9c25318b454b516a2f148a9234bae key_phase=false len=5 pn=18 [2025-04-30T18:36:42.537972342Z TRACE quiche] ee7808f5aacbda14644368dc2911f360a1552160 tx frm ACK delay=5 blocks=[2..13] ecn_counts=None [2025-04-30T18:36:42.538000254Z TRACE quiche::recovery::congestion::recovery] ee7808f5aacbda14644368dc2911f360a1552160 timer=none latest_rtt=29.998885ms srtt=39.101545ms min_rtt=29.998885ms rttvar=17.751482ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=0 app_limited=true congestion_recovery_start_time=None Rate { delivered: 1841, delivered_time: Instant { tv_sec: 954, tv_nsec: 678535817 }, first_sent_time: Instant { tv_sec: 954, tv_nsec: 678535817 }, end_of_app_limited: 8, last_sent_packet: 18, largest_acked: 8, rate_sample: RateSample { delivery_rate: 44626, is_app_limited: true, interval: 33.791473ms, delivered: 1508, prior_delivered: 333, prior_time: Some(Instant { tv_sec: 954, tv_nsec: 644046982 }), send_elapsed: 509.32µs, ack_elapsed: 33.791473ms, rtt: 33.282153ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 431568, last_update: Instant { tv_sec: 954, tv_nsec: 678191054 }, next_time: Instant { tv_sec: 954, tv_nsec: 678535817 }, 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-30T18:36:42.538040249Z TRACE quiche_apps::client] written 43 bytes from [::]:46880 to [fd00:cafe:cafe:100::100]:443 [2025-04-30T18:36:42.538044978Z TRACE quiche_apps::client] [::]:46880 -> [fd00:cafe:cafe:100::100]:443: done writing [2025-04-30T18:36:42.538378342Z TRACE quiche_apps::client] got 562 bytes from [fd00:cafe:cafe:100::100]:443 to [::]:46880 [2025-04-30T18:36:42.538382810Z TRACE quiche] ee7808f5aacbda14644368dc2911f360a1552160 rx pkt Short dcid=ee7808f5aacbda14644368dc2911f360a1552160 key_phase=false len=541 pn=14 [2025-04-30T18:36:42.538388841Z TRACE quiche] ee7808f5aacbda14644368dc2911f360a1552160 rx frm STREAM id=4 off=6531 len=518 fin=false [2025-04-30T18:36:42.538395153Z TRACE quiche_apps::client] [::]:46880: processed 562 bytes [2025-04-30T18:36:42.538398479Z TRACE quiche_apps::client] [::]:46880: recv() would block [2025-04-30T18:36:42.538400733Z TRACE quiche_apps::client] done reading [2025-04-30T18:36:42.538403208Z TRACE quiche::h3] ee7808f5aacbda14644368dc2911f360a1552160 stream id 4 is readable [2025-04-30T18:36:42.538407326Z DEBUG quiche_apps::common] got 518 bytes of response data on stream 4 [2025-04-30T18:36:42.538413998Z TRACE quiche] ee7808f5aacbda14644368dc2911f360a1552160 pmtud probe status false hs_con=true hs_sent=false cwnd_avail=13500 out_len=1350 left=1307 [2025-04-30T18:36:42.538417024Z TRACE quiche] ee7808f5aacbda14644368dc2911f360a1552160 tx pkt Short dcid=2e6d4629edf9c25318b454b516a2f148a9234bae key_phase=false len=5 pn=19 [2025-04-30T18:36:42.538419539Z TRACE quiche] ee7808f5aacbda14644368dc2911f360a1552160 tx frm ACK delay=3 blocks=[2..14] ecn_counts=None [2025-04-30T18:36:42.538425059Z TRACE quiche::recovery::congestion::recovery] ee7808f5aacbda14644368dc2911f360a1552160 timer=none latest_rtt=29.998885ms srtt=39.101545ms min_rtt=29.998885ms rttvar=17.751482ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=0 app_limited=true congestion_recovery_start_time=None Rate { delivered: 1841, delivered_time: Instant { tv_sec: 954, tv_nsec: 678535817 }, first_sent_time: Instant { tv_sec: 954, tv_nsec: 678535817 }, end_of_app_limited: 8, last_sent_packet: 19, largest_acked: 8, rate_sample: RateSample { delivery_rate: 44626, is_app_limited: true, interval: 33.791473ms, delivered: 1508, prior_delivered: 333, prior_time: Some(Instant { tv_sec: 954, tv_nsec: 644046982 }), send_elapsed: 509.32µs, ack_elapsed: 33.791473ms, rtt: 33.282153ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 431568, last_update: Instant { tv_sec: 954, tv_nsec: 678191054 }, next_time: Instant { tv_sec: 954, tv_nsec: 678535817 }, 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-30T18:36:42.538456397Z TRACE quiche_apps::client] written 43 bytes from [::]:46880 to [fd00:cafe:cafe:100::100]:443 [2025-04-30T18:36:42.538460285Z TRACE quiche_apps::client] [::]:46880 -> [fd00:cafe:cafe:100::100]:443: done writing [2025-04-30T18:36:42.559474139Z TRACE quiche_apps::client] got 836 bytes from [fd00:cafe:cafe:100::100]:443 to [::]:46880 [2025-04-30T18:36:42.559495138Z TRACE quiche] ee7808f5aacbda14644368dc2911f360a1552160 rx pkt Short dcid=ee7808f5aacbda14644368dc2911f360a1552160 key_phase=false len=815 pn=15 [2025-04-30T18:36:42.559508353Z TRACE quiche] ee7808f5aacbda14644368dc2911f360a1552160 rx frm STREAM id=4 off=7049 len=792 fin=false [2025-04-30T18:36:42.559525816Z TRACE quiche_apps::client] [::]:46880: processed 836 bytes [2025-04-30T18:36:42.559530474Z TRACE quiche_apps::client] [::]:46880: recv() would block [2025-04-30T18:36:42.559533520Z TRACE quiche_apps::client] done reading [2025-04-30T18:36:42.559537868Z TRACE quiche::h3] ee7808f5aacbda14644368dc2911f360a1552160 stream id 4 is readable [2025-04-30T18:36:42.559545823Z DEBUG quiche_apps::common] got 792 bytes of response data on stream 4 [2025-04-30T18:36:42.559557715Z TRACE quiche] ee7808f5aacbda14644368dc2911f360a1552160 pmtud probe status false hs_con=true hs_sent=false cwnd_avail=13500 out_len=1350 left=1307 [2025-04-30T18:36:42.559563235Z TRACE quiche] ee7808f5aacbda14644368dc2911f360a1552160 tx pkt Short dcid=2e6d4629edf9c25318b454b516a2f148a9234bae key_phase=false len=5 pn=20 [2025-04-30T18:36:42.559566672Z TRACE quiche] ee7808f5aacbda14644368dc2911f360a1552160 tx frm ACK delay=8 blocks=[2..15] ecn_counts=None [2025-04-30T18:36:42.559576981Z TRACE quiche::recovery::congestion::recovery] ee7808f5aacbda14644368dc2911f360a1552160 timer=none latest_rtt=29.998885ms srtt=39.101545ms min_rtt=29.998885ms rttvar=17.751482ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=0 app_limited=true congestion_recovery_start_time=None Rate { delivered: 1841, delivered_time: Instant { tv_sec: 954, tv_nsec: 709575906 }, first_sent_time: Instant { tv_sec: 954, tv_nsec: 709575906 }, end_of_app_limited: 8, last_sent_packet: 20, largest_acked: 8, rate_sample: RateSample { delivery_rate: 44626, is_app_limited: true, interval: 33.791473ms, delivered: 1508, prior_delivered: 333, prior_time: Some(Instant { tv_sec: 954, tv_nsec: 644046982 }), send_elapsed: 509.32µs, ack_elapsed: 33.791473ms, rtt: 33.282153ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 431568, last_update: Instant { tv_sec: 954, tv_nsec: 709575906 }, next_time: Instant { tv_sec: 954, tv_nsec: 709575906 }, 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-30T18:36:42.559636172Z TRACE quiche_apps::client] written 43 bytes from [::]:46880 to [fd00:cafe:cafe:100::100]:443 [2025-04-30T18:36:42.559641752Z TRACE quiche_apps::client] [::]:46880 -> [fd00:cafe:cafe:100::100]:443: done writing [2025-04-30T18:36:42.560712635Z TRACE quiche_apps::client] got 1350 bytes from [fd00:cafe:cafe:100::100]:443 to [::]:46880 [2025-04-30T18:36:42.560720009Z TRACE quiche] ee7808f5aacbda14644368dc2911f360a1552160 rx pkt Short dcid=ee7808f5aacbda14644368dc2911f360a1552160 key_phase=false len=1329 pn=16 [2025-04-30T18:36:42.560726311Z TRACE quiche] ee7808f5aacbda14644368dc2911f360a1552160 rx frm STREAM id=4 off=7841 len=1306 fin=false [2025-04-30T18:36:42.560732903Z TRACE quiche_apps::client] [::]:46880: processed 1350 bytes [2025-04-30T18:36:42.560736340Z TRACE quiche_apps::client] [::]:46880: recv() would block [2025-04-30T18:36:42.560738554Z TRACE quiche_apps::client] done reading [2025-04-30T18:36:42.560741129Z TRACE quiche::h3] ee7808f5aacbda14644368dc2911f360a1552160 stream id 4 is readable [2025-04-30T18:36:42.560745507Z DEBUG quiche_apps::common] got 1306 bytes of response data on stream 4 [2025-04-30T18:36:42.560776525Z TRACE quiche] ee7808f5aacbda14644368dc2911f360a1552160 pmtud probe status false hs_con=true hs_sent=false cwnd_avail=13500 out_len=1350 left=1307 [2025-04-30T18:36:42.560779971Z TRACE quiche] ee7808f5aacbda14644368dc2911f360a1552160 tx pkt Short dcid=2e6d4629edf9c25318b454b516a2f148a9234bae key_phase=false len=5 pn=21 [2025-04-30T18:36:42.560782426Z TRACE quiche] ee7808f5aacbda14644368dc2911f360a1552160 tx frm ACK delay=7 blocks=[2..16] ecn_counts=None [2025-04-30T18:36:42.560788347Z TRACE quiche::recovery::congestion::recovery] ee7808f5aacbda14644368dc2911f360a1552160 timer=none latest_rtt=29.998885ms srtt=39.101545ms min_rtt=29.998885ms rttvar=17.751482ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=0 app_limited=true congestion_recovery_start_time=None Rate { delivered: 1841, delivered_time: Instant { tv_sec: 954, tv_nsec: 709575906 }, first_sent_time: Instant { tv_sec: 954, tv_nsec: 709575906 }, end_of_app_limited: 8, last_sent_packet: 21, largest_acked: 8, rate_sample: RateSample { delivery_rate: 44626, is_app_limited: true, interval: 33.791473ms, delivered: 1508, prior_delivered: 333, prior_time: Some(Instant { tv_sec: 954, tv_nsec: 644046982 }), send_elapsed: 509.32µs, ack_elapsed: 33.791473ms, rtt: 33.282153ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 431568, last_update: Instant { tv_sec: 954, tv_nsec: 709575906 }, next_time: Instant { tv_sec: 954, tv_nsec: 709575906 }, 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-30T18:36:42.560815658Z TRACE quiche_apps::client] written 43 bytes from [::]:46880 to [fd00:cafe:cafe:100::100]:443 [2025-04-30T18:36:42.560819395Z TRACE quiche_apps::client] [::]:46880 -> [fd00:cafe:cafe:100::100]:443: done writing [2025-04-30T18:36:42.561678582Z TRACE quiche_apps::client] got 1159 bytes from [fd00:cafe:cafe:100::100]:443 to [::]:46880 [2025-04-30T18:36:42.561685695Z TRACE quiche] ee7808f5aacbda14644368dc2911f360a1552160 rx pkt Short dcid=ee7808f5aacbda14644368dc2911f360a1552160 key_phase=false len=1138 pn=17 [2025-04-30T18:36:42.561691616Z TRACE quiche] ee7808f5aacbda14644368dc2911f360a1552160 rx frm STREAM id=4 off=9147 len=1115 fin=true [2025-04-30T18:36:42.561698008Z TRACE quiche_apps::client] [::]:46880: processed 1159 bytes [2025-04-30T18:36:42.561701414Z TRACE quiche_apps::client] [::]:46880: recv() would block [2025-04-30T18:36:42.561703689Z TRACE quiche_apps::client] done reading [2025-04-30T18:36:42.561706154Z TRACE quiche::h3] ee7808f5aacbda14644368dc2911f360a1552160 stream id 4 is readable [2025-04-30T18:36:42.561716944Z DEBUG quiche_apps::common] got 1115 bytes of response data on stream 4 [2025-04-30T18:36:42.561719799Z DEBUG quiche_apps::common] 2/2 responses received [2025-04-30T18:36:42.561722384Z INFO quiche_apps::common] 2/2 response(s) received in 108.476371ms, closing... [2025-04-30T18:36:42.561728886Z TRACE quiche] ee7808f5aacbda14644368dc2911f360a1552160 pmtud probe status false hs_con=true hs_sent=false cwnd_avail=13500 out_len=1350 left=1312 [2025-04-30T18:36:42.561732312Z TRACE quiche] ee7808f5aacbda14644368dc2911f360a1552160 tx pkt Short dcid=2e6d4629edf9c25318b454b516a2f148a9234bae key_phase=false len=11 pn=22 [2025-04-30T18:36:42.561734707Z TRACE quiche] ee7808f5aacbda14644368dc2911f360a1552160 tx frm APPLICATION_CLOSE err=100 reason=[6b, 74, 68, 78, 62, 79, 65] [2025-04-30T18:36:42.561742030Z TRACE quiche::recovery::congestion::recovery] ee7808f5aacbda14644368dc2911f360a1552160 timer=135.091664ms latest_rtt=29.998885ms srtt=39.101545ms min_rtt=29.998885ms rttvar=17.751482ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=49 app_limited=true congestion_recovery_start_time=None Rate { delivered: 1841, delivered_time: Instant { tv_sec: 954, tv_nsec: 709575906 }, first_sent_time: Instant { tv_sec: 954, tv_nsec: 709575906 }, end_of_app_limited: 21, last_sent_packet: 22, largest_acked: 8, rate_sample: RateSample { delivery_rate: 44626, is_app_limited: true, interval: 33.791473ms, delivered: 1508, prior_delivered: 333, prior_time: Some(Instant { tv_sec: 954, tv_nsec: 644046982 }), send_elapsed: 509.32µs, ack_elapsed: 33.791473ms, rtt: 33.282153ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 431568, last_update: Instant { tv_sec: 954, tv_nsec: 711750423 }, next_time: Instant { tv_sec: 954, tv_nsec: 709575906 }, max_datagram_size: 1350, last_packet_size: None, iv: 113.539µ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-30T18:36:42.561770013Z TRACE quiche_apps::client] written 49 bytes from [::]:46880 to [fd00:cafe:cafe:100::100]:443 [2025-04-30T18:36:42.561773359Z TRACE quiche_apps::client] [::]:46880 -> [fd00:cafe:cafe:100::100]:443: done writing [2025-04-30T18:36:42.561780953Z TRACE quiche_apps::client] got 69 bytes from [fd00:cafe:cafe:100::100]:443 to [::]:46880 [2025-04-30T18:36:42.561783849Z TRACE quiche_apps::client] [::]:46880: processed 69 bytes [2025-04-30T18:36:42.561786844Z TRACE quiche_apps::client] [::]:46880: recv() would block [2025-04-30T18:36:42.561789089Z TRACE quiche_apps::client] done reading [2025-04-30T18:36:42.561792335Z TRACE quiche_apps::client] [::]:46880 -> [fd00:cafe:cafe:100::100]:443: done writing [2025-04-30T18:36:42.893220528Z TRACE quiche_apps::client] timed out [2025-04-30T18:36:42.893254331Z TRACE quiche] ee7808f5aacbda14644368dc2911f360a1552160 draining timeout expired [2025-04-30T18:36:42.893311989Z TRACE quiche_apps::client] done reading [2025-04-30T18:36:42.893316588Z INFO quiche_apps::client] connection closed, recv=18 sent=23 lost=0 retrans=0 sent_bytes=2634 recv_bytes=17779 lost_bytes=0 [local_addr=[::]:46880 peer_addr=[fd00:cafe:cafe:100::100]:443 validation_state=Validated active=true recv=18 sent=23 lost=0 retrans=0 rtt=39.101545ms min_rtt=Some(29.998885ms) rttvar=17.751482ms cwnd=13500 sent_bytes=2634 recv_bytes=17779 lost_bytes=0 stream_retrans_bytes=0 pmtu=1350 delivery_rate=44626]