possible deadlock in hfsplus_block_free
10 views
Skip to first unread message
syzbot
Dec 1, 2022, 2:36:46 PM12/1/22
to syzkaller...@googlegroups.com
Hello,
syzbot found the following issue on:
HEAD commit: 179ef7fe8677 Linux 4.14.300
git tree: linux-4.14.y
console output: https://syzkaller.appspot.com/x/log.txt?x=1777e1a1880000
kernel config: https://syzkaller.appspot.com/x/.config?x=aa85f51ec321d5a9
dashboard link: https://syzkaller.appspot.com/bug?extid=29adb337e20196ce447a
compiler: gcc version 10.2.1 20210110 (Debian 10.2.1-6)
Unfortunately, I don't have any reproducer for this issue yet.
Downloadable assets:
disk image: https://storage.googleapis.com/syzbot-assets/d311ef57b59a/disk-179ef7fe.raw.xz
vmlinux: https://storage.googleapis.com/syzbot-assets/25bf5d729f69/vmlinux-179ef7fe.xz
kernel image: https://storage.googleapis.com/syzbot-assets/db9b96571e69/bzImage-179ef7fe.xz
IMPORTANT: if you fix the issue, please add the following tag to the commit:
Reported-by: syzbot+29adb3...@syzkaller.appspotmail.com
audit: type=1804 audit(1669923371.824:13): pid=12019 uid=0 auid=4294967295 ses=4294967295 op="invalid_pcr" cause="open_writers" comm="syz-executor.4" name="/root/syzkaller-testdir1635526590/syzkaller.1UIi16/94/file0/bus" dev="loop4" ino=25 res=1
======================================================
WARNING: possible circular locking dependency detected
4.14.300-syzkaller #0 Not tainted
------------------------------------------------------
syz-executor.4/12019 is trying to acquire lock:
(&sbi->alloc_mutex){+.+.}, at: [<ffffffff81d45b97>] hfsplus_block_free+0xc7/0x560 fs/hfsplus/bitmap.c:182
but task is already holding lock:
(&tree->tree_lock#2/1){+.+.}, at: [<ffffffff81d40011>] hfsplus_find_init+0x161/0x220 fs/hfsplus/bfind.c:33
audit: type=1804 audit(1669923371.834:14): pid=12019 uid=0 auid=4294967295 ses=4294967295 op="invalid_pcr" cause="ToMToU" comm="syz-executor.4" name="/root/syzkaller-testdir1635526590/syzkaller.1UIi16/94/file0/bus" dev="loop4" ino=25 res=1
which lock already depends on the new lock.
the existing dependency chain (in reverse order) is:
-> #2 (&tree->tree_lock#2/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
audit: type=1804 audit(1669923371.834:15): pid=12019 uid=0 auid=4294967295 ses=4294967295 op="invalid_pcr" cause="ToMToU" comm="syz-executor.4" name="/root/syzkaller-testdir1635526590/syzkaller.1UIi16/94/file0/bus" dev="loop4" ino=25 res=1
cont_write_begin+0x4a3/0x740 fs/buffer.c:2497
hfsplus_write_begin+0x87/0x130 fs/hfsplus/inode.c:53
cont_expand_zero fs/buffer.c:2424 [inline]
cont_write_begin+0x296/0x740 fs/buffer.c:2487
hfsplus_write_begin+0x87/0x130 fs/hfsplus/inode.c:53
generic_cont_expand_simple+0xe1/0x130 fs/buffer.c:2388
hfsplus_setattr+0x139/0x310 fs/hfsplus/inode.c:258
notify_change+0x56b/0xd10 fs/attr.c:315
do_truncate+0xff/0x1a0 fs/open.c:63
do_sys_ftruncate.constprop.0+0x3a3/0x480 fs/open.c:205
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
cont_expand_zero fs/buffer.c:2424 [inline]
cont_write_begin+0x296/0x740 fs/buffer.c:2487
hfsplus_write_begin+0x87/0x130 fs/hfsplus/inode.c:53
generic_cont_expand_simple+0xe1/0x130 fs/buffer.c:2388
hfsplus_setattr+0x139/0x310 fs/hfsplus/inode.c:258
notify_change+0x56b/0xd10 fs/attr.c:315
do_truncate+0xff/0x1a0 fs/open.c:63
do_sys_ftruncate.constprop.0+0x3a3/0x480 fs/open.c:205
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_write_failed fs/hfsplus/inode.c:42 [inline]
hfsplus_write_begin+0x103/0x130 fs/hfsplus/inode.c:57
cont_expand_zero fs/buffer.c:2424 [inline]
cont_write_begin+0x296/0x740 fs/buffer.c:2487
hfsplus_write_begin+0x87/0x130 fs/hfsplus/inode.c:53
generic_cont_expand_simple+0xe1/0x130 fs/buffer.c:2388
hfsplus_setattr+0x139/0x310 fs/hfsplus/inode.c:258
notify_change+0x56b/0xd10 fs/attr.c:315
do_truncate+0xff/0x1a0 fs/open.c:63
do_sys_ftruncate.constprop.0+0x3a3/0x480 fs/open.c:205
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:
&sbi->alloc_mutex --> &HFSPLUS_I(inode)->extents_lock --> &tree->tree_lock#2/1
Possible unsafe locking scenario:
CPU0 CPU1
---- ----
lock(&tree->tree_lock#2/1);
lock(&HFSPLUS_I(inode)->extents_lock);
lock(&tree->tree_lock#2/1);
lock(&sbi->alloc_mutex);
*** DEADLOCK ***
4 locks held by syz-executor.4/12019:
#0: (sb_writers#13){.+.+}, at: [<ffffffff81867a9b>] sb_start_write include/linux/fs.h:1551 [inline]
#0: (sb_writers#13){.+.+}, at: [<ffffffff81867a9b>] do_sys_ftruncate.constprop.0+0x1fb/0x480 fs/open.c:200
#1: (&sb->s_type->i_mutex_key#21){+.+.}, at: [<ffffffff81867080>] inode_lock include/linux/fs.h:719 [inline]
#1: (&sb->s_type->i_mutex_key#21){+.+.}, at: [<ffffffff81867080>] do_truncate+0xf0/0x1a0 fs/open.c:61
#2: (&hip->extents_lock){+.+.}, at: [<ffffffff81d2e3ba>] hfsplus_file_truncate+0x1ba/0xe80 fs/hfsplus/extents.c:571
#3: (&tree->tree_lock#2/1){+.+.}, at: [<ffffffff81d40011>] hfsplus_find_init+0x161/0x220 fs/hfsplus/bfind.c:33
stack backtrace:
CPU: 1 PID: 12019 Comm: syz-executor.4 Not tainted 4.14.300-syzkaller #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 10/26/2022
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_write_failed fs/hfsplus/inode.c:42 [inline]
hfsplus_write_begin+0x103/0x130 fs/hfsplus/inode.c:57
cont_expand_zero fs/buffer.c:2424 [inline]
cont_write_begin+0x296/0x740 fs/buffer.c:2487
hfsplus_write_begin+0x87/0x130 fs/hfsplus/inode.c:53
generic_cont_expand_simple+0xe1/0x130 fs/buffer.c:2388
hfsplus_setattr+0x139/0x310 fs/hfsplus/inode.c:258
notify_change+0x56b/0xd10 fs/attr.c:315
do_truncate+0xff/0x1a0 fs/open.c:63
do_sys_ftruncate.constprop.0+0x3a3/0x480 fs/open.c:205
do_syscall_64+0x1d5/0x640 arch/x86/entry/common.c:292
entry_SYSCALL_64_after_hwframe+0x5e/0xd3
audit: type=1804 audit(1669923372.724:16): pid=12044 uid=0 auid=4294967295 ses=4294967295 op="invalid_pcr" cause="open_writers" comm="syz-executor.3" name="/root/syzkaller-testdir3635600960/syzkaller.uqRLMg/85/bus" dev="sda1" ino=14218 res=1
UDF-fs: error (device loop1): udf_process_sequence: Block 100 of volume descriptor sequence is corrupted or we could not read it
UDF-fs: error (device loop1): udf_process_sequence: Block 1988 of volume descriptor sequence is corrupted or we could not read it
audit: type=1804 audit(1669923373.384:17): pid=12055 uid=0 auid=4294967295 ses=4294967295 op="invalid_pcr" cause="open_writers" comm="syz-executor.3" name="/root/syzkaller-testdir3635600960/syzkaller.uqRLMg/86/bus" dev="sda1" ino=14266 res=1
UDF-fs: Scanning with blocksize 512 failed
UDF-fs: error (device loop1): udf_read_tagged: tag version 0x0000 != 0x0002 || 0x0003, block 0
UDF-fs: error (device loop1): udf_read_tagged: tag version 0x0000 != 0x0002 || 0x0003, block 0
UDF-fs: error (device loop1): udf_read_tagged: tag version 0x0000 != 0x0002 || 0x0003, block 0
UDF-fs: warning (device loop1): udf_load_vrs: No anchor found
UDF-fs: Scanning with blocksize 1024 failed
UDF-fs: error (device loop1): udf_read_tagged: tag version 0x0000 != 0x0002 || 0x0003, block 0
UDF-fs: error (device loop1): udf_read_tagged: read failed, block=512, location=512
UDF-fs: error (device loop1): udf_read_tagged: tag version 0x0000 != 0x0002 || 0x0003, block 0
audit: type=1804 audit(1669923373.394:18): pid=12058 uid=0 auid=4294967295 ses=4294967295 op="invalid_pcr" cause="open_writers" comm="syz-executor.0" name="/root/syzkaller-testdir2261287791/syzkaller.bkph0H/99/bus" dev="sda1" ino=14267 res=1
UDF-fs: error (device loop1): udf_read_tagged: tag version 0x0000 != 0x0002 || 0x0003, block 0
UDF-fs: warning (device loop1): udf_load_vrs: No anchor found
UDF-fs: Scanning with blocksize 2048 failed
UDF-fs: error (device loop1): udf_read_tagged: read failed, block=256, location=256
UDF-fs: error (device loop1): udf_read_tagged: tag version 0x0000 != 0x0002 || 0x0003, block 0
UDF-fs: error (device loop1): udf_read_tagged: read failed, block=512, location=512
audit: type=1804 audit(1669923373.725:19): pid=12062 uid=0 auid=4294967295 ses=4294967295 op="invalid_pcr" cause="open_writers" comm="syz-executor.4" name="/root/syzkaller-testdir1635526590/syzkaller.1UIi16/95/file0/bus" dev="loop4" ino=25 res=1
UDF-fs: error (device loop1): udf_read_tagged: tag version 0x0000 != 0x0002 || 0x0003, block 0
UDF-fs: error (device loop1): udf_read_tagged: tag version 0x0000 != 0x0002 || 0x0003, block 0
UDF-fs: warning (device loop1): udf_load_vrs: No anchor found
UDF-fs: Scanning with blocksize 4096 failed
UDF-fs: warning (device loop1): udf_fill_super: No partition found (1)
audit: type=1804 audit(1669923373.725:20): pid=12062 uid=0 auid=4294967295 ses=4294967295 op="invalid_pcr" cause="ToMToU" comm="syz-executor.4" name="/root/syzkaller-testdir1635526590/syzkaller.1UIi16/95/file0/bus" dev="loop4" ino=25 res=1
audit: type=1804 audit(1669923373.725:21): pid=12062 uid=0 auid=4294967295 ses=4294967295 op="invalid_pcr" cause="ToMToU" comm="syz-executor.4" name="/root/syzkaller-testdir1635526590/syzkaller.1UIi16/95/file0/bus" dev="loop4" ino=25 res=1
audit: type=1804 audit(1669923374.305:22): pid=12081 uid=0 auid=4294967295 ses=4294967295 op="invalid_pcr" cause="open_writers" comm="syz-executor.3" name="/root/syzkaller-testdir3635600960/syzkaller.uqRLMg/87/bus" dev="sda1" ino=14272 res=1
UDF-fs: error (device loop1): udf_process_sequence: Block 100 of volume descriptor sequence is corrupted or we could not read it
UDF-fs: error (device loop1): udf_process_sequence: Block 1988 of volume descriptor sequence is corrupted or we could not read it
UDF-fs: Scanning with blocksize 512 failed
UDF-fs: error (device loop1): udf_read_tagged: tag version 0x0000 != 0x0002 || 0x0003, block 0
UDF-fs: error (device loop1): udf_read_tagged: tag version 0x0000 != 0x0002 || 0x0003, block 0
UDF-fs: error (device loop1): udf_read_tagged: tag version 0x0000 != 0x0002 || 0x0003, block 0
UDF-fs: warning (device loop1): udf_load_vrs: No anchor found
UDF-fs: Scanning with blocksize 1024 failed
UDF-fs: error (device loop1): udf_read_tagged: tag version 0x0000 != 0x0002 || 0x0003, block 0
UDF-fs: error (device loop1): udf_read_tagged: read failed, block=512, location=512
UDF-fs: error (device loop1): udf_read_tagged: tag version 0x0000 != 0x0002 || 0x0003, block 0
UDF-fs: error (device loop1): udf_read_tagged: tag version 0x0000 != 0x0002 || 0x0003, block 0
UDF-fs: warning (device loop1): udf_load_vrs: No anchor found
UDF-fs: Scanning with blocksize 2048 failed
UDF-fs: error (device loop1): udf_read_tagged: read failed, block=256, location=256
UDF-fs: error (device loop1): udf_read_tagged: tag version 0x0000 != 0x0002 || 0x0003, block 0
UDF-fs: error (device loop1): udf_read_tagged: read failed, block=512, location=512
UDF-fs: error (device loop1): udf_read_tagged: tag version 0x0000 != 0x0002 || 0x0003, block 0
UDF-fs: error (device loop1): udf_read_tagged: tag version 0x0000 != 0x0002 || 0x0003, block 0
UDF-fs: warning (device loop1): udf_load_vrs: No anchor found
UDF-fs: Scanning with blocksize 4096 failed
UDF-fs: warning (device loop1): udf_fill_super: No partition found (1)
UDF-fs: error (device loop1): udf_process_sequence: Block 100 of volume descriptor sequence is corrupted or we could not read it
UDF-fs: error (device loop1): udf_process_sequence: Block 1988 of volume descriptor sequence is corrupted or we could not read it
UDF-fs: Scanning with blocksize 512 failed
UDF-fs: error (device loop1): udf_read_tagged: tag version 0x0000 != 0x0002 || 0x0003, block 0
UDF-fs: error (device loop1): udf_read_tagged: tag version 0x0000 != 0x0002 || 0x0003, block 0
UDF-fs: error (device loop1): udf_read_tagged: tag version 0x0000 != 0x0002 || 0x0003, block 0
UDF-fs: warning (device loop1): udf_load_vrs: No anchor found
UDF-fs: Scanning with blocksize 1024 failed
UDF-fs: error (device loop1): udf_read_tagged: tag version 0x0000 != 0x0002 || 0x0003, block 0
UDF-fs: error (device loop1): udf_read_tagged: read failed, block=512, location=512
UDF-fs: error (device loop1): udf_read_tagged: tag version 0x0000 != 0x0002 || 0x0003, block 0
UDF-fs: error (device loop1): udf_read_tagged: tag version 0x0000 != 0x0002 || 0x0003, block 0
UDF-fs: warning (device loop1): udf_load_vrs: No anchor found
UDF-fs: Scanning with blocksize 2048 failed
UDF-fs: error (device loop1): udf_read_tagged: read failed, block=256, location=256
UDF-fs: error (device loop1): udf_read_tagged: tag version 0x0000 != 0x0002 || 0x0003, block 0
UDF-fs: error (device loop1): udf_read_tagged: read failed, block=512, location=512
UDF-fs: error (device loop1): udf_read_tagged: tag version 0x0000 != 0x0002 || 0x0003, block 0
UDF-fs: error (device loop1): udf_read_tagged: tag version 0x0000 != 0x0002 || 0x0003, block 0
UDF-fs: warning (device loop1): udf_load_vrs: No anchor found
kauditd_printk_skb: 24 callbacks suppressed
audit: type=1804 audit(1669923377.165:47): pid=12222 uid=0 auid=4294967295 ses=4294967295 op="invalid_pcr" cause="open_writers" comm="syz-executor.5" name="/root/syzkaller-testdir3540420677/syzkaller.5Lg9wK/89/file0/bus" dev="loop5" ino=25 res=1
UDF-fs: Scanning with blocksize 4096 failed
audit: type=1804 audit(1669923377.165:48): pid=12222 uid=0 auid=4294967295 ses=4294967295 op="invalid_pcr" cause="ToMToU" comm="syz-executor.5" name="/root/syzkaller-testdir3540420677/syzkaller.5Lg9wK/89/file0/bus" dev="loop5" ino=25 res=1
audit: type=1804 audit(1669923377.165:49): pid=12222 uid=0 auid=4294967295 ses=4294967295 op="invalid_pcr" cause="ToMToU" comm="syz-executor.5" name="/root/syzkaller-testdir3540420677/syzkaller.5Lg9wK/89/file0/bus" dev="loop5" ino=25 res=1
UDF-fs: warning (device loop1): udf_fill_super: No partition found (1)
audit: type=1804 audit(1669923377.405:50): pid=12236 uid=0 auid=4294967295 ses=4294967295 op="invalid_pcr" cause="open_writers" comm="syz-executor.3" name="/root/syzkaller-testdir3635600960/syzkaller.uqRLMg/90/file0/bus" dev="loop3" ino=25 res=1
audit: type=1804 audit(1669923377.405:51): pid=12236 uid=0 auid=4294967295 ses=4294967295 op="invalid_pcr" cause="ToMToU" comm="syz-executor.3" name="/root/syzkaller-testdir3635600960/syzkaller.uqRLMg/90/file0/bus" dev="loop3" ino=25 res=1
audit: type=1804 audit(1669923377.405:52): pid=12236 uid=0 auid=4294967295 ses=4294967295 op="invalid_pcr" cause="ToMToU" comm="syz-executor.3" name="/root/syzkaller-testdir3635600960/syzkaller.uqRLMg/90/file0/bus" dev="loop3" ino=25 res=1
audit: type=1804 audit(1669923377.525:53): pid=12247 uid=0 auid=4294967295 ses=4294967295 op="invalid_pcr" cause="open_writers" comm="syz-executor.0" name="/root/syzkaller-testdir2261287791/syzkaller.bkph0H/104/file0/bus" dev="loop0" ino=25 res=1
UDF-fs: error (device loop1): udf_process_sequence: Block 100 of volume descriptor sequence is corrupted or we could not read it
UDF-fs: error (device loop1): udf_process_sequence: Block 1988 of volume descriptor sequence is corrupted or we could not read it
UDF-fs: Scanning with blocksize 512 failed
UDF-fs: error (device loop1): udf_read_tagged: tag version 0x0000 != 0x0002 || 0x0003, block 0
UDF-fs: error (device loop1): udf_read_tagged: tag version 0x0000 != 0x0002 || 0x0003, block 0
audit: type=1804 audit(1669923377.525:54): pid=12247 uid=0 auid=4294967295 ses=4294967295 op="invalid_pcr" cause="ToMToU" comm="syz-executor.0" name="/root/syzkaller-testdir2261287791/syzkaller.bkph0H/104/file0/bus" dev="loop0" ino=25 res=1
UDF-fs: error (device loop1): udf_read_tagged: tag version 0x0000 != 0x0002 || 0x0003, block 0
audit: type=1804 audit(1669923377.525:55): pid=12247 uid=0 auid=4294967295 ses=4294967295 op="invalid_pcr" cause="ToMToU" comm="syz-executor.0" name="/root/syzkaller-testdir2261287791/syzkaller.bkph0H/104/file0/bus" dev="loop0" ino=25 res=1
UDF-fs: warning (device loop1): udf_load_vrs: No anchor found
UDF-fs: Scanning with blocksize 1024 failed
UDF-fs: error (device loop1): udf_read_tagged: tag version 0x0000 != 0x0002 || 0x0003, block 0
UDF-fs: error (device loop1): udf_read_tagged: read failed, block=512, location=512
UDF-fs: error (device loop1): udf_read_tagged: tag version 0x0000 != 0x0002 || 0x0003, block 0
audit: type=1804 audit(1669923378.295:56): pid=12302 uid=0 auid=4294967295 ses=4294967295 op="invalid_pcr" cause="open_writers" comm="syz-executor.3" name="/root/syzkaller-testdir3635600960/syzkaller.uqRLMg/91/file0/bus" dev="loop3" ino=25 res=1
UDF-fs: error (device loop1): udf_read_tagged: tag version 0x0000 != 0x0002 || 0x0003, block 0
UDF-fs: warning (device loop1): udf_load_vrs: No anchor found
UDF-fs: Scanning with blocksize 2048 failed
UDF-fs: error (device loop1): udf_read_tagged: read failed, block=256, location=256
UDF-fs: error (device loop1): udf_read_tagged: tag version 0x0000 != 0x0002 || 0x0003, block 0
UDF-fs: error (device loop1): udf_read_tagged: read failed, block=512, location=512
UDF-fs: error (device loop1): udf_read_tagged: tag version 0x0000 != 0x0002 || 0x0003, block 0
UDF-fs: error (device loop1): udf_read_tagged: tag version 0x0000 != 0x0002 || 0x0003, block 0
UDF-fs: warning (device loop1): udf_load_vrs: No anchor found
UDF-fs: Scanning with blocksize 4096 failed
UDF-fs: warning (device loop1): udf_fill_super: No partition found (1)
net_ratelimit: 1 callbacks suppressed
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
---
This report is generated by a bot. It may contain errors.
See https://goo.gl/tpsmEJ for more information about syzbot.
syzbot engineers can be reached at syzk...@googlegroups.com.
syzbot will keep track of this issue. See:
https://goo.gl/tpsmEJ#status for how to communicate with syzbot.
syzbot found the following issue on:
HEAD commit: 179ef7fe8677 Linux 4.14.300
git tree: linux-4.14.y
console output: https://syzkaller.appspot.com/x/log.txt?x=1777e1a1880000
kernel config: https://syzkaller.appspot.com/x/.config?x=aa85f51ec321d5a9
dashboard link: https://syzkaller.appspot.com/bug?extid=29adb337e20196ce447a
compiler: gcc version 10.2.1 20210110 (Debian 10.2.1-6)
Unfortunately, I don't have any reproducer for this issue yet.
Downloadable assets:
disk image: https://storage.googleapis.com/syzbot-assets/d311ef57b59a/disk-179ef7fe.raw.xz
vmlinux: https://storage.googleapis.com/syzbot-assets/25bf5d729f69/vmlinux-179ef7fe.xz
kernel image: https://storage.googleapis.com/syzbot-assets/db9b96571e69/bzImage-179ef7fe.xz
IMPORTANT: if you fix the issue, please add the following tag to the commit:
Reported-by: syzbot+29adb3...@syzkaller.appspotmail.com
audit: type=1804 audit(1669923371.824:13): pid=12019 uid=0 auid=4294967295 ses=4294967295 op="invalid_pcr" cause="open_writers" comm="syz-executor.4" name="/root/syzkaller-testdir1635526590/syzkaller.1UIi16/94/file0/bus" dev="loop4" ino=25 res=1
======================================================
WARNING: possible circular locking dependency detected
4.14.300-syzkaller #0 Not tainted
------------------------------------------------------
syz-executor.4/12019 is trying to acquire lock:
(&sbi->alloc_mutex){+.+.}, at: [<ffffffff81d45b97>] hfsplus_block_free+0xc7/0x560 fs/hfsplus/bitmap.c:182
but task is already holding lock:
(&tree->tree_lock#2/1){+.+.}, at: [<ffffffff81d40011>] hfsplus_find_init+0x161/0x220 fs/hfsplus/bfind.c:33
audit: type=1804 audit(1669923371.834:14): pid=12019 uid=0 auid=4294967295 ses=4294967295 op="invalid_pcr" cause="ToMToU" comm="syz-executor.4" name="/root/syzkaller-testdir1635526590/syzkaller.1UIi16/94/file0/bus" dev="loop4" ino=25 res=1
which lock already depends on the new lock.
the existing dependency chain (in reverse order) is:
-> #2 (&tree->tree_lock#2/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
audit: type=1804 audit(1669923371.834:15): pid=12019 uid=0 auid=4294967295 ses=4294967295 op="invalid_pcr" cause="ToMToU" comm="syz-executor.4" name="/root/syzkaller-testdir1635526590/syzkaller.1UIi16/94/file0/bus" dev="loop4" ino=25 res=1
cont_write_begin+0x4a3/0x740 fs/buffer.c:2497
hfsplus_write_begin+0x87/0x130 fs/hfsplus/inode.c:53
cont_expand_zero fs/buffer.c:2424 [inline]
cont_write_begin+0x296/0x740 fs/buffer.c:2487
hfsplus_write_begin+0x87/0x130 fs/hfsplus/inode.c:53
generic_cont_expand_simple+0xe1/0x130 fs/buffer.c:2388
hfsplus_setattr+0x139/0x310 fs/hfsplus/inode.c:258
notify_change+0x56b/0xd10 fs/attr.c:315
do_truncate+0xff/0x1a0 fs/open.c:63
do_sys_ftruncate.constprop.0+0x3a3/0x480 fs/open.c:205
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
cont_expand_zero fs/buffer.c:2424 [inline]
cont_write_begin+0x296/0x740 fs/buffer.c:2487
hfsplus_write_begin+0x87/0x130 fs/hfsplus/inode.c:53
generic_cont_expand_simple+0xe1/0x130 fs/buffer.c:2388
hfsplus_setattr+0x139/0x310 fs/hfsplus/inode.c:258
notify_change+0x56b/0xd10 fs/attr.c:315
do_truncate+0xff/0x1a0 fs/open.c:63
do_sys_ftruncate.constprop.0+0x3a3/0x480 fs/open.c:205
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_write_failed fs/hfsplus/inode.c:42 [inline]
hfsplus_write_begin+0x103/0x130 fs/hfsplus/inode.c:57
cont_expand_zero fs/buffer.c:2424 [inline]
cont_write_begin+0x296/0x740 fs/buffer.c:2487
hfsplus_write_begin+0x87/0x130 fs/hfsplus/inode.c:53
generic_cont_expand_simple+0xe1/0x130 fs/buffer.c:2388
hfsplus_setattr+0x139/0x310 fs/hfsplus/inode.c:258
notify_change+0x56b/0xd10 fs/attr.c:315
do_truncate+0xff/0x1a0 fs/open.c:63
do_sys_ftruncate.constprop.0+0x3a3/0x480 fs/open.c:205
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:
&sbi->alloc_mutex --> &HFSPLUS_I(inode)->extents_lock --> &tree->tree_lock#2/1
Possible unsafe locking scenario:
CPU0 CPU1
---- ----
lock(&tree->tree_lock#2/1);
lock(&HFSPLUS_I(inode)->extents_lock);
lock(&tree->tree_lock#2/1);
lock(&sbi->alloc_mutex);
*** DEADLOCK ***
4 locks held by syz-executor.4/12019:
#0: (sb_writers#13){.+.+}, at: [<ffffffff81867a9b>] sb_start_write include/linux/fs.h:1551 [inline]
#0: (sb_writers#13){.+.+}, at: [<ffffffff81867a9b>] do_sys_ftruncate.constprop.0+0x1fb/0x480 fs/open.c:200
#1: (&sb->s_type->i_mutex_key#21){+.+.}, at: [<ffffffff81867080>] inode_lock include/linux/fs.h:719 [inline]
#1: (&sb->s_type->i_mutex_key#21){+.+.}, at: [<ffffffff81867080>] do_truncate+0xf0/0x1a0 fs/open.c:61
#2: (&hip->extents_lock){+.+.}, at: [<ffffffff81d2e3ba>] hfsplus_file_truncate+0x1ba/0xe80 fs/hfsplus/extents.c:571
#3: (&tree->tree_lock#2/1){+.+.}, at: [<ffffffff81d40011>] hfsplus_find_init+0x161/0x220 fs/hfsplus/bfind.c:33
stack backtrace:
CPU: 1 PID: 12019 Comm: syz-executor.4 Not tainted 4.14.300-syzkaller #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 10/26/2022
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_write_failed fs/hfsplus/inode.c:42 [inline]
hfsplus_write_begin+0x103/0x130 fs/hfsplus/inode.c:57
cont_expand_zero fs/buffer.c:2424 [inline]
cont_write_begin+0x296/0x740 fs/buffer.c:2487
hfsplus_write_begin+0x87/0x130 fs/hfsplus/inode.c:53
generic_cont_expand_simple+0xe1/0x130 fs/buffer.c:2388
hfsplus_setattr+0x139/0x310 fs/hfsplus/inode.c:258
notify_change+0x56b/0xd10 fs/attr.c:315
do_truncate+0xff/0x1a0 fs/open.c:63
do_sys_ftruncate.constprop.0+0x3a3/0x480 fs/open.c:205
do_syscall_64+0x1d5/0x640 arch/x86/entry/common.c:292
entry_SYSCALL_64_after_hwframe+0x5e/0xd3
audit: type=1804 audit(1669923372.724:16): pid=12044 uid=0 auid=4294967295 ses=4294967295 op="invalid_pcr" cause="open_writers" comm="syz-executor.3" name="/root/syzkaller-testdir3635600960/syzkaller.uqRLMg/85/bus" dev="sda1" ino=14218 res=1
UDF-fs: error (device loop1): udf_process_sequence: Block 100 of volume descriptor sequence is corrupted or we could not read it
UDF-fs: error (device loop1): udf_process_sequence: Block 1988 of volume descriptor sequence is corrupted or we could not read it
audit: type=1804 audit(1669923373.384:17): pid=12055 uid=0 auid=4294967295 ses=4294967295 op="invalid_pcr" cause="open_writers" comm="syz-executor.3" name="/root/syzkaller-testdir3635600960/syzkaller.uqRLMg/86/bus" dev="sda1" ino=14266 res=1
UDF-fs: Scanning with blocksize 512 failed
UDF-fs: error (device loop1): udf_read_tagged: tag version 0x0000 != 0x0002 || 0x0003, block 0
UDF-fs: error (device loop1): udf_read_tagged: tag version 0x0000 != 0x0002 || 0x0003, block 0
UDF-fs: error (device loop1): udf_read_tagged: tag version 0x0000 != 0x0002 || 0x0003, block 0
UDF-fs: warning (device loop1): udf_load_vrs: No anchor found
UDF-fs: Scanning with blocksize 1024 failed
UDF-fs: error (device loop1): udf_read_tagged: tag version 0x0000 != 0x0002 || 0x0003, block 0
UDF-fs: error (device loop1): udf_read_tagged: read failed, block=512, location=512
UDF-fs: error (device loop1): udf_read_tagged: tag version 0x0000 != 0x0002 || 0x0003, block 0
audit: type=1804 audit(1669923373.394:18): pid=12058 uid=0 auid=4294967295 ses=4294967295 op="invalid_pcr" cause="open_writers" comm="syz-executor.0" name="/root/syzkaller-testdir2261287791/syzkaller.bkph0H/99/bus" dev="sda1" ino=14267 res=1
UDF-fs: error (device loop1): udf_read_tagged: tag version 0x0000 != 0x0002 || 0x0003, block 0
UDF-fs: warning (device loop1): udf_load_vrs: No anchor found
UDF-fs: Scanning with blocksize 2048 failed
UDF-fs: error (device loop1): udf_read_tagged: read failed, block=256, location=256
UDF-fs: error (device loop1): udf_read_tagged: tag version 0x0000 != 0x0002 || 0x0003, block 0
UDF-fs: error (device loop1): udf_read_tagged: read failed, block=512, location=512
audit: type=1804 audit(1669923373.725:19): pid=12062 uid=0 auid=4294967295 ses=4294967295 op="invalid_pcr" cause="open_writers" comm="syz-executor.4" name="/root/syzkaller-testdir1635526590/syzkaller.1UIi16/95/file0/bus" dev="loop4" ino=25 res=1
UDF-fs: error (device loop1): udf_read_tagged: tag version 0x0000 != 0x0002 || 0x0003, block 0
UDF-fs: error (device loop1): udf_read_tagged: tag version 0x0000 != 0x0002 || 0x0003, block 0
UDF-fs: warning (device loop1): udf_load_vrs: No anchor found
UDF-fs: Scanning with blocksize 4096 failed
UDF-fs: warning (device loop1): udf_fill_super: No partition found (1)
audit: type=1804 audit(1669923373.725:20): pid=12062 uid=0 auid=4294967295 ses=4294967295 op="invalid_pcr" cause="ToMToU" comm="syz-executor.4" name="/root/syzkaller-testdir1635526590/syzkaller.1UIi16/95/file0/bus" dev="loop4" ino=25 res=1
audit: type=1804 audit(1669923373.725:21): pid=12062 uid=0 auid=4294967295 ses=4294967295 op="invalid_pcr" cause="ToMToU" comm="syz-executor.4" name="/root/syzkaller-testdir1635526590/syzkaller.1UIi16/95/file0/bus" dev="loop4" ino=25 res=1
audit: type=1804 audit(1669923374.305:22): pid=12081 uid=0 auid=4294967295 ses=4294967295 op="invalid_pcr" cause="open_writers" comm="syz-executor.3" name="/root/syzkaller-testdir3635600960/syzkaller.uqRLMg/87/bus" dev="sda1" ino=14272 res=1
UDF-fs: error (device loop1): udf_process_sequence: Block 100 of volume descriptor sequence is corrupted or we could not read it
UDF-fs: error (device loop1): udf_process_sequence: Block 1988 of volume descriptor sequence is corrupted or we could not read it
UDF-fs: Scanning with blocksize 512 failed
UDF-fs: error (device loop1): udf_read_tagged: tag version 0x0000 != 0x0002 || 0x0003, block 0
UDF-fs: error (device loop1): udf_read_tagged: tag version 0x0000 != 0x0002 || 0x0003, block 0
UDF-fs: error (device loop1): udf_read_tagged: tag version 0x0000 != 0x0002 || 0x0003, block 0
UDF-fs: warning (device loop1): udf_load_vrs: No anchor found
UDF-fs: Scanning with blocksize 1024 failed
UDF-fs: error (device loop1): udf_read_tagged: tag version 0x0000 != 0x0002 || 0x0003, block 0
UDF-fs: error (device loop1): udf_read_tagged: read failed, block=512, location=512
UDF-fs: error (device loop1): udf_read_tagged: tag version 0x0000 != 0x0002 || 0x0003, block 0
UDF-fs: error (device loop1): udf_read_tagged: tag version 0x0000 != 0x0002 || 0x0003, block 0
UDF-fs: warning (device loop1): udf_load_vrs: No anchor found
UDF-fs: Scanning with blocksize 2048 failed
UDF-fs: error (device loop1): udf_read_tagged: read failed, block=256, location=256
UDF-fs: error (device loop1): udf_read_tagged: tag version 0x0000 != 0x0002 || 0x0003, block 0
UDF-fs: error (device loop1): udf_read_tagged: read failed, block=512, location=512
UDF-fs: error (device loop1): udf_read_tagged: tag version 0x0000 != 0x0002 || 0x0003, block 0
UDF-fs: error (device loop1): udf_read_tagged: tag version 0x0000 != 0x0002 || 0x0003, block 0
UDF-fs: warning (device loop1): udf_load_vrs: No anchor found
UDF-fs: Scanning with blocksize 4096 failed
UDF-fs: warning (device loop1): udf_fill_super: No partition found (1)
UDF-fs: error (device loop1): udf_process_sequence: Block 100 of volume descriptor sequence is corrupted or we could not read it
UDF-fs: error (device loop1): udf_process_sequence: Block 1988 of volume descriptor sequence is corrupted or we could not read it
UDF-fs: Scanning with blocksize 512 failed
UDF-fs: error (device loop1): udf_read_tagged: tag version 0x0000 != 0x0002 || 0x0003, block 0
UDF-fs: error (device loop1): udf_read_tagged: tag version 0x0000 != 0x0002 || 0x0003, block 0
UDF-fs: error (device loop1): udf_read_tagged: tag version 0x0000 != 0x0002 || 0x0003, block 0
UDF-fs: warning (device loop1): udf_load_vrs: No anchor found
UDF-fs: Scanning with blocksize 1024 failed
UDF-fs: error (device loop1): udf_read_tagged: tag version 0x0000 != 0x0002 || 0x0003, block 0
UDF-fs: error (device loop1): udf_read_tagged: read failed, block=512, location=512
UDF-fs: error (device loop1): udf_read_tagged: tag version 0x0000 != 0x0002 || 0x0003, block 0
UDF-fs: error (device loop1): udf_read_tagged: tag version 0x0000 != 0x0002 || 0x0003, block 0
UDF-fs: warning (device loop1): udf_load_vrs: No anchor found
UDF-fs: Scanning with blocksize 2048 failed
UDF-fs: error (device loop1): udf_read_tagged: read failed, block=256, location=256
UDF-fs: error (device loop1): udf_read_tagged: tag version 0x0000 != 0x0002 || 0x0003, block 0
UDF-fs: error (device loop1): udf_read_tagged: read failed, block=512, location=512
UDF-fs: error (device loop1): udf_read_tagged: tag version 0x0000 != 0x0002 || 0x0003, block 0
UDF-fs: error (device loop1): udf_read_tagged: tag version 0x0000 != 0x0002 || 0x0003, block 0
UDF-fs: warning (device loop1): udf_load_vrs: No anchor found
kauditd_printk_skb: 24 callbacks suppressed
audit: type=1804 audit(1669923377.165:47): pid=12222 uid=0 auid=4294967295 ses=4294967295 op="invalid_pcr" cause="open_writers" comm="syz-executor.5" name="/root/syzkaller-testdir3540420677/syzkaller.5Lg9wK/89/file0/bus" dev="loop5" ino=25 res=1
UDF-fs: Scanning with blocksize 4096 failed
audit: type=1804 audit(1669923377.165:48): pid=12222 uid=0 auid=4294967295 ses=4294967295 op="invalid_pcr" cause="ToMToU" comm="syz-executor.5" name="/root/syzkaller-testdir3540420677/syzkaller.5Lg9wK/89/file0/bus" dev="loop5" ino=25 res=1
audit: type=1804 audit(1669923377.165:49): pid=12222 uid=0 auid=4294967295 ses=4294967295 op="invalid_pcr" cause="ToMToU" comm="syz-executor.5" name="/root/syzkaller-testdir3540420677/syzkaller.5Lg9wK/89/file0/bus" dev="loop5" ino=25 res=1
UDF-fs: warning (device loop1): udf_fill_super: No partition found (1)
audit: type=1804 audit(1669923377.405:50): pid=12236 uid=0 auid=4294967295 ses=4294967295 op="invalid_pcr" cause="open_writers" comm="syz-executor.3" name="/root/syzkaller-testdir3635600960/syzkaller.uqRLMg/90/file0/bus" dev="loop3" ino=25 res=1
audit: type=1804 audit(1669923377.405:51): pid=12236 uid=0 auid=4294967295 ses=4294967295 op="invalid_pcr" cause="ToMToU" comm="syz-executor.3" name="/root/syzkaller-testdir3635600960/syzkaller.uqRLMg/90/file0/bus" dev="loop3" ino=25 res=1
audit: type=1804 audit(1669923377.405:52): pid=12236 uid=0 auid=4294967295 ses=4294967295 op="invalid_pcr" cause="ToMToU" comm="syz-executor.3" name="/root/syzkaller-testdir3635600960/syzkaller.uqRLMg/90/file0/bus" dev="loop3" ino=25 res=1
audit: type=1804 audit(1669923377.525:53): pid=12247 uid=0 auid=4294967295 ses=4294967295 op="invalid_pcr" cause="open_writers" comm="syz-executor.0" name="/root/syzkaller-testdir2261287791/syzkaller.bkph0H/104/file0/bus" dev="loop0" ino=25 res=1
UDF-fs: error (device loop1): udf_process_sequence: Block 100 of volume descriptor sequence is corrupted or we could not read it
UDF-fs: error (device loop1): udf_process_sequence: Block 1988 of volume descriptor sequence is corrupted or we could not read it
UDF-fs: Scanning with blocksize 512 failed
UDF-fs: error (device loop1): udf_read_tagged: tag version 0x0000 != 0x0002 || 0x0003, block 0
UDF-fs: error (device loop1): udf_read_tagged: tag version 0x0000 != 0x0002 || 0x0003, block 0
audit: type=1804 audit(1669923377.525:54): pid=12247 uid=0 auid=4294967295 ses=4294967295 op="invalid_pcr" cause="ToMToU" comm="syz-executor.0" name="/root/syzkaller-testdir2261287791/syzkaller.bkph0H/104/file0/bus" dev="loop0" ino=25 res=1
UDF-fs: error (device loop1): udf_read_tagged: tag version 0x0000 != 0x0002 || 0x0003, block 0
audit: type=1804 audit(1669923377.525:55): pid=12247 uid=0 auid=4294967295 ses=4294967295 op="invalid_pcr" cause="ToMToU" comm="syz-executor.0" name="/root/syzkaller-testdir2261287791/syzkaller.bkph0H/104/file0/bus" dev="loop0" ino=25 res=1
UDF-fs: warning (device loop1): udf_load_vrs: No anchor found
UDF-fs: Scanning with blocksize 1024 failed
UDF-fs: error (device loop1): udf_read_tagged: tag version 0x0000 != 0x0002 || 0x0003, block 0
UDF-fs: error (device loop1): udf_read_tagged: read failed, block=512, location=512
UDF-fs: error (device loop1): udf_read_tagged: tag version 0x0000 != 0x0002 || 0x0003, block 0
audit: type=1804 audit(1669923378.295:56): pid=12302 uid=0 auid=4294967295 ses=4294967295 op="invalid_pcr" cause="open_writers" comm="syz-executor.3" name="/root/syzkaller-testdir3635600960/syzkaller.uqRLMg/91/file0/bus" dev="loop3" ino=25 res=1
UDF-fs: error (device loop1): udf_read_tagged: tag version 0x0000 != 0x0002 || 0x0003, block 0
UDF-fs: warning (device loop1): udf_load_vrs: No anchor found
UDF-fs: Scanning with blocksize 2048 failed
UDF-fs: error (device loop1): udf_read_tagged: read failed, block=256, location=256
UDF-fs: error (device loop1): udf_read_tagged: tag version 0x0000 != 0x0002 || 0x0003, block 0
UDF-fs: error (device loop1): udf_read_tagged: read failed, block=512, location=512
UDF-fs: error (device loop1): udf_read_tagged: tag version 0x0000 != 0x0002 || 0x0003, block 0
UDF-fs: error (device loop1): udf_read_tagged: tag version 0x0000 != 0x0002 || 0x0003, block 0
UDF-fs: warning (device loop1): udf_load_vrs: No anchor found
UDF-fs: Scanning with blocksize 4096 failed
UDF-fs: warning (device loop1): udf_fill_super: No partition found (1)
net_ratelimit: 1 callbacks suppressed
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
---
This report is generated by a bot. It may contain errors.
See https://goo.gl/tpsmEJ for more information about syzbot.
syzbot engineers can be reached at syzk...@googlegroups.com.
syzbot will keep track of this issue. See:
https://goo.gl/tpsmEJ#status for how to communicate with syzbot.
syzbot
Dec 4, 2022, 2:32:38 PM12/4/22
to syzkaller...@googlegroups.com
Hello,
syzbot found the following issue on:
HEAD commit: 3f8a27f9e27b Linux 4.19.211
syzbot found the following issue on:
git tree: linux-4.19.y
console output: https://syzkaller.appspot.com/x/log.txt?x=1513d497880000
kernel config: https://syzkaller.appspot.com/x/.config?x=9b9277b418617afe
dashboard link: https://syzkaller.appspot.com/bug?extid=9a3af69699b90503a205
compiler: gcc version 10.2.1 20210110 (Debian 10.2.1-6)
Unfortunately, I don't have any reproducer for this issue yet.
Downloadable assets:
disk image: https://storage.googleapis.com/syzbot-assets/98c0bdb4abb3/disk-3f8a27f9.raw.xz
Unfortunately, I don't have any reproducer for this issue yet.
Downloadable assets:
vmlinux: https://storage.googleapis.com/syzbot-assets/ea228ff02669/vmlinux-3f8a27f9.xz
IMPORTANT: if you fix the issue, please add the following tag to the commit:
hfsplus: invalid extended attribute record
IPVS: ftp: loaded support on port[0] = 21
======================================================
WARNING: possible circular locking dependency detected
4.19.211-syzkaller #0 Not tainted
WARNING: possible circular locking dependency detected
------------------------------------------------------
syz-executor.3/15739 is trying to acquire lock:
00000000dab86b7d (&sbi->alloc_mutex){+.+.}, at: hfsplus_block_free+0xdb/0x5d0 fs/hfsplus/bitmap.c:182
but task is already holding lock:
which lock already depends on the new lock.
the existing dependency chain (in reverse order) is:
hfsplus_get_block+0x292/0x960 fs/hfsplus/extents.c:260
block_read_full_page+0x288/0xd10 fs/buffer.c:2259
do_read_cache_page+0x533/0x1170 mm/filemap.c:2828
read_mapping_page include/linux/pagemap.h:402 [inline]
hfsplus_block_allocate+0x197/0xa60 fs/hfsplus/bitmap.c:37
hfsplus_file_extend+0x436/0xf40 fs/hfsplus/extents.c:468
hfsplus_get_block+0x196/0x960 fs/hfsplus/extents.c:245
__block_write_begin_int+0x46c/0x17b0 fs/buffer.c:1978
__block_write_begin fs/buffer.c:2028 [inline]
block_write_begin+0x58/0x2e0 fs/buffer.c:2087
cont_write_begin+0x55a/0x820 fs/buffer.c:2440
hfsplus_write_begin+0x87/0x150 fs/hfsplus/inode.c:52
cont_expand_zero fs/buffer.c:2367 [inline]
cont_write_begin+0x2ee/0x820 fs/buffer.c:2430
hfsplus_write_begin+0x87/0x150 fs/hfsplus/inode.c:52
generic_cont_expand_simple+0x106/0x170 fs/buffer.c:2331
hfsplus_setattr+0x18b/0x310 fs/hfsplus/inode.c:257
notify_change+0x70b/0xfc0 fs/attr.c:334
do_truncate+0x134/0x1f0 fs/open.c:63
do_sys_ftruncate+0x492/0x560 fs/open.c:194
do_syscall_64+0xf9/0x620 arch/x86/entry/common.c:293
entry_SYSCALL_64_after_hwframe+0x49/0xbe
-> #0 (&sbi->alloc_mutex){+.+.}:
__mutex_lock+0xd7/0x1190 kernel/locking/mutex.c:1078
hfsplus_block_free+0xdb/0x5d0 fs/hfsplus/bitmap.c:182
hfsplus_free_extents+0x228/0x520 fs/hfsplus/extents.c:363
hfsplus_file_truncate+0xd96/0x1040 fs/hfsplus/extents.c:591
hfsplus_delete_inode+0x18d/0x220 fs/hfsplus/inode.c:419
hfsplus_unlink+0x595/0x820 fs/hfsplus/dir.c:405
vfs_unlink+0x27d/0x4e0 fs/namei.c:4002
do_unlinkat+0x3b8/0x660 fs/namei.c:4065
do_syscall_64+0xf9/0x620 arch/x86/entry/common.c:293
entry_SYSCALL_64_after_hwframe+0x49/0xbe
other info that might help us debug this:
Possible unsafe locking scenario:
CPU0 CPU1
---- ----
lock(&HFSPLUS_I(inode)->extents_lock);
CPU0 CPU1
---- ----
lock(&sbi->alloc_mutex);
lock(&HFSPLUS_I(inode)->extents_lock);
lock(&sbi->alloc_mutex);
*** DEADLOCK ***
5 locks held by syz-executor.3/15739:
*** DEADLOCK ***
#0: 00000000c58ab199 (sb_writers#25){.+.+}, at: sb_start_write include/linux/fs.h:1579 [inline]
#0: 00000000c58ab199 (sb_writers#25){.+.+}, at: mnt_want_write+0x3a/0xb0 fs/namespace.c:360
#1: 00000000460a62fc (&type->i_mutex_dir_key#14/1){+.+.}, at: inode_lock_nested include/linux/fs.h:783 [inline]
#1: 00000000460a62fc (&type->i_mutex_dir_key#14/1){+.+.}, at: do_unlinkat+0x27d/0x660 fs/namei.c:4051
#2: 000000006350e492 (&sb->s_type->i_mutex_key#29){+.+.}, at: inode_lock include/linux/fs.h:748 [inline]
#2: 000000006350e492 (&sb->s_type->i_mutex_key#29){+.+.}, at: vfs_unlink+0xca/0x4e0 fs/namei.c:3993
#3: 0000000015d61578 (&sbi->vh_mutex){+.+.}, at: hfsplus_unlink+0x140/0x820 fs/hfsplus/dir.c:370
#4: 00000000a22c77b2 (&HFSPLUS_I(inode)->extents_lock){+.+.}, at: hfsplus_file_truncate+0x1e2/0x1040 fs/hfsplus/extents.c:576
stack backtrace:
CPU: 0 PID: 15739 Comm: syz-executor.3 Not tainted 4.19.211-syzkaller #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 10/26/2022
Call Trace:
__dump_stack lib/dump_stack.c:77 [inline]
Call Trace:
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
hfsplus_block_free+0xdb/0x5d0 fs/hfsplus/bitmap.c:182
hfsplus_free_extents+0x228/0x520 fs/hfsplus/extents.c:363
hfsplus_file_truncate+0xd96/0x1040 fs/hfsplus/extents.c:591
hfsplus_delete_inode+0x18d/0x220 fs/hfsplus/inode.c:419
hfsplus_unlink+0x595/0x820 fs/hfsplus/dir.c:405
vfs_unlink+0x27d/0x4e0 fs/namei.c:4002
do_unlinkat+0x3b8/0x660 fs/namei.c:4065
do_syscall_64+0xf9/0x620 arch/x86/entry/common.c:293
entry_SYSCALL_64_after_hwframe+0x49/0xbe
RIP: 0033:0x7fe1d5cf90d9
Code: 28 00 00 00 75 05 48 83 c4 28 c3 e8 f1 19 00 00 90 48 89 f8 48 89 f7 48 89 d6 48 89 ca 4d 89 c2 4d 89 c8 4c 8b 4c 24 08 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:00007fe1d426b168 EFLAGS: 00000246 ORIG_RAX: 0000000000000057
RAX: ffffffffffffffda RBX: 00007fe1d5e18f80 RCX: 00007fe1d5cf90d9
RDX: 0000000000000000 RSI: 0000000000000000 RDI: 0000000020000000
RBP: 00007fe1d5d54ae9 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000246 R12: 0000000000000000
R13: 00007ffe6c464b8f R14: 00007fe1d426b300 R15: 0000000000022000
IPv6: ADDRCONF(NETDEV_CHANGE): vcan0: link becomes ready
hfsplus: invalid extended attribute record
IPv6: ADDRCONF(NETDEV_CHANGE): vxcan0: link becomes ready
IPv6: ADDRCONF(NETDEV_CHANGE): vxcan1: link becomes ready
kauditd_printk_skb: 25 callbacks suppressed
audit: type=1804 audit(1670182302.085:316): pid=15833 uid=0 auid=4294967295 ses=4294967295 subj==unconfined op=invalid_pcr cause=open_writers comm="syz-executor.3" name="/root/syzkaller-testdir2910190345/syzkaller.QaedVD/115/memory.events" dev="sda1" ino=14109 res=1
audit: type=1800 audit(1670182302.085:317): pid=15833 uid=0 auid=4294967295 ses=4294967295 subj==unconfined op=collect_data cause=failed(directio) comm="syz-executor.3" name="memory.events" dev="sda1" ino=14109 res=0
audit: type=1804 audit(1670182302.375:318): pid=15857 uid=0 auid=4294967295 ses=4294967295 subj==unconfined op=invalid_pcr cause=open_writers comm="syz-executor.3" name="/root/syzkaller-testdir2910190345/syzkaller.QaedVD/116/memory.events" dev="sda1" ino=14556 res=1
audit: type=1800 audit(1670182302.375:319): pid=15857 uid=0 auid=4294967295 ses=4294967295 subj==unconfined op=collect_data cause=failed(directio) comm="syz-executor.3" name="memory.events" dev="sda1" ino=14556 res=0
F2FS-fs (loop2): Found nat_bits in checkpoint
F2FS-fs (loop2): Mounted with checkpoint version = 48b305e5
F2FS-fs (loop5): Found nat_bits in checkpoint
F2FS-fs (loop5): Mounted with checkpoint version = 48b305e5
audit: type=1804 audit(1670182303.465:320): pid=15901 uid=0 auid=4294967295 ses=4294967295 subj==unconfined op=invalid_pcr cause=open_writers comm="syz-executor.3" name="/root/syzkaller-testdir2910190345/syzkaller.QaedVD/117/memory.events" dev="sda1" ino=14229 res=1
audit: type=1800 audit(1670182303.465:321): pid=15901 uid=0 auid=4294967295 ses=4294967295 subj==unconfined op=collect_data cause=failed(directio) comm="syz-executor.3" name="memory.events" dev="sda1" ino=14229 res=0
print_req_error: I/O error, dev loop7, sector 0
Buffer I/O error on dev loop7, logical block 0, lost async page write
print_req_error: I/O error, dev loop7, sector 4
Buffer I/O error on dev loop7, logical block 1, lost async page write
print_req_error: I/O error, dev loop7, sector 8
Buffer I/O error on dev loop7, logical block 2, lost async page write
print_req_error: I/O error, dev loop7, sector 12
Buffer I/O error on dev loop7, logical block 3, lost async page write
print_req_error: I/O error, dev loop7, sector 16
Buffer I/O error on dev loop7, logical block 4, lost async page write
print_req_error: I/O error, dev loop7, sector 20
Buffer I/O error on dev loop7, logical block 5, lost async page write
print_req_error: I/O error, dev loop7, sector 24
Buffer I/O error on dev loop7, logical block 6, lost async page write
print_req_error: I/O error, dev loop7, sector 28
Buffer I/O error on dev loop7, logical block 7, lost async page write
print_req_error: I/O error, dev loop7, sector 32
Buffer I/O error on dev loop7, logical block 8, lost async page write
print_req_error: I/O error, dev loop7, sector 36
Buffer I/O error on dev loop7, logical block 10, lost async page write
F2FS-fs (loop3): Found nat_bits in checkpoint
F2FS-fs (loop3): Mounted with checkpoint version = 48b305e5
F2FS-fs (loop2): Found nat_bits in checkpoint
F2FS-fs (loop2): Mounted with checkpoint version = 48b305e5
audit: type=1804 audit(1670182305.795:322): pid=16007 uid=0 auid=4294967295 ses=4294967295 subj==unconfined op=invalid_pcr cause=open_writers comm="syz-executor.1" name="/root/syzkaller-testdir2398540719/syzkaller.7omLNv/121/memory.events" dev="sda1" ino=14578 res=1
audit: type=1800 audit(1670182305.795:323): pid=16007 uid=0 auid=4294967295 ses=4294967295 subj==unconfined op=collect_data cause=failed(directio) comm="syz-executor.1" name="memory.events" dev="sda1" ino=14578 res=0
F2FS-fs (loop3): Found nat_bits in checkpoint
F2FS-fs (loop2): Found nat_bits in checkpoint
f2fs_msg: 2 callbacks suppressed
F2FS-fs (loop2): Found nat_bits in checkpoint
F2FS-fs (loop2): Mounted with checkpoint version = 48b305e5
F2FS-fs (loop3): Found nat_bits in checkpoint
F2FS-fs (loop3): Mounted with checkpoint version = 48b305e5
print_req_error: 1737 callbacks suppressed
print_req_error: I/O error, dev loop7, sector 0
buffer_io_error: 1736 callbacks suppressed
Buffer I/O error on dev loop7, logical block 0, lost async page write
print_req_error: I/O error, dev loop7, sector 4
Buffer I/O error on dev loop7, logical block 1, lost async page write
print_req_error: I/O error, dev loop7, sector 8
Buffer I/O error on dev loop7, logical block 2, lost async page write
print_req_error: I/O error, dev loop7, sector 12
Buffer I/O error on dev loop7, logical block 3, lost async page write
print_req_error: I/O error, dev loop7, sector 16
Buffer I/O error on dev loop7, logical block 4, lost async page write
print_req_error: I/O error, dev loop7, sector 20
Buffer I/O error on dev loop7, logical block 5, lost async page write
print_req_error: I/O error, dev loop7, sector 24
Buffer I/O error on dev loop7, logical block 6, lost async page write
print_req_error: I/O error, dev loop7, sector 28
Buffer I/O error on dev loop7, logical block 7, lost async page write
print_req_error: I/O error, dev loop7, sector 32
Buffer I/O error on dev loop7, logical block 8, lost async page write
print_req_error: I/O error, dev loop7, sector 36
Buffer I/O error on dev loop7, logical block 9, lost async page write
x_tables: ip6_tables: CLASSIFY target: used from hooks PREROUTING, but only usable from FORWARD/OUTPUT/POSTROUTING
F2FS-fs (loop2): Found nat_bits in checkpoint
F2FS-fs (loop2): Mounted with checkpoint version = 48b305e5
Reply all
Reply to author
Forward
0 new messages