perf stat: Enable raw data to be printed
[safe/jmp/linux-2.6] / tools / perf / builtin-stat.c
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  *
36  * Released under the GPL v2. (and only v2, not any later version)
37  */
38
39 #include "perf.h"
40 #include "builtin.h"
41 #include "util/util.h"
42 #include "util/parse-options.h"
43 #include "util/parse-events.h"
44
45 #include <sys/prctl.h>
46 #include <math.h>
47
48 static struct perf_counter_attr default_attrs[MAX_COUNTERS] = {
49
50   { .type = PERF_TYPE_SOFTWARE, .config = PERF_COUNT_SW_TASK_CLOCK      },
51   { .type = PERF_TYPE_SOFTWARE, .config = PERF_COUNT_SW_CONTEXT_SWITCHES},
52   { .type = PERF_TYPE_SOFTWARE, .config = PERF_COUNT_SW_CPU_MIGRATIONS  },
53   { .type = PERF_TYPE_SOFTWARE, .config = PERF_COUNT_SW_PAGE_FAULTS     },
54
55   { .type = PERF_TYPE_HARDWARE, .config = PERF_COUNT_HW_CPU_CYCLES      },
56   { .type = PERF_TYPE_HARDWARE, .config = PERF_COUNT_HW_INSTRUCTIONS    },
57   { .type = PERF_TYPE_HARDWARE, .config = PERF_COUNT_HW_CACHE_REFERENCES},
58   { .type = PERF_TYPE_HARDWARE, .config = PERF_COUNT_HW_CACHE_MISSES    },
59
60 };
61
62 static int                      system_wide                     =  0;
63 static int                      inherit                         =  1;
64 static int                      verbose                         =  0;
65
66 static int                      fd[MAX_NR_CPUS][MAX_COUNTERS];
67
68 static int                      target_pid                      = -1;
69 static int                      nr_cpus                         =  0;
70 static unsigned int             page_size;
71
72 static int                      scale                           =  1;
73
74 static const unsigned int default_count[] = {
75         1000000,
76         1000000,
77           10000,
78           10000,
79         1000000,
80           10000,
81 };
82
83 #define MAX_RUN 100
84
85 static int                      run_count               =  1;
86 static int                      run_idx                 =  0;
87
88 static __u64                    event_res[MAX_RUN][MAX_COUNTERS][3];
89 static __u64                    event_scaled[MAX_RUN][MAX_COUNTERS];
90
91 //static __u64                  event_hist[MAX_RUN][MAX_COUNTERS][3];
92
93
94 static __u64                    runtime_nsecs[MAX_RUN];
95 static __u64                    walltime_nsecs[MAX_RUN];
96 static __u64                    runtime_cycles[MAX_RUN];
97
98 static __u64                    event_res_avg[MAX_COUNTERS][3];
99 static __u64                    event_res_noise[MAX_COUNTERS][3];
100
101 static __u64                    event_scaled_avg[MAX_COUNTERS];
102
103 static __u64                    runtime_nsecs_avg;
104 static __u64                    runtime_nsecs_noise;
105
106 static __u64                    walltime_nsecs_avg;
107 static __u64                    walltime_nsecs_noise;
108
109 static __u64                    runtime_cycles_avg;
110 static __u64                    runtime_cycles_noise;
111
112 static void create_perf_stat_counter(int counter)
113 {
114         struct perf_counter_attr *attr = attrs + counter;
115
116         if (scale)
117                 attr->read_format = PERF_FORMAT_TOTAL_TIME_ENABLED |
118                                     PERF_FORMAT_TOTAL_TIME_RUNNING;
119
120         if (system_wide) {
121                 int cpu;
122                 for (cpu = 0; cpu < nr_cpus; cpu ++) {
123                         fd[cpu][counter] = sys_perf_counter_open(attr, -1, cpu, -1, 0);
124                         if (fd[cpu][counter] < 0 && verbose) {
125                                 printf("Error: counter %d, sys_perf_counter_open() syscall returned with %d (%s)\n", counter, fd[cpu][counter], strerror(errno));
126                         }
127                 }
128         } else {
129                 attr->inherit   = inherit;
130                 attr->disabled  = 1;
131
132                 fd[0][counter] = sys_perf_counter_open(attr, 0, -1, -1, 0);
133                 if (fd[0][counter] < 0 && verbose) {
134                         printf("Error: counter %d, sys_perf_counter_open() syscall returned with %d (%s)\n", counter, fd[0][counter], strerror(errno));
135                 }
136         }
137 }
138
139 /*
140  * Does the counter have nsecs as a unit?
141  */
142 static inline int nsec_counter(int counter)
143 {
144         if (attrs[counter].type != PERF_TYPE_SOFTWARE)
145                 return 0;
146
147         if (attrs[counter].config == PERF_COUNT_SW_CPU_CLOCK)
148                 return 1;
149
150         if (attrs[counter].config == PERF_COUNT_SW_TASK_CLOCK)
151                 return 1;
152
153         return 0;
154 }
155
156 /*
157  * Read out the results of a single counter:
158  */
159 static void read_counter(int counter)
160 {
161         __u64 *count, single_count[3];
162         ssize_t res;
163         int cpu, nv;
164         int scaled;
165
166         count = event_res[run_idx][counter];
167
168         count[0] = count[1] = count[2] = 0;
169
170         nv = scale ? 3 : 1;
171         for (cpu = 0; cpu < nr_cpus; cpu ++) {
172                 if (fd[cpu][counter] < 0)
173                         continue;
174
175                 res = read(fd[cpu][counter], single_count, nv * sizeof(__u64));
176                 assert(res == nv * sizeof(__u64));
177                 close(fd[cpu][counter]);
178                 fd[cpu][counter] = -1;
179
180                 count[0] += single_count[0];
181                 if (scale) {
182                         count[1] += single_count[1];
183                         count[2] += single_count[2];
184                 }
185         }
186
187         scaled = 0;
188         if (scale) {
189                 if (count[2] == 0) {
190                         event_scaled[run_idx][counter] = -1;
191                         count[0] = 0;
192                         return;
193                 }
194
195                 if (count[2] < count[1]) {
196                         event_scaled[run_idx][counter] = 1;
197                         count[0] = (unsigned long long)
198                                 ((double)count[0] * count[1] / count[2] + 0.5);
199                 }
200         }
201         /*
202          * Save the full runtime - to allow normalization during printout:
203          */
204         if (attrs[counter].type == PERF_TYPE_SOFTWARE &&
205                 attrs[counter].config == PERF_COUNT_SW_TASK_CLOCK)
206                 runtime_nsecs[run_idx] = count[0];
207         if (attrs[counter].type == PERF_TYPE_HARDWARE &&
208                 attrs[counter].config == PERF_COUNT_HW_CPU_CYCLES)
209                 runtime_cycles[run_idx] = count[0];
210 }
211
212 static int run_perf_stat(int argc, const char **argv)
213 {
214         unsigned long long t0, t1;
215         int status = 0;
216         int counter;
217         int pid;
218
219         if (!system_wide)
220                 nr_cpus = 1;
221
222         for (counter = 0; counter < nr_counters; counter++)
223                 create_perf_stat_counter(counter);
224
225         /*
226          * Enable counters and exec the command:
227          */
228         t0 = rdclock();
229         prctl(PR_TASK_PERF_COUNTERS_ENABLE);
230
231         if ((pid = fork()) < 0)
232                 perror("failed to fork");
233
234         if (!pid) {
235                 if (execvp(argv[0], (char **)argv)) {
236                         perror(argv[0]);
237                         exit(-1);
238                 }
239         }
240
241         wait(&status);
242
243         prctl(PR_TASK_PERF_COUNTERS_DISABLE);
244         t1 = rdclock();
245
246         walltime_nsecs[run_idx] = t1 - t0;
247
248         for (counter = 0; counter < nr_counters; counter++)
249                 read_counter(counter);
250
251         return WEXITSTATUS(status);
252 }
253
254 static void print_noise(__u64 *count, __u64 *noise)
255 {
256         if (run_count > 1)
257                 fprintf(stderr, "   ( +- %7.3f%% )",
258                         (double)noise[0]/(count[0]+1)*100.0);
259 }
260
261 static void nsec_printout(int counter, __u64 *count, __u64 *noise)
262 {
263         double msecs = (double)count[0] / 1000000;
264
265         fprintf(stderr, " %14.6f  %-20s", msecs, event_name(counter));
266
267         if (attrs[counter].type == PERF_TYPE_SOFTWARE &&
268                 attrs[counter].config == PERF_COUNT_SW_TASK_CLOCK) {
269
270                 if (walltime_nsecs_avg)
271                         fprintf(stderr, " # %10.3f CPUs ",
272                                 (double)count[0] / (double)walltime_nsecs_avg);
273         }
274         print_noise(count, noise);
275 }
276
277 static void abs_printout(int counter, __u64 *count, __u64 *noise)
278 {
279         fprintf(stderr, " %14Ld  %-20s", count[0], event_name(counter));
280
281         if (runtime_cycles_avg &&
282                 attrs[counter].type == PERF_TYPE_HARDWARE &&
283                         attrs[counter].config == PERF_COUNT_HW_INSTRUCTIONS) {
284
285                 fprintf(stderr, " # %10.3f IPC  ",
286                         (double)count[0] / (double)runtime_cycles_avg);
287         } else {
288                 if (runtime_nsecs_avg) {
289                         fprintf(stderr, " # %10.3f M/sec",
290                                 (double)count[0]/runtime_nsecs_avg*1000.0);
291                 }
292         }
293         print_noise(count, noise);
294 }
295
296 /*
297  * Print out the results of a single counter:
298  */
299 static void print_counter(int counter)
300 {
301         __u64 *count, *noise;
302         int scaled;
303
304         count = event_res_avg[counter];
305         noise = event_res_noise[counter];
306         scaled = event_scaled_avg[counter];
307
308         if (scaled == -1) {
309                 fprintf(stderr, " %14s  %-20s\n",
310                         "<not counted>", event_name(counter));
311                 return;
312         }
313
314         if (nsec_counter(counter))
315                 nsec_printout(counter, count, noise);
316         else
317                 abs_printout(counter, count, noise);
318
319         if (scaled)
320                 fprintf(stderr, "  (scaled from %.2f%%)",
321                         (double) count[2] / count[1] * 100);
322
323         fprintf(stderr, "\n");
324 }
325
326 /*
327  * normalize_noise noise values down to stddev:
328  */
329 static void normalize_noise(__u64 *val)
330 {
331         double res;
332
333         res = (double)*val / (run_count * sqrt((double)run_count));
334
335         *val = (__u64)res;
336 }
337
338 static void update_avg(const char *name, int idx, __u64 *avg, __u64 *val)
339 {
340         *avg += *val;
341
342         if (verbose > 1)
343                 fprintf(stderr, "debug: %20s[%d]: %Ld\n", name, idx, *val);
344 }
345 /*
346  * Calculate the averages and noises:
347  */
348 static void calc_avg(void)
349 {
350         int i, j;
351
352         if (verbose > 1)
353                 fprintf(stderr, "\n");
354
355         for (i = 0; i < run_count; i++) {
356                 update_avg("runtime", 0, &runtime_nsecs_avg, runtime_nsecs + i);
357                 update_avg("walltime", 0, &walltime_nsecs_avg, walltime_nsecs + i);
358                 update_avg("runtime_cycles", 0, &runtime_cycles_avg, runtime_cycles + i);
359
360                 for (j = 0; j < nr_counters; j++) {
361                         update_avg("counter/0", j,
362                                 event_res_avg[j]+0, event_res[i][j]+0);
363                         update_avg("counter/1", j,
364                                 event_res_avg[j]+1, event_res[i][j]+1);
365                         update_avg("counter/2", j,
366                                 event_res_avg[j]+2, event_res[i][j]+2);
367                         update_avg("scaled", j,
368                                 event_scaled_avg + j, event_scaled[i]+j);
369                 }
370         }
371         runtime_nsecs_avg /= run_count;
372         walltime_nsecs_avg /= run_count;
373         runtime_cycles_avg /= run_count;
374
375         for (j = 0; j < nr_counters; j++) {
376                 event_res_avg[j][0] /= run_count;
377                 event_res_avg[j][1] /= run_count;
378                 event_res_avg[j][2] /= run_count;
379         }
380
381         for (i = 0; i < run_count; i++) {
382                 runtime_nsecs_noise +=
383                         abs((__s64)(runtime_nsecs[i] - runtime_nsecs_avg));
384                 walltime_nsecs_noise +=
385                         abs((__s64)(walltime_nsecs[i] - walltime_nsecs_avg));
386                 runtime_cycles_noise +=
387                         abs((__s64)(runtime_cycles[i] - runtime_cycles_avg));
388
389                 for (j = 0; j < nr_counters; j++) {
390                         event_res_noise[j][0] +=
391                                 abs((__s64)(event_res[i][j][0] - event_res_avg[j][0]));
392                         event_res_noise[j][1] +=
393                                 abs((__s64)(event_res[i][j][1] - event_res_avg[j][1]));
394                         event_res_noise[j][2] +=
395                                 abs((__s64)(event_res[i][j][2] - event_res_avg[j][2]));
396                 }
397         }
398
399         normalize_noise(&runtime_nsecs_noise);
400         normalize_noise(&walltime_nsecs_noise);
401         normalize_noise(&runtime_cycles_noise);
402
403         for (j = 0; j < nr_counters; j++) {
404                 normalize_noise(&event_res_noise[j][0]);
405                 normalize_noise(&event_res_noise[j][1]);
406                 normalize_noise(&event_res_noise[j][2]);
407         }
408 }
409
410 static void print_stat(int argc, const char **argv)
411 {
412         int i, counter;
413
414         calc_avg();
415
416         fflush(stdout);
417
418         fprintf(stderr, "\n");
419         fprintf(stderr, " Performance counter stats for \'%s", argv[0]);
420
421         for (i = 1; i < argc; i++)
422                 fprintf(stderr, " %s", argv[i]);
423
424         fprintf(stderr, "\'");
425         if (run_count > 1)
426                 fprintf(stderr, " (%d runs)", run_count);
427         fprintf(stderr, ":\n\n");
428
429         for (counter = 0; counter < nr_counters; counter++)
430                 print_counter(counter);
431
432
433         fprintf(stderr, "\n");
434         fprintf(stderr, " %14.9f  seconds time elapsed.\n",
435                         (double)walltime_nsecs_avg/1e9);
436         fprintf(stderr, "\n");
437 }
438
439 static volatile int signr = -1;
440
441 static void skip_signal(int signo)
442 {
443         signr = signo;
444 }
445
446 static void sig_atexit(void)
447 {
448         if (signr == -1)
449                 return;
450
451         signal(signr, SIG_DFL);
452         kill(getpid(), signr);
453 }
454
455 static const char * const stat_usage[] = {
456         "perf stat [<options>] <command>",
457         NULL
458 };
459
460 static const struct option options[] = {
461         OPT_CALLBACK('e', "event", NULL, "event",
462                      "event selector. use 'perf list' to list available events",
463                      parse_events),
464         OPT_BOOLEAN('i', "inherit", &inherit,
465                     "child tasks inherit counters"),
466         OPT_INTEGER('p', "pid", &target_pid,
467                     "stat events on existing pid"),
468         OPT_BOOLEAN('a', "all-cpus", &system_wide,
469                             "system-wide collection from all CPUs"),
470         OPT_BOOLEAN('S', "scale", &scale,
471                             "scale/normalize counters"),
472         OPT_BOOLEAN('v', "verbose", &verbose,
473                     "be more verbose (show counter open errors, etc)"),
474         OPT_INTEGER('r', "repeat", &run_count,
475                     "repeat command and print average + stddev (max: 100)"),
476         OPT_END()
477 };
478
479 int cmd_stat(int argc, const char **argv, const char *prefix)
480 {
481         int status;
482
483         page_size = sysconf(_SC_PAGE_SIZE);
484
485         memcpy(attrs, default_attrs, sizeof(attrs));
486
487         argc = parse_options(argc, argv, options, stat_usage, 0);
488         if (!argc)
489                 usage_with_options(stat_usage, options);
490         if (run_count <= 0 || run_count > MAX_RUN)
491                 usage_with_options(stat_usage, options);
492
493         if (!nr_counters)
494                 nr_counters = 8;
495
496         nr_cpus = sysconf(_SC_NPROCESSORS_ONLN);
497         assert(nr_cpus <= MAX_NR_CPUS);
498         assert(nr_cpus >= 0);
499
500         /*
501          * We dont want to block the signals - that would cause
502          * child tasks to inherit that and Ctrl-C would not work.
503          * What we want is for Ctrl-C to work in the exec()-ed
504          * task, but being ignored by perf stat itself:
505          */
506         atexit(sig_atexit);
507         signal(SIGINT,  skip_signal);
508         signal(SIGALRM, skip_signal);
509         signal(SIGABRT, skip_signal);
510
511         status = 0;
512         for (run_idx = 0; run_idx < run_count; run_idx++) {
513                 if (run_count != 1 && verbose)
514                         fprintf(stderr, "[ perf stat: executing run #%d ... ]\n", run_idx+1);
515                 status = run_perf_stat(argc, argv);
516         }
517
518         print_stat(argc, argv);
519
520         return status;
521 }