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