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 #include <vnet/classify/vnet_classify.h>
  43
  44 u8 *vnet_trace_placeholder;
  45
  46 /* Helper function for nodes which only trace buffer data. */
  47 void
  48 vlib_trace_frame_buffers_only (vlib_main_t * vm,
  49                                vlib_node_runtime_t * node,
  50                                u32 * buffers,
  51                                uword n_buffers,
  52                                uword next_buffer_stride,
  53                                uword n_buffer_data_bytes_in_trace)
  54 {
  55   u32 n_left, *from;
  56
  57   n_left = n_buffers;
  58   from = buffers;
  59
  60   while (n_left >= 4)
  61     {
  62       u32 bi0, bi1;
  63       vlib_buffer_t *b0, *b1;
  64       u8 *t0, *t1;
  65
  66       /* Prefetch next iteration. */
  67       vlib_prefetch_buffer_with_index (vm, from[2], LOAD);
  68       vlib_prefetch_buffer_with_index (vm, from[3], LOAD);
  69
  70       bi0 = from[0];
  71       bi1 = from[1];
  72
  73       b0 = vlib_get_buffer (vm, bi0);
  74       b1 = vlib_get_buffer (vm, bi1);
  75
  76       if (b0->flags & VLIB_BUFFER_IS_TRACED)
  77         {
  78           t0 = vlib_add_trace (vm, node, b0, n_buffer_data_bytes_in_trace);
  79           clib_memcpy_fast (t0, b0->data + b0->current_data,
  80                             n_buffer_data_bytes_in_trace);
  81         }
  82       if (b1->flags & VLIB_BUFFER_IS_TRACED)
  83         {
  84           t1 = vlib_add_trace (vm, node, b1, n_buffer_data_bytes_in_trace);
  85           clib_memcpy_fast (t1, b1->data + b1->current_data,
  86                             n_buffer_data_bytes_in_trace);
  87         }
  88       from += 2;
  89       n_left -= 2;
  90     }
  91
  92   while (n_left >= 1)
  93     {
  94       u32 bi0;
  95       vlib_buffer_t *b0;
  96       u8 *t0;
  97
  98       bi0 = from[0];
  99
 100       b0 = vlib_get_buffer (vm, bi0);
 101
 102       if (b0->flags & VLIB_BUFFER_IS_TRACED)
 103         {
 104           t0 = vlib_add_trace (vm, node, b0, n_buffer_data_bytes_in_trace);
 105           clib_memcpy_fast (t0, b0->data + b0->current_data,
 106                             n_buffer_data_bytes_in_trace);
 107         }
 108       from += 1;
 109       n_left -= 1;
 110     }
 111 }
 112
 113 /* Free up all trace buffer memory. */
 114 void
 115 clear_trace_buffer (void)
 116 {
 117   int i;
 118   vlib_trace_main_t *tm;
 119
 120   /* *INDENT-OFF* */
 121   foreach_vlib_main (
 122   ({
 123     tm = &this_vlib_main->trace_main;
 124
 125     tm->trace_enable = 0;
 126     vec_free (tm->nodes);
 127   }));
 128
 129   foreach_vlib_main (
 130   ({
 131     tm = &this_vlib_main->trace_main;
 132
 133     for (i = 0; i < vec_len (tm->trace_buffer_pool); i++)
 134       if (! pool_is_free_index (tm->trace_buffer_pool, i))
 135         vec_free (tm->trace_buffer_pool[i]);
 136     pool_free (tm->trace_buffer_pool);
 137   }));
 138   /* *INDENT-ON* */
 139 }
 140
 141 u8 *
 142 format_vlib_trace (u8 * s, va_list * va)
 143 {
 144   vlib_main_t *vm = va_arg (*va, vlib_main_t *);
 145   vlib_trace_header_t *h = va_arg (*va, vlib_trace_header_t *);
 146   vlib_trace_header_t *e = vec_end (h);
 147   vlib_node_t *node, *prev_node;
 148   clib_time_t *ct = &vm->clib_time;
 149   f64 t;
 150
 151   prev_node = 0;
 152   while (h < e)
 153     {
 154       node = vlib_get_node (vm, h->node_index);
 155
 156       if (node != prev_node)
 157         {
 158           t =
 159             (h->time - vm->cpu_time_main_loop_start) * ct->seconds_per_clock;
 160           s =
 161             format (s, "\n%U: %v", format_time_interval, "h:m:s:u", t,
 162                     node->name);
 163         }
 164       prev_node = node;
 165
 166       if (node->format_trace)
 167         s = format (s, "\n  %U", node->format_trace, vm, node, h->data);
 168       else
 169         s = format (s, "\n  %U", node->format_buffer, h->data);
 170
 171       h = vlib_trace_header_next (h);
 172     }
 173
 174   return s;
 175 }
 176
 177 /* Root of all trace cli commands. */
 178 /* *INDENT-OFF* */
 179 VLIB_CLI_COMMAND (trace_cli_command,static) = {
 180   .path = "trace",
 181   .short_help = "Packet tracer commands",
 182 };
 183 /* *INDENT-ON* */
 184
 185 int
 186 trace_time_cmp (void *a1, void *a2)
 187 {
 188   vlib_trace_header_t **t1 = a1;
 189   vlib_trace_header_t **t2 = a2;
 190   i64 dt = t1[0]->time - t2[0]->time;
 191   return dt < 0 ? -1 : (dt > 0 ? +1 : 0);
 192 }
 193
 194 /*
 195  * Return 1 if this packet passes the trace filter, or 0 otherwise
 196  */
 197 u32
 198 filter_accept (vlib_trace_main_t * tm, vlib_trace_header_t * h)
 199 {
 200   vlib_trace_header_t *e = vec_end (h);
 201
 202   if (tm->filter_flag == 0)
 203     return 1;
 204
 205   /*
 206    * When capturing a post-mortem dispatch trace,
 207    * toss all existing traces once per dispatch cycle.
 208    * So we can trace 4 billion pkts without running out of
 209    * memory...
 210    */
 211   if (tm->filter_flag == FILTER_FLAG_POST_MORTEM)
 212     return 0;
 213
 214   if (tm->filter_flag == FILTER_FLAG_INCLUDE)
 215     {
 216       while (h < e)
 217         {
 218           if (h->node_index == tm->filter_node_index)
 219             return 1;
 220           h = vlib_trace_header_next (h);
 221         }
 222       return 0;
 223     }
 224   else                          /* FILTER_FLAG_EXCLUDE */
 225     {
 226       while (h < e)
 227         {
 228           if (h->node_index == tm->filter_node_index)
 229             return 0;
 230           h = vlib_trace_header_next (h);
 231         }
 232       return 1;
 233     }
 234
 235   return 0;
 236 }
 237
 238 /*
 239  * Remove traces from the trace buffer pool that don't pass the filter
 240  */
 241 void
 242 trace_apply_filter (vlib_main_t * vm)
 243 {
 244   vlib_trace_main_t *tm = &vm->trace_main;
 245   vlib_trace_header_t **h;
 246   vlib_trace_header_t ***traces_to_remove = 0;
 247   u32 index;
 248   u32 trace_index;
 249   u32 n_accepted;
 250
 251   u32 accept;
 252
 253   if (tm->filter_flag == FILTER_FLAG_NONE)
 254     return;
 255
 256   /*
 257    * Ideally we would retain the first N traces that pass the filter instead
 258    * of any N traces.
 259    */
 260   n_accepted = 0;
 261   /* *INDENT-OFF* */
 262   pool_foreach (h, tm->trace_buffer_pool)
 263     {
 264       accept = filter_accept(tm, h[0]);
 265
 266       if ((n_accepted == tm->filter_count) || !accept)
 267           vec_add1 (traces_to_remove, h);
 268       else
 269           n_accepted++;
 270   }
 271   /* *INDENT-ON* */
 272
 273   /* remove all traces that we don't want to keep */
 274   for (index = 0; index < vec_len (traces_to_remove); index++)
 275     {
 276       trace_index = traces_to_remove[index] - tm->trace_buffer_pool;
 277       _vec_len (tm->trace_buffer_pool[trace_index]) = 0;
 278       pool_put_index (tm->trace_buffer_pool, trace_index);
 279     }
 280
 281   vec_free (traces_to_remove);
 282 }
 283
 284 static clib_error_t *
 285 cli_show_trace_buffer (vlib_main_t * vm,
 286                        unformat_input_t * input, vlib_cli_command_t * cmd)
 287 {
 288   vlib_trace_main_t *tm;
 289   vlib_trace_header_t **h, **traces;
 290   u32 i, index = 0;
 291   char *fmt;
 292   u8 *s = 0;
 293   u32 max;
 294
 295   /*
 296    * By default display only this many traces. To display more, explicitly
 297    * specify a max. This prevents unexpectedly huge outputs.
 298    */
 299   max = 50;
 300   while (unformat_check_input (input) != (uword) UNFORMAT_END_OF_INPUT)
 301     {
 302       if (unformat (input, "max %d", &max))
 303         ;
 304       else
 305         return clib_error_create ("expected 'max COUNT', got `%U'",
 306                                   format_unformat_error, input);
 307     }
 308
 309
 310   /* Get active traces from pool. */
 311
 312   /* *INDENT-OFF* */
 313   foreach_vlib_main (
 314   ({
 315     fmt = "------------------- Start of thread %d %s -------------------\n";
 316     s = format (s, fmt, index, vlib_worker_threads[index].name);
 317
 318     tm = &this_vlib_main->trace_main;
 319
 320     trace_apply_filter(this_vlib_main);
 321
 322     traces = 0;
 323     pool_foreach (h, tm->trace_buffer_pool)
 324      {
 325       vec_add1 (traces, h[0]);
 326     }
 327
 328     if (vec_len (traces) == 0)
 329       {
 330         s = format (s, "No packets in trace buffer\n");
 331         goto done;
 332       }
 333
 334     /* Sort them by increasing time. */
 335     vec_sort_with_function (traces, trace_time_cmp);
 336
 337     for (i = 0; i < vec_len (traces); i++)
 338       {
 339         if (i == max)
 340           {
 341             char *warn = "Limiting display to %d packets."
 342                                " To display more specify max.";
 343             vlib_cli_output (vm, warn, max);
 344             s = format (s, warn, max);
 345             goto done;
 346           }
 347
 348         s = format (s, "Packet %d\n%U\n\n", i + 1,
 349                          format_vlib_trace, vm, traces[i]);
 350       }
 351
 352   done:
 353     vec_free (traces);
 354
 355     index++;
 356   }));
 357   /* *INDENT-ON* */
 358
 359   vlib_cli_output (vm, "%v", s);
 360   vec_free (s);
 361   return 0;
 362 }
 363
 364 /* *INDENT-OFF* */
 365 VLIB_CLI_COMMAND (show_trace_cli,static) = {
 366   .path = "show trace",
 367   .short_help = "Show trace buffer [max COUNT]",
 368   .function = cli_show_trace_buffer,
 369 };
 370 /* *INDENT-ON* */
 371
 372 int vlib_enable_disable_pkt_trace_filter (int enable) __attribute__ ((weak));
 373
 374 int
 375 vlib_enable_disable_pkt_trace_filter (int enable)
 376 {
 377   return 0;
 378 }
 379
 380 void
 381 vlib_trace_stop_and_clear (void)
 382 {
 383   vlib_enable_disable_pkt_trace_filter (0);     /* disble tracing */
 384   clear_trace_buffer ();
 385 }
 386
 387
 388 void
 389 trace_update_capture_options (u32 add, u32 node_index, u32 filter, u8 verbose)
 390 {
 391   vlib_trace_main_t *tm;
 392   vlib_trace_node_t *tn;
 393
 394   if (add == ~0)
 395     add = 50;
 396
 397   /* *INDENT-OFF* */
 398   foreach_vlib_main ((
 399     {
 400       tm = &this_vlib_main->trace_main;
 401       tm->verbose = verbose;
 402       vec_validate (tm->nodes, node_index);
 403       tn = tm->nodes + node_index;
 404
 405       /*
 406        * Adding 0 makes no real sense, and there wa no other way
 407        * to explicilty zero-out the limits and count, so make
 408        * an "add 0" request really be "set to 0".
 409        */
 410       if (add == 0)
 411           tn->limit = tn->count = 0;
 412       else
 413           tn->limit += add;
 414     }));
 415
 416   foreach_vlib_main ((
 417     {
 418       tm = &this_vlib_main->trace_main;
 419       tm->trace_enable = 1;
 420     }));
 421   /* *INDENT-ON* */
 422
 423   vlib_enable_disable_pkt_trace_filter (! !filter);
 424 }
 425
 426 static clib_error_t *
 427 cli_add_trace_buffer (vlib_main_t * vm,
 428                       unformat_input_t * input, vlib_cli_command_t * cmd)
 429 {
 430   unformat_input_t _line_input, *line_input = &_line_input;
 431   vlib_node_t *node;
 432   u32 node_index, add;
 433   u8 verbose = 0;
 434   int filter = 0;
 435   clib_error_t *error = 0;
 436
 437   if (!unformat_user (input, unformat_line_input, line_input))
 438     return 0;
 439
 440   if (vnet_trace_placeholder == 0)
 441     vec_validate_aligned (vnet_trace_placeholder, 2048,
 442                           CLIB_CACHE_LINE_BYTES);
 443
 444   while (unformat_check_input (line_input) != (uword) UNFORMAT_END_OF_INPUT)
 445     {
 446       if (unformat (line_input, "%U %d",
 447                     unformat_vlib_node, vm, &node_index, &add))
 448         ;
 449       else if (unformat (line_input, "verbose"))
 450         verbose = 1;
 451       else if (unformat (line_input, "filter"))
 452         filter = 1;
 453       else
 454         {
 455           error = clib_error_create ("expected NODE COUNT, got `%U'",
 456                                      format_unformat_error, line_input);
 457           goto done;
 458         }
 459     }
 460
 461   node = vlib_get_node (vm, node_index);
 462
 463   if ((node->flags & VLIB_NODE_FLAG_TRACE_SUPPORTED) == 0)
 464     {
 465       error = clib_error_create ("node '%U' doesn't support per-node "
 466                                  "tracing. There may be another way to "
 467                                  "initiate trace on this node.",
 468                                  format_vlib_node_name, vm, node_index);
 469       goto done;
 470     }
 471
 472   u32 filter_table = classify_get_trace_chain ();
 473   if (filter && filter_table == ~0)
 474     {
 475       error = clib_error_create ("No packet trace filter configured...");
 476       goto done;
 477     }
 478
 479   trace_update_capture_options (add, node_index, filter, verbose);
 480
 481 done:
 482   unformat_free (line_input);
 483
 484   return error;
 485 }
 486
 487 /* *INDENT-OFF* */
 488 VLIB_CLI_COMMAND (add_trace_cli,static) = {
 489   .path = "trace add",
 490   .short_help = "trace add <input-graph-node> <add'l-pkts-for-node-> [filter] [verbose]",
 491   .function = cli_add_trace_buffer,
 492 };
 493 /* *INDENT-ON* */
 494
 495 /*
 496  * Configure a filter for packet traces.
 497  *
 498  * This supplements the packet trace feature so that only packets matching
 499  * the filter are included in the trace. Currently the only filter is to
 500  * keep packets that include a certain node in the trace or exclude a certain
 501  * node in the trace.
 502  *
 503  * The count of traced packets in the "trace add" command is still used to
 504  * create a certain number of traces. The "trace filter" command specifies
 505  * how many of those packets should be retained in the trace.
 506  *
 507  * For example, 1Mpps of traffic is arriving and one of those packets is being
 508  * dropped. To capture the trace for only that dropped packet, you can do:
 509  *     trace filter include error-drop 1
 510  *     trace add dpdk-input 1000000
 511  *     <wait one second>
 512  *     show trace
 513  *
 514  * Note that the filter could be implemented by capturing all traces and just
 515  * reducing traces displayed by the "show trace" function. But that would
 516  * require a lot of memory for storing the traces, making that infeasible.
 517  *
 518  * To remove traces from the trace pool that do not include a certain node
 519  * requires that the trace be "complete" before applying the filter. To
 520  * accomplish this, the trace pool is filtered upon each iteraction of the
 521  * main vlib loop. Doing so keeps the number of allocated traces down to a
 522  * reasonably low number. This requires that tracing for a buffer is not
 523  * performed after the vlib main loop interation completes. i.e. you can't
 524  * save away a buffer temporarily then inject it back into the graph and
 525  * expect that the trace_index is still valid (such as a traffic manager might
 526  * do). A new trace buffer should be allocated for those types of packets.
 527  *
 528  * The filter can be extended to support multiple nodes and other match
 529  * criteria (e.g. input sw_if_index, mac address) but for now just checks if
 530  * a specified node is in the trace or not in the trace.
 531  */
 532
 533 void
 534 trace_filter_set (u32 node_index, u32 flag, u32 count)
 535 {
 536   /* *INDENT-OFF* */
 537   foreach_vlib_main (
 538   ({
 539     vlib_trace_main_t *tm;
 540
 541     tm = &this_vlib_main->trace_main;
 542     tm->filter_node_index = node_index;
 543     tm->filter_flag = flag;
 544     tm->filter_count = count;
 545
 546     /*
 547      * Clear the trace limits to stop any in-progress tracing
 548      * Prevents runaway trace allocations when the filter changes
 549      * (or is removed)
 550      */
 551     vec_free (tm->nodes);
 552   }));
 553   /* *INDENT-ON* */
 554 }
 555
 556
 557 static clib_error_t *
 558 cli_filter_trace (vlib_main_t * vm,
 559                   unformat_input_t * input, vlib_cli_command_t * cmd)
 560 {
 561   u32 filter_node_index;
 562   u32 filter_flag;
 563   u32 filter_count;
 564
 565   if (unformat (input, "include %U %d",
 566                 unformat_vlib_node, vm, &filter_node_index, &filter_count))
 567     {
 568       filter_flag = FILTER_FLAG_INCLUDE;
 569     }
 570   else if (unformat (input, "exclude %U %d",
 571                      unformat_vlib_node, vm, &filter_node_index,
 572                      &filter_count))
 573     {
 574       filter_flag = FILTER_FLAG_EXCLUDE;
 575     }
 576   else if (unformat (input, "none"))
 577     {
 578       filter_flag = FILTER_FLAG_NONE;
 579       filter_node_index = 0;
 580       filter_count = 0;
 581     }
 582   else
 583     return
 584       clib_error_create
 585       ("expected 'include NODE COUNT' or 'exclude NODE COUNT' or 'none', got `%U'",
 586        format_unformat_error, input);
 587
 588   trace_filter_set (filter_node_index, filter_flag, filter_count);
 589
 590   return 0;
 591 }
 592
 593 /* *INDENT-OFF* */
 594 VLIB_CLI_COMMAND (filter_trace_cli,static) = {
 595   .path = "trace filter",
 596   .short_help = "trace filter none | [include|exclude] NODE COUNT",
 597   .function = cli_filter_trace,
 598 };
 599 /* *INDENT-ON* */
 600
 601 static clib_error_t *
 602 cli_clear_trace_buffer (vlib_main_t * vm,
 603                         unformat_input_t * input, vlib_cli_command_t * cmd)
 604 {
 605   vlib_trace_stop_and_clear ();
 606   return 0;
 607 }
 608
 609 /* *INDENT-OFF* */
 610 VLIB_CLI_COMMAND (clear_trace_cli,static) = {
 611   .path = "clear trace",
 612   .short_help = "Clear trace buffer and free memory",
 613   .function = cli_clear_trace_buffer,
 614 };
 615 /* *INDENT-ON* */
 616
 617 /* Placeholder function to get us linked in. */
 618 void
 619 vlib_trace_cli_reference (void)
 620 {
 621 }
 622
 623 int
 624 vnet_is_packet_traced (vlib_buffer_t * b,
 625                        u32 classify_table_index, int func)
 626 __attribute__ ((weak));
 627
 628 int
 629 vnet_is_packet_traced (vlib_buffer_t * b, u32 classify_table_index, int func)
 630 {
 631   clib_warning ("BUG: STUB called");
 632   return 1;
 633 }
 634
 635 void *
 636 vlib_add_trace (vlib_main_t * vm,
 637                 vlib_node_runtime_t * r, vlib_buffer_t * b, u32 n_data_bytes)
 638 {
 639   return vlib_add_trace_inline (vm, r, b, n_data_bytes);
 640 }
 641
 642
 643
 644 /*
 645  * fd.io coding-style-patch-verification: ON
 646  *
 647  * Local Variables:
 648  * eval: (c-set-style "gnu")
 649  * End:
 650  */