lkml.org 
[lkml]   [2021]   [Apr]   [1]   [last100]   RSS Feed
Views: [wrap][no wrap]   [headers]  [forward] 
 
Messages in this thread
    Patch in this message
    /
    Date
    From
    SubjectRe: [syzbot] WARNING in mntput_no_expire (2)
    On Thu, Apr 01, 2021 at 07:46:13PM +0200, Christian Brauner wrote:
    > On Thu, Apr 01, 2021 at 10:09:18AM -0600, Jens Axboe wrote:
    > > On 4/1/21 9:45 AM, Christian Brauner wrote:
    > > > On Thu, Apr 01, 2021 at 02:09:20AM -0700, syzbot wrote:
    > > >> Hello,
    > > >>
    > > >> syzbot found the following issue on:
    > > >>
    > > >> HEAD commit: d19cc4bf Merge tag 'trace-v5.12-rc5' of git://git.kernel.o..
    > > >> git tree: upstream
    > > >> console output: https://syzkaller.appspot.com/x/log.txt?x=1018f281d00000
    > > >> kernel config: https://syzkaller.appspot.com/x/.config?x=d1a3d65a48dbd1bc
    > > >> dashboard link: https://syzkaller.appspot.com/bug?extid=c88a7030da47945a3cc3
    > > >> syz repro: https://syzkaller.appspot.com/x/repro.syz?x=12f50d11d00000
    > > >> C reproducer: https://syzkaller.appspot.com/x/repro.c?x=137694a1d00000
    > > >>
    > > >> IMPORTANT: if you fix the issue, please add the following tag to the commit:
    > > >> Reported-by: syzbot+c88a7030da47945a3cc3@syzkaller.appspotmail.com
    > > >>
    > > >> ------------[ cut here ]------------
    > > >> WARNING: CPU: 1 PID: 8409 at fs/namespace.c:1186 mntput_no_expire+0xaca/0xcb0 fs/namespace.c:1186
    > > >> Modules linked in:
    > > >> CPU: 1 PID: 8409 Comm: syz-executor035 Not tainted 5.12.0-rc5-syzkaller #0
    > > >> Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011
    > > >> RIP: 0010:mntput_no_expire+0xaca/0xcb0 fs/namespace.c:1186
    > > >> Code: ff 48 c7 c2 e0 cb 78 89 be c2 02 00 00 48 c7 c7 a0 cb 78 89 c6 05 e5 6d e5 0b 01 e8 ff e1 f6 06 e9 3f fd ff ff e8 c6 a5 a8 ff <0f> 0b e9 fc fc ff ff e8 ba a5 a8 ff e8 55 dc 94 ff 31 ff 89 c5 89
    > > >> RSP: 0018:ffffc9000165fc78 EFLAGS: 00010293
    > > >> RAX: 0000000000000000 RBX: 1ffff920002cbf95 RCX: 0000000000000000
    > > >> RDX: ffff88802072d4c0 RSI: ffffffff81cb4b8a RDI: 0000000000000003
    > > >> RBP: ffff888011656900 R08: 0000000000000000 R09: ffffffff8fa978af
    > > >> R10: ffffffff81cb4884 R11: 0000000000000000 R12: 0000000000000008
    > > >> R13: ffffc9000165fcc8 R14: dffffc0000000000 R15: 00000000ffffffff
    > > >> FS: 0000000000000000(0000) GS:ffff8880b9d00000(0000) knlGS:0000000000000000
    > > >> CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
    > > >> CR2: 000055a722053160 CR3: 000000000bc8e000 CR4: 00000000001506e0
    > > >> DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
    > > >> DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
    > > >> Call Trace:
    > > >> mntput fs/namespace.c:1232 [inline]
    > > >> cleanup_mnt+0x523/0x530 fs/namespace.c:1132
    > > >> task_work_run+0xdd/0x1a0 kernel/task_work.c:140
    > > >> exit_task_work include/linux/task_work.h:30 [inline]
    > > >> do_exit+0xbfc/0x2a60 kernel/exit.c:825
    > > >> do_group_exit+0x125/0x310 kernel/exit.c:922
    > > >> __do_sys_exit_group kernel/exit.c:933 [inline]
    > > >> __se_sys_exit_group kernel/exit.c:931 [inline]
    > > >> __x64_sys_exit_group+0x3a/0x50 kernel/exit.c:931
    > > >> do_syscall_64+0x2d/0x70 arch/x86/entry/common.c:46
    > > >> entry_SYSCALL_64_after_hwframe+0x44/0xae
    > > >> RIP: 0033:0x446af9
    > > >> Code: Unable to access opcode bytes at RIP 0x446acf.
    > > >> RSP: 002b:00000000005dfe48 EFLAGS: 00000246 ORIG_RAX: 00000000000000e7
    > > >> RAX: ffffffffffffffda RBX: 00000000004ce450 RCX: 0000000000446af9
    > > >> RDX: 000000000000003c RSI: 00000000000000e7 RDI: 0000000000000001
    > > >> RBP: 0000000000000001 R08: ffffffffffffffbc R09: 0000000000000000
    > > >> R10: 0000000000000000 R11: 0000000000000246 R12: 00000000004ce450
    > > >> R13: 0000000000000001 R14: 0000000000000000 R15: 0000000000000001
    > > >
    > > > [+Cc Jens + io_uring]
    > > >
    > > > Hm, this reproducer uses io_uring and it's the io_uring_enter() that
    > > > triggers this reliably. With this reproducer I've managed to reproduce
    > > > the issue on v5.12-rc4, and v5.12-rc3, v5.12-rc2 and v5.12-rc1.
    > > > It's not reproducible at
    > > > 9820b4dca0f9c6b7ab8b4307286cdace171b724d
    > > > which is the commit immediately before the first v5.12 io_uring merge.
    > > > It's first reproducible with the first io_uring merge for v5.12, i.e.
    > > > 5bbb336ba75d95611a7b9456355b48705016bdb1
    > >
    > > Thanks, that's good info. I'll take a look at it and see if I can
    > > reproduce.
    >
    > Ok, I was deep into this anyway and it didn't make much sense to do
    > anything else at that point so I bisected this a bit further. The first
    > bad commit is:
    >
    > commit 3a81fd02045c329f25e5900fa61f613c9b317644
    > Author: Jens Axboe <axboe@kernel.dk>
    > Date: Thu Dec 10 12:25:36 2020 -0700
    >
    > io_uring: enable LOOKUP_CACHED path resolution for filename lookups
    >
    > Instead of being pessimistic and assume that path lookup will block, use
    > LOOKUP_CACHED to attempt just a cached lookup. This ensures that the
    > fast path is always done inline, and we only punt to async context if
    > IO is needed to satisfy the lookup.
    >
    > For forced nonblock open attempts, mark the file O_NONBLOCK over the
    > actual ->open() call as well. We can safely clear this again before
    > doing fd_install(), so it'll never be user visible that we fiddled with
    > it.
    >
    > This greatly improves the performance of file open where the dentry is
    > already cached:
    >
    > ached 5.10-git 5.10-git+LOOKUP_CACHED Speedup
    > ---------------------------------------------------------------
    > 33% 1,014,975 900,474 1.1x
    > 89% 545,466 292,937 1.9x
    > 100% 435,636 151,475 2.9x
    >
    > The more cache hot we are, the faster the inline LOOKUP_CACHED
    > optimization helps. This is unsurprising and expected, as a thread
    > offload becomes a more dominant part of the total overhead. If we look
    > at io_uring tracing, doing an IORING_OP_OPENAT on a file that isn't in
    > the dentry cache will yield:
    >
    > 275.550481: io_uring_create: ring 00000000ddda6278, fd 3 sq size 8, cq size 16, flags 0
    > 275.550491: io_uring_submit_sqe: ring 00000000ddda6278, op 18, data 0x0, non block 1, sq_thread 0
    > 275.550498: io_uring_queue_async_work: ring 00000000ddda6278, request 00000000c0267d17, flags 69760, normal queue, work 000000003d683991
    > 275.550502: io_uring_cqring_wait: ring 00000000ddda6278, min_events 1
    > 275.550556: io_uring_complete: ring 00000000ddda6278, user_data 0x0, result 4
    >
    > which shows a failed nonblock lookup, then punt to worker, and then we
    > complete with fd == 4. This takes 65 usec in total. Re-running the same
    > test case again:
    >
    > 281.253956: io_uring_create: ring 0000000008207252, fd 3 sq size 8, cq size 16, flags 0
    > 281.253967: io_uring_submit_sqe: ring 0000000008207252, op 18, data 0x0, non block 1, sq_thread 0
    > 281.253973: io_uring_complete: ring 0000000008207252, user_data 0x0, result 4
    >
    > shows the same request completing inline, also returning fd == 4. This
    > takes 6 usec.
    >
    > Signed-off-by: Jens Axboe <axboe@kernel.dk>

    I _think_ I see what the issue is. It seems that an assumption made in
    this commit might be wrong and we're missing a mnt_add_count() bump that
    we would otherwise have gotten if we've moved the failure handling into
    the unlazy helpers themselves.

    Al, does that sound plausible?

    commit eacd9aa8cedeb412842c7b339adbaa0477fdd5ad
    Author: Al Viro <viro@zeniv.linux.org.uk>
    Date: Mon Feb 15 12:03:23 2021 -0500

    fix handling of nd->depth on LOOKUP_CACHED failures in try_to_unlazy*

    After switching to non-RCU mode, we want nd->depth to match the number
    of entries in nd->stack[] that need eventual path_put().
    legitimize_links() takes care of that on failures; unfortunately,
    failure exits added for LOOKUP_CACHED do not.

    We could add the logics for that into those failure exits, both in
    try_to_unlazy() and in try_to_unlazy_next(), but since both checks
    are immediately followed by legitimize_links() and there's no calls
    of legitimize_links() other than those two... It's easier to
    move the check (and required handling of nd->depth on failure) into
    legitimize_links() itself.

    [caught by Jens: ... and since we are zeroing ->depth here, we need
    to do drop_links() first]

    Fixes: 6c6ec2b0a3e0 "fs: add support for LOOKUP_CACHED"
    Tested-by: Jens Axboe <axboe@kernel.dk>
    Signed-off-by: Al Viro <viro@zeniv.linux.org.uk>

    diff --git a/fs/namei.c b/fs/namei.c
    index 4cae88733a5c..de74ad2bc6e2 100644
    --- a/fs/namei.c
    +++ b/fs/namei.c
    @@ -630,6 +630,11 @@ static inline bool legitimize_path(struct nameidata *nd,
    static bool legitimize_links(struct nameidata *nd)
    {
    int i;
    + if (unlikely(nd->flags & LOOKUP_CACHED)) {
    + drop_links(nd);
    + nd->depth = 0;
    + return false;
    + }
    for (i = 0; i < nd->depth; i++) {
    struct saved *last = nd->stack + i;
    if (unlikely(!legitimize_path(nd, &last->link, last->seq))) {
    @@ -686,8 +691,6 @@ static bool try_to_unlazy(struct nameidata *nd)
    BUG_ON(!(nd->flags & LOOKUP_RCU));

    nd->flags &= ~LOOKUP_RCU;
    - if (nd->flags & LOOKUP_CACHED)
    - goto out1;
    if (unlikely(!legitimize_links(nd)))
    goto out1;
    if (unlikely(!legitimize_path(nd, &nd->path, nd->seq)))
    @@ -724,8 +727,6 @@ static bool try_to_unlazy_next(struct nameidata *nd, struct dentry *dentry, unsi
    BUG_ON(!(nd->flags & LOOKUP_RCU));

    nd->flags &= ~LOOKUP_RCU;
    - if (nd->flags & LOOKUP_CACHED)
    - goto out2;
    if (unlikely(!legitimize_links(nd)))
    goto out2;
    if (unlikely(!legitimize_mnt(nd->path.mnt, nd->m_seq)))
    \
     
     \ /
      Last update: 2021-04-01 20:40    [W:4.447 / U:0.348 seconds]
    ©2003-2020 Jasper Spaans|hosted at Digital Ocean and TransIP|Read the blog|Advertise on this site