aboutsummaryrefslogtreecommitdiffstats
path: root/src/vnet
diff options
context:
space:
mode:
authorFlorin Coras <fcoras@cisco.com>2020-04-13 01:20:25 +0000
committerFlorin Coras <fcoras@cisco.com>2020-04-13 03:04:45 +0000
commit111666766d9db5a2546a6cdb0f296977472c5993 (patch)
tree2adad1630a888c3c48a736eb5670040b5366b81c /src/vnet
parent7357043d2abc8d3811362f256e7c9086e7b0d378 (diff)
session: cleanup debug code
Type: refactor Signed-off-by: Florin Coras <fcoras@cisco.com> Change-Id: Ie6c03195019fe18c547b22f4387d7f2b14b71461
Diffstat (limited to 'src/vnet')
-rw-r--r--src/vnet/CMakeLists.txt1
-rw-r--r--src/vnet/session/session.c16
-rw-r--r--src/vnet/session/session_cli.c79
-rw-r--r--src/vnet/session/session_debug.c281
-rw-r--r--src/vnet/session/session_debug.h145
-rw-r--r--src/vnet/session/session_node.c160
6 files changed, 363 insertions, 319 deletions
diff --git a/src/vnet/CMakeLists.txt b/src/vnet/CMakeLists.txt
index 151b0997e52..9911b0420a6 100644
--- a/src/vnet/CMakeLists.txt
+++ b/src/vnet/CMakeLists.txt
@@ -1159,6 +1159,7 @@ list(APPEND VNET_API_FILES devices/pipe/pipe.api)
list(APPEND VNET_SOURCES
session/session.c
+ session/session_debug.c
session/session_table.c
session/session_rules_table.c
session/session_lookup.c
diff --git a/src/vnet/session/session.c b/src/vnet/session/session.c
index caa362e1f1d..1274408675f 100644
--- a/src/vnet/session/session.c
+++ b/src/vnet/session/session.c
@@ -18,17 +18,12 @@
*/
#include <vnet/session/session.h>
-#include <vnet/session/session_debug.h>
#include <vnet/session/application.h>
#include <vnet/dpo/load_balance.h>
#include <vnet/fib/ip4_fib.h>
session_main_t session_main;
-#if SESSION_DEBUG
-session_dbg_main_t session_dbg_main;
-#endif
-
static inline int
session_send_evt_to_thread (void *data, void *args, u32 thread_index,
session_evt_type_t evt_type)
@@ -1709,16 +1704,7 @@ session_manager_main_enable (vlib_main_t * vm)
/* Enable transports */
transport_enable_disable (vm, 1);
-
-#if SESSION_DEBUG
- session_dbg_main_t *sdm = &session_dbg_main;
- vec_validate_aligned (sdm->wrk, num_threads - 1, CLIB_CACHE_LINE_BYTES);
- int thread;
- for (thread = 0; thread < num_threads; thread++)
- {
- clib_memset (&sdm->wrk[thread], 0, sizeof (session_dbg_evts_t));
- }
-#endif /* SESSION_DEBUG */
+ session_debug_init ();
return 0;
}
diff --git a/src/vnet/session/session_cli.c b/src/vnet/session/session_cli.c
index 563ee83c758..9f6d74c031d 100644
--- a/src/vnet/session/session_cli.c
+++ b/src/vnet/session/session_cli.c
@@ -14,7 +14,6 @@
*/
#include <vnet/session/application.h>
#include <vnet/session/session.h>
-#include <vnet/session/session_debug.h>
u8 *
format_session_fifos (u8 * s, va_list * args)
@@ -880,84 +879,6 @@ VLIB_CLI_COMMAND (session_enable_disable_command, static) =
};
/* *INDENT-ON* */
-#if SESSION_DEBUG
-
-static clib_error_t *
-show_session_dbg_clock_cycles_fn (vlib_main_t * vm, unformat_input_t * input,
- vlib_cli_command_t * cmd)
-{
- u32 thread;
-
- if (unformat_check_input (input) != UNFORMAT_END_OF_INPUT)
- return clib_error_return (0, "unknown input `%U'", format_unformat_error,
- input);
-
- for (thread = 0; thread < vec_len (session_dbg_main.wrk); thread++)
- {
- vlib_cli_output (vm, "Threads %u:\n", thread);
- session_dbg_evts_t *sdm = &session_dbg_main.wrk[thread];
-
-#define _(sym, disp, type, str) \
- if(disp) \
- { \
- if (!type) \
- vlib_cli_output (vm, "\t %25s : %12lu ", \
- str, sdm->sess_dbg_evt_type[SESS_Q_##sym].u64);\
- else \
- vlib_cli_output (vm, "\t %25s : %12.3f ", \
- str, sdm->sess_dbg_evt_type[SESS_Q_##sym].f64);\
- }
-
- foreach_session_events
-#undef _
- }
- return 0;
-}
-
-
-/* *INDENT-OFF* */
-VLIB_CLI_COMMAND (show_session_dbg_clock_cycles_command, static) =
-{
- .path = "show session dbg clock_cycles",
- .short_help = "show session dbg clock_cycles",
- .function = show_session_dbg_clock_cycles_fn,
-};
-/* *INDENT-ON* */
-
-
-static clib_error_t *
-clear_session_dbg_clock_cycles_fn (vlib_main_t * vm, unformat_input_t * input,
- vlib_cli_command_t * cmd)
-{
- session_dbg_evts_t *sdb;
- u32 thread;
-
- if (unformat_check_input (input) != UNFORMAT_END_OF_INPUT)
- return clib_error_return (0, "unknown input `%U'", format_unformat_error,
- input);
-
- for (thread = 0; thread < vec_len (session_dbg_main.wrk); thread++)
- {
- sdb = &session_dbg_main.wrk[thread];
- clib_memset (sdb, 0, sizeof (session_dbg_evts_t));
- sdb->last_time = vlib_time_now (vlib_mains[thread]);
- }
-
- return 0;
-}
-
-
-/* *INDENT-OFF* */
-VLIB_CLI_COMMAND (clear_session_clock_cycles_command, static) =
-{
- .path = "clear session dbg clock_cycles",
- .short_help = "clear session dbg clock_cycles",
- .function = clear_session_dbg_clock_cycles_fn,
-};
-#endif /* #if SESSION_DEBUG */
-
-/* *INDENT-ON* */
-
/*
* fd.io coding-style-patch-verification: ON
*
diff --git a/src/vnet/session/session_debug.c b/src/vnet/session/session_debug.c
new file mode 100644
index 00000000000..33d1dc57196
--- /dev/null
+++ b/src/vnet/session/session_debug.c
@@ -0,0 +1,281 @@
+/*
+ * Copyright (c) 2020 Cisco and/or its affiliates.
+ * Licensed under the Apache License, Version 2.0 (the "License");
+ * you may not use this file except in compliance with the License.
+ * You may obtain a copy of the License at:
+ *
+ * http://www.apache.org/licenses/LICENSE-2.0
+ *
+ * Unless required by applicable law or agreed to in writing, software
+ * distributed under the License is distributed on an "AS IS" BASIS,
+ * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+ * See the License for the specific language governing permissions and
+ * limitations under the License.
+ */
+
+#include <vnet/session/session_debug.h>
+#include <vnet/session/session.h>
+
+#if SESSION_DEBUG > 0
+
+session_dbg_main_t session_dbg_main;
+
+static clib_error_t *
+show_session_dbg_clock_cycles_fn (vlib_main_t * vm, unformat_input_t * input,
+ vlib_cli_command_t * cmd)
+{
+ u32 thread;
+
+ if (unformat_check_input (input) != UNFORMAT_END_OF_INPUT)
+ return clib_error_return (0, "unknown input `%U'", format_unformat_error,
+ input);
+
+ for (thread = 0; thread < vec_len (session_dbg_main.wrk); thread++)
+ {
+ vlib_cli_output (vm, "Threads %u:\n", thread);
+ session_dbg_evts_t *sdm = &session_dbg_main.wrk[thread];
+
+#define _(sym, disp, type, str) \
+ if(disp) \
+ { \
+ if (!type) \
+ vlib_cli_output (vm, "\t %25s : %12lu ", str, \
+ sdm->counters[SESS_Q_##sym].u64); \
+ else \
+ vlib_cli_output (vm, "\t %25s : %12.3f ", str, \
+ sdm->counters[SESS_Q_##sym].f64); \
+ }
+ foreach_session_events
+#undef _
+ }
+ return 0;
+}
+
+
+/* *INDENT-OFF* */
+VLIB_CLI_COMMAND (show_session_dbg_clock_cycles_command, static) =
+{
+ .path = "show session dbg clock_cycles",
+ .short_help = "show session dbg clock_cycles",
+ .function = show_session_dbg_clock_cycles_fn,
+};
+/* *INDENT-ON* */
+
+
+static clib_error_t *
+clear_session_dbg_clock_cycles_fn (vlib_main_t * vm, unformat_input_t * input,
+ vlib_cli_command_t * cmd)
+{
+ session_dbg_evts_t *sde;
+ u32 thread;
+
+ if (unformat_check_input (input) != UNFORMAT_END_OF_INPUT)
+ return clib_error_return (0, "unknown input `%U'", format_unformat_error,
+ input);
+
+ for (thread = 0; thread < vec_len (session_dbg_main.wrk); thread++)
+ {
+ sde = &session_dbg_main.wrk[thread];
+ clib_memset (sde, 0, sizeof (session_dbg_evts_t));
+ sde->last_time = vlib_time_now (vlib_mains[thread]);
+ sde->start_time = sde->last_time;
+ }
+
+ return 0;
+}
+
+
+/* *INDENT-OFF* */
+VLIB_CLI_COMMAND (clear_session_clock_cycles_command, static) =
+{
+ .path = "clear session dbg clock_cycles",
+ .short_help = "clear session dbg clock_cycles",
+ .function = clear_session_dbg_clock_cycles_fn,
+};
+/* *INDENT-ON* */
+
+void
+session_debug_init (void)
+{
+ vlib_thread_main_t *vtm = vlib_get_thread_main ();
+ session_dbg_main_t *sdm = &session_dbg_main;
+ u32 num_threads, thread;
+
+ num_threads = vtm->n_vlib_mains;
+
+ vec_validate_aligned (sdm->wrk, num_threads - 1, CLIB_CACHE_LINE_BYTES);
+ for (thread = 0; thread < num_threads; thread++)
+ {
+ clib_memset (&sdm->wrk[thread], 0, sizeof (session_dbg_evts_t));
+ sdm->wrk[thread].start_time = vlib_time_now (vlib_mains[thread]);
+ }
+}
+#else
+void
+session_debug_init (void)
+{
+}
+#endif
+
+void
+dump_thread_0_event_queue (void)
+{
+ session_main_t *smm = vnet_get_session_main ();
+ vlib_main_t *vm = &vlib_global_main;
+ u32 my_thread_index = vm->thread_index;
+ session_event_t _e, *e = &_e;
+ svm_msg_q_ring_t *ring;
+ session_t *s0;
+ svm_msg_q_msg_t *msg;
+ svm_msg_q_t *mq;
+ int i, index;
+
+ mq = smm->wrk[my_thread_index].vpp_event_queue;
+ index = mq->q->head;
+
+ for (i = 0; i < mq->q->cursize; i++)
+ {
+ msg = (svm_msg_q_msg_t *) (&mq->q->data[0] + mq->q->elsize * index);
+ ring = svm_msg_q_ring (mq, msg->ring_index);
+ clib_memcpy_fast (e, svm_msg_q_msg_data (mq, msg), ring->elsize);
+
+ switch (e->event_type)
+ {
+ case SESSION_IO_EVT_TX:
+ s0 = session_get_if_valid (e->session_index, my_thread_index);
+ fformat (stdout, "[%04d] TX session %d\n", i, s0->session_index);
+ break;
+
+ case SESSION_CTRL_EVT_CLOSE:
+ s0 = session_get_from_handle (e->session_handle);
+ fformat (stdout, "[%04d] disconnect session %d\n", i,
+ s0->session_index);
+ break;
+
+ case SESSION_IO_EVT_BUILTIN_RX:
+ s0 = session_get_if_valid (e->session_index, my_thread_index);
+ fformat (stdout, "[%04d] builtin_rx %d\n", i, s0->session_index);
+ break;
+
+ case SESSION_CTRL_EVT_RPC:
+ fformat (stdout, "[%04d] RPC call %llx with %llx\n",
+ i, (u64) (uword) (e->rpc_args.fp),
+ (u64) (uword) (e->rpc_args.arg));
+ break;
+
+ default:
+ fformat (stdout, "[%04d] unhandled event type %d\n",
+ i, e->event_type);
+ break;
+ }
+
+ index++;
+
+ if (index == mq->q->maxsize)
+ index = 0;
+ }
+}
+
+static u8
+session_node_cmp_event (session_event_t * e, svm_fifo_t * f)
+{
+ session_t *s;
+ switch (e->event_type)
+ {
+ case SESSION_IO_EVT_RX:
+ case SESSION_IO_EVT_TX:
+ case SESSION_IO_EVT_BUILTIN_RX:
+ case SESSION_IO_EVT_BUILTIN_TX:
+ case SESSION_IO_EVT_TX_FLUSH:
+ if (e->session_index == f->master_session_index)
+ return 1;
+ break;
+ case SESSION_CTRL_EVT_CLOSE:
+ break;
+ case SESSION_CTRL_EVT_RPC:
+ s = session_get_from_handle (e->session_handle);
+ if (!s)
+ {
+ clib_warning ("session has event but doesn't exist!");
+ break;
+ }
+ if (s->rx_fifo == f || s->tx_fifo == f)
+ return 1;
+ break;
+ default:
+ break;
+ }
+ return 0;
+}
+
+u8
+session_node_lookup_fifo_event (svm_fifo_t * f, session_event_t * e)
+{
+ session_evt_elt_t *elt;
+ session_worker_t *wrk;
+ int i, index, found = 0;
+ svm_msg_q_msg_t *msg;
+ svm_msg_q_ring_t *ring;
+ svm_msg_q_t *mq;
+ u8 thread_index;
+
+ ASSERT (e);
+ thread_index = f->master_thread_index;
+ wrk = session_main_get_worker (thread_index);
+
+ /*
+ * Search evt queue
+ */
+ mq = wrk->vpp_event_queue;
+ index = mq->q->head;
+ for (i = 0; i < mq->q->cursize; i++)
+ {
+ msg = (svm_msg_q_msg_t *) (&mq->q->data[0] + mq->q->elsize * index);
+ ring = svm_msg_q_ring (mq, msg->ring_index);
+ clib_memcpy_fast (e, svm_msg_q_msg_data (mq, msg), ring->elsize);
+ found = session_node_cmp_event (e, f);
+ if (found)
+ return 1;
+ index = (index + 1) % mq->q->maxsize;
+ }
+ /*
+ * Search pending events vector
+ */
+
+ /* *INDENT-OFF* */
+ clib_llist_foreach (wrk->event_elts, evt_list,
+ pool_elt_at_index (wrk->event_elts, wrk->new_head),
+ elt, ({
+ found = session_node_cmp_event (&elt->evt, f);
+ if (found)
+ {
+ clib_memcpy_fast (e, &elt->evt, sizeof (*e));
+ goto done;
+ }
+ }));
+ /* *INDENT-ON* */
+
+ /* *INDENT-OFF* */
+ clib_llist_foreach (wrk->event_elts, evt_list,
+ pool_elt_at_index (wrk->event_elts, wrk->old_head),
+ elt, ({
+ found = session_node_cmp_event (&elt->evt, f);
+ if (found)
+ {
+ clib_memcpy_fast (e, &elt->evt, sizeof (*e));
+ goto done;
+ }
+ }));
+ /* *INDENT-ON* */
+
+done:
+ return found;
+}
+
+/*
+ * fd.io coding-style-patch-verification: ON
+ *
+ * Local Variables:
+ * eval: (c-set-style "gnu")
+ * End:
+ */
diff --git a/src/vnet/session/session_debug.h b/src/vnet/session/session_debug.h
index 6140466998a..a42d90d471c 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 @@ typedef enum _session_evt_dbg
#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 @@ typedef struct session_dbg_evts_t
{
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 @@ extern session_dbg_main_t session_dbg_main;
* 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 @@ extern session_dbg_main_t session_dbg_main;
#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 @@ extern session_dbg_main_t session_dbg_main;
#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
diff --git a/src/vnet/session/session_node.c b/src/vnet/session/session_node.c
index 867ff4fcaf7..0f5030b4d31 100644
--- a/src/vnet/session/session_node.c
+++ b/src/vnet/session/session_node.c
@@ -1317,7 +1317,7 @@ session_queue_node_fn (vlib_main_t * vm, vlib_node_runtime_t * node,
session_evt_elt_t *elt, *ctrl_he, *new_he, *old_he;
clib_llist_index_t ei, next_ei, old_ti;
svm_msg_q_msg_t _msg, *msg = &_msg;
- int i, n_tx_packets;
+ int i = 0, n_tx_packets;
session_event_t *evt;
svm_msg_q_t *mq;
@@ -1351,9 +1351,10 @@ session_queue_node_fn (vlib_main_t * vm, vlib_node_runtime_t * node,
svm_msg_q_free_msg (mq, msg);
}
svm_msg_q_unlock (mq);
- SESSION_EVT (SESSION_EVT_DSP_CNTRS, MQ_DEQ, wrk, n_to_dequeue);
}
+ SESSION_EVT (SESSION_EVT_DSP_CNTRS, MQ_DEQ, wrk, n_to_dequeue, !i);
+
/*
* Handle control events
*/
@@ -1440,161 +1441,6 @@ VLIB_REGISTER_NODE (session_queue_node) =
};
/* *INDENT-ON* */
-void
-dump_thread_0_event_queue (void)
-{
- session_main_t *smm = vnet_get_session_main ();
- vlib_main_t *vm = &vlib_global_main;
- u32 my_thread_index = vm->thread_index;
- session_event_t _e, *e = &_e;
- svm_msg_q_ring_t *ring;
- session_t *s0;
- svm_msg_q_msg_t *msg;
- svm_msg_q_t *mq;
- int i, index;
-
- mq = smm->wrk[my_thread_index].vpp_event_queue;
- index = mq->q->head;
-
- for (i = 0; i < mq->q->cursize; i++)
- {
- msg = (svm_msg_q_msg_t *) (&mq->q->data[0] + mq->q->elsize * index);
- ring = svm_msg_q_ring (mq, msg->ring_index);
- clib_memcpy_fast (e, svm_msg_q_msg_data (mq, msg), ring->elsize);
-
- switch (e->event_type)
- {
- case SESSION_IO_EVT_TX:
- s0 = session_event_get_session (e, my_thread_index);
- fformat (stdout, "[%04d] TX session %d\n", i, s0->session_index);
- break;
-
- case SESSION_CTRL_EVT_CLOSE:
- s0 = session_get_from_handle (e->session_handle);
- fformat (stdout, "[%04d] disconnect session %d\n", i,
- s0->session_index);
- break;
-
- case SESSION_IO_EVT_BUILTIN_RX:
- s0 = session_event_get_session (e, my_thread_index);
- fformat (stdout, "[%04d] builtin_rx %d\n", i, s0->session_index);
- break;
-
- case SESSION_CTRL_EVT_RPC:
- fformat (stdout, "[%04d] RPC call %llx with %llx\n",
- i, (u64) (uword) (e->rpc_args.fp),
- (u64) (uword) (e->rpc_args.arg));
- break;
-
- default:
- fformat (stdout, "[%04d] unhandled event type %d\n",
- i, e->event_type);
- break;
- }
-
- index++;
-
- if (index == mq->q->maxsize)
- index = 0;
- }
-}
-
-static u8
-session_node_cmp_event (session_event_t * e, svm_fifo_t * f)
-{
- session_t *s;
- switch (e->event_type)
- {
- case SESSION_IO_EVT_RX:
- case SESSION_IO_EVT_TX:
- case SESSION_IO_EVT_BUILTIN_RX:
- case SESSION_IO_EVT_BUILTIN_TX:
- case SESSION_IO_EVT_TX_FLUSH:
- if (e->session_index == f->master_session_index)
- return 1;
- break;
- case SESSION_CTRL_EVT_CLOSE:
- break;
- case SESSION_CTRL_EVT_RPC:
- s = session_get_from_handle (e->session_handle);
- if (!s)
- {
- clib_warning ("session has event but doesn't exist!");
- break;
- }
- if (s->rx_fifo == f || s->tx_fifo == f)
- return 1;
- break;
- default:
- break;
- }
- return 0;
-}
-
-u8
-session_node_lookup_fifo_event (svm_fifo_t * f, session_event_t * e)
-{
- session_evt_elt_t *elt;
- session_worker_t *wrk;
- int i, index, found = 0;
- svm_msg_q_msg_t *msg;
- svm_msg_q_ring_t *ring;
- svm_msg_q_t *mq;
- u8 thread_index;
-
- ASSERT (e);
- thread_index = f->master_thread_index;
- wrk = session_main_get_worker (thread_index);
-
- /*
- * Search evt queue
- */
- mq = wrk->vpp_event_queue;
- index = mq->q->head;
- for (i = 0; i < mq->q->cursize; i++)
- {
- msg = (svm_msg_q_msg_t *) (&mq->q->data[0] + mq->q->elsize * index);
- ring = svm_msg_q_ring (mq, msg->ring_index);
- clib_memcpy_fast (e, svm_msg_q_msg_data (mq, msg), ring->elsize);
- found = session_node_cmp_event (e, f);
- if (found)
- return 1;
- index = (index + 1) % mq->q->maxsize;
- }
- /*
- * Search pending events vector
- */
-
- /* *INDENT-OFF* */
- clib_llist_foreach (wrk->event_elts, evt_list,
- pool_elt_at_index (wrk->event_elts, wrk->new_head),
- elt, ({
- found = session_node_cmp_event (&elt->evt, f);
- if (found)
- {
- clib_memcpy_fast (e, &elt->evt, sizeof (*e));
- goto done;
- }
- }));
- /* *INDENT-ON* */
-
- /* *INDENT-OFF* */
- clib_llist_foreach (wrk->event_elts, evt_list,
- pool_elt_at_index (wrk->event_elts, wrk->old_head),
- elt, ({
- found = session_node_cmp_event (&elt->evt, f);
- if (found)
- {
- clib_memcpy_fast (e, &elt->evt, sizeof (*e));
- goto done;
- }
- }));
- /* *INDENT-ON* */
-
-done:
- return found;
-}
-
static clib_error_t *
session_queue_exit (vlib_main_t * vm)
{