From 0bcc9d511e52a9832e723825b4c84d9332d7025b Mon Sep 17 00:00:00 2001 From: Bud Grise Date: Tue, 2 Feb 2016 14:23:29 -0500 Subject: Tracing enhancements. Limit buffer tracing to 50 in order to limit large output, unless the user over rides the max "sh trace max ". Add trace filtering, to be able to only trace packets that were processed by a specific node or exclude packets processed by a node. Example, only include packets processed by error-drop: # trace filter include error-drop 1 # trace add dpdk-input 1000000 # show trace Change-Id: I5d9e15d2268ea55e6ef87b2b8756049c49b2791b Signed-off-by: Todd Foggoa --- vlib/vlib/trace.c | 206 ++++++++++++++++++++++++++++++++++++++++++++++-- vlib/vlib/trace.h | 8 ++ vlib/vlib/trace_funcs.h | 12 +++ 3 files changed, 221 insertions(+), 5 deletions(-) diff --git a/vlib/vlib/trace.c b/vlib/vlib/trace.c index 03f25385..b3008644 100644 --- a/vlib/vlib/trace.c +++ b/vlib/vlib/trace.c @@ -109,9 +109,10 @@ vlib_trace_frame_buffers_only (vlib_main_t * vm, /* Free up all trace buffer memory. */ always_inline void -clear_trace_buffer (vlib_trace_main_t * tm) +clear_trace_buffer (void) { int i; + vlib_trace_main_t * tm; foreach_vlib_main ( ({ @@ -179,16 +180,108 @@ trace_cmp (void * a1, void * a2) return dt < 0 ? -1 : (dt > 0 ? +1 : 0); } +/* + * Return 1 if this packet passes the trace filter, or 0 otherwise + */ +u32 filter_accept (vlib_trace_main_t * tm, vlib_trace_header_t * h) +{ + vlib_trace_header_t * e = vec_end (h); + + if (tm->filter_flag == 0) return 1; + + if (tm->filter_flag == FILTER_FLAG_INCLUDE) + { + while (h < e) + { + if (h->node_index == tm->filter_node_index) + return 1; + h = vlib_trace_header_next (h); + } + return 0; + } + else /* FILTER_FLAG_EXCLUDE */ + { + while (h < e) + { + if (h->node_index == tm->filter_node_index) + return 0; + h = vlib_trace_header_next (h); + } + return 1; + } + + return 0; +} + +/* + * Remove traces from the trace buffer pool that don't pass the filter + */ +void trace_apply_filter (vlib_main_t * vm) +{ + vlib_trace_main_t * tm = &vm->trace_main; + vlib_trace_header_t ** h; + vlib_trace_header_t *** traces_to_remove = 0; + u32 index; + u32 trace_index; + u32 n_accepted; + + u32 accept; + + if (tm->filter_flag == FILTER_FLAG_NONE) + return; + + /* + * Ideally we would retain the first N traces that pass the filter instead + * of any N traces. + */ + n_accepted = 0; + pool_foreach (h, tm->trace_buffer_pool, + ({ + accept = filter_accept(tm, h[0]); + + if ((n_accepted == tm->filter_count) || !accept) + vec_add1 (traces_to_remove, h); + else + n_accepted++; + })); + + /* remove all traces that we don't want to keep */ + for (index=0; indextrace_buffer_pool; + _vec_len (tm->trace_buffer_pool[trace_index]) = 0; + pool_put_index (tm->trace_buffer_pool, trace_index); + } + + vec_free (traces_to_remove); +} + static clib_error_t * cli_show_trace_buffer (vlib_main_t * vm, unformat_input_t * input, vlib_cli_command_t * cmd) { - vlib_trace_main_t * tm = &vm->trace_main; + vlib_trace_main_t * tm; vlib_trace_header_t ** h, ** traces; u32 i, index = 0; char * fmt; u8 * s = 0; + u32 max; + + /* + * By default display only this many traces. To display more, explicitly + * specify a max. This prevents unexpectedly huge outputs. + */ + max = 50; + while (unformat_check_input(input) != (uword)UNFORMAT_END_OF_INPUT) + { + if (unformat (input, "max %d", &max)) + ; + else + return clib_error_create ("expected 'max COUNT', got `%U'", + format_unformat_error, input); + } + /* Get active traces from pool. */ @@ -202,6 +295,9 @@ cli_show_trace_buffer (vlib_main_t * vm, tm = &this_vlib_main->trace_main; mainheap = clib_mem_set_heap (this_vlib_main->heap_base); + + trace_apply_filter(this_vlib_main); + traces = 0; pool_foreach (h, tm->trace_buffer_pool, ({ @@ -220,6 +316,13 @@ cli_show_trace_buffer (vlib_main_t * vm, for (i = 0; i < vec_len (traces); i++) { + if (i == max) + { + vlib_cli_output (vm, "Limiting display to %d packets." + " To display more specify max.", max); + goto done; + } + clib_mem_set_heap (mainheap); s = format (s, "Packet %d\n%U\n\n", i + 1, @@ -242,7 +345,7 @@ cli_show_trace_buffer (vlib_main_t * vm, VLIB_CLI_COMMAND (show_trace_cli,static) = { .path = "show trace", - .short_help = "Show trace buffer", + .short_help = "Show trace buffer [max COUNT]", .function = cli_show_trace_buffer, }; @@ -283,13 +386,106 @@ VLIB_CLI_COMMAND (add_trace_cli,static) = { .function = cli_add_trace_buffer, }; + +/* + * Configure a filter for packet traces. + * + * This supplements the packet trace feature so that only packets matching + * the filter are included in the trace. Currently the only filter is to + * keep packets that include a certain node in the trace or exclude a certain + * node in the trace. + * + * The count of traced packets in the "trace add" command is still used to + * create a certain number of traces. The "trace filter" command specifies + * how many of those packets should be retained in the trace. + * + * For example, 1Mpps of traffic is arriving and one of those packets is being + * dropped. To capture the trace for only that dropped packet, you can do: + * trace filter include error-drop 1 + * trace add dpdk-input 1000000 + * + * show trace + * + * Note that the filter could be implemented by capturing all traces and just + * reducing traces displayed by the "show trace" function. But that would + * require a lot of memory for storing the traces, making that infeasible. + * + * To remove traces from the trace pool that do not include a certain node + * requires that the trace be "complete" before applying the filter. To + * accomplish this, the trace pool is filtered upon each iteraction of the + * main vlib loop. Doing so keeps the number of allocated traces down to a + * reasonably low number. This requires that tracing for a buffer is not + * performed after the vlib main loop interation completes. i.e. you can't + * save away a buffer temporarily then inject it back into the graph and + * expect that the trace_index is still valid (such as a traffic manager might + * do). A new trace buffer should be allocated for those types of packets. + * + * The filter can be extended to support multiple nodes and other match + * criteria (e.g. input sw_if_index, mac address) but for now just checks if + * a specified node is in the trace or not in the trace. + */ +static clib_error_t * +cli_filter_trace (vlib_main_t * vm, + unformat_input_t * input, + vlib_cli_command_t * cmd) +{ + vlib_trace_main_t * tm = &vm->trace_main; + u32 filter_node_index; + u32 filter_flag; + u32 filter_count; + void *mainheap; + + if (unformat (input, "include %U %d", + unformat_vlib_node, vm, &filter_node_index, &filter_count)) + { + filter_flag = FILTER_FLAG_INCLUDE; + } + else if (unformat (input, "exclude %U %d", + unformat_vlib_node, vm, &filter_node_index, &filter_count)) + { + filter_flag = FILTER_FLAG_EXCLUDE; + } + else if (unformat (input, "none")) + { + filter_flag = FILTER_FLAG_NONE; + filter_node_index = 0; + filter_count = 0; + } + else + return clib_error_create ("expected 'include NODE COUNT' or 'exclude NODE COUNT' or 'none', got `%U'", + format_unformat_error, input); + + foreach_vlib_main ( + ({ + tm = &this_vlib_main->trace_main; + tm->filter_node_index = filter_node_index; + tm->filter_flag = filter_flag; + tm->filter_count = filter_count; + + /* + * Clear the trace limits to stop any in-progress tracing + * Prevents runaway trace allocations when the filter changes (or is removed) + */ + mainheap = clib_mem_set_heap (this_vlib_main->heap_base); + vec_free (tm->nodes); + clib_mem_set_heap (mainheap); + })); + + return 0; +} + +VLIB_CLI_COMMAND (filter_trace_cli,static) = { + .path = "trace filter", + .short_help = "filter trace output - include NODE COUNT | exclude NODE COUNT | none", + .function = cli_filter_trace, +}; + static clib_error_t * cli_clear_trace_buffer (vlib_main_t * vm, unformat_input_t * input, vlib_cli_command_t * cmd) { - vlib_trace_main_t * tm = &vm->trace_main; - clear_trace_buffer (tm); + clear_trace_buffer (); return 0; } diff --git a/vlib/vlib/trace.h b/vlib/vlib/trace.h index 228a22ab..50e51638 100644 --- a/vlib/vlib/trace.h +++ b/vlib/vlib/trace.h @@ -68,6 +68,14 @@ typedef struct { /* Pool of trace buffers. */ vlib_trace_header_t ** trace_buffer_pool; + u32 last_main_loop_count; + u32 filter_node_index; + u32 filter_flag; +#define FILTER_FLAG_NONE 0 +#define FILTER_FLAG_INCLUDE 1 +#define FILTER_FLAG_EXCLUDE 2 + u32 filter_count; + /* Per node trace counts. */ vlib_trace_node_t * nodes; } vlib_trace_main_t; diff --git a/vlib/vlib/trace_funcs.h b/vlib/vlib/trace_funcs.h index 3dc7471e..1da46b41 100644 --- a/vlib/vlib/trace_funcs.h +++ b/vlib/vlib/trace_funcs.h @@ -99,6 +99,8 @@ vlib_trace_next_frame (vlib_main_t * vm, nf->flags |= VLIB_FRAME_TRACE; } +void trace_apply_filter (vlib_main_t * vm); + /* Mark buffer as traced and allocate trace buffer. */ always_inline void vlib_trace_buffer (vlib_main_t * vm, @@ -110,6 +112,16 @@ vlib_trace_buffer (vlib_main_t * vm, vlib_trace_main_t * tm = &vm->trace_main; vlib_trace_header_t ** h; + /* + * Apply filter to existing traces to keep number of allocated traces low. + * Performed each time around the main loop. + */ + if (tm->last_main_loop_count != vm->main_loop_count) + { + tm->last_main_loop_count = vm->main_loop_count; + trace_apply_filter (vm); + } + vlib_trace_next_frame (vm, r, next_index); pool_get (tm->trace_buffer_pool, h); -- cgit 1.2.3-korg