xen/tools: tracing: trace (Credit2) runq traversal.

When traversing a Credit2 runqueue to select the
best candidate vCPU to be run next, show in the
trace which vCPUs we consider.

A bit verbose, but quite useful, considering that
we may end up looking at, but then discarding, one
of more vCPU. This will help understand which ones
are skipped and why.

Also, add how much credits the chosen vCPU has
(in the TRC_CSCHED2_RUNQ_CANDIDATE record). And,
while there, fix a bug in tools/xentrace/formats
(still in the output of TRC_CSCHED2_RUNQ_CANDIDATE).

Signed-off-by: Dario Faggioli <dario.faggioli@citrix.com>
Acked-by: George Dunlap <george.dunlap@citrix.com>

diff --git a/tools/xentrace/formats b/tools/xentrace/formats
index db89f92e9f6c64b2dd503c8d4897879334d12961..72c0b2448b19eadd660a2bfbd69d3fd43591c38b 100644 (file)
--- a/tools/xentrace/formats
+++ b/tools/xentrace/formats
@@ -65,9 +65,10 @@
 0x00022210  CPU%(cpu)d  %(tsc)d (+%(reltsc)8d)  csched2:load_check     [ lrq_id[16]:orq_id[16] = 0x%(1)08x, delta = %(2)d ]
 0x00022211  CPU%(cpu)d  %(tsc)d (+%(reltsc)8d)  csched2:load_balance   [ l_bavgload = 0x%(2)08x%(1)08x, o_bavgload = 0x%(4)08x%(3)08x, lrq_id[16]:orq_id[16] = 0x%(5)08x ]
 0x00022212  CPU%(cpu)d  %(tsc)d (+%(reltsc)8d)  csched2:pick_cpu       [ b_avgload = 0x%(2)08x%(1)08x, dom:vcpu = 0x%(3)08x, rq_id[16]:new_cpu[16] = %(4)d ]
-0x00022213  CPU%(cpu)d  %(tsc)d (+%(reltsc)8d)  csched2:runq_candidate [ dom:vcpu = 0x%(1)08x, skipped_vcpus = %(2)d tickled_cpu = %(3)d ]
+0x00022213  CPU%(cpu)d  %(tsc)d (+%(reltsc)8d)  csched2:runq_candidate [ dom:vcpu = 0x%(1)08x, credit = %(4)d, skipped_vcpus = %(3)d, tickled_cpu = %(2)d ]
 0x00022214  CPU%(cpu)d  %(tsc)d (+%(reltsc)8d)  csched2:schedule       [ rq:cpu = 0x%(1)08x, tasklet[8]:idle[8]:smt_idle[8]:tickled[8] = %(2)08x ]
 0x00022215  CPU%(cpu)d  %(tsc)d (+%(reltsc)8d)  csched2:ratelimit      [ dom:vcpu = 0x%(1)08x, runtime = %(2)d ]
+0x00022216  CPU%(cpu)d  %(tsc)d (+%(reltsc)8d)  csched2:runq_cand_chk  [ dom:vcpu = 0x%(1)08x ]
 
 0x00022801  CPU%(cpu)d  %(tsc)d (+%(reltsc)8d)  rtds:tickle        [ cpu = %(1)d ]
 0x00022802  CPU%(cpu)d  %(tsc)d (+%(reltsc)8d)  rtds:runq_pick     [ dom:vcpu = 0x%(1)08x, cur_deadline = 0x%(3)08x%(2)08x, cur_budget = 0x%(5)08x%(4)08x ]

diff --git a/tools/xentrace/xenalyze.c b/tools/xentrace/xenalyze.c
index a90da209dd311afc2f21dbc8f31574a2531eeb1c..2678e2a1eb4ae357e236edb1daeb7e40fedbd34a 100644 (file)
--- a/tools/xentrace/xenalyze.c
+++ b/tools/xentrace/xenalyze.c
@@ -7825,12 +7825,13 @@ void sched_process(struct pcpu_info *p)
                 struct {
                     unsigned vcpuid:16, domid:16;
                     unsigned tickled_cpu, skipped;
+                    int credit;
                 } *r = (typeof(r))ri->d;
 
-                printf(" %s csched2:runq_candidate d%uv%u, "
+                printf(" %s csched2:runq_candidate d%uv%u, credit = %d, "
                        "%u vcpus skipped, ",
                        ri->dump_header, r->domid, r->vcpuid,
-                       r->skipped);
+                       r->credit, r->skipped);
                 if (r->tickled_cpu == (unsigned)-1)
                     printf("no cpu was tickled\n");
                 else
@@ -7864,6 +7865,16 @@ void sched_process(struct pcpu_info *p)
                        r->runtime / 1000, r->runtime % 1000);
             }
             break;
+        case TRC_SCHED_CLASS_EVT(CSCHED2, 23): /* RUNQ_CAND_CHECK  */
+            if(opt.dump_all) {
+                struct {
+                    unsigned int vcpuid:16, domid:16;
+                } *r = (typeof(r))ri->d;
+
+                printf(" %s csched2:runq_cand_check d%uv%u\n",
+                       ri->dump_header, r->domid, r->vcpuid);
+            }
+            break;
         /* RTDS (TRC_RTDS_xxx) */
         case TRC_SCHED_CLASS_EVT(RTDS, 1): /* TICKLE           */
             if(opt.dump_all) {

diff --git a/xen/common/sched_credit2.c b/xen/common/sched_credit2.c
index 66b7f96bd9c8e31e05f524c10ac66e29329a9327..af457c1e09b57d87b26b7152ace06b25b871be8f 100644 (file)
--- a/xen/common/sched_credit2.c
+++ b/xen/common/sched_credit2.c
@@ -56,6 +56,7 @@
 #define TRC_CSCHED2_RUNQ_CANDIDATE   TRC_SCHED_CLASS_EVT(CSCHED2, 20)
 #define TRC_CSCHED2_SCHEDULE         TRC_SCHED_CLASS_EVT(CSCHED2, 21)
 #define TRC_CSCHED2_RATELIMIT        TRC_SCHED_CLASS_EVT(CSCHED2, 22)
+#define TRC_CSCHED2_RUNQ_CAND_CHECK  TRC_SCHED_CLASS_EVT(CSCHED2, 23)
 
 /*
  * WARNING: This is still in an experimental phase.  Status and work can be found at the
@@ -2494,6 +2495,18 @@ runq_candidate(struct csched2_runqueue_data *rqd,
     {
         struct csched2_vcpu * svc = list_entry(iter, struct csched2_vcpu, runq_elem);
 
+        if ( unlikely(tb_init_done) )
+        {
+            struct {
+                unsigned vcpu:16, dom:16;
+            } d;
+            d.dom = svc->vcpu->domain->domain_id;
+            d.vcpu = svc->vcpu->vcpu_id;
+            __trace_var(TRC_CSCHED2_RUNQ_CAND_CHECK, 1,
+                        sizeof(d),
+                        (unsigned char *)&d);
+        }
+
         /* Only consider vcpus that are allowed to run on this processor. */
         if ( !cpumask_test_cpu(cpu, svc->vcpu->cpu_hard_affinity) )
         {
@@ -2542,9 +2555,11 @@ runq_candidate(struct csched2_runqueue_data *rqd,
         struct {
             unsigned vcpu:16, dom:16;
             unsigned tickled_cpu, skipped;
+            int credit;
         } d;
         d.dom = snext->vcpu->domain->domain_id;
         d.vcpu = snext->vcpu->vcpu_id;
+        d.credit = snext->credit;
         d.tickled_cpu = snext->tickled_cpu;
         d.skipped = *skipped;
         __trace_var(TRC_CSCHED2_RUNQ_CANDIDATE, 1,