[Date Prev][Date Next][Thread Prev][Thread Next][Date Index][Thread Index]

Re: [Xen-devel] [PATCH 11/24] tools: tracing: handle more scheduling related events.



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@xxxxxxxxxx>

Acked-by: George Dunlap <george.dunlap@xxxxxxxxxx>

> ---
> Cc: George Dunlap <george.dunlap@xxxxxxxxxxxxx>
> Cc: Ian Jackson <ian.jackson@xxxxxxxxxxxxx>
> Cc: Wei Liu <wei.liu2@xxxxxxxxxx>
> ---
>  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);
>          }
> 


_______________________________________________
Xen-devel mailing list
Xen-devel@xxxxxxxxxxxxx
https://lists.xen.org/xen-devel

 


Rackspace

Lists.xenproject.org is hosted with RackSpace, monitoring our
servers 24x7x365 and backed by RackSpace's Fanatical Support®.