diff options
| -rw-r--r-- | src/vnet/CMakeLists.txt | 1 | ||||
| -rw-r--r-- | src/vnet/session/session.c | 16 | ||||
| -rw-r--r-- | src/vnet/session/session_cli.c | 79 | ||||
| -rw-r--r-- | src/vnet/session/session_debug.c | 281 | ||||
| -rw-r--r-- | src/vnet/session/session_debug.h | 145 | ||||
| -rw-r--r-- | src/vnet/session/session_node.c | 160 |
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) { |