[2025-04-30T11:30:38.548606851Z INFO quiche_server] listening on [::]:443 [2025-04-30T11:30:38.548637379Z TRACE mio::poll] registering event source with poller: token=Token(0), interests=READABLE [2025-04-30T11:30:38.548646556Z TRACE quiche_server] GSO detected: false [2025-04-30T11:30:39.350588201Z TRACE quiche_server] got 1207 bytes from [::ffff:193.167.100.2]:40644 to [::]:443 [2025-04-30T11:30:39.350625581Z TRACE quiche_server] got packet Initial version=57414954 dcid= scid= token= [2025-04-30T11:30:39.350633806Z WARN quiche_server] Doing version negotiation [2025-04-30T11:30:39.350723604Z TRACE quiche_server] got 1207 bytes from [::ffff:193.167.100.2]:40644 to [::]:443 [2025-04-30T11:30:39.350729825Z TRACE quiche_server] got packet Initial version=57414954 dcid= scid= token= [2025-04-30T11:30:39.350733612Z WARN quiche_server] Doing version negotiation [2025-04-30T11:30:39.350767656Z TRACE quiche_server] got 1207 bytes from [::ffff:193.167.100.2]:40644 to [::]:443 [2025-04-30T11:30:39.350774929Z TRACE quiche_server] got packet Initial version=57414954 dcid= scid= token= [2025-04-30T11:30:39.350778776Z WARN quiche_server] Doing version negotiation [2025-04-30T11:30:39.350805296Z TRACE quiche_server] recv() would block [2025-04-30T11:30:39.604246312Z TRACE quiche_server] got 1232 bytes from [fd00:cafe:cafe::100]:49441 to [::]:443 [2025-04-30T11:30:39.604279705Z TRACE quiche_server] got packet Initial version=1 dcid=0a0b66044727dbfa scid= token= [2025-04-30T11:30:39.604287990Z DEBUG quiche_server] New connection: dcid=0a0b66044727dbfa scid=91b55275c6c1097e0068093249eb2be3031195e3 [2025-04-30T11:30:39.604554858Z TRACE quiche] 91b55275c6c1097e0068093249eb2be3031195e3 rx pkt Initial version=1 dcid=0a0b66044727dbfa scid= token= len=1214 pn=10941547 [2025-04-30T11:30:39.604572701Z TRACE quiche] 91b55275c6c1097e0068093249eb2be3031195e3 rx frm CRYPTO off=0 len=310 [2025-04-30T11:30:39.604601695Z TRACE quiche::tls] checking peer ALPN Ok("hq-interop") against Ok("h3") [2025-04-30T11:30:39.604605692Z TRACE quiche::tls] checking peer ALPN Ok("hq-interop") against Ok("hq-interop") [2025-04-30T11:30:39.604688166Z TRACE quiche::tls] 91b55275c6c1097e0068093249eb2be3031195e3 write message lvl=Initial len=90 [2025-04-30T11:30:39.604718703Z TRACE quiche::tls] 91b55275c6c1097e0068093249eb2be3031195e3 set write secret lvl=Handshake [2025-04-30T11:30:39.604784726Z TRACE quiche::tls] 91b55275c6c1097e0068093249eb2be3031195e3 write message lvl=Handshake len=698 [2025-04-30T11:30:39.604787642Z TRACE quiche::tls] 91b55275c6c1097e0068093249eb2be3031195e3 set write secret lvl=OneRTT [2025-04-30T11:30:39.604793834Z TRACE quiche::tls] 91b55275c6c1097e0068093249eb2be3031195e3 set read secret lvl=Handshake [2025-04-30T11:30:39.604812418Z TRACE quiche] 91b55275c6c1097e0068093249eb2be3031195e3 rx frm PADDING len=880 [2025-04-30T11:30:39.604828949Z TRACE quiche_server] 91b55275c6c1097e0068093249eb2be3031195e3 processed 1232 bytes [2025-04-30T11:30:39.604842194Z TRACE quiche_server] recv() would block [2025-04-30T11:30:39.604854407Z TRACE quiche] 91b55275c6c1097e0068093249eb2be3031195e3 tx pkt Initial version=1 dcid= scid=91b55275c6c1097e0068093249eb2be3031195e3 len=102 pn=0 [2025-04-30T11:30:39.604857863Z TRACE quiche] 91b55275c6c1097e0068093249eb2be3031195e3 tx frm ACK delay=39 blocks=[10941547..10941547] ecn_counts=None [2025-04-30T11:30:39.604862471Z TRACE quiche] 91b55275c6c1097e0068093249eb2be3031195e3 tx frm CRYPTO off=0 len=90 [2025-04-30T11:30:39.604871568Z TRACE quiche::recovery::congestion::recovery] 91b55275c6c1097e0068093249eb2be3031195e3 timer=998.972158ms latest_rtt=0ns srtt=333ms min_rtt=333ms rttvar=166.5ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=149 app_limited=true congestion_recovery_start_time=None Rate { delivered: 0, delivered_time: Instant { tv_sec: 566, tv_nsec: 780483877 }, first_sent_time: Instant { tv_sec: 566, tv_nsec: 780483877 }, 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: 566, tv_nsec: 780483877 }, next_time: Instant { tv_sec: 566, tv_nsec: 780483877 }, 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-30T11:30:39.604899972Z TRACE quiche] 91b55275c6c1097e0068093249eb2be3031195e3 tx pkt Handshake version=1 dcid= scid=91b55275c6c1097e0068093249eb2be3031195e3 len=702 pn=1 [2025-04-30T11:30:39.604902957Z TRACE quiche] 91b55275c6c1097e0068093249eb2be3031195e3 tx frm CRYPTO off=0 len=698 [2025-04-30T11:30:39.604908507Z TRACE quiche::recovery::congestion::recovery] 91b55275c6c1097e0068093249eb2be3031195e3 timer=998.93578ms latest_rtt=0ns srtt=333ms min_rtt=333ms rttvar=166.5ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=897 app_limited=true congestion_recovery_start_time=None Rate { delivered: 0, delivered_time: Instant { tv_sec: 566, tv_nsec: 780483877 }, first_sent_time: Instant { tv_sec: 566, tv_nsec: 780483877 }, 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: 566, tv_nsec: 780483877 }, next_time: Instant { tv_sec: 566, tv_nsec: 780483877 }, 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-30T11:30:39.604957880Z TRACE quiche_server] 91b55275c6c1097e0068093249eb2be3031195e3 written 1200 bytes with Some(SendInfo { from: [::]:443, to: [fd00:cafe:cafe::100]:49441, at: Instant { tv_sec: 566, tv_nsec: 780483877 } }) [2025-04-30T11:30:39.604964041Z TRACE quiche_server] Collecting garbage [2025-04-30T11:30:39.604970283Z TRACE quiche_server] recv() would block [2025-04-30T11:30:39.604976134Z TRACE quiche_server] 91b55275c6c1097e0068093249eb2be3031195e3 done writing [2025-04-30T11:30:39.604979780Z TRACE quiche_server] Collecting garbage [2025-04-30T11:30:39.638034978Z TRACE quiche_server] got 94 bytes from [fd00:cafe:cafe::100]:49441 to [::]:443 [2025-04-30T11:30:39.638064974Z TRACE quiche_server] got packet Handshake version=1 dcid=91b55275c6c1097e0068093249eb2be3031195e3 scid= [2025-04-30T11:30:39.638080062Z TRACE quiche] 91b55275c6c1097e0068093249eb2be3031195e3 rx pkt Handshake version=1 dcid=91b55275c6c1097e0068093249eb2be3031195e3 scid= len=65 pn=10941547 [2025-04-30T11:30:39.638093357Z TRACE quiche] 91b55275c6c1097e0068093249eb2be3031195e3 rx frm CRYPTO off=0 len=36 [2025-04-30T11:30:39.638115478Z TRACE quiche::tls] 91b55275c6c1097e0068093249eb2be3031195e3 set read secret lvl=OneRTT [2025-04-30T11:30:39.638155593Z TRACE quiche::tls] 91b55275c6c1097e0068093249eb2be3031195e3 write message lvl=OneRTT len=396 [2025-04-30T11:30:39.638167826Z TRACE quiche] 91b55275c6c1097e0068093249eb2be3031195e3 dropped epoch 1 state [2025-04-30T11:30:39.638172905Z TRACE quiche] 91b55275c6c1097e0068093249eb2be3031195e3 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: 60000, stateless_reset_token: None, max_udp_payload_size: 1500, initial_max_data: 2621440, initial_max_stream_data_bidi_local: 262144, initial_max_stream_data_bidi_remote: 262144, initial_max_stream_data_uni: 262144, initial_max_streams_bidi: 100, initial_max_streams_uni: 100, ack_delay_exponent: 3, max_ack_delay: 25, disable_active_migration: false, active_conn_id_limit: 5, initial_source_connection_id: Some(), retry_source_connection_id: None, max_datagram_frame_size: Some(65535), unknown_params: None } [2025-04-30T11:30:39.638199114Z TRACE quiche] 91b55275c6c1097e0068093249eb2be3031195e3 rx frm ACK delay=177 blocks=[1..1] ecn_counts=None [2025-04-30T11:30:39.638231234Z TRACE quiche] 91b55275c6c1097e0068093249eb2be3031195e3 dropped epoch 0 state [2025-04-30T11:30:39.638234881Z TRACE quiche_server] 91b55275c6c1097e0068093249eb2be3031195e3 processed 94 bytes [2025-04-30T11:30:39.638244669Z TRACE quiche_server] got 112 bytes from [fd00:cafe:cafe::100]:49441 to [::]:443 [2025-04-30T11:30:39.638248787Z TRACE quiche_server] got packet Short dcid=91b55275c6c1097e0068093249eb2be3031195e3 key_phase=false [2025-04-30T11:30:39.638255129Z TRACE quiche] 91b55275c6c1097e0068093249eb2be3031195e3 rx pkt Short dcid=91b55275c6c1097e0068093249eb2be3031195e3 key_phase=false len=91 pn=10941547 [2025-04-30T11:30:39.638261471Z TRACE quiche] 91b55275c6c1097e0068093249eb2be3031195e3 rx frm STREAM id=0 off=0 len=17 fin=true [2025-04-30T11:30:39.638266931Z TRACE quiche] 91b55275c6c1097e0068093249eb2be3031195e3 rx frm STREAM id=4 off=0 len=17 fin=true [2025-04-30T11:30:39.638270868Z TRACE quiche] 91b55275c6c1097e0068093249eb2be3031195e3 rx frm PADDING len=31 [2025-04-30T11:30:39.638278663Z TRACE quiche_server] 91b55275c6c1097e0068093249eb2be3031195e3 processed 112 bytes [2025-04-30T11:30:39.638281898Z DEBUG quiche_apps::common] 91b55275c6c1097e0068093249eb2be3031195e3 response stream 0 is writable with capacity Ok(13500) [2025-04-30T11:30:39.638285966Z DEBUG quiche_apps::common] 91b55275c6c1097e0068093249eb2be3031195e3 response stream 4 is writable with capacity Ok(13500) [2025-04-30T11:30:39.638292538Z TRACE quiche_apps::common] 91b55275c6c1097e0068093249eb2be3031195e3 received 17 bytes [2025-04-30T11:30:39.638295534Z TRACE quiche_apps::common] 91b55275c6c1097e0068093249eb2be3031195e3 stream 0 has 17 bytes (fin? true) [2025-04-30T11:30:39.638300633Z INFO quiche_apps::common] 91b55275c6c1097e0068093249eb2be3031195e3 got GET request for "/www/omuhsmgiub" on stream 0 [2025-04-30T11:30:39.638334817Z INFO quiche_apps::common] 91b55275c6c1097e0068093249eb2be3031195e3 sending response of size 5120 on stream 0 [2025-04-30T11:30:39.638343353Z TRACE quiche_apps::common] 91b55275c6c1097e0068093249eb2be3031195e3 received 17 bytes [2025-04-30T11:30:39.638346299Z TRACE quiche_apps::common] 91b55275c6c1097e0068093249eb2be3031195e3 stream 4 has 17 bytes (fin? true) [2025-04-30T11:30:39.638349565Z INFO quiche_apps::common] 91b55275c6c1097e0068093249eb2be3031195e3 got GET request for "/www/ljwphgqzpz" on stream 4 [2025-04-30T11:30:39.638388377Z INFO quiche_apps::common] 91b55275c6c1097e0068093249eb2be3031195e3 sending response of size 10240 on stream 4 [2025-04-30T11:30:39.638402163Z TRACE quiche_server] recv() would block [2025-04-30T11:30:39.638411671Z TRACE quiche] 91b55275c6c1097e0068093249eb2be3031195e3 pmtud probe status false hs_con=true hs_sent=false cwnd_avail=13500 out_len=1350 left=1324 [2025-04-30T11:30:39.638421860Z TRACE quiche] 91b55275c6c1097e0068093249eb2be3031195e3 tx pkt Short dcid= key_phase=false len=1332 pn=2 [2025-04-30T11:30:39.638425386Z TRACE quiche] 91b55275c6c1097e0068093249eb2be3031195e3 tx frm ACK delay=19 blocks=[10941547..10941547] ecn_counts=None [2025-04-30T11:30:39.638429574Z TRACE quiche] 91b55275c6c1097e0068093249eb2be3031195e3 tx frm NEW_CONNECTION_ID seq_num=1 retire_prior_to=0 conn_id=[54, a6, f0, 88, 5a, ce, b7, 6b, 32, 94, 6b, b3, d3, bb, 33, 63, 7d, 60, b2, b3] reset_token=[ee, c3, fa, 00, 46, 72, 23, 0c, c5, 37, 41, aa, a0, 3c, bd, 70] [2025-04-30T11:30:39.638439102Z TRACE quiche] 91b55275c6c1097e0068093249eb2be3031195e3 tx frm NEW_CONNECTION_ID seq_num=2 retire_prior_to=0 conn_id=[78, c4, df, b0, 17, 90, f1, a4, 39, 4f, a4, 42, 72, cd, 55, 53, b4, 05, 18, 98] reset_token=[fb, a9, 9f, 9d, a7, 09, 2d, b4, ed, 54, da, 7e, bb, 34, ff, b6] [2025-04-30T11:30:39.638446505Z TRACE quiche] 91b55275c6c1097e0068093249eb2be3031195e3 tx frm NEW_CONNECTION_ID seq_num=3 retire_prior_to=0 conn_id=[7f, c1, 9e, 5c, 37, f4, 30, e0, 5c, de, d0, b8, 41, 54, f9, 82, a3, 29, 9d, 50] reset_token=[dc, 22, 37, e6, d0, 4a, 0e, 79, bf, 1b, 13, 4d, 5d, 61, ca, 53] [2025-04-30T11:30:39.638459309Z TRACE quiche] 91b55275c6c1097e0068093249eb2be3031195e3 tx frm NEW_CONNECTION_ID seq_num=4 retire_prior_to=0 conn_id=[ad, 60, b5, dd, 94, a4, cb, a6, 26, 59, 18, 64, eb, 2f, 90, 4f, 27, 1c, d1, b5] reset_token=[40, 6a, 63, b7, 45, a4, 7e, bc, 20, a3, 41, 48, 24, 97, c9, ab] [2025-04-30T11:30:39.638466673Z TRACE quiche] 91b55275c6c1097e0068093249eb2be3031195e3 tx frm HANDSHAKE_DONE [2025-04-30T11:30:39.638469709Z TRACE quiche] 91b55275c6c1097e0068093249eb2be3031195e3 tx frm CRYPTO off=0 len=396 [2025-04-30T11:30:39.638472845Z TRACE quiche] 91b55275c6c1097e0068093249eb2be3031195e3 tx frm STREAM id=0 off=0 len=758 fin=false [2025-04-30T11:30:39.638488234Z TRACE quiche::recovery::congestion::recovery] 91b55275c6c1097e0068093249eb2be3031195e3 timer=1.023916294s latest_rtt=0ns srtt=333ms min_rtt=333ms rttvar=166.5ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=1350 app_limited=true congestion_recovery_start_time=None Rate { delivered: 0, delivered_time: Instant { tv_sec: 566, tv_nsec: 814044628 }, first_sent_time: Instant { tv_sec: 566, tv_nsec: 814044628 }, end_of_app_limited: 1, last_sent_packet: 2, 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: 566, tv_nsec: 814044628 }, next_time: Instant { tv_sec: 566, tv_nsec: 814044628 }, 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-30T11:30:39.638509283Z TRACE quiche] 91b55275c6c1097e0068093249eb2be3031195e3 pmtud probe status false hs_con=true hs_sent=true cwnd_avail=12150 out_len=1350 left=1332 [2025-04-30T11:30:39.638513931Z TRACE quiche] 91b55275c6c1097e0068093249eb2be3031195e3 tx pkt Short dcid= key_phase=false len=1332 pn=3 [2025-04-30T11:30:39.638517047Z TRACE quiche] 91b55275c6c1097e0068093249eb2be3031195e3 tx frm STREAM id=4 off=0 len=1327 fin=false [2025-04-30T11:30:39.638523068Z TRACE quiche::recovery::congestion::recovery] 91b55275c6c1097e0068093249eb2be3031195e3 timer=1.023984141s latest_rtt=0ns srtt=333ms min_rtt=333ms rttvar=166.5ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=2700 app_limited=true congestion_recovery_start_time=None Rate { delivered: 0, delivered_time: Instant { tv_sec: 566, tv_nsec: 814044628 }, first_sent_time: Instant { tv_sec: 566, tv_nsec: 814044628 }, end_of_app_limited: 1, last_sent_packet: 3, 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: 566, tv_nsec: 814146869 }, next_time: Instant { tv_sec: 566, tv_nsec: 814146869 }, 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-30T11:30:39.638536113Z TRACE quiche] 91b55275c6c1097e0068093249eb2be3031195e3 pmtud probe status false hs_con=true hs_sent=true cwnd_avail=10800 out_len=1350 left=1332 [2025-04-30T11:30:39.638540160Z TRACE quiche] 91b55275c6c1097e0068093249eb2be3031195e3 tx pkt Short dcid= key_phase=false len=1332 pn=4 [2025-04-30T11:30:39.638547374Z TRACE quiche] 91b55275c6c1097e0068093249eb2be3031195e3 tx frm STREAM id=0 off=758 len=1326 fin=false [2025-04-30T11:30:39.638552934Z TRACE quiche::recovery::congestion::recovery] 91b55275c6c1097e0068093249eb2be3031195e3 timer=1.023981606s latest_rtt=0ns srtt=333ms min_rtt=333ms rttvar=166.5ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=4050 app_limited=true congestion_recovery_start_time=None Rate { delivered: 0, delivered_time: Instant { tv_sec: 566, tv_nsec: 814044628 }, first_sent_time: Instant { tv_sec: 566, tv_nsec: 814044628 }, end_of_app_limited: 1, last_sent_packet: 4, 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: 566, tv_nsec: 814174290 }, next_time: Instant { tv_sec: 566, tv_nsec: 814174290 }, 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-30T11:30:39.638566149Z TRACE quiche] 91b55275c6c1097e0068093249eb2be3031195e3 pmtud probe status false hs_con=true hs_sent=true cwnd_avail=9450 out_len=1350 left=1332 [2025-04-30T11:30:39.638570156Z TRACE quiche] 91b55275c6c1097e0068093249eb2be3031195e3 tx pkt Short dcid= key_phase=false len=1332 pn=5 [2025-04-30T11:30:39.638573212Z TRACE quiche] 91b55275c6c1097e0068093249eb2be3031195e3 tx frm STREAM id=4 off=1327 len=1326 fin=false [2025-04-30T11:30:39.638578572Z TRACE quiche::recovery::congestion::recovery] 91b55275c6c1097e0068093249eb2be3031195e3 timer=1.023986264s latest_rtt=0ns srtt=333ms min_rtt=333ms rttvar=166.5ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=5400 app_limited=true congestion_recovery_start_time=None Rate { delivered: 0, delivered_time: Instant { tv_sec: 566, tv_nsec: 814044628 }, first_sent_time: Instant { tv_sec: 566, tv_nsec: 814044628 }, end_of_app_limited: 1, last_sent_packet: 5, 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: 566, tv_nsec: 814204466 }, next_time: Instant { tv_sec: 566, tv_nsec: 814204466 }, 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-30T11:30:39.638590785Z TRACE quiche] 91b55275c6c1097e0068093249eb2be3031195e3 pmtud probe status false hs_con=true hs_sent=true cwnd_avail=8100 out_len=1350 left=1332 [2025-04-30T11:30:39.638594542Z TRACE quiche] 91b55275c6c1097e0068093249eb2be3031195e3 tx pkt Short dcid= key_phase=false len=1332 pn=6 [2025-04-30T11:30:39.638597477Z TRACE quiche] 91b55275c6c1097e0068093249eb2be3031195e3 tx frm STREAM id=0 off=2084 len=1326 fin=false [2025-04-30T11:30:39.638603328Z TRACE quiche::recovery::congestion::recovery] 91b55275c6c1097e0068093249eb2be3031195e3 timer=1.023986224s latest_rtt=0ns srtt=333ms min_rtt=333ms rttvar=166.5ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=6750 app_limited=true congestion_recovery_start_time=None Rate { delivered: 0, delivered_time: Instant { tv_sec: 566, tv_nsec: 814044628 }, first_sent_time: Instant { tv_sec: 566, tv_nsec: 814044628 }, end_of_app_limited: 1, last_sent_packet: 6, 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: 566, tv_nsec: 814229172 }, next_time: Instant { tv_sec: 566, tv_nsec: 814229172 }, 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-30T11:30:39.638618837Z TRACE quiche] 91b55275c6c1097e0068093249eb2be3031195e3 pmtud probe status false hs_con=true hs_sent=true cwnd_avail=6750 out_len=1350 left=1332 [2025-04-30T11:30:39.638622694Z TRACE quiche] 91b55275c6c1097e0068093249eb2be3031195e3 tx pkt Short dcid= key_phase=false len=1332 pn=7 [2025-04-30T11:30:39.638625640Z TRACE quiche] 91b55275c6c1097e0068093249eb2be3031195e3 tx frm STREAM id=4 off=2653 len=1326 fin=false [2025-04-30T11:30:39.638631220Z TRACE quiche::recovery::congestion::recovery] 91b55275c6c1097e0068093249eb2be3031195e3 timer=1.023986234s latest_rtt=0ns srtt=333ms min_rtt=333ms rttvar=166.5ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=8100 app_limited=true congestion_recovery_start_time=None Rate { delivered: 0, delivered_time: Instant { tv_sec: 566, tv_nsec: 814044628 }, first_sent_time: Instant { tv_sec: 566, tv_nsec: 814044628 }, end_of_app_limited: 1, last_sent_packet: 7, 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: 566, tv_nsec: 814257084 }, next_time: Instant { tv_sec: 566, tv_nsec: 814257084 }, 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-30T11:30:39.638642932Z TRACE quiche] 91b55275c6c1097e0068093249eb2be3031195e3 pmtud probe status false hs_con=true hs_sent=true cwnd_avail=5400 out_len=1350 left=1332 [2025-04-30T11:30:39.638646649Z TRACE quiche] 91b55275c6c1097e0068093249eb2be3031195e3 tx pkt Short dcid= key_phase=false len=1332 pn=8 [2025-04-30T11:30:39.638649574Z TRACE quiche] 91b55275c6c1097e0068093249eb2be3031195e3 tx frm STREAM id=0 off=3410 len=1326 fin=false [2025-04-30T11:30:39.638654744Z TRACE quiche::recovery::congestion::recovery] 91b55275c6c1097e0068093249eb2be3031195e3 timer=1.023987116s latest_rtt=0ns srtt=333ms min_rtt=333ms rttvar=166.5ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=9450 app_limited=true congestion_recovery_start_time=None Rate { delivered: 0, delivered_time: Instant { tv_sec: 566, tv_nsec: 814044628 }, first_sent_time: Instant { tv_sec: 566, tv_nsec: 814044628 }, end_of_app_limited: 1, last_sent_packet: 8, 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: 566, tv_nsec: 814281460 }, next_time: Instant { tv_sec: 566, tv_nsec: 814281460 }, 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-30T11:30:39.638667788Z TRACE quiche] 91b55275c6c1097e0068093249eb2be3031195e3 pmtud probe status false hs_con=true hs_sent=true cwnd_avail=4050 out_len=1350 left=1332 [2025-04-30T11:30:39.638674591Z TRACE quiche] 91b55275c6c1097e0068093249eb2be3031195e3 tx pkt Short dcid= key_phase=false len=1332 pn=9 [2025-04-30T11:30:39.638677567Z TRACE quiche] 91b55275c6c1097e0068093249eb2be3031195e3 tx frm STREAM id=4 off=3979 len=1326 fin=false [2025-04-30T11:30:39.638682736Z TRACE quiche::recovery::congestion::recovery] 91b55275c6c1097e0068093249eb2be3031195e3 timer=1.023984s latest_rtt=0ns srtt=333ms min_rtt=333ms rttvar=166.5ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=10800 app_limited=true congestion_recovery_start_time=None Rate { delivered: 0, delivered_time: Instant { tv_sec: 566, tv_nsec: 814044628 }, first_sent_time: Instant { tv_sec: 566, tv_nsec: 814044628 }, end_of_app_limited: 1, last_sent_packet: 9, 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: 566, tv_nsec: 814306316 }, next_time: Instant { tv_sec: 566, tv_nsec: 814306316 }, 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-30T11:30:39.638693226Z TRACE quiche] 91b55275c6c1097e0068093249eb2be3031195e3 pmtud probe status false hs_con=true hs_sent=true cwnd_avail=2700 out_len=1350 left=1332 [2025-04-30T11:30:39.638696081Z TRACE quiche] 91b55275c6c1097e0068093249eb2be3031195e3 tx pkt Short dcid= key_phase=false len=390 pn=10 [2025-04-30T11:30:39.638698455Z TRACE quiche] 91b55275c6c1097e0068093249eb2be3031195e3 tx frm STREAM id=0 off=4736 len=384 fin=true [2025-04-30T11:30:39.638724163Z TRACE quiche::recovery::congestion::recovery] 91b55275c6c1097e0068093249eb2be3031195e3 timer=1.023967981s latest_rtt=0ns srtt=333ms min_rtt=333ms rttvar=166.5ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=11208 app_limited=true congestion_recovery_start_time=None Rate { delivered: 0, delivered_time: Instant { tv_sec: 566, tv_nsec: 814044628 }, first_sent_time: Instant { tv_sec: 566, tv_nsec: 814044628 }, end_of_app_limited: 1, last_sent_packet: 10, 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: 566, tv_nsec: 814331844 }, next_time: Instant { tv_sec: 566, tv_nsec: 814331844 }, 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-30T11:30:39.638820784Z TRACE quiche_server] 91b55275c6c1097e0068093249eb2be3031195e3 written 11208 bytes with Some(SendInfo { from: [::]:443, to: [fd00:cafe:cafe::100]:49441, at: Instant { tv_sec: 566, tv_nsec: 814044628 } }) [2025-04-30T11:30:39.638826775Z TRACE quiche_server] Collecting garbage [2025-04-30T11:30:39.638832305Z TRACE quiche_server] recv() would block [2025-04-30T11:30:39.638836373Z TRACE quiche] 91b55275c6c1097e0068093249eb2be3031195e3 pmtud probe status false hs_con=true hs_sent=true cwnd_avail=2292 out_len=1350 left=1332 [2025-04-30T11:30:39.638839970Z TRACE quiche] 91b55275c6c1097e0068093249eb2be3031195e3 tx pkt Short dcid= key_phase=false len=1332 pn=11 [2025-04-30T11:30:39.638842384Z TRACE quiche] 91b55275c6c1097e0068093249eb2be3031195e3 tx frm STREAM id=4 off=5305 len=1326 fin=false [2025-04-30T11:30:39.638849076Z TRACE quiche::recovery::congestion::recovery] 91b55275c6c1097e0068093249eb2be3031195e3 timer=1.023985143s latest_rtt=0ns srtt=333ms min_rtt=333ms rttvar=166.5ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=12558 app_limited=true congestion_recovery_start_time=None Rate { delivered: 0, delivered_time: Instant { tv_sec: 566, tv_nsec: 814044628 }, first_sent_time: Instant { tv_sec: 566, tv_nsec: 814044628 }, end_of_app_limited: 1, last_sent_packet: 11, 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: 566, tv_nsec: 814473739 }, next_time: Instant { tv_sec: 566, tv_nsec: 814473739 }, 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-30T11:30:39.638863874Z TRACE quiche] 91b55275c6c1097e0068093249eb2be3031195e3 pmtud probe status false hs_con=true hs_sent=true cwnd_avail=942 out_len=1350 left=924 [2025-04-30T11:30:39.638867060Z TRACE quiche] 91b55275c6c1097e0068093249eb2be3031195e3 tx pkt Short dcid= key_phase=false len=924 pn=12 [2025-04-30T11:30:39.638869414Z TRACE quiche] 91b55275c6c1097e0068093249eb2be3031195e3 tx frm STREAM id=4 off=6631 len=918 fin=false [2025-04-30T11:30:39.638874274Z TRACE quiche::recovery::congestion::recovery] 91b55275c6c1097e0068093249eb2be3031195e3 timer=1.023988519s latest_rtt=0ns srtt=333ms min_rtt=333ms rttvar=166.5ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=13500 app_limited=false congestion_recovery_start_time=None Rate { delivered: 0, delivered_time: Instant { tv_sec: 566, tv_nsec: 814044628 }, first_sent_time: Instant { tv_sec: 566, tv_nsec: 814044628 }, end_of_app_limited: 1, last_sent_packet: 12, 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: 566, tv_nsec: 814502282 }, next_time: Instant { tv_sec: 566, tv_nsec: 814502282 }, 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-30T11:30:39.638903969Z TRACE quiche_server] 91b55275c6c1097e0068093249eb2be3031195e3 written 2292 bytes with Some(SendInfo { from: [::]:443, to: [fd00:cafe:cafe::100]:49441, at: Instant { tv_sec: 566, tv_nsec: 814473739 } }) [2025-04-30T11:30:39.638908327Z TRACE quiche_server] Collecting garbage [2025-04-30T11:30:39.638912014Z TRACE quiche_server] recv() would block [2025-04-30T11:30:39.638915380Z TRACE quiche] 91b55275c6c1097e0068093249eb2be3031195e3 pmtud probe status false hs_con=true hs_sent=true cwnd_avail=0 out_len=1350 left=0 [2025-04-30T11:30:39.638918546Z TRACE quiche_server] 91b55275c6c1097e0068093249eb2be3031195e3 done writing [2025-04-30T11:30:39.638920830Z TRACE quiche_server] Collecting garbage [2025-04-30T11:30:39.670531089Z TRACE quiche_server] got 48 bytes from [fd00:cafe:cafe::100]:49441 to [::]:443 [2025-04-30T11:30:39.670555404Z TRACE quiche_server] got packet Short dcid=91b55275c6c1097e0068093249eb2be3031195e3 key_phase=false [2025-04-30T11:30:39.670570522Z TRACE quiche] 91b55275c6c1097e0068093249eb2be3031195e3 rx pkt Short dcid=91b55275c6c1097e0068093249eb2be3031195e3 key_phase=false len=27 pn=10941548 [2025-04-30T11:30:39.670584789Z TRACE quiche] 91b55275c6c1097e0068093249eb2be3031195e3 rx frm ACK delay=17 blocks=[2..2] ecn_counts=None [2025-04-30T11:30:39.670603895Z TRACE quiche::recovery::congestion::recovery] 91b55275c6c1097e0068093249eb2be3031195e3 packet newly acked 2 [2025-04-30T11:30:39.670613302Z TRACE quiche] 91b55275c6c1097e0068093249eb2be3031195e3 rx frm PADDING len=5 [2025-04-30T11:30:39.670643077Z TRACE quiche_server] 91b55275c6c1097e0068093249eb2be3031195e3 processed 48 bytes [2025-04-30T11:30:39.670649489Z DEBUG quiche_apps::common] 91b55275c6c1097e0068093249eb2be3031195e3 response stream 4 is writable with capacity Ok(2700) [2025-04-30T11:30:39.670666621Z TRACE quiche_server] recv() would block [2025-04-30T11:30:39.670677532Z TRACE quiche] 91b55275c6c1097e0068093249eb2be3031195e3 pmtud probe status false hs_con=true hs_sent=true cwnd_avail=2700 out_len=1350 left=1332 [2025-04-30T11:30:39.670689063Z TRACE quiche] 91b55275c6c1097e0068093249eb2be3031195e3 tx pkt Short dcid= key_phase=false len=1332 pn=13 [2025-04-30T11:30:39.670693852Z TRACE quiche] 91b55275c6c1097e0068093249eb2be3031195e3 tx frm STREAM id=4 off=7549 len=1326 fin=false [2025-04-30T11:30:39.670710022Z TRACE quiche::recovery::congestion::recovery] 91b55275c6c1097e0068093249eb2be3031195e3 timer=121.445295ms latest_rtt=32.161777ms srtt=32.161777ms min_rtt=32.161777ms rttvar=16.080888ms cwnd=14850 ssthresh=18446744073709551615 bytes_in_flight=13500 app_limited=true congestion_recovery_start_time=None Rate { delivered: 1350, delivered_time: Instant { tv_sec: 566, tv_nsec: 846206405 }, first_sent_time: Instant { tv_sec: 566, tv_nsec: 814044628 }, end_of_app_limited: 0, last_sent_packet: 13, largest_acked: 2, rate_sample: RateSample { delivery_rate: 41975, is_app_limited: true, interval: 32.161777ms, delivered: 1350, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 566, tv_nsec: 814044628 }), send_elapsed: 0ns, ack_elapsed: 32.161777ms, rtt: 32.161777ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 577160, last_update: Instant { tv_sec: 566, tv_nsec: 846310640 }, next_time: Instant { tv_sec: 566, tv_nsec: 846310640 }, max_datagram_size: 1350, last_packet_size: Some(0), iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(13) last_round_min_rtt=32.161777ms 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-30T11:30:39.670740970Z TRACE quiche] 91b55275c6c1097e0068093249eb2be3031195e3 pmtud probe status false hs_con=true hs_sent=true cwnd_avail=1350 out_len=1350 left=1332 [2025-04-30T11:30:39.670747162Z TRACE quiche] 91b55275c6c1097e0068093249eb2be3031195e3 tx pkt Short dcid= key_phase=false len=1332 pn=14 [2025-04-30T11:30:39.670751780Z TRACE quiche] 91b55275c6c1097e0068093249eb2be3031195e3 tx frm STREAM id=4 off=8875 len=1326 fin=false [2025-04-30T11:30:39.670761999Z TRACE quiche::recovery::congestion::recovery] 91b55275c6c1097e0068093249eb2be3031195e3 timer=121.461004ms latest_rtt=32.161777ms srtt=32.161777ms min_rtt=32.161777ms rttvar=16.080888ms cwnd=14850 ssthresh=18446744073709551615 bytes_in_flight=14850 app_limited=false congestion_recovery_start_time=None Rate { delivered: 1350, delivered_time: Instant { tv_sec: 566, tv_nsec: 846206405 }, first_sent_time: Instant { tv_sec: 566, tv_nsec: 814044628 }, end_of_app_limited: 0, last_sent_packet: 14, largest_acked: 2, rate_sample: RateSample { delivery_rate: 41975, is_app_limited: true, interval: 32.161777ms, delivered: 1350, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 566, tv_nsec: 814044628 }), send_elapsed: 0ns, ack_elapsed: 32.161777ms, rtt: 32.161777ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 577160, last_update: Instant { tv_sec: 566, tv_nsec: 846310640 }, next_time: Instant { tv_sec: 566, tv_nsec: 846310640 }, max_datagram_size: 1350, last_packet_size: Some(0), iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(13) last_round_min_rtt=32.161777ms 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-30T11:30:39.670793678Z TRACE quiche] 91b55275c6c1097e0068093249eb2be3031195e3 pmtud probe status false hs_con=true hs_sent=true cwnd_avail=0 out_len=1350 left=0 [2025-04-30T11:30:39.670799700Z TRACE quiche_server] 91b55275c6c1097e0068093249eb2be3031195e3 done writing [2025-04-30T11:30:39.670858700Z TRACE quiche_server] 91b55275c6c1097e0068093249eb2be3031195e3 written 2700 bytes with Some(SendInfo { from: [::]:443, to: [fd00:cafe:cafe::100]:49441, at: Instant { tv_sec: 566, tv_nsec: 846310640 } }) [2025-04-30T11:30:39.670871243Z TRACE quiche_server] Collecting garbage [2025-04-30T11:30:39.680418550Z TRACE quiche_server] got 48 bytes from [fd00:cafe:cafe::100]:49441 to [::]:443 [2025-04-30T11:30:39.680435993Z TRACE quiche_server] got packet Short dcid=91b55275c6c1097e0068093249eb2be3031195e3 key_phase=false [2025-04-30T11:30:39.680445570Z TRACE quiche] 91b55275c6c1097e0068093249eb2be3031195e3 rx pkt Short dcid=91b55275c6c1097e0068093249eb2be3031195e3 key_phase=false len=27 pn=10941549 [2025-04-30T11:30:39.680454457Z TRACE quiche] 91b55275c6c1097e0068093249eb2be3031195e3 rx frm ACK delay=1 blocks=[2..12] ecn_counts=None [2025-04-30T11:30:39.680459336Z TRACE quiche::recovery::congestion::recovery] 91b55275c6c1097e0068093249eb2be3031195e3 packet newly acked 3 [2025-04-30T11:30:39.680462592Z TRACE quiche::recovery::congestion::recovery] 91b55275c6c1097e0068093249eb2be3031195e3 packet newly acked 4 [2025-04-30T11:30:39.680464816Z TRACE quiche::recovery::congestion::recovery] 91b55275c6c1097e0068093249eb2be3031195e3 packet newly acked 5 [2025-04-30T11:30:39.680466940Z TRACE quiche::recovery::congestion::recovery] 91b55275c6c1097e0068093249eb2be3031195e3 packet newly acked 6 [2025-04-30T11:30:39.680469916Z TRACE quiche::recovery::congestion::recovery] 91b55275c6c1097e0068093249eb2be3031195e3 packet newly acked 7 [2025-04-30T11:30:39.680472821Z TRACE quiche::recovery::congestion::recovery] 91b55275c6c1097e0068093249eb2be3031195e3 packet newly acked 8 [2025-04-30T11:30:39.680474995Z TRACE quiche::recovery::congestion::recovery] 91b55275c6c1097e0068093249eb2be3031195e3 packet newly acked 9 [2025-04-30T11:30:39.680477109Z TRACE quiche::recovery::congestion::recovery] 91b55275c6c1097e0068093249eb2be3031195e3 packet newly acked 10 [2025-04-30T11:30:39.680479734Z TRACE quiche::recovery::congestion::recovery] 91b55275c6c1097e0068093249eb2be3031195e3 packet newly acked 11 [2025-04-30T11:30:39.680482188Z TRACE quiche::recovery::congestion::recovery] 91b55275c6c1097e0068093249eb2be3031195e3 packet newly acked 12 [2025-04-30T11:30:39.680486928Z TRACE quiche] 91b55275c6c1097e0068093249eb2be3031195e3 rx frm PADDING len=5 [2025-04-30T11:30:39.680512886Z TRACE quiche_server] 91b55275c6c1097e0068093249eb2be3031195e3 processed 48 bytes [2025-04-30T11:30:39.680518256Z TRACE quiche_server] recv() would block [2025-04-30T11:30:39.680523205Z TRACE quiche] 91b55275c6c1097e0068093249eb2be3031195e3 pmtud probe status false hs_con=true hs_sent=true cwnd_avail=22274 out_len=1350 left=1332 [2025-04-30T11:30:39.680528044Z TRACE quiche] 91b55275c6c1097e0068093249eb2be3031195e3 tx pkt Short dcid= key_phase=false len=45 pn=15 [2025-04-30T11:30:39.680530759Z TRACE quiche] 91b55275c6c1097e0068093249eb2be3031195e3 tx frm STREAM id=4 off=10201 len=39 fin=true [2025-04-30T11:30:39.680537772Z TRACE quiche::recovery::congestion::recovery] 91b55275c6c1097e0068093249eb2be3031195e3 timer=115.973705ms latest_rtt=41.580364ms srtt=33.338099ms min_rtt=32.161777ms rttvar=14.413312ms cwnd=24974 ssthresh=18446744073709551615 bytes_in_flight=2763 app_limited=true congestion_recovery_start_time=None Rate { delivered: 13500, delivered_time: Instant { tv_sec: 566, tv_nsec: 856082646 }, first_sent_time: Instant { tv_sec: 566, tv_nsec: 814044628 }, end_of_app_limited: 14, last_sent_packet: 15, largest_acked: 12, rate_sample: RateSample { delivery_rate: 419752, is_app_limited: true, interval: 32.161777ms, delivered: 13500, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 566, tv_nsec: 814044628 }), send_elapsed: 0ns, ack_elapsed: 32.161777ms, rtt: 32.161777ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 936391, last_update: Instant { tv_sec: 566, tv_nsec: 846310640 }, next_time: Instant { tv_sec: 566, tv_nsec: 846310640 }, max_datagram_size: 1350, last_packet_size: Some(0), iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(13) last_round_min_rtt=32.161777ms current_round_min_rtt=41.580364ms css_baseline_min_rtt=41.580364ms rtt_sample_count=1 css_start_time=Some(Instant { tv_sec: 566, tv_nsec: 856082646 }) css_round_count=0 cubic={ k=0 w_max=0 } [2025-04-30T11:30:39.680589709Z TRACE quiche_server] 91b55275c6c1097e0068093249eb2be3031195e3 written 63 bytes with Some(SendInfo { from: [::]:443, to: [fd00:cafe:cafe::100]:49441, at: Instant { tv_sec: 566, tv_nsec: 846310640 } }) [2025-04-30T11:30:39.680595370Z TRACE quiche_server] Collecting garbage [2025-04-30T11:30:39.680599487Z TRACE quiche_server] recv() would block [2025-04-30T11:30:39.680602313Z TRACE quiche_server] 91b55275c6c1097e0068093249eb2be3031195e3 done writing [2025-04-30T11:30:39.680604517Z TRACE quiche_server] Collecting garbage [2025-04-30T11:30:39.711391096Z TRACE quiche_server] got 49 bytes from [fd00:cafe:cafe::100]:49441 to [::]:443 [2025-04-30T11:30:39.711426943Z TRACE quiche_server] got packet Short dcid=91b55275c6c1097e0068093249eb2be3031195e3 key_phase=false [2025-04-30T11:30:39.711446710Z TRACE quiche] 91b55275c6c1097e0068093249eb2be3031195e3 rx pkt Short dcid=91b55275c6c1097e0068093249eb2be3031195e3 key_phase=false len=28 pn=10941550 [2025-04-30T11:30:39.711463852Z TRACE quiche] 91b55275c6c1097e0068093249eb2be3031195e3 rx frm APPLICATION_CLOSE err=0 reason=[4e, 6f, 20, 45, 72, 72, 6f, 72] [2025-04-30T11:30:39.711489380Z TRACE quiche_server] 91b55275c6c1097e0068093249eb2be3031195e3 processed 49 bytes [2025-04-30T11:30:39.711499899Z TRACE quiche_server] recv() would block [2025-04-30T11:30:39.711503947Z TRACE quiche_server] 91b55275c6c1097e0068093249eb2be3031195e3 done writing [2025-04-30T11:30:39.711507494Z TRACE quiche_server] Collecting garbage [2025-04-30T11:30:39.984814552Z TRACE quiche_server] timed out [2025-04-30T11:30:39.984849397Z TRACE quiche] 91b55275c6c1097e0068093249eb2be3031195e3 draining timeout expired [2025-04-30T11:30:39.984902476Z TRACE quiche_server] 91b55275c6c1097e0068093249eb2be3031195e3 done writing [2025-04-30T11:30:39.984908508Z TRACE quiche_server] Collecting garbage [2025-04-30T11:30:39.984913827Z INFO quiche_server] 91b55275c6c1097e0068093249eb2be3031195e3 connection collected recv=6 sent=16 lost=0 retrans=0 sent_bytes=17160 recv_bytes=1583 lost_bytes=0 [local_addr=[::]:443 peer_addr=[fd00:cafe:cafe::100]:49441 validation_state=Validated active=true recv=6 sent=16 lost=0 retrans=0 rtt=33.338099ms min_rtt=Some(32.161777ms) rttvar=14.413312ms cwnd=24974 sent_bytes=17160 recv_bytes=1583 lost_bytes=0 stream_retrans_bytes=0 pmtu=1350 delivery_rate=419752]