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  *   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 }