From fc00897c8a3f7f57144e6e77b34e9d5020af719f Mon Sep 17 00:00:00 2001 From: Namhyung Kim Date: Wed, 5 Feb 2025 12:54:43 -0800 Subject: [PATCH] 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 Acked-by: Arnaldo Carvalho de Melo Tested-by: Arnaldo Carvalho de Melo Link: https://lore.kernel.org/r/20250205205443.1986408-5-namhyung@kernel.org Signed-off-by: Namhyung Kim --- tools/perf/Documentation/perf-trace.txt | 4 + tools/perf/builtin-trace.c | 129 ++++++++++++++++++++---- 2 files changed, 114 insertions(+), 19 deletions(-) diff --git a/tools/perf/Documentation/perf-trace.txt b/tools/perf/Documentation/perf-trace.txt index fb3d2af33844..887dc37773d0 100644 --- a/tools/perf/Documentation/perf-trace.txt +++ b/tools/perf/Documentation/perf-trace.txt @@ -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 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:: 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. diff --git a/tools/perf/builtin-trace.c b/tools/perf/builtin-trace.c index a2bab8016fcf..dbf513f9e478 100644 --- a/tools/perf/builtin-trace.c +++ b/tools/perf/builtin-trace.c @@ -139,6 +139,12 @@ struct syscall_fmt { bool hexret; }; +enum summary_mode { + SUMMARY__NONE = 0, + SUMMARY__BY_TOTAL, + SUMMARY__BY_THREAD, +}; + struct trace { struct perf_tool tool; struct syscalltbl *sctbl; @@ -177,14 +183,17 @@ struct trace { pid_t *entries; struct bpf_map *map; } filter_pids; + struct hashmap *syscall_stats; double duration_filter; double runtime_ms; + unsigned long pfmaj, pfmin; struct { u64 vfs_getname, proc_getname; } stats; unsigned int max_stack; unsigned int min_stack; + enum summary_mode summary_mode; int raw_augmented_syscalls_args_size; bool raw_augmented_syscalls; bool fd_path_disabled; @@ -2496,18 +2505,23 @@ struct syscall_stats { }; 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; 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)); if (stats == NULL) return; init_stats(&stats->stats); - if (hashmap__add(ttrace->syscall_stats, id, stats) < 0) { + if (hashmap__add(syscall_stats, id, stats) < 0) { free(stats); return; } @@ -2521,7 +2535,7 @@ static void thread__update_stats(struct thread *thread, struct thread_trace *ttr if (err < 0) { ++stats->nr_failures; - if (!errno_summary) + if (!trace->errno_summary) return; 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); 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) { trace__set_fd_pathname(thread, ret, ttrace->filename.name); @@ -3251,10 +3265,13 @@ static int trace__pgfault(struct trace *trace, if (ttrace == NULL) 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++; - else + trace->pfmaj++; + } else { ttrace->pfmin++; + trace->pfmin++; + } if (trace->summary_only) goto out; @@ -3413,6 +3430,7 @@ out_free: } 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) { @@ -4325,6 +4343,12 @@ static int trace__run(struct trace *trace, int argc, const char **argv) 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); if (forks) { @@ -4485,8 +4509,12 @@ out_disable: ordered_events__flush(&trace->oe.data, OE_FLUSH__FINAL); if (!err) { - if (trace->summary) - trace__fprintf_thread_summary(trace, trace->output); + 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); + } if (trace->show_tool_stats) { fprintf(trace->output, "Stats:\n " @@ -4498,6 +4526,7 @@ out_disable: } out_delete_evlist: + delete_syscall_stats(trace->syscall_stats); trace__symbols__exit(trace); evlist__free_syscall_tp_fields(evlist); evlist__delete(evlist); @@ -4625,6 +4654,12 @@ static int trace__replay(struct trace *trace) 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(); err = perf_session__process_events(session); @@ -4635,12 +4670,13 @@ static int trace__replay(struct trace *trace) trace__fprintf_thread_summary(trace, trace->output); out: + delete_syscall_stats(trace->syscall_stats); perf_session__delete(session); return err; } -static size_t trace__fprintf_threads_header(FILE *fp) +static size_t trace__fprintf_summary_header(FILE *fp) { size_t printed; @@ -4663,19 +4699,19 @@ static int entry_cmp(const void *e1, const void *e2) 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 hashmap_entry *pos; unsigned bkt, i, nr; - nr = ttrace->syscall_stats->sz; + nr = syscall_stats->sz; entry = malloc(nr * sizeof(*entry)); if (entry == NULL) return NULL; 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 stats *st = &ss->stats; @@ -4690,14 +4726,14 @@ static struct syscall_entry *thread__sort_stats(struct thread_trace *ttrace) return entry; } -static size_t thread__dump_stats(struct thread_trace *ttrace, - struct trace *trace, FILE *fp) +static size_t syscall__dump_stats(struct trace *trace, FILE *fp, + struct hashmap *syscall_stats) { size_t printed = 0; struct syscall *sc; struct syscall_entry *entries; - entries = thread__sort_stats(ttrace); + entries = syscall__sort_stats(syscall_stats); if (entries == NULL) 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, " --------------- -------- ------ -------- --------- --------- --------- ------\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_stats *stats = entry->stats; @@ -4744,6 +4780,17 @@ static size_t thread__dump_stats(struct thread_trace *ttrace, 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) { 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) { - size_t printed = trace__fprintf_threads_header(fp); + size_t printed = trace__fprintf_summary_header(fp); LIST_HEAD(threads); 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; } +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, int unset __maybe_unused) { @@ -5083,6 +5151,23 @@ static int trace__parse_cgroups(const struct option *opt, const char *str, int u 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) { struct trace *trace = arg; @@ -5230,6 +5315,9 @@ int cmd_trace(int argc, const char **argv) "Show all syscalls and summary with statistics"), OPT_BOOLEAN(0, "errno-summary", &trace.errno_summary, "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", "Trace pagefaults", parse_pagefaults, "maj"), OPT_BOOLEAN(0, "syscalls", &trace.trace_syscalls, "Trace syscalls"), @@ -5526,8 +5614,11 @@ init_augmented_syscall_tp: trace.summary = trace.summary_only; /* Keep exited threads, otherwise information might be lost for summary */ - if (trace.summary) + if (trace.summary) { symbol_conf.keep_exited_threads = true; + if (trace.summary_mode == SUMMARY__NONE) + trace.summary_mode = SUMMARY__BY_THREAD; + } if (output_name != NULL) { err = trace__open_output(&trace, output_name); -- 2.50.1