kvmppc_wait_for_nap warnings and KVM host+guest hang on 3.14-rc6*

[Aneesh Kumar K.V]

Anton Blanchard <anton at samba.org> writes:

> Hi,
>
> I was testing KVM on an upstream kernel (3.14.0-rc6-00145-ga4ecdf8)
> with Gregory's emulated MMIO fixes.
>
> I ran with 16 cores and 4 threads (matches the host):
>
> qemu-system-ppc64 -enable-kvm -smp cores=16,threads=4 -m 32G -M
> pseries -cpu POWER7 -nographic -nodefaults -monitor stdio -serial pty
> -drive file=XXX -netdev
> bridge,br=br0,id=net0,helper=/usr/libexec/qemu-bridge-helper -device
> virtio-net-pci,netdev=net0

>
> Note that in kernel XICS acceleration wasn't enabled (perhaps it should
> be the default, it isn't right now):
>
> qemu-system-ppc64: KVM and IRQ_XICS capability must be present for in-kernel XICS
>
> During boot I see processors stuck in the guest:

The hang during boot is mostly due to missing top 5 patches which you
can find below.

https://github.com/agraf/linux-2.6/commits/kvm-ppc-queue



>
> [   16.145166] Processor 1 is stuck.

I see that on host when i try to kexec without making all the cpu online
(ie not doing --smt=on). Haven't got around to looking at that.

>
> And thousands of:
>
> kvmppc_wait_for_nap timeout 0 1
> kvmppc_wait_for_nap timeout 0 1
> kvmppc_wait_for_nap timeout 0 1
> kvmppc_wait_for_nap timeout 0 1
>

I haven't see that error before.

> And eventually:
>
> INFO: rcu_sched self-detected stall on CPU { 52}  (t=10170 jiffies g=765 c=764 q=127)
> CPU: 52 PID: 11833 Comm: qemu-system-ppc Not tainted 3.14.0-rc6-00145-ga4ecdf8-dirty #10
> Call Trace:
> [c000000765caad20] [c000000000015f3c] .show_stack+0x7c/0x1f0 (unreliable)
> [c000000765caadf0] [c00000000082d83c] .dump_stack+0x88/0xb4
> [c000000765caae70] [c0000000000f7cf0] .rcu_check_callbacks+0x5b0/0x950
> [c000000765caafa0] [c00000000009c860] .update_process_times+0x50/0xa0
> [c000000765cab030] [c000000000103c40] .tick_sched_handle.isra.16+0x20/0xa0
> [c000000765cab0b0] [c000000000103d1c] .tick_sched_timer+0x5c/0xa0
> [c000000765cab150] [c0000000000ba0f8] .__run_hrtimer+0x98/0x260
> [c000000765cab1f0] [c0000000000baef8] .hrtimer_interrupt+0x138/0x320
> [c000000765cab300] [c00000000001e430] .timer_interrupt+0x100/0x2f0
> [c000000765cab3b0] [c00000000000a8d8] restore_check_irq_replay+0x40/0x5c
> --- Exception: 901 at .__kvmppc_vcore_entry+0x140/0x1ac [kvm_hv]
>     LR = kvmppc_call_hv_entry+0x8/0xe8
> [c000000765cab6a0] [d000000006394f74] .__kvmppc_vcore_entry+0x140/0x1ac [kvm_hv] (unreliable)
> [c000000765cab870] [d000000006394148] .kvmppc_vcpu_run_hv+0x8b8/0x1520 [kvm_hv]
> [c000000765cab9f0] [d000000005e5c250] .kvmppc_vcpu_run+0x30/0x50 [kvm]
> [c000000765caba60] [d000000005e599f4] .kvm_arch_vcpu_ioctl_run+0x54/0x1b0 [kvm]INFO: rcu_sched detected stalls on CPUs/tasks: { 52} (detected by 60, t=10170 jiffies, g=765, c=764, q=127)
> Task dump for CPU 52:
> qemu-system-ppc R  running task     9184 11833  11817 0x00000084
> Call Trace:
> [c000000765cab2f0] [c000000765cab3b0] 0xc000000765cab3b0 (unreliable)
> [c000000765cab420] [c000000000d518e8] kexec_stack+0x18e8/0x10000
> [c000000765cabaf0] [d000000005e54588] .kvm_vcpu_ioctl+0x478/0x740 [kvm]
> [c000000765cabcb0] [c0000000001ffcd4] .do_vfs_ioctl+0x4a4/0x760
> [c000000765cabd90] [c0000000001fffe8] .SyS_ioctl+0x58/0xb0
> [c000000765cabe30] [c00000000000a158] syscall_exit+0x0/0x98
>
> BUG: soft lockup - CPU#52 stuck for 97s! [qemu-system-ppc:11833]
> Modules linked in: tun xt_conntrack ipt_MASQUERADE iptable_nat nf_conntrack_ipv4 nf_defrag_ipv4 nf_nat_ipv4 nf_nat nf_conntrack iptable_filter ip_tables x_tables bridge stp llc kvm_hv powernv_rng rng_core kvm binfmt_misc nfsd exportfs autofs4
> CPU: 52 PID: 11833 Comm: qemu-system-ppc Not tainted 3.14.0-rc6-00145-ga4ecdf8-dirty #10
> task: c00000078f7af860 ti: c000000765ca8000 task.ti: c000000765ca8000
> NIP: d000000006394f74 LR: c00000000007a1dc CTR: c00000000007a1a0
> REGS: c000000765cab420 TRAP: 0901   Not tainted  (3.14.0-rc6-00145-ga4ecdf8-dirty)
> MSR: 9000000000009032 <SF,HV,EE,ME,IR,DR,RI>  CR: 24002824  XER: 20000000
> CFAR: c00000000007a2b4 SOFTE: 1 
> GPR00: c00000000007a1dc c000000765cab6a0 c000000000d518e8 000000aae8fb0387 
> GPR04: fffffff3dbd12408 0000000000000000 0000000000000007 9000000000009032 
> GPR08: d000000006394f74 c00000078b880000 9000000000001032 c00000000007a1a0 
> GPR12: 0000000000000500 c000000001e0d000 
> NIP [d000000006394f74] .__kvmppc_vcore_entry+0x140/0x1ac [kvm_hv]
> LR [c00000000007a1dc] kvmppc_call_hv_entry+0x8/0xe8
> Call Trace:
> [c000000765cab6a0] [d000000006394f74] .__kvmppc_vcore_entry+0x140/0x1ac [kvm_hv] (unreliable)
> [c000000765cab870] [d000000006394148] .kvmppc_vcpu_run_hv+0x8b8/0x1520 [kvm_hv]
> [c000000765cab9f0] [d000000005e5c250] .kvmppc_vcpu_run+0x30/0x50 [kvm]
> [c000000765caba60] [d000000005e599f4] .kvm_arch_vcpu_ioctl_run+0x54/0x1b0 [kvm]
> [c000000765cabaf0] [d000000005e54588] .kvm_vcpu_ioctl+0x478/0x740 [kvm]
> [c000000765cabcb0] [c0000000001ffcd4] .do_vfs_ioctl+0x4a4/0x760
> [c000000765cabd90] [c0000000001fffe8] .SyS_ioctl+0x58/0xb0
> [c000000765cabe30] [c00000000000a158] syscall_exit+0x0/0x98
> Instruction dump:
> 7d083a14 f90d03c0 60000000 60000000 60000000 60000000 60000000 60000000 
> 60000000 60000000 60000000 48003af1 <e8410028> e9c100e0 e9e100e8 ea0100f0 
>
> Anton