[<prev] [next>] [<thread-prev] [thread-next>] [day] [month] [year] [list]
Message-ID: <4F1659ED.6030403@gmail.com>
Date: Tue, 17 Jan 2012 22:34:37 -0700
From: David Ahern <dsahern@...il.com>
To: Xiao Guangrong <xiaoguangrong@...ux.vnet.ibm.com>
CC: Marcelo Tosatti <mtosatti@...hat.com>, Avi Kivity <avi@...hat.com>,
LKML <linux-kernel@...r.kernel.org>, KVM <kvm@...r.kernel.org>
Subject: Re: [PATCH 2/3] KVM: improve trace events of vmexit/mmio/ioport
On 01/17/2012 07:32 PM, Xiao Guangrong wrote:
>> There is an ongoing 'discussion' about modifying existing tracepoints
>> which your proposed patch violates. This is the start of it:
>>
>
>
> Hmm, i think we can still add completed tracepoints in the new version kernel,
> if old version kernel is used, we can fall back to use kvm_entry instead?
Yes, new ones are ok. I was referring to the tracepoints like kvm_pio
where you added the vcpu_id. And it is not really necessary: with
kvm_entry tracepoints it is easy to correlate vcpu to tid and even
without you still get thread base samples so events happening on a
thread are all the sample vcpu (even if you don't know whether that is
vcpu 0, 1, 2, etc).
>
> And there is a exception for mmio read, in current code, the mmio read event is
> actually used to trace the time when then read emulation is completed, i think
> we can add a tracepoint like mmio_read_begin to trace the start time of mmio read.
> So:
> - for the new kernel, we use mmio_read_begion and kvm_mmio(READ...) to calculate
> start time and end time.
> - for the old kernel, we use kvm_exit and kvm_mmio(READ...) to calculate start time
> and end time.
>
> Your idea?
>
I did play around with it a bit more today.
My concern would be adding more events may make things more precise, but
it adds more overhead and I am not sure the precision is worth it. For
example on my laptop (Penryn Core 2; a lab server with a xeon E5560
processor is much faster):
0.000002 kvm_exit reason IO_INSTRUCTION rip 0x806d0e30 info 710048 0
0.000003 kvm_emulate_insn 0:806d0e30: e4 71
0.000001 kvm_pio pio_read at 0x71 size 1 count 1
0.000001 kvm_userspace_exit reason KVM_EXIT_IO (2)
0.000003 kvm_set_irq gsi 8 level 0 source 0
0.000001 kvm_pic_set_irq chip 1 pin 0 (edge|masked)
0.000001 kvm_ioapic_set_irq pin 8 dst 1 vec=209 (Fixed|logical|edge)
total exit time: 0.000016
The first column is the delta-time between successive events for a vcpu.
Most of those events are in the rounded up microsecond range. Moving on
to the subsequent kvm_entry shows a total VMENTRY run time of 5 usecs:
ie., 16 usecs on a VMEXIT with 7 tracepoints and 5 usecs spent in a VMENTRY.
What I am getting at is that the cost of the tracepoints becomes a
significant overhead. If it costs 500nsec or 1usec to generate an event
and the time in a VMENTRY is only 5 usecs the tracepoint is a large part
of the time.
David
--
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to majordomo@...r.kernel.org
More majordomo info at http://vger.kernel.org/majordomo-info.html
Please read the FAQ at http://www.tux.org/lkml/
Powered by blists - more mailing lists