From mboxrd@z Thu Jan  1 00:00:00 1970
Return-Path: <linux-kernel-owner@vger.kernel.org>
Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand
        id S1753029AbcHUL5R (ORCPT <rfc822;w@1wt.eu>);
        Sun, 21 Aug 2016 07:57:17 -0400
Received: from aserp1050.oracle.com ([141.146.126.70]:43248 "EHLO
        aserp1050.oracle.com" rhost-flags-OK-OK-OK-OK) by vger.kernel.org
        with ESMTP id S1751722AbcHUL5P (ORCPT
        <rfc822;linux-kernel@vger.kernel.org>);
        Sun, 21 Aug 2016 07:57:15 -0400
From: Vegard Nossum <vegard.nossum@oracle.com>
Subject: 9p2000.L stat/unlink race (WARNING: fs/inode.c:280 drop_nlink)
To: Eric Van Hensbergen <ericvh@gmail.com>,
        Ron Minnich <rminnich@sandia.gov>, Latchesar Ionkov <lucho@ionkov.net>,
        Al Viro <viro@zeniv.linux.org.uk>
Cc: v9fs-developer@lists.sourceforge.net, linux-fsdevel@vger.kernel.org,
        LKML <linux-kernel@vger.kernel.org>
Message-ID: <c2eacc98-b0d7-7588-7f11-316080e19e40@oracle.com>
Date: Sun, 21 Aug 2016 13:55:43 +0200
User-Agent: Mozilla/5.0 (X11; Linux x86_64; rv:45.0) Gecko/20100101
 Thunderbird/45.2.0
MIME-Version: 1.0
Content-Type: text/plain; charset=utf-8; format=flowed
Content-Transfer-Encoding: 7bit
X-Source-IP: aserp1040.oracle.com [141.146.126.69]
Sender: linux-kernel-owner@vger.kernel.org
List-ID: <linux-kernel.vger.kernel.org>
X-Mailing-List: linux-kernel@vger.kernel.org

Hi,

I've been seeing this:

------------[ cut here ]------------
WARNING: CPU: 0 PID: 2377 at fs/inode.c:280 drop_nlink+0xc2/0x120
Kernel panic - not syncing: panic_on_warn set ...

CPU: 0 PID: 2377 Comm: syz-executor Not tainted 4.8.0-rc2+ #145
Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 
rel-1.9.3-0-ge2fc41e-prebuilt.qemu-project.org 04/01/2014
  0000000000000000 ffff880116437b50 ffffffff81f9f201 ffffffff83e72d60
  ffff880116437c28 ffffffff83ef6100 ffffffff847070c0 ffff880116437c18
  ffffffff8150538a 0000000041b58ab3 ffffffff844dc5dd ffffffff815051a7
Call Trace:
  [<ffffffff81f9f201>] dump_stack+0x83/0xb2
  [<ffffffff8150538a>] panic+0x1e3/0x3a1
  [<ffffffff815051a7>] ? set_ti_thread_flag+0x1e/0x1e
  [<ffffffff81505a58>] ? rt_mutex_top_waiter.part.10+0x6/0x6
  [<ffffffff83a4af46>] ? p9_idpool_put+0x36/0x40
  [<ffffffff816c85d2>] ? drop_nlink+0xc2/0x120
  [<ffffffff8126df4f>] __warn+0x1bf/0x1e0
  [<ffffffff8126e13c>] warn_slowpath_null+0x2c/0x40
  [<ffffffff816c85d2>] drop_nlink+0xc2/0x120
  [<ffffffff81b17106>] v9fs_remove+0x256/0x2d0
  [<ffffffff81b1719f>] v9fs_vfs_unlink+0x1f/0x30
  [<ffffffff816a7130>] vfs_unlink+0x2b0/0x490
  [<ffffffff816a7840>] do_unlinkat+0x530/0x660
  [<ffffffff816a7310>] ? vfs_unlink+0x490/0x490
  [<ffffffff81002f2f>] ? syscall_trace_enter+0x3cf/0xdb0
  [<ffffffff8150465a>] ? __context_tracking_exit.part.4+0x9a/0x1e0
  [<ffffffff81002b60>] ? exit_to_usermode_loop+0x190/0x190
  [<ffffffff82001b07>] ? check_preemption_disabled+0x37/0x1e0
  [<ffffffff82001cec>] ? __this_cpu_preempt_check+0x1c/0x20
  [<ffffffff816a79f0>] ? SyS_unlinkat+0x80/0x80
  [<ffffffff816a7a0a>] SyS_unlink+0x1a/0x20
  [<ffffffff81005524>] do_syscall_64+0x1c4/0x4e0
  [<ffffffff83c3286a>] entry_SYSCALL64_slow_path+0x25/0x25

It seems to happen when fstat() calls into v9fs_vfs_getattr_dotl() and
that does a v9fs_stat2inode_dotl() which changes inode->i_nlink from 1
to 0 (without any locking). The unlink() which was already in progress
then sees 0 when it does drop_nlink().

My mount flags are:

   trans=virtio,version=9p2000.L

If I add "cache=loose" then there is no warning (as expected, since
v9fs_vfs_getattr_dotl() bails out early in that case and doesn't change
the in-memory inode).


Vegard