syzbot


INFO: rcu detected stall in estimation_timer (2)

Status: closed as invalid on 2022/02/08 10:10
Subsystems: perf
[Documentation on labels]
First crash: 840d, last: 840d
Similar bugs (1)
Kernel Title Repro Cause bisect Fix bisect Count Last Reported Patched Status
upstream INFO: rcu detected stall in estimation_timer lvs 1 1368d 1368d 0/26 auto-closed as invalid on 2020/10/18 15:22

Sample crash report:
rcu: INFO: rcu_preempt self-detected stall on CPU
rcu: 	0-....: (7331 ticks this GP) idle=637/1/0x4000000000000000 softirq=127086/127086 fqs=3599 
	(t=10500 jiffies g=148189 q=2163)
NMI backtrace for cpu 0
CPU: 0 PID: 29868 Comm: syz-executor.3 Not tainted 5.16.0-rc7-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+0x5c/0x759 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: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+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_is_held_type+0xff/0x140 kernel/locking/lockdep.c:5685
Code: 00 00 b8 ff ff ff ff 65 0f c1 05 dc 86 be 76 83 f8 01 75 29 9c 58 f6 c4 02 75 3d 48 f7 04 24 00 02 00 00 74 01 fb 48 83 c4 08 <44> 89 e8 5b 5d 41 5c 41 5d 41 5e 41 5f c3 45 31 ed eb b9 0f 0b 48
RSP: 0018:ffffc900000074c8 EFLAGS: 00000282
RAX: 0000000000000046 RBX: 0000000000000004 RCX: 0000000000000001
RDX: 0000000000000000 RSI: 0000000000000104 RDI: 0000000000000000
RBP: ffffffff8bb812a0 R08: 0000000000000001 R09: 0000000000000001
R10: ffffffff81991b60 R11: 0000000000000000 R12: ffff88802f7b8180
R13: 0000000000000001 R14: 00000000ffffffff R15: ffff88802f7b8c80
 __perf_output_begin kernel/events/ring_buffer.c:170 [inline]
 perf_output_begin_forward+0x13c/0xae0 kernel/events/ring_buffer.c:268
 __perf_event_output kernel/events/core.c:7489 [inline]
 perf_event_output_forward+0xf2/0x280 kernel/events/core.c:7507
 __perf_event_overflow+0x13c/0x3d0 kernel/events/core.c:9207
 perf_swevent_overflow kernel/events/core.c:9283 [inline]
 perf_swevent_event+0x347/0x550 kernel/events/core.c:9311
 perf_tp_event+0x2e4/0xbc0 kernel/events/core.c:9739
 perf_trace_run_bpf_submit+0x11c/0x210 kernel/events/core.c:9713
 perf_trace_lock+0x2ef/0x4d0 include/trace/events/lock.h:39
 trace_lock_release include/trace/events/lock.h:58 [inline]
 lock_release+0x4a8/0x720 kernel/locking/lockdep.c:5648
 __raw_spin_unlock include/linux/spinlock_api_smp.h:141 [inline]
 _raw_spin_unlock+0x12/0x40 kernel/locking/spinlock.c:186
 spin_unlock include/linux/spinlock.h:389 [inline]
 estimation_timer+0x606/0x920 net/netfilter/ipvs/ip_vs_est.c:134
 call_timer_fn+0x1a5/0x6b0 kernel/time/timer.c:1421
 expire_timers kernel/time/timer.c:1466 [inline]
 __run_timers.part.0+0x67c/0xa30 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:637
 irq_exit_rcu+0x5/0x20 kernel/softirq.c:649
 sysvec_irq_work+0x93/0xc0 arch/x86/kernel/irq_work.c:17
 </IRQ>
 <TASK>
 asm_sysvec_irq_work+0x12/0x20 arch/x86/include/asm/idtentry.h:664
RIP: 0010:preempt_schedule_irq+0x49/0x90 kernel/sched/core.c:6668
Code: 55 53 65 48 8b 1c 25 40 70 02 00 48 89 dd 48 c1 ed 03 48 01 c5 bf 01 00 00 00 e8 12 84 09 f8 e8 dd 5f 37 f8 fb bf 01 00 00 00 <e8> 52 a9 ff ff 9c 58 fa f6 c4 02 75 27 bf 01 00 00 00 e8 40 73 09
RSP: 0018:ffffc900056b7a48 EFLAGS: 00000206
RAX: 000000000000718d RBX: ffff88802f7b8180 RCX: 1ffffffff1b21e01
RDX: 0000000000000000 RSI: 0000000000000001 RDI: 0000000000000001
RBP: ffffed1005ef7030 R08: 0000000000000001 R09: 0000000000000001
R10: ffffffff817d08b8 R11: 0000000000000000 R12: 0000000000000000
R13: 0000000000000000 R14: 0000000000000000 R15: 0000000000000000
 irqentry_exit+0x31/0x80 kernel/entry/common.c:425
 asm_sysvec_reschedule_ipi+0x12/0x20 arch/x86/include/asm/idtentry.h:643
RIP: 0010:qlist_free_all+0x67/0x110 mm/kasan/quarantine.c:160
Code: 07 bd 81 48 c1 e8 03 42 c6 04 28 fb e8 d2 7a ff ff 48 85 db 75 52 9c 58 f6 c4 02 0f 85 a4 00 00 00 48 85 db 74 01 fb 48 85 ed <74> 73 48 89 ee 4d 85 e4 4c 89 e7 74 38 48 63 87 80 00 00 00 48 8b
RSP: 0018:ffffc900056b7b18 EFLAGS: 00000282
RAX: 0000000000000006 RBX: 0000000000000200 RCX: 1ffffffff1b21e01
RDX: 0000000000000000 RSI: 0000000000000000 RDI: 0000000000000000
RBP: ffff8880a3834a80 R08: 0000000000000001 R09: 0000000000000001
R10: ffffffff817d08b8 R11: 000000000000003f R12: 0000000000000000
R13: dffffc0000000000 R14: ffffc900056b7b60 R15: ffffea0000000000
 kasan_quarantine_reduce+0x180/0x200 mm/kasan/quarantine.c:272
 __kasan_slab_alloc+0x97/0xb0 mm/kasan/common.c:444
 kasan_slab_alloc include/linux/kasan.h:259 [inline]
 slab_post_alloc_hook mm/slab.h:519 [inline]
 slab_alloc mm/slab.c:3323 [inline]
 kmem_cache_alloc+0x265/0x560 mm/slab.c:3507
 kmem_cache_zalloc include/linux/slab.h:714 [inline]
 __alloc_file+0x21/0x280 fs/file_table.c:101
 alloc_empty_file+0x6d/0x170 fs/file_table.c:150
 alloc_file+0x59/0x590 fs/file_table.c:192
 alloc_file_pseudo+0x165/0x250 fs/file_table.c:232
 __anon_inode_getfile fs/anon_inodes.c:109 [inline]
 anon_inode_getfile+0xb0/0x1e0 fs/anon_inodes.c:147
 __do_sys_perf_event_open+0x107e/0x3130 kernel/events/core.c:12243
 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:0x7f20f1c54e99
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:00007f20f05ca168 EFLAGS: 00000246 ORIG_RAX: 000000000000012a
RAX: ffffffffffffffda RBX: 00007f20f1d67f60 RCX: 00007f20f1c54e99
RDX: 0000000000000000 RSI: 0000000000000000 RDI: 0000000020000380
RBP: 00007f20f1caeff1 R08: 0000000000000000 R09: 0000000000000000
R10: ffffffffffffffff R11: 0000000000000246 R12: 0000000000000000
R13: 00007fffc90d85bf R14: 00007f20f05ca300 R15: 0000000000022000
 </TASK>
----------------
Code disassembly (best guess):
   0:	00 00                	add    %al,(%rax)
   2:	b8 ff ff ff ff       	mov    $0xffffffff,%eax
   7:	65 0f c1 05 dc 86 be 	xadd   %eax,%gs:0x76be86dc(%rip)        # 0x76be86eb
   e:	76
   f:	83 f8 01             	cmp    $0x1,%eax
  12:	75 29                	jne    0x3d
  14:	9c                   	pushfq
  15:	58                   	pop    %rax
  16:	f6 c4 02             	test   $0x2,%ah
  19:	75 3d                	jne    0x58
  1b:	48 f7 04 24 00 02 00 	testq  $0x200,(%rsp)
  22:	00
  23:	74 01                	je     0x26
  25:	fb                   	sti
  26:	48 83 c4 08          	add    $0x8,%rsp
* 2a:	44 89 e8             	mov    %r13d,%eax <-- trapping instruction
  2d:	5b                   	pop    %rbx
  2e:	5d                   	pop    %rbp
  2f:	41 5c                	pop    %r12
  31:	41 5d                	pop    %r13
  33:	41 5e                	pop    %r14
  35:	41 5f                	pop    %r15
  37:	c3                   	retq
  38:	45 31 ed             	xor    %r13d,%r13d
  3b:	eb b9                	jmp    0xfffffff6
  3d:	0f 0b                	ud2
  3f:	48                   	rex.W

Crashes (1):
Time Kernel Commit Syzkaller Config Log Report Syz repro C repro VM info Assets (help?) Manager Title
2021/12/30 23:03 upstream eec4df26e24e 2e49f10d .config console log report info ci-upstream-kasan-gce-selinux-root INFO: rcu detected stall in estimation_timer
* Struck through repros no longer work on HEAD.