FD.io VPP  v19.08.3-2-gbabecb413
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 int vlib_enable_disable_pkt_trace_filter (int enable) __attribute__ ((weak));
355 int
357 {
358  return 0;
359 }
360 
361 static clib_error_t *
363  unformat_input_t * input, vlib_cli_command_t * cmd)
364 {
365  unformat_input_t _line_input, *line_input = &_line_input;
366  vlib_trace_main_t *tm;
367  vlib_node_t *node;
368  vlib_trace_node_t *tn;
369  u32 node_index, add;
370  u8 verbose = 0;
371  int filter = 0;
372  clib_error_t *error = 0;
373 
374  if (!unformat_user (input, unformat_line_input, line_input))
375  return 0;
376 
377  if (vnet_trace_dummy == 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 if (unformat (line_input, "filter"))
388  filter = 1;
389  else
390  {
391  error = clib_error_create ("expected NODE COUNT, got `%U'",
392  format_unformat_error, line_input);
393  goto done;
394  }
395  }
396 
397  node = vlib_get_node (vm, node_index);
398 
399  if ((node->flags & VLIB_NODE_FLAG_TRACE_SUPPORTED) == 0)
400  {
401  error = clib_error_create ("node '%U' doesn't support per-node "
402  "tracing. There may be another way to "
403  "initiate trace on this node.",
404  format_vlib_node_name, vm, node_index);
405  goto done;
406  }
407 
408  if (filter)
409  {
410  if (vlib_enable_disable_pkt_trace_filter (1 /* enable */ ))
411  {
412  error = clib_error_create ("No packet trace filter configured...");
413  goto done;
414  }
415  }
416 
417  /* *INDENT-OFF* */
419  {
420  tm = &this_vlib_main->trace_main;
421  tm->verbose = verbose;
422  vec_validate (tm->nodes, node_index);
423  tn = tm->nodes + node_index;
424  tn->limit += add;
425  tm->trace_enable = 1;
426  }));
427  /* *INDENT-ON* */
428 
429 done:
430  unformat_free (line_input);
431 
432  return error;
433 }
434 
435 /* *INDENT-OFF* */
436 VLIB_CLI_COMMAND (add_trace_cli,static) = {
437  .path = "trace add",
438  .short_help = "Trace given number of packets",
439  .function = cli_add_trace_buffer,
440 };
441 /* *INDENT-ON* */
442 
443 /*
444  * Configure a filter for packet traces.
445  *
446  * This supplements the packet trace feature so that only packets matching
447  * the filter are included in the trace. Currently the only filter is to
448  * keep packets that include a certain node in the trace or exclude a certain
449  * node in the trace.
450  *
451  * The count of traced packets in the "trace add" command is still used to
452  * create a certain number of traces. The "trace filter" command specifies
453  * how many of those packets should be retained in the trace.
454  *
455  * For example, 1Mpps of traffic is arriving and one of those packets is being
456  * dropped. To capture the trace for only that dropped packet, you can do:
457  * trace filter include error-drop 1
458  * trace add dpdk-input 1000000
459  * <wait one second>
460  * show trace
461  *
462  * Note that the filter could be implemented by capturing all traces and just
463  * reducing traces displayed by the "show trace" function. But that would
464  * require a lot of memory for storing the traces, making that infeasible.
465  *
466  * To remove traces from the trace pool that do not include a certain node
467  * requires that the trace be "complete" before applying the filter. To
468  * accomplish this, the trace pool is filtered upon each iteraction of the
469  * main vlib loop. Doing so keeps the number of allocated traces down to a
470  * reasonably low number. This requires that tracing for a buffer is not
471  * performed after the vlib main loop interation completes. i.e. you can't
472  * save away a buffer temporarily then inject it back into the graph and
473  * expect that the trace_index is still valid (such as a traffic manager might
474  * do). A new trace buffer should be allocated for those types of packets.
475  *
476  * The filter can be extended to support multiple nodes and other match
477  * criteria (e.g. input sw_if_index, mac address) but for now just checks if
478  * a specified node is in the trace or not in the trace.
479  */
480 static clib_error_t *
482  unformat_input_t * input, vlib_cli_command_t * cmd)
483 {
484  vlib_trace_main_t *tm = &vm->trace_main;
485  u32 filter_node_index;
486  u32 filter_flag;
487  u32 filter_count;
488 
489  if (unformat (input, "include %U %d",
490  unformat_vlib_node, vm, &filter_node_index, &filter_count))
491  {
492  filter_flag = FILTER_FLAG_INCLUDE;
493  }
494  else if (unformat (input, "exclude %U %d",
495  unformat_vlib_node, vm, &filter_node_index,
496  &filter_count))
497  {
498  filter_flag = FILTER_FLAG_EXCLUDE;
499  }
500  else if (unformat (input, "none"))
501  {
502  filter_flag = FILTER_FLAG_NONE;
503  filter_node_index = 0;
504  filter_count = 0;
505  }
506  else
507  return
509  ("expected 'include NODE COUNT' or 'exclude NODE COUNT' or 'none', got `%U'",
510  format_unformat_error, input);
511 
512  /* *INDENT-OFF* */
514  ({
515  tm = &this_vlib_main->trace_main;
516  tm->filter_node_index = filter_node_index;
517  tm->filter_flag = filter_flag;
518  tm->filter_count = filter_count;
519 
520  /*
521  * Clear the trace limits to stop any in-progress tracing
522  * Prevents runaway trace allocations when the filter changes
523  * (or is removed)
524  */
525  vec_free (tm->nodes);
526  }));
527  /* *INDENT-ON* */
528 
529  return 0;
530 }
531 
532 /* *INDENT-OFF* */
533 VLIB_CLI_COMMAND (filter_trace_cli,static) = {
534  .path = "trace filter",
535  .short_help = "filter trace output - include NODE COUNT | exclude NODE COUNT | none",
536  .function = cli_filter_trace,
537 };
538 /* *INDENT-ON* */
539 
540 static clib_error_t *
542  unformat_input_t * input, vlib_cli_command_t * cmd)
543 {
544  vlib_enable_disable_pkt_trace_filter (0 /* enable */ );
546  return 0;
547 }
548 
549 /* *INDENT-OFF* */
550 VLIB_CLI_COMMAND (clear_trace_cli,static) = {
551  .path = "clear trace",
552  .short_help = "Clear trace buffer and free memory",
553  .function = cli_clear_trace_buffer,
554 };
555 /* *INDENT-ON* */
556 
557 /* Dummy function to get us linked in. */
558 void
560 {
561 }
562 
563 int
565  u32 classify_table_index, int func)
566 __attribute__ ((weak));
567 
568 int
570 {
571  clib_warning ("BUG: STUB called");
572  return 1;
573 }
574 
575 /*
576  * fd.io coding-style-patch-verification: ON
577  *
578  * Local Variables:
579  * eval: (c-set-style "gnu")
580  * End:
581  */
#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:90
void vlib_trace_cli_reference(void)
Definition: trace.c:559
format_function_t format_vlib_node_name
Definition: node_funcs.h:1141
vlib_trace_node_t * nodes
Definition: trace.h:100
static clib_error_t * cli_clear_trace_buffer(vlib_main_t *vm, unformat_input_t *input, vlib_cli_command_t *cmd)
Definition: trace.c:541
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:99
#define VLIB_NODE_FLAG_TRACE_SUPPORTED
Definition: node.h:306
format_function_t * format_trace
Definition: node.h:362
u16 flags
Definition: node.h:289
int i
uword unformat_user(unformat_input_t *input, unformat_function_t *func,...)
Definition: unformat.c:989
u8 * format(u8 *s, const char *fmt,...)
Definition: format.c:424
clib_time_t clib_time
Definition: main.h:87
#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:89
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:86
u32 trace_enable
Definition: trace.h:97
#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:99
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:96
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:283
vlib_worker_thread_t * vlib_worker_threads
Definition: threads.c:37
#define FILTER_FLAG_EXCLUDE
Definition: trace.h:93
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:91
static int trace_cmp(void *a1, void *a2)
Definition: trace.c:179
f64 seconds_per_clock
Definition: time.h:58
format_function_t * format_buffer
Definition: node.h:358
#define foreach_vlib_main(body)
Definition: threads.h:241
u8 name[64]
Definition: memclnt.api:152
u8 * name
Definition: node.h:264
u32 filter_count
Definition: trace.h:94
#define pool_free(p)
Free a pool.
Definition: pool.h:407
u32 classify_table_index
Definition: fib_types.api:68
#define UNFORMAT_END_OF_INPUT
Definition: format.h:145
static clib_error_t * cli_filter_trace(vlib_main_t *vm, unformat_input_t *input, vlib_cli_command_t *cmd)
Definition: trace.c:481
vlib_main_t * vm
Definition: buffer.c:323
static clib_error_t * cli_add_trace_buffer(vlib_main_t *vm, unformat_input_t *input, vlib_cli_command_t *cmd)
Definition: trace.c:362
#define vec_free(V)
Free vector&#39;s memory (no header).
Definition: vec.h:341
#define clib_warning(format, args...)
Definition: error.h:59
u8 data[]
Packet data.
Definition: buffer.h:181
#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:161
#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:164
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: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:47
#define vec_len(v)
Number of elements in vector (rvalue-only, NULL tolerant)
int vlib_enable_disable_pkt_trace_filter(int enable)
Definition: trace.c:356
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:983
static void unformat_free(unformat_input_t *i)
Definition: format.h:163
int vnet_is_packet_traced(vlib_buffer_t *b, u32 classify_table_index, int func)
Definition: trace.c:569
u8 * format_time_interval(u8 *s, va_list *args)
Definition: std-formats.c:138
unformat_function_t unformat_vlib_node
Definition: node_funcs.h:1147
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:772
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:978
static uword unformat_check_input(unformat_input_t *i)
Definition: format.h:171
#define FILTER_FLAG_INCLUDE
Definition: trace.h:92