diff options
Diffstat (limited to 'tools/perf/builtin-stat.c')
| -rw-r--r-- | tools/perf/builtin-stat.c | 168 |
1 files changed, 137 insertions, 31 deletions
diff --git a/tools/perf/builtin-stat.c b/tools/perf/builtin-stat.c index f17dc601b0f3..05be023c3f0e 100644 --- a/tools/perf/builtin-stat.c +++ b/tools/perf/builtin-stat.c @@ -65,6 +65,7 @@ #include "util/tool.h" #include "util/string2.h" #include "util/metricgroup.h" +#include "util/top.h" #include "asm/bug.h" #include <linux/time64.h> @@ -80,6 +81,9 @@ #include <sys/stat.h> #include <sys/wait.h> #include <unistd.h> +#include <sys/time.h> +#include <sys/resource.h> +#include <sys/wait.h> #include "sane_ctype.h" @@ -141,6 +145,8 @@ static struct target target = { typedef int (*aggr_get_id_t)(struct cpu_map *m, int cpu); +#define METRIC_ONLY_LEN 20 + static int run_count = 1; static bool no_inherit = false; static volatile pid_t child_pid = -1; @@ -164,15 +170,21 @@ static bool forever = false; static bool metric_only = false; static bool force_metric_only = false; static bool no_merge = false; +static bool walltime_run_table = false; static struct timespec ref_time; static struct cpu_map *aggr_map; static aggr_get_id_t aggr_get_id; static bool append_file; static bool interval_count; +static bool interval_clear; static const char *output_name; static int output_fd; static int print_free_counters_hint; static int print_mixed_hw_group_error; +static u64 *walltime_run; +static bool ru_display = false; +static struct rusage ru_data; +static unsigned int metric_only_len = METRIC_ONLY_LEN; struct perf_stat { bool record; @@ -569,7 +581,7 @@ static struct perf_evsel *perf_evsel__reset_weak_group(struct perf_evsel *evsel) return leader; } -static int __run_perf_stat(int argc, const char **argv) +static int __run_perf_stat(int argc, const char **argv, int run_idx) { int interval = stat_config.interval; int times = stat_config.times; @@ -724,7 +736,7 @@ try_again: break; } } - waitpid(child_pid, &status, 0); + wait4(child_pid, &status, 0, &ru_data); if (workload_exec_errno) { const char *emsg = str_error_r(workload_exec_errno, msg, sizeof(msg)); @@ -752,6 +764,9 @@ try_again: t1 = rdclock(); + if (walltime_run_table) + walltime_run[run_idx] = t1 - t0; + update_stats(&walltime_nsecs_stats, t1 - t0); /* @@ -766,7 +781,7 @@ try_again: return WEXITSTATUS(status); } -static int run_perf_stat(int argc, const char **argv) +static int run_perf_stat(int argc, const char **argv, int run_idx) { int ret; @@ -779,7 +794,7 @@ static int run_perf_stat(int argc, const char **argv) if (sync_run) sync(); - ret = __run_perf_stat(argc, argv); + ret = __run_perf_stat(argc, argv, run_idx); if (ret) return ret; @@ -957,8 +972,6 @@ static void print_metric_csv(void *ctx, fprintf(out, "%s%s%s%s", csv_sep, vals, csv_sep, unit); } -#define METRIC_ONLY_LEN 20 - /* Filter out some columns that don't work well in metrics only mode */ static bool valid_only_metric(const char *unit) @@ -989,22 +1002,20 @@ static void print_metric_only(void *ctx, const char *color, const char *fmt, { struct outstate *os = ctx; FILE *out = os->fh; - int n; - char buf[1024]; - unsigned mlen = METRIC_ONLY_LEN; + char buf[1024], str[1024]; + unsigned mlen = metric_only_len; if (!valid_only_metric(unit)) return; unit = fixunit(buf, os->evsel, unit); - if (color) - n = color_fprintf(out, color, fmt, val); - else - n = fprintf(out, fmt, val); - if (n > METRIC_ONLY_LEN) - n = METRIC_ONLY_LEN; if (mlen < strlen(unit)) mlen = strlen(unit) + 1; - fprintf(out, "%*s", mlen - n, ""); + + if (color) + mlen += strlen(color) + sizeof(PERF_COLOR_RESET) - 1; + + color_snprintf(str, sizeof(str), color ?: "", fmt, val); + fprintf(out, "%*s ", mlen, str); } static void print_metric_only_csv(void *ctx, const char *color __maybe_unused, @@ -1044,7 +1055,7 @@ static void print_metric_header(void *ctx, const char *color __maybe_unused, if (csv_output) fprintf(os->fh, "%s%s", unit, csv_sep); else - fprintf(os->fh, "%-*s ", METRIC_ONLY_LEN, unit); + fprintf(os->fh, "%*s ", metric_only_len, unit); } static void nsec_printout(int id, int nr, struct perf_evsel *evsel, double avg) @@ -1694,9 +1705,12 @@ static void print_interval(char *prefix, struct timespec *ts) FILE *output = stat_config.output; static int num_print_interval; + if (interval_clear) + puts(CONSOLE_CLEAR); + sprintf(prefix, "%6lu.%09lu%s", ts->tv_sec, ts->tv_nsec, csv_sep); - if (num_print_interval == 0 && !csv_output) { + if ((num_print_interval == 0 && !csv_output) || interval_clear) { switch (stat_config.aggr_mode) { case AGGR_SOCKET: fprintf(output, "# time socket cpus"); @@ -1709,7 +1723,7 @@ static void print_interval(char *prefix, struct timespec *ts) fprintf(output, " counts %*s events\n", unit_width, "unit"); break; case AGGR_NONE: - fprintf(output, "# time CPU"); + fprintf(output, "# time CPU "); if (!metric_only) fprintf(output, " counts %*s events\n", unit_width, "unit"); break; @@ -1728,7 +1742,7 @@ static void print_interval(char *prefix, struct timespec *ts) } } - if (num_print_interval == 0 && metric_only) + if ((num_print_interval == 0 || interval_clear) && metric_only) print_metric_headers(" ", true); if (++num_print_interval == 25) num_print_interval = 0; @@ -1764,19 +1778,81 @@ static void print_header(int argc, const char **argv) } } +static int get_precision(double num) +{ + if (num > 1) + return 0; + + return lround(ceil(-log10(num))); +} + +static void print_table(FILE *output, int precision, double avg) +{ + char tmp[64]; + int idx, indent = 0; + + scnprintf(tmp, 64, " %17.*f", precision, avg); + while (tmp[indent] == ' ') + indent++; + + fprintf(output, "%*s# Table of individual measurements:\n", indent, ""); + + for (idx = 0; idx < run_count; idx++) { + double run = (double) walltime_run[idx] / NSEC_PER_SEC; + int h, n = 1 + abs((int) (100.0 * (run - avg)/run) / 5); + + fprintf(output, " %17.*f (%+.*f) ", + precision, run, precision, run - avg); + + for (h = 0; h < n; h++) + fprintf(output, "#"); + + fprintf(output, "\n"); + } + + fprintf(output, "\n%*s# Final result:\n", indent, ""); +} + +static double timeval2double(struct timeval *t) +{ + return t->tv_sec + (double) t->tv_usec/USEC_PER_SEC; +} + static void print_footer(void) { + double avg = avg_stats(&walltime_nsecs_stats) / NSEC_PER_SEC; FILE *output = stat_config.output; int n; if (!null_run) fprintf(output, "\n"); - fprintf(output, " %17.9f seconds time elapsed", - avg_stats(&walltime_nsecs_stats) / NSEC_PER_SEC); - if (run_count > 1) { - fprintf(output, " "); - print_noise_pct(stddev_stats(&walltime_nsecs_stats), - avg_stats(&walltime_nsecs_stats)); + + if (run_count == 1) { + fprintf(output, " %17.9f seconds time elapsed", avg); + + if (ru_display) { + double ru_utime = timeval2double(&ru_data.ru_utime); + double ru_stime = timeval2double(&ru_data.ru_stime); + + fprintf(output, "\n\n"); + fprintf(output, " %17.9f seconds user\n", ru_utime); + fprintf(output, " %17.9f seconds sys\n", ru_stime); + } + } else { + double sd = stddev_stats(&walltime_nsecs_stats) / NSEC_PER_SEC; + /* + * Display at most 2 more significant + * digits than the stddev inaccuracy. + */ + int precision = get_precision(sd) + 2; + + if (walltime_run_table) + print_table(output, precision, avg); + + fprintf(output, " %17.*f +- %.*f seconds time elapsed", + precision, avg, precision, sd); + + print_noise_pct(sd, avg); } fprintf(output, "\n\n"); @@ -1952,6 +2028,8 @@ static const struct option stat_options[] = { "be more verbose (show counter open errors, etc)"), OPT_INTEGER('r', "repeat", &run_count, "repeat command and print average + stddev (max: 100, forever: 0)"), + OPT_BOOLEAN(0, "table", &walltime_run_table, + "display details about each run (only with -r option)"), OPT_BOOLEAN('n', "null", &null_run, "null run - dont start any counters"), OPT_INCR('d', "detailed", &detailed_run, @@ -1983,6 +2061,8 @@ static const struct option stat_options[] = { "(overhead is possible for values <= 100ms)"), OPT_INTEGER(0, "interval-count", &stat_config.times, "print counts for fixed number of times"), + OPT_BOOLEAN(0, "interval-clear", &interval_clear, + "clear screen in between new interval"), OPT_UINTEGER(0, "timeout", &stat_config.timeout, "stop workload and print counts after a timeout period in ms (>= 10ms)"), OPT_SET_UINT(0, "per-socket", &stat_config.aggr_mode, @@ -2362,14 +2442,13 @@ static int add_default_attributes(void) (PERF_COUNT_HW_CACHE_OP_PREFETCH << 8) | (PERF_COUNT_HW_CACHE_RESULT_MISS << 16) }, }; + struct parse_events_error errinfo; /* Set attrs if no event is selected and !null_run: */ if (null_run) return 0; if (transaction_run) { - struct parse_events_error errinfo; - if (pmu_have_event("cpu", "cycles-ct") && pmu_have_event("cpu", "el-start")) err = parse_events(evsel_list, transaction_attrs, @@ -2380,6 +2459,7 @@ static int add_default_attributes(void) &errinfo); if (err) { fprintf(stderr, "Cannot set up transaction events\n"); + parse_events_print_error(&errinfo, transaction_attrs); return -1; } return 0; @@ -2405,10 +2485,11 @@ static int add_default_attributes(void) pmu_have_event("msr", "smi")) { if (!force_metric_only) metric_only = true; - err = parse_events(evsel_list, smi_cost_attrs, NULL); + err = parse_events(evsel_list, smi_cost_attrs, &errinfo); } else { fprintf(stderr, "To measure SMI cost, it needs " "msr/aperf/, msr/smi/ and cpu/cycles/ support\n"); + parse_events_print_error(&errinfo, smi_cost_attrs); return -1; } if (err) { @@ -2443,12 +2524,13 @@ static int add_default_attributes(void) if (topdown_attrs[0] && str) { if (warn) arch_topdown_group_warn(); - err = parse_events(evsel_list, str, NULL); + err = parse_events(evsel_list, str, &errinfo); if (err) { fprintf(stderr, "Cannot set up top down events %s: %d\n", str, err); free(str); + parse_events_print_error(&errinfo, str); return -1; } } else { @@ -2843,6 +2925,13 @@ int cmd_stat(int argc, const char **argv) goto out; } + if (walltime_run_table && run_count <= 1) { + fprintf(stderr, "--table is only supported with -r\n"); + parse_options_usage(stat_usage, stat_options, "r", 1); + parse_options_usage(NULL, stat_options, "table", 0); + goto out; + } + if (output_fd < 0) { fprintf(stderr, "argument to --log-fd must be a > 0\n"); parse_options_usage(stat_usage, stat_options, "log-fd", 0); @@ -2888,6 +2977,13 @@ int cmd_stat(int argc, const char **argv) setup_system_wide(argc); + /* + * Display user/system times only for single + * run and when there's specified tracee. + */ + if ((run_count == 1) && target__none(&target)) + ru_display = true; + if (run_count < 0) { pr_err("Run count must be a positive number\n"); parse_options_usage(stat_usage, stat_options, "r", 1); @@ -2897,6 +2993,14 @@ int cmd_stat(int argc, const char **argv) run_count = 1; } + if (walltime_run_table) { + walltime_run = zalloc(run_count * sizeof(walltime_run[0])); + if (!walltime_run) { + pr_err("failed to setup -r option"); + goto out; + } + } + if ((stat_config.aggr_mode == AGGR_THREAD) && !target__has_task(&target)) { if (!target.system_wide || target.cpu_list) { @@ -3012,7 +3116,7 @@ int cmd_stat(int argc, const char **argv) fprintf(output, "[ perf stat: executing run #%d ... ]\n", run_idx + 1); - status = run_perf_stat(argc, argv); + status = run_perf_stat(argc, argv, run_idx); if (forever && status != -1) { print_counters(NULL, argc, argv); perf_stat__reset_stats(); @@ -3060,6 +3164,8 @@ int cmd_stat(int argc, const char **argv) perf_stat__exit_aggr_mode(); perf_evlist__free_stats(evsel_list); out: + free(walltime_run); + if (smi_cost && smi_reset) sysfs__write_int(FREEZE_ON_SMI_PATH, 0); |