Depending on memory allocations, it was possible to get a SEGFAULT in
free_dup_event() because the event pointer was bogus:
perf[1354]: segfault at ffffffff00000006 ip 00000000004b7fc7
Initially, I thought it was some double free. But it turns out
it looked more like a buffer overrun. Adding padding before
the union perf_event field in struct ordered_event avoided the
problem. But it was not obvious where this could be coming from
given the accesses to the struct, i.e., no internal array.
Then, it struck me that the following was bogus in __dup_event():
__dup_event(struct ordered_events *oe, union perf_event *event)
{
...
union perf_event *new_event;
new_event = memdup(event, event->header.size);
...
}
The problem here is that header.size <= sizeof(*new_event). The code
was trying to copy only what was necessary, but then, the allocation
was also only partial. In other words if the event was not the largest
possible for the union, it would not be fully backed by memory, likely
causing troubles.
This patch fixes the problem by passing the size of the union and not
that of the actual event.
Signed-off-by: Stephane Eranian <[email protected]>
---
tools/perf/util/ordered-events.c | 4 ++--
1 file changed, 2 insertions(+), 2 deletions(-)
diff --git a/tools/perf/util/ordered-events.c b/tools/perf/util/ordered-events.c
index bad9e0296e9a..a90dbe5df019 100644
--- a/tools/perf/util/ordered-events.c
+++ b/tools/perf/util/ordered-events.c
@@ -66,9 +66,9 @@ static union perf_event *__dup_event(struct ordered_events *oe,
union perf_event *new_event = NULL;
if (oe->cur_alloc_size < oe->max_alloc_size) {
- new_event = memdup(event, event->header.size);
+ new_event = memdup(event, sizeof(*event));
if (new_event)
- oe->cur_alloc_size += event->header.size;
+ oe->cur_alloc_size += sizeof(*event);
}
return new_event;
--
2.18.0.597.ga71716f1ad-goog
On Mon, Aug 06, 2018 at 06:23:35PM -0700, Stephane Eranian wrote:
> Depending on memory allocations, it was possible to get a SEGFAULT in
> free_dup_event() because the event pointer was bogus:
>
> perf[1354]: segfault at ffffffff00000006 ip 00000000004b7fc7
is there any reproducer?
>
> Initially, I thought it was some double free. But it turns out
> it looked more like a buffer overrun. Adding padding before
> the union perf_event field in struct ordered_event avoided the
> problem. But it was not obvious where this could be coming from
> given the accesses to the struct, i.e., no internal array.
>
> Then, it struck me that the following was bogus in __dup_event():
>
> __dup_event(struct ordered_events *oe, union perf_event *event)
> {
> ...
> union perf_event *new_event;
> new_event = memdup(event, event->header.size);
> ...
> }
>
> The problem here is that header.size <= sizeof(*new_event). The code
> was trying to copy only what was necessary, but then, the allocation
hum, and I think we should continue to do so.. we can't allocate ~4000
bytes space for 30 bytes sample
> was also only partial. In other words if the event was not the largest
> possible for the union, it would not be fully backed by memory, likely
> causing troubles.
how? using that event allocated space for another type of event?
>
> This patch fixes the problem by passing the size of the union and not
> that of the actual event.
I think that's just bypassing the real issue, please share more details
on how to reproduce this
thanks,
jirka
>
> Signed-off-by: Stephane Eranian <[email protected]>
>
> ---
> tools/perf/util/ordered-events.c | 4 ++--
> 1 file changed, 2 insertions(+), 2 deletions(-)
>
> diff --git a/tools/perf/util/ordered-events.c b/tools/perf/util/ordered-events.c
> index bad9e0296e9a..a90dbe5df019 100644
> --- a/tools/perf/util/ordered-events.c
> +++ b/tools/perf/util/ordered-events.c
> @@ -66,9 +66,9 @@ static union perf_event *__dup_event(struct ordered_events *oe,
> union perf_event *new_event = NULL;
>
> if (oe->cur_alloc_size < oe->max_alloc_size) {
> - new_event = memdup(event, event->header.size);
> + new_event = memdup(event, sizeof(*event));
> if (new_event)
> - oe->cur_alloc_size += event->header.size;
> + oe->cur_alloc_size += sizeof(*event);
> }
>
> return new_event;
> --
> 2.18.0.597.ga71716f1ad-goog
>
On Tue, Aug 7, 2018 at 12:20 AM Jiri Olsa <[email protected]> wrote:
>
> On Mon, Aug 06, 2018 at 06:23:35PM -0700, Stephane Eranian wrote:
> > Depending on memory allocations, it was possible to get a SEGFAULT in
> > free_dup_event() because the event pointer was bogus:
> >
> > perf[1354]: segfault at ffffffff00000006 ip 00000000004b7fc7
>
> is there any reproducer?
>
The cmdline is simple:
$ perf record -e cycles:pp -o - -a sleep 1 | perf inject -b -i - >/dev/null
I was using v4.13 for my tests and it may be sensitive to compiler.
Was using LLVM.
It may be a compiler related issue. You do not allocate the whole struct.
If the compiler was to do a memcpy() behind your back, you'd be in
troubles.
Adding extra padding before *event was also avoiding the problem.
struct ordered_event {
u64 timestamp;
u64 file_offset;
char pad[32]; <----- extra padding for debugging
union perf_event *event;
struct list_head list;
};
> >
> > Initially, I thought it was some double free. But it turns out
> > it looked more like a buffer overrun. Adding padding before
> > the union perf_event field in struct ordered_event avoided the
> > problem. But it was not obvious where this could be coming from
> > given the accesses to the struct, i.e., no internal array.
> >
> > Then, it struck me that the following was bogus in __dup_event():
> >
> > __dup_event(struct ordered_events *oe, union perf_event *event)
> > {
> > ...
> > union perf_event *new_event;
> > new_event = memdup(event, event->header.size);
> > ...
> > }
> >
> > The problem here is that header.size <= sizeof(*new_event). The code
> > was trying to copy only what was necessary, but then, the allocation
>
> hum, and I think we should continue to do so.. we can't allocate ~4000
> bytes space for 30 bytes sample
>
I understand that but it seems the event field gets overwritten under some
conditions.
> > was also only partial. In other words if the event was not the largest
> > possible for the union, it would not be fully backed by memory, likely
> > causing troubles.
>
> how? using that event allocated space for another type of event?
>
> >
> > This patch fixes the problem by passing the size of the union and not
> > that of the actual event.
>
> I think that's just bypassing the real issue, please share more details
> on how to reproduce this
>
> thanks,
> jirka
>
> >
> > Signed-off-by: Stephane Eranian <[email protected]>
> >
> > ---
> > tools/perf/util/ordered-events.c | 4 ++--
> > 1 file changed, 2 insertions(+), 2 deletions(-)
> >
> > diff --git a/tools/perf/util/ordered-events.c b/tools/perf/util/ordered-events.c
> > index bad9e0296e9a..a90dbe5df019 100644
> > --- a/tools/perf/util/ordered-events.c
> > +++ b/tools/perf/util/ordered-events.c
> > @@ -66,9 +66,9 @@ static union perf_event *__dup_event(struct ordered_events *oe,
> > union perf_event *new_event = NULL;
> >
> > if (oe->cur_alloc_size < oe->max_alloc_size) {
> > - new_event = memdup(event, event->header.size);
> > + new_event = memdup(event, sizeof(*event));
> > if (new_event)
> > - oe->cur_alloc_size += event->header.size;
> > + oe->cur_alloc_size += sizeof(*event);
> > }
> >
> > return new_event;
> > --
> > 2.18.0.597.ga71716f1ad-goog
> >
On Tue, Aug 07, 2018 at 01:16:22AM -0700, Stephane Eranian wrote:
> On Tue, Aug 7, 2018 at 12:20 AM Jiri Olsa <[email protected]> wrote:
> >
> > On Mon, Aug 06, 2018 at 06:23:35PM -0700, Stephane Eranian wrote:
> > > Depending on memory allocations, it was possible to get a SEGFAULT in
> > > free_dup_event() because the event pointer was bogus:
> > >
> > > perf[1354]: segfault at ffffffff00000006 ip 00000000004b7fc7
> >
> > is there any reproducer?
> >
> The cmdline is simple:
> $ perf record -e cycles:pp -o - -a sleep 1 | perf inject -b -i - >/dev/null
> I was using v4.13 for my tests and it may be sensitive to compiler.
> Was using LLVM.
I can't make it fail even when I compile with clang 'make CC=clang'
[jolsa@krava perf]$ clang --version
clang version 6.0.1 (tags/RELEASE_601/final)
I'm on v4.17, but I dont think kernel version is related to this issue
>
> It may be a compiler related issue. You do not allocate the whole struct.
> If the compiler was to do a memcpy() behind your back, you'd be in
> troubles.
>
> Adding extra padding before *event was also avoiding the problem.
> struct ordered_event {
> u64 timestamp;
> u64 file_offset;
> char pad[32]; <----- extra padding for debugging
> union perf_event *event;
> struct list_head list;
> };
might be some issue in the struct ordered_event allocation,
which is little convoluted
jirka
Jiri,
On Tue, Aug 7, 2018 at 1:50 AM Jiri Olsa <[email protected]> wrote:
>
> On Tue, Aug 07, 2018 at 01:16:22AM -0700, Stephane Eranian wrote:
> > On Tue, Aug 7, 2018 at 12:20 AM Jiri Olsa <[email protected]> wrote:
> > >
> > > On Mon, Aug 06, 2018 at 06:23:35PM -0700, Stephane Eranian wrote:
> > > > Depending on memory allocations, it was possible to get a SEGFAULT in
> > > > free_dup_event() because the event pointer was bogus:
> > > >
> > > > perf[1354]: segfault at ffffffff00000006 ip 00000000004b7fc7
> > >
> > > is there any reproducer?
> > >
> > The cmdline is simple:
> > $ perf record -e cycles:pp -o - -a sleep 1 | perf inject -b -i - >/dev/null
> > I was using v4.13 for my tests and it may be sensitive to compiler.
> > Was using LLVM.
>
> I can't make it fail even when I compile with clang 'make CC=clang'
>
I checked, my actual reproducer is:
$ perf record -o - -e cycles date | perf inject -b -i - >/dev/null
Tue Aug 7 12:03:48 PDT 2018
[ perf record: Woken up 1 times to write data ]
[ perf record: Captured and wrote 0.000 MB - ]
Segmentation fault (core dumped)
the crash is in perf inject.
So if I do:
$ perf record -o - -e cycles date >tt
$ gdb perf
(gdb) r inject -b -i - < tt >/dev/null
Program received signal SIGSEGV, Segmentation fault.
free_dup_event (oe=0x26a39a0, event=0xffffffff00000000) at
util/ordered-events.c:85
85 in util/ordered-events.c
(gdb) bt
#0 free_dup_event (oe=0x26a39a0, event=0xffffffff00000000) at
util/ordered-events.c:85
#1 ordered_events__free (oe=0x26a39a0) at util/ordered-events.c:310
#2 0x00000000004b5a56 in __perf_session__process_pipe_events
(session=<optimized out>) at util/session.c:1753
#3 perf_session__process_events (session=<optimized out>) at
util/session.c:1932
#4 0x000000000043a2eb in __cmd_inject (inject=<optimized out>) at
builtin-inject.c:750
#5 cmd_inject (argc=<optimized out>, argv=<optimized out>) at
builtin-inject.c:924
#6 0x000000000046b175 in run_builtin (p=0xabc640 <commands+576>,
argc=4, argv=0x7fffffffe560) at perf.c:297
#7 0x000000000046b062 in handle_internal_command (argc=4,
argv=0x7fffffffe560) at perf.c:349
#8 0x000000000046a5e8 in run_argv (argcp=<optimized out>,
argv=<optimized out>) at perf.c:393
#9 main (argc=4, argv=0x7fffffffe560) at perf.c:531
Again, this is with an older version of perf compiled with LLVM.
Notice the value of event passed to free_dup_event(): 0xffffffff00000000
And yes, I checked sizeof(union_perf_event) = 4168 which is the size of
the mmap2_event which is the largest.
I also checked that you are freeing what you have actually allocated.
No double free.
If I add the padding or modifies the call to memdup() as in the patch,
then the problem
goes away.
If you don't want to copy 4Kb each time, then you could also make the
event field
by a void *event and case whenever needed.
I suspect the problem may come from a compiler optimization or assumption which
clashes with what you are optimizing here.
> [jolsa@krava perf]$ clang --version
> clang version 6.0.1 (tags/RELEASE_601/final)
>
> I'm on v4.17, but I dont think kernel version is related to this issue
>
> >
> > It may be a compiler related issue. You do not allocate the whole struct.
> > If the compiler was to do a memcpy() behind your back, you'd be in
> > troubles.
> >
> > Adding extra padding before *event was also avoiding the problem.
> > struct ordered_event {
> > u64 timestamp;
> > u64 file_offset;
> > char pad[32]; <----- extra padding for debugging
> > union perf_event *event;
> > struct list_head list;
> > };
>
> might be some issue in the struct ordered_event allocation,
> which is little convoluted
>
> jirka
On Tue, Aug 07, 2018 at 12:11:05PM -0700, Stephane Eranian wrote:
> Jiri,
> On Tue, Aug 7, 2018 at 1:50 AM Jiri Olsa <[email protected]> wrote:
> >
> > On Tue, Aug 07, 2018 at 01:16:22AM -0700, Stephane Eranian wrote:
> > > On Tue, Aug 7, 2018 at 12:20 AM Jiri Olsa <[email protected]> wrote:
> > > >
> > > > On Mon, Aug 06, 2018 at 06:23:35PM -0700, Stephane Eranian wrote:
> > > > > Depending on memory allocations, it was possible to get a SEGFAULT in
> > > > > free_dup_event() because the event pointer was bogus:
> > > > >
> > > > > perf[1354]: segfault at ffffffff00000006 ip 00000000004b7fc7
> > > >
> > > > is there any reproducer?
> > > >
> > > The cmdline is simple:
> > > $ perf record -e cycles:pp -o - -a sleep 1 | perf inject -b -i - >/dev/null
> > > I was using v4.13 for my tests and it may be sensitive to compiler.
> > > Was using LLVM.
> >
> > I can't make it fail even when I compile with clang 'make CC=clang'
> >
> I checked, my actual reproducer is:
> $ perf record -o - -e cycles date | perf inject -b -i - >/dev/null
> Tue Aug 7 12:03:48 PDT 2018
> [ perf record: Woken up 1 times to write data ]
> [ perf record: Captured and wrote 0.000 MB - ]
> Segmentation fault (core dumped)
>
> the crash is in perf inject.
> So if I do:
> $ perf record -o - -e cycles date >tt
> $ gdb perf
> (gdb) r inject -b -i - < tt >/dev/null
> Program received signal SIGSEGV, Segmentation fault.
> free_dup_event (oe=0x26a39a0, event=0xffffffff00000000) at
> util/ordered-events.c:85
> 85 in util/ordered-events.c
> (gdb) bt
> #0 free_dup_event (oe=0x26a39a0, event=0xffffffff00000000) at
> util/ordered-events.c:85
> #1 ordered_events__free (oe=0x26a39a0) at util/ordered-events.c:310
> #2 0x00000000004b5a56 in __perf_session__process_pipe_events
> (session=<optimized out>) at util/session.c:1753
> #3 perf_session__process_events (session=<optimized out>) at
> util/session.c:1932
> #4 0x000000000043a2eb in __cmd_inject (inject=<optimized out>) at
> builtin-inject.c:750
> #5 cmd_inject (argc=<optimized out>, argv=<optimized out>) at
> builtin-inject.c:924
> #6 0x000000000046b175 in run_builtin (p=0xabc640 <commands+576>,
> argc=4, argv=0x7fffffffe560) at perf.c:297
> #7 0x000000000046b062 in handle_internal_command (argc=4,
> argv=0x7fffffffe560) at perf.c:349
> #8 0x000000000046a5e8 in run_argv (argcp=<optimized out>,
> argv=<optimized out>) at perf.c:393
> #9 main (argc=4, argv=0x7fffffffe560) at perf.c:531
nice
>
> Again, this is with an older version of perf compiled with LLVM.
can you also reproduce it with latest code?
> Notice the value of event passed to free_dup_event(): 0xffffffff00000000
> And yes, I checked sizeof(union_perf_event) = 4168 which is the size of
> the mmap2_event which is the largest.
>
> I also checked that you are freeing what you have actually allocated.
> No double free.
> If I add the padding or modifies the call to memdup() as in the patch,
> then the problem
> goes away.
>
> If you don't want to copy 4Kb each time, then you could also make the
> event field
> by a void *event and case whenever needed.
not sure I understand this one.. could you please elaborate?
>
> I suspect the problem may come from a compiler optimization or assumption which
> clashes with what you are optimizing here.
I'll go throught the code and try to find somethign.. thanks a lot for the backtrace
jirka
Hi,
Ok, I found the problem. It still exists upstream , just very tricky to trigger.
Took me lots of time with gdb + watchpoints to track this down, where
in fact it was just in front of me.
From the crashdump:
Program received signal SIGSEGV, Segmentation fault.
free_dup_event (oe=0x26a39a0, event=0xffffffff00000000)
I was puzzled by the 0xffffffff00000000. I tracked down where this
value was coming from using watchpoints.
In my case the memory was used before by elfutils to back the struct
Elf. The -1 in the upper bits came from:
file_read_elf () at third_party/elfutils/libelf/elf_begin.c:451
elf->state.elf64.scns.data[cnt].shndx_index = -1;
And yet the next access to that memory location was in the crash. That
meant the memory was released by
elfutils and reused by ordered_events, yet without any initialization.
But looking at alloc_event(), it was
not obvious to figure out how a new_event->event could be uninitialized.
Well, it turns out there is this little hack where the code
commandeers the first element in the oe->buffer to
use as a list_head for the oe->to_free freelist. The problem is that
this entry also gets freed, but its
event->event field is NEVER initialized. So depending on how the
memory was previously used, you
could get a on NULL value and crash in free_dup_event(). This is what
happened to me. I am glad
I pursued this further because the bug is still in the upstream
version. The patch is a one-liner fixing
the initialization of the event->event = NULL. For the other elements
in the list, the initialization is
already done at the end of alloc_event().
I will send the patch separately.
On Wed, Aug 8, 2018 at 1:23 AM Jiri Olsa <[email protected]> wrote:
>
> On Tue, Aug 07, 2018 at 12:11:05PM -0700, Stephane Eranian wrote:
> > Jiri,
> > On Tue, Aug 7, 2018 at 1:50 AM Jiri Olsa <[email protected]> wrote:
> > >
> > > On Tue, Aug 07, 2018 at 01:16:22AM -0700, Stephane Eranian wrote:
> > > > On Tue, Aug 7, 2018 at 12:20 AM Jiri Olsa <[email protected]> wrote:
> > > > >
> > > > > On Mon, Aug 06, 2018 at 06:23:35PM -0700, Stephane Eranian wrote:
> > > > > > Depending on memory allocations, it was possible to get a SEGFAULT in
> > > > > > free_dup_event() because the event pointer was bogus:
> > > > > >
> > > > > > perf[1354]: segfault at ffffffff00000006 ip 00000000004b7fc7
> > > > >
> > > > > is there any reproducer?
> > > > >
> > > > The cmdline is simple:
> > > > $ perf record -e cycles:pp -o - -a sleep 1 | perf inject -b -i - >/dev/null
> > > > I was using v4.13 for my tests and it may be sensitive to compiler.
> > > > Was using LLVM.
> > >
> > > I can't make it fail even when I compile with clang 'make CC=clang'
> > >
> > I checked, my actual reproducer is:
> > $ perf record -o - -e cycles date | perf inject -b -i - >/dev/null
> > Tue Aug 7 12:03:48 PDT 2018
> > [ perf record: Woken up 1 times to write data ]
> > [ perf record: Captured and wrote 0.000 MB - ]
> > Segmentation fault (core dumped)
> >
> > the crash is in perf inject.
> > So if I do:
> > $ perf record -o - -e cycles date >tt
> > $ gdb perf
> > (gdb) r inject -b -i - < tt >/dev/null
> > Program received signal SIGSEGV, Segmentation fault.
> > free_dup_event (oe=0x26a39a0, event=0xffffffff00000000) at
> > util/ordered-events.c:85
> > 85 in util/ordered-events.c
> > (gdb) bt
> > #0 free_dup_event (oe=0x26a39a0, event=0xffffffff00000000) at
> > util/ordered-events.c:85
> > #1 ordered_events__free (oe=0x26a39a0) at util/ordered-events.c:310
> > #2 0x00000000004b5a56 in __perf_session__process_pipe_events
> > (session=<optimized out>) at util/session.c:1753
> > #3 perf_session__process_events (session=<optimized out>) at
> > util/session.c:1932
> > #4 0x000000000043a2eb in __cmd_inject (inject=<optimized out>) at
> > builtin-inject.c:750
> > #5 cmd_inject (argc=<optimized out>, argv=<optimized out>) at
> > builtin-inject.c:924
> > #6 0x000000000046b175 in run_builtin (p=0xabc640 <commands+576>,
> > argc=4, argv=0x7fffffffe560) at perf.c:297
> > #7 0x000000000046b062 in handle_internal_command (argc=4,
> > argv=0x7fffffffe560) at perf.c:349
> > #8 0x000000000046a5e8 in run_argv (argcp=<optimized out>,
> > argv=<optimized out>) at perf.c:393
> > #9 main (argc=4, argv=0x7fffffffe560) at perf.c:531
>
> nice
>
> >
> > Again, this is with an older version of perf compiled with LLVM.
>
> can you also reproduce it with latest code?
>
> > Notice the value of event passed to free_dup_event(): 0xffffffff00000000
> > And yes, I checked sizeof(union_perf_event) = 4168 which is the size of
> > the mmap2_event which is the largest.
> >
> > I also checked that you are freeing what you have actually allocated.
> > No double free.
> > If I add the padding or modifies the call to memdup() as in the patch,
> > then the problem
> > goes away.
> >
> > If you don't want to copy 4Kb each time, then you could also make the
> > event field
> > by a void *event and case whenever needed.
>
> not sure I understand this one.. could you please elaborate?
>
> >
> > I suspect the problem may come from a compiler optimization or assumption which
> > clashes with what you are optimizing here.
>
> I'll go throught the code and try to find somethign.. thanks a lot for the backtrace
>
> jirka
>
On Wed, Aug 08, 2018 at 02:47:42PM -0700, Stephane Eranian wrote:
> Hi,
>
> Ok, I found the problem. It still exists upstream , just very tricky to trigger.
> Took me lots of time with gdb + watchpoints to track this down, where
> in fact it was just in front of me.
>
> From the crashdump:
> Program received signal SIGSEGV, Segmentation fault.
> free_dup_event (oe=0x26a39a0, event=0xffffffff00000000)
>
> I was puzzled by the 0xffffffff00000000. I tracked down where this
> value was coming from using watchpoints.
> In my case the memory was used before by elfutils to back the struct
> Elf. The -1 in the upper bits came from:
>
> file_read_elf () at third_party/elfutils/libelf/elf_begin.c:451
> elf->state.elf64.scns.data[cnt].shndx_index = -1;
>
> And yet the next access to that memory location was in the crash. That
> meant the memory was released by
> elfutils and reused by ordered_events, yet without any initialization.
> But looking at alloc_event(), it was
> not obvious to figure out how a new_event->event could be uninitialized.
>
> Well, it turns out there is this little hack where the code
> commandeers the first element in the oe->buffer to
> use as a list_head for the oe->to_free freelist. The problem is that
> this entry also gets freed, but its
> event->event field is NEVER initialized. So depending on how the
> memory was previously used, you
> could get a on NULL value and crash in free_dup_event(). This is what
> happened to me. I am glad
> I pursued this further because the bug is still in the upstream
> version. The patch is a one-liner fixing
> the initialization of the event->event = NULL. For the other elements
> in the list, the initialization is
> already done at the end of alloc_event().
>
> I will send the patch separately.
nice ;-) thanks
jirka