syzbot

======================================================
WARNING: possible circular locking dependency detected
4.19.211-syzkaller #0 Not tainted
------------------------------------------------------
syz-executor.1/8165 is trying to acquire lock:
00000000f2cf0b77 (&fs_devs->device_list_mutex){+.+.}, at: btrfs_run_dev_stats+0xbb/0xa80 fs/btrfs/volumes.c:7111

but task is already holding lock:
00000000f5f38e8d (&fs_info->tree_log_mutex){+.+.}, at: btrfs_commit_transaction+0x8c2/0x2480 fs/btrfs/transaction.c:2176

which lock already depends on the new lock.


the existing dependency chain (in reverse order) is:

-> #6 (&fs_info->tree_log_mutex){+.+.}:
       btrfs_commit_transaction+0x8c2/0x2480 fs/btrfs/transaction.c:2176
       btrfs_sync_fs+0x120/0x490 fs/btrfs/super.c:1279
       __sync_filesystem fs/sync.c:39 [inline]
       sync_filesystem+0x1b5/0x250 fs/sync.c:67
       generic_shutdown_super+0x70/0x370 fs/super.c:442
       kill_anon_super+0x36/0x60 fs/super.c:1032
       btrfs_kill_super+0x49/0x550 fs/btrfs/super.c:2221
       deactivate_locked_super+0x94/0x160 fs/super.c:329
       deactivate_super+0x174/0x1a0 fs/super.c:360
       cleanup_mnt+0x1a8/0x290 fs/namespace.c:1098
       task_work_run+0x148/0x1c0 kernel/task_work.c:113
       tracehook_notify_resume include/linux/tracehook.h:193 [inline]
       exit_to_usermode_loop+0x251/0x2a0 arch/x86/entry/common.c:167
       prepare_exit_to_usermode arch/x86/entry/common.c:198 [inline]
       syscall_return_slowpath arch/x86/entry/common.c:271 [inline]
       do_syscall_64+0x538/0x620 arch/x86/entry/common.c:296
       entry_SYSCALL_64_after_hwframe+0x49/0xbe

-> #5 (&fs_info->reloc_mutex){+.+.}:
       btrfs_record_root_in_trans+0x122/0x190 fs/btrfs/transaction.c:394
       start_transaction+0x234/0xf90 fs/btrfs/transaction.c:586
       btrfs_dirty_inode+0xe3/0x210 fs/btrfs/inode.c:6165
       btrfs_update_time+0x33b/0x3d0 fs/btrfs/inode.c:6207
       update_time fs/inode.c:1675 [inline]
       touch_atime+0x23c/0x2a0 fs/inode.c:1746
       file_accessed include/linux/fs.h:2123 [inline]
       generic_file_buffered_read mm/filemap.c:2322 [inline]
       generic_file_read_iter+0x19a8/0x2b60 mm/filemap.c:2385
       call_read_iter include/linux/fs.h:1815 [inline]
       new_sync_read fs/read_write.c:406 [inline]
       __vfs_read+0x518/0x750 fs/read_write.c:418
       integrity_kernel_read+0x147/0x1f0 security/integrity/iint.c:200
       ima_calc_file_hash_tfm security/integrity/ima/ima_crypto.c:364 [inline]
       ima_calc_file_shash security/integrity/ima/ima_crypto.c:393 [inline]
       ima_calc_file_hash+0x4b2/0x8a0 security/integrity/ima/ima_crypto.c:450
       ima_collect_measurement+0x4c4/0x570 security/integrity/ima/ima_api.c:231
       process_measurement+0xddd/0x1440 security/integrity/ima/ima_main.c:284
       ima_file_check+0xb9/0x100 security/integrity/ima/ima_main.c:391
       do_last fs/namei.c:3425 [inline]
       path_openat+0x7e4/0x2df0 fs/namei.c:3537
       do_filp_open+0x18c/0x3f0 fs/namei.c:3567
       do_sys_open+0x3b3/0x520 fs/open.c:1085
       do_syscall_64+0xf9/0x620 arch/x86/entry/common.c:293
       entry_SYSCALL_64_after_hwframe+0x49/0xbe

-> #4 (sb_internal#4){.+.+}:
       sb_start_intwrite include/linux/fs.h:1626 [inline]
       start_transaction+0xa37/0xf90 fs/btrfs/transaction.c:528
       cow_file_range_inline.constprop.0+0x2f8/0xf90 fs/btrfs/inode.c:309
       cow_file_range.constprop.0+0x2af/0xa30 fs/btrfs/inode.c:1010
       btrfs_run_delalloc_range+0x1df/0xdb0 fs/btrfs/inode.c:1657
       writepage_delalloc+0x1d0/0x510 fs/btrfs/extent_io.c:3269
       __extent_writepage+0x447/0xcc0 fs/btrfs/extent_io.c:3522
       extent_write_cache_pages.constprop.0+0x6e6/0x1120 fs/btrfs/extent_io.c:4107
       extent_writepages+0x104/0x1a0 fs/btrfs/extent_io.c:4232
       do_writepages+0xe5/0x290 mm/page-writeback.c:2344
       __writeback_single_inode+0x10c/0x11d0 fs/fs-writeback.c:1385
       writeback_sb_inodes+0x537/0xef0 fs/fs-writeback.c:1647
       wb_writeback+0x28d/0xcc0 fs/fs-writeback.c:1820
       wb_do_writeback fs/fs-writeback.c:1965 [inline]
       wb_workfn+0x29b/0x1250 fs/fs-writeback.c:2006
       process_one_work+0x864/0x1570 kernel/workqueue.c:2153
       worker_thread+0x64c/0x1130 kernel/workqueue.c:2296
       kthread+0x33f/0x460 kernel/kthread.c:259
       ret_from_fork+0x24/0x30 arch/x86/entry/entry_64.S:415

-> #3 ((work_completion)(&(&wb->dwork)->work)){+.+.}:
       wb_shutdown+0x172/0x210 mm/backing-dev.c:374
       bdi_unregister+0x169/0x610 mm/backing-dev.c:946
       del_gendisk+0x7f6/0xa80 block/genhd.c:788
       loop_remove drivers/block/loop.c:2066 [inline]
       loop_control_ioctl drivers/block/loop.c:2165 [inline]
       loop_control_ioctl+0x3b1/0x480 drivers/block/loop.c:2131
       vfs_ioctl fs/ioctl.c:46 [inline]
       file_ioctl fs/ioctl.c:501 [inline]
       do_vfs_ioctl+0xcdb/0x12e0 fs/ioctl.c:688
       ksys_ioctl+0x9b/0xc0 fs/ioctl.c:705
       __do_sys_ioctl fs/ioctl.c:712 [inline]
       __se_sys_ioctl fs/ioctl.c:710 [inline]
       __x64_sys_ioctl+0x6f/0xb0 fs/ioctl.c:710
       do_syscall_64+0xf9/0x620 arch/x86/entry/common.c:293
       entry_SYSCALL_64_after_hwframe+0x49/0xbe

-> #2 (loop_ctl_mutex){+.+.}:
       lo_open+0x19/0xd0 drivers/block/loop.c:1771
       __blkdev_get+0x372/0x1480 fs/block_dev.c:1494
       blkdev_get+0xb0/0x940 fs/block_dev.c:1627
       blkdev_open+0x202/0x290 fs/block_dev.c:1788
       do_dentry_open+0x4aa/0x1160 fs/open.c:796
       do_last fs/namei.c:3421 [inline]
       path_openat+0x793/0x2df0 fs/namei.c:3537
       do_filp_open+0x18c/0x3f0 fs/namei.c:3567
       do_sys_open+0x3b3/0x520 fs/open.c:1085
       do_syscall_64+0xf9/0x620 arch/x86/entry/common.c:293
       entry_SYSCALL_64_after_hwframe+0x49/0xbe

-> #1 (&bdev->bd_mutex){+.+.}:
       blkdev_put+0x30/0x520 fs/block_dev.c:1839
       btrfs_close_bdev fs/btrfs/volumes.c:1033 [inline]
       btrfs_close_one_device fs/btrfs/volumes.c:1057 [inline]
       close_fs_devices.part.0+0x24d/0x8e0 fs/btrfs/volumes.c:1085
       close_fs_devices fs/btrfs/volumes.c:1117 [inline]
       btrfs_close_devices+0x95/0x1f0 fs/btrfs/volumes.c:1103
       open_ctree+0x26b/0x61e0 fs/btrfs/disk-io.c:3326
       btrfs_fill_super fs/btrfs/super.c:1209 [inline]
       btrfs_mount_root+0x12e5/0x1830 fs/btrfs/super.c:1613
       mount_fs+0xa3/0x310 fs/super.c:1261
       vfs_kern_mount.part.0+0x68/0x470 fs/namespace.c:961
       vfs_kern_mount+0x3c/0x60 fs/namespace.c:951
       btrfs_mount+0x23a/0xaa0 fs/btrfs/super.c:1681
       mount_fs+0xa3/0x310 fs/super.c:1261
       vfs_kern_mount.part.0+0x68/0x470 fs/namespace.c:961
       vfs_kern_mount fs/namespace.c:951 [inline]
       do_new_mount fs/namespace.c:2492 [inline]
       do_mount+0x115c/0x2f50 fs/namespace.c:2822
       ksys_mount+0xcf/0x130 fs/namespace.c:3038
       __do_sys_mount fs/namespace.c:3052 [inline]
       __se_sys_mount fs/namespace.c:3049 [inline]
       __x64_sys_mount+0xba/0x150 fs/namespace.c:3049
       do_syscall_64+0xf9/0x620 arch/x86/entry/common.c:293
       entry_SYSCALL_64_after_hwframe+0x49/0xbe

-> #0 (&fs_devs->device_list_mutex){+.+.}:
       __mutex_lock_common kernel/locking/mutex.c:937 [inline]
       __mutex_lock+0xd7/0x1190 kernel/locking/mutex.c:1078
       btrfs_run_dev_stats+0xbb/0xa80 fs/btrfs/volumes.c:7111
       commit_cowonly_roots+0x1ce/0xc30 fs/btrfs/transaction.c:1172
       btrfs_commit_transaction+0x94a/0x2480 fs/btrfs/transaction.c:2218
       btrfs_sync_fs+0x120/0x490 fs/btrfs/super.c:1279
       __sync_filesystem fs/sync.c:39 [inline]
       sync_filesystem+0x1b5/0x250 fs/sync.c:67
       generic_shutdown_super+0x70/0x370 fs/super.c:442
       kill_anon_super+0x36/0x60 fs/super.c:1032
       btrfs_kill_super+0x49/0x550 fs/btrfs/super.c:2221
       deactivate_locked_super+0x94/0x160 fs/super.c:329
       deactivate_super+0x174/0x1a0 fs/super.c:360
       cleanup_mnt+0x1a8/0x290 fs/namespace.c:1098
       task_work_run+0x148/0x1c0 kernel/task_work.c:113
       tracehook_notify_resume include/linux/tracehook.h:193 [inline]
       exit_to_usermode_loop+0x251/0x2a0 arch/x86/entry/common.c:167
       prepare_exit_to_usermode arch/x86/entry/common.c:198 [inline]
       syscall_return_slowpath arch/x86/entry/common.c:271 [inline]
       do_syscall_64+0x538/0x620 arch/x86/entry/common.c:296
       entry_SYSCALL_64_after_hwframe+0x49/0xbe

other info that might help us debug this:

Chain exists of:
  &fs_devs->device_list_mutex --> &fs_info->reloc_mutex --> &fs_info->tree_log_mutex

 Possible unsafe locking scenario:

       CPU0                    CPU1
       ----                    ----
  lock(&fs_info->tree_log_mutex);
                               lock(&fs_info->reloc_mutex);
                               lock(&fs_info->tree_log_mutex);
  lock(&fs_devs->device_list_mutex);

 *** DEADLOCK ***

3 locks held by syz-executor.1/8165:
 #0: 000000004e91aea6 (&type->s_umount_key#88){+.+.}, at: deactivate_super+0x16c/0x1a0 fs/super.c:359
 #1: 000000009636a286 (&fs_info->reloc_mutex){+.+.}, at: btrfs_commit_transaction+0x80b/0x2480 fs/btrfs/transaction.c:2120
 #2: 00000000f5f38e8d (&fs_info->tree_log_mutex){+.+.}, at: btrfs_commit_transaction+0x8c2/0x2480 fs/btrfs/transaction.c:2176

stack backtrace:
CPU: 0 PID: 8165 Comm: syz-executor.1 Not tainted 4.19.211-syzkaller #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 03/02/2023
Call Trace:
 __dump_stack lib/dump_stack.c:77 [inline]
 dump_stack+0x1fc/0x2ef lib/dump_stack.c:118
 print_circular_bug.constprop.0.cold+0x2d7/0x41e kernel/locking/lockdep.c:1222
 check_prev_add kernel/locking/lockdep.c:1866 [inline]
 check_prevs_add kernel/locking/lockdep.c:1979 [inline]
 validate_chain kernel/locking/lockdep.c:2420 [inline]
 __lock_acquire+0x30c9/0x3ff0 kernel/locking/lockdep.c:3416
 lock_acquire+0x170/0x3c0 kernel/locking/lockdep.c:3908
 __mutex_lock_common kernel/locking/mutex.c:937 [inline]
 __mutex_lock+0xd7/0x1190 kernel/locking/mutex.c:1078
 btrfs_run_dev_stats+0xbb/0xa80 fs/btrfs/volumes.c:7111
 commit_cowonly_roots+0x1ce/0xc30 fs/btrfs/transaction.c:1172
 btrfs_commit_transaction+0x94a/0x2480 fs/btrfs/transaction.c:2218
 btrfs_sync_fs+0x120/0x490 fs/btrfs/super.c:1279
 __sync_filesystem fs/sync.c:39 [inline]
 sync_filesystem+0x1b5/0x250 fs/sync.c:67
 generic_shutdown_super+0x70/0x370 fs/super.c:442
 kill_anon_super+0x36/0x60 fs/super.c:1032
 btrfs_kill_super+0x49/0x550 fs/btrfs/super.c:2221
 deactivate_locked_super+0x94/0x160 fs/super.c:329
 deactivate_super+0x174/0x1a0 fs/super.c:360
 cleanup_mnt+0x1a8/0x290 fs/namespace.c:1098
 task_work_run+0x148/0x1c0 kernel/task_work.c:113
 tracehook_notify_resume include/linux/tracehook.h:193 [inline]
 exit_to_usermode_loop+0x251/0x2a0 arch/x86/entry/common.c:167
 prepare_exit_to_usermode arch/x86/entry/common.c:198 [inline]
 syscall_return_slowpath arch/x86/entry/common.c:271 [inline]
 do_syscall_64+0x538/0x620 arch/x86/entry/common.c:296
 entry_SYSCALL_64_after_hwframe+0x49/0xbe
RIP: 0033:0x7fc0d4631567
Code: ff ff ff f7 d8 64 89 01 48 83 c8 ff c3 66 0f 1f 44 00 00 31 f6 e9 09 00 00 00 66 0f 1f 84 00 00 00 00 00 b8 a6 00 00 00 0f 05 <48> 3d 01 f0 ff ff 73 01 c3 48 c7 c1 b8 ff ff ff f7 d8 64 89 01 48
RSP: 002b:00007ffe64afc158 EFLAGS: 00000246 ORIG_RAX: 00000000000000a6
RAX: 0000000000000000 RBX: 0000000000000000 RCX: 00007fc0d4631567
RDX: 00007ffe64afc22b RSI: 000000000000000a RDI: 00007ffe64afc220
RBP: 00007ffe64afc220 R08: 00000000ffffffff R09: 00007ffe64afbff0
R10: 0000555555c27903 R11: 0000000000000246 R12: 00007fc0d468ab24
R13: 00007ffe64afd2e0 R14: 0000555555c27810 R15: 00007ffe64afd320
kauditd_printk_skb: 72 callbacks suppressed
audit: type=1804 audit(1678010413.387:2617): pid=22276 uid=0 auid=4294967295 ses=4294967295 subj==unconfined op=invalid_pcr cause=open_writers comm="syz-executor.2" name="/root/syzkaller-testdir444301101/syzkaller.y6kwvt/508/bus" dev="sda1" ino=13898 res=1
audit: type=1804 audit(1678010413.427:2618): pid=22276 uid=0 auid=4294967295 ses=4294967295 subj==unconfined op=invalid_pcr cause=ToMToU comm="syz-executor.2" name="/root/syzkaller-testdir444301101/syzkaller.y6kwvt/508/bus" dev="sda1" ino=13898 res=1
audit: type=1804 audit(1678010413.427:2619): pid=22276 uid=0 auid=4294967295 ses=4294967295 subj==unconfined op=invalid_pcr cause=open_writers comm="syz-executor.2" name="/root/syzkaller-testdir444301101/syzkaller.y6kwvt/508/bus" dev="sda1" ino=13898 res=1
audit: type=1804 audit(1678010413.427:2620): pid=22276 uid=0 auid=4294967295 ses=4294967295 subj==unconfined op=invalid_pcr cause=ToMToU comm="syz-executor.2" name="/root/syzkaller-testdir444301101/syzkaller.y6kwvt/508/bus" dev="sda1" ino=13898 res=1
audit: type=1804 audit(1678010413.427:2621): pid=22276 uid=0 auid=4294967295 ses=4294967295 subj==unconfined op=invalid_pcr cause=open_writers comm="syz-executor.2" name="/root/syzkaller-testdir444301101/syzkaller.y6kwvt/508/bus" dev="sda1" ino=13898 res=1
audit: type=1804 audit(1678010413.427:2622): pid=22276 uid=0 auid=4294967295 ses=4294967295 subj==unconfined op=invalid_pcr cause=ToMToU comm="syz-executor.2" name="/root/syzkaller-testdir444301101/syzkaller.y6kwvt/508/bus" dev="sda1" ino=13898 res=1
audit: type=1804 audit(1678010413.427:2623): pid=22276 uid=0 auid=4294967295 ses=4294967295 subj==unconfined op=invalid_pcr cause=open_writers comm="syz-executor.2" name="/root/syzkaller-testdir444301101/syzkaller.y6kwvt/508/bus" dev="sda1" ino=13898 res=1
audit: type=1804 audit(1678010413.987:2624): pid=22305 uid=0 auid=4294967295 ses=4294967295 subj==unconfined op=invalid_pcr cause=open_writers comm="syz-executor.1" name="/root/syzkaller-testdir1756392805/syzkaller.lAcL9o/442/bus" dev="sda1" ino=14082 res=1
audit: type=1804 audit(1678010414.867:2625): pid=22319 uid=0 auid=4294967295 ses=4294967295 subj==unconfined op=invalid_pcr cause=open_writers comm="syz-executor.1" name="/root/syzkaller-testdir1756392805/syzkaller.lAcL9o/443/bus" dev="sda1" ino=14082 res=1
BTRFS info (device loop5): using free space tree
BTRFS info (device loop5): has skinny extents
BTRFS info (device loop5): flagging fs with big metadata feature
audit: type=1804 audit(1678010415.717:2626): pid=22300 uid=0 auid=4294967295 ses=4294967295 subj==unconfined op=invalid_pcr cause=open_writers comm="syz-executor.5" name="/root/syzkaller-testdir625570643/syzkaller.nszaey/509/file0/bus" dev="loop5" ino=263 res=1
BTRFS info (device loop5): using free space tree
BTRFS info (device loop5): has skinny extents
BTRFS info (device loop5): flagging fs with big metadata feature
BTRFS info (device loop5): using free space tree
BTRFS info (device loop5): has skinny extents
BTRFS info (device loop5): flagging fs with big metadata feature
kauditd_printk_skb: 116 callbacks suppressed
audit: type=1804 audit(1678010419.698:2743): pid=22486 uid=0 auid=4294967295 ses=4294967295 subj==unconfined op=invalid_pcr cause=open_writers comm="syz-executor.5" name="/root/syzkaller-testdir625570643/syzkaller.nszaey/511/file0/bus" dev="loop5" ino=263 res=1
audit: type=1804 audit(1678010420.848:2744): pid=22588 uid=0 auid=4294967295 ses=4294967295 subj==unconfined op=invalid_pcr cause=open_writers comm="syz-executor.1" name="/root/syzkaller-testdir1756392805/syzkaller.lAcL9o/451/bus" dev="sda1" ino=13903 res=1
audit: type=1804 audit(1678010420.848:2745): pid=22588 uid=0 auid=4294967295 ses=4294967295 subj==unconfined op=invalid_pcr cause=ToMToU comm="syz-executor.1" name="/root/syzkaller-testdir1756392805/syzkaller.lAcL9o/451/bus" dev="sda1" ino=13903 res=1
Unknown ioctl -1067952631
audit: type=1804 audit(1678010420.848:2746): pid=22588 uid=0 auid=4294967295 ses=4294967295 subj==unconfined op=invalid_pcr cause=open_writers comm="syz-executor.1" name="/root/syzkaller-testdir1756392805/syzkaller.lAcL9o/451/bus" dev="sda1" ino=13903 res=1
IPVS: ftp: loaded support on port[0] = 21
audit: type=1804 audit(1678010420.848:2747): pid=22588 uid=0 auid=4294967295 ses=4294967295 subj==unconfined op=invalid_pcr cause=ToMToU comm="syz-executor.1" name="/root/syzkaller-testdir1756392805/syzkaller.lAcL9o/451/bus" dev="sda1" ino=13903 res=1
audit: type=1804 audit(1678010420.878:2748): pid=22588 uid=0 auid=4294967295 ses=4294967295 subj==unconfined op=invalid_pcr cause=open_writers comm="syz-executor.1" name="/root/syzkaller-testdir1756392805/syzkaller.lAcL9o/451/bus" dev="sda1" ino=13903 res=1
ieee802154 phy0 wpan0: encryption failed: -22
ieee802154 phy1 wpan1: encryption failed: -22
audit: type=1804 audit(1678010420.878:2749): pid=22585 uid=0 auid=4294967295 ses=4294967295 subj==unconfined op=invalid_pcr cause=ToMToU comm="syz-executor.1" name="/root/syzkaller-testdir1756392805/syzkaller.lAcL9o/451/bus" dev="sda1" ino=13903 res=1
x_tables: duplicate underflow at hook 1
audit: type=1804 audit(1678010420.878:2750): pid=22585 uid=0 auid=4294967295 ses=4294967295 subj==unconfined op=invalid_pcr cause=open_writers comm="syz-executor.1" name="/root/syzkaller-testdir1756392805/syzkaller.lAcL9o/451/bus" dev="sda1" ino=13903 res=1
audit: type=1804 audit(1678010420.938:2751): pid=22588 uid=0 auid=4294967295 ses=4294967295 subj==unconfined op=invalid_pcr cause=ToMToU comm="syz-executor.1" name="/root/syzkaller-testdir1756392805/syzkaller.lAcL9o/451/bus" dev="sda1" ino=13903 res=1