perf tools: Up the verbose level for some really verbose stuff
[pandora-kernel.git] / 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 }