From ff6cdcca2dc741bb3b0d3757e83ada523c7a4a45 Mon Sep 17 00:00:00 2001 From: Nathan Skrzypczak Date: Thu, 19 Dec 2019 11:54:10 +0100 Subject: [PATCH 1/1] hsa: Add periodic timing Type: feature Change-Id: I18cf38d6f77e0d42212c85262f3bb769b9477b29 Signed-off-by: Nathan Skrzypczak --- src/plugins/hs_apps/sapi/vpp_echo.c | 43 ++++++++++++++++++++++++++---- src/plugins/hs_apps/sapi/vpp_echo_common.c | 14 ++++++++++ src/plugins/hs_apps/sapi/vpp_echo_common.h | 32 +++++++++++++--------- 3 files changed, 71 insertions(+), 18 deletions(-) diff --git a/src/plugins/hs_apps/sapi/vpp_echo.c b/src/plugins/hs_apps/sapi/vpp_echo.c index 739797a28e2..84089c6b512 100644 --- 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 e7829f3ab89..0642ee67429 100644 --- 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 978a9ec00aa..264d1695af0 100644 --- 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 */ -- 2.16.6