builtin-annotate.c 15.1 KB
Newer Older
1 2 3 4 5 6 7 8 9 10 11 12
/*
 * builtin-annotate.c
 *
 * Builtin annotate command: Analyze the perf.data input file,
 * look up and read DSOs and symbol information and display
 * a histogram of results, along various sorting keys.
 */
#include "builtin.h"

#include "util/util.h"

#include "util/color.h"
13
#include <linux/list.h>
14
#include "util/cache.h"
15
#include <linux/rbtree.h>
16 17 18 19
#include "util/symbol.h"
#include "util/string.h"

#include "perf.h"
20
#include "util/debug.h"
21

22
#include "util/event.h"
23 24
#include "util/parse-options.h"
#include "util/parse-events.h"
25
#include "util/thread.h"
26
#include "util/sort.h"
27
#include "util/hist.h"
28 29 30

static char		const *input_name = "perf.data";

31
static int		force;
32 33
static int		input;

34 35
static int		full_paths;

36 37
static int		print_line;

38 39 40
static unsigned long	page_size;
static unsigned long	mmap_window = 32;

41 42 43 44 45
struct sym_hist {
	u64		sum;
	u64		ip[0];
};

46
struct sym_ext {
47
	struct rb_node	node;
48 49 50 51
	double		percent;
	char		*path;
};

52 53 54 55 56
struct sym_priv {
	struct sym_hist	*hist;
	struct sym_ext	*ext;
};

57 58 59 60 61
static struct symbol_conf symbol_conf = {
	.priv_size	  = sizeof(struct sym_priv),
	.try_vmlinux_path = true,
};

62 63
static const char *sym_hist_filter;

64
static int symbol_filter(struct map *map __used, struct symbol *sym)
65
{
66 67
	if (sym_hist_filter == NULL ||
	    strcmp(sym->name, sym_hist_filter) == 0) {
68
		struct sym_priv *priv = symbol__priv(sym);
69 70 71 72 73 74 75 76 77 78 79 80 81 82 83 84
		const int size = (sizeof(*priv->hist) +
				  (sym->end - sym->start) * sizeof(u64));

		priv->hist = malloc(size);
		if (priv->hist)
			memset(priv->hist, 0, size);
		return 0;
	}
	/*
	 * FIXME: We should really filter it out, as we don't want to go thru symbols
	 * we're not interested, and if a DSO ends up with no symbols, delete it too,
	 * but right now the kernel loading routines in symbol.c bail out if no symbols
	 * are found, fix it later.
	 */
	return 0;
}
85

86 87 88
/*
 * collect histogram counts
 */
89
static void hist_hit(struct hist_entry *he, u64 ip)
90
{
91 92
	unsigned int sym_size, offset;
	struct symbol *sym = he->sym;
93 94
	struct sym_priv *priv;
	struct sym_hist *h;
95

96
	he->count++;
97

98 99 100
	if (!sym || !he->map)
		return;

101
	priv = symbol__priv(sym);
102
	if (!priv->hist)
103
		return;
104

105 106
	sym_size = sym->end - sym->start;
	offset = ip - sym->start;
107

108 109 110 111
	if (verbose)
		fprintf(stderr, "%s: ip=%Lx\n", __func__,
			he->map->unmap_ip(he->map, ip));

112 113
	if (offset >= sym_size)
		return;
114

115 116 117
	h = priv->hist;
	h->sum++;
	h->ip[offset]++;
118

119 120
	if (verbose >= 3)
		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 128
static int hist_entry__add(struct thread *thread, struct map *map,
			   struct symbol *sym, u64 ip, u64 count, char level)
129
{
130 131 132 133
	bool hit;
	struct hist_entry *he = __hist_entry__add(thread, map, sym, NULL, ip,
						  count, level, &hit);
	if (he == NULL)
134
		return -ENOMEM;
135
	hist_hit(he, ip);
136 137 138
	return 0;
}

139
static int process_sample_event(event_t *event)
140 141
{
	char level;
142
	u64 ip = event->ip.ip;
143
	struct map *map = NULL;
144
	struct symbol *sym = NULL;
145
	struct thread *thread = threads__findnew(event->ip.pid);
146

147 148
	dump_printf("(IP, %d): %d: %p\n", event->header.misc,
		    event->ip.pid, (void *)(long)ip);
149 150 151 152 153 154 155

	if (thread == NULL) {
		fprintf(stderr, "problem processing %d event, skipping it.\n",
			event->header.type);
		return -1;
	}

156 157
	dump_printf(" ... thread: %s:%d\n", thread->comm, thread->pid);

158
	if (event->header.misc & PERF_RECORD_MISC_KERNEL) {
159
		level = 'k';
160
		sym = kernel_maps__find_function(ip, &map, symbol_filter);
161 162
		dump_printf(" ...... dso: %s\n",
			    map ? map->dso->long_name : "<not found>");
163
	} else if (event->header.misc & PERF_RECORD_MISC_USER) {
164
		level = '.';
165
		map = thread__find_map(thread, MAP__FUNCTION, ip);
166 167
		if (map != NULL) {
			ip = map->map_ip(map, ip);
168
			sym = map__find_symbol(map, ip, symbol_filter);
169 170 171 172 173
		} else {
			/*
			 * If this is outside of all known maps,
			 * and is a negative address, try to look it
			 * up in the kernel dso, as it might be a
174 175 176 177 178
			 * vsyscall or vdso (which executes in user-mode).
			 *
			 * XXX This is nasty, we should have a symbol list in
			 * the "[vdso]" dso, but for now lets use the old
			 * trick of looking in the whole kernel symbol list.
179
			 */
180 181 182
			if ((long long)ip < 0)
				sym = kernel_maps__find_function(ip, &map,
								 symbol_filter);
183
		}
184 185
		dump_printf(" ...... dso: %s\n",
			    map ? map->dso->long_name : "<not found>");
186 187
	} else {
		level = 'H';
188
		dump_printf(" ...... dso: [hypervisor]\n");
189 190
	}

191 192 193 194
	if (hist_entry__add(thread, map, sym, ip, 1, level)) {
		fprintf(stderr, "problem incrementing symbol count, "
				"skipping event\n");
		return -1;
195 196 197 198 199
	}

	return 0;
}

200
static int event__process(event_t *self)
201
{
202
	switch (self->header.type) {
203
	case PERF_RECORD_SAMPLE:
204
		return process_sample_event(self);
205

206
	case PERF_RECORD_MMAP:
207
		return event__process_mmap(self);
208

209
	case PERF_RECORD_COMM:
210
		return event__process_comm(self);
211

212
	case PERF_RECORD_FORK:
213
		return event__process_task(self);
214 215 216 217
	/*
	 * We dont process them right now but they are fine:
	 */

218 219
	case PERF_RECORD_THROTTLE:
	case PERF_RECORD_UNTHROTTLE:
220 221 222 223 224 225 226 227 228
		return 0;

	default:
		return -1;
	}

	return 0;
}

229
static int parse_line(FILE *file, struct hist_entry *he, u64 len)
230
{
231
	struct symbol *sym = he->sym;
232
	char *line = NULL, *tmp, *tmp2;
233 234
	static const char *prev_line;
	static const char *prev_color;
235 236
	unsigned int offset;
	size_t line_len;
237
	u64 start;
238
	s64 line_ip;
239 240 241 242 243 244 245 246 247 248 249 250 251 252 253 254 255 256 257 258 259 260 261 262 263 264 265 266 267 268 269 270 271 272 273
	int ret;
	char *c;

	if (getline(&line, &line_len, file) < 0)
		return -1;
	if (!line)
		return -1;

	c = strchr(line, '\n');
	if (c)
		*c = 0;

	line_ip = -1;
	offset = 0;
	ret = -2;

	/*
	 * Strip leading spaces:
	 */
	tmp = line;
	while (*tmp) {
		if (*tmp != ' ')
			break;
		tmp++;
	}

	if (*tmp) {
		/*
		 * Parse hexa addresses followed by ':'
		 */
		line_ip = strtoull(tmp, &tmp2, 16);
		if (*tmp2 != ':')
			line_ip = -1;
	}

274 275
	start = he->map->unmap_ip(he->map, sym->start);

276
	if (line_ip != -1) {
277
		const char *path = NULL;
278 279
		unsigned int hits = 0;
		double percent = 0.0;
280
		const char *color;
281
		struct sym_priv *priv = symbol__priv(sym);
282 283
		struct sym_ext *sym_ext = priv->ext;
		struct sym_hist *h = priv->hist;
284

285
		offset = line_ip - start;
286
		if (offset < len)
287
			hits = h->ip[offset];
288

289
		if (offset < len && sym_ext) {
290 291
			path = sym_ext[offset].path;
			percent = sym_ext[offset].percent;
292 293
		} else if (h->sum)
			percent = 100.0 * hits / h->sum;
294

295
		color = get_percent_color(percent);
296

297 298 299 300 301 302 303 304 305 306 307 308 309 310
		/*
		 * Also color the filename and line if needed, with
		 * the same color than the percentage. Don't print it
		 * twice for close colored ip with the same filename:line
		 */
		if (path) {
			if (!prev_line || strcmp(prev_line, path)
				       || color != prev_color) {
				color_fprintf(stdout, color, " %s", path);
				prev_line = path;
				prev_color = color;
			}
		}

311 312 313 314 315 316 317 318 319 320 321 322 323
		color_fprintf(stdout, color, " %7.2f", percent);
		printf(" :	");
		color_fprintf(stdout, PERF_COLOR_BLUE, "%s\n", line);
	} else {
		if (!*line)
			printf("         :\n");
		else
			printf("         :	%s\n", line);
	}

	return 0;
}

324 325 326 327 328 329 330 331 332 333 334 335 336 337 338 339 340 341 342 343 344 345
static struct rb_root root_sym_ext;

static void insert_source_line(struct sym_ext *sym_ext)
{
	struct sym_ext *iter;
	struct rb_node **p = &root_sym_ext.rb_node;
	struct rb_node *parent = NULL;

	while (*p != NULL) {
		parent = *p;
		iter = rb_entry(parent, struct sym_ext, node);

		if (sym_ext->percent > iter->percent)
			p = &(*p)->rb_left;
		else
			p = &(*p)->rb_right;
	}

	rb_link_node(&sym_ext->node, parent, p);
	rb_insert_color(&sym_ext->node, &root_sym_ext);
}

346
static void free_source_line(struct hist_entry *he, int len)
347
{
348
	struct sym_priv *priv = symbol__priv(he->sym);
349
	struct sym_ext *sym_ext = priv->ext;
350 351 352 353 354 355 356 357 358
	int i;

	if (!sym_ext)
		return;

	for (i = 0; i < len; i++)
		free(sym_ext[i].path);
	free(sym_ext);

359
	priv->ext = NULL;
360
	root_sym_ext = RB_ROOT;
361 362 363
}

/* Get the filename:line for the colored entries */
364
static void
365
get_source_line(struct hist_entry *he, int len, const char *filename)
366
{
367 368
	struct symbol *sym = he->sym;
	u64 start;
369 370 371
	int i;
	char cmd[PATH_MAX * 2];
	struct sym_ext *sym_ext;
372
	struct sym_priv *priv = symbol__priv(sym);
373
	struct sym_hist *h = priv->hist;
374

375
	if (!h->sum)
376 377
		return;

378 379
	sym_ext = priv->ext = calloc(len, sizeof(struct sym_ext));
	if (!priv->ext)
380 381
		return;

382
	start = he->map->unmap_ip(he->map, sym->start);
383 384 385 386

	for (i = 0; i < len; i++) {
		char *path = NULL;
		size_t line_len;
387
		u64 offset;
388 389
		FILE *fp;

390
		sym_ext[i].percent = 100.0 * h->ip[i] / h->sum;
391 392 393
		if (sym_ext[i].percent <= 0.5)
			continue;

394
		offset = start + i;
395
		sprintf(cmd, "addr2line -e %s %016llx", filename, offset);
396 397 398 399 400 401 402
		fp = popen(cmd, "r");
		if (!fp)
			continue;

		if (getline(&path, &line_len, fp) < 0 || !line_len)
			goto next;

403
		sym_ext[i].path = malloc(sizeof(char) * line_len + 1);
404 405 406 407
		if (!sym_ext[i].path)
			goto next;

		strcpy(sym_ext[i].path, path);
408
		insert_source_line(&sym_ext[i]);
409 410 411 412 413 414

	next:
		pclose(fp);
	}
}

415
static void print_summary(const char *filename)
416 417 418 419 420 421 422 423 424 425 426 427 428 429 430
{
	struct sym_ext *sym_ext;
	struct rb_node *node;

	printf("\nSorted summary for file %s\n", filename);
	printf("----------------------------------------------\n\n");

	if (RB_EMPTY_ROOT(&root_sym_ext)) {
		printf(" Nothing higher than %1.1f%%\n", MIN_GREEN);
		return;
	}

	node = rb_first(&root_sym_ext);
	while (node) {
		double percent;
431
		const char *color;
432 433 434 435
		char *path;

		sym_ext = rb_entry(node, struct sym_ext, node);
		percent = sym_ext->percent;
436
		color = get_percent_color(percent);
437 438 439 440 441 442 443
		path = sym_ext->path;

		color_fprintf(stdout, color, " %7.2f %s", percent, path);
		node = rb_next(node);
	}
}

444
static void annotate_sym(struct hist_entry *he)
445
{
446 447 448
	struct map *map = he->map;
	struct dso *dso = map->dso;
	struct symbol *sym = he->sym;
449 450
	const char *filename = dso->long_name, *d_filename;
	u64 len;
451 452 453 454 455
	char command[PATH_MAX*2];
	FILE *file;

	if (!filename)
		return;
456

457 458 459 460 461 462
	if (verbose)
		fprintf(stderr, "%s: filename=%s, sym=%s, start=%Lx, end=%Lx\n",
			__func__, filename, sym->name,
			map->unmap_ip(map, sym->start),
			map->unmap_ip(map, sym->end));

463 464 465 466
	if (full_paths)
		d_filename = filename;
	else
		d_filename = basename(filename);
467 468 469

	len = sym->end - sym->start;

470
	if (print_line) {
471
		get_source_line(he, len, filename);
472 473 474 475
		print_summary(filename);
	}

	printf("\n\n------------------------------------------------\n");
476
	printf(" Percent |	Source code & Disassembly of %s\n", d_filename);
477 478 479
	printf("------------------------------------------------\n");

	if (verbose >= 2)
480 481
		printf("annotating [%p] %30s : [%p] %30s\n",
		       dso, dso->long_name, sym, sym->name);
482

483
	sprintf(command, "objdump --start-address=0x%016Lx --stop-address=0x%016Lx -dS %s|grep -v %s",
484 485
		map->unmap_ip(map, sym->start), map->unmap_ip(map, sym->end),
		filename, filename);
486 487 488 489 490 491 492 493 494

	if (verbose >= 3)
		printf("doing: %s\n", command);

	file = popen(command, "r");
	if (!file)
		return;

	while (!feof(file)) {
495
		if (parse_line(file, he, len) < 0)
496 497 498 499
			break;
	}

	pclose(file);
500
	if (print_line)
501
		free_source_line(he, len);
502 503 504 505 506 507
}

static void find_annotations(void)
{
	struct rb_node *nd;

508 509
	for (nd = rb_first(&output_hists); nd; nd = rb_next(nd)) {
		struct hist_entry *he = rb_entry(nd, struct hist_entry, rb_node);
510
		struct sym_priv *priv;
511

512 513
		if (he->sym == NULL)
			continue;
514

515
		priv = symbol__priv(he->sym);
516 517 518 519 520 521 522 523 524 525
		if (priv->hist == NULL)
			continue;

		annotate_sym(he);
		/*
		 * Since we have a hist_entry per IP for the same symbol, free
		 * he->sym->hist to signal we already processed this symbol.
		 */
		free(priv->hist);
		priv->hist = NULL;
526 527 528
	}
}

529 530 531 532 533
static int __cmd_annotate(void)
{
	int ret, rc = EXIT_FAILURE;
	unsigned long offset = 0;
	unsigned long head = 0;
534
	struct stat input_stat;
535 536 537 538
	event_t *event;
	uint32_t size;
	char *buf;

539
	register_idle_thread();
540 541 542 543 544 545 546

	input = open(input_name, O_RDONLY);
	if (input < 0) {
		perror("failed to open file");
		exit(-1);
	}

547
	ret = fstat(input, &input_stat);
548 549 550 551 552
	if (ret < 0) {
		perror("failed to stat file");
		exit(-1);
	}

553 554
	if (!force && input_stat.st_uid && (input_stat.st_uid != geteuid())) {
		fprintf(stderr, "file: %s not owned by current user or root\n", input_name);
555 556 557
		exit(-1);
	}

558
	if (!input_stat.st_size) {
559 560 561 562 563 564 565 566 567 568 569 570 571 572 573 574 575 576 577 578 579
		fprintf(stderr, "zero-sized file, nothing to do!\n");
		exit(0);
	}

remap:
	buf = (char *)mmap(NULL, page_size * mmap_window, PROT_READ,
			   MAP_SHARED, input, offset);
	if (buf == MAP_FAILED) {
		perror("failed to mmap file");
		exit(-1);
	}

more:
	event = (event_t *)(buf + head);

	size = event->header.size;
	if (!size)
		size = 8;

	if (head + event->header.size >= page_size * mmap_window) {
		unsigned long shift = page_size * (head / page_size);
580
		int munmap_ret;
581

582 583
		munmap_ret = munmap(buf, page_size * mmap_window);
		assert(munmap_ret == 0);
584 585 586 587 588 589 590 591

		offset += shift;
		head -= shift;
		goto remap;
	}

	size = event->header.size;

592
	dump_printf("%p [%p]: event: %d\n",
593 594 595 596
			(void *)(offset + head),
			(void *)(long)event->header.size,
			event->header.type);

597
	if (!size || event__process(event) < 0) {
598

599
		dump_printf("%p [%p]: skipping unknown header type: %d\n",
600 601 602 603 604 605 606 607 608 609 610 611 612 613 614 615
			(void *)(offset + head),
			(void *)(long)(event->header.size),
			event->header.type);
		/*
		 * assume we lost track of the stream, check alignment, and
		 * increment a single u64 in the hope to catch on again 'soon'.
		 */

		if (unlikely(head & 7))
			head &= ~7ULL;

		size = 8;
	}

	head += size;

616
	if (offset + head < (unsigned long)input_stat.st_size)
617 618 619 620 621 622
		goto more;

	rc = EXIT_SUCCESS;
	close(input);


623 624
	if (dump_trace) {
		event__print_totals();
625
		return 0;
626
	}
627

628
	if (verbose > 3)
629
		threads__fprintf(stdout);
630

631
	if (verbose > 2)
632 633 634
		dsos__fprintf(stdout);

	collapse__resort();
635
	output__resort(event__total[0]);
636 637

	find_annotations();
638 639 640 641 642 643 644 645 646 647 648 649

	return rc;
}

static const char * const annotate_usage[] = {
	"perf annotate [<options>] <command>",
	NULL
};

static const struct option options[] = {
	OPT_STRING('i', "input", &input_name, "file",
		    "input file name"),
650
	OPT_STRING('s', "symbol", &sym_hist_filter, "symbol",
651
		    "symbol to annotate"),
652
	OPT_BOOLEAN('f', "force", &force, "don't complain, do it"),
653 654 655 656
	OPT_BOOLEAN('v', "verbose", &verbose,
		    "be more verbose (show symbol address, etc)"),
	OPT_BOOLEAN('D', "dump-raw-trace", &dump_trace,
		    "dump raw trace in ASCII"),
657 658 659
	OPT_STRING('k', "vmlinux", &symbol_conf.vmlinux_name,
		   "file", "vmlinux pathname"),
	OPT_BOOLEAN('m', "modules", &symbol_conf.use_modules,
660
		    "load module symbols - WARNING: use only with -k and LIVE kernel"),
661 662
	OPT_BOOLEAN('l', "print-line", &print_line,
		    "print matching source lines (may be slow)"),
663 664
	OPT_BOOLEAN('P', "full-paths", &full_paths,
		    "Don't shorten the displayed pathnames"),
665 666 667 668 669 670 671 672 673 674 675 676 677 678 679 680 681 682
	OPT_END()
};

static void setup_sorting(void)
{
	char *tmp, *tok, *str = strdup(sort_order);

	for (tok = strtok_r(str, ", ", &tmp);
			tok; tok = strtok_r(NULL, ", ", &tmp)) {
		if (sort_dimension__add(tok) < 0) {
			error("Unknown --sort key: `%s'", tok);
			usage_with_options(annotate_usage, options);
		}
	}

	free(str);
}

683
int cmd_annotate(int argc, const char **argv, const char *prefix __used)
684
{
685 686
	if (symbol__init(&symbol_conf) < 0)
		return -1;
687 688 689 690 691 692 693

	page_size = getpagesize();

	argc = parse_options(argc, argv, options, annotate_usage, 0);

	setup_sorting();

694 695 696 697 698 699 700 701 702 703 704
	if (argc) {
		/*
		 * Special case: if there's an argument left then assume tha
		 * it's a symbol filter:
		 */
		if (argc > 1)
			usage_with_options(annotate_usage, options);

		sym_hist_filter = argv[0];
	}

705 706
	setup_pager();

707 708 709 710 711 712
	if (field_sep && *field_sep == '.') {
		fputs("'.' is the only non valid --field-separator argument\n",
				stderr);
		exit(129);
	}

713 714
	return __cmd_annotate();
}