| Message ID | 147145432341.25877.7540974364706702.stgit@Solace.fritz.box (mailing list archive) |
|---|---|
| State | New, archived |
| Headers | show |
On 17/08/16 18:18, Dario Faggioli wrote: > In both Credit2's trace records relative to checking > whether we want to preempt a vcpu (in runq_tickle()), > and to credits being burn, make it explicit on which > pcpu the vcpu being considered is running. > > Such information isn't currently available, not even > by looking at on which pcpu the events happen, as we > do both the above operation from a certain pcpu on > vcpus running on different pcpus. But you should be able to tell where a given vcpu is currently running from the runstate changes, right? Obviously xentrace_format couldn't tell you that, but xenalyze should be able to, unless there were lost trace records on the vcpu in question. My modus operandi has been "try to keep trace volume from growing" rather than "wait until trace volume is noticably an issue and reduce it". Presumably you've been doing a lot of tracing -- do you think I should change my approach? -George
On Tue, 2016-09-20 at 15:35 +0100, George Dunlap wrote: > On 17/08/16 18:18, Dario Faggioli wrote: > > > > In both Credit2's trace records relative to checking > > whether we want to preempt a vcpu (in runq_tickle()), > > and to credits being burn, make it explicit on which > > pcpu the vcpu being considered is running. > > > > Such information isn't currently available, not even > > by looking at on which pcpu the events happen, as we > > do both the above operation from a certain pcpu on > > vcpus running on different pcpus. > > But you should be able to tell where a given vcpu is currently > running > from the runstate changes, right? Obviously xentrace_format couldn't > tell you that, but xenalyze should be able to, unless there were lost > trace records on the vcpu in question. > Well, yes and no. For instance, burn_credits() is not only called from csched_schedule(), where indeed we have the information in close records. It's also called from inside runq_tickle() itself (as we want to update the credits of the various vcpus we are considering preempting), which in turns can be called during vcpu wakeup. In that case, knowing where a certain vcpu that we're asking to burn its credit is running, may mean going quite a bit up in the trace, to find its last context switch/runstate change, which is not always the easiest thing to do. It indeed can be scripted, but when _looking_ at a trace, trying to figure out why you're observing this or that weird behavior, I think knowing v->processor is a useful information. > My modus operandi has been "try to keep trace volume from growing" > rather than "wait until trace volume is noticably an issue and reduce > it". Presumably you've been doing a lot of tracing -- do you think I > should change my approach? > No, I think the approach is a good one. It's just that, in this case, I think this is useful information, so I'll keep the patch in v2. But if you're not sure, just ignore it, and we can sort this at another time. :-) Thanks and Regards, Dario
On 29/09/16 18:23, Dario Faggioli wrote: > On Tue, 2016-09-20 at 15:35 +0100, George Dunlap wrote: >> On 17/08/16 18:18, Dario Faggioli wrote: >>> >>> In both Credit2's trace records relative to checking >>> whether we want to preempt a vcpu (in runq_tickle()), >>> and to credits being burn, make it explicit on which >>> pcpu the vcpu being considered is running. >>> >>> Such information isn't currently available, not even >>> by looking at on which pcpu the events happen, as we >>> do both the above operation from a certain pcpu on >>> vcpus running on different pcpus. >> >> But you should be able to tell where a given vcpu is currently >> running >> from the runstate changes, right? Obviously xentrace_format couldn't >> tell you that, but xenalyze should be able to, unless there were lost >> trace records on the vcpu in question. >> > Well, yes and no. For instance, burn_credits() is not only called from > csched_schedule(), where indeed we have the information in close > records. It's also called from inside runq_tickle() itself (as we want > to update the credits of the various vcpus we are considering > preempting), which in turns can be called during vcpu wakeup. > > In that case, knowing where a certain vcpu that we're asking to burn > its credit is running, may mean going quite a bit up in the trace, to > find its last context switch/runstate change, which is not always the > easiest thing to do. > > It indeed can be scripted, but when _looking_ at a trace, trying to > figure out why you're observing this or that weird behavior, I think > knowing v->processor is a useful information. But if you're using xenalyze, xenalyze will know where the vcpu is running / was last run; couldn't you have xenalyze report that information when dumping the burn_credits record? Again, I'm just pushing back to make sure the additional trace volume is actually necessary. :-) -George
On Thu, 2016-09-29 at 18:28 +0100, George Dunlap wrote: > On 29/09/16 18:23, Dario Faggioli wrote: > > In that case, knowing where a certain vcpu that we're asking to > > burn > > its credit is running, may mean going quite a bit up in the trace, > > to > > find its last context switch/runstate change, which is not always > > the > > easiest thing to do. > > > > It indeed can be scripted, but when _looking_ at a trace, trying to > > figure out why you're observing this or that weird behavior, I > > think > > knowing v->processor is a useful information. > > But if you're using xenalyze, xenalyze will know where the vcpu is > running / was last run; couldn't you have xenalyze report that > information when dumping the burn_credits record? > Yes, this is indeed a possibility. Xenalyze is not doing anything like or similar to that for now (at least, not in dump mode), that's probably why it did not occur to me that this could be done. But yeah, we've already discussed that it can become more intelligent and do more complex things and more refined reports, and this can well fit into that. > Again, I'm just pushing back to make sure the additional trace volume > is > actually necessary. :-) > Sure, that's fine! Ok, let's drop this patch for now then. :-) Regards, Dario
diff --git a/tools/xentrace/formats b/tools/xentrace/formats index 0de7990..adff681 100644 --- a/tools/xentrace/formats +++ b/tools/xentrace/formats @@ -45,9 +45,9 @@ 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] -0x00022203 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) csched2:credit burn [ dom:vcpu = 0x%(1)08x, credit = %(2)d, delta = %(3)d ] +0x00022203 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) csched2:credit burn [ dom:vcpu = 0x%(1)08x, cpu = %(3)d, credit = %(2)d, delta = %(4)d ] 0x00022204 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) csched2:credit_add -0x00022205 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) csched2:tickle_check [ dom:vcpu = 0x%(1)08x, credit = %(2)d ] +0x00022205 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) csched2:tickle_check [ dom:vcpu = 0x%(1)08x, cpu = %(2)d, credit = %(3)d ] 0x00022206 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) csched2:tickle [ cpu = %(1)d ] 0x00022207 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) csched2:credit_reset [ dom:vcpu = 0x%(1)08x, cr_start = %(2)d, cr_end = %(3)d, mult = %(4)d ] 0x00022208 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) csched2:sched_tasklet diff --git a/tools/xentrace/xenalyze.c b/tools/xentrace/xenalyze.c index 0b697d0..58a8d41 100644 --- a/tools/xentrace/xenalyze.c +++ b/tools/xentrace/xenalyze.c @@ -7607,24 +7607,27 @@ void sched_process(struct pcpu_info *p) case TRC_SCHED_CLASS_EVT(CSCHED2, 3): /* CREDIT_BURN */ if(opt.dump_all) { struct { - unsigned int vcpuid:16, domid:16, credit; + unsigned int vcpuid:16, domid:16, credit, cpu; int delta; } *r = (typeof(r))ri->d; - printf(" %s csched2:burn_credits d%uv%u, credit = %u, delta = %d\n", + printf(" %s csched2:burn_credits d%uv%u, " + "on cpu = %u, credit = %u, delta = %d\n", ri->dump_header, r->domid, r->vcpuid, - r->credit, r->delta); + r->cpu, r->credit, r->delta); } break; case TRC_SCHED_CLASS_EVT(CSCHED2, 5): /* TICKLE_CHECK */ if(opt.dump_all) { struct { unsigned int vcpuid:16, domid:16; - unsigned int credit; + unsigned int cpu, credit; } *r = (typeof(r))ri->d; - printf(" %s csched2:tickle_check d%uv%u, credit = %u\n", - ri->dump_header, r->domid, r->vcpuid, r->credit); + printf(" %s csched2:tickle_check d%uv%u, " + "on cpu = %u, credits = %u\n", + ri->dump_header, r->domid, r->vcpuid, + r->cpu, r->credit); } break; case TRC_SCHED_CLASS_EVT(CSCHED2, 6): /* TICKLE */ diff --git a/xen/common/sched_credit2.c b/xen/common/sched_credit2.c index 164296b..c8396a8 100644 --- a/xen/common/sched_credit2.c +++ b/xen/common/sched_credit2.c @@ -1027,11 +1027,12 @@ runq_tickle(const struct scheduler *ops, struct csched2_vcpu *new, s_time_t now) { struct { unsigned vcpu:16, dom:16; - unsigned credit; + unsigned cpu, credit; } d; d.dom = cur->vcpu->domain->domain_id; d.vcpu = cur->vcpu->vcpu_id; d.credit = cur->credit; + d.cpu = i; __trace_var(TRC_CSCHED2_TICKLE_CHECK, 1, sizeof(d), (unsigned char *)&d); @@ -1181,12 +1182,13 @@ void burn_credits(struct csched2_runqueue_data *rqd, { struct { unsigned vcpu:16, dom:16; - unsigned credit; + unsigned credit, cpu; int delta; } d; d.dom = svc->vcpu->domain->domain_id; d.vcpu = svc->vcpu->vcpu_id; d.credit = svc->credit; + d.cpu = svc->vcpu->processor; d.delta = delta; __trace_var(TRC_CSCHED2_CREDIT_BURN, 1, sizeof(d),
In both Credit2's trace records relative to checking whether we want to preempt a vcpu (in runq_tickle()), and to credits being burn, make it explicit on which pcpu the vcpu being considered is running. Such information isn't currently available, not even by looking at on which pcpu the events happen, as we do both the above operation from a certain pcpu on vcpus running on different pcpus. 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 | 4 ++-- tools/xentrace/xenalyze.c | 15 +++++++++------ xen/common/sched_credit2.c | 6 ++++-- 3 files changed, 15 insertions(+), 10 deletions(-)