* [PATCH 2/3] perf sched timehist: Fix invalid period calculation
2016-12-22 6:03 [PATCH 1/3] perf sched timehist: Enlarge default comm_width Namhyung Kim
@ 2016-12-22 6:03 ` Namhyung Kim
2016-12-23 19:29 ` [tip:perf/urgent] " tip-bot for Namhyung Kim
2016-12-22 6:03 ` [PATCH 3/3] perf sched timehist: Show total scheduling time Namhyung Kim
` (4 subsequent siblings)
5 siblings, 1 reply; 9+ messages in thread
From: Namhyung Kim @ 2016-12-22 6:03 UTC (permalink / raw)
To: Arnaldo Carvalho de Melo
Cc: Ingo Molnar, Peter Zijlstra, Jiri Olsa, LKML, David Ahern
When --time option is given with a value outside recorded time, the last
sample time (tprev) was set to that value and run time calculation might
be incorrect. This is a problem of the first samples for each cpus
since it would skip the runtime update when tprev is 0. But with --time
option it had non-zero (which is invalid) value so the calculation is
also incorrect.
For example, let's see the followging:
$ perf sched timehist
time cpu task name wait time sch delay run time
[tid/pid] (msec) (msec) (msec)
--------------- ------ ------------------------------ --------- --------- ---------
3195.968367 [0003] <idle> 0.000 0.000 0.000
3195.968386 [0002] Timer[4306/4277] 0.000 0.000 0.018
3195.968397 [0002] Web Content[4277] 0.000 0.000 0.000
3195.968595 [0001] JS Helper[4302/4277] 0.000 0.000 0.000
3195.969217 [0000] <idle> 0.000 0.000 0.621
3195.969251 [0001] kworker/1:1H[291] 0.000 0.000 0.033
The sample starts at 3195.968367 but when I gave a time interval from
3194 to 3196 (in sec) it will calculate the whole 2 second as runtime.
In below, 2 cpus accounted it as runtime, other 2 cpus accounted it as
idle time.
Before:
$ perf sched timehist --time 3194,3196 -s | tail
Idle stats:
CPU 0 idle for 1995.991 msec
CPU 1 idle for 20.793 msec
CPU 2 idle for 30.191 msec
CPU 3 idle for 1999.852 msec
Total number of unique tasks: 23
Total number of context switches: 128
Total run time (msec): 3724.940
After:
$ perf sched timehist --time 3194,3196 -s | tail
Idle stats:
CPU 0 idle for 10.811 msec
CPU 1 idle for 20.793 msec
CPU 2 idle for 30.191 msec
CPU 3 idle for 18.337 msec
Total number of unique tasks: 23
Total number of context switches: 128
Total run time (msec): 18.139
Cc: David Ahern <dsahern@gmail.com>
Fixes: 853b74071110 ("perf sched timehist: Add option to specify time window of interest")
Signed-off-by: Namhyung Kim <namhyung@kernel.org>
---
tools/perf/builtin-sched.c | 2 +-
1 file changed, 1 insertion(+), 1 deletion(-)
diff --git a/tools/perf/builtin-sched.c b/tools/perf/builtin-sched.c
index 5052caa91caa..d53e706a6f17 100644
--- a/tools/perf/builtin-sched.c
+++ b/tools/perf/builtin-sched.c
@@ -2405,7 +2405,7 @@ static int timehist_sched_change_event(struct perf_tool *tool,
if (ptime->start && ptime->start > t)
goto out;
- if (ptime->start > tprev)
+ if (tprev && ptime->start > tprev)
tprev = ptime->start;
/*
--
2.10.0
^ permalink raw reply related [flat|nested] 9+ messages in thread* [tip:perf/urgent] perf sched timehist: Fix invalid period calculation
2016-12-22 6:03 ` [PATCH 2/3] perf sched timehist: Fix invalid period calculation Namhyung Kim
@ 2016-12-23 19:29 ` tip-bot for Namhyung Kim
0 siblings, 0 replies; 9+ messages in thread
From: tip-bot for Namhyung Kim @ 2016-12-23 19:29 UTC (permalink / raw)
To: linux-tip-commits
Cc: linux-kernel, a.p.zijlstra, namhyung, dsahern, hpa, mingo, jolsa,
acme, tglx
Commit-ID: bdd75729e5d279d734e8d3fb41ef4818ac1598ab
Gitweb: http://git.kernel.org/tip/bdd75729e5d279d734e8d3fb41ef4818ac1598ab
Author: Namhyung Kim <namhyung@kernel.org>
AuthorDate: Thu, 22 Dec 2016 15:03:49 +0900
Committer: Arnaldo Carvalho de Melo <acme@redhat.com>
CommitDate: Thu, 22 Dec 2016 16:35:46 -0300
perf sched timehist: Fix invalid period calculation
When --time option is given with a value outside recorded time, the last
sample time (tprev) was set to that value and run time calculation might
be incorrect. This is a problem of the first samples for each cpus
since it would skip the runtime update when tprev is 0. But with --time
option it had non-zero (which is invalid) value so the calculation is
also incorrect.
For example, let's see the followging:
$ perf sched timehist
time cpu task name wait time sch delay run time
[tid/pid] (msec) (msec) (msec)
--------------- ------ ------------------------------ --------- --------- ---------
3195.968367 [0003] <idle> 0.000 0.000 0.000
3195.968386 [0002] Timer[4306/4277] 0.000 0.000 0.018
3195.968397 [0002] Web Content[4277] 0.000 0.000 0.000
3195.968595 [0001] JS Helper[4302/4277] 0.000 0.000 0.000
3195.969217 [0000] <idle> 0.000 0.000 0.621
3195.969251 [0001] kworker/1:1H[291] 0.000 0.000 0.033
The sample starts at 3195.968367 but when I gave a time interval from
3194 to 3196 (in sec) it will calculate the whole 2 second as runtime.
In below, 2 cpus accounted it as runtime, other 2 cpus accounted it as
idle time.
Before:
$ perf sched timehist --time 3194,3196 -s | tail
Idle stats:
CPU 0 idle for 1995.991 msec
CPU 1 idle for 20.793 msec
CPU 2 idle for 30.191 msec
CPU 3 idle for 1999.852 msec
Total number of unique tasks: 23
Total number of context switches: 128
Total run time (msec): 3724.940
After:
$ perf sched timehist --time 3194,3196 -s | tail
Idle stats:
CPU 0 idle for 10.811 msec
CPU 1 idle for 20.793 msec
CPU 2 idle for 30.191 msec
CPU 3 idle for 18.337 msec
Total number of unique tasks: 23
Total number of context switches: 128
Total run time (msec): 18.139
Committer notes:
Further testing:
Before:
Idle stats:
CPU 0 idle for 229.785 msec
CPU 1 idle for 937.944 msec
CPU 2 idle for 188.931 msec
CPU 3 idle for 986.185 msec
After:
# perf sched timehist --time 40602,40603 -s | tail
Idle stats:
CPU 0 idle for 229.785 msec
CPU 1 idle for 175.407 msec
CPU 2 idle for 188.931 msec
CPU 3 idle for 223.657 msec
Total number of unique tasks: 68
Total number of context switches: 814
Total run time (msec): 97.688
# for cpu in `seq 0 3` ; do echo -n "CPU $cpu idle for " ; perf sched timehist --time 40602,40603 | grep "\[000${cpu}\].*\<idle\>" | tr -s ' ' | cut -d' ' -f7 | awk '{entries++ ; s+=$1} END {print s " msec (entries: " entries ")"}' ; done
CPU 0 idle for 229.721 msec (entries: 123)
CPU 1 idle for 175.381 msec (entries: 65)
CPU 2 idle for 188.903 msec (entries: 56)
CPU 3 idle for 223.61 msec (entries: 102)
Difference due to the idle stats being accounted at nanoseconds precision while
the <idle> entries in 'perf sched timehist' are trucated at msec.usec.
Signed-off-by: Namhyung Kim <namhyung@kernel.org>
Tested-by: Arnaldo Carvalho de Melo <acme@redhat.com>
Cc: David Ahern <dsahern@gmail.com>
Cc: Jiri Olsa <jolsa@kernel.org>
Cc: Peter Zijlstra <a.p.zijlstra@chello.nl>
Fixes: 853b74071110 ("perf sched timehist: Add option to specify time window of interest")
Link: http://lkml.kernel.org/r/20161222060350.17655-2-namhyung@kernel.org
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
---
tools/perf/builtin-sched.c | 2 +-
1 file changed, 1 insertion(+), 1 deletion(-)
diff --git a/tools/perf/builtin-sched.c b/tools/perf/builtin-sched.c
index 5052caa..d53e706 100644
--- a/tools/perf/builtin-sched.c
+++ b/tools/perf/builtin-sched.c
@@ -2405,7 +2405,7 @@ static int timehist_sched_change_event(struct perf_tool *tool,
if (ptime->start && ptime->start > t)
goto out;
- if (ptime->start > tprev)
+ if (tprev && ptime->start > tprev)
tprev = ptime->start;
/*
^ permalink raw reply related [flat|nested] 9+ messages in thread
* [PATCH 3/3] perf sched timehist: Show total scheduling time
2016-12-22 6:03 [PATCH 1/3] perf sched timehist: Enlarge default comm_width Namhyung Kim
2016-12-22 6:03 ` [PATCH 2/3] perf sched timehist: Fix invalid period calculation Namhyung Kim
@ 2016-12-22 6:03 ` Namhyung Kim
2017-01-05 7:49 ` [tip:perf/urgent] " tip-bot for Namhyung Kim
2016-12-22 13:19 ` [PATCH 1/3] perf sched timehist: Enlarge default comm_width Arnaldo Carvalho de Melo
` (3 subsequent siblings)
5 siblings, 1 reply; 9+ messages in thread
From: Namhyung Kim @ 2016-12-22 6:03 UTC (permalink / raw)
To: Arnaldo Carvalho de Melo
Cc: Ingo Molnar, Peter Zijlstra, Jiri Olsa, LKML, David Ahern
Show length of analyzed sample time and rate of idle task running.
This also takes care of time range given by --time option.
$ perf sched timehist -sI | tail
Samples do not have callchains.
Idle stats:
CPU 0 idle for 930.316 msec ( 92.93%)
CPU 1 idle for 963.614 msec ( 96.25%)
CPU 2 idle for 885.482 msec ( 88.45%)
CPU 3 idle for 938.635 msec ( 93.76%)
Total number of unique tasks: 118
Total number of context switches: 2337
Total run time (msec): 3718.048
Total scheduling time (msec): 1001.131 (x 4)
Suggested-by: David Ahern <dsahern@gmail.com>
Signed-off-by: Namhyung Kim <namhyung@kernel.org>
---
tools/perf/builtin-sched.c | 17 ++++++++++++++---
1 file changed, 14 insertions(+), 3 deletions(-)
diff --git a/tools/perf/builtin-sched.c b/tools/perf/builtin-sched.c
index d53e706a6f17..5b134b0d1ff3 100644
--- a/tools/perf/builtin-sched.c
+++ b/tools/perf/builtin-sched.c
@@ -209,6 +209,7 @@ struct perf_sched {
u64 skipped_samples;
const char *time_str;
struct perf_time_interval ptime;
+ struct perf_time_interval hist_time;
};
/* per thread run time data */
@@ -2460,6 +2461,11 @@ static int timehist_sched_change_event(struct perf_tool *tool,
timehist_print_sample(sched, sample, &al, thread, t);
out:
+ if (sched->hist_time.start == 0 && t >= ptime->start)
+ sched->hist_time.start = t;
+ if (ptime->end == 0 || t <= ptime->end)
+ sched->hist_time.end = t;
+
if (tr) {
/* time of this sched_switch event becomes last time task seen */
tr->last_time = sample->time;
@@ -2624,6 +2630,7 @@ static void timehist_print_summary(struct perf_sched *sched,
struct thread *t;
struct thread_runtime *r;
int i;
+ u64 hist_time = sched->hist_time.end - sched->hist_time.start;
memset(&totals, 0, sizeof(totals));
@@ -2665,7 +2672,7 @@ static void timehist_print_summary(struct perf_sched *sched,
totals.sched_count += r->run_stats.n;
printf(" CPU %2d idle for ", i);
print_sched_time(r->total_run_time, 6);
- printf(" msec\n");
+ printf(" msec (%6.2f%%)\n", 100.0 * r->total_run_time / hist_time);
} else
printf(" CPU %2d idle entire time window\n", i);
}
@@ -2701,12 +2708,16 @@ static void timehist_print_summary(struct perf_sched *sched,
printf("\n"
" Total number of unique tasks: %" PRIu64 "\n"
- "Total number of context switches: %" PRIu64 "\n"
- " Total run time (msec): ",
+ "Total number of context switches: %" PRIu64 "\n",
totals.task_count, totals.sched_count);
+ printf(" Total run time (msec): ");
print_sched_time(totals.total_run_time, 2);
printf("\n");
+
+ printf(" Total scheduling time (msec): ");
+ print_sched_time(hist_time, 2);
+ printf(" (x %d)\n", sched->max_cpu);
}
typedef int (*sched_handler)(struct perf_tool *tool,
--
2.10.0
^ permalink raw reply related [flat|nested] 9+ messages in thread* [tip:perf/urgent] perf sched timehist: Show total scheduling time
2016-12-22 6:03 ` [PATCH 3/3] perf sched timehist: Show total scheduling time Namhyung Kim
@ 2017-01-05 7:49 ` tip-bot for Namhyung Kim
0 siblings, 0 replies; 9+ messages in thread
From: tip-bot for Namhyung Kim @ 2017-01-05 7:49 UTC (permalink / raw)
To: linux-tip-commits
Cc: dsahern, tglx, hpa, linux-kernel, namhyung, a.p.zijlstra, acme,
jolsa, mingo
Commit-ID: 9396c9cb0d9534ca67bda8a34b2413a2ca1c67e9
Gitweb: http://git.kernel.org/tip/9396c9cb0d9534ca67bda8a34b2413a2ca1c67e9
Author: Namhyung Kim <namhyung@kernel.org>
AuthorDate: Thu, 22 Dec 2016 15:03:50 +0900
Committer: Arnaldo Carvalho de Melo <acme@redhat.com>
CommitDate: Tue, 27 Dec 2016 21:47:57 -0300
perf sched timehist: Show total scheduling time
Show length of analyzed sample time and rate of idle task running.
This also takes care of time range given by --time option.
$ perf sched timehist -sI | tail
Samples do not have callchains.
Idle stats:
CPU 0 idle for 930.316 msec ( 92.93%)
CPU 1 idle for 963.614 msec ( 96.25%)
CPU 2 idle for 885.482 msec ( 88.45%)
CPU 3 idle for 938.635 msec ( 93.76%)
Total number of unique tasks: 118
Total number of context switches: 2337
Total run time (msec): 3718.048
Total scheduling time (msec): 1001.131 (x 4)
Suggested-by: David Ahern <dsahern@gmail.com>
Signed-off-by: Namhyung Kim <namhyung@kernel.org>
Cc: Jiri Olsa <jolsa@kernel.org>
Cc: Peter Zijlstra <a.p.zijlstra@chello.nl>
Link: http://lkml.kernel.org/r/20161222060350.17655-3-namhyung@kernel.org
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
---
tools/perf/builtin-sched.c | 17 ++++++++++++++---
1 file changed, 14 insertions(+), 3 deletions(-)
diff --git a/tools/perf/builtin-sched.c b/tools/perf/builtin-sched.c
index d53e706..5b134b0 100644
--- a/tools/perf/builtin-sched.c
+++ b/tools/perf/builtin-sched.c
@@ -209,6 +209,7 @@ struct perf_sched {
u64 skipped_samples;
const char *time_str;
struct perf_time_interval ptime;
+ struct perf_time_interval hist_time;
};
/* per thread run time data */
@@ -2460,6 +2461,11 @@ static int timehist_sched_change_event(struct perf_tool *tool,
timehist_print_sample(sched, sample, &al, thread, t);
out:
+ if (sched->hist_time.start == 0 && t >= ptime->start)
+ sched->hist_time.start = t;
+ if (ptime->end == 0 || t <= ptime->end)
+ sched->hist_time.end = t;
+
if (tr) {
/* time of this sched_switch event becomes last time task seen */
tr->last_time = sample->time;
@@ -2624,6 +2630,7 @@ static void timehist_print_summary(struct perf_sched *sched,
struct thread *t;
struct thread_runtime *r;
int i;
+ u64 hist_time = sched->hist_time.end - sched->hist_time.start;
memset(&totals, 0, sizeof(totals));
@@ -2665,7 +2672,7 @@ static void timehist_print_summary(struct perf_sched *sched,
totals.sched_count += r->run_stats.n;
printf(" CPU %2d idle for ", i);
print_sched_time(r->total_run_time, 6);
- printf(" msec\n");
+ printf(" msec (%6.2f%%)\n", 100.0 * r->total_run_time / hist_time);
} else
printf(" CPU %2d idle entire time window\n", i);
}
@@ -2701,12 +2708,16 @@ static void timehist_print_summary(struct perf_sched *sched,
printf("\n"
" Total number of unique tasks: %" PRIu64 "\n"
- "Total number of context switches: %" PRIu64 "\n"
- " Total run time (msec): ",
+ "Total number of context switches: %" PRIu64 "\n",
totals.task_count, totals.sched_count);
+ printf(" Total run time (msec): ");
print_sched_time(totals.total_run_time, 2);
printf("\n");
+
+ printf(" Total scheduling time (msec): ");
+ print_sched_time(hist_time, 2);
+ printf(" (x %d)\n", sched->max_cpu);
}
typedef int (*sched_handler)(struct perf_tool *tool,
^ permalink raw reply related [flat|nested] 9+ messages in thread
* Re: [PATCH 1/3] perf sched timehist: Enlarge default comm_width
2016-12-22 6:03 [PATCH 1/3] perf sched timehist: Enlarge default comm_width Namhyung Kim
2016-12-22 6:03 ` [PATCH 2/3] perf sched timehist: Fix invalid period calculation Namhyung Kim
2016-12-22 6:03 ` [PATCH 3/3] perf sched timehist: Show total scheduling time Namhyung Kim
@ 2016-12-22 13:19 ` Arnaldo Carvalho de Melo
2016-12-23 19:27 ` [tip:perf/urgent] perf sched timehist: Honour 'comm_width' when aligning the headers tip-bot for Namhyung Kim
` (2 subsequent siblings)
5 siblings, 0 replies; 9+ messages in thread
From: Arnaldo Carvalho de Melo @ 2016-12-22 13:19 UTC (permalink / raw)
To: Namhyung Kim; +Cc: Ingo Molnar, Peter Zijlstra, Jiri Olsa, LKML, David Ahern
Em Thu, Dec 22, 2016 at 03:03:48PM +0900, Namhyung Kim escreveu:
> Current default value is 20 but it's easily changed to a bigger value as
> task has a long name and different tid and pid. And it makes the output
> not aligned. So change it to have a large value as summary shows.
So you're doing multiple things here:
1) making more places honour the comm_width (header)
2) changing its default from 20 to 30 and due to this, removing the
setting to 30 done at timehist_print_summary
I'll break it into two to reflect that.
- Arnaldo
> Signed-off-by: Namhyung Kim <namhyung@kernel.org>
> ---
> tools/perf/builtin-sched.c | 12 +++++-------
> 1 file changed, 5 insertions(+), 7 deletions(-)
>
> diff --git a/tools/perf/builtin-sched.c b/tools/perf/builtin-sched.c
> index c1c07bfe132c..5052caa91caa 100644
> --- a/tools/perf/builtin-sched.c
> +++ b/tools/perf/builtin-sched.c
> @@ -1775,7 +1775,7 @@ static u64 perf_evsel__get_time(struct perf_evsel *evsel, u32 cpu)
> return r->last_time[cpu];
> }
>
> -static int comm_width = 20;
> +static int comm_width = 30;
>
> static char *timehist_get_commstr(struct thread *thread)
> {
> @@ -1817,7 +1817,7 @@ static void timehist_header(struct perf_sched *sched)
> printf(" ");
> }
>
> - printf(" %-20s %9s %9s %9s",
> + printf(" %-*s %9s %9s %9s", comm_width,
> "task name", "wait time", "sch delay", "run time");
>
> printf("\n");
> @@ -1830,7 +1830,8 @@ static void timehist_header(struct perf_sched *sched)
> if (sched->show_cpu_visual)
> printf(" %*s ", ncpus, "");
>
> - printf(" %-20s %9s %9s %9s\n", "[tid/pid]", "(msec)", "(msec)", "(msec)");
> + printf(" %-*s %9s %9s %9s\n", comm_width,
> + "[tid/pid]", "(msec)", "(msec)", "(msec)");
>
> /*
> * separator
> @@ -1840,7 +1841,7 @@ static void timehist_header(struct perf_sched *sched)
> if (sched->show_cpu_visual)
> printf(" %.*s ", ncpus, graph_dotted_line);
>
> - printf(" %.20s %.9s %.9s %.9s",
> + printf(" %.*s %.9s %.9s %.9s", comm_width,
> graph_dotted_line, graph_dotted_line, graph_dotted_line,
> graph_dotted_line);
>
> @@ -2626,9 +2627,6 @@ static void timehist_print_summary(struct perf_sched *sched,
>
> memset(&totals, 0, sizeof(totals));
>
> - if (comm_width < 30)
> - comm_width = 30;
> -
> if (sched->idle_hist) {
> printf("\nIdle-time summary\n");
> printf("%*s parent sched-out ", comm_width, "comm");
> --
> 2.10.0
^ permalink raw reply [flat|nested] 9+ messages in thread* [tip:perf/urgent] perf sched timehist: Honour 'comm_width' when aligning the headers
2016-12-22 6:03 [PATCH 1/3] perf sched timehist: Enlarge default comm_width Namhyung Kim
` (2 preceding siblings ...)
2016-12-22 13:19 ` [PATCH 1/3] perf sched timehist: Enlarge default comm_width Arnaldo Carvalho de Melo
@ 2016-12-23 19:27 ` tip-bot for Namhyung Kim
2016-12-23 19:28 ` [tip:perf/urgent] perf sched timehist: Enlarge default 'comm_width' tip-bot for Namhyung Kim
2016-12-23 19:28 ` [tip:perf/urgent] perf sched timehist: Remove hardcoded 'comm_width' check at print_summary tip-bot for Namhyung Kim
5 siblings, 0 replies; 9+ messages in thread
From: tip-bot for Namhyung Kim @ 2016-12-23 19:27 UTC (permalink / raw)
To: linux-tip-commits
Cc: tglx, dsahern, acme, a.p.zijlstra, jolsa, mingo, namhyung, hpa,
linux-kernel
Commit-ID: 0e6758e8231d5905c2e267566e9bd679a68a7b00
Gitweb: http://git.kernel.org/tip/0e6758e8231d5905c2e267566e9bd679a68a7b00
Author: Namhyung Kim <namhyung@kernel.org>
AuthorDate: Thu, 22 Dec 2016 15:03:48 +0900
Committer: Arnaldo Carvalho de Melo <acme@redhat.com>
CommitDate: Thu, 22 Dec 2016 16:35:45 -0300
perf sched timehist: Honour 'comm_width' when aligning the headers
Current default value is 20, but that may change in the future, so make
places where we have 20 hardcoded use 'comm_width'.
Signed-off-by: Namhyung Kim <namhyung@kernel.org>
Cc: David Ahern <dsahern@gmail.com>
Cc: Jiri Olsa <jolsa@kernel.org>
Cc: Peter Zijlstra <a.p.zijlstra@chello.nl>
Link: http://lkml.kernel.org/r/20161222060350.17655-1-namhyung@kernel.org
[ Split from a larger patch ]
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
---
tools/perf/builtin-sched.c | 7 ++++---
1 file changed, 4 insertions(+), 3 deletions(-)
diff --git a/tools/perf/builtin-sched.c b/tools/perf/builtin-sched.c
index c1c07bf..020f9c9 100644
--- a/tools/perf/builtin-sched.c
+++ b/tools/perf/builtin-sched.c
@@ -1817,7 +1817,7 @@ static void timehist_header(struct perf_sched *sched)
printf(" ");
}
- printf(" %-20s %9s %9s %9s",
+ printf(" %-*s %9s %9s %9s", comm_width,
"task name", "wait time", "sch delay", "run time");
printf("\n");
@@ -1830,7 +1830,8 @@ static void timehist_header(struct perf_sched *sched)
if (sched->show_cpu_visual)
printf(" %*s ", ncpus, "");
- printf(" %-20s %9s %9s %9s\n", "[tid/pid]", "(msec)", "(msec)", "(msec)");
+ printf(" %-*s %9s %9s %9s\n", comm_width,
+ "[tid/pid]", "(msec)", "(msec)", "(msec)");
/*
* separator
@@ -1840,7 +1841,7 @@ static void timehist_header(struct perf_sched *sched)
if (sched->show_cpu_visual)
printf(" %.*s ", ncpus, graph_dotted_line);
- printf(" %.20s %.9s %.9s %.9s",
+ printf(" %.*s %.9s %.9s %.9s", comm_width,
graph_dotted_line, graph_dotted_line, graph_dotted_line,
graph_dotted_line);
^ permalink raw reply related [flat|nested] 9+ messages in thread* [tip:perf/urgent] perf sched timehist: Enlarge default 'comm_width'
2016-12-22 6:03 [PATCH 1/3] perf sched timehist: Enlarge default comm_width Namhyung Kim
` (3 preceding siblings ...)
2016-12-23 19:27 ` [tip:perf/urgent] perf sched timehist: Honour 'comm_width' when aligning the headers tip-bot for Namhyung Kim
@ 2016-12-23 19:28 ` tip-bot for Namhyung Kim
2016-12-23 19:28 ` [tip:perf/urgent] perf sched timehist: Remove hardcoded 'comm_width' check at print_summary tip-bot for Namhyung Kim
5 siblings, 0 replies; 9+ messages in thread
From: tip-bot for Namhyung Kim @ 2016-12-23 19:28 UTC (permalink / raw)
To: linux-tip-commits
Cc: a.p.zijlstra, dsahern, hpa, mingo, namhyung, acme, linux-kernel,
jolsa, tglx
Commit-ID: 9b8087d72086b249ff744cee237ad12cc5e9255d
Gitweb: http://git.kernel.org/tip/9b8087d72086b249ff744cee237ad12cc5e9255d
Author: Namhyung Kim <namhyung@kernel.org>
AuthorDate: Thu, 22 Dec 2016 15:03:48 +0900
Committer: Arnaldo Carvalho de Melo <acme@redhat.com>
CommitDate: Thu, 22 Dec 2016 16:35:45 -0300
perf sched timehist: Enlarge default 'comm_width'
Current default value is 20 but it's easily changed to a bigger value as
task has a long name and different tid and pid. And it makes the output
not aligned. So change it to have a large value as summary shows.
Committer notes:
Before:
# perf sched record
^C
# perf sched timehist
<SNIP>
40602.770537 [0001] rcuos/2[29] 7.970 0.002 0.020
40602.771512 [0003] <idle> 0.003 0.000 0.986
40602.771586 [0001] <idle> 0.020 0.000 1.049
40602.771606 [0001] qemu-system-x86[3593/3510] 0.000 0.002 0.020
40602.771629 [0003] qemu-system-x86[3510] 0.000 0.003 0.116
40602.771776 [0000] <idle> 0.001 0.000 1.892
<SNIP>
After:
# perf sched timehist
<SNIP>
40602.770537 [0001] rcuos/2[29] 7.970 0.002 0.020
40602.771512 [0003] <idle> 0.003 0.000 0.986
40602.771586 [0001] <idle> 0.020 0.000 1.049
40602.771606 [0001] qemu-system-x86[3593/3510] 0.000 0.002 0.020
40602.771629 [0003] qemu-system-x86[3510] 0.000 0.003 0.116
<SNIP>
Signed-off-by: Namhyung Kim <namhyung@kernel.org>
Tested-by: Arnaldo Carvalho de Melo <acme@redhat.com>
Cc: David Ahern <dsahern@gmail.com>
Cc: Jiri Olsa <jolsa@kernel.org>
Cc: Peter Zijlstra <a.p.zijlstra@chello.nl>
Link: http://lkml.kernel.org/r/20161222060350.17655-1-namhyung@kernel.org
[ Split from a larger patch ]
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
---
tools/perf/builtin-sched.c | 2 +-
1 file changed, 1 insertion(+), 1 deletion(-)
diff --git a/tools/perf/builtin-sched.c b/tools/perf/builtin-sched.c
index 020f9c9..c65f16c 100644
--- a/tools/perf/builtin-sched.c
+++ b/tools/perf/builtin-sched.c
@@ -1775,7 +1775,7 @@ static u64 perf_evsel__get_time(struct perf_evsel *evsel, u32 cpu)
return r->last_time[cpu];
}
-static int comm_width = 20;
+static int comm_width = 30;
static char *timehist_get_commstr(struct thread *thread)
{
^ permalink raw reply related [flat|nested] 9+ messages in thread* [tip:perf/urgent] perf sched timehist: Remove hardcoded 'comm_width' check at print_summary
2016-12-22 6:03 [PATCH 1/3] perf sched timehist: Enlarge default comm_width Namhyung Kim
` (4 preceding siblings ...)
2016-12-23 19:28 ` [tip:perf/urgent] perf sched timehist: Enlarge default 'comm_width' tip-bot for Namhyung Kim
@ 2016-12-23 19:28 ` tip-bot for Namhyung Kim
5 siblings, 0 replies; 9+ messages in thread
From: tip-bot for Namhyung Kim @ 2016-12-23 19:28 UTC (permalink / raw)
To: linux-tip-commits
Cc: dsahern, mingo, acme, a.p.zijlstra, linux-kernel, namhyung, hpa,
tglx, jolsa
Commit-ID: 4fa0d1aa2711a5053fb2422331bdf6bce99b5f87
Gitweb: http://git.kernel.org/tip/4fa0d1aa2711a5053fb2422331bdf6bce99b5f87
Author: Namhyung Kim <namhyung@kernel.org>
AuthorDate: Thu, 22 Dec 2016 15:03:48 +0900
Committer: Arnaldo Carvalho de Melo <acme@redhat.com>
CommitDate: Thu, 22 Dec 2016 16:35:46 -0300
perf sched timehist: Remove hardcoded 'comm_width' check at print_summary
Now that the default 'comm_width' value is 30, no need to check that at
print_summary,
Signed-off-by: Namhyung Kim <namhyung@kernel.org>
Cc: David Ahern <dsahern@gmail.com>
Cc: Jiri Olsa <jolsa@kernel.org>
Cc: Peter Zijlstra <a.p.zijlstra@chello.nl>
Link: http://lkml.kernel.org/r/20161222060350.17655-1-namhyung@kernel.org
[ Split from a larger patch ]
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
---
tools/perf/builtin-sched.c | 3 ---
1 file changed, 3 deletions(-)
diff --git a/tools/perf/builtin-sched.c b/tools/perf/builtin-sched.c
index c65f16c..5052caa 100644
--- a/tools/perf/builtin-sched.c
+++ b/tools/perf/builtin-sched.c
@@ -2627,9 +2627,6 @@ static void timehist_print_summary(struct perf_sched *sched,
memset(&totals, 0, sizeof(totals));
- if (comm_width < 30)
- comm_width = 30;
-
if (sched->idle_hist) {
printf("\nIdle-time summary\n");
printf("%*s parent sched-out ", comm_width, "comm");
^ permalink raw reply related [flat|nested] 9+ messages in thread