lkml.org 
[lkml]   [2016]   [Dec]   [13]   [last100]   RSS Feed
Views: [wrap][no wrap]   [headers]  [forward] 
 
Messages in this thread
    Patch in this message
    /
    From
    Subject[PATCH 06/22] perf sched timehist: Add -I/--idle-hist option
    Date
    From: Namhyung Kim <namhyung@kernel.org>

    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>

    Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
    ---
    tools/perf/Documentation/perf-sched.txt | 4 +++
    tools/perf/builtin-sched.c | 46 +++++++++++++++++++++++++++++----
    2 files changed, 45 insertions(+), 5 deletions(-)

    diff --git a/tools/perf/Documentation/perf-sched.txt b/tools/perf/Documentation/perf-sched.txt
    index 7775b1eb2bee..76173969ab80 100644
    --- 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 c8e7848e71a7..0b14265432df 100644
    --- 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)
    --
    2.9.3
    \
     
     \ /
      Last update: 2016-12-13 16:15    [W:4.178 / U:0.316 seconds]
    ©2003-2020 Jasper Spaans|hosted at Digital Ocean and TransIP|Read the blog|Advertise on this site