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.
>
> if (timehist_check_attr(sched, evlist) != 0)
> goto out;
>
