From: Arnaldo Carvalho de Melo <acme@kernel.org>
To: Namhyung Kim <namhyung@kernel.org>
Cc: Ian Rogers <irogers@google.com>,
Kan Liang <kan.liang@linux.intel.com>,
Jiri Olsa <jolsa@kernel.org>,
Adrian Hunter <adrian.hunter@intel.com>,
Peter Zijlstra <peterz@infradead.org>,
Ingo Molnar <mingo@kernel.org>,
LKML <linux-kernel@vger.kernel.org>,
linux-perf-users@vger.kernel.org,
James Clark <james.clark@linaro.org>,
Gabriele Monaco <gmonaco@redhat.com>,
Clark Williams <williams@redhat.com>
Subject: Re: [PATCH v2 1/3] perf ftrace: Display latency statistics at the end
Date: Wed, 8 Jan 2025 11:56:51 -0300 [thread overview]
Message-ID: <Z36SM3m2QP5HSiev@x1> (raw)
In-Reply-To: <20250107224352.1128669-1-namhyung@kernel.org>
On Tue, Jan 07, 2025 at 02:43:50PM -0800, Namhyung Kim wrote:
> Sometimes users also want to see average latency as well as histogram.
> Display latency statistics like avg, max, min at the end.
Thanks, applied to perf-tools-next, also CCing Gabriele, since he did
work on this tool recently.
- Arnaldo
> $ sudo ./perf ftrace latency -ab -T synchronize_rcu -- ...
> # DURATION | COUNT | GRAPH |
> 0 - 1 us | 0 | |
> 1 - 2 us | 0 | |
> 2 - 4 us | 0 | |
> 4 - 8 us | 0 | |
> 8 - 16 us | 0 | |
> 16 - 32 us | 0 | |
> 32 - 64 us | 0 | |
> 64 - 128 us | 0 | |
> 128 - 256 us | 0 | |
> 256 - 512 us | 0 | |
> 512 - 1024 us | 0 | |
> 1 - 2 ms | 0 | |
> 2 - 4 ms | 0 | |
> 4 - 8 ms | 0 | |
> 8 - 16 ms | 1 | ##### |
> 16 - 32 ms | 7 | ######################################## |
> 32 - 64 ms | 0 | |
> 64 - 128 ms | 0 | |
> 128 - 256 ms | 0 | |
> 256 - 512 ms | 0 | |
> 512 - 1024 ms | 0 | |
> 1 - ... s | 0 | |
>
> # statistics (in usec)
> total time: 171832
> avg time: 21479
> max time: 30906
> min time: 15869
> count: 8
>
> Reviewed-by: James Clark <james.clark@linaro.org>
> Signed-off-by: Namhyung Kim <namhyung@kernel.org>
> ---
> tools/perf/builtin-ftrace.c | 14 +++++++++++++-
> tools/perf/util/bpf_ftrace.c | 12 +++++++++++-
> tools/perf/util/bpf_skel/func_latency.bpf.c | 19 +++++++++++++++++++
> tools/perf/util/ftrace.h | 6 ++++--
> 4 files changed, 47 insertions(+), 4 deletions(-)
>
> diff --git a/tools/perf/builtin-ftrace.c b/tools/perf/builtin-ftrace.c
> index 834074162a63bf2b..2a786047ba32bcb7 100644
> --- a/tools/perf/builtin-ftrace.c
> +++ b/tools/perf/builtin-ftrace.c
> @@ -43,6 +43,8 @@
> static volatile sig_atomic_t workload_exec_errno;
> static volatile sig_atomic_t done;
>
> +static struct stats latency_stats; /* for tracepoints */
> +
> static void sig_handler(int sig __maybe_unused)
> {
> done = true;
> @@ -798,8 +800,10 @@ static void make_histogram(struct perf_ftrace *ftrace, int buckets[],
> if (i >= NUM_BUCKET || num >= max_latency - min_latency)
> i = NUM_BUCKET - 1;
>
> + num += min_latency;
> do_inc:
> buckets[i]++;
> + update_stats(&latency_stats, num);
>
> next:
> /* empty the line buffer for the next output */
> @@ -894,6 +898,12 @@ static void display_histogram(struct perf_ftrace *ftrace, int buckets[])
> printf(" | %10d | %.*s%*s |\n", buckets[NUM_BUCKET - 1],
> bar_len, bar, bar_total - bar_len, "");
>
> + printf("\n# statistics (in %s)\n", ftrace->use_nsec ? "nsec" : "usec");
> + printf(" total time: %20.0f\n", latency_stats.mean * latency_stats.n);
> + printf(" avg time: %20.0f\n", latency_stats.mean);
> + printf(" max time: %20"PRIu64"\n", latency_stats.max);
> + printf(" min time: %20"PRIu64"\n", latency_stats.min);
> + printf(" count: %20.0f\n", latency_stats.n);
> }
>
> static int prepare_func_latency(struct perf_ftrace *ftrace)
> @@ -932,6 +942,8 @@ static int prepare_func_latency(struct perf_ftrace *ftrace)
> if (fd < 0)
> pr_err("failed to open trace_pipe\n");
>
> + init_stats(&latency_stats);
> +
> put_tracing_file(trace_file);
> return fd;
> }
> @@ -961,7 +973,7 @@ static int stop_func_latency(struct perf_ftrace *ftrace)
> static int read_func_latency(struct perf_ftrace *ftrace, int buckets[])
> {
> if (ftrace->target.use_bpf)
> - return perf_ftrace__latency_read_bpf(ftrace, buckets);
> + return perf_ftrace__latency_read_bpf(ftrace, buckets, &latency_stats);
>
> return 0;
> }
> diff --git a/tools/perf/util/bpf_ftrace.c b/tools/perf/util/bpf_ftrace.c
> index bc484e65fb8f69ca..25fc280e414ac5fe 100644
> --- a/tools/perf/util/bpf_ftrace.c
> +++ b/tools/perf/util/bpf_ftrace.c
> @@ -11,6 +11,7 @@
> #include "util/debug.h"
> #include "util/evlist.h"
> #include "util/bpf_counter.h"
> +#include "util/stat.h"
>
> #include "util/bpf_skel/func_latency.skel.h"
>
> @@ -86,6 +87,8 @@ int perf_ftrace__latency_prepare_bpf(struct perf_ftrace *ftrace)
> }
> }
>
> + skel->bss->min = INT64_MAX;
> +
> skel->links.func_begin = bpf_program__attach_kprobe(skel->progs.func_begin,
> false, func->name);
> if (IS_ERR(skel->links.func_begin)) {
> @@ -122,7 +125,7 @@ int perf_ftrace__latency_stop_bpf(struct perf_ftrace *ftrace __maybe_unused)
> }
>
> int perf_ftrace__latency_read_bpf(struct perf_ftrace *ftrace __maybe_unused,
> - int buckets[])
> + int buckets[], struct stats *stats)
> {
> int i, fd, err;
> u32 idx;
> @@ -146,6 +149,13 @@ int perf_ftrace__latency_read_bpf(struct perf_ftrace *ftrace __maybe_unused,
> buckets[idx] += hist[i];
> }
>
> + if (skel->bss->count) {
> + stats->mean = skel->bss->total / skel->bss->count;
> + stats->n = skel->bss->count;
> + stats->max = skel->bss->max;
> + stats->min = skel->bss->min;
> + }
> +
> free(hist);
> return 0;
> }
> diff --git a/tools/perf/util/bpf_skel/func_latency.bpf.c b/tools/perf/util/bpf_skel/func_latency.bpf.c
> index 4df54e1b1411b10a..fb144811b34fc72a 100644
> --- a/tools/perf/util/bpf_skel/func_latency.bpf.c
> +++ b/tools/perf/util/bpf_skel/func_latency.bpf.c
> @@ -38,6 +38,12 @@ struct {
>
> int enabled = 0;
>
> +// stats
> +__s64 total;
> +__s64 count;
> +__s64 max;
> +__s64 min;
> +
> const volatile int has_cpu = 0;
> const volatile int has_task = 0;
> const volatile int use_nsec = 0;
> @@ -122,6 +128,8 @@ int BPF_PROG(func_end)
> delta >= max_latency - min_latency)
> key = NUM_BUCKET - 1;
> }
> +
> + delta += min_latency;
> goto do_lookup;
> }
> // calculate index using delta
> @@ -136,6 +144,17 @@ int BPF_PROG(func_end)
> return 0;
>
> *hist += 1;
> +
> + if (bucket_range == 0)
> + delta /= cmp_base;
> +
> + __sync_fetch_and_add(&total, delta);
> + __sync_fetch_and_add(&count, 1);
> +
> + if (delta > max)
> + max = delta;
> + if (delta < min)
> + min = delta;
> }
>
> return 0;
> diff --git a/tools/perf/util/ftrace.h b/tools/perf/util/ftrace.h
> index f218703063f74786..5dee2caba0fe403f 100644
> --- a/tools/perf/util/ftrace.h
> +++ b/tools/perf/util/ftrace.h
> @@ -7,6 +7,7 @@
>
> struct evlist;
> struct hashamp;
> +struct stats;
>
> struct perf_ftrace {
> struct evlist *evlist;
> @@ -46,7 +47,7 @@ int perf_ftrace__latency_prepare_bpf(struct perf_ftrace *ftrace);
> int perf_ftrace__latency_start_bpf(struct perf_ftrace *ftrace);
> int perf_ftrace__latency_stop_bpf(struct perf_ftrace *ftrace);
> int perf_ftrace__latency_read_bpf(struct perf_ftrace *ftrace,
> - int buckets[]);
> + int buckets[], struct stats *stats);
> int perf_ftrace__latency_cleanup_bpf(struct perf_ftrace *ftrace);
>
> #else /* !HAVE_BPF_SKEL */
> @@ -71,7 +72,8 @@ perf_ftrace__latency_stop_bpf(struct perf_ftrace *ftrace __maybe_unused)
>
> static inline int
> perf_ftrace__latency_read_bpf(struct perf_ftrace *ftrace __maybe_unused,
> - int buckets[] __maybe_unused)
> + int buckets[] __maybe_unused,
> + struct stats *stats __maybe_unused)
> {
> return -1;
> }
> --
> 2.47.1.613.gc27f4b7a9f-goog
prev parent reply other threads:[~2025-01-08 14:56 UTC|newest]
Thread overview: 5+ messages / expand[flat|nested] mbox.gz Atom feed top
2025-01-07 22:43 [PATCH v2 1/3] perf ftrace: Display latency statistics at the end Namhyung Kim
2025-01-07 22:43 ` [PATCH v2 2/3] perf ftrace: Add --graph-opts option to profile subcommand Namhyung Kim
2025-01-07 22:43 ` [PATCH v2 3/3] perf test: Update ftrace test to use --graph-opts Namhyung Kim
2025-01-08 19:52 ` Arnaldo Carvalho de Melo
2025-01-08 14:56 ` Arnaldo Carvalho de Melo [this message]
Reply instructions:
You may reply publicly to this message via plain-text email
using any one of the following methods:
* Save the following mbox file, import it into your mail client,
and reply-to-all from there: mbox
Avoid top-posting and favor interleaved quoting:
https://en.wikipedia.org/wiki/Posting_style#Interleaved_style
* Reply using the --to, --cc, and --in-reply-to
switches of git-send-email(1):
git send-email \
--in-reply-to=Z36SM3m2QP5HSiev@x1 \
--to=acme@kernel.org \
--cc=adrian.hunter@intel.com \
--cc=gmonaco@redhat.com \
--cc=irogers@google.com \
--cc=james.clark@linaro.org \
--cc=jolsa@kernel.org \
--cc=kan.liang@linux.intel.com \
--cc=linux-kernel@vger.kernel.org \
--cc=linux-perf-users@vger.kernel.org \
--cc=mingo@kernel.org \
--cc=namhyung@kernel.org \
--cc=peterz@infradead.org \
--cc=williams@redhat.com \
/path/to/YOUR_REPLY
https://kernel.org/pub/software/scm/git/docs/git-send-email.html
* If your mail client supports setting the In-Reply-To header
via mailto: links, try the mailto: link
Be sure your reply has a Subject: header at the top and a blank line
before the message body.
This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox;
as well as URLs for NNTP newsgroup(s).