audit: type=1804 audit(1675598896.689:20): pid=11284 uid=0 auid=4294967295 ses=4294967295 op="invalid_pcr" cause="open_writers" comm="syz-executor.4" name="/root/syzkaller-testdir3549742086/syzkaller.aQ0zwQ/92/.log" dev="sda1" ino=14033 res=1
ntfs: (device loop2): parse_options(): Option utf8 is no longer supported, using option nls=utf8. Please use option nls=utf8 in the future and make sure utf8 is compiled either as a module or into the kernel.
======================================================
WARNING: possible circular locking dependency detected
4.14.304-syzkaller #0 Not tainted
------------------------------------------------------
syz-executor.1/11344 is trying to acquire lock:
 (&sbi->alloc_mutex){+.+.}, at: [<ffffffff81d45e77>] hfsplus_block_free+0xc7/0x560 fs/hfsplus/bitmap.c:182

but task is already holding lock:
 (&tree->tree_lock/1){+.+.}, at: [<ffffffff81d402f1>] hfsplus_find_init+0x161/0x220 fs/hfsplus/bfind.c:33

which lock already depends on the new lock.


the existing dependency chain (in reverse order) is:

-> #2 (&tree->tree_lock/1){+.+.}:
       __mutex_lock_common kernel/locking/mutex.c:756 [inline]
       __mutex_lock+0xc4/0x1310 kernel/locking/mutex.c:893
       hfsplus_find_init+0x161/0x220 fs/hfsplus/bfind.c:33
       hfsplus_ext_read_extent+0x15f/0x9e0 fs/hfsplus/extents.c:216
       hfsplus_get_block+0x23e/0x820 fs/hfsplus/extents.c:268
       block_read_full_page+0x25e/0x8d0 fs/buffer.c:2316
       do_read_cache_page+0x38e/0xc10 mm/filemap.c:2713
       read_mapping_page include/linux/pagemap.h:398 [inline]
       hfsplus_block_allocate+0x189/0x910 fs/hfsplus/bitmap.c:37
       hfsplus_file_extend+0x421/0xef0 fs/hfsplus/extents.c:463
       hfsplus_get_block+0x15b/0x820 fs/hfsplus/extents.c:245
       __block_write_begin_int+0x35c/0x11d0 fs/buffer.c:2038
       __block_write_begin fs/buffer.c:2088 [inline]
       block_write_begin+0x58/0x270 fs/buffer.c:2147
       cont_write_begin+0x4a3/0x740 fs/buffer.c:2497
       hfsplus_write_begin+0x87/0x130 fs/hfsplus/inode.c:53
       generic_perform_write+0x1d5/0x430 mm/filemap.c:3055
       __generic_file_write_iter+0x227/0x590 mm/filemap.c:3180
       generic_file_write_iter+0x36f/0x650 mm/filemap.c:3208
       call_write_iter include/linux/fs.h:1780 [inline]
       new_sync_write fs/read_write.c:469 [inline]
       __vfs_write+0x44c/0x630 fs/read_write.c:482
       vfs_write+0x17f/0x4d0 fs/read_write.c:544
       SYSC_write fs/read_write.c:590 [inline]
       SyS_write+0xf2/0x210 fs/read_write.c:582
       do_syscall_64+0x1d5/0x640 arch/x86/entry/common.c:292
       entry_SYSCALL_64_after_hwframe+0x5e/0xd3

-> #1 (&HFSPLUS_I(inode)->extents_lock){+.+.}:
       __mutex_lock_common kernel/locking/mutex.c:756 [inline]
       __mutex_lock+0xc4/0x1310 kernel/locking/mutex.c:893
       hfsplus_get_block+0x1f9/0x820 fs/hfsplus/extents.c:260
       block_read_full_page+0x25e/0x8d0 fs/buffer.c:2316
       do_read_cache_page+0x38e/0xc10 mm/filemap.c:2713
       read_mapping_page include/linux/pagemap.h:398 [inline]
       hfsplus_block_allocate+0x189/0x910 fs/hfsplus/bitmap.c:37
       hfsplus_file_extend+0x421/0xef0 fs/hfsplus/extents.c:463
       hfsplus_get_block+0x15b/0x820 fs/hfsplus/extents.c:245
       __block_write_begin_int+0x35c/0x11d0 fs/buffer.c:2038
       __block_write_begin fs/buffer.c:2088 [inline]
       block_write_begin+0x58/0x270 fs/buffer.c:2147
       cont_write_begin+0x4a3/0x740 fs/buffer.c:2497
       hfsplus_write_begin+0x87/0x130 fs/hfsplus/inode.c:53
       generic_perform_write+0x1d5/0x430 mm/filemap.c:3055
       __generic_file_write_iter+0x227/0x590 mm/filemap.c:3180
       generic_file_write_iter+0x36f/0x650 mm/filemap.c:3208
       call_write_iter include/linux/fs.h:1780 [inline]
       new_sync_write fs/read_write.c:469 [inline]
       __vfs_write+0x44c/0x630 fs/read_write.c:482
       vfs_write+0x17f/0x4d0 fs/read_write.c:544
       SYSC_write fs/read_write.c:590 [inline]
       SyS_write+0xf2/0x210 fs/read_write.c:582
       do_syscall_64+0x1d5/0x640 arch/x86/entry/common.c:292
       entry_SYSCALL_64_after_hwframe+0x5e/0xd3

-> #0 (&sbi->alloc_mutex){+.+.}:
       lock_acquire+0x170/0x3f0 kernel/locking/lockdep.c:3998
       __mutex_lock_common kernel/locking/mutex.c:756 [inline]
       __mutex_lock+0xc4/0x1310 kernel/locking/mutex.c:893
       hfsplus_block_free+0xc7/0x560 fs/hfsplus/bitmap.c:182
       hfsplus_free_extents+0x320/0x440 fs/hfsplus/extents.c:371
       hfsplus_file_truncate+0xbc0/0xe80 fs/hfsplus/extents.c:585
       hfsplus_file_release+0xbc/0x1e0 fs/hfsplus/inode.c:234
       __fput+0x25f/0x7a0 fs/file_table.c:210
       task_work_run+0x11f/0x190 kernel/task_work.c:113
       exit_task_work include/linux/task_work.h:22 [inline]
       do_exit+0xa44/0x2850 kernel/exit.c:868
       do_group_exit+0x100/0x2e0 kernel/exit.c:965
       get_signal+0x38d/0x1ca0 kernel/signal.c:2412
       do_signal+0x7c/0x1550 arch/x86/kernel/signal.c:792
       exit_to_usermode_loop+0x160/0x200 arch/x86/entry/common.c:160
       prepare_exit_to_usermode arch/x86/entry/common.c:199 [inline]
       syscall_return_slowpath arch/x86/entry/common.c:270 [inline]
       do_syscall_64+0x4a3/0x640 arch/x86/entry/common.c:297
       entry_SYSCALL_64_after_hwframe+0x5e/0xd3

other info that might help us debug this:

Chain exists of:
  &sbi->alloc_mutex --> &HFSPLUS_I(inode)->extents_lock --> &tree->tree_lock/1

 Possible unsafe locking scenario:

       CPU0                    CPU1
       ----                    ----
  lock(&tree->tree_lock/1);
                               lock(&HFSPLUS_I(inode)->extents_lock);
                               lock(&tree->tree_lock/1);
  lock(&sbi->alloc_mutex);

 *** DEADLOCK ***

3 locks held by syz-executor.1/11344:
 #0:  (&sb->s_type->i_mutex_key#24){+.+.}, at: [<ffffffff81d28964>] inode_lock include/linux/fs.h:719 [inline]
 #0:  (&sb->s_type->i_mutex_key#24){+.+.}, at: [<ffffffff81d28964>] hfsplus_file_release+0xb4/0x1e0 fs/hfsplus/inode.c:233
 #1:  (&hip->extents_lock){+.+.}, at: [<ffffffff81d2e69a>] hfsplus_file_truncate+0x1ba/0xe80 fs/hfsplus/extents.c:571
 #2:  (&tree->tree_lock/1){+.+.}, at: [<ffffffff81d402f1>] hfsplus_find_init+0x161/0x220 fs/hfsplus/bfind.c:33

stack backtrace:
CPU: 1 PID: 11344 Comm: syz-executor.1 Not tainted 4.14.304-syzkaller #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/12/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
 __mutex_lock_common kernel/locking/mutex.c:756 [inline]
 __mutex_lock+0xc4/0x1310 kernel/locking/mutex.c:893
 hfsplus_block_free+0xc7/0x560 fs/hfsplus/bitmap.c:182
 hfsplus_free_extents+0x320/0x440 fs/hfsplus/extents.c:371
 hfsplus_file_truncate+0xbc0/0xe80 fs/hfsplus/extents.c:585
 hfsplus_file_release+0xbc/0x1e0 fs/hfsplus/inode.c:234
 __fput+0x25f/0x7a0 fs/file_table.c:210
 task_work_run+0x11f/0x190 kernel/task_work.c:113
 exit_task_work include/linux/task_work.h:22 [inline]
 do_exit+0xa44/0x2850 kernel/exit.c:868
 do_group_exit+0x100/0x2e0 kernel/exit.c:965
 get_signal+0x38d/0x1ca0 kernel/signal.c:2412
 do_signal+0x7c/0x1550 arch/x86/kernel/signal.c:792
 exit_to_usermode_loop+0x160/0x200 arch/x86/entry/common.c:160
 prepare_exit_to_usermode arch/x86/entry/common.c:199 [inline]
 syscall_return_slowpath arch/x86/entry/common.c:270 [inline]
 do_syscall_64+0x4a3/0x640 arch/x86/entry/common.c:297
 entry_SYSCALL_64_after_hwframe+0x5e/0xd3
RIP: 0033:0x7f64ace010c9
RSP: 002b:00007f64ab373218 EFLAGS: 00000246 ORIG_RAX: 00000000000000ca
RAX: 0000000000000001 RBX: 00007f64acf20f88 RCX: 00007f64ace010c9
RDX: 00000000000f4240 RSI: 0000000000000081 RDI: 00007f64acf20f8c
RBP: 00007f64acf20f80 R08: 0000003bac815590 R09: 0000000000000000
R10: 0000000000000006 R11: 0000000000000246 R12: 00007f64acf20f8c
R13: 00007ffc626bde2f R14: 00007f64ab373300 R15: 0000000000022000
audit: type=1800 audit(1675598896.929:21): pid=11344 uid=0 auid=4294967295 ses=4294967295 op="collect_data" cause="failed(directio)" comm="syz-executor.1" name=BCE0EE855094564983F1B4FE81AF4A6CADB156D7BAB80F52D8A7CD8E2020F9E69E64D4DD35EDA7BF1B31F1277AAE1330896BE7535308D3441A1E6B8B93774351CF5A2C72BF231EFEC81F5466AF8C2127B7A8C3DF831EC1AB6745A04C3CEA4F39C14F283D7C3C694F0789534B57230DCA6CFEDF760EBA7EDABE192A2539976F6C84AE82F2585B36F58A9194EB62D6E6B408C853C998CFCECADF083FECB1AAB167B71DE55F157EC802551FDF385A3288CF2E dev="loop1" ino=4 res=0
ntfs: volume version 3.1.
XFS (loop5): Superblock has unknown read-only compatible features (0x8) enabled.
XFS (loop5): Attempted to mount read-only compatible filesystem read-write.
XFS (loop5): Filesystem can only be safely mounted read only.
XFS (loop5): SB validate failed with error -22.
syz-executor.5 (11325): drop_caches: 2
syz-executor.5 (11325): drop_caches: 2
EXT4-fs (loop0): mounted filesystem without journal. Opts: ,errors=continue
audit: type=1800 audit(1675598898.079:22): pid=11382 uid=0 auid=4294967295 ses=4294967295 op="collect_data" cause="failed(directio)" comm="syz-executor.1" name=BCE0EE855094564983F1B4FE81AF4A6CADB156D7BAB80F52D8A7CD8E2020F9E69E64D4DD35EDA7BF1B31F1277AAE1330896BE7535308D3441A1E6B8B93774351CF5A2C72BF231EFEC81F5466AF8C2127B7A8C3DF831EC1AB6745A04C3CEA4F39C14F283D7C3C694F0789534B57230DCA6CFEDF760EBA7EDABE192A2539976F6C84AE82F2585B36F58A9194EB62D6E6B408C853C998CFCECADF083FECB1AAB167B71DE55F157EC802551FDF385A3288CF2E dev="loop1" ino=4 res=0
REISERFS (device loop5): found reiserfs format "3.5" with non-standard journal
audit: type=1800 audit(1675598898.229:23): pid=11413 uid=0 auid=4294967295 ses=4294967295 op="collect_data" cause="failed(directio)" comm="syz-executor.1" name=BCE0EE855094564983F1B4FE81AF4A6CADB156D7BAB80F52D8A7CD8E2020F9E69E64D4DD35EDA7BF1B31F1277AAE1330896BE7535308D3441A1E6B8B93774351CF5A2C72BF231EFEC81F5466AF8C2127B7A8C3DF831EC1AB6745A04C3CEA4F39C14F283D7C3C694F0789534B57230DCA6CFEDF760EBA7EDABE192A2539976F6C84AE82F2585B36F58A9194EB62D6E6B408C853C998CFCECADF083FECB1AAB167B71DE55F157EC802551FDF385A3288CF2E dev="loop1" ino=4 res=0
EXT4-fs (loop3): mounted filesystem without journal. Opts: ,errors=continue
REISERFS (device loop5): using ordered data mode
reiserfs: using flush barriers
REISERFS (device loop5): journal params: device loop5, size 512, journal first block 18, max trans len 256, max batch 225, max commit age 30, max trans age 30
REISERFS (device loop5): checking transaction log (loop5)
REISERFS (device loop5): Using r5 hash to sort names
audit: type=1800 audit(1675598898.469:24): pid=11433 uid=0 auid=4294967295 ses=4294967295 op="collect_data" cause="failed(directio)" comm="syz-executor.1" name=BCE0EE855094564983F1B4FE81AF4A6CADB156D7BAB80F52D8A7CD8E2020F9E69E64D4DD35EDA7BF1B31F1277AAE1330896BE7535308D3441A1E6B8B93774351CF5A2C72BF231EFEC81F5466AF8C2127B7A8C3DF831EC1AB6745A04C3CEA4F39C14F283D7C3C694F0789534B57230DCA6CFEDF760EBA7EDABE192A2539976F6C84AE82F2585B36F58A9194EB62D6E6B408C853C998CFCECADF083FECB1AAB167B71DE55F157EC802551FDF385A3288CF2E dev="loop1" ino=4 res=0
REISERFS warning (device loop5): jdm-13090 reiserfs_new_inode: ACLs aren't enabled in the fs, but vfs thinks they are!
REISERFS (device loop5): Created .reiserfs_priv - reserved for xattr storage.
XFS (loop4): Superblock has unknown read-only compatible features (0x8) enabled.
XFS (loop4): Attempted to mount read-only compatible filesystem read-write.
XFS (loop4): Filesystem can only be safely mounted read only.
EXT4-fs (loop3): mounted filesystem without journal. Opts: ,errors=continue
XFS (loop4): SB validate failed with error -22.
BTRFS error (device loop0): unsupported checksum algorithm 1
BTRFS error (device loop0): superblock checksum mismatch
syz-executor.4 (11399): drop_caches: 2
BTRFS error (device loop0): open_ctree failed
print_req_error: I/O error, dev loop5, sector 0
syz-executor.4 (11399): drop_caches: 2
unregister_netdevice: waiting for ip6gre0 to become free. Usage count = -1
BTRFS: device fsid 24c7a497-3402-47dd-bef8-82358f5f30e0 devid 1 transid 8 /dev/loop1
NILFS (loop5): segctord starting. Construction interval = 5 seconds, CP frequency < 30 seconds
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
audit: type=1800 audit(1675598898.969:25): pid=11422 uid=0 auid=4294967295 ses=4294967295 op="collect_data" cause="failed(directio)" comm="syz-executor.0" name="file1" dev="sda1" ino=13960 res=0
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
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
BTRFS info (device loop4): enabling inode map caching
BTRFS info (device loop4): trying to use backup root at mount time
BTRFS info (device loop4): use zlib compression
BTRFS info (device loop4): enabling ssd optimizations
BTRFS info (device loop4): using spread ssd allocation scheme
BTRFS info (device loop4): using free space tree
BTRFS info (device loop4): has skinny extents
BTRFS info (device loop4): enabling inode map caching
BTRFS info (device loop4): trying to use backup root at mount time
BTRFS info (device loop4): use zlib compression
BTRFS info (device loop4): enabling ssd optimizations
BTRFS info (device loop4): using spread ssd allocation scheme
BTRFS info (device loop4): using free space tree
BTRFS info (device loop4): has skinny extents
EXT4-fs (loop1): mounted filesystem without journal. Opts: ,errors=continue
nested_vmx_exit_reflected failed vm entry 7
*** Guest State ***
CR0: actual=0x0000000080000031, shadow=0x00000000e0000031, gh_mask=fffffffffffffff7
CR4: actual=0x0000000000112240, shadow=0x0000000000112200, gh_mask=ffffffffffffe871
EXT4-fs (loop1): mounted filesystem without journal. Opts: ,errors=continue
CR3 = 0x0000000000002000
RSP = 0x0000000000000f80  RIP = 0x0000000000000679
RFLAGS=0x00000042         DR7 = 0x0000000000000400
Sysenter RSP=0000000000000f80 CS:RIP=0050:0000000000002810
CS:   sel=0x0050, attr=0x0209b, limit=0x0000ffff, base=0x0000000000000000
DS:   sel=0x0038, attr=0x04093, limit=0x000fffff, base=0x0000000000000000
SS:   sel=0x0038, attr=0x04093, limit=0x000fffff, base=0x0000000000000000
ES:   sel=0x0038, attr=0x04093, limit=0x000fffff, base=0x0000000000000000
FS:   sel=0x0038, attr=0x04093, limit=0x000fffff, base=0x0000000000000000
GS:   sel=0x0038, attr=0x04093, limit=0x000fffff, base=0x0000000000000000
GDTR:                           limit=0x000007ff, base=0x0000000000001000
LDTR: sel=0x0008, attr=0x04082, limit=0x000007ff, base=0x0000000000001800
IDTR:                           limit=0x000001ff, base=0x0000000000003800
EXT4-fs (loop1): mounted filesystem without journal. Opts: ,errors=continue
TR:   sel=0x00d8, attr=0x0008b, limit=0x000001ff, base=0x0000000000003a00
EFER =     0x0000000000000501  PAT = 0x0007040600070406
DebugCtl = 0x0000000000000000  DebugExceptions = 0x0000000000000000
Interruptibility = 00000000  ActivityState = 00000000
*** Host State ***
RIP = 0xffffffff8116183e  RSP = 0xffff88804b0479b8
CS=0010 SS=0018 DS=0000 ES=0000 FS=0000 GS=0000 TR=0040
FSBase=00007f1d7318a700 GSBase=ffff8880ba500000 TRBase=fffffe000003e000
GDTBase=fffffe000003c000 IDTBase=fffffe0000000000
CR0=0000000080050033 CR3=00000000923a7000 CR4=00000000003426e0
Sysenter RSP=fffffe000003e000 CS:RIP=0010:ffffffff87401780
EFER = 0x0000000000000d01  PAT = 0x0407050600070106
*** Control State ***
PinBased=0000003f CPUBased=b6986dfa SecondaryExec=000040ea
EntryControls=0000d3ff ExitControls=002fefff
ExceptionBitmap=00060042 PFECmask=00000000 PFECmatch=00000000
VMEntry: intr_info=00000000 errcode=00000000 ilen=00000000
VMExit: intr_info=00000000 errcode=00000000 ilen=00000001
        reason=80000021 qualification=0000000000000000
IDTVectoring: info=00000000 errcode=00000000
TSC Offset = 0xffffff85e77932d4
EPT pointer = 0x000000009aa3c01e
Virtual processor ID = 0x0001
EXT4-fs (loop1): mounted filesystem without journal. Opts: ,errors=continue
kauditd_printk_skb: 1 callbacks suppressed
audit: type=1800 audit(1675598904.700:27): pid=12137 uid=0 auid=4294967295 ses=4294967295 op="collect_data" cause="failed(directio)" comm="syz-executor.5" name="file0" dev="sda1" ino=14126 res=0
audit: type=1800 audit(1675598905.170:28): pid=12181 uid=0 auid=4294967295 ses=4294967295 op="collect_data" cause="failed(directio)" comm="syz-executor.5" name="file0" dev="sda1" ino=14126 res=0
audit: type=1800 audit(1675598905.560:29): pid=12192 uid=0 auid=4294967295 ses=4294967295 op="collect_data" cause="failed(directio)" comm="syz-executor.5" name="file0" dev="sda1" ino=14150 res=0
audit: type=1804 audit(1675598905.620:30): pid=12204 uid=0 auid=4294967295 ses=4294967295 op="invalid_pcr" cause="ToMToU" comm="syz-executor.4" name="/root/syzkaller-testdir3549742086/syzkaller.aQ0zwQ/116/file0" dev="sda1" ino=14151 res=1
audit: type=1804 audit(1675598905.750:31): pid=12222 uid=0 auid=4294967295 ses=4294967295 op="invalid_pcr" cause="ToMToU" comm="syz-executor.4" name="/root/syzkaller-testdir3549742086/syzkaller.aQ0zwQ/117/file0" dev="sda1" ino=14151 res=1
audit: type=1804 audit(1675598905.900:32): pid=12238 uid=0 auid=4294967295 ses=4294967295 op="invalid_pcr" cause="ToMToU" comm="syz-executor.4" name="/root/syzkaller-testdir3549742086/syzkaller.aQ0zwQ/118/file0" dev="sda1" ino=14151 res=1
audit: type=1804 audit(1675598906.440:33): pid=12265 uid=0 auid=4294967295 ses=4294967295 op="invalid_pcr" cause="ToMToU" comm="syz-executor.4" name="/root/syzkaller-testdir3549742086/syzkaller.aQ0zwQ/119/file0" dev="sda1" ino=14165 res=1
audit: type=1800 audit(1675598906.450:34): pid=12269 uid=0 auid=4294967295 ses=4294967295 op="collect_data" cause="failed(directio)" comm="syz-executor.5" name="file0" dev="sda1" ino=14167 res=0