KVM: Trace emulated instructions
authorAvi Kivity <avi@redhat.com>
Sun, 11 Apr 2010 10:05:16 +0000 (13:05 +0300)
committerAvi Kivity <avi@redhat.com>
Mon, 17 May 2010 09:17:35 +0000 (12:17 +0300)
Log emulated instructions in ftrace, especially if they failed.

Signed-off-by: Avi Kivity <avi@redhat.com>
Signed-off-by: Marcelo Tosatti <mtosatti@redhat.com>
arch/x86/kvm/trace.h
arch/x86/kvm/x86.c

index 32c912c..a6544b8 100644 (file)
@@ -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
index 247e805..33a40c5 100644 (file)
@@ -3718,6 +3718,7 @@ int emulate_instruction(struct kvm_vcpu *vcpu,
                        ? X86EMUL_MODE_PROT32 : X86EMUL_MODE_PROT16;
 
                r = x86_decode_insn(&vcpu->arch.emulate_ctxt, &emulate_ops);
+               trace_kvm_emulate_insn_start(vcpu);
 
                /* Only allow emulation of specific instructions on #UD
                 * (namely VMMCALL, sysenter, sysexit, syscall)*/
@@ -3750,6 +3751,7 @@ int emulate_instruction(struct kvm_vcpu *vcpu,
                ++vcpu->stat.insn_emulation;
                if (r)  {
                        ++vcpu->stat.insn_emulation_fail;
+                       trace_kvm_emulate_insn_failed(vcpu);
                        if (kvm_mmu_unprotect_page_virt(vcpu, cr2))
                                return EMULATE_DONE;
                        return EMULATE_FAIL;
@@ -3786,6 +3788,8 @@ restart:
                if (kvm_mmu_unprotect_page_virt(vcpu, cr2))
                        goto done;
                if (!vcpu->mmio_needed) {
+                       ++vcpu->stat.insn_emulation_fail;
+                       trace_kvm_emulate_insn_failed(vcpu);
                        kvm_report_emulation_failure(vcpu, "mmio");
                        return EMULATE_FAIL;
                }