hsa: Add periodic timing

Type: feature

Change-Id: I18cf38d6f77e0d42212c85262f3bb769b9477b29
Signed-off-by: Nathan Skrzypczak <nathan.skrzypczak@gmail.com>

diff --git a/src/plugins/hs_apps/sapi/vpp_echo.c b/src/plugins/hs_apps/sapi/vpp_echo.c
index 739797a..84089c6 100644 (file)
--- a/src/plugins/hs_apps/sapi/vpp_echo.c
+++ b/src/plugins/hs_apps/sapi/vpp_echo.c
@@ -245,11 +245,6 @@ echo_update_count_on_session_close (echo_main_t * em, echo_session_t * s)
            echo_format_session, s, s->bytes_sent,
            s->bytes_sent + s->bytes_to_send);
 
-  ASSERT (em->stats.tx_total + s->bytes_sent <= em->stats.tx_expected);
-  ASSERT (em->stats.rx_total + s->bytes_received <= em->stats.rx_expected);
-  clib_atomic_fetch_add (&em->stats.tx_total, s->bytes_sent);
-  clib_atomic_fetch_add (&em->stats.rx_total, s->bytes_received);
-
   if (PREDICT_FALSE
       ((em->stats.rx_total == em->stats.rx_expected)
        && (em->stats.tx_total == em->stats.tx_expected)))
@@ -318,6 +313,7 @@ recv_data_chunk (echo_main_t * em, echo_session_t * s, u8 * rx_buf)
 
   s->bytes_received += n_read;
   s->bytes_to_receive -= n_read;
+  clib_atomic_fetch_add (&em->stats.rx_total, n_read);
   return n_read;
 }
 
@@ -326,6 +322,8 @@ send_data_chunk (echo_session_t * s, u8 * tx_buf, int offset, int len)
 {
   int n_sent;
   int bytes_this_chunk = clib_min (s->bytes_to_send, len - offset);
+  echo_main_t *em = &echo_main;
+
   if (!bytes_this_chunk)
     return 0;
   n_sent = app_send ((app_session_t *) s, tx_buf + offset,
@@ -334,6 +332,7 @@ send_data_chunk (echo_session_t * s, u8 * tx_buf, int offset, int len)
     return 0;
   s->bytes_to_send -= n_sent;
   s->bytes_sent += n_sent;
+  clib_atomic_fetch_add (&em->stats.tx_total, n_sent);
   return n_sent;
 }
 
@@ -758,6 +757,34 @@ echo_process_rpcs (echo_main_t * em)
     }
 }
 
+static inline void
+echo_print_periodic_stats (echo_main_t * em)
+{
+  f64 delta, now = clib_time_now (&em->clib_time);
+  echo_stats_t _st, *st = &_st;
+  echo_stats_t *lst = &em->last_stat_sampling;
+  delta = now - em->last_stat_sampling_ts;
+  if (delta < em->periodic_stats_delta)
+    return;
+
+  clib_memcpy_fast (st, &em->stats, sizeof (*st));
+  if (st->rx_total - lst->rx_total)
+    clib_warning ("RX: %U", echo_format_bytes_per_sec,
+                 (st->rx_total - lst->rx_total) / delta);
+  if (st->tx_total - lst->tx_total)
+    clib_warning ("TX: %U", echo_format_bytes_per_sec,
+                 (st->tx_total - lst->tx_total) / delta);
+  if (st->connected_count.q - lst->connected_count.q)
+    clib_warning ("conn: %d/s",
+                 st->connected_count.q - lst->connected_count.q);
+  if (st->accepted_count.q - lst->accepted_count.q)
+    clib_warning ("accept: %d/s",
+                 st->accepted_count.q - lst->accepted_count.q);
+
+  clib_memcpy_fast (lst, st, sizeof (*st));
+  em->last_stat_sampling_ts = now;
+}
+
 static void *
 echo_mq_thread_fn (void *arg)
 {
@@ -781,6 +808,9 @@ echo_mq_thread_fn (void *arg)
 
   while (em->state < STATE_DETACHED && !em->time_to_stop)
     {
+      if (em->periodic_stats_delta)
+       echo_print_periodic_stats (em);
+
       svm_msg_q_lock (mq);
       if (svm_msg_q_is_empty (mq) && svm_msg_q_timedwait (mq, 1))
        {
@@ -918,6 +948,7 @@ print_usage_and_exit (void)
           "  rx-results-diff     Rx results different to pass test\n"
           "  tx-results-diff     Tx results different to pass test\n"
           "  json                Output global stats in json\n"
+          "  stats N             Output stats evry N secs\n"
           "  log=N               Set the log level to [0: no output, 1:errors, 2:log]\n"
           "  crypto [engine]     Set the crypto engine [openssl, vpp, picotls, mbedtls]\n"
           "\n"
@@ -1052,6 +1083,8 @@ echo_process_opts (int argc, char **argv)
        em->tx_results_diff = 1;
       else if (unformat (a, "json"))
        em->output_json = 1;
+      else if (unformat (a, "stats %d", &em->periodic_stats_delta))
+       ;
       else if (unformat (a, "wait-for-gdb"))
        em->wait_for_gdb = 1;
       else if (unformat (a, "log=%d", &em->log_lvl))

diff --git a/src/plugins/hs_apps/sapi/vpp_echo_common.c b/src/plugins/hs_apps/sapi/vpp_echo_common.c
index e7829f3..0642ee6 100644 (file)
--- a/src/plugins/hs_apps/sapi/vpp_echo_common.c
+++ b/src/plugins/hs_apps/sapi/vpp_echo_common.c
@@ -257,6 +257,20 @@ echo_unformat_timing_event (unformat_input_t * input, va_list * args)
   return 1;
 }
 
+u8 *
+echo_format_bytes_per_sec (u8 * s, va_list * args)
+{
+  f64 bps = va_arg (*args, f64) * 8;
+  if (bps > 1e9)
+    return format (s, "%.3f Gb/s", bps / 1e9);
+  else if (bps > 1e6)
+    return format (s, "%.3f Mb/s", bps / 1e6);
+  else if (bps > 1e3)
+    return format (s, "%.3f Kb/s", bps / 1e3);
+  else
+    return format (s, "%.3f b/s", bps);
+}
+
 u8 *
 echo_format_timing_event (u8 * s, va_list * args)
 {

diff --git a/src/plugins/hs_apps/sapi/vpp_echo_common.h b/src/plugins/hs_apps/sapi/vpp_echo_common.h
index 978a9ec..264d169 100644 (file)
--- a/src/plugins/hs_apps/sapi/vpp_echo_common.h
+++ b/src/plugins/hs_apps/sapi/vpp_echo_common.h
@@ -263,6 +263,20 @@ typedef struct teardown_stat_
   u32 s;                       /* stream sessions */
 } teardown_stat_t;
 
+typedef struct echo_stats_
+{
+  u64 tx_total;
+  u64 rx_total;
+  u64 tx_expected;
+  u64 rx_expected;
+  teardown_stat_t reset_count; /* received reset from vpp */
+  teardown_stat_t close_count; /* received close from vpp */
+  teardown_stat_t active_count;        /* sent close to vpp */
+  teardown_stat_t clean_count; /* cleaned up stale session */
+  teardown_stat_t connected_count;     /* connected sessions count */
+  teardown_stat_t accepted_count;      /* connected sessions count */
+} echo_stats_t;
+
 typedef struct
 {
   svm_queue_t *vl_input_queue; /* vpe input queue */
@@ -320,6 +334,7 @@ typedef struct
   u32 ckpair_index;            /* Cert key pair used */
   u8 crypto_engine;            /* crypto engine used */
   u8 connect_flag;             /* flags to pass to mq connect */
+  u32 periodic_stats_delta;    /* seconds between periodic stats */
 
   u8 *appns_id;
   u64 appns_flags;
@@ -343,19 +358,9 @@ typedef struct
   uword *error_string_by_error_number;
   echo_proto_cb_vft_t *available_proto_cb_vft[TRANSPORT_N_PROTO];
 
-  struct
-  {
-    u64 tx_total;
-    u64 rx_total;
-    u64 tx_expected;
-    u64 rx_expected;
-    teardown_stat_t reset_count;       /* received reset from vpp */
-    teardown_stat_t close_count;       /* received close from vpp */
-    teardown_stat_t active_count;      /* sent close to vpp */
-    teardown_stat_t clean_count;       /* cleaned up stale session */
-    teardown_stat_t connected_count;   /* connected sessions count */
-    teardown_stat_t accepted_count;    /* connected sessions count */
-  } stats;
+  echo_stats_t stats;
+  echo_stats_t last_stat_sampling;     /* copy of stats at last sampling */
+  f64 last_stat_sampling_ts;
 
   struct                       /* Event based timing : start & end depend on CLI specified events */
   {
@@ -434,6 +439,7 @@ void echo_notify_event (echo_main_t * em, echo_test_evt_t e);
 void echo_session_print_stats (echo_main_t * em, echo_session_t * session);
 u8 *echo_format_crypto_engine (u8 * s, va_list * args);
 uword echo_unformat_crypto_engine (unformat_input_t * input, va_list * args);
+u8 *echo_format_bytes_per_sec (u8 * s, va_list * args);
 
 /* Binary API */