[2025-04-30T18:04:57.093550925Z INFO  quiche_server] listening on [::]:443
[2025-04-30T18:04:57.093574048Z TRACE mio::poll] registering event source with poller: token=Token(0), interests=READABLE
[2025-04-30T18:04:57.093580520Z TRACE quiche_server] GSO detected: false
[2025-04-30T18:04:57.923823563Z TRACE quiche_server] got 1207 bytes from [::ffff:193.167.100.2]:52813 to [::]:443
[2025-04-30T18:04:57.923857246Z TRACE quiche_server] got packet Initial version=57414954 dcid= scid= token=
[2025-04-30T18:04:57.923865952Z WARN  quiche_server] Doing version negotiation
[2025-04-30T18:04:57.923962372Z TRACE quiche_server] got 1207 bytes from [::ffff:193.167.100.2]:52813 to [::]:443
[2025-04-30T18:04:57.923968443Z TRACE quiche_server] got packet Initial version=57414954 dcid= scid= token=
[2025-04-30T18:04:57.923974745Z WARN  quiche_server] Doing version negotiation
[2025-04-30T18:04:57.924013437Z TRACE quiche_server] got 1207 bytes from [::ffff:193.167.100.2]:52813 to [::]:443
[2025-04-30T18:04:57.924018707Z TRACE quiche_server] got packet Initial version=57414954 dcid= scid= token=
[2025-04-30T18:04:57.924022234Z WARN  quiche_server] Doing version negotiation
[2025-04-30T18:04:57.924044205Z TRACE quiche_server] recv() would block
[2025-04-30T18:04:58.866924413Z TRACE quiche_server] got 1200 bytes from [::ffff:193.167.0.100]:44801 to [::]:443
[2025-04-30T18:04:58.866950231Z TRACE quiche_server] got packet Initial version=1 dcid=77cba19a51732421 scid=3d752cd322a203e9 token=
[2025-04-30T18:04:58.866960280Z DEBUG quiche_server] New connection: dcid=77cba19a51732421 scid=7fc7e24eb3f657759e9761fc5b1e21a46205e5f2
[2025-04-30T18:04:58.867178948Z TRACE quiche] 7fc7e24eb3f657759e9761fc5b1e21a46205e5f2 rx pkt Initial version=1 dcid=77cba19a51732421 scid=3d752cd322a203e9 token= len=1174 pn=0 
[2025-04-30T18:04:58.867191421Z TRACE quiche] 7fc7e24eb3f657759e9761fc5b1e21a46205e5f2 rx frm CRYPTO off=0 len=305
[2025-04-30T18:04:58.867220145Z TRACE quiche::tls] checking peer ALPN Ok("hq-interop") against Ok("h3")
[2025-04-30T18:04:58.867223932Z TRACE quiche::tls] checking peer ALPN Ok("hq-interop") against Ok("hq-interop")
[2025-04-30T18:04:58.867320733Z TRACE quiche::tls] 7fc7e24eb3f657759e9761fc5b1e21a46205e5f2 write message lvl=Initial len=123
[2025-04-30T18:04:58.867348074Z TRACE quiche::tls] 7fc7e24eb3f657759e9761fc5b1e21a46205e5f2 set write secret lvl=Handshake
[2025-04-30T18:04:58.867418896Z TRACE quiche::tls] 7fc7e24eb3f657759e9761fc5b1e21a46205e5f2 write message lvl=Handshake len=696
[2025-04-30T18:04:58.867422132Z TRACE quiche::tls] 7fc7e24eb3f657759e9761fc5b1e21a46205e5f2 set write secret lvl=OneRTT
[2025-04-30T18:04:58.867428454Z TRACE quiche::tls] 7fc7e24eb3f657759e9761fc5b1e21a46205e5f2 set read secret lvl=Handshake
[2025-04-30T18:04:58.867447740Z TRACE quiche] 7fc7e24eb3f657759e9761fc5b1e21a46205e5f2 rx frm PADDING len=845
[2025-04-30T18:04:58.867468799Z TRACE quiche_server] 7fc7e24eb3f657759e9761fc5b1e21a46205e5f2 processed 1200 bytes
[2025-04-30T18:04:58.867486823Z TRACE quiche_server] recv() would block
[2025-04-30T18:04:58.867498585Z TRACE quiche] 7fc7e24eb3f657759e9761fc5b1e21a46205e5f2 tx pkt Initial version=1 dcid=3d752cd322a203e9 scid=7fc7e24eb3f657759e9761fc5b1e21a46205e5f2 len=132 pn=0 
[2025-04-30T18:04:58.867501951Z TRACE quiche] 7fc7e24eb3f657759e9761fc5b1e21a46205e5f2 tx frm ACK delay=42 blocks=[0..0] ecn_counts=None
[2025-04-30T18:04:58.867506189Z TRACE quiche] 7fc7e24eb3f657759e9761fc5b1e21a46205e5f2 tx frm CRYPTO off=0 len=123
[2025-04-30T18:04:58.867515096Z TRACE quiche::recovery::congestion::recovery] 7fc7e24eb3f657759e9761fc5b1e21a46205e5f2 timer=998.97329ms latest_rtt=0ns srtt=333ms min_rtt=333ms rttvar=166.5ms cwnd=12000 ssthresh=18446744073709551615 bytes_in_flight=187 app_limited=true congestion_recovery_start_time=None Rate { delivered: 0, delivered_time: Instant { tv_sec: 356, tv_nsec: 159831432 }, first_sent_time: Instant { tv_sec: 356, tv_nsec: 159831432 }, 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: 12000, used: 0, rate: 0, last_update: Instant { tv_sec: 356, tv_nsec: 159831432 }, next_time: Instant { tv_sec: 356, tv_nsec: 159831432 }, max_datagram_size: 1200, 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-30T18:04:58.867553257Z TRACE quiche] 7fc7e24eb3f657759e9761fc5b1e21a46205e5f2 tx pkt Handshake version=1 dcid=3d752cd322a203e9 scid=7fc7e24eb3f657759e9761fc5b1e21a46205e5f2 len=700 pn=1 
[2025-04-30T18:04:58.867556132Z TRACE quiche] 7fc7e24eb3f657759e9761fc5b1e21a46205e5f2 tx frm CRYPTO off=0 len=696
[2025-04-30T18:04:58.867561612Z TRACE quiche::recovery::congestion::recovery] 7fc7e24eb3f657759e9761fc5b1e21a46205e5f2 timer=998.927204ms latest_rtt=0ns srtt=333ms min_rtt=333ms rttvar=166.5ms cwnd=12000 ssthresh=18446744073709551615 bytes_in_flight=941 app_limited=true congestion_recovery_start_time=None Rate { delivered: 0, delivered_time: Instant { tv_sec: 356, tv_nsec: 159831432 }, first_sent_time: Instant { tv_sec: 356, tv_nsec: 159831432 }, 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: 12000, used: 0, rate: 0, last_update: Instant { tv_sec: 356, tv_nsec: 159831432 }, next_time: Instant { tv_sec: 356, tv_nsec: 159831432 }, max_datagram_size: 1200, 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-30T18:04:58.867602709Z TRACE quiche_server] 7fc7e24eb3f657759e9761fc5b1e21a46205e5f2 written 1200 bytes with Some(SendInfo { from: [::]:443, to: [::ffff:193.167.0.100]:44801, at: Instant { tv_sec: 356, tv_nsec: 159831432 } })
[2025-04-30T18:04:58.867608490Z TRACE quiche_server] Collecting garbage
[2025-04-30T18:04:58.867613369Z TRACE quiche_server] recv() would block
[2025-04-30T18:04:58.867616856Z TRACE quiche_server] 7fc7e24eb3f657759e9761fc5b1e21a46205e5f2 done writing
[2025-04-30T18:04:58.867619090Z TRACE quiche_server] Collecting garbage
[2025-04-30T18:04:59.613082473Z TRACE quiche_server] got 1200 bytes from [::ffff:193.167.0.100]:44801 to [::]:443
[2025-04-30T18:04:59.613114172Z TRACE quiche_server] got packet Initial version=1 dcid=77cba19a51732421 scid=3d752cd322a203e9 token=
[2025-04-30T18:04:59.613128359Z TRACE quiche] 7fc7e24eb3f657759e9761fc5b1e21a46205e5f2 rx pkt Initial version=1 dcid=77cba19a51732421 scid=3d752cd322a203e9 token= len=1174 pn=1 
[2025-04-30T18:04:59.613140000Z TRACE quiche] 7fc7e24eb3f657759e9761fc5b1e21a46205e5f2 rx frm CRYPTO off=0 len=305
[2025-04-30T18:04:59.613153495Z TRACE quiche] 7fc7e24eb3f657759e9761fc5b1e21a46205e5f2 rx frm PADDING len=845
[2025-04-30T18:04:59.613171459Z TRACE quiche_server] 7fc7e24eb3f657759e9761fc5b1e21a46205e5f2 processed 1200 bytes
[2025-04-30T18:04:59.613176909Z TRACE quiche_server] recv() would block
[2025-04-30T18:04:59.613188120Z TRACE quiche] 7fc7e24eb3f657759e9761fc5b1e21a46205e5f2 tx pkt Initial version=1 dcid=3d752cd322a203e9 scid=7fc7e24eb3f657759e9761fc5b1e21a46205e5f2 len=5 pn=2 
[2025-04-30T18:04:59.613191316Z TRACE quiche] 7fc7e24eb3f657759e9761fc5b1e21a46205e5f2 tx frm ACK delay=7 blocks=[0..1] ecn_counts=None
[2025-04-30T18:04:59.613202116Z TRACE quiche::recovery::congestion::recovery] 7fc7e24eb3f657759e9761fc5b1e21a46205e5f2 timer=253.286199ms latest_rtt=0ns srtt=333ms min_rtt=333ms rttvar=166.5ms cwnd=12000 ssthresh=18446744073709551615 bytes_in_flight=941 app_limited=true congestion_recovery_start_time=None Rate { delivered: 0, delivered_time: Instant { tv_sec: 356, tv_nsec: 159831432 }, first_sent_time: Instant { tv_sec: 356, tv_nsec: 159831432 }, 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: 12000, used: 0, rate: 0, last_update: Instant { tv_sec: 356, tv_nsec: 905521479 }, next_time: Instant { tv_sec: 356, tv_nsec: 905521479 }, max_datagram_size: 1200, 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-30T18:04:59.613276405Z TRACE quiche_server] 7fc7e24eb3f657759e9761fc5b1e21a46205e5f2 written 1200 bytes with Some(SendInfo { from: [::]:443, to: [::ffff:193.167.0.100]:44801, at: Instant { tv_sec: 356, tv_nsec: 905521479 } })
[2025-04-30T18:04:59.613282737Z TRACE quiche_server] Collecting garbage
[2025-04-30T18:04:59.613287566Z TRACE quiche_server] recv() would block
[2025-04-30T18:04:59.613290742Z TRACE quiche_server] 7fc7e24eb3f657759e9761fc5b1e21a46205e5f2 done writing
[2025-04-30T18:04:59.613293076Z TRACE quiche_server] Collecting garbage
[2025-04-30T18:04:59.613998444Z TRACE quiche_server] got 1200 bytes from [::ffff:193.167.0.100]:44801 to [::]:443
[2025-04-30T18:04:59.614008733Z TRACE quiche_server] got packet Initial version=1 dcid=77cba19a51732421 scid=3d752cd322a203e9 token=
[2025-04-30T18:04:59.614015015Z TRACE quiche] 7fc7e24eb3f657759e9761fc5b1e21a46205e5f2 rx pkt Initial version=1 dcid=77cba19a51732421 scid=3d752cd322a203e9 token= len=1174 pn=2 
[2025-04-30T18:04:59.614020625Z TRACE quiche] 7fc7e24eb3f657759e9761fc5b1e21a46205e5f2 rx frm CRYPTO off=0 len=305
[2025-04-30T18:04:59.614027508Z TRACE quiche] 7fc7e24eb3f657759e9761fc5b1e21a46205e5f2 rx frm PADDING len=845
[2025-04-30T18:04:59.614036244Z TRACE quiche_server] 7fc7e24eb3f657759e9761fc5b1e21a46205e5f2 processed 1200 bytes
[2025-04-30T18:04:59.614040082Z TRACE quiche_server] recv() would block
[2025-04-30T18:04:59.614047906Z TRACE quiche] 7fc7e24eb3f657759e9761fc5b1e21a46205e5f2 tx pkt Initial version=1 dcid=3d752cd322a203e9 scid=7fc7e24eb3f657759e9761fc5b1e21a46205e5f2 len=5 pn=3 
[2025-04-30T18:04:59.614050631Z TRACE quiche] 7fc7e24eb3f657759e9761fc5b1e21a46205e5f2 tx frm ACK delay=4 blocks=[0..2] ecn_counts=None
[2025-04-30T18:04:59.614057504Z TRACE quiche::recovery::congestion::recovery] 7fc7e24eb3f657759e9761fc5b1e21a46205e5f2 timer=252.431212ms latest_rtt=0ns srtt=333ms min_rtt=333ms rttvar=166.5ms cwnd=12000 ssthresh=18446744073709551615 bytes_in_flight=941 app_limited=true congestion_recovery_start_time=None Rate { delivered: 0, delivered_time: Instant { tv_sec: 356, tv_nsec: 159831432 }, first_sent_time: Instant { tv_sec: 356, tv_nsec: 159831432 }, 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: 12000, used: 0, rate: 0, last_update: Instant { tv_sec: 356, tv_nsec: 906384531 }, next_time: Instant { tv_sec: 356, tv_nsec: 906384531 }, max_datagram_size: 1200, 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-30T18:04:59.614093922Z TRACE quiche_server] 7fc7e24eb3f657759e9761fc5b1e21a46205e5f2 written 1200 bytes with Some(SendInfo { from: [::]:443, to: [::ffff:193.167.0.100]:44801, at: Instant { tv_sec: 356, tv_nsec: 906384531 } })
[2025-04-30T18:04:59.614103830Z TRACE quiche_server] Collecting garbage
[2025-04-30T18:04:59.614107818Z TRACE quiche_server] recv() would block
[2025-04-30T18:04:59.614112266Z TRACE quiche_server] 7fc7e24eb3f657759e9761fc5b1e21a46205e5f2 done writing
[2025-04-30T18:04:59.614116013Z TRACE quiche_server] Collecting garbage
[2025-04-30T18:04:59.867426635Z TRACE quiche_server] timed out
[2025-04-30T18:04:59.867457723Z TRACE quiche] 7fc7e24eb3f657759e9761fc5b1e21a46205e5f2 loss detection timeout expired
[2025-04-30T18:04:59.867465377Z TRACE quiche::recovery::congestion::recovery] 7fc7e24eb3f657759e9761fc5b1e21a46205e5f2 timer=998.022558ms latest_rtt=0ns srtt=333ms min_rtt=333ms rttvar=166.5ms cwnd=12000 ssthresh=18446744073709551615 bytes_in_flight=941 app_limited=true congestion_recovery_start_time=None Rate { delivered: 0, delivered_time: Instant { tv_sec: 356, tv_nsec: 159831432 }, first_sent_time: Instant { tv_sec: 356, tv_nsec: 159831432 }, 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: 12000, used: 0, rate: 0, last_update: Instant { tv_sec: 356, tv_nsec: 906384531 }, next_time: Instant { tv_sec: 356, tv_nsec: 906384531 }, max_datagram_size: 1200, 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-30T18:04:59.867511934Z TRACE quiche] 7fc7e24eb3f657759e9761fc5b1e21a46205e5f2 tx pkt Initial version=1 dcid=3d752cd322a203e9 scid=7fc7e24eb3f657759e9761fc5b1e21a46205e5f2 len=135 pn=4 
[2025-04-30T18:04:59.867516563Z TRACE quiche] 7fc7e24eb3f657759e9761fc5b1e21a46205e5f2 tx frm ACK delay=31686 blocks=[0..2] ecn_counts=None
[2025-04-30T18:04:59.867522063Z TRACE quiche] 7fc7e24eb3f657759e9761fc5b1e21a46205e5f2 tx frm CRYPTO off=0 len=123
[2025-04-30T18:04:59.867540197Z TRACE quiche::recovery::congestion::recovery] 7fc7e24eb3f657759e9761fc5b1e21a46205e5f2 timer=997.948469ms latest_rtt=0ns srtt=333ms min_rtt=333ms rttvar=166.5ms cwnd=12000 ssthresh=18446744073709551615 bytes_in_flight=1131 app_limited=true congestion_recovery_start_time=None Rate { delivered: 0, delivered_time: Instant { tv_sec: 356, tv_nsec: 159831432 }, first_sent_time: Instant { tv_sec: 356, tv_nsec: 159831432 }, 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: 12000, used: 0, rate: 0, last_update: Instant { tv_sec: 357, tv_nsec: 159829192 }, next_time: Instant { tv_sec: 357, tv_nsec: 159829192 }, max_datagram_size: 1200, 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-30T18:04:59.867620367Z TRACE quiche_server] 7fc7e24eb3f657759e9761fc5b1e21a46205e5f2 written 1200 bytes with Some(SendInfo { from: [::]:443, to: [::ffff:193.167.0.100]:44801, at: Instant { tv_sec: 357, tv_nsec: 159829192 } })
[2025-04-30T18:04:59.867629664Z TRACE quiche_server] Collecting garbage
[2025-04-30T18:04:59.867639783Z TRACE quiche_server] recv() would block
[2025-04-30T18:04:59.867646405Z TRACE quiche_server] 7fc7e24eb3f657759e9761fc5b1e21a46205e5f2 done writing
[2025-04-30T18:04:59.867651184Z TRACE quiche_server] Collecting garbage
[2025-04-30T18:05:00.371474039Z TRACE quiche_server] got 96 bytes from [::ffff:193.167.0.100]:44801 to [::]:443
[2025-04-30T18:05:00.371507872Z TRACE quiche_server] got packet Handshake version=1 dcid=7fc7e24eb3f657759e9761fc5b1e21a46205e5f2 scid=3d752cd322a203e9
[2025-04-30T18:05:00.371523071Z TRACE quiche] 7fc7e24eb3f657759e9761fc5b1e21a46205e5f2 rx pkt Handshake version=1 dcid=7fc7e24eb3f657759e9761fc5b1e21a46205e5f2 scid=3d752cd322a203e9 len=59 pn=0 
[2025-04-30T18:05:00.371536155Z TRACE quiche] 7fc7e24eb3f657759e9761fc5b1e21a46205e5f2 rx frm CRYPTO off=0 len=36
[2025-04-30T18:05:00.371558487Z TRACE quiche::tls] 7fc7e24eb3f657759e9761fc5b1e21a46205e5f2 set read secret lvl=OneRTT
[2025-04-30T18:05:00.371599844Z TRACE quiche::tls] 7fc7e24eb3f657759e9761fc5b1e21a46205e5f2 write message lvl=OneRTT len=396
[2025-04-30T18:05:00.371612247Z TRACE quiche] 7fc7e24eb3f657759e9761fc5b1e21a46205e5f2 dropped epoch 1 state
[2025-04-30T18:05:00.371617016Z TRACE quiche] 7fc7e24eb3f657759e9761fc5b1e21a46205e5f2 connection established: proto=Ok("hq-interop") cipher=Some(AES128_GCM) curve=Some("P-256") sigalg=None resumed=false TransportParams { original_destination_connection_id: None, max_idle_timeout: 120000, stateless_reset_token: None, max_udp_payload_size: 1200, initial_max_data: 1048576, initial_max_stream_data_bidi_local: 16777216, initial_max_stream_data_bidi_remote: 16777216, initial_max_stream_data_uni: 16777216, initial_max_streams_bidi: 128, initial_max_streams_uni: 128, ack_delay_exponent: 3, max_ack_delay: 25, disable_active_migration: true, active_conn_id_limit: 8, initial_source_connection_id: Some(3d752cd322a203e9), retry_source_connection_id: None, max_datagram_frame_size: None, unknown_params: None }
[2025-04-30T18:05:00.371651541Z TRACE quiche] 7fc7e24eb3f657759e9761fc5b1e21a46205e5f2 dropped epoch 0 state
[2025-04-30T18:05:00.371655187Z TRACE quiche_server] 7fc7e24eb3f657759e9761fc5b1e21a46205e5f2 processed 96 bytes
[2025-04-30T18:05:00.371686205Z TRACE quiche_server] recv() would block
[2025-04-30T18:05:00.371697557Z TRACE quiche] 7fc7e24eb3f657759e9761fc5b1e21a46205e5f2 pmtud probe status false hs_con=true hs_sent=false cwnd_avail=12000 out_len=1200 left=1174
[2025-04-30T18:05:00.371708998Z TRACE quiche] 7fc7e24eb3f657759e9761fc5b1e21a46205e5f2 tx pkt Short dcid=3d752cd322a203e9 key_phase=false len=681 pn=5 
[2025-04-30T18:05:00.371712485Z TRACE quiche] 7fc7e24eb3f657759e9761fc5b1e21a46205e5f2 tx frm NEW_CONNECTION_ID seq_num=1 retire_prior_to=0 conn_id=[f7, 55, d5, 1b, 03, 88, 36, ed, 96, 2d, 8f, e4, 30, a6, d9, 82, 22, 0d, 81, ef] reset_token=[46, f8, 39, d2, 38, 01, 4c, 13, 90, d8, f2, d9, 82, cf, 09, 4c]
[2025-04-30T18:05:00.371722373Z TRACE quiche] 7fc7e24eb3f657759e9761fc5b1e21a46205e5f2 tx frm NEW_CONNECTION_ID seq_num=2 retire_prior_to=0 conn_id=[aa, 9b, 89, 22, 2d, 02, 6e, 72, 4e, e7, 1a, fd, 34, 60, 13, 6d, 09, 92, dd, 93] reset_token=[f1, be, 6e, f5, b1, 8f, 37, 5c, 39, 46, 7b, 78, 2c, 21, 91, 0a]
[2025-04-30T18:05:00.371730158Z TRACE quiche] 7fc7e24eb3f657759e9761fc5b1e21a46205e5f2 tx frm NEW_CONNECTION_ID seq_num=3 retire_prior_to=0 conn_id=[85, c0, 1a, 13, af, 9f, 71, 1d, 4d, 55, ad, 74, 15, a8, a5, 6e, 8f, 7d, 81, 13] reset_token=[14, 2b, ec, b6, 21, 9b, f9, 76, 0e, 57, 89, c1, 98, 5c, 8a, 0c]
[2025-04-30T18:05:00.371737672Z TRACE quiche] 7fc7e24eb3f657759e9761fc5b1e21a46205e5f2 tx frm NEW_CONNECTION_ID seq_num=4 retire_prior_to=0 conn_id=[7a, 60, 97, 0c, 21, 06, 2a, f4, 1f, f3, 1c, f9, 59, 0b, 04, 89, f0, 61, 32, c5] reset_token=[32, ce, df, c3, f2, 13, a7, 99, fc, fa, 2a, 2f, 84, bf, ef, 6e]
[2025-04-30T18:05:00.371745376Z TRACE quiche] 7fc7e24eb3f657759e9761fc5b1e21a46205e5f2 tx frm NEW_CONNECTION_ID seq_num=5 retire_prior_to=0 conn_id=[1b, 15, d1, 53, ff, b4, fd, ca, dd, 4a, b2, dc, 4d, 21, ac, a1, 82, c2, e4, e8] reset_token=[69, 6a, 5f, bb, be, 79, f2, 20, 59, 04, f5, 36, 98, 50, 43, 48]
[2025-04-30T18:05:00.371753040Z TRACE quiche] 7fc7e24eb3f657759e9761fc5b1e21a46205e5f2 tx frm NEW_CONNECTION_ID seq_num=6 retire_prior_to=0 conn_id=[05, 88, 20, c2, b8, be, a3, dc, d9, b2, 65, 81, f0, 4f, 75, c2, 73, b1, dd, 0a] reset_token=[5f, 1a, ca, 77, 66, 91, cb, ba, 63, 4a, 4e, 68, a3, 03, f8, 9a]
[2025-04-30T18:05:00.371766005Z TRACE quiche] 7fc7e24eb3f657759e9761fc5b1e21a46205e5f2 tx frm NEW_CONNECTION_ID seq_num=7 retire_prior_to=0 conn_id=[5e, b2, 7a, 7b, e1, 11, d2, 91, b8, 5a, 2b, f9, b8, 00, 52, 53, 81, 54, f4, 64] reset_token=[a2, ab, 87, 20, fc, 0d, 6f, ad, 6e, 84, 09, e1, d2, ae, 10, 25]
[2025-04-30T18:05:00.371773559Z TRACE quiche] 7fc7e24eb3f657759e9761fc5b1e21a46205e5f2 tx frm HANDSHAKE_DONE
[2025-04-30T18:05:00.371776414Z TRACE quiche] 7fc7e24eb3f657759e9761fc5b1e21a46205e5f2 tx frm CRYPTO off=0 len=396
[2025-04-30T18:05:00.371791873Z TRACE quiche::recovery::congestion::recovery] 7fc7e24eb3f657759e9761fc5b1e21a46205e5f2 timer=2.047899763s latest_rtt=0ns srtt=333ms min_rtt=333ms rttvar=166.5ms cwnd=12000 ssthresh=18446744073709551615 bytes_in_flight=707 app_limited=true congestion_recovery_start_time=None Rate { delivered: 0, delivered_time: Instant { tv_sec: 357, tv_nsec: 664034792 }, first_sent_time: Instant { tv_sec: 357, tv_nsec: 664034792 }, 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: 12000, used: 0, rate: 0, last_update: Instant { tv_sec: 357, tv_nsec: 664034792 }, next_time: Instant { tv_sec: 357, tv_nsec: 664034792 }, max_datagram_size: 1200, 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-30T18:05:00.371855792Z TRACE quiche_server] 7fc7e24eb3f657759e9761fc5b1e21a46205e5f2 written 707 bytes with Some(SendInfo { from: [::]:443, to: [::ffff:193.167.0.100]:44801, at: Instant { tv_sec: 357, tv_nsec: 664034792 } })
[2025-04-30T18:05:00.371862374Z TRACE quiche_server] Collecting garbage
[2025-04-30T18:05:00.371868776Z TRACE quiche_server] recv() would block
[2025-04-30T18:05:00.371874096Z TRACE quiche_server] 7fc7e24eb3f657759e9761fc5b1e21a46205e5f2 done writing
[2025-04-30T18:05:00.371879597Z TRACE quiche_server] Collecting garbage
[2025-04-30T18:05:00.372444041Z TRACE quiche_server] got 1200 bytes from [::ffff:193.167.0.100]:44801 to [::]:443
[2025-04-30T18:05:00.372454210Z TRACE quiche_server] got packet Initial version=1 dcid=7fc7e24eb3f657759e9761fc5b1e21a46205e5f2 scid=3d752cd322a203e9 token=
[2025-04-30T18:05:00.372464098Z TRACE quiche] 7fc7e24eb3f657759e9761fc5b1e21a46205e5f2 dropped invalid packet
[2025-04-30T18:05:00.372468657Z TRACE quiche_server] 7fc7e24eb3f657759e9761fc5b1e21a46205e5f2 processed 1200 bytes
[2025-04-30T18:05:00.372475840Z TRACE quiche_server] got 63 bytes from [::ffff:193.167.0.100]:44801 to [::]:443
[2025-04-30T18:05:00.372480749Z TRACE quiche_server] got packet Handshake version=1 dcid=7fc7e24eb3f657759e9761fc5b1e21a46205e5f2 scid=3d752cd322a203e9
[2025-04-30T18:05:00.372487793Z TRACE quiche] 7fc7e24eb3f657759e9761fc5b1e21a46205e5f2 dropped invalid packet
[2025-04-30T18:05:00.372491409Z TRACE quiche_server] 7fc7e24eb3f657759e9761fc5b1e21a46205e5f2 processed 63 bytes
[2025-04-30T18:05:00.372498252Z TRACE quiche_server] got 62 bytes from [::ffff:193.167.0.100]:44801 to [::]:443
[2025-04-30T18:05:00.372502109Z TRACE quiche_server] got packet Short dcid=7fc7e24eb3f657759e9761fc5b1e21a46205e5f2 key_phase=false
[2025-04-30T18:05:00.372506568Z TRACE quiche] 7fc7e24eb3f657759e9761fc5b1e21a46205e5f2 rx pkt Short dcid=7fc7e24eb3f657759e9761fc5b1e21a46205e5f2 key_phase=false len=41 pn=0 
[2025-04-30T18:05:00.372512869Z TRACE quiche] 7fc7e24eb3f657759e9761fc5b1e21a46205e5f2 rx frm STREAM id=0 off=0 len=17 fin=true
[2025-04-30T18:05:00.372521956Z TRACE quiche_server] 7fc7e24eb3f657759e9761fc5b1e21a46205e5f2 processed 62 bytes
[2025-04-30T18:05:00.372524742Z DEBUG quiche_apps::common] 7fc7e24eb3f657759e9761fc5b1e21a46205e5f2 response stream 0 is writable with capacity Ok(11293)
[2025-04-30T18:05:00.372536834Z TRACE quiche_apps::common] 7fc7e24eb3f657759e9761fc5b1e21a46205e5f2 received 17 bytes
[2025-04-30T18:05:00.372539559Z TRACE quiche_apps::common] 7fc7e24eb3f657759e9761fc5b1e21a46205e5f2 stream 0 has 17 bytes (fin? true)
[2025-04-30T18:05:00.372543998Z INFO  quiche_apps::common] 7fc7e24eb3f657759e9761fc5b1e21a46205e5f2 got GET request for "/www/vabkgdckut" on stream 0
[2025-04-30T18:05:00.372575877Z INFO  quiche_apps::common] 7fc7e24eb3f657759e9761fc5b1e21a46205e5f2 sending response of size 1024 on stream 0
[2025-04-30T18:05:00.372582078Z TRACE quiche_server] recv() would block
[2025-04-30T18:05:00.372588060Z TRACE quiche] 7fc7e24eb3f657759e9761fc5b1e21a46205e5f2 pmtud probe status false hs_con=true hs_sent=true cwnd_avail=11293 out_len=1200 left=1169
[2025-04-30T18:05:00.372592689Z TRACE quiche] 7fc7e24eb3f657759e9761fc5b1e21a46205e5f2 tx pkt Short dcid=3d752cd322a203e9 key_phase=false len=1034 pn=6 
[2025-04-30T18:05:00.372595313Z TRACE quiche] 7fc7e24eb3f657759e9761fc5b1e21a46205e5f2 tx frm ACK delay=10 blocks=[0..0] ecn_counts=None
[2025-04-30T18:05:00.372599281Z TRACE quiche] 7fc7e24eb3f657759e9761fc5b1e21a46205e5f2 tx frm STREAM id=0 off=0 len=1024 fin=true
[2025-04-30T18:05:00.372606925Z TRACE quiche::recovery::congestion::recovery] 7fc7e24eb3f657759e9761fc5b1e21a46205e5f2 timer=2.047977007s latest_rtt=0ns srtt=333ms min_rtt=333ms rttvar=166.5ms cwnd=12000 ssthresh=18446744073709551615 bytes_in_flight=1767 app_limited=true congestion_recovery_start_time=None Rate { delivered: 0, delivered_time: Instant { tv_sec: 357, tv_nsec: 664034792 }, first_sent_time: Instant { tv_sec: 357, tv_nsec: 664034792 }, 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: 12000, used: 0, rate: 0, last_update: Instant { tv_sec: 357, tv_nsec: 664926648 }, next_time: Instant { tv_sec: 357, tv_nsec: 664926648 }, max_datagram_size: 1200, 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-30T18:05:00.372649304Z TRACE quiche_server] 7fc7e24eb3f657759e9761fc5b1e21a46205e5f2 written 1060 bytes with Some(SendInfo { from: [::]:443, to: [::ffff:193.167.0.100]:44801, at: Instant { tv_sec: 357, tv_nsec: 664926648 } })
[2025-04-30T18:05:00.372655335Z TRACE quiche_server] Collecting garbage
[2025-04-30T18:05:00.372681735Z TRACE quiche_server] recv() would block
[2025-04-30T18:05:00.372691262Z TRACE quiche_server] 7fc7e24eb3f657759e9761fc5b1e21a46205e5f2 done writing
[2025-04-30T18:05:00.372694769Z TRACE quiche_server] Collecting garbage
[2025-04-30T18:05:01.873532158Z TRACE quiche_server] got 69 bytes from [::ffff:193.167.0.100]:44801 to [::]:443
[2025-04-30T18:05:01.873569448Z TRACE quiche_server] got packet Short dcid=7fc7e24eb3f657759e9761fc5b1e21a46205e5f2 key_phase=false
[2025-04-30T18:05:01.873584045Z TRACE quiche] 7fc7e24eb3f657759e9761fc5b1e21a46205e5f2 rx pkt Short dcid=7fc7e24eb3f657759e9761fc5b1e21a46205e5f2 key_phase=false len=48 pn=4 
[2025-04-30T18:05:01.873601688Z TRACE quiche] 7fc7e24eb3f657759e9761fc5b1e21a46205e5f2 rx frm NEW_CONNECTION_ID seq_num=1 retire_prior_to=0 conn_id=[ac, a5, d6, 14, a4, 7f, ef, 07] reset_token=[93, 3f, 62, d0, df, c6, 29, 42, 15, cc, ac, da, fa, 64, f8, 87]
[2025-04-30T18:05:01.873695994Z TRACE quiche_server] 7fc7e24eb3f657759e9761fc5b1e21a46205e5f2 processed 69 bytes
[2025-04-30T18:05:01.873709018Z TRACE quiche_server] got 69 bytes from [::ffff:193.167.0.100]:44801 to [::]:443
[2025-04-30T18:05:01.873713086Z TRACE quiche_server] got packet Short dcid=7fc7e24eb3f657759e9761fc5b1e21a46205e5f2 key_phase=false
[2025-04-30T18:05:01.873718827Z TRACE quiche] 7fc7e24eb3f657759e9761fc5b1e21a46205e5f2 rx pkt Short dcid=7fc7e24eb3f657759e9761fc5b1e21a46205e5f2 key_phase=false len=48 pn=5 
[2025-04-30T18:05:01.873731751Z TRACE quiche] 7fc7e24eb3f657759e9761fc5b1e21a46205e5f2 rx frm NEW_CONNECTION_ID seq_num=2 retire_prior_to=0 conn_id=[21, 6b, f7, 1f, 77, 64, 0c, a0] reset_token=[0d, ae, 94, a9, bb, 32, 1c, 27, ff, 62, eb, bb, 8e, c5, 0b, ff]
[2025-04-30T18:05:01.873741519Z TRACE quiche_server] 7fc7e24eb3f657759e9761fc5b1e21a46205e5f2 processed 69 bytes
[2025-04-30T18:05:01.873746468Z TRACE quiche_server] recv() would block
[2025-04-30T18:05:01.873755605Z TRACE quiche] 7fc7e24eb3f657759e9761fc5b1e21a46205e5f2 pmtud probe status false hs_con=true hs_sent=true cwnd_avail=10233 out_len=1200 left=1167
[2025-04-30T18:05:01.873761967Z TRACE quiche] 7fc7e24eb3f657759e9761fc5b1e21a46205e5f2 tx pkt Short dcid=3d752cd322a203e9 key_phase=false len=7 pn=7 
[2025-04-30T18:05:01.873765163Z TRACE quiche] 7fc7e24eb3f657759e9761fc5b1e21a46205e5f2 tx frm ACK delay=4 blocks=[0..0, 4..5] ecn_counts=None
[2025-04-30T18:05:01.873776284Z TRACE quiche::recovery::congestion::recovery] 7fc7e24eb3f657759e9761fc5b1e21a46205e5f2 timer=546.806816ms latest_rtt=0ns srtt=333ms min_rtt=333ms rttvar=166.5ms cwnd=12000 ssthresh=18446744073709551615 bytes_in_flight=1767 app_limited=true congestion_recovery_start_time=None Rate { delivered: 0, delivered_time: Instant { tv_sec: 357, tv_nsec: 664034792 }, first_sent_time: Instant { tv_sec: 357, tv_nsec: 664034792 }, 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: 12000, used: 0, rate: 0, last_update: Instant { tv_sec: 359, tv_nsec: 166091639 }, next_time: Instant { tv_sec: 359, tv_nsec: 166091639 }, max_datagram_size: 1200, 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-30T18:05:01.873843269Z TRACE quiche_server] 7fc7e24eb3f657759e9761fc5b1e21a46205e5f2 written 33 bytes with Some(SendInfo { from: [::]:443, to: [::ffff:193.167.0.100]:44801, at: Instant { tv_sec: 359, tv_nsec: 166091639 } })
[2025-04-30T18:05:01.873850182Z TRACE quiche_server] Collecting garbage
[2025-04-30T18:05:01.873856404Z TRACE quiche_server] recv() would block
[2025-04-30T18:05:01.873862244Z TRACE quiche_server] 7fc7e24eb3f657759e9761fc5b1e21a46205e5f2 done writing
[2025-04-30T18:05:01.873867384Z TRACE quiche_server] Collecting garbage
[2025-04-30T18:05:01.874233317Z TRACE quiche_server] got 46 bytes from [::ffff:193.167.0.100]:44801 to [::]:443
[2025-04-30T18:05:01.874241853Z TRACE quiche_server] got packet Short dcid=7fc7e24eb3f657759e9761fc5b1e21a46205e5f2 key_phase=false
[2025-04-30T18:05:01.874248216Z TRACE quiche] 7fc7e24eb3f657759e9761fc5b1e21a46205e5f2 rx pkt Short dcid=7fc7e24eb3f657759e9761fc5b1e21a46205e5f2 key_phase=false len=25 pn=6 
[2025-04-30T18:05:01.874254417Z TRACE quiche] 7fc7e24eb3f657759e9761fc5b1e21a46205e5f2 rx frm ACK delay=37 blocks=[5..6] ecn_counts=None
[2025-04-30T18:05:01.874258825Z TRACE quiche::recovery::congestion::recovery] 7fc7e24eb3f657759e9761fc5b1e21a46205e5f2 packet newly acked 5
[2025-04-30T18:05:01.874262352Z TRACE quiche::recovery::congestion::recovery] 7fc7e24eb3f657759e9761fc5b1e21a46205e5f2 packet newly acked 6
[2025-04-30T18:05:01.874280396Z TRACE quiche_server] 7fc7e24eb3f657759e9761fc5b1e21a46205e5f2 processed 46 bytes
[2025-04-30T18:05:01.874284934Z TRACE quiche_server] recv() would block
[2025-04-30T18:05:01.874287939Z TRACE quiche_server] 7fc7e24eb3f657759e9761fc5b1e21a46205e5f2 done writing
[2025-04-30T18:05:01.874290314Z TRACE quiche_server] Collecting garbage
[2025-04-30T18:05:13.276783345Z TRACE quiche_server] got 45 bytes from [::ffff:193.167.0.100]:44801 to [::]:443
[2025-04-30T18:05:13.276836735Z TRACE quiche_server] got packet Short dcid=7fc7e24eb3f657759e9761fc5b1e21a46205e5f2 key_phase=false
[2025-04-30T18:05:13.276851893Z TRACE quiche] 7fc7e24eb3f657759e9761fc5b1e21a46205e5f2 rx pkt Short dcid=7fc7e24eb3f657759e9761fc5b1e21a46205e5f2 key_phase=false len=24 pn=7 
[2025-04-30T18:05:13.276865308Z TRACE quiche] 7fc7e24eb3f657759e9761fc5b1e21a46205e5f2 rx frm CONNECTION_CLOSE err=0 frame=0 reason=[]
[2025-04-30T18:05:13.276883582Z TRACE quiche_server] 7fc7e24eb3f657759e9761fc5b1e21a46205e5f2 processed 45 bytes
[2025-04-30T18:05:13.276891607Z TRACE quiche_server] recv() would block
[2025-04-30T18:05:13.276894873Z TRACE quiche_server] 7fc7e24eb3f657759e9761fc5b1e21a46205e5f2 done writing
[2025-04-30T18:05:13.276898340Z TRACE quiche_server] Collecting garbage
[2025-04-30T18:05:26.804902320Z TRACE quiche_server] timed out
[2025-04-30T18:05:26.804944388Z TRACE quiche] 7fc7e24eb3f657759e9761fc5b1e21a46205e5f2 draining timeout expired
[2025-04-30T18:05:26.804988411Z TRACE quiche_server] 7fc7e24eb3f657759e9761fc5b1e21a46205e5f2 done writing
[2025-04-30T18:05:26.804993180Z TRACE quiche_server] Collecting garbage
[2025-04-30T18:05:26.805010712Z INFO  quiche_server] 7fc7e24eb3f657759e9761fc5b1e21a46205e5f2 connection collected recv=9 sent=8 lost=0 retrans=1 sent_bytes=3051 recv_bytes=3987 lost_bytes=0 [local_addr=[::]:443 peer_addr=[::ffff:193.167.0.100]:44801 validation_state=Validated active=true recv=9 sent=8 lost=0 retrans=1 rtt=1.501662801s min_rtt=Some(1.501662801s) rttvar=750.8314ms cwnd=12000 sent_bytes=3051 recv_bytes=3987 lost_bytes=0 stream_retrans_bytes=123 pmtu=1200 delivery_rate=1175]