Re: [RFC] Simple tool for VMEnters/VMExits matching and trace validation

[Dario Faggioli <dfaggioli@suse.com>]

[-- Attachment #1: Type: text/plain, Size: 3248 bytes --]

On Fri, 2021-04-16 at 17:32 -0400, Steven Rostedt wrote:
> On Fri, 16 Apr 2021 22:48:38 +0200
> Stefano De Venuto <stefano.devenuto99@gmail.com> wrote:
> > 
> > Yes. An example of those events is visible in this trace:
> > 
> >            trace.dat:        CPU 0/KVM-1567  [001]14320175367012:
> > kvm_entry:            vcpu 0, rip 0xffffffff84a792b6
> >            trace.dat:        CPU 0/KVM-1567  [001]14320175253942:
> > write_msr:            c0011020, value 0
> > trace-tumbleweed.dat:           <idle>-0     [000]14320175283462:
> > hrtimer_cancel:       hrtimer=0xffff9002fdc21a00
> > trace-tumbleweed.dat:           <idle>-0     [000]14320175291336:
> > hrtimer_expire_entry: hrtimer=0xffff9002fdc21a00
> > function=tick_sched_timer now=3601121397289
> > trace-tumbleweed.dat:           <idle>-0     [000]14320175317345:
> > hrtimer_expire_exit:  hrtimer=0xffff9002fdc21a00
> > trace-tumbleweed.dat:           <idle>-0     [000]14320175319329:
> > hrtimer_start:        hrtimer=0xffff9002fdc21a00
> > function=tick_sched_timer expires=3601125253926
> > softexpires=3601125253926 mode=0x0
> >            trace.dat:        CPU 0/KVM-1567  [001]14320175331517:
> > write_msr:            c0011020, value 40000000000000
> >            trace.dat:        CPU 0/KVM-1567  [001]14320175338548:
> > kvm_wait_lapic_expire: vcpu 0: delta 534432 (late)
> >            trace.dat:        CPU 0/KVM-1567  [001]14320175341750:
> > kvm_eoi:              apicid 0 vector 236
> >            trace.dat:        CPU 0/KVM-1567  [001]14320175343465:
> > kvm_pv_eoi:           apicid 0 vector 236
> >            trace.dat:        CPU 0/KVM-1567  [001]14320175345704:
> > kvm_exit:             vcpu 0 reason msr rip 0xffffffff84a792b4
> > info1 0x0000000000000001 info2 0x0000000000000000 intr_info
> > 0x00000000 error_code 0x00000000
> 
> Is the above with the time negotiations working fine?
> 
Yes. I think this is still with PTP.

But this time, this is actually all about the host.

> We do not yet support the guest shift, as we found that it was broken
> (I
> believe you reported that) and we do not have a machine available to
> that
> has that feature :-/
> 
Sure, but the problem here is that write_msr, kvm_wait_lapic_expire,
kvm_eoi, kvm_pv_eoi in trace.dat (which is the host trace), despite
happening after the VMExit, are shown before kvm_exit.

This, we think, has to do to where the call to trace_kvm_exit() is in
the kernel, and that's why we said we'll send a patch to move it.

It was just an example of what and how one can use the simple little
tool that Stefano has made on top of libkshark, as it was what helped
us spot this problem. :-)

Regards
-- 
Dario Faggioli, Ph.D
http://about.me/dario.faggioli
Virtualization Software Engineer
SUSE Labs, SUSE https://www.suse.com/
-------------------------------------------------------------------
<<This happens because _I_ choose it to happen!>> (Raistlin Majere)

[-- Attachment #2: This is a digitally signed message part --]
[-- Type: application/pgp-signature, Size: 833 bytes --]