#define TASK_STATE_TO_CHAR_STR "RSDTtZXxKWP"
+/* task state bitmask, copied from include/linux/sched.h */
+#define TASK_RUNNING 0
+#define TASK_INTERRUPTIBLE 1
+#define TASK_UNINTERRUPTIBLE 2
+#define __TASK_STOPPED 4
+#define __TASK_TRACED 8
+/* in tsk->exit_state */
+#define EXIT_DEAD 16
+#define EXIT_ZOMBIE 32
+#define EXIT_TRACE (EXIT_ZOMBIE | EXIT_DEAD)
+/* in tsk->state again */
+#define TASK_DEAD 64
+#define TASK_WAKEKILL 128
+#define TASK_WAKING 256
+#define TASK_PARKED 512
+
enum thread_state {
THREAD_SLEEPING = 0,
THREAD_WAIT_CPU,
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;
struct thread_runtime {
u64 last_time; /* time of previous sched in/out event */
u64 dt_run; /* run time */
- u64 dt_wait; /* time between CPU access (off cpu) */
+ u64 dt_sleep; /* time between CPU access by sleep (off cpu) */
+ u64 dt_iowait; /* time between CPU access by iowait (off cpu) */
+ u64 dt_preempt; /* time between CPU access by preempt (off cpu) */
u64 dt_delay; /* time between wakeup and sched-in */
u64 ready_to_run; /* time of wakeup */
struct stats run_stats;
u64 total_run_time;
+ u64 total_sleep_time;
+ u64 total_iowait_time;
+ u64 total_preempt_time;
+ u64 total_delay_time;
+ int last_state;
u64 migrations;
};
printf(" %-*s %9s %9s %9s", comm_width,
"task name", "wait time", "sch delay", "run time");
+ if (sched->show_state)
+ printf(" %s", "state");
+
printf("\n");
/*
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
*/
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;
char tstr[64];
+ u64 wait_time;
timestamp__scnprintf_usec(t, tstr, sizeof(tstr));
printf("%15s [%04d] ", tstr, sample->cpu);
printf(" %-*s ", comm_width, timehist_get_commstr(thread));
- print_sched_time(tr->dt_wait, 6);
+ wait_time = tr->dt_sleep + tr->dt_iowait + tr->dt_preempt;
+ print_sched_time(wait_time, 6);
+
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, "");
u64 t, u64 tprev)
{
r->dt_delay = 0;
- r->dt_wait = 0;
+ r->dt_sleep = 0;
+ r->dt_iowait = 0;
+ r->dt_preempt = 0;
r->dt_run = 0;
+
if (tprev) {
r->dt_run = t - tprev;
if (r->ready_to_run) {
if (r->last_time > tprev)
pr_debug("time travel: last sched out time for task > previous sched_switch event\n");
- else if (r->last_time)
- r->dt_wait = tprev - r->last_time;
+ else if (r->last_time) {
+ u64 dt_wait = tprev - r->last_time;
+
+ if (r->last_state == TASK_RUNNING)
+ r->dt_preempt = dt_wait;
+ else if (r->last_state == TASK_UNINTERRUPTIBLE)
+ r->dt_iowait = dt_wait;
+ else
+ r->dt_sleep = dt_wait;
+ }
}
update_stats(&r->run_stats, r->dt_run);
- r->total_run_time += r->dt_run;
+
+ r->total_run_time += r->dt_run;
+ r->total_delay_time += r->dt_delay;
+ r->total_sleep_time += r->dt_sleep;
+ r->total_iowait_time += r->dt_iowait;
+ r->total_preempt_time += r->dt_preempt;
}
static bool is_idle_sample(struct perf_sample *sample,
break;
sym = node->sym;
- if (sym && sym->name) {
+ if (sym) {
if (!strcmp(sym->name, "schedule") ||
!strcmp(sym->name, "__schedule") ||
!strcmp(sym->name, "preempt_schedule"))
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",
* 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;
+ last_tr->dt_sleep = 0;
+ last_tr->dt_iowait = 0;
+ last_tr->dt_preempt = 0;
if (itr->cursor.nr)
callchain_append(&itr->callchain, &itr->cursor, t - tprev);
}
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)
/* time of this sched_switch event becomes last time task seen */
tr->last_time = sample->time;
+ /* last state is used to determine where to account wait time */
+ tr->last_state = state;
+
/* sched out event for task so reset ready to run time */
tr->ready_to_run = 0;
}
printf("\n");
}
+static void print_thread_waittime(struct thread *t,
+ struct thread_runtime *r)
+{
+ printf("%*s %5d %9" PRIu64 " ",
+ comm_width, timehist_get_commstr(t), t->ppid,
+ (u64) r->run_stats.n);
+
+ print_sched_time(r->total_run_time, 8);
+ print_sched_time(r->total_sleep_time, 6);
+ printf(" ");
+ print_sched_time(r->total_iowait_time, 6);
+ printf(" ");
+ print_sched_time(r->total_preempt_time, 6);
+ printf(" ");
+ print_sched_time(r->total_delay_time, 6);
+ printf("\n");
+}
+
struct total_run_stats {
+ struct perf_sched *sched;
u64 sched_count;
u64 task_count;
u64 total_run_time;
stats->task_count++;
stats->sched_count += r->run_stats.n;
stats->total_run_time += r->total_run_time;
- print_thread_runtime(t, r);
+
+ if (stats->sched->show_state)
+ print_thread_waittime(t, r);
+ else
+ print_thread_runtime(t, r);
}
return 0;
u64 hist_time = sched->hist_time.end - sched->hist_time.start;
memset(&totals, 0, sizeof(totals));
+ totals.sched = sched;
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 if (sched->show_state) {
+ printf("\nWait-time summary\n");
+ printf("%*s parent sched-in ", comm_width, "comm");
+ printf(" run-time sleep iowait preempt delay\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(" (msec) (msec) (msec) (msec) %s\n",
+ sched->show_state ? "(msec)" : "%");
printf("%.117s\n", graph_dotted_line);
machine__for_each_thread(m, show_thread_runtime, &totals);
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)
};
projects / linux.git / blobdiff