rtxen: add traces for scheduling overhead

Signed-off-by: Sisu Xi<xisisu@gmail.com>

xen/arch/x86/domain.c

@@ -60,6 +60,8 @@
 #include <xen/numa.h>
 #include <xen/iommu.h>
 #include <compat/vcpu.h>
+#include <xen/trace.h>          /* trace schedule overhead */
+
 
 DEFINE_PER_CPU(struct vcpu *, curr_vcpu);
 DEFINE_PER_CPU(unsigned long, cr4);
@@ -1397,6 +1399,10 @@ void context_switch(struct vcpu *prev, struct vcpu *next)
 {
     unsigned int cpu = smp_processor_id();
     cpumask_t dirty_mask;
+    /* trace overhead */
+    s_time_t t1, t2;
+    int flush_tlb = 0;
+    t1 = NOW();
 
     ASSERT(local_irq_is_enabled());
 
@@ -1408,6 +1414,7 @@ void context_switch(struct vcpu *prev, struct vcpu *next)
     {
         /* Other cpus call __sync_local_execstate from flush ipi handler. */
         flush_tlb_mask(&dirty_mask);
+        flush_tlb = 1;
     }
 
     if (prev != next)
@@ -1462,7 +1469,20 @@ void context_switch(struct vcpu *prev, struct vcpu *next)
         /* Must be done with interrupts enabled */
         vpmu_load(next);
 
+    t2 = NOW();
+    TRACE_6D(TRC_SCHED_OVERHEAD_CONTEXT_SWITCH,
+             prev->domain->domain_id,
+             prev->vcpu_id,
+             next->domain->domain_id,
+             next->vcpu_id,
+             flush_tlb,
+             t2-t1);
+
+    t1 = NOW();
     context_saved(prev);
+    t2 = NOW();
+    TRACE_3D(TRC_SCHED_OVERHEAD_CONTEXT_SAVED, prev->domain->domain_id, prev->vcpu_id, t2-t1);
+
 
     if (prev != next)
         update_runstate_area(next);

xen/common/schedule.c

@@ -336,6 +336,9 @@ void sched_destroy_domain(struct domain *d)
 void vcpu_sleep_nosync(struct vcpu *v)
 {
     unsigned long flags;
+    /* trace overhead */
+    s_time_t t1, t2;
+    t1 = NOW();
 
     vcpu_schedule_lock_irqsave(v, flags);
 
@@ -349,6 +352,9 @@ void vcpu_sleep_nosync(struct vcpu *v)
 
     vcpu_schedule_unlock_irqrestore(v, flags);
 
+    t2 = NOW();
+    TRACE_3D(TRC_SCHED_OVERHEAD_SLEEP, v->domain->domain_id, v->vcpu_id, t2-t1);
+
     TRACE_2D(TRC_SCHED_SLEEP, v->domain->domain_id, v->vcpu_id);
 }
 
@@ -365,6 +371,9 @@ void vcpu_sleep_sync(struct vcpu *v)
 void vcpu_wake(struct vcpu *v)
 {
     unsigned long flags;
+    /* trace overhead */
+    s_time_t t1, t2;
+    t1 = NOW();
 
     vcpu_schedule_lock_irqsave(v, flags);
 
@@ -382,6 +391,9 @@ void vcpu_wake(struct vcpu *v)
 
     vcpu_schedule_unlock_irqrestore(v, flags);
 
+    t2 = NOW();
+    TRACE_3D(TRC_SCHED_OVERHEAD_WAKE, v->domain->domain_id, v->vcpu_id, t2-t1);
+
     TRACE_2D(TRC_SCHED_WAKE, v->domain->domain_id, v->vcpu_id);
 }
 
@@ -1146,6 +1158,8 @@ static void schedule(void)
     struct task_slice     next_slice;
     int cpu = smp_processor_id();
 
+    s_time_t t2;       /* trace scheduling latency */ 
+
     ASSERT_NOT_IN_ATOMIC();
 
     SCHED_STAT_CRANK(sched_run);
@@ -1188,6 +1202,17 @@ static void schedule(void)
     {
         pcpu_schedule_unlock_irq(cpu);
         trace_continue_running(next);
+
+        /* trace overhead */
+        t2 = NOW();
+        TRACE_6D(TRC_SCHED_OVERHEAD_SCHED_LATENCY,
+             prev->domain->domain_id,
+             prev->vcpu_id,
+             next->domain->domain_id,
+             next->vcpu_id,
+             next_slice.migrated,
+             t2-now);
+
         return continue_running(prev);
     }
 
@@ -1216,6 +1241,16 @@ static void schedule(void)
     ASSERT(next->runstate.state != RUNSTATE_running);
     vcpu_runstate_change(next, RUNSTATE_running, now);
 
+    /* trace overhead */
+    t2 = NOW();
+    TRACE_6D(TRC_SCHED_OVERHEAD_SCHED_LATENCY,
+             prev->domain->domain_id,
+             prev->vcpu_id,
+             next->domain->domain_id,
+             next->vcpu_id,
+             next_slice.migrated,
+             t2-now);
+
     /*
      * NB. Don't add any trace records from here until the actual context
      * switch, else lost_records resume will not work properly.

xen/include/public/trace.h

@@ -94,6 +94,16 @@
 
 #define TRC_SCHED_RUNSTATE_CHANGE   (TRC_SCHED_MIN + 1)
 #define TRC_SCHED_CONTINUE_RUNNING  (TRC_SCHED_MIN + 2)
+
+/* Trace to record scheduling overhead */
+#define TRC_SCHED_OVERHEAD_SCHED_LATENCY    (TRC_SCHED_MIN + 3)
+#define TRC_SCHED_OVERHEAD_CONTEXT_SWITCH   (TRC_SCHED_MIN + 4)
+#define TRC_SCHED_OVERHEAD_CONTEXT_SAVED    (TRC_SCHED_MIN + 5)
+#define TRC_SCHED_OVERHEAD_WAKE             (TRC_SCHED_MIN + 6)
+#define TRC_SCHED_OVERHEAD_SLEEP            (TRC_SCHED_MIN + 7)
+#define TRC_SCHED_OVERHEAD_SELF_SWITCH      (TRC_SCHED_MIN + 8)
+
+
 #define TRC_SCHED_DOM_ADD        (TRC_SCHED_VERBOSE +  1)
 #define TRC_SCHED_DOM_REM        (TRC_SCHED_VERBOSE +  2)
 #define TRC_SCHED_SLEEP          (TRC_SCHED_VERBOSE +  3)