diff mbox

[v2,05/16] xen: RTDS: pack trace data better for xentrace_format

Message ID 20160216181144.27876.14577.stgit@Solace.station (mailing list archive)
State New, archived
Headers show

Commit Message

Dario Faggioli Feb. 16, 2016, 6:11 p.m. UTC
when tracing runstate changes, the vcpu and domain IDs
are encoded in the lower and higher, respectively, parts
of a 32 bits integer. When decoding a trace with
xentrace_format, this makes it possible to display
such events like this:

CPU0  833435853624 (+     768)  running_to_runnable [ dom:vcpu = 0x7fff0000 ]
CPU0  833435854416 (+     792)  runnable_to_running [ dom:vcpu = 0x00000007 ]

For consistency, we should do the same when displaying
the events coming from the RTDS scheduler (when using
the same tool), and to do that, we need to invert the
order in which the fields are being put in the trace
struct right now.

While there, we also:
 - fix the use of TRC_RTDS_SCHED_TASKLET (it should
   only be involved when a tasklet is scheduled, not
   _every_ time rt_schedule() is invoked!);
 - remove a very chatty and useless (nothing has been
   picked!) use of TRC_RTDS_RUNQ_PICK.

In fact, one can already figure out when nothing has been
picked from the runqueue, by looking at when cpu_idle
is invoked --which is the same thing one would do if on
Credit or Credit2.

Signed-off-by: Dario Faggioli <dario.faggioli@citrix.com>
Reviewed-by: Konrad Rzeszutek Wilk <konrad.wilk@oracle.com>
---
Cc: George Dunlap <george.dunlap@citrix.com>
Cc: Meng Xu <xumengpanda@gmail.com>
Cc: Tianyang Chen <tiche@seas.upenn.edu>
Cc: Olaf Hering <olaf@aepfle.de>
---
Changes from v1:
 * enhanced changelog, as suggested during review.
---
 xen/common/sched_rt.c |   27 ++++-----------------------
 1 file changed, 4 insertions(+), 23 deletions(-)

Comments

George Dunlap Feb. 18, 2016, 11:12 a.m. UTC | #1
On 16/02/16 18:11, Dario Faggioli wrote:
> when tracing runstate changes, the vcpu and domain IDs
> are encoded in the lower and higher, respectively, parts
> of a 32 bits integer. When decoding a trace with
> xentrace_format, this makes it possible to display
> such events like this:
> 
> CPU0  833435853624 (+     768)  running_to_runnable [ dom:vcpu = 0x7fff0000 ]
> CPU0  833435854416 (+     792)  runnable_to_running [ dom:vcpu = 0x00000007 ]
> 
> For consistency, we should do the same when displaying
> the events coming from the RTDS scheduler (when using
> the same tool), and to do that, we need to invert the
> order in which the fields are being put in the trace
> struct right now.
> 
> While there, we also:
>  - fix the use of TRC_RTDS_SCHED_TASKLET (it should
>    only be involved when a tasklet is scheduled, not
>    _every_ time rt_schedule() is invoked!);
>  - remove a very chatty and useless (nothing has been
>    picked!) use of TRC_RTDS_RUNQ_PICK.
> 
> In fact, one can already figure out when nothing has been
> picked from the runqueue, by looking at when cpu_idle
> is invoked --which is the same thing one would do if on
> Credit or Credit2.
> 
> Signed-off-by: Dario Faggioli <dario.faggioli@citrix.com>
> Reviewed-by: Konrad Rzeszutek Wilk <konrad.wilk@oracle.com>

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

> ---
> Cc: George Dunlap <george.dunlap@citrix.com>
> Cc: Meng Xu <xumengpanda@gmail.com>
> Cc: Tianyang Chen <tiche@seas.upenn.edu>
> Cc: Olaf Hering <olaf@aepfle.de>
> ---
> Changes from v1:
>  * enhanced changelog, as suggested during review.
> ---
>  xen/common/sched_rt.c |   27 ++++-----------------------
>  1 file changed, 4 insertions(+), 23 deletions(-)
> 
> diff --git a/xen/common/sched_rt.c b/xen/common/sched_rt.c
> index 2e5430f..53de6d6 100644
> --- a/xen/common/sched_rt.c
> +++ b/xen/common/sched_rt.c
> @@ -362,7 +362,7 @@ rt_update_deadline(s_time_t now, struct rt_vcpu *svc)
>      /* TRACE */
>      {
>          struct {
> -            unsigned dom:16,vcpu:16;
> +            unsigned vcpu:16, dom:16;
>              unsigned cur_deadline_lo, cur_deadline_hi;
>              unsigned cur_budget_lo, cur_budget_hi;
>          } d;
> @@ -711,7 +711,7 @@ burn_budget(const struct scheduler *ops, struct rt_vcpu *svc, s_time_t now)
>      /* TRACE */
>      {
>          struct {
> -            unsigned dom:16, vcpu:16;
> +            unsigned vcpu:16, dom:16;
>              unsigned cur_budget_lo;
>              unsigned cur_budget_hi;
>              int delta;
> @@ -763,7 +763,7 @@ __runq_pick(const struct scheduler *ops, const cpumask_t *mask)
>          if( svc != NULL )
>          {
>              struct {
> -                unsigned dom:16, vcpu:16;
> +                unsigned vcpu:16, dom:16;
>                  unsigned cur_deadline_lo, cur_deadline_hi;
>                  unsigned cur_budget_lo, cur_budget_hi;
>              } d;
> @@ -777,8 +777,6 @@ __runq_pick(const struct scheduler *ops, const cpumask_t *mask)
>                        sizeof(d),
>                        (unsigned char *) &d);
>          }
> -        else
> -            trace_var(TRC_RTDS_RUNQ_PICK, 1, 0, NULL);
>      }
>  
>      return svc;
> @@ -845,6 +843,7 @@ rt_schedule(const struct scheduler *ops, s_time_t now, bool_t tasklet_work_sched
>  
>      if ( tasklet_work_scheduled )
>      {
> +        trace_var(TRC_RTDS_SCHED_TASKLET, 1, 0,  NULL);
>          snext = rt_vcpu(idle_vcpu[cpu]);
>      }
>      else
> @@ -885,24 +884,6 @@ rt_schedule(const struct scheduler *ops, s_time_t now, bool_t tasklet_work_sched
>      ret.time = MIN(snext->budget, MAX_SCHEDULE); /* sched quantum */
>      ret.task = snext->vcpu;
>  
> -    /* TRACE */
> -    {
> -        struct {
> -            unsigned dom:16,vcpu:16;
> -            unsigned cur_deadline_lo, cur_deadline_hi;
> -            unsigned cur_budget_lo, cur_budget_hi;
> -        } d;
> -        d.dom = snext->vcpu->domain->domain_id;
> -        d.vcpu = snext->vcpu->vcpu_id;
> -        d.cur_deadline_lo = (unsigned) snext->cur_deadline;
> -        d.cur_deadline_hi = (unsigned) (snext->cur_deadline >> 32);
> -        d.cur_budget_lo = (unsigned) snext->cur_budget;
> -        d.cur_budget_hi = (unsigned) (snext->cur_budget >> 32);
> -        trace_var(TRC_RTDS_SCHED_TASKLET, 1,
> -                  sizeof(d),
> -                  (unsigned char *)&d);
> -    }
> -
>      return ret;
>  }
>  
>
Meng Xu Feb. 18, 2016, 2:43 p.m. UTC | #2
I'm sorry for replying late. Somehow, I forgot to reply this patch email. :-(

On Tue, Feb 16, 2016 at 1:11 PM, Dario Faggioli
<dario.faggioli@citrix.com> wrote:
> when tracing runstate changes, the vcpu and domain IDs
> are encoded in the lower and higher, respectively, parts
> of a 32 bits integer. When decoding a trace with
> xentrace_format, this makes it possible to display
> such events like this:
>
> CPU0  833435853624 (+     768)  running_to_runnable [ dom:vcpu = 0x7fff0000 ]
> CPU0  833435854416 (+     792)  runnable_to_running [ dom:vcpu = 0x00000007 ]
>
> For consistency, we should do the same when displaying
> the events coming from the RTDS scheduler (when using
> the same tool), and to do that, we need to invert the
> order in which the fields are being put in the trace
> struct right now.
>
> While there, we also:
>  - fix the use of TRC_RTDS_SCHED_TASKLET (it should
>    only be involved when a tasklet is scheduled, not
>    _every_ time rt_schedule() is invoked!);
>  - remove a very chatty and useless (nothing has been
>    picked!) use of TRC_RTDS_RUNQ_PICK.
>
> In fact, one can already figure out when nothing has been
> picked from the runqueue, by looking at when cpu_idle
> is invoked --which is the same thing one would do if on
> Credit or Credit2.
>
> Signed-off-by: Dario Faggioli <dario.faggioli@citrix.com>
> Reviewed-by: Konrad Rzeszutek Wilk <konrad.wilk@oracle.com>

Reviewed-by: Meng Xu <mengxu@cis.upenn.edu>

> ---
> Cc: George Dunlap <george.dunlap@citrix.com>
> Cc: Meng Xu <xumengpanda@gmail.com>
> Cc: Tianyang Chen <tiche@seas.upenn.edu>
> Cc: Olaf Hering <olaf@aepfle.de>
> ---
> Changes from v1:
>  * enhanced changelog, as suggested during review.
> ---
>  xen/common/sched_rt.c |   27 ++++-----------------------
>  1 file changed, 4 insertions(+), 23 deletions(-)
>
> diff --git a/xen/common/sched_rt.c b/xen/common/sched_rt.c
> index 2e5430f..53de6d6 100644
> --- a/xen/common/sched_rt.c
> +++ b/xen/common/sched_rt.c
> @@ -362,7 +362,7 @@ rt_update_deadline(s_time_t now, struct rt_vcpu *svc)
>      /* TRACE */
>      {
>          struct {
> -            unsigned dom:16,vcpu:16;
> +            unsigned vcpu:16, dom:16;
>              unsigned cur_deadline_lo, cur_deadline_hi;
>              unsigned cur_budget_lo, cur_budget_hi;
>          } d;
> @@ -711,7 +711,7 @@ burn_budget(const struct scheduler *ops, struct rt_vcpu *svc, s_time_t now)
>      /* TRACE */
>      {
>          struct {
> -            unsigned dom:16, vcpu:16;
> +            unsigned vcpu:16, dom:16;
>              unsigned cur_budget_lo;
>              unsigned cur_budget_hi;
>              int delta;
> @@ -763,7 +763,7 @@ __runq_pick(const struct scheduler *ops, const cpumask_t *mask)
>          if( svc != NULL )
>          {
>              struct {
> -                unsigned dom:16, vcpu:16;
> +                unsigned vcpu:16, dom:16;
>                  unsigned cur_deadline_lo, cur_deadline_hi;
>                  unsigned cur_budget_lo, cur_budget_hi;
>              } d;
> @@ -777,8 +777,6 @@ __runq_pick(const struct scheduler *ops, const cpumask_t *mask)
>                        sizeof(d),
>                        (unsigned char *) &d);
>          }
> -        else
> -            trace_var(TRC_RTDS_RUNQ_PICK, 1, 0, NULL);
>      }
>
>      return svc;
> @@ -845,6 +843,7 @@ rt_schedule(const struct scheduler *ops, s_time_t now, bool_t tasklet_work_sched
>
>      if ( tasklet_work_scheduled )
>      {
> +        trace_var(TRC_RTDS_SCHED_TASKLET, 1, 0,  NULL);
>          snext = rt_vcpu(idle_vcpu[cpu]);
>      }
>      else
> @@ -885,24 +884,6 @@ rt_schedule(const struct scheduler *ops, s_time_t now, bool_t tasklet_work_sched
>      ret.time = MIN(snext->budget, MAX_SCHEDULE); /* sched quantum */
>      ret.task = snext->vcpu;
>
> -    /* TRACE */
> -    {
> -        struct {
> -            unsigned dom:16,vcpu:16;
> -            unsigned cur_deadline_lo, cur_deadline_hi;
> -            unsigned cur_budget_lo, cur_budget_hi;
> -        } d;
> -        d.dom = snext->vcpu->domain->domain_id;
> -        d.vcpu = snext->vcpu->vcpu_id;
> -        d.cur_deadline_lo = (unsigned) snext->cur_deadline;
> -        d.cur_deadline_hi = (unsigned) (snext->cur_deadline >> 32);
> -        d.cur_budget_lo = (unsigned) snext->cur_budget;
> -        d.cur_budget_hi = (unsigned) (snext->cur_budget >> 32);
> -        trace_var(TRC_RTDS_SCHED_TASKLET, 1,
> -                  sizeof(d),
> -                  (unsigned char *)&d);
> -    }
> -
>      return ret;
>  }
>
>



-----------
Meng Xu
PhD Student in Computer and Information Science
University of Pennsylvania
http://www.cis.upenn.edu/~mengxu/
diff mbox

Patch

diff --git a/xen/common/sched_rt.c b/xen/common/sched_rt.c
index 2e5430f..53de6d6 100644
--- a/xen/common/sched_rt.c
+++ b/xen/common/sched_rt.c
@@ -362,7 +362,7 @@  rt_update_deadline(s_time_t now, struct rt_vcpu *svc)
     /* TRACE */
     {
         struct {
-            unsigned dom:16,vcpu:16;
+            unsigned vcpu:16, dom:16;
             unsigned cur_deadline_lo, cur_deadline_hi;
             unsigned cur_budget_lo, cur_budget_hi;
         } d;
@@ -711,7 +711,7 @@  burn_budget(const struct scheduler *ops, struct rt_vcpu *svc, s_time_t now)
     /* TRACE */
     {
         struct {
-            unsigned dom:16, vcpu:16;
+            unsigned vcpu:16, dom:16;
             unsigned cur_budget_lo;
             unsigned cur_budget_hi;
             int delta;
@@ -763,7 +763,7 @@  __runq_pick(const struct scheduler *ops, const cpumask_t *mask)
         if( svc != NULL )
         {
             struct {
-                unsigned dom:16, vcpu:16;
+                unsigned vcpu:16, dom:16;
                 unsigned cur_deadline_lo, cur_deadline_hi;
                 unsigned cur_budget_lo, cur_budget_hi;
             } d;
@@ -777,8 +777,6 @@  __runq_pick(const struct scheduler *ops, const cpumask_t *mask)
                       sizeof(d),
                       (unsigned char *) &d);
         }
-        else
-            trace_var(TRC_RTDS_RUNQ_PICK, 1, 0, NULL);
     }
 
     return svc;
@@ -845,6 +843,7 @@  rt_schedule(const struct scheduler *ops, s_time_t now, bool_t tasklet_work_sched
 
     if ( tasklet_work_scheduled )
     {
+        trace_var(TRC_RTDS_SCHED_TASKLET, 1, 0,  NULL);
         snext = rt_vcpu(idle_vcpu[cpu]);
     }
     else
@@ -885,24 +884,6 @@  rt_schedule(const struct scheduler *ops, s_time_t now, bool_t tasklet_work_sched
     ret.time = MIN(snext->budget, MAX_SCHEDULE); /* sched quantum */
     ret.task = snext->vcpu;
 
-    /* TRACE */
-    {
-        struct {
-            unsigned dom:16,vcpu:16;
-            unsigned cur_deadline_lo, cur_deadline_hi;
-            unsigned cur_budget_lo, cur_budget_hi;
-        } d;
-        d.dom = snext->vcpu->domain->domain_id;
-        d.vcpu = snext->vcpu->vcpu_id;
-        d.cur_deadline_lo = (unsigned) snext->cur_deadline;
-        d.cur_deadline_hi = (unsigned) (snext->cur_deadline >> 32);
-        d.cur_budget_lo = (unsigned) snext->cur_budget;
-        d.cur_budget_hi = (unsigned) (snext->cur_budget >> 32);
-        trace_var(TRC_RTDS_SCHED_TASKLET, 1,
-                  sizeof(d),
-                  (unsigned char *)&d);
-    }
-
     return ret;
 }