* [PATCH v4] perf lock contention: skip traceiter functions
@ 2024-03-19 14:36 Anne Macedo
2024-03-20 22:54 ` Namhyung Kim
2024-03-21 19:58 ` Arnaldo Carvalho de Melo
0 siblings, 2 replies; 4+ messages in thread
From: Anne Macedo @ 2024-03-19 14:36 UTC (permalink / raw)
To: Arnaldo Carvalho de Melo, Namhyung Kim
Cc: Anne Macedo, Peter Zijlstra, Ingo Molnar, Mark Rutland,
Alexander Shishkin, Jiri Olsa, Ian Rogers, Adrian Hunter,
linux-perf-users, linux-kernel
The perf lock contention program currently shows the caller of the locks
as __traceiter_contention_begin+0x??. This caller can be ignored, as it is
from the traceiter itself. Instead, it should show the real callers for
the locks.
When fiddling with the --stack-skip parameter, the actual callers for
the locks start to show up. However, just ignore the
__traceiter_contention_begin and the __traceiter_contention_end symbols
so the actual callers will show up.
Before this patch is applied:
sudo perf lock con -a -b -- sleep 3
contended total wait max wait avg wait type caller
8 2.33 s 2.28 s 291.18 ms rwlock:W __traceiter_contention_begin+0x44
4 2.33 s 2.28 s 582.35 ms rwlock:W __traceiter_contention_begin+0x44
7 140.30 ms 46.77 ms 20.04 ms rwlock:W __traceiter_contention_begin+0x44
2 63.35 ms 33.76 ms 31.68 ms mutex trace_contention_begin+0x84
2 46.74 ms 46.73 ms 23.37 ms rwlock:W __traceiter_contention_begin+0x44
1 13.54 us 13.54 us 13.54 us mutex trace_contention_begin+0x84
1 3.67 us 3.67 us 3.67 us rwsem:R __traceiter_contention_begin+0x44
Before this patch is applied - using --stack-skip 5
sudo perf lock con --stack-skip 5 -a -b -- sleep 3
contended total wait max wait avg wait type caller
2 2.24 s 2.24 s 1.12 s rwlock:W do_epoll_wait+0x5a0
4 1.65 s 824.21 ms 412.08 ms rwlock:W do_exit+0x338
2 824.35 ms 824.29 ms 412.17 ms spinlock get_signal+0x108
2 824.14 ms 824.14 ms 412.07 ms rwlock:W release_task+0x68
1 25.22 ms 25.22 ms 25.22 ms mutex cgroup_kn_lock_live+0x58
1 24.71 us 24.71 us 24.71 us spinlock do_exit+0x44
1 22.04 us 22.04 us 22.04 us rwsem:R lock_mm_and_find_vma+0xb0
After this patch is applied:
sudo ./perf lock con -a -b -- sleep 3
contended total wait max wait avg wait type caller
4 4.13 s 2.07 s 1.03 s rwlock:W release_task+0x68
2 2.07 s 2.07 s 1.03 s rwlock:R mm_update_next_owner+0x50
2 2.07 s 2.07 s 1.03 s rwlock:W do_exit+0x338
1 41.56 ms 41.56 ms 41.56 ms mutex cgroup_kn_lock_live+0x58
2 36.12 us 18.83 us 18.06 us rwlock:W do_exit+0x338
changes since v3:
- remove dummy value and assume machine->traceiter and machine->trace
have zero address
changes since v2:
- add dummy value to machine->traceiter and machine->trace to make
necessary checks, fixing possible null pointer access
changes since v1:
- consider trace_contention and __traceiter_contention functions as
optional (i.e. check if sym is null to avoid segfault)
changes since v0:
- skip trace_contention functions
- use sym->end instead of __traceiter_contention_end for text_end
Signed-off-by: Anne Macedo <retpolanne@posteo.net>
---
tools/perf/util/machine.c | 24 ++++++++++++++++++++++++
tools/perf/util/machine.h | 2 +-
2 files changed, 25 insertions(+), 1 deletion(-)
diff --git a/tools/perf/util/machine.c b/tools/perf/util/machine.c
index 527517db3182..5eb9044bc223 100644
--- a/tools/perf/util/machine.c
+++ b/tools/perf/util/machine.c
@@ -3266,6 +3266,17 @@ bool machine__is_lock_function(struct machine *machine, u64 addr)
sym = machine__find_kernel_symbol_by_name(machine, "__lock_text_end", &kmap);
machine->lock.text_end = map__unmap_ip(kmap, sym->start);
+
+ sym = machine__find_kernel_symbol_by_name(machine, "__traceiter_contention_begin", &kmap);
+ if (sym) {
+ machine->traceiter.text_start = map__unmap_ip(kmap, sym->start);
+ machine->traceiter.text_end = map__unmap_ip(kmap, sym->end);
+ }
+ sym = machine__find_kernel_symbol_by_name(machine, "trace_contention_begin", &kmap);
+ if (sym) {
+ machine->trace.text_start = map__unmap_ip(kmap, sym->start);
+ machine->trace.text_end = map__unmap_ip(kmap, sym->end);
+ }
}
/* failed to get kernel symbols */
@@ -3280,5 +3291,18 @@ bool machine__is_lock_function(struct machine *machine, u64 addr)
if (machine->lock.text_start <= addr && addr < machine->lock.text_end)
return true;
+ /* traceiter functions currently don't have their own section
+ * but we consider them lock functions
+ */
+ if (machine->traceiter.text_start != 0) {
+ if (machine->traceiter.text_start <= addr && addr < machine->traceiter.text_end)
+ return true;
+ }
+
+ if (machine->trace.text_start != 0) {
+ if (machine->trace.text_start <= addr && addr < machine->trace.text_end)
+ return true;
+ }
+
return false;
}
diff --git a/tools/perf/util/machine.h b/tools/perf/util/machine.h
index e28c787616fe..4312f6db6de0 100644
--- a/tools/perf/util/machine.h
+++ b/tools/perf/util/machine.h
@@ -49,7 +49,7 @@ struct machine {
struct {
u64 text_start;
u64 text_end;
- } sched, lock;
+ } sched, lock, traceiter, trace;
pid_t *current_tid;
size_t current_tid_sz;
union { /* Tool specific area */
--
2.39.2
^ permalink raw reply related [flat|nested] 4+ messages in thread
* Re: [PATCH v4] perf lock contention: skip traceiter functions
2024-03-19 14:36 [PATCH v4] perf lock contention: skip traceiter functions Anne Macedo
@ 2024-03-20 22:54 ` Namhyung Kim
2024-03-21 19:58 ` Arnaldo Carvalho de Melo
1 sibling, 0 replies; 4+ messages in thread
From: Namhyung Kim @ 2024-03-20 22:54 UTC (permalink / raw)
To: Anne Macedo
Cc: Arnaldo Carvalho de Melo, Peter Zijlstra, Ingo Molnar,
Mark Rutland, Alexander Shishkin, Jiri Olsa, Ian Rogers,
Adrian Hunter, linux-perf-users, linux-kernel
Hi Anne,
On Tue, Mar 19, 2024 at 7:36 AM Anne Macedo <retpolanne@posteo.net> wrote:
>
> The perf lock contention program currently shows the caller of the locks
> as __traceiter_contention_begin+0x??. This caller can be ignored, as it is
> from the traceiter itself. Instead, it should show the real callers for
> the locks.
>
> When fiddling with the --stack-skip parameter, the actual callers for
> the locks start to show up. However, just ignore the
> __traceiter_contention_begin and the __traceiter_contention_end symbols
> so the actual callers will show up.
>
> Before this patch is applied:
>
> sudo perf lock con -a -b -- sleep 3
> contended total wait max wait avg wait type caller
>
> 8 2.33 s 2.28 s 291.18 ms rwlock:W __traceiter_contention_begin+0x44
> 4 2.33 s 2.28 s 582.35 ms rwlock:W __traceiter_contention_begin+0x44
> 7 140.30 ms 46.77 ms 20.04 ms rwlock:W __traceiter_contention_begin+0x44
> 2 63.35 ms 33.76 ms 31.68 ms mutex trace_contention_begin+0x84
> 2 46.74 ms 46.73 ms 23.37 ms rwlock:W __traceiter_contention_begin+0x44
> 1 13.54 us 13.54 us 13.54 us mutex trace_contention_begin+0x84
> 1 3.67 us 3.67 us 3.67 us rwsem:R __traceiter_contention_begin+0x44
>
> Before this patch is applied - using --stack-skip 5
>
> sudo perf lock con --stack-skip 5 -a -b -- sleep 3
> contended total wait max wait avg wait type caller
>
> 2 2.24 s 2.24 s 1.12 s rwlock:W do_epoll_wait+0x5a0
> 4 1.65 s 824.21 ms 412.08 ms rwlock:W do_exit+0x338
> 2 824.35 ms 824.29 ms 412.17 ms spinlock get_signal+0x108
> 2 824.14 ms 824.14 ms 412.07 ms rwlock:W release_task+0x68
> 1 25.22 ms 25.22 ms 25.22 ms mutex cgroup_kn_lock_live+0x58
> 1 24.71 us 24.71 us 24.71 us spinlock do_exit+0x44
> 1 22.04 us 22.04 us 22.04 us rwsem:R lock_mm_and_find_vma+0xb0
>
> After this patch is applied:
>
> sudo ./perf lock con -a -b -- sleep 3
> contended total wait max wait avg wait type caller
>
> 4 4.13 s 2.07 s 1.03 s rwlock:W release_task+0x68
> 2 2.07 s 2.07 s 1.03 s rwlock:R mm_update_next_owner+0x50
> 2 2.07 s 2.07 s 1.03 s rwlock:W do_exit+0x338
> 1 41.56 ms 41.56 ms 41.56 ms mutex cgroup_kn_lock_live+0x58
> 2 36.12 us 18.83 us 18.06 us rwlock:W do_exit+0x338
>
> changes since v3:
>
> - remove dummy value and assume machine->traceiter and machine->trace
> have zero address
>
> changes since v2:
>
> - add dummy value to machine->traceiter and machine->trace to make
> necessary checks, fixing possible null pointer access
>
> changes since v1:
>
> - consider trace_contention and __traceiter_contention functions as
> optional (i.e. check if sym is null to avoid segfault)
>
> changes since v0:
>
> - skip trace_contention functions
> - use sym->end instead of __traceiter_contention_end for text_end
>
> Signed-off-by: Anne Macedo <retpolanne@posteo.net>
Thanks for your work!
Acked-by: Namhyung Kim <namhyung@kernel.org>
Thanks,
Namhyung
> ---
> tools/perf/util/machine.c | 24 ++++++++++++++++++++++++
> tools/perf/util/machine.h | 2 +-
> 2 files changed, 25 insertions(+), 1 deletion(-)
>
> diff --git a/tools/perf/util/machine.c b/tools/perf/util/machine.c
> index 527517db3182..5eb9044bc223 100644
> --- a/tools/perf/util/machine.c
> +++ b/tools/perf/util/machine.c
> @@ -3266,6 +3266,17 @@ bool machine__is_lock_function(struct machine *machine, u64 addr)
>
> sym = machine__find_kernel_symbol_by_name(machine, "__lock_text_end", &kmap);
> machine->lock.text_end = map__unmap_ip(kmap, sym->start);
> +
> + sym = machine__find_kernel_symbol_by_name(machine, "__traceiter_contention_begin", &kmap);
> + if (sym) {
> + machine->traceiter.text_start = map__unmap_ip(kmap, sym->start);
> + machine->traceiter.text_end = map__unmap_ip(kmap, sym->end);
> + }
> + sym = machine__find_kernel_symbol_by_name(machine, "trace_contention_begin", &kmap);
> + if (sym) {
> + machine->trace.text_start = map__unmap_ip(kmap, sym->start);
> + machine->trace.text_end = map__unmap_ip(kmap, sym->end);
> + }
> }
>
> /* failed to get kernel symbols */
> @@ -3280,5 +3291,18 @@ bool machine__is_lock_function(struct machine *machine, u64 addr)
> if (machine->lock.text_start <= addr && addr < machine->lock.text_end)
> return true;
>
> + /* traceiter functions currently don't have their own section
> + * but we consider them lock functions
> + */
> + if (machine->traceiter.text_start != 0) {
> + if (machine->traceiter.text_start <= addr && addr < machine->traceiter.text_end)
> + return true;
> + }
> +
> + if (machine->trace.text_start != 0) {
> + if (machine->trace.text_start <= addr && addr < machine->trace.text_end)
> + return true;
> + }
> +
> return false;
> }
> diff --git a/tools/perf/util/machine.h b/tools/perf/util/machine.h
> index e28c787616fe..4312f6db6de0 100644
> --- a/tools/perf/util/machine.h
> +++ b/tools/perf/util/machine.h
> @@ -49,7 +49,7 @@ struct machine {
> struct {
> u64 text_start;
> u64 text_end;
> - } sched, lock;
> + } sched, lock, traceiter, trace;
> pid_t *current_tid;
> size_t current_tid_sz;
> union { /* Tool specific area */
> --
> 2.39.2
>
^ permalink raw reply [flat|nested] 4+ messages in thread
* Re: [PATCH v4] perf lock contention: skip traceiter functions
2024-03-19 14:36 [PATCH v4] perf lock contention: skip traceiter functions Anne Macedo
2024-03-20 22:54 ` Namhyung Kim
@ 2024-03-21 19:58 ` Arnaldo Carvalho de Melo
2024-03-21 20:48 ` Arnaldo Carvalho de Melo
1 sibling, 1 reply; 4+ messages in thread
From: Arnaldo Carvalho de Melo @ 2024-03-21 19:58 UTC (permalink / raw)
To: Anne Macedo
Cc: Namhyung Kim, Peter Zijlstra, Ingo Molnar, Mark Rutland,
Alexander Shishkin, Jiri Olsa, Ian Rogers, Adrian Hunter,
linux-perf-users, linux-kernel
Now lemme nitpick a bit, and I'll do it myself while processing the
patch, some are from my days sending patches to Ingo and from his
requests it become second nature, others I do to further clarify the
text:
And here is the reason for top posting, the first request is about the
subject line:
Subject: [PATCH v4] perf lock contention: skip traceiter functions
Becomes:
Subject: [PATCH v4] perf lock contention: Trim backtrace by skipping traceiter functions
Please make it so that after the component the one line summary starts
with a capital letter and packs as much info as possible.
On Tue, Mar 19, 2024 at 02:36:26PM +0000, Anne Macedo wrote:
> The perf lock contention program currently shows the caller of the locks
I try to make the sub (sub) command stand out by single quoting it:
The 'perf lock contention' program currently shows the caller of the locks
What follows is great, nice description, before/after.
Thanks, testing it now on x86_64 and aarch64, will apply it then.
- Arnaldo
> as __traceiter_contention_begin+0x??. This caller can be ignored, as it is
> from the traceiter itself. Instead, it should show the real callers for
> the locks.
>
> When fiddling with the --stack-skip parameter, the actual callers for
> the locks start to show up. However, just ignore the
> __traceiter_contention_begin and the __traceiter_contention_end symbols
> so the actual callers will show up.
>
> Before this patch is applied:
>
> sudo perf lock con -a -b -- sleep 3
> contended total wait max wait avg wait type caller
>
> 8 2.33 s 2.28 s 291.18 ms rwlock:W __traceiter_contention_begin+0x44
> 4 2.33 s 2.28 s 582.35 ms rwlock:W __traceiter_contention_begin+0x44
> 7 140.30 ms 46.77 ms 20.04 ms rwlock:W __traceiter_contention_begin+0x44
> 2 63.35 ms 33.76 ms 31.68 ms mutex trace_contention_begin+0x84
> 2 46.74 ms 46.73 ms 23.37 ms rwlock:W __traceiter_contention_begin+0x44
> 1 13.54 us 13.54 us 13.54 us mutex trace_contention_begin+0x84
> 1 3.67 us 3.67 us 3.67 us rwsem:R __traceiter_contention_begin+0x44
>
> Before this patch is applied - using --stack-skip 5
>
> sudo perf lock con --stack-skip 5 -a -b -- sleep 3
> contended total wait max wait avg wait type caller
>
> 2 2.24 s 2.24 s 1.12 s rwlock:W do_epoll_wait+0x5a0
> 4 1.65 s 824.21 ms 412.08 ms rwlock:W do_exit+0x338
> 2 824.35 ms 824.29 ms 412.17 ms spinlock get_signal+0x108
> 2 824.14 ms 824.14 ms 412.07 ms rwlock:W release_task+0x68
> 1 25.22 ms 25.22 ms 25.22 ms mutex cgroup_kn_lock_live+0x58
> 1 24.71 us 24.71 us 24.71 us spinlock do_exit+0x44
> 1 22.04 us 22.04 us 22.04 us rwsem:R lock_mm_and_find_vma+0xb0
>
> After this patch is applied:
>
> sudo ./perf lock con -a -b -- sleep 3
> contended total wait max wait avg wait type caller
>
> 4 4.13 s 2.07 s 1.03 s rwlock:W release_task+0x68
> 2 2.07 s 2.07 s 1.03 s rwlock:R mm_update_next_owner+0x50
> 2 2.07 s 2.07 s 1.03 s rwlock:W do_exit+0x338
> 1 41.56 ms 41.56 ms 41.56 ms mutex cgroup_kn_lock_live+0x58
> 2 36.12 us 18.83 us 18.06 us rwlock:W do_exit+0x338
>
> changes since v3:
>
> - remove dummy value and assume machine->traceiter and machine->trace
> have zero address
>
> changes since v2:
>
> - add dummy value to machine->traceiter and machine->trace to make
> necessary checks, fixing possible null pointer access
>
> changes since v1:
>
> - consider trace_contention and __traceiter_contention functions as
> optional (i.e. check if sym is null to avoid segfault)
>
> changes since v0:
>
> - skip trace_contention functions
> - use sym->end instead of __traceiter_contention_end for text_end
>
> Signed-off-by: Anne Macedo <retpolanne@posteo.net>
> ---
> tools/perf/util/machine.c | 24 ++++++++++++++++++++++++
> tools/perf/util/machine.h | 2 +-
> 2 files changed, 25 insertions(+), 1 deletion(-)
>
> diff --git a/tools/perf/util/machine.c b/tools/perf/util/machine.c
> index 527517db3182..5eb9044bc223 100644
> --- a/tools/perf/util/machine.c
> +++ b/tools/perf/util/machine.c
> @@ -3266,6 +3266,17 @@ bool machine__is_lock_function(struct machine *machine, u64 addr)
>
> sym = machine__find_kernel_symbol_by_name(machine, "__lock_text_end", &kmap);
> machine->lock.text_end = map__unmap_ip(kmap, sym->start);
> +
> + sym = machine__find_kernel_symbol_by_name(machine, "__traceiter_contention_begin", &kmap);
> + if (sym) {
> + machine->traceiter.text_start = map__unmap_ip(kmap, sym->start);
> + machine->traceiter.text_end = map__unmap_ip(kmap, sym->end);
> + }
> + sym = machine__find_kernel_symbol_by_name(machine, "trace_contention_begin", &kmap);
> + if (sym) {
> + machine->trace.text_start = map__unmap_ip(kmap, sym->start);
> + machine->trace.text_end = map__unmap_ip(kmap, sym->end);
> + }
> }
>
> /* failed to get kernel symbols */
> @@ -3280,5 +3291,18 @@ bool machine__is_lock_function(struct machine *machine, u64 addr)
> if (machine->lock.text_start <= addr && addr < machine->lock.text_end)
> return true;
>
> + /* traceiter functions currently don't have their own section
> + * but we consider them lock functions
> + */
> + if (machine->traceiter.text_start != 0) {
> + if (machine->traceiter.text_start <= addr && addr < machine->traceiter.text_end)
> + return true;
> + }
> +
> + if (machine->trace.text_start != 0) {
> + if (machine->trace.text_start <= addr && addr < machine->trace.text_end)
> + return true;
> + }
> +
> return false;
> }
> diff --git a/tools/perf/util/machine.h b/tools/perf/util/machine.h
> index e28c787616fe..4312f6db6de0 100644
> --- a/tools/perf/util/machine.h
> +++ b/tools/perf/util/machine.h
> @@ -49,7 +49,7 @@ struct machine {
> struct {
> u64 text_start;
> u64 text_end;
> - } sched, lock;
> + } sched, lock, traceiter, trace;
> pid_t *current_tid;
> size_t current_tid_sz;
> union { /* Tool specific area */
> --
> 2.39.2
>
^ permalink raw reply [flat|nested] 4+ messages in thread
* Re: [PATCH v4] perf lock contention: skip traceiter functions
2024-03-21 19:58 ` Arnaldo Carvalho de Melo
@ 2024-03-21 20:48 ` Arnaldo Carvalho de Melo
0 siblings, 0 replies; 4+ messages in thread
From: Arnaldo Carvalho de Melo @ 2024-03-21 20:48 UTC (permalink / raw)
To: Anne Macedo
Cc: Namhyung Kim, Peter Zijlstra, Ingo Molnar, Mark Rutland,
Alexander Shishkin, Jiri Olsa, Ian Rogers, Adrian Hunter,
linux-perf-users, linux-kernel
On Thu, Mar 21, 2024 at 04:58:20PM -0300, Arnaldo Carvalho de Melo wrote:
> Thanks, testing it now on x86_64 and aarch64, will apply it then.
Done, applied, on aarch64:
root@roc-rk3399-pc:~# perf lock contention --use-bpf -a find / > /dev/null
contended total wait max wait avg wait type caller
6 6.03 s 6.03 s 1.00 s spinlock __tick_broadcast_oneshot_control+0xc0
19 811.74 ms 621.76 ms 42.72 ms spinlock rcu_core+0xec
2 201.76 ms 201.75 ms 100.88 ms spinlock sugov_update_shared+0x44
6 7.80 ms 2.35 ms 1.30 ms mutex regulator_lock_recursive+0x144
1 702.63 us 702.63 us 702.63 us rwsem:W __btrfs_tree_lock+0x2c
4 62.42 us 18.96 us 15.60 us spinlock tick_do_update_jiffies64+0x44
2 39.96 us 22.17 us 19.98 us spinlock __tick_broadcast_oneshot_control+0xc0
2 33.83 us 18.08 us 16.92 us mutex mmc_blk_rw_wait+0x138
1 21.58 us 21.58 us 21.58 us spinlock sugov_update_shared+0x44
1 16.92 us 16.92 us 16.92 us spinlock cpu_pm_enter+0x34
1 16.04 us 16.04 us 16.04 us mutex clk_prepare_lock+0x4c
root@roc-rk3399-pc:~# uname -a
Linux roc-rk3399-pc 6.1.68-12200-g1c40dda3081e #1 SMP PREEMPT_DYNAMIC Thu Dec 14 04:02:49 EST 2023 aarch64 aarch64 aarch64 GNU/Linux
root@roc-rk3399-pc:~#
its in tmp.perf-tools-next, will move to perf-tools-next in the next batch, after build
tests together with other patches.
Thanks!
- Arnaldo
^ permalink raw reply [flat|nested] 4+ messages in thread
end of thread, other threads:[~2024-03-21 20:48 UTC | newest]
Thread overview: 4+ messages (download: mbox.gz follow: Atom feed
-- links below jump to the message on this page --
2024-03-19 14:36 [PATCH v4] perf lock contention: skip traceiter functions Anne Macedo
2024-03-20 22:54 ` Namhyung Kim
2024-03-21 19:58 ` Arnaldo Carvalho de Melo
2024-03-21 20:48 ` Arnaldo Carvalho de Melo
This is an external index of several public inboxes,
see mirroring instructions on how to clone and mirror
all data and code used by this external index.