From mboxrd@z Thu Jan 1 00:00:00 1970 Return-Path: Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand id S1751704AbdARJYz (ORCPT ); Wed, 18 Jan 2017 04:24:55 -0500 Received: from terminus.zytor.com ([198.137.202.10]:38516 "EHLO terminus.zytor.com" rhost-flags-OK-OK-OK-OK) by vger.kernel.org with ESMTP id S1751646AbdARJYt (ORCPT ); Wed, 18 Jan 2017 04:24:49 -0500 Date: Wed, 18 Jan 2017 01:24:11 -0800 From: tip-bot for Namhyung Kim Message-ID: Cc: minchan@kernel.org, acme@redhat.com, jolsa@kernel.org, tglx@linutronix.de, mingo@kernel.org, dsahern@gmail.com, peterz@infradead.org, linux-kernel@vger.kernel.org, hpa@zytor.com, namhyung@kernel.org Reply-To: dsahern@gmail.com, peterz@infradead.org, namhyung@kernel.org, linux-kernel@vger.kernel.org, hpa@zytor.com, minchan@kernel.org, acme@redhat.com, jolsa@kernel.org, tglx@linutronix.de, mingo@kernel.org In-Reply-To: <20170113104523.31212-2-namhyung@kernel.org> References: <20170113104523.31212-2-namhyung@kernel.org> To: linux-tip-commits@vger.kernel.org Subject: [tip:perf/core] perf sched timehist: Add --state option Git-Commit-ID: 414e050c68ec2a3dd815544ea48ff6016f1a7a11 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: 414e050c68ec2a3dd815544ea48ff6016f1a7a11 Gitweb: http://git.kernel.org/tip/414e050c68ec2a3dd815544ea48ff6016f1a7a11 Author: Namhyung Kim AuthorDate: Fri, 13 Jan 2017 19:45:22 +0900 Committer: Arnaldo Carvalho de Melo CommitDate: Tue, 17 Jan 2017 11:36:44 -0300 perf sched timehist: Add --state option The --state option is to show task state when switched out. The state is printed as a single character like in the /proc but I added 'I' for idle state rather than 'R'. $ perf sched timehist --state | head Samples do not have callchains. time cpu task name wait time sch delay run time state [tid/pid] (msec) (msec) (msec) -------- --- ----------------------- -------- ------------------ ----- 1.753791 [3] 0.000 0.000 0.000 I 1.753834 [1] perf[27469] 0.000 0.000 0.000 S 1.753904 [3] perf[27470] 0.000 0.006 0.112 S 1.753914 [1] 0.000 0.000 0.079 I 1.753915 [3] migration/3[23] 0.000 0.002 0.011 S 1.754287 [2] 0.000 0.000 0.000 I 1.754335 [2] transmission[1773/1739] 0.000 0.004 0.047 S Signed-off-by: Namhyung Kim Tested-by: Arnaldo Carvalho de Melo Cc: David Ahern Cc: Jiri Olsa Cc: Minchan Kim Cc: Peter Zijlstra Link: http://lkml.kernel.org/r/20170113104523.31212-2-namhyung@kernel.org Signed-off-by: Arnaldo Carvalho de Melo --- tools/perf/Documentation/perf-sched.txt | 2 ++ tools/perf/builtin-sched.c | 38 +++++++++++++++++++++++++++++---- 2 files changed, 36 insertions(+), 4 deletions(-) diff --git a/tools/perf/Documentation/perf-sched.txt b/tools/perf/Documentation/perf-sched.txt index 7617396..d33dedd 100644 --- a/tools/perf/Documentation/perf-sched.txt +++ b/tools/perf/Documentation/perf-sched.txt @@ -143,6 +143,8 @@ OPTIONS for 'perf sched timehist' stop time is not given (i.e, time string is 'x.y,') then analysis goes to end of file. +--state:: + Show task state when it switched out. SEE ALSO -------- diff --git a/tools/perf/builtin-sched.c b/tools/perf/builtin-sched.c index 6d3c3e8..a8ac766 100644 --- a/tools/perf/builtin-sched.c +++ b/tools/perf/builtin-sched.c @@ -222,6 +222,7 @@ struct perf_sched { bool show_cpu_visual; bool show_wakeups; bool show_migrations; + bool show_state; u64 skipped_samples; const char *time_str; struct perf_time_interval ptime; @@ -1840,6 +1841,9 @@ static void timehist_header(struct perf_sched *sched) printf(" %-*s %9s %9s %9s", comm_width, "task name", "wait time", "sch delay", "run time"); + if (sched->show_state) + printf(" %s", "state"); + printf("\n"); /* @@ -1850,9 +1854,14 @@ static void timehist_header(struct perf_sched *sched) if (sched->show_cpu_visual) printf(" %*s ", ncpus, ""); - printf(" %-*s %9s %9s %9s\n", comm_width, + printf(" %-*s %9s %9s %9s", comm_width, "[tid/pid]", "(msec)", "(msec)", "(msec)"); + if (sched->show_state) + printf(" %5s", ""); + + printf("\n"); + /* * separator */ @@ -1865,14 +1874,29 @@ static void timehist_header(struct perf_sched *sched) graph_dotted_line, graph_dotted_line, graph_dotted_line, graph_dotted_line); + if (sched->show_state) + printf(" %.5s", graph_dotted_line); + printf("\n"); } +static char task_state_char(struct thread *thread, int state) +{ + static const char state_to_char[] = TASK_STATE_TO_CHAR_STR; + unsigned bit = state ? ffs(state) : 0; + + /* 'I' for idle */ + if (thread->tid == 0) + return 'I'; + + return bit < sizeof(state_to_char) - 1 ? state_to_char[bit] : '?'; +} + static void timehist_print_sample(struct perf_sched *sched, struct perf_sample *sample, struct addr_location *al, struct thread *thread, - u64 t) + u64 t, int state) { struct thread_runtime *tr = thread__priv(thread); u32 max_cpus = sched->max_cpu + 1; @@ -1906,6 +1930,9 @@ static void timehist_print_sample(struct perf_sched *sched, print_sched_time(tr->dt_delay, 6); print_sched_time(tr->dt_run, 6); + if (sched->show_state) + printf(" %5c ", task_state_char(thread, state)); + if (sched->show_wakeups) printf(" %-*s", comm_width, ""); @@ -2406,6 +2433,8 @@ static int timehist_sched_change_event(struct perf_tool *tool, struct thread_runtime *tr = NULL; u64 tprev, t = sample->time; int rc = 0; + int state = perf_evsel__intval(evsel, sample, "prev_state"); + if (machine__resolve(machine, &al, sample) < 0) { pr_err("problem processing %d event. skipping it\n", @@ -2493,7 +2522,7 @@ static int timehist_sched_change_event(struct perf_tool *tool, } if (!sched->summary_only) - timehist_print_sample(sched, sample, &al, thread, t); + timehist_print_sample(sched, sample, &al, thread, t, state); out: if (sched->hist_time.start == 0 && t >= ptime->start) @@ -2506,7 +2535,7 @@ out: tr->last_time = sample->time; /* last state is used to determine where to account wait time */ - tr->last_state = perf_evsel__intval(evsel, sample, "prev_state"); + tr->last_state = state; /* sched out event for task so reset ready to run time */ tr->ready_to_run = 0; @@ -3278,6 +3307,7 @@ int cmd_sched(int argc, const char **argv, const char *prefix __maybe_unused) 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_BOOLEAN(0, "state", &sched.show_state, "Show task state when sched-out"), OPT_PARENT(sched_options) };