perf sched timehist: Add -I/--idle-hist option

The --idle-hist option is to analyze system idle state so which process
makes cpu to go idle.  If this option is specified, non-idle events will
be skipped and processes switching to/from idle will be shown.

This option is mostly useful when used with --summary(-only) option.  In
the idle-time summary view, idle time is accounted to previous thread
which is run before idle task.

The example output looks like following:

  Idle-time summary
                  comm parent sched-out idle-time min-idle avg-idle max-idle stddev migrations
                                (count)    (msec)   (msec)   (msec)   (msec)      %
  --------------------------------------------------------------------------------------------
        rcu_preempt[7]      2        95   550.872    0.011    5.798   23.146   7.63      0
       migration/1[16]      2         1    15.558   15.558   15.558   15.558   0.00      0
        khugepaged[39]      2         1     3.062    3.062    3.062    3.062   0.00      0
     kworker/0:1H[124]      2         2     4.728    0.611    2.364    4.116  74.12      0
  systemd-journal[167]      1         1     4.510    4.510    4.510    4.510   0.00      0
    kworker/u16:3[558]      2        13    74.737    0.080    5.749   12.960  21.96      0
   irq/34-iwlwifi[628]      2        21   118.403    0.032    5.638   23.990  24.00      0
    kworker/u17:0[673]      2         1     3.523    3.523    3.523    3.523   0.00      0
      dbus-daemon[722]      1         1     6.743    6.743    6.743    6.743   0.00      0
          ifplugd[741]      1         1    58.826   58.826   58.826   58.826   0.00      0
  wpa_supplicant[1490]      1         1    13.302   13.302   13.302   13.302   0.00      0
     wpa_actiond[1492]      1         2     4.064    0.168    2.032    3.896  91.72      0
         dockerd[1500]      1         1     0.055    0.055    0.055    0.055   0.00      0
  ...

Signed-off-by: Namhyung Kim <namhyung@kernel.org>
Tested-by: Arnaldo Carvalho de Melo <acme@redhat.com>
Acked-by: David Ahern <dsahern@gmail.com>
Cc: Andi Kleen <andi@firstfloor.org>
Cc: Jiri Olsa <jolsa@kernel.org>
Cc: Minchan Kim <minchan@kernel.org>
Cc: Peter Zijlstra <peterz@infradead.org>
Link: http://lkml.kernel.org/r/20161208144755.16673-6-namhyung@kernel.org
Link: http://lkml.kernel.org/r/20161213080632.19099-2-namhyung@kernel.org
[ Merged fix sent by Namhyumg, as posted in the second Link: tag ]
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>

diff --git a/tools/perf/Documentation/perf-sched.txt b/tools/perf/Documentation/perf-sched.txt
index 7775b1eb2bee6bd092fe854b63b12150aa50699f..76173969ab80375c468e2722ec5e2773dab96a7c 100644 (file)
--- a/tools/perf/Documentation/perf-sched.txt
+++ b/tools/perf/Documentation/perf-sched.txt
@@ -132,6 +132,10 @@ OPTIONS for 'perf sched timehist'
 --migrations::
        Show migration events.
 
+-I::
+--idle-hist::
+       Show idle-related events only.
+
 --time::
        Only analyze samples within given time window: <start>,<stop>. Times
        have the format seconds.microseconds. If start is not given (i.e., time

diff --git a/tools/perf/builtin-sched.c b/tools/perf/builtin-sched.c
index c8e7848e71a7846046b223048a33f4167c374c6b..0b14265432df5410116ff679edc5d15b0710e9e3 100644 (file)
--- a/tools/perf/builtin-sched.c
+++ b/tools/perf/builtin-sched.c
@@ -2421,7 +2421,36 @@ static int timehist_sched_change_event(struct perf_tool *tool,
                        t = ptime->end;
        }
 
-       timehist_update_runtime_stats(tr, t, tprev);
+       if (!sched->idle_hist || thread->tid == 0) {
+               timehist_update_runtime_stats(tr, t, tprev);
+
+               if (sched->idle_hist) {
+                       struct idle_thread_runtime *itr = (void *)tr;
+                       struct thread_runtime *last_tr;
+
+                       BUG_ON(thread->tid != 0);
+
+                       if (itr->last_thread == NULL)
+                               goto out;
+
+                       /* add current idle time as last thread's runtime */
+                       last_tr = thread__get_runtime(itr->last_thread);
+                       if (last_tr == NULL)
+                               goto out;
+
+                       timehist_update_runtime_stats(last_tr, t, tprev);
+                       /*
+                        * remove delta time of last thread as it's not updated
+                        * and otherwise it will show an invalid value next
+                        * time.  we only care total run time and run stat.
+                        */
+                       last_tr->dt_run = 0;
+                       last_tr->dt_wait = 0;
+                       last_tr->dt_delay = 0;
+
+                       itr->last_thread = NULL;
+               }
+       }
 
        if (!sched->summary_only)
                timehist_print_sample(sched, sample, &al, thread, t);
@@ -2543,9 +2572,15 @@ static void timehist_print_summary(struct perf_sched *sched,
        if (comm_width < 30)
                comm_width = 30;
 
-       printf("\nRuntime summary\n");
-       printf("%*s  parent   sched-in  ", comm_width, "comm");
-       printf("   run-time    min-run     avg-run     max-run  stddev  migrations\n");
+       if (sched->idle_hist) {
+               printf("\nIdle-time summary\n");
+               printf("%*s  parent  sched-out  ", comm_width, "comm");
+               printf("  idle-time   min-idle    avg-idle    max-idle  stddev  migrations\n");
+       } else {
+               printf("\nRuntime summary\n");
+               printf("%*s  parent   sched-in  ", comm_width, "comm");
+               printf("   run-time    min-run     avg-run     max-run  stddev  migrations\n");
+       }
        printf("%*s            (count)  ", comm_width, "");
        printf("     (msec)     (msec)      (msec)      (msec)       %%\n");
        printf("%.117s\n", graph_dotted_line);
@@ -2561,7 +2596,7 @@ static void timehist_print_summary(struct perf_sched *sched,
                printf("<no terminated tasks>\n");
 
        /* CPU idle stats not tracked when samples were skipped */
-       if (sched->skipped_samples)
+       if (sched->skipped_samples && !sched->idle_hist)
                return;
 
        printf("\nIdle stats:\n");
@@ -3107,6 +3142,7 @@ int cmd_sched(int argc, const char **argv, const char *prefix __maybe_unused)
        OPT_BOOLEAN('w', "wakeups", &sched.show_wakeups, "Show wakeup events"),
        OPT_BOOLEAN('M', "migrations", &sched.show_migrations, "Show migration events"),
        OPT_BOOLEAN('V', "cpu-visual", &sched.show_cpu_visual, "Add CPU visual"),
+       OPT_BOOLEAN('I', "idle-hist", &sched.idle_hist, "Show idle events only"),
        OPT_STRING(0, "time", &sched.time_str, "str",
                   "Time span for analysis (start,stop)"),
        OPT_PARENT(sched_options)