Re: Trouble adding kvm clock trace to qemu-kvm

[Avi Kivity <avi@redhat.com>]

On 04/30/2011 08:00 PM, Chris Thompson wrote:
> I'm trying to add a trace to qemu-kvm that will log the value of the 
> vcpu's clock when a specific interrupt gets pushed. I'm working with 
> qemu-kvm-0.14.0 on the 2.6.32-31 kernel. I've added the following to 
> kvm_arch_try_push_interrupts in qemu-kvm-x86.c:
>
> if (irq == 41) {
>     // Get the VCPU's TSC
>     struct kvm_clock_data clock;
>     kvm_vcpu_ioctl(env, KVM_GET_CLOCK, &clock);
>     uint64_t ticks = clock.clock;
>     trace_kvm_clock_at_injection(ticks);
> }
>

This mechanism is only active with -no-kvm-irqchip; otherwise interrupt 
injection happens in the kernel.

> And here's the trace event I added:
>
> kvm_clock_at_injection(uint64_t ticks) "interrupt 41 at clock %"PRIu64""
>
> I have that trace and the virtio_blk_req_complete trace enabled. An 
> excerpt from the resulting trace output from simpletrace.py:
>
> virtio_blk_req_complete 288390365546367 30461.681 req=46972352 status=0
> kvm_clock_at_injection 288390365546578 0.211 ticks=46972352
> virtio_blk_req_complete 288390394870065 29323.487 req=46972352 status=0
> kvm_clock_at_injection 288390394870276 0.211 ticks=46972352
>
> Am I getting the guest's clock incorrectly? And even if so, why is it 
> the same as the request pointer that virtio_blk_req_complete reports?
>
> Any ideas are appreciated.

What is the 'ticks' field?

-- 
I have a truly marvellous patch that fixes the bug which this
signature is too narrow to contain.