linux-kernel - Re: [PATCH v0] perf lock contention: skip traceiter functions

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

Hash Suite: Windows password security audit tool. GUI, reports in PDF.

[<prev] [next>] [<thread-prev] [day] [month] [year] [list]

Message-ID: <CAM9d7cjxNsOcGYAY4mi8-4+0w6YCAmQJCBdUFwW8q7_wh33EpQ@mail.gmail.com>
Date: Fri, 8 Mar 2024 15:24:29 -0800
From: Namhyung Kim <namhyung@...nel.org>
To: Anne Macedo <retpolanne@...teo.net>
Cc: Arnaldo Carvalho de Melo <acme@...nel.org>, Peter Zijlstra <peterz@...radead.org>, 
	Ingo Molnar <mingo@...hat.com>, Mark Rutland <mark.rutland@....com>, 
	Alexander Shishkin <alexander.shishkin@...ux.intel.com>, Jiri Olsa <jolsa@...nel.org>, 
	Ian Rogers <irogers@...gle.com>, Adrian Hunter <adrian.hunter@...el.com>, 
	linux-perf-users@...r.kernel.org, linux-kernel@...r.kernel.org
Subject: Re: [PATCH v0] perf lock contention: skip traceiter functions

On Fri, Mar 8, 2024 at 12:42 PM Anne Macedo <retpolanne@...teo.net> wrote:
>
> Arnaldo Carvalho de Melo <acme@...nel.org> writes:
>
> > On Fri, Mar 08, 2024 at 12:03:31PM +0000, Anne Macedo 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
> >>
> >>          6      5.27 s       1.76 s     878.55 ms     rwlock:W   release_task+0x68
> >>          2      2.99 s       2.99 s       1.50 s      spinlock   do_send_sig_info+0x3c
> >>          2      1.77 s       1.77 s     884.39 ms     spinlock   sigprocmask+0x98
> >>          2      1.76 s       1.76 s     878.56 ms     rwlock:W   do_exit+0x338
> >>          2      1.76 s       1.76 s     878.55 ms     rwlock:W   release_task+0x68
> >>          5      1.76 s       1.76 s     351.41 ms     rwlock:W   do_exit+0x338
> >>          1     48.10 ms     48.10 ms     48.10 ms        mutex   trace_contention_begin+0x84
> >>          4    257.80 us    119.34 us     64.45 us     spinlock   get_signal+0x108
> >>          1      9.33 us      9.33 us      9.33 us     rwlock:W   do_exit+0x338
> >
> > Testing it on the ARM64 board sometimes also show that
> > trace_contention_begin+0x84, maybe we need to skip that one as well?
> >
> I can skip trace_contention_begin and trace_contention_end as well.
>
> Question: I have 1409 __traceiter symbols on my kernel build, should we
> ignore them all? Or is __traceiter_contention_begin and
> __traceiter_contention_end the only ones that concern the lock contention?
>
> cat /proc/kallsyms | grep -P '\b__traceiter*' | wc -l
> 1409

Currently it's only __traceiter_contention_begin, we don't collect
stacktrace at contention_end for now.  Also we cannot guarantee
if __traceiter_contention_end is right after the contention_begin
so I think you should use sym->end of the contention_begin for
text_end.

And, traceiter functions don't belong to their own section so the
comment should be removed.  But I hope we can move them to
a section to make things clearer. :)

Thanks,
Namhyung