[2025-04-30T09:16:42.623131089Z INFO  quiche_server] listening on [::]:443
[2025-04-30T09:16:42.623154212Z TRACE mio::poll] registering event source with poller: token=Token(0), interests=READABLE
[2025-04-30T09:16:42.623161887Z TRACE quiche_server] GSO detected: false
[2025-04-30T09:16:43.456569775Z TRACE quiche_server] got 1207 bytes from [::ffff:193.167.100.2]:48048 to [::]:443
[2025-04-30T09:16:43.456612274Z TRACE quiche_server] got packet Initial version=57414954 dcid= scid= token=
[2025-04-30T09:16:43.456622513Z WARN  quiche_server] Doing version negotiation
[2025-04-30T09:16:43.456735184Z TRACE quiche_server] got 1207 bytes from [::ffff:193.167.100.2]:48048 to [::]:443
[2025-04-30T09:16:43.456744772Z TRACE quiche_server] got packet Initial version=57414954 dcid= scid= token=
[2025-04-30T09:16:43.456750172Z WARN  quiche_server] Doing version negotiation
[2025-04-30T09:16:43.456779387Z TRACE quiche_server] got 1207 bytes from [::ffff:193.167.100.2]:48048 to [::]:443
[2025-04-30T09:16:43.456785749Z TRACE quiche_server] got packet Initial version=57414954 dcid= scid= token=
[2025-04-30T09:16:43.456790608Z WARN  quiche_server] Doing version negotiation
[2025-04-30T09:16:43.456816166Z TRACE quiche_server] recv() would block
[2025-04-30T09:16:43.704452846Z TRACE quiche_server] got 1232 bytes from [fd00:cafe:cafe::100]:47277 to [::]:443
[2025-04-30T09:16:43.704478114Z TRACE quiche_server] got packet Initial version=1 dcid=1dd6da987d165d0a scid=c918d99dfa829af08924fef9f101b298 token=
[2025-04-30T09:16:43.704488443Z DEBUG quiche_server] New connection: dcid=1dd6da987d165d0a scid=a1b82d02b6f1890d8f9c66e13e859407604b3f9c
[2025-04-30T09:16:43.704714185Z TRACE quiche] a1b82d02b6f1890d8f9c66e13e859407604b3f9c rx pkt Initial version=1 dcid=1dd6da987d165d0a scid=c918d99dfa829af08924fef9f101b298 token= len=1198 pn=0 
[2025-04-30T09:16:43.704729243Z TRACE quiche] a1b82d02b6f1890d8f9c66e13e859407604b3f9c rx frm CRYPTO off=0 len=287
[2025-04-30T09:16:43.704758448Z TRACE quiche::tls] checking peer ALPN Ok("hq-interop") against Ok("h3")
[2025-04-30T09:16:43.704763307Z TRACE quiche::tls] checking peer ALPN Ok("hq-interop") against Ok("hq-interop")
[2025-04-30T09:16:43.704876950Z TRACE quiche::tls] a1b82d02b6f1890d8f9c66e13e859407604b3f9c write message lvl=Initial len=123
[2025-04-30T09:16:43.704907346Z TRACE quiche::tls] a1b82d02b6f1890d8f9c66e13e859407604b3f9c set write secret lvl=Handshake
[2025-04-30T09:16:43.704962930Z TRACE quiche::tls] a1b82d02b6f1890d8f9c66e13e859407604b3f9c write message lvl=Handshake len=697
[2025-04-30T09:16:43.704965936Z TRACE quiche::tls] a1b82d02b6f1890d8f9c66e13e859407604b3f9c set write secret lvl=OneRTT
[2025-04-30T09:16:43.704972068Z TRACE quiche::tls] a1b82d02b6f1890d8f9c66e13e859407604b3f9c set read secret lvl=Handshake
[2025-04-30T09:16:43.704989650Z TRACE quiche] a1b82d02b6f1890d8f9c66e13e859407604b3f9c rx frm PADDING len=890
[2025-04-30T09:16:43.705006502Z TRACE quiche_server] a1b82d02b6f1890d8f9c66e13e859407604b3f9c processed 1232 bytes
[2025-04-30T09:16:43.705016751Z TRACE quiche_server] recv() would block
[2025-04-30T09:16:43.705028843Z TRACE quiche] a1b82d02b6f1890d8f9c66e13e859407604b3f9c tx pkt Initial version=1 dcid=c918d99dfa829af08924fef9f101b298 scid=a1b82d02b6f1890d8f9c66e13e859407604b3f9c len=132 pn=0 
[2025-04-30T09:16:43.705032320Z TRACE quiche] a1b82d02b6f1890d8f9c66e13e859407604b3f9c tx frm ACK delay=41 blocks=[0..0] ecn_counts=None
[2025-04-30T09:16:43.705036648Z TRACE quiche] a1b82d02b6f1890d8f9c66e13e859407604b3f9c tx frm CRYPTO off=0 len=123
[2025-04-30T09:16:43.705045264Z TRACE quiche::recovery::congestion::recovery] a1b82d02b6f1890d8f9c66e13e859407604b3f9c timer=998.973009ms latest_rtt=0ns srtt=333ms min_rtt=333ms rttvar=166.5ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=195 app_limited=true congestion_recovery_start_time=None Rate { delivered: 0, delivered_time: Instant { tv_sec: 595, tv_nsec: 278643352 }, first_sent_time: Instant { tv_sec: 595, tv_nsec: 278643352 }, 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: 595, tv_nsec: 278643352 }, next_time: Instant { tv_sec: 595, tv_nsec: 278643352 }, 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:43.705073527Z TRACE quiche] a1b82d02b6f1890d8f9c66e13e859407604b3f9c tx pkt Handshake version=1 dcid=c918d99dfa829af08924fef9f101b298 scid=a1b82d02b6f1890d8f9c66e13e859407604b3f9c len=701 pn=1 
[2025-04-30T09:16:43.705076523Z TRACE quiche] a1b82d02b6f1890d8f9c66e13e859407604b3f9c tx frm CRYPTO off=0 len=697
[2025-04-30T09:16:43.705081673Z TRACE quiche::recovery::congestion::recovery] a1b82d02b6f1890d8f9c66e13e859407604b3f9c timer=998.937072ms latest_rtt=0ns srtt=333ms min_rtt=333ms rttvar=166.5ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=958 app_limited=true congestion_recovery_start_time=None Rate { delivered: 0, delivered_time: Instant { tv_sec: 595, tv_nsec: 278643352 }, first_sent_time: Instant { tv_sec: 595, tv_nsec: 278643352 }, 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: 595, tv_nsec: 278643352 }, next_time: Instant { tv_sec: 595, tv_nsec: 278643352 }, 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:43.705119724Z TRACE quiche_server] a1b82d02b6f1890d8f9c66e13e859407604b3f9c written 1200 bytes with Some(SendInfo { from: [::]:443, to: [fd00:cafe:cafe::100]:47277, at: Instant { tv_sec: 595, tv_nsec: 278643352 } })
[2025-04-30T09:16:43.705126296Z TRACE quiche_server] Collecting garbage
[2025-04-30T09:16:43.705131215Z TRACE quiche_server] recv() would block
[2025-04-30T09:16:43.705134481Z TRACE quiche_server] a1b82d02b6f1890d8f9c66e13e859407604b3f9c done writing
[2025-04-30T09:16:43.705136796Z TRACE quiche_server] Collecting garbage
[2025-04-30T09:16:43.740038949Z TRACE quiche_server] got 1232 bytes from [fd00:cafe:cafe::100]:47277 to [::]:443
[2025-04-30T09:16:43.740061752Z TRACE quiche_server] got packet Initial version=1 dcid=a1b82d02b6f1890d8f9c66e13e859407604b3f9c scid=c918d99dfa829af08924fef9f101b298 token=
[2025-04-30T09:16:43.740074435Z TRACE quiche] a1b82d02b6f1890d8f9c66e13e859407604b3f9c rx pkt Initial version=1 dcid=a1b82d02b6f1890d8f9c66e13e859407604b3f9c scid=c918d99dfa829af08924fef9f101b298 token= len=36 pn=1 
[2025-04-30T09:16:43.740086718Z TRACE quiche] a1b82d02b6f1890d8f9c66e13e859407604b3f9c rx frm ACK delay=1760 blocks=[0..0] ecn_counts=None
[2025-04-30T09:16:43.740092439Z TRACE quiche::recovery::congestion::recovery] a1b82d02b6f1890d8f9c66e13e859407604b3f9c packet newly acked 0
[2025-04-30T09:16:43.740098561Z TRACE quiche] a1b82d02b6f1890d8f9c66e13e859407604b3f9c rx frm PADDING len=13
[2025-04-30T09:16:43.740118398Z TRACE quiche] a1b82d02b6f1890d8f9c66e13e859407604b3f9c rx pkt Handshake version=1 dcid=a1b82d02b6f1890d8f9c66e13e859407604b3f9c scid=c918d99dfa829af08924fef9f101b298 len=1105 pn=0 
[2025-04-30T09:16:43.740124118Z TRACE quiche] a1b82d02b6f1890d8f9c66e13e859407604b3f9c rx frm ACK delay=1760 blocks=[1..1] ecn_counts=None
[2025-04-30T09:16:43.740126954Z TRACE quiche::recovery::congestion::recovery] a1b82d02b6f1890d8f9c66e13e859407604b3f9c packet newly acked 1
[2025-04-30T09:16:43.740137643Z TRACE quiche] a1b82d02b6f1890d8f9c66e13e859407604b3f9c rx frm CRYPTO off=0 len=36
[2025-04-30T09:16:43.740153403Z TRACE quiche::tls] a1b82d02b6f1890d8f9c66e13e859407604b3f9c set read secret lvl=OneRTT
[2025-04-30T09:16:43.740185483Z TRACE quiche::tls] a1b82d02b6f1890d8f9c66e13e859407604b3f9c write message lvl=OneRTT len=396
[2025-04-30T09:16:43.740194760Z TRACE quiche] a1b82d02b6f1890d8f9c66e13e859407604b3f9c dropped epoch 1 state
[2025-04-30T09:16:43.740198437Z TRACE quiche] a1b82d02b6f1890d8f9c66e13e859407604b3f9c connection established: proto=Ok("hq-interop") cipher=Some(AES128_GCM) curve=Some("P-256") sigalg=None resumed=false TransportParams { original_destination_connection_id: None, max_idle_timeout: 300000, stateless_reset_token: None, max_udp_payload_size: 65527, initial_max_data: 3750000, initial_max_stream_data_bidi_local: 3750000, initial_max_stream_data_bidi_remote: 3750000, initial_max_stream_data_uni: 3750000, initial_max_streams_bidi: 100, initial_max_streams_uni: 100, ack_delay_exponent: 3, max_ack_delay: 25, disable_active_migration: false, active_conn_id_limit: 3, initial_source_connection_id: Some(c918d99dfa829af08924fef9f101b298), retry_source_connection_id: None, max_datagram_frame_size: None, unknown_params: None }
[2025-04-30T09:16:43.740210961Z TRACE quiche] a1b82d02b6f1890d8f9c66e13e859407604b3f9c rx frm PADDING len=1043
[2025-04-30T09:16:43.740223544Z TRACE quiche] a1b82d02b6f1890d8f9c66e13e859407604b3f9c dropped epoch 0 state
[2025-04-30T09:16:43.740226380Z TRACE quiche_server] a1b82d02b6f1890d8f9c66e13e859407604b3f9c processed 1232 bytes
[2025-04-30T09:16:43.740234424Z TRACE quiche_server] got 81 bytes from [fd00:cafe:cafe::100]:47277 to [::]:443
[2025-04-30T09:16:43.740237721Z TRACE quiche_server] got packet Short dcid=a1b82d02b6f1890d8f9c66e13e859407604b3f9c key_phase=false
[2025-04-30T09:16:43.740242139Z TRACE quiche] a1b82d02b6f1890d8f9c66e13e859407604b3f9c rx pkt Short dcid=a1b82d02b6f1890d8f9c66e13e859407604b3f9c key_phase=false len=60 pn=0 
[2025-04-30T09:16:43.740246587Z TRACE quiche] a1b82d02b6f1890d8f9c66e13e859407604b3f9c rx frm STREAM id=4 off=0 len=0 fin=false
[2025-04-30T09:16:43.740251056Z TRACE quiche] a1b82d02b6f1890d8f9c66e13e859407604b3f9c rx frm STREAM id=0 off=0 len=17 fin=true
[2025-04-30T09:16:43.740254292Z TRACE quiche] a1b82d02b6f1890d8f9c66e13e859407604b3f9c rx frm STREAM id=4 off=0 len=17 fin=true
[2025-04-30T09:16:43.740259491Z TRACE quiche_server] a1b82d02b6f1890d8f9c66e13e859407604b3f9c processed 81 bytes
[2025-04-30T09:16:43.740262236Z DEBUG quiche_apps::common] a1b82d02b6f1890d8f9c66e13e859407604b3f9c response stream 4 is writable with capacity Ok(13500)
[2025-04-30T09:16:43.740265573Z DEBUG quiche_apps::common] a1b82d02b6f1890d8f9c66e13e859407604b3f9c response stream 0 is writable with capacity Ok(13500)
[2025-04-30T09:16:43.740270592Z TRACE quiche_apps::common] a1b82d02b6f1890d8f9c66e13e859407604b3f9c received 17 bytes
[2025-04-30T09:16:43.740273127Z TRACE quiche_apps::common] a1b82d02b6f1890d8f9c66e13e859407604b3f9c stream 0 has 17 bytes (fin? true)
[2025-04-30T09:16:43.740277485Z INFO  quiche_apps::common] a1b82d02b6f1890d8f9c66e13e859407604b3f9c got GET request for "/www/jkkjdrajql" on stream 0
[2025-04-30T09:16:43.740301009Z INFO  quiche_apps::common] a1b82d02b6f1890d8f9c66e13e859407604b3f9c sending response of size 5120 on stream 0
[2025-04-30T09:16:43.740308122Z TRACE quiche_apps::common] a1b82d02b6f1890d8f9c66e13e859407604b3f9c received 17 bytes
[2025-04-30T09:16:43.740310507Z TRACE quiche_apps::common] a1b82d02b6f1890d8f9c66e13e859407604b3f9c stream 4 has 17 bytes (fin? true)
[2025-04-30T09:16:43.740313092Z INFO  quiche_apps::common] a1b82d02b6f1890d8f9c66e13e859407604b3f9c got GET request for "/www/sdqmplqxnh" on stream 4
[2025-04-30T09:16:43.740326106Z INFO  quiche_apps::common] a1b82d02b6f1890d8f9c66e13e859407604b3f9c sending response of size 10240 on stream 4
[2025-04-30T09:16:43.740332578Z TRACE quiche_server] recv() would block
[2025-04-30T09:16:43.740340513Z TRACE quiche] a1b82d02b6f1890d8f9c66e13e859407604b3f9c pmtud probe status false hs_con=true hs_sent=false cwnd_avail=13500 out_len=1350 left=1311
[2025-04-30T09:16:43.740353247Z TRACE quiche] a1b82d02b6f1890d8f9c66e13e859407604b3f9c tx pkt Short dcid=c918d99dfa829af08924fef9f101b298 key_phase=false len=1316 pn=2 
[2025-04-30T09:16:43.740356162Z TRACE quiche] a1b82d02b6f1890d8f9c66e13e859407604b3f9c tx frm ACK delay=12 blocks=[0..0] ecn_counts=None
[2025-04-30T09:16:43.740359298Z TRACE quiche] a1b82d02b6f1890d8f9c66e13e859407604b3f9c tx frm NEW_CONNECTION_ID seq_num=1 retire_prior_to=0 conn_id=[78, 88, d8, 25, 6e, 67, 57, ba, 44, 40, d7, 87, c2, 54, 25, c9, ab, 06, 3b, e4] reset_token=[76, e9, bf, 84, 57, 10, d6, 77, e2, f3, 88, 89, a7, bd, 03, 4e]
[2025-04-30T09:16:43.740366081Z TRACE quiche] a1b82d02b6f1890d8f9c66e13e859407604b3f9c tx frm NEW_CONNECTION_ID seq_num=2 retire_prior_to=0 conn_id=[60, 87, d8, 2c, f0, 33, dc, 98, fb, 52, 5d, a7, 9e, fb, 17, c0, d0, 08, db, ae] reset_token=[2a, 72, 3a, fd, 68, 49, eb, 17, a8, 20, c6, 55, c0, 1a, ef, 71]
[2025-04-30T09:16:43.740371291Z TRACE quiche] a1b82d02b6f1890d8f9c66e13e859407604b3f9c tx frm HANDSHAKE_DONE
[2025-04-30T09:16:43.740373535Z TRACE quiche] a1b82d02b6f1890d8f9c66e13e859407604b3f9c tx frm CRYPTO off=0 len=396
[2025-04-30T09:16:43.740375879Z TRACE quiche] a1b82d02b6f1890d8f9c66e13e859407604b3f9c tx frm STREAM id=0 off=0 len=825 fin=false
[2025-04-30T09:16:43.740415824Z TRACE quiche::recovery::congestion::recovery] a1b82d02b6f1890d8f9c66e13e859407604b3f9c timer=112.601903ms latest_rtt=35.098792ms srtt=35.058325ms min_rtt=35.052545ms rttvar=13.156265ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=1350 app_limited=true congestion_recovery_start_time=None Rate { delivered: 958, delivered_time: Instant { tv_sec: 595, tv_nsec: 313959410 }, first_sent_time: Instant { tv_sec: 595, tv_nsec: 313959410 }, end_of_app_limited: 1, last_sent_packet: 2, largest_acked: 1, rate_sample: RateSample { delivery_rate: 27330, is_app_limited: true, interval: 35.052545ms, delivered: 958, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 595, tv_nsec: 278643352 }), send_elapsed: 0ns, ack_elapsed: 35.052545ms, rtt: 35.052545ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 481340, last_update: Instant { tv_sec: 595, tv_nsec: 313959410 }, next_time: Instant { tv_sec: 595, tv_nsec: 313959410 }, 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:43.740434148Z TRACE quiche] a1b82d02b6f1890d8f9c66e13e859407604b3f9c pmtud probe status false hs_con=true hs_sent=true cwnd_avail=12150 out_len=1350 left=1316
[2025-04-30T09:16:43.740437905Z TRACE quiche] a1b82d02b6f1890d8f9c66e13e859407604b3f9c tx pkt Short dcid=c918d99dfa829af08924fef9f101b298 key_phase=false len=1316 pn=3 
[2025-04-30T09:16:43.740440440Z TRACE quiche] a1b82d02b6f1890d8f9c66e13e859407604b3f9c tx frm STREAM id=4 off=0 len=1311 fin=false
[2025-04-30T09:16:43.740445449Z TRACE quiche::recovery::congestion::recovery] a1b82d02b6f1890d8f9c66e13e859407604b3f9c timer=112.669539ms latest_rtt=35.098792ms srtt=35.058325ms min_rtt=35.052545ms rttvar=13.156265ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=2700 app_limited=true congestion_recovery_start_time=None Rate { delivered: 958, delivered_time: Instant { tv_sec: 595, tv_nsec: 313959410 }, first_sent_time: Instant { tv_sec: 595, tv_nsec: 313959410 }, end_of_app_limited: 1, last_sent_packet: 3, largest_acked: 1, rate_sample: RateSample { delivery_rate: 27330, is_app_limited: true, interval: 35.052545ms, delivered: 958, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 595, tv_nsec: 278643352 }), send_elapsed: 0ns, ack_elapsed: 35.052545ms, rtt: 35.052545ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 481340, last_update: Instant { tv_sec: 595, tv_nsec: 313959410 }, next_time: Instant { tv_sec: 595, tv_nsec: 313959410 }, 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:43.740459686Z TRACE quiche] a1b82d02b6f1890d8f9c66e13e859407604b3f9c pmtud probe status false hs_con=true hs_sent=true cwnd_avail=10800 out_len=1350 left=1316
[2025-04-30T09:16:43.740462912Z TRACE quiche] a1b82d02b6f1890d8f9c66e13e859407604b3f9c tx pkt Short dcid=c918d99dfa829af08924fef9f101b298 key_phase=false len=1316 pn=4 
[2025-04-30T09:16:43.740465256Z TRACE quiche] a1b82d02b6f1890d8f9c66e13e859407604b3f9c tx frm STREAM id=0 off=825 len=1310 fin=false
[2025-04-30T09:16:43.740469925Z TRACE quiche::recovery::congestion::recovery] a1b82d02b6f1890d8f9c66e13e859407604b3f9c timer=112.671562ms latest_rtt=35.098792ms srtt=35.058325ms min_rtt=35.052545ms rttvar=13.156265ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=4050 app_limited=true congestion_recovery_start_time=None Rate { delivered: 958, delivered_time: Instant { tv_sec: 595, tv_nsec: 313959410 }, first_sent_time: Instant { tv_sec: 595, tv_nsec: 313959410 }, end_of_app_limited: 1, last_sent_packet: 4, largest_acked: 1, rate_sample: RateSample { delivery_rate: 27330, is_app_limited: true, interval: 35.052545ms, delivered: 958, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 595, tv_nsec: 278643352 }), send_elapsed: 0ns, ack_elapsed: 35.052545ms, rtt: 35.052545ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 481340, last_update: Instant { tv_sec: 595, tv_nsec: 313959410 }, next_time: Instant { tv_sec: 595, tv_nsec: 313959410 }, 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:43.740479673Z TRACE quiche] a1b82d02b6f1890d8f9c66e13e859407604b3f9c pmtud probe status false hs_con=true hs_sent=true cwnd_avail=9450 out_len=1350 left=1316
[2025-04-30T09:16:43.740482679Z TRACE quiche] a1b82d02b6f1890d8f9c66e13e859407604b3f9c tx pkt Short dcid=c918d99dfa829af08924fef9f101b298 key_phase=false len=1316 pn=5 
[2025-04-30T09:16:43.740485053Z TRACE quiche] a1b82d02b6f1890d8f9c66e13e859407604b3f9c tx frm STREAM id=4 off=1311 len=1310 fin=false
[2025-04-30T09:16:43.740489381Z TRACE quiche::recovery::congestion::recovery] a1b82d02b6f1890d8f9c66e13e859407604b3f9c timer=112.671954ms latest_rtt=35.098792ms srtt=35.058325ms min_rtt=35.052545ms rttvar=13.156265ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=5400 app_limited=true congestion_recovery_start_time=None Rate { delivered: 958, delivered_time: Instant { tv_sec: 595, tv_nsec: 313959410 }, first_sent_time: Instant { tv_sec: 595, tv_nsec: 313959410 }, end_of_app_limited: 1, last_sent_packet: 5, largest_acked: 1, rate_sample: RateSample { delivery_rate: 27330, is_app_limited: true, interval: 35.052545ms, delivered: 958, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 595, tv_nsec: 278643352 }), send_elapsed: 0ns, ack_elapsed: 35.052545ms, rtt: 35.052545ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 481340, last_update: Instant { tv_sec: 595, tv_nsec: 313959410 }, next_time: Instant { tv_sec: 595, tv_nsec: 313959410 }, 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:43.740501504Z TRACE quiche] a1b82d02b6f1890d8f9c66e13e859407604b3f9c pmtud probe status false hs_con=true hs_sent=true cwnd_avail=8100 out_len=1350 left=1316
[2025-04-30T09:16:43.740504420Z TRACE quiche] a1b82d02b6f1890d8f9c66e13e859407604b3f9c tx pkt Short dcid=c918d99dfa829af08924fef9f101b298 key_phase=false len=1316 pn=6 
[2025-04-30T09:16:43.740506764Z TRACE quiche] a1b82d02b6f1890d8f9c66e13e859407604b3f9c tx frm STREAM id=0 off=2135 len=1310 fin=false
[2025-04-30T09:16:43.740511282Z TRACE quiche::recovery::congestion::recovery] a1b82d02b6f1890d8f9c66e13e859407604b3f9c timer=112.672144ms latest_rtt=35.098792ms srtt=35.058325ms min_rtt=35.052545ms rttvar=13.156265ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=6750 app_limited=true congestion_recovery_start_time=None Rate { delivered: 958, delivered_time: Instant { tv_sec: 595, tv_nsec: 313959410 }, first_sent_time: Instant { tv_sec: 595, tv_nsec: 313959410 }, end_of_app_limited: 1, last_sent_packet: 6, largest_acked: 1, rate_sample: RateSample { delivery_rate: 27330, is_app_limited: true, interval: 35.052545ms, delivered: 958, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 595, tv_nsec: 278643352 }), send_elapsed: 0ns, ack_elapsed: 35.052545ms, rtt: 35.052545ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 481340, last_update: Instant { tv_sec: 595, tv_nsec: 313959410 }, next_time: Instant { tv_sec: 595, tv_nsec: 313959410 }, 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:43.740520580Z TRACE quiche] a1b82d02b6f1890d8f9c66e13e859407604b3f9c pmtud probe status false hs_con=true hs_sent=true cwnd_avail=6750 out_len=1350 left=1316
[2025-04-30T09:16:43.740523435Z TRACE quiche] a1b82d02b6f1890d8f9c66e13e859407604b3f9c tx pkt Short dcid=c918d99dfa829af08924fef9f101b298 key_phase=false len=1316 pn=7 
[2025-04-30T09:16:43.740525739Z TRACE quiche] a1b82d02b6f1890d8f9c66e13e859407604b3f9c tx frm STREAM id=4 off=2621 len=1310 fin=false
[2025-04-30T09:16:43.740529937Z TRACE quiche::recovery::congestion::recovery] a1b82d02b6f1890d8f9c66e13e859407604b3f9c timer=112.672705ms latest_rtt=35.098792ms srtt=35.058325ms min_rtt=35.052545ms rttvar=13.156265ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=8100 app_limited=true congestion_recovery_start_time=None Rate { delivered: 958, delivered_time: Instant { tv_sec: 595, tv_nsec: 313959410 }, first_sent_time: Instant { tv_sec: 595, tv_nsec: 313959410 }, end_of_app_limited: 1, last_sent_packet: 7, largest_acked: 1, rate_sample: RateSample { delivery_rate: 27330, is_app_limited: true, interval: 35.052545ms, delivered: 958, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 595, tv_nsec: 278643352 }), send_elapsed: 0ns, ack_elapsed: 35.052545ms, rtt: 35.052545ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 481340, last_update: Instant { tv_sec: 595, tv_nsec: 313959410 }, next_time: Instant { tv_sec: 595, tv_nsec: 313959410 }, 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:43.740538984Z TRACE quiche] a1b82d02b6f1890d8f9c66e13e859407604b3f9c pmtud probe status false hs_con=true hs_sent=true cwnd_avail=5400 out_len=1350 left=1316
[2025-04-30T09:16:43.740541890Z TRACE quiche] a1b82d02b6f1890d8f9c66e13e859407604b3f9c tx pkt Short dcid=c918d99dfa829af08924fef9f101b298 key_phase=false len=1316 pn=8 
[2025-04-30T09:16:43.740544214Z TRACE quiche] a1b82d02b6f1890d8f9c66e13e859407604b3f9c tx frm STREAM id=0 off=3445 len=1310 fin=false
[2025-04-30T09:16:43.740551367Z TRACE quiche::recovery::congestion::recovery] a1b82d02b6f1890d8f9c66e13e859407604b3f9c timer=112.669729ms latest_rtt=35.098792ms srtt=35.058325ms min_rtt=35.052545ms rttvar=13.156265ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=9450 app_limited=true congestion_recovery_start_time=None Rate { delivered: 958, delivered_time: Instant { tv_sec: 595, tv_nsec: 313959410 }, first_sent_time: Instant { tv_sec: 595, tv_nsec: 313959410 }, end_of_app_limited: 1, last_sent_packet: 8, largest_acked: 1, rate_sample: RateSample { delivery_rate: 27330, is_app_limited: true, interval: 35.052545ms, delivered: 958, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 595, tv_nsec: 278643352 }), send_elapsed: 0ns, ack_elapsed: 35.052545ms, rtt: 35.052545ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 481340, last_update: Instant { tv_sec: 595, tv_nsec: 313959410 }, next_time: Instant { tv_sec: 595, tv_nsec: 313959410 }, 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:43.740560665Z TRACE quiche] a1b82d02b6f1890d8f9c66e13e859407604b3f9c pmtud probe status false hs_con=true hs_sent=true cwnd_avail=4050 out_len=1350 left=1316
[2025-04-30T09:16:43.740563620Z TRACE quiche] a1b82d02b6f1890d8f9c66e13e859407604b3f9c tx pkt Short dcid=c918d99dfa829af08924fef9f101b298 key_phase=false len=1316 pn=9 
[2025-04-30T09:16:43.740565975Z TRACE quiche] a1b82d02b6f1890d8f9c66e13e859407604b3f9c tx frm STREAM id=4 off=3931 len=1310 fin=false
[2025-04-30T09:16:43.740570002Z TRACE quiche::recovery::congestion::recovery] a1b82d02b6f1890d8f9c66e13e859407604b3f9c timer=112.672685ms latest_rtt=35.098792ms srtt=35.058325ms min_rtt=35.052545ms rttvar=13.156265ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=10800 app_limited=true congestion_recovery_start_time=None Rate { delivered: 958, delivered_time: Instant { tv_sec: 595, tv_nsec: 313959410 }, first_sent_time: Instant { tv_sec: 595, tv_nsec: 313959410 }, end_of_app_limited: 1, last_sent_packet: 9, largest_acked: 1, rate_sample: RateSample { delivery_rate: 27330, is_app_limited: true, interval: 35.052545ms, delivered: 958, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 595, tv_nsec: 278643352 }), send_elapsed: 0ns, ack_elapsed: 35.052545ms, rtt: 35.052545ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 481340, last_update: Instant { tv_sec: 595, tv_nsec: 313959410 }, next_time: Instant { tv_sec: 595, tv_nsec: 313959410 }, 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:43.740597904Z TRACE quiche] a1b82d02b6f1890d8f9c66e13e859407604b3f9c pmtud probe status false hs_con=true hs_sent=true cwnd_avail=2700 out_len=1350 left=1316
[2025-04-30T09:16:43.740601311Z TRACE quiche] a1b82d02b6f1890d8f9c66e13e859407604b3f9c tx pkt Short dcid=c918d99dfa829af08924fef9f101b298 key_phase=false len=371 pn=10 
[2025-04-30T09:16:43.740603695Z TRACE quiche] a1b82d02b6f1890d8f9c66e13e859407604b3f9c tx frm STREAM id=0 off=4755 len=365 fin=true
[2025-04-30T09:16:43.740609205Z TRACE quiche::recovery::congestion::recovery] a1b82d02b6f1890d8f9c66e13e859407604b3f9c timer=112.670251ms latest_rtt=35.098792ms srtt=35.058325ms min_rtt=35.052545ms rttvar=13.156265ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=11205 app_limited=true congestion_recovery_start_time=None Rate { delivered: 958, delivered_time: Instant { tv_sec: 595, tv_nsec: 313959410 }, first_sent_time: Instant { tv_sec: 595, tv_nsec: 313959410 }, end_of_app_limited: 1, last_sent_packet: 10, largest_acked: 1, rate_sample: RateSample { delivery_rate: 27330, is_app_limited: true, interval: 35.052545ms, delivered: 958, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 595, tv_nsec: 278643352 }), send_elapsed: 0ns, ack_elapsed: 35.052545ms, rtt: 35.052545ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 481340, last_update: Instant { tv_sec: 595, tv_nsec: 313959410 }, next_time: Instant { tv_sec: 595, tv_nsec: 313959410 }, 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:43.740727066Z TRACE quiche_server] a1b82d02b6f1890d8f9c66e13e859407604b3f9c written 11205 bytes with Some(SendInfo { from: [::]:443, to: [fd00:cafe:cafe::100]:47277, at: Instant { tv_sec: 595, tv_nsec: 313959410 } })
[2025-04-30T09:16:43.740737155Z TRACE quiche_server] Collecting garbage
[2025-04-30T09:16:43.740745110Z TRACE quiche_server] recv() would block
[2025-04-30T09:16:43.740752894Z TRACE quiche] a1b82d02b6f1890d8f9c66e13e859407604b3f9c pmtud probe status false hs_con=true hs_sent=true cwnd_avail=2295 out_len=1350 left=1316
[2025-04-30T09:16:43.740758825Z TRACE quiche] a1b82d02b6f1890d8f9c66e13e859407604b3f9c tx pkt Short dcid=c918d99dfa829af08924fef9f101b298 key_phase=false len=1316 pn=11 
[2025-04-30T09:16:43.740763143Z TRACE quiche] a1b82d02b6f1890d8f9c66e13e859407604b3f9c tx frm STREAM id=4 off=5241 len=1310 fin=false
[2025-04-30T09:16:43.740773853Z TRACE quiche::recovery::congestion::recovery] a1b82d02b6f1890d8f9c66e13e859407604b3f9c timer=112.657216ms latest_rtt=35.098792ms srtt=35.058325ms min_rtt=35.052545ms rttvar=13.156265ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=12555 app_limited=true congestion_recovery_start_time=None Rate { delivered: 958, delivered_time: Instant { tv_sec: 595, tv_nsec: 313959410 }, first_sent_time: Instant { tv_sec: 595, tv_nsec: 313959410 }, end_of_app_limited: 1, last_sent_packet: 11, largest_acked: 1, rate_sample: RateSample { delivery_rate: 27330, is_app_limited: true, interval: 35.052545ms, delivered: 958, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 595, tv_nsec: 278643352 }), send_elapsed: 0ns, ack_elapsed: 35.052545ms, rtt: 35.052545ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 481340, last_update: Instant { tv_sec: 595, tv_nsec: 313959410 }, next_time: Instant { tv_sec: 595, tv_nsec: 313959410 }, 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:43.740795333Z TRACE quiche] a1b82d02b6f1890d8f9c66e13e859407604b3f9c pmtud probe status false hs_con=true hs_sent=true cwnd_avail=945 out_len=1350 left=911
[2025-04-30T09:16:43.740800634Z TRACE quiche] a1b82d02b6f1890d8f9c66e13e859407604b3f9c tx pkt Short dcid=c918d99dfa829af08924fef9f101b298 key_phase=false len=911 pn=12 
[2025-04-30T09:16:43.740804471Z TRACE quiche] a1b82d02b6f1890d8f9c66e13e859407604b3f9c tx frm STREAM id=4 off=6551 len=905 fin=false
[2025-04-30T09:16:43.740813237Z TRACE quiche::recovery::congestion::recovery] a1b82d02b6f1890d8f9c66e13e859407604b3f9c timer=112.662085ms latest_rtt=35.098792ms srtt=35.058325ms min_rtt=35.052545ms rttvar=13.156265ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=13500 app_limited=false congestion_recovery_start_time=None Rate { delivered: 958, delivered_time: Instant { tv_sec: 595, tv_nsec: 313959410 }, first_sent_time: Instant { tv_sec: 595, tv_nsec: 313959410 }, end_of_app_limited: 1, last_sent_packet: 12, largest_acked: 1, rate_sample: RateSample { delivery_rate: 27330, is_app_limited: true, interval: 35.052545ms, delivered: 958, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 595, tv_nsec: 278643352 }), send_elapsed: 0ns, ack_elapsed: 35.052545ms, rtt: 35.052545ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 481340, last_update: Instant { tv_sec: 595, tv_nsec: 313959410 }, next_time: Instant { tv_sec: 595, tv_nsec: 313959410 }, 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:43.740860025Z TRACE quiche_server] a1b82d02b6f1890d8f9c66e13e859407604b3f9c written 2295 bytes with Some(SendInfo { from: [::]:443, to: [fd00:cafe:cafe::100]:47277, at: Instant { tv_sec: 595, tv_nsec: 313959410 } })
[2025-04-30T09:16:43.740866306Z TRACE quiche_server] Collecting garbage
[2025-04-30T09:16:43.740872488Z TRACE quiche_server] recv() would block
[2025-04-30T09:16:43.740880062Z TRACE quiche] a1b82d02b6f1890d8f9c66e13e859407604b3f9c pmtud probe status false hs_con=true hs_sent=true cwnd_avail=0 out_len=1350 left=0
[2025-04-30T09:16:43.740885622Z TRACE quiche_server] a1b82d02b6f1890d8f9c66e13e859407604b3f9c done writing
[2025-04-30T09:16:43.740889490Z TRACE quiche_server] Collecting garbage
[2025-04-30T09:16:43.774696402Z TRACE quiche_server] got 1452 bytes from [fd00:cafe:cafe::100]:47277 to [::]:443
[2025-04-30T09:16:43.774712311Z TRACE quiche_server] got packet Short dcid=7888d8256e6757ba4440d787c25425c9ab063be4 key_phase=false
[2025-04-30T09:16:43.774730436Z TRACE quiche] a1b82d02b6f1890d8f9c66e13e859407604b3f9c rx pkt Short dcid=7888d8256e6757ba4440d787c25425c9ab063be4 key_phase=false len=1431 pn=1 
[2025-04-30T09:16:43.774738400Z TRACE quiche] a1b82d02b6f1890d8f9c66e13e859407604b3f9c path ID 0 now see SCID with seq num 1
[2025-04-30T09:16:43.774743360Z TRACE quiche] a1b82d02b6f1890d8f9c66e13e859407604b3f9c rx frm PING mtu_probe=None
[2025-04-30T09:16:43.774751465Z TRACE quiche] a1b82d02b6f1890d8f9c66e13e859407604b3f9c rx frm PADDING len=1413
[2025-04-30T09:16:43.774762686Z TRACE quiche_server] a1b82d02b6f1890d8f9c66e13e859407604b3f9c processed 1452 bytes
[2025-04-30T09:16:43.774768336Z TRACE quiche_server] recv() would block
[2025-04-30T09:16:43.774776081Z TRACE quiche] a1b82d02b6f1890d8f9c66e13e859407604b3f9c pmtud probe status false hs_con=true hs_sent=true cwnd_avail=0 out_len=1350 left=0
[2025-04-30T09:16:43.774780479Z TRACE quiche] a1b82d02b6f1890d8f9c66e13e859407604b3f9c tx pkt Short dcid=c918d99dfa829af08924fef9f101b298 key_phase=false len=5 pn=13 
[2025-04-30T09:16:43.774783765Z TRACE quiche] a1b82d02b6f1890d8f9c66e13e859407604b3f9c tx frm ACK delay=5 blocks=[0..1] ecn_counts=None
[2025-04-30T09:16:43.774792752Z TRACE quiche::recovery::congestion::recovery] a1b82d02b6f1890d8f9c66e13e859407604b3f9c timer=78.682561ms latest_rtt=35.098792ms srtt=35.058325ms min_rtt=35.052545ms rttvar=13.156265ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=13500 app_limited=false congestion_recovery_start_time=None Rate { delivered: 958, delivered_time: Instant { tv_sec: 595, tv_nsec: 313959410 }, first_sent_time: Instant { tv_sec: 595, tv_nsec: 313959410 }, end_of_app_limited: 1, last_sent_packet: 13, largest_acked: 1, rate_sample: RateSample { delivery_rate: 27330, is_app_limited: true, interval: 35.052545ms, delivered: 958, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 595, tv_nsec: 278643352 }), send_elapsed: 0ns, ack_elapsed: 35.052545ms, rtt: 35.052545ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 481340, last_update: Instant { tv_sec: 595, tv_nsec: 348395409 }, next_time: Instant { tv_sec: 595, tv_nsec: 348395409 }, 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:43.774849178Z TRACE quiche_server] a1b82d02b6f1890d8f9c66e13e859407604b3f9c written 39 bytes with Some(SendInfo { from: [::]:443, to: [fd00:cafe:cafe::100]:47277, at: Instant { tv_sec: 595, tv_nsec: 348395409 } })
[2025-04-30T09:16:43.774859216Z TRACE quiche_server] Collecting garbage
[2025-04-30T09:16:43.774868724Z TRACE quiche_server] got 154 bytes from [fd00:cafe:cafe::100]:47277 to [::]:443
[2025-04-30T09:16:43.774875417Z TRACE quiche_server] got packet Short dcid=7888d8256e6757ba4440d787c25425c9ab063be4 key_phase=false
[2025-04-30T09:16:43.774884223Z TRACE quiche] a1b82d02b6f1890d8f9c66e13e859407604b3f9c rx pkt Short dcid=7888d8256e6757ba4440d787c25425c9ab063be4 key_phase=false len=133 pn=2 
[2025-04-30T09:16:43.774894412Z TRACE quiche] a1b82d02b6f1890d8f9c66e13e859407604b3f9c rx frm ACK delay=98 blocks=[2..2] ecn_counts=None
[2025-04-30T09:16:43.774899782Z TRACE quiche::recovery::congestion::recovery] a1b82d02b6f1890d8f9c66e13e859407604b3f9c packet newly acked 2
[2025-04-30T09:16:43.774907537Z TRACE quiche] a1b82d02b6f1890d8f9c66e13e859407604b3f9c rx frm NEW_CONNECTION_ID seq_num=1 retire_prior_to=1 conn_id=[9b, fb, 45, fb, 55, 37, 03, 54, fc, bb, 44, ad, ae, a1, 27, ab] reset_token=[17, 27, 9f, b1, 68, dc, 94, 79, 0e, 7e, 8b, 17, 90, e8, 4f, 61]
[2025-04-30T09:16:43.774914830Z TRACE quiche] a1b82d02b6f1890d8f9c66e13e859407604b3f9c path ID 0 changed DCID: old seq num 0 new seq num 1
[2025-04-30T09:16:43.774919399Z TRACE quiche] a1b82d02b6f1890d8f9c66e13e859407604b3f9c rx frm NEW_CONNECTION_ID seq_num=2 retire_prior_to=1 conn_id=[4c, e9, 1e, 5a, 87, 1b, 56, ef, 2c, c0, 17, 73, 59, 03, e4, 41] reset_token=[e4, 7f, 4e, 34, b2, 6a, 24, d4, 9f, 0a, d4, 97, 06, d6, 36, 21]
[2025-04-30T09:16:43.774926252Z TRACE quiche] a1b82d02b6f1890d8f9c66e13e859407604b3f9c rx frm NEW_CONNECTION_ID seq_num=3 retire_prior_to=1 conn_id=[e8, 12, 91, 30, 61, ea, 4f, 63, 69, 6a, f1, e2, 44, f6, fe, 11] reset_token=[db, 5d, eb, eb, 06, 44, 12, 7e, 3c, bf, 0a, b7, 5f, 92, b3, 1d]
[2025-04-30T09:16:43.774931311Z TRACE quiche] a1b82d02b6f1890d8f9c66e13e859407604b3f9c rx frm RETIRE_CONNECTION_ID seq_num=0
[2025-04-30T09:16:43.774947071Z TRACE quiche_server] a1b82d02b6f1890d8f9c66e13e859407604b3f9c processed 154 bytes
[2025-04-30T09:16:43.774951108Z DEBUG quiche_apps::common] a1b82d02b6f1890d8f9c66e13e859407604b3f9c response stream 4 is writable with capacity Ok(2700)
[2025-04-30T09:16:43.774959193Z INFO  quiche_server] Retiring source CID a1b82d02b6f1890d8f9c66e13e859407604b3f9c
[2025-04-30T09:16:43.774968671Z TRACE quiche_server] recv() would block
[2025-04-30T09:16:43.774974862Z TRACE quiche] a1b82d02b6f1890d8f9c66e13e859407604b3f9c pmtud probe status false hs_con=true hs_sent=true cwnd_avail=2700 out_len=1350 left=1311
[2025-04-30T09:16:43.774981515Z TRACE quiche] a1b82d02b6f1890d8f9c66e13e859407604b3f9c tx pkt Short dcid=9bfb45fb55370354fcbb44adaea127ab key_phase=false len=1316 pn=14 
[2025-04-30T09:16:43.774984751Z TRACE quiche] a1b82d02b6f1890d8f9c66e13e859407604b3f9c tx frm ACK delay=11 blocks=[1..2] ecn_counts=None
[2025-04-30T09:16:43.774988498Z TRACE quiche] a1b82d02b6f1890d8f9c66e13e859407604b3f9c tx frm NEW_CONNECTION_ID seq_num=3 retire_prior_to=1 conn_id=[35, c6, 3d, a6, 6d, b2, 43, 3f, 41, 50, ed, f9, 09, 12, 9d, 72, b5, b8, f3, 20] reset_token=[d3, 3c, 23, 23, 7b, 58, ea, bb, 9c, e1, 25, e2, f7, 62, d0, a2]
[2025-04-30T09:16:43.774995321Z TRACE quiche] a1b82d02b6f1890d8f9c66e13e859407604b3f9c tx frm RETIRE_CONNECTION_ID seq_num=0
[2025-04-30T09:16:43.774998186Z TRACE quiche] a1b82d02b6f1890d8f9c66e13e859407604b3f9c tx frm STREAM id=4 off=7456 len=1263 fin=false
[2025-04-30T09:16:43.775007684Z TRACE quiche::recovery::congestion::recovery] a1b82d02b6f1890d8f9c66e13e859407604b3f9c timer=99.936785ms latest_rtt=34.548038ms srtt=34.994538ms min_rtt=34.548038ms rttvar=9.994769ms cwnd=14850 ssthresh=18446744073709551615 bytes_in_flight=13500 app_limited=true congestion_recovery_start_time=None Rate { delivered: 2308, delivered_time: Instant { tv_sec: 595, tv_nsec: 348507448 }, first_sent_time: Instant { tv_sec: 595, tv_nsec: 313959410 }, end_of_app_limited: 0, last_sent_packet: 14, largest_acked: 2, rate_sample: RateSample { delivery_rate: 39076, is_app_limited: true, interval: 34.548038ms, delivered: 1350, prior_delivered: 958, prior_time: Some(Instant { tv_sec: 595, tv_nsec: 313959410 }), send_elapsed: 0ns, ack_elapsed: 34.548038ms, rtt: 34.548038ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 530439, last_update: Instant { tv_sec: 595, tv_nsec: 348395409 }, next_time: Instant { tv_sec: 595, tv_nsec: 348395409 }, max_datagram_size: 1350, last_packet_size: Some(0), iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(14) last_round_min_rtt=34.548038ms 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:43.775030156Z TRACE quiche] a1b82d02b6f1890d8f9c66e13e859407604b3f9c pmtud probe status false hs_con=true hs_sent=true cwnd_avail=1350 out_len=1350 left=1316
[2025-04-30T09:16:43.775034494Z TRACE quiche] a1b82d02b6f1890d8f9c66e13e859407604b3f9c tx pkt Short dcid=9bfb45fb55370354fcbb44adaea127ab key_phase=false len=1316 pn=15 
[2025-04-30T09:16:43.775037540Z TRACE quiche] a1b82d02b6f1890d8f9c66e13e859407604b3f9c tx frm STREAM id=4 off=8719 len=1310 fin=false
[2025-04-30T09:16:43.775043351Z TRACE quiche::recovery::congestion::recovery] a1b82d02b6f1890d8f9c66e13e859407604b3f9c timer=99.958165ms latest_rtt=34.548038ms srtt=34.994538ms min_rtt=34.548038ms rttvar=9.994769ms cwnd=14850 ssthresh=18446744073709551615 bytes_in_flight=14850 app_limited=false congestion_recovery_start_time=None Rate { delivered: 2308, delivered_time: Instant { tv_sec: 595, tv_nsec: 348507448 }, first_sent_time: Instant { tv_sec: 595, tv_nsec: 313959410 }, end_of_app_limited: 0, last_sent_packet: 15, largest_acked: 2, rate_sample: RateSample { delivery_rate: 39076, is_app_limited: true, interval: 34.548038ms, delivered: 1350, prior_delivered: 958, prior_time: Some(Instant { tv_sec: 595, tv_nsec: 313959410 }), send_elapsed: 0ns, ack_elapsed: 34.548038ms, rtt: 34.548038ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 530439, last_update: Instant { tv_sec: 595, tv_nsec: 348395409 }, next_time: Instant { tv_sec: 595, tv_nsec: 348395409 }, max_datagram_size: 1350, last_packet_size: Some(0), iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(14) last_round_min_rtt=34.548038ms 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:43.775056074Z TRACE quiche] a1b82d02b6f1890d8f9c66e13e859407604b3f9c pmtud probe status false hs_con=true hs_sent=true cwnd_avail=0 out_len=1350 left=0
[2025-04-30T09:16:43.775059821Z TRACE quiche_server] a1b82d02b6f1890d8f9c66e13e859407604b3f9c done writing
[2025-04-30T09:16:43.775103553Z TRACE quiche_server] a1b82d02b6f1890d8f9c66e13e859407604b3f9c written 2700 bytes with Some(SendInfo { from: [::]:443, to: [fd00:cafe:cafe::100]:47277, at: Instant { tv_sec: 595, tv_nsec: 348395409 } })
[2025-04-30T09:16:43.775113101Z TRACE quiche_server] Collecting garbage
[2025-04-30T09:16:43.782797633Z TRACE quiche_server] got 57 bytes from [fd00:cafe:cafe::100]:47277 to [::]:443
[2025-04-30T09:16:43.782805748Z TRACE quiche_server] got packet Short dcid=7888d8256e6757ba4440d787c25425c9ab063be4 key_phase=false
[2025-04-30T09:16:43.782811158Z TRACE quiche] a1b82d02b6f1890d8f9c66e13e859407604b3f9c rx pkt Short dcid=7888d8256e6757ba4440d787c25425c9ab063be4 key_phase=false len=36 pn=3 
[2025-04-30T09:16:43.782816478Z TRACE quiche] a1b82d02b6f1890d8f9c66e13e859407604b3f9c rx frm ACK delay=18 blocks=[2..12] ecn_counts=None
[2025-04-30T09:16:43.782819944Z TRACE quiche::recovery::congestion::recovery] a1b82d02b6f1890d8f9c66e13e859407604b3f9c packet newly acked 3
[2025-04-30T09:16:43.782827238Z TRACE quiche::recovery::congestion::recovery] a1b82d02b6f1890d8f9c66e13e859407604b3f9c packet newly acked 4
[2025-04-30T09:16:43.782829652Z TRACE quiche::recovery::congestion::recovery] a1b82d02b6f1890d8f9c66e13e859407604b3f9c packet newly acked 5
[2025-04-30T09:16:43.782831816Z TRACE quiche::recovery::congestion::recovery] a1b82d02b6f1890d8f9c66e13e859407604b3f9c packet newly acked 6
[2025-04-30T09:16:43.782834412Z TRACE quiche::recovery::congestion::recovery] a1b82d02b6f1890d8f9c66e13e859407604b3f9c packet newly acked 7
[2025-04-30T09:16:43.782837166Z TRACE quiche::recovery::congestion::recovery] a1b82d02b6f1890d8f9c66e13e859407604b3f9c packet newly acked 8
[2025-04-30T09:16:43.782839381Z TRACE quiche::recovery::congestion::recovery] a1b82d02b6f1890d8f9c66e13e859407604b3f9c packet newly acked 9
[2025-04-30T09:16:43.782841565Z TRACE quiche::recovery::congestion::recovery] a1b82d02b6f1890d8f9c66e13e859407604b3f9c packet newly acked 10
[2025-04-30T09:16:43.782844160Z TRACE quiche::recovery::congestion::recovery] a1b82d02b6f1890d8f9c66e13e859407604b3f9c packet newly acked 11
[2025-04-30T09:16:43.782846584Z TRACE quiche::recovery::congestion::recovery] a1b82d02b6f1890d8f9c66e13e859407604b3f9c packet newly acked 12
[2025-04-30T09:16:43.782850371Z TRACE quiche] a1b82d02b6f1890d8f9c66e13e859407604b3f9c rx frm PADDING len=14
[2025-04-30T09:16:43.782866792Z TRACE quiche_server] a1b82d02b6f1890d8f9c66e13e859407604b3f9c processed 57 bytes
[2025-04-30T09:16:43.782871080Z TRACE quiche_server] recv() would block
[2025-04-30T09:16:43.782875819Z TRACE quiche] a1b82d02b6f1890d8f9c66e13e859407604b3f9c pmtud probe status false hs_con=true hs_sent=true cwnd_avail=22274 out_len=1350 left=1316
[2025-04-30T09:16:43.782879816Z TRACE quiche] a1b82d02b6f1890d8f9c66e13e859407604b3f9c tx pkt Short dcid=9bfb45fb55370354fcbb44adaea127ab key_phase=false len=217 pn=16 
[2025-04-30T09:16:43.782882301Z TRACE quiche] a1b82d02b6f1890d8f9c66e13e859407604b3f9c tx frm STREAM id=4 off=10029 len=211 fin=true
[2025-04-30T09:16:43.782888412Z TRACE quiche::recovery::congestion::recovery] a1b82d02b6f1890d8f9c66e13e859407604b3f9c timer=98.216853ms latest_rtt=42.475093ms srtt=35.911606ms min_rtt=34.548038ms rttvar=9.330214ms cwnd=24974 ssthresh=18446744073709551615 bytes_in_flight=2951 app_limited=true congestion_recovery_start_time=None Rate { delivered: 14458, delivered_time: Instant { tv_sec: 595, tv_nsec: 356434503 }, first_sent_time: Instant { tv_sec: 595, tv_nsec: 313959410 }, end_of_app_limited: 15, last_sent_packet: 16, largest_acked: 12, rate_sample: RateSample { delivery_rate: 390760, is_app_limited: true, interval: 34.548038ms, delivered: 13500, prior_delivered: 958, prior_time: Some(Instant { tv_sec: 595, tv_nsec: 313959410 }), send_elapsed: 0ns, ack_elapsed: 34.548038ms, rtt: 34.548038ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 869287, last_update: Instant { tv_sec: 595, tv_nsec: 348395409 }, next_time: Instant { tv_sec: 595, tv_nsec: 348395409 }, max_datagram_size: 1350, last_packet_size: Some(0), iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(14) last_round_min_rtt=34.548038ms current_round_min_rtt=42.475093ms css_baseline_min_rtt=42.475093ms rtt_sample_count=1 css_start_time=Some(Instant { tv_sec: 595, tv_nsec: 356434503 }) css_round_count=0 cubic={ k=0 w_max=0 } 
[2025-04-30T09:16:43.782920723Z TRACE quiche_server] a1b82d02b6f1890d8f9c66e13e859407604b3f9c written 251 bytes with Some(SendInfo { from: [::]:443, to: [fd00:cafe:cafe::100]:47277, at: Instant { tv_sec: 595, tv_nsec: 348395409 } })
[2025-04-30T09:16:43.782928317Z TRACE quiche_server] Collecting garbage
[2025-04-30T09:16:43.782933426Z TRACE quiche_server] recv() would block
[2025-04-30T09:16:43.782937835Z TRACE quiche_server] a1b82d02b6f1890d8f9c66e13e859407604b3f9c done writing
[2025-04-30T09:16:43.782941882Z TRACE quiche_server] Collecting garbage
[2025-04-30T09:16:43.814452772Z TRACE quiche_server] got 57 bytes from [fd00:cafe:cafe::100]:47277 to [::]:443
[2025-04-30T09:16:43.814464555Z TRACE quiche_server] got packet Short dcid=7888d8256e6757ba4440d787c25425c9ab063be4 key_phase=false
[2025-04-30T09:16:43.814476687Z TRACE quiche] a1b82d02b6f1890d8f9c66e13e859407604b3f9c rx pkt Short dcid=7888d8256e6757ba4440d787c25425c9ab063be4 key_phase=false len=36 pn=5 
[2025-04-30T09:16:43.814482899Z TRACE quiche] a1b82d02b6f1890d8f9c66e13e859407604b3f9c rx frm CONNECTION_CLOSE err=0 frame=0 reason=[]
[2025-04-30T09:16:43.814486686Z TRACE quiche] a1b82d02b6f1890d8f9c66e13e859407604b3f9c rx frm PADDING len=15
[2025-04-30T09:16:43.814495102Z TRACE quiche_server] a1b82d02b6f1890d8f9c66e13e859407604b3f9c processed 57 bytes
[2025-04-30T09:16:43.814499771Z TRACE quiche_server] recv() would block
[2025-04-30T09:16:43.814502165Z TRACE quiche_server] a1b82d02b6f1890d8f9c66e13e859407604b3f9c done writing
[2025-04-30T09:16:43.814504509Z TRACE quiche_server] Collecting garbage
[2025-04-30T09:16:44.034745369Z TRACE quiche_server] timed out
[2025-04-30T09:16:44.034774633Z TRACE quiche] a1b82d02b6f1890d8f9c66e13e859407604b3f9c draining timeout expired
[2025-04-30T09:16:44.034817874Z TRACE quiche_server] a1b82d02b6f1890d8f9c66e13e859407604b3f9c done writing
[2025-04-30T09:16:44.034821291Z TRACE quiche_server] Collecting garbage
[2025-04-30T09:16:44.034824737Z INFO  quiche_server] a1b82d02b6f1890d8f9c66e13e859407604b3f9c connection collected recv=8 sent=17 lost=0 retrans=0 sent_bytes=17448 recv_bytes=4265 lost_bytes=0 [local_addr=[::]:443 peer_addr=[fd00:cafe:cafe::100]:47277 validation_state=Validated active=true recv=8 sent=17 lost=0 retrans=0 rtt=35.911606ms min_rtt=Some(34.548038ms) rttvar=9.330214ms cwnd=24974 sent_bytes=17448 recv_bytes=4265 lost_bytes=0 stream_retrans_bytes=0 pmtu=1350 delivery_rate=390760]