Trouble adding kvm clock trace to qemu-kvm

[Chris Thompson <cthomp@cs.umn.edu>]

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);
}

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.

Thanks,

Chris