[2025-04-30T10:36:23.097410818Z TRACE mio::poll] registering event source with poller: token=Token(0), interests=READABLE
[2025-04-30T10:36:23.097694779Z INFO  quiche_apps::client] connecting to [fd00:cafe:cafe:100::100]:443 from [::]:35280 with scid 23c26c77f44724a732c3bdeb0a00627e6c4847cd
[2025-04-30T10:36:23.097737809Z TRACE quiche::tls] 23c26c77f44724a732c3bdeb0a00627e6c4847cd write message lvl=Initial len=266
[2025-04-30T10:36:23.097756514Z TRACE quiche] 23c26c77f44724a732c3bdeb0a00627e6c4847cd tx pkt Initial version=1 dcid=811c23116aab6ccf54ab08473dfc55f3 scid=23c26c77f44724a732c3bdeb0a00627e6c4847cd len=270 pn=0 
[2025-04-30T10:36:23.097759649Z TRACE quiche] 23c26c77f44724a732c3bdeb0a00627e6c4847cd tx frm CRYPTO off=0 len=266
[2025-04-30T10:36:23.097773575Z TRACE quiche::recovery::congestion::recovery] 23c26c77f44724a732c3bdeb0a00627e6c4847cd timer=998.930631ms 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: 805, tv_nsec: 228748595 }, first_sent_time: Instant { tv_sec: 805, tv_nsec: 228748595 }, 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: 805, tv_nsec: 228748595 }, next_time: Instant { tv_sec: 805, tv_nsec: 228748595 }, 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-30T10:36:23.097819100Z TRACE quiche_apps::client] written 1200
[2025-04-30T10:36:23.140327993Z TRACE quiche_apps::client] got 1232 bytes from [fd00:cafe:cafe:100::100]:443 to [::]:35280
[2025-04-30T10:36:23.140344845Z TRACE quiche] 23c26c77f44724a732c3bdeb0a00627e6c4847cd rx pkt Initial version=1 dcid=23c26c77f44724a732c3bdeb0a00627e6c4847cd scid=1522adf0d5c9bdb1905b token= len=116 pn=0 
[2025-04-30T10:36:23.140356046Z TRACE quiche] 23c26c77f44724a732c3bdeb0a00627e6c4847cd rx frm ACK delay=0 blocks=[0..0] ecn_counts=None
[2025-04-30T10:36:23.140362067Z TRACE quiche::recovery::congestion::recovery] 23c26c77f44724a732c3bdeb0a00627e6c4847cd packet newly acked 0
[2025-04-30T10:36:23.140368068Z TRACE quiche] 23c26c77f44724a732c3bdeb0a00627e6c4847cd rx frm CRYPTO off=0 len=90
[2025-04-30T10:36:23.140469247Z TRACE quiche::tls] 23c26c77f44724a732c3bdeb0a00627e6c4847cd set write secret lvl=Handshake
[2025-04-30T10:36:23.140479406Z TRACE quiche::tls] 23c26c77f44724a732c3bdeb0a00627e6c4847cd set read secret lvl=Handshake
[2025-04-30T10:36:23.140507398Z TRACE quiche] 23c26c77f44724a732c3bdeb0a00627e6c4847cd rx pkt Handshake version=1 dcid=23c26c77f44724a732c3bdeb0a00627e6c4847cd scid=1522adf0d5c9bdb1905b len=752 pn=0 
[2025-04-30T10:36:23.140514221Z TRACE quiche] 23c26c77f44724a732c3bdeb0a00627e6c4847cd rx frm CRYPTO off=0 len=731
[2025-04-30T10:36:23.140729573Z TRACE quiche::tls] 23c26c77f44724a732c3bdeb0a00627e6c4847cd write message lvl=Handshake len=36
[2025-04-30T10:36:23.140734111Z TRACE quiche::tls] 23c26c77f44724a732c3bdeb0a00627e6c4847cd set write secret lvl=OneRTT
[2025-04-30T10:36:23.140742407Z TRACE quiche::tls] 23c26c77f44724a732c3bdeb0a00627e6c4847cd set read secret lvl=OneRTT
[2025-04-30T10:36:23.140760511Z TRACE quiche] 23c26c77f44724a732c3bdeb0a00627e6c4847cd 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(811c23116aab6ccf54ab08473dfc55f3), max_idle_timeout: 30000, stateless_reset_token: None, max_udp_payload_size: 65527, initial_max_data: 4611686018427387903, initial_max_stream_data_bidi_local: 1048576, initial_max_stream_data_bidi_remote: 1048576, initial_max_stream_data_uni: 1048576, initial_max_streams_bidi: 16, initial_max_streams_uni: 16, ack_delay_exponent: 3, max_ack_delay: 20, disable_active_migration: false, active_conn_id_limit: 8, initial_source_connection_id: Some(1522adf0d5c9bdb1905b), retry_source_connection_id: None, max_datagram_frame_size: Some(0), unknown_params: None }
[2025-04-30T10:36:23.140792180Z TRACE quiche] 23c26c77f44724a732c3bdeb0a00627e6c4847cd rx pkt Short dcid=0000000000000000000000000000000000000000 key_phase=false len=264 pn=22895 
[2025-04-30T10:36:23.140798442Z TRACE quiche] 23c26c77f44724a732c3bdeb0a00627e6c4847cd dropped invalid packet
[2025-04-30T10:36:23.140801657Z TRACE quiche_apps::client] [::]:35280: processed 1232 bytes
[2025-04-30T10:36:23.140807028Z TRACE quiche_apps::client] [::]:35280: recv() would block
[2025-04-30T10:36:23.140810103Z TRACE quiche_apps::client] done reading
[2025-04-30T10:36:23.140819000Z DEBUG quiche_apps::common] sending HTTP request "GET /zmfgmcoevk\r\n"
[2025-04-30T10:36:23.140863623Z DEBUG quiche_apps::common] sending HTTP request "GET /jbrxjcplhv\r\n"
[2025-04-30T10:36:23.140913927Z TRACE quiche] 23c26c77f44724a732c3bdeb0a00627e6c4847cd tx pkt Initial version=1 dcid=1522adf0d5c9bdb1905b scid=23c26c77f44724a732c3bdeb0a00627e6c4847cd len=6 pn=1 
[2025-04-30T10:36:23.140918175Z TRACE quiche] 23c26c77f44724a732c3bdeb0a00627e6c4847cd tx frm ACK delay=71 blocks=[0..0] ecn_counts=None
[2025-04-30T10:36:23.140927613Z TRACE quiche::recovery::congestion::recovery] 23c26c77f44724a732c3bdeb0a00627e6c4847cd timer=127.322686ms latest_rtt=42.636471ms srtt=42.636471ms min_rtt=42.636471ms rttvar=21.318235ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=0 app_limited=true congestion_recovery_start_time=None Rate { delivered: 333, delivered_time: Instant { tv_sec: 805, tv_nsec: 271802405 }, first_sent_time: Instant { tv_sec: 805, tv_nsec: 271802405 }, end_of_app_limited: 1, last_sent_packet: 1, largest_acked: 0, rate_sample: RateSample { delivery_rate: 7810, is_app_limited: true, interval: 42.636471ms, delivered: 333, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 805, tv_nsec: 228748595 }), send_elapsed: 0ns, ack_elapsed: 42.636471ms, rtt: 42.636471ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 395787, last_update: Instant { tv_sec: 805, tv_nsec: 271802365 }, next_time: Instant { tv_sec: 805, tv_nsec: 271802405 }, 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-30T10:36:23.140949363Z TRACE quiche] 23c26c77f44724a732c3bdeb0a00627e6c4847cd tx pkt Handshake version=1 dcid=1522adf0d5c9bdb1905b scid=23c26c77f44724a732c3bdeb0a00627e6c4847cd len=45 pn=2 
[2025-04-30T10:36:23.140952780Z TRACE quiche] 23c26c77f44724a732c3bdeb0a00627e6c4847cd tx frm ACK delay=55 blocks=[0..0] ecn_counts=None
[2025-04-30T10:36:23.140956146Z TRACE quiche] 23c26c77f44724a732c3bdeb0a00627e6c4847cd tx frm CRYPTO off=0 len=36
[2025-04-30T10:36:23.141001250Z TRACE quiche::recovery::congestion::recovery] 23c26c77f44724a732c3bdeb0a00627e6c4847cd timer=127.81282ms latest_rtt=42.636471ms srtt=42.636471ms min_rtt=42.636471ms rttvar=21.318235ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=101 app_limited=true congestion_recovery_start_time=None Rate { delivered: 333, delivered_time: Instant { tv_sec: 805, tv_nsec: 271802405 }, first_sent_time: Instant { tv_sec: 805, tv_nsec: 271802405 }, end_of_app_limited: 1, last_sent_packet: 2, largest_acked: 0, rate_sample: RateSample { delivery_rate: 7810, is_app_limited: true, interval: 42.636471ms, delivered: 333, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 805, tv_nsec: 228748595 }), send_elapsed: 0ns, ack_elapsed: 42.636471ms, rtt: 42.636471ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 395787, last_update: Instant { tv_sec: 805, tv_nsec: 271949048 }, next_time: Instant { tv_sec: 805, tv_nsec: 271802405 }, max_datagram_size: 1350, last_packet_size: None, iv: 255.188µ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-30T10:36:23.141021698Z TRACE quiche] 23c26c77f44724a732c3bdeb0a00627e6c4847cd dropped epoch 0 state
[2025-04-30T10:36:23.141027780Z TRACE quiche] 23c26c77f44724a732c3bdeb0a00627e6c4847cd pmtud probe status false hs_con=false hs_sent=false cwnd_avail=13399 out_len=1186 left=1158
[2025-04-30T10:36:23.141041375Z TRACE quiche] 23c26c77f44724a732c3bdeb0a00627e6c4847cd tx pkt Short dcid=1522adf0d5c9bdb1905b key_phase=false len=1158 pn=3 
[2025-04-30T10:36:23.141044571Z TRACE quiche] 23c26c77f44724a732c3bdeb0a00627e6c4847cd tx frm NEW_CONNECTION_ID seq_num=1 retire_prior_to=0 conn_id=[da, b3, ee, db, dd, 36, 45, a5, 1c, 21, 38, ba, b3, ec, eb, 2c, d8, 44, 34, 69] reset_token=[01, 03, be, 7e, d4, 4e, e6, ca, c9, 97, f2, fc, b2, 5f, 31, 68]
[2025-04-30T10:36:23.141053047Z TRACE quiche] 23c26c77f44724a732c3bdeb0a00627e6c4847cd tx frm NEW_CONNECTION_ID seq_num=2 retire_prior_to=0 conn_id=[8f, 71, 9e, 0e, 52, 4d, 8f, e0, 12, b8, 9f, 70, 89, bb, 67, 86, 9c, 58, 8d, 57] reset_token=[51, b3, f4, b8, e0, 66, f5, 59, 4f, d1, cc, 59, db, 32, c1, b7]
[2025-04-30T10:36:23.141059589Z TRACE quiche] 23c26c77f44724a732c3bdeb0a00627e6c4847cd tx frm NEW_CONNECTION_ID seq_num=3 retire_prior_to=0 conn_id=[5f, e2, 57, 02, 7d, 02, 22, 66, e7, 71, cb, 05, c7, eb, ea, 61, 61, b7, 29, 4d] reset_token=[ba, 43, 2b, 25, 86, 73, 25, df, 7f, cf, 5c, 23, 97, 8b, 08, cf]
[2025-04-30T10:36:23.141065841Z TRACE quiche] 23c26c77f44724a732c3bdeb0a00627e6c4847cd tx frm NEW_CONNECTION_ID seq_num=4 retire_prior_to=0 conn_id=[c5, c6, f5, 70, 36, 0e, 62, 97, 3a, 83, 54, 7d, 35, 18, f9, 32, d3, 3e, 5d, 06] reset_token=[24, 92, 6d, 62, 3b, 48, 0b, 27, 9a, 3e, a5, dc, df, 93, 5a, dc]
[2025-04-30T10:36:23.141072042Z TRACE quiche] 23c26c77f44724a732c3bdeb0a00627e6c4847cd tx frm NEW_CONNECTION_ID seq_num=5 retire_prior_to=0 conn_id=[e4, c5, 21, cb, d8, 2c, cc, 2e, 70, 57, 8b, 0f, 3d, a4, e4, 1a, 21, 75, 76, 87] reset_token=[8e, e9, b0, 85, 30, 0c, 99, 28, 6f, 4b, 5c, 88, 69, 88, 7e, e5]
[2025-04-30T10:36:23.141078164Z TRACE quiche] 23c26c77f44724a732c3bdeb0a00627e6c4847cd tx frm NEW_CONNECTION_ID seq_num=6 retire_prior_to=0 conn_id=[0f, 42, 90, ca, e7, 53, b1, 72, f6, 75, 74, 7c, 13, dc, 54, 36, 0b, 56, e0, 6c] reset_token=[d9, f2, a1, e7, c6, 8c, 6e, 4a, 53, 35, 8e, c1, 61, eb, f0, d3]
[2025-04-30T10:36:23.141084485Z TRACE quiche] 23c26c77f44724a732c3bdeb0a00627e6c4847cd tx frm NEW_CONNECTION_ID seq_num=7 retire_prior_to=0 conn_id=[31, 3d, 63, d0, bb, 31, 21, 40, 08, 05, f8, c6, c8, 8b, 09, 3a, 73, fd, 2a, a7] reset_token=[b5, e5, 70, 61, 4e, 17, 79, 3b, c3, 19, 76, 33, 36, 55, c1, 6b]
[2025-04-30T10:36:23.141090657Z TRACE quiche] 23c26c77f44724a732c3bdeb0a00627e6c4847cd tx frm STREAM id=0 off=0 len=17 fin=true
[2025-04-30T10:36:23.141093943Z TRACE quiche] 23c26c77f44724a732c3bdeb0a00627e6c4847cd tx frm PADDING len=856
[2025-04-30T10:36:23.141104673Z TRACE quiche::recovery::congestion::recovery] 23c26c77f44724a732c3bdeb0a00627e6c4847cd timer=127.709748ms latest_rtt=42.636471ms srtt=42.636471ms min_rtt=42.636471ms rttvar=21.318235ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=1287 app_limited=true congestion_recovery_start_time=None Rate { delivered: 333, delivered_time: Instant { tv_sec: 805, tv_nsec: 271802405 }, first_sent_time: Instant { tv_sec: 805, tv_nsec: 271802405 }, end_of_app_limited: 2, last_sent_packet: 3, largest_acked: 0, rate_sample: RateSample { delivery_rate: 7810, is_app_limited: true, interval: 42.636471ms, delivered: 333, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 805, tv_nsec: 228748595 }), send_elapsed: 0ns, ack_elapsed: 42.636471ms, rtt: 42.636471ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 1186, rate: 395787, last_update: Instant { tv_sec: 805, tv_nsec: 271949048 }, next_time: Instant { tv_sec: 805, tv_nsec: 272204236 }, max_datagram_size: 1350, last_packet_size: Some(1186), 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-30T10:36:23.141146151Z TRACE quiche_apps::client] written 1350 bytes from [::]:35280 to [fd00:cafe:cafe:100::100]:443
[2025-04-30T10:36:23.141154426Z TRACE quiche] 23c26c77f44724a732c3bdeb0a00627e6c4847cd pmtud probe status false hs_con=false hs_sent=false cwnd_avail=12213 out_len=1350 left=1322
[2025-04-30T10:36:23.141158684Z TRACE quiche] 23c26c77f44724a732c3bdeb0a00627e6c4847cd tx pkt Short dcid=1522adf0d5c9bdb1905b key_phase=false len=22 pn=4 
[2025-04-30T10:36:23.141161780Z TRACE quiche] 23c26c77f44724a732c3bdeb0a00627e6c4847cd tx frm STREAM id=4 off=0 len=17 fin=true
[2025-04-30T10:36:23.141168442Z TRACE quiche::recovery::congestion::recovery] 23c26c77f44724a732c3bdeb0a00627e6c4847cd timer=127.646129ms latest_rtt=42.636471ms srtt=42.636471ms min_rtt=42.636471ms rttvar=21.318235ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=1337 app_limited=true congestion_recovery_start_time=None Rate { delivered: 333, delivered_time: Instant { tv_sec: 805, tv_nsec: 271802405 }, first_sent_time: Instant { tv_sec: 805, tv_nsec: 271802405 }, end_of_app_limited: 3, last_sent_packet: 4, largest_acked: 0, rate_sample: RateSample { delivery_rate: 7810, is_app_limited: true, interval: 42.636471ms, delivered: 333, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 805, tv_nsec: 228748595 }), send_elapsed: 0ns, ack_elapsed: 42.636471ms, rtt: 42.636471ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 395787, last_update: Instant { tv_sec: 805, tv_nsec: 272195008 }, next_time: Instant { tv_sec: 805, tv_nsec: 272204236 }, max_datagram_size: 1350, last_packet_size: None, iv: 3.122892ms, 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-30T10:36:23.141191535Z TRACE quiche_apps::client] written 50 bytes from [::]:35280 to [fd00:cafe:cafe:100::100]:443
[2025-04-30T10:36:23.141195452Z TRACE quiche_apps::client] [::]:35280 -> [fd00:cafe:cafe:100::100]:443: done writing
[2025-04-30T10:36:23.174360800Z TRACE quiche_apps::client] got 1332 bytes from [fd00:cafe:cafe:100::100]:443 to [::]:35280
[2025-04-30T10:36:23.174376610Z TRACE quiche] 23c26c77f44724a732c3bdeb0a00627e6c4847cd rx pkt Handshake version=1 dcid=23c26c77f44724a732c3bdeb0a00627e6c4847cd scid=1522adf0d5c9bdb1905b len=22 pn=1 
[2025-04-30T10:36:23.174385737Z TRACE quiche] 23c26c77f44724a732c3bdeb0a00627e6c4847cd rx frm ACK delay=0 blocks=[2..2] ecn_counts=None
[2025-04-30T10:36:23.174390505Z TRACE quiche::recovery::congestion::recovery] 23c26c77f44724a732c3bdeb0a00627e6c4847cd packet newly acked 2
[2025-04-30T10:36:23.174407928Z TRACE quiche] 23c26c77f44724a732c3bdeb0a00627e6c4847cd rx pkt Short dcid=23c26c77f44724a732c3bdeb0a00627e6c4847cd key_phase=false len=1250 pn=0 
[2025-04-30T10:36:23.174414721Z TRACE quiche] 23c26c77f44724a732c3bdeb0a00627e6c4847cd rx frm ACK delay=0 blocks=[3..3] ecn_counts=None
[2025-04-30T10:36:23.174418348Z TRACE quiche::recovery::congestion::recovery] 23c26c77f44724a732c3bdeb0a00627e6c4847cd packet newly acked 3
[2025-04-30T10:36:23.174422786Z TRACE quiche] 23c26c77f44724a732c3bdeb0a00627e6c4847cd rx frm HANDSHAKE_DONE
[2025-04-30T10:36:23.174427154Z TRACE quiche] 23c26c77f44724a732c3bdeb0a00627e6c4847cd dropped epoch 1 state
[2025-04-30T10:36:23.174431823Z TRACE quiche] 23c26c77f44724a732c3bdeb0a00627e6c4847cd rx frm NEW_CONNECTION_ID seq_num=1 retire_prior_to=0 conn_id=[03, 62, ef, a9, 12, 89, 7d, 71, eb, 8a] reset_token=[f7, 49, 46, 61, 4e, 15, e1, 72, 31, cf, 23, ea, 92, f7, 41, e3]
[2025-04-30T10:36:23.174447171Z TRACE quiche] 23c26c77f44724a732c3bdeb0a00627e6c4847cd rx frm NEW_CONNECTION_ID seq_num=2 retire_prior_to=0 conn_id=[63, 8d, 26, 11, 64, f3, a6, 1f, 18, 89] reset_token=[48, d5, c5, a6, 82, e7, 16, b3, cd, 56, 29, c6, 27, 00, 05, 87]
[2025-04-30T10:36:23.174453193Z TRACE quiche] 23c26c77f44724a732c3bdeb0a00627e6c4847cd rx frm NEW_CONNECTION_ID seq_num=3 retire_prior_to=0 conn_id=[db, f3, ff, d5, b6, 5f, a5, 15, c1, f2] reset_token=[2b, c1, 58, 1b, bc, b1, 2c, 86, 9c, 87, 39, 41, d1, 75, c9, 65]
[2025-04-30T10:36:23.174458713Z TRACE quiche] 23c26c77f44724a732c3bdeb0a00627e6c4847cd rx frm NEW_CONNECTION_ID seq_num=4 retire_prior_to=0 conn_id=[f4, e8, f8, ac, 54, aa, 3f, 1d, 5a, d5] reset_token=[4d, 91, 0e, 45, 7e, 34, 17, d9, 45, d9, d0, a8, bc, 8a, 7f, 66]
[2025-04-30T10:36:23.174464884Z TRACE quiche] 23c26c77f44724a732c3bdeb0a00627e6c4847cd rx frm NEW_CONNECTION_ID seq_num=5 retire_prior_to=0 conn_id=[5e, e8, 6e, 97, 15, 8d, 09, 74, 07, 28] reset_token=[bc, 50, 5d, 0a, 32, b2, 8e, d7, 35, c1, cb, 6b, 25, 03, f9, fd]
[2025-04-30T10:36:23.174470745Z TRACE quiche] 23c26c77f44724a732c3bdeb0a00627e6c4847cd rx frm NEW_CONNECTION_ID seq_num=6 retire_prior_to=0 conn_id=[17, 45, c4, a2, fa, 93, 60, 2a, 0b, 2d] reset_token=[c6, 36, d1, 13, 82, 46, cd, 9d, cd, 54, 13, 6f, ce, 24, e3, 18]
[2025-04-30T10:36:23.174476486Z TRACE quiche] 23c26c77f44724a732c3bdeb0a00627e6c4847cd rx frm NEW_CONNECTION_ID seq_num=7 retire_prior_to=0 conn_id=[ac, 09, ad, 9c, 26, f8, 77, ed, 8a, 71] reset_token=[f3, 44, b2, 1b, 52, 93, e1, b7, 6e, d4, 23, a6, 20, 92, 0b, 3b]
[2025-04-30T10:36:23.174485493Z TRACE quiche] 23c26c77f44724a732c3bdeb0a00627e6c4847cd rx frm PADDING len=1017
[2025-04-30T10:36:23.174518575Z TRACE quiche_apps::client] [::]:35280: processed 1332 bytes
[2025-04-30T10:36:23.174523885Z TRACE quiche_apps::client] [::]:35280: recv() would block
[2025-04-30T10:36:23.174526860Z TRACE quiche_apps::client] done reading
[2025-04-30T10:36:23.174536037Z TRACE quiche] 23c26c77f44724a732c3bdeb0a00627e6c4847cd pmtud probe status false hs_con=true hs_sent=false cwnd_avail=13450 out_len=1350 left=1317
[2025-04-30T10:36:23.174541377Z TRACE quiche] 23c26c77f44724a732c3bdeb0a00627e6c4847cd tx pkt Short dcid=1522adf0d5c9bdb1905b key_phase=false len=5 pn=5 
[2025-04-30T10:36:23.174544473Z TRACE quiche] 23c26c77f44724a732c3bdeb0a00627e6c4847cd tx frm ACK delay=15 blocks=[0..0] ecn_counts=None
[2025-04-30T10:36:23.174552618Z TRACE quiche::recovery::congestion::recovery] 23c26c77f44724a732c3bdeb0a00627e6c4847cd timer=90.068583ms latest_rtt=33.246478ms srtt=40.476021ms min_rtt=33.246478ms rttvar=15.748575ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=50 app_limited=true congestion_recovery_start_time=None Rate { delivered: 1620, delivered_time: Instant { tv_sec: 805, tv_nsec: 305450714 }, first_sent_time: Instant { tv_sec: 805, tv_nsec: 271802405 }, end_of_app_limited: 4, last_sent_packet: 5, largest_acked: 3, rate_sample: RateSample { delivery_rate: 38286, is_app_limited: true, interval: 33.615217ms, delivered: 1287, prior_delivered: 333, prior_time: Some(Instant { tv_sec: 805, tv_nsec: 271802405 }), send_elapsed: 0ns, ack_elapsed: 33.615217ms, rtt: 33.615217ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 416913, last_update: Instant { tv_sec: 805, tv_nsec: 305575337 }, next_time: Instant { tv_sec: 805, tv_nsec: 308698229 }, 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-30T10:36:23.174595518Z TRACE quiche_apps::client] written 33 bytes from [::]:35280 to [fd00:cafe:cafe:100::100]:443
[2025-04-30T10:36:23.174605867Z TRACE quiche_apps::client] [::]:35280 -> [fd00:cafe:cafe:100::100]:443: done writing
[2025-04-30T10:36:23.175442439Z TRACE quiche_apps::client] got 1332 bytes from [fd00:cafe:cafe:100::100]:443 to [::]:35280
[2025-04-30T10:36:23.175452928Z TRACE quiche] 23c26c77f44724a732c3bdeb0a00627e6c4847cd rx pkt Short dcid=23c26c77f44724a732c3bdeb0a00627e6c4847cd key_phase=false len=1311 pn=1 
[2025-04-30T10:36:23.175459491Z TRACE quiche] 23c26c77f44724a732c3bdeb0a00627e6c4847cd rx frm PING mtu_probe=None
[2025-04-30T10:36:23.175466574Z TRACE quiche] 23c26c77f44724a732c3bdeb0a00627e6c4847cd rx frm PADDING len=1293
[2025-04-30T10:36:23.175473066Z TRACE quiche_apps::client] [::]:35280: processed 1332 bytes
[2025-04-30T10:36:23.175476623Z TRACE quiche_apps::client] [::]:35280: recv() would block
[2025-04-30T10:36:23.175478957Z TRACE quiche_apps::client] done reading
[2025-04-30T10:36:23.175485539Z TRACE quiche] 23c26c77f44724a732c3bdeb0a00627e6c4847cd pmtud probe status false hs_con=true hs_sent=false cwnd_avail=13450 out_len=1350 left=1317
[2025-04-30T10:36:23.175488926Z TRACE quiche] 23c26c77f44724a732c3bdeb0a00627e6c4847cd tx pkt Short dcid=1522adf0d5c9bdb1905b key_phase=false len=5 pn=6 
[2025-04-30T10:36:23.175491390Z TRACE quiche] 23c26c77f44724a732c3bdeb0a00627e6c4847cd tx frm ACK delay=4 blocks=[0..1] ecn_counts=None
[2025-04-30T10:36:23.175497822Z TRACE quiche::recovery::congestion::recovery] 23c26c77f44724a732c3bdeb0a00627e6c4847cd timer=89.123489ms latest_rtt=33.246478ms srtt=40.476021ms min_rtt=33.246478ms rttvar=15.748575ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=50 app_limited=true congestion_recovery_start_time=None Rate { delivered: 1620, delivered_time: Instant { tv_sec: 805, tv_nsec: 305450714 }, first_sent_time: Instant { tv_sec: 805, tv_nsec: 271802405 }, end_of_app_limited: 4, last_sent_packet: 6, largest_acked: 3, rate_sample: RateSample { delivery_rate: 38286, is_app_limited: true, interval: 33.615217ms, delivered: 1287, prior_delivered: 333, prior_time: Some(Instant { tv_sec: 805, tv_nsec: 271802405 }), send_elapsed: 0ns, ack_elapsed: 33.615217ms, rtt: 33.615217ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 416913, last_update: Instant { tv_sec: 805, tv_nsec: 305575337 }, next_time: Instant { tv_sec: 805, tv_nsec: 308698229 }, 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-30T10:36:23.175527988Z TRACE quiche_apps::client] written 33 bytes from [::]:35280 to [fd00:cafe:cafe:100::100]:443
[2025-04-30T10:36:23.175532206Z TRACE quiche_apps::client] [::]:35280 -> [fd00:cafe:cafe:100::100]:443: done writing
[2025-04-30T10:36:23.176504341Z TRACE quiche_apps::client] got 1232 bytes from [fd00:cafe:cafe:100::100]:443 to [::]:35280
[2025-04-30T10:36:23.176514660Z TRACE quiche] 23c26c77f44724a732c3bdeb0a00627e6c4847cd rx pkt Short dcid=23c26c77f44724a732c3bdeb0a00627e6c4847cd key_phase=false len=1211 pn=2 
[2025-04-30T10:36:23.176522084Z TRACE quiche] 23c26c77f44724a732c3bdeb0a00627e6c4847cd rx frm STREAM id=0 off=0 len=1192 fin=false
[2025-04-30T10:36:23.176529648Z TRACE quiche_apps::client] [::]:35280: processed 1232 bytes
[2025-04-30T10:36:23.176533144Z TRACE quiche_apps::client] [::]:35280: recv() would block
[2025-04-30T10:36:23.176535459Z TRACE quiche_apps::client] done reading
[2025-04-30T10:36:23.176540258Z TRACE quiche_apps::common] received 1192 bytes
[2025-04-30T10:36:23.176543163Z TRACE quiche_apps::common] stream 0 has 1192 bytes (fin? false)
[2025-04-30T10:36:23.176549755Z TRACE quiche] 23c26c77f44724a732c3bdeb0a00627e6c4847cd pmtud probe status false hs_con=true hs_sent=false cwnd_avail=13450 out_len=1350 left=1317
[2025-04-30T10:36:23.176553012Z TRACE quiche] 23c26c77f44724a732c3bdeb0a00627e6c4847cd tx pkt Short dcid=1522adf0d5c9bdb1905b key_phase=false len=5 pn=7 
[2025-04-30T10:36:23.176560515Z TRACE quiche] 23c26c77f44724a732c3bdeb0a00627e6c4847cd tx frm ACK delay=4 blocks=[0..2] ecn_counts=None
[2025-04-30T10:36:23.176567358Z TRACE quiche::recovery::congestion::recovery] 23c26c77f44724a732c3bdeb0a00627e6c4847cd timer=88.054013ms latest_rtt=33.246478ms srtt=40.476021ms min_rtt=33.246478ms rttvar=15.748575ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=50 app_limited=true congestion_recovery_start_time=None Rate { delivered: 1620, delivered_time: Instant { tv_sec: 805, tv_nsec: 305450714 }, first_sent_time: Instant { tv_sec: 805, tv_nsec: 271802405 }, end_of_app_limited: 4, last_sent_packet: 7, largest_acked: 3, rate_sample: RateSample { delivery_rate: 38286, is_app_limited: true, interval: 33.615217ms, delivered: 1287, prior_delivered: 333, prior_time: Some(Instant { tv_sec: 805, tv_nsec: 271802405 }), send_elapsed: 0ns, ack_elapsed: 33.615217ms, rtt: 33.615217ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 416913, last_update: Instant { tv_sec: 805, tv_nsec: 305575337 }, next_time: Instant { tv_sec: 805, tv_nsec: 308698229 }, 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-30T10:36:23.176597184Z TRACE quiche_apps::client] written 33 bytes from [::]:35280 to [fd00:cafe:cafe:100::100]:443
[2025-04-30T10:36:23.176601191Z TRACE quiche_apps::client] [::]:35280 -> [fd00:cafe:cafe:100::100]:443: done writing
[2025-04-30T10:36:23.177531297Z TRACE quiche_apps::client] got 1232 bytes from [fd00:cafe:cafe:100::100]:443 to [::]:35280
[2025-04-30T10:36:23.177541767Z TRACE quiche] 23c26c77f44724a732c3bdeb0a00627e6c4847cd rx pkt Short dcid=23c26c77f44724a732c3bdeb0a00627e6c4847cd key_phase=false len=1211 pn=3 
[2025-04-30T10:36:23.177548900Z TRACE quiche] 23c26c77f44724a732c3bdeb0a00627e6c4847cd rx frm STREAM id=0 off=1192 len=1190 fin=false
[2025-04-30T10:36:23.177556705Z TRACE quiche_apps::client] [::]:35280: processed 1232 bytes
[2025-04-30T10:36:23.177560231Z TRACE quiche_apps::client] [::]:35280: recv() would block
[2025-04-30T10:36:23.177562525Z TRACE quiche_apps::client] done reading
[2025-04-30T10:36:23.177566693Z TRACE quiche_apps::common] received 1190 bytes
[2025-04-30T10:36:23.177568937Z TRACE quiche_apps::common] stream 0 has 1190 bytes (fin? false)
[2025-04-30T10:36:23.177575490Z TRACE quiche] 23c26c77f44724a732c3bdeb0a00627e6c4847cd pmtud probe status false hs_con=true hs_sent=false cwnd_avail=13450 out_len=1350 left=1317
[2025-04-30T10:36:23.177578766Z TRACE quiche] 23c26c77f44724a732c3bdeb0a00627e6c4847cd tx pkt Short dcid=1522adf0d5c9bdb1905b key_phase=false len=5 pn=8 
[2025-04-30T10:36:23.177581180Z TRACE quiche] 23c26c77f44724a732c3bdeb0a00627e6c4847cd tx frm ACK delay=4 blocks=[0..3] ecn_counts=None
[2025-04-30T10:36:23.177587833Z TRACE quiche::recovery::congestion::recovery] 23c26c77f44724a732c3bdeb0a00627e6c4847cd timer=87.033548ms latest_rtt=33.246478ms srtt=40.476021ms min_rtt=33.246478ms rttvar=15.748575ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=50 app_limited=true congestion_recovery_start_time=None Rate { delivered: 1620, delivered_time: Instant { tv_sec: 805, tv_nsec: 305450714 }, first_sent_time: Instant { tv_sec: 805, tv_nsec: 271802405 }, end_of_app_limited: 4, last_sent_packet: 8, largest_acked: 3, rate_sample: RateSample { delivery_rate: 38286, is_app_limited: true, interval: 33.615217ms, delivered: 1287, prior_delivered: 333, prior_time: Some(Instant { tv_sec: 805, tv_nsec: 271802405 }), send_elapsed: 0ns, ack_elapsed: 33.615217ms, rtt: 33.615217ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 416913, last_update: Instant { tv_sec: 805, tv_nsec: 305575337 }, next_time: Instant { tv_sec: 805, tv_nsec: 308698229 }, 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-30T10:36:23.177622508Z TRACE quiche_apps::client] written 33 bytes from [::]:35280 to [fd00:cafe:cafe:100::100]:443
[2025-04-30T10:36:23.177626695Z TRACE quiche_apps::client] [::]:35280 -> [fd00:cafe:cafe:100::100]:443: done writing
[2025-04-30T10:36:23.179896031Z TRACE quiche_apps::client] got 1232 bytes from [fd00:cafe:cafe:100::100]:443 to [::]:35280
[2025-04-30T10:36:23.179910227Z TRACE quiche] 23c26c77f44724a732c3bdeb0a00627e6c4847cd rx pkt Short dcid=23c26c77f44724a732c3bdeb0a00627e6c4847cd key_phase=false len=1211 pn=4 
[2025-04-30T10:36:23.179919034Z TRACE quiche] 23c26c77f44724a732c3bdeb0a00627e6c4847cd rx frm STREAM id=0 off=2382 len=1190 fin=false
[2025-04-30T10:36:23.179928611Z TRACE quiche_apps::client] [::]:35280: processed 1232 bytes
[2025-04-30T10:36:23.179933040Z TRACE quiche_apps::client] [::]:35280: recv() would block
[2025-04-30T10:36:23.179935885Z TRACE quiche_apps::client] done reading
[2025-04-30T10:36:23.179941275Z TRACE quiche_apps::common] received 1190 bytes
[2025-04-30T10:36:23.179944140Z TRACE quiche_apps::common] stream 0 has 1190 bytes (fin? false)
[2025-04-30T10:36:23.179952716Z TRACE quiche] 23c26c77f44724a732c3bdeb0a00627e6c4847cd pmtud probe status false hs_con=true hs_sent=false cwnd_avail=13450 out_len=1350 left=1317
[2025-04-30T10:36:23.179956754Z TRACE quiche] 23c26c77f44724a732c3bdeb0a00627e6c4847cd tx pkt Short dcid=1522adf0d5c9bdb1905b key_phase=false len=5 pn=9 
[2025-04-30T10:36:23.179988583Z TRACE quiche] 23c26c77f44724a732c3bdeb0a00627e6c4847cd tx frm ACK delay=5 blocks=[0..4] ecn_counts=None
[2025-04-30T10:36:23.179997790Z TRACE quiche::recovery::congestion::recovery] 23c26c77f44724a732c3bdeb0a00627e6c4847cd timer=84.62335ms latest_rtt=33.246478ms srtt=40.476021ms min_rtt=33.246478ms rttvar=15.748575ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=50 app_limited=true congestion_recovery_start_time=None Rate { delivered: 1620, delivered_time: Instant { tv_sec: 805, tv_nsec: 305450714 }, first_sent_time: Instant { tv_sec: 805, tv_nsec: 271802405 }, end_of_app_limited: 4, last_sent_packet: 9, largest_acked: 3, rate_sample: RateSample { delivery_rate: 38286, is_app_limited: true, interval: 33.615217ms, delivered: 1287, prior_delivered: 333, prior_time: Some(Instant { tv_sec: 805, tv_nsec: 271802405 }), send_elapsed: 0ns, ack_elapsed: 33.615217ms, rtt: 33.615217ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 416913, last_update: Instant { tv_sec: 805, tv_nsec: 305575337 }, next_time: Instant { tv_sec: 805, tv_nsec: 308698229 }, 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-30T10:36:23.180033126Z TRACE quiche_apps::client] written 33 bytes from [::]:35280 to [fd00:cafe:cafe:100::100]:443
[2025-04-30T10:36:23.180038166Z TRACE quiche_apps::client] [::]:35280 -> [fd00:cafe:cafe:100::100]:443: done writing
[2025-04-30T10:36:23.180900958Z TRACE quiche_apps::client] got 1232 bytes from [fd00:cafe:cafe:100::100]:443 to [::]:35280
[2025-04-30T10:36:23.180909154Z TRACE quiche] 23c26c77f44724a732c3bdeb0a00627e6c4847cd rx pkt Short dcid=23c26c77f44724a732c3bdeb0a00627e6c4847cd key_phase=false len=1211 pn=5 
[2025-04-30T10:36:23.180916157Z TRACE quiche] 23c26c77f44724a732c3bdeb0a00627e6c4847cd rx frm STREAM id=0 off=3572 len=1190 fin=false
[2025-04-30T10:36:23.180923851Z TRACE quiche_apps::client] [::]:35280: processed 1232 bytes
[2025-04-30T10:36:23.180927348Z TRACE quiche_apps::client] [::]:35280: recv() would block
[2025-04-30T10:36:23.180929682Z TRACE quiche_apps::client] done reading
[2025-04-30T10:36:23.180939521Z TRACE quiche_apps::common] received 1190 bytes
[2025-04-30T10:36:23.180941945Z TRACE quiche_apps::common] stream 0 has 1190 bytes (fin? false)
[2025-04-30T10:36:23.180948828Z TRACE quiche] 23c26c77f44724a732c3bdeb0a00627e6c4847cd pmtud probe status false hs_con=true hs_sent=false cwnd_avail=13450 out_len=1350 left=1317
[2025-04-30T10:36:23.180952184Z TRACE quiche] 23c26c77f44724a732c3bdeb0a00627e6c4847cd tx pkt Short dcid=1522adf0d5c9bdb1905b key_phase=false len=5 pn=10 
[2025-04-30T10:36:23.180954669Z TRACE quiche] 23c26c77f44724a732c3bdeb0a00627e6c4847cd tx frm ACK delay=5 blocks=[0..5] ecn_counts=None
[2025-04-30T10:36:23.180983182Z TRACE quiche::recovery::congestion::recovery] 23c26c77f44724a732c3bdeb0a00627e6c4847cd timer=83.637929ms latest_rtt=33.246478ms srtt=40.476021ms min_rtt=33.246478ms rttvar=15.748575ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=50 app_limited=true congestion_recovery_start_time=None Rate { delivered: 1620, delivered_time: Instant { tv_sec: 805, tv_nsec: 305450714 }, first_sent_time: Instant { tv_sec: 805, tv_nsec: 271802405 }, end_of_app_limited: 4, last_sent_packet: 10, largest_acked: 3, rate_sample: RateSample { delivery_rate: 38286, is_app_limited: true, interval: 33.615217ms, delivered: 1287, prior_delivered: 333, prior_time: Some(Instant { tv_sec: 805, tv_nsec: 271802405 }), send_elapsed: 0ns, ack_elapsed: 33.615217ms, rtt: 33.615217ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 416913, last_update: Instant { tv_sec: 805, tv_nsec: 305575337 }, next_time: Instant { tv_sec: 805, tv_nsec: 308698229 }, 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-30T10:36:23.181016674Z TRACE quiche_apps::client] written 33 bytes from [::]:35280 to [fd00:cafe:cafe:100::100]:443
[2025-04-30T10:36:23.181020933Z TRACE quiche_apps::client] [::]:35280 -> [fd00:cafe:cafe:100::100]:443: done writing
[2025-04-30T10:36:23.183020093Z TRACE quiche_apps::client] got 1232 bytes from [fd00:cafe:cafe:100::100]:443 to [::]:35280
[2025-04-30T10:36:23.183030793Z TRACE quiche] 23c26c77f44724a732c3bdeb0a00627e6c4847cd rx pkt Short dcid=23c26c77f44724a732c3bdeb0a00627e6c4847cd key_phase=false len=1211 pn=6 
[2025-04-30T10:36:23.183037486Z TRACE quiche] 23c26c77f44724a732c3bdeb0a00627e6c4847cd rx frm STREAM id=0 off=4762 len=358 fin=true
[2025-04-30T10:36:23.183041544Z TRACE quiche] 23c26c77f44724a732c3bdeb0a00627e6c4847cd rx frm STREAM id=4 off=0 len=828 fin=false
[2025-04-30T10:36:23.183049027Z TRACE quiche_apps::client] [::]:35280: processed 1232 bytes
[2025-04-30T10:36:23.183052524Z TRACE quiche_apps::client] [::]:35280: recv() would block
[2025-04-30T10:36:23.183054818Z TRACE quiche_apps::client] done reading
[2025-04-30T10:36:23.183060699Z TRACE quiche_apps::common] received 358 bytes
[2025-04-30T10:36:23.183063114Z TRACE quiche_apps::common] stream 0 has 358 bytes (fin? true)
[2025-04-30T10:36:23.183065458Z DEBUG quiche_apps::common] 1/2 responses received
[2025-04-30T10:36:23.183068654Z TRACE quiche_apps::common] received 828 bytes
[2025-04-30T10:36:23.183070838Z TRACE quiche_apps::common] stream 4 has 828 bytes (fin? false)
[2025-04-30T10:36:23.183077460Z TRACE quiche] 23c26c77f44724a732c3bdeb0a00627e6c4847cd pmtud probe status false hs_con=true hs_sent=false cwnd_avail=13450 out_len=1350 left=1317
[2025-04-30T10:36:23.183080666Z TRACE quiche] 23c26c77f44724a732c3bdeb0a00627e6c4847cd tx pkt Short dcid=1522adf0d5c9bdb1905b key_phase=false len=5 pn=11 
[2025-04-30T10:36:23.183083151Z TRACE quiche] 23c26c77f44724a732c3bdeb0a00627e6c4847cd tx frm ACK delay=5 blocks=[0..6] ecn_counts=None
[2025-04-30T10:36:23.183089383Z TRACE quiche::recovery::congestion::recovery] 23c26c77f44724a732c3bdeb0a00627e6c4847cd timer=81.531878ms latest_rtt=33.246478ms srtt=40.476021ms min_rtt=33.246478ms rttvar=15.748575ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=50 app_limited=true congestion_recovery_start_time=None Rate { delivered: 1620, delivered_time: Instant { tv_sec: 805, tv_nsec: 305450714 }, first_sent_time: Instant { tv_sec: 805, tv_nsec: 271802405 }, end_of_app_limited: 4, last_sent_packet: 11, largest_acked: 3, rate_sample: RateSample { delivery_rate: 38286, is_app_limited: true, interval: 33.615217ms, delivered: 1287, prior_delivered: 333, prior_time: Some(Instant { tv_sec: 805, tv_nsec: 271802405 }), send_elapsed: 0ns, ack_elapsed: 33.615217ms, rtt: 33.615217ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 416913, last_update: Instant { tv_sec: 805, tv_nsec: 305575337 }, next_time: Instant { tv_sec: 805, tv_nsec: 308698229 }, 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-30T10:36:23.183124338Z TRACE quiche_apps::client] written 33 bytes from [::]:35280 to [fd00:cafe:cafe:100::100]:443
[2025-04-30T10:36:23.183128506Z TRACE quiche_apps::client] [::]:35280 -> [fd00:cafe:cafe:100::100]:443: done writing
[2025-04-30T10:36:23.184028085Z TRACE quiche_apps::client] got 1232 bytes from [fd00:cafe:cafe:100::100]:443 to [::]:35280
[2025-04-30T10:36:23.184038614Z TRACE quiche] 23c26c77f44724a732c3bdeb0a00627e6c4847cd rx pkt Short dcid=23c26c77f44724a732c3bdeb0a00627e6c4847cd key_phase=false len=1211 pn=7 
[2025-04-30T10:36:23.184045407Z TRACE quiche] 23c26c77f44724a732c3bdeb0a00627e6c4847cd rx frm STREAM id=4 off=828 len=1190 fin=false
[2025-04-30T10:36:23.184053051Z TRACE quiche_apps::client] [::]:35280: processed 1232 bytes
[2025-04-30T10:36:23.184056598Z TRACE quiche_apps::client] [::]:35280: recv() would block
[2025-04-30T10:36:23.184058932Z TRACE quiche_apps::client] done reading
[2025-04-30T10:36:23.184063160Z TRACE quiche_apps::common] received 1190 bytes
[2025-04-30T10:36:23.184065384Z TRACE quiche_apps::common] stream 4 has 1190 bytes (fin? false)
[2025-04-30T10:36:23.184071806Z TRACE quiche] 23c26c77f44724a732c3bdeb0a00627e6c4847cd pmtud probe status false hs_con=true hs_sent=false cwnd_avail=13450 out_len=1350 left=1317
[2025-04-30T10:36:23.184075022Z TRACE quiche] 23c26c77f44724a732c3bdeb0a00627e6c4847cd tx pkt Short dcid=1522adf0d5c9bdb1905b key_phase=false len=5 pn=12 
[2025-04-30T10:36:23.184077517Z TRACE quiche] 23c26c77f44724a732c3bdeb0a00627e6c4847cd tx frm ACK delay=4 blocks=[0..7] ecn_counts=None
[2025-04-30T10:36:23.184084179Z TRACE quiche::recovery::congestion::recovery] 23c26c77f44724a732c3bdeb0a00627e6c4847cd timer=80.537182ms latest_rtt=33.246478ms srtt=40.476021ms min_rtt=33.246478ms rttvar=15.748575ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=50 app_limited=true congestion_recovery_start_time=None Rate { delivered: 1620, delivered_time: Instant { tv_sec: 805, tv_nsec: 305450714 }, first_sent_time: Instant { tv_sec: 805, tv_nsec: 271802405 }, end_of_app_limited: 4, last_sent_packet: 12, largest_acked: 3, rate_sample: RateSample { delivery_rate: 38286, is_app_limited: true, interval: 33.615217ms, delivered: 1287, prior_delivered: 333, prior_time: Some(Instant { tv_sec: 805, tv_nsec: 271802405 }), send_elapsed: 0ns, ack_elapsed: 33.615217ms, rtt: 33.615217ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 416913, last_update: Instant { tv_sec: 805, tv_nsec: 305575337 }, next_time: Instant { tv_sec: 805, tv_nsec: 308698229 }, 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-30T10:36:23.184118053Z TRACE quiche_apps::client] written 33 bytes from [::]:35280 to [fd00:cafe:cafe:100::100]:443
[2025-04-30T10:36:23.184122090Z TRACE quiche_apps::client] [::]:35280 -> [fd00:cafe:cafe:100::100]:443: done writing
[2025-04-30T10:36:23.186327115Z TRACE quiche_apps::client] got 1232 bytes from [fd00:cafe:cafe:100::100]:443 to [::]:35280
[2025-04-30T10:36:23.186339528Z TRACE quiche] 23c26c77f44724a732c3bdeb0a00627e6c4847cd rx pkt Short dcid=23c26c77f44724a732c3bdeb0a00627e6c4847cd key_phase=false len=1211 pn=8 
[2025-04-30T10:36:23.186347583Z TRACE quiche] 23c26c77f44724a732c3bdeb0a00627e6c4847cd rx frm STREAM id=4 off=2018 len=1190 fin=false
[2025-04-30T10:36:23.186356651Z TRACE quiche_apps::client] [::]:35280: processed 1232 bytes
[2025-04-30T10:36:23.186361009Z TRACE quiche_apps::client] [::]:35280: recv() would block
[2025-04-30T10:36:23.186363834Z TRACE quiche_apps::client] done reading
[2025-04-30T10:36:23.186368943Z TRACE quiche_apps::common] received 1190 bytes
[2025-04-30T10:36:23.186371708Z TRACE quiche_apps::common] stream 4 has 1190 bytes (fin? false)
[2025-04-30T10:36:23.186379503Z TRACE quiche] 23c26c77f44724a732c3bdeb0a00627e6c4847cd pmtud probe status false hs_con=true hs_sent=false cwnd_avail=13450 out_len=1350 left=1317
[2025-04-30T10:36:23.186383441Z TRACE quiche] 23c26c77f44724a732c3bdeb0a00627e6c4847cd tx pkt Short dcid=1522adf0d5c9bdb1905b key_phase=false len=5 pn=13 
[2025-04-30T10:36:23.186386476Z TRACE quiche] 23c26c77f44724a732c3bdeb0a00627e6c4847cd tx frm ACK delay=5 blocks=[0..8] ecn_counts=None
[2025-04-30T10:36:23.186393890Z TRACE quiche::recovery::congestion::recovery] 23c26c77f44724a732c3bdeb0a00627e6c4847cd timer=78.227411ms latest_rtt=33.246478ms srtt=40.476021ms min_rtt=33.246478ms rttvar=15.748575ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=50 app_limited=true congestion_recovery_start_time=None Rate { delivered: 1620, delivered_time: Instant { tv_sec: 805, tv_nsec: 305450714 }, first_sent_time: Instant { tv_sec: 805, tv_nsec: 271802405 }, end_of_app_limited: 4, last_sent_packet: 13, largest_acked: 3, rate_sample: RateSample { delivery_rate: 38286, is_app_limited: true, interval: 33.615217ms, delivered: 1287, prior_delivered: 333, prior_time: Some(Instant { tv_sec: 805, tv_nsec: 271802405 }), send_elapsed: 0ns, ack_elapsed: 33.615217ms, rtt: 33.615217ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 416913, last_update: Instant { tv_sec: 805, tv_nsec: 305575337 }, next_time: Instant { tv_sec: 805, tv_nsec: 308698229 }, 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-30T10:36:23.186427262Z TRACE quiche_apps::client] written 33 bytes from [::]:35280 to [fd00:cafe:cafe:100::100]:443
[2025-04-30T10:36:23.186431961Z TRACE quiche_apps::client] [::]:35280 -> [fd00:cafe:cafe:100::100]:443: done writing
[2025-04-30T10:36:23.187242894Z TRACE quiche_apps::client] got 1093 bytes from [fd00:cafe:cafe:100::100]:443 to [::]:35280
[2025-04-30T10:36:23.187254977Z TRACE quiche] 23c26c77f44724a732c3bdeb0a00627e6c4847cd rx pkt Short dcid=23c26c77f44724a732c3bdeb0a00627e6c4847cd key_phase=false len=1072 pn=9 
[2025-04-30T10:36:23.187261669Z TRACE quiche] 23c26c77f44724a732c3bdeb0a00627e6c4847cd rx frm STREAM id=4 off=3208 len=1051 fin=false
[2025-04-30T10:36:23.187268883Z TRACE quiche_apps::client] [::]:35280: processed 1093 bytes
[2025-04-30T10:36:23.187272300Z TRACE quiche_apps::client] [::]:35280: recv() would block
[2025-04-30T10:36:23.187274604Z TRACE quiche_apps::client] done reading
[2025-04-30T10:36:23.187278681Z TRACE quiche_apps::common] received 1051 bytes
[2025-04-30T10:36:23.187280936Z TRACE quiche_apps::common] stream 4 has 1051 bytes (fin? false)
[2025-04-30T10:36:23.187287598Z TRACE quiche] 23c26c77f44724a732c3bdeb0a00627e6c4847cd pmtud probe status false hs_con=true hs_sent=false cwnd_avail=13450 out_len=1350 left=1317
[2025-04-30T10:36:23.187295964Z TRACE quiche] 23c26c77f44724a732c3bdeb0a00627e6c4847cd tx pkt Short dcid=1522adf0d5c9bdb1905b key_phase=false len=5 pn=14 
[2025-04-30T10:36:23.187298528Z TRACE quiche] 23c26c77f44724a732c3bdeb0a00627e6c4847cd tx frm ACK delay=4 blocks=[0..9] ecn_counts=None
[2025-04-30T10:36:23.187304910Z TRACE quiche::recovery::congestion::recovery] 23c26c77f44724a732c3bdeb0a00627e6c4847cd timer=77.316431ms latest_rtt=33.246478ms srtt=40.476021ms min_rtt=33.246478ms rttvar=15.748575ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=50 app_limited=true congestion_recovery_start_time=None Rate { delivered: 1620, delivered_time: Instant { tv_sec: 805, tv_nsec: 305450714 }, first_sent_time: Instant { tv_sec: 805, tv_nsec: 271802405 }, end_of_app_limited: 4, last_sent_packet: 14, largest_acked: 3, rate_sample: RateSample { delivery_rate: 38286, is_app_limited: true, interval: 33.615217ms, delivered: 1287, prior_delivered: 333, prior_time: Some(Instant { tv_sec: 805, tv_nsec: 271802405 }), send_elapsed: 0ns, ack_elapsed: 33.615217ms, rtt: 33.615217ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 416913, last_update: Instant { tv_sec: 805, tv_nsec: 305575337 }, next_time: Instant { tv_sec: 805, tv_nsec: 308698229 }, 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-30T10:36:23.187333664Z TRACE quiche_apps::client] written 33 bytes from [::]:35280 to [fd00:cafe:cafe:100::100]:443
[2025-04-30T10:36:23.187337571Z TRACE quiche_apps::client] [::]:35280 -> [fd00:cafe:cafe:100::100]:443: done writing
[2025-04-30T10:36:23.194628468Z TRACE quiche_apps::client] got 44 bytes from [fd00:cafe:cafe:100::100]:443 to [::]:35280
[2025-04-30T10:36:23.194639870Z TRACE quiche] 23c26c77f44724a732c3bdeb0a00627e6c4847cd rx pkt Short dcid=23c26c77f44724a732c3bdeb0a00627e6c4847cd key_phase=false len=23 pn=10 
[2025-04-30T10:36:23.194646342Z TRACE quiche] 23c26c77f44724a732c3bdeb0a00627e6c4847cd rx frm ACK delay=2655 blocks=[3..4] ecn_counts=None
[2025-04-30T10:36:23.194650209Z TRACE quiche::recovery::congestion::recovery] 23c26c77f44724a732c3bdeb0a00627e6c4847cd packet newly acked 4
[2025-04-30T10:36:23.194661029Z TRACE quiche_apps::client] [::]:35280: processed 44 bytes
[2025-04-30T10:36:23.194664866Z TRACE quiche_apps::client] [::]:35280: recv() would block
[2025-04-30T10:36:23.194667241Z TRACE quiche_apps::client] done reading
[2025-04-30T10:36:23.194671769Z TRACE quiche_apps::client] [::]:35280 -> [fd00:cafe:cafe:100::100]:443: done writing
[2025-04-30T10:36:23.206087515Z TRACE quiche_apps::client] got 1232 bytes from [fd00:cafe:cafe:100::100]:443 to [::]:35280
[2025-04-30T10:36:23.206099237Z TRACE quiche] 23c26c77f44724a732c3bdeb0a00627e6c4847cd rx pkt Short dcid=23c26c77f44724a732c3bdeb0a00627e6c4847cd key_phase=false len=1211 pn=11 
[2025-04-30T10:36:23.206107121Z TRACE quiche] 23c26c77f44724a732c3bdeb0a00627e6c4847cd rx frm STREAM id=4 off=4259 len=1190 fin=false
[2025-04-30T10:36:23.206115607Z TRACE quiche_apps::client] [::]:35280: processed 1232 bytes
[2025-04-30T10:36:23.206119314Z TRACE quiche_apps::client] [::]:35280: recv() would block
[2025-04-30T10:36:23.206121719Z TRACE quiche_apps::client] done reading
[2025-04-30T10:36:23.206126227Z TRACE quiche_apps::common] received 1190 bytes
[2025-04-30T10:36:23.206128612Z TRACE quiche_apps::common] stream 4 has 1190 bytes (fin? false)
[2025-04-30T10:36:23.206135765Z TRACE quiche] 23c26c77f44724a732c3bdeb0a00627e6c4847cd pmtud probe status false hs_con=true hs_sent=false cwnd_avail=13500 out_len=1350 left=1317
[2025-04-30T10:36:23.206139482Z TRACE quiche] 23c26c77f44724a732c3bdeb0a00627e6c4847cd tx pkt Short dcid=1522adf0d5c9bdb1905b key_phase=false len=5 pn=15 
[2025-04-30T10:36:23.206147988Z TRACE quiche] 23c26c77f44724a732c3bdeb0a00627e6c4847cd tx frm ACK delay=4 blocks=[0..11] ecn_counts=None
[2025-04-30T10:36:23.206155371Z TRACE quiche::recovery::congestion::recovery] 23c26c77f44724a732c3bdeb0a00627e6c4847cd timer=none latest_rtt=53.477818ms srtt=39.601245ms min_rtt=33.246478ms rttvar=13.560981ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=0 app_limited=true congestion_recovery_start_time=None Rate { delivered: 1670, delivered_time: Instant { tv_sec: 805, tv_nsec: 308698229 }, first_sent_time: Instant { tv_sec: 805, tv_nsec: 308698229 }, end_of_app_limited: 14, last_sent_packet: 15, largest_acked: 4, rate_sample: RateSample { delivery_rate: 39773, is_app_limited: true, interval: 33.615217ms, delivered: 1337, prior_delivered: 333, prior_time: Some(Instant { tv_sec: 805, tv_nsec: 271802405 }), send_elapsed: 0ns, ack_elapsed: 33.615217ms, rtt: 33.615217ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 426122, last_update: Instant { tv_sec: 805, tv_nsec: 305575337 }, next_time: Instant { tv_sec: 805, tv_nsec: 308698229 }, 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-30T10:36:23.206189525Z TRACE quiche_apps::client] written 33 bytes from [::]:35280 to [fd00:cafe:cafe:100::100]:443
[2025-04-30T10:36:23.206194164Z TRACE quiche_apps::client] [::]:35280 -> [fd00:cafe:cafe:100::100]:443: done writing
[2025-04-30T10:36:23.207108701Z TRACE quiche_apps::client] got 1232 bytes from [fd00:cafe:cafe:100::100]:443 to [::]:35280
[2025-04-30T10:36:23.207115984Z TRACE quiche] 23c26c77f44724a732c3bdeb0a00627e6c4847cd rx pkt Short dcid=23c26c77f44724a732c3bdeb0a00627e6c4847cd key_phase=false len=1211 pn=12 
[2025-04-30T10:36:23.207122276Z TRACE quiche] 23c26c77f44724a732c3bdeb0a00627e6c4847cd rx frm STREAM id=4 off=5449 len=1190 fin=false
[2025-04-30T10:36:23.207128999Z TRACE quiche_apps::client] [::]:35280: processed 1232 bytes
[2025-04-30T10:36:23.207132425Z TRACE quiche_apps::client] [::]:35280: recv() would block
[2025-04-30T10:36:23.207134799Z TRACE quiche_apps::client] done reading
[2025-04-30T10:36:23.207149627Z TRACE quiche_apps::common] received 1190 bytes
[2025-04-30T10:36:23.207151971Z TRACE quiche_apps::common] stream 4 has 1190 bytes (fin? false)
[2025-04-30T10:36:23.207158193Z TRACE quiche] 23c26c77f44724a732c3bdeb0a00627e6c4847cd pmtud probe status false hs_con=true hs_sent=false cwnd_avail=13500 out_len=1350 left=1317
[2025-04-30T10:36:23.207161389Z TRACE quiche] 23c26c77f44724a732c3bdeb0a00627e6c4847cd tx pkt Short dcid=1522adf0d5c9bdb1905b key_phase=false len=5 pn=16 
[2025-04-30T10:36:23.207163833Z TRACE quiche] 23c26c77f44724a732c3bdeb0a00627e6c4847cd tx frm ACK delay=5 blocks=[0..12] ecn_counts=None
[2025-04-30T10:36:23.207169955Z TRACE quiche::recovery::congestion::recovery] 23c26c77f44724a732c3bdeb0a00627e6c4847cd timer=none latest_rtt=53.477818ms srtt=39.601245ms min_rtt=33.246478ms rttvar=13.560981ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=0 app_limited=true congestion_recovery_start_time=None Rate { delivered: 1670, delivered_time: Instant { tv_sec: 805, tv_nsec: 338199206 }, first_sent_time: Instant { tv_sec: 805, tv_nsec: 338199206 }, end_of_app_limited: 14, last_sent_packet: 16, largest_acked: 4, rate_sample: RateSample { delivery_rate: 39773, is_app_limited: true, interval: 33.615217ms, delivered: 1337, prior_delivered: 333, prior_time: Some(Instant { tv_sec: 805, tv_nsec: 271802405 }), send_elapsed: 0ns, ack_elapsed: 33.615217ms, rtt: 33.615217ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 426122, last_update: Instant { tv_sec: 805, tv_nsec: 338199206 }, next_time: Instant { tv_sec: 805, tv_nsec: 338199206 }, 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-30T10:36:23.207199811Z TRACE quiche_apps::client] written 33 bytes from [::]:35280 to [fd00:cafe:cafe:100::100]:443
[2025-04-30T10:36:23.207203858Z TRACE quiche_apps::client] [::]:35280 -> [fd00:cafe:cafe:100::100]:443: done writing
[2025-04-30T10:36:23.208242066Z TRACE quiche_apps::client] got 1372 bytes from [fd00:cafe:cafe:100::100]:443 to [::]:35280
[2025-04-30T10:36:23.208249049Z TRACE quiche] 23c26c77f44724a732c3bdeb0a00627e6c4847cd rx pkt Short dcid=23c26c77f44724a732c3bdeb0a00627e6c4847cd key_phase=false len=1351 pn=13 
[2025-04-30T10:36:23.208254539Z TRACE quiche] 23c26c77f44724a732c3bdeb0a00627e6c4847cd rx frm PING mtu_probe=None
[2025-04-30T10:36:23.208257815Z TRACE quiche] 23c26c77f44724a732c3bdeb0a00627e6c4847cd rx frm STREAM id=4 off=6639 len=1329 fin=false
[2025-04-30T10:36:23.208264227Z TRACE quiche_apps::client] [::]:35280: processed 1372 bytes
[2025-04-30T10:36:23.208267644Z TRACE quiche_apps::client] [::]:35280: recv() would block
[2025-04-30T10:36:23.208269948Z TRACE quiche_apps::client] done reading
[2025-04-30T10:36:23.208273735Z TRACE quiche_apps::common] received 1329 bytes
[2025-04-30T10:36:23.208275969Z TRACE quiche_apps::common] stream 4 has 1329 bytes (fin? false)
[2025-04-30T10:36:23.208281760Z TRACE quiche] 23c26c77f44724a732c3bdeb0a00627e6c4847cd pmtud probe status false hs_con=true hs_sent=false cwnd_avail=13500 out_len=1350 left=1317
[2025-04-30T10:36:23.208284776Z TRACE quiche] 23c26c77f44724a732c3bdeb0a00627e6c4847cd tx pkt Short dcid=1522adf0d5c9bdb1905b key_phase=false len=5 pn=17 
[2025-04-30T10:36:23.208287140Z TRACE quiche] 23c26c77f44724a732c3bdeb0a00627e6c4847cd tx frm ACK delay=4 blocks=[0..13] ecn_counts=None
[2025-04-30T10:36:23.208292650Z TRACE quiche::recovery::congestion::recovery] 23c26c77f44724a732c3bdeb0a00627e6c4847cd timer=none latest_rtt=53.477818ms srtt=39.601245ms min_rtt=33.246478ms rttvar=13.560981ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=0 app_limited=true congestion_recovery_start_time=None Rate { delivered: 1670, delivered_time: Instant { tv_sec: 805, tv_nsec: 338199206 }, first_sent_time: Instant { tv_sec: 805, tv_nsec: 338199206 }, end_of_app_limited: 14, last_sent_packet: 17, largest_acked: 4, rate_sample: RateSample { delivery_rate: 39773, is_app_limited: true, interval: 33.615217ms, delivered: 1337, prior_delivered: 333, prior_time: Some(Instant { tv_sec: 805, tv_nsec: 271802405 }), send_elapsed: 0ns, ack_elapsed: 33.615217ms, rtt: 33.615217ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 426122, last_update: Instant { tv_sec: 805, tv_nsec: 338199206 }, next_time: Instant { tv_sec: 805, tv_nsec: 338199206 }, 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-30T10:36:23.208318869Z TRACE quiche_apps::client] written 33 bytes from [::]:35280 to [fd00:cafe:cafe:100::100]:443
[2025-04-30T10:36:23.208322656Z TRACE quiche_apps::client] [::]:35280 -> [fd00:cafe:cafe:100::100]:443: done writing
[2025-04-30T10:36:23.209345525Z TRACE quiche_apps::client] got 1332 bytes from [fd00:cafe:cafe:100::100]:443 to [::]:35280
[2025-04-30T10:36:23.209352418Z TRACE quiche] 23c26c77f44724a732c3bdeb0a00627e6c4847cd rx pkt Short dcid=23c26c77f44724a732c3bdeb0a00627e6c4847cd key_phase=false len=1311 pn=14 
[2025-04-30T10:36:23.209358279Z TRACE quiche] 23c26c77f44724a732c3bdeb0a00627e6c4847cd rx frm STREAM id=4 off=7968 len=1290 fin=false
[2025-04-30T10:36:23.209364380Z TRACE quiche_apps::client] [::]:35280: processed 1332 bytes
[2025-04-30T10:36:23.209372426Z TRACE quiche_apps::client] [::]:35280: recv() would block
[2025-04-30T10:36:23.209374800Z TRACE quiche_apps::client] done reading
[2025-04-30T10:36:23.209378657Z TRACE quiche_apps::common] received 1290 bytes
[2025-04-30T10:36:23.209380921Z TRACE quiche_apps::common] stream 4 has 1290 bytes (fin? false)
[2025-04-30T10:36:23.209399436Z TRACE quiche] 23c26c77f44724a732c3bdeb0a00627e6c4847cd pmtud probe status false hs_con=true hs_sent=false cwnd_avail=13500 out_len=1350 left=1317
[2025-04-30T10:36:23.209402732Z TRACE quiche] 23c26c77f44724a732c3bdeb0a00627e6c4847cd tx pkt Short dcid=1522adf0d5c9bdb1905b key_phase=false len=5 pn=18 
[2025-04-30T10:36:23.209405197Z TRACE quiche] 23c26c77f44724a732c3bdeb0a00627e6c4847cd tx frm ACK delay=5 blocks=[0..14] ecn_counts=None
[2025-04-30T10:36:23.209410867Z TRACE quiche::recovery::congestion::recovery] 23c26c77f44724a732c3bdeb0a00627e6c4847cd timer=none latest_rtt=53.477818ms srtt=39.601245ms min_rtt=33.246478ms rttvar=13.560981ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=0 app_limited=true congestion_recovery_start_time=None Rate { delivered: 1670, delivered_time: Instant { tv_sec: 805, tv_nsec: 338199206 }, first_sent_time: Instant { tv_sec: 805, tv_nsec: 338199206 }, end_of_app_limited: 14, last_sent_packet: 18, largest_acked: 4, rate_sample: RateSample { delivery_rate: 39773, is_app_limited: true, interval: 33.615217ms, delivered: 1337, prior_delivered: 333, prior_time: Some(Instant { tv_sec: 805, tv_nsec: 271802405 }), send_elapsed: 0ns, ack_elapsed: 33.615217ms, rtt: 33.615217ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 426122, last_update: Instant { tv_sec: 805, tv_nsec: 338199206 }, next_time: Instant { tv_sec: 805, tv_nsec: 338199206 }, 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-30T10:36:23.209437106Z TRACE quiche_apps::client] written 33 bytes from [::]:35280 to [fd00:cafe:cafe:100::100]:443
[2025-04-30T10:36:23.209441014Z TRACE quiche_apps::client] [::]:35280 -> [fd00:cafe:cafe:100::100]:443: done writing
[2025-04-30T10:36:23.210450628Z TRACE quiche_apps::client] got 1332 bytes from [fd00:cafe:cafe:100::100]:443 to [::]:35280
[2025-04-30T10:36:23.210457911Z TRACE quiche] 23c26c77f44724a732c3bdeb0a00627e6c4847cd rx pkt Short dcid=23c26c77f44724a732c3bdeb0a00627e6c4847cd key_phase=false len=1311 pn=15 
[2025-04-30T10:36:23.210463622Z TRACE quiche] 23c26c77f44724a732c3bdeb0a00627e6c4847cd rx frm STREAM id=4 off=9258 len=982 fin=true
[2025-04-30T10:36:23.210467279Z TRACE quiche] 23c26c77f44724a732c3bdeb0a00627e6c4847cd rx frm CRYPTO off=0 len=302
[2025-04-30T10:36:23.210476816Z TRACE quiche_apps::client] [::]:35280: processed 1332 bytes
[2025-04-30T10:36:23.210480323Z TRACE quiche_apps::client] [::]:35280: recv() would block
[2025-04-30T10:36:23.210482627Z TRACE quiche_apps::client] done reading
[2025-04-30T10:36:23.210487066Z TRACE quiche_apps::common] received 982 bytes
[2025-04-30T10:36:23.210489310Z TRACE quiche_apps::common] stream 4 has 982 bytes (fin? true)
[2025-04-30T10:36:23.210491664Z DEBUG quiche_apps::common] 2/2 responses received
[2025-04-30T10:36:23.210494039Z INFO  quiche_apps::common] 2/2 response(s) received in 112.671462ms, closing...
[2025-04-30T10:36:23.210500040Z TRACE quiche] 23c26c77f44724a732c3bdeb0a00627e6c4847cd pmtud probe status false hs_con=true hs_sent=false cwnd_avail=13500 out_len=1350 left=1322
[2025-04-30T10:36:23.210503316Z TRACE quiche] 23c26c77f44724a732c3bdeb0a00627e6c4847cd tx pkt Short dcid=1522adf0d5c9bdb1905b key_phase=false len=10 pn=19 
[2025-04-30T10:36:23.210505730Z TRACE quiche] 23c26c77f44724a732c3bdeb0a00627e6c4847cd tx frm APPLICATION_CLOSE err=0 reason=[6b, 74, 68, 78, 62, 79, 65]
[2025-04-30T10:36:23.210512353Z TRACE quiche::recovery::congestion::recovery] 23c26c77f44724a732c3bdeb0a00627e6c4847cd timer=113.830552ms latest_rtt=53.477818ms srtt=39.601245ms min_rtt=33.246478ms rttvar=13.560981ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=38 app_limited=true congestion_recovery_start_time=None Rate { delivered: 1670, delivered_time: Instant { tv_sec: 805, tv_nsec: 338199206 }, first_sent_time: Instant { tv_sec: 805, tv_nsec: 338199206 }, end_of_app_limited: 18, last_sent_packet: 19, largest_acked: 4, rate_sample: RateSample { delivery_rate: 39773, is_app_limited: true, interval: 33.615217ms, delivered: 1337, prior_delivered: 333, prior_time: Some(Instant { tv_sec: 805, tv_nsec: 271802405 }), send_elapsed: 0ns, ack_elapsed: 33.615217ms, rtt: 33.615217ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 426122, last_update: Instant { tv_sec: 805, tv_nsec: 341541664 }, next_time: Instant { tv_sec: 805, tv_nsec: 338199206 }, max_datagram_size: 1350, last_packet_size: None, iv: 89.176µ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-30T10:36:23.210544663Z TRACE quiche_apps::client] written 38 bytes from [::]:35280 to [fd00:cafe:cafe:100::100]:443
[2025-04-30T10:36:23.210548410Z TRACE quiche_apps::client] [::]:35280 -> [fd00:cafe:cafe:100::100]:443: done writing
[2025-04-30T10:36:23.210583746Z TRACE quiche_apps::client] got 106 bytes from [fd00:cafe:cafe:100::100]:443 to [::]:35280
[2025-04-30T10:36:23.210587623Z TRACE quiche_apps::client] [::]:35280: processed 106 bytes
[2025-04-30T10:36:23.210590759Z TRACE quiche_apps::client] [::]:35280: recv() would block
[2025-04-30T10:36:23.210592993Z TRACE quiche_apps::client] done reading
[2025-04-30T10:36:23.210596370Z TRACE quiche_apps::client] [::]:35280 -> [fd00:cafe:cafe:100::100]:443: done writing
[2025-04-30T10:36:23.213621796Z TRACE quiche_apps::client] got 41 bytes from [fd00:cafe:cafe:100::100]:443 to [::]:35280
[2025-04-30T10:36:23.213629050Z TRACE quiche_apps::client] [::]:35280: processed 41 bytes
[2025-04-30T10:36:23.213633057Z TRACE quiche_apps::client] [::]:35280: recv() would block
[2025-04-30T10:36:23.213635883Z TRACE quiche_apps::client] done reading
[2025-04-30T10:36:23.213639810Z TRACE quiche_apps::client] [::]:35280 -> [fd00:cafe:cafe:100::100]:443: done writing
[2025-04-30T10:36:23.239909653Z TRACE quiche_apps::client] got 1422 bytes from [fd00:cafe:cafe:100::100]:443 to [::]:35280
[2025-04-30T10:36:23.239922487Z TRACE quiche_apps::client] [::]:35280: processed 1422 bytes
[2025-04-30T10:36:23.239927346Z TRACE quiche_apps::client] [::]:35280: recv() would block
[2025-04-30T10:36:23.239930482Z TRACE quiche_apps::client] done reading
[2025-04-30T10:36:23.239935542Z TRACE quiche_apps::client] [::]:35280 -> [fd00:cafe:cafe:100::100]:443: done writing
[2025-04-30T10:36:23.241013914Z TRACE quiche_apps::client] got 47 bytes from [fd00:cafe:cafe:100::100]:443 to [::]:35280
[2025-04-30T10:36:23.241019395Z TRACE quiche_apps::client] [::]:35280: processed 47 bytes
[2025-04-30T10:36:23.241022721Z TRACE quiche_apps::client] [::]:35280: recv() would block
[2025-04-30T10:36:23.241025015Z TRACE quiche_apps::client] done reading
[2025-04-30T10:36:23.241028121Z TRACE quiche_apps::client] [::]:35280 -> [fd00:cafe:cafe:100::100]:443: done writing
[2025-04-30T10:36:23.493333916Z TRACE quiche_apps::client] timed out
[2025-04-30T10:36:23.493353412Z TRACE quiche] 23c26c77f44724a732c3bdeb0a00627e6c4847cd draining timeout expired
[2025-04-30T10:36:23.493389360Z TRACE quiche_apps::client] done reading
[2025-04-30T10:36:23.493394399Z INFO  quiche_apps::client] connection closed, recv=19 sent=20 lost=0 retrans=0 sent_bytes=2233 recv_bytes=19872 lost_bytes=0 [local_addr=[::]:35280 peer_addr=[fd00:cafe:cafe:100::100]:443 validation_state=Validated active=true recv=19 sent=20 lost=0 retrans=0 rtt=39.601245ms min_rtt=Some(33.246478ms) rttvar=13.560981ms cwnd=13500 sent_bytes=2233 recv_bytes=19872 lost_bytes=0 stream_retrans_bytes=0 pmtu=1350 delivery_rate=39773]