inconsistent lock state in io_dismantle_req

From: syzbot
Date: Mon Feb 01 2021 - 04:18:34 EST


Hello,

syzbot found the following issue on:

HEAD commit: b01f250d Add linux-next specific files for 20210129
git tree: linux-next
console output: https://syzkaller.appspot.com/x/log.txt?x=160cda90d00000
kernel config: https://syzkaller.appspot.com/x/.config?x=725bc96dc234fda7
dashboard link: https://syzkaller.appspot.com/bug?extid=81d17233a2b02eafba33
compiler: gcc (GCC) 10.1.0-syz 20200507
syz repro: https://syzkaller.appspot.com/x/repro.syz?x=14f8a330d00000
C reproducer: https://syzkaller.appspot.com/x/repro.c?x=12c10440d00000

IMPORTANT: if you fix the issue, please add the following tag to the commit:
Reported-by: syzbot+81d17233a2b02eafba33@xxxxxxxxxxxxxxxxxxxxxxxxx

================================
WARNING: inconsistent lock state
5.11.0-rc5-next-20210129-syzkaller #0 Not tainted
--------------------------------
inconsistent {HARDIRQ-ON-W} -> {IN-HARDIRQ-W} usage.
syz-executor217/8450 [HC1[1]:SC0[0]:HE0:SE1] takes:
ffff888023d6e620 (&fs->lock){?.+.}-{2:2}, at: spin_lock include/linux/spinlock.h:354 [inline]
ffff888023d6e620 (&fs->lock){?.+.}-{2:2}, at: io_req_clean_work fs/io_uring.c:1398 [inline]
ffff888023d6e620 (&fs->lock){?.+.}-{2:2}, at: io_dismantle_req+0x66f/0xf60 fs/io_uring.c:2029
{HARDIRQ-ON-W} state was registered at:
lock_acquire kernel/locking/lockdep.c:5509 [inline]
lock_acquire+0x1a8/0x720 kernel/locking/lockdep.c:5474
__raw_spin_lock include/linux/spinlock_api_smp.h:142 [inline]
_raw_spin_lock+0x2a/0x40 kernel/locking/spinlock.c:151
spin_lock include/linux/spinlock.h:354 [inline]
set_fs_pwd+0x85/0x2a0 fs/fs_struct.c:39
init_chdir+0xdf/0x127 fs/init.c:54
devtmpfs_setup drivers/base/devtmpfs.c:418 [inline]
devtmpfsd+0x76/0x333 drivers/base/devtmpfs.c:433
kthread+0x3b1/0x4a0 kernel/kthread.c:292
ret_from_fork+0x1f/0x30 arch/x86/entry/entry_64.S:296
irq event stamp: 786
hardirqs last enabled at (785): [<ffffffff8903de4f>] __raw_spin_unlock_irq include/linux/spinlock_api_smp.h:168 [inline]
hardirqs last enabled at (785): [<ffffffff8903de4f>] _raw_spin_unlock_irq+0x1f/0x40 kernel/locking/spinlock.c:199
hardirqs last disabled at (786): [<ffffffff8901704c>] sysvec_apic_timer_interrupt+0xc/0x100 arch/x86/kernel/apic/apic.c:1096
softirqs last enabled at (664): [<ffffffff87abbe04>] read_pnet include/net/net_namespace.h:324 [inline]
softirqs last enabled at (664): [<ffffffff87abbe04>] sock_net include/net/sock.h:2550 [inline]
softirqs last enabled at (664): [<ffffffff87abbe04>] unix_create1+0x484/0x570 net/unix/af_unix.c:814
softirqs last disabled at (662): [<ffffffff87abbd81>] unix_sockets_unbound net/unix/af_unix.c:133 [inline]
softirqs last disabled at (662): [<ffffffff87abbd81>] unix_create1+0x401/0x570 net/unix/af_unix.c:808

other info that might help us debug this:
Possible unsafe locking scenario:

CPU0
----
lock(&fs->lock);
<Interrupt>
lock(&fs->lock);

*** DEADLOCK ***

1 lock held by syz-executor217/8450:
#0: ffff88802417c3e8 (&ctx->uring_lock){+.+.}-{3:3}, at: __do_sys_io_uring_enter+0x1071/0x1f30 fs/io_uring.c:9442

stack backtrace:
CPU: 1 PID: 8450 Comm: syz-executor217 Not tainted 5.11.0-rc5-next-20210129-syzkaller #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011
Call Trace:
<IRQ>
__dump_stack lib/dump_stack.c:79 [inline]
dump_stack+0x107/0x163 lib/dump_stack.c:120
print_usage_bug kernel/locking/lockdep.c:3806 [inline]
valid_state kernel/locking/lockdep.c:3817 [inline]
mark_lock_irq kernel/locking/lockdep.c:4020 [inline]
mark_lock.cold+0x61/0x8e kernel/locking/lockdep.c:4477
mark_usage kernel/locking/lockdep.c:4369 [inline]
__lock_acquire+0x1468/0x54c0 kernel/locking/lockdep.c:4853
lock_acquire kernel/locking/lockdep.c:5509 [inline]
lock_acquire+0x1a8/0x720 kernel/locking/lockdep.c:5474
__raw_spin_lock include/linux/spinlock_api_smp.h:142 [inline]
_raw_spin_lock+0x2a/0x40 kernel/locking/spinlock.c:151
spin_lock include/linux/spinlock.h:354 [inline]
io_req_clean_work fs/io_uring.c:1398 [inline]
io_dismantle_req+0x66f/0xf60 fs/io_uring.c:2029
__io_free_req+0x3d/0x2e0 fs/io_uring.c:2046
io_free_req fs/io_uring.c:2269 [inline]
io_double_put_req fs/io_uring.c:2392 [inline]
io_put_req+0xf9/0x570 fs/io_uring.c:2388
io_link_timeout_fn+0x30c/0x480 fs/io_uring.c:6497
__run_hrtimer kernel/time/hrtimer.c:1519 [inline]
__hrtimer_run_queues+0x609/0xe40 kernel/time/hrtimer.c:1583
hrtimer_interrupt+0x334/0x940 kernel/time/hrtimer.c:1645
local_apic_timer_interrupt arch/x86/kernel/apic/apic.c:1085 [inline]
__sysvec_apic_timer_interrupt+0x146/0x540 arch/x86/kernel/apic/apic.c:1102
asm_call_irq_on_stack+0xf/0x20
</IRQ>
__run_sysvec_on_irqstack arch/x86/include/asm/irq_stack.h:37 [inline]
run_sysvec_on_irqstack_cond arch/x86/include/asm/irq_stack.h:89 [inline]
sysvec_apic_timer_interrupt+0xbd/0x100 arch/x86/kernel/apic/apic.c:1096
asm_sysvec_apic_timer_interrupt+0x12/0x20 arch/x86/include/asm/idtentry.h:629
RIP: 0010:__raw_spin_unlock_irq include/linux/spinlock_api_smp.h:169 [inline]
RIP: 0010:_raw_spin_unlock_irq+0x25/0x40 kernel/locking/spinlock.c:199
Code: 0f 1f 44 00 00 55 48 8b 74 24 08 48 89 fd 48 83 c7 18 e8 de 04 55 f8 48 89 ef e8 36 ba 55 f8 e8 71 16 75 f8 fb bf 01 00 00 00 <e8> 76 b9 49 f8 65 8b 05 5f 11 fe 76 85 c0 74 02 5d c3 e8 cb 66 fc
RSP: 0018:ffffc9000166f978 EFLAGS: 00000206
RAX: 0000000000000311 RBX: ffff8881416eaa00 RCX: 1ffffffff1df7d02
RDX: 0000000000000000 RSI: 0000000000000001 RDI: 0000000000000001
RBP: ffff88802417c480 R08: 0000000000000001 R09: ffffffff8ef738e7
R10: 0000000000000001 R11: 0000000000000000 R12: ffff88802417c480
R13: 0000000000000000 R14: 0000000000000001 R15: 0000000000000000
spin_unlock_irq include/linux/spinlock.h:404 [inline]
io_queue_linked_timeout+0x194/0x1f0 fs/io_uring.c:6525
__io_queue_sqe+0x328/0x1290 fs/io_uring.c:6594
io_queue_sqe+0x631/0x10d0 fs/io_uring.c:6639
io_queue_link_head fs/io_uring.c:6650 [inline]
io_submit_sqe fs/io_uring.c:6697 [inline]
io_submit_sqes+0x19b5/0x2720 fs/io_uring.c:6960
__do_sys_io_uring_enter+0x107d/0x1f30 fs/io_uring.c:9443
do_syscall_64+0x2d/0x70 arch/x86/entry/common.c:46
entry_SYSCALL_64_after_hwframe+0x44/0xa9
RIP: 0033:0x441619
Code: e8 fc ab 02 00 48 83 c4 18 c3 0f 1f 80 00 00 00 00 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 0f 83 1b 09 fc ff c3 66 2e 0f 1f 84 00 00 00 00
RSP: 002b:00007ffc10aa3e28 EFLAGS: 00000246 ORIG_RAX: 00000000000001aa
RAX: ffffffffffffffda RBX: 0000000000000003 RCX: 0000000000441619
RDX: 0000000000000000 RSI: 0000000000004510 RDI: 0000000000000003
RBP: 00000000006cc018 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000246 R12: 00000000004023c0
R13: 0000000000402450 R14: 0000000000000000 R15: 0000000000000000


---
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 syzkaller@xxxxxxxxxxxxxxxx.

syzbot will keep track of this issue. See:
https://goo.gl/tpsmEJ#status for how to communicate with syzbot.
syzbot can test patches for this issue, for details see:
https://goo.gl/tpsmEJ#testing-patches