[2025-04-30T09:54:01.259350202Z INFO quiche_server] listening on [::]:443 [2025-04-30T09:54:01.259371953Z TRACE mio::poll] registering event source with poller: token=Token(0), interests=READABLE [2025-04-30T09:54:01.259378495Z TRACE quiche_server] GSO detected: false [2025-04-30T09:54:02.100251721Z TRACE quiche_server] got 1207 bytes from [::ffff:193.167.100.2]:48499 to [::]:443 [2025-04-30T09:54:02.100288860Z TRACE quiche_server] got packet Initial version=57414954 dcid= scid= token= [2025-04-30T09:54:02.100299750Z WARN quiche_server] Doing version negotiation [2025-04-30T09:54:02.100393234Z TRACE quiche_server] got 1207 bytes from [::ffff:193.167.100.2]:48499 to [::]:443 [2025-04-30T09:54:02.100399245Z TRACE quiche_server] got packet Initial version=57414954 dcid= scid= token= [2025-04-30T09:54:02.100403283Z WARN quiche_server] Doing version negotiation [2025-04-30T09:54:02.100423341Z TRACE quiche_server] got 1207 bytes from [::ffff:193.167.100.2]:48499 to [::]:443 [2025-04-30T09:54:02.100427218Z TRACE quiche_server] got packet Initial version=57414954 dcid= scid= token= [2025-04-30T09:54:02.100430474Z WARN quiche_server] Doing version negotiation [2025-04-30T09:54:02.100446413Z TRACE quiche_server] recv() would block [2025-04-30T09:54:02.280352835Z TRACE quiche_server] got 1232 bytes from [fd00:cafe:cafe::100]:48597 to [::]:443 [2025-04-30T09:54:02.280383763Z TRACE quiche_server] got packet Initial version=1 dcid=5d12f1fa20ff4728 scid=9f0372427ece69b6 token= [2025-04-30T09:54:02.280393380Z DEBUG quiche_server] New connection: dcid=5d12f1fa20ff4728 scid=47117fb0437a3eccf70f732217bb4f96c1ccc0ee [2025-04-30T09:54:02.280599134Z TRACE quiche] 47117fb0437a3eccf70f732217bb4f96c1ccc0ee rx pkt Initial version=1 dcid=5d12f1fa20ff4728 scid=9f0372427ece69b6 token= len=1206 pn=125586 [2025-04-30T09:54:02.280612539Z TRACE quiche] 47117fb0437a3eccf70f732217bb4f96c1ccc0ee rx frm PING mtu_probe=None [2025-04-30T09:54:02.280616887Z TRACE quiche] 47117fb0437a3eccf70f732217bb4f96c1ccc0ee rx frm CRYPTO off=0 len=283 [2025-04-30T09:54:02.280643567Z TRACE quiche::tls] checking peer ALPN Ok("hq-interop") against Ok("h3") [2025-04-30T09:54:02.280648115Z TRACE quiche::tls] checking peer ALPN Ok("hq-interop") against Ok("hq-interop") [2025-04-30T09:54:02.280761005Z TRACE quiche::tls] 47117fb0437a3eccf70f732217bb4f96c1ccc0ee write message lvl=Initial len=123 [2025-04-30T09:54:02.280794317Z TRACE quiche::tls] 47117fb0437a3eccf70f732217bb4f96c1ccc0ee set write secret lvl=Handshake [2025-04-30T09:54:02.280861202Z TRACE quiche::tls] 47117fb0437a3eccf70f732217bb4f96c1ccc0ee write message lvl=Handshake len=697 [2025-04-30T09:54:02.280864919Z TRACE quiche::tls] 47117fb0437a3eccf70f732217bb4f96c1ccc0ee set write secret lvl=OneRTT [2025-04-30T09:54:02.280872654Z TRACE quiche::tls] 47117fb0437a3eccf70f732217bb4f96c1ccc0ee set read secret lvl=Handshake [2025-04-30T09:54:02.280894344Z TRACE quiche] 47117fb0437a3eccf70f732217bb4f96c1ccc0ee rx frm PADDING len=898 [2025-04-30T09:54:02.280916215Z TRACE quiche_server] 47117fb0437a3eccf70f732217bb4f96c1ccc0ee processed 1232 bytes [2025-04-30T09:54:02.280937595Z TRACE quiche_server] recv() would block [2025-04-30T09:54:02.280951190Z TRACE quiche] 47117fb0437a3eccf70f732217bb4f96c1ccc0ee tx pkt Initial version=1 dcid=9f0372427ece69b6 scid=47117fb0437a3eccf70f732217bb4f96c1ccc0ee len=135 pn=0 [2025-04-30T09:54:02.280955117Z TRACE quiche] 47117fb0437a3eccf70f732217bb4f96c1ccc0ee tx frm ACK delay=46 blocks=[125586..125586] ecn_counts=None [2025-04-30T09:54:02.280960197Z TRACE quiche] 47117fb0437a3eccf70f732217bb4f96c1ccc0ee tx frm CRYPTO off=0 len=123 [2025-04-30T09:54:02.280970626Z TRACE quiche::recovery::congestion::recovery] 47117fb0437a3eccf70f732217bb4f96c1ccc0ee timer=998.968982ms latest_rtt=0ns srtt=333ms min_rtt=333ms rttvar=166.5ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=190 app_limited=true congestion_recovery_start_time=None Rate { delivered: 0, delivered_time: Instant { tv_sec: 672, tv_nsec: 67879009 }, first_sent_time: Instant { tv_sec: 672, tv_nsec: 67879009 }, 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: 672, tv_nsec: 67879009 }, next_time: Instant { tv_sec: 672, tv_nsec: 67879009 }, 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-30T09:54:02.281002245Z TRACE quiche] 47117fb0437a3eccf70f732217bb4f96c1ccc0ee tx pkt Handshake version=1 dcid=9f0372427ece69b6 scid=47117fb0437a3eccf70f732217bb4f96c1ccc0ee len=701 pn=1 [2025-04-30T09:54:02.281005811Z TRACE quiche] 47117fb0437a3eccf70f732217bb4f96c1ccc0ee tx frm CRYPTO off=0 len=697 [2025-04-30T09:54:02.281012704Z TRACE quiche::recovery::congestion::recovery] 47117fb0437a3eccf70f732217bb4f96c1ccc0ee timer=998.927445ms latest_rtt=0ns srtt=333ms min_rtt=333ms rttvar=166.5ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=945 app_limited=true congestion_recovery_start_time=None Rate { delivered: 0, delivered_time: Instant { tv_sec: 672, tv_nsec: 67879009 }, first_sent_time: Instant { tv_sec: 672, tv_nsec: 67879009 }, 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: 672, tv_nsec: 67879009 }, next_time: Instant { tv_sec: 672, tv_nsec: 67879009 }, 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-30T09:54:02.281086622Z TRACE quiche_server] 47117fb0437a3eccf70f732217bb4f96c1ccc0ee written 1200 bytes with Some(SendInfo { from: [::]:443, to: [fd00:cafe:cafe::100]:48597, at: Instant { tv_sec: 672, tv_nsec: 67879009 } }) [2025-04-30T09:54:02.281097362Z TRACE quiche_server] Collecting garbage [2025-04-30T09:54:02.281104555Z TRACE quiche_server] recv() would block [2025-04-30T09:54:02.281112000Z TRACE quiche_server] 47117fb0437a3eccf70f732217bb4f96c1ccc0ee done writing [2025-04-30T09:54:02.281116738Z TRACE quiche_server] Collecting garbage [2025-04-30T09:54:02.313350880Z TRACE quiche_server] got 412 bytes from [fd00:cafe:cafe::100]:48597 to [::]:443 [2025-04-30T09:54:02.313373513Z TRACE quiche_server] got packet Handshake version=1 dcid=47117fb0437a3eccf70f732217bb4f96c1ccc0ee scid=9f0372427ece69b6 [2025-04-30T09:54:02.313387368Z TRACE quiche] 47117fb0437a3eccf70f732217bb4f96c1ccc0ee rx pkt Handshake version=1 dcid=47117fb0437a3eccf70f732217bb4f96c1ccc0ee scid=9f0372427ece69b6 len=64 pn=0 [2025-04-30T09:54:02.313398068Z TRACE quiche] 47117fb0437a3eccf70f732217bb4f96c1ccc0ee rx frm ACK delay=45 blocks=[1..1] ecn_counts=None [2025-04-30T09:54:02.313404700Z TRACE quiche::recovery::congestion::recovery] 47117fb0437a3eccf70f732217bb4f96c1ccc0ee packet newly acked 1 [2025-04-30T09:54:02.313410221Z TRACE quiche] 47117fb0437a3eccf70f732217bb4f96c1ccc0ee rx frm CRYPTO off=0 len=36 [2025-04-30T09:54:02.313427613Z TRACE quiche::tls] 47117fb0437a3eccf70f732217bb4f96c1ccc0ee set read secret lvl=OneRTT [2025-04-30T09:54:02.313469581Z TRACE quiche::tls] 47117fb0437a3eccf70f732217bb4f96c1ccc0ee write message lvl=OneRTT len=396 [2025-04-30T09:54:02.313482806Z TRACE quiche] 47117fb0437a3eccf70f732217bb4f96c1ccc0ee dropped epoch 1 state [2025-04-30T09:54:02.313488416Z TRACE quiche] 47117fb0437a3eccf70f732217bb4f96c1ccc0ee connection established: proto=Ok("hq-interop") cipher=Some(AES128_GCM) curve=Some("P-256") sigalg=None resumed=false TransportParams { original_destination_connection_id: None, max_idle_timeout: 180000, stateless_reset_token: None, max_udp_payload_size: 1440, initial_max_data: 1048576, initial_max_stream_data_bidi_local: 2097152, initial_max_stream_data_bidi_remote: 65635, initial_max_stream_data_uni: 65535, initial_max_streams_bidi: 512, initial_max_streams_uni: 512, ack_delay_exponent: 3, max_ack_delay: 10, disable_active_migration: false, active_conn_id_limit: 8, initial_source_connection_id: Some(9f0372427ece69b6), retry_source_connection_id: None, max_datagram_frame_size: None, unknown_params: None } [2025-04-30T09:54:02.313531607Z TRACE quiche] 47117fb0437a3eccf70f732217bb4f96c1ccc0ee dropped epoch 0 state [2025-04-30T09:54:02.313535785Z TRACE quiche] 47117fb0437a3eccf70f732217bb4f96c1ccc0ee rx pkt Short dcid=47117fb0437a3eccf70f732217bb4f96c1ccc0ee key_phase=false len=290 pn=0 [2025-04-30T09:54:02.313542387Z TRACE quiche] 47117fb0437a3eccf70f732217bb4f96c1ccc0ee rx frm NEW_CONNECTION_ID seq_num=1 retire_prior_to=0 conn_id=[e3, 5f, 55, db, 09, b1, b5, fe] reset_token=[67, b0, f9, 33, c0, ff, d8, 37, 0f, 7f, d2, 96, 93, 0a, 03, 4e] [2025-04-30T09:54:02.313549240Z TRACE quiche] 47117fb0437a3eccf70f732217bb4f96c1ccc0ee rx frm NEW_CONNECTION_ID seq_num=2 retire_prior_to=0 conn_id=[53, 35, 9d, 4b, 81, 8c, f1, 78] reset_token=[fd, 02, c9, 22, 73, 2b, f4, 43, 09, 26, cf, 17, 8f, ed, 06, 56] [2025-04-30T09:54:02.313553949Z TRACE quiche] 47117fb0437a3eccf70f732217bb4f96c1ccc0ee rx frm NEW_CONNECTION_ID seq_num=3 retire_prior_to=0 conn_id=[5a, 8d, 7b, 8f, 5f, ec, ef, fe] reset_token=[7a, cf, ee, 37, 1f, eb, 27, 05, 4c, 95, 24, 86, a3, e4, bc, 1a] [2025-04-30T09:54:02.313558327Z TRACE quiche] 47117fb0437a3eccf70f732217bb4f96c1ccc0ee rx frm NEW_CONNECTION_ID seq_num=4 retire_prior_to=0 conn_id=[63, 9b, 97, 0a, 60, e5, 8e, d8] reset_token=[05, 55, de, 27, 70, 6c, 46, 87, 9f, 9d, a0, 8e, 80, 62, 78, fc] [2025-04-30T09:54:02.313563356Z TRACE quiche] 47117fb0437a3eccf70f732217bb4f96c1ccc0ee rx frm NEW_CONNECTION_ID seq_num=5 retire_prior_to=0 conn_id=[fc, 7c, cf, 29, 3a, 3a, 4a, ae] reset_token=[3b, 28, a3, ea, 07, 75, fc, 5a, 74, 13, 3d, 92, df, dd, 65, 77] [2025-04-30T09:54:02.313567975Z TRACE quiche] 47117fb0437a3eccf70f732217bb4f96c1ccc0ee rx frm NEW_CONNECTION_ID seq_num=6 retire_prior_to=0 conn_id=[54, cb, e8, 6b, 28, e1, a4, 20] reset_token=[4d, 64, eb, ff, 11, a7, de, f9, 5e, c7, 4b, d3, c9, cd, 1c, 67] [2025-04-30T09:54:02.313572463Z TRACE quiche] 47117fb0437a3eccf70f732217bb4f96c1ccc0ee rx frm NEW_CONNECTION_ID seq_num=7 retire_prior_to=0 conn_id=[a5, aa, dd, 07, 1b, 25, 1a, 38] reset_token=[94, 91, ad, 1a, f9, 27, 31, f4, 87, 0d, a7, 79, a1, d1, 46, 48] [2025-04-30T09:54:02.313576440Z TRACE quiche] 47117fb0437a3eccf70f732217bb4f96c1ccc0ee rx frm PADDING len=77 [2025-04-30T09:54:02.313584906Z TRACE quiche_server] 47117fb0437a3eccf70f732217bb4f96c1ccc0ee processed 412 bytes [2025-04-30T09:54:02.313593302Z TRACE quiche_server] got 183 bytes from [fd00:cafe:cafe::100]:48597 to [::]:443 [2025-04-30T09:54:02.313596648Z TRACE quiche_server] got packet Short dcid=47117fb0437a3eccf70f732217bb4f96c1ccc0ee key_phase=false [2025-04-30T09:54:02.313600926Z TRACE quiche] 47117fb0437a3eccf70f732217bb4f96c1ccc0ee rx pkt Short dcid=47117fb0437a3eccf70f732217bb4f96c1ccc0ee key_phase=false len=162 pn=1 [2025-04-30T09:54:02.313605124Z TRACE quiche] 47117fb0437a3eccf70f732217bb4f96c1ccc0ee rx frm STREAM id=0 off=0 len=17 fin=true [2025-04-30T09:54:02.313609893Z TRACE quiche] 47117fb0437a3eccf70f732217bb4f96c1ccc0ee rx frm STREAM id=4 off=0 len=17 fin=true [2025-04-30T09:54:02.313612968Z TRACE quiche] 47117fb0437a3eccf70f732217bb4f96c1ccc0ee rx frm PADDING len=105 [2025-04-30T09:54:02.313617737Z TRACE quiche_server] 47117fb0437a3eccf70f732217bb4f96c1ccc0ee processed 183 bytes [2025-04-30T09:54:02.313620362Z DEBUG quiche_apps::common] 47117fb0437a3eccf70f732217bb4f96c1ccc0ee response stream 0 is writable with capacity Ok(13500) [2025-04-30T09:54:02.313627426Z DEBUG quiche_apps::common] 47117fb0437a3eccf70f732217bb4f96c1ccc0ee response stream 4 is writable with capacity Ok(13500) [2025-04-30T09:54:02.313632996Z TRACE quiche_apps::common] 47117fb0437a3eccf70f732217bb4f96c1ccc0ee received 17 bytes [2025-04-30T09:54:02.313635510Z TRACE quiche_apps::common] 47117fb0437a3eccf70f732217bb4f96c1ccc0ee stream 0 has 17 bytes (fin? true) [2025-04-30T09:54:02.313639818Z INFO quiche_apps::common] 47117fb0437a3eccf70f732217bb4f96c1ccc0ee got GET request for "/www/nvkkgdtuzd" on stream 0 [2025-04-30T09:54:02.313668973Z INFO quiche_apps::common] 47117fb0437a3eccf70f732217bb4f96c1ccc0ee sending response of size 5120 on stream 0 [2025-04-30T09:54:02.313676046Z TRACE quiche_apps::common] 47117fb0437a3eccf70f732217bb4f96c1ccc0ee received 17 bytes [2025-04-30T09:54:02.313678330Z TRACE quiche_apps::common] 47117fb0437a3eccf70f732217bb4f96c1ccc0ee stream 4 has 17 bytes (fin? true) [2025-04-30T09:54:02.313680885Z INFO quiche_apps::common] 47117fb0437a3eccf70f732217bb4f96c1ccc0ee got GET request for "/www/jfimunaare" on stream 4 [2025-04-30T09:54:02.313694050Z INFO quiche_apps::common] 47117fb0437a3eccf70f732217bb4f96c1ccc0ee sending response of size 10240 on stream 4 [2025-04-30T09:54:02.313700642Z TRACE quiche_server] recv() would block [2025-04-30T09:54:02.313708867Z TRACE quiche] 47117fb0437a3eccf70f732217bb4f96c1ccc0ee pmtud probe status false hs_con=true hs_sent=false cwnd_avail=13500 out_len=1350 left=1319 [2025-04-30T09:54:02.313717944Z TRACE quiche] 47117fb0437a3eccf70f732217bb4f96c1ccc0ee tx pkt Short dcid=9f0372427ece69b6 key_phase=false len=1324 pn=2 [2025-04-30T09:54:02.313720860Z TRACE quiche] 47117fb0437a3eccf70f732217bb4f96c1ccc0ee tx frm ACK delay=13 blocks=[0..1] ecn_counts=None [2025-04-30T09:54:02.313724035Z TRACE quiche] 47117fb0437a3eccf70f732217bb4f96c1ccc0ee tx frm NEW_CONNECTION_ID seq_num=1 retire_prior_to=0 conn_id=[aa, e9, ea, b6, 9d, a5, af, 2f, 42, f9, b8, c3, c2, df, ff, 9f, 5e, e3, f9, 59] reset_token=[a7, 64, 70, e9, e3, 35, 03, 43, 07, 10, 93, 00, e0, 86, 60, 20] [2025-04-30T09:54:02.313729836Z TRACE quiche] 47117fb0437a3eccf70f732217bb4f96c1ccc0ee tx frm NEW_CONNECTION_ID seq_num=2 retire_prior_to=0 conn_id=[cc, e5, 1d, 81, 80, 65, 33, fd, 6e, bf, 56, fd, 24, 3a, e2, 01, 80, 26, f9, db] reset_token=[31, 8a, 82, 55, 1d, fd, 1e, bf, 35, 99, 2f, 56, ec, 0b, 2f, 07] [2025-04-30T09:54:02.313735176Z TRACE quiche] 47117fb0437a3eccf70f732217bb4f96c1ccc0ee tx frm NEW_CONNECTION_ID seq_num=3 retire_prior_to=0 conn_id=[e7, 91, e8, 93, 64, a7, d7, b2, 87, 37, 9d, 30, 56, ba, e5, 43, 1e, 90, 9f, 39] reset_token=[6a, 6d, 1f, b4, dc, 75, 5c, 53, de, b7, 98, 1e, 29, 10, b8, cc] [2025-04-30T09:54:02.313740185Z TRACE quiche] 47117fb0437a3eccf70f732217bb4f96c1ccc0ee tx frm NEW_CONNECTION_ID seq_num=4 retire_prior_to=0 conn_id=[cf, 03, ed, b5, ce, 39, 73, 5d, 41, ad, a0, c2, 65, 27, 53, 45, dd, 1e, 1c, 3a] reset_token=[10, 0b, 0e, f9, 34, e0, 00, c7, 81, dd, ee, 01, 5a, 99, 6a, a7] [2025-04-30T09:54:02.313745466Z TRACE quiche] 47117fb0437a3eccf70f732217bb4f96c1ccc0ee tx frm NEW_CONNECTION_ID seq_num=5 retire_prior_to=0 conn_id=[51, 02, 6f, 10, 7b, cf, 58, 8f, 62, a6, 61, f9, 19, e8, 8d, ff, 1b, 94, eb, 6a] reset_token=[73, fc, da, 3e, ed, e7, 78, 1a, 24, df, f1, 9f, 25, e7, 2c, 97] [2025-04-30T09:54:02.313750555Z TRACE quiche] 47117fb0437a3eccf70f732217bb4f96c1ccc0ee tx frm NEW_CONNECTION_ID seq_num=6 retire_prior_to=0 conn_id=[e4, 4b, 88, 6c, d8, 3f, 2e, 88, e1, 96, d2, 7e, ee, f0, ba, a8, b9, a9, 8f, 7d] reset_token=[d8, af, 4e, 6e, 8f, 5e, 6f, d5, 30, dd, df, be, 40, 7c, 3b, 63] [2025-04-30T09:54:02.313755634Z TRACE quiche] 47117fb0437a3eccf70f732217bb4f96c1ccc0ee tx frm NEW_CONNECTION_ID seq_num=7 retire_prior_to=0 conn_id=[7d, 47, ff, 2f, 43, b4, 98, 67, b2, d8, fc, a9, a0, 27, 1c, d7, bd, f9, 39, df] reset_token=[63, 6b, 5b, 3f, d1, fd, c2, 2c, 0a, c3, 89, cf, 58, a1, 74, 42] [2025-04-30T09:54:02.313760744Z TRACE quiche] 47117fb0437a3eccf70f732217bb4f96c1ccc0ee tx frm HANDSHAKE_DONE [2025-04-30T09:54:02.313762998Z TRACE quiche] 47117fb0437a3eccf70f732217bb4f96c1ccc0ee tx frm CRYPTO off=0 len=396 [2025-04-30T09:54:02.313769280Z TRACE quiche] 47117fb0437a3eccf70f732217bb4f96c1ccc0ee tx frm STREAM id=0 off=0 len=633 fin=false [2025-04-30T09:54:02.313782675Z TRACE quiche::recovery::congestion::recovery] 47117fb0437a3eccf70f732217bb4f96c1ccc0ee timer=107.248972ms latest_rtt=32.443021ms srtt=32.443021ms min_rtt=32.443021ms rttvar=16.22151ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=1350 app_limited=true congestion_recovery_start_time=None Rate { delivered: 755, delivered_time: Instant { tv_sec: 672, tv_nsec: 100641576 }, first_sent_time: Instant { tv_sec: 672, tv_nsec: 100641576 }, end_of_app_limited: 1, last_sent_packet: 2, largest_acked: 1, rate_sample: RateSample { delivery_rate: 23271, is_app_limited: true, interval: 32.443021ms, delivered: 755, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 672, tv_nsec: 67879009 }), send_elapsed: 0ns, ack_elapsed: 32.443021ms, rtt: 32.443021ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 520142, last_update: Instant { tv_sec: 672, tv_nsec: 100641576 }, next_time: Instant { tv_sec: 672, tv_nsec: 100641576 }, max_datagram_size: 1350, last_packet_size: Some(0), iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } [2025-04-30T09:54:02.313799055Z TRACE quiche] 47117fb0437a3eccf70f732217bb4f96c1ccc0ee pmtud probe status false hs_con=true hs_sent=true cwnd_avail=12150 out_len=1350 left=1324 [2025-04-30T09:54:02.313802602Z TRACE quiche] 47117fb0437a3eccf70f732217bb4f96c1ccc0ee tx pkt Short dcid=9f0372427ece69b6 key_phase=false len=1324 pn=3 [2025-04-30T09:54:02.313805057Z TRACE quiche] 47117fb0437a3eccf70f732217bb4f96c1ccc0ee tx frm STREAM id=4 off=0 len=1319 fin=false [2025-04-30T09:54:02.313827198Z TRACE quiche::recovery::congestion::recovery] 47117fb0437a3eccf70f732217bb4f96c1ccc0ee timer=107.298784ms latest_rtt=32.443021ms srtt=32.443021ms min_rtt=32.443021ms rttvar=16.22151ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=2700 app_limited=true congestion_recovery_start_time=None Rate { delivered: 755, delivered_time: Instant { tv_sec: 672, tv_nsec: 100641576 }, first_sent_time: Instant { tv_sec: 672, tv_nsec: 100641576 }, end_of_app_limited: 1, last_sent_packet: 3, largest_acked: 1, rate_sample: RateSample { delivery_rate: 23271, is_app_limited: true, interval: 32.443021ms, delivered: 755, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 672, tv_nsec: 67879009 }), send_elapsed: 0ns, ack_elapsed: 32.443021ms, rtt: 32.443021ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 520142, last_update: Instant { tv_sec: 672, tv_nsec: 100641576 }, next_time: Instant { tv_sec: 672, tv_nsec: 100641576 }, max_datagram_size: 1350, last_packet_size: Some(0), iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } [2025-04-30T09:54:02.313838419Z TRACE quiche] 47117fb0437a3eccf70f732217bb4f96c1ccc0ee pmtud probe status false hs_con=true hs_sent=true cwnd_avail=10800 out_len=1350 left=1324 [2025-04-30T09:54:02.313841585Z TRACE quiche] 47117fb0437a3eccf70f732217bb4f96c1ccc0ee tx pkt Short dcid=9f0372427ece69b6 key_phase=false len=1324 pn=4 [2025-04-30T09:54:02.313843939Z TRACE quiche] 47117fb0437a3eccf70f732217bb4f96c1ccc0ee tx frm STREAM id=0 off=633 len=1318 fin=false [2025-04-30T09:54:02.313848798Z TRACE quiche::recovery::congestion::recovery] 47117fb0437a3eccf70f732217bb4f96c1ccc0ee timer=107.317018ms latest_rtt=32.443021ms srtt=32.443021ms min_rtt=32.443021ms rttvar=16.22151ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=4050 app_limited=true congestion_recovery_start_time=None Rate { delivered: 755, delivered_time: Instant { tv_sec: 672, tv_nsec: 100641576 }, first_sent_time: Instant { tv_sec: 672, tv_nsec: 100641576 }, end_of_app_limited: 1, last_sent_packet: 4, largest_acked: 1, rate_sample: RateSample { delivery_rate: 23271, is_app_limited: true, interval: 32.443021ms, delivered: 755, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 672, tv_nsec: 67879009 }), send_elapsed: 0ns, ack_elapsed: 32.443021ms, rtt: 32.443021ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 520142, last_update: Instant { tv_sec: 672, tv_nsec: 100641576 }, next_time: Instant { tv_sec: 672, tv_nsec: 100641576 }, max_datagram_size: 1350, last_packet_size: Some(0), iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } [2025-04-30T09:54:02.313861231Z TRACE quiche] 47117fb0437a3eccf70f732217bb4f96c1ccc0ee pmtud probe status false hs_con=true hs_sent=true cwnd_avail=9450 out_len=1350 left=1324 [2025-04-30T09:54:02.313864397Z TRACE quiche] 47117fb0437a3eccf70f732217bb4f96c1ccc0ee tx pkt Short dcid=9f0372427ece69b6 key_phase=false len=1324 pn=5 [2025-04-30T09:54:02.313866761Z TRACE quiche] 47117fb0437a3eccf70f732217bb4f96c1ccc0ee tx frm STREAM id=4 off=1319 len=1318 fin=false [2025-04-30T09:54:02.313871230Z TRACE quiche::recovery::congestion::recovery] 47117fb0437a3eccf70f732217bb4f96c1ccc0ee timer=107.317689ms latest_rtt=32.443021ms srtt=32.443021ms min_rtt=32.443021ms rttvar=16.22151ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=5400 app_limited=true congestion_recovery_start_time=None Rate { delivered: 755, delivered_time: Instant { tv_sec: 672, tv_nsec: 100641576 }, first_sent_time: Instant { tv_sec: 672, tv_nsec: 100641576 }, end_of_app_limited: 1, last_sent_packet: 5, largest_acked: 1, rate_sample: RateSample { delivery_rate: 23271, is_app_limited: true, interval: 32.443021ms, delivered: 755, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 672, tv_nsec: 67879009 }), send_elapsed: 0ns, ack_elapsed: 32.443021ms, rtt: 32.443021ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 520142, last_update: Instant { tv_sec: 672, tv_nsec: 100641576 }, next_time: Instant { tv_sec: 672, tv_nsec: 100641576 }, max_datagram_size: 1350, last_packet_size: Some(0), iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } [2025-04-30T09:54:02.313880627Z TRACE quiche] 47117fb0437a3eccf70f732217bb4f96c1ccc0ee pmtud probe status false hs_con=true hs_sent=true cwnd_avail=8100 out_len=1350 left=1324 [2025-04-30T09:54:02.313883463Z TRACE quiche] 47117fb0437a3eccf70f732217bb4f96c1ccc0ee tx pkt Short dcid=9f0372427ece69b6 key_phase=false len=1324 pn=6 [2025-04-30T09:54:02.313885797Z TRACE quiche] 47117fb0437a3eccf70f732217bb4f96c1ccc0ee tx frm STREAM id=0 off=1951 len=1318 fin=false [2025-04-30T09:54:02.313890456Z TRACE quiche::recovery::congestion::recovery] 47117fb0437a3eccf70f732217bb4f96c1ccc0ee timer=107.318021ms latest_rtt=32.443021ms srtt=32.443021ms min_rtt=32.443021ms rttvar=16.22151ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=6750 app_limited=true congestion_recovery_start_time=None Rate { delivered: 755, delivered_time: Instant { tv_sec: 672, tv_nsec: 100641576 }, first_sent_time: Instant { tv_sec: 672, tv_nsec: 100641576 }, end_of_app_limited: 1, last_sent_packet: 6, largest_acked: 1, rate_sample: RateSample { delivery_rate: 23271, is_app_limited: true, interval: 32.443021ms, delivered: 755, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 672, tv_nsec: 67879009 }), send_elapsed: 0ns, ack_elapsed: 32.443021ms, rtt: 32.443021ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 520142, last_update: Instant { tv_sec: 672, tv_nsec: 100641576 }, next_time: Instant { tv_sec: 672, tv_nsec: 100641576 }, max_datagram_size: 1350, last_packet_size: Some(0), iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } [2025-04-30T09:54:02.313902518Z TRACE quiche] 47117fb0437a3eccf70f732217bb4f96c1ccc0ee pmtud probe status false hs_con=true hs_sent=true cwnd_avail=6750 out_len=1350 left=1324 [2025-04-30T09:54:02.313905393Z TRACE quiche] 47117fb0437a3eccf70f732217bb4f96c1ccc0ee tx pkt Short dcid=9f0372427ece69b6 key_phase=false len=1324 pn=7 [2025-04-30T09:54:02.313907748Z TRACE quiche] 47117fb0437a3eccf70f732217bb4f96c1ccc0ee tx frm STREAM id=4 off=2637 len=1318 fin=false [2025-04-30T09:54:02.313911976Z TRACE quiche::recovery::congestion::recovery] 47117fb0437a3eccf70f732217bb4f96c1ccc0ee timer=107.318412ms latest_rtt=32.443021ms srtt=32.443021ms min_rtt=32.443021ms rttvar=16.22151ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=8100 app_limited=true congestion_recovery_start_time=None Rate { delivered: 755, delivered_time: Instant { tv_sec: 672, tv_nsec: 100641576 }, first_sent_time: Instant { tv_sec: 672, tv_nsec: 100641576 }, end_of_app_limited: 1, last_sent_packet: 7, largest_acked: 1, rate_sample: RateSample { delivery_rate: 23271, is_app_limited: true, interval: 32.443021ms, delivered: 755, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 672, tv_nsec: 67879009 }), send_elapsed: 0ns, ack_elapsed: 32.443021ms, rtt: 32.443021ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 520142, last_update: Instant { tv_sec: 672, tv_nsec: 100641576 }, next_time: Instant { tv_sec: 672, tv_nsec: 100641576 }, max_datagram_size: 1350, last_packet_size: Some(0), iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } [2025-04-30T09:54:02.313921724Z TRACE quiche] 47117fb0437a3eccf70f732217bb4f96c1ccc0ee pmtud probe status false hs_con=true hs_sent=true cwnd_avail=5400 out_len=1350 left=1324 [2025-04-30T09:54:02.313924649Z TRACE quiche] 47117fb0437a3eccf70f732217bb4f96c1ccc0ee tx pkt Short dcid=9f0372427ece69b6 key_phase=false len=1324 pn=8 [2025-04-30T09:54:02.313926953Z TRACE quiche] 47117fb0437a3eccf70f732217bb4f96c1ccc0ee tx frm STREAM id=0 off=3269 len=1318 fin=false [2025-04-30T09:54:02.313931172Z TRACE quiche::recovery::congestion::recovery] 47117fb0437a3eccf70f732217bb4f96c1ccc0ee timer=107.318481ms latest_rtt=32.443021ms srtt=32.443021ms min_rtt=32.443021ms rttvar=16.22151ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=9450 app_limited=true congestion_recovery_start_time=None Rate { delivered: 755, delivered_time: Instant { tv_sec: 672, tv_nsec: 100641576 }, first_sent_time: Instant { tv_sec: 672, tv_nsec: 100641576 }, end_of_app_limited: 1, last_sent_packet: 8, largest_acked: 1, rate_sample: RateSample { delivery_rate: 23271, is_app_limited: true, interval: 32.443021ms, delivered: 755, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 672, tv_nsec: 67879009 }), send_elapsed: 0ns, ack_elapsed: 32.443021ms, rtt: 32.443021ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 520142, last_update: Instant { tv_sec: 672, tv_nsec: 100641576 }, next_time: Instant { tv_sec: 672, tv_nsec: 100641576 }, max_datagram_size: 1350, last_packet_size: Some(0), iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } [2025-04-30T09:54:02.313940539Z TRACE quiche] 47117fb0437a3eccf70f732217bb4f96c1ccc0ee pmtud probe status false hs_con=true hs_sent=true cwnd_avail=4050 out_len=1350 left=1324 [2025-04-30T09:54:02.313945969Z TRACE quiche] 47117fb0437a3eccf70f732217bb4f96c1ccc0ee tx pkt Short dcid=9f0372427ece69b6 key_phase=false len=1324 pn=9 [2025-04-30T09:54:02.313948353Z TRACE quiche] 47117fb0437a3eccf70f732217bb4f96c1ccc0ee tx frm STREAM id=4 off=3955 len=1318 fin=false [2025-04-30T09:54:02.313952561Z TRACE quiche::recovery::congestion::recovery] 47117fb0437a3eccf70f732217bb4f96c1ccc0ee timer=107.315786ms latest_rtt=32.443021ms srtt=32.443021ms min_rtt=32.443021ms rttvar=16.22151ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=10800 app_limited=true congestion_recovery_start_time=None Rate { delivered: 755, delivered_time: Instant { tv_sec: 672, tv_nsec: 100641576 }, first_sent_time: Instant { tv_sec: 672, tv_nsec: 100641576 }, end_of_app_limited: 1, last_sent_packet: 9, largest_acked: 1, rate_sample: RateSample { delivery_rate: 23271, is_app_limited: true, interval: 32.443021ms, delivered: 755, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 672, tv_nsec: 67879009 }), send_elapsed: 0ns, ack_elapsed: 32.443021ms, rtt: 32.443021ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 520142, last_update: Instant { tv_sec: 672, tv_nsec: 100641576 }, next_time: Instant { tv_sec: 672, tv_nsec: 100641576 }, max_datagram_size: 1350, last_packet_size: Some(0), iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } [2025-04-30T09:54:02.313961829Z TRACE quiche] 47117fb0437a3eccf70f732217bb4f96c1ccc0ee pmtud probe status false hs_con=true hs_sent=true cwnd_avail=2700 out_len=1350 left=1324 [2025-04-30T09:54:02.313964634Z TRACE quiche] 47117fb0437a3eccf70f732217bb4f96c1ccc0ee tx pkt Short dcid=9f0372427ece69b6 key_phase=false len=539 pn=10 [2025-04-30T09:54:02.313966998Z TRACE quiche] 47117fb0437a3eccf70f732217bb4f96c1ccc0ee tx frm STREAM id=0 off=4587 len=533 fin=true [2025-04-30T09:54:02.313971567Z TRACE quiche::recovery::congestion::recovery] 47117fb0437a3eccf70f732217bb4f96c1ccc0ee timer=107.318211ms latest_rtt=32.443021ms srtt=32.443021ms min_rtt=32.443021ms rttvar=16.22151ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=11365 app_limited=true congestion_recovery_start_time=None Rate { delivered: 755, delivered_time: Instant { tv_sec: 672, tv_nsec: 100641576 }, first_sent_time: Instant { tv_sec: 672, tv_nsec: 100641576 }, end_of_app_limited: 1, last_sent_packet: 10, largest_acked: 1, rate_sample: RateSample { delivery_rate: 23271, is_app_limited: true, interval: 32.443021ms, delivered: 755, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 672, tv_nsec: 67879009 }), send_elapsed: 0ns, ack_elapsed: 32.443021ms, rtt: 32.443021ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 520142, last_update: Instant { tv_sec: 672, tv_nsec: 100641576 }, next_time: Instant { tv_sec: 672, tv_nsec: 100641576 }, max_datagram_size: 1350, last_packet_size: Some(0), iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } [2025-04-30T09:54:02.314109283Z TRACE quiche_server] 47117fb0437a3eccf70f732217bb4f96c1ccc0ee written 11365 bytes with Some(SendInfo { from: [::]:443, to: [fd00:cafe:cafe::100]:48597, at: Instant { tv_sec: 672, tv_nsec: 100641576 } }) [2025-04-30T09:54:02.314122969Z TRACE quiche_server] Collecting garbage [2025-04-30T09:54:02.314130543Z TRACE quiche_server] recv() would block [2025-04-30T09:54:02.314138478Z TRACE quiche] 47117fb0437a3eccf70f732217bb4f96c1ccc0ee pmtud probe status false hs_con=true hs_sent=true cwnd_avail=2135 out_len=1350 left=1324 [2025-04-30T09:54:02.314150600Z TRACE quiche] 47117fb0437a3eccf70f732217bb4f96c1ccc0ee tx pkt Short dcid=9f0372427ece69b6 key_phase=false len=1324 pn=11 [2025-04-30T09:54:02.314154989Z TRACE quiche] 47117fb0437a3eccf70f732217bb4f96c1ccc0ee tx frm STREAM id=4 off=5273 len=1318 fin=false [2025-04-30T09:54:02.314165889Z TRACE quiche::recovery::congestion::recovery] 47117fb0437a3eccf70f732217bb4f96c1ccc0ee timer=107.2966ms latest_rtt=32.443021ms srtt=32.443021ms min_rtt=32.443021ms rttvar=16.22151ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=12715 app_limited=true congestion_recovery_start_time=None Rate { delivered: 755, delivered_time: Instant { tv_sec: 672, tv_nsec: 100641576 }, first_sent_time: Instant { tv_sec: 672, tv_nsec: 100641576 }, end_of_app_limited: 1, last_sent_packet: 11, largest_acked: 1, rate_sample: RateSample { delivery_rate: 23271, is_app_limited: true, interval: 32.443021ms, delivered: 755, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 672, tv_nsec: 67879009 }), send_elapsed: 0ns, ack_elapsed: 32.443021ms, rtt: 32.443021ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 520142, last_update: Instant { tv_sec: 672, tv_nsec: 100641576 }, next_time: Instant { tv_sec: 672, tv_nsec: 100641576 }, max_datagram_size: 1350, last_packet_size: Some(0), iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } [2025-04-30T09:54:02.314187770Z TRACE quiche] 47117fb0437a3eccf70f732217bb4f96c1ccc0ee pmtud probe status false hs_con=true hs_sent=true cwnd_avail=785 out_len=1350 left=759 [2025-04-30T09:54:02.314193460Z TRACE quiche] 47117fb0437a3eccf70f732217bb4f96c1ccc0ee tx pkt Short dcid=9f0372427ece69b6 key_phase=false len=759 pn=12 [2025-04-30T09:54:02.314198039Z TRACE quiche] 47117fb0437a3eccf70f732217bb4f96c1ccc0ee tx frm STREAM id=4 off=6591 len=753 fin=false [2025-04-30T09:54:02.314205973Z TRACE quiche::recovery::congestion::recovery] 47117fb0437a3eccf70f732217bb4f96c1ccc0ee timer=107.307681ms latest_rtt=32.443021ms srtt=32.443021ms min_rtt=32.443021ms rttvar=16.22151ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=13500 app_limited=false congestion_recovery_start_time=None Rate { delivered: 755, delivered_time: Instant { tv_sec: 672, tv_nsec: 100641576 }, first_sent_time: Instant { tv_sec: 672, tv_nsec: 100641576 }, end_of_app_limited: 1, last_sent_packet: 12, largest_acked: 1, rate_sample: RateSample { delivery_rate: 23271, is_app_limited: true, interval: 32.443021ms, delivered: 755, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 672, tv_nsec: 67879009 }), send_elapsed: 0ns, ack_elapsed: 32.443021ms, rtt: 32.443021ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 520142, last_update: Instant { tv_sec: 672, tv_nsec: 100641576 }, next_time: Instant { tv_sec: 672, tv_nsec: 100641576 }, max_datagram_size: 1350, last_packet_size: Some(0), iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } [2025-04-30T09:54:02.314241590Z TRACE quiche_server] 47117fb0437a3eccf70f732217bb4f96c1ccc0ee written 2135 bytes with Some(SendInfo { from: [::]:443, to: [fd00:cafe:cafe::100]:48597, at: Instant { tv_sec: 672, tv_nsec: 100641576 } }) [2025-04-30T09:54:02.314246609Z TRACE quiche_server] Collecting garbage [2025-04-30T09:54:02.314253091Z TRACE quiche_server] recv() would block [2025-04-30T09:54:02.314259603Z TRACE quiche] 47117fb0437a3eccf70f732217bb4f96c1ccc0ee pmtud probe status false hs_con=true hs_sent=true cwnd_avail=0 out_len=1350 left=0 [2025-04-30T09:54:02.314264813Z TRACE quiche_server] 47117fb0437a3eccf70f732217bb4f96c1ccc0ee done writing [2025-04-30T09:54:02.314274802Z TRACE quiche_server] Collecting garbage [2025-04-30T09:54:02.345797848Z TRACE quiche_server] got 55 bytes from [fd00:cafe:cafe::100]:48597 to [::]:443 [2025-04-30T09:54:02.345816162Z TRACE quiche_server] got packet Short dcid=47117fb0437a3eccf70f732217bb4f96c1ccc0ee key_phase=false [2025-04-30T09:54:02.345827083Z TRACE quiche] 47117fb0437a3eccf70f732217bb4f96c1ccc0ee rx pkt Short dcid=47117fb0437a3eccf70f732217bb4f96c1ccc0ee key_phase=false len=34 pn=2 [2025-04-30T09:54:02.345837492Z TRACE quiche] 47117fb0437a3eccf70f732217bb4f96c1ccc0ee rx frm ACK delay=24 blocks=[2..2] ecn_counts=None [2025-04-30T09:54:02.345843743Z TRACE quiche::recovery::congestion::recovery] 47117fb0437a3eccf70f732217bb4f96c1ccc0ee packet newly acked 2 [2025-04-30T09:54:02.345850436Z TRACE quiche] 47117fb0437a3eccf70f732217bb4f96c1ccc0ee rx frm PADDING len=12 [2025-04-30T09:54:02.345869361Z TRACE quiche_server] 47117fb0437a3eccf70f732217bb4f96c1ccc0ee processed 55 bytes [2025-04-30T09:54:02.345872898Z DEBUG quiche_apps::common] 47117fb0437a3eccf70f732217bb4f96c1ccc0ee response stream 4 is writable with capacity Ok(2700) [2025-04-30T09:54:02.345882616Z TRACE quiche_server] recv() would block [2025-04-30T09:54:02.345890060Z TRACE quiche] 47117fb0437a3eccf70f732217bb4f96c1ccc0ee pmtud probe status false hs_con=true hs_sent=true cwnd_avail=2700 out_len=1350 left=1324 [2025-04-30T09:54:02.345897203Z TRACE quiche] 47117fb0437a3eccf70f732217bb4f96c1ccc0ee tx pkt Short dcid=9f0372427ece69b6 key_phase=false len=1324 pn=13 [2025-04-30T09:54:02.345900099Z TRACE quiche] 47117fb0437a3eccf70f732217bb4f96c1ccc0ee tx frm STREAM id=4 off=7344 len=1318 fin=false [2025-04-30T09:54:02.345908444Z TRACE quiche::recovery::congestion::recovery] 47117fb0437a3eccf70f732217bb4f96c1ccc0ee timer=91.365407ms latest_rtt=32.121201ms srtt=32.402793ms min_rtt=32.121201ms rttvar=12.246587ms cwnd=14850 ssthresh=18446744073709551615 bytes_in_flight=13500 app_limited=true congestion_recovery_start_time=None Rate { delivered: 2105, delivered_time: Instant { tv_sec: 672, tv_nsec: 132762777 }, first_sent_time: Instant { tv_sec: 672, tv_nsec: 100641576 }, end_of_app_limited: 0, last_sent_packet: 13, largest_acked: 2, rate_sample: RateSample { delivery_rate: 42028, is_app_limited: true, interval: 32.121201ms, delivered: 1350, prior_delivered: 755, prior_time: Some(Instant { tv_sec: 672, tv_nsec: 100641576 }), send_elapsed: 0ns, ack_elapsed: 32.121201ms, rtt: 32.121201ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 572867, last_update: Instant { tv_sec: 672, tv_nsec: 132823560 }, next_time: Instant { tv_sec: 672, tv_nsec: 132823560 }, 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.121201ms 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-30T09:54:02.345923082Z TRACE quiche] 47117fb0437a3eccf70f732217bb4f96c1ccc0ee pmtud probe status false hs_con=true hs_sent=true cwnd_avail=1350 out_len=1350 left=1324 [2025-04-30T09:54:02.345926217Z TRACE quiche] 47117fb0437a3eccf70f732217bb4f96c1ccc0ee tx pkt Short dcid=9f0372427ece69b6 key_phase=false len=1324 pn=14 [2025-04-30T09:54:02.345928612Z TRACE quiche] 47117fb0437a3eccf70f732217bb4f96c1ccc0ee tx frm STREAM id=4 off=8662 len=1318 fin=false [2025-04-30T09:54:02.345933330Z TRACE quiche::recovery::congestion::recovery] 47117fb0437a3eccf70f732217bb4f96c1ccc0ee timer=91.37747ms latest_rtt=32.121201ms srtt=32.402793ms min_rtt=32.121201ms rttvar=12.246587ms cwnd=14850 ssthresh=18446744073709551615 bytes_in_flight=14850 app_limited=false congestion_recovery_start_time=None Rate { delivered: 2105, delivered_time: Instant { tv_sec: 672, tv_nsec: 132762777 }, first_sent_time: Instant { tv_sec: 672, tv_nsec: 100641576 }, end_of_app_limited: 0, last_sent_packet: 14, largest_acked: 2, rate_sample: RateSample { delivery_rate: 42028, is_app_limited: true, interval: 32.121201ms, delivered: 1350, prior_delivered: 755, prior_time: Some(Instant { tv_sec: 672, tv_nsec: 100641576 }), send_elapsed: 0ns, ack_elapsed: 32.121201ms, rtt: 32.121201ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 572867, last_update: Instant { tv_sec: 672, tv_nsec: 132823560 }, next_time: Instant { tv_sec: 672, tv_nsec: 132823560 }, 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.121201ms 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-30T09:54:02.345950242Z TRACE quiche] 47117fb0437a3eccf70f732217bb4f96c1ccc0ee pmtud probe status false hs_con=true hs_sent=true cwnd_avail=0 out_len=1350 left=0 [2025-04-30T09:54:02.345953328Z TRACE quiche_server] 47117fb0437a3eccf70f732217bb4f96c1ccc0ee done writing [2025-04-30T09:54:02.345988573Z TRACE quiche_server] 47117fb0437a3eccf70f732217bb4f96c1ccc0ee written 2700 bytes with Some(SendInfo { from: [::]:443, to: [fd00:cafe:cafe::100]:48597, at: Instant { tv_sec: 672, tv_nsec: 132823560 } }) [2025-04-30T09:54:02.345994144Z TRACE quiche_server] Collecting garbage [2025-04-30T09:54:02.347741119Z TRACE quiche_server] got 55 bytes from [fd00:cafe:cafe::100]:48597 to [::]:443 [2025-04-30T09:54:02.347748994Z TRACE quiche_server] got packet Short dcid=47117fb0437a3eccf70f732217bb4f96c1ccc0ee key_phase=false [2025-04-30T09:54:02.347755276Z TRACE quiche] 47117fb0437a3eccf70f732217bb4f96c1ccc0ee rx pkt Short dcid=47117fb0437a3eccf70f732217bb4f96c1ccc0ee key_phase=false len=34 pn=3 [2025-04-30T09:54:02.347761317Z TRACE quiche] 47117fb0437a3eccf70f732217bb4f96c1ccc0ee rx frm ACK delay=3 blocks=[2..4] ecn_counts=None [2025-04-30T09:54:02.347765284Z TRACE quiche::recovery::congestion::recovery] 47117fb0437a3eccf70f732217bb4f96c1ccc0ee packet newly acked 3 [2025-04-30T09:54:02.347768350Z TRACE quiche::recovery::congestion::recovery] 47117fb0437a3eccf70f732217bb4f96c1ccc0ee packet newly acked 4 [2025-04-30T09:54:02.347772437Z TRACE quiche] 47117fb0437a3eccf70f732217bb4f96c1ccc0ee rx frm PADDING len=12 [2025-04-30T09:54:02.347783578Z TRACE quiche_server] 47117fb0437a3eccf70f732217bb4f96c1ccc0ee processed 55 bytes [2025-04-30T09:54:02.347788197Z TRACE quiche_server] recv() would block [2025-04-30T09:54:02.347793456Z TRACE quiche] 47117fb0437a3eccf70f732217bb4f96c1ccc0ee pmtud probe status false hs_con=true hs_sent=true cwnd_avail=5400 out_len=1350 left=1324 [2025-04-30T09:54:02.347798005Z TRACE quiche] 47117fb0437a3eccf70f732217bb4f96c1ccc0ee tx pkt Short dcid=9f0372427ece69b6 key_phase=false len=266 pn=15 [2025-04-30T09:54:02.347801081Z TRACE quiche] 47117fb0437a3eccf70f732217bb4f96c1ccc0ee tx frm STREAM id=4 off=9980 len=260 fin=true [2025-04-30T09:54:02.347808054Z TRACE quiche::recovery::congestion::recovery] 47117fb0437a3eccf70f732217bb4f96c1ccc0ee timer=80.952418ms latest_rtt=34.051237ms srtt=32.605847ms min_rtt=32.121201ms rttvar=9.591051ms cwnd=17550 ssthresh=18446744073709551615 bytes_in_flight=12442 app_limited=true congestion_recovery_start_time=None Rate { delivered: 4805, delivered_time: Instant { tv_sec: 672, tv_nsec: 134692813 }, first_sent_time: Instant { tv_sec: 672, tv_nsec: 100641576 }, end_of_app_limited: 0, last_sent_packet: 15, largest_acked: 4, rate_sample: RateSample { delivery_rate: 126084, is_app_limited: true, interval: 32.121201ms, delivered: 4050, prior_delivered: 755, prior_time: Some(Instant { tv_sec: 672, tv_nsec: 100641576 }), send_elapsed: 0ns, ack_elapsed: 32.121201ms, rtt: 32.121201ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 672808, last_update: Instant { tv_sec: 672, tv_nsec: 132823560 }, next_time: Instant { tv_sec: 672, tv_nsec: 132823560 }, 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.121201ms current_round_min_rtt=34.051237ms 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-04-30T09:54:02.347847107Z TRACE quiche_server] 47117fb0437a3eccf70f732217bb4f96c1ccc0ee written 292 bytes with Some(SendInfo { from: [::]:443, to: [fd00:cafe:cafe::100]:48597, at: Instant { tv_sec: 672, tv_nsec: 132823560 } }) [2025-04-30T09:54:02.347852777Z TRACE quiche_server] Collecting garbage [2025-04-30T09:54:02.347857306Z TRACE quiche_server] recv() would block [2025-04-30T09:54:02.347860341Z TRACE quiche_server] 47117fb0437a3eccf70f732217bb4f96c1ccc0ee done writing [2025-04-30T09:54:02.347863006Z TRACE quiche_server] Collecting garbage [2025-04-30T09:54:02.349967197Z TRACE quiche_server] got 55 bytes from [fd00:cafe:cafe::100]:48597 to [::]:443 [2025-04-30T09:54:02.349973960Z TRACE quiche_server] got packet Short dcid=47117fb0437a3eccf70f732217bb4f96c1ccc0ee key_phase=false [2025-04-30T09:54:02.349978919Z TRACE quiche] 47117fb0437a3eccf70f732217bb4f96c1ccc0ee rx pkt Short dcid=47117fb0437a3eccf70f732217bb4f96c1ccc0ee key_phase=false len=34 pn=4 [2025-04-30T09:54:02.349983768Z TRACE quiche] 47117fb0437a3eccf70f732217bb4f96c1ccc0ee rx frm ACK delay=2 blocks=[2..6] ecn_counts=None [2025-04-30T09:54:02.349987014Z TRACE quiche::recovery::congestion::recovery] 47117fb0437a3eccf70f732217bb4f96c1ccc0ee packet newly acked 5 [2025-04-30T09:54:02.349989328Z TRACE quiche::recovery::congestion::recovery] 47117fb0437a3eccf70f732217bb4f96c1ccc0ee packet newly acked 6 [2025-04-30T09:54:02.349992474Z TRACE quiche] 47117fb0437a3eccf70f732217bb4f96c1ccc0ee rx frm PADDING len=12 [2025-04-30T09:54:02.350001100Z TRACE quiche_server] 47117fb0437a3eccf70f732217bb4f96c1ccc0ee processed 55 bytes [2025-04-30T09:54:02.350004827Z TRACE quiche_server] recv() would block [2025-04-30T09:54:02.350007332Z TRACE quiche_server] 47117fb0437a3eccf70f732217bb4f96c1ccc0ee done writing [2025-04-30T09:54:02.350009516Z TRACE quiche_server] Collecting garbage [2025-04-30T09:54:02.352230013Z TRACE quiche_server] got 55 bytes from [fd00:cafe:cafe::100]:48597 to [::]:443 [2025-04-30T09:54:02.352237066Z TRACE quiche_server] got packet Short dcid=47117fb0437a3eccf70f732217bb4f96c1ccc0ee key_phase=false [2025-04-30T09:54:02.352242266Z TRACE quiche] 47117fb0437a3eccf70f732217bb4f96c1ccc0ee rx pkt Short dcid=47117fb0437a3eccf70f732217bb4f96c1ccc0ee key_phase=false len=34 pn=5 [2025-04-30T09:54:02.352247295Z TRACE quiche] 47117fb0437a3eccf70f732217bb4f96c1ccc0ee rx frm ACK delay=5 blocks=[2..8] ecn_counts=None [2025-04-30T09:54:02.352250892Z TRACE quiche::recovery::congestion::recovery] 47117fb0437a3eccf70f732217bb4f96c1ccc0ee packet newly acked 7 [2025-04-30T09:54:02.352253717Z TRACE quiche::recovery::congestion::recovery] 47117fb0437a3eccf70f732217bb4f96c1ccc0ee packet newly acked 8 [2025-04-30T09:54:02.352257134Z TRACE quiche] 47117fb0437a3eccf70f732217bb4f96c1ccc0ee rx frm PADDING len=12 [2025-04-30T09:54:02.352266751Z TRACE quiche_server] 47117fb0437a3eccf70f732217bb4f96c1ccc0ee processed 55 bytes [2025-04-30T09:54:02.352270999Z TRACE quiche_server] recv() would block [2025-04-30T09:54:02.352274095Z TRACE quiche_server] 47117fb0437a3eccf70f732217bb4f96c1ccc0ee done writing [2025-04-30T09:54:02.352276790Z TRACE quiche_server] Collecting garbage [2025-04-30T09:54:02.353866693Z TRACE quiche_server] got 55 bytes from [fd00:cafe:cafe::100]:48597 to [::]:443 [2025-04-30T09:54:02.353875319Z TRACE quiche_server] got packet Short dcid=47117fb0437a3eccf70f732217bb4f96c1ccc0ee key_phase=false [2025-04-30T09:54:02.353880589Z TRACE quiche] 47117fb0437a3eccf70f732217bb4f96c1ccc0ee rx pkt Short dcid=47117fb0437a3eccf70f732217bb4f96c1ccc0ee key_phase=false len=34 pn=6 [2025-04-30T09:54:02.353885418Z TRACE quiche] 47117fb0437a3eccf70f732217bb4f96c1ccc0ee rx frm ACK delay=5 blocks=[2..10] ecn_counts=None [2025-04-30T09:54:02.353888624Z TRACE quiche::recovery::congestion::recovery] 47117fb0437a3eccf70f732217bb4f96c1ccc0ee packet newly acked 9 [2025-04-30T09:54:02.353890868Z TRACE quiche::recovery::congestion::recovery] 47117fb0437a3eccf70f732217bb4f96c1ccc0ee packet newly acked 10 [2025-04-30T09:54:02.353894124Z TRACE quiche] 47117fb0437a3eccf70f732217bb4f96c1ccc0ee rx frm PADDING len=12 [2025-04-30T09:54:02.353911436Z TRACE quiche_server] 47117fb0437a3eccf70f732217bb4f96c1ccc0ee processed 55 bytes [2025-04-30T09:54:02.353915654Z TRACE quiche_server] recv() would block [2025-04-30T09:54:02.353918429Z TRACE quiche_server] 47117fb0437a3eccf70f732217bb4f96c1ccc0ee done writing [2025-04-30T09:54:02.353920643Z TRACE quiche_server] Collecting garbage [2025-04-30T09:54:02.355637362Z TRACE quiche_server] got 55 bytes from [fd00:cafe:cafe::100]:48597 to [::]:443 [2025-04-30T09:54:02.355644766Z TRACE quiche_server] got packet Short dcid=47117fb0437a3eccf70f732217bb4f96c1ccc0ee key_phase=false [2025-04-30T09:54:02.355650697Z TRACE quiche] 47117fb0437a3eccf70f732217bb4f96c1ccc0ee rx pkt Short dcid=47117fb0437a3eccf70f732217bb4f96c1ccc0ee key_phase=false len=34 pn=7 [2025-04-30T09:54:02.355656047Z TRACE quiche] 47117fb0437a3eccf70f732217bb4f96c1ccc0ee rx frm ACK delay=3 blocks=[2..12] ecn_counts=None [2025-04-30T09:54:02.355661207Z TRACE quiche::recovery::congestion::recovery] 47117fb0437a3eccf70f732217bb4f96c1ccc0ee packet newly acked 11 [2025-04-30T09:54:02.355664463Z TRACE quiche::recovery::congestion::recovery] 47117fb0437a3eccf70f732217bb4f96c1ccc0ee packet newly acked 12 [2025-04-30T09:54:02.355668851Z TRACE quiche] 47117fb0437a3eccf70f732217bb4f96c1ccc0ee rx frm PADDING len=12 [2025-04-30T09:54:02.355693327Z TRACE quiche_server] 47117fb0437a3eccf70f732217bb4f96c1ccc0ee processed 55 bytes [2025-04-30T09:54:02.355697705Z TRACE quiche_server] recv() would block [2025-04-30T09:54:02.355700861Z TRACE quiche_server] 47117fb0437a3eccf70f732217bb4f96c1ccc0ee done writing [2025-04-30T09:54:02.355703526Z TRACE quiche_server] Collecting garbage [2025-04-30T09:54:02.378645564Z TRACE quiche_server] got 55 bytes from [fd00:cafe:cafe::100]:48597 to [::]:443 [2025-04-30T09:54:02.378659029Z TRACE quiche_server] got packet Short dcid=47117fb0437a3eccf70f732217bb4f96c1ccc0ee key_phase=false [2025-04-30T09:54:02.378667625Z TRACE quiche] 47117fb0437a3eccf70f732217bb4f96c1ccc0ee rx pkt Short dcid=47117fb0437a3eccf70f732217bb4f96c1ccc0ee key_phase=false len=34 pn=8 [2025-04-30T09:54:02.378675470Z TRACE quiche] 47117fb0437a3eccf70f732217bb4f96c1ccc0ee rx frm ACK delay=3 blocks=[2..14] ecn_counts=None [2025-04-30T09:54:02.378680769Z TRACE quiche::recovery::congestion::recovery] 47117fb0437a3eccf70f732217bb4f96c1ccc0ee packet newly acked 13 [2025-04-30T09:54:02.378683945Z TRACE quiche::recovery::congestion::recovery] 47117fb0437a3eccf70f732217bb4f96c1ccc0ee packet newly acked 14 [2025-04-30T09:54:02.378688644Z TRACE quiche] 47117fb0437a3eccf70f732217bb4f96c1ccc0ee rx frm PADDING len=12 [2025-04-30T09:54:02.378704033Z TRACE quiche_server] 47117fb0437a3eccf70f732217bb4f96c1ccc0ee processed 55 bytes [2025-04-30T09:54:02.378709903Z TRACE quiche_server] recv() would block [2025-04-30T09:54:02.378713641Z TRACE quiche_server] 47117fb0437a3eccf70f732217bb4f96c1ccc0ee done writing [2025-04-30T09:54:02.378716616Z TRACE quiche_server] Collecting garbage [2025-04-30T09:54:02.378897733Z TRACE quiche_server] got 46 bytes from [fd00:cafe:cafe::100]:48597 to [::]:443 [2025-04-30T09:54:02.378902442Z TRACE quiche_server] got packet Short dcid=47117fb0437a3eccf70f732217bb4f96c1ccc0ee key_phase=false [2025-04-30T09:54:02.378907842Z TRACE quiche] 47117fb0437a3eccf70f732217bb4f96c1ccc0ee rx pkt Short dcid=47117fb0437a3eccf70f732217bb4f96c1ccc0ee key_phase=false len=25 pn=9 [2025-04-30T09:54:02.378913042Z TRACE quiche] 47117fb0437a3eccf70f732217bb4f96c1ccc0ee rx frm ACK delay=7 blocks=[2..15] ecn_counts=None [2025-04-30T09:54:02.378916669Z TRACE quiche::recovery::congestion::recovery] 47117fb0437a3eccf70f732217bb4f96c1ccc0ee packet newly acked 15 [2025-04-30T09:54:02.378921047Z TRACE quiche] 47117fb0437a3eccf70f732217bb4f96c1ccc0ee rx frm APPLICATION_CLOSE err=0 reason=[] [2025-04-30T09:54:02.378932448Z TRACE quiche_server] 47117fb0437a3eccf70f732217bb4f96c1ccc0ee processed 46 bytes [2025-04-30T09:54:02.378936796Z TRACE quiche_server] recv() would block [2025-04-30T09:54:02.378939652Z TRACE quiche_server] 47117fb0437a3eccf70f732217bb4f96c1ccc0ee done writing [2025-04-30T09:54:02.378948929Z TRACE quiche_server] Collecting garbage [2025-04-30T09:54:02.545182998Z TRACE quiche_server] timed out [2025-04-30T09:54:02.545216490Z TRACE quiche] 47117fb0437a3eccf70f732217bb4f96c1ccc0ee draining timeout expired [2025-04-30T09:54:02.545263488Z TRACE quiche_server] 47117fb0437a3eccf70f732217bb4f96c1ccc0ee done writing [2025-04-30T09:54:02.545267245Z TRACE quiche_server] Collecting garbage [2025-04-30T09:54:02.545271383Z INFO quiche_server] 47117fb0437a3eccf70f732217bb4f96c1ccc0ee connection collected recv=12 sent=16 lost=0 retrans=0 sent_bytes=17437 recv_bytes=2258 lost_bytes=0 [local_addr=[::]:443 peer_addr=[fd00:cafe:cafe::100]:48597 validation_state=Validated active=true recv=12 sent=16 lost=0 retrans=0 rtt=34.855693ms min_rtt=Some(32.121201ms) rttvar=5.113613ms cwnd=17550 sent_bytes=17437 recv_bytes=2258 lost_bytes=0 stream_retrans_bytes=0 pmtu=1350 delivery_rate=386613]