kvm/x86: Hyper-V SynIC timers tracepoints
authorAndrey Smetanin <asmetanin@virtuozzo.com>
Wed, 23 Dec 2015 13:54:00 +0000 (16:54 +0300)
committerPaolo Bonzini <pbonzini@redhat.com>
Fri, 8 Jan 2016 18:04:43 +0000 (19:04 +0100)
Trace the following Hyper SynIC timers events:
* periodic timer start
* one-shot timer start
* timer callback
* timer expiration and message delivery result
* timer config setup
* timer count setup
* timer cleanup

Signed-off-by: Andrey Smetanin <asmetanin@virtuozzo.com>
CC: Gleb Natapov <gleb@kernel.org>
CC: Paolo Bonzini <pbonzini@redhat.com>
CC: Roman Kagan <rkagan@virtuozzo.com>
CC: Denis V. Lunev <den@openvz.org>
CC: qemu-devel@nongnu.org
Signed-off-by: Paolo Bonzini <pbonzini@redhat.com>
arch/x86/kvm/hyperv.c
arch/x86/kvm/trace.h

index 2d83d4598507a95b639f0dde9f9b2681dfdcd5e7..c58ba67175acde5b8b3e12dbaf84df46fb44f62c 100644 (file)
@@ -405,6 +405,9 @@ static void stimer_cleanup(struct kvm_vcpu_hv_stimer *stimer)
 {
        struct kvm_vcpu *vcpu = stimer_to_vcpu(stimer);
 
+       trace_kvm_hv_stimer_cleanup(stimer_to_vcpu(stimer)->vcpu_id,
+                                   stimer->index);
+
        hrtimer_cancel(&stimer->timer);
        clear_bit(stimer->index,
                  vcpu_to_hv_vcpu(vcpu)->stimer_pending_bitmap);
@@ -417,6 +420,8 @@ static enum hrtimer_restart stimer_timer_callback(struct hrtimer *timer)
        struct kvm_vcpu_hv_stimer *stimer;
 
        stimer = container_of(timer, struct kvm_vcpu_hv_stimer, timer);
+       trace_kvm_hv_stimer_callback(stimer_to_vcpu(stimer)->vcpu_id,
+                                    stimer->index);
        stimer_mark_pending(stimer, true);
 
        return HRTIMER_NORESTART;
@@ -448,6 +453,11 @@ static int stimer_start(struct kvm_vcpu_hv_stimer *stimer)
                } else
                        stimer->exp_time = time_now + stimer->count;
 
+               trace_kvm_hv_stimer_start_periodic(
+                                       stimer_to_vcpu(stimer)->vcpu_id,
+                                       stimer->index,
+                                       time_now, stimer->exp_time);
+
                hrtimer_start(&stimer->timer,
                              ktime_add_ns(ktime_now,
                                           100 * (stimer->exp_time - time_now)),
@@ -466,6 +476,10 @@ static int stimer_start(struct kvm_vcpu_hv_stimer *stimer)
                return 0;
        }
 
+       trace_kvm_hv_stimer_start_one_shot(stimer_to_vcpu(stimer)->vcpu_id,
+                                          stimer->index,
+                                          time_now, stimer->count);
+
        hrtimer_start(&stimer->timer,
                      ktime_add_ns(ktime_now, 100 * (stimer->count - time_now)),
                      HRTIMER_MODE_ABS);
@@ -475,6 +489,9 @@ static int stimer_start(struct kvm_vcpu_hv_stimer *stimer)
 static int stimer_set_config(struct kvm_vcpu_hv_stimer *stimer, u64 config,
                             bool host)
 {
+       trace_kvm_hv_stimer_set_config(stimer_to_vcpu(stimer)->vcpu_id,
+                                      stimer->index, config, host);
+
        stimer_cleanup(stimer);
        if ((stimer->config & HV_STIMER_ENABLE) && HV_STIMER_SINT(config) == 0)
                config &= ~HV_STIMER_ENABLE;
@@ -486,6 +503,9 @@ static int stimer_set_config(struct kvm_vcpu_hv_stimer *stimer, u64 config,
 static int stimer_set_count(struct kvm_vcpu_hv_stimer *stimer, u64 count,
                            bool host)
 {
+       trace_kvm_hv_stimer_set_count(stimer_to_vcpu(stimer)->vcpu_id,
+                                     stimer->index, count, host);
+
        stimer_cleanup(stimer);
        stimer->count = count;
        if (stimer->count == 0)
@@ -564,8 +584,13 @@ static int stimer_send_msg(struct kvm_vcpu_hv_stimer *stimer)
 
 static void stimer_expiration(struct kvm_vcpu_hv_stimer *stimer)
 {
+       int r;
+
        stimer->msg_pending = true;
-       if (!stimer_send_msg(stimer)) {
+       r = stimer_send_msg(stimer);
+       trace_kvm_hv_stimer_expiration(stimer_to_vcpu(stimer)->vcpu_id,
+                                      stimer->index, r);
+       if (!r) {
                stimer->msg_pending = false;
                if (!(stimer->config & HV_STIMER_PERIODIC))
                        stimer->config &= ~HV_STIMER_ENABLE;
index 4be350003bcedd135f41eb99307c56313f45b2c8..ad9f6a23f13961feca86340c9cda300608da8b8e 100644 (file)
@@ -1118,6 +1118,176 @@ TRACE_EVENT(kvm_hv_synic_set_msr,
                  __entry->vcpu_id, __entry->msr, __entry->data, __entry->host)
 );
 
+/*
+ * Tracepoint for stimer_set_config.
+ */
+TRACE_EVENT(kvm_hv_stimer_set_config,
+       TP_PROTO(int vcpu_id, int timer_index, u64 config, bool host),
+       TP_ARGS(vcpu_id, timer_index, config, host),
+
+       TP_STRUCT__entry(
+               __field(int, vcpu_id)
+               __field(int, timer_index)
+               __field(u64, config)
+               __field(bool, host)
+       ),
+
+       TP_fast_assign(
+               __entry->vcpu_id = vcpu_id;
+               __entry->timer_index = timer_index;
+               __entry->config = config;
+               __entry->host = host;
+       ),
+
+       TP_printk("vcpu_id %d timer %d config 0x%llx host %d",
+                 __entry->vcpu_id, __entry->timer_index, __entry->config,
+                 __entry->host)
+);
+
+/*
+ * Tracepoint for stimer_set_count.
+ */
+TRACE_EVENT(kvm_hv_stimer_set_count,
+       TP_PROTO(int vcpu_id, int timer_index, u64 count, bool host),
+       TP_ARGS(vcpu_id, timer_index, count, host),
+
+       TP_STRUCT__entry(
+               __field(int, vcpu_id)
+               __field(int, timer_index)
+               __field(u64, count)
+               __field(bool, host)
+       ),
+
+       TP_fast_assign(
+               __entry->vcpu_id = vcpu_id;
+               __entry->timer_index = timer_index;
+               __entry->count = count;
+               __entry->host = host;
+       ),
+
+       TP_printk("vcpu_id %d timer %d count %llu host %d",
+                 __entry->vcpu_id, __entry->timer_index, __entry->count,
+                 __entry->host)
+);
+
+/*
+ * Tracepoint for stimer_start(periodic timer case).
+ */
+TRACE_EVENT(kvm_hv_stimer_start_periodic,
+       TP_PROTO(int vcpu_id, int timer_index, u64 time_now, u64 exp_time),
+       TP_ARGS(vcpu_id, timer_index, time_now, exp_time),
+
+       TP_STRUCT__entry(
+               __field(int, vcpu_id)
+               __field(int, timer_index)
+               __field(u64, time_now)
+               __field(u64, exp_time)
+       ),
+
+       TP_fast_assign(
+               __entry->vcpu_id = vcpu_id;
+               __entry->timer_index = timer_index;
+               __entry->time_now = time_now;
+               __entry->exp_time = exp_time;
+       ),
+
+       TP_printk("vcpu_id %d timer %d time_now %llu exp_time %llu",
+                 __entry->vcpu_id, __entry->timer_index, __entry->time_now,
+                 __entry->exp_time)
+);
+
+/*
+ * Tracepoint for stimer_start(one-shot timer case).
+ */
+TRACE_EVENT(kvm_hv_stimer_start_one_shot,
+       TP_PROTO(int vcpu_id, int timer_index, u64 time_now, u64 count),
+       TP_ARGS(vcpu_id, timer_index, time_now, count),
+
+       TP_STRUCT__entry(
+               __field(int, vcpu_id)
+               __field(int, timer_index)
+               __field(u64, time_now)
+               __field(u64, count)
+       ),
+
+       TP_fast_assign(
+               __entry->vcpu_id = vcpu_id;
+               __entry->timer_index = timer_index;
+               __entry->time_now = time_now;
+               __entry->count = count;
+       ),
+
+       TP_printk("vcpu_id %d timer %d time_now %llu count %llu",
+                 __entry->vcpu_id, __entry->timer_index, __entry->time_now,
+                 __entry->count)
+);
+
+/*
+ * Tracepoint for stimer_timer_callback.
+ */
+TRACE_EVENT(kvm_hv_stimer_callback,
+       TP_PROTO(int vcpu_id, int timer_index),
+       TP_ARGS(vcpu_id, timer_index),
+
+       TP_STRUCT__entry(
+               __field(int, vcpu_id)
+               __field(int, timer_index)
+       ),
+
+       TP_fast_assign(
+               __entry->vcpu_id = vcpu_id;
+               __entry->timer_index = timer_index;
+       ),
+
+       TP_printk("vcpu_id %d timer %d",
+                 __entry->vcpu_id, __entry->timer_index)
+);
+
+/*
+ * Tracepoint for stimer_expiration.
+ */
+TRACE_EVENT(kvm_hv_stimer_expiration,
+       TP_PROTO(int vcpu_id, int timer_index, int msg_send_result),
+       TP_ARGS(vcpu_id, timer_index, msg_send_result),
+
+       TP_STRUCT__entry(
+               __field(int, vcpu_id)
+               __field(int, timer_index)
+               __field(int, msg_send_result)
+       ),
+
+       TP_fast_assign(
+               __entry->vcpu_id = vcpu_id;
+               __entry->timer_index = timer_index;
+               __entry->msg_send_result = msg_send_result;
+       ),
+
+       TP_printk("vcpu_id %d timer %d msg send result %d",
+                 __entry->vcpu_id, __entry->timer_index,
+                 __entry->msg_send_result)
+);
+
+/*
+ * Tracepoint for stimer_cleanup.
+ */
+TRACE_EVENT(kvm_hv_stimer_cleanup,
+       TP_PROTO(int vcpu_id, int timer_index),
+       TP_ARGS(vcpu_id, timer_index),
+
+       TP_STRUCT__entry(
+               __field(int, vcpu_id)
+               __field(int, timer_index)
+       ),
+
+       TP_fast_assign(
+               __entry->vcpu_id = vcpu_id;
+               __entry->timer_index = timer_index;
+       ),
+
+       TP_printk("vcpu_id %d timer %d",
+                 __entry->vcpu_id, __entry->timer_index)
+);
+
 #endif /* _TRACE_KVM_H */
 
 #undef TRACE_INCLUDE_PATH