BFS-fs: bfs_fill_super(): loop2 is unclean, continuing 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 ------------------------------------------------------ kworker/u4:4/3547 is trying to acquire lock: (sb_internal#2){.+.+}, at: [] sb_start_intwrite include/linux/fs.h:1598 [inline] (sb_internal#2){.+.+}, at: [] start_transaction+0x6de/0xf30 fs/btrfs/transaction.c:548 but task is already holding lock: ((&work->normal_work)){+.+.}, at: [] process_one_work+0x6e6/0x14a0 kernel/workqueue.c:2092 which lock already depends on the new lock. the existing dependency chain (in reverse order) is: -> #4 ((&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 -> #3 ("%s-%s""btrfs", name){+.+.}: 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 -> #2 (&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 -> #1 (&fs_devs->device_list_mutex){+.+.}: __mutex_lock_common kernel/locking/mutex.c:756 [inline] __mutex_lock+0xc4/0x1310 kernel/locking/mutex.c:893 btrfs_finish_chunk_alloc+0x221/0xe90 fs/btrfs/volumes.c:4923 btrfs_create_pending_block_groups+0x1fd/0x540 fs/btrfs/extent-tree.c:10388 __btrfs_end_transaction+0x1f2/0xaa0 fs/btrfs/transaction.c:851 flush_space+0x8de/0xde0 fs/btrfs/extent-tree.c:5046 btrfs_async_reclaim_metadata_space+0x414/0xc20 fs/btrfs/extent-tree.c:5162 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 -> #0 (sb_internal#2){.+.+}: lock_acquire+0x170/0x3f0 kernel/locking/lockdep.c:3998 percpu_down_read_preempt_disable include/linux/percpu-rwsem.h:36 [inline] percpu_down_read include/linux/percpu-rwsem.h:59 [inline] __sb_start_write+0x64/0x260 fs/super.c:1342 sb_start_intwrite include/linux/fs.h:1598 [inline] start_transaction+0x6de/0xf30 fs/btrfs/transaction.c:548 btrfs_qgroup_rescan_worker+0x176/0x1060 fs/btrfs/qgroup.c:2632 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 other info that might help us debug this: Chain exists of: sb_internal#2 --> "%s-%s""btrfs", name --> (&work->normal_work) Possible unsafe locking scenario: CPU0 CPU1 ---- ---- lock((&work->normal_work)); lock("%s-%s""btrfs", name); lock((&work->normal_work)); lock(sb_internal#2); *** DEADLOCK *** 2 locks held by kworker/u4:4/3547: #0: ("%s-%s""btrfs", name){+.+.}, at: [] process_one_work+0x6b0/0x14a0 kernel/workqueue.c:2088 #1: ((&work->normal_work)){+.+.}, at: [] process_one_work+0x6e6/0x14a0 kernel/workqueue.c:2092 stack backtrace: CPU: 1 PID: 3547 Comm: kworker/u4:4 Not tainted 4.14.302-syzkaller #0 Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 10/26/2022 Workqueue: btrfs-qgroup-rescan btrfs_qgroup_rescan_helper 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 percpu_down_read_preempt_disable include/linux/percpu-rwsem.h:36 [inline] percpu_down_read include/linux/percpu-rwsem.h:59 [inline] __sb_start_write+0x64/0x260 fs/super.c:1342 sb_start_intwrite include/linux/fs.h:1598 [inline] start_transaction+0x6de/0xf30 fs/btrfs/transaction.c:548 btrfs_qgroup_rescan_worker+0x176/0x1060 fs/btrfs/qgroup.c:2632 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 BTRFS error (device loop0): fail to start transaction for status update: -28 audit: type=1800 audit(1673311515.409:18): pid=9979 uid=0 auid=4294967295 ses=4294967295 op="collect_data" cause="failed(directio)" comm="syz-executor.1" name="bus" dev="loop1" ino=5 res=0 audit: type=1800 audit(1673311515.439:19): pid=9976 uid=0 auid=4294967295 ses=4294967295 op="collect_data" cause="failed(directio)" comm="syz-executor.4" name="bus" dev="loop4" ino=6 res=0 audit: type=1804 audit(1673311515.469:20): pid=9980 uid=0 auid=4294967295 ses=4294967295 op="invalid_pcr" cause="open_writers" comm="syz-executor.5" name="/root/syzkaller-testdir2665391280/syzkaller.zRnvGu/11/file0/bus" dev="loop5" ino=7 res=1 audit: type=1804 audit(1673311515.549:21): pid=9999 uid=0 auid=4294967295 ses=4294967295 op="invalid_pcr" cause="ToMToU" comm="syz-executor.5" name="/root/syzkaller-testdir2665391280/syzkaller.zRnvGu/11/file0/bus" dev="loop5" ino=7 res=1 audit: type=1800 audit(1673311515.749:22): pid=10010 uid=0 auid=4294967295 ses=4294967295 op="collect_data" cause="failed(directio)" comm="syz-executor.1" name="bus" dev="loop1" ino=8 res=0 BTRFS info (device loop0): using free space tree BTRFS info (device loop0): has skinny extents audit: type=1800 audit(1673311515.789:23): pid=10017 uid=0 auid=4294967295 ses=4294967295 op="collect_data" cause="failed(directio)" comm="syz-executor.4" name="bus" dev="loop4" ino=9 res=0 BTRFS error (device loop0): fail to start transaction for status update: -28 audit: type=1800 audit(1673311516.369:24): pid=10072 uid=0 auid=4294967295 ses=4294967295 op="collect_data" cause="failed(directio)" comm="syz-executor.4" name="bus" dev="loop4" ino=10 res=0 audit: type=1804 audit(1673311516.479:25): pid=10073 uid=0 auid=4294967295 ses=4294967295 op="invalid_pcr" cause="open_writers" comm="syz-executor.5" name="/root/syzkaller-testdir2665391280/syzkaller.zRnvGu/12/file0/bus" dev="loop5" ino=11 res=1 audit: type=1804 audit(1673311516.539:26): pid=10092 uid=0 auid=4294967295 ses=4294967295 op="invalid_pcr" cause="ToMToU" comm="syz-executor.5" name="/root/syzkaller-testdir2665391280/syzkaller.zRnvGu/12/file0/bus" dev="loop5" ino=11 res=1 BTRFS info (device loop1): using free space tree BTRFS info (device loop1): has skinny extents audit: type=1804 audit(1673311516.819:27): pid=10099 uid=0 auid=4294967295 ses=4294967295 op="invalid_pcr" cause="open_writers" comm="syz-executor.4" name="/root/syzkaller-testdir1698682466/syzkaller.rueIZI/15/file0/bus" dev="loop4" ino=12 res=1 audit: type=1804 audit(1673311516.879:28): pid=10119 uid=0 auid=4294967295 ses=4294967295 op="invalid_pcr" cause="ToMToU" comm="syz-executor.4" name="/root/syzkaller-testdir1698682466/syzkaller.rueIZI/15/file0/bus" dev="loop4" ino=12 res=1 BTRFS error (device loop1): fail to start transaction for status update: -28 audit: type=1804 audit(1673311517.479:29): pid=10158 uid=0 auid=4294967295 ses=4294967295 op="invalid_pcr" cause="open_writers" comm="syz-executor.4" name="/root/syzkaller-testdir1698682466/syzkaller.rueIZI/16/file0/bus" dev="loop4" ino=13 res=1 audit: type=1804 audit(1673311517.509:30): pid=10155 uid=0 auid=4294967295 ses=4294967295 op="invalid_pcr" cause="open_writers" comm="syz-executor.5" name="/root/syzkaller-testdir2665391280/syzkaller.zRnvGu/13/file0/bus" dev="loop5" ino=14 res=1 audit: type=1804 audit(1673311517.559:31): pid=10174 uid=0 auid=4294967295 ses=4294967295 op="invalid_pcr" cause="ToMToU" comm="syz-executor.4" name="/root/syzkaller-testdir1698682466/syzkaller.rueIZI/16/file0/bus" dev="loop4" ino=13 res=1 BTRFS info (device loop1): using free space tree audit: type=1804 audit(1673311517.579:32): pid=10175 uid=0 auid=4294967295 ses=4294967295 op="invalid_pcr" cause="ToMToU" comm="syz-executor.5" name="/root/syzkaller-testdir2665391280/syzkaller.zRnvGu/13/file0/bus" dev="loop5" ino=14 res=1 BTRFS info (device loop1): has skinny extents BTRFS error (device loop1): fail to start transaction for status update: -28 device syz_tun entered promiscuous mode device batadv_slave_0 entered promiscuous mode device syz_tun left promiscuous mode device batadv_slave_0 left promiscuous mode BTRFS info (device loop1): using free space tree BTRFS info (device loop1): has skinny extents device syz_tun entered promiscuous mode device batadv_slave_0 entered promiscuous mode device syz_tun left promiscuous mode device batadv_slave_0 left promiscuous mode device syz_tun entered promiscuous mode device batadv_slave_0 entered promiscuous mode device syz_tun left promiscuous mode BTRFS error (device loop1): fail to start transaction for status update: -28 device batadv_slave_0 left promiscuous mode device syz_tun entered promiscuous mode device batadv_slave_0 entered promiscuous mode device syz_tun entered promiscuous mode device batadv_slave_0 entered promiscuous mode device syz_tun left promiscuous mode device batadv_slave_0 left promiscuous mode device syz_tun left promiscuous mode device batadv_slave_0 left promiscuous mode device syz_tun entered promiscuous mode device batadv_slave_0 entered promiscuous mode device syz_tun entered promiscuous mode device batadv_slave_0 entered promiscuous mode device syz_tun left promiscuous mode device batadv_slave_0 left promiscuous mode device syz_tun entered promiscuous mode device batadv_slave_0 entered promiscuous mode device syz_tun left promiscuous mode device batadv_slave_0 left promiscuous mode device syz_tun left promiscuous mode device batadv_slave_0 left promiscuous mode device syz_tun entered promiscuous mode device batadv_slave_0 entered promiscuous mode device syz_tun entered promiscuous mode device batadv_slave_0 entered promiscuous mode device syz_tun left promiscuous mode device batadv_slave_0 left promiscuous mode device syz_tun entered promiscuous mode device batadv_slave_0 entered promiscuous mode device syz_tun left promiscuous mode device batadv_slave_0 left promiscuous mode device syz_tun entered promiscuous mode device batadv_slave_0 entered promiscuous mode device syz_tun left promiscuous mode device batadv_slave_0 left promiscuous mode device syz_tun left promiscuous mode device batadv_slave_0 left promiscuous mode device syz_tun entered promiscuous mode device batadv_slave_0 entered promiscuous mode device syz_tun left promiscuous mode device batadv_slave_0 left promiscuous mode kvm [10530]: vcpu0, guest rIP: 0xfff0 disabled perfctr wrmsr: 0xc2 data 0x3ad6e37883b8e6ec kvm [10561]: vcpu0, guest rIP: 0xfff0 disabled perfctr wrmsr: 0xc2 data 0x3ad6e37883b8e6ec kvm [10564]: vcpu0, guest rIP: 0xfff0 disabled perfctr wrmsr: 0xc2 data 0x3ad6e37883b8e6ec kvm [10582]: vcpu0, guest rIP: 0xfff0 disabled perfctr wrmsr: 0xc2 data 0x3ad6e37883b8e6ec kvm [10595]: vcpu0, guest rIP: 0xfff0 disabled perfctr wrmsr: 0xc2 data 0x3ad6e37883b8e6ec kvm [10615]: vcpu0, guest rIP: 0xfff0 disabled perfctr wrmsr: 0xc2 data 0x3ad6e37883b8e6ec kvm [10628]: vcpu0, guest rIP: 0xfff0 disabled perfctr wrmsr: 0xc2 data 0x3ad6e37883b8e6ec device bond_slave_0 entered promiscuous mode device bond_slave_0 entered promiscuous mode ip_tables: iptables: counters copy to user failed while replacing table ip_tables: iptables: counters copy to user failed while replacing table device bond_slave_0 entered promiscuous mode ip_tables: iptables: counters copy to user failed while replacing table ip_tables: iptables: counters copy to user failed while replacing table ip_tables: iptables: counters copy to user failed while replacing table ip_tables: iptables: counters copy to user failed while replacing table ip_tables: iptables: counters copy to user failed while replacing table ip_tables: iptables: counters copy to user failed while replacing table ip_tables: iptables: counters copy to user failed while replacing table ip_tables: iptables: counters copy to user failed while replacing table netlink: 12 bytes leftover after parsing attributes in process `syz-executor.4'. netlink: 12 bytes leftover after parsing attributes in process `syz-executor.0'. IPVS: ftp: loaded support on port[0] = 21 netlink: 12 bytes leftover after parsing attributes in process `syz-executor.4'. netlink: 12 bytes leftover after parsing attributes in process `syz-executor.0'. netlink: 12 bytes leftover after parsing attributes in process `syz-executor.4'. netlink: 9 bytes leftover after parsing attributes in process `syz-executor.1'. device gretap0 entered promiscuous mode netlink: 9 bytes leftover after parsing attributes in process `syz-executor.1'. ‘|‚ªu: renamed from gretap0 device ‘|‚ªu left promiscuous mode netlink: 12 bytes leftover after parsing attributes in process `syz-executor.4'. netlink: 12 bytes leftover after parsing attributes in process `syz-executor.0'. netlink: 9 bytes leftover after parsing attributes in process `syz-executor.1'. device ‘|‚ªu entered promiscuous mode device ‘|‚ªu left promiscuous mode hub 9-0:1.0: USB hub found hub 9-0:1.0: 8 ports detected device ‘|‚ªu entered promiscuous mode device ‘|‚ªu left promiscuous mode hub 9-0:1.0: USB hub found hub 9-0:1.0: 8 ports detected