* [PATCH 1/2] perf lock: Do not discard broken lock stats
@ 2022-05-21 1:08 Namhyung Kim
2022-05-21 1:08 ` [PATCH 2/2] perf lock: Add -t/--thread option for report Namhyung Kim
0 siblings, 1 reply; 4+ messages in thread
From: Namhyung Kim @ 2022-05-21 1:08 UTC (permalink / raw)
To: Arnaldo Carvalho de Melo, Jiri Olsa
Cc: Ingo Molnar, Peter Zijlstra, LKML, Ian Rogers, linux-perf-users
Currently it discards a lock_stat for a lock instance when there's a
broken lock_seq_stat in a single task for the lock. But it also means
that the existing (and later) valid lock stat info for that lock will
be discarded as well.
This is not ideal since we can lose many valuable info because of a
single failure. Actually those failures are indepent to the existing
stat. So we can only discard the broken lock_seq_stat but keep the
valid lock_stat.
The discarded lock_seq_stat will be reallocated in a subsequent event
with SEQ_STATE_UNINITIALIZED which will be ignored until it see the
start of the next sequence. So it should be ok just free it.
Before:
$ perf lock report -F acquired,contended,avg_wait
Warning:
Processed 1401603 events and lost 18 chunks!
Check IO/CPU overload!
Name acquired contended avg wait (ns)
rcu_read_lock 251225 0 0
&(ei->i_block_re... 8731 0 0
&sb->s_type->i_l... 8731 0 0
hrtimer_bases.lock 5261 0 0
hrtimer_bases.lock 2626 0 0
hrtimer_bases.lock 1953 0 0
hrtimer_bases.lock 1382 0 0
cpu_hotplug_lock 1350 0 0
hrtimer_bases.lock 1273 0 0
hrtimer_bases.lock 1269 0 0
hrtimer_bases.lock 1198 0 0
...
New:
Name acquired contended avg wait (ns)
rcu_read_lock 251225 0 0
tk_core.seq.seqc... 54074 0 0
&xa->xa_lock 17470 0 0
&ei->i_es_lock 17464 0 0
&ei->i_raw_lock 9391 0 0
&mapping->privat... 8734 0 0
&ei->i_data_sem 8731 0 0
&(ei->i_block_re... 8731 0 0
&sb->s_type->i_l... 8731 0 0
jiffies_seq.seqc... 6953 0 0
&mm->mmap_lock 6889 0 0
balancing 5768 0 0
hrtimer_bases.lock 5261 0 0
...
Signed-off-by: Namhyung Kim <namhyung@kernel.org>
---
tools/perf/builtin-lock.c | 64 +++++++++++++++------------------------
1 file changed, 25 insertions(+), 39 deletions(-)
diff --git a/tools/perf/builtin-lock.c b/tools/perf/builtin-lock.c
index cdfe1d4ced4b..7ceb12e30719 100644
--- a/tools/perf/builtin-lock.c
+++ b/tools/perf/builtin-lock.c
@@ -65,7 +65,7 @@ struct lock_stat {
u64 wait_time_min;
u64 wait_time_max;
- int discard; /* flag of blacklist */
+ int broken; /* flag of blacklist */
int combined;
};
@@ -384,9 +384,6 @@ static void combine_lock_stats(struct lock_stat *st)
ret = !!st->name - !!p->name;
if (ret == 0) {
- if (st->discard)
- goto out;
-
p->nr_acquired += st->nr_acquired;
p->nr_contended += st->nr_contended;
p->wait_time_total += st->wait_time_total;
@@ -399,10 +396,7 @@ static void combine_lock_stats(struct lock_stat *st)
if (p->wait_time_max < st->wait_time_max)
p->wait_time_max = st->wait_time_max;
- /* now it got a new !discard record */
- p->discard = 0;
-
-out:
+ p->broken |= st->broken;
st->combined = 1;
return;
}
@@ -415,15 +409,6 @@ static void combine_lock_stats(struct lock_stat *st)
rb_link_node(&st->rb, parent, rb);
rb_insert_color(&st->rb, &sorted);
-
- if (st->discard) {
- st->nr_acquired = 0;
- st->nr_contended = 0;
- st->wait_time_total = 0;
- st->avg_wait_time = 0;
- st->wait_time_min = ULLONG_MAX;
- st->wait_time_max = 0;
- }
}
static void insert_to_result(struct lock_stat *st,
@@ -560,8 +545,6 @@ static int report_lock_acquire_event(struct evsel *evsel,
ls = lock_stat_findnew(addr, name);
if (!ls)
return -ENOMEM;
- if (ls->discard)
- return 0;
ts = thread_stat_findnew(sample->tid);
if (!ts)
@@ -599,9 +582,11 @@ static int report_lock_acquire_event(struct evsel *evsel,
case SEQ_STATE_ACQUIRING:
case SEQ_STATE_CONTENDED:
broken:
- /* broken lock sequence, discard it */
- ls->discard = 1;
- bad_hist[BROKEN_ACQUIRE]++;
+ /* broken lock sequence */
+ if (!ls->broken) {
+ ls->broken = 1;
+ bad_hist[BROKEN_ACQUIRE]++;
+ }
list_del_init(&seq->list);
free(seq);
goto end;
@@ -629,8 +614,6 @@ static int report_lock_acquired_event(struct evsel *evsel,
ls = lock_stat_findnew(addr, name);
if (!ls)
return -ENOMEM;
- if (ls->discard)
- return 0;
ts = thread_stat_findnew(sample->tid);
if (!ts)
@@ -657,9 +640,11 @@ static int report_lock_acquired_event(struct evsel *evsel,
case SEQ_STATE_RELEASED:
case SEQ_STATE_ACQUIRED:
case SEQ_STATE_READ_ACQUIRED:
- /* broken lock sequence, discard it */
- ls->discard = 1;
- bad_hist[BROKEN_ACQUIRED]++;
+ /* broken lock sequence */
+ if (!ls->broken) {
+ ls->broken = 1;
+ bad_hist[BROKEN_ACQUIRED]++;
+ }
list_del_init(&seq->list);
free(seq);
goto end;
@@ -688,8 +673,6 @@ static int report_lock_contended_event(struct evsel *evsel,
ls = lock_stat_findnew(addr, name);
if (!ls)
return -ENOMEM;
- if (ls->discard)
- return 0;
ts = thread_stat_findnew(sample->tid);
if (!ts)
@@ -709,9 +692,11 @@ static int report_lock_contended_event(struct evsel *evsel,
case SEQ_STATE_ACQUIRED:
case SEQ_STATE_READ_ACQUIRED:
case SEQ_STATE_CONTENDED:
- /* broken lock sequence, discard it */
- ls->discard = 1;
- bad_hist[BROKEN_CONTENDED]++;
+ /* broken lock sequence */
+ if (!ls->broken) {
+ ls->broken = 1;
+ bad_hist[BROKEN_CONTENDED]++;
+ }
list_del_init(&seq->list);
free(seq);
goto end;
@@ -740,8 +725,6 @@ static int report_lock_release_event(struct evsel *evsel,
ls = lock_stat_findnew(addr, name);
if (!ls)
return -ENOMEM;
- if (ls->discard)
- return 0;
ts = thread_stat_findnew(sample->tid);
if (!ts)
@@ -767,9 +750,11 @@ static int report_lock_release_event(struct evsel *evsel,
case SEQ_STATE_ACQUIRING:
case SEQ_STATE_CONTENDED:
case SEQ_STATE_RELEASED:
- /* broken lock sequence, discard it */
- ls->discard = 1;
- bad_hist[BROKEN_RELEASE]++;
+ /* broken lock sequence */
+ if (!ls->broken) {
+ ls->broken = 1;
+ bad_hist[BROKEN_RELEASE]++;
+ }
goto free_seq;
default:
BUG_ON("Unknown state of lock sequence found!\n");
@@ -854,10 +839,11 @@ static void print_result(void)
bad = total = 0;
while ((st = pop_from_result())) {
total++;
- if (st->discard) {
+ if (st->broken)
bad++;
+ if (!st->nr_acquired)
continue;
- }
+
bzero(cut_name, 20);
if (strlen(st->name) < 20) {
--
2.36.1.124.g0e6072fb45-goog
^ permalink raw reply related [flat|nested] 4+ messages in thread
* [PATCH 2/2] perf lock: Add -t/--thread option for report
2022-05-21 1:08 [PATCH 1/2] perf lock: Do not discard broken lock stats Namhyung Kim
@ 2022-05-21 1:08 ` Namhyung Kim
2022-05-23 12:50 ` Arnaldo Carvalho de Melo
0 siblings, 1 reply; 4+ messages in thread
From: Namhyung Kim @ 2022-05-21 1:08 UTC (permalink / raw)
To: Arnaldo Carvalho de Melo, Jiri Olsa
Cc: Ingo Molnar, Peter Zijlstra, LKML, Ian Rogers, linux-perf-users
The -t option is to show per-thread lock stat like below:
$ perf lock report -t -F acquired,contended,avg_wait
Name acquired contended avg wait (ns)
perf 240569 9 5784
swapper 106610 19 543
:15789 17370 2 14538
ContainerMgr 8981 6 874
sleep 5275 1 11281
ContainerThread 4416 4 944
RootPressureThr 3215 5 1215
rcu_preempt 2954 0 0
ContainerMgr 2560 0 0
unnamed 1873 0 0
EventManager_De 1845 1 636
futex-default-S 1609 0 0
...
Signed-off-by: Namhyung Kim <namhyung@kernel.org>
---
tools/perf/builtin-lock.c | 28 +++++++++++++++++++++++++++-
1 file changed, 27 insertions(+), 1 deletion(-)
diff --git a/tools/perf/builtin-lock.c b/tools/perf/builtin-lock.c
index 7ceb12e30719..b1200b7340a6 100644
--- a/tools/perf/builtin-lock.c
+++ b/tools/perf/builtin-lock.c
@@ -118,6 +118,7 @@ struct thread_stat {
static struct rb_root thread_stats;
static bool combine_locks;
+static bool show_thread_stats;
static struct thread_stat *thread_stat_find(u32 tid)
{
@@ -542,6 +543,10 @@ static int report_lock_acquire_event(struct evsel *evsel,
u64 addr = evsel__intval(evsel, sample, "lockdep_addr");
int flag = evsel__intval(evsel, sample, "flags");
+ /* abuse ls->addr for tid */
+ if (show_thread_stats)
+ addr = sample->tid;
+
ls = lock_stat_findnew(addr, name);
if (!ls)
return -ENOMEM;
@@ -611,6 +616,9 @@ static int report_lock_acquired_event(struct evsel *evsel,
const char *name = evsel__strval(evsel, sample, "name");
u64 addr = evsel__intval(evsel, sample, "lockdep_addr");
+ if (show_thread_stats)
+ addr = sample->tid;
+
ls = lock_stat_findnew(addr, name);
if (!ls)
return -ENOMEM;
@@ -670,6 +678,9 @@ static int report_lock_contended_event(struct evsel *evsel,
const char *name = evsel__strval(evsel, sample, "name");
u64 addr = evsel__intval(evsel, sample, "lockdep_addr");
+ if (show_thread_stats)
+ addr = sample->tid;
+
ls = lock_stat_findnew(addr, name);
if (!ls)
return -ENOMEM;
@@ -722,6 +733,9 @@ static int report_lock_release_event(struct evsel *evsel,
const char *name = evsel__strval(evsel, sample, "name");
u64 addr = evsel__intval(evsel, sample, "lockdep_addr");
+ if (show_thread_stats)
+ addr = sample->tid;
+
ls = lock_stat_findnew(addr, name);
if (!ls)
return -ENOMEM;
@@ -848,7 +862,17 @@ static void print_result(void)
if (strlen(st->name) < 20) {
/* output raw name */
- pr_info("%20s ", st->name);
+ const char *name = st->name;
+
+ if (show_thread_stats) {
+ struct thread *t;
+
+ /* st->addr contains tid of thread */
+ t = perf_session__findnew(session, st->addr);
+ name = thread__comm_str(t);
+ }
+
+ pr_info("%20s ", name);
} else {
strncpy(cut_name, st->name, 16);
cut_name[16] = '.';
@@ -1125,6 +1149,8 @@ int cmd_lock(int argc, const char **argv)
/* TODO: type */
OPT_BOOLEAN('c', "combine-locks", &combine_locks,
"combine locks in the same class"),
+ OPT_BOOLEAN('t', "threads", &show_thread_stats,
+ "show per-thread lock stats"),
OPT_PARENT(lock_options)
};
--
2.36.1.124.g0e6072fb45-goog
^ permalink raw reply related [flat|nested] 4+ messages in thread
* Re: [PATCH 2/2] perf lock: Add -t/--thread option for report
2022-05-21 1:08 ` [PATCH 2/2] perf lock: Add -t/--thread option for report Namhyung Kim
@ 2022-05-23 12:50 ` Arnaldo Carvalho de Melo
2022-05-24 17:31 ` Namhyung Kim
0 siblings, 1 reply; 4+ messages in thread
From: Arnaldo Carvalho de Melo @ 2022-05-23 12:50 UTC (permalink / raw)
To: Namhyung Kim
Cc: Jiri Olsa, Ingo Molnar, Peter Zijlstra, LKML, Ian Rogers,
linux-perf-users
Em Fri, May 20, 2022 at 06:08:11PM -0700, Namhyung Kim escreveu:
> The -t option is to show per-thread lock stat like below:
>
> $ perf lock report -t -F acquired,contended,avg_wait
>
> Name acquired contended avg wait (ns)
>
> perf 240569 9 5784
> swapper 106610 19 543
> :15789 17370 2 14538
> ContainerMgr 8981 6 874
> sleep 5275 1 11281
> ContainerThread 4416 4 944
> RootPressureThr 3215 5 1215
> rcu_preempt 2954 0 0
> ContainerMgr 2560 0 0
> unnamed 1873 0 0
> EventManager_De 1845 1 636
> futex-default-S 1609 0 0
> ...
Applied both and added this:
⬢[acme@toolbox perf]$ git diff
diff --git a/tools/perf/Documentation/perf-lock.txt b/tools/perf/Documentation/perf-lock.txt
index b43222229807672c..656b537b2fba078f 100644
--- a/tools/perf/Documentation/perf-lock.txt
+++ b/tools/perf/Documentation/perf-lock.txt
@@ -64,6 +64,27 @@ REPORT OPTIONS
--combine-locks::
Merge lock instances in the same class (based on name).
+-t::
+--threads::
+ The -t option is to show per-thread lock stat like below:
+
+ $ perf lock report -t -F acquired,contended,avg_wait
+
+ Name acquired contended avg wait (ns)
+
+ perf 240569 9 5784
+ swapper 106610 19 543
+ :15789 17370 2 14538
+ ContainerMgr 8981 6 874
+ sleep 5275 1 11281
+ ContainerThread 4416 4 944
+ RootPressureThr 3215 5 1215
+ rcu_preempt 2954 0 0
+ ContainerMgr 2560 0 0
+ unnamed 1873 0 0
+ EventManager_De 1845 1 636
+ futex-default-S 1609 0 0
+
INFO OPTIONS
------------
> Signed-off-by: Namhyung Kim <namhyung@kernel.org>
> ---
> tools/perf/builtin-lock.c | 28 +++++++++++++++++++++++++++-
> 1 file changed, 27 insertions(+), 1 deletion(-)
>
> diff --git a/tools/perf/builtin-lock.c b/tools/perf/builtin-lock.c
> index 7ceb12e30719..b1200b7340a6 100644
> --- a/tools/perf/builtin-lock.c
> +++ b/tools/perf/builtin-lock.c
> @@ -118,6 +118,7 @@ struct thread_stat {
> static struct rb_root thread_stats;
>
> static bool combine_locks;
> +static bool show_thread_stats;
>
> static struct thread_stat *thread_stat_find(u32 tid)
> {
> @@ -542,6 +543,10 @@ static int report_lock_acquire_event(struct evsel *evsel,
> u64 addr = evsel__intval(evsel, sample, "lockdep_addr");
> int flag = evsel__intval(evsel, sample, "flags");
>
> + /* abuse ls->addr for tid */
> + if (show_thread_stats)
> + addr = sample->tid;
> +
> ls = lock_stat_findnew(addr, name);
> if (!ls)
> return -ENOMEM;
> @@ -611,6 +616,9 @@ static int report_lock_acquired_event(struct evsel *evsel,
> const char *name = evsel__strval(evsel, sample, "name");
> u64 addr = evsel__intval(evsel, sample, "lockdep_addr");
>
> + if (show_thread_stats)
> + addr = sample->tid;
> +
> ls = lock_stat_findnew(addr, name);
> if (!ls)
> return -ENOMEM;
> @@ -670,6 +678,9 @@ static int report_lock_contended_event(struct evsel *evsel,
> const char *name = evsel__strval(evsel, sample, "name");
> u64 addr = evsel__intval(evsel, sample, "lockdep_addr");
>
> + if (show_thread_stats)
> + addr = sample->tid;
> +
> ls = lock_stat_findnew(addr, name);
> if (!ls)
> return -ENOMEM;
> @@ -722,6 +733,9 @@ static int report_lock_release_event(struct evsel *evsel,
> const char *name = evsel__strval(evsel, sample, "name");
> u64 addr = evsel__intval(evsel, sample, "lockdep_addr");
>
> + if (show_thread_stats)
> + addr = sample->tid;
> +
> ls = lock_stat_findnew(addr, name);
> if (!ls)
> return -ENOMEM;
> @@ -848,7 +862,17 @@ static void print_result(void)
>
> if (strlen(st->name) < 20) {
> /* output raw name */
> - pr_info("%20s ", st->name);
> + const char *name = st->name;
> +
> + if (show_thread_stats) {
> + struct thread *t;
> +
> + /* st->addr contains tid of thread */
> + t = perf_session__findnew(session, st->addr);
> + name = thread__comm_str(t);
> + }
> +
> + pr_info("%20s ", name);
> } else {
> strncpy(cut_name, st->name, 16);
> cut_name[16] = '.';
> @@ -1125,6 +1149,8 @@ int cmd_lock(int argc, const char **argv)
> /* TODO: type */
> OPT_BOOLEAN('c', "combine-locks", &combine_locks,
> "combine locks in the same class"),
> + OPT_BOOLEAN('t', "threads", &show_thread_stats,
> + "show per-thread lock stats"),
> OPT_PARENT(lock_options)
> };
>
> --
> 2.36.1.124.g0e6072fb45-goog
--
- Arnaldo
^ permalink raw reply related [flat|nested] 4+ messages in thread
* Re: [PATCH 2/2] perf lock: Add -t/--thread option for report
2022-05-23 12:50 ` Arnaldo Carvalho de Melo
@ 2022-05-24 17:31 ` Namhyung Kim
0 siblings, 0 replies; 4+ messages in thread
From: Namhyung Kim @ 2022-05-24 17:31 UTC (permalink / raw)
To: Arnaldo Carvalho de Melo
Cc: Jiri Olsa, Ingo Molnar, Peter Zijlstra, LKML, Ian Rogers,
linux-perf-users
Hi Arnaldo,
On Mon, May 23, 2022 at 5:50 AM Arnaldo Carvalho de Melo
<acme@kernel.org> wrote:
> Applied both and added this:
>
> ⬢[acme@toolbox perf]$ git diff
> diff --git a/tools/perf/Documentation/perf-lock.txt b/tools/perf/Documentation/perf-lock.txt
> index b43222229807672c..656b537b2fba078f 100644
> --- a/tools/perf/Documentation/perf-lock.txt
> +++ b/tools/perf/Documentation/perf-lock.txt
> @@ -64,6 +64,27 @@ REPORT OPTIONS
> --combine-locks::
> Merge lock instances in the same class (based on name).
>
> +-t::
> +--threads::
> + The -t option is to show per-thread lock stat like below:
> +
> + $ perf lock report -t -F acquired,contended,avg_wait
> +
> + Name acquired contended avg wait (ns)
> +
> + perf 240569 9 5784
> + swapper 106610 19 543
> + :15789 17370 2 14538
> + ContainerMgr 8981 6 874
> + sleep 5275 1 11281
> + ContainerThread 4416 4 944
> + RootPressureThr 3215 5 1215
> + rcu_preempt 2954 0 0
> + ContainerMgr 2560 0 0
> + unnamed 1873 0 0
> + EventManager_De 1845 1 636
> + futex-default-S 1609 0 0
> +
> INFO OPTIONS
> ------------
Thanks a lot for doing this!
Namhyung
^ permalink raw reply [flat|nested] 4+ messages in thread
end of thread, other threads:[~2022-05-24 17:31 UTC | newest]
Thread overview: 4+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2022-05-21 1:08 [PATCH 1/2] perf lock: Do not discard broken lock stats Namhyung Kim
2022-05-21 1:08 ` [PATCH 2/2] perf lock: Add -t/--thread option for report Namhyung Kim
2022-05-23 12:50 ` Arnaldo Carvalho de Melo
2022-05-24 17:31 ` Namhyung Kim
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).