audit: type=1804 audit(1674544395.042:7): pid=11151 uid=0 auid=4294967295 ses=4294967295 op="invalid_pcr" cause="open_writers" comm="syz-executor.4" name="/root/syzkaller-testdir1897409014/syzkaller.rG9vrd/56/bus" dev="sda1" ino=14100 res=1
======================================================
WARNING: possible circular locking dependency detected
4.14.304-syzkaller #0 Not tainted
------------------------------------------------------
syz-executor.0/11133 is trying to acquire lock:
("dio/%s"sb->s_id){+.+.}, at: [<ffffffff8135ca1b>] flush_workqueue+0xcb/0x1310 kernel/workqueue.c:2622
but task is already holding lock:
(&sb->s_type->i_mutex_key#24){+.+.}, at: [<ffffffff8234b2e9>] inode_lock include/linux/fs.h:719 [inline]
(&sb->s_type->i_mutex_key#24){+.+.}, at: [<ffffffff8234b2e9>] udf_file_write_iter+0x69/0x470 fs/udf/file.c:144
which lock already depends on the new lock.
the existing dependency chain (in reverse order) is:
-> #2 (&sb->s_type->i_mutex_key#24){+.+.}:
down_write+0x34/0x90 kernel/locking/rwsem.c:54
inode_lock include/linux/fs.h:719 [inline]
__generic_file_fsync+0x9e/0x190 fs/libfs.c:1005
generic_file_fsync+0x73/0x110 fs/libfs.c:1042
vfs_fsync_range+0x103/0x260 fs/sync.c:196
generic_write_sync include/linux/fs.h:2684 [inline]
dio_complete+0x561/0x8d0 fs/direct-io.c:330
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
-> #1 ((&dio->complete_work)){+.+.}:
process_one_work+0x736/0x14a0 kernel/workqueue.c:2093
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
-> #0 ("dio/%s"sb->s_id){+.+.}:
lock_acquire+0x170/0x3f0 kernel/locking/lockdep.c:3998
flush_workqueue+0xfa/0x1310 kernel/workqueue.c:2625
drain_workqueue+0x177/0x3e0 kernel/workqueue.c:2790
destroy_workqueue+0x71/0x710 kernel/workqueue.c:4116
__alloc_workqueue_key+0xd50/0x1080 kernel/workqueue.c:4093
sb_init_dio_done_wq+0x34/0x80 fs/direct-io.c:624
do_blockdev_direct_IO fs/direct-io.c:1287 [inline]
__blockdev_direct_IO+0x3df1/0xdcb0 fs/direct-io.c:1423
blockdev_direct_IO include/linux/fs.h:2994 [inline]
udf_direct_IO+0x10a/0x230 fs/udf/inode.c:220
generic_file_direct_write+0x1df/0x420 mm/filemap.c:2958
__generic_file_write_iter+0x2a2/0x590 mm/filemap.c:3137
udf_file_write_iter+0x284/0x470 fs/udf/file.c:169
call_write_iter include/linux/fs.h:1780 [inline]
aio_write+0x2ed/0x560 fs/aio.c:1553
io_submit_one fs/aio.c:1641 [inline]
do_io_submit+0x847/0x1570 fs/aio.c:1709
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:
"dio/%s"sb->s_id --> (&dio->complete_work) --> &sb->s_type->i_mutex_key#24
Possible unsafe locking scenario:
CPU0 CPU1
---- ----
lock(&sb->s_type->i_mutex_key#24);
lock((&dio->complete_work));
lock(&sb->s_type->i_mutex_key#24);
lock("dio/%s"sb->s_id);
*** DEADLOCK ***
2 locks held by syz-executor.0/11133:
#0: (sb_writers#17){.+.+}, at: [<ffffffff81985e28>] file_start_write include/linux/fs.h:2714 [inline]
#0: (sb_writers#17){.+.+}, at: [<ffffffff81985e28>] aio_write+0x408/0x560 fs/aio.c:1552
#1: (&sb->s_type->i_mutex_key#24){+.+.}, at: [<ffffffff8234b2e9>] inode_lock include/linux/fs.h:719 [inline]
#1: (&sb->s_type->i_mutex_key#24){+.+.}, at: [<ffffffff8234b2e9>] udf_file_write_iter+0x69/0x470 fs/udf/file.c:144
stack backtrace:
CPU: 1 PID: 11133 Comm: syz-executor.0 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
flush_workqueue+0xfa/0x1310 kernel/workqueue.c:2625
drain_workqueue+0x177/0x3e0 kernel/workqueue.c:2790
destroy_workqueue+0x71/0x710 kernel/workqueue.c:4116
__alloc_workqueue_key+0xd50/0x1080 kernel/workqueue.c:4093
sb_init_dio_done_wq+0x34/0x80 fs/direct-io.c:624
do_blockdev_direct_IO fs/direct-io.c:1287 [inline]
__blockdev_direct_IO+0x3df1/0xdcb0 fs/direct-io.c:1423
blockdev_direct_IO include/linux/fs.h:2994 [inline]
udf_direct_IO+0x10a/0x230 fs/udf/inode.c:220
generic_file_direct_write+0x1df/0x420 mm/filemap.c:2958
__generic_file_write_iter+0x2a2/0x590 mm/filemap.c:3137
udf_file_write_iter+0x284/0x470 fs/udf/file.c:169
call_write_iter include/linux/fs.h:1780 [inline]
aio_write+0x2ed/0x560 fs/aio.c:1553
io_submit_one fs/aio.c:1641 [inline]
do_io_submit+0x847/0x1570 fs/aio.c:1709
do_syscall_64+0x1d5/0x640 arch/x86/entry/common.c:292
entry_SYSCALL_64_after_hwframe+0x5e/0xd3
RIP: 0033:0x7ff2efd4b0c9
RSP: 002b:00007ff2ee2bd168 EFLAGS: 00000246 ORIG_RAX: 00000000000000d1
RAX: ffffffffffffffda RBX: 00007ff2efe6af80 RCX: 00007ff2efd4b0c9
RDX: 0000000020000540 RSI: 0000000000000004 RDI: 00007ff2e5f7c000
RBP: 00007ff2efda6ae9 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000246 R12: 0000000000000000
R13: 00007ffd64babb0f R14: 00007ff2ee2bd300 R15: 0000000000022000
FAT-fs (loop5): Directory bread(block 65449) failed
FAT-fs (loop5): Directory bread(block 65450) failed
FAT-fs (loop5): Directory bread(block 65449) failed
FAT-fs (loop5): Directory bread(block 65450) failed
FAT-fs (loop5): Directory bread(block 65449) failed
FAT-fs (loop5): Directory bread(block 65450) failed
FAT-fs (loop5): FAT read failed (blocknr 65409)
FAT-fs (loop5): Directory bread(block 65449) failed
FAT-fs (loop5): Directory bread(block 65450) failed
FAT-fs (loop5): FAT read failed (blocknr 65409)
audit: type=1804 audit(1674544396.412:8): pid=11168 uid=0 auid=4294967295 ses=4294967295 op="invalid_pcr" cause="open_writers" comm="syz-executor.2" name="/root/syzkaller-testdir2185598199/syzkaller.MUD2LV/43/bus" dev="sda1" ino=14115 res=1
audit: type=1804 audit(1674544396.522:9): pid=11165 uid=0 auid=4294967295 ses=4294967295 op="invalid_pcr" cause="open_writers" comm="syz-executor.3" name="/root/syzkaller-testdir1915980077/syzkaller.QvVEWq/57/bus" dev="sda1" ino=14128 res=1
FAT-fs (loop5): Directory bread(block 65449) failed
FAT-fs (loop5): Directory bread(block 65450) failed
FAT-fs (loop5): Directory bread(block 65449) failed
FAT-fs (loop5): Directory bread(block 65450) failed
FAT-fs (loop5): Directory bread(block 65449) failed
FAT-fs (loop5): Directory bread(block 65450) failed
FAT-fs (loop5): FAT read failed (blocknr 65409)
FAT-fs (loop5): Directory bread(block 65449) failed
FAT-fs (loop5): Directory bread(block 65450) failed
FAT-fs (loop5): FAT read failed (blocknr 65409)
audit: type=1804 audit(1674544397.192:10): pid=11190 uid=0 auid=4294967295 ses=4294967295 op="invalid_pcr" cause="open_writers" comm="syz-executor.3" name="/root/syzkaller-testdir1915980077/syzkaller.QvVEWq/58/bus" dev="sda1" ino=14124 res=1
audit: type=1804 audit(1674544397.602:11): pid=11187 uid=0 auid=4294967295 ses=4294967295 op="invalid_pcr" cause="open_writers" comm="syz-executor.4" name="/root/syzkaller-testdir1897409014/syzkaller.rG9vrd/57/bus" dev="sda1" ino=14100 res=1
audit: type=1804 audit(1674544397.732:12): pid=11198 uid=0 auid=4294967295 ses=4294967295 op="invalid_pcr" cause="open_writers" comm="syz-executor.2" name="/root/syzkaller-testdir2185598199/syzkaller.MUD2LV/44/bus" dev="sda1" ino=14130 res=1
audit: type=1804 audit(1674544398.322:13): pid=11210 uid=0 auid=4294967295 ses=4294967295 op="invalid_pcr" cause="open_writers" comm="syz-executor.3" name="/root/syzkaller-testdir1915980077/syzkaller.QvVEWq/59/bus" dev="sda1" ino=14131 res=1
audit: type=1804 audit(1674544398.702:14): pid=11207 uid=0 auid=4294967295 ses=4294967295 op="invalid_pcr" cause="open_writers" comm="syz-executor.4" name="/root/syzkaller-testdir1897409014/syzkaller.rG9vrd/58/bus" dev="sda1" ino=14100 res=1
audit: type=1804 audit(1674544398.982:15): pid=11228 uid=0 auid=4294967295 ses=4294967295 op="invalid_pcr" cause="open_writers" comm="syz-executor.4" name="/root/syzkaller-testdir1897409014/syzkaller.rG9vrd/59/bus" dev="sda1" ino=14121 res=1
audit: type=1804 audit(1674544399.502:16): pid=11241 uid=0 auid=4294967295 ses=4294967295 op="invalid_pcr" cause="open_writers" comm="syz-executor.2" name="/root/syzkaller-testdir2185598199/syzkaller.MUD2LV/45/bus" dev="sda1" ino=14130 res=1
: renamed from syz_tun
FAT-fs (loop5): Directory bread(block 65449) failed
FAT-fs (loop5): Directory bread(block 65450) failed
FAT-fs (loop5): Directory bread(block 65449) failed
FAT-fs (loop5): Directory bread(block 65450) failed
FAT-fs (loop5): Directory bread(block 65449) failed
FAT-fs (loop5): Directory bread(block 65450) failed
FAT-fs (loop5): FAT read failed (blocknr 65409)
FAT-fs (loop5): Directory bread(block 65449) failed
FAT-fs (loop5): Directory bread(block 65450) failed
audit: type=1804 audit(1674544400.462:17): pid=11258 uid=0 auid=4294967295 ses=4294967295 op="invalid_pcr" cause="open_writers" comm="syz-executor.0" name="/root/syzkaller-testdir529721367/syzkaller.jFNguN/53/bus" dev="sda1" ino=14099 res=1
FAT-fs (loop5): FAT read failed (blocknr 65409)
: renamed from syz_tun
audit: type=1804 audit(1674544401.752:18): pid=11285 uid=0 auid=4294967295 ses=4294967295 op="invalid_pcr" cause="open_writers" comm="syz-executor.0" name="/root/syzkaller-testdir529721367/syzkaller.jFNguN/54/bus" dev="sda1" ino=14153 res=1
audit: type=1804 audit(1674544402.122:19): pid=11280 uid=0 auid=4294967295 ses=4294967295 op="invalid_pcr" cause="open_writers" comm="syz-executor.2" name="/root/syzkaller-testdir2185598199/syzkaller.MUD2LV/46/bus" dev="sda1" ino=14135 res=1
: renamed from syz_tun
audit: type=1804 audit(1674544402.332:20): pid=11304 uid=0 auid=4294967295 ses=4294967295 op="invalid_pcr" cause="open_writers" comm="syz-executor.0" name="/root/syzkaller-testdir529721367/syzkaller.jFNguN/55/bus" dev="sda1" ino=14155 res=1
UDF-fs: INFO Mounting volume 'LinuxUDF', timestamp 2022/11/22 14:59 (1000)
UDF-fs: INFO Mounting volume 'LinuxUDF', timestamp 2022/11/22 14:59 (1000)
UDF-fs: INFO Mounting volume 'LinuxUDF', timestamp 2022/11/22 14:59 (1000)
kvm: vcpu 0: requested 128 ns lapic timer period limited to 500000 ns
UDF-fs: INFO Mounting volume 'LinuxUDF', timestamp 2022/11/22 14:59 (1000)
UDF-fs: INFO Mounting volume 'LinuxUDF', timestamp 2022/11/22 14:59 (1000)
UDF-fs: INFO Mounting volume 'LinuxUDF', timestamp 2022/11/22 14:59 (1000)
kvm: vcpu 0: requested 128 ns lapic timer period limited to 500000 ns
kvm: vcpu 0: requested 128 ns lapic timer period limited to 500000 ns
kvm: vcpu 0: requested 128 ns lapic timer period limited to 500000 ns
kvm: vcpu 0: requested 128 ns lapic timer period limited to 500000 ns
kvm: vcpu 0: requested 128 ns lapic timer period limited to 500000 ns
kvm: vcpu 0: requested 128 ns lapic timer period limited to 500000 ns