perf trace: Add --summary-mode option

The --summary-mode option will select how to show the syscall summary at
the end.  By default, it'll show the summary for each thread and it's
the same as if --summary-mode=thread is passed.

The other option is to show total summary, which is --summary-mode=total.
I'd like to have this instead of a separate option like --total-summary
because we may want to add a new summary mode (by cgroup) later.

  $ sudo ./perf trace -as --summary-mode=total sleep 1

   Summary of events:

   total, 21580 events

     syscall            calls  errors  total       min       avg       max       stddev
                                       (msec)    (msec)    (msec)    (msec)        (%)
     --------------- --------  ------ -------- --------- --------- ---------     ------
     epoll_wait          1305      0 14716.712     0.000    11.277   551.529      8.87%
     futex               1256     89 13331.197     0.000    10.614   733.722     15.49%
     poll                 669      0  6806.618     0.000    10.174   459.316     11.77%
     ppoll                220      0  3968.797     0.000    18.040   516.775     25.35%
     clock_nanosleep        1      0  1000.027  1000.027  1000.027  1000.027      0.00%
     epoll_pwait           21      0   592.783     0.000    28.228   522.293     88.29%
     nanosleep             16      0    60.515     0.000     3.782    10.123     33.33%
     ioctl                510      0     4.284     0.001     0.008     0.182      8.84%
     recvmsg             1434    775     3.497     0.001     0.002     0.174      6.37%
     write               1393      0     2.854     0.001     0.002     0.017      1.79%
     read                1063    100     2.236     0.000     0.002     0.083      5.11%
     ...

Reviewed-by: Howard Chu <howardchu95@gmail.com>
Acked-by: Arnaldo Carvalho de Melo <acme@redhat.com>
Tested-by: Arnaldo Carvalho de Melo <acme@redhat.com>
Link: https://lore.kernel.org/r/20250205205443.1986408-5-namhyung@kernel.org
Signed-off-by: Namhyung Kim <namhyung@kernel.org>
This commit is contained in:
Namhyung Kim 2025-02-05 12:54:43 -08:00
parent bd50a26c9a
commit fc00897c8a
2 changed files with 114 additions and 19 deletions

View File

@ -150,6 +150,10 @@ the thread executes on the designated CPUs. Default is to monitor all CPUs.
To be used with -s or -S, to show stats for the errnos experienced by To be used with -s or -S, to show stats for the errnos experienced by
syscalls, using only this option will trigger --summary. syscalls, using only this option will trigger --summary.
--summary-mode=mode::
To be used with -s or -S, to select how to show summary. By default it'll
show the syscall summary by thread. Possible values are: thread, total.
--tool_stats:: --tool_stats::
Show tool stats such as number of times fd->pathname was discovered thru Show tool stats such as number of times fd->pathname was discovered thru
hooking the open syscall return + vfs_getname or via reading /proc/pid/fd, etc. hooking the open syscall return + vfs_getname or via reading /proc/pid/fd, etc.

View File

@ -139,6 +139,12 @@ struct syscall_fmt {
bool hexret; bool hexret;
}; };
enum summary_mode {
SUMMARY__NONE = 0,
SUMMARY__BY_TOTAL,
SUMMARY__BY_THREAD,
};
struct trace { struct trace {
struct perf_tool tool; struct perf_tool tool;
struct syscalltbl *sctbl; struct syscalltbl *sctbl;
@ -177,14 +183,17 @@ struct trace {
pid_t *entries; pid_t *entries;
struct bpf_map *map; struct bpf_map *map;
} filter_pids; } filter_pids;
struct hashmap *syscall_stats;
double duration_filter; double duration_filter;
double runtime_ms; double runtime_ms;
unsigned long pfmaj, pfmin;
struct { struct {
u64 vfs_getname, u64 vfs_getname,
proc_getname; proc_getname;
} stats; } stats;
unsigned int max_stack; unsigned int max_stack;
unsigned int min_stack; unsigned int min_stack;
enum summary_mode summary_mode;
int raw_augmented_syscalls_args_size; int raw_augmented_syscalls_args_size;
bool raw_augmented_syscalls; bool raw_augmented_syscalls;
bool fd_path_disabled; bool fd_path_disabled;
@ -2496,18 +2505,23 @@ struct syscall_stats {
}; };
static void thread__update_stats(struct thread *thread, struct thread_trace *ttrace, static void thread__update_stats(struct thread *thread, struct thread_trace *ttrace,
int id, struct perf_sample *sample, long err, bool errno_summary) int id, struct perf_sample *sample, long err,
struct trace *trace)
{ {
struct hashmap *syscall_stats = ttrace->syscall_stats;
struct syscall_stats *stats = NULL; struct syscall_stats *stats = NULL;
u64 duration = 0; u64 duration = 0;
if (!hashmap__find(ttrace->syscall_stats, id, &stats)) { if (trace->summary_mode == SUMMARY__BY_TOTAL)
syscall_stats = trace->syscall_stats;
if (!hashmap__find(syscall_stats, id, &stats)) {
stats = zalloc(sizeof(*stats)); stats = zalloc(sizeof(*stats));
if (stats == NULL) if (stats == NULL)
return; return;
init_stats(&stats->stats); init_stats(&stats->stats);
if (hashmap__add(ttrace->syscall_stats, id, stats) < 0) { if (hashmap__add(syscall_stats, id, stats) < 0) {
free(stats); free(stats);
return; return;
} }
@ -2521,7 +2535,7 @@ static void thread__update_stats(struct thread *thread, struct thread_trace *ttr
if (err < 0) { if (err < 0) {
++stats->nr_failures; ++stats->nr_failures;
if (!errno_summary) if (!trace->errno_summary)
return; return;
err = -err; err = -err;
@ -2813,7 +2827,7 @@ static int trace__sys_exit(struct trace *trace, struct evsel *evsel,
ret = perf_evsel__sc_tp_uint(evsel, ret, sample); ret = perf_evsel__sc_tp_uint(evsel, ret, sample);
if (trace->summary) if (trace->summary)
thread__update_stats(thread, ttrace, id, sample, ret, trace->errno_summary); thread__update_stats(thread, ttrace, id, sample, ret, trace);
if (!trace->fd_path_disabled && sc->is_open && ret >= 0 && ttrace->filename.pending_open) { if (!trace->fd_path_disabled && sc->is_open && ret >= 0 && ttrace->filename.pending_open) {
trace__set_fd_pathname(thread, ret, ttrace->filename.name); trace__set_fd_pathname(thread, ret, ttrace->filename.name);
@ -3251,10 +3265,13 @@ static int trace__pgfault(struct trace *trace,
if (ttrace == NULL) if (ttrace == NULL)
goto out_put; goto out_put;
if (evsel->core.attr.config == PERF_COUNT_SW_PAGE_FAULTS_MAJ) if (evsel->core.attr.config == PERF_COUNT_SW_PAGE_FAULTS_MAJ) {
ttrace->pfmaj++; ttrace->pfmaj++;
else trace->pfmaj++;
} else {
ttrace->pfmin++; ttrace->pfmin++;
trace->pfmin++;
}
if (trace->summary_only) if (trace->summary_only)
goto out; goto out;
@ -3413,6 +3430,7 @@ static int trace__record(struct trace *trace, int argc, const char **argv)
} }
static size_t trace__fprintf_thread_summary(struct trace *trace, FILE *fp); static size_t trace__fprintf_thread_summary(struct trace *trace, FILE *fp);
static size_t trace__fprintf_total_summary(struct trace *trace, FILE *fp);
static bool evlist__add_vfs_getname(struct evlist *evlist) static bool evlist__add_vfs_getname(struct evlist *evlist)
{ {
@ -4325,6 +4343,12 @@ static int trace__run(struct trace *trace, int argc, const char **argv)
goto out_delete_evlist; goto out_delete_evlist;
} }
if (trace->summary_mode == SUMMARY__BY_TOTAL) {
trace->syscall_stats = alloc_syscall_stats();
if (trace->syscall_stats == NULL)
goto out_delete_evlist;
}
evlist__config(evlist, &trace->opts, &callchain_param); evlist__config(evlist, &trace->opts, &callchain_param);
if (forks) { if (forks) {
@ -4485,8 +4509,12 @@ static int trace__run(struct trace *trace, int argc, const char **argv)
ordered_events__flush(&trace->oe.data, OE_FLUSH__FINAL); ordered_events__flush(&trace->oe.data, OE_FLUSH__FINAL);
if (!err) { if (!err) {
if (trace->summary) if (trace->summary) {
if (trace->summary_mode == SUMMARY__BY_TOTAL)
trace__fprintf_total_summary(trace, trace->output);
else
trace__fprintf_thread_summary(trace, trace->output); trace__fprintf_thread_summary(trace, trace->output);
}
if (trace->show_tool_stats) { if (trace->show_tool_stats) {
fprintf(trace->output, "Stats:\n " fprintf(trace->output, "Stats:\n "
@ -4498,6 +4526,7 @@ static int trace__run(struct trace *trace, int argc, const char **argv)
} }
out_delete_evlist: out_delete_evlist:
delete_syscall_stats(trace->syscall_stats);
trace__symbols__exit(trace); trace__symbols__exit(trace);
evlist__free_syscall_tp_fields(evlist); evlist__free_syscall_tp_fields(evlist);
evlist__delete(evlist); evlist__delete(evlist);
@ -4625,6 +4654,12 @@ static int trace__replay(struct trace *trace)
evsel->handler = trace__pgfault; evsel->handler = trace__pgfault;
} }
if (trace->summary_mode == SUMMARY__BY_TOTAL) {
trace->syscall_stats = alloc_syscall_stats();
if (trace->syscall_stats == NULL)
goto out;
}
setup_pager(); setup_pager();
err = perf_session__process_events(session); err = perf_session__process_events(session);
@ -4635,12 +4670,13 @@ static int trace__replay(struct trace *trace)
trace__fprintf_thread_summary(trace, trace->output); trace__fprintf_thread_summary(trace, trace->output);
out: out:
delete_syscall_stats(trace->syscall_stats);
perf_session__delete(session); perf_session__delete(session);
return err; return err;
} }
static size_t trace__fprintf_threads_header(FILE *fp) static size_t trace__fprintf_summary_header(FILE *fp)
{ {
size_t printed; size_t printed;
@ -4663,19 +4699,19 @@ static int entry_cmp(const void *e1, const void *e2)
return entry1->msecs > entry2->msecs ? -1 : 1; return entry1->msecs > entry2->msecs ? -1 : 1;
} }
static struct syscall_entry *thread__sort_stats(struct thread_trace *ttrace) static struct syscall_entry *syscall__sort_stats(struct hashmap *syscall_stats)
{ {
struct syscall_entry *entry; struct syscall_entry *entry;
struct hashmap_entry *pos; struct hashmap_entry *pos;
unsigned bkt, i, nr; unsigned bkt, i, nr;
nr = ttrace->syscall_stats->sz; nr = syscall_stats->sz;
entry = malloc(nr * sizeof(*entry)); entry = malloc(nr * sizeof(*entry));
if (entry == NULL) if (entry == NULL)
return NULL; return NULL;
i = 0; i = 0;
hashmap__for_each_entry(ttrace->syscall_stats, pos, bkt) { hashmap__for_each_entry(syscall_stats, pos, bkt) {
struct syscall_stats *ss = pos->pvalue; struct syscall_stats *ss = pos->pvalue;
struct stats *st = &ss->stats; struct stats *st = &ss->stats;
@ -4690,14 +4726,14 @@ static struct syscall_entry *thread__sort_stats(struct thread_trace *ttrace)
return entry; return entry;
} }
static size_t thread__dump_stats(struct thread_trace *ttrace, static size_t syscall__dump_stats(struct trace *trace, FILE *fp,
struct trace *trace, FILE *fp) struct hashmap *syscall_stats)
{ {
size_t printed = 0; size_t printed = 0;
struct syscall *sc; struct syscall *sc;
struct syscall_entry *entries; struct syscall_entry *entries;
entries = thread__sort_stats(ttrace); entries = syscall__sort_stats(syscall_stats);
if (entries == NULL) if (entries == NULL)
return 0; return 0;
@ -4707,7 +4743,7 @@ static size_t thread__dump_stats(struct thread_trace *ttrace,
printed += fprintf(fp, " (msec) (msec) (msec) (msec) (%%)\n"); printed += fprintf(fp, " (msec) (msec) (msec) (msec) (%%)\n");
printed += fprintf(fp, " --------------- -------- ------ -------- --------- --------- --------- ------\n"); printed += fprintf(fp, " --------------- -------- ------ -------- --------- --------- --------- ------\n");
for (size_t i = 0; i < ttrace->syscall_stats->sz; i++) { for (size_t i = 0; i < syscall_stats->sz; i++) {
struct syscall_entry *entry = &entries[i]; struct syscall_entry *entry = &entries[i];
struct syscall_stats *stats = entry->stats; struct syscall_stats *stats = entry->stats;
@ -4744,6 +4780,17 @@ static size_t thread__dump_stats(struct thread_trace *ttrace,
return printed; return printed;
} }
static size_t thread__dump_stats(struct thread_trace *ttrace,
struct trace *trace, FILE *fp)
{
return syscall__dump_stats(trace, fp, ttrace->syscall_stats);
}
static size_t system__dump_stats(struct trace *trace, FILE *fp)
{
return syscall__dump_stats(trace, fp, trace->syscall_stats);
}
static size_t trace__fprintf_thread(FILE *fp, struct thread *thread, struct trace *trace) static size_t trace__fprintf_thread(FILE *fp, struct thread *thread, struct trace *trace)
{ {
size_t printed = 0; size_t printed = 0;
@ -4797,7 +4844,7 @@ static int trace_nr_events_cmp(void *priv __maybe_unused,
static size_t trace__fprintf_thread_summary(struct trace *trace, FILE *fp) static size_t trace__fprintf_thread_summary(struct trace *trace, FILE *fp)
{ {
size_t printed = trace__fprintf_threads_header(fp); size_t printed = trace__fprintf_summary_header(fp);
LIST_HEAD(threads); LIST_HEAD(threads);
if (machine__thread_list(trace->host, &threads) == 0) { if (machine__thread_list(trace->host, &threads) == 0) {
@ -4812,6 +4859,27 @@ static size_t trace__fprintf_thread_summary(struct trace *trace, FILE *fp)
return printed; return printed;
} }
static size_t trace__fprintf_total_summary(struct trace *trace, FILE *fp)
{
size_t printed = trace__fprintf_summary_header(fp);
printed += fprintf(fp, " total, ");
printed += fprintf(fp, "%lu events", trace->nr_events);
if (trace->pfmaj)
printed += fprintf(fp, ", %lu majfaults", trace->pfmaj);
if (trace->pfmin)
printed += fprintf(fp, ", %lu minfaults", trace->pfmin);
if (trace->sched)
printed += fprintf(fp, ", %.3f msec\n", trace->runtime_ms);
else if (fputc('\n', fp) != EOF)
++printed;
printed += system__dump_stats(trace, fp);
return printed;
}
static int trace__set_duration(const struct option *opt, const char *str, static int trace__set_duration(const struct option *opt, const char *str,
int unset __maybe_unused) int unset __maybe_unused)
{ {
@ -5083,6 +5151,23 @@ static int trace__parse_cgroups(const struct option *opt, const char *str, int u
return 0; return 0;
} }
static int trace__parse_summary_mode(const struct option *opt, const char *str,
int unset __maybe_unused)
{
struct trace *trace = opt->value;
if (!strcmp(str, "thread")) {
trace->summary_mode = SUMMARY__BY_THREAD;
} else if (!strcmp(str, "total")) {
trace->summary_mode = SUMMARY__BY_TOTAL;
} else {
pr_err("Unknown summary mode: %s\n", str);
return -1;
}
return 0;
}
static int trace__config(const char *var, const char *value, void *arg) static int trace__config(const char *var, const char *value, void *arg)
{ {
struct trace *trace = arg; struct trace *trace = arg;
@ -5230,6 +5315,9 @@ int cmd_trace(int argc, const char **argv)
"Show all syscalls and summary with statistics"), "Show all syscalls and summary with statistics"),
OPT_BOOLEAN(0, "errno-summary", &trace.errno_summary, OPT_BOOLEAN(0, "errno-summary", &trace.errno_summary,
"Show errno stats per syscall, use with -s or -S"), "Show errno stats per syscall, use with -s or -S"),
OPT_CALLBACK(0, "summary-mode", &trace, "mode",
"How to show summary: select thread (default) or total",
trace__parse_summary_mode),
OPT_CALLBACK_DEFAULT('F', "pf", &trace.trace_pgfaults, "all|maj|min", OPT_CALLBACK_DEFAULT('F', "pf", &trace.trace_pgfaults, "all|maj|min",
"Trace pagefaults", parse_pagefaults, "maj"), "Trace pagefaults", parse_pagefaults, "maj"),
OPT_BOOLEAN(0, "syscalls", &trace.trace_syscalls, "Trace syscalls"), OPT_BOOLEAN(0, "syscalls", &trace.trace_syscalls, "Trace syscalls"),
@ -5526,8 +5614,11 @@ int cmd_trace(int argc, const char **argv)
trace.summary = trace.summary_only; trace.summary = trace.summary_only;
/* Keep exited threads, otherwise information might be lost for summary */ /* Keep exited threads, otherwise information might be lost for summary */
if (trace.summary) if (trace.summary) {
symbol_conf.keep_exited_threads = true; symbol_conf.keep_exited_threads = true;
if (trace.summary_mode == SUMMARY__NONE)
trace.summary_mode = SUMMARY__BY_THREAD;
}
if (output_name != NULL) { if (output_name != NULL) {
err = trace__open_output(&trace, output_name); err = trace__open_output(&trace, output_name);