FD.io VPP  v17.10-9-gd594711
Vector Packet Processing
trace.c
Go to the documentation of this file.
1 /*
2  * Copyright (c) 2015 Cisco and/or its affiliates.
3  * Licensed under the Apache License, Version 2.0 (the "License");
4  * you may not use this file except in compliance with the License.
5  * You may obtain a copy of the License at:
6  *
7  * http://www.apache.org/licenses/LICENSE-2.0
8  *
9  * Unless required by applicable law or agreed to in writing, software
10  * distributed under the License is distributed on an "AS IS" BASIS,
11  * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
12  * See the License for the specific language governing permissions and
13  * limitations under the License.
14  */
15 /*
16  * trace.c: VLIB trace buffer.
17  *
18  * Copyright (c) 2008 Eliot Dresselhaus
19  *
20  * Permission is hereby granted, free of charge, to any person obtaining
21  * a copy of this software and associated documentation files (the
22  * "Software"), to deal in the Software without restriction, including
23  * without limitation the rights to use, copy, modify, merge, publish,
24  * distribute, sublicense, and/or sell copies of the Software, and to
25  * permit persons to whom the Software is furnished to do so, subject to
26  * the following conditions:
27  *
28  * The above copyright notice and this permission notice shall be
29  * included in all copies or substantial portions of the Software.
30  *
31  * THE SOFTWARE IS PROVIDED "AS IS", WITHOUT WARRANTY OF ANY KIND,
32  * EXPRESS OR IMPLIED, INCLUDING BUT NOT LIMITED TO THE WARRANTIES OF
33  * MERCHANTABILITY, FITNESS FOR A PARTICULAR PURPOSE AND
34  * NONINFRINGEMENT. IN NO EVENT SHALL THE AUTHORS OR COPYRIGHT HOLDERS BE
35  * LIABLE FOR ANY CLAIM, DAMAGES OR OTHER LIABILITY, WHETHER IN AN ACTION
36  * OF CONTRACT, TORT OR OTHERWISE, ARISING FROM, OUT OF OR IN CONNECTION
37  * WITH THE SOFTWARE OR THE USE OR OTHER DEALINGS IN THE SOFTWARE.
38  */
39 
40 #include <vlib/vlib.h>
41 #include <vlib/threads.h>
42 
43 /* Helper function for nodes which only trace buffer data. */
44 void
46  vlib_node_runtime_t * node,
47  u32 * buffers,
48  uword n_buffers,
49  uword next_buffer_stride,
50  uword n_buffer_data_bytes_in_trace)
51 {
52  u32 n_left, *from;
53 
54  n_left = n_buffers;
55  from = buffers;
56 
57  while (n_left >= 4)
58  {
59  u32 bi0, bi1;
60  vlib_buffer_t *b0, *b1;
61  u8 *t0, *t1;
62 
63  /* Prefetch next iteration. */
64  vlib_prefetch_buffer_with_index (vm, from[2], LOAD);
65  vlib_prefetch_buffer_with_index (vm, from[3], LOAD);
66 
67  bi0 = from[0];
68  bi1 = from[1];
69 
70  b0 = vlib_get_buffer (vm, bi0);
71  b1 = vlib_get_buffer (vm, bi1);
72 
73  if (b0->flags & VLIB_BUFFER_IS_TRACED)
74  {
75  t0 = vlib_add_trace (vm, node, b0, n_buffer_data_bytes_in_trace);
76  clib_memcpy (t0, b0->data + b0->current_data,
77  n_buffer_data_bytes_in_trace);
78  }
79  if (b1->flags & VLIB_BUFFER_IS_TRACED)
80  {
81  t1 = vlib_add_trace (vm, node, b1, n_buffer_data_bytes_in_trace);
82  clib_memcpy (t1, b1->data + b1->current_data,
83  n_buffer_data_bytes_in_trace);
84  }
85  from += 2;
86  n_left -= 2;
87  }
88 
89  while (n_left >= 1)
90  {
91  u32 bi0;
92  vlib_buffer_t *b0;
93  u8 *t0;
94 
95  bi0 = from[0];
96 
97  b0 = vlib_get_buffer (vm, bi0);
98 
99  if (b0->flags & VLIB_BUFFER_IS_TRACED)
100  {
101  t0 = vlib_add_trace (vm, node, b0, n_buffer_data_bytes_in_trace);
102  clib_memcpy (t0, b0->data + b0->current_data,
103  n_buffer_data_bytes_in_trace);
104  }
105  from += 1;
106  n_left -= 1;
107  }
108 }
109 
110 /* Free up all trace buffer memory. */
111 always_inline void
113 {
114  int i;
115  vlib_trace_main_t *tm;
116 
117  /* *INDENT-OFF* */
119  ({
120  void *mainheap;
121 
122  tm = &this_vlib_main->trace_main;
123  mainheap = clib_mem_set_heap (this_vlib_main->heap_base);
124 
125  tm->trace_active_hint = 0;
126 
127  for (i = 0; i < vec_len (tm->trace_buffer_pool); i++)
128  if (! pool_is_free_index (tm->trace_buffer_pool, i))
129  vec_free (tm->trace_buffer_pool[i]);
131  clib_mem_set_heap (mainheap);
132  }));
133  /* *INDENT-ON* */
134 }
135 
136 static u8 *
137 format_vlib_trace (u8 * s, va_list * va)
138 {
139  vlib_main_t *vm = va_arg (*va, vlib_main_t *);
140  vlib_trace_header_t *h = va_arg (*va, vlib_trace_header_t *);
141  vlib_trace_header_t *e = vec_end (h);
142  vlib_node_t *node, *prev_node;
143  clib_time_t *ct = &vm->clib_time;
144  f64 t;
145 
146  prev_node = 0;
147  while (h < e)
148  {
149  node = vlib_get_node (vm, h->node_index);
150 
151  if (node != prev_node)
152  {
153  t =
155  s =
156  format (s, "\n%U: %v", format_time_interval, "h:m:s:u", t,
157  node->name);
158  }
159  prev_node = node;
160 
161  if (node->format_trace)
162  s = format (s, "\n %U", node->format_trace, vm, node, h->data);
163  else
164  s = format (s, "\n %U", node->format_buffer, h->data);
165 
166  h = vlib_trace_header_next (h);
167  }
168 
169  return s;
170 }
171 
172 /* Root of all trace cli commands. */
173 /* *INDENT-OFF* */
174 VLIB_CLI_COMMAND (trace_cli_command,static) = {
175  .path = "trace",
176  .short_help = "Packet tracer commands",
177 };
178 /* *INDENT-ON* */
179 
180 static int
181 trace_cmp (void *a1, void *a2)
182 {
183  vlib_trace_header_t **t1 = a1;
184  vlib_trace_header_t **t2 = a2;
185  i64 dt = t1[0]->time - t2[0]->time;
186  return dt < 0 ? -1 : (dt > 0 ? +1 : 0);
187 }
188 
189 /*
190  * Return 1 if this packet passes the trace filter, or 0 otherwise
191  */
192 u32
194 {
195  vlib_trace_header_t *e = vec_end (h);
196 
197  if (tm->filter_flag == 0)
198  return 1;
199 
200  if (tm->filter_flag == FILTER_FLAG_INCLUDE)
201  {
202  while (h < e)
203  {
204  if (h->node_index == tm->filter_node_index)
205  return 1;
206  h = vlib_trace_header_next (h);
207  }
208  return 0;
209  }
210  else /* FILTER_FLAG_EXCLUDE */
211  {
212  while (h < e)
213  {
214  if (h->node_index == tm->filter_node_index)
215  return 0;
216  h = vlib_trace_header_next (h);
217  }
218  return 1;
219  }
220 
221  return 0;
222 }
223 
224 /*
225  * Remove traces from the trace buffer pool that don't pass the filter
226  */
227 void
229 {
230  vlib_trace_main_t *tm = &vm->trace_main;
232  vlib_trace_header_t ***traces_to_remove = 0;
233  u32 index;
234  u32 trace_index;
235  u32 n_accepted;
236 
237  u32 accept;
238 
239  if (tm->filter_flag == FILTER_FLAG_NONE)
240  return;
241 
242  /*
243  * Ideally we would retain the first N traces that pass the filter instead
244  * of any N traces.
245  */
246  n_accepted = 0;
247  /* *INDENT-OFF* */
249  ({
250  accept = filter_accept(tm, h[0]);
251 
252  if ((n_accepted == tm->filter_count) || !accept)
253  vec_add1 (traces_to_remove, h);
254  else
255  n_accepted++;
256  }));
257  /* *INDENT-ON* */
258 
259  /* remove all traces that we don't want to keep */
260  for (index = 0; index < vec_len (traces_to_remove); index++)
261  {
262  trace_index = traces_to_remove[index] - tm->trace_buffer_pool;
263  _vec_len (tm->trace_buffer_pool[trace_index]) = 0;
264  pool_put_index (tm->trace_buffer_pool, trace_index);
265  }
266 
267  vec_free (traces_to_remove);
268 }
269 
270 static clib_error_t *
272  unformat_input_t * input, vlib_cli_command_t * cmd)
273 {
274  vlib_trace_main_t *tm;
275  vlib_trace_header_t **h, **traces;
276  u32 i, index = 0;
277  char *fmt;
278  u8 *s = 0;
279  u32 max;
280 
281  /*
282  * By default display only this many traces. To display more, explicitly
283  * specify a max. This prevents unexpectedly huge outputs.
284  */
285  max = 50;
287  {
288  if (unformat (input, "max %d", &max))
289  ;
290  else
291  return clib_error_create ("expected 'max COUNT', got `%U'",
292  format_unformat_error, input);
293  }
294 
295 
296  /* Get active traces from pool. */
297 
298  /* *INDENT-OFF* */
300  ({
301  void *mainheap;
302 
303  fmt = "------------------- Start of thread %d %s -------------------\n";
304  s = format (s, fmt, index, vlib_worker_threads[index].name);
305 
306  tm = &this_vlib_main->trace_main;
307 
308  mainheap = clib_mem_set_heap (this_vlib_main->heap_base);
309 
310  trace_apply_filter(this_vlib_main);
311 
312  traces = 0;
314  ({
315  vec_add1 (traces, h[0]);
316  }));
317 
318  if (vec_len (traces) == 0)
319  {
320  clib_mem_set_heap (mainheap);
321  s = format (s, "No packets in trace buffer\n");
322  goto done;
323  }
324 
325  /* Sort them by increasing time. */
327 
328  for (i = 0; i < vec_len (traces); i++)
329  {
330  if (i == max)
331  {
332  vlib_cli_output (vm, "Limiting display to %d packets."
333  " To display more specify max.", max);
334  goto done;
335  }
336 
337  clib_mem_set_heap (mainheap);
338 
339  s = format (s, "Packet %d\n%U\n\n", i + 1,
340  format_vlib_trace, vm, traces[i]);
341 
342  mainheap = clib_mem_set_heap (this_vlib_main->heap_base);
343  }
344 
345  done:
346  vec_free (traces);
347  clib_mem_set_heap (mainheap);
348 
349  index++;
350  }));
351  /* *INDENT-ON* */
352 
353  vlib_cli_output (vm, "%v", s);
354  vec_free (s);
355  return 0;
356 }
357 
358 /* *INDENT-OFF* */
359 VLIB_CLI_COMMAND (show_trace_cli,static) = {
360  .path = "show trace",
361  .short_help = "Show trace buffer [max COUNT]",
362  .function = cli_show_trace_buffer,
363 };
364 /* *INDENT-ON* */
365 
366 static clib_error_t *
368  unformat_input_t * input, vlib_cli_command_t * cmd)
369 {
370  unformat_input_t _line_input, *line_input = &_line_input;
371  vlib_trace_main_t *tm;
372  vlib_trace_node_t *tn;
373  u32 node_index, add;
374  u8 verbose = 0;
375  clib_error_t *error = 0;
376 
377  if (!unformat_user (input, unformat_line_input, line_input))
378  return 0;
379 
380  while (unformat_check_input (line_input) != (uword) UNFORMAT_END_OF_INPUT)
381  {
382  if (unformat (line_input, "%U %d",
383  unformat_vlib_node, vm, &node_index, &add))
384  ;
385  else if (unformat (line_input, "verbose"))
386  verbose = 1;
387  else
388  {
389  error = clib_error_create ("expected NODE COUNT, got `%U'",
390  format_unformat_error, line_input);
391  goto done;
392  }
393  }
394 
395  /* *INDENT-OFF* */
397  {
398  void *oldheap;
399  tm = &this_vlib_main->trace_main;
400  tm->trace_active_hint = 1;
401  tm->verbose = verbose;
402  oldheap =
403  clib_mem_set_heap (this_vlib_main->heap_base);
404  vec_validate (tm->nodes, node_index);
405  tn = tm->nodes + node_index;
406  tn->limit += add; clib_mem_set_heap (oldheap);
407  }));
408  /* *INDENT-ON* */
409 
410 done:
411  unformat_free (line_input);
412 
413  return error;
414 }
415 
416 /* *INDENT-OFF* */
417 VLIB_CLI_COMMAND (add_trace_cli,static) = {
418  .path = "trace add",
419  .short_help = "Trace given number of packets",
420  .function = cli_add_trace_buffer,
421 };
422 /* *INDENT-ON* */
423 
424 
425 /*
426  * Configure a filter for packet traces.
427  *
428  * This supplements the packet trace feature so that only packets matching
429  * the filter are included in the trace. Currently the only filter is to
430  * keep packets that include a certain node in the trace or exclude a certain
431  * node in the trace.
432  *
433  * The count of traced packets in the "trace add" command is still used to
434  * create a certain number of traces. The "trace filter" command specifies
435  * how many of those packets should be retained in the trace.
436  *
437  * For example, 1Mpps of traffic is arriving and one of those packets is being
438  * dropped. To capture the trace for only that dropped packet, you can do:
439  * trace filter include error-drop 1
440  * trace add dpdk-input 1000000
441  * <wait one second>
442  * show trace
443  *
444  * Note that the filter could be implemented by capturing all traces and just
445  * reducing traces displayed by the "show trace" function. But that would
446  * require a lot of memory for storing the traces, making that infeasible.
447  *
448  * To remove traces from the trace pool that do not include a certain node
449  * requires that the trace be "complete" before applying the filter. To
450  * accomplish this, the trace pool is filtered upon each iteraction of the
451  * main vlib loop. Doing so keeps the number of allocated traces down to a
452  * reasonably low number. This requires that tracing for a buffer is not
453  * performed after the vlib main loop interation completes. i.e. you can't
454  * save away a buffer temporarily then inject it back into the graph and
455  * expect that the trace_index is still valid (such as a traffic manager might
456  * do). A new trace buffer should be allocated for those types of packets.
457  *
458  * The filter can be extended to support multiple nodes and other match
459  * criteria (e.g. input sw_if_index, mac address) but for now just checks if
460  * a specified node is in the trace or not in the trace.
461  */
462 static clib_error_t *
464  unformat_input_t * input, vlib_cli_command_t * cmd)
465 {
466  vlib_trace_main_t *tm = &vm->trace_main;
467  u32 filter_node_index;
468  u32 filter_flag;
469  u32 filter_count;
470  void *mainheap;
471 
472  if (unformat (input, "include %U %d",
473  unformat_vlib_node, vm, &filter_node_index, &filter_count))
474  {
475  filter_flag = FILTER_FLAG_INCLUDE;
476  }
477  else if (unformat (input, "exclude %U %d",
478  unformat_vlib_node, vm, &filter_node_index,
479  &filter_count))
480  {
481  filter_flag = FILTER_FLAG_EXCLUDE;
482  }
483  else if (unformat (input, "none"))
484  {
485  filter_flag = FILTER_FLAG_NONE;
486  filter_node_index = 0;
487  filter_count = 0;
488  }
489  else
490  return
492  ("expected 'include NODE COUNT' or 'exclude NODE COUNT' or 'none', got `%U'",
493  format_unformat_error, input);
494 
495  /* *INDENT-OFF* */
497  ({
498  tm = &this_vlib_main->trace_main;
499  tm->filter_node_index = filter_node_index;
500  tm->filter_flag = filter_flag;
501  tm->filter_count = filter_count;
502 
503  /*
504  * Clear the trace limits to stop any in-progress tracing
505  * Prevents runaway trace allocations when the filter changes (or is removed)
506  */
507  mainheap = clib_mem_set_heap (this_vlib_main->heap_base);
508  vec_free (tm->nodes);
509  clib_mem_set_heap (mainheap);
510  }));
511  /* *INDENT-ON* */
512 
513  return 0;
514 }
515 
516 /* *INDENT-OFF* */
517 VLIB_CLI_COMMAND (filter_trace_cli,static) = {
518  .path = "trace filter",
519  .short_help = "filter trace output - include NODE COUNT | exclude NODE COUNT | none",
520  .function = cli_filter_trace,
521 };
522 /* *INDENT-ON* */
523 
524 static clib_error_t *
526  unformat_input_t * input, vlib_cli_command_t * cmd)
527 {
529  return 0;
530 }
531 
532 /* *INDENT-OFF* */
533 VLIB_CLI_COMMAND (clear_trace_cli,static) = {
534  .path = "clear trace",
535  .short_help = "Clear trace buffer and free memory",
536  .function = cli_clear_trace_buffer,
537 };
538 /* *INDENT-ON* */
539 
540 /* Dummy function to get us linked in. */
541 void
543 {
544 }
545 
546 /*
547  * fd.io coding-style-patch-verification: ON
548  *
549  * Local Variables:
550  * eval: (c-set-style "gnu")
551  * End:
552  */
#define vec_validate(V, I)
Make sure vector is long enough for given index (no header, unspecified alignment) ...
Definition: vec.h:432
u32 filter_flag
Definition: trace.h:76
sll srl srl sll sra u16x4 i
Definition: vector_sse2.h:337
u32 trace_active_hint
Definition: trace.h:83
void vlib_trace_cli_reference(void)
Definition: trace.c:542
vlib_trace_node_t * nodes
Definition: trace.h:86
static clib_error_t * cli_clear_trace_buffer(vlib_main_t *vm, unformat_input_t *input, vlib_cli_command_t *cmd)
Definition: trace.c:525
static vlib_trace_header_t * vlib_trace_header_next(vlib_trace_header_t *h)
Definition: trace_funcs.h:77
format_function_t * format_trace
Definition: node.h:315
uword unformat_user(unformat_input_t *input, unformat_function_t *func,...)
Definition: unformat.c:983
u8 * format(u8 *s, const char *fmt,...)
Definition: format.c:419
clib_time_t clib_time
Definition: main.h:62
u32 filter_node_index
Definition: trace.h:75
static clib_error_t * cli_show_trace_buffer(vlib_main_t *vm, unformat_input_t *input, vlib_cli_command_t *cmd)
Definition: trace.c:271
vlib_trace_header_t ** trace_buffer_pool
Definition: trace.h:72
i16 current_data
signed offset in data[], pre_data[] that we are currently processing.
Definition: buffer.h:68
#define pool_foreach(VAR, POOL, BODY)
Iterate through pool.
Definition: pool.h:437
#define vlib_prefetch_buffer_with_index(vm, bi, type)
Prefetch buffer metadata by buffer index The first 64 bytes of buffer contains most header informatio...
Definition: buffer_funcs.h:180
#define always_inline
Definition: clib.h:84
#define vec_end(v)
End (last data address) of vector.
#define clib_error_create(args...)
Definition: error.h:96
u64 cpu_time_main_loop_start
Definition: main.h:68
u32 filter_accept(vlib_trace_main_t *tm, vlib_trace_header_t *h)
Definition: trace.c:193
unformat_function_t unformat_line_input
Definition: format.h:281
vlib_worker_thread_t * vlib_worker_threads
Definition: threads.c:35
add
Definition: vector_sse2.h:279
#define FILTER_FLAG_EXCLUDE
Definition: trace.h:79
struct _unformat_input_t unformat_input_t
#define FILTER_FLAG_NONE
Definition: trace.h:77
static int trace_cmp(void *a1, void *a2)
Definition: trace.c:181
f64 seconds_per_clock
Definition: time.h:57
format_function_t * format_buffer
Definition: node.h:311
#define foreach_vlib_main(body)
Definition: threads.h:244
long i64
Definition: types.h:82
u8 * name
Definition: node.h:221
u32 filter_count
Definition: trace.h:80
#define pool_free(p)
Free a pool.
Definition: pool.h:351
#define UNFORMAT_END_OF_INPUT
Definition: format.h:143
static clib_error_t * cli_filter_trace(vlib_main_t *vm, unformat_input_t *input, vlib_cli_command_t *cmd)
Definition: trace.c:463
vlib_main_t * vm
Definition: buffer.c:283
vec_header_t h
Definition: buffer.c:282
static clib_error_t * cli_add_trace_buffer(vlib_main_t *vm, unformat_input_t *input, vlib_cli_command_t *cmd)
Definition: trace.c:367
#define vec_free(V)
Free vector&#39;s memory (no header).
Definition: vec.h:336
static void * clib_mem_set_heap(void *heap)
Definition: mem.h:226
#define VLIB_BUFFER_IS_TRACED
Definition: buffer.h:93
#define clib_memcpy(a, b, c)
Definition: string.h:69
#define pool_is_free_index(P, I)
Use free bitmap to query whether given index is free.
Definition: pool.h:267
#define VLIB_CLI_COMMAND(x,...)
Definition: cli.h:154
#define pool_put_index(p, i)
Free pool element with given index.
Definition: pool.h:293
unsigned int u32
Definition: types.h:88
static void clear_trace_buffer(void)
Definition: trace.c:112
vlib_trace_main_t trace_main
Definition: main.h:135
u64 uword
Definition: types.h:112
static void * vlib_add_trace(vlib_main_t *vm, vlib_node_runtime_t *r, vlib_buffer_t *b, u32 n_data_bytes)
Definition: trace_funcs.h:55
void vlib_trace_frame_buffers_only(vlib_main_t *vm, vlib_node_runtime_t *node, u32 *buffers, uword n_buffers, uword next_buffer_stride, uword n_buffer_data_bytes_in_trace)
Definition: trace.c:45
#define vec_len(v)
Number of elements in vector (rvalue-only, NULL tolerant)
double f64
Definition: types.h:142
unsigned char u8
Definition: types.h:56
#define vec_sort_with_function(vec, f)
Sort a vector using the supplied element comparison function.
Definition: vec.h:956
static void unformat_free(unformat_input_t *i)
Definition: format.h:161
u8 * format_time_interval(u8 *s, va_list *args)
Definition: std-formats.c:122
unformat_function_t unformat_vlib_node
Definition: node_funcs.h:1155
u8 * format_unformat_error(u8 *s, va_list *va)
Definition: unformat.c:91
u8 data[0]
Packet data.
Definition: buffer.h:157
static vlib_node_t * vlib_get_node(vlib_main_t *vm, u32 i)
Get vlib node by index.
Definition: node_funcs.h:59
u32 flags
buffer flags: VLIB_BUFFER_FREE_LIST_INDEX_MASK: bits used to store free list index, VLIB_BUFFER_IS_TRACED: trace this buffer.
Definition: buffer.h:75
void vlib_cli_output(vlib_main_t *vm, char *fmt,...)
Definition: cli.c:680
static vlib_buffer_t * vlib_get_buffer(vlib_main_t *vm, u32 buffer_index)
Translate buffer index into buffer pointer.
Definition: buffer_funcs.h:57
void trace_apply_filter(vlib_main_t *vm)
Definition: trace.c:228
static u8 * format_vlib_trace(u8 *s, va_list *va)
Definition: trace.c:137
uword unformat(unformat_input_t *i, const char *fmt,...)
Definition: unformat.c:972
static uword unformat_check_input(unformat_input_t *i)
Definition: format.h:169
#define FILTER_FLAG_INCLUDE
Definition: trace.h:78