tools/perf/builtin-annotate.c

   1 /*
   2  * builtin-annotate.c
   3  *
   4  * Builtin annotate command: Analyze the perf.data input file,
   5  * look up and read DSOs and symbol information and display
   6  * a histogram of results, along various sorting keys.
   7  */
   8 #include "builtin.h"
   9
  10 #include "util/util.h"
  11
  12 #include "util/color.h"
  13 #include <linux/list.h>
  14 #include "util/cache.h"
  15 #include <linux/rbtree.h>
  16 #include "util/symbol.h"
  17 #include "util/string.h"
  18
  19 #include "perf.h"
  20 #include "util/debug.h"
  21
  22 #include "util/parse-options.h"
  23 #include "util/parse-events.h"
  24 #include "util/thread.h"
  25 #include "util/sort.h"
  26 #include "util/hist.h"
  27
  28 static char             const *input_name = "perf.data";
  29
  30 static int              force;
  31 static int              input;
  32 static int              show_mask = SHOW_KERNEL | SHOW_USER | SHOW_HV;
  33
  34 static int              full_paths;
  35
  36 static int              print_line;
  37
  38 static unsigned long    page_size;
  39 static unsigned long    mmap_window = 32;
  40
  41 static struct rb_root   threads;
  42 static struct thread    *last_match;
  43
  44
  45 struct sym_ext {
  46         struct rb_node  node;
  47         double          percent;
  48         char            *path;
  49 };
  50
  51
  52 /*
  53  * collect histogram counts
  54  */
  55 static void hist_hit(struct hist_entry *he, u64 ip)
  56 {
  57         unsigned int sym_size, offset;
  58         struct symbol *sym = he->sym;
  59
  60         he->count++;
  61
  62         if (!sym || !sym->hist)
  63                 return;
  64
  65         sym_size = sym->end - sym->start;
  66         ip = he->map->map_ip(he->map, ip);
  67         offset = ip - sym->start;
  68
  69         if (offset >= sym_size)
  70                 return;
  71
  72         sym->hist_sum++;
  73         sym->hist[offset]++;
  74
  75         if (verbose >= 3)
  76                 printf("%p %s: count++ [ip: %p, %08Lx] => %Ld\n",
  77                         (void *)(unsigned long)he->sym->start,
  78                         he->sym->name,
  79                         (void *)(unsigned long)ip, ip - he->sym->start,
  80                         sym->hist[offset]);
  81 }
  82
  83 static int hist_entry__add(struct thread *thread, struct map *map,
  84                            struct symbol *sym, u64 ip, u64 count, char level)
  85 {
  86         bool hit;
  87         struct hist_entry *he = __hist_entry__add(thread, map, sym, NULL, ip,
  88                                                   count, level, &hit);
  89         if (he == NULL)
  90                 return -ENOMEM;
  91         if (hit)
  92                 hist_hit(he, ip);
  93         return 0;
  94 }
  95
  96 static int
  97 process_sample_event(event_t *event, unsigned long offset, unsigned long head)
  98 {
  99         char level;
 100         int show = 0;
 101         struct thread *thread;
 102         u64 ip = event->ip.ip;
 103         struct map *map = NULL;
 104         struct symbol *sym = NULL;
 105
 106         thread = threads__findnew(event->ip.pid, &threads, &last_match);
 107
 108         dump_printf("%p [%p]: PERF_EVENT (IP, %d): %d: %p\n",
 109                 (void *)(offset + head),
 110                 (void *)(long)(event->header.size),
 111                 event->header.misc,
 112                 event->ip.pid,
 113                 (void *)(long)ip);
 114
 115         dump_printf(" ... thread: %s:%d\n", thread->comm, thread->pid);
 116
 117         if (thread == NULL) {
 118                 fprintf(stderr, "problem processing %d event, skipping it.\n",
 119                         event->header.type);
 120                 return -1;
 121         }
 122
 123         if (event->header.misc & PERF_RECORD_MISC_KERNEL) {
 124                 show = SHOW_KERNEL;
 125                 level = 'k';
 126                 sym = kernel_maps__find_symbol(ip, &map);
 127                 dump_printf(" ...... dso: %s\n",
 128                             map ? map->dso->long_name : "<not found>");
 129         } else if (event->header.misc & PERF_RECORD_MISC_USER) {
 130                 show = SHOW_USER;
 131                 level = '.';
 132                 map = thread__find_map(thread, ip);
 133                 if (map != NULL) {
 134 got_map:
 135                         ip = map->map_ip(map, ip);
 136                         sym = map->dso->find_symbol(map->dso, ip);
 137                 } else {
 138                         /*
 139                          * If this is outside of all known maps,
 140                          * and is a negative address, try to look it
 141                          * up in the kernel dso, as it might be a
 142                          * vsyscall or vdso (which executes in user-mode).
 143                          *
 144                          * XXX This is nasty, we should have a symbol list in
 145                          * the "[vdso]" dso, but for now lets use the old
 146                          * trick of looking in the whole kernel symbol list.
 147                          */
 148                         if ((long long)ip < 0) {
 149                                 map = kernel_map;
 150                                 goto got_map;
 151                         }
 152                 }
 153                 dump_printf(" ...... dso: %s\n",
 154                             map ? map->dso->long_name : "<not found>");
 155         } else {
 156                 show = SHOW_HV;
 157                 level = 'H';
 158                 dump_printf(" ...... dso: [hypervisor]\n");
 159         }
 160
 161         if (show & show_mask) {
 162                 if (hist_entry__add(thread, map, sym, ip, 1, level)) {
 163                         fprintf(stderr,
 164                 "problem incrementing symbol count, skipping event\n");
 165                         return -1;
 166                 }
 167         }
 168         total++;
 169
 170         return 0;
 171 }
 172
 173 static int
 174 process_mmap_event(event_t *event, unsigned long offset, unsigned long head)
 175 {
 176         struct thread *thread;
 177         struct map *map = map__new(&event->mmap, NULL, 0);
 178
 179         thread = threads__findnew(event->mmap.pid, &threads, &last_match);
 180
 181         dump_printf("%p [%p]: PERF_RECORD_MMAP %d: [%p(%p) @ %p]: %s\n",
 182                 (void *)(offset + head),
 183                 (void *)(long)(event->header.size),
 184                 event->mmap.pid,
 185                 (void *)(long)event->mmap.start,
 186                 (void *)(long)event->mmap.len,
 187                 (void *)(long)event->mmap.pgoff,
 188                 event->mmap.filename);
 189
 190         if (thread == NULL || map == NULL) {
 191                 dump_printf("problem processing PERF_RECORD_MMAP, skipping event.\n");
 192                 return 0;
 193         }
 194
 195         thread__insert_map(thread, map);
 196         total_mmap++;
 197
 198         return 0;
 199 }
 200
 201 static int
 202 process_comm_event(event_t *event, unsigned long offset, unsigned long head)
 203 {
 204         struct thread *thread;
 205
 206         thread = threads__findnew(event->comm.pid, &threads, &last_match);
 207         dump_printf("%p [%p]: PERF_RECORD_COMM: %s:%d\n",
 208                 (void *)(offset + head),
 209                 (void *)(long)(event->header.size),
 210                 event->comm.comm, event->comm.pid);
 211
 212         if (thread == NULL ||
 213             thread__set_comm(thread, event->comm.comm)) {
 214                 dump_printf("problem processing PERF_RECORD_COMM, skipping event.\n");
 215                 return -1;
 216         }
 217         total_comm++;
 218
 219         return 0;
 220 }
 221
 222 static int
 223 process_fork_event(event_t *event, unsigned long offset, unsigned long head)
 224 {
 225         struct thread *thread;
 226         struct thread *parent;
 227
 228         thread = threads__findnew(event->fork.pid, &threads, &last_match);
 229         parent = threads__findnew(event->fork.ppid, &threads, &last_match);
 230         dump_printf("%p [%p]: PERF_RECORD_FORK: %d:%d\n",
 231                 (void *)(offset + head),
 232                 (void *)(long)(event->header.size),
 233                 event->fork.pid, event->fork.ppid);
 234
 235         /*
 236          * A thread clone will have the same PID for both
 237          * parent and child.
 238          */
 239         if (thread == parent)
 240                 return 0;
 241
 242         if (!thread || !parent || thread__fork(thread, parent)) {
 243                 dump_printf("problem processing PERF_RECORD_FORK, skipping event.\n");
 244                 return -1;
 245         }
 246         total_fork++;
 247
 248         return 0;
 249 }
 250
 251 static int
 252 process_event(event_t *event, unsigned long offset, unsigned long head)
 253 {
 254         switch (event->header.type) {
 255         case PERF_RECORD_SAMPLE:
 256                 return process_sample_event(event, offset, head);
 257
 258         case PERF_RECORD_MMAP:
 259                 return process_mmap_event(event, offset, head);
 260
 261         case PERF_RECORD_COMM:
 262                 return process_comm_event(event, offset, head);
 263
 264         case PERF_RECORD_FORK:
 265                 return process_fork_event(event, offset, head);
 266         /*
 267          * We dont process them right now but they are fine:
 268          */
 269
 270         case PERF_RECORD_THROTTLE:
 271         case PERF_RECORD_UNTHROTTLE:
 272                 return 0;
 273
 274         default:
 275                 return -1;
 276         }
 277
 278         return 0;
 279 }
 280
 281 static int
 282 parse_line(FILE *file, struct symbol *sym, u64 len)
 283 {
 284         char *line = NULL, *tmp, *tmp2;
 285         static const char *prev_line;
 286         static const char *prev_color;
 287         unsigned int offset;
 288         size_t line_len;
 289         s64 line_ip;
 290         int ret;
 291         char *c;
 292
 293         if (getline(&line, &line_len, file) < 0)
 294                 return -1;
 295         if (!line)
 296                 return -1;
 297
 298         c = strchr(line, '\n');
 299         if (c)
 300                 *c = 0;
 301
 302         line_ip = -1;
 303         offset = 0;
 304         ret = -2;
 305
 306         /*
 307          * Strip leading spaces:
 308          */
 309         tmp = line;
 310         while (*tmp) {
 311                 if (*tmp != ' ')
 312                         break;
 313                 tmp++;
 314         }
 315
 316         if (*tmp) {
 317                 /*
 318                  * Parse hexa addresses followed by ':'
 319                  */
 320                 line_ip = strtoull(tmp, &tmp2, 16);
 321                 if (*tmp2 != ':')
 322                         line_ip = -1;
 323         }
 324
 325         if (line_ip != -1) {
 326                 const char *path = NULL;
 327                 unsigned int hits = 0;
 328                 double percent = 0.0;
 329                 const char *color;
 330                 struct sym_ext *sym_ext = sym->priv;
 331
 332                 offset = line_ip - sym->start;
 333                 if (offset < len)
 334                         hits = sym->hist[offset];
 335
 336                 if (offset < len && sym_ext) {
 337                         path = sym_ext[offset].path;
 338                         percent = sym_ext[offset].percent;
 339                 } else if (sym->hist_sum)
 340                         percent = 100.0 * hits / sym->hist_sum;
 341
 342                 color = get_percent_color(percent);
 343
 344                 /*
 345                  * Also color the filename and line if needed, with
 346                  * the same color than the percentage. Don't print it
 347                  * twice for close colored ip with the same filename:line
 348                  */
 349                 if (path) {
 350                         if (!prev_line || strcmp(prev_line, path)
 351                                        || color != prev_color) {
 352                                 color_fprintf(stdout, color, " %s", path);
 353                                 prev_line = path;
 354                                 prev_color = color;
 355                         }
 356                 }
 357
 358                 color_fprintf(stdout, color, " %7.2f", percent);
 359                 printf(" :      ");
 360                 color_fprintf(stdout, PERF_COLOR_BLUE, "%s\n", line);
 361         } else {
 362                 if (!*line)
 363                         printf("         :\n");
 364                 else
 365                         printf("         :      %s\n", line);
 366         }
 367
 368         return 0;
 369 }
 370
 371 static struct rb_root root_sym_ext;
 372
 373 static void insert_source_line(struct sym_ext *sym_ext)
 374 {
 375         struct sym_ext *iter;
 376         struct rb_node **p = &root_sym_ext.rb_node;
 377         struct rb_node *parent = NULL;
 378
 379         while (*p != NULL) {
 380                 parent = *p;
 381                 iter = rb_entry(parent, struct sym_ext, node);
 382
 383                 if (sym_ext->percent > iter->percent)
 384                         p = &(*p)->rb_left;
 385                 else
 386                         p = &(*p)->rb_right;
 387         }
 388
 389         rb_link_node(&sym_ext->node, parent, p);
 390         rb_insert_color(&sym_ext->node, &root_sym_ext);
 391 }
 392
 393 static void free_source_line(struct symbol *sym, int len)
 394 {
 395         struct sym_ext *sym_ext = sym->priv;
 396         int i;
 397
 398         if (!sym_ext)
 399                 return;
 400
 401         for (i = 0; i < len; i++)
 402                 free(sym_ext[i].path);
 403         free(sym_ext);
 404
 405         sym->priv = NULL;
 406         root_sym_ext = RB_ROOT;
 407 }
 408
 409 /* Get the filename:line for the colored entries */
 410 static void
 411 get_source_line(struct symbol *sym, int len, const char *filename)
 412 {
 413         int i;
 414         char cmd[PATH_MAX * 2];
 415         struct sym_ext *sym_ext;
 416
 417         if (!sym->hist_sum)
 418                 return;
 419
 420         sym->priv = calloc(len, sizeof(struct sym_ext));
 421         if (!sym->priv)
 422                 return;
 423
 424         sym_ext = sym->priv;
 425
 426         for (i = 0; i < len; i++) {
 427                 char *path = NULL;
 428                 size_t line_len;
 429                 u64 offset;
 430                 FILE *fp;
 431
 432                 sym_ext[i].percent = 100.0 * sym->hist[i] / sym->hist_sum;
 433                 if (sym_ext[i].percent <= 0.5)
 434                         continue;
 435
 436                 offset = sym->start + i;
 437                 sprintf(cmd, "addr2line -e %s %016llx", filename, offset);
 438                 fp = popen(cmd, "r");
 439                 if (!fp)
 440                         continue;
 441
 442                 if (getline(&path, &line_len, fp) < 0 || !line_len)
 443                         goto next;
 444
 445                 sym_ext[i].path = malloc(sizeof(char) * line_len + 1);
 446                 if (!sym_ext[i].path)
 447                         goto next;
 448
 449                 strcpy(sym_ext[i].path, path);
 450                 insert_source_line(&sym_ext[i]);
 451
 452         next:
 453                 pclose(fp);
 454         }
 455 }
 456
 457 static void print_summary(const char *filename)
 458 {
 459         struct sym_ext *sym_ext;
 460         struct rb_node *node;
 461
 462         printf("\nSorted summary for file %s\n", filename);
 463         printf("----------------------------------------------\n\n");
 464
 465         if (RB_EMPTY_ROOT(&root_sym_ext)) {
 466                 printf(" Nothing higher than %1.1f%%\n", MIN_GREEN);
 467                 return;
 468         }
 469
 470         node = rb_first(&root_sym_ext);
 471         while (node) {
 472                 double percent;
 473                 const char *color;
 474                 char *path;
 475
 476                 sym_ext = rb_entry(node, struct sym_ext, node);
 477                 percent = sym_ext->percent;
 478                 color = get_percent_color(percent);
 479                 path = sym_ext->path;
 480
 481                 color_fprintf(stdout, color, " %7.2f %s", percent, path);
 482                 node = rb_next(node);
 483         }
 484 }
 485
 486 static void annotate_sym(struct dso *dso, struct symbol *sym)
 487 {
 488         const char *filename = dso->long_name, *d_filename;
 489         u64 len;
 490         char command[PATH_MAX*2];
 491         FILE *file;
 492
 493         if (!filename)
 494                 return;
 495
 496         if (full_paths)
 497                 d_filename = filename;
 498         else
 499                 d_filename = basename(filename);
 500
 501         len = sym->end - sym->start;
 502
 503         if (print_line) {
 504                 get_source_line(sym, len, filename);
 505                 print_summary(filename);
 506         }
 507
 508         printf("\n\n------------------------------------------------\n");
 509         printf(" Percent |      Source code & Disassembly of %s\n", d_filename);
 510         printf("------------------------------------------------\n");
 511
 512         if (verbose >= 2)
 513                 printf("annotating [%p] %30s : [%p] %30s\n",
 514                        dso, dso->long_name, sym, sym->name);
 515
 516         sprintf(command, "objdump --start-address=0x%016Lx --stop-address=0x%016Lx -dS %s|grep -v %s",
 517                 sym->start, sym->end, filename, filename);
 518
 519         if (verbose >= 3)
 520                 printf("doing: %s\n", command);
 521
 522         file = popen(command, "r");
 523         if (!file)
 524                 return;
 525
 526         while (!feof(file)) {
 527                 if (parse_line(file, sym, len) < 0)
 528                         break;
 529         }
 530
 531         pclose(file);
 532         if (print_line)
 533                 free_source_line(sym, len);
 534 }
 535
 536 static void find_annotations(void)
 537 {
 538         struct rb_node *nd;
 539         struct dso *dso;
 540         int count = 0;
 541
 542         list_for_each_entry(dso, &dsos, node) {
 543
 544                 for (nd = rb_first(&dso->syms); nd; nd = rb_next(nd)) {
 545                         struct symbol *sym = rb_entry(nd, struct symbol, rb_node);
 546
 547                         if (sym->hist) {
 548                                 annotate_sym(dso, sym);
 549                                 count++;
 550                         }
 551                 }
 552         }
 553
 554         if (!count)
 555                 printf(" Error: symbol '%s' not present amongst the samples.\n", sym_hist_filter);
 556 }
 557
 558 static int __cmd_annotate(void)
 559 {
 560         int ret, rc = EXIT_FAILURE;
 561         unsigned long offset = 0;
 562         unsigned long head = 0;
 563         struct stat input_stat;
 564         event_t *event;
 565         uint32_t size;
 566         char *buf;
 567
 568         register_idle_thread(&threads, &last_match);
 569
 570         input = open(input_name, O_RDONLY);
 571         if (input < 0) {
 572                 perror("failed to open file");
 573                 exit(-1);
 574         }
 575
 576         ret = fstat(input, &input_stat);
 577         if (ret < 0) {
 578                 perror("failed to stat file");
 579                 exit(-1);
 580         }
 581
 582         if (!force && input_stat.st_uid && (input_stat.st_uid != geteuid())) {
 583                 fprintf(stderr, "file: %s not owned by current user or root\n", input_name);
 584                 exit(-1);
 585         }
 586
 587         if (!input_stat.st_size) {
 588                 fprintf(stderr, "zero-sized file, nothing to do!\n");
 589                 exit(0);
 590         }
 591
 592         if (load_kernel() < 0) {
 593                 perror("failed to load kernel symbols");
 594                 return EXIT_FAILURE;
 595         }
 596
 597 remap:
 598         buf = (char *)mmap(NULL, page_size * mmap_window, PROT_READ,
 599                            MAP_SHARED, input, offset);
 600         if (buf == MAP_FAILED) {
 601                 perror("failed to mmap file");
 602                 exit(-1);
 603         }
 604
 605 more:
 606         event = (event_t *)(buf + head);
 607
 608         size = event->header.size;
 609         if (!size)
 610                 size = 8;
 611
 612         if (head + event->header.size >= page_size * mmap_window) {
 613                 unsigned long shift = page_size * (head / page_size);
 614                 int munmap_ret;
 615
 616                 munmap_ret = munmap(buf, page_size * mmap_window);
 617                 assert(munmap_ret == 0);
 618
 619                 offset += shift;
 620                 head -= shift;
 621                 goto remap;
 622         }
 623
 624         size = event->header.size;
 625
 626         dump_printf("%p [%p]: event: %d\n",
 627                         (void *)(offset + head),
 628                         (void *)(long)event->header.size,
 629                         event->header.type);
 630
 631         if (!size || process_event(event, offset, head) < 0) {
 632
 633                 dump_printf("%p [%p]: skipping unknown header type: %d\n",
 634                         (void *)(offset + head),
 635                         (void *)(long)(event->header.size),
 636                         event->header.type);
 637
 638                 total_unknown++;
 639
 640                 /*
 641                  * assume we lost track of the stream, check alignment, and
 642                  * increment a single u64 in the hope to catch on again 'soon'.
 643                  */
 644
 645                 if (unlikely(head & 7))
 646                         head &= ~7ULL;
 647
 648                 size = 8;
 649         }
 650
 651         head += size;
 652
 653         if (offset + head < (unsigned long)input_stat.st_size)
 654                 goto more;
 655
 656         rc = EXIT_SUCCESS;
 657         close(input);
 658
 659         dump_printf("      IP events: %10ld\n", total);
 660         dump_printf("    mmap events: %10ld\n", total_mmap);
 661         dump_printf("    comm events: %10ld\n", total_comm);
 662         dump_printf("    fork events: %10ld\n", total_fork);
 663         dump_printf(" unknown events: %10ld\n", total_unknown);
 664
 665         if (dump_trace)
 666                 return 0;
 667
 668         if (verbose >= 3)
 669                 threads__fprintf(stdout, &threads);
 670
 671         if (verbose >= 2)
 672                 dsos__fprintf(stdout);
 673
 674         collapse__resort();
 675         output__resort(total);
 676
 677         find_annotations();
 678
 679         return rc;
 680 }
 681
 682 static const char * const annotate_usage[] = {
 683         "perf annotate [<options>] <command>",
 684         NULL
 685 };
 686
 687 static const struct option options[] = {
 688         OPT_STRING('i', "input", &input_name, "file",
 689                     "input file name"),
 690         OPT_STRING('s', "symbol", &sym_hist_filter, "symbol",
 691                     "symbol to annotate"),
 692         OPT_BOOLEAN('f', "force", &force, "don't complain, do it"),
 693         OPT_BOOLEAN('v', "verbose", &verbose,
 694                     "be more verbose (show symbol address, etc)"),
 695         OPT_BOOLEAN('D', "dump-raw-trace", &dump_trace,
 696                     "dump raw trace in ASCII"),
 697         OPT_STRING('k', "vmlinux", &vmlinux_name, "file", "vmlinux pathname"),
 698         OPT_BOOLEAN('m', "modules", &modules,
 699                     "load module symbols - WARNING: use only with -k and LIVE kernel"),
 700         OPT_BOOLEAN('l', "print-line", &print_line,
 701                     "print matching source lines (may be slow)"),
 702         OPT_BOOLEAN('P', "full-paths", &full_paths,
 703                     "Don't shorten the displayed pathnames"),
 704         OPT_END()
 705 };
 706
 707 static void setup_sorting(void)
 708 {
 709         char *tmp, *tok, *str = strdup(sort_order);
 710
 711         for (tok = strtok_r(str, ", ", &tmp);
 712                         tok; tok = strtok_r(NULL, ", ", &tmp)) {
 713                 if (sort_dimension__add(tok) < 0) {
 714                         error("Unknown --sort key: `%s'", tok);
 715                         usage_with_options(annotate_usage, options);
 716                 }
 717         }
 718
 719         free(str);
 720 }
 721
 722 int cmd_annotate(int argc, const char **argv, const char *prefix __used)
 723 {
 724         symbol__init();
 725
 726         page_size = getpagesize();
 727
 728         argc = parse_options(argc, argv, options, annotate_usage, 0);
 729
 730         setup_sorting();
 731
 732         if (argc) {
 733                 /*
 734                  * Special case: if there's an argument left then assume tha
 735                  * it's a symbol filter:
 736                  */
 737                 if (argc > 1)
 738                         usage_with_options(annotate_usage, options);
 739
 740                 sym_hist_filter = argv[0];
 741         }
 742
 743         if (!sym_hist_filter)
 744                 usage_with_options(annotate_usage, options);
 745
 746         setup_pager();
 747
 748         if (field_sep && *field_sep == '.') {
 749                 fputs("'.' is the only non valid --field-separator argument\n",
 750                                 stderr);
 751                 exit(129);
 752         }
 753
 754         return __cmd_annotate();
 755 }