[2025-09-12T06:35:42.798154954Z TRACE mio::poll] registering event source with poller: token=Token(0), interests=READABLE
[2025-09-12T06:35:42.798472367Z INFO  quiche_apps::client] connecting to [fd00:cafe:cafe:100::100]:443 from [::]:56481 with scid fe592c901da213fc87b8e71a723b935abf2f92db
[2025-09-12T06:35:42.798515327Z TRACE quiche::tls] fe592c901da213fc87b8e71a723b935abf2f92db write message lvl=Initial len=267
[2025-09-12T06:35:42.798532169Z TRACE quiche] fe592c901da213fc87b8e71a723b935abf2f92db tx pkt Initial version=1 dcid=b2eb16446b094c6f373164d6ec2ca2eb scid=fe592c901da213fc87b8e71a723b935abf2f92db len=271 pn=0 
[2025-09-12T06:35:42.798535425Z TRACE quiche] fe592c901da213fc87b8e71a723b935abf2f92db tx frm CRYPTO off=0 len=267
[2025-09-12T06:35:42.798549210Z TRACE quiche::recovery::congestion::recovery] fe592c901da213fc87b8e71a723b935abf2f92db timer=998.932053ms latest_rtt=0ns srtt=333ms min_rtt=333ms rttvar=166.5ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=334 app_limited=true congestion_recovery_start_time=None Rate { delivered: 0, delivered_time: Instant { tv_sec: 1061, tv_nsec: 588210313 }, first_sent_time: Instant { tv_sec: 1061, tv_nsec: 588210313 }, 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: 1061, tv_nsec: 588210313 }, next_time: Instant { tv_sec: 1061, tv_nsec: 588210313 }, 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-12T06:35:42.798593043Z TRACE quiche_apps::client] written 1200
[2025-09-12T06:35:42.839303590Z TRACE quiche_apps::client] got 1232 bytes from [fd00:cafe:cafe:100::100]:443 to [::]:56481
[2025-09-12T06:35:42.839320591Z TRACE quiche] fe592c901da213fc87b8e71a723b935abf2f92db rx pkt Initial version=1 dcid=fe592c901da213fc87b8e71a723b935abf2f92db scid=7c193bc9be78d2a4 token= len=117 pn=0 
[2025-09-12T06:35:42.839332123Z TRACE quiche] fe592c901da213fc87b8e71a723b935abf2f92db rx frm ACK delay=128 blocks=[0..0] ecn_counts=None
[2025-09-12T06:35:42.839337834Z TRACE quiche::recovery::congestion::recovery] fe592c901da213fc87b8e71a723b935abf2f92db packet newly acked 0
[2025-09-12T06:35:42.839343334Z TRACE quiche] fe592c901da213fc87b8e71a723b935abf2f92db rx frm CRYPTO off=0 len=90
[2025-09-12T06:35:42.839442379Z TRACE quiche::tls] fe592c901da213fc87b8e71a723b935abf2f92db set write secret lvl=Handshake
[2025-09-12T06:35:42.839452598Z TRACE quiche::tls] fe592c901da213fc87b8e71a723b935abf2f92db set read secret lvl=Handshake
[2025-09-12T06:35:42.839479939Z TRACE quiche] fe592c901da213fc87b8e71a723b935abf2f92db rx pkt Handshake version=1 dcid=fe592c901da213fc87b8e71a723b935abf2f92db scid=7c193bc9be78d2a4 len=1040 pn=1 
[2025-09-12T06:35:42.839486321Z TRACE quiche] fe592c901da213fc87b8e71a723b935abf2f92db rx frm CRYPTO off=0 len=761
[2025-09-12T06:35:42.839705220Z TRACE quiche::tls] fe592c901da213fc87b8e71a723b935abf2f92db write message lvl=Handshake len=36
[2025-09-12T06:35:42.839709999Z TRACE quiche::tls] fe592c901da213fc87b8e71a723b935abf2f92db set write secret lvl=OneRTT
[2025-09-12T06:35:42.839718245Z TRACE quiche::tls] fe592c901da213fc87b8e71a723b935abf2f92db set read secret lvl=OneRTT
[2025-09-12T06:35:42.839736318Z TRACE quiche] fe592c901da213fc87b8e71a723b935abf2f92db 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(b2eb16446b094c6f373164d6ec2ca2eb), max_idle_timeout: 30000, stateless_reset_token: Some(31597882467464835426316549667852281895), 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(7c193bc9be78d2a4), retry_source_connection_id: None, max_datagram_frame_size: None, unknown_params: None }
[2025-09-12T06:35:42.839756316Z TRACE quiche] fe592c901da213fc87b8e71a723b935abf2f92db rx frm PADDING len=258
[2025-09-12T06:35:42.839772907Z TRACE quiche_apps::client] [::]:56481: processed 1232 bytes
[2025-09-12T06:35:42.839778437Z TRACE quiche_apps::client] [::]:56481: recv() would block
[2025-09-12T06:35:42.839781372Z TRACE quiche_apps::client] done reading
[2025-09-12T06:35:42.839797142Z TRACE quiche::h3] fe592c901da213fc87b8e71a723b935abf2f92db tx frm SETTINGS stream=2 len=18
[2025-09-12T06:35:42.839814865Z TRACE quiche::h3] fe592c901da213fc87b8e71a723b935abf2f92db tx frm GREASE stream=0 len=0
[2025-09-12T06:35:42.839822099Z TRACE quiche::h3] fe592c901da213fc87b8e71a723b935abf2f92db tx frm GREASE stream=0 len=18
[2025-09-12T06:35:42.839830675Z TRACE quiche::h3] fe592c901da213fc87b8e71a723b935abf2f92db tx frm HEADERS stream=0 len=31 fin=true
[2025-09-12T06:35:42.839837658Z DEBUG quiche_apps::common] Sent HTTP request [":method: GET", ":scheme: https", ":authority: server46", ":path: /bguqzsydsj", "user-agent: quiche"]
[2025-09-12T06:35:42.839905945Z TRACE quiche] fe592c901da213fc87b8e71a723b935abf2f92db tx pkt Initial version=1 dcid=7c193bc9be78d2a4 scid=fe592c901da213fc87b8e71a723b935abf2f92db len=6 pn=1 
[2025-09-12T06:35:42.839910614Z TRACE quiche] fe592c901da213fc87b8e71a723b935abf2f92db tx frm ACK delay=73 blocks=[0..0] ecn_counts=None
[2025-09-12T06:35:42.839921284Z TRACE quiche::recovery::congestion::recovery] fe592c901da213fc87b8e71a723b935abf2f92db timer=121.903928ms latest_rtt=40.835972ms srtt=40.835972ms min_rtt=40.835972ms rttvar=20.417986ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=0 app_limited=true congestion_recovery_start_time=None Rate { delivered: 334, delivered_time: Instant { tv_sec: 1061, tv_nsec: 629463164 }, first_sent_time: Instant { tv_sec: 1061, tv_nsec: 629463164 }, end_of_app_limited: 1, last_sent_packet: 1, largest_acked: 0, rate_sample: RateSample { bandwidth: 65.43 Kbps, is_app_limited: true, interval: 40.835972ms, delivered: 334, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 1061, tv_nsec: 588210313 }), send_elapsed: 0ns, ack_elapsed: 40.835972ms, rtt: 40.835972ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 413238, last_update: Instant { tv_sec: 1061, tv_nsec: 629463124 }, next_time: Instant { tv_sec: 1061, tv_nsec: 629463164 }, 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-12T06:35:42.839943636Z TRACE quiche] fe592c901da213fc87b8e71a723b935abf2f92db tx pkt Handshake version=1 dcid=7c193bc9be78d2a4 scid=fe592c901da213fc87b8e71a723b935abf2f92db len=45 pn=2 
[2025-09-12T06:35:42.839947212Z TRACE quiche] fe592c901da213fc87b8e71a723b935abf2f92db tx frm ACK delay=57 blocks=[1..1] ecn_counts=None
[2025-09-12T06:35:42.839950499Z TRACE quiche] fe592c901da213fc87b8e71a723b935abf2f92db tx frm CRYPTO off=0 len=36
[2025-09-12T06:35:42.839957501Z TRACE quiche::recovery::congestion::recovery] fe592c901da213fc87b8e71a723b935abf2f92db timer=122.448194ms latest_rtt=40.835972ms srtt=40.835972ms min_rtt=40.835972ms rttvar=20.417986ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=99 app_limited=true congestion_recovery_start_time=None Rate { delivered: 334, delivered_time: Instant { tv_sec: 1061, tv_nsec: 629463164 }, first_sent_time: Instant { tv_sec: 1061, tv_nsec: 629463164 }, end_of_app_limited: 1, last_sent_packet: 2, largest_acked: 0, rate_sample: RateSample { bandwidth: 65.43 Kbps, is_app_limited: true, interval: 40.835972ms, delivered: 334, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 1061, tv_nsec: 588210313 }), send_elapsed: 0ns, ack_elapsed: 40.835972ms, rtt: 40.835972ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 413238, last_update: Instant { tv_sec: 1061, tv_nsec: 629626629 }, next_time: Instant { tv_sec: 1061, tv_nsec: 629463164 }, max_datagram_size: 1350, last_packet_size: None, iv: 239.571µ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-12T06:35:42.839976547Z TRACE quiche] fe592c901da213fc87b8e71a723b935abf2f92db dropped epoch 0 state
[2025-09-12T06:35:42.839992437Z TRACE quiche] fe592c901da213fc87b8e71a723b935abf2f92db tx pkt Short dcid=7c193bc9be78d2a4 key_phase=false len=1164 pn=3 
[2025-09-12T06:35:42.839995713Z TRACE quiche] fe592c901da213fc87b8e71a723b935abf2f92db tx frm NEW_CONNECTION_ID seq_num=1 retire_prior_to=0 conn_id=[b0, 96, 05, d1, 35, b5, dd, 69, 33, f7, 4d, fb, 81, 61, ae, 47, 13, c9, 41, d2] reset_token=[3a, ea, 3d, 53, bb, 22, 39, 40, cb, 53, b4, b3, bf, 43, 0f, 9c]
[2025-09-12T06:35:42.840003758Z TRACE quiche] fe592c901da213fc87b8e71a723b935abf2f92db tx frm NEW_CONNECTION_ID seq_num=2 retire_prior_to=0 conn_id=[5f, 1d, 7a, cf, 17, 99, e4, 33, d1, cd, c5, 89, b6, b6, ef, 93, 0e, 82, 09, ab] reset_token=[7d, 5b, 4c, d3, ea, 97, 87, 7a, 85, 48, aa, f8, 7e, 55, e6, 06]
[2025-09-12T06:35:42.840010310Z TRACE quiche] fe592c901da213fc87b8e71a723b935abf2f92db tx frm NEW_CONNECTION_ID seq_num=3 retire_prior_to=0 conn_id=[42, 67, 5b, 53, cb, 75, 1c, c1, 20, f4, 10, 78, ca, 3d, 94, 4a, 58, 39, 52, 84] reset_token=[3e, d4, 50, d0, fe, ce, 82, ad, ee, 0c, 65, 03, e0, 60, e7, 8b]
[2025-09-12T06:35:42.840016462Z TRACE quiche] fe592c901da213fc87b8e71a723b935abf2f92db tx frm NEW_CONNECTION_ID seq_num=4 retire_prior_to=0 conn_id=[0e, 43, 62, 0a, 0a, a0, ac, 45, 0f, 4b, c7, 12, 85, e1, 77, 7b, 57, 4a, 92, 53] reset_token=[b3, e4, e8, fc, 64, 8a, 1c, 3d, 57, 5c, 0e, 2b, d8, c1, 1e, 10]
[2025-09-12T06:35:42.840022844Z TRACE quiche] fe592c901da213fc87b8e71a723b935abf2f92db tx frm NEW_CONNECTION_ID seq_num=5 retire_prior_to=0 conn_id=[61, 23, a4, 79, e3, 82, 57, a7, c0, 66, aa, 18, 6d, 46, 4f, aa, 19, 73, af, 9f] reset_token=[2b, e1, 1e, 7c, 0b, 0d, 5e, 7e, 6f, 1c, bf, d6, be, ab, c8, 79]
[2025-09-12T06:35:42.840028945Z TRACE quiche] fe592c901da213fc87b8e71a723b935abf2f92db tx frm NEW_CONNECTION_ID seq_num=6 retire_prior_to=0 conn_id=[35, 5b, 66, 7d, 5f, ac, 3d, a8, 15, 58, 13, bb, 84, d7, d8, d8, ac, 01, 69, b9] reset_token=[c5, c3, 28, 43, de, 96, b8, a5, 99, 20, 55, 8d, 49, 08, 90, ae]
[2025-09-12T06:35:42.840035046Z TRACE quiche] fe592c901da213fc87b8e71a723b935abf2f92db tx frm NEW_CONNECTION_ID seq_num=7 retire_prior_to=0 conn_id=[90, 67, 68, 60, 84, 06, 7d, c6, ff, bb, f0, a2, 01, db, c4, 1f, 0b, 7e, 71, 33] reset_token=[ac, 11, 33, fe, 28, 51, 66, 2d, 85, 16, 91, 85, 22, 81, 37, 76]
[2025-09-12T06:35:42.840041218Z TRACE quiche] fe592c901da213fc87b8e71a723b935abf2f92db tx frm STREAM id=2 off=0 len=19 fin=false
[2025-09-12T06:35:42.840044444Z TRACE quiche] fe592c901da213fc87b8e71a723b935abf2f92db tx frm PADDING len=860
[2025-09-12T06:35:42.840072076Z TRACE quiche::recovery::congestion::recovery] fe592c901da213fc87b8e71a723b935abf2f92db timer=122.33345ms latest_rtt=40.835972ms srtt=40.835972ms min_rtt=40.835972ms rttvar=20.417986ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=1289 app_limited=true congestion_recovery_start_time=None Rate { delivered: 334, delivered_time: Instant { tv_sec: 1061, tv_nsec: 629463164 }, first_sent_time: Instant { tv_sec: 1061, tv_nsec: 629463164 }, end_of_app_limited: 2, last_sent_packet: 3, largest_acked: 0, rate_sample: RateSample { bandwidth: 65.43 Kbps, is_app_limited: true, interval: 40.835972ms, delivered: 334, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 1061, tv_nsec: 588210313 }), send_elapsed: 0ns, ack_elapsed: 40.835972ms, rtt: 40.835972ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 1190, rate: 413238, last_update: Instant { tv_sec: 1061, tv_nsec: 629626629 }, next_time: Instant { tv_sec: 1061, tv_nsec: 629866200 }, 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-12T06:35:42.840113894Z TRACE quiche_apps::client] written 1350 bytes from [::]:56481 to [fd00:cafe:cafe:100::100]:443
[2025-09-12T06:35:42.840123251Z TRACE quiche] fe592c901da213fc87b8e71a723b935abf2f92db tx pkt Short dcid=7c193bc9be78d2a4 key_phase=false len=6 pn=4 
[2025-09-12T06:35:42.840126497Z TRACE quiche] fe592c901da213fc87b8e71a723b935abf2f92db tx frm STREAM id=6 off=0 len=1 fin=false
[2025-09-12T06:35:42.840133040Z TRACE quiche::recovery::congestion::recovery] fe592c901da213fc87b8e71a723b935abf2f92db timer=122.272707ms latest_rtt=40.835972ms srtt=40.835972ms min_rtt=40.835972ms rttvar=20.417986ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=1321 app_limited=true congestion_recovery_start_time=None Rate { delivered: 334, delivered_time: Instant { tv_sec: 1061, tv_nsec: 629463164 }, first_sent_time: Instant { tv_sec: 1061, tv_nsec: 629463164 }, end_of_app_limited: 3, last_sent_packet: 4, largest_acked: 0, rate_sample: RateSample { bandwidth: 65.43 Kbps, is_app_limited: true, interval: 40.835972ms, delivered: 334, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 1061, tv_nsec: 588210313 }), send_elapsed: 0ns, ack_elapsed: 40.835972ms, rtt: 40.835972ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 413238, last_update: Instant { tv_sec: 1061, tv_nsec: 629847462 }, next_time: Instant { tv_sec: 1061, tv_nsec: 629866200 }, max_datagram_size: 1350, last_packet_size: None, iv: 2.957134ms, 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-12T06:35:42.840160040Z TRACE quiche_apps::client] written 32 bytes from [::]:56481 to [fd00:cafe:cafe:100::100]:443
[2025-09-12T06:35:42.840166272Z TRACE quiche] fe592c901da213fc87b8e71a723b935abf2f92db tx pkt Short dcid=7c193bc9be78d2a4 key_phase=false len=6 pn=5 
[2025-09-12T06:35:42.840169337Z TRACE quiche] fe592c901da213fc87b8e71a723b935abf2f92db tx frm STREAM id=10 off=0 len=1 fin=false
[2025-09-12T06:35:42.840174988Z TRACE quiche::recovery::congestion::recovery] fe592c901da213fc87b8e71a723b935abf2f92db timer=122.230798ms latest_rtt=40.835972ms srtt=40.835972ms min_rtt=40.835972ms rttvar=20.417986ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=1353 app_limited=true congestion_recovery_start_time=None Rate { delivered: 334, delivered_time: Instant { tv_sec: 1061, tv_nsec: 629463164 }, first_sent_time: Instant { tv_sec: 1061, tv_nsec: 629463164 }, end_of_app_limited: 4, last_sent_packet: 5, largest_acked: 0, rate_sample: RateSample { bandwidth: 65.43 Kbps, is_app_limited: true, interval: 40.835972ms, delivered: 334, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 1061, tv_nsec: 588210313 }), send_elapsed: 0ns, ack_elapsed: 40.835972ms, rtt: 40.835972ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 32, rate: 413238, last_update: Instant { tv_sec: 1061, tv_nsec: 629847462 }, next_time: Instant { tv_sec: 1061, tv_nsec: 632849420 }, 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-12T06:35:42.840204313Z TRACE quiche_apps::client] written 32 bytes from [::]:56481 to [fd00:cafe:cafe:100::100]:443
[2025-09-12T06:35:42.840210444Z TRACE quiche] fe592c901da213fc87b8e71a723b935abf2f92db tx pkt Short dcid=7c193bc9be78d2a4 key_phase=false len=74 pn=6 
[2025-09-12T06:35:42.840213550Z TRACE quiche] fe592c901da213fc87b8e71a723b935abf2f92db tx frm STREAM id=0 off=0 len=69 fin=true
[2025-09-12T06:35:42.840219511Z TRACE quiche::recovery::congestion::recovery] fe592c901da213fc87b8e71a723b935abf2f92db timer=122.186265ms latest_rtt=40.835972ms srtt=40.835972ms min_rtt=40.835972ms rttvar=20.417986ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=1453 app_limited=true congestion_recovery_start_time=None Rate { delivered: 334, delivered_time: Instant { tv_sec: 1061, tv_nsec: 629463164 }, first_sent_time: Instant { tv_sec: 1061, tv_nsec: 629463164 }, end_of_app_limited: 5, last_sent_packet: 6, largest_acked: 0, rate_sample: RateSample { bandwidth: 65.43 Kbps, is_app_limited: true, interval: 40.835972ms, delivered: 334, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 1061, tv_nsec: 588210313 }), send_elapsed: 0ns, ack_elapsed: 40.835972ms, rtt: 40.835972ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 413238, last_update: Instant { tv_sec: 1061, tv_nsec: 629936398 }, next_time: Instant { tv_sec: 1061, tv_nsec: 632849420 }, max_datagram_size: 1350, last_packet_size: None, iv: 319.429µ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-12T06:35:42.840242514Z TRACE quiche_apps::client] written 100 bytes from [::]:56481 to [fd00:cafe:cafe:100::100]:443
[2025-09-12T06:35:42.840246642Z TRACE quiche_apps::client] [::]:56481 -> [fd00:cafe:cafe:100::100]:443: done writing
[2025-09-12T06:35:42.873153478Z TRACE quiche_apps::client] got 583 bytes from [fd00:cafe:cafe:100::100]:443 to [::]:56481
[2025-09-12T06:35:42.873170520Z TRACE quiche] fe592c901da213fc87b8e71a723b935abf2f92db rx pkt Short dcid=fe592c901da213fc87b8e71a723b935abf2f92db key_phase=false len=562 pn=2 
[2025-09-12T06:35:42.873180429Z TRACE quiche] fe592c901da213fc87b8e71a723b935abf2f92db rx frm CRYPTO off=0 len=540
[2025-09-12T06:35:42.873208391Z TRACE quiche] fe592c901da213fc87b8e71a723b935abf2f92db rx frm HANDSHAKE_DONE
[2025-09-12T06:35:42.873213921Z TRACE quiche] fe592c901da213fc87b8e71a723b935abf2f92db dropped epoch 1 state
[2025-09-12T06:35:42.873224832Z TRACE quiche_apps::client] [::]:56481: processed 583 bytes
[2025-09-12T06:35:42.873229741Z TRACE quiche_apps::client] [::]:56481: recv() would block
[2025-09-12T06:35:42.873232977Z TRACE quiche_apps::client] done reading
[2025-09-12T06:35:42.873243927Z TRACE quiche] fe592c901da213fc87b8e71a723b935abf2f92db tx pkt Short dcid=7c193bc9be78d2a4 key_phase=false len=5 pn=7 
[2025-09-12T06:35:42.873247694Z TRACE quiche] fe592c901da213fc87b8e71a723b935abf2f92db tx frm ACK delay=9 blocks=[2..2] ecn_counts=None
[2025-09-12T06:35:42.873257853Z TRACE quiche::recovery::congestion::recovery] fe592c901da213fc87b8e71a723b935abf2f92db timer=114.457402ms latest_rtt=40.835972ms srtt=40.835972ms min_rtt=40.835972ms rttvar=20.417986ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=1354 app_limited=true congestion_recovery_start_time=None Rate { delivered: 334, delivered_time: Instant { tv_sec: 1061, tv_nsec: 629463164 }, first_sent_time: Instant { tv_sec: 1061, tv_nsec: 629463164 }, end_of_app_limited: 5, last_sent_packet: 7, largest_acked: 0, rate_sample: RateSample { bandwidth: 65.43 Kbps, is_app_limited: true, interval: 40.835972ms, delivered: 334, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 1061, tv_nsec: 588210313 }), send_elapsed: 0ns, ack_elapsed: 40.835972ms, rtt: 40.835972ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 413238, last_update: Instant { tv_sec: 1061, tv_nsec: 662966725 }, next_time: Instant { tv_sec: 1061, tv_nsec: 663286154 }, 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-12T06:35:42.873332072Z TRACE quiche_apps::client] written 31 bytes from [::]:56481 to [fd00:cafe:cafe:100::100]:443
[2025-09-12T06:35:42.873338945Z TRACE quiche_apps::client] [::]:56481 -> [fd00:cafe:cafe:100::100]:443: done writing
[2025-09-12T06:35:42.873370013Z TRACE quiche_apps::client] got 298 bytes from [fd00:cafe:cafe:100::100]:443 to [::]:56481
[2025-09-12T06:35:42.873375423Z TRACE quiche] fe592c901da213fc87b8e71a723b935abf2f92db dropped invalid packet
[2025-09-12T06:35:42.873379000Z TRACE quiche_apps::client] [::]:56481: processed 298 bytes
[2025-09-12T06:35:42.873384370Z TRACE quiche_apps::client] got 48 bytes from [fd00:cafe:cafe:100::100]:443 to [::]:56481
[2025-09-12T06:35:42.873388738Z TRACE quiche] fe592c901da213fc87b8e71a723b935abf2f92db rx pkt Short dcid=fe592c901da213fc87b8e71a723b935abf2f92db key_phase=false len=27 pn=5 
[2025-09-12T06:35:42.873395500Z TRACE quiche] fe592c901da213fc87b8e71a723b935abf2f92db rx frm ACK delay=15 blocks=[3..6] ecn_counts=None
[2025-09-12T06:35:42.873400149Z TRACE quiche::recovery::congestion::recovery] fe592c901da213fc87b8e71a723b935abf2f92db packet newly acked 3
[2025-09-12T06:35:42.873403996Z TRACE quiche::recovery::congestion::recovery] fe592c901da213fc87b8e71a723b935abf2f92db packet newly acked 4
[2025-09-12T06:35:42.873407302Z TRACE quiche::recovery::congestion::recovery] fe592c901da213fc87b8e71a723b935abf2f92db packet newly acked 5
[2025-09-12T06:35:42.873410218Z TRACE quiche::recovery::congestion::recovery] fe592c901da213fc87b8e71a723b935abf2f92db packet newly acked 6
[2025-09-12T06:35:42.873415007Z TRACE quiche] fe592c901da213fc87b8e71a723b935abf2f92db rx frm STREAM id=0 off=0 len=0 fin=true
[2025-09-12T06:35:42.873432249Z TRACE quiche_apps::client] [::]:56481: processed 48 bytes
[2025-09-12T06:35:42.873436898Z TRACE quiche_apps::client] [::]:56481: recv() would block
[2025-09-12T06:35:42.873439963Z TRACE quiche_apps::client] done reading
[2025-09-12T06:35:42.873443109Z TRACE quiche::h3] fe592c901da213fc87b8e71a723b935abf2f92db stream id 0 is readable
[2025-09-12T06:35:42.873449882Z TRACE quiche::h3::stream] fe592c901da213fc87b8e71a723b935abf2f92db read 0 bytes on stream 0
[2025-09-12T06:35:42.873454000Z DEBUG quiche_apps::common] 1/1 responses received
[2025-09-12T06:35:42.873457246Z INFO  quiche_apps::common] 1/1 response(s) received in 74.860576ms, closing...
[2025-09-12T06:35:42.873466142Z TRACE quiche] fe592c901da213fc87b8e71a723b935abf2f92db tx pkt Short dcid=7c193bc9be78d2a4 key_phase=false len=11 pn=8 
[2025-09-12T06:35:42.873469629Z TRACE quiche] fe592c901da213fc87b8e71a723b935abf2f92db tx frm APPLICATION_CLOSE err=100 reason=[6b, 74, 68, 78, 62, 79, 65]
[2025-09-12T06:35:42.873478165Z TRACE quiche::recovery::congestion::recovery] fe592c901da213fc87b8e71a723b935abf2f92db timer=136.321891ms latest_rtt=30.266754ms srtt=39.514819ms min_rtt=30.266754ms rttvar=17.955793ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=37 app_limited=true congestion_recovery_start_time=None Rate { delivered: 1688, delivered_time: Instant { tv_sec: 1061, tv_nsec: 663286154 }, first_sent_time: Instant { tv_sec: 1061, tv_nsec: 663286154 }, end_of_app_limited: 7, last_sent_packet: 8, largest_acked: 6, rate_sample: RateSample { bandwidth: 321.87 Kbps, is_app_limited: true, interval: 33.65301ms, delivered: 1354, prior_delivered: 334, prior_time: Some(Instant { tv_sec: 1061, tv_nsec: 629463164 }), send_elapsed: 3.386256ms, ack_elapsed: 33.65301ms, rtt: 30.266754ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 427054, last_update: Instant { tv_sec: 1061, tv_nsec: 663191034 }, next_time: Instant { tv_sec: 1061, tv_nsec: 663286154 }, max_datagram_size: 1350, last_packet_size: None, iv: 86.64µ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-12T06:35:42.873534600Z TRACE quiche_apps::client] written 37 bytes from [::]:56481 to [fd00:cafe:cafe:100::100]:443
[2025-09-12T06:35:42.873539650Z TRACE quiche_apps::client] [::]:56481 -> [fd00:cafe:cafe:100::100]:443: done writing
[2025-09-12T06:35:43.207930108Z TRACE quiche_apps::client] timed out
[2025-09-12T06:35:43.207947731Z TRACE quiche] fe592c901da213fc87b8e71a723b935abf2f92db draining timeout expired
[2025-09-12T06:35:43.207981184Z TRACE quiche_apps::client] done reading
[2025-09-12T06:35:43.207987406Z INFO  quiche_apps::client] connection closed, recv=4 sent=9 lost=0 retrans=0 sent_bytes=1916 recv_bytes=1863 lost_bytes=0 [local_addr=[::]:56481 peer_addr=[fd00:cafe:cafe:100::100]:443 validation_state=Validated active=true recv=4 sent=9 lost=0 retrans=0 rtt=39.514819ms min_rtt=Some(30.266754ms) rttvar=17.955793ms cwnd=13500 sent_bytes=1916 recv_bytes=1863 lost_bytes=0 stream_retrans_bytes=0 pmtu=1350 delivery_rate=40234]