Re: [PATCH] KVM: nVMX: nSVM: Show guest mode in kvm_{entry,exit} tracepoints

[Sean Christopherson <seanjc@google.com>]

On Mon, Jun 21, 2021, Krish Sadhukhan wrote:
> From debugging point of view, KVM entry and exit tracepoints are important
> in that they indicate when a guest starts and exits. When L1 runs L2, there
> is no way we can determine from KVM tracing when L1 starts/exits and when
> L2 starts/exits as there is no marker in place today in those tracepoints.
> Debugging becomes even more difficult when more than one L2 run in an L1 and
> there is no way of determining which L2 from which L1 made the entries/exits.
> Therefore, showing guest mode in the entry and exit tracepoints
> will make debugging much easier.

> If an L1 runs multiple L2s, though we can not identify the specific L2 from
> the entry and exit tracepoints, we still will be able to determine whether it
> was L1 or an L2 that made the entries and the exits.

Hmm, this is a solvable problem, and might even be worth solving immediately,
e.g. kvm_x86_ops.get_vmcx12 to retrieve the L1 GPA of the vmcs12/vmcb12.
More below.

> With this patch KVM entry and exit tracepoints will show "guest_mode = 0" if
> it is a guest and "guest_mode = 1" if it is a nested guest.

Uber pedantry, but technically not true, as trace_kvm_entry() doesn't have the
'=', and in the exit tracepoint, the '=' should be dropped to be consistent with
the existing format.  Might be a moot point though.

> Signed-off-by: Krish Sdhukhan <krish.sadhukhan@oracle.com>
> ---
>  arch/x86/kvm/trace.h | 16 +++++++++++-----
>  1 file changed, 11 insertions(+), 5 deletions(-)
> 
> diff --git a/arch/x86/kvm/trace.h b/arch/x86/kvm/trace.h
> index b484141ea15b..44dba26c6be2 100644
> --- a/arch/x86/kvm/trace.h
> +++ b/arch/x86/kvm/trace.h
> @@ -21,14 +21,17 @@ TRACE_EVENT(kvm_entry,
>  	TP_STRUCT__entry(
>  		__field(	unsigned int,	vcpu_id		)
>  		__field(	unsigned long,	rip		)
> +		__field(        bool,           guest_mode      )
>  	),
>  
>  	TP_fast_assign(
>  		__entry->vcpu_id        = vcpu->vcpu_id;
>  		__entry->rip		= kvm_rip_read(vcpu);
> +		__entry->guest_mode     = is_guest_mode(vcpu);
>  	),
>  
> -	TP_printk("vcpu %u, rip 0x%lx", __entry->vcpu_id, __entry->rip)
> +	TP_printk("vcpu %u, rip 0x%lx, guest_mode %d", __entry->vcpu_id,
> +		  __entry->rip, __entry->guest_mode)
>  );
>  
>  /*
> @@ -285,6 +288,7 @@ TRACE_EVENT(name,							     \
>  		__field(	u32,	        intr_info	)	     \
>  		__field(	u32,	        error_code	)	     \
>  		__field(	unsigned int,	vcpu_id         )	     \
> +		__field(        bool,           guest_mode      )            \
>  	),								     \
>  									     \
>  	TP_fast_assign(							     \
> @@ -295,15 +299,17 @@ TRACE_EVENT(name,							     \
>  		static_call(kvm_x86_get_exit_info)(vcpu, &__entry->info1,    \
>  					  &__entry->info2,		     \
>  					  &__entry->intr_info,		     \
> -					  &__entry->error_code);	     \
> +					  &__entry->error_code);     	     \
> +		__entry->guest_mode      = is_guest_mode(vcpu);		     \
>  	),								     \
>  									     \
>  	TP_printk("vcpu %u reason %s%s%s rip 0x%lx info1 0x%016llx "	     \
> -		  "info2 0x%016llx intr_info 0x%08x error_code 0x%08x",	     \
> -		  __entry->vcpu_id,					     \
> +		  "info2 0x%016llx intr_info 0x%08x error_code 0x%08x "	     \
> +		  "guest_mode = %d", __entry->vcpu_id,          	     \

I'm biased because I've never really liked is_guest_mode(), but I think guest_mode
will be confusing to users.  KVM developers are familiar with guest_mode() == L2,
but random debuggers/users are unlikely to make that connection.

A clever/heinous way to "solve" this issue and display vmcx12 iff L2 is active
would be to bastardize the L1/L2 strings and vmcx12 value formatting to yield:

  vcpu 0 reason <reason> guest L1 rip 0xfffff ...

and

  vcpu 0 reason <reason> guest L2 vmcx12 0xaaaaa rip 0xfffff ...

 
#define TRACE_EVENT_KVM_EXIT(name)					     \
TRACE_EVENT(name,							     \
	TP_PROTO(unsigned int exit_reason, struct kvm_vcpu *vcpu, u32 isa),  \
	TP_ARGS(exit_reason, vcpu, isa),				     \
									     \
	TP_STRUCT__entry(						     \
		__field(	unsigned int,	exit_reason	)	     \
		__field(	unsigned long,	guest_rip	)	     \
		__field(	u32,	        isa             )	     \
		__field(	u64,	        info1           )	     \
		__field(	u64,	        info2           )	     \
		__field(	u32,	        intr_info	)	     \
		__field(	u32,	        error_code	)	     \
		__field(	unsigned int,	vcpu_id         )	     \
		__field(	u64,	        vmcx12          )	     \
	),								     \
									     \
	TP_fast_assign(							     \
		__entry->exit_reason	= exit_reason;			     \
		__entry->guest_rip	= kvm_rip_read(vcpu);		     \
		__entry->isa            = isa;				     \
		__entry->vcpu_id        = vcpu->vcpu_id;		     \
		static_call(kvm_x86_get_exit_info)(vcpu, &__entry->info1,    \
					  &__entry->info2,		     \
					  &__entry->intr_info,		     \
					  &__entry->error_code);	     \
		__entry->vmcx12		= is_guest_mode(vcpu) ?		     \
					  static_call(kvm_x86_get_vmcx12) :  \
					  INVALID_PAGE;			     \
	),								     \
									     \
	TP_printk("vcpu %u reason %s%s%s guest %s%llx rip 0x%lx "	     \
		  "info1 0x%016llx info2 0x%016llx "			     \
		  "intr_info 0x%08x error_code 0x%08x",			     \
		  __entry->vcpu_id,					     \
		  kvm_print_exit_reason(__entry->exit_reason, __entry->isa), \
		  __entry->vmcx12 == INVALID_PAGE ? "L" : "L2 vmcx12 0x",    \
		  __entry->vmcx12 == INVALID_PAGE ? 1 : __entry->vmcx12,     \
		  __entry->guest_rip, __entry->info1, __entry->info2,	     \
		  __entry->intr_info, __entry->error_code)		     \
)