syzbot


INFO: rcu detected stall in tctx_task_work

Status: closed as invalid on 2021/10/31 19:40
Subsystems: io-uring fs
[Documentation on labels]
Reported-by: syzbot+e4f5deeeccdd5a4873fe@syzkaller.appspotmail.com
First crash: 907d, last: 905d
Cause bisection: introduced by (bisect log) :
commit 34ced75ca1f63fac6148497971212583aa0f7a87
Author: Xiaoguang Wang <xiaoguang.wang@linux.alibaba.com>
Date: Mon Oct 25 05:38:48 2021 +0000

  io_uring: reduce frequent add_wait_queue() overhead for multi-shot poll request

Crash: INFO: task hung in io_uring_try_cancel_requests (log)
Repro: C syz .config
  
Discussions (1)
Title Replies (including bot) Last reply
[syzbot] INFO: rcu detected stall in tctx_task_work 1 (2) 2021/10/31 19:40
Similar bugs (1)
Kernel Title Repro Cause bisect Fix bisect Count Last Reported Patched Status
upstream INFO: rcu detected stall in tctx_task_work (2) fs io-uring syz unreliable 4 898d 905d 0/26 closed as invalid on 2021/12/14 20:12

Sample crash report:
rcu: INFO: rcu_preempt self-detected stall on CPU
rcu: 	0-....: (10499 ticks this GP) idle=91d/1/0x4000000000000000 softirq=9714/9714 fqs=3884 
	(t=10500 jiffies g=11093 q=47)
NMI backtrace for cpu 0
CPU: 0 PID: 6487 Comm: syz-executor141 Not tainted 5.15.0-rc7-next-20211029-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:88 [inline]
 dump_stack_lvl+0xcd/0x134 lib/dump_stack.c:106
 nmi_cpu_backtrace.cold+0x47/0x144 lib/nmi_backtrace.c:105
 nmi_trigger_cpumask_backtrace+0x1ae/0x220 lib/nmi_backtrace.c:62
 trigger_single_cpu_backtrace include/linux/nmi.h:164 [inline]
 rcu_dump_cpu_stacks+0x25e/0x3f0 kernel/rcu/tree_stall.h:343
 print_cpu_stall kernel/rcu/tree_stall.h:604 [inline]
 check_cpu_stall kernel/rcu/tree_stall.h:688 [inline]
 rcu_pending kernel/rcu/tree.c:3922 [inline]
 rcu_sched_clock_irq.cold+0x9d/0x746 kernel/rcu/tree.c:2620
 update_process_times+0x16d/0x200 kernel/time/timer.c:1785
 tick_sched_handle+0x9b/0x180 kernel/time/tick-sched.c:226
 tick_sched_timer+0x1b0/0x2d0 kernel/time/tick-sched.c:1428
 __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:debug_spin_unlock kernel/locking/spinlock_debug.c:104 [inline]
RIP: 0010:do_raw_spin_unlock+0x101/0x230 kernel/locking/spinlock_debug.c:140
Code: 8e fc 00 00 00 65 8b 05 e5 c5 a4 7e 39 45 08 0f 85 b5 00 00 00 48 b8 00 00 00 00 00 fc ff df 4c 89 ea 48 c1 ea 03 80 3c 02 00 <0f> 85 f5 00 00 00 4c 89 e2 48 c7 45 10 ff ff ff ff 48 b8 00 00 00
RSP: 0018:ffffc90002a8fcc8 EFLAGS: 00000246
RAX: dffffc0000000000 RBX: ffff88801a315950 RCX: ffffffff815d4f10
RDX: 1ffff1100449ce7a RSI: 0000000000000004 RDI: ffff8880224e73c0
RBP: ffff8880224e73c0 R08: 0000000000000000 R09: ffff8880224e73c3
R10: ffffed100449ce78 R11: 0000000000000000 R12: ffff8880224e73c8
R13: ffff8880224e73d0 R14: ffff88801a315918 R15: ffff88801a3158c0
 __raw_spin_unlock include/linux/spinlock_api_smp.h:151 [inline]
 _raw_spin_unlock+0x1a/0x40 kernel/locking/spinlock.c:186
 tctx_task_work+0x1b3/0x630 fs/io_uring.c:2207
 task_work_run+0xdd/0x1a0 kernel/task_work.c:164
 exit_task_work include/linux/task_work.h:32 [inline]
 do_exit+0xc14/0x2b40 kernel/exit.c:832
 do_group_exit+0x125/0x310 kernel/exit.c:929
 __do_sys_exit_group kernel/exit.c:940 [inline]
 __se_sys_exit_group kernel/exit.c:938 [inline]
 __x64_sys_exit_group+0x3a/0x50 kernel/exit.c:938
 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:0x7fe6950481a9
Code: Unable to access opcode bytes at RIP 0x7fe69504817f.
RSP: 002b:00007ffc42a91cb8 EFLAGS: 00000246 ORIG_RAX: 00000000000000e7
RAX: ffffffffffffffda RBX: 00007fe6950bc330 RCX: 00007fe6950481a9
RDX: 000000000000003c RSI: 00000000000000e7 RDI: 0000000000000000
RBP: 0000000000000000 R08: ffffffffffffffc0 R09: 00000000f5ffffff
R10: 0000000000000000 R11: 0000000000000246 R12: 00007fe6950bc330
R13: 0000000000000001 R14: 0000000000000000 R15: 0000000000000001
 </TASK>
----------------
Code disassembly (best guess):
   0:	8e fc                	mov    %esp,%?
   2:	00 00                	add    %al,(%rax)
   4:	00 65 8b             	add    %ah,-0x75(%rbp)
   7:	05 e5 c5 a4 7e       	add    $0x7ea4c5e5,%eax
   c:	39 45 08             	cmp    %eax,0x8(%rbp)
   f:	0f 85 b5 00 00 00    	jne    0xca
  15:	48 b8 00 00 00 00 00 	movabs $0xdffffc0000000000,%rax
  1c:	fc ff df
  1f:	4c 89 ea             	mov    %r13,%rdx
  22:	48 c1 ea 03          	shr    $0x3,%rdx
  26:	80 3c 02 00          	cmpb   $0x0,(%rdx,%rax,1)
* 2a:	0f 85 f5 00 00 00    	jne    0x125 <-- trapping instruction
  30:	4c 89 e2             	mov    %r12,%rdx
  33:	48 c7 45 10 ff ff ff 	movq   $0xffffffffffffffff,0x10(%rbp)
  3a:	ff
  3b:	48                   	rex.W
  3c:	b8                   	.byte 0xb8
  3d:	00 00                	add    %al,(%rax)

Crashes (9):
Time Kernel Commit Syzkaller Config Log Report Syz repro C repro VM info Assets (help?) Manager Title
2021/10/30 02:37 linux-next bdcc9f6a5682 098b5d53 .config console log report syz C ci-upstream-linux-next-kasan-gce-root INFO: rcu detected stall in tctx_task_work
2021/10/31 07:17 linux-next bdcc9f6a5682 098b5d53 .config console log report info ci-upstream-linux-next-kasan-gce-root INFO: rcu detected stall in tctx_task_work
2021/10/31 07:16 linux-next bdcc9f6a5682 098b5d53 .config console log report info ci-upstream-linux-next-kasan-gce-root INFO: rcu detected stall in tctx_task_work
2021/10/30 17:19 linux-next bdcc9f6a5682 098b5d53 .config console log report info ci-upstream-linux-next-kasan-gce-root INFO: rcu detected stall in tctx_task_work
2021/10/30 17:18 linux-next bdcc9f6a5682 098b5d53 .config console log report info ci-upstream-linux-next-kasan-gce-root INFO: rcu detected stall in tctx_task_work
2021/10/30 01:55 linux-next bdcc9f6a5682 098b5d53 .config console log report info ci-upstream-linux-next-kasan-gce-root INFO: rcu detected stall in tctx_task_work
2021/10/30 00:13 linux-next bdcc9f6a5682 098b5d53 .config console log report info ci-upstream-linux-next-kasan-gce-root INFO: rcu detected stall in tctx_task_work
2021/10/29 10:28 linux-next bdcc9f6a5682 2353a3ec .config console log report info ci-upstream-linux-next-kasan-gce-root INFO: rcu detected stall in tctx_task_work
2021/10/29 09:07 linux-next bdcc9f6a5682 2353a3ec .config console log report info ci-upstream-linux-next-kasan-gce-root INFO: rcu detected stall in tctx_task_work
* Struck through repros no longer work on HEAD.