[2025-04-30T11:47:50.882484341Z INFO quiche_server] listening on [::]:443 [2025-04-30T11:47:50.882509588Z TRACE mio::poll] registering event source with poller: token=Token(0), interests=READABLE [2025-04-30T11:47:50.882516752Z TRACE quiche_server] GSO detected: false [2025-04-30T11:47:51.698113128Z TRACE quiche_server] got 1207 bytes from [::ffff:193.167.100.2]:55523 to [::]:443 [2025-04-30T11:47:51.698147172Z TRACE quiche_server] got packet Initial version=57414954 dcid= scid= token= [2025-04-30T11:47:51.698155538Z WARN quiche_server] Doing version negotiation [2025-04-30T11:47:51.698256867Z TRACE quiche_server] got 1207 bytes from [::ffff:193.167.100.2]:55523 to [::]:443 [2025-04-30T11:47:51.698263189Z TRACE quiche_server] got packet Initial version=57414954 dcid= scid= token= [2025-04-30T11:47:51.698267136Z WARN quiche_server] Doing version negotiation [2025-04-30T11:47:51.698287595Z TRACE quiche_server] got 1207 bytes from [::ffff:193.167.100.2]:55523 to [::]:443 [2025-04-30T11:47:51.698294127Z TRACE quiche_server] got packet Initial version=57414954 dcid= scid= token= [2025-04-30T11:47:51.698299848Z WARN quiche_server] Doing version negotiation [2025-04-30T11:47:51.698331467Z TRACE quiche_server] recv() would block [2025-04-30T11:47:54.905516352Z TRACE quiche_server] got 1200 bytes from [::ffff:193.167.0.100]:50877 to [::]:443 [2025-04-30T11:47:54.905543512Z TRACE quiche_server] got packet Initial version=1 dcid=c6a29b95be50ad608a48372e6d248db716be30cf scid=3cb3e9cea527d2ae token= [2025-04-30T11:47:54.905553220Z DEBUG quiche_server] New connection: dcid=c6a29b95be50ad608a48372e6d248db716be30cf scid=708eab6292ab3bbfa3cca9d8c860df6ba145e6d8 [2025-04-30T11:47:54.905752293Z TRACE quiche] 708eab6292ab3bbfa3cca9d8c860df6ba145e6d8 rx pkt Initial version=1 dcid=c6a29b95be50ad608a48372e6d248db716be30cf scid=3cb3e9cea527d2ae token= len=1162 pn=0 [2025-04-30T11:47:54.905766800Z TRACE quiche] 708eab6292ab3bbfa3cca9d8c860df6ba145e6d8 rx frm CRYPTO off=0 len=286 [2025-04-30T11:47:54.905796105Z TRACE quiche::tls] checking peer ALPN Ok("hq-interop") against Ok("h3") [2025-04-30T11:47:54.905800713Z TRACE quiche::tls] checking peer ALPN Ok("hq-interop") against Ok("hq-interop") [2025-04-30T11:47:54.905926479Z TRACE quiche::tls] 708eab6292ab3bbfa3cca9d8c860df6ba145e6d8 write message lvl=Initial len=90 [2025-04-30T11:47:54.905967215Z TRACE quiche::tls] 708eab6292ab3bbfa3cca9d8c860df6ba145e6d8 set write secret lvl=Handshake [2025-04-30T11:47:54.906048797Z TRACE quiche::tls] 708eab6292ab3bbfa3cca9d8c860df6ba145e6d8 write message lvl=Handshake len=724 [2025-04-30T11:47:54.906052514Z TRACE quiche::tls] 708eab6292ab3bbfa3cca9d8c860df6ba145e6d8 set write secret lvl=OneRTT [2025-04-30T11:47:54.906060399Z TRACE quiche::tls] 708eab6292ab3bbfa3cca9d8c860df6ba145e6d8 set read secret lvl=Handshake [2025-04-30T11:47:54.906080707Z TRACE quiche] 708eab6292ab3bbfa3cca9d8c860df6ba145e6d8 rx frm PADDING len=855 [2025-04-30T11:47:54.906101406Z TRACE quiche_server] 708eab6292ab3bbfa3cca9d8c860df6ba145e6d8 processed 1200 bytes [2025-04-30T11:47:54.906114350Z TRACE quiche_server] recv() would block [2025-04-30T11:47:54.906125721Z TRACE quiche] 708eab6292ab3bbfa3cca9d8c860df6ba145e6d8 tx pkt Initial version=1 dcid=3cb3e9cea527d2ae scid=708eab6292ab3bbfa3cca9d8c860df6ba145e6d8 len=99 pn=0 [2025-04-30T11:47:54.906129127Z TRACE quiche] 708eab6292ab3bbfa3cca9d8c860df6ba145e6d8 tx frm ACK delay=48 blocks=[0..0] ecn_counts=None [2025-04-30T11:47:54.906133406Z TRACE quiche] 708eab6292ab3bbfa3cca9d8c860df6ba145e6d8 tx frm CRYPTO off=0 len=90 [2025-04-30T11:47:54.906142182Z TRACE quiche::recovery::congestion::recovery] 708eab6292ab3bbfa3cca9d8c860df6ba145e6d8 timer=998.973972ms latest_rtt=0ns srtt=333ms min_rtt=333ms rttvar=166.5ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=154 app_limited=true congestion_recovery_start_time=None Rate { delivered: 0, delivered_time: Instant { tv_sec: 430, tv_nsec: 696227253 }, first_sent_time: Instant { tv_sec: 430, tv_nsec: 696227253 }, 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: 430, tv_nsec: 696227253 }, next_time: Instant { tv_sec: 430, tv_nsec: 696227253 }, 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-30T11:47:54.906168371Z TRACE quiche] 708eab6292ab3bbfa3cca9d8c860df6ba145e6d8 tx pkt Handshake version=1 dcid=3cb3e9cea527d2ae scid=708eab6292ab3bbfa3cca9d8c860df6ba145e6d8 len=728 pn=1 [2025-04-30T11:47:54.906171306Z TRACE quiche] 708eab6292ab3bbfa3cca9d8c860df6ba145e6d8 tx frm CRYPTO off=0 len=724 [2025-04-30T11:47:54.906176847Z TRACE quiche::recovery::congestion::recovery] 708eab6292ab3bbfa3cca9d8c860df6ba145e6d8 timer=998.939677ms latest_rtt=0ns srtt=333ms min_rtt=333ms rttvar=166.5ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=936 app_limited=true congestion_recovery_start_time=None Rate { delivered: 0, delivered_time: Instant { tv_sec: 430, tv_nsec: 696227253 }, first_sent_time: Instant { tv_sec: 430, tv_nsec: 696227253 }, 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: 430, tv_nsec: 696227253 }, next_time: Instant { tv_sec: 430, tv_nsec: 696227253 }, 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-30T11:47:54.906220298Z TRACE quiche_server] 708eab6292ab3bbfa3cca9d8c860df6ba145e6d8 written 1200 bytes with Some(SendInfo { from: [::]:443, to: [::ffff:193.167.0.100]:50877, at: Instant { tv_sec: 430, tv_nsec: 696227253 } }) [2025-04-30T11:47:54.906227922Z TRACE quiche_server] Collecting garbage [2025-04-30T11:47:54.906234865Z TRACE quiche_server] recv() would block [2025-04-30T11:47:54.906240897Z TRACE quiche_server] 708eab6292ab3bbfa3cca9d8c860df6ba145e6d8 done writing [2025-04-30T11:47:54.906244804Z TRACE quiche_server] Collecting garbage [2025-04-30T11:47:54.938953058Z TRACE quiche_server] got 1200 bytes from [::ffff:193.167.0.100]:50877 to [::]:443 [2025-04-30T11:47:54.938966834Z TRACE quiche_server] got packet Initial version=1 dcid=708eab6292ab3bbfa3cca9d8c860df6ba145e6d8 scid=3cb3e9cea527d2ae token= [2025-04-30T11:47:54.938976091Z TRACE quiche] 708eab6292ab3bbfa3cca9d8c860df6ba145e6d8 rx pkt Initial version=1 dcid=708eab6292ab3bbfa3cca9d8c860df6ba145e6d8 scid=3cb3e9cea527d2ae token= len=22 pn=1 [2025-04-30T11:47:54.938983445Z TRACE quiche] 708eab6292ab3bbfa3cca9d8c860df6ba145e6d8 rx frm ACK delay=44 blocks=[0..0] ecn_counts=None [2025-04-30T11:47:54.938989065Z TRACE quiche::recovery::congestion::recovery] 708eab6292ab3bbfa3cca9d8c860df6ba145e6d8 packet newly acked 0 [2025-04-30T11:47:54.939004434Z TRACE quiche] 708eab6292ab3bbfa3cca9d8c860df6ba145e6d8 rx pkt Handshake version=1 dcid=708eab6292ab3bbfa3cca9d8c860df6ba145e6d8 scid=3cb3e9cea527d2ae len=1103 pn=0 [2025-04-30T11:47:54.939009824Z TRACE quiche] 708eab6292ab3bbfa3cca9d8c860df6ba145e6d8 rx frm ACK delay=44 blocks=[1..1] ecn_counts=None [2025-04-30T11:47:54.939013802Z TRACE quiche::recovery::congestion::recovery] 708eab6292ab3bbfa3cca9d8c860df6ba145e6d8 packet newly acked 1 [2025-04-30T11:47:54.939018090Z TRACE quiche] 708eab6292ab3bbfa3cca9d8c860df6ba145e6d8 rx frm CRYPTO off=0 len=52 [2025-04-30T11:47:54.939037275Z TRACE quiche::tls] 708eab6292ab3bbfa3cca9d8c860df6ba145e6d8 set read secret lvl=OneRTT [2025-04-30T11:47:54.939084844Z TRACE quiche::tls] 708eab6292ab3bbfa3cca9d8c860df6ba145e6d8 write message lvl=OneRTT len=428 [2025-04-30T11:47:54.939098229Z TRACE quiche] 708eab6292ab3bbfa3cca9d8c860df6ba145e6d8 dropped epoch 1 state [2025-04-30T11:47:54.939104141Z TRACE quiche] 708eab6292ab3bbfa3cca9d8c860df6ba145e6d8 connection established: proto=Ok("hq-interop") cipher=Some(AES256_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: 1472, initial_max_data: 4611686018427387903, initial_max_stream_data_bidi_local: 1250000, initial_max_stream_data_bidi_remote: 1250000, initial_max_stream_data_uni: 1250000, initial_max_streams_bidi: 100, initial_max_streams_uni: 100, ack_delay_exponent: 3, max_ack_delay: 25, disable_active_migration: false, active_conn_id_limit: 5, initial_source_connection_id: Some(3cb3e9cea527d2ae), retry_source_connection_id: None, max_datagram_frame_size: Some(65535), unknown_params: None } [2025-04-30T11:47:54.939122164Z TRACE quiche] 708eab6292ab3bbfa3cca9d8c860df6ba145e6d8 rx frm PADDING len=1026 [2025-04-30T11:47:54.939140779Z TRACE quiche] 708eab6292ab3bbfa3cca9d8c860df6ba145e6d8 dropped epoch 0 state [2025-04-30T11:47:54.939143965Z TRACE quiche_server] 708eab6292ab3bbfa3cca9d8c860df6ba145e6d8 processed 1200 bytes [2025-04-30T11:47:54.939156739Z TRACE quiche_server] got 234 bytes from [::ffff:193.167.0.100]:50877 to [::]:443 [2025-04-30T11:47:54.939160336Z TRACE quiche_server] got packet Short dcid=708eab6292ab3bbfa3cca9d8c860df6ba145e6d8 key_phase=false [2025-04-30T11:47:54.939165195Z TRACE quiche] 708eab6292ab3bbfa3cca9d8c860df6ba145e6d8 rx pkt Short dcid=708eab6292ab3bbfa3cca9d8c860df6ba145e6d8 key_phase=false len=213 pn=0 [2025-04-30T11:47:54.939171286Z TRACE quiche] 708eab6292ab3bbfa3cca9d8c860df6ba145e6d8 rx frm NEW_CONNECTION_ID seq_num=1 retire_prior_to=0 conn_id=[69, 40, 02, eb, e3, 37, 31, 48] reset_token=[b8, aa, b9, 11, d9, d9, 5c, f9, 47, 14, fa, 2e, d4, 97, d5, f9] [2025-04-30T11:47:54.939177919Z TRACE quiche] 708eab6292ab3bbfa3cca9d8c860df6ba145e6d8 rx frm NEW_CONNECTION_ID seq_num=2 retire_prior_to=0 conn_id=[b6, c8, 84, 98, f2, 97, 51, a1] reset_token=[18, 16, b0, 68, 74, c9, 5a, 16, 88, 0d, 5c, ce, 88, 3d, cf, fb] [2025-04-30T11:47:54.939182567Z TRACE quiche] 708eab6292ab3bbfa3cca9d8c860df6ba145e6d8 rx frm NEW_CONNECTION_ID seq_num=3 retire_prior_to=0 conn_id=[95, 3d, e7, 87, a0, d0, cd, a4] reset_token=[04, 6b, bb, df, d8, 03, d6, 30, 03, e7, 87, d4, 07, b8, b0, 5b] [2025-04-30T11:47:54.939187166Z TRACE quiche] 708eab6292ab3bbfa3cca9d8c860df6ba145e6d8 rx frm NEW_CONNECTION_ID seq_num=4 retire_prior_to=0 conn_id=[89, 51, 59, d5, 3f, cc, 50, 1a] reset_token=[da, 46, a0, 76, 3a, 31, eb, b9, 17, f7, 30, 06, 8a, 2c, 4e, b9] [2025-04-30T11:47:54.939192256Z TRACE quiche] 708eab6292ab3bbfa3cca9d8c860df6ba145e6d8 rx frm NEW_CONNECTION_ID seq_num=5 retire_prior_to=0 conn_id=[33, 0f, 8a, e9, fc, 56, cc, ae] reset_token=[48, 56, de, 9a, 57, 55, f2, 56, 0e, c0, ff, 87, 98, 88, 3e, 14] [2025-04-30T11:47:54.939196824Z TRACE quiche] 708eab6292ab3bbfa3cca9d8c860df6ba145e6d8 rx frm NEW_CONNECTION_ID seq_num=6 retire_prior_to=0 conn_id=[1f, 90, 42, 27, 96, 0a, 9b, 4b] reset_token=[ff, d1, 67, d9, b5, d4, 3a, bb, 41, 79, b7, cf, dc, 0a, 24, 93] [2025-04-30T11:47:54.939201713Z TRACE quiche] 708eab6292ab3bbfa3cca9d8c860df6ba145e6d8 rx frm NEW_CONNECTION_ID seq_num=7 retire_prior_to=0 conn_id=[6b, 39, 94, ae, 2d, 50, 8a, bf] reset_token=[37, a8, 78, 3f, d6, a6, ed, 26, 32, d1, e6, 18, 02, 0f, 53, 1e] [2025-04-30T11:47:54.939210660Z TRACE quiche_server] 708eab6292ab3bbfa3cca9d8c860df6ba145e6d8 processed 234 bytes [2025-04-30T11:47:54.939215279Z TRACE quiche_server] got 58 bytes from [::ffff:193.167.0.100]:50877 to [::]:443 [2025-04-30T11:47:54.939218194Z TRACE quiche_server] got packet Short dcid=708eab6292ab3bbfa3cca9d8c860df6ba145e6d8 key_phase=false [2025-04-30T11:47:54.939226940Z TRACE quiche] 708eab6292ab3bbfa3cca9d8c860df6ba145e6d8 rx pkt Short dcid=708eab6292ab3bbfa3cca9d8c860df6ba145e6d8 key_phase=false len=37 pn=1 [2025-04-30T11:47:54.939231068Z TRACE quiche] 708eab6292ab3bbfa3cca9d8c860df6ba145e6d8 rx frm STREAM id=0 off=0 len=17 fin=true [2025-04-30T11:47:54.939237460Z TRACE quiche_server] 708eab6292ab3bbfa3cca9d8c860df6ba145e6d8 processed 58 bytes [2025-04-30T11:47:54.939240155Z DEBUG quiche_apps::common] 708eab6292ab3bbfa3cca9d8c860df6ba145e6d8 response stream 0 is writable with capacity Ok(13500) [2025-04-30T11:47:54.939246457Z TRACE quiche_apps::common] 708eab6292ab3bbfa3cca9d8c860df6ba145e6d8 received 17 bytes [2025-04-30T11:47:54.939249162Z TRACE quiche_apps::common] 708eab6292ab3bbfa3cca9d8c860df6ba145e6d8 stream 0 has 17 bytes (fin? true) [2025-04-30T11:47:54.939253139Z INFO quiche_apps::common] 708eab6292ab3bbfa3cca9d8c860df6ba145e6d8 got GET request for "/www/dkajpltelu" on stream 0 [2025-04-30T11:47:54.939275351Z INFO quiche_apps::common] 708eab6292ab3bbfa3cca9d8c860df6ba145e6d8 sending response of size 5120 on stream 0 [2025-04-30T11:47:54.939282645Z TRACE quiche_server] recv() would block [2025-04-30T11:47:54.939289217Z TRACE quiche] 708eab6292ab3bbfa3cca9d8c860df6ba145e6d8 pmtud probe status false hs_con=true hs_sent=false cwnd_avail=13500 out_len=1350 left=1319 [2025-04-30T11:47:54.939296701Z TRACE quiche] 708eab6292ab3bbfa3cca9d8c860df6ba145e6d8 tx pkt Short dcid=3cb3e9cea527d2ae key_phase=false len=1324 pn=2 [2025-04-30T11:47:54.939299396Z TRACE quiche] 708eab6292ab3bbfa3cca9d8c860df6ba145e6d8 tx frm ACK delay=7 blocks=[0..1] ecn_counts=None [2025-04-30T11:47:54.939302542Z TRACE quiche] 708eab6292ab3bbfa3cca9d8c860df6ba145e6d8 tx frm NEW_CONNECTION_ID seq_num=1 retire_prior_to=0 conn_id=[3d, aa, ba, 36, dc, ce, e8, 7c, b1, 1d, 7f, a7, 21, 74, 24, 11, aa, 42, 6e, a8] reset_token=[5b, 3b, cf, 45, 97, fe, 39, df, 2f, 9e, c6, 1d, 3c, 52, a2, 54] [2025-04-30T11:47:54.939308152Z TRACE quiche] 708eab6292ab3bbfa3cca9d8c860df6ba145e6d8 tx frm NEW_CONNECTION_ID seq_num=2 retire_prior_to=0 conn_id=[ba, f0, fc, a6, 54, c3, 74, c9, 2c, f6, 00, b4, 54, f0, b6, d4, cd, 1c, 85, 73] reset_token=[17, 7e, 20, ee, e8, 9c, 6e, 3e, 21, 30, 8b, cc, 91, 03, 8c, 96] [2025-04-30T11:47:54.939313342Z TRACE quiche] 708eab6292ab3bbfa3cca9d8c860df6ba145e6d8 tx frm NEW_CONNECTION_ID seq_num=3 retire_prior_to=0 conn_id=[25, fc, 73, c1, 13, e8, 73, 71, 55, de, 4a, 81, af, 4c, 3e, 21, 29, 08, 2d, 06] reset_token=[0e, 97, 70, 5e, 3e, df, c0, f2, 6c, ad, 93, 65, 9b, 34, 47, 91] [2025-04-30T11:47:54.939318452Z TRACE quiche] 708eab6292ab3bbfa3cca9d8c860df6ba145e6d8 tx frm NEW_CONNECTION_ID seq_num=4 retire_prior_to=0 conn_id=[3c, e9, ea, 09, bb, ee, 8f, ab, 12, 58, d5, cf, 04, 4f, cc, 36, 3f, 05, 78, 3b] reset_token=[a1, da, 23, f3, 3e, fb, 5f, 3d, 83, e1, 92, 70, ac, 86, 7c, 33] [2025-04-30T11:47:54.939323601Z TRACE quiche] 708eab6292ab3bbfa3cca9d8c860df6ba145e6d8 tx frm HANDSHAKE_DONE [2025-04-30T11:47:54.939325855Z TRACE quiche] 708eab6292ab3bbfa3cca9d8c860df6ba145e6d8 tx frm CRYPTO off=0 len=428 [2025-04-30T11:47:54.939328240Z TRACE quiche] 708eab6292ab3bbfa3cca9d8c860df6ba145e6d8 tx frm STREAM id=0 off=0 len=721 fin=false [2025-04-30T11:47:54.939338389Z TRACE quiche::recovery::congestion::recovery] 708eab6292ab3bbfa3cca9d8c860df6ba145e6d8 timer=107.122342ms latest_rtt=32.887008ms srtt=32.860779ms min_rtt=32.857032ms rttvar=12.328881ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=1350 app_limited=true congestion_recovery_start_time=None Rate { delivered: 936, delivered_time: Instant { tv_sec: 430, tv_nsec: 729395397 }, first_sent_time: Instant { tv_sec: 430, tv_nsec: 729395397 }, end_of_app_limited: 1, last_sent_packet: 2, largest_acked: 1, rate_sample: RateSample { delivery_rate: 28487, is_app_limited: true, interval: 32.857032ms, delivered: 936, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 430, tv_nsec: 696227253 }), send_elapsed: 0ns, ack_elapsed: 32.857032ms, rtt: 32.857032ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 513530, last_update: Instant { tv_sec: 430, tv_nsec: 729395397 }, next_time: Instant { tv_sec: 430, tv_nsec: 729395397 }, 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-30T11:47:54.939358046Z TRACE quiche] 708eab6292ab3bbfa3cca9d8c860df6ba145e6d8 pmtud probe status false hs_con=true hs_sent=true cwnd_avail=12150 out_len=1350 left=1324 [2025-04-30T11:47:54.939361733Z TRACE quiche] 708eab6292ab3bbfa3cca9d8c860df6ba145e6d8 tx pkt Short dcid=3cb3e9cea527d2ae key_phase=false len=1324 pn=3 [2025-04-30T11:47:54.939364187Z TRACE quiche] 708eab6292ab3bbfa3cca9d8c860df6ba145e6d8 tx frm STREAM id=0 off=721 len=1318 fin=false [2025-04-30T11:47:54.939369156Z TRACE quiche::recovery::congestion::recovery] 708eab6292ab3bbfa3cca9d8c860df6ba145e6d8 timer=107.163359ms latest_rtt=32.887008ms srtt=32.860779ms min_rtt=32.857032ms rttvar=12.328881ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=2700 app_limited=true congestion_recovery_start_time=None Rate { delivered: 936, delivered_time: Instant { tv_sec: 430, tv_nsec: 729395397 }, first_sent_time: Instant { tv_sec: 430, tv_nsec: 729395397 }, end_of_app_limited: 2, last_sent_packet: 3, largest_acked: 1, rate_sample: RateSample { delivery_rate: 28487, is_app_limited: true, interval: 32.857032ms, delivered: 936, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 430, tv_nsec: 696227253 }), send_elapsed: 0ns, ack_elapsed: 32.857032ms, rtt: 32.857032ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 513530, last_update: Instant { tv_sec: 430, tv_nsec: 729395397 }, next_time: Instant { tv_sec: 430, tv_nsec: 729395397 }, 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-30T11:47:54.939379065Z TRACE quiche] 708eab6292ab3bbfa3cca9d8c860df6ba145e6d8 pmtud probe status false hs_con=true hs_sent=true cwnd_avail=10800 out_len=1350 left=1324 [2025-04-30T11:47:54.939382100Z TRACE quiche] 708eab6292ab3bbfa3cca9d8c860df6ba145e6d8 tx pkt Short dcid=3cb3e9cea527d2ae key_phase=false len=1324 pn=4 [2025-04-30T11:47:54.939384455Z TRACE quiche] 708eab6292ab3bbfa3cca9d8c860df6ba145e6d8 tx frm STREAM id=0 off=2039 len=1318 fin=false [2025-04-30T11:47:54.939388773Z TRACE quiche::recovery::congestion::recovery] 708eab6292ab3bbfa3cca9d8c860df6ba145e6d8 timer=107.165372ms latest_rtt=32.887008ms srtt=32.860779ms min_rtt=32.857032ms rttvar=12.328881ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=4050 app_limited=true congestion_recovery_start_time=None Rate { delivered: 936, delivered_time: Instant { tv_sec: 430, tv_nsec: 729395397 }, first_sent_time: Instant { tv_sec: 430, tv_nsec: 729395397 }, end_of_app_limited: 3, last_sent_packet: 4, largest_acked: 1, rate_sample: RateSample { delivery_rate: 28487, is_app_limited: true, interval: 32.857032ms, delivered: 936, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 430, tv_nsec: 696227253 }), send_elapsed: 0ns, ack_elapsed: 32.857032ms, rtt: 32.857032ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 513530, last_update: Instant { tv_sec: 430, tv_nsec: 729395397 }, next_time: Instant { tv_sec: 430, tv_nsec: 729395397 }, 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-30T11:47:54.939397990Z TRACE quiche] 708eab6292ab3bbfa3cca9d8c860df6ba145e6d8 pmtud probe status false hs_con=true hs_sent=true cwnd_avail=9450 out_len=1350 left=1324 [2025-04-30T11:47:54.939403771Z TRACE quiche] 708eab6292ab3bbfa3cca9d8c860df6ba145e6d8 tx pkt Short dcid=3cb3e9cea527d2ae key_phase=false len=1324 pn=5 [2025-04-30T11:47:54.939406246Z TRACE quiche] 708eab6292ab3bbfa3cca9d8c860df6ba145e6d8 tx frm STREAM id=0 off=3357 len=1318 fin=false [2025-04-30T11:47:54.939426644Z TRACE quiche::recovery::congestion::recovery] 708eab6292ab3bbfa3cca9d8c860df6ba145e6d8 timer=107.146547ms latest_rtt=32.887008ms srtt=32.860779ms min_rtt=32.857032ms rttvar=12.328881ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=5400 app_limited=true congestion_recovery_start_time=None Rate { delivered: 936, delivered_time: Instant { tv_sec: 430, tv_nsec: 729395397 }, first_sent_time: Instant { tv_sec: 430, tv_nsec: 729395397 }, end_of_app_limited: 4, last_sent_packet: 5, largest_acked: 1, rate_sample: RateSample { delivery_rate: 28487, is_app_limited: true, interval: 32.857032ms, delivered: 936, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 430, tv_nsec: 696227253 }), send_elapsed: 0ns, ack_elapsed: 32.857032ms, rtt: 32.857032ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 513530, last_update: Instant { tv_sec: 430, tv_nsec: 729395397 }, next_time: Instant { tv_sec: 430, tv_nsec: 729395397 }, 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-30T11:47:54.939436753Z TRACE quiche] 708eab6292ab3bbfa3cca9d8c860df6ba145e6d8 pmtud probe status false hs_con=true hs_sent=true cwnd_avail=8100 out_len=1350 left=1324 [2025-04-30T11:47:54.939439728Z TRACE quiche] 708eab6292ab3bbfa3cca9d8c860df6ba145e6d8 tx pkt Short dcid=3cb3e9cea527d2ae key_phase=false len=451 pn=6 [2025-04-30T11:47:54.939442133Z TRACE quiche] 708eab6292ab3bbfa3cca9d8c860df6ba145e6d8 tx frm STREAM id=0 off=4675 len=445 fin=true [2025-04-30T11:47:54.939447252Z TRACE quiche::recovery::congestion::recovery] 708eab6292ab3bbfa3cca9d8c860df6ba145e6d8 timer=107.164431ms latest_rtt=32.887008ms srtt=32.860779ms min_rtt=32.857032ms rttvar=12.328881ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=5877 app_limited=true congestion_recovery_start_time=None Rate { delivered: 936, delivered_time: Instant { tv_sec: 430, tv_nsec: 729395397 }, first_sent_time: Instant { tv_sec: 430, tv_nsec: 729395397 }, end_of_app_limited: 5, last_sent_packet: 6, largest_acked: 1, rate_sample: RateSample { delivery_rate: 28487, is_app_limited: true, interval: 32.857032ms, delivered: 936, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 430, tv_nsec: 696227253 }), send_elapsed: 0ns, ack_elapsed: 32.857032ms, rtt: 32.857032ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 513530, last_update: Instant { tv_sec: 430, tv_nsec: 729395397 }, next_time: Instant { tv_sec: 430, tv_nsec: 729395397 }, 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-30T11:47:54.939529005Z TRACE quiche_server] 708eab6292ab3bbfa3cca9d8c860df6ba145e6d8 written 5877 bytes with Some(SendInfo { from: [::]:443, to: [::ffff:193.167.0.100]:50877, at: Instant { tv_sec: 430, tv_nsec: 729395397 } }) [2025-04-30T11:47:54.939538102Z TRACE quiche_server] Collecting garbage [2025-04-30T11:47:54.939545386Z TRACE quiche_server] recv() would block [2025-04-30T11:47:54.939549594Z TRACE quiche_server] 708eab6292ab3bbfa3cca9d8c860df6ba145e6d8 done writing [2025-04-30T11:47:54.939553581Z TRACE quiche_server] Collecting garbage [2025-04-30T11:47:54.971113866Z TRACE quiche_server] got 43 bytes from [::ffff:193.167.0.100]:50877 to [::]:443 [2025-04-30T11:47:54.971132090Z TRACE quiche_server] got packet Short dcid=708eab6292ab3bbfa3cca9d8c860df6ba145e6d8 key_phase=false [2025-04-30T11:47:54.971143261Z TRACE quiche] 708eab6292ab3bbfa3cca9d8c860df6ba145e6d8 rx pkt Short dcid=708eab6292ab3bbfa3cca9d8c860df6ba145e6d8 key_phase=false len=22 pn=2 [2025-04-30T11:47:54.971153069Z TRACE quiche] 708eab6292ab3bbfa3cca9d8c860df6ba145e6d8 rx frm ACK delay=9 blocks=[2..2] ecn_counts=None [2025-04-30T11:47:54.971159111Z TRACE quiche::recovery::congestion::recovery] 708eab6292ab3bbfa3cca9d8c860df6ba145e6d8 packet newly acked 2 [2025-04-30T11:47:54.971181212Z TRACE quiche_server] 708eab6292ab3bbfa3cca9d8c860df6ba145e6d8 processed 43 bytes [2025-04-30T11:47:54.971187804Z TRACE quiche_server] recv() would block [2025-04-30T11:47:54.971191962Z TRACE quiche_server] 708eab6292ab3bbfa3cca9d8c860df6ba145e6d8 done writing [2025-04-30T11:47:54.971194958Z TRACE quiche_server] Collecting garbage [2025-04-30T11:47:54.973158380Z TRACE quiche_server] got 43 bytes from [::ffff:193.167.0.100]:50877 to [::]:443 [2025-04-30T11:47:54.973165724Z TRACE quiche_server] got packet Short dcid=708eab6292ab3bbfa3cca9d8c860df6ba145e6d8 key_phase=false [2025-04-30T11:47:54.973170863Z TRACE quiche] 708eab6292ab3bbfa3cca9d8c860df6ba145e6d8 rx pkt Short dcid=708eab6292ab3bbfa3cca9d8c860df6ba145e6d8 key_phase=false len=22 pn=3 [2025-04-30T11:47:54.973176143Z TRACE quiche] 708eab6292ab3bbfa3cca9d8c860df6ba145e6d8 rx frm ACK delay=2 blocks=[2..4] ecn_counts=None [2025-04-30T11:47:54.973179760Z TRACE quiche::recovery::congestion::recovery] 708eab6292ab3bbfa3cca9d8c860df6ba145e6d8 packet newly acked 3 [2025-04-30T11:47:54.973182886Z TRACE quiche::recovery::congestion::recovery] 708eab6292ab3bbfa3cca9d8c860df6ba145e6d8 packet newly acked 4 [2025-04-30T11:47:54.973192574Z TRACE quiche_server] 708eab6292ab3bbfa3cca9d8c860df6ba145e6d8 processed 43 bytes [2025-04-30T11:47:54.973196972Z TRACE quiche_server] recv() would block [2025-04-30T11:47:54.973200138Z TRACE quiche_server] 708eab6292ab3bbfa3cca9d8c860df6ba145e6d8 done writing [2025-04-30T11:47:54.973202843Z TRACE quiche_server] Collecting garbage [2025-04-30T11:47:54.974650491Z TRACE quiche_server] got 43 bytes from [::ffff:193.167.0.100]:50877 to [::]:443 [2025-04-30T11:47:54.974656222Z TRACE quiche_server] got packet Short dcid=708eab6292ab3bbfa3cca9d8c860df6ba145e6d8 key_phase=false [2025-04-30T11:47:54.974660329Z TRACE quiche] 708eab6292ab3bbfa3cca9d8c860df6ba145e6d8 rx pkt Short dcid=708eab6292ab3bbfa3cca9d8c860df6ba145e6d8 key_phase=false len=22 pn=4 [2025-04-30T11:47:54.974664537Z TRACE quiche] 708eab6292ab3bbfa3cca9d8c860df6ba145e6d8 rx frm ACK delay=1 blocks=[2..6] ecn_counts=None [2025-04-30T11:47:54.974667453Z TRACE quiche::recovery::congestion::recovery] 708eab6292ab3bbfa3cca9d8c860df6ba145e6d8 packet newly acked 5 [2025-04-30T11:47:54.974669947Z TRACE quiche::recovery::congestion::recovery] 708eab6292ab3bbfa3cca9d8c860df6ba145e6d8 packet newly acked 6 [2025-04-30T11:47:54.974679826Z TRACE quiche_server] 708eab6292ab3bbfa3cca9d8c860df6ba145e6d8 processed 43 bytes [2025-04-30T11:47:54.974683242Z TRACE quiche_server] recv() would block [2025-04-30T11:47:54.974685707Z TRACE quiche_server] 708eab6292ab3bbfa3cca9d8c860df6ba145e6d8 done writing [2025-04-30T11:47:54.974687841Z TRACE quiche_server] Collecting garbage [2025-04-30T11:47:54.974775304Z TRACE quiche_server] got 46 bytes from [::ffff:193.167.0.100]:50877 to [::]:443 [2025-04-30T11:47:54.974778721Z TRACE quiche_server] got packet Short dcid=708eab6292ab3bbfa3cca9d8c860df6ba145e6d8 key_phase=false [2025-04-30T11:47:54.974782528Z TRACE quiche] 708eab6292ab3bbfa3cca9d8c860df6ba145e6d8 rx pkt Short dcid=708eab6292ab3bbfa3cca9d8c860df6ba145e6d8 key_phase=false len=25 pn=5 [2025-04-30T11:47:54.974786445Z TRACE quiche] 708eab6292ab3bbfa3cca9d8c860df6ba145e6d8 rx frm ACK delay=17 blocks=[2..6] ecn_counts=None [2025-04-30T11:47:54.974790303Z TRACE quiche] 708eab6292ab3bbfa3cca9d8c860df6ba145e6d8 rx frm APPLICATION_CLOSE err=0 reason=[] [2025-04-30T11:47:54.974803718Z TRACE quiche_server] 708eab6292ab3bbfa3cca9d8c860df6ba145e6d8 processed 46 bytes [2025-04-30T11:47:54.974807344Z TRACE quiche_server] recv() would block [2025-04-30T11:47:54.974809649Z TRACE quiche_server] 708eab6292ab3bbfa3cca9d8c860df6ba145e6d8 done writing [2025-04-30T11:47:54.974811813Z TRACE quiche_server] Collecting garbage [2025-04-30T11:47:54.975936697Z TRACE quiche_server] got 1200 bytes from [::ffff:193.167.0.100]:50877 to [::]:443 [2025-04-30T11:47:54.975944522Z TRACE quiche_server] got packet Initial version=1 dcid=25564cacb83d7de3b3b7bc304f3d42e68962447e scid=21e1f1620d21d3ac token= [2025-04-30T11:47:54.975950042Z DEBUG quiche_server] New connection: dcid=25564cacb83d7de3b3b7bc304f3d42e68962447e scid=15875681f0cc60d9780ee9d4c1a436582da4a595 [2025-04-30T11:47:54.976071068Z TRACE quiche] 15875681f0cc60d9780ee9d4c1a436582da4a595 rx pkt Initial version=1 dcid=25564cacb83d7de3b3b7bc304f3d42e68962447e scid=21e1f1620d21d3ac token= len=1162 pn=0 [2025-04-30T11:47:54.976079644Z TRACE quiche] 15875681f0cc60d9780ee9d4c1a436582da4a595 rx frm CRYPTO off=0 len=537 [2025-04-30T11:47:54.976102397Z TRACE quiche::tls] checking peer ALPN Ok("hq-interop") against Ok("h3") [2025-04-30T11:47:54.976105953Z TRACE quiche::tls] checking peer ALPN Ok("hq-interop") against Ok("hq-interop") [2025-04-30T11:47:54.976203586Z TRACE quiche::tls] 15875681f0cc60d9780ee9d4c1a436582da4a595 write message lvl=Initial len=96 [2025-04-30T11:47:54.976219486Z TRACE quiche::tls] 15875681f0cc60d9780ee9d4c1a436582da4a595 set write secret lvl=Handshake [2025-04-30T11:47:54.976248009Z TRACE quiche::tls] 15875681f0cc60d9780ee9d4c1a436582da4a595 write message lvl=Handshake len=176 [2025-04-30T11:47:54.976250604Z TRACE quiche::tls] 15875681f0cc60d9780ee9d4c1a436582da4a595 set write secret lvl=OneRTT [2025-04-30T11:47:54.976257747Z TRACE quiche::tls] 15875681f0cc60d9780ee9d4c1a436582da4a595 set read secret lvl=Handshake [2025-04-30T11:47:54.976270842Z TRACE quiche] 15875681f0cc60d9780ee9d4c1a436582da4a595 rx frm PADDING len=604 [2025-04-30T11:47:54.976282363Z TRACE quiche_server] 15875681f0cc60d9780ee9d4c1a436582da4a595 processed 1200 bytes [2025-04-30T11:47:54.976294216Z TRACE quiche_server] recv() would block [2025-04-30T11:47:54.976303633Z TRACE quiche] 15875681f0cc60d9780ee9d4c1a436582da4a595 tx pkt Initial version=1 dcid=21e1f1620d21d3ac scid=15875681f0cc60d9780ee9d4c1a436582da4a595 len=105 pn=0 [2025-04-30T11:47:54.976306539Z TRACE quiche] 15875681f0cc60d9780ee9d4c1a436582da4a595 tx frm ACK delay=30 blocks=[0..0] ecn_counts=None [2025-04-30T11:47:54.976309755Z TRACE quiche] 15875681f0cc60d9780ee9d4c1a436582da4a595 tx frm CRYPTO off=0 len=96 [2025-04-30T11:47:54.976317469Z TRACE quiche::recovery::congestion::recovery] 15875681f0cc60d9780ee9d4c1a436582da4a595 timer=998.97848ms latest_rtt=0ns srtt=333ms min_rtt=333ms rttvar=166.5ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=160 app_limited=true congestion_recovery_start_time=None Rate { delivered: 0, delivered_time: Instant { tv_sec: 430, tv_nsec: 766406898 }, first_sent_time: Instant { tv_sec: 430, tv_nsec: 766406898 }, 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: 430, tv_nsec: 766406898 }, next_time: Instant { tv_sec: 430, tv_nsec: 766406898 }, 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-30T11:47:54.976333589Z TRACE quiche] 15875681f0cc60d9780ee9d4c1a436582da4a595 tx pkt Handshake version=1 dcid=21e1f1620d21d3ac scid=15875681f0cc60d9780ee9d4c1a436582da4a595 len=180 pn=1 [2025-04-30T11:47:54.976341514Z TRACE quiche] 15875681f0cc60d9780ee9d4c1a436582da4a595 tx frm CRYPTO off=0 len=176 [2025-04-30T11:47:54.976346844Z TRACE quiche::recovery::congestion::recovery] 15875681f0cc60d9780ee9d4c1a436582da4a595 timer=998.949365ms latest_rtt=0ns srtt=333ms min_rtt=333ms rttvar=166.5ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=394 app_limited=true congestion_recovery_start_time=None Rate { delivered: 0, delivered_time: Instant { tv_sec: 430, tv_nsec: 766406898 }, first_sent_time: Instant { tv_sec: 430, tv_nsec: 766406898 }, 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: 430, tv_nsec: 766406898 }, next_time: Instant { tv_sec: 430, tv_nsec: 766406898 }, 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-30T11:47:54.976388001Z TRACE quiche_server] 15875681f0cc60d9780ee9d4c1a436582da4a595 written 1200 bytes with Some(SendInfo { from: [::]:443, to: [::ffff:193.167.0.100]:50877, at: Instant { tv_sec: 430, tv_nsec: 766406898 } }) [2025-04-30T11:47:54.976393511Z TRACE quiche_server] 708eab6292ab3bbfa3cca9d8c860df6ba145e6d8 done writing [2025-04-30T11:47:54.976395846Z TRACE quiche_server] Collecting garbage [2025-04-30T11:47:54.976397899Z TRACE quiche_server] Collecting garbage [2025-04-30T11:47:54.976401646Z TRACE quiche_server] recv() would block [2025-04-30T11:47:54.976405083Z TRACE quiche_server] 15875681f0cc60d9780ee9d4c1a436582da4a595 done writing [2025-04-30T11:47:54.976407357Z TRACE quiche_server] 708eab6292ab3bbfa3cca9d8c860df6ba145e6d8 done writing [2025-04-30T11:47:54.976409471Z TRACE quiche_server] Collecting garbage [2025-04-30T11:47:54.976411545Z TRACE quiche_server] Collecting garbage [2025-04-30T11:47:55.008981667Z TRACE quiche_server] got 1200 bytes from [::ffff:193.167.0.100]:50877 to [::]:443 [2025-04-30T11:47:55.008998779Z TRACE quiche_server] got packet Initial version=1 dcid=15875681f0cc60d9780ee9d4c1a436582da4a595 scid=21e1f1620d21d3ac token= [2025-04-30T11:47:55.009010631Z TRACE quiche] 15875681f0cc60d9780ee9d4c1a436582da4a595 rx pkt Initial version=1 dcid=15875681f0cc60d9780ee9d4c1a436582da4a595 scid=21e1f1620d21d3ac token= len=22 pn=1 [2025-04-30T11:47:55.009021101Z TRACE quiche] 15875681f0cc60d9780ee9d4c1a436582da4a595 rx frm ACK delay=32 blocks=[0..0] ecn_counts=None [2025-04-30T11:47:55.009027312Z TRACE quiche::recovery::congestion::recovery] 15875681f0cc60d9780ee9d4c1a436582da4a595 packet newly acked 0 [2025-04-30T11:47:55.009046849Z TRACE quiche] 15875681f0cc60d9780ee9d4c1a436582da4a595 rx pkt Handshake version=1 dcid=15875681f0cc60d9780ee9d4c1a436582da4a595 scid=21e1f1620d21d3ac len=1103 pn=0 [2025-04-30T11:47:55.009053401Z TRACE quiche] 15875681f0cc60d9780ee9d4c1a436582da4a595 rx frm ACK delay=32 blocks=[1..1] ecn_counts=None [2025-04-30T11:47:55.009056848Z TRACE quiche::recovery::congestion::recovery] 15875681f0cc60d9780ee9d4c1a436582da4a595 packet newly acked 1 [2025-04-30T11:47:55.009060544Z TRACE quiche] 15875681f0cc60d9780ee9d4c1a436582da4a595 rx frm CRYPTO off=0 len=52 [2025-04-30T11:47:55.009074270Z TRACE quiche::tls] 15875681f0cc60d9780ee9d4c1a436582da4a595 set read secret lvl=OneRTT [2025-04-30T11:47:55.009105148Z TRACE quiche::tls] 15875681f0cc60d9780ee9d4c1a436582da4a595 write message lvl=OneRTT len=428 [2025-04-30T11:47:55.009113073Z TRACE quiche] 15875681f0cc60d9780ee9d4c1a436582da4a595 dropped epoch 1 state [2025-04-30T11:47:55.009116900Z TRACE quiche] 15875681f0cc60d9780ee9d4c1a436582da4a595 connection established: proto=Ok("hq-interop") cipher=Some(AES256_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: 1472, initial_max_data: 4611686018427387903, initial_max_stream_data_bidi_local: 1250000, initial_max_stream_data_bidi_remote: 1250000, initial_max_stream_data_uni: 1250000, initial_max_streams_bidi: 100, initial_max_streams_uni: 100, ack_delay_exponent: 3, max_ack_delay: 25, disable_active_migration: false, active_conn_id_limit: 5, initial_source_connection_id: Some(21e1f1620d21d3ac), retry_source_connection_id: None, max_datagram_frame_size: Some(65535), unknown_params: None } [2025-04-30T11:47:55.009136456Z TRACE quiche] 15875681f0cc60d9780ee9d4c1a436582da4a595 rx frm PADDING len=1026 [2025-04-30T11:47:55.009148649Z TRACE quiche] 15875681f0cc60d9780ee9d4c1a436582da4a595 dropped epoch 0 state [2025-04-30T11:47:55.009151334Z TRACE quiche_server] 15875681f0cc60d9780ee9d4c1a436582da4a595 processed 1200 bytes [2025-04-30T11:47:55.009158518Z TRACE quiche_server] got 234 bytes from [::ffff:193.167.0.100]:50877 to [::]:443 [2025-04-30T11:47:55.009161824Z TRACE quiche_server] got packet Short dcid=15875681f0cc60d9780ee9d4c1a436582da4a595 key_phase=false [2025-04-30T11:47:55.009166252Z TRACE quiche] 15875681f0cc60d9780ee9d4c1a436582da4a595 rx pkt Short dcid=15875681f0cc60d9780ee9d4c1a436582da4a595 key_phase=false len=213 pn=0 [2025-04-30T11:47:55.009171582Z TRACE quiche] 15875681f0cc60d9780ee9d4c1a436582da4a595 rx frm NEW_CONNECTION_ID seq_num=1 retire_prior_to=0 conn_id=[67, f3, 9c, 21, b1, 74, fd, 5d] reset_token=[db, 4a, 63, 34, cd, 1b, d2, 82, b8, d1, 8b, 29, 7e, 2e, a3, c9] [2025-04-30T11:47:55.009178365Z TRACE quiche] 15875681f0cc60d9780ee9d4c1a436582da4a595 rx frm NEW_CONNECTION_ID seq_num=2 retire_prior_to=0 conn_id=[86, c2, ac, f4, 2a, 74, fd, d7] reset_token=[6c, 0c, 26, d4, 19, da, 96, 65, d8, a8, 1b, 35, ff, 5c, 6d, c4] [2025-04-30T11:47:55.009183004Z TRACE quiche] 15875681f0cc60d9780ee9d4c1a436582da4a595 rx frm NEW_CONNECTION_ID seq_num=3 retire_prior_to=0 conn_id=[2f, c0, af, ac, 57, 2c, 3c, 13] reset_token=[c8, 07, 5c, bc, 23, 3e, 8b, de, e2, dd, d5, d9, 92, 57, cb, 3b] [2025-04-30T11:47:55.009187612Z TRACE quiche] 15875681f0cc60d9780ee9d4c1a436582da4a595 rx frm NEW_CONNECTION_ID seq_num=4 retire_prior_to=0 conn_id=[35, 89, e1, b9, b0, 5e, 47, b6] reset_token=[01, 9b, 62, d4, 4a, df, c9, fd, d1, b2, 72, 6b, b1, 9d, 1b, 04] [2025-04-30T11:47:55.009192822Z TRACE quiche] 15875681f0cc60d9780ee9d4c1a436582da4a595 rx frm NEW_CONNECTION_ID seq_num=5 retire_prior_to=0 conn_id=[98, 05, cc, e0, 89, fc, 3d, 43] reset_token=[e6, 13, a0, bb, 8a, 4a, 09, 51, 13, 42, 19, ff, e3, 86, 70, 33] [2025-04-30T11:47:55.009197611Z TRACE quiche] 15875681f0cc60d9780ee9d4c1a436582da4a595 rx frm NEW_CONNECTION_ID seq_num=6 retire_prior_to=0 conn_id=[cd, 02, 50, 35, d4, 53, 85, 74] reset_token=[b8, be, 0e, da, c0, cd, 74, 4d, 6f, 93, 58, 17, 0a, b1, 01, b2] [2025-04-30T11:47:55.009202400Z TRACE quiche] 15875681f0cc60d9780ee9d4c1a436582da4a595 rx frm NEW_CONNECTION_ID seq_num=7 retire_prior_to=0 conn_id=[03, 9f, f7, 42, 80, 6a, 06, 6e] reset_token=[33, 2c, b9, 6d, d8, dd, c2, d8, 57, c8, fb, f8, 31, 15, 4d, 50] [2025-04-30T11:47:55.009210956Z TRACE quiche_server] 15875681f0cc60d9780ee9d4c1a436582da4a595 processed 234 bytes [2025-04-30T11:47:55.009215564Z TRACE quiche_server] got 58 bytes from [::ffff:193.167.0.100]:50877 to [::]:443 [2025-04-30T11:47:55.009218370Z TRACE quiche_server] got packet Short dcid=15875681f0cc60d9780ee9d4c1a436582da4a595 key_phase=false [2025-04-30T11:47:55.009221956Z TRACE quiche] 15875681f0cc60d9780ee9d4c1a436582da4a595 rx pkt Short dcid=15875681f0cc60d9780ee9d4c1a436582da4a595 key_phase=false len=37 pn=1 [2025-04-30T11:47:55.009225964Z TRACE quiche] 15875681f0cc60d9780ee9d4c1a436582da4a595 rx frm STREAM id=0 off=0 len=17 fin=true [2025-04-30T11:47:55.009231895Z TRACE quiche_server] 15875681f0cc60d9780ee9d4c1a436582da4a595 processed 58 bytes [2025-04-30T11:47:55.009238337Z DEBUG quiche_apps::common] 15875681f0cc60d9780ee9d4c1a436582da4a595 response stream 0 is writable with capacity Ok(13500) [2025-04-30T11:47:55.009243777Z TRACE quiche_apps::common] 15875681f0cc60d9780ee9d4c1a436582da4a595 received 17 bytes [2025-04-30T11:47:55.009246332Z TRACE quiche_apps::common] 15875681f0cc60d9780ee9d4c1a436582da4a595 stream 0 has 17 bytes (fin? true) [2025-04-30T11:47:55.009250159Z INFO quiche_apps::common] 15875681f0cc60d9780ee9d4c1a436582da4a595 got GET request for "/www/dkajpltelu" on stream 0 [2025-04-30T11:47:55.009270006Z INFO quiche_apps::common] 15875681f0cc60d9780ee9d4c1a436582da4a595 sending response of size 5120 on stream 0 [2025-04-30T11:47:55.009277019Z TRACE quiche_server] recv() would block [2025-04-30T11:47:55.009283802Z TRACE quiche] 15875681f0cc60d9780ee9d4c1a436582da4a595 pmtud probe status false hs_con=true hs_sent=false cwnd_avail=13500 out_len=1350 left=1319 [2025-04-30T11:47:55.009291747Z TRACE quiche] 15875681f0cc60d9780ee9d4c1a436582da4a595 tx pkt Short dcid=21e1f1620d21d3ac key_phase=false len=1324 pn=2 [2025-04-30T11:47:55.009294462Z TRACE quiche] 15875681f0cc60d9780ee9d4c1a436582da4a595 tx frm ACK delay=7 blocks=[0..1] ecn_counts=None [2025-04-30T11:47:55.009297548Z TRACE quiche] 15875681f0cc60d9780ee9d4c1a436582da4a595 tx frm NEW_CONNECTION_ID seq_num=1 retire_prior_to=0 conn_id=[80, 54, 62, 16, 6d, 3e, 28, b9, 72, e7, b7, f9, e9, 50, f6, e7, 0e, e7, 61, 25] reset_token=[0f, 0d, 18, 15, ad, 7c, ac, 29, 48, b5, a1, 1f, f5, f2, 0b, 64] [2025-04-30T11:47:55.009303148Z TRACE quiche] 15875681f0cc60d9780ee9d4c1a436582da4a595 tx frm NEW_CONNECTION_ID seq_num=2 retire_prior_to=0 conn_id=[e3, d3, d2, 18, 13, b5, ed, af, e3, a2, 53, cc, 07, 81, e3, 5a, 49, 45, d4, 8c] reset_token=[80, bb, ad, 99, ca, d4, 48, 3c, 77, be, f3, 62, 5c, 89, de, 70] [2025-04-30T11:47:55.009308328Z TRACE quiche] 15875681f0cc60d9780ee9d4c1a436582da4a595 tx frm NEW_CONNECTION_ID seq_num=3 retire_prior_to=0 conn_id=[b7, 25, a7, b2, 2f, fb, 00, d7, c0, 1c, 0f, b3, 86, 04, c1, d3, f7, ca, ec, 8f] reset_token=[33, ab, 4c, 03, 67, a3, fb, 64, 18, 1f, f1, e1, 63, 73, eb, cd] [2025-04-30T11:47:55.009313538Z TRACE quiche] 15875681f0cc60d9780ee9d4c1a436582da4a595 tx frm NEW_CONNECTION_ID seq_num=4 retire_prior_to=0 conn_id=[b5, 93, d4, 3a, ae, 93, fc, e9, 99, f3, e0, 0a, f7, f3, 0e, f1, 16, ad, 5b, 54] reset_token=[97, 44, d8, a1, 3f, 05, 70, e7, 98, 93, a3, 17, 7d, 90, 3e, 11] [2025-04-30T11:47:55.009318607Z TRACE quiche] 15875681f0cc60d9780ee9d4c1a436582da4a595 tx frm HANDSHAKE_DONE [2025-04-30T11:47:55.009320851Z TRACE quiche] 15875681f0cc60d9780ee9d4c1a436582da4a595 tx frm CRYPTO off=0 len=428 [2025-04-30T11:47:55.009323186Z TRACE quiche] 15875681f0cc60d9780ee9d4c1a436582da4a595 tx frm STREAM id=0 off=0 len=721 fin=false [2025-04-30T11:47:55.009333505Z TRACE quiche::recovery::congestion::recovery] 15875681f0cc60d9780ee9d4c1a436582da4a595 timer=106.765495ms latest_rtt=32.748896ms srtt=32.715723ms min_rtt=32.710985ms rttvar=12.276096ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=1350 app_limited=true congestion_recovery_start_time=None Rate { delivered: 394, delivered_time: Instant { tv_sec: 430, tv_nsec: 799389772 }, first_sent_time: Instant { tv_sec: 430, tv_nsec: 799389772 }, end_of_app_limited: 1, last_sent_packet: 2, largest_acked: 1, rate_sample: RateSample { delivery_rate: 12044, is_app_limited: true, interval: 32.710985ms, delivered: 394, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 430, tv_nsec: 766406898 }), send_elapsed: 0ns, ack_elapsed: 32.710985ms, rtt: 32.710985ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 515807, last_update: Instant { tv_sec: 430, tv_nsec: 799389772 }, next_time: Instant { tv_sec: 430, tv_nsec: 799389772 }, 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-30T11:47:55.009352921Z TRACE quiche] 15875681f0cc60d9780ee9d4c1a436582da4a595 pmtud probe status false hs_con=true hs_sent=true cwnd_avail=12150 out_len=1350 left=1324 [2025-04-30T11:47:55.009356488Z TRACE quiche] 15875681f0cc60d9780ee9d4c1a436582da4a595 tx pkt Short dcid=21e1f1620d21d3ac key_phase=false len=1324 pn=3 [2025-04-30T11:47:55.009359023Z TRACE quiche] 15875681f0cc60d9780ee9d4c1a436582da4a595 tx frm STREAM id=0 off=721 len=1318 fin=false [2025-04-30T11:47:55.009363872Z TRACE quiche::recovery::congestion::recovery] 15875681f0cc60d9780ee9d4c1a436582da4a595 timer=106.807283ms latest_rtt=32.748896ms srtt=32.715723ms min_rtt=32.710985ms rttvar=12.276096ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=2700 app_limited=true congestion_recovery_start_time=None Rate { delivered: 394, delivered_time: Instant { tv_sec: 430, tv_nsec: 799389772 }, first_sent_time: Instant { tv_sec: 430, tv_nsec: 799389772 }, end_of_app_limited: 2, last_sent_packet: 3, largest_acked: 1, rate_sample: RateSample { delivery_rate: 12044, is_app_limited: true, interval: 32.710985ms, delivered: 394, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 430, tv_nsec: 766406898 }), send_elapsed: 0ns, ack_elapsed: 32.710985ms, rtt: 32.710985ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 515807, last_update: Instant { tv_sec: 430, tv_nsec: 799389772 }, next_time: Instant { tv_sec: 430, tv_nsec: 799389772 }, 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-30T11:47:55.009374041Z TRACE quiche] 15875681f0cc60d9780ee9d4c1a436582da4a595 pmtud probe status false hs_con=true hs_sent=true cwnd_avail=10800 out_len=1350 left=1324 [2025-04-30T11:47:55.009376986Z TRACE quiche] 15875681f0cc60d9780ee9d4c1a436582da4a595 tx pkt Short dcid=21e1f1620d21d3ac key_phase=false len=1324 pn=4 [2025-04-30T11:47:55.009379311Z TRACE quiche] 15875681f0cc60d9780ee9d4c1a436582da4a595 tx frm STREAM id=0 off=2039 len=1318 fin=false [2025-04-30T11:47:55.009383699Z TRACE quiche::recovery::congestion::recovery] 15875681f0cc60d9780ee9d4c1a436582da4a595 timer=106.809167ms latest_rtt=32.748896ms srtt=32.715723ms min_rtt=32.710985ms rttvar=12.276096ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=4050 app_limited=true congestion_recovery_start_time=None Rate { delivered: 394, delivered_time: Instant { tv_sec: 430, tv_nsec: 799389772 }, first_sent_time: Instant { tv_sec: 430, tv_nsec: 799389772 }, end_of_app_limited: 3, last_sent_packet: 4, largest_acked: 1, rate_sample: RateSample { delivery_rate: 12044, is_app_limited: true, interval: 32.710985ms, delivered: 394, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 430, tv_nsec: 766406898 }), send_elapsed: 0ns, ack_elapsed: 32.710985ms, rtt: 32.710985ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 515807, last_update: Instant { tv_sec: 430, tv_nsec: 799389772 }, next_time: Instant { tv_sec: 430, tv_nsec: 799389772 }, 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-30T11:47:55.009393056Z TRACE quiche] 15875681f0cc60d9780ee9d4c1a436582da4a595 pmtud probe status false hs_con=true hs_sent=true cwnd_avail=9450 out_len=1350 left=1324 [2025-04-30T11:47:55.009395992Z TRACE quiche] 15875681f0cc60d9780ee9d4c1a436582da4a595 tx pkt Short dcid=21e1f1620d21d3ac key_phase=false len=1324 pn=5 [2025-04-30T11:47:55.009398326Z TRACE quiche] 15875681f0cc60d9780ee9d4c1a436582da4a595 tx frm STREAM id=0 off=3357 len=1318 fin=false [2025-04-30T11:47:55.009423854Z TRACE quiche::recovery::congestion::recovery] 15875681f0cc60d9780ee9d4c1a436582da4a595 timer=106.788117ms latest_rtt=32.748896ms srtt=32.715723ms min_rtt=32.710985ms rttvar=12.276096ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=5400 app_limited=true congestion_recovery_start_time=None Rate { delivered: 394, delivered_time: Instant { tv_sec: 430, tv_nsec: 799389772 }, first_sent_time: Instant { tv_sec: 430, tv_nsec: 799389772 }, end_of_app_limited: 4, last_sent_packet: 5, largest_acked: 1, rate_sample: RateSample { delivery_rate: 12044, is_app_limited: true, interval: 32.710985ms, delivered: 394, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 430, tv_nsec: 766406898 }), send_elapsed: 0ns, ack_elapsed: 32.710985ms, rtt: 32.710985ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 515807, last_update: Instant { tv_sec: 430, tv_nsec: 799389772 }, next_time: Instant { tv_sec: 430, tv_nsec: 799389772 }, 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-30T11:47:55.009434053Z TRACE quiche] 15875681f0cc60d9780ee9d4c1a436582da4a595 pmtud probe status false hs_con=true hs_sent=true cwnd_avail=8100 out_len=1350 left=1324 [2025-04-30T11:47:55.009437099Z TRACE quiche] 15875681f0cc60d9780ee9d4c1a436582da4a595 tx pkt Short dcid=21e1f1620d21d3ac key_phase=false len=451 pn=6 [2025-04-30T11:47:55.009439463Z TRACE quiche] 15875681f0cc60d9780ee9d4c1a436582da4a595 tx frm STREAM id=0 off=4675 len=445 fin=true [2025-04-30T11:47:55.009444132Z TRACE quiche::recovery::congestion::recovery] 15875681f0cc60d9780ee9d4c1a436582da4a595 timer=106.808786ms latest_rtt=32.748896ms srtt=32.715723ms min_rtt=32.710985ms rttvar=12.276096ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=5877 app_limited=true congestion_recovery_start_time=None Rate { delivered: 394, delivered_time: Instant { tv_sec: 430, tv_nsec: 799389772 }, first_sent_time: Instant { tv_sec: 430, tv_nsec: 799389772 }, end_of_app_limited: 5, last_sent_packet: 6, largest_acked: 1, rate_sample: RateSample { delivery_rate: 12044, is_app_limited: true, interval: 32.710985ms, delivered: 394, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 430, tv_nsec: 766406898 }), send_elapsed: 0ns, ack_elapsed: 32.710985ms, rtt: 32.710985ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 515807, last_update: Instant { tv_sec: 430, tv_nsec: 799389772 }, next_time: Instant { tv_sec: 430, tv_nsec: 799389772 }, 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-30T11:47:55.009558596Z TRACE quiche_server] 15875681f0cc60d9780ee9d4c1a436582da4a595 written 5877 bytes with Some(SendInfo { from: [::]:443, to: [::ffff:193.167.0.100]:50877, at: Instant { tv_sec: 430, tv_nsec: 799389772 } }) [2025-04-30T11:47:55.009568304Z TRACE quiche_server] 708eab6292ab3bbfa3cca9d8c860df6ba145e6d8 done writing [2025-04-30T11:47:55.009572552Z TRACE quiche_server] Collecting garbage [2025-04-30T11:47:55.009575398Z TRACE quiche_server] Collecting garbage [2025-04-30T11:47:55.009581469Z TRACE quiche_server] got 58 bytes from [::ffff:193.167.0.100]:50877 to [::]:443 [2025-04-30T11:47:55.009584785Z TRACE quiche_server] got packet Short dcid=15875681f0cc60d9780ee9d4c1a436582da4a595 key_phase=false [2025-04-30T11:47:55.009590325Z TRACE quiche] 15875681f0cc60d9780ee9d4c1a436582da4a595 rx pkt Short dcid=15875681f0cc60d9780ee9d4c1a436582da4a595 key_phase=false len=37 pn=2 [2025-04-30T11:47:55.009595816Z TRACE quiche] 15875681f0cc60d9780ee9d4c1a436582da4a595 rx frm STREAM id=4 off=0 len=17 fin=true [2025-04-30T11:47:55.009607988Z TRACE quiche_server] 15875681f0cc60d9780ee9d4c1a436582da4a595 processed 58 bytes [2025-04-30T11:47:55.009610814Z DEBUG quiche_apps::common] 15875681f0cc60d9780ee9d4c1a436582da4a595 response stream 4 is writable with capacity Ok(7623) [2025-04-30T11:47:55.009615382Z TRACE quiche_apps::common] 15875681f0cc60d9780ee9d4c1a436582da4a595 received 17 bytes [2025-04-30T11:47:55.009617686Z TRACE quiche_apps::common] 15875681f0cc60d9780ee9d4c1a436582da4a595 stream 4 has 17 bytes (fin? true) [2025-04-30T11:47:55.009621133Z INFO quiche_apps::common] 15875681f0cc60d9780ee9d4c1a436582da4a595 got GET request for "/www/kczordlhps" on stream 4 [2025-04-30T11:47:55.009639147Z INFO quiche_apps::common] 15875681f0cc60d9780ee9d4c1a436582da4a595 sending response of size 10240 on stream 4 [2025-04-30T11:47:55.009646540Z TRACE quiche_server] recv() would block [2025-04-30T11:47:55.009651941Z TRACE quiche] 15875681f0cc60d9780ee9d4c1a436582da4a595 pmtud probe status false hs_con=true hs_sent=true cwnd_avail=7623 out_len=1350 left=1319 [2025-04-30T11:47:55.009655958Z TRACE quiche] 15875681f0cc60d9780ee9d4c1a436582da4a595 tx pkt Short dcid=21e1f1620d21d3ac key_phase=false len=1324 pn=7 [2025-04-30T11:47:55.009658503Z TRACE quiche] 15875681f0cc60d9780ee9d4c1a436582da4a595 tx frm ACK delay=7 blocks=[0..2] ecn_counts=None [2025-04-30T11:47:55.009661699Z TRACE quiche] 15875681f0cc60d9780ee9d4c1a436582da4a595 tx frm STREAM id=4 off=0 len=1314 fin=false [2025-04-30T11:47:55.009668412Z TRACE quiche::recovery::congestion::recovery] 15875681f0cc60d9780ee9d4c1a436582da4a595 timer=106.80018ms latest_rtt=32.748896ms srtt=32.715723ms min_rtt=32.710985ms rttvar=12.276096ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=7227 app_limited=true congestion_recovery_start_time=None Rate { delivered: 394, delivered_time: Instant { tv_sec: 430, tv_nsec: 799389772 }, first_sent_time: Instant { tv_sec: 430, tv_nsec: 799389772 }, end_of_app_limited: 5, last_sent_packet: 7, largest_acked: 1, rate_sample: RateSample { delivery_rate: 12044, is_app_limited: true, interval: 32.710985ms, delivered: 394, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 430, tv_nsec: 766406898 }), send_elapsed: 0ns, ack_elapsed: 32.710985ms, rtt: 32.710985ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 515807, last_update: Instant { tv_sec: 430, tv_nsec: 799389772 }, next_time: Instant { tv_sec: 430, tv_nsec: 799389772 }, 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-30T11:47:55.009680023Z TRACE quiche] 15875681f0cc60d9780ee9d4c1a436582da4a595 pmtud probe status false hs_con=true hs_sent=true cwnd_avail=6273 out_len=1350 left=1324 [2025-04-30T11:47:55.009682919Z TRACE quiche] 15875681f0cc60d9780ee9d4c1a436582da4a595 tx pkt Short dcid=21e1f1620d21d3ac key_phase=false len=1324 pn=8 [2025-04-30T11:47:55.009685243Z TRACE quiche] 15875681f0cc60d9780ee9d4c1a436582da4a595 tx frm STREAM id=4 off=1314 len=1318 fin=false [2025-04-30T11:47:55.009689681Z TRACE quiche::recovery::congestion::recovery] 15875681f0cc60d9780ee9d4c1a436582da4a595 timer=106.808966ms latest_rtt=32.748896ms srtt=32.715723ms min_rtt=32.710985ms rttvar=12.276096ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=8577 app_limited=true congestion_recovery_start_time=None Rate { delivered: 394, delivered_time: Instant { tv_sec: 430, tv_nsec: 799389772 }, first_sent_time: Instant { tv_sec: 430, tv_nsec: 799389772 }, end_of_app_limited: 5, last_sent_packet: 8, largest_acked: 1, rate_sample: RateSample { delivery_rate: 12044, is_app_limited: true, interval: 32.710985ms, delivered: 394, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 430, tv_nsec: 766406898 }), send_elapsed: 0ns, ack_elapsed: 32.710985ms, rtt: 32.710985ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 515807, last_update: Instant { tv_sec: 430, tv_nsec: 799389772 }, next_time: Instant { tv_sec: 430, tv_nsec: 799389772 }, 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-30T11:47:55.009702966Z TRACE quiche] 15875681f0cc60d9780ee9d4c1a436582da4a595 pmtud probe status false hs_con=true hs_sent=true cwnd_avail=4923 out_len=1350 left=1324 [2025-04-30T11:47:55.009705851Z TRACE quiche] 15875681f0cc60d9780ee9d4c1a436582da4a595 tx pkt Short dcid=21e1f1620d21d3ac key_phase=false len=1324 pn=9 [2025-04-30T11:47:55.009708156Z TRACE quiche] 15875681f0cc60d9780ee9d4c1a436582da4a595 tx frm STREAM id=4 off=2632 len=1318 fin=false [2025-04-30T11:47:55.009712404Z TRACE quiche::recovery::congestion::recovery] 15875681f0cc60d9780ee9d4c1a436582da4a595 timer=106.809558ms latest_rtt=32.748896ms srtt=32.715723ms min_rtt=32.710985ms rttvar=12.276096ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=9927 app_limited=true congestion_recovery_start_time=None Rate { delivered: 394, delivered_time: Instant { tv_sec: 430, tv_nsec: 799389772 }, first_sent_time: Instant { tv_sec: 430, tv_nsec: 799389772 }, end_of_app_limited: 5, last_sent_packet: 9, largest_acked: 1, rate_sample: RateSample { delivery_rate: 12044, is_app_limited: true, interval: 32.710985ms, delivered: 394, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 430, tv_nsec: 766406898 }), send_elapsed: 0ns, ack_elapsed: 32.710985ms, rtt: 32.710985ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 515807, last_update: Instant { tv_sec: 430, tv_nsec: 799389772 }, next_time: Instant { tv_sec: 430, tv_nsec: 799389772 }, 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-30T11:47:55.009721601Z TRACE quiche] 15875681f0cc60d9780ee9d4c1a436582da4a595 pmtud probe status false hs_con=true hs_sent=true cwnd_avail=3573 out_len=1350 left=1324 [2025-04-30T11:47:55.009724406Z TRACE quiche] 15875681f0cc60d9780ee9d4c1a436582da4a595 tx pkt Short dcid=21e1f1620d21d3ac key_phase=false len=1324 pn=10 [2025-04-30T11:47:55.009726770Z TRACE quiche] 15875681f0cc60d9780ee9d4c1a436582da4a595 tx frm STREAM id=4 off=3950 len=1318 fin=false [2025-04-30T11:47:55.009731590Z TRACE quiche::recovery::congestion::recovery] 15875681f0cc60d9780ee9d4c1a436582da4a595 timer=106.809036ms latest_rtt=32.748896ms srtt=32.715723ms min_rtt=32.710985ms rttvar=12.276096ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=11277 app_limited=true congestion_recovery_start_time=None Rate { delivered: 394, delivered_time: Instant { tv_sec: 430, tv_nsec: 799389772 }, first_sent_time: Instant { tv_sec: 430, tv_nsec: 799389772 }, end_of_app_limited: 5, last_sent_packet: 10, largest_acked: 1, rate_sample: RateSample { delivery_rate: 12044, is_app_limited: true, interval: 32.710985ms, delivered: 394, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 430, tv_nsec: 766406898 }), send_elapsed: 0ns, ack_elapsed: 32.710985ms, rtt: 32.710985ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 515807, last_update: Instant { tv_sec: 430, tv_nsec: 799389772 }, next_time: Instant { tv_sec: 430, tv_nsec: 799389772 }, 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-30T11:47:55.009743742Z TRACE quiche] 15875681f0cc60d9780ee9d4c1a436582da4a595 pmtud probe status false hs_con=true hs_sent=true cwnd_avail=2223 out_len=1350 left=1324 [2025-04-30T11:47:55.009746628Z TRACE quiche] 15875681f0cc60d9780ee9d4c1a436582da4a595 tx pkt Short dcid=21e1f1620d21d3ac key_phase=false len=1324 pn=11 [2025-04-30T11:47:55.009748952Z TRACE quiche] 15875681f0cc60d9780ee9d4c1a436582da4a595 tx frm STREAM id=4 off=5268 len=1318 fin=false [2025-04-30T11:47:55.009753210Z TRACE quiche::recovery::congestion::recovery] 15875681f0cc60d9780ee9d4c1a436582da4a595 timer=106.809477ms latest_rtt=32.748896ms srtt=32.715723ms min_rtt=32.710985ms rttvar=12.276096ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=12627 app_limited=true congestion_recovery_start_time=None Rate { delivered: 394, delivered_time: Instant { tv_sec: 430, tv_nsec: 799389772 }, first_sent_time: Instant { tv_sec: 430, tv_nsec: 799389772 }, end_of_app_limited: 5, last_sent_packet: 11, largest_acked: 1, rate_sample: RateSample { delivery_rate: 12044, is_app_limited: true, interval: 32.710985ms, delivered: 394, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 430, tv_nsec: 766406898 }), send_elapsed: 0ns, ack_elapsed: 32.710985ms, rtt: 32.710985ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 515807, last_update: Instant { tv_sec: 430, tv_nsec: 799389772 }, next_time: Instant { tv_sec: 430, tv_nsec: 799389772 }, 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-30T11:47:55.009762447Z TRACE quiche] 15875681f0cc60d9780ee9d4c1a436582da4a595 pmtud probe status false hs_con=true hs_sent=true cwnd_avail=873 out_len=1350 left=847 [2025-04-30T11:47:55.009765273Z TRACE quiche] 15875681f0cc60d9780ee9d4c1a436582da4a595 tx pkt Short dcid=21e1f1620d21d3ac key_phase=false len=847 pn=12 [2025-04-30T11:47:55.009767587Z TRACE quiche] 15875681f0cc60d9780ee9d4c1a436582da4a595 tx frm STREAM id=4 off=6586 len=841 fin=false [2025-04-30T11:47:55.009771645Z TRACE quiche::recovery::congestion::recovery] 15875681f0cc60d9780ee9d4c1a436582da4a595 timer=106.809778ms latest_rtt=32.748896ms srtt=32.715723ms min_rtt=32.710985ms rttvar=12.276096ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=13500 app_limited=false congestion_recovery_start_time=None Rate { delivered: 394, delivered_time: Instant { tv_sec: 430, tv_nsec: 799389772 }, first_sent_time: Instant { tv_sec: 430, tv_nsec: 799389772 }, end_of_app_limited: 5, last_sent_packet: 12, largest_acked: 1, rate_sample: RateSample { delivery_rate: 12044, is_app_limited: true, interval: 32.710985ms, delivered: 394, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 430, tv_nsec: 766406898 }), send_elapsed: 0ns, ack_elapsed: 32.710985ms, rtt: 32.710985ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 515807, last_update: Instant { tv_sec: 430, tv_nsec: 799389772 }, next_time: Instant { tv_sec: 430, tv_nsec: 799389772 }, 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-30T11:47:55.009889595Z TRACE quiche_server] 15875681f0cc60d9780ee9d4c1a436582da4a595 written 7623 bytes with Some(SendInfo { from: [::]:443, to: [::ffff:193.167.0.100]:50877, at: Instant { tv_sec: 430, tv_nsec: 799389772 } }) [2025-04-30T11:47:55.009920132Z TRACE quiche_server] 708eab6292ab3bbfa3cca9d8c860df6ba145e6d8 done writing [2025-04-30T11:47:55.009923679Z TRACE quiche_server] Collecting garbage [2025-04-30T11:47:55.009927225Z TRACE quiche_server] Collecting garbage [2025-04-30T11:47:55.009937865Z TRACE quiche_server] recv() would block [2025-04-30T11:47:55.009943135Z TRACE quiche] 15875681f0cc60d9780ee9d4c1a436582da4a595 pmtud probe status false hs_con=true hs_sent=true cwnd_avail=0 out_len=1350 left=0 [2025-04-30T11:47:55.009946562Z TRACE quiche_server] 15875681f0cc60d9780ee9d4c1a436582da4a595 done writing [2025-04-30T11:47:55.009948866Z TRACE quiche_server] 708eab6292ab3bbfa3cca9d8c860df6ba145e6d8 done writing [2025-04-30T11:47:55.009950980Z TRACE quiche_server] Collecting garbage [2025-04-30T11:47:55.009952994Z TRACE quiche_server] Collecting garbage [2025-04-30T11:47:55.041089682Z TRACE quiche_server] got 43 bytes from [::ffff:193.167.0.100]:50877 to [::]:443 [2025-04-30T11:47:55.041105231Z TRACE quiche_server] got packet Short dcid=15875681f0cc60d9780ee9d4c1a436582da4a595 key_phase=false [2025-04-30T11:47:55.041114598Z TRACE quiche] 15875681f0cc60d9780ee9d4c1a436582da4a595 rx pkt Short dcid=15875681f0cc60d9780ee9d4c1a436582da4a595 key_phase=false len=22 pn=3 [2025-04-30T11:47:55.041124176Z TRACE quiche] 15875681f0cc60d9780ee9d4c1a436582da4a595 rx frm ACK delay=9 blocks=[2..2] ecn_counts=None [2025-04-30T11:47:55.041130178Z TRACE quiche::recovery::congestion::recovery] 15875681f0cc60d9780ee9d4c1a436582da4a595 packet newly acked 2 [2025-04-30T11:47:55.041147901Z TRACE quiche_server] 15875681f0cc60d9780ee9d4c1a436582da4a595 processed 43 bytes [2025-04-30T11:47:55.041151718Z DEBUG quiche_apps::common] 15875681f0cc60d9780ee9d4c1a436582da4a595 response stream 4 is writable with capacity Ok(2700) [2025-04-30T11:47:55.041161546Z TRACE quiche_server] recv() would block [2025-04-30T11:47:55.041168219Z TRACE quiche] 15875681f0cc60d9780ee9d4c1a436582da4a595 pmtud probe status false hs_con=true hs_sent=true cwnd_avail=2700 out_len=1350 left=1324 [2025-04-30T11:47:55.041174270Z TRACE quiche] 15875681f0cc60d9780ee9d4c1a436582da4a595 tx pkt Short dcid=21e1f1620d21d3ac key_phase=false len=1324 pn=13 [2025-04-30T11:47:55.041177496Z TRACE quiche] 15875681f0cc60d9780ee9d4c1a436582da4a595 tx frm STREAM id=4 off=7427 len=1318 fin=false [2025-04-30T11:47:55.041186413Z TRACE quiche::recovery::congestion::recovery] 15875681f0cc60d9780ee9d4c1a436582da4a595 timer=95.293648ms latest_rtt=31.833311ms srtt=32.60542ms min_rtt=31.833311ms rttvar=9.427675ms cwnd=14850 ssthresh=18446744073709551615 bytes_in_flight=13500 app_limited=true congestion_recovery_start_time=None Rate { delivered: 1744, delivered_time: Instant { tv_sec: 430, tv_nsec: 831223083 }, first_sent_time: Instant { tv_sec: 430, tv_nsec: 799389772 }, end_of_app_limited: 5, last_sent_packet: 13, largest_acked: 2, rate_sample: RateSample { delivery_rate: 42408, is_app_limited: true, interval: 31.833311ms, delivered: 1350, prior_delivered: 394, prior_time: Some(Instant { tv_sec: 430, tv_nsec: 799389772 }), send_elapsed: 0ns, ack_elapsed: 31.833311ms, rtt: 31.833311ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 569307, last_update: Instant { tv_sec: 430, tv_nsec: 831274910 }, next_time: Instant { tv_sec: 430, tv_nsec: 831274910 }, max_datagram_size: 1350, last_packet_size: Some(0), iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(13) last_round_min_rtt=31.833311ms 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-30T11:47:55.041204537Z TRACE quiche] 15875681f0cc60d9780ee9d4c1a436582da4a595 pmtud probe status false hs_con=true hs_sent=true cwnd_avail=1350 out_len=1350 left=1324 [2025-04-30T11:47:55.041208614Z TRACE quiche] 15875681f0cc60d9780ee9d4c1a436582da4a595 tx pkt Short dcid=21e1f1620d21d3ac key_phase=false len=1324 pn=14 [2025-04-30T11:47:55.041211730Z TRACE quiche] 15875681f0cc60d9780ee9d4c1a436582da4a595 tx frm STREAM id=4 off=8745 len=1318 fin=false [2025-04-30T11:47:55.041217691Z TRACE quiche::recovery::congestion::recovery] 15875681f0cc60d9780ee9d4c1a436582da4a595 timer=95.300951ms latest_rtt=31.833311ms srtt=32.60542ms min_rtt=31.833311ms rttvar=9.427675ms cwnd=14850 ssthresh=18446744073709551615 bytes_in_flight=14850 app_limited=false congestion_recovery_start_time=None Rate { delivered: 1744, delivered_time: Instant { tv_sec: 430, tv_nsec: 831223083 }, first_sent_time: Instant { tv_sec: 430, tv_nsec: 799389772 }, end_of_app_limited: 5, last_sent_packet: 14, largest_acked: 2, rate_sample: RateSample { delivery_rate: 42408, is_app_limited: true, interval: 31.833311ms, delivered: 1350, prior_delivered: 394, prior_time: Some(Instant { tv_sec: 430, tv_nsec: 799389772 }), send_elapsed: 0ns, ack_elapsed: 31.833311ms, rtt: 31.833311ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 569307, last_update: Instant { tv_sec: 430, tv_nsec: 831274910 }, next_time: Instant { tv_sec: 430, tv_nsec: 831274910 }, max_datagram_size: 1350, last_packet_size: Some(0), iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(13) last_round_min_rtt=31.833311ms 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-30T11:47:55.041237849Z TRACE quiche] 15875681f0cc60d9780ee9d4c1a436582da4a595 pmtud probe status false hs_con=true hs_sent=true cwnd_avail=0 out_len=1350 left=0 [2025-04-30T11:47:55.041241767Z TRACE quiche_server] 15875681f0cc60d9780ee9d4c1a436582da4a595 done writing [2025-04-30T11:47:55.041303943Z TRACE quiche_server] 15875681f0cc60d9780ee9d4c1a436582da4a595 written 2700 bytes with Some(SendInfo { from: [::]:443, to: [::ffff:193.167.0.100]:50877, at: Instant { tv_sec: 430, tv_nsec: 831274910 } }) [2025-04-30T11:47:55.041314613Z TRACE quiche_server] 708eab6292ab3bbfa3cca9d8c860df6ba145e6d8 done writing [2025-04-30T11:47:55.041319361Z TRACE quiche_server] Collecting garbage [2025-04-30T11:47:55.041323620Z TRACE quiche_server] Collecting garbage [2025-04-30T11:47:55.043145437Z TRACE quiche_server] got 43 bytes from [::ffff:193.167.0.100]:50877 to [::]:443 [2025-04-30T11:47:55.043153623Z TRACE quiche_server] got packet Short dcid=15875681f0cc60d9780ee9d4c1a436582da4a595 key_phase=false [2025-04-30T11:47:55.043160135Z TRACE quiche] 15875681f0cc60d9780ee9d4c1a436582da4a595 rx pkt Short dcid=15875681f0cc60d9780ee9d4c1a436582da4a595 key_phase=false len=22 pn=4 [2025-04-30T11:47:55.043166557Z TRACE quiche] 15875681f0cc60d9780ee9d4c1a436582da4a595 rx frm ACK delay=2 blocks=[2..4] ecn_counts=None [2025-04-30T11:47:55.043170775Z TRACE quiche::recovery::congestion::recovery] 15875681f0cc60d9780ee9d4c1a436582da4a595 packet newly acked 3 [2025-04-30T11:47:55.043173880Z TRACE quiche::recovery::congestion::recovery] 15875681f0cc60d9780ee9d4c1a436582da4a595 packet newly acked 4 [2025-04-30T11:47:55.043186043Z TRACE quiche_server] 15875681f0cc60d9780ee9d4c1a436582da4a595 processed 43 bytes [2025-04-30T11:47:55.043190992Z TRACE quiche_server] recv() would block [2025-04-30T11:47:55.043196102Z TRACE quiche] 15875681f0cc60d9780ee9d4c1a436582da4a595 pmtud probe status false hs_con=true hs_sent=true cwnd_avail=5400 out_len=1350 left=1324 [2025-04-30T11:47:55.043200901Z TRACE quiche] 15875681f0cc60d9780ee9d4c1a436582da4a595 tx pkt Short dcid=21e1f1620d21d3ac key_phase=false len=183 pn=15 [2025-04-30T11:47:55.043204017Z TRACE quiche] 15875681f0cc60d9780ee9d4c1a436582da4a595 tx frm STREAM id=4 off=10063 len=177 fin=true [2025-04-30T11:47:55.043211300Z TRACE quiche::recovery::congestion::recovery] 15875681f0cc60d9780ee9d4c1a436582da4a595 timer=87.286073ms latest_rtt=33.879799ms srtt=32.762716ms min_rtt=31.833311ms rttvar=7.38535ms cwnd=17550 ssthresh=18446744073709551615 bytes_in_flight=12359 app_limited=true congestion_recovery_start_time=None Rate { delivered: 4444, delivered_time: Instant { tv_sec: 430, tv_nsec: 833269571 }, first_sent_time: Instant { tv_sec: 430, tv_nsec: 799389772 }, end_of_app_limited: 5, last_sent_packet: 15, largest_acked: 4, rate_sample: RateSample { delivery_rate: 127225, is_app_limited: true, interval: 31.833311ms, delivered: 4050, prior_delivered: 394, prior_time: Some(Instant { tv_sec: 430, tv_nsec: 799389772 }), send_elapsed: 0ns, ack_elapsed: 31.833311ms, rtt: 31.833311ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 669587, last_update: Instant { tv_sec: 430, tv_nsec: 831274910 }, next_time: Instant { tv_sec: 430, tv_nsec: 831274910 }, max_datagram_size: 1350, last_packet_size: Some(0), iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(13) last_round_min_rtt=31.833311ms current_round_min_rtt=33.879799ms css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=2 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } [2025-04-30T11:47:55.043261875Z TRACE quiche_server] 15875681f0cc60d9780ee9d4c1a436582da4a595 written 209 bytes with Some(SendInfo { from: [::]:443, to: [::ffff:193.167.0.100]:50877, at: Instant { tv_sec: 430, tv_nsec: 831274910 } }) [2025-04-30T11:47:55.043272314Z TRACE quiche_server] 708eab6292ab3bbfa3cca9d8c860df6ba145e6d8 done writing [2025-04-30T11:47:55.043277053Z TRACE quiche_server] Collecting garbage [2025-04-30T11:47:55.043281422Z TRACE quiche_server] Collecting garbage [2025-04-30T11:47:55.043288234Z TRACE quiche_server] recv() would block [2025-04-30T11:47:55.043293314Z TRACE quiche_server] 15875681f0cc60d9780ee9d4c1a436582da4a595 done writing [2025-04-30T11:47:55.043297852Z TRACE quiche_server] 708eab6292ab3bbfa3cca9d8c860df6ba145e6d8 done writing [2025-04-30T11:47:55.043301820Z TRACE quiche_server] Collecting garbage [2025-04-30T11:47:55.043304414Z TRACE quiche_server] Collecting garbage [2025-04-30T11:47:55.044652817Z TRACE quiche_server] got 43 bytes from [::ffff:193.167.0.100]:50877 to [::]:443 [2025-04-30T11:47:55.044659259Z TRACE quiche_server] got packet Short dcid=15875681f0cc60d9780ee9d4c1a436582da4a595 key_phase=false [2025-04-30T11:47:55.044664198Z TRACE quiche] 15875681f0cc60d9780ee9d4c1a436582da4a595 rx pkt Short dcid=15875681f0cc60d9780ee9d4c1a436582da4a595 key_phase=false len=22 pn=5 [2025-04-30T11:47:55.044669298Z TRACE quiche] 15875681f0cc60d9780ee9d4c1a436582da4a595 rx frm ACK delay=2 blocks=[2..6] ecn_counts=None [2025-04-30T11:47:55.044672513Z TRACE quiche::recovery::congestion::recovery] 15875681f0cc60d9780ee9d4c1a436582da4a595 packet newly acked 5 [2025-04-30T11:47:55.044674918Z TRACE quiche::recovery::congestion::recovery] 15875681f0cc60d9780ee9d4c1a436582da4a595 packet newly acked 6 [2025-04-30T11:47:55.044686339Z TRACE quiche_server] 15875681f0cc60d9780ee9d4c1a436582da4a595 processed 43 bytes [2025-04-30T11:47:55.044690137Z TRACE quiche_server] recv() would block [2025-04-30T11:47:55.044692711Z TRACE quiche_server] 15875681f0cc60d9780ee9d4c1a436582da4a595 done writing [2025-04-30T11:47:55.044694935Z TRACE quiche_server] 708eab6292ab3bbfa3cca9d8c860df6ba145e6d8 done writing [2025-04-30T11:47:55.044697070Z TRACE quiche_server] Collecting garbage [2025-04-30T11:47:55.044699053Z TRACE quiche_server] Collecting garbage [2025-04-30T11:47:55.046858723Z TRACE quiche_server] got 43 bytes from [::ffff:193.167.0.100]:50877 to [::]:443 [2025-04-30T11:47:55.046865425Z TRACE quiche_server] got packet Short dcid=15875681f0cc60d9780ee9d4c1a436582da4a595 key_phase=false [2025-04-30T11:47:55.046870585Z TRACE quiche] 15875681f0cc60d9780ee9d4c1a436582da4a595 rx pkt Short dcid=15875681f0cc60d9780ee9d4c1a436582da4a595 key_phase=false len=22 pn=6 [2025-04-30T11:47:55.046875685Z TRACE quiche] 15875681f0cc60d9780ee9d4c1a436582da4a595 rx frm ACK delay=1 blocks=[2..8] ecn_counts=None [2025-04-30T11:47:55.046879061Z TRACE quiche::recovery::congestion::recovery] 15875681f0cc60d9780ee9d4c1a436582da4a595 packet newly acked 7 [2025-04-30T11:47:55.046881966Z TRACE quiche::recovery::congestion::recovery] 15875681f0cc60d9780ee9d4c1a436582da4a595 packet newly acked 8 [2025-04-30T11:47:55.046913325Z TRACE quiche_server] 15875681f0cc60d9780ee9d4c1a436582da4a595 processed 43 bytes [2025-04-30T11:47:55.046919967Z TRACE quiche_server] recv() would block [2025-04-30T11:47:55.046923414Z TRACE quiche_server] 15875681f0cc60d9780ee9d4c1a436582da4a595 done writing [2025-04-30T11:47:55.046926299Z TRACE quiche_server] 708eab6292ab3bbfa3cca9d8c860df6ba145e6d8 done writing [2025-04-30T11:47:55.046934695Z TRACE quiche_server] Collecting garbage [2025-04-30T11:47:55.046937360Z TRACE quiche_server] Collecting garbage [2025-04-30T11:47:55.049063827Z TRACE quiche_server] got 43 bytes from [::ffff:193.167.0.100]:50877 to [::]:443 [2025-04-30T11:47:55.049070089Z TRACE quiche_server] got packet Short dcid=15875681f0cc60d9780ee9d4c1a436582da4a595 key_phase=false [2025-04-30T11:47:55.049074567Z TRACE quiche] 15875681f0cc60d9780ee9d4c1a436582da4a595 rx pkt Short dcid=15875681f0cc60d9780ee9d4c1a436582da4a595 key_phase=false len=22 pn=7 [2025-04-30T11:47:55.049079046Z TRACE quiche] 15875681f0cc60d9780ee9d4c1a436582da4a595 rx frm ACK delay=1 blocks=[2..10] ecn_counts=None [2025-04-30T11:47:55.049082172Z TRACE quiche::recovery::congestion::recovery] 15875681f0cc60d9780ee9d4c1a436582da4a595 packet newly acked 9 [2025-04-30T11:47:55.049084546Z TRACE quiche::recovery::congestion::recovery] 15875681f0cc60d9780ee9d4c1a436582da4a595 packet newly acked 10 [2025-04-30T11:47:55.049092631Z TRACE quiche_server] 15875681f0cc60d9780ee9d4c1a436582da4a595 processed 43 bytes [2025-04-30T11:47:55.049096358Z TRACE quiche_server] recv() would block [2025-04-30T11:47:55.049099484Z TRACE quiche_server] 15875681f0cc60d9780ee9d4c1a436582da4a595 done writing [2025-04-30T11:47:55.049102229Z TRACE quiche_server] 708eab6292ab3bbfa3cca9d8c860df6ba145e6d8 done writing [2025-04-30T11:47:55.049104844Z TRACE quiche_server] Collecting garbage [2025-04-30T11:47:55.049108170Z TRACE quiche_server] Collecting garbage [2025-04-30T11:47:55.050878572Z TRACE quiche_server] got 43 bytes from [::ffff:193.167.0.100]:50877 to [::]:443 [2025-04-30T11:47:55.050884082Z TRACE quiche_server] got packet Short dcid=15875681f0cc60d9780ee9d4c1a436582da4a595 key_phase=false [2025-04-30T11:47:55.050888180Z TRACE quiche] 15875681f0cc60d9780ee9d4c1a436582da4a595 rx pkt Short dcid=15875681f0cc60d9780ee9d4c1a436582da4a595 key_phase=false len=22 pn=8 [2025-04-30T11:47:55.050909370Z TRACE quiche] 15875681f0cc60d9780ee9d4c1a436582da4a595 rx frm ACK delay=1 blocks=[2..12] ecn_counts=None [2025-04-30T11:47:55.050912996Z TRACE quiche::recovery::congestion::recovery] 15875681f0cc60d9780ee9d4c1a436582da4a595 packet newly acked 11 [2025-04-30T11:47:55.050915330Z TRACE quiche::recovery::congestion::recovery] 15875681f0cc60d9780ee9d4c1a436582da4a595 packet newly acked 12 [2025-04-30T11:47:55.050923045Z TRACE quiche_server] 15875681f0cc60d9780ee9d4c1a436582da4a595 processed 43 bytes [2025-04-30T11:47:55.050926702Z TRACE quiche_server] recv() would block [2025-04-30T11:47:55.050929267Z TRACE quiche_server] 15875681f0cc60d9780ee9d4c1a436582da4a595 done writing [2025-04-30T11:47:55.050931471Z TRACE quiche_server] 708eab6292ab3bbfa3cca9d8c860df6ba145e6d8 done writing [2025-04-30T11:47:55.050933615Z TRACE quiche_server] Collecting garbage [2025-04-30T11:47:55.050935648Z TRACE quiche_server] Collecting garbage [2025-04-30T11:47:55.073957780Z TRACE quiche_server] got 43 bytes from [::ffff:193.167.0.100]:50877 to [::]:443 [2025-04-30T11:47:55.073983829Z TRACE quiche_server] got packet Short dcid=15875681f0cc60d9780ee9d4c1a436582da4a595 key_phase=false [2025-04-30T11:47:55.073994869Z TRACE quiche] 15875681f0cc60d9780ee9d4c1a436582da4a595 rx pkt Short dcid=15875681f0cc60d9780ee9d4c1a436582da4a595 key_phase=false len=22 pn=10 [2025-04-30T11:47:55.074006331Z TRACE quiche] 15875681f0cc60d9780ee9d4c1a436582da4a595 rx frm ACK delay=1 blocks=[2..14] ecn_counts=None [2025-04-30T11:47:55.074011811Z TRACE quiche::recovery::congestion::recovery] 15875681f0cc60d9780ee9d4c1a436582da4a595 packet newly acked 13 [2025-04-30T11:47:55.074014857Z TRACE quiche::recovery::congestion::recovery] 15875681f0cc60d9780ee9d4c1a436582da4a595 packet newly acked 14 [2025-04-30T11:47:55.074055884Z TRACE quiche_server] 15875681f0cc60d9780ee9d4c1a436582da4a595 processed 43 bytes [2025-04-30T11:47:55.074061644Z TRACE quiche_server] recv() would block [2025-04-30T11:47:55.074065632Z TRACE quiche_server] 15875681f0cc60d9780ee9d4c1a436582da4a595 done writing [2025-04-30T11:47:55.074068207Z TRACE quiche_server] 708eab6292ab3bbfa3cca9d8c860df6ba145e6d8 done writing [2025-04-30T11:47:55.074073817Z TRACE quiche_server] Collecting garbage [2025-04-30T11:47:55.074076061Z TRACE quiche_server] Collecting garbage [2025-04-30T11:47:55.074082834Z TRACE quiche_server] got 46 bytes from [::ffff:193.167.0.100]:50877 to [::]:443 [2025-04-30T11:47:55.074086040Z TRACE quiche_server] got packet Short dcid=15875681f0cc60d9780ee9d4c1a436582da4a595 key_phase=false [2025-04-30T11:47:55.074090128Z TRACE quiche] 15875681f0cc60d9780ee9d4c1a436582da4a595 rx pkt Short dcid=15875681f0cc60d9780ee9d4c1a436582da4a595 key_phase=false len=25 pn=11 [2025-04-30T11:47:55.074094255Z TRACE quiche] 15875681f0cc60d9780ee9d4c1a436582da4a595 rx frm ACK delay=12 blocks=[2..15] ecn_counts=None [2025-04-30T11:47:55.074097110Z TRACE quiche::recovery::congestion::recovery] 15875681f0cc60d9780ee9d4c1a436582da4a595 packet newly acked 15 [2025-04-30T11:47:55.074100717Z TRACE quiche] 15875681f0cc60d9780ee9d4c1a436582da4a595 rx frm APPLICATION_CLOSE err=0 reason=[] [2025-04-30T11:47:55.074111227Z TRACE quiche_server] 15875681f0cc60d9780ee9d4c1a436582da4a595 processed 46 bytes [2025-04-30T11:47:55.074114683Z TRACE quiche_server] recv() would block [2025-04-30T11:47:55.074116878Z TRACE quiche_server] 15875681f0cc60d9780ee9d4c1a436582da4a595 done writing [2025-04-30T11:47:55.074119011Z TRACE quiche_server] 708eab6292ab3bbfa3cca9d8c860df6ba145e6d8 done writing [2025-04-30T11:47:55.074121065Z TRACE quiche_server] Collecting garbage [2025-04-30T11:47:55.074123059Z TRACE quiche_server] Collecting garbage [2025-04-30T11:47:55.149249436Z TRACE quiche_server] timed out [2025-04-30T11:47:55.149280505Z TRACE quiche] 708eab6292ab3bbfa3cca9d8c860df6ba145e6d8 draining timeout expired [2025-04-30T11:47:55.149320499Z TRACE quiche_server] 15875681f0cc60d9780ee9d4c1a436582da4a595 done writing [2025-04-30T11:47:55.149324917Z TRACE quiche_server] 708eab6292ab3bbfa3cca9d8c860df6ba145e6d8 done writing [2025-04-30T11:47:55.149327863Z TRACE quiche_server] Collecting garbage [2025-04-30T11:47:55.149330788Z TRACE quiche_server] Collecting garbage [2025-04-30T11:47:55.149334075Z INFO quiche_server] 708eab6292ab3bbfa3cca9d8c860df6ba145e6d8 connection collected recv=9 sent=7 lost=0 retrans=0 sent_bytes=6813 recv_bytes=2867 lost_bytes=0 [local_addr=[::]:443 peer_addr=[::ffff:193.167.0.100]:50877 validation_state=Validated active=true recv=9 sent=7 lost=0 retrans=0 rtt=33.188171ms min_rtt=Some(31.855968ms) rttvar=6.177659ms cwnd=13500 sent_bytes=6813 recv_bytes=2867 lost_bytes=0 stream_retrans_bytes=0 pmtu=1350 delivery_rate=184486] [2025-04-30T11:47:55.232503435Z TRACE quiche_server] timed out [2025-04-30T11:47:55.232534062Z TRACE quiche] 15875681f0cc60d9780ee9d4c1a436582da4a595 draining timeout expired [2025-04-30T11:47:55.232574768Z TRACE quiche_server] 15875681f0cc60d9780ee9d4c1a436582da4a595 done writing [2025-04-30T11:47:55.232578816Z TRACE quiche_server] Collecting garbage [2025-04-30T11:47:55.232582833Z INFO quiche_server] 15875681f0cc60d9780ee9d4c1a436582da4a595 connection collected recv=14 sent=16 lost=0 retrans=0 sent_bytes=16803 recv_bytes=3097 lost_bytes=0 [local_addr=[::]:443 peer_addr=[::ffff:193.167.0.100]:50877 validation_state=Validated active=true recv=14 sent=16 lost=0 retrans=0 rtt=34.731399ms min_rtt=Some(31.833311ms) rttvar=4.493276ms cwnd=17550 sent_bytes=16803 recv_bytes=3097 lost_bytes=0 stream_retrans_bytes=0 pmtu=1350 delivery_rate=387610]