On Wed, Dec 14, 2016 at 02:33:45PM -0700, David Ahern wrote:
> On 12/13/16 1:05 AM, Namhyung Kim wrote:
> > Hmm... something like this?
>
> yes. 1 comment though ...
>
> >
> >
> >
> > From 5a1702bd15d78b0fe0c31d2d48ec8afa41fbf10c Mon Sep 17 00:00:00 2001
> > From: Namhyung Kim <namhy...@kernel.org>
> > Date: Tue, 13 Dec 2016 15:05:14 +0900
> > Subject: [PATCH] perf sched timehist: Show total scheduling time
> >
> > Show length of analyzed sample time and rate of idle task running.
> > This also takes care of time range given by --time option.
> >
> > $ perf sched timehist -sI | tail
> > Samples do not have callchains.
> > Idle stats:
> > CPU 0 idle for 930.316 msec ( 92.93%)
> > CPU 1 idle for 963.614 msec ( 96.25%)
> > CPU 2 idle for 885.482 msec ( 88.45%)
> > CPU 3 idle for 938.635 msec ( 93.76%)
> >
> > Total number of unique tasks: 118
> > Total number of context switches: 2337
> > Total run time (msec): 3718.048
> > Total scheduling time (msec): 1001.131
> >
> > Suggested-by: David Ahern <dsah...@gmail.com>
> > Signed-off-by: Namhyung Kim <namhy...@kernel.org>
> > ---
> > tools/perf/builtin-sched.c | 19 ++++++++++++++++---
> > 1 file changed, 16 insertions(+), 3 deletions(-)
> >
> > diff --git a/tools/perf/builtin-sched.c b/tools/perf/builtin-sched.c
> > index 64a0959bccd7..9c0b3016e85a 100644
> > --- a/tools/perf/builtin-sched.c
> > +++ b/tools/perf/builtin-sched.c
> > @@ -209,6 +209,7 @@ struct perf_sched {
> > u64 skipped_samples;
> > const char *time_str;
> > struct perf_time_interval ptime;
> > + struct perf_time_interval hist_time;
> > };
> >
> > /* per thread run time data */
> > @@ -2624,6 +2625,7 @@ static void timehist_print_summary(struct perf_sched
> > *sched,
> > struct thread *t;
> > struct thread_runtime *r;
> > int i;
> > + u64 hist_time = sched->hist_time.end - sched->hist_time.start;
> >
> > memset(&totals, 0, sizeof(totals));
> >
> > @@ -2668,7 +2670,7 @@ static void timehist_print_summary(struct perf_sched
> > *sched,
> > totals.sched_count += r->run_stats.n;
> > printf(" CPU %2d idle for ", i);
> > print_sched_time(r->total_run_time, 6);
> > - printf(" msec\n");
> > + printf(" msec (%6.2f%%)\n", 100.0 * r->total_run_time
> > / hist_time);
> > } else
> > printf(" CPU %2d idle entire time window\n", i);
> > }
> > @@ -2704,12 +2706,16 @@ static void timehist_print_summary(struct
> > perf_sched *sched,
> >
> > printf("\n"
> > " Total number of unique tasks: %" PRIu64 "\n"
> > - "Total number of context switches: %" PRIu64 "\n"
> > - " Total run time (msec): ",
> > + "Total number of context switches: %" PRIu64 "\n",
> > totals.task_count, totals.sched_count);
> >
> > + printf(" Total run time (msec): ");
> > print_sched_time(totals.total_run_time, 2);
> > printf("\n");
> > +
> > + printf(" Total scheduling time (msec): ");
> > + print_sched_time(hist_time, 2);
> > + printf("\n");
> > }
> >
> > typedef int (*sched_handler)(struct perf_tool *tool,
> > @@ -2731,6 +2737,12 @@ static int perf_timehist__process_sample(struct
> > perf_tool *tool,
> > if (this_cpu > sched->max_cpu)
> > sched->max_cpu = this_cpu;
> >
> > + if (sched->hist_time.start == 0)
> > + sched->hist_time.start = sample->time;
> > + /* do not update end time if user gave a ptime */
> > + if (sched->ptime.end == 0)
> > + sched->hist_time.end = sample->time;
> > +
> > if (evsel->handler != NULL) {
> > sched_handler f = evsel->handler;
> >
> > @@ -2814,6 +2826,7 @@ static int perf_sched__timehist(struct perf_sched
> > *sched)
> > pr_err("Invalid time string\n");
> > return -EINVAL;
> > }
> > + sched->hist_time = sched->ptime;
>
> The time given by the user does not necessarily correlate with a
> time in the file. eg., start time could be way before the file starts
> or end time way after.
Right, I'll keep the actual sampling window within the ptime then.
Thanks,
Namhyung
>
> >
> > if (timehist_check_attr(sched, evlist) != 0)
> > goto out;
> >
>
