src/vlib/trace.c

   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
  45 vlib_trace_frame_buffers_only (vlib_main_t * vm,
  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
 112 clear_trace_buffer (void)
 113 {
 114   int i;
 115   vlib_trace_main_t *tm;
 116
 117   /* *INDENT-OFF* */
 118   foreach_vlib_main (
 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]);
 130     pool_free (tm->trace_buffer_pool);
 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 =
 154             (h->time - vm->cpu_time_main_loop_start) * ct->seconds_per_clock;
 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
 193 filter_accept (vlib_trace_main_t * tm, vlib_trace_header_t * h)
 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
 228 trace_apply_filter (vlib_main_t * vm)
 229 {
 230   vlib_trace_main_t *tm = &vm->trace_main;
 231   vlib_trace_header_t **h;
 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* */
 248   pool_foreach (h, tm->trace_buffer_pool,
 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 *
 271 cli_show_trace_buffer (vlib_main_t * vm,
 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;
 286   while (unformat_check_input (input) != (uword) UNFORMAT_END_OF_INPUT)
 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* */
 299   foreach_vlib_main (
 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;
 313     pool_foreach (h, tm->trace_buffer_pool,
 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. */
 326     vec_sort_with_function (traces, trace_cmp);
 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 *
 367 cli_add_trace_buffer (vlib_main_t * vm,
 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
 376   if (!unformat_user (input, unformat_line_input, line_input))
 377     return 0;
 378
 379   while (unformat_check_input (line_input) != (uword) UNFORMAT_END_OF_INPUT)
 380     {
 381       if (unformat (line_input, "%U %d",
 382                     unformat_vlib_node, vm, &node_index, &add))
 383         ;
 384       else if (unformat (line_input, "verbose"))
 385         verbose = 1;
 386       else
 387         return clib_error_create ("expected NODE COUNT, got `%U'",
 388                                   format_unformat_error, line_input);
 389     }
 390
 391   /* *INDENT-OFF* */
 392   foreach_vlib_main ((
 393     {
 394       void *oldheap;
 395       tm = &this_vlib_main->trace_main;
 396       tm->trace_active_hint = 1;
 397       tm->verbose = verbose;
 398       oldheap =
 399         clib_mem_set_heap (this_vlib_main->heap_base);
 400       vec_validate (tm->nodes, node_index);
 401       tn = tm->nodes + node_index;
 402       tn->limit += add; clib_mem_set_heap (oldheap);
 403     }));
 404   /* *INDENT-ON* */
 405
 406   return 0;
 407 }
 408
 409 /* *INDENT-OFF* */
 410 VLIB_CLI_COMMAND (add_trace_cli,static) = {
 411   .path = "trace add",
 412   .short_help = "Trace given number of packets",
 413   .function = cli_add_trace_buffer,
 414 };
 415 /* *INDENT-ON* */
 416
 417
 418 /*
 419  * Configure a filter for packet traces.
 420  *
 421  * This supplements the packet trace feature so that only packets matching
 422  * the filter are included in the trace. Currently the only filter is to
 423  * keep packets that include a certain node in the trace or exclude a certain
 424  * node in the trace.
 425  *
 426  * The count of traced packets in the "trace add" command is still used to
 427  * create a certain number of traces. The "trace filter" command specifies
 428  * how many of those packets should be retained in the trace.
 429  *
 430  * For example, 1Mpps of traffic is arriving and one of those packets is being
 431  * dropped. To capture the trace for only that dropped packet, you can do:
 432  *     trace filter include error-drop 1
 433  *     trace add dpdk-input 1000000
 434  *     <wait one second>
 435  *     show trace
 436  *
 437  * Note that the filter could be implemented by capturing all traces and just
 438  * reducing traces displayed by the "show trace" function. But that would
 439  * require a lot of memory for storing the traces, making that infeasible.
 440  *
 441  * To remove traces from the trace pool that do not include a certain node
 442  * requires that the trace be "complete" before applying the filter. To
 443  * accomplish this, the trace pool is filtered upon each iteraction of the
 444  * main vlib loop. Doing so keeps the number of allocated traces down to a
 445  * reasonably low number. This requires that tracing for a buffer is not
 446  * performed after the vlib main loop interation completes. i.e. you can't
 447  * save away a buffer temporarily then inject it back into the graph and
 448  * expect that the trace_index is still valid (such as a traffic manager might
 449  * do). A new trace buffer should be allocated for those types of packets.
 450  *
 451  * The filter can be extended to support multiple nodes and other match
 452  * criteria (e.g. input sw_if_index, mac address) but for now just checks if
 453  * a specified node is in the trace or not in the trace.
 454  */
 455 static clib_error_t *
 456 cli_filter_trace (vlib_main_t * vm,
 457                   unformat_input_t * input, vlib_cli_command_t * cmd)
 458 {
 459   vlib_trace_main_t *tm = &vm->trace_main;
 460   u32 filter_node_index;
 461   u32 filter_flag;
 462   u32 filter_count;
 463   void *mainheap;
 464
 465   if (unformat (input, "include %U %d",
 466                 unformat_vlib_node, vm, &filter_node_index, &filter_count))
 467     {
 468       filter_flag = FILTER_FLAG_INCLUDE;
 469     }
 470   else if (unformat (input, "exclude %U %d",
 471                      unformat_vlib_node, vm, &filter_node_index,
 472                      &filter_count))
 473     {
 474       filter_flag = FILTER_FLAG_EXCLUDE;
 475     }
 476   else if (unformat (input, "none"))
 477     {
 478       filter_flag = FILTER_FLAG_NONE;
 479       filter_node_index = 0;
 480       filter_count = 0;
 481     }
 482   else
 483     return
 484       clib_error_create
 485       ("expected 'include NODE COUNT' or 'exclude NODE COUNT' or 'none', got `%U'",
 486        format_unformat_error, input);
 487
 488   /* *INDENT-OFF* */
 489   foreach_vlib_main (
 490     ({
 491     tm = &this_vlib_main->trace_main;
 492     tm->filter_node_index = filter_node_index;
 493     tm->filter_flag = filter_flag;
 494     tm->filter_count = filter_count;
 495
 496     /*
 497      * Clear the trace limits to stop any in-progress tracing
 498      * Prevents runaway trace allocations when the filter changes (or is removed)
 499      */
 500     mainheap = clib_mem_set_heap (this_vlib_main->heap_base);
 501     vec_free (tm->nodes);
 502     clib_mem_set_heap (mainheap);
 503   }));
 504   /* *INDENT-ON* */
 505
 506   return 0;
 507 }
 508
 509 /* *INDENT-OFF* */
 510 VLIB_CLI_COMMAND (filter_trace_cli,static) = {
 511   .path = "trace filter",
 512   .short_help = "filter trace output - include NODE COUNT | exclude NODE COUNT | none",
 513   .function = cli_filter_trace,
 514 };
 515 /* *INDENT-ON* */
 516
 517 static clib_error_t *
 518 cli_clear_trace_buffer (vlib_main_t * vm,
 519                         unformat_input_t * input, vlib_cli_command_t * cmd)
 520 {
 521   clear_trace_buffer ();
 522   return 0;
 523 }
 524
 525 /* *INDENT-OFF* */
 526 VLIB_CLI_COMMAND (clear_trace_cli,static) = {
 527   .path = "clear trace",
 528   .short_help = "Clear trace buffer and free memory",
 529   .function = cli_clear_trace_buffer,
 530 };
 531 /* *INDENT-ON* */
 532
 533 /* Dummy function to get us linked in. */
 534 void
 535 vlib_trace_cli_reference (void)
 536 {
 537 }
 538
 539 /*
 540  * fd.io coding-style-patch-verification: ON
 541  *
 542  * Local Variables:
 543  * eval: (c-set-style "gnu")
 544  * End:
 545  */