kvm: x86: add trace event for pvclock updates

The new trace event records:
  * the id of vcpu being updated
  * the pvclock_vcpu_time_info struct being written to guest memory

This is useful for debugging pvclock bugs, such as the bug fixed by
"[PATCH] kvm: x86: Fix kvm clock versioning.".

Signed-off-by: David Matlack <dmatlack@google.com>
Signed-off-by: Paolo Bonzini <pbonzini@redhat.com>

diff --git a/arch/x86/kvm/trace.h b/arch/x86/kvm/trace.h
index 6b06ab8748dd5ca2657ebf1cb87f039aff8f4c64..c2a34bb5ad93a8a3b5336d941c889887124d494f 100644 (file)
--- a/arch/x86/kvm/trace.h
+++ b/arch/x86/kvm/trace.h
@@ -5,6 +5,7 @@
 #include <asm/vmx.h>
 #include <asm/svm.h>
 #include <asm/clocksource.h>
+#include <asm/pvclock-abi.h>
 
 #undef TRACE_SYSTEM
 #define TRACE_SYSTEM kvm
@@ -877,6 +878,42 @@ TRACE_EVENT(kvm_ple_window,
 #define trace_kvm_ple_window_shrink(vcpu_id, new, old) \
        trace_kvm_ple_window(false, vcpu_id, new, old)
 
+TRACE_EVENT(kvm_pvclock_update,
+       TP_PROTO(unsigned int vcpu_id, struct pvclock_vcpu_time_info *pvclock),
+       TP_ARGS(vcpu_id, pvclock),
+
+       TP_STRUCT__entry(
+               __field(        unsigned int,   vcpu_id                 )
+               __field(        __u32,          version                 )
+               __field(        __u64,          tsc_timestamp           )
+               __field(        __u64,          system_time             )
+               __field(        __u32,          tsc_to_system_mul       )
+               __field(        __s8,           tsc_shift               )
+               __field(        __u8,           flags                   )
+       ),
+
+       TP_fast_assign(
+               __entry->vcpu_id           = vcpu_id;
+               __entry->version           = pvclock->version;
+               __entry->tsc_timestamp     = pvclock->tsc_timestamp;
+               __entry->system_time       = pvclock->system_time;
+               __entry->tsc_to_system_mul = pvclock->tsc_to_system_mul;
+               __entry->tsc_shift         = pvclock->tsc_shift;
+               __entry->flags             = pvclock->flags;
+       ),
+
+       TP_printk("vcpu_id %u, pvclock { version %u, tsc_timestamp 0x%llx, "
+                 "system_time 0x%llx, tsc_to_system_mul 0x%x, tsc_shift %d, "
+                 "flags 0x%x }",
+                 __entry->vcpu_id,
+                 __entry->version,
+                 __entry->tsc_timestamp,
+                 __entry->system_time,
+                 __entry->tsc_to_system_mul,
+                 __entry->tsc_shift,
+                 __entry->flags)
+);
+
 #endif /* _TRACE_KVM_H */
 
 #undef TRACE_INCLUDE_PATH

diff --git a/arch/x86/kvm/x86.c b/arch/x86/kvm/x86.c
index 8bf37d0ab40460f8457a04053e77a8af31fb3022..f85da5cb6aa6465f942468d61fc136d1d0626459 100644 (file)
--- a/arch/x86/kvm/x86.c
+++ b/arch/x86/kvm/x86.c
@@ -1661,6 +1661,8 @@ static int kvm_guest_time_update(struct kvm_vcpu *v)
 
        vcpu->hv_clock.flags = pvclock_flags;
 
+       trace_kvm_pvclock_update(v->vcpu_id, &vcpu->hv_clock);
+
        kvm_write_guest_cached(v->kvm, &vcpu->pv_time,
                                &vcpu->hv_clock,
                                sizeof(vcpu->hv_clock));