[2025-09-12T02:33:10.449706815Z INFO quiche_server] listening on [::]:443 [2025-09-12T02:33:10.449727854Z TRACE mio::poll] registering event source with poller: token=Token(0), interests=READABLE [2025-09-12T02:33:10.449733976Z TRACE quiche_server] GSO detected: false [2025-09-12T02:33:10.782752058Z TRACE quiche_server] got 1207 bytes from [::ffff:193.167.100.2]:35587 to [::]:443 [2025-09-12T02:33:10.782783616Z TRACE quiche_server] got packet Initial version=57414954 dcid= scid= token= [2025-09-12T02:33:10.782791180Z WARN quiche_server] Doing version negotiation [2025-09-12T02:33:10.782851734Z TRACE quiche_server] recv() would block [2025-09-12T02:33:11.478232742Z TRACE quiche_server] got 1252 bytes from [::ffff:193.167.0.100]:40446 to [::]:443 [2025-09-12T02:33:11.478253992Z TRACE quiche_server] got packet Initial version=1 dcid=225db2744b00c6109d scid= token= [2025-09-12T02:33:11.478266395Z DEBUG quiche_server] New connection: dcid=225db2744b00c6109d scid=edb86c75c7613dd7530dac786ae13d2674d0b4c9 [2025-09-12T02:33:11.478427997Z TRACE quiche] edb86c75c7613dd7530dac786ae13d2674d0b4c9 rx pkt Initial version=1 dcid=225db2744b00c6109d scid= token= len=1233 pn=28 [2025-09-12T02:33:11.478440650Z TRACE quiche] edb86c75c7613dd7530dac786ae13d2674d0b4c9 rx frm CRYPTO off=0 len=1212 [2025-09-12T02:33:11.478472219Z TRACE quiche_server] edb86c75c7613dd7530dac786ae13d2674d0b4c9 processed 1252 bytes [2025-09-12T02:33:11.478482108Z TRACE quiche_server] got 1252 bytes from [::ffff:193.167.0.100]:40446 to [::]:443 [2025-09-12T02:33:11.478485734Z TRACE quiche_server] got packet Initial version=1 dcid=225db2744b00c6109d scid= token= [2025-09-12T02:33:11.478489993Z TRACE quiche] edb86c75c7613dd7530dac786ae13d2674d0b4c9 rx pkt Initial version=1 dcid=225db2744b00c6109d scid= token= len=350 pn=29 [2025-09-12T02:33:11.478493950Z TRACE quiche] edb86c75c7613dd7530dac786ae13d2674d0b4c9 rx frm CRYPTO off=1212 len=328 [2025-09-12T02:33:11.478545055Z TRACE quiche::tls] checking peer ALPN Ok("hq-interop") against Ok("h3") [2025-09-12T02:33:11.478552619Z TRACE quiche::tls] checking peer ALPN Ok("hq-interop") against Ok("hq-interop") [2025-09-12T02:33:11.478638560Z TRACE quiche::tls] edb86c75c7613dd7530dac786ae13d2674d0b4c9 write message lvl=Initial len=90 [2025-09-12T02:33:11.478663286Z TRACE quiche::tls] edb86c75c7613dd7530dac786ae13d2674d0b4c9 set write secret lvl=Handshake [2025-09-12T02:33:11.478727276Z TRACE quiche::tls] edb86c75c7613dd7530dac786ae13d2674d0b4c9 write message lvl=Handshake len=698 [2025-09-12T02:33:11.478730051Z TRACE quiche::tls] edb86c75c7613dd7530dac786ae13d2674d0b4c9 set write secret lvl=OneRTT [2025-09-12T02:33:11.478736323Z TRACE quiche::tls] edb86c75c7613dd7530dac786ae13d2674d0b4c9 set read secret lvl=Handshake [2025-09-12T02:33:11.478753004Z TRACE quiche] edb86c75c7613dd7530dac786ae13d2674d0b4c9 dropped invalid packet [2025-09-12T02:33:11.478755659Z TRACE quiche_server] edb86c75c7613dd7530dac786ae13d2674d0b4c9 processed 1252 bytes [2025-09-12T02:33:11.478769124Z TRACE quiche_server] recv() would block [2025-09-12T02:33:11.478781417Z TRACE quiche] edb86c75c7613dd7530dac786ae13d2674d0b4c9 tx pkt Initial version=1 dcid= scid=edb86c75c7613dd7530dac786ae13d2674d0b4c9 len=99 pn=0 [2025-09-12T02:33:11.478784683Z TRACE quiche] edb86c75c7613dd7530dac786ae13d2674d0b4c9 tx frm ACK delay=36 blocks=[28..29] ecn_counts=None [2025-09-12T02:33:11.478789432Z TRACE quiche] edb86c75c7613dd7530dac786ae13d2674d0b4c9 tx frm CRYPTO off=0 len=90 [2025-09-12T02:33:11.478798178Z TRACE quiche::recovery::congestion::recovery] edb86c75c7613dd7530dac786ae13d2674d0b4c9 timer=998.97318ms 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: 1138, tv_nsec: 224261259 }, first_sent_time: Instant { tv_sec: 1138, tv_nsec: 224261259 }, end_of_app_limited: 1, last_sent_packet: 0, largest_acked: 0, rate_sample: RateSample { bandwidth: 0.00 Kbps, 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: 1138, tv_nsec: 224261259 }, next_time: Instant { tv_sec: 1138, tv_nsec: 224261259 }, 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-09-12T02:33:11.478825620Z TRACE quiche] edb86c75c7613dd7530dac786ae13d2674d0b4c9 tx pkt Handshake version=1 dcid= scid=edb86c75c7613dd7530dac786ae13d2674d0b4c9 len=702 pn=1 [2025-09-12T02:33:11.478828385Z TRACE quiche] edb86c75c7613dd7530dac786ae13d2674d0b4c9 tx frm CRYPTO off=0 len=698 [2025-09-12T02:33:11.478834095Z TRACE quiche::recovery::congestion::recovery] edb86c75c7613dd7530dac786ae13d2674d0b4c9 timer=998.937574ms latest_rtt=0ns srtt=333ms min_rtt=333ms rttvar=166.5ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=894 app_limited=true congestion_recovery_start_time=None Rate { delivered: 0, delivered_time: Instant { tv_sec: 1138, tv_nsec: 224261259 }, first_sent_time: Instant { tv_sec: 1138, tv_nsec: 224261259 }, end_of_app_limited: 1, last_sent_packet: 1, largest_acked: 0, rate_sample: RateSample { bandwidth: 0.00 Kbps, 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: 1138, tv_nsec: 224261259 }, next_time: Instant { tv_sec: 1138, tv_nsec: 224261259 }, 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-09-12T02:33:11.478878208Z TRACE quiche_server] edb86c75c7613dd7530dac786ae13d2674d0b4c9 written 1200 bytes with Some(SendInfo { from: [::]:443, to: [::ffff:193.167.0.100]:40446, at: Instant { tv_sec: 1138, tv_nsec: 224261259 } }) [2025-09-12T02:33:11.478887495Z TRACE quiche_server] Collecting garbage [2025-09-12T02:33:11.478894398Z TRACE quiche_server] recv() would block [2025-09-12T02:33:11.478901461Z TRACE quiche_server] edb86c75c7613dd7530dac786ae13d2674d0b4c9 done writing [2025-09-12T02:33:11.478904216Z TRACE quiche_server] Collecting garbage [2025-09-12T02:33:11.511730400Z TRACE quiche_server] got 105 bytes from [::ffff:193.167.0.100]:40446 to [::]:443 [2025-09-12T02:33:11.511746931Z TRACE quiche_server] got packet Initial version=1 dcid=edb86c75c7613dd7530dac786ae13d2674d0b4c9 scid= token= [2025-09-12T02:33:11.511757090Z TRACE quiche] edb86c75c7613dd7530dac786ae13d2674d0b4c9 rx pkt Initial version=1 dcid=edb86c75c7613dd7530dac786ae13d2674d0b4c9 scid= token= len=23 pn=30 [2025-09-12T02:33:11.511766187Z TRACE quiche] edb86c75c7613dd7530dac786ae13d2674d0b4c9 rx frm ACK delay=168 blocks=[0..0] ecn_counts=None [2025-09-12T02:33:11.511772138Z TRACE quiche::recovery::congestion::recovery] edb86c75c7613dd7530dac786ae13d2674d0b4c9 packet newly acked 0 [2025-09-12T02:33:11.511791344Z TRACE quiche] edb86c75c7613dd7530dac786ae13d2674d0b4c9 rx pkt Handshake version=1 dcid=edb86c75c7613dd7530dac786ae13d2674d0b4c9 scid= len=23 pn=0 [2025-09-12T02:33:11.511796344Z TRACE quiche] edb86c75c7613dd7530dac786ae13d2674d0b4c9 rx frm ACK delay=168 blocks=[1..1] ecn_counts=None [2025-09-12T02:33:11.511799750Z TRACE quiche::recovery::congestion::recovery] edb86c75c7613dd7530dac786ae13d2674d0b4c9 packet newly acked 1 [2025-09-12T02:33:11.511809979Z TRACE quiche] edb86c75c7613dd7530dac786ae13d2674d0b4c9 dropped epoch 0 state [2025-09-12T02:33:11.511813366Z TRACE quiche_server] edb86c75c7613dd7530dac786ae13d2674d0b4c9 processed 105 bytes [2025-09-12T02:33:11.511825879Z TRACE quiche_server] recv() would block [2025-09-12T02:33:11.511833333Z TRACE quiche_server] edb86c75c7613dd7530dac786ae13d2674d0b4c9 done writing [2025-09-12T02:33:11.511836469Z TRACE quiche_server] Collecting garbage [2025-09-12T02:33:11.512244781Z TRACE quiche_server] got 143 bytes from [::ffff:193.167.0.100]:40446 to [::]:443 [2025-09-12T02:33:11.512248789Z TRACE quiche_server] got packet Handshake version=1 dcid=edb86c75c7613dd7530dac786ae13d2674d0b4c9 scid= [2025-09-12T02:33:11.512253478Z TRACE quiche] edb86c75c7613dd7530dac786ae13d2674d0b4c9 rx pkt Handshake version=1 dcid=edb86c75c7613dd7530dac786ae13d2674d0b4c9 scid= len=56 pn=1 [2025-09-12T02:33:11.512258477Z TRACE quiche] edb86c75c7613dd7530dac786ae13d2674d0b4c9 rx frm CRYPTO off=0 len=36 [2025-09-12T02:33:11.512269067Z TRACE quiche::tls] edb86c75c7613dd7530dac786ae13d2674d0b4c9 set read secret lvl=OneRTT [2025-09-12T02:33:11.512304022Z TRACE quiche::tls] edb86c75c7613dd7530dac786ae13d2674d0b4c9 write message lvl=OneRTT len=396 [2025-09-12T02:33:11.512310094Z TRACE quiche] edb86c75c7613dd7530dac786ae13d2674d0b4c9 dropped epoch 1 state [2025-09-12T02:33:11.512313229Z TRACE quiche] edb86c75c7613dd7530dac786ae13d2674d0b4c9 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: 65527, initial_max_data: 4611686018427387903, initial_max_stream_data_bidi_local: 1048576, initial_max_stream_data_bidi_remote: 1048576, initial_max_stream_data_uni: 1048576, initial_max_streams_bidi: 16, initial_max_streams_uni: 16, ack_delay_exponent: 3, max_ack_delay: 20, disable_active_migration: false, active_conn_id_limit: 8, initial_source_connection_id: Some(), retry_source_connection_id: None, max_datagram_frame_size: Some(1200), unknown_params: None } [2025-09-12T02:33:11.512330191Z TRACE quiche] edb86c75c7613dd7530dac786ae13d2674d0b4c9 rx pkt Short dcid=edb86c75c7613dd7530dac786ae13d2674d0b4c9 key_phase=false len=37 pn=0 [2025-09-12T02:33:11.512334769Z TRACE quiche] edb86c75c7613dd7530dac786ae13d2674d0b4c9 rx frm STREAM id=0 off=0 len=17 fin=true [2025-09-12T02:33:11.512340901Z TRACE quiche_server] edb86c75c7613dd7530dac786ae13d2674d0b4c9 processed 143 bytes [2025-09-12T02:33:11.512344418Z DEBUG quiche_apps::common] edb86c75c7613dd7530dac786ae13d2674d0b4c9 response stream 0 is writable with capacity Ok(13500) [2025-09-12T02:33:11.512350349Z TRACE quiche_apps::common] edb86c75c7613dd7530dac786ae13d2674d0b4c9 received 17 bytes [2025-09-12T02:33:11.512352943Z TRACE quiche_apps::common] edb86c75c7613dd7530dac786ae13d2674d0b4c9 stream 0 has 17 bytes (fin? true) [2025-09-12T02:33:11.512357071Z INFO quiche_apps::common] edb86c75c7613dd7530dac786ae13d2674d0b4c9 got GET request for "/www/aioklsyade" on stream 0 [2025-09-12T02:33:11.512378582Z INFO quiche_apps::common] edb86c75c7613dd7530dac786ae13d2674d0b4c9 sending response of size 5120 on stream 0 [2025-09-12T02:33:11.512386015Z TRACE quiche_server] recv() would block [2025-09-12T02:33:11.512398168Z TRACE quiche] edb86c75c7613dd7530dac786ae13d2674d0b4c9 tx pkt Short dcid= key_phase=false len=1332 pn=2 [2025-09-12T02:33:11.512401414Z TRACE quiche] edb86c75c7613dd7530dac786ae13d2674d0b4c9 tx frm ACK delay=7 blocks=[0..0] ecn_counts=None [2025-09-12T02:33:11.512404871Z TRACE quiche] edb86c75c7613dd7530dac786ae13d2674d0b4c9 tx frm NEW_CONNECTION_ID seq_num=1 retire_prior_to=0 conn_id=[0d, be, a3, 0a, 41, 4a, d3, eb, d7, e0, f3, 7c, 52, d3, eb, ef, d7, ce, 44, 09] reset_token=[b6, 16, 3f, f1, 24, 5d, 92, 59, 85, 68, 8d, 46, 05, 55, 30, ca] [2025-09-12T02:33:11.512411643Z TRACE quiche] edb86c75c7613dd7530dac786ae13d2674d0b4c9 tx frm NEW_CONNECTION_ID seq_num=2 retire_prior_to=0 conn_id=[b8, ec, db, 11, 24, ac, 68, e9, af, 6b, 8f, 9d, a0, 64, 71, 50, ea, ce, 42, 74] reset_token=[8c, 6e, 0e, 5b, 02, a8, fb, f2, db, 52, 8b, 56, 48, 5b, aa, 3b] [2025-09-12T02:33:11.512417324Z TRACE quiche] edb86c75c7613dd7530dac786ae13d2674d0b4c9 tx frm NEW_CONNECTION_ID seq_num=3 retire_prior_to=0 conn_id=[4b, e6, 83, 25, 1d, ec, c3, ff, 9c, f3, d1, 29, 28, b7, 32, 15, 79, ff, 35, b3] reset_token=[65, 55, d1, b0, 6a, dc, 46, cd, e2, 73, 89, 17, 6c, 13, 9d, dd] [2025-09-12T02:33:11.512427473Z TRACE quiche] edb86c75c7613dd7530dac786ae13d2674d0b4c9 tx frm NEW_CONNECTION_ID seq_num=4 retire_prior_to=0 conn_id=[ff, aa, d4, 25, d3, a1, 6c, 59, f1, 22, a3, 29, ae, 97, 29, c1, 29, ce, e1, 0c] reset_token=[f0, ec, 59, f5, 55, 6f, 4c, e3, d5, cc, bd, 7a, e5, c7, 94, 0c] [2025-09-12T02:33:11.512432993Z TRACE quiche] edb86c75c7613dd7530dac786ae13d2674d0b4c9 tx frm NEW_CONNECTION_ID seq_num=5 retire_prior_to=0 conn_id=[27, 06, 23, 1b, 2f, 01, cb, cb, f5, 64, b7, 7b, 2d, 94, e4, ca, d5, 9f, 1f, b5] reset_token=[ec, b3, a3, 83, 12, c4, a3, 60, c3, 3c, 85, 03, 13, 84, 03, e0] [2025-09-12T02:33:11.512438523Z TRACE quiche] edb86c75c7613dd7530dac786ae13d2674d0b4c9 tx frm NEW_CONNECTION_ID seq_num=6 retire_prior_to=0 conn_id=[04, 31, ab, b8, 7a, c9, 8a, 62, ac, 6b, bb, 58, b9, 25, 60, 83, 0e, 7f, 50, 67] reset_token=[51, 3d, 68, ef, f0, 04, 9b, 2b, 80, 9d, d0, ae, ca, 1d, 13, 9e] [2025-09-12T02:33:11.512443893Z TRACE quiche] edb86c75c7613dd7530dac786ae13d2674d0b4c9 tx frm NEW_CONNECTION_ID seq_num=7 retire_prior_to=0 conn_id=[11, 05, eb, 41, 13, bf, af, 9d, 33, 2f, ea, 09, 61, 84, 0b, 69, 75, 9d, 24, e1] reset_token=[99, 39, a9, dd, 97, d6, 77, 85, 4b, 33, 5d, c4, 3c, a0, 92, 5b] [2025-09-12T02:33:11.512449183Z TRACE quiche] edb86c75c7613dd7530dac786ae13d2674d0b4c9 tx frm HANDSHAKE_DONE [2025-09-12T02:33:11.512451427Z TRACE quiche] edb86c75c7613dd7530dac786ae13d2674d0b4c9 tx frm CRYPTO off=0 len=396 [2025-09-12T02:33:11.512453772Z TRACE quiche] edb86c75c7613dd7530dac786ae13d2674d0b4c9 tx frm STREAM id=0 off=0 len=641 fin=false [2025-09-12T02:33:11.512466185Z TRACE quiche::recovery::congestion::recovery] edb86c75c7613dd7530dac786ae13d2674d0b4c9 timer=102.418812ms latest_rtt=33.018733ms srtt=32.987086ms min_rtt=32.982566ms rttvar=12.377503ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=1350 app_limited=true congestion_recovery_start_time=None Rate { delivered: 894, delivered_time: Instant { tv_sec: 1138, tv_nsec: 257877619 }, first_sent_time: Instant { tv_sec: 1138, tv_nsec: 257877619 }, end_of_app_limited: 1, last_sent_packet: 2, largest_acked: 1, rate_sample: RateSample { bandwidth: 216.60 Kbps, is_app_limited: true, interval: 33.018733ms, delivered: 894, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 1138, tv_nsec: 224261259 }), send_elapsed: 0ns, ack_elapsed: 33.018733ms, rtt: 33.018733ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 511563, last_update: Instant { tv_sec: 1138, tv_nsec: 257877619 }, next_time: Instant { tv_sec: 1138, tv_nsec: 257877619 }, 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-09-12T02:33:11.512484199Z TRACE quiche] edb86c75c7613dd7530dac786ae13d2674d0b4c9 tx pkt Short dcid= key_phase=false len=1332 pn=3 [2025-09-12T02:33:11.512486934Z TRACE quiche] edb86c75c7613dd7530dac786ae13d2674d0b4c9 tx frm STREAM id=0 off=641 len=1326 fin=false [2025-09-12T02:33:11.512491993Z TRACE quiche::recovery::congestion::recovery] edb86c75c7613dd7530dac786ae13d2674d0b4c9 timer=102.486618ms latest_rtt=33.018733ms srtt=32.987086ms min_rtt=32.982566ms rttvar=12.377503ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=2700 app_limited=true congestion_recovery_start_time=None Rate { delivered: 894, delivered_time: Instant { tv_sec: 1138, tv_nsec: 257877619 }, first_sent_time: Instant { tv_sec: 1138, tv_nsec: 257877619 }, end_of_app_limited: 2, last_sent_packet: 3, largest_acked: 1, rate_sample: RateSample { bandwidth: 216.60 Kbps, is_app_limited: true, interval: 33.018733ms, delivered: 894, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 1138, tv_nsec: 224261259 }), send_elapsed: 0ns, ack_elapsed: 33.018733ms, rtt: 33.018733ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 511563, last_update: Instant { tv_sec: 1138, tv_nsec: 257877619 }, next_time: Instant { tv_sec: 1138, tv_nsec: 257877619 }, 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-09-12T02:33:11.512506681Z TRACE quiche] edb86c75c7613dd7530dac786ae13d2674d0b4c9 tx pkt Short dcid= key_phase=false len=1332 pn=4 [2025-09-12T02:33:11.512509266Z TRACE quiche] edb86c75c7613dd7530dac786ae13d2674d0b4c9 tx frm STREAM id=0 off=1967 len=1326 fin=false [2025-09-12T02:33:11.512534422Z TRACE quiche::recovery::congestion::recovery] edb86c75c7613dd7530dac786ae13d2674d0b4c9 timer=102.467452ms latest_rtt=33.018733ms srtt=32.987086ms min_rtt=32.982566ms rttvar=12.377503ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=4050 app_limited=true congestion_recovery_start_time=None Rate { delivered: 894, delivered_time: Instant { tv_sec: 1138, tv_nsec: 257877619 }, first_sent_time: Instant { tv_sec: 1138, tv_nsec: 257877619 }, end_of_app_limited: 3, last_sent_packet: 4, largest_acked: 1, rate_sample: RateSample { bandwidth: 216.60 Kbps, is_app_limited: true, interval: 33.018733ms, delivered: 894, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 1138, tv_nsec: 224261259 }), send_elapsed: 0ns, ack_elapsed: 33.018733ms, rtt: 33.018733ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 511563, last_update: Instant { tv_sec: 1138, tv_nsec: 257877619 }, next_time: Instant { tv_sec: 1138, tv_nsec: 257877619 }, 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-09-12T02:33:11.512549521Z TRACE quiche] edb86c75c7613dd7530dac786ae13d2674d0b4c9 tx pkt Short dcid= key_phase=false len=1332 pn=5 [2025-09-12T02:33:11.512552126Z TRACE quiche] edb86c75c7613dd7530dac786ae13d2674d0b4c9 tx frm STREAM id=0 off=3293 len=1326 fin=false [2025-09-12T02:33:11.512556554Z TRACE quiche::recovery::congestion::recovery] edb86c75c7613dd7530dac786ae13d2674d0b4c9 timer=102.48774ms latest_rtt=33.018733ms srtt=32.987086ms min_rtt=32.982566ms rttvar=12.377503ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=5400 app_limited=true congestion_recovery_start_time=None Rate { delivered: 894, delivered_time: Instant { tv_sec: 1138, tv_nsec: 257877619 }, first_sent_time: Instant { tv_sec: 1138, tv_nsec: 257877619 }, end_of_app_limited: 4, last_sent_packet: 5, largest_acked: 1, rate_sample: RateSample { bandwidth: 216.60 Kbps, is_app_limited: true, interval: 33.018733ms, delivered: 894, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 1138, tv_nsec: 224261259 }), send_elapsed: 0ns, ack_elapsed: 33.018733ms, rtt: 33.018733ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 511563, last_update: Instant { tv_sec: 1138, tv_nsec: 257877619 }, next_time: Instant { tv_sec: 1138, tv_nsec: 257877619 }, 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-09-12T02:33:11.512567083Z TRACE quiche] edb86c75c7613dd7530dac786ae13d2674d0b4c9 tx pkt Short dcid= key_phase=false len=507 pn=6 [2025-09-12T02:33:11.512569618Z TRACE quiche] edb86c75c7613dd7530dac786ae13d2674d0b4c9 tx frm STREAM id=0 off=4619 len=501 fin=true [2025-09-12T02:33:11.512592481Z TRACE quiche::recovery::congestion::recovery] edb86c75c7613dd7530dac786ae13d2674d0b4c9 timer=102.470228ms latest_rtt=33.018733ms srtt=32.987086ms min_rtt=32.982566ms rttvar=12.377503ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=5925 app_limited=true congestion_recovery_start_time=None Rate { delivered: 894, delivered_time: Instant { tv_sec: 1138, tv_nsec: 257877619 }, first_sent_time: Instant { tv_sec: 1138, tv_nsec: 257877619 }, end_of_app_limited: 5, last_sent_packet: 6, largest_acked: 1, rate_sample: RateSample { bandwidth: 216.60 Kbps, is_app_limited: true, interval: 33.018733ms, delivered: 894, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 1138, tv_nsec: 224261259 }), send_elapsed: 0ns, ack_elapsed: 33.018733ms, rtt: 33.018733ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 511563, last_update: Instant { tv_sec: 1138, tv_nsec: 257877619 }, next_time: Instant { tv_sec: 1138, tv_nsec: 257877619 }, 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-09-12T02:33:11.512678061Z TRACE quiche_server] edb86c75c7613dd7530dac786ae13d2674d0b4c9 written 5925 bytes with Some(SendInfo { from: [::]:443, to: [::ffff:193.167.0.100]:40446, at: Instant { tv_sec: 1138, tv_nsec: 257877619 } }) [2025-09-12T02:33:11.512687008Z TRACE quiche_server] Collecting garbage [2025-09-12T02:33:11.512692378Z TRACE quiche_server] recv() would block [2025-09-12T02:33:11.512697998Z TRACE quiche_server] edb86c75c7613dd7530dac786ae13d2674d0b4c9 done writing [2025-09-12T02:33:11.512701575Z TRACE quiche_server] Collecting garbage [2025-09-12T02:33:11.545498071Z TRACE quiche_server] got 1352 bytes from [::ffff:193.167.0.100]:40446 to [::]:443 [2025-09-12T02:33:11.545509693Z TRACE quiche_server] got packet Short dcid=edb86c75c7613dd7530dac786ae13d2674d0b4c9 key_phase=false [2025-09-12T02:33:11.545537705Z TRACE quiche] edb86c75c7613dd7530dac786ae13d2674d0b4c9 rx pkt Short dcid=edb86c75c7613dd7530dac786ae13d2674d0b4c9 key_phase=false len=1331 pn=1 [2025-09-12T02:33:11.545545069Z TRACE quiche] edb86c75c7613dd7530dac786ae13d2674d0b4c9 rx frm ACK delay=36 blocks=[2..2] ecn_counts=None [2025-09-12T02:33:11.545549467Z TRACE quiche::recovery::congestion::recovery] edb86c75c7613dd7530dac786ae13d2674d0b4c9 packet newly acked 2 [2025-09-12T02:33:11.545554416Z TRACE quiche] edb86c75c7613dd7530dac786ae13d2674d0b4c9 rx frm PING mtu_probe=None [2025-09-12T02:33:11.545560858Z TRACE quiche] edb86c75c7613dd7530dac786ae13d2674d0b4c9 rx frm PADDING len=1308 [2025-09-12T02:33:11.545572540Z TRACE quiche_server] edb86c75c7613dd7530dac786ae13d2674d0b4c9 processed 1352 bytes [2025-09-12T02:33:11.545577199Z TRACE quiche_server] recv() would block [2025-09-12T02:33:11.545583932Z TRACE quiche] edb86c75c7613dd7530dac786ae13d2674d0b4c9 tx pkt Short dcid= key_phase=false len=5 pn=7 [2025-09-12T02:33:11.545586717Z TRACE quiche] edb86c75c7613dd7530dac786ae13d2674d0b4c9 tx frm ACK delay=5 blocks=[1..1] ecn_counts=None [2025-09-12T02:33:11.545593109Z TRACE quiche::recovery::congestion::recovery] edb86c75c7613dd7530dac786ae13d2674d0b4c9 timer=57.27266ms latest_rtt=33.147652ms srtt=33.007156ms min_rtt=32.982566ms rttvar=9.323268ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=4575 app_limited=true congestion_recovery_start_time=None Rate { delivered: 2244, delivered_time: Instant { tv_sec: 1138, tv_nsec: 291025271 }, first_sent_time: Instant { tv_sec: 1138, tv_nsec: 257877619 }, end_of_app_limited: 6, last_sent_packet: 7, largest_acked: 2, rate_sample: RateSample { bandwidth: 325.81 Kbps, is_app_limited: true, interval: 33.147652ms, delivered: 1350, prior_delivered: 894, prior_time: Some(Instant { tv_sec: 1138, tv_nsec: 257877619 }), send_elapsed: 0ns, ack_elapsed: 33.147652ms, rtt: 33.147652ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 511252, last_update: Instant { tv_sec: 1138, tv_nsec: 291068853 }, next_time: Instant { tv_sec: 1138, tv_nsec: 291068853 }, 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-09-12T02:33:11.545638153Z TRACE quiche_server] edb86c75c7613dd7530dac786ae13d2674d0b4c9 written 23 bytes with Some(SendInfo { from: [::]:443, to: [::ffff:193.167.0.100]:40446, at: Instant { tv_sec: 1138, tv_nsec: 291068853 } }) [2025-09-12T02:33:11.545643643Z TRACE quiche_server] Collecting garbage [2025-09-12T02:33:11.545647600Z TRACE quiche_server] recv() would block [2025-09-12T02:33:11.545650556Z TRACE quiche_server] edb86c75c7613dd7530dac786ae13d2674d0b4c9 done writing [2025-09-12T02:33:11.545652770Z TRACE quiche_server] Collecting garbage [2025-09-12T02:33:11.546350103Z TRACE quiche_server] got 43 bytes from [::ffff:193.167.0.100]:40446 to [::]:443 [2025-09-12T02:33:11.546353930Z TRACE quiche_server] got packet Short dcid=edb86c75c7613dd7530dac786ae13d2674d0b4c9 key_phase=false [2025-09-12T02:33:11.546359029Z TRACE quiche] edb86c75c7613dd7530dac786ae13d2674d0b4c9 rx pkt Short dcid=edb86c75c7613dd7530dac786ae13d2674d0b4c9 key_phase=false len=22 pn=2 [2025-09-12T02:33:11.546364079Z TRACE quiche] edb86c75c7613dd7530dac786ae13d2674d0b4c9 rx frm ACK delay=3 blocks=[2..4] ecn_counts=None [2025-09-12T02:33:11.546367315Z TRACE quiche::recovery::congestion::recovery] edb86c75c7613dd7530dac786ae13d2674d0b4c9 packet newly acked 3 [2025-09-12T02:33:11.546369790Z TRACE quiche::recovery::congestion::recovery] edb86c75c7613dd7530dac786ae13d2674d0b4c9 packet newly acked 4 [2025-09-12T02:33:11.546378987Z TRACE quiche_server] edb86c75c7613dd7530dac786ae13d2674d0b4c9 processed 43 bytes [2025-09-12T02:33:11.546382724Z TRACE quiche_server] recv() would block [2025-09-12T02:33:11.546385439Z TRACE quiche_server] edb86c75c7613dd7530dac786ae13d2674d0b4c9 done writing [2025-09-12T02:33:11.546387613Z TRACE quiche_server] Collecting garbage [2025-09-12T02:33:11.547848153Z TRACE quiche_server] got 43 bytes from [::ffff:193.167.0.100]:40446 to [::]:443 [2025-09-12T02:33:11.547856509Z TRACE quiche_server] got packet Short dcid=edb86c75c7613dd7530dac786ae13d2674d0b4c9 key_phase=false [2025-09-12T02:33:11.547861889Z TRACE quiche] edb86c75c7613dd7530dac786ae13d2674d0b4c9 rx pkt Short dcid=edb86c75c7613dd7530dac786ae13d2674d0b4c9 key_phase=false len=22 pn=3 [2025-09-12T02:33:11.547866999Z TRACE quiche] edb86c75c7613dd7530dac786ae13d2674d0b4c9 rx frm ACK delay=2 blocks=[2..6] ecn_counts=None [2025-09-12T02:33:11.547870395Z TRACE quiche::recovery::congestion::recovery] edb86c75c7613dd7530dac786ae13d2674d0b4c9 packet newly acked 5 [2025-09-12T02:33:11.547872750Z TRACE quiche::recovery::congestion::recovery] edb86c75c7613dd7530dac786ae13d2674d0b4c9 packet newly acked 6 [2025-09-12T02:33:11.547884111Z TRACE quiche_server] edb86c75c7613dd7530dac786ae13d2674d0b4c9 processed 43 bytes [2025-09-12T02:33:11.547888178Z TRACE quiche_server] recv() would block [2025-09-12T02:33:11.547891194Z TRACE quiche_server] edb86c75c7613dd7530dac786ae13d2674d0b4c9 done writing [2025-09-12T02:33:11.547893458Z TRACE quiche_server] Collecting garbage [2025-09-12T02:33:11.548023842Z TRACE quiche_server] got 54 bytes from [::ffff:193.167.0.100]:40446 to [::]:443 [2025-09-12T02:33:11.548027438Z TRACE quiche_server] got packet Short dcid=edb86c75c7613dd7530dac786ae13d2674d0b4c9 key_phase=false [2025-09-12T02:33:11.548031596Z TRACE quiche] edb86c75c7613dd7530dac786ae13d2674d0b4c9 rx pkt Short dcid=edb86c75c7613dd7530dac786ae13d2674d0b4c9 key_phase=false len=33 pn=4 [2025-09-12T02:33:11.548035874Z TRACE quiche] edb86c75c7613dd7530dac786ae13d2674d0b4c9 rx frm ACK delay=20 blocks=[2..6] ecn_counts=None [2025-09-12T02:33:11.548044731Z TRACE quiche] edb86c75c7613dd7530dac786ae13d2674d0b4c9 rx frm APPLICATION_CLOSE err=0 reason=[6b, 74, 68, 78, 62, 79, 65, 21] [2025-09-12T02:33:11.548051373Z TRACE quiche_server] edb86c75c7613dd7530dac786ae13d2674d0b4c9 processed 54 bytes [2025-09-12T02:33:11.548054799Z TRACE quiche_server] recv() would block [2025-09-12T02:33:11.548057054Z TRACE quiche_server] edb86c75c7613dd7530dac786ae13d2674d0b4c9 done writing [2025-09-12T02:33:11.548059188Z TRACE quiche_server] Collecting garbage [2025-09-12T02:33:11.576152851Z TRACE quiche_server] got 55 bytes from [::ffff:193.167.0.100]:40446 to [::]:443 [2025-09-12T02:33:11.576166647Z TRACE quiche_server] got packet Short dcid=edb86c75c7613dd7530dac786ae13d2674d0b4c9 key_phase=false [2025-09-12T02:33:11.576173800Z TRACE quiche_server] edb86c75c7613dd7530dac786ae13d2674d0b4c9 processed 55 bytes [2025-09-12T02:33:11.576179531Z TRACE quiche_server] recv() would block [2025-09-12T02:33:11.576183067Z TRACE quiche_server] edb86c75c7613dd7530dac786ae13d2674d0b4c9 done writing [2025-09-12T02:33:11.576186243Z TRACE quiche_server] Collecting garbage [2025-09-12T02:33:11.721387041Z TRACE quiche_server] timed out [2025-09-12T02:33:11.721403502Z TRACE quiche] edb86c75c7613dd7530dac786ae13d2674d0b4c9 draining timeout expired [2025-09-12T02:33:11.721440101Z TRACE quiche_server] edb86c75c7613dd7530dac786ae13d2674d0b4c9 done writing [2025-09-12T02:33:11.721443948Z TRACE quiche_server] Collecting garbage [2025-09-12T02:33:11.721449248Z INFO quiche_server] edb86c75c7613dd7530dac786ae13d2674d0b4c9 connection collected recv=10 sent=8 lost=0 retrans=0 sent_bytes=6842 recv_bytes=3361 lost_bytes=0 [local_addr=[::]:443 peer_addr=[::ffff:193.167.0.100]:40446 validation_state=Validated active=true recv=10 sent=8 lost=0 retrans=0 rtt=33.416032ms min_rtt=Some(32.982566ms) rttvar=6.003417ms cwnd=13500 sent_bytes=6842 recv_bytes=3361 lost_bytes=0 stream_retrans_bytes=0 pmtu=1350 delivery_rate=167029] [2025-09-12T02:33:11.932964963Z TRACE quiche_server] got 1252 bytes from [::ffff:193.167.0.100]:40446 to [::]:443 [2025-09-12T02:33:11.932986633Z TRACE quiche_server] got packet Initial version=1 dcid=17caadcc7c334975 scid= token= [2025-09-12T02:33:11.932993576Z DEBUG quiche_server] New connection: dcid=17caadcc7c334975 scid=33426bae239cb8ad2de16417161e5c98cdf17bf0 [2025-09-12T02:33:11.933119521Z TRACE quiche] 33426bae239cb8ad2de16417161e5c98cdf17bf0 rx pkt Initial version=1 dcid=17caadcc7c334975 scid= token= len=1234 pn=32 [2025-09-12T02:33:11.933131834Z TRACE quiche] 33426bae239cb8ad2de16417161e5c98cdf17bf0 rx frm CRYPTO off=0 len=1213 [2025-09-12T02:33:11.933157593Z TRACE quiche_server] 33426bae239cb8ad2de16417161e5c98cdf17bf0 processed 1252 bytes [2025-09-12T02:33:11.933166950Z TRACE quiche_server] recv() would block [2025-09-12T02:33:11.933177951Z TRACE quiche] 33426bae239cb8ad2de16417161e5c98cdf17bf0 tx pkt Initial version=1 dcid= scid=33426bae239cb8ad2de16417161e5c98cdf17bf0 len=5 pn=0 [2025-09-12T02:33:11.933181207Z TRACE quiche] 33426bae239cb8ad2de16417161e5c98cdf17bf0 tx frm ACK delay=9 blocks=[32..32] ecn_counts=None [2025-09-12T02:33:11.933191897Z TRACE quiche::recovery::congestion::recovery] 33426bae239cb8ad2de16417161e5c98cdf17bf0 timer=none latest_rtt=0ns srtt=333ms min_rtt=333ms rttvar=166.5ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=0 app_limited=false congestion_recovery_start_time=None Rate { delivered: 0, delivered_time: Instant { tv_sec: 1138, tv_nsec: 678659315 }, first_sent_time: Instant { tv_sec: 1138, tv_nsec: 678659315 }, end_of_app_limited: 0, last_sent_packet: 0, largest_acked: 0, rate_sample: RateSample { bandwidth: 0.00 Kbps, 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: 1138, tv_nsec: 678659315 }, next_time: Instant { tv_sec: 1138, tv_nsec: 678659315 }, max_datagram_size: 1350, last_packet_size: None, iv: 0ns, max_pacing_rate: None } hystart=window_end=None 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-09-12T02:33:11.933243984Z TRACE quiche_server] 33426bae239cb8ad2de16417161e5c98cdf17bf0 written 1200 bytes with Some(SendInfo { from: [::]:443, to: [::ffff:193.167.0.100]:40446, at: Instant { tv_sec: 1138, tv_nsec: 678659315 } }) [2025-09-12T02:33:11.933250286Z TRACE quiche_server] Collecting garbage [2025-09-12T02:33:11.933254774Z TRACE quiche_server] recv() would block [2025-09-12T02:33:11.933258341Z TRACE quiche_server] 33426bae239cb8ad2de16417161e5c98cdf17bf0 done writing [2025-09-12T02:33:11.933260555Z TRACE quiche_server] Collecting garbage [2025-09-12T02:33:11.933940906Z TRACE quiche_server] got 1252 bytes from [::ffff:193.167.0.100]:40446 to [::]:443 [2025-09-12T02:33:11.933949121Z TRACE quiche_server] got packet Initial version=1 dcid=17caadcc7c334975 scid= token= [2025-09-12T02:33:11.933954511Z TRACE quiche] 33426bae239cb8ad2de16417161e5c98cdf17bf0 rx pkt Initial version=1 dcid=17caadcc7c334975 scid= token= len=572 pn=33 [2025-09-12T02:33:11.933959571Z TRACE quiche] 33426bae239cb8ad2de16417161e5c98cdf17bf0 rx frm CRYPTO off=1213 len=550 [2025-09-12T02:33:11.933982904Z TRACE quiche::tls] checking peer ALPN Ok("hq-interop") against Ok("h3") [2025-09-12T02:33:11.933986411Z TRACE quiche::tls] checking peer ALPN Ok("hq-interop") against Ok("hq-interop") [2025-09-12T02:33:11.934089644Z TRACE quiche::tls] 33426bae239cb8ad2de16417161e5c98cdf17bf0 write message lvl=Initial len=96 [2025-09-12T02:33:11.934104602Z TRACE quiche::tls] 33426bae239cb8ad2de16417161e5c98cdf17bf0 set write secret lvl=Handshake [2025-09-12T02:33:11.934128216Z TRACE quiche::tls] 33426bae239cb8ad2de16417161e5c98cdf17bf0 write message lvl=Handshake len=148 [2025-09-12T02:33:11.934130821Z TRACE quiche::tls] 33426bae239cb8ad2de16417161e5c98cdf17bf0 set write secret lvl=OneRTT [2025-09-12T02:33:11.934136912Z TRACE quiche::tls] 33426bae239cb8ad2de16417161e5c98cdf17bf0 set read secret lvl=Handshake [2025-09-12T02:33:11.934152541Z TRACE quiche] 33426bae239cb8ad2de16417161e5c98cdf17bf0 dropped invalid packet [2025-09-12T02:33:11.934155296Z TRACE quiche_server] 33426bae239cb8ad2de16417161e5c98cdf17bf0 processed 1252 bytes [2025-09-12T02:33:11.934168080Z TRACE quiche_server] recv() would block [2025-09-12T02:33:11.934176416Z TRACE quiche] 33426bae239cb8ad2de16417161e5c98cdf17bf0 tx pkt Initial version=1 dcid= scid=33426bae239cb8ad2de16417161e5c98cdf17bf0 len=105 pn=1 [2025-09-12T02:33:11.934179201Z TRACE quiche] 33426bae239cb8ad2de16417161e5c98cdf17bf0 tx frm ACK delay=27 blocks=[32..33] ecn_counts=None [2025-09-12T02:33:11.934182317Z TRACE quiche] 33426bae239cb8ad2de16417161e5c98cdf17bf0 tx frm CRYPTO off=0 len=96 [2025-09-12T02:33:11.934189420Z TRACE quiche::recovery::congestion::recovery] 33426bae239cb8ad2de16417161e5c98cdf17bf0 timer=998.980584ms latest_rtt=0ns srtt=333ms min_rtt=333ms rttvar=166.5ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=152 app_limited=true congestion_recovery_start_time=None Rate { delivered: 0, delivered_time: Instant { tv_sec: 1138, tv_nsec: 679659594 }, first_sent_time: Instant { tv_sec: 1138, tv_nsec: 679659594 }, end_of_app_limited: 1, last_sent_packet: 1, largest_acked: 0, rate_sample: RateSample { bandwidth: 0.00 Kbps, 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: 1138, tv_nsec: 679659594 }, next_time: Instant { tv_sec: 1138, tv_nsec: 679659594 }, max_datagram_size: 1350, last_packet_size: None, iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(1) 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-09-12T02:33:11.934210469Z TRACE quiche] 33426bae239cb8ad2de16417161e5c98cdf17bf0 tx pkt Handshake version=1 dcid= scid=33426bae239cb8ad2de16417161e5c98cdf17bf0 len=152 pn=2 [2025-09-12T02:33:11.934213255Z TRACE quiche] 33426bae239cb8ad2de16417161e5c98cdf17bf0 tx frm CRYPTO off=0 len=148 [2025-09-12T02:33:11.934218625Z TRACE quiche::recovery::congestion::recovery] 33426bae239cb8ad2de16417161e5c98cdf17bf0 timer=998.951419ms latest_rtt=0ns srtt=333ms min_rtt=333ms rttvar=166.5ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=350 app_limited=true congestion_recovery_start_time=None Rate { delivered: 0, delivered_time: Instant { tv_sec: 1138, tv_nsec: 679659594 }, first_sent_time: Instant { tv_sec: 1138, tv_nsec: 679659594 }, end_of_app_limited: 1, last_sent_packet: 2, largest_acked: 0, rate_sample: RateSample { bandwidth: 0.00 Kbps, 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: 1138, tv_nsec: 679659594 }, next_time: Instant { tv_sec: 1138, tv_nsec: 679659594 }, max_datagram_size: 1350, last_packet_size: None, iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(1) 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-09-12T02:33:11.934251256Z TRACE quiche_server] 33426bae239cb8ad2de16417161e5c98cdf17bf0 written 1200 bytes with Some(SendInfo { from: [::]:443, to: [::ffff:193.167.0.100]:40446, at: Instant { tv_sec: 1138, tv_nsec: 679659594 } }) [2025-09-12T02:33:11.934256055Z TRACE quiche_server] Collecting garbage [2025-09-12T02:33:11.934259802Z TRACE quiche_server] recv() would block [2025-09-12T02:33:11.934263208Z TRACE quiche_server] 33426bae239cb8ad2de16417161e5c98cdf17bf0 done writing [2025-09-12T02:33:11.934265452Z TRACE quiche_server] Collecting garbage [2025-09-12T02:33:11.966676714Z TRACE quiche_server] got 144 bytes from [::ffff:193.167.0.100]:40446 to [::]:443 [2025-09-12T02:33:11.966688526Z TRACE quiche_server] got packet Initial version=1 dcid=33426bae239cb8ad2de16417161e5c98cdf17bf0 scid= token= [2025-09-12T02:33:11.966695549Z TRACE quiche] 33426bae239cb8ad2de16417161e5c98cdf17bf0 rx pkt Initial version=1 dcid=33426bae239cb8ad2de16417161e5c98cdf17bf0 scid= token= len=23 pn=34 [2025-09-12T02:33:11.966702152Z TRACE quiche] 33426bae239cb8ad2de16417161e5c98cdf17bf0 rx frm ACK delay=94 blocks=[0..1] ecn_counts=None [2025-09-12T02:33:11.966706530Z TRACE quiche::recovery::congestion::recovery] 33426bae239cb8ad2de16417161e5c98cdf17bf0 packet newly acked 0 [2025-09-12T02:33:11.966709265Z TRACE quiche::recovery::congestion::recovery] 33426bae239cb8ad2de16417161e5c98cdf17bf0 packet newly acked 1 [2025-09-12T02:33:11.966722880Z TRACE quiche] 33426bae239cb8ad2de16417161e5c98cdf17bf0 rx pkt Handshake version=1 dcid=33426bae239cb8ad2de16417161e5c98cdf17bf0 scid= len=62 pn=0 [2025-09-12T02:33:11.966727349Z TRACE quiche] 33426bae239cb8ad2de16417161e5c98cdf17bf0 rx frm ACK delay=94 blocks=[2..2] ecn_counts=None [2025-09-12T02:33:11.966730174Z TRACE quiche::recovery::congestion::recovery] 33426bae239cb8ad2de16417161e5c98cdf17bf0 packet newly acked 2 [2025-09-12T02:33:11.966733610Z TRACE quiche] 33426bae239cb8ad2de16417161e5c98cdf17bf0 rx frm CRYPTO off=0 len=36 [2025-09-12T02:33:11.966744210Z TRACE quiche::tls] 33426bae239cb8ad2de16417161e5c98cdf17bf0 set read secret lvl=OneRTT [2025-09-12T02:33:11.966769357Z TRACE quiche::tls] 33426bae239cb8ad2de16417161e5c98cdf17bf0 write message lvl=OneRTT len=396 [2025-09-12T02:33:11.966777162Z TRACE quiche] 33426bae239cb8ad2de16417161e5c98cdf17bf0 dropped epoch 1 state [2025-09-12T02:33:11.966780378Z TRACE quiche] 33426bae239cb8ad2de16417161e5c98cdf17bf0 connection established: proto=Ok("hq-interop") cipher=Some(AES128_GCM) curve=Some("X25519") sigalg=None resumed=true TransportParams { original_destination_connection_id: None, max_idle_timeout: 30000, stateless_reset_token: None, max_udp_payload_size: 65527, initial_max_data: 4611686018427387903, initial_max_stream_data_bidi_local: 1048576, initial_max_stream_data_bidi_remote: 1048576, initial_max_stream_data_uni: 1048576, initial_max_streams_bidi: 16, initial_max_streams_uni: 16, ack_delay_exponent: 3, max_ack_delay: 20, disable_active_migration: false, active_conn_id_limit: 8, initial_source_connection_id: Some(), retry_source_connection_id: None, max_datagram_frame_size: Some(1200), unknown_params: None } [2025-09-12T02:33:11.966803892Z TRACE quiche] 33426bae239cb8ad2de16417161e5c98cdf17bf0 dropped epoch 0 state [2025-09-12T02:33:11.966806887Z TRACE quiche_server] 33426bae239cb8ad2de16417161e5c98cdf17bf0 processed 144 bytes [2025-09-12T02:33:11.966813049Z TRACE quiche_server] got 58 bytes from [::ffff:193.167.0.100]:40446 to [::]:443 [2025-09-12T02:33:11.966816225Z TRACE quiche_server] got packet Short dcid=33426bae239cb8ad2de16417161e5c98cdf17bf0 key_phase=false [2025-09-12T02:33:11.966820643Z TRACE quiche] 33426bae239cb8ad2de16417161e5c98cdf17bf0 rx pkt Short dcid=33426bae239cb8ad2de16417161e5c98cdf17bf0 key_phase=false len=37 pn=0 [2025-09-12T02:33:11.966825031Z TRACE quiche] 33426bae239cb8ad2de16417161e5c98cdf17bf0 rx frm STREAM id=0 off=0 len=17 fin=true [2025-09-12T02:33:11.966831152Z TRACE quiche_server] 33426bae239cb8ad2de16417161e5c98cdf17bf0 processed 58 bytes [2025-09-12T02:33:11.966833898Z DEBUG quiche_apps::common] 33426bae239cb8ad2de16417161e5c98cdf17bf0 response stream 0 is writable with capacity Ok(13500) [2025-09-12T02:33:11.966839448Z TRACE quiche_apps::common] 33426bae239cb8ad2de16417161e5c98cdf17bf0 received 17 bytes [2025-09-12T02:33:11.966842023Z TRACE quiche_apps::common] 33426bae239cb8ad2de16417161e5c98cdf17bf0 stream 0 has 17 bytes (fin? true) [2025-09-12T02:33:11.966846080Z INFO quiche_apps::common] 33426bae239cb8ad2de16417161e5c98cdf17bf0 got GET request for "/www/evfbwsbtwu" on stream 0 [2025-09-12T02:33:11.966867721Z INFO quiche_apps::common] 33426bae239cb8ad2de16417161e5c98cdf17bf0 sending response of size 10240 on stream 0 [2025-09-12T02:33:11.966875405Z TRACE quiche_server] recv() would block [2025-09-12T02:33:11.966886566Z TRACE quiche] 33426bae239cb8ad2de16417161e5c98cdf17bf0 tx pkt Short dcid= key_phase=false len=1332 pn=3 [2025-09-12T02:33:11.966889712Z TRACE quiche] 33426bae239cb8ad2de16417161e5c98cdf17bf0 tx frm ACK delay=7 blocks=[0..0] ecn_counts=None [2025-09-12T02:33:11.966892938Z TRACE quiche] 33426bae239cb8ad2de16417161e5c98cdf17bf0 tx frm NEW_CONNECTION_ID seq_num=1 retire_prior_to=0 conn_id=[89, da, 44, 74, 36, 79, d6, 93, cd, 42, 2b, 93, 4b, b1, 8d, bc, e0, 51, 50, 1e] reset_token=[d6, a0, 41, 19, 7d, 47, 72, 7e, c9, a7, e3, 83, 14, 91, dc, 52] [2025-09-12T02:33:11.966899170Z TRACE quiche] 33426bae239cb8ad2de16417161e5c98cdf17bf0 tx frm NEW_CONNECTION_ID seq_num=2 retire_prior_to=0 conn_id=[37, 7f, 5e, 2b, dc, 9b, d1, 00, 0a, 99, a4, a9, bb, 94, 3e, ca, 4c, 48, 44, a0] reset_token=[8f, fb, 9f, 5b, f8, 70, ad, 8f, 4a, 18, ba, 36, 4d, 51, db, 08] [2025-09-12T02:33:11.966904880Z TRACE quiche] 33426bae239cb8ad2de16417161e5c98cdf17bf0 tx frm NEW_CONNECTION_ID seq_num=3 retire_prior_to=0 conn_id=[f0, 45, f9, fb, a9, a8, 8f, 58, 77, 9a, aa, c4, 53, b7, 59, 5a, 1f, b6, 18, 72] reset_token=[78, ff, ce, 67, b3, 31, a8, 47, 93, d6, 65, 7b, b2, e6, 55, 97] [2025-09-12T02:33:11.966910030Z TRACE quiche] 33426bae239cb8ad2de16417161e5c98cdf17bf0 tx frm NEW_CONNECTION_ID seq_num=4 retire_prior_to=0 conn_id=[9c, 07, d8, c1, 8d, 4d, fa, c0, 0e, ec, 79, ff, 46, af, de, f5, d3, a7, 38, 69] reset_token=[34, f9, 91, 9e, ef, cc, ca, e0, 30, 4f, 6e, 3d, 1c, 78, df, b7] [2025-09-12T02:33:11.966915169Z TRACE quiche] 33426bae239cb8ad2de16417161e5c98cdf17bf0 tx frm NEW_CONNECTION_ID seq_num=5 retire_prior_to=0 conn_id=[0d, 54, 21, f0, de, b3, ec, 6d, 43, b1, 86, ae, 83, b1, d4, 8b, a8, f0, a0, 5f] reset_token=[fc, 18, bc, 07, 18, 2e, 3a, 25, 28, 72, b0, ea, b9, 03, ce, 46] [2025-09-12T02:33:11.966920369Z TRACE quiche] 33426bae239cb8ad2de16417161e5c98cdf17bf0 tx frm NEW_CONNECTION_ID seq_num=6 retire_prior_to=0 conn_id=[26, 43, 38, 11, ba, b9, 09, 30, 5d, df, f1, 23, 21, 58, 85, 21, 5b, 63, 10, a3] reset_token=[87, 81, 58, 2f, 05, ea, 0d, 90, cd, 91, 8b, b1, d3, e6, 6a, 01] [2025-09-12T02:33:11.966929857Z TRACE quiche] 33426bae239cb8ad2de16417161e5c98cdf17bf0 tx frm NEW_CONNECTION_ID seq_num=7 retire_prior_to=0 conn_id=[d4, 3c, c7, 74, 89, 2a, 89, 0d, 6e, 5f, c9, 9a, 15, 51, dc, 59, 77, d8, 7a, 23] reset_token=[97, db, e7, 49, 42, 67, d8, 2e, 82, 1d, f2, c5, 7e, 5c, 2d, 62] [2025-09-12T02:33:11.966935027Z TRACE quiche] 33426bae239cb8ad2de16417161e5c98cdf17bf0 tx frm HANDSHAKE_DONE [2025-09-12T02:33:11.966937281Z TRACE quiche] 33426bae239cb8ad2de16417161e5c98cdf17bf0 tx frm CRYPTO off=0 len=396 [2025-09-12T02:33:11.966939645Z TRACE quiche] 33426bae239cb8ad2de16417161e5c98cdf17bf0 tx frm STREAM id=0 off=0 len=641 fin=false [2025-09-12T02:33:11.966952329Z TRACE quiche::recovery::congestion::recovery] 33426bae239cb8ad2de16417161e5c98cdf17bf0 timer=101.266188ms latest_rtt=32.552025ms srtt=32.527206ms min_rtt=32.523661ms rttvar=12.203463ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=1350 app_limited=true congestion_recovery_start_time=None Rate { delivered: 350, delivered_time: Instant { tv_sec: 1138, tv_nsec: 712367159 }, first_sent_time: Instant { tv_sec: 1138, tv_nsec: 712367159 }, end_of_app_limited: 2, last_sent_packet: 3, largest_acked: 2, rate_sample: RateSample { bandwidth: 86.02 Kbps, is_app_limited: true, interval: 32.552025ms, delivered: 350, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 1138, tv_nsec: 679659594 }), send_elapsed: 0ns, ack_elapsed: 32.552025ms, rtt: 32.552025ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 518796, last_update: Instant { tv_sec: 1138, tv_nsec: 712367159 }, next_time: Instant { tv_sec: 1138, tv_nsec: 712367159 }, max_datagram_size: 1350, last_packet_size: Some(0), iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(1) 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-09-12T02:33:11.966968880Z TRACE quiche] 33426bae239cb8ad2de16417161e5c98cdf17bf0 tx pkt Short dcid= key_phase=false len=1332 pn=4 [2025-09-12T02:33:11.966971565Z TRACE quiche] 33426bae239cb8ad2de16417161e5c98cdf17bf0 tx frm STREAM id=0 off=641 len=1326 fin=false [2025-09-12T02:33:11.966976514Z TRACE quiche::recovery::congestion::recovery] 33426bae239cb8ad2de16417161e5c98cdf17bf0 timer=101.330799ms latest_rtt=32.552025ms srtt=32.527206ms min_rtt=32.523661ms rttvar=12.203463ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=2700 app_limited=true congestion_recovery_start_time=None Rate { delivered: 350, delivered_time: Instant { tv_sec: 1138, tv_nsec: 712367159 }, first_sent_time: Instant { tv_sec: 1138, tv_nsec: 712367159 }, end_of_app_limited: 3, last_sent_packet: 4, largest_acked: 2, rate_sample: RateSample { bandwidth: 86.02 Kbps, is_app_limited: true, interval: 32.552025ms, delivered: 350, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 1138, tv_nsec: 679659594 }), send_elapsed: 0ns, ack_elapsed: 32.552025ms, rtt: 32.552025ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 518796, last_update: Instant { tv_sec: 1138, tv_nsec: 712367159 }, next_time: Instant { tv_sec: 1138, tv_nsec: 712367159 }, max_datagram_size: 1350, last_packet_size: Some(0), iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(1) 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-09-12T02:33:11.966987896Z TRACE quiche] 33426bae239cb8ad2de16417161e5c98cdf17bf0 tx pkt Short dcid= key_phase=false len=1332 pn=5 [2025-09-12T02:33:11.966990520Z TRACE quiche] 33426bae239cb8ad2de16417161e5c98cdf17bf0 tx frm STREAM id=0 off=1967 len=1326 fin=false [2025-09-12T02:33:11.966998185Z TRACE quiche::recovery::congestion::recovery] 33426bae239cb8ad2de16417161e5c98cdf17bf0 timer=101.329056ms latest_rtt=32.552025ms srtt=32.527206ms min_rtt=32.523661ms rttvar=12.203463ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=4050 app_limited=true congestion_recovery_start_time=None Rate { delivered: 350, delivered_time: Instant { tv_sec: 1138, tv_nsec: 712367159 }, first_sent_time: Instant { tv_sec: 1138, tv_nsec: 712367159 }, end_of_app_limited: 4, last_sent_packet: 5, largest_acked: 2, rate_sample: RateSample { bandwidth: 86.02 Kbps, is_app_limited: true, interval: 32.552025ms, delivered: 350, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 1138, tv_nsec: 679659594 }), send_elapsed: 0ns, ack_elapsed: 32.552025ms, rtt: 32.552025ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 518796, last_update: Instant { tv_sec: 1138, tv_nsec: 712367159 }, next_time: Instant { tv_sec: 1138, tv_nsec: 712367159 }, max_datagram_size: 1350, last_packet_size: Some(0), iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(1) 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-09-12T02:33:11.967008844Z TRACE quiche] 33426bae239cb8ad2de16417161e5c98cdf17bf0 tx pkt Short dcid= key_phase=false len=1332 pn=6 [2025-09-12T02:33:11.967011329Z TRACE quiche] 33426bae239cb8ad2de16417161e5c98cdf17bf0 tx frm STREAM id=0 off=3293 len=1326 fin=false [2025-09-12T02:33:11.967015587Z TRACE quiche::recovery::congestion::recovery] 33426bae239cb8ad2de16417161e5c98cdf17bf0 timer=101.332652ms latest_rtt=32.552025ms srtt=32.527206ms min_rtt=32.523661ms rttvar=12.203463ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=5400 app_limited=true congestion_recovery_start_time=None Rate { delivered: 350, delivered_time: Instant { tv_sec: 1138, tv_nsec: 712367159 }, first_sent_time: Instant { tv_sec: 1138, tv_nsec: 712367159 }, end_of_app_limited: 4, last_sent_packet: 6, largest_acked: 2, rate_sample: RateSample { bandwidth: 86.02 Kbps, is_app_limited: true, interval: 32.552025ms, delivered: 350, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 1138, tv_nsec: 679659594 }), send_elapsed: 0ns, ack_elapsed: 32.552025ms, rtt: 32.552025ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 518796, last_update: Instant { tv_sec: 1138, tv_nsec: 712367159 }, next_time: Instant { tv_sec: 1138, tv_nsec: 712367159 }, max_datagram_size: 1350, last_packet_size: Some(0), iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(1) 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-09-12T02:33:11.967025656Z TRACE quiche] 33426bae239cb8ad2de16417161e5c98cdf17bf0 tx pkt Short dcid= key_phase=false len=1332 pn=7 [2025-09-12T02:33:11.967028131Z TRACE quiche] 33426bae239cb8ad2de16417161e5c98cdf17bf0 tx frm STREAM id=0 off=4619 len=1326 fin=false [2025-09-12T02:33:11.967051755Z TRACE quiche::recovery::congestion::recovery] 33426bae239cb8ad2de16417161e5c98cdf17bf0 timer=101.313356ms latest_rtt=32.552025ms srtt=32.527206ms min_rtt=32.523661ms rttvar=12.203463ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=6750 app_limited=true congestion_recovery_start_time=None Rate { delivered: 350, delivered_time: Instant { tv_sec: 1138, tv_nsec: 712367159 }, first_sent_time: Instant { tv_sec: 1138, tv_nsec: 712367159 }, end_of_app_limited: 4, last_sent_packet: 7, largest_acked: 2, rate_sample: RateSample { bandwidth: 86.02 Kbps, is_app_limited: true, interval: 32.552025ms, delivered: 350, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 1138, tv_nsec: 679659594 }), send_elapsed: 0ns, ack_elapsed: 32.552025ms, rtt: 32.552025ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 518796, last_update: Instant { tv_sec: 1138, tv_nsec: 712367159 }, next_time: Instant { tv_sec: 1138, tv_nsec: 712367159 }, max_datagram_size: 1350, last_packet_size: Some(0), iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(1) 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-09-12T02:33:11.967065791Z TRACE quiche] 33426bae239cb8ad2de16417161e5c98cdf17bf0 tx pkt Short dcid= key_phase=false len=1332 pn=8 [2025-09-12T02:33:11.967068436Z TRACE quiche] 33426bae239cb8ad2de16417161e5c98cdf17bf0 tx frm STREAM id=0 off=5945 len=1326 fin=false [2025-09-12T02:33:11.967073024Z TRACE quiche::recovery::congestion::recovery] 33426bae239cb8ad2de16417161e5c98cdf17bf0 timer=101.331881ms latest_rtt=32.552025ms srtt=32.527206ms min_rtt=32.523661ms rttvar=12.203463ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=8100 app_limited=true congestion_recovery_start_time=None Rate { delivered: 350, delivered_time: Instant { tv_sec: 1138, tv_nsec: 712367159 }, first_sent_time: Instant { tv_sec: 1138, tv_nsec: 712367159 }, end_of_app_limited: 4, last_sent_packet: 8, largest_acked: 2, rate_sample: RateSample { bandwidth: 86.02 Kbps, is_app_limited: true, interval: 32.552025ms, delivered: 350, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 1138, tv_nsec: 679659594 }), send_elapsed: 0ns, ack_elapsed: 32.552025ms, rtt: 32.552025ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 518796, last_update: Instant { tv_sec: 1138, tv_nsec: 712367159 }, next_time: Instant { tv_sec: 1138, tv_nsec: 712367159 }, max_datagram_size: 1350, last_packet_size: Some(0), iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(1) 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-09-12T02:33:11.967083153Z TRACE quiche] 33426bae239cb8ad2de16417161e5c98cdf17bf0 tx pkt Short dcid= key_phase=false len=1332 pn=9 [2025-09-12T02:33:11.967085608Z TRACE quiche] 33426bae239cb8ad2de16417161e5c98cdf17bf0 tx frm STREAM id=0 off=7271 len=1326 fin=false [2025-09-12T02:33:11.967089766Z TRACE quiche::recovery::congestion::recovery] 33426bae239cb8ad2de16417161e5c98cdf17bf0 timer=101.332883ms latest_rtt=32.552025ms srtt=32.527206ms min_rtt=32.523661ms rttvar=12.203463ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=9450 app_limited=true congestion_recovery_start_time=None Rate { delivered: 350, delivered_time: Instant { tv_sec: 1138, tv_nsec: 712367159 }, first_sent_time: Instant { tv_sec: 1138, tv_nsec: 712367159 }, end_of_app_limited: 4, last_sent_packet: 9, largest_acked: 2, rate_sample: RateSample { bandwidth: 86.02 Kbps, is_app_limited: true, interval: 32.552025ms, delivered: 350, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 1138, tv_nsec: 679659594 }), send_elapsed: 0ns, ack_elapsed: 32.552025ms, rtt: 32.552025ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 518796, last_update: Instant { tv_sec: 1138, tv_nsec: 712367159 }, next_time: Instant { tv_sec: 1138, tv_nsec: 712367159 }, max_datagram_size: 1350, last_packet_size: Some(0), iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(1) 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-09-12T02:33:11.967099564Z TRACE quiche] 33426bae239cb8ad2de16417161e5c98cdf17bf0 tx pkt Short dcid= key_phase=false len=1332 pn=10 [2025-09-12T02:33:11.967102029Z TRACE quiche] 33426bae239cb8ad2de16417161e5c98cdf17bf0 tx frm STREAM id=0 off=8597 len=1326 fin=false [2025-09-12T02:33:11.967106237Z TRACE quiche::recovery::congestion::recovery] 33426bae239cb8ad2de16417161e5c98cdf17bf0 timer=101.333033ms latest_rtt=32.552025ms srtt=32.527206ms min_rtt=32.523661ms rttvar=12.203463ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=10800 app_limited=true congestion_recovery_start_time=None Rate { delivered: 350, delivered_time: Instant { tv_sec: 1138, tv_nsec: 712367159 }, first_sent_time: Instant { tv_sec: 1138, tv_nsec: 712367159 }, end_of_app_limited: 4, last_sent_packet: 10, largest_acked: 2, rate_sample: RateSample { bandwidth: 86.02 Kbps, is_app_limited: true, interval: 32.552025ms, delivered: 350, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 1138, tv_nsec: 679659594 }), send_elapsed: 0ns, ack_elapsed: 32.552025ms, rtt: 32.552025ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 518796, last_update: Instant { tv_sec: 1138, tv_nsec: 712367159 }, next_time: Instant { tv_sec: 1138, tv_nsec: 712367159 }, max_datagram_size: 1350, last_packet_size: Some(0), iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(1) 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-09-12T02:33:11.967118860Z TRACE quiche] 33426bae239cb8ad2de16417161e5c98cdf17bf0 tx pkt Short dcid= key_phase=false len=323 pn=11 [2025-09-12T02:33:11.967121405Z TRACE quiche] 33426bae239cb8ad2de16417161e5c98cdf17bf0 tx frm STREAM id=0 off=9923 len=317 fin=true [2025-09-12T02:33:11.967125803Z TRACE quiche::recovery::congestion::recovery] 33426bae239cb8ad2de16417161e5c98cdf17bf0 timer=101.332762ms latest_rtt=32.552025ms srtt=32.527206ms min_rtt=32.523661ms rttvar=12.203463ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=11141 app_limited=true congestion_recovery_start_time=None Rate { delivered: 350, delivered_time: Instant { tv_sec: 1138, tv_nsec: 712367159 }, first_sent_time: Instant { tv_sec: 1138, tv_nsec: 712367159 }, end_of_app_limited: 4, last_sent_packet: 11, largest_acked: 2, rate_sample: RateSample { bandwidth: 86.02 Kbps, is_app_limited: true, interval: 32.552025ms, delivered: 350, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 1138, tv_nsec: 679659594 }), send_elapsed: 0ns, ack_elapsed: 32.552025ms, rtt: 32.552025ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 518796, last_update: Instant { tv_sec: 1138, tv_nsec: 712367159 }, next_time: Instant { tv_sec: 1138, tv_nsec: 712367159 }, max_datagram_size: 1350, last_packet_size: Some(0), iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(1) 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-09-12T02:33:11.967252940Z TRACE quiche_server] 33426bae239cb8ad2de16417161e5c98cdf17bf0 written 11141 bytes with Some(SendInfo { from: [::]:443, to: [::ffff:193.167.0.100]:40446, at: Instant { tv_sec: 1138, tv_nsec: 712367159 } }) [2025-09-12T02:33:11.967262338Z TRACE quiche_server] Collecting garbage [2025-09-12T02:33:11.967268389Z TRACE quiche_server] recv() would block [2025-09-12T02:33:11.967273369Z TRACE quiche_server] 33426bae239cb8ad2de16417161e5c98cdf17bf0 done writing [2025-09-12T02:33:11.967277286Z TRACE quiche_server] Collecting garbage [2025-09-12T02:33:12.000016596Z TRACE quiche_server] got 1352 bytes from [::ffff:193.167.0.100]:40446 to [::]:443 [2025-09-12T02:33:12.000030531Z TRACE quiche_server] got packet Short dcid=33426bae239cb8ad2de16417161e5c98cdf17bf0 key_phase=false [2025-09-12T02:33:12.000038857Z TRACE quiche] 33426bae239cb8ad2de16417161e5c98cdf17bf0 rx pkt Short dcid=33426bae239cb8ad2de16417161e5c98cdf17bf0 key_phase=false len=1331 pn=1 [2025-09-12T02:33:12.000047834Z TRACE quiche] 33426bae239cb8ad2de16417161e5c98cdf17bf0 rx frm ACK delay=32 blocks=[3..3] ecn_counts=None [2025-09-12T02:33:12.000053314Z TRACE quiche::recovery::congestion::recovery] 33426bae239cb8ad2de16417161e5c98cdf17bf0 packet newly acked 3 [2025-09-12T02:33:12.000066959Z TRACE quiche] 33426bae239cb8ad2de16417161e5c98cdf17bf0 rx frm PING mtu_probe=None [2025-09-12T02:33:12.000075105Z TRACE quiche] 33426bae239cb8ad2de16417161e5c98cdf17bf0 rx frm PADDING len=1308 [2025-09-12T02:33:12.000090544Z TRACE quiche_server] 33426bae239cb8ad2de16417161e5c98cdf17bf0 processed 1352 bytes [2025-09-12T02:33:12.000096204Z TRACE quiche_server] recv() would block [2025-09-12T02:33:12.000104440Z TRACE quiche] 33426bae239cb8ad2de16417161e5c98cdf17bf0 tx pkt Short dcid= key_phase=false len=5 pn=12 [2025-09-12T02:33:12.000108036Z TRACE quiche] 33426bae239cb8ad2de16417161e5c98cdf17bf0 tx frm ACK delay=8 blocks=[1..1] ecn_counts=None [2025-09-12T02:33:12.000116763Z TRACE quiche::recovery::congestion::recovery] 33426bae239cb8ad2de16417161e5c98cdf17bf0 timer=56.561281ms latest_rtt=33.159415ms srtt=32.574231ms min_rtt=32.523661ms rttvar=9.246649ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=9791 app_limited=true congestion_recovery_start_time=None Rate { delivered: 1700, delivered_time: Instant { tv_sec: 1138, tv_nsec: 745526574 }, first_sent_time: Instant { tv_sec: 1138, tv_nsec: 712367159 }, end_of_app_limited: 4, last_sent_packet: 12, largest_acked: 3, rate_sample: RateSample { bandwidth: 325.70 Kbps, is_app_limited: true, interval: 33.159415ms, delivered: 1350, prior_delivered: 350, prior_time: Some(Instant { tv_sec: 1138, tv_nsec: 712367159 }), send_elapsed: 0ns, ack_elapsed: 33.159415ms, rtt: 33.159415ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 518047, last_update: Instant { tv_sec: 1138, tv_nsec: 745588579 }, next_time: Instant { tv_sec: 1138, tv_nsec: 745588579 }, max_datagram_size: 1350, last_packet_size: Some(0), iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(1) 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-09-12T02:33:12.000159803Z TRACE quiche_server] 33426bae239cb8ad2de16417161e5c98cdf17bf0 written 23 bytes with Some(SendInfo { from: [::]:443, to: [::ffff:193.167.0.100]:40446, at: Instant { tv_sec: 1138, tv_nsec: 745588579 } }) [2025-09-12T02:33:12.000168640Z TRACE quiche_server] Collecting garbage [2025-09-12T02:33:12.000174270Z TRACE quiche_server] recv() would block [2025-09-12T02:33:12.000179159Z TRACE quiche_server] 33426bae239cb8ad2de16417161e5c98cdf17bf0 done writing [2025-09-12T02:33:12.000182526Z TRACE quiche_server] Collecting garbage [2025-09-12T02:33:12.000839753Z TRACE quiche_server] got 43 bytes from [::ffff:193.167.0.100]:40446 to [::]:443 [2025-09-12T02:33:12.000846416Z TRACE quiche_server] got packet Short dcid=33426bae239cb8ad2de16417161e5c98cdf17bf0 key_phase=false [2025-09-12T02:33:12.000851585Z TRACE quiche] 33426bae239cb8ad2de16417161e5c98cdf17bf0 rx pkt Short dcid=33426bae239cb8ad2de16417161e5c98cdf17bf0 key_phase=false len=22 pn=2 [2025-09-12T02:33:12.000856605Z TRACE quiche] 33426bae239cb8ad2de16417161e5c98cdf17bf0 rx frm ACK delay=4 blocks=[3..5] ecn_counts=None [2025-09-12T02:33:12.000859951Z TRACE quiche::recovery::congestion::recovery] 33426bae239cb8ad2de16417161e5c98cdf17bf0 packet newly acked 4 [2025-09-12T02:33:12.000862436Z TRACE quiche::recovery::congestion::recovery] 33426bae239cb8ad2de16417161e5c98cdf17bf0 packet newly acked 5 [2025-09-12T02:33:12.000872094Z TRACE quiche_server] 33426bae239cb8ad2de16417161e5c98cdf17bf0 processed 43 bytes [2025-09-12T02:33:12.000876031Z TRACE quiche_server] recv() would block [2025-09-12T02:33:12.000878907Z TRACE quiche_server] 33426bae239cb8ad2de16417161e5c98cdf17bf0 done writing [2025-09-12T02:33:12.000881100Z TRACE quiche_server] Collecting garbage [2025-09-12T02:33:12.003062927Z TRACE quiche_server] got 43 bytes from [::ffff:193.167.0.100]:40446 to [::]:443 [2025-09-12T02:33:12.003068487Z TRACE quiche_server] got packet Short dcid=33426bae239cb8ad2de16417161e5c98cdf17bf0 key_phase=false [2025-09-12T02:33:12.003072715Z TRACE quiche] 33426bae239cb8ad2de16417161e5c98cdf17bf0 rx pkt Short dcid=33426bae239cb8ad2de16417161e5c98cdf17bf0 key_phase=false len=22 pn=3 [2025-09-12T02:33:12.003081551Z TRACE quiche] 33426bae239cb8ad2de16417161e5c98cdf17bf0 rx frm ACK delay=4 blocks=[3..7] ecn_counts=None [2025-09-12T02:33:12.003084657Z TRACE quiche::recovery::congestion::recovery] 33426bae239cb8ad2de16417161e5c98cdf17bf0 packet newly acked 6 [2025-09-12T02:33:12.003086881Z TRACE quiche::recovery::congestion::recovery] 33426bae239cb8ad2de16417161e5c98cdf17bf0 packet newly acked 7 [2025-09-12T02:33:12.003094756Z TRACE quiche_server] 33426bae239cb8ad2de16417161e5c98cdf17bf0 processed 43 bytes [2025-09-12T02:33:12.003098353Z TRACE quiche_server] recv() would block [2025-09-12T02:33:12.003101008Z TRACE quiche_server] 33426bae239cb8ad2de16417161e5c98cdf17bf0 done writing [2025-09-12T02:33:12.003103212Z TRACE quiche_server] Collecting garbage [2025-09-12T02:33:12.005295607Z TRACE quiche_server] got 43 bytes from [::ffff:193.167.0.100]:40446 to [::]:443 [2025-09-12T02:33:12.005302861Z TRACE quiche_server] got packet Short dcid=33426bae239cb8ad2de16417161e5c98cdf17bf0 key_phase=false [2025-09-12T02:33:12.005308371Z TRACE quiche] 33426bae239cb8ad2de16417161e5c98cdf17bf0 rx pkt Short dcid=33426bae239cb8ad2de16417161e5c98cdf17bf0 key_phase=false len=22 pn=4 [2025-09-12T02:33:12.005313641Z TRACE quiche] 33426bae239cb8ad2de16417161e5c98cdf17bf0 rx frm ACK delay=2 blocks=[3..9] ecn_counts=None [2025-09-12T02:33:12.005317478Z TRACE quiche::recovery::congestion::recovery] 33426bae239cb8ad2de16417161e5c98cdf17bf0 packet newly acked 8 [2025-09-12T02:33:12.005320564Z TRACE quiche::recovery::congestion::recovery] 33426bae239cb8ad2de16417161e5c98cdf17bf0 packet newly acked 9 [2025-09-12T02:33:12.005330683Z TRACE quiche_server] 33426bae239cb8ad2de16417161e5c98cdf17bf0 processed 43 bytes [2025-09-12T02:33:12.005335312Z TRACE quiche_server] recv() would block [2025-09-12T02:33:12.005338788Z TRACE quiche_server] 33426bae239cb8ad2de16417161e5c98cdf17bf0 done writing [2025-09-12T02:33:12.005341704Z TRACE quiche_server] Collecting garbage [2025-09-12T02:33:12.006656830Z TRACE quiche_server] got 43 bytes from [::ffff:193.167.0.100]:40446 to [::]:443 [2025-09-12T02:33:12.006662100Z TRACE quiche_server] got packet Short dcid=33426bae239cb8ad2de16417161e5c98cdf17bf0 key_phase=false [2025-09-12T02:33:12.006666098Z TRACE quiche] 33426bae239cb8ad2de16417161e5c98cdf17bf0 rx pkt Short dcid=33426bae239cb8ad2de16417161e5c98cdf17bf0 key_phase=false len=22 pn=5 [2025-09-12T02:33:12.006670215Z TRACE quiche] 33426bae239cb8ad2de16417161e5c98cdf17bf0 rx frm ACK delay=2 blocks=[3..11] ecn_counts=None [2025-09-12T02:33:12.006673061Z TRACE quiche::recovery::congestion::recovery] 33426bae239cb8ad2de16417161e5c98cdf17bf0 packet newly acked 10 [2025-09-12T02:33:12.006675305Z TRACE quiche::recovery::congestion::recovery] 33426bae239cb8ad2de16417161e5c98cdf17bf0 packet newly acked 11 [2025-09-12T02:33:12.006684061Z TRACE quiche_server] 33426bae239cb8ad2de16417161e5c98cdf17bf0 processed 43 bytes [2025-09-12T02:33:12.006687528Z TRACE quiche_server] recv() would block [2025-09-12T02:33:12.006690283Z TRACE quiche_server] 33426bae239cb8ad2de16417161e5c98cdf17bf0 done writing [2025-09-12T02:33:12.006692537Z TRACE quiche_server] Collecting garbage [2025-09-12T02:33:12.006874657Z TRACE quiche_server] got 54 bytes from [::ffff:193.167.0.100]:40446 to [::]:443 [2025-09-12T02:33:12.006878264Z TRACE quiche_server] got packet Short dcid=33426bae239cb8ad2de16417161e5c98cdf17bf0 key_phase=false [2025-09-12T02:33:12.006882251Z TRACE quiche] 33426bae239cb8ad2de16417161e5c98cdf17bf0 rx pkt Short dcid=33426bae239cb8ad2de16417161e5c98cdf17bf0 key_phase=false len=33 pn=6 [2025-09-12T02:33:12.006886650Z TRACE quiche] 33426bae239cb8ad2de16417161e5c98cdf17bf0 rx frm ACK delay=27 blocks=[3..11] ecn_counts=None [2025-09-12T02:33:12.006890156Z TRACE quiche] 33426bae239cb8ad2de16417161e5c98cdf17bf0 rx frm APPLICATION_CLOSE err=0 reason=[6b, 74, 68, 78, 62, 79, 65, 21] [2025-09-12T02:33:12.006896057Z TRACE quiche_server] 33426bae239cb8ad2de16417161e5c98cdf17bf0 processed 54 bytes [2025-09-12T02:33:12.006904363Z TRACE quiche_server] recv() would block [2025-09-12T02:33:12.006906737Z TRACE quiche_server] 33426bae239cb8ad2de16417161e5c98cdf17bf0 done writing [2025-09-12T02:33:12.006908921Z TRACE quiche_server] Collecting garbage [2025-09-12T02:33:12.030605961Z TRACE quiche_server] got 55 bytes from [::ffff:193.167.0.100]:40446 to [::]:443 [2025-09-12T02:33:12.030616621Z TRACE quiche_server] got packet Short dcid=33426bae239cb8ad2de16417161e5c98cdf17bf0 key_phase=false [2025-09-12T02:33:12.030621620Z TRACE quiche_server] 33426bae239cb8ad2de16417161e5c98cdf17bf0 processed 55 bytes [2025-09-12T02:33:12.030625708Z TRACE quiche_server] recv() would block [2025-09-12T02:33:12.030628263Z TRACE quiche_server] 33426bae239cb8ad2de16417161e5c98cdf17bf0 done writing [2025-09-12T02:33:12.030630557Z TRACE quiche_server] Collecting garbage [2025-09-12T02:33:12.183835300Z TRACE quiche_server] timed out [2025-09-12T02:33:12.183858152Z TRACE quiche] 33426bae239cb8ad2de16417161e5c98cdf17bf0 draining timeout expired [2025-09-12T02:33:12.183898428Z TRACE quiche_server] 33426bae239cb8ad2de16417161e5c98cdf17bf0 done writing [2025-09-12T02:33:12.183901594Z TRACE quiche_server] Collecting garbage [2025-09-12T02:33:12.183906483Z INFO quiche_server] 33426bae239cb8ad2de16417161e5c98cdf17bf0 connection collected recv=11 sent=13 lost=0 retrans=0 sent_bytes=11566 recv_bytes=3622 lost_bytes=0 [local_addr=[::]:443 peer_addr=[::ffff:193.167.0.100]:40446 validation_state=Validated active=true recv=11 sent=13 lost=0 retrans=0 rtt=34.570475ms min_rtt=Some(32.523661ms) rttvar=6.019289ms cwnd=13500 sent_bytes=11566 recv_bytes=3622 lost_bytes=0 stream_retrans_bytes=0 pmtu=1350 delivery_rate=280010]