Add more checks to _check_dmesg
PATCH 1/1 Add more checks to _check_dmesg
From: Filipe Manana <[email protected]>
Teach _check_dmesg to look for improper RCU usage and circular locking dependency messages. It's useful to check for these as they might point to a real problem in the filesystem's implementation (or the current implementation just confuses the checker, probably worth simplifying the filesystem's implementation).
Currently the test btrfs/071 for example triggers such warnings:
[ 912.924839] ===============================
[ 912.925617] [ INFO: suspicious RCU usage. ]
[ 912.926394] 4.3.0-rc5-btrfs-next-17+ #1 Not tainted
[ 912.927274] -------------------------------
[ 912.928364] fs/btrfs/volumes.c:1977 suspicious rcu_dereference_check() usage!
[ 912.929626]
[ 912.929626] other info that might help us debug this:
[ 912.929626]
[ 912.931197]
[ 912.931197] rcu_scheduler_active = 1, debug_locks = 1
[ 912.933822] 4 locks held by btrfs/6400:
[ 912.934558] #0: (&fs_info->dev_replace.lock_finishing_cancel_unmount){+.+...}, at: [<ffffffffa046a193>] btrfs_dev_replace_finishing+0x3e/0x696 [btrfs]
[ 912.948929] #1: (uuid_mutex){+.+.+.}, at: [<ffffffffa046a24a>] btrfs_dev_replace_finishing+0xf5/0x696 [btrfs]
[ 912.950987] #2: (&fs_devs->device_list_mutex){+.+.+.}, at: [<ffffffffa046a263>] btrfs_dev_replace_finishing+0x10e/0x696 [btrfs]
[ 912.953265] #3: (&fs_info->chunk_mutex){+.+...}, at: [<ffffffffa046a278>] btrfs_dev_replace_finishing+0x123/0x696 [btrfs](...)
[ 912.987973] ======================================================
[ 912.989242] [ INFO: possible circular locking dependency detected ]
[ 912.990583] 4.3.0-rc5-btrfs-next-17+ #1 Not tainted
[ 912.990801] -------------------------------------------------------
[ 912.990801] btrfs/6400 is trying to acquire lock:
[ 912.990801] (&bdev->bd_mutex){+.+.+.}, at: [<ffffffff8119d202>] __blkdev_get+0xa3/0x3d9
[ 912.990801]
[ 912.990801] but task is already holding lock:
[ 912.990801] (&fs_info->chunk_mutex){+.+.+.}, at: [<ffffffffa046a278>] btrfs_dev_replace_finishing+0x123/0x696 [btrfs]
[ 912.990801]
[ 912.990801] which lock already depends on the new lock.
[ 912.990801]
[ 912.990801]
[ 912.990801] the existing dependency chain (in reverse order) is:(...)
Signed-off-by Filipe Manana <[email protected]>
--- common/rc | 2 ++ 1 file changed, 2 insertions(+)
common/rc +2 -0
@@ -3055,6 +3055,8 @@ _check_dmesg() -e "Oops:" \ -e "possible recursive locking detected" \ -e "Internal error" \ + -e "INFO: suspicious RCU usage" \ + -e "INFO: possible circular locking dependency detected" \ $seqres.dmesg if [ $? -eq 0 ]; then echo "_check_dmesg: something found in dmesg (see $seqres.dmesg)"
Signature · 1 line
2.1.3
Quoted 41 lines · On Wed, Nov 18, 2015 at 04:10:03PM +0000, [email protected] wrote:
From: Filipe Manana <[email protected]>
Teach
_check_dmesgto look for improper RCU usage and circular locking dependency messages. It's useful to check for these as they might point to a real problem in the filesystem's implementation (or the current implementation just confuses the checker, probably worth simplifying the filesystem's implementation).Currently the test btrfs/071 for example triggers such warnings:
[ 912.924839] =============================== [ 912.925617] [ INFO: suspicious RCU usage. ] [ 912.926394] 4.3.0-rc5-btrfs-next-17+ #1 Not tainted [ 912.927274] ------------------------------- [ 912.928364] fs/btrfs/volumes.c:1977 suspicious rcu_dereference_check() usage! [ 912.929626] [ 912.929626] other info that might help us debug this: [ 912.929626] [ 912.931197] [ 912.931197] rcu_scheduler_active = 1, debug_locks = 1 [ 912.933822] 4 locks held by btrfs/6400: [ 912.934558] #0: (&fs_info->dev_replace.lock_finishing_cancel_unmount){+.+...}, at: [<ffffffffa046a193>] btrfs_dev_replace_finishing+0x3e/0x696 [btrfs] [ 912.948929] #1: (uuid_mutex){+.+.+.}, at: [<ffffffffa046a24a>] btrfs_dev_replace_finishing+0xf5/0x696 [btrfs] [ 912.950987] #2: (&fs_devs->device_list_mutex){+.+.+.}, at: [<ffffffffa046a263>] btrfs_dev_replace_finishing+0x10e/0x696 [btrfs] [ 912.953265] #3: (&fs_info->chunk_mutex){+.+...}, at: [<ffffffffa046a278>] btrfs_dev_replace_finishing+0x123/0x696 [btrfs](...)
[ 912.987973] ====================================================== [ 912.989242] [ INFO: possible circular locking dependency detected ] [ 912.990583] 4.3.0-rc5-btrfs-next-17+ #1 Not tainted [ 912.990801] ------------------------------------------------------- [ 912.990801] btrfs/6400 is trying to acquire lock: [ 912.990801] (&bdev->bd_mutex){+.+.+.}, at: [<ffffffff8119d202>] __blkdev_get+0xa3/0x3d9 [ 912.990801] [ 912.990801] but task is already holding lock: [ 912.990801] (&fs_info->chunk_mutex){+.+.+.}, at: [<ffffffffa046a278>] btrfs_dev_replace_finishing+0x123/0x696 [btrfs] [ 912.990801] [ 912.990801] which lock already depends on the new lock. [ 912.990801] [ 912.990801] [ 912.990801] the existing dependency chain (in reverse order) is:
Quoted 3 lines
(...)
Signed-off-by Filipe Manana <[email protected]>
Makes sense to me.
Reviewed-by Eryu Guan <[email protected]>
Quoted 24 lines
--- common/rc | 2 ++ 1 file changed, 2 insertions(+)common/rc +2
-0@@ -3055,6 +3055,8 @@ _check_dmesg() -e "Oops:" \ -e "possible recursive locking detected" \ -e "Internal error" \ + -e "INFO: suspicious RCU usage" \ + -e "INFO: possible circular locking dependency detected" \ $seqres.dmesg if [ $? -eq 0 ]; then echo "_check_dmesg: something found in dmesg (see $seqres.dmesg)"Signature · 6 lines
2.1.3 -- To unsubscribe from this list: send the line "unsubscribe fstests" in the body of a message to [email protected] More majordomo info at http://vger.kernel.org/majordomo-info.html