syzbot


INFO: rcu detected stall in tctx_task_work (2)

Status: closed as invalid on 2021/12/14 20:12
Subsystems: fs io-uring
[Documentation on labels]
First crash: 907d, last: 901d
Cause bisection: introduced by (bisect log) [merge commit]:
commit 418739d9f3d24c4f7314309547350370f4287016
Author: Stephen Rothwell <sfr@canb.auug.org.au>
Date: Fri Oct 29 07:17:02 2021 +0000

  Merge branch 'akpm-current/current'

Crash: WARNING: ODEBUG bug in __io_free_req (log)
Repro: syz .config
  
Similar bugs (1)
Kernel Title Repro Cause bisect Fix bisect Count Last Reported Patched Status
upstream INFO: rcu detected stall in tctx_task_work io-uring fs C done 9 908d 907d 0/26 closed as invalid on 2021/10/31 19:40

Sample crash report:
rcu: INFO: rcu_preempt self-detected stall on CPU
rcu: 	1-....: (1 GPs behind) idle=785/1/0x4000000000000000 softirq=51846/51847 fqs=5242 
	(t=10502 jiffies g=80757 q=2357)
NMI backtrace for cpu 1
CPU: 1 PID: 28936 Comm: syz-executor.1 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:lock_acquire+0x1ef/0x510 kernel/locking/lockdep.c:5605
Code: 99 a5 7e 83 f8 01 0f 85 b4 02 00 00 9c 58 f6 c4 02 0f 85 9f 02 00 00 48 83 7c 24 08 00 74 01 fb 48 b8 00 00 00 00 00 fc ff df <48> 01 c3 48 c7 03 00 00 00 00 48 c7 43 08 00 00 00 00 48 8b 84 24
RSP: 0018:ffffc90002b2fcd0 EFLAGS: 00000206
RAX: dffffc0000000000 RBX: 1ffff92000565f9c RCX: ffffffff815c8e3f
RDX: 1ffff1100b8ccc44 RSI: 0000000000000001 RDI: 0000000000000000
RBP: 0000000000000001 R08: 0000000000000000 R09: ffffffff8fa48af7
R10: fffffbfff1f4915e R11: 0000000000000000 R12: 0000000000000000
R13: 0000000000000000 R14: ffff88801c6913d8 R15: 0000000000000000
 __raw_spin_lock include/linux/spinlock_api_smp.h:142 [inline]
 _raw_spin_lock+0x2a/0x40 kernel/locking/spinlock.c:154
 spin_lock include/linux/spinlock.h:367 [inline]
 __io_free_req+0x2f6/0x3c5 fs/io_uring.c:2039
 tctx_task_work+0x1b3/0x630 fs/io_uring.c:2207
 task_work_run+0xdd/0x1a0 kernel/task_work.c:164
 tracehook_notify_signal include/linux/tracehook.h:214 [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:0x7f0aee4a3ae9
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:00007f0aedc19188 EFLAGS: 00000246 ORIG_RAX: 00000000000001aa
RAX: 0000000000000001 RBX: 00007f0aee5b6f60 RCX: 00007f0aee4a3ae9
RDX: 0000000000000000 RSI: 0000000000006019 RDI: 0000000000000003
RBP: 00007f0aee4fdf25 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000246 R12: 0000000000000000
R13: 00007ffcd72b5b9f R14: 00007f0aedc19300 R15: 0000000000022000
 </TASK>
----------------
Code disassembly (best guess):
   0:	99                   	cltd
   1:	a5                   	movsl  %ds:(%rsi),%es:(%rdi)
   2:	7e 83                	jle    0xffffff87
   4:	f8                   	clc
   5:	01 0f                	add    %ecx,(%rdi)
   7:	85 b4 02 00 00 9c 58 	test   %esi,0x589c0000(%rdx,%rax,1)
   e:	f6 c4 02             	test   $0x2,%ah
  11:	0f 85 9f 02 00 00    	jne    0x2b6
  17:	48 83 7c 24 08 00    	cmpq   $0x0,0x8(%rsp)
  1d:	74 01                	je     0x20
  1f:	fb                   	sti
  20:	48 b8 00 00 00 00 00 	movabs $0xdffffc0000000000,%rax
  27:	fc ff df
* 2a:	48 01 c3             	add    %rax,%rbx <-- trapping instruction
  2d:	48 c7 03 00 00 00 00 	movq   $0x0,(%rbx)
  34:	48 c7 43 08 00 00 00 	movq   $0x0,0x8(%rbx)
  3b:	00
  3c:	48                   	rex.W
  3d:	8b                   	.byte 0x8b
  3e:	84                   	.byte 0x84
  3f:	24                   	.byte 0x24

Crashes (4):
Time Kernel Commit Syzkaller Config Log Report Syz repro C repro VM info Assets (help?) Manager Title
2021/10/31 22:45 linux-next bdcc9f6a5682 098b5d53 .config console log report syz ci-upstream-linux-next-kasan-gce-root INFO: rcu detected stall in tctx_task_work
2021/11/01 18: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/31 19:52 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/11/07 08:34 upstream 512b7931ad05 4c1be0be .config console log report info ci-upstream-kasan-gce BUG: soft lockup in tctx_task_work
* Struck through repros no longer work on HEAD.