Skip to contentSkip to conversation

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

PATCH Marcelo Tosatti 2 participants 3 messages Feb 11, 2013 – Feb 12, 2013

Subsystems (3)
x86 KVM KVM x86
lore
Share & tools
lore

Marcelo Tosatti

author
#0 lore raw

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.

arch/x86/kvm/trace.h +34 -0
index fe5e00e..c461368 100644
@@ -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,
arch/x86/kvm/x86.c +16 -25

122 lines not on this page · raw message

#1 lore raw
Quoted 4 lines · Marcelo Tosatti

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

They are errors. Linux compiled with PV support ignores them, but other guest OSes or Linux without PV will crash. Some indication that guest crash due to use of unsupported MSR is a helpful hint where to look.

Quoted 1 line

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

What new information those trace points provide that we cannot get today from trace_kvm_msr()?

Quoted 174 lines
arch/x86/kvm/trace.h +34 -0
index fe5e00e..c461368 100644
@@ -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,
arch/x86/kvm/x86.c +14 -23
index c243b81..f5abcce 100644
@@ -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);

arch/x86/kvm/x86.c int kvm_get_msr_common(struct kvm_vcpu *vcpu, u32 msr, u64 *pdata) · line 2385

Quoted 10 lines
arch/x86/kvm/x86.c +2 -2
 		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;

--
Gleb.

author
#2 lore raw
Quoted 8 lines · Gleb Natapov
Quoted 4 lines · Marcelo Tosatti

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

They are errors. Linux compiled with PV support ignores them, but other guest OSes or Linux without PV will crash. Some indication that guest crash due to use of unsupported MSR is a helpful hint where to look.

OK, closing
https://bugzilla.redhat.com/show_bug.cgi?id=883216
as wontfix because printk_ratelimit renders the messages unreliable.

Quoted 3 lines
Quoted 1 line

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

What new information those trace points provide that we cannot get today from trace_kvm_msr()?

None.