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 <avi@xxxxxxxxxx>
> ---
> 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 majordomo@xxxxxxxxxxxxxxx
More majordomo info at http://vger.kernel.org/majordomo-info.html
