2019-08-23 23:38:31

by Andi Kleen

[permalink] [raw]
Subject: [PATCH 1/2] perf report: Use timestamp__scnprintf_nsec for time sort key

From: Andi Kleen <[email protected]>

Use timestamp__scnprintf_nsec to print nanoseconds for the time
sort key, instead of open coding.

Signed-off-by: Andi Kleen <[email protected]>
---
tools/perf/util/sort.c | 10 ++--------
1 file changed, 2 insertions(+), 8 deletions(-)

diff --git a/tools/perf/util/sort.c b/tools/perf/util/sort.c
index f9a38a1dd4d1..0985e9072db0 100644
--- a/tools/perf/util/sort.c
+++ b/tools/perf/util/sort.c
@@ -668,17 +668,11 @@ sort__time_cmp(struct hist_entry *left, struct hist_entry *right)
static int hist_entry__time_snprintf(struct hist_entry *he, char *bf,
size_t size, unsigned int width)
{
- unsigned long secs;
- unsigned long long nsecs;
char he_time[32];

- nsecs = he->time;
- secs = nsecs / NSEC_PER_SEC;
- nsecs -= secs * NSEC_PER_SEC;
-
if (symbol_conf.nanosecs)
- snprintf(he_time, sizeof he_time, "%5lu.%09llu: ",
- secs, nsecs);
+ timestamp__scnprintf_nsec(he->time, he_time,
+ sizeof(he_time));
else
timestamp__scnprintf_usec(he->time, he_time,
sizeof(he_time));
--
2.20.1


2019-08-23 23:39:42

by Andi Kleen

[permalink] [raw]
Subject: [PATCH 2/2] perf report: Fix --ns time sort key output

From: Andi Kleen <[email protected]>

If the user specified --ns, the column to print the sort time stamp
wasn't wide enough to actually print the full nanoseconds.

Widen the time key column width when --ns is specified.

Before:

% perf record -a sleep 1
% perf report --sort time,overhead,symbol --stdio --ns
...
2.39% 187851.10000 [k] smp_call_function_single - -
1.53% 187851.10000 [k] intel_idle - -
0.59% 187851.10000 [.] __wcscmp_ifunc - -
0.33% 187851.10000 [.] 0000000000000000 - -
0.28% 187851.10000 [k] cpuidle_enter_state - -

After:

% perf report --sort time,overhead,symbol --stdio --ns
...
2.39% 187851.100000000 [k] smp_call_function_single - -
1.53% 187851.100000000 [k] intel_idle - -
0.59% 187851.100000000 [.] __wcscmp_ifunc - -
0.33% 187851.100000000 [.] 0000000000000000 - -
0.28% 187851.100000000 [k] cpuidle_enter_state - -

Signed-off-by: Andi Kleen <[email protected]>
---
tools/perf/util/hist.c | 5 ++++-
1 file changed, 4 insertions(+), 1 deletion(-)

diff --git a/tools/perf/util/hist.c b/tools/perf/util/hist.c
index 8efbf58dc3d0..33702675073c 100644
--- a/tools/perf/util/hist.c
+++ b/tools/perf/util/hist.c
@@ -193,7 +193,10 @@ void hists__calc_col_len(struct hists *hists, struct hist_entry *h)
hists__new_col_len(hists, HISTC_MEM_LVL, 21 + 3);
hists__new_col_len(hists, HISTC_LOCAL_WEIGHT, 12);
hists__new_col_len(hists, HISTC_GLOBAL_WEIGHT, 12);
- hists__new_col_len(hists, HISTC_TIME, 12);
+ if (symbol_conf.nanosecs)
+ hists__new_col_len(hists, HISTC_TIME, 16);
+ else
+ hists__new_col_len(hists, HISTC_TIME, 12);

if (h->srcline) {
len = MAX(strlen(h->srcline), strlen(sort_srcline.se_header));
--
2.20.1

2019-08-25 14:32:25

by Arnaldo Carvalho de Melo

[permalink] [raw]
Subject: Re: [PATCH 1/2] perf report: Use timestamp__scnprintf_nsec for time sort key

Em Fri, Aug 23, 2019 at 02:03:37PM -0700, Andi Kleen escreveu:
> From: Andi Kleen <[email protected]>
>
> Use timestamp__scnprintf_nsec to print nanoseconds for the time
> sort key, instead of open coding.

Thanks, tested and applied.

- Arnaldo

> Signed-off-by: Andi Kleen <[email protected]>
> ---
> tools/perf/util/sort.c | 10 ++--------
> 1 file changed, 2 insertions(+), 8 deletions(-)
>
> diff --git a/tools/perf/util/sort.c b/tools/perf/util/sort.c
> index f9a38a1dd4d1..0985e9072db0 100644
> --- a/tools/perf/util/sort.c
> +++ b/tools/perf/util/sort.c
> @@ -668,17 +668,11 @@ sort__time_cmp(struct hist_entry *left, struct hist_entry *right)
> static int hist_entry__time_snprintf(struct hist_entry *he, char *bf,
> size_t size, unsigned int width)
> {
> - unsigned long secs;
> - unsigned long long nsecs;
> char he_time[32];
>
> - nsecs = he->time;
> - secs = nsecs / NSEC_PER_SEC;
> - nsecs -= secs * NSEC_PER_SEC;
> -
> if (symbol_conf.nanosecs)
> - snprintf(he_time, sizeof he_time, "%5lu.%09llu: ",
> - secs, nsecs);
> + timestamp__scnprintf_nsec(he->time, he_time,
> + sizeof(he_time));
> else
> timestamp__scnprintf_usec(he->time, he_time,
> sizeof(he_time));
> --
> 2.20.1

--

- Arnaldo

Subject: [tip: perf/core] perf report: Fix --ns time sort key output

The following commit has been merged into the perf/core branch of tip:

Commit-ID: 3dab6ac080dcd7f71cb9ceb84ad7dafecd6f7c07
Gitweb: https://git.kernel.org/tip/3dab6ac080dcd7f71cb9ceb84ad7dafecd6f7c07
Author: Andi Kleen <[email protected]>
AuthorDate: Fri, 23 Aug 2019 14:03:38 -07:00
Committer: Arnaldo Carvalho de Melo <[email protected]>
CommitterDate: Mon, 26 Aug 2019 11:58:29 -03:00

perf report: Fix --ns time sort key output

If the user specified --ns, the column to print the sort time stamp
wasn't wide enough to actually print the full nanoseconds.

Widen the time key column width when --ns is specified.

Before:

% perf record -a sleep 1
% perf report --sort time,overhead,symbol --stdio --ns
...
2.39% 187851.10000 [k] smp_call_function_single - -
1.53% 187851.10000 [k] intel_idle - -
0.59% 187851.10000 [.] __wcscmp_ifunc - -
0.33% 187851.10000 [.] 0000000000000000 - -
0.28% 187851.10000 [k] cpuidle_enter_state - -

After:

% perf report --sort time,overhead,symbol --stdio --ns
...
2.39% 187851.100000000 [k] smp_call_function_single - -
1.53% 187851.100000000 [k] intel_idle - -
0.59% 187851.100000000 [.] __wcscmp_ifunc - -
0.33% 187851.100000000 [.] 0000000000000000 - -
0.28% 187851.100000000 [k] cpuidle_enter_state - -

Signed-off-by: Andi Kleen <[email protected]>
Tested-by: Arnaldo Carvalho de Melo <[email protected]>
Cc: Jiri Olsa <[email protected]>
Link: http://lkml.kernel.org/r/[email protected]
Signed-off-by: Arnaldo Carvalho de Melo <[email protected]>
---
tools/perf/util/hist.c | 5 ++++-
1 file changed, 4 insertions(+), 1 deletion(-)

diff --git a/tools/perf/util/hist.c b/tools/perf/util/hist.c
index 8efbf58..3370267 100644
--- a/tools/perf/util/hist.c
+++ b/tools/perf/util/hist.c
@@ -193,7 +193,10 @@ void hists__calc_col_len(struct hists *hists, struct hist_entry *h)
hists__new_col_len(hists, HISTC_MEM_LVL, 21 + 3);
hists__new_col_len(hists, HISTC_LOCAL_WEIGHT, 12);
hists__new_col_len(hists, HISTC_GLOBAL_WEIGHT, 12);
- hists__new_col_len(hists, HISTC_TIME, 12);
+ if (symbol_conf.nanosecs)
+ hists__new_col_len(hists, HISTC_TIME, 16);
+ else
+ hists__new_col_len(hists, HISTC_TIME, 12);

if (h->srcline) {
len = MAX(strlen(h->srcline), strlen(sort_srcline.se_header));

Subject: [tip: perf/core] perf report: Use timestamp__scnprintf_nsec() for time sort key

The following commit has been merged into the perf/core branch of tip:

Commit-ID: 092804ae092fc6097348f5c09b62cde040717aa1
Gitweb: https://git.kernel.org/tip/092804ae092fc6097348f5c09b62cde040717aa1
Author: Andi Kleen <[email protected]>
AuthorDate: Fri, 23 Aug 2019 14:03:37 -07:00
Committer: Arnaldo Carvalho de Melo <[email protected]>
CommitterDate: Mon, 26 Aug 2019 11:58:29 -03:00

perf report: Use timestamp__scnprintf_nsec() for time sort key

Use timestamp__scnprintf_nsec() to print nanoseconds for the time sort
key, instead of open coding.

Signed-off-by: Andi Kleen <[email protected]>
Cc: Jiri Olsa <[email protected]>
Link: http://lkml.kernel.org/r/[email protected]
Signed-off-by: Arnaldo Carvalho de Melo <[email protected]>
---
tools/perf/util/sort.c | 10 ++--------
1 file changed, 2 insertions(+), 8 deletions(-)

diff --git a/tools/perf/util/sort.c b/tools/perf/util/sort.c
index c522bdd..83eb3fa 100644
--- a/tools/perf/util/sort.c
+++ b/tools/perf/util/sort.c
@@ -670,17 +670,11 @@ sort__time_cmp(struct hist_entry *left, struct hist_entry *right)
static int hist_entry__time_snprintf(struct hist_entry *he, char *bf,
size_t size, unsigned int width)
{
- unsigned long secs;
- unsigned long long nsecs;
char he_time[32];

- nsecs = he->time;
- secs = nsecs / NSEC_PER_SEC;
- nsecs -= secs * NSEC_PER_SEC;
-
if (symbol_conf.nanosecs)
- snprintf(he_time, sizeof he_time, "%5lu.%09llu: ",
- secs, nsecs);
+ timestamp__scnprintf_nsec(he->time, he_time,
+ sizeof(he_time));
else
timestamp__scnprintf_usec(he->time, he_time,
sizeof(he_time));