[2025-04-30T10:32:45.370901971Z INFO quiche_server] listening on [::]:443 [2025-04-30T10:32:45.370926237Z TRACE mio::poll] registering event source with poller: token=Token(0), interests=READABLE [2025-04-30T10:32:45.370933139Z TRACE quiche_server] GSO detected: false [2025-04-30T10:32:46.218137549Z TRACE quiche_server] got 1207 bytes from [::ffff:193.167.100.2]:57008 to [::]:443 [2025-04-30T10:32:46.218171693Z TRACE quiche_server] got packet Initial version=57414954 dcid= scid= token= [2025-04-30T10:32:46.218179597Z WARN quiche_server] Doing version negotiation [2025-04-30T10:32:46.218284252Z TRACE quiche_server] got 1207 bytes from [::ffff:193.167.100.2]:57008 to [::]:443 [2025-04-30T10:32:46.218293930Z TRACE quiche_server] got packet Initial version=57414954 dcid= scid= token= [2025-04-30T10:32:46.218299892Z WARN quiche_server] Doing version negotiation [2025-04-30T10:32:46.218332733Z TRACE quiche_server] got 1207 bytes from [::ffff:193.167.100.2]:57008 to [::]:443 [2025-04-30T10:32:46.218339556Z TRACE quiche_server] got packet Initial version=57414954 dcid= scid= token= [2025-04-30T10:32:46.218344455Z WARN quiche_server] Doing version negotiation [2025-04-30T10:32:46.218377617Z TRACE quiche_server] recv() would block [2025-04-30T10:32:46.403089407Z TRACE quiche_server] got 1280 bytes from [::ffff:193.167.0.100]:38465 to [::]:443 [2025-04-30T10:32:46.403113652Z TRACE quiche_server] got packet Initial version=1 dcid=4c5f19114236e68e3777 scid= token= [2025-04-30T10:32:46.403121377Z DEBUG quiche_server] New connection: dcid=4c5f19114236e68e3777 scid=dafab94ef8f0913ec3999204595b758552438294 [2025-04-30T10:32:46.403324786Z TRACE quiche] dafab94ef8f0913ec3999204595b758552438294 rx pkt Initial version=1 dcid=4c5f19114236e68e3777 scid= token= len=1260 pn=0 [2025-04-30T10:32:46.403341587Z TRACE quiche] dafab94ef8f0913ec3999204595b758552438294 rx frm PADDING len=962 [2025-04-30T10:32:46.403345885Z TRACE quiche] dafab94ef8f0913ec3999204595b758552438294 rx frm CRYPTO off=0 len=276 [2025-04-30T10:32:46.403374549Z TRACE quiche::tls] checking peer ALPN Ok("hq-interop") against Ok("h3") [2025-04-30T10:32:46.403379428Z TRACE quiche::tls] checking peer ALPN Ok("hq-interop") against Ok("hq-interop") [2025-04-30T10:32:46.403480977Z TRACE quiche::tls] dafab94ef8f0913ec3999204595b758552438294 write message lvl=Initial len=90 [2025-04-30T10:32:46.403511434Z TRACE quiche::tls] dafab94ef8f0913ec3999204595b758552438294 set write secret lvl=Handshake [2025-04-30T10:32:46.403587746Z TRACE quiche::tls] dafab94ef8f0913ec3999204595b758552438294 write message lvl=Handshake len=701 [2025-04-30T10:32:46.403591523Z TRACE quiche::tls] dafab94ef8f0913ec3999204595b758552438294 set write secret lvl=OneRTT [2025-04-30T10:32:46.403599298Z TRACE quiche::tls] dafab94ef8f0913ec3999204595b758552438294 set read secret lvl=Handshake [2025-04-30T10:32:46.403630385Z TRACE quiche_server] dafab94ef8f0913ec3999204595b758552438294 processed 1280 bytes [2025-04-30T10:32:46.403644352Z TRACE quiche_server] recv() would block [2025-04-30T10:32:46.403656434Z TRACE quiche] dafab94ef8f0913ec3999204595b758552438294 tx pkt Initial version=1 dcid= scid=dafab94ef8f0913ec3999204595b758552438294 len=99 pn=0 [2025-04-30T10:32:46.403660792Z TRACE quiche] dafab94ef8f0913ec3999204595b758552438294 tx frm ACK delay=43 blocks=[0..0] ecn_counts=None [2025-04-30T10:32:46.403665731Z TRACE quiche] dafab94ef8f0913ec3999204595b758552438294 tx frm CRYPTO off=0 len=90 [2025-04-30T10:32:46.403676622Z TRACE quiche::recovery::congestion::recovery] dafab94ef8f0913ec3999204595b758552438294 timer=998.969773ms 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: 343, tv_nsec: 882701902 }, first_sent_time: Instant { tv_sec: 343, tv_nsec: 882701902 }, 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: 343, tv_nsec: 882701902 }, next_time: Instant { tv_sec: 343, tv_nsec: 882701902 }, max_datagram_size: 1350, last_packet_size: None, iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } [2025-04-30T10:32:46.403707149Z TRACE quiche] dafab94ef8f0913ec3999204595b758552438294 tx pkt Handshake version=1 dcid= scid=dafab94ef8f0913ec3999204595b758552438294 len=705 pn=1 [2025-04-30T10:32:46.403710815Z TRACE quiche] dafab94ef8f0913ec3999204595b758552438294 tx frm CRYPTO off=0 len=701 [2025-04-30T10:32:46.403717638Z TRACE quiche::recovery::congestion::recovery] dafab94ef8f0913ec3999204595b758552438294 timer=998.929088ms latest_rtt=0ns srtt=333ms min_rtt=333ms rttvar=166.5ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=897 app_limited=true congestion_recovery_start_time=None Rate { delivered: 0, delivered_time: Instant { tv_sec: 343, tv_nsec: 882701902 }, first_sent_time: Instant { tv_sec: 343, tv_nsec: 882701902 }, 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: 343, tv_nsec: 882701902 }, next_time: Instant { tv_sec: 343, tv_nsec: 882701902 }, max_datagram_size: 1350, last_packet_size: None, iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } [2025-04-30T10:32:46.403770457Z TRACE quiche_server] dafab94ef8f0913ec3999204595b758552438294 written 1200 bytes with Some(SendInfo { from: [::]:443, to: [::ffff:193.167.0.100]:38465, at: Instant { tv_sec: 343, tv_nsec: 882701902 } }) [2025-04-30T10:32:46.403777590Z TRACE quiche_server] Collecting garbage [2025-04-30T10:32:46.403785725Z TRACE quiche_server] recv() would block [2025-04-30T10:32:46.403792848Z TRACE quiche_server] dafab94ef8f0913ec3999204595b758552438294 done writing [2025-04-30T10:32:46.403796776Z TRACE quiche_server] Collecting garbage [2025-04-30T10:32:46.437076532Z TRACE quiche_server] got 1280 bytes from [::ffff:193.167.0.100]:38465 to [::]:443 [2025-04-30T10:32:46.437100997Z TRACE quiche_server] got packet Initial version=1 dcid=dafab94ef8f0913ec3999204595b758552438294 scid= token= [2025-04-30T10:32:46.437113380Z TRACE quiche] dafab94ef8f0913ec3999204595b758552438294 rx pkt Initial version=1 dcid=dafab94ef8f0913ec3999204595b758552438294 scid= token= len=1164 pn=1 [2025-04-30T10:32:46.437125583Z TRACE quiche] dafab94ef8f0913ec3999204595b758552438294 rx frm ACK delay=0 blocks=[0..0] ecn_counts=None [2025-04-30T10:32:46.437132546Z TRACE quiche::recovery::congestion::recovery] dafab94ef8f0913ec3999204595b758552438294 packet newly acked 0 [2025-04-30T10:32:46.437142454Z TRACE quiche] dafab94ef8f0913ec3999204595b758552438294 rx frm PADDING len=1141 [2025-04-30T10:32:46.437164425Z TRACE quiche] dafab94ef8f0913ec3999204595b758552438294 rx pkt Handshake version=1 dcid=dafab94ef8f0913ec3999204595b758552438294 scid= len=57 pn=0 [2025-04-30T10:32:46.437170136Z TRACE quiche] dafab94ef8f0913ec3999204595b758552438294 rx frm CRYPTO off=0 len=36 [2025-04-30T10:32:46.437187539Z TRACE quiche::tls] dafab94ef8f0913ec3999204595b758552438294 set read secret lvl=OneRTT [2025-04-30T10:32:46.437224608Z TRACE quiche::tls] dafab94ef8f0913ec3999204595b758552438294 write message lvl=OneRTT len=396 [2025-04-30T10:32:46.437234796Z TRACE quiche] dafab94ef8f0913ec3999204595b758552438294 dropped epoch 1 state [2025-04-30T10:32:46.437247841Z TRACE quiche] dafab94ef8f0913ec3999204595b758552438294 connection established: proto=Ok("hq-interop") cipher=Some(AES128_GCM) curve=Some("X25519") sigalg=None resumed=false TransportParams { original_destination_connection_id: None, max_idle_timeout: 30000, stateless_reset_token: None, max_udp_payload_size: 1452, initial_max_data: 786432, initial_max_stream_data_bidi_local: 524288, initial_max_stream_data_bidi_remote: 524288, initial_max_stream_data_uni: 524288, initial_max_streams_bidi: 100, initial_max_streams_uni: 100, ack_delay_exponent: 3, max_ack_delay: 26, disable_active_migration: false, active_conn_id_limit: 4, initial_source_connection_id: Some(), retry_source_connection_id: None, max_datagram_frame_size: None, unknown_params: None } [2025-04-30T10:32:46.437267477Z TRACE quiche] dafab94ef8f0913ec3999204595b758552438294 dropped epoch 0 state [2025-04-30T10:32:46.437270974Z TRACE quiche_server] dafab94ef8f0913ec3999204595b758552438294 processed 1280 bytes [2025-04-30T10:32:46.437280041Z TRACE quiche_server] got 110 bytes from [::ffff:193.167.0.100]:38465 to [::]:443 [2025-04-30T10:32:46.437284148Z TRACE quiche_server] got packet Handshake version=1 dcid=dafab94ef8f0913ec3999204595b758552438294 scid= [2025-04-30T10:32:46.437289288Z TRACE quiche] dafab94ef8f0913ec3999204595b758552438294 dropped invalid packet [2025-04-30T10:32:46.437292314Z TRACE quiche_server] dafab94ef8f0913ec3999204595b758552438294 processed 110 bytes [2025-04-30T10:32:46.437296692Z TRACE quiche_server] recv() would block [2025-04-30T10:32:46.437303004Z TRACE quiche] dafab94ef8f0913ec3999204595b758552438294 pmtud probe status false hs_con=true hs_sent=false cwnd_avail=13500 out_len=1350 left=1332 [2025-04-30T10:32:46.437312181Z TRACE quiche] dafab94ef8f0913ec3999204595b758552438294 tx pkt Short dcid= key_phase=false len=521 pn=2 [2025-04-30T10:32:46.437315667Z TRACE quiche] dafab94ef8f0913ec3999204595b758552438294 tx frm NEW_CONNECTION_ID seq_num=1 retire_prior_to=0 conn_id=[e1, b5, ca, 8a, 71, ca, b5, 6e, d4, 41, e7, cb, 97, 7e, ad, 13, ff, c4, a6, b3] reset_token=[98, fb, ef, 1b, b6, 8b, 55, 5b, 50, 78, 72, 7c, 21, a7, a1, f7] [2025-04-30T10:32:46.437323652Z TRACE quiche] dafab94ef8f0913ec3999204595b758552438294 tx frm NEW_CONNECTION_ID seq_num=2 retire_prior_to=0 conn_id=[7f, b9, 6c, 84, 67, ad, 31, 52, 61, 81, 34, 81, 23, f7, 74, bd, 21, ca, f1, 9a] reset_token=[f6, b6, 49, 73, 95, fa, 27, 3b, 3e, 62, 94, d8, fa, d4, d1, 87] [2025-04-30T10:32:46.437330375Z TRACE quiche] dafab94ef8f0913ec3999204595b758552438294 tx frm NEW_CONNECTION_ID seq_num=3 retire_prior_to=0 conn_id=[5d, 76, 55, a9, ec, c2, 4b, 2b, ce, 08, 85, 94, d1, 11, cd, e8, 06, 0e, 81, 8c] reset_token=[34, b8, c3, f5, 74, 51, 86, 91, 3b, f0, 2f, ff, 39, 16, ef, e9] [2025-04-30T10:32:46.437336877Z TRACE quiche] dafab94ef8f0913ec3999204595b758552438294 tx frm HANDSHAKE_DONE [2025-04-30T10:32:46.437339722Z TRACE quiche] dafab94ef8f0913ec3999204595b758552438294 tx frm CRYPTO off=0 len=396 [2025-04-30T10:32:46.437350562Z TRACE quiche::recovery::congestion::recovery] dafab94ef8f0913ec3999204595b758552438294 timer=126.337988ms latest_rtt=33.463238ms srtt=33.463238ms min_rtt=33.463238ms rttvar=16.731619ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=539 app_limited=true congestion_recovery_start_time=None Rate { delivered: 146, delivered_time: Instant { tv_sec: 343, tv_nsec: 916354293 }, first_sent_time: Instant { tv_sec: 343, tv_nsec: 916354293 }, end_of_app_limited: 1, last_sent_packet: 2, largest_acked: 0, rate_sample: RateSample { delivery_rate: 4362, is_app_limited: true, interval: 33.463238ms, delivered: 146, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 343, tv_nsec: 882701902 }), send_elapsed: 0ns, ack_elapsed: 33.463238ms, rtt: 33.463238ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 504284, last_update: Instant { tv_sec: 343, tv_nsec: 916354293 }, next_time: Instant { tv_sec: 343, tv_nsec: 916354293 }, max_datagram_size: 1350, last_packet_size: Some(0), iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } [2025-04-30T10:32:46.437411225Z TRACE quiche_server] dafab94ef8f0913ec3999204595b758552438294 written 539 bytes with Some(SendInfo { from: [::]:443, to: [::ffff:193.167.0.100]:38465, at: Instant { tv_sec: 343, tv_nsec: 916354293 } }) [2025-04-30T10:32:46.437418068Z TRACE quiche_server] Collecting garbage [2025-04-30T10:32:46.437423669Z TRACE quiche_server] recv() would block [2025-04-30T10:32:46.437428267Z TRACE quiche_server] dafab94ef8f0913ec3999204595b758552438294 done writing [2025-04-30T10:32:46.437433377Z TRACE quiche_server] Collecting garbage [2025-04-30T10:32:46.468492042Z TRACE quiche_server] got 46 bytes from [::ffff:193.167.0.100]:38465 to [::]:443 [2025-04-30T10:32:46.468504725Z TRACE quiche_server] got packet Short dcid=e1b5ca8a71cab56ed441e7cb977ead13ffc4a6b3 key_phase=false [2025-04-30T10:32:46.468514754Z TRACE quiche] dafab94ef8f0913ec3999204595b758552438294 rx pkt Short dcid=e1b5ca8a71cab56ed441e7cb977ead13ffc4a6b3 key_phase=false len=25 pn=1 [2025-04-30T10:32:46.468522118Z TRACE quiche] dafab94ef8f0913ec3999204595b758552438294 path ID 0 now see SCID with seq num 1 [2025-04-30T10:32:46.468527598Z TRACE quiche] dafab94ef8f0913ec3999204595b758552438294 rx frm ACK delay=16 blocks=[2..2] ecn_counts=None [2025-04-30T10:32:46.468532557Z TRACE quiche::recovery::congestion::recovery] dafab94ef8f0913ec3999204595b758552438294 packet newly acked 2 [2025-04-30T10:32:46.468537616Z TRACE quiche] dafab94ef8f0913ec3999204595b758552438294 rx frm RETIRE_CONNECTION_ID seq_num=0 [2025-04-30T10:32:46.468552043Z TRACE quiche_server] dafab94ef8f0913ec3999204595b758552438294 processed 46 bytes [2025-04-30T10:32:46.468556251Z INFO quiche_server] Retiring source CID dafab94ef8f0913ec3999204595b758552438294 [2025-04-30T10:32:46.468565088Z TRACE quiche_server] recv() would block [2025-04-30T10:32:46.468572371Z TRACE quiche] dafab94ef8f0913ec3999204595b758552438294 pmtud probe status false hs_con=true hs_sent=true cwnd_avail=13500 out_len=1350 left=1327 [2025-04-30T10:32:46.468578052Z TRACE quiche] dafab94ef8f0913ec3999204595b758552438294 tx pkt Short dcid= key_phase=false len=45 pn=3 [2025-04-30T10:32:46.468581448Z TRACE quiche] dafab94ef8f0913ec3999204595b758552438294 tx frm ACK delay=7 blocks=[1..1] ecn_counts=None [2025-04-30T10:32:46.468585145Z TRACE quiche] dafab94ef8f0913ec3999204595b758552438294 tx frm NEW_CONNECTION_ID seq_num=4 retire_prior_to=1 conn_id=[07, 9a, 8d, 59, db, 20, 4c, 2c, b3, a6, 78, 1d, 33, 86, 6d, 8d, e1, 99, 6c, f0] reset_token=[b8, 5f, 88, ca, 1e, 6c, 81, e9, a3, ef, 2c, b0, 3e, 77, 18, a5] [2025-04-30T10:32:46.468598891Z TRACE quiche::recovery::congestion::recovery] dafab94ef8f0913ec3999204595b758552438294 timer=111.595102ms latest_rtt=31.213363ms srtt=33.182003ms min_rtt=31.213363ms rttvar=13.111182ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=63 app_limited=true congestion_recovery_start_time=None Rate { delivered: 685, delivered_time: Instant { tv_sec: 343, tv_nsec: 947622638 }, first_sent_time: Instant { tv_sec: 343, tv_nsec: 947622638 }, end_of_app_limited: 2, last_sent_packet: 3, largest_acked: 2, rate_sample: RateSample { delivery_rate: 17268, is_app_limited: true, interval: 31.213363ms, delivered: 539, prior_delivered: 146, prior_time: Some(Instant { tv_sec: 343, tv_nsec: 916354293 }), send_elapsed: 0ns, ack_elapsed: 31.213363ms, rtt: 31.213363ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 508558, last_update: Instant { tv_sec: 343, tv_nsec: 947622638 }, next_time: Instant { tv_sec: 343, tv_nsec: 947622638 }, max_datagram_size: 1350, last_packet_size: Some(0), iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } [2025-04-30T10:32:46.468661688Z TRACE quiche_server] dafab94ef8f0913ec3999204595b758552438294 written 63 bytes with Some(SendInfo { from: [::]:443, to: [::ffff:193.167.0.100]:38465, at: Instant { tv_sec: 343, tv_nsec: 947622638 } }) [2025-04-30T10:32:46.468669903Z TRACE quiche_server] Collecting garbage [2025-04-30T10:32:46.468677868Z TRACE quiche_server] recv() would block [2025-04-30T10:32:46.468682978Z TRACE quiche_server] dafab94ef8f0913ec3999204595b758552438294 done writing [2025-04-30T10:32:46.468687787Z TRACE quiche_server] Collecting garbage [2025-04-30T10:32:46.499423038Z TRACE quiche_server] got 63 bytes from [::ffff:193.167.0.100]:38465 to [::]:443 [2025-04-30T10:32:46.499446382Z TRACE quiche_server] got packet Short dcid=e1b5ca8a71cab56ed441e7cb977ead13ffc4a6b3 key_phase=false [2025-04-30T10:32:46.499459185Z TRACE quiche] dafab94ef8f0913ec3999204595b758552438294 rx pkt Short dcid=e1b5ca8a71cab56ed441e7cb977ead13ffc4a6b3 key_phase=false len=42 pn=2 [2025-04-30T10:32:46.499471078Z TRACE quiche] dafab94ef8f0913ec3999204595b758552438294 rx frm ACK delay=18 blocks=[3..3] ecn_counts=None [2025-04-30T10:32:46.499478201Z TRACE quiche::recovery::congestion::recovery] dafab94ef8f0913ec3999204595b758552438294 packet newly acked 3 [2025-04-30T10:32:46.499484563Z TRACE quiche] dafab94ef8f0913ec3999204595b758552438294 rx frm STREAM id=0 off=0 len=17 fin=true [2025-04-30T10:32:46.499507345Z TRACE quiche_server] dafab94ef8f0913ec3999204595b758552438294 processed 63 bytes [2025-04-30T10:32:46.499511603Z DEBUG quiche_apps::common] dafab94ef8f0913ec3999204595b758552438294 response stream 0 is writable with capacity Ok(13500) [2025-04-30T10:32:46.499520480Z TRACE quiche_apps::common] dafab94ef8f0913ec3999204595b758552438294 received 17 bytes [2025-04-30T10:32:46.499523716Z TRACE quiche_apps::common] dafab94ef8f0913ec3999204595b758552438294 stream 0 has 17 bytes (fin? true) [2025-04-30T10:32:46.499528915Z INFO quiche_apps::common] dafab94ef8f0913ec3999204595b758552438294 got GET request for "/www/usjcuwtokq" on stream 0 [2025-04-30T10:32:46.499567057Z INFO quiche_apps::common] dafab94ef8f0913ec3999204595b758552438294 sending response of size 5120 on stream 0 [2025-04-30T10:32:46.499576624Z TRACE quiche_server] recv() would block [2025-04-30T10:32:46.499585651Z TRACE quiche] dafab94ef8f0913ec3999204595b758552438294 pmtud probe status false hs_con=true hs_sent=true cwnd_avail=13500 out_len=1350 left=1327 [2025-04-30T10:32:46.499593666Z TRACE quiche] dafab94ef8f0913ec3999204595b758552438294 tx pkt Short dcid= key_phase=false len=1332 pn=4 [2025-04-30T10:32:46.499597022Z TRACE quiche] dafab94ef8f0913ec3999204595b758552438294 tx frm ACK delay=15 blocks=[2..2] ecn_counts=None [2025-04-30T10:32:46.499601060Z TRACE quiche] dafab94ef8f0913ec3999204595b758552438294 tx frm STREAM id=0 off=0 len=1322 fin=false [2025-04-30T10:32:46.499611550Z TRACE quiche::recovery::congestion::recovery] dafab94ef8f0913ec3999204595b758552438294 timer=100.490106ms latest_rtt=30.888057ms srtt=32.895259ms min_rtt=30.888057ms rttvar=10.406872ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=1350 app_limited=true congestion_recovery_start_time=None Rate { delivered: 748, delivered_time: Instant { tv_sec: 343, tv_nsec: 978634365 }, first_sent_time: Instant { tv_sec: 343, tv_nsec: 978634365 }, end_of_app_limited: 3, last_sent_packet: 4, largest_acked: 3, rate_sample: RateSample { delivery_rate: 2039, is_app_limited: true, interval: 30.888057ms, delivered: 63, prior_delivered: 685, prior_time: Some(Instant { tv_sec: 343, tv_nsec: 947622638 }), send_elapsed: 0ns, ack_elapsed: 30.888057ms, rtt: 30.888057ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 512991, last_update: Instant { tv_sec: 343, tv_nsec: 978634365 }, next_time: Instant { tv_sec: 343, tv_nsec: 978634365 }, max_datagram_size: 1350, last_packet_size: Some(0), iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } [2025-04-30T10:32:46.499642447Z TRACE quiche] dafab94ef8f0913ec3999204595b758552438294 pmtud probe status false hs_con=true hs_sent=true cwnd_avail=12150 out_len=1350 left=1332 [2025-04-30T10:32:46.499646846Z TRACE quiche] dafab94ef8f0913ec3999204595b758552438294 tx pkt Short dcid= key_phase=false len=1332 pn=5 [2025-04-30T10:32:46.499649951Z TRACE quiche] dafab94ef8f0913ec3999204595b758552438294 tx frm STREAM id=0 off=1322 len=1326 fin=false [2025-04-30T10:32:46.499656223Z TRACE quiche::recovery::congestion::recovery] dafab94ef8f0913ec3999204595b758552438294 timer=100.506907ms latest_rtt=30.888057ms srtt=32.895259ms min_rtt=30.888057ms rttvar=10.406872ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=2700 app_limited=true congestion_recovery_start_time=None Rate { delivered: 748, delivered_time: Instant { tv_sec: 343, tv_nsec: 978634365 }, first_sent_time: Instant { tv_sec: 343, tv_nsec: 978634365 }, end_of_app_limited: 4, last_sent_packet: 5, largest_acked: 3, rate_sample: RateSample { delivery_rate: 2039, is_app_limited: true, interval: 30.888057ms, delivered: 63, prior_delivered: 685, prior_time: Some(Instant { tv_sec: 343, tv_nsec: 947622638 }), send_elapsed: 0ns, ack_elapsed: 30.888057ms, rtt: 30.888057ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 512991, last_update: Instant { tv_sec: 343, tv_nsec: 978634365 }, next_time: Instant { tv_sec: 343, tv_nsec: 978634365 }, max_datagram_size: 1350, last_packet_size: Some(0), iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } [2025-04-30T10:32:46.499668506Z TRACE quiche] dafab94ef8f0913ec3999204595b758552438294 pmtud probe status false hs_con=true hs_sent=true cwnd_avail=10800 out_len=1350 left=1332 [2025-04-30T10:32:46.499672283Z TRACE quiche] dafab94ef8f0913ec3999204595b758552438294 tx pkt Short dcid= key_phase=false len=1332 pn=6 [2025-04-30T10:32:46.499675238Z TRACE quiche] dafab94ef8f0913ec3999204595b758552438294 tx frm STREAM id=0 off=2648 len=1326 fin=false [2025-04-30T10:32:46.499680598Z TRACE quiche::recovery::congestion::recovery] dafab94ef8f0913ec3999204595b758552438294 timer=100.509352ms latest_rtt=30.888057ms srtt=32.895259ms min_rtt=30.888057ms rttvar=10.406872ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=4050 app_limited=true congestion_recovery_start_time=None Rate { delivered: 748, delivered_time: Instant { tv_sec: 343, tv_nsec: 978634365 }, first_sent_time: Instant { tv_sec: 343, tv_nsec: 978634365 }, end_of_app_limited: 5, last_sent_packet: 6, largest_acked: 3, rate_sample: RateSample { delivery_rate: 2039, is_app_limited: true, interval: 30.888057ms, delivered: 63, prior_delivered: 685, prior_time: Some(Instant { tv_sec: 343, tv_nsec: 947622638 }), send_elapsed: 0ns, ack_elapsed: 30.888057ms, rtt: 30.888057ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 512991, last_update: Instant { tv_sec: 343, tv_nsec: 978634365 }, next_time: Instant { tv_sec: 343, tv_nsec: 978634365 }, max_datagram_size: 1350, last_packet_size: Some(0), iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } [2025-04-30T10:32:46.499691859Z TRACE quiche] dafab94ef8f0913ec3999204595b758552438294 pmtud probe status false hs_con=true hs_sent=true cwnd_avail=9450 out_len=1350 left=1332 [2025-04-30T10:32:46.499695496Z TRACE quiche] dafab94ef8f0913ec3999204595b758552438294 tx pkt Short dcid= key_phase=false len=1152 pn=7 [2025-04-30T10:32:46.499698411Z TRACE quiche] dafab94ef8f0913ec3999204595b758552438294 tx frm STREAM id=0 off=3974 len=1146 fin=true [2025-04-30T10:32:46.499707659Z TRACE quiche::recovery::congestion::recovery] dafab94ef8f0913ec3999204595b758552438294 timer=100.505785ms latest_rtt=30.888057ms srtt=32.895259ms min_rtt=30.888057ms rttvar=10.406872ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=5220 app_limited=true congestion_recovery_start_time=None Rate { delivered: 748, delivered_time: Instant { tv_sec: 343, tv_nsec: 978634365 }, first_sent_time: Instant { tv_sec: 343, tv_nsec: 978634365 }, end_of_app_limited: 6, last_sent_packet: 7, largest_acked: 3, rate_sample: RateSample { delivery_rate: 2039, is_app_limited: true, interval: 30.888057ms, delivered: 63, prior_delivered: 685, prior_time: Some(Instant { tv_sec: 343, tv_nsec: 947622638 }), send_elapsed: 0ns, ack_elapsed: 30.888057ms, rtt: 30.888057ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 512991, last_update: Instant { tv_sec: 343, tv_nsec: 978634365 }, next_time: Instant { tv_sec: 343, tv_nsec: 978634365 }, max_datagram_size: 1350, last_packet_size: Some(0), iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } [2025-04-30T10:32:46.499833293Z TRACE quiche_server] dafab94ef8f0913ec3999204595b758552438294 written 5220 bytes with Some(SendInfo { from: [::]:443, to: [::ffff:193.167.0.100]:38465, at: Instant { tv_sec: 343, tv_nsec: 978634365 } }) [2025-04-30T10:32:46.499845846Z TRACE quiche_server] Collecting garbage [2025-04-30T10:32:46.499853831Z TRACE quiche_server] recv() would block [2025-04-30T10:32:46.499859151Z TRACE quiche_server] dafab94ef8f0913ec3999204595b758552438294 done writing [2025-04-30T10:32:46.499863730Z TRACE quiche_server] Collecting garbage [2025-04-30T10:32:46.532455653Z TRACE quiche_server] got 44 bytes from [::ffff:193.167.0.100]:38465 to [::]:443 [2025-04-30T10:32:46.532477955Z TRACE quiche_server] got packet Short dcid=e1b5ca8a71cab56ed441e7cb977ead13ffc4a6b3 key_phase=false [2025-04-30T10:32:46.532490598Z TRACE quiche] dafab94ef8f0913ec3999204595b758552438294 rx pkt Short dcid=e1b5ca8a71cab56ed441e7cb977ead13ffc4a6b3 key_phase=false len=23 pn=3 [2025-04-30T10:32:46.532502100Z TRACE quiche] dafab94ef8f0913ec3999204595b758552438294 rx frm ACK delay=6 blocks=[4..5] ecn_counts=None [2025-04-30T10:32:46.532508392Z TRACE quiche::recovery::congestion::recovery] dafab94ef8f0913ec3999204595b758552438294 packet newly acked 4 [2025-04-30T10:32:46.532511858Z TRACE quiche::recovery::congestion::recovery] dafab94ef8f0913ec3999204595b758552438294 packet newly acked 5 [2025-04-30T10:32:46.532557232Z TRACE quiche_server] dafab94ef8f0913ec3999204595b758552438294 processed 44 bytes [2025-04-30T10:32:46.532564025Z TRACE quiche_server] recv() would block [2025-04-30T10:32:46.532567762Z TRACE quiche_server] dafab94ef8f0913ec3999204595b758552438294 done writing [2025-04-30T10:32:46.532570337Z TRACE quiche_server] Collecting garbage [2025-04-30T10:32:46.534466292Z TRACE quiche_server] got 44 bytes from [::ffff:193.167.0.100]:38465 to [::]:443 [2025-04-30T10:32:46.534473816Z TRACE quiche_server] got packet Short dcid=e1b5ca8a71cab56ed441e7cb977ead13ffc4a6b3 key_phase=false [2025-04-30T10:32:46.534479536Z TRACE quiche] dafab94ef8f0913ec3999204595b758552438294 rx pkt Short dcid=e1b5ca8a71cab56ed441e7cb977ead13ffc4a6b3 key_phase=false len=23 pn=4 [2025-04-30T10:32:46.534485057Z TRACE quiche] dafab94ef8f0913ec3999204595b758552438294 rx frm ACK delay=5 blocks=[4..7] ecn_counts=None [2025-04-30T10:32:46.534488793Z TRACE quiche::recovery::congestion::recovery] dafab94ef8f0913ec3999204595b758552438294 packet newly acked 6 [2025-04-30T10:32:46.534491629Z TRACE quiche::recovery::congestion::recovery] dafab94ef8f0913ec3999204595b758552438294 packet newly acked 7 [2025-04-30T10:32:46.534505234Z TRACE quiche_server] dafab94ef8f0913ec3999204595b758552438294 processed 44 bytes [2025-04-30T10:32:46.534516505Z TRACE quiche_server] got 42 bytes from [::ffff:193.167.0.100]:38465 to [::]:443 [2025-04-30T10:32:46.534520102Z TRACE quiche_server] got packet Short dcid=e1b5ca8a71cab56ed441e7cb977ead13ffc4a6b3 key_phase=false [2025-04-30T10:32:46.534524440Z TRACE quiche] dafab94ef8f0913ec3999204595b758552438294 rx pkt Short dcid=e1b5ca8a71cab56ed441e7cb977ead13ffc4a6b3 key_phase=false len=21 pn=5 [2025-04-30T10:32:46.534529750Z TRACE quiche] dafab94ef8f0913ec3999204595b758552438294 rx frm APPLICATION_CLOSE err=0 reason=[] [2025-04-30T10:32:46.534536553Z TRACE quiche_server] dafab94ef8f0913ec3999204595b758552438294 processed 42 bytes [2025-04-30T10:32:46.534540470Z TRACE quiche_server] recv() would block [2025-04-30T10:32:46.534543225Z TRACE quiche_server] dafab94ef8f0913ec3999204595b758552438294 done writing [2025-04-30T10:32:46.534545900Z TRACE quiche_server] Collecting garbage [2025-04-30T10:32:46.536326410Z TRACE quiche_server] got 1280 bytes from [::ffff:193.167.0.100]:58948 to [::]:443 [2025-04-30T10:32:46.536333964Z TRACE quiche_server] got packet Initial version=1 dcid=d62738cfe09c177f4466251058 scid= token= [2025-04-30T10:32:46.536338622Z DEBUG quiche_server] New connection: dcid=d62738cfe09c177f4466251058 scid=3497fdbbb7aa20e64922e8d08f87dc43c3ced6f3 [2025-04-30T10:32:46.536473854Z TRACE quiche] 3497fdbbb7aa20e64922e8d08f87dc43c3ced6f3 rx pkt Initial version=1 dcid=d62738cfe09c177f4466251058 scid= token= len=1257 pn=0 [2025-04-30T10:32:46.536486518Z TRACE quiche] 3497fdbbb7aa20e64922e8d08f87dc43c3ced6f3 rx frm PADDING len=736 [2025-04-30T10:32:46.536490355Z TRACE quiche] 3497fdbbb7aa20e64922e8d08f87dc43c3ced6f3 rx frm CRYPTO off=0 len=499 [2025-04-30T10:32:46.536518077Z TRACE quiche::tls] checking peer ALPN Ok("hq-interop") against Ok("h3") [2025-04-30T10:32:46.536522425Z TRACE quiche::tls] checking peer ALPN Ok("hq-interop") against Ok("hq-interop") [2025-04-30T10:32:46.536640245Z TRACE quiche::tls] 3497fdbbb7aa20e64922e8d08f87dc43c3ced6f3 write message lvl=Initial len=96 [2025-04-30T10:32:46.536658358Z TRACE quiche::tls] 3497fdbbb7aa20e64922e8d08f87dc43c3ced6f3 set write secret lvl=Handshake [2025-04-30T10:32:46.536687092Z TRACE quiche::tls] 3497fdbbb7aa20e64922e8d08f87dc43c3ced6f3 write message lvl=Handshake len=153 [2025-04-30T10:32:46.536690208Z TRACE quiche::tls] 3497fdbbb7aa20e64922e8d08f87dc43c3ced6f3 set write secret lvl=OneRTT [2025-04-30T10:32:46.536697421Z TRACE quiche::tls] 3497fdbbb7aa20e64922e8d08f87dc43c3ced6f3 set read secret lvl=Handshake [2025-04-30T10:32:46.536718751Z TRACE quiche_server] 3497fdbbb7aa20e64922e8d08f87dc43c3ced6f3 processed 1280 bytes [2025-04-30T10:32:46.536731535Z TRACE quiche_server] recv() would block [2025-04-30T10:32:46.536734520Z TRACE quiche_server] dafab94ef8f0913ec3999204595b758552438294 done writing [2025-04-30T10:32:46.536745591Z TRACE quiche] 3497fdbbb7aa20e64922e8d08f87dc43c3ced6f3 tx pkt Initial version=1 dcid= scid=3497fdbbb7aa20e64922e8d08f87dc43c3ced6f3 len=105 pn=0 [2025-04-30T10:32:46.536749438Z TRACE quiche] 3497fdbbb7aa20e64922e8d08f87dc43c3ced6f3 tx frm ACK delay=35 blocks=[0..0] ecn_counts=None [2025-04-30T10:32:46.536753476Z TRACE quiche] 3497fdbbb7aa20e64922e8d08f87dc43c3ced6f3 tx frm CRYPTO off=0 len=96 [2025-04-30T10:32:46.536762893Z TRACE quiche::recovery::congestion::recovery] 3497fdbbb7aa20e64922e8d08f87dc43c3ced6f3 timer=998.973671ms 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: 344, tv_nsec: 15791921 }, first_sent_time: Instant { tv_sec: 344, tv_nsec: 15791921 }, 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: 344, tv_nsec: 15791921 }, next_time: Instant { tv_sec: 344, tv_nsec: 15791921 }, max_datagram_size: 1350, last_packet_size: None, iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } [2025-04-30T10:32:46.536790275Z TRACE quiche] 3497fdbbb7aa20e64922e8d08f87dc43c3ced6f3 tx pkt Handshake version=1 dcid= scid=3497fdbbb7aa20e64922e8d08f87dc43c3ced6f3 len=157 pn=1 [2025-04-30T10:32:46.536793681Z TRACE quiche] 3497fdbbb7aa20e64922e8d08f87dc43c3ced6f3 tx frm CRYPTO off=0 len=153 [2025-04-30T10:32:46.536799902Z TRACE quiche::recovery::congestion::recovery] 3497fdbbb7aa20e64922e8d08f87dc43c3ced6f3 timer=998.936893ms latest_rtt=0ns srtt=333ms min_rtt=333ms rttvar=166.5ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=355 app_limited=true congestion_recovery_start_time=None Rate { delivered: 0, delivered_time: Instant { tv_sec: 344, tv_nsec: 15791921 }, first_sent_time: Instant { tv_sec: 344, tv_nsec: 15791921 }, 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: 344, tv_nsec: 15791921 }, next_time: Instant { tv_sec: 344, tv_nsec: 15791921 }, max_datagram_size: 1350, last_packet_size: None, iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } [2025-04-30T10:32:46.536851799Z TRACE quiche_server] 3497fdbbb7aa20e64922e8d08f87dc43c3ced6f3 written 1200 bytes with Some(SendInfo { from: [::]:443, to: [::ffff:193.167.0.100]:58948, at: Instant { tv_sec: 344, tv_nsec: 15791921 } }) [2025-04-30T10:32:46.536858652Z TRACE quiche_server] Collecting garbage [2025-04-30T10:32:46.536861417Z TRACE quiche_server] Collecting garbage [2025-04-30T10:32:46.536866066Z TRACE quiche_server] recv() would block [2025-04-30T10:32:46.536868771Z TRACE quiche_server] dafab94ef8f0913ec3999204595b758552438294 done writing [2025-04-30T10:32:46.536872898Z TRACE quiche_server] 3497fdbbb7aa20e64922e8d08f87dc43c3ced6f3 done writing [2025-04-30T10:32:46.536875583Z TRACE quiche_server] Collecting garbage [2025-04-30T10:32:46.536878048Z TRACE quiche_server] Collecting garbage [2025-04-30T10:32:46.569858504Z TRACE quiche_server] got 1280 bytes from [::ffff:193.167.0.100]:58948 to [::]:443 [2025-04-30T10:32:46.569881276Z TRACE quiche_server] got packet Initial version=1 dcid=3497fdbbb7aa20e64922e8d08f87dc43c3ced6f3 scid= token= [2025-04-30T10:32:46.569895102Z TRACE quiche] 3497fdbbb7aa20e64922e8d08f87dc43c3ced6f3 rx pkt Initial version=1 dcid=3497fdbbb7aa20e64922e8d08f87dc43c3ced6f3 scid= token= len=1164 pn=1 [2025-04-30T10:32:46.569907685Z TRACE quiche] 3497fdbbb7aa20e64922e8d08f87dc43c3ced6f3 rx frm ACK delay=0 blocks=[0..0] ecn_counts=None [2025-04-30T10:32:46.569914408Z TRACE quiche::recovery::congestion::recovery] 3497fdbbb7aa20e64922e8d08f87dc43c3ced6f3 packet newly acked 0 [2025-04-30T10:32:46.569924677Z TRACE quiche] 3497fdbbb7aa20e64922e8d08f87dc43c3ced6f3 rx frm PADDING len=1141 [2025-04-30T10:32:46.569971985Z TRACE quiche] 3497fdbbb7aa20e64922e8d08f87dc43c3ced6f3 rx pkt Handshake version=1 dcid=3497fdbbb7aa20e64922e8d08f87dc43c3ced6f3 scid= len=57 pn=0 [2025-04-30T10:32:46.569979599Z TRACE quiche] 3497fdbbb7aa20e64922e8d08f87dc43c3ced6f3 rx frm CRYPTO off=0 len=36 [2025-04-30T10:32:46.569999527Z TRACE quiche::tls] 3497fdbbb7aa20e64922e8d08f87dc43c3ced6f3 set read secret lvl=OneRTT [2025-04-30T10:32:46.570041214Z TRACE quiche::tls] 3497fdbbb7aa20e64922e8d08f87dc43c3ced6f3 write message lvl=OneRTT len=396 [2025-04-30T10:32:46.570051393Z TRACE quiche] 3497fdbbb7aa20e64922e8d08f87dc43c3ced6f3 dropped epoch 1 state [2025-04-30T10:32:46.570064898Z TRACE quiche] 3497fdbbb7aa20e64922e8d08f87dc43c3ced6f3 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: 1452, initial_max_data: 786432, initial_max_stream_data_bidi_local: 524288, initial_max_stream_data_bidi_remote: 524288, initial_max_stream_data_uni: 524288, initial_max_streams_bidi: 100, initial_max_streams_uni: 100, ack_delay_exponent: 3, max_ack_delay: 26, disable_active_migration: false, active_conn_id_limit: 4, initial_source_connection_id: Some(), retry_source_connection_id: None, max_datagram_frame_size: None, unknown_params: None } [2025-04-30T10:32:46.570086308Z TRACE quiche] 3497fdbbb7aa20e64922e8d08f87dc43c3ced6f3 dropped epoch 0 state [2025-04-30T10:32:46.570089815Z TRACE quiche_server] 3497fdbbb7aa20e64922e8d08f87dc43c3ced6f3 processed 1280 bytes [2025-04-30T10:32:46.570099012Z TRACE quiche_server] got 52 bytes from [::ffff:193.167.0.100]:58948 to [::]:443 [2025-04-30T10:32:46.570103180Z TRACE quiche_server] got packet Handshake version=1 dcid=3497fdbbb7aa20e64922e8d08f87dc43c3ced6f3 scid= [2025-04-30T10:32:46.570109261Z TRACE quiche] 3497fdbbb7aa20e64922e8d08f87dc43c3ced6f3 dropped invalid packet [2025-04-30T10:32:46.570112377Z TRACE quiche_server] 3497fdbbb7aa20e64922e8d08f87dc43c3ced6f3 processed 52 bytes [2025-04-30T10:32:46.570117436Z TRACE quiche_server] got 58 bytes from [::ffff:193.167.0.100]:58948 to [::]:443 [2025-04-30T10:32:46.570120773Z TRACE quiche_server] got packet Short dcid=3497fdbbb7aa20e64922e8d08f87dc43c3ced6f3 key_phase=false [2025-04-30T10:32:46.570125411Z TRACE quiche] 3497fdbbb7aa20e64922e8d08f87dc43c3ced6f3 rx pkt Short dcid=3497fdbbb7aa20e64922e8d08f87dc43c3ced6f3 key_phase=false len=37 pn=0 [2025-04-30T10:32:46.570131332Z TRACE quiche] 3497fdbbb7aa20e64922e8d08f87dc43c3ced6f3 rx frm STREAM id=0 off=0 len=17 fin=true [2025-04-30T10:32:46.570138896Z TRACE quiche_server] 3497fdbbb7aa20e64922e8d08f87dc43c3ced6f3 processed 58 bytes [2025-04-30T10:32:46.570142072Z DEBUG quiche_apps::common] 3497fdbbb7aa20e64922e8d08f87dc43c3ced6f3 response stream 0 is writable with capacity Ok(13500) [2025-04-30T10:32:46.570149566Z TRACE quiche_apps::common] 3497fdbbb7aa20e64922e8d08f87dc43c3ced6f3 received 17 bytes [2025-04-30T10:32:46.570152762Z TRACE quiche_apps::common] 3497fdbbb7aa20e64922e8d08f87dc43c3ced6f3 stream 0 has 17 bytes (fin? true) [2025-04-30T10:32:46.570157742Z INFO quiche_apps::common] 3497fdbbb7aa20e64922e8d08f87dc43c3ced6f3 got GET request for "/www/wzuysylzdw" on stream 0 [2025-04-30T10:32:46.570187417Z INFO quiche_apps::common] 3497fdbbb7aa20e64922e8d08f87dc43c3ced6f3 sending response of size 10240 on stream 0 [2025-04-30T10:32:46.570195793Z TRACE quiche_server] recv() would block [2025-04-30T10:32:46.570199259Z TRACE quiche_server] dafab94ef8f0913ec3999204595b758552438294 done writing [2025-04-30T10:32:46.570207544Z TRACE quiche] 3497fdbbb7aa20e64922e8d08f87dc43c3ced6f3 pmtud probe status false hs_con=true hs_sent=false cwnd_avail=13500 out_len=1350 left=1327 [2025-04-30T10:32:46.570216822Z TRACE quiche] 3497fdbbb7aa20e64922e8d08f87dc43c3ced6f3 tx pkt Short dcid= key_phase=false len=1332 pn=2 [2025-04-30T10:32:46.570220178Z TRACE quiche] 3497fdbbb7aa20e64922e8d08f87dc43c3ced6f3 tx frm ACK delay=10 blocks=[0..0] ecn_counts=None [2025-04-30T10:32:46.570224215Z TRACE quiche] 3497fdbbb7aa20e64922e8d08f87dc43c3ced6f3 tx frm NEW_CONNECTION_ID seq_num=1 retire_prior_to=0 conn_id=[9c, 2a, dd, 29, f2, ae, a5, 3a, 61, a2, 4b, 27, 59, 24, 1e, 02, 92, 1d, b3, 1f] reset_token=[6f, e1, c0, 4a, fc, 98, 35, be, 8d, 6b, 37, b2, e2, 93, bc, a9] [2025-04-30T10:32:46.570232621Z TRACE quiche] 3497fdbbb7aa20e64922e8d08f87dc43c3ced6f3 tx frm NEW_CONNECTION_ID seq_num=2 retire_prior_to=0 conn_id=[fb, 50, 94, 52, e3, fd, 71, 0c, c9, aa, 19, f4, f8, 84, 4c, 15, 08, ac, 3b, 11] reset_token=[12, c6, 95, 65, 18, 30, ef, 15, 01, c9, fd, c5, bf, 53, b1, 18] [2025-04-30T10:32:46.570244564Z TRACE quiche] 3497fdbbb7aa20e64922e8d08f87dc43c3ced6f3 tx frm NEW_CONNECTION_ID seq_num=3 retire_prior_to=0 conn_id=[c8, 2f, 89, 28, 80, 16, a4, 50, 92, 83, 56, 36, c3, ce, 75, 1c, 87, dd, 92, 44] reset_token=[95, 4d, 90, 69, 0b, 07, 59, fb, fc, 21, 0f, 7a, 87, 43, cc, 00] [2025-04-30T10:32:46.570251176Z TRACE quiche] 3497fdbbb7aa20e64922e8d08f87dc43c3ced6f3 tx frm HANDSHAKE_DONE [2025-04-30T10:32:46.570254031Z TRACE quiche] 3497fdbbb7aa20e64922e8d08f87dc43c3ced6f3 tx frm CRYPTO off=0 len=396 [2025-04-30T10:32:46.570256916Z TRACE quiche] 3497fdbbb7aa20e64922e8d08f87dc43c3ced6f3 tx frm STREAM id=0 off=0 len=801 fin=false [2025-04-30T10:32:46.570270171Z TRACE quiche::recovery::congestion::recovery] 3497fdbbb7aa20e64922e8d08f87dc43c3ced6f3 timer=125.394513ms latest_rtt=33.15441ms srtt=33.15441ms min_rtt=33.15441ms rttvar=16.577205ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=1350 app_limited=true congestion_recovery_start_time=None Rate { delivered: 152, delivered_time: Instant { tv_sec: 344, tv_nsec: 49256850 }, first_sent_time: Instant { tv_sec: 344, tv_nsec: 49256850 }, end_of_app_limited: 1, last_sent_packet: 2, largest_acked: 0, rate_sample: RateSample { delivery_rate: 4584, is_app_limited: true, interval: 33.15441ms, delivered: 152, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 344, tv_nsec: 15791921 }), send_elapsed: 0ns, ack_elapsed: 33.15441ms, rtt: 33.15441ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 508982, last_update: Instant { tv_sec: 344, tv_nsec: 49256850 }, next_time: Instant { tv_sec: 344, tv_nsec: 49256850 }, max_datagram_size: 1350, last_packet_size: Some(0), iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } [2025-04-30T10:32:46.570289477Z TRACE quiche] 3497fdbbb7aa20e64922e8d08f87dc43c3ced6f3 pmtud probe status false hs_con=true hs_sent=true cwnd_avail=12150 out_len=1350 left=1332 [2025-04-30T10:32:46.570293895Z TRACE quiche] 3497fdbbb7aa20e64922e8d08f87dc43c3ced6f3 tx pkt Short dcid= key_phase=false len=1332 pn=3 [2025-04-30T10:32:46.570297081Z TRACE quiche] 3497fdbbb7aa20e64922e8d08f87dc43c3ced6f3 tx frm STREAM id=0 off=801 len=1326 fin=false [2025-04-30T10:32:46.570303093Z TRACE quiche::recovery::congestion::recovery] 3497fdbbb7aa20e64922e8d08f87dc43c3ced6f3 timer=125.447792ms latest_rtt=33.15441ms srtt=33.15441ms min_rtt=33.15441ms rttvar=16.577205ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=2700 app_limited=true congestion_recovery_start_time=None Rate { delivered: 152, delivered_time: Instant { tv_sec: 344, tv_nsec: 49256850 }, first_sent_time: Instant { tv_sec: 344, tv_nsec: 49256850 }, end_of_app_limited: 2, last_sent_packet: 3, largest_acked: 0, rate_sample: RateSample { delivery_rate: 4584, is_app_limited: true, interval: 33.15441ms, delivered: 152, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 344, tv_nsec: 15791921 }), send_elapsed: 0ns, ack_elapsed: 33.15441ms, rtt: 33.15441ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 508982, last_update: Instant { tv_sec: 344, tv_nsec: 49256850 }, next_time: Instant { tv_sec: 344, tv_nsec: 49256850 }, max_datagram_size: 1350, last_packet_size: Some(0), iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } [2025-04-30T10:32:46.570315255Z TRACE quiche] 3497fdbbb7aa20e64922e8d08f87dc43c3ced6f3 pmtud probe status false hs_con=true hs_sent=true cwnd_avail=10800 out_len=1350 left=1332 [2025-04-30T10:32:46.570319123Z TRACE quiche] 3497fdbbb7aa20e64922e8d08f87dc43c3ced6f3 tx pkt Short dcid= key_phase=false len=1332 pn=4 [2025-04-30T10:32:46.570325725Z TRACE quiche] 3497fdbbb7aa20e64922e8d08f87dc43c3ced6f3 tx frm STREAM id=0 off=2127 len=1326 fin=false [2025-04-30T10:32:46.570331215Z TRACE quiche::recovery::congestion::recovery] 3497fdbbb7aa20e64922e8d08f87dc43c3ced6f3 timer=125.445968ms latest_rtt=33.15441ms srtt=33.15441ms min_rtt=33.15441ms rttvar=16.577205ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=4050 app_limited=true congestion_recovery_start_time=None Rate { delivered: 152, delivered_time: Instant { tv_sec: 344, tv_nsec: 49256850 }, first_sent_time: Instant { tv_sec: 344, tv_nsec: 49256850 }, end_of_app_limited: 3, last_sent_packet: 4, largest_acked: 0, rate_sample: RateSample { delivery_rate: 4584, is_app_limited: true, interval: 33.15441ms, delivered: 152, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 344, tv_nsec: 15791921 }), send_elapsed: 0ns, ack_elapsed: 33.15441ms, rtt: 33.15441ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 508982, last_update: Instant { tv_sec: 344, tv_nsec: 49256850 }, next_time: Instant { tv_sec: 344, tv_nsec: 49256850 }, max_datagram_size: 1350, last_packet_size: Some(0), iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } [2025-04-30T10:32:46.570342716Z TRACE quiche] 3497fdbbb7aa20e64922e8d08f87dc43c3ced6f3 pmtud probe status false hs_con=true hs_sent=true cwnd_avail=9450 out_len=1350 left=1332 [2025-04-30T10:32:46.570346313Z TRACE quiche] 3497fdbbb7aa20e64922e8d08f87dc43c3ced6f3 tx pkt Short dcid= key_phase=false len=1332 pn=5 [2025-04-30T10:32:46.570349199Z TRACE quiche] 3497fdbbb7aa20e64922e8d08f87dc43c3ced6f3 tx frm STREAM id=0 off=3453 len=1326 fin=false [2025-04-30T10:32:46.570354288Z TRACE quiche::recovery::congestion::recovery] 3497fdbbb7aa20e64922e8d08f87dc43c3ced6f3 timer=125.450536ms latest_rtt=33.15441ms srtt=33.15441ms min_rtt=33.15441ms rttvar=16.577205ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=5400 app_limited=true congestion_recovery_start_time=None Rate { delivered: 152, delivered_time: Instant { tv_sec: 344, tv_nsec: 49256850 }, first_sent_time: Instant { tv_sec: 344, tv_nsec: 49256850 }, end_of_app_limited: 3, last_sent_packet: 5, largest_acked: 0, rate_sample: RateSample { delivery_rate: 4584, is_app_limited: true, interval: 33.15441ms, delivered: 152, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 344, tv_nsec: 15791921 }), send_elapsed: 0ns, ack_elapsed: 33.15441ms, rtt: 33.15441ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 508982, last_update: Instant { tv_sec: 344, tv_nsec: 49256850 }, next_time: Instant { tv_sec: 344, tv_nsec: 49256850 }, max_datagram_size: 1350, last_packet_size: Some(0), iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } [2025-04-30T10:32:46.570365539Z TRACE quiche] 3497fdbbb7aa20e64922e8d08f87dc43c3ced6f3 pmtud probe status false hs_con=true hs_sent=true cwnd_avail=8100 out_len=1350 left=1332 [2025-04-30T10:32:46.570369126Z TRACE quiche] 3497fdbbb7aa20e64922e8d08f87dc43c3ced6f3 tx pkt Short dcid= key_phase=false len=1332 pn=6 [2025-04-30T10:32:46.570372041Z TRACE quiche] 3497fdbbb7aa20e64922e8d08f87dc43c3ced6f3 tx frm STREAM id=0 off=4779 len=1326 fin=false [2025-04-30T10:32:46.570377621Z TRACE quiche::recovery::congestion::recovery] 3497fdbbb7aa20e64922e8d08f87dc43c3ced6f3 timer=125.450106ms latest_rtt=33.15441ms srtt=33.15441ms min_rtt=33.15441ms rttvar=16.577205ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=6750 app_limited=true congestion_recovery_start_time=None Rate { delivered: 152, delivered_time: Instant { tv_sec: 344, tv_nsec: 49256850 }, first_sent_time: Instant { tv_sec: 344, tv_nsec: 49256850 }, end_of_app_limited: 3, last_sent_packet: 6, largest_acked: 0, rate_sample: RateSample { delivery_rate: 4584, is_app_limited: true, interval: 33.15441ms, delivered: 152, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 344, tv_nsec: 15791921 }), send_elapsed: 0ns, ack_elapsed: 33.15441ms, rtt: 33.15441ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 508982, last_update: Instant { tv_sec: 344, tv_nsec: 49256850 }, next_time: Instant { tv_sec: 344, tv_nsec: 49256850 }, max_datagram_size: 1350, last_packet_size: Some(0), iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } [2025-04-30T10:32:46.570392179Z TRACE quiche] 3497fdbbb7aa20e64922e8d08f87dc43c3ced6f3 pmtud probe status false hs_con=true hs_sent=true cwnd_avail=6750 out_len=1350 left=1332 [2025-04-30T10:32:46.570395795Z TRACE quiche] 3497fdbbb7aa20e64922e8d08f87dc43c3ced6f3 tx pkt Short dcid= key_phase=false len=1332 pn=7 [2025-04-30T10:32:46.570398741Z TRACE quiche] 3497fdbbb7aa20e64922e8d08f87dc43c3ced6f3 tx frm STREAM id=0 off=6105 len=1326 fin=false [2025-04-30T10:32:46.570403860Z TRACE quiche::recovery::congestion::recovery] 3497fdbbb7aa20e64922e8d08f87dc43c3ced6f3 timer=125.450426ms latest_rtt=33.15441ms srtt=33.15441ms min_rtt=33.15441ms rttvar=16.577205ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=8100 app_limited=true congestion_recovery_start_time=None Rate { delivered: 152, delivered_time: Instant { tv_sec: 344, tv_nsec: 49256850 }, first_sent_time: Instant { tv_sec: 344, tv_nsec: 49256850 }, end_of_app_limited: 3, last_sent_packet: 7, largest_acked: 0, rate_sample: RateSample { delivery_rate: 4584, is_app_limited: true, interval: 33.15441ms, delivered: 152, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 344, tv_nsec: 15791921 }), send_elapsed: 0ns, ack_elapsed: 33.15441ms, rtt: 33.15441ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 508982, last_update: Instant { tv_sec: 344, tv_nsec: 49256850 }, next_time: Instant { tv_sec: 344, tv_nsec: 49256850 }, max_datagram_size: 1350, last_packet_size: Some(0), iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } [2025-04-30T10:32:46.570415111Z TRACE quiche] 3497fdbbb7aa20e64922e8d08f87dc43c3ced6f3 pmtud probe status false hs_con=true hs_sent=true cwnd_avail=5400 out_len=1350 left=1332 [2025-04-30T10:32:46.570418818Z TRACE quiche] 3497fdbbb7aa20e64922e8d08f87dc43c3ced6f3 tx pkt Short dcid= key_phase=false len=1332 pn=8 [2025-04-30T10:32:46.570421734Z TRACE quiche] 3497fdbbb7aa20e64922e8d08f87dc43c3ced6f3 tx frm STREAM id=0 off=7431 len=1326 fin=false [2025-04-30T10:32:46.570426833Z TRACE quiche::recovery::congestion::recovery] 3497fdbbb7aa20e64922e8d08f87dc43c3ced6f3 timer=125.450386ms latest_rtt=33.15441ms srtt=33.15441ms min_rtt=33.15441ms rttvar=16.577205ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=9450 app_limited=true congestion_recovery_start_time=None Rate { delivered: 152, delivered_time: Instant { tv_sec: 344, tv_nsec: 49256850 }, first_sent_time: Instant { tv_sec: 344, tv_nsec: 49256850 }, end_of_app_limited: 3, last_sent_packet: 8, largest_acked: 0, rate_sample: RateSample { delivery_rate: 4584, is_app_limited: true, interval: 33.15441ms, delivered: 152, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 344, tv_nsec: 15791921 }), send_elapsed: 0ns, ack_elapsed: 33.15441ms, rtt: 33.15441ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 508982, last_update: Instant { tv_sec: 344, tv_nsec: 49256850 }, next_time: Instant { tv_sec: 344, tv_nsec: 49256850 }, max_datagram_size: 1350, last_packet_size: Some(0), iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } [2025-04-30T10:32:46.570441240Z TRACE quiche] 3497fdbbb7aa20e64922e8d08f87dc43c3ced6f3 pmtud probe status false hs_con=true hs_sent=true cwnd_avail=4050 out_len=1350 left=1332 [2025-04-30T10:32:46.570444877Z TRACE quiche] 3497fdbbb7aa20e64922e8d08f87dc43c3ced6f3 tx pkt Short dcid= key_phase=false len=1332 pn=9 [2025-04-30T10:32:46.570447802Z TRACE quiche] 3497fdbbb7aa20e64922e8d08f87dc43c3ced6f3 tx frm STREAM id=0 off=8757 len=1326 fin=false [2025-04-30T10:32:46.570453052Z TRACE quiche::recovery::congestion::recovery] 3497fdbbb7aa20e64922e8d08f87dc43c3ced6f3 timer=125.450326ms latest_rtt=33.15441ms srtt=33.15441ms min_rtt=33.15441ms rttvar=16.577205ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=10800 app_limited=true congestion_recovery_start_time=None Rate { delivered: 152, delivered_time: Instant { tv_sec: 344, tv_nsec: 49256850 }, first_sent_time: Instant { tv_sec: 344, tv_nsec: 49256850 }, end_of_app_limited: 3, last_sent_packet: 9, largest_acked: 0, rate_sample: RateSample { delivery_rate: 4584, is_app_limited: true, interval: 33.15441ms, delivered: 152, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 344, tv_nsec: 15791921 }), send_elapsed: 0ns, ack_elapsed: 33.15441ms, rtt: 33.15441ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 508982, last_update: Instant { tv_sec: 344, tv_nsec: 49256850 }, next_time: Instant { tv_sec: 344, tv_nsec: 49256850 }, max_datagram_size: 1350, last_packet_size: Some(0), iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } [2025-04-30T10:32:46.570464203Z TRACE quiche] 3497fdbbb7aa20e64922e8d08f87dc43c3ced6f3 pmtud probe status false hs_con=true hs_sent=true cwnd_avail=2700 out_len=1350 left=1332 [2025-04-30T10:32:46.570467760Z TRACE quiche] 3497fdbbb7aa20e64922e8d08f87dc43c3ced6f3 tx pkt Short dcid= key_phase=false len=163 pn=10 [2025-04-30T10:32:46.570470695Z TRACE quiche] 3497fdbbb7aa20e64922e8d08f87dc43c3ced6f3 tx frm STREAM id=0 off=10083 len=157 fin=true [2025-04-30T10:32:46.570476365Z TRACE quiche::recovery::congestion::recovery] 3497fdbbb7aa20e64922e8d08f87dc43c3ced6f3 timer=125.450055ms latest_rtt=33.15441ms srtt=33.15441ms min_rtt=33.15441ms rttvar=16.577205ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=10981 app_limited=true congestion_recovery_start_time=None Rate { delivered: 152, delivered_time: Instant { tv_sec: 344, tv_nsec: 49256850 }, first_sent_time: Instant { tv_sec: 344, tv_nsec: 49256850 }, end_of_app_limited: 3, last_sent_packet: 10, largest_acked: 0, rate_sample: RateSample { delivery_rate: 4584, is_app_limited: true, interval: 33.15441ms, delivered: 152, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 344, tv_nsec: 15791921 }), send_elapsed: 0ns, ack_elapsed: 33.15441ms, rtt: 33.15441ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 508982, last_update: Instant { tv_sec: 344, tv_nsec: 49256850 }, next_time: Instant { tv_sec: 344, tv_nsec: 49256850 }, max_datagram_size: 1350, last_packet_size: Some(0), iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } [2025-04-30T10:32:46.570621877Z TRACE quiche_server] 3497fdbbb7aa20e64922e8d08f87dc43c3ced6f3 written 10981 bytes with Some(SendInfo { from: [::]:443, to: [::ffff:193.167.0.100]:58948, at: Instant { tv_sec: 344, tv_nsec: 49256850 } }) [2025-04-30T10:32:46.570633679Z TRACE quiche_server] Collecting garbage [2025-04-30T10:32:46.570636644Z TRACE quiche_server] Collecting garbage [2025-04-30T10:32:46.570642295Z TRACE quiche_server] recv() would block [2025-04-30T10:32:46.570645050Z TRACE quiche_server] dafab94ef8f0913ec3999204595b758552438294 done writing [2025-04-30T10:32:46.570648326Z TRACE quiche_server] 3497fdbbb7aa20e64922e8d08f87dc43c3ced6f3 done writing [2025-04-30T10:32:46.570650941Z TRACE quiche_server] Collecting garbage [2025-04-30T10:32:46.570653416Z TRACE quiche_server] Collecting garbage [2025-04-30T10:32:46.602404032Z TRACE quiche_server] got 46 bytes from [::ffff:193.167.0.100]:58948 to [::]:443 [2025-04-30T10:32:46.602424059Z TRACE quiche_server] got packet Short dcid=9c2add29f2aea53a61a24b2759241e02921db31f key_phase=false [2025-04-30T10:32:46.602436743Z TRACE quiche] 3497fdbbb7aa20e64922e8d08f87dc43c3ced6f3 rx pkt Short dcid=9c2add29f2aea53a61a24b2759241e02921db31f key_phase=false len=25 pn=1 [2025-04-30T10:32:46.602445529Z TRACE quiche] 3497fdbbb7aa20e64922e8d08f87dc43c3ced6f3 path ID 0 now see SCID with seq num 1 [2025-04-30T10:32:46.602452552Z TRACE quiche] 3497fdbbb7aa20e64922e8d08f87dc43c3ced6f3 rx frm ACK delay=25 blocks=[2..2] ecn_counts=None [2025-04-30T10:32:46.602461338Z TRACE quiche::recovery::congestion::recovery] 3497fdbbb7aa20e64922e8d08f87dc43c3ced6f3 packet newly acked 2 [2025-04-30T10:32:46.602471828Z TRACE quiche] 3497fdbbb7aa20e64922e8d08f87dc43c3ced6f3 rx frm RETIRE_CONNECTION_ID seq_num=0 [2025-04-30T10:32:46.602518435Z TRACE quiche_server] 3497fdbbb7aa20e64922e8d08f87dc43c3ced6f3 processed 46 bytes [2025-04-30T10:32:46.602523224Z INFO quiche_server] Retiring source CID 3497fdbbb7aa20e64922e8d08f87dc43c3ced6f3 [2025-04-30T10:32:46.602531629Z TRACE quiche_server] recv() would block [2025-04-30T10:32:46.602534425Z TRACE quiche_server] dafab94ef8f0913ec3999204595b758552438294 done writing [2025-04-30T10:32:46.602543431Z TRACE quiche] 3497fdbbb7aa20e64922e8d08f87dc43c3ced6f3 pmtud probe status false hs_con=true hs_sent=true cwnd_avail=3869 out_len=1350 left=1327 [2025-04-30T10:32:46.602552899Z TRACE quiche] 3497fdbbb7aa20e64922e8d08f87dc43c3ced6f3 tx pkt Short dcid= key_phase=false len=45 pn=11 [2025-04-30T10:32:46.602557558Z TRACE quiche] 3497fdbbb7aa20e64922e8d08f87dc43c3ced6f3 tx frm ACK delay=13 blocks=[1..1] ecn_counts=None [2025-04-30T10:32:46.602562878Z TRACE quiche] 3497fdbbb7aa20e64922e8d08f87dc43c3ced6f3 tx frm NEW_CONNECTION_ID seq_num=4 retire_prior_to=1 conn_id=[6c, 82, da, 2e, d2, 33, 84, 42, a1, 16, f7, f2, a8, 34, d0, 2f, 49, 71, 29, 34] reset_token=[9f, 8b, 18, 66, 2e, ef, 68, 74, 76, 43, ee, ea, ac, 1e, 26, f2] [2025-04-30T10:32:46.602579930Z TRACE quiche::recovery::congestion::recovery] 3497fdbbb7aa20e64922e8d08f87dc43c3ced6f3 timer=109.649641ms latest_rtt=32.231482ms srtt=33.039043ms min_rtt=32.231482ms rttvar=12.663635ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=9694 app_limited=true congestion_recovery_start_time=None Rate { delivered: 1502, delivered_time: Instant { tv_sec: 344, tv_nsec: 81488332 }, first_sent_time: Instant { tv_sec: 344, tv_nsec: 49256850 }, end_of_app_limited: 3, last_sent_packet: 11, largest_acked: 2, rate_sample: RateSample { delivery_rate: 41884, is_app_limited: true, interval: 32.231482ms, delivered: 1350, prior_delivered: 152, prior_time: Some(Instant { tv_sec: 344, tv_nsec: 49256850 }), send_elapsed: 0ns, ack_elapsed: 32.231482ms, rtt: 32.231482ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 510759, last_update: Instant { tv_sec: 344, tv_nsec: 81591434 }, next_time: Instant { tv_sec: 344, tv_nsec: 81591434 }, max_datagram_size: 1350, last_packet_size: Some(0), iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } [2025-04-30T10:32:46.602633860Z TRACE quiche_server] 3497fdbbb7aa20e64922e8d08f87dc43c3ced6f3 written 63 bytes with Some(SendInfo { from: [::]:443, to: [::ffff:193.167.0.100]:58948, at: Instant { tv_sec: 344, tv_nsec: 81591434 } }) [2025-04-30T10:32:46.602649259Z TRACE quiche_server] Collecting garbage [2025-04-30T10:32:46.602653086Z TRACE quiche_server] Collecting garbage [2025-04-30T10:32:46.602659147Z TRACE quiche_server] recv() would block [2025-04-30T10:32:46.602663025Z TRACE quiche_server] dafab94ef8f0913ec3999204595b758552438294 done writing [2025-04-30T10:32:46.602667353Z TRACE quiche_server] 3497fdbbb7aa20e64922e8d08f87dc43c3ced6f3 done writing [2025-04-30T10:32:46.602671060Z TRACE quiche_server] Collecting garbage [2025-04-30T10:32:46.602674055Z TRACE quiche_server] Collecting garbage [2025-04-30T10:32:46.604277615Z TRACE quiche_server] got 44 bytes from [::ffff:193.167.0.100]:58948 to [::]:443 [2025-04-30T10:32:46.604288295Z TRACE quiche_server] got packet Short dcid=9c2add29f2aea53a61a24b2759241e02921db31f key_phase=false [2025-04-30T10:32:46.604294526Z TRACE quiche] 3497fdbbb7aa20e64922e8d08f87dc43c3ced6f3 rx pkt Short dcid=9c2add29f2aea53a61a24b2759241e02921db31f key_phase=false len=23 pn=2 [2025-04-30T10:32:46.604300607Z TRACE quiche] 3497fdbbb7aa20e64922e8d08f87dc43c3ced6f3 rx frm ACK delay=4 blocks=[2..4] ecn_counts=None [2025-04-30T10:32:46.604304305Z TRACE quiche::recovery::congestion::recovery] 3497fdbbb7aa20e64922e8d08f87dc43c3ced6f3 packet newly acked 3 [2025-04-30T10:32:46.604306939Z TRACE quiche::recovery::congestion::recovery] 3497fdbbb7aa20e64922e8d08f87dc43c3ced6f3 packet newly acked 4 [2025-04-30T10:32:46.604318160Z TRACE quiche_server] 3497fdbbb7aa20e64922e8d08f87dc43c3ced6f3 processed 44 bytes [2025-04-30T10:32:46.604322408Z TRACE quiche_server] recv() would block [2025-04-30T10:32:46.604324732Z TRACE quiche_server] dafab94ef8f0913ec3999204595b758552438294 done writing [2025-04-30T10:32:46.604327498Z TRACE quiche_server] 3497fdbbb7aa20e64922e8d08f87dc43c3ced6f3 done writing [2025-04-30T10:32:46.604329692Z TRACE quiche_server] Collecting garbage [2025-04-30T10:32:46.604331776Z TRACE quiche_server] Collecting garbage [2025-04-30T10:32:46.606481964Z TRACE quiche_server] got 44 bytes from [::ffff:193.167.0.100]:58948 to [::]:443 [2025-04-30T10:32:46.606492874Z TRACE quiche_server] got packet Short dcid=9c2add29f2aea53a61a24b2759241e02921db31f key_phase=false [2025-04-30T10:32:46.606498845Z TRACE quiche] 3497fdbbb7aa20e64922e8d08f87dc43c3ced6f3 rx pkt Short dcid=9c2add29f2aea53a61a24b2759241e02921db31f key_phase=false len=23 pn=3 [2025-04-30T10:32:46.606504756Z TRACE quiche] 3497fdbbb7aa20e64922e8d08f87dc43c3ced6f3 rx frm ACK delay=5 blocks=[2..6] ecn_counts=None [2025-04-30T10:32:46.606508383Z TRACE quiche::recovery::congestion::recovery] 3497fdbbb7aa20e64922e8d08f87dc43c3ced6f3 packet newly acked 5 [2025-04-30T10:32:46.606510858Z TRACE quiche::recovery::congestion::recovery] 3497fdbbb7aa20e64922e8d08f87dc43c3ced6f3 packet newly acked 6 [2025-04-30T10:32:46.606522689Z TRACE quiche_server] 3497fdbbb7aa20e64922e8d08f87dc43c3ced6f3 processed 44 bytes [2025-04-30T10:32:46.606526968Z TRACE quiche_server] recv() would block [2025-04-30T10:32:46.606529332Z TRACE quiche_server] dafab94ef8f0913ec3999204595b758552438294 done writing [2025-04-30T10:32:46.606532247Z TRACE quiche_server] 3497fdbbb7aa20e64922e8d08f87dc43c3ced6f3 done writing [2025-04-30T10:32:46.606534471Z TRACE quiche_server] Collecting garbage [2025-04-30T10:32:46.606536515Z TRACE quiche_server] Collecting garbage [2025-04-30T10:32:46.608705509Z TRACE quiche_server] got 44 bytes from [::ffff:193.167.0.100]:58948 to [::]:443 [2025-04-30T10:32:46.608729945Z TRACE quiche_server] got packet Short dcid=9c2add29f2aea53a61a24b2759241e02921db31f key_phase=false [2025-04-30T10:32:46.608736196Z TRACE quiche] 3497fdbbb7aa20e64922e8d08f87dc43c3ced6f3 rx pkt Short dcid=9c2add29f2aea53a61a24b2759241e02921db31f key_phase=false len=23 pn=4 [2025-04-30T10:32:46.608741967Z TRACE quiche] 3497fdbbb7aa20e64922e8d08f87dc43c3ced6f3 rx frm ACK delay=6 blocks=[2..8] ecn_counts=None [2025-04-30T10:32:46.608745744Z TRACE quiche::recovery::congestion::recovery] 3497fdbbb7aa20e64922e8d08f87dc43c3ced6f3 packet newly acked 7 [2025-04-30T10:32:46.608756234Z TRACE quiche::recovery::congestion::recovery] 3497fdbbb7aa20e64922e8d08f87dc43c3ced6f3 packet newly acked 8 [2025-04-30T10:32:46.608772935Z TRACE quiche_server] 3497fdbbb7aa20e64922e8d08f87dc43c3ced6f3 processed 44 bytes [2025-04-30T10:32:46.608780249Z TRACE quiche_server] recv() would block [2025-04-30T10:32:46.608782934Z TRACE quiche_server] dafab94ef8f0913ec3999204595b758552438294 done writing [2025-04-30T10:32:46.608785859Z TRACE quiche_server] 3497fdbbb7aa20e64922e8d08f87dc43c3ced6f3 done writing [2025-04-30T10:32:46.608788113Z TRACE quiche_server] Collecting garbage [2025-04-30T10:32:46.608790167Z TRACE quiche_server] Collecting garbage [2025-04-30T10:32:46.609965047Z TRACE quiche_server] got 44 bytes from [::ffff:193.167.0.100]:58948 to [::]:443 [2025-04-30T10:32:46.609977240Z TRACE quiche_server] got packet Short dcid=9c2add29f2aea53a61a24b2759241e02921db31f key_phase=false [2025-04-30T10:32:46.609985476Z TRACE quiche] 3497fdbbb7aa20e64922e8d08f87dc43c3ced6f3 rx pkt Short dcid=9c2add29f2aea53a61a24b2759241e02921db31f key_phase=false len=23 pn=5 [2025-04-30T10:32:46.609993360Z TRACE quiche] 3497fdbbb7aa20e64922e8d08f87dc43c3ced6f3 rx frm ACK delay=5 blocks=[2..10] ecn_counts=None [2025-04-30T10:32:46.609998199Z TRACE quiche::recovery::congestion::recovery] 3497fdbbb7aa20e64922e8d08f87dc43c3ced6f3 packet newly acked 9 [2025-04-30T10:32:46.610000944Z TRACE quiche::recovery::congestion::recovery] 3497fdbbb7aa20e64922e8d08f87dc43c3ced6f3 packet newly acked 10 [2025-04-30T10:32:46.610013738Z TRACE quiche_server] 3497fdbbb7aa20e64922e8d08f87dc43c3ced6f3 processed 44 bytes [2025-04-30T10:32:46.610019559Z TRACE quiche_server] got 42 bytes from [::ffff:193.167.0.100]:58948 to [::]:443 [2025-04-30T10:32:46.610022534Z TRACE quiche_server] got packet Short dcid=9c2add29f2aea53a61a24b2759241e02921db31f key_phase=false [2025-04-30T10:32:46.610026171Z TRACE quiche] 3497fdbbb7aa20e64922e8d08f87dc43c3ced6f3 rx pkt Short dcid=9c2add29f2aea53a61a24b2759241e02921db31f key_phase=false len=21 pn=6 [2025-04-30T10:32:46.610030449Z TRACE quiche] 3497fdbbb7aa20e64922e8d08f87dc43c3ced6f3 rx frm APPLICATION_CLOSE err=0 reason=[] [2025-04-30T10:32:46.610036030Z TRACE quiche_server] 3497fdbbb7aa20e64922e8d08f87dc43c3ced6f3 processed 42 bytes [2025-04-30T10:32:46.610039446Z TRACE quiche_server] recv() would block [2025-04-30T10:32:46.610041770Z TRACE quiche_server] dafab94ef8f0913ec3999204595b758552438294 done writing [2025-04-30T10:32:46.610043954Z TRACE quiche_server] 3497fdbbb7aa20e64922e8d08f87dc43c3ced6f3 done writing [2025-04-30T10:32:46.610046069Z TRACE quiche_server] Collecting garbage [2025-04-30T10:32:46.610048122Z TRACE quiche_server] Collecting garbage [2025-04-30T10:32:46.711178427Z TRACE quiche_server] timed out [2025-04-30T10:32:46.711210166Z TRACE quiche] dafab94ef8f0913ec3999204595b758552438294 draining timeout expired [2025-04-30T10:32:46.711254699Z TRACE quiche_server] dafab94ef8f0913ec3999204595b758552438294 done writing [2025-04-30T10:32:46.711259989Z TRACE quiche_server] 3497fdbbb7aa20e64922e8d08f87dc43c3ced6f3 done writing [2025-04-30T10:32:46.711264668Z TRACE quiche_server] Collecting garbage [2025-04-30T10:32:46.711270068Z INFO quiche_server] dafab94ef8f0913ec3999204595b758552438294 connection collected recv=8 sent=8 lost=0 retrans=0 sent_bytes=6719 recv_bytes=2799 lost_bytes=0 [local_addr=[::]:443 peer_addr=[::ffff:193.167.0.100]:38465 validation_state=Validated active=true recv=8 sent=8 lost=0 retrans=0 rtt=33.136867ms min_rtt=Some(30.888057ms) rttvar=6.352608ms cwnd=13500 sent_bytes=6719 recv_bytes=2799 lost_bytes=0 stream_retrans_bytes=0 pmtu=1350 delivery_rate=158625] [2025-04-30T10:32:46.711305594Z TRACE quiche_server] Collecting garbage [2025-04-30T10:32:46.797415995Z TRACE quiche_server] timed out [2025-04-30T10:32:46.797436794Z TRACE quiche] 3497fdbbb7aa20e64922e8d08f87dc43c3ced6f3 draining timeout expired [2025-04-30T10:32:46.797469595Z TRACE quiche_server] 3497fdbbb7aa20e64922e8d08f87dc43c3ced6f3 done writing [2025-04-30T10:32:46.797477360Z TRACE quiche_server] Collecting garbage [2025-04-30T10:32:46.797480686Z INFO quiche_server] 3497fdbbb7aa20e64922e8d08f87dc43c3ced6f3 connection collected recv=10 sent=12 lost=0 retrans=0 sent_bytes=11399 recv_bytes=2882 lost_bytes=0 [local_addr=[::]:443 peer_addr=[::ffff:193.167.0.100]:58948 validation_state=Validated active=true recv=10 sent=12 lost=0 retrans=0 rtt=34.865879ms min_rtt=Some(32.231482ms) rttvar=6.866926ms cwnd=13500 sent_bytes=11399 recv_bytes=2882 lost_bytes=0 stream_retrans_bytes=0 pmtu=1350 delivery_rate=340691]