syzbot


INFO: task hung in io_uring_alloc_task_context

Status: closed as invalid on 2022/02/08 09:40
Reported-by: syzbot+@syzkaller.appspotmail.com
First crash: 381d, last: 321d
similar bugs (2):
Kernel Title Repro Cause bisect Fix bisect Count Last Reported Patched Status
upstream INFO: task hung in io_uring_alloc_task_context (2) 1 267d 267d 0/24 auto-closed as invalid on 2022/06/09 11:30
upstream INFO: task hung in io_uring_alloc_task_context (3) 1 161d 161d 0/24 auto-closed as invalid on 2022/09/22 17:27

Sample crash report:
INFO: task syz-executor.5:20129 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.5  state:D stack:29664 pid:20129 ppid:  6206 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_init_wq_offload fs/io_uring.c:8662 [inline]
 io_uring_alloc_task_context+0xf9/0x544 fs/io_uring.c:8703
 __io_uring_add_tctx_node.cold+0x19/0x188 fs/io_uring.c:9756
 io_uring_add_tctx_node fs/io_uring.c:9801 [inline]
 __do_sys_io_uring_enter+0x19db/0x1f50 fs/io_uring.c:10104
 do_syscall_x64 arch/x86/entry/common.c:50 [inline]
 do_syscall_64+0x35/0xb0 arch/x86/entry/common.c:80
 entry_SYSCALL_64_after_hwframe+0x44/0xae
RIP: 0033:0x7f2d7f6f3fe9
RSP: 002b:00007f2d7e048168 EFLAGS: 00000246 ORIG_RAX: 00000000000001aa
RAX: ffffffffffffffda RBX: 00007f2d7f807030 RCX: 00007f2d7f6f3fe9
RDX: 0000000000000000 RSI: 00000000000002ff RDI: 0000000000000003
RBP: 00007f2d7f74e08d R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000246 R12: 0000000000000000
R13: 00007ffd5814caef R14: 00007f2d7e048300 R15: 0000000000022000
 </TASK>

Showing all locks held in the system:
1 lock held by khungtaskd/27:
 #0: ffffffff8bb829a0 (rcu_read_lock){....}-{1:2}, at: debug_show_all_locks+0x53/0x260 kernel/locking/lockdep.c:6460
2 locks held by getty/3290:
 #0: ffff88814af50098 (&tty->ldisc_sem){++++}-{0:0}, at: tty_ldisc_ref_wait+0x22/0x80 drivers/tty/tty_ldisc.c:244
 #1: ffffc90002b8e2e8 (&ldata->atomic_read_lock){+.+.}-{3:3}, at: n_tty_read+0xcf0/0x1230 drivers/tty/n_tty.c:2077
5 locks held by syz-executor.5/20124:
1 lock held by syz-executor.5/20129:
 #0: ffff88807df240a8 (&ctx->uring_lock){+.+.}-{3:3}, at: io_init_wq_offload fs/io_uring.c:8662 [inline]
 #0: ffff88807df240a8 (&ctx->uring_lock){+.+.}-{3:3}, at: io_uring_alloc_task_context+0xf9/0x544 fs/io_uring.c:8703

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

NMI backtrace for cpu 0
CPU: 0 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+0x405/0x4f0 kernel/kthread.c:327
 ret_from_fork+0x1f/0x30 arch/x86/entry/entry_64.S:295
 </TASK>
Sending NMI from CPU 0 to CPUs 1:
NMI backtrace for cpu 1
CPU: 1 PID: 20124 Comm: syz-executor.5 Not tainted 5.16.0-syzkaller #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011
RIP: 0010:check_preemption_disabled+0x4/0x170 lib/smp_processor_id.c:13
Code: 00 00 e8 1f a0 51 f8 65 48 8b 3c 25 00 70 02 00 e8 51 ef 07 f8 eb 99 0f 1f 44 00 00 0f 0b e9 23 ff ff ff cc cc cc 41 56 41 55 <49> 89 f5 41 54 55 48 89 fd 53 0f 1f 44 00 00 65 44 8b 25 ad 06 b8
RSP: 0018:ffffc90002c06e60 EFLAGS: 00000046
RAX: 0000000000000000 RBX: 0000000000000003 RCX: 0000000000000001
RDX: 0000000000000000 RSI: ffffffff89abfe20 RDI: ffffffff8a0521a0
RBP: ffffffff8bb828e0 R08: 0000000000000000 R09: ffffffff8d934dd7
R10: fffffbfff1b269ba R11: 0000000000000001 R12: ffff888035d821c0
R13: 0000000000000000 R14: 00000000ffffffff R15: ffff888035d82c70
FS:  00007f2d7e069700(0000) GS:ffff8880b9d00000(0000) knlGS:0000000000000000
CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
CR2: 000000c00d69a678 CR3: 000000005168b000 CR4: 00000000003506e0
DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
Call Trace:
 <TASK>
 lockdep_recursion_finish kernel/locking/lockdep.c:438 [inline]
 lock_is_held_type+0xd7/0x140 kernel/locking/lockdep.c:5683
 lock_is_held include/linux/lockdep.h:283 [inline]
 rcu_read_lock_sched_held+0x3a/0x70 kernel/rcu/update.c:125
 trace_lock_release include/trace/events/lock.h:58 [inline]
 lock_release+0x522/0x720 kernel/locking/lockdep.c:5650
 seqcount_lockdep_reader_access include/linux/seqlock.h:104 [inline]
 read_seqbegin include/linux/seqlock.h:840 [inline]
 zone_span_seqbegin include/linux/memory_hotplug.h:83 [inline]
 page_outside_zone_boundaries mm/page_alloc.c:580 [inline]
 bad_range+0x251/0x330 mm/page_alloc.c:607
 rmqueue mm/page_alloc.c:3728 [inline]
 get_page_from_freelist+0xa51/0x2f50 mm/page_alloc.c:4146
 __alloc_pages+0x1b2/0x500 mm/page_alloc.c:5369
 alloc_pages+0x1a7/0x300 mm/mempolicy.c:2190
 __get_free_pages+0x8/0x40 mm/page_alloc.c:5418
 kasan_populate_vmalloc_pte mm/kasan/shadow.c:271 [inline]
 kasan_populate_vmalloc_pte+0x25/0x160 mm/kasan/shadow.c:262
 apply_to_pte_range mm/memory.c:2540 [inline]
 apply_to_pmd_range mm/memory.c:2584 [inline]
 apply_to_pud_range mm/memory.c:2620 [inline]
 apply_to_p4d_range mm/memory.c:2656 [inline]
 __apply_to_page_range+0x686/0x1030 mm/memory.c:2690
 alloc_vmap_area+0xa7a/0x1dc0 mm/vmalloc.c:1569
 __get_vm_area_node.constprop.0+0x128/0x380 mm/vmalloc.c:2434
 __vmalloc_node_range+0x12c/0xab0 mm/vmalloc.c:3055
 vmalloc_user+0x67/0x80 mm/vmalloc.c:3200
 vb2_vmalloc_alloc+0x124/0x400 drivers/media/common/videobuf2/videobuf2-vmalloc.c:47
 __vb2_buf_mem_alloc drivers/media/common/videobuf2/videobuf2-core.c:233 [inline]
 __vb2_queue_alloc+0x60b/0x1180 drivers/media/common/videobuf2/videobuf2-core.c:444
 vb2_core_reqbufs+0x7e5/0xd70 drivers/media/common/videobuf2/videobuf2-core.c:838
 __vb2_init_fileio+0x33d/0xd00 drivers/media/common/videobuf2/videobuf2-core.c:2636
 vb2_core_poll+0x498/0x770 drivers/media/common/videobuf2/videobuf2-core.c:2465
 vb2_poll+0x31/0x160 drivers/media/common/videobuf2/videobuf2-v4l2.c:958
 vb2_fop_poll+0x10e/0x360 drivers/media/common/videobuf2/videobuf2-v4l2.c:1211
 v4l2_poll+0x158/0x220 drivers/media/v4l2-core/v4l2-dev.c:348
 vfs_poll include/linux/poll.h:90 [inline]
 __io_arm_poll_handler+0x397/0x9e0 fs/io_uring.c:5719
 io_arm_poll_handler+0x2f3/0x760 fs/io_uring.c:5803
 io_queue_sqe_arm_apoll+0x61/0x1a0 fs/io_uring.c:7034
 __io_queue_sqe fs/io_uring.c:7072 [inline]
 io_queue_sqe fs/io_uring.c:7099 [inline]
 io_submit_sqe fs/io_uring.c:7307 [inline]
 io_submit_sqes+0x7bf2/0x8f20 fs/io_uring.c:7413
 __do_sys_io_uring_enter+0xf6e/0x1f50 fs/io_uring.c:10108
 do_syscall_x64 arch/x86/entry/common.c:50 [inline]
 do_syscall_64+0x35/0xb0 arch/x86/entry/common.c:80
 entry_SYSCALL_64_after_hwframe+0x44/0xae
RIP: 0033:0x7f2d7f6f3fe9
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:00007f2d7e069168 EFLAGS: 00000246 ORIG_RAX: 00000000000001aa
RAX: ffffffffffffffda RBX: 00007f2d7f806f60 RCX: 00007f2d7f6f3fe9
RDX: 000000000000ddc1 RSI: 0000000000006a23 RDI: 0000000000000003
RBP: 00007f2d7f74e08d R08: 0000000020000040 R09: 0000000000000008
R10: 0000000000000002 R11: 0000000000000246 R12: 0000000000000000
R13: 00007ffd5814caef R14: 00007f2d7e069300 R15: 0000000000022000
 </TASK>
----------------
Code disassembly (best guess):
   0:	00 00                	add    %al,(%rax)
   2:	e8 1f a0 51 f8       	callq  0xf851a026
   7:	65 48 8b 3c 25 00 70 	mov    %gs:0x27000,%rdi
   e:	02 00
  10:	e8 51 ef 07 f8       	callq  0xf807ef66
  15:	eb 99                	jmp    0xffffffb0
  17:	0f 1f 44 00 00       	nopl   0x0(%rax,%rax,1)
  1c:	0f 0b                	ud2
  1e:	e9 23 ff ff ff       	jmpq   0xffffff46
  23:	cc                   	int3
  24:	cc                   	int3
  25:	cc                   	int3
  26:	41 56                	push   %r14
  28:	41 55                	push   %r13
* 2a:	49 89 f5             	mov    %rsi,%r13 <-- trapping instruction
  2d:	41 54                	push   %r12
  2f:	55                   	push   %rbp
  30:	48 89 fd             	mov    %rdi,%rbp
  33:	53                   	push   %rbx
  34:	0f 1f 44 00 00       	nopl   0x0(%rax,%rax,1)
  39:	65                   	gs
  3a:	44                   	rex.R
  3b:	8b                   	.byte 0x8b
  3c:	25                   	.byte 0x25
  3d:	ad                   	lods   %ds:(%rsi),%eax
  3e:	06                   	(bad)
  3f:	b8                   	.byte 0xb8

Crashes (4):
Manager Time Kernel Commit Syzkaller Config Log Report Syz repro C repro VM info Title
ci-upstream-kasan-gce-selinux-root 2022/01/16 03:36 upstream a33f5c380c4b 723cfaf0 .config log report info INFO: task hung in io_uring_alloc_task_context
ci-upstream-kasan-gce 2022/01/11 06:53 upstream 133d9c53c9dc ddb0ab8c .config log report info INFO: task hung in io_uring_alloc_task_context
ci-upstream-kasan-gce-root 2021/11/18 01:13 upstream ee1703cda8dc cafff8b6 .config log report info INFO: task hung in io_uring_alloc_task_context
ci-upstream-kasan-gce 2021/11/17 12:30 upstream 8ab774587903 cafff8b6 .config log report info INFO: task hung in io_uring_alloc_task_context
* Struck through repros no longer work on HEAD.