Re: fs: NULL deref in atime_needs_update

[Dmitry Vyukov <dvyukov@google.com>]

On Mon, Feb 22, 2016 at 6:23 PM, Al Viro <viro@zeniv.linux.org.uk> wrote:
> On Mon, Feb 22, 2016 at 12:20:30PM +0100, Dmitry Vyukov wrote:
>
>> I've reproduced the second report (the one originating in openat) with
>> this patch and the WARNING did _not_ fire:
>
> Lovely...  Could you dump your inode.o on anonftp somewhere?  Or post
> the disassembled atime_needs_update, for that matter - shouldn't be
> all that long...  .config (and gcc version) you are using would also be nice.
>
> On the face of it, NULL inode is a plausible source of that one, but
> it's _very_ odd.  It would have to be NULL ->link_inode, and since the
> warning hadn't triggered, there was a successful should_follow_link(),
> with NULL inode argument.
>
>         Could you slap WARN_ON(!inode) in pick_link()?  Or even
> WARN_ON(IS_ERR_OR_NULL(inode)), for that matter...


I was able to reproduce the crash on vanilla kernel (no KASAN, no
KCOV) with the new WARNING, this one does fire.

So I am on commit 4de8ebeff8ddefaceeb7fc6a9b1a514fc9624509 (Feb 22), with:

$ git diff
diff --git a/fs/namei.c b/fs/namei.c
index f624d13..9675e9e 100644
--- a/fs/namei.c
+++ b/fs/namei.c
@@ -1669,6 +1669,7 @@ static int pick_link(struct nameidata *nd,
struct path *link,
 {
        int error;
        struct saved *last;
+       WARN_ON(IS_ERR_OR_NULL(inode));
        if (unlikely(nd->total_link_count++ >= MAXSYMLINKS)) {
                path_to_nameidata(link, nd);
                return -ELOOP;
@@ -3273,6 +3274,10 @@ opened:
                        goto exit_fput;
        }
 out:
+       if (unlikely(error > 0)) {
+               WARN_ON(1);
+               error = -EINVAL;
+       }
        if (got_write)
                mnt_drop_write(nd->path.mnt);
        path_put(&save_parent);


The crash:

[ 8095.048336] ------------[ cut here ]------------
[ 8095.048864] WARNING: CPU: 3 PID: 5532 at fs/namei.c:1672
should_follow_link.part.25+0x55/0x21a()
[ 8095.049830] Modules linked in:
[ 8095.050155] CPU: 3 PID: 5532 Comm: syz-executor Not tainted 4.5.0-rc5+ #69
[ 8095.050760] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996),
BIOS Bochs 01/01/2011
[ 8095.051104]  0000000000000000 ffff8800005ffc78 ffffffff8194e5f9
0000000000000000
[ 8095.051649]  ffffffff8334c24c ffff8800005ffcb0 ffffffff81172291
ffff8800005ffde0
[ 8095.051649]  ffff8800005ffd98 0000000000048000 ffff8800005ffde0
ffff8800005ffefc
[ 8095.051649] Call Trace:
[ 8095.051649]  [<ffffffff8194e5f9>] dump_stack+0x99/0xd0
[ 8095.054784]  [<ffffffff81172291>] warn_slowpath_common+0x81/0xc0
[ 8095.054784]  [<ffffffff81172385>] warn_slowpath_null+0x15/0x20
[ 8095.054784]  [<ffffffff8185a55c>] should_follow_link.part.25+0x55/0x21a
[ 8095.054784]  [<ffffffff813180c9>] path_openat+0x1229/0x1500
[ 8095.057172]  [<ffffffff813193d9>] do_filp_open+0x79/0xd0
[ 8095.057172]  [<ffffffff82b170c2>] ? _raw_spin_unlock+0x22/0x30
[ 8095.057172]  [<ffffffff81328d98>] ? __alloc_fd+0xf8/0x200
[ 8095.058364]  [<ffffffff81306eb0>] do_sys_open+0x110/0x1f0
[ 8095.058364]  [<ffffffff81306fbf>] SyS_openat+0xf/0x20
[ 8095.058364]  [<ffffffff82b17b76>] entry_SYSCALL_64_fastpath+0x16/0x7a
[ 8095.060124] ---[ end trace 50e32daa426e4c92 ]---
[ 8095.060526] BUG: unable to handle kernel NULL pointer dereference
at 000000000000000c
[ 8095.061111] IP: [<ffffffff813272b9>] atime_needs_update+0x9/0xc0
[ 8095.061549] PGD 6ae6e067 PUD 6ae6a067 PMD 0
[ 8095.061549] Oops: 0000 [#1] SMP DEBUG_PAGEALLOC
[ 8095.061549] Modules linked in:
[ 8095.061549] CPU: 3 PID: 5532 Comm: syz-executor Tainted: G        W
      4.5.0-rc5+ #69
[ 8095.061549] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996),
BIOS Bochs 01/01/2011
[ 8095.061549] task: ffff88002bc00000 ti: ffff8800005fc000 task.ti:
ffff8800005fc000
[ 8095.061549] RIP: 0010:[<ffffffff813272b9>]  [<ffffffff813272b9>]
atime_needs_update+0x9/0xc0
[ 8095.061549] RSP: 0018:ffff8800005ffcb0  EFLAGS: 00010282
[ 8095.061549] RAX: 0000000000000030 RBX: ffff8800005ffde0 RCX: 0000000000000000
[ 8095.061549] RDX: ffff8800005ffe38 RSI: 0000000000000000 RDI: ffff8800005ffe38
[ 8095.061549] RBP: ffff8800005ffcc0 R08: 0000000000000002 R09: 0000000000000001
[ 8095.061549] R10: 0000000000000001 R11: 0000000000001828 R12: 0000000000000000
[ 8095.061549] R13: ffff8800005ffe38 R14: ffff880031950be0 R15: ffff8800005ffefc
[ 8095.061549] FS:  00007fc3bf2ee700(0000) GS:ffff88007f900000(0000)
knlGS:0000000000000000
[ 8095.069746] CS:  0010 DS: 0000 ES: 0000 CR0: 000000008005003b
[ 8095.069746] CR2: 000000000000000c CR3: 000000006b982000 CR4: 00000000000006e0
[ 8095.071108] Stack:
[ 8095.071538]  ffff8800005ffcc0 ffff8800005ffde0 ffff8800005ffd00
ffffffff81314ca2
[ 8095.072227]  0000000200000002 0000000000000005 ffff8800005ffd98
0000000000048000
[ 8095.072227]  ffff8800005ffde0 ffff8800005ffefc ffff8800005ffdd0
ffffffff81317173
[ 8095.072227] Call Trace:
[ 8095.072227]  [<ffffffff81314ca2>] trailing_symlink+0x62/0x260
[ 8095.072227]  [<ffffffff81317173>] path_openat+0x2d3/0x1500
[ 8095.072227]  [<ffffffff813193d9>] do_filp_open+0x79/0xd0
[ 8095.072227]  [<ffffffff82b170c2>] ? _raw_spin_unlock+0x22/0x30
[ 8095.072227]  [<ffffffff81328d98>] ? __alloc_fd+0xf8/0x200
[ 8095.072227]  [<ffffffff81306eb0>] do_sys_open+0x110/0x1f0
[ 8095.072227]  [<ffffffff81306fbf>] SyS_openat+0xf/0x20
[ 8095.072227]  [<ffffffff82b17b76>] entry_SYSCALL_64_fastpath+0x16/0x7a
[ 8095.072227] Code: ff ff ff 48 85 c0 48 89 c3 74 08 48 89 c7 e8 ef
dc ff ff 48 89 d8 5b 5d c3 66 0f 1f 84 00 00 00 00 00 55 48 89 e5 53
48 83 ec 08 <f6> 46 0c 02 48 8b 1f 75 6b 48 8b 7e 28 48 8b 47 50 a9 01
04 00
[ 8095.072227] RIP  [<ffffffff813272b9>] atime_needs_update+0x9/0xc0
[ 8095.072227]  RSP <ffff8800005ffcb0>
[ 8095.072227] CR2: 000000000000000c
[ 8095.116838] ---[ end trace 50e32daa426e4c93 ]---
[ 8095.116838] BUG: sleeping function called from invalid context at
include/linux/sched.h:2795
[ 8095.116838] in_atomic(): 1, irqs_disabled(): 1, pid: 5532, name: syz-executor
[ 8095.116838] INFO: lockdep is turned off.
[ 8095.116838] irq event stamp: 636
[ 8095.116838] hardirqs last  enabled at (635): [<ffffffff811d9926>]
vprintk_emit+0x2d6/0x5f0
[ 8095.116838] hardirqs last disabled at (636): [<ffffffff82b1a089>]
error_entry+0x69/0xc0
[ 8095.116838] softirqs last  enabled at (632): [<ffffffff81178172>]
__do_softirq+0x222/0x4a0
[ 8095.116838] softirqs last disabled at (623): [<ffffffff81178767>]
irq_exit+0xa7/0xc0
[ 8095.116838] CPU: 3 PID: 5532 Comm: syz-executor Tainted: G      D W
      4.5.0-rc5+ #69
[ 8095.116838] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996),
BIOS Bochs 01/01/2011
[ 8095.116838]  0000000000000000 ffff8800005ff9a8 ffffffff8194e5f9
ffff88002bc00000
[ 8095.116838]  000000000000159c ffff8800005ff9d0 ffffffff811a0659
ffffffff832a29c3
[ 8095.116838]  0000000000000aeb 0000000000000000 ffff8800005ff9f8
ffffffff811a0764
[ 8095.116838] Call Trace:
[ 8095.116838]  [<ffffffff8194e5f9>] dump_stack+0x99/0xd0
[ 8095.116838]  [<ffffffff811a0659>] ___might_sleep+0x179/0x240
[ 8095.116838]  [<ffffffff811a0764>] __might_sleep+0x44/0x80
[ 8095.116838]  [<ffffffff811842cf>] exit_signals+0x1f/0x130
[ 8095.116838]  [<ffffffff811756ef>] do_exit+0xbf/0xd10
[ 8095.116838]  [<ffffffff811da524>] ? kmsg_dump+0x104/0x180
[ 8095.116838]  [<ffffffff8108549f>] oops_end+0x9f/0xe0
[ 8095.116838]  [<ffffffff810ce6e8>] no_context+0x108/0x390
[ 8095.116838]  [<ffffffff811d7837>] ? print_time.part.13+0x67/0x90
[ 8095.116838]  [<ffffffff810cea8d>] __bad_area_nosemaphore+0x11d/0x220
[ 8095.116838]  [<ffffffff810ceb9e>] bad_area_nosemaphore+0xe/0x10
[ 8095.116838]  [<ffffffff810cf2c4>] __do_page_fault+0x84/0x470
[ 8095.116838]  [<ffffffff810cf764>] trace_do_page_fault+0x74/0x2c0
[ 8095.116838]  [<ffffffff810c9ba4>] do_async_page_fault+0x14/0x90
[ 8095.116838]  [<ffffffff82b19eb8>] async_page_fault+0x28/0x30
[ 8095.116838]  [<ffffffff813272b9>] ? atime_needs_update+0x9/0xc0
[ 8095.116838]  [<ffffffff81314ca2>] trailing_symlink+0x62/0x260
[ 8095.116838]  [<ffffffff81317173>] path_openat+0x2d3/0x1500
[ 8095.116838]  [<ffffffff813193d9>] do_filp_open+0x79/0xd0
[ 8095.116838]  [<ffffffff82b170c2>] ? _raw_spin_unlock+0x22/0x30
[ 8095.116838]  [<ffffffff81328d98>] ? __alloc_fd+0xf8/0x200
[ 8095.116838]  [<ffffffff81306eb0>] do_sys_open+0x110/0x1f0
[ 8095.116838]  [<ffffffff81306fbf>] SyS_openat+0xf/0x20
[ 8095.116838]  [<ffffffff82b17b76>] entry_SYSCALL_64_fastpath+0x16/0x7a
[ 8095.195133] note: syz-executor[5532] exited with preempt_count 1


And here is my inode.o:
https://gist.githubusercontent.com/dvyukov/27ec88c2c1a83c2e0f38/raw/2514d0ddd7720a978e6a2f67c2dcb391046ce0e7/gistfile1.txt

This can be reproduced following the instructions here:
https://github.com/google/syzkaller/wiki/How-to-execute-syzkaller-programs
Using this command line:
# ./syz-execprog -cover=0 -procs=60 -repeat=0 prog
with the following program:
https://gist.githubusercontent.com/dvyukov/fc026f36f9f76d1a440b/raw/0e133afa99eb7de45880523fbd48256cd2ae4a6c/gistfile1.txt
(requires CONFIG_USER_NS=y). The crash triggers after hours of execution.