[2025-04-30T10:31:43.474329783Z INFO quiche_server] listening on [::]:443 [2025-04-30T10:31:43.474352175Z TRACE mio::poll] registering event source with poller: token=Token(0), interests=READABLE [2025-04-30T10:31:43.474358647Z TRACE quiche_server] GSO detected: false [2025-04-30T10:31:44.266135301Z TRACE quiche_server] got 1207 bytes from [::ffff:193.167.100.2]:54503 to [::]:443 [2025-04-30T10:31:44.266168974Z TRACE quiche_server] got packet Initial version=57414954 dcid= scid= token= [2025-04-30T10:31:44.266177500Z WARN quiche_server] Doing version negotiation [2025-04-30T10:31:44.266270383Z TRACE quiche_server] got 1207 bytes from [::ffff:193.167.100.2]:54503 to [::]:443 [2025-04-30T10:31:44.266276424Z TRACE quiche_server] got packet Initial version=57414954 dcid= scid= token= [2025-04-30T10:31:44.266280271Z WARN quiche_server] Doing version negotiation [2025-04-30T10:31:44.266300950Z TRACE quiche_server] got 1207 bytes from [::ffff:193.167.100.2]:54503 to [::]:443 [2025-04-30T10:31:44.266304847Z TRACE quiche_server] got packet Initial version=57414954 dcid= scid= token= [2025-04-30T10:31:44.266308143Z WARN quiche_server] Doing version negotiation [2025-04-30T10:31:44.266335284Z TRACE quiche_server] recv() would block [2025-04-30T10:31:45.225513416Z TRACE quiche_server] got 1280 bytes from [::ffff:193.167.0.100]:50943 to [::]:443 [2025-04-30T10:31:45.225540316Z TRACE quiche_server] got packet Initial version=1 dcid=de9ba4cadd48e4968a5c93a1b11bd2806c7d7b2f scid= token= [2025-04-30T10:31:45.225548962Z DEBUG quiche_server] New connection: dcid=de9ba4cadd48e4968a5c93a1b11bd2806c7d7b2f scid=28fdcfb82eef4c4b614eae3386fe0b8c8be3a334 [2025-04-30T10:31:45.225752812Z TRACE quiche] 28fdcfb82eef4c4b614eae3386fe0b8c8be3a334 rx pkt Initial version=1 dcid=de9ba4cadd48e4968a5c93a1b11bd2806c7d7b2f scid= token= len=1250 pn=0 [2025-04-30T10:31:45.225767259Z TRACE quiche] 28fdcfb82eef4c4b614eae3386fe0b8c8be3a334 rx frm PADDING len=953 [2025-04-30T10:31:45.225770776Z TRACE quiche] 28fdcfb82eef4c4b614eae3386fe0b8c8be3a334 rx frm CRYPTO off=0 len=275 [2025-04-30T10:31:45.225797415Z TRACE quiche::tls] checking peer ALPN Ok("hq-interop") against Ok("h3") [2025-04-30T10:31:45.225801282Z TRACE quiche::tls] checking peer ALPN Ok("hq-interop") against Ok("hq-interop") [2025-04-30T10:31:45.225883736Z TRACE quiche::tls] 28fdcfb82eef4c4b614eae3386fe0b8c8be3a334 write message lvl=Initial len=90 [2025-04-30T10:31:45.225911538Z TRACE quiche::tls] 28fdcfb82eef4c4b614eae3386fe0b8c8be3a334 set write secret lvl=Handshake [2025-04-30T10:31:45.226016494Z TRACE quiche::tls] 28fdcfb82eef4c4b614eae3386fe0b8c8be3a334 write message lvl=Handshake len=708 [2025-04-30T10:31:45.226022044Z TRACE quiche::tls] 28fdcfb82eef4c4b614eae3386fe0b8c8be3a334 set write secret lvl=OneRTT [2025-04-30T10:31:45.226028977Z TRACE quiche::tls] 28fdcfb82eef4c4b614eae3386fe0b8c8be3a334 set read secret lvl=Handshake [2025-04-30T10:31:45.226059234Z TRACE quiche_server] 28fdcfb82eef4c4b614eae3386fe0b8c8be3a334 processed 1280 bytes [2025-04-30T10:31:45.226071296Z TRACE quiche_server] recv() would block [2025-04-30T10:31:45.226082317Z TRACE quiche] 28fdcfb82eef4c4b614eae3386fe0b8c8be3a334 tx pkt Initial version=1 dcid= scid=28fdcfb82eef4c4b614eae3386fe0b8c8be3a334 len=99 pn=0 [2025-04-30T10:31:45.226085663Z TRACE quiche] 28fdcfb82eef4c4b614eae3386fe0b8c8be3a334 tx frm ACK delay=43 blocks=[0..0] ecn_counts=None [2025-04-30T10:31:45.226090041Z TRACE quiche] 28fdcfb82eef4c4b614eae3386fe0b8c8be3a334 tx frm CRYPTO off=0 len=90 [2025-04-30T10:31:45.226099409Z TRACE quiche::recovery::congestion::recovery] 28fdcfb82eef4c4b614eae3386fe0b8c8be3a334 timer=998.973571ms latest_rtt=0ns srtt=333ms min_rtt=333ms rttvar=166.5ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=146 app_limited=true congestion_recovery_start_time=None Rate { delivered: 0, delivered_time: Instant { tv_sec: 282, tv_nsec: 705128356 }, first_sent_time: Instant { tv_sec: 282, tv_nsec: 705128356 }, 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: 282, tv_nsec: 705128356 }, next_time: Instant { tv_sec: 282, tv_nsec: 705128356 }, 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:31:45.226126609Z TRACE quiche] 28fdcfb82eef4c4b614eae3386fe0b8c8be3a334 tx pkt Handshake version=1 dcid= scid=28fdcfb82eef4c4b614eae3386fe0b8c8be3a334 len=712 pn=1 [2025-04-30T10:31:45.226129585Z TRACE quiche] 28fdcfb82eef4c4b614eae3386fe0b8c8be3a334 tx frm CRYPTO off=0 len=708 [2025-04-30T10:31:45.226135205Z TRACE quiche::recovery::congestion::recovery] 28fdcfb82eef4c4b614eae3386fe0b8c8be3a334 timer=998.938075ms latest_rtt=0ns srtt=333ms min_rtt=333ms rttvar=166.5ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=904 app_limited=true congestion_recovery_start_time=None Rate { delivered: 0, delivered_time: Instant { tv_sec: 282, tv_nsec: 705128356 }, first_sent_time: Instant { tv_sec: 282, tv_nsec: 705128356 }, 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: 282, tv_nsec: 705128356 }, next_time: Instant { tv_sec: 282, tv_nsec: 705128356 }, 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:31:45.226186661Z TRACE quiche_server] 28fdcfb82eef4c4b614eae3386fe0b8c8be3a334 written 1200 bytes with Some(SendInfo { from: [::]:443, to: [::ffff:193.167.0.100]:50943, at: Instant { tv_sec: 282, tv_nsec: 705128356 } }) [2025-04-30T10:31:45.226192652Z TRACE quiche_server] Collecting garbage [2025-04-30T10:31:45.226197131Z TRACE quiche_server] recv() would block [2025-04-30T10:31:45.226200587Z TRACE quiche_server] 28fdcfb82eef4c4b614eae3386fe0b8c8be3a334 done writing [2025-04-30T10:31:45.226202861Z TRACE quiche_server] Collecting garbage [2025-04-30T10:31:45.421016526Z TRACE quiche_server] got 1280 bytes from [::ffff:193.167.0.100]:50943 to [::]:443 [2025-04-30T10:31:45.421049568Z TRACE quiche_server] got packet Initial version=1 dcid=de9ba4cadd48e4968a5c93a1b11bd2806c7d7b2f scid= token= [2025-04-30T10:31:45.421062783Z TRACE quiche] 28fdcfb82eef4c4b614eae3386fe0b8c8be3a334 rx pkt Initial version=1 dcid=de9ba4cadd48e4968a5c93a1b11bd2806c7d7b2f scid= token= len=1250 pn=1 [2025-04-30T10:31:45.421081608Z TRACE quiche] 28fdcfb82eef4c4b614eae3386fe0b8c8be3a334 rx frm PADDING len=953 [2025-04-30T10:31:45.421087750Z TRACE quiche] 28fdcfb82eef4c4b614eae3386fe0b8c8be3a334 rx frm CRYPTO off=0 len=275 [2025-04-30T10:31:45.421113938Z TRACE quiche_server] 28fdcfb82eef4c4b614eae3386fe0b8c8be3a334 processed 1280 bytes [2025-04-30T10:31:45.421119859Z TRACE quiche_server] recv() would block [2025-04-30T10:31:45.421130619Z TRACE quiche] 28fdcfb82eef4c4b614eae3386fe0b8c8be3a334 tx pkt Initial version=1 dcid= scid=28fdcfb82eef4c4b614eae3386fe0b8c8be3a334 len=5 pn=2 [2025-04-30T10:31:45.421133695Z TRACE quiche] 28fdcfb82eef4c4b614eae3386fe0b8c8be3a334 tx frm ACK delay=8 blocks=[0..1] ecn_counts=None [2025-04-30T10:31:45.421144285Z TRACE quiche::recovery::congestion::recovery] 28fdcfb82eef4c4b614eae3386fe0b8c8be3a334 timer=803.928364ms latest_rtt=0ns srtt=333ms min_rtt=333ms rttvar=166.5ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=904 app_limited=true congestion_recovery_start_time=None Rate { delivered: 0, delivered_time: Instant { tv_sec: 282, tv_nsec: 705128356 }, first_sent_time: Instant { tv_sec: 282, tv_nsec: 705128356 }, 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: 282, tv_nsec: 900177280 }, next_time: Instant { tv_sec: 282, tv_nsec: 900177280 }, 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:31:45.421219796Z TRACE quiche_server] 28fdcfb82eef4c4b614eae3386fe0b8c8be3a334 written 1200 bytes with Some(SendInfo { from: [::]:443, to: [::ffff:193.167.0.100]:50943, at: Instant { tv_sec: 282, tv_nsec: 900177280 } }) [2025-04-30T10:31:45.421229423Z TRACE quiche_server] Collecting garbage [2025-04-30T10:31:45.421236246Z TRACE quiche_server] recv() would block [2025-04-30T10:31:45.421241897Z TRACE quiche_server] 28fdcfb82eef4c4b614eae3386fe0b8c8be3a334 done writing [2025-04-30T10:31:45.421245884Z TRACE quiche_server] Collecting garbage [2025-04-30T10:31:45.422012414Z TRACE quiche_server] got 1280 bytes from [::ffff:193.167.0.100]:50943 to [::]:443 [2025-04-30T10:31:45.422020048Z TRACE quiche_server] got packet Initial version=1 dcid=de9ba4cadd48e4968a5c93a1b11bd2806c7d7b2f scid= token= [2025-04-30T10:31:45.422025708Z TRACE quiche] 28fdcfb82eef4c4b614eae3386fe0b8c8be3a334 rx pkt Initial version=1 dcid=de9ba4cadd48e4968a5c93a1b11bd2806c7d7b2f scid= token= len=1250 pn=2 [2025-04-30T10:31:45.422033803Z TRACE quiche] 28fdcfb82eef4c4b614eae3386fe0b8c8be3a334 rx frm PADDING len=953 [2025-04-30T10:31:45.422036609Z TRACE quiche] 28fdcfb82eef4c4b614eae3386fe0b8c8be3a334 rx frm CRYPTO off=0 len=275 [2025-04-30T10:31:45.422046327Z TRACE quiche_server] 28fdcfb82eef4c4b614eae3386fe0b8c8be3a334 processed 1280 bytes [2025-04-30T10:31:45.422049944Z TRACE quiche_server] recv() would block [2025-04-30T10:31:45.422056586Z TRACE quiche] 28fdcfb82eef4c4b614eae3386fe0b8c8be3a334 tx pkt Initial version=1 dcid= scid=28fdcfb82eef4c4b614eae3386fe0b8c8be3a334 len=5 pn=3 [2025-04-30T10:31:45.422059241Z TRACE quiche] 28fdcfb82eef4c4b614eae3386fe0b8c8be3a334 tx frm ACK delay=3 blocks=[0..2] ecn_counts=None [2025-04-30T10:31:45.422065803Z TRACE quiche::recovery::congestion::recovery] 28fdcfb82eef4c4b614eae3386fe0b8c8be3a334 timer=803.007397ms latest_rtt=0ns srtt=333ms min_rtt=333ms rttvar=166.5ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=904 app_limited=true congestion_recovery_start_time=None Rate { delivered: 0, delivered_time: Instant { tv_sec: 282, tv_nsec: 705128356 }, first_sent_time: Instant { tv_sec: 282, tv_nsec: 705128356 }, end_of_app_limited: 1, last_sent_packet: 3, largest_acked: 0, rate_sample: RateSample { delivery_rate: 0, is_app_limited: false, interval: 0ns, delivered: 0, prior_delivered: 0, prior_time: None, send_elapsed: 0ns, ack_elapsed: 0ns, rtt: 0ns } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 0, last_update: Instant { tv_sec: 282, tv_nsec: 901106682 }, next_time: Instant { tv_sec: 282, tv_nsec: 901106682 }, 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:31:45.422104966Z TRACE quiche_server] 28fdcfb82eef4c4b614eae3386fe0b8c8be3a334 written 1200 bytes with Some(SendInfo { from: [::]:443, to: [::ffff:193.167.0.100]:50943, at: Instant { tv_sec: 282, tv_nsec: 901106682 } }) [2025-04-30T10:31:45.422119764Z TRACE quiche_server] Collecting garbage [2025-04-30T10:31:45.422125585Z TRACE quiche_server] recv() would block [2025-04-30T10:31:45.422130904Z TRACE quiche_server] 28fdcfb82eef4c4b614eae3386fe0b8c8be3a334 done writing [2025-04-30T10:31:45.422134962Z TRACE quiche_server] Collecting garbage [2025-04-30T10:31:45.821982008Z TRACE quiche_server] got 1280 bytes from [::ffff:193.167.0.100]:50943 to [::]:443 [2025-04-30T10:31:45.822017193Z TRACE quiche_server] got packet Initial version=1 dcid=de9ba4cadd48e4968a5c93a1b11bd2806c7d7b2f scid= token= [2025-04-30T10:31:45.822032773Z TRACE quiche] 28fdcfb82eef4c4b614eae3386fe0b8c8be3a334 rx pkt Initial version=1 dcid=de9ba4cadd48e4968a5c93a1b11bd2806c7d7b2f scid= token= len=1250 pn=3 [2025-04-30T10:31:45.822049424Z TRACE quiche] 28fdcfb82eef4c4b614eae3386fe0b8c8be3a334 rx frm PADDING len=953 [2025-04-30T10:31:45.822054102Z TRACE quiche] 28fdcfb82eef4c4b614eae3386fe0b8c8be3a334 rx frm CRYPTO off=0 len=275 [2025-04-30T10:31:45.822082686Z TRACE quiche_server] 28fdcfb82eef4c4b614eae3386fe0b8c8be3a334 processed 1280 bytes [2025-04-30T10:31:45.822089608Z TRACE quiche_server] recv() would block [2025-04-30T10:31:45.822102462Z TRACE quiche] 28fdcfb82eef4c4b614eae3386fe0b8c8be3a334 tx pkt Initial version=1 dcid= scid=28fdcfb82eef4c4b614eae3386fe0b8c8be3a334 len=5 pn=4 [2025-04-30T10:31:45.822108594Z TRACE quiche] 28fdcfb82eef4c4b614eae3386fe0b8c8be3a334 tx frm ACK delay=8 blocks=[0..3] ecn_counts=None [2025-04-30T10:31:45.822124594Z TRACE quiche::recovery::congestion::recovery] 28fdcfb82eef4c4b614eae3386fe0b8c8be3a334 timer=402.947675ms latest_rtt=0ns srtt=333ms min_rtt=333ms rttvar=166.5ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=904 app_limited=true congestion_recovery_start_time=None Rate { delivered: 0, delivered_time: Instant { tv_sec: 282, tv_nsec: 705128356 }, first_sent_time: Instant { tv_sec: 282, tv_nsec: 705128356 }, end_of_app_limited: 1, last_sent_packet: 4, largest_acked: 0, rate_sample: RateSample { delivery_rate: 0, is_app_limited: false, interval: 0ns, delivered: 0, prior_delivered: 0, prior_time: None, send_elapsed: 0ns, ack_elapsed: 0ns, rtt: 0ns } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 0, last_update: Instant { tv_sec: 283, tv_nsec: 301147329 }, next_time: Instant { tv_sec: 283, tv_nsec: 301147329 }, 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:31:45.822201667Z TRACE quiche_server] 28fdcfb82eef4c4b614eae3386fe0b8c8be3a334 written 1200 bytes with Some(SendInfo { from: [::]:443, to: [::ffff:193.167.0.100]:50943, at: Instant { tv_sec: 283, tv_nsec: 301147329 } }) [2025-04-30T10:31:45.822223278Z TRACE quiche_server] Collecting garbage [2025-04-30T10:31:45.822231223Z TRACE quiche_server] recv() would block [2025-04-30T10:31:45.822237975Z TRACE quiche_server] 28fdcfb82eef4c4b614eae3386fe0b8c8be3a334 done writing [2025-04-30T10:31:45.822242413Z TRACE quiche_server] Collecting garbage [2025-04-30T10:31:45.822908826Z TRACE quiche_server] got 1280 bytes from [::ffff:193.167.0.100]:50943 to [::]:443 [2025-04-30T10:31:45.822919526Z TRACE quiche_server] got packet Initial version=1 dcid=de9ba4cadd48e4968a5c93a1b11bd2806c7d7b2f scid= token= [2025-04-30T10:31:45.822927931Z TRACE quiche] 28fdcfb82eef4c4b614eae3386fe0b8c8be3a334 rx pkt Initial version=1 dcid=de9ba4cadd48e4968a5c93a1b11bd2806c7d7b2f scid= token= len=1250 pn=4 [2025-04-30T10:31:45.822938832Z TRACE quiche] 28fdcfb82eef4c4b614eae3386fe0b8c8be3a334 rx frm PADDING len=953 [2025-04-30T10:31:45.822942499Z TRACE quiche] 28fdcfb82eef4c4b614eae3386fe0b8c8be3a334 rx frm CRYPTO off=0 len=275 [2025-04-30T10:31:45.822986130Z TRACE quiche_server] 28fdcfb82eef4c4b614eae3386fe0b8c8be3a334 processed 1280 bytes [2025-04-30T10:31:45.823011507Z TRACE quiche_server] recv() would block [2025-04-30T10:31:45.823021606Z TRACE quiche] 28fdcfb82eef4c4b614eae3386fe0b8c8be3a334 tx pkt Initial version=1 dcid= scid=28fdcfb82eef4c4b614eae3386fe0b8c8be3a334 len=5 pn=5 [2025-04-30T10:31:45.823025153Z TRACE quiche] 28fdcfb82eef4c4b614eae3386fe0b8c8be3a334 tx frm ACK delay=11 blocks=[0..4] ecn_counts=None [2025-04-30T10:31:45.823035853Z TRACE quiche::recovery::congestion::recovery] 28fdcfb82eef4c4b614eae3386fe0b8c8be3a334 timer=402.037157ms latest_rtt=0ns srtt=333ms min_rtt=333ms rttvar=166.5ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=904 app_limited=true congestion_recovery_start_time=None Rate { delivered: 0, delivered_time: Instant { tv_sec: 282, tv_nsec: 705128356 }, first_sent_time: Instant { tv_sec: 282, tv_nsec: 705128356 }, end_of_app_limited: 1, last_sent_packet: 5, largest_acked: 0, rate_sample: RateSample { delivery_rate: 0, is_app_limited: false, interval: 0ns, delivered: 0, prior_delivered: 0, prior_time: None, send_elapsed: 0ns, ack_elapsed: 0ns, rtt: 0ns } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 0, last_update: Instant { tv_sec: 283, tv_nsec: 302069338 }, next_time: Instant { tv_sec: 283, tv_nsec: 302069338 }, 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:31:45.823089934Z TRACE quiche_server] 28fdcfb82eef4c4b614eae3386fe0b8c8be3a334 written 1200 bytes with Some(SendInfo { from: [::]:443, to: [::ffff:193.167.0.100]:50943, at: Instant { tv_sec: 283, tv_nsec: 302069338 } }) [2025-04-30T10:31:45.823100293Z TRACE quiche_server] Collecting garbage [2025-04-30T10:31:45.823107276Z TRACE quiche_server] recv() would block [2025-04-30T10:31:45.823114099Z TRACE quiche_server] 28fdcfb82eef4c4b614eae3386fe0b8c8be3a334 done writing [2025-04-30T10:31:45.823118587Z TRACE quiche_server] Collecting garbage [2025-04-30T10:31:46.225576999Z TRACE quiche_server] timed out [2025-04-30T10:31:46.225610151Z TRACE quiche] 28fdcfb82eef4c4b614eae3386fe0b8c8be3a334 loss detection timeout expired [2025-04-30T10:31:46.225618777Z TRACE quiche::recovery::congestion::recovery] 28fdcfb82eef4c4b614eae3386fe0b8c8be3a334 timer=998.453502ms latest_rtt=0ns srtt=333ms min_rtt=333ms rttvar=166.5ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=904 app_limited=true congestion_recovery_start_time=None Rate { delivered: 0, delivered_time: Instant { tv_sec: 282, tv_nsec: 705128356 }, first_sent_time: Instant { tv_sec: 282, tv_nsec: 705128356 }, end_of_app_limited: 1, last_sent_packet: 5, largest_acked: 0, rate_sample: RateSample { delivery_rate: 0, is_app_limited: false, interval: 0ns, delivered: 0, prior_delivered: 0, prior_time: None, send_elapsed: 0ns, ack_elapsed: 0ns, rtt: 0ns } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 0, last_update: Instant { tv_sec: 283, tv_nsec: 302069338 }, next_time: Instant { tv_sec: 283, tv_nsec: 302069338 }, 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:31:46.225667017Z TRACE quiche] 28fdcfb82eef4c4b614eae3386fe0b8c8be3a334 tx pkt Initial version=1 dcid= scid=28fdcfb82eef4c4b614eae3386fe0b8c8be3a334 len=102 pn=6 [2025-04-30T10:31:46.225671806Z TRACE quiche] 28fdcfb82eef4c4b614eae3386fe0b8c8be3a334 tx frm ACK delay=50341 blocks=[0..4] ecn_counts=None [2025-04-30T10:31:46.225677687Z TRACE quiche] 28fdcfb82eef4c4b614eae3386fe0b8c8be3a334 tx frm CRYPTO off=0 len=90 [2025-04-30T10:31:46.225695801Z TRACE quiche::recovery::congestion::recovery] 28fdcfb82eef4c4b614eae3386fe0b8c8be3a334 timer=998.377369ms latest_rtt=0ns srtt=333ms min_rtt=333ms rttvar=166.5ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=1053 app_limited=true congestion_recovery_start_time=None Rate { delivered: 0, delivered_time: Instant { tv_sec: 282, tv_nsec: 705128356 }, first_sent_time: Instant { tv_sec: 282, tv_nsec: 705128356 }, 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: 283, tv_nsec: 704696225 }, next_time: Instant { tv_sec: 283, tv_nsec: 704696225 }, 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:31:46.225812207Z TRACE quiche_server] 28fdcfb82eef4c4b614eae3386fe0b8c8be3a334 written 1200 bytes with Some(SendInfo { from: [::]:443, to: [::ffff:193.167.0.100]:50943, at: Instant { tv_sec: 283, tv_nsec: 704696225 } }) [2025-04-30T10:31:46.225825152Z TRACE quiche_server] Collecting garbage [2025-04-30T10:31:46.225833948Z TRACE quiche_server] recv() would block [2025-04-30T10:31:46.225840811Z TRACE quiche_server] 28fdcfb82eef4c4b614eae3386fe0b8c8be3a334 done writing [2025-04-30T10:31:46.225845309Z TRACE quiche_server] Collecting garbage [2025-04-30T10:31:46.622170470Z TRACE quiche_server] got 1280 bytes from [::ffff:193.167.0.100]:50943 to [::]:443 [2025-04-30T10:31:46.622205124Z TRACE quiche_server] got packet Initial version=1 dcid=de9ba4cadd48e4968a5c93a1b11bd2806c7d7b2f scid= token= [2025-04-30T10:31:46.622219962Z TRACE quiche] 28fdcfb82eef4c4b614eae3386fe0b8c8be3a334 rx pkt Initial version=1 dcid=de9ba4cadd48e4968a5c93a1b11bd2806c7d7b2f scid= token= len=1250 pn=5 [2025-04-30T10:31:46.622236162Z TRACE quiche] 28fdcfb82eef4c4b614eae3386fe0b8c8be3a334 rx frm PADDING len=953 [2025-04-30T10:31:46.622241051Z TRACE quiche] 28fdcfb82eef4c4b614eae3386fe0b8c8be3a334 rx frm CRYPTO off=0 len=275 [2025-04-30T10:31:46.622268242Z TRACE quiche_server] 28fdcfb82eef4c4b614eae3386fe0b8c8be3a334 processed 1280 bytes [2025-04-30T10:31:46.622274804Z TRACE quiche_server] recv() would block [2025-04-30T10:31:46.622286877Z TRACE quiche] 28fdcfb82eef4c4b614eae3386fe0b8c8be3a334 tx pkt Initial version=1 dcid= scid=28fdcfb82eef4c4b614eae3386fe0b8c8be3a334 len=5 pn=7 [2025-04-30T10:31:46.622290654Z TRACE quiche] 28fdcfb82eef4c4b614eae3386fe0b8c8be3a334 tx frm ACK delay=8 blocks=[0..5] ecn_counts=None [2025-04-30T10:31:46.622303338Z TRACE quiche::recovery::congestion::recovery] 28fdcfb82eef4c4b614eae3386fe0b8c8be3a334 timer=601.769261ms latest_rtt=0ns srtt=333ms min_rtt=333ms rttvar=166.5ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=1053 app_limited=true congestion_recovery_start_time=None Rate { delivered: 0, delivered_time: Instant { tv_sec: 282, tv_nsec: 705128356 }, first_sent_time: Instant { tv_sec: 282, tv_nsec: 705128356 }, end_of_app_limited: 5, 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: 284, tv_nsec: 101332535 }, next_time: Instant { tv_sec: 284, tv_nsec: 101332535 }, 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:31:46.622393155Z TRACE quiche_server] 28fdcfb82eef4c4b614eae3386fe0b8c8be3a334 written 1200 bytes with Some(SendInfo { from: [::]:443, to: [::ffff:193.167.0.100]:50943, at: Instant { tv_sec: 284, tv_nsec: 101332535 } }) [2025-04-30T10:31:46.622403124Z TRACE quiche_server] Collecting garbage [2025-04-30T10:31:46.622410848Z TRACE quiche_server] recv() would block [2025-04-30T10:31:46.622417791Z TRACE quiche_server] 28fdcfb82eef4c4b614eae3386fe0b8c8be3a334 done writing [2025-04-30T10:31:46.622422119Z TRACE quiche_server] Collecting garbage [2025-04-30T10:31:46.623107246Z TRACE quiche_server] got 1280 bytes from [::ffff:193.167.0.100]:50943 to [::]:443 [2025-04-30T10:31:46.623119269Z TRACE quiche_server] got packet Initial version=1 dcid=de9ba4cadd48e4968a5c93a1b11bd2806c7d7b2f scid= token= [2025-04-30T10:31:46.623126262Z TRACE quiche] 28fdcfb82eef4c4b614eae3386fe0b8c8be3a334 rx pkt Initial version=1 dcid=de9ba4cadd48e4968a5c93a1b11bd2806c7d7b2f scid= token= len=1250 pn=6 [2025-04-30T10:31:46.623135129Z TRACE quiche] 28fdcfb82eef4c4b614eae3386fe0b8c8be3a334 rx frm PADDING len=953 [2025-04-30T10:31:46.623138154Z TRACE quiche] 28fdcfb82eef4c4b614eae3386fe0b8c8be3a334 rx frm CRYPTO off=0 len=275 [2025-04-30T10:31:46.623149816Z TRACE quiche_server] 28fdcfb82eef4c4b614eae3386fe0b8c8be3a334 processed 1280 bytes [2025-04-30T10:31:46.623153974Z TRACE quiche_server] recv() would block [2025-04-30T10:31:46.623164633Z TRACE quiche] 28fdcfb82eef4c4b614eae3386fe0b8c8be3a334 tx pkt Initial version=1 dcid= scid=28fdcfb82eef4c4b614eae3386fe0b8c8be3a334 len=5 pn=8 [2025-04-30T10:31:46.623169883Z TRACE quiche] 28fdcfb82eef4c4b614eae3386fe0b8c8be3a334 tx frm ACK delay=4 blocks=[0..6] ecn_counts=None [2025-04-30T10:31:46.623182116Z TRACE quiche::recovery::congestion::recovery] 28fdcfb82eef4c4b614eae3386fe0b8c8be3a334 timer=600.891004ms latest_rtt=0ns srtt=333ms min_rtt=333ms rttvar=166.5ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=1053 app_limited=true congestion_recovery_start_time=None Rate { delivered: 0, delivered_time: Instant { tv_sec: 282, tv_nsec: 705128356 }, first_sent_time: Instant { tv_sec: 282, tv_nsec: 705128356 }, end_of_app_limited: 5, 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: 284, tv_nsec: 102210953 }, next_time: Instant { tv_sec: 284, tv_nsec: 102210953 }, 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:31:46.623227100Z TRACE quiche_server] 28fdcfb82eef4c4b614eae3386fe0b8c8be3a334 written 1200 bytes with Some(SendInfo { from: [::]:443, to: [::ffff:193.167.0.100]:50943, at: Instant { tv_sec: 284, tv_nsec: 102210953 } }) [2025-04-30T10:31:46.623235896Z TRACE quiche_server] Collecting garbage [2025-04-30T10:31:46.623241888Z TRACE quiche_server] recv() would block [2025-04-30T10:31:46.623247849Z TRACE quiche_server] 28fdcfb82eef4c4b614eae3386fe0b8c8be3a334 done writing [2025-04-30T10:31:46.623251195Z TRACE quiche_server] Collecting garbage [2025-04-30T10:31:46.729931314Z TRACE quiche_server] got 1280 bytes from [::ffff:193.167.0.100]:50943 to [::]:443 [2025-04-30T10:31:46.729995104Z TRACE quiche_server] got packet Initial version=1 dcid=28fdcfb82eef4c4b614eae3386fe0b8c8be3a334 scid= token= [2025-04-30T10:31:46.730010883Z TRACE quiche] 28fdcfb82eef4c4b614eae3386fe0b8c8be3a334 rx pkt Initial version=1 dcid=28fdcfb82eef4c4b614eae3386fe0b8c8be3a334 scid= token= len=1164 pn=7 [2025-04-30T10:31:46.730024799Z TRACE quiche] 28fdcfb82eef4c4b614eae3386fe0b8c8be3a334 rx frm ACK delay=0 blocks=[0..0] ecn_counts=None [2025-04-30T10:31:46.730056047Z TRACE quiche::recovery::congestion::recovery] 28fdcfb82eef4c4b614eae3386fe0b8c8be3a334 packet newly acked 0 [2025-04-30T10:31:46.730066667Z TRACE quiche] 28fdcfb82eef4c4b614eae3386fe0b8c8be3a334 rx frm PADDING len=1141 [2025-04-30T10:31:46.730093697Z TRACE quiche] 28fdcfb82eef4c4b614eae3386fe0b8c8be3a334 rx pkt Handshake version=1 dcid=28fdcfb82eef4c4b614eae3386fe0b8c8be3a334 scid= len=57 pn=0 [2025-04-30T10:31:46.730099819Z TRACE quiche] 28fdcfb82eef4c4b614eae3386fe0b8c8be3a334 rx frm CRYPTO off=0 len=36 [2025-04-30T10:31:46.730120808Z TRACE quiche::tls] 28fdcfb82eef4c4b614eae3386fe0b8c8be3a334 set read secret lvl=OneRTT [2025-04-30T10:31:46.730142518Z TRACE quiche] 28fdcfb82eef4c4b614eae3386fe0b8c8be3a334 dropped epoch 1 state [2025-04-30T10:31:46.730147237Z TRACE quiche] 28fdcfb82eef4c4b614eae3386fe0b8c8be3a334 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: 1452, initial_max_data: 786432, initial_max_stream_data_bidi_local: 524288, initial_max_stream_data_bidi_remote: 524288, initial_max_stream_data_uni: 524288, initial_max_streams_bidi: 100, initial_max_streams_uni: 100, ack_delay_exponent: 3, max_ack_delay: 26, disable_active_migration: false, active_conn_id_limit: 4, initial_source_connection_id: Some(), retry_source_connection_id: None, max_datagram_frame_size: None, unknown_params: None } [2025-04-30T10:31:46.730194605Z TRACE quiche] 28fdcfb82eef4c4b614eae3386fe0b8c8be3a334 dropped epoch 0 state [2025-04-30T10:31:46.730198533Z TRACE quiche_server] 28fdcfb82eef4c4b614eae3386fe0b8c8be3a334 processed 1280 bytes [2025-04-30T10:31:46.730208221Z TRACE quiche_server] got 52 bytes from [::ffff:193.167.0.100]:50943 to [::]:443 [2025-04-30T10:31:46.730212369Z TRACE quiche_server] got packet Handshake version=1 dcid=28fdcfb82eef4c4b614eae3386fe0b8c8be3a334 scid= [2025-04-30T10:31:46.730217919Z TRACE quiche] 28fdcfb82eef4c4b614eae3386fe0b8c8be3a334 dropped invalid packet [2025-04-30T10:31:46.730220925Z TRACE quiche_server] 28fdcfb82eef4c4b614eae3386fe0b8c8be3a334 processed 52 bytes [2025-04-30T10:31:46.730226114Z TRACE quiche_server] got 58 bytes from [::ffff:193.167.0.100]:50943 to [::]:443 [2025-04-30T10:31:46.730229561Z TRACE quiche_server] got packet Short dcid=28fdcfb82eef4c4b614eae3386fe0b8c8be3a334 key_phase=false [2025-04-30T10:31:46.730234500Z TRACE quiche] 28fdcfb82eef4c4b614eae3386fe0b8c8be3a334 rx pkt Short dcid=28fdcfb82eef4c4b614eae3386fe0b8c8be3a334 key_phase=false len=37 pn=0 [2025-04-30T10:31:46.730240401Z TRACE quiche] 28fdcfb82eef4c4b614eae3386fe0b8c8be3a334 rx frm STREAM id=0 off=0 len=17 fin=true [2025-04-30T10:31:46.730249368Z TRACE quiche_server] 28fdcfb82eef4c4b614eae3386fe0b8c8be3a334 processed 58 bytes [2025-04-30T10:31:46.730252644Z DEBUG quiche_apps::common] 28fdcfb82eef4c4b614eae3386fe0b8c8be3a334 response stream 0 is writable with capacity Ok(13500) [2025-04-30T10:31:46.730260438Z TRACE quiche_apps::common] 28fdcfb82eef4c4b614eae3386fe0b8c8be3a334 received 17 bytes [2025-04-30T10:31:46.730263574Z TRACE quiche_apps::common] 28fdcfb82eef4c4b614eae3386fe0b8c8be3a334 stream 0 has 17 bytes (fin? true) [2025-04-30T10:31:46.730268784Z INFO quiche_apps::common] 28fdcfb82eef4c4b614eae3386fe0b8c8be3a334 got GET request for "/www/wpndxpwkyq" on stream 0 [2025-04-30T10:31:46.730305592Z INFO quiche_apps::common] 28fdcfb82eef4c4b614eae3386fe0b8c8be3a334 sending response of size 1024 on stream 0 [2025-04-30T10:31:46.730313627Z TRACE quiche_server] recv() would block [2025-04-30T10:31:46.730322484Z TRACE quiche] 28fdcfb82eef4c4b614eae3386fe0b8c8be3a334 pmtud probe status false hs_con=true hs_sent=false cwnd_avail=13500 out_len=1350 left=1327 [2025-04-30T10:31:46.730332753Z TRACE quiche] 28fdcfb82eef4c4b614eae3386fe0b8c8be3a334 tx pkt Short dcid= key_phase=false len=1155 pn=9 [2025-04-30T10:31:46.730336290Z TRACE quiche] 28fdcfb82eef4c4b614eae3386fe0b8c8be3a334 tx frm ACK delay=10 blocks=[0..0] ecn_counts=None [2025-04-30T10:31:46.730344946Z TRACE quiche] 28fdcfb82eef4c4b614eae3386fe0b8c8be3a334 tx frm NEW_CONNECTION_ID seq_num=1 retire_prior_to=0 conn_id=[65, 94, 73, bf, 39, b4, ee, d2, f6, 0c, 62, d5, 77, e8, 9e, cd, 25, 39, a8, 30] reset_token=[72, 8b, 8b, 07, 29, 3b, 32, 7d, c4, c2, 87, 50, 6f, a6, 55, 10] [2025-04-30T10:31:46.730354253Z TRACE quiche] 28fdcfb82eef4c4b614eae3386fe0b8c8be3a334 tx frm NEW_CONNECTION_ID seq_num=2 retire_prior_to=0 conn_id=[c0, 0e, 93, 45, 97, 57, d0, 64, f2, 16, 00, 20, a2, 24, f0, b9, cd, 87, 37, 4c] reset_token=[69, 5a, 5e, 6a, 8e, 0d, 6f, 92, 9e, a1, 33, 58, 45, 07, 7e, 82] [2025-04-30T10:31:46.730362058Z TRACE quiche] 28fdcfb82eef4c4b614eae3386fe0b8c8be3a334 tx frm NEW_CONNECTION_ID seq_num=3 retire_prior_to=0 conn_id=[4f, 75, 63, 3f, 5b, 95, 9c, 01, b5, 56, 7e, 6a, 12, 06, b8, d3, 5a, ed, 55, e1] reset_token=[06, 18, 1a, 72, 32, b3, 4b, 61, d0, 41, f5, 92, ff, 3d, 92, 1d] [2025-04-30T10:31:46.730369562Z TRACE quiche] 28fdcfb82eef4c4b614eae3386fe0b8c8be3a334 tx frm HANDSHAKE_DONE [2025-04-30T10:31:46.730372477Z TRACE quiche] 28fdcfb82eef4c4b614eae3386fe0b8c8be3a334 tx frm STREAM id=0 off=0 len=1024 fin=true [2025-04-30T10:31:46.730385612Z TRACE quiche::recovery::congestion::recovery] 28fdcfb82eef4c4b614eae3386fe0b8c8be3a334 timer=4.537730353s latest_rtt=1.503933285s srtt=1.503933285s min_rtt=1.503933285s rttvar=751.966642ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=1173 app_limited=true congestion_recovery_start_time=None Rate { delivered: 146, delivered_time: Instant { tv_sec: 284, tv_nsec: 102210953 }, first_sent_time: Instant { tv_sec: 284, tv_nsec: 102210953 }, end_of_app_limited: 8, last_sent_packet: 9, largest_acked: 0, rate_sample: RateSample { delivery_rate: 97, is_app_limited: true, interval: 1.503933285s, delivered: 146, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 282, tv_nsec: 705128356 }), send_elapsed: 0ns, ack_elapsed: 1.503933285s, rtt: 1.503933285s } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 11220, last_update: Instant { tv_sec: 284, tv_nsec: 102210953 }, next_time: Instant { tv_sec: 284, tv_nsec: 102210953 }, 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:31:46.730460421Z TRACE quiche_server] 28fdcfb82eef4c4b614eae3386fe0b8c8be3a334 written 1173 bytes with Some(SendInfo { from: [::]:443, to: [::ffff:193.167.0.100]:50943, at: Instant { tv_sec: 284, tv_nsec: 102210953 } }) [2025-04-30T10:31:46.730470831Z TRACE quiche_server] Collecting garbage [2025-04-30T10:31:46.730478575Z TRACE quiche_server] recv() would block [2025-04-30T10:31:46.730484245Z TRACE quiche_server] 28fdcfb82eef4c4b614eae3386fe0b8c8be3a334 done writing [2025-04-30T10:31:46.730488914Z TRACE quiche_server] Collecting garbage [2025-04-30T10:31:46.929160471Z TRACE quiche_server] got 86 bytes from [::ffff:193.167.0.100]:50943 to [::]:443 [2025-04-30T10:31:46.929199273Z TRACE quiche_server] got packet Handshake version=1 dcid=28fdcfb82eef4c4b614eae3386fe0b8c8be3a334 scid= [2025-04-30T10:31:46.929214021Z TRACE quiche] 28fdcfb82eef4c4b614eae3386fe0b8c8be3a334 dropped invalid packet [2025-04-30T10:31:46.929218048Z TRACE quiche_server] 28fdcfb82eef4c4b614eae3386fe0b8c8be3a334 processed 86 bytes [2025-04-30T10:31:46.929226794Z TRACE quiche_server] got 86 bytes from [::ffff:193.167.0.100]:50943 to [::]:443 [2025-04-30T10:31:46.929230581Z TRACE quiche_server] got packet Handshake version=1 dcid=28fdcfb82eef4c4b614eae3386fe0b8c8be3a334 scid= [2025-04-30T10:31:46.929235290Z TRACE quiche] 28fdcfb82eef4c4b614eae3386fe0b8c8be3a334 dropped invalid packet [2025-04-30T10:31:46.929238216Z TRACE quiche_server] 28fdcfb82eef4c4b614eae3386fe0b8c8be3a334 processed 86 bytes [2025-04-30T10:31:46.929242624Z TRACE quiche_server] recv() would block [2025-04-30T10:31:46.929262792Z TRACE quiche_server] 28fdcfb82eef4c4b614eae3386fe0b8c8be3a334 done writing [2025-04-30T10:31:46.929266158Z TRACE quiche_server] Collecting garbage [2025-04-30T10:31:47.330179070Z TRACE quiche_server] got 86 bytes from [::ffff:193.167.0.100]:50943 to [::]:443 [2025-04-30T10:31:47.330213774Z TRACE quiche_server] got packet Handshake version=1 dcid=28fdcfb82eef4c4b614eae3386fe0b8c8be3a334 scid= [2025-04-30T10:31:47.330227380Z TRACE quiche] 28fdcfb82eef4c4b614eae3386fe0b8c8be3a334 dropped invalid packet [2025-04-30T10:31:47.330231487Z TRACE quiche_server] 28fdcfb82eef4c4b614eae3386fe0b8c8be3a334 processed 86 bytes [2025-04-30T10:31:47.330239923Z TRACE quiche_server] got 86 bytes from [::ffff:193.167.0.100]:50943 to [::]:443 [2025-04-30T10:31:47.330243770Z TRACE quiche_server] got packet Handshake version=1 dcid=28fdcfb82eef4c4b614eae3386fe0b8c8be3a334 scid= [2025-04-30T10:31:47.330248649Z TRACE quiche] 28fdcfb82eef4c4b614eae3386fe0b8c8be3a334 dropped invalid packet [2025-04-30T10:31:47.330251515Z TRACE quiche_server] 28fdcfb82eef4c4b614eae3386fe0b8c8be3a334 processed 86 bytes [2025-04-30T10:31:47.330256113Z TRACE quiche_server] recv() would block [2025-04-30T10:31:47.330261654Z TRACE quiche_server] 28fdcfb82eef4c4b614eae3386fe0b8c8be3a334 done writing [2025-04-30T10:31:47.330264799Z TRACE quiche_server] Collecting garbage [2025-04-30T10:31:48.131211727Z TRACE quiche_server] got 86 bytes from [::ffff:193.167.0.100]:50943 to [::]:443 [2025-04-30T10:31:48.131248645Z TRACE quiche_server] got packet Handshake version=1 dcid=28fdcfb82eef4c4b614eae3386fe0b8c8be3a334 scid= [2025-04-30T10:31:48.131262120Z TRACE quiche] 28fdcfb82eef4c4b614eae3386fe0b8c8be3a334 dropped invalid packet [2025-04-30T10:31:48.131266639Z TRACE quiche_server] 28fdcfb82eef4c4b614eae3386fe0b8c8be3a334 processed 86 bytes [2025-04-30T10:31:48.131275155Z TRACE quiche_server] got 86 bytes from [::ffff:193.167.0.100]:50943 to [::]:443 [2025-04-30T10:31:48.131279483Z TRACE quiche_server] got packet Handshake version=1 dcid=28fdcfb82eef4c4b614eae3386fe0b8c8be3a334 scid= [2025-04-30T10:31:48.131284622Z TRACE quiche] 28fdcfb82eef4c4b614eae3386fe0b8c8be3a334 dropped invalid packet [2025-04-30T10:31:48.131288189Z TRACE quiche_server] 28fdcfb82eef4c4b614eae3386fe0b8c8be3a334 processed 86 bytes [2025-04-30T10:31:48.131292978Z TRACE quiche_server] recv() would block [2025-04-30T10:31:48.131299189Z TRACE quiche_server] 28fdcfb82eef4c4b614eae3386fe0b8c8be3a334 done writing [2025-04-30T10:31:48.131304539Z TRACE quiche_server] Collecting garbage [2025-04-30T10:31:48.232471923Z TRACE quiche_server] got 46 bytes from [::ffff:193.167.0.100]:50943 to [::]:443 [2025-04-30T10:31:48.232504744Z TRACE quiche_server] got packet Short dcid=659473bf39b4eed2f60c62d577e89ecd2539a830 key_phase=false [2025-04-30T10:31:48.232519912Z TRACE quiche] 28fdcfb82eef4c4b614eae3386fe0b8c8be3a334 rx pkt Short dcid=659473bf39b4eed2f60c62d577e89ecd2539a830 key_phase=false len=25 pn=1 [2025-04-30T10:31:48.232530863Z TRACE quiche] 28fdcfb82eef4c4b614eae3386fe0b8c8be3a334 path ID 0 now see SCID with seq num 1 [2025-04-30T10:31:48.232544247Z TRACE quiche] 28fdcfb82eef4c4b614eae3386fe0b8c8be3a334 rx frm ACK delay=30 blocks=[9..9] ecn_counts=None [2025-04-30T10:31:48.232551691Z TRACE quiche::recovery::congestion::recovery] 28fdcfb82eef4c4b614eae3386fe0b8c8be3a334 packet newly acked 9 [2025-04-30T10:31:48.232559405Z TRACE quiche] 28fdcfb82eef4c4b614eae3386fe0b8c8be3a334 rx frm RETIRE_CONNECTION_ID seq_num=0 [2025-04-30T10:31:48.232584903Z TRACE quiche_server] 28fdcfb82eef4c4b614eae3386fe0b8c8be3a334 processed 46 bytes [2025-04-30T10:31:48.232590694Z INFO quiche_server] Retiring source CID 28fdcfb82eef4c4b614eae3386fe0b8c8be3a334 [2025-04-30T10:31:48.232602055Z TRACE quiche_server] got 42 bytes from [::ffff:193.167.0.100]:50943 to [::]:443 [2025-04-30T10:31:48.232606553Z TRACE quiche_server] got packet Short dcid=659473bf39b4eed2f60c62d577e89ecd2539a830 key_phase=false [2025-04-30T10:31:48.232611773Z TRACE quiche] 28fdcfb82eef4c4b614eae3386fe0b8c8be3a334 rx pkt Short dcid=659473bf39b4eed2f60c62d577e89ecd2539a830 key_phase=false len=21 pn=2 [2025-04-30T10:31:48.232632882Z TRACE quiche] 28fdcfb82eef4c4b614eae3386fe0b8c8be3a334 rx frm APPLICATION_CLOSE err=0 reason=[] [2025-04-30T10:31:48.232638924Z TRACE quiche_server] 28fdcfb82eef4c4b614eae3386fe0b8c8be3a334 processed 42 bytes [2025-04-30T10:31:48.232643322Z TRACE quiche_server] recv() would block [2025-04-30T10:31:48.232646027Z TRACE quiche_server] 28fdcfb82eef4c4b614eae3386fe0b8c8be3a334 done writing [2025-04-30T10:31:48.232648471Z TRACE quiche_server] Collecting garbage