[2025-09-11T18:58:20.471166181Z TRACE mio::poll] registering event source with poller: token=Token(0), interests=READABLE
[2025-09-11T18:58:20.471458006Z INFO  quiche_apps::client] connecting to [fd00:cafe:cafe:100::100]:443 from [::]:45561 with scid 7abe682f4bc7038c41fa12a09737f13c85a5a74c
[2025-09-11T18:58:20.471497650Z TRACE quiche::tls] 7abe682f4bc7038c41fa12a09737f13c85a5a74c write message lvl=Initial len=266
[2025-09-11T18:58:20.471514592Z TRACE quiche] 7abe682f4bc7038c41fa12a09737f13c85a5a74c tx pkt Initial version=1 dcid=fffc76cd8fb6ee264b3a7770ee69700f scid=7abe682f4bc7038c41fa12a09737f13c85a5a74c len=270 pn=0 
[2025-09-11T18:58:20.471517758Z TRACE quiche] 7abe682f4bc7038c41fa12a09737f13c85a5a74c tx frm CRYPTO off=0 len=266
[2025-09-11T18:58:20.471531914Z TRACE quiche::recovery::congestion::recovery] 7abe682f4bc7038c41fa12a09737f13c85a5a74c timer=998.932645ms 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: 716, tv_nsec: 384637139 }, first_sent_time: Instant { tv_sec: 716, tv_nsec: 384637139 }, end_of_app_limited: 1, last_sent_packet: 0, largest_acked: 0, rate_sample: RateSample { bandwidth: 0.00 Kbps, is_app_limited: false, interval: 0ns, delivered: 0, prior_delivered: 0, prior_time: None, send_elapsed: 0ns, ack_elapsed: 0ns, rtt: 0ns } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 0, last_update: Instant { tv_sec: 716, tv_nsec: 384637139 }, next_time: Instant { tv_sec: 716, tv_nsec: 384637139 }, max_datagram_size: 1350, last_packet_size: None, iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } 
[2025-09-11T18:58:20.471589732Z TRACE quiche_apps::client] written 1200
[2025-09-11T18:58:20.512467112Z TRACE quiche_apps::client] got 1232 bytes from [fd00:cafe:cafe:100::100]:443 to [::]:45561
[2025-09-11T18:58:20.512491848Z TRACE quiche] 7abe682f4bc7038c41fa12a09737f13c85a5a74c rx pkt Initial version=1 dcid=7abe682f4bc7038c41fa12a09737f13c85a5a74c scid=6855a593450b76b2 token= len=117 pn=0 
[2025-09-11T18:58:20.512506395Z TRACE quiche] 7abe682f4bc7038c41fa12a09737f13c85a5a74c rx frm ACK delay=144 blocks=[0..0] ecn_counts=None
[2025-09-11T18:58:20.512512517Z TRACE quiche::recovery::congestion::recovery] 7abe682f4bc7038c41fa12a09737f13c85a5a74c packet newly acked 0
[2025-09-11T18:58:20.512518157Z TRACE quiche] 7abe682f4bc7038c41fa12a09737f13c85a5a74c rx frm CRYPTO off=0 len=90
[2025-09-11T18:58:20.512613555Z TRACE quiche::tls] 7abe682f4bc7038c41fa12a09737f13c85a5a74c set write secret lvl=Handshake
[2025-09-11T18:58:20.512624105Z TRACE quiche::tls] 7abe682f4bc7038c41fa12a09737f13c85a5a74c set read secret lvl=Handshake
[2025-09-11T18:58:20.512655143Z TRACE quiche] 7abe682f4bc7038c41fa12a09737f13c85a5a74c rx pkt Handshake version=1 dcid=7abe682f4bc7038c41fa12a09737f13c85a5a74c scid=6855a593450b76b2 len=1040 pn=1 
[2025-09-11T18:58:20.512660864Z TRACE quiche] 7abe682f4bc7038c41fa12a09737f13c85a5a74c rx frm CRYPTO off=0 len=711
[2025-09-11T18:58:20.512881346Z TRACE quiche::tls] 7abe682f4bc7038c41fa12a09737f13c85a5a74c write message lvl=Handshake len=36
[2025-09-11T18:58:20.512886665Z TRACE quiche::tls] 7abe682f4bc7038c41fa12a09737f13c85a5a74c set write secret lvl=OneRTT
[2025-09-11T18:58:20.512893899Z TRACE quiche::tls] 7abe682f4bc7038c41fa12a09737f13c85a5a74c set read secret lvl=OneRTT
[2025-09-11T18:58:20.512909288Z TRACE quiche] 7abe682f4bc7038c41fa12a09737f13c85a5a74c 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(fffc76cd8fb6ee264b3a7770ee69700f), max_idle_timeout: 30000, stateless_reset_token: Some(284235260940430158884652735572189259519), max_udp_payload_size: 65527, initial_max_data: 1572864, initial_max_stream_data_bidi_local: 0, initial_max_stream_data_bidi_remote: 1048576, initial_max_stream_data_uni: 12288, initial_max_streams_bidi: 100, initial_max_streams_uni: 3, ack_delay_exponent: 3, max_ack_delay: 25, disable_active_migration: false, active_conn_id_limit: 8, initial_source_connection_id: Some(6855a593450b76b2), retry_source_connection_id: None, max_datagram_frame_size: None, unknown_params: None }
[2025-09-11T18:58:20.512928103Z TRACE quiche] 7abe682f4bc7038c41fa12a09737f13c85a5a74c rx frm PADDING len=308
[2025-09-11T18:58:20.512942289Z TRACE quiche_apps::client] [::]:45561: processed 1232 bytes
[2025-09-11T18:58:20.512946798Z TRACE quiche_apps::client] [::]:45561: recv() would block
[2025-09-11T18:58:20.512949272Z TRACE quiche_apps::client] done reading
[2025-09-11T18:58:20.512969460Z TRACE quiche::h3] 7abe682f4bc7038c41fa12a09737f13c85a5a74c tx frm SETTINGS stream=2 len=18
[2025-09-11T18:58:20.512985370Z TRACE quiche::h3] 7abe682f4bc7038c41fa12a09737f13c85a5a74c tx frm GREASE stream=0 len=0
[2025-09-11T18:58:20.512991030Z TRACE quiche::h3] 7abe682f4bc7038c41fa12a09737f13c85a5a74c tx frm GREASE stream=0 len=18
[2025-09-11T18:58:20.512998133Z TRACE quiche::h3] 7abe682f4bc7038c41fa12a09737f13c85a5a74c tx frm HEADERS stream=0 len=30 fin=true
[2025-09-11T18:58:20.513003894Z DEBUG quiche_apps::common] Sent HTTP request [":method: GET", ":scheme: https", ":authority: server6", ":path: /akynlrakav", "user-agent: quiche"]
[2025-09-11T18:58:20.513061131Z TRACE quiche::h3] 7abe682f4bc7038c41fa12a09737f13c85a5a74c tx frm HEADERS stream=4 len=30 fin=true
[2025-09-11T18:58:20.513066531Z DEBUG quiche_apps::common] Sent HTTP request [":method: GET", ":scheme: https", ":authority: server6", ":path: /utkdkahkij", "user-agent: quiche"]
[2025-09-11T18:58:20.513110253Z TRACE quiche] 7abe682f4bc7038c41fa12a09737f13c85a5a74c tx pkt Initial version=1 dcid=6855a593450b76b2 scid=7abe682f4bc7038c41fa12a09737f13c85a5a74c len=6 pn=1 
[2025-09-11T18:58:20.513113769Z TRACE quiche] 7abe682f4bc7038c41fa12a09737f13c85a5a74c tx frm ACK delay=77 blocks=[0..0] ecn_counts=None
[2025-09-11T18:58:20.513123217Z TRACE quiche::recovery::congestion::recovery] 7abe682f4bc7038c41fa12a09737f13c85a5a74c timer=122.426024ms latest_rtt=41.021138ms srtt=41.021138ms min_rtt=41.021138ms rttvar=20.510569ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=0 app_limited=true congestion_recovery_start_time=None Rate { delivered: 333, delivered_time: Instant { tv_sec: 716, tv_nsec: 426079674 }, first_sent_time: Instant { tv_sec: 716, tv_nsec: 426079674 }, end_of_app_limited: 1, last_sent_packet: 1, largest_acked: 0, rate_sample: RateSample { bandwidth: 64.94 Kbps, is_app_limited: true, interval: 41.021138ms, delivered: 333, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 716, tv_nsec: 384637139 }), send_elapsed: 0ns, ack_elapsed: 41.021138ms, rtt: 41.021138ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 411373, last_update: Instant { tv_sec: 716, tv_nsec: 426079644 }, next_time: Instant { tv_sec: 716, tv_nsec: 426079674 }, max_datagram_size: 1350, last_packet_size: Some(0), iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } 
[2025-09-11T18:58:20.513143335Z TRACE quiche] 7abe682f4bc7038c41fa12a09737f13c85a5a74c tx pkt Handshake version=1 dcid=6855a593450b76b2 scid=7abe682f4bc7038c41fa12a09737f13c85a5a74c len=45 pn=2 
[2025-09-11T18:58:20.513146480Z TRACE quiche] 7abe682f4bc7038c41fa12a09737f13c85a5a74c tx frm ACK delay=60 blocks=[1..1] ecn_counts=None
[2025-09-11T18:58:20.513149075Z TRACE quiche] 7abe682f4bc7038c41fa12a09737f13c85a5a74c tx frm CRYPTO off=0 len=36
[2025-09-11T18:58:20.513154836Z TRACE quiche::recovery::congestion::recovery] 7abe682f4bc7038c41fa12a09737f13c85a5a74c timer=123.010826ms latest_rtt=41.021138ms srtt=41.021138ms min_rtt=41.021138ms rttvar=20.510569ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=99 app_limited=true congestion_recovery_start_time=None Rate { delivered: 333, delivered_time: Instant { tv_sec: 716, tv_nsec: 426079674 }, first_sent_time: Instant { tv_sec: 716, tv_nsec: 426079674 }, end_of_app_limited: 1, last_sent_packet: 2, largest_acked: 0, rate_sample: RateSample { bandwidth: 64.94 Kbps, is_app_limited: true, interval: 41.021138ms, delivered: 333, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 716, tv_nsec: 384637139 }), send_elapsed: 0ns, ack_elapsed: 41.021138ms, rtt: 41.021138ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 411373, last_update: Instant { tv_sec: 716, tv_nsec: 426274478 }, next_time: Instant { tv_sec: 716, tv_nsec: 426079674 }, max_datagram_size: 1350, last_packet_size: None, iv: 240.658µs, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } 
[2025-09-11T18:58:20.513170525Z TRACE quiche] 7abe682f4bc7038c41fa12a09737f13c85a5a74c dropped epoch 0 state
[2025-09-11T18:58:20.513183860Z TRACE quiche] 7abe682f4bc7038c41fa12a09737f13c85a5a74c tx pkt Short dcid=6855a593450b76b2 key_phase=false len=1164 pn=3 
[2025-09-11T18:58:20.513186595Z TRACE quiche] 7abe682f4bc7038c41fa12a09737f13c85a5a74c tx frm NEW_CONNECTION_ID seq_num=1 retire_prior_to=0 conn_id=[69, c8, 41, c6, fe, ee, f1, 85, cb, c0, 8e, 1e, 31, cb, dd, c6, 47, 54, 33, c4] reset_token=[81, 2b, 03, 42, 67, d6, 4e, 76, 6c, e1, 04, dd, 26, 55, ee, 85]
[2025-09-11T18:58:20.513193448Z TRACE quiche] 7abe682f4bc7038c41fa12a09737f13c85a5a74c tx frm NEW_CONNECTION_ID seq_num=2 retire_prior_to=0 conn_id=[fa, a9, 65, b0, 77, 53, 43, fa, 1f, 94, 01, a2, 99, 30, fd, 0a, 25, ee, 2a, e0] reset_token=[c3, c8, 0d, 5a, 76, 9a, ea, bf, a2, 06, 9b, 29, 09, aa, 80, f6]
[2025-09-11T18:58:20.513198818Z TRACE quiche] 7abe682f4bc7038c41fa12a09737f13c85a5a74c tx frm NEW_CONNECTION_ID seq_num=3 retire_prior_to=0 conn_id=[79, 0e, d2, 15, 97, 99, c8, 48, 21, d3, db, 0d, 9a, fa, 1d, cd, 33, b5, ec, 72] reset_token=[d4, c4, 9d, 77, 95, 9f, a3, b7, 49, 1b, 0c, 21, e8, 5f, d2, 4e]
[2025-09-11T18:58:20.513203978Z TRACE quiche] 7abe682f4bc7038c41fa12a09737f13c85a5a74c tx frm NEW_CONNECTION_ID seq_num=4 retire_prior_to=0 conn_id=[12, e8, b2, 7f, 9d, 97, 9c, f7, 92, 58, 3a, 70, 3f, 91, 5c, 22, 32, 3a, f3, 25] reset_token=[e1, a2, bc, b2, 93, 4e, c0, 0f, 2a, 20, db, 00, 6f, 7a, 02, d4]
[2025-09-11T18:58:20.513209027Z TRACE quiche] 7abe682f4bc7038c41fa12a09737f13c85a5a74c tx frm NEW_CONNECTION_ID seq_num=5 retire_prior_to=0 conn_id=[d2, eb, 6f, 35, fd, 8e, ce, 7b, 3a, 47, af, 92, 86, b9, c6, e8, 96, d7, 05, ce] reset_token=[68, 4b, 45, cd, bf, 4a, 19, eb, 9b, ab, d2, 26, 35, aa, 36, 9f]
[2025-09-11T18:58:20.513213986Z TRACE quiche] 7abe682f4bc7038c41fa12a09737f13c85a5a74c tx frm NEW_CONNECTION_ID seq_num=6 retire_prior_to=0 conn_id=[3d, 1a, 75, 66, 9e, 32, 13, 78, f4, eb, 91, 75, cc, 32, e8, 58, 13, 91, 70, 1c] reset_token=[c7, 71, 35, e4, a6, 72, 2e, 9b, 3f, b0, 33, 2b, 92, 24, d4, 10]
[2025-09-11T18:58:20.513218926Z TRACE quiche] 7abe682f4bc7038c41fa12a09737f13c85a5a74c tx frm NEW_CONNECTION_ID seq_num=7 retire_prior_to=0 conn_id=[91, 70, d3, 90, 89, 1b, 1f, 62, 81, 98, df, 0c, 13, db, 4d, 18, 31, 3d, 33, bf] reset_token=[a9, 0a, b8, 25, b9, 11, d3, 22, ec, c0, 30, f7, 4e, ff, fc, 57]
[2025-09-11T18:58:20.513223915Z TRACE quiche] 7abe682f4bc7038c41fa12a09737f13c85a5a74c tx frm STREAM id=2 off=0 len=19 fin=false
[2025-09-11T18:58:20.513226410Z TRACE quiche] 7abe682f4bc7038c41fa12a09737f13c85a5a74c tx frm PADDING len=860
[2025-09-11T18:58:20.513250725Z TRACE quiche::recovery::congestion::recovery] 7abe682f4bc7038c41fa12a09737f13c85a5a74c timer=122.914837ms latest_rtt=41.021138ms srtt=41.021138ms min_rtt=41.021138ms rttvar=20.510569ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=1289 app_limited=true congestion_recovery_start_time=None Rate { delivered: 333, delivered_time: Instant { tv_sec: 716, tv_nsec: 426079674 }, first_sent_time: Instant { tv_sec: 716, tv_nsec: 426079674 }, end_of_app_limited: 2, last_sent_packet: 3, largest_acked: 0, rate_sample: RateSample { bandwidth: 64.94 Kbps, is_app_limited: true, interval: 41.021138ms, delivered: 333, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 716, tv_nsec: 384637139 }), send_elapsed: 0ns, ack_elapsed: 41.021138ms, rtt: 41.021138ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 1190, rate: 411373, last_update: Instant { tv_sec: 716, tv_nsec: 426274478 }, next_time: Instant { tv_sec: 716, tv_nsec: 426515136 }, max_datagram_size: 1350, last_packet_size: Some(1190), iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } 
[2025-09-11T18:58:20.513290800Z TRACE quiche_apps::client] written 1350 bytes from [::]:45561 to [fd00:cafe:cafe:100::100]:443
[2025-09-11T18:58:20.513299065Z TRACE quiche] 7abe682f4bc7038c41fa12a09737f13c85a5a74c tx pkt Short dcid=6855a593450b76b2 key_phase=false len=6 pn=4 
[2025-09-11T18:58:20.513301640Z TRACE quiche] 7abe682f4bc7038c41fa12a09737f13c85a5a74c tx frm STREAM id=6 off=0 len=1 fin=false
[2025-09-11T18:58:20.513307170Z TRACE quiche::recovery::congestion::recovery] 7abe682f4bc7038c41fa12a09737f13c85a5a74c timer=122.858492ms latest_rtt=41.021138ms srtt=41.021138ms min_rtt=41.021138ms rttvar=20.510569ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=1321 app_limited=true congestion_recovery_start_time=None Rate { delivered: 333, delivered_time: Instant { tv_sec: 716, tv_nsec: 426079674 }, first_sent_time: Instant { tv_sec: 716, tv_nsec: 426079674 }, end_of_app_limited: 3, last_sent_packet: 4, largest_acked: 0, rate_sample: RateSample { bandwidth: 64.94 Kbps, is_app_limited: true, interval: 41.021138ms, delivered: 333, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 716, tv_nsec: 384637139 }), send_elapsed: 0ns, ack_elapsed: 41.021138ms, rtt: 41.021138ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 411373, last_update: Instant { tv_sec: 716, tv_nsec: 426466927 }, next_time: Instant { tv_sec: 716, tv_nsec: 426515136 }, max_datagram_size: 1350, last_packet_size: None, iv: 2.97054ms, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } 
[2025-09-11T18:58:20.513329422Z TRACE quiche_apps::client] written 32 bytes from [::]:45561 to [fd00:cafe:cafe:100::100]:443
[2025-09-11T18:58:20.513334702Z TRACE quiche] 7abe682f4bc7038c41fa12a09737f13c85a5a74c tx pkt Short dcid=6855a593450b76b2 key_phase=false len=6 pn=5 
[2025-09-11T18:58:20.513337176Z TRACE quiche] 7abe682f4bc7038c41fa12a09737f13c85a5a74c tx frm STREAM id=10 off=0 len=1 fin=false
[2025-09-11T18:58:20.513341715Z TRACE quiche::recovery::congestion::recovery] 7abe682f4bc7038c41fa12a09737f13c85a5a74c timer=122.823978ms latest_rtt=41.021138ms srtt=41.021138ms min_rtt=41.021138ms rttvar=20.510569ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=1353 app_limited=true congestion_recovery_start_time=None Rate { delivered: 333, delivered_time: Instant { tv_sec: 716, tv_nsec: 426079674 }, first_sent_time: Instant { tv_sec: 716, tv_nsec: 426079674 }, end_of_app_limited: 4, last_sent_packet: 5, largest_acked: 0, rate_sample: RateSample { bandwidth: 64.94 Kbps, is_app_limited: true, interval: 41.021138ms, delivered: 333, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 716, tv_nsec: 384637139 }), send_elapsed: 0ns, ack_elapsed: 41.021138ms, rtt: 41.021138ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 32, rate: 411373, last_update: Instant { tv_sec: 716, tv_nsec: 426466927 }, next_time: Instant { tv_sec: 716, tv_nsec: 429485676 }, 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-09-11T18:58:20.513365690Z TRACE quiche_apps::client] written 32 bytes from [::]:45561 to [fd00:cafe:cafe:100::100]:443
[2025-09-11T18:58:20.513370960Z TRACE quiche] 7abe682f4bc7038c41fa12a09737f13c85a5a74c tx pkt Short dcid=6855a593450b76b2 key_phase=false len=73 pn=6 
[2025-09-11T18:58:20.513373394Z TRACE quiche] 7abe682f4bc7038c41fa12a09737f13c85a5a74c tx frm STREAM id=0 off=0 len=68 fin=true
[2025-09-11T18:58:20.513378243Z TRACE quiche::recovery::congestion::recovery] 7abe682f4bc7038c41fa12a09737f13c85a5a74c timer=122.787449ms latest_rtt=41.021138ms srtt=41.021138ms min_rtt=41.021138ms rttvar=20.510569ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=1452 app_limited=true congestion_recovery_start_time=None Rate { delivered: 333, delivered_time: Instant { tv_sec: 716, tv_nsec: 426079674 }, first_sent_time: Instant { tv_sec: 716, tv_nsec: 426079674 }, end_of_app_limited: 5, last_sent_packet: 6, largest_acked: 0, rate_sample: RateSample { bandwidth: 64.94 Kbps, is_app_limited: true, interval: 41.021138ms, delivered: 333, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 716, tv_nsec: 384637139 }), send_elapsed: 0ns, ack_elapsed: 41.021138ms, rtt: 41.021138ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 411373, last_update: Instant { tv_sec: 716, tv_nsec: 426540695 }, next_time: Instant { tv_sec: 716, tv_nsec: 429485676 }, max_datagram_size: 1350, last_packet_size: None, iv: 318.446µs, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } 
[2025-09-11T18:58:20.513394854Z TRACE quiche_apps::client] written 99 bytes from [::]:45561 to [fd00:cafe:cafe:100::100]:443
[2025-09-11T18:58:20.513399332Z TRACE quiche] 7abe682f4bc7038c41fa12a09737f13c85a5a74c tx pkt Short dcid=6855a593450b76b2 key_phase=false len=37 pn=7 
[2025-09-11T18:58:20.513401767Z TRACE quiche] 7abe682f4bc7038c41fa12a09737f13c85a5a74c tx frm STREAM id=4 off=0 len=32 fin=true
[2025-09-11T18:58:20.513406406Z TRACE quiche::recovery::congestion::recovery] 7abe682f4bc7038c41fa12a09737f13c85a5a74c timer=122.759297ms latest_rtt=41.021138ms srtt=41.021138ms min_rtt=41.021138ms rttvar=20.510569ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=1515 app_limited=true congestion_recovery_start_time=None Rate { delivered: 333, delivered_time: Instant { tv_sec: 716, tv_nsec: 426079674 }, first_sent_time: Instant { tv_sec: 716, tv_nsec: 426079674 }, end_of_app_limited: 6, last_sent_packet: 7, largest_acked: 0, rate_sample: RateSample { bandwidth: 64.94 Kbps, is_app_limited: true, interval: 41.021138ms, delivered: 333, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 716, tv_nsec: 384637139 }), send_elapsed: 0ns, ack_elapsed: 41.021138ms, rtt: 41.021138ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 63, rate: 411373, last_update: Instant { tv_sec: 716, tv_nsec: 426540695 }, next_time: Instant { tv_sec: 716, tv_nsec: 429804122 }, max_datagram_size: 1350, last_packet_size: Some(63), iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } 
[2025-09-11T18:58:20.513424730Z TRACE quiche_apps::client] written 63 bytes from [::]:45561 to [fd00:cafe:cafe:100::100]:443
[2025-09-11T18:58:20.513428106Z TRACE quiche_apps::client] [::]:45561 -> [fd00:cafe:cafe:100::100]:443: done writing
[2025-09-11T18:58:20.546537367Z TRACE quiche_apps::client] got 583 bytes from [fd00:cafe:cafe:100::100]:443 to [::]:45561
[2025-09-11T18:58:20.546552976Z TRACE quiche] 7abe682f4bc7038c41fa12a09737f13c85a5a74c rx pkt Short dcid=7abe682f4bc7038c41fa12a09737f13c85a5a74c key_phase=false len=562 pn=2 
[2025-09-11T18:58:20.546562664Z TRACE quiche] 7abe682f4bc7038c41fa12a09737f13c85a5a74c rx frm CRYPTO off=0 len=540
[2025-09-11T18:58:20.546588312Z TRACE quiche] 7abe682f4bc7038c41fa12a09737f13c85a5a74c rx frm HANDSHAKE_DONE
[2025-09-11T18:58:20.546593501Z TRACE quiche] 7abe682f4bc7038c41fa12a09737f13c85a5a74c dropped epoch 1 state
[2025-09-11T18:58:20.546603159Z TRACE quiche_apps::client] [::]:45561: processed 583 bytes
[2025-09-11T18:58:20.546607628Z TRACE quiche_apps::client] [::]:45561: recv() would block
[2025-09-11T18:58:20.546610553Z TRACE quiche_apps::client] done reading
[2025-09-11T18:58:20.546620812Z TRACE quiche] 7abe682f4bc7038c41fa12a09737f13c85a5a74c tx pkt Short dcid=6855a593450b76b2 key_phase=false len=5 pn=8 
[2025-09-11T18:58:20.546624169Z TRACE quiche] 7abe682f4bc7038c41fa12a09737f13c85a5a74c tx frm ACK delay=8 blocks=[2..2] ecn_counts=None
[2025-09-11T18:58:20.546632414Z TRACE quiche::recovery::congestion::recovery] 7abe682f4bc7038c41fa12a09737f13c85a5a74c timer=114.828038ms latest_rtt=41.021138ms srtt=41.021138ms min_rtt=41.021138ms rttvar=20.510569ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=1416 app_limited=true congestion_recovery_start_time=None Rate { delivered: 333, delivered_time: Instant { tv_sec: 716, tv_nsec: 426079674 }, first_sent_time: Instant { tv_sec: 716, tv_nsec: 426079674 }, end_of_app_limited: 6, last_sent_packet: 8, largest_acked: 0, rate_sample: RateSample { bandwidth: 64.94 Kbps, is_app_limited: true, interval: 41.021138ms, delivered: 333, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 716, tv_nsec: 384637139 }), send_elapsed: 0ns, ack_elapsed: 41.021138ms, rtt: 41.021138ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 411373, last_update: Instant { tv_sec: 716, tv_nsec: 459787662 }, next_time: Instant { tv_sec: 716, tv_nsec: 459787662 }, max_datagram_size: 1350, last_packet_size: Some(0), iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } 
[2025-09-11T18:58:20.546671948Z TRACE quiche_apps::client] written 31 bytes from [::]:45561 to [fd00:cafe:cafe:100::100]:443
[2025-09-11T18:58:20.546677117Z TRACE quiche_apps::client] [::]:45561 -> [fd00:cafe:cafe:100::100]:443: done writing
[2025-09-11T18:58:20.546761595Z TRACE quiche_apps::client] got 326 bytes from [fd00:cafe:cafe:100::100]:443 to [::]:45561
[2025-09-11T18:58:20.546767186Z TRACE quiche] 7abe682f4bc7038c41fa12a09737f13c85a5a74c dropped invalid packet
[2025-09-11T18:58:20.546770552Z TRACE quiche_apps::client] [::]:45561: processed 326 bytes
[2025-09-11T18:58:20.546774319Z TRACE quiche_apps::client] [::]:45561: recv() would block
[2025-09-11T18:58:20.546777024Z TRACE quiche_apps::client] done reading
[2025-09-11T18:58:20.546781543Z TRACE quiche_apps::client] [::]:45561 -> [fd00:cafe:cafe:100::100]:443: done writing
[2025-09-11T18:58:20.546866812Z TRACE quiche_apps::client] got 51 bytes from [fd00:cafe:cafe:100::100]:443 to [::]:45561
[2025-09-11T18:58:20.546874746Z TRACE quiche] 7abe682f4bc7038c41fa12a09737f13c85a5a74c rx pkt Short dcid=7abe682f4bc7038c41fa12a09737f13c85a5a74c key_phase=false len=30 pn=5 
[2025-09-11T18:58:20.546881379Z TRACE quiche] 7abe682f4bc7038c41fa12a09737f13c85a5a74c rx frm ACK delay=15 blocks=[3..7] ecn_counts=None
[2025-09-11T18:58:20.546885537Z TRACE quiche::recovery::congestion::recovery] 7abe682f4bc7038c41fa12a09737f13c85a5a74c packet newly acked 3
[2025-09-11T18:58:20.546890035Z TRACE quiche::recovery::congestion::recovery] 7abe682f4bc7038c41fa12a09737f13c85a5a74c packet newly acked 4
[2025-09-11T18:58:20.546899523Z TRACE quiche::recovery::congestion::recovery] 7abe682f4bc7038c41fa12a09737f13c85a5a74c packet newly acked 5
[2025-09-11T18:58:20.546902428Z TRACE quiche::recovery::congestion::recovery] 7abe682f4bc7038c41fa12a09737f13c85a5a74c packet newly acked 6
[2025-09-11T18:58:20.546905604Z TRACE quiche::recovery::congestion::recovery] 7abe682f4bc7038c41fa12a09737f13c85a5a74c packet newly acked 7
[2025-09-11T18:58:20.546910152Z TRACE quiche] 7abe682f4bc7038c41fa12a09737f13c85a5a74c rx frm STREAM id=0 off=0 len=0 fin=true
[2025-09-11T18:58:20.546914200Z TRACE quiche] 7abe682f4bc7038c41fa12a09737f13c85a5a74c rx frm STREAM id=4 off=0 len=0 fin=true
[2025-09-11T18:58:20.546931072Z TRACE quiche_apps::client] [::]:45561: processed 51 bytes
[2025-09-11T18:58:20.546935340Z TRACE quiche_apps::client] [::]:45561: recv() would block
[2025-09-11T18:58:20.546938055Z TRACE quiche_apps::client] done reading
[2025-09-11T18:58:20.546940900Z TRACE quiche::h3] 7abe682f4bc7038c41fa12a09737f13c85a5a74c stream id 0 is readable
[2025-09-11T18:58:20.546947352Z TRACE quiche::h3::stream] 7abe682f4bc7038c41fa12a09737f13c85a5a74c read 0 bytes on stream 0
[2025-09-11T18:58:20.546951279Z TRACE quiche::h3] 7abe682f4bc7038c41fa12a09737f13c85a5a74c stream id 4 is readable
[2025-09-11T18:58:20.546955357Z TRACE quiche::h3::stream] 7abe682f4bc7038c41fa12a09737f13c85a5a74c read 0 bytes on stream 4
[2025-09-11T18:58:20.546958673Z DEBUG quiche_apps::common] 1/2 responses received
[2025-09-11T18:58:20.546961689Z DEBUG quiche_apps::common] 2/2 responses received
[2025-09-11T18:58:20.546964394Z INFO  quiche_apps::common] 2/2 response(s) received in 75.369132ms, closing...
[2025-09-11T18:58:20.546972309Z TRACE quiche] 7abe682f4bc7038c41fa12a09737f13c85a5a74c tx pkt Short dcid=6855a593450b76b2 key_phase=false len=11 pn=9 
[2025-09-11T18:58:20.546975405Z TRACE quiche] 7abe682f4bc7038c41fa12a09737f13c85a5a74c tx frm APPLICATION_CLOSE err=100 reason=[6b, 74, 68, 78, 62, 79, 65]
[2025-09-11T18:58:20.546983259Z TRACE quiche::recovery::congestion::recovery] 7abe682f4bc7038c41fa12a09737f13c85a5a74c timer=136.970323ms latest_rtt=30.241722ms srtt=39.67371ms min_rtt=30.241722ms rttvar=18.07778ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=37 app_limited=true congestion_recovery_start_time=None Rate { delivered: 1749, delivered_time: Instant { tv_sec: 716, tv_nsec: 459787662 }, first_sent_time: Instant { tv_sec: 716, tv_nsec: 459787662 }, end_of_app_limited: 8, last_sent_packet: 9, largest_acked: 7, rate_sample: RateSample { bandwidth: 333.50 Kbps, is_app_limited: true, interval: 33.96617ms, delivered: 1416, prior_delivered: 333, prior_time: Some(Instant { tv_sec: 716, tv_nsec: 426079674 }), send_elapsed: 3.724448ms, ack_elapsed: 33.96617ms, rtt: 30.241722ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 425344, last_update: Instant { tv_sec: 716, tv_nsec: 460141112 }, next_time: Instant { tv_sec: 716, tv_nsec: 459787662 }, max_datagram_size: 1350, last_packet_size: None, iv: 86.988µs, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } 
[2025-09-11T18:58:20.547017343Z TRACE quiche_apps::client] written 37 bytes from [::]:45561 to [fd00:cafe:cafe:100::100]:443
[2025-09-11T18:58:20.547021540Z TRACE quiche_apps::client] [::]:45561 -> [fd00:cafe:cafe:100::100]:443: done writing
[2025-09-11T18:58:20.883402622Z TRACE quiche_apps::client] timed out
[2025-09-11T18:58:20.883423501Z TRACE quiche] 7abe682f4bc7038c41fa12a09737f13c85a5a74c draining timeout expired
[2025-09-11T18:58:20.883460530Z TRACE quiche_apps::client] done reading
[2025-09-11T18:58:20.883467112Z INFO  quiche_apps::client] connection closed, recv=4 sent=10 lost=0 retrans=0 sent_bytes=1977 recv_bytes=1866 lost_bytes=0 [local_addr=[::]:45561 peer_addr=[fd00:cafe:cafe:100::100]:443 validation_state=Validated active=true recv=4 sent=10 lost=0 retrans=0 rtt=39.67371ms min_rtt=Some(30.241722ms) rttvar=18.07778ms cwnd=13500 sent_bytes=1977 recv_bytes=1866 lost_bytes=0 stream_retrans_bytes=0 pmtu=1350 delivery_rate=41688]