ntfs: volume version 3.1.
======================================================
syz-executor.3 (10839): drop_caches: 1
WARNING: possible circular locking dependency detected
4.14.305-syzkaller #0 Not tainted
------------------------------------------------------
kworker/u4:5/7956 is trying to acquire lock:
 (&rl->lock){++++}, at: [<ffffffff82102ce6>] ntfs_read_block fs/ntfs/aops.c:269 [inline]
 (&rl->lock){++++}, at: [<ffffffff82102ce6>] ntfs_readpage+0x1396/0x1ad0 fs/ntfs/aops.c:456

but task is already holding lock:
 (&ni->mrec_lock){+.+.}, at: [<ffffffff8213dccb>] map_mft_record+0x2b/0xbe0 fs/ntfs/mft.c:166

which lock already depends on the new lock.


the existing dependency chain (in reverse order) is:

-> #1 (&ni->mrec_lock){+.+.}:
       __mutex_lock_common kernel/locking/mutex.c:756 [inline]
       __mutex_lock+0xc4/0x1310 kernel/locking/mutex.c:893
       map_mft_record+0x2b/0xbe0 fs/ntfs/mft.c:166
       ntfs_truncate+0x1a6/0x22d0 fs/ntfs/inode.c:2415
       ntfs_truncate_vfs fs/ntfs/inode.c:2895 [inline]
       ntfs_setattr+0x148/0x580 fs/ntfs/inode.c:2945
       notify_change+0x56b/0xd10 fs/attr.c:315
       do_truncate+0xff/0x1a0 fs/open.c:63
       handle_truncate fs/namei.c:3010 [inline]
       do_last fs/namei.c:3437 [inline]
       path_openat+0x1dcc/0x2970 fs/namei.c:3571
       do_filp_open+0x179/0x3c0 fs/namei.c:3605
       do_sys_open+0x296/0x410 fs/open.c:1081
       do_syscall_64+0x1d5/0x640 arch/x86/entry/common.c:292
       entry_SYSCALL_64_after_hwframe+0x5e/0xd3

-> #0 (&rl->lock){++++}:
       lock_acquire+0x170/0x3f0 kernel/locking/lockdep.c:3998
       down_read+0x36/0x80 kernel/locking/rwsem.c:24
       ntfs_read_block fs/ntfs/aops.c:269 [inline]
       ntfs_readpage+0x1396/0x1ad0 fs/ntfs/aops.c:456
       do_read_cache_page+0x38e/0xc10 mm/filemap.c:2713
       read_mapping_page include/linux/pagemap.h:398 [inline]
       ntfs_map_page fs/ntfs/aops.h:89 [inline]
       ntfs_sync_mft_mirror+0x1f4/0x1560 fs/ntfs/mft.c:490
       write_mft_record_nolock+0xece/0x1240 fs/ntfs/mft.c:793
       write_mft_record fs/ntfs/mft.h:109 [inline]
       __ntfs_write_inode+0x58d/0xcc0 fs/ntfs/inode.c:3084
       write_inode fs/fs-writeback.c:1241 [inline]
       __writeback_single_inode+0x6a4/0x1010 fs/fs-writeback.c:1439
       writeback_sb_inodes+0x48b/0xd30 fs/fs-writeback.c:1645
       wb_writeback+0x243/0xb80 fs/fs-writeback.c:1820
       wb_do_writeback fs/fs-writeback.c:1952 [inline]
       wb_workfn+0x2bd/0xf50 fs/fs-writeback.c:1988
       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:

 Possible unsafe locking scenario:

       CPU0                    CPU1
       ----                    ----
  lock(&ni->mrec_lock);
                               lock(&rl->lock);
                               lock(&ni->mrec_lock);
  lock(&rl->lock);

 *** DEADLOCK ***

3 locks held by kworker/u4:5/7956:
 #0:  ("writeback"){+.+.}, at: [<ffffffff813660e0>] process_one_work+0x6b0/0x14a0 kernel/workqueue.c:2088
 #1:  ((&(&wb->dwork)->work)){+.+.}, at: [<ffffffff81366116>] process_one_work+0x6e6/0x14a0 kernel/workqueue.c:2092
 #2:  (&ni->mrec_lock){+.+.}, at: [<ffffffff8213dccb>] map_mft_record+0x2b/0xbe0 fs/ntfs/mft.c:166

stack backtrace:
CPU: 0 PID: 7956 Comm: kworker/u4:5 Not tainted 4.14.305-syzkaller #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/12/2023
Workqueue: writeback wb_workfn (flush-7:1)
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
 down_read+0x36/0x80 kernel/locking/rwsem.c:24
 ntfs_read_block fs/ntfs/aops.c:269 [inline]
 ntfs_readpage+0x1396/0x1ad0 fs/ntfs/aops.c:456
 do_read_cache_page+0x38e/0xc10 mm/filemap.c:2713
 read_mapping_page include/linux/pagemap.h:398 [inline]
 ntfs_map_page fs/ntfs/aops.h:89 [inline]
 ntfs_sync_mft_mirror+0x1f4/0x1560 fs/ntfs/mft.c:490
 write_mft_record_nolock+0xece/0x1240 fs/ntfs/mft.c:793
 write_mft_record fs/ntfs/mft.h:109 [inline]
 __ntfs_write_inode+0x58d/0xcc0 fs/ntfs/inode.c:3084
 write_inode fs/fs-writeback.c:1241 [inline]
 __writeback_single_inode+0x6a4/0x1010 fs/fs-writeback.c:1439
 writeback_sb_inodes+0x48b/0xd30 fs/fs-writeback.c:1645
 wb_writeback+0x243/0xb80 fs/fs-writeback.c:1820
 wb_do_writeback fs/fs-writeback.c:1952 [inline]
 wb_workfn+0x2bd/0xf50 fs/fs-writeback.c:1988
 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
audit: type=1800 audit(1675806308.355:37): pid=10894 uid=0 auid=4294967295 ses=4294967295 op="collect_data" cause="failed(directio)" comm="syz-executor.5" name="bus" dev="loop5" ino=7 res=0
syz-executor.2 (10880): drop_caches: 1
syz-executor.2 (10880): drop_caches: 1
audit: type=1800 audit(1675806309.315:38): pid=10919 uid=0 auid=4294967295 ses=4294967295 op="collect_data" cause="failed(directio)" comm="syz-executor.5" name="bus" dev="loop5" ino=7 res=0
syz-executor.3 (10909): drop_caches: 1
syz-executor.2 (10925): drop_caches: 1
syz-executor.3 (10909): drop_caches: 1
syz-executor.2 (10925): drop_caches: 1
devpts: called with bogus options
syz-executor.3 (10963): drop_caches: 1
syz-executor.3 (10963): drop_caches: 1
devpts: called with bogus options
devpts: called with bogus options
devpts: called with bogus options
devpts: called with bogus options
devpts: called with bogus options
devpts: called with bogus options
devpts: called with bogus options
devpts: called with bogus options
devpts: called with bogus options
devpts: called with bogus options
devpts: called with bogus options
devpts: called with bogus options
devpts: called with bogus options
device vxlan0 entered promiscuous mode
devpts: called with bogus options
devpts: called with bogus options
devpts: called with bogus options
netlink: 8 bytes leftover after parsing attributes in process `syz-executor.4'.
devpts: called with bogus options
devpts: called with bogus options
device vxlan0 entered promiscuous mode
netlink: 8 bytes leftover after parsing attributes in process `syz-executor.4'.
device vxlan0 entered promiscuous mode
netlink: 8 bytes leftover after parsing attributes in process `syz-executor.4'.
audit: type=1804 audit(1675806311.475:39): pid=11115 uid=0 auid=4294967295 ses=4294967295 op="invalid_pcr" cause="open_writers" comm="syz-executor.0" name="/root/syzkaller-testdir2283570738/syzkaller.XOXqfa/57/cgroup.controllers" dev="sda1" ino=14192 res=1
netlink: 8 bytes leftover after parsing attributes in process `syz-executor.4'.
device vxlan0 entered promiscuous mode
netlink: 12 bytes leftover after parsing attributes in process `syz-executor.4'.
audit: type=1804 audit(1675806311.845:40): pid=11155 uid=0 auid=4294967295 ses=4294967295 op="invalid_pcr" cause="open_writers" comm="syz-executor.5" name="/root/syzkaller-testdir611297587/syzkaller.9pHe1i/64/bus" dev="sda1" ino=14177 res=1
netlink: 12 bytes leftover after parsing attributes in process `syz-executor.4'.
audit: type=1800 audit(1675806311.865:41): pid=11155 uid=0 auid=4294967295 ses=4294967295 op="collect_data" cause="failed(directio)" comm="syz-executor.5" name="bus" dev="sda1" ino=14177 res=0
netlink: 12 bytes leftover after parsing attributes in process `syz-executor.1'.
audit: type=1804 audit(1675806312.545:42): pid=11167 uid=0 auid=4294967295 ses=4294967295 op="invalid_pcr" cause="open_writers" comm="syz-executor.0" name="/root/syzkaller-testdir2283570738/syzkaller.XOXqfa/58/cgroup.controllers" dev="sda1" ino=14158 res=1
netlink: 12 bytes leftover after parsing attributes in process `syz-executor.4'.
netlink: 12 bytes leftover after parsing attributes in process `syz-executor.1'.
audit: type=1804 audit(1675806312.695:43): pid=11188 uid=0 auid=4294967295 ses=4294967295 op="invalid_pcr" cause="open_writers" comm="syz-executor.5" name="/root/syzkaller-testdir611297587/syzkaller.9pHe1i/65/bus" dev="sda1" ino=14123 res=1
audit: type=1800 audit(1675806312.725:44): pid=11188 uid=0 auid=4294967295 ses=4294967295 op="collect_data" cause="failed(directio)" comm="syz-executor.5" name="bus" dev="sda1" ino=14123 res=0
netlink: 12 bytes leftover after parsing attributes in process `syz-executor.4'.
audit: type=1804 audit(1675806312.785:45): pid=11176 uid=0 auid=4294967295 ses=4294967295 op="invalid_pcr" cause="open_writers" comm="syz-executor.3" name="/root/syzkaller-testdir222909330/syzkaller.QAjma7/55/cgroup.controllers" dev="sda1" ino=14184 res=1
audit: type=1804 audit(1675806313.415:46): pid=11213 uid=0 auid=4294967295 ses=4294967295 op="invalid_pcr" cause="open_writers" comm="syz-executor.1" name="/root/syzkaller-testdir2808253161/syzkaller.FhZtTj/68/bus" dev="sda1" ino=14198 res=1
audit: type=1800 audit(1675806313.445:47): pid=11213 uid=0 auid=4294967295 ses=4294967295 op="collect_data" cause="failed(directio)" comm="syz-executor.1" name="bus" dev="sda1" ino=14198 res=0
audit: type=1804 audit(1675806313.465:48): pid=11207 uid=0 auid=4294967295 ses=4294967295 op="invalid_pcr" cause="open_writers" comm="syz-executor.0" name="/root/syzkaller-testdir2283570738/syzkaller.XOXqfa/59/cgroup.controllers" dev="sda1" ino=14172 res=1
kauditd_printk_skb: 10 callbacks suppressed
audit: type=1804 audit(1675806316.625:59): pid=11263 uid=0 auid=4294967295 ses=4294967295 op="invalid_pcr" cause="open_writers" comm="syz-executor.3" name="/root/syzkaller-testdir222909330/syzkaller.QAjma7/57/cgroup.controllers" dev="sda1" ino=14203 res=1
audit: type=1804 audit(1675806316.725:60): pid=11251 uid=0 auid=4294967295 ses=4294967295 op="invalid_pcr" cause="open_writers" comm="syz-executor.0" name="/root/syzkaller-testdir2283570738/syzkaller.XOXqfa/60/cgroup.controllers" dev="sda1" ino=14173 res=1
audit: type=1804 audit(1675806316.845:61): pid=11268 uid=0 auid=4294967295 ses=4294967295 op="invalid_pcr" cause="open_writers" comm="syz-executor.4" name="/root/syzkaller-testdir3188793953/syzkaller.6ki3xz/55/cgroup.controllers" dev="sda1" ino=14200 res=1
audit: type=1804 audit(1675806317.565:62): pid=11306 uid=0 auid=4294967295 ses=4294967295 op="invalid_pcr" cause="open_writers" comm="syz-executor.4" name="/root/syzkaller-testdir3188793953/syzkaller.6ki3xz/56/cgroup.controllers" dev="sda1" ino=14154 res=1