FD.io VPP  v19.04.2-12-g66b1689
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 
44 
45 /* Helper function for nodes which only trace buffer data. */
46 void
48  vlib_node_runtime_t * node,
49  u32 * buffers,
50  uword n_buffers,
51  uword next_buffer_stride,
52  uword n_buffer_data_bytes_in_trace)
53 {
54  u32 n_left, *from;
55 
56  n_left = n_buffers;
57  from = buffers;
58 
59  while (n_left >= 4)
60  {
61  u32 bi0, bi1;
62  vlib_buffer_t *b0, *b1;
63  u8 *t0, *t1;
64 
65  /* Prefetch next iteration. */
66  vlib_prefetch_buffer_with_index (vm, from[2], LOAD);
67  vlib_prefetch_buffer_with_index (vm, from[3], LOAD);
68 
69  bi0 = from[0];
70  bi1 = from[1];
71 
72  b0 = vlib_get_buffer (vm, bi0);
73  b1 = vlib_get_buffer (vm, bi1);
74 
75  if (b0->flags & VLIB_BUFFER_IS_TRACED)
76  {
77  t0 = vlib_add_trace (vm, node, b0, n_buffer_data_bytes_in_trace);
78  clib_memcpy_fast (t0, b0->data + b0->current_data,
79  n_buffer_data_bytes_in_trace);
80  }
81  if (b1->flags & VLIB_BUFFER_IS_TRACED)
82  {
83  t1 = vlib_add_trace (vm, node, b1, n_buffer_data_bytes_in_trace);
84  clib_memcpy_fast (t1, b1->data + b1->current_data,
85  n_buffer_data_bytes_in_trace);
86  }
87  from += 2;
88  n_left -= 2;
89  }
90 
91  while (n_left >= 1)
92  {
93  u32 bi0;
94  vlib_buffer_t *b0;
95  u8 *t0;
96 
97  bi0 = from[0];
98 
99  b0 = vlib_get_buffer (vm, bi0);
100 
101  if (b0->flags & VLIB_BUFFER_IS_TRACED)
102  {
103  t0 = vlib_add_trace (vm, node, b0, n_buffer_data_bytes_in_trace);
104  clib_memcpy_fast (t0, b0->data + b0->current_data,
105  n_buffer_data_bytes_in_trace);
106  }
107  from += 1;
108  n_left -= 1;
109  }
110 }
111 
112 /* Free up all trace buffer memory. */
113 always_inline void
115 {
116  int i;
117  vlib_trace_main_t *tm;
118 
119  /* *INDENT-OFF* */
121  ({
122  tm = &this_vlib_main->trace_main;
123 
124  tm->trace_enable = 0;
125 
126  for (i = 0; i < vec_len (tm->trace_buffer_pool); i++)
127  if (! pool_is_free_index (tm->trace_buffer_pool, i))
128  vec_free (tm->trace_buffer_pool[i]);
130  }));
131  /* *INDENT-ON* */
132 }
133 
134 u8 *
135 format_vlib_trace (u8 * s, va_list * va)
136 {
137  vlib_main_t *vm = va_arg (*va, vlib_main_t *);
138  vlib_trace_header_t *h = va_arg (*va, vlib_trace_header_t *);
139  vlib_trace_header_t *e = vec_end (h);
140  vlib_node_t *node, *prev_node;
141  clib_time_t *ct = &vm->clib_time;
142  f64 t;
143 
144  prev_node = 0;
145  while (h < e)
146  {
147  node = vlib_get_node (vm, h->node_index);
148 
149  if (node != prev_node)
150  {
151  t =
153  s =
154  format (s, "\n%U: %v", format_time_interval, "h:m:s:u", t,
155  node->name);
156  }
157  prev_node = node;
158 
159  if (node->format_trace)
160  s = format (s, "\n %U", node->format_trace, vm, node, h->data);
161  else
162  s = format (s, "\n %U", node->format_buffer, h->data);
163 
164  h = vlib_trace_header_next (h);
165  }
166 
167  return s;
168 }
169 
170 /* Root of all trace cli commands. */
171 /* *INDENT-OFF* */
172 VLIB_CLI_COMMAND (trace_cli_command,static) = {
173  .path = "trace",
174  .short_help = "Packet tracer commands",
175 };
176 /* *INDENT-ON* */
177 
178 static int
179 trace_cmp (void *a1, void *a2)
180 {
181  vlib_trace_header_t **t1 = a1;
182  vlib_trace_header_t **t2 = a2;
183  i64 dt = t1[0]->time - t2[0]->time;
184  return dt < 0 ? -1 : (dt > 0 ? +1 : 0);
185 }
186 
187 /*
188  * Return 1 if this packet passes the trace filter, or 0 otherwise
189  */
190 u32
192 {
193  vlib_trace_header_t *e = vec_end (h);
194 
195  if (tm->filter_flag == 0)
196  return 1;
197 
198  if (tm->filter_flag == FILTER_FLAG_INCLUDE)
199  {
200  while (h < e)
201  {
202  if (h->node_index == tm->filter_node_index)
203  return 1;
204  h = vlib_trace_header_next (h);
205  }
206  return 0;
207  }
208  else /* FILTER_FLAG_EXCLUDE */
209  {
210  while (h < e)
211  {
212  if (h->node_index == tm->filter_node_index)
213  return 0;
214  h = vlib_trace_header_next (h);
215  }
216  return 1;
217  }
218 
219  return 0;
220 }
221 
222 /*
223  * Remove traces from the trace buffer pool that don't pass the filter
224  */
225 void
227 {
228  vlib_trace_main_t *tm = &vm->trace_main;
230  vlib_trace_header_t ***traces_to_remove = 0;
231  u32 index;
232  u32 trace_index;
233  u32 n_accepted;
234 
235  u32 accept;
236 
237  if (tm->filter_flag == FILTER_FLAG_NONE)
238  return;
239 
240  /*
241  * Ideally we would retain the first N traces that pass the filter instead
242  * of any N traces.
243  */
244  n_accepted = 0;
245  /* *INDENT-OFF* */
247  ({
248  accept = filter_accept(tm, h[0]);
249 
250  if ((n_accepted == tm->filter_count) || !accept)
251  vec_add1 (traces_to_remove, h);
252  else
253  n_accepted++;
254  }));
255  /* *INDENT-ON* */
256 
257  /* remove all traces that we don't want to keep */
258  for (index = 0; index < vec_len (traces_to_remove); index++)
259  {
260  trace_index = traces_to_remove[index] - tm->trace_buffer_pool;
261  _vec_len (tm->trace_buffer_pool[trace_index]) = 0;
262  pool_put_index (tm->trace_buffer_pool, trace_index);
263  }
264 
265  vec_free (traces_to_remove);
266 }
267 
268 static clib_error_t *
270  unformat_input_t * input, vlib_cli_command_t * cmd)
271 {
272  vlib_trace_main_t *tm;
273  vlib_trace_header_t **h, **traces;
274  u32 i, index = 0;
275  char *fmt;
276  u8 *s = 0;
277  u32 max;
278 
279  /*
280  * By default display only this many traces. To display more, explicitly
281  * specify a max. This prevents unexpectedly huge outputs.
282  */
283  max = 50;
285  {
286  if (unformat (input, "max %d", &max))
287  ;
288  else
289  return clib_error_create ("expected 'max COUNT', got `%U'",
290  format_unformat_error, input);
291  }
292 
293 
294  /* Get active traces from pool. */
295 
296  /* *INDENT-OFF* */
298  ({
299  fmt = "------------------- Start of thread %d %s -------------------\n";
300  s = format (s, fmt, index, vlib_worker_threads[index].name);
301 
302  tm = &this_vlib_main->trace_main;
303 
304  trace_apply_filter(this_vlib_main);
305 
306  traces = 0;
308  ({
309  vec_add1 (traces, h[0]);
310  }));
311 
312  if (vec_len (traces) == 0)
313  {
314  s = format (s, "No packets in trace buffer\n");
315  goto done;
316  }
317 
318  /* Sort them by increasing time. */
320 
321  for (i = 0; i < vec_len (traces); i++)
322  {
323  if (i == max)
324  {
325  vlib_cli_output (vm, "Limiting display to %d packets."
326  " To display more specify max.", max);
327  goto done;
328  }
329 
330  s = format (s, "Packet %d\n%U\n\n", i + 1,
331  format_vlib_trace, vm, traces[i]);
332  }
333 
334  done:
335  vec_free (traces);
336 
337  index++;
338  }));
339  /* *INDENT-ON* */
340 
341  vlib_cli_output (vm, "%v", s);
342  vec_free (s);
343  return 0;
344 }
345 
346 /* *INDENT-OFF* */
347 VLIB_CLI_COMMAND (show_trace_cli,static) = {
348  .path = "show trace",
349  .short_help = "Show trace buffer [max COUNT]",
350  .function = cli_show_trace_buffer,
351 };
352 /* *INDENT-ON* */
353 
354 static clib_error_t *
356  unformat_input_t * input, vlib_cli_command_t * cmd)
357 {
358  unformat_input_t _line_input, *line_input = &_line_input;
359  vlib_trace_main_t *tm;
360  vlib_trace_node_t *tn;
361  u32 node_index, add;
362  u8 verbose = 0;
363  clib_error_t *error = 0;
364 
365  if (!unformat_user (input, unformat_line_input, line_input))
366  return 0;
367 
368  if (vnet_trace_dummy == 0)
370 
371  while (unformat_check_input (line_input) != (uword) UNFORMAT_END_OF_INPUT)
372  {
373  if (unformat (line_input, "%U %d",
374  unformat_vlib_node, vm, &node_index, &add))
375  ;
376  else if (unformat (line_input, "verbose"))
377  verbose = 1;
378  else
379  {
380  error = clib_error_create ("expected NODE COUNT, got `%U'",
381  format_unformat_error, line_input);
382  goto done;
383  }
384  }
385 
386  /* *INDENT-OFF* */
388  {
389  tm = &this_vlib_main->trace_main;
390  tm->verbose = verbose;
391  vec_validate (tm->nodes, node_index);
392  tn = tm->nodes + node_index;
393  tn->limit += add;
394  tm->trace_enable = 1;
395  }));
396  /* *INDENT-ON* */
397 
398 done:
399  unformat_free (line_input);
400 
401  return error;
402 }
403 
404 /* *INDENT-OFF* */
405 VLIB_CLI_COMMAND (add_trace_cli,static) = {
406  .path = "trace add",
407  .short_help = "Trace given number of packets",
408  .function = cli_add_trace_buffer,
409 };
410 /* *INDENT-ON* */
411 
412 
413 /*
414  * Configure a filter for packet traces.
415  *
416  * This supplements the packet trace feature so that only packets matching
417  * the filter are included in the trace. Currently the only filter is to
418  * keep packets that include a certain node in the trace or exclude a certain
419  * node in the trace.
420  *
421  * The count of traced packets in the "trace add" command is still used to
422  * create a certain number of traces. The "trace filter" command specifies
423  * how many of those packets should be retained in the trace.
424  *
425  * For example, 1Mpps of traffic is arriving and one of those packets is being
426  * dropped. To capture the trace for only that dropped packet, you can do:
427  * trace filter include error-drop 1
428  * trace add dpdk-input 1000000
429  * <wait one second>
430  * show trace
431  *
432  * Note that the filter could be implemented by capturing all traces and just
433  * reducing traces displayed by the "show trace" function. But that would
434  * require a lot of memory for storing the traces, making that infeasible.
435  *
436  * To remove traces from the trace pool that do not include a certain node
437  * requires that the trace be "complete" before applying the filter. To
438  * accomplish this, the trace pool is filtered upon each iteraction of the
439  * main vlib loop. Doing so keeps the number of allocated traces down to a
440  * reasonably low number. This requires that tracing for a buffer is not
441  * performed after the vlib main loop interation completes. i.e. you can't
442  * save away a buffer temporarily then inject it back into the graph and
443  * expect that the trace_index is still valid (such as a traffic manager might
444  * do). A new trace buffer should be allocated for those types of packets.
445  *
446  * The filter can be extended to support multiple nodes and other match
447  * criteria (e.g. input sw_if_index, mac address) but for now just checks if
448  * a specified node is in the trace or not in the trace.
449  */
450 static clib_error_t *
452  unformat_input_t * input, vlib_cli_command_t * cmd)
453 {
454  vlib_trace_main_t *tm = &vm->trace_main;
455  u32 filter_node_index;
456  u32 filter_flag;
457  u32 filter_count;
458 
459  if (unformat (input, "include %U %d",
460  unformat_vlib_node, vm, &filter_node_index, &filter_count))
461  {
462  filter_flag = FILTER_FLAG_INCLUDE;
463  }
464  else if (unformat (input, "exclude %U %d",
465  unformat_vlib_node, vm, &filter_node_index,
466  &filter_count))
467  {
468  filter_flag = FILTER_FLAG_EXCLUDE;
469  }
470  else if (unformat (input, "none"))
471  {
472  filter_flag = FILTER_FLAG_NONE;
473  filter_node_index = 0;
474  filter_count = 0;
475  }
476  else
477  return
479  ("expected 'include NODE COUNT' or 'exclude NODE COUNT' or 'none', got `%U'",
480  format_unformat_error, input);
481 
482  /* *INDENT-OFF* */
484  ({
485  tm = &this_vlib_main->trace_main;
486  tm->filter_node_index = filter_node_index;
487  tm->filter_flag = filter_flag;
488  tm->filter_count = filter_count;
489 
490  /*
491  * Clear the trace limits to stop any in-progress tracing
492  * Prevents runaway trace allocations when the filter changes
493  * (or is removed)
494  */
495  vec_free (tm->nodes);
496  }));
497  /* *INDENT-ON* */
498 
499  return 0;
500 }
501 
502 /* *INDENT-OFF* */
503 VLIB_CLI_COMMAND (filter_trace_cli,static) = {
504  .path = "trace filter",
505  .short_help = "filter trace output - include NODE COUNT | exclude NODE COUNT | none",
506  .function = cli_filter_trace,
507 };
508 /* *INDENT-ON* */
509 
510 static clib_error_t *
512  unformat_input_t * input, vlib_cli_command_t * cmd)
513 {
515  return 0;
516 }
517 
518 /* *INDENT-OFF* */
519 VLIB_CLI_COMMAND (clear_trace_cli,static) = {
520  .path = "clear trace",
521  .short_help = "Clear trace buffer and free memory",
522  .function = cli_clear_trace_buffer,
523 };
524 /* *INDENT-ON* */
525 
526 /* Dummy function to get us linked in. */
527 void
529 {
530 }
531 
532 /*
533  * fd.io coding-style-patch-verification: ON
534  *
535  * Local Variables:
536  * eval: (c-set-style "gnu")
537  * End:
538  */
#define vec_validate(V, I)
Make sure vector is long enough for given index (no header, unspecified alignment) ...
Definition: vec.h:439
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:124
u32 filter_flag
Definition: trace.h:76
void vlib_trace_cli_reference(void)
Definition: trace.c:528
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:511
i16 current_data
signed offset in data[], pre_data[] that we are currently processing.
Definition: buffer.h:110
#define clib_memcpy_fast(a, b, c)
Definition: string.h:81
static vlib_trace_header_t * vlib_trace_header_next(vlib_trace_header_t *h)
Definition: trace_funcs.h:87
format_function_t * format_trace
Definition: node.h:360
u8 data[0]
Packet data.
Definition: buffer.h:181
int i
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:424
clib_time_t clib_time
Definition: main.h:72
#define vec_validate_aligned(V, I, A)
Make sure vector is long enough for given index (no header, specified alignment)
Definition: vec.h:450
unsigned char u8
Definition: types.h:56
u32 filter_node_index
Definition: trace.h:75
double f64
Definition: types.h:142
static clib_error_t * cli_show_trace_buffer(vlib_main_t *vm, unformat_input_t *input, vlib_cli_command_t *cmd)
Definition: trace.c:269
vlib_trace_header_t ** trace_buffer_pool
Definition: trace.h:72
u32 trace_enable
Definition: trace.h:83
#define pool_foreach(VAR, POOL, BODY)
Iterate through pool.
Definition: pool.h:493
#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:440
#define always_inline
Definition: clib.h:98
unsigned int u32
Definition: types.h:88
#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:81
u32 filter_accept(vlib_trace_main_t *tm, vlib_trace_header_t *h)
Definition: trace.c:191
unformat_function_t unformat_line_input
Definition: format.h:282
vlib_worker_thread_t * vlib_worker_threads
Definition: threads.c:36
#define FILTER_FLAG_EXCLUDE
Definition: trace.h:79
u8 * format_vlib_trace(u8 *s, va_list *va)
Definition: trace.c:135
struct _unformat_input_t unformat_input_t
signed long i64
Definition: types.h:78
#define FILTER_FLAG_NONE
Definition: trace.h:77
static int trace_cmp(void *a1, void *a2)
Definition: trace.c:179
f64 seconds_per_clock
Definition: time.h:57
format_function_t * format_buffer
Definition: node.h:356
#define foreach_vlib_main(body)
Definition: threads.h:235
u8 name[64]
Definition: memclnt.api:152
u8 * name
Definition: node.h:263
u32 filter_count
Definition: trace.h:80
#define pool_free(p)
Free a pool.
Definition: pool.h:407
#define UNFORMAT_END_OF_INPUT
Definition: format.h:144
static clib_error_t * cli_filter_trace(vlib_main_t *vm, unformat_input_t *input, vlib_cli_command_t *cmd)
Definition: trace.c:451
vlib_main_t * vm
Definition: buffer.c:312
static clib_error_t * cli_add_trace_buffer(vlib_main_t *vm, unformat_input_t *input, vlib_cli_command_t *cmd)
Definition: trace.c:355
#define vec_free(V)
Free vector&#39;s memory (no header).
Definition: vec.h:341
#define pool_is_free_index(P, I)
Use free bitmap to query whether given index is free.
Definition: pool.h:283
#define VLIB_CLI_COMMAND(x,...)
Definition: cli.h:155
#define pool_put_index(p, i)
Free pool element with given index.
Definition: pool.h:311
static void clear_trace_buffer(void)
Definition: trace.c:114
vlib_trace_main_t trace_main
Definition: main.h:141
u8 * vnet_trace_dummy
Definition: trace.c:43
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:57
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:47
#define vec_len(v)
Number of elements in vector (rvalue-only, NULL tolerant)
VLIB buffer representation.
Definition: buffer.h:102
u64 uword
Definition: types.h:112
#define vec_sort_with_function(vec, f)
Sort a vector using the supplied element comparison function.
Definition: vec.h:980
static void unformat_free(unformat_input_t *i)
Definition: format.h:162
u8 * format_time_interval(u8 *s, va_list *args)
Definition: std-formats.c:122
unformat_function_t unformat_vlib_node
Definition: node_funcs.h:1177
u8 * format_unformat_error(u8 *s, va_list *va)
Definition: unformat.c:91
static vlib_node_t * vlib_get_node(vlib_main_t *vm, u32 i)
Get vlib node by index.
Definition: node_funcs.h:59
#define CLIB_CACHE_LINE_BYTES
Definition: cache.h:59
void vlib_cli_output(vlib_main_t *vm, char *fmt,...)
Definition: cli.c:762
static vlib_buffer_t * vlib_get_buffer(vlib_main_t *vm, u32 buffer_index)
Translate buffer index into buffer pointer.
Definition: buffer_funcs.h:85
void trace_apply_filter(vlib_main_t *vm)
Definition: trace.c:226
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:170
#define FILTER_FLAG_INCLUDE
Definition: trace.h:78