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