[btrfs?] possible deadlock in btrfs_scrub_dev

[syzbot]

Hello,

syzbot found the following issue on:

HEAD commit: c4215ee4771b Linux 4.14.302
git tree: linux-4.14.y
console output: https://syzkaller.appspot.com/x/log.txt?x=1264b863880000
kernel config: https://syzkaller.appspot.com/x/.config?x=4a9988fe055c9527
dashboard link: https://syzkaller.appspot.com/bug?extid=b1a530302b8cbd3b85d7
compiler: gcc version 10.2.1 20210110 (Debian 10.2.1-6)

Unfortunately, I don't have any reproducer for this issue yet.

Downloadable assets:
disk image: https://storage.googleapis.com/syzbot-assets/c93ba055d204/disk-c4215ee4.raw.xz
vmlinux: https://storage.googleapis.com/syzbot-assets/bfbc929a33c1/vmlinux-c4215ee4.xz
kernel image: https://storage.googleapis.com/syzbot-assets/444658051770/bzImage-c4215ee4.xz

IMPORTANT: if you fix the issue, please add the following tag to the commit:
Reported-by: syzbot+b1a530...@syzkaller.appspotmail.com

netlink: 16 bytes leftover after parsing attributes in process `syz-executor.0'.
BTRFS: device fsid 24c7a497-3402-47dd-bef8-82358f5f30e0 devid 1 transid 8 /dev/loop3
BTRFS info (device loop3): using free space tree
BTRFS info (device loop3): has skinny extents
======================================================
WARNING: possible circular locking dependency detected
4.14.302-syzkaller #0 Not tainted
------------------------------------------------------
syz-executor.3/9543 is trying to acquire lock:
("%s-%s""btrfs", name){+.+.}, at: [<ffffffff8135cb6b>] flush_workqueue+0xcb/0x1310 kernel/workqueue.c:2622

but task is already holding lock:
(&fs_info->scrub_lock){+.+.}, at: [<ffffffff82b1ba96>] btrfs_scrub_dev+0x506/0xcd0 fs/btrfs/scrub.c:4217

which lock already depends on the new lock.


the existing dependency chain (in reverse order) is:

-> #3 (&fs_info->scrub_lock){+.+.}:
__mutex_lock_common kernel/locking/mutex.c:756 [inline]
__mutex_lock+0xc4/0x1310 kernel/locking/mutex.c:893
btrfs_scrub_dev+0x1f3/0xcd0 fs/btrfs/scrub.c:4150
btrfs_ioctl_scrub fs/btrfs/ioctl.c:4451 [inline]
btrfs_ioctl+0xba8/0x5b20 fs/btrfs/ioctl.c:5681
vfs_ioctl fs/ioctl.c:46 [inline]
file_ioctl fs/ioctl.c:500 [inline]
do_vfs_ioctl+0x75a/0xff0 fs/ioctl.c:684
SYSC_ioctl fs/ioctl.c:701 [inline]
SyS_ioctl+0x7f/0xb0 fs/ioctl.c:692
do_syscall_64+0x1d5/0x640 arch/x86/entry/common.c:292
entry_SYSCALL_64_after_hwframe+0x5e/0xd3

-> #2 (&fs_devs->device_list_mutex){+.+.}:
__mutex_lock_common kernel/locking/mutex.c:756 [inline]
__mutex_lock+0xc4/0x1310 kernel/locking/mutex.c:893
__reada_start_machine fs/btrfs/reada.c:765 [inline]
reada_start_machine_worker+0x1d2/0xa90 fs/btrfs/reada.c:746
normal_work_helper+0x304/0x1330 fs/btrfs/async-thread.c:376
process_one_work+0x793/0x14a0 kernel/workqueue.c:2117
worker_thread+0x5cc/0xff0 kernel/workqueue.c:2251
kthread+0x30d/0x420 kernel/kthread.c:232
ret_from_fork+0x24/0x30 arch/x86/entry/entry_64.S:406

-> #1 ((&work->normal_work)){+.+.}:
process_one_work+0x736/0x14a0 kernel/workqueue.c:2093
worker_thread+0x5cc/0xff0 kernel/workqueue.c:2251
kthread+0x30d/0x420 kernel/kthread.c:232
ret_from_fork+0x24/0x30 arch/x86/entry/entry_64.S:406

-> #0 ("%s-%s""btrfs", name){+.+.}:
lock_acquire+0x170/0x3f0 kernel/locking/lockdep.c:3998
flush_workqueue+0xfa/0x1310 kernel/workqueue.c:2625
drain_workqueue+0x177/0x3e0 kernel/workqueue.c:2790
destroy_workqueue+0x71/0x710 kernel/workqueue.c:4116
__btrfs_destroy_workqueue fs/btrfs/async-thread.c:436 [inline]
btrfs_destroy_workqueue+0xf8/0x630 fs/btrfs/async-thread.c:447
scrub_workers_put+0x90/0x1a0 fs/btrfs/scrub.c:4075
btrfs_scrub_dev+0x536/0xcd0 fs/btrfs/scrub.c:4219
btrfs_ioctl_scrub fs/btrfs/ioctl.c:4451 [inline]
btrfs_ioctl+0xba8/0x5b20 fs/btrfs/ioctl.c:5681
vfs_ioctl fs/ioctl.c:46 [inline]
file_ioctl fs/ioctl.c:500 [inline]
do_vfs_ioctl+0x75a/0xff0 fs/ioctl.c:684
SYSC_ioctl fs/ioctl.c:701 [inline]
SyS_ioctl+0x7f/0xb0 fs/ioctl.c:692
do_syscall_64+0x1d5/0x640 arch/x86/entry/common.c:292
entry_SYSCALL_64_after_hwframe+0x5e/0xd3

other info that might help us debug this:

Chain exists of:
"%s-%s""btrfs", name --> &fs_devs->device_list_mutex --> &fs_info->scrub_lock

Possible unsafe locking scenario:

CPU0 CPU1
---- ----
lock(&fs_info->scrub_lock);
lock(&fs_devs->device_list_mutex);
lock(&fs_info->scrub_lock);
lock("%s-%s""btrfs", name);

*** DEADLOCK ***

1 lock held by syz-executor.3/9543:
#0: (&fs_info->scrub_lock){+.+.}, at: [<ffffffff82b1ba96>] btrfs_scrub_dev+0x506/0xcd0 fs/btrfs/scrub.c:4217

stack backtrace:
CPU: 1 PID: 9543 Comm: syz-executor.3 Not tainted 4.14.302-syzkaller #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 10/26/2022
Call Trace:
__dump_stack lib/dump_stack.c:17 [inline]
dump_stack+0x1b2/0x281 lib/dump_stack.c:58
print_circular_bug.constprop.0.cold+0x2d7/0x41e kernel/locking/lockdep.c:1258
check_prev_add kernel/locking/lockdep.c:1905 [inline]
check_prevs_add kernel/locking/lockdep.c:2022 [inline]
validate_chain kernel/locking/lockdep.c:2464 [inline]
__lock_acquire+0x2e0e/0x3f20 kernel/locking/lockdep.c:3491
lock_acquire+0x170/0x3f0 kernel/locking/lockdep.c:3998
flush_workqueue+0xfa/0x1310 kernel/workqueue.c:2625
drain_workqueue+0x177/0x3e0 kernel/workqueue.c:2790
destroy_workqueue+0x71/0x710 kernel/workqueue.c:4116
__btrfs_destroy_workqueue fs/btrfs/async-thread.c:436 [inline]
btrfs_destroy_workqueue+0xf8/0x630 fs/btrfs/async-thread.c:447
scrub_workers_put+0x90/0x1a0 fs/btrfs/scrub.c:4075
btrfs_scrub_dev+0x536/0xcd0 fs/btrfs/scrub.c:4219
btrfs_ioctl_scrub fs/btrfs/ioctl.c:4451 [inline]
btrfs_ioctl+0xba8/0x5b20 fs/btrfs/ioctl.c:5681
vfs_ioctl fs/ioctl.c:46 [inline]
file_ioctl fs/ioctl.c:500 [inline]
do_vfs_ioctl+0x75a/0xff0 fs/ioctl.c:684
SYSC_ioctl fs/ioctl.c:701 [inline]
SyS_ioctl+0x7f/0xb0 fs/ioctl.c:692
do_syscall_64+0x1d5/0x640 arch/x86/entry/common.c:292
entry_SYSCALL_64_after_hwframe+0x5e/0xd3
RIP: 0033:0x7f66d25e90d9
RSP: 002b:00007f66d0b5b168 EFLAGS: 00000246 ORIG_RAX: 0000000000000010
RAX: ffffffffffffffda RBX: 00007f66d2708f80 RCX: 00007f66d25e90d9
RDX: 0000000020000100 RSI: 00000000c400941b RDI: 0000000000000004
RBP: 00007f66d2644ae9 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000246 R12: 0000000000000000
R13: 00007ffd43a5a92f R14: 00007f66d0b5b300 R15: 0000000000022000
netlink: 44 bytes leftover after parsing attributes in process `syz-executor.0'.
BTRFS info (device loop3): using free space tree
BTRFS info (device loop3): has skinny extents
BTRFS info (device loop3): using free space tree
BTRFS info (device loop3): has skinny extents
BTRFS info (device loop3): using free space tree
BTRFS info (device loop3): has skinny extents
netlink: 132 bytes leftover after parsing attributes in process `syz-executor.3'.
syz-executor.2 uses obsolete (PF_INET,SOCK_PACKET)
IPVS: ftp: loaded support on port[0] = 21
can: request_module (can-proto-0) failed.
input: syz1 as /devices/virtual/input/input5
hrtimer: interrupt took 27637 ns
XFS (loop0): Superblock has unknown read-only compatible features (0x8) enabled.
XFS (loop0): Attempted to mount read-only compatible filesystem read-write.
XFS (loop0): Filesystem can only be safely mounted read only.
XFS (loop0): SB validate failed with error -22.
audit: type=1804 audit(1671296001.354:2): pid=10371 uid=0 auid=4294967295 ses=4294967295 op="invalid_pcr" cause="open_writers" comm="syz-executor.0" name="/root/syzkaller-testdir2273990990/syzkaller.VLztb8/50/bus" dev="sda1" ino=13983 res=1
audit: type=1800 audit(1671296001.354:3): pid=10371 uid=0 auid=4294967295 ses=4294967295 op="collect_data" cause="failed(directio)" comm="syz-executor.0" name="bus" dev="sda1" ino=13983 res=0
input: syz1 as /devices/virtual/input/input6
audit: type=1804 audit(1671296001.354:4): pid=10371 uid=0 auid=4294967295 ses=4294967295 op="invalid_pcr" cause="ToMToU" comm="syz-executor.0" name="/root/syzkaller-testdir2273990990/syzkaller.VLztb8/50/bus" dev="sda1" ino=13983 res=1
input: syz1 as /devices/virtual/input/input7
can: request_module (can-proto-0) failed.


---
This report is generated by a bot. It may contain errors.
See https://goo.gl/tpsmEJ for more information about syzbot.
syzbot engineers can be reached at syzk...@googlegroups.com.

syzbot will keep track of this issue. See:
https://goo.gl/tpsmEJ#status for how to communicate with syzbot.

[syzbot]

syzbot has found a reproducer for the following issue on:

HEAD commit: c4215ee4771b Linux 4.14.302
git tree: linux-4.14.y

console output: https://syzkaller.appspot.com/x/log.txt?x=14800abf880000

kernel config: https://syzkaller.appspot.com/x/.config?x=4a9988fe055c9527
dashboard link: https://syzkaller.appspot.com/bug?extid=b1a530302b8cbd3b85d7
compiler: gcc version 10.2.1 20210110 (Debian 10.2.1-6)

syz repro: https://syzkaller.appspot.com/x/repro.syz?x=156a451b880000
C reproducer: https://syzkaller.appspot.com/x/repro.c?x=17825f8b880000

Downloadable assets:
disk image: https://storage.googleapis.com/syzbot-assets/c93ba055d204/disk-c4215ee4.raw.xz
vmlinux: https://storage.googleapis.com/syzbot-assets/bfbc929a33c1/vmlinux-c4215ee4.xz
kernel image: https://storage.googleapis.com/syzbot-assets/444658051770/bzImage-c4215ee4.xz

mounted in repro: https://storage.googleapis.com/syzbot-assets/ebb1a370d364/mount_1.gz

IMPORTANT: if you fix the issue, please add the following tag to the commit:
Reported-by: syzbot+b1a530...@syzkaller.appspotmail.com

BTRFS: device fsid 24c7a497-3402-47dd-bef8-82358f5f30e0 devid 1 transid 8 /dev/loop0
BTRFS info (device loop0): using free space tree
BTRFS info (device loop0): has skinny extents

======================================================
WARNING: possible circular locking dependency detected
4.14.302-syzkaller #0 Not tainted
------------------------------------------------------

syz-executor417/8001 is trying to acquire lock:

1 lock held by syz-executor417/8001:

#0: (&fs_info->scrub_lock){+.+.}, at: [<ffffffff82b1ba96>] btrfs_scrub_dev+0x506/0xcd0 fs/btrfs/scrub.c:4217

stack backtrace:

CPU: 0 PID: 8001 Comm: syz-executor417 Not tainted 4.14.302-syzkaller #0

RIP: 0033:0x7fe60f70d8c9