perf sched timehist: Add -V/--cpu-visual option

The -V option provides a visual aid for sched switches by cpu:

  $ perf sched timehist -V
             time    cpu  0123456789abc  task name              b/n time  sch delay   run time
                                         [tid/pid]                (msec)     (msec)     (msec)
  --------------- ------  -------------  --------------------  ---------  ---------  ---------
  ...
   2412598.429696 [0009]           i     <idle>                    0.000      0.000      0.000
   2412598.429767 [0002]    s            perf[7219]                0.000      0.000      0.000
   2412598.429783 [0009]           s     perf[7220]                0.000      0.006      0.087
   2412598.429794 [0010]            i    <idle>                    0.000      0.000      0.000
   2412598.429795 [0009]           s     migration/9[53]           0.000      0.003      0.011
   2412598.430370 [0010]            s    sleep[7220]               0.011      0.000      0.576
   2412598.432584 [0003]     i           <idle>                    0.000      0.000      0.000
  ...

Committer notes:

'i' marks idle time, 's' are scheduler events.

Signed-off-by: David Ahern <dsahern@gmail.com>
Signed-off-by: Namhyung Kim <namhyung@kernel.org>
Acked-by: Ingo Molnar <mingo@kernel.org>
Acked-by: Jiri Olsa <jolsa@kernel.org>
Tested-by: Arnaldo Carvalho de Melo <acme@redhat.com>
Cc: Andi Kleen <andi@firstfloor.org>
Cc: Peter Zijlstra <a.p.zijlstra@chello.nl>
Cc: Stephane Eranian <eranian@google.com>
Link: http://lkml.kernel.org/r/20161116060634.28477-8-namhyung@kernel.org
[ Add documentation based on above commit message ]
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 83452088727def9a2266e3d387010b0561f38aa2..fb9e52d65fca2b0f4179aaedc1a5030ed939be5c 100644 (file)
--- a/tools/perf/Documentation/perf-sched.txt
+++ b/tools/perf/Documentation/perf-sched.txt
@@ -119,6 +119,11 @@ OPTIONS for 'perf sched timehist'
 --symfs=<directory>::
     Look for files with symbols relative to this directory.
 
+-V::
+--cpu-visual::
+       Show visual aid for sched switches by CPU: 'i' marks idle time,
+       's' are scheduler events.
+
 -w::
 --wakeups::
        Show wakeup events.

diff --git a/tools/perf/builtin-sched.c b/tools/perf/builtin-sched.c
index 1f8731640809aee29e201cd7a913832ecb3612c0..829468defa07e9b54606987703b05dae9e60c6de 100644 (file)
--- a/tools/perf/builtin-sched.c
+++ b/tools/perf/builtin-sched.c
@@ -201,6 +201,7 @@ struct perf_sched {
        bool            summary_only;
        bool            show_callchain;
        unsigned int    max_stack;
+       bool            show_cpu_visual;
        bool            show_wakeups;
        u64             skipped_samples;
 };
@@ -1783,10 +1784,23 @@ static char *timehist_get_commstr(struct thread *thread)
        return str;
 }
 
-static void timehist_header(void)
+static void timehist_header(struct perf_sched *sched)
 {
+       u32 ncpus = sched->max_cpu + 1;
+       u32 i, j;
+
        printf("%15s %6s ", "time", "cpu");
 
+       if (sched->show_cpu_visual) {
+               printf(" ");
+               for (i = 0, j = 0; i < ncpus; ++i) {
+                       printf("%x", j++);
+                       if (j > 15)
+                               j = 0;
+               }
+               printf(" ");
+       }
+
        printf(" %-20s  %9s  %9s  %9s",
                "task name", "wait time", "sch delay", "run time");
 
@@ -1797,6 +1811,9 @@ static void timehist_header(void)
         */
        printf("%15s %-6s ", "", "");
 
+       if (sched->show_cpu_visual)
+               printf(" %*s ", ncpus, "");
+
        printf(" %-20s  %9s  %9s  %9s\n", "[tid/pid]", "(msec)", "(msec)", "(msec)");
 
        /*
@@ -1804,6 +1821,9 @@ static void timehist_header(void)
         */
        printf("%.15s %.6s ", graph_dotted_line, graph_dotted_line);
 
+       if (sched->show_cpu_visual)
+               printf(" %.*s ", ncpus, graph_dotted_line);
+
        printf(" %.20s  %.9s  %.9s  %.9s",
                graph_dotted_line, graph_dotted_line, graph_dotted_line,
                graph_dotted_line);
@@ -1817,11 +1837,28 @@ static void timehist_print_sample(struct perf_sched *sched,
                                  struct thread *thread)
 {
        struct thread_runtime *tr = thread__priv(thread);
+       u32 max_cpus = sched->max_cpu + 1;
        char tstr[64];
 
        timestamp__scnprintf_usec(sample->time, tstr, sizeof(tstr));
        printf("%15s [%04d] ", tstr, sample->cpu);
 
+       if (sched->show_cpu_visual) {
+               u32 i;
+               char c;
+
+               printf(" ");
+               for (i = 0; i < max_cpus; ++i) {
+                       /* flag idle times with 'i'; others are sched events */
+                       if (i == sample->cpu)
+                               c = (thread->tid == 0) ? 'i' : 's';
+                       else
+                               c = ' ';
+                       printf("%c", c);
+               }
+               printf(" ");
+       }
+
        printf(" %-*s ", comm_width, timehist_get_commstr(thread));
 
        print_sched_time(tr->dt_wait, 6);
@@ -2095,6 +2132,8 @@ static void timehist_print_wakeup_event(struct perf_sched *sched,
 
        timestamp__scnprintf_usec(sample->time, tstr, sizeof(tstr));
        printf("%15s [%04d] ", tstr, sample->cpu);
+       if (sched->show_cpu_visual)
+               printf(" %*s ", sched->max_cpu + 1, "");
 
        printf(" %-*s ", comm_width, timehist_get_commstr(thread));
 
@@ -2458,7 +2497,7 @@ static int perf_sched__timehist(struct perf_sched *sched)
                sched->summary = sched->summary_only;
 
        if (!sched->summary_only)
-               timehist_header();
+               timehist_header(sched);
 
        err = perf_session__process_events(session);
        if (err) {
@@ -2842,6 +2881,7 @@ int cmd_sched(int argc, const char **argv, const char *prefix __maybe_unused)
        OPT_BOOLEAN('S', "with-summary", &sched.summary,
                    "Show all syscalls and summary with statistics"),
        OPT_BOOLEAN('w', "wakeups", &sched.show_wakeups, "Show wakeup events"),
+       OPT_BOOLEAN('V', "cpu-visual", &sched.show_cpu_visual, "Add CPU visual"),
        OPT_PARENT(sched_options)
        };