From 350f54fab2afd7f819e64fbeecdf980086fa59f2 Mon Sep 17 00:00:00 2001 From: David Ahern Date: Fri, 25 Nov 2016 09:28:41 -0700 Subject: [PATCH] perf sched timehist: Handle cpu migration events Add handlers for sched:sched_migrate_task event. Total number of migrations is added to summary display and -M/--migrations can be used to show migration events. Signed-off-by: David Ahern Tested-by: Arnaldo Carvalho de Melo Cc: Namhyung Kim Link: http://lkml.kernel.org/r/1480091321-35591-1-git-send-email-dsa@cumulusnetworks.com Signed-off-by: Arnaldo Carvalho de Melo --- tools/perf/Documentation/perf-sched.txt | 4 + tools/perf/builtin-sched.c | 97 ++++++++++++++++++++++++- 2 files changed, 99 insertions(+), 2 deletions(-) diff --git a/tools/perf/Documentation/perf-sched.txt b/tools/perf/Documentation/perf-sched.txt index fb9e52d65fca..121c60da03e5 100644 --- a/tools/perf/Documentation/perf-sched.txt +++ b/tools/perf/Documentation/perf-sched.txt @@ -128,6 +128,10 @@ OPTIONS for 'perf sched timehist' --wakeups:: Show wakeup events. +-M:: +--migrations:: + Show migration events. + SEE ALSO -------- linkperf:perf-record[1] diff --git a/tools/perf/builtin-sched.c b/tools/perf/builtin-sched.c index a49a032f5b15..4f9e7cba4ebf 100644 --- a/tools/perf/builtin-sched.c +++ b/tools/perf/builtin-sched.c @@ -203,6 +203,7 @@ struct perf_sched { unsigned int max_stack; bool show_cpu_visual; bool show_wakeups; + bool show_migrations; u64 skipped_samples; }; @@ -216,6 +217,8 @@ struct thread_runtime { struct stats run_stats; u64 total_run_time; + + u64 migrations; }; /* per event run time data */ @@ -2197,6 +2200,87 @@ static int timehist_sched_wakeup_event(struct perf_tool *tool, 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, union perf_event *event, struct perf_evsel *evsel, @@ -2295,6 +2379,7 @@ static void print_thread_runtime(struct thread *t, print_sched_time(r->run_stats.max, 6); printf(" "); printf("%5.2f", stddev); + printf(" %5" PRIu64, r->migrations); printf("\n"); } @@ -2356,10 +2441,10 @@ static void timehist_print_summary(struct perf_sched *sched, printf("\nRuntime summary\n"); 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(" (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); task_count = totals.task_count; @@ -2460,6 +2545,9 @@ static int perf_sched__timehist(struct perf_sched *sched) { "sched:sched_wakeup", 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 = { .path = input_name, .mode = PERF_DATA_MODE_READ, @@ -2507,6 +2595,10 @@ static int perf_sched__timehist(struct perf_sched *sched) if (!perf_session__has_traces(session, "record -R")) goto out; + if (sched->show_migrations && + perf_session__set_tracepoints_handlers(session, migrate_handlers)) + goto out; + /* pre-allocate struct for per-CPU idle stats */ sched->max_cpu = session->header.env.nr_cpus_online; if (sched->max_cpu == 0) @@ -2903,6 +2995,7 @@ int cmd_sched(int argc, const char **argv, const char *prefix __maybe_unused) OPT_BOOLEAN('S', "with-summary", &sched.summary, "Show all syscalls and summary with statistics"), 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_PARENT(sched_options) };