From mboxrd@z Thu Jan 1 00:00:00 1970 Return-Path: Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand id S1756732AbcLNVdv (ORCPT ); Wed, 14 Dec 2016 16:33:51 -0500 Received: from mail-pg0-f67.google.com ([74.125.83.67]:33728 "EHLO mail-pg0-f67.google.com" rhost-flags-OK-OK-OK-OK) by vger.kernel.org with ESMTP id S1753911AbcLNVdt (ORCPT ); Wed, 14 Dec 2016 16:33:49 -0500 Subject: Re: [PATCHSET 0/6] perf sched timehist: Introduce --idle-hist option (v2) To: Namhyung Kim References: <20161208144755.16673-1-namhyung@kernel.org> <00499939-48a7-217d-8127-47763abf5fbd@gmail.com> <20161212172620.GD4142@danjae.aot.lge.com> <4be90f86-ec74-de6a-fb10-03e749d02c3a@gmail.com> <20161213080501.GA10539@danjae.aot.lge.com> Cc: Arnaldo Carvalho de Melo , Ingo Molnar , Peter Zijlstra , Jiri Olsa , LKML , Andi Kleen , Minchan Kim From: David Ahern Message-ID: <5d94fa4b-a439-85b3-0e97-21a119920029@gmail.com> Date: Wed, 14 Dec 2016 14:33:45 -0700 User-Agent: Mozilla/5.0 (Macintosh; Intel Mac OS X 10.11; rv:45.0) Gecko/20100101 Thunderbird/45.5.1 MIME-Version: 1.0 In-Reply-To: <20161213080501.GA10539@danjae.aot.lge.com> Content-Type: text/plain; charset=utf-8 Content-Transfer-Encoding: 7bit Sender: linux-kernel-owner@vger.kernel.org List-ID: X-Mailing-List: linux-kernel@vger.kernel.org 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 > 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 > Signed-off-by: Namhyung Kim > --- > 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; >