KVM: x86: switch unhandled MSR printk's to tracepoints

[Marcelo Tosatti <mtosatti@redhat.com>]

Such messages in the system log very often cause confusion because users
understand the "kvm: unhandled MSR" messages as errors.

Switch to trace points, making the information available on demand.

diff --git a/arch/x86/kvm/trace.h b/arch/x86/kvm/trace.h
index fe5e00e..c461368 100644
--- a/arch/x86/kvm/trace.h
+++ b/arch/x86/kvm/trace.h
@@ -318,6 +318,40 @@ TRACE_EVENT(kvm_msr,
 #define trace_kvm_msr_write_ex(ecx, data)  trace_kvm_msr(1, ecx, data, true)
 
 /*
+ * Tracepoint for unhandled guest MSR access.
+ */
+TRACE_EVENT(kvm_msr_unhandled,
+	TP_PROTO(bool write, u32 ecx, u64 data, bool unhandled),
+	TP_ARGS(write, ecx, data, unhandled),
+
+	TP_STRUCT__entry(
+		__field(	u32,		ecx		)
+		__field(	u64,		data		)
+		__field(	bool,		write		)
+		__field(	bool,		unhandled	)
+	),
+
+	TP_fast_assign(
+		__entry->ecx		= ecx;
+		__entry->data		= data;
+		__entry->write		= write;
+		__entry->unhandled	= unhandled;
+	),
+
+	TP_printk("unhandled MSR %s %x = 0x%llx (%s)",
+		  __entry->write ? "write" : "read",
+		  __entry->ecx, __entry->data,
+		  __entry->unhandled ? "injected #GP" : "ignored")
+);
+
+#define trace_kvm_msr_unhandled_read(ecx) trace_kvm_msr(0, ecx, 0, false)
+#define trace_kvm_msr_unhandled_read_ex(ecx) trace_kvm_msr(0, ecx, 0, true)
+#define trace_kvm_msr_unhandled_write(ecx, data)	\
+					  trace_kvm_msr(1, ecx, data, false)
+#define trace_kvm_msr_unhandled_write_ex(ecx, data)	\
+					  trace_kvm_msr(1, ecx, data, true)
+
+/*
  * Tracepoint for guest CR access.
  */
 TRACE_EVENT(kvm_cr,
diff --git a/arch/x86/kvm/x86.c b/arch/x86/kvm/x86.c
index c243b81..f5abcce 100644
--- a/arch/x86/kvm/x86.c
+++ b/arch/x86/kvm/x86.c
@@ -1772,8 +1772,7 @@ static int set_msr_hyperv_pw(struct kvm_vcpu *vcpu, u32 msr, u64 data)
 		break;
 	}
 	default:
-		vcpu_unimpl(vcpu, "HYPER-V unimplemented wrmsr: 0x%x "
-			    "data 0x%llx\n", msr, data);
+		trace_kvm_msr_unhandled_write_ex(msr, data);
 		return 1;
 	}
 	return 0;
@@ -1805,8 +1804,7 @@ static int set_msr_hyperv(struct kvm_vcpu *vcpu, u32 msr, u64 data)
 	case HV_X64_MSR_TPR:
 		return kvm_hv_vapic_msr_write(vcpu, APIC_TASKPRI, data);
 	default:
-		vcpu_unimpl(vcpu, "HYPER-V unimplemented wrmsr: 0x%x "
-			    "data 0x%llx\n", msr, data);
+		trace_kvm_msr_unhandled_write_ex(msr, data);
 		return 1;
 	}
 
@@ -1888,15 +1886,13 @@ int kvm_set_msr_common(struct kvm_vcpu *vcpu, struct msr_data *msr_info)
 		data &= ~(u64)0x100;	/* ignore ignne emulation enable */
 		data &= ~(u64)0x8;	/* ignore TLB cache disable */
 		if (data != 0) {
-			vcpu_unimpl(vcpu, "unimplemented HWCR wrmsr: 0x%llx\n",
-				    data);
+			trace_kvm_msr_unhandled_write_ex(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);
+			trace_kvm_msr_unhandled_write_ex(msr, data);
 			return 1;
 		}
 		break;
@@ -1911,8 +1907,8 @@ int kvm_set_msr_common(struct kvm_vcpu *vcpu, struct msr_data *msr_info)
 			   thus reserved and should throw a #GP */
 			return 1;
 		}
-		vcpu_unimpl(vcpu, "%s: MSR_IA32_DEBUGCTLMSR 0x%llx, nop\n",
-			    __func__, data);
+
+		trace_kvm_msr_unhandled_write(msr, data);
 		break;
 	case MSR_IA32_UCODE_REV:
 	case MSR_IA32_UCODE_WRITE:
@@ -2020,8 +2016,7 @@ int kvm_set_msr_common(struct kvm_vcpu *vcpu, struct msr_data *msr_info)
 	case MSR_K7_EVNTSEL2:
 	case MSR_K7_EVNTSEL3:
 		if (data != 0)
-			vcpu_unimpl(vcpu, "unimplemented perfctr wrmsr: "
-				    "0x%x data 0x%llx\n", msr, data);
+			trace_kvm_msr_unhandled_write(msr, data);
 		break;
 	/* at least RHEL 4 unconditionally writes to the perfctr registers,
 	 * so we ignore writes to make it happy.
@@ -2030,8 +2025,7 @@ int kvm_set_msr_common(struct kvm_vcpu *vcpu, struct msr_data *msr_info)
 	case MSR_K7_PERFCTR1:
 	case MSR_K7_PERFCTR2:
 	case MSR_K7_PERFCTR3:
-		vcpu_unimpl(vcpu, "unimplemented perfctr wrmsr: "
-			    "0x%x data 0x%llx\n", msr, data);
+		trace_kvm_msr_unhandled_write(msr, data);
 		break;
 	case MSR_P6_PERFCTR0:
 	case MSR_P6_PERFCTR1:
@@ -2042,8 +2036,7 @@ int kvm_set_msr_common(struct kvm_vcpu *vcpu, struct msr_data *msr_info)
 			return kvm_pmu_set_msr(vcpu, msr, data);
 
 		if (pr || data != 0)
-			vcpu_unimpl(vcpu, "disabled perfctr wrmsr: "
-				    "0x%x data 0x%llx\n", msr, data);
+			trace_kvm_msr_unhandled_write(msr, data);
 		break;
 	case MSR_K7_CLK_CTL:
 		/*
@@ -2069,7 +2062,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.
 		 */
-		vcpu_unimpl(vcpu, "ignored wrmsr: 0x%x data %llx\n", msr, data);
+		trace_kvm_msr_unhandled_write(msr, data);
 		break;
 	case MSR_AMD64_OSVW_ID_LENGTH:
 		if (!guest_cpuid_has_osvw(vcpu))
@@ -2087,12 +2080,10 @@ int kvm_set_msr_common(struct kvm_vcpu *vcpu, struct msr_data *msr_info)
 		if (kvm_pmu_msr(vcpu, msr))
 			return kvm_pmu_set_msr(vcpu, msr, data);
 		if (!ignore_msrs) {
-			vcpu_unimpl(vcpu, "unhandled wrmsr: 0x%x data %llx\n",
-				    msr, data);
+			trace_kvm_msr_unhandled_write_ex(msr, data);
 			return 1;
 		} else {
-			vcpu_unimpl(vcpu, "ignored wrmsr: 0x%x data %llx\n",
-				    msr, data);
+			trace_kvm_msr_unhandled_write(msr, data);
 			break;
 		}
 	}
@@ -2195,7 +2186,7 @@ static int get_msr_hyperv_pw(struct kvm_vcpu *vcpu, u32 msr, u64 *pdata)
 		data = kvm->arch.hv_hypercall;
 		break;
 	default:
-		vcpu_unimpl(vcpu, "Hyper-V unhandled rdmsr: 0x%x\n", msr);
+		trace_kvm_msr_unhandled_write_ex(msr, data);
 		return 1;
 	}
 
@@ -2226,7 +2217,7 @@ static int get_msr_hyperv(struct kvm_vcpu *vcpu, u32 msr, u64 *pdata)
 		data = vcpu->arch.hv_vapic;
 		break;
 	default:
-		vcpu_unimpl(vcpu, "Hyper-V unhandled rdmsr: 0x%x\n", msr);
+		trace_kvm_msr_unhandled_read_ex(msr);
 		return 1;
 	}
 	*pdata = data;
@@ -2385,10 +2376,10 @@ int kvm_get_msr_common(struct kvm_vcpu *vcpu, u32 msr, u64 *pdata)
 		if (kvm_pmu_msr(vcpu, msr))
 			return kvm_pmu_get_msr(vcpu, msr, pdata);
 		if (!ignore_msrs) {
-			vcpu_unimpl(vcpu, "unhandled rdmsr: 0x%x\n", msr);
+			trace_kvm_msr_unhandled_read_ex(msr);
 			return 1;
 		} else {
-			vcpu_unimpl(vcpu, "ignored rdmsr: 0x%x\n", msr);
+			trace_kvm_msr_unhandled_read(msr);
 			data = 0;
 		}
 		break;