* 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).