diff options
Diffstat (limited to 'tools/perf/builtin-stat.c')
| -rw-r--r-- | tools/perf/builtin-stat.c | 1735 |
1 files changed, 1409 insertions, 326 deletions
diff --git a/tools/perf/builtin-stat.c b/tools/perf/builtin-stat.c index a482a191a0c..65a151e3606 100644 --- a/tools/perf/builtin-stat.c +++ b/tools/perf/builtin-stat.c @@ -6,24 +6,28 @@ * * Sample output: - $ perf stat ~/hackbench 10 - Time: 0.104 + $ perf stat ./hackbench 10 - Performance counter stats for '/home/mingo/hackbench': + Time: 0.118 - 1255.538611 task clock ticks # 10.143 CPU utilization factor - 54011 context switches # 0.043 M/sec - 385 CPU migrations # 0.000 M/sec - 17755 pagefaults # 0.014 M/sec - 3808323185 CPU cycles # 3033.219 M/sec - 1575111190 instructions # 1254.530 M/sec - 17367895 cache references # 13.833 M/sec - 7674421 cache misses # 6.112 M/sec + Performance counter stats for './hackbench 10': - Wall-clock time elapsed: 123.786620 msecs + 1708.761321 task-clock # 11.037 CPUs utilized + 41,190 context-switches # 0.024 M/sec + 6,735 CPU-migrations # 0.004 M/sec + 17,318 page-faults # 0.010 M/sec + 5,205,202,243 cycles # 3.046 GHz + 3,856,436,920 stalled-cycles-frontend # 74.09% frontend cycles idle + 1,600,790,871 stalled-cycles-backend # 30.75% backend cycles idle + 2,603,501,247 instructions # 0.50 insns per cycle + # 1.48 stalled cycles per insn + 484,357,498 branches # 283.455 M/sec + 6,388,934 branch-misses # 1.32% of all branches + + 0.154822978 seconds time elapsed * - * Copyright (C) 2008, Red Hat Inc, Ingo Molnar <mingo@redhat.com> + * Copyright (C) 2008-2011, Red Hat Inc, Ingo Molnar <mingo@redhat.com> * * Improvements and fixes by: * @@ -42,120 +46,249 @@ #include "util/util.h" #include "util/parse-options.h" #include "util/parse-events.h" +#include "util/pmu.h" #include "util/event.h" +#include "util/evlist.h" #include "util/evsel.h" #include "util/debug.h" +#include "util/color.h" +#include "util/stat.h" #include "util/header.h" #include "util/cpumap.h" #include "util/thread.h" +#include "util/thread_map.h" +#include <stdlib.h> #include <sys/prctl.h> -#include <math.h> #include <locale.h> #define DEFAULT_SEPARATOR " " +#define CNTR_NOT_SUPPORTED "<not supported>" +#define CNTR_NOT_COUNTED "<not counted>" + +static void print_stat(int argc, const char **argv); +static void print_counter_aggr(struct perf_evsel *counter, char *prefix); +static void print_counter(struct perf_evsel *counter, char *prefix); +static void print_aggr(char *prefix); + +/* Default events used for perf stat -T */ +static const char * const transaction_attrs[] = { + "task-clock", + "{" + "instructions," + "cycles," + "cpu/cycles-t/," + "cpu/tx-start/," + "cpu/el-start/," + "cpu/cycles-ct/" + "}" +}; -static struct perf_event_attr default_attrs[] = { +/* More limited version when the CPU does not have all events. */ +static const char * const transaction_limited_attrs[] = { + "task-clock", + "{" + "instructions," + "cycles," + "cpu/cycles-t/," + "cpu/tx-start/" + "}" +}; - { .type = PERF_TYPE_SOFTWARE, .config = PERF_COUNT_SW_TASK_CLOCK }, - { .type = PERF_TYPE_SOFTWARE, .config = PERF_COUNT_SW_CONTEXT_SWITCHES }, - { .type = PERF_TYPE_SOFTWARE, .config = PERF_COUNT_SW_CPU_MIGRATIONS }, - { .type = PERF_TYPE_SOFTWARE, .config = PERF_COUNT_SW_PAGE_FAULTS }, +/* must match transaction_attrs and the beginning limited_attrs */ +enum { + T_TASK_CLOCK, + T_INSTRUCTIONS, + T_CYCLES, + T_CYCLES_IN_TX, + T_TRANSACTION_START, + T_ELISION_START, + T_CYCLES_IN_TX_CP, +}; - { .type = PERF_TYPE_HARDWARE, .config = PERF_COUNT_HW_CPU_CYCLES }, - { .type = PERF_TYPE_HARDWARE, .config = PERF_COUNT_HW_INSTRUCTIONS }, - { .type = PERF_TYPE_HARDWARE, .config = PERF_COUNT_HW_BRANCH_INSTRUCTIONS }, - { .type = PERF_TYPE_HARDWARE, .config = PERF_COUNT_HW_BRANCH_MISSES }, - { .type = PERF_TYPE_HARDWARE, .config = PERF_COUNT_HW_CACHE_REFERENCES }, - { .type = PERF_TYPE_HARDWARE, .config = PERF_COUNT_HW_CACHE_MISSES }, +static struct perf_evlist *evsel_list; +static struct target target = { + .uid = UINT_MAX, }; -static bool system_wide = false; -static struct cpu_map *cpus; -static int run_idx = 0; +enum aggr_mode { + AGGR_NONE, + AGGR_GLOBAL, + AGGR_SOCKET, + AGGR_CORE, +}; static int run_count = 1; static bool no_inherit = false; static bool scale = true; -static bool no_aggr = false; -static pid_t target_pid = -1; -static pid_t target_tid = -1; -static struct thread_map *threads; -static pid_t child_pid = -1; +static enum aggr_mode aggr_mode = AGGR_GLOBAL; +static volatile pid_t child_pid = -1; static bool null_run = false; +static int detailed_run = 0; +static bool transaction_run; static bool big_num = true; static int big_num_opt = -1; -static const char *cpu_list; static const char *csv_sep = NULL; static bool csv_output = false; +static bool group = false; +static FILE *output = NULL; +static const char *pre_cmd = NULL; +static const char *post_cmd = NULL; +static bool sync_run = false; +static unsigned int interval = 0; +static unsigned int initial_delay = 0; +static unsigned int unit_width = 4; /* strlen("unit") */ +static bool forever = false; +static struct timespec ref_time; +static struct cpu_map *aggr_map; +static int (*aggr_get_id)(struct cpu_map *m, int cpu); static volatile int done = 0; -struct stats -{ - double n, mean, M2; -}; - struct perf_stat { struct stats res_stats[3]; }; +static inline void diff_timespec(struct timespec *r, struct timespec *a, + struct timespec *b) +{ + r->tv_sec = a->tv_sec - b->tv_sec; + if (a->tv_nsec < b->tv_nsec) { + r->tv_nsec = a->tv_nsec + 1000000000L - b->tv_nsec; + r->tv_sec--; + } else { + r->tv_nsec = a->tv_nsec - b->tv_nsec ; + } +} + +static inline struct cpu_map *perf_evsel__cpus(struct perf_evsel *evsel) +{ + return (evsel->cpus && !target.cpu_list) ? evsel->cpus : evsel_list->cpus; +} + +static inline int perf_evsel__nr_cpus(struct perf_evsel *evsel) +{ + return perf_evsel__cpus(evsel)->nr; +} + +static void perf_evsel__reset_stat_priv(struct perf_evsel *evsel) +{ + int i; + struct perf_stat *ps = evsel->priv; + + for (i = 0; i < 3; i++) + init_stats(&ps->res_stats[i]); +} + static int perf_evsel__alloc_stat_priv(struct perf_evsel *evsel) { evsel->priv = zalloc(sizeof(struct perf_stat)); - return evsel->priv == NULL ? -ENOMEM : 0; + if (evsel == NULL) + return -ENOMEM; + perf_evsel__reset_stat_priv(evsel); + return 0; } static void perf_evsel__free_stat_priv(struct perf_evsel *evsel) { - free(evsel->priv); - evsel->priv = NULL; + zfree(&evsel->priv); } -static void update_stats(struct stats *stats, u64 val) +static int perf_evsel__alloc_prev_raw_counts(struct perf_evsel *evsel) { - double delta; + void *addr; + size_t sz; + + sz = sizeof(*evsel->counts) + + (perf_evsel__nr_cpus(evsel) * sizeof(struct perf_counts_values)); + + addr = zalloc(sz); + if (!addr) + return -ENOMEM; - stats->n++; - delta = val - stats->mean; - stats->mean += delta / stats->n; - stats->M2 += delta*(val - stats->mean); + evsel->prev_raw_counts = addr; + + return 0; } -static double avg_stats(struct stats *stats) +static void perf_evsel__free_prev_raw_counts(struct perf_evsel *evsel) { - return stats->mean; + zfree(&evsel->prev_raw_counts); } -/* - * http://en.wikipedia.org/wiki/Algorithms_for_calculating_variance - * - * (\Sum n_i^2) - ((\Sum n_i)^2)/n - * s^2 = ------------------------------- - * n - 1 - * - * http://en.wikipedia.org/wiki/Stddev - * - * The std dev of the mean is related to the std dev by: - * - * s - * s_mean = ------- - * sqrt(n) - * - */ -static double stddev_stats(struct stats *stats) +static void perf_evlist__free_stats(struct perf_evlist *evlist) { - double variance = stats->M2 / (stats->n - 1); - double variance_mean = variance / stats->n; + struct perf_evsel *evsel; + + evlist__for_each(evlist, evsel) { + perf_evsel__free_stat_priv(evsel); + perf_evsel__free_counts(evsel); + perf_evsel__free_prev_raw_counts(evsel); + } +} + +static int perf_evlist__alloc_stats(struct perf_evlist *evlist, bool alloc_raw) +{ + struct perf_evsel *evsel; + + evlist__for_each(evlist, evsel) { + if (perf_evsel__alloc_stat_priv(evsel) < 0 || + perf_evsel__alloc_counts(evsel, perf_evsel__nr_cpus(evsel)) < 0 || + (alloc_raw && perf_evsel__alloc_prev_raw_counts(evsel) < 0)) + goto out_free; + } - return sqrt(variance_mean); + return 0; + +out_free: + perf_evlist__free_stats(evlist); + return -1; } -struct stats runtime_nsecs_stats[MAX_NR_CPUS]; -struct stats runtime_cycles_stats[MAX_NR_CPUS]; -struct stats runtime_branches_stats[MAX_NR_CPUS]; -struct stats walltime_nsecs_stats; +static struct stats runtime_nsecs_stats[MAX_NR_CPUS]; +static struct stats runtime_cycles_stats[MAX_NR_CPUS]; +static struct stats runtime_stalled_cycles_front_stats[MAX_NR_CPUS]; +static struct stats runtime_stalled_cycles_back_stats[MAX_NR_CPUS]; +static struct stats runtime_branches_stats[MAX_NR_CPUS]; +static struct stats runtime_cacherefs_stats[MAX_NR_CPUS]; +static struct stats runtime_l1_dcache_stats[MAX_NR_CPUS]; +static struct stats runtime_l1_icache_stats[MAX_NR_CPUS]; +static struct stats runtime_ll_cache_stats[MAX_NR_CPUS]; +static struct stats runtime_itlb_cache_stats[MAX_NR_CPUS]; +static struct stats runtime_dtlb_cache_stats[MAX_NR_CPUS]; +static struct stats runtime_cycles_in_tx_stats[MAX_NR_CPUS]; +static struct stats walltime_nsecs_stats; +static struct stats runtime_transaction_stats[MAX_NR_CPUS]; +static struct stats runtime_elision_stats[MAX_NR_CPUS]; + +static void perf_stat__reset_stats(struct perf_evlist *evlist) +{ + struct perf_evsel *evsel; + + evlist__for_each(evlist, evsel) { + perf_evsel__reset_stat_priv(evsel); + perf_evsel__reset_counts(evsel, perf_evsel__nr_cpus(evsel)); + } + + memset(runtime_nsecs_stats, 0, sizeof(runtime_nsecs_stats)); + memset(runtime_cycles_stats, 0, sizeof(runtime_cycles_stats)); + memset(runtime_stalled_cycles_front_stats, 0, sizeof(runtime_stalled_cycles_front_stats)); + memset(runtime_stalled_cycles_back_stats, 0, sizeof(runtime_stalled_cycles_back_stats)); + memset(runtime_branches_stats, 0, sizeof(runtime_branches_stats)); + memset(runtime_cacherefs_stats, 0, sizeof(runtime_cacherefs_stats)); + memset(runtime_l1_dcache_stats, 0, sizeof(runtime_l1_dcache_stats)); + memset(runtime_l1_icache_stats, 0, sizeof(runtime_l1_icache_stats)); + memset(runtime_ll_cache_stats, 0, sizeof(runtime_ll_cache_stats)); + memset(runtime_itlb_cache_stats, 0, sizeof(runtime_itlb_cache_stats)); + memset(runtime_dtlb_cache_stats, 0, sizeof(runtime_dtlb_cache_stats)); + memset(runtime_cycles_in_tx_stats, 0, + sizeof(runtime_cycles_in_tx_stats)); + memset(runtime_transaction_stats, 0, + sizeof(runtime_transaction_stats)); + memset(runtime_elision_stats, 0, sizeof(runtime_elision_stats)); + memset(&walltime_nsecs_stats, 0, sizeof(walltime_nsecs_stats)); +} static int create_perf_stat_counter(struct perf_evsel *evsel) { @@ -165,16 +298,18 @@ static int create_perf_stat_counter(struct perf_evsel *evsel) attr->read_format = PERF_FORMAT_TOTAL_TIME_ENABLED | PERF_FORMAT_TOTAL_TIME_RUNNING; - if (system_wide) - return perf_evsel__open_per_cpu(evsel, cpus); - attr->inherit = !no_inherit; - if (target_pid == -1 && target_tid == -1) { + + if (target__has_cpu(&target)) + return perf_evsel__open_per_cpu(evsel, perf_evsel__cpus(evsel)); + + if (!target__has_task(&target) && perf_evsel__is_group_leader(evsel)) { attr->disabled = 1; - attr->enable_on_exec = 1; + if (!initial_delay) + attr->enable_on_exec = 1; } - return perf_evsel__open_per_thread(evsel, threads); + return perf_evsel__open_per_thread(evsel, evsel_list->threads); } /* @@ -189,6 +324,69 @@ static inline int nsec_counter(struct perf_evsel *evsel) return 0; } +static struct perf_evsel *nth_evsel(int n) +{ + static struct perf_evsel **array; + static int array_len; + struct perf_evsel *ev; + int j; + + /* Assumes this only called when evsel_list does not change anymore. */ + if (!array) { + evlist__for_each(evsel_list, ev) + array_len++; + array = malloc(array_len * sizeof(void *)); + if (!array) + exit(ENOMEM); + j = 0; + evlist__for_each(evsel_list, ev) + array[j++] = ev; + } + if (n < array_len) + return array[n]; + return NULL; +} + +/* + * Update various tracking values we maintain to print + * more semantic information such as miss/hit ratios, + * instruction rates, etc: + */ +static void update_shadow_stats(struct perf_evsel *counter, u64 *count) +{ + if (perf_evsel__match(counter, SOFTWARE, SW_TASK_CLOCK)) + update_stats(&runtime_nsecs_stats[0], count[0]); + else if (perf_evsel__match(counter, HARDWARE, HW_CPU_CYCLES)) + update_stats(&runtime_cycles_stats[0], count[0]); + else if (transaction_run && + perf_evsel__cmp(counter, nth_evsel(T_CYCLES_IN_TX))) + update_stats(&runtime_cycles_in_tx_stats[0], count[0]); + else if (transaction_run && + perf_evsel__cmp(counter, nth_evsel(T_TRANSACTION_START))) + update_stats(&runtime_transaction_stats[0], count[0]); + else if (transaction_run && + perf_evsel__cmp(counter, nth_evsel(T_ELISION_START))) + update_stats(&runtime_elision_stats[0], count[0]); + else if (perf_evsel__match(counter, HARDWARE, HW_STALLED_CYCLES_FRONTEND)) + update_stats(&runtime_stalled_cycles_front_stats[0], count[0]); + else if (perf_evsel__match(counter, HARDWARE, HW_STALLED_CYCLES_BACKEND)) + update_stats(&runtime_stalled_cycles_back_stats[0], count[0]); + else if (perf_evsel__match(counter, HARDWARE, HW_BRANCH_INSTRUCTIONS)) + update_stats(&runtime_branches_stats[0], count[0]); + else if (perf_evsel__match(counter, HARDWARE, HW_CACHE_REFERENCES)) + update_stats(&runtime_cacherefs_stats[0], count[0]); + else if (perf_evsel__match(counter, HW_CACHE, HW_CACHE_L1D)) + update_stats(&runtime_l1_dcache_stats[0], count[0]); + else if (perf_evsel__match(counter, HW_CACHE, HW_CACHE_L1I)) + update_stats(&runtime_l1_icache_stats[0], count[0]); + else if (perf_evsel__match(counter, HW_CACHE, HW_CACHE_LL)) + update_stats(&runtime_ll_cache_stats[0], count[0]); + else if (perf_evsel__match(counter, HW_CACHE, HW_CACHE_DTLB)) + update_stats(&runtime_dtlb_cache_stats[0], count[0]); + else if (perf_evsel__match(counter, HW_CACHE, HW_CACHE_ITLB)) + update_stats(&runtime_itlb_cache_stats[0], count[0]); +} + /* * Read out the results of a single counter: * aggregate counts across CPUs in system-wide mode @@ -199,26 +397,22 @@ static int read_counter_aggr(struct perf_evsel *counter) u64 *count = counter->counts->aggr.values; int i; - if (__perf_evsel__read(counter, cpus->nr, threads->nr, scale) < 0) + if (__perf_evsel__read(counter, perf_evsel__nr_cpus(counter), + thread_map__nr(evsel_list->threads), scale) < 0) return -1; for (i = 0; i < 3; i++) update_stats(&ps->res_stats[i], count[i]); if (verbose) { - fprintf(stderr, "%s: %" PRIu64 " %" PRIu64 " %" PRIu64 "\n", - event_name(counter), count[0], count[1], count[2]); + fprintf(output, "%s: %" PRIu64 " %" PRIu64 " %" PRIu64 "\n", + perf_evsel__name(counter), count[0], count[1], count[2]); } /* * Save the full runtime - to allow normalization during printout: */ - if (perf_evsel__match(counter, SOFTWARE, SW_TASK_CLOCK)) - update_stats(&runtime_nsecs_stats[0], count[0]); - if (perf_evsel__match(counter, HARDWARE, HW_CPU_CYCLES)) - update_stats(&runtime_cycles_stats[0], count[0]); - if (perf_evsel__match(counter, HARDWARE, HW_BRANCH_INSTRUCTIONS)) - update_stats(&runtime_branches_stats[0], count[0]); + update_shadow_stats(counter, count); return 0; } @@ -232,135 +426,268 @@ static int read_counter(struct perf_evsel *counter) u64 *count; int cpu; - for (cpu = 0; cpu < cpus->nr; cpu++) { + for (cpu = 0; cpu < perf_evsel__nr_cpus(counter); cpu++) { if (__perf_evsel__read_on_cpu(counter, cpu, 0, scale) < 0) return -1; count = counter->counts->cpu[cpu].values; - if (perf_evsel__match(counter, SOFTWARE, SW_TASK_CLOCK)) - update_stats(&runtime_nsecs_stats[cpu], count[0]); - if (perf_evsel__match(counter, HARDWARE, HW_CPU_CYCLES)) - update_stats(&runtime_cycles_stats[cpu], count[0]); - if (perf_evsel__match(counter, HARDWARE, HW_BRANCH_INSTRUCTIONS)) - update_stats(&runtime_branches_stats[cpu], count[0]); + update_shadow_stats(counter, count); } return 0; } -static int run_perf_stat(int argc __used, const char **argv) +static void print_interval(void) { - unsigned long long t0, t1; + static int num_print_interval; struct perf_evsel *counter; - int status = 0; - int child_ready_pipe[2], go_pipe[2]; - const bool forks = (argc > 0); - char buf; + struct perf_stat *ps; + struct timespec ts, rs; + char prefix[64]; - if (forks && (pipe(child_ready_pipe) < 0 || pipe(go_pipe) < 0)) { - perror("failed to create pipes"); - exit(1); + if (aggr_mode == AGGR_GLOBAL) { + evlist__for_each(evsel_list, counter) { + ps = counter->priv; + memset(ps->res_stats, 0, sizeof(ps->res_stats)); + read_counter_aggr(counter); + } + } else { + evlist__for_each(evsel_list, counter) { + ps = counter->priv; + memset(ps->res_stats, 0, sizeof(ps->res_stats)); + read_counter(counter); + } } - if (forks) { - if ((child_pid = fork()) < 0) - perror("failed to fork"); + clock_gettime(CLOCK_MONOTONIC, &ts); + diff_timespec(&rs, &ts, &ref_time); + sprintf(prefix, "%6lu.%09lu%s", rs.tv_sec, rs.tv_nsec, csv_sep); + + if (num_print_interval == 0 && !csv_output) { + switch (aggr_mode) { + case AGGR_SOCKET: + fprintf(output, "# time socket cpus counts %*s events\n", unit_width, "unit"); + break; + case AGGR_CORE: + fprintf(output, "# time core cpus counts %*s events\n", unit_width, "unit"); + break; + case AGGR_NONE: + fprintf(output, "# time CPU counts %*s events\n", unit_width, "unit"); + break; + case AGGR_GLOBAL: + default: + fprintf(output, "# time counts %*s events\n", unit_width, "unit"); + } + } + + if (++num_print_interval == 25) + num_print_interval = 0; + + switch (aggr_mode) { + case AGGR_CORE: + case AGGR_SOCKET: + print_aggr(prefix); + break; + case AGGR_NONE: + evlist__for_each(evsel_list, counter) + print_counter(counter, prefix); + break; + case AGGR_GLOBAL: + default: + evlist__for_each(evsel_list, counter) + print_counter_aggr(counter, prefix); + } - if (!child_pid) { - close(child_ready_pipe[0]); - close(go_pipe[1]); - fcntl(go_pipe[0], F_SETFD, FD_CLOEXEC); + fflush(output); +} - /* - * Do a dummy execvp to get the PLT entry resolved, - * so we avoid the resolver overhead on the real - * execvp call. - */ - execvp("", (char **)argv); +static void handle_initial_delay(void) +{ + struct perf_evsel *counter; - /* - * Tell the parent we're ready to go - */ - close(child_ready_pipe[1]); + if (initial_delay) { + const int ncpus = cpu_map__nr(evsel_list->cpus), + nthreads = thread_map__nr(evsel_list->threads); - /* - * Wait until the parent tells us to go. - */ - if (read(go_pipe[0], &buf, 1) == -1) - perror("unable to read pipe"); + usleep(initial_delay * 1000); + evlist__for_each(evsel_list, counter) + perf_evsel__enable(counter, ncpus, nthreads); + } +} - execvp(argv[0], (char **)argv); +static volatile int workload_exec_errno; - perror(argv[0]); - exit(-1); - } +/* + * perf_evlist__prepare_workload will send a SIGUSR1 + * if the fork fails, since we asked by setting its + * want_signal to true. + */ +static void workload_exec_failed_signal(int signo __maybe_unused, siginfo_t *info, + void *ucontext __maybe_unused) +{ + workload_exec_errno = info->si_value.sival_int; +} - if (target_tid == -1 && target_pid == -1 && !system_wide) - threads->map[0] = child_pid; +static int __run_perf_stat(int argc, const char **argv) +{ + char msg[512]; + unsigned long long t0, t1; + struct perf_evsel *counter; + struct timespec ts; + size_t l; + int status = 0; + const bool forks = (argc > 0); + + if (interval) { + ts.tv_sec = interval / 1000; + ts.tv_nsec = (interval % 1000) * 1000000; + } else { + ts.tv_sec = 1; + ts.tv_nsec = 0; + } - /* - * Wait for the child to be ready to exec. - */ - close(child_ready_pipe[1]); - close(go_pipe[0]); - if (read(child_ready_pipe[0], &buf, 1) == -1) - perror("unable to read pipe"); - close(child_ready_pipe[0]); + if (forks) { + if (perf_evlist__prepare_workload(evsel_list, &target, argv, false, + workload_exec_failed_signal) < 0) { + perror("failed to prepare workload"); + return -1; + } + child_pid = evsel_list->workload.pid; } - list_for_each_entry(counter, &evsel_list, node) { + if (group) + perf_evlist__set_leader(evsel_list); + + evlist__for_each(evsel_list, counter) { if (create_perf_stat_counter(counter) < 0) { - if (errno == -EPERM || errno == -EACCES) { - error("You may not have permission to collect %sstats.\n" - "\t Consider tweaking" - " /proc/sys/kernel/perf_event_paranoid or running as root.", - system_wide ? "system-wide " : ""); - } else if (errno == ENOENT) { - error("%s event is not supported. ", event_name(counter)); - } else { - error("open_counter returned with %d (%s). " - "/bin/dmesg may provide additional information.\n", - errno, strerror(errno)); + /* + * PPC returns ENXIO for HW counters until 2.6.37 + * (behavior changed with commit b0a873e). + */ + if (errno == EINVAL || errno == ENOSYS || + errno == ENOENT || errno == EOPNOTSUPP || + errno == ENXIO) { + if (verbose) + ui__warning("%s event is not supported by the kernel.\n", + perf_evsel__name(counter)); + counter->supported = false; + continue; } + + perf_evsel__open_strerror(counter, &target, + errno, msg, sizeof(msg)); + ui__error("%s\n", msg); + if (child_pid != -1) kill(child_pid, SIGTERM); - die("Not all events could be opened.\n"); + return -1; } + counter->supported = true; + + l = strlen(counter->unit); + if (l > unit_width) + unit_width = l; + } + + if (perf_evlist__apply_filters(evsel_list)) { + error("failed to set filter with %d (%s)\n", errno, + strerror(errno)); + return -1; } /* * Enable counters and exec the command: */ t0 = rdclock(); + clock_gettime(CLOCK_MONOTONIC, &ref_time); if (forks) { - close(go_pipe[1]); + perf_evlist__start_workload(evsel_list); + handle_initial_delay(); + + if (interval) { + while (!waitpid(child_pid, &status, WNOHANG)) { + nanosleep(&ts, NULL); + print_interval(); + } + } wait(&status); + + if (workload_exec_errno) { + const char *emsg = strerror_r(workload_exec_errno, msg, sizeof(msg)); + pr_err("Workload failed: %s\n", emsg); + return -1; + } + + if (WIFSIGNALED(status)) + psignal(WTERMSIG(status), argv[0]); } else { - while(!done) sleep(1); + handle_initial_delay(); + while (!done) { + nanosleep(&ts, NULL); + if (interval) + print_interval(); + } } t1 = rdclock(); update_stats(&walltime_nsecs_stats, t1 - t0); - if (no_aggr) { - list_for_each_entry(counter, &evsel_list, node) { - read_counter(counter); - perf_evsel__close_fd(counter, cpus->nr, 1); + if (aggr_mode == AGGR_GLOBAL) { + evlist__for_each(evsel_list, counter) { + read_counter_aggr(counter); + perf_evsel__close_fd(counter, perf_evsel__nr_cpus(counter), + thread_map__nr(evsel_list->threads)); } } else { - list_for_each_entry(counter, &evsel_list, node) { - read_counter_aggr(counter); - perf_evsel__close_fd(counter, cpus->nr, threads->nr); + evlist__for_each(evsel_list, counter) { + read_counter(counter); + perf_evsel__close_fd(counter, perf_evsel__nr_cpus(counter), 1); } } return WEXITSTATUS(status); } +static int run_perf_stat(int argc, const char **argv) +{ + int ret; + + if (pre_cmd) { + ret = system(pre_cmd); + if (ret) + return ret; + } + + if (sync_run) + sync(); + + ret = __run_perf_stat(argc, argv); + if (ret) + return ret; + + if (post_cmd) { + ret = system(post_cmd); + if (ret) + return ret; + } + + return ret; +} + +static void print_noise_pct(double total, double avg) +{ + double pct = rel_stddev_stats(total, avg); + + if (csv_output) + fprintf(output, "%s%.2f%%", csv_sep, pct); + else if (pct) + fprintf(output, " ( +-%6.2f%% )", pct); +} + static void print_noise(struct perf_evsel *evsel, double avg) { struct perf_stat *ps; @@ -369,79 +696,489 @@ static void print_noise(struct perf_evsel *evsel, double avg) return; ps = evsel->priv; - fprintf(stderr, " ( +- %7.3f%% )", - 100 * stddev_stats(&ps->res_stats[0]) / avg); + print_noise_pct(stddev_stats(&ps->res_stats[0]), avg); } -static void nsec_printout(int cpu, struct perf_evsel *evsel, double avg) +static void aggr_printout(struct perf_evsel *evsel, int id, int nr) +{ + switch (aggr_mode) { + case AGGR_CORE: + fprintf(output, "S%d-C%*d%s%*d%s", + cpu_map__id_to_socket(id), + csv_output ? 0 : -8, + cpu_map__id_to_cpu(id), + csv_sep, + csv_output ? 0 : 4, + nr, + csv_sep); + break; + case AGGR_SOCKET: + fprintf(output, "S%*d%s%*d%s", + csv_output ? 0 : -5, + id, + csv_sep, + csv_output ? 0 : 4, + nr, + csv_sep); + break; + case AGGR_NONE: + fprintf(output, "CPU%*d%s", + csv_output ? 0 : -4, + perf_evsel__cpus(evsel)->map[id], csv_sep); + break; + case AGGR_GLOBAL: + default: + break; + } +} + +static void nsec_printout(int cpu, int nr, struct perf_evsel *evsel, double avg) { double msecs = avg / 1e6; - char cpustr[16] = { '\0', }; - const char *fmt = csv_output ? "%s%.6f%s%s" : "%s%18.6f%s%-24s"; + const char *fmt_v, *fmt_n; + char name[25]; - if (no_aggr) - sprintf(cpustr, "CPU%*d%s", - csv_output ? 0 : -4, - cpus->map[cpu], csv_sep); + fmt_v = csv_output ? "%.6f%s" : "%18.6f%s"; + fmt_n = csv_output ? "%s" : "%-25s"; + + aggr_printout(evsel, cpu, nr); - fprintf(stderr, fmt, cpustr, msecs, csv_sep, event_name(evsel)); + scnprintf(name, sizeof(name), "%s%s", + perf_evsel__name(evsel), csv_output ? "" : " (msec)"); + + fprintf(output, fmt_v, msecs, csv_sep); if (csv_output) + fprintf(output, "%s%s", evsel->unit, csv_sep); + else + fprintf(output, "%-*s%s", unit_width, evsel->unit, csv_sep); + + fprintf(output, fmt_n, name); + + if (evsel->cgrp) + fprintf(output, "%s%s", csv_sep, evsel->cgrp->name); + + if (csv_output || interval) return; if (perf_evsel__match(evsel, SOFTWARE, SW_TASK_CLOCK)) - fprintf(stderr, " # %10.3f CPUs ", - avg / avg_stats(&walltime_nsecs_stats)); + fprintf(output, " # %8.3f CPUs utilized ", + avg / avg_stats(&walltime_nsecs_stats)); + else + fprintf(output, " "); +} + +/* used for get_ratio_color() */ +enum grc_type { + GRC_STALLED_CYCLES_FE, + GRC_STALLED_CYCLES_BE, + GRC_CACHE_MISSES, + GRC_MAX_NR +}; + +static const char *get_ratio_color(enum grc_type type, double ratio) +{ + static const double grc_table[GRC_MAX_NR][3] = { + [GRC_STALLED_CYCLES_FE] = { 50.0, 30.0, 10.0 }, + [GRC_STALLED_CYCLES_BE] = { 75.0, 50.0, 20.0 }, + [GRC_CACHE_MISSES] = { 20.0, 10.0, 5.0 }, + }; + const char *color = PERF_COLOR_NORMAL; + + if (ratio > grc_table[type][0]) + color = PERF_COLOR_RED; + else if (ratio > grc_table[type][1]) + color = PERF_COLOR_MAGENTA; + else if (ratio > grc_table[type][2]) + color = PERF_COLOR_YELLOW; + + return color; +} + +static void print_stalled_cycles_frontend(int cpu, + struct perf_evsel *evsel + __maybe_unused, double avg) +{ + double total, ratio = 0.0; + const char *color; + + total = avg_stats(&runtime_cycles_stats[cpu]); + + if (total) + ratio = avg / total * 100.0; + + color = get_ratio_color(GRC_STALLED_CYCLES_FE, ratio); + + fprintf(output, " # "); + color_fprintf(output, color, "%6.2f%%", ratio); + fprintf(output, " frontend cycles idle "); +} + +static void print_stalled_cycles_backend(int cpu, + struct perf_evsel *evsel + __maybe_unused, double avg) +{ + double total, ratio = 0.0; + const char *color; + + total = avg_stats(&runtime_cycles_stats[cpu]); + + if (total) + ratio = avg / total * 100.0; + + color = get_ratio_color(GRC_STALLED_CYCLES_BE, ratio); + + fprintf(output, " # "); + color_fprintf(output, color, "%6.2f%%", ratio); + fprintf(output, " backend cycles idle "); +} + +static void print_branch_misses(int cpu, + struct perf_evsel *evsel __maybe_unused, + double avg) +{ + double total, ratio = 0.0; + const char *color; + + total = avg_stats(&runtime_branches_stats[cpu]); + + if (total) + ratio = avg / total * 100.0; + + color = get_ratio_color(GRC_CACHE_MISSES, ratio); + + fprintf(output, " # "); + color_fprintf(output, color, "%6.2f%%", ratio); + fprintf(output, " of all branches "); +} + +static void print_l1_dcache_misses(int cpu, + struct perf_evsel *evsel __maybe_unused, + double avg) +{ + double total, ratio = 0.0; + const char *color; + + total = avg_stats(&runtime_l1_dcache_stats[cpu]); + + if (total) + ratio = avg / total * 100.0; + + color = get_ratio_color(GRC_CACHE_MISSES, ratio); + + fprintf(output, " # "); + color_fprintf(output, color, "%6.2f%%", ratio); + fprintf(output, " of all L1-dcache hits "); +} + +static void print_l1_icache_misses(int cpu, + struct perf_evsel *evsel __maybe_unused, + double avg) +{ + double total, ratio = 0.0; + const char *color; + + total = avg_stats(&runtime_l1_icache_stats[cpu]); + + if (total) + ratio = avg / total * 100.0; + + color = get_ratio_color(GRC_CACHE_MISSES, ratio); + + fprintf(output, " # "); + color_fprintf(output, color, "%6.2f%%", ratio); + fprintf(output, " of all L1-icache hits "); +} + +static void print_dtlb_cache_misses(int cpu, + struct perf_evsel *evsel __maybe_unused, + double avg) +{ + double total, ratio = 0.0; + const char *color; + + total = avg_stats(&runtime_dtlb_cache_stats[cpu]); + + if (total) + ratio = avg / total * 100.0; + + color = get_ratio_color(GRC_CACHE_MISSES, ratio); + + fprintf(output, " # "); + color_fprintf(output, color, "%6.2f%%", ratio); + fprintf(output, " of all dTLB cache hits "); } -static void abs_printout(int cpu, struct perf_evsel *evsel, double avg) +static void print_itlb_cache_misses(int cpu, + struct perf_evsel *evsel __maybe_unused, + double avg) { double total, ratio = 0.0; - char cpustr[16] = { '\0', }; + const char *color; + + total = avg_stats(&runtime_itlb_cache_stats[cpu]); + + if (total) + ratio = avg / total * 100.0; + + color = get_ratio_color(GRC_CACHE_MISSES, ratio); + + fprintf(output, " # "); + color_fprintf(output, color, "%6.2f%%", ratio); + fprintf(output, " of all iTLB cache hits "); +} + +static void print_ll_cache_misses(int cpu, + struct perf_evsel *evsel __maybe_unused, + double avg) +{ + double total, ratio = 0.0; + const char *color; + + total = avg_stats(&runtime_ll_cache_stats[cpu]); + + if (total) + ratio = avg / total * 100.0; + + color = get_ratio_color(GRC_CACHE_MISSES, ratio); + + fprintf(output, " # "); + color_fprintf(output, color, "%6.2f%%", ratio); + fprintf(output, " of all LL-cache hits "); +} + +static void abs_printout(int cpu, int nr, struct perf_evsel *evsel, double avg) +{ + double total, ratio = 0.0, total2; + double sc = evsel->scale; const char *fmt; - if (csv_output) - fmt = "%s%.0f%s%s"; - else if (big_num) - fmt = "%s%'18.0f%s%-24s"; - else - fmt = "%s%18.0f%s%-24s"; + if (csv_output) { + fmt = sc != 1.0 ? "%.2f%s" : "%.0f%s"; + } else { + if (big_num) + fmt = sc != 1.0 ? "%'18.2f%s" : "%'18.0f%s"; + else + fmt = sc != 1.0 ? "%18.2f%s" : "%18.0f%s"; + } - if (no_aggr) - sprintf(cpustr, "CPU%*d%s", - csv_output ? 0 : -4, - cpus->map[cpu], csv_sep); - else + aggr_printout(evsel, cpu, nr); + + if (aggr_mode == AGGR_GLOBAL) cpu = 0; - fprintf(stderr, fmt, cpustr, avg, csv_sep, event_name(evsel)); + fprintf(output, fmt, avg, csv_sep); - if (csv_output) + if (evsel->unit) + fprintf(output, "%-*s%s", + csv_output ? 0 : unit_width, + evsel->unit, csv_sep); + + fprintf(output, "%-*s", csv_output ? 0 : 25, perf_evsel__name(evsel)); + + if (evsel->cgrp) + fprintf(output, "%s%s", csv_sep, evsel->cgrp->name); + + if (csv_output || interval) return; if (perf_evsel__match(evsel, HARDWARE, HW_INSTRUCTIONS)) { total = avg_stats(&runtime_cycles_stats[cpu]); - - if (total) + if (total) { ratio = avg / total; + fprintf(output, " # %5.2f insns per cycle ", ratio); + } + total = avg_stats(&runtime_stalled_cycles_front_stats[cpu]); + total = max(total, avg_stats(&runtime_stalled_cycles_back_stats[cpu])); + + if (total && avg) { + ratio = total / avg; + fprintf(output, "\n"); + if (aggr_mode == AGGR_NONE) + fprintf(output, " "); + fprintf(output, " # %5.2f stalled cycles per insn", ratio); + } - fprintf(stderr, " # %10.3f IPC ", ratio); } else if (perf_evsel__match(evsel, HARDWARE, HW_BRANCH_MISSES) && runtime_branches_stats[cpu].n != 0) { - total = avg_stats(&runtime_branches_stats[cpu]); + print_branch_misses(cpu, evsel, avg); + } else if ( + evsel->attr.type == PERF_TYPE_HW_CACHE && + evsel->attr.config == ( PERF_COUNT_HW_CACHE_L1D | + ((PERF_COUNT_HW_CACHE_OP_READ) << 8) | + ((PERF_COUNT_HW_CACHE_RESULT_MISS) << 16)) && + runtime_l1_dcache_stats[cpu].n != 0) { + print_l1_dcache_misses(cpu, evsel, avg); + } else if ( + evsel->attr.type == PERF_TYPE_HW_CACHE && + evsel->attr.config == ( PERF_COUNT_HW_CACHE_L1I | + ((PERF_COUNT_HW_CACHE_OP_READ) << 8) | + ((PERF_COUNT_HW_CACHE_RESULT_MISS) << 16)) && + runtime_l1_icache_stats[cpu].n != 0) { + print_l1_icache_misses(cpu, evsel, avg); + } else if ( + evsel->attr.type == PERF_TYPE_HW_CACHE && + evsel->attr.config == ( PERF_COUNT_HW_CACHE_DTLB | + ((PERF_COUNT_HW_CACHE_OP_READ) << 8) | + ((PERF_COUNT_HW_CACHE_RESULT_MISS) << 16)) && + runtime_dtlb_cache_stats[cpu].n != 0) { + print_dtlb_cache_misses(cpu, evsel, avg); + } else if ( + evsel->attr.type == PERF_TYPE_HW_CACHE && + evsel->attr.config == ( PERF_COUNT_HW_CACHE_ITLB | + ((PERF_COUNT_HW_CACHE_OP_READ) << 8) | + ((PERF_COUNT_HW_CACHE_RESULT_MISS) << 16)) && + runtime_itlb_cache_stats[cpu].n != 0) { + print_itlb_cache_misses(cpu, evsel, avg); + } else if ( + evsel->attr.type == PERF_TYPE_HW_CACHE && + evsel->attr.config == ( PERF_COUNT_HW_CACHE_LL | + ((PERF_COUNT_HW_CACHE_OP_READ) << 8) | + ((PERF_COUNT_HW_CACHE_RESULT_MISS) << 16)) && + runtime_ll_cache_stats[cpu].n != 0) { + print_ll_cache_misses(cpu, evsel, avg); + } else if (perf_evsel__match(evsel, HARDWARE, HW_CACHE_MISSES) && + runtime_cacherefs_stats[cpu].n != 0) { + total = avg_stats(&runtime_cacherefs_stats[cpu]); if (total) ratio = avg * 100 / total; - fprintf(stderr, " # %10.3f %% ", ratio); + fprintf(output, " # %8.3f %% of all cache refs ", ratio); + + } else if (perf_evsel__match(evsel, HARDWARE, HW_STALLED_CYCLES_FRONTEND)) { + print_stalled_cycles_frontend(cpu, evsel, avg); + } else if (perf_evsel__match(evsel, HARDWARE, HW_STALLED_CYCLES_BACKEND)) { + print_stalled_cycles_backend(cpu, evsel, avg); + } else if (perf_evsel__match(evsel, HARDWARE, HW_CPU_CYCLES)) { + total = avg_stats(&runtime_nsecs_stats[cpu]); + + if (total) { + ratio = avg / total; + fprintf(output, " # %8.3f GHz ", ratio); + } + } else if (transaction_run && + perf_evsel__cmp(evsel, nth_evsel(T_CYCLES_IN_TX))) { + total = avg_stats(&runtime_cycles_stats[cpu]); + if (total) + fprintf(output, + " # %5.2f%% transactional cycles ", + 100.0 * (avg / total)); + } else if (transaction_run && + perf_evsel__cmp(evsel, nth_evsel(T_CYCLES_IN_TX_CP))) { + total = avg_stats(&runtime_cycles_stats[cpu]); + total2 = avg_stats(&runtime_cycles_in_tx_stats[cpu]); + if (total2 < avg) + total2 = avg; + if (total) + fprintf(output, + " # %5.2f%% aborted cycles ", + 100.0 * ((total2-avg) / total)); + } else if (transaction_run && + perf_evsel__cmp(evsel, nth_evsel(T_TRANSACTION_START)) && + avg > 0 && + runtime_cycles_in_tx_stats[cpu].n != 0) { + total = avg_stats(&runtime_cycles_in_tx_stats[cpu]); + + if (total) + ratio = total / avg; + + fprintf(output, " # %8.0f cycles / transaction ", ratio); + } else if (transaction_run && + perf_evsel__cmp(evsel, nth_evsel(T_ELISION_START)) && + avg > 0 && + runtime_cycles_in_tx_stats[cpu].n != 0) { + total = avg_stats(&runtime_cycles_in_tx_stats[cpu]); + if (total) + ratio = total / avg; + + fprintf(output, " # %8.0f cycles / elision ", ratio); } else if (runtime_nsecs_stats[cpu].n != 0) { + char unit = 'M'; + total = avg_stats(&runtime_nsecs_stats[cpu]); if (total) ratio = 1000.0 * avg / total; + if (ratio < 0.001) { + ratio *= 1000; + unit = 'K'; + } + + fprintf(output, " # %8.3f %c/sec ", ratio, unit); + } else { + fprintf(output, " "); + } +} + +static void print_aggr(char *prefix) +{ + struct perf_evsel *counter; + int cpu, cpu2, s, s2, id, nr; + double uval; + u64 ena, run, val; + + if (!(aggr_map || aggr_get_id)) + return; + + for (s = 0; s < aggr_map->nr; s++) { + id = aggr_map->map[s]; + evlist__for_each(evsel_list, counter) { + val = ena = run = 0; + nr = 0; + for (cpu = 0; cpu < perf_evsel__nr_cpus(counter); cpu++) { + cpu2 = perf_evsel__cpus(counter)->map[cpu]; + s2 = aggr_get_id(evsel_list->cpus, cpu2); + if (s2 != id) + continue; + val += counter->counts->cpu[cpu].val; + ena += counter->counts->cpu[cpu].ena; + run += counter->counts->cpu[cpu].run; + nr++; + } + if (prefix) + fprintf(output, "%s", prefix); + + if (run == 0 || ena == 0) { + aggr_printout(counter, id, nr); + + fprintf(output, "%*s%s", + csv_output ? 0 : 18, + counter->supported ? CNTR_NOT_COUNTED : CNTR_NOT_SUPPORTED, + csv_sep); + + fprintf(output, "%-*s%s", + csv_output ? 0 : unit_width, + counter->unit, csv_sep); + + fprintf(output, "%*s", + csv_output ? 0 : -25, + perf_evsel__name(counter)); - fprintf(stderr, " # %10.3f M/sec", ratio); + if (counter->cgrp) + fprintf(output, "%s%s", + csv_sep, counter->cgrp->name); + + fputc('\n', output); + continue; + } + uval = val * counter->scale; + + if (nsec_counter(counter)) + nsec_printout(id, nr, counter, uval); + else + abs_printout(id, nr, counter, uval); + + if (!csv_output) { + print_noise(counter, 1.0); + + if (run != ena) + fprintf(output, " (%.2f%%)", + 100.0 * run / ena); + } + fputc('\n', output); + } } } @@ -449,83 +1186,117 @@ static void abs_printout(int cpu, struct perf_evsel *evsel, double avg) * Print out the results of a single counter: * aggregated counts in system-wide mode */ -static void print_counter_aggr(struct perf_evsel *counter) +static void print_counter_aggr(struct perf_evsel *counter, char *prefix) { struct perf_stat *ps = counter->priv; double avg = avg_stats(&ps->res_stats[0]); int scaled = counter->counts->scaled; + double uval; + + if (prefix) + fprintf(output, "%s", prefix); if (scaled == -1) { - fprintf(stderr, "%*s%s%-24s\n", + fprintf(output, "%*s%s", csv_output ? 0 : 18, - "<not counted>", csv_sep, event_name(counter)); + counter->supported ? CNTR_NOT_COUNTED : CNTR_NOT_SUPPORTED, + csv_sep); + fprintf(output, "%-*s%s", + csv_output ? 0 : unit_width, + counter->unit, csv_sep); + fprintf(output, "%*s", + csv_output ? 0 : -25, + perf_evsel__name(counter)); + + if (counter->cgrp) + fprintf(output, "%s%s", csv_sep, counter->cgrp->name); + + fputc('\n', output); return; } + uval = avg * counter->scale; + if (nsec_counter(counter)) - nsec_printout(-1, counter, avg); + nsec_printout(-1, 0, counter, uval); else - abs_printout(-1, counter, avg); + abs_printout(-1, 0, counter, uval); + + print_noise(counter, avg); if (csv_output) { - fputc('\n', stderr); + fputc('\n', output); return; } - print_noise(counter, avg); - if (scaled) { double avg_enabled, avg_running; avg_enabled = avg_stats(&ps->res_stats[1]); avg_running = avg_stats(&ps->res_stats[2]); - fprintf(stderr, " (scaled from %.2f%%)", - 100 * avg_running / avg_enabled); + fprintf(output, " [%5.2f%%]", 100 * avg_running / avg_enabled); } - - fprintf(stderr, "\n"); + fprintf(output, "\n"); } /* * Print out the results of a single counter: * does not use aggregated count in system-wide */ -static void print_counter(struct perf_evsel *counter) +static void print_counter(struct perf_evsel *counter, char *prefix) { u64 ena, run, val; + double uval; int cpu; - for (cpu = 0; cpu < cpus->nr; cpu++) { + for (cpu = 0; cpu < perf_evsel__nr_cpus(counter); cpu++) { val = counter->counts->cpu[cpu].val; ena = counter->counts->cpu[cpu].ena; run = counter->counts->cpu[cpu].run; + + if (prefix) + fprintf(output, "%s", prefix); + if (run == 0 || ena == 0) { - fprintf(stderr, "CPU%*d%s%*s%s%-24s", + fprintf(output, "CPU%*d%s%*s%s", csv_output ? 0 : -4, - cpus->map[cpu], csv_sep, + perf_evsel__cpus(counter)->map[cpu], csv_sep, csv_output ? 0 : 18, - "<not counted>", csv_sep, - event_name(counter)); + counter->supported ? CNTR_NOT_COUNTED : CNTR_NOT_SUPPORTED, + csv_sep); + + fprintf(output, "%-*s%s", + csv_output ? 0 : unit_width, + counter->unit, csv_sep); - fprintf(stderr, "\n"); + fprintf(output, "%*s", + csv_output ? 0 : -25, + perf_evsel__name(counter)); + + if (counter->cgrp) + fprintf(output, "%s%s", + csv_sep, counter->cgrp->name); + + fputc('\n', output); continue; } + uval = val * counter->scale; + if (nsec_counter(counter)) - nsec_printout(cpu, counter, val); + nsec_printout(cpu, 0, counter, uval); else - abs_printout(cpu, counter, val); + abs_printout(cpu, 0, counter, uval); if (!csv_output) { print_noise(counter, 1.0); - if (run != ena) { - fprintf(stderr, " (scaled from %.2f%%)", + if (run != ena) + fprintf(output, " (%.2f%%)", 100.0 * run / ena); - } } - fprintf(stderr, "\n"); + fputc('\n', output); } } @@ -537,41 +1308,55 @@ static void print_stat(int argc, const char **argv) fflush(stdout); if (!csv_output) { - fprintf(stderr, "\n"); - fprintf(stderr, " Performance counter stats for "); - if(target_pid == -1 && target_tid == -1) { - fprintf(stderr, "\'%s", argv[0]); + fprintf(output, "\n"); + fprintf(output, " Performance counter stats for "); + if (target.system_wide) + fprintf(output, "\'system wide"); + else if (target.cpu_list) + fprintf(output, "\'CPU(s) %s", target.cpu_list); + else if (!target__has_task(&target)) { + fprintf(output, "\'%s", argv[0]); for (i = 1; i < argc; i++) - fprintf(stderr, " %s", argv[i]); - } else if (target_pid != -1) - fprintf(stderr, "process id \'%d", target_pid); + fprintf(output, " %s", argv[i]); + } else if (target.pid) + fprintf(output, "process id \'%s", target.pid); else - fprintf(stderr, "thread id \'%d", target_tid); + fprintf(output, "thread id \'%s", target.tid); - fprintf(stderr, "\'"); + fprintf(output, "\'"); if (run_count > 1) - fprintf(stderr, " (%d runs)", run_count); - fprintf(stderr, ":\n\n"); + fprintf(output, " (%d runs)", run_count); + fprintf(output, ":\n\n"); } - if (no_aggr) { - list_for_each_entry(counter, &evsel_list, node) - print_counter(counter); - } else { - list_for_each_entry(counter, &evsel_list, node) - print_counter_aggr(counter); + switch (aggr_mode) { + case AGGR_CORE: + case AGGR_SOCKET: + print_aggr(NULL); + break; + case AGGR_GLOBAL: + evlist__for_each(evsel_list, counter) + print_counter_aggr(counter, NULL); + break; + case AGGR_NONE: + evlist__for_each(evsel_list, counter) + print_counter(counter, NULL); + break; + default: + break; } if (!csv_output) { - fprintf(stderr, "\n"); - fprintf(stderr, " %18.9f seconds time elapsed", + if (!null_run) + fprintf(output, "\n"); + fprintf(output, " %17.9f seconds time elapsed", avg_stats(&walltime_nsecs_stats)/1e9); if (run_count > 1) { - fprintf(stderr, " ( +- %7.3f%% )", - 100*stddev_stats(&walltime_nsecs_stats) / - avg_stats(&walltime_nsecs_stats)); + fprintf(output, " "); + print_noise_pct(stddev_stats(&walltime_nsecs_stats), + avg_stats(&walltime_nsecs_stats)); } - fprintf(stderr, "\n\n"); + fprintf(output, "\n\n"); } } @@ -579,17 +1364,38 @@ static volatile int signr = -1; static void skip_signal(int signo) { - if(child_pid == -1) + if ((child_pid == -1) || interval) done = 1; signr = signo; + /* + * render child_pid harmless + * won't send SIGTERM to a random + * process in case of race condition + * and fast PID recycling + */ + child_pid = -1; } static void sig_atexit(void) { + sigset_t set, oset; + + /* + * avoid race condition with SIGCHLD handler + * in skip_signal() which is modifying child_pid + * goal is to avoid send SIGTERM to a random + * process + */ + sigemptyset(&set); + sigaddset(&set, SIGCHLD); + sigprocmask(SIG_BLOCK, &set, &oset); + if (child_pid != -1) kill(child_pid, SIGTERM); + sigprocmask(SIG_SETMASK, &oset, NULL); + if (signr == -1) return; @@ -597,128 +1403,400 @@ static void sig_atexit(void) kill(getpid(), signr); } -static const char * const stat_usage[] = { - "perf stat [<options>] [<command>]", - NULL -}; - -static int stat__set_big_num(const struct option *opt __used, - const char *s __used, int unset) +static int stat__set_big_num(const struct option *opt __maybe_unused, + const char *s __maybe_unused, int unset) { big_num_opt = unset ? 0 : 1; return 0; } -static const struct option options[] = { - OPT_CALLBACK('e', "event", NULL, "event", +static int perf_stat_init_aggr_mode(void) +{ + switch (aggr_mode) { + case AGGR_SOCKET: + if (cpu_map__build_socket_map(evsel_list->cpus, &aggr_map)) { + perror("cannot build socket map"); + return -1; + } + aggr_get_id = cpu_map__get_socket; + break; + case AGGR_CORE: + if (cpu_map__build_core_map(evsel_list->cpus, &aggr_map)) { + perror("cannot build core map"); + return -1; + } + aggr_get_id = cpu_map__get_core; + break; + case AGGR_NONE: + case AGGR_GLOBAL: + default: + break; + } + return 0; +} + +static int setup_events(const char * const *attrs, unsigned len) +{ + unsigned i; + + for (i = 0; i < len; i++) { + if (parse_events(evsel_list, attrs[i])) + return -1; + } + return 0; +} + +/* + * Add default attributes, if there were no attributes specified or + * if -d/--detailed, -d -d or -d -d -d is used: + */ +static int add_default_attributes(void) +{ + struct perf_event_attr default_attrs[] = { + + { .type = PERF_TYPE_SOFTWARE, .config = PERF_COUNT_SW_TASK_CLOCK }, + { .type = PERF_TYPE_SOFTWARE, .config = PERF_COUNT_SW_CONTEXT_SWITCHES }, + { .type = PERF_TYPE_SOFTWARE, .config = PERF_COUNT_SW_CPU_MIGRATIONS }, + { .type = PERF_TYPE_SOFTWARE, .config = PERF_COUNT_SW_PAGE_FAULTS }, + + { .type = PERF_TYPE_HARDWARE, .config = PERF_COUNT_HW_CPU_CYCLES }, + { .type = PERF_TYPE_HARDWARE, .config = PERF_COUNT_HW_STALLED_CYCLES_FRONTEND }, + { .type = PERF_TYPE_HARDWARE, .config = PERF_COUNT_HW_STALLED_CYCLES_BACKEND }, + { .type = PERF_TYPE_HARDWARE, .config = PERF_COUNT_HW_INSTRUCTIONS }, + { .type = PERF_TYPE_HARDWARE, .config = PERF_COUNT_HW_BRANCH_INSTRUCTIONS }, + { .type = PERF_TYPE_HARDWARE, .config = PERF_COUNT_HW_BRANCH_MISSES }, + +}; + +/* + * Detailed stats (-d), covering the L1 and last level data caches: + */ + struct perf_event_attr detailed_attrs[] = { + + { .type = PERF_TYPE_HW_CACHE, + .config = + PERF_COUNT_HW_CACHE_L1D << 0 | + (PERF_COUNT_HW_CACHE_OP_READ << 8) | + (PERF_COUNT_HW_CACHE_RESULT_ACCESS << 16) }, + + { .type = PERF_TYPE_HW_CACHE, + .config = + PERF_COUNT_HW_CACHE_L1D << 0 | + (PERF_COUNT_HW_CACHE_OP_READ << 8) | + (PERF_COUNT_HW_CACHE_RESULT_MISS << 16) }, + + { .type = PERF_TYPE_HW_CACHE, + .config = + PERF_COUNT_HW_CACHE_LL << 0 | + (PERF_COUNT_HW_CACHE_OP_READ << 8) | + (PERF_COUNT_HW_CACHE_RESULT_ACCESS << 16) }, + + { .type = PERF_TYPE_HW_CACHE, + .config = + PERF_COUNT_HW_CACHE_LL << 0 | + (PERF_COUNT_HW_CACHE_OP_READ << 8) | + (PERF_COUNT_HW_CACHE_RESULT_MISS << 16) }, +}; + +/* + * Very detailed stats (-d -d), covering the instruction cache and the TLB caches: + */ + struct perf_event_attr very_detailed_attrs[] = { + + { .type = PERF_TYPE_HW_CACHE, + .config = + PERF_COUNT_HW_CACHE_L1I << 0 | + (PERF_COUNT_HW_CACHE_OP_READ << 8) | + (PERF_COUNT_HW_CACHE_RESULT_ACCESS << 16) }, + + { .type = PERF_TYPE_HW_CACHE, + .config = + PERF_COUNT_HW_CACHE_L1I << 0 | + (PERF_COUNT_HW_CACHE_OP_READ << 8) | + (PERF_COUNT_HW_CACHE_RESULT_MISS << 16) }, + + { .type = PERF_TYPE_HW_CACHE, + .config = + PERF_COUNT_HW_CACHE_DTLB << 0 | + (PERF_COUNT_HW_CACHE_OP_READ << 8) | + (PERF_COUNT_HW_CACHE_RESULT_ACCESS << 16) }, + + { .type = PERF_TYPE_HW_CACHE, + .config = + PERF_COUNT_HW_CACHE_DTLB << 0 | + (PERF_COUNT_HW_CACHE_OP_READ << 8) | + (PERF_COUNT_HW_CACHE_RESULT_MISS << 16) }, + + { .type = PERF_TYPE_HW_CACHE, + .config = + PERF_COUNT_HW_CACHE_ITLB << 0 | + (PERF_COUNT_HW_CACHE_OP_READ << 8) | + (PERF_COUNT_HW_CACHE_RESULT_ACCESS << 16) }, + + { .type = PERF_TYPE_HW_CACHE, + .config = + PERF_COUNT_HW_CACHE_ITLB << 0 | + (PERF_COUNT_HW_CACHE_OP_READ << 8) | + (PERF_COUNT_HW_CACHE_RESULT_MISS << 16) }, + +}; + +/* + * Very, very detailed stats (-d -d -d), adding prefetch events: + */ + struct perf_event_attr very_very_detailed_attrs[] = { + + { .type = PERF_TYPE_HW_CACHE, + .config = + PERF_COUNT_HW_CACHE_L1D << 0 | + (PERF_COUNT_HW_CACHE_OP_PREFETCH << 8) | + (PERF_COUNT_HW_CACHE_RESULT_ACCESS << 16) }, + + { .type = PERF_TYPE_HW_CACHE, + .config = + PERF_COUNT_HW_CACHE_L1D << 0 | + (PERF_COUNT_HW_CACHE_OP_PREFETCH << 8) | + (PERF_COUNT_HW_CACHE_RESULT_MISS << 16) }, +}; + + /* Set attrs if no event is selected and !null_run: */ + if (null_run) + return 0; + + if (transaction_run) { + int err; + if (pmu_have_event("cpu", "cycles-ct") && + pmu_have_event("cpu", "el-start")) + err = setup_events(transaction_attrs, + ARRAY_SIZE(transaction_attrs)); + else + err = setup_events(transaction_limited_attrs, + ARRAY_SIZE(transaction_limited_attrs)); + if (err < 0) { + fprintf(stderr, "Cannot set up transaction events\n"); + return -1; + } + return 0; + } + + if (!evsel_list->nr_entries) { + if (perf_evlist__add_default_attrs(evsel_list, default_attrs) < 0) + return -1; + } + + /* Detailed events get appended to the event list: */ + + if (detailed_run < 1) + return 0; + + /* Append detailed run extra attributes: */ + if (perf_evlist__add_default_attrs(evsel_list, detailed_attrs) < 0) + return -1; + + if (detailed_run < 2) + return 0; + + /* Append very detailed run extra attributes: */ + if (perf_evlist__add_default_attrs(evsel_list, very_detailed_attrs) < 0) + return -1; + + if (detailed_run < 3) + return 0; + + /* Append very, very detailed run extra attributes: */ + return perf_evlist__add_default_attrs(evsel_list, very_very_detailed_attrs); +} + +int cmd_stat(int argc, const char **argv, const char *prefix __maybe_unused) +{ + bool append_file = false; + int output_fd = 0; + const char *output_name = NULL; + const struct option options[] = { + OPT_BOOLEAN('T', "transaction", &transaction_run, + "hardware transaction statistics"), + OPT_CALLBACK('e', "event", &evsel_list, "event", "event selector. use 'perf list' to list available events", - parse_events), + parse_events_option), + OPT_CALLBACK(0, "filter", &evsel_list, "filter", + "event filter", parse_filter), OPT_BOOLEAN('i', "no-inherit", &no_inherit, "child tasks do not inherit counters"), - OPT_INTEGER('p', "pid", &target_pid, - "stat events on existing process id"), - OPT_INTEGER('t', "tid", &target_tid, - "stat events on existing thread id"), - OPT_BOOLEAN('a', "all-cpus", &system_wide, + OPT_STRING('p', "pid", &target.pid, "pid", + "stat events on existing process id"), + OPT_STRING('t', "tid", &target.tid, "tid", + "stat events on existing thread id"), + OPT_BOOLEAN('a', "all-cpus", &target.system_wide, "system-wide collection from all CPUs"), - OPT_BOOLEAN('c', "scale", &scale, - "scale/normalize counters"), + OPT_BOOLEAN('g', "group", &group, + "put the counters into a counter group"), + OPT_BOOLEAN('c', "scale", &scale, "scale/normalize counters"), OPT_INCR('v', "verbose", &verbose, "be more verbose (show counter open errors, etc)"), OPT_INTEGER('r', "repeat", &run_count, - "repeat command and print average + stddev (max: 100)"), + "repeat command and print average + stddev (max: 100, forever: 0)"), OPT_BOOLEAN('n', "null", &null_run, "null run - dont start any counters"), + OPT_INCR('d', "detailed", &detailed_run, + "detailed run - start a lot of events"), + OPT_BOOLEAN('S', "sync", &sync_run, + "call sync() before starting a run"), OPT_CALLBACK_NOOPT('B', "big-num", NULL, NULL, "print large numbers with thousands\' separators", stat__set_big_num), - OPT_STRING('C', "cpu", &cpu_list, "cpu", + OPT_STRING('C', "cpu", &target.cpu_list, "cpu", "list of cpus to monitor in system-wide"), - OPT_BOOLEAN('A', "no-aggr", &no_aggr, - "disable CPU count aggregation"), + OPT_SET_UINT('A', "no-aggr", &aggr_mode, + "disable CPU count aggregation", AGGR_NONE), OPT_STRING('x', "field-separator", &csv_sep, "separator", "print counts with custom separator"), + OPT_CALLBACK('G', "cgroup", &evsel_list, "name", + "monitor event in cgroup name only", parse_cgroups), + OPT_STRING('o', "output", &output_name, "file", "output file name"), + OPT_BOOLEAN(0, "append", &append_file, "append to the output file"), + OPT_INTEGER(0, "log-fd", &output_fd, + "log output to fd, instead of stderr"), + OPT_STRING(0, "pre", &pre_cmd, "command", + "command to run prior to the measured command"), + OPT_STRING(0, "post", &post_cmd, "command", + "command to run after to the measured command"), + OPT_UINTEGER('I', "interval-print", &interval, + "print counts at regular interval in ms (>= 100)"), + OPT_SET_UINT(0, "per-socket", &aggr_mode, + "aggregate counts per processor socket", AGGR_SOCKET), + OPT_SET_UINT(0, "per-core", &aggr_mode, + "aggregate counts per physical processor core", AGGR_CORE), + OPT_UINTEGER('D', "delay", &initial_delay, + "ms to wait before starting measurement after program start"), OPT_END() -}; - -int cmd_stat(int argc, const char **argv, const char *prefix __used) -{ - struct perf_evsel *pos; - int status = -ENOMEM; + }; + const char * const stat_usage[] = { + "perf stat [<options>] [<command>]", + NULL + }; + int status = -EINVAL, run_idx; + const char *mode; setlocale(LC_ALL, ""); + evsel_list = perf_evlist__new(); + if (evsel_list == NULL) + return -ENOMEM; + argc = parse_options(argc, argv, options, stat_usage, PARSE_OPT_STOP_AT_NON_OPTION); - if (csv_sep) + output = stderr; + if (output_name && strcmp(output_name, "-")) + output = NULL; + + if (output_name && output_fd) { + fprintf(stderr, "cannot use both --output and --log-fd\n"); + parse_options_usage(stat_usage, options, "o", 1); + parse_options_usage(NULL, options, "log-fd", 0); + goto out; + } + + if (output_fd < 0) { + fprintf(stderr, "argument to --log-fd must be a > 0\n"); + parse_options_usage(stat_usage, options, "log-fd", 0); + goto out; + } + + if (!output) { + struct timespec tm; + mode = append_file ? "a" : "w"; + + output = fopen(output_name, mode); + if (!output) { + perror("failed to create output file"); + return -1; + } + clock_gettime(CLOCK_REALTIME, &tm); + fprintf(output, "# started on %s\n", ctime(&tm.tv_sec)); + } else if (output_fd > 0) { + mode = append_file ? "a" : "w"; + output = fdopen(output_fd, mode); + if (!output) { + perror("Failed opening logfd"); + return -errno; + } + } + + if (csv_sep) { csv_output = true; - else + if (!strcmp(csv_sep, "\\t")) + csv_sep = "\t"; + } else csv_sep = DEFAULT_SEPARATOR; /* * let the spreadsheet do the pretty-printing */ if (csv_output) { - /* User explicitely passed -B? */ + /* User explicitly passed -B? */ if (big_num_opt == 1) { fprintf(stderr, "-B option not supported with -x\n"); - usage_with_options(stat_usage, options); + parse_options_usage(stat_usage, options, "B", 1); + parse_options_usage(NULL, options, "x", 1); + goto out; } else /* Nope, so disable big number formatting */ big_num = false; } else if (big_num_opt == 0) /* User passed --no-big-num */ big_num = false; - if (!argc && target_pid == -1 && target_tid == -1) - usage_with_options(stat_usage, options); - if (run_count <= 0) - usage_with_options(stat_usage, options); - - /* no_aggr is for system-wide only */ - if (no_aggr && !system_wide) + if (!argc && target__none(&target)) usage_with_options(stat_usage, options); - /* Set attrs and nr_counters if no event is selected and !null_run */ - if (!null_run && !nr_counters) { - size_t c; - - nr_counters = ARRAY_SIZE(default_attrs); - - for (c = 0; c < ARRAY_SIZE(default_attrs); ++c) { - pos = perf_evsel__new(&default_attrs[c], - nr_counters); - if (pos == NULL) - goto out; - list_add(&pos->node, &evsel_list); - } + if (run_count < 0) { + pr_err("Run count must be a positive number\n"); + parse_options_usage(stat_usage, options, "r", 1); + goto out; + } else if (run_count == 0) { + forever = true; + run_count = 1; } - if (target_pid != -1) - target_tid = target_pid; + /* no_aggr, cgroup are for system-wide only */ + if ((aggr_mode != AGGR_GLOBAL || nr_cgroups) && + !target__has_cpu(&target)) { + fprintf(stderr, "both cgroup and no-aggregation " + "modes only available in system-wide mode\n"); - threads = thread_map__new(target_pid, target_tid); - if (threads == NULL) { - pr_err("Problems finding threads of monitor\n"); - usage_with_options(stat_usage, options); + parse_options_usage(stat_usage, options, "G", 1); + parse_options_usage(NULL, options, "A", 1); + parse_options_usage(NULL, options, "a", 1); + goto out; } - if (system_wide) - cpus = cpu_map__new(cpu_list); - else - cpus = cpu_map__dummy_new(); + if (add_default_attributes()) + goto out; - if (cpus == NULL) { - perror("failed to parse CPUs map"); - usage_with_options(stat_usage, options); - return -1; - } + target__validate(&target); - list_for_each_entry(pos, &evsel_list, node) { - if (perf_evsel__alloc_stat_priv(pos) < 0 || - perf_evsel__alloc_counts(pos, cpus->nr) < 0 || - perf_evsel__alloc_fd(pos, cpus->nr, threads->nr) < 0) - goto out_free_fd; + if (perf_evlist__create_maps(evsel_list, &target) < 0) { + if (target__has_task(&target)) { + pr_err("Problems finding threads of monitor\n"); + parse_options_usage(stat_usage, options, "p", 1); + parse_options_usage(NULL, options, "t", 1); + } else if (target__has_cpu(&target)) { + perror("failed to parse CPUs map"); + parse_options_usage(stat_usage, options, "C", 1); + parse_options_usage(NULL, options, "a", 1); + } + goto out; } + if (interval && interval < 100) { + pr_err("print interval must be >= 100ms\n"); + parse_options_usage(stat_usage, options, "I", 1); + goto out; + } + + if (perf_evlist__alloc_stats(evsel_list, interval)) + goto out; + + if (perf_stat_init_aggr_mode()) + goto out; /* * We dont want to block the signals - that would cause @@ -727,25 +1805,30 @@ int cmd_stat(int argc, const char **argv, const char *prefix __used) * task, but being ignored by perf stat itself: */ atexit(sig_atexit); - signal(SIGINT, skip_signal); + if (!forever) + signal(SIGINT, skip_signal); + signal(SIGCHLD, skip_signal); signal(SIGALRM, skip_signal); signal(SIGABRT, skip_signal); status = 0; - for (run_idx = 0; run_idx < run_count; run_idx++) { + for (run_idx = 0; forever || run_idx < run_count; run_idx++) { if (run_count != 1 && verbose) - fprintf(stderr, "[ perf stat: executing run #%d ... ]\n", run_idx + 1); + fprintf(output, "[ perf stat: executing run #%d ... ]\n", + run_idx + 1); + status = run_perf_stat(argc, argv); + if (forever && status != -1) { + print_stat(argc, argv); + perf_stat__reset_stats(evsel_list); + } } - if (status != -1) + if (!forever && status != -1 && !interval) print_stat(argc, argv); -out_free_fd: - list_for_each_entry(pos, &evsel_list, node) - perf_evsel__free_stat_priv(pos); - perf_evsel_list__delete(); + + perf_evlist__free_stats(evsel_list); out: - thread_map__delete(threads); - threads = NULL; + perf_evlist__delete(evsel_list); return status; } |