Commit 414e050c authored by Namhyung Kim's avatar Namhyung Kim Committed by Arnaldo Carvalho de Melo

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] <idle>                     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] <idle>                     0.000     0.000    0.079     I
  1.753915 [3] migration/3[23]            0.000     0.002    0.011     S
  1.754287 [2] <idle>                     0.000     0.000    0.000     I
  1.754335 [2] transmission[1773/1739]    0.000     0.004    0.047     S
Signed-off-by: default avatarNamhyung Kim <namhyung@kernel.org>
Tested-by: default avatarArnaldo Carvalho de Melo <acme@redhat.com>
Cc: David Ahern <dsahern@gmail.com>
Cc: Jiri Olsa <jolsa@kernel.org>
Cc: Minchan Kim <minchan@kernel.org>
Cc: Peter Zijlstra <peterz@infradead.org>
Link: http://lkml.kernel.org/r/20170113104523.31212-2-namhyung@kernel.orgSigned-off-by: default avatarArnaldo Carvalho de Melo <acme@redhat.com>
parent 941bdea7
...@@ -143,6 +143,8 @@ OPTIONS for 'perf sched timehist' ...@@ -143,6 +143,8 @@ OPTIONS for 'perf sched timehist'
stop time is not given (i.e, time string is 'x.y,') then analysis goes stop time is not given (i.e, time string is 'x.y,') then analysis goes
to end of file. to end of file.
--state::
Show task state when it switched out.
SEE ALSO SEE ALSO
-------- --------
......
...@@ -222,6 +222,7 @@ struct perf_sched { ...@@ -222,6 +222,7 @@ struct perf_sched {
bool show_cpu_visual; bool show_cpu_visual;
bool show_wakeups; bool show_wakeups;
bool show_migrations; bool show_migrations;
bool show_state;
u64 skipped_samples; u64 skipped_samples;
const char *time_str; const char *time_str;
struct perf_time_interval ptime; struct perf_time_interval ptime;
...@@ -1840,6 +1841,9 @@ static void timehist_header(struct perf_sched *sched) ...@@ -1840,6 +1841,9 @@ static void timehist_header(struct perf_sched *sched)
printf(" %-*s %9s %9s %9s", comm_width, printf(" %-*s %9s %9s %9s", comm_width,
"task name", "wait time", "sch delay", "run time"); "task name", "wait time", "sch delay", "run time");
if (sched->show_state)
printf(" %s", "state");
printf("\n"); printf("\n");
/* /*
...@@ -1850,9 +1854,14 @@ static void timehist_header(struct perf_sched *sched) ...@@ -1850,9 +1854,14 @@ static void timehist_header(struct perf_sched *sched)
if (sched->show_cpu_visual) if (sched->show_cpu_visual)
printf(" %*s ", ncpus, ""); printf(" %*s ", ncpus, "");
printf(" %-*s %9s %9s %9s\n", comm_width, printf(" %-*s %9s %9s %9s", comm_width,
"[tid/pid]", "(msec)", "(msec)", "(msec)"); "[tid/pid]", "(msec)", "(msec)", "(msec)");
if (sched->show_state)
printf(" %5s", "");
printf("\n");
/* /*
* separator * separator
*/ */
...@@ -1865,14 +1874,29 @@ static void timehist_header(struct perf_sched *sched) ...@@ -1865,14 +1874,29 @@ static void timehist_header(struct perf_sched *sched)
graph_dotted_line, graph_dotted_line, graph_dotted_line, graph_dotted_line, graph_dotted_line, graph_dotted_line,
graph_dotted_line); graph_dotted_line);
if (sched->show_state)
printf(" %.5s", graph_dotted_line);
printf("\n"); 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, static void timehist_print_sample(struct perf_sched *sched,
struct perf_sample *sample, struct perf_sample *sample,
struct addr_location *al, struct addr_location *al,
struct thread *thread, struct thread *thread,
u64 t) u64 t, int state)
{ {
struct thread_runtime *tr = thread__priv(thread); struct thread_runtime *tr = thread__priv(thread);
u32 max_cpus = sched->max_cpu + 1; u32 max_cpus = sched->max_cpu + 1;
...@@ -1906,6 +1930,9 @@ static void timehist_print_sample(struct perf_sched *sched, ...@@ -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_delay, 6);
print_sched_time(tr->dt_run, 6); print_sched_time(tr->dt_run, 6);
if (sched->show_state)
printf(" %5c ", task_state_char(thread, state));
if (sched->show_wakeups) if (sched->show_wakeups)
printf(" %-*s", comm_width, ""); printf(" %-*s", comm_width, "");
...@@ -2406,6 +2433,8 @@ static int timehist_sched_change_event(struct perf_tool *tool, ...@@ -2406,6 +2433,8 @@ static int timehist_sched_change_event(struct perf_tool *tool,
struct thread_runtime *tr = NULL; struct thread_runtime *tr = NULL;
u64 tprev, t = sample->time; u64 tprev, t = sample->time;
int rc = 0; int rc = 0;
int state = perf_evsel__intval(evsel, sample, "prev_state");
if (machine__resolve(machine, &al, sample) < 0) { if (machine__resolve(machine, &al, sample) < 0) {
pr_err("problem processing %d event. skipping it\n", pr_err("problem processing %d event. skipping it\n",
...@@ -2493,7 +2522,7 @@ static int timehist_sched_change_event(struct perf_tool *tool, ...@@ -2493,7 +2522,7 @@ static int timehist_sched_change_event(struct perf_tool *tool,
} }
if (!sched->summary_only) if (!sched->summary_only)
timehist_print_sample(sched, sample, &al, thread, t); timehist_print_sample(sched, sample, &al, thread, t, state);
out: out:
if (sched->hist_time.start == 0 && t >= ptime->start) if (sched->hist_time.start == 0 && t >= ptime->start)
...@@ -2506,7 +2535,7 @@ static int timehist_sched_change_event(struct perf_tool *tool, ...@@ -2506,7 +2535,7 @@ static int timehist_sched_change_event(struct perf_tool *tool,
tr->last_time = sample->time; tr->last_time = sample->time;
/* last state is used to determine where to account wait 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 */ /* sched out event for task so reset ready to run time */
tr->ready_to_run = 0; tr->ready_to_run = 0;
...@@ -3278,6 +3307,7 @@ int cmd_sched(int argc, const char **argv, const char *prefix __maybe_unused) ...@@ -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_BOOLEAN('I', "idle-hist", &sched.idle_hist, "Show idle events only"),
OPT_STRING(0, "time", &sched.time_str, "str", OPT_STRING(0, "time", &sched.time_str, "str",
"Time span for analysis (start,stop)"), "Time span for analysis (start,stop)"),
OPT_BOOLEAN(0, "state", &sched.show_state, "Show task state when sched-out"),
OPT_PARENT(sched_options) OPT_PARENT(sched_options)
}; };
......
Markdown is supported
0%
or
You are about to add 0 people to the discussion. Proceed with caution.
Finish editing this message first!
Please register or to comment