Re: [PATCH 2/6] KVM: x86/pmu: Gate all "unimplemented MSR" prints on report_ignored_msrs

[Vitaly Kuznetsov]

Sean Christopherson <seanjc@xxxxxxxxxx> writes:

> Add helpers to print unimplemented MSR accesses and condition all such
> prints on report_ignored_msrs, i.e. honor userspace's request to not
> print unimplemented MSRs.  Even though vcpu_unimpl() is ratelimited,
> printing can still be problematic, e.g. if a print gets stalled when host
> userspace is writing MSRs during live migration, an effective stall can
> result in very noticeable disruption in the guest.
>
> E.g. the profile below was taken while calling KVM_SET_MSRS on the PMU
> counters while the PMU was disabled in KVM.
>
>   -   99.75%     0.00%  [.] __ioctl
>    - __ioctl
>       - 99.74% entry_SYSCALL_64_after_hwframe
>            do_syscall_64
>            sys_ioctl
>          - do_vfs_ioctl
>             - 92.48% kvm_vcpu_ioctl
>                - kvm_arch_vcpu_ioctl
>                   - 85.12% kvm_set_msr_ignored_check
>                        svm_set_msr
>                        kvm_set_msr_common
>                        printk
>                        vprintk_func
>                        vprintk_default
>                        vprintk_emit
>                        console_unlock
>                        call_console_drivers
>                        univ8250_console_write
>                        serial8250_console_write
>                        uart_console_write
>
> Reported-by: Aaron Lewis <aaronlewis@xxxxxxxxxx>
> Signed-off-by: Sean Christopherson <seanjc@xxxxxxxxxx>
> ---
>  arch/x86/kvm/hyperv.c  | 10 ++++------
>  arch/x86/kvm/svm/svm.c |  5 ++---
>  arch/x86/kvm/vmx/vmx.c |  4 +---
>  arch/x86/kvm/x86.c     | 18 +++++-------------
>  arch/x86/kvm/x86.h     | 12 ++++++++++++
>  5 files changed, 24 insertions(+), 25 deletions(-)
>
> diff --git a/arch/x86/kvm/hyperv.c b/arch/x86/kvm/hyperv.c
> index 71aff0edc0ed..3eb8caf87ee4 100644
> --- a/arch/x86/kvm/hyperv.c
> +++ b/arch/x86/kvm/hyperv.c
> @@ -1430,8 +1430,7 @@ static int kvm_hv_set_msr_pw(struct kvm_vcpu *vcpu, u32 msr, u64 data,
>  	case HV_X64_MSR_SYNDBG_CONTROL ... HV_X64_MSR_SYNDBG_PENDING_BUFFER:
>  		return syndbg_set_msr(vcpu, msr, data, host);
>  	default:
> -		vcpu_unimpl(vcpu, "Hyper-V unhandled wrmsr: 0x%x data 0x%llx\n",
> -			    msr, data);
> +		kvm_pr_unimpl_wrmsr(vcpu, msr, data);
>  		return 1;
>  	}
>  	return 0;
> @@ -1552,8 +1551,7 @@ static int kvm_hv_set_msr(struct kvm_vcpu *vcpu, u32 msr, u64 data, bool host)
>  			return 1;
>  		break;
>  	default:
> -		vcpu_unimpl(vcpu, "Hyper-V unhandled wrmsr: 0x%x data 0x%llx\n",
> -			    msr, data);
> +		kvm_pr_unimpl_wrmsr(vcpu, msr, data);
>  		return 1;
>  	}
>  
> @@ -1608,7 +1606,7 @@ static int kvm_hv_get_msr_pw(struct kvm_vcpu *vcpu, u32 msr, u64 *pdata,
>  	case HV_X64_MSR_SYNDBG_CONTROL ... HV_X64_MSR_SYNDBG_PENDING_BUFFER:
>  		return syndbg_get_msr(vcpu, msr, pdata, host);
>  	default:
> -		vcpu_unimpl(vcpu, "Hyper-V unhandled rdmsr: 0x%x\n", msr);
> +		kvm_pr_unimpl_rdmsr(vcpu, msr);
>  		return 1;
>  	}
>  
> @@ -1673,7 +1671,7 @@ static int kvm_hv_get_msr(struct kvm_vcpu *vcpu, u32 msr, u64 *pdata,
>  		data = APIC_BUS_FREQUENCY;
>  		break;
>  	default:
> -		vcpu_unimpl(vcpu, "Hyper-V unhandled rdmsr: 0x%x\n", msr);
> +		kvm_pr_unimpl_rdmsr(vcpu, msr);
>  		return 1;
>  	}
>  	*pdata = data;
> diff --git a/arch/x86/kvm/svm/svm.c b/arch/x86/kvm/svm/svm.c
> index d13cf53e7390..dd21e8b1a259 100644
> --- a/arch/x86/kvm/svm/svm.c
> +++ b/arch/x86/kvm/svm/svm.c
> @@ -3015,8 +3015,7 @@ static int svm_set_msr(struct kvm_vcpu *vcpu, struct msr_data *msr)
>  		break;
>  	case MSR_IA32_DEBUGCTLMSR:
>  		if (!lbrv) {
> -			vcpu_unimpl(vcpu, "%s: MSR_IA32_DEBUGCTL 0x%llx, nop\n",
> -				    __func__, data);
> +			kvm_pr_unimpl_wrmsr(vcpu, ecx, data);
>  			break;
>  		}
>  		if (data & DEBUGCTL_RESERVED_BITS)
> @@ -3045,7 +3044,7 @@ static int svm_set_msr(struct kvm_vcpu *vcpu, struct msr_data *msr)
>  	case MSR_VM_CR:
>  		return svm_set_vm_cr(vcpu, data);
>  	case MSR_VM_IGNNE:
> -		vcpu_unimpl(vcpu, "unimplemented wrmsr: 0x%x data 0x%llx\n", ecx, data);
> +		kvm_pr_unimpl_wrmsr(vcpu, ecx, data);
>  		break;
>  	case MSR_AMD64_DE_CFG: {
>  		struct kvm_msr_entry msr_entry;
> diff --git a/arch/x86/kvm/vmx/vmx.c b/arch/x86/kvm/vmx/vmx.c
> index c788aa382611..8f0f67c75f35 100644
> --- a/arch/x86/kvm/vmx/vmx.c
> +++ b/arch/x86/kvm/vmx/vmx.c
> @@ -2206,9 +2206,7 @@ static int vmx_set_msr(struct kvm_vcpu *vcpu, struct msr_data *msr_info)
>  
>  		invalid = data & ~vmx_get_supported_debugctl(vcpu, msr_info->host_initiated);
>  		if (invalid & (DEBUGCTLMSR_BTF|DEBUGCTLMSR_LBR)) {
> -			if (report_ignored_msrs)
> -				vcpu_unimpl(vcpu, "%s: BTF|LBR in IA32_DEBUGCTLMSR 0x%llx, nop\n",
> -					    __func__, data);
> +			kvm_pr_unimpl_wrmsr(vcpu, msr_index, data);
>  			data &= ~(DEBUGCTLMSR_BTF|DEBUGCTLMSR_LBR);
>  			invalid &= ~(DEBUGCTLMSR_BTF|DEBUGCTLMSR_LBR);
>  		}
> diff --git a/arch/x86/kvm/x86.c b/arch/x86/kvm/x86.c
> index ad95ce92a154..d4a610ffe2b8 100644
> --- a/arch/x86/kvm/x86.c
> +++ b/arch/x86/kvm/x86.c
> @@ -3560,7 +3560,6 @@ static void record_steal_time(struct kvm_vcpu *vcpu)
>  
>  int kvm_set_msr_common(struct kvm_vcpu *vcpu, struct msr_data *msr_info)
>  {
> -	bool pr = false;
>  	u32 msr = msr_info->index;
>  	u64 data = msr_info->data;
>  
> @@ -3606,15 +3605,13 @@ int kvm_set_msr_common(struct kvm_vcpu *vcpu, struct msr_data *msr_info)
>  		if (data == BIT_ULL(18)) {
>  			vcpu->arch.msr_hwcr = data;
>  		} else if (data != 0) {
> -			vcpu_unimpl(vcpu, "unimplemented HWCR wrmsr: 0x%llx\n",
> -				    data);
> +			kvm_pr_unimpl_wrmsr(vcpu, msr, data);
>  			return 1;
>  		}
>  		break;
>  	case MSR_FAM10H_MMIO_CONF_BASE:
>  		if (data != 0) {
> -			vcpu_unimpl(vcpu, "unimplemented MMIO_CONF_BASE wrmsr: "
> -				    "0x%llx\n", data);
> +			kvm_pr_unimpl_wrmsr(vcpu, msr, data);
>  			return 1;
>  		}
>  		break;
> @@ -3794,16 +3791,13 @@ int kvm_set_msr_common(struct kvm_vcpu *vcpu, struct msr_data *msr_info)
>  
>  	case MSR_K7_PERFCTR0 ... MSR_K7_PERFCTR3:
>  	case MSR_P6_PERFCTR0 ... MSR_P6_PERFCTR1:
> -		pr = true;
> -		fallthrough;
>  	case MSR_K7_EVNTSEL0 ... MSR_K7_EVNTSEL3:
>  	case MSR_P6_EVNTSEL0 ... MSR_P6_EVNTSEL1:
>  		if (kvm_pmu_is_valid_msr(vcpu, msr))
>  			return kvm_pmu_set_msr(vcpu, msr_info);
>  
> -		if (pr || data != 0)
> -			vcpu_unimpl(vcpu, "disabled perfctr wrmsr: "
> -				    "0x%x data 0x%llx\n", msr, data);
> +		if (data)
> +			kvm_pr_unimpl_wrmsr(vcpu, msr, data);

The logic here was that "*_PERFCTR*" MSRs are reported even when 'data
== 0' but looking at the commit 5753785fa977 ("KVM: do not #GP on perf
MSR writes when vPMU is disabled") I can't really say why it was needed.

>  		break;
>  	case MSR_K7_CLK_CTL:
>  		/*
> @@ -3831,9 +3825,7 @@ int kvm_set_msr_common(struct kvm_vcpu *vcpu, struct msr_data *msr_info)
>  		/* Drop writes to this legacy MSR -- see rdmsr
>  		 * counterpart for further detail.
>  		 */
> -		if (report_ignored_msrs)
> -			vcpu_unimpl(vcpu, "ignored wrmsr: 0x%x data 0x%llx\n",
> -				msr, data);
> +		kvm_pr_unimpl_wrmsr(vcpu, msr, data);
>  		break;
>  	case MSR_AMD64_OSVW_ID_LENGTH:
>  		if (!guest_cpuid_has(vcpu, X86_FEATURE_OSVW))
> diff --git a/arch/x86/kvm/x86.h b/arch/x86/kvm/x86.h
> index 9de72586f406..f3554bf05201 100644
> --- a/arch/x86/kvm/x86.h
> +++ b/arch/x86/kvm/x86.h
> @@ -331,6 +331,18 @@ extern bool report_ignored_msrs;
>  
>  extern bool eager_page_split;
>  
> +static inline void kvm_pr_unimpl_wrmsr(struct kvm_vcpu *vcpu, u32 msr, u64 data)
> +{
> +	if (report_ignored_msrs)
> +		vcpu_unimpl(vcpu, "Unhandled WRMSR(0x%x) = 0x%llx\n", msr, data);
> +}
> +
> +static inline void kvm_pr_unimpl_rdmsr(struct kvm_vcpu *vcpu, u32 msr)
> +{
> +	if (report_ignored_msrs)
> +		vcpu_unimpl(vcpu, "Unhandled RDMSR(0x%x)\n", msr);
> +}
> +
>  static inline u64 nsec_to_cycles(struct kvm_vcpu *vcpu, u64 nsec)
>  {
>  	return pvclock_scale_delta(nsec, vcpu->arch.virtual_tsc_mult,

Reviewed-by: Vitaly Kuznetsov <vkuznets@xxxxxxxxxx>

-- 
Vitaly