[<prev] [next>] [<thread-prev] [thread-next>] [day] [month] [year] [list]
Message-ID: <248f0079f4c95b6a07e9b39f491218de685db289.camel@kernel.org>
Date: Wed, 02 Jan 2019 16:42:20 -0500
From: Jeff Layton <jlayton@...nel.org>
To: Dmitry Vyukov <dvyukov@...gle.com>
Cc: syzbot <syzbot+239d99847eb49ecb3899@...kaller.appspotmail.com>,
Bruce Fields <bfields@...ldses.org>,
linux-fsdevel <linux-fsdevel@...r.kernel.org>,
LKML <linux-kernel@...r.kernel.org>,
syzkaller-bugs <syzkaller-bugs@...glegroups.com>,
Al Viro <viro@...iv.linux.org.uk>
Subject: Re: KASAN: use-after-free Read in posix_lock_inode
On Wed, 2019-01-02 at 19:54 +0100, Dmitry Vyukov wrote:
> On Wed, Jan 2, 2019 at 7:51 PM Dmitry Vyukov <dvyukov@...gle.com> wrote:
> > On Wed, Jan 2, 2019 at 7:20 PM Jeff Layton <jlayton@...nel.org> wrote:
> > > On Wed, 2019-01-02 at 02:31 -0800, syzbot wrote:
> > > > Hello,
> > > >
> > > > syzbot found the following crash on:
> > > >
> > > > HEAD commit: e1ef035d272e Merge tag 'armsoc-defconfig' of git://git.ker..
> > > > git tree: upstream
> > > > console output: https://syzkaller.appspot.com/x/log.txt?x=16bb4c4b400000
> > > > kernel config: https://syzkaller.appspot.com/x/.config?x=9c6a26e22579190b
> > > > dashboard link: https://syzkaller.appspot.com/bug?extid=239d99847eb49ecb3899
> > > > compiler: gcc (GCC) 9.0.0 20181231 (experimental)
> > > > syz repro: https://syzkaller.appspot.com/x/repro.syz?x=128aa377400000
> > > >
> > > > IMPORTANT: if you fix the bug, please add the following tag to the commit:
> > > > Reported-by: syzbot+239d99847eb49ecb3899@...kaller.appspotmail.com
> > > >
> > > > IPv6: ADDRCONF(NETDEV_UP): vxcan1: link is not ready
> > > > IPv6: ADDRCONF(NETDEV_UP): vxcan1: link is not ready
> > > > 8021q: adding VLAN 0 to HW filter on device batadv0
> > > > 8021q: adding VLAN 0 to HW filter on device batadv0
> > > > ==================================================================
> > > > BUG: KASAN: use-after-free in what_owner_is_waiting_for fs/locks.c:1000
> > > > [inline]
> > > > BUG: KASAN: use-after-free in posix_locks_deadlock fs/locks.c:1023 [inline]
> > > > BUG: KASAN: use-after-free in posix_lock_inode+0x1f9e/0x2750 fs/locks.c:1163
> > > > Read of size 8 at addr ffff88808791b000 by task syz-executor2/10100
> > > >
> > > > CPU: 1 PID: 10100 Comm: syz-executor2 Not tainted 4.20.0+ #3
> > > > Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS
> > > > Google 01/01/2011
> > > > 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
> > > > __asan_report_load8_noabort+0x14/0x20 mm/kasan/generic_report.c:135
> > > > what_owner_is_waiting_for fs/locks.c:1000 [inline]
> > > > posix_locks_deadlock fs/locks.c:1023 [inline]
> > > > posix_lock_inode+0x1f9e/0x2750 fs/locks.c:1163
> > > > posix_lock_file fs/locks.c:1346 [inline]
> > > > vfs_lock_file fs/locks.c:2314 [inline]
> > > > vfs_lock_file+0xc7/0xf0 fs/locks.c:2309
> > > > do_lock_file_wait.part.0+0xe5/0x260 fs/locks.c:2328
> > > > do_lock_file_wait fs/locks.c:2324 [inline]
> > > > fcntl_setlk+0x2f1/0xfe0 fs/locks.c:2413
> > > > do_fcntl+0x843/0x12b0 fs/fcntl.c:370
> > > > __do_sys_fcntl fs/fcntl.c:463 [inline]
> > > > __se_sys_fcntl fs/fcntl.c:448 [inline]
> > > > __x64_sys_fcntl+0x16d/0x1e0 fs/fcntl.c:448
> > > > do_syscall_64+0x1a3/0x800 arch/x86/entry/common.c:290
> > > > entry_SYSCALL_64_after_hwframe+0x49/0xbe
> > > > RIP: 0033:0x457ec9
> > > > Code: 6d b7 fb ff c3 66 2e 0f 1f 84 00 00 00 00 00 66 90 48 89 f8 48 89 f7
> > > > 48 89 d6 48 89 ca 4d 89 c2 4d 89 c8 4c 8b 4c 24 08 0f 05 <48> 3d 01 f0 ff
> > > > ff 0f 83 3b b7 fb ff c3 66 2e 0f 1f 84 00 00 00 00
> > > > RSP: 002b:00007f58bbb50c78 EFLAGS: 00000246 ORIG_RAX: 0000000000000048
> > > > RAX: ffffffffffffffda RBX: 0000000000000003 RCX: 0000000000457ec9
> > > > RDX: 0000000020000140 RSI: 0000000000000007 RDI: 0000000000000003
> > > > RBP: 000000000073bf00 R08: 0000000000000000 R09: 0000000000000000
> > > > R10: 0000000000000000 R11: 0000000000000246 R12: 00007f58bbb516d4
> > > > R13: 00000000004be5f0 R14: 00000000004ceab0 R15: 00000000ffffffff
> > > >
> > > > Allocated by task 10100:
> > > > 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
> > > > kasan_slab_alloc+0xf/0x20 mm/kasan/common.c:397
> > > > kmem_cache_alloc+0x12d/0x710 mm/slab.c:3541
> > > > kmem_cache_zalloc include/linux/slab.h:730 [inline]
> > > > locks_alloc_lock+0x8e/0x2f0 fs/locks.c:344
> > > > fcntl_setlk+0xa9/0xfe0 fs/locks.c:2362
> > > > do_fcntl+0x843/0x12b0 fs/fcntl.c:370
> > > > __do_sys_fcntl fs/fcntl.c:463 [inline]
> > > > __se_sys_fcntl fs/fcntl.c:448 [inline]
> > > > __x64_sys_fcntl+0x16d/0x1e0 fs/fcntl.c:448
> > > > do_syscall_64+0x1a3/0x800 arch/x86/entry/common.c:290
> > > > entry_SYSCALL_64_after_hwframe+0x49/0xbe
> > > >
> > > > Freed by task 10100:
> > > > 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]
> > > > kmem_cache_free+0x86/0x260 mm/slab.c:3747
> > > > locks_free_lock+0x27a/0x3f0 fs/locks.c:381
> > > > fcntl_setlk+0x7b5/0xfe0 fs/locks.c:2439
> > > > do_fcntl+0x843/0x12b0 fs/fcntl.c:370
> > > > __do_sys_fcntl fs/fcntl.c:463 [inline]
> > > > __se_sys_fcntl fs/fcntl.c:448 [inline]
> > > > __x64_sys_fcntl+0x16d/0x1e0 fs/fcntl.c:448
> > > > 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 ffff88808791b000
> > > > which belongs to the cache file_lock_cache of size 264
> > > > The buggy address is located 0 bytes inside of
> > > > 264-byte region [ffff88808791b000, ffff88808791b108)
> > > > The buggy address belongs to the page:
> > > > page:ffffea00021e46c0 count:1 mapcount:0 mapping:ffff8880aa16a1c0 index:0x0
> > > > flags: 0x1fffc0000000200(slab)
> > > > raw: 01fffc0000000200 ffffea0002333508 ffffea00021d76c8 ffff8880aa16a1c0
> > > > raw: 0000000000000000 ffff88808791b000 000000010000000c 0000000000000000
> > > > page dumped because: kasan: bad access detected
> > > >
> > > > Memory state around the buggy address:
> > > > ffff88808791af00: fb fb fb fb fb fb fb fc fc fc fc fc fc fc fc fc
> > > > ffff88808791af80: fc fc fc fc fc fc fc fc fc fc fc fc fc fc fc fc
> > > > > ffff88808791b000: fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb
> > > > ^
> > > > ffff88808791b080: fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb
> > > > ffff88808791b100: fb fc fc fc fc fc fc fc fc fb fb fb fb fb fb fb
> > > > ==================================================================
> > > >
> > > >
> > >
> > > I've given this a harder look and I really don't quite grok what
> > > this output is telling me:
> > >
> > > All 3 stack traces say they come from PID 10100, but the use-after-free
> > > seems to occur well before the free could have occurred in the context
> > > of the current fcntl call.
> >
> > Interestingly it is the case in all crashes for this bug. It may be
> > something inherent, or maybe just the particular program that
> > triggered this is such that these accesses happen in the same thread.
> >
> > > So, I guess that leaves the possibility that we freed a lock request
> > > from an earlier fcntl call without removing it properly from the tree,
> > > but (a) I don't see how that could happen, _and_ (b) why didn't that
> > > trip the BUG_ONs in locks_free_lock?
> > >
> > > I'll keep looking at this, but I'm a bit stumped at the moment.
> >
> > The simplest repro for this is:
> >
> > # See https://goo.gl/kgGztJ for information about syzkaller reproducers.
> > #{"threaded":true,"collide":true,"repeat":true,"procs":6,"sandbox":"none","fault_call":-1,"tun":true,"tmpdir":true,"cgroups":true,"netdev":true,"resetnet":true,"segv":true}
> > r0 = epoll_create1(0x0)
> > fcntl$lock(r0, 0x7, &(0x7f0000000080))
> > fcntl$lock(r0, 0x7, &(0x7f0000000140)={0x1000000000001, 0x0, 0x1000000})
> >
> > "collide":true means that the 2 fcntl's were executed in parallel. But
> > still the alloc/free/access always happened in the same thread, so the
> > thread interaction seems to be somewhat unusual.
>
> Looking at frequency of this crash, repro properties and some other
> signals my money are on a race/atomicity violation with a narrow
> inconsistency window. E.g. unlock something and then expect things
> have not changed after re-lock, or remove from list and reset a
> pointer few instructions later.
Thanks Dmitry,
The good news is that it's quite reproducible. I used syz-prog2c on the
reproducer and got the attached program (build with -lpthread).
I didn't have KASAN enabled on my throwaway VM, but I got a GPF and
stack trace much like the one above when I ran this on a kernel with the
thundering herd set. A kernel based on a commit from earlier in the
merge window didn't show the problem.
I tested commenting out some lockless shortcuts, but they didn't fix it.
I'll keep playing with it.
Cheers,
--
Jeff Layton <jlayton@...nel.org>
View attachment "repro.c" of type "text/x-csrc" (40894 bytes)
Powered by blists - more mailing lists