[2025-04-30T09:16:14.870001439Z INFO  quiche_server] listening on [::]:443
[2025-04-30T09:16:14.870022929Z TRACE mio::poll] registering event source with poller: token=Token(0), interests=READABLE
[2025-04-30T09:16:14.870029230Z TRACE quiche_server] GSO detected: false
[2025-04-30T09:16:15.701732237Z TRACE quiche_server] got 1207 bytes from [::ffff:193.167.100.2]:60701 to [::]:443
[2025-04-30T09:16:15.701777361Z TRACE quiche_server] got packet Initial version=57414954 dcid= scid= token=
[2025-04-30T09:16:15.701785866Z WARN  quiche_server] Doing version negotiation
[2025-04-30T09:16:15.701877817Z TRACE quiche_server] got 1207 bytes from [::ffff:193.167.100.2]:60701 to [::]:443
[2025-04-30T09:16:15.701887535Z TRACE quiche_server] got packet Initial version=57414954 dcid= scid= token=
[2025-04-30T09:16:15.701893686Z WARN  quiche_server] Doing version negotiation
[2025-04-30T09:16:15.701925445Z TRACE quiche_server] got 1207 bytes from [::ffff:193.167.100.2]:60701 to [::]:443
[2025-04-30T09:16:15.701932418Z TRACE quiche_server] got packet Initial version=57414954 dcid= scid= token=
[2025-04-30T09:16:15.701938349Z WARN  quiche_server] Doing version negotiation
[2025-04-30T09:16:15.701968455Z TRACE quiche_server] recv() would block
[2025-04-30T09:16:15.895217994Z TRACE quiche_server] got 1200 bytes from [fd00:cafe:cafe::100]:54428 to [::]:443
[2025-04-30T09:16:15.895239364Z TRACE quiche_server] got packet Initial version=1 dcid=304d0b951e4ee09a scid= token=
[2025-04-30T09:16:15.895246758Z DEBUG quiche_server] New connection: dcid=304d0b951e4ee09a scid=82325ea2d31bfdc8239cefba8e4d6637da06a0cb
[2025-04-30T09:16:15.895422934Z TRACE quiche] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb rx pkt Initial version=1 dcid=304d0b951e4ee09a scid= token= len=1182 pn=0 
[2025-04-30T09:16:15.895435778Z TRACE quiche] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb rx frm CRYPTO off=0 len=290
[2025-04-30T09:16:15.895461736Z TRACE quiche::tls] checking peer ALPN Ok("hq-interop") against Ok("h3")
[2025-04-30T09:16:15.895465653Z TRACE quiche::tls] checking peer ALPN Ok("hq-interop") against Ok("hq-interop")
[2025-04-30T09:16:15.895552674Z TRACE quiche::tls] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb write message lvl=Initial len=90
[2025-04-30T09:16:15.895605322Z TRACE quiche::tls] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb set write secret lvl=Handshake
[2025-04-30T09:16:15.895677326Z TRACE quiche::tls] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb write message lvl=Handshake len=712
[2025-04-30T09:16:15.895680602Z TRACE quiche::tls] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb set write secret lvl=OneRTT
[2025-04-30T09:16:15.895688296Z TRACE quiche::tls] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb set read secret lvl=Handshake
[2025-04-30T09:16:15.895708333Z TRACE quiche] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb rx frm PADDING len=868
[2025-04-30T09:16:15.895729292Z TRACE quiche_server] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb processed 1200 bytes
[2025-04-30T09:16:15.895741044Z TRACE quiche_server] recv() would block
[2025-04-30T09:16:15.895752625Z TRACE quiche] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb tx pkt Initial version=1 dcid= scid=82325ea2d31bfdc8239cefba8e4d6637da06a0cb len=99 pn=0 
[2025-04-30T09:16:15.895756152Z TRACE quiche] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb tx frm ACK delay=43 blocks=[0..0] ecn_counts=None
[2025-04-30T09:16:15.895760771Z TRACE quiche] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb tx frm CRYPTO off=0 len=90
[2025-04-30T09:16:15.895770028Z TRACE quiche::recovery::congestion::recovery] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb timer=998.972609ms latest_rtt=0ns srtt=333ms min_rtt=333ms rttvar=166.5ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=146 app_limited=true congestion_recovery_start_time=None Rate { delivered: 0, delivered_time: Instant { tv_sec: 682, tv_nsec: 151168425 }, first_sent_time: Instant { tv_sec: 682, tv_nsec: 151168425 }, 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: 682, tv_nsec: 151168425 }, next_time: Instant { tv_sec: 682, tv_nsec: 151168425 }, 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-30T09:16:15.895798791Z TRACE quiche] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb tx pkt Handshake version=1 dcid= scid=82325ea2d31bfdc8239cefba8e4d6637da06a0cb len=716 pn=1 
[2025-04-30T09:16:15.895801847Z TRACE quiche] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb tx frm CRYPTO off=0 len=712
[2025-04-30T09:16:15.895807707Z TRACE quiche::recovery::congestion::recovery] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb timer=998.93531ms latest_rtt=0ns srtt=333ms min_rtt=333ms rttvar=166.5ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=908 app_limited=true congestion_recovery_start_time=None Rate { delivered: 0, delivered_time: Instant { tv_sec: 682, tv_nsec: 151168425 }, first_sent_time: Instant { tv_sec: 682, tv_nsec: 151168425 }, 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: 682, tv_nsec: 151168425 }, next_time: Instant { tv_sec: 682, tv_nsec: 151168425 }, 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-30T09:16:15.895848383Z TRACE quiche_server] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb written 1200 bytes with Some(SendInfo { from: [::]:443, to: [fd00:cafe:cafe::100]:54428, at: Instant { tv_sec: 682, tv_nsec: 151168425 } })
[2025-04-30T09:16:15.895857650Z TRACE quiche_server] Collecting garbage
[2025-04-30T09:16:15.895864323Z TRACE quiche_server] recv() would block
[2025-04-30T09:16:15.895869843Z TRACE quiche_server] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb done writing
[2025-04-30T09:16:15.895873850Z TRACE quiche_server] Collecting garbage
[2025-04-30T09:16:15.928058011Z TRACE quiche_server] got 109 bytes from [fd00:cafe:cafe::100]:54428 to [::]:443
[2025-04-30T09:16:15.928071325Z TRACE quiche_server] got packet Handshake version=1 dcid=82325ea2d31bfdc8239cefba8e4d6637da06a0cb scid=
[2025-04-30T09:16:15.928079961Z TRACE quiche] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb rx pkt Handshake version=1 dcid=82325ea2d31bfdc8239cefba8e4d6637da06a0cb scid= len=80 pn=1 
[2025-04-30T09:16:15.928087866Z TRACE quiche] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb rx frm ACK delay=2 blocks=[1..1] ecn_counts=None
[2025-04-30T09:16:15.928093346Z TRACE quiche::recovery::congestion::recovery] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb packet newly acked 1
[2025-04-30T09:16:15.928098806Z TRACE quiche] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb rx frm CRYPTO off=0 len=52
[2025-04-30T09:16:15.928111871Z TRACE quiche::tls] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb set read secret lvl=OneRTT
[2025-04-30T09:16:15.928149721Z TRACE quiche::tls] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb write message lvl=OneRTT len=428
[2025-04-30T09:16:15.928158507Z TRACE quiche] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb dropped epoch 1 state
[2025-04-30T09:16:15.928162594Z TRACE quiche] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb 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: 50000, stateless_reset_token: None, max_udp_payload_size: 1472, initial_max_data: 16777216, initial_max_stream_data_bidi_local: 65536, initial_max_stream_data_bidi_remote: 65536, initial_max_stream_data_uni: 65536, initial_max_streams_bidi: 0, initial_max_streams_uni: 3, ack_delay_exponent: 8, max_ack_delay: 26, disable_active_migration: false, active_conn_id_limit: 4, initial_source_connection_id: Some(), retry_source_connection_id: None, max_datagram_frame_size: None, unknown_params: None }
[2025-04-30T09:16:15.928193362Z TRACE quiche] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb dropped epoch 0 state
[2025-04-30T09:16:15.928197219Z TRACE quiche_server] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb processed 109 bytes
[2025-04-30T09:16:15.928203480Z TRACE quiche_server] recv() would block
[2025-04-30T09:16:15.928208980Z TRACE quiche] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb pmtud probe status false hs_con=true hs_sent=false cwnd_avail=13500 out_len=1350 left=1332
[2025-04-30T09:16:15.928216875Z TRACE quiche] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb tx pkt Short dcid= key_phase=false len=553 pn=2 
[2025-04-30T09:16:15.928220161Z TRACE quiche] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb tx frm NEW_CONNECTION_ID seq_num=1 retire_prior_to=0 conn_id=[fa, 15, 20, 40, 23, d5, 3d, 39, 0e, 1c, d2, c8, 72, 81, d4, 08, ce, 0d, 4c, ca] reset_token=[b3, f8, 29, 42, cf, 00, 1d, c3, 69, 1e, 81, 9f, fd, 01, c2, 62]
[2025-04-30T09:16:15.928229368Z TRACE quiche] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb tx frm NEW_CONNECTION_ID seq_num=2 retire_prior_to=0 conn_id=[48, e8, 7e, 65, 58, c5, d0, a4, d0, 0e, 9c, 11, 2f, ff, 37, f9, aa, 4d, aa, 64] reset_token=[28, 4e, f2, 89, 12, d5, 19, ee, 61, b5, 7e, 0f, 55, 9a, fd, ce]
[2025-04-30T09:16:15.928237003Z TRACE quiche] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb tx frm NEW_CONNECTION_ID seq_num=3 retire_prior_to=0 conn_id=[8d, 6a, ea, 35, 8a, d2, 00, e3, 59, 21, 6d, 83, f2, c0, 00, f0, 3d, e7, 05, 06] reset_token=[49, 1b, eb, 8a, 9e, 30, 1a, 6f, 00, 02, 0b, 71, 8e, ef, c5, c3]
[2025-04-30T09:16:15.928244797Z TRACE quiche] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb tx frm HANDSHAKE_DONE
[2025-04-30T09:16:15.928247833Z TRACE quiche] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb tx frm CRYPTO off=0 len=428
[2025-04-30T09:16:15.928258462Z TRACE quiche::recovery::congestion::recovery] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb timer=122.951402ms latest_rtt=32.33471ms srtt=32.33471ms min_rtt=32.33471ms rttvar=16.167355ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=571 app_limited=true congestion_recovery_start_time=None Rate { delivered: 762, delivered_time: Instant { tv_sec: 682, tv_nsec: 183631293 }, first_sent_time: Instant { tv_sec: 682, tv_nsec: 183631293 }, end_of_app_limited: 1, last_sent_packet: 2, largest_acked: 1, rate_sample: RateSample { delivery_rate: 23566, is_app_limited: true, interval: 32.33471ms, delivered: 762, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 682, tv_nsec: 151168425 }), send_elapsed: 0ns, ack_elapsed: 32.33471ms, rtt: 32.33471ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 521884, last_update: Instant { tv_sec: 682, tv_nsec: 183631293 }, next_time: Instant { tv_sec: 682, tv_nsec: 183631293 }, 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-30T09:16:15.928303596Z TRACE quiche_server] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb written 571 bytes with Some(SendInfo { from: [::]:443, to: [fd00:cafe:cafe::100]:54428, at: Instant { tv_sec: 682, tv_nsec: 183631293 } })
[2025-04-30T09:16:15.928313675Z TRACE quiche_server] Collecting garbage
[2025-04-30T09:16:15.928320658Z TRACE quiche_server] recv() would block
[2025-04-30T09:16:15.928325977Z TRACE quiche_server] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb done writing
[2025-04-30T09:16:15.928330626Z TRACE quiche_server] Collecting garbage
[2025-04-30T09:16:15.929057955Z TRACE quiche_server] got 1232 bytes from [fd00:cafe:cafe::100]:54428 to [::]:443
[2025-04-30T09:16:15.929065158Z TRACE quiche_server] got packet Short dcid=82325ea2d31bfdc8239cefba8e4d6637da06a0cb key_phase=false
[2025-04-30T09:16:15.929070989Z TRACE quiche] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb rx pkt Short dcid=82325ea2d31bfdc8239cefba8e4d6637da06a0cb key_phase=false len=1211 pn=2 
[2025-04-30T09:16:15.929076980Z TRACE quiche] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb rx frm PING mtu_probe=None
[2025-04-30T09:16:15.929079986Z TRACE quiche] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb rx frm STREAM id=0 off=0 len=17 fin=true
[2025-04-30T09:16:15.929084193Z TRACE quiche] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb rx frm STREAM id=4 off=0 len=17 fin=true
[2025-04-30T09:16:15.929091116Z TRACE quiche] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb rx frm PADDING len=1148
[2025-04-30T09:16:15.929098129Z TRACE quiche_server] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb processed 1232 bytes
[2025-04-30T09:16:15.929101054Z DEBUG quiche_apps::common] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb response stream 0 is writable with capacity Ok(12929)
[2025-04-30T09:16:15.929104331Z DEBUG quiche_apps::common] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb response stream 4 is writable with capacity Ok(12929)
[2025-04-30T09:16:15.929110061Z TRACE quiche_apps::common] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb received 17 bytes
[2025-04-30T09:16:15.929113007Z TRACE quiche_apps::common] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb stream 0 has 17 bytes (fin? true)
[2025-04-30T09:16:15.929117094Z INFO  quiche_apps::common] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb got GET request for "/www/iripbqtrpw" on stream 0
[2025-04-30T09:16:15.929137362Z INFO  quiche_apps::common] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb sending response of size 5120 on stream 0
[2025-04-30T09:16:15.929143924Z TRACE quiche_apps::common] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb received 17 bytes
[2025-04-30T09:16:15.929146409Z TRACE quiche_apps::common] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb stream 4 has 17 bytes (fin? true)
[2025-04-30T09:16:15.929149094Z INFO  quiche_apps::common] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb got GET request for "/www/kbnowfphaw" on stream 4
[2025-04-30T09:16:15.929162188Z INFO  quiche_apps::common] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb sending response of size 10240 on stream 4
[2025-04-30T09:16:15.929169271Z TRACE quiche_server] recv() would block
[2025-04-30T09:16:15.929174310Z TRACE quiche] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb pmtud probe status false hs_con=true hs_sent=true cwnd_avail=12929 out_len=1350 left=1327
[2025-04-30T09:16:15.929178709Z TRACE quiche] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb tx pkt Short dcid= key_phase=false len=1332 pn=3 
[2025-04-30T09:16:15.929181283Z TRACE quiche] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb tx frm ACK delay=12 blocks=[2..2] ecn_counts=None
[2025-04-30T09:16:15.929184499Z TRACE quiche] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb tx frm STREAM id=0 off=0 len=1322 fin=false
[2025-04-30T09:16:15.929191693Z TRACE quiche::recovery::congestion::recovery] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb timer=122.983641ms latest_rtt=32.33471ms srtt=32.33471ms min_rtt=32.33471ms rttvar=16.167355ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=1921 app_limited=true congestion_recovery_start_time=None Rate { delivered: 762, delivered_time: Instant { tv_sec: 682, tv_nsec: 183631293 }, first_sent_time: Instant { tv_sec: 682, tv_nsec: 183631293 }, end_of_app_limited: 1, last_sent_packet: 3, largest_acked: 1, rate_sample: RateSample { delivery_rate: 23566, is_app_limited: true, interval: 32.33471ms, delivered: 762, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 682, tv_nsec: 151168425 }), send_elapsed: 0ns, ack_elapsed: 32.33471ms, rtt: 32.33471ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 521884, last_update: Instant { tv_sec: 682, tv_nsec: 183631293 }, next_time: Instant { tv_sec: 682, tv_nsec: 183631293 }, 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-30T09:16:15.929211078Z TRACE quiche] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb pmtud probe status false hs_con=true hs_sent=true cwnd_avail=11579 out_len=1350 left=1332
[2025-04-30T09:16:15.929214625Z TRACE quiche] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb tx pkt Short dcid= key_phase=false len=1332 pn=4 
[2025-04-30T09:16:15.929217120Z TRACE quiche] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb tx frm STREAM id=4 off=0 len=1327 fin=false
[2025-04-30T09:16:15.929222119Z TRACE quiche::recovery::congestion::recovery] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb timer=122.991727ms latest_rtt=32.33471ms srtt=32.33471ms min_rtt=32.33471ms rttvar=16.167355ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=3271 app_limited=true congestion_recovery_start_time=None Rate { delivered: 762, delivered_time: Instant { tv_sec: 682, tv_nsec: 183631293 }, first_sent_time: Instant { tv_sec: 682, tv_nsec: 183631293 }, end_of_app_limited: 1, last_sent_packet: 4, largest_acked: 1, rate_sample: RateSample { delivery_rate: 23566, is_app_limited: true, interval: 32.33471ms, delivered: 762, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 682, tv_nsec: 151168425 }), send_elapsed: 0ns, ack_elapsed: 32.33471ms, rtt: 32.33471ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 521884, last_update: Instant { tv_sec: 682, tv_nsec: 183631293 }, next_time: Instant { tv_sec: 682, tv_nsec: 183631293 }, 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-30T09:16:15.929234412Z TRACE quiche] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb pmtud probe status false hs_con=true hs_sent=true cwnd_avail=10229 out_len=1350 left=1332
[2025-04-30T09:16:15.929237507Z TRACE quiche] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb tx pkt Short dcid= key_phase=false len=1332 pn=5 
[2025-04-30T09:16:15.929239942Z TRACE quiche] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb tx frm STREAM id=0 off=1322 len=1326 fin=false
[2025-04-30T09:16:15.929244520Z TRACE quiche::recovery::congestion::recovery] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb timer=122.99306ms latest_rtt=32.33471ms srtt=32.33471ms min_rtt=32.33471ms rttvar=16.167355ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=4621 app_limited=true congestion_recovery_start_time=None Rate { delivered: 762, delivered_time: Instant { tv_sec: 682, tv_nsec: 183631293 }, first_sent_time: Instant { tv_sec: 682, tv_nsec: 183631293 }, end_of_app_limited: 1, last_sent_packet: 5, largest_acked: 1, rate_sample: RateSample { delivery_rate: 23566, is_app_limited: true, interval: 32.33471ms, delivered: 762, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 682, tv_nsec: 151168425 }), send_elapsed: 0ns, ack_elapsed: 32.33471ms, rtt: 32.33471ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 521884, last_update: Instant { tv_sec: 682, tv_nsec: 183631293 }, next_time: Instant { tv_sec: 682, tv_nsec: 183631293 }, 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-30T09:16:15.929256322Z TRACE quiche] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb pmtud probe status false hs_con=true hs_sent=true cwnd_avail=8879 out_len=1350 left=1332
[2025-04-30T09:16:15.929259398Z TRACE quiche] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb tx pkt Short dcid= key_phase=false len=1332 pn=6 
[2025-04-30T09:16:15.929264538Z TRACE quiche] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb tx frm STREAM id=4 off=1327 len=1326 fin=false
[2025-04-30T09:16:15.929269637Z TRACE quiche::recovery::congestion::recovery] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb timer=122.989934ms latest_rtt=32.33471ms srtt=32.33471ms min_rtt=32.33471ms rttvar=16.167355ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=5971 app_limited=true congestion_recovery_start_time=None Rate { delivered: 762, delivered_time: Instant { tv_sec: 682, tv_nsec: 183631293 }, first_sent_time: Instant { tv_sec: 682, tv_nsec: 183631293 }, end_of_app_limited: 1, last_sent_packet: 6, largest_acked: 1, rate_sample: RateSample { delivery_rate: 23566, is_app_limited: true, interval: 32.33471ms, delivered: 762, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 682, tv_nsec: 151168425 }), send_elapsed: 0ns, ack_elapsed: 32.33471ms, rtt: 32.33471ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 521884, last_update: Instant { tv_sec: 682, tv_nsec: 183631293 }, next_time: Instant { tv_sec: 682, tv_nsec: 183631293 }, 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-30T09:16:15.929281539Z TRACE quiche] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb pmtud probe status false hs_con=true hs_sent=true cwnd_avail=7529 out_len=1350 left=1332
[2025-04-30T09:16:15.929284585Z TRACE quiche] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb tx pkt Short dcid= key_phase=false len=1332 pn=7 
[2025-04-30T09:16:15.929286959Z TRACE quiche] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb tx frm STREAM id=0 off=2648 len=1326 fin=false
[2025-04-30T09:16:15.929291467Z TRACE quiche::recovery::congestion::recovery] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb timer=122.99314ms latest_rtt=32.33471ms srtt=32.33471ms min_rtt=32.33471ms rttvar=16.167355ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=7321 app_limited=true congestion_recovery_start_time=None Rate { delivered: 762, delivered_time: Instant { tv_sec: 682, tv_nsec: 183631293 }, first_sent_time: Instant { tv_sec: 682, tv_nsec: 183631293 }, end_of_app_limited: 1, last_sent_packet: 7, largest_acked: 1, rate_sample: RateSample { delivery_rate: 23566, is_app_limited: true, interval: 32.33471ms, delivered: 762, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 682, tv_nsec: 151168425 }), send_elapsed: 0ns, ack_elapsed: 32.33471ms, rtt: 32.33471ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 521884, last_update: Instant { tv_sec: 682, tv_nsec: 183631293 }, next_time: Instant { tv_sec: 682, tv_nsec: 183631293 }, 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-30T09:16:15.929303119Z TRACE quiche] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb pmtud probe status false hs_con=true hs_sent=true cwnd_avail=6179 out_len=1350 left=1332
[2025-04-30T09:16:15.929306155Z TRACE quiche] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb tx pkt Short dcid= key_phase=false len=1332 pn=8 
[2025-04-30T09:16:15.929308519Z TRACE quiche] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb tx frm STREAM id=4 off=2653 len=1326 fin=false
[2025-04-30T09:16:15.929312987Z TRACE quiche::recovery::congestion::recovery] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb timer=122.99338ms latest_rtt=32.33471ms srtt=32.33471ms min_rtt=32.33471ms rttvar=16.167355ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=8671 app_limited=true congestion_recovery_start_time=None Rate { delivered: 762, delivered_time: Instant { tv_sec: 682, tv_nsec: 183631293 }, first_sent_time: Instant { tv_sec: 682, tv_nsec: 183631293 }, end_of_app_limited: 1, last_sent_packet: 8, largest_acked: 1, rate_sample: RateSample { delivery_rate: 23566, is_app_limited: true, interval: 32.33471ms, delivered: 762, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 682, tv_nsec: 151168425 }), send_elapsed: 0ns, ack_elapsed: 32.33471ms, rtt: 32.33471ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 521884, last_update: Instant { tv_sec: 682, tv_nsec: 183631293 }, next_time: Instant { tv_sec: 682, tv_nsec: 183631293 }, 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-30T09:16:15.929327434Z TRACE quiche] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb pmtud probe status false hs_con=true hs_sent=true cwnd_avail=4829 out_len=1350 left=1332
[2025-04-30T09:16:15.929330450Z TRACE quiche] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb tx pkt Short dcid= key_phase=false len=1152 pn=9 
[2025-04-30T09:16:15.929332894Z TRACE quiche] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb tx frm STREAM id=0 off=3974 len=1146 fin=true
[2025-04-30T09:16:15.929337373Z TRACE quiche::recovery::congestion::recovery] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb timer=122.99328ms latest_rtt=32.33471ms srtt=32.33471ms min_rtt=32.33471ms rttvar=16.167355ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=9841 app_limited=true congestion_recovery_start_time=None Rate { delivered: 762, delivered_time: Instant { tv_sec: 682, tv_nsec: 183631293 }, first_sent_time: Instant { tv_sec: 682, tv_nsec: 183631293 }, end_of_app_limited: 1, last_sent_packet: 9, largest_acked: 1, rate_sample: RateSample { delivery_rate: 23566, is_app_limited: true, interval: 32.33471ms, delivered: 762, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 682, tv_nsec: 151168425 }), send_elapsed: 0ns, ack_elapsed: 32.33471ms, rtt: 32.33471ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 521884, last_update: Instant { tv_sec: 682, tv_nsec: 183631293 }, next_time: Instant { tv_sec: 682, tv_nsec: 183631293 }, 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-30T09:16:15.929437799Z TRACE quiche_server] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb written 9270 bytes with Some(SendInfo { from: [::]:443, to: [fd00:cafe:cafe::100]:54428, at: Instant { tv_sec: 682, tv_nsec: 183631293 } })
[2025-04-30T09:16:15.929446525Z TRACE quiche_server] Collecting garbage
[2025-04-30T09:16:15.929452256Z TRACE quiche_server] recv() would block
[2025-04-30T09:16:15.929458908Z TRACE quiche] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb pmtud probe status false hs_con=true hs_sent=true cwnd_avail=3659 out_len=1350 left=1332
[2025-04-30T09:16:15.929464258Z TRACE quiche] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb tx pkt Short dcid= key_phase=false len=1332 pn=10 
[2025-04-30T09:16:15.929466943Z TRACE quiche] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb tx frm STREAM id=4 off=3979 len=1326 fin=false
[2025-04-30T09:16:15.929474527Z TRACE quiche::recovery::congestion::recovery] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb timer=122.985245ms latest_rtt=32.33471ms srtt=32.33471ms min_rtt=32.33471ms rttvar=16.167355ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=11191 app_limited=true congestion_recovery_start_time=None Rate { delivered: 762, delivered_time: Instant { tv_sec: 682, tv_nsec: 183631293 }, first_sent_time: Instant { tv_sec: 682, tv_nsec: 183631293 }, end_of_app_limited: 1, last_sent_packet: 10, largest_acked: 1, rate_sample: RateSample { delivery_rate: 23566, is_app_limited: true, interval: 32.33471ms, delivered: 762, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 682, tv_nsec: 151168425 }), send_elapsed: 0ns, ack_elapsed: 32.33471ms, rtt: 32.33471ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 521884, last_update: Instant { tv_sec: 682, tv_nsec: 183631293 }, next_time: Instant { tv_sec: 682, tv_nsec: 183631293 }, 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-30T09:16:15.929493953Z TRACE quiche] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb pmtud probe status false hs_con=true hs_sent=true cwnd_avail=2309 out_len=1350 left=1332
[2025-04-30T09:16:15.929497159Z TRACE quiche] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb tx pkt Short dcid= key_phase=false len=1332 pn=11 
[2025-04-30T09:16:15.929499604Z TRACE quiche] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb tx frm STREAM id=4 off=5305 len=1326 fin=false
[2025-04-30T09:16:15.929519400Z TRACE quiche::recovery::congestion::recovery] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb timer=122.97724ms latest_rtt=32.33471ms srtt=32.33471ms min_rtt=32.33471ms rttvar=16.167355ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=12541 app_limited=true congestion_recovery_start_time=None Rate { delivered: 762, delivered_time: Instant { tv_sec: 682, tv_nsec: 183631293 }, first_sent_time: Instant { tv_sec: 682, tv_nsec: 183631293 }, end_of_app_limited: 1, last_sent_packet: 11, largest_acked: 1, rate_sample: RateSample { delivery_rate: 23566, is_app_limited: true, interval: 32.33471ms, delivered: 762, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 682, tv_nsec: 151168425 }), send_elapsed: 0ns, ack_elapsed: 32.33471ms, rtt: 32.33471ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 521884, last_update: Instant { tv_sec: 682, tv_nsec: 183631293 }, next_time: Instant { tv_sec: 682, tv_nsec: 183631293 }, 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-30T09:16:15.929537233Z TRACE quiche] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb pmtud probe status false hs_con=true hs_sent=true cwnd_avail=959 out_len=1350 left=941
[2025-04-30T09:16:15.929540399Z TRACE quiche] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb tx pkt Short dcid= key_phase=false len=941 pn=12 
[2025-04-30T09:16:15.929542884Z TRACE quiche] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb tx frm STREAM id=4 off=6631 len=935 fin=false
[2025-04-30T09:16:15.929547693Z TRACE quiche::recovery::congestion::recovery] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb timer=122.992549ms latest_rtt=32.33471ms srtt=32.33471ms min_rtt=32.33471ms rttvar=16.167355ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=13500 app_limited=false congestion_recovery_start_time=None Rate { delivered: 762, delivered_time: Instant { tv_sec: 682, tv_nsec: 183631293 }, first_sent_time: Instant { tv_sec: 682, tv_nsec: 183631293 }, end_of_app_limited: 1, last_sent_packet: 12, largest_acked: 1, rate_sample: RateSample { delivery_rate: 23566, is_app_limited: true, interval: 32.33471ms, delivered: 762, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 682, tv_nsec: 151168425 }), send_elapsed: 0ns, ack_elapsed: 32.33471ms, rtt: 32.33471ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 521884, last_update: Instant { tv_sec: 682, tv_nsec: 183631293 }, next_time: Instant { tv_sec: 682, tv_nsec: 183631293 }, 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-30T09:16:15.929625537Z TRACE quiche_server] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb written 3659 bytes with Some(SendInfo { from: [::]:443, to: [fd00:cafe:cafe::100]:54428, at: Instant { tv_sec: 682, tv_nsec: 183631293 } })
[2025-04-30T09:16:15.929637369Z TRACE quiche_server] Collecting garbage
[2025-04-30T09:16:15.929643400Z TRACE quiche_server] recv() would block
[2025-04-30T09:16:15.929649531Z TRACE quiche] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb pmtud probe status false hs_con=true hs_sent=true cwnd_avail=0 out_len=1350 left=0
[2025-04-30T09:16:15.929653559Z TRACE quiche_server] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb done writing
[2025-04-30T09:16:15.929655813Z TRACE quiche_server] Collecting garbage
[2025-04-30T09:16:15.960869895Z TRACE quiche_server] got 46 bytes from [fd00:cafe:cafe::100]:54428 to [::]:443
[2025-04-30T09:16:15.960881747Z TRACE quiche_server] got packet Short dcid=82325ea2d31bfdc8239cefba8e4d6637da06a0cb key_phase=false
[2025-04-30T09:16:15.960889461Z TRACE quiche] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb rx pkt Short dcid=82325ea2d31bfdc8239cefba8e4d6637da06a0cb key_phase=false len=25 pn=3 
[2025-04-30T09:16:15.960895943Z TRACE quiche] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb rx frm ACK delay=0 blocks=[2..3] ecn_counts=None
[2025-04-30T09:16:15.960899831Z TRACE quiche::recovery::congestion::recovery] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb packet newly acked 2
[2025-04-30T09:16:15.960902596Z TRACE quiche::recovery::congestion::recovery] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb packet newly acked 3
[2025-04-30T09:16:15.960916652Z TRACE quiche_server] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb processed 46 bytes
[2025-04-30T09:16:15.960919938Z DEBUG quiche_apps::common] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb response stream 4 is writable with capacity Ok(3271)
[2025-04-30T09:16:15.960927272Z TRACE quiche_server] recv() would block
[2025-04-30T09:16:15.960931930Z TRACE quiche] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb pmtud probe status false hs_con=true hs_sent=true cwnd_avail=3271 out_len=1350 left=1332
[2025-04-30T09:16:15.960936699Z TRACE quiche] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb tx pkt Short dcid= key_phase=false len=1332 pn=13 
[2025-04-30T09:16:15.960939264Z TRACE quiche] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb tx frm STREAM id=4 off=7566 len=1326 fin=false
[2025-04-30T09:16:15.960946267Z TRACE quiche::recovery::congestion::recovery] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb timer=107.210107ms latest_rtt=32.681783ms srtt=32.378093ms min_rtt=32.33471ms rttvar=12.212284ms cwnd=14850 ssthresh=18446744073709551615 bytes_in_flight=12929 app_limited=true congestion_recovery_start_time=None Rate { delivered: 2683, delivered_time: Instant { tv_sec: 682, tv_nsec: 216313076 }, first_sent_time: Instant { tv_sec: 682, tv_nsec: 183631293 }, end_of_app_limited: 0, last_sent_packet: 13, largest_acked: 3, rate_sample: RateSample { delivery_rate: 58778, is_app_limited: true, interval: 32.681783ms, delivered: 1921, prior_delivered: 762, prior_time: Some(Instant { tv_sec: 682, tv_nsec: 183631293 }), send_elapsed: 0ns, ack_elapsed: 32.681783ms, rtt: 32.681783ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 573304, last_update: Instant { tv_sec: 682, tv_nsec: 216354553 }, next_time: Instant { tv_sec: 682, tv_nsec: 216354553 }, max_datagram_size: 1350, last_packet_size: Some(0), iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(13) last_round_min_rtt=32.681783ms 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-30T09:16:15.960962357Z TRACE quiche] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb pmtud probe status false hs_con=true hs_sent=true cwnd_avail=1921 out_len=1350 left=1332
[2025-04-30T09:16:15.960971814Z TRACE quiche] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb tx pkt Short dcid= key_phase=false len=1332 pn=14 
[2025-04-30T09:16:15.960974489Z TRACE quiche] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb tx frm STREAM id=4 off=8892 len=1326 fin=false
[2025-04-30T09:16:15.960979528Z TRACE quiche::recovery::congestion::recovery] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb timer=107.208645ms latest_rtt=32.681783ms srtt=32.378093ms min_rtt=32.33471ms rttvar=12.212284ms cwnd=14850 ssthresh=18446744073709551615 bytes_in_flight=14279 app_limited=true congestion_recovery_start_time=None Rate { delivered: 2683, delivered_time: Instant { tv_sec: 682, tv_nsec: 216313076 }, first_sent_time: Instant { tv_sec: 682, tv_nsec: 183631293 }, end_of_app_limited: 0, last_sent_packet: 14, largest_acked: 3, rate_sample: RateSample { delivery_rate: 58778, is_app_limited: true, interval: 32.681783ms, delivered: 1921, prior_delivered: 762, prior_time: Some(Instant { tv_sec: 682, tv_nsec: 183631293 }), send_elapsed: 0ns, ack_elapsed: 32.681783ms, rtt: 32.681783ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 573304, last_update: Instant { tv_sec: 682, tv_nsec: 216354553 }, next_time: Instant { tv_sec: 682, tv_nsec: 216354553 }, max_datagram_size: 1350, last_packet_size: Some(0), iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(13) last_round_min_rtt=32.681783ms 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-30T09:16:15.960992212Z TRACE quiche] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb pmtud probe status false hs_con=true hs_sent=true cwnd_avail=571 out_len=1350 left=553
[2025-04-30T09:16:15.960995247Z TRACE quiche] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb tx pkt Short dcid= key_phase=false len=28 pn=15 
[2025-04-30T09:16:15.960997682Z TRACE quiche] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb tx frm STREAM id=4 off=10218 len=22 fin=true
[2025-04-30T09:16:15.961002271Z TRACE quiche::recovery::congestion::recovery] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb timer=107.216139ms latest_rtt=32.681783ms srtt=32.378093ms min_rtt=32.33471ms rttvar=12.212284ms cwnd=14850 ssthresh=18446744073709551615 bytes_in_flight=14325 app_limited=true congestion_recovery_start_time=None Rate { delivered: 2683, delivered_time: Instant { tv_sec: 682, tv_nsec: 216313076 }, first_sent_time: Instant { tv_sec: 682, tv_nsec: 183631293 }, end_of_app_limited: 0, last_sent_packet: 15, largest_acked: 3, rate_sample: RateSample { delivery_rate: 58778, is_app_limited: true, interval: 32.681783ms, delivered: 1921, prior_delivered: 762, prior_time: Some(Instant { tv_sec: 682, tv_nsec: 183631293 }), send_elapsed: 0ns, ack_elapsed: 32.681783ms, rtt: 32.681783ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 573304, last_update: Instant { tv_sec: 682, tv_nsec: 216354553 }, next_time: Instant { tv_sec: 682, tv_nsec: 216354553 }, max_datagram_size: 1350, last_packet_size: Some(0), iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(13) last_round_min_rtt=32.681783ms 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-30T09:16:15.961060599Z TRACE quiche_server] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb written 2746 bytes with Some(SendInfo { from: [::]:443, to: [fd00:cafe:cafe::100]:54428, at: Instant { tv_sec: 682, tv_nsec: 216354553 } })
[2025-04-30T09:16:15.961068964Z TRACE quiche_server] Collecting garbage
[2025-04-30T09:16:15.961074645Z TRACE quiche_server] recv() would block
[2025-04-30T09:16:15.961079093Z TRACE quiche_server] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb done writing
[2025-04-30T09:16:15.961082880Z TRACE quiche_server] Collecting garbage
[2025-04-30T09:16:15.961958052Z TRACE quiche_server] got 1312 bytes from [fd00:cafe:cafe::100]:54428 to [::]:443
[2025-04-30T09:16:15.961966518Z TRACE quiche_server] got packet Short dcid=82325ea2d31bfdc8239cefba8e4d6637da06a0cb key_phase=false
[2025-04-30T09:16:15.961977379Z TRACE quiche] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb rx pkt Short dcid=82325ea2d31bfdc8239cefba8e4d6637da06a0cb key_phase=false len=1291 pn=4 
[2025-04-30T09:16:15.961983480Z TRACE quiche] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb rx frm PING mtu_probe=None
[2025-04-30T09:16:15.961990323Z TRACE quiche] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb rx frm PADDING len=1270
[2025-04-30T09:16:15.961996724Z TRACE quiche_server] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb processed 1312 bytes
[2025-04-30T09:16:15.962000812Z TRACE quiche_server] recv() would block
[2025-04-30T09:16:15.962005541Z TRACE quiche] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb pmtud probe status false hs_con=true hs_sent=true cwnd_avail=525 out_len=1350 left=502
[2025-04-30T09:16:15.962008947Z TRACE quiche] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb tx pkt Short dcid= key_phase=false len=5 pn=16 
[2025-04-30T09:16:15.962011451Z TRACE quiche] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb tx frm ACK delay=3 blocks=[3..4] ecn_counts=None
[2025-04-30T09:16:15.962018134Z TRACE quiche::recovery::congestion::recovery] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb timer=106.200145ms latest_rtt=32.681783ms srtt=32.378093ms min_rtt=32.33471ms rttvar=12.212284ms cwnd=14850 ssthresh=18446744073709551615 bytes_in_flight=14325 app_limited=true congestion_recovery_start_time=None Rate { delivered: 2683, delivered_time: Instant { tv_sec: 682, tv_nsec: 216313076 }, first_sent_time: Instant { tv_sec: 682, tv_nsec: 183631293 }, end_of_app_limited: 0, last_sent_packet: 16, largest_acked: 3, rate_sample: RateSample { delivery_rate: 58778, is_app_limited: true, interval: 32.681783ms, delivered: 1921, prior_delivered: 762, prior_time: Some(Instant { tv_sec: 682, tv_nsec: 183631293 }), send_elapsed: 0ns, ack_elapsed: 32.681783ms, rtt: 32.681783ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 573304, last_update: Instant { tv_sec: 682, tv_nsec: 216354553 }, next_time: Instant { tv_sec: 682, tv_nsec: 216354553 }, max_datagram_size: 1350, last_packet_size: Some(0), iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(13) last_round_min_rtt=32.681783ms 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-30T09:16:15.962052668Z TRACE quiche_server] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb written 23 bytes with Some(SendInfo { from: [::]:443, to: [fd00:cafe:cafe::100]:54428, at: Instant { tv_sec: 682, tv_nsec: 216354553 } })
[2025-04-30T09:16:15.962060372Z TRACE quiche_server] Collecting garbage
[2025-04-30T09:16:15.962066574Z TRACE quiche_server] recv() would block
[2025-04-30T09:16:15.962070792Z TRACE quiche_server] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb done writing
[2025-04-30T09:16:15.962074438Z TRACE quiche_server] Collecting garbage
[2025-04-30T09:16:15.963098287Z TRACE quiche_server] got 57 bytes from [fd00:cafe:cafe::100]:54428 to [::]:443
[2025-04-30T09:16:15.963105731Z TRACE quiche_server] got packet Short dcid=82325ea2d31bfdc8239cefba8e4d6637da06a0cb key_phase=false
[2025-04-30T09:16:15.963111531Z TRACE quiche] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb rx pkt Short dcid=82325ea2d31bfdc8239cefba8e4d6637da06a0cb key_phase=false len=36 pn=5 
[2025-04-30T09:16:15.963117182Z TRACE quiche] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb rx frm ACK delay=0 blocks=[2..5] ecn_counts=None
[2025-04-30T09:16:15.963120608Z TRACE quiche::recovery::congestion::recovery] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb packet newly acked 4
[2025-04-30T09:16:15.963123253Z TRACE quiche::recovery::congestion::recovery] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb packet newly acked 5
[2025-04-30T09:16:15.963126770Z TRACE quiche] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb rx frm MAX_DATA max=16781191
[2025-04-30T09:16:15.963129555Z TRACE quiche] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb rx frm MAX_STREAM_DATA stream=0 max=68184
[2025-04-30T09:16:15.963140665Z TRACE quiche_server] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb processed 57 bytes
[2025-04-30T09:16:15.963149572Z TRACE quiche_server] recv() would block
[2025-04-30T09:16:15.963154180Z TRACE quiche] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb pmtud probe status false hs_con=true hs_sent=true cwnd_avail=3225 out_len=1350 left=1327
[2025-04-30T09:16:15.963157527Z TRACE quiche] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb tx pkt Short dcid= key_phase=false len=5 pn=17 
[2025-04-30T09:16:15.963160101Z TRACE quiche] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb tx frm ACK delay=5 blocks=[3..5] ecn_counts=None
[2025-04-30T09:16:15.963166152Z TRACE quiche::recovery::congestion::recovery] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb timer=95.681787ms latest_rtt=34.904293ms srtt=32.693867ms min_rtt=32.33471ms rttvar=9.790763ms cwnd=14850 ssthresh=18446744073709551615 bytes_in_flight=11625 app_limited=true congestion_recovery_start_time=None Rate { delivered: 5383, delivered_time: Instant { tv_sec: 682, tv_nsec: 218535586 }, first_sent_time: Instant { tv_sec: 682, tv_nsec: 183631293 }, end_of_app_limited: 0, last_sent_packet: 17, largest_acked: 5, rate_sample: RateSample { delivery_rate: 141393, is_app_limited: true, interval: 32.681783ms, delivered: 4621, prior_delivered: 762, prior_time: Some(Instant { tv_sec: 682, tv_nsec: 183631293 }), send_elapsed: 0ns, ack_elapsed: 32.681783ms, rtt: 32.681783ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 567767, last_update: Instant { tv_sec: 682, tv_nsec: 216354553 }, next_time: Instant { tv_sec: 682, tv_nsec: 216354553 }, max_datagram_size: 1350, last_packet_size: Some(0), iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(13) last_round_min_rtt=32.681783ms 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-30T09:16:15.963201358Z TRACE quiche_server] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb written 23 bytes with Some(SendInfo { from: [::]:443, to: [fd00:cafe:cafe::100]:54428, at: Instant { tv_sec: 682, tv_nsec: 216354553 } })
[2025-04-30T09:16:15.963209312Z TRACE quiche_server] Collecting garbage
[2025-04-30T09:16:15.963215033Z TRACE quiche_server] recv() would block
[2025-04-30T09:16:15.963219401Z TRACE quiche_server] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb done writing
[2025-04-30T09:16:15.963223258Z TRACE quiche_server] Collecting garbage
[2025-04-30T09:16:15.965356113Z TRACE quiche_server] got 57 bytes from [fd00:cafe:cafe::100]:54428 to [::]:443
[2025-04-30T09:16:15.965365360Z TRACE quiche_server] got packet Short dcid=82325ea2d31bfdc8239cefba8e4d6637da06a0cb key_phase=false
[2025-04-30T09:16:15.965372353Z TRACE quiche] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb rx pkt Short dcid=82325ea2d31bfdc8239cefba8e4d6637da06a0cb key_phase=false len=36 pn=6 
[2025-04-30T09:16:15.965378945Z TRACE quiche] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb rx frm ACK delay=0 blocks=[2..7] ecn_counts=None
[2025-04-30T09:16:15.965383323Z TRACE quiche::recovery::congestion::recovery] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb packet newly acked 6
[2025-04-30T09:16:15.965386519Z TRACE quiche::recovery::congestion::recovery] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb packet newly acked 7
[2025-04-30T09:16:15.965390727Z TRACE quiche] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb rx frm MAX_DATA max=16783843
[2025-04-30T09:16:15.965394073Z TRACE quiche] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb rx frm MAX_STREAM_DATA stream=0 max=69510
[2025-04-30T09:16:15.965406706Z TRACE quiche_server] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb processed 57 bytes
[2025-04-30T09:16:15.965411986Z TRACE quiche_server] recv() would block
[2025-04-30T09:16:15.965417697Z TRACE quiche] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb pmtud probe status false hs_con=true hs_sent=true cwnd_avail=5925 out_len=1350 left=1327
[2025-04-30T09:16:15.965421684Z TRACE quiche] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb tx pkt Short dcid= key_phase=false len=5 pn=18 
[2025-04-30T09:16:15.965424880Z TRACE quiche] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb tx frm ACK delay=5 blocks=[3..6] ecn_counts=None
[2025-04-30T09:16:15.965438606Z TRACE quiche::recovery::congestion::recovery] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb timer=88.648446ms latest_rtt=37.164925ms srtt=33.252748ms min_rtt=32.33471ms rttvar=8.460836ms cwnd=14850 ssthresh=18446744073709551615 bytes_in_flight=8925 app_limited=true congestion_recovery_start_time=None Rate { delivered: 8083, delivered_time: Instant { tv_sec: 682, tv_nsec: 220796218 }, first_sent_time: Instant { tv_sec: 682, tv_nsec: 183631293 }, end_of_app_limited: 0, last_sent_packet: 18, largest_acked: 7, rate_sample: RateSample { delivery_rate: 224008, is_app_limited: true, interval: 32.681783ms, delivered: 7321, prior_delivered: 762, prior_time: Some(Instant { tv_sec: 682, tv_nsec: 183631293 }), send_elapsed: 0ns, ack_elapsed: 32.681783ms, rtt: 32.681783ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 558224, last_update: Instant { tv_sec: 682, tv_nsec: 216354553 }, next_time: Instant { tv_sec: 682, tv_nsec: 216354553 }, max_datagram_size: 1350, last_packet_size: Some(0), iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(13) last_round_min_rtt=32.681783ms 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-30T09:16:15.965479241Z TRACE quiche_server] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb written 23 bytes with Some(SendInfo { from: [::]:443, to: [fd00:cafe:cafe::100]:54428, at: Instant { tv_sec: 682, tv_nsec: 216354553 } })
[2025-04-30T09:16:15.965488709Z TRACE quiche_server] Collecting garbage
[2025-04-30T09:16:15.965496303Z TRACE quiche_server] recv() would block
[2025-04-30T09:16:15.965502063Z TRACE quiche_server] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb done writing
[2025-04-30T09:16:15.965507143Z TRACE quiche_server] Collecting garbage
[2025-04-30T09:16:15.967482415Z TRACE quiche_server] got 51 bytes from [fd00:cafe:cafe::100]:54428 to [::]:443
[2025-04-30T09:16:15.967492133Z TRACE quiche_server] got packet Short dcid=82325ea2d31bfdc8239cefba8e4d6637da06a0cb key_phase=false
[2025-04-30T09:16:15.967499517Z TRACE quiche] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb rx pkt Short dcid=82325ea2d31bfdc8239cefba8e4d6637da06a0cb key_phase=false len=30 pn=7 
[2025-04-30T09:16:15.967506550Z TRACE quiche] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb rx frm ACK delay=0 blocks=[2..9] ecn_counts=None
[2025-04-30T09:16:15.967510918Z TRACE quiche::recovery::congestion::recovery] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb packet newly acked 8
[2025-04-30T09:16:15.967514164Z TRACE quiche::recovery::congestion::recovery] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb packet newly acked 9
[2025-04-30T09:16:15.967518392Z TRACE quiche] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb rx frm MAX_DATA max=16786315
[2025-04-30T09:16:15.967532989Z TRACE quiche_server] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb processed 51 bytes
[2025-04-30T09:16:15.967538339Z TRACE quiche_server] recv() would block
[2025-04-30T09:16:15.967544180Z TRACE quiche] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb pmtud probe status false hs_con=true hs_sent=true cwnd_avail=8445 out_len=1350 left=1327
[2025-04-30T09:16:15.967548227Z TRACE quiche] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb tx pkt Short dcid= key_phase=false len=5 pn=19 
[2025-04-30T09:16:15.967551403Z TRACE quiche] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb tx frm ACK delay=5 blocks=[3..7] ecn_counts=None
[2025-04-30T09:16:15.967558255Z TRACE quiche::recovery::congestion::recovery] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb timer=84.861872ms latest_rtt=39.291888ms srtt=34.00764ms min_rtt=32.33471ms rttvar=7.855412ms cwnd=14850 ssthresh=18446744073709551615 bytes_in_flight=6405 app_limited=true congestion_recovery_start_time=None Rate { delivered: 10603, delivered_time: Instant { tv_sec: 682, tv_nsec: 222923181 }, first_sent_time: Instant { tv_sec: 682, tv_nsec: 183631293 }, end_of_app_limited: 0, last_sent_packet: 19, largest_acked: 9, rate_sample: RateSample { delivery_rate: 301115, is_app_limited: true, interval: 32.681783ms, delivered: 9841, prior_delivered: 762, prior_time: Some(Instant { tv_sec: 682, tv_nsec: 183631293 }), send_elapsed: 0ns, ack_elapsed: 32.681783ms, rtt: 32.681783ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 545833, last_update: Instant { tv_sec: 682, tv_nsec: 216354553 }, next_time: Instant { tv_sec: 682, tv_nsec: 216354553 }, max_datagram_size: 1350, last_packet_size: Some(0), iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(13) last_round_min_rtt=32.681783ms 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-30T09:16:15.967627755Z TRACE quiche_server] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb written 23 bytes with Some(SendInfo { from: [::]:443, to: [fd00:cafe:cafe::100]:54428, at: Instant { tv_sec: 682, tv_nsec: 216354553 } })
[2025-04-30T09:16:15.967638494Z TRACE quiche_server] Collecting garbage
[2025-04-30T09:16:15.967646058Z TRACE quiche_server] recv() would block
[2025-04-30T09:16:15.967651929Z TRACE quiche_server] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb done writing
[2025-04-30T09:16:15.967657209Z TRACE quiche_server] Collecting garbage
[2025-04-30T09:16:15.969668979Z TRACE quiche_server] got 57 bytes from [fd00:cafe:cafe::100]:54428 to [::]:443
[2025-04-30T09:16:15.969676914Z TRACE quiche_server] got packet Short dcid=82325ea2d31bfdc8239cefba8e4d6637da06a0cb key_phase=false
[2025-04-30T09:16:15.969683486Z TRACE quiche] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb rx pkt Short dcid=82325ea2d31bfdc8239cefba8e4d6637da06a0cb key_phase=false len=36 pn=8 
[2025-04-30T09:16:15.969689968Z TRACE quiche] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb rx frm ACK delay=0 blocks=[2..11] ecn_counts=None
[2025-04-30T09:16:15.969694126Z TRACE quiche::recovery::congestion::recovery] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb packet newly acked 10
[2025-04-30T09:16:15.969697181Z TRACE quiche::recovery::congestion::recovery] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb packet newly acked 11
[2025-04-30T09:16:15.969701048Z TRACE quiche] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb rx frm MAX_DATA max=16788967
[2025-04-30T09:16:15.969704184Z TRACE quiche] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb rx frm MAX_STREAM_DATA stream=4 max=72167
[2025-04-30T09:16:15.969715846Z TRACE quiche_server] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb processed 57 bytes
[2025-04-30T09:16:15.969720735Z TRACE quiche_server] recv() would block
[2025-04-30T09:16:15.969731865Z TRACE quiche] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb pmtud probe status false hs_con=true hs_sent=true cwnd_avail=11145 out_len=1350 left=1327
[2025-04-30T09:16:15.969738177Z TRACE quiche] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb tx pkt Short dcid= key_phase=false len=5 pn=20 
[2025-04-30T09:16:15.969741243Z TRACE quiche] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb tx frm ACK delay=5 blocks=[3..8] ecn_counts=None
[2025-04-30T09:16:15.969747865Z TRACE quiche::recovery::congestion::recovery] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb timer=83.219221ms latest_rtt=41.476238ms srtt=34.941214ms min_rtt=32.33471ms rttvar=7.758708ms cwnd=14850 ssthresh=18446744073709551615 bytes_in_flight=3705 app_limited=true congestion_recovery_start_time=None Rate { delivered: 13303, delivered_time: Instant { tv_sec: 682, tv_nsec: 225107531 }, first_sent_time: Instant { tv_sec: 682, tv_nsec: 183631293 }, end_of_app_limited: 19, last_sent_packet: 20, largest_acked: 11, rate_sample: RateSample { delivery_rate: 383730, is_app_limited: true, interval: 32.681783ms, delivered: 12541, prior_delivered: 762, prior_time: Some(Instant { tv_sec: 682, tv_nsec: 183631293 }), send_elapsed: 0ns, ack_elapsed: 32.681783ms, rtt: 32.681783ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 531249, last_update: Instant { tv_sec: 682, tv_nsec: 216354553 }, next_time: Instant { tv_sec: 682, tv_nsec: 216354553 }, max_datagram_size: 1350, last_packet_size: Some(0), iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(13) last_round_min_rtt=32.681783ms 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-30T09:16:15.969792358Z TRACE quiche_server] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb written 23 bytes with Some(SendInfo { from: [::]:443, to: [fd00:cafe:cafe::100]:54428, at: Instant { tv_sec: 682, tv_nsec: 216354553 } })
[2025-04-30T09:16:15.969801525Z TRACE quiche_server] Collecting garbage
[2025-04-30T09:16:15.969808578Z TRACE quiche_server] recv() would block
[2025-04-30T09:16:15.969813988Z TRACE quiche_server] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb done writing
[2025-04-30T09:16:15.969818797Z TRACE quiche_server] Collecting garbage
[2025-04-30T09:16:15.992587511Z TRACE quiche_server] got 57 bytes from [fd00:cafe:cafe::100]:54428 to [::]:443
[2025-04-30T09:16:15.992602108Z TRACE quiche_server] got packet Short dcid=82325ea2d31bfdc8239cefba8e4d6637da06a0cb key_phase=false
[2025-04-30T09:16:15.992610774Z TRACE quiche] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb rx pkt Short dcid=82325ea2d31bfdc8239cefba8e4d6637da06a0cb key_phase=false len=36 pn=9 
[2025-04-30T09:16:15.992619300Z TRACE quiche] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb rx frm ACK delay=0 blocks=[2..13] ecn_counts=None
[2025-04-30T09:16:15.992624660Z TRACE quiche::recovery::congestion::recovery] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb packet newly acked 12
[2025-04-30T09:16:15.992628116Z TRACE quiche::recovery::congestion::recovery] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb packet newly acked 13
[2025-04-30T09:16:15.992632925Z TRACE quiche] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb rx frm MAX_DATA max=16791228
[2025-04-30T09:16:15.992636451Z TRACE quiche] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb rx frm MAX_STREAM_DATA stream=4 max=74428
[2025-04-30T09:16:15.992651920Z TRACE quiche_server] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb processed 57 bytes
[2025-04-30T09:16:15.992657811Z TRACE quiche_server] recv() would block
[2025-04-30T09:16:15.992664554Z TRACE quiche] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb pmtud probe status false hs_con=true hs_sent=true cwnd_avail=13454 out_len=1350 left=1327
[2025-04-30T09:16:15.992669202Z TRACE quiche] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb tx pkt Short dcid= key_phase=false len=5 pn=21 
[2025-04-30T09:16:15.992672598Z TRACE quiche] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb tx frm ACK delay=6 blocks=[3..9] ecn_counts=None
[2025-04-30T09:16:15.992680433Z TRACE quiche::recovery::congestion::recovery] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb timer=55.381518ms latest_rtt=31.679836ms srtt=34.533541ms min_rtt=31.679836ms rttvar=6.634375ms cwnd=14850 ssthresh=18446744073709551615 bytes_in_flight=1396 app_limited=true congestion_recovery_start_time=None Rate { delivered: 15612, delivered_time: Instant { tv_sec: 682, tv_nsec: 248034389 }, first_sent_time: Instant { tv_sec: 682, tv_nsec: 216354553 }, end_of_app_limited: 20, last_sent_packet: 21, largest_acked: 13, rate_sample: RateSample { delivery_rate: 395101, is_app_limited: false, interval: 32.72326ms, delivered: 12929, prior_delivered: 2683, prior_time: Some(Instant { tv_sec: 682, tv_nsec: 216313076 }), send_elapsed: 32.72326ms, ack_elapsed: 31.721313ms, rtt: 31.679836ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 537520, last_update: Instant { tv_sec: 682, tv_nsec: 248085884 }, next_time: Instant { tv_sec: 682, tv_nsec: 248085884 }, max_datagram_size: 1350, last_packet_size: Some(0), iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(13) last_round_min_rtt=32.681783ms 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-30T09:16:15.992728482Z TRACE quiche_server] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb written 23 bytes with Some(SendInfo { from: [::]:443, to: [fd00:cafe:cafe::100]:54428, at: Instant { tv_sec: 682, tv_nsec: 248085884 } })
[2025-04-30T09:16:15.992748028Z TRACE quiche_server] Collecting garbage
[2025-04-30T09:16:15.992755743Z TRACE quiche_server] recv() would block
[2025-04-30T09:16:15.992761563Z TRACE quiche_server] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb done writing
[2025-04-30T09:16:15.992766633Z TRACE quiche_server] Collecting garbage
[2025-04-30T09:16:15.993677131Z TRACE quiche_server] got 51 bytes from [fd00:cafe:cafe::100]:54428 to [::]:443
[2025-04-30T09:16:15.993684535Z TRACE quiche_server] got packet Short dcid=82325ea2d31bfdc8239cefba8e4d6637da06a0cb key_phase=false
[2025-04-30T09:16:15.993690155Z TRACE quiche] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb rx pkt Short dcid=82325ea2d31bfdc8239cefba8e4d6637da06a0cb key_phase=false len=30 pn=10 
[2025-04-30T09:16:15.993695715Z TRACE quiche] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb rx frm ACK delay=0 blocks=[2..15] ecn_counts=None
[2025-04-30T09:16:15.993699182Z TRACE quiche::recovery::congestion::recovery] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb packet newly acked 14
[2025-04-30T09:16:15.993701646Z TRACE quiche::recovery::congestion::recovery] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb packet newly acked 15
[2025-04-30T09:16:15.993704712Z TRACE quiche] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb rx frm MAX_DATA max=16792576
[2025-04-30T09:16:15.993727184Z TRACE quiche_server] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb processed 51 bytes
[2025-04-30T09:16:15.993731432Z TRACE quiche_server] recv() would block
[2025-04-30T09:16:15.993735980Z TRACE quiche] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb pmtud probe status false hs_con=true hs_sent=true cwnd_avail=14850 out_len=1350 left=1327
[2025-04-30T09:16:15.993739236Z TRACE quiche] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb tx pkt Short dcid= key_phase=false len=5 pn=22 
[2025-04-30T09:16:15.993741680Z TRACE quiche] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb tx frm ACK delay=5 blocks=[3..10] ecn_counts=None
[2025-04-30T09:16:15.993747351Z TRACE quiche::recovery::congestion::recovery] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb timer=none latest_rtt=32.759718ms srtt=34.311812ms min_rtt=31.679836ms rttvar=5.419236ms cwnd=14850 ssthresh=18446744073709551615 bytes_in_flight=0 app_limited=true congestion_recovery_start_time=None Rate { delivered: 17008, delivered_time: Instant { tv_sec: 682, tv_nsec: 248085884 }, first_sent_time: Instant { tv_sec: 682, tv_nsec: 248085884 }, end_of_app_limited: 21, last_sent_packet: 22, largest_acked: 15, rate_sample: RateSample { delivery_rate: 437762, is_app_limited: false, interval: 32.72326ms, delivered: 14325, prior_delivered: 2683, prior_time: Some(Instant { tv_sec: 682, tv_nsec: 216313076 }), send_elapsed: 32.72326ms, ack_elapsed: 31.721313ms, rtt: 31.679836ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 540994, last_update: Instant { tv_sec: 682, tv_nsec: 248085884 }, next_time: Instant { tv_sec: 682, tv_nsec: 248085884 }, max_datagram_size: 1350, last_packet_size: Some(0), iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(13) last_round_min_rtt=32.681783ms 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-30T09:16:15.993781114Z TRACE quiche_server] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb written 23 bytes with Some(SendInfo { from: [::]:443, to: [fd00:cafe:cafe::100]:54428, at: Instant { tv_sec: 682, tv_nsec: 248085884 } })
[2025-04-30T09:16:15.993789259Z TRACE quiche_server] Collecting garbage
[2025-04-30T09:16:15.993794839Z TRACE quiche_server] recv() would block
[2025-04-30T09:16:15.993799277Z TRACE quiche_server] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb done writing
[2025-04-30T09:16:15.993803074Z TRACE quiche_server] Collecting garbage
[2025-04-30T09:16:15.994835248Z TRACE quiche_server] got 1350 bytes from [fd00:cafe:cafe::100]:54428 to [::]:443
[2025-04-30T09:16:15.994841660Z TRACE quiche_server] got packet Short dcid=82325ea2d31bfdc8239cefba8e4d6637da06a0cb key_phase=false
[2025-04-30T09:16:15.994846990Z TRACE quiche] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb rx pkt Short dcid=82325ea2d31bfdc8239cefba8e4d6637da06a0cb key_phase=false len=1329 pn=11 
[2025-04-30T09:16:15.994857329Z TRACE quiche] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb rx frm PING mtu_probe=None
[2025-04-30T09:16:15.994864553Z TRACE quiche] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb rx frm PADDING len=1308
[2025-04-30T09:16:15.994870343Z TRACE quiche_server] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb processed 1350 bytes
[2025-04-30T09:16:15.994875583Z TRACE quiche_server] got 49 bytes from [fd00:cafe:cafe::100]:54428 to [::]:443
[2025-04-30T09:16:15.994878518Z TRACE quiche_server] got packet Short dcid=82325ea2d31bfdc8239cefba8e4d6637da06a0cb key_phase=false
[2025-04-30T09:16:15.994882676Z TRACE quiche] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb rx pkt Short dcid=82325ea2d31bfdc8239cefba8e4d6637da06a0cb key_phase=false len=28 pn=12 
[2025-04-30T09:16:15.994887024Z TRACE quiche] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb rx frm ACK delay=0 blocks=[6..17] ecn_counts=None
[2025-04-30T09:16:15.994890170Z TRACE quiche::recovery::congestion::recovery] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb packet newly acked 16
[2025-04-30T09:16:15.994892605Z TRACE quiche::recovery::congestion::recovery] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb packet newly acked 17
[2025-04-30T09:16:15.994895770Z TRACE quiche] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb rx frm APPLICATION_CLOSE err=0 reason=[]
[2025-04-30T09:16:15.994901711Z TRACE quiche_server] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb processed 49 bytes
[2025-04-30T09:16:15.994905178Z TRACE quiche_server] recv() would block
[2025-04-30T09:16:15.994907422Z TRACE quiche_server] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb done writing
[2025-04-30T09:16:15.994909606Z TRACE quiche_server] Collecting garbage
[2025-04-30T09:16:16.163122128Z TRACE quiche_server] timed out
[2025-04-30T09:16:16.163153486Z TRACE quiche] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb draining timeout expired
[2025-04-30T09:16:16.163193200Z TRACE quiche_server] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb done writing
[2025-04-30T09:16:16.163196556Z TRACE quiche_server] Collecting garbage
[2025-04-30T09:16:16.163199993Z INFO  quiche_server] 82325ea2d31bfdc8239cefba8e4d6637da06a0cb connection collected recv=13 sent=23 lost=0 retrans=0 sent_bytes=17315 recv_bytes=5628 lost_bytes=0 [local_addr=[::]:443 peer_addr=[fd00:cafe:cafe::100]:54428 validation_state=Validated active=true recv=13 sent=23 lost=0 retrans=0 rtt=34.311812ms min_rtt=Some(31.679836ms) rttvar=5.419236ms cwnd=14850 sent_bytes=17315 recv_bytes=5628 lost_bytes=0 stream_retrans_bytes=0 pmtu=1350 delivery_rate=355251]