[2025-04-30T09:47:47.323742160Z INFO quiche_server] listening on [::]:443 [2025-04-30T09:47:47.323764842Z TRACE mio::poll] registering event source with poller: token=Token(0), interests=READABLE [2025-04-30T09:47:47.323771715Z TRACE quiche_server] GSO detected: false [2025-04-30T09:47:48.148261554Z TRACE quiche_server] got 1207 bytes from [::ffff:193.167.100.2]:60774 to [::]:443 [2025-04-30T09:47:48.148290879Z TRACE quiche_server] got packet Initial version=57414954 dcid= scid= token= [2025-04-30T09:47:48.148298433Z WARN quiche_server] Doing version negotiation [2025-04-30T09:47:48.148393039Z TRACE quiche_server] got 1207 bytes from [::ffff:193.167.100.2]:60774 to [::]:443 [2025-04-30T09:47:48.148399041Z TRACE quiche_server] got packet Initial version=57414954 dcid= scid= token= [2025-04-30T09:47:48.148402958Z WARN quiche_server] Doing version negotiation [2025-04-30T09:47:48.148423817Z TRACE quiche_server] got 1207 bytes from [::ffff:193.167.100.2]:60774 to [::]:443 [2025-04-30T09:47:48.148430720Z TRACE quiche_server] got packet Initial version=57414954 dcid= scid= token= [2025-04-30T09:47:48.148436951Z WARN quiche_server] Doing version negotiation [2025-04-30T09:47:48.148465975Z TRACE quiche_server] recv() would block [2025-04-30T09:47:48.368221827Z TRACE quiche_server] got 1252 bytes from [::ffff:193.167.0.100]:39383 to [::]:443 [2025-04-30T09:47:48.368245612Z TRACE quiche_server] got packet Initial version=1 dcid=8648360ae1a1a35b scid=c25cdfd2ba4af143 token= [2025-04-30T09:47:48.368254668Z DEBUG quiche_server] New connection: dcid=8648360ae1a1a35b scid=0f6c0885e55d44d1844a94507a3de7784507e2a3 [2025-04-30T09:47:48.368452197Z TRACE quiche] 0f6c0885e55d44d1844a94507a3de7784507e2a3 rx pkt Initial version=1 dcid=8648360ae1a1a35b scid=c25cdfd2ba4af143 token= len=1226 pn=114861 [2025-04-30T09:47:48.368466172Z TRACE quiche] 0f6c0885e55d44d1844a94507a3de7784507e2a3 rx frm PING mtu_probe=None [2025-04-30T09:47:48.368470360Z TRACE quiche] 0f6c0885e55d44d1844a94507a3de7784507e2a3 rx frm CRYPTO off=0 len=285 [2025-04-30T09:47:48.368496749Z TRACE quiche::tls] checking peer ALPN Ok("hq-interop") against Ok("h3") [2025-04-30T09:47:48.368501308Z TRACE quiche::tls] checking peer ALPN Ok("hq-interop") against Ok("hq-interop") [2025-04-30T09:47:48.368614379Z TRACE quiche::tls] 0f6c0885e55d44d1844a94507a3de7784507e2a3 write message lvl=Initial len=123 [2025-04-30T09:47:48.368644435Z TRACE quiche::tls] 0f6c0885e55d44d1844a94507a3de7784507e2a3 set write secret lvl=Handshake [2025-04-30T09:47:48.368711870Z TRACE quiche::tls] 0f6c0885e55d44d1844a94507a3de7784507e2a3 write message lvl=Handshake len=696 [2025-04-30T09:47:48.368715397Z TRACE quiche::tls] 0f6c0885e55d44d1844a94507a3de7784507e2a3 set write secret lvl=OneRTT [2025-04-30T09:47:48.368723182Z TRACE quiche::tls] 0f6c0885e55d44d1844a94507a3de7784507e2a3 set read secret lvl=Handshake [2025-04-30T09:47:48.368743930Z TRACE quiche] 0f6c0885e55d44d1844a94507a3de7784507e2a3 rx frm PADDING len=916 [2025-04-30T09:47:48.368765651Z TRACE quiche_server] 0f6c0885e55d44d1844a94507a3de7784507e2a3 processed 1252 bytes [2025-04-30T09:47:48.368786389Z TRACE quiche_server] recv() would block [2025-04-30T09:47:48.368800466Z TRACE quiche] 0f6c0885e55d44d1844a94507a3de7784507e2a3 tx pkt Initial version=1 dcid=c25cdfd2ba4af143 scid=0f6c0885e55d44d1844a94507a3de7784507e2a3 len=135 pn=0 [2025-04-30T09:47:48.368804473Z TRACE quiche] 0f6c0885e55d44d1844a94507a3de7784507e2a3 tx frm ACK delay=45 blocks=[114861..114861] ecn_counts=None [2025-04-30T09:47:48.368810214Z TRACE quiche] 0f6c0885e55d44d1844a94507a3de7784507e2a3 tx frm CRYPTO off=0 len=123 [2025-04-30T09:47:48.368818730Z TRACE quiche::recovery::congestion::recovery] 0f6c0885e55d44d1844a94507a3de7784507e2a3 timer=998.969824ms latest_rtt=0ns srtt=333ms min_rtt=333ms rttvar=166.5ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=190 app_limited=true congestion_recovery_start_time=None Rate { delivered: 0, delivered_time: Instant { tv_sec: 298, tv_nsec: 155727734 }, first_sent_time: Instant { tv_sec: 298, tv_nsec: 155727734 }, 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: 298, tv_nsec: 155727734 }, next_time: Instant { tv_sec: 298, tv_nsec: 155727734 }, max_datagram_size: 1350, last_packet_size: None, iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } [2025-04-30T09:47:48.368846421Z TRACE quiche] 0f6c0885e55d44d1844a94507a3de7784507e2a3 tx pkt Handshake version=1 dcid=c25cdfd2ba4af143 scid=0f6c0885e55d44d1844a94507a3de7784507e2a3 len=700 pn=1 [2025-04-30T09:47:48.368849347Z TRACE quiche] 0f6c0885e55d44d1844a94507a3de7784507e2a3 tx frm CRYPTO off=0 len=696 [2025-04-30T09:47:48.368855068Z TRACE quiche::recovery::congestion::recovery] 0f6c0885e55d44d1844a94507a3de7784507e2a3 timer=998.933877ms latest_rtt=0ns srtt=333ms min_rtt=333ms rttvar=166.5ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=944 app_limited=true congestion_recovery_start_time=None Rate { delivered: 0, delivered_time: Instant { tv_sec: 298, tv_nsec: 155727734 }, first_sent_time: Instant { tv_sec: 298, tv_nsec: 155727734 }, 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: 298, tv_nsec: 155727734 }, next_time: Instant { tv_sec: 298, tv_nsec: 155727734 }, max_datagram_size: 1350, last_packet_size: None, iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } [2025-04-30T09:47:48.368900823Z TRACE quiche_server] 0f6c0885e55d44d1844a94507a3de7784507e2a3 written 1200 bytes with Some(SendInfo { from: [::]:443, to: [::ffff:193.167.0.100]:39383, at: Instant { tv_sec: 298, tv_nsec: 155727734 } }) [2025-04-30T09:47:48.368909118Z TRACE quiche_server] Collecting garbage [2025-04-30T09:47:48.368916061Z TRACE quiche_server] recv() would block [2025-04-30T09:47:48.368921551Z TRACE quiche_server] 0f6c0885e55d44d1844a94507a3de7784507e2a3 done writing [2025-04-30T09:47:48.368925258Z TRACE quiche_server] Collecting garbage [2025-04-30T09:47:48.401038186Z TRACE quiche_server] got 412 bytes from [::ffff:193.167.0.100]:39383 to [::]:443 [2025-04-30T09:47:48.401053595Z TRACE quiche_server] got packet Handshake version=1 dcid=0f6c0885e55d44d1844a94507a3de7784507e2a3 scid=c25cdfd2ba4af143 [2025-04-30T09:47:48.401078772Z TRACE quiche] 0f6c0885e55d44d1844a94507a3de7784507e2a3 rx pkt Handshake version=1 dcid=0f6c0885e55d44d1844a94507a3de7784507e2a3 scid=c25cdfd2ba4af143 len=64 pn=0 [2025-04-30T09:47:48.401089111Z TRACE quiche] 0f6c0885e55d44d1844a94507a3de7784507e2a3 rx frm ACK delay=41 blocks=[1..1] ecn_counts=None [2025-04-30T09:47:48.401094651Z TRACE quiche::recovery::congestion::recovery] 0f6c0885e55d44d1844a94507a3de7784507e2a3 packet newly acked 1 [2025-04-30T09:47:48.401100101Z TRACE quiche] 0f6c0885e55d44d1844a94507a3de7784507e2a3 rx frm CRYPTO off=0 len=36 [2025-04-30T09:47:48.401112104Z TRACE quiche::tls] 0f6c0885e55d44d1844a94507a3de7784507e2a3 set read secret lvl=OneRTT [2025-04-30T09:47:48.401141128Z TRACE quiche::tls] 0f6c0885e55d44d1844a94507a3de7784507e2a3 write message lvl=OneRTT len=396 [2025-04-30T09:47:48.401149223Z TRACE quiche] 0f6c0885e55d44d1844a94507a3de7784507e2a3 dropped epoch 1 state [2025-04-30T09:47:48.401152629Z TRACE quiche] 0f6c0885e55d44d1844a94507a3de7784507e2a3 connection established: proto=Ok("hq-interop") cipher=Some(AES128_GCM) curve=Some("P-256") sigalg=None resumed=false TransportParams { original_destination_connection_id: None, max_idle_timeout: 180000, stateless_reset_token: None, max_udp_payload_size: 1440, initial_max_data: 1048576, initial_max_stream_data_bidi_local: 2097152, initial_max_stream_data_bidi_remote: 65635, initial_max_stream_data_uni: 65535, initial_max_streams_bidi: 512, initial_max_streams_uni: 512, ack_delay_exponent: 3, max_ack_delay: 10, disable_active_migration: false, active_conn_id_limit: 8, initial_source_connection_id: Some(c25cdfd2ba4af143), retry_source_connection_id: None, max_datagram_frame_size: None, unknown_params: None } [2025-04-30T09:47:48.401184248Z TRACE quiche] 0f6c0885e55d44d1844a94507a3de7784507e2a3 dropped epoch 0 state [2025-04-30T09:47:48.401187865Z TRACE quiche] 0f6c0885e55d44d1844a94507a3de7784507e2a3 rx pkt Short dcid=0f6c0885e55d44d1844a94507a3de7784507e2a3 key_phase=false len=290 pn=0 [2025-04-30T09:47:48.401194096Z TRACE quiche] 0f6c0885e55d44d1844a94507a3de7784507e2a3 rx frm NEW_CONNECTION_ID seq_num=1 retire_prior_to=0 conn_id=[e4, c9, 78, 14, 74, 8b, 68, ad] reset_token=[a8, a2, f7, 29, 71, 3a, e0, 52, 2f, 2f, 86, cd, 34, 2b, 09, d4] [2025-04-30T09:47:48.401200799Z TRACE quiche] 0f6c0885e55d44d1844a94507a3de7784507e2a3 rx frm NEW_CONNECTION_ID seq_num=2 retire_prior_to=0 conn_id=[04, 78, e6, 5b, a9, a1, b7, 55] reset_token=[85, e3, 6f, 72, 42, f5, af, 61, 08, 26, b1, ab, a6, 41, a0, 21] [2025-04-30T09:47:48.401205608Z TRACE quiche] 0f6c0885e55d44d1844a94507a3de7784507e2a3 rx frm NEW_CONNECTION_ID seq_num=3 retire_prior_to=0 conn_id=[cf, a2, 41, f7, 40, 22, 93, 2d] reset_token=[ca, 10, 85, 02, 62, 76, 86, 48, cc, 75, 46, 0d, 76, 65, 35, 43] [2025-04-30T09:47:48.401210106Z TRACE quiche] 0f6c0885e55d44d1844a94507a3de7784507e2a3 rx frm NEW_CONNECTION_ID seq_num=4 retire_prior_to=0 conn_id=[9e, 26, 31, 27, a7, 69, fe, 67] reset_token=[d0, 7e, 5e, 37, 3f, 41, 39, 30, e0, 97, 44, 5a, 45, d4, 96, 3b] [2025-04-30T09:47:48.401215126Z TRACE quiche] 0f6c0885e55d44d1844a94507a3de7784507e2a3 rx frm NEW_CONNECTION_ID seq_num=5 retire_prior_to=0 conn_id=[22, 6f, 85, 7c, b3, 5a, d0, 76] reset_token=[5b, 10, 14, 3f, 57, b6, 21, 32, 9a, 91, aa, 44, 6a, 80, 65, 40] [2025-04-30T09:47:48.401219864Z TRACE quiche] 0f6c0885e55d44d1844a94507a3de7784507e2a3 rx frm NEW_CONNECTION_ID seq_num=6 retire_prior_to=0 conn_id=[63, ca, 67, 61, d0, 87, 03, e5] reset_token=[af, 13, 8c, e8, 1c, 5c, 0a, f5, bb, 4f, 34, 33, 25, 01, 96, 85] [2025-04-30T09:47:48.401224533Z TRACE quiche] 0f6c0885e55d44d1844a94507a3de7784507e2a3 rx frm NEW_CONNECTION_ID seq_num=7 retire_prior_to=0 conn_id=[ea, d3, 26, 5a, 6c, 3a, d8, 83] reset_token=[5e, 2e, 8f, b6, 8e, f5, a8, aa, e4, 50, d6, b0, f4, cd, 88, 03] [2025-04-30T09:47:48.401228721Z TRACE quiche] 0f6c0885e55d44d1844a94507a3de7784507e2a3 rx frm PADDING len=77 [2025-04-30T09:47:48.401237087Z TRACE quiche_server] 0f6c0885e55d44d1844a94507a3de7784507e2a3 processed 412 bytes [2025-04-30T09:47:48.401244801Z TRACE quiche_server] got 183 bytes from [::ffff:193.167.0.100]:39383 to [::]:443 [2025-04-30T09:47:48.401248127Z TRACE quiche_server] got packet Short dcid=0f6c0885e55d44d1844a94507a3de7784507e2a3 key_phase=false [2025-04-30T09:47:48.401252315Z TRACE quiche] 0f6c0885e55d44d1844a94507a3de7784507e2a3 rx pkt Short dcid=0f6c0885e55d44d1844a94507a3de7784507e2a3 key_phase=false len=162 pn=1 [2025-04-30T09:47:48.401256513Z TRACE quiche] 0f6c0885e55d44d1844a94507a3de7784507e2a3 rx frm STREAM id=0 off=0 len=17 fin=true [2025-04-30T09:47:48.401261262Z TRACE quiche] 0f6c0885e55d44d1844a94507a3de7784507e2a3 rx frm PADDING len=125 [2025-04-30T09:47:48.401265660Z TRACE quiche_server] 0f6c0885e55d44d1844a94507a3de7784507e2a3 processed 183 bytes [2025-04-30T09:47:48.401268425Z DEBUG quiche_apps::common] 0f6c0885e55d44d1844a94507a3de7784507e2a3 response stream 0 is writable with capacity Ok(13500) [2025-04-30T09:47:48.401274827Z TRACE quiche_apps::common] 0f6c0885e55d44d1844a94507a3de7784507e2a3 received 17 bytes [2025-04-30T09:47:48.401281049Z TRACE quiche_apps::common] 0f6c0885e55d44d1844a94507a3de7784507e2a3 stream 0 has 17 bytes (fin? true) [2025-04-30T09:47:48.401285166Z INFO quiche_apps::common] 0f6c0885e55d44d1844a94507a3de7784507e2a3 got GET request for "/www/aeqgajnmwl" on stream 0 [2025-04-30T09:47:48.401309792Z INFO quiche_apps::common] 0f6c0885e55d44d1844a94507a3de7784507e2a3 sending response of size 5120 on stream 0 [2025-04-30T09:47:48.401316795Z TRACE quiche_server] recv() would block [2025-04-30T09:47:48.401323488Z TRACE quiche] 0f6c0885e55d44d1844a94507a3de7784507e2a3 pmtud probe status false hs_con=true hs_sent=false cwnd_avail=13500 out_len=1350 left=1319 [2025-04-30T09:47:48.401331412Z TRACE quiche] 0f6c0885e55d44d1844a94507a3de7784507e2a3 tx pkt Short dcid=c25cdfd2ba4af143 key_phase=false len=1324 pn=2 [2025-04-30T09:47:48.401334228Z TRACE quiche] 0f6c0885e55d44d1844a94507a3de7784507e2a3 tx frm ACK delay=8 blocks=[0..1] ecn_counts=None [2025-04-30T09:47:48.401337363Z TRACE quiche] 0f6c0885e55d44d1844a94507a3de7784507e2a3 tx frm NEW_CONNECTION_ID seq_num=1 retire_prior_to=0 conn_id=[3c, 5d, d5, af, 2a, f7, b7, d1, 8a, 2e, 5d, 95, 01, 5e, a6, e7, 6d, 86, c2, 96] reset_token=[a5, 16, b2, 44, 3b, 0a, 51, 7f, ff, b5, 2b, ea, cc, 6b, 57, 10] [2025-04-30T09:47:48.401343385Z TRACE quiche] 0f6c0885e55d44d1844a94507a3de7784507e2a3 tx frm NEW_CONNECTION_ID seq_num=2 retire_prior_to=0 conn_id=[24, 3f, c4, ee, 67, 6e, a2, 10, c2, b8, 82, 72, 2e, 9d, b6, 8c, 76, fd, b8, 4a] reset_token=[58, 9d, 11, 46, 1c, 4a, bc, 8e, 1a, 25, c5, d9, fe, b7, eb, 4f] [2025-04-30T09:47:48.401348765Z TRACE quiche] 0f6c0885e55d44d1844a94507a3de7784507e2a3 tx frm NEW_CONNECTION_ID seq_num=3 retire_prior_to=0 conn_id=[32, 5d, 1f, 26, 73, 30, 59, 10, ad, a1, 81, 05, f6, 02, ca, 9a, b5, 4b, b3, e9] reset_token=[dc, fe, 87, 10, 60, d0, ba, f9, 80, 3f, 82, 53, c6, a5, f6, 76] [2025-04-30T09:47:48.401354075Z TRACE quiche] 0f6c0885e55d44d1844a94507a3de7784507e2a3 tx frm NEW_CONNECTION_ID seq_num=4 retire_prior_to=0 conn_id=[da, 87, a6, 45, af, f8, 0e, 64, 91, 5b, a6, bf, 5e, 03, bf, f7, 97, 72, e1, 0c] reset_token=[03, df, 97, c6, 01, 45, b9, c1, 34, c7, 3e, 95, ad, 96, 3d, 38] [2025-04-30T09:47:48.401359525Z TRACE quiche] 0f6c0885e55d44d1844a94507a3de7784507e2a3 tx frm NEW_CONNECTION_ID seq_num=5 retire_prior_to=0 conn_id=[18, 62, 00, ee, a6, 71, 87, 50, fc, d2, ce, 13, 37, 4c, 75, 5a, 4e, 5a, 06, 77] reset_token=[59, 08, 0f, 7c, 16, e4, 56, b8, 43, ab, c7, 65, 55, 25, 57, 52] [2025-04-30T09:47:48.401364895Z TRACE quiche] 0f6c0885e55d44d1844a94507a3de7784507e2a3 tx frm NEW_CONNECTION_ID seq_num=6 retire_prior_to=0 conn_id=[5a, 7e, 55, 12, f0, 57, 86, f7, 77, 0a, ba, 40, d5, ff, dd, 62, 7a, 51, 7d, b1] reset_token=[23, 63, 9e, 0f, 2f, fb, cf, f2, d3, 98, 15, f8, ef, 70, 41, de] [2025-04-30T09:47:48.401370195Z TRACE quiche] 0f6c0885e55d44d1844a94507a3de7784507e2a3 tx frm NEW_CONNECTION_ID seq_num=7 retire_prior_to=0 conn_id=[16, 86, c1, e4, 0e, 79, 74, d3, c5, a1, 4a, 3b, e5, 6e, 28, aa, a5, 50, 96, a9] reset_token=[53, 21, d7, c3, e8, f1, ff, 92, b8, bf, 95, 22, 23, 7d, fb, bb] [2025-04-30T09:47:48.401375374Z TRACE quiche] 0f6c0885e55d44d1844a94507a3de7784507e2a3 tx frm HANDSHAKE_DONE [2025-04-30T09:47:48.401377659Z TRACE quiche] 0f6c0885e55d44d1844a94507a3de7784507e2a3 tx frm CRYPTO off=0 len=396 [2025-04-30T09:47:48.401380013Z TRACE quiche] 0f6c0885e55d44d1844a94507a3de7784507e2a3 tx frm STREAM id=0 off=0 len=633 fin=false [2025-04-30T09:47:48.401391795Z TRACE quiche::recovery::congestion::recovery] 0f6c0885e55d44d1844a94507a3de7784507e2a3 timer=106.742146ms latest_rtt=32.271744ms srtt=32.271744ms min_rtt=32.271744ms rttvar=16.135872ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=1350 app_limited=true congestion_recovery_start_time=None Rate { delivered: 754, delivered_time: Instant { tv_sec: 298, tv_nsec: 188257639 }, first_sent_time: Instant { tv_sec: 298, tv_nsec: 188257639 }, end_of_app_limited: 1, last_sent_packet: 2, largest_acked: 1, rate_sample: RateSample { delivery_rate: 23364, is_app_limited: true, interval: 32.271744ms, delivered: 754, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 298, tv_nsec: 155727734 }), send_elapsed: 0ns, ack_elapsed: 32.271744ms, rtt: 32.271744ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 522903, last_update: Instant { tv_sec: 298, tv_nsec: 188257639 }, next_time: Instant { tv_sec: 298, tv_nsec: 188257639 }, max_datagram_size: 1350, last_packet_size: Some(0), iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } [2025-04-30T09:47:48.401410660Z TRACE quiche] 0f6c0885e55d44d1844a94507a3de7784507e2a3 pmtud probe status false hs_con=true hs_sent=true cwnd_avail=12150 out_len=1350 left=1324 [2025-04-30T09:47:48.401414247Z TRACE quiche] 0f6c0885e55d44d1844a94507a3de7784507e2a3 tx pkt Short dcid=c25cdfd2ba4af143 key_phase=false len=1324 pn=3 [2025-04-30T09:47:48.401416751Z TRACE quiche] 0f6c0885e55d44d1844a94507a3de7784507e2a3 tx frm STREAM id=0 off=633 len=1318 fin=false [2025-04-30T09:47:48.401421791Z TRACE quiche::recovery::congestion::recovery] 0f6c0885e55d44d1844a94507a3de7784507e2a3 timer=106.802287ms latest_rtt=32.271744ms srtt=32.271744ms min_rtt=32.271744ms rttvar=16.135872ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=2700 app_limited=true congestion_recovery_start_time=None Rate { delivered: 754, delivered_time: Instant { tv_sec: 298, tv_nsec: 188257639 }, first_sent_time: Instant { tv_sec: 298, tv_nsec: 188257639 }, end_of_app_limited: 2, last_sent_packet: 3, largest_acked: 1, rate_sample: RateSample { delivery_rate: 23364, is_app_limited: true, interval: 32.271744ms, delivered: 754, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 298, tv_nsec: 155727734 }), send_elapsed: 0ns, ack_elapsed: 32.271744ms, rtt: 32.271744ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 522903, last_update: Instant { tv_sec: 298, tv_nsec: 188257639 }, next_time: Instant { tv_sec: 298, tv_nsec: 188257639 }, max_datagram_size: 1350, last_packet_size: Some(0), iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } [2025-04-30T09:47:48.401432140Z TRACE quiche] 0f6c0885e55d44d1844a94507a3de7784507e2a3 pmtud probe status false hs_con=true hs_sent=true cwnd_avail=10800 out_len=1350 left=1324 [2025-04-30T09:47:48.401435106Z TRACE quiche] 0f6c0885e55d44d1844a94507a3de7784507e2a3 tx pkt Short dcid=c25cdfd2ba4af143 key_phase=false len=1324 pn=4 [2025-04-30T09:47:48.401437450Z TRACE quiche] 0f6c0885e55d44d1844a94507a3de7784507e2a3 tx frm STREAM id=0 off=1951 len=1318 fin=false [2025-04-30T09:47:48.401458640Z TRACE quiche::recovery::congestion::recovery] 0f6c0885e55d44d1844a94507a3de7784507e2a3 timer=106.78733ms latest_rtt=32.271744ms srtt=32.271744ms min_rtt=32.271744ms rttvar=16.135872ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=4050 app_limited=true congestion_recovery_start_time=None Rate { delivered: 754, delivered_time: Instant { tv_sec: 298, tv_nsec: 188257639 }, first_sent_time: Instant { tv_sec: 298, tv_nsec: 188257639 }, end_of_app_limited: 3, last_sent_packet: 4, largest_acked: 1, rate_sample: RateSample { delivery_rate: 23364, is_app_limited: true, interval: 32.271744ms, delivered: 754, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 298, tv_nsec: 155727734 }), send_elapsed: 0ns, ack_elapsed: 32.271744ms, rtt: 32.271744ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 522903, last_update: Instant { tv_sec: 298, tv_nsec: 188257639 }, next_time: Instant { tv_sec: 298, tv_nsec: 188257639 }, max_datagram_size: 1350, last_packet_size: Some(0), iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } [2025-04-30T09:47:48.401472646Z TRACE quiche] 0f6c0885e55d44d1844a94507a3de7784507e2a3 pmtud probe status false hs_con=true hs_sent=true cwnd_avail=9450 out_len=1350 left=1324 [2025-04-30T09:47:48.401475862Z TRACE quiche] 0f6c0885e55d44d1844a94507a3de7784507e2a3 tx pkt Short dcid=c25cdfd2ba4af143 key_phase=false len=1324 pn=5 [2025-04-30T09:47:48.401478296Z TRACE quiche] 0f6c0885e55d44d1844a94507a3de7784507e2a3 tx frm STREAM id=0 off=3269 len=1318 fin=false [2025-04-30T09:47:48.401483035Z TRACE quiche::recovery::congestion::recovery] 0f6c0885e55d44d1844a94507a3de7784507e2a3 timer=106.80336ms latest_rtt=32.271744ms srtt=32.271744ms min_rtt=32.271744ms rttvar=16.135872ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=5400 app_limited=true congestion_recovery_start_time=None Rate { delivered: 754, delivered_time: Instant { tv_sec: 298, tv_nsec: 188257639 }, first_sent_time: Instant { tv_sec: 298, tv_nsec: 188257639 }, end_of_app_limited: 4, last_sent_packet: 5, largest_acked: 1, rate_sample: RateSample { delivery_rate: 23364, is_app_limited: true, interval: 32.271744ms, delivered: 754, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 298, tv_nsec: 155727734 }), send_elapsed: 0ns, ack_elapsed: 32.271744ms, rtt: 32.271744ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 522903, last_update: Instant { tv_sec: 298, tv_nsec: 188257639 }, next_time: Instant { tv_sec: 298, tv_nsec: 188257639 }, max_datagram_size: 1350, last_packet_size: Some(0), iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } [2025-04-30T09:47:48.401493124Z TRACE quiche] 0f6c0885e55d44d1844a94507a3de7784507e2a3 pmtud probe status false hs_con=true hs_sent=true cwnd_avail=8100 out_len=1350 left=1324 [2025-04-30T09:47:48.401496089Z TRACE quiche] 0f6c0885e55d44d1844a94507a3de7784507e2a3 tx pkt Short dcid=c25cdfd2ba4af143 key_phase=false len=539 pn=6 [2025-04-30T09:47:48.401498434Z TRACE quiche] 0f6c0885e55d44d1844a94507a3de7784507e2a3 tx frm STREAM id=0 off=4587 len=533 fin=true [2025-04-30T09:47:48.401503123Z TRACE quiche::recovery::congestion::recovery] 0f6c0885e55d44d1844a94507a3de7784507e2a3 timer=106.804121ms latest_rtt=32.271744ms srtt=32.271744ms min_rtt=32.271744ms rttvar=16.135872ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=5965 app_limited=true congestion_recovery_start_time=None Rate { delivered: 754, delivered_time: Instant { tv_sec: 298, tv_nsec: 188257639 }, first_sent_time: Instant { tv_sec: 298, tv_nsec: 188257639 }, end_of_app_limited: 5, last_sent_packet: 6, largest_acked: 1, rate_sample: RateSample { delivery_rate: 23364, is_app_limited: true, interval: 32.271744ms, delivered: 754, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 298, tv_nsec: 155727734 }), send_elapsed: 0ns, ack_elapsed: 32.271744ms, rtt: 32.271744ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 522903, last_update: Instant { tv_sec: 298, tv_nsec: 188257639 }, next_time: Instant { tv_sec: 298, tv_nsec: 188257639 }, max_datagram_size: 1350, last_packet_size: Some(0), iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } [2025-04-30T09:47:48.401587530Z TRACE quiche_server] 0f6c0885e55d44d1844a94507a3de7784507e2a3 written 5965 bytes with Some(SendInfo { from: [::]:443, to: [::ffff:193.167.0.100]:39383, at: Instant { tv_sec: 298, tv_nsec: 188257639 } }) [2025-04-30T09:47:48.401593381Z TRACE quiche_server] Collecting garbage [2025-04-30T09:47:48.401601847Z TRACE quiche_server] recv() would block [2025-04-30T09:47:48.401604782Z TRACE quiche_server] 0f6c0885e55d44d1844a94507a3de7784507e2a3 done writing [2025-04-30T09:47:48.401606996Z TRACE quiche_server] Collecting garbage [2025-04-30T09:47:48.433289749Z TRACE quiche_server] got 55 bytes from [::ffff:193.167.0.100]:39383 to [::]:443 [2025-04-30T09:47:48.433306521Z TRACE quiche_server] got packet Short dcid=0f6c0885e55d44d1844a94507a3de7784507e2a3 key_phase=false [2025-04-30T09:47:48.433315898Z TRACE quiche] 0f6c0885e55d44d1844a94507a3de7784507e2a3 rx pkt Short dcid=0f6c0885e55d44d1844a94507a3de7784507e2a3 key_phase=false len=34 pn=2 [2025-04-30T09:47:48.433324785Z TRACE quiche] 0f6c0885e55d44d1844a94507a3de7784507e2a3 rx frm ACK delay=22 blocks=[2..2] ecn_counts=None [2025-04-30T09:47:48.433330094Z TRACE quiche::recovery::congestion::recovery] 0f6c0885e55d44d1844a94507a3de7784507e2a3 packet newly acked 2 [2025-04-30T09:47:48.433336416Z TRACE quiche] 0f6c0885e55d44d1844a94507a3de7784507e2a3 rx frm PADDING len=12 [2025-04-30T09:47:48.433354259Z TRACE quiche_server] 0f6c0885e55d44d1844a94507a3de7784507e2a3 processed 55 bytes [2025-04-30T09:47:48.433360581Z TRACE quiche_server] recv() would block [2025-04-30T09:47:48.433364739Z TRACE quiche_server] 0f6c0885e55d44d1844a94507a3de7784507e2a3 done writing [2025-04-30T09:47:48.433368035Z TRACE quiche_server] Collecting garbage [2025-04-30T09:47:48.435255574Z TRACE quiche_server] got 55 bytes from [::ffff:193.167.0.100]:39383 to [::]:443 [2025-04-30T09:47:48.435267095Z TRACE quiche_server] got packet Short dcid=0f6c0885e55d44d1844a94507a3de7784507e2a3 key_phase=false [2025-04-30T09:47:48.435273657Z TRACE quiche] 0f6c0885e55d44d1844a94507a3de7784507e2a3 rx pkt Short dcid=0f6c0885e55d44d1844a94507a3de7784507e2a3 key_phase=false len=34 pn=3 [2025-04-30T09:47:48.435280139Z TRACE quiche] 0f6c0885e55d44d1844a94507a3de7784507e2a3 rx frm ACK delay=3 blocks=[2..4] ecn_counts=None [2025-04-30T09:47:48.435284297Z TRACE quiche::recovery::congestion::recovery] 0f6c0885e55d44d1844a94507a3de7784507e2a3 packet newly acked 3 [2025-04-30T09:47:48.435287303Z TRACE quiche::recovery::congestion::recovery] 0f6c0885e55d44d1844a94507a3de7784507e2a3 packet newly acked 4 [2025-04-30T09:47:48.435291380Z TRACE quiche] 0f6c0885e55d44d1844a94507a3de7784507e2a3 rx frm PADDING len=12 [2025-04-30T09:47:48.435303112Z TRACE quiche_server] 0f6c0885e55d44d1844a94507a3de7784507e2a3 processed 55 bytes [2025-04-30T09:47:48.435308172Z TRACE quiche_server] recv() would block [2025-04-30T09:47:48.435311618Z TRACE quiche_server] 0f6c0885e55d44d1844a94507a3de7784507e2a3 done writing [2025-04-30T09:47:48.435314373Z TRACE quiche_server] Collecting garbage [2025-04-30T09:47:48.436858792Z TRACE quiche_server] got 46 bytes from [::ffff:193.167.0.100]:39383 to [::]:443 [2025-04-30T09:47:48.436867568Z TRACE quiche_server] got packet Short dcid=0f6c0885e55d44d1844a94507a3de7784507e2a3 key_phase=false [2025-04-30T09:47:48.436872918Z TRACE quiche] 0f6c0885e55d44d1844a94507a3de7784507e2a3 rx pkt Short dcid=0f6c0885e55d44d1844a94507a3de7784507e2a3 key_phase=false len=25 pn=4 [2025-04-30T09:47:48.436878108Z TRACE quiche] 0f6c0885e55d44d1844a94507a3de7784507e2a3 rx frm ACK delay=6 blocks=[2..6] ecn_counts=None [2025-04-30T09:47:48.436881394Z TRACE quiche::recovery::congestion::recovery] 0f6c0885e55d44d1844a94507a3de7784507e2a3 packet newly acked 5 [2025-04-30T09:47:48.436883748Z TRACE quiche::recovery::congestion::recovery] 0f6c0885e55d44d1844a94507a3de7784507e2a3 packet newly acked 6 [2025-04-30T09:47:48.436887155Z TRACE quiche] 0f6c0885e55d44d1844a94507a3de7784507e2a3 rx frm APPLICATION_CLOSE err=0 reason=[] [2025-04-30T09:47:48.436899538Z TRACE quiche_server] 0f6c0885e55d44d1844a94507a3de7784507e2a3 processed 46 bytes [2025-04-30T09:47:48.436903615Z TRACE quiche_server] recv() would block [2025-04-30T09:47:48.436905950Z TRACE quiche_server] 0f6c0885e55d44d1844a94507a3de7784507e2a3 done writing [2025-04-30T09:47:48.436908124Z TRACE quiche_server] Collecting garbage [2025-04-30T09:47:48.631154806Z TRACE quiche_server] timed out [2025-04-30T09:47:48.631200311Z TRACE quiche] 0f6c0885e55d44d1844a94507a3de7784507e2a3 draining timeout expired [2025-04-30T09:47:48.631235206Z TRACE quiche_server] 0f6c0885e55d44d1844a94507a3de7784507e2a3 done writing [2025-04-30T09:47:48.631239103Z TRACE quiche_server] Collecting garbage [2025-04-30T09:47:48.631242790Z INFO quiche_server] 0f6c0885e55d44d1844a94507a3de7784507e2a3 connection collected recv=7 sent=7 lost=0 retrans=0 sent_bytes=6909 recv_bytes=2003 lost_bytes=0 [local_addr=[::]:443 peer_addr=[::ffff:193.167.0.100]:39383 validation_state=Validated active=true recv=7 sent=7 lost=0 retrans=0 rtt=32.830736ms min_rtt=Some(31.995165ms) rttvar=7.927578ms cwnd=13500 sent_bytes=6909 recv_bytes=2003 lost_bytes=0 stream_retrans_bytes=0 pmtu=1350 delivery_rate=186434] [2025-04-30T09:47:48.774099231Z TRACE quiche_server] got 1252 bytes from [::ffff:193.167.0.100]:39856 to [::]:443 [2025-04-30T09:47:48.774120511Z TRACE quiche_server] got packet Initial version=1 dcid=f212d6692e8617f3 scid=d9f57a60d06e5132 token= [2025-04-30T09:47:48.774127795Z DEBUG quiche_server] New connection: dcid=f212d6692e8617f3 scid=e4eecae305ae4905bf120cbbe07518cde97fc6c4 [2025-04-30T09:47:48.774249471Z TRACE quiche] e4eecae305ae4905bf120cbbe07518cde97fc6c4 rx pkt Initial version=1 dcid=f212d6692e8617f3 scid=d9f57a60d06e5132 token= len=1226 pn=72911 [2025-04-30T09:47:48.774261444Z TRACE quiche] e4eecae305ae4905bf120cbbe07518cde97fc6c4 rx frm PING mtu_probe=None [2025-04-30T09:47:48.774265011Z TRACE quiche] e4eecae305ae4905bf120cbbe07518cde97fc6c4 rx frm CRYPTO off=0 len=506 [2025-04-30T09:47:48.774288394Z TRACE quiche::tls] checking peer ALPN Ok("hq-interop") against Ok("h3") [2025-04-30T09:47:48.774292371Z TRACE quiche::tls] checking peer ALPN Ok("hq-interop") against Ok("hq-interop") [2025-04-30T09:47:48.774400513Z TRACE quiche::tls] e4eecae305ae4905bf120cbbe07518cde97fc6c4 write message lvl=Initial len=129 [2025-04-30T09:47:48.774416713Z TRACE quiche::tls] e4eecae305ae4905bf120cbbe07518cde97fc6c4 set write secret lvl=Handshake [2025-04-30T09:47:48.774440467Z TRACE quiche::tls] e4eecae305ae4905bf120cbbe07518cde97fc6c4 write message lvl=Handshake len=148 [2025-04-30T09:47:48.774443012Z TRACE quiche::tls] e4eecae305ae4905bf120cbbe07518cde97fc6c4 set write secret lvl=OneRTT [2025-04-30T09:47:48.774448983Z TRACE quiche::tls] e4eecae305ae4905bf120cbbe07518cde97fc6c4 set read secret lvl=Handshake [2025-04-30T09:47:48.774462338Z TRACE quiche] e4eecae305ae4905bf120cbbe07518cde97fc6c4 rx frm PADDING len=695 [2025-04-30T09:47:48.774478278Z TRACE quiche_server] e4eecae305ae4905bf120cbbe07518cde97fc6c4 processed 1252 bytes [2025-04-30T09:47:48.774494979Z TRACE quiche_server] recv() would block [2025-04-30T09:47:48.774505869Z TRACE quiche] e4eecae305ae4905bf120cbbe07518cde97fc6c4 tx pkt Initial version=1 dcid=d9f57a60d06e5132 scid=e4eecae305ae4905bf120cbbe07518cde97fc6c4 len=141 pn=0 [2025-04-30T09:47:48.774509175Z TRACE quiche] e4eecae305ae4905bf120cbbe07518cde97fc6c4 tx frm ACK delay=33 blocks=[72911..72911] ecn_counts=None [2025-04-30T09:47:48.774513494Z TRACE quiche] e4eecae305ae4905bf120cbbe07518cde97fc6c4 tx frm CRYPTO off=0 len=129 [2025-04-30T09:47:48.774522080Z TRACE quiche::recovery::congestion::recovery] e4eecae305ae4905bf120cbbe07518cde97fc6c4 timer=998.974473ms latest_rtt=0ns srtt=333ms min_rtt=333ms rttvar=166.5ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=196 app_limited=true congestion_recovery_start_time=None Rate { delivered: 0, delivered_time: Instant { tv_sec: 298, tv_nsec: 561435763 }, first_sent_time: Instant { tv_sec: 298, tv_nsec: 561435763 }, 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: 298, tv_nsec: 561435763 }, next_time: Instant { tv_sec: 298, tv_nsec: 561435763 }, max_datagram_size: 1350, last_packet_size: None, iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } [2025-04-30T09:47:48.774548198Z TRACE quiche] e4eecae305ae4905bf120cbbe07518cde97fc6c4 tx pkt Handshake version=1 dcid=d9f57a60d06e5132 scid=e4eecae305ae4905bf120cbbe07518cde97fc6c4 len=152 pn=1 [2025-04-30T09:47:48.774551064Z TRACE quiche] e4eecae305ae4905bf120cbbe07518cde97fc6c4 tx frm CRYPTO off=0 len=148 [2025-04-30T09:47:48.774556334Z TRACE quiche::recovery::congestion::recovery] e4eecae305ae4905bf120cbbe07518cde97fc6c4 timer=998.94062ms latest_rtt=0ns srtt=333ms min_rtt=333ms rttvar=166.5ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=402 app_limited=true congestion_recovery_start_time=None Rate { delivered: 0, delivered_time: Instant { tv_sec: 298, tv_nsec: 561435763 }, first_sent_time: Instant { tv_sec: 298, tv_nsec: 561435763 }, 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: 298, tv_nsec: 561435763 }, next_time: Instant { tv_sec: 298, tv_nsec: 561435763 }, max_datagram_size: 1350, last_packet_size: None, iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } [2025-04-30T09:47:48.774603121Z TRACE quiche_server] e4eecae305ae4905bf120cbbe07518cde97fc6c4 written 1200 bytes with Some(SendInfo { from: [::]:443, to: [::ffff:193.167.0.100]:39856, at: Instant { tv_sec: 298, tv_nsec: 561435763 } }) [2025-04-30T09:47:48.774609102Z TRACE quiche_server] Collecting garbage [2025-04-30T09:47:48.774613881Z TRACE quiche_server] recv() would block [2025-04-30T09:47:48.774618179Z TRACE quiche_server] e4eecae305ae4905bf120cbbe07518cde97fc6c4 done writing [2025-04-30T09:47:48.774621776Z TRACE quiche_server] Collecting garbage [2025-04-30T09:47:48.806655864Z TRACE quiche_server] got 412 bytes from [::ffff:193.167.0.100]:39856 to [::]:443 [2025-04-30T09:47:48.806671202Z TRACE quiche_server] got packet Handshake version=1 dcid=e4eecae305ae4905bf120cbbe07518cde97fc6c4 scid=d9f57a60d06e5132 [2025-04-30T09:47:48.806680860Z TRACE quiche] e4eecae305ae4905bf120cbbe07518cde97fc6c4 rx pkt Handshake version=1 dcid=e4eecae305ae4905bf120cbbe07518cde97fc6c4 scid=d9f57a60d06e5132 len=64 pn=0 [2025-04-30T09:47:48.806689416Z TRACE quiche] e4eecae305ae4905bf120cbbe07518cde97fc6c4 rx frm ACK delay=31 blocks=[1..1] ecn_counts=None [2025-04-30T09:47:48.806694566Z TRACE quiche::recovery::congestion::recovery] e4eecae305ae4905bf120cbbe07518cde97fc6c4 packet newly acked 1 [2025-04-30T09:47:48.806699665Z TRACE quiche] e4eecae305ae4905bf120cbbe07518cde97fc6c4 rx frm CRYPTO off=0 len=36 [2025-04-30T09:47:48.806712419Z TRACE quiche::tls] e4eecae305ae4905bf120cbbe07518cde97fc6c4 set read secret lvl=OneRTT [2025-04-30T09:47:48.806739159Z TRACE quiche::tls] e4eecae305ae4905bf120cbbe07518cde97fc6c4 write message lvl=OneRTT len=396 [2025-04-30T09:47:48.806747455Z TRACE quiche] e4eecae305ae4905bf120cbbe07518cde97fc6c4 dropped epoch 1 state [2025-04-30T09:47:48.806751041Z TRACE quiche] e4eecae305ae4905bf120cbbe07518cde97fc6c4 connection established: proto=Ok("hq-interop") cipher=Some(AES128_GCM) curve=Some("P-256") sigalg=None resumed=true TransportParams { original_destination_connection_id: None, max_idle_timeout: 180000, stateless_reset_token: None, max_udp_payload_size: 1440, initial_max_data: 1048576, initial_max_stream_data_bidi_local: 2097152, initial_max_stream_data_bidi_remote: 65635, initial_max_stream_data_uni: 65535, initial_max_streams_bidi: 512, initial_max_streams_uni: 512, ack_delay_exponent: 3, max_ack_delay: 10, disable_active_migration: false, active_conn_id_limit: 8, initial_source_connection_id: Some(d9f57a60d06e5132), retry_source_connection_id: None, max_datagram_frame_size: None, unknown_params: None } [2025-04-30T09:47:48.806785245Z TRACE quiche] e4eecae305ae4905bf120cbbe07518cde97fc6c4 dropped epoch 0 state [2025-04-30T09:47:48.806788741Z TRACE quiche] e4eecae305ae4905bf120cbbe07518cde97fc6c4 rx pkt Short dcid=e4eecae305ae4905bf120cbbe07518cde97fc6c4 key_phase=false len=290 pn=0 [2025-04-30T09:47:48.806795013Z TRACE quiche] e4eecae305ae4905bf120cbbe07518cde97fc6c4 rx frm NEW_CONNECTION_ID seq_num=1 retire_prior_to=0 conn_id=[17, e9, dc, 7a, e1, f9, 1b, 30] reset_token=[8b, e3, 9f, 85, 02, 9e, 4f, 4d, c1, 4b, 89, 13, d5, 8a, d8, b4] [2025-04-30T09:47:48.806801756Z TRACE quiche] e4eecae305ae4905bf120cbbe07518cde97fc6c4 rx frm NEW_CONNECTION_ID seq_num=2 retire_prior_to=0 conn_id=[4d, c1, 87, ec, 18, 58, 89, 7e] reset_token=[4b, d9, 38, 7b, 62, a7, 7f, 03, c7, a1, 94, b4, c1, 8d, 5f, ce] [2025-04-30T09:47:48.806806454Z TRACE quiche] e4eecae305ae4905bf120cbbe07518cde97fc6c4 rx frm NEW_CONNECTION_ID seq_num=3 retire_prior_to=0 conn_id=[28, d3, 08, 51, 17, f5, c9, 41] reset_token=[11, cc, 1d, c0, a2, 92, c6, eb, eb, 0e, 46, c5, 5a, 10, 34, 1b] [2025-04-30T09:47:48.806810993Z TRACE quiche] e4eecae305ae4905bf120cbbe07518cde97fc6c4 rx frm NEW_CONNECTION_ID seq_num=4 retire_prior_to=0 conn_id=[98, ce, 14, 75, 40, a2, c7, 90] reset_token=[21, 12, 10, 24, 57, 52, 05, 6a, f2, 57, 7f, 2f, 83, 33, 8e, 9e] [2025-04-30T09:47:48.806815992Z TRACE quiche] e4eecae305ae4905bf120cbbe07518cde97fc6c4 rx frm NEW_CONNECTION_ID seq_num=5 retire_prior_to=0 conn_id=[28, 89, f7, d1, 19, dc, b4, 6e] reset_token=[3f, d1, 3e, 05, 70, 70, 80, 27, 8e, 0e, 14, c0, 64, 4f, 07, 2c] [2025-04-30T09:47:48.806820661Z TRACE quiche] e4eecae305ae4905bf120cbbe07518cde97fc6c4 rx frm NEW_CONNECTION_ID seq_num=6 retire_prior_to=0 conn_id=[3b, c5, be, 6a, bc, 65, cc, 11] reset_token=[29, 9e, 04, d0, 7b, 6f, ca, 3e, 81, a1, e5, b4, ea, b1, b8, 91] [2025-04-30T09:47:48.806826081Z TRACE quiche] e4eecae305ae4905bf120cbbe07518cde97fc6c4 rx frm NEW_CONNECTION_ID seq_num=7 retire_prior_to=0 conn_id=[3b, cd, 97, 27, 07, 7c, 65, b9] reset_token=[05, 2b, 0c, 3a, 46, c3, ab, 79, a7, 94, 50, 59, 07, 93, 8c, cf] [2025-04-30T09:47:48.806830409Z TRACE quiche] e4eecae305ae4905bf120cbbe07518cde97fc6c4 rx frm PADDING len=77 [2025-04-30T09:47:48.806838775Z TRACE quiche_server] e4eecae305ae4905bf120cbbe07518cde97fc6c4 processed 412 bytes [2025-04-30T09:47:48.806846168Z TRACE quiche_server] got 183 bytes from [::ffff:193.167.0.100]:39856 to [::]:443 [2025-04-30T09:47:48.806849374Z TRACE quiche_server] got packet Short dcid=e4eecae305ae4905bf120cbbe07518cde97fc6c4 key_phase=false [2025-04-30T09:47:48.806853542Z TRACE quiche] e4eecae305ae4905bf120cbbe07518cde97fc6c4 rx pkt Short dcid=e4eecae305ae4905bf120cbbe07518cde97fc6c4 key_phase=false len=162 pn=1 [2025-04-30T09:47:48.806857690Z TRACE quiche] e4eecae305ae4905bf120cbbe07518cde97fc6c4 rx frm STREAM id=0 off=0 len=17 fin=true [2025-04-30T09:47:48.806862168Z TRACE quiche] e4eecae305ae4905bf120cbbe07518cde97fc6c4 rx frm PADDING len=125 [2025-04-30T09:47:48.806866476Z TRACE quiche_server] e4eecae305ae4905bf120cbbe07518cde97fc6c4 processed 183 bytes [2025-04-30T09:47:48.806869121Z DEBUG quiche_apps::common] e4eecae305ae4905bf120cbbe07518cde97fc6c4 response stream 0 is writable with capacity Ok(13500) [2025-04-30T09:47:48.806875694Z TRACE quiche_apps::common] e4eecae305ae4905bf120cbbe07518cde97fc6c4 received 17 bytes [2025-04-30T09:47:48.806878258Z TRACE quiche_apps::common] e4eecae305ae4905bf120cbbe07518cde97fc6c4 stream 0 has 17 bytes (fin? true) [2025-04-30T09:47:48.806882346Z INFO quiche_apps::common] e4eecae305ae4905bf120cbbe07518cde97fc6c4 got GET request for "/www/csyofcifgq" on stream 0 [2025-04-30T09:47:48.806908184Z INFO quiche_apps::common] e4eecae305ae4905bf120cbbe07518cde97fc6c4 sending response of size 10240 on stream 0 [2025-04-30T09:47:48.806920537Z TRACE quiche_server] recv() would block [2025-04-30T09:47:48.806927520Z TRACE quiche] e4eecae305ae4905bf120cbbe07518cde97fc6c4 pmtud probe status false hs_con=true hs_sent=false cwnd_avail=13500 out_len=1350 left=1319 [2025-04-30T09:47:48.806935745Z TRACE quiche] e4eecae305ae4905bf120cbbe07518cde97fc6c4 tx pkt Short dcid=d9f57a60d06e5132 key_phase=false len=1324 pn=2 [2025-04-30T09:47:48.806938581Z TRACE quiche] e4eecae305ae4905bf120cbbe07518cde97fc6c4 tx frm ACK delay=9 blocks=[0..1] ecn_counts=None [2025-04-30T09:47:48.806941706Z TRACE quiche] e4eecae305ae4905bf120cbbe07518cde97fc6c4 tx frm NEW_CONNECTION_ID seq_num=1 retire_prior_to=0 conn_id=[de, 6b, 18, dd, c9, 80, a4, a0, 36, c0, e4, 1b, 68, 8b, 52, 23, 94, c7, 79, 31] reset_token=[df, db, fa, 42, ef, 7f, 85, fd, 1b, fa, 44, e1, 21, df, 28, 95] [2025-04-30T09:47:48.806947507Z TRACE quiche] e4eecae305ae4905bf120cbbe07518cde97fc6c4 tx frm NEW_CONNECTION_ID seq_num=2 retire_prior_to=0 conn_id=[a0, 95, 3d, 74, 1c, 3b, 5f, eb, 30, 65, be, f2, c5, 55, 5a, 53, bd, 26, a3, 5b] reset_token=[dc, 75, 28, ff, 28, 91, c4, 2f, b4, 4f, 27, 6c, 65, 59, 48, f8] [2025-04-30T09:47:48.806952887Z TRACE quiche] e4eecae305ae4905bf120cbbe07518cde97fc6c4 tx frm NEW_CONNECTION_ID seq_num=3 retire_prior_to=0 conn_id=[1a, 65, b7, 6c, 22, 55, fb, 23, 7e, 6f, 12, 6c, 3f, 4b, fc, 3b, 7e, 0c, f7, 7b] reset_token=[89, 81, b3, 5b, 87, 7a, 85, e0, ff, af, 9d, e3, a7, 33, ce, c7] [2025-04-30T09:47:48.806958117Z TRACE quiche] e4eecae305ae4905bf120cbbe07518cde97fc6c4 tx frm NEW_CONNECTION_ID seq_num=4 retire_prior_to=0 conn_id=[23, c6, 59, db, 6a, ed, f7, 9c, 34, ac, 41, 2c, 1f, f0, 65, a2, ae, 03, 95, 6f] reset_token=[cc, 2d, 3e, 14, 2e, 48, 84, db, 1c, 7a, 02, bb, 1a, f3, c7, 06] [2025-04-30T09:47:48.806963497Z TRACE quiche] e4eecae305ae4905bf120cbbe07518cde97fc6c4 tx frm NEW_CONNECTION_ID seq_num=5 retire_prior_to=0 conn_id=[49, 3a, 2c, b0, 3b, dc, 8f, 3d, 91, 66, 25, 86, d1, 4a, 40, 56, 29, eb, 08, 91] reset_token=[73, 15, 63, c9, ef, 87, 77, 56, 5b, ff, 91, 6c, 8c, cd, 3b, dd] [2025-04-30T09:47:48.806968767Z TRACE quiche] e4eecae305ae4905bf120cbbe07518cde97fc6c4 tx frm NEW_CONNECTION_ID seq_num=6 retire_prior_to=0 conn_id=[93, 7a, bb, 42, 55, 49, 08, 44, de, e0, 44, d1, 2a, 1f, 0b, ff, 41, b9, 72, e8] reset_token=[4b, 8a, 2c, 17, cf, 18, f4, 36, eb, c9, c0, 34, 52, 4e, 33, 74] [2025-04-30T09:47:48.806974057Z TRACE quiche] e4eecae305ae4905bf120cbbe07518cde97fc6c4 tx frm NEW_CONNECTION_ID seq_num=7 retire_prior_to=0 conn_id=[eb, 92, 82, 3a, 4f, ef, 67, bf, 2b, 80, 7d, f2, 96, 12, a0, 31, c6, ab, 3a, 03] reset_token=[65, 5c, b2, 45, 30, d4, fc, 89, 96, 86, 4b, 60, 42, d5, bd, 02] [2025-04-30T09:47:48.806979296Z TRACE quiche] e4eecae305ae4905bf120cbbe07518cde97fc6c4 tx frm HANDSHAKE_DONE [2025-04-30T09:47:48.806981541Z TRACE quiche] e4eecae305ae4905bf120cbbe07518cde97fc6c4 tx frm CRYPTO off=0 len=396 [2025-04-30T09:47:48.806983805Z TRACE quiche] e4eecae305ae4905bf120cbbe07518cde97fc6c4 tx frm STREAM id=0 off=0 len=633 fin=false [2025-04-30T09:47:48.806995677Z TRACE quiche::recovery::congestion::recovery] e4eecae305ae4905bf120cbbe07518cde97fc6c4 timer=106.469489ms latest_rtt=32.181012ms srtt=32.181012ms min_rtt=32.181012ms rttvar=16.090506ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=1350 app_limited=true congestion_recovery_start_time=None Rate { delivered: 206, delivered_time: Instant { tv_sec: 298, tv_nsec: 593861491 }, first_sent_time: Instant { tv_sec: 298, tv_nsec: 593861491 }, end_of_app_limited: 1, last_sent_packet: 2, largest_acked: 1, rate_sample: RateSample { delivery_rate: 6401, is_app_limited: true, interval: 32.181012ms, delivered: 206, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 298, tv_nsec: 561435763 }), send_elapsed: 0ns, ack_elapsed: 32.181012ms, rtt: 32.181012ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 524377, last_update: Instant { tv_sec: 298, tv_nsec: 593861491 }, next_time: Instant { tv_sec: 298, tv_nsec: 593861491 }, max_datagram_size: 1350, last_packet_size: Some(0), iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } [2025-04-30T09:47:48.807014673Z TRACE quiche] e4eecae305ae4905bf120cbbe07518cde97fc6c4 pmtud probe status false hs_con=true hs_sent=true cwnd_avail=12150 out_len=1350 left=1324 [2025-04-30T09:47:48.807018400Z TRACE quiche] e4eecae305ae4905bf120cbbe07518cde97fc6c4 tx pkt Short dcid=d9f57a60d06e5132 key_phase=false len=1324 pn=3 [2025-04-30T09:47:48.807020874Z TRACE quiche] e4eecae305ae4905bf120cbbe07518cde97fc6c4 tx frm STREAM id=0 off=633 len=1318 fin=false [2025-04-30T09:47:48.807025943Z TRACE quiche::recovery::congestion::recovery] e4eecae305ae4905bf120cbbe07518cde97fc6c4 timer=106.530012ms latest_rtt=32.181012ms srtt=32.181012ms min_rtt=32.181012ms rttvar=16.090506ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=2700 app_limited=true congestion_recovery_start_time=None Rate { delivered: 206, delivered_time: Instant { tv_sec: 298, tv_nsec: 593861491 }, first_sent_time: Instant { tv_sec: 298, tv_nsec: 593861491 }, end_of_app_limited: 2, last_sent_packet: 3, largest_acked: 1, rate_sample: RateSample { delivery_rate: 6401, is_app_limited: true, interval: 32.181012ms, delivered: 206, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 298, tv_nsec: 561435763 }), send_elapsed: 0ns, ack_elapsed: 32.181012ms, rtt: 32.181012ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 524377, last_update: Instant { tv_sec: 298, tv_nsec: 593861491 }, next_time: Instant { tv_sec: 298, tv_nsec: 593861491 }, max_datagram_size: 1350, last_packet_size: Some(0), iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } [2025-04-30T09:47:48.807036343Z TRACE quiche] e4eecae305ae4905bf120cbbe07518cde97fc6c4 pmtud probe status false hs_con=true hs_sent=true cwnd_avail=10800 out_len=1350 left=1324 [2025-04-30T09:47:48.807039138Z TRACE quiche] e4eecae305ae4905bf120cbbe07518cde97fc6c4 tx pkt Short dcid=d9f57a60d06e5132 key_phase=false len=1324 pn=4 [2025-04-30T09:47:48.807041483Z TRACE quiche] e4eecae305ae4905bf120cbbe07518cde97fc6c4 tx frm STREAM id=0 off=1951 len=1318 fin=false [2025-04-30T09:47:48.807084703Z TRACE quiche::recovery::congestion::recovery] e4eecae305ae4905bf120cbbe07518cde97fc6c4 timer=106.492972ms latest_rtt=32.181012ms srtt=32.181012ms min_rtt=32.181012ms rttvar=16.090506ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=4050 app_limited=true congestion_recovery_start_time=None Rate { delivered: 206, delivered_time: Instant { tv_sec: 298, tv_nsec: 593861491 }, first_sent_time: Instant { tv_sec: 298, tv_nsec: 593861491 }, end_of_app_limited: 3, last_sent_packet: 4, largest_acked: 1, rate_sample: RateSample { delivery_rate: 6401, is_app_limited: true, interval: 32.181012ms, delivered: 206, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 298, tv_nsec: 561435763 }), send_elapsed: 0ns, ack_elapsed: 32.181012ms, rtt: 32.181012ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 524377, last_update: Instant { tv_sec: 298, tv_nsec: 593861491 }, next_time: Instant { tv_sec: 298, tv_nsec: 593861491 }, max_datagram_size: 1350, last_packet_size: Some(0), iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } [2025-04-30T09:47:48.807100202Z TRACE quiche] e4eecae305ae4905bf120cbbe07518cde97fc6c4 pmtud probe status false hs_con=true hs_sent=true cwnd_avail=9450 out_len=1350 left=1324 [2025-04-30T09:47:48.807103809Z TRACE quiche] e4eecae305ae4905bf120cbbe07518cde97fc6c4 tx pkt Short dcid=d9f57a60d06e5132 key_phase=false len=1324 pn=5 [2025-04-30T09:47:48.807110471Z TRACE quiche] e4eecae305ae4905bf120cbbe07518cde97fc6c4 tx frm STREAM id=0 off=3269 len=1318 fin=false [2025-04-30T09:47:48.807115751Z TRACE quiche::recovery::congestion::recovery] e4eecae305ae4905bf120cbbe07518cde97fc6c4 timer=106.525393ms latest_rtt=32.181012ms srtt=32.181012ms min_rtt=32.181012ms rttvar=16.090506ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=5400 app_limited=true congestion_recovery_start_time=None Rate { delivered: 206, delivered_time: Instant { tv_sec: 298, tv_nsec: 593861491 }, first_sent_time: Instant { tv_sec: 298, tv_nsec: 593861491 }, end_of_app_limited: 3, last_sent_packet: 5, largest_acked: 1, rate_sample: RateSample { delivery_rate: 6401, is_app_limited: true, interval: 32.181012ms, delivered: 206, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 298, tv_nsec: 561435763 }), send_elapsed: 0ns, ack_elapsed: 32.181012ms, rtt: 32.181012ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 524377, last_update: Instant { tv_sec: 298, tv_nsec: 593861491 }, next_time: Instant { tv_sec: 298, tv_nsec: 593861491 }, max_datagram_size: 1350, last_packet_size: Some(0), iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } [2025-04-30T09:47:48.807126210Z TRACE quiche] e4eecae305ae4905bf120cbbe07518cde97fc6c4 pmtud probe status false hs_con=true hs_sent=true cwnd_avail=8100 out_len=1350 left=1324 [2025-04-30T09:47:48.807129126Z TRACE quiche] e4eecae305ae4905bf120cbbe07518cde97fc6c4 tx pkt Short dcid=d9f57a60d06e5132 key_phase=false len=1324 pn=6 [2025-04-30T09:47:48.807131490Z TRACE quiche] e4eecae305ae4905bf120cbbe07518cde97fc6c4 tx frm STREAM id=0 off=4587 len=1318 fin=false [2025-04-30T09:47:48.807136009Z TRACE quiche::recovery::congestion::recovery] e4eecae305ae4905bf120cbbe07518cde97fc6c4 timer=106.531886ms latest_rtt=32.181012ms srtt=32.181012ms min_rtt=32.181012ms rttvar=16.090506ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=6750 app_limited=true congestion_recovery_start_time=None Rate { delivered: 206, delivered_time: Instant { tv_sec: 298, tv_nsec: 593861491 }, first_sent_time: Instant { tv_sec: 298, tv_nsec: 593861491 }, end_of_app_limited: 3, last_sent_packet: 6, largest_acked: 1, rate_sample: RateSample { delivery_rate: 6401, is_app_limited: true, interval: 32.181012ms, delivered: 206, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 298, tv_nsec: 561435763 }), send_elapsed: 0ns, ack_elapsed: 32.181012ms, rtt: 32.181012ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 524377, last_update: Instant { tv_sec: 298, tv_nsec: 593861491 }, next_time: Instant { tv_sec: 298, tv_nsec: 593861491 }, max_datagram_size: 1350, last_packet_size: Some(0), iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } [2025-04-30T09:47:48.807146027Z TRACE quiche] e4eecae305ae4905bf120cbbe07518cde97fc6c4 pmtud probe status false hs_con=true hs_sent=true cwnd_avail=6750 out_len=1350 left=1324 [2025-04-30T09:47:48.807148903Z TRACE quiche] e4eecae305ae4905bf120cbbe07518cde97fc6c4 tx pkt Short dcid=d9f57a60d06e5132 key_phase=false len=1324 pn=7 [2025-04-30T09:47:48.807151267Z TRACE quiche] e4eecae305ae4905bf120cbbe07518cde97fc6c4 tx frm STREAM id=0 off=5905 len=1318 fin=false [2025-04-30T09:47:48.807155445Z TRACE quiche::recovery::congestion::recovery] e4eecae305ae4905bf120cbbe07518cde97fc6c4 timer=106.532336ms latest_rtt=32.181012ms srtt=32.181012ms min_rtt=32.181012ms rttvar=16.090506ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=8100 app_limited=true congestion_recovery_start_time=None Rate { delivered: 206, delivered_time: Instant { tv_sec: 298, tv_nsec: 593861491 }, first_sent_time: Instant { tv_sec: 298, tv_nsec: 593861491 }, end_of_app_limited: 3, last_sent_packet: 7, largest_acked: 1, rate_sample: RateSample { delivery_rate: 6401, is_app_limited: true, interval: 32.181012ms, delivered: 206, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 298, tv_nsec: 561435763 }), send_elapsed: 0ns, ack_elapsed: 32.181012ms, rtt: 32.181012ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 524377, last_update: Instant { tv_sec: 298, tv_nsec: 593861491 }, next_time: Instant { tv_sec: 298, tv_nsec: 593861491 }, max_datagram_size: 1350, last_packet_size: Some(0), iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } [2025-04-30T09:47:48.807168239Z TRACE quiche] e4eecae305ae4905bf120cbbe07518cde97fc6c4 pmtud probe status false hs_con=true hs_sent=true cwnd_avail=5400 out_len=1350 left=1324 [2025-04-30T09:47:48.807171244Z TRACE quiche] e4eecae305ae4905bf120cbbe07518cde97fc6c4 tx pkt Short dcid=d9f57a60d06e5132 key_phase=false len=1324 pn=8 [2025-04-30T09:47:48.807173609Z TRACE quiche] e4eecae305ae4905bf120cbbe07518cde97fc6c4 tx frm STREAM id=0 off=7223 len=1318 fin=false [2025-04-30T09:47:48.807177847Z TRACE quiche::recovery::congestion::recovery] e4eecae305ae4905bf120cbbe07518cde97fc6c4 timer=106.532276ms latest_rtt=32.181012ms srtt=32.181012ms min_rtt=32.181012ms rttvar=16.090506ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=9450 app_limited=true congestion_recovery_start_time=None Rate { delivered: 206, delivered_time: Instant { tv_sec: 298, tv_nsec: 593861491 }, first_sent_time: Instant { tv_sec: 298, tv_nsec: 593861491 }, end_of_app_limited: 3, last_sent_packet: 8, largest_acked: 1, rate_sample: RateSample { delivery_rate: 6401, is_app_limited: true, interval: 32.181012ms, delivered: 206, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 298, tv_nsec: 561435763 }), send_elapsed: 0ns, ack_elapsed: 32.181012ms, rtt: 32.181012ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 524377, last_update: Instant { tv_sec: 298, tv_nsec: 593861491 }, next_time: Instant { tv_sec: 298, tv_nsec: 593861491 }, max_datagram_size: 1350, last_packet_size: Some(0), iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } [2025-04-30T09:47:48.807187505Z TRACE quiche] e4eecae305ae4905bf120cbbe07518cde97fc6c4 pmtud probe status false hs_con=true hs_sent=true cwnd_avail=4050 out_len=1350 left=1324 [2025-04-30T09:47:48.807190350Z TRACE quiche] e4eecae305ae4905bf120cbbe07518cde97fc6c4 tx pkt Short dcid=d9f57a60d06e5132 key_phase=false len=1324 pn=9 [2025-04-30T09:47:48.807192654Z TRACE quiche] e4eecae305ae4905bf120cbbe07518cde97fc6c4 tx frm STREAM id=0 off=8541 len=1318 fin=false [2025-04-30T09:47:48.807196822Z TRACE quiche::recovery::congestion::recovery] e4eecae305ae4905bf120cbbe07518cde97fc6c4 timer=106.532646ms latest_rtt=32.181012ms srtt=32.181012ms min_rtt=32.181012ms rttvar=16.090506ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=10800 app_limited=true congestion_recovery_start_time=None Rate { delivered: 206, delivered_time: Instant { tv_sec: 298, tv_nsec: 593861491 }, first_sent_time: Instant { tv_sec: 298, tv_nsec: 593861491 }, end_of_app_limited: 3, last_sent_packet: 9, largest_acked: 1, rate_sample: RateSample { delivery_rate: 6401, is_app_limited: true, interval: 32.181012ms, delivered: 206, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 298, tv_nsec: 561435763 }), send_elapsed: 0ns, ack_elapsed: 32.181012ms, rtt: 32.181012ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 524377, last_update: Instant { tv_sec: 298, tv_nsec: 593861491 }, next_time: Instant { tv_sec: 298, tv_nsec: 593861491 }, max_datagram_size: 1350, last_packet_size: Some(0), iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } [2025-04-30T09:47:48.807209706Z TRACE quiche] e4eecae305ae4905bf120cbbe07518cde97fc6c4 pmtud probe status false hs_con=true hs_sent=true cwnd_avail=2700 out_len=1350 left=1324 [2025-04-30T09:47:48.807212581Z TRACE quiche] e4eecae305ae4905bf120cbbe07518cde97fc6c4 tx pkt Short dcid=d9f57a60d06e5132 key_phase=false len=387 pn=10 [2025-04-30T09:47:48.807214956Z TRACE quiche] e4eecae305ae4905bf120cbbe07518cde97fc6c4 tx frm STREAM id=0 off=9859 len=381 fin=true [2025-04-30T09:47:48.807219825Z TRACE quiche::recovery::congestion::recovery] e4eecae305ae4905bf120cbbe07518cde97fc6c4 timer=106.531825ms latest_rtt=32.181012ms srtt=32.181012ms min_rtt=32.181012ms rttvar=16.090506ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=11213 app_limited=true congestion_recovery_start_time=None Rate { delivered: 206, delivered_time: Instant { tv_sec: 298, tv_nsec: 593861491 }, first_sent_time: Instant { tv_sec: 298, tv_nsec: 593861491 }, end_of_app_limited: 3, last_sent_packet: 10, largest_acked: 1, rate_sample: RateSample { delivery_rate: 6401, is_app_limited: true, interval: 32.181012ms, delivered: 206, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 298, tv_nsec: 561435763 }), send_elapsed: 0ns, ack_elapsed: 32.181012ms, rtt: 32.181012ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 524377, last_update: Instant { tv_sec: 298, tv_nsec: 593861491 }, next_time: Instant { tv_sec: 298, tv_nsec: 593861491 }, max_datagram_size: 1350, last_packet_size: Some(0), iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } [2025-04-30T09:47:48.807344718Z TRACE quiche_server] e4eecae305ae4905bf120cbbe07518cde97fc6c4 written 11213 bytes with Some(SendInfo { from: [::]:443, to: [::ffff:193.167.0.100]:39856, at: Instant { tv_sec: 298, tv_nsec: 593861491 } }) [2025-04-30T09:47:48.807350368Z TRACE quiche_server] Collecting garbage [2025-04-30T09:47:48.807355067Z TRACE quiche_server] recv() would block [2025-04-30T09:47:48.807357942Z TRACE quiche_server] e4eecae305ae4905bf120cbbe07518cde97fc6c4 done writing [2025-04-30T09:47:48.807360166Z TRACE quiche_server] Collecting garbage [2025-04-30T09:47:48.838994369Z TRACE quiche_server] got 55 bytes from [::ffff:193.167.0.100]:39856 to [::]:443 [2025-04-30T09:47:48.839008836Z TRACE quiche_server] got packet Short dcid=e4eecae305ae4905bf120cbbe07518cde97fc6c4 key_phase=false [2025-04-30T09:47:48.839018885Z TRACE quiche] e4eecae305ae4905bf120cbbe07518cde97fc6c4 rx pkt Short dcid=e4eecae305ae4905bf120cbbe07518cde97fc6c4 key_phase=false len=34 pn=2 [2025-04-30T09:47:48.839026809Z TRACE quiche] e4eecae305ae4905bf120cbbe07518cde97fc6c4 rx frm ACK delay=21 blocks=[2..2] ecn_counts=None [2025-04-30T09:47:48.839031819Z TRACE quiche::recovery::congestion::recovery] e4eecae305ae4905bf120cbbe07518cde97fc6c4 packet newly acked 2 [2025-04-30T09:47:48.839037920Z TRACE quiche] e4eecae305ae4905bf120cbbe07518cde97fc6c4 rx frm PADDING len=12 [2025-04-30T09:47:48.839054822Z TRACE quiche_server] e4eecae305ae4905bf120cbbe07518cde97fc6c4 processed 55 bytes [2025-04-30T09:47:48.839060342Z TRACE quiche_server] recv() would block [2025-04-30T09:47:48.839085068Z TRACE quiche_server] e4eecae305ae4905bf120cbbe07518cde97fc6c4 done writing [2025-04-30T09:47:48.839088364Z TRACE quiche_server] Collecting garbage [2025-04-30T09:47:48.840938403Z TRACE quiche_server] got 55 bytes from [::ffff:193.167.0.100]:39856 to [::]:443 [2025-04-30T09:47:48.840953681Z TRACE quiche_server] got packet Short dcid=e4eecae305ae4905bf120cbbe07518cde97fc6c4 key_phase=false [2025-04-30T09:47:48.840959652Z TRACE quiche] e4eecae305ae4905bf120cbbe07518cde97fc6c4 rx pkt Short dcid=e4eecae305ae4905bf120cbbe07518cde97fc6c4 key_phase=false len=34 pn=3 [2025-04-30T09:47:48.840965483Z TRACE quiche] e4eecae305ae4905bf120cbbe07518cde97fc6c4 rx frm ACK delay=2 blocks=[2..4] ecn_counts=None [2025-04-30T09:47:48.840969420Z TRACE quiche::recovery::congestion::recovery] e4eecae305ae4905bf120cbbe07518cde97fc6c4 packet newly acked 3 [2025-04-30T09:47:48.840972496Z TRACE quiche::recovery::congestion::recovery] e4eecae305ae4905bf120cbbe07518cde97fc6c4 packet newly acked 4 [2025-04-30T09:47:48.840976423Z TRACE quiche] e4eecae305ae4905bf120cbbe07518cde97fc6c4 rx frm PADDING len=12 [2025-04-30T09:47:48.840987174Z TRACE quiche_server] e4eecae305ae4905bf120cbbe07518cde97fc6c4 processed 55 bytes [2025-04-30T09:47:48.840991862Z TRACE quiche_server] recv() would block [2025-04-30T09:47:48.840995138Z TRACE quiche_server] e4eecae305ae4905bf120cbbe07518cde97fc6c4 done writing [2025-04-30T09:47:48.840997843Z TRACE quiche_server] Collecting garbage [2025-04-30T09:47:48.843142841Z TRACE quiche_server] got 55 bytes from [::ffff:193.167.0.100]:39856 to [::]:443 [2025-04-30T09:47:48.843150225Z TRACE quiche_server] got packet Short dcid=e4eecae305ae4905bf120cbbe07518cde97fc6c4 key_phase=false [2025-04-30T09:47:48.843155475Z TRACE quiche] e4eecae305ae4905bf120cbbe07518cde97fc6c4 rx pkt Short dcid=e4eecae305ae4905bf120cbbe07518cde97fc6c4 key_phase=false len=34 pn=4 [2025-04-30T09:47:48.843160364Z TRACE quiche] e4eecae305ae4905bf120cbbe07518cde97fc6c4 rx frm ACK delay=2 blocks=[2..6] ecn_counts=None [2025-04-30T09:47:48.843163841Z TRACE quiche::recovery::congestion::recovery] e4eecae305ae4905bf120cbbe07518cde97fc6c4 packet newly acked 5 [2025-04-30T09:47:48.843166636Z TRACE quiche::recovery::congestion::recovery] e4eecae305ae4905bf120cbbe07518cde97fc6c4 packet newly acked 6 [2025-04-30T09:47:48.843170283Z TRACE quiche] e4eecae305ae4905bf120cbbe07518cde97fc6c4 rx frm PADDING len=12 [2025-04-30T09:47:48.843179540Z TRACE quiche_server] e4eecae305ae4905bf120cbbe07518cde97fc6c4 processed 55 bytes [2025-04-30T09:47:48.843183938Z TRACE quiche_server] recv() would block [2025-04-30T09:47:48.843186964Z TRACE quiche_server] e4eecae305ae4905bf120cbbe07518cde97fc6c4 done writing [2025-04-30T09:47:48.843189669Z TRACE quiche_server] Collecting garbage [2025-04-30T09:47:48.845374211Z TRACE quiche_server] got 55 bytes from [::ffff:193.167.0.100]:39856 to [::]:443 [2025-04-30T09:47:48.845380883Z TRACE quiche_server] got packet Short dcid=e4eecae305ae4905bf120cbbe07518cde97fc6c4 key_phase=false [2025-04-30T09:47:48.845386033Z TRACE quiche] e4eecae305ae4905bf120cbbe07518cde97fc6c4 rx pkt Short dcid=e4eecae305ae4905bf120cbbe07518cde97fc6c4 key_phase=false len=34 pn=5 [2025-04-30T09:47:48.845391112Z TRACE quiche] e4eecae305ae4905bf120cbbe07518cde97fc6c4 rx frm ACK delay=3 blocks=[2..8] ecn_counts=None [2025-04-30T09:47:48.845394719Z TRACE quiche::recovery::congestion::recovery] e4eecae305ae4905bf120cbbe07518cde97fc6c4 packet newly acked 7 [2025-04-30T09:47:48.845397504Z TRACE quiche::recovery::congestion::recovery] e4eecae305ae4905bf120cbbe07518cde97fc6c4 packet newly acked 8 [2025-04-30T09:47:48.845401010Z TRACE quiche] e4eecae305ae4905bf120cbbe07518cde97fc6c4 rx frm PADDING len=12 [2025-04-30T09:47:48.845409987Z TRACE quiche_server] e4eecae305ae4905bf120cbbe07518cde97fc6c4 processed 55 bytes [2025-04-30T09:47:48.845414235Z TRACE quiche_server] recv() would block [2025-04-30T09:47:48.845417381Z TRACE quiche_server] e4eecae305ae4905bf120cbbe07518cde97fc6c4 done writing [2025-04-30T09:47:48.845420016Z TRACE quiche_server] Collecting garbage [2025-04-30T09:47:48.846825295Z TRACE quiche_server] got 46 bytes from [::ffff:193.167.0.100]:39856 to [::]:443 [2025-04-30T09:47:48.846831958Z TRACE quiche_server] got packet Short dcid=e4eecae305ae4905bf120cbbe07518cde97fc6c4 key_phase=false [2025-04-30T09:47:48.846842127Z TRACE quiche] e4eecae305ae4905bf120cbbe07518cde97fc6c4 rx pkt Short dcid=e4eecae305ae4905bf120cbbe07518cde97fc6c4 key_phase=false len=25 pn=6 [2025-04-30T09:47:48.846847547Z TRACE quiche] e4eecae305ae4905bf120cbbe07518cde97fc6c4 rx frm ACK delay=6 blocks=[2..10] ecn_counts=None [2025-04-30T09:47:48.846851144Z TRACE quiche::recovery::congestion::recovery] e4eecae305ae4905bf120cbbe07518cde97fc6c4 packet newly acked 9 [2025-04-30T09:47:48.846854039Z TRACE quiche::recovery::congestion::recovery] e4eecae305ae4905bf120cbbe07518cde97fc6c4 packet newly acked 10 [2025-04-30T09:47:48.846857906Z TRACE quiche] e4eecae305ae4905bf120cbbe07518cde97fc6c4 rx frm APPLICATION_CLOSE err=0 reason=[] [2025-04-30T09:47:48.846871030Z TRACE quiche_server] e4eecae305ae4905bf120cbbe07518cde97fc6c4 processed 46 bytes [2025-04-30T09:47:48.846875419Z TRACE quiche_server] recv() would block [2025-04-30T09:47:48.846878204Z TRACE quiche_server] e4eecae305ae4905bf120cbbe07518cde97fc6c4 done writing [2025-04-30T09:47:48.846880849Z TRACE quiche_server] Collecting garbage [2025-04-30T09:47:49.037103362Z TRACE quiche_server] timed out [2025-04-30T09:47:49.037133158Z TRACE quiche] e4eecae305ae4905bf120cbbe07518cde97fc6c4 draining timeout expired [2025-04-30T09:47:49.037177801Z TRACE quiche_server] e4eecae305ae4905bf120cbbe07518cde97fc6c4 done writing [2025-04-30T09:47:49.037181859Z TRACE quiche_server] Collecting garbage [2025-04-30T09:47:49.037186096Z INFO quiche_server] e4eecae305ae4905bf120cbbe07518cde97fc6c4 connection collected recv=9 sent=11 lost=0 retrans=0 sent_bytes=11615 recv_bytes=2113 lost_bytes=0 [local_addr=[::]:443 peer_addr=[::ffff:193.167.0.100]:39856 validation_state=Validated active=true recv=9 sent=11 lost=0 retrans=0 rtt=34.360329ms min_rtt=Some(32.093529ms) rttvar=7.173693ms cwnd=13500 sent_bytes=11615 recv_bytes=2113 lost_bytes=0 stream_retrans_bytes=0 pmtu=1350 delivery_rate=349385]