[2025-04-30T11:51:37.205693582Z INFO quiche_server] listening on [::]:443 [2025-04-30T11:51:37.205719180Z TRACE mio::poll] registering event source with poller: token=Token(0), interests=READABLE [2025-04-30T11:51:37.205726755Z TRACE quiche_server] GSO detected: false [2025-04-30T11:51:38.002123394Z TRACE quiche_server] got 1207 bytes from [::ffff:193.167.100.2]:46996 to [::]:443 [2025-04-30T11:51:38.002157648Z TRACE quiche_server] got packet Initial version=57414954 dcid= scid= token= [2025-04-30T11:51:38.002165573Z WARN quiche_server] Doing version negotiation [2025-04-30T11:51:38.002268926Z TRACE quiche_server] got 1207 bytes from [::ffff:193.167.100.2]:46996 to [::]:443 [2025-04-30T11:51:38.002275158Z TRACE quiche_server] got packet Initial version=57414954 dcid= scid= token= [2025-04-30T11:51:38.002278985Z WARN quiche_server] Doing version negotiation [2025-04-30T11:51:38.002299573Z TRACE quiche_server] got 1207 bytes from [::ffff:193.167.100.2]:46996 to [::]:443 [2025-04-30T11:51:38.002303741Z TRACE quiche_server] got packet Initial version=57414954 dcid= scid= token= [2025-04-30T11:51:38.002307037Z WARN quiche_server] Doing version negotiation [2025-04-30T11:51:38.002328036Z TRACE quiche_server] recv() would block [2025-04-30T11:51:41.233678263Z TRACE quiche_server] got 1200 bytes from [::ffff:193.167.0.100]:46267 to [::]:443 [2025-04-30T11:51:41.233705394Z TRACE quiche_server] got packet Initial version=1 dcid=9b14722ab2c578695a55e86c9c9bfab746177c49 scid=203afec490ab54a6 token= [2025-04-30T11:51:41.233714571Z DEBUG quiche_server] New connection: dcid=9b14722ab2c578695a55e86c9c9bfab746177c49 scid=fd9bc0cfbfdaf088546f8ffc84042f51e62cece3 [2025-04-30T11:51:41.233941045Z TRACE quiche] fd9bc0cfbfdaf088546f8ffc84042f51e62cece3 rx pkt Initial version=1 dcid=9b14722ab2c578695a55e86c9c9bfab746177c49 scid=203afec490ab54a6 token= len=1162 pn=0 [2025-04-30T11:51:41.233959519Z TRACE quiche] fd9bc0cfbfdaf088546f8ffc84042f51e62cece3 rx frm CRYPTO off=0 len=286 [2025-04-30T11:51:41.233989095Z TRACE quiche::tls] checking peer ALPN Ok("hq-interop") against Ok("h3") [2025-04-30T11:51:41.233993743Z TRACE quiche::tls] checking peer ALPN Ok("hq-interop") against Ok("hq-interop") [2025-04-30T11:51:41.234098349Z TRACE quiche::tls] fd9bc0cfbfdaf088546f8ffc84042f51e62cece3 write message lvl=Initial len=90 [2025-04-30T11:51:41.234132262Z TRACE quiche::tls] fd9bc0cfbfdaf088546f8ffc84042f51e62cece3 set write secret lvl=Handshake [2025-04-30T11:51:41.234240474Z TRACE quiche::tls] fd9bc0cfbfdaf088546f8ffc84042f51e62cece3 write message lvl=Handshake len=9972 [2025-04-30T11:51:41.234245234Z TRACE quiche::tls] fd9bc0cfbfdaf088546f8ffc84042f51e62cece3 set write secret lvl=OneRTT [2025-04-30T11:51:41.234252948Z TRACE quiche::tls] fd9bc0cfbfdaf088546f8ffc84042f51e62cece3 set read secret lvl=Handshake [2025-04-30T11:51:41.234272364Z TRACE quiche] fd9bc0cfbfdaf088546f8ffc84042f51e62cece3 rx frm PADDING len=855 [2025-04-30T11:51:41.234292933Z TRACE quiche_server] fd9bc0cfbfdaf088546f8ffc84042f51e62cece3 processed 1200 bytes [2025-04-30T11:51:41.234306087Z TRACE quiche_server] recv() would block [2025-04-30T11:51:41.234317418Z TRACE quiche] fd9bc0cfbfdaf088546f8ffc84042f51e62cece3 tx pkt Initial version=1 dcid=203afec490ab54a6 scid=fd9bc0cfbfdaf088546f8ffc84042f51e62cece3 len=99 pn=0 [2025-04-30T11:51:41.234320735Z TRACE quiche] fd9bc0cfbfdaf088546f8ffc84042f51e62cece3 tx frm ACK delay=53 blocks=[0..0] ecn_counts=None [2025-04-30T11:51:41.234325123Z TRACE quiche] fd9bc0cfbfdaf088546f8ffc84042f51e62cece3 tx frm CRYPTO off=0 len=90 [2025-04-30T11:51:41.234334300Z TRACE quiche::recovery::congestion::recovery] fd9bc0cfbfdaf088546f8ffc84042f51e62cece3 timer=998.9734ms 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: 657, tv_nsec: 24418860 }, first_sent_time: Instant { tv_sec: 657, tv_nsec: 24418860 }, 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: 657, tv_nsec: 24418860 }, next_time: Instant { tv_sec: 657, tv_nsec: 24418860 }, max_datagram_size: 1350, last_packet_size: None, iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } [2025-04-30T11:51:41.234361541Z TRACE quiche] fd9bc0cfbfdaf088546f8ffc84042f51e62cece3 tx pkt Handshake version=1 dcid=203afec490ab54a6 scid=fd9bc0cfbfdaf088546f8ffc84042f51e62cece3 len=992 pn=1 [2025-04-30T11:51:41.234364517Z TRACE quiche] fd9bc0cfbfdaf088546f8ffc84042f51e62cece3 tx frm CRYPTO off=0 len=988 [2025-04-30T11:51:41.234369987Z TRACE quiche::recovery::congestion::recovery] fd9bc0cfbfdaf088546f8ffc84042f51e62cece3 timer=998.938084ms 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: 657, tv_nsec: 24418860 }, first_sent_time: Instant { tv_sec: 657, tv_nsec: 24418860 }, 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: 657, tv_nsec: 24418860 }, next_time: Instant { tv_sec: 657, tv_nsec: 24418860 }, max_datagram_size: 1350, last_packet_size: None, iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } [2025-04-30T11:51:41.234416915Z TRACE quiche_server] fd9bc0cfbfdaf088546f8ffc84042f51e62cece3 written 1200 bytes with Some(SendInfo { from: [::]:443, to: [::ffff:193.167.0.100]:46267, at: Instant { tv_sec: 657, tv_nsec: 24418860 } }) [2025-04-30T11:51:41.234425931Z TRACE quiche_server] Collecting garbage [2025-04-30T11:51:41.234432824Z TRACE quiche_server] recv() would block [2025-04-30T11:51:41.234444837Z TRACE quiche] fd9bc0cfbfdaf088546f8ffc84042f51e62cece3 tx pkt Handshake version=1 dcid=203afec490ab54a6 scid=fd9bc0cfbfdaf088546f8ffc84042f51e62cece3 len=1146 pn=2 [2025-04-30T11:51:41.234449616Z TRACE quiche] fd9bc0cfbfdaf088546f8ffc84042f51e62cece3 tx frm CRYPTO off=988 len=1141 [2025-04-30T11:51:41.234457891Z TRACE quiche::recovery::congestion::recovery] fd9bc0cfbfdaf088546f8ffc84042f51e62cece3 timer=998.85018ms 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: 657, tv_nsec: 24418860 }, first_sent_time: Instant { tv_sec: 657, tv_nsec: 24418860 }, 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: 657, tv_nsec: 24546499 }, next_time: Instant { tv_sec: 657, tv_nsec: 24546499 }, max_datagram_size: 1350, last_packet_size: None, iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } [2025-04-30T11:51:41.234497836Z TRACE quiche_server] fd9bc0cfbfdaf088546f8ffc84042f51e62cece3 written 1200 bytes with Some(SendInfo { from: [::]:443, to: [::ffff:193.167.0.100]:46267, at: Instant { tv_sec: 657, tv_nsec: 24546499 } }) [2025-04-30T11:51:41.234506081Z TRACE quiche_server] Collecting garbage [2025-04-30T11:51:41.234512153Z TRACE quiche_server] recv() would block [2025-04-30T11:51:41.234524816Z TRACE quiche] fd9bc0cfbfdaf088546f8ffc84042f51e62cece3 tx pkt Handshake version=1 dcid=203afec490ab54a6 scid=fd9bc0cfbfdaf088546f8ffc84042f51e62cece3 len=1146 pn=3 [2025-04-30T11:51:41.234529044Z TRACE quiche] fd9bc0cfbfdaf088546f8ffc84042f51e62cece3 tx frm CRYPTO off=2129 len=1141 [2025-04-30T11:51:41.234536338Z TRACE quiche::recovery::congestion::recovery] fd9bc0cfbfdaf088546f8ffc84042f51e62cece3 timer=998.771703ms 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: 657, tv_nsec: 24418860 }, first_sent_time: Instant { tv_sec: 657, tv_nsec: 24418860 }, 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: 657, tv_nsec: 24626268 }, next_time: Instant { tv_sec: 657, tv_nsec: 24626268 }, max_datagram_size: 1350, last_packet_size: None, iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } [2025-04-30T11:51:41.234569109Z TRACE quiche_server] fd9bc0cfbfdaf088546f8ffc84042f51e62cece3 written 1200 bytes with Some(SendInfo { from: [::]:443, to: [::ffff:193.167.0.100]:46267, at: Instant { tv_sec: 657, tv_nsec: 24626268 } }) [2025-04-30T11:51:41.234576413Z TRACE quiche_server] Collecting garbage [2025-04-30T11:51:41.234581632Z TRACE quiche_server] recv() would block [2025-04-30T11:51:41.234586742Z TRACE quiche_server] fd9bc0cfbfdaf088546f8ffc84042f51e62cece3 done writing [2025-04-30T11:51:41.234590489Z TRACE quiche_server] Collecting garbage [2025-04-30T11:51:42.071485947Z TRACE quiche_server] got 57 bytes from [::ffff:193.167.0.100]:46267 to [::]:443 [2025-04-30T11:51:42.071525120Z TRACE quiche_server] got packet Handshake version=1 dcid=fd9bc0cfbfdaf088546f8ffc84042f51e62cece3 scid=203afec490ab54a6 [2025-04-30T11:51:42.071541381Z TRACE quiche] fd9bc0cfbfdaf088546f8ffc84042f51e62cece3 rx pkt Handshake version=1 dcid=fd9bc0cfbfdaf088546f8ffc84042f51e62cece3 scid=203afec490ab54a6 len=20 pn=6 [2025-04-30T11:51:42.071553854Z TRACE quiche] fd9bc0cfbfdaf088546f8ffc84042f51e62cece3 rx frm PING mtu_probe=None [2025-04-30T11:51:42.071558433Z TRACE quiche] fd9bc0cfbfdaf088546f8ffc84042f51e62cece3 rx frm PADDING len=2 [2025-04-30T11:51:42.071583379Z TRACE quiche] fd9bc0cfbfdaf088546f8ffc84042f51e62cece3 dropped epoch 0 state [2025-04-30T11:51:42.071587036Z TRACE quiche_server] fd9bc0cfbfdaf088546f8ffc84042f51e62cece3 processed 57 bytes [2025-04-30T11:51:42.071595021Z TRACE quiche_server] got 57 bytes from [::ffff:193.167.0.100]:46267 to [::]:443 [2025-04-30T11:51:42.071598888Z TRACE quiche_server] got packet Handshake version=1 dcid=fd9bc0cfbfdaf088546f8ffc84042f51e62cece3 scid=203afec490ab54a6 [2025-04-30T11:51:42.071604359Z TRACE quiche] fd9bc0cfbfdaf088546f8ffc84042f51e62cece3 rx pkt Handshake version=1 dcid=fd9bc0cfbfdaf088546f8ffc84042f51e62cece3 scid=203afec490ab54a6 len=20 pn=7 [2025-04-30T11:51:42.071609578Z TRACE quiche] fd9bc0cfbfdaf088546f8ffc84042f51e62cece3 rx frm PING mtu_probe=None [2025-04-30T11:51:42.071612594Z TRACE quiche] fd9bc0cfbfdaf088546f8ffc84042f51e62cece3 rx frm PADDING len=2 [2025-04-30T11:51:42.071621020Z TRACE quiche_server] fd9bc0cfbfdaf088546f8ffc84042f51e62cece3 processed 57 bytes [2025-04-30T11:51:42.071639053Z TRACE quiche_server] recv() would block [2025-04-30T11:51:42.071658119Z TRACE quiche] fd9bc0cfbfdaf088546f8ffc84042f51e62cece3 tx pkt Handshake version=1 dcid=203afec490ab54a6 scid=fd9bc0cfbfdaf088546f8ffc84042f51e62cece3 len=1146 pn=4 [2025-04-30T11:51:42.071662026Z TRACE quiche] fd9bc0cfbfdaf088546f8ffc84042f51e62cece3 tx frm ACK delay=6 blocks=[6..7] ecn_counts=None [2025-04-30T11:51:42.071667497Z TRACE quiche] fd9bc0cfbfdaf088546f8ffc84042f51e62cece3 tx frm CRYPTO off=3270 len=1136 [2025-04-30T11:51:42.071680000Z TRACE quiche::recovery::congestion::recovery] fd9bc0cfbfdaf088546f8ffc84042f51e62cece3 timer=998.961358ms 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: 657, tv_nsec: 24418860 }, first_sent_time: Instant { tv_sec: 657, tv_nsec: 24418860 }, 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: 657, tv_nsec: 861752688 }, next_time: Instant { tv_sec: 657, tv_nsec: 861752688 }, max_datagram_size: 1350, last_packet_size: None, iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } [2025-04-30T11:51:42.071743879Z TRACE quiche_server] fd9bc0cfbfdaf088546f8ffc84042f51e62cece3 written 1200 bytes with Some(SendInfo { from: [::]:443, to: [::ffff:193.167.0.100]:46267, at: Instant { tv_sec: 657, tv_nsec: 861752688 } }) [2025-04-30T11:51:42.071754709Z TRACE quiche_server] Collecting garbage [2025-04-30T11:51:42.071763646Z TRACE quiche_server] recv() would block [2025-04-30T11:51:42.071778514Z TRACE quiche] fd9bc0cfbfdaf088546f8ffc84042f51e62cece3 tx pkt Handshake version=1 dcid=203afec490ab54a6 scid=fd9bc0cfbfdaf088546f8ffc84042f51e62cece3 len=1146 pn=5 [2025-04-30T11:51:42.071784956Z TRACE quiche] fd9bc0cfbfdaf088546f8ffc84042f51e62cece3 tx frm CRYPTO off=4406 len=1141 [2025-04-30T11:51:42.071796798Z TRACE quiche::recovery::congestion::recovery] fd9bc0cfbfdaf088546f8ffc84042f51e62cece3 timer=998.970374ms 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: 657, tv_nsec: 24418860 }, first_sent_time: Instant { tv_sec: 657, tv_nsec: 24418860 }, 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: 657, tv_nsec: 861878202 }, next_time: Instant { tv_sec: 657, tv_nsec: 861878202 }, max_datagram_size: 1350, last_packet_size: None, iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } [2025-04-30T11:51:42.071839648Z TRACE quiche_server] fd9bc0cfbfdaf088546f8ffc84042f51e62cece3 written 1200 bytes with Some(SendInfo { from: [::]:443, to: [::ffff:193.167.0.100]:46267, at: Instant { tv_sec: 657, tv_nsec: 861878202 } }) [2025-04-30T11:51:42.071849767Z TRACE quiche_server] Collecting garbage [2025-04-30T11:51:42.071856400Z TRACE quiche_server] recv() would block [2025-04-30T11:51:42.071877158Z TRACE quiche] fd9bc0cfbfdaf088546f8ffc84042f51e62cece3 tx pkt Handshake version=1 dcid=203afec490ab54a6 scid=fd9bc0cfbfdaf088546f8ffc84042f51e62cece3 len=1146 pn=6 [2025-04-30T11:51:42.071880184Z TRACE quiche] fd9bc0cfbfdaf088546f8ffc84042f51e62cece3 tx frm CRYPTO off=5547 len=1141 [2025-04-30T11:51:42.071887147Z TRACE quiche::recovery::congestion::recovery] fd9bc0cfbfdaf088546f8ffc84042f51e62cece3 timer=998.981275ms 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: 657, tv_nsec: 24418860 }, first_sent_time: Instant { tv_sec: 657, tv_nsec: 24418860 }, 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: 657, tv_nsec: 861979151 }, next_time: Instant { tv_sec: 657, tv_nsec: 861979151 }, max_datagram_size: 1350, last_packet_size: None, iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } [2025-04-30T11:51:42.071959993Z TRACE quiche_server] fd9bc0cfbfdaf088546f8ffc84042f51e62cece3 written 1200 bytes with Some(SendInfo { from: [::]:443, to: [::ffff:193.167.0.100]:46267, at: Instant { tv_sec: 657, tv_nsec: 861979151 } }) [2025-04-30T11:51:42.071968329Z TRACE quiche_server] Collecting garbage [2025-04-30T11:51:42.071974240Z TRACE quiche_server] recv() would block [2025-04-30T11:51:42.071986523Z TRACE quiche] fd9bc0cfbfdaf088546f8ffc84042f51e62cece3 tx pkt Handshake version=1 dcid=203afec490ab54a6 scid=fd9bc0cfbfdaf088546f8ffc84042f51e62cece3 len=1146 pn=7 [2025-04-30T11:51:42.071991332Z TRACE quiche] fd9bc0cfbfdaf088546f8ffc84042f51e62cece3 tx frm CRYPTO off=6688 len=1141 [2025-04-30T11:51:42.071998636Z TRACE quiche::recovery::congestion::recovery] fd9bc0cfbfdaf088546f8ffc84042f51e62cece3 timer=998.97877ms 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: 657, tv_nsec: 24418860 }, first_sent_time: Instant { tv_sec: 657, tv_nsec: 24418860 }, 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: 657, tv_nsec: 862088245 }, next_time: Instant { tv_sec: 657, tv_nsec: 862088245 }, max_datagram_size: 1350, last_packet_size: None, iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } [2025-04-30T11:51:42.072031988Z TRACE quiche_server] fd9bc0cfbfdaf088546f8ffc84042f51e62cece3 written 1200 bytes with Some(SendInfo { from: [::]:443, to: [::ffff:193.167.0.100]:46267, at: Instant { tv_sec: 657, tv_nsec: 862088245 } }) [2025-04-30T11:51:42.072039833Z TRACE quiche_server] Collecting garbage [2025-04-30T11:51:42.072045624Z TRACE quiche_server] recv() would block [2025-04-30T11:51:42.072057466Z TRACE quiche] fd9bc0cfbfdaf088546f8ffc84042f51e62cece3 tx pkt Handshake version=1 dcid=203afec490ab54a6 scid=fd9bc0cfbfdaf088546f8ffc84042f51e62cece3 len=1146 pn=8 [2025-04-30T11:51:42.072061674Z TRACE quiche] fd9bc0cfbfdaf088546f8ffc84042f51e62cece3 tx frm CRYPTO off=7829 len=1141 [2025-04-30T11:51:42.072073586Z TRACE quiche::recovery::congestion::recovery] fd9bc0cfbfdaf088546f8ffc84042f51e62cece3 timer=998.974963ms 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: 657, tv_nsec: 24418860 }, first_sent_time: Instant { tv_sec: 657, tv_nsec: 24418860 }, 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: 657, tv_nsec: 862159408 }, next_time: Instant { tv_sec: 657, tv_nsec: 862159408 }, max_datagram_size: 1350, last_packet_size: None, iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } [2025-04-30T11:51:42.072106166Z TRACE quiche_server] fd9bc0cfbfdaf088546f8ffc84042f51e62cece3 written 1200 bytes with Some(SendInfo { from: [::]:443, to: [::ffff:193.167.0.100]:46267, at: Instant { tv_sec: 657, tv_nsec: 862159408 } }) [2025-04-30T11:51:42.072113791Z TRACE quiche_server] Collecting garbage [2025-04-30T11:51:42.072119511Z TRACE quiche_server] recv() would block [2025-04-30T11:51:42.072131173Z TRACE quiche] fd9bc0cfbfdaf088546f8ffc84042f51e62cece3 tx pkt Handshake version=1 dcid=203afec490ab54a6 scid=fd9bc0cfbfdaf088546f8ffc84042f51e62cece3 len=1007 pn=9 [2025-04-30T11:51:42.072136022Z TRACE quiche] fd9bc0cfbfdaf088546f8ffc84042f51e62cece3 tx frm CRYPTO off=8970 len=1002 [2025-04-30T11:51:42.072144077Z TRACE quiche::recovery::congestion::recovery] fd9bc0cfbfdaf088546f8ffc84042f51e62cece3 timer=998.978469ms latest_rtt=0ns srtt=333ms min_rtt=333ms rttvar=166.5ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=10507 app_limited=true congestion_recovery_start_time=None Rate { delivered: 0, delivered_time: Instant { tv_sec: 657, tv_nsec: 24418860 }, first_sent_time: Instant { tv_sec: 657, tv_nsec: 24418860 }, 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: 657, tv_nsec: 862233366 }, next_time: Instant { tv_sec: 657, tv_nsec: 862233366 }, max_datagram_size: 1350, last_packet_size: None, iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } [2025-04-30T11:51:42.072177079Z TRACE quiche_server] fd9bc0cfbfdaf088546f8ffc84042f51e62cece3 written 1061 bytes with Some(SendInfo { from: [::]:443, to: [::ffff:193.167.0.100]:46267, at: Instant { tv_sec: 657, tv_nsec: 862233366 } }) [2025-04-30T11:51:42.072184974Z TRACE quiche_server] Collecting garbage [2025-04-30T11:51:42.072190444Z TRACE quiche_server] recv() would block [2025-04-30T11:51:42.072195954Z TRACE quiche_server] fd9bc0cfbfdaf088546f8ffc84042f51e62cece3 done writing [2025-04-30T11:51:42.072199421Z TRACE quiche_server] Collecting garbage [2025-04-30T11:51:42.103288661Z TRACE quiche_server] got 59 bytes from [::ffff:193.167.0.100]:46267 to [::]:443 [2025-04-30T11:51:42.103302477Z TRACE quiche_server] got packet Handshake version=1 dcid=fd9bc0cfbfdaf088546f8ffc84042f51e62cece3 scid=203afec490ab54a6 [2025-04-30T11:51:42.103313808Z TRACE quiche] fd9bc0cfbfdaf088546f8ffc84042f51e62cece3 rx pkt Handshake version=1 dcid=fd9bc0cfbfdaf088546f8ffc84042f51e62cece3 scid=203afec490ab54a6 len=22 pn=8 [2025-04-30T11:51:42.103329437Z TRACE quiche] fd9bc0cfbfdaf088546f8ffc84042f51e62cece3 rx frm ACK delay=9 blocks=[1..4] ecn_counts=None [2025-04-30T11:51:42.103335919Z TRACE quiche::recovery::congestion::recovery] fd9bc0cfbfdaf088546f8ffc84042f51e62cece3 packet newly acked 1 [2025-04-30T11:51:42.103339937Z TRACE quiche::recovery::congestion::recovery] fd9bc0cfbfdaf088546f8ffc84042f51e62cece3 packet newly acked 2 [2025-04-30T11:51:42.103342912Z TRACE quiche::recovery::congestion::recovery] fd9bc0cfbfdaf088546f8ffc84042f51e62cece3 packet newly acked 3 [2025-04-30T11:51:42.103345828Z TRACE quiche::recovery::congestion::recovery] fd9bc0cfbfdaf088546f8ffc84042f51e62cece3 packet newly acked 4 [2025-04-30T11:51:42.103369242Z TRACE quiche_server] fd9bc0cfbfdaf088546f8ffc84042f51e62cece3 processed 59 bytes [2025-04-30T11:51:42.103375042Z TRACE quiche_server] recv() would block [2025-04-30T11:51:42.103381815Z TRACE quiche_server] fd9bc0cfbfdaf088546f8ffc84042f51e62cece3 done writing [2025-04-30T11:51:42.103385232Z TRACE quiche_server] Collecting garbage [2025-04-30T11:51:42.104162966Z TRACE quiche_server] got 59 bytes from [::ffff:193.167.0.100]:46267 to [::]:443 [2025-04-30T11:51:42.104169357Z TRACE quiche_server] got packet Handshake version=1 dcid=fd9bc0cfbfdaf088546f8ffc84042f51e62cece3 scid=203afec490ab54a6 [2025-04-30T11:51:42.104174417Z TRACE quiche] fd9bc0cfbfdaf088546f8ffc84042f51e62cece3 rx pkt Handshake version=1 dcid=fd9bc0cfbfdaf088546f8ffc84042f51e62cece3 scid=203afec490ab54a6 len=22 pn=9 [2025-04-30T11:51:42.104179005Z TRACE quiche] fd9bc0cfbfdaf088546f8ffc84042f51e62cece3 rx frm ACK delay=3 blocks=[1..5] ecn_counts=None [2025-04-30T11:51:42.104182141Z TRACE quiche::recovery::congestion::recovery] fd9bc0cfbfdaf088546f8ffc84042f51e62cece3 packet newly acked 5 [2025-04-30T11:51:42.104191308Z TRACE quiche_server] fd9bc0cfbfdaf088546f8ffc84042f51e62cece3 processed 59 bytes [2025-04-30T11:51:42.104194845Z TRACE quiche_server] recv() would block [2025-04-30T11:51:42.104198231Z TRACE quiche_server] fd9bc0cfbfdaf088546f8ffc84042f51e62cece3 done writing [2025-04-30T11:51:42.104200516Z TRACE quiche_server] Collecting garbage [2025-04-30T11:51:42.105094447Z TRACE quiche_server] got 59 bytes from [::ffff:193.167.0.100]:46267 to [::]:443 [2025-04-30T11:51:42.105100147Z TRACE quiche_server] got packet Handshake version=1 dcid=fd9bc0cfbfdaf088546f8ffc84042f51e62cece3 scid=203afec490ab54a6 [2025-04-30T11:51:42.105104856Z TRACE quiche] fd9bc0cfbfdaf088546f8ffc84042f51e62cece3 rx pkt Handshake version=1 dcid=fd9bc0cfbfdaf088546f8ffc84042f51e62cece3 scid=203afec490ab54a6 len=22 pn=10 [2025-04-30T11:51:42.105109365Z TRACE quiche] fd9bc0cfbfdaf088546f8ffc84042f51e62cece3 rx frm ACK delay=2 blocks=[1..6] ecn_counts=None [2025-04-30T11:51:42.105112230Z TRACE quiche::recovery::congestion::recovery] fd9bc0cfbfdaf088546f8ffc84042f51e62cece3 packet newly acked 6 [2025-04-30T11:51:42.105120195Z TRACE quiche_server] fd9bc0cfbfdaf088546f8ffc84042f51e62cece3 processed 59 bytes [2025-04-30T11:51:42.105123551Z TRACE quiche_server] recv() would block [2025-04-30T11:51:42.105126577Z TRACE quiche_server] fd9bc0cfbfdaf088546f8ffc84042f51e62cece3 done writing [2025-04-30T11:51:42.105128871Z TRACE quiche_server] Collecting garbage [2025-04-30T11:51:42.106025497Z TRACE quiche_server] got 59 bytes from [::ffff:193.167.0.100]:46267 to [::]:443 [2025-04-30T11:51:42.106031108Z TRACE quiche_server] got packet Handshake version=1 dcid=fd9bc0cfbfdaf088546f8ffc84042f51e62cece3 scid=203afec490ab54a6 [2025-04-30T11:51:42.106035636Z TRACE quiche] fd9bc0cfbfdaf088546f8ffc84042f51e62cece3 rx pkt Handshake version=1 dcid=fd9bc0cfbfdaf088546f8ffc84042f51e62cece3 scid=203afec490ab54a6 len=22 pn=11 [2025-04-30T11:51:42.106039984Z TRACE quiche] fd9bc0cfbfdaf088546f8ffc84042f51e62cece3 rx frm ACK delay=2 blocks=[1..7] ecn_counts=None [2025-04-30T11:51:42.106042840Z TRACE quiche::recovery::congestion::recovery] fd9bc0cfbfdaf088546f8ffc84042f51e62cece3 packet newly acked 7 [2025-04-30T11:51:42.106074409Z TRACE quiche_server] fd9bc0cfbfdaf088546f8ffc84042f51e62cece3 processed 59 bytes [2025-04-30T11:51:42.106078246Z TRACE quiche_server] recv() would block [2025-04-30T11:51:42.106081482Z TRACE quiche_server] fd9bc0cfbfdaf088546f8ffc84042f51e62cece3 done writing [2025-04-30T11:51:42.106083736Z TRACE quiche_server] Collecting garbage [2025-04-30T11:51:42.107021489Z TRACE quiche_server] got 59 bytes from [::ffff:193.167.0.100]:46267 to [::]:443 [2025-04-30T11:51:42.107027350Z TRACE quiche_server] got packet Handshake version=1 dcid=fd9bc0cfbfdaf088546f8ffc84042f51e62cece3 scid=203afec490ab54a6 [2025-04-30T11:51:42.107032259Z TRACE quiche] fd9bc0cfbfdaf088546f8ffc84042f51e62cece3 rx pkt Handshake version=1 dcid=fd9bc0cfbfdaf088546f8ffc84042f51e62cece3 scid=203afec490ab54a6 len=22 pn=12 [2025-04-30T11:51:42.107036708Z TRACE quiche] fd9bc0cfbfdaf088546f8ffc84042f51e62cece3 rx frm ACK delay=2 blocks=[1..8] ecn_counts=None [2025-04-30T11:51:42.107039733Z TRACE quiche::recovery::congestion::recovery] fd9bc0cfbfdaf088546f8ffc84042f51e62cece3 packet newly acked 8 [2025-04-30T11:51:42.107047929Z TRACE quiche_server] fd9bc0cfbfdaf088546f8ffc84042f51e62cece3 processed 59 bytes [2025-04-30T11:51:42.107051335Z TRACE quiche_server] recv() would block [2025-04-30T11:51:42.107054431Z TRACE quiche_server] fd9bc0cfbfdaf088546f8ffc84042f51e62cece3 done writing [2025-04-30T11:51:42.107056665Z TRACE quiche_server] Collecting garbage [2025-04-30T11:51:42.108121496Z TRACE quiche_server] got 114 bytes from [::ffff:193.167.0.100]:46267 to [::]:443 [2025-04-30T11:51:42.108127086Z TRACE quiche_server] got packet Handshake version=1 dcid=fd9bc0cfbfdaf088546f8ffc84042f51e62cece3 scid=203afec490ab54a6 [2025-04-30T11:51:42.108131625Z TRACE quiche] fd9bc0cfbfdaf088546f8ffc84042f51e62cece3 rx pkt Handshake version=1 dcid=fd9bc0cfbfdaf088546f8ffc84042f51e62cece3 scid=203afec490ab54a6 len=77 pn=13 [2025-04-30T11:51:42.108136314Z TRACE quiche] fd9bc0cfbfdaf088546f8ffc84042f51e62cece3 rx frm ACK delay=25 blocks=[1..9] ecn_counts=None [2025-04-30T11:51:42.108139269Z TRACE quiche::recovery::congestion::recovery] fd9bc0cfbfdaf088546f8ffc84042f51e62cece3 packet newly acked 9 [2025-04-30T11:51:42.108142686Z TRACE quiche] fd9bc0cfbfdaf088546f8ffc84042f51e62cece3 rx frm CRYPTO off=0 len=52 [2025-04-30T11:51:42.108156932Z TRACE quiche::tls] fd9bc0cfbfdaf088546f8ffc84042f51e62cece3 set read secret lvl=OneRTT [2025-04-30T11:51:42.108194071Z TRACE quiche::tls] fd9bc0cfbfdaf088546f8ffc84042f51e62cece3 write message lvl=OneRTT len=428 [2025-04-30T11:51:42.108202086Z TRACE quiche] fd9bc0cfbfdaf088546f8ffc84042f51e62cece3 dropped epoch 1 state [2025-04-30T11:51:42.108205793Z TRACE quiche] fd9bc0cfbfdaf088546f8ffc84042f51e62cece3 connection established: proto=Ok("hq-interop") cipher=Some(AES256_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: 1472, initial_max_data: 4611686018427387903, initial_max_stream_data_bidi_local: 1250000, initial_max_stream_data_bidi_remote: 1250000, initial_max_stream_data_uni: 1250000, initial_max_streams_bidi: 100, initial_max_streams_uni: 100, ack_delay_exponent: 3, max_ack_delay: 25, disable_active_migration: false, active_conn_id_limit: 5, initial_source_connection_id: Some(203afec490ab54a6), retry_source_connection_id: None, max_datagram_frame_size: Some(65535), unknown_params: None } [2025-04-30T11:51:42.108224118Z TRACE quiche_server] fd9bc0cfbfdaf088546f8ffc84042f51e62cece3 processed 114 bytes [2025-04-30T11:51:42.108235239Z TRACE quiche_server] recv() would block [2025-04-30T11:51:42.108240468Z TRACE quiche] fd9bc0cfbfdaf088546f8ffc84042f51e62cece3 pmtud probe status false hs_con=true hs_sent=false cwnd_avail=13500 out_len=1350 left=1324 [2025-04-30T11:51:42.108247982Z TRACE quiche] fd9bc0cfbfdaf088546f8ffc84042f51e62cece3 tx pkt Short dcid=203afec490ab54a6 key_phase=false len=593 pn=10 [2025-04-30T11:51:42.108250728Z TRACE quiche] fd9bc0cfbfdaf088546f8ffc84042f51e62cece3 tx frm NEW_CONNECTION_ID seq_num=1 retire_prior_to=0 conn_id=[1a, 8c, 00, f2, d2, f7, c3, 28, 1f, e0, 57, d2, 32, 8f, 54, 4b, ec, c7, fe, 6d] reset_token=[3a, ef, 13, 05, 27, 9f, db, 3b, 75, fd, 99, 89, fd, 15, 93, d2] [2025-04-30T11:51:42.108262740Z TRACE quiche] fd9bc0cfbfdaf088546f8ffc84042f51e62cece3 tx frm NEW_CONNECTION_ID seq_num=2 retire_prior_to=0 conn_id=[d4, b1, 25, d6, 97, 8b, bd, 7f, 7a, 72, d1, f8, 14, 66, 9c, bb, ea, 73, 8d, 0c] reset_token=[38, 9c, c1, a5, 67, 7c, 00, ab, 87, 41, 86, ca, 4b, 31, 93, f3] [2025-04-30T11:51:42.108268551Z TRACE quiche] fd9bc0cfbfdaf088546f8ffc84042f51e62cece3 tx frm NEW_CONNECTION_ID seq_num=3 retire_prior_to=0 conn_id=[0d, af, 10, 36, ac, cb, 3c, 13, e0, 8d, 09, 34, 3c, b1, 96, 71, 26, b3, 19, 74] reset_token=[40, 1c, c1, a9, 8b, 94, fb, ec, 95, c6, 3c, 1c, 66, 93, c9, e7] [2025-04-30T11:51:42.108274281Z TRACE quiche] fd9bc0cfbfdaf088546f8ffc84042f51e62cece3 tx frm NEW_CONNECTION_ID seq_num=4 retire_prior_to=0 conn_id=[7b, 9a, 43, a2, 14, c4, 86, a6, 18, f0, e7, 97, db, 4d, 8d, 22, 43, fa, 93, de] reset_token=[f6, 9e, fb, dd, c7, a7, 1e, 3b, a9, 04, c4, 71, b7, 1c, 48, ad] [2025-04-30T11:51:42.108279712Z TRACE quiche] fd9bc0cfbfdaf088546f8ffc84042f51e62cece3 tx frm HANDSHAKE_DONE [2025-04-30T11:51:42.108282076Z TRACE quiche] fd9bc0cfbfdaf088546f8ffc84042f51e62cece3 tx frm CRYPTO off=0 len=428 [2025-04-30T11:51:42.108292475Z TRACE quiche::recovery::congestion::recovery] fd9bc0cfbfdaf088546f8ffc84042f51e62cece3 timer=80.286678ms latest_rtt=36.008136ms srtt=32.95612ms min_rtt=31.668903ms rttvar=5.596493ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=619 app_limited=true congestion_recovery_start_time=None Rate { delivered: 10507, delivered_time: Instant { tv_sec: 657, tv_nsec: 898347861 }, first_sent_time: Instant { tv_sec: 657, tv_nsec: 898347861 }, end_of_app_limited: 9, last_sent_packet: 10, largest_acked: 9, rate_sample: RateSample { delivery_rate: 12090, is_app_limited: true, interval: 869.002731ms, delivered: 10507, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 657, tv_nsec: 24418860 }), send_elapsed: 0ns, ack_elapsed: 869.002731ms, rtt: 869.002731ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 512044, last_update: Instant { tv_sec: 657, tv_nsec: 898347861 }, next_time: Instant { tv_sec: 657, tv_nsec: 898347861 }, 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-30T11:51:42.108338982Z TRACE quiche_server] fd9bc0cfbfdaf088546f8ffc84042f51e62cece3 written 619 bytes with Some(SendInfo { from: [::]:443, to: [::ffff:193.167.0.100]:46267, at: Instant { tv_sec: 657, tv_nsec: 898347861 } }) [2025-04-30T11:51:42.108347489Z TRACE quiche_server] Collecting garbage [2025-04-30T11:51:42.108355874Z TRACE quiche_server] got 234 bytes from [::ffff:193.167.0.100]:46267 to [::]:443 [2025-04-30T11:51:42.108361004Z TRACE quiche_server] got packet Short dcid=fd9bc0cfbfdaf088546f8ffc84042f51e62cece3 key_phase=false [2025-04-30T11:51:42.108368648Z TRACE quiche] fd9bc0cfbfdaf088546f8ffc84042f51e62cece3 rx pkt Short dcid=fd9bc0cfbfdaf088546f8ffc84042f51e62cece3 key_phase=false len=213 pn=0 [2025-04-30T11:51:42.108378176Z TRACE quiche] fd9bc0cfbfdaf088546f8ffc84042f51e62cece3 rx frm NEW_CONNECTION_ID seq_num=1 retire_prior_to=0 conn_id=[1b, bd, c5, 30, 87, 70, 1f, 8e] reset_token=[a3, 88, a6, c1, 6d, 67, 0b, 90, 15, 6d, 87, 6c, 19, 6d, 19, 34] [2025-04-30T11:51:42.108384778Z TRACE quiche] fd9bc0cfbfdaf088546f8ffc84042f51e62cece3 rx frm NEW_CONNECTION_ID seq_num=2 retire_prior_to=0 conn_id=[6e, f7, 40, 8d, be, af, 36, 2b] reset_token=[37, 62, 4d, 6a, 69, ff, d8, ac, 63, cf, 03, a4, 53, 33, bf, e2] [2025-04-30T11:51:42.108389627Z TRACE quiche] fd9bc0cfbfdaf088546f8ffc84042f51e62cece3 rx frm NEW_CONNECTION_ID seq_num=3 retire_prior_to=0 conn_id=[4a, 95, 12, aa, a0, 1f, 15, 4e] reset_token=[a7, 0e, 13, 3e, a5, e8, f2, 79, 0f, cf, c1, b6, 89, b0, fa, 7c] [2025-04-30T11:51:42.108398824Z TRACE quiche] fd9bc0cfbfdaf088546f8ffc84042f51e62cece3 rx frm NEW_CONNECTION_ID seq_num=4 retire_prior_to=0 conn_id=[5c, a7, fb, b1, ff, dd, e7, a2] reset_token=[21, 1b, 05, ef, a7, 72, 99, 33, 35, b6, fc, 8d, 72, 02, f2, b0] [2025-04-30T11:51:42.108404264Z TRACE quiche] fd9bc0cfbfdaf088546f8ffc84042f51e62cece3 rx frm NEW_CONNECTION_ID seq_num=5 retire_prior_to=0 conn_id=[1c, e7, 46, 32, e5, 0b, f8, 02] reset_token=[d8, 78, 0f, b8, 69, 57, 0b, bc, 92, 2b, f2, 06, b6, 1e, 9e, fa] [2025-04-30T11:51:42.108409013Z TRACE quiche] fd9bc0cfbfdaf088546f8ffc84042f51e62cece3 rx frm NEW_CONNECTION_ID seq_num=6 retire_prior_to=0 conn_id=[6e, ae, d6, d5, 8b, d7, 1c, e3] reset_token=[90, 7a, f4, db, b9, 1b, 3c, 06, 84, a8, d2, b2, ad, d8, a0, f7] [2025-04-30T11:51:42.108413592Z TRACE quiche] fd9bc0cfbfdaf088546f8ffc84042f51e62cece3 rx frm NEW_CONNECTION_ID seq_num=7 retire_prior_to=0 conn_id=[58, fd, 6f, d0, f3, 27, 39, 48] reset_token=[17, 8e, 2e, 45, 7e, 99, 42, 31, ce, a5, 4f, b1, 54, a7, 74, 7a] [2025-04-30T11:51:42.108423581Z TRACE quiche_server] fd9bc0cfbfdaf088546f8ffc84042f51e62cece3 processed 234 bytes [2025-04-30T11:51:42.108429041Z TRACE quiche_server] got 58 bytes from [::ffff:193.167.0.100]:46267 to [::]:443 [2025-04-30T11:51:42.108431896Z TRACE quiche_server] got packet Short dcid=fd9bc0cfbfdaf088546f8ffc84042f51e62cece3 key_phase=false [2025-04-30T11:51:42.108435803Z TRACE quiche] fd9bc0cfbfdaf088546f8ffc84042f51e62cece3 rx pkt Short dcid=fd9bc0cfbfdaf088546f8ffc84042f51e62cece3 key_phase=false len=37 pn=1 [2025-04-30T11:51:42.108439991Z TRACE quiche] fd9bc0cfbfdaf088546f8ffc84042f51e62cece3 rx frm STREAM id=0 off=0 len=17 fin=true [2025-04-30T11:51:42.108446634Z TRACE quiche_server] fd9bc0cfbfdaf088546f8ffc84042f51e62cece3 processed 58 bytes [2025-04-30T11:51:42.108449409Z DEBUG quiche_apps::common] fd9bc0cfbfdaf088546f8ffc84042f51e62cece3 response stream 0 is writable with capacity Ok(12881) [2025-04-30T11:51:42.108455781Z TRACE quiche_apps::common] fd9bc0cfbfdaf088546f8ffc84042f51e62cece3 received 17 bytes [2025-04-30T11:51:42.108458446Z TRACE quiche_apps::common] fd9bc0cfbfdaf088546f8ffc84042f51e62cece3 stream 0 has 17 bytes (fin? true) [2025-04-30T11:51:42.108463125Z INFO quiche_apps::common] fd9bc0cfbfdaf088546f8ffc84042f51e62cece3 got GET request for "/www/kqbysqcspf" on stream 0 [2025-04-30T11:51:42.108486749Z INFO quiche_apps::common] fd9bc0cfbfdaf088546f8ffc84042f51e62cece3 sending response of size 5120 on stream 0 [2025-04-30T11:51:42.108493752Z TRACE quiche_server] recv() would block [2025-04-30T11:51:42.108499032Z TRACE quiche] fd9bc0cfbfdaf088546f8ffc84042f51e62cece3 pmtud probe status false hs_con=true hs_sent=true cwnd_avail=12881 out_len=1350 left=1319 [2025-04-30T11:51:42.108503400Z TRACE quiche] fd9bc0cfbfdaf088546f8ffc84042f51e62cece3 tx pkt Short dcid=203afec490ab54a6 key_phase=false len=1324 pn=11 [2025-04-30T11:51:42.108505995Z TRACE quiche] fd9bc0cfbfdaf088546f8ffc84042f51e62cece3 tx frm ACK delay=7 blocks=[0..1] ecn_counts=None [2025-04-30T11:51:42.108509111Z TRACE quiche] fd9bc0cfbfdaf088546f8ffc84042f51e62cece3 tx frm STREAM id=0 off=0 len=1314 fin=false [2025-04-30T11:51:42.108516354Z TRACE quiche::recovery::congestion::recovery] fd9bc0cfbfdaf088546f8ffc84042f51e62cece3 timer=80.321333ms latest_rtt=36.008136ms srtt=32.95612ms min_rtt=31.668903ms rttvar=5.596493ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=1969 app_limited=true congestion_recovery_start_time=None Rate { delivered: 10507, delivered_time: Instant { tv_sec: 657, tv_nsec: 898347861 }, first_sent_time: Instant { tv_sec: 657, tv_nsec: 898347861 }, end_of_app_limited: 10, last_sent_packet: 11, largest_acked: 9, rate_sample: RateSample { delivery_rate: 12090, is_app_limited: true, interval: 869.002731ms, delivered: 10507, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 657, tv_nsec: 24418860 }), send_elapsed: 0ns, ack_elapsed: 869.002731ms, rtt: 869.002731ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 512044, last_update: Instant { tv_sec: 657, tv_nsec: 898347861 }, next_time: Instant { tv_sec: 657, tv_nsec: 898347861 }, 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-30T11:51:42.108533065Z TRACE quiche] fd9bc0cfbfdaf088546f8ffc84042f51e62cece3 pmtud probe status false hs_con=true hs_sent=true cwnd_avail=11531 out_len=1350 left=1324 [2025-04-30T11:51:42.108536402Z TRACE quiche] fd9bc0cfbfdaf088546f8ffc84042f51e62cece3 tx pkt Short dcid=203afec490ab54a6 key_phase=false len=1324 pn=12 [2025-04-30T11:51:42.108538866Z TRACE quiche] fd9bc0cfbfdaf088546f8ffc84042f51e62cece3 tx frm STREAM id=0 off=1314 len=1318 fin=false [2025-04-30T11:51:42.108543986Z TRACE quiche::recovery::congestion::recovery] fd9bc0cfbfdaf088546f8ffc84042f51e62cece3 timer=80.329448ms latest_rtt=36.008136ms srtt=32.95612ms min_rtt=31.668903ms rttvar=5.596493ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=3319 app_limited=true congestion_recovery_start_time=None Rate { delivered: 10507, delivered_time: Instant { tv_sec: 657, tv_nsec: 898347861 }, first_sent_time: Instant { tv_sec: 657, tv_nsec: 898347861 }, end_of_app_limited: 11, last_sent_packet: 12, largest_acked: 9, rate_sample: RateSample { delivery_rate: 12090, is_app_limited: true, interval: 869.002731ms, delivered: 10507, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 657, tv_nsec: 24418860 }), send_elapsed: 0ns, ack_elapsed: 869.002731ms, rtt: 869.002731ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 512044, last_update: Instant { tv_sec: 657, tv_nsec: 898347861 }, next_time: Instant { tv_sec: 657, tv_nsec: 898347861 }, 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-30T11:51:42.108554295Z TRACE quiche] fd9bc0cfbfdaf088546f8ffc84042f51e62cece3 pmtud probe status false hs_con=true hs_sent=true cwnd_avail=10181 out_len=1350 left=1324 [2025-04-30T11:51:42.108557301Z TRACE quiche] fd9bc0cfbfdaf088546f8ffc84042f51e62cece3 tx pkt Short dcid=203afec490ab54a6 key_phase=false len=1324 pn=13 [2025-04-30T11:51:42.108559685Z TRACE quiche] fd9bc0cfbfdaf088546f8ffc84042f51e62cece3 tx frm STREAM id=0 off=2632 len=1318 fin=false [2025-04-30T11:51:42.108564073Z TRACE quiche::recovery::congestion::recovery] fd9bc0cfbfdaf088546f8ffc84042f51e62cece3 timer=80.331121ms latest_rtt=36.008136ms srtt=32.95612ms min_rtt=31.668903ms rttvar=5.596493ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=4669 app_limited=true congestion_recovery_start_time=None Rate { delivered: 10507, delivered_time: Instant { tv_sec: 657, tv_nsec: 898347861 }, first_sent_time: Instant { tv_sec: 657, tv_nsec: 898347861 }, end_of_app_limited: 12, last_sent_packet: 13, largest_acked: 9, rate_sample: RateSample { delivery_rate: 12090, is_app_limited: true, interval: 869.002731ms, delivered: 10507, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 657, tv_nsec: 24418860 }), send_elapsed: 0ns, ack_elapsed: 869.002731ms, rtt: 869.002731ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 512044, last_update: Instant { tv_sec: 657, tv_nsec: 898347861 }, next_time: Instant { tv_sec: 657, tv_nsec: 898347861 }, 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-30T11:51:42.108577238Z TRACE quiche] fd9bc0cfbfdaf088546f8ffc84042f51e62cece3 pmtud probe status false hs_con=true hs_sent=true cwnd_avail=8831 out_len=1350 left=1324 [2025-04-30T11:51:42.108580273Z TRACE quiche] fd9bc0cfbfdaf088546f8ffc84042f51e62cece3 tx pkt Short dcid=203afec490ab54a6 key_phase=false len=1176 pn=14 [2025-04-30T11:51:42.108582658Z TRACE quiche] fd9bc0cfbfdaf088546f8ffc84042f51e62cece3 tx frm STREAM id=0 off=3950 len=1170 fin=true [2025-04-30T11:51:42.108587788Z TRACE quiche::recovery::congestion::recovery] fd9bc0cfbfdaf088546f8ffc84042f51e62cece3 timer=80.33022ms latest_rtt=36.008136ms srtt=32.95612ms min_rtt=31.668903ms rttvar=5.596493ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=5871 app_limited=true congestion_recovery_start_time=None Rate { delivered: 10507, delivered_time: Instant { tv_sec: 657, tv_nsec: 898347861 }, first_sent_time: Instant { tv_sec: 657, tv_nsec: 898347861 }, end_of_app_limited: 13, last_sent_packet: 14, largest_acked: 9, rate_sample: RateSample { delivery_rate: 12090, is_app_limited: true, interval: 869.002731ms, delivered: 10507, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 657, tv_nsec: 24418860 }), send_elapsed: 0ns, ack_elapsed: 869.002731ms, rtt: 869.002731ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 512044, last_update: Instant { tv_sec: 657, tv_nsec: 898347861 }, next_time: Instant { tv_sec: 657, tv_nsec: 898347861 }, 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-30T11:51:42.108677936Z TRACE quiche_server] fd9bc0cfbfdaf088546f8ffc84042f51e62cece3 written 5252 bytes with Some(SendInfo { from: [::]:443, to: [::ffff:193.167.0.100]:46267, at: Instant { tv_sec: 657, tv_nsec: 898347861 } }) [2025-04-30T11:51:42.108686853Z TRACE quiche_server] Collecting garbage [2025-04-30T11:51:42.108692904Z TRACE quiche_server] recv() would block [2025-04-30T11:51:42.108695890Z TRACE quiche_server] fd9bc0cfbfdaf088546f8ffc84042f51e62cece3 done writing [2025-04-30T11:51:42.108698194Z TRACE quiche_server] Collecting garbage [2025-04-30T11:51:42.139272302Z TRACE quiche_server] got 43 bytes from [::ffff:193.167.0.100]:46267 to [::]:443 [2025-04-30T11:51:42.139285056Z TRACE quiche_server] got packet Short dcid=fd9bc0cfbfdaf088546f8ffc84042f51e62cece3 key_phase=false [2025-04-30T11:51:42.139292740Z TRACE quiche] fd9bc0cfbfdaf088546f8ffc84042f51e62cece3 rx pkt Short dcid=fd9bc0cfbfdaf088546f8ffc84042f51e62cece3 key_phase=false len=22 pn=2 [2025-04-30T11:51:42.139299984Z TRACE quiche] fd9bc0cfbfdaf088546f8ffc84042f51e62cece3 rx frm ACK delay=8 blocks=[10..10] ecn_counts=None [2025-04-30T11:51:42.139304672Z TRACE quiche::recovery::congestion::recovery] fd9bc0cfbfdaf088546f8ffc84042f51e62cece3 packet newly acked 10 [2025-04-30T11:51:42.139317176Z TRACE quiche_server] fd9bc0cfbfdaf088546f8ffc84042f51e62cece3 processed 43 bytes [2025-04-30T11:51:42.139322436Z TRACE quiche_server] recv() would block [2025-04-30T11:51:42.139326153Z TRACE quiche_server] fd9bc0cfbfdaf088546f8ffc84042f51e62cece3 done writing [2025-04-30T11:51:42.139329098Z TRACE quiche_server] Collecting garbage [2025-04-30T11:51:42.141413806Z TRACE quiche_server] got 43 bytes from [::ffff:193.167.0.100]:46267 to [::]:443 [2025-04-30T11:51:42.141420899Z TRACE quiche_server] got packet Short dcid=fd9bc0cfbfdaf088546f8ffc84042f51e62cece3 key_phase=false [2025-04-30T11:51:42.141426099Z TRACE quiche] fd9bc0cfbfdaf088546f8ffc84042f51e62cece3 rx pkt Short dcid=fd9bc0cfbfdaf088546f8ffc84042f51e62cece3 key_phase=false len=22 pn=3 [2025-04-30T11:51:42.141431268Z TRACE quiche] fd9bc0cfbfdaf088546f8ffc84042f51e62cece3 rx frm ACK delay=2 blocks=[10..12] ecn_counts=None [2025-04-30T11:51:42.141434955Z TRACE quiche::recovery::congestion::recovery] fd9bc0cfbfdaf088546f8ffc84042f51e62cece3 packet newly acked 11 [2025-04-30T11:51:42.141445205Z TRACE quiche::recovery::congestion::recovery] fd9bc0cfbfdaf088546f8ffc84042f51e62cece3 packet newly acked 12 [2025-04-30T11:51:42.141456425Z TRACE quiche_server] fd9bc0cfbfdaf088546f8ffc84042f51e62cece3 processed 43 bytes [2025-04-30T11:51:42.141461034Z TRACE quiche_server] recv() would block [2025-04-30T11:51:42.141464290Z TRACE quiche_server] fd9bc0cfbfdaf088546f8ffc84042f51e62cece3 done writing [2025-04-30T11:51:42.141466985Z TRACE quiche_server] Collecting garbage [2025-04-30T11:51:42.143484828Z TRACE quiche_server] got 43 bytes from [::ffff:193.167.0.100]:46267 to [::]:443 [2025-04-30T11:51:42.143491901Z TRACE quiche_server] got packet Short dcid=fd9bc0cfbfdaf088546f8ffc84042f51e62cece3 key_phase=false [2025-04-30T11:51:42.143497101Z TRACE quiche] fd9bc0cfbfdaf088546f8ffc84042f51e62cece3 rx pkt Short dcid=fd9bc0cfbfdaf088546f8ffc84042f51e62cece3 key_phase=false len=22 pn=4 [2025-04-30T11:51:42.143502360Z TRACE quiche] fd9bc0cfbfdaf088546f8ffc84042f51e62cece3 rx frm ACK delay=1 blocks=[10..14] ecn_counts=None [2025-04-30T11:51:42.143505927Z TRACE quiche::recovery::congestion::recovery] fd9bc0cfbfdaf088546f8ffc84042f51e62cece3 packet newly acked 13 [2025-04-30T11:51:42.143508792Z TRACE quiche::recovery::congestion::recovery] fd9bc0cfbfdaf088546f8ffc84042f51e62cece3 packet newly acked 14 [2025-04-30T11:51:42.143532477Z TRACE quiche_server] fd9bc0cfbfdaf088546f8ffc84042f51e62cece3 processed 43 bytes [2025-04-30T11:51:42.143537246Z TRACE quiche_server] recv() would block [2025-04-30T11:51:42.143540462Z TRACE quiche_server] fd9bc0cfbfdaf088546f8ffc84042f51e62cece3 done writing [2025-04-30T11:51:42.143543247Z TRACE quiche_server] Collecting garbage [2025-04-30T11:51:42.143611324Z TRACE quiche_server] got 46 bytes from [::ffff:193.167.0.100]:46267 to [::]:443 [2025-04-30T11:51:42.143615582Z TRACE quiche_server] got packet Short dcid=fd9bc0cfbfdaf088546f8ffc84042f51e62cece3 key_phase=false [2025-04-30T11:51:42.143620572Z TRACE quiche] fd9bc0cfbfdaf088546f8ffc84042f51e62cece3 rx pkt Short dcid=fd9bc0cfbfdaf088546f8ffc84042f51e62cece3 key_phase=false len=25 pn=5 [2025-04-30T11:51:42.143625711Z TRACE quiche] fd9bc0cfbfdaf088546f8ffc84042f51e62cece3 rx frm ACK delay=17 blocks=[10..14] ecn_counts=None [2025-04-30T11:51:42.143630290Z TRACE quiche] fd9bc0cfbfdaf088546f8ffc84042f51e62cece3 rx frm APPLICATION_CLOSE err=0 reason=[] [2025-04-30T11:51:42.143638194Z TRACE quiche_server] fd9bc0cfbfdaf088546f8ffc84042f51e62cece3 processed 46 bytes [2025-04-30T11:51:42.143642382Z TRACE quiche_server] recv() would block [2025-04-30T11:51:42.143645178Z TRACE quiche_server] fd9bc0cfbfdaf088546f8ffc84042f51e62cece3 done writing [2025-04-30T11:51:42.143647843Z TRACE quiche_server] Collecting garbage [2025-04-30T11:51:42.283832482Z TRACE quiche_server] timed out [2025-04-30T11:51:42.283849294Z TRACE quiche] fd9bc0cfbfdaf088546f8ffc84042f51e62cece3 draining timeout expired [2025-04-30T11:51:42.283878217Z TRACE quiche_server] fd9bc0cfbfdaf088546f8ffc84042f51e62cece3 done writing [2025-04-30T11:51:42.283881884Z TRACE quiche_server] Collecting garbage [2025-04-30T11:51:42.283885291Z INFO quiche_server] fd9bc0cfbfdaf088546f8ffc84042f51e62cece3 connection collected recv=15 sent=15 lost=0 retrans=0 sent_bytes=16532 recv_bytes=2190 lost_bytes=0 [local_addr=[::]:443 peer_addr=[::ffff:193.167.0.100]:46267 validation_state=Validated active=true recv=15 sent=15 lost=0 retrans=0 rtt=33.084535ms min_rtt=Some(31.053774ms) rttvar=3.332602ms cwnd=13500 sent_bytes=16532 recv_bytes=2190 lost_bytes=0 stream_retrans_bytes=0 pmtu=1350 delivery_rate=189059]