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