From: Semir Sionek <ssionek@cisco.com>
Date: Mon, 8 Sep 2025 12:18:49 +0000 (+0000)
Subject: hsa: include rtt & jitter measurements in echo client periodic reports
X-Git-Url: https://gerrit.fd.io/r/gitweb?a=commitdiff_plain;h=f6b9414b063c518b272729be9c92ea228fdfd108;p=vpp.git

hsa: include rtt & jitter measurements in echo client periodic reports

Periodic reports in echo client now include RTT measurements by default
in TCP & UDP echo-bytes runs. They can be swapped for basic jitter
measurements with report-jitter.

Type: improvement

Change-Id: I8ee0b17b49ed24799adb95ac7a3bbad383e339e1
Signed-off-by: Semir Sionek <ssionek@cisco.com>
---

diff --git a/src/plugins/hs_apps/echo_client.c b/src/plugins/hs_apps/echo_client.c
index 93e729602a8..7064f2f721d 100644
--- a/src/plugins/hs_apps/echo_client.c
+++ b/src/plugins/hs_apps/echo_client.c
@@ -90,6 +90,7 @@ update_rtt_stats (f64 session_rtt)
 {
   ec_main_t *ecm = &ec_main;
   clib_spinlock_lock (&ecm->rtt_stats.w_lock);
+  ecm->rtt_stats.last_rtt = session_rtt;
   ecm->rtt_stats.sum_rtt += session_rtt;
   ecm->rtt_stats.n_sum++;
   if (session_rtt < ecm->rtt_stats.min_rtt)
@@ -99,6 +100,24 @@ update_rtt_stats (f64 session_rtt)
   clib_spinlock_unlock (&ecm->rtt_stats.w_lock);
 }
 
+static void
+update_rtt_stats_tcp (ec_session_t *es)
+{
+  session_t *s = session_get_from_handle_if_valid (es->vpp_session_handle);
+  if (s)
+    {
+      transport_connection_t *tc;
+      tcp_connection_t *tcpc;
+      tc = transport_get_connection (TRANSPORT_PROTO_TCP, s->connection_index,
+				     s->thread_index);
+      if (PREDICT_TRUE (tc != NULL))
+	{
+	  tcpc = tcp_get_connection_from_transport (tc);
+	  update_rtt_stats (tcpc->srtt * TCP_TICK);
+	}
+    }
+}
+
 static void
 send_data_chunk (ec_main_t *ecm, ec_session_t *es)
 {
@@ -169,7 +188,7 @@ send_data_chunk (ec_main_t *ecm, ec_session_t *es)
 	  bytes_this_chunk = clib_min (bytes_this_chunk, max_enqueue);
 	  if (!ecm->throughput)
 	    bytes_this_chunk = clib_min (bytes_this_chunk, 1460);
-	  if (ecm->cfg.test_bytes)
+	  if (ecm->include_buffer_offset)
 	    {
 	      /* Include buffer offset info to also be able to verify
 	       * out-of-order packets */
@@ -178,6 +197,13 @@ send_data_chunk (ec_main_t *ecm, ec_session_t *es)
 		{ (u8 *) &test_buf_offset, sizeof (u32) },
 		{ test_data + test_buf_offset, bytes_this_chunk }
 	      };
+	      if (ecm->echo_bytes &&
+		  ((es->rtt_stat & EC_UDP_RTT_TX_FLAG) == 0))
+		{
+		  es->rtt_udp_buffer_offset = test_buf_offset;
+		  es->send_rtt = vlib_time_now (vlib_get_main ());
+		  es->rtt_stat |= EC_UDP_RTT_TX_FLAG;
+		}
 	      rv = app_send_dgram_segs ((app_session_t *) es, data_segs, 2,
 					bytes_this_chunk + sizeof (u32), 0);
 	      if (rv)
@@ -236,7 +262,7 @@ receive_data_chunk (ec_worker_t *wrk, ec_session_t *es)
   u8 *rx_buf_start = wrk->rx_buf;
   u32 test_buf_offset = es->bytes_received;
 
-  if (ecm->cfg.test_bytes)
+  if (ecm->include_buffer_offset)
     {
       n_read =
 	app_recv ((app_session_t *) es, wrk->rx_buf, vec_len (wrk->rx_buf));
@@ -275,8 +301,21 @@ receive_data_chunk (ec_worker_t *wrk, ec_session_t *es)
       if (ecm->transport_proto == TRANSPORT_PROTO_UDP && ecm->echo_bytes &&
 	  (es->rtt_stat & EC_UDP_RTT_RX_FLAG) == 0)
 	{
-	  es->rtt_stat |= EC_UDP_RTT_RX_FLAG;
-	  update_rtt_stats (vlib_time_now (vlib_get_main ()) - es->send_rtt);
+	  /* For periodic reports, verify that the buffer offset matches and we
+	   * received the expected dgram, otherwise just match up the first
+	   * received one */
+	  if (((test_buf_offset == es->rtt_udp_buffer_offset) &&
+	       ecm->report_interval) ||
+	      !ecm->report_interval)
+	    {
+	      f64 rtt;
+	      es->rtt_stat |= EC_UDP_RTT_RX_FLAG;
+	      rtt = vlib_time_now (vlib_get_main ()) - es->send_rtt;
+	      if (ecm->rtt_stats.last_rtt > 0)
+		es->jitter =
+		  clib_abs (rtt * 1000 - ecm->rtt_stats.last_rtt * 1000);
+	      update_rtt_stats (rtt);
+	    }
 	}
       if (ecm->cfg.verbose)
 	{
@@ -388,12 +427,6 @@ ec_node_fn (vlib_main_t *vm, vlib_node_runtime_t *node, vlib_frame_t *frame)
 
       if (es->bytes_to_send > 0)
 	{
-	  if (ecm->transport_proto == TRANSPORT_PROTO_UDP && ecm->echo_bytes &&
-	      (es->rtt_stat & EC_UDP_RTT_TX_FLAG) == 0)
-	    {
-	      es->send_rtt = time_now;
-	      es->rtt_stat |= EC_UDP_RTT_TX_FLAG;
-	    }
 	  send_data_chunk (ecm, es);
 	  if (ecm->throughput)
 	    es->time_to_send += ecm->pacing_window_len;
@@ -416,17 +449,7 @@ ec_node_fn (vlib_main_t *vm, vlib_node_runtime_t *node, vlib_frame_t *frame)
 	  if (s)
 	    {
 	      if (ecm->transport_proto == TRANSPORT_PROTO_TCP)
-		{
-		  transport_connection_t *tc;
-		  tcp_connection_t *tcpc;
-		  tc = transport_get_connection (
-		    TRANSPORT_PROTO_TCP, s->connection_index, s->thread_index);
-		  if (PREDICT_TRUE (tc != NULL))
-		    {
-		      tcpc = tcp_get_connection_from_transport (tc);
-		      update_rtt_stats (tcpc->srtt * TCP_TICK);
-		    }
-		}
+		update_rtt_stats_tcp (es);
 
 	      vnet_disconnect_args_t _a, *a = &_a;
 	      a->handle = session_handle (s);
@@ -507,6 +530,8 @@ ec_reset_runtime_config (ec_main_t *ecm)
   ecm->last_total_rx_bytes = 0;
   ecm->last_total_rx_dgrams = 0;
   ecm->last_total_tx_dgrams = 0;
+  ecm->report_interval_jitter = 0;
+  ecm->include_buffer_offset = 0;
   clib_memset (&ecm->rtt_stats, 0, sizeof (ec_rttstat_t));
   ecm->rtt_stats.min_rtt = CLIB_F64_MAX;
   if (ecm->rtt_stats.w_lock == NULL)
@@ -1296,7 +1321,8 @@ static void
 ec_print_periodic_stats (vlib_main_t *vm, bool print_header, bool print_footer)
 {
   ec_main_t *ecm = &ec_main;
-  f64 time_now, print_delta, interval_start, interval_end;
+  f64 time_now, print_delta, interval_start, interval_end, rtt = 0.0,
+							   jitter = 0.0;
   u64 total_bytes,
     received_bytes = 0, sent_bytes = 0, dgrams_sent = 0, dgrams_received = 0,
     last_total_bytes = ecm->last_total_tx_bytes + ecm->last_total_rx_bytes;
@@ -1312,6 +1338,18 @@ ec_print_periodic_stats (vlib_main_t *vm, bool print_header, bool print_footer)
 	    {
 	      dgrams_received += sess->dgrams_received;
 	      dgrams_sent += sess->dgrams_sent;
+	      sess->rtt_stat = 0;
+	      jitter += sess->jitter;
+	    }
+	  else if (ecm->transport_proto == TRANSPORT_PROTO_TCP)
+	    {
+	      session_t *s =
+		session_get_from_handle_if_valid (sess->vpp_session_handle);
+	      if (s)
+		{
+		  update_rtt_stats_tcp (sess);
+		  rtt += ecm->rtt_stats.last_rtt;
+		}
 	    }
 	}
     }
@@ -1323,76 +1361,87 @@ ec_print_periodic_stats (vlib_main_t *vm, bool print_header, bool print_footer)
 
   if (ecm->transport_proto == TRANSPORT_PROTO_UDP)
     {
-      u8 *tput = 0;
+      jitter /= ecm->n_clients;
+      rtt = ecm->rtt_stats.last_rtt * 1000;
       if (print_header)
 	{
 	  ec_cli ("-----------------------------------------------------------"
-		  "-------------");
+		  "-------------------------");
 	  if (ecm->report_interval_total)
-	    ec_cli ("Run time (s)  Transmitted   Received   Throughput   "
-		    "Sent/received dgrams");
+	    ec_cli (
+	      "Run time (s)  Transmitted   Received   Throughput   "
+	      "%sSent/received dgrams",
+	      (ecm->report_interval_jitter ? "Jitter      " : "Roundtrip   "));
 	  else
-	    ec_cli ("Interval (s)  Transmitted   Received   Throughput   "
-		    "Sent/received dgrams");
+	    ec_cli (
+	      "Interval (s)  Transmitted   Received   Throughput   "
+	      "%sSent/received dgrams",
+	      (ecm->report_interval_jitter ? "Jitter      " : "Roundtrip   "));
 	}
       if (ecm->report_interval_total)
 	{
-	  tput =
-	    format (tput, "%Ub/s", format_base10,
-		    flt_round_nearest ((f64) total_bytes /
-				       (time_now - ecm->test_start_time)) *
-		      8);
-	  ec_cli ("%-13.1f %-13U %-10U %-12s %llu/%llu", interval_end,
-		  format_base10, sent_bytes, format_base10, received_bytes,
-		  tput, dgrams_sent, dgrams_received);
+	  ec_cli ("%-13.1f %-13U %-10U %+9Ub/s %+9.3fms %llu/%llu",
+		  interval_end, format_base10, sent_bytes, format_base10,
+		  received_bytes, format_base10,
+		  flt_round_nearest ((f64) (total_bytes - last_total_bytes) /
+				     print_delta) *
+		    8,
+		  (ecm->report_interval_jitter ? jitter : rtt), dgrams_sent,
+		  dgrams_received);
 	}
       else
 	{
-	  tput =
-	    format (tput, "%Ub/s", format_base10,
-		    flt_round_nearest ((f64) (total_bytes - last_total_bytes) /
-				       print_delta) *
-		      8);
-	  ec_cli ("%.1f-%-9.1f %-13U %-10U %-12s %llu/%llu", interval_start,
-		  interval_end, format_base10,
+	  rtt /= ecm->n_clients;
+	  ec_cli ("%.1f-%-9.1f %-13U %-10U %+9Ub/s %+9.3fms %llu/%llu",
+		  interval_start, interval_end, format_base10,
 		  sent_bytes - ecm->last_total_tx_bytes, format_base10,
-		  received_bytes - ecm->last_total_rx_bytes, tput,
+		  received_bytes - ecm->last_total_rx_bytes, format_base10,
+		  flt_round_nearest ((f64) (total_bytes - last_total_bytes) /
+				     print_delta) *
+		    8,
+		  (ecm->report_interval_jitter ? jitter : rtt),
 		  (dgrams_sent - ecm->last_total_tx_dgrams),
 		  (dgrams_received - ecm->last_total_rx_dgrams));
 	}
       if (print_footer)
 	ec_cli ("-------------------------------------------------------------"
-		"-----------");
+		"-----------------------");
       ecm->last_total_tx_dgrams = dgrams_sent;
       ecm->last_total_rx_dgrams = dgrams_received;
-      vec_free (tput);
     }
   else
     {
       if (print_header)
 	{
-	  ec_cli ("-------------------------------------------------");
+	  ec_cli (
+	    "-------------------------------------------------------------");
 	  if (ecm->report_interval_total)
-	    ec_cli ("Run time (s)  Transmitted   Received   Throughput");
+	    ec_cli (
+	      "Run time (s)  Transmitted   Received   Throughput   Roundtrip");
 	  else
-	    ec_cli ("Interval (s)  Transmitted   Received   Throughput");
+	    ec_cli (
+	      "Interval (s)  Transmitted   Received   Throughput   Roundtrip");
 	}
       if (ecm->report_interval_total)
-	ec_cli ("%-13.1f %-13U %-10U %Ub/s", interval_end, format_base10,
-		sent_bytes, format_base10, received_bytes, format_base10,
+	ec_cli ("%-13.1f %-13U %-10U %+9Ub/s %+7.3fms", interval_end,
+		format_base10, sent_bytes, format_base10, received_bytes,
+		format_base10,
 		flt_round_nearest ((f64) total_bytes /
 				   (time_now - ecm->test_start_time)) *
-		  8);
+		  8,
+		rtt * 1000);
       else
-	ec_cli ("%.1f-%-9.1f %-13U %-10U %Ub/s", interval_start, interval_end,
-		format_base10, sent_bytes - ecm->last_total_tx_bytes,
-		format_base10, received_bytes - ecm->last_total_rx_bytes,
-		format_base10,
+	ec_cli ("%.1f-%-9.1f %-13U %-10U %+9Ub/s %+7.3fms", interval_start,
+		interval_end, format_base10,
+		sent_bytes - ecm->last_total_tx_bytes, format_base10,
+		received_bytes - ecm->last_total_rx_bytes, format_base10,
 		flt_round_nearest (((f64) (total_bytes - last_total_bytes)) /
 				   print_delta) *
-		  8);
+		  8,
+		rtt * 1000);
       if (print_footer)
-	ec_cli ("-------------------------------------------------");
+	ec_cli (
+	  "-------------------------------------------------------------");
     }
   ecm->last_print_time = time_now;
   ecm->last_total_tx_bytes = sent_bytes;
@@ -1440,7 +1489,7 @@ ec_print_final_stats (vlib_main_t *vm, f64 total_delta)
   ec_cli ("%u bytes/second %s",
 	  flt_round_nearest (((f64) total_bytes) / (total_delta)),
 	  transfer_type);
-  ec_cli ("%UBps %s", format_base10,
+  ec_cli ("%UB/s %s", format_base10,
 	  flt_round_nearest (((f64) total_bytes) / (total_delta)),
 	  transfer_type);
 }
@@ -1513,12 +1562,14 @@ ec_command_fn (vlib_main_t *vm, unformat_input_t *input,
       else if (unformat (line_input, "client-batch %d",
 			 &ecm->connections_per_batch))
 	;
-      else if (unformat (line_input, "report-interval %u",
-			 &ecm->report_interval))
-	;
+      else if (unformat (line_input, "report-jitter"))
+	ecm->report_interval_jitter = 1;
       else if (unformat (line_input, "report-interval-total %u",
 			 &ecm->report_interval))
 	ecm->report_interval_total = 1;
+      else if (unformat (line_input, "report-interval %u",
+			 &ecm->report_interval))
+	;
       else if (unformat (line_input, "report-interval"))
 	ecm->report_interval = 1;
       else if (unformat (line_input, "appns %_%v%_", &ecm->appns_id))
@@ -1584,6 +1635,10 @@ parse_config:
   else
     ecm->cfg.test = HS_TEST_TYPE_UNI;
 
+  if (ecm->cfg.test_bytes ||
+      (ecm->echo_bytes && ecm->transport_proto == TRANSPORT_PROTO_UDP))
+    ecm->include_buffer_offset = 1;
+
   ec_ctrl_connect ();
   ec_wait_for_signal (EC_CLI_CFG_SYNC);
 
@@ -1784,7 +1839,8 @@ VLIB_CLI_COMMAND (ec_command, static) = {
     "[run-time <time>][syn-timeout <time>][echo-bytes][fifo-size <size>]"
     "[private-segment-count <count>][private-segment-size <bytes>[m|g]]"
     "[preallocate-fifos][preallocate-sessions][client-batch <batch-size>]"
-    "[throughput <bytes>[m|g]][report-interval[-total] <time>][uri "
+    "[throughput <bytes>[m|g]][report-interval[-total] "
+    "<time>][report-jitter][[uri "
     "<tcp://ip/port>]"
     "[test-bytes][verbose]",
   .function = ec_command_fn,
diff --git a/src/plugins/hs_apps/echo_client.h b/src/plugins/hs_apps/echo_client.h
index 787ae7ed102..51310386123 100644
--- a/src/plugins/hs_apps/echo_client.h
+++ b/src/plugins/hs_apps/echo_client.h
@@ -27,6 +27,7 @@ typedef struct ec_rttstat_
   f64 min_rtt;
   f64 max_rtt;
   f64 sum_rtt;
+  f64 last_rtt;
   u32 n_sum;
   clib_spinlock_t w_lock;
 } ec_rttstat_t;
@@ -49,6 +50,8 @@ typedef struct ec_session_
   u64 bytes_paced_current;
   f64 send_rtt;
   u8 rtt_stat;
+  u32 rtt_udp_buffer_offset;
+  f64 jitter;
   u64 dgrams_sent;
   u64 dgrams_received;
 } ec_session_t;
@@ -128,9 +131,10 @@ typedef struct
   f64 test_timeout;			/**< Test timeout (s) */
   f64 run_time;				/**< Length of a test (s) */
   u64 max_chunk_bytes;
-  u64 report_interval;	    /**< Time between periodic raports (s) */
+  u64 report_interval;	    /**< Time between periodic reports (s) */
   u8 report_interval_total; /**< Shown data are totals since the start of the
 			       test */
+  u8 report_interval_jitter; /**< Report jitter in periodic reports */
 
   /*
    * Flags
@@ -145,6 +149,7 @@ typedef struct
   u8 test_failed;
   u8 transport_proto;
   u8 barrier_acq_needed;
+  u8 include_buffer_offset;
 
   vlib_main_t *vlib_main;
 } ec_main_t;
diff --git a/test-c/hs-test/echo_test.go b/test-c/hs-test/echo_test.go
index 6e26f87a7fd..a3a95909bd4 100644
--- a/test-c/hs-test/echo_test.go
+++ b/test-c/hs-test/echo_test.go
@@ -8,7 +8,7 @@ import (
 )
 
 func init() {
-	RegisterVethTests(EchoBuiltinTest, EchoBuiltinBandwidthTest, EchoBuiltinEchobytesTest, EchoBuiltinRoundtripTest, EchoBuiltinTestbytesTest, EchoBuiltinPeriodicReportTest, EchoBuiltinPeriodicReportTotalTest, TlsSingleConnectionTest)
+	RegisterVethTests(EchoBuiltinTest, EchoBuiltinBandwidthTest, EchoBuiltinEchobytesTest, EchoBuiltinRoundtripTest, EchoBuiltinTestbytesTest, EchoBuiltinPeriodicReportTest, EchoBuiltinPeriodicReportTotalTest, TlsSingleConnectionTest, EchoBuiltinPeriodicReportUDPTest)
 	RegisterVethMWTests(TcpWithLossTest)
 	RegisterSoloVeth6Tests(TcpWithLoss6Test)
 }
@@ -58,7 +58,7 @@ func EchoBuiltinBandwidthTest(s *VethsSuite) {
 }
 
 func EchoBuiltinPeriodicReportTotalTest(s *VethsSuite) {
-	regex := regexp.MustCompile(`(\d?\.\d)\s+(\d+\.\d+)M\s+0\s+\d+\.\d+Mb/s`)
+	regex := regexp.MustCompile(`(\d?\.\d)\s+(\d+\.\d+)M\s+0\s+\d+\.\d+Mb/s\s+(\d?\.\d+)ms`)
 	serverVpp := s.Containers.ServerVpp.VppInstance
 
 	serverVpp.Vppctl("test echo server " +
@@ -79,6 +79,8 @@ func EchoBuiltinPeriodicReportTotalTest(s *VethsSuite) {
 		for i := 0; i < 4; i++ {
 			mbytes, _ := strconv.ParseFloat(matches[i][2], 32)
 			s.AssertEqualWithinThreshold(mbytes, 2*(i+1), 0.1)
+			rtt, _ := strconv.ParseFloat(matches[i][3], 32)
+			s.AssertGreaterThan(rtt, 0.0)
 		}
 		// Verify reporting times
 		s.AssertEqual(matches[0][1], "1.0")
@@ -90,8 +92,51 @@ func EchoBuiltinPeriodicReportTotalTest(s *VethsSuite) {
 	}
 }
 
+func EchoBuiltinPeriodicReportUDPTest(s *VethsSuite) {
+	regex := regexp.MustCompile(`(\d?\.\d)-(\d?.\d)\s+(\d+\.\d+)M\s+\d?\.\d+M\s+\d+\.\d+Mb/s\s+(\d?\.\d+)ms\s+(\d+)/(\d+)`)
+	serverVpp := s.Containers.ServerVpp.VppInstance
+
+	serverVpp.Vppctl("test echo server " +
+		" uri udp://" + s.Interfaces.Server.Ip4AddressString() + "/" + s.Ports.Port1)
+
+	clientVpp := s.Containers.ClientVpp.VppInstance
+
+	o := clientVpp.Vppctl("test echo client bytes 6000k throughput 12m report-interval 1 echo-bytes" +
+		" uri udp://" + s.Interfaces.Server.Ip4AddressString() + "/" + s.Ports.Port1)
+	s.Log(o)
+	s.AssertContains(o, "Test started")
+	s.AssertContains(o, "Test finished")
+	if regex.MatchString(o) {
+		matches := regex.FindAllStringSubmatch(o, -1)
+		// Check we got a correct number of reports
+		s.AssertEqual(4, len(matches))
+		// Verify TX numbers
+		for i := 0; i < 4; i++ {
+			mbytes, _ := strconv.ParseFloat(matches[i][3], 32)
+			s.AssertEqualWithinThreshold(mbytes, 1.5, 0.1)
+			rtt, _ := strconv.ParseFloat(matches[i][4], 32)
+			s.AssertGreaterThan(rtt, 0.0)
+			dgramsSent, _ := strconv.ParseUint(matches[i][5], 10, 32)
+			s.AssertEqualWithinThreshold(dgramsSent, 2048, 20)
+			dgramsReceived, _ := strconv.ParseUint(matches[i][6], 10, 32)
+			s.AssertEqualWithinThreshold(dgramsReceived, 2048, 50)
+		}
+		// Verify time interval numbers
+		s.AssertEqual(matches[0][1], "0.0")
+		s.AssertEqual(matches[0][2], "1.0")
+		s.AssertEqual(matches[1][1], "1.0")
+		s.AssertEqual(matches[1][2], "2.0")
+		s.AssertEqual(matches[2][1], "2.0")
+		s.AssertEqual(matches[2][2], "3.0")
+		s.AssertEqual(matches[3][1], "3.0")
+		s.AssertEqual(matches[3][2], "4.0")
+	} else {
+		s.AssertEmpty("invalid echo test client output")
+	}
+}
+
 func EchoBuiltinPeriodicReportTest(s *VethsSuite) {
-	regex := regexp.MustCompile(`(\d?\.\d)-(\d?.\d)\s+(\d+\.\d+)M\s+0\s+\d+\.\d+Mb/s`)
+	regex := regexp.MustCompile(`(\d?\.\d)-(\d?.\d)\s+(\d+\.\d+)M\s+0\s+\d+\.\d+Mb/s\s+(\d?\.\d+)ms`)
 	serverVpp := s.Containers.ServerVpp.VppInstance
 
 	serverVpp.Vppctl("test echo server " +
@@ -112,6 +157,8 @@ func EchoBuiltinPeriodicReportTest(s *VethsSuite) {
 		for i := 0; i < 4; i++ {
 			mbytes, _ := strconv.ParseFloat(matches[i][3], 32)
 			s.AssertEqualWithinThreshold(mbytes, 2, 0.1)
+			rtt, _ := strconv.ParseFloat(matches[i][4], 32)
+			s.AssertGreaterThan(rtt, 0.0)
 		}
 		// Verify time interval numbers
 		s.AssertEqual(matches[0][1], "0.0")