BTRFS info (device loop3): enabling ssd optimizations
BTRFS info (device loop3): using spread ssd allocation scheme
BTRFS info (device loop3): using free space tree
BTRFS info (device loop3): has skinny extents
======================================================
WARNING: possible circular locking dependency detected
4.14.306-syzkaller #0 Not tainted
------------------------------------------------------
syz-executor.3/11871 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.3/11871:
 #0:  (&fs_info->scrub_lock){+.+.}, at: [<ffffffff82b1bd66>] btrfs_scrub_dev+0x506/0xcd0 fs/btrfs/scrub.c:4217

stack backtrace:
CPU: 1 PID: 11871 Comm: syz-executor.3 Not tainted 4.14.306-syzkaller #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 02/16/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:0x7f717431f0f9
RSP: 002b:00007f7172891168 EFLAGS: 00000246 ORIG_RAX: 0000000000000010
RAX: ffffffffffffffda RBX: 00007f717443ef80 RCX: 00007f717431f0f9
RDX: 0000000020000100 RSI: 00000000c400941b RDI: 0000000000000004
RBP: 00007f717437aae9 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000246 R12: 0000000000000000
R13: 00007ffe72d25cff R14: 00007f7172891300 R15: 0000000000022000
rdma_op ffff88809175ef58 conn xmit_rdma           (null)
EXT4-fs (loop2): ext4_check_descriptors: Checksum for group 0 failed (17020!=33349)
EXT4-fs (loop2): group descriptors corrupted!
kvm: emulating exchange as write
EXT4-fs (loop2): ext4_check_descriptors: Checksum for group 0 failed (17020!=33349)
EXT4-fs (loop2): group descriptors corrupted!
print_req_error: I/O error, dev loop2, sector 0
Buffer I/O error on dev loop2, logical block 0, async page read
print_req_error: I/O error, dev loop2, sector 6
Buffer I/O error on dev loop2, logical block 3, async page read
BTRFS info (device loop1): enabling inode map caching
BTRFS info (device loop1): trying to use backup root at mount time
BTRFS info (device loop1): use zlib compression
BTRFS info (device loop1): enabling ssd optimizations
BTRFS info (device loop1): using spread ssd allocation scheme
BTRFS info (device loop1): using free space tree
BTRFS info (device loop1): has skinny extents
EXT4-fs (loop2): ext4_check_descriptors: Checksum for group 0 failed (17020!=33349)
EXT4-fs (loop2): group descriptors corrupted!
BTRFS info (device loop1): enabling inode map caching
BTRFS info (device loop1): trying to use backup root at mount time
BTRFS info (device loop1): use zlib compression
BTRFS info (device loop1): enabling ssd optimizations
BTRFS info (device loop1): using spread ssd allocation scheme
BTRFS info (device loop1): using free space tree
BTRFS info (device loop1): has skinny extents
BTRFS info (device loop1): enabling inode map caching
BTRFS info (device loop1): trying to use backup root at mount time
BTRFS info (device loop1): use zlib compression
BTRFS info (device loop1): enabling ssd optimizations
BTRFS info (device loop1): using spread ssd allocation scheme
BTRFS info (device loop1): using free space tree
BTRFS info (device loop1): has skinny extents
NILFS (loop1): invalid segment: Checksum error in segment payload
NILFS (loop1): trying rollback from an earlier position
NILFS (loop1): recovery complete
NILFS (loop1): segctord starting. Construction interval = 5 seconds, CP frequency < 30 seconds
audit: type=1804 audit(1677239758.297:51): pid=12194 uid=0 auid=4294967295 ses=4294967295 op="invalid_pcr" cause="ToMToU" comm="syz-executor.1" name=2F726F6F742F73797A6B616C6C65722D74657374646972313432303531393639392F73797A6B616C6C65722E72756A66764D2F37382F131377C5FC35D41454D5D41D29AD1A6029598146E6BE166E41AD0DBD4054033C9F33BBDA8224A2F3D772E7636E48B33CBF708372E8F1B9933EC5127743BE2206209EF02DF9CBF2F6E880D3382F627573 dev="loop1" ino=12 res=1
audit: type=1804 audit(1677239758.347:52): pid=12194 uid=0 auid=4294967295 ses=4294967295 op="invalid_pcr" cause="ToMToU" comm="syz-executor.1" name=2F726F6F742F73797A6B616C6C65722D74657374646972313432303531393639392F73797A6B616C6C65722E72756A66764D2F37382F131377C5FC35D41454D5D41D29AD1A6029598146E6BE166E41AD0DBD4054033C9F33BBDA8224A2F3D772E7636E48B33CBF708372E8F1B9933EC5127743BE2206209EF02DF9CBF2F6E880D3382F627573 dev="loop1" ino=12 res=1
NILFS (loop1): invalid segment: Checksum error in segment payload
NILFS (loop1): trying rollback from an earlier position
audit: type=1804 audit(1677239758.347:53): pid=12224 uid=0 auid=4294967295 ses=4294967295 op="invalid_pcr" cause="ToMToU" comm="syz-executor.1" name=2F726F6F742F73797A6B616C6C65722D74657374646972313432303531393639392F73797A6B616C6C65722E72756A66764D2F37382F131377C5FC35D41454D5D41D29AD1A6029598146E6BE166E41AD0DBD4054033C9F33BBDA8224A2F3D772E7636E48B33CBF708372E8F1B9933EC5127743BE2206209EF02DF9CBF2F6E880D3382F627573 dev="loop1" ino=12 res=1
NILFS (loop1): recovery complete
NILFS (loop1): segctord starting. Construction interval = 5 seconds, CP frequency < 30 seconds
audit: type=1804 audit(1677239758.787:54): pid=12228 uid=0 auid=4294967295 ses=4294967295 op="invalid_pcr" cause="open_writers" comm="syz-executor.1" name=2F726F6F742F73797A6B616C6C65722D74657374646972313432303531393639392F73797A6B616C6C65722E72756A66764D2F37392F131377C5FC35D41454D5D41D29AD1A6029598146E6BE166E41AD0DBD4054033C9F33BBDA8224A2F3D772E7636E48B33CBF708372E8F1B9933EC5127743BE2206209EF02DF9CBF2F6E880D3382F627573 dev="loop1" ino=12 res=1
audit: type=1804 audit(1677239758.797:55): pid=12228 uid=0 auid=4294967295 ses=4294967295 op="invalid_pcr" cause="ToMToU" comm="syz-executor.1" name=2F726F6F742F73797A6B616C6C65722D74657374646972313432303531393639392F73797A6B616C6C65722E72756A66764D2F37392F131377C5FC35D41454D5D41D29AD1A6029598146E6BE166E41AD0DBD4054033C9F33BBDA8224A2F3D772E7636E48B33CBF708372E8F1B9933EC5127743BE2206209EF02DF9CBF2F6E880D3382F627573 dev="loop1" ino=12 res=1
audit: type=1804 audit(1677239758.797:56): pid=12228 uid=0 auid=4294967295 ses=4294967295 op="invalid_pcr" cause="ToMToU" comm="syz-executor.1" name=2F726F6F742F73797A6B616C6C65722D74657374646972313432303531393639392F73797A6B616C6C65722E72756A66764D2F37392F131377C5FC35D41454D5D41D29AD1A6029598146E6BE166E41AD0DBD4054033C9F33BBDA8224A2F3D772E7636E48B33CBF708372E8F1B9933EC5127743BE2206209EF02DF9CBF2F6E880D3382F627573 dev="loop1" ino=12 res=1
NILFS (loop4): invalid segment: Checksum error in segment payload
NILFS (loop5): invalid segment: Checksum error in segment payload
NILFS (loop4): trying rollback from an earlier position
NILFS (loop5): trying rollback from an earlier position
NILFS (loop5): recovery complete
NILFS (loop5): segctord starting. Construction interval = 5 seconds, CP frequency < 30 seconds
NILFS (loop4): recovery complete
UDF-fs: INFO Mounting volume 'LinuxUDF', timestamp 2022/11/22 14:59 (1000)
NILFS (loop4): segctord starting. Construction interval = 5 seconds, CP frequency < 30 seconds
audit: type=1804 audit(1677239759.477:57): pid=12254 uid=0 auid=4294967295 ses=4294967295 op="invalid_pcr" cause="open_writers" comm="syz-executor.5" name=2F726F6F742F73797A6B616C6C65722D746573746469723233383333373635302F73797A6B616C6C65722E4B32706C4F462F38312F131377C5FC35D41454D5D41D29AD1A6029598146E6BE166E41AD0DBD4054033C9F33BBDA8224A2F3D772E7636E48B33CBF708372E8F1B9933EC5127743BE2206209EF02DF9CBF2F6E880D3382F627573 dev="loop5" ino=12 res=1
NILFS (loop1): invalid segment: Checksum error in segment payload
NILFS (loop1): trying rollback from an earlier position
audit: type=1804 audit(1677239759.527:58): pid=12254 uid=0 auid=4294967295 ses=4294967295 op="invalid_pcr" cause="ToMToU" comm="syz-executor.5" name=2F726F6F742F73797A6B616C6C65722D746573746469723233383333373635302F73797A6B616C6C65722E4B32706C4F462F38312F131377C5FC35D41454D5D41D29AD1A6029598146E6BE166E41AD0DBD4054033C9F33BBDA8224A2F3D772E7636E48B33CBF708372E8F1B9933EC5127743BE2206209EF02DF9CBF2F6E880D3382F627573 dev="loop5" ino=12 res=1
NILFS (loop1): recovery complete
NILFS (loop1): segctord starting. Construction interval = 5 seconds, CP frequency < 30 seconds
audit: type=1804 audit(1677239759.527:59): pid=12254 uid=0 auid=4294967295 ses=4294967295 op="invalid_pcr" cause="ToMToU" comm="syz-executor.5" name=2F726F6F742F73797A6B616C6C65722D746573746469723233383333373635302F73797A6B616C6C65722E4B32706C4F462F38312F131377C5FC35D41454D5D41D29AD1A6029598146E6BE166E41AD0DBD4054033C9F33BBDA8224A2F3D772E7636E48B33CBF708372E8F1B9933EC5127743BE2206209EF02DF9CBF2F6E880D3382F627573 dev="loop5" ino=12 res=1
UDF-fs: INFO Mounting volume 'LinuxUDF', timestamp 2022/11/22 14:59 (1000)
NILFS (loop5): invalid segment: Checksum error in segment payload
NILFS (loop4): invalid segment: Checksum error in segment payload
NILFS (loop5): trying rollback from an earlier position
NILFS (loop4): trying rollback from an earlier position
audit: type=1804 audit(1677239759.587:60): pid=12253 uid=0 auid=4294967295 ses=4294967295 op="invalid_pcr" cause="open_writers" comm="syz-executor.4" name=2F726F6F742F73797A6B616C6C65722D746573746469723437303234373135322F73797A6B616C6C65722E4B51613146662F38302F131377C5FC35D41454D5D41D29AD1A6029598146E6BE166E41AD0DBD4054033C9F33BBDA8224A2F3D772E7636E48B33CBF708372E8F1B9933EC5127743BE2206209EF02DF9CBF2F6E880D3382F627573 dev="loop4" ino=12 res=1
NILFS (loop5): recovery complete
NILFS (loop4): recovery complete
NILFS (loop5): segctord starting. Construction interval = 5 seconds, CP frequency < 30 seconds
NILFS (loop4): segctord starting. Construction interval = 5 seconds, CP frequency < 30 seconds
NILFS (loop1): invalid segment: Checksum error in segment payload
NILFS (loop1): trying rollback from an earlier position
NILFS (loop1): recovery complete
NILFS (loop1): segctord starting. Construction interval = 5 seconds, CP frequency < 30 seconds
UDF-fs: INFO Mounting volume 'LinuxUDF', timestamp 2022/11/22 14:59 (1000)
UDF-fs: INFO Mounting volume 'LinuxUDF', timestamp 2022/11/22 14:59 (1000)
NILFS (loop5): invalid segment: Checksum error in segment payload
NILFS (loop5): trying rollback from an earlier position
NILFS (loop5): recovery complete
NILFS (loop5): segctord starting. Construction interval = 5 seconds, CP frequency < 30 seconds
NILFS (loop4): invalid segment: Checksum error in segment payload
NILFS (loop4): trying rollback from an earlier position
NILFS (loop4): recovery complete
NILFS (loop4): segctord starting. Construction interval = 5 seconds, CP frequency < 30 seconds
UDF-fs: INFO Mounting volume 'LinuxUDF', timestamp 2022/11/22 14:59 (1000)
UDF-fs: INFO Mounting volume 'LinuxUDF', timestamp 2022/11/22 14:59 (1000)
UDF-fs: INFO Mounting volume 'LinuxUDF', timestamp 2022/11/22 14:59 (1000)
UDF-fs: INFO Mounting volume 'LinuxUDF', timestamp 2022/11/22 14:59 (1000)
UDF-fs: INFO Mounting volume 'LinuxUDF', timestamp 2022/11/22 14:59 (1000)
kauditd_printk_skb: 26 callbacks suppressed
audit: type=1800 audit(1677239763.287:87): pid=12493 uid=0 auid=4294967295 ses=4294967295 op="collect_data" cause="failed(directio)" comm="syz-executor.1" name="file0" dev="sda1" ino=14301 res=0
UDF-fs: INFO Mounting volume 'LinuxUDF', timestamp 2022/11/22 14:59 (1000)