linux-kernel.vger.kernel.org archive mirror
 help / color / mirror / Atom feed
* perf object code reading test crashes
@ 2016-02-17  6:42 Steven Noonan
  2016-02-17 14:27 ` Arnaldo Carvalho de Melo
  0 siblings, 1 reply; 5+ messages in thread
From: Steven Noonan @ 2016-02-17  6:42 UTC (permalink / raw)
  To: Linux Kernel mailing List; +Cc: Arnaldo Carvalho de Melo, Adrian Hunter

I oddly didn't run into this issue on every machine I tried, but
there's some issues here:

$ sudo perf test 21
21: Test object code reading                                 :***
Error in `perf': corrupted double-linked list: 0x00000000023ffcd0 ***
======= Backtrace: =========
/usr/lib/libc.so.6(+0x72055)[0x7f25be0f3055]
/usr/lib/libc.so.6(+0x779b6)[0x7f25be0f89b6]
/usr/lib/libc.so.6(+0x7a0ed)[0x7f25be0fb0ed]
/usr/lib/libc.so.6(__libc_calloc+0xba)[0x7f25be0fceda]
perf(parse_events_lex_init_extra+0x38)[0x4cfff8]
perf(parse_events+0x55)[0x4a0615]
perf(perf_evlist__config+0xcf)[0x4eeb2f]
perf[0x479f82]
perf(test__code_reading+0x1e)[0x47ad4e]
perf(cmd_test+0x5dd)[0x46452d]
perf[0x47f4e3]
perf(main+0x603)[0x42c723]
/usr/lib/libc.so.6(__libc_start_main+0xf0)[0x7f25be0a1610]
perf(_start+0x29)[0x42c859]
======= Memory map: ========
00400000-0068d000 r-xp 00000000 08:03 2384296
  /usr/bin/perf
0088d000-008a1000 r--p 0028d000 08:03 2384296
  /usr/bin/perf
008a1000-008c2000 rw-p 002a1000 08:03 2384296
  /usr/bin/perf
008c2000-0194f000 rw-p 00000000 00:00 0
02193000-021b4000 rw-p 00000000 00:00 0                                  [heap]
021b4000-0254a000 rw-p 00000000 00:00 0                                  [heap]
7f25b8000000-7f25b8021000 rw-p 00000000 00:00 0
7f25b8021000-7f25bc000000 ---p 00000000 00:00 0
7f25bcdff000-7f25bce15000 r-xp 00000000 08:03 2378588
  /usr/lib/libgcc_s.so.1
7f25bce15000-7f25bd014000 ---p 00016000 08:03 2378588
  /usr/lib/libgcc_s.so.1
7f25bd014000-7f25bd015000 rw-p 00015000 08:03 2378588
  /usr/lib/libgcc_s.so.1
7f25bd015000-7f25bd017000 r-xp 00000000 08:03 2361423
  /usr/lib/libutil-2.22.so
7f25bd017000-7f25bd216000 ---p 00002000 08:03 2361423
  /usr/lib/libutil-2.22.so
7f25bd216000-7f25bd217000 r--p 00001000 08:03 2361423
  /usr/lib/libutil-2.22.so
7f25bd217000-7f25bd218000 rw-p 00002000 08:03 2361423
  /usr/lib/libutil-2.22.so
7f25bd218000-7f25bd220000 r-xp 00000000 08:03 2361358
  /usr/lib/libcrypt-2.22.so
7f25bd220000-7f25bd420000 ---p 00008000 08:03 2361358
  /usr/lib/libcrypt-2.22.so
7f25bd420000-7f25bd421000 r--p 00008000 08:03 2361358
  /usr/lib/libcrypt-2.22.so
7f25bd421000-7f25bd422000 rw-p 00009000 08:03 2361358
  /usr/lib/libcrypt-2.22.so
7f25bd422000-7f25bd450000 rw-p 00000000 00:00 0
7f25bd450000-7f25bd45f000 r-xp 00000000 08:03 2365752
  /usr/lib/libbz2.so.1.0.6
7f25bd45f000-7f25bd65e000 ---p 0000f000 08:03 2365752
  /usr/lib/libbz2.so.1.0.6
7f25bd65e000-7f25bd660000 rw-p 0000e000 08:03 2365752
  /usr/lib/libbz2.so.1.0.6
7f25bd660000-7f25bd66a000 r-xp 00000000 08:03 2379940
  /usr/lib/libnuma.so.1.0.0
7f25bd66a000-7f25bd86a000 ---p 0000a000 08:03 2379940
  /usr/lib/libnuma.so.1.0.0
7f25bd86a000-7f25bd86b000 r--p 0000a000 08:03 2379940
  /usr/lib/libnuma.so.1.0.0
7f25bd86b000-7f25bd86c000 rw-p 0000b000 08:03 2379940
  /usr/lib/libnuma.so.1.0.0
7f25bd86c000-7f25bd891000 r-xp 00000000 08:03 2365772
  /usr/lib/liblzma.so.5.2.2
7f25bd891000-7f25bda90000 ---p 00025000 08:03 2365772
  /usr/lib/liblzma.so.5.2.2
7f25bda90000-7f25bda91000 r--p 00024000 08:03 2365772
  /usr/lib/liblzma.so.5.2.2
7f25bda91000-7f25bda92000 rw-p 00025000 08:03 2365772
  /usr/lib/liblzma.so.5.2.2
7f25bda92000-7f25bdaa7000 r-xp 00000000 08:03 2365728
  /usr/lib/libz.so.1.2.8
7f25bdaa7000-7f25bdca6000 ---p 00015000 08:03 2365728
  /usr/lib/libz.so.1.2.8
7f25bdca6000-7f25bdca7000 r--p 00014000 08:03 2365728
  /usr/lib/libz.so.1.2.8
7f25bdca7000-7f25bdca8000 rw-p 00015000 08:03 2365728
  /usr/lib/libz.so.1.2.8
7f25bdca8000-7f25bde33000 r-xp 00000000 08:03 2380612
  /usr/lib/libpython2.7.so.1.0
7f25bde33000-7f25be032000 ---p 0018b000 08:03 2380612
  /usr/lib/libpython2.7.so.1.0
7f25be032000-7f25be034000 r--p 0018a000 08:03 2380612
  /usr/lib/libpython2.7.so.1.0
7f25be034000-7f25be072000 rw-p 0018c000 08:03 2380612
  /usr/lib/libpython2.7.so.1.0
7f25be072000-7f25be081000 rw-p 00000000 00:00 0
7f25be081000-7f25be21b000 r-xp 00000000 08:03 2361437
  /usr/lib/libc-2.22.so
7f25be21b000-7f25be41b000 ---p 0019a000 08:03 2361437
  /usr/lib/libc-2.22.so
7f25be41b000-7f25be41f000 r--p 0019a000 08:03 2361437
  /usr/lib/libc-2.22.so
7f25be41f000-7f25be421000 rw-p 0019e000 08:03 2361437
  /usr/lib/libc-2.22.so
7f25be421000-7f25be425000 rw-p 00000000 00:00 0
7f25be425000-7f25be5ff000 r-xp 00000000 08:03 2367396
  /usr/lib/perl5/core_perl/CORE/libperl.so
7f25be5ff000-7f25be7ff000 ---p 001da000 08:03 2367396
  /usr/lib/perl5/core_perl/CORE/libperl.so
7f25be7ff000-7f25be804000 r--p 001da000 08:03 2367396
  /usr/lib/perl5/core_perl/CORE/libperl.so
7f25be804000-7f25be808000 rw-p 001df000 08:03 2367396
  /usr/lib/perl5/core_perl/CORE/libperl.so
7f25be808000-7f25be905000 r-xp 00000000 08:03 2392491
  /usr/lib/libslang.so.2.3.0
7f25be905000-7f25beb04000 ---p 000fd000 08:03 2392491
  /usr/lib/libslang.so.2.3.0
7f25beb04000-7f25beb09000 r--p 000fc000 08:03 2392491
  /usr/lib/libslang.so.2.3.0
7f25beb09000-7f25beb22000 rw-p 00101000 08:03 2392491
  /usr/lib/libslang.so.2.3.0
7f25beb22000-7f25beb77000 rw-p 00000000 00:00 0
7f25beb77000-7f25beb87000 r-xp 00000000 08:03 2384494
  /usr/lib/libunwind-x86_64.so.8.0.1
7f25beb87000-7f25bed86000 ---p 00010000 08:03 2384494
  /usr/lib/libunwind-x86_64.so.8.0.1
7f25bed86000-7f25bed87000 r--p 0000f000 08:03 2384494
  /usr/lib/libunwind-x86_64.so.8.0.1
7f25bed87000-7f25bed88000 rw-p 00010000 08:03 2384494
  /usr/lib/libunwind-x86_64.so.8.0.1
7f25bed88000-7f25bed96000 rw-p 00000000 00:00 0
7f25bed96000-7f25beda1000 r-xp 00000000 08:03 2384491
  /usr/lib/libunwind.so.8.0.1
7f25beda1000-7f25befa0000 ---p 0000b000 08:03 2384491
  /usr/lib/libunwind.so.8.0.1
7f25befa0000-7f25befa1000 r--p 0000a000 08:03 2384491
  /usr/lib/libunwind.so.8.0.1
7f25befa1000-7f25befa2000 rw-p 0000b000 08:03 2384491
  /usr/lib/libunwind.so.8.0.1
7f25befa2000-7f25befb0000 rw-p 00000000 00:00 0
7f25befb0000-7f25beff7000 r-xp 00000000 08:03 2365854
  /usr/lib/libdw-0.165.so
7f25beff7000-7f25bf1f7000 ---p 00047000 08:03 2365854
  /usr/lib/libdw-0.165.so
7f25bf1f7000-7f25bf1f9000 r--p 00047000 08:03 2365854
  /usr/lib/libdw-0.165.so
7f25bf1f9000-7f25bf1fa000 rw-p 00049000 08:03 2365854
  /usr/lib/libdw-0.165.so
7f25bf1fa000-7f25bf211000 r-xp 00000000 08:03 2365856
  /usr/lib/libelf-0.165.so
7f25bf211000-7f25bf410000 ---p 00017000 08:03 2365856
  /usr/lib/libelf-0.165.so
7f25bf410000-7f25bf411000 r--p 00016000 08:03 2365856
  /usr/lib/libelf-0.165.so
7f25bf411000-7f25bf412000 rw-p 00017000 08:03 2365856
  /usr/lib/libelf-0.165.so
7f25bf412000-7f25bf415000 r-xp 00000000 08:03 2361340
  /usr/lib/libdl-2.22.so
7f25bf415000-7f25bf614000 ---p 00003000 08:03 2361340
  /usr/lib/libdl-2.22.so
7f25bf614000-7f25bf615000 r--p 00002000 08:03 2361340
  /usr/lib/libdl-2.22.so
7f25bf615000-7f25bf616000 rw-p 00003000 08:03 2361340
  /usr/lib/libdl-2.22.so
7f25bf616000-7f25bf713000 r-xp 00000000 08:03 2361395
  /usr/lib/libm-2.22.so
7f25bf713000-7f25bf912000 ---p 000fd000 08:03 2361395
  /usr/lib/libm-2.22.so
7f25bf912000-7f25bf913000 r--p 000fc000 08:03 2361395
  /usr/lib/libm-2.22.so
7f25bf913000-7f25bf914000 rw-p 000fd000 08:03 2361395
  /usr/lib/libm-2.22.so
7f25bf914000-7f25bf91b000 r-xp 00000000 08:03 2361374
  /usr/lib/librt-2.22.so
7f25bf91b000-7f25bfb1a000 ---p 00007000 08:03 2361374
  /usr/lib/librt-2.22.so
7f25bfb1a000-7f25bfb1b000 r--p 00006000 08:03 2361374
  /usr/lib/librt-2.22.so
7f25bfb1b000-7f25bfb1c000 rw-p 00007000 08:03 2361374
  /usr/lib/librt-2.22.so
7f25bfb1c000-7f25bfb34000 r-xp 00000000 08:03 2361457
  /usr/lib/libpthread-2.22.so
7f25bfb34000-7f25bfd33000 ---p 00018000 08:03 2361457
  /usr/lib/libpthread-2.22.so
7f25bfd33000-7f25bfd34000 r--p 00017000 08:03 2361457
  /usr/lib/libpthread-2.22.so
7f25bfd34000-7f25bfd35000 rw-p 00018000 08:03 2361457
  /usr/lib/libpthread-2.22.so
7f25bfd35000-7f25bfd39000 rw-p 00000000 00:00 0
7f25bfd39000-7f25bfd5b000 r-xp 00000000 08:03 2361373
  /usr/lib/ld-2.22.so
7f25bff13000-7f25bff1e000 rw-p 00000000 00:00 0
7f25bff59000-7f25bff5a000 rw-p 00000000 00:00 0
7f25bff5a000-7f25bff5b000 r--p 00021000 08:03 2361373
  /usr/lib/ld-2.22.so
7f25bff5b000-7f25bff5c000 rw-p 00022000 08:03 2361373
  /usr/lib/ld-2.22.so
7f25bff5c000-7f25bff5d000 rw-p 00000000 00:00 0
7ffc284af000-7ffc284d0000 rw-p 00000000 00:00 0                          [stack]
7ffc28585000-7ffc28587000 r--p 00000000 00:00 0                          [vvar]
7ffc28587000-7ffc28589000 r-xp 00000000 00:00 0                          [vdso]
 FAILED!


Valgrind seems to suggest that the cpu map is getting freed too early:

==11450== 3 errors in context 25 of 25:
==11450== Invalid read of size 4
==11450==    at 0x4CC64D: atomic_inc (atomic.h:48)
==11450==    by 0x4CC64D: cpu_map__get (cpumap.c:235)
==11450==    by 0x484DF0: __perf_evlist__propagate_maps (evlist.c:137)
==11450==    by 0x4857D9: perf_evlist__add (evlist.c:165)
==11450==    by 0x48588E: perf_evlist__splice_list_tail (evlist.c:182)
==11450==    by 0x4947F9: parse_events (parse-events.c:1411)
==11450==    by 0x476383: do_test_code_reading (code-reading.c:534)
==11450==    by 0x476575: test__code_reading (code-reading.c:608)
==11450==    by 0x45D7CD: run_test (builtin-test.c:219)
==11450==    by 0x45D982: __cmd_test (builtin-test.c:268)
==11450==    by 0x45DBD1: cmd_test (builtin-test.c:338)
==11450==    by 0x47B580: run_builtin (perf.c:386)
==11450==    by 0x47B77D: handle_internal_command (perf.c:447)
==11450==  Address 0x875b8a0 is 0 bytes inside a block of size 136 free'd
==11450==    at 0x4C29D2A: free (in
/usr/lib/valgrind/vgpreload_memcheck-amd64-linux.so)
==11450==    by 0x4CBD49: cpu_map__delete (cpumap.c:228)
==11450==    by 0x4CC690: cpu_map__put (cpumap.c:242)
==11450==    by 0x484DE3: __perf_evlist__propagate_maps (evlist.c:136)
==11450==    by 0x484E87: perf_evlist__propagate_maps (evlist.c:152)
==11450==    by 0x486948: perf_evlist__set_maps (evlist.c:1222)
==11450==    by 0x4763FC: do_test_code_reading (code-reading.c:552)
==11450==    by 0x476575: test__code_reading (code-reading.c:608)
==11450==    by 0x45D7CD: run_test (builtin-test.c:219)
==11450==    by 0x45D982: __cmd_test (builtin-test.c:268)
==11450==    by 0x45DBD1: cmd_test (builtin-test.c:338)
==11450==    by 0x47B580: run_builtin (perf.c:386)
==11450==  Block was alloc'd at
==11450==    at 0x4C28C10: malloc (in
/usr/lib/valgrind/vgpreload_memcheck-amd64-linux.so)
==11450==    by 0x4CBC10: cpu_map__trim_new (cpumap.c:35)
==11450==    by 0x4CC1FD: cpu_map__read (cpumap.c:93)
==11450==    by 0x4CC286: cpu_map__read_all_cpu_map (cpumap.c:110)
==11450==    by 0x4CC2E3: cpu_map__new (cpumap.c:125)
==11450==    by 0x4762BC: do_test_code_reading (code-reading.c:512)
==11450==    by 0x476575: test__code_reading (code-reading.c:608)
==11450==    by 0x45D7CD: run_test (builtin-test.c:219)
==11450==    by 0x45D982: __cmd_test (builtin-test.c:268)
==11450==    by 0x45DBD1: cmd_test (builtin-test.c:338)
==11450==    by 0x47B580: run_builtin (perf.c:386)
==11450==    by 0x47B77D: handle_internal_command (perf.c:447)


I tried this, and the problem goes away:

diff --git a/tools/perf/tests/code-reading.c b/tools/perf/tests/code-reading.c
index a767a64..00d30b9 100644
--- a/tools/perf/tests/code-reading.c
+++ b/tools/perf/tests/code-reading.c
@@ -514,6 +514,7 @@ static int do_test_code_reading(bool try_kcore)
                pr_debug("cpu_map__new failed\n");
                goto out_put;
        }
+       cpu_map__get(cpus);

        while (1) {
                const char *str;


But the above change seems totally bogus, because cpu_map__new should
have set the reference count to 1 already, so we must have unbalanced
get/put calls somehow. Anyone see the issue?

^ permalink raw reply related	[flat|nested] 5+ messages in thread

* Re: perf object code reading test crashes
  2016-02-17  6:42 perf object code reading test crashes Steven Noonan
@ 2016-02-17 14:27 ` Arnaldo Carvalho de Melo
  2016-02-18  1:13   ` Steven Noonan
  0 siblings, 1 reply; 5+ messages in thread
From: Arnaldo Carvalho de Melo @ 2016-02-17 14:27 UTC (permalink / raw)
  To: Steven Noonan; +Cc: Linux Kernel mailing List, Adrian Hunter, acme

Em Tue, Feb 16, 2016 at 10:42:19PM -0800, Steven Noonan escreveu:
> I oddly didn't run into this issue on every machine I tried, but
> there's some issues here:
> 
> $ sudo perf test 21
> 21: Test object code reading                                 :***
> Error in `perf': corrupted double-linked list: 0x00000000023ffcd0 ***

>  FAILED!
> 
> Valgrind seems to suggest that the cpu map is getting freed too early:
> 
> ==11450==  Address 0x875b8a0 is 0 bytes inside a block of size 136 free'd
> ==11450==    at 0x4C29D2A: free (in
> /usr/lib/valgrind/vgpreload_memcheck-amd64-linux.so)
> ==11450==    by 0x4CBD49: cpu_map__delete (cpumap.c:228)
> ==11450==    by 0x4CC690: cpu_map__put (cpumap.c:242)
> ==11450==    by 0x484DE3: __perf_evlist__propagate_maps (evlist.c:136)
 
 
> I tried this, and the problem goes away:

 
> +++ b/tools/perf/tests/code-reading.c
> @@ -514,6 +514,7 @@ static int do_test_code_reading(bool try_kcore)
>         }
> +       cpu_map__get(cpus);
> 
>         while (1) {

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,

Thanks for the nice report!

- Arnaldo

diff --git a/tools/perf/util/evlist.c b/tools/perf/util/evlist.c
index d81f13de2476..a7eb0eae9938 100644
--- a/tools/perf/util/evlist.c
+++ b/tools/perf/util/evlist.c
@@ -1181,12 +1181,12 @@ void perf_evlist__set_maps(struct perf_evlist *evlist, struct cpu_map *cpus,
 	 */
 	if (cpus != evlist->cpus) {
 		cpu_map__put(evlist->cpus);
-		evlist->cpus = cpus;
+		evlist->cpus = cpu_map__get(cpus);
 	}
 
 	if (threads != evlist->threads) {
 		thread_map__put(evlist->threads);
-		evlist->threads = threads;
+		evlist->threads = thread_map__get(threads);
 	}
 
 	perf_evlist__propagate_maps(evlist);

^ permalink raw reply related	[flat|nested] 5+ messages in thread

* Re: perf object code reading test crashes
  2016-02-17 14:27 ` Arnaldo Carvalho de Melo
@ 2016-02-18  1:13   ` Steven Noonan
  2016-02-18 14:27     ` Arnaldo Carvalho de Melo
  0 siblings, 1 reply; 5+ messages in thread
From: Steven Noonan @ 2016-02-18  1:13 UTC (permalink / raw)
  To: Arnaldo Carvalho de Melo; +Cc: Linux Kernel mailing List, Adrian Hunter, acme

On Wed, Feb 17, 2016 at 6:27 AM, Arnaldo Carvalho de Melo
<acme@redhat.com> wrote:
> Em Tue, Feb 16, 2016 at 10:42:19PM -0800, Steven Noonan escreveu:
>> I oddly didn't run into this issue on every machine I tried, but
>> there's some issues here:
>>
>> $ sudo perf test 21
>> 21: Test object code reading                                 :***
>> Error in `perf': corrupted double-linked list: 0x00000000023ffcd0 ***
>
>>  FAILED!
>>
>> Valgrind seems to suggest that the cpu map is getting freed too early:
>>
>> ==11450==  Address 0x875b8a0 is 0 bytes inside a block of size 136 free'd
>> ==11450==    at 0x4C29D2A: free (in
>> /usr/lib/valgrind/vgpreload_memcheck-amd64-linux.so)
>> ==11450==    by 0x4CBD49: cpu_map__delete (cpumap.c:228)
>> ==11450==    by 0x4CC690: cpu_map__put (cpumap.c:242)
>> ==11450==    by 0x484DE3: __perf_evlist__propagate_maps (evlist.c:136)
>
>
>> I tried this, and the problem goes away:
>
>
>> +++ b/tools/perf/tests/code-reading.c
>> @@ -514,6 +514,7 @@ static int do_test_code_reading(bool try_kcore)
>>         }
>> +       cpu_map__get(cpus);
>>
>>         while (1) {
>
> 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,
>
> Thanks for the nice report!
>
> - Arnaldo

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

Reported-and-Tested-by: Steven Noonan <steven@uplinklabs.net>


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
------------------------------------------------------------
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 0
sys_perf_event_open failed, error -22
------------------------------------------------------------
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
  comm_exec                        1
------------------------------------------------------------
sys_perf_event_open: pid 19527  cpu 0  group_fd -1  flags 0
sys_perf_event_open failed, error -22
------------------------------------------------------------
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
  comm_exec                        1
------------------------------------------------------------
sys_perf_event_open: pid 19527  cpu 0  group_fd -1  flags 0
sys_perf_event_open failed, error -22
------------------------------------------------------------
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
  comm_exec                        1
------------------------------------------------------------
sys_perf_event_open: pid 19527  cpu 0  group_fd -1  flags 0
sys_perf_event_open failed, error -22
Parsing event 'cycles:u'
------------------------------------------------------------
perf_event_attr:
  size                             112
  { sample_period, sample_freq }   4000
  sample_type                      IP|TID|PERIOD
  disabled                         1
  inherit                          1
  exclude_kernel                   1
  exclude_hv                       1
  mmap                             1
  comm                             1
  freq                             1
  task                             1
  comm_exec                        1
------------------------------------------------------------
sys_perf_event_open: pid 19527  cpu 0  group_fd -1  flags 0
sys_perf_event_open failed, error -22
perf_evlist__open failed
test child finished with -1
---- end ----
Test object code reading: FAILED!


>
> diff --git a/tools/perf/util/evlist.c b/tools/perf/util/evlist.c
> index d81f13de2476..a7eb0eae9938 100644
> --- a/tools/perf/util/evlist.c
> +++ b/tools/perf/util/evlist.c
> @@ -1181,12 +1181,12 @@ void perf_evlist__set_maps(struct perf_evlist *evlist, struct cpu_map *cpus,
>          */
>         if (cpus != evlist->cpus) {
>                 cpu_map__put(evlist->cpus);
> -               evlist->cpus = cpus;
> +               evlist->cpus = cpu_map__get(cpus);
>         }
>
>         if (threads != evlist->threads) {
>                 thread_map__put(evlist->threads);
> -               evlist->threads = threads;
> +               evlist->threads = thread_map__get(threads);
>         }
>
>         perf_evlist__propagate_maps(evlist);

^ permalink raw reply	[flat|nested] 5+ messages in thread

* Re: perf object code reading test crashes
  2016-02-18  1:13   ` Steven Noonan
@ 2016-02-18 14:27     ` Arnaldo Carvalho de Melo
  2016-02-18 14:36       ` Arnaldo Carvalho de Melo
  0 siblings, 1 reply; 5+ messages in thread
From: Arnaldo Carvalho de Melo @ 2016-02-18 14:27 UTC (permalink / raw)
  To: Steven Noonan; +Cc: Linux Kernel mailing List, Adrian Hunter

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@uplinklabs.net>

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,
 		},

^ permalink raw reply related	[flat|nested] 5+ messages in thread

* Re: perf object code reading test crashes
  2016-02-18 14:27     ` Arnaldo Carvalho de Melo
@ 2016-02-18 14:36       ` Arnaldo Carvalho de Melo
  0 siblings, 0 replies; 5+ messages in thread
From: Arnaldo Carvalho de Melo @ 2016-02-18 14:36 UTC (permalink / raw)
  To: Steven Noonan; +Cc: Linux Kernel mailing List, Adrian Hunter

Em Thu, Feb 18, 2016 at 11:27:27AM -0300, Arnaldo Carvalho de Melo escreveu:
> 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:

Ok, so this test actually process samples, so please just replace that
with a lower freq, say 10.

> 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,
>  		},

^ permalink raw reply	[flat|nested] 5+ messages in thread

end of thread, other threads:[~2016-02-18 14:36 UTC | newest]

Thread overview: 5+ messages (download: mbox.gz follow: Atom feed
-- links below jump to the message on this page --
2016-02-17  6:42 perf object code reading test crashes Steven Noonan
2016-02-17 14:27 ` Arnaldo Carvalho de Melo
2016-02-18  1:13   ` Steven Noonan
2016-02-18 14:27     ` Arnaldo Carvalho de Melo
2016-02-18 14:36       ` Arnaldo Carvalho de Melo

This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox;
as well as URLs for NNTP newsgroup(s).