[2025-04-30T10:31:07.621692197Z INFO  quiche_server] listening on [::]:443
[2025-04-30T10:31:07.621718005Z TRACE mio::poll] registering event source with poller: token=Token(0), interests=READABLE
[2025-04-30T10:31:07.621727012Z TRACE quiche_server] GSO detected: false
[2025-04-30T10:31:08.426113420Z TRACE quiche_server] got 1207 bytes from [::ffff:193.167.100.2]:41347 to [::]:443
[2025-04-30T10:31:08.426159405Z TRACE quiche_server] got packet Initial version=57414954 dcid= scid= token=
[2025-04-30T10:31:08.426167711Z WARN  quiche_server] Doing version negotiation
[2025-04-30T10:31:08.426256677Z TRACE quiche_server] got 1207 bytes from [::ffff:193.167.100.2]:41347 to [::]:443
[2025-04-30T10:31:08.426262858Z TRACE quiche_server] got packet Initial version=57414954 dcid= scid= token=
[2025-04-30T10:31:08.426266625Z WARN  quiche_server] Doing version negotiation
[2025-04-30T10:31:08.426287014Z TRACE quiche_server] got 1207 bytes from [::ffff:193.167.100.2]:41347 to [::]:443
[2025-04-30T10:31:08.426290951Z TRACE quiche_server] got packet Initial version=57414954 dcid= scid= token=
[2025-04-30T10:31:08.426294197Z WARN  quiche_server] Doing version negotiation
[2025-04-30T10:31:08.426309846Z TRACE quiche_server] recv() would block
[2025-04-30T10:31:08.683223017Z TRACE quiche_server] got 1280 bytes from [::ffff:193.167.0.100]:49943 to [::]:443
[2025-04-30T10:31:08.683257110Z TRACE quiche_server] got packet Initial version=1 dcid=a8189bee7c47ed6790cc6654886d scid= token=
[2025-04-30T10:31:08.683266708Z DEBUG quiche_server] New connection: dcid=a8189bee7c47ed6790cc6654886d scid=02ab03a7ea26757bdd727e79d1e52c6fda6d4f62
[2025-04-30T10:31:08.683491698Z TRACE quiche] 02ab03a7ea26757bdd727e79d1e52c6fda6d4f62 rx pkt Initial version=1 dcid=a8189bee7c47ed6790cc6654886d scid= token= len=1256 pn=0 
[2025-04-30T10:31:08.683508720Z TRACE quiche] 02ab03a7ea26757bdd727e79d1e52c6fda6d4f62 rx frm PADDING len=958
[2025-04-30T10:31:08.683513117Z TRACE quiche] 02ab03a7ea26757bdd727e79d1e52c6fda6d4f62 rx frm CRYPTO off=0 len=276
[2025-04-30T10:31:08.683542943Z TRACE quiche::tls] checking peer ALPN Ok("hq-interop") against Ok("h3")
[2025-04-30T10:31:08.683547792Z TRACE quiche::tls] checking peer ALPN Ok("hq-interop") against Ok("hq-interop")
[2025-04-30T10:31:08.683642128Z TRACE quiche::tls] 02ab03a7ea26757bdd727e79d1e52c6fda6d4f62 write message lvl=Initial len=90
[2025-04-30T10:31:08.683672014Z TRACE quiche::tls] 02ab03a7ea26757bdd727e79d1e52c6fda6d4f62 set write secret lvl=Handshake
[2025-04-30T10:31:08.683735993Z TRACE quiche::tls] 02ab03a7ea26757bdd727e79d1e52c6fda6d4f62 write message lvl=Handshake len=705
[2025-04-30T10:31:08.683738909Z TRACE quiche::tls] 02ab03a7ea26757bdd727e79d1e52c6fda6d4f62 set write secret lvl=OneRTT
[2025-04-30T10:31:08.683745110Z TRACE quiche::tls] 02ab03a7ea26757bdd727e79d1e52c6fda6d4f62 set read secret lvl=Handshake
[2025-04-30T10:31:08.683774946Z TRACE quiche_server] 02ab03a7ea26757bdd727e79d1e52c6fda6d4f62 processed 1280 bytes
[2025-04-30T10:31:08.683787299Z TRACE quiche_server] recv() would block
[2025-04-30T10:31:08.683798530Z TRACE quiche] 02ab03a7ea26757bdd727e79d1e52c6fda6d4f62 tx pkt Initial version=1 dcid= scid=02ab03a7ea26757bdd727e79d1e52c6fda6d4f62 len=99 pn=0 
[2025-04-30T10:31:08.683801946Z TRACE quiche] 02ab03a7ea26757bdd727e79d1e52c6fda6d4f62 tx frm ACK delay=40 blocks=[0..0] ecn_counts=None
[2025-04-30T10:31:08.683806324Z TRACE quiche] 02ab03a7ea26757bdd727e79d1e52c6fda6d4f62 tx frm CRYPTO off=0 len=90
[2025-04-30T10:31:08.683814991Z TRACE quiche::recovery::congestion::recovery] 02ab03a7ea26757bdd727e79d1e52c6fda6d4f62 timer=998.973922ms 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: 246, tv_nsec: 162844369 }, first_sent_time: Instant { tv_sec: 246, tv_nsec: 162844369 }, 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: 246, tv_nsec: 162844369 }, next_time: Instant { tv_sec: 246, tv_nsec: 162844369 }, 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:08.683842732Z TRACE quiche] 02ab03a7ea26757bdd727e79d1e52c6fda6d4f62 tx pkt Handshake version=1 dcid= scid=02ab03a7ea26757bdd727e79d1e52c6fda6d4f62 len=709 pn=1 
[2025-04-30T10:31:08.683845638Z TRACE quiche] 02ab03a7ea26757bdd727e79d1e52c6fda6d4f62 tx frm CRYPTO off=0 len=705
[2025-04-30T10:31:08.683851158Z TRACE quiche::recovery::congestion::recovery] 02ab03a7ea26757bdd727e79d1e52c6fda6d4f62 timer=998.938145ms latest_rtt=0ns srtt=333ms min_rtt=333ms rttvar=166.5ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=901 app_limited=true congestion_recovery_start_time=None Rate { delivered: 0, delivered_time: Instant { tv_sec: 246, tv_nsec: 162844369 }, first_sent_time: Instant { tv_sec: 246, tv_nsec: 162844369 }, 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: 246, tv_nsec: 162844369 }, next_time: Instant { tv_sec: 246, tv_nsec: 162844369 }, 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:08.683907122Z TRACE quiche_server] 02ab03a7ea26757bdd727e79d1e52c6fda6d4f62 written 1200 bytes with Some(SendInfo { from: [::]:443, to: [::ffff:193.167.0.100]:49943, at: Instant { tv_sec: 246, tv_nsec: 162844369 } })
[2025-04-30T10:31:08.683916770Z TRACE quiche_server] Collecting garbage
[2025-04-30T10:31:08.683923894Z TRACE quiche_server] recv() would block
[2025-04-30T10:31:08.683929334Z TRACE quiche_server] 02ab03a7ea26757bdd727e79d1e52c6fda6d4f62 done writing
[2025-04-30T10:31:08.683933221Z TRACE quiche_server] Collecting garbage
[2025-04-30T10:31:08.717384296Z TRACE quiche_server] got 1280 bytes from [::ffff:193.167.0.100]:49943 to [::]:443
[2025-04-30T10:31:08.717419391Z TRACE quiche_server] got packet Initial version=1 dcid=02ab03a7ea26757bdd727e79d1e52c6fda6d4f62 scid= token=
[2025-04-30T10:31:08.717434529Z TRACE quiche] 02ab03a7ea26757bdd727e79d1e52c6fda6d4f62 rx pkt Initial version=1 dcid=02ab03a7ea26757bdd727e79d1e52c6fda6d4f62 scid= token= len=1164 pn=1 
[2025-04-30T10:31:08.717448636Z TRACE quiche] 02ab03a7ea26757bdd727e79d1e52c6fda6d4f62 rx frm ACK delay=0 blocks=[0..0] ecn_counts=None
[2025-04-30T10:31:08.717456360Z TRACE quiche::recovery::congestion::recovery] 02ab03a7ea26757bdd727e79d1e52c6fda6d4f62 packet newly acked 0
[2025-04-30T10:31:08.717467471Z TRACE quiche] 02ab03a7ea26757bdd727e79d1e52c6fda6d4f62 rx frm PADDING len=1141
[2025-04-30T10:31:08.717492297Z TRACE quiche] 02ab03a7ea26757bdd727e79d1e52c6fda6d4f62 rx pkt Handshake version=1 dcid=02ab03a7ea26757bdd727e79d1e52c6fda6d4f62 scid= len=57 pn=0 
[2025-04-30T10:31:08.717498318Z TRACE quiche] 02ab03a7ea26757bdd727e79d1e52c6fda6d4f62 rx frm CRYPTO off=0 len=36
[2025-04-30T10:31:08.717518396Z TRACE quiche::tls] 02ab03a7ea26757bdd727e79d1e52c6fda6d4f62 set read secret lvl=OneRTT
[2025-04-30T10:31:08.717540968Z TRACE quiche] 02ab03a7ea26757bdd727e79d1e52c6fda6d4f62 dropped epoch 1 state
[2025-04-30T10:31:08.717545626Z TRACE quiche] 02ab03a7ea26757bdd727e79d1e52c6fda6d4f62 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:08.717579289Z TRACE quiche] 02ab03a7ea26757bdd727e79d1e52c6fda6d4f62 dropped epoch 0 state
[2025-04-30T10:31:08.717583046Z TRACE quiche_server] 02ab03a7ea26757bdd727e79d1e52c6fda6d4f62 processed 1280 bytes
[2025-04-30T10:31:08.717593355Z TRACE quiche_server] got 52 bytes from [::ffff:193.167.0.100]:49943 to [::]:443
[2025-04-30T10:31:08.717597513Z TRACE quiche_server] got packet Handshake version=1 dcid=02ab03a7ea26757bdd727e79d1e52c6fda6d4f62 scid=
[2025-04-30T10:31:08.717603024Z TRACE quiche] 02ab03a7ea26757bdd727e79d1e52c6fda6d4f62 dropped invalid packet
[2025-04-30T10:31:08.717606190Z TRACE quiche_server] 02ab03a7ea26757bdd727e79d1e52c6fda6d4f62 processed 52 bytes
[2025-04-30T10:31:08.717611339Z TRACE quiche_server] got 58 bytes from [::ffff:193.167.0.100]:49943 to [::]:443
[2025-04-30T10:31:08.717614856Z TRACE quiche_server] got packet Short dcid=02ab03a7ea26757bdd727e79d1e52c6fda6d4f62 key_phase=false
[2025-04-30T10:31:08.717619775Z TRACE quiche] 02ab03a7ea26757bdd727e79d1e52c6fda6d4f62 rx pkt Short dcid=02ab03a7ea26757bdd727e79d1e52c6fda6d4f62 key_phase=false len=37 pn=0 
[2025-04-30T10:31:08.717625586Z TRACE quiche] 02ab03a7ea26757bdd727e79d1e52c6fda6d4f62 rx frm STREAM id=0 off=0 len=17 fin=true
[2025-04-30T10:31:08.717633340Z TRACE quiche_server] 02ab03a7ea26757bdd727e79d1e52c6fda6d4f62 processed 58 bytes
[2025-04-30T10:31:08.717637037Z DEBUG quiche_apps::common] 02ab03a7ea26757bdd727e79d1e52c6fda6d4f62 response stream 0 is writable with capacity Ok(13500)
[2025-04-30T10:31:08.717643990Z TRACE quiche_apps::common] 02ab03a7ea26757bdd727e79d1e52c6fda6d4f62 received 17 bytes
[2025-04-30T10:31:08.717647126Z TRACE quiche_apps::common] 02ab03a7ea26757bdd727e79d1e52c6fda6d4f62 stream 0 has 17 bytes (fin? true)
[2025-04-30T10:31:08.717652175Z INFO  quiche_apps::common] 02ab03a7ea26757bdd727e79d1e52c6fda6d4f62 got GET request for "/www/mmjkvyvugl" on stream 0
[2025-04-30T10:31:08.717686599Z INFO  quiche_apps::common] 02ab03a7ea26757bdd727e79d1e52c6fda6d4f62 sending response of size 1024 on stream 0
[2025-04-30T10:31:08.717694735Z TRACE quiche_server] recv() would block
[2025-04-30T10:31:08.717703551Z TRACE quiche] 02ab03a7ea26757bdd727e79d1e52c6fda6d4f62 pmtud probe status false hs_con=true hs_sent=false cwnd_avail=13500 out_len=1350 left=1327
[2025-04-30T10:31:08.717713219Z TRACE quiche] 02ab03a7ea26757bdd727e79d1e52c6fda6d4f62 tx pkt Short dcid= key_phase=false len=1155 pn=2 
[2025-04-30T10:31:08.717716615Z TRACE quiche] 02ab03a7ea26757bdd727e79d1e52c6fda6d4f62 tx frm ACK delay=10 blocks=[0..0] ecn_counts=None
[2025-04-30T10:31:08.717720533Z TRACE quiche] 02ab03a7ea26757bdd727e79d1e52c6fda6d4f62 tx frm NEW_CONNECTION_ID seq_num=1 retire_prior_to=0 conn_id=[86, 3e, 18, a1, 37, 6e, 6c, 36, fa, 1c, db, 97, 22, fe, 15, 4e, 7e, d0, 3c, a4] reset_token=[4a, c8, 16, ab, 4a, 35, 13, fd, e4, a2, e1, 8b, d9, 8f, 01, f5]
[2025-04-30T10:31:08.717729479Z TRACE quiche] 02ab03a7ea26757bdd727e79d1e52c6fda6d4f62 tx frm NEW_CONNECTION_ID seq_num=2 retire_prior_to=0 conn_id=[4a, 4c, 26, 35, 0e, 2d, 34, a0, cb, be, 4f, 3a, 61, 51, 8d, d8, 05, 55, e6, 17] reset_token=[41, cb, 52, 9b, e2, 34, 20, e9, f2, 30, 07, 1a, 61, 93, 91, c9]
[2025-04-30T10:31:08.717737374Z TRACE quiche] 02ab03a7ea26757bdd727e79d1e52c6fda6d4f62 tx frm NEW_CONNECTION_ID seq_num=3 retire_prior_to=0 conn_id=[f2, 83, 81, 64, 08, c5, 97, 4f, 5c, 35, 33, 1c, 0b, ec, 88, 1e, a3, ae, d7, 35] reset_token=[86, 59, 12, 93, 7f, 25, 99, 91, 62, a1, cc, 8d, e9, 7c, 4d, 8a]
[2025-04-30T10:31:08.717749707Z TRACE quiche] 02ab03a7ea26757bdd727e79d1e52c6fda6d4f62 tx frm HANDSHAKE_DONE
[2025-04-30T10:31:08.717752652Z TRACE quiche] 02ab03a7ea26757bdd727e79d1e52c6fda6d4f62 tx frm STREAM id=0 off=0 len=1024 fin=true
[2025-04-30T10:31:08.717765647Z TRACE quiche::recovery::congestion::recovery] 02ab03a7ea26757bdd727e79d1e52c6fda6d4f62 timer=126.854386ms latest_rtt=33.640938ms srtt=33.640938ms min_rtt=33.640938ms rttvar=16.820469ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=1173 app_limited=true congestion_recovery_start_time=None Rate { delivered: 146, delivered_time: Instant { tv_sec: 246, tv_nsec: 196752595 }, first_sent_time: Instant { tv_sec: 246, tv_nsec: 196752595 }, end_of_app_limited: 1, last_sent_packet: 2, largest_acked: 0, rate_sample: RateSample { delivery_rate: 4339, is_app_limited: true, interval: 33.640938ms, delivered: 146, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 246, tv_nsec: 162844369 }), send_elapsed: 0ns, ack_elapsed: 33.640938ms, rtt: 33.640938ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 501620, last_update: Instant { tv_sec: 246, tv_nsec: 196752595 }, next_time: Instant { tv_sec: 246, tv_nsec: 196752595 }, 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:08.717832291Z TRACE quiche_server] 02ab03a7ea26757bdd727e79d1e52c6fda6d4f62 written 1173 bytes with Some(SendInfo { from: [::]:443, to: [::ffff:193.167.0.100]:49943, at: Instant { tv_sec: 246, tv_nsec: 196752595 } })
[2025-04-30T10:31:08.717840657Z TRACE quiche_server] Collecting garbage
[2025-04-30T10:31:08.717847089Z TRACE quiche_server] recv() would block
[2025-04-30T10:31:08.717851998Z TRACE quiche_server] 02ab03a7ea26757bdd727e79d1e52c6fda6d4f62 done writing
[2025-04-30T10:31:08.717855635Z TRACE quiche_server] Collecting garbage
[2025-04-30T10:31:08.749570025Z TRACE quiche_server] got 46 bytes from [::ffff:193.167.0.100]:49943 to [::]:443
[2025-04-30T10:31:08.749605191Z TRACE quiche_server] got packet Short dcid=863e18a1376e6c36fa1cdb9722fe154e7ed03ca4 key_phase=false
[2025-04-30T10:31:08.749619277Z TRACE quiche] 02ab03a7ea26757bdd727e79d1e52c6fda6d4f62 rx pkt Short dcid=863e18a1376e6c36fa1cdb9722fe154e7ed03ca4 key_phase=false len=25 pn=1 
[2025-04-30T10:31:08.749628514Z TRACE quiche] 02ab03a7ea26757bdd727e79d1e52c6fda6d4f62 path ID 0 now see SCID with seq num 1
[2025-04-30T10:31:08.749635367Z TRACE quiche] 02ab03a7ea26757bdd727e79d1e52c6fda6d4f62 rx frm ACK delay=26 blocks=[2..2] ecn_counts=None
[2025-04-30T10:31:08.749641589Z TRACE quiche::recovery::congestion::recovery] 02ab03a7ea26757bdd727e79d1e52c6fda6d4f62 packet newly acked 2
[2025-04-30T10:31:08.749647340Z TRACE quiche] 02ab03a7ea26757bdd727e79d1e52c6fda6d4f62 rx frm RETIRE_CONNECTION_ID seq_num=0
[2025-04-30T10:31:08.749671615Z TRACE quiche_server] 02ab03a7ea26757bdd727e79d1e52c6fda6d4f62 processed 46 bytes
[2025-04-30T10:31:08.749676133Z INFO  quiche_server] Retiring source CID 02ab03a7ea26757bdd727e79d1e52c6fda6d4f62
[2025-04-30T10:31:08.749685832Z TRACE quiche_server] got 42 bytes from [::ffff:193.167.0.100]:49943 to [::]:443
[2025-04-30T10:31:08.749689058Z TRACE quiche_server] got packet Short dcid=863e18a1376e6c36fa1cdb9722fe154e7ed03ca4 key_phase=false
[2025-04-30T10:31:08.749694257Z TRACE quiche] 02ab03a7ea26757bdd727e79d1e52c6fda6d4f62 rx pkt Short dcid=863e18a1376e6c36fa1cdb9722fe154e7ed03ca4 key_phase=false len=21 pn=2 
[2025-04-30T10:31:08.749701851Z TRACE quiche] 02ab03a7ea26757bdd727e79d1e52c6fda6d4f62 rx frm APPLICATION_CLOSE err=0 reason=[]
[2025-04-30T10:31:08.749710718Z TRACE quiche_server] 02ab03a7ea26757bdd727e79d1e52c6fda6d4f62 processed 42 bytes
[2025-04-30T10:31:08.749716819Z TRACE quiche_server] recv() would block
[2025-04-30T10:31:08.749728842Z TRACE quiche_server] 02ab03a7ea26757bdd727e79d1e52c6fda6d4f62 done writing
[2025-04-30T10:31:08.749731597Z TRACE quiche_server] Collecting garbage
[2025-04-30T10:31:09.007044945Z TRACE quiche_server] timed out
[2025-04-30T10:31:09.007082976Z TRACE quiche] 02ab03a7ea26757bdd727e79d1e52c6fda6d4f62 draining timeout expired
[2025-04-30T10:31:09.007158517Z TRACE quiche_server] 02ab03a7ea26757bdd727e79d1e52c6fda6d4f62 done writing
[2025-04-30T10:31:09.007164448Z TRACE quiche_server] Collecting garbage
[2025-04-30T10:31:09.007169928Z INFO  quiche_server] 02ab03a7ea26757bdd727e79d1e52c6fda6d4f62 connection collected recv=6 sent=3 lost=0 retrans=0 sent_bytes=2074 recv_bytes=2706 lost_bytes=0 [local_addr=[::]:443 peer_addr=[::ffff:193.167.0.100]:49943 validation_state=Validated active=true recv=6 sent=3 lost=0 retrans=0 rtt=33.425576ms min_rtt=Some(31.918051ms) rttvar=13.046072ms cwnd=13500 sent_bytes=2074 recv_bytes=2706 lost_bytes=0 stream_retrans_bytes=0 pmtu=1350 delivery_rate=36750]