INFO: rcu detected stall in cursor_timer_handler

7 views
Skip to first unread message

syzbot

unread,
Dec 29, 2019, 7:50:12 AM12/29/19
to syzkaller...@googlegroups.com
Hello,

syzbot found the following crash on:

HEAD commit: e1f7d50a Linux 4.14.160
git tree: linux-4.14.y
console output: https://syzkaller.appspot.com/x/log.txt?x=17dc0485e00000
kernel config: https://syzkaller.appspot.com/x/.config?x=46599517442ad9fb
dashboard link: https://syzkaller.appspot.com/bug?extid=65723a220aabb1a7407e
compiler: gcc (GCC) 9.0.0 20181231 (experimental)

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+65723a...@syzkaller.appspotmail.com

IPv6: ADDRCONF(NETDEV_CHANGE): vxcan1: link becomes ready
IPv6: ADDRCONF(NETDEV_CHANGE): vxcan0: link becomes ready
8021q: adding VLAN 0 to HW filter on device batadv0
dlm: no locking on control device
INFO: rcu_preempt self-detected stall on CPU
1-...: (1 GPs behind) idle=886/140000000000002/0 softirq=239884/239885
fqs=7
(t=10500 jiffies g=101635 c=101634 q=843)
rcu_preempt kthread starved for 6672 jiffies! g101635 c101634 f0x0
RCU_GP_WAIT_FQS(3) ->state=0x0 ->cpu=0
rcu_preempt R running task 29072 8 2 0x80000000
Call Trace:
context_switch kernel/sched/core.c:2808 [inline]
__schedule+0x7b8/0x1cd0 kernel/sched/core.c:3384
schedule+0x92/0x1c0 kernel/sched/core.c:3428
schedule_timeout+0x43e/0xe10 kernel/time/timer.c:1746
rcu_gp_kthread+0xbf4/0x1ec0 kernel/rcu/tree.c:2255
kthread+0x319/0x430 kernel/kthread.c:232
ret_from_fork+0x24/0x30 arch/x86/entry/entry_64.S:404
NMI backtrace for cpu 1
CPU: 1 PID: 26219 Comm: syz-executor.2 Not tainted 4.14.160-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:17 [inline]
dump_stack+0x142/0x197 lib/dump_stack.c:58
nmi_cpu_backtrace.cold+0x57/0x94 lib/nmi_backtrace.c:101
nmi_trigger_cpumask_backtrace+0x141/0x189 lib/nmi_backtrace.c:62
arch_trigger_cpumask_backtrace+0x14/0x20 arch/x86/kernel/apic/hw_nmi.c:38
trigger_single_cpu_backtrace include/linux/nmi.h:158 [inline]
rcu_dump_cpu_stacks+0x186/0x1d2 kernel/rcu/tree.c:1396
print_cpu_stall kernel/rcu/tree.c:1542 [inline]
check_cpu_stall kernel/rcu/tree.c:1610 [inline]
__rcu_pending kernel/rcu/tree.c:3390 [inline]
rcu_pending kernel/rcu/tree.c:3452 [inline]
rcu_check_callbacks.cold+0x43d/0xd0a kernel/rcu/tree.c:2792
update_process_times+0x31/0x70 kernel/time/timer.c:1590
tick_sched_handle+0x85/0x160 kernel/time/tick-sched.c:161
tick_sched_timer+0x43/0x130 kernel/time/tick-sched.c:1219
__run_hrtimer kernel/time/hrtimer.c:1220 [inline]
__hrtimer_run_queues+0x270/0xbc0 kernel/time/hrtimer.c:1284
hrtimer_interrupt+0x1d8/0x5d0 kernel/time/hrtimer.c:1318
local_apic_timer_interrupt arch/x86/kernel/apic/apic.c:1075 [inline]
smp_apic_timer_interrupt+0x11c/0x5e0 arch/x86/kernel/apic/apic.c:1100
apic_timer_interrupt+0x96/0xa0 arch/x86/entry/entry_64.S:792
RIP: 0010:arch_local_irq_restore arch/x86/include/asm/paravirt.h:779
[inline]
RIP: 0010:__raw_spin_unlock_irqrestore include/linux/spinlock_api_smp.h:160
[inline]
RIP: 0010:_raw_spin_unlock_irqrestore+0x95/0xe0
kernel/locking/spinlock.c:192
RSP: 0018:ffff8880aed07c48 EFLAGS: 00000282 ORIG_RAX: ffffffffffffff10
RAX: 1ffffffff0fe2d29 RBX: 0000000000000282 RCX: 1ffff1101147d551
RDX: dffffc0000000000 RSI: ffff88808a3eaa68 RDI: 0000000000000282
RBP: ffff8880aed07c58 R08: ffff88808a3ea1c0 R09: ffff88808a3eaa88
R10: 0000000000000000 R11: 0000000000000000 R12: ffff8880aed239c0
R13: 0000000000000001 R14: 0000000000000000 R15: ffff8880aed239c0
__mod_timer kernel/time/timer.c:1026 [inline]
mod_timer+0x56c/0xeb0 kernel/time/timer.c:1069
cursor_timer_handler+0xdb/0x130 drivers/video/fbdev/core/fbcon.c:404
call_timer_fn+0x161/0x670 kernel/time/timer.c:1279
expire_timers kernel/time/timer.c:1318 [inline]
__run_timers kernel/time/timer.c:1636 [inline]
__run_timers kernel/time/timer.c:1604 [inline]
run_timer_softirq+0x5b7/0x1520 kernel/time/timer.c:1649
__do_softirq+0x244/0x9a0 kernel/softirq.c:288
invoke_softirq kernel/softirq.c:368 [inline]
irq_exit+0x160/0x1b0 kernel/softirq.c:409
exiting_irq arch/x86/include/asm/apic.h:648 [inline]
smp_apic_timer_interrupt+0x146/0x5e0 arch/x86/kernel/apic/apic.c:1102
apic_timer_interrupt+0x96/0xa0 arch/x86/entry/entry_64.S:792
</IRQ>
RIP: 0010:arch_local_irq_restore arch/x86/include/asm/paravirt.h:779
[inline]
RIP: 0010:console_unlock+0x9f8/0xed0 kernel/printk/printk.c:2405
RSP: 0018:ffff8880401f7a38 EFLAGS: 00000212 ORIG_RAX: ffffffffffffff10
RAX: 0000000000040000 RBX: 0000000000000200 RCX: ffffc9000f660000
RDX: 0000000000007b07 RSI: ffffffff814b5aa2 RDI: 0000000000000212
RBP: ffff8880401f7ac8 R08: ffff88808a3ea1c0 R09: ffff88808a3eaa60
R10: 0000000000000000 R11: 0000000000000000 R12: 0000000000000000
R13: ffffffff83eb6950 R14: ffffffff8859e4f0 R15: dffffc0000000000
vprintk_emit kernel/printk/printk.c:1923 [inline]
vprintk_emit+0x1f9/0x600 kernel/printk/printk.c:1888
vprintk_default+0x28/0x30 kernel/printk/printk.c:1963
vprintk_func+0x5d/0x159 kernel/printk/printk_safe.c:401
printk+0x9e/0xbc kernel/printk/printk.c:1996
device_write.cold+0x18/0x200 fs/dlm/user.c:573
__vfs_write+0x105/0x6b0 fs/read_write.c:480
vfs_write+0x198/0x500 fs/read_write.c:544
SYSC_write fs/read_write.c:590 [inline]
SyS_write+0xfd/0x230 fs/read_write.c:582
do_syscall_64+0x1e8/0x640 arch/x86/entry/common.c:292
entry_SYSCALL_64_after_hwframe+0x42/0xb7
RIP: 0033:0x45a919
RSP: 002b:00007f9b3629ec78 EFLAGS: 00000246 ORIG_RAX: 0000000000000001
RAX: ffffffffffffffda RBX: 0000000000000003 RCX: 000000000045a919
RDX: 0000000000000068 RSI: 0000000020000280 RDI: 0000000000000004
RBP: 000000000075bf20 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000246 R12: 00007f9b3629f6d4
R13: 00000000004cbeba R14: 00000000004e5d28 R15: 00000000ffffffff
INFO: rcu_sched detected stalls on CPUs/tasks:
1-...: (1 GPs behind) idle=886/140000000000002/0 softirq=239884/239885
fqs=7
(detected by 0, t=10502 jiffies, g=20997, c=20996, q=4)
Sending NMI from CPU 0 to CPUs 1:
NMI backtrace for cpu 1
CPU: 1 PID: 26219 Comm: syz-executor.2 Not tainted 4.14.160-syzkaller #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS
Google 01/01/2011
task: ffff88808a3ea1c0 task.stack: ffff8880401f0000
RIP: 0010:__pvclock_read_cycles arch/x86/include/asm/pvclock.h:84 [inline]
RIP: 0010:pvclock_clocksource_read+0x11f/0x4a0 arch/x86/kernel/pvclock.c:87
RSP: 0018:ffff8880aed07a78 EFLAGS: 00000002
RAX: 000004ed64ed98e4 RBX: ffff88821fff7040 RCX: 0000000000000004
RDX: 0000000000000000 RSI: 0000000000000001 RDI: ffffed1043ffee0b
RBP: ffff8880aed07b00 R08: ffff88821fff705c R09: ffff88821fff7048
R10: ffff88821fff7050 R11: 0000000000000000 R12: dffffc0000000000
R13: ffff88821fff7043 R14: ffffed1043ffee09 R15: ffff88821fff705d
FS: 00007f9b3629f700(0000) GS:ffff8880aed00000(0000) knlGS:0000000000000000
CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
CR2: 00007ffb466d8db4 CR3: 000000008d1eb000 CR4: 00000000001406e0
DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
Call Trace:
<IRQ>
kvm_clock_read+0x23/0x40 arch/x86/kernel/kvmclock.c:88
kvm_sched_clock_read+0x9/0x20 arch/x86/kernel/kvmclock.c:100
paravirt_sched_clock arch/x86/include/asm/paravirt.h:175 [inline]
sched_clock+0x2e/0x50 arch/x86/kernel/tsc.c:228
sched_clock_cpu+0x1b/0x1c0 kernel/sched/clock.c:363
irqtime_account_irq+0x6a/0x290 kernel/sched/cputime.c:63
account_irq_enter_time include/linux/vtime.h:108 [inline]
irq_enter+0x66/0xe0 kernel/softirq.c:353
entering_irq arch/x86/include/asm/apic.h:629 [inline]
entering_ack_irq arch/x86/include/asm/apic.h:635 [inline]
smp_apic_timer_interrupt+0x24/0x5e0 arch/x86/kernel/apic/apic.c:1098
apic_timer_interrupt+0x96/0xa0 arch/x86/entry/entry_64.S:792
RIP: 0010:clocksource_watchdog+0x184/0x890 kernel/time/clocksource.c:202
RSP: 0018:ffff8880aed07cc0 EFLAGS: 00000206 ORIG_RAX: ffffffffffffff10
RAX: ffff88808a3ea1c0 RBX: ffffffff89a8df20 RCX: 1ffff1101147d556
RDX: 0000000000000100 RSI: ffff88808a3eaa90 RDI: ffff88808a3eaa3c
RBP: ffff8880aed07d40 R08: 0000022473ed8b44 R09: ffff88808a3eaab0
R10: 0000000000000000 R11: 0000000000000000 R12: ffffffff87eed6c0
R13: ffffffff87eed660 R14: dffffc0000000000 R15: 0000022473ed8b44
call_timer_fn+0x161/0x670 kernel/time/timer.c:1279
expire_timers kernel/time/timer.c:1318 [inline]
__run_timers kernel/time/timer.c:1636 [inline]
__run_timers kernel/time/timer.c:1604 [inline]
run_timer_softirq+0x5b7/0x1520 kernel/time/timer.c:1649
__do_softirq+0x244/0x9a0 kernel/softirq.c:288
invoke_softirq kernel/softirq.c:368 [inline]
irq_exit+0x160/0x1b0 kernel/softirq.c:409
exiting_irq arch/x86/include/asm/apic.h:648 [inline]
smp_apic_timer_interrupt+0x146/0x5e0 arch/x86/kernel/apic/apic.c:1102
apic_timer_interrupt+0x96/0xa0 arch/x86/entry/entry_64.S:792
</IRQ>
RIP: 0010:arch_local_irq_restore arch/x86/include/asm/paravirt.h:779
[inline]
RIP: 0010:console_unlock+0x9f8/0xed0 kernel/printk/printk.c:2405
RSP: 0018:ffff8880401f7a38 EFLAGS: 00000212 ORIG_RAX: ffffffffffffff10
RAX: 0000000000040000 RBX: 0000000000000200 RCX: ffffc9000f660000
RDX: 0000000000007b07 RSI: ffffffff814b5aa2 RDI: 0000000000000212
RBP: ffff8880401f7ac8 R08: ffff88808a3ea1c0 R09: ffff88808a3eaa60
R10: 0000000000000000 R11: 0000000000000000 R12: 0000000000000000
R13: ffffffff83eb6950 R14: ffffffff8859e4f0 R15: dffffc0000000000
vprintk_emit kernel/printk/printk.c:1923 [inline]
vprintk_emit+0x1f9/0x600 kernel/printk/printk.c:1888
vprintk_default+0x28/0x30 kernel/printk/printk.c:1963
vprintk_func+0x5d/0x159 kernel/printk/printk_safe.c:401
printk+0x9e/0xbc kernel/printk/printk.c:1996
device_write.cold+0x18/0x200 fs/dlm/user.c:573
__vfs_write+0x105/0x6b0 fs/read_write.c:480
vfs_write+0x198/0x500 fs/read_write.c:544
SYSC_write fs/read_write.c:590 [inline]
SyS_write+0xfd/0x230 fs/read_write.c:582
do_syscall_64+0x1e8/0x640 arch/x86/entry/common.c:292
entry_SYSCALL_64_after_hwframe+0x42/0xb7
RIP: 0033:0x45a919
RSP: 002b:00007f9b3629ec78 EFLAGS: 00000246 ORIG_RAX: 0000000000000001
RAX: ffffffffffffffda RBX: 0000000000000003 RCX: 000000000045a919
RDX: 0000000000000068 RSI: 0000000020000280 RDI: 0000000000000004
RBP: 000000000075bf20 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000246 R12: 00007f9b3629f6d4
R13: 00000000004cbeba R14: 00000000004e5d28 R15: 00000000ffffffff
Code: 40 84 d6 0f 85 e8 02 00 00 83 e7 07 40 38 f9 40 0f 9e c6 84 c9 0f 95
c2 40 84 d6 0f 85 d0 02 00 00 48 8b 7d b8 4c 89 c1 83 e1 07 <48> 2b 43 08
0f b6 17 38 ca 7f 08 84 d2 0f 85 e4 01 00 00 48 8b
rcu_sched kthread starved for 6674 jiffies! g20997 c20996 f0x0
RCU_GP_WAIT_FQS(3) ->state=0x0 ->cpu=0
rcu_sched R running task 29360 9 2 0x80000000
Call Trace:
context_switch kernel/sched/core.c:2808 [inline]
__schedule+0x7b8/0x1cd0 kernel/sched/core.c:3384
schedule+0x92/0x1c0 kernel/sched/core.c:3428
schedule_timeout+0x43e/0xe10 kernel/time/timer.c:1746
rcu_gp_kthread+0xbf4/0x1ec0 kernel/rcu/tree.c:2255
kthread+0x319/0x430 kernel/kthread.c:232
ret_from_fork+0x24/0x30 arch/x86/entry/entry_64.S:404
device bridge_slave_1 left promiscuous mode
bridge0: port 2(bridge_slave_1) entered disabled state
device bridge_slave_0 left promiscuous mode
bridge0: port 1(bridge_slave_0) entered disabled state


---
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

unread,
Apr 27, 2020, 8:50:12 AM4/27/20
to syzkaller...@googlegroups.com
Auto-closing this bug as obsolete.
Crashes did not happen for a while, no reproducer and no activity.
Reply all
Reply to author
Forward
0 new messages