diff options
| author |   Florin Coras <fcoras@cisco.com> | 2019-10-30 17:11:53 -0700 |
|---|---|---|
| committer |   Andrew Yourtchenko <ayourtch@gmail.com> | 2019-11-05 10:42:46 +0000 |
| commit | e04a58d27bac8f97bda85a7684b7bb68682341cc (patch) | |
| tree | bf6167a00311abff1d3a3ac6b07001c30fcb9510 | |
| parent | 6de46b40d2d2429e8f4f06272536fb5535c73908 (diff) | |
session: fix dispatch event logging
Type: fix
Change-Id: Icf3c73cd7eb7565ed6e1b0371da172b5408a9d36
Signed-off-by: Florin Coras <fcoras@cisco.com>
(cherry picked from commit ba13c3b3695cb4758848d856174b725afcc7cdb8)
| -rw-r--r-- | src/vnet/session/session_debug.h | 43 |
1 files changed, 27 insertions, 16 deletions
diff --git a/src/vnet/session/session_debug.h b/src/vnet/session/session_debug.h index 228c1b36ac6..a57b02d228e 100644 --- a/src/vnet/session/session_debug.h +++ b/src/vnet/session/session_debug.h @@ -37,6 +37,7 @@ typedef enum _session_evt_dbg #define SESSION_DEBUG 0 * (TRANSPORT_DEBUG > 0) #define SESSION_DEQ_EVTS (0) +#define SESSION_DISPATCH_DBG (0) #define SESSION_EVT_POLL_DBG (0) #define SESSION_SM (0) @@ -100,27 +101,35 @@ typedef enum _session_evt_dbg DEC_SESSION_ETD(_s, _e, 1); \ ed->data[0] = _len; \ } +#else +#define SESSION_EVT_DEQ_HANDLER(_s, _now, _max, _has_evt, _ts) +#define SESSION_EVT_ENQ_HANDLER(_s, _body) +#endif /* SESSION_DEQ_NODE_EVTS */ -#define SESSION_EVT_DEQ_NODE_HANDLER(_node_evt) \ +#if SESSION_DISPATCH_DBG +#define SESSION_EVT_DEQ_NODE_HANDLER(_wrk, _node_evt, _ntx) \ { \ ELOG_TYPE_DECLARE (_e) = \ { \ - .format = "deq-node: %s", \ - .format_args = "t4", \ + .format = "dispatch: %s pkts %u re-entry: %u dispatch %u", \ + .format_args = "t4i4i4i4", \ .n_enum_strings = 2, \ .enum_strings = { \ "start", \ "end", \ }, \ }; \ - DEC_SESSION_ED(_e, 1); \ + DEC_SESSION_ED(_e, 4); \ ed->data[0] = _node_evt; \ + ed->data[1] = _ntx; \ + ed->data[2] = (_wrk->last_vlib_time - _wrk->last_event_poll) \ + * 1000000.0; \ + ed->data[3] = (vlib_time_now (_wrk->vm) - _wrk->last_vlib_time) \ + * 1000000.0; \ } #else -#define SESSION_EVT_DEQ_HANDLER(_s, _body) -#define SESSION_EVT_ENQ_HANDLER(_s, _body) -#define SESSION_EVT_DEQ_NODE_HANDLER(_node_evt) -#endif /* SESSION_DEQ_NODE_EVTS */ +#define SESSION_EVT_DEQ_NODE_HANDLER(_node_evt, _ntx) +#endif /* SESSION_DISPATCH_DBG */ #if SESSION_EVT_POLL_DBG && SESSION_DEBUG > 1 #define SESSION_EVT_POLL_GAP(_wrk) \ @@ -131,14 +140,15 @@ typedef enum _session_evt_dbg .format_args = "i4", \ }; \ DEC_SESSION_ED(_e, 1); \ - ed->data[0] = (u32) ((now - _wrk->last_event_poll)*1000000.0); \ + ed->data[0] = (u32) ((_wrk->last_vlib_time - _wrk->last_event_poll) \ + *1000000.0); \ } #define SESSION_EVT_POLL_GAP_TRACK_HANDLER(_wrk) \ { \ - if (PREDICT_TRUE (smm->last_event_poll != 0.0)) \ - if (now > smm->last_event_poll + 500e-6) \ - SESSION_EVT_POLL_GAP(smm, _ti); \ - _wrk->last_event_poll = now; \ + if (PREDICT_TRUE (_wrk->last_event_poll != 0.0)) \ + if (_wrk->last_vlib_time > _wrk->last_event_poll + 500e-6) \ + SESSION_EVT_POLL_GAP(_wrk); \ + _wrk->last_event_poll = _wrk->last_vlib_time; \ } #define SESSION_EVT_POLL_DISPATCH_TIME_HANDLER(_wrk) \ @@ -165,15 +175,16 @@ typedef enum _session_evt_dbg #define SESSION_EVT_DISPATCH_START_HANDLER(_wrk) \ { \ if (SESSION_DEQ_EVTS > 1) \ - SESSION_EVT_DEQ_NODE_HANDLER (0); \ + SESSION_EVT_DEQ_NODE_HANDLER (_wrk, 0, 0); \ SESSION_EVT_POLL_GAP_TRACK_HANDLER (wrk); \ } #define SESSION_EVT_DISPATCH_END_HANDLER(_wrk, _ntx) \ { \ - if (SESSION_DEQ_EVTS > 1 || _ntx) \ - SESSION_EVT_DEQ_NODE_HANDLER (1); \ + 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); \ } #define CONCAT_HELPER(_a, _b) _a##_b |