possible deadlock in ext4_file_write_iter (2)

5 views
Skip to first unread message

syzbot

unread,
Oct 24, 2020, 4:36:16 AM10/24/20
to syzkaller...@googlegroups.com
Hello,

syzbot found the following issue on:

HEAD commit: 5b7a52cd Linux 4.14.202
git tree: linux-4.14.y
console output: https://syzkaller.appspot.com/x/log.txt?x=13618a28500000
kernel config: https://syzkaller.appspot.com/x/.config?x=fa386e02ca459165
dashboard link: https://syzkaller.appspot.com/bug?extid=735bf1ddeace671aa13b
compiler: gcc (GCC) 10.1.0-syz 20200507

Unfortunately, I don't have any reproducer for this issue yet.

IMPORTANT: if you fix the issue, please add the following tag to the commit:
Reported-by: syzbot+735bf1...@syzkaller.appspotmail.com

======================================================
WARNING: possible circular locking dependency detected
4.14.202-syzkaller #0 Not tainted
------------------------------------------------------
//selinux/19963 is trying to acquire lock:
("dio/%s"sb->s_id){+.+.}, at: [<ffffffff81369e5b>] flush_workqueue+0xcb/0x1310 kernel/workqueue.c:2621

but task is already holding lock:
(&sb->s_type->i_mutex_key#10){++++}, at: [<ffffffff81ba743c>] inode_trylock include/linux/fs.h:739 [inline]
(&sb->s_type->i_mutex_key#10){++++}, at: [<ffffffff81ba743c>] ext4_file_write_iter+0x1cc/0xd20 fs/ext4/file.c:236

which lock already depends on the new lock.


the existing dependency chain (in reverse order) is:

-> #2 (&sb->s_type->i_mutex_key#10){++++}:
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:987
ext4_sync_file+0x8ed/0x12c0 fs/ext4/fsync.c:118
vfs_fsync_range+0x103/0x260 fs/sync.c:196
generic_write_sync include/linux/fs.h:2682 [inline]
dio_complete+0x561/0x8d0 fs/direct-io.c:330
process_one_work+0x793/0x14a0 kernel/workqueue.c:2116
worker_thread+0x5cc/0xff0 kernel/workqueue.c:2250
kthread+0x30d/0x420 kernel/kthread.c:232
ret_from_fork+0x24/0x30 arch/x86/entry/entry_64.S:404

-> #1 ((&dio->complete_work)){+.+.}:
process_one_work+0x736/0x14a0 kernel/workqueue.c:2092
worker_thread+0x5cc/0xff0 kernel/workqueue.c:2250
kthread+0x30d/0x420 kernel/kthread.c:232
ret_from_fork+0x24/0x30 arch/x86/entry/entry_64.S:404

-> #0 ("dio/%s"sb->s_id){+.+.}:
lock_acquire+0x170/0x3f0 kernel/locking/lockdep.c:3998
flush_workqueue+0xfa/0x1310 kernel/workqueue.c:2624
drain_workqueue+0x177/0x3e0 kernel/workqueue.c:2789
destroy_workqueue+0x71/0x710 kernel/workqueue.c:4102
sb_init_dio_done_wq+0x61/0x80 fs/direct-io.c:635
do_blockdev_direct_IO fs/direct-io.c:1286 [inline]
__blockdev_direct_IO+0x3dea/0xdc60 fs/direct-io.c:1422
ext4_direct_IO_write fs/ext4/inode.c:3716 [inline]
ext4_direct_IO+0x888/0x1b80 fs/ext4/inode.c:3857
generic_file_direct_write+0x1df/0x420 mm/filemap.c:2958
__generic_file_write_iter+0x2a2/0x590 mm/filemap.c:3137
ext4_file_write_iter+0x276/0xd20 fs/ext4/file.c:270
call_write_iter include/linux/fs.h:1778 [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+0x46/0xbb

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#10

Possible unsafe locking scenario:

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

*** DEADLOCK ***

2 locks held by //selinux/19963:
#0: (sb_writers#3){.+.+}, at: [<ffffffff819a52c8>] file_start_write include/linux/fs.h:2712 [inline]
#0: (sb_writers#3){.+.+}, at: [<ffffffff819a52c8>] aio_write+0x408/0x560 fs/aio.c:1552
#1: (&sb->s_type->i_mutex_key#10){++++}, at: [<ffffffff81ba743c>] inode_trylock include/linux/fs.h:739 [inline]
#1: (&sb->s_type->i_mutex_key#10){++++}, at: [<ffffffff81ba743c>] ext4_file_write_iter+0x1cc/0xd20 fs/ext4/file.c:236

stack backtrace:
CPU: 1 PID: 19963 Comm: //selinux Not tainted 4.14.202-syzkaller #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011
Call Trace:
__dump_stack lib/dump_stack.c:17 [inline]
dump_stack+0x1b2/0x283 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:2624
drain_workqueue+0x177/0x3e0 kernel/workqueue.c:2789
destroy_workqueue+0x71/0x710 kernel/workqueue.c:4102
sb_init_dio_done_wq+0x61/0x80 fs/direct-io.c:635
do_blockdev_direct_IO fs/direct-io.c:1286 [inline]
__blockdev_direct_IO+0x3dea/0xdc60 fs/direct-io.c:1422
ext4_direct_IO_write fs/ext4/inode.c:3716 [inline]
ext4_direct_IO+0x888/0x1b80 fs/ext4/inode.c:3857
generic_file_direct_write+0x1df/0x420 mm/filemap.c:2958
__generic_file_write_iter+0x2a2/0x590 mm/filemap.c:3137
ext4_file_write_iter+0x276/0xd20 fs/ext4/file.c:270
call_write_iter include/linux/fs.h:1778 [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+0x46/0xbb
RIP: 0033:0x45de59
RSP: 002b:00007f663f57bc78 EFLAGS: 00000246 ORIG_RAX: 00000000000000d1
RAX: ffffffffffffffda RBX: 0000000000008280 RCX: 000000000045de59
RDX: 0000000020000540 RSI: 0000000000000006 RDI: 00007f663f559000
RBP: 000000000118bf60 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000246 R12: 000000000118bf2c
R13: 00007ffd6f1bb2ef R14: 00007f663f57c9c0 R15: 000000000118bf2c


---
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

unread,
Jan 17, 2021, 10:46:19 PM1/17/21
to syzkaller...@googlegroups.com
syzbot has found a reproducer for the following issue on:

HEAD commit: 2762b48e Linux 4.14.216
git tree: linux-4.14.y
console output: https://syzkaller.appspot.com/x/log.txt?x=14212094d00000
kernel config: https://syzkaller.appspot.com/x/.config?x=e8574522d7c28056
dashboard link: https://syzkaller.appspot.com/bug?extid=735bf1ddeace671aa13b
compiler: gcc (GCC) 10.1.0-syz 20200507
syz repro: https://syzkaller.appspot.com/x/repro.syz?x=13932a58d00000

IMPORTANT: if you fix the issue, please add the following tag to the commit:
Reported-by: syzbot+735bf1...@syzkaller.appspotmail.com

Bluetooth: hci5 command 0x0419 tx timeout
hrtimer: interrupt took 26566 ns
Bluetooth: hci3 command 0x0419 tx timeout
Bluetooth: hci4 command 0x0419 tx timeout
======================================================
WARNING: possible circular locking dependency detected
4.14.216-syzkaller #0 Not tainted
------------------------------------------------------
syz-executor.0/9478 is trying to acquire lock:
("dio/%s"sb->s_id){+.+.}, at: [<ffffffff8135a24b>] flush_workqueue+0xcb/0x1310 kernel/workqueue.c:2621

but task is already holding lock:
(&sb->s_type->i_mutex_key#10){+.+.}, at: [<ffffffff81b6fc5c>] inode_trylock include/linux/fs.h:739 [inline]
(&sb->s_type->i_mutex_key#10){+.+.}, at: [<ffffffff81b6fc5c>] ext4_file_write_iter+0x1cc/0xd20 fs/ext4/file.c:236

which lock already depends on the new lock.


the existing dependency chain (in reverse order) is:

-> #2 (&sb->s_type->i_mutex_key#10){+.+.}:
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:989
ext4_sync_file+0x8ed/0x12c0 fs/ext4/fsync.c:118
vfs_fsync_range+0x103/0x260 fs/sync.c:196
generic_write_sync include/linux/fs.h:2682 [inline]
dio_complete+0x561/0x8d0 fs/direct-io.c:330
process_one_work+0x793/0x14a0 kernel/workqueue.c:2116
worker_thread+0x5cc/0xff0 kernel/workqueue.c:2250
kthread+0x30d/0x420 kernel/kthread.c:232
ret_from_fork+0x24/0x30 arch/x86/entry/entry_64.S:404

-> #1 ((&dio->complete_work)){+.+.}:
process_one_work+0x736/0x14a0 kernel/workqueue.c:2092
worker_thread+0x5cc/0xff0 kernel/workqueue.c:2250
kthread+0x30d/0x420 kernel/kthread.c:232
ret_from_fork+0x24/0x30 arch/x86/entry/entry_64.S:404

-> #0 ("dio/%s"sb->s_id){+.+.}:
lock_acquire+0x170/0x3f0 kernel/locking/lockdep.c:3998
flush_workqueue+0xfa/0x1310 kernel/workqueue.c:2624
drain_workqueue+0x177/0x3e0 kernel/workqueue.c:2789
destroy_workqueue+0x71/0x710 kernel/workqueue.c:4109
sb_init_dio_done_wq+0x61/0x80 fs/direct-io.c:635
do_blockdev_direct_IO fs/direct-io.c:1286 [inline]
__blockdev_direct_IO+0x3dea/0xdc60 fs/direct-io.c:1422
ext4_direct_IO_write fs/ext4/inode.c:3725 [inline]
ext4_direct_IO+0x888/0x1b80 fs/ext4/inode.c:3866
generic_file_direct_write+0x1df/0x420 mm/filemap.c:2958
__generic_file_write_iter+0x2a2/0x590 mm/filemap.c:3137
ext4_file_write_iter+0x7c5/0xd20 fs/ext4/file.c:270
call_write_iter include/linux/fs.h:1778 [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+0x46/0xbb

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#10

Possible unsafe locking scenario:

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

*** DEADLOCK ***

2 locks held by syz-executor.0/9478:
#0: (sb_writers#3){.+.+}, at: [<ffffffff8197c3b8>] file_start_write include/linux/fs.h:2712 [inline]
#0: (sb_writers#3){.+.+}, at: [<ffffffff8197c3b8>] aio_write+0x408/0x560 fs/aio.c:1552
#1: (&sb->s_type->i_mutex_key#10){+.+.}, at: [<ffffffff81b6fc5c>] inode_trylock include/linux/fs.h:739 [inline]
#1: (&sb->s_type->i_mutex_key#10){+.+.}, at: [<ffffffff81b6fc5c>] ext4_file_write_iter+0x1cc/0xd20 fs/ext4/file.c:236

stack backtrace:
CPU: 1 PID: 9478 Comm: syz-executor.0 Not tainted 4.14.216-syzkaller #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011
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:2624
drain_workqueue+0x177/0x3e0 kernel/workqueue.c:2789
destroy_workqueue+0x71/0x710 kernel/workqueue.c:4109
sb_init_dio_done_wq+0x61/0x80 fs/direct-io.c:635
do_blockdev_direct_IO fs/direct-io.c:1286 [inline]
__blockdev_direct_IO+0x3dea/0xdc60 fs/direct-io.c:1422
ext4_direct_IO_write fs/ext4/inode.c:3725 [inline]
ext4_direct_IO+0x888/0x1b80 fs/ext4/inode.c:3866
generic_file_direct_write+0x1df/0x420 mm/filemap.c:2958
__generic_file_write_iter+0x2a2/0x590 mm/filemap.c:3137
ext4_file_write_iter+0x7c5/0xd20 fs/ext4/file.c:270
call_write_iter include/linux/fs.h:1778 [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+0x46/0xbb
RIP: 0033:0x45e219
RSP: 002b:00007f91e5118c68 EFLAGS: 00000246 ORIG_RAX: 00000000000000d1
RAX: ffffffffffffffda RBX: 0000000000000003 RCX: 000000000045e219
RDX: 00000000200003c0 RSI: 00000000000041e3 RDI: 00007f91e50f6000
RBP: 000000000119bfc0 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000246 R12: 000000000119bf8c
R13: 00007ffe46ed3f3f R14: 00007f91e51199c0 R15: 000000000119bf8c
Bluetooth: hci0 command 0x0419 tx timeout

Reply all
Reply to author
Forward
0 new messages