Messages in this thread Patch in this message | | | Date | Tue, 13 Dec 2016 17:05:01 +0900 | From | Namhyung Kim <> | Subject | Re: [PATCHSET 0/6] perf sched timehist: Introduce --idle-hist option (v2) |
| |
On Mon, Dec 12, 2016 at 10:37:30AM -0700, David Ahern wrote: > On 12/12/16 10:26 AM, Namhyung Kim wrote: > > Do you mean adding an elapsed time so that it can see the cpu utilization (or > > something similar)? Then we need to expose the elapsed time during record or > > maybe just use time difference between first and last sample? > > I was thinking tstart = time of first sample analyzed, tend = time of last > sample analyzed, dt = tend - tstart. > > If the analysis window (dt) is 5 seconds and each cpu is idle for 0.1 seconds > of that 5 second window then the system is under high load.
Hmm... something like this?
From 5a1702bd15d78b0fe0c31d2d48ec8afa41fbf10c Mon Sep 17 00:00:00 2001 From: Namhyung Kim <namhyung@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 <dsahern@gmail.com> Signed-off-by: Namhyung Kim <namhyung@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; if (timehist_check_attr(sched, evlist) != 0) goto out; -- 2.10.2
| |