From nobody Tue Jun 16 03:28:37 2026 Return-Path: X-Spam-Checker-Version: SpamAssassin 3.4.0 (2014-02-07) on aws-us-west-2-korg-lkml-1.web.codeaurora.org Received: from vger.kernel.org (vger.kernel.org [23.128.96.18]) by smtp.lore.kernel.org (Postfix) with ESMTP id BC83CC433F5 for ; Wed, 20 Apr 2022 10:24:40 +0000 (UTC) Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand id S1377635AbiDTK1X (ORCPT ); Wed, 20 Apr 2022 06:27:23 -0400 Received: from lindbergh.monkeyblade.net ([23.128.96.19]:56228 "EHLO lindbergh.monkeyblade.net" rhost-flags-OK-OK-OK-OK) by vger.kernel.org with ESMTP id S1348560AbiDTK1Q (ORCPT ); Wed, 20 Apr 2022 06:27:16 -0400 Received: from euporie.uberspace.de (euporie.uberspace.de [185.26.156.232]) by lindbergh.monkeyblade.net (Postfix) with ESMTPS id C3F153F32A for ; Wed, 20 Apr 2022 03:24:29 -0700 (PDT) Received: (qmail 15638 invoked by uid 989); 20 Apr 2022 10:24:27 -0000 Authentication-Results: euporie.uberspace.de; auth=pass (plain) From: Florian Fischer To: linux-perf-users@vger.kernel.org Cc: Ian Rogers , Xing Zhengjun , linux-kernel@vger.kernel.org, Peter Zijlstra , Ingo Molnar , Arnaldo Carvalho de Melo , Florian Fischer Subject: [PATCH v4 1/3] perf stat: introduce stats for the user and system rusage times Date: Wed, 20 Apr 2022 12:23:52 +0200 Message-Id: <20220420102354.468173-2-florian.fischer@muhq.space> X-Mailer: git-send-email 2.36.0 In-Reply-To: <20220420102354.468173-1-florian.fischer@muhq.space> References: <20220420102354.468173-1-florian.fischer@muhq.space> MIME-Version: 1.0 Content-Transfer-Encoding: quoted-printable X-Rspamd-Bar: ----- X-Rspamd-Report: R_MISSING_CHARSET(0.5) MIME_GOOD(-0.1) REPLY(-4) MID_CONTAINS_FROM(1) BAYES_HAM(-2.999999) X-Rspamd-Score: -5.599999 Received: from unknown (HELO unkown) (::1) by euporie.uberspace.de (Haraka/2.8.28) with ESMTPSA; Wed, 20 Apr 2022 12:24:27 +0200 Precedence: bulk List-ID: X-Mailing-List: linux-kernel@vger.kernel.org Content-Type: text/plain; charset="utf-8" This is preparation for exporting rusage values as tool events. Add new global stats tracking the values obtained via rusage. For now only ru_utime and ru_stime are part of the tracked stats. Both are stored as nanoseconds to be consistent with 'duration_time', although the finest resolution the struct timeval data in rusage provides are microseconds. Signed-off-by: Florian Fischer --- tools/perf/builtin-stat.c | 5 ++++- tools/perf/util/stat-shadow.c | 2 ++ tools/perf/util/stat.h | 21 +++++++++++++++++++++ 3 files changed, 27 insertions(+), 1 deletion(-) diff --git a/tools/perf/builtin-stat.c b/tools/perf/builtin-stat.c index a96f106dc93a..61faffb535f5 100644 --- a/tools/perf/builtin-stat.c +++ b/tools/perf/builtin-stat.c @@ -216,6 +216,7 @@ static struct perf_stat_config stat_config =3D { .run_count =3D 1, .metric_only_len =3D METRIC_ONLY_LEN, .walltime_nsecs_stats =3D &walltime_nsecs_stats, + .ru_stats =3D &ru_stats, .big_num =3D true, .ctl_fd =3D -1, .ctl_fd_ack =3D -1, @@ -1010,8 +1011,10 @@ static int __run_perf_stat(int argc, const char **ar= gv, int run_idx) evlist__reset_prev_raw_counts(evsel_list); runtime_stat_reset(&stat_config); perf_stat__reset_shadow_per_stat(&rt_stat); - } else + } else { update_stats(&walltime_nsecs_stats, t1 - t0); + update_rusage_stats(&ru_stats, &stat_config.ru_data); + } =20 /* * Closing a group leader splits the group, and as we only disable diff --git a/tools/perf/util/stat-shadow.c b/tools/perf/util/stat-shadow.c index 10af7804e482..ea4c35e4f1da 100644 --- a/tools/perf/util/stat-shadow.c +++ b/tools/perf/util/stat-shadow.c @@ -26,6 +26,7 @@ =20 struct runtime_stat rt_stat; struct stats walltime_nsecs_stats; +struct rusage_stats ru_stats; =20 struct saved_value { struct rb_node rb_node; @@ -199,6 +200,7 @@ void perf_stat__reset_shadow_stats(void) { reset_stat(&rt_stat); memset(&walltime_nsecs_stats, 0, sizeof(walltime_nsecs_stats)); + memset(&ru_stats, 0, sizeof(ru_stats)); } =20 void perf_stat__reset_shadow_per_stat(struct runtime_stat *st) diff --git a/tools/perf/util/stat.h b/tools/perf/util/stat.h index 335d19cc3063..e31c94d952e9 100644 --- a/tools/perf/util/stat.h +++ b/tools/perf/util/stat.h @@ -108,6 +108,11 @@ struct runtime_stat { struct rblist value_list; }; =20 +struct rusage_stats { + struct stats ru_utime_usec_stat; + struct stats ru_stime_usec_stat; +}; + typedef struct aggr_cpu_id (*aggr_get_id_t)(struct perf_stat_config *confi= g, struct perf_cpu cpu); =20 struct perf_stat_config { @@ -148,6 +153,7 @@ struct perf_stat_config { const char *csv_sep; struct stats *walltime_nsecs_stats; struct rusage ru_data; + struct rusage_stats *ru_stats; struct cpu_aggr_map *aggr_map; aggr_get_id_t aggr_get_id; struct cpu_aggr_map *cpus_aggr_map; @@ -177,6 +183,20 @@ static inline void init_stats(struct stats *stats) stats->max =3D 0; } =20 +static inline void init_rusage_stats(struct rusage_stats *ru_stats) { + init_stats(&ru_stats->ru_utime_usec_stat); + init_stats(&ru_stats->ru_stime_usec_stat); +} + +static inline void update_rusage_stats(struct rusage_stats *ru_stats, stru= ct rusage* rusage) { + const u64 us_to_ns =3D 1000; + const u64 s_to_ns =3D 1000000000; + update_stats(&ru_stats->ru_utime_usec_stat, + (rusage->ru_utime.tv_usec * us_to_ns + rusage->ru_utime.tv_s= ec * s_to_ns)); + update_stats(&ru_stats->ru_stime_usec_stat, + (rusage->ru_stime.tv_usec * us_to_ns + rusage->ru_stime.tv_s= ec * s_to_ns)); +} + struct evsel; struct evlist; =20 @@ -196,6 +216,7 @@ bool __perf_stat_evsel__is(struct evsel *evsel, enum pe= rf_stat_evsel_id id); =20 extern struct runtime_stat rt_stat; extern struct stats walltime_nsecs_stats; +extern struct rusage_stats ru_stats; =20 typedef void (*print_metric_t)(struct perf_stat_config *config, void *ctx, const char *color, const char *unit, --=20 2.36.0 From nobody Tue Jun 16 03:28:37 2026 Return-Path: X-Spam-Checker-Version: SpamAssassin 3.4.0 (2014-02-07) on aws-us-west-2-korg-lkml-1.web.codeaurora.org Received: from vger.kernel.org (vger.kernel.org [23.128.96.18]) by smtp.lore.kernel.org (Postfix) with ESMTP id AA209C433EF for ; Wed, 20 Apr 2022 10:25:59 +0000 (UTC) Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand id S1377671AbiDTK12 (ORCPT ); Wed, 20 Apr 2022 06:27:28 -0400 Received: from lindbergh.monkeyblade.net ([23.128.96.19]:56234 "EHLO lindbergh.monkeyblade.net" rhost-flags-OK-OK-OK-OK) by vger.kernel.org with ESMTP id S1349965AbiDTK1Q (ORCPT ); Wed, 20 Apr 2022 06:27:16 -0400 Received: from euporie.uberspace.de (euporie.uberspace.de [185.26.156.232]) by lindbergh.monkeyblade.net (Postfix) with ESMTPS id 3339A3F338 for ; Wed, 20 Apr 2022 03:24:29 -0700 (PDT) Received: (qmail 15688 invoked by uid 989); 20 Apr 2022 10:24:28 -0000 Authentication-Results: euporie.uberspace.de; auth=pass (plain) From: Florian Fischer To: linux-perf-users@vger.kernel.org Cc: Ian Rogers , Xing Zhengjun , linux-kernel@vger.kernel.org, Peter Zijlstra , Ingo Molnar , Arnaldo Carvalho de Melo , Florian Fischer Subject: [PATCH v4 2/3] perf stat: add user_time and system_time events Date: Wed, 20 Apr 2022 12:23:53 +0200 Message-Id: <20220420102354.468173-3-florian.fischer@muhq.space> X-Mailer: git-send-email 2.36.0 In-Reply-To: <20220420102354.468173-1-florian.fischer@muhq.space> References: <20220420102354.468173-1-florian.fischer@muhq.space> MIME-Version: 1.0 Content-Transfer-Encoding: quoted-printable X-Rspamd-Bar: ----- X-Rspamd-Report: R_MISSING_CHARSET(0.5) MIME_GOOD(-0.1) REPLY(-4) MID_CONTAINS_FROM(1) BAYES_HAM(-2.984822) X-Rspamd-Score: -5.584822 Received: from unknown (HELO unkown) (::1) by euporie.uberspace.de (Haraka/2.8.28) with ESMTPSA; Wed, 20 Apr 2022 12:24:28 +0200 Precedence: bulk List-ID: X-Mailing-List: linux-kernel@vger.kernel.org Content-Type: text/plain; charset="utf-8" It bothered me that during benchmarking using perf stat (to collect for example CPU cache events) I could not simultaneously retrieve the times spend in user or kernel mode in a machine readable format. When running perf stat the output for humans contains the times reported by rusage and wait4. $ perf stat -e cache-misses:u -- true Performance counter stats for 'true': 4,206 cache-misses:u 0.001113619 seconds time elapsed 0.001175000 seconds user 0.000000000 seconds sys But perf stat's machine-readable format does not provide this information. $ perf stat -x, -e cache-misses:u -- true 4282,,cache-misses:u,492859,100.00,, I found no way to retrieve this information using the available events while using machine-readable output. This patch adds two new tool internal events 'user_time' and 'system_time', similarly to the already present 'duration_time' event. Both events use the already collected rusage information obtained by wait4 and tracked in the global ru_stats. Examples presenting cache-misses and rusage information in both human and machine-readable form: $ ./perf stat -e duration_time,user_time,system_time,cache-misses -- grep -= q -r duration_time . Performance counter stats for 'grep -q -r duration_time .': 67,422,542 ns duration_time:u 50,517,000 ns user_time:u 16,839,000 ns system_time:u 30,937 cache-misses:u 0.067422542 seconds time elapsed 0.050517000 seconds user 0.016839000 seconds sys $ ./perf stat -x, -e duration_time,user_time,system_time,cache-misses -- gr= ep -q -r duration_time . 72134524,ns,duration_time:u,72134524,100.00,, 65225000,ns,user_time:u,65225000,100.00,, 6865000,ns,system_time:u,6865000,100.00,, 38705,,cache-misses:u,71189328,100.00,, Signed-off-by: Florian Fischer --- tools/perf/builtin-stat.c | 36 ++++++++++++++++++++++++++-------- tools/perf/util/evsel.h | 4 ++++ tools/perf/util/parse-events.c | 4 +++- tools/perf/util/parse-events.l | 2 ++ 4 files changed, 37 insertions(+), 9 deletions(-) diff --git a/tools/perf/builtin-stat.c b/tools/perf/builtin-stat.c index 61faffb535f5..dea34c8990ae 100644 --- a/tools/perf/builtin-stat.c +++ b/tools/perf/builtin-stat.c @@ -342,15 +342,35 @@ static int evsel__write_stat_event(struct evsel *coun= ter, int cpu_map_idx, u32 t static int read_single_counter(struct evsel *counter, int cpu_map_idx, int thread, struct timespec *rs) { - if (counter->tool_event =3D=3D PERF_TOOL_DURATION_TIME) { - u64 val =3D rs->tv_nsec + rs->tv_sec*1000000000ULL; - struct perf_counts_values *count =3D - perf_counts(counter->counts, cpu_map_idx, thread); - count->ena =3D count->run =3D val; - count->val =3D val; - return 0; + switch(counter->tool_event) { + case PERF_TOOL_DURATION_TIME: { + u64 val =3D rs->tv_nsec + rs->tv_sec*1000000000ULL; + struct perf_counts_values *count =3D + perf_counts(counter->counts, cpu_map_idx, thread); + count->ena =3D count->run =3D val; + count->val =3D val; + return 0; + } + case PERF_TOOL_USER_TIME: + case PERF_TOOL_SYSTEM_TIME: { + u64 val; + struct perf_counts_values *count =3D + perf_counts(counter->counts, cpu_map_idx, thread); + if (counter->tool_event =3D=3D PERF_TOOL_USER_TIME) + val =3D ru_stats.ru_utime_usec_stat.mean; + else + val =3D ru_stats.ru_stime_usec_stat.mean; + count->ena =3D count->run =3D val; + count->val =3D val; + return 0; + } + default: + case PERF_TOOL_NONE: + return evsel__read_counter(counter, cpu_map_idx, thread); + case PERF_TOOL_MAX: + /* This should never be reached */ + return 0; } - return evsel__read_counter(counter, cpu_map_idx, thread); } =20 /* diff --git a/tools/perf/util/evsel.h b/tools/perf/util/evsel.h index 041b42d33bf5..7e2209b47b39 100644 --- a/tools/perf/util/evsel.h +++ b/tools/perf/util/evsel.h @@ -30,6 +30,10 @@ typedef int (evsel__sb_cb_t)(union perf_event *event, vo= id *data); enum perf_tool_event { PERF_TOOL_NONE =3D 0, PERF_TOOL_DURATION_TIME =3D 1, + PERF_TOOL_USER_TIME =3D 2, + PERF_TOOL_SYSTEM_TIME =3D 3, + + PERF_TOOL_MAX, }; =20 /** struct evsel - event selector diff --git a/tools/perf/util/parse-events.c b/tools/perf/util/parse-events.c index dd84fed698a3..064ec368a90b 100644 --- a/tools/perf/util/parse-events.c +++ b/tools/perf/util/parse-events.c @@ -402,7 +402,9 @@ static int add_event_tool(struct list_head *list, int *= idx, if (!evsel) return -ENOMEM; evsel->tool_event =3D tool_event; - if (tool_event =3D=3D PERF_TOOL_DURATION_TIME) { + if (tool_event =3D=3D PERF_TOOL_DURATION_TIME + || tool_event =3D=3D PERF_TOOL_USER_TIME + || tool_event =3D=3D PERF_TOOL_SYSTEM_TIME) { free((char *)evsel->unit); evsel->unit =3D strdup("ns"); } diff --git a/tools/perf/util/parse-events.l b/tools/perf/util/parse-events.l index 5b6e4b5249cf..3a9ce96c8bce 100644 --- a/tools/perf/util/parse-events.l +++ b/tools/perf/util/parse-events.l @@ -353,6 +353,8 @@ alignment-faults { return sym(yyscanner, PERF_TYPE_S= OFTWARE, PERF_COUNT_SW_AL emulation-faults { return sym(yyscanner, PERF_TYPE_SOFTWARE, PERF_COUNT= _SW_EMULATION_FAULTS); } dummy { return sym(yyscanner, PERF_TYPE_SOFTWARE, PERF_COUNT_SW_DUMMY= ); } duration_time { return tool(yyscanner, PERF_TOOL_DURATION_TIME); } +user_time { return tool(yyscanner, PERF_TOOL_USER_TIME); } +system_time { return tool(yyscanner, PERF_TOOL_SYSTEM_TIME); } bpf-output { return sym(yyscanner, PERF_TYPE_SOFTWARE, PERF_COUNT_SW_B= PF_OUTPUT); } cgroup-switches { return sym(yyscanner, PERF_TYPE_SOFTWARE, PERF_COUNT= _SW_CGROUP_SWITCHES); } =20 --=20 2.36.0 From nobody Tue Jun 16 03:28:37 2026 Return-Path: X-Spam-Checker-Version: SpamAssassin 3.4.0 (2014-02-07) on aws-us-west-2-korg-lkml-1.web.codeaurora.org Received: from vger.kernel.org (vger.kernel.org [23.128.96.18]) by smtp.lore.kernel.org (Postfix) with ESMTP id 0ADF2C433FE for ; Wed, 20 Apr 2022 10:26:00 +0000 (UTC) Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand id S1377684AbiDTK1a (ORCPT ); Wed, 20 Apr 2022 06:27:30 -0400 Received: from lindbergh.monkeyblade.net ([23.128.96.19]:56264 "EHLO lindbergh.monkeyblade.net" rhost-flags-OK-OK-OK-OK) by vger.kernel.org with ESMTP id S1359472AbiDTK1R (ORCPT ); Wed, 20 Apr 2022 06:27:17 -0400 Received: from euporie.uberspace.de (euporie.uberspace.de [185.26.156.232]) by lindbergh.monkeyblade.net (Postfix) with ESMTPS id 789753F885 for ; Wed, 20 Apr 2022 03:24:31 -0700 (PDT) Received: (qmail 15788 invoked by uid 989); 20 Apr 2022 10:24:29 -0000 Authentication-Results: euporie.uberspace.de; auth=pass (plain) From: Florian Fischer To: linux-perf-users@vger.kernel.org Cc: Ian Rogers , Xing Zhengjun , linux-kernel@vger.kernel.org, Peter Zijlstra , Ingo Molnar , Arnaldo Carvalho de Melo , Florian Fischer Subject: [PATCH v4 3/3] perf list: print all available tool events Date: Wed, 20 Apr 2022 12:23:54 +0200 Message-Id: <20220420102354.468173-4-florian.fischer@muhq.space> X-Mailer: git-send-email 2.36.0 In-Reply-To: <20220420102354.468173-1-florian.fischer@muhq.space> References: <20220420102354.468173-1-florian.fischer@muhq.space> MIME-Version: 1.0 Content-Transfer-Encoding: quoted-printable X-Rspamd-Bar: ----- X-Rspamd-Report: R_MISSING_CHARSET(0.5) MIME_GOOD(-0.1) REPLY(-4) MID_CONTAINS_FROM(1) BAYES_HAM(-2.968525) X-Rspamd-Score: -5.568525 Received: from unknown (HELO unkown) (::1) by euporie.uberspace.de (Haraka/2.8.28) with ESMTPSA; Wed, 20 Apr 2022 12:24:29 +0200 Precedence: bulk List-ID: X-Mailing-List: linux-kernel@vger.kernel.org Content-Type: text/plain; charset="utf-8" Introduce names for the new tool events 'user_time' and 'system_time'. Signed-off-by: Florian Fischer --- tools/perf/util/evsel.c | 19 ++++++++++------ tools/perf/util/evsel.h | 1 + tools/perf/util/parse-events.c | 40 +++++++++++++++++++++++++++++----- 3 files changed, 47 insertions(+), 13 deletions(-) diff --git a/tools/perf/util/evsel.c b/tools/perf/util/evsel.c index 2a1729e7aee4..d38722560e80 100644 --- a/tools/perf/util/evsel.c +++ b/tools/perf/util/evsel.c @@ -597,6 +597,17 @@ static int evsel__sw_name(struct evsel *evsel, char *b= f, size_t size) return r + evsel__add_modifiers(evsel, bf + r, size - r); } =20 +const char *evsel__tool_names[PERF_TOOL_MAX] =3D { + "duration_time", + "user_time", + "system_time", +}; + +static int evsel__tool_name(enum perf_tool_event ev, char *bf, size_t size) +{ + return scnprintf(bf, size, "%s", evsel__tool_names[ev]); +} + static int __evsel__bp_name(char *bf, size_t size, u64 addr, u64 type) { int r; @@ -723,12 +734,6 @@ static int evsel__raw_name(struct evsel *evsel, char *= bf, size_t size) return ret + evsel__add_modifiers(evsel, bf + ret, size - ret); } =20 -static int evsel__tool_name(char *bf, size_t size) -{ - int ret =3D scnprintf(bf, size, "duration_time"); - return ret; -} - const char *evsel__name(struct evsel *evsel) { char bf[128]; @@ -754,7 +759,7 @@ const char *evsel__name(struct evsel *evsel) =20 case PERF_TYPE_SOFTWARE: if (evsel->tool_event) - evsel__tool_name(bf, sizeof(bf)); + evsel__tool_name(evsel->tool_event, bf, sizeof(bf)); else evsel__sw_name(evsel, bf, sizeof(bf)); break; diff --git a/tools/perf/util/evsel.h b/tools/perf/util/evsel.h index 7e2209b47b39..45d674812239 100644 --- a/tools/perf/util/evsel.h +++ b/tools/perf/util/evsel.h @@ -262,6 +262,7 @@ extern const char *evsel__hw_cache_op[PERF_COUNT_HW_CAC= HE_OP_MAX][EVSEL__MAX_ALI extern const char *evsel__hw_cache_result[PERF_COUNT_HW_CACHE_RESULT_MAX][= EVSEL__MAX_ALIASES]; extern const char *evsel__hw_names[PERF_COUNT_HW_MAX]; extern const char *evsel__sw_names[PERF_COUNT_SW_MAX]; +extern const char *evsel__tool_names[PERF_TOOL_MAX]; extern char *evsel__bpf_counter_events; bool evsel__match_bpf_counter_events(const char *name); =20 diff --git a/tools/perf/util/parse-events.c b/tools/perf/util/parse-events.c index 064ec368a90b..c0e88d3b3e3c 100644 --- a/tools/perf/util/parse-events.c +++ b/tools/perf/util/parse-events.c @@ -154,6 +154,21 @@ struct event_symbol event_symbols_sw[PERF_COUNT_SW_MAX= ] =3D { }, }; =20 +struct event_symbol event_symbols_tool[PERF_TOOL_MAX] =3D { + [PERF_TOOL_DURATION_TIME] =3D { + .symbol =3D "duration_time", + .alias =3D "", + }, + [PERF_TOOL_USER_TIME] =3D { + .symbol =3D "user_time", + .alias =3D "", + }, + [PERF_TOOL_SYSTEM_TIME] =3D { + .symbol =3D "system_time", + .alias =3D "", + }, +}; + #define __PERF_EVENT_FIELD(config, name) \ ((config & PERF_EVENT_##name##_MASK) >> PERF_EVENT_##name##_SHIFT) =20 @@ -3058,21 +3073,34 @@ int print_hwcache_events(const char *event_glob, bo= ol name_only) return evt_num; } =20 -static void print_tool_event(const char *name, const char *event_glob, +static void print_tool_event(const struct event_symbol *syms, const char *= event_glob, bool name_only) { - if (event_glob && !strglobmatch(name, event_glob)) + if (syms->symbol =3D=3D NULL) + return; + + if (event_glob && !(strglobmatch(syms->symbol, event_glob) || + (syms->alias && strglobmatch(syms->alias, event_glob)))) return; + if (name_only) - printf("%s ", name); - else + printf("%s ", syms->symbol); + else { + char name[MAX_NAME_LEN]; + if (syms->alias) + snprintf(name, MAX_NAME_LEN, "%s OR %s", syms->symbol, syms->alias); + else + strlcpy(name, syms->symbol, MAX_NAME_LEN); printf(" %-50s [%s]\n", name, "Tool event"); - + } } =20 void print_tool_events(const char *event_glob, bool name_only) { - print_tool_event("duration_time", event_glob, name_only); + // Start at 1 because the first enum entry symbols no tool event + for (int i =3D 1; i < PERF_TOOL_MAX; ++i) { + print_tool_event(event_symbols_tool + i, event_glob, name_only); + } if (pager_in_use()) printf("\n"); } --=20 2.36.0