xref: /linux/tools/perf/builtin-stat.c (revision b3b77c8caef1750ebeea1054e39e358550ea9f55)
1 /*
2  * builtin-stat.c
3  *
4  * Builtin stat command: Give a precise performance counters summary
5  * overview about any workload, CPU or specific PID.
6  *
7  * Sample output:
8 
9    $ perf stat ~/hackbench 10
10    Time: 0.104
11 
12     Performance counter stats for '/home/mingo/hackbench':
13 
14        1255.538611  task clock ticks     #      10.143 CPU utilization factor
15              54011  context switches     #       0.043 M/sec
16                385  CPU migrations       #       0.000 M/sec
17              17755  pagefaults           #       0.014 M/sec
18         3808323185  CPU cycles           #    3033.219 M/sec
19         1575111190  instructions         #    1254.530 M/sec
20           17367895  cache references     #      13.833 M/sec
21            7674421  cache misses         #       6.112 M/sec
22 
23     Wall-clock time elapsed:   123.786620 msecs
24 
25  *
26  * Copyright (C) 2008, Red Hat Inc, Ingo Molnar <mingo@redhat.com>
27  *
28  * Improvements and fixes by:
29  *
30  *   Arjan van de Ven <arjan@linux.intel.com>
31  *   Yanmin Zhang <yanmin.zhang@intel.com>
32  *   Wu Fengguang <fengguang.wu@intel.com>
33  *   Mike Galbraith <efault@gmx.de>
34  *   Paul Mackerras <paulus@samba.org>
35  *   Jaswinder Singh Rajput <jaswinder@kernel.org>
36  *
37  * Released under the GPL v2. (and only v2, not any later version)
38  */
39 
40 #include "perf.h"
41 #include "builtin.h"
42 #include "util/util.h"
43 #include "util/parse-options.h"
44 #include "util/parse-events.h"
45 #include "util/event.h"
46 #include "util/debug.h"
47 #include "util/header.h"
48 #include "util/cpumap.h"
49 #include "util/thread.h"
50 
51 #include <sys/prctl.h>
52 #include <math.h>
53 
54 static struct perf_event_attr default_attrs[] = {
55 
56   { .type = PERF_TYPE_SOFTWARE, .config = PERF_COUNT_SW_TASK_CLOCK		},
57   { .type = PERF_TYPE_SOFTWARE, .config = PERF_COUNT_SW_CONTEXT_SWITCHES	},
58   { .type = PERF_TYPE_SOFTWARE, .config = PERF_COUNT_SW_CPU_MIGRATIONS		},
59   { .type = PERF_TYPE_SOFTWARE, .config = PERF_COUNT_SW_PAGE_FAULTS		},
60 
61   { .type = PERF_TYPE_HARDWARE, .config = PERF_COUNT_HW_CPU_CYCLES		},
62   { .type = PERF_TYPE_HARDWARE, .config = PERF_COUNT_HW_INSTRUCTIONS		},
63   { .type = PERF_TYPE_HARDWARE, .config = PERF_COUNT_HW_BRANCH_INSTRUCTIONS	},
64   { .type = PERF_TYPE_HARDWARE, .config = PERF_COUNT_HW_BRANCH_MISSES		},
65   { .type = PERF_TYPE_HARDWARE, .config = PERF_COUNT_HW_CACHE_REFERENCES	},
66   { .type = PERF_TYPE_HARDWARE, .config = PERF_COUNT_HW_CACHE_MISSES		},
67 
68 };
69 
70 static bool			system_wide			=  false;
71 static unsigned int		nr_cpus				=  0;
72 static int			run_idx				=  0;
73 
74 static int			run_count			=  1;
75 static bool			no_inherit			= false;
76 static bool			scale				=  true;
77 static pid_t			target_pid			= -1;
78 static pid_t			target_tid			= -1;
79 static pid_t			*all_tids			=  NULL;
80 static int			thread_num			=  0;
81 static pid_t			child_pid			= -1;
82 static bool			null_run			=  false;
83 
84 static int			*fd[MAX_NR_CPUS][MAX_COUNTERS];
85 
86 static int			event_scaled[MAX_COUNTERS];
87 
88 static volatile int done = 0;
89 
90 struct stats
91 {
92 	double n, mean, M2;
93 };
94 
95 static void update_stats(struct stats *stats, u64 val)
96 {
97 	double delta;
98 
99 	stats->n++;
100 	delta = val - stats->mean;
101 	stats->mean += delta / stats->n;
102 	stats->M2 += delta*(val - stats->mean);
103 }
104 
105 static double avg_stats(struct stats *stats)
106 {
107 	return stats->mean;
108 }
109 
110 /*
111  * http://en.wikipedia.org/wiki/Algorithms_for_calculating_variance
112  *
113  *       (\Sum n_i^2) - ((\Sum n_i)^2)/n
114  * s^2 = -------------------------------
115  *                  n - 1
116  *
117  * http://en.wikipedia.org/wiki/Stddev
118  *
119  * The std dev of the mean is related to the std dev by:
120  *
121  *             s
122  * s_mean = -------
123  *          sqrt(n)
124  *
125  */
126 static double stddev_stats(struct stats *stats)
127 {
128 	double variance = stats->M2 / (stats->n - 1);
129 	double variance_mean = variance / stats->n;
130 
131 	return sqrt(variance_mean);
132 }
133 
134 struct stats			event_res_stats[MAX_COUNTERS][3];
135 struct stats			runtime_nsecs_stats;
136 struct stats			walltime_nsecs_stats;
137 struct stats			runtime_cycles_stats;
138 struct stats			runtime_branches_stats;
139 
140 #define MATCH_EVENT(t, c, counter)			\
141 	(attrs[counter].type == PERF_TYPE_##t &&	\
142 	 attrs[counter].config == PERF_COUNT_##c)
143 
144 #define ERR_PERF_OPEN \
145 "Error: counter %d, sys_perf_event_open() syscall returned with %d (%s)\n"
146 
147 static int create_perf_stat_counter(int counter)
148 {
149 	struct perf_event_attr *attr = attrs + counter;
150 	int thread;
151 	int ncreated = 0;
152 
153 	if (scale)
154 		attr->read_format = PERF_FORMAT_TOTAL_TIME_ENABLED |
155 				    PERF_FORMAT_TOTAL_TIME_RUNNING;
156 
157 	if (system_wide) {
158 		unsigned int cpu;
159 
160 		for (cpu = 0; cpu < nr_cpus; cpu++) {
161 			fd[cpu][counter][0] = sys_perf_event_open(attr,
162 					-1, cpumap[cpu], -1, 0);
163 			if (fd[cpu][counter][0] < 0)
164 				pr_debug(ERR_PERF_OPEN, counter,
165 					 fd[cpu][counter][0], strerror(errno));
166 			else
167 				++ncreated;
168 		}
169 	} else {
170 		attr->inherit = !no_inherit;
171 		if (target_pid == -1 && target_tid == -1) {
172 			attr->disabled = 1;
173 			attr->enable_on_exec = 1;
174 		}
175 		for (thread = 0; thread < thread_num; thread++) {
176 			fd[0][counter][thread] = sys_perf_event_open(attr,
177 				all_tids[thread], -1, -1, 0);
178 			if (fd[0][counter][thread] < 0)
179 				pr_debug(ERR_PERF_OPEN, counter,
180 					 fd[0][counter][thread],
181 					 strerror(errno));
182 			else
183 				++ncreated;
184 		}
185 	}
186 
187 	return ncreated;
188 }
189 
190 /*
191  * Does the counter have nsecs as a unit?
192  */
193 static inline int nsec_counter(int counter)
194 {
195 	if (MATCH_EVENT(SOFTWARE, SW_CPU_CLOCK, counter) ||
196 	    MATCH_EVENT(SOFTWARE, SW_TASK_CLOCK, counter))
197 		return 1;
198 
199 	return 0;
200 }
201 
202 /*
203  * Read out the results of a single counter:
204  */
205 static void read_counter(int counter)
206 {
207 	u64 count[3], single_count[3];
208 	unsigned int cpu;
209 	size_t res, nv;
210 	int scaled;
211 	int i, thread;
212 
213 	count[0] = count[1] = count[2] = 0;
214 
215 	nv = scale ? 3 : 1;
216 	for (cpu = 0; cpu < nr_cpus; cpu++) {
217 		for (thread = 0; thread < thread_num; thread++) {
218 			if (fd[cpu][counter][thread] < 0)
219 				continue;
220 
221 			res = read(fd[cpu][counter][thread],
222 					single_count, nv * sizeof(u64));
223 			assert(res == nv * sizeof(u64));
224 
225 			close(fd[cpu][counter][thread]);
226 			fd[cpu][counter][thread] = -1;
227 
228 			count[0] += single_count[0];
229 			if (scale) {
230 				count[1] += single_count[1];
231 				count[2] += single_count[2];
232 			}
233 		}
234 	}
235 
236 	scaled = 0;
237 	if (scale) {
238 		if (count[2] == 0) {
239 			event_scaled[counter] = -1;
240 			count[0] = 0;
241 			return;
242 		}
243 
244 		if (count[2] < count[1]) {
245 			event_scaled[counter] = 1;
246 			count[0] = (unsigned long long)
247 				((double)count[0] * count[1] / count[2] + 0.5);
248 		}
249 	}
250 
251 	for (i = 0; i < 3; i++)
252 		update_stats(&event_res_stats[counter][i], count[i]);
253 
254 	if (verbose) {
255 		fprintf(stderr, "%s: %Ld %Ld %Ld\n", event_name(counter),
256 				count[0], count[1], count[2]);
257 	}
258 
259 	/*
260 	 * Save the full runtime - to allow normalization during printout:
261 	 */
262 	if (MATCH_EVENT(SOFTWARE, SW_TASK_CLOCK, counter))
263 		update_stats(&runtime_nsecs_stats, count[0]);
264 	if (MATCH_EVENT(HARDWARE, HW_CPU_CYCLES, counter))
265 		update_stats(&runtime_cycles_stats, count[0]);
266 	if (MATCH_EVENT(HARDWARE, HW_BRANCH_INSTRUCTIONS, counter))
267 		update_stats(&runtime_branches_stats, count[0]);
268 }
269 
270 static int run_perf_stat(int argc __used, const char **argv)
271 {
272 	unsigned long long t0, t1;
273 	int status = 0;
274 	int counter, ncreated = 0;
275 	int child_ready_pipe[2], go_pipe[2];
276 	const bool forks = (argc > 0);
277 	char buf;
278 
279 	if (!system_wide)
280 		nr_cpus = 1;
281 
282 	if (forks && (pipe(child_ready_pipe) < 0 || pipe(go_pipe) < 0)) {
283 		perror("failed to create pipes");
284 		exit(1);
285 	}
286 
287 	if (forks) {
288 		if ((child_pid = fork()) < 0)
289 			perror("failed to fork");
290 
291 		if (!child_pid) {
292 			close(child_ready_pipe[0]);
293 			close(go_pipe[1]);
294 			fcntl(go_pipe[0], F_SETFD, FD_CLOEXEC);
295 
296 			/*
297 			 * Do a dummy execvp to get the PLT entry resolved,
298 			 * so we avoid the resolver overhead on the real
299 			 * execvp call.
300 			 */
301 			execvp("", (char **)argv);
302 
303 			/*
304 			 * Tell the parent we're ready to go
305 			 */
306 			close(child_ready_pipe[1]);
307 
308 			/*
309 			 * Wait until the parent tells us to go.
310 			 */
311 			if (read(go_pipe[0], &buf, 1) == -1)
312 				perror("unable to read pipe");
313 
314 			execvp(argv[0], (char **)argv);
315 
316 			perror(argv[0]);
317 			exit(-1);
318 		}
319 
320 		if (target_tid == -1 && target_pid == -1 && !system_wide)
321 			all_tids[0] = child_pid;
322 
323 		/*
324 		 * Wait for the child to be ready to exec.
325 		 */
326 		close(child_ready_pipe[1]);
327 		close(go_pipe[0]);
328 		if (read(child_ready_pipe[0], &buf, 1) == -1)
329 			perror("unable to read pipe");
330 		close(child_ready_pipe[0]);
331 	}
332 
333 	for (counter = 0; counter < nr_counters; counter++)
334 		ncreated += create_perf_stat_counter(counter);
335 
336 	if (ncreated == 0) {
337 		pr_err("No permission to collect %sstats.\n"
338 		       "Consider tweaking /proc/sys/kernel/perf_event_paranoid.\n",
339 		       system_wide ? "system-wide " : "");
340 		if (child_pid != -1)
341 			kill(child_pid, SIGTERM);
342 		return -1;
343 	}
344 
345 	/*
346 	 * Enable counters and exec the command:
347 	 */
348 	t0 = rdclock();
349 
350 	if (forks) {
351 		close(go_pipe[1]);
352 		wait(&status);
353 	} else {
354 		while(!done) sleep(1);
355 	}
356 
357 	t1 = rdclock();
358 
359 	update_stats(&walltime_nsecs_stats, t1 - t0);
360 
361 	for (counter = 0; counter < nr_counters; counter++)
362 		read_counter(counter);
363 
364 	return WEXITSTATUS(status);
365 }
366 
367 static void print_noise(int counter, double avg)
368 {
369 	if (run_count == 1)
370 		return;
371 
372 	fprintf(stderr, "   ( +- %7.3f%% )",
373 			100 * stddev_stats(&event_res_stats[counter][0]) / avg);
374 }
375 
376 static void nsec_printout(int counter, double avg)
377 {
378 	double msecs = avg / 1e6;
379 
380 	fprintf(stderr, " %14.6f  %-24s", msecs, event_name(counter));
381 
382 	if (MATCH_EVENT(SOFTWARE, SW_TASK_CLOCK, counter)) {
383 		fprintf(stderr, " # %10.3f CPUs ",
384 				avg / avg_stats(&walltime_nsecs_stats));
385 	}
386 }
387 
388 static void abs_printout(int counter, double avg)
389 {
390 	double total, ratio = 0.0;
391 
392 	fprintf(stderr, " %14.0f  %-24s", avg, event_name(counter));
393 
394 	if (MATCH_EVENT(HARDWARE, HW_INSTRUCTIONS, counter)) {
395 		total = avg_stats(&runtime_cycles_stats);
396 
397 		if (total)
398 			ratio = avg / total;
399 
400 		fprintf(stderr, " # %10.3f IPC  ", ratio);
401 	} else if (MATCH_EVENT(HARDWARE, HW_BRANCH_MISSES, counter) &&
402 			runtime_branches_stats.n != 0) {
403 		total = avg_stats(&runtime_branches_stats);
404 
405 		if (total)
406 			ratio = avg * 100 / total;
407 
408 		fprintf(stderr, " # %10.3f %%    ", ratio);
409 
410 	} else if (runtime_nsecs_stats.n != 0) {
411 		total = avg_stats(&runtime_nsecs_stats);
412 
413 		if (total)
414 			ratio = 1000.0 * avg / total;
415 
416 		fprintf(stderr, " # %10.3f M/sec", ratio);
417 	}
418 }
419 
420 /*
421  * Print out the results of a single counter:
422  */
423 static void print_counter(int counter)
424 {
425 	double avg = avg_stats(&event_res_stats[counter][0]);
426 	int scaled = event_scaled[counter];
427 
428 	if (scaled == -1) {
429 		fprintf(stderr, " %14s  %-24s\n",
430 			"<not counted>", event_name(counter));
431 		return;
432 	}
433 
434 	if (nsec_counter(counter))
435 		nsec_printout(counter, avg);
436 	else
437 		abs_printout(counter, avg);
438 
439 	print_noise(counter, avg);
440 
441 	if (scaled) {
442 		double avg_enabled, avg_running;
443 
444 		avg_enabled = avg_stats(&event_res_stats[counter][1]);
445 		avg_running = avg_stats(&event_res_stats[counter][2]);
446 
447 		fprintf(stderr, "  (scaled from %.2f%%)",
448 				100 * avg_running / avg_enabled);
449 	}
450 
451 	fprintf(stderr, "\n");
452 }
453 
454 static void print_stat(int argc, const char **argv)
455 {
456 	int i, counter;
457 
458 	fflush(stdout);
459 
460 	fprintf(stderr, "\n");
461 	fprintf(stderr, " Performance counter stats for ");
462 	if(target_pid == -1 && target_tid == -1) {
463 		fprintf(stderr, "\'%s", argv[0]);
464 		for (i = 1; i < argc; i++)
465 			fprintf(stderr, " %s", argv[i]);
466 	} else if (target_pid != -1)
467 		fprintf(stderr, "process id \'%d", target_pid);
468 	else
469 		fprintf(stderr, "thread id \'%d", target_tid);
470 
471 	fprintf(stderr, "\'");
472 	if (run_count > 1)
473 		fprintf(stderr, " (%d runs)", run_count);
474 	fprintf(stderr, ":\n\n");
475 
476 	for (counter = 0; counter < nr_counters; counter++)
477 		print_counter(counter);
478 
479 	fprintf(stderr, "\n");
480 	fprintf(stderr, " %14.9f  seconds time elapsed",
481 			avg_stats(&walltime_nsecs_stats)/1e9);
482 	if (run_count > 1) {
483 		fprintf(stderr, "   ( +- %7.3f%% )",
484 				100*stddev_stats(&walltime_nsecs_stats) /
485 				avg_stats(&walltime_nsecs_stats));
486 	}
487 	fprintf(stderr, "\n\n");
488 }
489 
490 static volatile int signr = -1;
491 
492 static void skip_signal(int signo)
493 {
494 	if(child_pid == -1)
495 		done = 1;
496 
497 	signr = signo;
498 }
499 
500 static void sig_atexit(void)
501 {
502 	if (child_pid != -1)
503 		kill(child_pid, SIGTERM);
504 
505 	if (signr == -1)
506 		return;
507 
508 	signal(signr, SIG_DFL);
509 	kill(getpid(), signr);
510 }
511 
512 static const char * const stat_usage[] = {
513 	"perf stat [<options>] [<command>]",
514 	NULL
515 };
516 
517 static const struct option options[] = {
518 	OPT_CALLBACK('e', "event", NULL, "event",
519 		     "event selector. use 'perf list' to list available events",
520 		     parse_events),
521 	OPT_BOOLEAN('i', "no-inherit", &no_inherit,
522 		    "child tasks do not inherit counters"),
523 	OPT_INTEGER('p', "pid", &target_pid,
524 		    "stat events on existing process id"),
525 	OPT_INTEGER('t', "tid", &target_tid,
526 		    "stat events on existing thread id"),
527 	OPT_BOOLEAN('a', "all-cpus", &system_wide,
528 		    "system-wide collection from all CPUs"),
529 	OPT_BOOLEAN('c', "scale", &scale,
530 		    "scale/normalize counters"),
531 	OPT_INCR('v', "verbose", &verbose,
532 		    "be more verbose (show counter open errors, etc)"),
533 	OPT_INTEGER('r', "repeat", &run_count,
534 		    "repeat command and print average + stddev (max: 100)"),
535 	OPT_BOOLEAN('n', "null", &null_run,
536 		    "null run - dont start any counters"),
537 	OPT_END()
538 };
539 
540 int cmd_stat(int argc, const char **argv, const char *prefix __used)
541 {
542 	int status;
543 	int i,j;
544 
545 	argc = parse_options(argc, argv, options, stat_usage,
546 		PARSE_OPT_STOP_AT_NON_OPTION);
547 	if (!argc && target_pid == -1 && target_tid == -1)
548 		usage_with_options(stat_usage, options);
549 	if (run_count <= 0)
550 		usage_with_options(stat_usage, options);
551 
552 	/* Set attrs and nr_counters if no event is selected and !null_run */
553 	if (!null_run && !nr_counters) {
554 		memcpy(attrs, default_attrs, sizeof(default_attrs));
555 		nr_counters = ARRAY_SIZE(default_attrs);
556 	}
557 
558 	if (system_wide)
559 		nr_cpus = read_cpu_map();
560 	else
561 		nr_cpus = 1;
562 
563 	if (target_pid != -1) {
564 		target_tid = target_pid;
565 		thread_num = find_all_tid(target_pid, &all_tids);
566 		if (thread_num <= 0) {
567 			fprintf(stderr, "Can't find all threads of pid %d\n",
568 					target_pid);
569 			usage_with_options(stat_usage, options);
570 		}
571 	} else {
572 		all_tids=malloc(sizeof(pid_t));
573 		if (!all_tids)
574 			return -ENOMEM;
575 
576 		all_tids[0] = target_tid;
577 		thread_num = 1;
578 	}
579 
580 	for (i = 0; i < MAX_NR_CPUS; i++) {
581 		for (j = 0; j < MAX_COUNTERS; j++) {
582 			fd[i][j] = malloc(sizeof(int)*thread_num);
583 			if (!fd[i][j])
584 				return -ENOMEM;
585 		}
586 	}
587 
588 	/*
589 	 * We dont want to block the signals - that would cause
590 	 * child tasks to inherit that and Ctrl-C would not work.
591 	 * What we want is for Ctrl-C to work in the exec()-ed
592 	 * task, but being ignored by perf stat itself:
593 	 */
594 	atexit(sig_atexit);
595 	signal(SIGINT,  skip_signal);
596 	signal(SIGALRM, skip_signal);
597 	signal(SIGABRT, skip_signal);
598 
599 	status = 0;
600 	for (run_idx = 0; run_idx < run_count; run_idx++) {
601 		if (run_count != 1 && verbose)
602 			fprintf(stderr, "[ perf stat: executing run #%d ... ]\n", run_idx + 1);
603 		status = run_perf_stat(argc, argv);
604 	}
605 
606 	if (status != -1)
607 		print_stat(argc, argv);
608 
609 	return status;
610 }
611