Hi!
I am working on AddressSanitizer -- a tool that detects use-after-free
and out-of-bounds bugs
(https://code.google.com/p/address-sanitizer/wiki/AddressSanitizerForKernel).
Below is one of the bug reports that I got while running trinity syscall fuzzer.
Kernel is built on revision d8efd82eece89f8a5790b0febf17522affe9e1f1.
[ 286.473434] ERROR: AddressSanitizer: heap-buffer-overflow on
address ffff8800359c99f3
[ 286.474598] ffff8800359c99f3 is located 0 bytes to the right of
243-byte region [ffff8800359c9900, ffff8800359c99f3)
[ 286.476100] Accessed by thread T13003:
[ 286.476735] #0 ffffffff810dd2da (asan_report_error+0x32a/0x440)
[ 286.477556] #1 ffffffff810dc6b0 (asan_check_region+0x30/0x40)
[ 286.478353] #2 ffffffff810dd4d3 (__tsan_write1+0x13/0x20)
[ 286.479112] #3 ffffffff811cd19e (ftrace_regex_release+0x1be/0x260)
[ 286.479929] #4 ffffffff812a1065 (__fput+0x155/0x360)
[ 286.480627] #5 ffffffff812a12de (____fput+0x1e/0x30)
[ 286.481331] #6 ffffffff8111708d (task_work_run+0x10d/0x140)
[ 286.482107] #7 ffffffff810ea043 (do_exit+0x433/0x11f0)
[ 286.482793] #8 ffffffff810eaee4 (do_group_exit+0x84/0x130)
[ 286.483552] #9 ffffffff810eafb1 (SyS_exit_group+0x21/0x30)
[ 286.484320] #10 ffffffff81928782 (system_call_fastpath+0x16/0x1b)
[ 286.485151]
[ 286.485365] Allocated by thread T5167:
[ 286.485979] #0 ffffffff810dc778 (asan_slab_alloc+0x48/0xc0)
[ 286.486750] #1 ffffffff8128337c (__kmalloc+0xbc/0x500)
[ 286.487474] #2 ffffffff811d9d54 (trace_parser_get_init+0x34/0x90)
[ 286.488313] #3 ffffffff811cd7b3 (ftrace_regex_open+0x83/0x2e0)
[ 286.489120] #4 ffffffff811cda7d (ftrace_filter_open+0x2d/0x40)
[ 286.489894] #5 ffffffff8129b4ff (do_dentry_open+0x32f/0x430)
[ 286.490674] #6 ffffffff8129b668 (finish_open+0x68/0xa0)
[ 286.491411] #7 ffffffff812b66ac (do_last+0xb8c/0x1710)
[ 286.492135] #8 ffffffff812b7350 (path_openat+0x120/0xb50)
[ 286.492855] #9 ffffffff812b8884 (do_filp_open+0x54/0xb0)
[ 286.493604] #10 ffffffff8129d36c (do_sys_open+0x1ac/0x2c0)
[ 286.494366] #11 ffffffff8129d4b7 (SyS_open+0x37/0x50)
[ 286.495078] #12 ffffffff81928782 (system_call_fastpath+0x16/0x1b)
[ 286.495878]
[ 286.496120] Shadow bytes around the buggy address:
[ 286.496810] ffff8800359c9700: fd fd fd fd fd fd fd fd fd fd fd fd
fd fd fd fd
[ 286.499707] ffff8800359c9780: fd fd fd fd fd fd fd fd fa fa fa fa
fa fa fa fa
[ 286.502622] ffff8800359c9800: fa fa fa fa fa fa fa fa fa fa fa fa
fa fa fa fa
[ 286.505521] ffff8800359c9880: fa fa fa fa fa fa fa fa fa fa fa fa
fa fa fa fa
[ 286.508459] ffff8800359c9900: 00 00 00 00 00 00 00 00 00 00 00 00
00 00 00 00
[ 286.511345] =>ffff8800359c9980: 00 00 00 00 00 00 00 00 00 00 00 00
00 00[03]fb
[ 286.514243] ffff8800359c9a00: fa fa fa fa fa fa fa fa fa fa fa fa
fa fa fa fa
[ 286.517175] ffff8800359c9a80: fa fa fa fa fa fa fa fa fa fa fa fa
fa fa fa fa
[ 286.520059] ffff8800359c9b00: fa fa fa fa fa fa fa fa 00 00 00 00
00 00 00 00
[ 286.522936] ffff8800359c9b80: 00 00 00 00 00 00 00 00 00 00 00 00
00 00 00 00
[ 286.525921] ffff8800359c9c00: 00 00 00 00 00 00 00 00 fa fa fa fa
fa fa fa fa
[ 286.528738] Shadow byte legend (one shadow byte represents 8
application bytes):
[ 286.529701] Addressable: 00
[ 286.530346] Partially addressable: 01 02 03 04 05 06 07
[ 286.531155] Heap redzone: fa
[ 286.531753] Heap kmalloc redzone: fb
[ 286.532414] Freed heap region: fd
[ 286.533083] Shadow gap: fe
The out-of-bounds access happens on 'parser->buffer[parser->idx] = 0;'
My guess is that 'trace_get_user()' was called.
Checking that 'parser->idx < parser->size - 1' is not performed in 'if
(isspace(ch))' section, so 'parser->idx' becomes equal to
'parser->size' after 'parser->buffer[parser->idx++] = ch;'.
(However in 'while (cnt && !isspace(ch))' loop checking is performed.)
Please help to confirm/triage the report.
On Wed, Oct 02, 2013 at 10:38:01PM +0400, Andrey Konovalov wrote:
> Hi!
>
> I am working on AddressSanitizer -- a tool that detects use-after-free
> and out-of-bounds bugs
> (https://code.google.com/p/address-sanitizer/wiki/AddressSanitizerForKernel).
> Below is one of the bug reports that I got while running trinity syscall fuzzer.
> Kernel is built on revision d8efd82eece89f8a5790b0febf17522affe9e1f1.
>
> [ 286.473434] ERROR: AddressSanitizer: heap-buffer-overflow on
> address ffff8800359c99f3
> [ 286.474598] ffff8800359c99f3 is located 0 bytes to the right of
> 243-byte region [ffff8800359c9900, ffff8800359c99f3)
> [ 286.476100] Accessed by thread T13003:
> [ 286.476735] #0 ffffffff810dd2da (asan_report_error+0x32a/0x440)
> [ 286.477556] #1 ffffffff810dc6b0 (asan_check_region+0x30/0x40)
> [ 286.478353] #2 ffffffff810dd4d3 (__tsan_write1+0x13/0x20)
> [ 286.479112] #3 ffffffff811cd19e (ftrace_regex_release+0x1be/0x260)
> [ 286.479929] #4 ffffffff812a1065 (__fput+0x155/0x360)
> [ 286.480627] #5 ffffffff812a12de (____fput+0x1e/0x30)
> [ 286.481331] #6 ffffffff8111708d (task_work_run+0x10d/0x140)
> [ 286.482107] #7 ffffffff810ea043 (do_exit+0x433/0x11f0)
> [ 286.482793] #8 ffffffff810eaee4 (do_group_exit+0x84/0x130)
> [ 286.483552] #9 ffffffff810eafb1 (SyS_exit_group+0x21/0x30)
> [ 286.484320] #10 ffffffff81928782 (system_call_fastpath+0x16/0x1b)
> [ 286.485151]
Excellent! This looks exactly like the trace I've been hitting that triggers
WARNING: CPU: 3 PID: 26435 at kernel/trace/ftrace.c:1640 __ftrace_hash_rec_update.part.37+0x20a/0x240()
> [ 286.485365] Allocated by thread T5167:
> [ 286.485979] #0 ffffffff810dc778 (asan_slab_alloc+0x48/0xc0)
> [ 286.486750] #1 ffffffff8128337c (__kmalloc+0xbc/0x500)
> [ 286.487474] #2 ffffffff811d9d54 (trace_parser_get_init+0x34/0x90)
> [ 286.488313] #3 ffffffff811cd7b3 (ftrace_regex_open+0x83/0x2e0)
> [ 286.489120] #4 ffffffff811cda7d (ftrace_filter_open+0x2d/0x40)
> [ 286.489894] #5 ffffffff8129b4ff (do_dentry_open+0x32f/0x430)
> [ 286.490674] #6 ffffffff8129b668 (finish_open+0x68/0xa0)
> [ 286.491411] #7 ffffffff812b66ac (do_last+0xb8c/0x1710)
> [ 286.492135] #8 ffffffff812b7350 (path_openat+0x120/0xb50)
> [ 286.492855] #9 ffffffff812b8884 (do_filp_open+0x54/0xb0)
> [ 286.493604] #10 ffffffff8129d36c (do_sys_open+0x1ac/0x2c0)
> [ 286.494366] #11 ffffffff8129d4b7 (SyS_open+0x37/0x50)
> [ 286.495078] #12 ffffffff81928782 (system_call_fastpath+0x16/0x1b)
And that's the cause. I wonder what was being opened.
Do you happen to have a trinity-child log for that thread ?
Dave
On Wed, Oct 2, 2013 at 10:57 PM, Dave Jones <[email protected]> wrote:
> And that's the cause. I wonder what was being opened.
> Do you happen to have a trinity-child log for that thread ?
Unfortunately not.
On Wed, 2013-10-02 at 14:57 -0400, Dave Jones wrote:
> And that's the cause. I wonder what was being opened.
> Do you happen to have a trinity-child log for that thread ?
Thanks for the update. This definitely looks like the bug, and explains
a lot. I'll look into this, as I'm currently at a conference, it may be
sporadic.
-- Steve
On Wed, Oct 02, 2013 at 04:18:02PM -0400, Steven Rostedt wrote:
> On Wed, 2013-10-02 at 14:57 -0400, Dave Jones wrote:
>
> > And that's the cause. I wonder what was being opened.
> > Do you happen to have a trinity-child log for that thread ?
>
> Thanks for the update. This definitely looks like the bug, and explains
> a lot. I'll look into this, as I'm currently at a conference, it may be
> sporadic.
another potential clue.. I looked over some logs from some crashes, and saw that just before
the crash, there was a call to unshare(), after which the uid changed from 1000 to 65534.
Is that something that ftrace is prepared for ?
Dave
I got one more report of a similar bug:
AddressSanitizer: heap-buffer-overflow on address ffff8800205f0e40
Write of size 1 by thread T14005:
[<ffffffff811e2542>] ftrace_event_write+0xe2/0x130
./kernel/trace/trace_events.c:583
[<ffffffff8128c497>] vfs_write+0x127/0x2f0 ??:0
[<ffffffff8128d572>] SyS_write+0x72/0xd0 ??:0
[<ffffffff818423d2>] system_call_fastpath+0x16/0x1b
./arch/x86/kernel/entry_64.S:629
Allocated by thread T14005:
[< inlined >] trace_parser_get_init+0x28/0x70 kmalloc
./include/linux/slab.h:413
[<ffffffff811cc258>] trace_parser_get_init+0x28/0x70 ./kernel/trace/trace.c:759
[<ffffffff811e24d2>] ftrace_event_write+0x72/0x130
./kernel/trace/trace_events.c:572
[<ffffffff8128c497>] vfs_write+0x127/0x2f0 ??:0
[<ffffffff8128d572>] SyS_write+0x72/0xd0 ??:0
[<ffffffff818423d2>] system_call_fastpath+0x16/0x1b
./arch/x86/kernel/entry_64.S:629
The buggy address ffff8800205f0e40 is located 0 bytes to the right
of 128-byte region [ffff8800205f0dc0, ffff8800205f0e40)
Memory state around the buggy address:
ffff8800205f0900: rrrrrrrr rrrrrrrr rrrrrrrr rrrrrrrr
ffff8800205f0a00: rrrrrrrr ........ ........ rrrrrrrr
ffff8800205f0b00: rrrrrrrr rrrrrrrr rrrrrrrr rrrrrrrr
ffff8800205f0c00: ........ .......5 rrrrrrrr rrrrrrrr
ffff8800205f0d00: rrrrrrrr rrrrrrrr rrrrrrrr ........
>ffff8800205f0e00: ........ rrrrrrrr rrrrrrrr rrrrrrrr
^
ffff8800205f0f00: rrrrrrrr rrrrrrrr rrrrrrrr rrrrrrrr
ffff8800205f1000: ........ ........ ........ ........
ffff8800205f1100: ........ ........ ........ ........
ffff8800205f1200: ........ ........ ........ ........
ffff8800205f1300: ........ ........ ........ ........
Legend:
f - 8 freed bytes
r - 8 redzone bytes
. - 8 allocated bytes
x=1..7 - x allocated bytes + (8-x) redzone bytes
This time it was caused by 'parser.buffer[parser.idx] = 0;' in
'ftrace_event_write()', which calls 'trace_get_user()' right before
the bad assignment.
So I still think that the bug is in 'trage_get_user()':
Checking that 'parser->idx < parser->size - 1' is not performed in 'if
(isspace(ch))' section, so 'parser->idx' becomes equal to
'parser->size' after 'parser->buffer[parser->idx++] = ch;'.
(However in 'while (cnt && !isspace(ch))' loop checking is performed.)
On Wed, 9 Oct 2013 14:05:26 +0400
Andrey Konovalov <[email protected]> wrote:
> So I still think that the bug is in 'trage_get_user()':
> Checking that 'parser->idx < parser->size - 1' is not performed in 'if
> (isspace(ch))' section, so 'parser->idx' becomes equal to
> 'parser->size' after 'parser->buffer[parser->idx++] = ch;'.
> (However in 'while (cnt && !isspace(ch))' loop checking is performed.)
Yep, you are correct. I put in some printk's and did same writing to
the set_events file and was able to prove that I could get that "0"
written into the +1 overflow boundary.
Can you try this patch to see if it fixes it for you.
Thanks,
-- Steve
diff --git a/kernel/trace/trace.c b/kernel/trace/trace.c
index d5f7c4d..063a92b 100644
--- a/kernel/trace/trace.c
+++ b/kernel/trace/trace.c
@@ -843,9 +843,12 @@ int trace_get_user(struct trace_parser *parser, const char __user *ubuf,
if (isspace(ch)) {
parser->buffer[parser->idx] = 0;
parser->cont = false;
- } else {
+ } else if (parser->idx < parser->size - 1) {
parser->cont = true;
parser->buffer[parser->idx++] = ch;
+ } else {
+ ret = -EINVAL;
+ goto out;
}
*ppos += read;
Testing now with your patch.
I've seen this report only twice, so it will be difficult to say if
it's not happening any more or just not triggered.
On Thu, Oct 10, 2013 at 6:23 AM, Steven Rostedt <[email protected]> wrote:
> On Wed, 9 Oct 2013 14:05:26 +0400
> Andrey Konovalov <[email protected]> wrote:
>
>> So I still think that the bug is in 'trage_get_user()':
>> Checking that 'parser->idx < parser->size - 1' is not performed in 'if
>> (isspace(ch))' section, so 'parser->idx' becomes equal to
>> 'parser->size' after 'parser->buffer[parser->idx++] = ch;'.
>> (However in 'while (cnt && !isspace(ch))' loop checking is performed.)
>
> Yep, you are correct. I put in some printk's and did same writing to
> the set_events file and was able to prove that I could get that "0"
> written into the +1 overflow boundary.
>
> Can you try this patch to see if it fixes it for you.
>
> Thanks,
>
> -- Steve
>
> diff --git a/kernel/trace/trace.c b/kernel/trace/trace.c
> index d5f7c4d..063a92b 100644
> --- a/kernel/trace/trace.c
> +++ b/kernel/trace/trace.c
> @@ -843,9 +843,12 @@ int trace_get_user(struct trace_parser *parser, const char __user *ubuf,
> if (isspace(ch)) {
> parser->buffer[parser->idx] = 0;
> parser->cont = false;
> - } else {
> + } else if (parser->idx < parser->size - 1) {
> parser->cont = true;
> parser->buffer[parser->idx++] = ch;
> + } else {
> + ret = -EINVAL;
> + goto out;
> }
>
> *ppos += read;
>
On Mon, 14 Oct 2013 12:29:13 +0400
Andrey Konovalov <[email protected]> wrote:
> Testing now with your patch.
> I've seen this report only twice, so it will be difficult to say if
> it's not happening any more or just not triggered.
Can I assume that this is fixed? I'll put it in for 3.12 and mark it
for stable too.
-- Steve
>
> On Thu, Oct 10, 2013 at 6:23 AM, Steven Rostedt <[email protected]> wrote:
> > On Wed, 9 Oct 2013 14:05:26 +0400
> > Andrey Konovalov <[email protected]> wrote:
> >time cat trace > /tmp/trace
> >> So I still think that the bug is in 'trage_get_user()':
> >> Checking that 'parser->idx < parser->size - 1' is not performed in 'if
> >> (isspace(ch))' section, so 'parser->idx' becomes equal to
> >> 'parser->size' after 'parser->buffer[parser->idx++] = ch;'.
> >> (However in 'while (cnt && !isspace(ch))' loop checking is performed.)
> >
> > Yep, you are correct. I put in some printk's and did same writing to
> > the set_events file and was able to prove that I could get that "0"
> > written into the +1 overflow boundary.
> >
> > Can you try this patch to see if it fixes it for you.
> >
> > Thanks,
> >
> > -- Steve
> >
> > diff --git a/kernel/trace/trace.c b/kernel/trace/trace.c
> > index d5f7c4d..063a92b 100644
> > --- a/kernel/trace/trace.c
> > +++ b/kernel/trace/trace.c
> > @@ -843,9 +843,12 @@ int trace_get_user(struct trace_parser *parser, const char __user *ubuf,
> > if (isspace(ch)) {
> > parser->buffer[parser->idx] = 0;
> > parser->cont = false;
> > - } else {
> > + } else if (parser->idx < parser->size - 1) {
> > parser->cont = true;
> > parser->buffer[parser->idx++] = ch;
> > + } else {
> > + ret = -EINVAL;
> > + goto out;
> > }
> >
> > *ppos += read;
> >
On Fri, Oct 18, 2013 at 11:09 PM, Steven Rostedt <[email protected]> wrote:
> Can I assume that this is fixed? I'll put it in for 3.12 and mark it
> for stable too.
I think yes. OK.