[2025-09-12T02:40:17.821983409Z INFO quiche_server] listening on [::]:443 [2025-09-12T02:40:17.822004618Z TRACE mio::poll] registering event source with poller: token=Token(0), interests=READABLE [2025-09-12T02:40:17.822010659Z TRACE quiche_server] GSO detected: false [2025-09-12T02:40:18.142708848Z TRACE quiche_server] got 1207 bytes from [::ffff:193.167.100.2]:52302 to [::]:443 [2025-09-12T02:40:18.142756056Z TRACE quiche_server] got packet Initial version=57414954 dcid= scid= token= [2025-09-12T02:40:18.142764402Z WARN quiche_server] Doing version negotiation [2025-09-12T02:40:18.142844912Z TRACE quiche_server] recv() would block [2025-09-12T02:40:18.852285482Z TRACE quiche_server] got 1232 bytes from [fd00:cafe:cafe::100]:36922 to [::]:443 [2025-09-12T02:40:18.852309226Z TRACE quiche_server] got packet Initial version=1 dcid=8e2f9e9245bb1a63fc1768ccf7 scid= token= [2025-09-12T02:40:18.852323793Z DEBUG quiche_server] New connection: dcid=8e2f9e9245bb1a63fc1768ccf7 scid=a765fd8c4c22aa86807d2f05b1a971767d9cd78a [2025-09-12T02:40:18.852553773Z TRACE quiche] a765fd8c4c22aa86807d2f05b1a971767d9cd78a rx pkt Initial version=1 dcid=8e2f9e9245bb1a63fc1768ccf7 scid= token= len=1209 pn=3 [2025-09-12T02:40:18.852571185Z TRACE quiche] a765fd8c4c22aa86807d2f05b1a971767d9cd78a rx frm CRYPTO off=0 len=1188 [2025-09-12T02:40:18.852606902Z TRACE quiche_server] a765fd8c4c22aa86807d2f05b1a971767d9cd78a processed 1232 bytes [2025-09-12T02:40:18.852618584Z TRACE quiche_server] got 1232 bytes from [fd00:cafe:cafe::100]:36922 to [::]:443 [2025-09-12T02:40:18.852622411Z TRACE quiche_server] got packet Initial version=1 dcid=8e2f9e9245bb1a63fc1768ccf7 scid= token= [2025-09-12T02:40:18.852626839Z TRACE quiche] a765fd8c4c22aa86807d2f05b1a971767d9cd78a rx pkt Initial version=1 dcid=8e2f9e9245bb1a63fc1768ccf7 scid= token= len=374 pn=4 [2025-09-12T02:40:18.852630887Z TRACE quiche] a765fd8c4c22aa86807d2f05b1a971767d9cd78a rx frm CRYPTO off=1188 len=352 [2025-09-12T02:40:18.852652006Z TRACE quiche::tls] checking peer ALPN Ok("hq-interop") against Ok("h3") [2025-09-12T02:40:18.852655933Z TRACE quiche::tls] checking peer ALPN Ok("hq-interop") against Ok("hq-interop") [2025-09-12T02:40:18.852742305Z TRACE quiche::tls] a765fd8c4c22aa86807d2f05b1a971767d9cd78a write message lvl=Initial len=90 [2025-09-12T02:40:18.852768534Z TRACE quiche::tls] a765fd8c4c22aa86807d2f05b1a971767d9cd78a set write secret lvl=Handshake [2025-09-12T02:40:18.852832343Z TRACE quiche::tls] a765fd8c4c22aa86807d2f05b1a971767d9cd78a write message lvl=Handshake len=700 [2025-09-12T02:40:18.852835359Z TRACE quiche::tls] a765fd8c4c22aa86807d2f05b1a971767d9cd78a set write secret lvl=OneRTT [2025-09-12T02:40:18.852841600Z TRACE quiche::tls] a765fd8c4c22aa86807d2f05b1a971767d9cd78a set read secret lvl=Handshake [2025-09-12T02:40:18.852856999Z TRACE quiche] a765fd8c4c22aa86807d2f05b1a971767d9cd78a dropped invalid packet [2025-09-12T02:40:18.852859614Z TRACE quiche_server] a765fd8c4c22aa86807d2f05b1a971767d9cd78a processed 1232 bytes [2025-09-12T02:40:18.852872899Z TRACE quiche_server] recv() would block [2025-09-12T02:40:18.852884440Z TRACE quiche] a765fd8c4c22aa86807d2f05b1a971767d9cd78a tx pkt Initial version=1 dcid= scid=a765fd8c4c22aa86807d2f05b1a971767d9cd78a len=99 pn=0 [2025-09-12T02:40:18.852887837Z TRACE quiche] a765fd8c4c22aa86807d2f05b1a971767d9cd78a tx frm ACK delay=31 blocks=[3..4] ecn_counts=None [2025-09-12T02:40:18.852892385Z TRACE quiche] a765fd8c4c22aa86807d2f05b1a971767d9cd78a tx frm CRYPTO off=0 len=90 [2025-09-12T02:40:18.852900821Z TRACE quiche::recovery::congestion::recovery] a765fd8c4c22aa86807d2f05b1a971767d9cd78a timer=998.974232ms latest_rtt=0ns srtt=333ms min_rtt=333ms rttvar=166.5ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=146 app_limited=true congestion_recovery_start_time=None Rate { delivered: 0, delivered_time: Instant { tv_sec: 1565, tv_nsec: 598364973 }, first_sent_time: Instant { tv_sec: 1565, tv_nsec: 598364973 }, end_of_app_limited: 1, last_sent_packet: 0, largest_acked: 0, rate_sample: RateSample { bandwidth: 0.00 Kbps, is_app_limited: false, interval: 0ns, delivered: 0, prior_delivered: 0, prior_time: None, send_elapsed: 0ns, ack_elapsed: 0ns, rtt: 0ns } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 0, last_update: Instant { tv_sec: 1565, tv_nsec: 598364973 }, next_time: Instant { tv_sec: 1565, tv_nsec: 598364973 }, max_datagram_size: 1350, last_packet_size: None, iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } [2025-09-12T02:40:18.852927681Z TRACE quiche] a765fd8c4c22aa86807d2f05b1a971767d9cd78a tx pkt Handshake version=1 dcid= scid=a765fd8c4c22aa86807d2f05b1a971767d9cd78a len=704 pn=1 [2025-09-12T02:40:18.852930506Z TRACE quiche] a765fd8c4c22aa86807d2f05b1a971767d9cd78a tx frm CRYPTO off=0 len=700 [2025-09-12T02:40:18.852935936Z TRACE quiche::recovery::congestion::recovery] a765fd8c4c22aa86807d2f05b1a971767d9cd78a timer=998.939447ms latest_rtt=0ns srtt=333ms min_rtt=333ms rttvar=166.5ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=896 app_limited=true congestion_recovery_start_time=None Rate { delivered: 0, delivered_time: Instant { tv_sec: 1565, tv_nsec: 598364973 }, first_sent_time: Instant { tv_sec: 1565, tv_nsec: 598364973 }, end_of_app_limited: 1, last_sent_packet: 1, largest_acked: 0, rate_sample: RateSample { bandwidth: 0.00 Kbps, is_app_limited: false, interval: 0ns, delivered: 0, prior_delivered: 0, prior_time: None, send_elapsed: 0ns, ack_elapsed: 0ns, rtt: 0ns } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 0, last_update: Instant { tv_sec: 1565, tv_nsec: 598364973 }, next_time: Instant { tv_sec: 1565, tv_nsec: 598364973 }, max_datagram_size: 1350, last_packet_size: None, iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } [2025-09-12T02:40:18.852983435Z TRACE quiche_server] a765fd8c4c22aa86807d2f05b1a971767d9cd78a written 1200 bytes with Some(SendInfo { from: [::]:443, to: [fd00:cafe:cafe::100]:36922, at: Instant { tv_sec: 1565, tv_nsec: 598364973 } }) [2025-09-12T02:40:18.852993273Z TRACE quiche_server] Collecting garbage [2025-09-12T02:40:18.853000467Z TRACE quiche_server] recv() would block [2025-09-12T02:40:18.853006258Z TRACE quiche_server] a765fd8c4c22aa86807d2f05b1a971767d9cd78a done writing [2025-09-12T02:40:18.853009714Z TRACE quiche_server] Collecting garbage [2025-09-12T02:40:18.886053851Z TRACE quiche_server] got 105 bytes from [fd00:cafe:cafe::100]:36922 to [::]:443 [2025-09-12T02:40:18.886069571Z TRACE quiche_server] got packet Initial version=1 dcid=a765fd8c4c22aa86807d2f05b1a971767d9cd78a scid= token= [2025-09-12T02:40:18.886080441Z TRACE quiche] a765fd8c4c22aa86807d2f05b1a971767d9cd78a rx pkt Initial version=1 dcid=a765fd8c4c22aa86807d2f05b1a971767d9cd78a scid= token= len=23 pn=5 [2025-09-12T02:40:18.886088776Z TRACE quiche] a765fd8c4c22aa86807d2f05b1a971767d9cd78a rx frm ACK delay=182 blocks=[0..0] ecn_counts=None [2025-09-12T02:40:18.886094066Z TRACE quiche::recovery::congestion::recovery] a765fd8c4c22aa86807d2f05b1a971767d9cd78a packet newly acked 0 [2025-09-12T02:40:18.886112841Z TRACE quiche] a765fd8c4c22aa86807d2f05b1a971767d9cd78a rx pkt Handshake version=1 dcid=a765fd8c4c22aa86807d2f05b1a971767d9cd78a scid= len=23 pn=0 [2025-09-12T02:40:18.886117109Z TRACE quiche] a765fd8c4c22aa86807d2f05b1a971767d9cd78a rx frm ACK delay=182 blocks=[1..1] ecn_counts=None [2025-09-12T02:40:18.886119935Z TRACE quiche::recovery::congestion::recovery] a765fd8c4c22aa86807d2f05b1a971767d9cd78a packet newly acked 1 [2025-09-12T02:40:18.886128771Z TRACE quiche] a765fd8c4c22aa86807d2f05b1a971767d9cd78a dropped epoch 0 state [2025-09-12T02:40:18.886131676Z TRACE quiche_server] a765fd8c4c22aa86807d2f05b1a971767d9cd78a processed 105 bytes [2025-09-12T02:40:18.886143208Z TRACE quiche_server] recv() would block [2025-09-12T02:40:18.886151163Z TRACE quiche_server] a765fd8c4c22aa86807d2f05b1a971767d9cd78a done writing [2025-09-12T02:40:18.886153988Z TRACE quiche_server] Collecting garbage [2025-09-12T02:40:18.886613636Z TRACE quiche_server] got 163 bytes from [fd00:cafe:cafe::100]:36922 to [::]:443 [2025-09-12T02:40:18.886621722Z TRACE quiche_server] got packet Handshake version=1 dcid=a765fd8c4c22aa86807d2f05b1a971767d9cd78a scid= [2025-09-12T02:40:18.886627392Z TRACE quiche] a765fd8c4c22aa86807d2f05b1a971767d9cd78a rx pkt Handshake version=1 dcid=a765fd8c4c22aa86807d2f05b1a971767d9cd78a scid= len=56 pn=1 [2025-09-12T02:40:18.886633634Z TRACE quiche] a765fd8c4c22aa86807d2f05b1a971767d9cd78a rx frm CRYPTO off=0 len=36 [2025-09-12T02:40:18.886647189Z TRACE quiche::tls] a765fd8c4c22aa86807d2f05b1a971767d9cd78a set read secret lvl=OneRTT [2025-09-12T02:40:18.886683357Z TRACE quiche::tls] a765fd8c4c22aa86807d2f05b1a971767d9cd78a write message lvl=OneRTT len=396 [2025-09-12T02:40:18.886691552Z TRACE quiche] a765fd8c4c22aa86807d2f05b1a971767d9cd78a dropped epoch 1 state [2025-09-12T02:40:18.886695609Z TRACE quiche] a765fd8c4c22aa86807d2f05b1a971767d9cd78a 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: 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(), retry_source_connection_id: None, max_datagram_frame_size: Some(1200), unknown_params: None } [2025-09-12T02:40:18.886716058Z TRACE quiche] a765fd8c4c22aa86807d2f05b1a971767d9cd78a rx pkt Short dcid=a765fd8c4c22aa86807d2f05b1a971767d9cd78a key_phase=false len=57 pn=0 [2025-09-12T02:40:18.886721518Z TRACE quiche] a765fd8c4c22aa86807d2f05b1a971767d9cd78a rx frm STREAM id=0 off=0 len=17 fin=true [2025-09-12T02:40:18.886726988Z TRACE quiche] a765fd8c4c22aa86807d2f05b1a971767d9cd78a rx frm STREAM id=4 off=0 len=17 fin=true [2025-09-12T02:40:18.886733460Z TRACE quiche_server] a765fd8c4c22aa86807d2f05b1a971767d9cd78a processed 163 bytes [2025-09-12T02:40:18.886737708Z DEBUG quiche_apps::common] a765fd8c4c22aa86807d2f05b1a971767d9cd78a response stream 0 is writable with capacity Ok(13500) [2025-09-12T02:40:18.886741425Z DEBUG quiche_apps::common] a765fd8c4c22aa86807d2f05b1a971767d9cd78a response stream 4 is writable with capacity Ok(13500) [2025-09-12T02:40:18.886747406Z TRACE quiche_apps::common] a765fd8c4c22aa86807d2f05b1a971767d9cd78a received 17 bytes [2025-09-12T02:40:18.886750522Z TRACE quiche_apps::common] a765fd8c4c22aa86807d2f05b1a971767d9cd78a stream 0 has 17 bytes (fin? true) [2025-09-12T02:40:18.886755641Z INFO quiche_apps::common] a765fd8c4c22aa86807d2f05b1a971767d9cd78a got GET request for "/www/mpsjxbhabv" on stream 0 [2025-09-12T02:40:18.886780999Z INFO quiche_apps::common] a765fd8c4c22aa86807d2f05b1a971767d9cd78a sending response of size 5120 on stream 0 [2025-09-12T02:40:18.886788964Z TRACE quiche_apps::common] a765fd8c4c22aa86807d2f05b1a971767d9cd78a received 17 bytes [2025-09-12T02:40:18.886791879Z TRACE quiche_apps::common] a765fd8c4c22aa86807d2f05b1a971767d9cd78a stream 4 has 17 bytes (fin? true) [2025-09-12T02:40:18.886795075Z INFO quiche_apps::common] a765fd8c4c22aa86807d2f05b1a971767d9cd78a got GET request for "/www/uqbdbrwjym" on stream 4 [2025-09-12T02:40:18.886810334Z INFO quiche_apps::common] a765fd8c4c22aa86807d2f05b1a971767d9cd78a sending response of size 10240 on stream 4 [2025-09-12T02:40:18.886818128Z TRACE quiche_server] recv() would block [2025-09-12T02:40:18.886832956Z TRACE quiche] a765fd8c4c22aa86807d2f05b1a971767d9cd78a tx pkt Short dcid= key_phase=false len=1332 pn=2 [2025-09-12T02:40:18.886842534Z TRACE quiche] a765fd8c4c22aa86807d2f05b1a971767d9cd78a tx frm ACK delay=13 blocks=[0..0] ecn_counts=None [2025-09-12T02:40:18.886846832Z TRACE quiche] a765fd8c4c22aa86807d2f05b1a971767d9cd78a tx frm NEW_CONNECTION_ID seq_num=1 retire_prior_to=0 conn_id=[0f, ae, 61, 9f, ef, f1, 1a, f2, 24, 7b, b7, 02, 3e, 9a, d8, 22, f7, 89, 47, 7a] reset_token=[4b, 5e, 1d, 88, ae, a5, 55, c5, 8b, e3, ed, 30, 23, b2, 85, f3] [2025-09-12T02:40:18.886855017Z TRACE quiche] a765fd8c4c22aa86807d2f05b1a971767d9cd78a tx frm NEW_CONNECTION_ID seq_num=2 retire_prior_to=0 conn_id=[97, 17, 65, ce, 5d, f3, 9e, 1c, ee, f6, fe, ad, d9, ec, 40, fa, 56, fb, c5, be] reset_token=[a3, e6, 2d, 06, a4, be, d0, c7, d2, ae, d7, 88, d8, 8d, 59, a2] [2025-09-12T02:40:18.886861509Z TRACE quiche] a765fd8c4c22aa86807d2f05b1a971767d9cd78a tx frm NEW_CONNECTION_ID seq_num=3 retire_prior_to=0 conn_id=[44, d1, 4f, 66, 36, fe, a9, 3e, 52, c0, 29, ad, e2, ca, ae, 37, b0, e8, 78, d1] reset_token=[be, a2, d9, 0d, 8b, bd, 10, f5, 92, 9d, f9, f3, 34, b5, fc, 57] [2025-09-12T02:40:18.886867691Z TRACE quiche] a765fd8c4c22aa86807d2f05b1a971767d9cd78a tx frm NEW_CONNECTION_ID seq_num=4 retire_prior_to=0 conn_id=[85, 8e, 23, 80, aa, af, 53, 16, 66, 2f, 5c, ff, a5, 06, 05, 43, 33, 02, e6, e8] reset_token=[b9, 38, 9e, 9e, 28, 99, 35, 80, eb, 6c, 1c, 2c, 02, d4, 07, 41] [2025-09-12T02:40:18.886874073Z TRACE quiche] a765fd8c4c22aa86807d2f05b1a971767d9cd78a tx frm NEW_CONNECTION_ID seq_num=5 retire_prior_to=0 conn_id=[f2, f1, 86, 01, e7, 5f, 0e, 9f, 35, 3a, 5a, 20, f9, 43, e8, 3a, 91, 60, f0, c8] reset_token=[e9, 65, c0, df, e8, b4, 99, 15, 15, 89, cb, e1, 92, 41, 47, 31] [2025-09-12T02:40:18.886880314Z TRACE quiche] a765fd8c4c22aa86807d2f05b1a971767d9cd78a tx frm NEW_CONNECTION_ID seq_num=6 retire_prior_to=0 conn_id=[2c, 2f, 89, ae, dc, e5, ac, 43, f0, ad, ef, d2, 6d, 67, 7e, 7f, 96, 9c, 35, 96] reset_token=[21, 36, d6, 62, 22, f2, 59, 30, e5, b4, 2b, 63, 79, 22, e5, 38] [2025-09-12T02:40:18.886886165Z TRACE quiche] a765fd8c4c22aa86807d2f05b1a971767d9cd78a tx frm NEW_CONNECTION_ID seq_num=7 retire_prior_to=0 conn_id=[da, b3, 32, 0c, 59, 74, b0, f4, 05, a0, 59, 47, 50, 3c, e8, a0, 7b, 4f, 03, 4c] reset_token=[de, 41, 56, cc, bf, 92, 41, 79, 75, 9c, 9f, 51, ef, 70, 0d, 93] [2025-09-12T02:40:18.886892317Z TRACE quiche] a765fd8c4c22aa86807d2f05b1a971767d9cd78a tx frm HANDSHAKE_DONE [2025-09-12T02:40:18.886895102Z TRACE quiche] a765fd8c4c22aa86807d2f05b1a971767d9cd78a tx frm CRYPTO off=0 len=396 [2025-09-12T02:40:18.886898007Z TRACE quiche] a765fd8c4c22aa86807d2f05b1a971767d9cd78a tx frm STREAM id=0 off=0 len=641 fin=false [2025-09-12T02:40:18.886913687Z TRACE quiche::recovery::congestion::recovery] a765fd8c4c22aa86807d2f05b1a971767d9cd78a timer=102.950468ms latest_rtt=33.236537ms srtt=33.206292ms min_rtt=33.201972ms rttvar=12.45938ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=1350 app_limited=true congestion_recovery_start_time=None Rate { delivered: 896, delivered_time: Instant { tv_sec: 1565, tv_nsec: 632310243 }, first_sent_time: Instant { tv_sec: 1565, tv_nsec: 632310243 }, end_of_app_limited: 1, last_sent_packet: 2, largest_acked: 1, rate_sample: RateSample { bandwidth: 215.66 Kbps, is_app_limited: true, interval: 33.236537ms, delivered: 896, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 1565, tv_nsec: 598364973 }), send_elapsed: 0ns, ack_elapsed: 33.236537ms, rtt: 33.236537ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 508186, last_update: Instant { tv_sec: 1565, tv_nsec: 632310243 }, next_time: Instant { tv_sec: 1565, tv_nsec: 632310243 }, max_datagram_size: 1350, last_packet_size: Some(0), iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } [2025-09-12T02:40:18.886935427Z TRACE quiche] a765fd8c4c22aa86807d2f05b1a971767d9cd78a tx pkt Short dcid= key_phase=false len=1332 pn=3 [2025-09-12T02:40:18.886942771Z TRACE quiche] a765fd8c4c22aa86807d2f05b1a971767d9cd78a tx frm STREAM id=4 off=0 len=1327 fin=false [2025-09-12T02:40:18.886949113Z TRACE quiche::recovery::congestion::recovery] a765fd8c4c22aa86807d2f05b1a971767d9cd78a timer=103.02697ms latest_rtt=33.236537ms srtt=33.206292ms min_rtt=33.201972ms rttvar=12.45938ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=2700 app_limited=true congestion_recovery_start_time=None Rate { delivered: 896, delivered_time: Instant { tv_sec: 1565, tv_nsec: 632310243 }, first_sent_time: Instant { tv_sec: 1565, tv_nsec: 632310243 }, end_of_app_limited: 1, last_sent_packet: 3, largest_acked: 1, rate_sample: RateSample { bandwidth: 215.66 Kbps, is_app_limited: true, interval: 33.236537ms, delivered: 896, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 1565, tv_nsec: 598364973 }), send_elapsed: 0ns, ack_elapsed: 33.236537ms, rtt: 33.236537ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 508186, last_update: Instant { tv_sec: 1565, tv_nsec: 632310243 }, next_time: Instant { tv_sec: 1565, tv_nsec: 632310243 }, max_datagram_size: 1350, last_packet_size: Some(0), iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } [2025-09-12T02:40:18.886962879Z TRACE quiche] a765fd8c4c22aa86807d2f05b1a971767d9cd78a tx pkt Short dcid= key_phase=false len=1332 pn=4 [2025-09-12T02:40:18.886965964Z TRACE quiche] a765fd8c4c22aa86807d2f05b1a971767d9cd78a tx frm STREAM id=0 off=641 len=1326 fin=false [2025-09-12T02:40:18.886971344Z TRACE quiche::recovery::congestion::recovery] a765fd8c4c22aa86807d2f05b1a971767d9cd78a timer=103.032962ms latest_rtt=33.236537ms srtt=33.206292ms min_rtt=33.201972ms rttvar=12.45938ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=4050 app_limited=true congestion_recovery_start_time=None Rate { delivered: 896, delivered_time: Instant { tv_sec: 1565, tv_nsec: 632310243 }, first_sent_time: Instant { tv_sec: 1565, tv_nsec: 632310243 }, end_of_app_limited: 1, last_sent_packet: 4, largest_acked: 1, rate_sample: RateSample { bandwidth: 215.66 Kbps, is_app_limited: true, interval: 33.236537ms, delivered: 896, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 1565, tv_nsec: 598364973 }), send_elapsed: 0ns, ack_elapsed: 33.236537ms, rtt: 33.236537ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 508186, last_update: Instant { tv_sec: 1565, tv_nsec: 632310243 }, next_time: Instant { tv_sec: 1565, tv_nsec: 632310243 }, max_datagram_size: 1350, last_packet_size: Some(0), iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } [2025-09-12T02:40:18.886983767Z TRACE quiche] a765fd8c4c22aa86807d2f05b1a971767d9cd78a tx pkt Short dcid= key_phase=false len=1332 pn=5 [2025-09-12T02:40:18.886986803Z TRACE quiche] a765fd8c4c22aa86807d2f05b1a971767d9cd78a tx frm STREAM id=4 off=1327 len=1326 fin=false [2025-09-12T02:40:18.886991943Z TRACE quiche::recovery::congestion::recovery] a765fd8c4c22aa86807d2f05b1a971767d9cd78a timer=103.033953ms latest_rtt=33.236537ms srtt=33.206292ms min_rtt=33.201972ms rttvar=12.45938ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=5400 app_limited=true congestion_recovery_start_time=None Rate { delivered: 896, delivered_time: Instant { tv_sec: 1565, tv_nsec: 632310243 }, first_sent_time: Instant { tv_sec: 1565, tv_nsec: 632310243 }, end_of_app_limited: 1, last_sent_packet: 5, largest_acked: 1, rate_sample: RateSample { bandwidth: 215.66 Kbps, is_app_limited: true, interval: 33.236537ms, delivered: 896, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 1565, tv_nsec: 598364973 }), send_elapsed: 0ns, ack_elapsed: 33.236537ms, rtt: 33.236537ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 508186, last_update: Instant { tv_sec: 1565, tv_nsec: 632310243 }, next_time: Instant { tv_sec: 1565, tv_nsec: 632310243 }, max_datagram_size: 1350, last_packet_size: Some(0), iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } [2025-09-12T02:40:18.887026878Z TRACE quiche] a765fd8c4c22aa86807d2f05b1a971767d9cd78a tx pkt Short dcid= key_phase=false len=1332 pn=6 [2025-09-12T02:40:18.887030294Z TRACE quiche] a765fd8c4c22aa86807d2f05b1a971767d9cd78a tx frm STREAM id=0 off=1967 len=1326 fin=false [2025-09-12T02:40:18.887036626Z TRACE quiche::recovery::congestion::recovery] a765fd8c4c22aa86807d2f05b1a971767d9cd78a timer=103.03177ms latest_rtt=33.236537ms srtt=33.206292ms min_rtt=33.201972ms rttvar=12.45938ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=6750 app_limited=true congestion_recovery_start_time=None Rate { delivered: 896, delivered_time: Instant { tv_sec: 1565, tv_nsec: 632310243 }, first_sent_time: Instant { tv_sec: 1565, tv_nsec: 632310243 }, end_of_app_limited: 1, last_sent_packet: 6, largest_acked: 1, rate_sample: RateSample { bandwidth: 215.66 Kbps, is_app_limited: true, interval: 33.236537ms, delivered: 896, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 1565, tv_nsec: 598364973 }), send_elapsed: 0ns, ack_elapsed: 33.236537ms, rtt: 33.236537ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 508186, last_update: Instant { tv_sec: 1565, tv_nsec: 632310243 }, next_time: Instant { tv_sec: 1565, tv_nsec: 632310243 }, max_datagram_size: 1350, last_packet_size: Some(0), iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } [2025-09-12T02:40:18.887049310Z TRACE quiche] a765fd8c4c22aa86807d2f05b1a971767d9cd78a tx pkt Short dcid= key_phase=false len=1332 pn=7 [2025-09-12T02:40:18.887052335Z TRACE quiche] a765fd8c4c22aa86807d2f05b1a971767d9cd78a tx frm STREAM id=4 off=2653 len=1326 fin=false [2025-09-12T02:40:18.887057555Z TRACE quiche::recovery::congestion::recovery] a765fd8c4c22aa86807d2f05b1a971767d9cd78a timer=103.033643ms latest_rtt=33.236537ms srtt=33.206292ms min_rtt=33.201972ms rttvar=12.45938ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=8100 app_limited=true congestion_recovery_start_time=None Rate { delivered: 896, delivered_time: Instant { tv_sec: 1565, tv_nsec: 632310243 }, first_sent_time: Instant { tv_sec: 1565, tv_nsec: 632310243 }, end_of_app_limited: 1, last_sent_packet: 7, largest_acked: 1, rate_sample: RateSample { bandwidth: 215.66 Kbps, is_app_limited: true, interval: 33.236537ms, delivered: 896, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 1565, tv_nsec: 598364973 }), send_elapsed: 0ns, ack_elapsed: 33.236537ms, rtt: 33.236537ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 508186, last_update: Instant { tv_sec: 1565, tv_nsec: 632310243 }, next_time: Instant { tv_sec: 1565, tv_nsec: 632310243 }, max_datagram_size: 1350, last_packet_size: Some(0), iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } [2025-09-12T02:40:18.887069467Z TRACE quiche] a765fd8c4c22aa86807d2f05b1a971767d9cd78a tx pkt Short dcid= key_phase=false len=1332 pn=8 [2025-09-12T02:40:18.887072543Z TRACE quiche] a765fd8c4c22aa86807d2f05b1a971767d9cd78a tx frm STREAM id=0 off=3293 len=1326 fin=false [2025-09-12T02:40:18.887081189Z TRACE quiche::recovery::congestion::recovery] a765fd8c4c22aa86807d2f05b1a971767d9cd78a timer=103.030277ms latest_rtt=33.236537ms srtt=33.206292ms min_rtt=33.201972ms rttvar=12.45938ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=9450 app_limited=true congestion_recovery_start_time=None Rate { delivered: 896, delivered_time: Instant { tv_sec: 1565, tv_nsec: 632310243 }, first_sent_time: Instant { tv_sec: 1565, tv_nsec: 632310243 }, end_of_app_limited: 1, last_sent_packet: 8, largest_acked: 1, rate_sample: RateSample { bandwidth: 215.66 Kbps, is_app_limited: true, interval: 33.236537ms, delivered: 896, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 1565, tv_nsec: 598364973 }), send_elapsed: 0ns, ack_elapsed: 33.236537ms, rtt: 33.236537ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 508186, last_update: Instant { tv_sec: 1565, tv_nsec: 632310243 }, next_time: Instant { tv_sec: 1565, tv_nsec: 632310243 }, max_datagram_size: 1350, last_packet_size: Some(0), iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } [2025-09-12T02:40:18.887093713Z TRACE quiche] a765fd8c4c22aa86807d2f05b1a971767d9cd78a tx pkt Short dcid= key_phase=false len=1332 pn=9 [2025-09-12T02:40:18.887096758Z TRACE quiche] a765fd8c4c22aa86807d2f05b1a971767d9cd78a tx frm STREAM id=4 off=3979 len=1326 fin=false [2025-09-12T02:40:18.887102099Z TRACE quiche::recovery::congestion::recovery] a765fd8c4c22aa86807d2f05b1a971767d9cd78a timer=103.033172ms latest_rtt=33.236537ms srtt=33.206292ms min_rtt=33.201972ms rttvar=12.45938ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=10800 app_limited=true congestion_recovery_start_time=None Rate { delivered: 896, delivered_time: Instant { tv_sec: 1565, tv_nsec: 632310243 }, first_sent_time: Instant { tv_sec: 1565, tv_nsec: 632310243 }, end_of_app_limited: 1, last_sent_packet: 9, largest_acked: 1, rate_sample: RateSample { bandwidth: 215.66 Kbps, is_app_limited: true, interval: 33.236537ms, delivered: 896, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 1565, tv_nsec: 598364973 }), send_elapsed: 0ns, ack_elapsed: 33.236537ms, rtt: 33.236537ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 508186, last_update: Instant { tv_sec: 1565, tv_nsec: 632310243 }, next_time: Instant { tv_sec: 1565, tv_nsec: 632310243 }, max_datagram_size: 1350, last_packet_size: Some(0), iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } [2025-09-12T02:40:18.887114021Z TRACE quiche] a765fd8c4c22aa86807d2f05b1a971767d9cd78a tx pkt Short dcid= key_phase=false len=507 pn=10 [2025-09-12T02:40:18.887117167Z TRACE quiche] a765fd8c4c22aa86807d2f05b1a971767d9cd78a tx frm STREAM id=0 off=4619 len=501 fin=true [2025-09-12T02:40:18.887122647Z TRACE quiche::recovery::congestion::recovery] a765fd8c4c22aa86807d2f05b1a971767d9cd78a timer=103.033442ms latest_rtt=33.236537ms srtt=33.206292ms min_rtt=33.201972ms rttvar=12.45938ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=11325 app_limited=true congestion_recovery_start_time=None Rate { delivered: 896, delivered_time: Instant { tv_sec: 1565, tv_nsec: 632310243 }, first_sent_time: Instant { tv_sec: 1565, tv_nsec: 632310243 }, end_of_app_limited: 1, last_sent_packet: 10, largest_acked: 1, rate_sample: RateSample { bandwidth: 215.66 Kbps, is_app_limited: true, interval: 33.236537ms, delivered: 896, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 1565, tv_nsec: 598364973 }), send_elapsed: 0ns, ack_elapsed: 33.236537ms, rtt: 33.236537ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 508186, last_update: Instant { tv_sec: 1565, tv_nsec: 632310243 }, next_time: Instant { tv_sec: 1565, tv_nsec: 632310243 }, max_datagram_size: 1350, last_packet_size: Some(0), iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } [2025-09-12T02:40:18.887258571Z TRACE quiche_server] a765fd8c4c22aa86807d2f05b1a971767d9cd78a written 11325 bytes with Some(SendInfo { from: [::]:443, to: [fd00:cafe:cafe::100]:36922, at: Instant { tv_sec: 1565, tv_nsec: 632310243 } }) [2025-09-12T02:40:18.887269401Z TRACE quiche_server] Collecting garbage [2025-09-12T02:40:18.887276454Z TRACE quiche_server] recv() would block [2025-09-12T02:40:18.887287244Z TRACE quiche] a765fd8c4c22aa86807d2f05b1a971767d9cd78a tx pkt Short dcid= key_phase=false len=1332 pn=11 [2025-09-12T02:40:18.887290631Z TRACE quiche] a765fd8c4c22aa86807d2f05b1a971767d9cd78a tx frm STREAM id=4 off=5305 len=1326 fin=false [2025-09-12T02:40:18.887299086Z TRACE quiche::recovery::congestion::recovery] a765fd8c4c22aa86807d2f05b1a971767d9cd78a timer=103.025769ms latest_rtt=33.236537ms srtt=33.206292ms min_rtt=33.201972ms rttvar=12.45938ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=12675 app_limited=true congestion_recovery_start_time=None Rate { delivered: 896, delivered_time: Instant { tv_sec: 1565, tv_nsec: 632310243 }, first_sent_time: Instant { tv_sec: 1565, tv_nsec: 632310243 }, end_of_app_limited: 1, last_sent_packet: 11, largest_acked: 1, rate_sample: RateSample { bandwidth: 215.66 Kbps, is_app_limited: true, interval: 33.236537ms, delivered: 896, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 1565, tv_nsec: 598364973 }), send_elapsed: 0ns, ack_elapsed: 33.236537ms, rtt: 33.236537ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 508186, last_update: Instant { tv_sec: 1565, tv_nsec: 632310243 }, next_time: Instant { tv_sec: 1565, tv_nsec: 632310243 }, max_datagram_size: 1350, last_packet_size: Some(0), iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } [2025-09-12T02:40:18.887313874Z TRACE quiche] a765fd8c4c22aa86807d2f05b1a971767d9cd78a tx pkt Short dcid= key_phase=false len=807 pn=12 [2025-09-12T02:40:18.887316970Z TRACE quiche] a765fd8c4c22aa86807d2f05b1a971767d9cd78a tx frm STREAM id=4 off=6631 len=801 fin=false [2025-09-12T02:40:18.887322179Z TRACE quiche::recovery::congestion::recovery] a765fd8c4c22aa86807d2f05b1a971767d9cd78a timer=103.033383ms latest_rtt=33.236537ms srtt=33.206292ms min_rtt=33.201972ms rttvar=12.45938ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=13500 app_limited=false congestion_recovery_start_time=None Rate { delivered: 896, delivered_time: Instant { tv_sec: 1565, tv_nsec: 632310243 }, first_sent_time: Instant { tv_sec: 1565, tv_nsec: 632310243 }, end_of_app_limited: 1, last_sent_packet: 12, largest_acked: 1, rate_sample: RateSample { bandwidth: 215.66 Kbps, is_app_limited: true, interval: 33.236537ms, delivered: 896, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 1565, tv_nsec: 598364973 }), send_elapsed: 0ns, ack_elapsed: 33.236537ms, rtt: 33.236537ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 508186, last_update: Instant { tv_sec: 1565, tv_nsec: 632310243 }, next_time: Instant { tv_sec: 1565, tv_nsec: 632310243 }, max_datagram_size: 1350, last_packet_size: Some(0), iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } [2025-09-12T02:40:18.887372984Z TRACE quiche_server] a765fd8c4c22aa86807d2f05b1a971767d9cd78a written 2175 bytes with Some(SendInfo { from: [::]:443, to: [fd00:cafe:cafe::100]:36922, at: Instant { tv_sec: 1565, tv_nsec: 632310243 } }) [2025-09-12T02:40:18.887381901Z TRACE quiche_server] Collecting garbage [2025-09-12T02:40:18.887387351Z TRACE quiche_server] recv() would block [2025-09-12T02:40:18.887394184Z TRACE quiche_server] a765fd8c4c22aa86807d2f05b1a971767d9cd78a done writing [2025-09-12T02:40:18.887398191Z TRACE quiche_server] Collecting garbage [2025-09-12T02:40:18.920205687Z TRACE quiche_server] got 1332 bytes from [fd00:cafe:cafe::100]:36922 to [::]:443 [2025-09-12T02:40:18.920218942Z TRACE quiche_server] got packet Short dcid=a765fd8c4c22aa86807d2f05b1a971767d9cd78a key_phase=false [2025-09-12T02:40:18.920226716Z TRACE quiche] a765fd8c4c22aa86807d2f05b1a971767d9cd78a rx pkt Short dcid=a765fd8c4c22aa86807d2f05b1a971767d9cd78a key_phase=false len=1311 pn=1 [2025-09-12T02:40:18.920234892Z TRACE quiche] a765fd8c4c22aa86807d2f05b1a971767d9cd78a rx frm ACK delay=42 blocks=[2..2] ecn_counts=None [2025-09-12T02:40:18.920239620Z TRACE quiche::recovery::congestion::recovery] a765fd8c4c22aa86807d2f05b1a971767d9cd78a packet newly acked 2 [2025-09-12T02:40:18.920245381Z TRACE quiche] a765fd8c4c22aa86807d2f05b1a971767d9cd78a rx frm PING mtu_probe=None [2025-09-12T02:40:18.920253216Z TRACE quiche] a765fd8c4c22aa86807d2f05b1a971767d9cd78a rx frm PADDING len=1288 [2025-09-12T02:40:18.920267172Z TRACE quiche_server] a765fd8c4c22aa86807d2f05b1a971767d9cd78a processed 1332 bytes [2025-09-12T02:40:18.920270969Z DEBUG quiche_apps::common] a765fd8c4c22aa86807d2f05b1a971767d9cd78a response stream 4 is writable with capacity Ok(2700) [2025-09-12T02:40:18.920278874Z TRACE quiche_server] recv() would block [2025-09-12T02:40:18.920287850Z TRACE quiche] a765fd8c4c22aa86807d2f05b1a971767d9cd78a tx pkt Short dcid= key_phase=false len=1332 pn=13 [2025-09-12T02:40:18.920291557Z TRACE quiche] a765fd8c4c22aa86807d2f05b1a971767d9cd78a tx frm ACK delay=7 blocks=[1..1] ecn_counts=None [2025-09-12T02:40:18.920295074Z TRACE quiche] a765fd8c4c22aa86807d2f05b1a971767d9cd78a tx frm STREAM id=4 off=7432 len=1321 fin=false [2025-09-12T02:40:18.920303710Z TRACE quiche::recovery::congestion::recovery] a765fd8c4c22aa86807d2f05b1a971767d9cd78a timer=90.784853ms latest_rtt=33.40427ms srtt=33.231038ms min_rtt=33.201972ms rttvar=9.394029ms cwnd=14850 ssthresh=18446744073709551615 bytes_in_flight=13500 app_limited=true congestion_recovery_start_time=None Rate { delivered: 2246, delivered_time: Instant { tv_sec: 1565, tv_nsec: 665714513 }, first_sent_time: Instant { tv_sec: 1565, tv_nsec: 632310243 }, end_of_app_limited: 0, last_sent_packet: 13, largest_acked: 2, rate_sample: RateSample { bandwidth: 323.30 Kbps, is_app_limited: true, interval: 33.40427ms, delivered: 1350, prior_delivered: 896, prior_time: Some(Instant { tv_sec: 1565, tv_nsec: 632310243 }), send_elapsed: 0ns, ack_elapsed: 33.40427ms, rtt: 33.40427ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 558589, last_update: Instant { tv_sec: 1565, tv_nsec: 665771209 }, next_time: Instant { tv_sec: 1565, tv_nsec: 665771209 }, max_datagram_size: 1350, last_packet_size: Some(0), iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(13) last_round_min_rtt=33.40427ms current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } [2025-09-12T02:40:18.920323086Z TRACE quiche] a765fd8c4c22aa86807d2f05b1a971767d9cd78a tx pkt Short dcid= key_phase=false len=1332 pn=14 [2025-09-12T02:40:18.920326533Z TRACE quiche] a765fd8c4c22aa86807d2f05b1a971767d9cd78a tx frm STREAM id=4 off=8753 len=1326 fin=false [2025-09-12T02:40:18.920332454Z TRACE quiche::recovery::congestion::recovery] a765fd8c4c22aa86807d2f05b1a971767d9cd78a timer=90.794841ms latest_rtt=33.40427ms srtt=33.231038ms min_rtt=33.201972ms rttvar=9.394029ms cwnd=14850 ssthresh=18446744073709551615 bytes_in_flight=14850 app_limited=false congestion_recovery_start_time=None Rate { delivered: 2246, delivered_time: Instant { tv_sec: 1565, tv_nsec: 665714513 }, first_sent_time: Instant { tv_sec: 1565, tv_nsec: 632310243 }, end_of_app_limited: 0, last_sent_packet: 14, largest_acked: 2, rate_sample: RateSample { bandwidth: 323.30 Kbps, is_app_limited: true, interval: 33.40427ms, delivered: 1350, prior_delivered: 896, prior_time: Some(Instant { tv_sec: 1565, tv_nsec: 632310243 }), send_elapsed: 0ns, ack_elapsed: 33.40427ms, rtt: 33.40427ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 558589, last_update: Instant { tv_sec: 1565, tv_nsec: 665771209 }, next_time: Instant { tv_sec: 1565, tv_nsec: 665771209 }, max_datagram_size: 1350, last_packet_size: Some(0), iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(13) last_round_min_rtt=33.40427ms current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } [2025-09-12T02:40:18.920353824Z TRACE quiche_server] a765fd8c4c22aa86807d2f05b1a971767d9cd78a done writing [2025-09-12T02:40:18.920399910Z TRACE quiche_server] a765fd8c4c22aa86807d2f05b1a971767d9cd78a written 2700 bytes with Some(SendInfo { from: [::]:443, to: [fd00:cafe:cafe::100]:36922, at: Instant { tv_sec: 1565, tv_nsec: 665771209 } }) [2025-09-12T02:40:18.920410479Z TRACE quiche_server] Collecting garbage [2025-09-12T02:40:18.920982417Z TRACE quiche_server] got 43 bytes from [fd00:cafe:cafe::100]:36922 to [::]:443 [2025-09-12T02:40:18.920990773Z TRACE quiche_server] got packet Short dcid=a765fd8c4c22aa86807d2f05b1a971767d9cd78a key_phase=false [2025-09-12T02:40:18.920997265Z TRACE quiche] a765fd8c4c22aa86807d2f05b1a971767d9cd78a rx pkt Short dcid=a765fd8c4c22aa86807d2f05b1a971767d9cd78a key_phase=false len=22 pn=2 [2025-09-12T02:40:18.921003627Z TRACE quiche] a765fd8c4c22aa86807d2f05b1a971767d9cd78a rx frm ACK delay=2 blocks=[2..4] ecn_counts=None [2025-09-12T02:40:18.921007885Z TRACE quiche::recovery::congestion::recovery] a765fd8c4c22aa86807d2f05b1a971767d9cd78a packet newly acked 3 [2025-09-12T02:40:18.921010880Z TRACE quiche::recovery::congestion::recovery] a765fd8c4c22aa86807d2f05b1a971767d9cd78a packet newly acked 4 [2025-09-12T02:40:18.921023133Z TRACE quiche_server] a765fd8c4c22aa86807d2f05b1a971767d9cd78a processed 43 bytes [2025-09-12T02:40:18.921027992Z TRACE quiche_server] recv() would block [2025-09-12T02:40:18.921034665Z TRACE quiche] a765fd8c4c22aa86807d2f05b1a971767d9cd78a tx pkt Short dcid= key_phase=false len=167 pn=15 [2025-09-12T02:40:18.921037841Z TRACE quiche] a765fd8c4c22aa86807d2f05b1a971767d9cd78a tx frm STREAM id=4 off=10079 len=161 fin=true [2025-09-12T02:40:18.921045004Z TRACE quiche::recovery::congestion::recovery] a765fd8c4c22aa86807d2f05b1a971767d9cd78a timer=82.44271ms latest_rtt=34.17532ms srtt=33.347073ms min_rtt=33.201972ms rttvar=7.277591ms cwnd=17550 ssthresh=18446744073709551615 bytes_in_flight=12335 app_limited=true congestion_recovery_start_time=None Rate { delivered: 4946, delivered_time: Instant { tv_sec: 1565, tv_nsec: 666485563 }, first_sent_time: Instant { tv_sec: 1565, tv_nsec: 632310243 }, end_of_app_limited: 0, last_sent_packet: 15, largest_acked: 4, rate_sample: RateSample { bandwidth: 948.05 Kbps, is_app_limited: true, interval: 34.17532ms, delivered: 4050, prior_delivered: 896, prior_time: Some(Instant { tv_sec: 1565, tv_nsec: 632310243 }), send_elapsed: 0ns, ack_elapsed: 34.17532ms, rtt: 34.17532ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 657853, last_update: Instant { tv_sec: 1565, tv_nsec: 665771209 }, next_time: Instant { tv_sec: 1565, tv_nsec: 665771209 }, max_datagram_size: 1350, last_packet_size: Some(0), iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(13) last_round_min_rtt=33.40427ms current_round_min_rtt=34.17532ms css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=2 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } [2025-09-12T02:40:18.921081873Z TRACE quiche_server] a765fd8c4c22aa86807d2f05b1a971767d9cd78a written 185 bytes with Some(SendInfo { from: [::]:443, to: [fd00:cafe:cafe::100]:36922, at: Instant { tv_sec: 1565, tv_nsec: 665771209 } }) [2025-09-12T02:40:18.921098704Z TRACE quiche_server] Collecting garbage [2025-09-12T02:40:18.921106389Z TRACE quiche_server] recv() would block [2025-09-12T02:40:18.921112160Z TRACE quiche_server] a765fd8c4c22aa86807d2f05b1a971767d9cd78a done writing [2025-09-12T02:40:18.921116337Z TRACE quiche_server] Collecting garbage [2025-09-12T02:40:18.923167738Z TRACE quiche_server] got 43 bytes from [fd00:cafe:cafe::100]:36922 to [::]:443 [2025-09-12T02:40:18.923174110Z TRACE quiche_server] got packet Short dcid=a765fd8c4c22aa86807d2f05b1a971767d9cd78a key_phase=false [2025-09-12T02:40:18.923178919Z TRACE quiche] a765fd8c4c22aa86807d2f05b1a971767d9cd78a rx pkt Short dcid=a765fd8c4c22aa86807d2f05b1a971767d9cd78a key_phase=false len=22 pn=3 [2025-09-12T02:40:18.923183768Z TRACE quiche] a765fd8c4c22aa86807d2f05b1a971767d9cd78a rx frm ACK delay=2 blocks=[2..6] ecn_counts=None [2025-09-12T02:40:18.923187064Z TRACE quiche::recovery::congestion::recovery] a765fd8c4c22aa86807d2f05b1a971767d9cd78a packet newly acked 5 [2025-09-12T02:40:18.923189408Z TRACE quiche::recovery::congestion::recovery] a765fd8c4c22aa86807d2f05b1a971767d9cd78a packet newly acked 6 [2025-09-12T02:40:18.923198435Z TRACE quiche_server] a765fd8c4c22aa86807d2f05b1a971767d9cd78a processed 43 bytes [2025-09-12T02:40:18.923202202Z TRACE quiche_server] recv() would block [2025-09-12T02:40:18.923204867Z TRACE quiche_server] a765fd8c4c22aa86807d2f05b1a971767d9cd78a done writing [2025-09-12T02:40:18.923207071Z TRACE quiche_server] Collecting garbage [2025-09-12T02:40:18.925454738Z TRACE quiche_server] got 43 bytes from [fd00:cafe:cafe::100]:36922 to [::]:443 [2025-09-12T02:40:18.925460238Z TRACE quiche_server] got packet Short dcid=a765fd8c4c22aa86807d2f05b1a971767d9cd78a key_phase=false [2025-09-12T02:40:18.925464356Z TRACE quiche] a765fd8c4c22aa86807d2f05b1a971767d9cd78a rx pkt Short dcid=a765fd8c4c22aa86807d2f05b1a971767d9cd78a key_phase=false len=22 pn=4 [2025-09-12T02:40:18.925468463Z TRACE quiche] a765fd8c4c22aa86807d2f05b1a971767d9cd78a rx frm ACK delay=5 blocks=[2..8] ecn_counts=None [2025-09-12T02:40:18.925471359Z TRACE quiche::recovery::congestion::recovery] a765fd8c4c22aa86807d2f05b1a971767d9cd78a packet newly acked 7 [2025-09-12T02:40:18.925473653Z TRACE quiche::recovery::congestion::recovery] a765fd8c4c22aa86807d2f05b1a971767d9cd78a packet newly acked 8 [2025-09-12T02:40:18.925481427Z TRACE quiche_server] a765fd8c4c22aa86807d2f05b1a971767d9cd78a processed 43 bytes [2025-09-12T02:40:18.925486497Z TRACE quiche_server] recv() would block [2025-09-12T02:40:18.925489643Z TRACE quiche_server] a765fd8c4c22aa86807d2f05b1a971767d9cd78a done writing [2025-09-12T02:40:18.925492348Z TRACE quiche_server] Collecting garbage [2025-09-12T02:40:18.926985215Z TRACE quiche_server] got 43 bytes from [fd00:cafe:cafe::100]:36922 to [::]:443 [2025-09-12T02:40:18.926990716Z TRACE quiche_server] got packet Short dcid=a765fd8c4c22aa86807d2f05b1a971767d9cd78a key_phase=false [2025-09-12T02:40:18.926994623Z TRACE quiche] a765fd8c4c22aa86807d2f05b1a971767d9cd78a rx pkt Short dcid=a765fd8c4c22aa86807d2f05b1a971767d9cd78a key_phase=false len=22 pn=5 [2025-09-12T02:40:18.926998650Z TRACE quiche] a765fd8c4c22aa86807d2f05b1a971767d9cd78a rx frm ACK delay=2 blocks=[2..10] ecn_counts=None [2025-09-12T02:40:18.927001536Z TRACE quiche::recovery::congestion::recovery] a765fd8c4c22aa86807d2f05b1a971767d9cd78a packet newly acked 9 [2025-09-12T02:40:18.927003780Z TRACE quiche::recovery::congestion::recovery] a765fd8c4c22aa86807d2f05b1a971767d9cd78a packet newly acked 10 [2025-09-12T02:40:18.927012366Z TRACE quiche_server] a765fd8c4c22aa86807d2f05b1a971767d9cd78a processed 43 bytes [2025-09-12T02:40:18.927015843Z TRACE quiche_server] recv() would block [2025-09-12T02:40:18.927018387Z TRACE quiche_server] a765fd8c4c22aa86807d2f05b1a971767d9cd78a done writing [2025-09-12T02:40:18.927020521Z TRACE quiche_server] Collecting garbage [2025-09-12T02:40:18.928795586Z TRACE quiche_server] got 43 bytes from [fd00:cafe:cafe::100]:36922 to [::]:443 [2025-09-12T02:40:18.928802749Z TRACE quiche_server] got packet Short dcid=a765fd8c4c22aa86807d2f05b1a971767d9cd78a key_phase=false [2025-09-12T02:40:18.928807698Z TRACE quiche] a765fd8c4c22aa86807d2f05b1a971767d9cd78a rx pkt Short dcid=a765fd8c4c22aa86807d2f05b1a971767d9cd78a key_phase=false len=22 pn=6 [2025-09-12T02:40:18.928812657Z TRACE quiche] a765fd8c4c22aa86807d2f05b1a971767d9cd78a rx frm ACK delay=2 blocks=[2..12] ecn_counts=None [2025-09-12T02:40:18.928816224Z TRACE quiche::recovery::congestion::recovery] a765fd8c4c22aa86807d2f05b1a971767d9cd78a packet newly acked 11 [2025-09-12T02:40:18.928819049Z TRACE quiche::recovery::congestion::recovery] a765fd8c4c22aa86807d2f05b1a971767d9cd78a packet newly acked 12 [2025-09-12T02:40:18.928828156Z TRACE quiche_server] a765fd8c4c22aa86807d2f05b1a971767d9cd78a processed 43 bytes [2025-09-12T02:40:18.928832444Z TRACE quiche_server] recv() would block [2025-09-12T02:40:18.928835690Z TRACE quiche_server] a765fd8c4c22aa86807d2f05b1a971767d9cd78a done writing [2025-09-12T02:40:18.928838386Z TRACE quiche_server] Collecting garbage [2025-09-12T02:40:18.953055181Z TRACE quiche_server] got 1372 bytes from [fd00:cafe:cafe::100]:36922 to [::]:443 [2025-09-12T02:40:18.953068516Z TRACE quiche_server] got packet Short dcid=a765fd8c4c22aa86807d2f05b1a971767d9cd78a key_phase=false [2025-09-12T02:40:18.953076410Z TRACE quiche] a765fd8c4c22aa86807d2f05b1a971767d9cd78a rx pkt Short dcid=a765fd8c4c22aa86807d2f05b1a971767d9cd78a key_phase=false len=1351 pn=7 [2025-09-12T02:40:18.953085237Z TRACE quiche] a765fd8c4c22aa86807d2f05b1a971767d9cd78a rx frm PING mtu_probe=None [2025-09-12T02:40:18.953092340Z TRACE quiche] a765fd8c4c22aa86807d2f05b1a971767d9cd78a rx frm PADDING len=1333 [2025-09-12T02:40:18.953102098Z TRACE quiche_server] a765fd8c4c22aa86807d2f05b1a971767d9cd78a processed 1372 bytes [2025-09-12T02:40:18.953107939Z TRACE quiche_server] got 43 bytes from [fd00:cafe:cafe::100]:36922 to [::]:443 [2025-09-12T02:40:18.953110975Z TRACE quiche_server] got packet Short dcid=a765fd8c4c22aa86807d2f05b1a971767d9cd78a key_phase=false [2025-09-12T02:40:18.953114562Z TRACE quiche] a765fd8c4c22aa86807d2f05b1a971767d9cd78a rx pkt Short dcid=a765fd8c4c22aa86807d2f05b1a971767d9cd78a key_phase=false len=22 pn=8 [2025-09-12T02:40:18.953118689Z TRACE quiche] a765fd8c4c22aa86807d2f05b1a971767d9cd78a rx frm ACK delay=3 blocks=[2..14] ecn_counts=None [2025-09-12T02:40:18.953123308Z TRACE quiche::recovery::congestion::recovery] a765fd8c4c22aa86807d2f05b1a971767d9cd78a packet newly acked 13 [2025-09-12T02:40:18.953126053Z TRACE quiche::recovery::congestion::recovery] a765fd8c4c22aa86807d2f05b1a971767d9cd78a packet newly acked 14 [2025-09-12T02:40:18.953152342Z TRACE quiche_server] a765fd8c4c22aa86807d2f05b1a971767d9cd78a processed 43 bytes [2025-09-12T02:40:18.953156390Z TRACE quiche_server] recv() would block [2025-09-12T02:40:18.953165206Z TRACE quiche] a765fd8c4c22aa86807d2f05b1a971767d9cd78a tx pkt Short dcid= key_phase=false len=5 pn=16 [2025-09-12T02:40:18.953168172Z TRACE quiche] a765fd8c4c22aa86807d2f05b1a971767d9cd78a tx frm ACK delay=6 blocks=[2..8] ecn_counts=None [2025-09-12T02:40:18.953175405Z TRACE quiche::recovery::congestion::recovery] a765fd8c4c22aa86807d2f05b1a971767d9cd78a timer=44.857602ms latest_rtt=32.832271ms srtt=35.537108ms min_rtt=32.832271ms rttvar=5.366423ms cwnd=17550 ssthresh=18446744073709551615 bytes_in_flight=185 app_limited=true congestion_recovery_start_time=None Rate { delivered: 17096, delivered_time: Instant { tv_sec: 1565, tv_nsec: 698603480 }, first_sent_time: Instant { tv_sec: 1565, tv_nsec: 665771209 }, end_of_app_limited: 15, last_sent_packet: 16, largest_acked: 14, rate_sample: RateSample { bandwidth: 3.55 Mbps, is_app_limited: false, interval: 33.460966ms, delivered: 14850, prior_delivered: 2246, prior_time: Some(Instant { tv_sec: 1565, tv_nsec: 665714513 }), send_elapsed: 33.460966ms, ack_elapsed: 32.888967ms, rtt: 32.832271ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 617312, last_update: Instant { tv_sec: 1565, tv_nsec: 698648154 }, next_time: Instant { tv_sec: 1565, tv_nsec: 698648154 }, max_datagram_size: 1350, last_packet_size: Some(0), iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(13) last_round_min_rtt=33.40427ms current_round_min_rtt=34.17532ms css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=2 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } [2025-09-12T02:40:18.953219337Z TRACE quiche_server] a765fd8c4c22aa86807d2f05b1a971767d9cd78a written 23 bytes with Some(SendInfo { from: [::]:443, to: [fd00:cafe:cafe::100]:36922, at: Instant { tv_sec: 1565, tv_nsec: 698648154 } }) [2025-09-12T02:40:18.953228084Z TRACE quiche_server] Collecting garbage [2025-09-12T02:40:18.953234526Z TRACE quiche_server] recv() would block [2025-09-12T02:40:18.953239205Z TRACE quiche_server] a765fd8c4c22aa86807d2f05b1a971767d9cd78a done writing [2025-09-12T02:40:18.953242912Z TRACE quiche_server] Collecting garbage [2025-09-12T02:40:18.953311800Z TRACE quiche_server] got 54 bytes from [fd00:cafe:cafe::100]:36922 to [::]:443 [2025-09-12T02:40:18.953315918Z TRACE quiche_server] got packet Short dcid=a765fd8c4c22aa86807d2f05b1a971767d9cd78a key_phase=false [2025-09-12T02:40:18.953321047Z TRACE quiche] a765fd8c4c22aa86807d2f05b1a971767d9cd78a rx pkt Short dcid=a765fd8c4c22aa86807d2f05b1a971767d9cd78a key_phase=false len=33 pn=9 [2025-09-12T02:40:18.953326217Z TRACE quiche] a765fd8c4c22aa86807d2f05b1a971767d9cd78a rx frm ACK delay=15 blocks=[2..15] ecn_counts=None [2025-09-12T02:40:18.953329623Z TRACE quiche::recovery::congestion::recovery] a765fd8c4c22aa86807d2f05b1a971767d9cd78a packet newly acked 15 [2025-09-12T02:40:18.953333591Z TRACE quiche] a765fd8c4c22aa86807d2f05b1a971767d9cd78a rx frm APPLICATION_CLOSE err=0 reason=[6b, 74, 68, 78, 62, 79, 65, 21] [2025-09-12T02:40:18.953345503Z TRACE quiche_server] a765fd8c4c22aa86807d2f05b1a971767d9cd78a processed 54 bytes [2025-09-12T02:40:18.953349310Z TRACE quiche_server] recv() would block [2025-09-12T02:40:18.953351594Z TRACE quiche_server] a765fd8c4c22aa86807d2f05b1a971767d9cd78a done writing [2025-09-12T02:40:18.953353728Z TRACE quiche_server] Collecting garbage [2025-09-12T02:40:18.983826475Z TRACE quiche_server] got 55 bytes from [fd00:cafe:cafe::100]:36922 to [::]:443 [2025-09-12T02:40:18.983837696Z TRACE quiche_server] got packet Short dcid=a765fd8c4c22aa86807d2f05b1a971767d9cd78a key_phase=false [2025-09-12T02:40:18.983842866Z TRACE quiche_server] a765fd8c4c22aa86807d2f05b1a971767d9cd78a processed 55 bytes [2025-09-12T02:40:18.983847063Z TRACE quiche_server] recv() would block [2025-09-12T02:40:18.983849588Z TRACE quiche_server] a765fd8c4c22aa86807d2f05b1a971767d9cd78a done writing [2025-09-12T02:40:18.983852003Z TRACE quiche_server] Collecting garbage [2025-09-12T02:40:19.116041217Z TRACE quiche_server] timed out [2025-09-12T02:40:19.116066424Z TRACE quiche] a765fd8c4c22aa86807d2f05b1a971767d9cd78a draining timeout expired [2025-09-12T02:40:19.116108954Z TRACE quiche_server] a765fd8c4c22aa86807d2f05b1a971767d9cd78a done writing [2025-09-12T02:40:19.116112981Z TRACE quiche_server] Collecting garbage [2025-09-12T02:40:19.116119002Z INFO quiche_server] a765fd8c4c22aa86807d2f05b1a971767d9cd78a connection collected recv=15 sent=17 lost=0 retrans=0 sent_bytes=17304 recv_bytes=4913 lost_bytes=0 [local_addr=[::]:443 peer_addr=[fd00:cafe:cafe::100]:36922 validation_state=Validated active=true recv=15 sent=17 lost=0 retrans=0 rtt=35.209742ms min_rtt=Some(32.832271ms) rttvar=4.679547ms cwnd=17550 sent_bytes=17304 recv_bytes=4913 lost_bytes=0 stream_retrans_bytes=0 pmtu=1350 delivery_rate=368638]