Re: AVIC warning - what does it mean?

[Andreas Hartmann <andihartmann@01019freenet.de>]

On 09/08/2017 at 03:31 PM Radim Krcmar wrote:
> 2017-09-08 13:23+0200, Andreas Hartmann:
>>> On 08/09/2017 11:58, Andreas Hartmann wrote:
>>>
>>>> If AVIC is enabled, I'm usually getting one warning like the one below a
>>>> few minutes after the VM has been started.
>>>>
>>>> What does it mean?
>>>>
>>>> There isn't any problem with that VM - it's just working as expected. If
>>>> AVIC is disabled, the warning doesn't come up and the VM works fine, too.
>>>>
>>>> Base is a Ryzen system (RMA'd CPU w/o gcc segfaults meanwhile and X370
>>>> chipset (ASUS Prime X370-PRO with Bios 0810)). Linux is 4.9.48.
>>>>
>>>>
>>>> [ 1603.482692] ------------[ cut here ]------------
>>>> [ 1603.482702] WARNING: CPU: 1 PID: 2936 at ../arch/x86/kvm/svm.c:1484 avic_vcpu_load+0x162/0x190 [kvm_amd]
>>>> [ 1603.482703] Modules linked in: sr_mod cdrom uas usb_storage vhost_net tun vhost macvtap macvlan igb dca nf_log_ipv4 nf_log_common xt_LOG ipt_REJECT nf_reject_ipv4 xt_tcpudp nf_conntrack_ipv4 nf_defrag_ipv4 xt_conntrack nf_conntrack iptable_filter ip_tables x_tables vfio_pci vfio_iommu_type1 vfio_virqfd vfio br_netfilter bridge stp llc iscsi_ibft iscsi_boot_sysfs snd_hda_codec_generic snd_hda_codec_hdmi snd_hda_intel snd_hda_codec snd_hda_core snd_hwdep kvm_amd snd_pcm eeepc_wmi asus_wmi kvm sparse_keymap snd_seq rfkill video snd_seq_device mxm_wmi irqbypass snd_timer sp5100_tco i2c_piix4 snd pcspkr e1000e soundcore ptp pps_core fjes pinctrl_amd gpio_amdpt acpi_cpufreq gpio_generic 8250_dw tpm_tis shpchp i2c_designware_platform wmi i2c_designware_core tpm_tis_core button tpm nfsd auth_rp
>>>>   cgss nfs_acl
>>>> [ 1603.482740]  lockd grace sunrpc xfs libcrc32c dm_crypt algif_skcipher af_alg hid_generic usbhid raid1 md_mod amdkfd amd_iommu_v2 crct10dif_pclmul crc32_pclmul crc32c_intel ghash_clmulni_intel radeon i2c_algo_bit drm_kms_helper syscopyarea sysfillrect sysimgblt fb_sys_fops ttm serio_raw drm ccp xhci_pci xhci_hcd usbcore aesni_intel aes_x86_64 glue_helper lrw ablk_helper cryptd ata_generic pata_atiixp dm_mirror dm_region_hash dm_log sg thermal dm_multipath dm_mod scsi_dh_rdac scsi_dh_emc scsi_dh_alua
>>>> [ 1603.482766] CPU: 1 PID: 2936 Comm: CPU 2/KVM Not tainted 4.9.48-1.1-default #1
>>>> [ 1603.482767] Hardware name: System manufacturer System Product Name/PRIME X370-PRO, BIOS 0810 08/01/2017
>>>> [ 1603.482768]  ffffab614aa4fcb8 ffffffff893c14fa 0000000000000000 0000000000000000
>>>> [ 1603.482772]  ffffab614aa4fcf8 ffffffff89085da1 000005cc004b6f7f 0000000000000001
>>>> [ 1603.482774]  c0000007ea4bc001 0000000000000001 000001753dd1e17d ffff9e84ea7e0140
>>>> [ 1603.482776] Call Trace:
>>>> [ 1603.482798]  [<ffffffff893c14fa>] dump_stack+0x63/0x89
>>>> [ 1603.482804]  [<ffffffff89085da1>] __warn+0xd1/0xf0
>>>> [ 1603.482809]  [<ffffffff89085e8d>] warn_slowpath_null+0x1d/0x20
>>>> [ 1603.482813]  [<ffffffffc15ade42>] avic_vcpu_load+0x162/0x190 [kvm_amd]
>>>> [ 1603.482849]  [<ffffffffc0950da4>] ? kvm_cpu_has_interrupt+0x44/0x50 [kvm]
>>>> [ 1603.482852]  [<ffffffffc15ae138>] svm_vcpu_unblocking+0x18/0x20 [kvm_amd]
>>>> [ 1603.482868]  [<ffffffffc091b424>] kvm_vcpu_block+0xc4/0x310 [kvm]
>>>> [ 1603.482889]  [<ffffffffc0937fac>] kvm_arch_vcpu_ioctl_run+0x19c/0x400 [kvm]
>>>> [ 1603.482906]  [<ffffffffc091cc42>] kvm_vcpu_ioctl+0x312/0x5e0 [kvm]
>>>> [ 1603.482913]  [<ffffffff8910d10f>] ? do_futex+0x10f/0x510
>>>> [ 1603.482916]  [<ffffffff8923ec06>] do_vfs_ioctl+0x96/0x5b0
>>>> [ 1603.482921]  [<ffffffff89249767>] ? __fget+0x77/0xb0
>>>> [ 1603.482922]  [<ffffffff8923f199>] SyS_ioctl+0x79/0x90
>>>> [ 1603.482927]  [<ffffffff8900393b>] do_syscall_64+0x5b/0xd0
>>>> [ 1603.482932]  [<ffffffff89719c2f>] entry_SYSCALL64_slow_path+0x25/0x25
>>>> [ 1603.484799] ---[ end trace d24b045704bb6ae7 ]---

[...]

> I'm thinking this happens if the VCPU is preempted in avic_set_running()
> after 'svm->avic_is_running = true' and before avic_vcpu_load().
> avic_vcpu_load() is then called from both avic_set_running() and
> svm_vcpu_load().
> 
> The warning does not reveal any harmful bug.  Disabling preemption in
> avic_set_running() would allow us to keep the protective warning.
> (It seems to be slightly better than remembeging and restoring the avic
>  state on sched out/in.)
> 
> Can you try the following patch?

I'm currently testing. I'll be back after I'm sure that the patch fixes 
the problem (or not).


Thanks,
regards,
Andreas

> 
> diff --git a/arch/x86/kvm/svm.c b/arch/x86/kvm/svm.c
> index 968f38dcb864..6b123f375d66 100644
> --- a/arch/x86/kvm/svm.c
> +++ b/arch/x86/kvm/svm.c
> @@ -1572,11 +1572,15 @@ static void avic_set_running(struct kvm_vcpu *vcpu, bool is_run)
>  {
>  	struct vcpu_svm *svm = to_svm(vcpu);
>  
> +	preempt_disable();
> +
>  	svm->avic_is_running = is_run;
>  	if (is_run)
>  		avic_vcpu_load(vcpu, vcpu->cpu);
>  	else
>  		avic_vcpu_put(vcpu);
> +
> +	preempt_enable();
>  }
>  
>  static void svm_vcpu_reset(struct kvm_vcpu *vcpu, bool init_event)
>