| Message ID | 147145433038.25877.16124577573706461350.stgit@Solace.fritz.box (mailing list archive) |
|---|---|
| State | New, archived |
| Headers | show |
On 17/08/16 18:18, Dario Faggioli wrote: > There are some scheduling related trace records that > are not being taken care of (and hence only dumped as > raw records). > > Some of them are being introduced in this series, while > other were just neglected by previous patches. > > Add support for them. > > Signed-off-by: Dario Faggioli <dario.faggioli@citrix.com> Acked-by: George Dunlap <george.dunlap@citrix.com> > --- > Cc: George Dunlap <george.dunlap@eu.citrix.com> > Cc: Ian Jackson <ian.jackson@eu.citrix.com> > Cc: Wei Liu <wei.liu2@citrix.com> > --- > tools/xentrace/formats | 8 ++++ > tools/xentrace/xenalyze.c | 101 +++++++++++++++++++++++++++++++++++++++++++++ > 2 files changed, 109 insertions(+) > > diff --git a/tools/xentrace/formats b/tools/xentrace/formats > index adff681..3488a06 100644 > --- a/tools/xentrace/formats > +++ b/tools/xentrace/formats > @@ -42,6 +42,10 @@ > 0x00022004 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) csched:stolen_vcpu [ dom:vcpu = 0x%(2)04x%(3)04x, from = %(1)d ] > 0x00022005 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) csched:picked_cpu [ dom:vcpu = 0x%(1)04x%(2)04x, cpu = %(3)d ] > 0x00022006 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) csched:tickle [ cpu = %(1)d ] > +0x00022007 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) csched:boost [ dom:vcpu = 0x%(1)04x%(2)04x ] > +0x00022008 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) csched:unboost [ dom:vcpu = 0x%(1)04x%(2)04x ] > +0x00022009 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) csched:schedule [ cpu = %(1)d, tasklet_scheduled = %(2)d, was_idle = %(3)d ] > +0x0002200A CPU%(cpu)d %(tsc)d (+%(reltsc)8d) csched:ratelimit [ dom:vcpu = 0x%(1)04x%(2)04x, runtime = %(3)d ] > > 0x00022201 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) csched2:tick > 0x00022202 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) csched2:runq_pos [ dom:vcpu = 0x%(1)08x, pos = %(2)d] > @@ -61,12 +65,16 @@ > 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, runq_pos = %(2)d tickled_cpu = %(3)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 ] > > 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 ] > 0x00022803 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) rtds:burn_budget [ dom:vcpu = 0x%(1)08x, cur_budget = 0x%(3)08x%(2)08x, delta = %(4)d ] > 0x00022804 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) rtds:repl_budget [ dom:vcpu = 0x%(1)08x, cur_deadline = 0x%(3)08x%(2)08x, cur_budget = 0x%(5)08x%(4)08x ] > 0x00022805 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) rtds:sched_tasklet > +0x00022806 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) rtds:schedule [ cpu[16]:tasklet[8]:idle[4]:tickled[4] = %(1)08x ] > > 0x00041001 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) domain_create [ dom = 0x%(1)08x ] > 0x00041002 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) domain_destroy [ dom = 0x%(1)08x ] > diff --git a/tools/xentrace/xenalyze.c b/tools/xentrace/xenalyze.c > index 58a8d41..aaff1d9 100644 > --- a/tools/xentrace/xenalyze.c > +++ b/tools/xentrace/xenalyze.c > @@ -7590,6 +7590,50 @@ void sched_process(struct pcpu_info *p) > ri->dump_header, r->cpu); > } > break; > + case TRC_SCHED_CLASS_EVT(CSCHED, 7): /* BOOST_START */ > + if(opt.dump_all) { > + struct { > + unsigned int domid, vcpuid; > + } *r = (typeof(r))ri->d; > + > + printf(" %s csched: d%uv%u boosted\n", > + ri->dump_header, r->domid, r->vcpuid); > + } > + break; > + case TRC_SCHED_CLASS_EVT(CSCHED, 8): /* BOOST_END */ > + if(opt.dump_all) { > + struct { > + unsigned int domid, vcpuid; > + } *r = (typeof(r))ri->d; > + > + printf(" %s csched: d%uv%u unboosted\n", > + ri->dump_header, r->domid, r->vcpuid); > + } > + break; > + case TRC_SCHED_CLASS_EVT(CSCHED, 9): /* SCHEDULE */ > + if(opt.dump_all) { > + struct { > + unsigned int cpu, tasklet, idle; > + } *r = (typeof(r))ri->d; > + > + printf(" %s csched:schedule cpu %u, %s%s\n", > + ri->dump_header, r->cpu, > + r->tasklet ? ", tasklet scheduled" : "", > + r->idle ? ", idle" : ", busy"); > + } > + break; > + case TRC_SCHED_CLASS_EVT(CSCHED, 10): /* RATELIMIT */ > + if(opt.dump_all) { > + struct { > + unsigned int domid, vcpuid; > + unsigned int runtime; > + } *r = (typeof(r))ri->d; > + > + printf(" %s csched:ratelimit, d%uv%u run only %u.%uus\n", > + ri->dump_header, r->domid, r->vcpuid, > + r->runtime / 1000, r->runtime % 1000); > + } > + break; > /* CREDIT 2 (TRC_CSCHED2_xxx) */ > case TRC_SCHED_CLASS_EVT(CSCHED2, 1): /* TICK */ > case TRC_SCHED_CLASS_EVT(CSCHED2, 4): /* CREDIT_ADD */ > @@ -7779,6 +7823,50 @@ void sched_process(struct pcpu_info *p) > ri->dump_header, r->domid, r->vcpuid, r->rqi, r->cpu); > } > break; > + case TRC_SCHED_CLASS_EVT(CSCHED2, 20): /* RUNQ_CANDIDATE */ > + if (opt.dump_all) { > + struct { > + unsigned vcpuid:16, domid:16; > + unsigned tickled_cpu, position; > + } *r = (typeof(r))ri->d; > + > + printf(" %s csched2:runq_candidate d%uv%u, " > + "pos in runq %u, ", > + ri->dump_header, r->domid, r->vcpuid, > + r->position); > + if (r->tickled_cpu == (unsigned)-1) > + printf("no cpu was tickled"); > + else > + printf("cpu %u was tickled\n", r->tickled_cpu); > + } > + break; > + case TRC_SCHED_CLASS_EVT(CSCHED2, 21): /* SCHEDULE */ > + if (opt.dump_all) { > + struct { > + unsigned cpu:16, rqi:16; > + unsigned tasklet:8, idle:8, smt_idle:8, tickled:8; > + } *r = (typeof(r))ri->d; > + > + printf(" %s csched2:schedule cpu %u, rq# %u%s%s%s%s\n", > + ri->dump_header, r->cpu, r->rqi, > + r->tasklet ? ", tasklet scheduled" : "", > + r->idle ? ", idle" : ", busy", > + r->idle ? (r->smt_idle ? ", SMT idle" : ", SMT busy") : "", > + r->tickled ? ", tickled" : ", not tickled"); > + } > + break; > + case TRC_SCHED_CLASS_EVT(CSCHED2, 22): /* RATELIMIT */ > + if (opt.dump_all) { > + struct { > + unsigned int vcpuid:16, domid:16; > + unsigned int runtime; > + } *r = (typeof(r))ri->d; > + > + printf(" %s csched2:ratelimit, d%uv%u run only %u.%uus\n", > + ri->dump_header, r->domid, r->vcpuid, > + r->runtime / 1000, r->runtime % 1000); > + } > + break; > /* RTDS (TRC_RTDS_xxx) */ > case TRC_SCHED_CLASS_EVT(RTDS, 1): /* TICKLE */ > if(opt.dump_all) { > @@ -7831,6 +7919,19 @@ void sched_process(struct pcpu_info *p) > if(opt.dump_all) > printf(" %s rtds:sched_tasklet\n", ri->dump_header); > break; > + case TRC_SCHED_CLASS_EVT(RTDS, 6): /* SCHEDULE */ > + if (opt.dump_all) { > + struct { > + unsigned cpu:16, tasklet:8, idle:4, tickled:4; > + } __attribute__((packed)) *r = (typeof(r))ri->d; > + > + printf(" %s rtds:schedule cpu %u, %s%s%s\n", > + ri->dump_header, r->cpu, > + r->tasklet ? ", tasklet scheduled" : "", > + r->idle ? ", idle" : ", busy", > + r->tickled ? ", tickled" : ", not tickled"); > + } > + break; > default: > process_generic(ri); > } >
diff --git a/tools/xentrace/formats b/tools/xentrace/formats index adff681..3488a06 100644 --- a/tools/xentrace/formats +++ b/tools/xentrace/formats @@ -42,6 +42,10 @@ 0x00022004 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) csched:stolen_vcpu [ dom:vcpu = 0x%(2)04x%(3)04x, from = %(1)d ] 0x00022005 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) csched:picked_cpu [ dom:vcpu = 0x%(1)04x%(2)04x, cpu = %(3)d ] 0x00022006 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) csched:tickle [ cpu = %(1)d ] +0x00022007 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) csched:boost [ dom:vcpu = 0x%(1)04x%(2)04x ] +0x00022008 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) csched:unboost [ dom:vcpu = 0x%(1)04x%(2)04x ] +0x00022009 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) csched:schedule [ cpu = %(1)d, tasklet_scheduled = %(2)d, was_idle = %(3)d ] +0x0002200A CPU%(cpu)d %(tsc)d (+%(reltsc)8d) csched:ratelimit [ dom:vcpu = 0x%(1)04x%(2)04x, runtime = %(3)d ] 0x00022201 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) csched2:tick 0x00022202 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) csched2:runq_pos [ dom:vcpu = 0x%(1)08x, pos = %(2)d] @@ -61,12 +65,16 @@ 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, runq_pos = %(2)d tickled_cpu = %(3)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 ] 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 ] 0x00022803 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) rtds:burn_budget [ dom:vcpu = 0x%(1)08x, cur_budget = 0x%(3)08x%(2)08x, delta = %(4)d ] 0x00022804 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) rtds:repl_budget [ dom:vcpu = 0x%(1)08x, cur_deadline = 0x%(3)08x%(2)08x, cur_budget = 0x%(5)08x%(4)08x ] 0x00022805 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) rtds:sched_tasklet +0x00022806 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) rtds:schedule [ cpu[16]:tasklet[8]:idle[4]:tickled[4] = %(1)08x ] 0x00041001 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) domain_create [ dom = 0x%(1)08x ] 0x00041002 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) domain_destroy [ dom = 0x%(1)08x ] diff --git a/tools/xentrace/xenalyze.c b/tools/xentrace/xenalyze.c index 58a8d41..aaff1d9 100644 --- a/tools/xentrace/xenalyze.c +++ b/tools/xentrace/xenalyze.c @@ -7590,6 +7590,50 @@ void sched_process(struct pcpu_info *p) ri->dump_header, r->cpu); } break; + case TRC_SCHED_CLASS_EVT(CSCHED, 7): /* BOOST_START */ + if(opt.dump_all) { + struct { + unsigned int domid, vcpuid; + } *r = (typeof(r))ri->d; + + printf(" %s csched: d%uv%u boosted\n", + ri->dump_header, r->domid, r->vcpuid); + } + break; + case TRC_SCHED_CLASS_EVT(CSCHED, 8): /* BOOST_END */ + if(opt.dump_all) { + struct { + unsigned int domid, vcpuid; + } *r = (typeof(r))ri->d; + + printf(" %s csched: d%uv%u unboosted\n", + ri->dump_header, r->domid, r->vcpuid); + } + break; + case TRC_SCHED_CLASS_EVT(CSCHED, 9): /* SCHEDULE */ + if(opt.dump_all) { + struct { + unsigned int cpu, tasklet, idle; + } *r = (typeof(r))ri->d; + + printf(" %s csched:schedule cpu %u, %s%s\n", + ri->dump_header, r->cpu, + r->tasklet ? ", tasklet scheduled" : "", + r->idle ? ", idle" : ", busy"); + } + break; + case TRC_SCHED_CLASS_EVT(CSCHED, 10): /* RATELIMIT */ + if(opt.dump_all) { + struct { + unsigned int domid, vcpuid; + unsigned int runtime; + } *r = (typeof(r))ri->d; + + printf(" %s csched:ratelimit, d%uv%u run only %u.%uus\n", + ri->dump_header, r->domid, r->vcpuid, + r->runtime / 1000, r->runtime % 1000); + } + break; /* CREDIT 2 (TRC_CSCHED2_xxx) */ case TRC_SCHED_CLASS_EVT(CSCHED2, 1): /* TICK */ case TRC_SCHED_CLASS_EVT(CSCHED2, 4): /* CREDIT_ADD */ @@ -7779,6 +7823,50 @@ void sched_process(struct pcpu_info *p) ri->dump_header, r->domid, r->vcpuid, r->rqi, r->cpu); } break; + case TRC_SCHED_CLASS_EVT(CSCHED2, 20): /* RUNQ_CANDIDATE */ + if (opt.dump_all) { + struct { + unsigned vcpuid:16, domid:16; + unsigned tickled_cpu, position; + } *r = (typeof(r))ri->d; + + printf(" %s csched2:runq_candidate d%uv%u, " + "pos in runq %u, ", + ri->dump_header, r->domid, r->vcpuid, + r->position); + if (r->tickled_cpu == (unsigned)-1) + printf("no cpu was tickled"); + else + printf("cpu %u was tickled\n", r->tickled_cpu); + } + break; + case TRC_SCHED_CLASS_EVT(CSCHED2, 21): /* SCHEDULE */ + if (opt.dump_all) { + struct { + unsigned cpu:16, rqi:16; + unsigned tasklet:8, idle:8, smt_idle:8, tickled:8; + } *r = (typeof(r))ri->d; + + printf(" %s csched2:schedule cpu %u, rq# %u%s%s%s%s\n", + ri->dump_header, r->cpu, r->rqi, + r->tasklet ? ", tasklet scheduled" : "", + r->idle ? ", idle" : ", busy", + r->idle ? (r->smt_idle ? ", SMT idle" : ", SMT busy") : "", + r->tickled ? ", tickled" : ", not tickled"); + } + break; + case TRC_SCHED_CLASS_EVT(CSCHED2, 22): /* RATELIMIT */ + if (opt.dump_all) { + struct { + unsigned int vcpuid:16, domid:16; + unsigned int runtime; + } *r = (typeof(r))ri->d; + + printf(" %s csched2:ratelimit, d%uv%u run only %u.%uus\n", + ri->dump_header, r->domid, r->vcpuid, + r->runtime / 1000, r->runtime % 1000); + } + break; /* RTDS (TRC_RTDS_xxx) */ case TRC_SCHED_CLASS_EVT(RTDS, 1): /* TICKLE */ if(opt.dump_all) { @@ -7831,6 +7919,19 @@ void sched_process(struct pcpu_info *p) if(opt.dump_all) printf(" %s rtds:sched_tasklet\n", ri->dump_header); break; + case TRC_SCHED_CLASS_EVT(RTDS, 6): /* SCHEDULE */ + if (opt.dump_all) { + struct { + unsigned cpu:16, tasklet:8, idle:4, tickled:4; + } __attribute__((packed)) *r = (typeof(r))ri->d; + + printf(" %s rtds:schedule cpu %u, %s%s%s\n", + ri->dump_header, r->cpu, + r->tasklet ? ", tasklet scheduled" : "", + r->idle ? ", idle" : ", busy", + r->tickled ? ", tickled" : ", not tickled"); + } + break; default: process_generic(ri); }
There are some scheduling related trace records that are not being taken care of (and hence only dumped as raw records). Some of them are being introduced in this series, while other were just neglected by previous patches. Add support for them. Signed-off-by: Dario Faggioli <dario.faggioli@citrix.com> --- Cc: George Dunlap <george.dunlap@eu.citrix.com> Cc: Ian Jackson <ian.jackson@eu.citrix.com> Cc: Wei Liu <wei.liu2@citrix.com> --- tools/xentrace/formats | 8 ++++ tools/xentrace/xenalyze.c | 101 +++++++++++++++++++++++++++++++++++++++++++++ 2 files changed, 109 insertions(+)