* [PATCH] perf sched timehist: Add --next option
@ 2017-03-14 1:56 Brendan Gregg
2017-03-14 13:12 ` Arnaldo Carvalho de Melo
2017-03-15 18:41 ` [tip:perf/core] " tip-bot for Brendan Gregg
0 siblings, 2 replies; 4+ messages in thread
From: Brendan Gregg @ 2017-03-14 1:56 UTC (permalink / raw)
To: Peter Zijlstra, Ingo Molnar, Arnaldo Carvalho de Melo,
Alexander Shishkin
Cc: linux-kernel, Namhyung Kim, 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 wait time sch delay run time
[tid/pid] (msec) (msec) (msec)
--------------- ------ ------------------------------ --------- --------- ---------
1136374.793792 [0000] <idle> 0.000 0.000 0.000 next: rngd[1524]
1136374.793801 [0000] rngd[1524] 0.000 0.000 0.009 next: swapper/0[0]
1136374.794048 [0007] <idle> 0.000 0.000 0.000 next: yes[30884]
1136374.794066 [0007] yes[30884] 0.000 0.000 0.018 next: swapper/7[0]
1136374.794126 [0002] <idle> 0.000 0.000 0.000 next: rngd[1524]
1136374.794140 [0002] rngd[1524] 0.325 0.006 0.013 next: swapper/2[0]
1136374.794281 [0003] <idle> 0.000 0.000 0.000 next: perf[31070]
Signed-off-by: Brendan Gregg <bgregg@netflix.com>
---
tools/perf/Documentation/perf-sched.txt | 4 ++++
tools/perf/builtin-sched.c | 29 ++++++++++++++++++++++++-----
2 files changed, 28 insertions(+), 5 deletions(-)
diff --git a/tools/perf/Documentation/perf-sched.txt b/tools/perf/Documentation/perf-sched.txt
index d33dedd..a092a24 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 b94cf0d..fedc8f2 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,13 @@ 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 +2542,8 @@ 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)
@@ -3340,6 +3352,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"),
@@ -3437,10 +3450,16 @@ 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.7.4
^ permalink raw reply related [flat|nested] 4+ messages in thread
* Re: [PATCH] perf sched timehist: Add --next option
2017-03-14 1:56 [PATCH] perf sched timehist: Add --next option Brendan Gregg
@ 2017-03-14 13:12 ` Arnaldo Carvalho de Melo
2017-03-15 0:39 ` Brendan Gregg
2017-03-15 18:41 ` [tip:perf/core] " tip-bot for Brendan Gregg
1 sibling, 1 reply; 4+ messages in thread
From: Arnaldo Carvalho de Melo @ 2017-03-14 13:12 UTC (permalink / raw)
To: Brendan Gregg
Cc: Peter Zijlstra, Ingo Molnar, Alexander Shishkin, linux-kernel,
Namhyung Kim
Em Tue, Mar 14, 2017 at 01:56:29AM +0000, Brendan Gregg escreveu:
> 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 wait time sch delay run time
> [tid/pid] (msec) (msec) (msec)
> --------------- ------ ------------------------------ --------- --------- ---------
Thanks, applied.
Minor request: when printing tool output in the cset comment, please add
two spaces before all lines, my git-am scripts get confused with that
--- thinking its a separator.
- Arnaldo
> 1136374.793792 [0000] <idle> 0.000 0.000 0.000 next: rngd[1524]
> 1136374.793801 [0000] rngd[1524] 0.000 0.000 0.009 next: swapper/0[0]
> 1136374.794048 [0007] <idle> 0.000 0.000 0.000 next: yes[30884]
> 1136374.794066 [0007] yes[30884] 0.000 0.000 0.018 next: swapper/7[0]
> 1136374.794126 [0002] <idle> 0.000 0.000 0.000 next: rngd[1524]
> 1136374.794140 [0002] rngd[1524] 0.325 0.006 0.013 next: swapper/2[0]
> 1136374.794281 [0003] <idle> 0.000 0.000 0.000 next: perf[31070]
>
> Signed-off-by: Brendan Gregg <bgregg@netflix.com>
> ---
> tools/perf/Documentation/perf-sched.txt | 4 ++++
> tools/perf/builtin-sched.c | 29 ++++++++++++++++++++++++-----
> 2 files changed, 28 insertions(+), 5 deletions(-)
>
> diff --git a/tools/perf/Documentation/perf-sched.txt b/tools/perf/Documentation/perf-sched.txt
> index d33dedd..a092a24 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 b94cf0d..fedc8f2 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,13 @@ 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 +2542,8 @@ 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)
> @@ -3340,6 +3352,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"),
> @@ -3437,10 +3450,16 @@ 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.7.4
^ permalink raw reply [flat|nested] 4+ messages in thread
* Re: [PATCH] perf sched timehist: Add --next option
2017-03-14 13:12 ` Arnaldo Carvalho de Melo
@ 2017-03-15 0:39 ` Brendan Gregg
0 siblings, 0 replies; 4+ messages in thread
From: Brendan Gregg @ 2017-03-15 0:39 UTC (permalink / raw)
To: Arnaldo Carvalho de Melo
Cc: Peter Zijlstra, Ingo Molnar, Alexander Shishkin, linux-kernel,
Namhyung Kim
On Tue, Mar 14, 2017 at 6:12 AM, Arnaldo Carvalho de Melo
<acme@kernel.org> wrote:
> Em Tue, Mar 14, 2017 at 01:56:29AM +0000, Brendan Gregg escreveu:
>> 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 wait time sch delay run time
>> [tid/pid] (msec) (msec) (msec)
>> --------------- ------ ------------------------------ --------- --------- ---------
>
> Thanks, applied.
>
> Minor request: when printing tool output in the cset comment, please add
> two spaces before all lines, my git-am scripts get confused with that
> --- thinking its a separator.
Ok, will do in the future, thanks Arnaldo!
Brendan
^ permalink raw reply [flat|nested] 4+ messages in thread
* [tip:perf/core] perf sched timehist: Add --next option
2017-03-14 1:56 [PATCH] perf sched timehist: Add --next option Brendan Gregg
2017-03-14 13:12 ` Arnaldo Carvalho de Melo
@ 2017-03-15 18:41 ` tip-bot for Brendan Gregg
1 sibling, 0 replies; 4+ messages in thread
From: tip-bot for Brendan Gregg @ 2017-03-15 18:41 UTC (permalink / raw)
To: linux-tip-commits
Cc: acme, linux-kernel, mingo, peterz, namhyung, alexander.shishkin,
hpa, tglx, bgregg
Commit-ID: 292c4a8f985b35b3738d5900fe256c4fed4cd3f5
Gitweb: http://git.kernel.org/tip/292c4a8f985b35b3738d5900fe256c4fed4cd3f5
Author: Brendan Gregg <bgregg@netflix.com>
AuthorDate: Tue, 14 Mar 2017 01:56:29 +0000
Committer: Arnaldo Carvalho de Melo <acme@redhat.com>
CommitDate: Tue, 14 Mar 2017 15:17:38 -0300
perf sched timehist: Add --next option
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] <idle> 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] <idle> 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] <idle> 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] <idle> 0.000 0.000 0.000 next: perf[31070]
Signed-off-by: Brendan Gregg <bgregg@netflix.com>
Tested-by: Arnaldo Carvalho de Melo <acme@redhat.com>
Cc: Alexander Shishkin <alexander.shishkin@linux.intel.com>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: Peter Zijlstra <peterz@infradead.org>
Link: http://lkml.kernel.org/r/1489456589-32555-1-git-send-email-bgregg@netflix.com
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
---
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 d33dedd..a092a24 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 16170e9..b92c4d9 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;
}
^ permalink raw reply related [flat|nested] 4+ messages in thread
end of thread, other threads:[~2017-03-15 18:43 UTC | newest]
Thread overview: 4+ messages (download: mbox.gz follow: Atom feed
-- links below jump to the message on this page --
2017-03-14 1:56 [PATCH] perf sched timehist: Add --next option Brendan Gregg
2017-03-14 13:12 ` Arnaldo Carvalho de Melo
2017-03-15 0:39 ` Brendan Gregg
2017-03-15 18:41 ` [tip:perf/core] " tip-bot for Brendan Gregg
This is an external index of several public inboxes,
see mirroring instructions on how to clone and mirror
all data and code used by this external index.