[2025-04-30T10:37:57.713475833Z INFO  quiche_server] listening on [::]:443
[2025-04-30T10:37:57.713507662Z TRACE mio::poll] registering event source with poller: token=Token(0), interests=READABLE
[2025-04-30T10:37:57.713516719Z TRACE quiche_server] GSO detected: false
[2025-04-30T10:37:58.538235069Z TRACE quiche_server] got 1207 bytes from [::ffff:193.167.100.2]:42705 to [::]:443
[2025-04-30T10:37:58.538281596Z TRACE quiche_server] got packet Initial version=57414954 dcid= scid= token=
[2025-04-30T10:37:58.538292116Z WARN  quiche_server] Doing version negotiation
[2025-04-30T10:37:58.538408282Z TRACE quiche_server] got 1207 bytes from [::ffff:193.167.100.2]:42705 to [::]:443
[2025-04-30T10:37:58.538417600Z TRACE quiche_server] got packet Initial version=57414954 dcid= scid= token=
[2025-04-30T10:37:58.538423621Z WARN  quiche_server] Doing version negotiation
[2025-04-30T10:37:58.538454839Z TRACE quiche_server] got 1207 bytes from [::ffff:193.167.100.2]:42705 to [::]:443
[2025-04-30T10:37:58.538461341Z TRACE quiche_server] got packet Initial version=57414954 dcid= scid= token=
[2025-04-30T10:37:58.538466270Z WARN  quiche_server] Doing version negotiation
[2025-04-30T10:37:58.538490386Z TRACE quiche_server] recv() would block
[2025-04-30T10:37:58.747293358Z TRACE quiche_server] got 1280 bytes from [fd00:cafe:cafe::100]:60621 to [::]:443
[2025-04-30T10:37:58.747321250Z TRACE quiche_server] got packet Initial version=1 dcid=40c1b887a692e86963d89c6f1438a639b236 scid= token=
[2025-04-30T10:37:58.747330908Z DEBUG quiche_server] New connection: dcid=40c1b887a692e86963d89c6f1438a639b236 scid=d4f59da8da5b07ba05661845b11d9044a9aa0dcf
[2025-04-30T10:37:58.747548874Z TRACE quiche] d4f59da8da5b07ba05661845b11d9044a9aa0dcf rx pkt Initial version=1 dcid=40c1b887a692e86963d89c6f1438a639b236 scid= token= len=1252 pn=0 
[2025-04-30T10:37:58.747566327Z TRACE quiche] d4f59da8da5b07ba05661845b11d9044a9aa0dcf rx frm PADDING len=964
[2025-04-30T10:37:58.747570514Z TRACE quiche] d4f59da8da5b07ba05661845b11d9044a9aa0dcf rx frm CRYPTO off=0 len=266
[2025-04-30T10:37:58.747598366Z TRACE quiche::tls] checking peer ALPN Ok("hq-interop") against Ok("h3")
[2025-04-30T10:37:58.747602925Z TRACE quiche::tls] checking peer ALPN Ok("hq-interop") against Ok("hq-interop")
[2025-04-30T10:37:58.747704685Z TRACE quiche::tls] d4f59da8da5b07ba05661845b11d9044a9aa0dcf write message lvl=Initial len=90
[2025-04-30T10:37:58.747738678Z TRACE quiche::tls] d4f59da8da5b07ba05661845b11d9044a9aa0dcf set write secret lvl=Handshake
[2025-04-30T10:37:58.747815962Z TRACE quiche::tls] d4f59da8da5b07ba05661845b11d9044a9aa0dcf write message lvl=Handshake len=706
[2025-04-30T10:37:58.747819649Z TRACE quiche::tls] d4f59da8da5b07ba05661845b11d9044a9aa0dcf set write secret lvl=OneRTT
[2025-04-30T10:37:58.747827404Z TRACE quiche::tls] d4f59da8da5b07ba05661845b11d9044a9aa0dcf set read secret lvl=Handshake
[2025-04-30T10:37:58.747860716Z TRACE quiche_server] d4f59da8da5b07ba05661845b11d9044a9aa0dcf processed 1280 bytes
[2025-04-30T10:37:58.747874561Z TRACE quiche_server] recv() would block
[2025-04-30T10:37:58.747888227Z TRACE quiche] d4f59da8da5b07ba05661845b11d9044a9aa0dcf tx pkt Initial version=1 dcid= scid=d4f59da8da5b07ba05661845b11d9044a9aa0dcf len=99 pn=0 
[2025-04-30T10:37:58.747892245Z TRACE quiche] d4f59da8da5b07ba05661845b11d9044a9aa0dcf tx frm ACK delay=44 blocks=[0..0] ecn_counts=None
[2025-04-30T10:37:58.747898306Z TRACE quiche] d4f59da8da5b07ba05661845b11d9044a9aa0dcf tx frm CRYPTO off=0 len=90
[2025-04-30T10:37:58.747908825Z TRACE quiche::recovery::congestion::recovery] d4f59da8da5b07ba05661845b11d9044a9aa0dcf timer=998.96785ms 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: 656, tv_nsec: 226932282 }, first_sent_time: Instant { tv_sec: 656, tv_nsec: 226932282 }, 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: 656, tv_nsec: 226932282 }, next_time: Instant { tv_sec: 656, tv_nsec: 226932282 }, max_datagram_size: 1350, last_packet_size: None, iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } 
[2025-04-30T10:37:58.747940755Z TRACE quiche] d4f59da8da5b07ba05661845b11d9044a9aa0dcf tx pkt Handshake version=1 dcid= scid=d4f59da8da5b07ba05661845b11d9044a9aa0dcf len=710 pn=1 
[2025-04-30T10:37:58.747944392Z TRACE quiche] d4f59da8da5b07ba05661845b11d9044a9aa0dcf tx frm CRYPTO off=0 len=706
[2025-04-30T10:37:58.747991329Z TRACE quiche::recovery::congestion::recovery] d4f59da8da5b07ba05661845b11d9044a9aa0dcf timer=998.885326ms latest_rtt=0ns srtt=333ms min_rtt=333ms rttvar=166.5ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=902 app_limited=true congestion_recovery_start_time=None Rate { delivered: 0, delivered_time: Instant { tv_sec: 656, tv_nsec: 226932282 }, first_sent_time: Instant { tv_sec: 656, tv_nsec: 226932282 }, 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: 656, tv_nsec: 226932282 }, next_time: Instant { tv_sec: 656, tv_nsec: 226932282 }, max_datagram_size: 1350, last_packet_size: None, iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } 
[2025-04-30T10:37:58.748036243Z TRACE quiche_server] d4f59da8da5b07ba05661845b11d9044a9aa0dcf written 1200 bytes with Some(SendInfo { from: [::]:443, to: [fd00:cafe:cafe::100]:60621, at: Instant { tv_sec: 656, tv_nsec: 226932282 } })
[2025-04-30T10:37:58.748043076Z TRACE quiche_server] Collecting garbage
[2025-04-30T10:37:58.748050259Z TRACE quiche_server] recv() would block
[2025-04-30T10:37:58.748057643Z TRACE quiche_server] d4f59da8da5b07ba05661845b11d9044a9aa0dcf done writing
[2025-04-30T10:37:58.748061911Z TRACE quiche_server] Collecting garbage
[2025-04-30T10:37:58.781552305Z TRACE quiche_server] got 1280 bytes from [fd00:cafe:cafe::100]:60621 to [::]:443
[2025-04-30T10:37:58.781581570Z TRACE quiche_server] got packet Initial version=1 dcid=d4f59da8da5b07ba05661845b11d9044a9aa0dcf scid= token=
[2025-04-30T10:37:58.781594734Z TRACE quiche] d4f59da8da5b07ba05661845b11d9044a9aa0dcf rx pkt Initial version=1 dcid=d4f59da8da5b07ba05661845b11d9044a9aa0dcf scid= token= len=1164 pn=1 
[2025-04-30T10:37:58.781607949Z TRACE quiche] d4f59da8da5b07ba05661845b11d9044a9aa0dcf rx frm ACK delay=0 blocks=[0..0] ecn_counts=None
[2025-04-30T10:37:58.781616565Z TRACE quiche::recovery::congestion::recovery] d4f59da8da5b07ba05661845b11d9044a9aa0dcf packet newly acked 0
[2025-04-30T10:37:58.781633406Z TRACE quiche] d4f59da8da5b07ba05661845b11d9044a9aa0dcf rx frm PADDING len=1141
[2025-04-30T10:37:58.781666247Z TRACE quiche] d4f59da8da5b07ba05661845b11d9044a9aa0dcf rx pkt Handshake version=1 dcid=d4f59da8da5b07ba05661845b11d9044a9aa0dcf scid= len=57 pn=0 
[2025-04-30T10:37:58.781677108Z TRACE quiche] d4f59da8da5b07ba05661845b11d9044a9aa0dcf rx frm CRYPTO off=0 len=36
[2025-04-30T10:37:58.781701163Z TRACE quiche::tls] d4f59da8da5b07ba05661845b11d9044a9aa0dcf set read secret lvl=OneRTT
[2025-04-30T10:37:58.781728133Z TRACE quiche] d4f59da8da5b07ba05661845b11d9044a9aa0dcf dropped epoch 1 state
[2025-04-30T10:37:58.781732932Z TRACE quiche] d4f59da8da5b07ba05661845b11d9044a9aa0dcf connection established: proto=Ok("hq-interop") cipher=Some(AES128_GCM) curve=Some("X25519") sigalg=None resumed=false TransportParams { original_destination_connection_id: None, max_idle_timeout: 30000, stateless_reset_token: None, max_udp_payload_size: 1452, initial_max_data: 786432, initial_max_stream_data_bidi_local: 524288, initial_max_stream_data_bidi_remote: 524288, initial_max_stream_data_uni: 524288, initial_max_streams_bidi: 100, initial_max_streams_uni: 100, ack_delay_exponent: 3, max_ack_delay: 26, disable_active_migration: false, active_conn_id_limit: 4, initial_source_connection_id: Some(), retry_source_connection_id: None, max_datagram_frame_size: None, unknown_params: None }
[2025-04-30T10:37:58.781764902Z TRACE quiche] d4f59da8da5b07ba05661845b11d9044a9aa0dcf dropped epoch 0 state
[2025-04-30T10:37:58.781768669Z TRACE quiche_server] d4f59da8da5b07ba05661845b11d9044a9aa0dcf processed 1280 bytes
[2025-04-30T10:37:58.781778687Z TRACE quiche_server] got 52 bytes from [fd00:cafe:cafe::100]:60621 to [::]:443
[2025-04-30T10:37:58.781783075Z TRACE quiche_server] got packet Handshake version=1 dcid=d4f59da8da5b07ba05661845b11d9044a9aa0dcf scid=
[2025-04-30T10:37:58.781788886Z TRACE quiche] d4f59da8da5b07ba05661845b11d9044a9aa0dcf dropped invalid packet
[2025-04-30T10:37:58.781792052Z TRACE quiche_server] d4f59da8da5b07ba05661845b11d9044a9aa0dcf processed 52 bytes
[2025-04-30T10:37:58.781797192Z TRACE quiche_server] got 58 bytes from [fd00:cafe:cafe::100]:60621 to [::]:443
[2025-04-30T10:37:58.781800718Z TRACE quiche_server] got packet Short dcid=d4f59da8da5b07ba05661845b11d9044a9aa0dcf key_phase=false
[2025-04-30T10:37:58.781805587Z TRACE quiche] d4f59da8da5b07ba05661845b11d9044a9aa0dcf rx pkt Short dcid=d4f59da8da5b07ba05661845b11d9044a9aa0dcf key_phase=false len=37 pn=0 
[2025-04-30T10:37:58.781811669Z TRACE quiche] d4f59da8da5b07ba05661845b11d9044a9aa0dcf rx frm STREAM id=0 off=0 len=17 fin=true
[2025-04-30T10:37:58.781819934Z TRACE quiche_server] d4f59da8da5b07ba05661845b11d9044a9aa0dcf processed 58 bytes
[2025-04-30T10:37:58.781823220Z DEBUG quiche_apps::common] d4f59da8da5b07ba05661845b11d9044a9aa0dcf response stream 0 is writable with capacity Ok(13500)
[2025-04-30T10:37:58.781830564Z TRACE quiche_apps::common] d4f59da8da5b07ba05661845b11d9044a9aa0dcf received 17 bytes
[2025-04-30T10:37:58.781833690Z TRACE quiche_apps::common] d4f59da8da5b07ba05661845b11d9044a9aa0dcf stream 0 has 17 bytes (fin? true)
[2025-04-30T10:37:58.781838789Z INFO  quiche_apps::common] d4f59da8da5b07ba05661845b11d9044a9aa0dcf got GET request for "/www/hjzjjtcejz" on stream 0
[2025-04-30T10:37:58.781868996Z INFO  quiche_apps::common] d4f59da8da5b07ba05661845b11d9044a9aa0dcf sending response of size 10240 on stream 0
[2025-04-30T10:37:58.781879255Z TRACE quiche_server] got 58 bytes from [fd00:cafe:cafe::100]:60621 to [::]:443
[2025-04-30T10:37:58.781882821Z TRACE quiche_server] got packet Short dcid=d4f59da8da5b07ba05661845b11d9044a9aa0dcf key_phase=false
[2025-04-30T10:37:58.781887510Z TRACE quiche] d4f59da8da5b07ba05661845b11d9044a9aa0dcf rx pkt Short dcid=d4f59da8da5b07ba05661845b11d9044a9aa0dcf key_phase=false len=37 pn=1 
[2025-04-30T10:37:58.781892660Z TRACE quiche] d4f59da8da5b07ba05661845b11d9044a9aa0dcf rx frm STREAM id=4 off=0 len=17 fin=true
[2025-04-30T10:37:58.781898380Z TRACE quiche_server] d4f59da8da5b07ba05661845b11d9044a9aa0dcf processed 58 bytes
[2025-04-30T10:37:58.781901406Z DEBUG quiche_apps::common] d4f59da8da5b07ba05661845b11d9044a9aa0dcf response stream 4 is writable with capacity Ok(13500)
[2025-04-30T10:37:58.781905664Z TRACE quiche_apps::common] d4f59da8da5b07ba05661845b11d9044a9aa0dcf received 17 bytes
[2025-04-30T10:37:58.781908589Z TRACE quiche_apps::common] d4f59da8da5b07ba05661845b11d9044a9aa0dcf stream 4 has 17 bytes (fin? true)
[2025-04-30T10:37:58.781911966Z INFO  quiche_apps::common] d4f59da8da5b07ba05661845b11d9044a9aa0dcf got GET request for "/www/rlakwuminw" on stream 4
[2025-04-30T10:37:58.781927184Z INFO  quiche_apps::common] d4f59da8da5b07ba05661845b11d9044a9aa0dcf sending response of size 5120 on stream 4
[2025-04-30T10:37:58.781938936Z TRACE quiche_server] recv() would block
[2025-04-30T10:37:58.781971917Z TRACE quiche] d4f59da8da5b07ba05661845b11d9044a9aa0dcf pmtud probe status false hs_con=true hs_sent=false cwnd_avail=13500 out_len=1350 left=1327
[2025-04-30T10:37:58.781986274Z TRACE quiche] d4f59da8da5b07ba05661845b11d9044a9aa0dcf tx pkt Short dcid= key_phase=false len=1332 pn=2 
[2025-04-30T10:37:58.781989670Z TRACE quiche] d4f59da8da5b07ba05661845b11d9044a9aa0dcf tx frm ACK delay=10 blocks=[0..1] ecn_counts=None
[2025-04-30T10:37:58.781993898Z TRACE quiche] d4f59da8da5b07ba05661845b11d9044a9aa0dcf tx frm NEW_CONNECTION_ID seq_num=1 retire_prior_to=0 conn_id=[74, 22, 83, 81, d2, ad, a9, d6, 63, 6d, e4, b3, f2, 7c, 85, e4, 4e, 25, 66, 56] reset_token=[f8, 22, 56, 1d, d7, 04, 58, 82, 82, 72, 3b, 95, 0f, e7, ea, ed]
[2025-04-30T10:37:58.782002294Z TRACE quiche] d4f59da8da5b07ba05661845b11d9044a9aa0dcf tx frm NEW_CONNECTION_ID seq_num=2 retire_prior_to=0 conn_id=[c2, 97, 6a, 31, 1e, 55, 68, 4c, 0b, e7, 4e, 8a, 0a, 08, e8, 4a, 9b, ec, 81, ed] reset_token=[c4, e3, 68, d2, 6c, ec, 49, 9f, 98, 1e, 2d, 8a, 2f, 0f, 37, 14]
[2025-04-30T10:37:58.782008957Z TRACE quiche] d4f59da8da5b07ba05661845b11d9044a9aa0dcf tx frm NEW_CONNECTION_ID seq_num=3 retire_prior_to=0 conn_id=[c4, 95, 12, 93, cc, b2, 4a, ed, 09, 4e, be, d5, ab, 08, eb, 0d, 55, 0f, 12, 53] reset_token=[34, 0d, e5, 94, be, 05, 78, d2, 1d, e7, b2, 4d, 97, 8f, a2, f7]
[2025-04-30T10:37:58.782015589Z TRACE quiche] d4f59da8da5b07ba05661845b11d9044a9aa0dcf tx frm HANDSHAKE_DONE
[2025-04-30T10:37:58.782018494Z TRACE quiche] d4f59da8da5b07ba05661845b11d9044a9aa0dcf tx frm STREAM id=0 off=0 len=1201 fin=false
[2025-04-30T10:37:58.782032110Z TRACE quiche::recovery::congestion::recovery] d4f59da8da5b07ba05661845b11d9044a9aa0dcf timer=127.052177ms latest_rtt=33.714312ms srtt=33.714312ms min_rtt=33.714312ms rttvar=16.857156ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=1350 app_limited=true congestion_recovery_start_time=None Rate { delivered: 146, delivered_time: Instant { tv_sec: 656, tv_nsec: 260996737 }, first_sent_time: Instant { tv_sec: 656, tv_nsec: 260996737 }, end_of_app_limited: 1, last_sent_packet: 2, largest_acked: 0, rate_sample: RateSample { delivery_rate: 4330, is_app_limited: true, interval: 33.714312ms, delivered: 146, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 656, tv_nsec: 226932282 }), send_elapsed: 0ns, ack_elapsed: 33.714312ms, rtt: 33.714312ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 500529, last_update: Instant { tv_sec: 656, tv_nsec: 260996737 }, next_time: Instant { tv_sec: 656, tv_nsec: 260996737 }, max_datagram_size: 1350, last_packet_size: Some(0), iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } 
[2025-04-30T10:37:58.782052297Z TRACE quiche] d4f59da8da5b07ba05661845b11d9044a9aa0dcf pmtud probe status false hs_con=true hs_sent=true cwnd_avail=12150 out_len=1350 left=1332
[2025-04-30T10:37:58.782056445Z TRACE quiche] d4f59da8da5b07ba05661845b11d9044a9aa0dcf tx pkt Short dcid= key_phase=false len=1332 pn=3 
[2025-04-30T10:37:58.782059521Z TRACE quiche] d4f59da8da5b07ba05661845b11d9044a9aa0dcf tx frm STREAM id=4 off=0 len=1327 fin=false
[2025-04-30T10:37:58.782065562Z TRACE quiche::recovery::congestion::recovery] d4f59da8da5b07ba05661845b11d9044a9aa0dcf timer=127.127447ms latest_rtt=33.714312ms srtt=33.714312ms min_rtt=33.714312ms rttvar=16.857156ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=2700 app_limited=true congestion_recovery_start_time=None Rate { delivered: 146, delivered_time: Instant { tv_sec: 656, tv_nsec: 260996737 }, first_sent_time: Instant { tv_sec: 656, tv_nsec: 260996737 }, end_of_app_limited: 1, last_sent_packet: 3, largest_acked: 0, rate_sample: RateSample { delivery_rate: 4330, is_app_limited: true, interval: 33.714312ms, delivered: 146, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 656, tv_nsec: 226932282 }), send_elapsed: 0ns, ack_elapsed: 33.714312ms, rtt: 33.714312ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 500529, last_update: Instant { tv_sec: 656, tv_nsec: 260996737 }, next_time: Instant { tv_sec: 656, tv_nsec: 260996737 }, max_datagram_size: 1350, last_packet_size: Some(0), iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } 
[2025-04-30T10:37:58.782082494Z TRACE quiche] d4f59da8da5b07ba05661845b11d9044a9aa0dcf pmtud probe status false hs_con=true hs_sent=true cwnd_avail=10800 out_len=1350 left=1332
[2025-04-30T10:37:58.782086481Z TRACE quiche] d4f59da8da5b07ba05661845b11d9044a9aa0dcf tx pkt Short dcid= key_phase=false len=1332 pn=4 
[2025-04-30T10:37:58.782089497Z TRACE quiche] d4f59da8da5b07ba05661845b11d9044a9aa0dcf tx frm STREAM id=0 off=1201 len=1326 fin=false
[2025-04-30T10:37:58.782095117Z TRACE quiche::recovery::congestion::recovery] d4f59da8da5b07ba05661845b11d9044a9aa0dcf timer=127.12896ms latest_rtt=33.714312ms srtt=33.714312ms min_rtt=33.714312ms rttvar=16.857156ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=4050 app_limited=true congestion_recovery_start_time=None Rate { delivered: 146, delivered_time: Instant { tv_sec: 656, tv_nsec: 260996737 }, first_sent_time: Instant { tv_sec: 656, tv_nsec: 260996737 }, end_of_app_limited: 1, last_sent_packet: 4, largest_acked: 0, rate_sample: RateSample { delivery_rate: 4330, is_app_limited: true, interval: 33.714312ms, delivered: 146, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 656, tv_nsec: 226932282 }), send_elapsed: 0ns, ack_elapsed: 33.714312ms, rtt: 33.714312ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 500529, last_update: Instant { tv_sec: 656, tv_nsec: 260996737 }, next_time: Instant { tv_sec: 656, tv_nsec: 260996737 }, max_datagram_size: 1350, last_packet_size: Some(0), iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } 
[2025-04-30T10:37:58.782106559Z TRACE quiche] d4f59da8da5b07ba05661845b11d9044a9aa0dcf pmtud probe status false hs_con=true hs_sent=true cwnd_avail=9450 out_len=1350 left=1332
[2025-04-30T10:37:58.782110235Z TRACE quiche] d4f59da8da5b07ba05661845b11d9044a9aa0dcf tx pkt Short dcid= key_phase=false len=1332 pn=5 
[2025-04-30T10:37:58.782113151Z TRACE quiche] d4f59da8da5b07ba05661845b11d9044a9aa0dcf tx frm STREAM id=4 off=1327 len=1326 fin=false
[2025-04-30T10:37:58.782118421Z TRACE quiche::recovery::congestion::recovery] d4f59da8da5b07ba05661845b11d9044a9aa0dcf timer=127.129972ms latest_rtt=33.714312ms srtt=33.714312ms min_rtt=33.714312ms rttvar=16.857156ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=5400 app_limited=true congestion_recovery_start_time=None Rate { delivered: 146, delivered_time: Instant { tv_sec: 656, tv_nsec: 260996737 }, first_sent_time: Instant { tv_sec: 656, tv_nsec: 260996737 }, end_of_app_limited: 1, last_sent_packet: 5, largest_acked: 0, rate_sample: RateSample { delivery_rate: 4330, is_app_limited: true, interval: 33.714312ms, delivered: 146, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 656, tv_nsec: 226932282 }), send_elapsed: 0ns, ack_elapsed: 33.714312ms, rtt: 33.714312ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 500529, last_update: Instant { tv_sec: 656, tv_nsec: 260996737 }, next_time: Instant { tv_sec: 656, tv_nsec: 260996737 }, max_datagram_size: 1350, last_packet_size: Some(0), iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } 
[2025-04-30T10:37:58.782132828Z TRACE quiche] d4f59da8da5b07ba05661845b11d9044a9aa0dcf pmtud probe status false hs_con=true hs_sent=true cwnd_avail=8100 out_len=1350 left=1332
[2025-04-30T10:37:58.782136524Z TRACE quiche] d4f59da8da5b07ba05661845b11d9044a9aa0dcf tx pkt Short dcid= key_phase=false len=1332 pn=6 
[2025-04-30T10:37:58.782139530Z TRACE quiche] d4f59da8da5b07ba05661845b11d9044a9aa0dcf tx frm STREAM id=0 off=2527 len=1326 fin=false
[2025-04-30T10:37:58.782145070Z TRACE quiche::recovery::congestion::recovery] d4f59da8da5b07ba05661845b11d9044a9aa0dcf timer=127.129551ms latest_rtt=33.714312ms srtt=33.714312ms min_rtt=33.714312ms rttvar=16.857156ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=6750 app_limited=true congestion_recovery_start_time=None Rate { delivered: 146, delivered_time: Instant { tv_sec: 656, tv_nsec: 260996737 }, first_sent_time: Instant { tv_sec: 656, tv_nsec: 260996737 }, end_of_app_limited: 1, last_sent_packet: 6, largest_acked: 0, rate_sample: RateSample { delivery_rate: 4330, is_app_limited: true, interval: 33.714312ms, delivered: 146, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 656, tv_nsec: 226932282 }), send_elapsed: 0ns, ack_elapsed: 33.714312ms, rtt: 33.714312ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 500529, last_update: Instant { tv_sec: 656, tv_nsec: 260996737 }, next_time: Instant { tv_sec: 656, tv_nsec: 260996737 }, max_datagram_size: 1350, last_packet_size: Some(0), iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } 
[2025-04-30T10:37:58.782156241Z TRACE quiche] d4f59da8da5b07ba05661845b11d9044a9aa0dcf pmtud probe status false hs_con=true hs_sent=true cwnd_avail=6750 out_len=1350 left=1332
[2025-04-30T10:37:58.782159958Z TRACE quiche] d4f59da8da5b07ba05661845b11d9044a9aa0dcf tx pkt Short dcid= key_phase=false len=1332 pn=7 
[2025-04-30T10:37:58.782162864Z TRACE quiche] d4f59da8da5b07ba05661845b11d9044a9aa0dcf tx frm STREAM id=4 off=2653 len=1326 fin=false
[2025-04-30T10:37:58.782168223Z TRACE quiche::recovery::congestion::recovery] d4f59da8da5b07ba05661845b11d9044a9aa0dcf timer=127.129822ms latest_rtt=33.714312ms srtt=33.714312ms min_rtt=33.714312ms rttvar=16.857156ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=8100 app_limited=true congestion_recovery_start_time=None Rate { delivered: 146, delivered_time: Instant { tv_sec: 656, tv_nsec: 260996737 }, first_sent_time: Instant { tv_sec: 656, tv_nsec: 260996737 }, end_of_app_limited: 1, last_sent_packet: 7, largest_acked: 0, rate_sample: RateSample { delivery_rate: 4330, is_app_limited: true, interval: 33.714312ms, delivered: 146, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 656, tv_nsec: 226932282 }), send_elapsed: 0ns, ack_elapsed: 33.714312ms, rtt: 33.714312ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 500529, last_update: Instant { tv_sec: 656, tv_nsec: 260996737 }, next_time: Instant { tv_sec: 656, tv_nsec: 260996737 }, max_datagram_size: 1350, last_packet_size: Some(0), iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } 
[2025-04-30T10:37:58.782179254Z TRACE quiche] d4f59da8da5b07ba05661845b11d9044a9aa0dcf pmtud probe status false hs_con=true hs_sent=true cwnd_avail=5400 out_len=1350 left=1332
[2025-04-30T10:37:58.782182851Z TRACE quiche] d4f59da8da5b07ba05661845b11d9044a9aa0dcf tx pkt Short dcid= key_phase=false len=1332 pn=8 
[2025-04-30T10:37:58.782185856Z TRACE quiche] d4f59da8da5b07ba05661845b11d9044a9aa0dcf tx frm STREAM id=0 off=3853 len=1326 fin=false
[2025-04-30T10:37:58.782194402Z TRACE quiche::recovery::congestion::recovery] d4f59da8da5b07ba05661845b11d9044a9aa0dcf timer=127.126616ms latest_rtt=33.714312ms srtt=33.714312ms min_rtt=33.714312ms rttvar=16.857156ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=9450 app_limited=true congestion_recovery_start_time=None Rate { delivered: 146, delivered_time: Instant { tv_sec: 656, tv_nsec: 260996737 }, first_sent_time: Instant { tv_sec: 656, tv_nsec: 260996737 }, end_of_app_limited: 1, last_sent_packet: 8, largest_acked: 0, rate_sample: RateSample { delivery_rate: 4330, is_app_limited: true, interval: 33.714312ms, delivered: 146, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 656, tv_nsec: 226932282 }), send_elapsed: 0ns, ack_elapsed: 33.714312ms, rtt: 33.714312ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 500529, last_update: Instant { tv_sec: 656, tv_nsec: 260996737 }, next_time: Instant { tv_sec: 656, tv_nsec: 260996737 }, max_datagram_size: 1350, last_packet_size: Some(0), iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } 
[2025-04-30T10:37:58.782205673Z TRACE quiche] d4f59da8da5b07ba05661845b11d9044a9aa0dcf pmtud probe status false hs_con=true hs_sent=true cwnd_avail=4050 out_len=1350 left=1332
[2025-04-30T10:37:58.782209410Z TRACE quiche] d4f59da8da5b07ba05661845b11d9044a9aa0dcf tx pkt Short dcid= key_phase=false len=1147 pn=9 
[2025-04-30T10:37:58.782212386Z TRACE quiche] d4f59da8da5b07ba05661845b11d9044a9aa0dcf tx frm STREAM id=4 off=3979 len=1141 fin=true
[2025-04-30T10:37:58.782217766Z TRACE quiche::recovery::congestion::recovery] d4f59da8da5b07ba05661845b11d9044a9aa0dcf timer=127.129711ms latest_rtt=33.714312ms srtt=33.714312ms min_rtt=33.714312ms rttvar=16.857156ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=10615 app_limited=true congestion_recovery_start_time=None Rate { delivered: 146, delivered_time: Instant { tv_sec: 656, tv_nsec: 260996737 }, first_sent_time: Instant { tv_sec: 656, tv_nsec: 260996737 }, end_of_app_limited: 1, last_sent_packet: 9, largest_acked: 0, rate_sample: RateSample { delivery_rate: 4330, is_app_limited: true, interval: 33.714312ms, delivered: 146, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 656, tv_nsec: 226932282 }), send_elapsed: 0ns, ack_elapsed: 33.714312ms, rtt: 33.714312ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 500529, last_update: Instant { tv_sec: 656, tv_nsec: 260996737 }, next_time: Instant { tv_sec: 656, tv_nsec: 260996737 }, max_datagram_size: 1350, last_packet_size: Some(0), iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } 
[2025-04-30T10:37:58.782377303Z TRACE quiche_server] d4f59da8da5b07ba05661845b11d9044a9aa0dcf written 10615 bytes with Some(SendInfo { from: [::]:443, to: [fd00:cafe:cafe::100]:60621, at: Instant { tv_sec: 656, tv_nsec: 260996737 } })
[2025-04-30T10:37:58.782387943Z TRACE quiche_server] Collecting garbage
[2025-04-30T10:37:58.782394916Z TRACE quiche_server] recv() would block
[2025-04-30T10:37:58.782401468Z TRACE quiche] d4f59da8da5b07ba05661845b11d9044a9aa0dcf pmtud probe status false hs_con=true hs_sent=true cwnd_avail=2885 out_len=1350 left=1332
[2025-04-30T10:37:58.782407890Z TRACE quiche] d4f59da8da5b07ba05661845b11d9044a9aa0dcf tx pkt Short dcid= key_phase=false len=1332 pn=10 
[2025-04-30T10:37:58.782411908Z TRACE quiche] d4f59da8da5b07ba05661845b11d9044a9aa0dcf tx frm STREAM id=0 off=5179 len=1326 fin=false
[2025-04-30T10:37:58.782423519Z TRACE quiche::recovery::congestion::recovery] d4f59da8da5b07ba05661845b11d9044a9aa0dcf timer=127.116928ms latest_rtt=33.714312ms srtt=33.714312ms min_rtt=33.714312ms rttvar=16.857156ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=11965 app_limited=true congestion_recovery_start_time=None Rate { delivered: 146, delivered_time: Instant { tv_sec: 656, tv_nsec: 260996737 }, first_sent_time: Instant { tv_sec: 656, tv_nsec: 260996737 }, end_of_app_limited: 1, last_sent_packet: 10, largest_acked: 0, rate_sample: RateSample { delivery_rate: 4330, is_app_limited: true, interval: 33.714312ms, delivered: 146, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 656, tv_nsec: 226932282 }), send_elapsed: 0ns, ack_elapsed: 33.714312ms, rtt: 33.714312ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 500529, last_update: Instant { tv_sec: 656, tv_nsec: 260996737 }, next_time: Instant { tv_sec: 656, tv_nsec: 260996737 }, max_datagram_size: 1350, last_packet_size: Some(0), iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } 
[2025-04-30T10:37:58.782449909Z TRACE quiche] d4f59da8da5b07ba05661845b11d9044a9aa0dcf pmtud probe status false hs_con=true hs_sent=true cwnd_avail=1535 out_len=1350 left=1332
[2025-04-30T10:37:58.782453656Z TRACE quiche] d4f59da8da5b07ba05661845b11d9044a9aa0dcf tx pkt Short dcid= key_phase=false len=1332 pn=11 
[2025-04-30T10:37:58.782456200Z TRACE quiche] d4f59da8da5b07ba05661845b11d9044a9aa0dcf tx frm STREAM id=0 off=6505 len=1326 fin=false
[2025-04-30T10:37:58.782461761Z TRACE quiche::recovery::congestion::recovery] d4f59da8da5b07ba05661845b11d9044a9aa0dcf timer=127.12922ms latest_rtt=33.714312ms srtt=33.714312ms min_rtt=33.714312ms rttvar=16.857156ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=13315 app_limited=true congestion_recovery_start_time=None Rate { delivered: 146, delivered_time: Instant { tv_sec: 656, tv_nsec: 260996737 }, first_sent_time: Instant { tv_sec: 656, tv_nsec: 260996737 }, end_of_app_limited: 1, last_sent_packet: 11, largest_acked: 0, rate_sample: RateSample { delivery_rate: 4330, is_app_limited: true, interval: 33.714312ms, delivered: 146, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 656, tv_nsec: 226932282 }), send_elapsed: 0ns, ack_elapsed: 33.714312ms, rtt: 33.714312ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 500529, last_update: Instant { tv_sec: 656, tv_nsec: 260996737 }, next_time: Instant { tv_sec: 656, tv_nsec: 260996737 }, max_datagram_size: 1350, last_packet_size: Some(0), iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } 
[2025-04-30T10:37:58.782471800Z TRACE quiche] d4f59da8da5b07ba05661845b11d9044a9aa0dcf pmtud probe status false hs_con=true hs_sent=true cwnd_avail=185 out_len=1350 left=167
[2025-04-30T10:37:58.782474715Z TRACE quiche] d4f59da8da5b07ba05661845b11d9044a9aa0dcf tx pkt Short dcid= key_phase=false len=167 pn=12 
[2025-04-30T10:37:58.782477099Z TRACE quiche] d4f59da8da5b07ba05661845b11d9044a9aa0dcf tx frm STREAM id=0 off=7831 len=161 fin=false
[2025-04-30T10:37:58.782481598Z TRACE quiche::recovery::congestion::recovery] d4f59da8da5b07ba05661845b11d9044a9aa0dcf timer=127.132176ms latest_rtt=33.714312ms srtt=33.714312ms min_rtt=33.714312ms rttvar=16.857156ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=13500 app_limited=false congestion_recovery_start_time=None Rate { delivered: 146, delivered_time: Instant { tv_sec: 656, tv_nsec: 260996737 }, first_sent_time: Instant { tv_sec: 656, tv_nsec: 260996737 }, end_of_app_limited: 1, last_sent_packet: 12, largest_acked: 0, rate_sample: RateSample { delivery_rate: 4330, is_app_limited: true, interval: 33.714312ms, delivered: 146, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 656, tv_nsec: 226932282 }), send_elapsed: 0ns, ack_elapsed: 33.714312ms, rtt: 33.714312ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 500529, last_update: Instant { tv_sec: 656, tv_nsec: 260996737 }, next_time: Instant { tv_sec: 656, tv_nsec: 260996737 }, max_datagram_size: 1350, last_packet_size: Some(0), iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } 
[2025-04-30T10:37:58.782531561Z TRACE quiche_server] d4f59da8da5b07ba05661845b11d9044a9aa0dcf written 2885 bytes with Some(SendInfo { from: [::]:443, to: [fd00:cafe:cafe::100]:60621, at: Instant { tv_sec: 656, tv_nsec: 260996737 } })
[2025-04-30T10:37:58.782539486Z TRACE quiche_server] Collecting garbage
[2025-04-30T10:37:58.782545838Z TRACE quiche_server] recv() would block
[2025-04-30T10:37:58.782551408Z TRACE quiche] d4f59da8da5b07ba05661845b11d9044a9aa0dcf pmtud probe status false hs_con=true hs_sent=true cwnd_avail=0 out_len=1350 left=0
[2025-04-30T10:37:58.782556678Z TRACE quiche_server] d4f59da8da5b07ba05661845b11d9044a9aa0dcf done writing
[2025-04-30T10:37:58.782560475Z TRACE quiche_server] Collecting garbage
[2025-04-30T10:37:58.814087499Z TRACE quiche_server] got 46 bytes from [fd00:cafe:cafe::100]:60621 to [::]:443
[2025-04-30T10:37:58.814102387Z TRACE quiche_server] got packet Short dcid=74228381d2ada9d6636de4b3f27c85e44e256656 key_phase=false
[2025-04-30T10:37:58.814111183Z TRACE quiche] d4f59da8da5b07ba05661845b11d9044a9aa0dcf rx pkt Short dcid=74228381d2ada9d6636de4b3f27c85e44e256656 key_phase=false len=25 pn=2 
[2025-04-30T10:37:58.814118236Z TRACE quiche] d4f59da8da5b07ba05661845b11d9044a9aa0dcf path ID 0 now see SCID with seq num 1
[2025-04-30T10:37:58.814123236Z TRACE quiche] d4f59da8da5b07ba05661845b11d9044a9aa0dcf rx frm ACK delay=24 blocks=[2..2] ecn_counts=None
[2025-04-30T10:37:58.814128586Z TRACE quiche::recovery::congestion::recovery] d4f59da8da5b07ba05661845b11d9044a9aa0dcf packet newly acked 2
[2025-04-30T10:37:58.814135018Z TRACE quiche] d4f59da8da5b07ba05661845b11d9044a9aa0dcf rx frm RETIRE_CONNECTION_ID seq_num=0
[2025-04-30T10:37:58.814152059Z TRACE quiche_server] d4f59da8da5b07ba05661845b11d9044a9aa0dcf processed 46 bytes
[2025-04-30T10:37:58.814156458Z INFO  quiche_server] Retiring source CID d4f59da8da5b07ba05661845b11d9044a9aa0dcf
[2025-04-30T10:37:58.814166056Z TRACE quiche_server] recv() would block
[2025-04-30T10:37:58.814173139Z TRACE quiche] d4f59da8da5b07ba05661845b11d9044a9aa0dcf pmtud probe status false hs_con=true hs_sent=true cwnd_avail=2700 out_len=1350 left=1327
[2025-04-30T10:37:58.814180623Z TRACE quiche] d4f59da8da5b07ba05661845b11d9044a9aa0dcf tx pkt Short dcid= key_phase=false len=1332 pn=13 
[2025-04-30T10:37:58.814183949Z TRACE quiche] d4f59da8da5b07ba05661845b11d9044a9aa0dcf tx frm ACK delay=7 blocks=[2..2] ecn_counts=None
[2025-04-30T10:37:58.814187536Z TRACE quiche] d4f59da8da5b07ba05661845b11d9044a9aa0dcf tx frm NEW_CONNECTION_ID seq_num=4 retire_prior_to=1 conn_id=[6c, b6, 53, 28, 6a, a8, b7, bd, e9, 0c, 45, e0, 1b, bc, 8b, 79, 6b, 99, 51, 6f] reset_token=[e5, 4d, fe, 39, 35, bf, ff, 37, c6, d5, 4a, 6e, 8a, fc, 3b, a9]
[2025-04-30T10:37:58.814195631Z TRACE quiche] d4f59da8da5b07ba05661845b11d9044a9aa0dcf tx frm STREAM id=0 off=7992 len=1281 fin=false
[2025-04-30T10:37:58.814205960Z TRACE quiche::recovery::congestion::recovery] d4f59da8da5b07ba05661845b11d9044a9aa0dcf timer=111.601625ms latest_rtt=32.167538ms srtt=33.520965ms min_rtt=32.167538ms rttvar=13.02956ms cwnd=14850 ssthresh=18446744073709551615 bytes_in_flight=13500 app_limited=true congestion_recovery_start_time=None Rate { delivered: 1496, delivered_time: Instant { tv_sec: 656, tv_nsec: 293164275 }, first_sent_time: Instant { tv_sec: 656, tv_nsec: 260996737 }, end_of_app_limited: 0, last_sent_packet: 13, largest_acked: 2, rate_sample: RateSample { delivery_rate: 41967, is_app_limited: true, interval: 32.167538ms, delivered: 1350, prior_delivered: 146, prior_time: Some(Instant { tv_sec: 656, tv_nsec: 260996737 }), send_elapsed: 0ns, ack_elapsed: 32.167538ms, rtt: 32.167538ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 553757, last_update: Instant { tv_sec: 656, tv_nsec: 293223616 }, next_time: Instant { tv_sec: 656, tv_nsec: 293223616 }, 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.167538ms current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } 
[2025-04-30T10:37:58.814230385Z TRACE quiche] d4f59da8da5b07ba05661845b11d9044a9aa0dcf pmtud probe status false hs_con=true hs_sent=true cwnd_avail=1350 out_len=1350 left=1332
[2025-04-30T10:37:58.814234563Z TRACE quiche] d4f59da8da5b07ba05661845b11d9044a9aa0dcf tx pkt Short dcid= key_phase=false len=973 pn=14 
[2025-04-30T10:37:58.814237699Z TRACE quiche] d4f59da8da5b07ba05661845b11d9044a9aa0dcf tx frm STREAM id=0 off=9273 len=967 fin=true
[2025-04-30T10:37:58.814244111Z TRACE quiche::recovery::congestion::recovery] d4f59da8da5b07ba05661845b11d9044a9aa0dcf timer=111.623746ms latest_rtt=32.167538ms srtt=33.520965ms min_rtt=32.167538ms rttvar=13.02956ms cwnd=14850 ssthresh=18446744073709551615 bytes_in_flight=14491 app_limited=true congestion_recovery_start_time=None Rate { delivered: 1496, delivered_time: Instant { tv_sec: 656, tv_nsec: 293164275 }, first_sent_time: Instant { tv_sec: 656, tv_nsec: 260996737 }, end_of_app_limited: 0, last_sent_packet: 14, largest_acked: 2, rate_sample: RateSample { delivery_rate: 41967, is_app_limited: true, interval: 32.167538ms, delivered: 1350, prior_delivered: 146, prior_time: Some(Instant { tv_sec: 656, tv_nsec: 260996737 }), send_elapsed: 0ns, ack_elapsed: 32.167538ms, rtt: 32.167538ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 553757, last_update: Instant { tv_sec: 656, tv_nsec: 293223616 }, next_time: Instant { tv_sec: 656, tv_nsec: 293223616 }, 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.167538ms current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } 
[2025-04-30T10:37:58.814292040Z TRACE quiche_server] d4f59da8da5b07ba05661845b11d9044a9aa0dcf written 2341 bytes with Some(SendInfo { from: [::]:443, to: [fd00:cafe:cafe::100]:60621, at: Instant { tv_sec: 656, tv_nsec: 293223616 } })
[2025-04-30T10:37:58.814298092Z TRACE quiche_server] Collecting garbage
[2025-04-30T10:37:58.814303221Z TRACE quiche_server] recv() would block
[2025-04-30T10:37:58.814306397Z TRACE quiche_server] d4f59da8da5b07ba05661845b11d9044a9aa0dcf done writing
[2025-04-30T10:37:58.814309132Z TRACE quiche_server] Collecting garbage
[2025-04-30T10:37:58.816086977Z TRACE quiche_server] got 44 bytes from [fd00:cafe:cafe::100]:60621 to [::]:443
[2025-04-30T10:37:58.816094411Z TRACE quiche_server] got packet Short dcid=74228381d2ada9d6636de4b3f27c85e44e256656 key_phase=false
[2025-04-30T10:37:58.816100042Z TRACE quiche] d4f59da8da5b07ba05661845b11d9044a9aa0dcf rx pkt Short dcid=74228381d2ada9d6636de4b3f27c85e44e256656 key_phase=false len=23 pn=3 
[2025-04-30T10:37:58.816105993Z TRACE quiche] d4f59da8da5b07ba05661845b11d9044a9aa0dcf rx frm ACK delay=4 blocks=[2..4] ecn_counts=None
[2025-04-30T10:37:58.816109970Z TRACE quiche::recovery::congestion::recovery] d4f59da8da5b07ba05661845b11d9044a9aa0dcf packet newly acked 3
[2025-04-30T10:37:58.816112926Z TRACE quiche::recovery::congestion::recovery] d4f59da8da5b07ba05661845b11d9044a9aa0dcf packet newly acked 4
[2025-04-30T10:37:58.816124357Z TRACE quiche_server] d4f59da8da5b07ba05661845b11d9044a9aa0dcf processed 44 bytes
[2025-04-30T10:37:58.816134947Z TRACE quiche_server] recv() would block
[2025-04-30T10:37:58.816137581Z TRACE quiche_server] d4f59da8da5b07ba05661845b11d9044a9aa0dcf done writing
[2025-04-30T10:37:58.816139725Z TRACE quiche_server] Collecting garbage
[2025-04-30T10:37:58.818300805Z TRACE quiche_server] got 44 bytes from [fd00:cafe:cafe::100]:60621 to [::]:443
[2025-04-30T10:37:58.818306957Z TRACE quiche_server] got packet Short dcid=74228381d2ada9d6636de4b3f27c85e44e256656 key_phase=false
[2025-04-30T10:37:58.818311505Z TRACE quiche] d4f59da8da5b07ba05661845b11d9044a9aa0dcf rx pkt Short dcid=74228381d2ada9d6636de4b3f27c85e44e256656 key_phase=false len=23 pn=4 
[2025-04-30T10:37:58.818315833Z TRACE quiche] d4f59da8da5b07ba05661845b11d9044a9aa0dcf rx frm ACK delay=5 blocks=[2..6] ecn_counts=None
[2025-04-30T10:37:58.818318949Z TRACE quiche::recovery::congestion::recovery] d4f59da8da5b07ba05661845b11d9044a9aa0dcf packet newly acked 5
[2025-04-30T10:37:58.818321373Z TRACE quiche::recovery::congestion::recovery] d4f59da8da5b07ba05661845b11d9044a9aa0dcf packet newly acked 6
[2025-04-30T10:37:58.818329048Z TRACE quiche_server] d4f59da8da5b07ba05661845b11d9044a9aa0dcf processed 44 bytes
[2025-04-30T10:37:58.818332684Z TRACE quiche_server] recv() would block
[2025-04-30T10:37:58.818335169Z TRACE quiche_server] d4f59da8da5b07ba05661845b11d9044a9aa0dcf done writing
[2025-04-30T10:37:58.818337343Z TRACE quiche_server] Collecting garbage
[2025-04-30T10:37:58.820549057Z TRACE quiche_server] got 44 bytes from [fd00:cafe:cafe::100]:60621 to [::]:443
[2025-04-30T10:37:58.820555760Z TRACE quiche_server] got packet Short dcid=74228381d2ada9d6636de4b3f27c85e44e256656 key_phase=false
[2025-04-30T10:37:58.820560699Z TRACE quiche] d4f59da8da5b07ba05661845b11d9044a9aa0dcf rx pkt Short dcid=74228381d2ada9d6636de4b3f27c85e44e256656 key_phase=false len=23 pn=5 
[2025-04-30T10:37:58.820565528Z TRACE quiche] d4f59da8da5b07ba05661845b11d9044a9aa0dcf rx frm ACK delay=5 blocks=[2..8] ecn_counts=None
[2025-04-30T10:37:58.820568954Z TRACE quiche::recovery::congestion::recovery] d4f59da8da5b07ba05661845b11d9044a9aa0dcf packet newly acked 7
[2025-04-30T10:37:58.820571930Z TRACE quiche::recovery::congestion::recovery] d4f59da8da5b07ba05661845b11d9044a9aa0dcf packet newly acked 8
[2025-04-30T10:37:58.820581267Z TRACE quiche_server] d4f59da8da5b07ba05661845b11d9044a9aa0dcf processed 44 bytes
[2025-04-30T10:37:58.820585505Z TRACE quiche_server] recv() would block
[2025-04-30T10:37:58.820588541Z TRACE quiche_server] d4f59da8da5b07ba05661845b11d9044a9aa0dcf done writing
[2025-04-30T10:37:58.820591396Z TRACE quiche_server] Collecting garbage
[2025-04-30T10:37:58.822622684Z TRACE quiche_server] got 44 bytes from [fd00:cafe:cafe::100]:60621 to [::]:443
[2025-04-30T10:37:58.822629356Z TRACE quiche_server] got packet Short dcid=74228381d2ada9d6636de4b3f27c85e44e256656 key_phase=false
[2025-04-30T10:37:58.822634165Z TRACE quiche] d4f59da8da5b07ba05661845b11d9044a9aa0dcf rx pkt Short dcid=74228381d2ada9d6636de4b3f27c85e44e256656 key_phase=false len=23 pn=6 
[2025-04-30T10:37:58.822638974Z TRACE quiche] d4f59da8da5b07ba05661845b11d9044a9aa0dcf rx frm ACK delay=5 blocks=[2..10] ecn_counts=None
[2025-04-30T10:37:58.822642601Z TRACE quiche::recovery::congestion::recovery] d4f59da8da5b07ba05661845b11d9044a9aa0dcf packet newly acked 9
[2025-04-30T10:37:58.822645506Z TRACE quiche::recovery::congestion::recovery] d4f59da8da5b07ba05661845b11d9044a9aa0dcf packet newly acked 10
[2025-04-30T10:37:58.822665052Z TRACE quiche_server] d4f59da8da5b07ba05661845b11d9044a9aa0dcf processed 44 bytes
[2025-04-30T10:37:58.822669351Z TRACE quiche_server] recv() would block
[2025-04-30T10:37:58.822672496Z TRACE quiche_server] d4f59da8da5b07ba05661845b11d9044a9aa0dcf done writing
[2025-04-30T10:37:58.822675201Z TRACE quiche_server] Collecting garbage
[2025-04-30T10:37:58.823928688Z TRACE quiche_server] got 44 bytes from [fd00:cafe:cafe::100]:60621 to [::]:443
[2025-04-30T10:37:58.823934229Z TRACE quiche_server] got packet Short dcid=74228381d2ada9d6636de4b3f27c85e44e256656 key_phase=false
[2025-04-30T10:37:58.823943987Z TRACE quiche] d4f59da8da5b07ba05661845b11d9044a9aa0dcf rx pkt Short dcid=74228381d2ada9d6636de4b3f27c85e44e256656 key_phase=false len=23 pn=7 
[2025-04-30T10:37:58.823971258Z TRACE quiche] d4f59da8da5b07ba05661845b11d9044a9aa0dcf rx frm ACK delay=5 blocks=[2..12] ecn_counts=None
[2025-04-30T10:37:58.823974414Z TRACE quiche::recovery::congestion::recovery] d4f59da8da5b07ba05661845b11d9044a9aa0dcf packet newly acked 11
[2025-04-30T10:37:58.823976838Z TRACE quiche::recovery::congestion::recovery] d4f59da8da5b07ba05661845b11d9044a9aa0dcf packet newly acked 12
[2025-04-30T10:37:58.823984903Z TRACE quiche_server] d4f59da8da5b07ba05661845b11d9044a9aa0dcf processed 44 bytes
[2025-04-30T10:37:58.823988731Z TRACE quiche_server] recv() would block
[2025-04-30T10:37:58.823991385Z TRACE quiche_server] d4f59da8da5b07ba05661845b11d9044a9aa0dcf done writing
[2025-04-30T10:37:58.823993580Z TRACE quiche_server] Collecting garbage
[2025-04-30T10:37:58.846795925Z TRACE quiche_server] got 44 bytes from [fd00:cafe:cafe::100]:60621 to [::]:443
[2025-04-30T10:37:58.846826232Z TRACE quiche_server] got packet Short dcid=74228381d2ada9d6636de4b3f27c85e44e256656 key_phase=false
[2025-04-30T10:37:58.846838715Z TRACE quiche] d4f59da8da5b07ba05661845b11d9044a9aa0dcf rx pkt Short dcid=74228381d2ada9d6636de4b3f27c85e44e256656 key_phase=false len=23 pn=8 
[2025-04-30T10:37:58.846850037Z TRACE quiche] d4f59da8da5b07ba05661845b11d9044a9aa0dcf rx frm ACK delay=4 blocks=[3..14] ecn_counts=None
[2025-04-30T10:37:58.846856959Z TRACE quiche::recovery::congestion::recovery] d4f59da8da5b07ba05661845b11d9044a9aa0dcf packet newly acked 13
[2025-04-30T10:37:58.846860376Z TRACE quiche::recovery::congestion::recovery] d4f59da8da5b07ba05661845b11d9044a9aa0dcf packet newly acked 14
[2025-04-30T10:37:58.846888488Z TRACE quiche_server] d4f59da8da5b07ba05661845b11d9044a9aa0dcf processed 44 bytes
[2025-04-30T10:37:58.846899348Z TRACE quiche_server] got 42 bytes from [fd00:cafe:cafe::100]:60621 to [::]:443
[2025-04-30T10:37:58.846904047Z TRACE quiche_server] got packet Short dcid=74228381d2ada9d6636de4b3f27c85e44e256656 key_phase=false
[2025-04-30T10:37:58.846911301Z TRACE quiche] d4f59da8da5b07ba05661845b11d9044a9aa0dcf rx pkt Short dcid=74228381d2ada9d6636de4b3f27c85e44e256656 key_phase=false len=21 pn=9 
[2025-04-30T10:37:58.846917502Z TRACE quiche] d4f59da8da5b07ba05661845b11d9044a9aa0dcf rx frm APPLICATION_CLOSE err=0 reason=[]
[2025-04-30T10:37:58.846924746Z TRACE quiche_server] d4f59da8da5b07ba05661845b11d9044a9aa0dcf processed 42 bytes
[2025-04-30T10:37:58.846929064Z TRACE quiche_server] recv() would block
[2025-04-30T10:37:58.846931749Z TRACE quiche_server] d4f59da8da5b07ba05661845b11d9044a9aa0dcf done writing
[2025-04-30T10:37:58.846934364Z TRACE quiche_server] Collecting garbage
[2025-04-30T10:37:59.027135637Z TRACE quiche_server] timed out
[2025-04-30T10:37:59.027178407Z TRACE quiche] d4f59da8da5b07ba05661845b11d9044a9aa0dcf draining timeout expired
[2025-04-30T10:37:59.027233800Z TRACE quiche_server] d4f59da8da5b07ba05661845b11d9044a9aa0dcf done writing
[2025-04-30T10:37:59.027239431Z TRACE quiche_server] Collecting garbage
[2025-04-30T10:37:59.027245021Z INFO  quiche_server] d4f59da8da5b07ba05661845b11d9044a9aa0dcf connection collected recv=13 sent=15 lost=0 retrans=0 sent_bytes=16743 recv_bytes=3028 lost_bytes=0 [local_addr=[::]:443 peer_addr=[fd00:cafe:cafe::100]:60621 validation_state=Validated active=true recv=13 sent=15 lost=0 retrans=0 rtt=35.683794ms min_rtt=Some(32.167538ms) rttvar=6.045856ms cwnd=14850 sent_bytes=16743 recv_bytes=3028 lost_bytes=0 stream_retrans_bytes=0 pmtu=1350 delivery_rate=442793]