syzbot


INFO: rcu detected stall in pie_timer (5)

Status: closed as invalid on 2022/02/08 10:00
Reported-by: syzbot+@syzkaller.appspotmail.com
First crash: 376d, last: 373d
similar bugs (5):
Kernel Title Repro Cause bisect Fix bisect Count Last Reported Patched Status
upstream INFO: rcu detected stall in pie_timer (4) 1 553d 553d 0/24 auto-closed as invalid on 2021/08/22 00:34
upstream INFO: rcu detected stall in pie_timer (2) 2 1135d 1139d 0/24 auto-closed as invalid on 2020/01/18 03:16
upstream INFO: rcu detected stall in pie_timer C 19 1140d 1175d 14/24 fixed on 2019/10/15 23:40
upstream INFO: rcu detected stall in pie_timer (3) 4 812d 881d 0/24 auto-closed as invalid on 2020/12/06 09:21
linux-4.19 INFO: rcu detected stall in pie_timer C error 28 78d 1176d 0/1 upstream: reported C repro on 2019/09/09 01:30

Sample crash report:
rcu: INFO: rcu_preempt self-detected stall on CPU
rcu: 	0-...!: (8454 ticks this GP) idle=915/1/0x4000000000000000 softirq=95225/95227 fqs=19 
	(t=10500 jiffies g=179853 q=511)
rcu: rcu_preempt kthread starved for 6261 jiffies! g179853 f0x0 RCU_GP_WAIT_FQS(5) ->state=0x0 ->cpu=1
rcu: 	Unless rcu_preempt kthread gets sufficient CPU time, OOM is now expected behavior.
rcu: RCU grace-period kthread stack dump:
task:rcu_preempt     state:R  running task     stack:28616 pid:   14 ppid:     2 flags:0x00004000
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_timeout+0x14a/0x2a0 kernel/time/timer.c:1881
 rcu_gp_fqs_loop+0x186/0x810 kernel/rcu/tree.c:1955
 rcu_gp_kthread+0x1de/0x320 kernel/rcu/tree.c:2128
 kthread+0x405/0x4f0 kernel/kthread.c:327
 ret_from_fork+0x1f/0x30 arch/x86/entry/entry_64.S:295
 </TASK>
rcu: Stack dump where RCU GP kthread last ran:
Sending NMI from CPU 0 to CPUs 1:
NMI backtrace for cpu 1
CPU: 1 PID: 10 Comm: kworker/u4:1 Not tainted 5.16.0-rc1-syzkaller #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011
Workqueue: events_unbound toggle_allocation_gate
RIP: 0010:csd_lock_wait kernel/smp.c:440 [inline]
RIP: 0010:smp_call_function_many_cond+0x452/0xc20 kernel/smp.c:969
Code: 0b 00 85 ed 74 4d 48 b8 00 00 00 00 00 fc ff df 4d 89 f4 4c 89 f5 49 c1 ec 03 83 e5 07 49 01 c4 83 c5 03 e8 70 79 0b 00 f3 90 <41> 0f b6 04 24 40 38 c5 7c 08 84 c0 0f 85 33 06 00 00 8b 43 08 31
RSP: 0018:ffffc90000f0f9f8 EFLAGS: 00000293
RAX: 0000000000000000 RBX: ffffe8ffffc0b640 RCX: 0000000000000000
RDX: ffff888011c7e280 RSI: ffffffff816b5820 RDI: 0000000000000003
RBP: 0000000000000003 R08: 0000000000000000 R09: 0000000000000001
R10: ffffffff816b5846 R11: 0000000000000000 R12: fffff91ffff816c9
R13: 0000000000000000 R14: ffffe8ffffc0b648 R15: 0000000000000001
FS:  0000000000000000(0000) GS:ffff8880b9d00000(0000) knlGS:0000000000000000
CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
CR2: 00007f5d0b091000 CR3: 000000000b88e000 CR4: 00000000003506e0
DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
Call Trace:
 <TASK>
 on_each_cpu_cond_mask+0x56/0xa0 kernel/smp.c:1135
 on_each_cpu include/linux/smp.h:71 [inline]
 text_poke_sync arch/x86/kernel/alternative.c:1112 [inline]
 text_poke_bp_batch+0x1b3/0x560 arch/x86/kernel/alternative.c:1297
 text_poke_flush arch/x86/kernel/alternative.c:1451 [inline]
 text_poke_flush arch/x86/kernel/alternative.c:1448 [inline]
 text_poke_finish+0x16/0x30 arch/x86/kernel/alternative.c:1458
 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:732 [inline]
 toggle_allocation_gate+0x100/0x390 mm/kfence/core.c:724
 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>
NMI backtrace for cpu 0
CPU: 0 PID: 19171 Comm: syz-executor.4 Not tainted 5.16.0-rc1-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:111
 nmi_trigger_cpumask_backtrace+0x1b3/0x230 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:627 [inline]
 check_cpu_stall kernel/rcu/tree_stall.h:711 [inline]
 rcu_pending kernel/rcu/tree.c:3878 [inline]
 rcu_sched_clock_irq.cold+0x9d/0x746 kernel/rcu/tree.c:2597
 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:1421
 __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+0x40/0xc0 arch/x86/kernel/apic/apic.c:1097
 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: 91 a6 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:ffffc90000007c18 EFLAGS: 00000206
RAX: dffffc0000000000 RBX: 1ffff92000000f85 RCX: ffffffff815b95df
RDX: 1ffff110065e3d53 RSI: 0000000000000102 RDI: 0000000000000000
RBP: 0000000000000001 R08: 0000000000000000 R09: ffffffff8ff74ae7
R10: fffffbfff1fee95c R11: 0000000000000000 R12: 0000000000000000
R13: 0000000000000000 R14: ffff88809cfcf908 R15: 0000000000000000
 __raw_spin_lock include/linux/spinlock_api_smp.h:133 [inline]
 _raw_spin_lock+0x2a/0x40 kernel/locking/spinlock.c:154
 spin_lock include/linux/spinlock.h:349 [inline]
 pie_timer+0x86/0x180 net/sched/sch_pie.c:429
 call_timer_fn+0x1a5/0x6b0 kernel/time/timer.c:1421
 expire_timers kernel/time/timer.c:1466 [inline]
 __run_timers.part.0+0x675/0xa20 kernel/time/timer.c:1734
 __run_timers kernel/time/timer.c:1715 [inline]
 run_timer_softirq+0xb3/0x1d0 kernel/time/timer.c:1747
 __do_softirq+0x29b/0x9c2 kernel/softirq.c:558
 invoke_softirq kernel/softirq.c:432 [inline]
 __irq_exit_rcu+0x123/0x180 kernel/softirq.c:636
 irq_exit_rcu+0x5/0x20 kernel/softirq.c:648
 sysvec_apic_timer_interrupt+0x93/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:finish_task_switch.isra.0+0x323/0xb80 kernel/sched/core.c:4852
Code: 13 05 f4 07 85 c0 75 02 0f 0b 48 85 db 0f 85 25 01 00 00 4c 89 f7 e8 fc f7 ff ff e8 17 4a 2d 00 fb 65 48 8b 1c 25 40 70 02 00 <48> 8d bb 80 15 00 00 48 b8 00 00 00 00 00 fc ff df 48 89 fa 48 c1
RSP: 0018:ffffc90002b079b0 EFLAGS: 00000206
RAX: 0000000000000d09 RBX: ffff888032f1e040 RCX: 1ffffffff1b21781
RDX: 0000000000000000 RSI: 0000000000000001 RDI: 0000000000000000
RBP: ffffc90002b079f8 R08: 0000000000000001 R09: 0000000000000001
R10: ffffffff817d1608 R11: 0000000000000000 R12: ffff8880b9c3a858
R13: ffff88803f334240 R14: ffff8880b9c39b00 R15: ffff8880b9c3a538
 context_switch kernel/sched/core.c:4975 [inline]
 __schedule+0xaa2/0x4940 kernel/sched/core.c:6253
 preempt_schedule_common+0x45/0xc0 kernel/sched/core.c:6419
 preempt_schedule_thunk+0x16/0x18 arch/x86/entry/thunk_64.S:35
 __raw_spin_unlock include/linux/spinlock_api_smp.h:143 [inline]
 _raw_spin_unlock+0x36/0x40 kernel/locking/spinlock.c:186
 spin_unlock include/linux/spinlock.h:389 [inline]
 futex_queue kernel/futex/futex.h:179 [inline]
 futex_wait_queue+0x7e/0x3b0 kernel/futex/waitwake.c:338
 futex_wait+0x2c9/0x670 kernel/futex/waitwake.c:656
 do_futex+0x205/0x390 kernel/futex/syscalls.c:122
 __do_sys_futex kernel/futex/syscalls.c:199 [inline]
 __se_sys_futex kernel/futex/syscalls.c:180 [inline]
 __x64_sys_futex+0x1b0/0x4a0 kernel/futex/syscalls.c:180
 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:0x7f8be6fadae9
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:00007ffdd6e928a8 EFLAGS: 00000246 ORIG_RAX: 00000000000000ca
RAX: ffffffffffffffda RBX: 0000000000000032 RCX: 00007f8be6fadae9
RDX: 0000000000000000 RSI: 0000000000000080 RDI: 00007f8be70c0f6c
RBP: 00007f8be70c0f6c R08: 00007ffdd6f35080 R09: 0000000000000000
R10: 00007ffdd6e92980 R11: 0000000000000246 R12: 0000000000139542
R13: 00000000000003e8 R14: 00007f8be70c0f60 R15: 0000000000139510
 </TASK>
----------------
Code disassembly (best guess):
   0:	0b 00                	or     (%rax),%eax
   2:	85 ed                	test   %ebp,%ebp
   4:	74 4d                	je     0x53
   6:	48 b8 00 00 00 00 00 	movabs $0xdffffc0000000000,%rax
   d:	fc ff df
  10:	4d 89 f4             	mov    %r14,%r12
  13:	4c 89 f5             	mov    %r14,%rbp
  16:	49 c1 ec 03          	shr    $0x3,%r12
  1a:	83 e5 07             	and    $0x7,%ebp
  1d:	49 01 c4             	add    %rax,%r12
  20:	83 c5 03             	add    $0x3,%ebp
  23:	e8 70 79 0b 00       	callq  0xb7998
  28:	f3 90                	pause
* 2a:	41 0f b6 04 24       	movzbl (%r12),%eax <-- trapping instruction
  2f:	40 38 c5             	cmp    %al,%bpl
  32:	7c 08                	jl     0x3c
  34:	84 c0                	test   %al,%al
  36:	0f 85 33 06 00 00    	jne    0x66f
  3c:	8b 43 08             	mov    0x8(%rbx),%eax
  3f:	31                   	.byte 0x31

Crashes (2):
Manager Time Kernel Commit Syzkaller Config Log Report Syz repro C repro VM info Title
ci-upstream-kasan-gce-selinux-root 2021/11/20 09:39 upstream 4c388a8e740d 3a9d0024 .config log report info INFO: rcu detected stall in pie_timer
ci-upstream-kasan-gce 2021/11/17 08:00 upstream 8ab774587903 cafff8b6 .config log report info INFO: rcu detected stall in pie_timer
* Struck through repros no longer work on HEAD.