[PATCH 2/2] KVM: Trace emulated instructions
Log emulated instructions in ftrace, especially if they failed.
Signed-off-by: Avi Kivity a...@redhat.com
---
arch/x86/kvm/trace.h | 86 ++
arch/x86/kvm/x86.c |4 ++
2 files changed, 90 insertions(+), 0 deletions(-)
diff --git a/arch/x86/kvm/trace.h b/arch/x86/kvm/trace.h
index 32c912c..a6544b8 100644
--- a/arch/x86/kvm/trace.h
+++ b/arch/x86/kvm/trace.h
@@ -603,6 +603,92 @@ TRACE_EVENT(kvm_skinit,
__entry-rip, __entry-slb)
);
+#define __print_insn(insn, ilen) ({ \
+ int i; \
+ const char *ret = p-buffer + p-len;\
+\
+ for (i = 0; i ilen; ++i) \
+ trace_seq_printf(p, %02x, insn[i]); \
+ trace_seq_printf(p, %c, 0);\
+ ret; \
+ })
+
+#define KVM_EMUL_INSN_F_CR0_PE (1 0)
+#define KVM_EMUL_INSN_F_EFL_VM (1 1)
+#define KVM_EMUL_INSN_F_CS_D (1 2)
+#define KVM_EMUL_INSN_F_CS_L (1 3)
+
+#define kvm_trace_symbol_emul_flags \
+ { 0,real }, \
+ { KVM_EMUL_INSN_F_CR0_PE \
+ | KVM_EMUL_INSN_F_EFL_VM, vm16 }, \
+ { KVM_EMUL_INSN_F_CR0_PE, prot16 }, \
+ { KVM_EMUL_INSN_F_CR0_PE \
+ | KVM_EMUL_INSN_F_CS_D, prot32 }, \
+ { KVM_EMUL_INSN_F_CR0_PE \
+ | KVM_EMUL_INSN_F_CS_L, prot64 }
+
+#define kei_decode_mode(mode) ({ \
+ u8 flags = 0xff;\
+ switch (mode) { \
+ case X86EMUL_MODE_REAL: \
+ flags = 0; \
+ break; \
+ case X86EMUL_MODE_VM86: \
+ flags = KVM_EMUL_INSN_F_EFL_VM; \
+ break; \
+ case X86EMUL_MODE_PROT16: \
+ flags = KVM_EMUL_INSN_F_CR0_PE; \
+ break; \
+ case X86EMUL_MODE_PROT32: \
+ flags = KVM_EMUL_INSN_F_CR0_PE \
+ | KVM_EMUL_INSN_F_CS_D; \
+ break; \
+ case X86EMUL_MODE_PROT64: \
+ flags = KVM_EMUL_INSN_F_CR0_PE \
+ | KVM_EMUL_INSN_F_CS_L; \
+ break; \
+ } \
+ flags; \
+ })
+
+TRACE_EVENT(kvm_emulate_insn,
+ TP_PROTO(struct kvm_vcpu *vcpu, __u8 failed),
+ TP_ARGS(vcpu, failed),
+
+ TP_STRUCT__entry(
+ __field(__u64, rip )
+ __field(__u32, csbase)
+ __field(__u8, len )
+ __array(__u8, insn,15 )
+ __field(__u8, flags )
+ __field(__u8, failed)
+ ),
+
+ TP_fast_assign(
+ __entry-rip = vcpu-arch.emulate_ctxt.decode.fetch.start;
+ __entry-csbase = kvm_x86_ops-get_segment_base(vcpu,
VCPU_SREG_CS);
+ __entry-len = vcpu-arch.emulate_ctxt.decode.eip
+ - vcpu-arch.emulate_ctxt.decode.fetch.start;
+ memcpy(__entry-insn,
+ vcpu-arch.emulate_ctxt.decode.fetch.data,
+ 15);
+ __entry-flags = kei_decode_mode(vcpu-arch.emulate_ctxt.mode);
+ __entry-failed = failed;
+ ),
+
+ TP_printk(%x:%llx:%s (%s)%s,
+ __entry-csbase, __entry-rip,
+ __print_insn(__entry-insn, __entry-len),
+ __print_symbolic(__entry-flags,
+ kvm_trace_symbol_emul_flags),
+ __entry-failed ? failed :
+ )
+ );
+
+#define trace_kvm_emulate_insn_start(vcpu) trace_kvm_emulate_insn(vcpu, 0)
+#define trace_kvm_emulate_insn_failed(vcpu) trace_kvm_emulate_insn(vcpu, 1)
+
#endif /* _TRACE_KVM_H */
#undef TRACE_INCLUDE_PATH
diff --git a/arch/x86/kvm/x86.c b/arch/x86/kvm/x86.c
index fd5c3d3..b3adb5e 100644
--- a/arch/x86/kvm/x86.c
+++ b/arch/x86/kvm/x86.c
@@ -3716,6 +3716,7 @@ int emulate_instruction(struct kvm_vcpu *vcpu,
? X86EMUL_MODE_PROT32 : X86EMUL_MODE_PROT16;
r =
Re: [PATCH 2/2] KVM: Trace emulated instructions
On Tue, Apr 06, 2010 at 12:38:00AM +0300, Avi Kivity wrote: On 04/05/2010 09:44 PM, Marcelo Tosatti wrote: On Thu, Mar 25, 2010 at 05:02:56PM +0200, Avi Kivity wrote: Log emulated instructions in ftrace, especially if they failed. Why not log all emulated instructions? Seems useful to me. That was the intent, but it didn't pan out. I tried to avoid double-logging where an mmio read is dispatched to userspace, and the instruction is re-executed. Perhaps we should split it into a decode trace and execution result trace? Less easy to use but avoids confusion due to duplication. I don't think duplication introduces confusion, as long as one can see rip on the trace entry (the duplication can actually be useful). -- To unsubscribe from this list: send the line unsubscribe kvm in the body of a message to majord...@vger.kernel.org More majordomo info at http://vger.kernel.org/majordomo-info.html
Re: [PATCH 2/2] KVM: Trace emulated instructions
On Thu, Mar 25, 2010 at 05:02:56PM +0200, Avi Kivity wrote:
Log emulated instructions in ftrace, especially if they failed.
Signed-off-by: Avi Kivity a...@redhat.com
---
arch/x86/kvm/trace.h | 86
++
arch/x86/kvm/x86.c |4 ++
2 files changed, 90 insertions(+), 0 deletions(-)
diff --git a/arch/x86/kvm/trace.h b/arch/x86/kvm/trace.h
index 32c912c..a6544b8 100644
--- a/arch/x86/kvm/trace.h
+++ b/arch/x86/kvm/trace.h
@@ -603,6 +603,92 @@ TRACE_EVENT(kvm_skinit,
__entry-rip, __entry-slb)
);
+#define __print_insn(insn, ilen) ({ \
+ int i; \
+ const char *ret = p-buffer + p-len;\
+ \
+ for (i = 0; i ilen; ++i) \
+ trace_seq_printf(p, %02x, insn[i]); \
+ trace_seq_printf(p, %c, 0);\
+ ret; \
+ })
+
+#define KVM_EMUL_INSN_F_CR0_PE (1 0)
+#define KVM_EMUL_INSN_F_EFL_VM (1 1)
+#define KVM_EMUL_INSN_F_CS_D (1 2)
+#define KVM_EMUL_INSN_F_CS_L (1 3)
+
+#define kvm_trace_symbol_emul_flags\
+ { 0,real }, \
+ { KVM_EMUL_INSN_F_CR0_PE \
+ | KVM_EMUL_INSN_F_EFL_VM, vm16 }, \
+ { KVM_EMUL_INSN_F_CR0_PE, prot16 }, \
+ { KVM_EMUL_INSN_F_CR0_PE \
+ | KVM_EMUL_INSN_F_CS_D, prot32 }, \
+ { KVM_EMUL_INSN_F_CR0_PE \
+ | KVM_EMUL_INSN_F_CS_L, prot64 }
+
+#define kei_decode_mode(mode) ({ \
+ u8 flags = 0xff;\
+ switch (mode) { \
+ case X86EMUL_MODE_REAL: \
+ flags = 0; \
+ break; \
+ case X86EMUL_MODE_VM86: \
+ flags = KVM_EMUL_INSN_F_EFL_VM; \
+ break; \
+ case X86EMUL_MODE_PROT16: \
+ flags = KVM_EMUL_INSN_F_CR0_PE; \
+ break; \
+ case X86EMUL_MODE_PROT32: \
+ flags = KVM_EMUL_INSN_F_CR0_PE \
+ | KVM_EMUL_INSN_F_CS_D; \
+ break; \
+ case X86EMUL_MODE_PROT64: \
+ flags = KVM_EMUL_INSN_F_CR0_PE \
+ | KVM_EMUL_INSN_F_CS_L; \
+ break; \
+ } \
+ flags; \
+ })
+
+TRACE_EVENT(kvm_emulate_insn,
+ TP_PROTO(struct kvm_vcpu *vcpu, __u8 failed),
+ TP_ARGS(vcpu, failed),
+
+ TP_STRUCT__entry(
+ __field(__u64, rip )
+ __field(__u32, csbase)
+ __field(__u8, len )
+ __array(__u8, insn,15 )
+ __field(__u8, flags )
+ __field(__u8, failed)
+ ),
+
+ TP_fast_assign(
+ __entry-rip = vcpu-arch.emulate_ctxt.decode.fetch.start;
+ __entry-csbase = kvm_x86_ops-get_segment_base(vcpu,
VCPU_SREG_CS);
+ __entry-len = vcpu-arch.emulate_ctxt.decode.eip
+- vcpu-arch.emulate_ctxt.decode.fetch.start;
+ memcpy(__entry-insn,
+vcpu-arch.emulate_ctxt.decode.fetch.data,
+15);
+ __entry-flags = kei_decode_mode(vcpu-arch.emulate_ctxt.mode);
+ __entry-failed = failed;
+ ),
+
+ TP_printk(%x:%llx:%s (%s)%s,
+ __entry-csbase, __entry-rip,
+ __print_insn(__entry-insn, __entry-len),
+ __print_symbolic(__entry-flags,
+kvm_trace_symbol_emul_flags),
+ __entry-failed ? failed :
+ )
+ );
+
+#define trace_kvm_emulate_insn_start(vcpu) trace_kvm_emulate_insn(vcpu, 0)
+#define trace_kvm_emulate_insn_failed(vcpu) trace_kvm_emulate_insn(vcpu, 1)
+
#endif /* _TRACE_KVM_H */
#undef TRACE_INCLUDE_PATH
diff --git a/arch/x86/kvm/x86.c b/arch/x86/kvm/x86.c
index fd5c3d3..9413da5 100644
--- a/arch/x86/kvm/x86.c
+++ b/arch/x86/kvm/x86.c
@@ -3750,6 +3750,7 @@ int emulate_instruction(struct kvm_vcpu *vcpu,
++vcpu-stat.insn_emulation_fail;
Re: [PATCH 2/2] KVM: Trace emulated instructions
On 04/05/2010 09:44 PM, Marcelo Tosatti wrote: On Thu, Mar 25, 2010 at 05:02:56PM +0200, Avi Kivity wrote: Log emulated instructions in ftrace, especially if they failed. Why not log all emulated instructions? Seems useful to me. That was the intent, but it didn't pan out. I tried to avoid double-logging where an mmio read is dispatched to userspace, and the instruction is re-executed. Perhaps we should split it into a decode trace and execution result trace? Less easy to use but avoids confusion due to duplication. -- Do not meddle in the internals of kernels, for they are subtle and quick to panic. -- To unsubscribe from this list: send the line unsubscribe kvm in the body of a message to majord...@vger.kernel.org More majordomo info at http://vger.kernel.org/majordomo-info.html
[PATCH 2/2] KVM: Trace emulated instructions
Log emulated instructions in ftrace, especially if they failed.
Signed-off-by: Avi Kivity a...@redhat.com
---
arch/x86/kvm/trace.h | 86 ++
arch/x86/kvm/x86.c |4 ++
2 files changed, 90 insertions(+), 0 deletions(-)
diff --git a/arch/x86/kvm/trace.h b/arch/x86/kvm/trace.h
index 32c912c..a6544b8 100644
--- a/arch/x86/kvm/trace.h
+++ b/arch/x86/kvm/trace.h
@@ -603,6 +603,92 @@ TRACE_EVENT(kvm_skinit,
__entry-rip, __entry-slb)
);
+#define __print_insn(insn, ilen) ({ \
+ int i; \
+ const char *ret = p-buffer + p-len;\
+\
+ for (i = 0; i ilen; ++i) \
+ trace_seq_printf(p, %02x, insn[i]); \
+ trace_seq_printf(p, %c, 0);\
+ ret; \
+ })
+
+#define KVM_EMUL_INSN_F_CR0_PE (1 0)
+#define KVM_EMUL_INSN_F_EFL_VM (1 1)
+#define KVM_EMUL_INSN_F_CS_D (1 2)
+#define KVM_EMUL_INSN_F_CS_L (1 3)
+
+#define kvm_trace_symbol_emul_flags \
+ { 0,real }, \
+ { KVM_EMUL_INSN_F_CR0_PE \
+ | KVM_EMUL_INSN_F_EFL_VM, vm16 }, \
+ { KVM_EMUL_INSN_F_CR0_PE, prot16 }, \
+ { KVM_EMUL_INSN_F_CR0_PE \
+ | KVM_EMUL_INSN_F_CS_D, prot32 }, \
+ { KVM_EMUL_INSN_F_CR0_PE \
+ | KVM_EMUL_INSN_F_CS_L, prot64 }
+
+#define kei_decode_mode(mode) ({ \
+ u8 flags = 0xff;\
+ switch (mode) { \
+ case X86EMUL_MODE_REAL: \
+ flags = 0; \
+ break; \
+ case X86EMUL_MODE_VM86: \
+ flags = KVM_EMUL_INSN_F_EFL_VM; \
+ break; \
+ case X86EMUL_MODE_PROT16: \
+ flags = KVM_EMUL_INSN_F_CR0_PE; \
+ break; \
+ case X86EMUL_MODE_PROT32: \
+ flags = KVM_EMUL_INSN_F_CR0_PE \
+ | KVM_EMUL_INSN_F_CS_D; \
+ break; \
+ case X86EMUL_MODE_PROT64: \
+ flags = KVM_EMUL_INSN_F_CR0_PE \
+ | KVM_EMUL_INSN_F_CS_L; \
+ break; \
+ } \
+ flags; \
+ })
+
+TRACE_EVENT(kvm_emulate_insn,
+ TP_PROTO(struct kvm_vcpu *vcpu, __u8 failed),
+ TP_ARGS(vcpu, failed),
+
+ TP_STRUCT__entry(
+ __field(__u64, rip )
+ __field(__u32, csbase)
+ __field(__u8, len )
+ __array(__u8, insn,15 )
+ __field(__u8, flags )
+ __field(__u8, failed)
+ ),
+
+ TP_fast_assign(
+ __entry-rip = vcpu-arch.emulate_ctxt.decode.fetch.start;
+ __entry-csbase = kvm_x86_ops-get_segment_base(vcpu,
VCPU_SREG_CS);
+ __entry-len = vcpu-arch.emulate_ctxt.decode.eip
+ - vcpu-arch.emulate_ctxt.decode.fetch.start;
+ memcpy(__entry-insn,
+ vcpu-arch.emulate_ctxt.decode.fetch.data,
+ 15);
+ __entry-flags = kei_decode_mode(vcpu-arch.emulate_ctxt.mode);
+ __entry-failed = failed;
+ ),
+
+ TP_printk(%x:%llx:%s (%s)%s,
+ __entry-csbase, __entry-rip,
+ __print_insn(__entry-insn, __entry-len),
+ __print_symbolic(__entry-flags,
+ kvm_trace_symbol_emul_flags),
+ __entry-failed ? failed :
+ )
+ );
+
+#define trace_kvm_emulate_insn_start(vcpu) trace_kvm_emulate_insn(vcpu, 0)
+#define trace_kvm_emulate_insn_failed(vcpu) trace_kvm_emulate_insn(vcpu, 1)
+
#endif /* _TRACE_KVM_H */
#undef TRACE_INCLUDE_PATH
diff --git a/arch/x86/kvm/x86.c b/arch/x86/kvm/x86.c
index fd5c3d3..9413da5 100644
--- a/arch/x86/kvm/x86.c
+++ b/arch/x86/kvm/x86.c
@@ -3750,6 +3750,7 @@ int emulate_instruction(struct kvm_vcpu *vcpu,
++vcpu-stat.insn_emulation_fail;
if
