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