[PATCH v2] perf lock contention: skip traceiter functions

Anne Macedo posted 1 patch 1 year, 11 months ago
There is a newer version of this series
tools/perf/util/machine.c | 21 +++++++++++++++++++++
tools/perf/util/machine.h |  2 +-
2 files changed, 22 insertions(+), 1 deletion(-)
[PATCH v2] perf lock contention: skip traceiter functions
Posted by Anne Macedo 1 year, 11 months ago
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 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 | 21 +++++++++++++++++++++
 tools/perf/util/machine.h |  2 +-
 2 files changed, 22 insertions(+), 1 deletion(-)

diff --git a/tools/perf/util/machine.c b/tools/perf/util/machine.c
index 527517db3182..968f69364f9a 100644
--- a/tools/perf/util/machine.c
+++ b/tools/perf/util/machine.c
@@ -3266,6 +3266,18 @@ 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 +3292,14 @@ 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 <= addr && addr < machine->traceiter.text_end)
+		return true;
+
+	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
Re: [PATCH v2] perf lock contention: skip traceiter functions
Posted by Namhyung Kim 1 year, 11 months ago
On Mon, Mar 11, 2024 at 3:57 PM 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 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 | 21 +++++++++++++++++++++
>  tools/perf/util/machine.h |  2 +-
>  2 files changed, 22 insertions(+), 1 deletion(-)
>
> diff --git a/tools/perf/util/machine.c b/tools/perf/util/machine.c
> index 527517db3182..968f69364f9a 100644
> --- a/tools/perf/util/machine.c
> +++ b/tools/perf/util/machine.c
> @@ -3266,6 +3266,18 @@ 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 +3292,14 @@ 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 <= addr && addr < machine->traceiter.text_end)
> +               return true;
> +
> +       if (machine->trace.text_start <= addr && addr < machine->trace.text_end)
> +               return true;

You cannot simply check these as they are set optionally.

Thanks,
Namhyung


> +
>         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
>
Re: [PATCH v2] perf lock contention: skip traceiter functions
Posted by Anne Macedo 1 year, 11 months ago
Namhyung Kim <namhyung@kernel.org> writes:

> On Mon, Mar 11, 2024 at 3:57 PM 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 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 | 21 +++++++++++++++++++++
>>  tools/perf/util/machine.h |  2 +-
>>  2 files changed, 22 insertions(+), 1 deletion(-)
>>
>> diff --git a/tools/perf/util/machine.c b/tools/perf/util/machine.c
>> index 527517db3182..968f69364f9a 100644
>> --- a/tools/perf/util/machine.c
>> +++ b/tools/perf/util/machine.c
>> @@ -3266,6 +3266,18 @@ 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 +3292,14 @@ 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 <= addr && addr < machine->traceiter.text_end)
>> +               return true;
>> +
>> +       if (machine->trace.text_start <= addr && addr < machine->trace.text_end)
>> +               return true;
>
> You cannot simply check these as they are set optionally.
>
Should I move them to the same if block where I check for the sym?
>
> Thanks,
> Namhyung
>
>
>> +
>>         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
>>
Thanks, Anne