linux-kernel - [BUG] perf: bogus correlation of kernel symbols

lists.openwall.net		lists / announce owl-users owl-dev john-users john-dev passwdqc-users yescrypt popa3d-users / oss-security kernel-hardening musl sabotage tlsify passwords / crypt-dev xvendor / Bugtraq Full-Disclosure linux-kernel linux-netdev linux-ext4 linux-hardening linux-cve-announce PHC
Open Source and information security mailing list archives

Hash Suite: Windows password security audit tool. GUI, reports in PDF.

[<prev] [next>] [thread-next>] [day] [month] [year] [list]

Message-ID: <BANLkTim8mAzZbdOhBodaOFKM5esP-Q+K7g@mail.gmail.com>
Date:	Thu, 12 May 2011 16:48:46 +0200
From:	Stephane Eranian <eranian@...gle.com>
To:	Arnaldo Carvalho de Melo <acme@...hat.com>
Cc:	LKML <linux-kernel@...r.kernel.org>
Subject: [BUG] perf: bogus correlation of kernel symbols

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@...r.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html
Please read the FAQ at  http://www.tux.org/lkml/