[2025-04-30T17:19:57.245784787Z TRACE mio::poll] registering event source with poller: token=Token(0), interests=READABLE
[2025-04-30T17:19:57.246053461Z INFO  quiche_apps::client] connecting to [fd00:cafe:cafe:100::100]:443 from [::]:41995 with scid a4231187ece90a57c2217f5d6ad95c92062ca8d4
[2025-04-30T17:19:57.246093606Z TRACE quiche::tls] a4231187ece90a57c2217f5d6ad95c92062ca8d4 write message lvl=Initial len=266
[2025-04-30T17:19:57.246112422Z TRACE quiche] a4231187ece90a57c2217f5d6ad95c92062ca8d4 tx pkt Initial version=1 dcid=7c38a19109716663e7d8b638032b8f57 scid=a4231187ece90a57c2217f5d6ad95c92062ca8d4 len=270 pn=0 
[2025-04-30T17:19:57.246115628Z TRACE quiche] a4231187ece90a57c2217f5d6ad95c92062ca8d4 tx frm CRYPTO off=0 len=266
[2025-04-30T17:19:57.246128342Z TRACE quiche::recovery::congestion::recovery] a4231187ece90a57c2217f5d6ad95c92062ca8d4 timer=998.932083ms 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: 859, tv_nsec: 774548261 }, first_sent_time: Instant { tv_sec: 859, tv_nsec: 774548261 }, 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: 859, tv_nsec: 774548261 }, next_time: Instant { tv_sec: 859, tv_nsec: 774548261 }, 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-30T17:19:57.246174268Z TRACE quiche_apps::client] written 1200
[2025-04-30T17:19:57.286605758Z TRACE quiche_apps::client] got 1232 bytes from [fd00:cafe:cafe:100::100]:443 to [::]:41995
[2025-04-30T17:19:57.286623651Z TRACE quiche] a4231187ece90a57c2217f5d6ad95c92062ca8d4 rx pkt Initial version=1 dcid=a4231187ece90a57c2217f5d6ad95c92062ca8d4 scid=4000008b102e8f85 token= len=1194 pn=14215648 
[2025-04-30T17:19:57.286641044Z TRACE quiche] a4231187ece90a57c2217f5d6ad95c92062ca8d4 rx frm CRYPTO off=0 len=90
[2025-04-30T17:19:57.286747544Z TRACE quiche::tls] a4231187ece90a57c2217f5d6ad95c92062ca8d4 set write secret lvl=Handshake
[2025-04-30T17:19:57.286758104Z TRACE quiche::tls] a4231187ece90a57c2217f5d6ad95c92062ca8d4 set read secret lvl=Handshake
[2025-04-30T17:19:57.286768874Z TRACE quiche] a4231187ece90a57c2217f5d6ad95c92062ca8d4 rx frm ACK delay=119 blocks=[0..0] ecn_counts=None
[2025-04-30T17:19:57.286774575Z TRACE quiche::recovery::congestion::recovery] a4231187ece90a57c2217f5d6ad95c92062ca8d4 packet newly acked 0
[2025-04-30T17:19:57.286784664Z TRACE quiche] a4231187ece90a57c2217f5d6ad95c92062ca8d4 rx frm PADDING len=1074
[2025-04-30T17:19:57.286806535Z TRACE quiche_apps::client] [::]:41995: processed 1232 bytes
[2025-04-30T17:19:57.286812285Z TRACE quiche_apps::client] [::]:41995: recv() would block
[2025-04-30T17:19:57.286815391Z TRACE quiche_apps::client] done reading
[2025-04-30T17:19:57.286832333Z TRACE quiche] a4231187ece90a57c2217f5d6ad95c92062ca8d4 tx pkt Initial version=1 dcid=4000008b102e8f85 scid=a4231187ece90a57c2217f5d6ad95c92062ca8d4 len=8 pn=1 
[2025-04-30T17:19:57.286836120Z TRACE quiche] a4231187ece90a57c2217f5d6ad95c92062ca8d4 tx frm ACK delay=26 blocks=[14215648..14215648] ecn_counts=None
[2025-04-30T17:19:57.286845037Z TRACE quiche::recovery::congestion::recovery] a4231187ece90a57c2217f5d6ad95c92062ca8d4 timer=121.45428ms latest_rtt=40.559661ms srtt=40.559661ms min_rtt=40.559661ms rttvar=20.27983ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=0 app_limited=true congestion_recovery_start_time=None Rate { delivered: 333, delivered_time: Instant { tv_sec: 859, tv_nsec: 815311143 }, first_sent_time: Instant { tv_sec: 859, tv_nsec: 815311143 }, end_of_app_limited: 1, last_sent_packet: 1, largest_acked: 0, rate_sample: RateSample { delivery_rate: 8210, is_app_limited: true, interval: 40.559661ms, delivered: 333, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 859, tv_nsec: 774548261 }), send_elapsed: 0ns, ack_elapsed: 40.559661ms, rtt: 40.559661ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 416053, last_update: Instant { tv_sec: 859, tv_nsec: 815311143 }, next_time: Instant { tv_sec: 859, tv_nsec: 815311143 }, 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-30T17:19:57.286905240Z TRACE quiche_apps::client] written 1200 bytes from [::]:41995 to [fd00:cafe:cafe:100::100]:443
[2025-04-30T17:19:57.286918014Z TRACE quiche_apps::client] [::]:41995 -> [fd00:cafe:cafe:100::100]:443: done writing
[2025-04-30T17:19:57.287247742Z TRACE quiche_apps::client] got 774 bytes from [fd00:cafe:cafe:100::100]:443 to [::]:41995
[2025-04-30T17:19:57.287255227Z TRACE quiche] a4231187ece90a57c2217f5d6ad95c92062ca8d4 rx pkt Handshake version=1 dcid=a4231187ece90a57c2217f5d6ad95c92062ca8d4 scid=4000008b102e8f85 len=737 pn=14215648 
[2025-04-30T17:19:57.287263162Z TRACE quiche] a4231187ece90a57c2217f5d6ad95c92062ca8d4 rx frm CRYPTO off=0 len=713
[2025-04-30T17:19:57.287498894Z TRACE quiche::tls] a4231187ece90a57c2217f5d6ad95c92062ca8d4 write message lvl=Handshake len=36
[2025-04-30T17:19:57.287503823Z TRACE quiche::tls] a4231187ece90a57c2217f5d6ad95c92062ca8d4 set write secret lvl=OneRTT
[2025-04-30T17:19:57.287513060Z TRACE quiche::tls] a4231187ece90a57c2217f5d6ad95c92062ca8d4 set read secret lvl=OneRTT
[2025-04-30T17:19:57.287551412Z TRACE quiche] a4231187ece90a57c2217f5d6ad95c92062ca8d4 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(7c38a19109716663e7d8b638032b8f57), max_idle_timeout: 60000, stateless_reset_token: Some(30619597064991651263891421859940050193), max_udp_payload_size: 1500, initial_max_data: 2621440, initial_max_stream_data_bidi_local: 262144, initial_max_stream_data_bidi_remote: 262144, initial_max_stream_data_uni: 262144, initial_max_streams_bidi: 100, initial_max_streams_uni: 100, ack_delay_exponent: 3, max_ack_delay: 25, disable_active_migration: false, active_conn_id_limit: 2, initial_source_connection_id: Some(4000008b102e8f85), retry_source_connection_id: None, max_datagram_frame_size: Some(65535), unknown_params: None }
[2025-04-30T17:19:57.287572502Z TRACE quiche_apps::client] [::]:41995: processed 774 bytes
[2025-04-30T17:19:57.287578553Z TRACE quiche_apps::client] got 112 bytes from [fd00:cafe:cafe:100::100]:443 to [::]:41995
[2025-04-30T17:19:57.287582390Z TRACE quiche] a4231187ece90a57c2217f5d6ad95c92062ca8d4 rx pkt Short dcid=a4231187ece90a57c2217f5d6ad95c92062ca8d4 key_phase=false len=91 pn=14215648 
[2025-04-30T17:19:57.287587861Z TRACE quiche] a4231187ece90a57c2217f5d6ad95c92062ca8d4 rx frm STREAM id=3 off=0 len=40 fin=false
[2025-04-30T17:19:57.287592209Z TRACE quiche] a4231187ece90a57c2217f5d6ad95c92062ca8d4 rx frm STREAM id=7 off=0 len=1 fin=false
[2025-04-30T17:19:57.287595124Z TRACE quiche] a4231187ece90a57c2217f5d6ad95c92062ca8d4 rx frm STREAM id=11 off=0 len=1 fin=false
[2025-04-30T17:19:57.287598220Z TRACE quiche] a4231187ece90a57c2217f5d6ad95c92062ca8d4 rx frm PADDING len=20
[2025-04-30T17:19:57.287603420Z TRACE quiche_apps::client] [::]:41995: processed 112 bytes
[2025-04-30T17:19:57.287606736Z TRACE quiche_apps::client] [::]:41995: recv() would block
[2025-04-30T17:19:57.287609060Z TRACE quiche_apps::client] done reading
[2025-04-30T17:19:57.287626283Z TRACE quiche::h3] a4231187ece90a57c2217f5d6ad95c92062ca8d4 tx frm SETTINGS stream=2 len=18
[2025-04-30T17:19:57.287650789Z TRACE quiche::h3] a4231187ece90a57c2217f5d6ad95c92062ca8d4 open GREASE stream 14
[2025-04-30T17:19:57.287659455Z TRACE quiche::h3] a4231187ece90a57c2217f5d6ad95c92062ca8d4 tx frm GREASE stream=0 len=0
[2025-04-30T17:19:57.287665056Z TRACE quiche::h3] a4231187ece90a57c2217f5d6ad95c92062ca8d4 tx frm GREASE stream=0 len=18
[2025-04-30T17:19:57.287671558Z TRACE quiche::h3] a4231187ece90a57c2217f5d6ad95c92062ca8d4 tx frm HEADERS stream=0 len=30 fin=true
[2025-04-30T17:19:57.287677268Z DEBUG quiche_apps::common] Sent HTTP request [":method: GET", ":scheme: https", ":authority: server6", ":path: /rtxkwoxqnf", "user-agent: quiche"]
[2025-04-30T17:19:57.287721171Z TRACE quiche::h3] a4231187ece90a57c2217f5d6ad95c92062ca8d4 tx frm HEADERS stream=4 len=29 fin=true
[2025-04-30T17:19:57.287726942Z DEBUG quiche_apps::common] Sent HTTP request [":method: GET", ":scheme: https", ":authority: server6", ":path: /ntcnfiyrdt", "user-agent: quiche"]
[2025-04-30T17:19:57.287757269Z TRACE quiche::h3] a4231187ece90a57c2217f5d6ad95c92062ca8d4 stream id 3 is readable
[2025-04-30T17:19:57.287762418Z TRACE quiche::h3::stream] a4231187ece90a57c2217f5d6ad95c92062ca8d4 read 1 bytes on stream 3
[2025-04-30T17:19:57.287766205Z TRACE quiche::h3] a4231187ece90a57c2217f5d6ad95c92062ca8d4 open peer's control stream 3
[2025-04-30T17:19:57.287769361Z TRACE quiche::h3::stream] a4231187ece90a57c2217f5d6ad95c92062ca8d4 read 1 bytes on stream 3
[2025-04-30T17:19:57.287786423Z TRACE quiche::h3::stream] a4231187ece90a57c2217f5d6ad95c92062ca8d4 read 1 bytes on stream 3
[2025-04-30T17:19:57.287790531Z TRACE quiche::h3::stream] a4231187ece90a57c2217f5d6ad95c92062ca8d4 read 37 bytes on stream 3
[2025-04-30T17:19:57.287794128Z TRACE quiche::h3] a4231187ece90a57c2217f5d6ad95c92062ca8d4 rx frm SETTINGS max_field_section=Some(131072), qpack_max_table=Some(4096), qpack_blocked=Some(100) raw=Some([(1, 4096), (6, 131072), (7, 100), (8, 1), (16765559, 1), (630, 1), (51, 1), (727725890, 1), (33, 4207849484)]), additional_settings=Some([(16765559, 1), (727725890, 1), (33, 4207849484)]) stream=3 payload_len=37
[2025-04-30T17:19:57.287803796Z TRACE quiche::h3] a4231187ece90a57c2217f5d6ad95c92062ca8d4 stream id 7 is readable
[2025-04-30T17:19:57.287807513Z TRACE quiche::h3::stream] a4231187ece90a57c2217f5d6ad95c92062ca8d4 read 1 bytes on stream 7
[2025-04-30T17:19:57.287810989Z TRACE quiche::h3] a4231187ece90a57c2217f5d6ad95c92062ca8d4 stream id 11 is readable
[2025-04-30T17:19:57.287814225Z TRACE quiche::h3::stream] a4231187ece90a57c2217f5d6ad95c92062ca8d4 read 1 bytes on stream 11
[2025-04-30T17:19:57.287826759Z TRACE quiche] a4231187ece90a57c2217f5d6ad95c92062ca8d4 tx pkt Handshake version=1 dcid=4000008b102e8f85 scid=a4231187ece90a57c2217f5d6ad95c92062ca8d4 len=49 pn=2 
[2025-04-30T17:19:57.287829684Z TRACE quiche] a4231187ece90a57c2217f5d6ad95c92062ca8d4 tx frm ACK delay=71 blocks=[14215648..14215648] ecn_counts=None
[2025-04-30T17:19:57.287832830Z TRACE quiche] a4231187ece90a57c2217f5d6ad95c92062ca8d4 tx frm CRYPTO off=0 len=36
[2025-04-30T17:19:57.287840485Z TRACE quiche::recovery::congestion::recovery] a4231187ece90a57c2217f5d6ad95c92062ca8d4 timer=121.657701ms latest_rtt=40.559661ms srtt=40.559661ms min_rtt=40.559661ms rttvar=20.27983ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=103 app_limited=true congestion_recovery_start_time=None Rate { delivered: 333, delivered_time: Instant { tv_sec: 859, tv_nsec: 816036965 }, first_sent_time: Instant { tv_sec: 859, tv_nsec: 816036965 }, end_of_app_limited: 1, last_sent_packet: 2, largest_acked: 0, rate_sample: RateSample { delivery_rate: 8210, is_app_limited: true, interval: 40.559661ms, delivered: 333, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 859, tv_nsec: 774548261 }), send_elapsed: 0ns, ack_elapsed: 40.559661ms, rtt: 40.559661ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 103, rate: 416053, last_update: Instant { tv_sec: 859, tv_nsec: 816036935 }, next_time: Instant { tv_sec: 859, tv_nsec: 816036965 }, max_datagram_size: 1350, last_packet_size: Some(103), 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-30T17:19:57.287864039Z TRACE quiche] a4231187ece90a57c2217f5d6ad95c92062ca8d4 dropped epoch 0 state
[2025-04-30T17:19:57.287868618Z TRACE quiche] a4231187ece90a57c2217f5d6ad95c92062ca8d4 pmtud probe status false hs_con=false hs_sent=false cwnd_avail=13397 out_len=1247 left=1213
[2025-04-30T17:19:57.287874148Z TRACE quiche] a4231187ece90a57c2217f5d6ad95c92062ca8d4 tx pkt Short dcid=4000008b102e8f85 key_phase=false len=72 pn=3 
[2025-04-30T17:19:57.287876593Z TRACE quiche] a4231187ece90a57c2217f5d6ad95c92062ca8d4 tx frm ACK delay=35 blocks=[14215648..14215648] ecn_counts=None
[2025-04-30T17:19:57.287879217Z TRACE quiche] a4231187ece90a57c2217f5d6ad95c92062ca8d4 tx frm NEW_CONNECTION_ID seq_num=1 retire_prior_to=0 conn_id=[1f, 98, 74, 5f, 4b, 6f, ae, 01, 63, a3, bd, 18, 33, 39, cb, 07, a3, bb, 3a, 5f] reset_token=[cf, c7, f8, c7, c0, 78, 2b, a3, d8, 02, c8, b3, 3e, 61, 03, 21]
[2025-04-30T17:19:57.287885830Z TRACE quiche] a4231187ece90a57c2217f5d6ad95c92062ca8d4 tx frm STREAM id=2 off=0 len=19 fin=false
[2025-04-30T17:19:57.287892151Z TRACE quiche::recovery::congestion::recovery] a4231187ece90a57c2217f5d6ad95c92062ca8d4 timer=121.606084ms latest_rtt=40.559661ms srtt=40.559661ms min_rtt=40.559661ms rttvar=20.27983ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=201 app_limited=true congestion_recovery_start_time=None Rate { delivered: 333, delivered_time: Instant { tv_sec: 859, tv_nsec: 816036965 }, first_sent_time: Instant { tv_sec: 859, tv_nsec: 816036965 }, end_of_app_limited: 2, last_sent_packet: 3, largest_acked: 0, rate_sample: RateSample { delivery_rate: 8210, is_app_limited: true, interval: 40.559661ms, delivered: 333, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 859, tv_nsec: 774548261 }), send_elapsed: 0ns, ack_elapsed: 40.559661ms, rtt: 40.559661ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 416053, last_update: Instant { tv_sec: 859, tv_nsec: 816306591 }, next_time: Instant { tv_sec: 859, tv_nsec: 816036965 }, max_datagram_size: 1350, last_packet_size: None, iv: 483.112µ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-30T17:19:57.287924973Z TRACE quiche_apps::client] written 201 bytes from [::]:41995 to [fd00:cafe:cafe:100::100]:443
[2025-04-30T17:19:57.287935042Z TRACE quiche] a4231187ece90a57c2217f5d6ad95c92062ca8d4 pmtud probe status false hs_con=false hs_sent=false cwnd_avail=13299 out_len=1350 left=1324
[2025-04-30T17:19:57.287940913Z TRACE quiche] a4231187ece90a57c2217f5d6ad95c92062ca8d4 tx pkt Short dcid=4000008b102e8f85 key_phase=false len=6 pn=4 
[2025-04-30T17:19:57.287945051Z TRACE quiche] a4231187ece90a57c2217f5d6ad95c92062ca8d4 tx frm STREAM id=6 off=0 len=1 fin=false
[2025-04-30T17:19:57.287953757Z TRACE quiche::recovery::congestion::recovery] a4231187ece90a57c2217f5d6ad95c92062ca8d4 timer=121.544098ms latest_rtt=40.559661ms srtt=40.559661ms min_rtt=40.559661ms rttvar=20.27983ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=233 app_limited=true congestion_recovery_start_time=None Rate { delivered: 333, delivered_time: Instant { tv_sec: 859, tv_nsec: 816036965 }, first_sent_time: Instant { tv_sec: 859, tv_nsec: 816036965 }, end_of_app_limited: 3, last_sent_packet: 4, largest_acked: 0, rate_sample: RateSample { delivery_rate: 8210, is_app_limited: true, interval: 40.559661ms, delivered: 333, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 859, tv_nsec: 774548261 }), send_elapsed: 0ns, ack_elapsed: 40.559661ms, rtt: 40.559661ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 32, rate: 416053, last_update: Instant { tv_sec: 859, tv_nsec: 816306591 }, next_time: Instant { tv_sec: 859, tv_nsec: 816901553 }, 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-30T17:19:57.287991277Z TRACE quiche_apps::client] written 32 bytes from [::]:41995 to [fd00:cafe:cafe:100::100]:443
[2025-04-30T17:19:57.288001056Z TRACE quiche] a4231187ece90a57c2217f5d6ad95c92062ca8d4 pmtud probe status false hs_con=false hs_sent=false cwnd_avail=13267 out_len=1350 left=1324
[2025-04-30T17:19:57.288006616Z TRACE quiche] a4231187ece90a57c2217f5d6ad95c92062ca8d4 tx pkt Short dcid=4000008b102e8f85 key_phase=false len=6 pn=5 
[2025-04-30T17:19:57.288010624Z TRACE quiche] a4231187ece90a57c2217f5d6ad95c92062ca8d4 tx frm STREAM id=10 off=0 len=1 fin=false
[2025-04-30T17:19:57.288019441Z TRACE quiche::recovery::congestion::recovery] a4231187ece90a57c2217f5d6ad95c92062ca8d4 timer=121.478104ms latest_rtt=40.559661ms srtt=40.559661ms min_rtt=40.559661ms rttvar=20.27983ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=265 app_limited=true congestion_recovery_start_time=None Rate { delivered: 333, delivered_time: Instant { tv_sec: 859, tv_nsec: 816036965 }, first_sent_time: Instant { tv_sec: 859, tv_nsec: 816036965 }, end_of_app_limited: 4, last_sent_packet: 5, largest_acked: 0, rate_sample: RateSample { delivery_rate: 8210, is_app_limited: true, interval: 40.559661ms, delivered: 333, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 859, tv_nsec: 774548261 }), send_elapsed: 0ns, ack_elapsed: 40.559661ms, rtt: 40.559661ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 64, rate: 416053, last_update: Instant { tv_sec: 859, tv_nsec: 816306591 }, next_time: Instant { tv_sec: 859, tv_nsec: 816901553 }, 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-30T17:19:57.288048395Z TRACE quiche_apps::client] written 32 bytes from [::]:41995 to [fd00:cafe:cafe:100::100]:443
[2025-04-30T17:19:57.288057321Z TRACE quiche] a4231187ece90a57c2217f5d6ad95c92062ca8d4 pmtud probe status false hs_con=false hs_sent=false cwnd_avail=13235 out_len=1350 left=1324
[2025-04-30T17:19:57.288063042Z TRACE quiche] a4231187ece90a57c2217f5d6ad95c92062ca8d4 tx pkt Short dcid=4000008b102e8f85 key_phase=false len=73 pn=6 
[2025-04-30T17:19:57.288066919Z TRACE quiche] a4231187ece90a57c2217f5d6ad95c92062ca8d4 tx frm STREAM id=0 off=0 len=68 fin=true
[2025-04-30T17:19:57.288075806Z TRACE quiche::recovery::congestion::recovery] a4231187ece90a57c2217f5d6ad95c92062ca8d4 timer=121.42215ms latest_rtt=40.559661ms srtt=40.559661ms min_rtt=40.559661ms rttvar=20.27983ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=364 app_limited=true congestion_recovery_start_time=None Rate { delivered: 333, delivered_time: Instant { tv_sec: 859, tv_nsec: 816036965 }, first_sent_time: Instant { tv_sec: 859, tv_nsec: 816036965 }, end_of_app_limited: 5, last_sent_packet: 6, largest_acked: 0, rate_sample: RateSample { delivery_rate: 8210, is_app_limited: true, interval: 40.559661ms, delivered: 333, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 859, tv_nsec: 774548261 }), send_elapsed: 0ns, ack_elapsed: 40.559661ms, rtt: 40.559661ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 416053, last_update: Instant { tv_sec: 859, tv_nsec: 816540860 }, next_time: Instant { tv_sec: 859, tv_nsec: 816901553 }, max_datagram_size: 1350, last_packet_size: None, iv: 391.777µ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-30T17:19:57.288108407Z TRACE quiche_apps::client] written 99 bytes from [::]:41995 to [fd00:cafe:cafe:100::100]:443
[2025-04-30T17:19:57.288117404Z TRACE quiche] a4231187ece90a57c2217f5d6ad95c92062ca8d4 pmtud probe status false hs_con=false hs_sent=false cwnd_avail=13136 out_len=1350 left=1324
[2025-04-30T17:19:57.288123195Z TRACE quiche] a4231187ece90a57c2217f5d6ad95c92062ca8d4 tx pkt Short dcid=4000008b102e8f85 key_phase=false len=36 pn=7 
[2025-04-30T17:19:57.288127453Z TRACE quiche] a4231187ece90a57c2217f5d6ad95c92062ca8d4 tx frm STREAM id=4 off=0 len=31 fin=true
[2025-04-30T17:19:57.288137372Z TRACE quiche::recovery::congestion::recovery] a4231187ece90a57c2217f5d6ad95c92062ca8d4 timer=121.360564ms latest_rtt=40.559661ms srtt=40.559661ms min_rtt=40.559661ms rttvar=20.27983ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=426 app_limited=true congestion_recovery_start_time=None Rate { delivered: 333, delivered_time: Instant { tv_sec: 859, tv_nsec: 816036965 }, first_sent_time: Instant { tv_sec: 859, tv_nsec: 816036965 }, end_of_app_limited: 6, last_sent_packet: 7, largest_acked: 0, rate_sample: RateSample { delivery_rate: 8210, is_app_limited: true, interval: 40.559661ms, delivered: 333, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 859, tv_nsec: 774548261 }), send_elapsed: 0ns, ack_elapsed: 40.559661ms, rtt: 40.559661ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 62, rate: 416053, last_update: Instant { tv_sec: 859, tv_nsec: 816540860 }, next_time: Instant { tv_sec: 859, tv_nsec: 817293330 }, max_datagram_size: 1350, last_packet_size: Some(62), 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-30T17:19:57.288164883Z TRACE quiche_apps::client] written 62 bytes from [::]:41995 to [fd00:cafe:cafe:100::100]:443
[2025-04-30T17:19:57.288173820Z TRACE quiche] a4231187ece90a57c2217f5d6ad95c92062ca8d4 pmtud probe status false hs_con=false hs_sent=false cwnd_avail=13074 out_len=1350 left=1324
[2025-04-30T17:19:57.288179120Z TRACE quiche] a4231187ece90a57c2217f5d6ad95c92062ca8d4 tx pkt Short dcid=4000008b102e8f85 key_phase=false len=31 pn=8 
[2025-04-30T17:19:57.288183117Z TRACE quiche] a4231187ece90a57c2217f5d6ad95c92062ca8d4 tx frm STREAM id=14 off=0 len=26 fin=true
[2025-04-30T17:19:57.288191664Z TRACE quiche::recovery::congestion::recovery] a4231187ece90a57c2217f5d6ad95c92062ca8d4 timer=121.305992ms latest_rtt=40.559661ms srtt=40.559661ms min_rtt=40.559661ms rttvar=20.27983ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=483 app_limited=true congestion_recovery_start_time=None Rate { delivered: 333, delivered_time: Instant { tv_sec: 859, tv_nsec: 816036965 }, first_sent_time: Instant { tv_sec: 859, tv_nsec: 816036965 }, end_of_app_limited: 7, last_sent_packet: 8, largest_acked: 0, rate_sample: RateSample { delivery_rate: 8210, is_app_limited: true, interval: 40.559661ms, delivered: 333, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 859, tv_nsec: 774548261 }), send_elapsed: 0ns, ack_elapsed: 40.559661ms, rtt: 40.559661ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 416053, last_update: Instant { tv_sec: 859, tv_nsec: 816657609 }, next_time: Instant { tv_sec: 859, tv_nsec: 817293330 }, max_datagram_size: 1350, last_packet_size: None, iv: 286.021µ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-30T17:19:57.288219526Z TRACE quiche_apps::client] written 57 bytes from [::]:41995 to [fd00:cafe:cafe:100::100]:443
[2025-04-30T17:19:57.288231298Z TRACE quiche_apps::client] [::]:41995 -> [fd00:cafe:cafe:100::100]:443: done writing
[2025-04-30T17:19:57.318812207Z TRACE quiche_apps::client] got 58 bytes from [fd00:cafe:cafe:100::100]:443 to [::]:41995
[2025-04-30T17:19:57.318824349Z TRACE quiche] a4231187ece90a57c2217f5d6ad95c92062ca8d4 rx pkt Handshake version=1 dcid=a4231187ece90a57c2217f5d6ad95c92062ca8d4 scid=4000008b102e8f85 len=22 pn=14215649 
[2025-04-30T17:19:57.318832134Z TRACE quiche] a4231187ece90a57c2217f5d6ad95c92062ca8d4 rx frm ACK delay=40 blocks=[2..2] ecn_counts=None
[2025-04-30T17:19:57.318836482Z TRACE quiche::recovery::congestion::recovery] a4231187ece90a57c2217f5d6ad95c92062ca8d4 packet newly acked 2
[2025-04-30T17:19:57.318851471Z TRACE quiche_apps::client] [::]:41995: processed 58 bytes
[2025-04-30T17:19:57.318856239Z TRACE quiche_apps::client] [::]:41995: recv() would block
[2025-04-30T17:19:57.318859185Z TRACE quiche_apps::client] done reading
[2025-04-30T17:19:57.318864896Z TRACE quiche_apps::client] [::]:41995 -> [fd00:cafe:cafe:100::100]:443: done writing
[2025-04-30T17:19:57.319193492Z TRACE quiche_apps::client] got 432 bytes from [fd00:cafe:cafe:100::100]:443 to [::]:41995
[2025-04-30T17:19:57.319199003Z TRACE quiche] a4231187ece90a57c2217f5d6ad95c92062ca8d4 rx pkt Short dcid=a4231187ece90a57c2217f5d6ad95c92062ca8d4 key_phase=false len=411 pn=14215649 
[2025-04-30T17:19:57.319205505Z TRACE quiche] a4231187ece90a57c2217f5d6ad95c92062ca8d4 rx frm CRYPTO off=0 len=242
[2025-04-30T17:19:57.319223138Z TRACE quiche] a4231187ece90a57c2217f5d6ad95c92062ca8d4 rx frm ACK delay=46 blocks=[3..3] ecn_counts=None
[2025-04-30T17:19:57.319227326Z TRACE quiche::recovery::congestion::recovery] a4231187ece90a57c2217f5d6ad95c92062ca8d4 packet newly acked 3
[2025-04-30T17:19:57.319231493Z TRACE quiche] a4231187ece90a57c2217f5d6ad95c92062ca8d4 rx frm HANDSHAKE_DONE
[2025-04-30T17:19:57.319235311Z TRACE quiche] a4231187ece90a57c2217f5d6ad95c92062ca8d4 dropped epoch 1 state
[2025-04-30T17:19:57.319240130Z TRACE quiche] a4231187ece90a57c2217f5d6ad95c92062ca8d4 rx frm NEW_CONNECTION_ID seq_num=1 retire_prior_to=0 conn_id=[40, 00, 00, 96, c5, 81, c3, 8b] reset_token=[62, 8d, 73, 3d, 69, ba, ee, 15, 05, 4c, 2d, 24, 9f, 31, 30, 25]
[2025-04-30T17:19:57.319247454Z TRACE quiche] a4231187ece90a57c2217f5d6ad95c92062ca8d4 rx frm NEW_CONNECTION_ID seq_num=2 retire_prior_to=0 conn_id=[40, 00, 00, 9a, 54, a3, 4f, db] reset_token=[13, e2, 81, 53, c7, 36, 2d, 01, 40, 49, 68, 9d, a3, ed, 92, 8b]
[2025-04-30T17:19:57.319253515Z TRACE quiche] a4231187ece90a57c2217f5d6ad95c92062ca8d4 rx frm NEW_CONNECTION_ID seq_num=3 retire_prior_to=0 conn_id=[40, 00, 00, 98, ca, a6, 6f, 44] reset_token=[f3, 5a, dc, 9e, f6, ac, 3c, e7, 1a, 56, f4, b8, 96, f7, 0b, ec]
[2025-04-30T17:19:57.319259276Z TRACE quiche] a4231187ece90a57c2217f5d6ad95c92062ca8d4 rx frm NEW_CONNECTION_ID seq_num=4 retire_prior_to=0 conn_id=[40, 00, 00, 8f, f6, a8, c9, 82] reset_token=[71, b0, aa, c1, 21, 28, 61, 79, 9c, 02, eb, c8, c9, 15, 96, 45]
[2025-04-30T17:19:57.319264245Z TRACE quiche] a4231187ece90a57c2217f5d6ad95c92062ca8d4 rx frm PADDING len=30
[2025-04-30T17:19:57.319277620Z TRACE quiche_apps::client] [::]:41995: processed 432 bytes
[2025-04-30T17:19:57.319281968Z TRACE quiche_apps::client] [::]:41995: recv() would block
[2025-04-30T17:19:57.319284723Z TRACE quiche_apps::client] done reading
[2025-04-30T17:19:57.319292488Z TRACE quiche] a4231187ece90a57c2217f5d6ad95c92062ca8d4 pmtud probe status false hs_con=true hs_sent=false cwnd_avail=13218 out_len=1350 left=1316
[2025-04-30T17:19:57.319296666Z TRACE quiche] a4231187ece90a57c2217f5d6ad95c92062ca8d4 tx pkt Short dcid=4000008b102e8f85 key_phase=false len=8 pn=9 
[2025-04-30T17:19:57.319299752Z TRACE quiche] a4231187ece90a57c2217f5d6ad95c92062ca8d4 tx frm ACK delay=11 blocks=[14215649..14215649] ecn_counts=None
[2025-04-30T17:19:57.319306975Z TRACE quiche::recovery::congestion::recovery] a4231187ece90a57c2217f5d6ad95c92062ca8d4 timer=92.96072ms latest_rtt=31.648051ms srtt=38.38394ms min_rtt=31.272637ms rttvar=15.178403ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=282 app_limited=true congestion_recovery_start_time=None Rate { delivered: 534, delivered_time: Instant { tv_sec: 859, tv_nsec: 847685016 }, first_sent_time: Instant { tv_sec: 859, tv_nsec: 816036965 }, end_of_app_limited: 8, last_sent_packet: 9, largest_acked: 3, rate_sample: RateSample { delivery_rate: 6427, is_app_limited: true, interval: 31.272637ms, delivered: 201, prior_delivered: 333, prior_time: Some(Instant { tv_sec: 859, tv_nsec: 816036965 }), send_elapsed: 0ns, ack_elapsed: 31.272637ms, rtt: 31.272637ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 439636, last_update: Instant { tv_sec: 859, tv_nsec: 847776267 }, next_time: Instant { tv_sec: 859, tv_nsec: 848062288 }, 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-30T17:19:57.319351959Z TRACE quiche_apps::client] written 34 bytes from [::]:41995 to [fd00:cafe:cafe:100::100]:443
[2025-04-30T17:19:57.319359905Z TRACE quiche_apps::client] [::]:41995 -> [fd00:cafe:cafe:100::100]:443: done writing
[2025-04-30T17:19:57.319373279Z TRACE quiche_apps::client] got 112 bytes from [fd00:cafe:cafe:100::100]:443 to [::]:41995
[2025-04-30T17:19:57.319380523Z TRACE quiche] a4231187ece90a57c2217f5d6ad95c92062ca8d4 rx pkt Short dcid=a4231187ece90a57c2217f5d6ad95c92062ca8d4 key_phase=false len=91 pn=14215650 
[2025-04-30T17:19:57.319390592Z TRACE quiche] a4231187ece90a57c2217f5d6ad95c92062ca8d4 rx frm ACK delay=67 blocks=[3..6] ecn_counts=None
[2025-04-30T17:19:57.319397064Z TRACE quiche::recovery::congestion::recovery] a4231187ece90a57c2217f5d6ad95c92062ca8d4 packet newly acked 4
[2025-04-30T17:19:57.319400691Z TRACE quiche::recovery::congestion::recovery] a4231187ece90a57c2217f5d6ad95c92062ca8d4 packet newly acked 5
[2025-04-30T17:19:57.319403436Z TRACE quiche::recovery::congestion::recovery] a4231187ece90a57c2217f5d6ad95c92062ca8d4 packet newly acked 6
[2025-04-30T17:19:57.319407734Z TRACE quiche] a4231187ece90a57c2217f5d6ad95c92062ca8d4 rx frm STREAM id=0 off=0 len=62 fin=false
[2025-04-30T17:19:57.319411852Z TRACE quiche] a4231187ece90a57c2217f5d6ad95c92062ca8d4 rx frm PADDING len=3
[2025-04-30T17:19:57.319424516Z TRACE quiche_apps::client] [::]:41995: processed 112 bytes
[2025-04-30T17:19:57.319428984Z TRACE quiche_apps::client] [::]:41995: recv() would block
[2025-04-30T17:19:57.319431799Z TRACE quiche_apps::client] done reading
[2025-04-30T17:19:57.319434895Z TRACE quiche::h3] a4231187ece90a57c2217f5d6ad95c92062ca8d4 stream id 0 is readable
[2025-04-30T17:19:57.319439314Z TRACE quiche::h3::stream] a4231187ece90a57c2217f5d6ad95c92062ca8d4 read 1 bytes on stream 0
[2025-04-30T17:19:57.319443191Z TRACE quiche::h3::stream] a4231187ece90a57c2217f5d6ad95c92062ca8d4 read 1 bytes on stream 0
[2025-04-30T17:19:57.319447038Z TRACE quiche::h3::stream] a4231187ece90a57c2217f5d6ad95c92062ca8d4 read 1 bytes on stream 0
[2025-04-30T17:19:57.319450324Z TRACE quiche::h3] a4231187ece90a57c2217f5d6ad95c92062ca8d4 rx frm UNKNOWN raw_type=157 stream=0 payload_len=0
[2025-04-30T17:19:57.319456145Z TRACE quiche::h3::stream] a4231187ece90a57c2217f5d6ad95c92062ca8d4 read 1 bytes on stream 0
[2025-04-30T17:19:57.319459832Z TRACE quiche::h3::stream] a4231187ece90a57c2217f5d6ad95c92062ca8d4 read 1 bytes on stream 0
[2025-04-30T17:19:57.319464310Z TRACE quiche::h3::stream] a4231187ece90a57c2217f5d6ad95c92062ca8d4 read 57 bytes on stream 0
[2025-04-30T17:19:57.319467346Z TRACE quiche::h3] a4231187ece90a57c2217f5d6ad95c92062ca8d4 rx frm HEADERS stream=0 payload_len=57
[2025-04-30T17:19:57.319470762Z TRACE quiche::h3::qpack::decoder] Header count=0 base=0
[2025-04-30T17:19:57.319473828Z TRACE quiche::h3::qpack::decoder] Indexed index=25 static=true
[2025-04-30T17:19:57.319484969Z TRACE quiche::h3::qpack::decoder] Literal name_idx=83 static=true value=[104, 51, 61, 34, 58, 52, 52, 51, 34, 59, 32, 109, 97, 61, 51, 54, 48, 48]
[2025-04-30T17:19:57.319490890Z TRACE quiche::h3::qpack::decoder] Literal Without Name Reference name=[112, 114, 105, 111, 114, 105, 116, 121] value=[117, 61, 51, 44, 105]
[2025-04-30T17:19:57.319496611Z TRACE quiche::h3::qpack::decoder] Literal name_idx=6 static=true value=[87, 101, 100, 44, 32, 51, 48, 32, 65, 112, 114, 32, 50, 48, 50, 53, 32, 49, 55, 58, 49, 57, 58, 53, 55, 32, 71, 77, 84]
[2025-04-30T17:19:57.319539091Z DEBUG quiche_apps::common] got response headers [(":status", "200"), ("alt-svc", "h3=\":443\"; ma=3600"), ("priority", "u=3,i"), ("date", "Wed, 30 Apr 2025 17:19:57 GMT")] on stream id 0
[2025-04-30T17:19:57.319549280Z TRACE quiche] a4231187ece90a57c2217f5d6ad95c92062ca8d4 pmtud probe status false hs_con=true hs_sent=false cwnd_avail=13381 out_len=1350 left=1316
[2025-04-30T17:19:57.319552516Z TRACE quiche] a4231187ece90a57c2217f5d6ad95c92062ca8d4 tx pkt Short dcid=4000008b102e8f85 key_phase=false len=8 pn=10 
[2025-04-30T17:19:57.319554940Z TRACE quiche] a4231187ece90a57c2217f5d6ad95c92062ca8d4 tx frm ACK delay=21 blocks=[14215649..14215650] ecn_counts=None
[2025-04-30T17:19:57.319561202Z TRACE quiche::recovery::congestion::recovery] a4231187ece90a57c2217f5d6ad95c92062ca8d4 timer=84.019877ms latest_rtt=30.964843ms srtt=37.456552ms min_rtt=30.964843ms rttvar=13.238576ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=119 app_limited=true congestion_recovery_start_time=None Rate { delivered: 697, delivered_time: Instant { tv_sec: 859, tv_nsec: 847866396 }, first_sent_time: Instant { tv_sec: 859, tv_nsec: 816036965 }, end_of_app_limited: 9, last_sent_packet: 10, largest_acked: 6, rate_sample: RateSample { delivery_rate: 11639, is_app_limited: true, interval: 31.272637ms, delivered: 364, prior_delivered: 333, prior_time: Some(Instant { tv_sec: 859, tv_nsec: 816036965 }), send_elapsed: 0ns, ack_elapsed: 31.272637ms, rtt: 31.272637ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 450521, last_update: Instant { tv_sec: 859, tv_nsec: 847776267 }, next_time: Instant { tv_sec: 859, tv_nsec: 848062288 }, 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-30T17:19:57.319590397Z TRACE quiche_apps::client] written 34 bytes from [::]:41995 to [fd00:cafe:cafe:100::100]:443
[2025-04-30T17:19:57.319596999Z TRACE quiche_apps::client] [::]:41995 -> [fd00:cafe:cafe:100::100]:443: done writing
[2025-04-30T17:19:57.320381181Z TRACE quiche_apps::client] got 1232 bytes from [fd00:cafe:cafe:100::100]:443 to [::]:41995
[2025-04-30T17:19:57.320386411Z TRACE quiche] a4231187ece90a57c2217f5d6ad95c92062ca8d4 rx pkt Short dcid=a4231187ece90a57c2217f5d6ad95c92062ca8d4 key_phase=false len=1211 pn=14215651 
[2025-04-30T17:19:57.320392191Z TRACE quiche] a4231187ece90a57c2217f5d6ad95c92062ca8d4 rx frm ACK delay=82 blocks=[3..7] ecn_counts=None
[2025-04-30T17:19:57.320395377Z TRACE quiche::recovery::congestion::recovery] a4231187ece90a57c2217f5d6ad95c92062ca8d4 packet newly acked 7
[2025-04-30T17:19:57.320400096Z TRACE quiche] a4231187ece90a57c2217f5d6ad95c92062ca8d4 rx frm STREAM id=0 off=62 len=1185 fin=false
[2025-04-30T17:19:57.320409774Z TRACE quiche_apps::client] [::]:41995: processed 1232 bytes
[2025-04-30T17:19:57.320413211Z TRACE quiche_apps::client] [::]:41995: recv() would block
[2025-04-30T17:19:57.320415545Z TRACE quiche_apps::client] done reading
[2025-04-30T17:19:57.320418080Z TRACE quiche::h3] a4231187ece90a57c2217f5d6ad95c92062ca8d4 stream id 0 is readable
[2025-04-30T17:19:57.320421626Z TRACE quiche::h3::stream] a4231187ece90a57c2217f5d6ad95c92062ca8d4 read 1 bytes on stream 0
[2025-04-30T17:19:57.320429541Z TRACE quiche::h3::stream] a4231187ece90a57c2217f5d6ad95c92062ca8d4 read 1 bytes on stream 0
[2025-04-30T17:19:57.320432637Z TRACE quiche::h3::stream] a4231187ece90a57c2217f5d6ad95c92062ca8d4 read 1 bytes on stream 0
[2025-04-30T17:19:57.320434922Z TRACE quiche::h3] a4231187ece90a57c2217f5d6ad95c92062ca8d4 rx frm DATA stream=0 wire_payload_len=5120
[2025-04-30T17:19:57.320440081Z DEBUG quiche_apps::common] got 1182 bytes of response data on stream 0
[2025-04-30T17:19:57.320446734Z TRACE quiche] a4231187ece90a57c2217f5d6ad95c92062ca8d4 pmtud probe status false hs_con=true hs_sent=false cwnd_avail=13443 out_len=1350 left=1316
[2025-04-30T17:19:57.320449819Z TRACE quiche] a4231187ece90a57c2217f5d6ad95c92062ca8d4 tx pkt Short dcid=4000008b102e8f85 key_phase=false len=8 pn=11 
[2025-04-30T17:19:57.320452184Z TRACE quiche] a4231187ece90a57c2217f5d6ad95c92062ca8d4 tx frm ACK delay=7 blocks=[14215649..14215651] ecn_counts=None
[2025-04-30T17:19:57.320457834Z TRACE quiche::recovery::congestion::recovery] a4231187ece90a57c2217f5d6ad95c92062ca8d4 timer=75.02761ms latest_rtt=31.578994ms srtt=36.721857ms min_rtt=30.964843ms rttvar=11.398321ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=57 app_limited=true congestion_recovery_start_time=None Rate { delivered: 759, delivered_time: Instant { tv_sec: 859, tv_nsec: 848872324 }, first_sent_time: Instant { tv_sec: 859, tv_nsec: 816036965 }, end_of_app_limited: 10, last_sent_packet: 11, largest_acked: 7, rate_sample: RateSample { delivery_rate: 13622, is_app_limited: true, interval: 31.272637ms, delivered: 426, prior_delivered: 333, prior_time: Some(Instant { tv_sec: 859, tv_nsec: 816036965 }), send_elapsed: 0ns, ack_elapsed: 31.272637ms, rtt: 31.272637ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 459535, last_update: Instant { tv_sec: 859, tv_nsec: 847776267 }, next_time: Instant { tv_sec: 859, tv_nsec: 848062288 }, 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-30T17:19:57.320487490Z TRACE quiche_apps::client] written 34 bytes from [::]:41995 to [fd00:cafe:cafe:100::100]:443
[2025-04-30T17:19:57.320494133Z TRACE quiche_apps::client] [::]:41995 -> [fd00:cafe:cafe:100::100]:443: done writing
[2025-04-30T17:19:57.321402817Z TRACE quiche_apps::client] got 1232 bytes from [fd00:cafe:cafe:100::100]:443 to [::]:41995
[2025-04-30T17:19:57.321410782Z TRACE quiche] a4231187ece90a57c2217f5d6ad95c92062ca8d4 rx pkt Short dcid=a4231187ece90a57c2217f5d6ad95c92062ca8d4 key_phase=false len=1211 pn=14215652 
[2025-04-30T17:19:57.321416443Z TRACE quiche] a4231187ece90a57c2217f5d6ad95c92062ca8d4 rx frm STREAM id=4 off=0 len=59 fin=false
[2025-04-30T17:19:57.321420500Z TRACE quiche] a4231187ece90a57c2217f5d6ad95c92062ca8d4 rx frm STREAM id=0 off=1247 len=1128 fin=false
[2025-04-30T17:19:57.321427193Z TRACE quiche_apps::client] [::]:41995: processed 1232 bytes
[2025-04-30T17:19:57.321430570Z TRACE quiche_apps::client] [::]:41995: recv() would block
[2025-04-30T17:19:57.321432854Z TRACE quiche_apps::client] done reading
[2025-04-30T17:19:57.321435469Z TRACE quiche::h3] a4231187ece90a57c2217f5d6ad95c92062ca8d4 stream id 4 is readable
[2025-04-30T17:19:57.321439176Z TRACE quiche::h3::stream] a4231187ece90a57c2217f5d6ad95c92062ca8d4 read 1 bytes on stream 4
[2025-04-30T17:19:57.321442372Z TRACE quiche::h3::stream] a4231187ece90a57c2217f5d6ad95c92062ca8d4 read 1 bytes on stream 4
[2025-04-30T17:19:57.321446068Z TRACE quiche::h3::stream] a4231187ece90a57c2217f5d6ad95c92062ca8d4 read 57 bytes on stream 4
[2025-04-30T17:19:57.321448573Z TRACE quiche::h3] a4231187ece90a57c2217f5d6ad95c92062ca8d4 rx frm HEADERS stream=4 payload_len=57
[2025-04-30T17:19:57.321451238Z TRACE quiche::h3::qpack::decoder] Header count=0 base=0
[2025-04-30T17:19:57.321453493Z TRACE quiche::h3::qpack::decoder] Indexed index=25 static=true
[2025-04-30T17:19:57.321460927Z TRACE quiche::h3::qpack::decoder] Literal name_idx=83 static=true value=[104, 51, 61, 34, 58, 52, 52, 51, 34, 59, 32, 109, 97, 61, 51, 54, 48, 48]
[2025-04-30T17:19:57.321464934Z TRACE quiche::h3::qpack::decoder] Literal Without Name Reference name=[112, 114, 105, 111, 114, 105, 116, 121] value=[117, 61, 51, 44, 105]
[2025-04-30T17:19:57.321468310Z TRACE quiche::h3::qpack::decoder] Literal name_idx=6 static=true value=[87, 101, 100, 44, 32, 51, 48, 32, 65, 112, 114, 32, 50, 48, 50, 53, 32, 49, 55, 58, 49, 57, 58, 53, 55, 32, 71, 77, 84]
[2025-04-30T17:19:57.321475504Z DEBUG quiche_apps::common] got response headers [(":status", "200"), ("alt-svc", "h3=\":443\"; ma=3600"), ("priority", "u=3,i"), ("date", "Wed, 30 Apr 2025 17:19:57 GMT")] on stream id 4
[2025-04-30T17:19:57.321479671Z TRACE quiche::h3] a4231187ece90a57c2217f5d6ad95c92062ca8d4 stream id 0 is readable
[2025-04-30T17:19:57.321483469Z DEBUG quiche_apps::common] got 1128 bytes of response data on stream 0
[2025-04-30T17:19:57.321490071Z TRACE quiche] a4231187ece90a57c2217f5d6ad95c92062ca8d4 pmtud probe status false hs_con=true hs_sent=false cwnd_avail=13443 out_len=1350 left=1316
[2025-04-30T17:19:57.321493167Z TRACE quiche] a4231187ece90a57c2217f5d6ad95c92062ca8d4 tx pkt Short dcid=4000008b102e8f85 key_phase=false len=8 pn=12 
[2025-04-30T17:19:57.321495491Z TRACE quiche] a4231187ece90a57c2217f5d6ad95c92062ca8d4 tx frm ACK delay=9 blocks=[14215649..14215652] ecn_counts=None
[2025-04-30T17:19:57.321502254Z TRACE quiche::recovery::congestion::recovery] a4231187ece90a57c2217f5d6ad95c92062ca8d4 timer=73.98315ms latest_rtt=31.578994ms srtt=36.721857ms min_rtt=30.964843ms rttvar=11.398321ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=57 app_limited=true congestion_recovery_start_time=None Rate { delivered: 759, delivered_time: Instant { tv_sec: 859, tv_nsec: 848872324 }, first_sent_time: Instant { tv_sec: 859, tv_nsec: 816036965 }, end_of_app_limited: 10, last_sent_packet: 12, largest_acked: 7, rate_sample: RateSample { delivery_rate: 13622, is_app_limited: true, interval: 31.272637ms, delivered: 426, prior_delivered: 333, prior_time: Some(Instant { tv_sec: 859, tv_nsec: 816036965 }), send_elapsed: 0ns, ack_elapsed: 31.272637ms, rtt: 31.272637ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 459535, last_update: Instant { tv_sec: 859, tv_nsec: 847776267 }, next_time: Instant { tv_sec: 859, tv_nsec: 848062288 }, 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-30T17:19:57.321547178Z TRACE quiche_apps::client] written 34 bytes from [::]:41995 to [fd00:cafe:cafe:100::100]:443
[2025-04-30T17:19:57.321557648Z TRACE quiche_apps::client] [::]:41995 -> [fd00:cafe:cafe:100::100]:443: done writing
[2025-04-30T17:19:57.322426949Z TRACE quiche_apps::client] got 1232 bytes from [fd00:cafe:cafe:100::100]:443 to [::]:41995
[2025-04-30T17:19:57.322431778Z TRACE quiche] a4231187ece90a57c2217f5d6ad95c92062ca8d4 rx pkt Short dcid=a4231187ece90a57c2217f5d6ad95c92062ca8d4 key_phase=false len=1211 pn=14215653 
[2025-04-30T17:19:57.322437860Z TRACE quiche] a4231187ece90a57c2217f5d6ad95c92062ca8d4 rx frm STREAM id=0 off=2375 len=1190 fin=false
[2025-04-30T17:19:57.322444612Z TRACE quiche_apps::client] [::]:41995: processed 1232 bytes
[2025-04-30T17:19:57.322447938Z TRACE quiche_apps::client] [::]:41995: recv() would block
[2025-04-30T17:19:57.322450263Z TRACE quiche_apps::client] done reading
[2025-04-30T17:19:57.322452968Z TRACE quiche::h3] a4231187ece90a57c2217f5d6ad95c92062ca8d4 stream id 0 is readable
[2025-04-30T17:19:57.322457436Z DEBUG quiche_apps::common] got 1190 bytes of response data on stream 0
[2025-04-30T17:19:57.322463738Z TRACE quiche] a4231187ece90a57c2217f5d6ad95c92062ca8d4 pmtud probe status false hs_con=true hs_sent=false cwnd_avail=13443 out_len=1350 left=1316
[2025-04-30T17:19:57.322471833Z TRACE quiche] a4231187ece90a57c2217f5d6ad95c92062ca8d4 tx pkt Short dcid=4000008b102e8f85 key_phase=false len=8 pn=13 
[2025-04-30T17:19:57.322474348Z TRACE quiche] a4231187ece90a57c2217f5d6ad95c92062ca8d4 tx frm ACK delay=4 blocks=[14215649..14215653] ecn_counts=None
[2025-04-30T17:19:57.322480569Z TRACE quiche::recovery::congestion::recovery] a4231187ece90a57c2217f5d6ad95c92062ca8d4 timer=73.004835ms latest_rtt=31.578994ms srtt=36.721857ms min_rtt=30.964843ms rttvar=11.398321ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=57 app_limited=true congestion_recovery_start_time=None Rate { delivered: 759, delivered_time: Instant { tv_sec: 859, tv_nsec: 848872324 }, first_sent_time: Instant { tv_sec: 859, tv_nsec: 816036965 }, end_of_app_limited: 10, last_sent_packet: 13, largest_acked: 7, rate_sample: RateSample { delivery_rate: 13622, is_app_limited: true, interval: 31.272637ms, delivered: 426, prior_delivered: 333, prior_time: Some(Instant { tv_sec: 859, tv_nsec: 816036965 }), send_elapsed: 0ns, ack_elapsed: 31.272637ms, rtt: 31.272637ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 459535, last_update: Instant { tv_sec: 859, tv_nsec: 847776267 }, next_time: Instant { tv_sec: 859, tv_nsec: 848062288 }, 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-30T17:19:57.322509654Z TRACE quiche_apps::client] written 34 bytes from [::]:41995 to [fd00:cafe:cafe:100::100]:443
[2025-04-30T17:19:57.322532277Z TRACE quiche_apps::client] [::]:41995 -> [fd00:cafe:cafe:100::100]:443: done writing
[2025-04-30T17:19:57.323453245Z TRACE quiche_apps::client] got 1232 bytes from [fd00:cafe:cafe:100::100]:443 to [::]:41995
[2025-04-30T17:19:57.323458475Z TRACE quiche] a4231187ece90a57c2217f5d6ad95c92062ca8d4 rx pkt Short dcid=a4231187ece90a57c2217f5d6ad95c92062ca8d4 key_phase=false len=1211 pn=14215654 
[2025-04-30T17:19:57.323464716Z TRACE quiche] a4231187ece90a57c2217f5d6ad95c92062ca8d4 rx frm STREAM id=0 off=3565 len=1190 fin=false
[2025-04-30T17:19:57.323471609Z TRACE quiche_apps::client] [::]:41995: processed 1232 bytes
[2025-04-30T17:19:57.323474955Z TRACE quiche_apps::client] [::]:41995: recv() would block
[2025-04-30T17:19:57.323477240Z TRACE quiche_apps::client] done reading
[2025-04-30T17:19:57.323479864Z TRACE quiche::h3] a4231187ece90a57c2217f5d6ad95c92062ca8d4 stream id 0 is readable
[2025-04-30T17:19:57.323484343Z DEBUG quiche_apps::common] got 1190 bytes of response data on stream 0
[2025-04-30T17:19:57.323490605Z TRACE quiche] a4231187ece90a57c2217f5d6ad95c92062ca8d4 pmtud probe status false hs_con=true hs_sent=false cwnd_avail=13443 out_len=1350 left=1316
[2025-04-30T17:19:57.323493761Z TRACE quiche] a4231187ece90a57c2217f5d6ad95c92062ca8d4 tx pkt Short dcid=4000008b102e8f85 key_phase=false len=8 pn=14 
[2025-04-30T17:19:57.323496195Z TRACE quiche] a4231187ece90a57c2217f5d6ad95c92062ca8d4 tx frm ACK delay=4 blocks=[14215649..14215654] ecn_counts=None
[2025-04-30T17:19:57.323502046Z TRACE quiche::recovery::congestion::recovery] a4231187ece90a57c2217f5d6ad95c92062ca8d4 timer=71.983398ms latest_rtt=31.578994ms srtt=36.721857ms min_rtt=30.964843ms rttvar=11.398321ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=57 app_limited=true congestion_recovery_start_time=None Rate { delivered: 759, delivered_time: Instant { tv_sec: 859, tv_nsec: 848872324 }, first_sent_time: Instant { tv_sec: 859, tv_nsec: 816036965 }, end_of_app_limited: 10, last_sent_packet: 14, largest_acked: 7, rate_sample: RateSample { delivery_rate: 13622, is_app_limited: true, interval: 31.272637ms, delivered: 426, prior_delivered: 333, prior_time: Some(Instant { tv_sec: 859, tv_nsec: 816036965 }), send_elapsed: 0ns, ack_elapsed: 31.272637ms, rtt: 31.272637ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 459535, last_update: Instant { tv_sec: 859, tv_nsec: 847776267 }, next_time: Instant { tv_sec: 859, tv_nsec: 848062288 }, 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-30T17:19:57.323550447Z TRACE quiche_apps::client] written 34 bytes from [::]:41995 to [fd00:cafe:cafe:100::100]:443
[2025-04-30T17:19:57.323560907Z TRACE quiche_apps::client] [::]:41995 -> [fd00:cafe:cafe:100::100]:443: done writing
[2025-04-30T17:19:57.323891497Z TRACE quiche_apps::client] got 496 bytes from [fd00:cafe:cafe:100::100]:443 to [::]:41995
[2025-04-30T17:19:57.323896436Z TRACE quiche] a4231187ece90a57c2217f5d6ad95c92062ca8d4 rx pkt Short dcid=a4231187ece90a57c2217f5d6ad95c92062ca8d4 key_phase=false len=475 pn=14215655 
[2025-04-30T17:19:57.323901996Z TRACE quiche] a4231187ece90a57c2217f5d6ad95c92062ca8d4 rx frm STREAM id=0 off=4755 len=430 fin=true
[2025-04-30T17:19:57.323905533Z TRACE quiche] a4231187ece90a57c2217f5d6ad95c92062ca8d4 rx frm PADDING len=22
[2025-04-30T17:19:57.323911985Z TRACE quiche_apps::client] [::]:41995: processed 496 bytes
[2025-04-30T17:19:57.323915292Z TRACE quiche_apps::client] [::]:41995: recv() would block
[2025-04-30T17:19:57.323917576Z TRACE quiche_apps::client] done reading
[2025-04-30T17:19:57.323920081Z TRACE quiche::h3] a4231187ece90a57c2217f5d6ad95c92062ca8d4 stream id 0 is readable
[2025-04-30T17:19:57.323925561Z DEBUG quiche_apps::common] got 430 bytes of response data on stream 0
[2025-04-30T17:19:57.323928276Z DEBUG quiche_apps::common] 1/2 responses received
[2025-04-30T17:19:57.323934207Z TRACE quiche] a4231187ece90a57c2217f5d6ad95c92062ca8d4 pmtud probe status false hs_con=true hs_sent=false cwnd_avail=13443 out_len=1350 left=1316
[2025-04-30T17:19:57.323937273Z TRACE quiche] a4231187ece90a57c2217f5d6ad95c92062ca8d4 tx pkt Short dcid=4000008b102e8f85 key_phase=false len=8 pn=15 
[2025-04-30T17:19:57.323939637Z TRACE quiche] a4231187ece90a57c2217f5d6ad95c92062ca8d4 tx frm ACK delay=4 blocks=[14215649..14215655] ecn_counts=None
[2025-04-30T17:19:57.323945378Z TRACE quiche::recovery::congestion::recovery] a4231187ece90a57c2217f5d6ad95c92062ca8d4 timer=71.540076ms latest_rtt=31.578994ms srtt=36.721857ms min_rtt=30.964843ms rttvar=11.398321ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=57 app_limited=true congestion_recovery_start_time=None Rate { delivered: 759, delivered_time: Instant { tv_sec: 859, tv_nsec: 848872324 }, first_sent_time: Instant { tv_sec: 859, tv_nsec: 816036965 }, end_of_app_limited: 10, last_sent_packet: 15, largest_acked: 7, rate_sample: RateSample { delivery_rate: 13622, is_app_limited: true, interval: 31.272637ms, delivered: 426, prior_delivered: 333, prior_time: Some(Instant { tv_sec: 859, tv_nsec: 816036965 }), send_elapsed: 0ns, ack_elapsed: 31.272637ms, rtt: 31.272637ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 459535, last_update: Instant { tv_sec: 859, tv_nsec: 847776267 }, next_time: Instant { tv_sec: 859, tv_nsec: 848062288 }, 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-30T17:19:57.323973290Z TRACE quiche_apps::client] written 34 bytes from [::]:41995 to [fd00:cafe:cafe:100::100]:443
[2025-04-30T17:19:57.323979452Z TRACE quiche_apps::client] [::]:41995 -> [fd00:cafe:cafe:100::100]:443: done writing
[2025-04-30T17:19:57.324917301Z TRACE quiche_apps::client] got 1232 bytes from [fd00:cafe:cafe:100::100]:443 to [::]:41995
[2025-04-30T17:19:57.324929414Z TRACE quiche] a4231187ece90a57c2217f5d6ad95c92062ca8d4 rx pkt Short dcid=a4231187ece90a57c2217f5d6ad95c92062ca8d4 key_phase=false len=1211 pn=14215656 
[2025-04-30T17:19:57.324935265Z TRACE quiche] a4231187ece90a57c2217f5d6ad95c92062ca8d4 rx frm ACK delay=97 blocks=[3..8] ecn_counts=None
[2025-04-30T17:19:57.324938581Z TRACE quiche::recovery::congestion::recovery] a4231187ece90a57c2217f5d6ad95c92062ca8d4 packet newly acked 8
[2025-04-30T17:19:57.324942609Z TRACE quiche] a4231187ece90a57c2217f5d6ad95c92062ca8d4 rx frm STREAM id=4 off=59 len=1185 fin=false
[2025-04-30T17:19:57.324952698Z TRACE quiche_apps::client] [::]:41995: processed 1232 bytes
[2025-04-30T17:19:57.324956215Z TRACE quiche_apps::client] [::]:41995: recv() would block
[2025-04-30T17:19:57.324958509Z TRACE quiche_apps::client] done reading
[2025-04-30T17:19:57.324961024Z TRACE quiche::h3] a4231187ece90a57c2217f5d6ad95c92062ca8d4 stream id 4 is readable
[2025-04-30T17:19:57.324964460Z TRACE quiche::h3::stream] a4231187ece90a57c2217f5d6ad95c92062ca8d4 read 1 bytes on stream 4
[2025-04-30T17:19:57.324967646Z TRACE quiche::h3::stream] a4231187ece90a57c2217f5d6ad95c92062ca8d4 read 1 bytes on stream 4
[2025-04-30T17:19:57.324970632Z TRACE quiche::h3::stream] a4231187ece90a57c2217f5d6ad95c92062ca8d4 read 1 bytes on stream 4
[2025-04-30T17:19:57.324972906Z TRACE quiche::h3] a4231187ece90a57c2217f5d6ad95c92062ca8d4 rx frm DATA stream=4 wire_payload_len=10240
[2025-04-30T17:19:57.324977905Z DEBUG quiche_apps::common] got 1182 bytes of response data on stream 4
[2025-04-30T17:19:57.324984378Z TRACE quiche] a4231187ece90a57c2217f5d6ad95c92062ca8d4 pmtud probe status false hs_con=true hs_sent=false cwnd_avail=13500 out_len=1350 left=1316
[2025-04-30T17:19:57.324987373Z TRACE quiche] a4231187ece90a57c2217f5d6ad95c92062ca8d4 tx pkt Short dcid=4000008b102e8f85 key_phase=false len=8 pn=16 
[2025-04-30T17:19:57.324989748Z TRACE quiche] a4231187ece90a57c2217f5d6ad95c92062ca8d4 tx frm ACK delay=6 blocks=[14215649..14215656] ecn_counts=None
[2025-04-30T17:19:57.324995188Z TRACE quiche::recovery::congestion::recovery] a4231187ece90a57c2217f5d6ad95c92062ca8d4 timer=none latest_rtt=36.122128ms srtt=36.54989ms min_rtt=30.964843ms rttvar=8.892672ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=0 app_limited=true congestion_recovery_start_time=None Rate { delivered: 816, delivered_time: Instant { tv_sec: 859, tv_nsec: 848062288 }, first_sent_time: Instant { tv_sec: 859, tv_nsec: 848062288 }, end_of_app_limited: 15, last_sent_packet: 16, largest_acked: 8, rate_sample: RateSample { delivery_rate: 15444, is_app_limited: true, interval: 31.272637ms, delivered: 483, prior_delivered: 333, prior_time: Some(Instant { tv_sec: 859, tv_nsec: 816036965 }), send_elapsed: 0ns, ack_elapsed: 31.272637ms, rtt: 31.272637ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 461697, last_update: Instant { tv_sec: 859, tv_nsec: 847776267 }, next_time: Instant { tv_sec: 859, tv_nsec: 848062288 }, 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-30T17:19:57.325024633Z TRACE quiche_apps::client] written 34 bytes from [::]:41995 to [fd00:cafe:cafe:100::100]:443
[2025-04-30T17:19:57.325031275Z TRACE quiche_apps::client] [::]:41995 -> [fd00:cafe:cafe:100::100]:443: done writing
[2025-04-30T17:19:57.325943106Z TRACE quiche_apps::client] got 1232 bytes from [fd00:cafe:cafe:100::100]:443 to [::]:41995
[2025-04-30T17:19:57.325950139Z TRACE quiche] a4231187ece90a57c2217f5d6ad95c92062ca8d4 rx pkt Short dcid=a4231187ece90a57c2217f5d6ad95c92062ca8d4 key_phase=false len=1211 pn=14215657 
[2025-04-30T17:19:57.325956832Z TRACE quiche] a4231187ece90a57c2217f5d6ad95c92062ca8d4 rx frm STREAM id=4 off=1244 len=1190 fin=false
[2025-04-30T17:19:57.325969185Z TRACE quiche_apps::client] [::]:41995: processed 1232 bytes
[2025-04-30T17:19:57.325972822Z TRACE quiche_apps::client] [::]:41995: recv() would block
[2025-04-30T17:19:57.325975137Z TRACE quiche_apps::client] done reading
[2025-04-30T17:19:57.325977741Z TRACE quiche::h3] a4231187ece90a57c2217f5d6ad95c92062ca8d4 stream id 4 is readable
[2025-04-30T17:19:57.325982320Z DEBUG quiche_apps::common] got 1190 bytes of response data on stream 4
[2025-04-30T17:19:57.325989163Z TRACE quiche] a4231187ece90a57c2217f5d6ad95c92062ca8d4 pmtud probe status false hs_con=true hs_sent=false cwnd_avail=13500 out_len=1350 left=1316
[2025-04-30T17:19:57.325992339Z TRACE quiche] a4231187ece90a57c2217f5d6ad95c92062ca8d4 tx pkt Short dcid=4000008b102e8f85 key_phase=false len=8 pn=17 
[2025-04-30T17:19:57.325994773Z TRACE quiche] a4231187ece90a57c2217f5d6ad95c92062ca8d4 tx frm ACK delay=4 blocks=[14215649..14215657] ecn_counts=None
[2025-04-30T17:19:57.326001406Z TRACE quiche::recovery::congestion::recovery] a4231187ece90a57c2217f5d6ad95c92062ca8d4 timer=none latest_rtt=36.122128ms srtt=36.54989ms min_rtt=30.964843ms rttvar=8.892672ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=0 app_limited=true congestion_recovery_start_time=None Rate { delivered: 816, delivered_time: Instant { tv_sec: 859, tv_nsec: 848062288 }, first_sent_time: Instant { tv_sec: 859, tv_nsec: 848062288 }, end_of_app_limited: 15, last_sent_packet: 17, largest_acked: 8, rate_sample: RateSample { delivery_rate: 15444, is_app_limited: true, interval: 31.272637ms, delivered: 483, prior_delivered: 333, prior_time: Some(Instant { tv_sec: 859, tv_nsec: 816036965 }), send_elapsed: 0ns, ack_elapsed: 31.272637ms, rtt: 31.272637ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 461697, last_update: Instant { tv_sec: 859, tv_nsec: 847776267 }, next_time: Instant { tv_sec: 859, tv_nsec: 848062288 }, 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-30T17:19:57.326031041Z TRACE quiche_apps::client] written 34 bytes from [::]:41995 to [fd00:cafe:cafe:100::100]:443
[2025-04-30T17:19:57.326037543Z TRACE quiche_apps::client] [::]:41995 -> [fd00:cafe:cafe:100::100]:443: done writing
[2025-04-30T17:19:57.326980733Z TRACE quiche_apps::client] got 1232 bytes from [fd00:cafe:cafe:100::100]:443 to [::]:41995
[2025-04-30T17:19:57.326988488Z TRACE quiche] a4231187ece90a57c2217f5d6ad95c92062ca8d4 rx pkt Short dcid=a4231187ece90a57c2217f5d6ad95c92062ca8d4 key_phase=false len=1211 pn=14215658 
[2025-04-30T17:19:57.326994459Z TRACE quiche] a4231187ece90a57c2217f5d6ad95c92062ca8d4 rx frm STREAM id=4 off=2434 len=1190 fin=false
[2025-04-30T17:19:57.327000831Z TRACE quiche_apps::client] [::]:41995: processed 1232 bytes
[2025-04-30T17:19:57.327004157Z TRACE quiche_apps::client] [::]:41995: recv() would block
[2025-04-30T17:19:57.327006452Z TRACE quiche_apps::client] done reading
[2025-04-30T17:19:57.327008996Z TRACE quiche::h3] a4231187ece90a57c2217f5d6ad95c92062ca8d4 stream id 4 is readable
[2025-04-30T17:19:57.327013044Z DEBUG quiche_apps::common] got 1190 bytes of response data on stream 4
[2025-04-30T17:19:57.327019035Z TRACE quiche] a4231187ece90a57c2217f5d6ad95c92062ca8d4 pmtud probe status false hs_con=true hs_sent=false cwnd_avail=13500 out_len=1350 left=1316
[2025-04-30T17:19:57.327022041Z TRACE quiche] a4231187ece90a57c2217f5d6ad95c92062ca8d4 tx pkt Short dcid=4000008b102e8f85 key_phase=false len=8 pn=18 
[2025-04-30T17:19:57.327024395Z TRACE quiche] a4231187ece90a57c2217f5d6ad95c92062ca8d4 tx frm ACK delay=3 blocks=[14215649..14215658] ecn_counts=None
[2025-04-30T17:19:57.327055303Z TRACE quiche::recovery::congestion::recovery] a4231187ece90a57c2217f5d6ad95c92062ca8d4 timer=none latest_rtt=36.122128ms srtt=36.54989ms min_rtt=30.964843ms rttvar=8.892672ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=0 app_limited=true congestion_recovery_start_time=None Rate { delivered: 816, delivered_time: Instant { tv_sec: 859, tv_nsec: 848062288 }, first_sent_time: Instant { tv_sec: 859, tv_nsec: 848062288 }, end_of_app_limited: 15, last_sent_packet: 18, largest_acked: 8, rate_sample: RateSample { delivery_rate: 15444, is_app_limited: true, interval: 31.272637ms, delivered: 483, prior_delivered: 333, prior_time: Some(Instant { tv_sec: 859, tv_nsec: 816036965 }), send_elapsed: 0ns, ack_elapsed: 31.272637ms, rtt: 31.272637ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 461697, last_update: Instant { tv_sec: 859, tv_nsec: 847776267 }, next_time: Instant { tv_sec: 859, tv_nsec: 848062288 }, 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-30T17:19:57.327086361Z TRACE quiche_apps::client] written 34 bytes from [::]:41995 to [fd00:cafe:cafe:100::100]:443
[2025-04-30T17:19:57.327093295Z TRACE quiche_apps::client] [::]:41995 -> [fd00:cafe:cafe:100::100]:443: done writing
[2025-04-30T17:19:57.327990919Z TRACE quiche_apps::client] got 1232 bytes from [fd00:cafe:cafe:100::100]:443 to [::]:41995
[2025-04-30T17:19:57.327998282Z TRACE quiche] a4231187ece90a57c2217f5d6ad95c92062ca8d4 rx pkt Short dcid=a4231187ece90a57c2217f5d6ad95c92062ca8d4 key_phase=false len=1211 pn=14215659 
[2025-04-30T17:19:57.328004144Z TRACE quiche] a4231187ece90a57c2217f5d6ad95c92062ca8d4 rx frm STREAM id=4 off=3624 len=1190 fin=false
[2025-04-30T17:19:57.328010746Z TRACE quiche_apps::client] [::]:41995: processed 1232 bytes
[2025-04-30T17:19:57.328014062Z TRACE quiche_apps::client] [::]:41995: recv() would block
[2025-04-30T17:19:57.328016306Z TRACE quiche_apps::client] done reading
[2025-04-30T17:19:57.328018781Z TRACE quiche::h3] a4231187ece90a57c2217f5d6ad95c92062ca8d4 stream id 4 is readable
[2025-04-30T17:19:57.328022929Z DEBUG quiche_apps::common] got 1190 bytes of response data on stream 4
[2025-04-30T17:19:57.328028940Z TRACE quiche] a4231187ece90a57c2217f5d6ad95c92062ca8d4 pmtud probe status false hs_con=true hs_sent=false cwnd_avail=13500 out_len=1350 left=1316
[2025-04-30T17:19:57.328031925Z TRACE quiche] a4231187ece90a57c2217f5d6ad95c92062ca8d4 tx pkt Short dcid=4000008b102e8f85 key_phase=false len=8 pn=19 
[2025-04-30T17:19:57.328034330Z TRACE quiche] a4231187ece90a57c2217f5d6ad95c92062ca8d4 tx frm ACK delay=3 blocks=[14215649..14215659] ecn_counts=None
[2025-04-30T17:19:57.328040071Z TRACE quiche::recovery::congestion::recovery] a4231187ece90a57c2217f5d6ad95c92062ca8d4 timer=none latest_rtt=36.122128ms srtt=36.54989ms min_rtt=30.964843ms rttvar=8.892672ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=0 app_limited=true congestion_recovery_start_time=None Rate { delivered: 816, delivered_time: Instant { tv_sec: 859, tv_nsec: 848062288 }, first_sent_time: Instant { tv_sec: 859, tv_nsec: 848062288 }, end_of_app_limited: 15, last_sent_packet: 19, largest_acked: 8, rate_sample: RateSample { delivery_rate: 15444, is_app_limited: true, interval: 31.272637ms, delivered: 483, prior_delivered: 333, prior_time: Some(Instant { tv_sec: 859, tv_nsec: 816036965 }), send_elapsed: 0ns, ack_elapsed: 31.272637ms, rtt: 31.272637ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 461697, last_update: Instant { tv_sec: 859, tv_nsec: 847776267 }, next_time: Instant { tv_sec: 859, tv_nsec: 848062288 }, 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-30T17:19:57.328072401Z TRACE quiche_apps::client] written 34 bytes from [::]:41995 to [fd00:cafe:cafe:100::100]:443
[2025-04-30T17:19:57.328079565Z TRACE quiche_apps::client] [::]:41995 -> [fd00:cafe:cafe:100::100]:443: done writing
[2025-04-30T17:19:57.329016072Z TRACE quiche_apps::client] got 1232 bytes from [fd00:cafe:cafe:100::100]:443 to [::]:41995
[2025-04-30T17:19:57.329023486Z TRACE quiche] a4231187ece90a57c2217f5d6ad95c92062ca8d4 rx pkt Short dcid=a4231187ece90a57c2217f5d6ad95c92062ca8d4 key_phase=false len=1211 pn=14215660 
[2025-04-30T17:19:57.329029247Z TRACE quiche] a4231187ece90a57c2217f5d6ad95c92062ca8d4 rx frm STREAM id=4 off=4814 len=1190 fin=false
[2025-04-30T17:19:57.329035679Z TRACE quiche_apps::client] [::]:41995: processed 1232 bytes
[2025-04-30T17:19:57.329038995Z TRACE quiche_apps::client] [::]:41995: recv() would block
[2025-04-30T17:19:57.329041249Z TRACE quiche_apps::client] done reading
[2025-04-30T17:19:57.329043734Z TRACE quiche::h3] a4231187ece90a57c2217f5d6ad95c92062ca8d4 stream id 4 is readable
[2025-04-30T17:19:57.329047942Z DEBUG quiche_apps::common] got 1190 bytes of response data on stream 4
[2025-04-30T17:19:57.329053973Z TRACE quiche] a4231187ece90a57c2217f5d6ad95c92062ca8d4 pmtud probe status false hs_con=true hs_sent=false cwnd_avail=13500 out_len=1350 left=1316
[2025-04-30T17:19:57.329056908Z TRACE quiche] a4231187ece90a57c2217f5d6ad95c92062ca8d4 tx pkt Short dcid=4000008b102e8f85 key_phase=false len=8 pn=20 
[2025-04-30T17:19:57.329059293Z TRACE quiche] a4231187ece90a57c2217f5d6ad95c92062ca8d4 tx frm ACK delay=3 blocks=[14215649..14215660] ecn_counts=None
[2025-04-30T17:19:57.329064994Z TRACE quiche::recovery::congestion::recovery] a4231187ece90a57c2217f5d6ad95c92062ca8d4 timer=none latest_rtt=36.122128ms srtt=36.54989ms min_rtt=30.964843ms rttvar=8.892672ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=0 app_limited=true congestion_recovery_start_time=None Rate { delivered: 816, delivered_time: Instant { tv_sec: 859, tv_nsec: 848062288 }, first_sent_time: Instant { tv_sec: 859, tv_nsec: 848062288 }, end_of_app_limited: 15, last_sent_packet: 20, largest_acked: 8, rate_sample: RateSample { delivery_rate: 15444, is_app_limited: true, interval: 31.272637ms, delivered: 483, prior_delivered: 333, prior_time: Some(Instant { tv_sec: 859, tv_nsec: 816036965 }), send_elapsed: 0ns, ack_elapsed: 31.272637ms, rtt: 31.272637ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 461697, last_update: Instant { tv_sec: 859, tv_nsec: 847776267 }, next_time: Instant { tv_sec: 859, tv_nsec: 848062288 }, 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-30T17:19:57.329091774Z TRACE quiche_apps::client] written 34 bytes from [::]:41995 to [fd00:cafe:cafe:100::100]:443
[2025-04-30T17:19:57.329098186Z TRACE quiche_apps::client] [::]:41995 -> [fd00:cafe:cafe:100::100]:443: done writing
[2025-04-30T17:19:57.330041897Z TRACE quiche_apps::client] got 1232 bytes from [fd00:cafe:cafe:100::100]:443 to [::]:41995
[2025-04-30T17:19:57.330049351Z TRACE quiche] a4231187ece90a57c2217f5d6ad95c92062ca8d4 rx pkt Short dcid=a4231187ece90a57c2217f5d6ad95c92062ca8d4 key_phase=false len=1211 pn=14215661 
[2025-04-30T17:19:57.330055222Z TRACE quiche] a4231187ece90a57c2217f5d6ad95c92062ca8d4 rx frm STREAM id=4 off=6004 len=1190 fin=false
[2025-04-30T17:19:57.330061594Z TRACE quiche_apps::client] [::]:41995: processed 1232 bytes
[2025-04-30T17:19:57.330064950Z TRACE quiche_apps::client] [::]:41995: recv() would block
[2025-04-30T17:19:57.330067204Z TRACE quiche_apps::client] done reading
[2025-04-30T17:19:57.330069699Z TRACE quiche::h3] a4231187ece90a57c2217f5d6ad95c92062ca8d4 stream id 4 is readable
[2025-04-30T17:19:57.330073947Z DEBUG quiche_apps::common] got 1190 bytes of response data on stream 4
[2025-04-30T17:19:57.330089045Z TRACE quiche] a4231187ece90a57c2217f5d6ad95c92062ca8d4 pmtud probe status false hs_con=true hs_sent=false cwnd_avail=13500 out_len=1350 left=1316
[2025-04-30T17:19:57.330092151Z TRACE quiche] a4231187ece90a57c2217f5d6ad95c92062ca8d4 tx pkt Short dcid=4000008b102e8f85 key_phase=false len=8 pn=21 
[2025-04-30T17:19:57.330094445Z TRACE quiche] a4231187ece90a57c2217f5d6ad95c92062ca8d4 tx frm ACK delay=4 blocks=[14215649..14215661] ecn_counts=None
[2025-04-30T17:19:57.330100296Z TRACE quiche::recovery::congestion::recovery] a4231187ece90a57c2217f5d6ad95c92062ca8d4 timer=none latest_rtt=36.122128ms srtt=36.54989ms min_rtt=30.964843ms rttvar=8.892672ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=0 app_limited=true congestion_recovery_start_time=None Rate { delivered: 816, delivered_time: Instant { tv_sec: 859, tv_nsec: 848062288 }, first_sent_time: Instant { tv_sec: 859, tv_nsec: 848062288 }, end_of_app_limited: 15, last_sent_packet: 21, largest_acked: 8, rate_sample: RateSample { delivery_rate: 15444, is_app_limited: true, interval: 31.272637ms, delivered: 483, prior_delivered: 333, prior_time: Some(Instant { tv_sec: 859, tv_nsec: 816036965 }), send_elapsed: 0ns, ack_elapsed: 31.272637ms, rtt: 31.272637ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 461697, last_update: Instant { tv_sec: 859, tv_nsec: 847776267 }, next_time: Instant { tv_sec: 859, tv_nsec: 848062288 }, 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-30T17:19:57.330128289Z TRACE quiche_apps::client] written 34 bytes from [::]:41995 to [fd00:cafe:cafe:100::100]:443
[2025-04-30T17:19:57.330134811Z TRACE quiche_apps::client] [::]:41995 -> [fd00:cafe:cafe:100::100]:443: done writing
[2025-04-30T17:19:57.331068543Z TRACE quiche_apps::client] got 1232 bytes from [fd00:cafe:cafe:100::100]:443 to [::]:41995
[2025-04-30T17:19:57.331076037Z TRACE quiche] a4231187ece90a57c2217f5d6ad95c92062ca8d4 rx pkt Short dcid=a4231187ece90a57c2217f5d6ad95c92062ca8d4 key_phase=false len=1211 pn=14215662 
[2025-04-30T17:19:57.331081748Z TRACE quiche] a4231187ece90a57c2217f5d6ad95c92062ca8d4 rx frm STREAM id=4 off=7194 len=1190 fin=false
[2025-04-30T17:19:57.331088340Z TRACE quiche_apps::client] [::]:41995: processed 1232 bytes
[2025-04-30T17:19:57.331091646Z TRACE quiche_apps::client] [::]:41995: recv() would block
[2025-04-30T17:19:57.331093991Z TRACE quiche_apps::client] done reading
[2025-04-30T17:19:57.331096475Z TRACE quiche::h3] a4231187ece90a57c2217f5d6ad95c92062ca8d4 stream id 4 is readable
[2025-04-30T17:19:57.331100623Z DEBUG quiche_apps::common] got 1190 bytes of response data on stream 4
[2025-04-30T17:19:57.331120500Z TRACE quiche] a4231187ece90a57c2217f5d6ad95c92062ca8d4 pmtud probe status false hs_con=true hs_sent=false cwnd_avail=13500 out_len=1350 left=1316
[2025-04-30T17:19:57.331123737Z TRACE quiche] a4231187ece90a57c2217f5d6ad95c92062ca8d4 tx pkt Short dcid=4000008b102e8f85 key_phase=false len=8 pn=22 
[2025-04-30T17:19:57.331126081Z TRACE quiche] a4231187ece90a57c2217f5d6ad95c92062ca8d4 tx frm ACK delay=5 blocks=[14215649..14215662] ecn_counts=None
[2025-04-30T17:19:57.331132122Z TRACE quiche::recovery::congestion::recovery] a4231187ece90a57c2217f5d6ad95c92062ca8d4 timer=none latest_rtt=36.122128ms srtt=36.54989ms min_rtt=30.964843ms rttvar=8.892672ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=0 app_limited=true congestion_recovery_start_time=None Rate { delivered: 816, delivered_time: Instant { tv_sec: 859, tv_nsec: 848062288 }, first_sent_time: Instant { tv_sec: 859, tv_nsec: 848062288 }, end_of_app_limited: 15, last_sent_packet: 22, largest_acked: 8, rate_sample: RateSample { delivery_rate: 15444, is_app_limited: true, interval: 31.272637ms, delivered: 483, prior_delivered: 333, prior_time: Some(Instant { tv_sec: 859, tv_nsec: 816036965 }), send_elapsed: 0ns, ack_elapsed: 31.272637ms, rtt: 31.272637ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 461697, last_update: Instant { tv_sec: 859, tv_nsec: 847776267 }, next_time: Instant { tv_sec: 859, tv_nsec: 848062288 }, 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-30T17:19:57.331164012Z TRACE quiche_apps::client] written 34 bytes from [::]:41995 to [fd00:cafe:cafe:100::100]:443
[2025-04-30T17:19:57.331171246Z TRACE quiche_apps::client] [::]:41995 -> [fd00:cafe:cafe:100::100]:443: done writing
[2025-04-30T17:19:57.350799855Z TRACE quiche_apps::client] got 1232 bytes from [fd00:cafe:cafe:100::100]:443 to [::]:41995
[2025-04-30T17:19:57.350809513Z TRACE quiche] a4231187ece90a57c2217f5d6ad95c92062ca8d4 rx pkt Short dcid=a4231187ece90a57c2217f5d6ad95c92062ca8d4 key_phase=false len=1211 pn=14215663 
[2025-04-30T17:19:57.350817147Z TRACE quiche] a4231187ece90a57c2217f5d6ad95c92062ca8d4 rx frm ACK delay=7 blocks=[4..9] ecn_counts=None
[2025-04-30T17:19:57.350821435Z TRACE quiche::recovery::congestion::recovery] a4231187ece90a57c2217f5d6ad95c92062ca8d4 packet newly acked 9
[2025-04-30T17:19:57.350826625Z TRACE quiche] a4231187ece90a57c2217f5d6ad95c92062ca8d4 rx frm STREAM id=4 off=8384 len=1185 fin=false
[2025-04-30T17:19:57.350836393Z TRACE quiche_apps::client] [::]:41995: processed 1232 bytes
[2025-04-30T17:19:57.350840671Z TRACE quiche_apps::client] [::]:41995: recv() would block
[2025-04-30T17:19:57.350843517Z TRACE quiche_apps::client] done reading
[2025-04-30T17:19:57.350846622Z TRACE quiche::h3] a4231187ece90a57c2217f5d6ad95c92062ca8d4 stream id 4 is readable
[2025-04-30T17:19:57.350852093Z DEBUG quiche_apps::common] got 1185 bytes of response data on stream 4
[2025-04-30T17:19:57.350860228Z TRACE quiche] a4231187ece90a57c2217f5d6ad95c92062ca8d4 pmtud probe status false hs_con=true hs_sent=false cwnd_avail=13500 out_len=1350 left=1316
[2025-04-30T17:19:57.350864005Z TRACE quiche] a4231187ece90a57c2217f5d6ad95c92062ca8d4 tx pkt Short dcid=4000008b102e8f85 key_phase=false len=8 pn=23 
[2025-04-30T17:19:57.350866940Z TRACE quiche] a4231187ece90a57c2217f5d6ad95c92062ca8d4 tx frm ACK delay=6 blocks=[14215650..14215663] ecn_counts=None
[2025-04-30T17:19:57.350873473Z TRACE quiche::recovery::congestion::recovery] a4231187ece90a57c2217f5d6ad95c92062ca8d4 timer=none latest_rtt=36.122128ms srtt=36.54989ms min_rtt=30.964843ms rttvar=8.892672ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=0 app_limited=true congestion_recovery_start_time=None Rate { delivered: 816, delivered_time: Instant { tv_sec: 859, tv_nsec: 879344047 }, first_sent_time: Instant { tv_sec: 859, tv_nsec: 879344047 }, end_of_app_limited: 22, last_sent_packet: 23, largest_acked: 9, rate_sample: RateSample { delivery_rate: 8805, is_app_limited: true, interval: 32.025323ms, delivered: 282, prior_delivered: 534, prior_time: Some(Instant { tv_sec: 859, tv_nsec: 847685016 }), send_elapsed: 32.025323ms, ack_elapsed: 31.610029ms, rtt: 31.232757ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 461697, last_update: Instant { tv_sec: 859, tv_nsec: 879344047 }, next_time: Instant { tv_sec: 859, tv_nsec: 879344047 }, 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-30T17:19:57.350907627Z TRACE quiche_apps::client] written 34 bytes from [::]:41995 to [fd00:cafe:cafe:100::100]:443
[2025-04-30T17:19:57.350915552Z TRACE quiche_apps::client] [::]:41995 -> [fd00:cafe:cafe:100::100]:443: done writing
[2025-04-30T17:19:57.351507202Z TRACE quiche_apps::client] got 784 bytes from [fd00:cafe:cafe:100::100]:443 to [::]:41995
[2025-04-30T17:19:57.351531718Z TRACE quiche] a4231187ece90a57c2217f5d6ad95c92062ca8d4 rx pkt Short dcid=a4231187ece90a57c2217f5d6ad95c92062ca8d4 key_phase=false len=763 pn=14215664 
[2025-04-30T17:19:57.351539042Z TRACE quiche] a4231187ece90a57c2217f5d6ad95c92062ca8d4 rx frm ACK delay=5 blocks=[8..11] ecn_counts=None
[2025-04-30T17:19:57.351543079Z TRACE quiche::recovery::congestion::recovery] a4231187ece90a57c2217f5d6ad95c92062ca8d4 packet newly acked 10
[2025-04-30T17:19:57.351546095Z TRACE quiche::recovery::congestion::recovery] a4231187ece90a57c2217f5d6ad95c92062ca8d4 packet newly acked 11
[2025-04-30T17:19:57.351550543Z TRACE quiche] a4231187ece90a57c2217f5d6ad95c92062ca8d4 rx frm STREAM id=4 off=9569 len=733 fin=true
[2025-04-30T17:19:57.351554580Z TRACE quiche] a4231187ece90a57c2217f5d6ad95c92062ca8d4 rx frm PADDING len=2
[2025-04-30T17:19:57.351563808Z TRACE quiche_apps::client] [::]:41995: processed 784 bytes
[2025-04-30T17:19:57.351568036Z TRACE quiche_apps::client] [::]:41995: recv() would block
[2025-04-30T17:19:57.351571192Z TRACE quiche_apps::client] done reading
[2025-04-30T17:19:57.351574849Z TRACE quiche::h3] a4231187ece90a57c2217f5d6ad95c92062ca8d4 stream id 4 is readable
[2025-04-30T17:19:57.351580930Z DEBUG quiche_apps::common] got 733 bytes of response data on stream 4
[2025-04-30T17:19:57.351584256Z DEBUG quiche_apps::common] 2/2 responses received
[2025-04-30T17:19:57.351587012Z INFO  quiche_apps::common] 2/2 response(s) received in 105.407444ms, closing...
[2025-04-30T17:19:57.351593574Z TRACE quiche] a4231187ece90a57c2217f5d6ad95c92062ca8d4 pmtud probe status false hs_con=true hs_sent=false cwnd_avail=13500 out_len=1350 left=1324
[2025-04-30T17:19:57.351596800Z TRACE quiche] a4231187ece90a57c2217f5d6ad95c92062ca8d4 tx pkt Short dcid=4000008b102e8f85 key_phase=false len=11 pn=24 
[2025-04-30T17:19:57.351599164Z TRACE quiche] a4231187ece90a57c2217f5d6ad95c92062ca8d4 tx frm APPLICATION_CLOSE err=100 reason=[6b, 74, 68, 78, 62, 79, 65]
[2025-04-30T17:19:57.351605977Z TRACE quiche::recovery::congestion::recovery] a4231187ece90a57c2217f5d6ad95c92062ca8d4 timer=97.10582ms latest_rtt=36.122128ms srtt=36.54989ms min_rtt=30.964843ms rttvar=8.892672ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=37 app_limited=true congestion_recovery_start_time=None Rate { delivered: 816, delivered_time: Instant { tv_sec: 859, tv_nsec: 879344047 }, first_sent_time: Instant { tv_sec: 859, tv_nsec: 879344047 }, end_of_app_limited: 23, last_sent_packet: 24, largest_acked: 11, rate_sample: RateSample { delivery_rate: 1779, is_app_limited: true, interval: 32.025323ms, delivered: 57, prior_delivered: 759, prior_time: Some(Instant { tv_sec: 859, tv_nsec: 848872324 }), send_elapsed: 32.025323ms, ack_elapsed: 31.127083ms, rtt: 31.937119ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 461697, last_update: Instant { tv_sec: 859, tv_nsec: 880078625 }, next_time: Instant { tv_sec: 859, tv_nsec: 879344047 }, max_datagram_size: 1350, last_packet_size: None, iv: 80.139µ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-30T17:19:57.351641343Z TRACE quiche_apps::client] written 37 bytes from [::]:41995 to [fd00:cafe:cafe:100::100]:443
[2025-04-30T17:19:57.351647285Z TRACE quiche_apps::client] [::]:41995 -> [fd00:cafe:cafe:100::100]:443: done writing
[2025-04-30T17:19:57.382141377Z TRACE quiche_apps::client] got 53 bytes from [fd00:cafe:cafe:100::100]:443 to [::]:41995
[2025-04-30T17:19:57.382155944Z TRACE quiche_apps::client] [::]:41995: processed 53 bytes
[2025-04-30T17:19:57.382160923Z TRACE quiche_apps::client] [::]:41995: recv() would block
[2025-04-30T17:19:57.382164019Z TRACE quiche_apps::client] done reading
[2025-04-30T17:19:57.382176493Z TRACE quiche_apps::client] [::]:41995 -> [fd00:cafe:cafe:100::100]:443: done writing
[2025-04-30T17:19:57.568415471Z TRACE quiche_apps::client] timed out
[2025-04-30T17:19:57.568430169Z TRACE quiche] a4231187ece90a57c2217f5d6ad95c92062ca8d4 draining timeout expired
[2025-04-30T17:19:57.568464463Z TRACE quiche_apps::client] done reading
[2025-04-30T17:19:57.568469833Z INFO  quiche_apps::client] connection closed, recv=20 sent=25 lost=0 retrans=0 sent_bytes=1426 recv_bytes=18784 lost_bytes=0 [local_addr=[::]:41995 peer_addr=[fd00:cafe:cafe:100::100]:443 validation_state=Validated active=true recv=20 sent=25 lost=0 retrans=0 rtt=36.54989ms min_rtt=Some(30.964843ms) rttvar=8.892672ms cwnd=13500 sent_bytes=1426 recv_bytes=18784 lost_bytes=0 stream_retrans_bytes=0 pmtu=1350 delivery_rate=1779]