session: cleanup debug code
Type: refactor
Signed-off-by: Florin Coras <fcoras@cisco.com>
Change-Id: Ie6c03195019fe18c547b22f4387d7f2b14b71461
diff --git a/src/vnet/session/session_debug.h b/src/vnet/session/session_debug.h
index 6140466..a42d90d 100644
--- a/src/vnet/session/session_debug.h
+++ b/src/vnet/session/session_debug.h
@@ -18,18 +18,18 @@
#include <vnet/session/transport.h>
#include <vlib/vlib.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, "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") \
typedef enum _session_evt_dbg
{
@@ -38,29 +38,28 @@
#undef _
} session_evt_dbg_e;
-#define foreach_session_events \
-_(CLK_UPDATE_TIME, 1, 1, "Time Session Update Timers") \
-_(CLK_MQ_DEQ, 1, 1, "Time MQ Dequeue") \
+#define foreach_session_events \
+_(CLK_UPDATE_TIME, 1, 1, "Time Update Time") \
+_(CLK_MQ_DEQ, 1, 1, "Time MQ Dequeue") \
_(CLK_CTRL_EVTS, 1, 1, "Time Ctrl Events") \
-_(CLK_NEW_IO_EVTS, 1, 1, "Time New IO Events") \
-_(CLK_OLD_IO_EVTS, 1, 1, "Time Old IO Events") \
-\
-_(CNT_MQ_EVTS, 1, 0, "# of MQ Events Processed" ) \
-_(CNT_CTRL_EVTS, 1, 0, "# of Cntrl Events Processed" ) \
-_(CNT_NEW_EVTS, 1, 0, "# of New Events Processed" ) \
-_(CNT_OLD_EVTS, 1, 0, "# of Old Events Processed" ) \
-_(CNT_IO_EVTS, 1, 0, "# of Events Processed" ) \
-_(NODE_CALL_CNT, 1, 0, "Node call count") \
-_(NEW_IO_EVTS, 1, 0, "New IO Events") \
-_(OLD_IO_EVTS, 1, 0, "Old IO Events") \
-\
-_(BASE_OFFSET_IO_EVTS, 0, 0, "NULL") \
-_(SESSION_IO_EVT_RX, 1, 0, "# of IO Event RX") \
+_(CLK_NEW_IO_EVTS, 1, 1, "Time New IO Events") \
+_(CLK_OLD_IO_EVTS, 1, 1, "Time Old IO Events") \
+_(CLK_TOTAL, 1, 1, "Time Total in Node") \
+_(CLK_START, 1, 1, "Time Since Last Reset") \
+ \
+_(CNT_MQ_EVTS, 1, 0, "# of MQ Events Processed" ) \
+_(CNT_CTRL_EVTS, 1, 0, "# of Ctrl Events Processed" ) \
+_(CNT_NEW_EVTS, 1, 0, "# of New Events Processed" ) \
+_(CNT_OLD_EVTS, 1, 0, "# of Old Events Processed" ) \
+_(CNT_IO_EVTS, 1, 0, "# of Events Processed" ) \
+_(CNT_NODE_CALL, 1, 0, "# of Node Calls") \
+ \
+_(BASE_OFFSET_IO_EVTS, 0, 0, "NULL") \
+_(SESSION_IO_EVT_RX, 1, 0, "# of IO Event RX") \
_(SESSION_IO_EVT_TX, 1, 0, "# of IO Event TX") \
_(SESSION_IO_EVT_TX_FLUSH, 1, 0, "# of IO Event TX Flush") \
-_(SESSION_IO_EVT_BUILTIN_RX, 1, 0, "# of IO Event BuiltIn RX") \
-_(SESSION_IO_EVT_BUILTIN_TX, 1, 0, "# of IO Event BuiltIn TX") \
-
+_(SESSION_IO_EVT_BUILTIN_RX, 1, 0, "# of IO Event BuiltIn RX") \
+_(SESSION_IO_EVT_BUILTIN_TX, 1, 0, "# of IO Event BuiltIn TX") \
typedef enum
{
@@ -83,8 +82,9 @@
{
CLIB_CACHE_LINE_ALIGN_MARK (cacheline0);
f64 last_time;
+ f64 start_time;
u64 prev_io;
- session_dbg_counter_t sess_dbg_evt_type[SESS_Q_MAX_EVT_TYPES];
+ session_dbg_counter_t counters[SESS_Q_MAX_EVT_TYPES];
} session_dbg_evts_t;
typedef struct session_dbg_main_
@@ -189,7 +189,7 @@
* 1000000.0; \
}
#else
-#define SESSION_EVT_DEQ_NODE_HANDLER(_node_evt, _ntx)
+#define SESSION_EVT_DEQ_NODE_HANDLER(_wrk, _node_evt, _ntx)
#endif /* SESSION_DISPATCH_DBG */
#if SESSION_EVT_POLL_DBG && SESSION_DEBUG > 1
@@ -238,79 +238,86 @@
#if SESSION_CLOCKS_EVT_DBG
#define SESSION_EVT_DSP_CNTRS_UPDATE_TIME_HANDLER(_wrk, _diff, _args...) \
- session_dbg_evts_t *sdm = &session_dbg_main.wrk[_wrk->vm->thread_index]; \
- sdm->sess_dbg_evt_type[SESS_Q_CLK_UPDATE_TIME].f64 += _diff; \
+ session_dbg_evts_t *sde = &session_dbg_main.wrk[_wrk->vm->thread_index]; \
+ sde->counters[SESS_Q_CLK_UPDATE_TIME].f64 += _diff; \
-#define SESSION_EVT_DSP_CNTRS_MQ_DEQ_HANDLER(_wrk, _diff, _cnt, _args...) \
- session_dbg_evts_t *sdm = &session_dbg_main.wrk[_wrk->vm->thread_index]; \
- sdm->sess_dbg_evt_type[SESS_Q_CNT_MQ_EVTS].u64 += _cnt; \
- sdm->sess_dbg_evt_type[SESS_Q_CLK_MQ_DEQ].f64 += _diff; \
+#define SESSION_EVT_DSP_CNTRS_MQ_DEQ_HANDLER(_wrk, _diff, _cnt, _dq, _args...) \
+ session_dbg_evts_t *sde = &session_dbg_main.wrk[_wrk->vm->thread_index]; \
+ sde->counters[SESS_Q_CNT_MQ_EVTS].u64 += _dq * _cnt; \
+ sde->counters[SESS_Q_CLK_MQ_DEQ].f64 += _diff; \
#define SESSION_EVT_DSP_CNTRS_CTRL_EVTS_HANDLER(_wrk, _diff, _args...) \
- session_dbg_evts_t *sdm = &session_dbg_main.wrk[_wrk->vm->thread_index]; \
- sdm->sess_dbg_evt_type[SESS_Q_CLK_CTRL_EVTS].f64 += _diff; \
- sdm->prev_io = sdm->sess_dbg_evt_type[SESS_Q_CNT_IO_EVTS].u64; \
+ session_dbg_evts_t *sde = &session_dbg_main.wrk[_wrk->vm->thread_index]; \
+ sde->counters[SESS_Q_CLK_CTRL_EVTS].f64 += _diff; \
+ sde->prev_io = sde->counters[SESS_Q_CNT_IO_EVTS].u64; \
#define SESSION_EVT_DSP_CNTRS_NEW_IO_EVTS_HANDLER(_wrk, _diff, _args...) \
- session_dbg_evts_t *sdm = &session_dbg_main.wrk[_wrk->vm->thread_index]; \
- sdm->sess_dbg_evt_type[SESS_Q_CLK_NEW_IO_EVTS].f64 += _diff; \
- sdm->sess_dbg_evt_type[SESS_Q_CNT_NEW_EVTS].u64 += \
- sdm->sess_dbg_evt_type[SESS_Q_CNT_IO_EVTS].u64 - sdm->prev_io; \
- sdm->prev_io = sdm->sess_dbg_evt_type[SESS_Q_CNT_IO_EVTS].u64; \
+ session_dbg_evts_t *sde = &session_dbg_main.wrk[_wrk->vm->thread_index]; \
+ sde->counters[SESS_Q_CLK_NEW_IO_EVTS].f64 += _diff; \
+ sde->counters[SESS_Q_CNT_NEW_EVTS].u64 += \
+ sde->counters[SESS_Q_CNT_IO_EVTS].u64 - sde->prev_io; \
+ sde->prev_io = sde->counters[SESS_Q_CNT_IO_EVTS].u64; \
#define SESSION_EVT_DSP_CNTRS_OLD_IO_EVTS_HANDLER(_wrk, _diff, _args...) \
- session_dbg_evts_t *sdm = &session_dbg_main.wrk[_wrk->vm->thread_index]; \
- sdm->sess_dbg_evt_type[SESS_Q_CLK_OLD_IO_EVTS].f64 += _diff; \
- sdm->sess_dbg_evt_type[SESS_Q_CNT_OLD_EVTS].u64 += \
- sdm->sess_dbg_evt_type[SESS_Q_CNT_IO_EVTS].u64 - sdm->prev_io; \
+ session_dbg_evts_t *sde = &session_dbg_main.wrk[_wrk->vm->thread_index]; \
+ sde->counters[SESS_Q_CLK_OLD_IO_EVTS].f64 += _diff; \
+ sde->counters[SESS_Q_CNT_OLD_EVTS].u64 += \
+ sde->counters[SESS_Q_CNT_IO_EVTS].u64 - sde->prev_io; \
#define SESSION_EVT_DSP_CNTRS_HANDLER(_disp_evt, _wrk, _args...) \
{ \
- f64 time_now = vlib_time_now (_wrk->vm); \
- f64 diff = time_now - session_dbg_main.wrk[_wrk->vm->thread_index].last_time; \
+ f64 time_now = vlib_time_now (_wrk->vm), diff; \
+ diff = time_now - session_dbg_main.wrk[_wrk->vm->thread_index].last_time; \
session_dbg_main.wrk[_wrk->vm->thread_index].last_time = time_now; \
CC(CC(SESSION_EVT_DSP_CNTRS_,_disp_evt),_HANDLER)(wrk, diff, _args); \
}
#else
-#define SESSION_EVT_CLOCKS_HANDLER(_node_evt, _wrk)
+#define SESSION_EVT_DSP_CNTRS_HANDLER(_disp_evt, _wrk, _args...)
#endif /*SESSION_CLOCKS_EVT_DBG */
#if SESSION_COUNTS_EVT_DBG
-#define SESSION_EVT_COUNTS_HANDLER(_node_evt, _cnt, _wrk) \
+#define SESSION_EVT_COUNTS_HANDLER(_node_evt, _cnt, _wrk) \
{ \
session_dbg_main.wrk[_wrk->vm->thread_index]. \
- sess_dbg_evt_type[SESS_Q_##_node_evt].u64 += _cnt; \
+ 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_main.wrk[_wrk->vm->thread_index]. \
- sess_dbg_evt_type[type].u64 += _cnt ; \
- session_dbg_main.wrk[_wrk->vm->thread_index]. \
- sess_dbg_evt_type[SESS_Q_CNT_IO_EVTS].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 ; \
}
#else
-#define SESSION_EVT_COUNTS_HANDLER(_node_evt, _wrk)
+#define SESSION_EVT_COUNTS_HANDLER(_node_evt, _cnt, _wrk)
#define SESSION_IO_EVT_COUNTS_HANDLER(_node_evt, _cnt, _wrk)
#endif /*SESSION_COUNTS_EVT_DBG */
#define SESSION_EVT_DISPATCH_START_HANDLER(_wrk) \
{ \
+ session_dbg_evts_t *sde; \
+ sde = &session_dbg_main.wrk[_wrk->vm->thread_index]; \
if (SESSION_DEQ_EVTS > 1) \
SESSION_EVT_DEQ_NODE_HANDLER (_wrk, 0, 0); \
SESSION_EVT_POLL_GAP_TRACK_HANDLER (wrk); \
- session_dbg_main.wrk[_wrk->vm->thread_index]. \
- sess_dbg_evt_type[SESS_Q_##NODE_CALL_CNT].u64 +=1; \
+ sde->counters[SESS_Q_##CNT_NODE_CALL].u64 +=1; \
+ sde->last_time = vlib_time_now (_wrk->vm); \
}
#define SESSION_EVT_DISPATCH_END_HANDLER(_wrk, _ntx) \
{ \
+ f64 now = vlib_time_now (_wrk->vm); \
+ session_dbg_evts_t *sde; \
+ sde = &session_dbg_main.wrk[_wrk->vm->thread_index]; \
if (_ntx) \
SESSION_EVT_DEQ_NODE_HANDLER (_wrk, 1, _ntx); \
SESSION_EVT_POLL_DISPATCH_TIME_HANDLER(_wrk); \
- _wrk->last_event_poll = vlib_time_now (_wrk->vm); \
+ _wrk->last_event_poll = now; \
+ sde->counters[SESS_Q_CLK_TOTAL].f64 += now - _wrk->last_vlib_time; \
+ sde->counters[SESS_Q_CLK_START].f64 = now - sde->start_time; \
}
#define CONCAT_HELPER(_a, _b) _a##_b
@@ -322,6 +329,8 @@
#define SESSION_DBG(_fmt, _args...)
#endif /* SESSION_DEBUG */
+void session_debug_init (void);
+
#endif /* SRC_VNET_SESSION_SESSION_DEBUG_H_ */
/*
* fd.io coding-style-patch-verification: ON