| Message ID | 148664876211.595.17986015821032981184.stgit@Solace.fritz.box (mailing list archive) |
|---|---|
| State | New, archived |
| Headers | show |
On Thu, Feb 9, 2017 at 1:59 PM, Dario Faggioli <dario.faggioli@citrix.com> wrote: > 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. This sounds useful -- but what I don't quite understand is why it's useful simply to know that a vcpu was considered, and not also know specifically why it was decided against. (I'm sure you've found it useful or you wouldn't have submitted the patch.) Anyway, I can check it in as-is (if it applies). Acked-by: George Dunlap <george.dunlap@citrix.com> > > 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> > --- > Cc: George Dunlap <george.dunlap@eu.citrix.com> > --- > tools/xentrace/formats | 3 ++- > tools/xentrace/xenalyze.c | 15 +++++++++++++-- > xen/common/sched_credit2.c | 15 +++++++++++++++ > 3 files changed, 30 insertions(+), 3 deletions(-) > > diff --git a/tools/xentrace/formats b/tools/xentrace/formats > index db89f92..72c0b24 100644 > --- 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 a90da20..2678e2a 100644 > --- 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 8057abf..35d6988 100644 > --- a/xen/common/sched_credit2.c > +++ b/xen/common/sched_credit2.c > @@ -57,6 +57,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 > @@ -2498,6 +2499,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) ) > { > @@ -2546,9 +2559,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, > > > _______________________________________________ > Xen-devel mailing list > Xen-devel@lists.xen.org > https://lists.xen.org/xen-devel
On Wed, 2017-02-15 at 15:31 +0000, George Dunlap wrote: > On Thu, Feb 9, 2017 at 1:59 PM, Dario Faggioli > <dario.faggioli@citrix.com> wrote: > > > > 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. > > This sounds useful -- but what I don't quite understand is why it's > useful simply to know that a vcpu was considered, and not also know > specifically why it was decided against. (I'm sure you've found it > useful or you wouldn't have submitted the patch.) > Yeah, I see what you mean. Of course, the more info, the better. But knowing which vcpus have been skipped, is the real hard thing here. Meaning that it, in theory, was possible to reconstruct that, but only with a very tedious and error prone process of staring and noting down previous records. OTOH, once that you see which ones have been skipped --considering that there are not too many reasons for that to happen, yet-- it's fairly straightforward to guess why. And yes, as you say, I so far have found more useful to know which ones, while the why hasn't been critical for the trace analysis I've done so far. > Anyway, I can check it in as-is (if it applies). > > Acked-by: George Dunlap <george.dunlap@citrix.com> > Thanks, and fear not: I actually may end up sending a follow up patch for spitting out the reason why we skipped someone too... As you probably have understood by this point, I like a lot adding tracepoints! :-P :-P Regards, Dario
diff --git a/tools/xentrace/formats b/tools/xentrace/formats index db89f92..72c0b24 100644 --- 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 a90da20..2678e2a 100644 --- 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 8057abf..35d6988 100644 --- a/xen/common/sched_credit2.c +++ b/xen/common/sched_credit2.c @@ -57,6 +57,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 @@ -2498,6 +2499,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) ) { @@ -2546,9 +2559,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,
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> --- Cc: George Dunlap <george.dunlap@eu.citrix.com> --- tools/xentrace/formats | 3 ++- tools/xentrace/xenalyze.c | 15 +++++++++++++-- xen/common/sched_credit2.c | 15 +++++++++++++++ 3 files changed, 30 insertions(+), 3 deletions(-)