From mboxrd@z Thu Jan 1 00:00:00 1970 Return-Path: Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand id S1752740AbdCNSyp (ORCPT ); Tue, 14 Mar 2017 14:54:45 -0400 Received: from bombadil.infradead.org ([65.50.211.133]:35756 "EHLO bombadil.infradead.org" rhost-flags-OK-OK-OK-OK) by vger.kernel.org with ESMTP id S1751300AbdCNSuh (ORCPT ); Tue, 14 Mar 2017 14:50:37 -0400 From: Arnaldo Carvalho de Melo To: Ingo Molnar Cc: linux-kernel@vger.kernel.org, Brendan Gregg , Alexander Shishkin , Namhyung Kim , Peter Zijlstra , Arnaldo Carvalho de Melo Subject: [PATCH 14/19] perf sched timehist: Add --next option Date: Tue, 14 Mar 2017 15:50:18 -0300 Message-Id: <20170314185023.31303-15-acme@kernel.org> X-Mailer: git-send-email 2.9.3 In-Reply-To: <20170314185023.31303-1-acme@kernel.org> References: <20170314185023.31303-1-acme@kernel.org> X-SRS-Rewrite: SMTP reverse-path rewritten from by bombadil.infradead.org. See http://www.infradead.org/rpr.html Sender: linux-kernel-owner@vger.kernel.org List-ID: X-Mailing-List: linux-kernel@vger.kernel.org From: Brendan Gregg The --next option shows the next task for each context switch, providing more context for the sequence of scheduler events. $ perf sched timehist --next | head Samples do not have callchains. time cpu task name waittime schdelay run time [tid/pid] (msec) (msec) (msec) ---------- --- ---------- --------- ------ ----- 374.793792 [0] 0.000 0.000 0.000 next: rngd[1524] 374.793801 [0] rngd[1524] 0.000 0.000 0.009 next: swapper/0[0] 374.794048 [7] 0.000 0.000 0.000 next: yes[30884] 374.794066 [7] yes[30884] 0.000 0.000 0.018 next: swapper/7[0] 374.794126 [2] 0.000 0.000 0.000 next: rngd[1524] 374.794140 [2] rngd[1524] 0.325 0.006 0.013 next: swapper/2[0] 374.794281 [3] 0.000 0.000 0.000 next: perf[31070] Signed-off-by: Brendan Gregg Tested-by: Arnaldo Carvalho de Melo Cc: Alexander Shishkin Cc: Namhyung Kim Cc: Peter Zijlstra Link: http://lkml.kernel.org/r/1489456589-32555-1-git-send-email-bgregg@netflix.com Signed-off-by: Arnaldo Carvalho de Melo --- tools/perf/Documentation/perf-sched.txt | 4 ++++ tools/perf/builtin-sched.c | 25 ++++++++++++++++++++----- 2 files changed, 24 insertions(+), 5 deletions(-) diff --git a/tools/perf/Documentation/perf-sched.txt b/tools/perf/Documentation/perf-sched.txt index d33deddb0146..a092a2499e8f 100644 --- a/tools/perf/Documentation/perf-sched.txt +++ b/tools/perf/Documentation/perf-sched.txt @@ -132,6 +132,10 @@ OPTIONS for 'perf sched timehist' --migrations:: Show migration events. +-n:: +--next:: + Show next task. + -I:: --idle-hist:: Show idle-related events only. diff --git a/tools/perf/builtin-sched.c b/tools/perf/builtin-sched.c index 16170e9b47e6..b92c4d97192c 100644 --- a/tools/perf/builtin-sched.c +++ b/tools/perf/builtin-sched.c @@ -221,6 +221,7 @@ struct perf_sched { unsigned int max_stack; bool show_cpu_visual; bool show_wakeups; + bool show_next; bool show_migrations; bool show_state; u64 skipped_samples; @@ -1897,14 +1898,18 @@ static char task_state_char(struct thread *thread, int state) } static void timehist_print_sample(struct perf_sched *sched, + struct perf_evsel *evsel, struct perf_sample *sample, struct addr_location *al, struct thread *thread, u64 t, int state) { struct thread_runtime *tr = thread__priv(thread); + const char *next_comm = perf_evsel__strval(evsel, sample, "next_comm"); + const u32 next_pid = perf_evsel__intval(evsel, sample, "next_pid"); u32 max_cpus = sched->max_cpu + 1; char tstr[64]; + char nstr[30]; u64 wait_time; timestamp__scnprintf_usec(t, tstr, sizeof(tstr)); @@ -1937,7 +1942,12 @@ static void timehist_print_sample(struct perf_sched *sched, if (sched->show_state) printf(" %5c ", task_state_char(thread, state)); - if (sched->show_wakeups) + if (sched->show_next) { + snprintf(nstr, sizeof(nstr), "next: %s[%d]", next_comm, next_pid); + printf(" %-*s", comm_width, nstr); + } + + if (sched->show_wakeups && !sched->show_next) printf(" %-*s", comm_width, ""); if (thread->tid == 0) @@ -2531,7 +2541,7 @@ static int timehist_sched_change_event(struct perf_tool *tool, } if (!sched->summary_only) - timehist_print_sample(sched, sample, &al, thread, t, state); + timehist_print_sample(sched, evsel, sample, &al, thread, t, state); out: if (sched->hist_time.start == 0 && t >= ptime->start) @@ -3341,6 +3351,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('n', "next", &sched.show_next, "Show next task"), OPT_BOOLEAN('M', "migrations", &sched.show_migrations, "Show migration events"), OPT_BOOLEAN('V', "cpu-visual", &sched.show_cpu_visual, "Add CPU visual"), OPT_BOOLEAN('I', "idle-hist", &sched.idle_hist, "Show idle events only"), @@ -3438,10 +3449,14 @@ int cmd_sched(int argc, const char **argv, const char *prefix __maybe_unused) if (argc) usage_with_options(timehist_usage, timehist_options); } - if (sched.show_wakeups && sched.summary_only) { - pr_err(" Error: -s and -w are mutually exclusive.\n"); + if ((sched.show_wakeups || sched.show_next) && + sched.summary_only) { + pr_err(" Error: -s and -[n|w] are mutually exclusive.\n"); parse_options_usage(timehist_usage, timehist_options, "s", true); - parse_options_usage(NULL, timehist_options, "w", true); + if (sched.show_wakeups) + parse_options_usage(NULL, timehist_options, "w", true); + if (sched.show_next) + parse_options_usage(NULL, timehist_options, "n", true); return -EINVAL; } -- 2.9.3