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 <list> level <n>}
  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 <sluong@cisco.com>
Change-Id: Iab2989e0a847bb59002ef16494eebcc1d112b2ae

1 files changed, 84 insertions, 43 deletions

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 <vlib/vlib.h>
 #include <vpp/vnet/config.h>
 
-#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...)