2019-01-07 16:30:33

by syzbot

[permalink] [raw]
Subject: KASAN: slab-out-of-bounds Read in bacpy

Hello,

syzbot found the following crash on:

HEAD commit: 574823bfab82 Change mincore() to count "mapped" pages rath..
git tree: upstream
console output: https://syzkaller.appspot.com/x/log.txt?x=15145dab400000
kernel config: https://syzkaller.appspot.com/x/.config?x=d55557b516c45456
dashboard link: https://syzkaller.appspot.com/bug?extid=660883c56e2fa65d4497
compiler: gcc (GCC) 9.0.0 20181231 (experimental)
syz repro: https://syzkaller.appspot.com/x/repro.syz?x=1756666f400000
C reproducer: https://syzkaller.appspot.com/x/repro.c?x=1397354b400000

IMPORTANT: if you fix the bug, please add the following tag to the commit:
Reported-by: [email protected]

==================================================================
BUG: KASAN: slab-out-of-bounds in memcpy include/linux/string.h:352 [inline]
BUG: KASAN: slab-out-of-bounds in bacpy+0x23/0x30
include/net/bluetooth/bluetooth.h:236
Read of size 6 at addr ffff888094f0bc3b by task kworker/u5:0/1171

CPU: 0 PID: 1171 Comm: kworker/u5:0 Not tainted 4.20.0+ #13
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS
Google 01/01/2011
Workqueue: hci0 hci_rx_work
Call Trace:
__dump_stack lib/dump_stack.c:77 [inline]
dump_stack+0x1db/0x2d0 lib/dump_stack.c:113
print_address_description.cold+0x7c/0x20d mm/kasan/report.c:187
kasan_report.cold+0x1b/0x40 mm/kasan/report.c:317
check_memory_region_inline mm/kasan/generic.c:185 [inline]
check_memory_region+0x123/0x190 mm/kasan/generic.c:191
memcpy+0x24/0x50 mm/kasan/common.c:130
memcpy include/linux/string.h:352 [inline]
bacpy+0x23/0x30 include/net/bluetooth/bluetooth.h:236
hci_inquiry_result_with_rssi_evt net/bluetooth/hci_event.c:3986 [inline]
hci_event_packet+0x3afc/0xc22e net/bluetooth/hci_event.c:5863
hci_rx_work+0x578/0xcd0 net/bluetooth/hci_core.c:4412
process_one_work+0xd0c/0x1ce0 kernel/workqueue.c:2153
worker_thread+0x143/0x14a0 kernel/workqueue.c:2296
kthread+0x357/0x430 kernel/kthread.c:246
ret_from_fork+0x3a/0x50 arch/x86/entry/entry_64.S:352

Allocated by task 7831:
save_stack+0x45/0xd0 mm/kasan/common.c:73
set_track mm/kasan/common.c:85 [inline]
kasan_kmalloc mm/kasan/common.c:482 [inline]
kasan_kmalloc+0xcf/0xe0 mm/kasan/common.c:455
__do_kmalloc_node mm/slab.c:3671 [inline]
__kmalloc_node_track_caller+0x4e/0x70 mm/slab.c:3685
__kmalloc_reserve.isra.0+0x40/0xe0 net/core/skbuff.c:140
__alloc_skb+0x12d/0x730 net/core/skbuff.c:208
alloc_skb include/linux/skbuff.h:1011 [inline]
bt_skb_alloc include/net/bluetooth/bluetooth.h:339 [inline]
vhci_get_user drivers/bluetooth/hci_vhci.c:180 [inline]
vhci_write+0xc4/0x470 drivers/bluetooth/hci_vhci.c:299
call_write_iter include/linux/fs.h:1862 [inline]
new_sync_write fs/read_write.c:474 [inline]
__vfs_write+0x764/0xb40 fs/read_write.c:487
vfs_write+0x20c/0x580 fs/read_write.c:549
ksys_write+0x105/0x260 fs/read_write.c:598
__do_sys_write fs/read_write.c:610 [inline]
__se_sys_write fs/read_write.c:607 [inline]
__x64_sys_write+0x73/0xb0 fs/read_write.c:607
do_syscall_64+0x1a3/0x800 arch/x86/entry/common.c:290
entry_SYSCALL_64_after_hwframe+0x49/0xbe

Freed by task 5970:
save_stack+0x45/0xd0 mm/kasan/common.c:73
set_track mm/kasan/common.c:85 [inline]
__kasan_slab_free+0x102/0x150 mm/kasan/common.c:444
kasan_slab_free+0xe/0x10 mm/kasan/common.c:452
__cache_free mm/slab.c:3485 [inline]
kfree+0xcf/0x230 mm/slab.c:3804
load_elf_binary+0x25dd/0x5580 fs/binfmt_elf.c:1118
search_binary_handler fs/exec.c:1656 [inline]
search_binary_handler+0x17f/0x570 fs/exec.c:1634
exec_binprm fs/exec.c:1698 [inline]
__do_execve_file.isra.0+0x14f3/0x2700 fs/exec.c:1818
do_execveat_common fs/exec.c:1865 [inline]
do_execve fs/exec.c:1882 [inline]
__do_sys_execve fs/exec.c:1963 [inline]
__se_sys_execve fs/exec.c:1958 [inline]
__x64_sys_execve+0x8f/0xc0 fs/exec.c:1958
do_syscall_64+0x1a3/0x800 arch/x86/entry/common.c:290
entry_SYSCALL_64_after_hwframe+0x49/0xbe

The buggy address belongs to the object at ffff888094f0ba40
which belongs to the cache kmalloc-512 of size 512
The buggy address is located 507 bytes inside of
512-byte region [ffff888094f0ba40, ffff888094f0bc40)
The buggy address belongs to the page:
page:ffffea000253c2c0 count:1 mapcount:0 mapping:ffff88812c3f0940 index:0x0
flags: 0x1fffc0000000200(slab)
raw: 01fffc0000000200 ffffea00025dbf08 ffffea000253ca88 ffff88812c3f0940
raw: 0000000000000000 ffff888094f0b040 0000000100000006 0000000000000000
page dumped because: kasan: bad access detected

Memory state around the buggy address:
ffff888094f0bb00: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
ffff888094f0bb80: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
> ffff888094f0bc00: 00 00 00 00 00 00 00 00 fc fc fc fc fc fc fc fc
^
ffff888094f0bc80: fc fc fc fc fc fc fc fc fb fb fb fb fb fb fb fb
ffff888094f0bd00: fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb
==================================================================


---
This bug is generated by a bot. It may contain errors.
See https://goo.gl/tpsmEJ for more information about syzbot.
syzbot engineers can be reached at [email protected].

syzbot will keep track of this bug report. See:
https://goo.gl/tpsmEJ#bug-status-tracking for how to communicate with
syzbot.
syzbot can test patches for this bug, for details see:
https://goo.gl/tpsmEJ#testing-patches


2019-03-17 10:44:38

by syzbot

[permalink] [raw]
Subject: Re: KASAN: slab-out-of-bounds Read in bacpy

syzbot has bisected this bug to:

commit c470abd4fde40ea6a0846a2beab642a578c0b8cd
Author: Linus Torvalds <[email protected]>
Date: Sun Feb 19 22:34:00 2017 +0000

Linux 4.10

bisection log: https://syzkaller.appspot.com/x/bisect.txt?x=13dbe2cf200000
start commit: c470abd4 Linux 4.10
git tree: upstream
kernel config: https://syzkaller.appspot.com/x/.config?x=d55557b516c45456
dashboard link: https://syzkaller.appspot.com/bug?extid=660883c56e2fa65d4497
syz repro: https://syzkaller.appspot.com/x/repro.syz?x=1756666f400000
C reproducer: https://syzkaller.appspot.com/x/repro.c?x=1397354b400000

Reported-by: [email protected]
Fixes: c470abd4 ("Linux 4.10")

2019-03-17 16:37:54

by Linus Torvalds

[permalink] [raw]
Subject: Re: KASAN: slab-out-of-bounds Read in bacpy

On Sun, Mar 17, 2019 at 3:43 AM syzbot
<[email protected]> wrote:
>
> syzbot has bisected this bug to:
>
> commit c470abd4fde40ea6a0846a2beab642a578c0b8cd
> Author: Linus Torvalds <[email protected]>
> Date: Sun Feb 19 22:34:00 2017 +0000

Heh. Yeah, I doubt it.

It would probably be good if syzbot did some confidence testing before
bisecting.

Don't get me wrong, "git bisect" is absolutely wonderful and has done
a ton to help us fix bugs, but bisection has one major downside: if
the bug you are bisecting isn't 100% repeatable, the bisection will go
off into the random weeds and give completely nonsensical results.
They won't even be *close*. What makes bisection so powerful is also
what makes it then completely random if there's even *one* mistaken
bisection point.

So it would probably be good to test each bisection point at least
twice, and if they don't agree, report it as being unbisectable rather
than give a random "this is what introduced the problem".

Hmm?

Linus

2019-03-17 17:13:06

by Dmitry Vyukov

[permalink] [raw]
Subject: Re: KASAN: slab-out-of-bounds Read in bacpy

On Sun, Mar 17, 2019 at 5:35 PM Linus Torvalds
<[email protected]> wrote:
>
> On Sun, Mar 17, 2019 at 3:43 AM syzbot
> <[email protected]> wrote:
> >
> > syzbot has bisected this bug to:
> >
> > commit c470abd4fde40ea6a0846a2beab642a578c0b8cd
> > Author: Linus Torvalds <[email protected]>
> > Date: Sun Feb 19 22:34:00 2017 +0000
>
> Heh. Yeah, I doubt it.
>
> It would probably be good if syzbot did some confidence testing before
> bisecting.
>
> Don't get me wrong, "git bisect" is absolutely wonderful and has done
> a ton to help us fix bugs, but bisection has one major downside: if
> the bug you are bisecting isn't 100% repeatable, the bisection will go
> off into the random weeds and give completely nonsensical results.
> They won't even be *close*. What makes bisection so powerful is also
> what makes it then completely random if there's even *one* mistaken
> bisection point.
>
> So it would probably be good to test each bisection point at least
> twice, and if they don't agree, report it as being unbisectable rather
> than give a random "this is what introduced the problem".
>
> Hmm?


Hi Linus,

Please see https://github.com/google/syzkaller/blob/master/docs/syzbot.md#bisection
it should answer all of your questions. It does 2 and more.
And in this case it seems to be working as intended bisecting it to a
release tag.

2019-03-17 19:28:51

by Stefano Brivio

[permalink] [raw]
Subject: Re: KASAN: slab-out-of-bounds Read in bacpy

On Sun, 17 Mar 2019 18:11:49 +0100
Dmitry Vyukov <[email protected]> wrote:

> And in this case it seems to be working as intended bisecting it to a
> release tag.

I guess what went wrong here is that it had to skip quite a few
commits, and the result isn't relevant anymore. Maybe you could improve
this by handling a:

all runs: boot failed: can't ssh into the instance

case as bad revision? And, also, if scp times out (as it did on
912964eacb11), keep retrying instead of marking the revision as good?

--
Stefano

2019-03-17 20:42:16

by Linus Torvalds

[permalink] [raw]
Subject: Re: KASAN: slab-out-of-bounds Read in bacpy

On Sun, Mar 17, 2019 at 10:12 AM Dmitry Vyukov <[email protected]> wrote:
>
> Please see https://github.com/google/syzkaller/blob/master/docs/syzbot.md#bisection
> it should answer all of your questions. It does 2 and more.
> And in this case it seems to be working as intended bisecting it to a
> release tag.

No, it's definitely not working as intended.

You can see it in the bisect log - you don't actually have a single
"git bisect bad" outside of the initial one that you start bisecting
with. That's a pretty good sign of bisection being completely broken.
Yes, it can happen in theory, but in general with a good bisection,
you should see about as many "good" results as "bad".

I bet that what's going on is that your initial "let's test every
release" uses a _different_ process than the actual bisection itself
does.

So if I were you, I'd look at what syzbot does differently during
bisection vs what it does for that initial "test each release". For
example, does it do "make clean" in between each build in one case,
but not the other? Does it do "make oldconfig" vs a fixed config
generated from scratch every time? Because the fact that you first
tested 4.10 bad using the "test each release", and then when you do
bisection, the very commit *before* 4.10 is good (the only difference
being the EXTRAVERSION and the tag) shows that something went wrong.

Linus

2019-03-18 13:01:11

by Dmitry Vyukov

[permalink] [raw]
Subject: Re: KASAN: slab-out-of-bounds Read in bacpy

On Sun, Mar 17, 2019 at 8:25 PM Stefano Brivio <[email protected]> wrote:
>
> On Sun, 17 Mar 2019 18:11:49 +0100
> Dmitry Vyukov <[email protected]> wrote:
>
> > And in this case it seems to be working as intended bisecting it to a
> > release tag.
>
> I guess what went wrong here is that it had to skip quite a few
> commits, and the result isn't relevant anymore. Maybe you could improve
> this by handling a:
>
> all runs: boot failed: can't ssh into the instance
>
> case as bad revision? And, also, if scp times out (as it did on
> 912964eacb11), keep retrying instead of marking the revision as good?

Skipping revisions does not make the result wrong. In the worst case
git bisect will point to a range of commits.
But marking non-building/booting revisions as bad can actually diverge
bisection in the wrong direction and will result in pointing to
completely irrelevant commits. git skip is meant exactly for such
cases.
And in this case, skipping did not affect the process, it just needed
to do few more additional steps.

2019-03-19 13:30:04

by Dmitry Vyukov

[permalink] [raw]
Subject: Re: KASAN: slab-out-of-bounds Read in bacpy

On Sun, Mar 17, 2019 at 9:41 PM Linus Torvalds
<[email protected]> wrote:
>
> On Sun, Mar 17, 2019 at 10:12 AM Dmitry Vyukov <[email protected]> wrote:
> >
> > Please see https://github.com/google/syzkaller/blob/master/docs/syzbot.md#bisection
> > it should answer all of your questions. It does 2 and more.
> > And in this case it seems to be working as intended bisecting it to a
> > release tag.
>
> No, it's definitely not working as intended.
>
> You can see it in the bisect log - you don't actually have a single
> "git bisect bad" outside of the initial one that you start bisecting
> with. That's a pretty good sign of bisection being completely broken.
> Yes, it can happen in theory, but in general with a good bisection,
> you should see about as many "good" results as "bad".
>
> I bet that what's going on is that your initial "let's test every
> release" uses a _different_ process than the actual bisection itself
> does.
>
> So if I were you, I'd look at what syzbot does differently during
> bisection vs what it does for that initial "test each release". For
> example, does it do "make clean" in between each build in one case,
> but not the other? Does it do "make oldconfig" vs a fixed config
> generated from scratch every time? Because the fact that you first
> tested 4.10 bad using the "test each release", and then when you do
> bisection, the very commit *before* 4.10 is good (the only difference
> being the EXTRAVERSION and the tag) shows that something went wrong.


Well, this is intended behavior for some definition of intended.
The root cause of what happened here is that syzbot has to disable
CONFIG_USBIP_VHCI_HCD/CONFIG_BT_HCIVHCI when it crosses v4.10
boundary. It fixes boot on the release and otherwise no bisection will
succeed at all.
It's just happened so that this particular bug is dependent on these
exact configs and was introduced before v4.10. So it was bisected to
v4.10. And in this sense it is working as intended.

How would you define intended bisection behavior for the situation
when kernel is build/boot/test broken most of the time, even on
releases and even on recent releases? ;)
I guess the 100% fair answer is "the bug happens as far as we could
test (which is not too far)". And that's what I did initially, but the
result was way less useful than what we have now.

This and other details of the process are described here:
https://github.com/google/syzkaller/blob/master/docs/syzbot.md#bisection
This was the first attempt at giving more transparency into the process.

I see 2 potential improvements:
1. (simpler) noting in the bisection log things like disabled configs,
cherry-picked fixes and other things necessary to repair kernel.
2. (harder) try to figure out that the bug actually depends on the
disabled config
I've added this to https://github.com/google/syzkaller/issues/1051
But for (2) I would first like to see that this is a common enough
problem rather then a one-off thing, because it's easier to say than
to implement that reliably and this can affect bugs completely
unrelated to the disabled configs due to unavoidable kernel crash
flakes (and then somebody will need to explain what happened to all
people asking).

And obviously doing some real testing before merging each commit into
any kernel tree would help tremendously with bisection long term ;)

Even v5.0 is boot broken if I try to enable more configs. So we will
need to disable more configs in bisection in future as we onboard them
to syzbot. The current points in time we need to disable various
configs suspiciously resemble when they were added to syzbot config...