|
@@ -15,6 +15,7 @@
|
|
#include "util/color.h"
|
|
#include "util/color.h"
|
|
#include "util/stat.h"
|
|
#include "util/stat.h"
|
|
#include "util/callchain.h"
|
|
#include "util/callchain.h"
|
|
|
|
+#include "util/time-utils.h"
|
|
|
|
|
|
#include <subcmd/parse-options.h>
|
|
#include <subcmd/parse-options.h>
|
|
#include "util/trace-event.h"
|
|
#include "util/trace-event.h"
|
|
@@ -203,7 +204,10 @@ struct perf_sched {
|
|
unsigned int max_stack;
|
|
unsigned int max_stack;
|
|
bool show_cpu_visual;
|
|
bool show_cpu_visual;
|
|
bool show_wakeups;
|
|
bool show_wakeups;
|
|
|
|
+ bool show_migrations;
|
|
u64 skipped_samples;
|
|
u64 skipped_samples;
|
|
|
|
+ const char *time_str;
|
|
|
|
+ struct perf_time_interval ptime;
|
|
};
|
|
};
|
|
|
|
|
|
/* per thread run time data */
|
|
/* per thread run time data */
|
|
@@ -216,6 +220,8 @@ struct thread_runtime {
|
|
|
|
|
|
struct stats run_stats;
|
|
struct stats run_stats;
|
|
u64 total_run_time;
|
|
u64 total_run_time;
|
|
|
|
+
|
|
|
|
+ u64 migrations;
|
|
};
|
|
};
|
|
|
|
|
|
/* per event run time data */
|
|
/* per event run time data */
|
|
@@ -1834,13 +1840,14 @@ static void timehist_header(struct perf_sched *sched)
|
|
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)
|
|
{
|
|
{
|
|
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;
|
|
char tstr[64];
|
|
char tstr[64];
|
|
|
|
|
|
- timestamp__scnprintf_usec(sample->time, tstr, sizeof(tstr));
|
|
|
|
|
|
+ timestamp__scnprintf_usec(t, tstr, sizeof(tstr));
|
|
printf("%15s [%04d] ", tstr, sample->cpu);
|
|
printf("%15s [%04d] ", tstr, sample->cpu);
|
|
|
|
|
|
if (sched->show_cpu_visual) {
|
|
if (sched->show_cpu_visual) {
|
|
@@ -2191,12 +2198,94 @@ static int timehist_sched_wakeup_event(struct perf_tool *tool,
|
|
tr->ready_to_run = sample->time;
|
|
tr->ready_to_run = sample->time;
|
|
|
|
|
|
/* show wakeups if requested */
|
|
/* show wakeups if requested */
|
|
- if (sched->show_wakeups)
|
|
|
|
|
|
+ if (sched->show_wakeups &&
|
|
|
|
+ !perf_time__skip_sample(&sched->ptime, sample->time))
|
|
timehist_print_wakeup_event(sched, sample, machine, thread);
|
|
timehist_print_wakeup_event(sched, sample, machine, thread);
|
|
|
|
|
|
return 0;
|
|
return 0;
|
|
}
|
|
}
|
|
|
|
|
|
|
|
+static void timehist_print_migration_event(struct perf_sched *sched,
|
|
|
|
+ struct perf_evsel *evsel,
|
|
|
|
+ struct perf_sample *sample,
|
|
|
|
+ struct machine *machine,
|
|
|
|
+ struct thread *migrated)
|
|
|
|
+{
|
|
|
|
+ struct thread *thread;
|
|
|
|
+ char tstr[64];
|
|
|
|
+ u32 max_cpus = sched->max_cpu + 1;
|
|
|
|
+ u32 ocpu, dcpu;
|
|
|
|
+
|
|
|
|
+ if (sched->summary_only)
|
|
|
|
+ return;
|
|
|
|
+
|
|
|
|
+ max_cpus = sched->max_cpu + 1;
|
|
|
|
+ ocpu = perf_evsel__intval(evsel, sample, "orig_cpu");
|
|
|
|
+ dcpu = perf_evsel__intval(evsel, sample, "dest_cpu");
|
|
|
|
+
|
|
|
|
+ thread = machine__findnew_thread(machine, sample->pid, sample->tid);
|
|
|
|
+ if (thread == NULL)
|
|
|
|
+ return;
|
|
|
|
+
|
|
|
|
+ if (timehist_skip_sample(sched, thread) &&
|
|
|
|
+ timehist_skip_sample(sched, migrated)) {
|
|
|
|
+ return;
|
|
|
|
+ }
|
|
|
|
+
|
|
|
|
+ timestamp__scnprintf_usec(sample->time, tstr, sizeof(tstr));
|
|
|
|
+ printf("%15s [%04d] ", tstr, sample->cpu);
|
|
|
|
+
|
|
|
|
+ if (sched->show_cpu_visual) {
|
|
|
|
+ u32 i;
|
|
|
|
+ char c;
|
|
|
|
+
|
|
|
|
+ printf(" ");
|
|
|
|
+ for (i = 0; i < max_cpus; ++i) {
|
|
|
|
+ c = (i == sample->cpu) ? 'm' : ' ';
|
|
|
|
+ printf("%c", c);
|
|
|
|
+ }
|
|
|
|
+ printf(" ");
|
|
|
|
+ }
|
|
|
|
+
|
|
|
|
+ printf(" %-*s ", comm_width, timehist_get_commstr(thread));
|
|
|
|
+
|
|
|
|
+ /* dt spacer */
|
|
|
|
+ printf(" %9s %9s %9s ", "", "", "");
|
|
|
|
+
|
|
|
|
+ printf("migrated: %s", timehist_get_commstr(migrated));
|
|
|
|
+ printf(" cpu %d => %d", ocpu, dcpu);
|
|
|
|
+
|
|
|
|
+ printf("\n");
|
|
|
|
+}
|
|
|
|
+
|
|
|
|
+static int timehist_migrate_task_event(struct perf_tool *tool,
|
|
|
|
+ union perf_event *event __maybe_unused,
|
|
|
|
+ struct perf_evsel *evsel,
|
|
|
|
+ struct perf_sample *sample,
|
|
|
|
+ struct machine *machine)
|
|
|
|
+{
|
|
|
|
+ struct perf_sched *sched = container_of(tool, struct perf_sched, tool);
|
|
|
|
+ struct thread *thread;
|
|
|
|
+ struct thread_runtime *tr = NULL;
|
|
|
|
+ /* want pid of migrated task not pid in sample */
|
|
|
|
+ const u32 pid = perf_evsel__intval(evsel, sample, "pid");
|
|
|
|
+
|
|
|
|
+ thread = machine__findnew_thread(machine, 0, pid);
|
|
|
|
+ if (thread == NULL)
|
|
|
|
+ return -1;
|
|
|
|
+
|
|
|
|
+ tr = thread__get_runtime(thread);
|
|
|
|
+ if (tr == NULL)
|
|
|
|
+ return -1;
|
|
|
|
+
|
|
|
|
+ tr->migrations++;
|
|
|
|
+
|
|
|
|
+ /* show migrations if requested */
|
|
|
|
+ timehist_print_migration_event(sched, evsel, sample, machine, thread);
|
|
|
|
+
|
|
|
|
+ return 0;
|
|
|
|
+}
|
|
|
|
+
|
|
static int timehist_sched_change_event(struct perf_tool *tool,
|
|
static int timehist_sched_change_event(struct perf_tool *tool,
|
|
union perf_event *event,
|
|
union perf_event *event,
|
|
struct perf_evsel *evsel,
|
|
struct perf_evsel *evsel,
|
|
@@ -2204,10 +2293,11 @@ static int timehist_sched_change_event(struct perf_tool *tool,
|
|
struct machine *machine)
|
|
struct machine *machine)
|
|
{
|
|
{
|
|
struct perf_sched *sched = container_of(tool, struct perf_sched, tool);
|
|
struct perf_sched *sched = container_of(tool, struct perf_sched, tool);
|
|
|
|
+ struct perf_time_interval *ptime = &sched->ptime;
|
|
struct addr_location al;
|
|
struct addr_location al;
|
|
struct thread *thread;
|
|
struct thread *thread;
|
|
struct thread_runtime *tr = NULL;
|
|
struct thread_runtime *tr = NULL;
|
|
- u64 tprev;
|
|
|
|
|
|
+ u64 tprev, t = sample->time;
|
|
int rc = 0;
|
|
int rc = 0;
|
|
|
|
|
|
if (machine__resolve(machine, &al, sample) < 0) {
|
|
if (machine__resolve(machine, &al, sample) < 0) {
|
|
@@ -2234,9 +2324,35 @@ static int timehist_sched_change_event(struct perf_tool *tool,
|
|
|
|
|
|
tprev = perf_evsel__get_time(evsel, sample->cpu);
|
|
tprev = perf_evsel__get_time(evsel, sample->cpu);
|
|
|
|
|
|
- timehist_update_runtime_stats(tr, sample->time, tprev);
|
|
|
|
|
|
+ /*
|
|
|
|
+ * If start time given:
|
|
|
|
+ * - sample time is under window user cares about - skip sample
|
|
|
|
+ * - tprev is under window user cares about - reset to start of window
|
|
|
|
+ */
|
|
|
|
+ if (ptime->start && ptime->start > t)
|
|
|
|
+ goto out;
|
|
|
|
+
|
|
|
|
+ if (ptime->start > tprev)
|
|
|
|
+ tprev = ptime->start;
|
|
|
|
+
|
|
|
|
+ /*
|
|
|
|
+ * If end time given:
|
|
|
|
+ * - previous sched event is out of window - we are done
|
|
|
|
+ * - sample time is beyond window user cares about - reset it
|
|
|
|
+ * to close out stats for time window interest
|
|
|
|
+ */
|
|
|
|
+ if (ptime->end) {
|
|
|
|
+ if (tprev > ptime->end)
|
|
|
|
+ goto out;
|
|
|
|
+
|
|
|
|
+ if (t > ptime->end)
|
|
|
|
+ t = ptime->end;
|
|
|
|
+ }
|
|
|
|
+
|
|
|
|
+ timehist_update_runtime_stats(tr, t, tprev);
|
|
|
|
+
|
|
if (!sched->summary_only)
|
|
if (!sched->summary_only)
|
|
- timehist_print_sample(sched, sample, &al, thread);
|
|
|
|
|
|
+ timehist_print_sample(sched, sample, &al, thread, t);
|
|
|
|
|
|
out:
|
|
out:
|
|
if (tr) {
|
|
if (tr) {
|
|
@@ -2295,6 +2411,7 @@ static void print_thread_runtime(struct thread *t,
|
|
print_sched_time(r->run_stats.max, 6);
|
|
print_sched_time(r->run_stats.max, 6);
|
|
printf(" ");
|
|
printf(" ");
|
|
printf("%5.2f", stddev);
|
|
printf("%5.2f", stddev);
|
|
|
|
+ printf(" %5" PRIu64, r->migrations);
|
|
printf("\n");
|
|
printf("\n");
|
|
}
|
|
}
|
|
|
|
|
|
@@ -2356,10 +2473,10 @@ static void timehist_print_summary(struct perf_sched *sched,
|
|
|
|
|
|
printf("\nRuntime summary\n");
|
|
printf("\nRuntime summary\n");
|
|
printf("%*s parent sched-in ", comm_width, "comm");
|
|
printf("%*s parent sched-in ", comm_width, "comm");
|
|
- printf(" run-time min-run avg-run max-run stddev\n");
|
|
|
|
|
|
+ printf(" run-time min-run avg-run max-run stddev migrations\n");
|
|
printf("%*s (count) ", comm_width, "");
|
|
printf("%*s (count) ", comm_width, "");
|
|
printf(" (msec) (msec) (msec) (msec) %%\n");
|
|
printf(" (msec) (msec) (msec) (msec) %%\n");
|
|
- printf("%.105s\n", graph_dotted_line);
|
|
|
|
|
|
+ printf("%.117s\n", graph_dotted_line);
|
|
|
|
|
|
machine__for_each_thread(m, show_thread_runtime, &totals);
|
|
machine__for_each_thread(m, show_thread_runtime, &totals);
|
|
task_count = totals.task_count;
|
|
task_count = totals.task_count;
|
|
@@ -2460,6 +2577,9 @@ static int perf_sched__timehist(struct perf_sched *sched)
|
|
{ "sched:sched_wakeup", timehist_sched_wakeup_event, },
|
|
{ "sched:sched_wakeup", timehist_sched_wakeup_event, },
|
|
{ "sched:sched_wakeup_new", timehist_sched_wakeup_event, },
|
|
{ "sched:sched_wakeup_new", timehist_sched_wakeup_event, },
|
|
};
|
|
};
|
|
|
|
+ const struct perf_evsel_str_handler migrate_handlers[] = {
|
|
|
|
+ { "sched:sched_migrate_task", timehist_migrate_task_event, },
|
|
|
|
+ };
|
|
struct perf_data_file file = {
|
|
struct perf_data_file file = {
|
|
.path = input_name,
|
|
.path = input_name,
|
|
.mode = PERF_DATA_MODE_READ,
|
|
.mode = PERF_DATA_MODE_READ,
|
|
@@ -2495,6 +2615,11 @@ static int perf_sched__timehist(struct perf_sched *sched)
|
|
|
|
|
|
symbol__init(&session->header.env);
|
|
symbol__init(&session->header.env);
|
|
|
|
|
|
|
|
+ if (perf_time__parse_str(&sched->ptime, sched->time_str) != 0) {
|
|
|
|
+ pr_err("Invalid time string\n");
|
|
|
|
+ return -EINVAL;
|
|
|
|
+ }
|
|
|
|
+
|
|
if (timehist_check_attr(sched, evlist) != 0)
|
|
if (timehist_check_attr(sched, evlist) != 0)
|
|
goto out;
|
|
goto out;
|
|
|
|
|
|
@@ -2507,6 +2632,10 @@ static int perf_sched__timehist(struct perf_sched *sched)
|
|
if (!perf_session__has_traces(session, "record -R"))
|
|
if (!perf_session__has_traces(session, "record -R"))
|
|
goto out;
|
|
goto out;
|
|
|
|
|
|
|
|
+ if (sched->show_migrations &&
|
|
|
|
+ perf_session__set_tracepoints_handlers(session, migrate_handlers))
|
|
|
|
+ goto out;
|
|
|
|
+
|
|
/* pre-allocate struct for per-CPU idle stats */
|
|
/* pre-allocate struct for per-CPU idle stats */
|
|
sched->max_cpu = session->header.env.nr_cpus_online;
|
|
sched->max_cpu = session->header.env.nr_cpus_online;
|
|
if (sched->max_cpu == 0)
|
|
if (sched->max_cpu == 0)
|
|
@@ -2903,7 +3032,10 @@ int cmd_sched(int argc, const char **argv, const char *prefix __maybe_unused)
|
|
OPT_BOOLEAN('S', "with-summary", &sched.summary,
|
|
OPT_BOOLEAN('S', "with-summary", &sched.summary,
|
|
"Show all syscalls and summary with statistics"),
|
|
"Show all syscalls and summary with statistics"),
|
|
OPT_BOOLEAN('w', "wakeups", &sched.show_wakeups, "Show wakeup events"),
|
|
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('V', "cpu-visual", &sched.show_cpu_visual, "Add CPU visual"),
|
|
|
|
+ OPT_STRING(0, "time", &sched.time_str, "str",
|
|
|
|
+ "Time span for analysis (start,stop)"),
|
|
OPT_PARENT(sched_options)
|
|
OPT_PARENT(sched_options)
|
|
};
|
|
};
|
|
|
|
|