Re: perf object code reading test crashes

From: Arnaldo Carvalho de Melo
Date: Thu Feb 18 2016 - 09:27:37 EST


Em Wed, Feb 17, 2016 at 05:13:59PM -0800, Steven Noonan escreveu:
> On Wed, Feb 17, 2016 at 6:27 AM, Arnaldo Carvalho de Melo wrote
> > Yeah, we forgot to grab refcounts in perf_evlist__set_maps(), can you
> > try this instead, if it works please let me know so that I can add a:

> > Reported-and-Tested-by: you to this patch,

> That did the trick for the refcounting as far as valgrind/libc are concerned.

> Reported-and-Tested-by: Steven Noonan <steven@xxxxxxxxxxxxxx>

Thanks, about the test failing:

#define EINVAL 22 /* Invalid argument */

It can be a number of things, lemme try running it here:

> Now to figure out why the test is failing. This same test works fine
> on another system running the same kernel build:

> $ ./perf test -v -v 21
> 21: Test object code reading :
> --- start ---
> test child forked, pid 19527
> Looking at the vmlinux_path (7 entries long)
> Using /usr/lib/debug/lib/modules/4.4.1-1-ec2/vmlinux for symbols
> Parsing event 'cycles'
> ------------------------------------------------------------
> perf_event_attr:
> size 112
> { sample_period, sample_freq } 4000
> sample_type IP|TID|PERIOD
> disabled 1
> inherit 1
> mmap 1
> comm 1
> freq 1
> task 1
> sample_id_all 1
> exclude_guest 1
> mmap2 1
> comm_exec 1
> ------------------------------------------------------------
> sys_perf_event_open: pid 19527 cpu 0 group_fd -1 flags 0x8
> sys_perf_event_open failed, error -22

[acme@jouet linux]$ perf test -v -v 21 2>&1 | head -30
21: Test object code reading :
--- start ---
test child forked, pid 28587
Looking at the vmlinux_path (8 entries long)
Using /usr/lib/debug/lib/modules/4.3.5-300.fc23.x86_64/vmlinux for symbols
Parsing event 'cycles'
------------------------------------------------------------
perf_event_attr:
size 112
{ sample_period, sample_freq } 4000
sample_type IP|TID|PERIOD
disabled 1
inherit 1
mmap 1
comm 1
freq 1
task 1
sample_id_all 1
exclude_guest 1
mmap2 1
comm_exec 1
------------------------------------------------------------
sys_perf_event_open: pid 28587 cpu 0 group_fd -1 flags 0x8
sys_perf_event_open: pid 28587 cpu 1 group_fd -1 flags 0x8
sys_perf_event_open: pid 28587 cpu 2 group_fd -1 flags 0x8
sys_perf_event_open: pid 28587 cpu 3 group_fd -1 flags 0x8
mmap size 528384B
perf event ring buffer mmapped per cpu
Reading object code for memory address: 0xffffffff810604ea
File is: /usr/lib/debug/lib/modules/4.3.5-300.fc23.x86_64/vmlinux
[acme@jouet linux]$

Works and starts to use the vmlinux file, etc, now lets try reducing the max
sample_freq to something below 4000 (4 kHz):

[root@jouet ~]# cat /proc/sys/kernel/perf_event_max_sample_rate
25000
[root@jouet ~]# echo 1000 > /proc/sys/kernel/perf_event_max_sample_rate

When the system boots it starts with a high value and auto-decreases under
certain conditions:

[root@jouet ~]# dmesg | grep max_sample_rate
[ 2499.144373] perf interrupt took too long (2501 > 2500), lowering kernel.perf_event_max_sample_rate to 50000
[ 3592.413606] perf interrupt took too long (5069 > 5000), lowering kernel.perf_event_max_sample_rate to 25000
[root@jouet ~]#

So lets say this specific system of yours went all the way down to 1000 (1 kHz):

[acme@jouet linux]$ perf test -v -v 21 2>&1 | head -25
21: Test object code reading :
--- start ---
test child forked, pid 29140
Looking at the vmlinux_path (8 entries long)
Using /usr/lib/debug/lib/modules/4.3.5-300.fc23.x86_64/vmlinux for symbols
Parsing event 'cycles'
------------------------------------------------------------
perf_event_attr:
size 112
{ sample_period, sample_freq } 4000
sample_type IP|TID|PERIOD
disabled 1
inherit 1
mmap 1
comm 1
freq 1
task 1
sample_id_all 1
exclude_guest 1
mmap2 1
comm_exec 1
------------------------------------------------------------
sys_perf_event_open: pid 29140 cpu 0 group_fd -1 flags 0x8
sys_perf_event_open failed, error -22
------------------------------------------------------------
[acme@jouet linux]$ perf test -v -v 21 2>&1 | tail -5
sys_perf_event_open failed, error -22
perf_evlist__open failed
test child finished with -1
---- end ----
Test object code reading: FAILED!
[acme@jouet linux]$

Oops, guess this is the problem, and I also think we don't need more than 1 hz
in this test if even that :-\

So, try the patch at the end of this message, with it and with I get:

[root@jouet ~]# cat /proc/sys/kernel/perf_event_max_sample_rate
1000
[root@jouet ~]# perf test -v -v 21 2>&1 | tail -26
Using /proc/kcore for kernel object code
Using /proc/kallsyms for symbols
Parsing event 'cycles'
------------------------------------------------------------
perf_event_attr:
size 112
sample_type IP|TID
disabled 1
inherit 1
mmap 1
comm 1
task 1
sample_id_all 1
exclude_guest 1
mmap2 1
comm_exec 1
------------------------------------------------------------
sys_perf_event_open: pid 31476 cpu 0 group_fd -1 flags 0x8
sys_perf_event_open: pid 31476 cpu 1 group_fd -1 flags 0x8
sys_perf_event_open: pid 31476 cpu 2 group_fd -1 flags 0x8
sys_perf_event_open: pid 31476 cpu 3 group_fd -1 flags 0x8
mmap size 528384B
perf event ring buffer mmapped per cpu
test child finished with 0
---- end ----
Test object code reading: Ok
[root@jouet ~]#

---
diff --git a/tools/perf/tests/code-reading.c b/tools/perf/tests/code-reading.c
index 313a48c6b2bc..a984accdaa74 100644
--- a/tools/perf/tests/code-reading.c
+++ b/tools/perf/tests/code-reading.c
@@ -439,7 +439,6 @@ static int do_test_code_reading(bool try_kcore)
.mmap_pages = UINT_MAX,
.user_freq = UINT_MAX,
.user_interval = ULLONG_MAX,
- .freq = 4000,
.target = {
.uses_mmap = true,
},