perf test BPF failing on f24: fix

Hi Wang,

Something changed and a function used in a perf test for BPF is
not anymore appearing on vmlinux, albeit still available on /proc/kallsyms:

# readelf -wi /lib/modules/4.7.0+/build/vmlinux | grep -w sys_epoll_wait
#

But:

[root@jouet ~]# grep -i sys_epoll_wait /proc/kallsyms ffffffffbd295b50 T SyS_epoll_wait ffffffffbd295b50 T sys_epoll_wait
[root@jouet ~]#

I noticed that it is some sort of aliasing so I checked the other variant:

[root@jouet ~]# readelf -wi /lib/modules/4.7.0+/build/vmlinux | grep -w SyS_epoll_wait

    <2bc9b85>   DW_AT_name        : (indirect string, offset: 0xe7524): SyS_epoll_wait

[root@jouet ~]#

Trying to use perf probe also produces the same resuls I notice when running the perf test that is failing:

[root@jouet ~]# perf probe sys_epoll_wait
Failed to find debug information for address ffffffffbd295b50 Probe point 'sys_epoll_wait' not found.
Error: Failed to add events.
[root@jouet ~]# perf probe SyS_epoll_wait
Added new events:
probe:SyS_epoll_wait (on SyS_epoll_wait) probe:SyS_epoll_wait_1 (on SyS_epoll_wait) probe:SyS_epoll_wait_2 (on SyS_epoll_wait)

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

perf record -e probe:SyS_epoll_wait_2 -aR sleep 1

[root@jouet ~]#

So I am changing the BPF perf test to use the CamelCase notation alias:

Failing (with sys_epoll_wait):

[root@jouet ~]# perf test BPF

37: Test BPF filter                                          :
37.1: Test basic BPF filtering                               : FAILED!
37.2: Test BPF prologue generation                           : Skip
37.3: Test BPF relocation checker                            : Skip

[root@jouet ~]#

Changing to (SyS_epoll_wait):

[root@jouet ~]# perf test BPF

37: Test BPF filter                                          :
37.1: Test basic BPF filtering                               : Ok
37.2: Test BPF prologue generation                           : Ok
37.3: Test BPF relocation checker                            : Ok

[root@jouet ~]#

I'm adding a fix that just makes it use SyS_epoll_wait.

- Arnaldo

Quoted 26 lines

Hi Wang,

Something changed and a function used in a perf test for BPF is
not anymore appearing on vmlinux, albeit still available on /proc/kallsyms:

# readelf -wi /lib/modules/4.7.0+/build/vmlinux | grep -w sys_epoll_wait
#

But:

[root@jouet ~]# grep -i sys_epoll_wait /proc/kallsyms ffffffffbd295b50 T SyS_epoll_wait ffffffffbd295b50 T sys_epoll_wait
[root@jouet ~]#

I noticed that it is some sort of aliasing so I checked the other variant:

[root@jouet ~]# readelf -wi /lib/modules/4.7.0+/build/vmlinux | grep -w SyS_epoll_wait

    <2bc9b85>   DW_AT_name        : (indirect string, offset: 0xe7524): SyS_epoll_wait

[root@jouet ~]#

Trying to use perf probe also produces the same resuls I notice when running the perf test that is failing:

Quoted 9 lines

[root@jouet ~]# perf probe sys_epoll_wait
Failed to find debug information for address ffffffffbd295b50 Probe point 'sys_epoll_wait' not found.
Error: Failed to add events.
[root@jouet ~]# perf probe SyS_epoll_wait
Added new events:
probe:SyS_epoll_wait (on SyS_epoll_wait) probe:SyS_epoll_wait_1 (on SyS_epoll_wait) probe:SyS_epoll_wait_2 (on SyS_epoll_wait)

that change will break all sorts of scripts that relying on syscalls to start with sys_

I guess we can workaround in user space, but what was the motivation to disable kprobe attach on sys_* while it's still in kallsyms?

Quoted 30 lines

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

perf record -e probe:SyS_epoll_wait_2 -aR sleep 1

[root@jouet ~]#

So I am changing the BPF perf test to use the CamelCase notation alias:

Failing (with sys_epoll_wait):

[root@jouet ~]# perf test BPF

37: Test BPF filter                                          :
37.1: Test basic BPF filtering                               : FAILED!
37.2: Test BPF prologue generation                           : Skip
37.3: Test BPF relocation checker                            : Skip

[root@jouet ~]#

Changing to (SyS_epoll_wait):

[root@jouet ~]# perf test BPF

37: Test BPF filter                                          :
37.1: Test basic BPF filtering                               : Ok
37.2: Test BPF prologue generation                           : Ok
37.3: Test BPF relocation checker                            : Ok

[root@jouet ~]#

I'm adding a fix that just makes it use SyS_epoll_wait.

- Arnaldo

Em Tue, Aug 02, 2016 at 02:03:33PM -0700, Alexei Starovoitov escreveu:

Quoted 37 lines · Arnaldo Carvalho de Melo

Quoted 26 lines

Hi Wang,

Something changed and a function used in a perf test for BPF is
not anymore appearing on vmlinux, albeit still available on /proc/kallsyms:

# readelf -wi /lib/modules/4.7.0+/build/vmlinux | grep -w sys_epoll_wait
#

But:

[root@jouet ~]# grep -i sys_epoll_wait /proc/kallsyms ffffffffbd295b50 T SyS_epoll_wait ffffffffbd295b50 T sys_epoll_wait
[root@jouet ~]#

I noticed that it is some sort of aliasing so I checked the other variant:

[root@jouet ~]# readelf -wi /lib/modules/4.7.0+/build/vmlinux | grep -w SyS_epoll_wait

    <2bc9b85>   DW_AT_name        : (indirect string, offset: 0xe7524): SyS_epoll_wait

[root@jouet ~]#

Trying to use perf probe also produces the same resuls I notice when running the perf test that is failing:

Quoted 9 lines

[root@jouet ~]# perf probe sys_epoll_wait
Failed to find debug information for address ffffffffbd295b50 Probe point 'sys_epoll_wait' not found.
Error: Failed to add events.
[root@jouet ~]# perf probe SyS_epoll_wait
Added new events:
probe:SyS_epoll_wait (on SyS_epoll_wait) probe:SyS_epoll_wait_1 (on SyS_epoll_wait) probe:SyS_epoll_wait_2 (on SyS_epoll_wait)

Quoted 2 lines

that change will break all sorts of scripts that relying on syscalls to start with sys_

Is there a promise that internal kernel functions will not change names?

Quoted 2 lines

I guess we can workaround in user space, but what was the motivation to disable kprobe attach on sys_* while it's still in kallsyms?

Was it disabled? What I noticed whas that the sys_epoll_wait wasn't present in the DWARF info present in the vmlinux file, which would be good for others to confirm, which I'll check on other machines here at home, tomorrow.

Hi Wang,

Something changed and a function used in a perf test for BPF is
not anymore appearing on vmlinux, albeit still available on /proc/kallsyms:

# readelf -wi /lib/modules/4.7.0+/build/vmlinux | grep -w sys_epoll_wait
#

But:

[root@jouet ~]# grep -i sys_epoll_wait /proc/kallsyms ffffffffbd295b50 T SyS_epoll_wait ffffffffbd295b50 T sys_epoll_wait
[root@jouet ~]#

I noticed that it is some sort of aliasing so I checked the other variant:

[root@jouet ~]# readelf -wi /lib/modules/4.7.0+/build/vmlinux | grep -w SyS_epoll_wait

     <2bc9b85>   DW_AT_name        : (indirect string, offset: 0xe7524): SyS_epoll_wait

[root@jouet ~]#

Trying to use perf probe also produces the same resuls I notice when running the perf test that is failing:

[root@jouet ~]# perf probe sys_epoll_wait
Failed to find debug information for address ffffffffbd295b50 Probe point 'sys_epoll_wait' not found.
Error: Failed to add events.

Quoted 16 lines · Arnaldo Carvalho de Melo

Hi Wang,

Something changed and a function used in a perf test for BPF is
not anymore appearing on vmlinux, albeit still available on /proc/kallsyms:

# readelf -wi /lib/modules/4.7.0+/build/vmlinux | grep -w sys_epoll_wait
#

But:

[root@jouet ~]# grep -i sys_epoll_wait /proc/kallsyms ffffffffbd295b50 T SyS_epoll_wait ffffffffbd295b50 T sys_epoll_wait
[root@jouet ~]#

Quoted 8 lines

I noticed that it is some sort of aliasing so I checked the other variant:

[root@jouet ~]# readelf -wi /lib/modules/4.7.0+/build/vmlinux | grep -w SyS_epoll_wait
<2bc9b85> DW_AT_name : (indirect string, offset:
0xe7524): SyS_epoll_wait
[root@jouet ~]#

I also see no sys_epoll_wait in output of 'readelf -wi', but I can't reproduce the whole problem.

Quoted 7 lines

Trying to use perf probe also produces the same resuls I notice when running the perf test that is failing:

[root@jouet ~]# perf probe sys_epoll_wait
Failed to find debug information for address ffffffffbd295b50 Probe point 'sys_epoll_wait' not found.
Error: Failed to add events.

For me:

# uname -r
4.7.0

# perf probe -v sys_epoll_wait
probe-definition(0): sys_epoll_wait
symbol:sys_epoll_wait file:(null) line:0 offset:0 return:0 lazy:(null)
0 arguments
Looking at the vmlinux_path (8 entries long)
Using /lib/modules/4.7.0/build/vmlinux for symbols
Open Debuginfo file: /lib/modules/4.7.0/build/vmlinux
Try to find probe point from debuginfo.
Symbol sys_epoll_wait address found : ffffffff81281240
Matched function: SyS_epoll_wait
found inline addr: 0xffffffff81281240
Probe point found: SyS_epoll_wait+0
found inline addr: 0xffffffff812813a7
Probe point found: SyS_epoll_pwait+135
found inline addr: 0xffffffff8128157a
Probe point found: compat_SyS_epoll_pwait+154
Found 3 probe_trace_events.
Opening /sys/kernel/debug/tracing//kprobe_events write=1
Writing event: p:probe/sys_epoll_wait _text+2626112
Writing event: p:probe/sys_epoll_wait_1 _text+2626471
Writing event: p:probe/sys_epoll_wait_2 _text+2626938
Added new events:
  probe:sys_epoll_wait (on sys_epoll_wait)
  probe:sys_epoll_wait_1 (on sys_epoll_wait)
  probe:sys_epoll_wait_2 (on sys_epoll_wait)

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

perf record -e probe:sys_epoll_wait_2 -aR sleep 1

I'll try different kernel version and kconfig.

Hi Wang,

Something changed and a function used in a perf test for BPF is
not anymore appearing on vmlinux, albeit still available on /proc/kallsyms:

# readelf -wi /lib/modules/4.7.0+/build/vmlinux | grep -w sys_epoll_wait
#

But:

[root@jouet ~]# grep -i sys_epoll_wait /proc/kallsyms ffffffffbd295b50 T SyS_ep

oll_wait
ffffffffbd295b50 T sys_epoll_wait
[root@jouet ~]#

I noticed that it is some sort of aliasing so I checked the other variant:

[root@jouet ~]# readelf -wi /lib/modules/4.7.0+/build/vmlinux | grep -w SyS_epoll_wait

     <2bc9b85>   DW_AT_name        : (indirect string, offset: 0xe7524): SyS_epoll_wait

[root@jouet ~]#

Trying to use perf probe also produces the same resuls I notice when running the perf test that is failing:

[root@jouet ~]# perf probe sys_epoll_wait
Failed to find debug information for address ffffffffbd295b50 Probe point 'sys_epoll_wait' not found.
Error: Failed to add events.
[root@jouet ~]# perf probe SyS_epoll_wait
Added new events:
probe:SyS_epoll_wait (on SyS_epoll_wait) probe:SyS_epoll_wait_1 (on SyS_epoll_wait) probe:SyS_epoll_wait_2 (on SyS_epoll_wait)

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

perf record -e probe:SyS_epoll_wait_2 -aR sleep 1

[root@jouet ~]#

So I am changing the BPF perf test to use the CamelCase notation alias:

Add Masami to Cc list. He knowns debug info.

Please see below...

Quoted 8 lines · Arnaldo Carvalho de Melo

Hi Wang,

Something changed and a function used in a perf test for BPF is
not anymore appearing on vmlinux, albeit still available on /proc/kallsyms:

# readelf -wi /lib/modules/4.7.0+/build/vmlinux | grep -w sys_epoll_wait
#

As I have said in another mail, although I don't know why, I don't think the missing of sys_epoll_wait is the root cause of your failure.

I did a bisect search and found commit 83460ec8dcac14142e7860a01fa59c267ac4657c:
"syscalls.h: use gcc alias instead of assembler aliases for syscalls" After this commit, sys_xxx symbols is gone from output of 'readelf -wi'. It is
introduced in v3.13.

Quoted 4 lines

But:

[root@jouet ~]# grep -i sys_epoll_wait /proc/kallsyms ffffffffbd295b50 T SyS_ep

Quoted 3 lines

oll_wait
ffffffffbd295b50 T sys_epoll_wait
[root@jouet ~]#

If we remove vmlinux, perf should use /proc/kallsyms. I think the failure would gone. The problem is: when symbol searching fail using vmlinux, should we fallback to kallsyms? However, this is another question.

Quoted 4 lines

[root@jouet ~]# perf probe sys_epoll_wait
Failed to find debug information for address ffffffffbd295b50 Probe point 'sys_epoll_wait' not found.
Error: Failed to add events.

Quoted 6 lines

[root@jouet ~]# perf probe SyS_epoll_wait
Added new events:
probe:SyS_epoll_wait (on SyS_epoll_wait)
probe:SyS_epoll_wait_1 (on SyS_epoll_wait)
probe:SyS_epoll_wait_2 (on SyS_epoll_wait)

Quoted 7 lines

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

perf record -e probe:SyS_epoll_wait_2 -aR sleep 1

[root@jouet ~]#

So I am changing the BPF perf test to use the CamelCase notation alias:

Changing to SyS_xxx is okay, byt we still need to know the root cause.

Thank you.

Quoted 1 line

If we remove vmlinux, perf should use /proc/kallsyms. I think

Quoted 3 lines

the failure would gone. The problem is: when symbol searching fail using vmlinux, should we fallback to kallsyms? However, this is another question.

As below result shown, perf probe tries to fallback, but it seems to fail to find corresponding debuginfo entry...

Quoted 4 lines

Quoted 4 lines

[root@jouet ~]# perf probe sys_epoll_wait
Failed to find debug information for address ffffffffbd295b50 Probe point 'sys_epoll_wait' not found.
Error: Failed to add events.

So, at least I should investigate it.

Thanks,

Quoted 19 lines

Quoted 6 lines

[root@jouet ~]# perf probe SyS_epoll_wait
Added new events:
probe:SyS_epoll_wait (on SyS_epoll_wait)
probe:SyS_epoll_wait_1 (on SyS_epoll_wait)
probe:SyS_epoll_wait_2 (on SyS_epoll_wait)

Quoted 7 lines

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

perf record -e probe:SyS_epoll_wait_2 -aR sleep 1

[root@jouet ~]#

So I am changing the BPF perf test to use the CamelCase notation alias:

Changing to SyS_xxx is okay, byt we still need to know the root cause.

Thank you.

Signature · 1 line

Masami Hiramatsu <[email protected]>

Em Wed, Aug 03, 2016 at 11:45:57PM +0900, Masami Hiramatsu escreveu:

Quoted 1 line

Quoted 1 line

If we remove vmlinux, perf should use /proc/kallsyms. I think

I am not removing vmlinux, it is being used, its just that the function chosen by the 'perf test BPF' testcase isn't there.

So lets go again trying to chase this without missing a single step of the way:

We start with:

[root@jouet ~]# perf test bpf

37: Test BPF filter                                          :
37.1: Test basic BPF filtering                               : FAILED!
37.2: Test BPF prologue generation                           : Skip
37.3: Test BPF relocation checker                            : Skip

[root@jouet ~]#

Ok, so we add -v to get more information:

[root@jouet ~]# perf test -v bpf
<BIG SNIP>
bpf: config program 'func=sys_epoll_wait' symbol:sys_epoll_wait file:(null) line:0 offset:0 return:0 lazy:(null)
bpf: config 'func=sys_epoll_wait' is ok
Looking at the vmlinux_path (8 entries long)
Using /lib/modules/4.7.0+/build/vmlinux for symbols
Open Debuginfo file: /lib/modules/4.7.0+/build/vmlinux
Try to find probe point from debuginfo.
Symbol sys_epoll_wait address found : ffffffffbd295b50 Failed to find debug information for address ffffffffbd295b50 Probe point 'sys_epoll_wait' not found.
bpf_probe: failed to convert perf probe eventsFailed to add events selected by BPF
test child finished with -1
---- end ----
Test BPF filter subtest 0: FAILED!

--------------

See? It _is_ using /lib/modules/4.7.0+/build/vmlinux, and it should because:

[acme@jouet linux]$ file /lib/modules/4.7.0+/build/vmlinux /lib/modules/4.7.0+/build/vmlinux: ELF 64-bit LSB executable, x86-64, version 1 (SYSV), statically linked, BuildID[sha1]=a08d121dcee2a0ea0cfa5d84363de0c1cfdc729a, not stripped [acme@jouet linux]$

Its the kernel that is in use:

[acme@jouet linux]$ perf buildid-list --kernel

              a08d121dcee2a0ea0cfa5d84363de0c1cfdc729a

[acme@jouet linux]$ perf buildid-list -h --kernel

Usage: perf buildid-list [<options>]

-k, --kernel Show current kernel build id

[acme@jouet linux]$

And, in this vmlinux file, there is _no_ such function:

[acme@jouet linux]$ readelf -wi /lib/modules/4.7.0+/build/vmlinux | grep -w sys_epoll_wait [acme@jouet linux]$

Exactly like the 'perf probe -v bpf' says:

Symbol sys_epoll_wait address found : ffffffffbd295b50 Failed to find debug information for address ffffffffbd295b50

-----

It mapped it to an address, sure, it found it in /proc/kallsyms, but then it didn't find it in the matching vmlinux file.

Since the test was working before, when did it stop to be available on vmlinux?

Quoted 77 lines · On Wed, 3 Aug 2016 17:04:15 -0300 Arnaldo Carvalho de Melo <[email protected]>…

Em Wed, Aug 03, 2016 at 11:45:57PM +0900, Masami Hiramatsu escreveu:

Quoted 1 line

Quoted 1 line

If we remove vmlinux, perf should use /proc/kallsyms. I think

I am not removing vmlinux, it is being used, its just that the function chosen by the 'perf test BPF' testcase isn't there.

So lets go again trying to chase this without missing a single step of the way:

We start with:

[root@jouet ~]# perf test bpf

37: Test BPF filter                                          :
37.1: Test basic BPF filtering                               : FAILED!
37.2: Test BPF prologue generation                           : Skip
37.3: Test BPF relocation checker                            : Skip

[root@jouet ~]#

Ok, so we add -v to get more information:

[root@jouet ~]# perf test -v bpf
<BIG SNIP>
bpf: config program 'func=sys_epoll_wait' symbol:sys_epoll_wait file:(null) line:0 offset:0 return:0 lazy:(null)
bpf: config 'func=sys_epoll_wait' is ok
Looking at the vmlinux_path (8 entries long)
Using /lib/modules/4.7.0+/build/vmlinux for symbols
Open Debuginfo file: /lib/modules/4.7.0+/build/vmlinux
Try to find probe point from debuginfo.
Symbol sys_epoll_wait address found : ffffffffbd295b50 Failed to find debug information for address ffffffffbd295b50 Probe point 'sys_epoll_wait' not found.
bpf_probe: failed to convert perf probe eventsFailed to add events selected by BPF
test child finished with -1
---- end ----
Test BPF filter subtest 0: FAILED!

--------------

See? It _is_ using /lib/modules/4.7.0+/build/vmlinux, and it should because:

[acme@jouet linux]$ file /lib/modules/4.7.0+/build/vmlinux /lib/modules/4.7.0+/build/vmlinux: ELF 64-bit LSB executable, x86-64, version 1 (SYSV), statically linked, BuildID[sha1]=a08d121dcee2a0ea0cfa5d84363de0c1cfdc729a, not stripped [acme@jouet linux]$

Its the kernel that is in use:

[acme@jouet linux]$ perf buildid-list --kernel

              a08d121dcee2a0ea0cfa5d84363de0c1cfdc729a

[acme@jouet linux]$ perf buildid-list -h --kernel

Usage: perf buildid-list [<options>]

-k, --kernel Show current kernel build id

[acme@jouet linux]$

And, in this vmlinux file, there is _no_ such function:

[acme@jouet linux]$ readelf -wi /lib/modules/4.7.0+/build/vmlinux | grep -w sys_epoll_wait [acme@jouet linux]$

Exactly like the 'perf probe -v bpf' says:

Symbol sys_epoll_wait address found : ffffffffbd295b50 Failed to find debug information for address ffffffffbd295b50

-----

It mapped it to an address, sure, it found it in /proc/kallsyms, but then it didn't find it in the matching vmlinux file.

Quoted 2 lines

Since the test was working before, when did it stop to be available on vmlinux?

Would you remember the previous test was done with this kernel or other one?

Actually, I could put probes on sys_epoll_wait on F24 standard kernel.

-----
[mhiramat@devbox perf]$ sudo ./perf probe -vnf sys_epoll_wait probe-definition(0): sys_epoll_wait
symbol:sys_epoll_wait file:(null) line:0 offset:0 return:0 lazy:(null) 0 arguments
Looking at the vmlinux_path (8 entries long)
Using /usr/lib/debug/lib/modules/4.6.4-301.fc24.x86_64/vmlinux for symbols Open Debuginfo file: /usr/lib/debug/lib/modules/4.6.4-301.fc24.x86_64/vmlinux Try to find probe point from debuginfo.
Symbol sys_epoll_wait address found : ffffffff81292d60
Matched function: SyS_epoll_wait
found inline addr: 0xffffffff812930f3
Probe point found: compat_SyS_epoll_pwait+147
found inline addr: 0xffffffff81292ed6
Probe point found: SyS_epoll_pwait+134
found inline addr: 0xffffffff81292d60
Probe point found: SyS_epoll_wait+0
Found 3 probe_trace_events.
Opening /sys/kernel/debug/tracing//kprobe_events write=1
Writing event: p:probe/sys_epoll_wait _text+2699507
Writing event: p:probe/sys_epoll_wait_1 _text+2698966
Writing event: p:probe/sys_epoll_wait_2 _text+2698592
Added new events:
probe:sys_epoll_wait (on sys_epoll_wait)
probe:sys_epoll_wait_1 (on sys_epoll_wait) probe:sys_epoll_wait_2 (on sys_epoll_wait)

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

perf record -e probe:sys_epoll_wait_2 -aR sleep 1

-----
FYI, if perf-probe failed to find the symbol in debuginfo, it tries to find its address from symbol table(kallsyms, here), and then tries to convert the address to the symbol in debuginfo again. It seems that in your case this convert process is failed.

Then, could you grep DEBUG_INFO in .config? I guess your kernel enables some reduced debuginfo related config enabled...

Em Thu, Aug 04, 2016 at 03:32:21PM +0900, Masami Hiramatsu escreveu:

Quoted 3 lines

FYI, if perf-probe failed to find the symbol in debuginfo, it tries to find its address from symbol table(kallsyms, here), and then tries to convert the address to the symbol in debuginfo again. It seems that in your case this convert process is failed.

Yeah, that is what is failing for me.

Quoted 2 lines

Then, could you grep DEBUG_INFO in .config? I guess your kernel enables some reduced debuginfo related config enabled...

If that is the case, then we better add a proper warning because this is very subtle :-)

Checking...

[acme@jouet linux]$ grep ^CONFIG_DEBUG_ ../build/v4.7.0+/.config | grep 'INFO\|REDUCED' CONFIG_DEBUG_INFO=y
[acme@jouet linux]$

Nope.

- Arnaldo

So:

int err = debuginfo__get_text_offset(dbg, &baseaddr);

is returning 0, no relocation, its dwarf_addrdie() that is not finding SyS_epoll_wait from its address.

Trying to figure out why dwarf_addrdie(0xffffffffbd295b50) fails...

Em Thu, Aug 04, 2016 at 04:36:56PM -0300, Arnaldo Carvalho de Melo escreveu:

Quoted 8 lines

So:

int err = debuginfo__get_text_offset(dbg, &baseaddr);

is returning 0, no relocation, its dwarf_addrdie() that is not finding SyS_epoll_wait from its address.

Trying to figure out why dwarf_addrdie(0xffffffffbd295b50) fails...

So, trying to use that vmlinux with objdump to do disassembly I found that I need to do some offsetting, and after calculating it, this made things works for me:

tools/perf/util/probe-finder.c +0 -0

index f2d9ff064e2d..9b95754f28ed 100644

tools/perf/util/probe-finder.c +0 -1

 			addr += baseaddr;
 			reloc = true;
 			goto retry;
 
----------------

With it, which is not a proper fix, of course, we get:

[root@jouet ~]# perf probe sys_epoll_wait
Added new events:
probe:sys_epoll_wait (on sys_epoll_wait)
probe:sys_epoll_wait_1 (on sys_epoll_wait)
probe:sys_epoll_wait_2 (on sys_epoll_wait)

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

perf record -e probe:sys_epoll_wait_2 -aR sleep 1

[root@jouet ~]#

Which, using -v shows it "finding" the alias:

[root@jouet ~]# perf probe -v sys_epoll_wait probe-definition(0): sys_epoll_wait
symbol:sys_epoll_wait file:(null) line:0 offset:0 return:0 lazy:(null) 0 arguments
Looking at the vmlinux_path (8 entries long)
Using /lib/modules/4.7.0+/build/vmlinux for symbols
Open Debuginfo file: /lib/modules/4.7.0+/build/vmlinux
Try to find probe point from debuginfo.
Symbol sys_epoll_wait address found : ffffffffbd295b50 Matched function: SyS_epoll_wait
found inline addr: 0xffffffff81295ee7
Probe point found: compat_SyS_epoll_pwait+151
found inline addr: 0xffffffff81295cca
Probe point found: SyS_epoll_pwait+138
found inline addr: 0xffffffff81295b50
Probe point found: SyS_epoll_wait+0

Found 3 probe_trace_events.
Opening /sys/kernel/debug/tracing//kprobe_events write=1 Writing event: p:probe/sys_epoll_wait _text+2711271 Writing event: p:probe/sys_epoll_wait_1 _text+2710730 Writing event: p:probe/sys_epoll_wait_2 _text+2710352 Added new events:
probe:sys_epoll_wait (on sys_epoll_wait) probe:sys_epoll_wait_1 (on sys_epoll_wait) probe:sys_epoll_wait_2 (on sys_epoll_wait)

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

perf record -e probe:sys_epoll_wait_2 -aR sleep 1

[root@jouet ~]#

----------

Now to figure out why baseaddr is returning as zero...

- Arnaldo

Quoted 14 lines · On Thu, 4 Aug 2016 18:47:24 -0300 Arnaldo Carvalho de Melo <[email protected]>…

Em Thu, Aug 04, 2016 at 04:36:56PM -0300, Arnaldo Carvalho de Melo escreveu:

Quoted 8 lines

So:

int err = debuginfo__get_text_offset(dbg, &baseaddr);

is returning 0, no relocation, its dwarf_addrdie() that is not finding SyS_epoll_wait from its address.

Trying to figure out why dwarf_addrdie(0xffffffffbd295b50) fails...

So, trying to use that vmlinux with objdump to do disassembly I found that I need to do some offsetting, and after calculating it, this made things works for me:

tools/perf/util/probe-finder.c retry: · line 1490

Quoted 10 lines

tools/perf/util/probe-finder.c +2 -0

index f2d9ff064e2d..9b95754f28ed 100644
@@ -1486,6 +1486,8 @@ retry:
 	/* Find cu die */
 	if (!dwarf_addrdie(dbg->dbg, (Dwarf_Addr)addr, &cudie)) {
 		if (!reloc && debuginfo__get_text_offset(dbg, &baseaddr) == 0) {
+			if (baseaddr == 0)
+				baseaddr = -0x3c000000;

Hmm, strange... what's this magic number ...?
Actually debuginfo__get_text_offset() is for kernel modules and it relocate the offset.

But I guess sys_epoll_wait is in the kernel.

Quoted 22 lines

tools/perf/util/probe-finder.c +0 -1

 			addr += baseaddr;
 			reloc = true;
 			goto retry;
 
----------------

With it, which is not a proper fix, of course, we get:

[root@jouet ~]# perf probe sys_epoll_wait
Added new events:
probe:sys_epoll_wait (on sys_epoll_wait)
probe:sys_epoll_wait_1 (on sys_epoll_wait)
probe:sys_epoll_wait_2 (on sys_epoll_wait)

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

perf record -e probe:sys_epoll_wait_2 -aR sleep 1

[root@jouet ~]#

Which, using -v shows it "finding" the alias:

Quoted 16 lines

[root@jouet ~]# perf probe -v sys_epoll_wait probe-definition(0): sys_epoll_wait
symbol:sys_epoll_wait file:(null) line:0 offset:0 return:0 lazy:(null) 0 arguments
Looking at the vmlinux_path (8 entries long)
Using /lib/modules/4.7.0+/build/vmlinux for symbols
Open Debuginfo file: /lib/modules/4.7.0+/build/vmlinux
Try to find probe point from debuginfo.
Symbol sys_epoll_wait address found : ffffffffbd295b50 Matched function: SyS_epoll_wait
found inline addr: 0xffffffff81295ee7
Probe point found: compat_SyS_epoll_pwait+151
found inline addr: 0xffffffff81295cca
Probe point found: SyS_epoll_pwait+138
found inline addr: 0xffffffff81295b50
Probe point found: SyS_epoll_wait+0

Mine shows
----
Using /usr/lib/debug/lib/modules/4.6.4-301.fc24.x86_64/vmlinux for symbols Open Debuginfo file: /usr/lib/debug/lib/modules/4.6.4-301.fc24.x86_64/vmlinux Try to find probe point from debuginfo.
Symbol sys_epoll_wait address found : ffffffff81292d60 <-(*) Matched function: SyS_epoll_wait
found inline addr: 0xffffffff812930f3
Probe point found: compat_SyS_epoll_pwait+147
found inline addr: 0xffffffff81292ed6
Probe point found: SyS_epoll_pwait+134
found inline addr: 0xffffffff81292d60
Probe point found: SyS_epoll_wait+0
Found 3 probe_trace_events.
-----

See the symbol address calcurated from symbol map, in successful case the address exactly same address of SyS_epoll_wait. This indicates something might wrong in the symbol map. (maybe KASLR?) Could you check what happen if nokaslr is passed to your kernel?

Thank you,

Quoted 21 lines

Found 3 probe_trace_events.
Opening /sys/kernel/debug/tracing//kprobe_events write=1 Writing event: p:probe/sys_epoll_wait _text+2711271 Writing event: p:probe/sys_epoll_wait_1 _text+2710730 Writing event: p:probe/sys_epoll_wait_2 _text+2710352 Added new events:
probe:sys_epoll_wait (on sys_epoll_wait) probe:sys_epoll_wait_1 (on sys_epoll_wait) probe:sys_epoll_wait_2 (on sys_epoll_wait)

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

perf record -e probe:sys_epoll_wait_2 -aR sleep 1

[root@jouet ~]#

----------

Now to figure out why baseaddr is returning as zero...

- Arnaldo

Signature · 1 line

Masami Hiramatsu <[email protected]>

Em Fri, Aug 05, 2016 at 06:45:50PM +0900, Masami Hiramatsu escreveu:

Quoted 4 lines

See the symbol address calcurated from symbol map, in successful case the address exactly same address of SyS_epoll_wait. This indicates something might wrong in the symbol map. (maybe KASLR?) Could you check what happen if nokaslr is passed to your kernel?

[acme@jouet linux]$ grep RANDOMIZE_BASE ../build/v4.7.0+/.config CONFIG_RANDOMIZE_BASE=y

Yes, it is in place, I'll check rebooting with nokaslr.

Can you think about how to properly warn the user about this possibility, if it is confirmed to cause this issue?

I wonder why this doesn't seem to affect annotation, that also uses vmlinux, for instance:

[root@jouet ~]# perf record --all-kernel -F 10000 ping -f -c 100000 localhost PING localhost.localdomain (127.0.0.1) 56(84) bytes of data.

--- localhost.localdomain ping statistics ---
100000 packets transmitted, 100000 received, 0% packet loss, time 732ms rtt min/avg/max/mdev = 0.003/0.003/0.048/0.002 ms, ipg/ewma 0.007/0.003 ms [ perf record: Woken up 2 times to write data ]
[ perf record: Captured and wrote 0.298 MB perf.data (7340 samples) ] [root@jouet ~]# perf report -v | grep '\[' | head -10
Using /lib/modules/4.7.0+/build/vmlinux for symbols

   20.42%  ping   /lib/modules/4.7.0+/build/vmlinux  0x960374  v [k] ipt_do_table
    2.55%  ping   /lib/modules/4.7.0+/build/vmlinux  0x900b8a  v [k] nf_iterate
    1.94%  ping   /lib/modules/4.7.0+/build/vmlinux  0x95190b  v [k] fib_table_lookup
    1.68%  ping   /lib/modules/4.7.0+/build/vmlinux  0x2accfa  v [k] __local_bh_enable_ip
    1.68%  ping   /lib/modules/4.7.0+/build/vmlinux  0x9e41ab  v [k] _raw_spin_lock_irqsave
    1.66%  ping   /lib/modules/4.7.0+/build/vmlinux  0x55fd94  v [k] avc_has_perm
    1.65%  ping   /lib/modules/4.7.0+/build/vmlinux  0x90e3e2  v [k] __ip_append_data.isra.44
    1.31%  ping   /lib/modules/4.7.0+/build/vmlinux  0x5ead59  v [k] copy_user_enhanced_fast_string
    1.21%  ping   /lib/modules/4.7.0+/build/vmlinux  0x938820  v [k] raw_local_deliver
    1.14%  ping   /lib/modules/4.7.0+/build/vmlinux  0x6c6cea  v [k] n_tty_write

[root@jouet ~]#

[root@jouet ~]# perf annotate -v --stdio ipt_do_table
Looking at the vmlinux_path (8 entries long)
Using /lib/modules/4.7.0+/build/vmlinux for symbols
symbol__disassemble: filename=/lib/modules/4.7.0+/build/vmlinux, sym=ipt_do_table, start=0xffffffffbd7601c0, end=0xffffffffbd7607b0
annotating [0x3cef9b0] /lib/modules/4.7.0+/build/vmlinux : [0x4159750] ipt_do_table
Executing: objdump --start-address=0xffffffff817601c0 --stop-address=0xffffffff817607b0 -l -d --no-show-raw -S -C /lib/modules/4.7.0+/build/vmlinux 2>/dev/nu
Percent | Source code & Disassembly of vmlinux for cycles:ppp (1498 samples)
----------------------------------------------------------------------------------
<SNIP>

[root@jouet ~]# grep ffffffffbd7601c0 /proc/kallsyms ffffffffbd7601c0 T ipt_do_table
[root@jouet ~]#

Anyway, will reboot this machine with nokaslr to check that possibility.

Em Fri, Aug 05, 2016 at 06:45:50PM +0900, Masami Hiramatsu escreveu:

Quoted 30 lines

Quoted 19 lines · On Thu, 4 Aug 2016 18:47:24 -0300 Arnaldo Carvalho de Melo <[email protected]>…

Em Thu, Aug 04, 2016 at 04:36:56PM -0300, Arnaldo Carvalho de Melo escreveu:

Quoted 8 lines

So:

int err = debuginfo__get_text_offset(dbg, &baseaddr);

is returning 0, no relocation, its dwarf_addrdie() that is not finding SyS_epoll_wait from its address.

Trying to figure out why dwarf_addrdie(0xffffffffbd295b50) fails...

So, trying to use that vmlinux with objdump to do disassembly I found that I need to do some offsetting, and after calculating it, this made things works for me:

tools/perf/util/probe-finder.c +0 -0

index f2d9ff064e2d..9b95754f28ed 100644

tools/perf/util/probe-finder.c retry: · line 1490

Quoted 5 lines

tools/perf/util/probe-finder.c +2 -0

@@ -1486,6 +1486,8 @@ retry:
 	/* Find cu die */
 	if (!dwarf_addrdie(dbg->dbg, (Dwarf_Addr)addr, &cudie)) {
 		if (!reloc && debuginfo__get_text_offset(dbg, &baseaddr) == 0) {
+			if (baseaddr == 0)
+				baseaddr = -0x3c000000;

Hmm, strange... what's this magic number ...?
Actually debuginfo__get_text_offset() is for kernel modules and it relocate the offset.

Quoted 31 lines · On Fri, 5 Aug 2016 11:35:32 -0300 Arnaldo Carvalho de Melo <[email protected]>…

Em Fri, Aug 05, 2016 at 06:45:50PM +0900, Masami Hiramatsu escreveu:

Quoted 30 lines

Quoted 19 lines · On Thu, 4 Aug 2016 18:47:24 -0300 Arnaldo Carvalho de Melo <[email protected]>…

Em Thu, Aug 04, 2016 at 04:36:56PM -0300, Arnaldo Carvalho de Melo escreveu:

Quoted 8 lines

So:

int err = debuginfo__get_text_offset(dbg, &baseaddr);

is returning 0, no relocation, its dwarf_addrdie() that is not finding SyS_epoll_wait from its address.

Trying to figure out why dwarf_addrdie(0xffffffffbd295b50) fails...

So, trying to use that vmlinux with objdump to do disassembly I found that I need to do some offsetting, and after calculating it, this made things works for me:

tools/perf/util/probe-finder.c +0 -0

index f2d9ff064e2d..9b95754f28ed 100644

tools/perf/util/probe-finder.c retry: · line 1490

Quoted 5 lines

tools/perf/util/probe-finder.c +2 -0

@@ -1486,6 +1486,8 @@ retry:
 	/* Find cu die */
 	if (!dwarf_addrdie(dbg->dbg, (Dwarf_Addr)addr, &cudie)) {
 		if (!reloc && debuginfo__get_text_offset(dbg, &baseaddr) == 0) {
+			if (baseaddr == 0)
+				baseaddr = -0x3c000000;

Hmm, strange... what's this magic number ...?
Actually debuginfo__get_text_offset() is for kernel modules and it relocate the offset.

I've found "commit f90acac75713cc6f18a4b2f1b9162bc1cd893c20"

Actually, I forgot to count the relocation at find_alternative_probe_point(). Could you try the patch below?

------
perf-probe: Adjust map->reloc offset when finding kernel symbol from map

Quoted 4 lines

Quoted 4 lines

[root@jouet ~]# perf probe sys_epoll_wait
Failed to find debug information for address ffffffffbd295b50 Probe point 'sys_epoll_wait' not found.
Error: Failed to add events.

So, at least I should investigate it.

Quoted 5 lines · On Wed, 3 Aug 2016 23:45:57 +0900 Masami Hiramatsu <[email protected]> wrote:

Quoted 4 lines

Quoted 4 lines

[root@jouet ~]# perf probe sys_epoll_wait
Failed to find debug information for address ffffffffbd295b50 Probe point 'sys_epoll_wait' not found.
Error: Failed to add events.

So, at least I should investigate it.

FYI, on ubuntu16.04, I can put probes on sys_epoll_wait as below

mhiramat@devnote:~/ksrc/linux/tools/perf$ sudo ./perf probe -vnf sys_epoll_wait
probe-definition(0): sys_epoll_wait
symbol:sys_epoll_wait file:(null) line:0 offset:0 return:0 lazy:(null)
0 arguments
Looking at the vmlinux_path (8 entries long)
Using /usr/lib/debug/boot/vmlinux-4.4.0-31-generic for symbols
Open Debuginfo file: /usr/lib/debug/boot/vmlinux-4.4.0-31-generic
Try to find probe point from debuginfo.
Symbol sys_epoll_wait address found : ffffffff81257410
Matched function: SyS_epoll_wait
found inline addr: 0xffffffff81257410
Probe point found: SyS_epoll_wait+0
found inline addr: 0xffffffff8125756d
Probe point found: SyS_epoll_pwait+141
found inline addr: 0xffffffff81257793
Probe point found: compat_SyS_epoll_pwait+147
Found 3 probe_trace_events.
Opening /sys/kernel/debug/tracing//kprobe_events write=1
Writing event: p:probe/sys_epoll_wait _text+2454544
Writing event: p:probe/sys_epoll_wait_1 _text+2454893
Writing event: p:probe/sys_epoll_wait_2 _text+2455443
Added new events:
   probe:sys_epoll_wait (on sys_epoll_wait)
   probe:sys_epoll_wait_1 (on sys_epoll_wait)
   probe:sys_epoll_wait_2 (on sys_epoll_wait)

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

perf record -e probe:sys_epoll_wait_2 -aR sleep 1

Quoted 36 lines · Masami Hiramatsu

Quoted 5 lines · On Wed, 3 Aug 2016 23:45:57 +0900 Masami Hiramatsu <[email protected]> wrote:

Quoted 4 lines

Quoted 4 lines

[root@jouet ~]# perf probe sys_epoll_wait
Failed to find debug information for address ffffffffbd295b50 Probe point 'sys_epoll_wait' not found.
Error: Failed to add events.

So, at least I should investigate it.

FYI, on ubuntu16.04, I can put probes on sys_epoll_wait as below

mhiramat@devnote:~/ksrc/linux/tools/perf$ sudo ./perf probe -vnf sys_epoll_wait
probe-definition(0): sys_epoll_wait
symbol:sys_epoll_wait file:(null) line:0 offset:0 return:0 lazy:(null)
0 arguments
Looking at the vmlinux_path (8 entries long)
Using /usr/lib/debug/boot/vmlinux-4.4.0-31-generic for symbols
Open Debuginfo file: /usr/lib/debug/boot/vmlinux-4.4.0-31-generic
Try to find probe point from debuginfo.
Symbol sys_epoll_wait address found : ffffffff81257410
Matched function: SyS_epoll_wait
found inline addr: 0xffffffff81257410
Probe point found: SyS_epoll_wait+0
found inline addr: 0xffffffff8125756d
Probe point found: SyS_epoll_pwait+141
found inline addr: 0xffffffff81257793
Probe point found: compat_SyS_epoll_pwait+147
Found 3 probe_trace_events.
Opening /sys/kernel/debug/tracing//kprobe_events write=1
Writing event: p:probe/sys_epoll_wait _text+2454544
Writing event: p:probe/sys_epoll_wait_1 _text+2454893
Writing event: p:probe/sys_epoll_wait_2 _text+2455443
Added new events:
   probe:sys_epoll_wait (on sys_epoll_wait)
   probe:sys_epoll_wait_1 (on sys_epoll_wait)
   probe:sys_epoll_wait_2 (on sys_epoll_wait)

Quoted 4 lines

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

perf record -e probe:sys_epoll_wait_2 -aR sleep 1

Have you checked 'readelf -wi'? I guess you wouldn't find sys_epoll_wait.