From: Namhyung Kim Date: Fri, 13 Jan 2017 10:45:22 +0000 (+0900) Subject: perf sched timehist: Add --state option X-Git-Tag: v4.11-rc1~172^2~24^2~3 X-Git-Url: https://asedeno.scripts.mit.edu/gitweb/?a=commitdiff_plain;h=414e050c68ec2a3dd815544ea48ff6016f1a7a11;p=linux.git 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 --- diff --git a/tools/perf/Documentation/perf-sched.txt b/tools/perf/Documentation/perf-sched.txt index 76173969ab80..d33deddb0146 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 6d3c3e84881a..a8ac76602187 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 @@ static int timehist_sched_change_event(struct perf_tool *tool, 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) };