INFO: rcu detected stall in kvm_vcpu_ioctl

10 views
Skip to first unread message

syzbot

unread,
Jan 10, 2020, 2:56:12 PM1/10/20
to syzkaller...@googlegroups.com
Hello,

syzbot found the following crash on:

HEAD commit: cb1f9a16 Linux 4.19.94
git tree: linux-4.19.y
console output: https://syzkaller.appspot.com/x/log.txt?x=155db6aee00000
kernel config: https://syzkaller.appspot.com/x/.config?x=f87b837c6c739b95
dashboard link: https://syzkaller.appspot.com/bug?extid=fdc7ca10e5f338f55f79
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+fdc7ca...@syzkaller.appspotmail.com

rcu: INFO: rcu_preempt detected stalls on CPUs/tasks:
rcu: (detected by 0, t=10502 jiffies, g=101057, q=36)
rcu: All QSes seen, last rcu_preempt kthread activity 10502
(4295027990-4295017488), jiffies_till_next_fqs=1, root ->qsmask 0x0
syz-executor.4 R running task 26640 25021 8048 0x00000000
Call Trace:
<IRQ>
sched_show_task kernel/sched/core.c:5338 [inline]
sched_show_task.cold+0x2ee/0x35d kernel/sched/core.c:5313
print_other_cpu_stall kernel/rcu/tree.c:1430 [inline]
check_cpu_stall kernel/rcu/tree.c:1557 [inline]
__rcu_pending kernel/rcu/tree.c:3293 [inline]
rcu_pending kernel/rcu/tree.c:3336 [inline]
rcu_check_callbacks.cold+0xaa1/0xd90 kernel/rcu/tree.c:2682
update_process_times+0x32/0x80 kernel/time/timer.c:1638
tick_sched_handle+0xa2/0x190 kernel/time/tick-sched.c:164
tick_sched_timer+0x47/0x130 kernel/time/tick-sched.c:1274
__run_hrtimer kernel/time/hrtimer.c:1401 [inline]
__hrtimer_run_queues+0x33b/0xdc0 kernel/time/hrtimer.c:1463
hrtimer_interrupt+0x314/0x770 kernel/time/hrtimer.c:1521
local_apic_timer_interrupt arch/x86/kernel/apic/apic.c:1067 [inline]
smp_apic_timer_interrupt+0x111/0x550 arch/x86/kernel/apic/apic.c:1092
apic_timer_interrupt+0xf/0x20 arch/x86/entry/entry_64.S:893
</IRQ>
RIP: 0010:vmx_handle_external_intr+0x1af/0x200 arch/x86/kvm/vmx.c:10501
Code: 38 d1 0f 9e c2 84 c9 0f 95 c0 84 c2 75 53 8b 43 08 48 c1 e0 20 4c 09
e0 4c 09 e8 48 89 e2 48 83 e4 f0 6a 18 52 9c 6a 10 ff d0 <e8> 3c f7 52 00
5b 41 5c 41 5d 5d c3 e8 f0 8f 8a 00 e9 bb fe ff ff
RSP: 0018:ffff88804a70f9e8 EFLAGS: 00000082 ORIG_RAX: ffffffffffffff13
RAX: ffffffff876015c0 RBX: fffffe0000000ec0 RCX: 0000000000000000
RDX: ffff88804a70f9e8 RSI: 0000000000000001 RDI: fffffe0000000ec8
RBP: ffff88804a70fa00 R08: ffff88808796a480 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000000 R12: 0000000087600000
R13: 00000000000015c0 R14: fffffe4ffe59fa7a R15: 0000000000000000
vcpu_enter_guest+0xe16/0x5ed0 arch/x86/kvm/x86.c:7782
vcpu_run arch/x86/kvm/x86.c:7872 [inline]
kvm_arch_vcpu_ioctl_run+0x457/0x16b0 arch/x86/kvm/x86.c:8072
kvm_vcpu_ioctl+0x4dc/0xf90 arch/x86/kvm/../../../virt/kvm/kvm_main.c:2667
vfs_ioctl fs/ioctl.c:46 [inline]
file_ioctl fs/ioctl.c:501 [inline]
do_vfs_ioctl+0xd5f/0x1380 fs/ioctl.c:688
ksys_ioctl+0xab/0xd0 fs/ioctl.c:705
__do_sys_ioctl fs/ioctl.c:712 [inline]
__se_sys_ioctl fs/ioctl.c:710 [inline]
__x64_sys_ioctl+0x73/0xb0 fs/ioctl.c:710
do_syscall_64+0xfd/0x620 arch/x86/entry/common.c:293
entry_SYSCALL_64_after_hwframe+0x49/0xbe
RIP: 0033:0x45af49
Code: ad b6 fb ff c3 66 2e 0f 1f 84 00 00 00 00 00 66 90 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 0f 83 7b b6 fb ff c3 66 2e 0f 1f 84 00 00 00 00
RSP: 002b:00007f3e2a227c78 EFLAGS: 00000246 ORIG_RAX: 0000000000000010
RAX: ffffffffffffffda RBX: 0000000000000003 RCX: 000000000045af49
RDX: 0000000000000000 RSI: 000000000000ae80 RDI: 0000000000000006
RBP: 000000000075bf20 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000246 R12: 00007f3e2a2286d4
R13: 00000000004c4905 R14: 00000000004db298 R15: 00000000ffffffff
rcu: rcu_preempt kthread starved for 10502 jiffies! g101057 f0x2
RCU_GP_WAIT_FQS(5) ->state=0x0 ->cpu=1
rcu: RCU grace-period kthread stack dump:
rcu_preempt R running task 29104 10 2 0x80000000
Call Trace:
context_switch kernel/sched/core.c:2826 [inline]
__schedule+0x866/0x1dc0 kernel/sched/core.c:3515
schedule+0x92/0x1c0 kernel/sched/core.c:3559
schedule_timeout+0x4db/0xfc0 kernel/time/timer.c:1806
rcu_gp_kthread+0xd5c/0x2190 kernel/rcu/tree.c:2202
kthread+0x354/0x420 kernel/kthread.c:246
ret_from_fork+0x24/0x30 arch/x86/entry/entry_64.S:415


---
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,
Mar 1, 2020, 12:45:14 PM3/1/20
to syzkaller...@googlegroups.com
syzbot has found a reproducer for the following crash on:

HEAD commit: a083db76 Linux 4.19.107
git tree: linux-4.19.y
console output: https://syzkaller.appspot.com/x/log.txt?x=1728fa81e00000
kernel config: https://syzkaller.appspot.com/x/.config?x=c32f76aaadd644de
dashboard link: https://syzkaller.appspot.com/bug?extid=fdc7ca10e5f338f55f79
compiler: gcc (GCC) 9.0.0 20181231 (experimental)
syz repro: https://syzkaller.appspot.com/x/repro.syz?x=14d852c3e00000
C reproducer: https://syzkaller.appspot.com/x/repro.c?x=13818331e00000

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

kvm: emulating exchange as write
rcu: INFO: rcu_preempt detected stalls on CPUs/tasks:
rcu: (detected by 1, t=10502 jiffies, g=7029, q=9)
rcu: All QSes seen, last rcu_preempt kthread activity 10502 (4295015275-4295004773), jiffies_till_next_fqs=1, root ->qsmask 0x0
syz-executor855 R running task 28120 8454 8328 0x00000800
Call Trace:
<IRQ>
sched_show_task kernel/sched/core.c:5338 [inline]
sched_show_task.cold+0x2e2/0x343 kernel/sched/core.c:5313
print_other_cpu_stall kernel/rcu/tree.c:1430 [inline]
check_cpu_stall kernel/rcu/tree.c:1557 [inline]
__rcu_pending kernel/rcu/tree.c:3293 [inline]
rcu_pending kernel/rcu/tree.c:3336 [inline]
rcu_check_callbacks.cold+0xaf0/0xddc kernel/rcu/tree.c:2682
update_process_times+0x2a/0x70 kernel/time/timer.c:1638
tick_sched_handle+0x9b/0x180 kernel/time/tick-sched.c:168
tick_sched_timer+0x42/0x130 kernel/time/tick-sched.c:1278
__run_hrtimer kernel/time/hrtimer.c:1401 [inline]
__hrtimer_run_queues+0x2fc/0xd50 kernel/time/hrtimer.c:1463
hrtimer_interrupt+0x312/0x770 kernel/time/hrtimer.c:1521
local_apic_timer_interrupt arch/x86/kernel/apic/apic.c:1067 [inline]
smp_apic_timer_interrupt+0x10c/0x550 arch/x86/kernel/apic/apic.c:1092
apic_timer_interrupt+0xf/0x20 arch/x86/entry/entry_64.S:893
</IRQ>
RIP: 0010:vcpu_enter_guest+0xed3/0x5ed0 arch/x86/kvm/x86.c:7831
Code: ff df 48 c1 e8 03 80 3c 10 00 0f 85 cb 44 00 00 48 83 3d 67 2f a6 07 00 0f 84 c0 36 00 00 e8 84 71 5b 00 fb 66 0f 1f 44 00 00 <bf> 01 00 00 00 e8 13 73 3a 00 65 8b 1d 7c c6 f5 7e 31 ff 89 de e8
RSP: 0018:ffff88809fa37a30 EFLAGS: 00000293 ORIG_RAX: ffffffffffffff13
RAX: ffff88809f51e540 RBX: ffff88809f51e540 RCX: 1ffff11013ea3dbc
RDX: 0000000000000000 RSI: ffffffff810c273c RDI: ffff88809f51edbc
RBP: ffff88809fa37b40 R08: ffff88809f51e540 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000000 R12: ffff8880a4f306c0
R13: ffff8880a4f306ec R14: fffffe92e03ed1ee R15: 0000000000000000
vcpu_run arch/x86/kvm/x86.c:7913 [inline]
kvm_arch_vcpu_ioctl_run+0x446/0x16a0 arch/x86/kvm/x86.c:8113
kvm_vcpu_ioctl+0x493/0xe20 arch/x86/kvm/../../../virt/kvm/kvm_main.c:2667
vfs_ioctl fs/ioctl.c:46 [inline]
file_ioctl fs/ioctl.c:501 [inline]
do_vfs_ioctl+0xcda/0x12e0 fs/ioctl.c:688
ksys_ioctl+0x9b/0xc0 fs/ioctl.c:705
__do_sys_ioctl fs/ioctl.c:712 [inline]
__se_sys_ioctl fs/ioctl.c:710 [inline]
__x64_sys_ioctl+0x6f/0xb0 fs/ioctl.c:710
do_syscall_64+0xf9/0x620 arch/x86/entry/common.c:293
entry_SYSCALL_64_after_hwframe+0x49/0xbe
RIP: 0033:0x44a9e9
Code: e8 ec e7 ff ff 48 83 c4 18 c3 0f 1f 80 00 00 00 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 0f 83 1b ff fb ff c3 66 2e 0f 1f 84 00 00 00 00
RSP: 002b:00007f0d0e1e4ce8 EFLAGS: 00000246 ORIG_RAX: 0000000000000010
RAX: ffffffffffffffda RBX: 00000000006dfc58 RCX: 000000000044a9e9
RDX: 0000000000000000 RSI: 000000000000ae80 RDI: 0000000000000008
RBP: 00000000006dfc50 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000246 R12: 00000000006dfc5c
R13: 00007ffec2d9748f R14: 00007f0d0e1e59c0 R15: 0000000000000005
rcu: rcu_preempt kthread starved for 10502 jiffies! g7029 f0x2 RCU_GP_WAIT_FQS(5) ->state=0x0 ->cpu=1
rcu: RCU grace-period kthread stack dump:
rcu_preempt R running task 29152 10 2 0x80000000
Call Trace:
schedule+0x8d/0x1b0 kernel/sched/core.c:3559
schedule_timeout+0x4d1/0xf20 kernel/time/timer.c:1806
rcu_gp_kthread+0xcee/0x2060 kernel/rcu/tree.c:2202
kthread+0x34a/0x420 kernel/kthread.c:246
ret_from_fork+0x24/0x30 arch/x86/entry/entry_64.S:415

Reply all
Reply to author
Forward
0 new messages