[2025-04-30T08:49:36.356533043Z TRACE mio::poll] registering event source with poller: token=Token(0), interests=READABLE
[2025-04-30T08:49:36.356821161Z INFO  quiche_apps::client] connecting to [fd00:cafe:cafe:100::100]:443 from [::]:56234 with scid f8a846691887a508a3d7d0902544d1c923e3f979
[2025-04-30T08:49:36.356860624Z TRACE quiche::tls] f8a846691887a508a3d7d0902544d1c923e3f979 write message lvl=Initial len=266
[2025-04-30T08:49:36.356917590Z TRACE quiche] f8a846691887a508a3d7d0902544d1c923e3f979 tx pkt Initial version=1 dcid=e9cd34e62d11f681ac5abc1af2d5c6a6 scid=f8a846691887a508a3d7d0902544d1c923e3f979 len=270 pn=0 
[2025-04-30T08:49:36.356924403Z TRACE quiche] f8a846691887a508a3d7d0902544d1c923e3f979 tx frm CRYPTO off=0 len=266
[2025-04-30T08:49:36.356939030Z TRACE quiche::recovery::congestion::recovery] f8a846691887a508a3d7d0902544d1c923e3f979 timer=998.889033ms 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: 710, tv_nsec: 724954243 }, first_sent_time: Instant { tv_sec: 710, tv_nsec: 724954243 }, end_of_app_limited: 1, last_sent_packet: 0, largest_acked: 0, rate_sample: RateSample { delivery_rate: 0, is_app_limited: false, interval: 0ns, delivered: 0, prior_delivered: 0, prior_time: None, send_elapsed: 0ns, ack_elapsed: 0ns, rtt: 0ns } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 0, last_update: Instant { tv_sec: 710, tv_nsec: 724954243 }, next_time: Instant { tv_sec: 710, tv_nsec: 724954243 }, max_datagram_size: 1350, last_packet_size: None, iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } 
[2025-04-30T08:49:36.356989334Z TRACE quiche_apps::client] written 1200
[2025-04-30T08:49:36.398381383Z TRACE quiche_apps::client] got 1200 bytes from [fd00:cafe:cafe:100::100]:443 to [::]:56234
[2025-04-30T08:49:36.398404857Z TRACE quiche] f8a846691887a508a3d7d0902544d1c923e3f979 rx pkt Initial version=1 dcid=f8a846691887a508a3d7d0902544d1c923e3f979 scid=96a38cf8a0e01c607f89d7319f96a003825b token= len=119 pn=294871054 
[2025-04-30T08:49:36.398419554Z TRACE quiche] f8a846691887a508a3d7d0902544d1c923e3f979 rx frm ACK delay=0 blocks=[0..0] ecn_counts=None
[2025-04-30T08:49:36.398425745Z TRACE quiche::recovery::congestion::recovery] f8a846691887a508a3d7d0902544d1c923e3f979 packet newly acked 0
[2025-04-30T08:49:36.398431596Z TRACE quiche] f8a846691887a508a3d7d0902544d1c923e3f979 rx frm CRYPTO off=0 len=90
[2025-04-30T08:49:36.398525732Z TRACE quiche::tls] f8a846691887a508a3d7d0902544d1c923e3f979 set write secret lvl=Handshake
[2025-04-30T08:49:36.398536983Z TRACE quiche::tls] f8a846691887a508a3d7d0902544d1c923e3f979 set read secret lvl=Handshake
[2025-04-30T08:49:36.398568181Z TRACE quiche] f8a846691887a508a3d7d0902544d1c923e3f979 rx pkt Handshake version=1 dcid=f8a846691887a508a3d7d0902544d1c923e3f979 scid=96a38cf8a0e01c607f89d7319f96a003825b len=736 pn=294871054 
[2025-04-30T08:49:36.398574944Z TRACE quiche] f8a846691887a508a3d7d0902544d1c923e3f979 rx frm CRYPTO off=0 len=712
[2025-04-30T08:49:36.398768384Z TRACE quiche::tls] f8a846691887a508a3d7d0902544d1c923e3f979 write message lvl=Handshake len=36
[2025-04-30T08:49:36.398772252Z TRACE quiche::tls] f8a846691887a508a3d7d0902544d1c923e3f979 set write secret lvl=OneRTT
[2025-04-30T08:49:36.398779014Z TRACE quiche::tls] f8a846691887a508a3d7d0902544d1c923e3f979 set read secret lvl=OneRTT
[2025-04-30T08:49:36.398794143Z TRACE quiche] f8a846691887a508a3d7d0902544d1c923e3f979 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(e9cd34e62d11f681ac5abc1af2d5c6a6), max_idle_timeout: 30000, stateless_reset_token: Some(329860246912624946779230999635764952240), max_udp_payload_size: 65527, initial_max_data: 1048576, initial_max_stream_data_bidi_local: 0, initial_max_stream_data_bidi_remote: 262144, initial_max_stream_data_uni: 262144, initial_max_streams_bidi: 100, initial_max_streams_uni: 0, ack_delay_exponent: 3, max_ack_delay: 25, disable_active_migration: false, active_conn_id_limit: 7, initial_source_connection_id: Some(96a38cf8a0e01c607f89d7319f96a003825b), retry_source_connection_id: None, max_datagram_frame_size: None, unknown_params: None }
[2025-04-30T08:49:36.398823006Z TRACE quiche] f8a846691887a508a3d7d0902544d1c923e3f979 rx pkt Short dcid=f8a846691887a508a3d7d0902544d1c923e3f979 key_phase=false len=225 pn=294871054 
[2025-04-30T08:49:36.398829939Z TRACE quiche] f8a846691887a508a3d7d0902544d1c923e3f979 rx frm NEW_CONNECTION_ID seq_num=7 retire_prior_to=0 conn_id=[58, 0b, 22, 5d, 37, c1, c9, 36, a1, 8f, b5, 65, fb, 5f, 8a, 55, 5b, ae] reset_token=[0d, 7a, be, c9, 4e, 48, ba, 12, 01, 52, 1b, 59, 0d, f3, f0, ba]
[2025-04-30T08:49:36.398837664Z TRACE quiche] f8a846691887a508a3d7d0902544d1c923e3f979 rx frm NEW_CONNECTION_ID seq_num=6 retire_prior_to=0 conn_id=[09, 0e, ca, 59, f9, 72, 91, 1b, 48, cd, c9, fd, 50, 04, 75, 06, 0a, 6e] reset_token=[ef, 20, f0, ae, e8, f4, 33, 4b, 44, ef, c3, 9a, c0, 88, b7, 59]
[2025-04-30T08:49:36.398843455Z TRACE quiche] f8a846691887a508a3d7d0902544d1c923e3f979 rx frm NEW_CONNECTION_ID seq_num=5 retire_prior_to=0 conn_id=[ab, 91, 27, 9b, 1f, f2, c5, 25, 49, 91, 73, 39, bd, 64, b9, 6d, 78, 9b] reset_token=[a8, c0, b8, 15, c7, 66, 8a, 04, 90, 09, f9, 37, 25, 2e, a7, 29]
[2025-04-30T08:49:36.398848744Z TRACE quiche] f8a846691887a508a3d7d0902544d1c923e3f979 rx frm NEW_CONNECTION_ID seq_num=4 retire_prior_to=0 conn_id=[a4, 13, 9a, 7e, 62, 66, f9, aa, dd, c1, bd, 97, 03, f7, b3, a0, ee, 4d] reset_token=[5d, d0, 45, 0a, 09, eb, eb, b3, fb, e6, 0a, 3d, e9, ba, cf, 54]
[2025-04-30T08:49:36.398854325Z TRACE quiche] f8a846691887a508a3d7d0902544d1c923e3f979 rx frm NEW_CONNECTION_ID seq_num=3 retire_prior_to=0 conn_id=[8e, 17, 11, b0, 8c, e3, 91, 19, 98, cf, 6f, fe, c8, 82, 91, 2d, e4, 27] reset_token=[f7, 2c, e5, b6, 7f, 40, 0c, 25, d5, 16, 97, 50, 94, 56, 26, 56]
[2025-04-30T08:49:36.398858412Z TRACE quiche] f8a846691887a508a3d7d0902544d1c923e3f979 rx frm PADDING len=15
[2025-04-30T08:49:36.398865165Z TRACE quiche_apps::client] [::]:56234: processed 1200 bytes
[2025-04-30T08:49:36.398869683Z TRACE quiche_apps::client] [::]:56234: recv() would block
[2025-04-30T08:49:36.398872268Z TRACE quiche_apps::client] done reading
[2025-04-30T08:49:36.398905260Z DEBUG quiche_apps::common] sending HTTP request "GET /rhfvrkjgim\r\n"
[2025-04-30T08:49:36.398956525Z DEBUG quiche_apps::common] sending HTTP request "GET /jcqdbagwae\r\n"
[2025-04-30T08:49:36.399001630Z TRACE quiche] f8a846691887a508a3d7d0902544d1c923e3f979 tx pkt Initial version=1 dcid=96a38cf8a0e01c607f89d7319f96a003825b scid=f8a846691887a508a3d7d0902544d1c923e3f979 len=9 pn=1 
[2025-04-30T08:49:36.399005326Z TRACE quiche] f8a846691887a508a3d7d0902544d1c923e3f979 tx frm ACK delay=74 blocks=[294871054..294871054] ecn_counts=None
[2025-04-30T08:49:36.399014423Z TRACE quiche::recovery::congestion::recovery] f8a846691887a508a3d7d0902544d1c923e3f979 timer=124.097408ms latest_rtt=41.570912ms srtt=41.570912ms min_rtt=41.570912ms rttvar=20.785456ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=0 app_limited=true congestion_recovery_start_time=None Rate { delivered: 333, delivered_time: Instant { tv_sec: 710, tv_nsec: 766917797 }, first_sent_time: Instant { tv_sec: 710, tv_nsec: 766917797 }, end_of_app_limited: 1, last_sent_packet: 1, largest_acked: 0, rate_sample: RateSample { delivery_rate: 8010, is_app_limited: true, interval: 41.570912ms, delivered: 333, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 710, tv_nsec: 724954243 }), send_elapsed: 0ns, ack_elapsed: 41.570912ms, rtt: 41.570912ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 405932, last_update: Instant { tv_sec: 710, tv_nsec: 766917767 }, next_time: Instant { tv_sec: 710, tv_nsec: 766917797 }, max_datagram_size: 1350, last_packet_size: Some(0), iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } 
[2025-04-30T08:49:36.399040091Z TRACE quiche] f8a846691887a508a3d7d0902544d1c923e3f979 tx pkt Handshake version=1 dcid=96a38cf8a0e01c607f89d7319f96a003825b scid=f8a846691887a508a3d7d0902544d1c923e3f979 len=48 pn=2 
[2025-04-30T08:49:36.399043027Z TRACE quiche] f8a846691887a508a3d7d0902544d1c923e3f979 tx frm ACK delay=58 blocks=[294871054..294871054] ecn_counts=None
[2025-04-30T08:49:36.399045712Z TRACE quiche] f8a846691887a508a3d7d0902544d1c923e3f979 tx frm CRYPTO off=0 len=36
[2025-04-30T08:49:36.399051913Z TRACE quiche::recovery::congestion::recovery] f8a846691887a508a3d7d0902544d1c923e3f979 timer=124.653145ms latest_rtt=41.570912ms srtt=41.570912ms min_rtt=41.570912ms rttvar=20.785456ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=112 app_limited=true congestion_recovery_start_time=None Rate { delivered: 333, delivered_time: Instant { tv_sec: 710, tv_nsec: 766917797 }, first_sent_time: Instant { tv_sec: 710, tv_nsec: 766917797 }, end_of_app_limited: 1, last_sent_packet: 2, largest_acked: 0, rate_sample: RateSample { delivery_rate: 8010, is_app_limited: true, interval: 41.570912ms, delivered: 333, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 710, tv_nsec: 724954243 }), send_elapsed: 0ns, ack_elapsed: 41.570912ms, rtt: 41.570912ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 405932, last_update: Instant { tv_sec: 710, tv_nsec: 767118131 }, next_time: Instant { tv_sec: 710, tv_nsec: 766917797 }, max_datagram_size: 1350, last_packet_size: None, iv: 275.908µs, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } 
[2025-04-30T08:49:36.399063104Z TRACE quiche] f8a846691887a508a3d7d0902544d1c923e3f979 dropped epoch 0 state
[2025-04-30T08:49:36.399067983Z TRACE quiche] f8a846691887a508a3d7d0902544d1c923e3f979 pmtud probe status false hs_con=false hs_sent=false cwnd_avail=13388 out_len=1164 left=1120
[2025-04-30T08:49:36.399079114Z TRACE quiche] f8a846691887a508a3d7d0902544d1c923e3f979 tx pkt Short dcid=96a38cf8a0e01c607f89d7319f96a003825b key_phase=false len=1128 pn=3 
[2025-04-30T08:49:36.399081669Z TRACE quiche] f8a846691887a508a3d7d0902544d1c923e3f979 tx frm ACK delay=30 blocks=[294871054..294871054] ecn_counts=None
[2025-04-30T08:49:36.399084293Z TRACE quiche] f8a846691887a508a3d7d0902544d1c923e3f979 tx frm NEW_CONNECTION_ID seq_num=1 retire_prior_to=0 conn_id=[37, 0b, b3, c2, 69, 63, 1b, d2, 99, 74, e4, 28, 54, 5b, 35, f7, 1e, 8e, f1, 85] reset_token=[ab, a5, 74, a3, 13, b5, 85, 0b, 6f, 08, ee, b3, 09, e0, 91, 2d]
[2025-04-30T08:49:36.399090395Z TRACE quiche] f8a846691887a508a3d7d0902544d1c923e3f979 tx frm NEW_CONNECTION_ID seq_num=2 retire_prior_to=0 conn_id=[18, 1a, 0c, 45, 60, a0, 87, c2, ec, a7, c8, ec, e5, 5d, 17, df, 90, 0f, aa, ff] reset_token=[3b, 5b, 10, a8, 9b, 32, b2, 11, 76, a1, be, 92, 58, 19, f1, c8]
[2025-04-30T08:49:36.399095935Z TRACE quiche] f8a846691887a508a3d7d0902544d1c923e3f979 tx frm NEW_CONNECTION_ID seq_num=3 retire_prior_to=0 conn_id=[ef, 91, 97, b2, dc, f5, 9c, 35, af, 81, 7b, 59, e9, 43, 43, d8, 5e, 5f, a1, e0] reset_token=[84, 45, 23, 93, 22, d9, 14, 80, 58, 69, d0, d4, 01, af, 4c, 9d]
[2025-04-30T08:49:36.399101225Z TRACE quiche] f8a846691887a508a3d7d0902544d1c923e3f979 tx frm NEW_CONNECTION_ID seq_num=4 retire_prior_to=0 conn_id=[0d, 31, c1, 98, 9c, 4c, 61, f2, ce, ad, f4, ae, 7c, 42, 25, 37, 91, 04, 96, 31] reset_token=[b6, 18, c3, 70, c0, 95, 1c, f9, a9, 77, 19, 7c, 9c, 38, 4a, f2]
[2025-04-30T08:49:36.399106555Z TRACE quiche] f8a846691887a508a3d7d0902544d1c923e3f979 tx frm NEW_CONNECTION_ID seq_num=5 retire_prior_to=0 conn_id=[31, 6d, ed, a0, 3e, 04, 42, 4e, bc, 73, 71, 1c, 66, c5, ca, 85, 9c, f4, cd, 18] reset_token=[f6, 98, 82, 0b, 9a, 06, 03, fe, 1c, 58, e8, 8c, 20, c5, c6, cd]
[2025-04-30T08:49:36.399114991Z TRACE quiche] f8a846691887a508a3d7d0902544d1c923e3f979 tx frm NEW_CONNECTION_ID seq_num=6 retire_prior_to=0 conn_id=[82, 31, b3, a1, a9, a9, fd, 45, 32, cd, 8c, 97, 34, 6e, 71, 21, 38, 83, 63, fa] reset_token=[5c, d5, 30, 0e, 6a, 75, 27, d2, 93, 12, 20, 0f, 23, 31, bd, 02]
[2025-04-30T08:49:36.399120371Z TRACE quiche] f8a846691887a508a3d7d0902544d1c923e3f979 tx frm STREAM id=0 off=0 len=17 fin=true
[2025-04-30T08:49:36.399122936Z TRACE quiche] f8a846691887a508a3d7d0902544d1c923e3f979 tx frm PADDING len=858
[2025-04-30T08:49:36.399131341Z TRACE quiche::recovery::congestion::recovery] f8a846691887a508a3d7d0902544d1c923e3f979 timer=124.573717ms latest_rtt=41.570912ms srtt=41.570912ms min_rtt=41.570912ms rttvar=20.785456ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=1276 app_limited=true congestion_recovery_start_time=None Rate { delivered: 333, delivered_time: Instant { tv_sec: 710, tv_nsec: 766917797 }, first_sent_time: Instant { tv_sec: 710, tv_nsec: 766917797 }, end_of_app_limited: 2, last_sent_packet: 3, largest_acked: 0, rate_sample: RateSample { delivery_rate: 8010, is_app_limited: true, interval: 41.570912ms, delivered: 333, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 710, tv_nsec: 724954243 }), send_elapsed: 0ns, ack_elapsed: 41.570912ms, rtt: 41.570912ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 1164, rate: 405932, last_update: Instant { tv_sec: 710, tv_nsec: 767118131 }, next_time: Instant { tv_sec: 710, tv_nsec: 767394039 }, max_datagram_size: 1350, last_packet_size: Some(1164), iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } 
[2025-04-30T08:49:36.399167559Z TRACE quiche_apps::client] written 1350 bytes from [::]:56234 to [fd00:cafe:cafe:100::100]:443
[2025-04-30T08:49:36.399174121Z TRACE quiche] f8a846691887a508a3d7d0902544d1c923e3f979 pmtud probe status false hs_con=false hs_sent=false cwnd_avail=12224 out_len=1350 left=1314
[2025-04-30T08:49:36.399177518Z TRACE quiche] f8a846691887a508a3d7d0902544d1c923e3f979 tx pkt Short dcid=96a38cf8a0e01c607f89d7319f96a003825b key_phase=false len=22 pn=4 
[2025-04-30T08:49:36.399179932Z TRACE quiche] f8a846691887a508a3d7d0902544d1c923e3f979 tx frm STREAM id=4 off=0 len=17 fin=true
[2025-04-30T08:49:36.399185012Z TRACE quiche::recovery::congestion::recovery] f8a846691887a508a3d7d0902544d1c923e3f979 timer=124.520047ms latest_rtt=41.570912ms srtt=41.570912ms min_rtt=41.570912ms rttvar=20.785456ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=1334 app_limited=true congestion_recovery_start_time=None Rate { delivered: 333, delivered_time: Instant { tv_sec: 710, tv_nsec: 766917797 }, first_sent_time: Instant { tv_sec: 710, tv_nsec: 766917797 }, end_of_app_limited: 3, last_sent_packet: 4, largest_acked: 0, rate_sample: RateSample { delivery_rate: 8010, is_app_limited: true, interval: 41.570912ms, delivered: 333, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 710, tv_nsec: 724954243 }), send_elapsed: 0ns, ack_elapsed: 41.570912ms, rtt: 41.570912ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 405932, last_update: Instant { tv_sec: 710, tv_nsec: 767297084 }, next_time: Instant { tv_sec: 710, tv_nsec: 767394039 }, max_datagram_size: 1350, last_packet_size: None, iv: 3.010356ms, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } 
[2025-04-30T08:49:36.399207714Z TRACE quiche_apps::client] written 58 bytes from [::]:56234 to [fd00:cafe:cafe:100::100]:443
[2025-04-30T08:49:36.399215418Z TRACE quiche_apps::client] [::]:56234 -> [fd00:cafe:cafe:100::100]:443: done writing
[2025-04-30T08:49:36.399350931Z TRACE quiche_apps::client] got 1200 bytes from [fd00:cafe:cafe:100::100]:443 to [::]:56234
[2025-04-30T08:49:36.399356131Z TRACE quiche] f8a846691887a508a3d7d0902544d1c923e3f979 rx pkt Short dcid=f8a846691887a508a3d7d0902544d1c923e3f979 key_phase=false len=1179 pn=294871055 
[2025-04-30T08:49:36.399364175Z TRACE quiche] f8a846691887a508a3d7d0902544d1c923e3f979 rx frm NEW_CONNECTION_ID seq_num=2 retire_prior_to=0 conn_id=[8d, 34, cb, 02, 4b, 1a, 3f, c8, 21, d8, 23, 7a, f4, 2e, 3b, 07, 51, 7d] reset_token=[c4, ce, 15, 64, 7d, 0f, 2f, cf, bc, 97, ec, dd, cd, 11, d8, 7c]
[2025-04-30T08:49:36.399370928Z TRACE quiche] f8a846691887a508a3d7d0902544d1c923e3f979 rx frm NEW_CONNECTION_ID seq_num=1 retire_prior_to=0 conn_id=[6a, 09, 7f, e2, 8f, 33, b7, 1a, 37, f7, 1e, c1, 2c, 70, 95, ab, 82, 6a] reset_token=[a6, b3, 72, 9e, 4c, 6e, f5, e5, d2, 61, 56, 48, cb, 38, d0, 80]
[2025-04-30T08:49:36.399379013Z TRACE quiche] f8a846691887a508a3d7d0902544d1c923e3f979 rx frm PADDING len=1083
[2025-04-30T08:49:36.399402126Z TRACE quiche_apps::client] [::]:56234: processed 1200 bytes
[2025-04-30T08:49:36.399405964Z TRACE quiche_apps::client] [::]:56234: recv() would block
[2025-04-30T08:49:36.399408288Z TRACE quiche_apps::client] done reading
[2025-04-30T08:49:36.399414820Z TRACE quiche] f8a846691887a508a3d7d0902544d1c923e3f979 pmtud probe status false hs_con=false hs_sent=false cwnd_avail=12166 out_len=1350 left=1306
[2025-04-30T08:49:36.399418116Z TRACE quiche] f8a846691887a508a3d7d0902544d1c923e3f979 tx pkt Short dcid=96a38cf8a0e01c607f89d7319f96a003825b key_phase=false len=8 pn=5 
[2025-04-30T08:49:36.399420721Z TRACE quiche] f8a846691887a508a3d7d0902544d1c923e3f979 tx frm ACK delay=7 blocks=[294871054..294871055] ecn_counts=None
[2025-04-30T08:49:36.399427173Z TRACE quiche::recovery::congestion::recovery] f8a846691887a508a3d7d0902544d1c923e3f979 timer=124.277745ms latest_rtt=41.570912ms srtt=41.570912ms min_rtt=41.570912ms rttvar=20.785456ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=1334 app_limited=true congestion_recovery_start_time=None Rate { delivered: 333, delivered_time: Instant { tv_sec: 710, tv_nsec: 766917797 }, first_sent_time: Instant { tv_sec: 710, tv_nsec: 766917797 }, end_of_app_limited: 3, last_sent_packet: 5, largest_acked: 0, rate_sample: RateSample { delivery_rate: 8010, is_app_limited: true, interval: 41.570912ms, delivered: 333, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 710, tv_nsec: 724954243 }), send_elapsed: 0ns, ack_elapsed: 41.570912ms, rtt: 41.570912ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 405932, last_update: Instant { tv_sec: 710, tv_nsec: 767297084 }, next_time: Instant { tv_sec: 710, tv_nsec: 770547869 }, max_datagram_size: 1350, last_packet_size: Some(0), iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } 
[2025-04-30T08:49:36.399455746Z TRACE quiche_apps::client] written 44 bytes from [::]:56234 to [fd00:cafe:cafe:100::100]:443
[2025-04-30T08:49:36.399459854Z TRACE quiche_apps::client] [::]:56234 -> [fd00:cafe:cafe:100::100]:443: done writing
[2025-04-30T08:49:36.432950529Z TRACE quiche_apps::client] got 1342 bytes from [fd00:cafe:cafe:100::100]:443 to [::]:56234
[2025-04-30T08:49:36.432968823Z TRACE quiche] f8a846691887a508a3d7d0902544d1c923e3f979 rx pkt Short dcid=f8a846691887a508a3d7d0902544d1c923e3f979 key_phase=false len=1321 pn=294871056 
[2025-04-30T08:49:36.432981828Z TRACE quiche] f8a846691887a508a3d7d0902544d1c923e3f979 rx frm PING mtu_probe=None
[2025-04-30T08:49:36.432989652Z TRACE quiche] f8a846691887a508a3d7d0902544d1c923e3f979 rx frm PADDING len=1303
[2025-04-30T08:49:36.433002727Z TRACE quiche_apps::client] [::]:56234: processed 1342 bytes
[2025-04-30T08:49:36.433013136Z TRACE quiche_apps::client] [::]:56234: recv() would block
[2025-04-30T08:49:36.433015891Z TRACE quiche_apps::client] done reading
[2025-04-30T08:49:36.433026731Z TRACE quiche] f8a846691887a508a3d7d0902544d1c923e3f979 pmtud probe status false hs_con=false hs_sent=false cwnd_avail=12166 out_len=1350 left=1306
[2025-04-30T08:49:36.433031511Z TRACE quiche] f8a846691887a508a3d7d0902544d1c923e3f979 tx pkt Short dcid=96a38cf8a0e01c607f89d7319f96a003825b key_phase=false len=8 pn=6 
[2025-04-30T08:49:36.433034035Z TRACE quiche] f8a846691887a508a3d7d0902544d1c923e3f979 tx frm ACK delay=7 blocks=[294871054..294871056] ecn_counts=None
[2025-04-30T08:49:36.433044024Z TRACE quiche::recovery::congestion::recovery] f8a846691887a508a3d7d0902544d1c923e3f979 timer=90.660684ms latest_rtt=41.570912ms srtt=41.570912ms min_rtt=41.570912ms rttvar=20.785456ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=1334 app_limited=true congestion_recovery_start_time=None Rate { delivered: 333, delivered_time: Instant { tv_sec: 710, tv_nsec: 766917797 }, first_sent_time: Instant { tv_sec: 710, tv_nsec: 766917797 }, end_of_app_limited: 3, last_sent_packet: 6, largest_acked: 0, rate_sample: RateSample { delivery_rate: 8010, is_app_limited: true, interval: 41.570912ms, delivered: 333, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 710, tv_nsec: 724954243 }), send_elapsed: 0ns, ack_elapsed: 41.570912ms, rtt: 41.570912ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 405932, last_update: Instant { tv_sec: 710, tv_nsec: 801146048 }, next_time: Instant { tv_sec: 710, tv_nsec: 801146048 }, max_datagram_size: 1350, last_packet_size: Some(0), iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } 
[2025-04-30T08:49:36.433082976Z TRACE quiche_apps::client] written 44 bytes from [::]:56234 to [fd00:cafe:cafe:100::100]:443
[2025-04-30T08:49:36.433087535Z TRACE quiche_apps::client] [::]:56234 -> [fd00:cafe:cafe:100::100]:443: done writing
[2025-04-30T08:49:36.433929034Z TRACE quiche_apps::client] got 1200 bytes from [fd00:cafe:cafe:100::100]:443 to [::]:56234
[2025-04-30T08:49:36.433937670Z TRACE quiche] f8a846691887a508a3d7d0902544d1c923e3f979 rx pkt Short dcid=f8a846691887a508a3d7d0902544d1c923e3f979 key_phase=false len=1179 pn=294871057 
[2025-04-30T08:49:36.433943752Z TRACE quiche] f8a846691887a508a3d7d0902544d1c923e3f979 rx frm ACK delay=7 blocks=[3..5] ecn_counts=None
[2025-04-30T08:49:36.433947949Z TRACE quiche::recovery::congestion::recovery] f8a846691887a508a3d7d0902544d1c923e3f979 packet newly acked 3
[2025-04-30T08:49:36.433951787Z TRACE quiche::recovery::congestion::recovery] f8a846691887a508a3d7d0902544d1c923e3f979 packet newly acked 4
[2025-04-30T08:49:36.433954361Z TRACE quiche::recovery::congestion::recovery] f8a846691887a508a3d7d0902544d1c923e3f979 packet newly acked 5
[2025-04-30T08:49:36.433958569Z TRACE quiche] f8a846691887a508a3d7d0902544d1c923e3f979 rx frm HANDSHAKE_DONE
[2025-04-30T08:49:36.433963599Z TRACE quiche] f8a846691887a508a3d7d0902544d1c923e3f979 dropped epoch 1 state
[2025-04-30T08:49:36.433968618Z TRACE quiche] f8a846691887a508a3d7d0902544d1c923e3f979 rx frm NEW_TOKEN len=41
[2025-04-30T08:49:36.433971864Z TRACE quiche] f8a846691887a508a3d7d0902544d1c923e3f979 rx frm CRYPTO off=0 len=237
[2025-04-30T08:49:36.433993905Z TRACE quiche] f8a846691887a508a3d7d0902544d1c923e3f979 rx frm STREAM id=0 off=0 len=868 fin=false
[2025-04-30T08:49:36.434010125Z TRACE quiche_apps::client] [::]:56234: processed 1200 bytes
[2025-04-30T08:49:36.434014133Z TRACE quiche_apps::client] [::]:56234: recv() would block
[2025-04-30T08:49:36.434016467Z TRACE quiche_apps::client] done reading
[2025-04-30T08:49:36.434020435Z TRACE quiche_apps::common] received 868 bytes
[2025-04-30T08:49:36.434023190Z TRACE quiche_apps::common] stream 0 has 868 bytes (fin? false)
[2025-04-30T08:49:36.434035272Z TRACE quiche] f8a846691887a508a3d7d0902544d1c923e3f979 pmtud probe status false hs_con=true hs_sent=false cwnd_avail=13500 out_len=1350 left=1306
[2025-04-30T08:49:36.434038699Z TRACE quiche] f8a846691887a508a3d7d0902544d1c923e3f979 tx pkt Short dcid=96a38cf8a0e01c607f89d7319f96a003825b key_phase=false len=8 pn=7 
[2025-04-30T08:49:36.434041133Z TRACE quiche] f8a846691887a508a3d7d0902544d1c923e3f979 tx frm ACK delay=12 blocks=[294871056..294871057] ecn_counts=None
[2025-04-30T08:49:36.434047355Z TRACE quiche::recovery::congestion::recovery] f8a846691887a508a3d7d0902544d1c923e3f979 timer=none latest_rtt=31.514167ms srtt=40.313818ms min_rtt=31.514167ms rttvar=18.103278ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=0 app_limited=true congestion_recovery_start_time=None Rate { delivered: 1555, delivered_time: Instant { tv_sec: 710, tv_nsec: 801146048 }, first_sent_time: Instant { tv_sec: 710, tv_nsec: 801146048 }, end_of_app_limited: 6, last_sent_packet: 7, largest_acked: 5, rate_sample: RateSample { delivery_rate: 34770, is_app_limited: true, interval: 35.144239ms, delivered: 1222, prior_delivered: 333, prior_time: Some(Instant { tv_sec: 710, tv_nsec: 766917797 }), send_elapsed: 476.242µs, ack_elapsed: 35.144239ms, rtt: 34.667997ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 418590, last_update: Instant { tv_sec: 710, tv_nsec: 801146048 }, next_time: Instant { tv_sec: 710, tv_nsec: 801146048 }, max_datagram_size: 1350, last_packet_size: Some(0), iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } 
[2025-04-30T08:49:36.434079064Z TRACE quiche_apps::client] written 44 bytes from [::]:56234 to [fd00:cafe:cafe:100::100]:443
[2025-04-30T08:49:36.434083232Z TRACE quiche_apps::client] [::]:56234 -> [fd00:cafe:cafe:100::100]:443: done writing
[2025-04-30T08:49:36.434923599Z TRACE quiche_apps::client] got 1200 bytes from [fd00:cafe:cafe:100::100]:443 to [::]:56234
[2025-04-30T08:49:36.434930882Z TRACE quiche] f8a846691887a508a3d7d0902544d1c923e3f979 rx pkt Short dcid=f8a846691887a508a3d7d0902544d1c923e3f979 key_phase=false len=1179 pn=294871058 
[2025-04-30T08:49:36.434937244Z TRACE quiche] f8a846691887a508a3d7d0902544d1c923e3f979 rx frm STREAM id=0 off=868 len=1156 fin=false
[2025-04-30T08:49:36.434943917Z TRACE quiche_apps::client] [::]:56234: processed 1200 bytes
[2025-04-30T08:49:36.434947283Z TRACE quiche_apps::client] [::]:56234: recv() would block
[2025-04-30T08:49:36.434949547Z TRACE quiche_apps::client] done reading
[2025-04-30T08:49:36.434953435Z TRACE quiche_apps::common] received 1156 bytes
[2025-04-30T08:49:36.434955699Z TRACE quiche_apps::common] stream 0 has 1156 bytes (fin? false)
[2025-04-30T08:49:36.434961840Z TRACE quiche] f8a846691887a508a3d7d0902544d1c923e3f979 pmtud probe status false hs_con=true hs_sent=false cwnd_avail=13500 out_len=1350 left=1306
[2025-04-30T08:49:36.434964846Z TRACE quiche] f8a846691887a508a3d7d0902544d1c923e3f979 tx pkt Short dcid=96a38cf8a0e01c607f89d7319f96a003825b key_phase=false len=8 pn=8 
[2025-04-30T08:49:36.434967260Z TRACE quiche] f8a846691887a508a3d7d0902544d1c923e3f979 tx frm ACK delay=3 blocks=[294871056..294871058] ecn_counts=None
[2025-04-30T08:49:36.434972991Z TRACE quiche::recovery::congestion::recovery] f8a846691887a508a3d7d0902544d1c923e3f979 timer=none latest_rtt=31.514167ms srtt=40.313818ms min_rtt=31.514167ms rttvar=18.103278ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=0 app_limited=true congestion_recovery_start_time=None Rate { delivered: 1555, delivered_time: Instant { tv_sec: 710, tv_nsec: 801146048 }, first_sent_time: Instant { tv_sec: 710, tv_nsec: 801146048 }, end_of_app_limited: 6, last_sent_packet: 8, largest_acked: 5, rate_sample: RateSample { delivery_rate: 34770, is_app_limited: true, interval: 35.144239ms, delivered: 1222, prior_delivered: 333, prior_time: Some(Instant { tv_sec: 710, tv_nsec: 766917797 }), send_elapsed: 476.242µs, ack_elapsed: 35.144239ms, rtt: 34.667997ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 418590, last_update: Instant { tv_sec: 710, tv_nsec: 801146048 }, next_time: Instant { tv_sec: 710, tv_nsec: 801146048 }, max_datagram_size: 1350, last_packet_size: Some(0), iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } 
[2025-04-30T08:49:36.435003688Z TRACE quiche_apps::client] written 44 bytes from [::]:56234 to [fd00:cafe:cafe:100::100]:443
[2025-04-30T08:49:36.435007756Z TRACE quiche_apps::client] [::]:56234 -> [fd00:cafe:cafe:100::100]:443: done writing
[2025-04-30T08:49:36.435923904Z TRACE quiche_apps::client] got 1200 bytes from [fd00:cafe:cafe:100::100]:443 to [::]:56234
[2025-04-30T08:49:36.435930717Z TRACE quiche] f8a846691887a508a3d7d0902544d1c923e3f979 rx pkt Short dcid=f8a846691887a508a3d7d0902544d1c923e3f979 key_phase=false len=1179 pn=294871059 
[2025-04-30T08:49:36.435936728Z TRACE quiche] f8a846691887a508a3d7d0902544d1c923e3f979 rx frm STREAM id=0 off=2024 len=1156 fin=false
[2025-04-30T08:49:36.435942830Z TRACE quiche_apps::client] [::]:56234: processed 1200 bytes
[2025-04-30T08:49:36.435946146Z TRACE quiche_apps::client] [::]:56234: recv() would block
[2025-04-30T08:49:36.435948380Z TRACE quiche_apps::client] done reading
[2025-04-30T08:49:36.435952057Z TRACE quiche_apps::common] received 1156 bytes
[2025-04-30T08:49:36.435954311Z TRACE quiche_apps::common] stream 0 has 1156 bytes (fin? false)
[2025-04-30T08:49:36.435960122Z TRACE quiche] f8a846691887a508a3d7d0902544d1c923e3f979 pmtud probe status false hs_con=true hs_sent=false cwnd_avail=13500 out_len=1350 left=1306
[2025-04-30T08:49:36.435963098Z TRACE quiche] f8a846691887a508a3d7d0902544d1c923e3f979 tx pkt Short dcid=96a38cf8a0e01c607f89d7319f96a003825b key_phase=false len=8 pn=9 
[2025-04-30T08:49:36.435965442Z TRACE quiche] f8a846691887a508a3d7d0902544d1c923e3f979 tx frm ACK delay=3 blocks=[294871056..294871059] ecn_counts=None
[2025-04-30T08:49:36.435971032Z TRACE quiche::recovery::congestion::recovery] f8a846691887a508a3d7d0902544d1c923e3f979 timer=none latest_rtt=31.514167ms srtt=40.313818ms min_rtt=31.514167ms rttvar=18.103278ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=0 app_limited=true congestion_recovery_start_time=None Rate { delivered: 1555, delivered_time: Instant { tv_sec: 710, tv_nsec: 801146048 }, first_sent_time: Instant { tv_sec: 710, tv_nsec: 801146048 }, end_of_app_limited: 6, last_sent_packet: 9, largest_acked: 5, rate_sample: RateSample { delivery_rate: 34770, is_app_limited: true, interval: 35.144239ms, delivered: 1222, prior_delivered: 333, prior_time: Some(Instant { tv_sec: 710, tv_nsec: 766917797 }), send_elapsed: 476.242µs, ack_elapsed: 35.144239ms, rtt: 34.667997ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 418590, last_update: Instant { tv_sec: 710, tv_nsec: 801146048 }, next_time: Instant { tv_sec: 710, tv_nsec: 801146048 }, max_datagram_size: 1350, last_packet_size: Some(0), iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } 
[2025-04-30T08:49:36.435996269Z TRACE quiche_apps::client] written 44 bytes from [::]:56234 to [fd00:cafe:cafe:100::100]:443
[2025-04-30T08:49:36.435999966Z TRACE quiche_apps::client] [::]:56234 -> [fd00:cafe:cafe:100::100]:443: done writing
[2025-04-30T08:49:36.436922166Z TRACE quiche_apps::client] got 1200 bytes from [fd00:cafe:cafe:100::100]:443 to [::]:56234
[2025-04-30T08:49:36.436928778Z TRACE quiche] f8a846691887a508a3d7d0902544d1c923e3f979 rx pkt Short dcid=f8a846691887a508a3d7d0902544d1c923e3f979 key_phase=false len=1179 pn=294871060 
[2025-04-30T08:49:36.436938807Z TRACE quiche] f8a846691887a508a3d7d0902544d1c923e3f979 rx frm STREAM id=0 off=3180 len=1156 fin=false
[2025-04-30T08:49:36.436944958Z TRACE quiche_apps::client] [::]:56234: processed 1200 bytes
[2025-04-30T08:49:36.436948395Z TRACE quiche_apps::client] [::]:56234: recv() would block
[2025-04-30T08:49:36.436950669Z TRACE quiche_apps::client] done reading
[2025-04-30T08:49:36.436954396Z TRACE quiche_apps::common] received 1156 bytes
[2025-04-30T08:49:36.436956630Z TRACE quiche_apps::common] stream 0 has 1156 bytes (fin? false)
[2025-04-30T08:49:36.436962461Z TRACE quiche] f8a846691887a508a3d7d0902544d1c923e3f979 pmtud probe status false hs_con=true hs_sent=false cwnd_avail=13500 out_len=1350 left=1306
[2025-04-30T08:49:36.436965607Z TRACE quiche] f8a846691887a508a3d7d0902544d1c923e3f979 tx pkt Short dcid=96a38cf8a0e01c607f89d7319f96a003825b key_phase=false len=8 pn=10 
[2025-04-30T08:49:36.436967972Z TRACE quiche] f8a846691887a508a3d7d0902544d1c923e3f979 tx frm ACK delay=4 blocks=[294871056..294871060] ecn_counts=None
[2025-04-30T08:49:36.436973932Z TRACE quiche::recovery::congestion::recovery] f8a846691887a508a3d7d0902544d1c923e3f979 timer=none latest_rtt=31.514167ms srtt=40.313818ms min_rtt=31.514167ms rttvar=18.103278ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=0 app_limited=true congestion_recovery_start_time=None Rate { delivered: 1555, delivered_time: Instant { tv_sec: 710, tv_nsec: 801146048 }, first_sent_time: Instant { tv_sec: 710, tv_nsec: 801146048 }, end_of_app_limited: 6, last_sent_packet: 10, largest_acked: 5, rate_sample: RateSample { delivery_rate: 34770, is_app_limited: true, interval: 35.144239ms, delivered: 1222, prior_delivered: 333, prior_time: Some(Instant { tv_sec: 710, tv_nsec: 766917797 }), send_elapsed: 476.242µs, ack_elapsed: 35.144239ms, rtt: 34.667997ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 418590, last_update: Instant { tv_sec: 710, tv_nsec: 801146048 }, next_time: Instant { tv_sec: 710, tv_nsec: 801146048 }, max_datagram_size: 1350, last_packet_size: Some(0), iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } 
[2025-04-30T08:49:36.436998899Z TRACE quiche_apps::client] written 44 bytes from [::]:56234 to [fd00:cafe:cafe:100::100]:443
[2025-04-30T08:49:36.437002666Z TRACE quiche_apps::client] [::]:56234 -> [fd00:cafe:cafe:100::100]:443: done writing
[2025-04-30T08:49:36.437921530Z TRACE quiche_apps::client] got 1200 bytes from [fd00:cafe:cafe:100::100]:443 to [::]:56234
[2025-04-30T08:49:36.437928202Z TRACE quiche] f8a846691887a508a3d7d0902544d1c923e3f979 rx pkt Short dcid=f8a846691887a508a3d7d0902544d1c923e3f979 key_phase=false len=1179 pn=294871061 
[2025-04-30T08:49:36.437933452Z TRACE quiche] f8a846691887a508a3d7d0902544d1c923e3f979 rx frm STREAM id=0 off=4336 len=784 fin=true
[2025-04-30T08:49:36.437936708Z TRACE quiche] f8a846691887a508a3d7d0902544d1c923e3f979 rx frm STREAM id=4 off=0 len=368 fin=false
[2025-04-30T08:49:36.437943070Z TRACE quiche_apps::client] [::]:56234: processed 1200 bytes
[2025-04-30T08:49:36.437946446Z TRACE quiche_apps::client] [::]:56234: recv() would block
[2025-04-30T08:49:36.437948700Z TRACE quiche_apps::client] done reading
[2025-04-30T08:49:36.437953940Z TRACE quiche_apps::common] received 784 bytes
[2025-04-30T08:49:36.437956224Z TRACE quiche_apps::common] stream 0 has 784 bytes (fin? true)
[2025-04-30T08:49:36.437958569Z DEBUG quiche_apps::common] 1/2 responses received
[2025-04-30T08:49:36.437961714Z TRACE quiche_apps::common] received 368 bytes
[2025-04-30T08:49:36.437963879Z TRACE quiche_apps::common] stream 4 has 368 bytes (fin? false)
[2025-04-30T08:49:36.437969599Z TRACE quiche] f8a846691887a508a3d7d0902544d1c923e3f979 pmtud probe status false hs_con=true hs_sent=false cwnd_avail=13500 out_len=1350 left=1306
[2025-04-30T08:49:36.437976893Z TRACE quiche] f8a846691887a508a3d7d0902544d1c923e3f979 tx pkt Short dcid=96a38cf8a0e01c607f89d7319f96a003825b key_phase=false len=8 pn=11 
[2025-04-30T08:49:36.437979287Z TRACE quiche] f8a846691887a508a3d7d0902544d1c923e3f979 tx frm ACK delay=5 blocks=[294871056..294871061] ecn_counts=None
[2025-04-30T08:49:36.437984928Z TRACE quiche::recovery::congestion::recovery] f8a846691887a508a3d7d0902544d1c923e3f979 timer=none latest_rtt=31.514167ms srtt=40.313818ms min_rtt=31.514167ms rttvar=18.103278ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=0 app_limited=true congestion_recovery_start_time=None Rate { delivered: 1555, delivered_time: Instant { tv_sec: 710, tv_nsec: 801146048 }, first_sent_time: Instant { tv_sec: 710, tv_nsec: 801146048 }, end_of_app_limited: 6, last_sent_packet: 11, largest_acked: 5, rate_sample: RateSample { delivery_rate: 34770, is_app_limited: true, interval: 35.144239ms, delivered: 1222, prior_delivered: 333, prior_time: Some(Instant { tv_sec: 710, tv_nsec: 766917797 }), send_elapsed: 476.242µs, ack_elapsed: 35.144239ms, rtt: 34.667997ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 418590, last_update: Instant { tv_sec: 710, tv_nsec: 801146048 }, next_time: Instant { tv_sec: 710, tv_nsec: 801146048 }, max_datagram_size: 1350, last_packet_size: Some(0), iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } 
[2025-04-30T08:49:36.438009724Z TRACE quiche_apps::client] written 44 bytes from [::]:56234 to [fd00:cafe:cafe:100::100]:443
[2025-04-30T08:49:36.438013431Z TRACE quiche_apps::client] [::]:56234 -> [fd00:cafe:cafe:100::100]:443: done writing
[2025-04-30T08:49:36.438921845Z TRACE quiche_apps::client] got 1200 bytes from [fd00:cafe:cafe:100::100]:443 to [::]:56234
[2025-04-30T08:49:36.438928428Z TRACE quiche] f8a846691887a508a3d7d0902544d1c923e3f979 rx pkt Short dcid=f8a846691887a508a3d7d0902544d1c923e3f979 key_phase=false len=1179 pn=294871062 
[2025-04-30T08:49:36.438933998Z TRACE quiche] f8a846691887a508a3d7d0902544d1c923e3f979 rx frm STREAM id=4 off=368 len=1156 fin=false
[2025-04-30T08:49:36.438940079Z TRACE quiche_apps::client] [::]:56234: processed 1200 bytes
[2025-04-30T08:49:36.438943375Z TRACE quiche_apps::client] [::]:56234: recv() would block
[2025-04-30T08:49:36.438945609Z TRACE quiche_apps::client] done reading
[2025-04-30T08:49:36.438949467Z TRACE quiche_apps::common] received 1156 bytes
[2025-04-30T08:49:36.438951671Z TRACE quiche_apps::common] stream 4 has 1156 bytes (fin? false)
[2025-04-30T08:49:36.438957572Z TRACE quiche] f8a846691887a508a3d7d0902544d1c923e3f979 pmtud probe status false hs_con=true hs_sent=false cwnd_avail=13500 out_len=1350 left=1306
[2025-04-30T08:49:36.438960537Z TRACE quiche] f8a846691887a508a3d7d0902544d1c923e3f979 tx pkt Short dcid=96a38cf8a0e01c607f89d7319f96a003825b key_phase=false len=8 pn=12 
[2025-04-30T08:49:36.438962902Z TRACE quiche] f8a846691887a508a3d7d0902544d1c923e3f979 tx frm ACK delay=3 blocks=[294871056..294871062] ecn_counts=None
[2025-04-30T08:49:36.438968392Z TRACE quiche::recovery::congestion::recovery] f8a846691887a508a3d7d0902544d1c923e3f979 timer=none latest_rtt=31.514167ms srtt=40.313818ms min_rtt=31.514167ms rttvar=18.103278ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=0 app_limited=true congestion_recovery_start_time=None Rate { delivered: 1555, delivered_time: Instant { tv_sec: 710, tv_nsec: 801146048 }, first_sent_time: Instant { tv_sec: 710, tv_nsec: 801146048 }, end_of_app_limited: 6, last_sent_packet: 12, largest_acked: 5, rate_sample: RateSample { delivery_rate: 34770, is_app_limited: true, interval: 35.144239ms, delivered: 1222, prior_delivered: 333, prior_time: Some(Instant { tv_sec: 710, tv_nsec: 766917797 }), send_elapsed: 476.242µs, ack_elapsed: 35.144239ms, rtt: 34.667997ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 418590, last_update: Instant { tv_sec: 710, tv_nsec: 801146048 }, next_time: Instant { tv_sec: 710, tv_nsec: 801146048 }, max_datagram_size: 1350, last_packet_size: Some(0), iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } 
[2025-04-30T08:49:36.438998147Z TRACE quiche_apps::client] written 44 bytes from [::]:56234 to [fd00:cafe:cafe:100::100]:443
[2025-04-30T08:49:36.439002055Z TRACE quiche_apps::client] [::]:56234 -> [fd00:cafe:cafe:100::100]:443: done writing
[2025-04-30T08:49:36.439922271Z TRACE quiche_apps::client] got 1200 bytes from [fd00:cafe:cafe:100::100]:443 to [::]:56234
[2025-04-30T08:49:36.439928873Z TRACE quiche] f8a846691887a508a3d7d0902544d1c923e3f979 rx pkt Short dcid=f8a846691887a508a3d7d0902544d1c923e3f979 key_phase=false len=1179 pn=294871063 
[2025-04-30T08:49:36.439934303Z TRACE quiche] f8a846691887a508a3d7d0902544d1c923e3f979 rx frm STREAM id=4 off=1524 len=1156 fin=false
[2025-04-30T08:49:36.439940264Z TRACE quiche_apps::client] [::]:56234: processed 1200 bytes
[2025-04-30T08:49:36.439943601Z TRACE quiche_apps::client] [::]:56234: recv() would block
[2025-04-30T08:49:36.439945835Z TRACE quiche_apps::client] done reading
[2025-04-30T08:49:36.439949572Z TRACE quiche_apps::common] received 1156 bytes
[2025-04-30T08:49:36.439951776Z TRACE quiche_apps::common] stream 4 has 1156 bytes (fin? false)
[2025-04-30T08:49:36.439957516Z TRACE quiche] f8a846691887a508a3d7d0902544d1c923e3f979 pmtud probe status false hs_con=true hs_sent=false cwnd_avail=13500 out_len=1350 left=1306
[2025-04-30T08:49:36.439960412Z TRACE quiche] f8a846691887a508a3d7d0902544d1c923e3f979 tx pkt Short dcid=96a38cf8a0e01c607f89d7319f96a003825b key_phase=false len=8 pn=13 
[2025-04-30T08:49:36.439962756Z TRACE quiche] f8a846691887a508a3d7d0902544d1c923e3f979 tx frm ACK delay=3 blocks=[294871056..294871063] ecn_counts=None
[2025-04-30T08:49:36.439968276Z TRACE quiche::recovery::congestion::recovery] f8a846691887a508a3d7d0902544d1c923e3f979 timer=none latest_rtt=31.514167ms srtt=40.313818ms min_rtt=31.514167ms rttvar=18.103278ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=0 app_limited=true congestion_recovery_start_time=None Rate { delivered: 1555, delivered_time: Instant { tv_sec: 710, tv_nsec: 801146048 }, first_sent_time: Instant { tv_sec: 710, tv_nsec: 801146048 }, end_of_app_limited: 6, last_sent_packet: 13, largest_acked: 5, rate_sample: RateSample { delivery_rate: 34770, is_app_limited: true, interval: 35.144239ms, delivered: 1222, prior_delivered: 333, prior_time: Some(Instant { tv_sec: 710, tv_nsec: 766917797 }), send_elapsed: 476.242µs, ack_elapsed: 35.144239ms, rtt: 34.667997ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 418590, last_update: Instant { tv_sec: 710, tv_nsec: 801146048 }, next_time: Instant { tv_sec: 710, tv_nsec: 801146048 }, max_datagram_size: 1350, last_packet_size: Some(0), iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } 
[2025-04-30T08:49:36.439997491Z TRACE quiche_apps::client] written 44 bytes from [::]:56234 to [fd00:cafe:cafe:100::100]:443
[2025-04-30T08:49:36.440007319Z TRACE quiche_apps::client] [::]:56234 -> [fd00:cafe:cafe:100::100]:443: done writing
[2025-04-30T08:49:36.440921905Z TRACE quiche_apps::client] got 1200 bytes from [fd00:cafe:cafe:100::100]:443 to [::]:56234
[2025-04-30T08:49:36.440928527Z TRACE quiche] f8a846691887a508a3d7d0902544d1c923e3f979 rx pkt Short dcid=f8a846691887a508a3d7d0902544d1c923e3f979 key_phase=false len=1179 pn=294871064 
[2025-04-30T08:49:36.440938426Z TRACE quiche] f8a846691887a508a3d7d0902544d1c923e3f979 rx frm STREAM id=4 off=2680 len=1156 fin=false
[2025-04-30T08:49:36.440944417Z TRACE quiche_apps::client] [::]:56234: processed 1200 bytes
[2025-04-30T08:49:36.440947823Z TRACE quiche_apps::client] [::]:56234: recv() would block
[2025-04-30T08:49:36.440950027Z TRACE quiche_apps::client] done reading
[2025-04-30T08:49:36.440953804Z TRACE quiche_apps::common] received 1156 bytes
[2025-04-30T08:49:36.440956058Z TRACE quiche_apps::common] stream 4 has 1156 bytes (fin? false)
[2025-04-30T08:49:36.440961859Z TRACE quiche] f8a846691887a508a3d7d0902544d1c923e3f979 pmtud probe status false hs_con=true hs_sent=false cwnd_avail=13500 out_len=1350 left=1306
[2025-04-30T08:49:36.440964805Z TRACE quiche] f8a846691887a508a3d7d0902544d1c923e3f979 tx pkt Short dcid=96a38cf8a0e01c607f89d7319f96a003825b key_phase=false len=8 pn=14 
[2025-04-30T08:49:36.440967149Z TRACE quiche] f8a846691887a508a3d7d0902544d1c923e3f979 tx frm ACK delay=4 blocks=[294871056..294871064] ecn_counts=None
[2025-04-30T08:49:36.440973141Z TRACE quiche::recovery::congestion::recovery] f8a846691887a508a3d7d0902544d1c923e3f979 timer=none latest_rtt=31.514167ms srtt=40.313818ms min_rtt=31.514167ms rttvar=18.103278ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=0 app_limited=true congestion_recovery_start_time=None Rate { delivered: 1555, delivered_time: Instant { tv_sec: 710, tv_nsec: 801146048 }, first_sent_time: Instant { tv_sec: 710, tv_nsec: 801146048 }, end_of_app_limited: 6, last_sent_packet: 14, largest_acked: 5, rate_sample: RateSample { delivery_rate: 34770, is_app_limited: true, interval: 35.144239ms, delivered: 1222, prior_delivered: 333, prior_time: Some(Instant { tv_sec: 710, tv_nsec: 766917797 }), send_elapsed: 476.242µs, ack_elapsed: 35.144239ms, rtt: 34.667997ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 418590, last_update: Instant { tv_sec: 710, tv_nsec: 801146048 }, next_time: Instant { tv_sec: 710, tv_nsec: 801146048 }, max_datagram_size: 1350, last_packet_size: Some(0), iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } 
[2025-04-30T08:49:36.440998277Z TRACE quiche_apps::client] written 44 bytes from [::]:56234 to [fd00:cafe:cafe:100::100]:443
[2025-04-30T08:49:36.441001914Z TRACE quiche_apps::client] [::]:56234 -> [fd00:cafe:cafe:100::100]:443: done writing
[2025-04-30T08:49:36.441921579Z TRACE quiche_apps::client] got 1200 bytes from [fd00:cafe:cafe:100::100]:443 to [::]:56234
[2025-04-30T08:49:36.441928122Z TRACE quiche] f8a846691887a508a3d7d0902544d1c923e3f979 rx pkt Short dcid=f8a846691887a508a3d7d0902544d1c923e3f979 key_phase=false len=1179 pn=294871065 
[2025-04-30T08:49:36.441933471Z TRACE quiche] f8a846691887a508a3d7d0902544d1c923e3f979 rx frm STREAM id=4 off=3836 len=1156 fin=false
[2025-04-30T08:49:36.441939172Z TRACE quiche_apps::client] [::]:56234: processed 1200 bytes
[2025-04-30T08:49:36.441942468Z TRACE quiche_apps::client] [::]:56234: recv() would block
[2025-04-30T08:49:36.441944692Z TRACE quiche_apps::client] done reading
[2025-04-30T08:49:36.441948309Z TRACE quiche_apps::common] received 1156 bytes
[2025-04-30T08:49:36.441950493Z TRACE quiche_apps::common] stream 4 has 1156 bytes (fin? false)
[2025-04-30T08:49:36.441956244Z TRACE quiche] f8a846691887a508a3d7d0902544d1c923e3f979 pmtud probe status false hs_con=true hs_sent=false cwnd_avail=13500 out_len=1350 left=1306
[2025-04-30T08:49:36.441959129Z TRACE quiche] f8a846691887a508a3d7d0902544d1c923e3f979 tx pkt Short dcid=96a38cf8a0e01c607f89d7319f96a003825b key_phase=false len=8 pn=15 
[2025-04-30T08:49:36.441961464Z TRACE quiche] f8a846691887a508a3d7d0902544d1c923e3f979 tx frm ACK delay=3 blocks=[294871056..294871065] ecn_counts=None
[2025-04-30T08:49:36.441966964Z TRACE quiche::recovery::congestion::recovery] f8a846691887a508a3d7d0902544d1c923e3f979 timer=none latest_rtt=31.514167ms srtt=40.313818ms min_rtt=31.514167ms rttvar=18.103278ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=0 app_limited=true congestion_recovery_start_time=None Rate { delivered: 1555, delivered_time: Instant { tv_sec: 710, tv_nsec: 801146048 }, first_sent_time: Instant { tv_sec: 710, tv_nsec: 801146048 }, end_of_app_limited: 6, last_sent_packet: 15, largest_acked: 5, rate_sample: RateSample { delivery_rate: 34770, is_app_limited: true, interval: 35.144239ms, delivered: 1222, prior_delivered: 333, prior_time: Some(Instant { tv_sec: 710, tv_nsec: 766917797 }), send_elapsed: 476.242µs, ack_elapsed: 35.144239ms, rtt: 34.667997ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 418590, last_update: Instant { tv_sec: 710, tv_nsec: 801146048 }, next_time: Instant { tv_sec: 710, tv_nsec: 801146048 }, max_datagram_size: 1350, last_packet_size: Some(0), iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } 
[2025-04-30T08:49:36.441997120Z TRACE quiche_apps::client] written 44 bytes from [::]:56234 to [fd00:cafe:cafe:100::100]:443
[2025-04-30T08:49:36.442001067Z TRACE quiche_apps::client] [::]:56234 -> [fd00:cafe:cafe:100::100]:443: done writing
[2025-04-30T08:49:36.442921594Z TRACE quiche_apps::client] got 1200 bytes from [fd00:cafe:cafe:100::100]:443 to [::]:56234
[2025-04-30T08:49:36.442928216Z TRACE quiche] f8a846691887a508a3d7d0902544d1c923e3f979 rx pkt Short dcid=f8a846691887a508a3d7d0902544d1c923e3f979 key_phase=false len=1179 pn=294871066 
[2025-04-30T08:49:36.442933707Z TRACE quiche] f8a846691887a508a3d7d0902544d1c923e3f979 rx frm STREAM id=4 off=4992 len=1156 fin=false
[2025-04-30T08:49:36.442939658Z TRACE quiche_apps::client] [::]:56234: processed 1200 bytes
[2025-04-30T08:49:36.442942964Z TRACE quiche_apps::client] [::]:56234: recv() would block
[2025-04-30T08:49:36.442945198Z TRACE quiche_apps::client] done reading
[2025-04-30T08:49:36.442948875Z TRACE quiche_apps::common] received 1156 bytes
[2025-04-30T08:49:36.442951099Z TRACE quiche_apps::common] stream 4 has 1156 bytes (fin? false)
[2025-04-30T08:49:36.442956920Z TRACE quiche] f8a846691887a508a3d7d0902544d1c923e3f979 pmtud probe status false hs_con=true hs_sent=false cwnd_avail=13500 out_len=1350 left=1306
[2025-04-30T08:49:36.442959845Z TRACE quiche] f8a846691887a508a3d7d0902544d1c923e3f979 tx pkt Short dcid=96a38cf8a0e01c607f89d7319f96a003825b key_phase=false len=8 pn=16 
[2025-04-30T08:49:36.442962210Z TRACE quiche] f8a846691887a508a3d7d0902544d1c923e3f979 tx frm ACK delay=3 blocks=[294871056..294871066] ecn_counts=None
[2025-04-30T08:49:36.442979923Z TRACE quiche::recovery::congestion::recovery] f8a846691887a508a3d7d0902544d1c923e3f979 timer=none latest_rtt=31.514167ms srtt=40.313818ms min_rtt=31.514167ms rttvar=18.103278ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=0 app_limited=true congestion_recovery_start_time=None Rate { delivered: 1555, delivered_time: Instant { tv_sec: 710, tv_nsec: 801146048 }, first_sent_time: Instant { tv_sec: 710, tv_nsec: 801146048 }, end_of_app_limited: 6, last_sent_packet: 16, largest_acked: 5, rate_sample: RateSample { delivery_rate: 34770, is_app_limited: true, interval: 35.144239ms, delivered: 1222, prior_delivered: 333, prior_time: Some(Instant { tv_sec: 710, tv_nsec: 766917797 }), send_elapsed: 476.242µs, ack_elapsed: 35.144239ms, rtt: 34.667997ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 418590, last_update: Instant { tv_sec: 710, tv_nsec: 801146048 }, next_time: Instant { tv_sec: 710, tv_nsec: 801146048 }, max_datagram_size: 1350, last_packet_size: Some(0), iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } 
[2025-04-30T08:49:36.443009127Z TRACE quiche_apps::client] written 44 bytes from [::]:56234 to [fd00:cafe:cafe:100::100]:443
[2025-04-30T08:49:36.443013135Z TRACE quiche_apps::client] [::]:56234 -> [fd00:cafe:cafe:100::100]:443: done writing
[2025-04-30T08:49:36.443921268Z TRACE quiche_apps::client] got 1200 bytes from [fd00:cafe:cafe:100::100]:443 to [::]:56234
[2025-04-30T08:49:36.443927871Z TRACE quiche] f8a846691887a508a3d7d0902544d1c923e3f979 rx pkt Short dcid=f8a846691887a508a3d7d0902544d1c923e3f979 key_phase=false len=1179 pn=294871067 
[2025-04-30T08:49:36.443933581Z TRACE quiche] f8a846691887a508a3d7d0902544d1c923e3f979 rx frm STREAM id=4 off=6148 len=1156 fin=false
[2025-04-30T08:49:36.443939783Z TRACE quiche_apps::client] [::]:56234: processed 1200 bytes
[2025-04-30T08:49:36.443943199Z TRACE quiche_apps::client] [::]:56234: recv() would block
[2025-04-30T08:49:36.443945473Z TRACE quiche_apps::client] done reading
[2025-04-30T08:49:36.443949280Z TRACE quiche_apps::common] received 1156 bytes
[2025-04-30T08:49:36.443951505Z TRACE quiche_apps::common] stream 4 has 1156 bytes (fin? false)
[2025-04-30T08:49:36.443957386Z TRACE quiche] f8a846691887a508a3d7d0902544d1c923e3f979 pmtud probe status false hs_con=true hs_sent=false cwnd_avail=13500 out_len=1350 left=1306
[2025-04-30T08:49:36.443960451Z TRACE quiche] f8a846691887a508a3d7d0902544d1c923e3f979 tx pkt Short dcid=96a38cf8a0e01c607f89d7319f96a003825b key_phase=false len=8 pn=17 
[2025-04-30T08:49:36.443962906Z TRACE quiche] f8a846691887a508a3d7d0902544d1c923e3f979 tx frm ACK delay=3 blocks=[294871056..294871067] ecn_counts=None
[2025-04-30T08:49:36.443968556Z TRACE quiche::recovery::congestion::recovery] f8a846691887a508a3d7d0902544d1c923e3f979 timer=none latest_rtt=31.514167ms srtt=40.313818ms min_rtt=31.514167ms rttvar=18.103278ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=0 app_limited=true congestion_recovery_start_time=None Rate { delivered: 1555, delivered_time: Instant { tv_sec: 710, tv_nsec: 801146048 }, first_sent_time: Instant { tv_sec: 710, tv_nsec: 801146048 }, end_of_app_limited: 6, last_sent_packet: 17, largest_acked: 5, rate_sample: RateSample { delivery_rate: 34770, is_app_limited: true, interval: 35.144239ms, delivered: 1222, prior_delivered: 333, prior_time: Some(Instant { tv_sec: 710, tv_nsec: 766917797 }), send_elapsed: 476.242µs, ack_elapsed: 35.144239ms, rtt: 34.667997ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 418590, last_update: Instant { tv_sec: 710, tv_nsec: 801146048 }, next_time: Instant { tv_sec: 710, tv_nsec: 801146048 }, max_datagram_size: 1350, last_packet_size: Some(0), iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } 
[2025-04-30T08:49:36.443993273Z TRACE quiche_apps::client] written 44 bytes from [::]:56234 to [fd00:cafe:cafe:100::100]:443
[2025-04-30T08:49:36.443996899Z TRACE quiche_apps::client] [::]:56234 -> [fd00:cafe:cafe:100::100]:443: done writing
[2025-04-30T08:49:36.464796428Z TRACE quiche_apps::client] got 1342 bytes from [fd00:cafe:cafe:100::100]:443 to [::]:56234
[2025-04-30T08:49:36.464809862Z TRACE quiche] f8a846691887a508a3d7d0902544d1c923e3f979 rx pkt Short dcid=f8a846691887a508a3d7d0902544d1c923e3f979 key_phase=false len=1321 pn=294871068 
[2025-04-30T08:49:36.464820442Z TRACE quiche] f8a846691887a508a3d7d0902544d1c923e3f979 rx frm STREAM id=4 off=7304 len=1298 fin=false
[2025-04-30T08:49:36.464832475Z TRACE quiche_apps::client] [::]:56234: processed 1342 bytes
[2025-04-30T08:49:36.464836212Z TRACE quiche_apps::client] [::]:56234: recv() would block
[2025-04-30T08:49:36.464838616Z TRACE quiche_apps::client] done reading
[2025-04-30T08:49:36.464843756Z TRACE quiche_apps::common] received 1298 bytes
[2025-04-30T08:49:36.464852863Z TRACE quiche_apps::common] stream 4 has 1298 bytes (fin? false)
[2025-04-30T08:49:36.464913185Z TRACE quiche] f8a846691887a508a3d7d0902544d1c923e3f979 pmtud probe status false hs_con=true hs_sent=false cwnd_avail=13500 out_len=1350 left=1306
[2025-04-30T08:49:36.464920619Z TRACE quiche] f8a846691887a508a3d7d0902544d1c923e3f979 tx pkt Short dcid=96a38cf8a0e01c607f89d7319f96a003825b key_phase=false len=8 pn=18 
[2025-04-30T08:49:36.464923154Z TRACE quiche] f8a846691887a508a3d7d0902544d1c923e3f979 tx frm ACK delay=13 blocks=[294871056..294871068] ecn_counts=None
[2025-04-30T08:49:36.464931880Z TRACE quiche::recovery::congestion::recovery] f8a846691887a508a3d7d0902544d1c923e3f979 timer=none latest_rtt=31.514167ms srtt=40.313818ms min_rtt=31.514167ms rttvar=18.103278ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=0 app_limited=true congestion_recovery_start_time=None Rate { delivered: 1555, delivered_time: Instant { tv_sec: 710, tv_nsec: 801146048 }, first_sent_time: Instant { tv_sec: 710, tv_nsec: 801146048 }, end_of_app_limited: 6, last_sent_packet: 18, largest_acked: 5, rate_sample: RateSample { delivery_rate: 34770, is_app_limited: true, interval: 35.144239ms, delivered: 1222, prior_delivered: 333, prior_time: Some(Instant { tv_sec: 710, tv_nsec: 766917797 }), send_elapsed: 476.242µs, ack_elapsed: 35.144239ms, rtt: 34.667997ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 418590, last_update: Instant { tv_sec: 710, tv_nsec: 801146048 }, next_time: Instant { tv_sec: 710, tv_nsec: 801146048 }, max_datagram_size: 1350, last_packet_size: Some(0), iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } 
[2025-04-30T08:49:36.464967136Z TRACE quiche_apps::client] written 44 bytes from [::]:56234 to [fd00:cafe:cafe:100::100]:443
[2025-04-30T08:49:36.464971604Z TRACE quiche_apps::client] [::]:56234 -> [fd00:cafe:cafe:100::100]:443: done writing
[2025-04-30T08:49:36.465913781Z TRACE quiche_apps::client] got 1342 bytes from [fd00:cafe:cafe:100::100]:443 to [::]:56234
[2025-04-30T08:49:36.465921646Z TRACE quiche] f8a846691887a508a3d7d0902544d1c923e3f979 rx pkt Short dcid=f8a846691887a508a3d7d0902544d1c923e3f979 key_phase=false len=1321 pn=294871069 
[2025-04-30T08:49:36.465927908Z TRACE quiche] f8a846691887a508a3d7d0902544d1c923e3f979 rx frm STREAM id=4 off=8602 len=1298 fin=false
[2025-04-30T08:49:36.465934640Z TRACE quiche_apps::client] [::]:56234: processed 1342 bytes
[2025-04-30T08:49:36.465938107Z TRACE quiche_apps::client] [::]:56234: recv() would block
[2025-04-30T08:49:36.465940401Z TRACE quiche_apps::client] done reading
[2025-04-30T08:49:36.465944418Z TRACE quiche_apps::common] received 1298 bytes
[2025-04-30T08:49:36.465946753Z TRACE quiche_apps::common] stream 4 has 1298 bytes (fin? false)
[2025-04-30T08:49:36.465953045Z TRACE quiche] f8a846691887a508a3d7d0902544d1c923e3f979 pmtud probe status false hs_con=true hs_sent=false cwnd_avail=13500 out_len=1350 left=1306
[2025-04-30T08:49:36.465956110Z TRACE quiche] f8a846691887a508a3d7d0902544d1c923e3f979 tx pkt Short dcid=96a38cf8a0e01c607f89d7319f96a003825b key_phase=false len=8 pn=19 
[2025-04-30T08:49:36.465958555Z TRACE quiche] f8a846691887a508a3d7d0902544d1c923e3f979 tx frm ACK delay=3 blocks=[294871056..294871069] ecn_counts=None
[2025-04-30T08:49:36.465964626Z TRACE quiche::recovery::congestion::recovery] f8a846691887a508a3d7d0902544d1c923e3f979 timer=none latest_rtt=31.514167ms srtt=40.313818ms min_rtt=31.514167ms rttvar=18.103278ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=0 app_limited=true congestion_recovery_start_time=None Rate { delivered: 1555, delivered_time: Instant { tv_sec: 710, tv_nsec: 834075808 }, first_sent_time: Instant { tv_sec: 710, tv_nsec: 834075808 }, end_of_app_limited: 6, last_sent_packet: 19, largest_acked: 5, rate_sample: RateSample { delivery_rate: 34770, is_app_limited: true, interval: 35.144239ms, delivered: 1222, prior_delivered: 333, prior_time: Some(Instant { tv_sec: 710, tv_nsec: 766917797 }), send_elapsed: 476.242µs, ack_elapsed: 35.144239ms, rtt: 34.667997ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 418590, last_update: Instant { tv_sec: 710, tv_nsec: 834075808 }, next_time: Instant { tv_sec: 710, tv_nsec: 834075808 }, max_datagram_size: 1350, last_packet_size: Some(0), iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } 
[2025-04-30T08:49:36.465997117Z TRACE quiche_apps::client] written 44 bytes from [::]:56234 to [fd00:cafe:cafe:100::100]:443
[2025-04-30T08:49:36.466001255Z TRACE quiche_apps::client] [::]:56234 -> [fd00:cafe:cafe:100::100]:443: done writing
[2025-04-30T08:49:36.467004926Z TRACE quiche_apps::client] got 1342 bytes from [fd00:cafe:cafe:100::100]:443 to [::]:56234
[2025-04-30T08:49:36.467012059Z TRACE quiche] f8a846691887a508a3d7d0902544d1c923e3f979 rx pkt Short dcid=f8a846691887a508a3d7d0902544d1c923e3f979 key_phase=false len=1321 pn=294871070 
[2025-04-30T08:49:36.467017530Z TRACE quiche] f8a846691887a508a3d7d0902544d1c923e3f979 rx frm STREAM id=4 off=9900 len=340 fin=true
[2025-04-30T08:49:36.467024132Z TRACE quiche] f8a846691887a508a3d7d0902544d1c923e3f979 rx frm PADDING len=958
[2025-04-30T08:49:36.467030444Z TRACE quiche_apps::client] [::]:56234: processed 1342 bytes
[2025-04-30T08:49:36.467033830Z TRACE quiche_apps::client] [::]:56234: recv() would block
[2025-04-30T08:49:36.467036024Z TRACE quiche_apps::client] done reading
[2025-04-30T08:49:36.467040533Z TRACE quiche_apps::common] received 340 bytes
[2025-04-30T08:49:36.467042737Z TRACE quiche_apps::common] stream 4 has 340 bytes (fin? true)
[2025-04-30T08:49:36.467045071Z DEBUG quiche_apps::common] 2/2 responses received
[2025-04-30T08:49:36.467047435Z INFO  quiche_apps::common] 2/2 response(s) received in 110.054785ms, closing...
[2025-04-30T08:49:36.467053497Z TRACE quiche] f8a846691887a508a3d7d0902544d1c923e3f979 pmtud probe status false hs_con=true hs_sent=false cwnd_avail=13500 out_len=1350 left=1314
[2025-04-30T08:49:36.467056963Z TRACE quiche] f8a846691887a508a3d7d0902544d1c923e3f979 tx pkt Short dcid=96a38cf8a0e01c607f89d7319f96a003825b key_phase=false len=10 pn=20 
[2025-04-30T08:49:36.467059398Z TRACE quiche] f8a846691887a508a3d7d0902544d1c923e3f979 tx frm APPLICATION_CLOSE err=0 reason=[6b, 74, 68, 78, 62, 79, 65]
[2025-04-30T08:49:36.467066531Z TRACE quiche::recovery::congestion::recovery] f8a846691887a508a3d7d0902544d1c923e3f979 timer=137.711301ms latest_rtt=31.514167ms srtt=40.313818ms min_rtt=31.514167ms rttvar=18.103278ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=46 app_limited=true congestion_recovery_start_time=None Rate { delivered: 1555, delivered_time: Instant { tv_sec: 710, tv_nsec: 834075808 }, first_sent_time: Instant { tv_sec: 710, tv_nsec: 834075808 }, end_of_app_limited: 19, last_sent_packet: 20, largest_acked: 5, rate_sample: RateSample { delivery_rate: 34770, is_app_limited: true, interval: 35.144239ms, delivered: 1222, prior_delivered: 333, prior_time: Some(Instant { tv_sec: 710, tv_nsec: 766917797 }), send_elapsed: 476.242µs, ack_elapsed: 35.144239ms, rtt: 34.667997ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 418590, last_update: Instant { tv_sec: 710, tv_nsec: 835176761 }, next_time: Instant { tv_sec: 710, tv_nsec: 834075808 }, max_datagram_size: 1350, last_packet_size: None, iv: 109.893µs, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } 
[2025-04-30T08:49:36.467093812Z TRACE quiche_apps::client] written 46 bytes from [::]:56234 to [fd00:cafe:cafe:100::100]:443
[2025-04-30T08:49:36.467102067Z TRACE quiche_apps::client] [::]:56234 -> [fd00:cafe:cafe:100::100]:443: done writing
[2025-04-30T08:49:36.469579808Z TRACE quiche_apps::client] got 1342 bytes from [fd00:cafe:cafe:100::100]:443 to [::]:56234
[2025-04-30T08:49:36.469586791Z TRACE quiche_apps::client] [::]:56234: processed 1342 bytes
[2025-04-30T08:49:36.469590097Z TRACE quiche_apps::client] [::]:56234: recv() would block
[2025-04-30T08:49:36.469592411Z TRACE quiche_apps::client] done reading
[2025-04-30T08:49:36.469596128Z TRACE quiche_apps::client] [::]:56234 -> [fd00:cafe:cafe:100::100]:443: done writing
[2025-04-30T08:49:36.805983634Z TRACE quiche_apps::client] timed out
[2025-04-30T08:49:36.806010293Z TRACE quiche] f8a846691887a508a3d7d0902544d1c923e3f979 draining timeout expired
[2025-04-30T08:49:36.806051500Z TRACE quiche_apps::client] done reading
[2025-04-30T08:49:36.806055918Z INFO  quiche_apps::client] connection closed, recv=19 sent=21 lost=0 retrans=0 sent_bytes=2447 recv_bytes=20968 lost_bytes=0 [local_addr=[::]:56234 peer_addr=[fd00:cafe:cafe:100::100]:443 validation_state=Validated active=true recv=19 sent=21 lost=0 retrans=0 rtt=40.313818ms min_rtt=Some(31.514167ms) rttvar=18.103278ms cwnd=13500 sent_bytes=2447 recv_bytes=20968 lost_bytes=0 stream_retrans_bytes=0 pmtu=1350 delivery_rate=34770]