2011-02-25 00:14:43

by Cliff Wickman

[permalink] [raw]
Subject: [RFC] Performance Events 'Samples' report

From: Cliff Wickman <[email protected]>

The perf command's report prints clock periods under the heading of 'Samples'.
Our applications people have been confused by this "Samples" heading.

perf report -n

# Overhead Samples Command Shared Object Symbol
# ........ .......... ............... .................... ................................
#
99.41%1522136216246 pthreads pthreads [.] work_function
0.33% 4980298302 perf [kernel.kallsyms] [k] clear_page_c
....

It would be more compact to print the number of samples. And that would
be consistent with the heading.

Below is the code that displays the periods. I don't see that the number
of samples is available here, but probably easily could be.
I presume that clock periods are derived from #samples * sample period.

perf/util/hist.c

640
641 if (symbol_conf.show_nr_samples) {
642 if (sep)
643 ret += snprintf(s + ret, size - ret, "%c%" PRIu64, *sep, period);
644 else
645 ret += snprintf(s + ret, size - ret, "%11" PRIu64, period);
646 }
647

Signed-off-by: Cliff Wickman <[email protected]>


2011-02-25 02:40:22

by Arnaldo Carvalho de Melo

[permalink] [raw]
Subject: Re: [RFC] Performance Events 'Samples' report

Em Thu, Feb 24, 2011 at 06:15:26PM -0600, Cliff Wickman escreveu:
> From: Cliff Wickman <[email protected]>
>
> The perf command's report prints clock periods under the heading of 'Samples'.
> Our applications people have been confused by this "Samples" heading.
>
> perf report -n
>
> # Overhead Samples Command Shared Object Symbol
> # ........ .......... ............... .................... ................................
> #
> 99.41%1522136216246 pthreads pthreads [.] work_function
> 0.33% 4980298302 perf [kernel.kallsyms] [k] clear_page_c
> ....
>
> It would be more compact to print the number of samples. And that would
> be consistent with the heading.
>
> Below is the code that displays the periods. I don't see that the number
> of samples is available here, but probably easily could be.
> I presume that clock periods are derived from #samples * sample period.
>
> perf/util/hist.c
>
> 640
> 641 if (symbol_conf.show_nr_samples) {
> 642 if (sep)
> 643 ret += snprintf(s + ret, size - ret, "%c%" PRIu64, *sep, period);
> 644 else
> 645 ret += snprintf(s + ret, size - ret, "%11" PRIu64, period);
> 646 }
> 647

Wasn't this fixed by:

commit fec9cbd15b9e99bab9bc50f1ed7e20a1087d7c6d
Author: Arnaldo Carvalho de Melo <[email protected]>
Date: Thu Feb 17 10:37:23 2011 -0200

perf hists: Print number of samples, not the period sum

So that we match the header where we state the number of events with the
"Samples" column when using 'perf report -n/--show-nr-samples':

[root@emilia ~]# perf record -a sleep 1
[ perf record: Woken up 1 times to write data ]
[ perf record: Captured and wrote 0.111 MB perf.data (~4860 samples) ]
[root@emilia ~]# perf report --stdio --show-nr-samples
# Events: 11 cycles
#
# Overhead Samples Command Shared Object Symbol
# ........ .......... ........... .................. ............................
#
16.65% 1 sleep [kernel.kallsyms] [k] unmap_vmas
16.10% 1 perf libpthread-2.12.so [.] __pthread_cleanup_push_defer
15.79% 2 perf [kernel.kallsyms] [k] format_decode
12.88% 1 kworker/1:2 [kernel.kallsyms] [k] cache_reap
10.69% 1 swapper [kernel.kallsyms] [k] _raw_spin_lock
7.55% 1 sleep [kernel.kallsyms] [k] prepare_exec_creds
6.00% 1 perf [jbd2] [k] start_this_handle
5.29% 1 perf [kernel.kallsyms] [k] seq_read
4.75% 1 perf [kernel.kallsyms] [k] get_pid_task
4.30% 1 perf [kernel.kallsyms] [k] _raw_spin_unlock_irqrestore

#
# (For a higher level overview, try: perf report --sort comm,dso)
#
[root@emilia ~]#

Reported-by: Stephane Eranian <[email protected]>
Acked-by: Stephane Eranian <[email protected]>
Cc: Frederic Weisbecker <[email protected]>
Cc: Ingo Molnar <[email protected]>
Cc: Mike Galbraith <[email protected]>
Cc: Paul Mackerras <[email protected]>
Cc: Peter Zijlstra <[email protected]>
Cc: Stephane Eranian <[email protected]>
Cc: Tom Zanussi <[email protected]>
LKML-Reference: <new-submission>
Signed-off-by: Arnaldo Carvalho de Melo <[email protected]>

?

Please try using tip/perf/core.

- Arnaldo

2011-02-25 10:26:58

by Ingo Molnar

[permalink] [raw]
Subject: Re: [RFC] Performance Events 'Samples' report


* Arnaldo Carvalho de Melo <[email protected]> wrote:

> Wasn't this fixed by:
>
> commit fec9cbd15b9e99bab9bc50f1ed7e20a1087d7c6d
> Author: Arnaldo Carvalho de Melo <[email protected]>
> Date: Thu Feb 17 10:37:23 2011 -0200
>
> perf hists: Print number of samples, not the period sum

Yeah. I'll cherry-pick it over into perf/urgent, ok? It's been reported by several
people (I noticed it too) and the old numbers really made little sense - and the fix
is really simple.

Thanks,

Ingo