diff options
| author | Namhyung Kim <namhyung@kernel.org> | 2023-03-27 15:57:11 -0700 |
|---|---|---|
| committer | Arnaldo Carvalho de Melo <acme@redhat.com> | 2023-04-04 09:39:56 -0300 |
| commit | 84c3a2bb4c513ca9fd1326cf24d3729b769d9cf1 (patch) | |
| tree | f3e40c0eae98014a57f29d238b642b1abbf94f40 /tools/perf/builtin-lock.c | |
| parent | 35bf007e2ee0447166081646c0797bfa831b062f (diff) | |
perf lock contention: Show detail failure reason for BPF
It can fail to collect lock stat from BPF for various reasons. For
example, I've got a report that sometimes time calculation seems wrong
in case of contended spinlocks. I suspect the time delta went negative
for some reason.
Count them separately and show in the output like below:
$ sudo perf lock contention -abE5 sleep 10
contended total wait max wait avg wait type caller
13 785.61 us 79.36 us 60.43 us spinlock remove_wait_queue+0x14
10 469.02 us 87.51 us 46.90 us spinlock prepare_to_wait+0x27
9 289.09 us 69.08 us 32.12 us spinlock finish_wait+0x36
114 251.05 us 8.56 us 2.20 us spinlock try_to_wake_up+0x1f5
132 188.63 us 5.01 us 1.43 us spinlock __wake_up_common_lock+0x62
=== output for debug ===
bad: 1, total: 279
bad rate: 0.36 %
histogram of failure reasons
task: 1
stack: 0
time: 0
Signed-off-by: Namhyung Kim <namhyung@kernel.org>
Cc: Adrian Hunter <adrian.hunter@intel.com>
Cc: Hao Luo <haoluo@google.com>
Cc: Ian Rogers <irogers@google.com>
Cc: Ingo Molnar <mingo@kernel.org>
Cc: Jiri Olsa <jolsa@kernel.org>
Cc: Peter Zijlstra <peterz@infradead.org>
Cc: bpf@vger.kernel.org
Link: https://lore.kernel.org/r/20230327225711.245738-1-namhyung@kernel.org
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
Diffstat (limited to 'tools/perf/builtin-lock.c')
| -rw-r--r-- | tools/perf/builtin-lock.c | 28 |
1 files changed, 22 insertions, 6 deletions
diff --git a/tools/perf/builtin-lock.c b/tools/perf/builtin-lock.c index 82dd2dfe5692..32ec58fb80e4 100644 --- a/tools/perf/builtin-lock.c +++ b/tools/perf/builtin-lock.c @@ -1619,6 +1619,24 @@ static void sort_contention_result(void) sort_result(); } +static void print_bpf_events(int total, struct lock_contention_fails *fails) +{ + /* Output for debug, this have to be removed */ + int broken = fails->task + fails->stack + fails->time; + + if (quiet || total == 0 || (broken == 0 && verbose <= 0)) + return; + + total += broken; + pr_info("\n=== output for debug ===\n\n"); + pr_info("bad: %d, total: %d\n", broken, total); + pr_info("bad rate: %.2f %%\n", (double)broken / (double)total * 100); + + pr_info("histogram of failure reasons\n"); + pr_info(" %10s: %d\n", "task", fails->task); + pr_info(" %10s: %d\n", "stack", fails->stack); + pr_info(" %10s: %d\n", "time", fails->time); +} static void print_contention_result(struct lock_contention *con) { struct lock_stat *st; @@ -1646,8 +1664,6 @@ static void print_contention_result(struct lock_contention *con) } bad = total = printed = 0; - if (use_bpf) - bad = bad_hist[BROKEN_CONTENDED]; while ((st = pop_from_result())) { struct thread *t; @@ -1704,7 +1720,10 @@ static void print_contention_result(struct lock_contention *con) break; } - print_bad_events(bad, total); + if (use_bpf) + print_bpf_events(total, &con->fails); + else + print_bad_events(bad, total); } static bool force; @@ -1931,9 +1950,6 @@ static int __cmd_contention(int argc, const char **argv) lock_contention_stop(); lock_contention_read(&con); - - /* abuse bad hist stats for lost entries */ - bad_hist[BROKEN_CONTENDED] = con.lost; } else { err = perf_session__process_events(session); if (err) |