syzbot


INFO: task hung in io_req_task_submit

Status: closed as invalid on 2022/02/08 09:50
Reported-by: syzbot+@syzkaller.appspotmail.com
First crash: 320d, last: 320d

Sample crash report:
INFO: task syz-executor.4:30442 blocked for more than 143 seconds.
      Not tainted 5.16.0-syzkaller #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
task:syz-executor.4  state:D stack:26008 pid:30442 ppid:  7838 flags:0x00004004
Call Trace:
 <TASK>
 context_switch kernel/sched/core.c:4986 [inline]
 __schedule+0xab2/0x4f00 kernel/sched/core.c:6296
 schedule+0xd2/0x260 kernel/sched/core.c:6369
 schedule_preempt_disabled+0xf/0x20 kernel/sched/core.c:6428
 __mutex_lock_common kernel/locking/mutex.c:673 [inline]
 __mutex_lock+0xa32/0x12f0 kernel/locking/mutex.c:733
 io_tw_lock fs/io_uring.c:1165 [inline]
 io_req_task_submit+0x191/0x530 fs/io_uring.c:2444
 handle_tw_list fs/io_uring.c:2334 [inline]
 tctx_task_work+0x19a/0xee0 fs/io_uring.c:2368
 task_work_run+0xdd/0x1a0 kernel/task_work.c:164
 tracehook_notify_signal include/linux/tracehook.h:213 [inline]
 handle_signal_work kernel/entry/common.c:146 [inline]
 exit_to_user_mode_loop kernel/entry/common.c:172 [inline]
 exit_to_user_mode_prepare+0x256/0x290 kernel/entry/common.c:207
 __syscall_exit_to_user_mode_work kernel/entry/common.c:289 [inline]
 syscall_exit_to_user_mode+0x19/0x60 kernel/entry/common.c:300
 do_syscall_64+0x42/0xb0 arch/x86/entry/common.c:86
 entry_SYSCALL_64_after_hwframe+0x44/0xae
RIP: 0033:0x7f2407179fe9
RSP: 002b:00007f2405ace168 EFLAGS: 00000246 ORIG_RAX: 00000000000001aa
RAX: 00000000000002ff RBX: 00007f240728d030 RCX: 00007f2407179fe9
RDX: 0000000000000000 RSI: 00000000000002ff RDI: 0000000000000004
RBP: 00007f24071d408d R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000005 R11: 0000000000000246 R12: 0000000000000000
R13: 00007f24077c0b1f R14: 00007f2405ace300 R15: 0000000000022000
 </TASK>

Showing all locks held in the system:
1 lock held by khungtaskd/27:
 #0: ffffffff8bb85320 (rcu_read_lock){....}-{1:2}, at: debug_show_all_locks+0x53/0x260 kernel/locking/lockdep.c:6460
2 locks held by getty/3285:
 #0: ffff88814b00d098 (&tty->ldisc_sem){++++}-{0:0}, at: tty_ldisc_ref_wait+0x22/0x80 drivers/tty/tty_ldisc.c:244
 #1: ffffc90002b562e8 (&ldata->atomic_read_lock){+.+.}-{3:3}, at: n_tty_read+0xcf0/0x1230 drivers/tty/n_tty.c:2077
3 locks held by kworker/u4:9/28802:
2 locks held by syz-executor.4/30440:
1 lock held by syz-executor.4/30442:
 #0: ffff88804169d0a8 (&ctx->uring_lock){+.+.}-{3:3}, at: io_tw_lock fs/io_uring.c:1165 [inline]
 #0: ffff88804169d0a8 (&ctx->uring_lock){+.+.}-{3:3}, at: io_req_task_submit+0x191/0x530 fs/io_uring.c:2444

=============================================

NMI backtrace for cpu 1
CPU: 1 PID: 27 Comm: khungtaskd Not tainted 5.16.0-syzkaller #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011
Call Trace:
 <TASK>
 __dump_stack lib/dump_stack.c:88 [inline]
 dump_stack_lvl+0xcd/0x134 lib/dump_stack.c:106
 nmi_cpu_backtrace.cold+0x47/0x144 lib/nmi_backtrace.c:111
 nmi_trigger_cpumask_backtrace+0x1b3/0x230 lib/nmi_backtrace.c:62
 trigger_all_cpu_backtrace include/linux/nmi.h:146 [inline]
 check_hung_uninterruptible_tasks kernel/hung_task.c:210 [inline]
 watchdog+0xc1d/0xf50 kernel/hung_task.c:295
 kthread+0x2e9/0x3a0 kernel/kthread.c:359
 ret_from_fork+0x1f/0x30 arch/x86/entry/entry_64.S:295
 </TASK>
Sending NMI from CPU 1 to CPUs 0:
NMI backtrace for cpu 0
CPU: 0 PID: 30440 Comm: syz-executor.4 Not tainted 5.16.0-syzkaller #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011
RIP: 0010:kasan_check_range+0x12b/0x180 mm/kasan/generic.c:190
Code: 3a 00 74 ef 49 8d 04 2c 48 85 d2 75 0b 48 89 da 48 29 c2 e9 55 ff ff ff 49 39 d2 75 17 49 0f be 02 41 83 e1 07 49 39 c1 7d 0a <5b> b8 01 00 00 00 5d 41 5c c3 44 89 c2 e8 a3 ef ff ff 5b 83 f0 01
RSP: 0018:ffffc90000007998 EFLAGS: 00000046
RAX: fffffbfff1ff9149 RBX: fffffbfff1ff9149 RCX: ffffffff815cef6e
RDX: fffffbfff1ff9149 RSI: 0000000000000008 RDI: ffffffff8ffc8a40
RBP: fffffbfff1ff9148 R08: 0000000000000000 R09: ffffffff8ffc8a47
R10: fffffbfff1ff9148 R11: 0000000000000001 R12: ffff8880181e0ab0
R13: ffff8880181e0000 R14: ffffffff8d9493e8 R15: 0000000000000001
FS:  00007f2405aef700(0000) GS:ffff8880b9c00000(0000) knlGS:0000000000000000
CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
CR2: 000000c00a924ec8 CR3: 0000000077cbd000 CR4: 00000000003526f0
DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
Call Trace:
 <IRQ>
 instrument_atomic_read include/linux/instrumented.h:71 [inline]
 test_bit include/asm-generic/bitops/instrumented-non-atomic.h:134 [inline]
 hlock_class kernel/locking/lockdep.c:199 [inline]
 __lock_acquire+0x143e/0x5470 kernel/locking/lockdep.c:5023
 lock_acquire kernel/locking/lockdep.c:5639 [inline]
 lock_acquire+0x1ab/0x510 kernel/locking/lockdep.c:5604
 seqcount_lockdep_reader_access include/linux/seqlock.h:103 [inline]
 timekeeping_get_delta kernel/time/timekeeping.c:252 [inline]
 timekeeping_get_ns kernel/time/timekeeping.c:386 [inline]
 ktime_get+0x147/0x470 kernel/time/timekeeping.c:829
 hrtimer_forward_now include/linux/hrtimer.h:506 [inline]
 perf_swevent_hrtimer+0x246/0x3f0 kernel/events/core.c:10626
 __run_hrtimer kernel/time/hrtimer.c:1685 [inline]
 __hrtimer_run_queues+0x1c0/0xe50 kernel/time/hrtimer.c:1749
 hrtimer_interrupt+0x31c/0x790 kernel/time/hrtimer.c:1811
 local_apic_timer_interrupt arch/x86/kernel/apic/apic.c:1086 [inline]
 __sysvec_apic_timer_interrupt+0x146/0x530 arch/x86/kernel/apic/apic.c:1103
 sysvec_apic_timer_interrupt+0x8e/0xc0 arch/x86/kernel/apic/apic.c:1097
 </IRQ>
 <TASK>
 asm_sysvec_apic_timer_interrupt+0x12/0x20 arch/x86/include/asm/idtentry.h:638
RIP: 0010:preempt_count arch/x86/include/asm/preempt.h:27 [inline]
RIP: 0010:interrupt_context_level include/linux/preempt.h:91 [inline]
RIP: 0010:get_recursion_context kernel/events/internal.h:208 [inline]
RIP: 0010:perf_swevent_get_recursion_context+0x64/0x140 kernel/events/core.c:9457
Code: c1 ea 03 80 3c 02 00 0f 85 d4 00 00 00 48 03 1c ed a0 08 59 8b 31 ff 65 8b 2d c8 c5 6b 7e 41 89 ee 41 89 ed 81 e5 00 01 ff 00 <41> 81 e6 00 00 f0 00 41 81 e5 00 00 ff 00 4c 8d a3 9c 00 00 00 44
RSP: 0018:ffffc9000b667958 EFLAGS: 00000246
RAX: dffffc0000000000 RBX: ffff8880b9c348c0 RCX: 0000000000000000
RDX: 1ffffffff16b2114 RSI: 0000000000000001 RDI: 0000000000000000
RBP: 0000000000000000 R08: 0000000000002000 R09: 0000000000000000
R10: ffffffff81802f12 R11: 0000000000000000 R12: ffffc9000b667a28
R13: 0000000080000001 R14: 0000000080000001 R15: ffffc9000b667a78
 perf_trace_buf_alloc+0x38/0x260 kernel/trace/trace_event_perf.c:407
 perf_trace_lock_acquire+0x180/0x550 include/trace/events/lock.h:13
 trace_lock_acquire include/trace/events/lock.h:13 [inline]
 lock_acquire+0x416/0x510 kernel/locking/lockdep.c:5610
 rcu_lock_acquire include/linux/rcupdate.h:268 [inline]
 rcu_read_lock include/linux/rcupdate.h:694 [inline]
 percpu_ref_tryget_many include/linux/percpu-refcount.h:241 [inline]
 percpu_ref_tryget include/linux/percpu-refcount.h:266 [inline]
 obj_cgroup_tryget include/linux/memcontrol.h:774 [inline]
 get_obj_cgroup_from_current+0x168/0x530 mm/memcontrol.c:2930
 memcg_slab_pre_alloc_hook mm/slab.h:486 [inline]
 slab_pre_alloc_hook mm/slab.h:710 [inline]
 slab_alloc_node mm/slub.c:3144 [inline]
 slab_alloc mm/slub.c:3238 [inline]
 kmem_cache_alloc_trace+0x6e/0x2c0 mm/slub.c:3255
 kmalloc include/linux/slab.h:581 [inline]
 io_add_buffers fs/io_uring.c:4561 [inline]
 io_provide_buffers fs/io_uring.c:4595 [inline]
 io_issue_sqe+0x20f4/0x72e0 fs/io_uring.c:6787
 __io_queue_sqe fs/io_uring.c:7057 [inline]
 io_req_task_submit+0xce/0x530 fs/io_uring.c:2447
 handle_tw_list fs/io_uring.c:2334 [inline]
 tctx_task_work+0x19a/0xee0 fs/io_uring.c:2368
 task_work_run+0xdd/0x1a0 kernel/task_work.c:164
 tracehook_notify_signal include/linux/tracehook.h:213 [inline]
 handle_signal_work kernel/entry/common.c:146 [inline]
 exit_to_user_mode_loop kernel/entry/common.c:172 [inline]
 exit_to_user_mode_prepare+0x256/0x290 kernel/entry/common.c:207
 __syscall_exit_to_user_mode_work kernel/entry/common.c:289 [inline]
 syscall_exit_to_user_mode+0x19/0x60 kernel/entry/common.c:300
 do_syscall_64+0x42/0xb0 arch/x86/entry/common.c:86
 entry_SYSCALL_64_after_hwframe+0x44/0xae
RIP: 0033:0x7f2407179fe9
Code: ff ff c3 66 2e 0f 1f 84 00 00 00 00 00 0f 1f 40 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 73 01 c3 48 c7 c1 bc ff ff ff f7 d8 64 89 01 48
RSP: 002b:00007f2405aef168 EFLAGS: 00000246 ORIG_RAX: 00000000000001aa
RAX: 00000000000002ff RBX: 00007f240728cf60 RCX: 00007f2407179fe9
RDX: 0000000000000000 RSI: 00000000000002ff RDI: 0000000000000004
RBP: 00007f24071d408d R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000005 R11: 0000000000000246 R12: 0000000000000000
R13: 00007f24077c0b1f R14: 00007f2405aef300 R15: 0000000000022000
 </TASK>
----------------
Code disassembly (best guess):
   0:	3a 00                	cmp    (%rax),%al
   2:	74 ef                	je     0xfffffff3
   4:	49 8d 04 2c          	lea    (%r12,%rbp,1),%rax
   8:	48 85 d2             	test   %rdx,%rdx
   b:	75 0b                	jne    0x18
   d:	48 89 da             	mov    %rbx,%rdx
  10:	48 29 c2             	sub    %rax,%rdx
  13:	e9 55 ff ff ff       	jmpq   0xffffff6d
  18:	49 39 d2             	cmp    %rdx,%r10
  1b:	75 17                	jne    0x34
  1d:	49 0f be 02          	movsbq (%r10),%rax
  21:	41 83 e1 07          	and    $0x7,%r9d
  25:	49 39 c1             	cmp    %rax,%r9
  28:	7d 0a                	jge    0x34
* 2a:	5b                   	pop    %rbx <-- trapping instruction
  2b:	b8 01 00 00 00       	mov    $0x1,%eax
  30:	5d                   	pop    %rbp
  31:	41 5c                	pop    %r12
  33:	c3                   	retq
  34:	44 89 c2             	mov    %r8d,%edx
  37:	e8 a3 ef ff ff       	callq  0xffffefdf
  3c:	5b                   	pop    %rbx
  3d:	83 f0 01             	xor    $0x1,%eax

Crashes (1):
Manager Time Kernel Commit Syzkaller Config Log Report Syz repro C repro VM info Title
ci-upstream-kasan-gce 2022/01/19 17:38 upstream e9f5cbc0c851 0620189b .config log report info INFO: task hung in io_req_task_submit
* Struck through repros no longer work on HEAD.