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 <[email protected]> > --- > 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 (kvm_mmu_unprotect_page_virt(vcpu, cr2)) > return EMULATE_DONE; > + trace_kvm_emulate_insn_failed(vcpu); > return EMULATE_FAIL; > } > } > @@ -3767,6 +3768,7 @@ restart: > kvm_x86_ops->set_interrupt_shadow(vcpu, shadow_mask); > > if (vcpu->arch.pio.count) { > + trace_kvm_emulate_insn_start(vcpu);
Why not log all emulated instructions? Seems useful to me. -- To unsubscribe from this list: send the line "unsubscribe kvm" in the body of a message to [email protected] More majordomo info at http://vger.kernel.org/majordomo-info.html
