| Message ID | 148544957013.26566.1886390191777485188.stgit@Solace.fritz.box (mailing list archive) |
|---|---|
| State | New, archived |
| Headers | show |
Hi Dario, I'm commenting on the rtds part. On Thu, Jan 26, 2017 at 11:52 AM, Dario Faggioli <dario.faggioli@citrix.com> wrote: > Scheduling information debug dump for Credit2 is hard > to read as it contains the same information repeated > multiple time in different ways. > > In fact, in Credit2, CPUs are grouped in runqueus. > Here's the current debug output: > > CPU[00] sibling=00000000,00000003, core=00000000,000000ff > run: [32767.0] flags=0 cpu=0 credit=-1073741824 [w=0] load=0 (~0%) > 1: [0.3] flags=0 cpu=2 credit=3273410 [w=256] load=262144 (~100%) > 2: [0.4] flags=0 cpu=2 credit=2974954 [w=256] load=262144 (~100%) > CPU[01] sibling=00000000,00000003, core=00000000,000000ff > run: [32767.1] flags=0 cpu=1 credit=-1073741824 [w=0] load=0 (~0%) > 1: [0.3] flags=0 cpu=2 credit=3273410 [w=256] load=262144 (~100%) > 2: [0.4] flags=0 cpu=2 credit=2974954 [w=256] load=262144 (~100%) > CPU[02] sibling=00000000,0000000c, core=00000000,000000ff > run: [0.2] flags=2 cpu=2 credit=3556909 [w=256] load=262144 (~100%) > 1: [0.3] flags=0 cpu=2 credit=3273410 [w=256] load=262144 (~100%) > 2: [0.4] flags=0 cpu=2 credit=2974954 [w=256] load=262144 (~100%) > > Here, CPUs 0, 1 and 2, are all part of runqueue 0, > the content of which (which, BTW, is d0v3 and d0v4) > is printed 3 times! It is also not very useful to > see the details of the idle vcpus, as they're always > the same (except for the vCPU ids). > > With this change, we print: > - pCPUs details and, for non idle ones, what vCPU > they're running; > - the runqueue content, once and for all. > > Runqueue 0: > CPU[00] runq=0, sibling=00000000,00000003, core=00000000,000000ff > run: [0.15] flags=2 cpu=0 credit=5804742 [w=256] load=3655 (~1%) > CPU[01] runq=0, sibling=00000000,00000003, core=00000000,000000ff > CPU[02] runq=0, sibling=00000000,0000000c, core=00000000,000000ff > run: [0.3] flags=2 cpu=2 credit=6674856 [w=256] load=262144 (~100%) > CPU[03] runq=0, sibling=00000000,0000000c, core=00000000,000000ff > RUNQ: What is the difference between RUNQ and Runqueue 0 in the message? > 0: [0.1] flags=0 cpu=2 credit=6561215 [w=256] load=262144 (~100%) > 1: [0.2] flags=0 cpu=2 credit=5812356 [w=256] load=262144 (~100%) > > Stop printing details of idle vCPUs also in Credit1 > and RTDS (they're pretty useless in there too). > > Signed-off-by: Dario Faggioli <dario.faggioli@citrix.com> > --- > Cc: George Dunlap <george.dunlap@eu.citrix.com> > Cc: Anshul Makkar <anshul.makkar@citrix.com> > Cc: Meng Xu <mengxu@cis.upenn.edu> > --- > xen/common/sched_credit.c | 6 ++-- > xen/common/sched_credit2.c | 72 +++++++++++++++++++++----------------------- > xen/common/sched_rt.c | 9 +++++- > xen/common/schedule.c | 7 ++-- > 4 files changed, 49 insertions(+), 45 deletions(-) > > diff --git a/xen/common/sched_rt.c b/xen/common/sched_rt.c > index 24b4b22..f2d979c 100644 > --- a/xen/common/sched_rt.c > +++ b/xen/common/sched_rt.c > @@ -320,10 +320,17 @@ static void > rt_dump_pcpu(const struct scheduler *ops, int cpu) > { > struct rt_private *prv = rt_priv(ops); > + struct rt_vcpu *svc; > unsigned long flags; > > spin_lock_irqsave(&prv->lock, flags); > - rt_dump_vcpu(ops, rt_vcpu(curr_on_cpu(cpu))); > + printk("CPU[%02d]\n", cpu); We probably do not need this printk(). In rt_dump_vcpu(), we will print out the CPU number. > + /* current VCPU (nothing to say if that's the idle vcpu). */ > + svc = rt_vcpu(curr_on_cpu(cpu)); > + if ( svc && !is_idle_vcpu(svc->vcpu) ) > + { > + rt_dump_vcpu(ops, svc); > + } Maybe it is better to print the CPU number if the CPU is running an idle VCPU. The printk info could be: printk("CPU[%02d]: idle\n", cpu); > spin_unlock_irqrestore(&prv->lock, flags); > } Thanks, Meng ------------ Meng Xu PhD Student in Computer and Information Science University of Pennsylvania http://www.cis.upenn.edu/~mengxu/
On Thu, 2017-01-26 at 13:59 -0500, Meng Xu wrote: > Hi Dario, > Hi, > On Thu, Jan 26, 2017 at 11:52 AM, Dario Faggioli > <dario.faggioli@citrix.com> wrote: > > > > Runqueue 0: > > CPU[00] runq=0, sibling=00000000,00000003, core=00000000,000000ff > > run: [0.15] flags=2 cpu=0 credit=5804742 [w=256] load=3655 > > (~1%) > > CPU[01] runq=0, sibling=00000000,00000003, core=00000000,000000ff > > CPU[02] runq=0, sibling=00000000,0000000c, core=00000000,000000ff > > run: [0.3] flags=2 cpu=2 credit=6674856 [w=256] load=262144 > > (~100%) > > CPU[03] runq=0, sibling=00000000,0000000c, core=00000000,000000ff > > RUNQ: > > What is the difference between RUNQ and Runqueue 0 in the message? > Right. So, this is more comprehensive output: (XEN) [ 2797.156864] Cpupool 0: (XEN) [ 2797.156866] Cpus: 0-5,10-15 (XEN) [ 2797.156868] Scheduler: SMP Credit Scheduler rev2 (credit2) (XEN) [ 2797.156871] Active queues: 2 (XEN) [ 2797.156873] default-weight = 256 (XEN) [ 2797.156876] Runqueue 0: (XEN) [ 2797.156878] ncpus = 6 (XEN) [ 2797.156879] cpus = 0-5 (XEN) [ 2797.156881] max_weight = 256 (XEN) [ 2797.156882] instload = 5 (XEN) [ 2797.156884] aveload = 1052984 (~401%) (XEN) [ 2797.156887] idlers: 00000000,0000002a (XEN) [ 2797.156889] tickled: 00000000,00000000 (XEN) [ 2797.156891] fully idle cores: 00000000,00000000 (XEN) [ 2797.156894] Runqueue 1: (XEN) [ 2797.156896] ncpus = 6 (XEN) [ 2797.156897] cpus = 10-15 (XEN) [ 2797.156899] max_weight = 256 (XEN) [ 2797.156900] instload = 4 (XEN) [ 2797.156902] aveload = 1061305 (~404%) (XEN) [ 2797.156904] idlers: 00000000,0000e800 (XEN) [ 2797.156906] tickled: 00000000,00000000 (XEN) [ 2797.156908] fully idle cores: 00000000,0000c000 (XEN) [ 2797.156910] Domain info: (XEN) [ 2797.156912] Domain: 0 w 256 v 16 (XEN) [ 2797.156914] 1: [0.0] flags=2 cpu=4 credit=-476120314 [w=256] load=85800 (~32%) (XEN) [ 2797.156919] 2: [0.1] flags=0 cpu=2 credit=5630728 [w=256] load=262144 (~100%) (XEN) [ 2797.156923] 3: [0.2] flags=0 cpu=2 credit=4719251 [w=256] load=262144 (~100%) (XEN) [ 2797.156928] 4: [0.3] flags=2 cpu=2 credit=5648202 [w=256] load=262144 (~100%) (XEN) [ 2797.156933] 5: [0.4] flags=2 cpu=12 credit=2735243 [w=256] load=262144 (~100%) (XEN) [ 2797.156939] 6: [0.5] flags=2 cpu=12 credit=2721770 [w=256] load=262144 (~100%) (XEN) [ 2797.156945] 7: [0.6] flags=0 cpu=12 credit=2150753 [w=256] load=262144 (~100%) (XEN) [ 2797.156950] 8: [0.7] flags=0 cpu=14 credit=10424341 [w=256] load=2836 (~1%) (XEN) [ 2797.156986] 9: [0.8] flags=0 cpu=4 credit=10500000 [w=256] load=14 (~0%) (XEN) [ 2797.156991] 10: [0.9] flags=0 cpu=14 credit=10500000 [w=256] load=12 (~0%) (XEN) [ 2797.156995] 11: [0.10] flags=0 cpu=5 credit=9204778 [w=256] load=7692 (~2%) (XEN) [ 2797.156999] 12: [0.11] flags=0 cpu=1 credit=10501097 [w=256] load=2791 (~1%) (XEN) [ 2797.157004] 13: [0.12] flags=0 cpu=4 credit=10500000 [w=256] load=28 (~0%) (XEN) [ 2797.157008] 14: [0.13] flags=0 cpu=11 credit=10500000 [w=256] load=19 (~0%) (XEN) [ 2797.157013] 15: [0.14] flags=0 cpu=14 credit=10500000 [w=256] load=388 (~0%) (XEN) [ 2797.157017] 16: [0.15] flags=0 cpu=3 credit=9832716 [w=256] load=7326 (~2%) (XEN) [ 2797.157022] Domain: 1 w 256 v 2 (XEN) [ 2797.157024] 17: [1.0] flags=2 cpu=10 credit=-1085114190 [w=256] load=261922 (~99%) (XEN) [ 2797.157029] 18: [1.1] flags=0 cpu=14 credit=10500000 [w=256] load=0 (~0%) (XEN) [ 2797.157033] Domain: 2 w 256 v 2 (XEN) [ 2797.157035] 19: [2.0] flags=2 cpu=0 credit=-593239186 [w=256] load=47389 (~18%) (XEN) [ 2797.157040] 20: [2.1] flags=0 cpu=11 credit=10500000 [w=256] load=0 (~0%) (XEN) [ 2797.157044] Runqueue 0: (XEN) [ 2797.157047] CPU[00] runq=0, sibling=00000000,00000003, core=00000000,000000ff (XEN) [ 2797.157050] run: [2.0] flags=2 cpu=0 credit=-593239186 [w=256] load=47389 (~18%) (XEN) [ 2797.157055] CPU[01] runq=0, sibling=00000000,00000003, core=00000000,000000ff (XEN) [ 2797.157058] CPU[02] runq=0, sibling=00000000,0000000c, core=00000000,000000ff (XEN) [ 2797.157061] run: [0.3] flags=2 cpu=2 credit=5648202 [w=256] load=262144 (~100%) (XEN) [ 2797.157066] CPU[03] runq=0, sibling=00000000,0000000c, core=00000000,000000ff (XEN) [ 2797.157069] CPU[04] runq=0, sibling=00000000,00000030, core=00000000,000000ff (XEN) [ 2797.157072] run: [0.0] flags=2 cpu=4 credit=-476120314 [w=256] load=85800 (~32%) (XEN) [ 2797.157077] CPU[05] runq=0, sibling=00000000,00000030, core=00000000,000000ff (XEN) [ 2797.157080] RUNQ: (XEN) [ 2797.157081] 0: [0.1] flags=0 cpu=2 credit=5630728 [w=256] load=262144 (~100%) (XEN) [ 2797.157086] 1: [0.2] flags=0 cpu=2 credit=4719251 [w=256] load=262144 (~100%) (XEN) [ 2797.157090] Runqueue 1: (XEN) [ 2797.157093] CPU[10] runq=1, sibling=00000000,00000c00, core=00000000,0000ff00 (XEN) [ 2797.157096] run: [1.0] flags=2 cpu=10 credit=-1085114190 [w=256] load=261922 (~99%) (XEN) [ 2797.157101] CPU[11] runq=1, sibling=00000000,00000c00, core=00000000,0000ff00 (XEN) [ 2797.157104] CPU[12] runq=1, sibling=00000000,00003000, core=00000000,0000ff00 (XEN) [ 2797.157108] run: [0.5] flags=2 cpu=12 credit=2715377 [w=256] load=262144 (~100%) (XEN) [ 2797.157113] CPU[13] runq=1, sibling=00000000,00003000, core=00000000,0000ff00 (XEN) [ 2797.157118] CPU[14] runq=1, sibling=00000000,0000c000, core=00000000,0000ff00 (XEN) [ 2797.157121] CPU[15] runq=1, sibling=00000000,0000c000, core=00000000,0000ff00 (XEN) [ 2797.157125] RUNQ: (XEN) [ 2797.157126] 0: [0.6] flags=0 cpu=12 credit=2150753 [w=256] load=262144 (~100%) (XEN) [ 2797.157131] 1: [0.4] flags=0 cpu=12 credit=1732714 [w=256] load=262144 (~100%) "Runqueue 0" tells that what follow is information about the pCPUs and the vCPUs of that runqueue (it's the same label used above for, showing more general runqueue information. "RUNQ:" tells that what follows is the content of the runqueue, i.e., the vCPUs which are runnable but not running (the one that were running have been printed already, next to the pCPU they're running on), asn are waiting for their turn in this runqueue. Any better? > > diff --git a/xen/common/sched_rt.c b/xen/common/sched_rt.c > > index 24b4b22..f2d979c 100644 > > --- a/xen/common/sched_rt.c > > +++ b/xen/common/sched_rt.c > > > > + /* current VCPU (nothing to say if that's the idle vcpu). */ > > + svc = rt_vcpu(curr_on_cpu(cpu)); > > + if ( svc && !is_idle_vcpu(svc->vcpu) ) > > + { > > + rt_dump_vcpu(ops, svc); > > + } > > Maybe it is better to print the CPU number if the CPU is running an > idle VCPU. > The printk info could be: > printk("CPU[%02d]: idle\n", cpu); > This is the output for RTDS, with this patch applied, as it is, with one idle and one busy pCPU: (XEN) [ 399.222117] Scheduler: SMP RTDS Scheduler (rtds) (XEN) [ 399.222120] Global RunQueue info: (XEN) [ 399.222122] Global DepletedQueue info: (XEN) [ 399.222125] Global Replenishment Events info: (XEN) [ 399.222132] [ 1.1 ] cpu 9, (10000000, 4000000), cur_b=4000000 cur_d=399230000000 last_start=399220062444 (XEN) [ 399.222136] onQ=0 runnable=1 flags=2 effective hard_affinity=8-9 (XEN) [ 399.222139] Domain info: (XEN) [ 399.222141] domain: 1 (XEN) [ 399.222147] [ 1.0 ] cpu 8, (10000000, 4000000), cur_b=3973291 cur_d=399230000000 last_start=399220130217 (XEN) [ 399.222151] onQ=0 runnable=0 flags=0 effective hard_affinity=8-9 (XEN) [ 399.222157] [ 1.1 ] cpu 9, (10000000, 4000000), cur_b=4000000 cur_d=399230000000 last_start=399220062444 (XEN) [ 399.222161] onQ=0 runnable=1 flags=2 effective hard_affinity=8-9 (XEN) [ 399.222164] CPUs info: (XEN) [ 399.222167] CPU[08] (XEN) [ 399.222169] CPU[09] (XEN) [ 399.222175] [ 1.1 ] cpu 9, (10000000, 4000000), cur_b=4000000 cur_d=399230000000 last_start=399220062444 (XEN) [ 399.222179] onQ=0 runnable=1 flags=2 effective hard_affinity=8-9 I don't see what adding "idle" buys us, wrt to just listing the CPU without printing anything particular. And, on a big and mostly idle system, it will be printed a lot of times (next to each idle pCPU). They're running nothing, so they're quite obviously idle. It looks this simple to me IMO. TBH, what I don't especially like in the output above is, within the vCPU info being printed: - the spaces inside '[' ']'; - the big numbers; - the fact that last_start is rather useless (it's more tracing info than debug dump info, IMO); - the fact that the various queues info and CPUs info are not displaed closer, and they even have "Domain info:" in between them (which is because of schedule.c, not sched_rt.c, I know); - the word "info" after "Global RunQueue", "Global DepletedQueue", "Global Replenishment Events"; - the word "Global", in the names above; - the onQ and runnable flags being printed, which I don't is really necessary or useful; - the lack of scheduler wide information (e.g., the tickled mask, the next timeout of the replenishment timer, etc); But this is material for another patch. :-) Going back to printing "idle" or not, also remember that this is debug output, meant at being mostly useful for developers, or with help from developers. And developers can easily check in the code what having just the CPU ID printed means (in case it's not obvious, which I think it is, or they don't remember). That being said, it's not that I can't live with the added "idle" indication. But I like it less and would prefer not to add it. Thanks and Regards, Dario -- <<This happens because I choose it to happen!>> (Raistlin Majere) ----------------------------------------------------------------- Dario Faggioli, Ph.D, http://about.me/dario.faggioli Senior Software Engineer, Citrix Systems R&D Ltd., Cambridge (UK)
On Thu, Jan 26, 2017 at 5:08 PM, Dario Faggioli <dario.faggioli@citrix.com> wrote: > On Thu, 2017-01-26 at 13:59 -0500, Meng Xu wrote: >> Hi Dario, >> > Hi, > >> On Thu, Jan 26, 2017 at 11:52 AM, Dario Faggioli >> <dario.faggioli@citrix.com> wrote: >> > >> > Runqueue 0: >> > CPU[00] runq=0, sibling=00000000,00000003, core=00000000,000000ff >> > run: [0.15] flags=2 cpu=0 credit=5804742 [w=256] load=3655 >> > (~1%) >> > CPU[01] runq=0, sibling=00000000,00000003, core=00000000,000000ff >> > CPU[02] runq=0, sibling=00000000,0000000c, core=00000000,000000ff >> > run: [0.3] flags=2 cpu=2 credit=6674856 [w=256] load=262144 >> > (~100%) >> > CPU[03] runq=0, sibling=00000000,0000000c, core=00000000,000000ff >> > RUNQ: >> >> What is the difference between RUNQ and Runqueue 0 in the message? >> > Right. So, this is more comprehensive output: > > (XEN) [ 2797.156864] Cpupool 0: > (XEN) [ 2797.156866] Cpus: 0-5,10-15 > (XEN) [ 2797.156868] Scheduler: SMP Credit Scheduler rev2 (credit2) > (XEN) [ 2797.156871] Active queues: 2 > (XEN) [ 2797.156873] default-weight = 256 > (XEN) [ 2797.156876] Runqueue 0: > (XEN) [ 2797.156878] ncpus = 6 > (XEN) [ 2797.156879] cpus = 0-5 > (XEN) [ 2797.156881] max_weight = 256 > (XEN) [ 2797.156882] instload = 5 > (XEN) [ 2797.156884] aveload = 1052984 (~401%) > (XEN) [ 2797.156887] idlers: 00000000,0000002a > (XEN) [ 2797.156889] tickled: 00000000,00000000 > (XEN) [ 2797.156891] fully idle cores: 00000000,00000000 > (XEN) [ 2797.156894] Runqueue 1: > (XEN) [ 2797.156896] ncpus = 6 > (XEN) [ 2797.156897] cpus = 10-15 > (XEN) [ 2797.156899] max_weight = 256 > (XEN) [ 2797.156900] instload = 4 > (XEN) [ 2797.156902] aveload = 1061305 (~404%) > (XEN) [ 2797.156904] idlers: 00000000,0000e800 > (XEN) [ 2797.156906] tickled: 00000000,00000000 > (XEN) [ 2797.156908] fully idle cores: 00000000,0000c000 > (XEN) [ 2797.156910] Domain info: > (XEN) [ 2797.156912] Domain: 0 w 256 v 16 > (XEN) [ 2797.156914] 1: [0.0] flags=2 cpu=4 credit=-476120314 [w=256] load=85800 (~32%) > (XEN) [ 2797.156919] 2: [0.1] flags=0 cpu=2 credit=5630728 [w=256] load=262144 (~100%) > (XEN) [ 2797.156923] 3: [0.2] flags=0 cpu=2 credit=4719251 [w=256] load=262144 (~100%) > (XEN) [ 2797.156928] 4: [0.3] flags=2 cpu=2 credit=5648202 [w=256] load=262144 (~100%) > (XEN) [ 2797.156933] 5: [0.4] flags=2 cpu=12 credit=2735243 [w=256] load=262144 (~100%) > (XEN) [ 2797.156939] 6: [0.5] flags=2 cpu=12 credit=2721770 [w=256] load=262144 (~100%) > (XEN) [ 2797.156945] 7: [0.6] flags=0 cpu=12 credit=2150753 [w=256] load=262144 (~100%) > (XEN) [ 2797.156950] 8: [0.7] flags=0 cpu=14 credit=10424341 [w=256] load=2836 (~1%) > (XEN) [ 2797.156986] 9: [0.8] flags=0 cpu=4 credit=10500000 [w=256] load=14 (~0%) > (XEN) [ 2797.156991] 10: [0.9] flags=0 cpu=14 credit=10500000 [w=256] load=12 (~0%) > (XEN) [ 2797.156995] 11: [0.10] flags=0 cpu=5 credit=9204778 [w=256] load=7692 (~2%) > (XEN) [ 2797.156999] 12: [0.11] flags=0 cpu=1 credit=10501097 [w=256] load=2791 (~1%) > (XEN) [ 2797.157004] 13: [0.12] flags=0 cpu=4 credit=10500000 [w=256] load=28 (~0%) > (XEN) [ 2797.157008] 14: [0.13] flags=0 cpu=11 credit=10500000 [w=256] load=19 (~0%) > (XEN) [ 2797.157013] 15: [0.14] flags=0 cpu=14 credit=10500000 [w=256] load=388 (~0%) > (XEN) [ 2797.157017] 16: [0.15] flags=0 cpu=3 credit=9832716 [w=256] load=7326 (~2%) > (XEN) [ 2797.157022] Domain: 1 w 256 v 2 > (XEN) [ 2797.157024] 17: [1.0] flags=2 cpu=10 credit=-1085114190 [w=256] load=261922 (~99%) > (XEN) [ 2797.157029] 18: [1.1] flags=0 cpu=14 credit=10500000 [w=256] load=0 (~0%) > (XEN) [ 2797.157033] Domain: 2 w 256 v 2 > (XEN) [ 2797.157035] 19: [2.0] flags=2 cpu=0 credit=-593239186 [w=256] load=47389 (~18%) > (XEN) [ 2797.157040] 20: [2.1] flags=0 cpu=11 credit=10500000 [w=256] load=0 (~0%) > (XEN) [ 2797.157044] Runqueue 0: > (XEN) [ 2797.157047] CPU[00] runq=0, sibling=00000000,00000003, core=00000000,000000ff > (XEN) [ 2797.157050] run: [2.0] flags=2 cpu=0 credit=-593239186 [w=256] load=47389 (~18%) > (XEN) [ 2797.157055] CPU[01] runq=0, sibling=00000000,00000003, core=00000000,000000ff > (XEN) [ 2797.157058] CPU[02] runq=0, sibling=00000000,0000000c, core=00000000,000000ff > (XEN) [ 2797.157061] run: [0.3] flags=2 cpu=2 credit=5648202 [w=256] load=262144 (~100%) > (XEN) [ 2797.157066] CPU[03] runq=0, sibling=00000000,0000000c, core=00000000,000000ff > (XEN) [ 2797.157069] CPU[04] runq=0, sibling=00000000,00000030, core=00000000,000000ff > (XEN) [ 2797.157072] run: [0.0] flags=2 cpu=4 credit=-476120314 [w=256] load=85800 (~32%) > (XEN) [ 2797.157077] CPU[05] runq=0, sibling=00000000,00000030, core=00000000,000000ff > (XEN) [ 2797.157080] RUNQ: > (XEN) [ 2797.157081] 0: [0.1] flags=0 cpu=2 credit=5630728 [w=256] load=262144 (~100%) > (XEN) [ 2797.157086] 1: [0.2] flags=0 cpu=2 credit=4719251 [w=256] load=262144 (~100%) > (XEN) [ 2797.157090] Runqueue 1: > (XEN) [ 2797.157093] CPU[10] runq=1, sibling=00000000,00000c00, core=00000000,0000ff00 > (XEN) [ 2797.157096] run: [1.0] flags=2 cpu=10 credit=-1085114190 [w=256] load=261922 (~99%) > (XEN) [ 2797.157101] CPU[11] runq=1, sibling=00000000,00000c00, core=00000000,0000ff00 > (XEN) [ 2797.157104] CPU[12] runq=1, sibling=00000000,00003000, core=00000000,0000ff00 > (XEN) [ 2797.157108] run: [0.5] flags=2 cpu=12 credit=2715377 [w=256] load=262144 (~100%) > (XEN) [ 2797.157113] CPU[13] runq=1, sibling=00000000,00003000, core=00000000,0000ff00 > (XEN) [ 2797.157118] CPU[14] runq=1, sibling=00000000,0000c000, core=00000000,0000ff00 > (XEN) [ 2797.157121] CPU[15] runq=1, sibling=00000000,0000c000, core=00000000,0000ff00 > (XEN) [ 2797.157125] RUNQ: > (XEN) [ 2797.157126] 0: [0.6] flags=0 cpu=12 credit=2150753 [w=256] load=262144 (~100%) > (XEN) [ 2797.157131] 1: [0.4] flags=0 cpu=12 credit=1732714 [w=256] load=262144 (~100%) > > "Runqueue 0" tells that what follow is information about the pCPUs and > the vCPUs of that runqueue (it's the same label used above for, showing > more general runqueue information. > > "RUNQ:" tells that what follows is the content of the runqueue, i.e., > the vCPUs which are runnable but not running (the one that were running > have been printed already, next to the pCPU they're running on), asn > are waiting for their turn in this runqueue. > > Any better? I see the relation between RUNQ and Runqueue now. In RTDS, we did not keep the running VCPUs in the runqueue. So I feel it may be better to add a short explanation for RUNQ and Runqueue in the output to make it clearer. Maybe, something like this: "Runqueue 0" change to "Runqueue 0 (Running):" "RUNQ" change to "Runqueue 0 (Ready)" What do you think? > >> > diff --git a/xen/common/sched_rt.c b/xen/common/sched_rt.c >> > index 24b4b22..f2d979c 100644 >> > --- a/xen/common/sched_rt.c >> > +++ b/xen/common/sched_rt.c >> > >> > + /* current VCPU (nothing to say if that's the idle vcpu). */ >> > + svc = rt_vcpu(curr_on_cpu(cpu)); >> > + if ( svc && !is_idle_vcpu(svc->vcpu) ) >> > + { >> > + rt_dump_vcpu(ops, svc); >> > + } >> >> Maybe it is better to print the CPU number if the CPU is running an >> idle VCPU. >> The printk info could be: >> printk("CPU[%02d]: idle\n", cpu); >> > This is the output for RTDS, with this patch applied, as it is, with > one idle and one busy pCPU: > > > (XEN) [ 399.222117] Scheduler: SMP RTDS Scheduler (rtds) > (XEN) [ 399.222120] Global RunQueue info: > (XEN) [ 399.222122] Global DepletedQueue info: > (XEN) [ 399.222125] Global Replenishment Events info: > (XEN) [ 399.222132] [ 1.1 ] cpu 9, (10000000, 4000000), cur_b=4000000 cur_d=399230000000 last_start=399220062444 > (XEN) [ 399.222136] onQ=0 runnable=1 flags=2 effective hard_affinity=8-9 > (XEN) [ 399.222139] Domain info: > (XEN) [ 399.222141] domain: 1 > (XEN) [ 399.222147] [ 1.0 ] cpu 8, (10000000, 4000000), cur_b=3973291 cur_d=399230000000 last_start=399220130217 > (XEN) [ 399.222151] onQ=0 runnable=0 flags=0 effective hard_affinity=8-9 > (XEN) [ 399.222157] [ 1.1 ] cpu 9, (10000000, 4000000), cur_b=4000000 cur_d=399230000000 last_start=399220062444 > (XEN) [ 399.222161] onQ=0 runnable=1 flags=2 effective hard_affinity=8-9 > (XEN) [ 399.222164] CPUs info: > (XEN) [ 399.222167] CPU[08] > (XEN) [ 399.222169] CPU[09] > (XEN) [ 399.222175] [ 1.1 ] cpu 9, (10000000, 4000000), cur_b=4000000 cur_d=399230000000 last_start=399220062444 > (XEN) [ 399.222179] onQ=0 runnable=1 flags=2 effective hard_affinity=8-9 > > I don't see what adding "idle" buys us, wrt to just listing the CPU > without printing anything particular. And, on a big and mostly idle > system, it will be printed a lot of times (next to each idle pCPU). > > They're running nothing, so they're quite obviously idle. It looks this > simple to me IMO. > > TBH, what I don't especially like in the output above is, within the > vCPU info being printed: > - the spaces inside '[' ']'; > - the big numbers; > - the fact that last_start is rather useless (it's more tracing info > than debug dump info, IMO); I feel the last_start is useful, at least to identify the previous subtle bug in budget accounting. It tells us when the running VCPU was scheduled and indicates how the budget will be burned later. When I saw the last_start is in the previous period and the burn_budget() still use the old last_start to burn budget for the current period, I figured out the bug. > - the fact that the various queues info and CPUs info are not > displaed closer, and they even have "Domain info:" in between them > (which is because of schedule.c, not sched_rt.c, I know); > - the word "info" after "Global RunQueue", "Global DepletedQueue", > "Global Replenishment Events"; > - the word "Global", in the names above; > - the onQ and runnable flags being printed, which I don't is really > necessary or useful; > - the lack of scheduler wide information (e.g., the tickled mask, the > next timeout of the replenishment timer, etc); > > But this is material for another patch. :-) I agree with all of the above output improvements, except for killing the last_start info. :-) > > Going back to printing "idle" or not, also remember that this is debug > output, meant at being mostly useful for developers, or with help from > developers. And developers can easily check in the code what having > just the CPU ID printed means (in case it's not obvious, which I think > it is, or they don't remember). > > That being said, it's not that I can't live with the added "idle" > indication. But I like it less and would prefer not to add it. Sure! I was thinking if we should even avoid printing out the idle CPU number to make the output more concise on an idle systems. After seeing the complete output, I think the current output is fine. > > Thanks and Regards, Thank you very much! Meng ------------ Meng Xu PhD Student in Computer and Information Science University of Pennsylvania http://www.cis.upenn.edu/~mengxu/
On Fri, 2017-01-27 at 12:05 -0500, Meng Xu wrote: > On Thu, Jan 26, 2017 at 5:08 PM, Dario Faggioli > <dario.faggioli@citrix.com> wrote: > > "Runqueue 0" tells that what follow is information about the pCPUs > > and > > the vCPUs of that runqueue (it's the same label used above for, > > showing > > more general runqueue information. > > > > "RUNQ:" tells that what follows is the content of the runqueue, > > i.e., > > the vCPUs which are runnable but not running (the one that were > > running > > have been printed already, next to the pCPU they're running on), > > asn > > are waiting for their turn in this runqueue. > > > > Any better? > > I see the relation between RUNQ and Runqueue now. > In RTDS, we did not keep the running VCPUs in the runqueue. > Credit2 does remove the running vCPU from the runqueue too. That's the only (sane?) thing you can do if your runqueue is shared among multiple pCPUs (which is the case for both Credit2 and RTDS). Well, actually, that's indeed the case even in Credit1 (although, there you may leave it in the runq, if you want). > So I feel it may be better to add a short explanation for RUNQ and > Runqueue in the output to make it clearer. > > Maybe, something like this: > "Runqueue 0" change to "Runqueue 0 (Running):" > "RUNQ" change to "Runqueue 0 (Ready)" > > What do you think? > I'll think about it, but I don't terribly feel the need to be this verbose in this kind of output. > > TBH, what I don't especially like in the output above is, within > > the > > vCPU info being printed: > > - the spaces inside '[' ']'; > > - the big numbers; > > - the fact that last_start is rather useless (it's more tracing > > info > > than debug dump info, IMO); > > I feel the last_start is useful, at least to identify the previous > subtle bug in budget accounting. It tells us when the running VCPU > was > scheduled and indicates how the budget will be burned later. > When I saw the last_start is in the previous period and the > burn_budget() still use the old last_start to burn budget for the > current period, I figured out the bug. > That's ok, we're all different... That's what makes the World so beautiful. :-) > > - the fact that the various queues info and CPUs info are not > > displaed closer, and they even have "Domain info:" in between > > them > > (which is because of schedule.c, not sched_rt.c, I know); > > - the word "info" after "Global RunQueue", "Global DepletedQueue", > > "Global Replenishment Events"; > > - the word "Global", in the names above; > > - the onQ and runnable flags being printed, which I don't is > > really > > necessary or useful; > > - the lack of scheduler wide information (e.g., the tickled mask, > > the > > next timeout of the replenishment timer, etc); > > > > But this is material for another patch. :-) > > I agree with all of the above output improvements, except for killing > the last_start info. :-) > Ok. I'm not yet working on a patch that does remove it. If/when I will and send it, you're more than entitled, and have the necessary power, to Nack it. ;-P > > Going back to printing "idle" or not, also remember that this is > > debug > > output, meant at being mostly useful for developers, or with help > > from > > developers. And developers can easily check in the code what having > > just the CPU ID printed means (in case it's not obvious, which I > > think > > it is, or they don't remember). > > > > That being said, it's not that I can't live with the added "idle" > > indication. But I like it less and would prefer not to add it. > > Sure! I was thinking if we should even avoid printing out the idle > CPU > number to make the output more concise on an idle systems. > Yeah, that was also my first doing. But, then, looking at the output, I found it a little bit too obfuscated the info about what pCPUs are actually in use within the scheduler (think of the case where it's not default, and is in a cpupool). So I ended up deciding to leave it there, all of them, idle or not. > After seeing the complete output, I think the current output is fine. > Great! So, you'll send your Acked-by soon? Thanks and Regards, Dario
> > > > TBH, what I don't especially like in the output above is, within > > > the > > > vCPU info being printed: > > > - the spaces inside '[' ']'; > > > - the big numbers; > > > - the fact that last_start is rather useless (it's more tracing > > > info > > > than debug dump info, IMO); > > > > I feel the last_start is useful, at least to identify the previous > > subtle bug in budget accounting. It tells us when the running VCPU > > was > > scheduled and indicates how the budget will be burned later. > > When I saw the last_start is in the previous period and the > > burn_budget() still use the old last_start to burn budget for the > > current period, I figured out the bug. > > > That's ok, we're all different... That's what makes the World so > beautiful. :-) > > > > - the fact that the various queues info and CPUs info are not > > > displaed closer, and they even have "Domain info:" in between > > > them > > > (which is because of schedule.c, not sched_rt.c, I know); > > > - the word "info" after "Global RunQueue", "Global DepletedQueue", > > > "Global Replenishment Events"; > > > - the word "Global", in the names above; > > > - the onQ and runnable flags being printed, which I don't is > > > really > > > necessary or useful; > > > - the lack of scheduler wide information (e.g., the tickled mask, > > > the > > > next timeout of the replenishment timer, etc); > > > > > > But this is material for another patch. :-) > > > > I agree with all of the above output improvements, except for killing > > the last_start info. :-) > > > Ok. I'm not yet working on a patch that does remove it. If/when I will > and send it, you're more than entitled, and have the necessary power, > to Nack it. ;-P OK. Once this serials of patch gets in, I can send one patch to fix this output. > > > > > Going back to printing "idle" or not, also remember that this is > > > debug > > > output, meant at being mostly useful for developers, or with help > > > from > > > developers. And developers can easily check in the code what having > > > just the CPU ID printed means (in case it's not obvious, which I > > > think > > > it is, or they don't remember). > > > > > > That being said, it's not that I can't live with the added "idle" > > > indication. But I like it less and would prefer not to add it. > > > > Sure! I was thinking if we should even avoid printing out the idle > > CPU > > number to make the output more concise on an idle systems. > > > Yeah, that was also my first doing. But, then, looking at the output, I > found it a little bit too obfuscated the info about what pCPUs are > actually in use within the scheduler (think of the case where it's not > default, and is in a cpupool). > > So I ended up deciding to leave it there, all of them, idle or not. > > > After seeing the complete output, I think the current output is fine. > > > Great! So, you'll send your Acked-by soon? Yep. I'm replying to your original email. Meng ----------- Meng Xu PhD Student in Computer and Information Science University of Pennsylvania http://www.cis.upenn.edu/~mengxu/
On Thu, Jan 26, 2017 at 11:52 AM, Dario Faggioli <dario.faggioli@citrix.com> wrote: > Scheduling information debug dump for Credit2 is hard > to read as it contains the same information repeated > multiple time in different ways. > > In fact, in Credit2, CPUs are grouped in runqueus. > Here's the current debug output: > > CPU[00] sibling=00000000,00000003, core=00000000,000000ff > run: [32767.0] flags=0 cpu=0 credit=-1073741824 [w=0] load=0 (~0%) > 1: [0.3] flags=0 cpu=2 credit=3273410 [w=256] load=262144 (~100%) > 2: [0.4] flags=0 cpu=2 credit=2974954 [w=256] load=262144 (~100%) > CPU[01] sibling=00000000,00000003, core=00000000,000000ff > run: [32767.1] flags=0 cpu=1 credit=-1073741824 [w=0] load=0 (~0%) > 1: [0.3] flags=0 cpu=2 credit=3273410 [w=256] load=262144 (~100%) > 2: [0.4] flags=0 cpu=2 credit=2974954 [w=256] load=262144 (~100%) > CPU[02] sibling=00000000,0000000c, core=00000000,000000ff > run: [0.2] flags=2 cpu=2 credit=3556909 [w=256] load=262144 (~100%) > 1: [0.3] flags=0 cpu=2 credit=3273410 [w=256] load=262144 (~100%) > 2: [0.4] flags=0 cpu=2 credit=2974954 [w=256] load=262144 (~100%) > > Here, CPUs 0, 1 and 2, are all part of runqueue 0, > the content of which (which, BTW, is d0v3 and d0v4) > is printed 3 times! It is also not very useful to > see the details of the idle vcpus, as they're always > the same (except for the vCPU ids). > > With this change, we print: > - pCPUs details and, for non idle ones, what vCPU > they're running; > - the runqueue content, once and for all. > > Runqueue 0: > CPU[00] runq=0, sibling=00000000,00000003, core=00000000,000000ff > run: [0.15] flags=2 cpu=0 credit=5804742 [w=256] load=3655 (~1%) > CPU[01] runq=0, sibling=00000000,00000003, core=00000000,000000ff > CPU[02] runq=0, sibling=00000000,0000000c, core=00000000,000000ff > run: [0.3] flags=2 cpu=2 credit=6674856 [w=256] load=262144 (~100%) > CPU[03] runq=0, sibling=00000000,0000000c, core=00000000,000000ff > RUNQ: > 0: [0.1] flags=0 cpu=2 credit=6561215 [w=256] load=262144 (~100%) > 1: [0.2] flags=0 cpu=2 credit=5812356 [w=256] load=262144 (~100%) > > Stop printing details of idle vCPUs also in Credit1 > and RTDS (they're pretty useless in there too). > > Signed-off-by: Dario Faggioli <dario.faggioli@citrix.com> > --- > Cc: George Dunlap <george.dunlap@eu.citrix.com> > Cc: Anshul Makkar <anshul.makkar@citrix.com> > Cc: Meng Xu <mengxu@cis.upenn.edu> > --- > xen/common/sched_credit.c | 6 ++-- > xen/common/sched_credit2.c | 72 +++++++++++++++++++++----------------------- > xen/common/sched_rt.c | 9 +++++- > xen/common/schedule.c | 7 ++-- > 4 files changed, 49 insertions(+), 45 deletions(-) As to the sched_rt.c, Acked-by Meng Xu <mengxu@cis.upenn.edu> Thanks, Meng ----------- Meng Xu PhD Student in Computer and Information Science University of Pennsylvania http://www.cis.upenn.edu/~mengxu/
On 26/01/17 16:52, Dario Faggioli wrote: > Scheduling information debug dump for Credit2 is hard > to read as it contains the same information repeated > multiple time in different ways. > > In fact, in Credit2, CPUs are grouped in runqueus. > Here's the current debug output: > > CPU[00] sibling=00000000,00000003, core=00000000,000000ff > run: [32767.0] flags=0 cpu=0 credit=-1073741824 [w=0] load=0 (~0%) > 1: [0.3] flags=0 cpu=2 credit=3273410 [w=256] load=262144 (~100%) > 2: [0.4] flags=0 cpu=2 credit=2974954 [w=256] load=262144 (~100%) > CPU[01] sibling=00000000,00000003, core=00000000,000000ff > run: [32767.1] flags=0 cpu=1 credit=-1073741824 [w=0] load=0 (~0%) > 1: [0.3] flags=0 cpu=2 credit=3273410 [w=256] load=262144 (~100%) > 2: [0.4] flags=0 cpu=2 credit=2974954 [w=256] load=262144 (~100%) > CPU[02] sibling=00000000,0000000c, core=00000000,000000ff > run: [0.2] flags=2 cpu=2 credit=3556909 [w=256] load=262144 (~100%) > 1: [0.3] flags=0 cpu=2 credit=3273410 [w=256] load=262144 (~100%) > 2: [0.4] flags=0 cpu=2 credit=2974954 [w=256] load=262144 (~100%) > > Here, CPUs 0, 1 and 2, are all part of runqueue 0, > the content of which (which, BTW, is d0v3 and d0v4) > is printed 3 times! It is also not very useful to > see the details of the idle vcpus, as they're always > the same (except for the vCPU ids). > > With this change, we print: > - pCPUs details and, for non idle ones, what vCPU > they're running; > - the runqueue content, once and for all. > > Runqueue 0: > CPU[00] runq=0, sibling=00000000,00000003, core=00000000,000000ff > run: [0.15] flags=2 cpu=0 credit=5804742 [w=256] load=3655 (~1%) > CPU[01] runq=0, sibling=00000000,00000003, core=00000000,000000ff > CPU[02] runq=0, sibling=00000000,0000000c, core=00000000,000000ff > run: [0.3] flags=2 cpu=2 credit=6674856 [w=256] load=262144 (~100%) > CPU[03] runq=0, sibling=00000000,0000000c, core=00000000,000000ff > RUNQ: > 0: [0.1] flags=0 cpu=2 credit=6561215 [w=256] load=262144 (~100%) > 1: [0.2] flags=0 cpu=2 credit=5812356 [w=256] load=262144 (~100%) > > Stop printing details of idle vCPUs also in Credit1 > and RTDS (they're pretty useless in there too). > > Signed-off-by: Dario Faggioli <dario.faggioli@citrix.com> Hang on -- how does this relate to the credit2 dumping patch you sent the previous week? I'm all in favor of not saving up a massive queue of patches, but if the patches have conflicts with existing patches, I think it would be better if you re-sent a full series with a new version number, so I wouldn't have to try to figure out what order they needed to be applied in and which ones weren't necessary anymore. There's no problem, I don't think, of sending version n+1 of a series that has no changes other than adding new patches. I've checked in and pushed the three patches that I reviewed today; can you rebase your outstanding changes and send another series? Thanks! And sorry it took so long to get to. -George
On Wed, 2017-02-01 at 14:59 +0000, George Dunlap wrote: > On 26/01/17 16:52, Dario Faggioli wrote: > > > > Scheduling information debug dump for Credit2 is hard > > to read as it contains the same information repeated > > multiple time in different ways. > > > > [..] > > > > Signed-off-by: Dario Faggioli <dario.faggioli@citrix.com> > > Hang on -- how does this relate to the credit2 dumping patch you sent > the previous week? > Err... Right, I'll tell you how they're related: I basically forgot that I did send the earlier one! :-( > I'm all in favor of not saving up a massive queue of patches, but if > the > patches have conflicts with existing patches, I think it would be > better > if you re-sent a full series with a new version number, so I wouldn't > have to try to figure out what order they needed to be applied in and > which ones weren't necessary anymore. There's no problem, I don't > think, of sending version n+1 of a series that has no changes other > than > adding new patches. > Indeed. But the problem in this case is I lost track of the fact that I did send the other one, and so I resent, after reworking it a bit more. Sorry for the confusion, this is totally my fault. :-/ > I've checked in and pushed the three patches that I reviewed today; > can > you rebase your outstanding changes and send another series? > Ok, I'll rebase this one on top of current staging and resubmit. > Thanks! And sorry it took so long to get to. > Well, sorry for the mess. :-P Thanks and Regards, Dario
diff --git a/xen/common/sched_credit.c b/xen/common/sched_credit.c index ad20819..7c0ff47 100644 --- a/xen/common/sched_credit.c +++ b/xen/common/sched_credit.c @@ -1988,13 +1988,13 @@ csched_dump_pcpu(const struct scheduler *ops, int cpu) runq = &spc->runq; cpumask_scnprintf(cpustr, sizeof(cpustr), per_cpu(cpu_sibling_mask, cpu)); - printk(" sort=%d, sibling=%s, ", spc->runq_sort_last, cpustr); + printk("CPU[%02d] sort=%d, sibling=%s, ", cpu, spc->runq_sort_last, cpustr); cpumask_scnprintf(cpustr, sizeof(cpustr), per_cpu(cpu_core_mask, cpu)); printk("core=%s\n", cpustr); - /* current VCPU */ + /* current VCPU (nothing to say if that's the idle vcpu). */ svc = CSCHED_VCPU(curr_on_cpu(cpu)); - if ( svc ) + if ( svc && !is_idle_vcpu(svc->vcpu) ) { printk("\trun: "); csched_dump_vcpu(svc); diff --git a/xen/common/sched_credit2.c b/xen/common/sched_credit2.c index b2f2b17..c4e2b9a 100644 --- a/xen/common/sched_credit2.c +++ b/xen/common/sched_credit2.c @@ -2627,56 +2627,25 @@ csched2_dump_vcpu(struct csched2_private *prv, struct csched2_vcpu *svc) printk("\n"); } -static void -csched2_dump_pcpu(const struct scheduler *ops, int cpu) +static inline void +dump_pcpu(const struct scheduler *ops, int cpu) { struct csched2_private *prv = CSCHED2_PRIV(ops); - struct list_head *runq, *iter; struct csched2_vcpu *svc; - unsigned long flags; - spinlock_t *lock; - int loop; #define cpustr keyhandler_scratch - /* - * We need both locks: - * - csched2_dump_vcpu() wants to access domains' weights, - * which are protected by the private scheduler lock; - * - we scan through the runqueue, so we need the proper runqueue - * lock (the one of the runqueue this cpu is associated to). - */ - read_lock_irqsave(&prv->lock, flags); - lock = per_cpu(schedule_data, cpu).schedule_lock; - spin_lock(lock); - - runq = &RQD(ops, cpu)->runq; - cpumask_scnprintf(cpustr, sizeof(cpustr), per_cpu(cpu_sibling_mask, cpu)); - printk(" sibling=%s, ", cpustr); + printk("CPU[%02d] runq=%d, sibling=%s, ", cpu, c2r(ops, cpu), cpustr); cpumask_scnprintf(cpustr, sizeof(cpustr), per_cpu(cpu_core_mask, cpu)); printk("core=%s\n", cpustr); - /* current VCPU */ + /* current VCPU (nothing to say if that's the idle vcpu) */ svc = CSCHED2_VCPU(curr_on_cpu(cpu)); - if ( svc ) + if ( svc && !is_idle_vcpu(svc->vcpu) ) { printk("\trun: "); csched2_dump_vcpu(prv, svc); } - - loop = 0; - list_for_each( iter, runq ) - { - svc = __runq_elem(iter); - if ( svc ) - { - printk("\t%3d: ", ++loop); - csched2_dump_vcpu(prv, svc); - } - } - - spin_unlock(lock); - read_unlock_irqrestore(&prv->lock, flags); #undef cpustr } @@ -2686,7 +2655,7 @@ csched2_dump(const struct scheduler *ops) struct list_head *iter_sdom; struct csched2_private *prv = CSCHED2_PRIV(ops); unsigned long flags; - int i, loop; + unsigned int i, j, loop; #define cpustr keyhandler_scratch /* @@ -2756,6 +2725,34 @@ csched2_dump(const struct scheduler *ops) } } + for_each_cpu(i, &prv->active_queues) + { + struct csched2_runqueue_data *rqd = prv->rqd + i; + struct list_head *iter, *runq = &rqd->runq; + int loop = 0; + + /* We need the lock to scan the runqueue. */ + spin_lock(&rqd->lock); + + printk("Runqueue %d:\n", i); + + for_each_cpu(j, &rqd->active) + dump_pcpu(ops, j); + + printk("RUNQ:\n"); + list_for_each( iter, runq ) + { + struct csched2_vcpu *svc = __runq_elem(iter); + + if ( svc ) + { + printk("\t%3d: ", loop++); + csched2_dump_vcpu(prv, svc); + } + } + spin_unlock(&rqd->lock); + } + read_unlock_irqrestore(&prv->lock, flags); #undef cpustr } @@ -3100,7 +3097,6 @@ static const struct scheduler sched_credit2_def = { .do_schedule = csched2_schedule, .context_saved = csched2_context_saved, - .dump_cpu_state = csched2_dump_pcpu, .dump_settings = csched2_dump, .init = csched2_init, .deinit = csched2_deinit, diff --git a/xen/common/sched_rt.c b/xen/common/sched_rt.c index 24b4b22..f2d979c 100644 --- a/xen/common/sched_rt.c +++ b/xen/common/sched_rt.c @@ -320,10 +320,17 @@ static void rt_dump_pcpu(const struct scheduler *ops, int cpu) { struct rt_private *prv = rt_priv(ops); + struct rt_vcpu *svc; unsigned long flags; spin_lock_irqsave(&prv->lock, flags); - rt_dump_vcpu(ops, rt_vcpu(curr_on_cpu(cpu))); + printk("CPU[%02d]\n", cpu); + /* current VCPU (nothing to say if that's the idle vcpu). */ + svc = rt_vcpu(curr_on_cpu(cpu)); + if ( svc && !is_idle_vcpu(svc->vcpu) ) + { + rt_dump_vcpu(ops, svc); + } spin_unlock_irqrestore(&prv->lock, flags); } diff --git a/xen/common/schedule.c b/xen/common/schedule.c index 43b5b99..e4320f3 100644 --- a/xen/common/schedule.c +++ b/xen/common/schedule.c @@ -1844,10 +1844,11 @@ void schedule_dump(struct cpupool *c) cpus = &cpupool_free_cpus; } - for_each_cpu (i, cpus) + if ( sched->dump_cpu_state != NULL ) { - printk("CPU[%02d] ", i); - SCHED_OP(sched, dump_cpu_state, i); + printk("CPUs info:\n"); + for_each_cpu (i, cpus) + SCHED_OP(sched, dump_cpu_state, i); } }
Scheduling information debug dump for Credit2 is hard to read as it contains the same information repeated multiple time in different ways. In fact, in Credit2, CPUs are grouped in runqueus. Here's the current debug output: CPU[00] sibling=00000000,00000003, core=00000000,000000ff run: [32767.0] flags=0 cpu=0 credit=-1073741824 [w=0] load=0 (~0%) 1: [0.3] flags=0 cpu=2 credit=3273410 [w=256] load=262144 (~100%) 2: [0.4] flags=0 cpu=2 credit=2974954 [w=256] load=262144 (~100%) CPU[01] sibling=00000000,00000003, core=00000000,000000ff run: [32767.1] flags=0 cpu=1 credit=-1073741824 [w=0] load=0 (~0%) 1: [0.3] flags=0 cpu=2 credit=3273410 [w=256] load=262144 (~100%) 2: [0.4] flags=0 cpu=2 credit=2974954 [w=256] load=262144 (~100%) CPU[02] sibling=00000000,0000000c, core=00000000,000000ff run: [0.2] flags=2 cpu=2 credit=3556909 [w=256] load=262144 (~100%) 1: [0.3] flags=0 cpu=2 credit=3273410 [w=256] load=262144 (~100%) 2: [0.4] flags=0 cpu=2 credit=2974954 [w=256] load=262144 (~100%) Here, CPUs 0, 1 and 2, are all part of runqueue 0, the content of which (which, BTW, is d0v3 and d0v4) is printed 3 times! It is also not very useful to see the details of the idle vcpus, as they're always the same (except for the vCPU ids). With this change, we print: - pCPUs details and, for non idle ones, what vCPU they're running; - the runqueue content, once and for all. Runqueue 0: CPU[00] runq=0, sibling=00000000,00000003, core=00000000,000000ff run: [0.15] flags=2 cpu=0 credit=5804742 [w=256] load=3655 (~1%) CPU[01] runq=0, sibling=00000000,00000003, core=00000000,000000ff CPU[02] runq=0, sibling=00000000,0000000c, core=00000000,000000ff run: [0.3] flags=2 cpu=2 credit=6674856 [w=256] load=262144 (~100%) CPU[03] runq=0, sibling=00000000,0000000c, core=00000000,000000ff RUNQ: 0: [0.1] flags=0 cpu=2 credit=6561215 [w=256] load=262144 (~100%) 1: [0.2] flags=0 cpu=2 credit=5812356 [w=256] load=262144 (~100%) Stop printing details of idle vCPUs also in Credit1 and RTDS (they're pretty useless in there too). Signed-off-by: Dario Faggioli <dario.faggioli@citrix.com> --- Cc: George Dunlap <george.dunlap@eu.citrix.com> Cc: Anshul Makkar <anshul.makkar@citrix.com> Cc: Meng Xu <mengxu@cis.upenn.edu> --- xen/common/sched_credit.c | 6 ++-- xen/common/sched_credit2.c | 72 +++++++++++++++++++++----------------------- xen/common/sched_rt.c | 9 +++++- xen/common/schedule.c | 7 ++-- 4 files changed, 49 insertions(+), 45 deletions(-)