[2025-04-30T10:41:25.913285612Z INFO quiche_server] listening on [::]:443 [2025-04-30T10:41:25.913306551Z TRACE mio::poll] registering event source with poller: token=Token(0), interests=READABLE [2025-04-30T10:41:25.913313013Z TRACE quiche_server] GSO detected: false [2025-04-30T10:41:26.721644235Z TRACE quiche_server] got 1207 bytes from [::ffff:193.167.100.2]:40743 to [::]:443 [2025-04-30T10:41:26.721677928Z TRACE quiche_server] got packet Initial version=57414954 dcid= scid= token= [2025-04-30T10:41:26.721688879Z WARN quiche_server] Doing version negotiation [2025-04-30T10:41:26.721783717Z TRACE quiche_server] got 1207 bytes from [::ffff:193.167.100.2]:40743 to [::]:443 [2025-04-30T10:41:26.721794427Z TRACE quiche_server] got packet Initial version=57414954 dcid= scid= token= [2025-04-30T10:41:26.721800549Z WARN quiche_server] Doing version negotiation [2025-04-30T10:41:26.721835655Z TRACE quiche_server] got 1207 bytes from [::ffff:193.167.100.2]:40743 to [::]:443 [2025-04-30T10:41:26.721842888Z TRACE quiche_server] got packet Initial version=57414954 dcid= scid= token= [2025-04-30T10:41:26.721848519Z WARN quiche_server] Doing version negotiation [2025-04-30T10:41:26.721882463Z TRACE quiche_server] recv() would block [2025-04-30T10:41:26.952589135Z TRACE quiche_server] got 1200 bytes from [fd00:cafe:cafe::100]:52611 to [::]:443 [2025-04-30T10:41:26.952614172Z TRACE quiche_server] got packet Initial version=1 dcid=2daeab91a0b92616be9faaa358e6ff26f06f84fd scid=c4c1f6c2daf7db5c token= [2025-04-30T10:41:26.952625333Z DEBUG quiche_server] New connection: dcid=2daeab91a0b92616be9faaa358e6ff26f06f84fd scid=cdedf144d7d63e508ccfa76157cd7d2d2eefeee5 [2025-04-30T10:41:26.952834787Z TRACE quiche] cdedf144d7d63e508ccfa76157cd7d2d2eefeee5 rx pkt Initial version=1 dcid=2daeab91a0b92616be9faaa358e6ff26f06f84fd scid=c4c1f6c2daf7db5c token= len=1162 pn=0 [2025-04-30T10:41:26.952849876Z TRACE quiche] cdedf144d7d63e508ccfa76157cd7d2d2eefeee5 rx frm CRYPTO off=0 len=248 [2025-04-30T10:41:26.952877999Z TRACE quiche::tls] checking peer ALPN Ok("hq-interop") against Ok("h3") [2025-04-30T10:41:26.952882878Z TRACE quiche::tls] checking peer ALPN Ok("hq-interop") against Ok("hq-interop") [2025-04-30T10:41:26.952989839Z TRACE quiche::tls] cdedf144d7d63e508ccfa76157cd7d2d2eefeee5 write message lvl=Initial len=90 [2025-04-30T10:41:26.953020657Z TRACE quiche::tls] cdedf144d7d63e508ccfa76157cd7d2d2eefeee5 set write secret lvl=Handshake [2025-04-30T10:41:26.953099105Z TRACE quiche::tls] cdedf144d7d63e508ccfa76157cd7d2d2eefeee5 write message lvl=Handshake len=708 [2025-04-30T10:41:26.953102912Z TRACE quiche::tls] cdedf144d7d63e508ccfa76157cd7d2d2eefeee5 set write secret lvl=OneRTT [2025-04-30T10:41:26.953110937Z TRACE quiche::tls] cdedf144d7d63e508ccfa76157cd7d2d2eefeee5 set read secret lvl=Handshake [2025-04-30T10:41:26.953133570Z TRACE quiche] cdedf144d7d63e508ccfa76157cd7d2d2eefeee5 rx frm PADDING len=893 [2025-04-30T10:41:26.953157194Z TRACE quiche_server] cdedf144d7d63e508ccfa76157cd7d2d2eefeee5 processed 1200 bytes [2025-04-30T10:41:26.953179877Z TRACE quiche_server] recv() would block [2025-04-30T10:41:26.953193462Z TRACE quiche] cdedf144d7d63e508ccfa76157cd7d2d2eefeee5 tx pkt Initial version=1 dcid=c4c1f6c2daf7db5c scid=cdedf144d7d63e508ccfa76157cd7d2d2eefeee5 len=99 pn=0 [2025-04-30T10:41:26.953197860Z TRACE quiche] cdedf144d7d63e508ccfa76157cd7d2d2eefeee5 tx frm ACK delay=47 blocks=[0..0] ecn_counts=None [2025-04-30T10:41:26.953203521Z TRACE quiche] cdedf144d7d63e508ccfa76157cd7d2d2eefeee5 tx frm CRYPTO off=0 len=90 [2025-04-30T10:41:26.953214832Z TRACE quiche::recovery::congestion::recovery] cdedf144d7d63e508ccfa76157cd7d2d2eefeee5 timer=998.967349ms latest_rtt=0ns srtt=333ms min_rtt=333ms rttvar=166.5ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=154 app_limited=true congestion_recovery_start_time=None Rate { delivered: 0, delivered_time: Instant { tv_sec: 578, tv_nsec: 304737907 }, first_sent_time: Instant { tv_sec: 578, tv_nsec: 304737907 }, 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: 578, tv_nsec: 304737907 }, next_time: Instant { tv_sec: 578, tv_nsec: 304737907 }, max_datagram_size: 1350, last_packet_size: None, iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } [2025-04-30T10:41:26.953256862Z TRACE quiche] cdedf144d7d63e508ccfa76157cd7d2d2eefeee5 tx pkt Handshake version=1 dcid=c4c1f6c2daf7db5c scid=cdedf144d7d63e508ccfa76157cd7d2d2eefeee5 len=712 pn=1 [2025-04-30T10:41:26.953262222Z TRACE quiche] cdedf144d7d63e508ccfa76157cd7d2d2eefeee5 tx frm CRYPTO off=0 len=708 [2025-04-30T10:41:26.953269465Z TRACE quiche::recovery::congestion::recovery] cdedf144d7d63e508ccfa76157cd7d2d2eefeee5 timer=998.913047ms latest_rtt=0ns srtt=333ms min_rtt=333ms rttvar=166.5ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=920 app_limited=true congestion_recovery_start_time=None Rate { delivered: 0, delivered_time: Instant { tv_sec: 578, tv_nsec: 304737907 }, first_sent_time: Instant { tv_sec: 578, tv_nsec: 304737907 }, 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: 578, tv_nsec: 304737907 }, next_time: Instant { tv_sec: 578, tv_nsec: 304737907 }, max_datagram_size: 1350, last_packet_size: None, iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } [2025-04-30T10:41:26.953315712Z TRACE quiche_server] cdedf144d7d63e508ccfa76157cd7d2d2eefeee5 written 1200 bytes with Some(SendInfo { from: [::]:443, to: [fd00:cafe:cafe::100]:52611, at: Instant { tv_sec: 578, tv_nsec: 304737907 } }) [2025-04-30T10:41:26.953323236Z TRACE quiche_server] Collecting garbage [2025-04-30T10:41:26.953332063Z TRACE quiche_server] recv() would block [2025-04-30T10:41:26.953338745Z TRACE quiche_server] cdedf144d7d63e508ccfa76157cd7d2d2eefeee5 done writing [2025-04-30T10:41:26.953343525Z TRACE quiche_server] Collecting garbage [2025-04-30T10:41:26.987255032Z TRACE quiche_server] got 1200 bytes from [fd00:cafe:cafe::100]:52611 to [::]:443 [2025-04-30T10:41:26.987270231Z TRACE quiche_server] got packet Initial version=1 dcid=cdedf144d7d63e508ccfa76157cd7d2d2eefeee5 scid=c4c1f6c2daf7db5c token= [2025-04-30T10:41:26.987279659Z TRACE quiche] cdedf144d7d63e508ccfa76157cd7d2d2eefeee5 rx pkt Initial version=1 dcid=cdedf144d7d63e508ccfa76157cd7d2d2eefeee5 scid=c4c1f6c2daf7db5c token= len=977 pn=1 [2025-04-30T10:41:26.987288065Z TRACE quiche] cdedf144d7d63e508ccfa76157cd7d2d2eefeee5 rx frm ACK delay=171 blocks=[0..0] ecn_counts=None [2025-04-30T10:41:26.987293445Z TRACE quiche::recovery::congestion::recovery] cdedf144d7d63e508ccfa76157cd7d2d2eefeee5 packet newly acked 0 [2025-04-30T10:41:26.987302582Z TRACE quiche] cdedf144d7d63e508ccfa76157cd7d2d2eefeee5 rx frm PADDING len=953 [2025-04-30T10:41:26.987318171Z TRACE quiche] cdedf144d7d63e508ccfa76157cd7d2d2eefeee5 rx pkt Handshake version=1 dcid=cdedf144d7d63e508ccfa76157cd7d2d2eefeee5 scid=c4c1f6c2daf7db5c len=62 pn=2 [2025-04-30T10:41:26.987324002Z TRACE quiche] cdedf144d7d63e508ccfa76157cd7d2d2eefeee5 rx frm ACK delay=88 blocks=[1..1] ecn_counts=None [2025-04-30T10:41:26.987327629Z TRACE quiche::recovery::congestion::recovery] cdedf144d7d63e508ccfa76157cd7d2d2eefeee5 packet newly acked 1 [2025-04-30T10:41:26.987338880Z TRACE quiche] cdedf144d7d63e508ccfa76157cd7d2d2eefeee5 rx frm CRYPTO off=0 len=36 [2025-04-30T10:41:26.987351083Z TRACE quiche::tls] cdedf144d7d63e508ccfa76157cd7d2d2eefeee5 set read secret lvl=OneRTT [2025-04-30T10:41:26.987385909Z TRACE quiche::tls] cdedf144d7d63e508ccfa76157cd7d2d2eefeee5 write message lvl=OneRTT len=396 [2025-04-30T10:41:26.987394184Z TRACE quiche] cdedf144d7d63e508ccfa76157cd7d2d2eefeee5 dropped epoch 1 state [2025-04-30T10:41:26.987398622Z TRACE quiche] cdedf144d7d63e508ccfa76157cd7d2d2eefeee5 connection established: proto=Ok("hq-interop") cipher=Some(AES128_GCM) curve=Some("X25519") sigalg=None resumed=false TransportParams { original_destination_connection_id: None, max_idle_timeout: 30000, stateless_reset_token: None, max_udp_payload_size: 65527, initial_max_data: 15728640, initial_max_stream_data_bidi_local: 6291456, initial_max_stream_data_bidi_remote: 0, initial_max_stream_data_uni: 32768, 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: 8, initial_source_connection_id: Some(c4c1f6c2daf7db5c), retry_source_connection_id: None, max_datagram_frame_size: None, unknown_params: None } [2025-04-30T10:41:26.987420403Z TRACE quiche] cdedf144d7d63e508ccfa76157cd7d2d2eefeee5 dropped epoch 0 state [2025-04-30T10:41:26.987424651Z TRACE quiche] cdedf144d7d63e508ccfa76157cd7d2d2eefeee5 rx pkt Short dcid=cdedf144d7d63e508ccfa76157cd7d2d2eefeee5 key_phase=false len=65 pn=3 [2025-04-30T10:41:26.987432016Z TRACE quiche] cdedf144d7d63e508ccfa76157cd7d2d2eefeee5 rx frm NEW_CONNECTION_ID seq_num=1 retire_prior_to=0 conn_id=[fe, 77, 2f, 9b, e3, 04, b0, 42] reset_token=[8d, 89, 51, 95, 9e, 14, 01, 8e, 4f, fd, d3, 05, 58, b4, 54, 15] [2025-04-30T10:41:26.987439359Z TRACE quiche] cdedf144d7d63e508ccfa76157cd7d2d2eefeee5 rx frm STREAM id=0 off=0 len=17 fin=true [2025-04-30T10:41:26.987480447Z TRACE quiche_server] cdedf144d7d63e508ccfa76157cd7d2d2eefeee5 processed 1200 bytes [2025-04-30T10:41:26.987489934Z DEBUG quiche_apps::common] cdedf144d7d63e508ccfa76157cd7d2d2eefeee5 response stream 0 is writable with capacity Ok(13500) [2025-04-30T10:41:26.987498100Z TRACE quiche_apps::common] cdedf144d7d63e508ccfa76157cd7d2d2eefeee5 received 17 bytes [2025-04-30T10:41:26.987501446Z TRACE quiche_apps::common] cdedf144d7d63e508ccfa76157cd7d2d2eefeee5 stream 0 has 17 bytes (fin? true) [2025-04-30T10:41:26.987506395Z INFO quiche_apps::common] cdedf144d7d63e508ccfa76157cd7d2d2eefeee5 got GET request for "/www/ynhkfjfvvv" on stream 0 [2025-04-30T10:41:26.987531693Z INFO quiche_apps::common] cdedf144d7d63e508ccfa76157cd7d2d2eefeee5 sending response of size 5120 on stream 0 [2025-04-30T10:41:26.987541722Z TRACE quiche_server] recv() would block [2025-04-30T10:41:26.987550488Z TRACE quiche] cdedf144d7d63e508ccfa76157cd7d2d2eefeee5 pmtud probe status false hs_con=true hs_sent=false cwnd_avail=13500 out_len=1350 left=1319 [2025-04-30T10:41:26.987560327Z TRACE quiche] cdedf144d7d63e508ccfa76157cd7d2d2eefeee5 tx pkt Short dcid=c4c1f6c2daf7db5c key_phase=false len=1324 pn=2 [2025-04-30T10:41:26.987564134Z TRACE quiche] cdedf144d7d63e508ccfa76157cd7d2d2eefeee5 tx frm ACK delay=15 blocks=[3..3] ecn_counts=None [2025-04-30T10:41:26.987568242Z TRACE quiche] cdedf144d7d63e508ccfa76157cd7d2d2eefeee5 tx frm NEW_CONNECTION_ID seq_num=1 retire_prior_to=0 conn_id=[f4, 0a, 45, ae, 90, 1f, b0, 74, 6d, 60, e1, a8, 25, 7b, 87, 36, 03, a1, 01, 4a] reset_token=[ab, 8d, 17, cd, 09, b4, e1, 38, 10, c4, 53, 0a, 3c, de, 7b, 34] [2025-04-30T10:41:26.987576327Z TRACE quiche] cdedf144d7d63e508ccfa76157cd7d2d2eefeee5 tx frm NEW_CONNECTION_ID seq_num=2 retire_prior_to=0 conn_id=[7a, 31, 0d, 60, 8c, b9, f3, 75, 68, 05, 84, bb, 3d, b0, 34, 57, fa, 12, d5, 24] reset_token=[2e, 2e, d0, 50, a4, b9, 95, 7c, 5f, 92, fe, 53, 3b, fc, 36, 98] [2025-04-30T10:41:26.987583480Z TRACE quiche] cdedf144d7d63e508ccfa76157cd7d2d2eefeee5 tx frm NEW_CONNECTION_ID seq_num=3 retire_prior_to=0 conn_id=[ee, db, d5, f9, 17, c0, c4, 33, e6, 4d, 81, 9b, 9f, ec, ef, 05, c2, 8f, c7, 2f] reset_token=[10, 44, 9f, cb, fa, 29, c5, e9, 5d, fc, 2d, e8, eb, 4b, 3f, 67] [2025-04-30T10:41:26.987596585Z TRACE quiche] cdedf144d7d63e508ccfa76157cd7d2d2eefeee5 tx frm NEW_CONNECTION_ID seq_num=4 retire_prior_to=0 conn_id=[15, 96, 64, 7a, 84, 77, 6f, 52, 68, e2, fa, 8e, 13, af, 6f, bb, 03, f4, c3, 64] reset_token=[47, f5, a4, 0e, c2, a5, 06, 49, 48, 85, 51, 40, a9, 89, 6a, cd] [2025-04-30T10:41:26.987603678Z TRACE quiche] cdedf144d7d63e508ccfa76157cd7d2d2eefeee5 tx frm NEW_CONNECTION_ID seq_num=5 retire_prior_to=0 conn_id=[df, 68, 71, 66, 4b, f0, aa, f1, 63, 0a, 73, 9e, bd, 7b, 09, 68, a5, 03, ad, 5a] reset_token=[6a, 1c, b8, 6d, 5e, 0c, 4f, bf, 15, dd, 96, 15, 10, 5d, 28, 73] [2025-04-30T10:41:26.987610541Z TRACE quiche] cdedf144d7d63e508ccfa76157cd7d2d2eefeee5 tx frm NEW_CONNECTION_ID seq_num=6 retire_prior_to=0 conn_id=[11, 1b, 54, 79, a8, 33, 14, e4, 0a, ce, 33, 8d, da, 80, fc, b9, ef, 47, 74, 25] reset_token=[d6, 5a, 51, 8b, 3f, 2a, b7, 47, 3f, 8a, 1d, 4f, 96, d4, e6, 8c] [2025-04-30T10:41:26.987617344Z TRACE quiche] cdedf144d7d63e508ccfa76157cd7d2d2eefeee5 tx frm NEW_CONNECTION_ID seq_num=7 retire_prior_to=0 conn_id=[0c, 0f, dc, 01, 0d, c2, 8d, 76, b7, 33, 16, ca, 6e, b0, b9, a5, 1e, bc, ab, 41] reset_token=[af, 0a, f6, 8a, f2, 01, dc, d0, 1c, 8c, a4, fd, 17, 20, 2d, 64] [2025-04-30T10:41:26.987624478Z TRACE quiche] cdedf144d7d63e508ccfa76157cd7d2d2eefeee5 tx frm HANDSHAKE_DONE [2025-04-30T10:41:26.987627583Z TRACE quiche] cdedf144d7d63e508ccfa76157cd7d2d2eefeee5 tx frm CRYPTO off=0 len=396 [2025-04-30T10:41:26.987630779Z TRACE quiche] cdedf144d7d63e508ccfa76157cd7d2d2eefeee5 tx frm STREAM id=0 off=0 len=633 fin=false [2025-04-30T10:41:26.987646178Z TRACE quiche::recovery::congestion::recovery] cdedf144d7d63e508ccfa76157cd7d2d2eefeee5 timer=110.179711ms latest_rtt=34.134547ms srtt=34.099699ms min_rtt=34.094722ms rttvar=12.795476ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=1350 app_limited=true congestion_recovery_start_time=None Rate { delivered: 920, delivered_time: Instant { tv_sec: 578, tv_nsec: 339099862 }, first_sent_time: Instant { tv_sec: 578, tv_nsec: 339099862 }, end_of_app_limited: 1, last_sent_packet: 2, largest_acked: 1, rate_sample: RateSample { delivery_rate: 26983, is_app_limited: true, interval: 34.094722ms, delivered: 920, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 578, tv_nsec: 304737907 }), send_elapsed: 0ns, ack_elapsed: 34.094722ms, rtt: 34.094722ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 494872, last_update: Instant { tv_sec: 578, tv_nsec: 339099862 }, next_time: Instant { tv_sec: 578, tv_nsec: 339099862 }, max_datagram_size: 1350, last_packet_size: Some(0), iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } [2025-04-30T10:41:26.987664834Z TRACE quiche] cdedf144d7d63e508ccfa76157cd7d2d2eefeee5 pmtud probe status false hs_con=true hs_sent=true cwnd_avail=12150 out_len=1350 left=1324 [2025-04-30T10:41:26.987669652Z TRACE quiche] cdedf144d7d63e508ccfa76157cd7d2d2eefeee5 tx pkt Short dcid=c4c1f6c2daf7db5c key_phase=false len=1324 pn=3 [2025-04-30T10:41:26.987672969Z TRACE quiche] cdedf144d7d63e508ccfa76157cd7d2d2eefeee5 tx frm STREAM id=0 off=633 len=1318 fin=false [2025-04-30T10:41:26.987679591Z TRACE quiche::recovery::congestion::recovery] cdedf144d7d63e508ccfa76157cd7d2d2eefeee5 timer=110.264211ms latest_rtt=34.134547ms srtt=34.099699ms min_rtt=34.094722ms rttvar=12.795476ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=2700 app_limited=true congestion_recovery_start_time=None Rate { delivered: 920, delivered_time: Instant { tv_sec: 578, tv_nsec: 339099862 }, first_sent_time: Instant { tv_sec: 578, tv_nsec: 339099862 }, end_of_app_limited: 2, last_sent_packet: 3, largest_acked: 1, rate_sample: RateSample { delivery_rate: 26983, is_app_limited: true, interval: 34.094722ms, delivered: 920, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 578, tv_nsec: 304737907 }), send_elapsed: 0ns, ack_elapsed: 34.094722ms, rtt: 34.094722ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 494872, last_update: Instant { tv_sec: 578, tv_nsec: 339099862 }, next_time: Instant { tv_sec: 578, tv_nsec: 339099862 }, max_datagram_size: 1350, last_packet_size: Some(0), iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } [2025-04-30T10:41:26.987698106Z TRACE quiche] cdedf144d7d63e508ccfa76157cd7d2d2eefeee5 pmtud probe status false hs_con=true hs_sent=true cwnd_avail=10800 out_len=1350 left=1324 [2025-04-30T10:41:26.987702224Z TRACE quiche] cdedf144d7d63e508ccfa76157cd7d2d2eefeee5 tx pkt Short dcid=c4c1f6c2daf7db5c key_phase=false len=1324 pn=4 [2025-04-30T10:41:26.987705380Z TRACE quiche] cdedf144d7d63e508ccfa76157cd7d2d2eefeee5 tx frm STREAM id=0 off=1951 len=1318 fin=false [2025-04-30T10:41:26.987711341Z TRACE quiche::recovery::congestion::recovery] cdedf144d7d63e508ccfa76157cd7d2d2eefeee5 timer=110.266415ms latest_rtt=34.134547ms srtt=34.099699ms min_rtt=34.094722ms rttvar=12.795476ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=4050 app_limited=true congestion_recovery_start_time=None Rate { delivered: 920, delivered_time: Instant { tv_sec: 578, tv_nsec: 339099862 }, first_sent_time: Instant { tv_sec: 578, tv_nsec: 339099862 }, end_of_app_limited: 3, last_sent_packet: 4, largest_acked: 1, rate_sample: RateSample { delivery_rate: 26983, is_app_limited: true, interval: 34.094722ms, delivered: 920, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 578, tv_nsec: 304737907 }), send_elapsed: 0ns, ack_elapsed: 34.094722ms, rtt: 34.094722ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 494872, last_update: Instant { tv_sec: 578, tv_nsec: 339099862 }, next_time: Instant { tv_sec: 578, tv_nsec: 339099862 }, max_datagram_size: 1350, last_packet_size: Some(0), iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } [2025-04-30T10:41:26.987721680Z TRACE quiche] cdedf144d7d63e508ccfa76157cd7d2d2eefeee5 pmtud probe status false hs_con=true hs_sent=true cwnd_avail=9450 out_len=1350 left=1324 [2025-04-30T10:41:26.987724616Z TRACE quiche] cdedf144d7d63e508ccfa76157cd7d2d2eefeee5 tx pkt Short dcid=c4c1f6c2daf7db5c key_phase=false len=1324 pn=5 [2025-04-30T10:41:26.987726950Z TRACE quiche] cdedf144d7d63e508ccfa76157cd7d2d2eefeee5 tx frm STREAM id=0 off=3269 len=1318 fin=false [2025-04-30T10:41:26.987731108Z TRACE quiche::recovery::congestion::recovery] cdedf144d7d63e508ccfa76157cd7d2d2eefeee5 timer=110.271053ms latest_rtt=34.134547ms srtt=34.099699ms min_rtt=34.094722ms rttvar=12.795476ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=5400 app_limited=true congestion_recovery_start_time=None Rate { delivered: 920, delivered_time: Instant { tv_sec: 578, tv_nsec: 339099862 }, first_sent_time: Instant { tv_sec: 578, tv_nsec: 339099862 }, end_of_app_limited: 4, last_sent_packet: 5, largest_acked: 1, rate_sample: RateSample { delivery_rate: 26983, is_app_limited: true, interval: 34.094722ms, delivered: 920, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 578, tv_nsec: 304737907 }), send_elapsed: 0ns, ack_elapsed: 34.094722ms, rtt: 34.094722ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 494872, last_update: Instant { tv_sec: 578, tv_nsec: 339099862 }, next_time: Instant { tv_sec: 578, tv_nsec: 339099862 }, max_datagram_size: 1350, last_packet_size: Some(0), iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } [2025-04-30T10:41:26.987742950Z TRACE quiche] cdedf144d7d63e508ccfa76157cd7d2d2eefeee5 pmtud probe status false hs_con=true hs_sent=true cwnd_avail=8100 out_len=1350 left=1324 [2025-04-30T10:41:26.987745856Z TRACE quiche] cdedf144d7d63e508ccfa76157cd7d2d2eefeee5 tx pkt Short dcid=c4c1f6c2daf7db5c key_phase=false len=539 pn=6 [2025-04-30T10:41:26.987748200Z TRACE quiche] cdedf144d7d63e508ccfa76157cd7d2d2eefeee5 tx frm STREAM id=0 off=4587 len=533 fin=true [2025-04-30T10:41:26.987753089Z TRACE quiche::recovery::congestion::recovery] cdedf144d7d63e508ccfa76157cd7d2d2eefeee5 timer=110.270242ms latest_rtt=34.134547ms srtt=34.099699ms min_rtt=34.094722ms rttvar=12.795476ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=5965 app_limited=true congestion_recovery_start_time=None Rate { delivered: 920, delivered_time: Instant { tv_sec: 578, tv_nsec: 339099862 }, first_sent_time: Instant { tv_sec: 578, tv_nsec: 339099862 }, end_of_app_limited: 5, last_sent_packet: 6, largest_acked: 1, rate_sample: RateSample { delivery_rate: 26983, is_app_limited: true, interval: 34.094722ms, delivered: 920, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 578, tv_nsec: 304737907 }), send_elapsed: 0ns, ack_elapsed: 34.094722ms, rtt: 34.094722ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 494872, last_update: Instant { tv_sec: 578, tv_nsec: 339099862 }, next_time: Instant { tv_sec: 578, tv_nsec: 339099862 }, max_datagram_size: 1350, last_packet_size: Some(0), iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } [2025-04-30T10:41:26.987818813Z TRACE quiche_server] cdedf144d7d63e508ccfa76157cd7d2d2eefeee5 written 5965 bytes with Some(SendInfo { from: [::]:443, to: [fd00:cafe:cafe::100]:52611, at: Instant { tv_sec: 578, tv_nsec: 339099862 } }) [2025-04-30T10:41:26.987827569Z TRACE quiche_server] Collecting garbage [2025-04-30T10:41:26.987834102Z TRACE quiche_server] recv() would block [2025-04-30T10:41:26.987838470Z TRACE quiche_server] cdedf144d7d63e508ccfa76157cd7d2d2eefeee5 done writing [2025-04-30T10:41:26.987842197Z TRACE quiche_server] Collecting garbage [2025-04-30T10:41:27.020545407Z TRACE quiche_server] got 44 bytes from [fd00:cafe:cafe::100]:52611 to [::]:443 [2025-04-30T10:41:27.020559253Z TRACE quiche_server] got packet Short dcid=cdedf144d7d63e508ccfa76157cd7d2d2eefeee5 key_phase=false [2025-04-30T10:41:27.020566887Z TRACE quiche] cdedf144d7d63e508ccfa76157cd7d2d2eefeee5 rx pkt Short dcid=cdedf144d7d63e508ccfa76157cd7d2d2eefeee5 key_phase=false len=23 pn=4 [2025-04-30T10:41:27.020574462Z TRACE quiche] cdedf144d7d63e508ccfa76157cd7d2d2eefeee5 rx frm ACK delay=6 blocks=[2..3] ecn_counts=None [2025-04-30T10:41:27.020579431Z TRACE quiche::recovery::congestion::recovery] cdedf144d7d63e508ccfa76157cd7d2d2eefeee5 packet newly acked 2 [2025-04-30T10:41:27.020583539Z TRACE quiche::recovery::congestion::recovery] cdedf144d7d63e508ccfa76157cd7d2d2eefeee5 packet newly acked 3 [2025-04-30T10:41:27.020623013Z TRACE quiche_server] cdedf144d7d63e508ccfa76157cd7d2d2eefeee5 processed 44 bytes [2025-04-30T10:41:27.020629265Z TRACE quiche_server] recv() would block [2025-04-30T10:41:27.020633332Z TRACE quiche_server] cdedf144d7d63e508ccfa76157cd7d2d2eefeee5 done writing [2025-04-30T10:41:27.020636398Z TRACE quiche_server] Collecting garbage [2025-04-30T10:41:27.022807012Z TRACE quiche_server] got 44 bytes from [fd00:cafe:cafe::100]:52611 to [::]:443 [2025-04-30T10:41:27.022818584Z TRACE quiche_server] got packet Short dcid=cdedf144d7d63e508ccfa76157cd7d2d2eefeee5 key_phase=false [2025-04-30T10:41:27.022825056Z TRACE quiche] cdedf144d7d63e508ccfa76157cd7d2d2eefeee5 rx pkt Short dcid=cdedf144d7d63e508ccfa76157cd7d2d2eefeee5 key_phase=false len=23 pn=5 [2025-04-30T10:41:27.022837079Z TRACE quiche] cdedf144d7d63e508ccfa76157cd7d2d2eefeee5 rx frm ACK delay=8 blocks=[2..5] ecn_counts=None [2025-04-30T10:41:27.022841447Z TRACE quiche::recovery::congestion::recovery] cdedf144d7d63e508ccfa76157cd7d2d2eefeee5 packet newly acked 4 [2025-04-30T10:41:27.022844423Z TRACE quiche::recovery::congestion::recovery] cdedf144d7d63e508ccfa76157cd7d2d2eefeee5 packet newly acked 5 [2025-04-30T10:41:27.022857387Z TRACE quiche_server] cdedf144d7d63e508ccfa76157cd7d2d2eefeee5 processed 44 bytes [2025-04-30T10:41:27.022862397Z TRACE quiche_server] recv() would block [2025-04-30T10:41:27.022865943Z TRACE quiche_server] cdedf144d7d63e508ccfa76157cd7d2d2eefeee5 done writing [2025-04-30T10:41:27.022868728Z TRACE quiche_server] Collecting garbage [2025-04-30T10:41:27.023385631Z TRACE quiche_server] got 64 bytes from [fd00:cafe:cafe::100]:52611 to [::]:443 [2025-04-30T10:41:27.023393866Z TRACE quiche_server] got packet Short dcid=cdedf144d7d63e508ccfa76157cd7d2d2eefeee5 key_phase=false [2025-04-30T10:41:27.023399848Z TRACE quiche] cdedf144d7d63e508ccfa76157cd7d2d2eefeee5 rx pkt Short dcid=cdedf144d7d63e508ccfa76157cd7d2d2eefeee5 key_phase=false len=43 pn=6 [2025-04-30T10:41:27.023405739Z TRACE quiche] cdedf144d7d63e508ccfa76157cd7d2d2eefeee5 rx frm ACK delay=5 blocks=[2..6] ecn_counts=None [2025-04-30T10:41:27.023409726Z TRACE quiche::recovery::congestion::recovery] cdedf144d7d63e508ccfa76157cd7d2d2eefeee5 packet newly acked 6 [2025-04-30T10:41:27.023414004Z TRACE quiche] cdedf144d7d63e508ccfa76157cd7d2d2eefeee5 rx frm STREAM id=4 off=0 len=17 fin=true [2025-04-30T10:41:27.023426908Z TRACE quiche_server] cdedf144d7d63e508ccfa76157cd7d2d2eefeee5 processed 64 bytes [2025-04-30T10:41:27.023430205Z DEBUG quiche_apps::common] cdedf144d7d63e508ccfa76157cd7d2d2eefeee5 response stream 4 is writable with capacity Ok(13500) [2025-04-30T10:41:27.023435525Z TRACE quiche_apps::common] cdedf144d7d63e508ccfa76157cd7d2d2eefeee5 received 17 bytes [2025-04-30T10:41:27.023438440Z TRACE quiche_apps::common] cdedf144d7d63e508ccfa76157cd7d2d2eefeee5 stream 4 has 17 bytes (fin? true) [2025-04-30T10:41:27.023442568Z INFO quiche_apps::common] cdedf144d7d63e508ccfa76157cd7d2d2eefeee5 got GET request for "/www/cgqofdoldk" on stream 4 [2025-04-30T10:41:27.023486190Z INFO quiche_apps::common] cdedf144d7d63e508ccfa76157cd7d2d2eefeee5 sending response of size 10240 on stream 4 [2025-04-30T10:41:27.023498864Z TRACE quiche_server] recv() would block [2025-04-30T10:41:27.023506097Z TRACE quiche] cdedf144d7d63e508ccfa76157cd7d2d2eefeee5 pmtud probe status false hs_con=true hs_sent=true cwnd_avail=13500 out_len=1350 left=1319 [2025-04-30T10:41:27.023511277Z TRACE quiche] cdedf144d7d63e508ccfa76157cd7d2d2eefeee5 tx pkt Short dcid=c4c1f6c2daf7db5c key_phase=false len=1324 pn=7 [2025-04-30T10:41:27.023514573Z TRACE quiche] cdedf144d7d63e508ccfa76157cd7d2d2eefeee5 tx frm ACK delay=13 blocks=[4..6] ecn_counts=None [2025-04-30T10:41:27.023518280Z TRACE quiche] cdedf144d7d63e508ccfa76157cd7d2d2eefeee5 tx frm STREAM id=4 off=0 len=1314 fin=false [2025-04-30T10:41:27.023527107Z TRACE quiche::recovery::congestion::recovery] cdedf144d7d63e508ccfa76157cd7d2d2eefeee5 timer=84.136749ms latest_rtt=35.853908ms srtt=34.332695ms min_rtt=33.020627ms rttvar=6.207458ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=1350 app_limited=true congestion_recovery_start_time=None Rate { delivered: 6885, delivered_time: Instant { tv_sec: 578, tv_nsec: 375056724 }, first_sent_time: Instant { tv_sec: 578, tv_nsec: 375056724 }, end_of_app_limited: 6, last_sent_packet: 7, largest_acked: 6, rate_sample: RateSample { delivery_rate: 180644, is_app_limited: true, interval: 33.020627ms, delivered: 5965, prior_delivered: 920, prior_time: Some(Instant { tv_sec: 578, tv_nsec: 339099862 }), send_elapsed: 0ns, ack_elapsed: 33.020627ms, rtt: 33.020627ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 491513, last_update: Instant { tv_sec: 578, tv_nsec: 375056724 }, next_time: Instant { tv_sec: 578, tv_nsec: 375056724 }, max_datagram_size: 1350, last_packet_size: Some(0), iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } [2025-04-30T10:41:27.023549189Z TRACE quiche] cdedf144d7d63e508ccfa76157cd7d2d2eefeee5 pmtud probe status false hs_con=true hs_sent=true cwnd_avail=12150 out_len=1350 left=1324 [2025-04-30T10:41:27.023553326Z TRACE quiche] cdedf144d7d63e508ccfa76157cd7d2d2eefeee5 tx pkt Short dcid=c4c1f6c2daf7db5c key_phase=false len=1324 pn=8 [2025-04-30T10:41:27.023556382Z TRACE quiche] cdedf144d7d63e508ccfa76157cd7d2d2eefeee5 tx frm STREAM id=4 off=1314 len=1318 fin=false [2025-04-30T10:41:27.023562283Z TRACE quiche::recovery::congestion::recovery] cdedf144d7d63e508ccfa76157cd7d2d2eefeee5 timer=84.147299ms latest_rtt=35.853908ms srtt=34.332695ms min_rtt=33.020627ms rttvar=6.207458ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=2700 app_limited=true congestion_recovery_start_time=None Rate { delivered: 6885, delivered_time: Instant { tv_sec: 578, tv_nsec: 375056724 }, first_sent_time: Instant { tv_sec: 578, tv_nsec: 375056724 }, end_of_app_limited: 7, last_sent_packet: 8, largest_acked: 6, rate_sample: RateSample { delivery_rate: 180644, is_app_limited: true, interval: 33.020627ms, delivered: 5965, prior_delivered: 920, prior_time: Some(Instant { tv_sec: 578, tv_nsec: 339099862 }), send_elapsed: 0ns, ack_elapsed: 33.020627ms, rtt: 33.020627ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 491513, last_update: Instant { tv_sec: 578, tv_nsec: 375056724 }, next_time: Instant { tv_sec: 578, tv_nsec: 375056724 }, max_datagram_size: 1350, last_packet_size: Some(0), iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } [2025-04-30T10:41:27.023574386Z TRACE quiche] cdedf144d7d63e508ccfa76157cd7d2d2eefeee5 pmtud probe status false hs_con=true hs_sent=true cwnd_avail=10800 out_len=1350 left=1324 [2025-04-30T10:41:27.023577963Z TRACE quiche] cdedf144d7d63e508ccfa76157cd7d2d2eefeee5 tx pkt Short dcid=c4c1f6c2daf7db5c key_phase=false len=1324 pn=9 [2025-04-30T10:41:27.023580818Z TRACE quiche] cdedf144d7d63e508ccfa76157cd7d2d2eefeee5 tx frm STREAM id=4 off=2632 len=1318 fin=false [2025-04-30T10:41:27.023586259Z TRACE quiche::recovery::congestion::recovery] cdedf144d7d63e508ccfa76157cd7d2d2eefeee5 timer=84.149142ms latest_rtt=35.853908ms srtt=34.332695ms min_rtt=33.020627ms rttvar=6.207458ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=4050 app_limited=true congestion_recovery_start_time=None Rate { delivered: 6885, delivered_time: Instant { tv_sec: 578, tv_nsec: 375056724 }, first_sent_time: Instant { tv_sec: 578, tv_nsec: 375056724 }, end_of_app_limited: 8, last_sent_packet: 9, largest_acked: 6, rate_sample: RateSample { delivery_rate: 180644, is_app_limited: true, interval: 33.020627ms, delivered: 5965, prior_delivered: 920, prior_time: Some(Instant { tv_sec: 578, tv_nsec: 339099862 }), send_elapsed: 0ns, ack_elapsed: 33.020627ms, rtt: 33.020627ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 491513, last_update: Instant { tv_sec: 578, tv_nsec: 375056724 }, next_time: Instant { tv_sec: 578, tv_nsec: 375056724 }, max_datagram_size: 1350, last_packet_size: Some(0), iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } [2025-04-30T10:41:27.023597700Z TRACE quiche] cdedf144d7d63e508ccfa76157cd7d2d2eefeee5 pmtud probe status false hs_con=true hs_sent=true cwnd_avail=9450 out_len=1350 left=1324 [2025-04-30T10:41:27.023604813Z TRACE quiche] cdedf144d7d63e508ccfa76157cd7d2d2eefeee5 tx pkt Short dcid=c4c1f6c2daf7db5c key_phase=false len=1324 pn=10 [2025-04-30T10:41:27.023607869Z TRACE quiche] cdedf144d7d63e508ccfa76157cd7d2d2eefeee5 tx frm STREAM id=4 off=3950 len=1318 fin=false [2025-04-30T10:41:27.023613159Z TRACE quiche::recovery::congestion::recovery] cdedf144d7d63e508ccfa76157cd7d2d2eefeee5 timer=84.145585ms latest_rtt=35.853908ms srtt=34.332695ms min_rtt=33.020627ms rttvar=6.207458ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=5400 app_limited=true congestion_recovery_start_time=None Rate { delivered: 6885, delivered_time: Instant { tv_sec: 578, tv_nsec: 375056724 }, first_sent_time: Instant { tv_sec: 578, tv_nsec: 375056724 }, end_of_app_limited: 8, last_sent_packet: 10, largest_acked: 6, rate_sample: RateSample { delivery_rate: 180644, is_app_limited: true, interval: 33.020627ms, delivered: 5965, prior_delivered: 920, prior_time: Some(Instant { tv_sec: 578, tv_nsec: 339099862 }), send_elapsed: 0ns, ack_elapsed: 33.020627ms, rtt: 33.020627ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 491513, last_update: Instant { tv_sec: 578, tv_nsec: 375056724 }, next_time: Instant { tv_sec: 578, tv_nsec: 375056724 }, max_datagram_size: 1350, last_packet_size: Some(0), iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } [2025-04-30T10:41:27.023624741Z TRACE quiche] cdedf144d7d63e508ccfa76157cd7d2d2eefeee5 pmtud probe status false hs_con=true hs_sent=true cwnd_avail=8100 out_len=1350 left=1324 [2025-04-30T10:41:27.023628338Z TRACE quiche] cdedf144d7d63e508ccfa76157cd7d2d2eefeee5 tx pkt Short dcid=c4c1f6c2daf7db5c key_phase=false len=1324 pn=11 [2025-04-30T10:41:27.023631223Z TRACE quiche] cdedf144d7d63e508ccfa76157cd7d2d2eefeee5 tx frm STREAM id=4 off=5268 len=1318 fin=false [2025-04-30T10:41:27.023636483Z TRACE quiche::recovery::congestion::recovery] cdedf144d7d63e508ccfa76157cd7d2d2eefeee5 timer=84.149282ms latest_rtt=35.853908ms srtt=34.332695ms min_rtt=33.020627ms rttvar=6.207458ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=6750 app_limited=true congestion_recovery_start_time=None Rate { delivered: 6885, delivered_time: Instant { tv_sec: 578, tv_nsec: 375056724 }, first_sent_time: Instant { tv_sec: 578, tv_nsec: 375056724 }, end_of_app_limited: 8, last_sent_packet: 11, largest_acked: 6, rate_sample: RateSample { delivery_rate: 180644, is_app_limited: true, interval: 33.020627ms, delivered: 5965, prior_delivered: 920, prior_time: Some(Instant { tv_sec: 578, tv_nsec: 339099862 }), send_elapsed: 0ns, ack_elapsed: 33.020627ms, rtt: 33.020627ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 491513, last_update: Instant { tv_sec: 578, tv_nsec: 375056724 }, next_time: Instant { tv_sec: 578, tv_nsec: 375056724 }, max_datagram_size: 1350, last_packet_size: Some(0), iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } [2025-04-30T10:41:27.023647664Z TRACE quiche] cdedf144d7d63e508ccfa76157cd7d2d2eefeee5 pmtud probe status false hs_con=true hs_sent=true cwnd_avail=6750 out_len=1350 left=1324 [2025-04-30T10:41:27.023651201Z TRACE quiche] cdedf144d7d63e508ccfa76157cd7d2d2eefeee5 tx pkt Short dcid=c4c1f6c2daf7db5c key_phase=false len=1324 pn=12 [2025-04-30T10:41:27.023654046Z TRACE quiche] cdedf144d7d63e508ccfa76157cd7d2d2eefeee5 tx frm STREAM id=4 off=6586 len=1318 fin=false [2025-04-30T10:41:27.023659226Z TRACE quiche::recovery::congestion::recovery] cdedf144d7d63e508ccfa76157cd7d2d2eefeee5 timer=84.149642ms latest_rtt=35.853908ms srtt=34.332695ms min_rtt=33.020627ms rttvar=6.207458ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=8100 app_limited=true congestion_recovery_start_time=None Rate { delivered: 6885, delivered_time: Instant { tv_sec: 578, tv_nsec: 375056724 }, first_sent_time: Instant { tv_sec: 578, tv_nsec: 375056724 }, end_of_app_limited: 8, last_sent_packet: 12, largest_acked: 6, rate_sample: RateSample { delivery_rate: 180644, is_app_limited: true, interval: 33.020627ms, delivered: 5965, prior_delivered: 920, prior_time: Some(Instant { tv_sec: 578, tv_nsec: 339099862 }), send_elapsed: 0ns, ack_elapsed: 33.020627ms, rtt: 33.020627ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 491513, last_update: Instant { tv_sec: 578, tv_nsec: 375056724 }, next_time: Instant { tv_sec: 578, tv_nsec: 375056724 }, max_datagram_size: 1350, last_packet_size: Some(0), iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } [2025-04-30T10:41:27.023673703Z TRACE quiche] cdedf144d7d63e508ccfa76157cd7d2d2eefeee5 pmtud probe status false hs_con=true hs_sent=true cwnd_avail=5400 out_len=1350 left=1324 [2025-04-30T10:41:27.023677470Z TRACE quiche] cdedf144d7d63e508ccfa76157cd7d2d2eefeee5 tx pkt Short dcid=c4c1f6c2daf7db5c key_phase=false len=1324 pn=13 [2025-04-30T10:41:27.023680396Z TRACE quiche] cdedf144d7d63e508ccfa76157cd7d2d2eefeee5 tx frm STREAM id=4 off=7904 len=1318 fin=false [2025-04-30T10:41:27.023685615Z TRACE quiche::recovery::congestion::recovery] cdedf144d7d63e508ccfa76157cd7d2d2eefeee5 timer=84.149142ms latest_rtt=35.853908ms srtt=34.332695ms min_rtt=33.020627ms rttvar=6.207458ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=9450 app_limited=true congestion_recovery_start_time=None Rate { delivered: 6885, delivered_time: Instant { tv_sec: 578, tv_nsec: 375056724 }, first_sent_time: Instant { tv_sec: 578, tv_nsec: 375056724 }, end_of_app_limited: 8, last_sent_packet: 13, largest_acked: 6, rate_sample: RateSample { delivery_rate: 180644, is_app_limited: true, interval: 33.020627ms, delivered: 5965, prior_delivered: 920, prior_time: Some(Instant { tv_sec: 578, tv_nsec: 339099862 }), send_elapsed: 0ns, ack_elapsed: 33.020627ms, rtt: 33.020627ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 491513, last_update: Instant { tv_sec: 578, tv_nsec: 375056724 }, next_time: Instant { tv_sec: 578, tv_nsec: 375056724 }, max_datagram_size: 1350, last_packet_size: Some(0), iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } [2025-04-30T10:41:27.023697227Z TRACE quiche] cdedf144d7d63e508ccfa76157cd7d2d2eefeee5 pmtud probe status false hs_con=true hs_sent=true cwnd_avail=4050 out_len=1350 left=1324 [2025-04-30T10:41:27.023700704Z TRACE quiche] cdedf144d7d63e508ccfa76157cd7d2d2eefeee5 tx pkt Short dcid=c4c1f6c2daf7db5c key_phase=false len=1024 pn=14 [2025-04-30T10:41:27.023703599Z TRACE quiche] cdedf144d7d63e508ccfa76157cd7d2d2eefeee5 tx frm STREAM id=4 off=9222 len=1018 fin=true [2025-04-30T10:41:27.023708819Z TRACE quiche::recovery::congestion::recovery] cdedf144d7d63e508ccfa76157cd7d2d2eefeee5 timer=84.149572ms latest_rtt=35.853908ms srtt=34.332695ms min_rtt=33.020627ms rttvar=6.207458ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=10500 app_limited=true congestion_recovery_start_time=None Rate { delivered: 6885, delivered_time: Instant { tv_sec: 578, tv_nsec: 375056724 }, first_sent_time: Instant { tv_sec: 578, tv_nsec: 375056724 }, end_of_app_limited: 8, last_sent_packet: 14, largest_acked: 6, rate_sample: RateSample { delivery_rate: 180644, is_app_limited: true, interval: 33.020627ms, delivered: 5965, prior_delivered: 920, prior_time: Some(Instant { tv_sec: 578, tv_nsec: 339099862 }), send_elapsed: 0ns, ack_elapsed: 33.020627ms, rtt: 33.020627ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 491513, last_update: Instant { tv_sec: 578, tv_nsec: 375056724 }, next_time: Instant { tv_sec: 578, tv_nsec: 375056724 }, max_datagram_size: 1350, last_packet_size: Some(0), iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } [2025-04-30T10:41:27.023829526Z TRACE quiche_server] cdedf144d7d63e508ccfa76157cd7d2d2eefeee5 written 10500 bytes with Some(SendInfo { from: [::]:443, to: [fd00:cafe:cafe::100]:52611, at: Instant { tv_sec: 578, tv_nsec: 375056724 } }) [2025-04-30T10:41:27.023839124Z TRACE quiche_server] Collecting garbage [2025-04-30T10:41:27.023845366Z TRACE quiche_server] recv() would block [2025-04-30T10:41:27.023849824Z TRACE quiche_server] cdedf144d7d63e508ccfa76157cd7d2d2eefeee5 done writing [2025-04-30T10:41:27.023853231Z TRACE quiche_server] Collecting garbage [2025-04-30T10:41:27.056537808Z TRACE quiche_server] got 44 bytes from [fd00:cafe:cafe::100]:52611 to [::]:443 [2025-04-30T10:41:27.056553537Z TRACE quiche_server] got packet Short dcid=cdedf144d7d63e508ccfa76157cd7d2d2eefeee5 key_phase=false [2025-04-30T10:41:27.056561051Z TRACE quiche] cdedf144d7d63e508ccfa76157cd7d2d2eefeee5 rx pkt Short dcid=cdedf144d7d63e508ccfa76157cd7d2d2eefeee5 key_phase=false len=23 pn=7 [2025-04-30T10:41:27.056568175Z TRACE quiche] cdedf144d7d63e508ccfa76157cd7d2d2eefeee5 rx frm ACK delay=6 blocks=[7..8] ecn_counts=None [2025-04-30T10:41:27.056573134Z TRACE quiche::recovery::congestion::recovery] cdedf144d7d63e508ccfa76157cd7d2d2eefeee5 packet newly acked 7 [2025-04-30T10:41:27.056577001Z TRACE quiche::recovery::congestion::recovery] cdedf144d7d63e508ccfa76157cd7d2d2eefeee5 packet newly acked 8 [2025-04-30T10:41:27.056590286Z TRACE quiche_server] cdedf144d7d63e508ccfa76157cd7d2d2eefeee5 processed 44 bytes [2025-04-30T10:41:27.056596087Z TRACE quiche_server] recv() would block [2025-04-30T10:41:27.056600396Z TRACE quiche_server] cdedf144d7d63e508ccfa76157cd7d2d2eefeee5 done writing [2025-04-30T10:41:27.056604032Z TRACE quiche_server] Collecting garbage [2025-04-30T10:41:27.058733086Z TRACE quiche_server] got 44 bytes from [fd00:cafe:cafe::100]:52611 to [::]:443 [2025-04-30T10:41:27.058745870Z TRACE quiche_server] got packet Short dcid=cdedf144d7d63e508ccfa76157cd7d2d2eefeee5 key_phase=false [2025-04-30T10:41:27.058753825Z TRACE quiche] cdedf144d7d63e508ccfa76157cd7d2d2eefeee5 rx pkt Short dcid=cdedf144d7d63e508ccfa76157cd7d2d2eefeee5 key_phase=false len=23 pn=8 [2025-04-30T10:41:27.058761199Z TRACE quiche] cdedf144d7d63e508ccfa76157cd7d2d2eefeee5 rx frm ACK delay=5 blocks=[7..10] ecn_counts=None [2025-04-30T10:41:27.058766238Z TRACE quiche::recovery::congestion::recovery] cdedf144d7d63e508ccfa76157cd7d2d2eefeee5 packet newly acked 9 [2025-04-30T10:41:27.058769955Z TRACE quiche::recovery::congestion::recovery] cdedf144d7d63e508ccfa76157cd7d2d2eefeee5 packet newly acked 10 [2025-04-30T10:41:27.058782909Z TRACE quiche_server] cdedf144d7d63e508ccfa76157cd7d2d2eefeee5 processed 44 bytes [2025-04-30T10:41:27.058789201Z TRACE quiche_server] recv() would block [2025-04-30T10:41:27.058793469Z TRACE quiche_server] cdedf144d7d63e508ccfa76157cd7d2d2eefeee5 done writing [2025-04-30T10:41:27.058797146Z TRACE quiche_server] Collecting garbage [2025-04-30T10:41:27.060930530Z TRACE quiche_server] got 44 bytes from [fd00:cafe:cafe::100]:52611 to [::]:443 [2025-04-30T10:41:27.060944507Z TRACE quiche_server] got packet Short dcid=cdedf144d7d63e508ccfa76157cd7d2d2eefeee5 key_phase=false [2025-04-30T10:41:27.060952902Z TRACE quiche] cdedf144d7d63e508ccfa76157cd7d2d2eefeee5 rx pkt Short dcid=cdedf144d7d63e508ccfa76157cd7d2d2eefeee5 key_phase=false len=23 pn=9 [2025-04-30T10:41:27.060970946Z TRACE quiche] cdedf144d7d63e508ccfa76157cd7d2d2eefeee5 rx frm ACK delay=5 blocks=[7..12] ecn_counts=None [2025-04-30T10:41:27.060976928Z TRACE quiche::recovery::congestion::recovery] cdedf144d7d63e508ccfa76157cd7d2d2eefeee5 packet newly acked 11 [2025-04-30T10:41:27.060979492Z TRACE quiche::recovery::congestion::recovery] cdedf144d7d63e508ccfa76157cd7d2d2eefeee5 packet newly acked 12 [2025-04-30T10:41:27.060990934Z TRACE quiche_server] cdedf144d7d63e508ccfa76157cd7d2d2eefeee5 processed 44 bytes [2025-04-30T10:41:27.060995362Z TRACE quiche_server] recv() would block [2025-04-30T10:41:27.061000121Z TRACE quiche_server] cdedf144d7d63e508ccfa76157cd7d2d2eefeee5 done writing [2025-04-30T10:41:27.061003898Z TRACE quiche_server] Collecting garbage [2025-04-30T10:41:27.062988555Z TRACE quiche_server] got 44 bytes from [fd00:cafe:cafe::100]:52611 to [::]:443 [2025-04-30T10:41:27.063000798Z TRACE quiche_server] got packet Short dcid=cdedf144d7d63e508ccfa76157cd7d2d2eefeee5 key_phase=false [2025-04-30T10:41:27.063007280Z TRACE quiche] cdedf144d7d63e508ccfa76157cd7d2d2eefeee5 rx pkt Short dcid=cdedf144d7d63e508ccfa76157cd7d2d2eefeee5 key_phase=false len=23 pn=10 [2025-04-30T10:41:27.063013402Z TRACE quiche] cdedf144d7d63e508ccfa76157cd7d2d2eefeee5 rx frm ACK delay=5 blocks=[7..14] ecn_counts=None [2025-04-30T10:41:27.063017169Z TRACE quiche::recovery::congestion::recovery] cdedf144d7d63e508ccfa76157cd7d2d2eefeee5 packet newly acked 13 [2025-04-30T10:41:27.063019643Z TRACE quiche::recovery::congestion::recovery] cdedf144d7d63e508ccfa76157cd7d2d2eefeee5 packet newly acked 14 [2025-04-30T10:41:27.063033780Z TRACE quiche_server] cdedf144d7d63e508ccfa76157cd7d2d2eefeee5 processed 44 bytes [2025-04-30T10:41:27.063039360Z TRACE quiche_server] got 42 bytes from [fd00:cafe:cafe::100]:52611 to [::]:443 [2025-04-30T10:41:27.063042386Z TRACE quiche_server] got packet Short dcid=cdedf144d7d63e508ccfa76157cd7d2d2eefeee5 key_phase=false [2025-04-30T10:41:27.063046103Z TRACE quiche] cdedf144d7d63e508ccfa76157cd7d2d2eefeee5 rx pkt Short dcid=cdedf144d7d63e508ccfa76157cd7d2d2eefeee5 key_phase=false len=21 pn=11 [2025-04-30T10:41:27.063049990Z TRACE quiche] cdedf144d7d63e508ccfa76157cd7d2d2eefeee5 rx frm CONNECTION_CLOSE err=0 frame=0 reason=[] [2025-04-30T10:41:27.063055821Z TRACE quiche_server] cdedf144d7d63e508ccfa76157cd7d2d2eefeee5 processed 42 bytes [2025-04-30T10:41:27.063059278Z TRACE quiche_server] recv() would block [2025-04-30T10:41:27.063061602Z TRACE quiche_server] cdedf144d7d63e508ccfa76157cd7d2d2eefeee5 done writing [2025-04-30T10:41:27.063063897Z TRACE quiche_server] Collecting garbage [2025-04-30T10:41:27.218252051Z TRACE quiche_server] timed out [2025-04-30T10:41:27.218280374Z TRACE quiche] cdedf144d7d63e508ccfa76157cd7d2d2eefeee5 draining timeout expired [2025-04-30T10:41:27.218328104Z TRACE quiche_server] cdedf144d7d63e508ccfa76157cd7d2d2eefeee5 done writing [2025-04-30T10:41:27.218334176Z TRACE quiche_server] Collecting garbage [2025-04-30T10:41:27.218340147Z INFO quiche_server] cdedf144d7d63e508ccfa76157cd7d2d2eefeee5 connection collected recv=12 sent=15 lost=0 retrans=0 sent_bytes=17385 recv_bytes=2770 lost_bytes=0 [local_addr=[::]:443 peer_addr=[fd00:cafe:cafe::100]:52611 validation_state=Validated active=true recv=12 sent=15 lost=0 retrans=0 rtt=35.287997ms min_rtt=Some(33.020627ms) rttvar=4.020134ms cwnd=13500 sent_bytes=17385 recv_bytes=2770 lost_bytes=0 stream_retrans_bytes=0 pmtu=1350 delivery_rate=317622]