All of lore.kernel.org
 help / color / mirror / Atom feed
From: syzbot <syzbot+ef4b654b49ed7ff049bf@syzkaller.appspotmail.com>
To: axboe@kernel.dk, bijan.mottahedeh@oracle.com,
	io-uring@vger.kernel.org, linux-fsdevel@vger.kernel.org,
	linux-kernel@vger.kernel.org, syzkaller-bugs@googlegroups.com,
	viro@zeniv.linux.org.uk
Subject: possible deadlock in io_timeout_fn
Date: Mon, 10 Aug 2020 08:37:17 -0700	[thread overview]
Message-ID: <000000000000cb5dff05ac87ba2e@google.com> (raw)

Hello,

syzbot found the following issue on:

HEAD commit:    449dc8c9 Merge tag 'for-v5.9' of git://git.kernel.org/pub/..
git tree:       upstream
console output: https://syzkaller.appspot.com/x/log.txt?x=11293dc6900000
kernel config:  https://syzkaller.appspot.com/x/.config?x=9d25235bf0162fbc
dashboard link: https://syzkaller.appspot.com/bug?extid=ef4b654b49ed7ff049bf
compiler:       clang version 10.0.0 (https://github.com/llvm/llvm-project/ c2443155a0fb245c8f17f2c1c72b6ea391e86e81)
syz repro:      https://syzkaller.appspot.com/x/repro.syz?x=126b0f1a900000
C reproducer:   https://syzkaller.appspot.com/x/repro.c?x=13e32994900000

The issue was bisected to:

commit e62753e4e2926f249d088cc0517be5ed4efec6d6
Author: Bijan Mottahedeh <bijan.mottahedeh@oracle.com>
Date:   Sat May 23 04:31:18 2020 +0000

    io_uring: call statx directly

bisection log:  https://syzkaller.appspot.com/x/bisect.txt?x=1195de52900000
final oops:     https://syzkaller.appspot.com/x/report.txt?x=1395de52900000
console output: https://syzkaller.appspot.com/x/log.txt?x=1595de52900000

IMPORTANT: if you fix the issue, please add the following tag to the commit:
Reported-by: syzbot+ef4b654b49ed7ff049bf@syzkaller.appspotmail.com
Fixes: e62753e4e292 ("io_uring: call statx directly")

========================================================
WARNING: possible irq lock inversion dependency detected
5.8.0-syzkaller #0 Not tainted
--------------------------------------------------------
syz-executor659/6838 just changed the state of lock:
ffff8880a8bc44d8 (&ctx->completion_lock){-...}-{2:2}, at: io_timeout_fn+0x6b/0x360 fs/io_uring.c:4999
but this lock took another, HARDIRQ-unsafe lock in the past:
 (&fs->lock){+.+.}-{2:2}


and interrupts could create inverse lock ordering between them.


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

       CPU0                    CPU1
       ----                    ----
  lock(&fs->lock);
                               local_irq_disable();
                               lock(&ctx->completion_lock);
                               lock(&fs->lock);
  <Interrupt>
    lock(&ctx->completion_lock);

 *** DEADLOCK ***

1 lock held by syz-executor659/6838:
 #0: ffff8880a8bc4428 (&ctx->uring_lock){+.+.}-{3:3}, at: __do_sys_io_uring_enter fs/io_uring.c:8035 [inline]
 #0: ffff8880a8bc4428 (&ctx->uring_lock){+.+.}-{3:3}, at: __se_sys_io_uring_enter+0x19d/0x1300 fs/io_uring.c:7995

the shortest dependencies between 2nd lock and 1st lock:
 -> (&fs->lock){+.+.}-{2:2} {
    HARDIRQ-ON-W at:
                      lock_acquire+0x160/0x730 kernel/locking/lockdep.c:5005
                      __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+0x3b/0x220 fs/fs_struct.c:39
                      init_chdir+0xe2/0x10b fs/init.c:54
                      devtmpfs_setup+0xa5/0xd4 drivers/base/devtmpfs.c:415
                      devtmpfsd+0x11/0x40 drivers/base/devtmpfs.c:430
                      kthread+0x37e/0x3a0 drivers/block/aoe/aoecmd.c:1234
                      ret_from_fork+0x1f/0x30 arch/x86/entry/entry_64.S:294
    SOFTIRQ-ON-W at:
                      lock_acquire+0x160/0x730 kernel/locking/lockdep.c:5005
                      __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+0x3b/0x220 fs/fs_struct.c:39
                      init_chdir+0xe2/0x10b fs/init.c:54
                      devtmpfs_setup+0xa5/0xd4 drivers/base/devtmpfs.c:415
                      devtmpfsd+0x11/0x40 drivers/base/devtmpfs.c:430
                      kthread+0x37e/0x3a0 drivers/block/aoe/aoecmd.c:1234
                      ret_from_fork+0x1f/0x30 arch/x86/entry/entry_64.S:294
    INITIAL USE at:
                     lock_acquire+0x160/0x730 kernel/locking/lockdep.c:5005
                     __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+0x3b/0x220 fs/fs_struct.c:39
                     init_chdir+0xe2/0x10b fs/init.c:54
                     devtmpfs_setup+0xa5/0xd4 drivers/base/devtmpfs.c:415
                     devtmpfsd+0x11/0x40 drivers/base/devtmpfs.c:430
                     kthread+0x37e/0x3a0 drivers/block/aoe/aoecmd.c:1234
                     ret_from_fork+0x1f/0x30 arch/x86/entry/entry_64.S:294
  }
  ... key      at: [<ffffffff8b84e190>] copy_fs_struct.__key+0x0/0x10
  ... acquired at:
   lock_acquire+0x160/0x730 kernel/locking/lockdep.c:5005
   __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:1126 [inline]
   io_dismantle_req+0x285/0x5d0 fs/io_uring.c:1544
   __io_free_req+0x24/0x190 fs/io_uring.c:1562
   __io_double_put_req fs/io_uring.c:1909 [inline]
   __io_fail_links+0x1d7/0x6c0 fs/io_uring.c:1659
   io_fail_links fs/io_uring.c:1675 [inline]
   __io_req_find_next fs/io_uring.c:1698 [inline]
   io_req_find_next+0x101a/0x1260 fs/io_uring.c:1706
   io_steal_work fs/io_uring.c:1897 [inline]
   io_wq_submit_work+0x446/0x590 fs/io_uring.c:5792
   io_worker_handle_work+0xf8f/0x1570 fs/io-wq.c:527
   io_wqe_worker+0x2ff/0x810 fs/io-wq.c:569
   kthread+0x37e/0x3a0 drivers/block/aoe/aoecmd.c:1234
   ret_from_fork+0x1f/0x30 arch/x86/entry/entry_64.S:294

-> (&ctx->completion_lock){-...}-{2:2} {
   IN-HARDIRQ-W at:
                    lock_acquire+0x160/0x730 kernel/locking/lockdep.c:5005
                    __raw_spin_lock_irqsave include/linux/spinlock_api_smp.h:110 [inline]
                    _raw_spin_lock_irqsave+0x9e/0xc0 kernel/locking/spinlock.c:159
                    io_timeout_fn+0x6b/0x360 fs/io_uring.c:4999
                    __run_hrtimer kernel/time/hrtimer.c:1520 [inline]
                    __hrtimer_run_queues+0x47f/0x930 kernel/time/hrtimer.c:1584
                    hrtimer_interrupt+0x373/0xd60 kernel/time/hrtimer.c:1646
                    local_apic_timer_interrupt arch/x86/kernel/apic/apic.c:1079 [inline]
                    __sysvec_apic_timer_interrupt+0xf0/0x260 arch/x86/kernel/apic/apic.c:1096
                    asm_call_on_stack+0xf/0x20 arch/x86/entry/entry_64.S:706
                    __run_on_irqstack arch/x86/include/asm/irq_stack.h:22 [inline]
                    run_on_irqstack_cond arch/x86/include/asm/irq_stack.h:48 [inline]
                    sysvec_apic_timer_interrupt+0x94/0xf0 arch/x86/kernel/apic/apic.c:1090
                    asm_sysvec_apic_timer_interrupt+0x12/0x20 arch/x86/include/asm/idtentry.h:581
                    arch_local_irq_enable arch/x86/include/asm/paravirt.h:780 [inline]
                    __raw_spin_unlock_irq include/linux/spinlock_api_smp.h:168 [inline]
                    _raw_spin_unlock_irq+0x57/0x80 kernel/locking/spinlock.c:199
                    spin_unlock_irq include/linux/spinlock.h:404 [inline]
                    io_timeout fs/io_uring.c:5162 [inline]
                    io_issue_sqe+0x5b64/0xb8c0 fs/io_uring.c:5594
                    __io_queue_sqe+0x287/0xff0 fs/io_uring.c:5981
                    io_submit_sqe fs/io_uring.c:6130 [inline]
                    io_submit_sqes+0x14cf/0x25d0 fs/io_uring.c:6327
                    __do_sys_io_uring_enter fs/io_uring.c:8036 [inline]
                    __se_sys_io_uring_enter+0x1af/0x1300 fs/io_uring.c:7995
                    do_syscall_64+0x31/0x70 arch/x86/entry/common.c:46
                    entry_SYSCALL_64_after_hwframe+0x44/0xa9
   INITIAL USE at:
                   lock_acquire+0x160/0x730 kernel/locking/lockdep.c:5005
                   __raw_spin_lock_irqsave include/linux/spinlock_api_smp.h:110 [inline]
                   _raw_spin_lock_irqsave+0x9e/0xc0 kernel/locking/spinlock.c:159
                   io_cqring_add_event fs/io_uring.c:1419 [inline]
                   __io_req_complete+0x15e/0x2c0 fs/io_uring.c:1458
                   io_issue_sqe+0x8678/0xb8c0 fs/io_uring.c:3569
                   io_wq_submit_work+0x35e/0x590 fs/io_uring.c:5775
                   io_worker_handle_work+0xf8f/0x1570 fs/io-wq.c:527
                   io_wqe_worker+0x2ff/0x810 fs/io-wq.c:569
                   kthread+0x37e/0x3a0 drivers/block/aoe/aoecmd.c:1234
                   ret_from_fork+0x1f/0x30 arch/x86/entry/entry_64.S:294
 }
 ... key      at: [<ffffffff8b84ef58>] io_ring_ctx_alloc.__key.111+0x0/0x10
 ... acquired at:
   mark_lock_irq kernel/locking/lockdep.c:3568 [inline]
   mark_lock+0x529/0x1b00 kernel/locking/lockdep.c:4006
   mark_usage kernel/locking/lockdep.c:3902 [inline]
   __lock_acquire+0xa5c/0x2ab0 kernel/locking/lockdep.c:4380
   lock_acquire+0x160/0x730 kernel/locking/lockdep.c:5005
   __raw_spin_lock_irqsave include/linux/spinlock_api_smp.h:110 [inline]
   _raw_spin_lock_irqsave+0x9e/0xc0 kernel/locking/spinlock.c:159
   io_timeout_fn+0x6b/0x360 fs/io_uring.c:4999
   __run_hrtimer kernel/time/hrtimer.c:1520 [inline]
   __hrtimer_run_queues+0x47f/0x930 kernel/time/hrtimer.c:1584
   hrtimer_interrupt+0x373/0xd60 kernel/time/hrtimer.c:1646
   local_apic_timer_interrupt arch/x86/kernel/apic/apic.c:1079 [inline]
   __sysvec_apic_timer_interrupt+0xf0/0x260 arch/x86/kernel/apic/apic.c:1096
   asm_call_on_stack+0xf/0x20 arch/x86/entry/entry_64.S:706
   __run_on_irqstack arch/x86/include/asm/irq_stack.h:22 [inline]
   run_on_irqstack_cond arch/x86/include/asm/irq_stack.h:48 [inline]
   sysvec_apic_timer_interrupt+0x94/0xf0 arch/x86/kernel/apic/apic.c:1090
   asm_sysvec_apic_timer_interrupt+0x12/0x20 arch/x86/include/asm/idtentry.h:581
   arch_local_irq_enable arch/x86/include/asm/paravirt.h:780 [inline]
   __raw_spin_unlock_irq include/linux/spinlock_api_smp.h:168 [inline]
   _raw_spin_unlock_irq+0x57/0x80 kernel/locking/spinlock.c:199
   spin_unlock_irq include/linux/spinlock.h:404 [inline]
   io_timeout fs/io_uring.c:5162 [inline]
   io_issue_sqe+0x5b64/0xb8c0 fs/io_uring.c:5594
   __io_queue_sqe+0x287/0xff0 fs/io_uring.c:5981
   io_submit_sqe fs/io_uring.c:6130 [inline]
   io_submit_sqes+0x14cf/0x25d0 fs/io_uring.c:6327
   __do_sys_io_uring_enter fs/io_uring.c:8036 [inline]
   __se_sys_io_uring_enter+0x1af/0x1300 fs/io_uring.c:7995
   do_syscall_64+0x31/0x70 arch/x86/entry/common.c:46
   entry_SYSCALL_64_after_hwframe+0x44/0xa9


stack backtrace:
CPU: 1 PID: 6838 Comm: syz-executor659 Not tainted 5.8.0-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:77 [inline]
 dump_stack+0x1f0/0x31e lib/dump_stack.c:118
 print_irq_inversion_bug+0xb67/0xe90 kernel/locking/lockdep.c:3428
 check_usage_forwards+0x13f/0x240 kernel/locking/lockdep.c:3453
 mark_lock_irq kernel/locking/lockdep.c:3568 [inline]
 mark_lock+0x529/0x1b00 kernel/locking/lockdep.c:4006
 mark_usage kernel/locking/lockdep.c:3902 [inline]
 __lock_acquire+0xa5c/0x2ab0 kernel/locking/lockdep.c:4380
 lock_acquire+0x160/0x730 kernel/locking/lockdep.c:5005
 __raw_spin_lock_irqsave include/linux/spinlock_api_smp.h:110 [inline]
 _raw_spin_lock_irqsave+0x9e/0xc0 kernel/locking/spinlock.c:159
 io_timeout_fn+0x6b/0x360 fs/io_uring.c:4999
 __run_hrtimer kernel/time/hrtimer.c:1520 [inline]
 __hrtimer_run_queues+0x47f/0x930 kernel/time/hrtimer.c:1584
 hrtimer_interrupt+0x373/0xd60 kernel/time/hrtimer.c:1646
 local_apic_timer_interrupt arch/x86/kernel/apic/apic.c:1079 [inline]
 __sysvec_apic_timer_interrupt+0xf0/0x260 arch/x86/kernel/apic/apic.c:1096
 asm_call_on_stack+0xf/0x20 arch/x86/entry/entry_64.S:706
 </IRQ>
 __run_on_irqstack arch/x86/include/asm/irq_stack.h:22 [inline]
 run_on_irqstack_cond arch/x86/include/asm/irq_stack.h:48 [inline]
 sysvec_apic_timer_interrupt+0x94/0xf0 arch/x86/kernel/apic/apic.c:1090
 asm_sysvec_apic_timer_interrupt+0x12/0x20 arch/x86/include/asm/idtentry.h:581
RIP: 0010:__raw_spin_unlock_irq include/linux/spinlock_api_smp.h:169 [inline]
RIP: 0010:_raw_spin_unlock_irq+0x57/0x80 kernel/locking/spinlock.c:199
Code: 00 00 00 00 fc ff df 80 3c 08 00 74 0c 48 c7 c7 c8 14 4d 89 e8 6a 28 8b f9 48 83 3d 0a a9 23 01 00 74 25 fb 66 0f 1f 44 00 00 <bf> 01 00 00 00 e8 6f 62 27 f9 65 8b 05 34 92 d8 77 85 c0 74 02 5b
RSP: 0018:ffffc9000102f8f0 EFLAGS: 00000286
RAX: 1ffffffff129a299 RBX: ffff8880a8bc44c0 RCX: dffffc0000000000
RDX: 0000000000000000 RSI: 0000000000000008 RDI: ffffffff88296b8f
RBP: ffffc9000102fb80 R08: dffffc0000000000 R09: fffffbfff167c6b8
R10: fffffbfff167c6b8 R11: 0000000000000000 R12: 0000000000000000
R13: dffffc0000000000 R14: ffff8880a2dfdc08 R15: ffff8880a2dfdc58
 spin_unlock_irq include/linux/spinlock.h:404 [inline]
 io_timeout fs/io_uring.c:5162 [inline]
 io_issue_sqe+0x5b64/0xb8c0 fs/io_uring.c:5594
 __io_queue_sqe+0x287/0xff0 fs/io_uring.c:5981
 io_submit_sqe fs/io_uring.c:6130 [inline]
 io_submit_sqes+0x14cf/0x25d0 fs/io_uring.c:6327
 __do_sys_io_uring_enter fs/io_uring.c:8036 [inline]
 __se_sys_io_uring_enter+0x1af/0x1300 fs/io_uring.c:7995
 do_syscall_64+0x31/0x70 arch/x86/entry/common.c:46
 entry_SYSCALL_64_after_hwframe+0x44/0xa9
RIP: 0033:0x440b99
Code: 18 89 d0 c3 66 2e 0f 1f 84 00 00 00 00 00 0f 1f 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 7b 13 fc ff c3 66 2e 0f 1f 84 00 00 00 00
RSP: 002b:00007ffea6abdbf8 EFLAGS: 00000246 ORIG_RAX: 00000000000001aa
RAX: ffffffffffffffda RBX: 00000000004002c8 RCX: 0000000000440b99
RDX: 0000000000000000 RSI: 000000000000450c RDI: 0000000000000005
RBP: 00000000006cb018 R08


---
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@googlegroups.com.

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

             reply	other threads:[~2020-08-10 15:37 UTC|newest]

Thread overview: 2+ messages / expand[flat|nested]  mbox.gz  Atom feed  top
2020-08-10 15:37 syzbot [this message]
2020-08-10 16:53 ` possible deadlock in io_timeout_fn Jens Axboe

Reply instructions:

You may reply publicly to this message via plain-text email
using any one of the following methods:

* Save the following mbox file, import it into your mail client,
  and reply-to-all from there: mbox

  Avoid top-posting and favor interleaved quoting:
  https://en.wikipedia.org/wiki/Posting_style#Interleaved_style

* Reply using the --to, --cc, and --in-reply-to
  switches of git-send-email(1):

  git send-email \
    --in-reply-to=000000000000cb5dff05ac87ba2e@google.com \
    --to=syzbot+ef4b654b49ed7ff049bf@syzkaller.appspotmail.com \
    --cc=axboe@kernel.dk \
    --cc=bijan.mottahedeh@oracle.com \
    --cc=io-uring@vger.kernel.org \
    --cc=linux-fsdevel@vger.kernel.org \
    --cc=linux-kernel@vger.kernel.org \
    --cc=syzkaller-bugs@googlegroups.com \
    --cc=viro@zeniv.linux.org.uk \
    /path/to/YOUR_REPLY

  https://kernel.org/pub/software/scm/git/docs/git-send-email.html

* If your mail client supports setting the In-Reply-To header
  via mailto: links, try the mailto: link
Be sure your reply has a Subject: header at the top and a blank line before the message body.
This is an external index of several public inboxes,
see mirroring instructions on how to clone and mirror
all data and code used by this external index.