| Message ID | 160873470698.11652.13483635328769030605.stgit@Wayrath (mailing list archive) |
|---|---|
| State | New, archived |
| Headers | show |
| Series | kvm: tracing: Fix unmatched kvm_entry and kvm_exit events | expand |
On Wed, 2020-12-23 at 14:45 +0000, Dario Faggioli wrote: > From: Lorenzo Brescia <lorenzo.brescia@edu.unito.it> > > On VMX, if we exit and then re-enter immediately without leaving > the vmx_vcpu_run() function, the kvm_entry event is not logged. > That means we will see one (or more) kvm_exit, without its (their) > corresponding kvm_entry, as shown here: > > CPU-1979 [002] 89.871187: kvm_entry: vcpu 1 > CPU-1979 [002] 89.871218: kvm_exit: reason MSR_WRITE > CPU-1979 [002] 89.871259: kvm_exit: reason MSR_WRITE > > It also seems possible for a kvm_entry event to be logged, but then > we leave vmx_vcpu_run() right away (if vmx->emulation_required is > true). In this case, we will have a spurious kvm_entry event in the > trace. > Gentle ping... :-) Thanks and Regards
On 23/12/20 15:45, Dario Faggioli wrote: > From: Lorenzo Brescia <lorenzo.brescia@edu.unito.it> > > On VMX, if we exit and then re-enter immediately without leaving > the vmx_vcpu_run() function, the kvm_entry event is not logged. > That means we will see one (or more) kvm_exit, without its (their) > corresponding kvm_entry, as shown here: > > CPU-1979 [002] 89.871187: kvm_entry: vcpu 1 > CPU-1979 [002] 89.871218: kvm_exit: reason MSR_WRITE > CPU-1979 [002] 89.871259: kvm_exit: reason MSR_WRITE > > It also seems possible for a kvm_entry event to be logged, but then > we leave vmx_vcpu_run() right away (if vmx->emulation_required is > true). In this case, we will have a spurious kvm_entry event in the > trace. > > Fix these situations by moving trace_kvm_entry() inside vmx_vcpu_run() > (where trace_kvm_exit() already is). > > A trace obtained with this patch applied looks like this: > > CPU-14295 [000] 8388.395387: kvm_entry: vcpu 0 > CPU-14295 [000] 8388.395392: kvm_exit: reason MSR_WRITE > CPU-14295 [000] 8388.395393: kvm_entry: vcpu 0 > CPU-14295 [000] 8388.395503: kvm_exit: reason EXTERNAL_INTERRUPT > > Of course, not calling trace_kvm_entry() in common x86 code any > longer means that we need to adjust the SVM side of things too. > > Signed-off-by: Lorenzo Brescia <lorenzo.brescia@edu.unito.it> > Signed-off-by: Dario Faggioli <dfaggioli@suse.com> > --- > Cc: Paolo Bonzini <pbonzini@redhat.com> > Cc: Sean Christopherson <seanjc@google.com> > Cc: Vitaly Kuznetsov <vkuznets@redhat.com> > Cc: Wanpeng Li <wanpengli@tencent.com> > Cc: Jim Mattson <jmattson@google.com> > Cc: Joerg Roedel <joro@8bytes.org> > Cc: kvm@vger.kernel.org > Cc: Lorenzo Brescia <lorenzo.brescia@edu.unito.it> > Cc: Dario Faggioli <dfaggioli@suse.com> > --- > arch/x86/kvm/svm/svm.c | 2 ++ > arch/x86/kvm/vmx/vmx.c | 2 ++ > arch/x86/kvm/x86.c | 3 +-- > 3 files changed, 5 insertions(+), 2 deletions(-) > > diff --git a/arch/x86/kvm/svm/svm.c b/arch/x86/kvm/svm/svm.c > index cce0143a6f80..ed272fcf6495 100644 > --- a/arch/x86/kvm/svm/svm.c > +++ b/arch/x86/kvm/svm/svm.c > @@ -3741,6 +3741,8 @@ static __no_kcsan fastpath_t svm_vcpu_run(struct kvm_vcpu *vcpu) > { > struct vcpu_svm *svm = to_svm(vcpu); > > + trace_kvm_entry(vcpu); > + > svm->vmcb->save.rax = vcpu->arch.regs[VCPU_REGS_RAX]; > svm->vmcb->save.rsp = vcpu->arch.regs[VCPU_REGS_RSP]; > svm->vmcb->save.rip = vcpu->arch.regs[VCPU_REGS_RIP]; > diff --git a/arch/x86/kvm/vmx/vmx.c b/arch/x86/kvm/vmx/vmx.c > index 75c9c6a0a3a4..ff20f9e6e5b3 100644 > --- a/arch/x86/kvm/vmx/vmx.c > +++ b/arch/x86/kvm/vmx/vmx.c > @@ -6653,6 +6653,8 @@ static fastpath_t vmx_vcpu_run(struct kvm_vcpu *vcpu) > if (vmx->emulation_required) > return EXIT_FASTPATH_NONE; > > + trace_kvm_entry(vcpu); > + > if (vmx->ple_window_dirty) { > vmx->ple_window_dirty = false; > vmcs_write32(PLE_WINDOW, vmx->ple_window); > diff --git a/arch/x86/kvm/x86.c b/arch/x86/kvm/x86.c > index 3f7c1fc7a3ce..a79666204907 100644 > --- a/arch/x86/kvm/x86.c > +++ b/arch/x86/kvm/x86.c > @@ -8973,8 +8973,6 @@ static int vcpu_enter_guest(struct kvm_vcpu *vcpu) > kvm_x86_ops.request_immediate_exit(vcpu); > } > > - trace_kvm_entry(vcpu); > - > fpregs_assert_state_consistent(); > if (test_thread_flag(TIF_NEED_FPU_LOAD)) > switch_fpu_return(); > @@ -11538,6 +11536,7 @@ int kvm_sev_es_string_io(struct kvm_vcpu *vcpu, unsigned int size, > } > EXPORT_SYMBOL_GPL(kvm_sev_es_string_io); > > +EXPORT_TRACEPOINT_SYMBOL_GPL(kvm_entry); > EXPORT_TRACEPOINT_SYMBOL_GPL(kvm_exit); > EXPORT_TRACEPOINT_SYMBOL_GPL(kvm_fast_mmio); > EXPORT_TRACEPOINT_SYMBOL_GPL(kvm_inj_virq); > > Qeuued, thanks! Paolo
On 23/12/20 15:45, Dario Faggioli wrote: > From: Lorenzo Brescia <lorenzo.brescia@edu.unito.it> > > On VMX, if we exit and then re-enter immediately without leaving > the vmx_vcpu_run() function, the kvm_entry event is not logged. > That means we will see one (or more) kvm_exit, without its (their) > corresponding kvm_entry, as shown here: > > CPU-1979 [002] 89.871187: kvm_entry: vcpu 1 > CPU-1979 [002] 89.871218: kvm_exit: reason MSR_WRITE > CPU-1979 [002] 89.871259: kvm_exit: reason MSR_WRITE > > It also seems possible for a kvm_entry event to be logged, but then > we leave vmx_vcpu_run() right away (if vmx->emulation_required is > true). In this case, we will have a spurious kvm_entry event in the > trace. > > Fix these situations by moving trace_kvm_entry() inside vmx_vcpu_run() > (where trace_kvm_exit() already is). > > A trace obtained with this patch applied looks like this: > > CPU-14295 [000] 8388.395387: kvm_entry: vcpu 0 > CPU-14295 [000] 8388.395392: kvm_exit: reason MSR_WRITE > CPU-14295 [000] 8388.395393: kvm_entry: vcpu 0 > CPU-14295 [000] 8388.395503: kvm_exit: reason EXTERNAL_INTERRUPT > > Of course, not calling trace_kvm_entry() in common x86 code any > longer means that we need to adjust the SVM side of things too. > > Signed-off-by: Lorenzo Brescia <lorenzo.brescia@edu.unito.it> > Signed-off-by: Dario Faggioli <dfaggioli@suse.com> > --- > Cc: Paolo Bonzini <pbonzini@redhat.com> > Cc: Sean Christopherson <seanjc@google.com> > Cc: Vitaly Kuznetsov <vkuznets@redhat.com> > Cc: Wanpeng Li <wanpengli@tencent.com> > Cc: Jim Mattson <jmattson@google.com> > Cc: Joerg Roedel <joro@8bytes.org> > Cc: kvm@vger.kernel.org > Cc: Lorenzo Brescia <lorenzo.brescia@edu.unito.it> > Cc: Dario Faggioli <dfaggioli@suse.com> > --- > arch/x86/kvm/svm/svm.c | 2 ++ > arch/x86/kvm/vmx/vmx.c | 2 ++ > arch/x86/kvm/x86.c | 3 +-- > 3 files changed, 5 insertions(+), 2 deletions(-) > > diff --git a/arch/x86/kvm/svm/svm.c b/arch/x86/kvm/svm/svm.c > index cce0143a6f80..ed272fcf6495 100644 > --- a/arch/x86/kvm/svm/svm.c > +++ b/arch/x86/kvm/svm/svm.c > @@ -3741,6 +3741,8 @@ static __no_kcsan fastpath_t svm_vcpu_run(struct kvm_vcpu *vcpu) > { > struct vcpu_svm *svm = to_svm(vcpu); > > + trace_kvm_entry(vcpu); > + > svm->vmcb->save.rax = vcpu->arch.regs[VCPU_REGS_RAX]; > svm->vmcb->save.rsp = vcpu->arch.regs[VCPU_REGS_RSP]; > svm->vmcb->save.rip = vcpu->arch.regs[VCPU_REGS_RIP]; > diff --git a/arch/x86/kvm/vmx/vmx.c b/arch/x86/kvm/vmx/vmx.c > index 75c9c6a0a3a4..ff20f9e6e5b3 100644 > --- a/arch/x86/kvm/vmx/vmx.c > +++ b/arch/x86/kvm/vmx/vmx.c > @@ -6653,6 +6653,8 @@ static fastpath_t vmx_vcpu_run(struct kvm_vcpu *vcpu) > if (vmx->emulation_required) > return EXIT_FASTPATH_NONE; > > + trace_kvm_entry(vcpu); > + > if (vmx->ple_window_dirty) { > vmx->ple_window_dirty = false; > vmcs_write32(PLE_WINDOW, vmx->ple_window); > diff --git a/arch/x86/kvm/x86.c b/arch/x86/kvm/x86.c > index 3f7c1fc7a3ce..a79666204907 100644 > --- a/arch/x86/kvm/x86.c > +++ b/arch/x86/kvm/x86.c > @@ -8973,8 +8973,6 @@ static int vcpu_enter_guest(struct kvm_vcpu *vcpu) > kvm_x86_ops.request_immediate_exit(vcpu); > } > > - trace_kvm_entry(vcpu); > - > fpregs_assert_state_consistent(); > if (test_thread_flag(TIF_NEED_FPU_LOAD)) > switch_fpu_return(); > @@ -11538,6 +11536,7 @@ int kvm_sev_es_string_io(struct kvm_vcpu *vcpu, unsigned int size, > } > EXPORT_SYMBOL_GPL(kvm_sev_es_string_io); > > +EXPORT_TRACEPOINT_SYMBOL_GPL(kvm_entry); > EXPORT_TRACEPOINT_SYMBOL_GPL(kvm_exit); > EXPORT_TRACEPOINT_SYMBOL_GPL(kvm_fast_mmio); > EXPORT_TRACEPOINT_SYMBOL_GPL(kvm_inj_virq); > > Queued, thanks. Paolo
diff --git a/arch/x86/kvm/svm/svm.c b/arch/x86/kvm/svm/svm.c index cce0143a6f80..ed272fcf6495 100644 --- a/arch/x86/kvm/svm/svm.c +++ b/arch/x86/kvm/svm/svm.c @@ -3741,6 +3741,8 @@ static __no_kcsan fastpath_t svm_vcpu_run(struct kvm_vcpu *vcpu) { struct vcpu_svm *svm = to_svm(vcpu); + trace_kvm_entry(vcpu); + svm->vmcb->save.rax = vcpu->arch.regs[VCPU_REGS_RAX]; svm->vmcb->save.rsp = vcpu->arch.regs[VCPU_REGS_RSP]; svm->vmcb->save.rip = vcpu->arch.regs[VCPU_REGS_RIP]; diff --git a/arch/x86/kvm/vmx/vmx.c b/arch/x86/kvm/vmx/vmx.c index 75c9c6a0a3a4..ff20f9e6e5b3 100644 --- a/arch/x86/kvm/vmx/vmx.c +++ b/arch/x86/kvm/vmx/vmx.c @@ -6653,6 +6653,8 @@ static fastpath_t vmx_vcpu_run(struct kvm_vcpu *vcpu) if (vmx->emulation_required) return EXIT_FASTPATH_NONE; + trace_kvm_entry(vcpu); + if (vmx->ple_window_dirty) { vmx->ple_window_dirty = false; vmcs_write32(PLE_WINDOW, vmx->ple_window); diff --git a/arch/x86/kvm/x86.c b/arch/x86/kvm/x86.c index 3f7c1fc7a3ce..a79666204907 100644 --- a/arch/x86/kvm/x86.c +++ b/arch/x86/kvm/x86.c @@ -8973,8 +8973,6 @@ static int vcpu_enter_guest(struct kvm_vcpu *vcpu) kvm_x86_ops.request_immediate_exit(vcpu); } - trace_kvm_entry(vcpu); - fpregs_assert_state_consistent(); if (test_thread_flag(TIF_NEED_FPU_LOAD)) switch_fpu_return(); @@ -11538,6 +11536,7 @@ int kvm_sev_es_string_io(struct kvm_vcpu *vcpu, unsigned int size, } EXPORT_SYMBOL_GPL(kvm_sev_es_string_io); +EXPORT_TRACEPOINT_SYMBOL_GPL(kvm_entry); EXPORT_TRACEPOINT_SYMBOL_GPL(kvm_exit); EXPORT_TRACEPOINT_SYMBOL_GPL(kvm_fast_mmio); EXPORT_TRACEPOINT_SYMBOL_GPL(kvm_inj_virq);