Re: [PATCH v0] perf lock contention: skip traceiter functions
From: Namhyung Kim
Date: Fri Mar 08 2024 - 18:24:53 EST
On Fri, Mar 8, 2024 at 12:42 PM Anne Macedo <retpolanne@xxxxxxxxxx> wrote:
>
> Arnaldo Carvalho de Melo <acme@xxxxxxxxxx> 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