EXT4-fs (loop4): 1 orphan inode deleted
EXT4-fs (loop4): mounted filesystem without journal. Opts: errors=remount-ro,sysvgroups,dioread_lock,resuid=0x0000000000000000,data_err=abort,noload,max_dir_size_kb=0x0000000000200006,init_itable=0x0000000000010001,usrquota,
======================================================
WARNING: possible circular locking dependency detected
4.14.306-syzkaller #0 Not tainted
------------------------------------------------------
syz-executor.2/11880 is trying to acquire lock:
("%s-%s""btrfs", name){+.+.}, at: [<ffffffff8135cb1b>] flush_workqueue+0xcb/0x1310 kernel/workqueue.c:2622
but task is already holding lock:
(&fs_info->scrub_lock){+.+.}, at: [<ffffffff82b1bd66>] 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.2/11880:
#0: (&fs_info->scrub_lock){+.+.}, at: [<ffffffff82b1bd66>] btrfs_scrub_dev+0x506/0xcd0 fs/btrfs/scrub.c:4217
stack backtrace:
CPU: 1 PID: 11880 Comm: syz-executor.2 Not tainted 4.14.306-syzkaller #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/21/2023
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:0x7f465e5090f9
RSP: 002b:00007f465ca7b168 EFLAGS: 00000246 ORIG_RAX: 0000000000000010
RAX: ffffffffffffffda RBX: 00007f465e628f80 RCX: 00007f465e5090f9
RDX: 0000000020000100 RSI: 00000000c400941b RDI: 0000000000000004
RBP: 00007f465e564ae9 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000246 R12: 0000000000000000
R13: 00007ffe39cf8e4f R14: 00007f465ca7b300 R15: 0000000000022000
kauditd_printk_skb: 9 callbacks suppressed
audit: type=1800 audit(1677156834.342:13): pid=12017 uid=0 auid=4294967295 ses=4294967295 op="collect_data" cause="failed(directio)" comm="syz-executor.5" name="file0" dev="sda1" ino=14253 res=0
EXT4-fs error (device loop4): mb_free_blocks:1464: group 0, inode 16: block 39:freeing already freed block (bit 39); block bitmap corrupt.
EXT4-fs (loop4): Remounting filesystem read-only
audit: type=1804 audit(1677156834.362:14): pid=12017 uid=0 auid=4294967295 ses=4294967295 op="invalid_pcr" cause="open_writers" comm="syz-executor.5" name="/root/syzkaller-testdir3308352048/syzkaller.UZKMmU/62/file0" dev="sda1" ino=14253 res=1
EXT4-fs error (device loop4): ext4_mb_generate_buddy:754: group 0, block bitmap and bg descriptor inconsistent: 42 vs 43 free clusters
audit: type=1804 audit(1677156834.362:15): pid=12017 uid=0 auid=4294967295 ses=4294967295 op="invalid_pcr" cause="ToMToU" comm="syz-executor.5" name="/root/syzkaller-testdir3308352048/syzkaller.UZKMmU/62/file0" dev="sda1" ino=14253 res=1
Quota error (device loop4): dqput: Can't write quota structure (error -30). Quota may get out of sync!
Quota error (device loop4): dqput: Can't write quota structure (error -30). Quota may get out of sync!
EXT4-fs (loop4): 1 orphan inode deleted
BTRFS info (device loop0): enabling inode map caching
BTRFS info (device loop0): trying to use backup root at mount time
EXT4-fs (loop4): mounted filesystem without journal. Opts: errors=remount-ro,sysvgroups,dioread_lock,resuid=0x0000000000000000,data_err=abort,noload,max_dir_size_kb=0x0000000000200006,init_itable=0x0000000000010001,usrquota,
BTRFS info (device loop0): use zlib compression
BTRFS info (device loop0): enabling ssd optimizations
BTRFS info (device loop0): using spread ssd allocation scheme
BTRFS info (device loop0): using free space tree
BTRFS info (device loop0): has skinny extents
audit: type=1800 audit(1677156835.212:16): pid=12092 uid=0 auid=4294967295 ses=4294967295 op="collect_data" cause="failed(directio)" comm="syz-executor.5" name="file0" dev="sda1" ino=14253 res=0
audit: type=1804 audit(1677156835.232:17): pid=12092 uid=0 auid=4294967295 ses=4294967295 op="invalid_pcr" cause="open_writers" comm="syz-executor.5" name="/root/syzkaller-testdir3308352048/syzkaller.UZKMmU/63/file0" dev="sda1" ino=14253 res=1
audit: type=1804 audit(1677156835.232:18): pid=12092 uid=0 auid=4294967295 ses=4294967295 op="invalid_pcr" cause="ToMToU" comm="syz-executor.5" name="/root/syzkaller-testdir3308352048/syzkaller.UZKMmU/63/file0" dev="sda1" ino=14253 res=1
BTRFS info (device loop0): enabling inode map caching
BTRFS info (device loop0): trying to use backup root at mount time
BTRFS info (device loop0): use zlib compression
BTRFS info (device loop0): enabling ssd optimizations
BTRFS info (device loop0): using spread ssd allocation scheme
BTRFS info (device loop0): using free space tree
BTRFS info (device loop0): has skinny extents
audit: type=1800 audit(1677156836.092:19): pid=12155 uid=0 auid=4294967295 ses=4294967295 op="collect_data" cause="failed(directio)" comm="syz-executor.5" name="file0" dev="sda1" ino=14246 res=0
audit: type=1804 audit(1677156836.102:20): pid=12155 uid=0 auid=4294967295 ses=4294967295 op="invalid_pcr" cause="open_writers" comm="syz-executor.5" name="/root/syzkaller-testdir3308352048/syzkaller.UZKMmU/64/file0" dev="sda1" ino=14246 res=1
BTRFS info (device loop0): enabling inode map caching
BTRFS info (device loop0): trying to use backup root at mount time
BTRFS info (device loop0): use zlib compression
BTRFS info (device loop0): enabling ssd optimizations
BTRFS info (device loop0): using spread ssd allocation scheme
BTRFS info (device loop0): using free space tree
BTRFS info (device loop0): has skinny extents
kauditd_printk_skb: 16 callbacks suppressed
audit: type=1800 audit(1677156839.143:37): pid=12301 uid=0 auid=4294967295 ses=4294967295 op="collect_data" cause="failed(directio)" comm="syz-executor.2" name="file0" dev="sda1" ino=14021 res=0
audit: type=1804 audit(1677156839.143:38): pid=12301 uid=0 auid=4294967295 ses=4294967295 op="invalid_pcr" cause="open_writers" comm="syz-executor.2" name="/root/syzkaller-testdir2058402763/syzkaller.IF9qDv/61/file0" dev="sda1" ino=14021 res=1
audit: type=1804 audit(1677156839.143:39): pid=12301 uid=0 auid=4294967295 ses=4294967295 op="invalid_pcr" cause="ToMToU" comm="syz-executor.2" name="/root/syzkaller-testdir2058402763/syzkaller.IF9qDv/61/file0" dev="sda1" ino=14021 res=1
audit: type=1800 audit(1677156839.363:40): pid=12299 uid=0 auid=4294967295 ses=4294967295 op="collect_data" cause="failed(directio)" comm="syz-executor.0" name="file0" dev="sda1" ino=14261 res=0
audit: type=1804 audit(1677156839.373:41): pid=12299 uid=0 auid=4294967295 ses=4294967295 op="invalid_pcr" cause="open_writers" comm="syz-executor.0" name="/root/syzkaller-testdir1924649566/syzkaller.jMc3yt/86/file0" dev="sda1" ino=14261 res=1
audit: type=1804 audit(1677156839.373:42): pid=12299 uid=0 auid=4294967295 ses=4294967295 op="invalid_pcr" cause="ToMToU" comm="syz-executor.0" name="/root/syzkaller-testdir1924649566/syzkaller.jMc3yt/86/file0" dev="sda1" ino=14261 res=1
BTRFS info (device loop0): enabling inode map caching
BTRFS warning (device loop0): excessive commit interval 622039222
audit: type=1800 audit(1677156839.923:43): pid=12312 uid=0 auid=4294967295 ses=4294967295 op="collect_data" cause="failed(directio)" comm="syz-executor.5" name="file0" dev="sda1" ino=13907 res=0
BTRFS info (device loop0): force zlib compression
BTRFS info (device loop0): using free space tree
BTRFS info (device loop0): has skinny extents
======================================================
WARNING: the mand mount option is being deprecated and
will be removed in v5.15!
======================================================
audit: type=1804 audit(1677156839.923:44): pid=12312 uid=0 auid=4294967295 ses=4294967295 op="invalid_pcr" cause="open_writers" comm="syz-executor.5" name="/root/syzkaller-testdir3308352048/syzkaller.UZKMmU/67/file0" dev="sda1" ino=13907 res=1
audit: type=1804 audit(1677156839.923:45): pid=12312 uid=0 auid=4294967295 ses=4294967295 op="invalid_pcr" cause="ToMToU" comm="syz-executor.5" name="/root/syzkaller-testdir3308352048/syzkaller.UZKMmU/67/file0" dev="sda1" ino=13907 res=1
audit: type=1800 audit(1677156839.923:46): pid=12315 uid=0 auid=4294967295 ses=4294967295 op="collect_data" cause="failed(directio)" comm="syz-executor.3" name="file0" dev="sda1" ino=13908 res=0
BTRFS info (device loop0): enabling inode map caching
BTRFS warning (device loop0): excessive commit interval 622039222
BTRFS info (device loop0): force zlib compression
BTRFS info (device loop0): using free space tree
BTRFS info (device loop0): has skinny extents
BTRFS info (device loop0): enabling inode map caching
BTRFS warning (device loop0): excessive commit interval 622039222
BTRFS info (device loop0): force zlib compression
BTRFS info (device loop0): using free space tree
BTRFS info (device loop0): has skinny extents