From 20de85b6da7e0b6dd0d73bc8358e7c67564d0c36 Mon Sep 17 00:00:00 2001 From: Steven Luong Date: Mon, 17 Oct 2022 10:39:06 -0700 Subject: session: add session debug cli - add session debug cli to enable fine control of which event logs are enable/disable with below syntax session debug {show | group level } list may be entered with a dash, "0-4" or it may be entered with a comma, "0,1,4" - fix compilation errors when SESSION_EVT is enable - change SESSION_EVT_FREE_HANDLER to use DEC_SESSION_ED instead of DEC_SESSION_ETD because the transport may already be free when the handler is called Type: improvement Signed-off-by: Steven Luong Change-Id: Iab2989e0a847bb59002ef16494eebcc1d112b2ae --- src/vnet/session/session.c | 13 ++-- src/vnet/session/session_debug.c | 86 +++++++++++++++++++++++++- src/vnet/session/session_debug.h | 127 ++++++++++++++++++++++++++------------- src/vnet/session/session_node.c | 4 +- 4 files changed, 176 insertions(+), 54 deletions(-) (limited to 'src/vnet') diff --git a/src/vnet/session/session.c b/src/vnet/session/session.c index 54d9b22c838..4c57b1ac9bb 100644 --- a/src/vnet/session/session.c +++ b/src/vnet/session/session.c @@ -216,15 +216,12 @@ session_alloc (u32 thread_index) void session_free (session_t * s) { - if (CLIB_DEBUG) - { - u8 thread_index = s->thread_index; - clib_memset (s, 0xFA, sizeof (*s)); - pool_put (session_main.wrk[thread_index].sessions, s); - return; - } + session_worker_t *wrk = &session_main.wrk[s->thread_index]; + SESSION_EVT (SESSION_EVT_FREE, s); - pool_put (session_main.wrk[s->thread_index].sessions, s); + if (CLIB_DEBUG) + clib_memset (s, 0xFA, sizeof (*s)); + pool_put (wrk->sessions, s); } u8 diff --git a/src/vnet/session/session_debug.c b/src/vnet/session/session_debug.c index e4efe1b244e..a6c4adb2bdc 100644 --- a/src/vnet/session/session_debug.c +++ b/src/vnet/session/session_debug.c @@ -117,12 +117,96 @@ session_debug_init (void) sdm->wrk[thread].start_time = session_dbg_time_now (thread); } } + +static const char *session_evt_grp_str[] = { +#define _(sym, str) str, + foreach_session_evt_grp +#undef _ +}; + +static void +session_debug_show_groups (vlib_main_t *vm) +{ + session_dbg_main_t *sdm = &session_dbg_main; + int i = 0; + + vlib_cli_output (vm, "%-10s%-30s%-10s", "Index", "Group", "Level"); + + for (i = 0; i < SESSION_EVT_N_GRP; i++) + vlib_cli_output (vm, "%-10d%-30s%-10d", i, session_evt_grp_str[i], + sdm->grp_dbg_lvl[i]); +} + +static clib_error_t * +session_debug_fn (vlib_main_t *vm, unformat_input_t *input, + vlib_cli_command_t *cmd) +{ + session_dbg_main_t *sdm = &session_dbg_main; + u32 group, level = ~0; + clib_error_t *error = 0; + u8 is_show = 0; + uword *bitmap = 0; + + while (unformat_check_input (input) != UNFORMAT_END_OF_INPUT) + { + if (unformat (input, "show")) + is_show = 1; + else if (unformat (input, "group %U", unformat_bitmap_list, &bitmap)) + ; + else if (unformat (input, "level %d", &level)) + ; + else + { + error = clib_error_return (0, "unknown input `%U'", + format_unformat_error, input); + goto done; + } + } + + if (is_show) + { + session_debug_show_groups (vm); + goto done; + } + if (level == ~0) + { + vlib_cli_output (vm, "level must be entered"); + goto done; + } + + group = clib_bitmap_last_set (bitmap); + if (group == ~0) + { + vlib_cli_output (vm, "group must be entered"); + goto done; + } + if (group >= SESSION_EVT_N_GRP) + { + vlib_cli_output (vm, "group out of bounds"); + goto done; + } + clib_bitmap_foreach (group, bitmap) + sdm->grp_dbg_lvl[group] = level; + +done: + + clib_bitmap_free (bitmap); + return error; +} + +VLIB_CLI_COMMAND (session_debug_command, static) = { + .path = "session debug", + .short_help = "session debug {show | debug group level }", + .function = session_debug_fn, + .is_mp_safe = 1, +}; + #else void session_debug_init (void) { } -#endif +#endif /* SESSION_DEBUG */ void dump_thread_0_event_queue (void) diff --git a/src/vnet/session/session_debug.h b/src/vnet/session/session_debug.h index 4f49ea1d2f2..588d58c790c 100644 --- a/src/vnet/session/session_debug.h +++ b/src/vnet/session/session_debug.h @@ -19,26 +19,56 @@ #include #include -#define foreach_session_dbg_evt \ - _(ENQ, "enqueue") \ - _(DEQ, "dequeue") \ - _(DEQ_NODE, "dequeue") \ - _(POLL_GAP_TRACK, "poll gap track") \ - _(POLL_DISPATCH_TIME, "dispatch time") \ - _(DISPATCH_START, "dispatch start") \ - _(DISPATCH_END, "dispatch end") \ - _(FREE, "session free") \ - _(DSP_CNTRS, "dispatch counters") \ - _(IO_EVT_COUNTS, "io evt counts") \ - _(EVT_COUNTS, "ctrl evt counts") \ +#define foreach_session_dbg_evt \ + _ (ENQ, DEQ_EVTS, 1, "enqueue") \ + _ (DEQ, DEQ_EVTS, 1, "dequeue") \ + _ (DEQ_NODE, DISPATCH_DBG, 1, "dequeue") \ + _ (POLL_GAP_TRACK, EVT_POLL_DBG, 1, "poll gap track") \ + _ (POLL_DISPATCH_TIME, EVT_POLL_DBG, 1, "dispatch time") \ + _ (DISPATCH_START, CLOCKS_EVT_DBG, 1, "dispatch start") \ + _ (DISPATCH_END, CLOCKS_EVT_DBG, 1, "dispatch end") \ + _ (DSP_CNTRS, CLOCKS_EVT_DBG, 1, "dispatch counters") \ + _ (FREE, SM, 1, "session free") \ + _ (IO_EVT_COUNTS, COUNTS_EVT_DBG, 1, "io evt counts") \ + _ (COUNTS, COUNTS_EVT_DBG, 1, "ctrl evt counts") typedef enum _session_evt_dbg { -#define _(sym, str) SESSION_EVT_##sym, +#define _(sym, grp, lvl, str) SESSION_EVT_##sym, foreach_session_dbg_evt #undef _ } session_evt_dbg_e; +typedef enum session_evt_lvl_ +{ +#define _(sym, grp, lvl, str) SESSION_EVT_##sym##_LVL = lvl, + foreach_session_dbg_evt +#undef _ +} session_evt_lvl_e; + +#define foreach_session_evt_grp \ + _ (DEQ_EVTS, "dequeue/enqueue events") \ + _ (DISPATCH_DBG, "dispatch") \ + _ (EVT_POLL_DBG, "event poll") \ + _ (SM, "state machine") \ + _ (CLOCKS_EVT_DBG, "clocks events") \ + _ (COUNTS_EVT_DBG, "counts events") + +typedef enum session_evt_grp_ +{ +#define _(sym, str) SESSION_EVT_GRP_##sym, + foreach_session_evt_grp +#undef _ + SESSION_EVT_N_GRP +} session_evt_grp_e; + +typedef enum session_evt_to_grp_ +{ +#define _(sym, grp, lvl, str) SESSION_EVT_##sym##_GRP = SESSION_EVT_GRP_##grp, + foreach_session_dbg_evt +#undef _ +} session_evt_to_grp_e; + #define foreach_session_events \ _(CLK_UPDATE_TIME, 1, 1, "Time Update Time") \ _(CLK_MQ_DEQ, 1, 1, "Time MQ Dequeue") \ @@ -91,22 +121,28 @@ typedef struct session_dbg_evts_t typedef struct session_dbg_main_ { session_dbg_evts_t *wrk; + u8 grp_dbg_lvl[SESSION_EVT_N_GRP]; } session_dbg_main_t; extern session_dbg_main_t session_dbg_main; -#ifdef VPP_SESSION_DEBUG -#define SESSION_DEBUG 1 * (TRANSPORT_DEBUG > 0) +#if defined VPP_SESSION_DEBUG && (TRANSPORT_DEBUG > 0) +#define SESSION_DEBUG (1) +#define SESSION_DEQ_EVTS (1) +#define SESSION_DISPATCH_DBG (1) +#define SESSION_EVT_POLL_DBG (1) +#define SESSION_SM (1) +#define SESSION_CLOCKS_EVT_DBG (1) +#define SESSION_COUNTS_EVT_DBG (1) #else -#define SESSION_DEBUG 0 * (TRANSPORT_DEBUG > 0) -#endif - -#define SESSION_DEQ_EVTS (0) -#define SESSION_DISPATCH_DBG (0) -#define SESSION_EVT_POLL_DBG (0) -#define SESSION_SM (0) +#define SESSION_DEBUG (0) +#define SESSION_DEQ_EVTS (0) +#define SESSION_DISPATCH_DBG (0) +#define SESSION_EVT_POLL_DBG (0) +#define SESSION_SM (0) #define SESSION_CLOCKS_EVT_DBG (0) #define SESSION_COUNTS_EVT_DBG (0) +#endif #if SESSION_DEBUG @@ -129,16 +165,15 @@ extern session_dbg_main_t session_dbg_main; ed = ELOG_DATA (&vlib_global_main.elog_main, _e) #if SESSION_SM -#define SESSION_EVT_FREE_HANDLER(_s) \ -{ \ - ELOG_TYPE_DECLARE (_e) = \ - { \ - .format = "free: idx %u", \ - .format_args = "i4", \ - }; \ - DEC_SESSION_ETD(_s, _e, 1); \ - ed->data[0] = _s->session_index; \ -} +#define SESSION_EVT_FREE_HANDLER(_s) \ + { \ + ELOG_TYPE_DECLARE (_e) = { \ + .format = "free: idx %u", \ + .format_args = "i4", \ + }; \ + DEC_SESSION_ED (_e, 1); \ + ed->data[0] = _s->session_index; \ + } #else #define SESSION_EVT_FREE_HANDLER(_s) #endif @@ -288,17 +323,17 @@ extern session_dbg_main_t session_dbg_main; counters[SESS_Q_##_node_evt].u64 += _cnt; \ } -#define SESSION_IO_EVT_COUNTS_HANDLER(_node_evt, _cnt, _wrk) \ -{ \ - u8 type = SESS_Q_BASE_OFFSET_IO_EVTS + _node_evt + 1; \ - session_dbg_evts_t *sde; \ - sde = &session_dbg_main.wrk[_wrk->vm->thread_index]; \ - sde->counters[type].u64 += _cnt; \ - sde->counters[SESS_Q_CNT_IO_EVTS].u64 += _cnt ; \ -} +#define SESSION_EVT_IO_EVT_COUNTS_HANDLER(_node_evt, _cnt, _wrk) \ + { \ + u8 type = SESS_Q_BASE_OFFSET_IO_EVTS + _node_evt + 1; \ + session_dbg_evts_t *sde; \ + sde = &session_dbg_main.wrk[_wrk->vm->thread_index]; \ + sde->counters[type].u64 += _cnt; \ + sde->counters[SESS_Q_CNT_IO_EVTS].u64 += _cnt; \ + } #else #define SESSION_EVT_COUNTS_HANDLER(_node_evt, _cnt, _wrk) -#define SESSION_IO_EVT_COUNTS_HANDLER(_node_evt, _cnt, _wrk) +#define SESSION_EVT_IO_EVT_COUNTS_HANDLER(_node_evt, _cnt, _wrk) #endif /*SESSION_COUNTS_EVT_DBG */ @@ -328,8 +363,14 @@ extern session_dbg_main_t session_dbg_main; #define CONCAT_HELPER(_a, _b) _a##_b #define CC(_a, _b) CONCAT_HELPER(_a, _b) -#define SESSION_EVT(_evt, _args...) CC(_evt, _HANDLER)(_args) - +#define session_evt_lvl(_evt) CC (_evt, _LVL) +#define session_evt_grp(_evt) CC (_evt, _GRP) +#define session_evt_grp_dbg_lvl(_evt) \ + session_dbg_main.grp_dbg_lvl[session_evt_grp (_evt)] +#define SESSION_EVT(_evt, _args...) \ + if (PREDICT_FALSE (session_evt_grp_dbg_lvl (_evt) >= \ + session_evt_lvl (_evt))) \ + CC (_evt, _HANDLER) (_args) #else #define SESSION_EVT(_evt, _args...) #define SESSION_DBG(_fmt, _args...) diff --git a/src/vnet/session/session_node.c b/src/vnet/session/session_node.c index 1908a58f08f..c29e0590aa8 100644 --- a/src/vnet/session/session_node.c +++ b/src/vnet/session/session_node.c @@ -1552,7 +1552,7 @@ session_tx_fifo_read_and_snd_i (session_worker_t * wrk, *n_tx_packets += ctx->n_segs_per_evt; SESSION_EVT (SESSION_EVT_DEQ, ctx->s, ctx->max_len_to_snd, ctx->max_dequeue, - ctx->s->tx_fifo->has_event, wrk->last_vlib_time); + ctx->s->tx_fifo->shr->has_event, wrk->last_vlib_time); ASSERT (ctx->left_to_snd == 0); @@ -1790,7 +1790,7 @@ session_event_dispatch_io (session_worker_t * wrk, vlib_node_runtime_t * node, clib_warning ("unhandled event type %d", e->event_type); } - SESSION_EVT (SESSION_IO_EVT_COUNTS, e->event_type, 1, wrk); + SESSION_EVT (SESSION_EVT_IO_EVT_COUNTS, e->event_type, 1, wrk); /* Regrab elements in case pool moved */ elt = clib_llist_elt (wrk->event_elts, ei); -- cgit 1.2.3-korg