[2025-04-30T12:28:44.810624767Z INFO quiche_server] listening on [::]:443 [2025-04-30T12:28:44.810649353Z TRACE mio::poll] registering event source with poller: token=Token(0), interests=READABLE [2025-04-30T12:28:44.810656416Z TRACE quiche_server] GSO detected: false [2025-04-30T12:28:45.626176070Z TRACE quiche_server] got 1207 bytes from [::ffff:193.167.100.2]:51331 to [::]:443 [2025-04-30T12:28:45.626219120Z TRACE quiche_server] got packet Initial version=57414954 dcid= scid= token= [2025-04-30T12:28:45.626230802Z WARN quiche_server] Doing version negotiation [2025-04-30T12:28:45.626336028Z TRACE quiche_server] got 1207 bytes from [::ffff:193.167.100.2]:51331 to [::]:443 [2025-04-30T12:28:45.626345005Z TRACE quiche_server] got packet Initial version=57414954 dcid= scid= token= [2025-04-30T12:28:45.626350585Z WARN quiche_server] Doing version negotiation [2025-04-30T12:28:45.626381573Z TRACE quiche_server] got 1207 bytes from [::ffff:193.167.100.2]:51331 to [::]:443 [2025-04-30T12:28:45.626388256Z TRACE quiche_server] got packet Initial version=57414954 dcid= scid= token= [2025-04-30T12:28:45.626392904Z WARN quiche_server] Doing version negotiation [2025-04-30T12:28:45.626419434Z TRACE quiche_server] recv() would block [2025-04-30T12:28:45.845049358Z TRACE quiche_server] got 1200 bytes from [fd00:cafe:cafe::100]:34756 to [::]:443 [2025-04-30T12:28:45.845072601Z TRACE quiche_server] got packet Initial version=1 dcid=92e99f49ae691801 scid=431965a8e70d05bc token= [2025-04-30T12:28:45.845081788Z DEBUG quiche_server] New connection: dcid=92e99f49ae691801 scid=88f12fb4444785c0e6eb39b2bfe7f1737f1dc003 [2025-04-30T12:28:45.845277754Z TRACE quiche] 88f12fb4444785c0e6eb39b2bfe7f1737f1dc003 rx pkt Initial version=1 dcid=92e99f49ae691801 scid=431965a8e70d05bc token= len=270 pn=0 [2025-04-30T12:28:45.845292010Z TRACE quiche] 88f12fb4444785c0e6eb39b2bfe7f1737f1dc003 rx frm CRYPTO off=0 len=249 [2025-04-30T12:28:45.845321215Z TRACE quiche::tls] checking peer ALPN Ok("hq-interop") against Ok("h3") [2025-04-30T12:28:45.845325914Z TRACE quiche::tls] checking peer ALPN Ok("hq-interop") against Ok("hq-interop") [2025-04-30T12:28:45.845426030Z TRACE quiche::tls] 88f12fb4444785c0e6eb39b2bfe7f1737f1dc003 write message lvl=Initial len=90 [2025-04-30T12:28:45.845454864Z TRACE quiche::tls] 88f12fb4444785c0e6eb39b2bfe7f1737f1dc003 set write secret lvl=Handshake [2025-04-30T12:28:45.845530595Z TRACE quiche::tls] 88f12fb4444785c0e6eb39b2bfe7f1737f1dc003 write message lvl=Handshake len=698 [2025-04-30T12:28:45.845534282Z TRACE quiche::tls] 88f12fb4444785c0e6eb39b2bfe7f1737f1dc003 set write secret lvl=OneRTT [2025-04-30T12:28:45.845542067Z TRACE quiche::tls] 88f12fb4444785c0e6eb39b2bfe7f1737f1dc003 set read secret lvl=Handshake [2025-04-30T12:28:45.845577633Z TRACE quiche] 88f12fb4444785c0e6eb39b2bfe7f1737f1dc003 dropped invalid packet [2025-04-30T12:28:45.845581330Z TRACE quiche_server] 88f12fb4444785c0e6eb39b2bfe7f1737f1dc003 processed 1200 bytes [2025-04-30T12:28:45.845591599Z TRACE quiche_server] recv() would block [2025-04-30T12:28:45.845604964Z TRACE quiche] 88f12fb4444785c0e6eb39b2bfe7f1737f1dc003 tx pkt Initial version=1 dcid=431965a8e70d05bc scid=88f12fb4444785c0e6eb39b2bfe7f1737f1dc003 len=99 pn=0 [2025-04-30T12:28:45.845608911Z TRACE quiche] 88f12fb4444785c0e6eb39b2bfe7f1737f1dc003 tx frm ACK delay=43 blocks=[0..0] ecn_counts=None [2025-04-30T12:28:45.845614592Z TRACE quiche] 88f12fb4444785c0e6eb39b2bfe7f1737f1dc003 tx frm CRYPTO off=0 len=90 [2025-04-30T12:28:45.845625041Z TRACE quiche::recovery::congestion::recovery] 88f12fb4444785c0e6eb39b2bfe7f1737f1dc003 timer=998.968181ms latest_rtt=0ns srtt=333ms min_rtt=333ms rttvar=166.5ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=154 app_limited=true congestion_recovery_start_time=None Rate { delivered: 0, delivered_time: Instant { tv_sec: 528, tv_nsec: 345613558 }, first_sent_time: Instant { tv_sec: 528, tv_nsec: 345613558 }, 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: false, capacity: 13500, used: 0, rate: 0, last_update: Instant { tv_sec: 528, tv_nsec: 345613558 }, next_time: Instant { tv_sec: 528, tv_nsec: 345613558 }, 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-30T12:28:45.845657863Z TRACE quiche] 88f12fb4444785c0e6eb39b2bfe7f1737f1dc003 tx pkt Handshake version=1 dcid=431965a8e70d05bc scid=88f12fb4444785c0e6eb39b2bfe7f1737f1dc003 len=702 pn=1 [2025-04-30T12:28:45.845661520Z TRACE quiche] 88f12fb4444785c0e6eb39b2bfe7f1737f1dc003 tx frm CRYPTO off=0 len=698 [2025-04-30T12:28:45.845668422Z TRACE quiche::recovery::congestion::recovery] 88f12fb4444785c0e6eb39b2bfe7f1737f1dc003 timer=998.925652ms latest_rtt=0ns srtt=333ms min_rtt=333ms rttvar=166.5ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=910 app_limited=true congestion_recovery_start_time=None Rate { delivered: 0, delivered_time: Instant { tv_sec: 528, tv_nsec: 345613558 }, first_sent_time: Instant { tv_sec: 528, tv_nsec: 345613558 }, end_of_app_limited: 1, last_sent_packet: 1, 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: false, capacity: 13500, used: 0, rate: 0, last_update: Instant { tv_sec: 528, tv_nsec: 345613558 }, next_time: Instant { tv_sec: 528, tv_nsec: 345613558 }, 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-30T12:28:45.845711773Z TRACE quiche_server] 88f12fb4444785c0e6eb39b2bfe7f1737f1dc003 written 1200 bytes with Some(SendInfo { from: [::]:443, to: [fd00:cafe:cafe::100]:34756, at: Instant { tv_sec: 528, tv_nsec: 345613558 } }) [2025-04-30T12:28:45.845722614Z TRACE quiche_server] Collecting garbage [2025-04-30T12:28:45.845730398Z TRACE quiche_server] recv() would block [2025-04-30T12:28:45.845737211Z TRACE quiche_server] 88f12fb4444785c0e6eb39b2bfe7f1737f1dc003 done writing [2025-04-30T12:28:45.845742370Z TRACE quiche_server] Collecting garbage [2025-04-30T12:28:45.878731261Z TRACE quiche_server] got 1200 bytes from [fd00:cafe:cafe::100]:34756 to [::]:443 [2025-04-30T12:28:45.878745778Z TRACE quiche_server] got packet Initial version=1 dcid=88f12fb4444785c0e6eb39b2bfe7f1737f1dc003 scid=431965a8e70d05bc token= [2025-04-30T12:28:45.878755015Z TRACE quiche] 88f12fb4444785c0e6eb39b2bfe7f1737f1dc003 rx pkt Initial version=1 dcid=88f12fb4444785c0e6eb39b2bfe7f1737f1dc003 scid=431965a8e70d05bc token= len=22 pn=1 [2025-04-30T12:28:45.878763541Z TRACE quiche] 88f12fb4444785c0e6eb39b2bfe7f1737f1dc003 rx frm ACK delay=0 blocks=[0..0] ecn_counts=None [2025-04-30T12:28:45.878769402Z TRACE quiche::recovery::congestion::recovery] 88f12fb4444785c0e6eb39b2bfe7f1737f1dc003 packet newly acked 0 [2025-04-30T12:28:45.878788838Z TRACE quiche] 88f12fb4444785c0e6eb39b2bfe7f1737f1dc003 rx pkt Handshake version=1 dcid=88f12fb4444785c0e6eb39b2bfe7f1737f1dc003 scid=431965a8e70d05bc len=61 pn=0 [2025-04-30T12:28:45.878794499Z TRACE quiche] 88f12fb4444785c0e6eb39b2bfe7f1737f1dc003 rx frm ACK delay=0 blocks=[1..1] ecn_counts=None [2025-04-30T12:28:45.878797895Z TRACE quiche::recovery::congestion::recovery] 88f12fb4444785c0e6eb39b2bfe7f1737f1dc003 packet newly acked 1 [2025-04-30T12:28:45.878801833Z TRACE quiche] 88f12fb4444785c0e6eb39b2bfe7f1737f1dc003 rx frm CRYPTO off=0 len=36 [2025-04-30T12:28:45.878823583Z TRACE quiche::tls] 88f12fb4444785c0e6eb39b2bfe7f1737f1dc003 set read secret lvl=OneRTT [2025-04-30T12:28:45.878856154Z TRACE quiche] 88f12fb4444785c0e6eb39b2bfe7f1737f1dc003 dropped epoch 1 state [2025-04-30T12:28:45.878861113Z TRACE quiche] 88f12fb4444785c0e6eb39b2bfe7f1737f1dc003 connection established: proto=Ok("hq-interop") cipher=Some(AES128_GCM) curve=Some("X25519") sigalg=None resumed=false TransportParams { original_destination_connection_id: None, max_idle_timeout: 0, stateless_reset_token: None, max_udp_payload_size: 1472, initial_max_data: 65536, initial_max_stream_data_bidi_local: 65536, initial_max_stream_data_bidi_remote: 65536, initial_max_stream_data_uni: 65536, initial_max_streams_bidi: 0, initial_max_streams_uni: 0, ack_delay_exponent: 3, max_ack_delay: 25, disable_active_migration: true, active_conn_id_limit: 2, initial_source_connection_id: Some(431965a8e70d05bc), retry_source_connection_id: None, max_datagram_frame_size: None, unknown_params: None } [2025-04-30T12:28:45.878881651Z TRACE quiche] 88f12fb4444785c0e6eb39b2bfe7f1737f1dc003 dropped epoch 0 state [2025-04-30T12:28:45.878885308Z TRACE quiche] 88f12fb4444785c0e6eb39b2bfe7f1737f1dc003 rx pkt Short dcid=88f12fb4444785c0e6eb39b2bfe7f1737f1dc003 key_phase=false len=1021 pn=0 [2025-04-30T12:28:45.878892462Z TRACE quiche] 88f12fb4444785c0e6eb39b2bfe7f1737f1dc003 rx frm NEW_CONNECTION_ID seq_num=1 retire_prior_to=0 conn_id=[99, 40, c0, 85, 84, f6, fe, 3c] reset_token=[4c, 99, df, e6, b0, 2e, 33, a8, 8e, 73, 91, 40, 33, 07, 6c, 90] [2025-04-30T12:28:45.878901118Z TRACE quiche] 88f12fb4444785c0e6eb39b2bfe7f1737f1dc003 rx frm NEW_CONNECTION_ID seq_num=2 retire_prior_to=0 conn_id=[b8, 04, 24, 79, c1, f5, 92, ff] reset_token=[12, f2, 0a, c0, ff, 2b, ec, a1, 26, 2b, a4, a9, 5a, d4, 34, 01] [2025-04-30T12:28:45.878907089Z TRACE quiche] 88f12fb4444785c0e6eb39b2bfe7f1737f1dc003 rx frm NEW_CONNECTION_ID seq_num=3 retire_prior_to=0 conn_id=[bb, 7c, a8, 39, 6d, 7c, 78, 3f] reset_token=[44, bd, e5, f7, d4, 44, 00, 03, b9, 83, 78, b8, a2, 5e, 97, 50] [2025-04-30T12:28:45.878914863Z TRACE quiche] 88f12fb4444785c0e6eb39b2bfe7f1737f1dc003 rx frm PADDING len=920 [2025-04-30T12:28:45.878922538Z TRACE quiche_server] 88f12fb4444785c0e6eb39b2bfe7f1737f1dc003 processed 1200 bytes [2025-04-30T12:28:45.878930933Z TRACE quiche_server] got 58 bytes from [fd00:cafe:cafe::100]:34756 to [::]:443 [2025-04-30T12:28:45.878935071Z TRACE quiche_server] got packet Short dcid=88f12fb4444785c0e6eb39b2bfe7f1737f1dc003 key_phase=false [2025-04-30T12:28:45.878940231Z TRACE quiche] 88f12fb4444785c0e6eb39b2bfe7f1737f1dc003 rx pkt Short dcid=88f12fb4444785c0e6eb39b2bfe7f1737f1dc003 key_phase=false len=37 pn=1 [2025-04-30T12:28:45.878945000Z TRACE quiche] 88f12fb4444785c0e6eb39b2bfe7f1737f1dc003 rx frm STREAM id=0 off=0 len=17 fin=true [2025-04-30T12:28:45.878952153Z TRACE quiche_server] 88f12fb4444785c0e6eb39b2bfe7f1737f1dc003 processed 58 bytes [2025-04-30T12:28:45.878955479Z DEBUG quiche_apps::common] 88f12fb4444785c0e6eb39b2bfe7f1737f1dc003 response stream 0 is writable with capacity Ok(13500) [2025-04-30T12:28:45.878962332Z TRACE quiche_apps::common] 88f12fb4444785c0e6eb39b2bfe7f1737f1dc003 received 17 bytes [2025-04-30T12:28:45.878965407Z TRACE quiche_apps::common] 88f12fb4444785c0e6eb39b2bfe7f1737f1dc003 stream 0 has 17 bytes (fin? true) [2025-04-30T12:28:45.878970126Z INFO quiche_apps::common] 88f12fb4444785c0e6eb39b2bfe7f1737f1dc003 got GET request for "/www/kirttmyzxd" on stream 0 [2025-04-30T12:28:45.879023957Z INFO quiche_apps::common] 88f12fb4444785c0e6eb39b2bfe7f1737f1dc003 sending response of size 5120 on stream 0 [2025-04-30T12:28:45.879036150Z TRACE quiche_server] got 58 bytes from [fd00:cafe:cafe::100]:34756 to [::]:443 [2025-04-30T12:28:45.879040027Z TRACE quiche_server] got packet Short dcid=88f12fb4444785c0e6eb39b2bfe7f1737f1dc003 key_phase=false [2025-04-30T12:28:45.879045447Z TRACE quiche] 88f12fb4444785c0e6eb39b2bfe7f1737f1dc003 rx pkt Short dcid=88f12fb4444785c0e6eb39b2bfe7f1737f1dc003 key_phase=false len=37 pn=2 [2025-04-30T12:28:45.879050957Z TRACE quiche] 88f12fb4444785c0e6eb39b2bfe7f1737f1dc003 rx frm STREAM id=4 off=0 len=17 fin=true [2025-04-30T12:28:45.879065995Z TRACE quiche_server] 88f12fb4444785c0e6eb39b2bfe7f1737f1dc003 processed 58 bytes [2025-04-30T12:28:45.879069361Z DEBUG quiche_apps::common] 88f12fb4444785c0e6eb39b2bfe7f1737f1dc003 response stream 4 is writable with capacity Ok(13500) [2025-04-30T12:28:45.879073980Z TRACE quiche_apps::common] 88f12fb4444785c0e6eb39b2bfe7f1737f1dc003 received 17 bytes [2025-04-30T12:28:45.879076835Z TRACE quiche_apps::common] 88f12fb4444785c0e6eb39b2bfe7f1737f1dc003 stream 4 has 17 bytes (fin? true) [2025-04-30T12:28:45.879080412Z INFO quiche_apps::common] 88f12fb4444785c0e6eb39b2bfe7f1737f1dc003 got GET request for "/www/ebcouqujhb" on stream 4 [2025-04-30T12:28:45.879098195Z INFO quiche_apps::common] 88f12fb4444785c0e6eb39b2bfe7f1737f1dc003 sending response of size 10240 on stream 4 [2025-04-30T12:28:45.879105669Z TRACE quiche_server] recv() would block [2025-04-30T12:28:45.879114365Z TRACE quiche] 88f12fb4444785c0e6eb39b2bfe7f1737f1dc003 pmtud probe status false hs_con=true hs_sent=false cwnd_avail=13500 out_len=1350 left=1319 [2025-04-30T12:28:45.879122631Z TRACE quiche] 88f12fb4444785c0e6eb39b2bfe7f1737f1dc003 tx pkt Short dcid=431965a8e70d05bc key_phase=false len=1324 pn=2 [2025-04-30T12:28:45.879125907Z TRACE quiche] 88f12fb4444785c0e6eb39b2bfe7f1737f1dc003 tx frm ACK delay=8 blocks=[0..2] ecn_counts=None [2025-04-30T12:28:45.879129774Z TRACE quiche] 88f12fb4444785c0e6eb39b2bfe7f1737f1dc003 tx frm NEW_CONNECTION_ID seq_num=1 retire_prior_to=0 conn_id=[39, 17, da, 34, f2, 95, 8f, 4c, 4c, fc, 59, 37, be, d4, dd, cf, 52, 1a, df, 0d] reset_token=[93, c6, b7, 20, e0, ce, 56, fc, 37, 19, 47, be, 16, 9a, 37, 6d] [2025-04-30T12:28:45.879136817Z TRACE quiche] 88f12fb4444785c0e6eb39b2bfe7f1737f1dc003 tx frm HANDSHAKE_DONE [2025-04-30T12:28:45.879139643Z TRACE quiche] 88f12fb4444785c0e6eb39b2bfe7f1737f1dc003 tx frm STREAM id=0 off=0 len=1273 fin=false [2025-04-30T12:28:45.879150533Z TRACE quiche::recovery::congestion::recovery] 88f12fb4444785c0e6eb39b2bfe7f1737f1dc003 timer=107.893555ms latest_rtt=33.193652ms srtt=33.163144ms min_rtt=33.158787ms rttvar=12.44326ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=1350 app_limited=true congestion_recovery_start_time=None Rate { delivered: 910, delivered_time: Instant { tv_sec: 528, tv_nsec: 379127698 }, first_sent_time: Instant { tv_sec: 528, tv_nsec: 379127698 }, end_of_app_limited: 1, last_sent_packet: 2, largest_acked: 1, rate_sample: RateSample { delivery_rate: 27443, is_app_limited: true, interval: 33.158787ms, delivered: 910, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 528, tv_nsec: 345613558 }), send_elapsed: 0ns, ack_elapsed: 33.158787ms, rtt: 33.158787ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 508848, last_update: Instant { tv_sec: 528, tv_nsec: 379127698 }, next_time: Instant { tv_sec: 528, tv_nsec: 379127698 }, 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-30T12:28:45.879169799Z TRACE quiche] 88f12fb4444785c0e6eb39b2bfe7f1737f1dc003 pmtud probe status false hs_con=true hs_sent=true cwnd_avail=12150 out_len=1350 left=1324 [2025-04-30T12:28:45.879174017Z TRACE quiche] 88f12fb4444785c0e6eb39b2bfe7f1737f1dc003 tx pkt Short dcid=431965a8e70d05bc key_phase=false len=1324 pn=3 [2025-04-30T12:28:45.879177102Z TRACE quiche] 88f12fb4444785c0e6eb39b2bfe7f1737f1dc003 tx frm STREAM id=4 off=0 len=1319 fin=false [2025-04-30T12:28:45.879183113Z TRACE quiche::recovery::congestion::recovery] 88f12fb4444785c0e6eb39b2bfe7f1737f1dc003 timer=107.920335ms latest_rtt=33.193652ms srtt=33.163144ms min_rtt=33.158787ms rttvar=12.44326ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=2700 app_limited=true congestion_recovery_start_time=None Rate { delivered: 910, delivered_time: Instant { tv_sec: 528, tv_nsec: 379127698 }, first_sent_time: Instant { tv_sec: 528, tv_nsec: 379127698 }, end_of_app_limited: 1, last_sent_packet: 3, largest_acked: 1, rate_sample: RateSample { delivery_rate: 27443, is_app_limited: true, interval: 33.158787ms, delivered: 910, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 528, tv_nsec: 345613558 }), send_elapsed: 0ns, ack_elapsed: 33.158787ms, rtt: 33.158787ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 508848, last_update: Instant { tv_sec: 528, tv_nsec: 379127698 }, next_time: Instant { tv_sec: 528, tv_nsec: 379127698 }, 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-30T12:28:45.879200436Z TRACE quiche] 88f12fb4444785c0e6eb39b2bfe7f1737f1dc003 pmtud probe status false hs_con=true hs_sent=true cwnd_avail=10800 out_len=1350 left=1324 [2025-04-30T12:28:45.879204403Z TRACE quiche] 88f12fb4444785c0e6eb39b2bfe7f1737f1dc003 tx pkt Short dcid=431965a8e70d05bc key_phase=false len=1324 pn=4 [2025-04-30T12:28:45.879207359Z TRACE quiche] 88f12fb4444785c0e6eb39b2bfe7f1737f1dc003 tx frm STREAM id=0 off=1273 len=1318 fin=false [2025-04-30T12:28:45.879212759Z TRACE quiche::recovery::congestion::recovery] 88f12fb4444785c0e6eb39b2bfe7f1737f1dc003 timer=107.922017ms latest_rtt=33.193652ms srtt=33.163144ms min_rtt=33.158787ms rttvar=12.44326ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=4050 app_limited=true congestion_recovery_start_time=None Rate { delivered: 910, delivered_time: Instant { tv_sec: 528, tv_nsec: 379127698 }, first_sent_time: Instant { tv_sec: 528, tv_nsec: 379127698 }, end_of_app_limited: 1, last_sent_packet: 4, largest_acked: 1, rate_sample: RateSample { delivery_rate: 27443, is_app_limited: true, interval: 33.158787ms, delivered: 910, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 528, tv_nsec: 345613558 }), send_elapsed: 0ns, ack_elapsed: 33.158787ms, rtt: 33.158787ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 508848, last_update: Instant { tv_sec: 528, tv_nsec: 379127698 }, next_time: Instant { tv_sec: 528, tv_nsec: 379127698 }, 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-30T12:28:45.879224270Z TRACE quiche] 88f12fb4444785c0e6eb39b2bfe7f1737f1dc003 pmtud probe status false hs_con=true hs_sent=true cwnd_avail=9450 out_len=1350 left=1324 [2025-04-30T12:28:45.879227927Z TRACE quiche] 88f12fb4444785c0e6eb39b2bfe7f1737f1dc003 tx pkt Short dcid=431965a8e70d05bc key_phase=false len=1324 pn=5 [2025-04-30T12:28:45.879230873Z TRACE quiche] 88f12fb4444785c0e6eb39b2bfe7f1737f1dc003 tx frm STREAM id=4 off=1319 len=1318 fin=false [2025-04-30T12:28:45.879236123Z TRACE quiche::recovery::congestion::recovery] 88f12fb4444785c0e6eb39b2bfe7f1737f1dc003 timer=107.922879ms latest_rtt=33.193652ms srtt=33.163144ms min_rtt=33.158787ms rttvar=12.44326ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=5400 app_limited=true congestion_recovery_start_time=None Rate { delivered: 910, delivered_time: Instant { tv_sec: 528, tv_nsec: 379127698 }, first_sent_time: Instant { tv_sec: 528, tv_nsec: 379127698 }, end_of_app_limited: 1, last_sent_packet: 5, largest_acked: 1, rate_sample: RateSample { delivery_rate: 27443, is_app_limited: true, interval: 33.158787ms, delivered: 910, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 528, tv_nsec: 345613558 }), send_elapsed: 0ns, ack_elapsed: 33.158787ms, rtt: 33.158787ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 508848, last_update: Instant { tv_sec: 528, tv_nsec: 379127698 }, next_time: Instant { tv_sec: 528, tv_nsec: 379127698 }, 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-30T12:28:45.879250780Z TRACE quiche] 88f12fb4444785c0e6eb39b2bfe7f1737f1dc003 pmtud probe status false hs_con=true hs_sent=true cwnd_avail=8100 out_len=1350 left=1324 [2025-04-30T12:28:45.879254447Z TRACE quiche] 88f12fb4444785c0e6eb39b2bfe7f1737f1dc003 tx pkt Short dcid=431965a8e70d05bc key_phase=false len=1324 pn=6 [2025-04-30T12:28:45.879257312Z TRACE quiche] 88f12fb4444785c0e6eb39b2bfe7f1737f1dc003 tx frm STREAM id=0 off=2591 len=1318 fin=false [2025-04-30T12:28:45.879262802Z TRACE quiche::recovery::congestion::recovery] 88f12fb4444785c0e6eb39b2bfe7f1737f1dc003 timer=107.922679ms latest_rtt=33.193652ms srtt=33.163144ms min_rtt=33.158787ms rttvar=12.44326ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=6750 app_limited=true congestion_recovery_start_time=None Rate { delivered: 910, delivered_time: Instant { tv_sec: 528, tv_nsec: 379127698 }, first_sent_time: Instant { tv_sec: 528, tv_nsec: 379127698 }, end_of_app_limited: 1, last_sent_packet: 6, largest_acked: 1, rate_sample: RateSample { delivery_rate: 27443, is_app_limited: true, interval: 33.158787ms, delivered: 910, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 528, tv_nsec: 345613558 }), send_elapsed: 0ns, ack_elapsed: 33.158787ms, rtt: 33.158787ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 508848, last_update: Instant { tv_sec: 528, tv_nsec: 379127698 }, next_time: Instant { tv_sec: 528, tv_nsec: 379127698 }, 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-30T12:28:45.879274063Z TRACE quiche] 88f12fb4444785c0e6eb39b2bfe7f1737f1dc003 pmtud probe status false hs_con=true hs_sent=true cwnd_avail=6750 out_len=1350 left=1324 [2025-04-30T12:28:45.879277660Z TRACE quiche] 88f12fb4444785c0e6eb39b2bfe7f1737f1dc003 tx pkt Short dcid=431965a8e70d05bc key_phase=false len=1324 pn=7 [2025-04-30T12:28:45.879280515Z TRACE quiche] 88f12fb4444785c0e6eb39b2bfe7f1737f1dc003 tx frm STREAM id=4 off=2637 len=1318 fin=false [2025-04-30T12:28:45.879285595Z TRACE quiche::recovery::congestion::recovery] 88f12fb4444785c0e6eb39b2bfe7f1737f1dc003 timer=107.923251ms latest_rtt=33.193652ms srtt=33.163144ms min_rtt=33.158787ms rttvar=12.44326ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=8100 app_limited=true congestion_recovery_start_time=None Rate { delivered: 910, delivered_time: Instant { tv_sec: 528, tv_nsec: 379127698 }, first_sent_time: Instant { tv_sec: 528, tv_nsec: 379127698 }, end_of_app_limited: 1, last_sent_packet: 7, largest_acked: 1, rate_sample: RateSample { delivery_rate: 27443, is_app_limited: true, interval: 33.158787ms, delivered: 910, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 528, tv_nsec: 345613558 }), send_elapsed: 0ns, ack_elapsed: 33.158787ms, rtt: 33.158787ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 508848, last_update: Instant { tv_sec: 528, tv_nsec: 379127698 }, next_time: Instant { tv_sec: 528, tv_nsec: 379127698 }, 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-30T12:28:45.879296675Z TRACE quiche] 88f12fb4444785c0e6eb39b2bfe7f1737f1dc003 pmtud probe status false hs_con=true hs_sent=true cwnd_avail=5400 out_len=1350 left=1324 [2025-04-30T12:28:45.879303558Z TRACE quiche] 88f12fb4444785c0e6eb39b2bfe7f1737f1dc003 tx pkt Short dcid=431965a8e70d05bc key_phase=false len=1217 pn=8 [2025-04-30T12:28:45.879306554Z TRACE quiche] 88f12fb4444785c0e6eb39b2bfe7f1737f1dc003 tx frm STREAM id=0 off=3909 len=1211 fin=true [2025-04-30T12:28:45.879330348Z TRACE quiche::recovery::congestion::recovery] 88f12fb4444785c0e6eb39b2bfe7f1737f1dc003 timer=107.901079ms latest_rtt=33.193652ms srtt=33.163144ms min_rtt=33.158787ms rttvar=12.44326ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=9343 app_limited=true congestion_recovery_start_time=None Rate { delivered: 910, delivered_time: Instant { tv_sec: 528, tv_nsec: 379127698 }, first_sent_time: Instant { tv_sec: 528, tv_nsec: 379127698 }, end_of_app_limited: 1, last_sent_packet: 8, largest_acked: 1, rate_sample: RateSample { delivery_rate: 27443, is_app_limited: true, interval: 33.158787ms, delivered: 910, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 528, tv_nsec: 345613558 }), send_elapsed: 0ns, ack_elapsed: 33.158787ms, rtt: 33.158787ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 508848, last_update: Instant { tv_sec: 528, tv_nsec: 379127698 }, next_time: Instant { tv_sec: 528, tv_nsec: 379127698 }, 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-30T12:28:45.879423161Z TRACE quiche_server] 88f12fb4444785c0e6eb39b2bfe7f1737f1dc003 written 9343 bytes with Some(SendInfo { from: [::]:443, to: [fd00:cafe:cafe::100]:34756, at: Instant { tv_sec: 528, tv_nsec: 379127698 } }) [2025-04-30T12:28:45.879434553Z TRACE quiche_server] Collecting garbage [2025-04-30T12:28:45.879443089Z TRACE quiche_server] recv() would block [2025-04-30T12:28:45.879451254Z TRACE quiche] 88f12fb4444785c0e6eb39b2bfe7f1737f1dc003 pmtud probe status false hs_con=true hs_sent=true cwnd_avail=4157 out_len=1350 left=1324 [2025-04-30T12:28:45.879459599Z TRACE quiche] 88f12fb4444785c0e6eb39b2bfe7f1737f1dc003 tx pkt Short dcid=431965a8e70d05bc key_phase=false len=1324 pn=9 [2025-04-30T12:28:45.879464679Z TRACE quiche] 88f12fb4444785c0e6eb39b2bfe7f1737f1dc003 tx frm STREAM id=4 off=3955 len=1318 fin=false [2025-04-30T12:28:45.879478544Z TRACE quiche::recovery::congestion::recovery] 88f12fb4444785c0e6eb39b2bfe7f1737f1dc003 timer=107.903804ms latest_rtt=33.193652ms srtt=33.163144ms min_rtt=33.158787ms rttvar=12.44326ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=10693 app_limited=true congestion_recovery_start_time=None Rate { delivered: 910, delivered_time: Instant { tv_sec: 528, tv_nsec: 379127698 }, first_sent_time: Instant { tv_sec: 528, tv_nsec: 379127698 }, end_of_app_limited: 1, last_sent_packet: 9, largest_acked: 1, rate_sample: RateSample { delivery_rate: 27443, is_app_limited: true, interval: 33.158787ms, delivered: 910, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 528, tv_nsec: 345613558 }), send_elapsed: 0ns, ack_elapsed: 33.158787ms, rtt: 33.158787ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 508848, last_update: Instant { tv_sec: 528, tv_nsec: 379127698 }, next_time: Instant { tv_sec: 528, tv_nsec: 379127698 }, 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-30T12:28:45.879507769Z TRACE quiche] 88f12fb4444785c0e6eb39b2bfe7f1737f1dc003 pmtud probe status false hs_con=true hs_sent=true cwnd_avail=2807 out_len=1350 left=1324 [2025-04-30T12:28:45.879525642Z TRACE quiche] 88f12fb4444785c0e6eb39b2bfe7f1737f1dc003 tx pkt Short dcid=431965a8e70d05bc key_phase=false len=1324 pn=10 [2025-04-30T12:28:45.879531133Z TRACE quiche] 88f12fb4444785c0e6eb39b2bfe7f1737f1dc003 tx frm STREAM id=4 off=5273 len=1318 fin=false [2025-04-30T12:28:45.879543856Z TRACE quiche::recovery::congestion::recovery] 88f12fb4444785c0e6eb39b2bfe7f1737f1dc003 timer=107.894537ms latest_rtt=33.193652ms srtt=33.163144ms min_rtt=33.158787ms rttvar=12.44326ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=12043 app_limited=true congestion_recovery_start_time=None Rate { delivered: 910, delivered_time: Instant { tv_sec: 528, tv_nsec: 379127698 }, first_sent_time: Instant { tv_sec: 528, tv_nsec: 379127698 }, end_of_app_limited: 1, last_sent_packet: 10, largest_acked: 1, rate_sample: RateSample { delivery_rate: 27443, is_app_limited: true, interval: 33.158787ms, delivered: 910, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 528, tv_nsec: 345613558 }), send_elapsed: 0ns, ack_elapsed: 33.158787ms, rtt: 33.158787ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 508848, last_update: Instant { tv_sec: 528, tv_nsec: 379127698 }, next_time: Instant { tv_sec: 528, tv_nsec: 379127698 }, 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-30T12:28:45.879567991Z TRACE quiche] 88f12fb4444785c0e6eb39b2bfe7f1737f1dc003 pmtud probe status false hs_con=true hs_sent=true cwnd_avail=1457 out_len=1350 left=1324 [2025-04-30T12:28:45.879574754Z TRACE quiche] 88f12fb4444785c0e6eb39b2bfe7f1737f1dc003 tx pkt Short dcid=431965a8e70d05bc key_phase=false len=1324 pn=11 [2025-04-30T12:28:45.879579893Z TRACE quiche] 88f12fb4444785c0e6eb39b2bfe7f1737f1dc003 tx frm STREAM id=4 off=6591 len=1318 fin=false [2025-04-30T12:28:45.879590834Z TRACE quiche::recovery::congestion::recovery] 88f12fb4444785c0e6eb39b2bfe7f1737f1dc003 timer=107.909584ms latest_rtt=33.193652ms srtt=33.163144ms min_rtt=33.158787ms rttvar=12.44326ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=13393 app_limited=true congestion_recovery_start_time=None Rate { delivered: 910, delivered_time: Instant { tv_sec: 528, tv_nsec: 379127698 }, first_sent_time: Instant { tv_sec: 528, tv_nsec: 379127698 }, end_of_app_limited: 1, last_sent_packet: 11, largest_acked: 1, rate_sample: RateSample { delivery_rate: 27443, is_app_limited: true, interval: 33.158787ms, delivered: 910, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 528, tv_nsec: 345613558 }), send_elapsed: 0ns, ack_elapsed: 33.158787ms, rtt: 33.158787ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 508848, last_update: Instant { tv_sec: 528, tv_nsec: 379127698 }, next_time: Instant { tv_sec: 528, tv_nsec: 379127698 }, 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-30T12:28:45.879605111Z TRACE quiche] 88f12fb4444785c0e6eb39b2bfe7f1737f1dc003 pmtud probe status false hs_con=true hs_sent=true cwnd_avail=107 out_len=1350 left=81 [2025-04-30T12:28:45.879608918Z TRACE quiche] 88f12fb4444785c0e6eb39b2bfe7f1737f1dc003 tx pkt Short dcid=431965a8e70d05bc key_phase=false len=81 pn=12 [2025-04-30T12:28:45.879611913Z TRACE quiche] 88f12fb4444785c0e6eb39b2bfe7f1737f1dc003 tx frm STREAM id=4 off=7909 len=75 fin=false [2025-04-30T12:28:45.879617975Z TRACE quiche::recovery::congestion::recovery] 88f12fb4444785c0e6eb39b2bfe7f1737f1dc003 timer=107.921136ms latest_rtt=33.193652ms srtt=33.163144ms min_rtt=33.158787ms rttvar=12.44326ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=13500 app_limited=false congestion_recovery_start_time=None Rate { delivered: 910, delivered_time: Instant { tv_sec: 528, tv_nsec: 379127698 }, first_sent_time: Instant { tv_sec: 528, tv_nsec: 379127698 }, end_of_app_limited: 1, last_sent_packet: 12, largest_acked: 1, rate_sample: RateSample { delivery_rate: 27443, is_app_limited: true, interval: 33.158787ms, delivered: 910, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 528, tv_nsec: 345613558 }), send_elapsed: 0ns, ack_elapsed: 33.158787ms, rtt: 33.158787ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 508848, last_update: Instant { tv_sec: 528, tv_nsec: 379127698 }, next_time: Instant { tv_sec: 528, tv_nsec: 379127698 }, 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-30T12:28:45.879687113Z TRACE quiche_server] 88f12fb4444785c0e6eb39b2bfe7f1737f1dc003 written 4157 bytes with Some(SendInfo { from: [::]:443, to: [fd00:cafe:cafe::100]:34756, at: Instant { tv_sec: 528, tv_nsec: 379127698 } }) [2025-04-30T12:28:45.879693866Z TRACE quiche_server] Collecting garbage [2025-04-30T12:28:45.879698895Z TRACE quiche_server] recv() would block [2025-04-30T12:28:45.879703965Z TRACE quiche] 88f12fb4444785c0e6eb39b2bfe7f1737f1dc003 pmtud probe status false hs_con=true hs_sent=true cwnd_avail=0 out_len=1350 left=0 [2025-04-30T12:28:45.879709595Z TRACE quiche_server] 88f12fb4444785c0e6eb39b2bfe7f1737f1dc003 done writing [2025-04-30T12:28:45.879714765Z TRACE quiche_server] Collecting garbage [2025-04-30T12:28:45.911019114Z TRACE quiche_server] got 43 bytes from [fd00:cafe:cafe::100]:34756 to [::]:443 [2025-04-30T12:28:45.911032669Z TRACE quiche_server] got packet Short dcid=88f12fb4444785c0e6eb39b2bfe7f1737f1dc003 key_phase=false [2025-04-30T12:28:45.911042006Z TRACE quiche] 88f12fb4444785c0e6eb39b2bfe7f1737f1dc003 rx pkt Short dcid=88f12fb4444785c0e6eb39b2bfe7f1737f1dc003 key_phase=false len=22 pn=3 [2025-04-30T12:28:45.911051093Z TRACE quiche] 88f12fb4444785c0e6eb39b2bfe7f1737f1dc003 rx frm ACK delay=0 blocks=[2..2] ecn_counts=None [2025-04-30T12:28:45.911056153Z TRACE quiche::recovery::congestion::recovery] 88f12fb4444785c0e6eb39b2bfe7f1737f1dc003 packet newly acked 2 [2025-04-30T12:28:45.911074046Z TRACE quiche_server] 88f12fb4444785c0e6eb39b2bfe7f1737f1dc003 processed 43 bytes [2025-04-30T12:28:45.911080228Z TRACE quiche_server] recv() would block [2025-04-30T12:28:45.911087191Z TRACE quiche] 88f12fb4444785c0e6eb39b2bfe7f1737f1dc003 pmtud probe status false hs_con=true hs_sent=true cwnd_avail=2700 out_len=1350 left=1324 [2025-04-30T12:28:45.911092992Z TRACE quiche] 88f12fb4444785c0e6eb39b2bfe7f1737f1dc003 tx pkt Short dcid=431965a8e70d05bc key_phase=false len=1324 pn=13 [2025-04-30T12:28:45.911096247Z TRACE quiche] 88f12fb4444785c0e6eb39b2bfe7f1737f1dc003 tx frm STREAM id=4 off=7984 len=1318 fin=false [2025-04-30T12:28:45.911104543Z TRACE quiche::recovery::congestion::recovery] 88f12fb4444785c0e6eb39b2bfe7f1737f1dc003 timer=96.548401ms latest_rtt=31.931819ms srtt=33.009228ms min_rtt=31.931819ms rttvar=9.640276ms cwnd=14850 ssthresh=18446744073709551615 bytes_in_flight=13500 app_limited=true congestion_recovery_start_time=None Rate { delivered: 2260, delivered_time: Instant { tv_sec: 528, tv_nsec: 411059517 }, first_sent_time: Instant { tv_sec: 528, tv_nsec: 379127698 }, end_of_app_limited: 0, last_sent_packet: 13, largest_acked: 2, rate_sample: RateSample { delivery_rate: 42277, is_app_limited: true, interval: 31.931819ms, delivered: 1350, prior_delivered: 910, prior_time: Some(Instant { tv_sec: 528, tv_nsec: 379127698 }), send_elapsed: 0ns, ack_elapsed: 31.931819ms, rtt: 31.931819ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 562342, last_update: Instant { tv_sec: 528, tv_nsec: 411102156 }, next_time: Instant { tv_sec: 528, tv_nsec: 411102156 }, max_datagram_size: 1350, last_packet_size: Some(0), iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(13) last_round_min_rtt=31.931819ms 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-30T12:28:45.911129850Z TRACE quiche] 88f12fb4444785c0e6eb39b2bfe7f1737f1dc003 pmtud probe status false hs_con=true hs_sent=true cwnd_avail=1350 out_len=1350 left=1324 [2025-04-30T12:28:45.911134038Z TRACE quiche] 88f12fb4444785c0e6eb39b2bfe7f1737f1dc003 tx pkt Short dcid=431965a8e70d05bc key_phase=false len=944 pn=14 [2025-04-30T12:28:45.911137054Z TRACE quiche] 88f12fb4444785c0e6eb39b2bfe7f1737f1dc003 tx frm STREAM id=4 off=9302 len=938 fin=true [2025-04-30T12:28:45.911143115Z TRACE quiche::recovery::congestion::recovery] 88f12fb4444785c0e6eb39b2bfe7f1737f1dc003 timer=96.555083ms latest_rtt=31.931819ms srtt=33.009228ms min_rtt=31.931819ms rttvar=9.640276ms cwnd=14850 ssthresh=18446744073709551615 bytes_in_flight=14470 app_limited=true congestion_recovery_start_time=None Rate { delivered: 2260, delivered_time: Instant { tv_sec: 528, tv_nsec: 411059517 }, first_sent_time: Instant { tv_sec: 528, tv_nsec: 379127698 }, end_of_app_limited: 0, last_sent_packet: 14, largest_acked: 2, rate_sample: RateSample { delivery_rate: 42277, is_app_limited: true, interval: 31.931819ms, delivered: 1350, prior_delivered: 910, prior_time: Some(Instant { tv_sec: 528, tv_nsec: 379127698 }), send_elapsed: 0ns, ack_elapsed: 31.931819ms, rtt: 31.931819ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 562342, last_update: Instant { tv_sec: 528, tv_nsec: 411102156 }, next_time: Instant { tv_sec: 528, tv_nsec: 411102156 }, max_datagram_size: 1350, last_packet_size: Some(0), iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(13) last_round_min_rtt=31.931819ms 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-30T12:28:45.911190073Z TRACE quiche_server] 88f12fb4444785c0e6eb39b2bfe7f1737f1dc003 written 2320 bytes with Some(SendInfo { from: [::]:443, to: [fd00:cafe:cafe::100]:34756, at: Instant { tv_sec: 528, tv_nsec: 411102156 } }) [2025-04-30T12:28:45.911198779Z TRACE quiche_server] Collecting garbage [2025-04-30T12:28:45.911206633Z TRACE quiche_server] recv() would block [2025-04-30T12:28:45.911212103Z TRACE quiche_server] 88f12fb4444785c0e6eb39b2bfe7f1737f1dc003 done writing [2025-04-30T12:28:45.911216492Z TRACE quiche_server] Collecting garbage [2025-04-30T12:28:45.913176166Z TRACE quiche_server] got 43 bytes from [fd00:cafe:cafe::100]:34756 to [::]:443 [2025-04-30T12:28:45.913186836Z TRACE quiche_server] got packet Short dcid=88f12fb4444785c0e6eb39b2bfe7f1737f1dc003 key_phase=false [2025-04-30T12:28:45.913192507Z TRACE quiche] 88f12fb4444785c0e6eb39b2bfe7f1737f1dc003 rx pkt Short dcid=88f12fb4444785c0e6eb39b2bfe7f1737f1dc003 key_phase=false len=22 pn=4 [2025-04-30T12:28:45.913197967Z TRACE quiche] 88f12fb4444785c0e6eb39b2bfe7f1737f1dc003 rx frm ACK delay=0 blocks=[2..4] ecn_counts=None [2025-04-30T12:28:45.913201493Z TRACE quiche::recovery::congestion::recovery] 88f12fb4444785c0e6eb39b2bfe7f1737f1dc003 packet newly acked 3 [2025-04-30T12:28:45.913204088Z TRACE quiche::recovery::congestion::recovery] 88f12fb4444785c0e6eb39b2bfe7f1737f1dc003 packet newly acked 4 [2025-04-30T12:28:45.913214969Z TRACE quiche_server] 88f12fb4444785c0e6eb39b2bfe7f1737f1dc003 processed 43 bytes [2025-04-30T12:28:45.913219617Z TRACE quiche_server] recv() would block [2025-04-30T12:28:45.913222523Z TRACE quiche_server] 88f12fb4444785c0e6eb39b2bfe7f1737f1dc003 done writing [2025-04-30T12:28:45.913224887Z TRACE quiche_server] Collecting garbage [2025-04-30T12:28:45.915400725Z TRACE quiche_server] got 43 bytes from [fd00:cafe:cafe::100]:34756 to [::]:443 [2025-04-30T12:28:45.915409842Z TRACE quiche_server] got packet Short dcid=88f12fb4444785c0e6eb39b2bfe7f1737f1dc003 key_phase=false [2025-04-30T12:28:45.915419911Z TRACE quiche] 88f12fb4444785c0e6eb39b2bfe7f1737f1dc003 rx pkt Short dcid=88f12fb4444785c0e6eb39b2bfe7f1737f1dc003 key_phase=false len=22 pn=5 [2025-04-30T12:28:45.915425331Z TRACE quiche] 88f12fb4444785c0e6eb39b2bfe7f1737f1dc003 rx frm ACK delay=0 blocks=[2..6] ecn_counts=None [2025-04-30T12:28:45.915428587Z TRACE quiche::recovery::congestion::recovery] 88f12fb4444785c0e6eb39b2bfe7f1737f1dc003 packet newly acked 5 [2025-04-30T12:28:45.915431062Z TRACE quiche::recovery::congestion::recovery] 88f12fb4444785c0e6eb39b2bfe7f1737f1dc003 packet newly acked 6 [2025-04-30T12:28:45.915440780Z TRACE quiche_server] 88f12fb4444785c0e6eb39b2bfe7f1737f1dc003 processed 43 bytes [2025-04-30T12:28:45.915450247Z TRACE quiche_server] recv() would block [2025-04-30T12:28:45.915456249Z TRACE quiche_server] 88f12fb4444785c0e6eb39b2bfe7f1737f1dc003 done writing [2025-04-30T12:28:45.915458493Z TRACE quiche_server] Collecting garbage [2025-04-30T12:28:45.917553700Z TRACE quiche_server] got 43 bytes from [fd00:cafe:cafe::100]:34756 to [::]:443 [2025-04-30T12:28:45.917567315Z TRACE quiche_server] got packet Short dcid=88f12fb4444785c0e6eb39b2bfe7f1737f1dc003 key_phase=false [2025-04-30T12:28:45.917573336Z TRACE quiche] 88f12fb4444785c0e6eb39b2bfe7f1737f1dc003 rx pkt Short dcid=88f12fb4444785c0e6eb39b2bfe7f1737f1dc003 key_phase=false len=22 pn=6 [2025-04-30T12:28:45.917578275Z TRACE quiche] 88f12fb4444785c0e6eb39b2bfe7f1737f1dc003 rx frm ACK delay=0 blocks=[2..8] ecn_counts=None [2025-04-30T12:28:45.917581432Z TRACE quiche::recovery::congestion::recovery] 88f12fb4444785c0e6eb39b2bfe7f1737f1dc003 packet newly acked 7 [2025-04-30T12:28:45.917583806Z TRACE quiche::recovery::congestion::recovery] 88f12fb4444785c0e6eb39b2bfe7f1737f1dc003 packet newly acked 8 [2025-04-30T12:28:45.917595748Z TRACE quiche_server] 88f12fb4444785c0e6eb39b2bfe7f1737f1dc003 processed 43 bytes [2025-04-30T12:28:45.917601228Z TRACE quiche_server] recv() would block [2025-04-30T12:28:45.917606428Z TRACE quiche_server] 88f12fb4444785c0e6eb39b2bfe7f1737f1dc003 done writing [2025-04-30T12:28:45.917609734Z TRACE quiche_server] Collecting garbage [2025-04-30T12:28:45.917667502Z TRACE quiche_server] got 43 bytes from [fd00:cafe:cafe::100]:34756 to [::]:443 [2025-04-30T12:28:45.917673704Z TRACE quiche_server] got packet Short dcid=88f12fb4444785c0e6eb39b2bfe7f1737f1dc003 key_phase=false [2025-04-30T12:28:45.917678593Z TRACE quiche] 88f12fb4444785c0e6eb39b2bfe7f1737f1dc003 rx pkt Short dcid=88f12fb4444785c0e6eb39b2bfe7f1737f1dc003 key_phase=false len=22 pn=7 [2025-04-30T12:28:45.917683322Z TRACE quiche] 88f12fb4444785c0e6eb39b2bfe7f1737f1dc003 rx frm MAX_DATA max=74611 [2025-04-30T12:28:45.917689643Z TRACE quiche_server] 88f12fb4444785c0e6eb39b2bfe7f1737f1dc003 processed 43 bytes [2025-04-30T12:28:45.917693440Z TRACE quiche_server] recv() would block [2025-04-30T12:28:45.917698851Z TRACE quiche] 88f12fb4444785c0e6eb39b2bfe7f1737f1dc003 pmtud probe status false hs_con=true hs_sent=true cwnd_avail=8373 out_len=1350 left=1319 [2025-04-30T12:28:45.917702177Z TRACE quiche] 88f12fb4444785c0e6eb39b2bfe7f1737f1dc003 tx pkt Short dcid=431965a8e70d05bc key_phase=false len=5 pn=15 [2025-04-30T12:28:45.917704721Z TRACE quiche] 88f12fb4444785c0e6eb39b2bfe7f1737f1dc003 tx frm ACK delay=2 blocks=[3..7] ecn_counts=None [2025-04-30T12:28:45.917711344Z TRACE quiche::recovery::congestion::recovery] 88f12fb4444785c0e6eb39b2bfe7f1737f1dc003 timer=76.743145ms latest_rtt=38.46394ms srtt=34.154883ms min_rtt=31.931819ms rttvar=6.04294ms cwnd=14850 ssthresh=18446744073709551615 bytes_in_flight=6477 app_limited=true congestion_recovery_start_time=None Rate { delivered: 10253, delivered_time: Instant { tv_sec: 528, tv_nsec: 417591638 }, first_sent_time: Instant { tv_sec: 528, tv_nsec: 379127698 }, end_of_app_limited: 0, last_sent_packet: 15, largest_acked: 8, rate_sample: RateSample { delivery_rate: 292592, is_app_limited: true, interval: 31.931819ms, delivered: 9343, prior_delivered: 910, prior_time: Some(Instant { tv_sec: 528, tv_nsec: 379127698 }), send_elapsed: 0ns, ack_elapsed: 31.931819ms, rtt: 31.931819ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 543480, last_update: Instant { tv_sec: 528, tv_nsec: 411102156 }, next_time: Instant { tv_sec: 528, tv_nsec: 411102156 }, max_datagram_size: 1350, last_packet_size: Some(0), iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(13) last_round_min_rtt=31.931819ms 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-30T12:28:45.917747782Z TRACE quiche_server] 88f12fb4444785c0e6eb39b2bfe7f1737f1dc003 written 31 bytes with Some(SendInfo { from: [::]:443, to: [fd00:cafe:cafe::100]:34756, at: Instant { tv_sec: 528, tv_nsec: 411102156 } }) [2025-04-30T12:28:45.917752901Z TRACE quiche_server] Collecting garbage [2025-04-30T12:28:45.917756588Z TRACE quiche_server] recv() would block [2025-04-30T12:28:45.917759173Z TRACE quiche_server] 88f12fb4444785c0e6eb39b2bfe7f1737f1dc003 done writing [2025-04-30T12:28:45.917761357Z TRACE quiche_server] Collecting garbage [2025-04-30T12:28:45.919817211Z TRACE quiche_server] got 43 bytes from [fd00:cafe:cafe::100]:34756 to [::]:443 [2025-04-30T12:28:45.919828762Z TRACE quiche_server] got packet Short dcid=88f12fb4444785c0e6eb39b2bfe7f1737f1dc003 key_phase=false [2025-04-30T12:28:45.919835315Z TRACE quiche] 88f12fb4444785c0e6eb39b2bfe7f1737f1dc003 rx pkt Short dcid=88f12fb4444785c0e6eb39b2bfe7f1737f1dc003 key_phase=false len=22 pn=8 [2025-04-30T12:28:45.919841837Z TRACE quiche] 88f12fb4444785c0e6eb39b2bfe7f1737f1dc003 rx frm ACK delay=0 blocks=[2..10] ecn_counts=None [2025-04-30T12:28:45.919846215Z TRACE quiche::recovery::congestion::recovery] 88f12fb4444785c0e6eb39b2bfe7f1737f1dc003 packet newly acked 9 [2025-04-30T12:28:45.919849241Z TRACE quiche::recovery::congestion::recovery] 88f12fb4444785c0e6eb39b2bfe7f1737f1dc003 packet newly acked 10 [2025-04-30T12:28:45.919862295Z TRACE quiche_server] 88f12fb4444785c0e6eb39b2bfe7f1737f1dc003 processed 43 bytes [2025-04-30T12:28:45.919867304Z TRACE quiche_server] recv() would block [2025-04-30T12:28:45.919870791Z TRACE quiche_server] 88f12fb4444785c0e6eb39b2bfe7f1737f1dc003 done writing [2025-04-30T12:28:45.919873576Z TRACE quiche_server] Collecting garbage [2025-04-30T12:28:45.921046824Z TRACE quiche_server] got 43 bytes from [fd00:cafe:cafe::100]:34756 to [::]:443 [2025-04-30T12:28:45.921056452Z TRACE quiche_server] got packet Short dcid=88f12fb4444785c0e6eb39b2bfe7f1737f1dc003 key_phase=false [2025-04-30T12:28:45.921061441Z TRACE quiche] 88f12fb4444785c0e6eb39b2bfe7f1737f1dc003 rx pkt Short dcid=88f12fb4444785c0e6eb39b2bfe7f1737f1dc003 key_phase=false len=22 pn=9 [2025-04-30T12:28:45.921067302Z TRACE quiche] 88f12fb4444785c0e6eb39b2bfe7f1737f1dc003 rx frm ACK delay=0 blocks=[2..12] ecn_counts=None [2025-04-30T12:28:45.921071309Z TRACE quiche::recovery::congestion::recovery] 88f12fb4444785c0e6eb39b2bfe7f1737f1dc003 packet newly acked 11 [2025-04-30T12:28:45.921073694Z TRACE quiche::recovery::congestion::recovery] 88f12fb4444785c0e6eb39b2bfe7f1737f1dc003 packet newly acked 12 [2025-04-30T12:28:45.921083272Z TRACE quiche_server] 88f12fb4444785c0e6eb39b2bfe7f1737f1dc003 processed 43 bytes [2025-04-30T12:28:45.921087299Z TRACE quiche_server] recv() would block [2025-04-30T12:28:45.921090084Z TRACE quiche_server] 88f12fb4444785c0e6eb39b2bfe7f1737f1dc003 done writing [2025-04-30T12:28:45.921092239Z TRACE quiche_server] Collecting garbage [2025-04-30T12:28:45.942787938Z TRACE quiche_server] got 49 bytes from [fd00:cafe:cafe::100]:34756 to [::]:443 [2025-04-30T12:28:45.942800501Z TRACE quiche_server] got packet Short dcid=88f12fb4444785c0e6eb39b2bfe7f1737f1dc003 key_phase=false [2025-04-30T12:28:45.942807744Z TRACE quiche] 88f12fb4444785c0e6eb39b2bfe7f1737f1dc003 rx pkt Short dcid=88f12fb4444785c0e6eb39b2bfe7f1737f1dc003 key_phase=false len=28 pn=10 [2025-04-30T12:28:45.942814918Z TRACE quiche] 88f12fb4444785c0e6eb39b2bfe7f1737f1dc003 rx frm ACK delay=7 blocks=[2..13] ecn_counts=None [2025-04-30T12:28:45.942826710Z TRACE quiche::recovery::congestion::recovery] 88f12fb4444785c0e6eb39b2bfe7f1737f1dc003 packet newly acked 13 [2025-04-30T12:28:45.942831509Z TRACE quiche] 88f12fb4444785c0e6eb39b2bfe7f1737f1dc003 rx frm MAX_STREAM_DATA stream=4 max=74838 [2025-04-30T12:28:45.942844643Z TRACE quiche_server] 88f12fb4444785c0e6eb39b2bfe7f1737f1dc003 processed 49 bytes [2025-04-30T12:28:45.942849973Z TRACE quiche_server] recv() would block [2025-04-30T12:28:45.942857457Z TRACE quiche] 88f12fb4444785c0e6eb39b2bfe7f1737f1dc003 pmtud probe status false hs_con=true hs_sent=true cwnd_avail=13880 out_len=1350 left=1319 [2025-04-30T12:28:45.942861685Z TRACE quiche] 88f12fb4444785c0e6eb39b2bfe7f1737f1dc003 tx pkt Short dcid=431965a8e70d05bc key_phase=false len=5 pn=16 [2025-04-30T12:28:45.942864731Z TRACE quiche] 88f12fb4444785c0e6eb39b2bfe7f1737f1dc003 tx frm ACK delay=6 blocks=[3..10] ecn_counts=None [2025-04-30T12:28:45.942871994Z TRACE quiche::recovery::congestion::recovery] 88f12fb4444785c0e6eb39b2bfe7f1737f1dc003 timer=51.838366ms latest_rtt=31.72353ms srtt=35.332616ms min_rtt=31.72353ms rttvar=5.812507ms cwnd=14850 ssthresh=18446744073709551615 bytes_in_flight=970 app_limited=true congestion_recovery_start_time=None Rate { delivered: 15760, delivered_time: Instant { tv_sec: 528, tv_nsec: 442825686 }, first_sent_time: Instant { tv_sec: 528, tv_nsec: 411102156 }, end_of_app_limited: 15, last_sent_packet: 16, largest_acked: 13, rate_sample: RateSample { delivery_rate: 422212, is_app_limited: false, interval: 31.974458ms, delivered: 13500, prior_delivered: 2260, prior_time: Some(Instant { tv_sec: 528, tv_nsec: 411059517 }), send_elapsed: 31.974458ms, ack_elapsed: 31.766169ms, rtt: 31.72353ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 525364, last_update: Instant { tv_sec: 528, tv_nsec: 442871741 }, next_time: Instant { tv_sec: 528, tv_nsec: 442871741 }, max_datagram_size: 1350, last_packet_size: Some(0), iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(13) last_round_min_rtt=31.931819ms 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-30T12:28:45.942910767Z TRACE quiche_server] 88f12fb4444785c0e6eb39b2bfe7f1737f1dc003 written 31 bytes with Some(SendInfo { from: [::]:443, to: [fd00:cafe:cafe::100]:34756, at: Instant { tv_sec: 528, tv_nsec: 442871741 } }) [2025-04-30T12:28:45.942916437Z TRACE quiche_server] Collecting garbage [2025-04-30T12:28:45.942921206Z TRACE quiche_server] recv() would block [2025-04-30T12:28:45.942924462Z TRACE quiche_server] 88f12fb4444785c0e6eb39b2bfe7f1737f1dc003 done writing [2025-04-30T12:28:45.942927137Z TRACE quiche_server] Collecting garbage [2025-04-30T12:28:45.943573032Z TRACE quiche_server] got 42 bytes from [fd00:cafe:cafe::100]:34756 to [::]:443 [2025-04-30T12:28:45.943581117Z TRACE quiche_server] got packet Short dcid=88f12fb4444785c0e6eb39b2bfe7f1737f1dc003 key_phase=false [2025-04-30T12:28:45.943587639Z TRACE quiche] 88f12fb4444785c0e6eb39b2bfe7f1737f1dc003 rx pkt Short dcid=88f12fb4444785c0e6eb39b2bfe7f1737f1dc003 key_phase=false len=21 pn=11 [2025-04-30T12:28:45.943594311Z TRACE quiche] 88f12fb4444785c0e6eb39b2bfe7f1737f1dc003 rx frm CONNECTION_CLOSE err=0 frame=0 reason=[] [2025-04-30T12:28:45.943603689Z TRACE quiche_server] 88f12fb4444785c0e6eb39b2bfe7f1737f1dc003 processed 42 bytes [2025-04-30T12:28:45.943608658Z TRACE quiche_server] recv() would block [2025-04-30T12:28:45.943611574Z TRACE quiche_server] 88f12fb4444785c0e6eb39b2bfe7f1737f1dc003 done writing [2025-04-30T12:28:45.943614389Z TRACE quiche_server] Collecting garbage [2025-04-30T12:28:46.119842958Z TRACE quiche_server] timed out [2025-04-30T12:28:46.119862785Z TRACE quiche] 88f12fb4444785c0e6eb39b2bfe7f1737f1dc003 draining timeout expired [2025-04-30T12:28:46.119900946Z TRACE quiche_server] 88f12fb4444785c0e6eb39b2bfe7f1737f1dc003 done writing [2025-04-30T12:28:46.119904503Z TRACE quiche_server] Collecting garbage [2025-04-30T12:28:46.119911676Z INFO quiche_server] 88f12fb4444785c0e6eb39b2bfe7f1737f1dc003 connection collected recv=15 sent=17 lost=0 retrans=0 sent_bytes=16792 recv_bytes=2004 lost_bytes=0 [local_addr=[::]:443 peer_addr=[fd00:cafe:cafe::100]:34756 validation_state=Validated active=true recv=15 sent=17 lost=0 retrans=0 rtt=35.332616ms min_rtt=Some(31.72353ms) rttvar=5.812507ms cwnd=14850 sent_bytes=16792 recv_bytes=2004 lost_bytes=0 stream_retrans_bytes=0 pmtu=1350 delivery_rate=422212]