linux-kernel - Re: [PATCHSET 0/6] perf sched timehist: Introduce --idle-hist option (v2)

lists.openwall.net		lists / announce owl-users owl-dev john-users john-dev passwdqc-users yescrypt popa3d-users / oss-security kernel-hardening musl sabotage tlsify passwords / crypt-dev xvendor / Bugtraq Full-Disclosure linux-kernel linux-netdev linux-ext4 linux-hardening linux-cve-announce PHC
Open Source and information security mailing list archives

Hash Suite: Windows password security audit tool. GUI, reports in PDF.

[<prev] [next>] [<thread-prev] [thread-next>] [day] [month] [year] [list]

Date:   Fri, 16 Dec 2016 00:17:22 +0900
From:   Namhyung Kim <namhyung@...nel.org>
To:     David Ahern <dsahern@...il.com>
Cc:     Arnaldo Carvalho de Melo <acme@...nel.org>,
        Ingo Molnar <mingo@...nel.org>,
        Peter Zijlstra <peterz@...radead.org>,
        Jiri Olsa <jolsa@...nel.org>,
        LKML <linux-kernel@...r.kernel.org>,
        Andi Kleen <andi@...stfloor.org>,
        Minchan Kim <minchan@...nel.org>
Subject: Re: [PATCHSET 0/6] perf sched timehist: Introduce --idle-hist option
 (v2)

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 <namhyung@...nel.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 <dsahern@...il.com>
> > Signed-off-by: Namhyung Kim <namhyung@...nel.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;
> > 
>