INFO: rcu detected stall in trace_timer_expire_entry

[syzbot]

Hello,

syzbot found the following crash on:

HEAD commit: f74c2bb9 Linux 5.3-rc8
git tree: upstream
console output: https://syzkaller.appspot.com/x/log.txt?x=112884f6600000
kernel config: https://syzkaller.appspot.com/x/.config?x=ed2b148cd67382ec
dashboard link: https://syzkaller.appspot.com/bug?extid=a292d95ece4a4895f50c
compiler: clang version 9.0.0 (/home/glider/llvm/clang
80fee25776c2fb61e74c1ecb1a523375c2500b69)
CC: [b...@alien8.de c...@lca.pw dr...@endlessm.com h...@zytor.com
jacob....@linux.intel.com linux-...@vger.kernel.org mi...@redhat.com
pu...@hygon.cn rp...@linux.vnet.ibm.com tg...@linutronix.de x...@kernel.org]

Unfortunately, I don't have any reproducer for this crash yet.

IMPORTANT: if you fix the bug, please add the following tag to the commit:
Reported-by: syzbot+a292d9...@syzkaller.appspotmail.com

rcu: INFO: rcu_preempt self-detected stall on CPU
rcu: 0-...!: (1 GPs behind) idle=24a/1/0x4000000000000004
softirq=264076/264086 fqs=0
(t=10501 jiffies g=347289 q=90)
rcu: rcu_preempt kthread starved for 10502 jiffies! g347289 f0x0
RCU_GP_WAIT_FQS(5) ->state=0x0 ->cpu=1
rcu: RCU grace-period kthread stack dump:
rcu_preempt R running task 28896 10 2 0x80004000
Call Trace:
context_switch kernel/sched/core.c:3254 [inline]
__schedule+0x877/0xc50 kernel/sched/core.c:3880
schedule+0x131/0x1e0 kernel/sched/core.c:3947
schedule_timeout+0x14f/0x240 kernel/time/timer.c:1807
rcu_gp_fqs_loop kernel/rcu/tree.c:1611 [inline]
rcu_gp_kthread+0xef8/0x1790 kernel/rcu/tree.c:1768
kthread+0x332/0x350 kernel/kthread.c:255
ret_from_fork+0x24/0x30 arch/x86/entry/entry_64.S:352
NMI backtrace for cpu 0
CPU: 0 PID: 31509 Comm: syz-executor.3 Not tainted 5.3.0-rc8 #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS
Google 01/01/2011
Call Trace:
<IRQ>
__dump_stack lib/dump_stack.c:77 [inline]
dump_stack+0x1d8/0x2f8 lib/dump_stack.c:113
nmi_cpu_backtrace+0xaf/0x1a0 lib/nmi_backtrace.c:101
nmi_trigger_cpumask_backtrace+0x174/0x290 lib/nmi_backtrace.c:62
arch_trigger_cpumask_backtrace+0x10/0x20 arch/x86/kernel/apic/hw_nmi.c:38
trigger_single_cpu_backtrace include/linux/nmi.h:164 [inline]
rcu_dump_cpu_stacks+0x15a/0x220 kernel/rcu/tree_stall.h:254
print_cpu_stall kernel/rcu/tree_stall.h:455 [inline]
check_cpu_stall kernel/rcu/tree_stall.h:529 [inline]
rcu_pending kernel/rcu/tree.c:2736 [inline]
rcu_sched_clock_irq+0xb95/0x16d0 kernel/rcu/tree.c:2183
update_process_times+0x134/0x190 kernel/time/timer.c:1639
tick_sched_handle kernel/time/tick-sched.c:167 [inline]
tick_sched_timer+0x263/0x420 kernel/time/tick-sched.c:1296
__run_hrtimer kernel/time/hrtimer.c:1389 [inline]
__hrtimer_run_queues+0x403/0x850 kernel/time/hrtimer.c:1451
hrtimer_interrupt+0x38c/0xda0 kernel/time/hrtimer.c:1509
local_apic_timer_interrupt arch/x86/kernel/apic/apic.c:1106 [inline]
smp_apic_timer_interrupt+0x109/0x280 arch/x86/kernel/apic/apic.c:1131
apic_timer_interrupt+0xf/0x20 arch/x86/entry/entry_64.S:830
RIP: 0010:bytes_is_nonzero mm/kasan/generic.c:94 [inline]
RIP: 0010:memory_is_nonzero mm/kasan/generic.c:109 [inline]
RIP: 0010:memory_is_poisoned_n mm/kasan/generic.c:135 [inline]
RIP: 0010:memory_is_poisoned mm/kasan/generic.c:166 [inline]
RIP: 0010:check_memory_region_inline mm/kasan/generic.c:182 [inline]
RIP: 0010:check_memory_region+0x8d/0x2e0 mm/kasan/generic.c:192
Code: 4d 85 f6 0f 84 a9 01 00 00 4c 89 cb 4c 29 d3 0f 1f 40 00 66 2e 0f 1f
84 00 00 00 00 00 45 0f b6 19 45 84 db 0f 85 09 02 00 00 <49> ff c1 48 ff
c3 75 eb e9 7b 01 00 00 44 89 cb 83 e3 07 0f 84 0a
RSP: 0018:ffff8880aea09ce0 EFLAGS: 00000246 ORIG_RAX: ffffffffffffff13
RAX: 0000000000000001 RBX: ffffffffffffffff RCX: ffffffff8163bba0
RDX: 0000000000000000 RSI: 0000000000000008 RDI: ffffffff88bdf460
RBP: ffff8880aea09d08 R08: dffffc0000000000 R09: fffffbfff117be8c
R10: fffffbfff117be8d R11: 0000000000000000 R12: 1ffffffff117be8c
R13: dffffc0000000001 R14: 0000000000000001 R15: ffff88808d6d9580
__kasan_check_read+0x11/0x20 mm/kasan/common.c:92
test_bit include/asm-generic/bitops-instrumented.h:237 [inline]
cpumask_test_cpu include/linux/cpumask.h:344 [inline]
trace_timer_expire_entry+0x190/0x2a0 include/trace/events/timer.h:90
call_timer_fn+0x8f/0x170 kernel/time/timer.c:1321
expire_timers kernel/time/timer.c:1366 [inline]
__run_timers+0x79e/0x970 kernel/time/timer.c:1685
run_timer_softirq+0x4a/0x90 kernel/time/timer.c:1698
__do_softirq+0x333/0x7c4 arch/x86/include/asm/paravirt.h:778
invoke_softirq kernel/softirq.c:373 [inline]
irq_exit+0x227/0x230 kernel/softirq.c:413
exiting_irq arch/x86/include/asm/apic.h:537 [inline]
smp_apic_timer_interrupt+0x113/0x280 arch/x86/kernel/apic/apic.c:1133
apic_timer_interrupt+0xf/0x20 arch/x86/entry/entry_64.S:830
</IRQ>
RIP: 0010:debug_spin_unlock kernel/locking/spinlock_debug.c:100 [inline]
RIP: 0010:do_raw_spin_unlock+0xc0/0x260 kernel/locking/spinlock_debug.c:138
Code: 25 c0 fd 01 00 49 39 45 00 0f 85 9e 00 00 00 4d 8d 66 08 4d 89 e7 49
c1 ef 03 41 8a 04 17 84 c0 0f 85 50 01 00 00 41 8b 04 24 <65> 8b 0d 91 98
a6 7e 39 c8 0f 85 92 00 00 00 80 3c 13 00 74 12 4c
RSP: 0018:ffff888215397938 EFLAGS: 00000246 ORIG_RAX: ffffffffffffff13
RAX: 0000000000000000 RBX: 1ffff110433dc19e RCX: ffffffff815afa29
RDX: dffffc0000000000 RSI: 0000000000000004 RDI: ffff888219ee0ce0
RBP: ffff888215397960 R08: dffffc0000000000 R09: ffffed10433dc19d
R10: ffffed10433dc19d R11: 0000000000000000 R12: ffff888219ee0ce8
R13: ffff888219ee0cf0 R14: ffff888219ee0ce0 R15: 1ffff110433dc19d
__raw_spin_unlock include/linux/spinlock_api_smp.h:151 [inline]
_raw_spin_unlock+0x22/0x50 kernel/locking/spinlock.c:183
spin_unlock include/linux/spinlock.h:378 [inline]
lockref_get_not_dead+0x77/0xc0 lib/lockref.c:217
legitimize_path fs/namei.c:623 [inline]
unlazy_walk+0x14f/0x730 fs/namei.c:675
may_lookup fs/namei.c:1697 [inline]
link_path_walk+0x1c2/0x1410 fs/namei.c:2082
path_openat+0x139/0x4460 fs/namei.c:3532
do_filp_open+0x192/0x3d0 fs/namei.c:3563
do_sys_open+0x29f/0x560 fs/open.c:1089
__do_sys_open fs/open.c:1107 [inline]
__se_sys_open fs/open.c:1102 [inline]
__x64_sys_open+0x87/0x90 fs/open.c:1102
do_syscall_64+0xfe/0x140 arch/x86/entry/common.c:296
entry_SYSCALL_64_after_hwframe+0x49/0xbe
RIP: 0033:0x4137d1
Code: 75 14 b8 02 00 00 00 0f 05 48 3d 01 f0 ff ff 0f 83 04 19 00 00 c3 48
83 ec 08 e8 0a fa ff ff 48 89 04 24 b8 02 00 00 00 0f 05 <48> 8b 3c 24 48
89 c2 e8 53 fa ff ff 48 89 d0 48 83 c4 08 48 3d 01
RSP: 002b:00007f2103439bb0 EFLAGS: 00000293 ORIG_RAX: 0000000000000002
RAX: ffffffffffffffda RBX: 0000000000000002 RCX: 00000000004137d1
RDX: 00007f2103439be6 RSI: 0000000000000002 RDI: 00007f2103439bd0
RBP: 000000000075bf20 R08: 0000000000000000 R09: 0000000000000016
R10: 000000000000000b R11: 0000000000000293 R12: 00007f210343a6d4
R13: 00000000004c8ef7 R14: 00000000004dff48 R15: 00000000ffffffff


---
This bug 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 syzk...@googlegroups.com.

syzbot will keep track of this bug report. See:
https://goo.gl/tpsmEJ#status for how to communicate with syzbot.

[syzbot]

Auto-closing this bug as obsolete.
Crashes did not happen for a while, no reproducer and no activity.