Groups | Search | Server Info | Keyboard shortcuts | Login | Register [http] [https] [nntp] [nntps]
Groups > linux.kernel > #1523246 > unrolled thread
| Started by | Namhyung Kim <namhyung@kernel.org> |
|---|---|
| First post | 2016-11-16 07:10 +0100 |
| Last post | 2016-11-24 05:50 +0100 |
| Articles | 5 — 3 participants |
Back to article view | Back to linux.kernel
This discussion starts older than the indexed window; earlier articles aren't shown. The article labeled Started by
below is the oldest one visible, not the original post.
[PATCH v2 7/8] perf sched timehist: Add -V/--cpu-visual option Namhyung Kim <namhyung@kernel.org> - 2016-11-16 07:10 +0100
Re: [PATCH v2 7/8] perf sched timehist: Add -V/--cpu-visual option Arnaldo Carvalho de Melo <acme@kernel.org> - 2016-11-22 19:40 +0100
Re: [PATCH v2 7/8] perf sched timehist: Add -V/--cpu-visual option Namhyung Kim <namhyung@kernel.org> - 2016-11-23 06:40 +0100
Re: [PATCH v2 7/8] perf sched timehist: Add -V/--cpu-visual option Arnaldo Carvalho de Melo <acme@kernel.org> - 2016-11-23 14:40 +0100
[tip:perf/core] perf sched timehist: Add -V/--cpu-visual option tip-bot for David Ahern <tipbot@zytor.com> - 2016-11-24 05:50 +0100
| From | Namhyung Kim <namhyung@kernel.org> |
|---|---|
| Date | 2016-11-16 07:10 +0100 |
| Subject | [PATCH v2 7/8] perf sched timehist: Add -V/--cpu-visual option |
| Message-ID | <sE1zY-7AZ-21@gated-at.bofh.it> |
From: David Ahern <dsahern@gmail.com>
The -V option provides a visual aid for sched switches by cpu:
$ perf sched timehist -V
time cpu 0123456789abc task name b/n time sch delay run time
[tid/pid] (msec) (msec) (msec)
--------------- ------ ------------- -------------------- --------- --------- ---------
...
2412598.429696 [0009] i <idle> 0.000 0.000 0.000
2412598.429767 [0002] s perf[7219] 0.000 0.000 0.000
2412598.429783 [0009] s perf[7220] 0.000 0.006 0.087
2412598.429794 [0010] i <idle> 0.000 0.000 0.000
2412598.429795 [0009] s migration/9[53] 0.000 0.003 0.011
2412598.430370 [0010] s sleep[7220] 0.011 0.000 0.576
2412598.432584 [0003] i <idle> 0.000 0.000 0.000
...
Signed-off-by: David Ahern <dsahern@gmail.com>
Signed-off-by: Namhyung Kim <namhyung@kernel.org>
---
tools/perf/builtin-sched.c | 44 ++++++++++++++++++++++++++++++++++++++++++--
1 file changed, 42 insertions(+), 2 deletions(-)
diff --git a/tools/perf/builtin-sched.c b/tools/perf/builtin-sched.c
index 1f8731640809..829468defa07 100644
--- a/tools/perf/builtin-sched.c
+++ b/tools/perf/builtin-sched.c
@@ -201,6 +201,7 @@ struct perf_sched {
bool summary_only;
bool show_callchain;
unsigned int max_stack;
+ bool show_cpu_visual;
bool show_wakeups;
u64 skipped_samples;
};
@@ -1783,10 +1784,23 @@ static char *timehist_get_commstr(struct thread *thread)
return str;
}
-static void timehist_header(void)
+static void timehist_header(struct perf_sched *sched)
{
+ u32 ncpus = sched->max_cpu + 1;
+ u32 i, j;
+
printf("%15s %6s ", "time", "cpu");
+ if (sched->show_cpu_visual) {
+ printf(" ");
+ for (i = 0, j = 0; i < ncpus; ++i) {
+ printf("%x", j++);
+ if (j > 15)
+ j = 0;
+ }
+ printf(" ");
+ }
+
printf(" %-20s %9s %9s %9s",
"task name", "wait time", "sch delay", "run time");
@@ -1797,6 +1811,9 @@ static void timehist_header(void)
*/
printf("%15s %-6s ", "", "");
+ if (sched->show_cpu_visual)
+ printf(" %*s ", ncpus, "");
+
printf(" %-20s %9s %9s %9s\n", "[tid/pid]", "(msec)", "(msec)", "(msec)");
/*
@@ -1804,6 +1821,9 @@ static void timehist_header(void)
*/
printf("%.15s %.6s ", graph_dotted_line, graph_dotted_line);
+ if (sched->show_cpu_visual)
+ printf(" %.*s ", ncpus, graph_dotted_line);
+
printf(" %.20s %.9s %.9s %.9s",
graph_dotted_line, graph_dotted_line, graph_dotted_line,
graph_dotted_line);
@@ -1817,11 +1837,28 @@ static void timehist_print_sample(struct perf_sched *sched,
struct thread *thread)
{
struct thread_runtime *tr = thread__priv(thread);
+ u32 max_cpus = sched->max_cpu + 1;
char tstr[64];
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) {
+ /* flag idle times with 'i'; others are sched events */
+ if (i == sample->cpu)
+ c = (thread->tid == 0) ? 'i' : 's';
+ else
+ c = ' ';
+ printf("%c", c);
+ }
+ printf(" ");
+ }
+
printf(" %-*s ", comm_width, timehist_get_commstr(thread));
print_sched_time(tr->dt_wait, 6);
@@ -2095,6 +2132,8 @@ static void timehist_print_wakeup_event(struct perf_sched *sched,
timestamp__scnprintf_usec(sample->time, tstr, sizeof(tstr));
printf("%15s [%04d] ", tstr, sample->cpu);
+ if (sched->show_cpu_visual)
+ printf(" %*s ", sched->max_cpu + 1, "");
printf(" %-*s ", comm_width, timehist_get_commstr(thread));
@@ -2458,7 +2497,7 @@ static int perf_sched__timehist(struct perf_sched *sched)
sched->summary = sched->summary_only;
if (!sched->summary_only)
- timehist_header();
+ timehist_header(sched);
err = perf_session__process_events(session);
if (err) {
@@ -2842,6 +2881,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('V', "cpu-visual", &sched.show_cpu_visual, "Add CPU visual"),
OPT_PARENT(sched_options)
};
--
2.10.1
[toc] | [next] | [standalone]
| From | Arnaldo Carvalho de Melo <acme@kernel.org> |
|---|---|
| Date | 2016-11-22 19:40 +0100 |
| Message-ID | <sGo93-2t5-7@gated-at.bofh.it> |
| In reply to | #1523246 |
Em Wed, Nov 16, 2016 at 03:06:33PM +0900, Namhyung Kim escreveu:
> From: David Ahern <dsahern@gmail.com>
>
> The -V option provides a visual aid for sched switches by cpu:
>
> $ perf sched timehist -V
> time cpu 0123456789abc task name b/n time sch delay run time
> [tid/pid] (msec) (msec) (msec)
> --------------- ------ ------------- -------------------- --------- --------- ---------
> ...
> 2412598.429696 [0009] i <idle> 0.000 0.000 0.000
> 2412598.429767 [0002] s perf[7219] 0.000 0.000 0.000
> 2412598.429783 [0009] s perf[7220] 0.000 0.006 0.087
> 2412598.429794 [0010] i <idle> 0.000 0.000 0.000
> 2412598.429795 [0009] s migration/9[53] 0.000 0.003 0.011
> 2412598.430370 [0010] s sleep[7220] 0.011 0.000 0.576
> 2412598.432584 [0003] i <idle> 0.000 0.000 0.000
> ...
Forgot to add docs, will do.
- Arnaldo
> Signed-off-by: David Ahern <dsahern@gmail.com>
> Signed-off-by: Namhyung Kim <namhyung@kernel.org>
> ---
> tools/perf/builtin-sched.c | 44 ++++++++++++++++++++++++++++++++++++++++++--
> 1 file changed, 42 insertions(+), 2 deletions(-)
>
> diff --git a/tools/perf/builtin-sched.c b/tools/perf/builtin-sched.c
> index 1f8731640809..829468defa07 100644
> --- a/tools/perf/builtin-sched.c
> +++ b/tools/perf/builtin-sched.c
> @@ -201,6 +201,7 @@ struct perf_sched {
> bool summary_only;
> bool show_callchain;
> unsigned int max_stack;
> + bool show_cpu_visual;
> bool show_wakeups;
> u64 skipped_samples;
> };
> @@ -1783,10 +1784,23 @@ static char *timehist_get_commstr(struct thread *thread)
> return str;
> }
>
> -static void timehist_header(void)
> +static void timehist_header(struct perf_sched *sched)
> {
> + u32 ncpus = sched->max_cpu + 1;
> + u32 i, j;
> +
> printf("%15s %6s ", "time", "cpu");
>
> + if (sched->show_cpu_visual) {
> + printf(" ");
> + for (i = 0, j = 0; i < ncpus; ++i) {
> + printf("%x", j++);
> + if (j > 15)
> + j = 0;
> + }
> + printf(" ");
> + }
> +
> printf(" %-20s %9s %9s %9s",
> "task name", "wait time", "sch delay", "run time");
>
> @@ -1797,6 +1811,9 @@ static void timehist_header(void)
> */
> printf("%15s %-6s ", "", "");
>
> + if (sched->show_cpu_visual)
> + printf(" %*s ", ncpus, "");
> +
> printf(" %-20s %9s %9s %9s\n", "[tid/pid]", "(msec)", "(msec)", "(msec)");
>
> /*
> @@ -1804,6 +1821,9 @@ static void timehist_header(void)
> */
> printf("%.15s %.6s ", graph_dotted_line, graph_dotted_line);
>
> + if (sched->show_cpu_visual)
> + printf(" %.*s ", ncpus, graph_dotted_line);
> +
> printf(" %.20s %.9s %.9s %.9s",
> graph_dotted_line, graph_dotted_line, graph_dotted_line,
> graph_dotted_line);
> @@ -1817,11 +1837,28 @@ static void timehist_print_sample(struct perf_sched *sched,
> struct thread *thread)
> {
> struct thread_runtime *tr = thread__priv(thread);
> + u32 max_cpus = sched->max_cpu + 1;
> char tstr[64];
>
> 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) {
> + /* flag idle times with 'i'; others are sched events */
> + if (i == sample->cpu)
> + c = (thread->tid == 0) ? 'i' : 's';
> + else
> + c = ' ';
> + printf("%c", c);
> + }
> + printf(" ");
> + }
> +
> printf(" %-*s ", comm_width, timehist_get_commstr(thread));
>
> print_sched_time(tr->dt_wait, 6);
> @@ -2095,6 +2132,8 @@ static void timehist_print_wakeup_event(struct perf_sched *sched,
>
> timestamp__scnprintf_usec(sample->time, tstr, sizeof(tstr));
> printf("%15s [%04d] ", tstr, sample->cpu);
> + if (sched->show_cpu_visual)
> + printf(" %*s ", sched->max_cpu + 1, "");
>
> printf(" %-*s ", comm_width, timehist_get_commstr(thread));
>
> @@ -2458,7 +2497,7 @@ static int perf_sched__timehist(struct perf_sched *sched)
> sched->summary = sched->summary_only;
>
> if (!sched->summary_only)
> - timehist_header();
> + timehist_header(sched);
>
> err = perf_session__process_events(session);
> if (err) {
> @@ -2842,6 +2881,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('V', "cpu-visual", &sched.show_cpu_visual, "Add CPU visual"),
> OPT_PARENT(sched_options)
> };
>
> --
> 2.10.1
[toc] | [prev] | [next] | [standalone]
| From | Namhyung Kim <namhyung@kernel.org> |
|---|---|
| Date | 2016-11-23 06:40 +0100 |
| Message-ID | <sGyrM-CL-7@gated-at.bofh.it> |
| In reply to | #1527838 |
On Tue, Nov 22, 2016 at 03:33:26PM -0300, Arnaldo Carvalho de Melo wrote:
> Em Wed, Nov 16, 2016 at 03:06:33PM +0900, Namhyung Kim escreveu:
> > From: David Ahern <dsahern@gmail.com>
> >
> > The -V option provides a visual aid for sched switches by cpu:
> >
> > $ perf sched timehist -V
> > time cpu 0123456789abc task name b/n time sch delay run time
> > [tid/pid] (msec) (msec) (msec)
> > --------------- ------ ------------- -------------------- --------- --------- ---------
> > ...
> > 2412598.429696 [0009] i <idle> 0.000 0.000 0.000
> > 2412598.429767 [0002] s perf[7219] 0.000 0.000 0.000
> > 2412598.429783 [0009] s perf[7220] 0.000 0.006 0.087
> > 2412598.429794 [0010] i <idle> 0.000 0.000 0.000
> > 2412598.429795 [0009] s migration/9[53] 0.000 0.003 0.011
> > 2412598.430370 [0010] s sleep[7220] 0.011 0.000 0.576
> > 2412598.432584 [0003] i <idle> 0.000 0.000 0.000
> > ...
>
> Forgot to add docs, will do.
The documentation of sched timehist command (including the -V option)
comes with the next patch (8/8).
Thanks,
Namhyung
>
> - Arnaldo
>
> > Signed-off-by: David Ahern <dsahern@gmail.com>
> > Signed-off-by: Namhyung Kim <namhyung@kernel.org>
> > ---
> > tools/perf/builtin-sched.c | 44 ++++++++++++++++++++++++++++++++++++++++++--
> > 1 file changed, 42 insertions(+), 2 deletions(-)
> >
> > diff --git a/tools/perf/builtin-sched.c b/tools/perf/builtin-sched.c
> > index 1f8731640809..829468defa07 100644
> > --- a/tools/perf/builtin-sched.c
> > +++ b/tools/perf/builtin-sched.c
> > @@ -201,6 +201,7 @@ struct perf_sched {
> > bool summary_only;
> > bool show_callchain;
> > unsigned int max_stack;
> > + bool show_cpu_visual;
> > bool show_wakeups;
> > u64 skipped_samples;
> > };
> > @@ -1783,10 +1784,23 @@ static char *timehist_get_commstr(struct thread *thread)
> > return str;
> > }
> >
> > -static void timehist_header(void)
> > +static void timehist_header(struct perf_sched *sched)
> > {
> > + u32 ncpus = sched->max_cpu + 1;
> > + u32 i, j;
> > +
> > printf("%15s %6s ", "time", "cpu");
> >
> > + if (sched->show_cpu_visual) {
> > + printf(" ");
> > + for (i = 0, j = 0; i < ncpus; ++i) {
> > + printf("%x", j++);
> > + if (j > 15)
> > + j = 0;
> > + }
> > + printf(" ");
> > + }
> > +
> > printf(" %-20s %9s %9s %9s",
> > "task name", "wait time", "sch delay", "run time");
> >
> > @@ -1797,6 +1811,9 @@ static void timehist_header(void)
> > */
> > printf("%15s %-6s ", "", "");
> >
> > + if (sched->show_cpu_visual)
> > + printf(" %*s ", ncpus, "");
> > +
> > printf(" %-20s %9s %9s %9s\n", "[tid/pid]", "(msec)", "(msec)", "(msec)");
> >
> > /*
> > @@ -1804,6 +1821,9 @@ static void timehist_header(void)
> > */
> > printf("%.15s %.6s ", graph_dotted_line, graph_dotted_line);
> >
> > + if (sched->show_cpu_visual)
> > + printf(" %.*s ", ncpus, graph_dotted_line);
> > +
> > printf(" %.20s %.9s %.9s %.9s",
> > graph_dotted_line, graph_dotted_line, graph_dotted_line,
> > graph_dotted_line);
> > @@ -1817,11 +1837,28 @@ static void timehist_print_sample(struct perf_sched *sched,
> > struct thread *thread)
> > {
> > struct thread_runtime *tr = thread__priv(thread);
> > + u32 max_cpus = sched->max_cpu + 1;
> > char tstr[64];
> >
> > 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) {
> > + /* flag idle times with 'i'; others are sched events */
> > + if (i == sample->cpu)
> > + c = (thread->tid == 0) ? 'i' : 's';
> > + else
> > + c = ' ';
> > + printf("%c", c);
> > + }
> > + printf(" ");
> > + }
> > +
> > printf(" %-*s ", comm_width, timehist_get_commstr(thread));
> >
> > print_sched_time(tr->dt_wait, 6);
> > @@ -2095,6 +2132,8 @@ static void timehist_print_wakeup_event(struct perf_sched *sched,
> >
> > timestamp__scnprintf_usec(sample->time, tstr, sizeof(tstr));
> > printf("%15s [%04d] ", tstr, sample->cpu);
> > + if (sched->show_cpu_visual)
> > + printf(" %*s ", sched->max_cpu + 1, "");
> >
> > printf(" %-*s ", comm_width, timehist_get_commstr(thread));
> >
> > @@ -2458,7 +2497,7 @@ static int perf_sched__timehist(struct perf_sched *sched)
> > sched->summary = sched->summary_only;
> >
> > if (!sched->summary_only)
> > - timehist_header();
> > + timehist_header(sched);
> >
> > err = perf_session__process_events(session);
> > if (err) {
> > @@ -2842,6 +2881,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('V', "cpu-visual", &sched.show_cpu_visual, "Add CPU visual"),
> > OPT_PARENT(sched_options)
> > };
> >
> > --
> > 2.10.1
[toc] | [prev] | [next] | [standalone]
| From | Arnaldo Carvalho de Melo <acme@kernel.org> |
|---|---|
| Date | 2016-11-23 14:40 +0100 |
| Message-ID | <sGFWi-5vy-1@gated-at.bofh.it> |
| In reply to | #1528137 |
Em Wed, Nov 23, 2016 at 02:34:40PM +0900, Namhyung Kim escreveu:
> On Tue, Nov 22, 2016 at 03:33:26PM -0300, Arnaldo Carvalho de Melo wrote:
> > Em Wed, Nov 16, 2016 at 03:06:33PM +0900, Namhyung Kim escreveu:
> > > From: David Ahern <dsahern@gmail.com>
> > >
> > > The -V option provides a visual aid for sched switches by cpu:
> > >
> > > $ perf sched timehist -V
> > > time cpu 0123456789abc task name b/n time sch delay run time
> > > [tid/pid] (msec) (msec) (msec)
> > > --------------- ------ ------------- -------------------- --------- --------- ---------
> > > ...
> > > 2412598.429696 [0009] i <idle> 0.000 0.000 0.000
> > > 2412598.429767 [0002] s perf[7219] 0.000 0.000 0.000
> > > 2412598.429783 [0009] s perf[7220] 0.000 0.006 0.087
> > > 2412598.429794 [0010] i <idle> 0.000 0.000 0.000
> > > 2412598.429795 [0009] s migration/9[53] 0.000 0.003 0.011
> > > 2412598.430370 [0010] s sleep[7220] 0.011 0.000 0.576
> > > 2412598.432584 [0003] i <idle> 0.000 0.000 0.000
> > > ...
> >
> > Forgot to add docs, will do.
>
> The documentation of sched timehist command (including the -V option)
> comes with the next patch (8/8).
I changed that to do it the preferred way, which is to add documentation
on the same changeset that introduces a new command line option.
I have it queued up, just reworking some stuff on a patch I wrote to
then send all this to Ingo, shouldn't take long,
Thanks,
- Arnaldo
> Thanks,
> Namhyung
>
>
> >
> > - Arnaldo
> >
> > > Signed-off-by: David Ahern <dsahern@gmail.com>
> > > Signed-off-by: Namhyung Kim <namhyung@kernel.org>
> > > ---
> > > tools/perf/builtin-sched.c | 44 ++++++++++++++++++++++++++++++++++++++++++--
> > > 1 file changed, 42 insertions(+), 2 deletions(-)
> > >
> > > diff --git a/tools/perf/builtin-sched.c b/tools/perf/builtin-sched.c
> > > index 1f8731640809..829468defa07 100644
> > > --- a/tools/perf/builtin-sched.c
> > > +++ b/tools/perf/builtin-sched.c
> > > @@ -201,6 +201,7 @@ struct perf_sched {
> > > bool summary_only;
> > > bool show_callchain;
> > > unsigned int max_stack;
> > > + bool show_cpu_visual;
> > > bool show_wakeups;
> > > u64 skipped_samples;
> > > };
> > > @@ -1783,10 +1784,23 @@ static char *timehist_get_commstr(struct thread *thread)
> > > return str;
> > > }
> > >
> > > -static void timehist_header(void)
> > > +static void timehist_header(struct perf_sched *sched)
> > > {
> > > + u32 ncpus = sched->max_cpu + 1;
> > > + u32 i, j;
> > > +
> > > printf("%15s %6s ", "time", "cpu");
> > >
> > > + if (sched->show_cpu_visual) {
> > > + printf(" ");
> > > + for (i = 0, j = 0; i < ncpus; ++i) {
> > > + printf("%x", j++);
> > > + if (j > 15)
> > > + j = 0;
> > > + }
> > > + printf(" ");
> > > + }
> > > +
> > > printf(" %-20s %9s %9s %9s",
> > > "task name", "wait time", "sch delay", "run time");
> > >
> > > @@ -1797,6 +1811,9 @@ static void timehist_header(void)
> > > */
> > > printf("%15s %-6s ", "", "");
> > >
> > > + if (sched->show_cpu_visual)
> > > + printf(" %*s ", ncpus, "");
> > > +
> > > printf(" %-20s %9s %9s %9s\n", "[tid/pid]", "(msec)", "(msec)", "(msec)");
> > >
> > > /*
> > > @@ -1804,6 +1821,9 @@ static void timehist_header(void)
> > > */
> > > printf("%.15s %.6s ", graph_dotted_line, graph_dotted_line);
> > >
> > > + if (sched->show_cpu_visual)
> > > + printf(" %.*s ", ncpus, graph_dotted_line);
> > > +
> > > printf(" %.20s %.9s %.9s %.9s",
> > > graph_dotted_line, graph_dotted_line, graph_dotted_line,
> > > graph_dotted_line);
> > > @@ -1817,11 +1837,28 @@ static void timehist_print_sample(struct perf_sched *sched,
> > > struct thread *thread)
> > > {
> > > struct thread_runtime *tr = thread__priv(thread);
> > > + u32 max_cpus = sched->max_cpu + 1;
> > > char tstr[64];
> > >
> > > 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) {
> > > + /* flag idle times with 'i'; others are sched events */
> > > + if (i == sample->cpu)
> > > + c = (thread->tid == 0) ? 'i' : 's';
> > > + else
> > > + c = ' ';
> > > + printf("%c", c);
> > > + }
> > > + printf(" ");
> > > + }
> > > +
> > > printf(" %-*s ", comm_width, timehist_get_commstr(thread));
> > >
> > > print_sched_time(tr->dt_wait, 6);
> > > @@ -2095,6 +2132,8 @@ static void timehist_print_wakeup_event(struct perf_sched *sched,
> > >
> > > timestamp__scnprintf_usec(sample->time, tstr, sizeof(tstr));
> > > printf("%15s [%04d] ", tstr, sample->cpu);
> > > + if (sched->show_cpu_visual)
> > > + printf(" %*s ", sched->max_cpu + 1, "");
> > >
> > > printf(" %-*s ", comm_width, timehist_get_commstr(thread));
> > >
> > > @@ -2458,7 +2497,7 @@ static int perf_sched__timehist(struct perf_sched *sched)
> > > sched->summary = sched->summary_only;
> > >
> > > if (!sched->summary_only)
> > > - timehist_header();
> > > + timehist_header(sched);
> > >
> > > err = perf_session__process_events(session);
> > > if (err) {
> > > @@ -2842,6 +2881,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('V', "cpu-visual", &sched.show_cpu_visual, "Add CPU visual"),
> > > OPT_PARENT(sched_options)
> > > };
> > >
> > > --
> > > 2.10.1
[toc] | [prev] | [next] | [standalone]
| From | tip-bot for David Ahern <tipbot@zytor.com> |
|---|---|
| Date | 2016-11-24 05:50 +0100 |
| Subject | [tip:perf/core] perf sched timehist: Add -V/--cpu-visual option |
| Message-ID | <sGU8V-62t-7@gated-at.bofh.it> |
| In reply to | #1523246 |
Commit-ID: a407b0678bc1c39d70af5fdbe6421c164b69a8c0
Gitweb: http://git.kernel.org/tip/a407b0678bc1c39d70af5fdbe6421c164b69a8c0
Author: David Ahern <dsahern@gmail.com>
AuthorDate: Wed, 16 Nov 2016 15:06:33 +0900
Committer: Arnaldo Carvalho de Melo <acme@redhat.com>
CommitDate: Wed, 23 Nov 2016 10:44:09 -0300
perf sched timehist: Add -V/--cpu-visual option
The -V option provides a visual aid for sched switches by cpu:
$ perf sched timehist -V
time cpu 0123456789abc task name b/n time sch delay run time
[tid/pid] (msec) (msec) (msec)
--------------- ------ ------------- -------------------- --------- --------- ---------
...
2412598.429696 [0009] i <idle> 0.000 0.000 0.000
2412598.429767 [0002] s perf[7219] 0.000 0.000 0.000
2412598.429783 [0009] s perf[7220] 0.000 0.006 0.087
2412598.429794 [0010] i <idle> 0.000 0.000 0.000
2412598.429795 [0009] s migration/9[53] 0.000 0.003 0.011
2412598.430370 [0010] s sleep[7220] 0.011 0.000 0.576
2412598.432584 [0003] i <idle> 0.000 0.000 0.000
...
Committer notes:
'i' marks idle time, 's' are scheduler events.
Signed-off-by: David Ahern <dsahern@gmail.com>
Signed-off-by: Namhyung Kim <namhyung@kernel.org>
Acked-by: Ingo Molnar <mingo@kernel.org>
Acked-by: Jiri Olsa <jolsa@kernel.org>
Tested-by: Arnaldo Carvalho de Melo <acme@redhat.com>
Cc: Andi Kleen <andi@firstfloor.org>
Cc: Peter Zijlstra <a.p.zijlstra@chello.nl>
Cc: Stephane Eranian <eranian@google.com>
Link: http://lkml.kernel.org/r/20161116060634.28477-8-namhyung@kernel.org
[ Add documentation based on above commit message ]
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
---
tools/perf/Documentation/perf-sched.txt | 5 ++++
tools/perf/builtin-sched.c | 44 +++++++++++++++++++++++++++++++--
2 files changed, 47 insertions(+), 2 deletions(-)
diff --git a/tools/perf/Documentation/perf-sched.txt b/tools/perf/Documentation/perf-sched.txt
index 8345208..fb9e52d 100644
--- a/tools/perf/Documentation/perf-sched.txt
+++ b/tools/perf/Documentation/perf-sched.txt
@@ -119,6 +119,11 @@ OPTIONS for 'perf sched timehist'
--symfs=<directory>::
Look for files with symbols relative to this directory.
+-V::
+--cpu-visual::
+ Show visual aid for sched switches by CPU: 'i' marks idle time,
+ 's' are scheduler events.
+
-w::
--wakeups::
Show wakeup events.
diff --git a/tools/perf/builtin-sched.c b/tools/perf/builtin-sched.c
index 1f87316..829468d 100644
--- a/tools/perf/builtin-sched.c
+++ b/tools/perf/builtin-sched.c
@@ -201,6 +201,7 @@ struct perf_sched {
bool summary_only;
bool show_callchain;
unsigned int max_stack;
+ bool show_cpu_visual;
bool show_wakeups;
u64 skipped_samples;
};
@@ -1783,10 +1784,23 @@ static char *timehist_get_commstr(struct thread *thread)
return str;
}
-static void timehist_header(void)
+static void timehist_header(struct perf_sched *sched)
{
+ u32 ncpus = sched->max_cpu + 1;
+ u32 i, j;
+
printf("%15s %6s ", "time", "cpu");
+ if (sched->show_cpu_visual) {
+ printf(" ");
+ for (i = 0, j = 0; i < ncpus; ++i) {
+ printf("%x", j++);
+ if (j > 15)
+ j = 0;
+ }
+ printf(" ");
+ }
+
printf(" %-20s %9s %9s %9s",
"task name", "wait time", "sch delay", "run time");
@@ -1797,6 +1811,9 @@ static void timehist_header(void)
*/
printf("%15s %-6s ", "", "");
+ if (sched->show_cpu_visual)
+ printf(" %*s ", ncpus, "");
+
printf(" %-20s %9s %9s %9s\n", "[tid/pid]", "(msec)", "(msec)", "(msec)");
/*
@@ -1804,6 +1821,9 @@ static void timehist_header(void)
*/
printf("%.15s %.6s ", graph_dotted_line, graph_dotted_line);
+ if (sched->show_cpu_visual)
+ printf(" %.*s ", ncpus, graph_dotted_line);
+
printf(" %.20s %.9s %.9s %.9s",
graph_dotted_line, graph_dotted_line, graph_dotted_line,
graph_dotted_line);
@@ -1817,11 +1837,28 @@ static void timehist_print_sample(struct perf_sched *sched,
struct thread *thread)
{
struct thread_runtime *tr = thread__priv(thread);
+ u32 max_cpus = sched->max_cpu + 1;
char tstr[64];
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) {
+ /* flag idle times with 'i'; others are sched events */
+ if (i == sample->cpu)
+ c = (thread->tid == 0) ? 'i' : 's';
+ else
+ c = ' ';
+ printf("%c", c);
+ }
+ printf(" ");
+ }
+
printf(" %-*s ", comm_width, timehist_get_commstr(thread));
print_sched_time(tr->dt_wait, 6);
@@ -2095,6 +2132,8 @@ static void timehist_print_wakeup_event(struct perf_sched *sched,
timestamp__scnprintf_usec(sample->time, tstr, sizeof(tstr));
printf("%15s [%04d] ", tstr, sample->cpu);
+ if (sched->show_cpu_visual)
+ printf(" %*s ", sched->max_cpu + 1, "");
printf(" %-*s ", comm_width, timehist_get_commstr(thread));
@@ -2458,7 +2497,7 @@ static int perf_sched__timehist(struct perf_sched *sched)
sched->summary = sched->summary_only;
if (!sched->summary_only)
- timehist_header();
+ timehist_header(sched);
err = perf_session__process_events(session);
if (err) {
@@ -2842,6 +2881,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('V', "cpu-visual", &sched.show_cpu_visual, "Add CPU visual"),
OPT_PARENT(sched_options)
};
[toc] | [prev] | [standalone]
Back to top | Article view | linux.kernel
csiph-web