[BUG] perf: bogus correlation of kernel symbols

[Stephane Eranian]

Hi,

I think there is a serious problem with kernel symbol correlation
with the latest perf in 2.6.39-rc7-tip.

Here is a simple example with a stupid program that only
does open()/close on /dev/null:

$ perf record -e cycles:k openclose
$ perf report --stdio

# Events: 2K cycles
#
# Overhead    Command     Shared Object           Symbol
# ........  .........  ................  ...............
#
    99.76%  openclose  [binfmt_misc]     [k] 0xffffffff81010fe6
     0.13%  openclose  libc-2.12.1.so    [.] __open_nocancel
     0.09%  openclose  libc-2.12.1.so    [.] __GI_close

The DSO (binfmt_misc) is bogus. That's not where time is spent.

But if I ran the same test as root:

$ sudo perf record -e cycles:k openclose
$ sudo perf report --stdio

# Events: 2K cycles
#
# Overhead    Command      Shared Object                         Symbol
# ........  .........  .................  .............................
#
    17.13%  openclose  [kernel.kallsyms]  [k] __lock_acquire
    11.77%  openclose  [kernel.kallsyms]  [k] native_sched_clock
     7.36%  openclose  [kernel.kallsyms]  [k] sched_clock_local
     5.99%  openclose  [kernel.kallsyms]  [k] lock_release
     5.38%  openclose  [kernel.kallsyms]  [k] local_clock
     4.43%  openclose  [kernel.kallsyms]  [k] lock_acquired
     4.05%  openclose  [kernel.kallsyms]  [k] lock_acquire
     3.95%  openclose  [kernel.kallsyms]  [k] lock_is_held
     3.51%  openclose  [kernel.kallsyms]  [k] sched_clock_cpu
     3.24%  openclose  [kernel.kallsyms]  [k] trace_hardirqs_off_caller

This is much more meaningful.

This is not related to the paranoid level (1 for me).

Looking at perf report -D, the same kernel address is associated to different
module based on my permission level.

first perf.data:
416749738927 0x4210 [0x28]: PERF_RECORD_SAMPLE(IP, 1): 4886/4886:
0xffffffff8107c1d8 period: 2262681
 ... thread: openclose:4886
 ...... dso: /lib/modules/2.6.39-rc7-tip/kernel/fs/binfmt_misc.ko

second perf.data:
436879910722 0xc950 [0x28]: PERF_RECORD_SAMPLE(IP, 1): 4894/4894:
0xffffffff8107c1d8 period: 2280253
 ... thread: openclose:4894
 ...... dso: vmlinux

Same address different mapping!

My path to vmlinux is all accessible to me.

If there were permission problems, I would expect perf record or perf report
to tell me and not fallback to some bogus mappings.
--
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to majordomo@xxxxxxxxxxxxxxx
More majordomo info at  http://vger.kernel.org/majordomo-info.html
Please read the FAQ at  http://www.tux.org/lkml/