perf report displays call graphs with unresolved kernel symbols

Question

I've gathered a perf trace of last branch record (LBR) samples:

$ sudo perf record -F 99 -a --call-graph lbr sleep 20
[ perf record: Woken up 41 times to write data ]
[ perf record: Captured and wrote 16.786 MB perf.data (73420 samples) ]

Because I've installed the kernel debug symbols (via Ubuntu's linux-image-xyz-dbgsym package), I see kernel stack traces in the samples displayed by perf script:

Wt--1 48503 [034] 1429895.019844:     646342 cycles:
        ffffffff8d4e4cb5 update_nohz_stats+0x25 (/usr/lib/debug/boot/vmlinux-5.4.0-73-generic)
        ffffffff8d4e801b update_sd_lb_stats+0x25b (/usr/lib/debug/boot/vmlinux-5.4.0-73-generic)
        ffffffff8d4e85b7 find_busiest_group+0x47 (/usr/lib/debug/boot/vmlinux-5.4.0-73-generic)
        ffffffff8d4e8bdf load_balance+0x15f (/usr/lib/debug/boot/vmlinux-5.4.0-73-generic)
        ffffffff8d4e9f73 newidle_balance+0x2b3 (/usr/lib/debug/boot/vmlinux-5.4.0-73-generic)
        ffffffff8d4ea105 pick_next_task_fair+0x45 (/usr/lib/debug/boot/vmlinux-5.4.0-73-generic)
        ffffffff8ded5214 __schedule+0x124 (/usr/lib/debug/boot/vmlinux-5.4.0-73-generic)
        ffffffff8ded5833 schedule+0x33 (/usr/lib/debug/boot/vmlinux-5.4.0-73-generic)
        ffffffff8d547a89 futex_wait_queue_me+0xb9 (/usr/lib/debug/boot/vmlinux-5.4.0-73-generic)
        ffffffff8d548aa0 futex_wait+0x100 (/usr/lib/debug/boot/vmlinux-5.4.0-73-generic)
        ffffffff8d54b48f do_futex+0x35f (/usr/lib/debug/boot/vmlinux-5.4.0-73-generic)
        ffffffff8d54bbef __x64_sys_futex+0x13f (/usr/lib/debug/boot/vmlinux-5.4.0-73-generic)
        ffffffff8d404207 do_syscall_64+0x57 (/usr/lib/debug/boot/vmlinux-5.4.0-73-generic)
        ffffffff8e00008c entry_SYSCALL_64+0x7c (/usr/lib/debug/boot/vmlinux-5.4.0-73-generic)
            55c03ef7ad70 pthread_cond_timedwait@plt+0x0 (/home/xyz/myapp)

However, perf report is unable to resolve the same symbols. I get:

-   13.11%     0.00%  Wt--1            [unknown]                   [.] 0xffffffff8e00008c
   - 0xffffffff8e00008c
      - 12.17% 0xffffffff8d404207
         - 4.64% 0xffffffff8d54bbef
            - 2.89% 0xffffffff8d54b48f
               - 2.68% 0xffffffff8d548aa0
                  - 2.55% 0xffffffff8d547a89
                     - 2.52% 0xffffffff8ded5833
                        - 1.17% 0xffffffff8ded5214
                           - 1.01% 0xffffffff8d4ea105
                              - 0.96% 0xffffffff8d4e9f73
                                 - 0.54% 0xffffffff8d4e8bdf
                                      0.52% 0xffffffff8d4e85b7
                        - 0.65% 0xffffffff8ded54b9
                             0.65% 0xffffffff8d4d6a6a

Notice the stack above matches the frames in the perf script output. So, what's different between the way perf report and perf script resolve symbols?

Here's the verbose output from perf report:

$ perf report -v --stdio > /dev/null
build id event received for /usr/lib/debug/boot/vmlinux-5.4.0-73-generic: 05638de83d4b5ca5d11614484f9cd5525a8b2713
build id event received for /lib/modules/5.4.0-73-generic/kernel/arch/x86/kvm/kvm.ko: 18e6d209819f08e64e59fa19961c358f60a9d835
build id event received for /lib/modules/5.4.0-73-generic/kernel/drivers/intel/sgx/isgx.ko: 9a37f67aff8f86a47b837ea01e5c1f673b95527a
build id event received for /lib/modules/5.4.0-73-generic/kernel/drivers/net/ethernet/intel/igb/igb.ko: 497aa60f1ff31ae7690a99a8c5a151b3f22abd80
build id event received for /lib/modules/5.4.0-73-generic/kernel/drivers/ata/libahci.ko: 801c3ad29053c29e5078bdb2cbe0e7bda1e43ff0
build id event received for /lib/x86_64-linux-gnu/libpthread-2.27.so: 68f36706eb2e6eee4046c4fdca2a19540b2f6113
build id event received for /lib/x86_64-linux-gnu/libc-2.27.so: ce450eb01a5e5acc7ce7b8c2633b02cc1093339e
build id event received for [vdso]: 75f9eb38e31c3dc2fab6314c45b01b07bd6d047d
build id event received for /home/vsts-agent/bin.2.184.2/libcoreclr.so: 9b44902bfb6d8f9067767e551977f8306f9e8d94
build id event received for /usr/sbin/sshd: 6f0593060a136468805766d2931cbd91157951aa
build id event received for /usr/bin/htop: 27866c7878627b082ca43d3e147f3f867a32b53f
build id event received for /lib/x86_64-linux-gnu/libncursesw.so.5.9: 8bbe057cadb725ac23aed0800c8f8cef05b207f1
Looking at the vmlinux_path (8 entries long)
Using /usr/lib/debug/boot/vmlinux-5.4.0-73-generic for symbols
symsrc__init: cannot get elf header.
Failed to open /home/xyz/mylib.so, continuing without symbols
[vdso] with build id 75f9eb38e31c3dc2fab6314c45b01b07bd6d047d not found, continuing without symbols
Failed to open [sep5], continuing without symbols

Notice that there is some user code for which I do not have symbols, so as expected both perf script and perf report are missing symbols there. This is the source of the symsrc__init error above.

Things I've already tried:

Passing --vmlinux, --kallsyms and --modules parameters. This had no obvious effect, but sent me down a rabbit hole of rebuilding perf myself so it links against libbfd (Ubuntu's perf does not, and shells out to addr2line which makes it very slow in these cases).
Inverting the display of call chains with --inverted or --children. This didn't change the fact that symbols were not resolved.
Limiting the length of displayed stacks with --max-stack=8 or similar. This significantly reduces the number of unresolved symbols showing up in the report, but I think it's just hiding the problem, because it prevents grouping samples from disjoint portions of a long callchain.

perf report displays call graphs with unresolved kernel symbols

0 Answers