possible deadlock in __generic_file_fsync

[syzbot]

Hello,

syzbot found the following crash on:

HEAD commit: 6d46bcc5 ANDROID: x86_64_cuttlefish_defconfig: disable CON..
git tree: android-4.14
console output: https://syzkaller.appspot.com/x/log.txt?x=10e1bc26400000
kernel config: https://syzkaller.appspot.com/x/.config?x=6d42c81ed97e27e5
dashboard link: https://syzkaller.appspot.com/bug?extid=7d66ca77f7bdfbb8e684
compiler: gcc (GCC) 8.0.1 20180413 (experimental)
syz repro: https://syzkaller.appspot.com/x/repro.syz?x=14feda41400000

IMPORTANT: if you fix the bug, please add the following tag to the commit:
Reported-by: syzbot+7d66ca...@syzkaller.appspotmail.com

audit: type=1400 audit(1539755749.782:12): avc: denied { read } for
pid=4438 comm="syz-executor0"
scontext=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023
tcontext=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023
tclass=netlink_generic_socket permissive=1
audit: type=1400 audit(1539755749.932:13): avc: denied { map } for
pid=4438 comm="syz-executor0" path="/dev/loop-control" dev="devtmpfs"
ino=1058 scontext=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023
tcontext=system_u:object_r:device_t:s0 tclass=chr_file permissive=1

======================================================
WARNING: possible circular locking dependency detected
4.14.76+ #20 Not tainted
------------------------------------------------------
kworker/1:1/68 is trying to acquire lock:
(&sb->s_type->i_mutex_key#9){+.+.}, at: [<ffffffff921db45e>] inode_lock
include/linux/fs.h:713 [inline]
(&sb->s_type->i_mutex_key#9){+.+.}, at: [<ffffffff921db45e>]
__generic_file_fsync+0x9e/0x1a0 fs/libfs.c:981

but task is already holding lock:
((&dio->complete_work)){+.+.}, at: [<ffffffff91d2795f>]
process_one_work+0x7bf/0x15c0 kernel/workqueue.c:2089

which lock already depends on the new lock.


the existing dependency chain (in reverse order) is:

-> #2 ((&dio->complete_work)){+.+.}:
process_one_work+0x813/0x15c0 kernel/workqueue.c:2090
worker_thread+0xdc/0x1000 kernel/workqueue.c:2248
kthread+0x348/0x420 kernel/kthread.c:232
ret_from_fork+0x3a/0x50 arch/x86/entry/entry_64.S:402

-> #1 ("dio/%s"sb->s_id){+.+.}:
flush_workqueue+0xfc/0x1390 kernel/workqueue.c:2616
drain_workqueue+0x17b/0x3f0 kernel/workqueue.c:2781
destroy_workqueue+0x23/0x600 kernel/workqueue.c:4088
sb_init_dio_done_wq+0x5e/0x70 fs/direct-io.c:613
do_blockdev_direct_IO fs/direct-io.c:1263 [inline]
__blockdev_direct_IO+0x29e2/0xc4e0 fs/direct-io.c:1399
ext4_direct_IO_write fs/ext4/inode.c:3710 [inline]
ext4_direct_IO+0x905/0x27f0 fs/ext4/inode.c:3863
generic_file_direct_write+0x225/0x430 mm/filemap.c:2940
__generic_file_write_iter+0x213/0x540 mm/filemap.c:3119
ext4_file_write_iter+0x4f6/0xe20 fs/ext4/file.c:264
call_write_iter include/linux/fs.h:1782 [inline]
aio_write+0x2f2/0x510 fs/aio.c:1551
io_submit_one fs/aio.c:1639 [inline]
do_io_submit+0xef4/0x12a0 fs/aio.c:1707
do_syscall_64+0x19b/0x4b0 arch/x86/entry/common.c:289
entry_SYSCALL_64_after_hwframe+0x42/0xb7

-> #0 (&sb->s_type->i_mutex_key#9){+.+.}:
lock_acquire+0x10f/0x380 kernel/locking/lockdep.c:3991
down_write+0x34/0x90 kernel/locking/rwsem.c:54
inode_lock include/linux/fs.h:713 [inline]
__generic_file_fsync+0x9e/0x1a0 fs/libfs.c:981
ext4_sync_file+0x39e/0x1050 fs/ext4/fsync.c:120
vfs_fsync_range+0x105/0x260 fs/sync.c:196
generic_write_sync include/linux/fs.h:2689 [inline]
dio_complete+0x621/0x800 fs/direct-io.c:308
process_one_work+0x86e/0x15c0 kernel/workqueue.c:2114
worker_thread+0xdc/0x1000 kernel/workqueue.c:2248
kthread+0x348/0x420 kernel/kthread.c:232
ret_from_fork+0x3a/0x50 arch/x86/entry/entry_64.S:402

other info that might help us debug this:

Chain exists of:
&sb->s_type->i_mutex_key#9 --> "dio/%s"sb->s_id --> (&dio->complete_work)

Possible unsafe locking scenario:

CPU0 CPU1
---- ----
lock((&dio->complete_work));
lock("dio/%s"sb->s_id);
lock((&dio->complete_work));
lock(&sb->s_type->i_mutex_key#9);

*** DEADLOCK ***

2 locks held by kworker/1:1/68:
#0: ("dio/%s"sb->s_id){+.+.}, at: [<ffffffff91d27927>]
process_one_work+0x787/0x15c0 kernel/workqueue.c:2085
#1: ((&dio->complete_work)){+.+.}, at: [<ffffffff91d2795f>]
process_one_work+0x7bf/0x15c0 kernel/workqueue.c:2089

stack backtrace:
CPU: 1 PID: 68 Comm: kworker/1:1 Not tainted 4.14.76+ #20
Workqueue: dio/sda1 dio_aio_complete_work
Call Trace:
__dump_stack lib/dump_stack.c:17 [inline]
dump_stack+0xb9/0x11b lib/dump_stack.c:53
print_circular_bug.isra.18.cold.43+0x2d3/0x40c
kernel/locking/lockdep.c:1258
check_prev_add kernel/locking/lockdep.c:1901 [inline]
check_prevs_add kernel/locking/lockdep.c:2018 [inline]
validate_chain kernel/locking/lockdep.c:2460 [inline]
__lock_acquire+0x2ff9/0x4320 kernel/locking/lockdep.c:3487
lock_acquire+0x10f/0x380 kernel/locking/lockdep.c:3991
down_write+0x34/0x90 kernel/locking/rwsem.c:54
inode_lock include/linux/fs.h:713 [inline]
__generic_file_fsync+0x9e/0x1a0 fs/libfs.c:981
ext4_sync_file+0x39e/0x1050 fs/ext4/fsync.c:120
vfs_fsync_range+0x105/0x260 fs/sync.c:196
generic_write_sync include/linux/fs.h:2689 [inline]
dio_complete+0x621/0x800 fs/direct-io.c:308
process_one_work+0x86e/0x15c0 kernel/workqueue.c:2114
worker_thread+0xdc/0x1000 kernel/workqueue.c:2248
kthread+0x348/0x420 kernel/kthread.c:232
ret_from_fork+0x3a/0x50 arch/x86/entry/entry_64.S:402
hrtimer: interrupt took 15813 ns


---
This bug 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 bug report. See:
https://goo.gl/tpsmEJ#status for how to communicate with syzbot.
syzbot can test patches for this bug, for details see:
https://goo.gl/tpsmEJ#testing-patches