[2025-04-30T11:32:41.273599258Z INFO  quiche_server] listening on [::]:443
[2025-04-30T11:32:41.273620879Z TRACE mio::poll] registering event source with poller: token=Token(0), interests=READABLE
[2025-04-30T11:32:41.273626930Z TRACE quiche_server] GSO detected: false
[2025-04-30T11:32:42.096537168Z TRACE quiche_server] got 1207 bytes from [::ffff:193.167.100.2]:41363 to [::]:443
[2025-04-30T11:32:42.096563177Z TRACE quiche_server] got packet Initial version=57414954 dcid= scid= token=
[2025-04-30T11:32:42.096570410Z WARN  quiche_server] Doing version negotiation
[2025-04-30T11:32:42.096654968Z TRACE quiche_server] got 1207 bytes from [::ffff:193.167.100.2]:41363 to [::]:443
[2025-04-30T11:32:42.096664646Z TRACE quiche_server] got packet Initial version=57414954 dcid= scid= token=
[2025-04-30T11:32:42.096670778Z WARN  quiche_server] Doing version negotiation
[2025-04-30T11:32:42.096702276Z TRACE quiche_server] got 1207 bytes from [::ffff:193.167.100.2]:41363 to [::]:443
[2025-04-30T11:32:42.096709811Z TRACE quiche_server] got packet Initial version=57414954 dcid= scid= token=
[2025-04-30T11:32:42.096715271Z WARN  quiche_server] Doing version negotiation
[2025-04-30T11:32:42.096748082Z TRACE quiche_server] recv() would block
[2025-04-30T11:32:42.505754224Z TRACE quiche_server] got 1200 bytes from [fd00:cafe:cafe::100]:49850 to [::]:443
[2025-04-30T11:32:42.505774973Z TRACE quiche_server] got packet Initial version=1 dcid=a77a2b1a5996763d scid=3c1dd5d7c9df779f token=
[2025-04-30T11:32:42.505782377Z DEBUG quiche_server] New connection: dcid=a77a2b1a5996763d scid=665d4afdb3c764ad25632e4fdc2aa92f89630f01
[2025-04-30T11:32:42.505969275Z TRACE quiche] 665d4afdb3c764ad25632e4fdc2aa92f89630f01 rx pkt Initial version=1 dcid=a77a2b1a5996763d scid=3c1dd5d7c9df779f token= len=504 pn=0 
[2025-04-30T11:32:42.505983753Z TRACE quiche] 665d4afdb3c764ad25632e4fdc2aa92f89630f01 rx frm CRYPTO off=0 len=482
[2025-04-30T11:32:42.506008769Z TRACE quiche::tls] checking peer ALPN Ok("hq-interop") against Ok("h3")
[2025-04-30T11:32:42.506012897Z TRACE quiche::tls] checking peer ALPN Ok("hq-interop") against Ok("hq-interop")
[2025-04-30T11:32:42.506110760Z TRACE quiche::tls] 665d4afdb3c764ad25632e4fdc2aa92f89630f01 write message lvl=Initial len=123
[2025-04-30T11:32:42.506137670Z TRACE quiche::tls] 665d4afdb3c764ad25632e4fdc2aa92f89630f01 set write secret lvl=Handshake
[2025-04-30T11:32:42.506197321Z TRACE quiche::tls] 665d4afdb3c764ad25632e4fdc2aa92f89630f01 write message lvl=Handshake len=714
[2025-04-30T11:32:42.506200227Z TRACE quiche::tls] 665d4afdb3c764ad25632e4fdc2aa92f89630f01 set write secret lvl=OneRTT
[2025-04-30T11:32:42.506207691Z TRACE quiche::tls] 665d4afdb3c764ad25632e4fdc2aa92f89630f01 set read secret lvl=Handshake
[2025-04-30T11:32:42.506236825Z TRACE quiche] 665d4afdb3c764ad25632e4fdc2aa92f89630f01 dropped invalid packet
[2025-04-30T11:32:42.506239911Z TRACE quiche_server] 665d4afdb3c764ad25632e4fdc2aa92f89630f01 processed 1200 bytes
[2025-04-30T11:32:42.506256772Z TRACE quiche_server] recv() would block
[2025-04-30T11:32:42.506267312Z TRACE quiche] 665d4afdb3c764ad25632e4fdc2aa92f89630f01 tx pkt Initial version=1 dcid=3c1dd5d7c9df779f scid=665d4afdb3c764ad25632e4fdc2aa92f89630f01 len=132 pn=0 
[2025-04-30T11:32:42.506270818Z TRACE quiche] 665d4afdb3c764ad25632e4fdc2aa92f89630f01 tx frm ACK delay=39 blocks=[0..0] ecn_counts=None
[2025-04-30T11:32:42.506275357Z TRACE quiche] 665d4afdb3c764ad25632e4fdc2aa92f89630f01 tx frm CRYPTO off=0 len=123
[2025-04-30T11:32:42.506284154Z TRACE quiche::recovery::congestion::recovery] 665d4afdb3c764ad25632e4fdc2aa92f89630f01 timer=998.974242ms latest_rtt=0ns srtt=333ms min_rtt=333ms rttvar=166.5ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=187 app_limited=true congestion_recovery_start_time=None Rate { delivered: 0, delivered_time: Instant { tv_sec: 789, tv_nsec: 535847673 }, first_sent_time: Instant { tv_sec: 789, tv_nsec: 535847673 }, 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: 789, tv_nsec: 535847673 }, next_time: Instant { tv_sec: 789, tv_nsec: 535847673 }, 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:32:42.506310202Z TRACE quiche] 665d4afdb3c764ad25632e4fdc2aa92f89630f01 tx pkt Handshake version=1 dcid=3c1dd5d7c9df779f scid=665d4afdb3c764ad25632e4fdc2aa92f89630f01 len=718 pn=1 
[2025-04-30T11:32:42.506313088Z TRACE quiche] 665d4afdb3c764ad25632e4fdc2aa92f89630f01 tx frm CRYPTO off=0 len=714
[2025-04-30T11:32:42.506318588Z TRACE quiche::recovery::congestion::recovery] 665d4afdb3c764ad25632e4fdc2aa92f89630f01 timer=998.940119ms latest_rtt=0ns srtt=333ms min_rtt=333ms rttvar=166.5ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=959 app_limited=true congestion_recovery_start_time=None Rate { delivered: 0, delivered_time: Instant { tv_sec: 789, tv_nsec: 535847673 }, first_sent_time: Instant { tv_sec: 789, tv_nsec: 535847673 }, 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: 789, tv_nsec: 535847673 }, next_time: Instant { tv_sec: 789, tv_nsec: 535847673 }, 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:32:42.506356839Z TRACE quiche_server] 665d4afdb3c764ad25632e4fdc2aa92f89630f01 written 1200 bytes with Some(SendInfo { from: [::]:443, to: [fd00:cafe:cafe::100]:49850, at: Instant { tv_sec: 789, tv_nsec: 535847673 } })
[2025-04-30T11:32:42.506365996Z TRACE quiche_server] Collecting garbage
[2025-04-30T11:32:42.506372539Z TRACE quiche_server] recv() would block
[2025-04-30T11:32:42.506378339Z TRACE quiche_server] 665d4afdb3c764ad25632e4fdc2aa92f89630f01 done writing
[2025-04-30T11:32:42.506382327Z TRACE quiche_server] Collecting garbage
[2025-04-30T11:32:42.540992028Z TRACE quiche_server] got 1200 bytes from [fd00:cafe:cafe::100]:49850 to [::]:443
[2025-04-30T11:32:42.541006124Z TRACE quiche_server] got packet Initial version=1 dcid=665d4afdb3c764ad25632e4fdc2aa92f89630f01 scid=3c1dd5d7c9df779f token=
[2025-04-30T11:32:42.541015010Z TRACE quiche] 665d4afdb3c764ad25632e4fdc2aa92f89630f01 rx pkt Initial version=1 dcid=665d4afdb3c764ad25632e4fdc2aa92f89630f01 scid=3c1dd5d7c9df779f token= len=24 pn=1 
[2025-04-30T11:32:42.541022945Z TRACE quiche] 665d4afdb3c764ad25632e4fdc2aa92f89630f01 rx frm ACK delay=251 blocks=[0..0] ecn_counts=None
[2025-04-30T11:32:42.541028125Z TRACE quiche::recovery::congestion::recovery] 665d4afdb3c764ad25632e4fdc2aa92f89630f01 packet newly acked 0
[2025-04-30T11:32:42.541045628Z TRACE quiche] 665d4afdb3c764ad25632e4fdc2aa92f89630f01 rx pkt Handshake version=1 dcid=665d4afdb3c764ad25632e4fdc2aa92f89630f01 scid=3c1dd5d7c9df779f len=80 pn=2 
[2025-04-30T11:32:42.541051448Z TRACE quiche] 665d4afdb3c764ad25632e4fdc2aa92f89630f01 rx frm ACK delay=251 blocks=[1..1] ecn_counts=None
[2025-04-30T11:32:42.541054925Z TRACE quiche::recovery::congestion::recovery] 665d4afdb3c764ad25632e4fdc2aa92f89630f01 packet newly acked 1
[2025-04-30T11:32:42.541058792Z TRACE quiche] 665d4afdb3c764ad25632e4fdc2aa92f89630f01 rx frm CRYPTO off=0 len=52
[2025-04-30T11:32:42.541072197Z TRACE quiche::tls] 665d4afdb3c764ad25632e4fdc2aa92f89630f01 set read secret lvl=OneRTT
[2025-04-30T11:32:42.541115638Z TRACE quiche::tls] 665d4afdb3c764ad25632e4fdc2aa92f89630f01 write message lvl=OneRTT len=428
[2025-04-30T11:32:42.541123573Z TRACE quiche] 665d4afdb3c764ad25632e4fdc2aa92f89630f01 dropped epoch 1 state
[2025-04-30T11:32:42.541127681Z TRACE quiche] 665d4afdb3c764ad25632e4fdc2aa92f89630f01 connection established: proto=Ok("hq-interop") cipher=Some(AES256_GCM) curve=Some("P-256") sigalg=None resumed=false TransportParams { original_destination_connection_id: None, max_idle_timeout: 60000, stateless_reset_token: None, max_udp_payload_size: 65527, initial_max_data: 262144, initial_max_stream_data_bidi_local: 262144, initial_max_stream_data_bidi_remote: 262144, initial_max_stream_data_uni: 262144, initial_max_streams_bidi: 128, initial_max_streams_uni: 128, ack_delay_exponent: 3, max_ack_delay: 25, disable_active_migration: false, active_conn_id_limit: 8, initial_source_connection_id: Some(3c1dd5d7c9df779f), retry_source_connection_id: None, max_datagram_frame_size: None, unknown_params: None }
[2025-04-30T11:32:42.541148389Z TRACE quiche] 665d4afdb3c764ad25632e4fdc2aa92f89630f01 dropped epoch 0 state
[2025-04-30T11:32:42.541152136Z TRACE quiche] 665d4afdb3c764ad25632e4fdc2aa92f89630f01 rx pkt Short dcid=665d4afdb3c764ad25632e4fdc2aa92f89630f01 key_phase=false len=1000 pn=3 
[2025-04-30T11:32:42.541159350Z TRACE quiche] 665d4afdb3c764ad25632e4fdc2aa92f89630f01 rx frm NEW_CONNECTION_ID seq_num=1 retire_prior_to=0 conn_id=[ba, e9, a3, b4, d1, 2a, 2a, 00] reset_token=[3a, 2e, 69, fc, 8a, ed, 5e, 13, a4, 86, 98, 0d, 85, 4e, 75, 29]
[2025-04-30T11:32:42.541167455Z TRACE quiche] 665d4afdb3c764ad25632e4fdc2aa92f89630f01 rx frm NEW_CONNECTION_ID seq_num=2 retire_prior_to=0 conn_id=[82, c0, 1f, f8, 61, 17, d9, 37] reset_token=[9f, f8, 51, a8, 2f, a9, 06, 06, c3, 01, 13, 52, 79, 99, 6b, 5c]
[2025-04-30T11:32:42.541173466Z TRACE quiche] 665d4afdb3c764ad25632e4fdc2aa92f89630f01 rx frm NEW_CONNECTION_ID seq_num=3 retire_prior_to=0 conn_id=[21, e9, b8, 26, c0, 49, ab, 75] reset_token=[06, 46, b6, f4, 4b, 86, 89, 36, 01, d2, 6d, 98, 4b, 49, 69, c2]
[2025-04-30T11:32:42.541179026Z TRACE quiche] 665d4afdb3c764ad25632e4fdc2aa92f89630f01 rx frm NEW_CONNECTION_ID seq_num=4 retire_prior_to=0 conn_id=[39, 28, 8f, 80, 3d, 72, 98, 51] reset_token=[b4, 36, ca, 16, 4c, b7, c8, af, ef, 6b, e3, 6d, 4b, 94, e7, ed]
[2025-04-30T11:32:42.541185248Z TRACE quiche] 665d4afdb3c764ad25632e4fdc2aa92f89630f01 rx frm NEW_CONNECTION_ID seq_num=5 retire_prior_to=0 conn_id=[3c, 3b, 40, 0e, 9d, 82, a2, 7a] reset_token=[a7, 7d, 2e, 86, 5d, 54, c8, 4b, 90, 33, ab, 02, 03, 29, e6, e1]
[2025-04-30T11:32:42.541191089Z TRACE quiche] 665d4afdb3c764ad25632e4fdc2aa92f89630f01 rx frm NEW_CONNECTION_ID seq_num=6 retire_prior_to=0 conn_id=[f9, a1, 18, 48, 00, fa, 18, 62] reset_token=[72, d5, cc, 49, 22, 11, 18, 72, 00, a8, 8e, b3, 41, 06, 96, fc]
[2025-04-30T11:32:42.541196920Z TRACE quiche] 665d4afdb3c764ad25632e4fdc2aa92f89630f01 rx frm NEW_CONNECTION_ID seq_num=7 retire_prior_to=0 conn_id=[65, 4d, cc, 47, da, 3a, fe, 04] reset_token=[d7, 3c, ba, de, 39, 71, 5e, 49, 2d, 6a, 76, bd, 3f, ea, 87, a4]
[2025-04-30T11:32:42.541204284Z TRACE quiche] 665d4afdb3c764ad25632e4fdc2aa92f89630f01 rx frm PADDING len=786
[2025-04-30T11:32:42.541214062Z TRACE quiche_server] 665d4afdb3c764ad25632e4fdc2aa92f89630f01 processed 1200 bytes
[2025-04-30T11:32:42.541228148Z TRACE quiche_server] got 60 bytes from [fd00:cafe:cafe::100]:49850 to [::]:443
[2025-04-30T11:32:42.541232226Z TRACE quiche_server] got packet Short dcid=665d4afdb3c764ad25632e4fdc2aa92f89630f01 key_phase=false
[2025-04-30T11:32:42.541237185Z TRACE quiche] 665d4afdb3c764ad25632e4fdc2aa92f89630f01 rx pkt Short dcid=665d4afdb3c764ad25632e4fdc2aa92f89630f01 key_phase=false len=39 pn=4 
[2025-04-30T11:32:42.541242064Z TRACE quiche] 665d4afdb3c764ad25632e4fdc2aa92f89630f01 rx frm STREAM id=0 off=0 len=17 fin=true
[2025-04-30T11:32:42.541249458Z TRACE quiche_server] 665d4afdb3c764ad25632e4fdc2aa92f89630f01 processed 60 bytes
[2025-04-30T11:32:42.541252754Z DEBUG quiche_apps::common] 665d4afdb3c764ad25632e4fdc2aa92f89630f01 response stream 0 is writable with capacity Ok(13500)
[2025-04-30T11:32:42.541264045Z TRACE quiche_apps::common] 665d4afdb3c764ad25632e4fdc2aa92f89630f01 received 17 bytes
[2025-04-30T11:32:42.541267241Z TRACE quiche_apps::common] 665d4afdb3c764ad25632e4fdc2aa92f89630f01 stream 0 has 17 bytes (fin? true)
[2025-04-30T11:32:42.541271930Z INFO  quiche_apps::common] 665d4afdb3c764ad25632e4fdc2aa92f89630f01 got GET request for "/www/ykyststlcg" on stream 0
[2025-04-30T11:32:42.541295073Z INFO  quiche_apps::common] 665d4afdb3c764ad25632e4fdc2aa92f89630f01 sending response of size 5120 on stream 0
[2025-04-30T11:32:42.541304561Z TRACE quiche_server] got 60 bytes from [fd00:cafe:cafe::100]:49850 to [::]:443
[2025-04-30T11:32:42.541308388Z TRACE quiche_server] got packet Short dcid=665d4afdb3c764ad25632e4fdc2aa92f89630f01 key_phase=false
[2025-04-30T11:32:42.541313267Z TRACE quiche] 665d4afdb3c764ad25632e4fdc2aa92f89630f01 rx pkt Short dcid=665d4afdb3c764ad25632e4fdc2aa92f89630f01 key_phase=false len=39 pn=5 
[2025-04-30T11:32:42.541318326Z TRACE quiche] 665d4afdb3c764ad25632e4fdc2aa92f89630f01 rx frm STREAM id=4 off=0 len=17 fin=true
[2025-04-30T11:32:42.541324568Z TRACE quiche_server] 665d4afdb3c764ad25632e4fdc2aa92f89630f01 processed 60 bytes
[2025-04-30T11:32:42.541327594Z DEBUG quiche_apps::common] 665d4afdb3c764ad25632e4fdc2aa92f89630f01 response stream 4 is writable with capacity Ok(13500)
[2025-04-30T11:32:42.541332032Z TRACE quiche_apps::common] 665d4afdb3c764ad25632e4fdc2aa92f89630f01 received 17 bytes
[2025-04-30T11:32:42.541334827Z TRACE quiche_apps::common] 665d4afdb3c764ad25632e4fdc2aa92f89630f01 stream 4 has 17 bytes (fin? true)
[2025-04-30T11:32:42.541338143Z INFO  quiche_apps::common] 665d4afdb3c764ad25632e4fdc2aa92f89630f01 got GET request for "/www/sdxscmvqib" on stream 4
[2025-04-30T11:32:42.541354334Z INFO  quiche_apps::common] 665d4afdb3c764ad25632e4fdc2aa92f89630f01 sending response of size 10240 on stream 4
[2025-04-30T11:32:42.541361818Z TRACE quiche_server] recv() would block
[2025-04-30T11:32:42.541376936Z TRACE quiche] 665d4afdb3c764ad25632e4fdc2aa92f89630f01 pmtud probe status false hs_con=true hs_sent=false cwnd_avail=13500 out_len=1350 left=1319
[2025-04-30T11:32:42.541386814Z TRACE quiche] 665d4afdb3c764ad25632e4fdc2aa92f89630f01 tx pkt Short dcid=3c1dd5d7c9df779f key_phase=false len=1324 pn=2 
[2025-04-30T11:32:42.541390451Z TRACE quiche] 665d4afdb3c764ad25632e4fdc2aa92f89630f01 tx frm ACK delay=7 blocks=[3..5] ecn_counts=None
[2025-04-30T11:32:42.541394339Z TRACE quiche] 665d4afdb3c764ad25632e4fdc2aa92f89630f01 tx frm NEW_CONNECTION_ID seq_num=1 retire_prior_to=0 conn_id=[15, e8, 7f, eb, 13, 8a, 4a, 08, 5b, 44, 67, 6a, 74, 50, 38, bb, 3d, 1f, f6, 23] reset_token=[2a, f9, 9a, 01, df, b5, bf, bf, e4, 6b, 0b, 30, 6d, b5, 8b, fc]
[2025-04-30T11:32:42.541401582Z TRACE quiche] 665d4afdb3c764ad25632e4fdc2aa92f89630f01 tx frm NEW_CONNECTION_ID seq_num=2 retire_prior_to=0 conn_id=[e1, 6f, a6, d0, 92, ac, a1, be, 47, 0c, 54, 80, 41, cd, 35, e5, f2, 05, bf, f1] reset_token=[42, a4, a4, 3d, 82, d2, 97, b4, 2d, 5e, 94, e4, d9, 4c, 5f, d6]
[2025-04-30T11:32:42.541408014Z TRACE quiche] 665d4afdb3c764ad25632e4fdc2aa92f89630f01 tx frm NEW_CONNECTION_ID seq_num=3 retire_prior_to=0 conn_id=[50, 31, 91, f9, 97, 8a, 22, 7f, 54, dd, 87, 9a, 0e, 45, 15, 71, 3a, 5c, 8d, 64] reset_token=[5f, cf, 9c, 38, 0e, 4b, 1a, 20, 75, b1, eb, 43, d9, 96, dd, 5a]
[2025-04-30T11:32:42.541439884Z TRACE quiche] 665d4afdb3c764ad25632e4fdc2aa92f89630f01 tx frm NEW_CONNECTION_ID seq_num=4 retire_prior_to=0 conn_id=[78, 7a, 8f, a2, 10, 5d, 62, 59, 0e, ff, e6, 58, 11, d9, 2c, ee, 43, 42, 22, 7d] reset_token=[53, 9f, bc, 49, 28, 19, 73, dc, 6c, 9f, 69, 7d, e0, 6b, f5, 48]
[2025-04-30T11:32:42.541449351Z TRACE quiche] 665d4afdb3c764ad25632e4fdc2aa92f89630f01 tx frm NEW_CONNECTION_ID seq_num=5 retire_prior_to=0 conn_id=[a8, 0f, bd, 24, 5c, 44, 9d, a7, 7b, c7, 01, 27, 90, aa, ff, c7, f3, ae, 4c, 6b] reset_token=[ee, d0, 14, 95, c4, a0, 69, 10, 91, 9c, 55, 9b, d5, 90, d7, 40]
[2025-04-30T11:32:42.541458468Z TRACE quiche] 665d4afdb3c764ad25632e4fdc2aa92f89630f01 tx frm NEW_CONNECTION_ID seq_num=6 retire_prior_to=0 conn_id=[81, c4, 13, 62, 03, 55, 40, e7, 8f, db, 25, c9, 03, 41, 52, b9, 3b, f1, 27, 42] reset_token=[7a, f6, 37, 40, 33, 8c, c5, 47, 92, 4d, 7a, 03, 04, 9b, 7c, 74]
[2025-04-30T11:32:42.541463497Z TRACE quiche] 665d4afdb3c764ad25632e4fdc2aa92f89630f01 tx frm NEW_CONNECTION_ID seq_num=7 retire_prior_to=0 conn_id=[1f, 56, ce, b0, d1, e5, 83, c1, b1, f2, 61, 47, fe, 78, ca, dc, 0c, ea, 53, 36] reset_token=[dc, 42, f0, a3, 54, 5a, e5, 33, d1, 75, 97, 99, eb, 96, 62, 07]
[2025-04-30T11:32:42.541468357Z TRACE quiche] 665d4afdb3c764ad25632e4fdc2aa92f89630f01 tx frm HANDSHAKE_DONE
[2025-04-30T11:32:42.541470641Z TRACE quiche] 665d4afdb3c764ad25632e4fdc2aa92f89630f01 tx frm CRYPTO off=0 len=428
[2025-04-30T11:32:42.541472995Z TRACE quiche] 665d4afdb3c764ad25632e4fdc2aa92f89630f01 tx frm STREAM id=0 off=0 len=601 fin=false
[2025-04-30T11:32:42.541499565Z TRACE quiche::recovery::congestion::recovery] 665d4afdb3c764ad25632e4fdc2aa92f89630f01 timer=111.785523ms latest_rtt=34.785949ms srtt=34.75794ms min_rtt=34.75394ms rttvar=13.040729ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=1350 app_limited=true congestion_recovery_start_time=None Rate { delivered: 959, delivered_time: Instant { tv_sec: 789, tv_nsec: 570953339 }, first_sent_time: Instant { tv_sec: 789, tv_nsec: 570953339 }, end_of_app_limited: 1, last_sent_packet: 2, largest_acked: 1, rate_sample: RateSample { delivery_rate: 27593, is_app_limited: true, interval: 34.75394ms, delivered: 959, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 789, tv_nsec: 535847673 }), send_elapsed: 0ns, ack_elapsed: 34.75394ms, rtt: 34.75394ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 485500, last_update: Instant { tv_sec: 789, tv_nsec: 570953339 }, next_time: Instant { tv_sec: 789, tv_nsec: 570953339 }, 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:32:42.541515164Z TRACE quiche] 665d4afdb3c764ad25632e4fdc2aa92f89630f01 pmtud probe status false hs_con=true hs_sent=true cwnd_avail=12150 out_len=1350 left=1324
[2025-04-30T11:32:42.541519101Z TRACE quiche] 665d4afdb3c764ad25632e4fdc2aa92f89630f01 tx pkt Short dcid=3c1dd5d7c9df779f key_phase=false len=1324 pn=3 
[2025-04-30T11:32:42.541521656Z TRACE quiche] 665d4afdb3c764ad25632e4fdc2aa92f89630f01 tx frm STREAM id=4 off=0 len=1319 fin=false
[2025-04-30T11:32:42.541526906Z TRACE quiche::recovery::congestion::recovery] 665d4afdb3c764ad25632e4fdc2aa92f89630f01 timer=111.90683ms latest_rtt=34.785949ms srtt=34.75794ms min_rtt=34.75394ms rttvar=13.040729ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=2700 app_limited=true congestion_recovery_start_time=None Rate { delivered: 959, delivered_time: Instant { tv_sec: 789, tv_nsec: 570953339 }, first_sent_time: Instant { tv_sec: 789, tv_nsec: 570953339 }, end_of_app_limited: 1, last_sent_packet: 3, largest_acked: 1, rate_sample: RateSample { delivery_rate: 27593, is_app_limited: true, interval: 34.75394ms, delivered: 959, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 789, tv_nsec: 535847673 }), send_elapsed: 0ns, ack_elapsed: 34.75394ms, rtt: 34.75394ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 485500, last_update: Instant { tv_sec: 789, tv_nsec: 570953339 }, next_time: Instant { tv_sec: 789, tv_nsec: 570953339 }, 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:32:42.541540291Z TRACE quiche] 665d4afdb3c764ad25632e4fdc2aa92f89630f01 pmtud probe status false hs_con=true hs_sent=true cwnd_avail=10800 out_len=1350 left=1324
[2025-04-30T11:32:42.541543587Z TRACE quiche] 665d4afdb3c764ad25632e4fdc2aa92f89630f01 tx pkt Short dcid=3c1dd5d7c9df779f key_phase=false len=1324 pn=4 
[2025-04-30T11:32:42.541545982Z TRACE quiche] 665d4afdb3c764ad25632e4fdc2aa92f89630f01 tx frm STREAM id=0 off=601 len=1318 fin=false
[2025-04-30T11:32:42.541550480Z TRACE quiche::recovery::congestion::recovery] 665d4afdb3c764ad25632e4fdc2aa92f89630f01 timer=111.909294ms latest_rtt=34.785949ms srtt=34.75794ms min_rtt=34.75394ms rttvar=13.040729ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=4050 app_limited=true congestion_recovery_start_time=None Rate { delivered: 959, delivered_time: Instant { tv_sec: 789, tv_nsec: 570953339 }, first_sent_time: Instant { tv_sec: 789, tv_nsec: 570953339 }, end_of_app_limited: 1, last_sent_packet: 4, largest_acked: 1, rate_sample: RateSample { delivery_rate: 27593, is_app_limited: true, interval: 34.75394ms, delivered: 959, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 789, tv_nsec: 535847673 }), send_elapsed: 0ns, ack_elapsed: 34.75394ms, rtt: 34.75394ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 485500, last_update: Instant { tv_sec: 789, tv_nsec: 570953339 }, next_time: Instant { tv_sec: 789, tv_nsec: 570953339 }, 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:32:42.541559767Z TRACE quiche] 665d4afdb3c764ad25632e4fdc2aa92f89630f01 pmtud probe status false hs_con=true hs_sent=true cwnd_avail=9450 out_len=1350 left=1324
[2025-04-30T11:32:42.541562803Z TRACE quiche] 665d4afdb3c764ad25632e4fdc2aa92f89630f01 tx pkt Short dcid=3c1dd5d7c9df779f key_phase=false len=1324 pn=5 
[2025-04-30T11:32:42.541565147Z TRACE quiche] 665d4afdb3c764ad25632e4fdc2aa92f89630f01 tx frm STREAM id=4 off=1319 len=1318 fin=false
[2025-04-30T11:32:42.541569405Z TRACE quiche::recovery::congestion::recovery] 665d4afdb3c764ad25632e4fdc2aa92f89630f01 timer=111.910016ms latest_rtt=34.785949ms srtt=34.75794ms min_rtt=34.75394ms rttvar=13.040729ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=5400 app_limited=true congestion_recovery_start_time=None Rate { delivered: 959, delivered_time: Instant { tv_sec: 789, tv_nsec: 570953339 }, first_sent_time: Instant { tv_sec: 789, tv_nsec: 570953339 }, end_of_app_limited: 1, last_sent_packet: 5, largest_acked: 1, rate_sample: RateSample { delivery_rate: 27593, is_app_limited: true, interval: 34.75394ms, delivered: 959, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 789, tv_nsec: 535847673 }), send_elapsed: 0ns, ack_elapsed: 34.75394ms, rtt: 34.75394ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 485500, last_update: Instant { tv_sec: 789, tv_nsec: 570953339 }, next_time: Instant { tv_sec: 789, tv_nsec: 570953339 }, 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:32:42.541578322Z TRACE quiche] 665d4afdb3c764ad25632e4fdc2aa92f89630f01 pmtud probe status false hs_con=true hs_sent=true cwnd_avail=8100 out_len=1350 left=1324
[2025-04-30T11:32:42.541581167Z TRACE quiche] 665d4afdb3c764ad25632e4fdc2aa92f89630f01 tx pkt Short dcid=3c1dd5d7c9df779f key_phase=false len=1324 pn=6 
[2025-04-30T11:32:42.541583441Z TRACE quiche] 665d4afdb3c764ad25632e4fdc2aa92f89630f01 tx frm STREAM id=0 off=1919 len=1318 fin=false
[2025-04-30T11:32:42.541588100Z TRACE quiche::recovery::congestion::recovery] 665d4afdb3c764ad25632e4fdc2aa92f89630f01 timer=111.910076ms latest_rtt=34.785949ms srtt=34.75794ms min_rtt=34.75394ms rttvar=13.040729ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=6750 app_limited=true congestion_recovery_start_time=None Rate { delivered: 959, delivered_time: Instant { tv_sec: 789, tv_nsec: 570953339 }, first_sent_time: Instant { tv_sec: 789, tv_nsec: 570953339 }, end_of_app_limited: 1, last_sent_packet: 6, largest_acked: 1, rate_sample: RateSample { delivery_rate: 27593, is_app_limited: true, interval: 34.75394ms, delivered: 959, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 789, tv_nsec: 535847673 }), send_elapsed: 0ns, ack_elapsed: 34.75394ms, rtt: 34.75394ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 485500, last_update: Instant { tv_sec: 789, tv_nsec: 570953339 }, next_time: Instant { tv_sec: 789, tv_nsec: 570953339 }, 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:32:42.541599892Z TRACE quiche] 665d4afdb3c764ad25632e4fdc2aa92f89630f01 pmtud probe status false hs_con=true hs_sent=true cwnd_avail=6750 out_len=1350 left=1324
[2025-04-30T11:32:42.541602858Z TRACE quiche] 665d4afdb3c764ad25632e4fdc2aa92f89630f01 tx pkt Short dcid=3c1dd5d7c9df779f key_phase=false len=1324 pn=7 
[2025-04-30T11:32:42.541605192Z TRACE quiche] 665d4afdb3c764ad25632e4fdc2aa92f89630f01 tx frm STREAM id=4 off=2637 len=1318 fin=false
[2025-04-30T11:32:42.541609540Z TRACE quiche::recovery::congestion::recovery] 665d4afdb3c764ad25632e4fdc2aa92f89630f01 timer=111.910026ms latest_rtt=34.785949ms srtt=34.75794ms min_rtt=34.75394ms rttvar=13.040729ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=8100 app_limited=true congestion_recovery_start_time=None Rate { delivered: 959, delivered_time: Instant { tv_sec: 789, tv_nsec: 570953339 }, first_sent_time: Instant { tv_sec: 789, tv_nsec: 570953339 }, end_of_app_limited: 1, last_sent_packet: 7, largest_acked: 1, rate_sample: RateSample { delivery_rate: 27593, is_app_limited: true, interval: 34.75394ms, delivered: 959, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 789, tv_nsec: 535847673 }), send_elapsed: 0ns, ack_elapsed: 34.75394ms, rtt: 34.75394ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 485500, last_update: Instant { tv_sec: 789, tv_nsec: 570953339 }, next_time: Instant { tv_sec: 789, tv_nsec: 570953339 }, 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:32:42.541618537Z TRACE quiche] 665d4afdb3c764ad25632e4fdc2aa92f89630f01 pmtud probe status false hs_con=true hs_sent=true cwnd_avail=5400 out_len=1350 left=1324
[2025-04-30T11:32:42.541621422Z TRACE quiche] 665d4afdb3c764ad25632e4fdc2aa92f89630f01 tx pkt Short dcid=3c1dd5d7c9df779f key_phase=false len=1324 pn=8 
[2025-04-30T11:32:42.541623727Z TRACE quiche] 665d4afdb3c764ad25632e4fdc2aa92f89630f01 tx frm STREAM id=0 off=3237 len=1318 fin=false
[2025-04-30T11:32:42.541627904Z TRACE quiche::recovery::congestion::recovery] 665d4afdb3c764ad25632e4fdc2aa92f89630f01 timer=111.910366ms latest_rtt=34.785949ms srtt=34.75794ms min_rtt=34.75394ms rttvar=13.040729ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=9450 app_limited=true congestion_recovery_start_time=None Rate { delivered: 959, delivered_time: Instant { tv_sec: 789, tv_nsec: 570953339 }, first_sent_time: Instant { tv_sec: 789, tv_nsec: 570953339 }, end_of_app_limited: 1, last_sent_packet: 8, largest_acked: 1, rate_sample: RateSample { delivery_rate: 27593, is_app_limited: true, interval: 34.75394ms, delivered: 959, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 789, tv_nsec: 535847673 }), send_elapsed: 0ns, ack_elapsed: 34.75394ms, rtt: 34.75394ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 485500, last_update: Instant { tv_sec: 789, tv_nsec: 570953339 }, next_time: Instant { tv_sec: 789, tv_nsec: 570953339 }, 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:32:42.541639396Z TRACE quiche] 665d4afdb3c764ad25632e4fdc2aa92f89630f01 pmtud probe status false hs_con=true hs_sent=true cwnd_avail=4050 out_len=1350 left=1324
[2025-04-30T11:32:42.541642241Z TRACE quiche] 665d4afdb3c764ad25632e4fdc2aa92f89630f01 tx pkt Short dcid=3c1dd5d7c9df779f key_phase=false len=1324 pn=9 
[2025-04-30T11:32:42.541644546Z TRACE quiche] 665d4afdb3c764ad25632e4fdc2aa92f89630f01 tx frm STREAM id=4 off=3955 len=1318 fin=false
[2025-04-30T11:32:42.541648794Z TRACE quiche::recovery::congestion::recovery] 665d4afdb3c764ad25632e4fdc2aa92f89630f01 timer=111.910376ms latest_rtt=34.785949ms srtt=34.75794ms min_rtt=34.75394ms rttvar=13.040729ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=10800 app_limited=true congestion_recovery_start_time=None Rate { delivered: 959, delivered_time: Instant { tv_sec: 789, tv_nsec: 570953339 }, first_sent_time: Instant { tv_sec: 789, tv_nsec: 570953339 }, end_of_app_limited: 1, last_sent_packet: 9, largest_acked: 1, rate_sample: RateSample { delivery_rate: 27593, is_app_limited: true, interval: 34.75394ms, delivered: 959, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 789, tv_nsec: 535847673 }), send_elapsed: 0ns, ack_elapsed: 34.75394ms, rtt: 34.75394ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 485500, last_update: Instant { tv_sec: 789, tv_nsec: 570953339 }, next_time: Instant { tv_sec: 789, tv_nsec: 570953339 }, 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:32:42.541657710Z TRACE quiche] 665d4afdb3c764ad25632e4fdc2aa92f89630f01 pmtud probe status false hs_con=true hs_sent=true cwnd_avail=2700 out_len=1350 left=1324
[2025-04-30T11:32:42.541660505Z TRACE quiche] 665d4afdb3c764ad25632e4fdc2aa92f89630f01 tx pkt Short dcid=3c1dd5d7c9df779f key_phase=false len=571 pn=10 
[2025-04-30T11:32:42.541662830Z TRACE quiche] 665d4afdb3c764ad25632e4fdc2aa92f89630f01 tx frm STREAM id=0 off=4555 len=565 fin=true
[2025-04-30T11:32:42.541667518Z TRACE quiche::recovery::congestion::recovery] 665d4afdb3c764ad25632e4fdc2aa92f89630f01 timer=111.909886ms latest_rtt=34.785949ms srtt=34.75794ms min_rtt=34.75394ms rttvar=13.040729ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=11397 app_limited=true congestion_recovery_start_time=None Rate { delivered: 959, delivered_time: Instant { tv_sec: 789, tv_nsec: 570953339 }, first_sent_time: Instant { tv_sec: 789, tv_nsec: 570953339 }, end_of_app_limited: 1, last_sent_packet: 10, largest_acked: 1, rate_sample: RateSample { delivery_rate: 27593, is_app_limited: true, interval: 34.75394ms, delivered: 959, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 789, tv_nsec: 535847673 }), send_elapsed: 0ns, ack_elapsed: 34.75394ms, rtt: 34.75394ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 485500, last_update: Instant { tv_sec: 789, tv_nsec: 570953339 }, next_time: Instant { tv_sec: 789, tv_nsec: 570953339 }, 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:32:42.541788204Z TRACE quiche_server] 665d4afdb3c764ad25632e4fdc2aa92f89630f01 written 11397 bytes with Some(SendInfo { from: [::]:443, to: [fd00:cafe:cafe::100]:49850, at: Instant { tv_sec: 789, tv_nsec: 570953339 } })
[2025-04-30T11:32:42.541798774Z TRACE quiche_server] Collecting garbage
[2025-04-30T11:32:42.541805186Z TRACE quiche_server] recv() would block
[2025-04-30T11:32:42.541811858Z TRACE quiche] 665d4afdb3c764ad25632e4fdc2aa92f89630f01 pmtud probe status false hs_con=true hs_sent=true cwnd_avail=2103 out_len=1350 left=1324
[2025-04-30T11:32:42.541818370Z TRACE quiche] 665d4afdb3c764ad25632e4fdc2aa92f89630f01 tx pkt Short dcid=3c1dd5d7c9df779f key_phase=false len=1324 pn=11 
[2025-04-30T11:32:42.541822528Z TRACE quiche] 665d4afdb3c764ad25632e4fdc2aa92f89630f01 tx frm STREAM id=4 off=5273 len=1318 fin=false
[2025-04-30T11:32:42.541829721Z TRACE quiche::recovery::congestion::recovery] 665d4afdb3c764ad25632e4fdc2aa92f89630f01 timer=111.899156ms latest_rtt=34.785949ms srtt=34.75794ms min_rtt=34.75394ms rttvar=13.040729ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=12747 app_limited=true congestion_recovery_start_time=None Rate { delivered: 959, delivered_time: Instant { tv_sec: 789, tv_nsec: 570953339 }, first_sent_time: Instant { tv_sec: 789, tv_nsec: 570953339 }, end_of_app_limited: 1, last_sent_packet: 11, largest_acked: 1, rate_sample: RateSample { delivery_rate: 27593, is_app_limited: true, interval: 34.75394ms, delivered: 959, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 789, tv_nsec: 535847673 }), send_elapsed: 0ns, ack_elapsed: 34.75394ms, rtt: 34.75394ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 485500, last_update: Instant { tv_sec: 789, tv_nsec: 570953339 }, next_time: Instant { tv_sec: 789, tv_nsec: 570953339 }, 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:32:42.541841563Z TRACE quiche] 665d4afdb3c764ad25632e4fdc2aa92f89630f01 pmtud probe status false hs_con=true hs_sent=true cwnd_avail=753 out_len=1350 left=727
[2025-04-30T11:32:42.541844709Z TRACE quiche] 665d4afdb3c764ad25632e4fdc2aa92f89630f01 tx pkt Short dcid=3c1dd5d7c9df779f key_phase=false len=727 pn=12 
[2025-04-30T11:32:42.541847144Z TRACE quiche] 665d4afdb3c764ad25632e4fdc2aa92f89630f01 tx frm STREAM id=4 off=6591 len=721 fin=false
[2025-04-30T11:32:42.541851512Z TRACE quiche::recovery::congestion::recovery] 665d4afdb3c764ad25632e4fdc2aa92f89630f01 timer=111.909394ms latest_rtt=34.785949ms srtt=34.75794ms min_rtt=34.75394ms rttvar=13.040729ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=13500 app_limited=false congestion_recovery_start_time=None Rate { delivered: 959, delivered_time: Instant { tv_sec: 789, tv_nsec: 570953339 }, first_sent_time: Instant { tv_sec: 789, tv_nsec: 570953339 }, end_of_app_limited: 1, last_sent_packet: 12, largest_acked: 1, rate_sample: RateSample { delivery_rate: 27593, is_app_limited: true, interval: 34.75394ms, delivered: 959, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 789, tv_nsec: 535847673 }), send_elapsed: 0ns, ack_elapsed: 34.75394ms, rtt: 34.75394ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 485500, last_update: Instant { tv_sec: 789, tv_nsec: 570953339 }, next_time: Instant { tv_sec: 789, tv_nsec: 570953339 }, 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:32:42.541894051Z TRACE quiche_server] 665d4afdb3c764ad25632e4fdc2aa92f89630f01 written 2103 bytes with Some(SendInfo { from: [::]:443, to: [fd00:cafe:cafe::100]:49850, at: Instant { tv_sec: 789, tv_nsec: 570953339 } })
[2025-04-30T11:32:42.541902267Z TRACE quiche_server] Collecting garbage
[2025-04-30T11:32:42.541907577Z TRACE quiche_server] recv() would block
[2025-04-30T11:32:42.541913437Z TRACE quiche] 665d4afdb3c764ad25632e4fdc2aa92f89630f01 pmtud probe status false hs_con=true hs_sent=true cwnd_avail=0 out_len=1350 left=0
[2025-04-30T11:32:42.541918868Z TRACE quiche_server] 665d4afdb3c764ad25632e4fdc2aa92f89630f01 done writing
[2025-04-30T11:32:42.541922004Z TRACE quiche_server] Collecting garbage
[2025-04-30T11:32:42.574433346Z TRACE quiche_server] got 44 bytes from [fd00:cafe:cafe::100]:49850 to [::]:443
[2025-04-30T11:32:42.574446822Z TRACE quiche_server] got packet Short dcid=665d4afdb3c764ad25632e4fdc2aa92f89630f01 key_phase=false
[2025-04-30T11:32:42.574454496Z TRACE quiche] 665d4afdb3c764ad25632e4fdc2aa92f89630f01 rx pkt Short dcid=665d4afdb3c764ad25632e4fdc2aa92f89630f01 key_phase=false len=23 pn=6 
[2025-04-30T11:32:42.574462280Z TRACE quiche] 665d4afdb3c764ad25632e4fdc2aa92f89630f01 rx frm ACK delay=7 blocks=[2..3] ecn_counts=None
[2025-04-30T11:32:42.574467130Z TRACE quiche::recovery::congestion::recovery] 665d4afdb3c764ad25632e4fdc2aa92f89630f01 packet newly acked 2
[2025-04-30T11:32:42.574471528Z TRACE quiche::recovery::congestion::recovery] 665d4afdb3c764ad25632e4fdc2aa92f89630f01 packet newly acked 3
[2025-04-30T11:32:42.574486947Z TRACE quiche_server] 665d4afdb3c764ad25632e4fdc2aa92f89630f01 processed 44 bytes
[2025-04-30T11:32:42.574491605Z TRACE quiche_server] recv() would block
[2025-04-30T11:32:42.574496454Z TRACE quiche] 665d4afdb3c764ad25632e4fdc2aa92f89630f01 pmtud probe status false hs_con=true hs_sent=true cwnd_avail=5400 out_len=1350 left=1324
[2025-04-30T11:32:42.574501003Z TRACE quiche] 665d4afdb3c764ad25632e4fdc2aa92f89630f01 tx pkt Short dcid=3c1dd5d7c9df779f key_phase=false len=1324 pn=13 
[2025-04-30T11:32:42.574503598Z TRACE quiche] 665d4afdb3c764ad25632e4fdc2aa92f89630f01 tx frm STREAM id=4 off=7312 len=1318 fin=false
[2025-04-30T11:32:42.574510310Z TRACE quiche::recovery::congestion::recovery] 665d4afdb3c764ad25632e4fdc2aa92f89630f01 timer=100.323956ms latest_rtt=33.088551ms srtt=34.549265ms min_rtt=33.088551ms rttvar=10.197893ms cwnd=16200 ssthresh=18446744073709551615 bytes_in_flight=12150 app_limited=true congestion_recovery_start_time=None Rate { delivered: 3659, delivered_time: Instant { tv_sec: 789, tv_nsec: 604041890 }, first_sent_time: Instant { tv_sec: 789, tv_nsec: 570953339 }, end_of_app_limited: 0, last_sent_packet: 13, largest_acked: 3, rate_sample: RateSample { delivery_rate: 81599, is_app_limited: true, interval: 33.088551ms, delivered: 2700, prior_delivered: 959, prior_time: Some(Instant { tv_sec: 789, tv_nsec: 570953339 }), send_elapsed: 0ns, ack_elapsed: 33.088551ms, rtt: 33.088551ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 586119, last_update: Instant { tv_sec: 789, tv_nsec: 604082426 }, next_time: Instant { tv_sec: 789, tv_nsec: 604082426 }, max_datagram_size: 1350, last_packet_size: Some(0), iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(13) last_round_min_rtt=33.088551ms 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:32:42.574523795Z TRACE quiche] 665d4afdb3c764ad25632e4fdc2aa92f89630f01 pmtud probe status false hs_con=true hs_sent=true cwnd_avail=4050 out_len=1350 left=1324
[2025-04-30T11:32:42.574527041Z TRACE quiche] 665d4afdb3c764ad25632e4fdc2aa92f89630f01 tx pkt Short dcid=3c1dd5d7c9df779f key_phase=false len=1324 pn=14 
[2025-04-30T11:32:42.574529496Z TRACE quiche] 665d4afdb3c764ad25632e4fdc2aa92f89630f01 tx frm STREAM id=4 off=8630 len=1318 fin=false
[2025-04-30T11:32:42.574539525Z TRACE quiche::recovery::congestion::recovery] 665d4afdb3c764ad25632e4fdc2aa92f89630f01 timer=100.323554ms latest_rtt=33.088551ms srtt=34.549265ms min_rtt=33.088551ms rttvar=10.197893ms cwnd=16200 ssthresh=18446744073709551615 bytes_in_flight=13500 app_limited=true congestion_recovery_start_time=None Rate { delivered: 3659, delivered_time: Instant { tv_sec: 789, tv_nsec: 604041890 }, first_sent_time: Instant { tv_sec: 789, tv_nsec: 570953339 }, end_of_app_limited: 0, last_sent_packet: 14, largest_acked: 3, rate_sample: RateSample { delivery_rate: 81599, is_app_limited: true, interval: 33.088551ms, delivered: 2700, prior_delivered: 959, prior_time: Some(Instant { tv_sec: 789, tv_nsec: 570953339 }), send_elapsed: 0ns, ack_elapsed: 33.088551ms, rtt: 33.088551ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 586119, last_update: Instant { tv_sec: 789, tv_nsec: 604082426 }, next_time: Instant { tv_sec: 789, tv_nsec: 604082426 }, max_datagram_size: 1350, last_packet_size: Some(0), iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(13) last_round_min_rtt=33.088551ms 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:32:42.574549714Z TRACE quiche] 665d4afdb3c764ad25632e4fdc2aa92f89630f01 pmtud probe status false hs_con=true hs_sent=true cwnd_avail=2700 out_len=1350 left=1324
[2025-04-30T11:32:42.574552609Z TRACE quiche] 665d4afdb3c764ad25632e4fdc2aa92f89630f01 tx pkt Short dcid=3c1dd5d7c9df779f key_phase=false len=298 pn=15 
[2025-04-30T11:32:42.574554974Z TRACE quiche] 665d4afdb3c764ad25632e4fdc2aa92f89630f01 tx frm STREAM id=4 off=9948 len=292 fin=true
[2025-04-30T11:32:42.574559121Z TRACE quiche::recovery::congestion::recovery] 665d4afdb3c764ad25632e4fdc2aa92f89630f01 timer=100.330237ms latest_rtt=33.088551ms srtt=34.549265ms min_rtt=33.088551ms rttvar=10.197893ms cwnd=16200 ssthresh=18446744073709551615 bytes_in_flight=13824 app_limited=true congestion_recovery_start_time=None Rate { delivered: 3659, delivered_time: Instant { tv_sec: 789, tv_nsec: 604041890 }, first_sent_time: Instant { tv_sec: 789, tv_nsec: 570953339 }, end_of_app_limited: 0, last_sent_packet: 15, largest_acked: 3, rate_sample: RateSample { delivery_rate: 81599, is_app_limited: true, interval: 33.088551ms, delivered: 2700, prior_delivered: 959, prior_time: Some(Instant { tv_sec: 789, tv_nsec: 570953339 }), send_elapsed: 0ns, ack_elapsed: 33.088551ms, rtt: 33.088551ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 586119, last_update: Instant { tv_sec: 789, tv_nsec: 604082426 }, next_time: Instant { tv_sec: 789, tv_nsec: 604082426 }, max_datagram_size: 1350, last_packet_size: Some(0), iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(13) last_round_min_rtt=33.088551ms 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:32:42.574613393Z TRACE quiche_server] 665d4afdb3c764ad25632e4fdc2aa92f89630f01 written 3024 bytes with Some(SendInfo { from: [::]:443, to: [fd00:cafe:cafe::100]:49850, at: Instant { tv_sec: 789, tv_nsec: 604082426 } })
[2025-04-30T11:32:42.574621638Z TRACE quiche_server] Collecting garbage
[2025-04-30T11:32:42.574627138Z TRACE quiche_server] recv() would block
[2025-04-30T11:32:42.574631336Z TRACE quiche_server] 665d4afdb3c764ad25632e4fdc2aa92f89630f01 done writing
[2025-04-30T11:32:42.574634753Z TRACE quiche_server] Collecting garbage
[2025-04-30T11:32:42.576646288Z TRACE quiche_server] got 44 bytes from [fd00:cafe:cafe::100]:49850 to [::]:443
[2025-04-30T11:32:42.576654393Z TRACE quiche_server] got packet Short dcid=665d4afdb3c764ad25632e4fdc2aa92f89630f01 key_phase=false
[2025-04-30T11:32:42.576660715Z TRACE quiche] 665d4afdb3c764ad25632e4fdc2aa92f89630f01 rx pkt Short dcid=665d4afdb3c764ad25632e4fdc2aa92f89630f01 key_phase=false len=23 pn=7 
[2025-04-30T11:32:42.576667007Z TRACE quiche] 665d4afdb3c764ad25632e4fdc2aa92f89630f01 rx frm ACK delay=6 blocks=[2..5] ecn_counts=None
[2025-04-30T11:32:42.576677035Z TRACE quiche::recovery::congestion::recovery] 665d4afdb3c764ad25632e4fdc2aa92f89630f01 packet newly acked 4
[2025-04-30T11:32:42.576680161Z TRACE quiche::recovery::congestion::recovery] 665d4afdb3c764ad25632e4fdc2aa92f89630f01 packet newly acked 5
[2025-04-30T11:32:42.576692464Z TRACE quiche_server] 665d4afdb3c764ad25632e4fdc2aa92f89630f01 processed 44 bytes
[2025-04-30T11:32:42.576697293Z TRACE quiche_server] recv() would block
[2025-04-30T11:32:42.576700589Z TRACE quiche_server] 665d4afdb3c764ad25632e4fdc2aa92f89630f01 done writing
[2025-04-30T11:32:42.576703314Z TRACE quiche_server] Collecting garbage
[2025-04-30T11:32:42.578888223Z TRACE quiche_server] got 44 bytes from [fd00:cafe:cafe::100]:49850 to [::]:443
[2025-04-30T11:32:42.578895266Z TRACE quiche_server] got packet Short dcid=665d4afdb3c764ad25632e4fdc2aa92f89630f01 key_phase=false
[2025-04-30T11:32:42.578900295Z TRACE quiche] 665d4afdb3c764ad25632e4fdc2aa92f89630f01 rx pkt Short dcid=665d4afdb3c764ad25632e4fdc2aa92f89630f01 key_phase=false len=23 pn=8 
[2025-04-30T11:32:42.578905435Z TRACE quiche] 665d4afdb3c764ad25632e4fdc2aa92f89630f01 rx frm ACK delay=8 blocks=[2..7] ecn_counts=None
[2025-04-30T11:32:42.578908921Z TRACE quiche::recovery::congestion::recovery] 665d4afdb3c764ad25632e4fdc2aa92f89630f01 packet newly acked 6
[2025-04-30T11:32:42.578911727Z TRACE quiche::recovery::congestion::recovery] 665d4afdb3c764ad25632e4fdc2aa92f89630f01 packet newly acked 7
[2025-04-30T11:32:42.578921154Z TRACE quiche_server] 665d4afdb3c764ad25632e4fdc2aa92f89630f01 processed 44 bytes
[2025-04-30T11:32:42.578925543Z TRACE quiche_server] recv() would block
[2025-04-30T11:32:42.578928618Z TRACE quiche_server] 665d4afdb3c764ad25632e4fdc2aa92f89630f01 done writing
[2025-04-30T11:32:42.578931313Z TRACE quiche_server] Collecting garbage
[2025-04-30T11:32:42.581117975Z TRACE quiche_server] got 44 bytes from [fd00:cafe:cafe::100]:49850 to [::]:443
[2025-04-30T11:32:42.581125419Z TRACE quiche_server] got packet Short dcid=665d4afdb3c764ad25632e4fdc2aa92f89630f01 key_phase=false
[2025-04-30T11:32:42.581130829Z TRACE quiche] 665d4afdb3c764ad25632e4fdc2aa92f89630f01 rx pkt Short dcid=665d4afdb3c764ad25632e4fdc2aa92f89630f01 key_phase=false len=23 pn=9 
[2025-04-30T11:32:42.581136320Z TRACE quiche] 665d4afdb3c764ad25632e4fdc2aa92f89630f01 rx frm ACK delay=7 blocks=[2..9] ecn_counts=None
[2025-04-30T11:32:42.581140127Z TRACE quiche::recovery::congestion::recovery] 665d4afdb3c764ad25632e4fdc2aa92f89630f01 packet newly acked 8
[2025-04-30T11:32:42.581143112Z TRACE quiche::recovery::congestion::recovery] 665d4afdb3c764ad25632e4fdc2aa92f89630f01 packet newly acked 9
[2025-04-30T11:32:42.581153382Z TRACE quiche_server] 665d4afdb3c764ad25632e4fdc2aa92f89630f01 processed 44 bytes
[2025-04-30T11:32:42.581158070Z TRACE quiche_server] recv() would block
[2025-04-30T11:32:42.581161356Z TRACE quiche_server] 665d4afdb3c764ad25632e4fdc2aa92f89630f01 done writing
[2025-04-30T11:32:42.581164212Z TRACE quiche_server] Collecting garbage
[2025-04-30T11:32:42.582771011Z TRACE quiche_server] got 44 bytes from [fd00:cafe:cafe::100]:49850 to [::]:443
[2025-04-30T11:32:42.582776381Z TRACE quiche_server] got packet Short dcid=665d4afdb3c764ad25632e4fdc2aa92f89630f01 key_phase=false
[2025-04-30T11:32:42.582780409Z TRACE quiche] 665d4afdb3c764ad25632e4fdc2aa92f89630f01 rx pkt Short dcid=665d4afdb3c764ad25632e4fdc2aa92f89630f01 key_phase=false len=23 pn=10 
[2025-04-30T11:32:42.582784426Z TRACE quiche] 665d4afdb3c764ad25632e4fdc2aa92f89630f01 rx frm ACK delay=7 blocks=[2..11] ecn_counts=None
[2025-04-30T11:32:42.582787342Z TRACE quiche::recovery::congestion::recovery] 665d4afdb3c764ad25632e4fdc2aa92f89630f01 packet newly acked 10
[2025-04-30T11:32:42.582789626Z TRACE quiche::recovery::congestion::recovery] 665d4afdb3c764ad25632e4fdc2aa92f89630f01 packet newly acked 11
[2025-04-30T11:32:42.582797892Z TRACE quiche_server] 665d4afdb3c764ad25632e4fdc2aa92f89630f01 processed 44 bytes
[2025-04-30T11:32:42.582805696Z TRACE quiche_server] recv() would block
[2025-04-30T11:32:42.582808331Z TRACE quiche_server] 665d4afdb3c764ad25632e4fdc2aa92f89630f01 done writing
[2025-04-30T11:32:42.582810475Z TRACE quiche_server] Collecting garbage
[2025-04-30T11:32:42.584493487Z TRACE quiche_server] got 45 bytes from [fd00:cafe:cafe::100]:49850 to [::]:443
[2025-04-30T11:32:42.584500410Z TRACE quiche_server] got packet Short dcid=665d4afdb3c764ad25632e4fdc2aa92f89630f01 key_phase=false
[2025-04-30T11:32:42.584505479Z TRACE quiche] 665d4afdb3c764ad25632e4fdc2aa92f89630f01 rx pkt Short dcid=665d4afdb3c764ad25632e4fdc2aa92f89630f01 key_phase=false len=24 pn=11 
[2025-04-30T11:32:42.584511541Z TRACE quiche] 665d4afdb3c764ad25632e4fdc2aa92f89630f01 rx frm ACK delay=146 blocks=[2..12] ecn_counts=None
[2025-04-30T11:32:42.584515859Z TRACE quiche::recovery::congestion::recovery] 665d4afdb3c764ad25632e4fdc2aa92f89630f01 packet newly acked 12
[2025-04-30T11:32:42.584541507Z TRACE quiche_server] 665d4afdb3c764ad25632e4fdc2aa92f89630f01 processed 45 bytes
[2025-04-30T11:32:42.584546806Z TRACE quiche_server] recv() would block
[2025-04-30T11:32:42.584550353Z TRACE quiche_server] 665d4afdb3c764ad25632e4fdc2aa92f89630f01 done writing
[2025-04-30T11:32:42.584553269Z TRACE quiche_server] Collecting garbage
[2025-04-30T11:32:42.607343103Z TRACE quiche_server] got 44 bytes from [fd00:cafe:cafe::100]:49850 to [::]:443
[2025-04-30T11:32:42.607355226Z TRACE quiche_server] got packet Short dcid=665d4afdb3c764ad25632e4fdc2aa92f89630f01 key_phase=false
[2025-04-30T11:32:42.607362379Z TRACE quiche] 665d4afdb3c764ad25632e4fdc2aa92f89630f01 rx pkt Short dcid=665d4afdb3c764ad25632e4fdc2aa92f89630f01 key_phase=false len=23 pn=12 
[2025-04-30T11:32:42.607369483Z TRACE quiche] 665d4afdb3c764ad25632e4fdc2aa92f89630f01 rx frm ACK delay=7 blocks=[2..14] ecn_counts=None
[2025-04-30T11:32:42.607374272Z TRACE quiche::recovery::congestion::recovery] 665d4afdb3c764ad25632e4fdc2aa92f89630f01 packet newly acked 13
[2025-04-30T11:32:42.607377358Z TRACE quiche::recovery::congestion::recovery] 665d4afdb3c764ad25632e4fdc2aa92f89630f01 packet newly acked 14
[2025-04-30T11:32:42.607402895Z TRACE quiche_server] 665d4afdb3c764ad25632e4fdc2aa92f89630f01 processed 44 bytes
[2025-04-30T11:32:42.607408255Z TRACE quiche_server] recv() would block
[2025-04-30T11:32:42.607432130Z TRACE quiche_server] 665d4afdb3c764ad25632e4fdc2aa92f89630f01 done writing
[2025-04-30T11:32:42.607437940Z TRACE quiche_server] Collecting garbage
[2025-04-30T11:32:42.607960145Z TRACE quiche_server] got 43 bytes from [fd00:cafe:cafe::100]:49850 to [::]:443
[2025-04-30T11:32:42.607965075Z TRACE quiche_server] got packet Short dcid=665d4afdb3c764ad25632e4fdc2aa92f89630f01 key_phase=false
[2025-04-30T11:32:42.607970555Z TRACE quiche] 665d4afdb3c764ad25632e4fdc2aa92f89630f01 rx pkt Short dcid=665d4afdb3c764ad25632e4fdc2aa92f89630f01 key_phase=false len=22 pn=13 
[2025-04-30T11:32:42.607976345Z TRACE quiche] 665d4afdb3c764ad25632e4fdc2aa92f89630f01 rx frm APPLICATION_CLOSE err=100 reason=[]
[2025-04-30T11:32:42.607984150Z TRACE quiche_server] 665d4afdb3c764ad25632e4fdc2aa92f89630f01 processed 43 bytes
[2025-04-30T11:32:42.607988619Z TRACE quiche_server] recv() would block
[2025-04-30T11:32:42.607991394Z TRACE quiche_server] 665d4afdb3c764ad25632e4fdc2aa92f89630f01 done writing
[2025-04-30T11:32:42.607994038Z TRACE quiche_server] Collecting garbage
[2025-04-30T11:32:42.784218079Z TRACE quiche_server] timed out
[2025-04-30T11:32:42.784232135Z TRACE quiche] 665d4afdb3c764ad25632e4fdc2aa92f89630f01 draining timeout expired
[2025-04-30T11:32:42.784260027Z TRACE quiche_server] 665d4afdb3c764ad25632e4fdc2aa92f89630f01 done writing
[2025-04-30T11:32:42.784263824Z TRACE quiche_server] Collecting garbage
[2025-04-30T11:32:42.784267241Z INFO  quiche_server] 665d4afdb3c764ad25632e4fdc2aa92f89630f01 connection collected recv=14 sent=16 lost=0 retrans=0 sent_bytes=17483 recv_bytes=2202 lost_bytes=0 [local_addr=[::]:443 peer_addr=[fd00:cafe:cafe::100]:49850 validation_state=Validated active=true recv=14 sent=16 lost=0 retrans=0 rtt=36.493581ms min_rtt=Some(32.867388ms) rttvar=5.489915ms cwnd=16200 sent_bytes=17483 recv_bytes=2202 lost_bytes=0 stream_retrans_bytes=0 pmtu=1350 delivery_rate=407496]