Hello,
syzbot found the following issue on:
HEAD commit: e911713e40ca Linux 4.14.299
git tree: linux-4.14.y
console output:
https://syzkaller.appspot.com/x/log.txt?x=16e0158e880000
kernel config:
https://syzkaller.appspot.com/x/.config?x=1d7ed9728cc57838
dashboard link:
https://syzkaller.appspot.com/bug?extid=50dde734aa62ec2523d3
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/c8588259d654/disk-e911713e.raw.xz
vmlinux:
https://storage.googleapis.com/syzbot-assets/700d08072e5e/vmlinux-e911713e.xz
kernel image:
https://storage.googleapis.com/syzbot-assets/844ad5da2ed5/bzImage-e911713e.xz
IMPORTANT: if you fix the issue, please add the following tag to the commit:
Reported-by:
syzbot+50dde7...@syzkaller.appspotmail.com
ntfs: volume version 3.1.
======================================================
WARNING: possible circular locking dependency detected
4.14.299-syzkaller #0 Not tainted
------------------------------------------------------
syz-executor.1/10592 is trying to acquire lock:
(&ni->mrec_lock){+.+.}, at: [<ffffffff8213d64b>] map_mft_record+0x2b/0xbe0 fs/ntfs/mft.c:166
but task is already holding lock:
(&rl->lock){++++}, at: [<ffffffff8211009d>] ntfs_attr_extend_allocation+0x1dd/0x2f80 fs/ntfs/attrib.c:1995
which lock already depends on the new lock.
the existing dependency chain (in reverse order) is:
-> #1 (&rl->lock){++++}:
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+0xef0/0x1240 fs/ntfs/mft.c:811
write_mft_record fs/ntfs/mft.h:109 [inline]
__ntfs_write_inode+0x58d/0xcc0 fs/ntfs/inode.c:3077
ntfs_commit_inode fs/ntfs/inode.h:315 [inline]
ntfs_put_super+0xf3c/0x14d0 fs/ntfs/super.c:2274
generic_shutdown_super+0x144/0x370 fs/super.c:446
kill_block_super+0x95/0xe0 fs/super.c:1161
deactivate_locked_super+0x6c/0xd0 fs/super.c:319
deactivate_super+0x7f/0xa0 fs/super.c:350
cleanup_mnt+0x186/0x2c0 fs/namespace.c:1183
task_work_run+0x11f/0x190 kernel/task_work.c:113
tracehook_notify_resume include/linux/tracehook.h:191 [inline]
exit_to_usermode_loop+0x1ad/0x200 arch/x86/entry/common.c:164
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
-> #0 (&ni->mrec_lock){+.+.}:
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
map_mft_record+0x2b/0xbe0 fs/ntfs/mft.c:166
ntfs_attr_extend_allocation+0x1e5/0x2f80 fs/ntfs/attrib.c:1996
ntfs_prepare_file_for_write fs/ntfs/file.c:412 [inline]
ntfs_file_write_iter+0x61b/0x1f70 fs/ntfs/file.c:1949
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
other info that might help us debug this:
Possible unsafe locking scenario:
CPU0 CPU1
---- ----
lock(&rl->lock);
lock(&ni->mrec_lock);
lock(&rl->lock);
lock(&ni->mrec_lock);
*** DEADLOCK ***
4 locks held by syz-executor.1/10592:
#0: (&f->f_pos_lock){+.+.}, at: [<ffffffff818d8b5b>] __fdget_pos+0x1fb/0x2b0 fs/file.c:819
#1: (sb_writers#16){.+.+}, at: [<ffffffff818726a8>] file_start_write include/linux/fs.h:2714 [inline]
#1: (sb_writers#16){.+.+}, at: [<ffffffff818726a8>] vfs_write+0x3d8/0x4d0 fs/read_write.c:543
#2: (&sb->s_type->i_mutex_key#23){+.+.}, at: [<ffffffff82126299>] inode_lock include/linux/fs.h:719 [inline]
#2: (&sb->s_type->i_mutex_key#23){+.+.}, at: [<ffffffff82126299>] ntfs_file_write_iter+0x79/0x1f70 fs/ntfs/file.c:1946
#3: (&rl->lock){++++}, at: [<ffffffff8211009d>] ntfs_attr_extend_allocation+0x1dd/0x2f80 fs/ntfs/attrib.c:1995
stack backtrace:
CPU: 1 PID: 10592 Comm: syz-executor.1 Not tainted 4.14.299-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
map_mft_record+0x2b/0xbe0 fs/ntfs/mft.c:166
ntfs_attr_extend_allocation+0x1e5/0x2f80 fs/ntfs/attrib.c:1996
ntfs_prepare_file_for_write fs/ntfs/file.c:412 [inline]
ntfs_file_write_iter+0x61b/0x1f70 fs/ntfs/file.c:1949
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
EXT4-fs (loop5): mounted filesystem without journal. Opts: errors=remount-ro,nombcache,usrquota,
netlink: 12 bytes leftover after parsing attributes in process `syz-executor.5'.
ntfs: volume version 3.1.
netlink: 12 bytes leftover after parsing attributes in process `syz-executor.5'.
netlink: 12 bytes leftover after parsing attributes in process `syz-executor.5'.
ntfs: volume version 3.1.
BTRFS: device fsid f90cac8b-044b-4fa8-8bee-4b8d3da88dc2 devid 1 transid 7 /dev/loop3
BTRFS info (device loop3): disk space caching is enabled
netlink: 12 bytes leftover after parsing attributes in process `syz-executor.5'.
ntfs: volume version 3.1.
BTRFS info (device loop3): has skinny extents
BTRFS info (device loop3): disk space caching is enabled
BTRFS info (device loop3): has skinny extents
BTRFS info (device loop3): disk space caching is enabled
BTRFS info (device loop3): has skinny extents
BTRFS info (device loop0): disk space caching is enabled
BTRFS info (device loop0): has skinny extents
NILFS (loop0): corrupt root inode
NILFS (loop0): segctord starting. Construction interval = 5 seconds, CP frequency < 30 seconds
audit: type=1804 audit(1668476464.391:6): pid=11144 uid=0 auid=4294967295 ses=4294967295 op="invalid_pcr" cause="open_writers" comm="syz-executor.1" name="/root/syzkaller-testdir2995794484/syzkaller.AelnhG/48/file1/bus" dev="loop1" ino=4 res=1
audit: type=1804 audit(1668476464.481:7): pid=11149 uid=0 auid=4294967295 ses=4294967295 op="invalid_pcr" cause="ToMToU" comm="syz-executor.1" name="/root/syzkaller-testdir2995794484/syzkaller.AelnhG/48/file1/bus" dev="loop1" ino=4 res=1
IPVS: ftp: loaded support on port[0] = 21
netlink: 12 bytes leftover after parsing attributes in process `syz-executor.3'.
NILFS (loop0): corrupt root inode
NILFS (loop0): segctord starting. Construction interval = 5 seconds, CP frequency < 30 seconds
audit: type=1804 audit(1668476465.111:8): pid=11195 uid=0 auid=4294967295 ses=4294967295 op="invalid_pcr" cause="open_writers" comm="syz-executor.1" name="/root/syzkaller-testdir2995794484/syzkaller.AelnhG/49/file1/bus" dev="loop1" ino=6 res=1
attempt to access beyond end of device
loop1: rw=2049, want=230, limit=87
attempt to access beyond end of device
loop1: rw=1, want=192, limit=87
NILFS (loop0): corrupt root inode
NILFS (loop0): segctord starting. Construction interval = 5 seconds, CP frequency < 30 seconds
audit: type=1804 audit(1668476465.631:9): pid=11239 uid=0 auid=4294967295 ses=4294967295 op="invalid_pcr" cause="open_writers" comm="syz-executor.1" name="/root/syzkaller-testdir2995794484/syzkaller.AelnhG/50/file1/bus" dev="loop1" ino=9 res=1
attempt to access beyond end of device
loop1: rw=2049, want=230, limit=87
attempt to access beyond end of device
loop1: rw=1, want=192, limit=87
NILFS (loop0): corrupt root inode
NILFS (loop0): segctord starting. Construction interval = 5 seconds, CP frequency < 30 seconds
audit: type=1804 audit(1668476465.991:10): pid=11257 uid=0 auid=4294967295 ses=4294967295 op="invalid_pcr" cause="open_writers" comm="syz-executor.1" name="/root/syzkaller-testdir2995794484/syzkaller.AelnhG/51/file1/bus" dev="loop1" ino=11 res=1
attempt to access beyond end of device
loop1: rw=2049, want=230, limit=87
attempt to access beyond end of device
loop1: rw=1, want=192, limit=87
audit: type=1804 audit(1668476467.691:11): pid=11327 uid=0 auid=4294967295 ses=4294967295 op="invalid_pcr" cause="open_writers" comm="syz-executor.2" name="/root/syzkaller-testdir1022598549/syzkaller.9m6fIc/57/file1/bus" dev="loop2" ino=13 res=1
attempt to access beyond end of device
loop2: rw=2049, want=230, limit=87
attempt to access beyond end of device
loop2: rw=1, want=192, limit=87
audit: type=1804 audit(1668476467.811:12): pid=11345 uid=0 auid=4294967295 ses=4294967295 op="invalid_pcr" cause="open_writers" comm="syz-executor.2" name="/root/syzkaller-testdir1022598549/syzkaller.9m6fIc/58/file1/bus" dev="loop2" ino=15 res=1
attempt to access beyond end of device
loop2: rw=2049, want=230, limit=87
attempt to access beyond end of device
loop2: rw=1, want=192, limit=87
audit: type=1804 audit(1668476467.951:13): pid=11353 uid=0 auid=4294967295 ses=4294967295 op="invalid_pcr" cause="open_writers" comm="syz-executor.2" name="/root/syzkaller-testdir1022598549/syzkaller.9m6fIc/59/file1/bus" dev="loop2" ino=17 res=1
attempt to access beyond end of device
loop2: rw=2049, want=230, limit=87
attempt to access beyond end of device
loop2: rw=1, want=192, limit=87
audit: type=1804 audit(1668476468.061:14): pid=11361 uid=0 auid=4294967295 ses=4294967295 op="invalid_pcr" cause="open_writers" comm="syz-executor.2" name="/root/syzkaller-testdir1022598549/syzkaller.9m6fIc/60/file1/bus" dev="loop2" ino=19 res=1
attempt to access beyond end of device
loop2: rw=2049, want=230, limit=87
attempt to access beyond end of device
loop2: rw=1, want=192, limit=87
audit: type=1804 audit(1668476468.211:15): pid=11378 uid=0 auid=4294967295 ses=4294967295 op="invalid_pcr" cause="open_writers" comm="syz-executor.2" name="/root/syzkaller-testdir1022598549/syzkaller.9m6fIc/61/file1/bus" dev="loop2" ino=21 res=1
attempt to access beyond end of device
loop2: rw=2049, want=230, limit=87
attempt to access beyond end of device
loop2: rw=1, want=192, limit=87
attempt to access beyond end of device
loop2: rw=2049, want=230, limit=87
attempt to access beyond end of device
loop2: rw=1, want=192, limit=87
attempt to access beyond end of device
loop2: rw=2049, want=230, limit=87
attempt to access beyond end of device
loop2: rw=1, want=192, limit=87
attempt to access beyond end of device
loop5: rw=2049, want=230, limit=87
attempt to access beyond end of device
loop2: rw=2049, want=230, limit=87
attempt to access beyond end of device
loop5: rw=1, want=192, limit=87
attempt to access beyond end of device
loop2: rw=1, want=192, limit=87
attempt to access beyond end of device
loop5: rw=2049, want=230, limit=87
attempt to access beyond end of device
loop2: rw=2049, want=230, limit=87
attempt to access beyond end of device
attempt to access beyond end of device
loop2: rw=1, want=192, limit=87
loop5: rw=1, want=192, limit=87
---
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.