* Re: Tracing kvm: kvm_entry and kvm_exit
2013-02-25 10:18 ` Tracing kvm: kvm_entry and kvm_exit Stefan Hajnoczi
@ 2013-02-26 16:24 ` Mohamad Gebai
2013-02-26 16:32 ` Gleb Natapov
2013-02-27 16:39 ` David Ahern
2 siblings, 0 replies; 10+ messages in thread
From: Mohamad Gebai @ 2013-02-26 16:24 UTC (permalink / raw)
To: Stefan Hajnoczi; +Cc: kvm, linux-perf-users
I did the same experience using LTTng where the events and counters are
activated before launching kvm. So the problem doesn't seem to be with the
activation time but rather with tracepoint instrumentation within kvm. I will
investigate on it but if anyone has any kind of explanation it would be
appreciated.
Selon Stefan Hajnoczi <stefanha@gmail.com>:
> On Fri, Feb 22, 2013 at 11:34:27AM -0500, Mohamad Gebai wrote:
> > I am tracing kvm using perf and I am analyzing the sequences of kvm_entry
> and
> > kvm_exit tracepoints.
> > I noticed that during the boot process of a VM, there are a lot more (2 to
> 3 as
> > many times) kvm_entry event than there are kvm_exit. I tried looking around
> but
> > didn't find anything that explains this. Is this missing instrumentation?
> Or
> > what other path does kvm take that doesn't generate a kvm_exit event?
>
> Gleb Natapov noticed something similar when playing with the perf script
> I posted here:
>
> http://permalink.gmane.org/gmane.comp.emulators.kvm.devel/104181
>
> Perhaps there is a code path that is missing trace_kvm_exit().
>
> We didn't investigate why it happens but the unexplained kvm_entry
> events only appeared at the beginning of the trace, so the theory was
> that events are not activated atomically by perf(1).
>
> CCing perf mailing list.
>
> It would be interesting if someone knows the answer.
>
> Stefan
>
^ permalink raw reply [flat|nested] 10+ messages in thread
* Re: Tracing kvm: kvm_entry and kvm_exit
2013-02-25 10:18 ` Tracing kvm: kvm_entry and kvm_exit Stefan Hajnoczi
2013-02-26 16:24 ` Mohamad Gebai
@ 2013-02-26 16:32 ` Gleb Natapov
2013-02-27 16:39 ` David Ahern
2 siblings, 0 replies; 10+ messages in thread
From: Gleb Natapov @ 2013-02-26 16:32 UTC (permalink / raw)
To: Stefan Hajnoczi; +Cc: Mohamad Gebai, kvm, linux-perf-users
On Mon, Feb 25, 2013 at 11:18:04AM +0100, Stefan Hajnoczi wrote:
> On Fri, Feb 22, 2013 at 11:34:27AM -0500, Mohamad Gebai wrote:
> > I am tracing kvm using perf and I am analyzing the sequences of kvm_entry and
> > kvm_exit tracepoints.
> > I noticed that during the boot process of a VM, there are a lot more (2 to 3 as
> > many times) kvm_entry event than there are kvm_exit. I tried looking around but
> > didn't find anything that explains this. Is this missing instrumentation? Or
> > what other path does kvm take that doesn't generate a kvm_exit event?
>
> Gleb Natapov noticed something similar when playing with the perf script
> I posted here:
>
> http://permalink.gmane.org/gmane.comp.emulators.kvm.devel/104181
>
> Perhaps there is a code path that is missing trace_kvm_exit().
>
During guest boot there is such path. If instruction is emulated entry
is reported but exit is not. What we saw with perf was different though,
It was during normal run, not boot, so emulation cannot explain it.
> We didn't investigate why it happens but the unexplained kvm_entry
> events only appeared at the beginning of the trace, so the theory was
> that events are not activated atomically by perf(1).
>
> CCing perf mailing list.
>
> It would be interesting if someone knows the answer.
>
> Stefan
> --
> To unsubscribe from this list: send the line "unsubscribe kvm" in
> the body of a message to majordomo@vger.kernel.org
> More majordomo info at http://vger.kernel.org/majordomo-info.html
--
Gleb.
^ permalink raw reply [flat|nested] 10+ messages in thread
* Re: Tracing kvm: kvm_entry and kvm_exit
2013-02-25 10:18 ` Tracing kvm: kvm_entry and kvm_exit Stefan Hajnoczi
2013-02-26 16:24 ` Mohamad Gebai
2013-02-26 16:32 ` Gleb Natapov
@ 2013-02-27 16:39 ` David Ahern
2013-02-28 4:49 ` David Ahern
2 siblings, 1 reply; 10+ messages in thread
From: David Ahern @ 2013-02-27 16:39 UTC (permalink / raw)
To: Stefan Hajnoczi; +Cc: Mohamad Gebai, kvm, linux-perf-users
On 2/25/13 3:18 AM, Stefan Hajnoczi wrote:
> On Fri, Feb 22, 2013 at 11:34:27AM -0500, Mohamad Gebai wrote:
>> I am tracing kvm using perf and I am analyzing the sequences of kvm_entry and
>> kvm_exit tracepoints.
>> I noticed that during the boot process of a VM, there are a lot more (2 to 3 as
>> many times) kvm_entry event than there are kvm_exit. I tried looking around but
>> didn't find anything that explains this. Is this missing instrumentation? Or
>> what other path does kvm take that doesn't generate a kvm_exit event?
>
> Gleb Natapov noticed something similar when playing with the perf script
> I posted here:
>
> http://permalink.gmane.org/gmane.comp.emulators.kvm.devel/104181
Have you tried using perf kvm stat? It is really easy to add a
flag/option to dump individual analysis points with the stats summary at
the end - or only dump data points greater than some threshold.
Latest version for the 'live mode' can be found here:
https://github.com/dsahern/linux/tree/perf-kvm-live-3.8
>
> Perhaps there is a code path that is missing trace_kvm_exit().
I have been playing with the live mode a bit lately. I'll add a debug to
note 2 consecutive entry events without an exit -- see if it sheds some
light on it.
David
^ permalink raw reply [flat|nested] 10+ messages in thread
* Re: Tracing kvm: kvm_entry and kvm_exit
2013-02-27 16:39 ` David Ahern
@ 2013-02-28 4:49 ` David Ahern
2013-02-28 8:44 ` Stefan Hajnoczi
2013-03-04 5:36 ` Mohamad Gebai
0 siblings, 2 replies; 10+ messages in thread
From: David Ahern @ 2013-02-28 4:49 UTC (permalink / raw)
To: Stefan Hajnoczi; +Cc: Mohamad Gebai, kvm, linux-perf-users
On 2/27/13 9:39 AM, David Ahern wrote:
> I have been playing with the live mode a bit lately. I'll add a debug to
> note 2 consecutive entry events without an exit -- see if it sheds some
> light on it.
If you feel game take this for a spin:
https://github.com/dsahern/linux/commits/perf-kvm-live-3.8
I pushed a few more commits that add debugs to show consecutive events
(2 entries or 2 exits), max and min times for various exit reasons and
an option to dump events that take longer than some threshold. If you
dump the output to a file or run screen with logging you should be able
to find when the 'long' event happens and which VMEXIT reason was the cause.
Example screen dump:
21:47:37.935302
Analyze events for all VMs, all VCPUs:
VM-EXIT Samples Samples% Time% Min Time Max
Time Avg time
APIC_ACCESS 978 61.51% 0.02% 1us
113us 7.81us ( +- 3.67% )
IO_INSTRUCTION 212 13.33% 0.00% 2us
85us 9.20us ( +- 7.57% )
CR_ACCESS 93 5.85% 0.00% 2us
66us 3.49us ( +- 19.73% )
EXTERNAL_INTERRUPT 53 3.33% 0.01% 3us
135us 57.02us ( +- 6.59% )
EXCEPTION_NMI 26 1.64% 0.00% 2us
3us 2.57us ( +- 1.74% )
PENDING_INTERRUPT 3 0.19% 0.00% 1us
1us 1.85us ( +- 4.18% )
Total Samples:1590, Total events handled time:39942741.62us.
295170818723592 VM 11854, vcpu 3: APIC_ACCESS event took 113usec
295170819686668 VM 11854, vcpu 0: EXTERNAL_INTERRUPT event took 112usec
295172155051688 VM 11854, vcpu 0: EXTERNAL_INTERRUPT event took 119usec
295172841724899 VM 11854, vcpu 0: APIC_ACCESS event took 129usec
295172999633325 VM 11854, vcpu 0: EXTERNAL_INTERRUPT event took 111usec
David
^ permalink raw reply [flat|nested] 10+ messages in thread* Re: Tracing kvm: kvm_entry and kvm_exit
2013-02-28 4:49 ` David Ahern
@ 2013-02-28 8:44 ` Stefan Hajnoczi
2013-03-04 5:36 ` Mohamad Gebai
1 sibling, 0 replies; 10+ messages in thread
From: Stefan Hajnoczi @ 2013-02-28 8:44 UTC (permalink / raw)
To: David Ahern; +Cc: Mohamad Gebai, kvm, linux-perf-users@vger.kernel.org
On Thu, Feb 28, 2013 at 5:49 AM, David Ahern <dsahern@gmail.com> wrote:
> On 2/27/13 9:39 AM, David Ahern wrote:
>>
>> I have been playing with the live mode a bit lately. I'll add a debug to
>> note 2 consecutive entry events without an exit -- see if it sheds some
>> light on it.
>
>
> If you feel game take this for a spin:
> https://github.com/dsahern/linux/commits/perf-kvm-live-3.8
This is very cool, thanks for sharing.
Next time I'm profiling vmexit latencies I'll give it a try.
Stefan
^ permalink raw reply [flat|nested] 10+ messages in thread
* Re: Tracing kvm: kvm_entry and kvm_exit
2013-02-28 4:49 ` David Ahern
2013-02-28 8:44 ` Stefan Hajnoczi
@ 2013-03-04 5:36 ` Mohamad Gebai
2013-03-04 5:40 ` David Ahern
1 sibling, 1 reply; 10+ messages in thread
From: Mohamad Gebai @ 2013-03-04 5:36 UTC (permalink / raw)
To: David Ahern; +Cc: Stefan Hajnoczi, kvm, linux-perf-users
Selon David Ahern <dsahern@gmail.com>:
> On 2/27/13 9:39 AM, David Ahern wrote:
> > I have been playing with the live mode a bit lately. I'll add a debug to
> > note 2 consecutive entry events without an exit -- see if it sheds some
> > light on it.
>
> If you feel game take this for a spin:
> https://github.com/dsahern/linux/commits/perf-kvm-live-3.8
Thank you for this, I have been testing it for the last couple of days, I can
see that perf kvm is getting more stable. Though I just realized that if you
launch perf kvm as soon as you start a VM, the VM fails to boot. Any idea why
this happens?
^ permalink raw reply [flat|nested] 10+ messages in thread
* Re: Tracing kvm: kvm_entry and kvm_exit
2013-03-04 5:36 ` Mohamad Gebai
@ 2013-03-04 5:40 ` David Ahern
2013-03-04 6:15 ` Mohamad Gebai
0 siblings, 1 reply; 10+ messages in thread
From: David Ahern @ 2013-03-04 5:40 UTC (permalink / raw)
To: Mohamad Gebai; +Cc: Stefan Hajnoczi, kvm, linux-perf-users
On 3/3/13 10:36 PM, Mohamad Gebai wrote:
> Thank you for this, I have been testing it for the last couple of days, I can
> see that perf kvm is getting more stable. Though I just realized that if you
> launch perf kvm as soon as you start a VM, the VM fails to boot. Any idea why
> this happens?
>
no, but tell me more and I'll see if I can reproduce.
host kernel version?
guest kernel?
qemu-kvm command line? (leave out the disk and network arguments -- just
the rest)
sequence of events? launching qemu-kvm in one window and at the "same
time" launching perf-kvm? Or is perf-kvm started a few seconds prior to
qemu-kvm or vice-versa?
^ permalink raw reply [flat|nested] 10+ messages in thread
* Re: Tracing kvm: kvm_entry and kvm_exit
2013-03-04 5:40 ` David Ahern
@ 2013-03-04 6:15 ` Mohamad Gebai
2013-03-05 17:23 ` David Ahern
0 siblings, 1 reply; 10+ messages in thread
From: Mohamad Gebai @ 2013-03-04 6:15 UTC (permalink / raw)
To: David Ahern; +Cc: Stefan Hajnoczi, kvm, linux-perf-users
> On 3/3/13 10:36 PM, Mohamad Gebai wrote:
> > Thank you for this, I have been testing it for the last couple of days, I
> can
> > see that perf kvm is getting more stable. Though I just realized that if
> you
> > launch perf kvm as soon as you start a VM, the VM fails to boot. Any idea
> why
> > this happens?
> >
>
> no, but tell me more and I'll see if I can reproduce.
>
Sure thing:
> host kernel version?
3.8 compiled from perf-kvm-live-3.8
> guest kernel?
3.8.1
> qemu-kvm command line? (leave out the disk and network arguments -- just
> the rest)
Actually using virt-manager for this but here's the most relevant part of the
qemu-kvm command line:
/usr/bin/qemu-kvm -name debian_test -S -M pc-1.2 -enable-kvm -m 1024 -smp
1,sockets=1,cores=1,threads=1
> sequence of events? launching qemu-kvm in one window and at the "same
> time" launching perf-kvm? Or is perf-kvm started a few seconds prior to
> qemu-kvm or vice-versa?
>
Actually qemu-kvm is launched first, then perf kvm is launched right after,
before the bootloader of the VM using this command line:
perf kvm stat -p <vm-pid> -e kvmmmu:*
^ permalink raw reply [flat|nested] 10+ messages in thread
* Re: Tracing kvm: kvm_entry and kvm_exit
2013-03-04 6:15 ` Mohamad Gebai
@ 2013-03-05 17:23 ` David Ahern
0 siblings, 0 replies; 10+ messages in thread
From: David Ahern @ 2013-03-05 17:23 UTC (permalink / raw)
To: Mohamad Gebai; +Cc: Stefan Hajnoczi, kvm, linux-perf-users
On 3/3/13 11:15 PM, Mohamad Gebai wrote:
>> host kernel version?
> 3.8 compiled from perf-kvm-live-3.8
I made no changes to the kernel side so essentially you are running v3.8
unmodified.
>> guest kernel?
> 3.8.1
>> qemu-kvm command line? (leave out the disk and network arguments -- just
>> the rest)
> Actually using virt-manager for this but here's the most relevant part of the
> qemu-kvm command line:
> /usr/bin/qemu-kvm -name debian_test -S -M pc-1.2 -enable-kvm -m 1024 -smp
> 1,sockets=1,cores=1,threads=1
ok, I take that to mean qemu-kvm 1.2.
> Actually qemu-kvm is launched first, then perf kvm is launched right after,
> before the bootloader of the VM using this command line:
> perf kvm stat -p <vm-pid> -e kvmmmu:*
I have not been able to reproduce it. Host kernel is v3.8, guest kernel
is 3.8.1-201.fc18.x86_64 (Fedora 18, latest kernel). Host CPU: Intel(R)
Xeon(R) CPU E5540 @ 2.53GHz.
qemu-kvm version is 1.2. Relevant command line (launched manually)
/usr/local/qemu-kvm/1.2/bin/qemu-system-x86_64 -m 4096 -smp
1,sockets=1,cores=1,threads=1 -S -M pc-1.2
That starts the VM with paused vcpus. Then launch perf-kvm-stat:
perf kvm stat -p $(vm-status -b f18) -e kvmmmu:*
VM boots just fine.
When I get some time I can try qemu versions 1.3 and 1.4 to see if it
makes a difference. Any output from the VM or host dmesg? What if you
start qemu manually?
David
^ permalink raw reply [flat|nested] 10+ messages in thread