[2025-04-30T11:55:44.217205254Z INFO  quiche_server] listening on [::]:443
[2025-04-30T11:55:44.217226894Z TRACE mio::poll] registering event source with poller: token=Token(0), interests=READABLE
[2025-04-30T11:55:44.217233277Z TRACE quiche_server] GSO detected: false
[2025-04-30T11:55:45.042086769Z TRACE quiche_server] got 1207 bytes from [::ffff:193.167.100.2]:49273 to [::]:443
[2025-04-30T11:55:45.042122927Z TRACE quiche_server] got packet Initial version=57414954 dcid= scid= token=
[2025-04-30T11:55:45.042131283Z WARN  quiche_server] Doing version negotiation
[2025-04-30T11:55:45.042228756Z TRACE quiche_server] got 1207 bytes from [::ffff:193.167.100.2]:49273 to [::]:443
[2025-04-30T11:55:45.042238134Z TRACE quiche_server] got packet Initial version=57414954 dcid= scid= token=
[2025-04-30T11:55:45.042243985Z WARN  quiche_server] Doing version negotiation
[2025-04-30T11:55:45.042276566Z TRACE quiche_server] got 1207 bytes from [::ffff:193.167.100.2]:49273 to [::]:443
[2025-04-30T11:55:45.042283820Z TRACE quiche_server] got packet Initial version=57414954 dcid= scid= token=
[2025-04-30T11:55:45.042288900Z WARN  quiche_server] Doing version negotiation
[2025-04-30T11:55:45.042320830Z TRACE quiche_server] recv() would block
[2025-04-30T11:55:48.236251750Z TRACE quiche_server] got 1200 bytes from [fd00:cafe:cafe::100]:39920 to [::]:443
[2025-04-30T11:55:48.236285153Z TRACE quiche_server] got packet Initial version=1 dcid=9ef78e1fcd5b967cbfd9b99be1ce74f2afa11988 scid=049b79a6d3870b22 token=
[2025-04-30T11:55:48.236293579Z DEBUG quiche_server] New connection: dcid=9ef78e1fcd5b967cbfd9b99be1ce74f2afa11988 scid=5f09ce565d45ed364e567a470937a338733e00fb
[2025-04-30T11:55:48.236506380Z TRACE quiche] 5f09ce565d45ed364e567a470937a338733e00fb rx pkt Initial version=1 dcid=9ef78e1fcd5b967cbfd9b99be1ce74f2afa11988 scid=049b79a6d3870b22 token= len=1162 pn=0 
[2025-04-30T11:55:48.236519144Z TRACE quiche] 5f09ce565d45ed364e567a470937a338733e00fb rx frm CRYPTO off=0 len=286
[2025-04-30T11:55:48.236545173Z TRACE quiche::tls] checking peer ALPN Ok("hq-interop") against Ok("h3")
[2025-04-30T11:55:48.236549060Z TRACE quiche::tls] checking peer ALPN Ok("hq-interop") against Ok("hq-interop")
[2025-04-30T11:55:48.236633510Z TRACE quiche::tls] 5f09ce565d45ed364e567a470937a338733e00fb write message lvl=Initial len=90
[2025-04-30T11:55:48.236664939Z TRACE quiche::tls] 5f09ce565d45ed364e567a470937a338733e00fb set write secret lvl=Handshake
[2025-04-30T11:55:48.236733007Z TRACE quiche::tls] 5f09ce565d45ed364e567a470937a338733e00fb write message lvl=Handshake len=727
[2025-04-30T11:55:48.236736003Z TRACE quiche::tls] 5f09ce565d45ed364e567a470937a338733e00fb set write secret lvl=OneRTT
[2025-04-30T11:55:48.236743587Z TRACE quiche::tls] 5f09ce565d45ed364e567a470937a338733e00fb set read secret lvl=Handshake
[2025-04-30T11:55:48.236762142Z TRACE quiche] 5f09ce565d45ed364e567a470937a338733e00fb rx frm PADDING len=855
[2025-04-30T11:55:48.236782080Z TRACE quiche_server] 5f09ce565d45ed364e567a470937a338733e00fb processed 1200 bytes
[2025-04-30T11:55:48.236795986Z TRACE quiche_server] recv() would block
[2025-04-30T11:55:48.236807678Z TRACE quiche] 5f09ce565d45ed364e567a470937a338733e00fb tx pkt Initial version=1 dcid=049b79a6d3870b22 scid=5f09ce565d45ed364e567a470937a338733e00fb len=99 pn=0 
[2025-04-30T11:55:48.236811014Z TRACE quiche] 5f09ce565d45ed364e567a470937a338733e00fb tx frm ACK delay=39 blocks=[0..0] ecn_counts=None
[2025-04-30T11:55:48.236815322Z TRACE quiche] 5f09ce565d45ed364e567a470937a338733e00fb tx frm CRYPTO off=0 len=90
[2025-04-30T11:55:48.236824009Z TRACE quiche::recovery::congestion::recovery] 5f09ce565d45ed364e567a470937a338733e00fb timer=998.973631ms latest_rtt=0ns srtt=333ms min_rtt=333ms rttvar=166.5ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=154 app_limited=true congestion_recovery_start_time=None Rate { delivered: 0, delivered_time: Instant { tv_sec: 904, tv_nsec: 26908739 }, first_sent_time: Instant { tv_sec: 904, tv_nsec: 26908739 }, 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: 904, tv_nsec: 26908739 }, next_time: Instant { tv_sec: 904, tv_nsec: 26908739 }, 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:55:48.236851320Z TRACE quiche] 5f09ce565d45ed364e567a470937a338733e00fb tx pkt Handshake version=1 dcid=049b79a6d3870b22 scid=5f09ce565d45ed364e567a470937a338733e00fb len=731 pn=1 
[2025-04-30T11:55:48.236854186Z TRACE quiche] 5f09ce565d45ed364e567a470937a338733e00fb tx frm CRYPTO off=0 len=727
[2025-04-30T11:55:48.236859736Z TRACE quiche::recovery::congestion::recovery] 5f09ce565d45ed364e567a470937a338733e00fb timer=998.938294ms latest_rtt=0ns srtt=333ms min_rtt=333ms rttvar=166.5ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=939 app_limited=true congestion_recovery_start_time=None Rate { delivered: 0, delivered_time: Instant { tv_sec: 904, tv_nsec: 26908739 }, first_sent_time: Instant { tv_sec: 904, tv_nsec: 26908739 }, 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: 904, tv_nsec: 26908739 }, next_time: Instant { tv_sec: 904, tv_nsec: 26908739 }, 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:55:48.236924078Z TRACE quiche_server] 5f09ce565d45ed364e567a470937a338733e00fb written 1200 bytes with Some(SendInfo { from: [::]:443, to: [fd00:cafe:cafe::100]:39920, at: Instant { tv_sec: 904, tv_nsec: 26908739 } })
[2025-04-30T11:55:48.236933836Z TRACE quiche_server] Collecting garbage
[2025-04-30T11:55:48.236941150Z TRACE quiche_server] recv() would block
[2025-04-30T11:55:48.236947021Z TRACE quiche_server] 5f09ce565d45ed364e567a470937a338733e00fb done writing
[2025-04-30T11:55:48.236950327Z TRACE quiche_server] Collecting garbage
[2025-04-30T11:55:48.269659755Z TRACE quiche_server] got 1200 bytes from [fd00:cafe:cafe::100]:39920 to [::]:443
[2025-04-30T11:55:48.269673561Z TRACE quiche_server] got packet Initial version=1 dcid=5f09ce565d45ed364e567a470937a338733e00fb scid=049b79a6d3870b22 token=
[2025-04-30T11:55:48.269682277Z TRACE quiche] 5f09ce565d45ed364e567a470937a338733e00fb rx pkt Initial version=1 dcid=5f09ce565d45ed364e567a470937a338733e00fb scid=049b79a6d3870b22 token= len=22 pn=1 
[2025-04-30T11:55:48.269689651Z TRACE quiche] 5f09ce565d45ed364e567a470937a338733e00fb rx frm ACK delay=48 blocks=[0..0] ecn_counts=None
[2025-04-30T11:55:48.269694681Z TRACE quiche::recovery::congestion::recovery] 5f09ce565d45ed364e567a470937a338733e00fb packet newly acked 0
[2025-04-30T11:55:48.269712264Z TRACE quiche] 5f09ce565d45ed364e567a470937a338733e00fb rx pkt Handshake version=1 dcid=5f09ce565d45ed364e567a470937a338733e00fb scid=049b79a6d3870b22 len=1103 pn=0 
[2025-04-30T11:55:48.269718436Z TRACE quiche] 5f09ce565d45ed364e567a470937a338733e00fb rx frm ACK delay=48 blocks=[1..1] ecn_counts=None
[2025-04-30T11:55:48.269721712Z TRACE quiche::recovery::congestion::recovery] 5f09ce565d45ed364e567a470937a338733e00fb packet newly acked 1
[2025-04-30T11:55:48.269725559Z TRACE quiche] 5f09ce565d45ed364e567a470937a338733e00fb rx frm CRYPTO off=0 len=52
[2025-04-30T11:55:48.269745517Z TRACE quiche::tls] 5f09ce565d45ed364e567a470937a338733e00fb set read secret lvl=OneRTT
[2025-04-30T11:55:48.269782937Z TRACE quiche::tls] 5f09ce565d45ed364e567a470937a338733e00fb write message lvl=OneRTT len=428
[2025-04-30T11:55:48.269790802Z TRACE quiche] 5f09ce565d45ed364e567a470937a338733e00fb dropped epoch 1 state
[2025-04-30T11:55:48.269795000Z TRACE quiche] 5f09ce565d45ed364e567a470937a338733e00fb connection established: proto=Ok("hq-interop") cipher=Some(AES256_GCM) curve=Some("X25519") sigalg=None resumed=false TransportParams { original_destination_connection_id: None, max_idle_timeout: 30000, stateless_reset_token: None, max_udp_payload_size: 1472, initial_max_data: 4611686018427387903, initial_max_stream_data_bidi_local: 1250000, initial_max_stream_data_bidi_remote: 1250000, initial_max_stream_data_uni: 1250000, initial_max_streams_bidi: 100, initial_max_streams_uni: 100, ack_delay_exponent: 3, max_ack_delay: 25, disable_active_migration: false, active_conn_id_limit: 5, initial_source_connection_id: Some(049b79a6d3870b22), retry_source_connection_id: None, max_datagram_frame_size: Some(65535), unknown_params: None }
[2025-04-30T11:55:48.269808055Z TRACE quiche] 5f09ce565d45ed364e567a470937a338733e00fb rx frm PADDING len=1026
[2025-04-30T11:55:48.269822281Z TRACE quiche] 5f09ce565d45ed364e567a470937a338733e00fb dropped epoch 0 state
[2025-04-30T11:55:48.269825538Z TRACE quiche_server] 5f09ce565d45ed364e567a470937a338733e00fb processed 1200 bytes
[2025-04-30T11:55:48.269831930Z TRACE quiche_server] recv() would block
[2025-04-30T11:55:48.269837961Z TRACE quiche] 5f09ce565d45ed364e567a470937a338733e00fb pmtud probe status false hs_con=true hs_sent=false cwnd_avail=13500 out_len=1350 left=1324
[2025-04-30T11:55:48.269845596Z TRACE quiche] 5f09ce565d45ed364e567a470937a338733e00fb tx pkt Short dcid=049b79a6d3870b22 key_phase=false len=593 pn=2 
[2025-04-30T11:55:48.269848882Z TRACE quiche] 5f09ce565d45ed364e567a470937a338733e00fb tx frm NEW_CONNECTION_ID seq_num=1 retire_prior_to=0 conn_id=[ae, aa, 26, 20, 7a, 5d, d0, cb, 7e, 6a, 01, 75, fd, c2, 46, 4a, 24, 41, f2, a9] reset_token=[85, b1, a4, f2, 7b, 85, 64, 92, 0b, 72, a6, f7, 75, d9, 0d, 90]
[2025-04-30T11:55:48.269857167Z TRACE quiche] 5f09ce565d45ed364e567a470937a338733e00fb tx frm NEW_CONNECTION_ID seq_num=2 retire_prior_to=0 conn_id=[4b, c8, df, 18, 4a, 03, ae, 39, af, ed, c3, 4a, f2, f7, 50, f0, a5, bd, 38, 56] reset_token=[9e, 46, 14, b7, 7f, 27, 70, d0, 4c, 54, 32, c7, db, af, 74, b8]
[2025-04-30T11:55:48.269863549Z TRACE quiche] 5f09ce565d45ed364e567a470937a338733e00fb tx frm NEW_CONNECTION_ID seq_num=3 retire_prior_to=0 conn_id=[ea, 62, 4d, 3d, f2, aa, 39, 9d, 08, 8a, a5, 20, 0b, 35, 52, ad, c9, 6a, bb, e3] reset_token=[a5, 64, 5f, 41, 35, d2, 11, 24, 6e, 39, d1, 4b, 63, 7b, ec, 4a]
[2025-04-30T11:55:48.269869891Z TRACE quiche] 5f09ce565d45ed364e567a470937a338733e00fb tx frm NEW_CONNECTION_ID seq_num=4 retire_prior_to=0 conn_id=[cc, cd, 3e, d3, ce, 8f, 54, d3, e7, 2c, 08, 3a, 6b, 3d, e3, 08, 8c, f4, db, 26] reset_token=[c0, 5a, 26, 76, f6, 41, 2b, c0, 57, aa, 60, 82, 55, 1e, cf, b6]
[2025-04-30T11:55:48.269875842Z TRACE quiche] 5f09ce565d45ed364e567a470937a338733e00fb tx frm HANDSHAKE_DONE
[2025-04-30T11:55:48.269878648Z TRACE quiche] 5f09ce565d45ed364e567a470937a338733e00fb tx frm CRYPTO off=0 len=428
[2025-04-30T11:55:48.269889869Z TRACE quiche::recovery::congestion::recovery] 5f09ce565d45ed364e567a470937a338733e00fb timer=107.158933ms latest_rtt=32.913292ms srtt=32.885878ms min_rtt=32.881963ms rttvar=12.338567ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=619 app_limited=true congestion_recovery_start_time=None Rate { delivered: 939, delivered_time: Instant { tv_sec: 904, tv_nsec: 59945083 }, first_sent_time: Instant { tv_sec: 904, tv_nsec: 59945083 }, end_of_app_limited: 1, last_sent_packet: 2, largest_acked: 1, rate_sample: RateSample { delivery_rate: 28556, is_app_limited: true, interval: 32.881963ms, delivered: 939, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 904, tv_nsec: 26908739 }), send_elapsed: 0ns, ack_elapsed: 32.881963ms, rtt: 32.881963ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 513138, last_update: Instant { tv_sec: 904, tv_nsec: 59945083 }, next_time: Instant { tv_sec: 904, tv_nsec: 59945083 }, 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:55:48.269964850Z TRACE quiche_server] 5f09ce565d45ed364e567a470937a338733e00fb written 619 bytes with Some(SendInfo { from: [::]:443, to: [fd00:cafe:cafe::100]:39920, at: Instant { tv_sec: 904, tv_nsec: 59945083 } })
[2025-04-30T11:55:48.269971733Z TRACE quiche_server] Collecting garbage
[2025-04-30T11:55:48.269979618Z TRACE quiche_server] got 234 bytes from [fd00:cafe:cafe::100]:39920 to [::]:443
[2025-04-30T11:55:48.269983636Z TRACE quiche_server] got packet Short dcid=5f09ce565d45ed364e567a470937a338733e00fb key_phase=false
[2025-04-30T11:55:48.269989908Z TRACE quiche] 5f09ce565d45ed364e567a470937a338733e00fb rx pkt Short dcid=5f09ce565d45ed364e567a470937a338733e00fb key_phase=false len=213 pn=0 
[2025-04-30T11:55:48.269997732Z TRACE quiche] 5f09ce565d45ed364e567a470937a338733e00fb rx frm NEW_CONNECTION_ID seq_num=1 retire_prior_to=0 conn_id=[ea, 26, b4, 55, ec, ff, 3f, 24] reset_token=[d1, a5, 0d, 41, ad, cb, 9a, c9, c7, 61, 48, f9, e3, eb, f9, 7b]
[2025-04-30T11:55:48.270005306Z TRACE quiche] 5f09ce565d45ed364e567a470937a338733e00fb rx frm NEW_CONNECTION_ID seq_num=2 retire_prior_to=0 conn_id=[07, 2c, 1e, 08, 38, fe, 0f, f1] reset_token=[07, 39, 52, ff, d2, 33, 3b, f8, a0, b8, 8a, 76, ab, 37, a6, b1]
[2025-04-30T11:55:48.270011248Z TRACE quiche] 5f09ce565d45ed364e567a470937a338733e00fb rx frm NEW_CONNECTION_ID seq_num=3 retire_prior_to=0 conn_id=[06, af, 48, 7b, 21, c5, 7b, 76] reset_token=[00, 4d, 78, 74, f3, 03, 9c, b5, 98, bc, 12, fc, 20, 08, 24, 51]
[2025-04-30T11:55:48.270016938Z TRACE quiche] 5f09ce565d45ed364e567a470937a338733e00fb rx frm NEW_CONNECTION_ID seq_num=4 retire_prior_to=0 conn_id=[55, 77, df, 17, 78, b2, 47, 97] reset_token=[29, cb, 9f, 39, 1f, 1c, d2, 90, 95, de, 23, 66, 46, d7, 85, 11]
[2025-04-30T11:55:48.270022980Z TRACE quiche] 5f09ce565d45ed364e567a470937a338733e00fb rx frm NEW_CONNECTION_ID seq_num=5 retire_prior_to=0 conn_id=[9d, 47, 16, d4, f5, b2, 13, b4] reset_token=[13, 2a, a0, b8, 03, f4, 38, ba, 1b, 6d, 2d, 79, a0, 15, 7c, 6e]
[2025-04-30T11:55:48.270028350Z TRACE quiche] 5f09ce565d45ed364e567a470937a338733e00fb rx frm NEW_CONNECTION_ID seq_num=6 retire_prior_to=0 conn_id=[9d, 13, d5, eb, 96, 34, a3, d1] reset_token=[f7, 10, 3b, 72, 1a, 35, 1e, f2, 7a, c4, d5, 8f, fe, be, cd, c7]
[2025-04-30T11:55:48.270033620Z TRACE quiche] 5f09ce565d45ed364e567a470937a338733e00fb rx frm NEW_CONNECTION_ID seq_num=7 retire_prior_to=0 conn_id=[3a, 4e, c4, 74, ef, 20, fe, 25] reset_token=[76, ec, 44, b4, 60, bf, 8a, 8f, 27, df, eb, a1, 51, 5b, 6c, 31]
[2025-04-30T11:55:48.270045192Z TRACE quiche_server] 5f09ce565d45ed364e567a470937a338733e00fb processed 234 bytes
[2025-04-30T11:55:48.270051594Z TRACE quiche_server] got 58 bytes from [fd00:cafe:cafe::100]:39920 to [::]:443
[2025-04-30T11:55:48.270055080Z TRACE quiche_server] got packet Short dcid=5f09ce565d45ed364e567a470937a338733e00fb key_phase=false
[2025-04-30T11:55:48.270059509Z TRACE quiche] 5f09ce565d45ed364e567a470937a338733e00fb rx pkt Short dcid=5f09ce565d45ed364e567a470937a338733e00fb key_phase=false len=37 pn=1 
[2025-04-30T11:55:48.270064418Z TRACE quiche] 5f09ce565d45ed364e567a470937a338733e00fb rx frm STREAM id=0 off=0 len=17 fin=true
[2025-04-30T11:55:48.270071772Z TRACE quiche_server] 5f09ce565d45ed364e567a470937a338733e00fb processed 58 bytes
[2025-04-30T11:55:48.270075088Z DEBUG quiche_apps::common] 5f09ce565d45ed364e567a470937a338733e00fb response stream 0 is writable with capacity Ok(12881)
[2025-04-30T11:55:48.270082081Z TRACE quiche_apps::common] 5f09ce565d45ed364e567a470937a338733e00fb received 17 bytes
[2025-04-30T11:55:48.270090026Z TRACE quiche_apps::common] 5f09ce565d45ed364e567a470937a338733e00fb stream 0 has 17 bytes (fin? true)
[2025-04-30T11:55:48.270094895Z INFO  quiche_apps::common] 5f09ce565d45ed364e567a470937a338733e00fb got GET request for "/www/cbmfoipddh" on stream 0
[2025-04-30T11:55:48.270119722Z INFO  quiche_apps::common] 5f09ce565d45ed364e567a470937a338733e00fb sending response of size 5120 on stream 0
[2025-04-30T11:55:48.270129811Z TRACE quiche_server] got 58 bytes from [fd00:cafe:cafe::100]:39920 to [::]:443
[2025-04-30T11:55:48.270133438Z TRACE quiche_server] got packet Short dcid=5f09ce565d45ed364e567a470937a338733e00fb key_phase=false
[2025-04-30T11:55:48.270138207Z TRACE quiche] 5f09ce565d45ed364e567a470937a338733e00fb rx pkt Short dcid=5f09ce565d45ed364e567a470937a338733e00fb key_phase=false len=37 pn=2 
[2025-04-30T11:55:48.270143136Z TRACE quiche] 5f09ce565d45ed364e567a470937a338733e00fb rx frm STREAM id=4 off=0 len=17 fin=true
[2025-04-30T11:55:48.270149388Z TRACE quiche_server] 5f09ce565d45ed364e567a470937a338733e00fb processed 58 bytes
[2025-04-30T11:55:48.270152404Z DEBUG quiche_apps::common] 5f09ce565d45ed364e567a470937a338733e00fb response stream 4 is writable with capacity Ok(12881)
[2025-04-30T11:55:48.270156782Z TRACE quiche_apps::common] 5f09ce565d45ed364e567a470937a338733e00fb received 17 bytes
[2025-04-30T11:55:48.270159627Z TRACE quiche_apps::common] 5f09ce565d45ed364e567a470937a338733e00fb stream 4 has 17 bytes (fin? true)
[2025-04-30T11:55:48.270162874Z INFO  quiche_apps::common] 5f09ce565d45ed364e567a470937a338733e00fb got GET request for "/www/zgjfzmqcjr" on stream 4
[2025-04-30T11:55:48.270179455Z INFO  quiche_apps::common] 5f09ce565d45ed364e567a470937a338733e00fb sending response of size 10240 on stream 4
[2025-04-30T11:55:48.270186628Z TRACE quiche_server] recv() would block
[2025-04-30T11:55:48.270192529Z TRACE quiche] 5f09ce565d45ed364e567a470937a338733e00fb pmtud probe status false hs_con=true hs_sent=true cwnd_avail=12881 out_len=1350 left=1319
[2025-04-30T11:55:48.270196717Z TRACE quiche] 5f09ce565d45ed364e567a470937a338733e00fb tx pkt Short dcid=049b79a6d3870b22 key_phase=false len=1324 pn=3 
[2025-04-30T11:55:48.270199252Z TRACE quiche] 5f09ce565d45ed364e567a470937a338733e00fb tx frm ACK delay=6 blocks=[0..2] ecn_counts=None
[2025-04-30T11:55:48.270202358Z TRACE quiche] 5f09ce565d45ed364e567a470937a338733e00fb tx frm STREAM id=0 off=0 len=1314 fin=false
[2025-04-30T11:55:48.270209281Z TRACE quiche::recovery::congestion::recovery] 5f09ce565d45ed364e567a470937a338733e00fb timer=107.219938ms latest_rtt=32.913292ms srtt=32.885878ms min_rtt=32.881963ms rttvar=12.338567ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=1969 app_limited=true congestion_recovery_start_time=None Rate { delivered: 939, delivered_time: Instant { tv_sec: 904, tv_nsec: 59945083 }, first_sent_time: Instant { tv_sec: 904, tv_nsec: 59945083 }, end_of_app_limited: 1, last_sent_packet: 3, largest_acked: 1, rate_sample: RateSample { delivery_rate: 28556, is_app_limited: true, interval: 32.881963ms, delivered: 939, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 904, tv_nsec: 26908739 }), send_elapsed: 0ns, ack_elapsed: 32.881963ms, rtt: 32.881963ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 513138, last_update: Instant { tv_sec: 904, tv_nsec: 59945083 }, next_time: Instant { tv_sec: 904, tv_nsec: 59945083 }, 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:55:48.270221233Z TRACE quiche] 5f09ce565d45ed364e567a470937a338733e00fb pmtud probe status false hs_con=true hs_sent=true cwnd_avail=11531 out_len=1350 left=1324
[2025-04-30T11:55:48.270224459Z TRACE quiche] 5f09ce565d45ed364e567a470937a338733e00fb tx pkt Short dcid=049b79a6d3870b22 key_phase=false len=1324 pn=4 
[2025-04-30T11:55:48.270230992Z TRACE quiche] 5f09ce565d45ed364e567a470937a338733e00fb tx frm STREAM id=4 off=0 len=1319 fin=false
[2025-04-30T11:55:48.270251260Z TRACE quiche::recovery::congestion::recovery] 5f09ce565d45ed364e567a470937a338733e00fb timer=107.208486ms latest_rtt=32.913292ms srtt=32.885878ms min_rtt=32.881963ms rttvar=12.338567ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=3319 app_limited=true congestion_recovery_start_time=None Rate { delivered: 939, delivered_time: Instant { tv_sec: 904, tv_nsec: 59945083 }, first_sent_time: Instant { tv_sec: 904, tv_nsec: 59945083 }, end_of_app_limited: 1, last_sent_packet: 4, largest_acked: 1, rate_sample: RateSample { delivery_rate: 28556, is_app_limited: true, interval: 32.881963ms, delivered: 939, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 904, tv_nsec: 26908739 }), send_elapsed: 0ns, ack_elapsed: 32.881963ms, rtt: 32.881963ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 513138, last_update: Instant { tv_sec: 904, tv_nsec: 59945083 }, next_time: Instant { tv_sec: 904, tv_nsec: 59945083 }, 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:55:48.270261850Z TRACE quiche] 5f09ce565d45ed364e567a470937a338733e00fb pmtud probe status false hs_con=true hs_sent=true cwnd_avail=10181 out_len=1350 left=1324
[2025-04-30T11:55:48.270265156Z TRACE quiche] 5f09ce565d45ed364e567a470937a338733e00fb tx pkt Short dcid=049b79a6d3870b22 key_phase=false len=1324 pn=5 
[2025-04-30T11:55:48.270267551Z TRACE quiche] 5f09ce565d45ed364e567a470937a338733e00fb tx frm STREAM id=0 off=1314 len=1318 fin=false
[2025-04-30T11:55:48.270272320Z TRACE quiche::recovery::congestion::recovery] 5f09ce565d45ed364e567a470937a338733e00fb timer=107.228294ms latest_rtt=32.913292ms srtt=32.885878ms min_rtt=32.881963ms rttvar=12.338567ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=4669 app_limited=true congestion_recovery_start_time=None Rate { delivered: 939, delivered_time: Instant { tv_sec: 904, tv_nsec: 59945083 }, first_sent_time: Instant { tv_sec: 904, tv_nsec: 59945083 }, end_of_app_limited: 1, last_sent_packet: 5, largest_acked: 1, rate_sample: RateSample { delivery_rate: 28556, is_app_limited: true, interval: 32.881963ms, delivered: 939, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 904, tv_nsec: 26908739 }), send_elapsed: 0ns, ack_elapsed: 32.881963ms, rtt: 32.881963ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 513138, last_update: Instant { tv_sec: 904, tv_nsec: 59945083 }, next_time: Instant { tv_sec: 904, tv_nsec: 59945083 }, 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:55:48.270281767Z TRACE quiche] 5f09ce565d45ed364e567a470937a338733e00fb pmtud probe status false hs_con=true hs_sent=true cwnd_avail=8831 out_len=1350 left=1324
[2025-04-30T11:55:48.270284733Z TRACE quiche] 5f09ce565d45ed364e567a470937a338733e00fb tx pkt Short dcid=049b79a6d3870b22 key_phase=false len=1324 pn=6 
[2025-04-30T11:55:48.270287057Z TRACE quiche] 5f09ce565d45ed364e567a470937a338733e00fb tx frm STREAM id=4 off=1319 len=1318 fin=false
[2025-04-30T11:55:48.270291716Z TRACE quiche::recovery::congestion::recovery] 5f09ce565d45ed364e567a470937a338733e00fb timer=107.229015ms latest_rtt=32.913292ms srtt=32.885878ms min_rtt=32.881963ms rttvar=12.338567ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=6019 app_limited=true congestion_recovery_start_time=None Rate { delivered: 939, delivered_time: Instant { tv_sec: 904, tv_nsec: 59945083 }, first_sent_time: Instant { tv_sec: 904, tv_nsec: 59945083 }, end_of_app_limited: 1, last_sent_packet: 6, largest_acked: 1, rate_sample: RateSample { delivery_rate: 28556, is_app_limited: true, interval: 32.881963ms, delivered: 939, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 904, tv_nsec: 26908739 }), send_elapsed: 0ns, ack_elapsed: 32.881963ms, rtt: 32.881963ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 513138, last_update: Instant { tv_sec: 904, tv_nsec: 59945083 }, next_time: Instant { tv_sec: 904, tv_nsec: 59945083 }, 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:55:48.270304200Z TRACE quiche] 5f09ce565d45ed364e567a470937a338733e00fb pmtud probe status false hs_con=true hs_sent=true cwnd_avail=7481 out_len=1350 left=1324
[2025-04-30T11:55:48.270307296Z TRACE quiche] 5f09ce565d45ed364e567a470937a338733e00fb tx pkt Short dcid=049b79a6d3870b22 key_phase=false len=1324 pn=7 
[2025-04-30T11:55:48.270309650Z TRACE quiche] 5f09ce565d45ed364e567a470937a338733e00fb tx frm STREAM id=0 off=2632 len=1318 fin=false
[2025-04-30T11:55:48.270314008Z TRACE quiche::recovery::congestion::recovery] 5f09ce565d45ed364e567a470937a338733e00fb timer=107.228995ms latest_rtt=32.913292ms srtt=32.885878ms min_rtt=32.881963ms rttvar=12.338567ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=7369 app_limited=true congestion_recovery_start_time=None Rate { delivered: 939, delivered_time: Instant { tv_sec: 904, tv_nsec: 59945083 }, first_sent_time: Instant { tv_sec: 904, tv_nsec: 59945083 }, end_of_app_limited: 1, last_sent_packet: 7, largest_acked: 1, rate_sample: RateSample { delivery_rate: 28556, is_app_limited: true, interval: 32.881963ms, delivered: 939, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 904, tv_nsec: 26908739 }), send_elapsed: 0ns, ack_elapsed: 32.881963ms, rtt: 32.881963ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 513138, last_update: Instant { tv_sec: 904, tv_nsec: 59945083 }, next_time: Instant { tv_sec: 904, tv_nsec: 59945083 }, 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:55:48.270323396Z TRACE quiche] 5f09ce565d45ed364e567a470937a338733e00fb pmtud probe status false hs_con=true hs_sent=true cwnd_avail=6131 out_len=1350 left=1324
[2025-04-30T11:55:48.270326382Z TRACE quiche] 5f09ce565d45ed364e567a470937a338733e00fb tx pkt Short dcid=049b79a6d3870b22 key_phase=false len=1324 pn=8 
[2025-04-30T11:55:48.270328686Z TRACE quiche] 5f09ce565d45ed364e567a470937a338733e00fb tx frm STREAM id=4 off=2637 len=1318 fin=false
[2025-04-30T11:55:48.270332994Z TRACE quiche::recovery::congestion::recovery] 5f09ce565d45ed364e567a470937a338733e00fb timer=107.229365ms latest_rtt=32.913292ms srtt=32.885878ms min_rtt=32.881963ms rttvar=12.338567ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=8719 app_limited=true congestion_recovery_start_time=None Rate { delivered: 939, delivered_time: Instant { tv_sec: 904, tv_nsec: 59945083 }, first_sent_time: Instant { tv_sec: 904, tv_nsec: 59945083 }, end_of_app_limited: 1, last_sent_packet: 8, largest_acked: 1, rate_sample: RateSample { delivery_rate: 28556, is_app_limited: true, interval: 32.881963ms, delivered: 939, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 904, tv_nsec: 26908739 }), send_elapsed: 0ns, ack_elapsed: 32.881963ms, rtt: 32.881963ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 513138, last_update: Instant { tv_sec: 904, tv_nsec: 59945083 }, next_time: Instant { tv_sec: 904, tv_nsec: 59945083 }, 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:55:48.270344917Z TRACE quiche] 5f09ce565d45ed364e567a470937a338733e00fb pmtud probe status false hs_con=true hs_sent=true cwnd_avail=4781 out_len=1350 left=1324
[2025-04-30T11:55:48.270347862Z TRACE quiche] 5f09ce565d45ed364e567a470937a338733e00fb tx pkt Short dcid=049b79a6d3870b22 key_phase=false len=1176 pn=9 
[2025-04-30T11:55:48.270350187Z TRACE quiche] 5f09ce565d45ed364e567a470937a338733e00fb tx frm STREAM id=0 off=3950 len=1170 fin=true
[2025-04-30T11:55:48.270354685Z TRACE quiche::recovery::congestion::recovery] 5f09ce565d45ed364e567a470937a338733e00fb timer=107.229275ms latest_rtt=32.913292ms srtt=32.885878ms min_rtt=32.881963ms rttvar=12.338567ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=9921 app_limited=true congestion_recovery_start_time=None Rate { delivered: 939, delivered_time: Instant { tv_sec: 904, tv_nsec: 59945083 }, first_sent_time: Instant { tv_sec: 904, tv_nsec: 59945083 }, end_of_app_limited: 1, last_sent_packet: 9, largest_acked: 1, rate_sample: RateSample { delivery_rate: 28556, is_app_limited: true, interval: 32.881963ms, delivered: 939, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 904, tv_nsec: 26908739 }), send_elapsed: 0ns, ack_elapsed: 32.881963ms, rtt: 32.881963ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 513138, last_update: Instant { tv_sec: 904, tv_nsec: 59945083 }, next_time: Instant { tv_sec: 904, tv_nsec: 59945083 }, 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:55:48.270423565Z TRACE quiche_server] 5f09ce565d45ed364e567a470937a338733e00fb written 9302 bytes with Some(SendInfo { from: [::]:443, to: [fd00:cafe:cafe::100]:39920, at: Instant { tv_sec: 904, tv_nsec: 59945083 } })
[2025-04-30T11:55:48.270428444Z TRACE quiche_server] Collecting garbage
[2025-04-30T11:55:48.270432722Z TRACE quiche_server] recv() would block
[2025-04-30T11:55:48.270436339Z TRACE quiche] 5f09ce565d45ed364e567a470937a338733e00fb pmtud probe status false hs_con=true hs_sent=true cwnd_avail=3579 out_len=1350 left=1324
[2025-04-30T11:55:48.270439856Z TRACE quiche] 5f09ce565d45ed364e567a470937a338733e00fb tx pkt Short dcid=049b79a6d3870b22 key_phase=false len=1324 pn=10 
[2025-04-30T11:55:48.270442330Z TRACE quiche] 5f09ce565d45ed364e567a470937a338733e00fb tx frm STREAM id=4 off=3955 len=1318 fin=false
[2025-04-30T11:55:48.270448051Z TRACE quiche::recovery::congestion::recovery] 5f09ce565d45ed364e567a470937a338733e00fb timer=107.22651ms latest_rtt=32.913292ms srtt=32.885878ms min_rtt=32.881963ms rttvar=12.338567ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=11271 app_limited=true congestion_recovery_start_time=None Rate { delivered: 939, delivered_time: Instant { tv_sec: 904, tv_nsec: 59945083 }, first_sent_time: Instant { tv_sec: 904, tv_nsec: 59945083 }, end_of_app_limited: 1, last_sent_packet: 10, largest_acked: 1, rate_sample: RateSample { delivery_rate: 28556, is_app_limited: true, interval: 32.881963ms, delivered: 939, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 904, tv_nsec: 26908739 }), send_elapsed: 0ns, ack_elapsed: 32.881963ms, rtt: 32.881963ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 513138, last_update: Instant { tv_sec: 904, tv_nsec: 59945083 }, next_time: Instant { tv_sec: 904, tv_nsec: 59945083 }, 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:55:48.270462148Z TRACE quiche] 5f09ce565d45ed364e567a470937a338733e00fb pmtud probe status false hs_con=true hs_sent=true cwnd_avail=2229 out_len=1350 left=1324
[2025-04-30T11:55:48.270465143Z TRACE quiche] 5f09ce565d45ed364e567a470937a338733e00fb tx pkt Short dcid=049b79a6d3870b22 key_phase=false len=1324 pn=11 
[2025-04-30T11:55:48.270467437Z TRACE quiche] 5f09ce565d45ed364e567a470937a338733e00fb tx frm STREAM id=4 off=5273 len=1318 fin=false
[2025-04-30T11:55:48.270471926Z TRACE quiche::recovery::congestion::recovery] 5f09ce565d45ed364e567a470937a338733e00fb timer=107.229135ms latest_rtt=32.913292ms srtt=32.885878ms min_rtt=32.881963ms rttvar=12.338567ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=12621 app_limited=true congestion_recovery_start_time=None Rate { delivered: 939, delivered_time: Instant { tv_sec: 904, tv_nsec: 59945083 }, first_sent_time: Instant { tv_sec: 904, tv_nsec: 59945083 }, end_of_app_limited: 1, last_sent_packet: 11, largest_acked: 1, rate_sample: RateSample { delivery_rate: 28556, is_app_limited: true, interval: 32.881963ms, delivered: 939, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 904, tv_nsec: 26908739 }), send_elapsed: 0ns, ack_elapsed: 32.881963ms, rtt: 32.881963ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 513138, last_update: Instant { tv_sec: 904, tv_nsec: 59945083 }, next_time: Instant { tv_sec: 904, tv_nsec: 59945083 }, 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:55:48.270481334Z TRACE quiche] 5f09ce565d45ed364e567a470937a338733e00fb pmtud probe status false hs_con=true hs_sent=true cwnd_avail=879 out_len=1350 left=853
[2025-04-30T11:55:48.270484169Z TRACE quiche] 5f09ce565d45ed364e567a470937a338733e00fb tx pkt Short dcid=049b79a6d3870b22 key_phase=false len=853 pn=12 
[2025-04-30T11:55:48.270486493Z TRACE quiche] 5f09ce565d45ed364e567a470937a338733e00fb tx frm STREAM id=4 off=6591 len=847 fin=false
[2025-04-30T11:55:48.270490872Z TRACE quiche::recovery::congestion::recovery] 5f09ce565d45ed364e567a470937a338733e00fb timer=107.229475ms latest_rtt=32.913292ms srtt=32.885878ms min_rtt=32.881963ms rttvar=12.338567ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=13500 app_limited=false congestion_recovery_start_time=None Rate { delivered: 939, delivered_time: Instant { tv_sec: 904, tv_nsec: 59945083 }, first_sent_time: Instant { tv_sec: 904, tv_nsec: 59945083 }, end_of_app_limited: 1, last_sent_packet: 12, largest_acked: 1, rate_sample: RateSample { delivery_rate: 28556, is_app_limited: true, interval: 32.881963ms, delivered: 939, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 904, tv_nsec: 26908739 }), send_elapsed: 0ns, ack_elapsed: 32.881963ms, rtt: 32.881963ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 513138, last_update: Instant { tv_sec: 904, tv_nsec: 59945083 }, next_time: Instant { tv_sec: 904, tv_nsec: 59945083 }, 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:55:48.270526519Z TRACE quiche_server] 5f09ce565d45ed364e567a470937a338733e00fb written 3579 bytes with Some(SendInfo { from: [::]:443, to: [fd00:cafe:cafe::100]:39920, at: Instant { tv_sec: 904, tv_nsec: 59945083 } })
[2025-04-30T11:55:48.270538983Z TRACE quiche_server] Collecting garbage
[2025-04-30T11:55:48.270542750Z TRACE quiche_server] recv() would block
[2025-04-30T11:55:48.270546126Z TRACE quiche] 5f09ce565d45ed364e567a470937a338733e00fb pmtud probe status false hs_con=true hs_sent=true cwnd_avail=0 out_len=1350 left=0
[2025-04-30T11:55:48.270549282Z TRACE quiche_server] 5f09ce565d45ed364e567a470937a338733e00fb done writing
[2025-04-30T11:55:48.270551516Z TRACE quiche_server] Collecting garbage
[2025-04-30T11:55:48.300950843Z TRACE quiche_server] got 43 bytes from [fd00:cafe:cafe::100]:39920 to [::]:443
[2025-04-30T11:55:48.300964138Z TRACE quiche_server] got packet Short dcid=5f09ce565d45ed364e567a470937a338733e00fb key_phase=false
[2025-04-30T11:55:48.300972554Z TRACE quiche] 5f09ce565d45ed364e567a470937a338733e00fb rx pkt Short dcid=5f09ce565d45ed364e567a470937a338733e00fb key_phase=false len=22 pn=3 
[2025-04-30T11:55:48.300979958Z TRACE quiche] 5f09ce565d45ed364e567a470937a338733e00fb rx frm ACK delay=6 blocks=[2..2] ecn_counts=None
[2025-04-30T11:55:48.300984687Z TRACE quiche::recovery::congestion::recovery] 5f09ce565d45ed364e567a470937a338733e00fb packet newly acked 2
[2025-04-30T11:55:48.300997852Z TRACE quiche_server] 5f09ce565d45ed364e567a470937a338733e00fb processed 43 bytes
[2025-04-30T11:55:48.301003232Z TRACE quiche_server] recv() would block
[2025-04-30T11:55:48.301009594Z TRACE quiche] 5f09ce565d45ed364e567a470937a338733e00fb pmtud probe status false hs_con=true hs_sent=true cwnd_avail=619 out_len=1350 left=593
[2025-04-30T11:55:48.301015175Z TRACE quiche] 5f09ce565d45ed364e567a470937a338733e00fb tx pkt Short dcid=049b79a6d3870b22 key_phase=false len=593 pn=13 
[2025-04-30T11:55:48.301018411Z TRACE quiche] 5f09ce565d45ed364e567a470937a338733e00fb tx frm STREAM id=4 off=7438 len=587 fin=false
[2025-04-30T11:55:48.301026556Z TRACE quiche::recovery::congestion::recovery] 5f09ce565d45ed364e567a470937a338733e00fb timer=96.411429ms latest_rtt=31.136266ms srtt=32.667176ms min_rtt=31.136266ms rttvar=9.691328ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=13500 app_limited=false congestion_recovery_start_time=None Rate { delivered: 1558, delivered_time: Instant { tv_sec: 904, tv_nsec: 91081349 }, first_sent_time: Instant { tv_sec: 904, tv_nsec: 59945083 }, end_of_app_limited: 0, last_sent_packet: 13, largest_acked: 2, rate_sample: RateSample { delivery_rate: 19880, is_app_limited: true, interval: 31.136266ms, delivered: 619, prior_delivered: 939, prior_time: Some(Instant { tv_sec: 904, tv_nsec: 59945083 }), send_elapsed: 0ns, ack_elapsed: 31.136266ms, rtt: 31.136266ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 516573, last_update: Instant { tv_sec: 904, tv_nsec: 91116426 }, next_time: Instant { tv_sec: 904, tv_nsec: 91116426 }, max_datagram_size: 1350, last_packet_size: Some(0), iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(13) last_round_min_rtt=31.136266ms 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:55:48.301066511Z TRACE quiche_server] 5f09ce565d45ed364e567a470937a338733e00fb written 619 bytes with Some(SendInfo { from: [::]:443, to: [fd00:cafe:cafe::100]:39920, at: Instant { tv_sec: 904, tv_nsec: 91116426 } })
[2025-04-30T11:55:48.301072713Z TRACE quiche_server] Collecting garbage
[2025-04-30T11:55:48.301077342Z TRACE quiche_server] recv() would block
[2025-04-30T11:55:48.301082010Z TRACE quiche] 5f09ce565d45ed364e567a470937a338733e00fb pmtud probe status false hs_con=true hs_sent=true cwnd_avail=0 out_len=1350 left=0
[2025-04-30T11:55:48.301085958Z TRACE quiche_server] 5f09ce565d45ed364e567a470937a338733e00fb done writing
[2025-04-30T11:55:48.301089184Z TRACE quiche_server] Collecting garbage
[2025-04-30T11:55:48.303109152Z TRACE quiche_server] got 43 bytes from [fd00:cafe:cafe::100]:39920 to [::]:443
[2025-04-30T11:55:48.303115484Z TRACE quiche_server] got packet Short dcid=5f09ce565d45ed364e567a470937a338733e00fb key_phase=false
[2025-04-30T11:55:48.303126495Z TRACE quiche] 5f09ce565d45ed364e567a470937a338733e00fb rx pkt Short dcid=5f09ce565d45ed364e567a470937a338733e00fb key_phase=false len=22 pn=4 
[2025-04-30T11:55:48.303131794Z TRACE quiche] 5f09ce565d45ed364e567a470937a338733e00fb rx frm ACK delay=2 blocks=[2..4] ecn_counts=None
[2025-04-30T11:55:48.303134980Z TRACE quiche::recovery::congestion::recovery] 5f09ce565d45ed364e567a470937a338733e00fb packet newly acked 3
[2025-04-30T11:55:48.303137525Z TRACE quiche::recovery::congestion::recovery] 5f09ce565d45ed364e567a470937a338733e00fb packet newly acked 4
[2025-04-30T11:55:48.303147775Z TRACE quiche_server] 5f09ce565d45ed364e567a470937a338733e00fb processed 43 bytes
[2025-04-30T11:55:48.303151682Z TRACE quiche_server] recv() would block
[2025-04-30T11:55:48.303155339Z TRACE quiche] 5f09ce565d45ed364e567a470937a338733e00fb pmtud probe status false hs_con=true hs_sent=true cwnd_avail=5400 out_len=1350 left=1324
[2025-04-30T11:55:48.303159116Z TRACE quiche] 5f09ce565d45ed364e567a470937a338733e00fb tx pkt Short dcid=049b79a6d3870b22 key_phase=false len=1324 pn=14 
[2025-04-30T11:55:48.303161581Z TRACE quiche] 5f09ce565d45ed364e567a470937a338733e00fb tx frm STREAM id=4 off=8025 len=1318 fin=false
[2025-04-30T11:55:48.303167281Z TRACE quiche::recovery::congestion::recovery] 5f09ce565d45ed364e567a470937a338733e00fb timer=87.411052ms latest_rtt=33.291068ms srtt=32.743162ms min_rtt=31.136266ms rttvar=7.420469ms cwnd=16200 ssthresh=18446744073709551615 bytes_in_flight=12150 app_limited=true congestion_recovery_start_time=None Rate { delivered: 4258, delivered_time: Instant { tv_sec: 904, tv_nsec: 93236151 }, first_sent_time: Instant { tv_sec: 904, tv_nsec: 59945083 }, end_of_app_limited: 0, last_sent_packet: 14, largest_acked: 4, rate_sample: RateSample { delivery_rate: 106595, is_app_limited: true, interval: 31.136266ms, delivered: 3319, prior_delivered: 939, prior_time: Some(Instant { tv_sec: 904, tv_nsec: 59945083 }), send_elapsed: 0ns, ack_elapsed: 31.136266ms, rtt: 31.136266ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 618449, last_update: Instant { tv_sec: 904, tv_nsec: 91116426 }, next_time: Instant { tv_sec: 904, tv_nsec: 91116426 }, max_datagram_size: 1350, last_packet_size: Some(0), iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(13) last_round_min_rtt=31.136266ms current_round_min_rtt=33.291068ms css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=2 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } 
[2025-04-30T11:55:48.303179054Z TRACE quiche] 5f09ce565d45ed364e567a470937a338733e00fb pmtud probe status false hs_con=true hs_sent=true cwnd_avail=4050 out_len=1350 left=1324
[2025-04-30T11:55:48.303182069Z TRACE quiche] 5f09ce565d45ed364e567a470937a338733e00fb tx pkt Short dcid=049b79a6d3870b22 key_phase=false len=903 pn=15 
[2025-04-30T11:55:48.303184494Z TRACE quiche] 5f09ce565d45ed364e567a470937a338733e00fb tx frm STREAM id=4 off=9343 len=897 fin=true
[2025-04-30T11:55:48.303189162Z TRACE quiche::recovery::congestion::recovery] 5f09ce565d45ed364e567a470937a338733e00fb timer=87.413677ms latest_rtt=33.291068ms srtt=32.743162ms min_rtt=31.136266ms rttvar=7.420469ms cwnd=16200 ssthresh=18446744073709551615 bytes_in_flight=13079 app_limited=true congestion_recovery_start_time=None Rate { delivered: 4258, delivered_time: Instant { tv_sec: 904, tv_nsec: 93236151 }, first_sent_time: Instant { tv_sec: 904, tv_nsec: 59945083 }, end_of_app_limited: 0, last_sent_packet: 15, largest_acked: 4, rate_sample: RateSample { delivery_rate: 106595, is_app_limited: true, interval: 31.136266ms, delivered: 3319, prior_delivered: 939, prior_time: Some(Instant { tv_sec: 904, tv_nsec: 59945083 }), send_elapsed: 0ns, ack_elapsed: 31.136266ms, rtt: 31.136266ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 618449, last_update: Instant { tv_sec: 904, tv_nsec: 91116426 }, next_time: Instant { tv_sec: 904, tv_nsec: 91116426 }, max_datagram_size: 1350, last_packet_size: Some(0), iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(13) last_round_min_rtt=31.136266ms current_round_min_rtt=33.291068ms css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=2 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } 
[2025-04-30T11:55:48.303231693Z TRACE quiche_server] 5f09ce565d45ed364e567a470937a338733e00fb written 2279 bytes with Some(SendInfo { from: [::]:443, to: [fd00:cafe:cafe::100]:39920, at: Instant { tv_sec: 904, tv_nsec: 91116426 } })
[2025-04-30T11:55:48.303237604Z TRACE quiche_server] Collecting garbage
[2025-04-30T11:55:48.303242213Z TRACE quiche_server] recv() would block
[2025-04-30T11:55:48.303245278Z TRACE quiche_server] 5f09ce565d45ed364e567a470937a338733e00fb done writing
[2025-04-30T11:55:48.303247913Z TRACE quiche_server] Collecting garbage
[2025-04-30T11:55:48.305325530Z TRACE quiche_server] got 43 bytes from [fd00:cafe:cafe::100]:39920 to [::]:443
[2025-04-30T11:55:48.305333224Z TRACE quiche_server] got packet Short dcid=5f09ce565d45ed364e567a470937a338733e00fb key_phase=false
[2025-04-30T11:55:48.305339246Z TRACE quiche] 5f09ce565d45ed364e567a470937a338733e00fb rx pkt Short dcid=5f09ce565d45ed364e567a470937a338733e00fb key_phase=false len=22 pn=5 
[2025-04-30T11:55:48.305345147Z TRACE quiche] 5f09ce565d45ed364e567a470937a338733e00fb rx frm ACK delay=1 blocks=[2..6] ecn_counts=None
[2025-04-30T11:55:48.305349024Z TRACE quiche::recovery::congestion::recovery] 5f09ce565d45ed364e567a470937a338733e00fb packet newly acked 5
[2025-04-30T11:55:48.305352060Z TRACE quiche::recovery::congestion::recovery] 5f09ce565d45ed364e567a470937a338733e00fb packet newly acked 6
[2025-04-30T11:55:48.305362700Z TRACE quiche_server] 5f09ce565d45ed364e567a470937a338733e00fb processed 43 bytes
[2025-04-30T11:55:48.305367388Z TRACE quiche_server] recv() would block
[2025-04-30T11:55:48.305370394Z TRACE quiche_server] 5f09ce565d45ed364e567a470937a338733e00fb done writing
[2025-04-30T11:55:48.305373039Z TRACE quiche_server] Collecting garbage
[2025-04-30T11:55:48.307565873Z TRACE quiche_server] got 43 bytes from [fd00:cafe:cafe::100]:39920 to [::]:443
[2025-04-30T11:55:48.307572846Z TRACE quiche_server] got packet Short dcid=5f09ce565d45ed364e567a470937a338733e00fb key_phase=false
[2025-04-30T11:55:48.307578206Z TRACE quiche] 5f09ce565d45ed364e567a470937a338733e00fb rx pkt Short dcid=5f09ce565d45ed364e567a470937a338733e00fb key_phase=false len=22 pn=6 
[2025-04-30T11:55:48.307583636Z TRACE quiche] 5f09ce565d45ed364e567a470937a338733e00fb rx frm ACK delay=1 blocks=[2..8] ecn_counts=None
[2025-04-30T11:55:48.307587263Z TRACE quiche::recovery::congestion::recovery] 5f09ce565d45ed364e567a470937a338733e00fb packet newly acked 7
[2025-04-30T11:55:48.307590198Z TRACE quiche::recovery::congestion::recovery] 5f09ce565d45ed364e567a470937a338733e00fb packet newly acked 8
[2025-04-30T11:55:48.307599146Z TRACE quiche_server] 5f09ce565d45ed364e567a470937a338733e00fb processed 43 bytes
[2025-04-30T11:55:48.307603474Z TRACE quiche_server] recv() would block
[2025-04-30T11:55:48.307606549Z TRACE quiche_server] 5f09ce565d45ed364e567a470937a338733e00fb done writing
[2025-04-30T11:55:48.307609225Z TRACE quiche_server] Collecting garbage
[2025-04-30T11:55:48.309689255Z TRACE quiche_server] got 43 bytes from [fd00:cafe:cafe::100]:39920 to [::]:443
[2025-04-30T11:55:48.309695948Z TRACE quiche_server] got packet Short dcid=5f09ce565d45ed364e567a470937a338733e00fb key_phase=false
[2025-04-30T11:55:48.309700937Z TRACE quiche] 5f09ce565d45ed364e567a470937a338733e00fb rx pkt Short dcid=5f09ce565d45ed364e567a470937a338733e00fb key_phase=false len=22 pn=7 
[2025-04-30T11:55:48.309706047Z TRACE quiche] 5f09ce565d45ed364e567a470937a338733e00fb rx frm ACK delay=1 blocks=[2..10] ecn_counts=None
[2025-04-30T11:55:48.309709504Z TRACE quiche::recovery::congestion::recovery] 5f09ce565d45ed364e567a470937a338733e00fb packet newly acked 9
[2025-04-30T11:55:48.309712409Z TRACE quiche::recovery::congestion::recovery] 5f09ce565d45ed364e567a470937a338733e00fb packet newly acked 10
[2025-04-30T11:55:48.309729231Z TRACE quiche_server] 5f09ce565d45ed364e567a470937a338733e00fb processed 43 bytes
[2025-04-30T11:55:48.309733830Z TRACE quiche_server] recv() would block
[2025-04-30T11:55:48.309736905Z TRACE quiche_server] 5f09ce565d45ed364e567a470937a338733e00fb done writing
[2025-04-30T11:55:48.309739560Z TRACE quiche_server] Collecting garbage
[2025-04-30T11:55:48.311547088Z TRACE quiche_server] got 43 bytes from [fd00:cafe:cafe::100]:39920 to [::]:443
[2025-04-30T11:55:48.311553861Z TRACE quiche_server] got packet Short dcid=5f09ce565d45ed364e567a470937a338733e00fb key_phase=false
[2025-04-30T11:55:48.311558960Z TRACE quiche] 5f09ce565d45ed364e567a470937a338733e00fb rx pkt Short dcid=5f09ce565d45ed364e567a470937a338733e00fb key_phase=false len=22 pn=8 
[2025-04-30T11:55:48.311564220Z TRACE quiche] 5f09ce565d45ed364e567a470937a338733e00fb rx frm ACK delay=1 blocks=[2..12] ecn_counts=None
[2025-04-30T11:55:48.311567707Z TRACE quiche::recovery::congestion::recovery] 5f09ce565d45ed364e567a470937a338733e00fb packet newly acked 11
[2025-04-30T11:55:48.311570602Z TRACE quiche::recovery::congestion::recovery] 5f09ce565d45ed364e567a470937a338733e00fb packet newly acked 12
[2025-04-30T11:55:48.311579579Z TRACE quiche_server] 5f09ce565d45ed364e567a470937a338733e00fb processed 43 bytes
[2025-04-30T11:55:48.311583767Z TRACE quiche_server] recv() would block
[2025-04-30T11:55:48.311586803Z TRACE quiche_server] 5f09ce565d45ed364e567a470937a338733e00fb done writing
[2025-04-30T11:55:48.311589468Z TRACE quiche_server] Collecting garbage
[2025-04-30T11:55:48.334771364Z TRACE quiche_server] got 43 bytes from [fd00:cafe:cafe::100]:39920 to [::]:443
[2025-04-30T11:55:48.334785501Z TRACE quiche_server] got packet Short dcid=5f09ce565d45ed364e567a470937a338733e00fb key_phase=false
[2025-04-30T11:55:48.334793516Z TRACE quiche] 5f09ce565d45ed364e567a470937a338733e00fb rx pkt Short dcid=5f09ce565d45ed364e567a470937a338733e00fb key_phase=false len=22 pn=9 
[2025-04-30T11:55:48.334800970Z TRACE quiche] 5f09ce565d45ed364e567a470937a338733e00fb rx frm ACK delay=3 blocks=[2..14] ecn_counts=None
[2025-04-30T11:55:48.334805599Z TRACE quiche::recovery::congestion::recovery] 5f09ce565d45ed364e567a470937a338733e00fb packet newly acked 13
[2025-04-30T11:55:48.334808705Z TRACE quiche::recovery::congestion::recovery] 5f09ce565d45ed364e567a470937a338733e00fb packet newly acked 14
[2025-04-30T11:55:48.334839773Z TRACE quiche_server] 5f09ce565d45ed364e567a470937a338733e00fb processed 43 bytes
[2025-04-30T11:55:48.334845354Z TRACE quiche_server] recv() would block
[2025-04-30T11:55:48.334849141Z TRACE quiche_server] 5f09ce565d45ed364e567a470937a338733e00fb done writing
[2025-04-30T11:55:48.334852117Z TRACE quiche_server] Collecting garbage
[2025-04-30T11:55:48.335607029Z TRACE quiche_server] got 46 bytes from [fd00:cafe:cafe::100]:39920 to [::]:443
[2025-04-30T11:55:48.335621327Z TRACE quiche_server] got packet Short dcid=5f09ce565d45ed364e567a470937a338733e00fb key_phase=false
[2025-04-30T11:55:48.335629352Z TRACE quiche] 5f09ce565d45ed364e567a470937a338733e00fb rx pkt Short dcid=5f09ce565d45ed364e567a470937a338733e00fb key_phase=false len=25 pn=11 
[2025-04-30T11:55:48.335636696Z TRACE quiche] 5f09ce565d45ed364e567a470937a338733e00fb rx frm ACK delay=14 blocks=[2..15] ecn_counts=None
[2025-04-30T11:55:48.335641384Z TRACE quiche::recovery::congestion::recovery] 5f09ce565d45ed364e567a470937a338733e00fb packet newly acked 15
[2025-04-30T11:55:48.335646223Z TRACE quiche] 5f09ce565d45ed364e567a470937a338733e00fb rx frm APPLICATION_CLOSE err=0 reason=[]
[2025-04-30T11:55:48.335662104Z TRACE quiche_server] 5f09ce565d45ed364e567a470937a338733e00fb processed 46 bytes
[2025-04-30T11:55:48.335667393Z TRACE quiche_server] recv() would block
[2025-04-30T11:55:48.335670379Z TRACE quiche_server] 5f09ce565d45ed364e567a470937a338733e00fb done writing
[2025-04-30T11:55:48.335673274Z TRACE quiche_server] Collecting garbage
[2025-04-30T11:55:48.488879836Z TRACE quiche_server] timed out
[2025-04-30T11:55:48.488935351Z TRACE quiche] 5f09ce565d45ed364e567a470937a338733e00fb draining timeout expired
[2025-04-30T11:55:48.488986097Z TRACE quiche_server] 5f09ce565d45ed364e567a470937a338733e00fb done writing
[2025-04-30T11:55:48.488990024Z TRACE quiche_server] Collecting garbage
[2025-04-30T11:55:48.488993971Z INFO  quiche_server] 5f09ce565d45ed364e567a470937a338733e00fb connection collected recv=14 sent=16 lost=0 retrans=0 sent_bytes=17337 recv_bytes=3097 lost_bytes=0 [local_addr=[::]:443 peer_addr=[fd00:cafe:cafe::100]:39920 validation_state=Validated active=true recv=14 sent=16 lost=0 retrans=0 rtt=35.072199ms min_rtt=Some(31.136266ms) rttvar=3.985797ms cwnd=16200 sent_bytes=17337 recv_bytes=3097 lost_bytes=0 stream_retrans_bytes=0 pmtu=1350 delivery_rate=413022]