[2025-12-14T03:43:11.873293504Z TRACE mio::poll] registering event source with poller: token=Token(0), interests=READABLE
[2025-12-14T03:43:11.873597690Z INFO  quiche_apps::client] connecting to [fd00:cafe:cafe:100::100]:443 from [::]:58150 with scid aefffa5165fad5b48a583d61131dbd5e1c48ad24
[2025-12-14T03:43:11.873640851Z TRACE quiche::tls] aefffa5165fad5b48a583d61131dbd5e1c48ad24 write message lvl=Initial len=266
[2025-12-14T03:43:11.873663443Z TRACE quiche] aefffa5165fad5b48a583d61131dbd5e1c48ad24 tx pkt Initial version=1 dcid=fa409d571b52e6f6e02d1a240d9f5bdf scid=aefffa5165fad5b48a583d61131dbd5e1c48ad24 len=270 pn=0 
[2025-12-14T03:43:11.873667631Z TRACE quiche] aefffa5165fad5b48a583d61131dbd5e1c48ad24 tx frm CRYPTO off=0 len=266
[2025-12-14T03:43:11.873686526Z TRACE quiche::recovery::congestion::recovery] aefffa5165fad5b48a583d61131dbd5e1c48ad24 timer=998.91935ms 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: 969, tv_nsec: 938462572 }, first_sent_time: Instant { tv_sec: 969, tv_nsec: 938462572 }, 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: 969, tv_nsec: 938462572 }, next_time: Instant { tv_sec: 969, tv_nsec: 938462572 }, 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-12-14T03:43:11.873734184Z TRACE quiche_apps::client] written 1200
[2025-12-14T03:43:12.128927306Z TRACE quiche_apps::client] got 1200 bytes from [fd00:cafe:cafe:100::100]:443 to [::]:58150
[2025-12-14T03:43:12.128970687Z TRACE quiche] aefffa5165fad5b48a583d61131dbd5e1c48ad24 rx pkt Initial version=1 dcid=aefffa5165fad5b48a583d61131dbd5e1c48ad24 scid=32d340db3e9f2033 token= len=397 pn=0 
[2025-12-14T03:43:12.128991085Z TRACE quiche] aefffa5165fad5b48a583d61131dbd5e1c48ad24 rx frm ACK delay=0 blocks=[0..0] ecn_counts=None
[2025-12-14T03:43:12.129000854Z TRACE quiche::recovery::congestion::recovery] aefffa5165fad5b48a583d61131dbd5e1c48ad24 packet newly acked 0
[2025-12-14T03:43:12.129010852Z TRACE quiche] aefffa5165fad5b48a583d61131dbd5e1c48ad24 rx frm CRYPTO off=0 len=90
[2025-12-14T03:43:12.129187501Z TRACE quiche::tls] aefffa5165fad5b48a583d61131dbd5e1c48ad24 set write secret lvl=Handshake
[2025-12-14T03:43:12.129206987Z TRACE quiche::tls] aefffa5165fad5b48a583d61131dbd5e1c48ad24 set read secret lvl=Handshake
[2025-12-14T03:43:12.129222907Z TRACE quiche] aefffa5165fad5b48a583d61131dbd5e1c48ad24 rx frm PADDING len=281
[2025-12-14T03:43:12.129260217Z TRACE quiche] aefffa5165fad5b48a583d61131dbd5e1c48ad24 rx pkt Handshake version=1 dcid=aefffa5165fad5b48a583d61131dbd5e1c48ad24 scid=32d340db3e9f2033 len=728 pn=0 
[2025-12-14T03:43:12.129270145Z TRACE quiche] aefffa5165fad5b48a583d61131dbd5e1c48ad24 rx frm CRYPTO off=0 len=707
[2025-12-14T03:43:12.129544095Z TRACE quiche::tls] aefffa5165fad5b48a583d61131dbd5e1c48ad24 write message lvl=Handshake len=36
[2025-12-14T03:43:12.129551579Z TRACE quiche::tls] aefffa5165fad5b48a583d61131dbd5e1c48ad24 set write secret lvl=OneRTT
[2025-12-14T03:43:12.129562990Z TRACE quiche::tls] aefffa5165fad5b48a583d61131dbd5e1c48ad24 set read secret lvl=OneRTT
[2025-12-14T03:43:12.129588999Z TRACE quiche] aefffa5165fad5b48a583d61131dbd5e1c48ad24 connection established: proto=Ok("hq-interop") cipher=Some(AES128_GCM) curve=Some("X25519") sigalg=Some("ecdsa_secp256r1_sha256") resumed=false TransportParams { original_destination_connection_id: Some(fa409d571b52e6f6e02d1a240d9f5bdf), max_idle_timeout: 30000, stateless_reset_token: None, max_udp_payload_size: 1500, initial_max_data: 10000000, initial_max_stream_data_bidi_local: 1000000, initial_max_stream_data_bidi_remote: 1000000, initial_max_stream_data_uni: 1000000, initial_max_streams_bidi: 100, initial_max_streams_uni: 0, ack_delay_exponent: 3, max_ack_delay: 25, disable_active_migration: true, active_conn_id_limit: 3, initial_source_connection_id: Some(32d340db3e9f2033), retry_source_connection_id: None, max_datagram_frame_size: None, unknown_params: None }
[2025-12-14T03:43:12.129633642Z TRACE quiche_apps::client] [::]:58150: processed 1200 bytes
[2025-12-14T03:43:12.129641587Z TRACE quiche_apps::client] [::]:58150: recv() would block
[2025-12-14T03:43:12.129646045Z TRACE quiche_apps::client] done reading
[2025-12-14T03:43:12.129658728Z DEBUG quiche_apps::common] sending HTTP request "GET /navy-hard-bluetooth\r\n"
[2025-12-14T03:43:12.129728428Z DEBUG quiche_apps::common] sending HTTP request "GET /anxious-content-helicopter\r\n"
[2025-12-14T03:43:12.129782108Z TRACE quiche] aefffa5165fad5b48a583d61131dbd5e1c48ad24 tx pkt Initial version=1 dcid=32d340db3e9f2033 scid=aefffa5165fad5b48a583d61131dbd5e1c48ad24 len=6 pn=1 
[2025-12-14T03:43:12.129789652Z TRACE quiche] aefffa5165fad5b48a583d61131dbd5e1c48ad24 tx frm ACK delay=102 blocks=[0..0] ecn_counts=None
[2025-12-14T03:43:12.129805822Z TRACE quiche::recovery::congestion::recovery] aefffa5165fad5b48a583d61131dbd5e1c48ad24 timer=765.22302ms latest_rtt=255.355895ms srtt=255.355895ms min_rtt=255.355895ms rttvar=127.677947ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=0 app_limited=true congestion_recovery_start_time=None Rate { delivered: 333, delivered_time: Instant { tv_sec: 970, tv_nsec: 194441618 }, first_sent_time: Instant { tv_sec: 970, tv_nsec: 194441618 }, end_of_app_limited: 1, last_sent_packet: 1, largest_acked: 0, rate_sample: RateSample { bandwidth: 10.43 Kbps, is_app_limited: true, interval: 255.355895ms, delivered: 333, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 969, tv_nsec: 938462572 }), send_elapsed: 0ns, ack_elapsed: 255.355895ms, rtt: 255.355895ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 66084, last_update: Instant { tv_sec: 970, tv_nsec: 194441577 }, next_time: Instant { tv_sec: 970, tv_nsec: 194441618 }, 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-12-14T03:43:12.129846077Z TRACE quiche] aefffa5165fad5b48a583d61131dbd5e1c48ad24 tx pkt Handshake version=1 dcid=32d340db3e9f2033 scid=aefffa5165fad5b48a583d61131dbd5e1c48ad24 len=46 pn=2 
[2025-12-14T03:43:12.129851828Z TRACE quiche] aefffa5165fad5b48a583d61131dbd5e1c48ad24 tx frm ACK delay=73 blocks=[0..0] ecn_counts=None
[2025-12-14T03:43:12.129857028Z TRACE quiche] aefffa5165fad5b48a583d61131dbd5e1c48ad24 tx frm CRYPTO off=0 len=36
[2025-12-14T03:43:12.129866966Z TRACE quiche::recovery::congestion::recovery] aefffa5165fad5b48a583d61131dbd5e1c48ad24 timer=765.968859ms latest_rtt=255.355895ms srtt=255.355895ms min_rtt=255.355895ms rttvar=127.677947ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=100 app_limited=true congestion_recovery_start_time=None Rate { delivered: 333, delivered_time: Instant { tv_sec: 970, tv_nsec: 194441618 }, first_sent_time: Instant { tv_sec: 970, tv_nsec: 194441618 }, end_of_app_limited: 1, last_sent_packet: 2, largest_acked: 0, rate_sample: RateSample { bandwidth: 10.43 Kbps, is_app_limited: true, interval: 255.355895ms, delivered: 333, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 969, tv_nsec: 938462572 }), send_elapsed: 0ns, ack_elapsed: 255.355895ms, rtt: 255.355895ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 66084, last_update: Instant { tv_sec: 970, tv_nsec: 194624849 }, next_time: Instant { tv_sec: 970, tv_nsec: 194441618 }, max_datagram_size: 1350, last_packet_size: None, iv: 1.513226ms, 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-12-14T03:43:12.129897132Z TRACE quiche] aefffa5165fad5b48a583d61131dbd5e1c48ad24 dropped epoch 0 state
[2025-12-14T03:43:12.129917731Z TRACE quiche] aefffa5165fad5b48a583d61131dbd5e1c48ad24 tx pkt Short dcid=32d340db3e9f2033 key_phase=false len=1163 pn=3 
[2025-12-14T03:43:12.129922770Z TRACE quiche] aefffa5165fad5b48a583d61131dbd5e1c48ad24 tx frm NEW_CONNECTION_ID seq_num=1 retire_prior_to=0 conn_id=[c7, 76, 49, 53, ff, 48, 6f, a9, 8e, c6, 43, 95, 26, 84, 00, d9, ac, d5, 78, da] reset_token=[bc, fc, de, 47, 22, f0, 8d, 5f, 3c, d4, 51, 64, 31, 7b, 77, 3d]
[2025-12-14T03:43:12.129934693Z TRACE quiche] aefffa5165fad5b48a583d61131dbd5e1c48ad24 tx frm NEW_CONNECTION_ID seq_num=2 retire_prior_to=0 conn_id=[92, 32, 8f, 40, 23, c1, 05, fe, 9d, 31, 95, be, 14, 16, 08, 0c, 3e, 7e, 02, 40] reset_token=[b2, 5d, 31, 02, 96, 31, f3, b6, 5f, 25, 0b, 18, 17, a2, c1, 13]
[2025-12-14T03:43:12.129945302Z TRACE quiche] aefffa5165fad5b48a583d61131dbd5e1c48ad24 tx frm STREAM id=0 off=0 len=26 fin=true
[2025-12-14T03:43:12.129950231Z TRACE quiche] aefffa5165fad5b48a583d61131dbd5e1c48ad24 tx frm PADDING len=1052
[2025-12-14T03:43:12.129961923Z TRACE quiche::recovery::congestion::recovery] aefffa5165fad5b48a583d61131dbd5e1c48ad24 timer=765.873852ms latest_rtt=255.355895ms srtt=255.355895ms min_rtt=255.355895ms rttvar=127.677947ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=1289 app_limited=true congestion_recovery_start_time=None Rate { delivered: 333, delivered_time: Instant { tv_sec: 970, tv_nsec: 194441618 }, first_sent_time: Instant { tv_sec: 970, tv_nsec: 194441618 }, end_of_app_limited: 2, last_sent_packet: 3, largest_acked: 0, rate_sample: RateSample { bandwidth: 10.43 Kbps, is_app_limited: true, interval: 255.355895ms, delivered: 333, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 969, tv_nsec: 938462572 }), send_elapsed: 0ns, ack_elapsed: 255.355895ms, rtt: 255.355895ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 1189, rate: 66084, last_update: Instant { tv_sec: 970, tv_nsec: 194624849 }, next_time: Instant { tv_sec: 970, tv_nsec: 196138075 }, max_datagram_size: 1350, last_packet_size: Some(1189), 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-12-14T03:43:12.130019420Z TRACE quiche_apps::client] written 1350 bytes from [::]:58150 to [fd00:cafe:cafe:100::100]:443
[2025-12-14T03:43:12.130031453Z TRACE quiche] aefffa5165fad5b48a583d61131dbd5e1c48ad24 tx pkt Short dcid=32d340db3e9f2033 key_phase=false len=38 pn=4 
[2025-12-14T03:43:12.130036692Z TRACE quiche] aefffa5165fad5b48a583d61131dbd5e1c48ad24 tx frm STREAM id=4 off=0 len=33 fin=true
[2025-12-14T03:43:12.130046220Z TRACE quiche::recovery::congestion::recovery] aefffa5165fad5b48a583d61131dbd5e1c48ad24 timer=765.789555ms latest_rtt=255.355895ms srtt=255.355895ms min_rtt=255.355895ms rttvar=127.677947ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=1353 app_limited=true congestion_recovery_start_time=None Rate { delivered: 333, delivered_time: Instant { tv_sec: 970, tv_nsec: 194441618 }, first_sent_time: Instant { tv_sec: 970, tv_nsec: 194441618 }, end_of_app_limited: 3, last_sent_packet: 4, largest_acked: 0, rate_sample: RateSample { bandwidth: 10.43 Kbps, is_app_limited: true, interval: 255.355895ms, delivered: 333, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 969, tv_nsec: 938462572 }), send_elapsed: 0ns, ack_elapsed: 255.355895ms, rtt: 255.355895ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 66084, last_update: Instant { tv_sec: 970, tv_nsec: 194882238 }, next_time: Instant { tv_sec: 970, tv_nsec: 196138075 }, max_datagram_size: 1350, last_packet_size: None, iv: 18.960717ms, 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-12-14T03:43:12.130093779Z TRACE quiche_apps::client] written 64 bytes from [::]:58150 to [fd00:cafe:cafe:100::100]:443
[2025-12-14T03:43:12.130101393Z TRACE quiche_apps::client] [::]:58150 -> [fd00:cafe:cafe:100::100]:443: done writing
[2025-12-14T03:43:12.187394063Z TRACE quiche_apps::client] got 224 bytes from [fd00:cafe:cafe:100::100]:443 to [::]:58150
[2025-12-14T03:43:12.187435701Z TRACE quiche] aefffa5165fad5b48a583d61131dbd5e1c48ad24 rx pkt Short dcid=aefffa5165fad5b48a583d61131dbd5e1c48ad24 key_phase=false len=203 pn=0 
[2025-12-14T03:43:12.187455037Z TRACE quiche] aefffa5165fad5b48a583d61131dbd5e1c48ad24 rx frm HANDSHAKE_DONE
[2025-12-14T03:43:12.187465116Z TRACE quiche] aefffa5165fad5b48a583d61131dbd5e1c48ad24 dropped epoch 1 state
[2025-12-14T03:43:12.187474523Z TRACE quiche] aefffa5165fad5b48a583d61131dbd5e1c48ad24 rx frm NEW_CONNECTION_ID seq_num=1 retire_prior_to=0 conn_id=[52, fa, 34, 23, 63, 34, 4e, 36] reset_token=[5e, 01, af, 6b, b0, 2e, 19, 1d, 42, 7e, a4, 36, f6, b6, 29, 00]
[2025-12-14T03:43:12.187488700Z TRACE quiche] aefffa5165fad5b48a583d61131dbd5e1c48ad24 rx frm NEW_CONNECTION_ID seq_num=2 retire_prior_to=0 conn_id=[62, 47, 79, 92, b8, a7, 3d, bb] reset_token=[16, f8, 72, 35, a8, e8, d2, 8b, 95, 61, a5, 80, c9, 1c, 4a, e8]
[2025-12-14T03:43:12.187497867Z TRACE quiche] aefffa5165fad5b48a583d61131dbd5e1c48ad24 rx frm NEW_CONNECTION_ID seq_num=3 retire_prior_to=0 conn_id=[03, 6b, 92, d8, d6, 18, 72, 83] reset_token=[48, f0, 90, d7, f8, a8, 66, 93, 1e, f2, 09, 3f, 9c, 0a, 6e, 95]
[2025-12-14T03:43:12.187507615Z TRACE quiche] aefffa5165fad5b48a583d61131dbd5e1c48ad24 rx frm NEW_CONNECTION_ID seq_num=4 retire_prior_to=0 conn_id=[5b, b8, 49, 15, 50, a9, e3, f8] reset_token=[cd, 20, 63, 59, 11, 6a, 4d, c2, f1, b9, 44, c9, 96, 16, fc, 3b]
[2025-12-14T03:43:12.187516692Z TRACE quiche] aefffa5165fad5b48a583d61131dbd5e1c48ad24 rx frm NEW_CONNECTION_ID seq_num=5 retire_prior_to=0 conn_id=[2f, 94, b6, c4, b8, a2, 7b, 1c] reset_token=[07, 81, 12, 4e, 0c, bd, 43, 16, b5, 78, 72, 79, c7, 3e, 6e, d7]
[2025-12-14T03:43:12.187525178Z TRACE quiche] aefffa5165fad5b48a583d61131dbd5e1c48ad24 rx frm CRYPTO off=0 len=42
[2025-12-14T03:43:12.187578457Z TRACE quiche_apps::client] [::]:58150: processed 224 bytes
[2025-12-14T03:43:12.187586382Z TRACE quiche_apps::client] [::]:58150: recv() would block
[2025-12-14T03:43:12.187591081Z TRACE quiche_apps::client] done reading
[2025-12-14T03:43:12.187609795Z TRACE quiche] aefffa5165fad5b48a583d61131dbd5e1c48ad24 tx pkt Short dcid=32d340db3e9f2033 key_phase=false len=5 pn=5 
[2025-12-14T03:43:12.187615396Z TRACE quiche] aefffa5165fad5b48a583d61131dbd5e1c48ad24 tx frm ACK delay=21 blocks=[0..0] ecn_counts=None
[2025-12-14T03:43:12.187629782Z TRACE quiche::recovery::congestion::recovery] aefffa5165fad5b48a583d61131dbd5e1c48ad24 timer=733.462811ms latest_rtt=255.355895ms srtt=255.355895ms min_rtt=255.355895ms rttvar=127.677947ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=1253 app_limited=true congestion_recovery_start_time=None Rate { delivered: 333, delivered_time: Instant { tv_sec: 970, tv_nsec: 194441618 }, first_sent_time: Instant { tv_sec: 970, tv_nsec: 194441618 }, end_of_app_limited: 3, last_sent_packet: 5, largest_acked: 0, rate_sample: RateSample { bandwidth: 10.43 Kbps, is_app_limited: true, interval: 255.355895ms, delivered: 333, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 969, tv_nsec: 938462572 }), send_elapsed: 0ns, ack_elapsed: 255.355895ms, rtt: 255.355895ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 66084, last_update: Instant { tv_sec: 970, tv_nsec: 194882238 }, next_time: Instant { tv_sec: 970, tv_nsec: 271414815 }, 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-12-14T03:43:12.187702768Z TRACE quiche_apps::client] written 31 bytes from [::]:58150 to [fd00:cafe:cafe:100::100]:443
[2025-12-14T03:43:12.187711144Z TRACE quiche_apps::client] [::]:58150 -> [fd00:cafe:cafe:100::100]:443: done writing
[2025-12-14T03:43:12.196820568Z TRACE quiche_apps::client] got 44 bytes from [fd00:cafe:cafe:100::100]:443 to [::]:58150
[2025-12-14T03:43:12.196840986Z TRACE quiche] aefffa5165fad5b48a583d61131dbd5e1c48ad24 rx pkt Short dcid=aefffa5165fad5b48a583d61131dbd5e1c48ad24 key_phase=false len=23 pn=1 
[2025-12-14T03:43:12.196853088Z TRACE quiche] aefffa5165fad5b48a583d61131dbd5e1c48ad24 rx frm ACK delay=250 blocks=[3..4] ecn_counts=None
[2025-12-14T03:43:12.196860813Z TRACE quiche::recovery::congestion::recovery] aefffa5165fad5b48a583d61131dbd5e1c48ad24 packet newly acked 3
[2025-12-14T03:43:12.196866543Z TRACE quiche::recovery::congestion::recovery] aefffa5165fad5b48a583d61131dbd5e1c48ad24 packet newly acked 4
[2025-12-14T03:43:12.196890247Z TRACE quiche_apps::client] [::]:58150: processed 44 bytes
[2025-12-14T03:43:12.196896930Z TRACE quiche_apps::client] [::]:58150: recv() would block
[2025-12-14T03:43:12.196901619Z TRACE quiche_apps::client] done reading
[2025-12-14T03:43:12.196909273Z TRACE quiche_apps::client] [::]:58150 -> [fd00:cafe:cafe:100::100]:443: done writing
[2025-12-14T03:43:12.200341665Z TRACE quiche_apps::client] got 1232 bytes from [fd00:cafe:cafe:100::100]:443 to [::]:58150
[2025-12-14T03:43:12.200359939Z TRACE quiche] aefffa5165fad5b48a583d61131dbd5e1c48ad24 rx pkt Short dcid=aefffa5165fad5b48a583d61131dbd5e1c48ad24 key_phase=false len=1211 pn=2 
[2025-12-14T03:43:12.200372612Z TRACE quiche] aefffa5165fad5b48a583d61131dbd5e1c48ad24 rx frm STREAM id=0 off=0 len=1189 fin=false
[2025-12-14T03:43:12.200385877Z TRACE quiche_apps::client] [::]:58150: processed 1232 bytes
[2025-12-14T03:43:12.200391828Z TRACE quiche_apps::client] [::]:58150: recv() would block
[2025-12-14T03:43:12.200396096Z TRACE quiche_apps::client] done reading
[2025-12-14T03:43:12.200403830Z TRACE quiche_apps::common] received 1189 bytes
[2025-12-14T03:43:12.200408559Z TRACE quiche_apps::common] stream 0 has 1189 bytes (fin? false)
[2025-12-14T03:43:12.200422074Z TRACE quiche] aefffa5165fad5b48a583d61131dbd5e1c48ad24 tx pkt Short dcid=32d340db3e9f2033 key_phase=false len=5 pn=6 
[2025-12-14T03:43:12.200427104Z TRACE quiche] aefffa5165fad5b48a583d61131dbd5e1c48ad24 tx frm ACK delay=7 blocks=[0..2] ecn_counts=None
[2025-12-14T03:43:12.200437994Z TRACE quiche::recovery::congestion::recovery] aefffa5165fad5b48a583d61131dbd5e1c48ad24 timer=none latest_rtt=65.556441ms srtt=231.630963ms min_rtt=65.556441ms rttvar=143.208323ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=0 app_limited=true congestion_recovery_start_time=None Rate { delivered: 1586, delivered_time: Instant { tv_sec: 970, tv_nsec: 271414815 }, first_sent_time: Instant { tv_sec: 970, tv_nsec: 271414815 }, end_of_app_limited: 5, last_sent_packet: 6, largest_acked: 4, rate_sample: RateSample { bandwidth: 149.05 Kbps, is_app_limited: true, interval: 67.252898ms, delivered: 1253, prior_delivered: 333, prior_time: Some(Instant { tv_sec: 970, tv_nsec: 194441618 }), send_elapsed: 1.696457ms, ack_elapsed: 67.252898ms, rtt: 65.556441ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 72852, last_update: Instant { tv_sec: 970, tv_nsec: 194882238 }, next_time: Instant { tv_sec: 970, tv_nsec: 271414815 }, 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-12-14T03:43:12.200525858Z TRACE quiche_apps::client] written 31 bytes from [::]:58150 to [fd00:cafe:cafe:100::100]:443
[2025-12-14T03:43:12.200534253Z TRACE quiche_apps::client] [::]:58150 -> [fd00:cafe:cafe:100::100]:443: done writing
[2025-12-14T03:43:12.201352116Z TRACE quiche_apps::client] got 1232 bytes from [fd00:cafe:cafe:100::100]:443 to [::]:58150
[2025-12-14T03:43:12.201366904Z TRACE quiche] aefffa5165fad5b48a583d61131dbd5e1c48ad24 rx pkt Short dcid=aefffa5165fad5b48a583d61131dbd5e1c48ad24 key_phase=false len=1211 pn=3 
[2025-12-14T03:43:12.201378185Z TRACE quiche] aefffa5165fad5b48a583d61131dbd5e1c48ad24 rx frm STREAM id=0 off=1189 len=1188 fin=false
[2025-12-14T03:43:12.201389857Z TRACE quiche_apps::client] [::]:58150: processed 1232 bytes
[2025-12-14T03:43:12.201395728Z TRACE quiche_apps::client] [::]:58150: recv() would block
[2025-12-14T03:43:12.201399985Z TRACE quiche_apps::client] done reading
[2025-12-14T03:43:12.201406758Z TRACE quiche_apps::common] received 1188 bytes
[2025-12-14T03:43:12.201411156Z TRACE quiche_apps::common] stream 0 has 1188 bytes (fin? false)
[2025-12-14T03:43:12.201422527Z TRACE quiche] aefffa5165fad5b48a583d61131dbd5e1c48ad24 tx pkt Short dcid=32d340db3e9f2033 key_phase=false len=5 pn=7 
[2025-12-14T03:43:12.201427547Z TRACE quiche] aefffa5165fad5b48a583d61131dbd5e1c48ad24 tx frm ACK delay=6 blocks=[0..3] ecn_counts=None
[2025-12-14T03:43:12.201438297Z TRACE quiche::recovery::congestion::recovery] aefffa5165fad5b48a583d61131dbd5e1c48ad24 timer=none latest_rtt=65.556441ms srtt=231.630963ms min_rtt=65.556441ms rttvar=143.208323ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=0 app_limited=true congestion_recovery_start_time=None Rate { delivered: 1586, delivered_time: Instant { tv_sec: 970, tv_nsec: 271414815 }, first_sent_time: Instant { tv_sec: 970, tv_nsec: 271414815 }, end_of_app_limited: 5, last_sent_packet: 7, largest_acked: 4, rate_sample: RateSample { bandwidth: 149.05 Kbps, is_app_limited: true, interval: 67.252898ms, delivered: 1253, prior_delivered: 333, prior_time: Some(Instant { tv_sec: 970, tv_nsec: 194441618 }), send_elapsed: 1.696457ms, ack_elapsed: 67.252898ms, rtt: 65.556441ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 72852, last_update: Instant { tv_sec: 970, tv_nsec: 194882238 }, next_time: Instant { tv_sec: 970, tv_nsec: 271414815 }, 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-12-14T03:43:12.201484433Z TRACE quiche_apps::client] written 31 bytes from [::]:58150 to [fd00:cafe:cafe:100::100]:443
[2025-12-14T03:43:12.201492127Z TRACE quiche_apps::client] [::]:58150 -> [fd00:cafe:cafe:100::100]:443: done writing
[2025-12-14T03:43:12.203183317Z TRACE quiche_apps::client] got 1232 bytes from [fd00:cafe:cafe:100::100]:443 to [::]:58150
[2025-12-14T03:43:12.203199196Z TRACE quiche] aefffa5165fad5b48a583d61131dbd5e1c48ad24 rx pkt Short dcid=aefffa5165fad5b48a583d61131dbd5e1c48ad24 key_phase=false len=1211 pn=4 
[2025-12-14T03:43:12.203210447Z TRACE quiche] aefffa5165fad5b48a583d61131dbd5e1c48ad24 rx frm STREAM id=4 off=0 len=1189 fin=false
[2025-12-14T03:43:12.203222449Z TRACE quiche_apps::client] [::]:58150: processed 1232 bytes
[2025-12-14T03:43:12.203228240Z TRACE quiche_apps::client] [::]:58150: recv() would block
[2025-12-14T03:43:12.203232638Z TRACE quiche_apps::client] done reading
[2025-12-14T03:43:12.203239571Z TRACE quiche_apps::common] received 1189 bytes
[2025-12-14T03:43:12.203243689Z TRACE quiche_apps::common] stream 4 has 1189 bytes (fin? false)
[2025-12-14T03:43:12.203255311Z TRACE quiche] aefffa5165fad5b48a583d61131dbd5e1c48ad24 tx pkt Short dcid=32d340db3e9f2033 key_phase=false len=5 pn=8 
[2025-12-14T03:43:12.203266932Z TRACE quiche] aefffa5165fad5b48a583d61131dbd5e1c48ad24 tx frm ACK delay=7 blocks=[0..4] ecn_counts=None
[2025-12-14T03:43:12.203278063Z TRACE quiche::recovery::congestion::recovery] aefffa5165fad5b48a583d61131dbd5e1c48ad24 timer=none latest_rtt=65.556441ms srtt=231.630963ms min_rtt=65.556441ms rttvar=143.208323ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=0 app_limited=true congestion_recovery_start_time=None Rate { delivered: 1586, delivered_time: Instant { tv_sec: 970, tv_nsec: 271414815 }, first_sent_time: Instant { tv_sec: 970, tv_nsec: 271414815 }, end_of_app_limited: 5, last_sent_packet: 8, largest_acked: 4, rate_sample: RateSample { bandwidth: 149.05 Kbps, is_app_limited: true, interval: 67.252898ms, delivered: 1253, prior_delivered: 333, prior_time: Some(Instant { tv_sec: 970, tv_nsec: 194441618 }), send_elapsed: 1.696457ms, ack_elapsed: 67.252898ms, rtt: 65.556441ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 72852, last_update: Instant { tv_sec: 970, tv_nsec: 194882238 }, next_time: Instant { tv_sec: 970, tv_nsec: 271414815 }, 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-12-14T03:43:12.203326082Z TRACE quiche_apps::client] written 31 bytes from [::]:58150 to [fd00:cafe:cafe:100::100]:443
[2025-12-14T03:43:12.203333556Z TRACE quiche_apps::client] [::]:58150 -> [fd00:cafe:cafe:100::100]:443: done writing
[2025-12-14T03:43:12.206344323Z TRACE quiche_apps::client] got 1232 bytes from [fd00:cafe:cafe:100::100]:443 to [::]:58150
[2025-12-14T03:43:12.206361074Z TRACE quiche] aefffa5165fad5b48a583d61131dbd5e1c48ad24 rx pkt Short dcid=aefffa5165fad5b48a583d61131dbd5e1c48ad24 key_phase=false len=1211 pn=5 
[2025-12-14T03:43:12.206372786Z TRACE quiche] aefffa5165fad5b48a583d61131dbd5e1c48ad24 rx frm STREAM id=0 off=2377 len=1188 fin=false
[2025-12-14T03:43:12.206385590Z TRACE quiche_apps::client] [::]:58150: processed 1232 bytes
[2025-12-14T03:43:12.206391621Z TRACE quiche_apps::client] [::]:58150: recv() would block
[2025-12-14T03:43:12.206396149Z TRACE quiche_apps::client] done reading
[2025-12-14T03:43:12.206403553Z TRACE quiche_apps::common] received 1188 bytes
[2025-12-14T03:43:12.206408322Z TRACE quiche_apps::common] stream 0 has 1188 bytes (fin? false)
[2025-12-14T03:43:12.206420515Z TRACE quiche] aefffa5165fad5b48a583d61131dbd5e1c48ad24 tx pkt Short dcid=32d340db3e9f2033 key_phase=false len=5 pn=9 
[2025-12-14T03:43:12.206425634Z TRACE quiche] aefffa5165fad5b48a583d61131dbd5e1c48ad24 tx frm ACK delay=7 blocks=[0..5] ecn_counts=None
[2025-12-14T03:43:12.206437446Z TRACE quiche::recovery::congestion::recovery] aefffa5165fad5b48a583d61131dbd5e1c48ad24 timer=none latest_rtt=65.556441ms srtt=231.630963ms min_rtt=65.556441ms rttvar=143.208323ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=0 app_limited=true congestion_recovery_start_time=None Rate { delivered: 1586, delivered_time: Instant { tv_sec: 970, tv_nsec: 271414815 }, first_sent_time: Instant { tv_sec: 970, tv_nsec: 271414815 }, end_of_app_limited: 5, last_sent_packet: 9, largest_acked: 4, rate_sample: RateSample { bandwidth: 149.05 Kbps, is_app_limited: true, interval: 67.252898ms, delivered: 1253, prior_delivered: 333, prior_time: Some(Instant { tv_sec: 970, tv_nsec: 194441618 }), send_elapsed: 1.696457ms, ack_elapsed: 67.252898ms, rtt: 65.556441ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 72852, last_update: Instant { tv_sec: 970, tv_nsec: 194882238 }, next_time: Instant { tv_sec: 970, tv_nsec: 271414815 }, 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-12-14T03:43:12.206489193Z TRACE quiche_apps::client] written 31 bytes from [::]:58150 to [fd00:cafe:cafe:100::100]:443
[2025-12-14T03:43:12.206497017Z TRACE quiche_apps::client] [::]:58150 -> [fd00:cafe:cafe:100::100]:443: done writing
[2025-12-14T03:43:12.207672977Z TRACE quiche_apps::client] got 1232 bytes from [fd00:cafe:cafe:100::100]:443 to [::]:58150
[2025-12-14T03:43:12.207689217Z TRACE quiche] aefffa5165fad5b48a583d61131dbd5e1c48ad24 rx pkt Short dcid=aefffa5165fad5b48a583d61131dbd5e1c48ad24 key_phase=false len=1211 pn=6 
[2025-12-14T03:43:12.207701079Z TRACE quiche] aefffa5165fad5b48a583d61131dbd5e1c48ad24 rx frm STREAM id=4 off=1189 len=1188 fin=false
[2025-12-14T03:43:12.207712350Z TRACE quiche_apps::client] [::]:58150: processed 1232 bytes
[2025-12-14T03:43:12.207717961Z TRACE quiche_apps::client] [::]:58150: recv() would block
[2025-12-14T03:43:12.207722549Z TRACE quiche_apps::client] done reading
[2025-12-14T03:43:12.207729652Z TRACE quiche_apps::common] received 1188 bytes
[2025-12-14T03:43:12.207733740Z TRACE quiche_apps::common] stream 4 has 1188 bytes (fin? false)
[2025-12-14T03:43:12.207746234Z TRACE quiche] aefffa5165fad5b48a583d61131dbd5e1c48ad24 tx pkt Short dcid=32d340db3e9f2033 key_phase=false len=5 pn=10 
[2025-12-14T03:43:12.207751543Z TRACE quiche] aefffa5165fad5b48a583d61131dbd5e1c48ad24 tx frm ACK delay=7 blocks=[0..6] ecn_counts=None
[2025-12-14T03:43:12.207762534Z TRACE quiche::recovery::congestion::recovery] aefffa5165fad5b48a583d61131dbd5e1c48ad24 timer=none latest_rtt=65.556441ms srtt=231.630963ms min_rtt=65.556441ms rttvar=143.208323ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=0 app_limited=true congestion_recovery_start_time=None Rate { delivered: 1586, delivered_time: Instant { tv_sec: 970, tv_nsec: 271414815 }, first_sent_time: Instant { tv_sec: 970, tv_nsec: 271414815 }, end_of_app_limited: 5, last_sent_packet: 10, largest_acked: 4, rate_sample: RateSample { bandwidth: 149.05 Kbps, is_app_limited: true, interval: 67.252898ms, delivered: 1253, prior_delivered: 333, prior_time: Some(Instant { tv_sec: 970, tv_nsec: 194441618 }), send_elapsed: 1.696457ms, ack_elapsed: 67.252898ms, rtt: 65.556441ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 72852, last_update: Instant { tv_sec: 970, tv_nsec: 194882238 }, next_time: Instant { tv_sec: 970, tv_nsec: 271414815 }, 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-12-14T03:43:12.207808880Z TRACE quiche_apps::client] written 31 bytes from [::]:58150 to [fd00:cafe:cafe:100::100]:443
[2025-12-14T03:43:12.207816344Z TRACE quiche_apps::client] [::]:58150 -> [fd00:cafe:cafe:100::100]:443: done writing
[2025-12-14T03:43:12.208376898Z TRACE quiche_apps::client] got 1232 bytes from [fd00:cafe:cafe:100::100]:443 to [::]:58150
[2025-12-14T03:43:12.208391164Z TRACE quiche] aefffa5165fad5b48a583d61131dbd5e1c48ad24 rx pkt Short dcid=aefffa5165fad5b48a583d61131dbd5e1c48ad24 key_phase=false len=1211 pn=7 
[2025-12-14T03:43:12.208401313Z TRACE quiche] aefffa5165fad5b48a583d61131dbd5e1c48ad24 rx frm STREAM id=0 off=3565 len=1188 fin=false
[2025-12-14T03:43:12.208412504Z TRACE quiche_apps::client] [::]:58150: processed 1232 bytes
[2025-12-14T03:43:12.208418285Z TRACE quiche_apps::client] [::]:58150: recv() would block
[2025-12-14T03:43:12.208422613Z TRACE quiche_apps::client] done reading
[2025-12-14T03:43:12.208429015Z TRACE quiche_apps::common] received 1188 bytes
[2025-12-14T03:43:12.208433133Z TRACE quiche_apps::common] stream 0 has 1188 bytes (fin? false)
[2025-12-14T03:43:12.208443702Z TRACE quiche] aefffa5165fad5b48a583d61131dbd5e1c48ad24 tx pkt Short dcid=32d340db3e9f2033 key_phase=false len=5 pn=11 
[2025-12-14T03:43:12.208455143Z TRACE quiche] aefffa5165fad5b48a583d61131dbd5e1c48ad24 tx frm ACK delay=6 blocks=[0..7] ecn_counts=None
[2025-12-14T03:43:12.208465232Z TRACE quiche::recovery::congestion::recovery] aefffa5165fad5b48a583d61131dbd5e1c48ad24 timer=none latest_rtt=65.556441ms srtt=231.630963ms min_rtt=65.556441ms rttvar=143.208323ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=0 app_limited=true congestion_recovery_start_time=None Rate { delivered: 1586, delivered_time: Instant { tv_sec: 970, tv_nsec: 271414815 }, first_sent_time: Instant { tv_sec: 970, tv_nsec: 271414815 }, end_of_app_limited: 5, last_sent_packet: 11, largest_acked: 4, rate_sample: RateSample { bandwidth: 149.05 Kbps, is_app_limited: true, interval: 67.252898ms, delivered: 1253, prior_delivered: 333, prior_time: Some(Instant { tv_sec: 970, tv_nsec: 194441618 }), send_elapsed: 1.696457ms, ack_elapsed: 67.252898ms, rtt: 65.556441ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 72852, last_update: Instant { tv_sec: 970, tv_nsec: 194882238 }, next_time: Instant { tv_sec: 970, tv_nsec: 271414815 }, 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-12-14T03:43:12.208604682Z TRACE quiche_apps::client] written 31 bytes from [::]:58150 to [fd00:cafe:cafe:100::100]:443
[2025-12-14T03:43:12.208614651Z TRACE quiche_apps::client] [::]:58150 -> [fd00:cafe:cafe:100::100]:443: done writing
[2025-12-14T03:43:12.209413488Z TRACE quiche_apps::client] got 1232 bytes from [fd00:cafe:cafe:100::100]:443 to [::]:58150
[2025-12-14T03:43:12.209429488Z TRACE quiche] aefffa5165fad5b48a583d61131dbd5e1c48ad24 rx pkt Short dcid=aefffa5165fad5b48a583d61131dbd5e1c48ad24 key_phase=false len=1211 pn=8 
[2025-12-14T03:43:12.209440709Z TRACE quiche] aefffa5165fad5b48a583d61131dbd5e1c48ad24 rx frm STREAM id=4 off=2377 len=1188 fin=false
[2025-12-14T03:43:12.209452271Z TRACE quiche_apps::client] [::]:58150: processed 1232 bytes
[2025-12-14T03:43:12.209458202Z TRACE quiche_apps::client] [::]:58150: recv() would block
[2025-12-14T03:43:12.209462389Z TRACE quiche_apps::client] done reading
[2025-12-14T03:43:12.209469092Z TRACE quiche_apps::common] received 1188 bytes
[2025-12-14T03:43:12.209473259Z TRACE quiche_apps::common] stream 4 has 1188 bytes (fin? false)
[2025-12-14T03:43:12.209484721Z TRACE quiche] aefffa5165fad5b48a583d61131dbd5e1c48ad24 tx pkt Short dcid=32d340db3e9f2033 key_phase=false len=5 pn=12 
[2025-12-14T03:43:12.209489500Z TRACE quiche] aefffa5165fad5b48a583d61131dbd5e1c48ad24 tx frm ACK delay=6 blocks=[0..8] ecn_counts=None
[2025-12-14T03:43:12.209499839Z TRACE quiche::recovery::congestion::recovery] aefffa5165fad5b48a583d61131dbd5e1c48ad24 timer=none latest_rtt=65.556441ms srtt=231.630963ms min_rtt=65.556441ms rttvar=143.208323ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=0 app_limited=true congestion_recovery_start_time=None Rate { delivered: 1586, delivered_time: Instant { tv_sec: 970, tv_nsec: 271414815 }, first_sent_time: Instant { tv_sec: 970, tv_nsec: 271414815 }, end_of_app_limited: 5, last_sent_packet: 12, largest_acked: 4, rate_sample: RateSample { bandwidth: 149.05 Kbps, is_app_limited: true, interval: 67.252898ms, delivered: 1253, prior_delivered: 333, prior_time: Some(Instant { tv_sec: 970, tv_nsec: 194441618 }), send_elapsed: 1.696457ms, ack_elapsed: 67.252898ms, rtt: 65.556441ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 72852, last_update: Instant { tv_sec: 970, tv_nsec: 194882238 }, next_time: Instant { tv_sec: 970, tv_nsec: 271414815 }, 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-12-14T03:43:12.209561524Z TRACE quiche_apps::client] written 31 bytes from [::]:58150 to [fd00:cafe:cafe:100::100]:443
[2025-12-14T03:43:12.209569539Z TRACE quiche_apps::client] [::]:58150 -> [fd00:cafe:cafe:100::100]:443: done writing
[2025-12-14T03:43:12.210990054Z TRACE quiche_apps::client] got 1232 bytes from [fd00:cafe:cafe:100::100]:443 to [::]:58150
[2025-12-14T03:43:12.211005824Z TRACE quiche] aefffa5165fad5b48a583d61131dbd5e1c48ad24 rx pkt Short dcid=aefffa5165fad5b48a583d61131dbd5e1c48ad24 key_phase=false len=1211 pn=9 
[2025-12-14T03:43:12.211016203Z TRACE quiche] aefffa5165fad5b48a583d61131dbd5e1c48ad24 rx frm STREAM id=0 off=4753 len=367 fin=true
[2025-12-14T03:43:12.211022635Z TRACE quiche] aefffa5165fad5b48a583d61131dbd5e1c48ad24 rx frm STREAM id=4 off=3565 len=815 fin=false
[2025-12-14T03:43:12.211033856Z TRACE quiche_apps::client] [::]:58150: processed 1232 bytes
[2025-12-14T03:43:12.211039496Z TRACE quiche_apps::client] [::]:58150: recv() would block
[2025-12-14T03:43:12.211043784Z TRACE quiche_apps::client] done reading
[2025-12-14T03:43:12.211072918Z TRACE quiche_apps::common] received 367 bytes
[2025-12-14T03:43:12.211077647Z TRACE quiche_apps::common] stream 0 has 367 bytes (fin? true)
[2025-12-14T03:43:12.211082066Z DEBUG quiche_apps::common] 1/2 responses received
[2025-12-14T03:43:12.211087766Z TRACE quiche_apps::common] received 815 bytes
[2025-12-14T03:43:12.211091704Z TRACE quiche_apps::common] stream 4 has 815 bytes (fin? false)
[2025-12-14T03:43:12.211103025Z TRACE quiche] aefffa5165fad5b48a583d61131dbd5e1c48ad24 tx pkt Short dcid=32d340db3e9f2033 key_phase=false len=5 pn=13 
[2025-12-14T03:43:12.211107763Z TRACE quiche] aefffa5165fad5b48a583d61131dbd5e1c48ad24 tx frm ACK delay=12 blocks=[0..9] ecn_counts=None
[2025-12-14T03:43:12.211119345Z TRACE quiche::recovery::congestion::recovery] aefffa5165fad5b48a583d61131dbd5e1c48ad24 timer=none latest_rtt=65.556441ms srtt=231.630963ms min_rtt=65.556441ms rttvar=143.208323ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=0 app_limited=true congestion_recovery_start_time=None Rate { delivered: 1586, delivered_time: Instant { tv_sec: 970, tv_nsec: 271414815 }, first_sent_time: Instant { tv_sec: 970, tv_nsec: 271414815 }, end_of_app_limited: 5, last_sent_packet: 13, largest_acked: 4, rate_sample: RateSample { bandwidth: 149.05 Kbps, is_app_limited: true, interval: 67.252898ms, delivered: 1253, prior_delivered: 333, prior_time: Some(Instant { tv_sec: 970, tv_nsec: 194441618 }), send_elapsed: 1.696457ms, ack_elapsed: 67.252898ms, rtt: 65.556441ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 72852, last_update: Instant { tv_sec: 970, tv_nsec: 194882238 }, next_time: Instant { tv_sec: 970, tv_nsec: 271414815 }, 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-12-14T03:43:12.211199444Z TRACE quiche_apps::client] written 31 bytes from [::]:58150 to [fd00:cafe:cafe:100::100]:443
[2025-12-14T03:43:12.211207299Z TRACE quiche_apps::client] [::]:58150 -> [fd00:cafe:cafe:100::100]:443: done writing
[2025-12-14T03:43:12.211984616Z TRACE quiche_apps::client] got 1232 bytes from [fd00:cafe:cafe:100::100]:443 to [::]:58150
[2025-12-14T03:43:12.211995376Z TRACE quiche] aefffa5165fad5b48a583d61131dbd5e1c48ad24 rx pkt Short dcid=aefffa5165fad5b48a583d61131dbd5e1c48ad24 key_phase=false len=1211 pn=10 
[2025-12-14T03:43:12.212004854Z TRACE quiche] aefffa5165fad5b48a583d61131dbd5e1c48ad24 rx frm MAX_STREAMS type=bidi max=101
[2025-12-14T03:43:12.212020984Z TRACE quiche] aefffa5165fad5b48a583d61131dbd5e1c48ad24 rx frm STREAM id=4 off=4380 len=1185 fin=false
[2025-12-14T03:43:12.212032395Z TRACE quiche_apps::client] [::]:58150: processed 1232 bytes
[2025-12-14T03:43:12.212044588Z TRACE quiche_apps::client] [::]:58150: recv() would block
[2025-12-14T03:43:12.212048816Z TRACE quiche_apps::client] done reading
[2025-12-14T03:43:12.212055378Z TRACE quiche_apps::common] received 1185 bytes
[2025-12-14T03:43:12.212059455Z TRACE quiche_apps::common] stream 4 has 1185 bytes (fin? false)
[2025-12-14T03:43:12.212070306Z TRACE quiche] aefffa5165fad5b48a583d61131dbd5e1c48ad24 tx pkt Short dcid=32d340db3e9f2033 key_phase=false len=5 pn=14 
[2025-12-14T03:43:12.212075045Z TRACE quiche] aefffa5165fad5b48a583d61131dbd5e1c48ad24 tx frm ACK delay=9 blocks=[0..10] ecn_counts=None
[2025-12-14T03:43:12.212085163Z TRACE quiche::recovery::congestion::recovery] aefffa5165fad5b48a583d61131dbd5e1c48ad24 timer=none latest_rtt=65.556441ms srtt=231.630963ms min_rtt=65.556441ms rttvar=143.208323ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=0 app_limited=true congestion_recovery_start_time=None Rate { delivered: 1586, delivered_time: Instant { tv_sec: 970, tv_nsec: 271414815 }, first_sent_time: Instant { tv_sec: 970, tv_nsec: 271414815 }, end_of_app_limited: 5, last_sent_packet: 14, largest_acked: 4, rate_sample: RateSample { bandwidth: 149.05 Kbps, is_app_limited: true, interval: 67.252898ms, delivered: 1253, prior_delivered: 333, prior_time: Some(Instant { tv_sec: 970, tv_nsec: 194441618 }), send_elapsed: 1.696457ms, ack_elapsed: 67.252898ms, rtt: 65.556441ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 72852, last_update: Instant { tv_sec: 970, tv_nsec: 194882238 }, next_time: Instant { tv_sec: 970, tv_nsec: 271414815 }, 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-12-14T03:43:12.212127633Z TRACE quiche_apps::client] written 31 bytes from [::]:58150 to [fd00:cafe:cafe:100::100]:443
[2025-12-14T03:43:12.212134395Z TRACE quiche_apps::client] [::]:58150 -> [fd00:cafe:cafe:100::100]:443: done writing
[2025-12-14T03:43:12.212615421Z TRACE quiche_apps::client] got 688 bytes from [fd00:cafe:cafe:100::100]:443 to [::]:58150
[2025-12-14T03:43:12.212629648Z TRACE quiche] aefffa5165fad5b48a583d61131dbd5e1c48ad24 rx pkt Short dcid=aefffa5165fad5b48a583d61131dbd5e1c48ad24 key_phase=false len=667 pn=11 
[2025-12-14T03:43:12.212650296Z TRACE quiche] aefffa5165fad5b48a583d61131dbd5e1c48ad24 rx frm STREAM id=4 off=5565 len=644 fin=false
[2025-12-14T03:43:12.212661497Z TRACE quiche_apps::client] [::]:58150: processed 688 bytes
[2025-12-14T03:43:12.212667067Z TRACE quiche_apps::client] [::]:58150: recv() would block
[2025-12-14T03:43:12.212671185Z TRACE quiche_apps::client] done reading
[2025-12-14T03:43:12.212677457Z TRACE quiche_apps::common] received 644 bytes
[2025-12-14T03:43:12.212681594Z TRACE quiche_apps::common] stream 4 has 644 bytes (fin? false)
[2025-12-14T03:43:12.212692444Z TRACE quiche] aefffa5165fad5b48a583d61131dbd5e1c48ad24 tx pkt Short dcid=32d340db3e9f2033 key_phase=false len=5 pn=15 
[2025-12-14T03:43:12.212697113Z TRACE quiche] aefffa5165fad5b48a583d61131dbd5e1c48ad24 tx frm ACK delay=7 blocks=[0..11] ecn_counts=None
[2025-12-14T03:43:12.212706941Z TRACE quiche::recovery::congestion::recovery] aefffa5165fad5b48a583d61131dbd5e1c48ad24 timer=none latest_rtt=65.556441ms srtt=231.630963ms min_rtt=65.556441ms rttvar=143.208323ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=0 app_limited=true congestion_recovery_start_time=None Rate { delivered: 1586, delivered_time: Instant { tv_sec: 970, tv_nsec: 271414815 }, first_sent_time: Instant { tv_sec: 970, tv_nsec: 271414815 }, end_of_app_limited: 5, last_sent_packet: 15, largest_acked: 4, rate_sample: RateSample { bandwidth: 149.05 Kbps, is_app_limited: true, interval: 67.252898ms, delivered: 1253, prior_delivered: 333, prior_time: Some(Instant { tv_sec: 970, tv_nsec: 194441618 }), send_elapsed: 1.696457ms, ack_elapsed: 67.252898ms, rtt: 65.556441ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 72852, last_update: Instant { tv_sec: 970, tv_nsec: 194882238 }, next_time: Instant { tv_sec: 970, tv_nsec: 271414815 }, 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-12-14T03:43:12.212754901Z TRACE quiche_apps::client] written 31 bytes from [::]:58150 to [fd00:cafe:cafe:100::100]:443
[2025-12-14T03:43:12.212761954Z TRACE quiche_apps::client] [::]:58150 -> [fd00:cafe:cafe:100::100]:443: done writing
[2025-12-14T03:43:12.219234557Z TRACE quiche_apps::client] got 224 bytes from [fd00:cafe:cafe:100::100]:443 to [::]:58150
[2025-12-14T03:43:12.219252741Z TRACE quiche] aefffa5165fad5b48a583d61131dbd5e1c48ad24 rx pkt Short dcid=aefffa5165fad5b48a583d61131dbd5e1c48ad24 key_phase=false len=203 pn=12 
[2025-12-14T03:43:12.219263711Z TRACE quiche] aefffa5165fad5b48a583d61131dbd5e1c48ad24 rx frm STREAM id=4 off=6209 len=180 fin=false
[2025-12-14T03:43:12.219275633Z TRACE quiche_apps::client] [::]:58150: processed 224 bytes
[2025-12-14T03:43:12.219281574Z TRACE quiche_apps::client] [::]:58150: recv() would block
[2025-12-14T03:43:12.219285582Z TRACE quiche_apps::client] done reading
[2025-12-14T03:43:12.219291844Z TRACE quiche_apps::common] received 180 bytes
[2025-12-14T03:43:12.219296011Z TRACE quiche_apps::common] stream 4 has 180 bytes (fin? false)
[2025-12-14T03:43:12.219307623Z TRACE quiche] aefffa5165fad5b48a583d61131dbd5e1c48ad24 tx pkt Short dcid=32d340db3e9f2033 key_phase=false len=5 pn=16 
[2025-12-14T03:43:12.219312442Z TRACE quiche] aefffa5165fad5b48a583d61131dbd5e1c48ad24 tx frm ACK delay=6 blocks=[0..12] ecn_counts=None
[2025-12-14T03:43:12.219322481Z TRACE quiche::recovery::congestion::recovery] aefffa5165fad5b48a583d61131dbd5e1c48ad24 timer=none latest_rtt=65.556441ms srtt=231.630963ms min_rtt=65.556441ms rttvar=143.208323ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=0 app_limited=true congestion_recovery_start_time=None Rate { delivered: 1586, delivered_time: Instant { tv_sec: 970, tv_nsec: 271414815 }, first_sent_time: Instant { tv_sec: 970, tv_nsec: 271414815 }, end_of_app_limited: 5, last_sent_packet: 16, largest_acked: 4, rate_sample: RateSample { bandwidth: 149.05 Kbps, is_app_limited: true, interval: 67.252898ms, delivered: 1253, prior_delivered: 333, prior_time: Some(Instant { tv_sec: 970, tv_nsec: 194441618 }), send_elapsed: 1.696457ms, ack_elapsed: 67.252898ms, rtt: 65.556441ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 72852, last_update: Instant { tv_sec: 970, tv_nsec: 194882238 }, next_time: Instant { tv_sec: 970, tv_nsec: 271414815 }, 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-12-14T03:43:12.219378695Z TRACE quiche_apps::client] written 31 bytes from [::]:58150 to [fd00:cafe:cafe:100::100]:443
[2025-12-14T03:43:12.219387852Z TRACE quiche_apps::client] [::]:58150 -> [fd00:cafe:cafe:100::100]:443: done writing
[2025-12-14T03:43:12.224597414Z TRACE quiche_apps::client] got 224 bytes from [fd00:cafe:cafe:100::100]:443 to [::]:58150
[2025-12-14T03:43:12.224614405Z TRACE quiche] aefffa5165fad5b48a583d61131dbd5e1c48ad24 rx pkt Short dcid=aefffa5165fad5b48a583d61131dbd5e1c48ad24 key_phase=false len=203 pn=13 
[2025-12-14T03:43:12.224624374Z TRACE quiche] aefffa5165fad5b48a583d61131dbd5e1c48ad24 rx frm STREAM id=4 off=6389 len=180 fin=false
[2025-12-14T03:43:12.224636196Z TRACE quiche_apps::client] [::]:58150: processed 224 bytes
[2025-12-14T03:43:12.224646716Z TRACE quiche_apps::client] [::]:58150: recv() would block
[2025-12-14T03:43:12.224649601Z TRACE quiche_apps::client] done reading
[2025-12-14T03:43:12.224655061Z TRACE quiche_apps::common] received 180 bytes
[2025-12-14T03:43:12.224658297Z TRACE quiche_apps::common] stream 4 has 180 bytes (fin? false)
[2025-12-14T03:43:12.224669628Z TRACE quiche] aefffa5165fad5b48a583d61131dbd5e1c48ad24 tx pkt Short dcid=32d340db3e9f2033 key_phase=false len=5 pn=17 
[2025-12-14T03:43:12.224673074Z TRACE quiche] aefffa5165fad5b48a583d61131dbd5e1c48ad24 tx frm ACK delay=6 blocks=[0..13] ecn_counts=None
[2025-12-14T03:43:12.224682542Z TRACE quiche::recovery::congestion::recovery] aefffa5165fad5b48a583d61131dbd5e1c48ad24 timer=none latest_rtt=65.556441ms srtt=231.630963ms min_rtt=65.556441ms rttvar=143.208323ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=0 app_limited=true congestion_recovery_start_time=None Rate { delivered: 1586, delivered_time: Instant { tv_sec: 970, tv_nsec: 271414815 }, first_sent_time: Instant { tv_sec: 970, tv_nsec: 271414815 }, end_of_app_limited: 5, last_sent_packet: 17, largest_acked: 4, rate_sample: RateSample { bandwidth: 149.05 Kbps, is_app_limited: true, interval: 67.252898ms, delivered: 1253, prior_delivered: 333, prior_time: Some(Instant { tv_sec: 970, tv_nsec: 194441618 }), send_elapsed: 1.696457ms, ack_elapsed: 67.252898ms, rtt: 65.556441ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 72852, last_update: Instant { tv_sec: 970, tv_nsec: 194882238 }, next_time: Instant { tv_sec: 970, tv_nsec: 271414815 }, 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-12-14T03:43:12.224722246Z TRACE quiche_apps::client] written 31 bytes from [::]:58150 to [fd00:cafe:cafe:100::100]:443
[2025-12-14T03:43:12.224731103Z TRACE quiche_apps::client] [::]:58150 -> [fd00:cafe:cafe:100::100]:443: done writing
[2025-12-14T03:43:12.233078647Z TRACE quiche_apps::client] got 1232 bytes from [fd00:cafe:cafe:100::100]:443 to [::]:58150
[2025-12-14T03:43:12.233098404Z TRACE quiche] aefffa5165fad5b48a583d61131dbd5e1c48ad24 rx pkt Short dcid=aefffa5165fad5b48a583d61131dbd5e1c48ad24 key_phase=false len=1211 pn=14 
[2025-12-14T03:43:12.233109545Z TRACE quiche] aefffa5165fad5b48a583d61131dbd5e1c48ad24 rx frm STREAM id=4 off=6569 len=1188 fin=false
[2025-12-14T03:43:12.233122369Z TRACE quiche_apps::client] [::]:58150: processed 1232 bytes
[2025-12-14T03:43:12.233127659Z TRACE quiche_apps::client] [::]:58150: recv() would block
[2025-12-14T03:43:12.233131115Z TRACE quiche_apps::client] done reading
[2025-12-14T03:43:12.233137527Z TRACE quiche_apps::common] received 1188 bytes
[2025-12-14T03:43:12.233141364Z TRACE quiche_apps::common] stream 4 has 1188 bytes (fin? false)
[2025-12-14T03:43:12.233182852Z TRACE quiche] aefffa5165fad5b48a583d61131dbd5e1c48ad24 tx pkt Short dcid=32d340db3e9f2033 key_phase=false len=5 pn=18 
[2025-12-14T03:43:12.233194754Z TRACE quiche] aefffa5165fad5b48a583d61131dbd5e1c48ad24 tx frm ACK delay=10 blocks=[0..14] ecn_counts=None
[2025-12-14T03:43:12.233210894Z TRACE quiche::recovery::congestion::recovery] aefffa5165fad5b48a583d61131dbd5e1c48ad24 timer=none latest_rtt=65.556441ms srtt=231.630963ms min_rtt=65.556441ms rttvar=143.208323ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=0 app_limited=true congestion_recovery_start_time=None Rate { delivered: 1586, delivered_time: Instant { tv_sec: 970, tv_nsec: 271414815 }, first_sent_time: Instant { tv_sec: 970, tv_nsec: 271414815 }, end_of_app_limited: 5, last_sent_packet: 18, largest_acked: 4, rate_sample: RateSample { bandwidth: 149.05 Kbps, is_app_limited: true, interval: 67.252898ms, delivered: 1253, prior_delivered: 333, prior_time: Some(Instant { tv_sec: 970, tv_nsec: 194441618 }), send_elapsed: 1.696457ms, ack_elapsed: 67.252898ms, rtt: 65.556441ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 72852, last_update: Instant { tv_sec: 970, tv_nsec: 194882238 }, next_time: Instant { tv_sec: 970, tv_nsec: 271414815 }, 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-12-14T03:43:12.233269964Z TRACE quiche_apps::client] written 31 bytes from [::]:58150 to [fd00:cafe:cafe:100::100]:443
[2025-12-14T03:43:12.233281455Z TRACE quiche_apps::client] [::]:58150 -> [fd00:cafe:cafe:100::100]:443: done writing
[2025-12-14T03:43:12.234890792Z TRACE quiche_apps::client] got 1232 bytes from [fd00:cafe:cafe:100::100]:443 to [::]:58150
[2025-12-14T03:43:12.234907884Z TRACE quiche] aefffa5165fad5b48a583d61131dbd5e1c48ad24 rx pkt Short dcid=aefffa5165fad5b48a583d61131dbd5e1c48ad24 key_phase=false len=1211 pn=15 
[2025-12-14T03:43:12.234920227Z TRACE quiche] aefffa5165fad5b48a583d61131dbd5e1c48ad24 rx frm STREAM id=4 off=7757 len=1188 fin=false
[2025-12-14T03:43:12.234932269Z TRACE quiche_apps::client] [::]:58150: processed 1232 bytes
[2025-12-14T03:43:12.234939122Z TRACE quiche_apps::client] [::]:58150: recv() would block
[2025-12-14T03:43:12.234943691Z TRACE quiche_apps::client] done reading
[2025-12-14T03:43:12.234951165Z TRACE quiche_apps::common] received 1188 bytes
[2025-12-14T03:43:12.234955833Z TRACE quiche_apps::common] stream 4 has 1188 bytes (fin? false)
[2025-12-14T03:43:12.235004113Z TRACE quiche] aefffa5165fad5b48a583d61131dbd5e1c48ad24 tx pkt Short dcid=32d340db3e9f2033 key_phase=false len=5 pn=19 
[2025-12-14T03:43:12.235011026Z TRACE quiche] aefffa5165fad5b48a583d61131dbd5e1c48ad24 tx frm ACK delay=11 blocks=[0..15] ecn_counts=None
[2025-12-14T03:43:12.235038677Z TRACE quiche::recovery::congestion::recovery] aefffa5165fad5b48a583d61131dbd5e1c48ad24 timer=none latest_rtt=65.556441ms srtt=231.630963ms min_rtt=65.556441ms rttvar=143.208323ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=0 app_limited=true congestion_recovery_start_time=None Rate { delivered: 1586, delivered_time: Instant { tv_sec: 970, tv_nsec: 271414815 }, first_sent_time: Instant { tv_sec: 970, tv_nsec: 271414815 }, end_of_app_limited: 5, last_sent_packet: 19, largest_acked: 4, rate_sample: RateSample { bandwidth: 149.05 Kbps, is_app_limited: true, interval: 67.252898ms, delivered: 1253, prior_delivered: 333, prior_time: Some(Instant { tv_sec: 970, tv_nsec: 194441618 }), send_elapsed: 1.696457ms, ack_elapsed: 67.252898ms, rtt: 65.556441ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 72852, last_update: Instant { tv_sec: 970, tv_nsec: 194882238 }, next_time: Instant { tv_sec: 970, tv_nsec: 271414815 }, 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-12-14T03:43:12.235086837Z TRACE quiche_apps::client] written 31 bytes from [::]:58150 to [fd00:cafe:cafe:100::100]:443
[2025-12-14T03:43:12.235095674Z TRACE quiche_apps::client] [::]:58150 -> [fd00:cafe:cafe:100::100]:443: done writing
[2025-12-14T03:43:12.235821498Z TRACE quiche_apps::client] got 1232 bytes from [fd00:cafe:cafe:100::100]:443 to [::]:58150
[2025-12-14T03:43:12.235834933Z TRACE quiche] aefffa5165fad5b48a583d61131dbd5e1c48ad24 rx pkt Short dcid=aefffa5165fad5b48a583d61131dbd5e1c48ad24 key_phase=false len=1211 pn=16 
[2025-12-14T03:43:12.235843028Z TRACE quiche] aefffa5165fad5b48a583d61131dbd5e1c48ad24 rx frm STREAM id=4 off=8945 len=1188 fin=false
[2025-12-14T03:43:12.235851944Z TRACE quiche_apps::client] [::]:58150: processed 1232 bytes
[2025-12-14T03:43:12.235861853Z TRACE quiche_apps::client] [::]:58150: recv() would block
[2025-12-14T03:43:12.235864778Z TRACE quiche_apps::client] done reading
[2025-12-14T03:43:12.235869808Z TRACE quiche_apps::common] received 1188 bytes
[2025-12-14T03:43:12.235872603Z TRACE quiche_apps::common] stream 4 has 1188 bytes (fin? false)
[2025-12-14T03:43:12.235881239Z TRACE quiche] aefffa5165fad5b48a583d61131dbd5e1c48ad24 tx pkt Short dcid=32d340db3e9f2033 key_phase=false len=5 pn=20 
[2025-12-14T03:43:12.235884585Z TRACE quiche] aefffa5165fad5b48a583d61131dbd5e1c48ad24 tx frm ACK delay=5 blocks=[0..16] ecn_counts=None
[2025-12-14T03:43:12.235892159Z TRACE quiche::recovery::congestion::recovery] aefffa5165fad5b48a583d61131dbd5e1c48ad24 timer=none latest_rtt=65.556441ms srtt=231.630963ms min_rtt=65.556441ms rttvar=143.208323ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=0 app_limited=true congestion_recovery_start_time=None Rate { delivered: 1586, delivered_time: Instant { tv_sec: 970, tv_nsec: 271414815 }, first_sent_time: Instant { tv_sec: 970, tv_nsec: 271414815 }, end_of_app_limited: 5, last_sent_packet: 20, largest_acked: 4, rate_sample: RateSample { bandwidth: 149.05 Kbps, is_app_limited: true, interval: 67.252898ms, delivered: 1253, prior_delivered: 333, prior_time: Some(Instant { tv_sec: 970, tv_nsec: 194441618 }), send_elapsed: 1.696457ms, ack_elapsed: 67.252898ms, rtt: 65.556441ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 72852, last_update: Instant { tv_sec: 970, tv_nsec: 194882238 }, next_time: Instant { tv_sec: 970, tv_nsec: 271414815 }, 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-12-14T03:43:12.235926984Z TRACE quiche_apps::client] written 31 bytes from [::]:58150 to [fd00:cafe:cafe:100::100]:443
[2025-12-14T03:43:12.235935430Z TRACE quiche_apps::client] [::]:58150 -> [fd00:cafe:cafe:100::100]:443: done writing
[2025-12-14T03:43:12.235995933Z TRACE quiche_apps::client] got 154 bytes from [fd00:cafe:cafe:100::100]:443 to [::]:58150
[2025-12-14T03:43:12.236003507Z TRACE quiche] aefffa5165fad5b48a583d61131dbd5e1c48ad24 rx pkt Short dcid=aefffa5165fad5b48a583d61131dbd5e1c48ad24 key_phase=false len=133 pn=17 
[2025-12-14T03:43:12.236009999Z TRACE quiche] aefffa5165fad5b48a583d61131dbd5e1c48ad24 rx frm STREAM id=4 off=10133 len=107 fin=true
[2025-12-14T03:43:12.236014117Z TRACE quiche] aefffa5165fad5b48a583d61131dbd5e1c48ad24 rx frm MAX_STREAMS type=bidi max=102
[2025-12-14T03:43:12.236021991Z TRACE quiche_apps::client] [::]:58150: processed 154 bytes
[2025-12-14T03:43:12.236025899Z TRACE quiche_apps::client] [::]:58150: recv() would block
[2025-12-14T03:43:12.236028593Z TRACE quiche_apps::client] done reading
[2025-12-14T03:43:12.236034324Z TRACE quiche_apps::common] received 107 bytes
[2025-12-14T03:43:12.236037069Z TRACE quiche_apps::common] stream 4 has 107 bytes (fin? true)
[2025-12-14T03:43:12.236039874Z DEBUG quiche_apps::common] 2/2 responses received
[2025-12-14T03:43:12.236042770Z INFO  quiche_apps::common] 2/2 response(s) received in 362.304789ms, closing...
[2025-12-14T03:43:12.236050394Z TRACE quiche] aefffa5165fad5b48a583d61131dbd5e1c48ad24 tx pkt Short dcid=32d340db3e9f2033 key_phase=false len=10 pn=21 
[2025-12-14T03:43:12.236053600Z TRACE quiche] aefffa5165fad5b48a583d61131dbd5e1c48ad24 tx frm APPLICATION_CLOSE err=0 reason=[6b, 74, 68, 78, 62, 79, 65]
[2025-12-14T03:43:12.236062396Z TRACE quiche::recovery::congestion::recovery] aefffa5165fad5b48a583d61131dbd5e1c48ad24 timer=829.448386ms latest_rtt=65.556441ms srtt=231.630963ms min_rtt=65.556441ms rttvar=143.208323ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=36 app_limited=true congestion_recovery_start_time=None Rate { delivered: 1586, delivered_time: Instant { tv_sec: 970, tv_nsec: 271414815 }, first_sent_time: Instant { tv_sec: 970, tv_nsec: 271414815 }, end_of_app_limited: 20, last_sent_packet: 21, largest_acked: 4, rate_sample: RateSample { bandwidth: 149.05 Kbps, is_app_limited: true, interval: 67.252898ms, delivered: 1253, prior_delivered: 333, prior_time: Some(Instant { tv_sec: 970, tv_nsec: 194441618 }), send_elapsed: 1.696457ms, ack_elapsed: 67.252898ms, rtt: 65.556441ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 72852, last_update: Instant { tv_sec: 970, tv_nsec: 300902933 }, next_time: Instant { tv_sec: 970, tv_nsec: 271414815 }, max_datagram_size: 1350, last_packet_size: None, iv: 494.153µ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-12-14T03:43:12.236101529Z TRACE quiche_apps::client] written 36 bytes from [::]:58150 to [fd00:cafe:cafe:100::100]:443
[2025-12-14T03:43:12.236109484Z TRACE quiche_apps::client] [::]:58150 -> [fd00:cafe:cafe:100::100]:443: done writing
[2025-12-14T03:43:12.276694788Z TRACE quiche_apps::client] got 42 bytes from [fd00:cafe:cafe:100::100]:443 to [::]:58150
[2025-12-14T03:43:12.276728861Z TRACE quiche_apps::client] [::]:58150: processed 42 bytes
[2025-12-14T03:43:12.276735143Z TRACE quiche_apps::client] [::]:58150: recv() would block
[2025-12-14T03:43:12.276739140Z TRACE quiche_apps::client] done reading
[2025-12-14T03:43:12.276750281Z TRACE quiche_apps::client] [::]:58150 -> [fd00:cafe:cafe:100::100]:443: done writing
[2025-12-14T03:43:14.652184849Z TRACE quiche_apps::client] timed out
[2025-12-14T03:43:14.652218592Z TRACE quiche] aefffa5165fad5b48a583d61131dbd5e1c48ad24 draining timeout expired
[2025-12-14T03:43:14.652264317Z TRACE quiche_apps::client] done reading
[2025-12-14T03:43:14.652270579Z INFO  quiche_apps::client] connection closed, recv=20 sent=22 lost=0 retrans=0 sent_bytes=2279 recv_bytes=17542 lost_bytes=0 [local_addr=[::]:58150 peer_addr=[fd00:cafe:cafe:100::100]:443 validation_state=Validated active=true recv=20 sent=22 lost=0 retrans=0 rtt=231.630963ms min_rtt=Some(65.556441ms) rttvar=143.208323ms cwnd=13500 sent_bytes=2279 recv_bytes=17542 lost_bytes=0 stream_retrans_bytes=0 pmtu=1350 delivery_rate=18631]