| lists.openwall.net | lists / announce owl-users owl-dev john-users john-dev passwdqc-users yescrypt popa3d-users / oss-security kernel-hardening musl sabotage tlsify passwords / crypt-dev xvendor / Bugtraq Full-Disclosure linux-kernel linux-netdev linux-ext4 linux-hardening linux-cve-announce PHC | |
|
Open Source and information security mailing list archives
| ||
|
Message-ID: <CAP-5=fX8ubOJJ7cauDAL8giVGz2uhr0GqOZUpQEOHTkYndvngA@mail.gmail.com>
Date: Tue, 26 Apr 2022 18:37:24 -0700
From: Ian Rogers <irogers@...gle.com>
To: Florian Fischer <florian.fischer@...q.space>
Cc: linux-perf-users@...r.kernel.org,
Xing Zhengjun <zhengjun.xing@...ux.intel.com>,
linux-kernel@...r.kernel.org,
Peter Zijlstra <peterz@...radead.org>,
Ingo Molnar <mingo@...hat.com>,
Arnaldo Carvalho de Melo <acme@...nel.org>
Subject: Re: [PATCH v4 2/3] perf stat: add user_time and system_time events
On Wed, Apr 20, 2022 at 3:24 AM Florian Fischer
<florian.fischer@...q.space> wrote:
>
> 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
nit: Are the :u on the *_time accurate here?
> 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 -- grep -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,,
nit: Similarly.
> Signed-off-by: Florian Fischer <florian.fischer@...q.space>
> ---
> 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 *counter, 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 == PERF_TOOL_DURATION_TIME) {
> - u64 val = rs->tv_nsec + rs->tv_sec*1000000000ULL;
> - struct perf_counts_values *count =
> - perf_counts(counter->counts, cpu_map_idx, thread);
> - count->ena = count->run = val;
> - count->val = val;
> - return 0;
When this was 1 tool event I think the if was okay, I think now we
should move the reading of the tool events to their own helper like
evsel__read_counter. Perhaps evsel__read_tool.
Thanks,
Ian
> + switch(counter->tool_event) {
> + case PERF_TOOL_DURATION_TIME: {
> + u64 val = rs->tv_nsec + rs->tv_sec*1000000000ULL;
> + struct perf_counts_values *count =
> + perf_counts(counter->counts, cpu_map_idx, thread);
> + count->ena = count->run = val;
> + count->val = val;
> + return 0;
> + }
> + case PERF_TOOL_USER_TIME:
> + case PERF_TOOL_SYSTEM_TIME: {
> + u64 val;
> + struct perf_counts_values *count =
> + perf_counts(counter->counts, cpu_map_idx, thread);
> + if (counter->tool_event == PERF_TOOL_USER_TIME)
> + val = ru_stats.ru_utime_usec_stat.mean;
> + else
> + val = ru_stats.ru_stime_usec_stat.mean;
> + count->ena = count->run = val;
> + count->val = 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);
> }
>
> /*
> 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, void *data);
> enum perf_tool_event {
> PERF_TOOL_NONE = 0,
> PERF_TOOL_DURATION_TIME = 1,
> + PERF_TOOL_USER_TIME = 2,
> + PERF_TOOL_SYSTEM_TIME = 3,
> +
> + PERF_TOOL_MAX,
> };
>
> /** 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 = tool_event;
> - if (tool_event == PERF_TOOL_DURATION_TIME) {
> + if (tool_event == PERF_TOOL_DURATION_TIME
> + || tool_event == PERF_TOOL_USER_TIME
> + || tool_event == PERF_TOOL_SYSTEM_TIME) {
> free((char *)evsel->unit);
> evsel->unit = 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_SOFTWARE, 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_BPF_OUTPUT); }
> cgroup-switches { return sym(yyscanner, PERF_TYPE_SOFTWARE, PERF_COUNT_SW_CGROUP_SWITCHES); }
>
> --
> 2.36.0
>
Powered by blists - more mailing lists