[2025-04-30T09:21:23.016835937Z TRACE mio::poll] registering event source with poller: token=Token(0), interests=READABLE
[2025-04-30T09:21:23.017122736Z INFO  quiche_apps::client] connecting to [fd00:cafe:cafe:100::100]:443 from [::]:36963 with scid e68335eb25deef9a0ee756f48eabd7086ec35189
[2025-04-30T09:21:23.017163212Z TRACE quiche::tls] e68335eb25deef9a0ee756f48eabd7086ec35189 write message lvl=Initial len=266
[2025-04-30T09:21:23.017179453Z TRACE quiche] e68335eb25deef9a0ee756f48eabd7086ec35189 tx pkt Initial version=1 dcid=abf516dd1307f68383d06a6f8516462f scid=e68335eb25deef9a0ee756f48eabd7086ec35189 len=270 pn=0 
[2025-04-30T09:21:23.017182529Z TRACE quiche] e68335eb25deef9a0ee756f48eabd7086ec35189 tx frm CRYPTO off=0 len=266
[2025-04-30T09:21:23.017196244Z TRACE quiche::recovery::congestion::recovery] e68335eb25deef9a0ee756f48eabd7086ec35189 timer=998.933285ms 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: 839, tv_nsec: 676594059 }, first_sent_time: Instant { tv_sec: 839, tv_nsec: 676594059 }, 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: 839, tv_nsec: 676594059 }, next_time: Instant { tv_sec: 839, tv_nsec: 676594059 }, 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-30T09:21:23.017243323Z TRACE quiche_apps::client] written 1200
[2025-04-30T09:21:23.057895019Z TRACE quiche_apps::client] got 1200 bytes from [fd00:cafe:cafe:100::100]:443 to [::]:36963
[2025-04-30T09:21:23.057913683Z TRACE quiche] e68335eb25deef9a0ee756f48eabd7086ec35189 rx pkt Initial version=1 dcid=e68335eb25deef9a0ee756f48eabd7086ec35189 scid=00000000000030040c307b3f9361829bea0d3b84 token= len=116 pn=0 
[2025-04-30T09:21:23.057926467Z TRACE quiche] e68335eb25deef9a0ee756f48eabd7086ec35189 rx frm ACK delay=0 blocks=[0..0] ecn_counts=None
[2025-04-30T09:21:23.057932549Z TRACE quiche::recovery::congestion::recovery] e68335eb25deef9a0ee756f48eabd7086ec35189 packet newly acked 0
[2025-04-30T09:21:23.057938590Z TRACE quiche] e68335eb25deef9a0ee756f48eabd7086ec35189 rx frm CRYPTO off=0 len=90
[2025-04-30T09:21:23.058047525Z TRACE quiche::tls] e68335eb25deef9a0ee756f48eabd7086ec35189 set write secret lvl=Handshake
[2025-04-30T09:21:23.058057945Z TRACE quiche::tls] e68335eb25deef9a0ee756f48eabd7086ec35189 set read secret lvl=Handshake
[2025-04-30T09:21:23.058090105Z TRACE quiche] e68335eb25deef9a0ee756f48eabd7086ec35189 rx pkt Handshake version=1 dcid=e68335eb25deef9a0ee756f48eabd7086ec35189 scid=00000000000030040c307b3f9361829bea0d3b84 len=985 pn=0 
[2025-04-30T09:21:23.058097329Z TRACE quiche] e68335eb25deef9a0ee756f48eabd7086ec35189 rx frm CRYPTO off=0 len=718
[2025-04-30T09:21:23.058321720Z TRACE quiche::tls] e68335eb25deef9a0ee756f48eabd7086ec35189 write message lvl=Handshake len=36
[2025-04-30T09:21:23.058326449Z TRACE quiche::tls] e68335eb25deef9a0ee756f48eabd7086ec35189 set write secret lvl=OneRTT
[2025-04-30T09:21:23.058334534Z TRACE quiche::tls] e68335eb25deef9a0ee756f48eabd7086ec35189 set read secret lvl=OneRTT
[2025-04-30T09:21:23.058351827Z TRACE quiche] e68335eb25deef9a0ee756f48eabd7086ec35189 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(abf516dd1307f68383d06a6f8516462f), max_idle_timeout: 75000, stateless_reset_token: Some(74755046227358240015208629298395116962), max_udp_payload_size: 65527, initial_max_data: 8585216, initial_max_stream_data_bidi_local: 65536, initial_max_stream_data_bidi_remote: 65536, initial_max_stream_data_uni: 65536, initial_max_streams_bidi: 128, initial_max_streams_uni: 3, ack_delay_exponent: 3, max_ack_delay: 25, disable_active_migration: false, active_conn_id_limit: 2, initial_source_connection_id: Some(00000000000030040c307b3f9361829bea0d3b84), retry_source_connection_id: None, max_datagram_frame_size: None, unknown_params: None }
[2025-04-30T09:21:23.058373468Z TRACE quiche] e68335eb25deef9a0ee756f48eabd7086ec35189 rx frm PADDING len=246
[2025-04-30T09:21:23.058390700Z TRACE quiche_apps::client] [::]:36963: processed 1200 bytes
[2025-04-30T09:21:23.058396310Z TRACE quiche_apps::client] [::]:36963: recv() would block
[2025-04-30T09:21:23.058399326Z TRACE quiche_apps::client] done reading
[2025-04-30T09:21:23.058415426Z TRACE quiche::h3] e68335eb25deef9a0ee756f48eabd7086ec35189 tx frm SETTINGS stream=2 len=18
[2025-04-30T09:21:23.058433170Z TRACE quiche::h3] e68335eb25deef9a0ee756f48eabd7086ec35189 tx frm GREASE stream=0 len=0
[2025-04-30T09:21:23.058440163Z TRACE quiche::h3] e68335eb25deef9a0ee756f48eabd7086ec35189 tx frm GREASE stream=0 len=18
[2025-04-30T09:21:23.058448709Z TRACE quiche::h3] e68335eb25deef9a0ee756f48eabd7086ec35189 tx frm HEADERS stream=0 len=30 fin=true
[2025-04-30T09:21:23.058456263Z DEBUG quiche_apps::common] Sent HTTP request [":method: GET", ":scheme: https", ":authority: server6", ":path: /ueqpxwpenl", "user-agent: quiche"]
[2025-04-30T09:21:23.058512990Z TRACE quiche::h3] e68335eb25deef9a0ee756f48eabd7086ec35189 tx frm HEADERS stream=4 len=30 fin=true
[2025-04-30T09:21:23.058519943Z DEBUG quiche_apps::common] Sent HTTP request [":method: GET", ":scheme: https", ":authority: server6", ":path: /arqsodtjbz", "user-agent: quiche"]
[2025-04-30T09:21:23.058594783Z TRACE quiche] e68335eb25deef9a0ee756f48eabd7086ec35189 tx pkt Initial version=1 dcid=00000000000030040c307b3f9361829bea0d3b84 scid=e68335eb25deef9a0ee756f48eabd7086ec35189 len=6 pn=1 
[2025-04-30T09:21:23.058601276Z TRACE quiche] e68335eb25deef9a0ee756f48eabd7086ec35189 tx frm ACK delay=85 blocks=[0..0] ecn_counts=None
[2025-04-30T09:21:23.058609882Z TRACE quiche::recovery::congestion::recovery] e68335eb25deef9a0ee756f48eabd7086ec35189 timer=121.638682ms latest_rtt=40.779716ms srtt=40.779716ms min_rtt=40.779716ms rttvar=20.389858ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=0 app_limited=true congestion_recovery_start_time=None Rate { delivered: 333, delivered_time: Instant { tv_sec: 839, tv_nsec: 717813802 }, first_sent_time: Instant { tv_sec: 839, tv_nsec: 717813802 }, end_of_app_limited: 1, last_sent_packet: 1, largest_acked: 0, rate_sample: RateSample { delivery_rate: 8165, is_app_limited: true, interval: 40.779716ms, delivered: 333, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 839, tv_nsec: 676594059 }), send_elapsed: 0ns, ack_elapsed: 40.779716ms, rtt: 40.779716ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 413808, last_update: Instant { tv_sec: 839, tv_nsec: 717813762 }, next_time: Instant { tv_sec: 839, tv_nsec: 717813802 }, 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-30T09:21:23.058628787Z TRACE quiche] e68335eb25deef9a0ee756f48eabd7086ec35189 tx pkt Handshake version=1 dcid=00000000000030040c307b3f9361829bea0d3b84 scid=e68335eb25deef9a0ee756f48eabd7086ec35189 len=46 pn=2 
[2025-04-30T09:21:23.058631533Z TRACE quiche] e68335eb25deef9a0ee756f48eabd7086ec35189 tx frm ACK delay=67 blocks=[0..0] ecn_counts=None
[2025-04-30T09:21:23.058634168Z TRACE quiche] e68335eb25deef9a0ee756f48eabd7086ec35189 tx frm CRYPTO off=0 len=36
[2025-04-30T09:21:23.058640049Z TRACE quiche::recovery::congestion::recovery] e68335eb25deef9a0ee756f48eabd7086ec35189 timer=122.285177ms latest_rtt=40.779716ms srtt=40.779716ms min_rtt=40.779716ms rttvar=20.389858ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=112 app_limited=true congestion_recovery_start_time=None Rate { delivered: 333, delivered_time: Instant { tv_sec: 839, tv_nsec: 717813802 }, first_sent_time: Instant { tv_sec: 839, tv_nsec: 717813802 }, end_of_app_limited: 1, last_sent_packet: 2, largest_acked: 0, rate_sample: RateSample { delivery_rate: 8165, is_app_limited: true, interval: 40.779716ms, delivered: 333, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 839, tv_nsec: 676594059 }), send_elapsed: 0ns, ack_elapsed: 40.779716ms, rtt: 40.779716ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 413808, last_update: Instant { tv_sec: 839, tv_nsec: 718050166 }, next_time: Instant { tv_sec: 839, tv_nsec: 717813802 }, max_datagram_size: 1350, last_packet_size: None, iv: 270.657µ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-30T09:21:23.058655878Z TRACE quiche] e68335eb25deef9a0ee756f48eabd7086ec35189 dropped epoch 0 state
[2025-04-30T09:21:23.058660698Z TRACE quiche] e68335eb25deef9a0ee756f48eabd7086ec35189 pmtud probe status false hs_con=false hs_sent=false cwnd_avail=13388 out_len=1165 left=1127
[2025-04-30T09:21:23.058672149Z TRACE quiche] e68335eb25deef9a0ee756f48eabd7086ec35189 tx pkt Short dcid=00000000000030040c307b3f9361829bea0d3b84 key_phase=false len=1127 pn=3 
[2025-04-30T09:21:23.058674634Z TRACE quiche] e68335eb25deef9a0ee756f48eabd7086ec35189 tx frm NEW_CONNECTION_ID seq_num=1 retire_prior_to=0 conn_id=[ca, d0, dc, 5f, 1a, d9, 0b, c5, e9, 53, 32, 73, 99, 82, ee, ea, ac, 46, de, 15] reset_token=[e4, 15, 5a, 68, 37, 82, f5, a9, ba, ed, 86, 47, 83, ed, d0, da]
[2025-04-30T09:21:23.058681386Z TRACE quiche] e68335eb25deef9a0ee756f48eabd7086ec35189 tx frm STREAM id=2 off=0 len=19 fin=false
[2025-04-30T09:21:23.058684041Z TRACE quiche] e68335eb25deef9a0ee756f48eabd7086ec35189 tx frm PADDING len=1063
[2025-04-30T09:21:23.058690173Z TRACE quiche::recovery::congestion::recovery] e68335eb25deef9a0ee756f48eabd7086ec35189 timer=122.235092ms latest_rtt=40.779716ms srtt=40.779716ms min_rtt=40.779716ms rttvar=20.389858ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=1277 app_limited=true congestion_recovery_start_time=None Rate { delivered: 333, delivered_time: Instant { tv_sec: 839, tv_nsec: 717813802 }, first_sent_time: Instant { tv_sec: 839, tv_nsec: 717813802 }, end_of_app_limited: 2, last_sent_packet: 3, largest_acked: 0, rate_sample: RateSample { delivery_rate: 8165, is_app_limited: true, interval: 40.779716ms, delivered: 333, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 839, tv_nsec: 676594059 }), send_elapsed: 0ns, ack_elapsed: 40.779716ms, rtt: 40.779716ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 1165, rate: 413808, last_update: Instant { tv_sec: 839, tv_nsec: 718050166 }, next_time: Instant { tv_sec: 839, tv_nsec: 718320823 }, 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-30T09:21:23.058723926Z TRACE quiche_apps::client] written 1350 bytes from [::]:36963 to [fd00:cafe:cafe:100::100]:443
[2025-04-30T09:21:23.058730629Z TRACE quiche] e68335eb25deef9a0ee756f48eabd7086ec35189 pmtud probe status false hs_con=false hs_sent=false cwnd_avail=12223 out_len=1350 left=1312
[2025-04-30T09:21:23.058734045Z TRACE quiche] e68335eb25deef9a0ee756f48eabd7086ec35189 tx pkt Short dcid=00000000000030040c307b3f9361829bea0d3b84 key_phase=false len=6 pn=4 
[2025-04-30T09:21:23.058742712Z TRACE quiche] e68335eb25deef9a0ee756f48eabd7086ec35189 tx frm STREAM id=6 off=0 len=1 fin=false
[2025-04-30T09:21:23.058772538Z TRACE quiche::recovery::congestion::recovery] e68335eb25deef9a0ee756f48eabd7086ec35189 timer=122.151806ms latest_rtt=40.779716ms srtt=40.779716ms min_rtt=40.779716ms rttvar=20.389858ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=1321 app_limited=true congestion_recovery_start_time=None Rate { delivered: 333, delivered_time: Instant { tv_sec: 839, tv_nsec: 717813802 }, first_sent_time: Instant { tv_sec: 839, tv_nsec: 717813802 }, end_of_app_limited: 3, last_sent_packet: 4, largest_acked: 0, rate_sample: RateSample { delivery_rate: 8165, is_app_limited: true, interval: 40.779716ms, delivered: 333, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 839, tv_nsec: 676594059 }), send_elapsed: 0ns, ack_elapsed: 40.779716ms, rtt: 40.779716ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 413808, last_update: Instant { tv_sec: 839, tv_nsec: 718191792 }, next_time: Instant { tv_sec: 839, tv_nsec: 718320823 }, max_datagram_size: 1350, last_packet_size: None, iv: 2.921645ms, 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-30T09:21:23.058814567Z TRACE quiche_apps::client] written 44 bytes from [::]:36963 to [fd00:cafe:cafe:100::100]:443
[2025-04-30T09:21:23.058823273Z TRACE quiche] e68335eb25deef9a0ee756f48eabd7086ec35189 pmtud probe status false hs_con=false hs_sent=false cwnd_avail=12179 out_len=1350 left=1312
[2025-04-30T09:21:23.058829204Z TRACE quiche] e68335eb25deef9a0ee756f48eabd7086ec35189 tx pkt Short dcid=00000000000030040c307b3f9361829bea0d3b84 key_phase=false len=6 pn=5 
[2025-04-30T09:21:23.058833362Z TRACE quiche] e68335eb25deef9a0ee756f48eabd7086ec35189 tx frm STREAM id=10 off=0 len=1 fin=false
[2025-04-30T09:21:23.058842840Z TRACE quiche::recovery::congestion::recovery] e68335eb25deef9a0ee756f48eabd7086ec35189 timer=122.081844ms latest_rtt=40.779716ms srtt=40.779716ms min_rtt=40.779716ms rttvar=20.389858ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=1365 app_limited=true congestion_recovery_start_time=None Rate { delivered: 333, delivered_time: Instant { tv_sec: 839, tv_nsec: 717813802 }, first_sent_time: Instant { tv_sec: 839, tv_nsec: 717813802 }, end_of_app_limited: 4, last_sent_packet: 5, largest_acked: 0, rate_sample: RateSample { delivery_rate: 8165, is_app_limited: true, interval: 40.779716ms, delivered: 333, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 839, tv_nsec: 676594059 }), send_elapsed: 0ns, ack_elapsed: 40.779716ms, rtt: 40.779716ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 44, rate: 413808, last_update: Instant { tv_sec: 839, tv_nsec: 718191792 }, next_time: Instant { tv_sec: 839, tv_nsec: 721242468 }, 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-30T09:21:23.058882865Z TRACE quiche_apps::client] written 44 bytes from [::]:36963 to [fd00:cafe:cafe:100::100]:443
[2025-04-30T09:21:23.058890910Z TRACE quiche] e68335eb25deef9a0ee756f48eabd7086ec35189 pmtud probe status false hs_con=false hs_sent=false cwnd_avail=12135 out_len=1350 left=1312
[2025-04-30T09:21:23.058897322Z TRACE quiche] e68335eb25deef9a0ee756f48eabd7086ec35189 tx pkt Short dcid=00000000000030040c307b3f9361829bea0d3b84 key_phase=false len=73 pn=6 
[2025-04-30T09:21:23.058901851Z TRACE quiche] e68335eb25deef9a0ee756f48eabd7086ec35189 tx frm STREAM id=0 off=0 len=68 fin=true
[2025-04-30T09:21:23.058911118Z TRACE quiche::recovery::congestion::recovery] e68335eb25deef9a0ee756f48eabd7086ec35189 timer=122.013606ms latest_rtt=40.779716ms srtt=40.779716ms min_rtt=40.779716ms rttvar=20.389858ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=1476 app_limited=true congestion_recovery_start_time=None Rate { delivered: 333, delivered_time: Instant { tv_sec: 839, tv_nsec: 717813802 }, first_sent_time: Instant { tv_sec: 839, tv_nsec: 717813802 }, end_of_app_limited: 5, last_sent_packet: 6, largest_acked: 0, rate_sample: RateSample { delivery_rate: 8165, is_app_limited: true, interval: 40.779716ms, delivered: 333, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 839, tv_nsec: 676594059 }), send_elapsed: 0ns, ack_elapsed: 40.779716ms, rtt: 40.779716ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 413808, last_update: Instant { tv_sec: 839, tv_nsec: 718351222 }, next_time: Instant { tv_sec: 839, tv_nsec: 721242468 }, max_datagram_size: 1350, last_packet_size: None, iv: 374.57µ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-30T09:21:23.058953618Z TRACE quiche_apps::client] written 111 bytes from [::]:36963 to [fd00:cafe:cafe:100::100]:443
[2025-04-30T09:21:23.058961112Z TRACE quiche] e68335eb25deef9a0ee756f48eabd7086ec35189 pmtud probe status false hs_con=false hs_sent=false cwnd_avail=12024 out_len=1350 left=1312
[2025-04-30T09:21:23.058966011Z TRACE quiche] e68335eb25deef9a0ee756f48eabd7086ec35189 tx pkt Short dcid=00000000000030040c307b3f9361829bea0d3b84 key_phase=false len=37 pn=7 
[2025-04-30T09:21:23.058970490Z TRACE quiche] e68335eb25deef9a0ee756f48eabd7086ec35189 tx frm STREAM id=4 off=0 len=32 fin=true
[2025-04-30T09:21:23.058980007Z TRACE quiche::recovery::congestion::recovery] e68335eb25deef9a0ee756f48eabd7086ec35189 timer=121.944737ms latest_rtt=40.779716ms srtt=40.779716ms min_rtt=40.779716ms rttvar=20.389858ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=1551 app_limited=true congestion_recovery_start_time=None Rate { delivered: 333, delivered_time: Instant { tv_sec: 839, tv_nsec: 717813802 }, first_sent_time: Instant { tv_sec: 839, tv_nsec: 717813802 }, end_of_app_limited: 6, last_sent_packet: 7, largest_acked: 0, rate_sample: RateSample { delivery_rate: 8165, is_app_limited: true, interval: 40.779716ms, delivered: 333, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 839, tv_nsec: 676594059 }), send_elapsed: 0ns, ack_elapsed: 40.779716ms, rtt: 40.779716ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 75, rate: 413808, last_update: Instant { tv_sec: 839, tv_nsec: 718351222 }, next_time: Instant { tv_sec: 839, tv_nsec: 721617038 }, 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-30T09:21:23.059018630Z TRACE quiche_apps::client] written 75 bytes from [::]:36963 to [fd00:cafe:cafe:100::100]:443
[2025-04-30T09:21:23.059023710Z TRACE quiche_apps::client] [::]:36963 -> [fd00:cafe:cafe:100::100]:443: done writing
[2025-04-30T09:21:23.091134963Z TRACE quiche_apps::client] got 890 bytes from [fd00:cafe:cafe:100::100]:443 to [::]:36963
[2025-04-30T09:21:23.091151925Z TRACE quiche] e68335eb25deef9a0ee756f48eabd7086ec35189 rx pkt Short dcid=e68335eb25deef9a0ee756f48eabd7086ec35189 key_phase=false len=869 pn=0 
[2025-04-30T09:21:23.091162615Z TRACE quiche] e68335eb25deef9a0ee756f48eabd7086ec35189 rx frm ACK delay=0 blocks=[3..3] ecn_counts=None
[2025-04-30T09:21:23.091167935Z TRACE quiche::recovery::congestion::recovery] e68335eb25deef9a0ee756f48eabd7086ec35189 packet newly acked 3
[2025-04-30T09:21:23.091173636Z TRACE quiche] e68335eb25deef9a0ee756f48eabd7086ec35189 rx frm CRYPTO off=0 len=540
[2025-04-30T09:21:23.091208751Z TRACE quiche] e68335eb25deef9a0ee756f48eabd7086ec35189 rx frm HANDSHAKE_DONE
[2025-04-30T09:21:23.091214492Z TRACE quiche] e68335eb25deef9a0ee756f48eabd7086ec35189 dropped epoch 1 state
[2025-04-30T09:21:23.091220604Z TRACE quiche] e68335eb25deef9a0ee756f48eabd7086ec35189 rx frm NEW_CONNECTION_ID seq_num=1 retire_prior_to=0 conn_id=[00, 00, 00, 00, 00, 00, 30, 04, 4f, 40, 81, 25, 2a, 6f, c8, 91, a6, 8c, 89, b5] reset_token=[5b, aa, 7b, 43, c6, f8, 0b, 91, 54, bc, 29, a0, 54, c7, a6, 00]
[2025-04-30T09:21:23.091229811Z TRACE quiche] e68335eb25deef9a0ee756f48eabd7086ec35189 rx frm NEW_CONNECTION_ID seq_num=2 retire_prior_to=0 conn_id=[00, 00, 00, 00, 00, 00, 30, 04, 16, 53, 44, a8, b1, 44, 0c, 98, 18, a6, 45, 59] reset_token=[58, 44, 39, b1, 53, 16, 00, 71, ad, e8, 40, b3, 32, 76, 05, 62]
[2025-04-30T09:21:23.091237716Z TRACE quiche] e68335eb25deef9a0ee756f48eabd7086ec35189 rx frm NEW_CONNECTION_ID seq_num=3 retire_prior_to=0 conn_id=[00, 00, 00, 00, 00, 00, 30, 04, 3d, ac, 0b, 6f, 1a, 16, 6c, 17, 4d, ad, 7a, 41] reset_token=[73, 6b, 56, 70, c0, 1f, 71, 69, 7f, 61, 66, 82, 31, d2, 7c, 1a]
[2025-04-30T09:21:23.091244919Z TRACE quiche] e68335eb25deef9a0ee756f48eabd7086ec35189 rx frm NEW_CONNECTION_ID seq_num=4 retire_prior_to=0 conn_id=[00, 00, 00, 00, 00, 00, 30, 04, 42, 1a, e6, 84, 97, bd, cd, 6d, 84, 51, 4c, 33] reset_token=[6e, f9, de, d3, a2, 7f, 06, f1, 27, ed, ff, 22, a2, d7, ee, 67]
[2025-04-30T09:21:23.091252183Z TRACE quiche] e68335eb25deef9a0ee756f48eabd7086ec35189 rx frm NEW_CONNECTION_ID seq_num=5 retire_prior_to=0 conn_id=[00, 00, 00, 00, 00, 00, 30, 04, 68, f0, bf, 8a, fa, 9e, 49, 7b, 8c, 8a, 26, 3b] reset_token=[96, c1, 92, 32, 8a, 98, 37, 42, ae, da, 4d, c5, c1, b5, f0, ec]
[2025-04-30T09:21:23.091259367Z TRACE quiche] e68335eb25deef9a0ee756f48eabd7086ec35189 rx frm NEW_CONNECTION_ID seq_num=6 retire_prior_to=0 conn_id=[00, 00, 00, 00, 00, 00, 30, 04, b3, 6a, fd, 93, 11, 1c, 36, cc, a8, d2, ea, 5c] reset_token=[10, 42, 4a, ba, d8, ee, 3c, 82, 8a, 24, 7e, 66, 9b, 03, 1b, 62]
[2025-04-30T09:21:23.091266400Z TRACE quiche] e68335eb25deef9a0ee756f48eabd7086ec35189 rx frm NEW_CONNECTION_ID seq_num=7 retire_prior_to=0 conn_id=[00, 00, 00, 00, 00, 00, 30, 04, ce, 2b, ea, a3, 30, b3, c5, bf, 1d, a2, ed, 57] reset_token=[69, e7, 41, 14, 43, c2, 74, 4a, e0, 5b, 31, df, fe, a9, d8, 05]
[2025-04-30T09:21:23.091271960Z TRACE quiche] e68335eb25deef9a0ee756f48eabd7086ec35189 rx frm STREAM id=3 off=0 len=1 fin=false
[2025-04-30T09:21:23.091276489Z TRACE quiche] e68335eb25deef9a0ee756f48eabd7086ec35189 rx frm STREAM id=3 off=1 len=8 fin=false
[2025-04-30T09:21:23.091280056Z TRACE quiche] e68335eb25deef9a0ee756f48eabd7086ec35189 rx frm STREAM id=7 off=0 len=1 fin=false
[2025-04-30T09:21:23.091299733Z TRACE quiche_apps::client] [::]:36963: processed 890 bytes
[2025-04-30T09:21:23.091306746Z TRACE quiche_apps::client] got 43 bytes from [fd00:cafe:cafe:100::100]:443 to [::]:36963
[2025-04-30T09:21:23.091311174Z TRACE quiche] e68335eb25deef9a0ee756f48eabd7086ec35189 rx pkt Short dcid=e68335eb25deef9a0ee756f48eabd7086ec35189 key_phase=false len=22 pn=1 
[2025-04-30T09:21:23.091316685Z TRACE quiche] e68335eb25deef9a0ee756f48eabd7086ec35189 rx frm ACK delay=0 blocks=[3..5] ecn_counts=None
[2025-04-30T09:21:23.091320381Z TRACE quiche::recovery::congestion::recovery] e68335eb25deef9a0ee756f48eabd7086ec35189 packet newly acked 4
[2025-04-30T09:21:23.091323257Z TRACE quiche::recovery::congestion::recovery] e68335eb25deef9a0ee756f48eabd7086ec35189 packet newly acked 5
[2025-04-30T09:21:23.091331562Z TRACE quiche_apps::client] [::]:36963: processed 43 bytes
[2025-04-30T09:21:23.091336001Z TRACE quiche_apps::client] [::]:36963: recv() would block
[2025-04-30T09:21:23.091338876Z TRACE quiche_apps::client] done reading
[2025-04-30T09:21:23.091342042Z TRACE quiche::h3] e68335eb25deef9a0ee756f48eabd7086ec35189 stream id 3 is readable
[2025-04-30T09:21:23.091348314Z TRACE quiche::h3::stream] e68335eb25deef9a0ee756f48eabd7086ec35189 read 1 bytes on stream 3
[2025-04-30T09:21:23.091353554Z TRACE quiche::h3] e68335eb25deef9a0ee756f48eabd7086ec35189 open peer's control stream 3
[2025-04-30T09:21:23.091362821Z TRACE quiche::h3::stream] e68335eb25deef9a0ee756f48eabd7086ec35189 read 1 bytes on stream 3
[2025-04-30T09:21:23.091366779Z TRACE quiche::h3::stream] e68335eb25deef9a0ee756f48eabd7086ec35189 read 1 bytes on stream 3
[2025-04-30T09:21:23.091370826Z TRACE quiche::h3::stream] e68335eb25deef9a0ee756f48eabd7086ec35189 read 6 bytes on stream 3
[2025-04-30T09:21:23.091374413Z TRACE quiche::h3] e68335eb25deef9a0ee756f48eabd7086ec35189 rx frm SETTINGS max_field_section=None, qpack_max_table=Some(4096), qpack_blocked=Some(128) raw=Some([(1, 4096), (7, 128)]), additional_settings=None stream=3 payload_len=6
[2025-04-30T09:21:23.091382568Z TRACE quiche::h3] e68335eb25deef9a0ee756f48eabd7086ec35189 stream id 7 is readable
[2025-04-30T09:21:23.091387207Z TRACE quiche::h3::stream] e68335eb25deef9a0ee756f48eabd7086ec35189 read 1 bytes on stream 7
[2025-04-30T09:21:23.091398218Z TRACE quiche] e68335eb25deef9a0ee756f48eabd7086ec35189 pmtud probe status false hs_con=true hs_sent=false cwnd_avail=13314 out_len=1350 left=1307
[2025-04-30T09:21:23.091402636Z TRACE quiche] e68335eb25deef9a0ee756f48eabd7086ec35189 tx pkt Short dcid=00000000000030040c307b3f9361829bea0d3b84 key_phase=false len=5 pn=8 
[2025-04-30T09:21:23.091405862Z TRACE quiche] e68335eb25deef9a0ee756f48eabd7086ec35189 tx frm ACK delay=10 blocks=[0..1] ecn_counts=None
[2025-04-30T09:21:23.091413276Z TRACE quiche::recovery::congestion::recovery] e68335eb25deef9a0ee756f48eabd7086ec35189 timer=93.41892ms latest_rtt=29.531763ms srtt=38.445449ms min_rtt=29.531763ms rttvar=15.607383ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=186 app_limited=true congestion_recovery_start_time=None Rate { delivered: 1586, delivered_time: Instant { tv_sec: 839, tv_nsec: 750774231 }, first_sent_time: Instant { tv_sec: 839, tv_nsec: 718320823 }, end_of_app_limited: 7, last_sent_packet: 8, largest_acked: 5, rate_sample: RateSample { delivery_rate: 38201, is_app_limited: true, interval: 32.799687ms, delivered: 1253, prior_delivered: 333, prior_time: Some(Instant { tv_sec: 839, tv_nsec: 717813802 }), send_elapsed: 507.021µs, ack_elapsed: 32.799687ms, rtt: 32.292666ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 438933, last_update: Instant { tv_sec: 839, tv_nsec: 750857297 }, next_time: Instant { tv_sec: 839, tv_nsec: 750857297 }, 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-30T09:21:23.091456387Z TRACE quiche_apps::client] written 43 bytes from [::]:36963 to [fd00:cafe:cafe:100::100]:443
[2025-04-30T09:21:23.091462118Z TRACE quiche_apps::client] [::]:36963 -> [fd00:cafe:cafe:100::100]:443: done writing
[2025-04-30T09:21:23.092194985Z TRACE quiche_apps::client] got 1200 bytes from [fd00:cafe:cafe:100::100]:443 to [::]:36963
[2025-04-30T09:21:23.092202629Z TRACE quiche] e68335eb25deef9a0ee756f48eabd7086ec35189 rx pkt Short dcid=e68335eb25deef9a0ee756f48eabd7086ec35189 key_phase=false len=1179 pn=2 
[2025-04-30T09:21:23.092208270Z TRACE quiche] e68335eb25deef9a0ee756f48eabd7086ec35189 rx frm ACK delay=0 blocks=[3..6] ecn_counts=None
[2025-04-30T09:21:23.092211556Z TRACE quiche::recovery::congestion::recovery] e68335eb25deef9a0ee756f48eabd7086ec35189 packet newly acked 6
[2025-04-30T09:21:23.092216125Z TRACE quiche] e68335eb25deef9a0ee756f48eabd7086ec35189 rx frm STREAM id=0 off=0 len=1152 fin=false
[2025-04-30T09:21:23.092225212Z TRACE quiche_apps::client] [::]:36963: processed 1200 bytes
[2025-04-30T09:21:23.092228768Z TRACE quiche_apps::client] [::]:36963: recv() would block
[2025-04-30T09:21:23.092231063Z TRACE quiche_apps::client] done reading
[2025-04-30T09:21:23.092233497Z TRACE quiche::h3] e68335eb25deef9a0ee756f48eabd7086ec35189 stream id 0 is readable
[2025-04-30T09:21:23.092241843Z TRACE quiche::h3::stream] e68335eb25deef9a0ee756f48eabd7086ec35189 read 1 bytes on stream 0
[2025-04-30T09:21:23.092245099Z TRACE quiche::h3::stream] e68335eb25deef9a0ee756f48eabd7086ec35189 read 1 bytes on stream 0
[2025-04-30T09:21:23.092247995Z TRACE quiche::h3::stream] e68335eb25deef9a0ee756f48eabd7086ec35189 read 1 bytes on stream 0
[2025-04-30T09:21:23.092251321Z TRACE quiche::h3::stream] e68335eb25deef9a0ee756f48eabd7086ec35189 read 139 bytes on stream 0
[2025-04-30T09:21:23.092253835Z TRACE quiche::h3] e68335eb25deef9a0ee756f48eabd7086ec35189 rx frm HEADERS stream=0 payload_len=139
[2025-04-30T09:21:23.092257152Z TRACE quiche::h3::qpack::decoder] Header count=0 base=0
[2025-04-30T09:21:23.092259646Z TRACE quiche::h3::qpack::decoder] Indexed index=25 static=true
[2025-04-30T09:21:23.092263844Z TRACE quiche::h3::qpack::decoder] Literal name_idx=92 static=true value=[110, 103, 105, 110, 120, 47, 49, 46, 50, 55, 46, 48]
[2025-04-30T09:21:23.092269805Z 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, 48, 57, 58, 50, 49, 58, 50, 51, 32, 71, 77, 84]
[2025-04-30T09:21:23.092274815Z TRACE quiche::h3::qpack::decoder] Literal name_idx=53 static=true value=[97, 112, 112, 108, 105, 99, 97, 116, 105, 111, 110, 47, 111, 99, 116, 101, 116, 45, 115, 116, 114, 101, 97, 109]
[2025-04-30T09:21:23.092278332Z TRACE quiche::h3::qpack::decoder] Literal name_idx=4 static=true value=[53, 49, 50, 48]
[2025-04-30T09:21:23.092281738Z TRACE quiche::h3::qpack::decoder] Literal name_idx=10 static=true value=[87, 101, 100, 44, 32, 51, 48, 32, 65, 112, 114, 32, 50, 48, 50, 53, 32, 48, 57, 58, 50, 49, 58, 50, 49, 32, 71, 77, 84]
[2025-04-30T09:21:23.092286547Z TRACE quiche::h3::qpack::decoder] Literal Without Name Reference name=[101, 116, 97, 103] value=[34, 54, 56, 49, 49, 101, 98, 57, 49, 45, 49, 52, 48, 48, 34]
[2025-04-30T09:21:23.092290655Z TRACE quiche::h3::qpack::decoder] Literal Without Name Reference name=[97, 108, 116, 45, 115, 118, 99] value=[104, 113, 45, 50, 57, 61, 34, 58, 52, 52, 51, 34]
[2025-04-30T09:21:23.092294362Z TRACE quiche::h3::qpack::decoder] Literal Without Name Reference name=[97, 99, 99, 101, 112, 116, 45, 114, 97, 110, 103, 101, 115] value=[98, 121, 116, 101, 115]
[2025-04-30T09:21:23.092303369Z DEBUG quiche_apps::common] got response headers [(":status", "200"), ("server", "nginx/1.27.0"), ("date", "Wed, 30 Apr 2025 09:21:23 GMT"), ("content-type", "application/octet-stream"), ("content-length", "5120"), ("last-modified", "Wed, 30 Apr 2025 09:21:21 GMT"), ("etag", "\"6811eb91-1400\""), ("alt-svc", "hq-29=\":443\""), ("accept-ranges", "bytes")] on stream id 0
[2025-04-30T09:21:23.092309911Z TRACE quiche::h3] e68335eb25deef9a0ee756f48eabd7086ec35189 stream id 0 is readable
[2025-04-30T09:21:23.092312926Z TRACE quiche::h3::stream] e68335eb25deef9a0ee756f48eabd7086ec35189 read 1 bytes on stream 0
[2025-04-30T09:21:23.092315832Z TRACE quiche::h3::stream] e68335eb25deef9a0ee756f48eabd7086ec35189 read 1 bytes on stream 0
[2025-04-30T09:21:23.092318667Z TRACE quiche::h3::stream] e68335eb25deef9a0ee756f48eabd7086ec35189 read 1 bytes on stream 0
[2025-04-30T09:21:23.092320982Z TRACE quiche::h3] e68335eb25deef9a0ee756f48eabd7086ec35189 rx frm DATA stream=0 wire_payload_len=5120
[2025-04-30T09:21:23.092325490Z DEBUG quiche_apps::common] got 1007 bytes of response data on stream 0
[2025-04-30T09:21:23.092332623Z TRACE quiche] e68335eb25deef9a0ee756f48eabd7086ec35189 pmtud probe status false hs_con=true hs_sent=false cwnd_avail=13425 out_len=1350 left=1307
[2025-04-30T09:21:23.092335729Z TRACE quiche] e68335eb25deef9a0ee756f48eabd7086ec35189 tx pkt Short dcid=00000000000030040c307b3f9361829bea0d3b84 key_phase=false len=5 pn=9 
[2025-04-30T09:21:23.092338224Z TRACE quiche] e68335eb25deef9a0ee756f48eabd7086ec35189 tx frm ACK delay=16 blocks=[0..2] ecn_counts=None
[2025-04-30T09:21:23.092343815Z TRACE quiche::recovery::congestion::recovery] e68335eb25deef9a0ee756f48eabd7086ec35189 timer=83.900972ms latest_rtt=30.422848ms srtt=37.442623ms min_rtt=29.531763ms rttvar=13.711187ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=75 app_limited=true congestion_recovery_start_time=None Rate { delivered: 1697, delivered_time: Instant { tv_sec: 839, tv_nsec: 751665316 }, first_sent_time: Instant { tv_sec: 839, tv_nsec: 718320823 }, end_of_app_limited: 8, last_sent_packet: 9, largest_acked: 6, rate_sample: RateSample { delivery_rate: 41585, is_app_limited: true, interval: 32.799687ms, delivered: 1364, prior_delivered: 333, prior_time: Some(Instant { tv_sec: 839, tv_nsec: 717813802 }), send_elapsed: 507.021µs, ack_elapsed: 32.799687ms, rtt: 32.292666ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 450689, last_update: Instant { tv_sec: 839, tv_nsec: 750857297 }, next_time: Instant { tv_sec: 839, tv_nsec: 750857297 }, 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-30T09:21:23.092386735Z TRACE quiche_apps::client] written 43 bytes from [::]:36963 to [fd00:cafe:cafe:100::100]:443
[2025-04-30T09:21:23.092391033Z TRACE quiche_apps::client] [::]:36963 -> [fd00:cafe:cafe:100::100]:443: done writing
[2025-04-30T09:21:23.093205464Z TRACE quiche_apps::client] got 1200 bytes from [fd00:cafe:cafe:100::100]:443 to [::]:36963
[2025-04-30T09:21:23.093212517Z TRACE quiche] e68335eb25deef9a0ee756f48eabd7086ec35189 rx pkt Short dcid=e68335eb25deef9a0ee756f48eabd7086ec35189 key_phase=false len=1179 pn=3 
[2025-04-30T09:21:23.093218619Z TRACE quiche] e68335eb25deef9a0ee756f48eabd7086ec35189 rx frm STREAM id=0 off=1152 len=1156 fin=false
[2025-04-30T09:21:23.093225201Z TRACE quiche_apps::client] [::]:36963: processed 1200 bytes
[2025-04-30T09:21:23.093228658Z TRACE quiche_apps::client] [::]:36963: recv() would block
[2025-04-30T09:21:23.093230942Z TRACE quiche_apps::client] done reading
[2025-04-30T09:21:23.093233387Z TRACE quiche::h3] e68335eb25deef9a0ee756f48eabd7086ec35189 stream id 0 is readable
[2025-04-30T09:21:23.093237745Z DEBUG quiche_apps::common] got 1156 bytes of response data on stream 0
[2025-04-30T09:21:23.093244417Z TRACE quiche] e68335eb25deef9a0ee756f48eabd7086ec35189 pmtud probe status false hs_con=true hs_sent=false cwnd_avail=13425 out_len=1350 left=1307
[2025-04-30T09:21:23.093247463Z TRACE quiche] e68335eb25deef9a0ee756f48eabd7086ec35189 tx pkt Short dcid=00000000000030040c307b3f9361829bea0d3b84 key_phase=false len=5 pn=10 
[2025-04-30T09:21:23.093249918Z TRACE quiche] e68335eb25deef9a0ee756f48eabd7086ec35189 tx frm ACK delay=4 blocks=[0..3] ecn_counts=None
[2025-04-30T09:21:23.093255718Z TRACE quiche::recovery::congestion::recovery] e68335eb25deef9a0ee756f48eabd7086ec35189 timer=82.989068ms latest_rtt=30.422848ms srtt=37.442623ms min_rtt=29.531763ms rttvar=13.711187ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=75 app_limited=true congestion_recovery_start_time=None Rate { delivered: 1697, delivered_time: Instant { tv_sec: 839, tv_nsec: 751665316 }, first_sent_time: Instant { tv_sec: 839, tv_nsec: 718320823 }, end_of_app_limited: 8, last_sent_packet: 10, largest_acked: 6, rate_sample: RateSample { delivery_rate: 41585, is_app_limited: true, interval: 32.799687ms, delivered: 1364, prior_delivered: 333, prior_time: Some(Instant { tv_sec: 839, tv_nsec: 717813802 }), send_elapsed: 507.021µs, ack_elapsed: 32.799687ms, rtt: 32.292666ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 450689, last_update: Instant { tv_sec: 839, tv_nsec: 750857297 }, next_time: Instant { tv_sec: 839, tv_nsec: 750857297 }, 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-30T09:21:23.093286857Z TRACE quiche_apps::client] written 43 bytes from [::]:36963 to [fd00:cafe:cafe:100::100]:443
[2025-04-30T09:21:23.093290804Z TRACE quiche_apps::client] [::]:36963 -> [fd00:cafe:cafe:100::100]:443: done writing
[2025-04-30T09:21:23.094189784Z TRACE quiche_apps::client] got 1200 bytes from [fd00:cafe:cafe:100::100]:443 to [::]:36963
[2025-04-30T09:21:23.094196677Z TRACE quiche] e68335eb25deef9a0ee756f48eabd7086ec35189 rx pkt Short dcid=e68335eb25deef9a0ee756f48eabd7086ec35189 key_phase=false len=1179 pn=4 
[2025-04-30T09:21:23.094202187Z TRACE quiche] e68335eb25deef9a0ee756f48eabd7086ec35189 rx frm STREAM id=0 off=2308 len=1156 fin=false
[2025-04-30T09:21:23.094208299Z TRACE quiche_apps::client] [::]:36963: processed 1200 bytes
[2025-04-30T09:21:23.094211705Z TRACE quiche_apps::client] [::]:36963: recv() would block
[2025-04-30T09:21:23.094213989Z TRACE quiche_apps::client] done reading
[2025-04-30T09:21:23.094216384Z TRACE quiche::h3] e68335eb25deef9a0ee756f48eabd7086ec35189 stream id 0 is readable
[2025-04-30T09:21:23.094220321Z DEBUG quiche_apps::common] got 1156 bytes of response data on stream 0
[2025-04-30T09:21:23.094226673Z TRACE quiche] e68335eb25deef9a0ee756f48eabd7086ec35189 pmtud probe status false hs_con=true hs_sent=false cwnd_avail=13425 out_len=1350 left=1307
[2025-04-30T09:21:23.094229649Z TRACE quiche] e68335eb25deef9a0ee756f48eabd7086ec35189 tx pkt Short dcid=00000000000030040c307b3f9361829bea0d3b84 key_phase=false len=5 pn=11 
[2025-04-30T09:21:23.094232003Z TRACE quiche] e68335eb25deef9a0ee756f48eabd7086ec35189 tx frm ACK delay=3 blocks=[0..4] ecn_counts=None
[2025-04-30T09:21:23.094237624Z TRACE quiche::recovery::congestion::recovery] e68335eb25deef9a0ee756f48eabd7086ec35189 timer=82.007182ms latest_rtt=30.422848ms srtt=37.442623ms min_rtt=29.531763ms rttvar=13.711187ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=75 app_limited=true congestion_recovery_start_time=None Rate { delivered: 1697, delivered_time: Instant { tv_sec: 839, tv_nsec: 751665316 }, first_sent_time: Instant { tv_sec: 839, tv_nsec: 718320823 }, end_of_app_limited: 8, last_sent_packet: 11, largest_acked: 6, rate_sample: RateSample { delivery_rate: 41585, is_app_limited: true, interval: 32.799687ms, delivered: 1364, prior_delivered: 333, prior_time: Some(Instant { tv_sec: 839, tv_nsec: 717813802 }), send_elapsed: 507.021µs, ack_elapsed: 32.799687ms, rtt: 32.292666ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 450689, last_update: Instant { tv_sec: 839, tv_nsec: 750857297 }, next_time: Instant { tv_sec: 839, tv_nsec: 750857297 }, 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-30T09:21:23.094263162Z TRACE quiche_apps::client] written 43 bytes from [::]:36963 to [fd00:cafe:cafe:100::100]:443
[2025-04-30T09:21:23.094267139Z TRACE quiche_apps::client] [::]:36963 -> [fd00:cafe:cafe:100::100]:443: done writing
[2025-04-30T09:21:23.095187639Z TRACE quiche_apps::client] got 1200 bytes from [fd00:cafe:cafe:100::100]:443 to [::]:36963
[2025-04-30T09:21:23.095194261Z TRACE quiche] e68335eb25deef9a0ee756f48eabd7086ec35189 rx pkt Short dcid=e68335eb25deef9a0ee756f48eabd7086ec35189 key_phase=false len=1179 pn=5 
[2025-04-30T09:21:23.095199582Z TRACE quiche] e68335eb25deef9a0ee756f48eabd7086ec35189 rx frm STREAM id=0 off=3464 len=1156 fin=false
[2025-04-30T09:21:23.095205422Z TRACE quiche_apps::client] [::]:36963: processed 1200 bytes
[2025-04-30T09:21:23.095208749Z TRACE quiche_apps::client] [::]:36963: recv() would block
[2025-04-30T09:21:23.095210983Z TRACE quiche_apps::client] done reading
[2025-04-30T09:21:23.095213377Z TRACE quiche::h3] e68335eb25deef9a0ee756f48eabd7086ec35189 stream id 0 is readable
[2025-04-30T09:21:23.095222044Z DEBUG quiche_apps::common] got 1156 bytes of response data on stream 0
[2025-04-30T09:21:23.095228646Z TRACE quiche] e68335eb25deef9a0ee756f48eabd7086ec35189 pmtud probe status false hs_con=true hs_sent=false cwnd_avail=13425 out_len=1350 left=1307
[2025-04-30T09:21:23.095231551Z TRACE quiche] e68335eb25deef9a0ee756f48eabd7086ec35189 tx pkt Short dcid=00000000000030040c307b3f9361829bea0d3b84 key_phase=false len=5 pn=12 
[2025-04-30T09:21:23.095233916Z TRACE quiche] e68335eb25deef9a0ee756f48eabd7086ec35189 tx frm ACK delay=4 blocks=[0..5] ecn_counts=None
[2025-04-30T09:21:23.095239436Z TRACE quiche::recovery::congestion::recovery] e68335eb25deef9a0ee756f48eabd7086ec35189 timer=81.00537ms latest_rtt=30.422848ms srtt=37.442623ms min_rtt=29.531763ms rttvar=13.711187ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=75 app_limited=true congestion_recovery_start_time=None Rate { delivered: 1697, delivered_time: Instant { tv_sec: 839, tv_nsec: 751665316 }, first_sent_time: Instant { tv_sec: 839, tv_nsec: 718320823 }, end_of_app_limited: 8, last_sent_packet: 12, largest_acked: 6, rate_sample: RateSample { delivery_rate: 41585, is_app_limited: true, interval: 32.799687ms, delivered: 1364, prior_delivered: 333, prior_time: Some(Instant { tv_sec: 839, tv_nsec: 717813802 }), send_elapsed: 507.021µs, ack_elapsed: 32.799687ms, rtt: 32.292666ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 450689, last_update: Instant { tv_sec: 839, tv_nsec: 750857297 }, next_time: Instant { tv_sec: 839, tv_nsec: 750857297 }, 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-30T09:21:23.095264844Z TRACE quiche_apps::client] written 43 bytes from [::]:36963 to [fd00:cafe:cafe:100::100]:443
[2025-04-30T09:21:23.095268701Z TRACE quiche_apps::client] [::]:36963 -> [fd00:cafe:cafe:100::100]:443: done writing
[2025-04-30T09:21:23.095783860Z TRACE quiche_apps::client] got 694 bytes from [fd00:cafe:cafe:100::100]:443 to [::]:36963
[2025-04-30T09:21:23.095788468Z TRACE quiche] e68335eb25deef9a0ee756f48eabd7086ec35189 rx pkt Short dcid=e68335eb25deef9a0ee756f48eabd7086ec35189 key_phase=false len=673 pn=6 
[2025-04-30T09:21:23.095793858Z TRACE quiche] e68335eb25deef9a0ee756f48eabd7086ec35189 rx frm STREAM id=0 off=4620 len=645 fin=false
[2025-04-30T09:21:23.095796954Z TRACE quiche] e68335eb25deef9a0ee756f48eabd7086ec35189 rx frm STREAM id=0 off=5265 len=0 fin=true
[2025-04-30T09:21:23.095802965Z TRACE quiche_apps::client] [::]:36963: processed 694 bytes
[2025-04-30T09:21:23.095806271Z TRACE quiche_apps::client] [::]:36963: recv() would block
[2025-04-30T09:21:23.095808496Z TRACE quiche_apps::client] done reading
[2025-04-30T09:21:23.095810860Z TRACE quiche::h3] e68335eb25deef9a0ee756f48eabd7086ec35189 stream id 0 is readable
[2025-04-30T09:21:23.095816350Z DEBUG quiche_apps::common] got 645 bytes of response data on stream 0
[2025-04-30T09:21:23.095819126Z DEBUG quiche_apps::common] 1/2 responses received
[2025-04-30T09:21:23.095825357Z TRACE quiche] e68335eb25deef9a0ee756f48eabd7086ec35189 pmtud probe status false hs_con=true hs_sent=false cwnd_avail=13425 out_len=1350 left=1307
[2025-04-30T09:21:23.095828373Z TRACE quiche] e68335eb25deef9a0ee756f48eabd7086ec35189 tx pkt Short dcid=00000000000030040c307b3f9361829bea0d3b84 key_phase=false len=5 pn=13 
[2025-04-30T09:21:23.095830777Z TRACE quiche] e68335eb25deef9a0ee756f48eabd7086ec35189 tx frm ACK delay=4 blocks=[0..6] ecn_counts=None
[2025-04-30T09:21:23.095836168Z TRACE quiche::recovery::congestion::recovery] e68335eb25deef9a0ee756f48eabd7086ec35189 timer=80.408618ms latest_rtt=30.422848ms srtt=37.442623ms min_rtt=29.531763ms rttvar=13.711187ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=75 app_limited=true congestion_recovery_start_time=None Rate { delivered: 1697, delivered_time: Instant { tv_sec: 839, tv_nsec: 751665316 }, first_sent_time: Instant { tv_sec: 839, tv_nsec: 718320823 }, end_of_app_limited: 8, last_sent_packet: 13, largest_acked: 6, rate_sample: RateSample { delivery_rate: 41585, is_app_limited: true, interval: 32.799687ms, delivered: 1364, prior_delivered: 333, prior_time: Some(Instant { tv_sec: 839, tv_nsec: 717813802 }), send_elapsed: 507.021µs, ack_elapsed: 32.799687ms, rtt: 32.292666ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 450689, last_update: Instant { tv_sec: 839, tv_nsec: 750857297 }, next_time: Instant { tv_sec: 839, tv_nsec: 750857297 }, 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-30T09:21:23.095865854Z TRACE quiche_apps::client] written 43 bytes from [::]:36963 to [fd00:cafe:cafe:100::100]:443
[2025-04-30T09:21:23.095869861Z TRACE quiche_apps::client] [::]:36963 -> [fd00:cafe:cafe:100::100]:443: done writing
[2025-04-30T09:21:23.096786844Z TRACE quiche_apps::client] got 1200 bytes from [fd00:cafe:cafe:100::100]:443 to [::]:36963
[2025-04-30T09:21:23.096795881Z TRACE quiche] e68335eb25deef9a0ee756f48eabd7086ec35189 rx pkt Short dcid=e68335eb25deef9a0ee756f48eabd7086ec35189 key_phase=false len=1179 pn=7 
[2025-04-30T09:21:23.096802073Z TRACE quiche] e68335eb25deef9a0ee756f48eabd7086ec35189 rx frm ACK delay=0 blocks=[3..7] ecn_counts=None
[2025-04-30T09:21:23.096805549Z TRACE quiche::recovery::congestion::recovery] e68335eb25deef9a0ee756f48eabd7086ec35189 packet newly acked 7
[2025-04-30T09:21:23.096809537Z TRACE quiche] e68335eb25deef9a0ee756f48eabd7086ec35189 rx frm STREAM id=4 off=0 len=1152 fin=false
[2025-04-30T09:21:23.096819145Z TRACE quiche_apps::client] [::]:36963: processed 1200 bytes
[2025-04-30T09:21:23.096822792Z TRACE quiche_apps::client] [::]:36963: recv() would block
[2025-04-30T09:21:23.096825106Z TRACE quiche_apps::client] done reading
[2025-04-30T09:21:23.096827581Z TRACE quiche::h3] e68335eb25deef9a0ee756f48eabd7086ec35189 stream id 4 is readable
[2025-04-30T09:21:23.096831218Z TRACE quiche::h3::stream] e68335eb25deef9a0ee756f48eabd7086ec35189 read 1 bytes on stream 4
[2025-04-30T09:21:23.096834484Z TRACE quiche::h3::stream] e68335eb25deef9a0ee756f48eabd7086ec35189 read 1 bytes on stream 4
[2025-04-30T09:21:23.096837379Z TRACE quiche::h3::stream] e68335eb25deef9a0ee756f48eabd7086ec35189 read 1 bytes on stream 4
[2025-04-30T09:21:23.096840786Z TRACE quiche::h3::stream] e68335eb25deef9a0ee756f48eabd7086ec35189 read 140 bytes on stream 4
[2025-04-30T09:21:23.096843310Z TRACE quiche::h3] e68335eb25deef9a0ee756f48eabd7086ec35189 rx frm HEADERS stream=4 payload_len=140
[2025-04-30T09:21:23.096845985Z TRACE quiche::h3::qpack::decoder] Header count=0 base=0
[2025-04-30T09:21:23.096848209Z TRACE quiche::h3::qpack::decoder] Indexed index=25 static=true
[2025-04-30T09:21:23.096851045Z TRACE quiche::h3::qpack::decoder] Literal name_idx=92 static=true value=[110, 103, 105, 110, 120, 47, 49, 46, 50, 55, 46, 48]
[2025-04-30T09:21:23.096854702Z 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, 48, 57, 58, 50, 49, 58, 50, 51, 32, 71, 77, 84]
[2025-04-30T09:21:23.096858629Z TRACE quiche::h3::qpack::decoder] Literal name_idx=53 static=true value=[97, 112, 112, 108, 105, 99, 97, 116, 105, 111, 110, 47, 111, 99, 116, 101, 116, 45, 115, 116, 114, 101, 97, 109]
[2025-04-30T09:21:23.096862166Z TRACE quiche::h3::qpack::decoder] Literal name_idx=4 static=true value=[49, 48, 50, 52, 48]
[2025-04-30T09:21:23.096865091Z TRACE quiche::h3::qpack::decoder] Literal name_idx=10 static=true value=[87, 101, 100, 44, 32, 51, 48, 32, 65, 112, 114, 32, 50, 48, 50, 53, 32, 48, 57, 58, 50, 49, 58, 50, 49, 32, 71, 77, 84]
[2025-04-30T09:21:23.096874038Z TRACE quiche::h3::qpack::decoder] Literal Without Name Reference name=[101, 116, 97, 103] value=[34, 54, 56, 49, 49, 101, 98, 57, 49, 45, 50, 56, 48, 48, 34]
[2025-04-30T09:21:23.096877725Z TRACE quiche::h3::qpack::decoder] Literal Without Name Reference name=[97, 108, 116, 45, 115, 118, 99] value=[104, 113, 45, 50, 57, 61, 34, 58, 52, 52, 51, 34]
[2025-04-30T09:21:23.096881111Z TRACE quiche::h3::qpack::decoder] Literal Without Name Reference name=[97, 99, 99, 101, 112, 116, 45, 114, 97, 110, 103, 101, 115] value=[98, 121, 116, 101, 115]
[2025-04-30T09:21:23.096890740Z DEBUG quiche_apps::common] got response headers [(":status", "200"), ("server", "nginx/1.27.0"), ("date", "Wed, 30 Apr 2025 09:21:23 GMT"), ("content-type", "application/octet-stream"), ("content-length", "10240"), ("last-modified", "Wed, 30 Apr 2025 09:21:21 GMT"), ("etag", "\"6811eb91-2800\""), ("alt-svc", "hq-29=\":443\""), ("accept-ranges", "bytes")] on stream id 4
[2025-04-30T09:21:23.096896651Z TRACE quiche::h3] e68335eb25deef9a0ee756f48eabd7086ec35189 stream id 4 is readable
[2025-04-30T09:21:23.096899766Z TRACE quiche::h3::stream] e68335eb25deef9a0ee756f48eabd7086ec35189 read 1 bytes on stream 4
[2025-04-30T09:21:23.096902742Z TRACE quiche::h3::stream] e68335eb25deef9a0ee756f48eabd7086ec35189 read 1 bytes on stream 4
[2025-04-30T09:21:23.096905648Z TRACE quiche::h3::stream] e68335eb25deef9a0ee756f48eabd7086ec35189 read 1 bytes on stream 4
[2025-04-30T09:21:23.096907882Z TRACE quiche::h3] e68335eb25deef9a0ee756f48eabd7086ec35189 rx frm DATA stream=4 wire_payload_len=10240
[2025-04-30T09:21:23.096912260Z DEBUG quiche_apps::common] got 1006 bytes of response data on stream 4
[2025-04-30T09:21:23.096919824Z TRACE quiche] e68335eb25deef9a0ee756f48eabd7086ec35189 pmtud probe status false hs_con=true hs_sent=false cwnd_avail=13500 out_len=1350 left=1307
[2025-04-30T09:21:23.096923020Z TRACE quiche] e68335eb25deef9a0ee756f48eabd7086ec35189 tx pkt Short dcid=00000000000030040c307b3f9361829bea0d3b84 key_phase=false len=5 pn=14 
[2025-04-30T09:21:23.096925465Z TRACE quiche] e68335eb25deef9a0ee756f48eabd7086ec35189 tx frm ACK delay=15 blocks=[0..7] ecn_counts=None
[2025-04-30T09:21:23.096931045Z TRACE quiche::recovery::congestion::recovery] e68335eb25deef9a0ee756f48eabd7086ec35189 timer=none latest_rtt=34.641399ms srtt=37.092469ms min_rtt=29.531763ms rttvar=10.983696ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=0 app_limited=true congestion_recovery_start_time=None Rate { delivered: 1772, delivered_time: Instant { tv_sec: 839, tv_nsec: 750857297 }, first_sent_time: Instant { tv_sec: 839, tv_nsec: 750857297 }, end_of_app_limited: 13, last_sent_packet: 14, largest_acked: 7, rate_sample: RateSample { delivery_rate: 43872, is_app_limited: true, interval: 32.799687ms, delivered: 1439, prior_delivered: 333, prior_time: Some(Instant { tv_sec: 839, tv_nsec: 717813802 }), send_elapsed: 507.021µs, ack_elapsed: 32.799687ms, rtt: 32.292666ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 454944, last_update: Instant { tv_sec: 839, tv_nsec: 750857297 }, next_time: Instant { tv_sec: 839, tv_nsec: 750857297 }, 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-30T09:21:23.096961072Z TRACE quiche_apps::client] written 43 bytes from [::]:36963 to [fd00:cafe:cafe:100::100]:443
[2025-04-30T09:21:23.096965159Z TRACE quiche_apps::client] [::]:36963 -> [fd00:cafe:cafe:100::100]:443: done writing
[2025-04-30T09:21:23.097784379Z TRACE quiche_apps::client] got 1200 bytes from [fd00:cafe:cafe:100::100]:443 to [::]:36963
[2025-04-30T09:21:23.097791633Z TRACE quiche] e68335eb25deef9a0ee756f48eabd7086ec35189 rx pkt Short dcid=e68335eb25deef9a0ee756f48eabd7086ec35189 key_phase=false len=1179 pn=8 
[2025-04-30T09:21:23.097797774Z TRACE quiche] e68335eb25deef9a0ee756f48eabd7086ec35189 rx frm STREAM id=4 off=1152 len=1156 fin=false
[2025-04-30T09:21:23.097808234Z TRACE quiche_apps::client] [::]:36963: processed 1200 bytes
[2025-04-30T09:21:23.097811871Z TRACE quiche_apps::client] [::]:36963: recv() would block
[2025-04-30T09:21:23.097814185Z TRACE quiche_apps::client] done reading
[2025-04-30T09:21:23.097816600Z TRACE quiche::h3] e68335eb25deef9a0ee756f48eabd7086ec35189 stream id 4 is readable
[2025-04-30T09:21:23.097820617Z DEBUG quiche_apps::common] got 1156 bytes of response data on stream 4
[2025-04-30T09:21:23.097827300Z TRACE quiche] e68335eb25deef9a0ee756f48eabd7086ec35189 pmtud probe status false hs_con=true hs_sent=false cwnd_avail=13500 out_len=1350 left=1307
[2025-04-30T09:21:23.097830245Z TRACE quiche] e68335eb25deef9a0ee756f48eabd7086ec35189 tx pkt Short dcid=00000000000030040c307b3f9361829bea0d3b84 key_phase=false len=5 pn=15 
[2025-04-30T09:21:23.097832640Z TRACE quiche] e68335eb25deef9a0ee756f48eabd7086ec35189 tx frm ACK delay=4 blocks=[0..8] ecn_counts=None
[2025-04-30T09:21:23.097838270Z TRACE quiche::recovery::congestion::recovery] e68335eb25deef9a0ee756f48eabd7086ec35189 timer=none latest_rtt=34.641399ms srtt=37.092469ms min_rtt=29.531763ms rttvar=10.983696ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=0 app_limited=true congestion_recovery_start_time=None Rate { delivered: 1772, delivered_time: Instant { tv_sec: 839, tv_nsec: 750857297 }, first_sent_time: Instant { tv_sec: 839, tv_nsec: 750857297 }, end_of_app_limited: 13, last_sent_packet: 15, largest_acked: 7, rate_sample: RateSample { delivery_rate: 43872, is_app_limited: true, interval: 32.799687ms, delivered: 1439, prior_delivered: 333, prior_time: Some(Instant { tv_sec: 839, tv_nsec: 717813802 }), send_elapsed: 507.021µs, ack_elapsed: 32.799687ms, rtt: 32.292666ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 454944, last_update: Instant { tv_sec: 839, tv_nsec: 750857297 }, next_time: Instant { tv_sec: 839, tv_nsec: 750857297 }, 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-30T09:21:23.097865080Z TRACE quiche_apps::client] written 43 bytes from [::]:36963 to [fd00:cafe:cafe:100::100]:443
[2025-04-30T09:21:23.097869018Z TRACE quiche_apps::client] [::]:36963 -> [fd00:cafe:cafe:100::100]:443: done writing
[2025-04-30T09:21:23.098782194Z TRACE quiche_apps::client] got 1200 bytes from [fd00:cafe:cafe:100::100]:443 to [::]:36963
[2025-04-30T09:21:23.098789027Z TRACE quiche] e68335eb25deef9a0ee756f48eabd7086ec35189 rx pkt Short dcid=e68335eb25deef9a0ee756f48eabd7086ec35189 key_phase=false len=1179 pn=9 
[2025-04-30T09:21:23.098794427Z TRACE quiche] e68335eb25deef9a0ee756f48eabd7086ec35189 rx frm STREAM id=4 off=2308 len=1156 fin=false
[2025-04-30T09:21:23.098800308Z TRACE quiche_apps::client] [::]:36963: processed 1200 bytes
[2025-04-30T09:21:23.098803675Z TRACE quiche_apps::client] [::]:36963: recv() would block
[2025-04-30T09:21:23.098805919Z TRACE quiche_apps::client] done reading
[2025-04-30T09:21:23.098808313Z TRACE quiche::h3] e68335eb25deef9a0ee756f48eabd7086ec35189 stream id 4 is readable
[2025-04-30T09:21:23.098812160Z DEBUG quiche_apps::common] got 1156 bytes of response data on stream 4
[2025-04-30T09:21:23.098818362Z TRACE quiche] e68335eb25deef9a0ee756f48eabd7086ec35189 pmtud probe status false hs_con=true hs_sent=false cwnd_avail=13500 out_len=1350 left=1307
[2025-04-30T09:21:23.098821388Z TRACE quiche] e68335eb25deef9a0ee756f48eabd7086ec35189 tx pkt Short dcid=00000000000030040c307b3f9361829bea0d3b84 key_phase=false len=5 pn=16 
[2025-04-30T09:21:23.098823742Z TRACE quiche] e68335eb25deef9a0ee756f48eabd7086ec35189 tx frm ACK delay=3 blocks=[0..9] ecn_counts=None
[2025-04-30T09:21:23.098829793Z TRACE quiche::recovery::congestion::recovery] e68335eb25deef9a0ee756f48eabd7086ec35189 timer=none latest_rtt=34.641399ms srtt=37.092469ms min_rtt=29.531763ms rttvar=10.983696ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=0 app_limited=true congestion_recovery_start_time=None Rate { delivered: 1772, delivered_time: Instant { tv_sec: 839, tv_nsec: 750857297 }, first_sent_time: Instant { tv_sec: 839, tv_nsec: 750857297 }, end_of_app_limited: 13, last_sent_packet: 16, largest_acked: 7, rate_sample: RateSample { delivery_rate: 43872, is_app_limited: true, interval: 32.799687ms, delivered: 1439, prior_delivered: 333, prior_time: Some(Instant { tv_sec: 839, tv_nsec: 717813802 }), send_elapsed: 507.021µs, ack_elapsed: 32.799687ms, rtt: 32.292666ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 454944, last_update: Instant { tv_sec: 839, tv_nsec: 750857297 }, next_time: Instant { tv_sec: 839, tv_nsec: 750857297 }, 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-30T09:21:23.098860551Z TRACE quiche_apps::client] written 43 bytes from [::]:36963 to [fd00:cafe:cafe:100::100]:443
[2025-04-30T09:21:23.098864569Z TRACE quiche_apps::client] [::]:36963 -> [fd00:cafe:cafe:100::100]:443: done writing
[2025-04-30T09:21:23.099781282Z TRACE quiche_apps::client] got 1200 bytes from [fd00:cafe:cafe:100::100]:443 to [::]:36963
[2025-04-30T09:21:23.099789828Z TRACE quiche] e68335eb25deef9a0ee756f48eabd7086ec35189 rx pkt Short dcid=e68335eb25deef9a0ee756f48eabd7086ec35189 key_phase=false len=1179 pn=10 
[2025-04-30T09:21:23.099795799Z TRACE quiche] e68335eb25deef9a0ee756f48eabd7086ec35189 rx frm STREAM id=4 off=3464 len=1156 fin=false
[2025-04-30T09:21:23.099802461Z TRACE quiche_apps::client] [::]:36963: processed 1200 bytes
[2025-04-30T09:21:23.099805928Z TRACE quiche_apps::client] [::]:36963: recv() would block
[2025-04-30T09:21:23.099808162Z TRACE quiche_apps::client] done reading
[2025-04-30T09:21:23.099810667Z TRACE quiche::h3] e68335eb25deef9a0ee756f48eabd7086ec35189 stream id 4 is readable
[2025-04-30T09:21:23.099814845Z DEBUG quiche_apps::common] got 1156 bytes of response data on stream 4
[2025-04-30T09:21:23.099821617Z TRACE quiche] e68335eb25deef9a0ee756f48eabd7086ec35189 pmtud probe status false hs_con=true hs_sent=false cwnd_avail=13500 out_len=1350 left=1307
[2025-04-30T09:21:23.099824723Z TRACE quiche] e68335eb25deef9a0ee756f48eabd7086ec35189 tx pkt Short dcid=00000000000030040c307b3f9361829bea0d3b84 key_phase=false len=5 pn=17 
[2025-04-30T09:21:23.099827178Z TRACE quiche] e68335eb25deef9a0ee756f48eabd7086ec35189 tx frm ACK delay=4 blocks=[0..10] ecn_counts=None
[2025-04-30T09:21:23.099836776Z TRACE quiche::recovery::congestion::recovery] e68335eb25deef9a0ee756f48eabd7086ec35189 timer=none latest_rtt=34.641399ms srtt=37.092469ms min_rtt=29.531763ms rttvar=10.983696ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=0 app_limited=true congestion_recovery_start_time=None Rate { delivered: 1772, delivered_time: Instant { tv_sec: 839, tv_nsec: 750857297 }, first_sent_time: Instant { tv_sec: 839, tv_nsec: 750857297 }, end_of_app_limited: 13, last_sent_packet: 17, largest_acked: 7, rate_sample: RateSample { delivery_rate: 43872, is_app_limited: true, interval: 32.799687ms, delivered: 1439, prior_delivered: 333, prior_time: Some(Instant { tv_sec: 839, tv_nsec: 717813802 }), send_elapsed: 507.021µs, ack_elapsed: 32.799687ms, rtt: 32.292666ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 454944, last_update: Instant { tv_sec: 839, tv_nsec: 750857297 }, next_time: Instant { tv_sec: 839, tv_nsec: 750857297 }, 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-30T09:21:23.099868355Z TRACE quiche_apps::client] written 43 bytes from [::]:36963 to [fd00:cafe:cafe:100::100]:443
[2025-04-30T09:21:23.099872463Z TRACE quiche_apps::client] [::]:36963 -> [fd00:cafe:cafe:100::100]:443: done writing
[2025-04-30T09:21:23.100785719Z TRACE quiche_apps::client] got 1200 bytes from [fd00:cafe:cafe:100::100]:443 to [::]:36963
[2025-04-30T09:21:23.100794476Z TRACE quiche] e68335eb25deef9a0ee756f48eabd7086ec35189 rx pkt Short dcid=e68335eb25deef9a0ee756f48eabd7086ec35189 key_phase=false len=1179 pn=11 
[2025-04-30T09:21:23.100800657Z TRACE quiche] e68335eb25deef9a0ee756f48eabd7086ec35189 rx frm STREAM id=4 off=4620 len=1156 fin=false
[2025-04-30T09:21:23.100807550Z TRACE quiche_apps::client] [::]:36963: processed 1200 bytes
[2025-04-30T09:21:23.100811017Z TRACE quiche_apps::client] [::]:36963: recv() would block
[2025-04-30T09:21:23.100813301Z TRACE quiche_apps::client] done reading
[2025-04-30T09:21:23.100815786Z TRACE quiche::h3] e68335eb25deef9a0ee756f48eabd7086ec35189 stream id 4 is readable
[2025-04-30T09:21:23.100819904Z DEBUG quiche_apps::common] got 1156 bytes of response data on stream 4
[2025-04-30T09:21:23.100826866Z TRACE quiche] e68335eb25deef9a0ee756f48eabd7086ec35189 pmtud probe status false hs_con=true hs_sent=false cwnd_avail=13500 out_len=1350 left=1307
[2025-04-30T09:21:23.100830103Z TRACE quiche] e68335eb25deef9a0ee756f48eabd7086ec35189 tx pkt Short dcid=00000000000030040c307b3f9361829bea0d3b84 key_phase=false len=5 pn=18 
[2025-04-30T09:21:23.100832567Z TRACE quiche] e68335eb25deef9a0ee756f48eabd7086ec35189 tx frm ACK delay=4 blocks=[0..11] ecn_counts=None
[2025-04-30T09:21:23.100838448Z TRACE quiche::recovery::congestion::recovery] e68335eb25deef9a0ee756f48eabd7086ec35189 timer=none latest_rtt=34.641399ms srtt=37.092469ms min_rtt=29.531763ms rttvar=10.983696ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=0 app_limited=true congestion_recovery_start_time=None Rate { delivered: 1772, delivered_time: Instant { tv_sec: 839, tv_nsec: 750857297 }, first_sent_time: Instant { tv_sec: 839, tv_nsec: 750857297 }, end_of_app_limited: 13, last_sent_packet: 18, largest_acked: 7, rate_sample: RateSample { delivery_rate: 43872, is_app_limited: true, interval: 32.799687ms, delivered: 1439, prior_delivered: 333, prior_time: Some(Instant { tv_sec: 839, tv_nsec: 717813802 }), send_elapsed: 507.021µs, ack_elapsed: 32.799687ms, rtt: 32.292666ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 454944, last_update: Instant { tv_sec: 839, tv_nsec: 750857297 }, next_time: Instant { tv_sec: 839, tv_nsec: 750857297 }, 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-30T09:21:23.100866281Z TRACE quiche_apps::client] written 43 bytes from [::]:36963 to [fd00:cafe:cafe:100::100]:443
[2025-04-30T09:21:23.100870248Z TRACE quiche_apps::client] [::]:36963 -> [fd00:cafe:cafe:100::100]:443: done writing
[2025-04-30T09:21:23.101785017Z TRACE quiche_apps::client] got 1200 bytes from [fd00:cafe:cafe:100::100]:443 to [::]:36963
[2025-04-30T09:21:23.101791770Z TRACE quiche] e68335eb25deef9a0ee756f48eabd7086ec35189 rx pkt Short dcid=e68335eb25deef9a0ee756f48eabd7086ec35189 key_phase=false len=1179 pn=12 
[2025-04-30T09:21:23.101797140Z TRACE quiche] e68335eb25deef9a0ee756f48eabd7086ec35189 rx frm STREAM id=4 off=5776 len=1156 fin=false
[2025-04-30T09:21:23.101803061Z TRACE quiche_apps::client] [::]:36963: processed 1200 bytes
[2025-04-30T09:21:23.101806447Z TRACE quiche_apps::client] [::]:36963: recv() would block
[2025-04-30T09:21:23.101808682Z TRACE quiche_apps::client] done reading
[2025-04-30T09:21:23.101811056Z TRACE quiche::h3] e68335eb25deef9a0ee756f48eabd7086ec35189 stream id 4 is readable
[2025-04-30T09:21:23.101819853Z DEBUG quiche_apps::common] got 1156 bytes of response data on stream 4
[2025-04-30T09:21:23.101826525Z TRACE quiche] e68335eb25deef9a0ee756f48eabd7086ec35189 pmtud probe status false hs_con=true hs_sent=false cwnd_avail=13500 out_len=1350 left=1307
[2025-04-30T09:21:23.101829501Z TRACE quiche] e68335eb25deef9a0ee756f48eabd7086ec35189 tx pkt Short dcid=00000000000030040c307b3f9361829bea0d3b84 key_phase=false len=5 pn=19 
[2025-04-30T09:21:23.101831895Z TRACE quiche] e68335eb25deef9a0ee756f48eabd7086ec35189 tx frm ACK delay=4 blocks=[0..12] ecn_counts=None
[2025-04-30T09:21:23.101846543Z TRACE quiche::recovery::congestion::recovery] e68335eb25deef9a0ee756f48eabd7086ec35189 timer=none latest_rtt=34.641399ms srtt=37.092469ms min_rtt=29.531763ms rttvar=10.983696ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=0 app_limited=true congestion_recovery_start_time=None Rate { delivered: 1772, delivered_time: Instant { tv_sec: 839, tv_nsec: 750857297 }, first_sent_time: Instant { tv_sec: 839, tv_nsec: 750857297 }, end_of_app_limited: 13, last_sent_packet: 19, largest_acked: 7, rate_sample: RateSample { delivery_rate: 43872, is_app_limited: true, interval: 32.799687ms, delivered: 1439, prior_delivered: 333, prior_time: Some(Instant { tv_sec: 839, tv_nsec: 717813802 }), send_elapsed: 507.021µs, ack_elapsed: 32.799687ms, rtt: 32.292666ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 454944, last_update: Instant { tv_sec: 839, tv_nsec: 750857297 }, next_time: Instant { tv_sec: 839, tv_nsec: 750857297 }, 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-30T09:21:23.101873413Z TRACE quiche_apps::client] written 43 bytes from [::]:36963 to [fd00:cafe:cafe:100::100]:443
[2025-04-30T09:21:23.101877481Z TRACE quiche_apps::client] [::]:36963 -> [fd00:cafe:cafe:100::100]:443: done writing
[2025-04-30T09:21:23.102783314Z TRACE quiche_apps::client] got 1200 bytes from [fd00:cafe:cafe:100::100]:443 to [::]:36963
[2025-04-30T09:21:23.102790086Z TRACE quiche] e68335eb25deef9a0ee756f48eabd7086ec35189 rx pkt Short dcid=e68335eb25deef9a0ee756f48eabd7086ec35189 key_phase=false len=1179 pn=13 
[2025-04-30T09:21:23.102795526Z TRACE quiche] e68335eb25deef9a0ee756f48eabd7086ec35189 rx frm STREAM id=4 off=6932 len=1156 fin=false
[2025-04-30T09:21:23.102801337Z TRACE quiche_apps::client] [::]:36963: processed 1200 bytes
[2025-04-30T09:21:23.102804734Z TRACE quiche_apps::client] [::]:36963: recv() would block
[2025-04-30T09:21:23.102806998Z TRACE quiche_apps::client] done reading
[2025-04-30T09:21:23.102809533Z TRACE quiche::h3] e68335eb25deef9a0ee756f48eabd7086ec35189 stream id 4 is readable
[2025-04-30T09:21:23.102813580Z DEBUG quiche_apps::common] got 1156 bytes of response data on stream 4
[2025-04-30T09:21:23.102820173Z TRACE quiche] e68335eb25deef9a0ee756f48eabd7086ec35189 pmtud probe status false hs_con=true hs_sent=false cwnd_avail=13500 out_len=1350 left=1307
[2025-04-30T09:21:23.102823198Z TRACE quiche] e68335eb25deef9a0ee756f48eabd7086ec35189 tx pkt Short dcid=00000000000030040c307b3f9361829bea0d3b84 key_phase=false len=5 pn=20 
[2025-04-30T09:21:23.102825573Z TRACE quiche] e68335eb25deef9a0ee756f48eabd7086ec35189 tx frm ACK delay=3 blocks=[0..13] ecn_counts=None
[2025-04-30T09:21:23.102831193Z TRACE quiche::recovery::congestion::recovery] e68335eb25deef9a0ee756f48eabd7086ec35189 timer=none latest_rtt=34.641399ms srtt=37.092469ms min_rtt=29.531763ms rttvar=10.983696ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=0 app_limited=true congestion_recovery_start_time=None Rate { delivered: 1772, delivered_time: Instant { tv_sec: 839, tv_nsec: 750857297 }, first_sent_time: Instant { tv_sec: 839, tv_nsec: 750857297 }, end_of_app_limited: 13, last_sent_packet: 20, largest_acked: 7, rate_sample: RateSample { delivery_rate: 43872, is_app_limited: true, interval: 32.799687ms, delivered: 1439, prior_delivered: 333, prior_time: Some(Instant { tv_sec: 839, tv_nsec: 717813802 }), send_elapsed: 507.021µs, ack_elapsed: 32.799687ms, rtt: 32.292666ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 454944, last_update: Instant { tv_sec: 839, tv_nsec: 750857297 }, next_time: Instant { tv_sec: 839, tv_nsec: 750857297 }, 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-30T09:21:23.102861089Z TRACE quiche_apps::client] written 43 bytes from [::]:36963 to [fd00:cafe:cafe:100::100]:443
[2025-04-30T09:21:23.102864937Z TRACE quiche_apps::client] [::]:36963 -> [fd00:cafe:cafe:100::100]:443: done writing
[2025-04-30T09:21:23.103782912Z TRACE quiche_apps::client] got 1200 bytes from [fd00:cafe:cafe:100::100]:443 to [::]:36963
[2025-04-30T09:21:23.103789725Z TRACE quiche] e68335eb25deef9a0ee756f48eabd7086ec35189 rx pkt Short dcid=e68335eb25deef9a0ee756f48eabd7086ec35189 key_phase=false len=1179 pn=14 
[2025-04-30T09:21:23.103795065Z TRACE quiche] e68335eb25deef9a0ee756f48eabd7086ec35189 rx frm STREAM id=4 off=8088 len=1156 fin=false
[2025-04-30T09:21:23.103801026Z TRACE quiche_apps::client] [::]:36963: processed 1200 bytes
[2025-04-30T09:21:23.103804402Z TRACE quiche_apps::client] [::]:36963: recv() would block
[2025-04-30T09:21:23.103806637Z TRACE quiche_apps::client] done reading
[2025-04-30T09:21:23.103809041Z TRACE quiche::h3] e68335eb25deef9a0ee756f48eabd7086ec35189 stream id 4 is readable
[2025-04-30T09:21:23.103813018Z DEBUG quiche_apps::common] got 1156 bytes of response data on stream 4
[2025-04-30T09:21:23.103839408Z TRACE quiche] e68335eb25deef9a0ee756f48eabd7086ec35189 pmtud probe status false hs_con=true hs_sent=false cwnd_avail=13500 out_len=1350 left=1307
[2025-04-30T09:21:23.103842854Z TRACE quiche] e68335eb25deef9a0ee756f48eabd7086ec35189 tx pkt Short dcid=00000000000030040c307b3f9361829bea0d3b84 key_phase=false len=5 pn=21 
[2025-04-30T09:21:23.103845299Z TRACE quiche] e68335eb25deef9a0ee756f48eabd7086ec35189 tx frm ACK delay=6 blocks=[0..14] ecn_counts=None
[2025-04-30T09:21:23.103851040Z TRACE quiche::recovery::congestion::recovery] e68335eb25deef9a0ee756f48eabd7086ec35189 timer=none latest_rtt=34.641399ms srtt=37.092469ms min_rtt=29.531763ms rttvar=10.983696ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=0 app_limited=true congestion_recovery_start_time=None Rate { delivered: 1772, delivered_time: Instant { tv_sec: 839, tv_nsec: 750857297 }, first_sent_time: Instant { tv_sec: 839, tv_nsec: 750857297 }, end_of_app_limited: 13, last_sent_packet: 21, largest_acked: 7, rate_sample: RateSample { delivery_rate: 43872, is_app_limited: true, interval: 32.799687ms, delivered: 1439, prior_delivered: 333, prior_time: Some(Instant { tv_sec: 839, tv_nsec: 717813802 }), send_elapsed: 507.021µs, ack_elapsed: 32.799687ms, rtt: 32.292666ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 454944, last_update: Instant { tv_sec: 839, tv_nsec: 750857297 }, next_time: Instant { tv_sec: 839, tv_nsec: 750857297 }, 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-30T09:21:23.103877239Z TRACE quiche_apps::client] written 43 bytes from [::]:36963 to [fd00:cafe:cafe:100::100]:443
[2025-04-30T09:21:23.103881217Z TRACE quiche_apps::client] [::]:36963 -> [fd00:cafe:cafe:100::100]:443: done writing
[2025-04-30T09:21:23.104776279Z TRACE quiche_apps::client] got 1191 bytes from [fd00:cafe:cafe:100::100]:443 to [::]:36963
[2025-04-30T09:21:23.104783542Z TRACE quiche] e68335eb25deef9a0ee756f48eabd7086ec35189 rx pkt Short dcid=e68335eb25deef9a0ee756f48eabd7086ec35189 key_phase=false len=1170 pn=15 
[2025-04-30T09:21:23.104789113Z TRACE quiche] e68335eb25deef9a0ee756f48eabd7086ec35189 rx frm STREAM id=4 off=9244 len=1142 fin=false
[2025-04-30T09:21:23.104792259Z TRACE quiche] e68335eb25deef9a0ee756f48eabd7086ec35189 rx frm STREAM id=4 off=10386 len=0 fin=true
[2025-04-30T09:21:23.104798290Z TRACE quiche_apps::client] [::]:36963: processed 1191 bytes
[2025-04-30T09:21:23.104801757Z TRACE quiche_apps::client] [::]:36963: recv() would block
[2025-04-30T09:21:23.104804011Z TRACE quiche_apps::client] done reading
[2025-04-30T09:21:23.104806465Z TRACE quiche::h3] e68335eb25deef9a0ee756f48eabd7086ec35189 stream id 4 is readable
[2025-04-30T09:21:23.104811114Z DEBUG quiche_apps::common] got 1142 bytes of response data on stream 4
[2025-04-30T09:21:23.104813739Z DEBUG quiche_apps::common] 2/2 responses received
[2025-04-30T09:21:23.104815973Z INFO  quiche_apps::common] 2/2 response(s) received in 87.569194ms, closing...
[2025-04-30T09:21:23.104822165Z TRACE quiche] e68335eb25deef9a0ee756f48eabd7086ec35189 pmtud probe status false hs_con=true hs_sent=false cwnd_avail=13500 out_len=1350 left=1312
[2025-04-30T09:21:23.104825401Z TRACE quiche] e68335eb25deef9a0ee756f48eabd7086ec35189 tx pkt Short dcid=00000000000030040c307b3f9361829bea0d3b84 key_phase=false len=11 pn=22 
[2025-04-30T09:21:23.104827776Z TRACE quiche] e68335eb25deef9a0ee756f48eabd7086ec35189 tx frm APPLICATION_CLOSE err=100 reason=[6b, 74, 68, 78, 62, 79, 65]
[2025-04-30T09:21:23.104834478Z TRACE quiche::recovery::congestion::recovery] e68335eb25deef9a0ee756f48eabd7086ec35189 timer=106.012205ms latest_rtt=34.641399ms srtt=37.092469ms min_rtt=29.531763ms rttvar=10.983696ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=49 app_limited=true congestion_recovery_start_time=None Rate { delivered: 1772, delivered_time: Instant { tv_sec: 839, tv_nsec: 750857297 }, first_sent_time: Instant { tv_sec: 839, tv_nsec: 750857297 }, end_of_app_limited: 21, last_sent_packet: 22, largest_acked: 7, rate_sample: RateSample { delivery_rate: 43872, is_app_limited: true, interval: 32.799687ms, delivered: 1439, prior_delivered: 333, prior_time: Some(Instant { tv_sec: 839, tv_nsec: 717813802 }), send_elapsed: 507.021µs, ack_elapsed: 32.799687ms, rtt: 32.292666ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 454944, last_update: Instant { tv_sec: 839, tv_nsec: 764283549 }, next_time: Instant { tv_sec: 839, tv_nsec: 750857297 }, max_datagram_size: 1350, last_packet_size: None, iv: 107.706µ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-30T09:21:23.104860828Z TRACE quiche_apps::client] written 49 bytes from [::]:36963 to [fd00:cafe:cafe:100::100]:443
[2025-04-30T09:21:23.104864324Z TRACE quiche_apps::client] [::]:36963 -> [fd00:cafe:cafe:100::100]:443: done writing
[2025-04-30T09:21:23.126261175Z TRACE quiche_apps::client] got 41 bytes from [fd00:cafe:cafe:100::100]:443 to [::]:36963
[2025-04-30T09:21:23.126274220Z TRACE quiche_apps::client] [::]:36963: processed 41 bytes
[2025-04-30T09:21:23.126278728Z TRACE quiche_apps::client] [::]:36963: recv() would block
[2025-04-30T09:21:23.126281744Z TRACE quiche_apps::client] done reading
[2025-04-30T09:21:23.126286563Z TRACE quiche_apps::client] [::]:36963 -> [fd00:cafe:cafe:100::100]:443: done writing
[2025-04-30T09:21:23.348561972Z TRACE quiche_apps::client] timed out
[2025-04-30T09:21:23.348593431Z TRACE quiche] e68335eb25deef9a0ee756f48eabd7086ec35189 draining timeout expired
[2025-04-30T09:21:23.348641712Z TRACE quiche_apps::client] done reading
[2025-04-30T09:21:23.348646611Z INFO  quiche_apps::client] connection closed, recv=18 sent=23 lost=0 retrans=0 sent_bytes=2608 recv_bytes=18418 lost_bytes=0 [local_addr=[::]:36963 peer_addr=[fd00:cafe:cafe:100::100]:443 validation_state=Validated active=true recv=18 sent=23 lost=0 retrans=0 rtt=37.092469ms min_rtt=Some(29.531763ms) rttvar=10.983696ms cwnd=13500 sent_bytes=2608 recv_bytes=18418 lost_bytes=0 stream_retrans_bytes=0 pmtu=1350 delivery_rate=43872]