Re: [syzbot] INFO: task hung in io_wq_put_and_exit

[Pavel Begunkov]

On 9/9/21 1:09 AM, syzbot wrote:
> Hello,
> 
> syzbot found the following issue on:
> 
> HEAD commit:    4b93c544e90e thunderbolt: test: split up test cases in tb_..
> git tree:       upstream
> console output: https://syzkaller.appspot.com/x/log.txt?x=111b2c2b300000
> kernel config:  https://syzkaller.appspot.com/x/.config?x=ac2f9cc43f6b17e4
> dashboard link: https://syzkaller.appspot.com/bug?extid=f62d3e0a4ea4f38f5326
> compiler:       gcc (Debian 10.2.1-6) 10.2.1 20210110, GNU ld (GNU Binutils for Debian) 2.35.1
> syz repro:      https://syzkaller.appspot.com/x/repro.syz?x=1152501b300000
> C reproducer:   https://syzkaller.appspot.com/x/repro.c?x=16612dcd300000
> 
> IMPORTANT: if you fix the issue, please add the following tag to the commit:
> Reported-by: syzbot+f62d3e0a4ea4f38f5326@xxxxxxxxxxxxxxxxxxxxxxxxx

Let's check if it's related to recent changes for worker creation
and signalling

#syz test: https://github.com/isilence/linux.git syztest_iowq_workers

> 
> INFO: task syz-executor687:8514 blocked for more than 143 seconds.
>       Not tainted 5.14.0-syzkaller #0
> "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
> task:syz-executor687 state:D stack:27296 pid: 8514 ppid:  8479 flags:0x00024004
> Call Trace:
>  context_switch kernel/sched/core.c:4940 [inline]
>  __schedule+0x940/0x26f0 kernel/sched/core.c:6287
>  schedule+0xd3/0x270 kernel/sched/core.c:6366
>  schedule_timeout+0x1db/0x2a0 kernel/time/timer.c:1857
>  do_wait_for_common kernel/sched/completion.c:85 [inline]
>  __wait_for_common kernel/sched/completion.c:106 [inline]
>  wait_for_common kernel/sched/completion.c:117 [inline]
>  wait_for_completion+0x176/0x280 kernel/sched/completion.c:138
>  io_wq_exit_workers fs/io-wq.c:1162 [inline]
>  io_wq_put_and_exit+0x40c/0xc70 fs/io-wq.c:1197
>  io_uring_clean_tctx fs/io_uring.c:9607 [inline]
>  io_uring_cancel_generic+0x5fe/0x740 fs/io_uring.c:9687
>  io_uring_files_cancel include/linux/io_uring.h:16 [inline]
>  do_exit+0x265/0x2a30 kernel/exit.c:780
>  do_group_exit+0x125/0x310 kernel/exit.c:922
>  get_signal+0x47f/0x2160 kernel/signal.c:2868
>  arch_do_signal_or_restart+0x2a9/0x1c40 arch/x86/kernel/signal.c:865
>  handle_signal_work kernel/entry/common.c:148 [inline]
>  exit_to_user_mode_loop kernel/entry/common.c:172 [inline]
>  exit_to_user_mode_prepare+0x17d/0x290 kernel/entry/common.c:209
>  __syscall_exit_to_user_mode_work kernel/entry/common.c:291 [inline]
>  syscall_exit_to_user_mode+0x19/0x60 kernel/entry/common.c:302
>  do_syscall_64+0x42/0xb0 arch/x86/entry/common.c:86
>  entry_SYSCALL_64_after_hwframe+0x44/0xae
> RIP: 0033:0x445cd9
> RSP: 002b:00007fc657f4b308 EFLAGS: 00000246 ORIG_RAX: 00000000000000ca
> RAX: 0000000000000001 RBX: 00000000004cb448 RCX: 0000000000445cd9
> RDX: 00000000000f4240 RSI: 0000000000000081 RDI: 00000000004cb44c
> RBP: 00000000004cb440 R08: 000000000000000e R09: 0000000000000000
> R10: 0000000000000000 R11: 0000000000000246 R12: 000000000049b154
> R13: 0000000000000003 R14: 00007fc657f4b400 R15: 0000000000022000
> 
> Showing all locks held in the system:
> 1 lock held by khungtaskd/1655:
>  #0: ffffffff8b97f960 (rcu_read_lock){....}-{1:2}, at: debug_show_all_locks+0x53/0x260 kernel/locking/lockdep.c:6446
> 
> =============================================
> 
> NMI backtrace for cpu 1
> CPU: 1 PID: 1655 Comm: khungtaskd Not tainted 5.14.0-syzkaller #0
> Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011
> Call Trace:
>  __dump_stack lib/dump_stack.c:88 [inline]
>  dump_stack_lvl+0xcd/0x134 lib/dump_stack.c:105
>  nmi_cpu_backtrace.cold+0x47/0x144 lib/nmi_backtrace.c:105
>  nmi_trigger_cpumask_backtrace+0x1ae/0x220 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+0x3e5/0x4d0 kernel/kthread.c:319
>  ret_from_fork+0x1f/0x30 arch/x86/entry/entry_64.S:295
> Sending NMI from CPU 1 to CPUs 0:
> NMI backtrace for cpu 0
> CPU: 0 PID: 10 Comm: kworker/u4:1 Not tainted 5.14.0-syzkaller #0
> Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011
> Workqueue: events_unbound toggle_allocation_gate
> RIP: 0010:__text_poke+0x5f0/0x8c0 arch/x86/kernel/alternative.c:878
> Code: fb 48 8b 7c 24 60 e8 5f 67 0d 08 48 8b 4c 24 18 48 b8 00 00 00 00 00 fc ff df 48 c7 04 01 00 00 00 00 48 8b 84 24 98 00 00 00 <65> 48 2b 04 25 28 00 00 00 0f 85 2e 02 00 00 48 81 c4 a0 00 00 00
> RSP: 0018:ffffc90000cf7a00 EFLAGS: 00000286
> RAX: cfe52cf07638a100 RBX: 0000000000000007 RCX: 1ffff9200019ef48
> RDX: 0000000000000001 RSI: 0000000000000004 RDI: 0000000000000001
> RBP: ffff888011eaa558 R08: 0000000000000000 R09: ffff888010db8123
> R10: ffffed10021b7024 R11: 000000000000003f R12: ffffffff81bcfd53
> R13: 0000000000000001 R14: 0000000000000d54 R15: ffffffff8baa9900
> FS:  0000000000000000(0000) GS:ffff8880b9c00000(0000) knlGS:0000000000000000
> CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
> CR2: 00007f442218f000 CR3: 000000000b68e000 CR4: 0000000000350ef0
> Call Trace:
>  text_poke_bp_batch+0x3d7/0x560 arch/x86/kernel/alternative.c:1178
>  text_poke_flush arch/x86/kernel/alternative.c:1268 [inline]
>  text_poke_flush arch/x86/kernel/alternative.c:1265 [inline]
>  text_poke_finish+0x16/0x30 arch/x86/kernel/alternative.c:1275
>  arch_jump_label_transform_apply+0x13/0x20 arch/x86/kernel/jump_label.c:146
>  jump_label_update+0x1d5/0x430 kernel/jump_label.c:830
>  static_key_enable_cpuslocked+0x1b1/0x260 kernel/jump_label.c:177
>  static_key_enable+0x16/0x20 kernel/jump_label.c:190
>  toggle_allocation_gate mm/kfence/core.c:623 [inline]
>  toggle_allocation_gate+0x100/0x390 mm/kfence/core.c:615
>  process_one_work+0x9bf/0x16b0 kernel/workqueue.c:2297
>  worker_thread+0x658/0x11f0 kernel/workqueue.c:2444
>  kthread+0x3e5/0x4d0 kernel/kthread.c:319
>  ret_from_fork+0x1f/0x30 arch/x86/entry/entry_64.S:295
> ----------------
> Code disassembly (best guess):
>    0:	fb                   	sti
>    1:	48 8b 7c 24 60       	mov    0x60(%rsp),%rdi
>    6:	e8 5f 67 0d 08       	callq  0x80d676a
>    b:	48 8b 4c 24 18       	mov    0x18(%rsp),%rcx
>   10:	48 b8 00 00 00 00 00 	movabs $0xdffffc0000000000,%rax
>   17:	fc ff df
>   1a:	48 c7 04 01 00 00 00 	movq   $0x0,(%rcx,%rax,1)
>   21:	00
>   22:	48 8b 84 24 98 00 00 	mov    0x98(%rsp),%rax
>   29:	00
> * 2a:	65 48 2b 04 25 28 00 	sub    %gs:0x28,%rax <-- trapping instruction
>   31:	00 00
>   33:	0f 85 2e 02 00 00    	jne    0x267
>   39:	48 81 c4 a0 00 00 00 	add    $0xa0,%rsp
> 
> 
> ---
> 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
> 

-- 
Pavel Begunkov