From mboxrd@z Thu Jan 1 00:00:00 1970 Return-Path: Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand id S1752568AbdAEHt7 (ORCPT ); Thu, 5 Jan 2017 02:49:59 -0500 Received: from terminus.zytor.com ([198.137.202.10]:56860 "EHLO terminus.zytor.com" rhost-flags-OK-OK-OK-OK) by vger.kernel.org with ESMTP id S1031006AbdAEHtu (ORCPT ); Thu, 5 Jan 2017 02:49:50 -0500 Date: Wed, 4 Jan 2017 23:49:13 -0800 From: tip-bot for Namhyung Kim Message-ID: Cc: dsahern@gmail.com, tglx@linutronix.de, hpa@zytor.com, linux-kernel@vger.kernel.org, namhyung@kernel.org, a.p.zijlstra@chello.nl, acme@redhat.com, jolsa@kernel.org, mingo@kernel.org Reply-To: a.p.zijlstra@chello.nl, acme@redhat.com, jolsa@kernel.org, mingo@kernel.org, dsahern@gmail.com, tglx@linutronix.de, hpa@zytor.com, namhyung@kernel.org, linux-kernel@vger.kernel.org In-Reply-To: <20161222060350.17655-3-namhyung@kernel.org> References: <20161222060350.17655-3-namhyung@kernel.org> To: linux-tip-commits@vger.kernel.org Subject: [tip:perf/urgent] perf sched timehist: Show total scheduling time Git-Commit-ID: 9396c9cb0d9534ca67bda8a34b2413a2ca1c67e9 X-Mailer: tip-git-log-daemon Robot-ID: Robot-Unsubscribe: Contact to get blacklisted from these emails MIME-Version: 1.0 Content-Transfer-Encoding: 8bit Content-Type: text/plain; charset=UTF-8 Content-Disposition: inline Sender: linux-kernel-owner@vger.kernel.org List-ID: X-Mailing-List: linux-kernel@vger.kernel.org Commit-ID: 9396c9cb0d9534ca67bda8a34b2413a2ca1c67e9 Gitweb: http://git.kernel.org/tip/9396c9cb0d9534ca67bda8a34b2413a2ca1c67e9 Author: Namhyung Kim AuthorDate: Thu, 22 Dec 2016 15:03:50 +0900 Committer: Arnaldo Carvalho de Melo CommitDate: Tue, 27 Dec 2016 21:47:57 -0300 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 (x 4) Suggested-by: David Ahern Signed-off-by: Namhyung Kim Cc: Jiri Olsa Cc: Peter Zijlstra Link: http://lkml.kernel.org/r/20161222060350.17655-3-namhyung@kernel.org Signed-off-by: Arnaldo Carvalho de Melo --- tools/perf/builtin-sched.c | 17 ++++++++++++++--- 1 file changed, 14 insertions(+), 3 deletions(-) diff --git a/tools/perf/builtin-sched.c b/tools/perf/builtin-sched.c index d53e706..5b134b0 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 */ @@ -2460,6 +2461,11 @@ static int timehist_sched_change_event(struct perf_tool *tool, timehist_print_sample(sched, sample, &al, thread, t); out: + if (sched->hist_time.start == 0 && t >= ptime->start) + sched->hist_time.start = t; + if (ptime->end == 0 || t <= ptime->end) + sched->hist_time.end = t; + if (tr) { /* time of this sched_switch event becomes last time task seen */ tr->last_time = sample->time; @@ -2624,6 +2630,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)); @@ -2665,7 +2672,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); } @@ -2701,12 +2708,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(" (x %d)\n", sched->max_cpu); } typedef int (*sched_handler)(struct perf_tool *tool,