syzbot


INFO: task hung in io_req_caches_free

Status: closed as invalid on 2022/02/08 09:40
Subsystems: fs
[Documentation on labels]
First crash: 889d, last: 872d

Sample crash report:
INFO: task kworker/u4:8:24522 blocked for more than 143 seconds.
      Not tainted 5.16.0-rc3-syzkaller #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
task:kworker/u4:8    state:D stack:24880 pid:24522 ppid:     2 flags:0x00004000
Workqueue: events_unbound io_ring_exit_work
Call Trace:
 <TASK>
 context_switch kernel/sched/core.c:4972 [inline]
 __schedule+0xa9a/0x4940 kernel/sched/core.c:6253
 schedule+0xd2/0x260 kernel/sched/core.c:6326
 schedule_preempt_disabled+0xf/0x20 kernel/sched/core.c:6385
 __mutex_lock_common kernel/locking/mutex.c:680 [inline]
 __mutex_lock+0xa32/0x12f0 kernel/locking/mutex.c:740
 io_req_caches_free+0x28/0x1e6 fs/io_uring.c:9311
 io_ring_exit_work+0x1e4/0xbd0 fs/io_uring.c:9496
 process_one_work+0x9b2/0x1690 kernel/workqueue.c:2298
 worker_thread+0x658/0x11f0 kernel/workqueue.c:2445
 kthread+0x405/0x4f0 kernel/kthread.c:327
 ret_from_fork+0x1f/0x30 arch/x86/entry/entry_64.S:295
 </TASK>

Showing all locks held in the system:
2 locks held by kworker/u4:1/10:
 #0: ffff8880b9d39a98 (&rq->__lock){-.-.}-{2:2}, at: raw_spin_rq_lock_nested+0x2b/0x120 kernel/sched/core.c:478
 #1: ffff8880b9d279c8 (&per_cpu_ptr(group->pcpu, cpu)->seq){-.-.}-{0:0}, at: psi_task_switch+0x3a6/0x490 kernel/sched/psi.c:880
1 lock held by khungtaskd/27:
 #0: ffffffff8bb83b60 (rcu_read_lock){....}-{1:2}, at: debug_show_all_locks+0x53/0x260 kernel/locking/lockdep.c:6458
1 lock held by in:imklog/6212:
 #0: ffff888019d9ad70 (&f->f_pos_lock){+.+.}-{3:3}, at: __fdget_pos+0xe9/0x100 fs/file.c:994
3 locks held by kworker/u4:8/24522:
 #0: ffff888010c69138 ((wq_completion)events_unbound){+.+.}-{0:0}, at: arch_atomic64_set arch/x86/include/asm/atomic64_64.h:34 [inline]
 #0: ffff888010c69138 ((wq_completion)events_unbound){+.+.}-{0:0}, at: arch_atomic_long_set include/linux/atomic/atomic-long.h:41 [inline]
 #0: ffff888010c69138 ((wq_completion)events_unbound){+.+.}-{0:0}, at: atomic_long_set include/linux/atomic/atomic-instrumented.h:1198 [inline]
 #0: ffff888010c69138 ((wq_completion)events_unbound){+.+.}-{0:0}, at: set_work_data kernel/workqueue.c:635 [inline]
 #0: ffff888010c69138 ((wq_completion)events_unbound){+.+.}-{0:0}, at: set_work_pool_and_clear_pending kernel/workqueue.c:662 [inline]
 #0: ffff888010c69138 ((wq_completion)events_unbound){+.+.}-{0:0}, at: process_one_work+0x896/0x1690 kernel/workqueue.c:2269
 #1: ffffc900039c7db0 ((work_completion)(&ctx->exit_work)){+.+.}-{0:0}, at: process_one_work+0x8ca/0x1690 kernel/workqueue.c:2273
 #2: ffff888142fa10a8 (&ctx->uring_lock){+.+.}-{3:3}, at: io_req_caches_free+0x28/0x1e6 fs/io_uring.c:9311
2 locks held by syz-executor.0/8752:

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

NMI backtrace for cpu 0
CPU: 0 PID: 27 Comm: khungtaskd Not tainted 5.16.0-rc3-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: 917 Comm: kworker/1:2 Not tainted 5.16.0-rc3-syzkaller #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011
Workqueue: events nsim_dev_trap_report_work
RIP: 0010:check_kcov_mode kernel/kcov.c:166 [inline]
RIP: 0010:__sanitizer_cov_trace_pc+0x7/0x60 kernel/kcov.c:200
Code: 46 00 5d be 03 00 00 00 e9 36 1c 63 02 66 0f 1f 44 00 00 48 8b be b0 01 00 00 e8 b4 ff ff ff 31 c0 c3 90 65 8b 05 39 c5 8a 7e <89> c1 48 8b 34 24 81 e1 00 01 00 00 65 48 8b 14 25 40 70 02 00 a9
RSP: 0018:ffffc900049af8c0 EFLAGS: 00000287
RAX: 0000000080000001 RBX: ffffffff9052b060 RCX: ffff88823bddaf00
RDX: 0000000000000000 RSI: ffff88801b399d00 RDI: 0000000000000003
RBP: ffff88823bdda000 R08: ffff88823bddac81 R09: 0000000000000030
R10: ffffffff81bea644 R11: 000000000000003f R12: dffffc0000000000
R13: ffff88823bddaf00 R14: ffff88823bddac81 R15: ffff88823bddaf00
FS:  0000000000000000(0000) GS:ffff8880b9d00000(0000) knlGS:0000000000000000
CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
CR2: 00007f4ba240d000 CR3: 000000000b88e000 CR4: 0000000000350ee0
Call Trace:
 <TASK>
 for_each_canary mm/kfence/core.c:346 [inline]
 kfence_guarded_alloc mm/kfence/core.c:436 [inline]
 __kfence_alloc+0xdb5/0x13a0 mm/kfence/core.c:908
 kfence_alloc include/linux/kfence.h:126 [inline]
 slab_alloc_node mm/slub.c:3152 [inline]
 kmem_cache_alloc_node+0x3cc/0x3f0 mm/slub.c:3270
 __alloc_skb+0x215/0x340 net/core/skbuff.c:414
 alloc_skb include/linux/skbuff.h:1126 [inline]
 nsim_dev_trap_skb_build drivers/net/netdevsim/dev.c:745 [inline]
 nsim_dev_trap_report drivers/net/netdevsim/dev.c:802 [inline]
 nsim_dev_trap_report_work+0x29a/0xbc0 drivers/net/netdevsim/dev.c:843
 process_one_work+0x9b2/0x1690 kernel/workqueue.c:2298
 worker_thread+0x658/0x11f0 kernel/workqueue.c:2445
 kthread+0x405/0x4f0 kernel/kthread.c:327
 ret_from_fork+0x1f/0x30 arch/x86/entry/entry_64.S:295
 </TASK>
----------------
Code disassembly (best guess):
   0:	46 00 5d be          	rex.RX add %r11b,-0x42(%rbp)
   4:	03 00                	add    (%rax),%eax
   6:	00 00                	add    %al,(%rax)
   8:	e9 36 1c 63 02       	jmpq   0x2631c43
   d:	66 0f 1f 44 00 00    	nopw   0x0(%rax,%rax,1)
  13:	48 8b be b0 01 00 00 	mov    0x1b0(%rsi),%rdi
  1a:	e8 b4 ff ff ff       	callq  0xffffffd3
  1f:	31 c0                	xor    %eax,%eax
  21:	c3                   	retq
  22:	90                   	nop
  23:	65 8b 05 39 c5 8a 7e 	mov    %gs:0x7e8ac539(%rip),%eax        # 0x7e8ac563
* 2a:	89 c1                	mov    %eax,%ecx <-- trapping instruction
  2c:	48 8b 34 24          	mov    (%rsp),%rsi
  30:	81 e1 00 01 00 00    	and    $0x100,%ecx
  36:	65 48 8b 14 25 40 70 	mov    %gs:0x27040,%rdx
  3d:	02 00
  3f:	a9                   	.byte 0xa9

Crashes (2):
Time Kernel Commit Syzkaller Config Log Report Syz repro C repro VM info Assets (help?) Manager Title
2021/12/04 15:06 upstream 12119cfa1052 a617004c .config console log report info ci-upstream-kasan-gce-root INFO: task hung in io_req_caches_free
2021/11/18 01:47 linux-next fd96a4057bd0 cafff8b6 .config console log report info ci-upstream-linux-next-kasan-gce-root INFO: task hung in io_req_caches_free
* Struck through repros no longer work on HEAD.