syzbot


INFO: rcu detected stall in kvm_get_dirty_log_protect

Status: auto-closed as invalid on 2020/07/23 19:52
Subsystems: kvm
[Documentation on labels]
First crash: 1473d, last: 1460d

Sample crash report:
rcu: INFO: rcu_preempt self-detected stall on CPU
rcu: 	0-...!: (1 GPs behind) idle=d9a/1/0x4000000000000002 softirq=11741/11742 fqs=72 
	(t=10500 jiffies g=13521 q=625)
rcu: rcu_preempt kthread starved for 10322 jiffies! g13521 f0x0 RCU_GP_WAIT_FQS(5) ->state=0x0 ->cpu=1
rcu: RCU grace-period kthread stack dump:
rcu_preempt     R  running task    28848    10      2 0x80004000
Call Trace:
 context_switch kernel/sched/core.c:3372 [inline]
 __schedule+0x937/0x1ff0 kernel/sched/core.c:4088
 __sched_text_start+0x8/0x8
 __raw_spin_lock_irqsave include/linux/spinlock_api_smp.h:117 [inline]
 _raw_spin_lock_irqsave+0x94/0xbf kernel/locking/spinlock.c:159
 check_preemption_disabled lib/smp_processor_id.c:52 [inline]
 debug_smp_processor_id+0x2f/0x185 lib/smp_processor_id.c:57
 schedule+0xd0/0x2a0 kernel/sched/core.c:4163
 schedule_timeout+0x35c/0x850 kernel/time/timer.c:1898
 usleep_range+0x160/0x160 kernel/time/timer.c:2093
 atomic_add_return include/asm-generic/atomic-instrumented.h:71 [inline]
 rcu_dynticks_snap kernel/rcu/tree.c:311 [inline]
 rcu_dynticks_in_eqs_since kernel/rcu/tree.c:332 [inline]
 rcu_implicit_dynticks_qs+0x73/0xac0 kernel/rcu/tree.c:1042
 __raw_spin_unlock_irqrestore include/linux/spinlock_api_smp.h:160 [inline]
 _raw_spin_unlock_irqrestore+0x62/0xe0 kernel/locking/spinlock.c:191
 __next_timer_interrupt+0x190/0x190 kernel/time/timer.c:1512
 prepare_to_swait_exclusive+0x110/0x110 kernel/sched/swait.c:98
 rcu_gp_fqs_loop kernel/rcu/tree.c:1674 [inline]
 rcu_gp_kthread+0x9bf/0x1960 kernel/rcu/tree.c:1836
 rcu_barrier+0x4b0/0x4b0 arch/x86/include/asm/paravirt.h:764
 __raw_spin_unlock_irqrestore include/linux/spinlock_api_smp.h:160 [inline]
 _raw_spin_unlock_irqrestore+0x62/0xe0 kernel/locking/spinlock.c:191
 __trace_hardirqs_on_caller kernel/locking/lockdep.c:3657 [inline]
 lockdep_hardirqs_on+0x463/0x620 kernel/locking/lockdep.c:3702
 __kthread_parkme+0x13f/0x1e0 kernel/kthread.c:212
 rcu_barrier+0x4b0/0x4b0 arch/x86/include/asm/paravirt.h:764
 kthread+0x388/0x470 kernel/kthread.c:268
 kthread_mod_delayed_work+0x1a0/0x1a0 kernel/kthread.c:1090
 ret_from_fork+0x24/0x30 arch/x86/entry/entry_64.S:352
NMI backtrace for cpu 0
CPU: 0 PID: 8728 Comm: syz-executor.0 Not tainted 5.7.0-rc2-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:77 [inline]
 dump_stack+0x188/0x20d lib/dump_stack.c:118
 nmi_cpu_backtrace.cold+0x70/0xb1 lib/nmi_backtrace.c:101
 lapic_can_unplug_cpu.cold+0x3b/0x3b
 nmi_trigger_cpumask_backtrace+0x231/0x27e lib/nmi_backtrace.c:62
 trigger_single_cpu_backtrace include/linux/nmi.h:164 [inline]
 rcu_dump_cpu_stacks+0x19b/0x1e5 kernel/rcu/tree_stall.h:254
 print_cpu_stall kernel/rcu/tree_stall.h:475 [inline]
 check_cpu_stall kernel/rcu/tree_stall.h:549 [inline]
 rcu_pending kernel/rcu/tree.c:3225 [inline]
 rcu_sched_clock_irq.cold+0x55d/0xcfa kernel/rcu/tree.c:2296
 trace_hardirqs_off+0x50/0x220 kernel/trace/trace_preemptirq.c:45
 update_process_times+0x25/0x60 kernel/time/timer.c:1727
 tick_sched_handle+0x9b/0x180 kernel/time/tick-sched.c:176
 tick_sched_timer+0x4e/0x140 kernel/time/tick-sched.c:1320
 __run_hrtimer kernel/time/hrtimer.c:1520 [inline]
 __hrtimer_run_queues+0x5ca/0xed0 kernel/time/hrtimer.c:1584
 tick_sched_do_timer+0x1a0/0x1a0 kernel/time/tick-sched.c:64
 atomic_try_cmpxchg include/asm-generic/atomic-instrumented.h:694 [inline]
 queued_spin_lock include/asm-generic/qspinlock.h:78 [inline]
 do_raw_spin_lock+0x129/0x2e0 kernel/locking/spinlock_debug.c:113
 hrtimer_init+0x320/0x320 include/linux/compiler.h:199
 ktime_get_update_offsets_now+0x2d6/0x450 kernel/time/timekeeping.c:2240
 hrtimer_interrupt+0x312/0x770 kernel/time/hrtimer.c:1646
 local_apic_timer_interrupt arch/x86/kernel/apic/apic.c:1113 [inline]
 smp_apic_timer_interrupt+0x15b/0x600 arch/x86/kernel/apic/apic.c:1138
 apic_timer_interrupt+0xf/0x20 arch/x86/entry/entry_64.S:829
 </IRQ>
RIP: 0010:kvm_after_interrupt arch/x86/kvm/x86.h:340 [inline]
RIP: 0010:handle_external_interrupt_irqoff+0x1a8/0x240 arch/x86/kvm/vmx/vmx.c:6305
Code: 80 0f 24 88 e8 f9 99 80 02 65 48 89 2d 49 ac e8 7e 48 c1 e3 20 4c 09 e3 4c 09 eb 48 89 e0 48 83 e4 f0 6a 18 50 9c 6a 10 ff d3 <48> c7 c7 80 0f 24 88 e8 cc 99 80 02 65 48 c7 05 18 ac e8 7e 00 00
RSP: 0018:ffffc90017a1faf8 EFLAGS: 00000086 ORIG_RAX: ffffffffffffff13
RAX: ffffc90017a1faf8 RBX: ffffffff87e016e0 RCX: ffffc90001b99000
RDX: 0000000000040000 RSI: ffffffff81195497 RDI: 0000000000000005
RBP: ffff888047ec0140 R08: ffff888048f8a580 R09: ffffed1011fbeb02
R10: ffff88808fdf580f R11: ffffed1011fbeb01 R12: 0000000087e00000
R13: 00000000000016e0 R14: ffffff6d2b0dc231 R15: ffff888047ec0140
 __irqentry_text_start+0x8/0x8
 kvm_before_interrupt arch/x86/kvm/x86.h:335 [inline]
 handle_external_interrupt_irqoff+0x187/0x240 arch/x86/kvm/vmx/vmx.c:6282
 kvm_before_interrupt arch/x86/kvm/x86.h:335 [inline]
 handle_external_interrupt_irqoff+0x187/0x240 arch/x86/kvm/vmx/vmx.c:6282
 vmx_handle_exit_irqoff+0x19d/0x320 arch/x86/kvm/vmx/vmx.c:6315
 vcpu_enter_guest+0xbc8/0x59d0 arch/x86/kvm/x86.c:8455
 mark_held_locks+0x9f/0xe0 kernel/locking/lockdep.c:3628
 kvm_vcpu_reload_apic_access_page+0x300/0x300 include/linux/mm.h:1080
 trace_hardirqs_on_thunk+0x1a/0x1c arch/x86/entry/thunk_64.S:41
 set_irq_regs arch/x86/include/asm/irq_regs.h:27 [inline]
 smp_apic_timer_interrupt+0x1b6/0x600 arch/x86/kernel/apic/apic.c:1142
 retint_kernel+0x2b/0x2b
 list_empty_careful include/linux/list.h:301 [inline]
 kvm_check_async_pf_completion+0x2a4/0x400 arch/x86/kvm/../../../virt/kvm/async_pf.c:137
 clear_bit include/asm-generic/bitops/instrumented-atomic.h:41 [inline]
 kvm_clear_request include/linux/kvm_host.h:1246 [inline]
 vcpu_run arch/x86/kvm/x86.c:8569 [inline]
 kvm_arch_vcpu_ioctl_run+0x42b/0x16a0 arch/x86/kvm/x86.c:8783
 vcpu_run arch/x86/kvm/x86.c:8561 [inline]
 kvm_arch_vcpu_ioctl_run+0x3fb/0x16a0 arch/x86/kvm/x86.c:8783
 vcpu_run arch/x86/kvm/x86.c:8561 [inline]
 kvm_arch_vcpu_ioctl_run+0x3fb/0x16a0 arch/x86/kvm/x86.c:8783
 kvm_vcpu_ioctl+0x493/0xe60 arch/x86/kvm/../../../virt/kvm/kvm_main.c:3138
 kvm_get_dirty_log_protect.isra.0+0x670/0x670 arch/x86/kvm/../../../virt/kvm/kvm_main.c:1465
 ioctl_file_clone+0x180/0x180 fs/ioctl.c:245
 rcu_lock_release include/linux/rcupdate.h:213 [inline]
 rcu_read_unlock include/linux/rcupdate.h:655 [inline]
 __fget_files+0x32f/0x500 fs/file.c:734
 ksys_dup3+0x3c0/0x3c0 include/linux/compiler.h:199
 kvm_get_dirty_log_protect.isra.0+0x670/0x670 arch/x86/kvm/../../../virt/kvm/kvm_main.c:1465
 vfs_ioctl fs/ioctl.c:47 [inline]
 ksys_ioctl+0x11a/0x180 fs/ioctl.c:763
 __do_sys_ioctl fs/ioctl.c:772 [inline]
 __se_sys_ioctl fs/ioctl.c:770 [inline]
 __x64_sys_ioctl+0x6f/0xb0 fs/ioctl.c:770
 __trace_hardirqs_on_caller kernel/locking/lockdep.c:3657 [inline]
 lockdep_hardirqs_on+0x463/0x620 kernel/locking/lockdep.c:3702
 do_syscall_64+0xf6/0x7d0 arch/x86/entry/common.c:295
 entry_SYSCALL_64_after_hwframe+0x49/0xb3

Crashes (2):
Time Kernel Commit Syzkaller Config Log Report Syz repro C repro VM info Assets (help?) Manager Title
2020/04/24 19:47 upstream b4f633221f0a 03d97a1b .config console log report ci-upstream-kasan-gce-root
2020/04/11 12:53 upstream ab6f762f0f53 a8c6a3f8 .config console log report ci-upstream-kasan-gce-root
* Struck through repros no longer work on HEAD.