[2025-04-30T12:27:29.948340903Z INFO quiche_server] listening on [::]:443 [2025-04-30T12:27:29.948362855Z TRACE mio::poll] registering event source with poller: token=Token(0), interests=READABLE [2025-04-30T12:27:29.948369617Z TRACE quiche_server] GSO detected: false [2025-04-30T12:27:30.746184847Z TRACE quiche_server] got 1207 bytes from [::ffff:193.167.100.2]:35824 to [::]:443 [2025-04-30T12:27:30.746217798Z TRACE quiche_server] got packet Initial version=57414954 dcid= scid= token= [2025-04-30T12:27:30.746225813Z WARN quiche_server] Doing version negotiation [2025-04-30T12:27:30.746311393Z TRACE quiche_server] got 1207 bytes from [::ffff:193.167.100.2]:35824 to [::]:443 [2025-04-30T12:27:30.746317685Z TRACE quiche_server] got packet Initial version=57414954 dcid= scid= token= [2025-04-30T12:27:30.746321742Z WARN quiche_server] Doing version negotiation [2025-04-30T12:27:30.746345907Z TRACE quiche_server] got 1207 bytes from [::ffff:193.167.100.2]:35824 to [::]:443 [2025-04-30T12:27:30.746352770Z TRACE quiche_server] got packet Initial version=57414954 dcid= scid= token= [2025-04-30T12:27:30.746358430Z WARN quiche_server] Doing version negotiation [2025-04-30T12:27:30.746393796Z TRACE quiche_server] recv() would block [2025-04-30T12:27:30.956430000Z TRACE quiche_server] got 1200 bytes from [::ffff:193.167.0.100]:59690 to [::]:443 [2025-04-30T12:27:30.956452852Z TRACE quiche_server] got packet Initial version=1 dcid=296454e97d2b465a scid=a8f4ff2b567af92e token= [2025-04-30T12:27:30.956461448Z DEBUG quiche_server] New connection: dcid=296454e97d2b465a scid=760cb45d7af5e5f149a306a8ffe305de36525f5c [2025-04-30T12:27:30.956657384Z TRACE quiche] 760cb45d7af5e5f149a306a8ffe305de36525f5c rx pkt Initial version=1 dcid=296454e97d2b465a scid=a8f4ff2b567af92e token= len=270 pn=0 [2025-04-30T12:27:30.956671530Z TRACE quiche] 760cb45d7af5e5f149a306a8ffe305de36525f5c rx frm CRYPTO off=0 len=249 [2025-04-30T12:27:30.956701075Z TRACE quiche::tls] checking peer ALPN Ok("hq-interop") against Ok("h3") [2025-04-30T12:27:30.956705974Z TRACE quiche::tls] checking peer ALPN Ok("hq-interop") against Ok("hq-interop") [2025-04-30T12:27:30.956806021Z TRACE quiche::tls] 760cb45d7af5e5f149a306a8ffe305de36525f5c write message lvl=Initial len=90 [2025-04-30T12:27:30.956835295Z TRACE quiche::tls] 760cb45d7af5e5f149a306a8ffe305de36525f5c set write secret lvl=Handshake [2025-04-30T12:27:30.956944739Z TRACE quiche::tls] 760cb45d7af5e5f149a306a8ffe305de36525f5c write message lvl=Handshake len=9943 [2025-04-30T12:27:30.956949879Z TRACE quiche::tls] 760cb45d7af5e5f149a306a8ffe305de36525f5c set write secret lvl=OneRTT [2025-04-30T12:27:30.956958134Z TRACE quiche::tls] 760cb45d7af5e5f149a306a8ffe305de36525f5c set read secret lvl=Handshake [2025-04-30T12:27:30.957024017Z TRACE quiche] 760cb45d7af5e5f149a306a8ffe305de36525f5c dropped invalid packet [2025-04-30T12:27:30.957032032Z TRACE quiche_server] 760cb45d7af5e5f149a306a8ffe305de36525f5c processed 1200 bytes [2025-04-30T12:27:30.957042842Z TRACE quiche_server] recv() would block [2025-04-30T12:27:30.957056728Z TRACE quiche] 760cb45d7af5e5f149a306a8ffe305de36525f5c tx pkt Initial version=1 dcid=a8f4ff2b567af92e scid=760cb45d7af5e5f149a306a8ffe305de36525f5c len=99 pn=0 [2025-04-30T12:27:30.957061066Z TRACE quiche] 760cb45d7af5e5f149a306a8ffe305de36525f5c tx frm ACK delay=52 blocks=[0..0] ecn_counts=None [2025-04-30T12:27:30.957066587Z TRACE quiche] 760cb45d7af5e5f149a306a8ffe305de36525f5c tx frm CRYPTO off=0 len=90 [2025-04-30T12:27:30.957078048Z TRACE quiche::recovery::congestion::recovery] 760cb45d7af5e5f149a306a8ffe305de36525f5c timer=998.966868ms 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: 453, tv_nsec: 457064921 }, first_sent_time: Instant { tv_sec: 453, tv_nsec: 457064921 }, 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: 453, tv_nsec: 457064921 }, next_time: Instant { tv_sec: 453, tv_nsec: 457064921 }, max_datagram_size: 1350, last_packet_size: None, iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } [2025-04-30T12:27:30.957112182Z TRACE quiche] 760cb45d7af5e5f149a306a8ffe305de36525f5c tx pkt Handshake version=1 dcid=a8f4ff2b567af92e scid=760cb45d7af5e5f149a306a8ffe305de36525f5c len=992 pn=1 [2025-04-30T12:27:30.957115808Z TRACE quiche] 760cb45d7af5e5f149a306a8ffe305de36525f5c tx frm CRYPTO off=0 len=988 [2025-04-30T12:27:30.957122751Z TRACE quiche::recovery::congestion::recovery] 760cb45d7af5e5f149a306a8ffe305de36525f5c timer=998.922686ms latest_rtt=0ns srtt=333ms min_rtt=333ms rttvar=166.5ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=1200 app_limited=true congestion_recovery_start_time=None Rate { delivered: 0, delivered_time: Instant { tv_sec: 453, tv_nsec: 457064921 }, first_sent_time: Instant { tv_sec: 453, tv_nsec: 457064921 }, 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: 453, tv_nsec: 457064921 }, next_time: Instant { tv_sec: 453, tv_nsec: 457064921 }, max_datagram_size: 1350, last_packet_size: None, iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } [2025-04-30T12:27:30.957175510Z TRACE quiche_server] 760cb45d7af5e5f149a306a8ffe305de36525f5c written 1200 bytes with Some(SendInfo { from: [::]:443, to: [::ffff:193.167.0.100]:59690, at: Instant { tv_sec: 453, tv_nsec: 457064921 } }) [2025-04-30T12:27:30.957186811Z TRACE quiche_server] Collecting garbage [2025-04-30T12:27:30.957194996Z TRACE quiche_server] recv() would block [2025-04-30T12:27:30.957209734Z TRACE quiche] 760cb45d7af5e5f149a306a8ffe305de36525f5c tx pkt Handshake version=1 dcid=a8f4ff2b567af92e scid=760cb45d7af5e5f149a306a8ffe305de36525f5c len=1146 pn=2 [2025-04-30T12:27:30.957215605Z TRACE quiche] 760cb45d7af5e5f149a306a8ffe305de36525f5c tx frm CRYPTO off=988 len=1141 [2025-04-30T12:27:30.957227807Z TRACE quiche::recovery::congestion::recovery] 760cb45d7af5e5f149a306a8ffe305de36525f5c timer=998.817109ms latest_rtt=0ns srtt=333ms min_rtt=333ms rttvar=166.5ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=2400 app_limited=true congestion_recovery_start_time=None Rate { delivered: 0, delivered_time: Instant { tv_sec: 453, tv_nsec: 457064921 }, first_sent_time: Instant { tv_sec: 453, tv_nsec: 457064921 }, end_of_app_limited: 1, last_sent_packet: 2, largest_acked: 0, rate_sample: RateSample { delivery_rate: 0, is_app_limited: false, interval: 0ns, delivered: 0, prior_delivered: 0, prior_time: None, send_elapsed: 0ns, ack_elapsed: 0ns, rtt: 0ns } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 0, last_update: Instant { tv_sec: 453, tv_nsec: 457218538 }, next_time: Instant { tv_sec: 453, tv_nsec: 457218538 }, max_datagram_size: 1350, last_packet_size: None, iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } [2025-04-30T12:27:30.957277229Z TRACE quiche_server] 760cb45d7af5e5f149a306a8ffe305de36525f5c written 1200 bytes with Some(SendInfo { from: [::]:443, to: [::ffff:193.167.0.100]:59690, at: Instant { tv_sec: 453, tv_nsec: 457218538 } }) [2025-04-30T12:27:30.957291075Z TRACE quiche_server] Collecting garbage [2025-04-30T12:27:30.957297497Z TRACE quiche_server] recv() would block [2025-04-30T12:27:30.957310502Z TRACE quiche] 760cb45d7af5e5f149a306a8ffe305de36525f5c tx pkt Handshake version=1 dcid=a8f4ff2b567af92e scid=760cb45d7af5e5f149a306a8ffe305de36525f5c len=1146 pn=3 [2025-04-30T12:27:30.957315120Z TRACE quiche] 760cb45d7af5e5f149a306a8ffe305de36525f5c tx frm CRYPTO off=2129 len=1141 [2025-04-30T12:27:30.957326020Z TRACE quiche::recovery::congestion::recovery] 760cb45d7af5e5f149a306a8ffe305de36525f5c timer=998.718705ms latest_rtt=0ns srtt=333ms min_rtt=333ms rttvar=166.5ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=3600 app_limited=true congestion_recovery_start_time=None Rate { delivered: 0, delivered_time: Instant { tv_sec: 453, tv_nsec: 457064921 }, first_sent_time: Instant { tv_sec: 453, tv_nsec: 457064921 }, end_of_app_limited: 2, last_sent_packet: 3, largest_acked: 0, rate_sample: RateSample { delivery_rate: 0, is_app_limited: false, interval: 0ns, delivered: 0, prior_delivered: 0, prior_time: None, send_elapsed: 0ns, ack_elapsed: 0ns, rtt: 0ns } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 0, last_update: Instant { tv_sec: 453, tv_nsec: 457319987 }, next_time: Instant { tv_sec: 453, tv_nsec: 457319987 }, max_datagram_size: 1350, last_packet_size: None, iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } [2025-04-30T12:27:30.957363510Z TRACE quiche_server] 760cb45d7af5e5f149a306a8ffe305de36525f5c written 1200 bytes with Some(SendInfo { from: [::]:443, to: [::ffff:193.167.0.100]:59690, at: Instant { tv_sec: 453, tv_nsec: 457319987 } }) [2025-04-30T12:27:30.957369481Z TRACE quiche_server] Collecting garbage [2025-04-30T12:27:30.957375372Z TRACE quiche_server] recv() would block [2025-04-30T12:27:30.957380702Z TRACE quiche_server] 760cb45d7af5e5f149a306a8ffe305de36525f5c done writing [2025-04-30T12:27:30.957384570Z TRACE quiche_server] Collecting garbage [2025-04-30T12:27:31.957443103Z TRACE quiche_server] timed out [2025-04-30T12:27:31.957475163Z TRACE quiche] 760cb45d7af5e5f149a306a8ffe305de36525f5c loss detection timeout expired [2025-04-30T12:27:31.957483087Z TRACE quiche::recovery::congestion::recovery] 760cb45d7af5e5f149a306a8ffe305de36525f5c timer=997.561558ms latest_rtt=0ns srtt=333ms min_rtt=333ms rttvar=166.5ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=3600 app_limited=true congestion_recovery_start_time=None Rate { delivered: 0, delivered_time: Instant { tv_sec: 453, tv_nsec: 457064921 }, first_sent_time: Instant { tv_sec: 453, tv_nsec: 457064921 }, end_of_app_limited: 2, last_sent_packet: 3, largest_acked: 0, rate_sample: RateSample { delivery_rate: 0, is_app_limited: false, interval: 0ns, delivered: 0, prior_delivered: 0, prior_time: None, send_elapsed: 0ns, ack_elapsed: 0ns, rtt: 0ns } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 0, last_update: Instant { tv_sec: 453, tv_nsec: 457319987 }, next_time: Instant { tv_sec: 453, tv_nsec: 457319987 }, max_datagram_size: 1350, last_packet_size: None, iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } [2025-04-30T12:27:31.957513163Z TRACE quiche_server] 760cb45d7af5e5f149a306a8ffe305de36525f5c done writing [2025-04-30T12:27:31.957517051Z TRACE quiche_server] Collecting garbage [2025-04-30T12:27:32.726511382Z TRACE quiche_server] got 57 bytes from [::ffff:193.167.0.100]:59690 to [::]:443 [2025-04-30T12:27:32.726554282Z TRACE quiche_server] got packet Handshake version=1 dcid=760cb45d7af5e5f149a306a8ffe305de36525f5c scid=a8f4ff2b567af92e [2025-04-30T12:27:32.726569831Z TRACE quiche] 760cb45d7af5e5f149a306a8ffe305de36525f5c rx pkt Handshake version=1 dcid=760cb45d7af5e5f149a306a8ffe305de36525f5c scid=a8f4ff2b567af92e len=20 pn=6 [2025-04-30T12:27:32.726582264Z TRACE quiche] 760cb45d7af5e5f149a306a8ffe305de36525f5c rx frm PING mtu_probe=None [2025-04-30T12:27:32.726586863Z TRACE quiche] 760cb45d7af5e5f149a306a8ffe305de36525f5c rx frm PADDING len=2 [2025-04-30T12:27:32.726613202Z TRACE quiche] 760cb45d7af5e5f149a306a8ffe305de36525f5c dropped epoch 0 state [2025-04-30T12:27:32.726617069Z TRACE quiche_server] 760cb45d7af5e5f149a306a8ffe305de36525f5c processed 57 bytes [2025-04-30T12:27:32.726623972Z TRACE quiche_server] recv() would block [2025-04-30T12:27:32.726643859Z TRACE quiche] 760cb45d7af5e5f149a306a8ffe305de36525f5c tx pkt Handshake version=1 dcid=a8f4ff2b567af92e scid=760cb45d7af5e5f149a306a8ffe305de36525f5c len=1146 pn=4 [2025-04-30T12:27:32.726647947Z TRACE quiche] 760cb45d7af5e5f149a306a8ffe305de36525f5c tx frm ACK delay=9 blocks=[6..6] ecn_counts=None [2025-04-30T12:27:32.726653778Z TRACE quiche] 760cb45d7af5e5f149a306a8ffe305de36525f5c tx frm CRYPTO off=3270 len=1136 [2025-04-30T12:27:32.726665970Z TRACE quiche::recovery::congestion::recovery] 760cb45d7af5e5f149a306a8ffe305de36525f5c timer=1.997960026s latest_rtt=0ns srtt=333ms min_rtt=333ms rttvar=166.5ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=4646 app_limited=true congestion_recovery_start_time=None Rate { delivered: 0, delivered_time: Instant { tv_sec: 453, tv_nsec: 457064921 }, first_sent_time: Instant { tv_sec: 453, tv_nsec: 457064921 }, end_of_app_limited: 3, last_sent_packet: 4, largest_acked: 0, rate_sample: RateSample { delivery_rate: 0, is_app_limited: false, interval: 0ns, delivered: 0, prior_delivered: 0, prior_time: None, send_elapsed: 0ns, ack_elapsed: 0ns, rtt: 0ns } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 0, last_update: Instant { tv_sec: 455, tv_nsec: 226645981 }, next_time: Instant { tv_sec: 455, tv_nsec: 226645981 }, max_datagram_size: 1350, last_packet_size: None, iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } [2025-04-30T12:27:32.726733767Z TRACE quiche_server] 760cb45d7af5e5f149a306a8ffe305de36525f5c written 1200 bytes with Some(SendInfo { from: [::]:443, to: [::ffff:193.167.0.100]:59690, at: Instant { tv_sec: 455, tv_nsec: 226645981 } }) [2025-04-30T12:27:32.726740870Z TRACE quiche_server] Collecting garbage [2025-04-30T12:27:32.726747032Z TRACE quiche_server] recv() would block [2025-04-30T12:27:32.726757130Z TRACE quiche] 760cb45d7af5e5f149a306a8ffe305de36525f5c tx pkt Handshake version=1 dcid=a8f4ff2b567af92e scid=760cb45d7af5e5f149a306a8ffe305de36525f5c len=1146 pn=5 [2025-04-30T12:27:32.726760587Z TRACE quiche] 760cb45d7af5e5f149a306a8ffe305de36525f5c tx frm CRYPTO off=4406 len=1141 [2025-04-30T12:27:32.726770395Z TRACE quiche::recovery::congestion::recovery] 760cb45d7af5e5f149a306a8ffe305de36525f5c timer=1.997978691s latest_rtt=0ns srtt=333ms min_rtt=333ms rttvar=166.5ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=5846 app_limited=true congestion_recovery_start_time=None Rate { delivered: 0, delivered_time: Instant { tv_sec: 453, tv_nsec: 457064921 }, first_sent_time: Instant { tv_sec: 453, tv_nsec: 457064921 }, end_of_app_limited: 4, last_sent_packet: 5, largest_acked: 0, rate_sample: RateSample { delivery_rate: 0, is_app_limited: false, interval: 0ns, delivered: 0, prior_delivered: 0, prior_time: None, send_elapsed: 0ns, ack_elapsed: 0ns, rtt: 0ns } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 0, last_update: Instant { tv_sec: 455, tv_nsec: 226768630 }, next_time: Instant { tv_sec: 455, tv_nsec: 226768630 }, max_datagram_size: 1350, last_packet_size: None, iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } [2025-04-30T12:27:32.726816100Z TRACE quiche_server] 760cb45d7af5e5f149a306a8ffe305de36525f5c written 1200 bytes with Some(SendInfo { from: [::]:443, to: [::ffff:193.167.0.100]:59690, at: Instant { tv_sec: 455, tv_nsec: 226768630 } }) [2025-04-30T12:27:32.726822342Z TRACE quiche_server] Collecting garbage [2025-04-30T12:27:32.726827021Z TRACE quiche_server] recv() would block [2025-04-30T12:27:32.726838342Z TRACE quiche] 760cb45d7af5e5f149a306a8ffe305de36525f5c tx pkt Handshake version=1 dcid=a8f4ff2b567af92e scid=760cb45d7af5e5f149a306a8ffe305de36525f5c len=1146 pn=6 [2025-04-30T12:27:32.726841838Z TRACE quiche] 760cb45d7af5e5f149a306a8ffe305de36525f5c tx frm CRYPTO off=5547 len=1141 [2025-04-30T12:27:32.726849532Z TRACE quiche::recovery::congestion::recovery] 760cb45d7af5e5f149a306a8ffe305de36525f5c timer=1.997979802s latest_rtt=0ns srtt=333ms min_rtt=333ms rttvar=166.5ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=7046 app_limited=true congestion_recovery_start_time=None Rate { delivered: 0, delivered_time: Instant { tv_sec: 453, tv_nsec: 457064921 }, first_sent_time: Instant { tv_sec: 453, tv_nsec: 457064921 }, end_of_app_limited: 5, last_sent_packet: 6, largest_acked: 0, rate_sample: RateSample { delivery_rate: 0, is_app_limited: false, interval: 0ns, delivered: 0, prior_delivered: 0, prior_time: None, send_elapsed: 0ns, ack_elapsed: 0ns, rtt: 0ns } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 0, last_update: Instant { tv_sec: 455, tv_nsec: 226848759 }, next_time: Instant { tv_sec: 455, tv_nsec: 226848759 }, max_datagram_size: 1350, last_packet_size: None, iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } [2025-04-30T12:27:32.726882754Z TRACE quiche_server] 760cb45d7af5e5f149a306a8ffe305de36525f5c written 1200 bytes with Some(SendInfo { from: [::]:443, to: [::ffff:193.167.0.100]:59690, at: Instant { tv_sec: 455, tv_nsec: 226848759 } }) [2025-04-30T12:27:32.726887624Z TRACE quiche_server] Collecting garbage [2025-04-30T12:27:32.726891811Z TRACE quiche_server] recv() would block [2025-04-30T12:27:32.726899706Z TRACE quiche] 760cb45d7af5e5f149a306a8ffe305de36525f5c tx pkt Handshake version=1 dcid=a8f4ff2b567af92e scid=760cb45d7af5e5f149a306a8ffe305de36525f5c len=1146 pn=7 [2025-04-30T12:27:32.726902902Z TRACE quiche] 760cb45d7af5e5f149a306a8ffe305de36525f5c tx frm CRYPTO off=6688 len=1141 [2025-04-30T12:27:32.726909705Z TRACE quiche::recovery::congestion::recovery] 760cb45d7af5e5f149a306a8ffe305de36525f5c timer=1.99798417s latest_rtt=0ns srtt=333ms min_rtt=333ms rttvar=166.5ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=8246 app_limited=true congestion_recovery_start_time=None Rate { delivered: 0, delivered_time: Instant { tv_sec: 453, tv_nsec: 457064921 }, first_sent_time: Instant { tv_sec: 453, tv_nsec: 457064921 }, end_of_app_limited: 6, last_sent_packet: 7, largest_acked: 0, rate_sample: RateSample { delivery_rate: 0, is_app_limited: false, interval: 0ns, delivered: 0, prior_delivered: 0, prior_time: None, send_elapsed: 0ns, ack_elapsed: 0ns, rtt: 0ns } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 0, last_update: Instant { tv_sec: 455, tv_nsec: 226913389 }, next_time: Instant { tv_sec: 455, tv_nsec: 226913389 }, max_datagram_size: 1350, last_packet_size: None, iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } [2025-04-30T12:27:32.726946604Z TRACE quiche_server] 760cb45d7af5e5f149a306a8ffe305de36525f5c written 1200 bytes with Some(SendInfo { from: [::]:443, to: [::ffff:193.167.0.100]:59690, at: Instant { tv_sec: 455, tv_nsec: 226913389 } }) [2025-04-30T12:27:32.726951623Z TRACE quiche_server] Collecting garbage [2025-04-30T12:27:32.726955931Z TRACE quiche_server] recv() would block [2025-04-30T12:27:32.726964277Z TRACE quiche] 760cb45d7af5e5f149a306a8ffe305de36525f5c tx pkt Handshake version=1 dcid=a8f4ff2b567af92e scid=760cb45d7af5e5f149a306a8ffe305de36525f5c len=1146 pn=8 [2025-04-30T12:27:32.726967503Z TRACE quiche] 760cb45d7af5e5f149a306a8ffe305de36525f5c tx frm CRYPTO off=7829 len=1141 [2025-04-30T12:27:32.726974185Z TRACE quiche::recovery::congestion::recovery] 760cb45d7af5e5f149a306a8ffe305de36525f5c timer=1.99798386s latest_rtt=0ns srtt=333ms min_rtt=333ms rttvar=166.5ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=9446 app_limited=true congestion_recovery_start_time=None Rate { delivered: 0, delivered_time: Instant { tv_sec: 453, tv_nsec: 457064921 }, first_sent_time: Instant { tv_sec: 453, tv_nsec: 457064921 }, end_of_app_limited: 7, last_sent_packet: 8, largest_acked: 0, rate_sample: RateSample { delivery_rate: 0, is_app_limited: false, interval: 0ns, delivered: 0, prior_delivered: 0, prior_time: None, send_elapsed: 0ns, ack_elapsed: 0ns, rtt: 0ns } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 0, last_update: Instant { tv_sec: 455, tv_nsec: 226977509 }, next_time: Instant { tv_sec: 455, tv_nsec: 226977509 }, max_datagram_size: 1350, last_packet_size: None, iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } [2025-04-30T12:27:32.727038595Z TRACE quiche_server] 760cb45d7af5e5f149a306a8ffe305de36525f5c written 1200 bytes with Some(SendInfo { from: [::]:443, to: [::ffff:193.167.0.100]:59690, at: Instant { tv_sec: 455, tv_nsec: 226977509 } }) [2025-04-30T12:27:32.727044667Z TRACE quiche_server] Collecting garbage [2025-04-30T12:27:32.727049135Z TRACE quiche_server] recv() would block [2025-04-30T12:27:32.727058092Z TRACE quiche] 760cb45d7af5e5f149a306a8ffe305de36525f5c tx pkt Handshake version=1 dcid=a8f4ff2b567af92e scid=760cb45d7af5e5f149a306a8ffe305de36525f5c len=978 pn=9 [2025-04-30T12:27:32.727061458Z TRACE quiche] 760cb45d7af5e5f149a306a8ffe305de36525f5c tx frm CRYPTO off=8970 len=973 [2025-04-30T12:27:32.727071276Z TRACE quiche::recovery::congestion::recovery] 760cb45d7af5e5f149a306a8ffe305de36525f5c timer=1.997980043s latest_rtt=0ns srtt=333ms min_rtt=333ms rttvar=166.5ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=10478 app_limited=true congestion_recovery_start_time=None Rate { delivered: 0, delivered_time: Instant { tv_sec: 453, tv_nsec: 457064921 }, first_sent_time: Instant { tv_sec: 453, tv_nsec: 457064921 }, end_of_app_limited: 8, last_sent_packet: 9, largest_acked: 0, rate_sample: RateSample { delivery_rate: 0, is_app_limited: false, interval: 0ns, delivered: 0, prior_delivered: 0, prior_time: None, send_elapsed: 0ns, ack_elapsed: 0ns, rtt: 0ns } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 0, last_update: Instant { tv_sec: 455, tv_nsec: 227070863 }, next_time: Instant { tv_sec: 455, tv_nsec: 227070863 }, max_datagram_size: 1350, last_packet_size: None, iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } [2025-04-30T12:27:32.727107734Z TRACE quiche_server] 760cb45d7af5e5f149a306a8ffe305de36525f5c written 1032 bytes with Some(SendInfo { from: [::]:443, to: [::ffff:193.167.0.100]:59690, at: Instant { tv_sec: 455, tv_nsec: 227070863 } }) [2025-04-30T12:27:32.727119997Z TRACE quiche_server] Collecting garbage [2025-04-30T12:27:32.727124485Z TRACE quiche_server] recv() would block [2025-04-30T12:27:32.727128473Z TRACE quiche_server] 760cb45d7af5e5f149a306a8ffe305de36525f5c done writing [2025-04-30T12:27:32.727131338Z TRACE quiche_server] Collecting garbage [2025-04-30T12:27:32.758400338Z TRACE quiche_server] got 59 bytes from [::ffff:193.167.0.100]:59690 to [::]:443 [2025-04-30T12:27:32.758418823Z TRACE quiche_server] got packet Handshake version=1 dcid=760cb45d7af5e5f149a306a8ffe305de36525f5c scid=a8f4ff2b567af92e [2025-04-30T12:27:32.758431647Z TRACE quiche] 760cb45d7af5e5f149a306a8ffe305de36525f5c rx pkt Handshake version=1 dcid=760cb45d7af5e5f149a306a8ffe305de36525f5c scid=a8f4ff2b567af92e len=22 pn=7 [2025-04-30T12:27:32.758442768Z TRACE quiche] 760cb45d7af5e5f149a306a8ffe305de36525f5c rx frm ACK delay=0 blocks=[1..4] ecn_counts=None [2025-04-30T12:27:32.758448809Z TRACE quiche::recovery::congestion::recovery] 760cb45d7af5e5f149a306a8ffe305de36525f5c packet newly acked 1 [2025-04-30T12:27:32.758452606Z TRACE quiche::recovery::congestion::recovery] 760cb45d7af5e5f149a306a8ffe305de36525f5c packet newly acked 2 [2025-04-30T12:27:32.758455401Z TRACE quiche::recovery::congestion::recovery] 760cb45d7af5e5f149a306a8ffe305de36525f5c packet newly acked 3 [2025-04-30T12:27:32.758458176Z TRACE quiche::recovery::congestion::recovery] 760cb45d7af5e5f149a306a8ffe305de36525f5c packet newly acked 4 [2025-04-30T12:27:32.758483023Z TRACE quiche_server] 760cb45d7af5e5f149a306a8ffe305de36525f5c processed 59 bytes [2025-04-30T12:27:32.758489765Z TRACE quiche_server] recv() would block [2025-04-30T12:27:32.758498962Z TRACE quiche_server] 760cb45d7af5e5f149a306a8ffe305de36525f5c done writing [2025-04-30T12:27:32.758502168Z TRACE quiche_server] Collecting garbage [2025-04-30T12:27:32.759128336Z TRACE quiche_server] got 59 bytes from [::ffff:193.167.0.100]:59690 to [::]:443 [2025-04-30T12:27:32.759136281Z TRACE quiche_server] got packet Handshake version=1 dcid=760cb45d7af5e5f149a306a8ffe305de36525f5c scid=a8f4ff2b567af92e [2025-04-30T12:27:32.759143845Z TRACE quiche] 760cb45d7af5e5f149a306a8ffe305de36525f5c rx pkt Handshake version=1 dcid=760cb45d7af5e5f149a306a8ffe305de36525f5c scid=a8f4ff2b567af92e len=22 pn=8 [2025-04-30T12:27:32.759150417Z TRACE quiche] 760cb45d7af5e5f149a306a8ffe305de36525f5c rx frm ACK delay=0 blocks=[1..5] ecn_counts=None [2025-04-30T12:27:32.759154695Z TRACE quiche::recovery::congestion::recovery] 760cb45d7af5e5f149a306a8ffe305de36525f5c packet newly acked 5 [2025-04-30T12:27:32.759168241Z TRACE quiche_server] 760cb45d7af5e5f149a306a8ffe305de36525f5c processed 59 bytes [2025-04-30T12:27:32.759173140Z TRACE quiche_server] recv() would block [2025-04-30T12:27:32.759178179Z TRACE quiche_server] 760cb45d7af5e5f149a306a8ffe305de36525f5c done writing [2025-04-30T12:27:32.759181145Z TRACE quiche_server] Collecting garbage [2025-04-30T12:27:32.760098075Z TRACE quiche_server] got 59 bytes from [::ffff:193.167.0.100]:59690 to [::]:443 [2025-04-30T12:27:32.760109125Z TRACE quiche_server] got packet Handshake version=1 dcid=760cb45d7af5e5f149a306a8ffe305de36525f5c scid=a8f4ff2b567af92e [2025-04-30T12:27:32.760116519Z TRACE quiche] 760cb45d7af5e5f149a306a8ffe305de36525f5c rx pkt Handshake version=1 dcid=760cb45d7af5e5f149a306a8ffe305de36525f5c scid=a8f4ff2b567af92e len=22 pn=9 [2025-04-30T12:27:32.760122380Z TRACE quiche] 760cb45d7af5e5f149a306a8ffe305de36525f5c rx frm ACK delay=0 blocks=[1..6] ecn_counts=None [2025-04-30T12:27:32.760125786Z TRACE quiche::recovery::congestion::recovery] 760cb45d7af5e5f149a306a8ffe305de36525f5c packet newly acked 6 [2025-04-30T12:27:32.760136135Z TRACE quiche_server] 760cb45d7af5e5f149a306a8ffe305de36525f5c processed 59 bytes [2025-04-30T12:27:32.760140183Z TRACE quiche_server] recv() would block [2025-04-30T12:27:32.760144110Z TRACE quiche_server] 760cb45d7af5e5f149a306a8ffe305de36525f5c done writing [2025-04-30T12:27:32.760154089Z TRACE quiche_server] Collecting garbage [2025-04-30T12:27:32.761077601Z TRACE quiche_server] got 59 bytes from [::ffff:193.167.0.100]:59690 to [::]:443 [2025-04-30T12:27:32.761086347Z TRACE quiche_server] got packet Handshake version=1 dcid=760cb45d7af5e5f149a306a8ffe305de36525f5c scid=a8f4ff2b567af92e [2025-04-30T12:27:32.761091918Z TRACE quiche] 760cb45d7af5e5f149a306a8ffe305de36525f5c rx pkt Handshake version=1 dcid=760cb45d7af5e5f149a306a8ffe305de36525f5c scid=a8f4ff2b567af92e len=22 pn=10 [2025-04-30T12:27:32.761097338Z TRACE quiche] 760cb45d7af5e5f149a306a8ffe305de36525f5c rx frm ACK delay=0 blocks=[1..7] ecn_counts=None [2025-04-30T12:27:32.761100664Z TRACE quiche::recovery::congestion::recovery] 760cb45d7af5e5f149a306a8ffe305de36525f5c packet newly acked 7 [2025-04-30T12:27:32.761110613Z TRACE quiche_server] 760cb45d7af5e5f149a306a8ffe305de36525f5c processed 59 bytes [2025-04-30T12:27:32.761114510Z TRACE quiche_server] recv() would block [2025-04-30T12:27:32.761118427Z TRACE quiche_server] 760cb45d7af5e5f149a306a8ffe305de36525f5c done writing [2025-04-30T12:27:32.761120722Z TRACE quiche_server] Collecting garbage [2025-04-30T12:27:32.762054282Z TRACE quiche_server] got 59 bytes from [::ffff:193.167.0.100]:59690 to [::]:443 [2025-04-30T12:27:32.762065223Z TRACE quiche_server] got packet Handshake version=1 dcid=760cb45d7af5e5f149a306a8ffe305de36525f5c scid=a8f4ff2b567af92e [2025-04-30T12:27:32.762071224Z TRACE quiche] 760cb45d7af5e5f149a306a8ffe305de36525f5c rx pkt Handshake version=1 dcid=760cb45d7af5e5f149a306a8ffe305de36525f5c scid=a8f4ff2b567af92e len=22 pn=11 [2025-04-30T12:27:32.762076744Z TRACE quiche] 760cb45d7af5e5f149a306a8ffe305de36525f5c rx frm ACK delay=0 blocks=[1..8] ecn_counts=None [2025-04-30T12:27:32.762080161Z TRACE quiche::recovery::congestion::recovery] 760cb45d7af5e5f149a306a8ffe305de36525f5c packet newly acked 8 [2025-04-30T12:27:32.762116238Z TRACE quiche_server] 760cb45d7af5e5f149a306a8ffe305de36525f5c processed 59 bytes [2025-04-30T12:27:32.762120726Z TRACE quiche_server] recv() would block [2025-04-30T12:27:32.762124864Z TRACE quiche_server] 760cb45d7af5e5f149a306a8ffe305de36525f5c done writing [2025-04-30T12:27:32.762127188Z TRACE quiche_server] Collecting garbage [2025-04-30T12:27:32.763473359Z TRACE quiche_server] got 220 bytes from [::ffff:193.167.0.100]:59690 to [::]:443 [2025-04-30T12:27:32.763484038Z TRACE quiche_server] got packet Handshake version=1 dcid=760cb45d7af5e5f149a306a8ffe305de36525f5c scid=a8f4ff2b567af92e [2025-04-30T12:27:32.763492114Z TRACE quiche] 760cb45d7af5e5f149a306a8ffe305de36525f5c rx pkt Handshake version=1 dcid=760cb45d7af5e5f149a306a8ffe305de36525f5c scid=a8f4ff2b567af92e len=61 pn=12 [2025-04-30T12:27:32.763501471Z TRACE quiche] 760cb45d7af5e5f149a306a8ffe305de36525f5c rx frm ACK delay=0 blocks=[1..9] ecn_counts=None [2025-04-30T12:27:32.763505509Z TRACE quiche::recovery::congestion::recovery] 760cb45d7af5e5f149a306a8ffe305de36525f5c packet newly acked 9 [2025-04-30T12:27:32.763509266Z TRACE quiche] 760cb45d7af5e5f149a306a8ffe305de36525f5c rx frm CRYPTO off=0 len=36 [2025-04-30T12:27:32.763523572Z TRACE quiche::tls] 760cb45d7af5e5f149a306a8ffe305de36525f5c set read secret lvl=OneRTT [2025-04-30T12:27:32.763542377Z TRACE quiche] 760cb45d7af5e5f149a306a8ffe305de36525f5c dropped epoch 1 state [2025-04-30T12:27:32.763546425Z TRACE quiche] 760cb45d7af5e5f149a306a8ffe305de36525f5c connection established: proto=Ok("hq-interop") cipher=Some(AES128_GCM) curve=Some("X25519") sigalg=None resumed=false TransportParams { original_destination_connection_id: None, max_idle_timeout: 0, stateless_reset_token: None, max_udp_payload_size: 1472, initial_max_data: 65536, initial_max_stream_data_bidi_local: 65536, initial_max_stream_data_bidi_remote: 65536, initial_max_stream_data_uni: 65536, initial_max_streams_bidi: 0, initial_max_streams_uni: 0, ack_delay_exponent: 3, max_ack_delay: 25, disable_active_migration: true, active_conn_id_limit: 2, initial_source_connection_id: Some(a8f4ff2b567af92e), retry_source_connection_id: None, max_datagram_frame_size: None, unknown_params: None } [2025-04-30T12:27:32.763572143Z TRACE quiche] 760cb45d7af5e5f149a306a8ffe305de36525f5c rx pkt Short dcid=760cb45d7af5e5f149a306a8ffe305de36525f5c key_phase=false len=101 pn=0 [2025-04-30T12:27:32.763578385Z TRACE quiche] 760cb45d7af5e5f149a306a8ffe305de36525f5c rx frm NEW_CONNECTION_ID seq_num=1 retire_prior_to=0 conn_id=[bc, 75, 7d, 2d, 59, 28, 20, 8e] reset_token=[96, ba, 0d, 9b, 3a, c9, 06, 20, 20, 30, 29, d2, 71, 62, b4, 76] [2025-04-30T12:27:32.763585999Z TRACE quiche] 760cb45d7af5e5f149a306a8ffe305de36525f5c rx frm NEW_CONNECTION_ID seq_num=2 retire_prior_to=0 conn_id=[55, 9d, 12, e5, 1e, 6c, a4, 86] reset_token=[1b, e7, 0e, cf, ff, 90, ec, b4, 01, 84, 2b, 38, 15, af, 44, 5b] [2025-04-30T12:27:32.763590728Z TRACE quiche] 760cb45d7af5e5f149a306a8ffe305de36525f5c rx frm NEW_CONNECTION_ID seq_num=3 retire_prior_to=0 conn_id=[ba, fd, e9, f4, 5d, 3d, 81, 31] reset_token=[49, c3, 29, c2, e4, 33, 76, 26, 28, 53, 23, 44, 05, d9, 5f, 14] [2025-04-30T12:27:32.763597690Z TRACE quiche_server] 760cb45d7af5e5f149a306a8ffe305de36525f5c processed 220 bytes [2025-04-30T12:27:32.763605054Z TRACE quiche_server] got 58 bytes from [::ffff:193.167.0.100]:59690 to [::]:443 [2025-04-30T12:27:32.763608330Z TRACE quiche_server] got packet Short dcid=760cb45d7af5e5f149a306a8ffe305de36525f5c key_phase=false [2025-04-30T12:27:32.763612448Z TRACE quiche] 760cb45d7af5e5f149a306a8ffe305de36525f5c rx pkt Short dcid=760cb45d7af5e5f149a306a8ffe305de36525f5c key_phase=false len=37 pn=1 [2025-04-30T12:27:32.763616436Z TRACE quiche] 760cb45d7af5e5f149a306a8ffe305de36525f5c rx frm STREAM id=0 off=0 len=17 fin=true [2025-04-30T12:27:32.763622888Z TRACE quiche_server] 760cb45d7af5e5f149a306a8ffe305de36525f5c processed 58 bytes [2025-04-30T12:27:32.763625783Z DEBUG quiche_apps::common] 760cb45d7af5e5f149a306a8ffe305de36525f5c response stream 0 is writable with capacity Ok(13500) [2025-04-30T12:27:32.763632526Z TRACE quiche_apps::common] 760cb45d7af5e5f149a306a8ffe305de36525f5c received 17 bytes [2025-04-30T12:27:32.763635050Z TRACE quiche_apps::common] 760cb45d7af5e5f149a306a8ffe305de36525f5c stream 0 has 17 bytes (fin? true) [2025-04-30T12:27:32.763639549Z INFO quiche_apps::common] 760cb45d7af5e5f149a306a8ffe305de36525f5c got GET request for "/www/lngowclwsy" on stream 0 [2025-04-30T12:27:32.763668954Z INFO quiche_apps::common] 760cb45d7af5e5f149a306a8ffe305de36525f5c sending response of size 5120 on stream 0 [2025-04-30T12:27:32.763677590Z TRACE quiche_server] recv() would block [2025-04-30T12:27:32.763686155Z TRACE quiche] 760cb45d7af5e5f149a306a8ffe305de36525f5c pmtud probe status false hs_con=true hs_sent=false cwnd_avail=13500 out_len=1350 left=1319 [2025-04-30T12:27:32.763695413Z TRACE quiche] 760cb45d7af5e5f149a306a8ffe305de36525f5c tx pkt Short dcid=a8f4ff2b567af92e key_phase=false len=1324 pn=10 [2025-04-30T12:27:32.763698809Z TRACE quiche] 760cb45d7af5e5f149a306a8ffe305de36525f5c tx frm ACK delay=9 blocks=[0..1] ecn_counts=None [2025-04-30T12:27:32.763702666Z TRACE quiche] 760cb45d7af5e5f149a306a8ffe305de36525f5c tx frm NEW_CONNECTION_ID seq_num=1 retire_prior_to=0 conn_id=[b0, c2, 67, 1a, ec, 89, 75, bc, b3, d4, e9, f5, e4, 01, 27, c2, d9, dc, 04, 04] reset_token=[1a, 97, 8e, 02, 7b, ed, a9, bd, b0, 7b, 3f, b1, 3c, 91, 3f, 6a] [2025-04-30T12:27:32.763709719Z TRACE quiche] 760cb45d7af5e5f149a306a8ffe305de36525f5c tx frm HANDSHAKE_DONE [2025-04-30T12:27:32.763712635Z TRACE quiche] 760cb45d7af5e5f149a306a8ffe305de36525f5c tx frm STREAM id=0 off=0 len=1273 fin=false [2025-04-30T12:27:32.763724707Z TRACE quiche::recovery::congestion::recovery] 760cb45d7af5e5f149a306a8ffe305de36525f5c timer=81.041863ms latest_rtt=36.439242ms srtt=33.139951ms min_rtt=31.801202ms rttvar=5.736669ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=1350 app_limited=true congestion_recovery_start_time=None Rate { delivered: 10478, delivered_time: Instant { tv_sec: 455, tv_nsec: 263699588 }, first_sent_time: Instant { tv_sec: 455, tv_nsec: 263699588 }, end_of_app_limited: 9, last_sent_packet: 10, largest_acked: 9, rate_sample: RateSample { delivery_rate: 5816, is_app_limited: true, interval: 1.801382262s, delivered: 10478, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 453, tv_nsec: 457064921 }), send_elapsed: 0ns, ack_elapsed: 1.801382262s, rtt: 1.801382262s } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 509204, last_update: Instant { tv_sec: 455, tv_nsec: 263699588 }, next_time: Instant { tv_sec: 455, tv_nsec: 263699588 }, max_datagram_size: 1350, last_packet_size: Some(0), iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } [2025-04-30T12:27:32.763749764Z TRACE quiche] 760cb45d7af5e5f149a306a8ffe305de36525f5c pmtud probe status false hs_con=true hs_sent=true cwnd_avail=12150 out_len=1350 left=1324 [2025-04-30T12:27:32.763754313Z TRACE quiche] 760cb45d7af5e5f149a306a8ffe305de36525f5c tx pkt Short dcid=a8f4ff2b567af92e key_phase=false len=1324 pn=11 [2025-04-30T12:27:32.763757488Z TRACE quiche] 760cb45d7af5e5f149a306a8ffe305de36525f5c tx frm STREAM id=0 off=1273 len=1318 fin=false [2025-04-30T12:27:32.763763790Z TRACE quiche::recovery::congestion::recovery] 760cb45d7af5e5f149a306a8ffe305de36525f5c timer=81.069976ms latest_rtt=36.439242ms srtt=33.139951ms min_rtt=31.801202ms rttvar=5.736669ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=2700 app_limited=true congestion_recovery_start_time=None Rate { delivered: 10478, delivered_time: Instant { tv_sec: 455, tv_nsec: 263699588 }, first_sent_time: Instant { tv_sec: 455, tv_nsec: 263699588 }, end_of_app_limited: 10, last_sent_packet: 11, largest_acked: 9, rate_sample: RateSample { delivery_rate: 5816, is_app_limited: true, interval: 1.801382262s, delivered: 10478, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 453, tv_nsec: 457064921 }), send_elapsed: 0ns, ack_elapsed: 1.801382262s, rtt: 1.801382262s } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 509204, last_update: Instant { tv_sec: 455, tv_nsec: 263699588 }, next_time: Instant { tv_sec: 455, tv_nsec: 263699588 }, max_datagram_size: 1350, last_packet_size: Some(0), iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } [2025-04-30T12:27:32.763776795Z TRACE quiche] 760cb45d7af5e5f149a306a8ffe305de36525f5c pmtud probe status false hs_con=true hs_sent=true cwnd_avail=10800 out_len=1350 left=1324 [2025-04-30T12:27:32.763780612Z TRACE quiche] 760cb45d7af5e5f149a306a8ffe305de36525f5c tx pkt Short dcid=a8f4ff2b567af92e key_phase=false len=1324 pn=12 [2025-04-30T12:27:32.763783647Z TRACE quiche] 760cb45d7af5e5f149a306a8ffe305de36525f5c tx frm STREAM id=0 off=2591 len=1318 fin=false [2025-04-30T12:27:32.763789118Z TRACE quiche::recovery::congestion::recovery] 760cb45d7af5e5f149a306a8ffe305de36525f5c timer=81.07254ms latest_rtt=36.439242ms srtt=33.139951ms min_rtt=31.801202ms rttvar=5.736669ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=4050 app_limited=true congestion_recovery_start_time=None Rate { delivered: 10478, delivered_time: Instant { tv_sec: 455, tv_nsec: 263699588 }, first_sent_time: Instant { tv_sec: 455, tv_nsec: 263699588 }, end_of_app_limited: 11, last_sent_packet: 12, largest_acked: 9, rate_sample: RateSample { delivery_rate: 5816, is_app_limited: true, interval: 1.801382262s, delivered: 10478, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 453, tv_nsec: 457064921 }), send_elapsed: 0ns, ack_elapsed: 1.801382262s, rtt: 1.801382262s } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 509204, last_update: Instant { tv_sec: 455, tv_nsec: 263699588 }, next_time: Instant { tv_sec: 455, tv_nsec: 263699588 }, max_datagram_size: 1350, last_packet_size: Some(0), iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } [2025-04-30T12:27:32.763804636Z TRACE quiche] 760cb45d7af5e5f149a306a8ffe305de36525f5c pmtud probe status false hs_con=true hs_sent=true cwnd_avail=9450 out_len=1350 left=1324 [2025-04-30T12:27:32.763808443Z TRACE quiche] 760cb45d7af5e5f149a306a8ffe305de36525f5c tx pkt Short dcid=a8f4ff2b567af92e key_phase=false len=1217 pn=13 [2025-04-30T12:27:32.763811429Z TRACE quiche] 760cb45d7af5e5f149a306a8ffe305de36525f5c tx frm STREAM id=0 off=3909 len=1211 fin=true [2025-04-30T12:27:32.763816819Z TRACE quiche::recovery::congestion::recovery] 760cb45d7af5e5f149a306a8ffe305de36525f5c timer=81.072901ms latest_rtt=36.439242ms srtt=33.139951ms min_rtt=31.801202ms rttvar=5.736669ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=5293 app_limited=true congestion_recovery_start_time=None Rate { delivered: 10478, delivered_time: Instant { tv_sec: 455, tv_nsec: 263699588 }, first_sent_time: Instant { tv_sec: 455, tv_nsec: 263699588 }, end_of_app_limited: 12, last_sent_packet: 13, largest_acked: 9, rate_sample: RateSample { delivery_rate: 5816, is_app_limited: true, interval: 1.801382262s, delivered: 10478, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 453, tv_nsec: 457064921 }), send_elapsed: 0ns, ack_elapsed: 1.801382262s, rtt: 1.801382262s } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 509204, last_update: Instant { tv_sec: 455, tv_nsec: 263699588 }, next_time: Instant { tv_sec: 455, tv_nsec: 263699588 }, max_datagram_size: 1350, last_packet_size: Some(0), iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } [2025-04-30T12:27:32.763937344Z TRACE quiche_server] 760cb45d7af5e5f149a306a8ffe305de36525f5c written 5293 bytes with Some(SendInfo { from: [::]:443, to: [::ffff:193.167.0.100]:59690, at: Instant { tv_sec: 455, tv_nsec: 263699588 } }) [2025-04-30T12:27:32.763949557Z TRACE quiche_server] Collecting garbage [2025-04-30T12:27:32.763958203Z TRACE quiche_server] recv() would block [2025-04-30T12:27:32.763964064Z TRACE quiche_server] 760cb45d7af5e5f149a306a8ffe305de36525f5c done writing [2025-04-30T12:27:32.763968833Z TRACE quiche_server] Collecting garbage [2025-04-30T12:27:32.795501376Z TRACE quiche_server] got 43 bytes from [::ffff:193.167.0.100]:59690 to [::]:443 [2025-04-30T12:27:32.795512276Z TRACE quiche_server] got packet Short dcid=760cb45d7af5e5f149a306a8ffe305de36525f5c key_phase=false [2025-04-30T12:27:32.795521073Z TRACE quiche] 760cb45d7af5e5f149a306a8ffe305de36525f5c rx pkt Short dcid=760cb45d7af5e5f149a306a8ffe305de36525f5c key_phase=false len=22 pn=2 [2025-04-30T12:27:32.795529028Z TRACE quiche] 760cb45d7af5e5f149a306a8ffe305de36525f5c rx frm ACK delay=0 blocks=[10..10] ecn_counts=None [2025-04-30T12:27:32.795533135Z TRACE quiche::recovery::congestion::recovery] 760cb45d7af5e5f149a306a8ffe305de36525f5c packet newly acked 10 [2025-04-30T12:27:32.795550868Z TRACE quiche_server] 760cb45d7af5e5f149a306a8ffe305de36525f5c processed 43 bytes [2025-04-30T12:27:32.795555928Z TRACE quiche_server] recv() would block [2025-04-30T12:27:32.795559554Z TRACE quiche_server] 760cb45d7af5e5f149a306a8ffe305de36525f5c done writing [2025-04-30T12:27:32.795561879Z TRACE quiche_server] Collecting garbage [2025-04-30T12:27:32.797550748Z TRACE quiche_server] got 43 bytes from [::ffff:193.167.0.100]:59690 to [::]:443 [2025-04-30T12:27:32.797558482Z TRACE quiche_server] got packet Short dcid=760cb45d7af5e5f149a306a8ffe305de36525f5c key_phase=false [2025-04-30T12:27:32.797563391Z TRACE quiche] 760cb45d7af5e5f149a306a8ffe305de36525f5c rx pkt Short dcid=760cb45d7af5e5f149a306a8ffe305de36525f5c key_phase=false len=22 pn=3 [2025-04-30T12:27:32.797573771Z TRACE quiche] 760cb45d7af5e5f149a306a8ffe305de36525f5c rx frm ACK delay=0 blocks=[10..12] ecn_counts=None [2025-04-30T12:27:32.797577288Z TRACE quiche::recovery::congestion::recovery] 760cb45d7af5e5f149a306a8ffe305de36525f5c packet newly acked 11 [2025-04-30T12:27:32.797579772Z TRACE quiche::recovery::congestion::recovery] 760cb45d7af5e5f149a306a8ffe305de36525f5c packet newly acked 12 [2025-04-30T12:27:32.797588989Z TRACE quiche_server] 760cb45d7af5e5f149a306a8ffe305de36525f5c processed 43 bytes [2025-04-30T12:27:32.797592866Z TRACE quiche_server] recv() would block [2025-04-30T12:27:32.797595632Z TRACE quiche_server] 760cb45d7af5e5f149a306a8ffe305de36525f5c done writing [2025-04-30T12:27:32.797597806Z TRACE quiche_server] Collecting garbage [2025-04-30T12:27:32.798670066Z TRACE quiche_server] got 42 bytes from [::ffff:193.167.0.100]:59690 to [::]:443 [2025-04-30T12:27:32.798676187Z TRACE quiche_server] got packet Short dcid=760cb45d7af5e5f149a306a8ffe305de36525f5c key_phase=false [2025-04-30T12:27:32.798680665Z TRACE quiche] 760cb45d7af5e5f149a306a8ffe305de36525f5c rx pkt Short dcid=760cb45d7af5e5f149a306a8ffe305de36525f5c key_phase=false len=21 pn=4 [2025-04-30T12:27:32.798685564Z TRACE quiche] 760cb45d7af5e5f149a306a8ffe305de36525f5c rx frm CONNECTION_CLOSE err=0 frame=0 reason=[] [2025-04-30T12:27:32.798691896Z TRACE quiche_server] 760cb45d7af5e5f149a306a8ffe305de36525f5c processed 42 bytes [2025-04-30T12:27:32.798695293Z TRACE quiche_server] recv() would block [2025-04-30T12:27:32.798697517Z TRACE quiche_server] 760cb45d7af5e5f149a306a8ffe305de36525f5c done writing [2025-04-30T12:27:32.798699761Z TRACE quiche_server] Collecting garbage [2025-04-30T12:27:32.942901908Z TRACE quiche_server] timed out [2025-04-30T12:27:32.942932886Z TRACE quiche] 760cb45d7af5e5f149a306a8ffe305de36525f5c draining timeout expired [2025-04-30T12:27:32.942980985Z TRACE quiche_server] 760cb45d7af5e5f149a306a8ffe305de36525f5c done writing [2025-04-30T12:27:32.943013967Z TRACE quiche_server] Collecting garbage [2025-04-30T12:27:32.943020569Z INFO quiche_server] 760cb45d7af5e5f149a306a8ffe305de36525f5c connection collected recv=13 sent=14 lost=0 retrans=0 sent_bytes=15925 recv_bytes=1054 lost_bytes=0 [local_addr=[::]:443 peer_addr=[::ffff:193.167.0.100]:59690 validation_state=Validated active=true recv=13 sent=14 lost=0 retrans=0 rtt=33.09039ms min_rtt=Some(31.801202ms) rttvar=3.697056ms cwnd=13500 sent_bytes=15925 recv_bytes=1054 lost_bytes=0 stream_retrans_bytes=0 pmtu=1350 delivery_rate=127203]