* Perf doesn't display kernel symbols anymore (bisected commit 659ad3492b91 ("perf maps: Switch from rbtree to lazily sorted array for addresses"))
@ 2024-12-16 7:01 Christophe Leroy
2024-12-17 14:18 ` James Clark
0 siblings, 1 reply; 15+ messages in thread
From: Christophe Leroy @ 2024-12-16 7:01 UTC (permalink / raw)
To: linux-perf-users@vger.kernel.org, Peter Zijlstra, Ingo Molnar,
Arnaldo Carvalho de Melo, Namhyung Kim
Hi,
I noticed with 6.12 LTS Kernel that perf top and perf record/report
don't display kernel symbols anymore, instead it displays the raw
address with [unknown] as object.
After bisect I see that the problem appears with commit 659ad3492b91
("perf maps: Switch from rbtree to lazily sorted array for addresses").
Previous commit 39d14c0dd650 ("Merge branch 'perf-tools' into
perf-tools-next") doesn't exbibit the problem.
Now:
# Overhead Command Shared Object Symbol
# ........ .......... .............
......................................
#
80.49% Coeur main [unknown] [k] 0xc005f0f8
3.91% Coeur main gau [.] engine_loop.constprop.0.isra.0
1.72% Coeur main [unknown] [k] 0xc005f11c
1.09% Coeur main [unknown] [k] 0xc01f82c8
0.44% Coeur main libc.so.6 [.] epoll_wait
0.38% Coeur main [unknown] [k] 0xc0011718
0.36% Coeur main [unknown] [k] 0xc01f45c0
0.22% Coeur main libc.so.6 [.]
__GI___pthread_enable_asynccancel
0.19% Coeur main libc.so.6 [.]
__GI___pthread_disable_asynccancel
0.19% Coeur main [unknown] [k] 0xc0011170
0.19% Coeur main [unknown] [k] 0xc019ac64
0.19% Coeur main [unknown] [k] 0xc01f54bc
0.16% Coeur main libc.so.6 [.] read
Before commit 659ad3492b91 ("perf maps: Switch from rbtree to lazily
sorted array for addresses"):
# Overhead Command Shared Object Symbol
# ........ .......... .................
......................................
#
76.65% Coeur main [kernel.kallsyms] [k] finish_task_switch.isra.0
4.26% Coeur main gau [.]
engine_loop.constprop.0.isra.0
3.69% Coeur main [kernel.kallsyms] [k] do_epoll_wait
2.00% Coeur main [kernel.kallsyms] [k] timerfd_read_iter
0.96% Coeur main [kernel.kallsyms] [k] ep_start_scan
0.87% Coeur main [kernel.kallsyms] [k] __rseq_handle_notify_resume
0.79% Coeur main [kernel.kallsyms] [k] system_call_exception
0.71% Coeur main [kernel.kallsyms] [k] do_notify_resume
0.66% Coeur main [kernel.kallsyms] [k] timerfd_poll
0.63% Coeur main [kernel.kallsyms] [k] __copy_tofrom_user
0.57% Coeur main libc.so.6 [.] read
0.52% Coeur main [kernel.kallsyms] [k] ep_item_poll.isra.0
0.52% Coeur main [kernel.kallsyms] [k]
schedule_hrtimeout_range_clock
0.49% Coeur main [kernel.kallsyms] [k] ep_done_scan
0.46% Coeur main [kernel.kallsyms] [k] schedule
0.46% Coeur main libc.so.6 [.]
__GI___pthread_disable_asynccancel
Can you help fixing that ?
Christophe
^ permalink raw reply [flat|nested] 15+ messages in thread
* Re: Perf doesn't display kernel symbols anymore (bisected commit 659ad3492b91 ("perf maps: Switch from rbtree to lazily sorted array for addresses"))
2024-12-16 7:01 Perf doesn't display kernel symbols anymore (bisected commit 659ad3492b91 ("perf maps: Switch from rbtree to lazily sorted array for addresses")) Christophe Leroy
@ 2024-12-17 14:18 ` James Clark
2024-12-17 14:50 ` Christophe Leroy
2024-12-26 15:51 ` Arnaldo Carvalho de Melo
0 siblings, 2 replies; 15+ messages in thread
From: James Clark @ 2024-12-17 14:18 UTC (permalink / raw)
To: Christophe Leroy
Cc: linux-perf-users@vger.kernel.org, Peter Zijlstra, Ingo Molnar,
Arnaldo Carvalho de Melo, Namhyung Kim
On 16/12/2024 7:01 am, Christophe Leroy wrote:
> Hi,
>
> I noticed with 6.12 LTS Kernel that perf top and perf record/report
> don't display kernel symbols anymore, instead it displays the raw
> address with [unknown] as object.
>
> After bisect I see that the problem appears with commit 659ad3492b91
> ("perf maps: Switch from rbtree to lazily sorted array for addresses").
Hi Christophe,
You might want to try applying 0b90dfda222e3 as it claims to fix this
commit. I doubt that will fix your issue but it's worth being sure.
There was also another fix recently that could be related: 23c44f6c83
Did you try the perf-tools-next branch? Maybe something that's already
fixed needs to be backported.
Thanks
James
> Previous commit 39d14c0dd650 ("Merge branch 'perf-tools' into perf-
> tools-next") doesn't exbibit the problem.
>
> Now:
>
> # Overhead Command Shared Object Symbol
> # ........ .......... ............. ......................................
> #
> 80.49% Coeur main [unknown] [k] 0xc005f0f8
> 3.91% Coeur main gau [.] engine_loop.constprop.0.isra.0
> 1.72% Coeur main [unknown] [k] 0xc005f11c
> 1.09% Coeur main [unknown] [k] 0xc01f82c8
> 0.44% Coeur main libc.so.6 [.] epoll_wait
> 0.38% Coeur main [unknown] [k] 0xc0011718
> 0.36% Coeur main [unknown] [k] 0xc01f45c0
> 0.22% Coeur main libc.so.6 [.]
> __GI___pthread_enable_asynccancel
> 0.19% Coeur main libc.so.6 [.]
> __GI___pthread_disable_asynccancel
> 0.19% Coeur main [unknown] [k] 0xc0011170
> 0.19% Coeur main [unknown] [k] 0xc019ac64
> 0.19% Coeur main [unknown] [k] 0xc01f54bc
> 0.16% Coeur main libc.so.6 [.] read
>
> Before commit 659ad3492b91 ("perf maps: Switch from rbtree to lazily
> sorted array for addresses"):
>
> # Overhead Command Shared Object Symbol
> # ........ .......... ................. ......................................
> #
> 76.65% Coeur main [kernel.kallsyms] [k] finish_task_switch.isra.0
> 4.26% Coeur main gau [.]
> engine_loop.constprop.0.isra.0
> 3.69% Coeur main [kernel.kallsyms] [k] do_epoll_wait
> 2.00% Coeur main [kernel.kallsyms] [k] timerfd_read_iter
> 0.96% Coeur main [kernel.kallsyms] [k] ep_start_scan
> 0.87% Coeur main [kernel.kallsyms] [k] __rseq_handle_notify_resume
> 0.79% Coeur main [kernel.kallsyms] [k] system_call_exception
> 0.71% Coeur main [kernel.kallsyms] [k] do_notify_resume
> 0.66% Coeur main [kernel.kallsyms] [k] timerfd_poll
> 0.63% Coeur main [kernel.kallsyms] [k] __copy_tofrom_user
> 0.57% Coeur main libc.so.6 [.] read
> 0.52% Coeur main [kernel.kallsyms] [k] ep_item_poll.isra.0
> 0.52% Coeur main [kernel.kallsyms] [k]
> schedule_hrtimeout_range_clock
> 0.49% Coeur main [kernel.kallsyms] [k] ep_done_scan
> 0.46% Coeur main [kernel.kallsyms] [k] schedule
> 0.46% Coeur main libc.so.6 [.]
> __GI___pthread_disable_asynccancel
>
> Can you help fixing that ?
>
> Christophe
>
^ permalink raw reply [flat|nested] 15+ messages in thread
* Re: Perf doesn't display kernel symbols anymore (bisected commit 659ad3492b91 ("perf maps: Switch from rbtree to lazily sorted array for addresses"))
2024-12-17 14:18 ` James Clark
@ 2024-12-17 14:50 ` Christophe Leroy
2024-12-26 15:51 ` Arnaldo Carvalho de Melo
1 sibling, 0 replies; 15+ messages in thread
From: Christophe Leroy @ 2024-12-17 14:50 UTC (permalink / raw)
To: James Clark, irogers@google.com
Cc: linux-perf-users@vger.kernel.org, Peter Zijlstra, Ingo Molnar,
Arnaldo Carvalho de Melo, Namhyung Kim
Le 17/12/2024 à 15:18, James Clark a écrit :
> [Vous ne recevez pas souvent de courriers de james.clark@linaro.org.
> Découvrez pourquoi ceci est important à https://aka.ms/
> LearnAboutSenderIdentification ]
>
> On 16/12/2024 7:01 am, Christophe Leroy wrote:
>> Hi,
>>
>> I noticed with 6.12 LTS Kernel that perf top and perf record/report
>> don't display kernel symbols anymore, instead it displays the raw
>> address with [unknown] as object.
>>
>> After bisect I see that the problem appears with commit 659ad3492b91
>> ("perf maps: Switch from rbtree to lazily sorted array for addresses").
>
> Hi Christophe,
Hi James,
>
> You might want to try applying 0b90dfda222e3 as it claims to fix this
> commit. I doubt that will fix your issue but it's worth being sure.
It doesn't fix the problem.
>
> There was also another fix recently that could be related: 23c44f6c83
>
> Did you try the perf-tools-next branch? Maybe something that's already
> fixed needs to be backported.
>
I didn't, trying it now and facing the following issue:
A new definition of MAX_NR_CPUS is added by commit e8399d34d568
("libperf cpumap: Hide/reduce scope of MAX_NR_CPUS"), conflicting with
the -DMAX_NR_CPUS=1 that I provide as EXTRA_CFLAGS for the reason
explained in commit 21b8732eb447 ("perf tools: Allow overriding
MAX_NR_CPUS at compile time")
After fixing that, I'm now able to build it and test it. Unfortunately
it doesn't solve the issue.
Christophe
^ permalink raw reply [flat|nested] 15+ messages in thread
* Re: Perf doesn't display kernel symbols anymore (bisected commit 659ad3492b91 ("perf maps: Switch from rbtree to lazily sorted array for addresses"))
2024-12-17 14:18 ` James Clark
2024-12-17 14:50 ` Christophe Leroy
@ 2024-12-26 15:51 ` Arnaldo Carvalho de Melo
2025-01-02 14:41 ` Christophe Leroy
1 sibling, 1 reply; 15+ messages in thread
From: Arnaldo Carvalho de Melo @ 2024-12-26 15:51 UTC (permalink / raw)
To: James Clark
Cc: Christophe Leroy, linux-perf-users@vger.kernel.org,
Peter Zijlstra, Ingo Molnar, Namhyung Kim
On Tue, Dec 17, 2024 at 02:18:07PM +0000, James Clark wrote:
> On 16/12/2024 7:01 am, Christophe Leroy wrote:
> > I noticed with 6.12 LTS Kernel that perf top and perf record/report
> > don't display kernel symbols anymore, instead it displays the raw
> > address with [unknown] as object.
> > After bisect I see that the problem appears with commit 659ad3492b91
> > ("perf maps: Switch from rbtree to lazily sorted array for addresses").
> You might want to try applying 0b90dfda222e3 as it claims to fix this
> commit. I doubt that will fix your issue but it's worth being sure.
> There was also another fix recently that could be related: 23c44f6c83
> Did you try the perf-tools-next branch? Maybe something that's already fixed
> needs to be backported.
Right, I tried reproducing this on perf-tools-next and couldn't, so
please test it there.
Thanks,
- Arnaldo
^ permalink raw reply [flat|nested] 15+ messages in thread
* Re: Perf doesn't display kernel symbols anymore (bisected commit 659ad3492b91 ("perf maps: Switch from rbtree to lazily sorted array for addresses"))
2024-12-26 15:51 ` Arnaldo Carvalho de Melo
@ 2025-01-02 14:41 ` Christophe Leroy
2025-01-02 17:52 ` Christophe Leroy
2025-01-02 18:19 ` Arnaldo Carvalho de Melo
0 siblings, 2 replies; 15+ messages in thread
From: Christophe Leroy @ 2025-01-02 14:41 UTC (permalink / raw)
To: Arnaldo Carvalho de Melo, James Clark
Cc: linux-perf-users@vger.kernel.org, Peter Zijlstra, Ingo Molnar,
Namhyung Kim
Hi Arnaldo,
Le 26/12/2024 à 16:51, Arnaldo Carvalho de Melo a écrit :
> On Tue, Dec 17, 2024 at 02:18:07PM +0000, James Clark wrote:
>> On 16/12/2024 7:01 am, Christophe Leroy wrote:
>>> I noticed with 6.12 LTS Kernel that perf top and perf record/report
>>> don't display kernel symbols anymore, instead it displays the raw
>>> address with [unknown] as object.
>
>>> After bisect I see that the problem appears with commit 659ad3492b91
>>> ("perf maps: Switch from rbtree to lazily sorted array for addresses").
>
>> You might want to try applying 0b90dfda222e3 as it claims to fix this
>> commit. I doubt that will fix your issue but it's worth being sure.
>
>> There was also another fix recently that could be related: 23c44f6c83
>
>> Did you try the perf-tools-next branch? Maybe something that's already fixed
>> needs to be backported.
>
> Right, I tried reproducing this on perf-tools-next and couldn't, so
> please test it there.
>
I tested it again on latest perf-tools-next (ed60738a9b7e ("perf stat:
Document and clarify outstate members")) and still have the same
problem, all kernel symbols appear as [unknown]:
PerfTop: 4163 irqs/sec kernel:28.3% exact: 0.0% lost: 0/0
drop: 0/14199 [4000Hz cpu-clock:ppp], (all, 1 CPU)
-------------------------------------------------------------------------------
5.75% [unknown] [k] 0xc005f11c
4.96% gau [.] engine_loop.constprop.0.isra.0
4.31% perf [.] hists__findnew_entry
4.13% [unknown] [k] 0xc0891c14
3.43% libc.so.6 [.] memset
3.11% perf [.] dso__find_symbol
2.63% perf [.] evsel__parse_sample
2.23% perf [.] deliver_event
2.06% perf [.] sort__dso_cmp
2.02% perf [.] sort__sym_cmp
1.92% perf [.] machine__resolve
1.72% libc.so.6 [.] _int_free
1.59% perf [.] perf_hpp__is_dynamic_entry
1.38% perf [.] __hists__add_entry.constprop.0
1.37% perf [.] maps__find
1.26% [unknown] [k] 0xc01f82c8
1.24% libc.so.6 [.] pthread_rwlock_unlock@@GLIBC_2.34
1.20% perf [.] down_read
1.18% libc.so.6 [.] cfree@GLIBC_2.0
1.12% libc.so.6 [.] pthread_rwlock_rdlock@@GLIBC_2.34
Thanks,
Christophe
^ permalink raw reply [flat|nested] 15+ messages in thread
* Re: Perf doesn't display kernel symbols anymore (bisected commit 659ad3492b91 ("perf maps: Switch from rbtree to lazily sorted array for addresses"))
2025-01-02 14:41 ` Christophe Leroy
@ 2025-01-02 17:52 ` Christophe Leroy
2025-01-02 18:19 ` Arnaldo Carvalho de Melo
1 sibling, 0 replies; 15+ messages in thread
From: Christophe Leroy @ 2025-01-02 17:52 UTC (permalink / raw)
To: Arnaldo Carvalho de Melo, James Clark
Cc: linux-perf-users@vger.kernel.org, Peter Zijlstra, Ingo Molnar,
Namhyung Kim
Le 02/01/2025 à 15:41, Christophe Leroy a écrit :
> Hi Arnaldo,
>
> Le 26/12/2024 à 16:51, Arnaldo Carvalho de Melo a écrit :
>> On Tue, Dec 17, 2024 at 02:18:07PM +0000, James Clark wrote:
>>> On 16/12/2024 7:01 am, Christophe Leroy wrote:
>>>> I noticed with 6.12 LTS Kernel that perf top and perf record/report
>>>> don't display kernel symbols anymore, instead it displays the raw
>>>> address with [unknown] as object.
>>
>>>> After bisect I see that the problem appears with commit 659ad3492b91
>>>> ("perf maps: Switch from rbtree to lazily sorted array for addresses").
>>> You might want to try applying 0b90dfda222e3 as it claims to fix this
>>> commit. I doubt that will fix your issue but it's worth being sure.
>>> There was also another fix recently that could be related: 23c44f6c83
>>> Did you try the perf-tools-next branch? Maybe something that's
>>> already fixed
>>> needs to be backported.
>>
>> Right, I tried reproducing this on perf-tools-next and couldn't, so
>> please test it there.
>>
>
> I tested it again on latest perf-tools-next (ed60738a9b7e ("perf stat:
> Document and clarify outstate members")) and still have the same
> problem, all kernel symbols appear as [unknown]:
>
> PerfTop: 4163 irqs/sec kernel:28.3% exact: 0.0% lost: 0/0
> drop: 0/14199 [4000Hz cpu-clock:ppp], (all, 1 CPU)
> -------------------------------------------------------------------------------
>
> 5.75% [unknown] [k] 0xc005f11c
> 4.96% gau [.] engine_loop.constprop.0.isra.0
> 4.31% perf [.] hists__findnew_entry
> 4.13% [unknown] [k] 0xc0891c14
> 3.43% libc.so.6 [.] memset
> 3.11% perf [.] dso__find_symbol
> 2.63% perf [.] evsel__parse_sample
> 2.23% perf [.] deliver_event
> 2.06% perf [.] sort__dso_cmp
> 2.02% perf [.] sort__sym_cmp
> 1.92% perf [.] machine__resolve
> 1.72% libc.so.6 [.] _int_free
> 1.59% perf [.] perf_hpp__is_dynamic_entry
> 1.38% perf [.] __hists__add_entry.constprop.0
> 1.37% perf [.] maps__find
> 1.26% [unknown] [k] 0xc01f82c8
> 1.24% libc.so.6 [.] pthread_rwlock_unlock@@GLIBC_2.34
> 1.20% perf [.] down_read
> 1.18% libc.so.6 [.] cfree@GLIBC_2.0
> 1.12% libc.so.6 [.] pthread_rwlock_rdlock@@GLIBC_2.34
If it helps, here is how I build perf:
make ARCH=powerpc CROSS_COMPILE=ppc-linux- WERROR=0 NO_SLANG=y NO_GTK2=y
NO_LIBPYTHON=y NO_LIBAUDIT=y NO_LIBNUMA=y NO_LIBBPF=y
EXTRA_CFLAGS="-DMAX_NR_CPUS=1 -fPIE" NO_LIBTRACEEVENT=1
Christophe
^ permalink raw reply [flat|nested] 15+ messages in thread
* Re: Perf doesn't display kernel symbols anymore (bisected commit 659ad3492b91 ("perf maps: Switch from rbtree to lazily sorted array for addresses"))
2025-01-02 14:41 ` Christophe Leroy
2025-01-02 17:52 ` Christophe Leroy
@ 2025-01-02 18:19 ` Arnaldo Carvalho de Melo
2025-01-02 19:42 ` Christophe Leroy
1 sibling, 1 reply; 15+ messages in thread
From: Arnaldo Carvalho de Melo @ 2025-01-02 18:19 UTC (permalink / raw)
To: Christophe Leroy
Cc: James Clark, linux-perf-users@vger.kernel.org, Peter Zijlstra,
Ingo Molnar, Namhyung Kim
On Thu, Jan 02, 2025 at 03:41:17PM +0100, Christophe Leroy wrote:
> Le 26/12/2024 à 16:51, Arnaldo Carvalho de Melo a écrit :
> > On Tue, Dec 17, 2024 at 02:18:07PM +0000, James Clark wrote:
> > > On 16/12/2024 7:01 am, Christophe Leroy wrote:
> > > > I noticed with 6.12 LTS Kernel that perf top and perf record/report
> > > > don't display kernel symbols anymore, instead it displays the raw
> > > > address with [unknown] as object.
> > > > After bisect I see that the problem appears with commit 659ad3492b91
> > > > ("perf maps: Switch from rbtree to lazily sorted array for addresses").
> > > You might want to try applying 0b90dfda222e3 as it claims to fix this
> > > commit. I doubt that will fix your issue but it's worth being sure.
> > > There was also another fix recently that could be related: 23c44f6c83
> > > Did you try the perf-tools-next branch? Maybe something that's already fixed
> > > needs to be backported.
> > Right, I tried reproducing this on perf-tools-next and couldn't, so
> > please test it there.
> I tested it again on latest perf-tools-next (ed60738a9b7e ("perf stat:
> Document and clarify outstate members")) and still have the same problem,
> all kernel symbols appear as [unknown]:
> PerfTop: 4163 irqs/sec kernel:28.3% exact: 0.0% lost: 0/0 drop:
> 0/14199 [4000Hz cpu-clock:ppp], (all, 1 CPU)
So this seems to be on a virt environment? Or have you explicitely used
'-e cpu-clock:ppp'?
Also can you please run with -v or with -vv to see if we can get some
more clues?
Maybe it is somehow not able to read kallsyms or find a suitable
vmlinux?
Also what distro is this?
I did one more test, this time using --stdio on a raspberry pi and
explicitely using '-e cycles:ppp' to get as close to your report as I
could:
root@raspberrypi:~# uname -a
Linux raspberrypi 6.6.51+rpt-rpi-v7 #1 SMP Raspbian 1:6.6.51-1+rpt3 (2024-10-08) armv7l GNU/Linux
root@raspberrypi:~# ~acme/bin/perf --version
perf version 6.13.rc2.ged60738a9b7e
root@raspberrypi:~# timeout 5s ~acme/bin/perf top -e cpu-cycles:ppp --stdio
PerfTop: 926 irqs/sec kernel:79.8% exact: 0.0% lost: 0/0 drop: 0/0 [4000Hz cpu-cycles:ppp], (all, 4 CPUs)
----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
12.08% perf [.] io__get_char
8.54% perf [.] kallsyms__parse
5.35% perf [.] __symbols__insert
3.87% [kernel] [k] module_get_kallsym
3.74% [kernel] [k] default_idle_call
3.69% perf [.] io__get_hex
3.50% [kernel] [k] kallsyms_expand_symbol.constprop.0
3.21% perf [.] rb_next
2.84% [kernel] [k] format_decode
2.53% [kernel] [k] number
2.29% [kernel] [k] vsnprintf
2.07% libc.so.6 [.] __libc_calloc
1.96% libc.so.6 [.] strchr
1.76% [kernel] [k] string
1.47% perf [.] symbol__new
1.42% perf [.] dso__load_sym_internal
1.36% libarmmem-v7l.so [.] strlen
1.26% [kernel] [k] memcpy
1.15% libc.so.6 [.] _int_malloc
1.00% perf [.] strlist__node_cmp
0.93% perf [.] rb_insert_color
0.91% [kernel] [k] update_iter
0.82% perf [.] eprintf
0.80% perf [.] rblist__find
0.79% libc.so.6 [.] memset
0.74% perf [.] map__process_kallsym_symbol
0.73% [kernel] [k] finish_task_switch
0.69% perf [.] veprintf
0.57% [kernel] [k] strscpy
0.55% perf [.] perf_hpp__is_dynamic_entry
0.49% libelf-0.188.so [.] gelf_getsym
0.48% [kernel] [k] seq_printf
0.48% libelf-0.188.so [.] gelf_getphdr
0.46% libc.so.6 [.] strcmp
0.45% [kernel] [k] memset
0.40% [kernel] [k] s_show
0.40% [kernel] [k] pointer
0.37% [kernel] [k] seq_read_iter
0.35% perf [.] hist_entry__cmp
root@raspberrypi:~#
^ permalink raw reply [flat|nested] 15+ messages in thread
* Re: Perf doesn't display kernel symbols anymore (bisected commit 659ad3492b91 ("perf maps: Switch from rbtree to lazily sorted array for addresses"))
2025-01-02 18:19 ` Arnaldo Carvalho de Melo
@ 2025-01-02 19:42 ` Christophe Leroy
2025-01-03 1:08 ` Arnaldo Carvalho de Melo
0 siblings, 1 reply; 15+ messages in thread
From: Christophe Leroy @ 2025-01-02 19:42 UTC (permalink / raw)
To: Arnaldo Carvalho de Melo
Cc: James Clark, linux-perf-users@vger.kernel.org, Peter Zijlstra,
Ingo Molnar, Namhyung Kim
Le 02/01/2025 à 19:19, Arnaldo Carvalho de Melo a écrit :
> On Thu, Jan 02, 2025 at 03:41:17PM +0100, Christophe Leroy wrote:
>> Le 26/12/2024 à 16:51, Arnaldo Carvalho de Melo a écrit :
>>> On Tue, Dec 17, 2024 at 02:18:07PM +0000, James Clark wrote:
>>>> On 16/12/2024 7:01 am, Christophe Leroy wrote:
>>>>> I noticed with 6.12 LTS Kernel that perf top and perf record/report
>>>>> don't display kernel symbols anymore, instead it displays the raw
>>>>> address with [unknown] as object.
>
>>>>> After bisect I see that the problem appears with commit 659ad3492b91
>>>>> ("perf maps: Switch from rbtree to lazily sorted array for addresses").
>>>> You might want to try applying 0b90dfda222e3 as it claims to fix this
>>>> commit. I doubt that will fix your issue but it's worth being sure.
>>>> There was also another fix recently that could be related: 23c44f6c83
>>>> Did you try the perf-tools-next branch? Maybe something that's already fixed
>>>> needs to be backported.
>
>>> Right, I tried reproducing this on perf-tools-next and couldn't, so
>>> please test it there.
>
>> I tested it again on latest perf-tools-next (ed60738a9b7e ("perf stat:
>> Document and clarify outstate members")) and still have the same problem,
>> all kernel symbols appear as [unknown]:
>
>> PerfTop: 4163 irqs/sec kernel:28.3% exact: 0.0% lost: 0/0 drop:
>> 0/14199 [4000Hz cpu-clock:ppp], (all, 1 CPU)
>
> So this seems to be on a virt environment? Or have you explicitely used
> '-e cpu-clock:ppp'?
It is a real HW and I have _not_ used -e cpu-clock:ppp
root@vgoippro:~# cat /proc/cpuinfo
processor : 0
cpu : e300c2
clock : 333.333335MHz
revision : 1.1 (pvr 8084 0011)
bogomips : 66.66
timebase : 33333333
platform : CMPCPRO
model : MIAE
Memory : 512 MB
>
> Also can you please run with -v or with -vv to see if we can get some
> more clues?
Sure, see at the end (first is the one that fails, followed by the one
that works)
>
> Maybe it is somehow not able to read kallsyms or find a suitable
> vmlinux?
There's no vmlinux but it should be able to read kallsyms as it does
with earlier version
>
> Also what distro is this?
No distro, it's raw embedded system built from scratch with gcc 12.3 and
glibc 2.38
>
> I did one more test, this time using --stdio on a raspberry pi and
> explicitely using '-e cycles:ppp' to get as close to your report as I
> could:
>
> root@raspberrypi:~# uname -a
> Linux raspberrypi 6.6.51+rpt-rpi-v7 #1 SMP Raspbian 1:6.6.51-1+rpt3 (2024-10-08) armv7l GNU/Linux
> root@raspberrypi:~# ~acme/bin/perf --version
> perf version 6.13.rc2.ged60738a9b7e
> root@raspberrypi:~# timeout 5s ~acme/bin/perf top -e cpu-cycles:ppp --stdio
> PerfTop: 926 irqs/sec kernel:79.8% exact: 0.0% lost: 0/0 drop: 0/0 [4000Hz cpu-cycles:ppp], (all, 4 CPUs)
root@vgoippro:~# uname -a
Linux vgoippro 6.12.4-01797-g8ba9a9738762 #556 PREEMPT Sun Dec 15
19:22:33 CET 2024 ppc GNU/Linux
root@vgoippro:~# ./perf --version
perf version 6.13.rc2.ged60738a9b7e
root@vgoippro:~# timeout 5s ./perf top --stdio
PerfTop: 0 irqs/sec kernel: 0.0% exact: 0.0% lost: 0/0
drop: 0/0 [4000Hz cpu-clock:ppp], (all, 1 CPU)
-------------------------------------------------------------------------------
PerfTop: 524 irqs/sec kernel:51.1% exact: 0.0% lost: 0/0
drop: 0/0 [4000Hz cpu-clock:ppp], (all, 1 CPU)
-------------------------------------------------------------------------------
17.18% [unknown] [k] 0xc0891c14
7.63% [unknown] [k] 0xc005f11c
4.48% libc.so.6 [.] _nss_files_parse_servent
4.10% gau [.] engine_loop.constprop.0.isra.0
3.91% libc.so.6 [.] memset
3.24% libc.so.6 [.] strcspn
3.05% libc.so.6 [.] __GI_____strtoul_l_internal
2.48% libc.so.6 [.] memcpy
2.19% libc.so.6 [.] memchr
2.00% libc.so.6 [.] _wordcopy_fwd_dest_aligned
2.00% [unknown] [k] 0xc005f0f8
1.81% libc.so.6 [.] _IO_getline_info
1.81% libc.so.6 [.] strlen
1.72% libc.so.6 [.] strcmp
1.62% libc.so.6 [.] __ftello64
1.62% libc.so.6 [.] internal_getent
1.53% libc.so.6 [.] _IO_seekoff_unlocked
1.15% libc.so.6 [.] __nss_readline
1.05% libc.so.6 [.] _wordcopy_fwd_aligned
1.05% [unknown] [k] 0xc01f82c8
As a comparison, the following one works:
root@vgoippro:~# ./perf-good --version
perf version 6.8.rc1.g39d14c0dd650
root@vgoippro:~# timeout 6s ./perf-good top --stdio
PerfTop: 0 irqs/sec kernel: 0.0% exact: 0.0% lost: 0/0
drop: 0/0 [4000Hz cpu-clock:ppp], (all, 1 CPU)
-------------------------------------------------------------------------------
PerfTop: 0 irqs/sec kernel: 0.0% exact: 0.0% lost: 0/0
drop: 0/0 [4000Hz cpu-clock:ppp], (all, 1 CPU)
-------------------------------------------------------------------------------
PerfTop: 451 irqs/sec kernel:31.7% exact: 0.0% lost: 0/0
drop: 7575/7575 [4000Hz cpu-clock:ppp], (all, 1 CPU)
-------------------------------------------------------------------------------
9.60% perf-good [.] io__get_char
6.40% perf-good [.] __symbols__insert
5.19% gau [.] engine_loop.constprop.0.isra.0
4.08% [kernel] [k] finish_task_switch.isra.0
3.64% perf-good [.] kallsyms__parse
3.20% libc.so.6 [.] memset
2.98% [kernel] [k] kallsyms_expand_symbol.constprop.0
2.65% libc.so.6 [.] memcpy
2.54% [kernel] [k] format_decode
2.43% libc.so.6 [.] __libc_calloc
2.32% libc.so.6 [.] _wordcopy_fwd_dest_aligned
2.32% perf-good [.] io__get_hex
1.99% libc.so.6 [.] __GI_____strtoul_l_internal
1.88% libc.so.6 [.] _int_malloc
1.88% libc.so.6 [.] got_label
1.77% libc.so.6 [.] _nss_files_parse_servent
1.66% libc.so.6 [.] strcspn
1.66% perf-good [.] strlist__node_cmp
1.55% [kernel] [k] __copy_tofrom_user
1.55% [kernel] [k] string
Here is the output with -vv of the one that fails:
Using CPUID 0x80840011
Problems creating module maps, continuing anyway...
------------------------------------------------------------
perf_event_attr:
type 0 (PERF_TYPE_HARDWARE)
size 136
config 0 (PERF_COUNT_HW_CPU_CYCLES)
{ sample_period, sample_freq } 4000
sample_type IP|TID|TIME|CPU|PERIOD
read_format ID|LOST
disabled 1
mmap 1
comm 1
freq 1
task 1
precise_ip 3
sample_id_all 1
mmap2 1
comm_exec 1
ksymbol 1
bpf_event 1
------------------------------------------------------------
sys_perf_event_open: pid -1 cpu 0 group_fd -1 flags 0x8
sys_perf_event_open failed, error -2
decreasing precise_ip by one (2)
------------------------------------------------------------
perf_event_attr:
type 0 (PERF_TYPE_HARDWARE)
size 136
config 0 (PERF_COUNT_HW_CPU_CYCLES)
{ sample_period, sample_freq } 4000
sample_type IP|TID|TIME|CPU|PERIOD
read_format ID|LOST
disabled 1
mmap 1
comm 1
freq 1
task 1
precise_ip 2
sample_id_all 1
mmap2 1
comm_exec 1
ksymbol 1
bpf_event 1
------------------------------------------------------------
sys_perf_event_open: pid -1 cpu 0 group_fd -1 flags 0x8
sys_perf_event_open failed, error -2
decreasing precise_ip by one (1)
------------------------------------------------------------
perf_event_attr:
type 0 (PERF_TYPE_HARDWARE)
size 136
config 0 (PERF_COUNT_HW_CPU_CYCLES)
{ sample_period, sample_freq } 4000
sample_type IP|TID|TIME|CPU|PERIOD
read_format ID|LOST
disabled 1
mmap 1
comm 1
freq 1
task 1
precise_ip 1
sample_id_all 1
mmap2 1
comm_exec 1
ksymbol 1
bpf_event 1
------------------------------------------------------------
sys_perf_event_open: pid -1 cpu 0 group_fd -1 flags 0x8
sys_perf_event_open failed, error -2
decreasing precise_ip by one (0)
------------------------------------------------------------
perf_event_attr:
type 0 (PERF_TYPE_HARDWARE)
size 136
config 0 (PERF_COUNT_HW_CPU_CYCLES)
{ sample_period, sample_freq } 4000
sample_type IP|TID|TIME|CPU|PERIOD
read_format ID|LOST
disabled 1
mmap 1
comm 1
freq 1
task 1
sample_id_all 1
mmap2 1
comm_exec 1
ksymbol 1
bpf_event 1
------------------------------------------------------------
sys_perf_event_open: pid -1 cpu 0 group_fd -1 flags 0x8
sys_perf_event_open failed, error -2
Warning:
The cycles event is not supported, trying to fall back to cpu-clock
------------------------------------------------------------
perf_event_attr:
type 1 (software)
size 136
config 0 (PERF_COUNT_SW_CPU_CLOCK)
{ sample_period, sample_freq } 4000
sample_type IP|TID|TIME|CPU|PERIOD
read_format ID|LOST
disabled 1
mmap 1
comm 1
freq 1
task 1
precise_ip 3
sample_id_all 1
mmap2 1
comm_exec 1
ksymbol 1
bpf_event 1
------------------------------------------------------------
sys_perf_event_open: pid -1 cpu 0 group_fd -1 flags 0x8 = 3
mmap size 528384B
0x11b71568: mmap mask[0]:
Missing PLT entry size for /lib/libc.so.6
Missing PLT entry size for /usr/local/bin/gau
Missing PLT entry size for /root/perf
Missing PLT entry size for /lib/libelf-0.176.so
^[[H^[[2J
PerfTop: 0 irqs/sec kernel: 0.0% exact: 0.0% lost: 0/0
drop: 0/0 [4000Hz cpu-clock:ppp], (all, 1 CPU)
-------------------------------------------------------------------------------
^[[H^[[2J
PerfTop: 259 irqs/sec kernel:86.1% exact: 0.0% lost: 0/0
drop: 0/0 [4000Hz cpu-clock:ppp], (all, 1 CPU)
-------------------------------------------------------------------------------
35.33% [unknown] 0xc0891c14 ! [k] 0xc0891c14
---------- end
12.93% [unknown] 0xc005f11c ! [k] 0xc005f11c
Map: f8c0000-f8dc000 0 /lib/nof/libgcc_s.so.1
Map: f8f0000-f8f1000 20000 /lib/nof/libgcc_s.so.1
Map: f900000-f909000 0 /lib/libcrypt.so.1
Map: f920000-f921000 10000 /lib/libcrypt.so.1
Map: f921000-f948000 0 /tmp/perf-863.map
Map: f950000-fb4f000 0 /lib/libc.so.6
Map: fb70000-fb74000 220000 /lib/libc.so.6
Map: fb74000-fb7e000 0 /tmp/perf-863.map
Map: fb80000-fdd8000 0 /lib/nof/libstdc++.so.6.0.30
Map: fdf0000-fdf1000 260000 /lib/nof/libstdc++.so.6.0.30
Map: fdf1000-fdf7000 0 /tmp/perf-863.map
Map: fe00000-fe59000 0 /lib/libdw-0.176.so
Map: fe70000-fe71000 60000 /lib/libdw-0.176.so
Map: fe80000-fe9b000 0 /lib/libelf-0.176.so
Map: feb0000-feb1000 20000 /lib/libelf-0.176.so
Map: fec0000-fee2000 0 /lib/libz.so.1.2.12
Map: ff00000-ff01000 30000 /lib/libz.so.1.2.12
Map: ff10000-ffe0000 0 /lib/libm.so.6
Map: fff0000-fff1000 d0000 /lib/libm.so.6
Map: 10000000-10341000 0 /root/perf
Map: 10360000-1036a000 360000 /root/perf
Map: 1036a000-1036f000 0 /tmp/perf-863.map
Map: b77f2000-b77f9000 0 [vdso]
Map: b77fe000-b782e000 0 /lib/ld.so.1
Map: b783e000-b7840000 40000 /lib/ld.so.1
---------- end
4.83% /usr/local/bin/gau 0x7218c d [.]
engine_loop.constprop.0.isra.
4.63% [unknown] 0xc005f0f8 ! [k] 0xc005f0f8
Map: f8c0000-f8dc000 0 /lib/nof/libgcc_s.so.1
Map: f8f0000-f8f1000 20000 /lib/nof/libgcc_s.so.1
Map: f900000-f909000 0 /lib/libcrypt.so.1
Map: f920000-f921000 10000 /lib/libcrypt.so.1
Map: f921000-f948000 0 /tmp/perf-863.map
Map: f950000-fb4f000 0 /lib/libc.so.6
Map: fb70000-fb74000 220000 /lib/libc.so.6
Map: fb74000-fb7e000 0 /tmp/perf-863.map
Map: fb80000-fdd8000 0 /lib/nof/libstdc++.so.6.0.30
Map: fdf0000-fdf1000 260000 /lib/nof/libstdc++.so.6.0.30
Map: fdf1000-fdf7000 0 /tmp/perf-863.map
Map: fe00000-fe59000 0 /lib/libdw-0.176.so
Map: fe70000-fe71000 60000 /lib/libdw-0.176.so
Map: fe80000-fe9b000 0 /lib/libelf-0.176.so
Map: feb0000-feb1000 20000 /lib/libelf-0.176.so
Map: fec0000-fee2000 0 /lib/libz.so.1.2.12
Map: ff00000-ff01000 30000 /lib/libz.so.1.2.12
Map: ff10000-ffe0000 0 /lib/libm.so.6
Map: fff0000-fff1000 d0000 /lib/libm.so.6
Map: 10000000-10341000 0 /root/perf
Map: 10360000-1036a000 360000 /root/perf
Map: 1036a000-1036f000 0 /tmp/perf-863.map
Map: b77f2000-b77f9000 0 [vdso]
Map: b77fe000-b782e000 0 /lib/ld.so.1
Map: b783e000-b7840000 40000 /lib/ld.so.1
---------- end
1.93% [unknown] 0xc0067d90 ! [k] 0xc0067d90
---------- end
1.35% [unknown] 0xc0011718 ! [k] 0xc0011718
Map: f8c0000-f8dc000 0 /lib/nof/libgcc_s.so.1
Map: f8f0000-f8f1000 20000 /lib/nof/libgcc_s.so.1
Map: f900000-f909000 0 /lib/libcrypt.so.1
Map: f920000-f921000 10000 /lib/libcrypt.so.1
Map: f921000-f948000 0 /tmp/perf-863.map
Map: f950000-fb4f000 0 /lib/libc.so.6
Map: fb70000-fb74000 220000 /lib/libc.so.6
Map: fb74000-fb7e000 0 /tmp/perf-863.map
Map: fb80000-fdd8000 0 /lib/nof/libstdc++.so.6.0.30
Map: fdf0000-fdf1000 260000 /lib/nof/libstdc++.so.6.0.30
Map: fdf1000-fdf7000 0 /tmp/perf-863.map
Map: fe00000-fe59000 0 /lib/libdw-0.176.so
Map: fe70000-fe71000 60000 /lib/libdw-0.176.so
Map: fe80000-fe9b000 0 /lib/libelf-0.176.so
Map: feb0000-feb1000 20000 /lib/libelf-0.176.so
Map: fec0000-fee2000 0 /lib/libz.so.1.2.12
Map: ff00000-ff01000 30000 /lib/libz.so.1.2.12
Map: ff10000-ffe0000 0 /lib/libm.so.6
Map: fff0000-fff1000 d0000 /lib/libm.so.6
Map: 10000000-10341000 0 /root/perf
Map: 10360000-1036a000 360000 /root/perf
Map: 1036a000-1036f000 0 /tmp/perf-863.map
Map: b77f2000-b77f9000 0 [vdso]
Map: b77fe000-b782e000 0 /lib/ld.so.1
Map: b783e000-b7840000 40000 /lib/ld.so.1
------Missing PLT entry size for /lib/nof/libstdc++.so.6.0.30
---- end
1.16% [unknown] 0xc001a90c ! [k] 0xc001a90c
Map: f8c0000-f8dc000 0 /lib/nof/libgcc_s.so.1
Map: f8f0000-f8f1000 20000 /lib/nof/libgcc_s.so.1
Map: f900000-f909000 0 /lib/libcrypt.so.1
Map: f920000-f921000 10000 /lib/libcrypt.so.1
Map: f921000-f948000 0 /tmp/perf-863.map
Map: f950000-fb4f000 0 /lib/libc.so.6
Map: fb70000-fb74000 220000 /lib/libc.so.6
Map: fb74000-fb7e000 0 /tmp/perf-863.map
Map: fb80000-fdd8000 0 /lib/nof/libstdc++.so.6.0.30
Map: fdf0000-fdf1000 260000 /lib/nof/libstdc++.so.6.0.30
Map: fdf1000-fdf7000 0 /tmp/perf-863.map
Map: fe00000-fe59000 0 /lib/libdw-0.176.so
Map: fe70000-fe71000 60000 /lib/libdw-0.176.so
Map: fe80000-fe9b000 0 /lib/libelf-0.176.so
Map: feb0000-feb1000 20000 /lib/libelf-0.176.so
Map: fec0000-fee2000 0 /lib/libz.so.1.2.12
Map: ff00000-ff01000 30000 /lib/libz.so.1.2.12
Map: ff10000-ffe0000 0 /lib/libm.so.6
Map: fff0000-fff1000 d0000 /lib/libm.so.6
Map: 10000000-10341000 0 /root/perf
Map: 10360000-1036a000 360000 /root/perf
Map: 1036a000-1036f000 0 /tmp/perf-863.map
Map: b77f2000-b77f9000 0 [vdso]
Map: b77fe000-b782e000 0 /lib/ld.so.1
Map: b783e000-b7840000 40000 /lib/ld.so.1
---------- end
0.97% [unknown] 0xc0067da0 ! [k] 0xc0067da0
---------- end
0.97% [unknown] 0xc0891c18 ! [k] 0xc0891c18
---------- end
0.77% [unknown] 0xc001a908 ! [k] 0xc001a908
Map: f8c0000-f8dc000 0 /lib/nof/libgcc_s.so.1
Map: f8f0000-f8f1000 20000 /lib/nof/libgcc_s.so.1
Map: f900000-f909000 0 /lib/libcrypt.so.1
Map: f920000-f921000 10000 /lib/libcrypt.so.1
Map: f921000-f948000 0 /tmp/perf-863.map
Map: f950000-fb4f000 0 /lib/libc.so.6
Map: fb70000-fb74000 220000 /lib/libc.so.6
Map: fb74000-fb7e000 0 /tmp/perf-863.map
Map: fb80000-fdd8000 0 /lib/nof/libstdc++.so.6.0.30
Map: fdf0000-fdf1000 260000 /lib/nof/libstdc++.so.6.0.30
Map: fdf1000-fdf7000 0 /tmp/perf-863.map
Map: fe00000-fe59000 0 /lib/libdw-0.176.so
Map: fe70000-fe71000 60000 /lib/libdw-0.176.so
Map: fe80000-fe9b000 0 /lib/libelf-0.176.so
Map: feb0000-feb1000 20000 /lib/libelf-0.176.so
Map: fec0000-fee2000 0 /lib/libz.so.1.2.12
Map: ff00000-ff01000 30000 /lib/libz.so.1.2.12
Map: ff10000-ffe0000 0 /lib/libm.so.6
Map: fff0000-fff1000 d0000 /lib/libm.so.6
Map: 10000000-10341000 0 /root/perf
Map: 10360000-1036a000 360000 /root/perf
Map: 1036a000-1036f000 0 /tmp/perf-863.map
Map: b77f2000-b77f9000 0 [vdso]
Map: b77fe000-b782e000 0 /lib/ld.so.1
Map: b783e000-b7840000 40000 /lib/ld.so.1
---------- end
0.77% [unknown] 0xc0067d54 ! [k] 0xc0067d54
---------- end
0.77% [unknown] 0xc0067d94 ! [k] 0xc0067d94
---------- end
0.77% [unknown] 0xc0891c10 ! [k] 0xc0891c10
---------- end
0.58% /lib/libc.so.6 0x94f3c d [.]
__GI___pthread_disable_asyncc
0.58% /lib/libc.so.6 0xaed94 d [.] malloc
0.58% /root/perf 0x143c00 d [.] ordered_events__queue
0.58% [unknown] 0xc002d720 ! [k] 0xc002d720
---------- end
0.58% [unknown] 0xc0067d4c ! [k] 0xc0067d4c
---------- end
0.58% [unknown] 0xc0067da4 ! [k] 0xc0067da4
---------- end
0.58% [unknown] 0xc00a781c ! [k] 0xc00a781c
Here is the output of the one that works:
Using CPUID 0x80840011
Problems creating module maps, continuing anyway...
------------------------------------------------------------
perf_event_attr:
type 0 (PERF_TYPE_HARDWARE)
size 136
config 0 (PERF_COUNT_HW_CPU_CYCLES)
{ sample_period, sample_freq } 4000
sample_type IP|TID|TIME|CPU|PERIOD
read_format ID|LOST
disabled 1
inherit 1
mmap 1
comm 1
freq 1
task 1
precise_ip 3
sample_id_all 1
mmap2 1
comm_exec 1
ksymbol 1
bpf_event 1
------------------------------------------------------------
sys_perf_event_open: pid -1 cpu 0 group_fd -1 flags 0x8
sys_perf_event_open failed, error -2
decreasing precise_ip by one (2)
------------------------------------------------------------
perf_event_attr:
type 0 (PERF_TYPE_HARDWARE)
size 136
config 0 (PERF_COUNT_HW_CPU_CYCLES)
{ sample_period, sample_freq } 4000
sample_type IP|TID|TIME|CPU|PERIOD
read_format ID|LOST
disabled 1
inherit 1
mmap 1
comm 1
freq 1
task 1
precise_ip 2
sample_id_all 1
mmap2 1
comm_exec 1
ksymbol 1
bpf_event 1
------------------------------------------------------------
sys_perf_event_open: pid -1 cpu 0 group_fd -1 flags 0x8
sys_perf_event_open failed, error -2
decreasing precise_ip by one (1)
------------------------------------------------------------
perf_event_attr:
type 0 (PERF_TYPE_HARDWARE)
size 136
config 0 (PERF_COUNT_HW_CPU_CYCLES)
{ sample_period, sample_freq } 4000
sample_type IP|TID|TIME|CPU|PERIOD
read_format ID|LOST
disabled 1
inherit 1
mmap 1
comm 1
freq 1
task 1
precise_ip 1
sample_id_all 1
mmap2 1
comm_exec 1
ksymbol 1
bpf_event 1
------------------------------------------------------------
sys_perf_event_open: pid -1 cpu 0 group_fd -1 flags 0x8
sys_perf_event_open failed, error -2
decreasing precise_ip by one (0)
------------------------------------------------------------
perf_event_attr:
type 0 (PERF_TYPE_HARDWARE)
size 136
config 0 (PERF_COUNT_HW_CPU_CYCLES)
{ sample_period, sample_freq } 4000
sample_type IP|TID|TIME|CPU|PERIOD
read_format ID|LOST
disabled 1
inherit 1
mmap 1
comm 1
freq 1
task 1
sample_id_all 1
mmap2 1
comm_exec 1
ksymbol 1
bpf_event 1
------------------------------------------------------------
sys_perf_event_open: pid -1 cpu 0 group_fd -1 flags 0x8
sys_perf_event_open failed, error -2
Warning:
The cycles event is not supported, trying to fall back to cpu-clock
------------------------------------------------------------
perf_event_attr:
type 1 (PERF_TYPE_SOFTWARE)
size 136
config 0 (PERF_COUNT_SW_CPU_CLOCK)
{ sample_period, sample_freq } 4000
sample_type IP|TID|TIME|CPU|PERIOD
read_format ID|LOST
disabled 1
inherit 1
mmap 1
comm 1
freq 1
task 1
precise_ip 3
sample_id_all 1
mmap2 1
comm_exec 1
ksymbol 1
bpf_event 1
------------------------------------------------------------
sys_perf_event_open: pid -1 cpu 0 group_fd -1 flags 0x8 = 3
mmap size 528384B
0x11ed8e18: mmap mask[0]:
Missing PLT entry size for /lib/libc.so.6
Looking at the vmlinux_path (8 entries long)
symsrc__init: cannot get elf header.
Using /proc/kallsyms for symbols
Missing PLT entry size for /usr/local/bin/gau
Missing PLT entry size for /root/perf-good
Failed to open /tmp/perf-887.map, continuing without symbols
^[[H^[[2J
PerfTop: 0 irqs/sec kernel: 0.0% exact: 0.0% lost: 0/0
drop: 0/0 [4000Hz cpu-clock:ppp], (all, 1 CPU)
-------------------------------------------------------------------------------
^[[H^[[2J
PerfTop: 1 irqs/sec kernel: 0.0% exact: 0.0% lost: 0/0
drop: 0/0 [4000Hz cpu-clock:ppp], (all, 1 CPU)
-------------------------------------------------------------------------------
100.00% /lib/libc.so.6 0x46e64 d [.] __libc_sigaction
^[[H^[[2J
PerfTop: 99 irqs/sec kernel:41.4% exact: 0.0% lost: 0/0
drop: 7841/7841 [4000Hz cpu-clock:ppp], (all, 1 CPU)
-------------------------------------------------------------------------------
13.51% /root/perf-good 0x1e83f4 d [.] io__get_char
8.01% /root/perf-good 0xd6f7c d [.] __symbols__insert
6.50% /usr/local/bin/gau 0x72194 d [.]
engine_loop.constprop.0.isra.
6.50% [kernel.kallsyms] 0xc005f11c k [k] finish_task_switch.isra.0
5.00% /root/perf-good 0x1e8a24 d [.] kallsyms__parse
5.00% [kernel.kallsyms] 0xc0886ed0 k [k] number
3.50% [kernel.kallsyms] 0xc00c3644 k [k]
kallsyms_expand_symbol.constp
3.00% /lib/libc.so.6 0xadc6c d [.] _int_malloc
3.00% [kernel.kallsyms] 0xc088557c k [k] format_decode
3.00% [kernel.kallsyms] 0xc01f82c8 k [k] timerfd_read_iter
3.00% [kernel.kallsyms] 0xc088b920 k [k] vsnprintf
2.50% /lib/libc.so.6 0xb5d10 d [.] strcmp
2.50% [kernel.kallsyms] 0xc0888bc4 k [k] string
2.00% /root/perf-good 0xcc854 d [.] strlist__node_cmp
2.00% /root/perf-good 0xd6c10 d [.] symbol__new
1.50% /lib/libc.so.6 0xbcbb4 d [.] _wordcopy_fwd_aligned
1.50% /lib/libc.so.6 0xb4ae4 d [.] memset
1.50% /root/perf-good 0x1e8618 d [.] io__get_hex
1.50% [kernel.kallsyms] 0xc001a860 k [k] __copy_tofrom_user
1.50% [kernel.kallsyms] 0xc01f5248 k [k] do_epoll_wait
Thanks for your help
Christophe
^ permalink raw reply [flat|nested] 15+ messages in thread
* Re: Perf doesn't display kernel symbols anymore (bisected commit 659ad3492b91 ("perf maps: Switch from rbtree to lazily sorted array for addresses"))
2025-01-02 19:42 ` Christophe Leroy
@ 2025-01-03 1:08 ` Arnaldo Carvalho de Melo
2025-01-03 6:33 ` Christophe Leroy
2025-01-03 12:40 ` Christophe Leroy
0 siblings, 2 replies; 15+ messages in thread
From: Arnaldo Carvalho de Melo @ 2025-01-03 1:08 UTC (permalink / raw)
To: Christophe Leroy
Cc: James Clark, linux-perf-users@vger.kernel.org, Peter Zijlstra,
Ingo Molnar, Namhyung Kim
On Thu, Jan 02, 2025 at 08:42:26PM +0100, Christophe Leroy wrote:
> Le 02/01/2025 à 19:19, Arnaldo Carvalho de Melo a écrit :
> > On Thu, Jan 02, 2025 at 03:41:17PM +0100, Christophe Leroy wrote:
> > > Le 26/12/2024 à 16:51, Arnaldo Carvalho de Melo a écrit :
> > > > On Tue, Dec 17, 2024 at 02:18:07PM +0000, James Clark wrote:
> > > > > On 16/12/2024 7:01 am, Christophe Leroy wrote:
> > > > > > I noticed with 6.12 LTS Kernel that perf top and perf record/report
> > > > > > don't display kernel symbols anymore, instead it displays the raw
> > > > > > address with [unknown] as object.
> >
> > > > > > After bisect I see that the problem appears with commit 659ad3492b91
> > > > > > ("perf maps: Switch from rbtree to lazily sorted array for addresses").
> > > > > You might want to try applying 0b90dfda222e3 as it claims to fix this
> > > > > commit. I doubt that will fix your issue but it's worth being sure.
> > > > > There was also another fix recently that could be related: 23c44f6c83
> > > > > Did you try the perf-tools-next branch? Maybe something that's already fixed
> > > > > needs to be backported.
> >
> > > > Right, I tried reproducing this on perf-tools-next and couldn't, so
> > > > please test it there.
> > > I tested it again on latest perf-tools-next (ed60738a9b7e ("perf stat:
> > > Document and clarify outstate members")) and still have the same problem,
> > > all kernel symbols appear as [unknown]:
> > > PerfTop: 4163 irqs/sec kernel:28.3% exact: 0.0% lost: 0/0 drop:
> > > 0/14199 [4000Hz cpu-clock:ppp], (all, 1 CPU)
> >
> > So this seems to be on a virt environment? Or have you explicitely used
> > '-e cpu-clock:ppp'?
>
> It is a real HW and I have _not_ used -e cpu-clock:ppp
I think we need to change the output of 'perf top' output to streamline
this reporting process, I'll try to look into it, how to cram more info
in as few top lines as possible to help resolving issues.
> root@vgoippro:~# cat /proc/cpuinfo
> processor : 0
> cpu : e300c2
> clock : 333.333335MHz
> revision : 1.1 (pvr 8084 0011)
> bogomips : 66.66
>
> timebase : 33333333
> platform : CMPCPRO
> model : MIAE
> Memory : 512 MB
>
> > Also can you please run with -v or with -vv to see if we can get some
> > more clues?
> Sure, see at the end (first is the one that fails, followed by the one that
> works)
Thanks!
> > Maybe it is somehow not able to read kallsyms or find a suitable
> > vmlinux?
> There's no vmlinux but it should be able to read kallsyms as it does with
> earlier version
Right, I got distracted by another issue while trying to understand this
one, CCed you on my report on that.
> > Also what distro is this?
> No distro, it's raw embedded system built from scratch with gcc 12.3 and
> glibc 2.38
Ok.
> > I did one more test, this time using --stdio on a raspberry pi and
> > explicitely using '-e cycles:ppp' to get as close to your report as I
> > could:
> > root@raspberrypi:~# uname -a
> > Linux raspberrypi 6.6.51+rpt-rpi-v7 #1 SMP Raspbian 1:6.6.51-1+rpt3 (2024-10-08) armv7l GNU/Linux
> > root@raspberrypi:~# ~acme/bin/perf --version
> > perf version 6.13.rc2.ged60738a9b7e
> > root@raspberrypi:~# timeout 5s ~acme/bin/perf top -e cpu-cycles:ppp --stdio
> > PerfTop: 926 irqs/sec kernel:79.8% exact: 0.0% lost: 0/0 drop: 0/0 [4000Hz cpu-cycles:ppp], (all, 4 CPUs)
> root@vgoippro:~# uname -a
> Linux vgoippro 6.12.4-01797-g8ba9a9738762 #556 PREEMPT Sun Dec 15 19:22:33
> CET 2024 ppc GNU/Linux
> root@vgoippro:~# ./perf --version
> perf version 6.13.rc2.ged60738a9b7e
> root@vgoippro:~# timeout 5s ./perf top --stdio
> PerfTop: 0 irqs/sec kernel: 0.0% exact: 0.0% lost: 0/0 drop: 0/0
> [4000Hz cpu-clock:ppp], (all, 1 CPU)
> -------------------------------------------------------------------------------
>
> PerfTop: 524 irqs/sec kernel:51.1% exact: 0.0% lost: 0/0 drop: 0/0
> [4000Hz cpu-clock:ppp], (all, 1 CPU)
> -------------------------------------------------------------------------------
>
> 17.18% [unknown] [k] 0xc0891c14
> 7.63% [unknown] [k] 0xc005f11c
I think I hadn't notice this '[unknown]' one bit before :-\ the [k] is
there, so having unknown is odd
> 4.48% libc.so.6 [.] _nss_files_parse_servent
> 4.10% gau [.] engine_loop.constprop.0.isra.0
> 3.91% libc.so.6 [.] memset
> 3.24% libc.so.6 [.] strcspn
> 3.05% libc.so.6 [.] __GI_____strtoul_l_internal
> 2.48% libc.so.6 [.] memcpy
> 2.19% libc.so.6 [.] memchr
> 2.00% libc.so.6 [.] _wordcopy_fwd_dest_aligned
> 2.00% [unknown] [k] 0xc005f0f8
> 1.81% libc.so.6 [.] _IO_getline_info
> 1.81% libc.so.6 [.] strlen
> 1.72% libc.so.6 [.] strcmp
> 1.62% libc.so.6 [.] __ftello64
> 1.62% libc.so.6 [.] internal_getent
> 1.53% libc.so.6 [.] _IO_seekoff_unlocked
> 1.15% libc.so.6 [.] __nss_readline
> 1.05% libc.so.6 [.] _wordcopy_fwd_aligned
> 1.05% [unknown] [k] 0xc01f82c8
> As a comparison, the following one works:
> root@vgoippro:~# ./perf-good --version
> perf version 6.8.rc1.g39d14c0dd650
> root@vgoippro:~# timeout 6s ./perf-good top --stdio
> PerfTop: 0 irqs/sec kernel: 0.0% exact: 0.0% lost: 0/0 drop: 0/0
> [4000Hz cpu-clock:ppp], (all, 1 CPU)
> -------------------------------------------------------------------------------
> PerfTop: 0 irqs/sec kernel: 0.0% exact: 0.0% lost: 0/0 drop: 0/0
> [4000Hz cpu-clock:ppp], (all, 1 CPU)
> -------------------------------------------------------------------------------
> PerfTop: 451 irqs/sec kernel:31.7% exact: 0.0% lost: 0/0 drop:
> 7575/7575 [4000Hz cpu-clock:ppp], (all, 1 CPU)
> -------------------------------------------------------------------------------
> 9.60% perf-good [.] io__get_char
> 6.40% perf-good [.] __symbols__insert
> 5.19% gau [.] engine_loop.constprop.0.isra.0
> 4.08% [kernel] [k] finish_task_switch.isra.0
> 3.64% perf-good [.] kallsyms__parse
> 3.20% libc.so.6 [.] memset
> 2.98% [kernel] [k] kallsyms_expand_symbol.constprop.0
> 2.65% libc.so.6 [.] memcpy
> 2.54% [kernel] [k] format_decode
> 2.43% libc.so.6 [.] __libc_calloc
> 2.32% libc.so.6 [.] _wordcopy_fwd_dest_aligned
> 2.32% perf-good [.] io__get_hex
> 1.99% libc.so.6 [.] __GI_____strtoul_l_internal
> 1.88% libc.so.6 [.] _int_malloc
> 1.88% libc.so.6 [.] got_label
> 1.77% libc.so.6 [.] _nss_files_parse_servent
> 1.66% libc.so.6 [.] strcspn
> 1.66% perf-good [.] strlist__node_cmp
> 1.55% [kernel] [k] __copy_tofrom_user
> 1.55% [kernel] [k] string
>
>
> Here is the output with -vv of the one that fails:
>
> Using CPUID 0x80840011
> Problems creating module maps, continuing anyway...
This one: comes from here:
if (symbol_conf.use_modules && machine__create_modules(machine) < 0) {
if (machine__is_host(machine))
pr_debug("Problems creating module maps, "
"continuing anyway...\n");
else
pr_debug("Problems creating module maps for guest %d, "
"continuing anyway...\n", machine->pid);
}
static int machine__create_modules(struct machine *machine)
{
const char *modules;
char path[PATH_MAX];
if (machine__is_default_guest(machine)) {
modules = symbol_conf.default_guest_modules;
} else {
snprintf(path, PATH_MAX, "%s/proc/modules", machine->root_dir);
modules = path;
}
if (symbol__restricted_filename(modules, "/proc/modules"))
return -1;
if (modules__parse(modules, machine, machine__create_module))
return -1;
if (!machine__set_modules_path(machine))
return 0;
pr_debug("Problems setting modules path maps, continuing anyway...\n");
return 0;
}
problems parsing /proc/modules?
symbol__restricted_filename() didn't change since 2012
modules__parse() also didn't have recent changes :-\
Maybe these messages are just red herrings...
I'm just ABENDing, to use a term a relative that is a brazilian bank
manager complaining about some internal systems mentioned as being
utterly irritating and that I found revealing about my age :-P
I'll try to continue tomorrow :-)
Off to bed!
- Arnaldo
> ------------------------------------------------------------
> perf_event_attr:
> type 0 (PERF_TYPE_HARDWARE)
> size 136
> config 0 (PERF_COUNT_HW_CPU_CYCLES)
> { sample_period, sample_freq } 4000
> sample_type IP|TID|TIME|CPU|PERIOD
> read_format ID|LOST
> disabled 1
> mmap 1
> comm 1
> freq 1
> task 1
> precise_ip 3
> sample_id_all 1
> mmap2 1
> comm_exec 1
> ksymbol 1
> bpf_event 1
> ------------------------------------------------------------
> sys_perf_event_open: pid -1 cpu 0 group_fd -1 flags 0x8
> sys_perf_event_open failed, error -2
> decreasing precise_ip by one (2)
> ------------------------------------------------------------
> perf_event_attr:
> type 0 (PERF_TYPE_HARDWARE)
> size 136
> config 0 (PERF_COUNT_HW_CPU_CYCLES)
> { sample_period, sample_freq } 4000
> sample_type IP|TID|TIME|CPU|PERIOD
> read_format ID|LOST
> disabled 1
> mmap 1
> comm 1
> freq 1
> task 1
> precise_ip 2
> sample_id_all 1
> mmap2 1
> comm_exec 1
> ksymbol 1
> bpf_event 1
> ------------------------------------------------------------
> sys_perf_event_open: pid -1 cpu 0 group_fd -1 flags 0x8
> sys_perf_event_open failed, error -2
> decreasing precise_ip by one (1)
> ------------------------------------------------------------
> perf_event_attr:
> type 0 (PERF_TYPE_HARDWARE)
> size 136
> config 0 (PERF_COUNT_HW_CPU_CYCLES)
> { sample_period, sample_freq } 4000
> sample_type IP|TID|TIME|CPU|PERIOD
> read_format ID|LOST
> disabled 1
> mmap 1
> comm 1
> freq 1
> task 1
> precise_ip 1
> sample_id_all 1
> mmap2 1
> comm_exec 1
> ksymbol 1
> bpf_event 1
> ------------------------------------------------------------
> sys_perf_event_open: pid -1 cpu 0 group_fd -1 flags 0x8
> sys_perf_event_open failed, error -2
> decreasing precise_ip by one (0)
> ------------------------------------------------------------
> perf_event_attr:
> type 0 (PERF_TYPE_HARDWARE)
> size 136
> config 0 (PERF_COUNT_HW_CPU_CYCLES)
> { sample_period, sample_freq } 4000
> sample_type IP|TID|TIME|CPU|PERIOD
> read_format ID|LOST
> disabled 1
> mmap 1
> comm 1
> freq 1
> task 1
> sample_id_all 1
> mmap2 1
> comm_exec 1
> ksymbol 1
> bpf_event 1
> ------------------------------------------------------------
> sys_perf_event_open: pid -1 cpu 0 group_fd -1 flags 0x8
> sys_perf_event_open failed, error -2
> Warning:
> The cycles event is not supported, trying to fall back to cpu-clock
> ------------------------------------------------------------
> perf_event_attr:
> type 1 (software)
> size 136
> config 0 (PERF_COUNT_SW_CPU_CLOCK)
> { sample_period, sample_freq } 4000
> sample_type IP|TID|TIME|CPU|PERIOD
> read_format ID|LOST
> disabled 1
> mmap 1
> comm 1
> freq 1
> task 1
> precise_ip 3
> sample_id_all 1
> mmap2 1
> comm_exec 1
> ksymbol 1
> bpf_event 1
> ------------------------------------------------------------
> sys_perf_event_open: pid -1 cpu 0 group_fd -1 flags 0x8 = 3
> mmap size 528384B
> 0x11b71568: mmap mask[0]:
> Missing PLT entry size for /lib/libc.so.6
> Missing PLT entry size for /usr/local/bin/gau
> Missing PLT entry size for /root/perf
> Missing PLT entry size for /lib/libelf-0.176.so
> ^[[H^[[2J
> PerfTop: 0 irqs/sec kernel: 0.0% exact: 0.0% lost: 0/0 drop: 0/0
> [4000Hz cpu-clock:ppp], (all, 1 CPU)
> -------------------------------------------------------------------------------
>
> ^[[H^[[2J
> PerfTop: 259 irqs/sec kernel:86.1% exact: 0.0% lost: 0/0 drop: 0/0
> [4000Hz cpu-clock:ppp], (all, 1 CPU)
> -------------------------------------------------------------------------------
>
> 35.33% [unknown] 0xc0891c14 ! [k] 0xc0891c14
> ---------- end
> 12.93% [unknown] 0xc005f11c ! [k] 0xc005f11c
> Map: f8c0000-f8dc000 0 /lib/nof/libgcc_s.so.1
> Map: f8f0000-f8f1000 20000 /lib/nof/libgcc_s.so.1
> Map: f900000-f909000 0 /lib/libcrypt.so.1
> Map: f920000-f921000 10000 /lib/libcrypt.so.1
> Map: f921000-f948000 0 /tmp/perf-863.map
> Map: f950000-fb4f000 0 /lib/libc.so.6
> Map: fb70000-fb74000 220000 /lib/libc.so.6
> Map: fb74000-fb7e000 0 /tmp/perf-863.map
> Map: fb80000-fdd8000 0 /lib/nof/libstdc++.so.6.0.30
> Map: fdf0000-fdf1000 260000 /lib/nof/libstdc++.so.6.0.30
> Map: fdf1000-fdf7000 0 /tmp/perf-863.map
> Map: fe00000-fe59000 0 /lib/libdw-0.176.so
> Map: fe70000-fe71000 60000 /lib/libdw-0.176.so
> Map: fe80000-fe9b000 0 /lib/libelf-0.176.so
> Map: feb0000-feb1000 20000 /lib/libelf-0.176.so
> Map: fec0000-fee2000 0 /lib/libz.so.1.2.12
> Map: ff00000-ff01000 30000 /lib/libz.so.1.2.12
> Map: ff10000-ffe0000 0 /lib/libm.so.6
> Map: fff0000-fff1000 d0000 /lib/libm.so.6
> Map: 10000000-10341000 0 /root/perf
> Map: 10360000-1036a000 360000 /root/perf
> Map: 1036a000-1036f000 0 /tmp/perf-863.map
> Map: b77f2000-b77f9000 0 [vdso]
> Map: b77fe000-b782e000 0 /lib/ld.so.1
> Map: b783e000-b7840000 40000 /lib/ld.so.1
> ---------- end
> 4.83% /usr/local/bin/gau 0x7218c d [.]
> engine_loop.constprop.0.isra.
> 4.63% [unknown] 0xc005f0f8 ! [k] 0xc005f0f8
> Map: f8c0000-f8dc000 0 /lib/nof/libgcc_s.so.1
> Map: f8f0000-f8f1000 20000 /lib/nof/libgcc_s.so.1
> Map: f900000-f909000 0 /lib/libcrypt.so.1
> Map: f920000-f921000 10000 /lib/libcrypt.so.1
> Map: f921000-f948000 0 /tmp/perf-863.map
> Map: f950000-fb4f000 0 /lib/libc.so.6
> Map: fb70000-fb74000 220000 /lib/libc.so.6
> Map: fb74000-fb7e000 0 /tmp/perf-863.map
> Map: fb80000-fdd8000 0 /lib/nof/libstdc++.so.6.0.30
> Map: fdf0000-fdf1000 260000 /lib/nof/libstdc++.so.6.0.30
> Map: fdf1000-fdf7000 0 /tmp/perf-863.map
> Map: fe00000-fe59000 0 /lib/libdw-0.176.so
> Map: fe70000-fe71000 60000 /lib/libdw-0.176.so
> Map: fe80000-fe9b000 0 /lib/libelf-0.176.so
> Map: feb0000-feb1000 20000 /lib/libelf-0.176.so
> Map: fec0000-fee2000 0 /lib/libz.so.1.2.12
> Map: ff00000-ff01000 30000 /lib/libz.so.1.2.12
> Map: ff10000-ffe0000 0 /lib/libm.so.6
> Map: fff0000-fff1000 d0000 /lib/libm.so.6
> Map: 10000000-10341000 0 /root/perf
> Map: 10360000-1036a000 360000 /root/perf
> Map: 1036a000-1036f000 0 /tmp/perf-863.map
> Map: b77f2000-b77f9000 0 [vdso]
> Map: b77fe000-b782e000 0 /lib/ld.so.1
> Map: b783e000-b7840000 40000 /lib/ld.so.1
> ---------- end
> 1.93% [unknown] 0xc0067d90 ! [k] 0xc0067d90
> ---------- end
> 1.35% [unknown] 0xc0011718 ! [k] 0xc0011718
> Map: f8c0000-f8dc000 0 /lib/nof/libgcc_s.so.1
> Map: f8f0000-f8f1000 20000 /lib/nof/libgcc_s.so.1
> Map: f900000-f909000 0 /lib/libcrypt.so.1
> Map: f920000-f921000 10000 /lib/libcrypt.so.1
> Map: f921000-f948000 0 /tmp/perf-863.map
> Map: f950000-fb4f000 0 /lib/libc.so.6
> Map: fb70000-fb74000 220000 /lib/libc.so.6
> Map: fb74000-fb7e000 0 /tmp/perf-863.map
> Map: fb80000-fdd8000 0 /lib/nof/libstdc++.so.6.0.30
> Map: fdf0000-fdf1000 260000 /lib/nof/libstdc++.so.6.0.30
> Map: fdf1000-fdf7000 0 /tmp/perf-863.map
> Map: fe00000-fe59000 0 /lib/libdw-0.176.so
> Map: fe70000-fe71000 60000 /lib/libdw-0.176.so
> Map: fe80000-fe9b000 0 /lib/libelf-0.176.so
> Map: feb0000-feb1000 20000 /lib/libelf-0.176.so
> Map: fec0000-fee2000 0 /lib/libz.so.1.2.12
> Map: ff00000-ff01000 30000 /lib/libz.so.1.2.12
> Map: ff10000-ffe0000 0 /lib/libm.so.6
> Map: fff0000-fff1000 d0000 /lib/libm.so.6
> Map: 10000000-10341000 0 /root/perf
> Map: 10360000-1036a000 360000 /root/perf
> Map: 1036a000-1036f000 0 /tmp/perf-863.map
> Map: b77f2000-b77f9000 0 [vdso]
> Map: b77fe000-b782e000 0 /lib/ld.so.1
> Map: b783e000-b7840000 40000 /lib/ld.so.1
> ------Missing PLT entry size for /lib/nof/libstdc++.so.6.0.30
> ---- end
> 1.16% [unknown] 0xc001a90c ! [k] 0xc001a90c
> Map: f8c0000-f8dc000 0 /lib/nof/libgcc_s.so.1
> Map: f8f0000-f8f1000 20000 /lib/nof/libgcc_s.so.1
> Map: f900000-f909000 0 /lib/libcrypt.so.1
> Map: f920000-f921000 10000 /lib/libcrypt.so.1
> Map: f921000-f948000 0 /tmp/perf-863.map
> Map: f950000-fb4f000 0 /lib/libc.so.6
> Map: fb70000-fb74000 220000 /lib/libc.so.6
> Map: fb74000-fb7e000 0 /tmp/perf-863.map
> Map: fb80000-fdd8000 0 /lib/nof/libstdc++.so.6.0.30
> Map: fdf0000-fdf1000 260000 /lib/nof/libstdc++.so.6.0.30
> Map: fdf1000-fdf7000 0 /tmp/perf-863.map
> Map: fe00000-fe59000 0 /lib/libdw-0.176.so
> Map: fe70000-fe71000 60000 /lib/libdw-0.176.so
> Map: fe80000-fe9b000 0 /lib/libelf-0.176.so
> Map: feb0000-feb1000 20000 /lib/libelf-0.176.so
> Map: fec0000-fee2000 0 /lib/libz.so.1.2.12
> Map: ff00000-ff01000 30000 /lib/libz.so.1.2.12
> Map: ff10000-ffe0000 0 /lib/libm.so.6
> Map: fff0000-fff1000 d0000 /lib/libm.so.6
> Map: 10000000-10341000 0 /root/perf
> Map: 10360000-1036a000 360000 /root/perf
> Map: 1036a000-1036f000 0 /tmp/perf-863.map
> Map: b77f2000-b77f9000 0 [vdso]
> Map: b77fe000-b782e000 0 /lib/ld.so.1
> Map: b783e000-b7840000 40000 /lib/ld.so.1
> ---------- end
> 0.97% [unknown] 0xc0067da0 ! [k] 0xc0067da0
> ---------- end
> 0.97% [unknown] 0xc0891c18 ! [k] 0xc0891c18
> ---------- end
> 0.77% [unknown] 0xc001a908 ! [k] 0xc001a908
> Map: f8c0000-f8dc000 0 /lib/nof/libgcc_s.so.1
> Map: f8f0000-f8f1000 20000 /lib/nof/libgcc_s.so.1
> Map: f900000-f909000 0 /lib/libcrypt.so.1
> Map: f920000-f921000 10000 /lib/libcrypt.so.1
> Map: f921000-f948000 0 /tmp/perf-863.map
> Map: f950000-fb4f000 0 /lib/libc.so.6
> Map: fb70000-fb74000 220000 /lib/libc.so.6
> Map: fb74000-fb7e000 0 /tmp/perf-863.map
> Map: fb80000-fdd8000 0 /lib/nof/libstdc++.so.6.0.30
> Map: fdf0000-fdf1000 260000 /lib/nof/libstdc++.so.6.0.30
> Map: fdf1000-fdf7000 0 /tmp/perf-863.map
> Map: fe00000-fe59000 0 /lib/libdw-0.176.so
> Map: fe70000-fe71000 60000 /lib/libdw-0.176.so
> Map: fe80000-fe9b000 0 /lib/libelf-0.176.so
> Map: feb0000-feb1000 20000 /lib/libelf-0.176.so
> Map: fec0000-fee2000 0 /lib/libz.so.1.2.12
> Map: ff00000-ff01000 30000 /lib/libz.so.1.2.12
> Map: ff10000-ffe0000 0 /lib/libm.so.6
> Map: fff0000-fff1000 d0000 /lib/libm.so.6
> Map: 10000000-10341000 0 /root/perf
> Map: 10360000-1036a000 360000 /root/perf
> Map: 1036a000-1036f000 0 /tmp/perf-863.map
> Map: b77f2000-b77f9000 0 [vdso]
> Map: b77fe000-b782e000 0 /lib/ld.so.1
> Map: b783e000-b7840000 40000 /lib/ld.so.1
> ---------- end
> 0.77% [unknown] 0xc0067d54 ! [k] 0xc0067d54
> ---------- end
> 0.77% [unknown] 0xc0067d94 ! [k] 0xc0067d94
> ---------- end
> 0.77% [unknown] 0xc0891c10 ! [k] 0xc0891c10
> ---------- end
> 0.58% /lib/libc.so.6 0x94f3c d [.]
> __GI___pthread_disable_asyncc
> 0.58% /lib/libc.so.6 0xaed94 d [.] malloc
> 0.58% /root/perf 0x143c00 d [.] ordered_events__queue
> 0.58% [unknown] 0xc002d720 ! [k] 0xc002d720
> ---------- end
> 0.58% [unknown] 0xc0067d4c ! [k] 0xc0067d4c
> ---------- end
> 0.58% [unknown] 0xc0067da4 ! [k] 0xc0067da4
> ---------- end
> 0.58% [unknown] 0xc00a781c ! [k] 0xc00a781c
>
>
> Here is the output of the one that works:
>
> Using CPUID 0x80840011
> Problems creating module maps, continuing anyway...
> ------------------------------------------------------------
> perf_event_attr:
> type 0 (PERF_TYPE_HARDWARE)
> size 136
> config 0 (PERF_COUNT_HW_CPU_CYCLES)
> { sample_period, sample_freq } 4000
> sample_type IP|TID|TIME|CPU|PERIOD
> read_format ID|LOST
> disabled 1
> inherit 1
> mmap 1
> comm 1
> freq 1
> task 1
> precise_ip 3
> sample_id_all 1
> mmap2 1
> comm_exec 1
> ksymbol 1
> bpf_event 1
> ------------------------------------------------------------
> sys_perf_event_open: pid -1 cpu 0 group_fd -1 flags 0x8
> sys_perf_event_open failed, error -2
> decreasing precise_ip by one (2)
> ------------------------------------------------------------
> perf_event_attr:
> type 0 (PERF_TYPE_HARDWARE)
> size 136
> config 0 (PERF_COUNT_HW_CPU_CYCLES)
> { sample_period, sample_freq } 4000
> sample_type IP|TID|TIME|CPU|PERIOD
> read_format ID|LOST
> disabled 1
> inherit 1
> mmap 1
> comm 1
> freq 1
> task 1
> precise_ip 2
> sample_id_all 1
> mmap2 1
> comm_exec 1
> ksymbol 1
> bpf_event 1
> ------------------------------------------------------------
> sys_perf_event_open: pid -1 cpu 0 group_fd -1 flags 0x8
> sys_perf_event_open failed, error -2
> decreasing precise_ip by one (1)
> ------------------------------------------------------------
> perf_event_attr:
> type 0 (PERF_TYPE_HARDWARE)
> size 136
> config 0 (PERF_COUNT_HW_CPU_CYCLES)
> { sample_period, sample_freq } 4000
> sample_type IP|TID|TIME|CPU|PERIOD
> read_format ID|LOST
> disabled 1
> inherit 1
> mmap 1
> comm 1
> freq 1
> task 1
> precise_ip 1
> sample_id_all 1
> mmap2 1
> comm_exec 1
> ksymbol 1
> bpf_event 1
> ------------------------------------------------------------
> sys_perf_event_open: pid -1 cpu 0 group_fd -1 flags 0x8
> sys_perf_event_open failed, error -2
> decreasing precise_ip by one (0)
> ------------------------------------------------------------
> perf_event_attr:
> type 0 (PERF_TYPE_HARDWARE)
> size 136
> config 0 (PERF_COUNT_HW_CPU_CYCLES)
> { sample_period, sample_freq } 4000
> sample_type IP|TID|TIME|CPU|PERIOD
> read_format ID|LOST
> disabled 1
> inherit 1
> mmap 1
> comm 1
> freq 1
> task 1
> sample_id_all 1
> mmap2 1
> comm_exec 1
> ksymbol 1
> bpf_event 1
> ------------------------------------------------------------
> sys_perf_event_open: pid -1 cpu 0 group_fd -1 flags 0x8
> sys_perf_event_open failed, error -2
> Warning:
> The cycles event is not supported, trying to fall back to cpu-clock
> ------------------------------------------------------------
> perf_event_attr:
> type 1 (PERF_TYPE_SOFTWARE)
> size 136
> config 0 (PERF_COUNT_SW_CPU_CLOCK)
> { sample_period, sample_freq } 4000
> sample_type IP|TID|TIME|CPU|PERIOD
> read_format ID|LOST
> disabled 1
> inherit 1
> mmap 1
> comm 1
> freq 1
> task 1
> precise_ip 3
> sample_id_all 1
> mmap2 1
> comm_exec 1
> ksymbol 1
> bpf_event 1
> ------------------------------------------------------------
> sys_perf_event_open: pid -1 cpu 0 group_fd -1 flags 0x8 = 3
> mmap size 528384B
> 0x11ed8e18: mmap mask[0]:
> Missing PLT entry size for /lib/libc.so.6
> Looking at the vmlinux_path (8 entries long)
> symsrc__init: cannot get elf header.
> Using /proc/kallsyms for symbols
> Missing PLT entry size for /usr/local/bin/gau
> Missing PLT entry size for /root/perf-good
> Failed to open /tmp/perf-887.map, continuing without symbols
> ^[[H^[[2J
> PerfTop: 0 irqs/sec kernel: 0.0% exact: 0.0% lost: 0/0 drop: 0/0
> [4000Hz cpu-clock:ppp], (all, 1 CPU)
> -------------------------------------------------------------------------------
>
> ^[[H^[[2J
> PerfTop: 1 irqs/sec kernel: 0.0% exact: 0.0% lost: 0/0 drop: 0/0
> [4000Hz cpu-clock:ppp], (all, 1 CPU)
> -------------------------------------------------------------------------------
>
> 100.00% /lib/libc.so.6 0x46e64 d [.] __libc_sigaction
> ^[[H^[[2J
> PerfTop: 99 irqs/sec kernel:41.4% exact: 0.0% lost: 0/0 drop:
> 7841/7841 [4000Hz cpu-clock:ppp], (all, 1 CPU)
> -------------------------------------------------------------------------------
>
> 13.51% /root/perf-good 0x1e83f4 d [.] io__get_char
> 8.01% /root/perf-good 0xd6f7c d [.] __symbols__insert
> 6.50% /usr/local/bin/gau 0x72194 d [.]
> engine_loop.constprop.0.isra.
> 6.50% [kernel.kallsyms] 0xc005f11c k [k] finish_task_switch.isra.0
> 5.00% /root/perf-good 0x1e8a24 d [.] kallsyms__parse
> 5.00% [kernel.kallsyms] 0xc0886ed0 k [k] number
> 3.50% [kernel.kallsyms] 0xc00c3644 k [k]
> kallsyms_expand_symbol.constp
> 3.00% /lib/libc.so.6 0xadc6c d [.] _int_malloc
> 3.00% [kernel.kallsyms] 0xc088557c k [k] format_decode
> 3.00% [kernel.kallsyms] 0xc01f82c8 k [k] timerfd_read_iter
> 3.00% [kernel.kallsyms] 0xc088b920 k [k] vsnprintf
> 2.50% /lib/libc.so.6 0xb5d10 d [.] strcmp
> 2.50% [kernel.kallsyms] 0xc0888bc4 k [k] string
> 2.00% /root/perf-good 0xcc854 d [.] strlist__node_cmp
> 2.00% /root/perf-good 0xd6c10 d [.] symbol__new
> 1.50% /lib/libc.so.6 0xbcbb4 d [.] _wordcopy_fwd_aligned
> 1.50% /lib/libc.so.6 0xb4ae4 d [.] memset
> 1.50% /root/perf-good 0x1e8618 d [.] io__get_hex
> 1.50% [kernel.kallsyms] 0xc001a860 k [k] __copy_tofrom_user
> 1.50% [kernel.kallsyms] 0xc01f5248 k [k] do_epoll_wait
>
>
> Thanks for your help
> Christophe
^ permalink raw reply [flat|nested] 15+ messages in thread
* Re: Perf doesn't display kernel symbols anymore (bisected commit 659ad3492b91 ("perf maps: Switch from rbtree to lazily sorted array for addresses"))
2025-01-03 1:08 ` Arnaldo Carvalho de Melo
@ 2025-01-03 6:33 ` Christophe Leroy
2025-01-03 12:40 ` Christophe Leroy
1 sibling, 0 replies; 15+ messages in thread
From: Christophe Leroy @ 2025-01-03 6:33 UTC (permalink / raw)
To: Arnaldo Carvalho de Melo, Christophe Leroy
Cc: James Clark, linux-perf-users@vger.kernel.org, Peter Zijlstra,
Ingo Molnar, Namhyung Kim
Le 03/01/2025 à 02:08, Arnaldo Carvalho de Melo a écrit :
>> Here is the output with -vv of the one that fails:
>>
>> Using CPUID 0x80840011
>> Problems creating module maps, continuing anyway...
>
> This one: comes from here:
>
> if (symbol_conf.use_modules && machine__create_modules(machine) < 0) {
> if (machine__is_host(machine))
> pr_debug("Problems creating module maps, "
> "continuing anyway...\n");
> else
> pr_debug("Problems creating module maps for guest %d, "
> "continuing anyway...\n", machine->pid);
> }
>
> static int machine__create_modules(struct machine *machine)
> {
> const char *modules;
> char path[PATH_MAX];
>
> if (machine__is_default_guest(machine)) {
> modules = symbol_conf.default_guest_modules;
> } else {
> snprintf(path, PATH_MAX, "%s/proc/modules", machine->root_dir);
> modules = path;
> }
>
> if (symbol__restricted_filename(modules, "/proc/modules"))
> return -1;
>
> if (modules__parse(modules, machine, machine__create_module))
> return -1;
>
> if (!machine__set_modules_path(machine))
> return 0;
>
> pr_debug("Problems setting modules path maps, continuing anyway...\n");
>
> return 0;
> }
>
>
> problems parsing /proc/modules?
>
> symbol__restricted_filename() didn't change since 2012
>
> modules__parse() also didn't have recent changes :-\
>
> Maybe these messages are just red herrings...
>
The kernel is built without CONFIG_MODULES
> I'm just ABENDing, to use a term a relative that is a brazilian bank
> manager complaining about some internal systems mentioned as being
> utterly irritating and that I found revealing about my age :-P
>
> I'll try to continue tomorrow :-)
>
> Off to bed!
>
> - Arnaldo
^ permalink raw reply [flat|nested] 15+ messages in thread
* Re: Perf doesn't display kernel symbols anymore (bisected commit 659ad3492b91 ("perf maps: Switch from rbtree to lazily sorted array for addresses"))
2025-01-03 1:08 ` Arnaldo Carvalho de Melo
2025-01-03 6:33 ` Christophe Leroy
@ 2025-01-03 12:40 ` Christophe Leroy
2025-01-03 16:26 ` Arnaldo Carvalho de Melo
1 sibling, 1 reply; 15+ messages in thread
From: Christophe Leroy @ 2025-01-03 12:40 UTC (permalink / raw)
To: Arnaldo Carvalho de Melo
Cc: James Clark, linux-perf-users@vger.kernel.org, Peter Zijlstra,
Ingo Molnar, Namhyung Kim, Ian Rogers
Le 03/01/2025 à 02:08, Arnaldo Carvalho de Melo a écrit :
>> PerfTop: 524 irqs/sec kernel:51.1% exact: 0.0% lost: 0/0 drop: 0/0
>> [4000Hz cpu-clock:ppp], (all, 1 CPU)
>> -------------------------------------------------------------------------------
>>
>> 17.18% [unknown] [k] 0xc0891c14
>> 7.63% [unknown] [k] 0xc005f11c
>
> I think I hadn't notice this '[unknown]' one bit before :-\ the [k] is
> there, so having unknown is odd
>
Problem found, it's in maps__find_next_entry(), this leads to both
map->start and map->end of kernel map being set to 0xc0000000, which
leads to the failure of bsearch() in maps__find().
Second problem is a build issue in perf-tools-next due to commit
e8399d34d568 ("libperf cpumap: Hide/reduce scope of MAX_NR_CPUS"), see
commit 21b8732eb447 ("perf tools: Allow overriding MAX_NR_CPUS at
compile time") to know why this is needed.
By the way I'm wondering why we need a duplicated definition of
MAX_NR_CPUS with different values. Second definition was added by commit
9c3516d1b850 ("libperf: Add perf_cpu_map__new()/perf_cpu_map__read()
functions")
diff --git a/tools/lib/perf/cpumap.c b/tools/lib/perf/cpumap.c
index fcc47214062a..12eaa6955121 100644
--- a/tools/lib/perf/cpumap.c
+++ b/tools/lib/perf/cpumap.c
@@ -13,7 +13,9 @@
#include "internal.h"
#include <api/fs/fs.h>
+#ifndef MAX_NR_CPUS
#define MAX_NR_CPUS 4096
+#endif
void perf_cpu_map__set_nr(struct perf_cpu_map *map, int nr_cpus)
{
diff --git a/tools/perf/util/maps.c b/tools/perf/util/maps.c
index 432399cbe5dd..d39bf27a5fdd 100644
--- a/tools/perf/util/maps.c
+++ b/tools/perf/util/maps.c
@@ -1137,7 +1137,7 @@ struct map *maps__find_next_entry(struct maps
*maps, struct map *map)
down_read(maps__lock(maps));
i = maps__by_address_index(maps, map);
- if (i < maps__nr_maps(maps))
+ if (++i < maps__nr_maps(maps))
result = map__get(maps__maps_by_address(maps)[i]);
up_read(maps__lock(maps));
Christophe
^ permalink raw reply related [flat|nested] 15+ messages in thread
* Re: Perf doesn't display kernel symbols anymore (bisected commit 659ad3492b91 ("perf maps: Switch from rbtree to lazily sorted array for addresses"))
2025-01-03 12:40 ` Christophe Leroy
@ 2025-01-03 16:26 ` Arnaldo Carvalho de Melo
2025-01-06 12:38 ` Christophe Leroy
0 siblings, 1 reply; 15+ messages in thread
From: Arnaldo Carvalho de Melo @ 2025-01-03 16:26 UTC (permalink / raw)
To: Christophe Leroy
Cc: James Clark, linux-perf-users@vger.kernel.org, Peter Zijlstra,
Ingo Molnar, Namhyung Kim, Ian Rogers
On Fri, Jan 03, 2025 at 01:40:24PM +0100, Christophe Leroy wrote:
> Le 03/01/2025 à 02:08, Arnaldo Carvalho de Melo a écrit :
> > > PerfTop: 524 irqs/sec kernel:51.1% exact: 0.0% lost: 0/0 drop: 0/0
> > > [4000Hz cpu-clock:ppp], (all, 1 CPU)
> > > -------------------------------------------------------------------------------
> > > 17.18% [unknown] [k] 0xc0891c14
> > > 7.63% [unknown] [k] 0xc005f11c
> > I think I hadn't notice this '[unknown]' one bit before :-\ the [k] is
> > there, so having unknown is odd
> Problem found, it's in maps__find_next_entry(), this leads to both
> map->start and map->end of kernel map being set to 0xc0000000, which leads
> to the failure of bsearch() in maps__find().
Right, and since you don't have any module (CONFIG_MODULES not set),
and most machines do, that is when the buggy function is called:
machine__create_kernel_maps()
if (!machine__get_running_kernel_start(machine, &name, &start, &end))
<SNIP>
if (end == ~0ULL) {
/* update end address of the kernel map using adjacent module address */
struct map *next = maps__find_next_entry(machine__kernel_maps(machine),
machine__kernel_map(machine));
if (next) {
machine__set_kernel_mmap(machine, start, map__start(next));
map__put(next);
}
}
<SNIP>
So machine__get_running_kernel_start() doesn't manage to fill end with
either because it doesn't find the ref_reloc_sym, one of:
const char *ref_reloc_sym_names[] = {"_text", "_stext", NULL}
And returns -1, so that first if block fails, and then start also
doesn't get set and remains 0, which doesn't seem to be the case, as you
get 0xc0000000 in it, or this fails:
err = kallsyms__get_symbol_start(filename, "_edata", &addr);
if (err)
err = kallsyms__get_function_start(filename, "_etext", &addr);
if (!err)
*end = addr;
So machine->vmlinux_map->start is set to 0xc0000000 and
machine->vmlinux_map->end has ~0ULL, as
ret = machine__update_kernel_mmap(machine, start, end);
Was called and it calls
machine__set_kernel_mmap(machine, start, end);
With 'end' equal to ~0ULL.
Now with your patch maps__find_next_entry() returns NULL and ->end
doesn't get set to ->start, remaining at ~0ULL, which makes the search
to work with just one map, the machine->vmlinux_nmap, got it.
Reviewed-by: Arnaldo Carvalho de Melo <acme@redhat.com>
> Second problem is a build issue in perf-tools-next due to commit
> e8399d34d568 ("libperf cpumap: Hide/reduce scope of MAX_NR_CPUS"), see
> commit 21b8732eb447 ("perf tools: Allow overriding MAX_NR_CPUS at compile
> time") to know why this is needed.
> By the way I'm wondering why we need a duplicated definition of MAX_NR_CPUS
> with different values. Second definition was added by commit 9c3516d1b850
> ("libperf: Add perf_cpu_map__new()/perf_cpu_map__read() functions")
I think that Ian's intention is to clean this up from what I can
remember from the discussion that lead to this initial set of patches.
I was going to work on this to make everything dynamic, i.e. not use a
MAX_NR_CPUS define but instead get the number of possible processors on
the machine and use it instead, but since Ian started working on it I
moved to other stuff.
Now we need to have this patch from you turned into two patches and with
a summary of the above analysis, would you do it, please?
The Reviewed-by tag I provided above applies to both patches,
Namhyung, I think this can go via perf-tools-next, as it is for a rare
situation, i.e. no CONFIG_MODULES and has been in the codebase since:
⬢ [acme@toolbox perf-tools-next]$ git tag --contains 659ad3492b913c903 | grep '^v6.[[:digit:]]$'
v6.9
⬢ [acme@toolbox perf-tools-next]$
I.e. its not a regression added in this cycle, ok?
Thanks!
- Arnaldo
> diff --git a/tools/lib/perf/cpumap.c b/tools/lib/perf/cpumap.c
> index fcc47214062a..12eaa6955121 100644
> --- a/tools/lib/perf/cpumap.c
> +++ b/tools/lib/perf/cpumap.c
> @@ -13,7 +13,9 @@
> #include "internal.h"
> #include <api/fs/fs.h>
>
> +#ifndef MAX_NR_CPUS
> #define MAX_NR_CPUS 4096
> +#endif
>
> void perf_cpu_map__set_nr(struct perf_cpu_map *map, int nr_cpus)
> {
> diff --git a/tools/perf/util/maps.c b/tools/perf/util/maps.c
> index 432399cbe5dd..d39bf27a5fdd 100644
> --- a/tools/perf/util/maps.c
> +++ b/tools/perf/util/maps.c
> @@ -1137,7 +1137,7 @@ struct map *maps__find_next_entry(struct maps *maps,
> struct map *map)
>
> down_read(maps__lock(maps));
> i = maps__by_address_index(maps, map);
> - if (i < maps__nr_maps(maps))
> + if (++i < maps__nr_maps(maps))
> result = map__get(maps__maps_by_address(maps)[i]);
>
> up_read(maps__lock(maps));
>
>
> Christophe
^ permalink raw reply [flat|nested] 15+ messages in thread
* Re: Perf doesn't display kernel symbols anymore (bisected commit 659ad3492b91 ("perf maps: Switch from rbtree to lazily sorted array for addresses"))
2025-01-03 16:26 ` Arnaldo Carvalho de Melo
@ 2025-01-06 12:38 ` Christophe Leroy
2025-01-06 21:46 ` Namhyung Kim
0 siblings, 1 reply; 15+ messages in thread
From: Christophe Leroy @ 2025-01-06 12:38 UTC (permalink / raw)
To: Arnaldo Carvalho de Melo
Cc: James Clark, linux-perf-users@vger.kernel.org, Peter Zijlstra,
Ingo Molnar, Namhyung Kim, Ian Rogers,
linuxppc-dev@lists.ozlabs.org
Le 03/01/2025 à 17:26, Arnaldo Carvalho de Melo a écrit :
> On Fri, Jan 03, 2025 at 01:40:24PM +0100, Christophe Leroy wrote:
>> Le 03/01/2025 à 02:08, Arnaldo Carvalho de Melo a écrit :
>>>> PerfTop: 524 irqs/sec kernel:51.1% exact: 0.0% lost: 0/0 drop: 0/0
>>>> [4000Hz cpu-clock:ppp], (all, 1 CPU)
>>>> -------------------------------------------------------------------------------
>
>>>> 17.18% [unknown] [k] 0xc0891c14
>>>> 7.63% [unknown] [k] 0xc005f11c
>
>>> I think I hadn't notice this '[unknown]' one bit before :-\ the [k] is
>>> there, so having unknown is odd
>
>> Problem found, it's in maps__find_next_entry(), this leads to both
>> map->start and map->end of kernel map being set to 0xc0000000, which leads
>> to the failure of bsearch() in maps__find().
>
> Right, and since you don't have any module (CONFIG_MODULES not set),
> and most machines do, that is when the buggy function is called:
>
> machine__create_kernel_maps()
> if (!machine__get_running_kernel_start(machine, &name, &start, &end))
> <SNIP>
> if (end == ~0ULL) {
> /* update end address of the kernel map using adjacent module address */
> struct map *next = maps__find_next_entry(machine__kernel_maps(machine),
> machine__kernel_map(machine));
>
> if (next) {
> machine__set_kernel_mmap(machine, start, map__start(next));
> map__put(next);
> }
> }
> <SNIP>
>
> So machine__get_running_kernel_start() doesn't manage to fill end with
> either because it doesn't find the ref_reloc_sym, one of:
>
> const char *ref_reloc_sym_names[] = {"_text", "_stext", NULL}
>
> And returns -1, so that first if block fails, and then start also
> doesn't get set and remains 0, which doesn't seem to be the case, as you
> get 0xc0000000 in it, or this fails:
>
> err = kallsyms__get_symbol_start(filename, "_edata", &addr);
> if (err)
> err = kallsyms__get_function_start(filename, "_etext", &addr);
> if (!err)
> *end = addr;
>
Indeed yes that one fails, because:
~# grep -e _stext -e _etext -e _edata /proc/kallsyms
c0000000 T _stext
c08b8000 D _etext
So there is no _edata and _etext is not text
$ ppc-linux-objdump -x vmlinux | grep -e _stext -e _etext -e _edata
c0000000 g .head.text 00000000 _stext
c08b8000 g .rodata 00000000 _etext
c1378000 g .sbss 00000000 _edata
Changing
kallsyms__get_function_start(filename, "_etext", &addr);
to
kallsyms__get_symbol_start(filename, "_etext", &addr);
works.
The following change works as well:
diff --git a/arch/powerpc/kernel/vmlinux.lds.S
b/arch/powerpc/kernel/vmlinux.lds.S
index b4c9decc7a75..b7b2cd7e2a20 100644
--- a/arch/powerpc/kernel/vmlinux.lds.S
+++ b/arch/powerpc/kernel/vmlinux.lds.S
@@ -123,10 +123,11 @@ SECTIONS
*/
*(.sfpr);
*(.text.asan.* .text.tsan.*)
+
+ . = ALIGN(PAGE_SIZE);
+ _etext = .;
} :text
- . = ALIGN(PAGE_SIZE);
- _etext = .;
PROVIDE32 (etext = .);
/* Read-only data */
As it leads to:
~# grep -e _stext -e _etext -e _edata /proc/kallsyms
c0000000 T _stext
c08b8000 T _etext
$ ppc-linux-objdump -x vmlinux | grep -e _stext -e _etext -e _edata
c0000000 g .head.text 00000000 _stext
c08b8000 g .text 00000000 _etext
c1378000 g .sbss 00000000 _edata
So what is the most correct fix ? Change architectures link script or
make perf _etext lookup more flexible, allowing non-text ?
Looking at vmlinux.lds.S from various architectures, I have the feeling
several of them are affected.
Now, regarding _edata, what I see is:
~# tail -2 /proc/kallsyms
c136a000 D __start___bug_table
c1377c14 D __stop___bug_table
And in System.map I have:
c136a000 D __start___bug_table
c1377c14 D __stop___bug_table
c1378000 B __bss_start
c1378000 B _edata
c1378000 B initcall_debug
c1378004 B reset_devices
Should perf try to locate the very last symbol when it doesn't find
_edata ? Or should architecture's link script be modified ? Otherwise
commit 69a87a32f5cd ("perf machine: Include data symbols in the kernel
map") is just pointless.
Christophe
^ permalink raw reply related [flat|nested] 15+ messages in thread
* Re: Perf doesn't display kernel symbols anymore (bisected commit 659ad3492b91 ("perf maps: Switch from rbtree to lazily sorted array for addresses"))
2025-01-06 12:38 ` Christophe Leroy
@ 2025-01-06 21:46 ` Namhyung Kim
2025-01-08 17:55 ` Christophe Leroy
0 siblings, 1 reply; 15+ messages in thread
From: Namhyung Kim @ 2025-01-06 21:46 UTC (permalink / raw)
To: Christophe Leroy
Cc: Arnaldo Carvalho de Melo, James Clark,
linux-perf-users@vger.kernel.org, Peter Zijlstra, Ingo Molnar,
Ian Rogers, linuxppc-dev@lists.ozlabs.org
Hello,
On Mon, Jan 06, 2025 at 01:38:52PM +0100, Christophe Leroy wrote:
>
>
> Le 03/01/2025 à 17:26, Arnaldo Carvalho de Melo a écrit :
> > On Fri, Jan 03, 2025 at 01:40:24PM +0100, Christophe Leroy wrote:
> > > Le 03/01/2025 à 02:08, Arnaldo Carvalho de Melo a écrit :
> > > > > PerfTop: 524 irqs/sec kernel:51.1% exact: 0.0% lost: 0/0 drop: 0/0
> > > > > [4000Hz cpu-clock:ppp], (all, 1 CPU)
> > > > > -------------------------------------------------------------------------------
> >
> > > > > 17.18% [unknown] [k] 0xc0891c14
> > > > > 7.63% [unknown] [k] 0xc005f11c
> >
> > > > I think I hadn't notice this '[unknown]' one bit before :-\ the [k] is
> > > > there, so having unknown is odd
> > > Problem found, it's in maps__find_next_entry(), this leads to both
> > > map->start and map->end of kernel map being set to 0xc0000000, which leads
> > > to the failure of bsearch() in maps__find().
> >
> > Right, and since you don't have any module (CONFIG_MODULES not set),
> > and most machines do, that is when the buggy function is called:
> >
> > machine__create_kernel_maps()
> > if (!machine__get_running_kernel_start(machine, &name, &start, &end))
> > <SNIP>
> > if (end == ~0ULL) {
> > /* update end address of the kernel map using adjacent module address */
> > struct map *next = maps__find_next_entry(machine__kernel_maps(machine),
> > machine__kernel_map(machine));
> >
> > if (next) {
> > machine__set_kernel_mmap(machine, start, map__start(next));
> > map__put(next);
> > }
> > }
> > <SNIP>
> >
> > So machine__get_running_kernel_start() doesn't manage to fill end with
> > either because it doesn't find the ref_reloc_sym, one of:
> >
> > const char *ref_reloc_sym_names[] = {"_text", "_stext", NULL}
> >
> > And returns -1, so that first if block fails, and then start also
> > doesn't get set and remains 0, which doesn't seem to be the case, as you
> > get 0xc0000000 in it, or this fails:
> >
> > err = kallsyms__get_symbol_start(filename, "_edata", &addr);
> > if (err)
> > err = kallsyms__get_function_start(filename, "_etext", &addr);
> > if (!err)
> > *end = addr;
> >
>
> Indeed yes that one fails, because:
>
> ~# grep -e _stext -e _etext -e _edata /proc/kallsyms
> c0000000 T _stext
> c08b8000 D _etext
>
> So there is no _edata and _etext is not text
>
> $ ppc-linux-objdump -x vmlinux | grep -e _stext -e _etext -e _edata
> c0000000 g .head.text 00000000 _stext
> c08b8000 g .rodata 00000000 _etext
> c1378000 g .sbss 00000000 _edata
>
> Changing
>
> kallsyms__get_function_start(filename, "_etext", &addr);
>
> to
>
> kallsyms__get_symbol_start(filename, "_etext", &addr);
>
> works.
>
>
> The following change works as well:
>
> diff --git a/arch/powerpc/kernel/vmlinux.lds.S
> b/arch/powerpc/kernel/vmlinux.lds.S
> index b4c9decc7a75..b7b2cd7e2a20 100644
> --- a/arch/powerpc/kernel/vmlinux.lds.S
> +++ b/arch/powerpc/kernel/vmlinux.lds.S
> @@ -123,10 +123,11 @@ SECTIONS
> */
> *(.sfpr);
> *(.text.asan.* .text.tsan.*)
> +
> + . = ALIGN(PAGE_SIZE);
> + _etext = .;
> } :text
>
> - . = ALIGN(PAGE_SIZE);
> - _etext = .;
> PROVIDE32 (etext = .);
>
> /* Read-only data */
>
> As it leads to:
>
> ~# grep -e _stext -e _etext -e _edata /proc/kallsyms
> c0000000 T _stext
> c08b8000 T _etext
>
> $ ppc-linux-objdump -x vmlinux | grep -e _stext -e _etext -e _edata
> c0000000 g .head.text 00000000 _stext
> c08b8000 g .text 00000000 _etext
> c1378000 g .sbss 00000000 _edata
>
> So what is the most correct fix ? Change architectures link script or make
> perf _etext lookup more flexible, allowing non-text ?
>
> Looking at vmlinux.lds.S from various architectures, I have the feeling
> several of them are affected.
>
> Now, regarding _edata, what I see is:
>
> ~# tail -2 /proc/kallsyms
> c136a000 D __start___bug_table
> c1377c14 D __stop___bug_table
>
> And in System.map I have:
>
> c136a000 D __start___bug_table
> c1377c14 D __stop___bug_table
> c1378000 B __bss_start
> c1378000 B _edata
> c1378000 B initcall_debug
> c1378004 B reset_devices
>
> Should perf try to locate the very last symbol when it doesn't find _edata ?
> Or should architecture's link script be modified ? Otherwise commit
> 69a87a32f5cd ("perf machine: Include data symbols in the kernel map") is
> just pointless.
Let's go with kallsyms__get_symbol_start(). I think it's the most
straight-forward and simplest fix.
Thanks,
Namhyung
^ permalink raw reply [flat|nested] 15+ messages in thread
* Re: Perf doesn't display kernel symbols anymore (bisected commit 659ad3492b91 ("perf maps: Switch from rbtree to lazily sorted array for addresses"))
2025-01-06 21:46 ` Namhyung Kim
@ 2025-01-08 17:55 ` Christophe Leroy
0 siblings, 0 replies; 15+ messages in thread
From: Christophe Leroy @ 2025-01-08 17:55 UTC (permalink / raw)
To: Namhyung Kim
Cc: Arnaldo Carvalho de Melo, James Clark,
linux-perf-users@vger.kernel.org, Peter Zijlstra, Ingo Molnar,
Ian Rogers, linuxppc-dev@lists.ozlabs.org
Le 06/01/2025 à 22:46, Namhyung Kim a écrit :
>>
>> And in System.map I have:
>>
>> c136a000 D __start___bug_table
>> c1377c14 D __stop___bug_table
>> c1378000 B __bss_start
>> c1378000 B _edata
>> c1378000 B initcall_debug
>> c1378004 B reset_devices
>>
>> Should perf try to locate the very last symbol when it doesn't find _edata ?
>> Or should architecture's link script be modified ? Otherwise commit
>> 69a87a32f5cd ("perf machine: Include data symbols in the kernel map") is
>> just pointless.
>
> Let's go with kallsyms__get_symbol_start(). I think it's the most
> straight-forward and simplest fix.
>
Ok, I did that, see patch
https://lore.kernel.org/linux-perf-users/b3ee1994d95257cb7f2de037c5030ba7d1bed404.1736327613.git.christophe.leroy@csgroup.eu/T/#u
And for the _edata which is sometimes missing, I send patch
https://lore.kernel.org/linux-perf-users/2fec8c50c271dff59f0177ff0884b6c374486ba5.1736327770.git.christophe.leroy@csgroup.eu/T/#u
Christophe
^ permalink raw reply [flat|nested] 15+ messages in thread
end of thread, other threads:[~2025-01-08 18:20 UTC | newest]
Thread overview: 15+ messages (download: mbox.gz follow: Atom feed
-- links below jump to the message on this page --
2024-12-16 7:01 Perf doesn't display kernel symbols anymore (bisected commit 659ad3492b91 ("perf maps: Switch from rbtree to lazily sorted array for addresses")) Christophe Leroy
2024-12-17 14:18 ` James Clark
2024-12-17 14:50 ` Christophe Leroy
2024-12-26 15:51 ` Arnaldo Carvalho de Melo
2025-01-02 14:41 ` Christophe Leroy
2025-01-02 17:52 ` Christophe Leroy
2025-01-02 18:19 ` Arnaldo Carvalho de Melo
2025-01-02 19:42 ` Christophe Leroy
2025-01-03 1:08 ` Arnaldo Carvalho de Melo
2025-01-03 6:33 ` Christophe Leroy
2025-01-03 12:40 ` Christophe Leroy
2025-01-03 16:26 ` Arnaldo Carvalho de Melo
2025-01-06 12:38 ` Christophe Leroy
2025-01-06 21:46 ` Namhyung Kim
2025-01-08 17:55 ` Christophe Leroy
This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox;
as well as URLs for NNTP newsgroup(s).