[Date Prev][Date Next][Thread Prev][Thread Next][Date Index][Thread Index] Re: [Xen-devel] [PATCH v2 10/10] xen/tools: tracing: always report how long next slice will be.
On Thu, Feb 9, 2017 at 1:59 PM, Dario Faggioli <dario.faggioli@xxxxxxxxxx> wrote: > In fact, it is quite useful a pice of information, > to know how long it is the "next time slice" a vCPU > has been granted. It allows one to assume (and then > check) when the scheduler is supposed to run next, > and other things. > > While this information is indeed reported when a > context switch happens, it is not when the same vCPU > that is running, continues to run. The patch looks fine; but the description seems a bit round-about. I think I would have said something like: --- xen: Report next slice time when continuing as well as switching We record trace information about the next timeslice when switching to a different vcpu, but not when continuing to run the same cpu. This information is quite useful; so add a trace including that information on the 'continue_running' path as well. --- What do you think? -George > > Fix that, with the following outcome. > > Before this change: > > csched2:schedule cpu 9, rq# 1, idle, SMT idle, tickled > csched2:runq_candidate d0v3, 0 vcpus skipped, cpu 9 was tickled > sched_switch prev d32767v9, run for 991.186us > sched_switch next d0v3, was runnable for 2.515us, next slice 10000.0us > sched_switch prev d32767v9 next d0v3 ^^^^^^^^^^^^^^^^^^^^ > runstate_change d32767v9 running->runnable > ... > csched2:schedule cpu 2, rq# 0, busy, not tickled > csched2:burn_credits d1v5, credit = 9996950, delta = 502913 > csched2:runq_candidate d1v5, 0 vcpus skipped, no cpu was tickled > runstate_continue d1v5 running->running > ????????????? > > That is, in the second block, it is shown that d1v5 > was already running and will continue to do so, > but we have no idea for how long. > > OTOH, after the change: > > csched2:schedule cpu 1, rq# 0, busy, not tickled > csched2:burn_credits d0v8, credit = 9998645, delta = 12104 > csched2:runq_candidate d0v8, credit = 9998645, 0 vcpus skipped, no cpu was > tickled > sched_switch continue d0v8, run for 1125.820us, next slice 9998.645us > runstate_continue d0v8 running->running ^^^^^^^^^^^^^^^^^^^^^ > > Signed-off-by: Dario Faggioli <dario.faggioli@xxxxxxxxxx> > --- > Cc: George Dunlap <george.dunlap@xxxxxxxxxxxxx> > --- > tools/xentrace/formats | 1 + > tools/xentrace/xenalyze.c | 17 +++++++++++++++++ > xen/common/schedule.c | 4 ++++ > xen/include/public/trace.h | 1 + > 4 files changed, 23 insertions(+) > > diff --git a/tools/xentrace/formats b/tools/xentrace/formats > index 72c0b24..a055231 100644 > --- a/tools/xentrace/formats > +++ b/tools/xentrace/formats > @@ -35,6 +35,7 @@ > 0x0002800e CPU%(cpu)d %(tsc)d (+%(reltsc)8d) switch_infprev [ dom:vcpu > = 0x%(1)04x%(2)04x, runtime = %(3)d ] > 0x0002800f CPU%(cpu)d %(tsc)d (+%(reltsc)8d) switch_infnext [ > new_dom:vcpu = 0x%(1)04x%(2)04x, time = %(3)d, r_time = %(4)d ] > 0x00028010 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) domain_shutdown_code [ > dom:vcpu = 0x%(1)04x%(2)04x, reason = 0x%(3)08x ] > +0x00028011 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) switch_infcont [ dom:vcpu > = 0x%(1)04x%(2)04x, runtime = %(3)d, r_time = %(4)d ] > > 0x00022001 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) csched:sched_tasklet > 0x00022002 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) csched:account_start [ > dom:vcpu = 0x%(1)04x%(2)04x, active = %(3)d ] > diff --git a/tools/xentrace/xenalyze.c b/tools/xentrace/xenalyze.c > index 2678e2a..68ffcc2 100644 > --- a/tools/xentrace/xenalyze.c > +++ b/tools/xentrace/xenalyze.c > @@ -7528,6 +7528,23 @@ void sched_process(struct pcpu_info *p) > printf("\n"); > } > break; > + case TRC_SCHED_SWITCH_INFCONT: > + if(opt.dump_all) > + { > + struct { > + unsigned int domid, vcpuid, rsince; > + int slice; > + } *r = (typeof(r))ri->d; > + > + printf(" %s sched_switch continue d%uv%u, run for %u.%uus", > + ri->dump_header, r->domid, r->vcpuid, > + r->rsince / 1000, r->rsince % 1000); > + if ( r->slice > 0 ) > + printf(", next slice %u.%uus", r->slice / 1000, > + r->slice % 1000); > + printf("\n"); > + } > + break; > case TRC_SCHED_CTL: > case TRC_SCHED_S_TIMER_FN: > case TRC_SCHED_T_TIMER_FN: > diff --git a/xen/common/schedule.c b/xen/common/schedule.c > index e4320f3..495f138 100644 > --- a/xen/common/schedule.c > +++ b/xen/common/schedule.c > @@ -1398,6 +1398,10 @@ static void schedule(void) > if ( unlikely(prev == next) ) > { > pcpu_schedule_unlock_irq(lock, cpu); > + TRACE_4D(TRC_SCHED_SWITCH_INFCONT, > + next->domain->domain_id, next->vcpu_id, > + now - prev->runstate.state_entry_time, > + next_slice.time); > trace_continue_running(next); > return continue_running(prev); > } > diff --git a/xen/include/public/trace.h b/xen/include/public/trace.h > index 5ef9c37..7f2e891 100644 > --- a/xen/include/public/trace.h > +++ b/xen/include/public/trace.h > @@ -115,6 +115,7 @@ > #define TRC_SCHED_SWITCH_INFPREV (TRC_SCHED_VERBOSE + 14) > #define TRC_SCHED_SWITCH_INFNEXT (TRC_SCHED_VERBOSE + 15) > #define TRC_SCHED_SHUTDOWN_CODE (TRC_SCHED_VERBOSE + 16) > +#define TRC_SCHED_SWITCH_INFCONT (TRC_SCHED_VERBOSE + 17) > > #define TRC_DOM0_DOM_ADD (TRC_DOM0_DOMOPS + 1) > #define TRC_DOM0_DOM_REM (TRC_DOM0_DOMOPS + 2) > > > _______________________________________________ > Xen-devel mailing list > Xen-devel@xxxxxxxxxxxxx > https://lists.xen.org/xen-devel _______________________________________________ Xen-devel mailing list Xen-devel@xxxxxxxxxxxxx https://lists.xen.org/xen-devel
|
Lists.xenproject.org is hosted with RackSpace, monitoring our |