| Message ID | 712b7c31-f681-7737-71e7-c028b8d2bba5@huawei.com (mailing list archive) |
|---|---|
| State | New, archived |
| Headers | show |
| Series | perf segmentation fault from NULL dereference | expand |
> Please me let me know if a valid issue so we can get a fix in.
If it crashes it must be a valid issue of course.
But I'm not sure about your bisect. Hard to see how my patch
could cause this. Sometimes bisects go wrong.
You verified by just reverting the patch?
First thing I would also try is to run with valgrind or ASan and see if it
reports anything.
-Andi
On Tue, Sep 25, 2018 at 04:53:40PM +0100, John Garry wrote: > Hi, > > I am seeing this perf crash on my arm64-based system: > > root@localhost:~# ./perf_debug_ record -e armv8_pmuv3_0/br_mis_pred/ sleep 1 > perf: Segmentation fault > Obtained 9 stack frames. > ./perf_debug_() [0x4c5ef8] > [0xffff82ba267c] > ./perf_debug_() [0x4bc5a8] > ./perf_debug_() [0x419550] > ./perf_debug_() [0x41a928] > ./perf_debug_() [0x472f58] > ./perf_debug_() [0x473210] > ./perf_debug_() [0x4070f4] > /lib/aarch64-linux-gnu/libc.so.6(__libc_start_main+0xe0) [0xffff8294c8a0] > Segmentation fault (core dumped) > > I find 'cycles' event is fine. > > I bisected the issue to here: > commit bfd8f72c2778f5bd63dc9eb6d23bd7a0d99cff6d (HEAD, refs/bisect/bad) > Author: Andi Kleen <ak@linux.intel.com> > Date: Fri Nov 17 13:42:58 2017 -0800 > > perf record: Synthesize unit/scale/... in event update > > Move the code to synthesize event updates for scale/unit/cpus to a > common utility file, and use it both from stat and record. > > This allows to access scale and other extra qualifiers from perf script. > > Signed-off-by: Andi Kleen <ak@linux.intel.com> > Acked-by: Jiri Olsa <jolsa@kernel.org> > Link: > http://lkml.kernel.org/r/20171117214300.32746-2-andi@firstfloor.org > Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com> > > I am suspicious that this is a real issue, as this patch has been in > mainline for some time... > > This simple change fixes the issue me: > diff --git a/tools/perf/util/header.c b/tools/perf/util/header.c > index 91e6d9c..f4fd826 100644 > --- a/tools/perf/util/header.c > +++ b/tools/perf/util/header.c > @@ -3576,7 +3576,7 @@ int perf_event__process_feature(struct perf_tool > *tool, > int max, err; > u16 type; > > - if (!evsel->own_cpus) > + if (!evsel->own_cpus || !(evsel->attr.read_format & PERF_FORMAT_ID)) // > roundabout check for !evsel->id > return 0; > > ev = cpu_map_data__alloc(evsel->own_cpus, &size, &type, &max); > > It turns out that evsel->id is NULL on a call to > perf_event__process_feature(), which upsets this code: > > ev->header.type = PERF_RECORD_EVENT_UPDATE; > ev->header.size = (u16)size; > ev->type = PERF_EVENT_UPDATE__CPUS; > ev->id = evsel->id[0]; > > Please me let me know if a valid issue so we can get a fix in. yea, I can see how we can get here with event having its own CPUs, and we allocate the id array later at the time we map the event I wonder instead of skipping on this feature, we should allocate the id array, like below I did not test that.. need to find the server having event with its own cpus.. also need to make sure evsel->cpus is the way to go in here thanks, jirka --- diff --git a/tools/perf/util/header.c b/tools/perf/util/header.c index 1ec1d9bc2d63..fb2a0dab3978 100644 --- a/tools/perf/util/header.c +++ b/tools/perf/util/header.c @@ -29,6 +29,7 @@ #include "symbol.h" #include "debug.h" #include "cpumap.h" +#include "thread_map.h" #include "pmu.h" #include "vdso.h" #include "strbuf.h" @@ -3579,6 +3580,11 @@ perf_event__synthesize_event_update_cpus(struct perf_tool *tool, if (!evsel->own_cpus) return 0; + if (!evsel->id || + perf_evsel__alloc_id(evsel, cpu_map__nr(evsel->cpus), + thread_map__nr(evsel->threads))) + return -ENOMEM; + ev = cpu_map_data__alloc(evsel->own_cpus, &size, &type, &max); if (!ev) return -ENOMEM;
On 27/09/2018 04:00, Andi Kleen wrote: >> Please me let me know if a valid issue so we can get a fix in. > > If it crashes it must be a valid issue of course. > > But I'm not sure about your bisect. Hard to see how my patch > could cause this. Sometimes bisects go wrong. > You verified by just reverting the patch? It no longer reverts cleanly. And the previous patch - 4ca69ca9db3a - did not have this crash: root@localhost:~# ./perf_debug_ record -e armv8_pmuv3_0/br_mis_pred/ sleep 1 [ perf record: Woken up 1 times to write data ] [ perf record: Captured and wrote 0.001 MB perf.data (6 samples) ] root@localhost:~# > > First thing I would also try is to run with valgrind or ASan and see if it > reports anything. Here's the valgrind output: root@localhost:~#valgrind --leak-check=yes ./perf_debug_ record -e armv8_pmuv3_0/br_mis_pred/ sleep 1 ==16025== Memcheck, a memory error detector ==16025== Copyright (C) 2002-2015, and GNU GPL'd, by Julian Seward et al. ==16025== Using Valgrind-3.11.0 and LibVEX; rerun with -h for copyright info ==16025== Command: ./perf_debug_ record -e armv8_pmuv3_0/br_mis_pred/ sleep 1 ==16025== --16025-- WARNING: unhandled arm64-linux syscall: 168 --16025-- You may be able to write your own handler. --16025-- Read the file README_MISSING_SYSCALL_OR_IOCTL. --16025-- Nevertheless we consider this a bug. Please report --16025-- it at http://valgrind.org/support/bug_reports.html. --16025-- WARNING: unhandled arm64-linux syscall: 241 --16025-- You may be able to write your own handler. --16025-- Read the file README_MISSING_SYSCALL_OR_IOCTL. --16025-- Nevertheless we consider this a bug. Please report --16025-- it at http://valgrind.org/support/bug_reports.html. perf_event_open(..., PERF_FLAG_FD_CLOEXEC) failed with unexpected error 38 (Function not implemented) --16025-- WARNING: unhandled arm64-linux syscall: 241 --16025-- You may be able to write your own handler. --16025-- Read the file README_MISSING_SYSCALL_OR_IOCTL. --16025-- Nevertheless we consider this a bug. Please report --16025-- it at http://valgrind.org/support/bug_reports.html. perf_event_open(..., 0) failed unexpectedly with error 38 (Function not implemented) --16025-- WARNING: unhandled arm64-linux syscall: 241 --16025-- You may be able to write your own handler. --16025-- Read the file README_MISSING_SYSCALL_OR_IOCTL. --16025-- Nevertheless we consider this a bug. Please report --16025-- it at http://valgrind.org/support/bug_reports.html. --16025-- WARNING: unhandled arm64-linux syscall: 241 --16025-- You may be able to write your own handler. --16025-- Read the file README_MISSING_SYSCALL_OR_IOCTL. --16025-- Nevertheless we consider this a bug. Please report --16025-- it at http://valgrind.org/support/bug_reports.html. --16025-- WARNING: unhandled arm64-linux syscall: 241 --16025-- You may be able to write your own handler. --16025-- Read the file README_MISSING_SYSCALL_OR_IOCTL. --16025-- Nevertheless we consider this a bug. Please report --16025-- it at http://valgrind.org/support/bug_reports.html. --16025-- WARNING: unhandled arm64-linux syscall: 241 --16025-- You may be able to write your own handler. --16025-- Read the file README_MISSING_SYSCALL_OR_IOCTL. --16025-- Nevertheless we consider this a bug. Please report --16025-- it at http://valgrind.org/support/bug_reports.html. Error: The sys_perf_event_open() syscall returned with 38 (Function not implemented) for event (armv8_pmuv3_0/br_mis_pred/). /bin/dmesg | grep -i perf may provide additional information. ==16059== ==16059== Process terminating with default action of signal 15 (SIGTERM) ==16059== at 0x486F974: __read_nocancel (syscall-template.S:84) ==16059== by 0x48D02F: read (unistd.h:44) ==16059== by 0x48D02F: perf_evlist__prepare_workload (evlist.c:1471) ==16059== by 0x41AB0F: __cmd_record (builtin-record.c:898) ==16059== by 0x41AB0F: cmd_record (builtin-record.c:1873) ==16059== by 0x476C7F: run_builtin (perf.c:302) ==16059== by 0x476F37: handle_internal_command (perf.c:354) ==16059== by 0x407093: run_argv (perf.c:398) ==16059== by 0x407093: main (perf.c:520) ==16059== ==16059== HEAP SUMMARY: ==16059== in use at exit: 56,239 bytes in 226 blocks ==16059== total heap usage: 1,164 allocs, 938 frees, 2,238,979 bytes allocated ==16059== ==16059== 12 bytes in 1 blocks are definitely lost in loss record 1 of 6 ==16059== at 0x4844B88: malloc (in /usr/lib/valgrind/vgpreload_memcheck-arm64-linux.so) ==16059== ==16059== 344 bytes in 5 blocks are possibly lost in loss record 3 of 6 ==16059== at 0x4846CFC: calloc (in /usr/lib/valgrind/vgpreload_memcheck-arm64-linux.so) ==16059== ==16059== 5,736 bytes in 125 blocks are possibly lost in loss record 4 of 6 ==16059== at 0x4844B88: malloc (in /usr/lib/valgrind/vgpreload_memcheck-arm64-linux.so) ==16059== ==16059== LEAK SUMMARY: ==16059== definitely lost: 12 bytes in 1 blocks ==16059== indirectly lost: 0 bytes in 0 blocks ==16059== possibly lost: 6,080 bytes in 130 blocks ==16059== still reachable: 50,147 bytes in 95 blocks ==16059== suppressed: 0 bytes in 0 blocks ==16059== Reachable blocks (those to which a pointer was found) are not shown. ==16059== To see them, rerun with: --leak-check=full --show-leak-kinds=all ==16059== ==16059== For counts of detected and suppressed errors, rerun with: -v ==16059== ERROR SUMMARY: 3 errors from 3 contexts (suppressed: 0 from 0) ==16025== Warning: invalid file descriptor -1 in syscall close() ==16025== Warning: invalid file descriptor -1 in syscall close() ==16025== Warning: invalid file descriptor -1 in syscall close() ==16025== Warning: invalid file descriptor -1 in syscall close() ==16025== Warning: invalid file descriptor -1 in syscall close() ==16025== Warning: invalid file descriptor -1 in syscall close() ==16025== Warning: invalid file descriptor -1 in syscall close() ==16025== Warning: invalid file descriptor -1 in syscall close() ==16025== Warning: invalid file descriptor -1 in syscall close() ==16025== Warning: invalid file descriptor -1 in syscall close() ==16025== Warning: invalid file descriptor -1 in syscall close() ==16025== Warning: invalid file descriptor -1 in syscall close() ==16025== Warning: invalid file descriptor -1 in syscall close() ==16025== Warning: invalid file descriptor -1 in syscall close() ==16025== Warning: invalid file descriptor -1 in syscall close() ==16025== Warning: invalid file descriptor -1 in syscall close() ==16025== Warning: invalid file descriptor -1 in syscall close() ==16025== Warning: invalid file descriptor -1 in syscall close() ==16025== Warning: invalid file descriptor -1 in syscall close() ==16025== Warning: invalid file descriptor -1 in syscall close() ==16025== Warning: invalid file descriptor -1 in syscall close() ==16025== Warning: invalid file descriptor -1 in syscall close() ==16025== Warning: invalid file descriptor -1 in syscall close() ==16025== Warning: invalid file descriptor -1 in syscall close() ==16025== Warning: invalid file descriptor -1 in syscall close() ==16025== Warning: invalid file descriptor -1 in syscall close() ==16025== Warning: invalid file descriptor -1 in syscall close() ==16025== Warning: invalid file descriptor -1 in syscall close() ==16025== Warning: invalid file descriptor -1 in syscall close() ==16025== Warning: invalid file descriptor -1 in syscall close() ==16025== Warning: invalid file descriptor -1 in syscall close() ==16025== Warning: invalid file descriptor -1 in syscall close() ==16025== Warning: invalid file descriptor -1 in syscall close() ==16025== Warning: invalid file descriptor -1 in syscall close() ==16025== Warning: invalid file descriptor -1 in syscall close() ==16025== Warning: invalid file descriptor -1 in syscall close() ==16025== Warning: invalid file descriptor -1 in syscall close() ==16025== Warning: invalid file descriptor -1 in syscall close() ==16025== Warning: invalid file descriptor -1 in syscall close() ==16025== Warning: invalid file descriptor -1 in syscall close() ==16025== Warning: invalid file descriptor -1 in syscall close() ==16025== Warning: invalid file descriptor -1 in syscall close() ==16025== Warning: invalid file descriptor -1 in syscall close() ==16025== Warning: invalid file descriptor -1 in syscall close() ==16025== Warning: invalid file descriptor -1 in syscall close() ==16025== Warning: invalid file descriptor -1 in syscall close() ==16025== Warning: invalid file descriptor -1 in syscall close() ==16025== Warning: invalid file descriptor -1 in syscall close() ==16025== Warning: invalid file descriptor -1 in syscall close() ==16025== Warning: invalid file descriptor -1 in syscall close() ==16025== Warning: invalid file descriptor -1 in syscall close() ==16025== Warning: invalid file descriptor -1 in syscall close() ==16025== Warning: invalid file descriptor -1 in syscall close() ==16025== Warning: invalid file descriptor -1 in syscall close() ==16025== Warning: invalid file descriptor -1 in syscall close() ==16025== Warning: invalid file descriptor -1 in syscall close() ==16025== Warning: invalid file descriptor -1 in syscall close() ==16025== Warning: invalid file descriptor -1 in syscall close() ==16025== Warning: invalid file descriptor -1 in syscall close() ==16025== Warning: invalid file descriptor -1 in syscall close() ==16025== Warning: invalid file descriptor -1 in syscall close() ==16025== Warning: invalid file descriptor -1 in syscall close() ==16025== Warning: invalid file descriptor -1 in syscall close() ==16025== Warning: invalid file descriptor -1 in syscall close() ==16025== ==16025== HEAP SUMMARY: ==16025== in use at exit: 26,640 bytes in 209 blocks ==16025== total heap usage: 1,202 allocs, 993 frees, 2,455,112 bytes allocated ==16025== ==16025== 328 bytes in 7 blocks are definitely lost in loss record 2 of 6 ==16025== at 0x4844B88: malloc (in /usr/lib/valgrind/vgpreload_memcheck-arm64-linux.so) ==16025== ==16025== 344 bytes in 5 blocks are possibly lost in loss record 3 of 6 ==16025== at 0x4846CFC: calloc (in /usr/lib/valgrind/vgpreload_memcheck-arm64-linux.so) ==16025== ==16025== 6,000 bytes in 126 blocks are possibly lost in loss record 5 of 6 ==16025== at 0x4844B88: malloc (in /usr/lib/valgrind/vgpreload_memcheck-arm64-linux.so) ==16025== ==16025== LEAK SUMMARY: ==16025== definitely lost: 328 bytes in 7 blocks ==16025== indirectly lost: 0 bytes in 0 blocks ==16025== possibly lost: 6,344 bytes in 131 blocks ==16025== still reachable: 19,968 bytes in 71 blocks ==16025== suppressed: 0 bytes in 0 blocks ==16025== Reachable blocks (those to which a pointer was found) are not shown. ==16025== To see them, rerun with: --leak-check=full --show-leak-kinds=all ==16025== ==16025== For counts of detected and suppressed errors, rerun with: -v ==16025== ERROR SUMMARY: 3 errors from 3 contexts (suppressed: 0 from 0) root@localhost:~# (pretty much the same as previous patch) Cheers, John > > -Andi > > . >
>> I am suspicious that this is a real issue, as this patch has been in >> mainline for some time... >> >> This simple change fixes the issue me: >> diff --git a/tools/perf/util/header.c b/tools/perf/util/header.c >> index 91e6d9c..f4fd826 100644 >> --- a/tools/perf/util/header.c >> +++ b/tools/perf/util/header.c >> @@ -3576,7 +3576,7 @@ int perf_event__process_feature(struct perf_tool >> *tool, >> int max, err; >> u16 type; >> >> - if (!evsel->own_cpus) >> + if (!evsel->own_cpus || !(evsel->attr.read_format & PERF_FORMAT_ID)) // >> roundabout check for !evsel->id >> return 0; >> >> ev = cpu_map_data__alloc(evsel->own_cpus, &size, &type, &max); >> >> It turns out that evsel->id is NULL on a call to >> perf_event__process_feature(), which upsets this code: >> >> ev->header.type = PERF_RECORD_EVENT_UPDATE; >> ev->header.size = (u16)size; >> ev->type = PERF_EVENT_UPDATE__CPUS; >> ev->id = evsel->id[0]; >> >> Please me let me know if a valid issue so we can get a fix in. > > yea, I can see how we can get here with event having > its own CPUs, and we allocate the id array later at > the time we map the event > > I wonder instead of skipping on this feature, we should > allocate the id array, like below > > I did not test that.. need to find the server having event > with its own cpus.. also need to make sure evsel->cpus is > the way to go in here > Thanks for the fix, but I got this: root@localhost:~# ./perf_debug_ record -e armv8_pmuv3_0/br_mis_pred/ sleep 1 Couldn't synthesize evsel cpus. root@localhost:~# > thanks, > jirka > > > --- > diff --git a/tools/perf/util/header.c b/tools/perf/util/header.c > index 1ec1d9bc2d63..fb2a0dab3978 100644 > --- a/tools/perf/util/header.c > +++ b/tools/perf/util/header.c > @@ -29,6 +29,7 @@ > #include "symbol.h" > #include "debug.h" > #include "cpumap.h" > +#include "thread_map.h" > #include "pmu.h" > #include "vdso.h" > #include "strbuf.h" > @@ -3579,6 +3580,11 @@ perf_event__synthesize_event_update_cpus(struct perf_tool *tool, > if (!evsel->own_cpus) > return 0; > > + if (!evsel->id || for my test, evsel->id is NULL > + perf_evsel__alloc_id(evsel, cpu_map__nr(evsel->cpus), > + thread_map__nr(evsel->threads))) and then this function is not called as we return immediately. So did you really want this: if (!evsel->id && perf_evsel__alloc_id(...)) return -ENOMEM; This looks to work: root@localhost:~# ./perf_debug_ record -e armv8_pmuv3_0/br_mis_pred/ sleep 1 [ perf record: Woken up 1 times to write data ] [ perf record: Captured and wrote 0.001 MB perf.data (7 samples) ] root@localhost:~# ./perf_debug_ report # To display the perf.data header info, please use --header/--header-only option # # # Total Lost Samples: 0 # # Samples: 7 of event 'armv8_pmuv3_0/br_mis_pred/' # Event count (approx.): 8260 # # Overhead Command Shared Object Symbol # ........ ....... ................. ...................... # 78.28% sleep libc-2.23.so [.] 0x00000000000faef0 20.53% sleep [kernel.kallsyms] [k] vmacache_find 1.09% sleep [kernel.kallsyms] [k] find_vma 0.10% perf_de [kernel.kallsyms] [k] perf_event_exec # # (Cannot load tips.txt file, please install perf!) # root@localhost:~# > + return -ENOMEM; > + > ev = cpu_map_data__alloc(evsel->own_cpus, &size, &type, &max); > if (!ev) > return -ENOMEM; > > . > Thanks, John
On Tue, Oct 02, 2018 at 11:41:36AM +0100, John Garry wrote: SNIP > > > > > > --- > > diff --git a/tools/perf/util/header.c b/tools/perf/util/header.c > > index 1ec1d9bc2d63..fb2a0dab3978 100644 > > --- a/tools/perf/util/header.c > > +++ b/tools/perf/util/header.c > > @@ -29,6 +29,7 @@ > > #include "symbol.h" > > #include "debug.h" > > #include "cpumap.h" > > +#include "thread_map.h" > > #include "pmu.h" > > #include "vdso.h" > > #include "strbuf.h" > > @@ -3579,6 +3580,11 @@ perf_event__synthesize_event_update_cpus(struct perf_tool *tool, > > if (!evsel->own_cpus) > > return 0; > > > > + if (!evsel->id || > > for my test, evsel->id is NULL > > > + perf_evsel__alloc_id(evsel, cpu_map__nr(evsel->cpus), > > + thread_map__nr(evsel->threads))) > > and then this function is not called as we return immediately. So did you > really want this: > > if (!evsel->id && perf_evsel__alloc_id(...)) > return -ENOMEM; ugh.. yes ;-) thanks for the fix.. I'll double check the logic and post the patch this week jirka > > This looks to work: > > root@localhost:~# ./perf_debug_ record -e armv8_pmuv3_0/br_mis_pred/ sleep 1 > [ perf record: Woken up 1 times to write data ] > [ perf record: Captured and wrote 0.001 MB perf.data (7 samples) ] > root@localhost:~# ./perf_debug_ report > # To display the perf.data header info, please use --header/--header-only > option > # > # > # Total Lost Samples: 0 > # > # Samples: 7 of event 'armv8_pmuv3_0/br_mis_pred/' > # Event count (approx.): 8260 > # > # Overhead Command Shared Object Symbol > # ........ ....... ................. ...................... > # > 78.28% sleep libc-2.23.so [.] 0x00000000000faef0 > 20.53% sleep [kernel.kallsyms] [k] vmacache_find > 1.09% sleep [kernel.kallsyms] [k] find_vma > 0.10% perf_de [kernel.kallsyms] [k] perf_event_exec > > > # > # (Cannot load tips.txt file, please install perf!) > # > root@localhost:~# > > > > + return -ENOMEM; > > + > > ev = cpu_map_data__alloc(evsel->own_cpus, &size, &type, &max); > > if (!ev) > > return -ENOMEM; > > > > . > > > > > Thanks, > John >
diff --git a/tools/perf/util/header.c b/tools/perf/util/header.c index 91e6d9c..f4fd826 100644 --- a/tools/perf/util/header.c +++ b/tools/perf/util/header.c @@ -3576,7 +3576,7 @@ int perf_event__process_feature(struct perf_tool *tool, int max, err; u16 type; - if (!evsel->own_cpus) + if (!evsel->own_cpus || !(evsel->attr.read_format & PERF_FORMAT_ID)) // roundabout check for !evsel->id return 0;
Hi, I am seeing this perf crash on my arm64-based system: root@localhost:~# ./perf_debug_ record -e armv8_pmuv3_0/br_mis_pred/ sleep 1 perf: Segmentation fault Obtained 9 stack frames. ./perf_debug_() [0x4c5ef8] [0xffff82ba267c] ./perf_debug_() [0x4bc5a8] ./perf_debug_() [0x419550] ./perf_debug_() [0x41a928] ./perf_debug_() [0x472f58] ./perf_debug_() [0x473210] ./perf_debug_() [0x4070f4] /lib/aarch64-linux-gnu/libc.so.6(__libc_start_main+0xe0) [0xffff8294c8a0] Segmentation fault (core dumped) I find 'cycles' event is fine. I bisected the issue to here: commit bfd8f72c2778f5bd63dc9eb6d23bd7a0d99cff6d (HEAD, refs/bisect/bad) Author: Andi Kleen <ak@linux.intel.com> Date: Fri Nov 17 13:42:58 2017 -0800 perf record: Synthesize unit/scale/... in event update Move the code to synthesize event updates for scale/unit/cpus to a common utility file, and use it both from stat and record. This allows to access scale and other extra qualifiers from perf script. Signed-off-by: Andi Kleen <ak@linux.intel.com> Acked-by: Jiri Olsa <jolsa@kernel.org> Link: http://lkml.kernel.org/r/20171117214300.32746-2-andi@firstfloor.org Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com> I am suspicious that this is a real issue, as this patch has been in mainline for some time... This simple change fixes the issue me: ev = cpu_map_data__alloc(evsel->own_cpus, &size, &type, &max); It turns out that evsel->id is NULL on a call to perf_event__process_feature(), which upsets this code: ev->header.type = PERF_RECORD_EVENT_UPDATE; ev->header.size = (u16)size; ev->type = PERF_EVENT_UPDATE__CPUS; ev->id = evsel->id[0]; Please me let me know if a valid issue so we can get a fix in. Apologies for crying wolf if I'm off the mark. Cheers, John