linux/tools/perf
Arnaldo Carvalho de Melo edeb0c90df perf tools: Stop fallbacking to kallsyms for vdso symbols lookup
David reports that:

<quote>
Perf has this hack where it uses the kernel symbol map as a backup when
a symbol can't be found in the user's symbol table(s).

This causes problems because the tests driving this code path use
machine__kernel_ip(), and that is completely meaningless on Sparc.  On
sparc64 the kernel and user live in physically separate virtual address
spaces, rather than a shared one.  And the kernel lives at a virtual
address that overlaps common userspace addresses.  So this test passes
almost all the time when a user symbol lookup fails.

The consequence of this is that, if the unfound user virtual address in
the sample doesn't match up to a kernel symbol either, we trigger things
like this code in builtin-top.c:

	if (al.sym == NULL && al.map != NULL) {
		const char *msg = "Kernel samples will not be resolved.\n";
		/*
		 * As we do lazy loading of symtabs we only will know if the
		 * specified vmlinux file is invalid when we actually have a
		 * hit in kernel space and then try to load it. So if we get
		 * here and there are _no_ symbols in the DSO backing the
		 * kernel map, bail out.
		 *
		 * We may never get here, for instance, if we use -K/
		 * --hide-kernel-symbols, even if the user specifies an
		 * invalid --vmlinux ;-)
		 */
		if (!machine->kptr_restrict_warned && !top->vmlinux_warned &&
		    __map__is_kernel(al.map) && map__has_symbols(al.map)) {
			if (symbol_conf.vmlinux_name) {
				char serr[256];
				dso__strerror_load(al.map->dso, serr, sizeof(serr));
				ui__warning("The %s file can't be used: %s\n%s",
					    symbol_conf.vmlinux_name, serr, msg);
			} else {
				ui__warning("A vmlinux file was not found.\n%s",
					    msg);
			}

			if (use_browser <= 0)
				sleep(5);
			top->vmlinux_warned = true;
		}
	}

When I fire up a compilation on sparc, this triggers immediately.

I'm trying to figure out what the "backup to kernel map" code is
accomplishing.

I see some language in the current code and in the changes that have
happened in this area talking about vdso.  Does that really happen?

The vdso is mapped into userspace virtual addresses, not kernel ones.

More history.  This didn't cause problems on sparc some time ago,
because the kernel IP check used to be "ip < 0" :-) Sparc kernel
addresses are not negative.  But now with machine__kernel_ip(), which
works using the symbol table determined kernel address range, it does
trigger.

What it all boils down to is that on architectures like sparc,
machine__kernel_ip() should always return false in this scenerio, and
therefore this kind of logic:

		if (cpumode == PERF_RECORD_MISC_USER && machine &&
		    mg != &machine->kmaps &&
		    machine__kernel_ip(machine, al->addr)) {

is basically invalid.  PERF_RECORD_MISC_USER implies no kernel address
can possibly match for the sample/event in question (no matter how
hard you try!) :-)
</>

So, I thought something had changed and in the past we would somehow
find that address in the kallsyms, but I couldn't find anything to back
that up, the patch introducing this is over a decade old, lots of things
changed, so I was just thinking I was missing something.

I tried a gtod busy loop to generate vdso activity and added a 'perf
probe' at that branch, on x86_64 to see if it ever gets hit:

Made thread__find_map() noinline, as 'perf probe' in lines of inline
functions seems to not be working, only at function start. (Masami?)

  # perf probe -x ~/bin/perf -L thread__find_map:57
  <thread__find_map@/home/acme/git/perf/tools/perf/util/event.c:57>
     57                 if (cpumode == PERF_RECORD_MISC_USER && machine &&
     58                     mg != &machine->kmaps &&
     59                     machine__kernel_ip(machine, al->addr)) {
     60                         mg = &machine->kmaps;
     61                         load_map = true;
     62                         goto try_again;
                        }
                } else {
                        /*
                         * Kernel maps might be changed when loading
                         * symbols so loading
                         * must be done prior to using kernel maps.
                         */
     69                 if (load_map)
     70                         map__load(al->map);
     71                 al->addr = al->map->map_ip(al->map, al->addr);

  # perf probe -x ~/bin/perf thread__find_map:60
  Added new event:
    probe_perf:thread__find_map (on thread__find_map:60 in /home/acme/bin/perf)

  You can now use it in all perf tools, such as:

	perf record -e probe_perf:thread__find_map -aR sleep 1

  #

  Then used this to see if, system wide, those probe points were being hit:

  # perf trace -e *perf:thread*/max-stack=8/
  ^C[root@jouet ~]#

  No hits when running 'perf top' and:

  # cat gtod.c
  #include <sys/time.h>

  int main(void)
  {
	struct timeval tv;

	while (1)
		gettimeofday(&tv, 0);

	return 0;
  }
  [root@jouet c]# ./gtod
  ^C

  Pressed 'P' in 'perf top' and the [vdso] samples are there:

  62.84%  [vdso]                    [.] __vdso_gettimeofday
   8.13%  gtod                      [.] main
   7.51%  [vdso]                    [.] 0x0000000000000914
   5.78%  [vdso]                    [.] 0x0000000000000917
   5.43%  gtod                      [.] _init
   2.71%  [vdso]                    [.] 0x000000000000092d
   0.35%  [kernel]                  [k] native_io_delay
   0.33%  libc-2.26.so              [.] __memmove_avx_unaligned_erms
   0.20%  [vdso]                    [.] 0x000000000000091d
   0.17%  [i2c_i801]                [k] i801_access
   0.06%  firefox                   [.] free
   0.06%  libglib-2.0.so.0.5400.3   [.] g_source_iter_next
   0.05%  [vdso]                    [.] 0x0000000000000919
   0.05%  libpthread-2.26.so        [.] __pthread_mutex_lock
   0.05%  libpixman-1.so.0.34.0     [.] 0x000000000006d3a7
   0.04%  [kernel]                  [k] entry_SYSCALL_64_trampoline
   0.04%  libxul.so                 [.] style::dom_apis::query_selector_slow
   0.04%  [kernel]                  [k] module_get_kallsym
   0.04%  firefox                   [.] malloc
   0.04%  [vdso]                    [.] 0x0000000000000910

  I added a 'perf probe' to thread__find_map:69, and that surely got tons
  of hits, i.e. for every map found, just to make sure the 'perf probe'
  command was really working.

  In the process I noticed a bug, we're only have records for '[vdso]' for
  pre-existing commands, i.e. ones that are running when we start 'perf top',
  when we will generate the PERF_RECORD_MMAP by looking at /perf/PID/maps.

  I.e. like this, for preexisting processes with a vdso map, again,
  tracing for all the system, only pre-existing processes get a [vdso] map
  (when having one):

  [root@jouet ~]# perf probe -x ~/bin/perf __machine__addnew_vdso
  Added new event:
  probe_perf:__machine__addnew_vdso (on __machine__addnew_vdso in /home/acme/bin/perf)

  You can now use it in all perf tools, such as:

	perf record -e probe_perf:__machine__addnew_vdso -aR sleep 1

  [root@jouet ~]# perf trace -e probe_perf:__machine__addnew_vdso/max-stack=8/
     0.000 probe_perf:__machine__addnew_vdso:(568eb3)
                                       __machine__addnew_vdso (/home/acme/bin/perf)
                                       map__new (/home/acme/bin/perf)
                                       machine__process_mmap2_event (/home/acme/bin/perf)
                                       machine__process_event (/home/acme/bin/perf)
                                       perf_event__process (/home/acme/bin/perf)
                                       perf_tool__process_synth_event (/home/acme/bin/perf)
                                       perf_event__synthesize_mmap_events (/home/acme/bin/perf)
                                       __event__synthesize_thread (/home/acme/bin/perf)

The kernel is generating a PERF_RECORD_MMAP for vDSOs, but somehow
'perf top' is not getting those records while 'perf record' is:

  # perf record ~acme/c/gtod
  ^C[ perf record: Woken up 1 times to write data ]
  [ perf record: Captured and wrote 0.076 MB perf.data (1499 samples) ]

  # perf report -D | grep PERF_RECORD_MMAP2
  71293612401913 0x11b48 [0x70]: PERF_RECORD_MMAP2 25484/25484: [0x400000(0x1000) @ 0 fd:02 1137 541179306]: r-xp /home/acme/c/gtod
  71293612419012 0x11be0 [0x70]: PERF_RECORD_MMAP2 25484/25484: [0x7fa4a2783000(0x227000) @ 0 fd:00 3146370 854107250]: r-xp /usr/lib64/ld-2.26.so
  71293612432110 0x11c50 [0x60]: PERF_RECORD_MMAP2 25484/25484: [0x7ffcdb53a000(0x2000) @ 0 00:00 0 0]: r-xp [vdso]
  71293612509944 0x11cb0 [0x70]: PERF_RECORD_MMAP2 25484/25484: [0x7fa4a23cd000(0x3b6000) @ 0 fd:00 3149723 262067164]: r-xp /usr/lib64/libc-2.26.so
  #
  # perf script | grep vdso | head
      gtod 25484 71293.612768: 2485554 cycles:ppp:  7ffcdb53a914 [unknown] ([vdso])
      gtod 25484 71293.613576: 2149343 cycles:ppp:  7ffcdb53a917 [unknown] ([vdso])
      gtod 25484 71293.614274: 1814652 cycles:ppp:  7ffcdb53aca8 __vdso_gettimeofday+0x98 ([vdso])
      gtod 25484 71293.614862: 1669070 cycles:ppp:  7ffcdb53acc5 __vdso_gettimeofday+0xb5 ([vdso])
      gtod 25484 71293.615404: 1451589 cycles:ppp:  7ffcdb53acc5 __vdso_gettimeofday+0xb5 ([vdso])
      gtod 25484 71293.615999: 1269941 cycles:ppp:  7ffcdb53ace6 __vdso_gettimeofday+0xd6 ([vdso])
      gtod 25484 71293.616405: 1177946 cycles:ppp:  7ffcdb53a914 [unknown] ([vdso])
      gtod 25484 71293.616775: 1121290 cycles:ppp:  7ffcdb53ac47 __vdso_gettimeofday+0x37 ([vdso])
      gtod 25484 71293.617150: 1037721 cycles:ppp:  7ffcdb53ace6 __vdso_gettimeofday+0xd6 ([vdso])
      gtod 25484 71293.617478:  994526 cycles:ppp:  7ffcdb53ace6 __vdso_gettimeofday+0xd6 ([vdso])
  #

The patch is the obvious one and with it we also continue to resolve
vdso symbols for pre-existing processes in 'perf top' and for all
processes in 'perf record' + 'perf report/script'.

Suggested-by: David Miller <davem@davemloft.net>
Acked-by: David Miller <davem@davemloft.net>
Cc: Adrian Hunter <adrian.hunter@intel.com>
Cc: David Ahern <dsahern@gmail.com>
Cc: Jiri Olsa <jolsa@kernel.org>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: Wang Nan <wangnan0@huawei.com>
Link: https://lkml.kernel.org/n/tip-cs7skq9pp0kjypiju6o7trse@git.kernel.org
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2018-10-17 15:56:15 -03:00
..
arch perf probe powerpc: Ignore SyS symbols irrespective of endianness 2018-08-30 15:15:11 -03:00
bench tools arch: Update arch/x86/lib/memcpy_64.S copy used in 'perf bench mem memcpy' 2018-07-30 12:36:51 -03:00
Documentation perf Documentation: Fix out-of-tree asciidoctor man page generation 2018-09-18 10:17:16 -03:00
examples/bpf perf trace: Handle "bpf-output" events associated with "__augmented_syscalls__" BPF map 2018-08-08 15:55:57 -03:00
include/bpf perf bpf: Add wrappers to BPF_FUNC_probe_read(_str) functions 2018-08-08 15:55:57 -03:00
jvmti
pmu-events perf vendor events intel: Fix wrong filter_band* values for uncore events 2018-10-11 11:13:23 -03:00
python
scripts perf script python: Fix export-to-sqlite.py sample columns 2018-09-25 11:37:05 -03:00
tests perf tools: Remove ext from struct kmod_path 2018-08-20 08:54:59 -03:00
trace perf trace beauty: Add beautifiers for 'socket''s 'protocol' arg 2018-07-31 10:52:47 -03:00
ui perf annotate: Add support to toggle percent type 2018-08-08 15:55:52 -03:00
util perf tools: Stop fallbacking to kallsyms for vdso symbols lookup 2018-10-17 15:56:15 -03:00
.gitignore
Build
builtin-annotate.c perf annotate: Add --percent-type option 2018-08-08 15:55:53 -03:00
builtin-bench.c
builtin-buildid-cache.c
builtin-buildid-list.c
builtin-c2c.c perf c2c report: Fix crash for empty browser 2018-07-31 10:53:20 -03:00
builtin-config.c
builtin-data.c
builtin-diff.c
builtin-evlist.c
builtin-ftrace.c
builtin-help.c
builtin-inject.c
builtin-kallsyms.c
builtin-kmem.c tools lib traceevent, perf tools: Rename 'enum pevent_flag' to 'enum tep_flag' 2018-08-13 15:22:18 -03:00
builtin-kvm.c
builtin-list.c
builtin-lock.c
builtin-mem.c
builtin-probe.c
builtin-record.c
builtin-report.c perf evsel: Store ids for events with their own cpus perf_event__synthesize_event_update_cpus 2018-10-16 08:18:52 -03:00
builtin-sched.c
builtin-script.c tools lib traceevent, perf tools: Rename pevent_set_* APIs 2018-08-13 15:22:10 -03:00
builtin-stat.c perf stat: Get rid of extra clock display function 2018-07-24 14:54:58 -03:00
builtin-timechart.c
builtin-top.c
builtin-trace.c perf trace: Wire up the augmented syscalls with the syscalls:sys_enter_FOO beautifier 2018-08-08 15:55:59 -03:00
builtin-version.c
builtin.h
check-headers.sh perf tools: Move syscall_64.tbl check into check-headers.sh 2018-08-14 15:10:40 -03:00
command-list.txt
CREDITS
design.txt
Makefile perf tools: Disable parallelism for 'make clean' 2018-08-20 08:54:58 -03:00
Makefile.config perf tools: Fix use of alternatives to find JDIR 2018-10-16 12:06:47 -03:00
Makefile.perf perf tools: Pass build flags to traceevent build 2018-10-16 14:57:59 -03:00
MANIFEST
perf-archive.sh
perf-completion.sh
perf-read-vdso.c
perf-sys.h
perf-with-kcore.sh
perf.c
perf.h perf tools: Allow overriding MAX_NR_CPUS at compile time 2018-08-01 12:33:24 -03:00