| 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
| ||
|
Date: Tue, 14 Jun 2022 08:40:44 -0700
From: Ian Rogers <irogers@...gle.com>
To: Namhyung Kim <namhyung@...nel.org>
Cc: Arnaldo Carvalho de Melo <acme@...nel.org>,
Jiri Olsa <jolsa@...nel.org>, Ingo Molnar <mingo@...nel.org>,
Peter Zijlstra <peterz@...radead.org>,
LKML <linux-kernel@...r.kernel.org>,
linux-perf-users@...r.kernel.org, Will Deacon <will@...nel.org>,
Waiman Long <longman@...hat.com>,
Boqun Feng <boqun.feng@...il.com>,
Davidlohr Bueso <dave@...olabs.net>
Subject: Re: [PATCH 1/5] perf lock: Print wait times with unit
On Fri, Jun 3, 2022 at 4:57 PM Namhyung Kim <namhyung@...nel.org> wrote:
>
> Currently it only prints the time in nsec but it's a bit hard to read
> and takes longer in the screen. We can change it to use different
> units and keep the number small to save the space.
>
> Before:
> $ perf lock report
>
> Name acquired contended avg wait (ns) total wait (ns) max wait (ns) min wait (ns)
>
> jiffies_lock 433 32 2778 88908 13570 692
> &lruvec->lru_lock 747 5 11254 56272 18317 1412
> slock-AF_INET6 7 1 23543 23543 23543 23543
> &newf->file_lock 706 15 1025 15388 2279 618
> slock-AF_INET6 8 1 10379 10379 10379 10379
> &rq->__lock 2143 5 2037 10185 3462 939
>
> After:
> Name acquired contended avg wait total wait max wait min wait
>
> jiffies_lock 433 32 2.78 us 88.91 us 13.57 us 692 ns
> &lruvec->lru_lock 747 5 11.25 us 56.27 us 18.32 us 1.41 us
> slock-AF_INET6 7 1 23.54 us 23.54 us 23.54 us 23.54 us
> &newf->file_lock 706 15 1.02 us 15.39 us 2.28 us 618 ns
> slock-AF_INET6 8 1 10.38 us 10.38 us 10.38 us 10.38 us
> &rq->__lock 2143 5 2.04 us 10.19 us 3.46 us 939 ns
>
> Signed-off-by: Namhyung Kim <namhyung@...nel.org>
Acked-by: Ian Rogers <irogers@...gle.com>
Thanks,
Ian
> ---
> tools/perf/builtin-lock.c | 48 ++++++++++++++++++++++++++++++++-------
> 1 file changed, 40 insertions(+), 8 deletions(-)
>
> diff --git a/tools/perf/builtin-lock.c b/tools/perf/builtin-lock.c
> index 23a33ac15e68..57e396323d05 100644
> --- a/tools/perf/builtin-lock.c
> +++ b/tools/perf/builtin-lock.c
> @@ -251,6 +251,31 @@ struct lock_key {
> struct list_head list;
> };
>
> +static void lock_stat_key_print_time(unsigned long long nsec, int len)
> +{
> + static const struct {
> + float base;
> + const char *unit;
> + } table[] = {
> + { 1e9 * 3600, "h " },
> + { 1e9 * 60, "m " },
> + { 1e9, "s " },
> + { 1e6, "ms" },
> + { 1e3, "us" },
> + { 0, NULL },
> + };
> +
> + for (int i = 0; table[i].unit; i++) {
> + if (nsec < table[i].base)
> + continue;
> +
> + pr_info("%*.2f %s", len - 3, nsec / table[i].base, table[i].unit);
> + return;
> + }
> +
> + pr_info("%*llu %s", len - 3, nsec, "ns");
> +}
> +
> #define PRINT_KEY(member) \
> static void lock_stat_key_print_ ## member(struct lock_key *key, \
> struct lock_stat *ls) \
> @@ -258,11 +283,18 @@ static void lock_stat_key_print_ ## member(struct lock_key *key, \
> pr_info("%*llu", key->len, (unsigned long long)ls->member); \
> }
>
> +#define PRINT_TIME(member) \
> +static void lock_stat_key_print_ ## member(struct lock_key *key, \
> + struct lock_stat *ls) \
> +{ \
> + lock_stat_key_print_time((unsigned long long)ls->member, key->len); \
> +}
> +
> PRINT_KEY(nr_acquired)
> PRINT_KEY(nr_contended)
> -PRINT_KEY(avg_wait_time)
> -PRINT_KEY(wait_time_total)
> -PRINT_KEY(wait_time_max)
> +PRINT_TIME(avg_wait_time)
> +PRINT_TIME(wait_time_total)
> +PRINT_TIME(wait_time_max)
>
> static void lock_stat_key_print_wait_time_min(struct lock_key *key,
> struct lock_stat *ls)
> @@ -272,7 +304,7 @@ static void lock_stat_key_print_wait_time_min(struct lock_key *key,
> if (wait_time == ULLONG_MAX)
> wait_time = 0;
>
> - pr_info("%*"PRIu64, key->len, wait_time);
> + lock_stat_key_print_time(wait_time, key->len);
> }
>
>
> @@ -291,10 +323,10 @@ static const char *output_fields;
> struct lock_key keys[] = {
> DEF_KEY_LOCK(acquired, "acquired", nr_acquired, 10),
> DEF_KEY_LOCK(contended, "contended", nr_contended, 10),
> - DEF_KEY_LOCK(avg_wait, "avg wait (ns)", avg_wait_time, 15),
> - DEF_KEY_LOCK(wait_total, "total wait (ns)", wait_time_total, 15),
> - DEF_KEY_LOCK(wait_max, "max wait (ns)", wait_time_max, 15),
> - DEF_KEY_LOCK(wait_min, "min wait (ns)", wait_time_min, 15),
> + DEF_KEY_LOCK(avg_wait, "avg wait", avg_wait_time, 12),
> + DEF_KEY_LOCK(wait_total, "total wait", wait_time_total, 12),
> + DEF_KEY_LOCK(wait_max, "max wait", wait_time_max, 12),
> + DEF_KEY_LOCK(wait_min, "min wait", wait_time_min, 12),
>
> /* extra comparisons much complicated should be here */
> { }
> --
> 2.36.1.255.ge46751e96f-goog
>
Powered by blists - more mailing lists