Re: [BUG] perf: perf report -n shows bogus number of samples

[Stephane Eranian]

On Thu, Feb 17, 2011 at 4:23 PM, Arnaldo Carvalho de Melo
<acme@xxxxxxxxxx> wrote:
> Em Wed, Feb 09, 2011 at 12:34:44AM +0100, Stephane Eranian escreveu:
>> I think the -n option of perf report shows bogus number of samples.
>>
>> I believe it does not print the number of samples but rather the
>> number of events if I understand the code in hist_entry__snprintf().
>> I think that's useless, the number of samples is more useful.
>
> <SNIP
>
>> $ perf record -e cycles ./repmov
>> $ perf report -D | fgrep RECORD_SAMPLE | wc -l
>> 86346
>> $ ./perf report -n
>> # Events: 86K cycles
>> #
>> # Overhead ÂSamples  ÂCommand   ÂShared Object           Symbol
>> # ........ .......... Â....... Â................. Â.........................
>> #
>>   98.92%238206388334  repmov Ârepmov       [.] main
>> Â Â Â0.08% Â189506224 Â repmov Â[kernel.kallsyms] Â[k] perf_ctx_adjust_freq
>> Â Â Â0.06% Â147582706 Â repmov Â[kernel.kallsyms] Â[k] perf_event_task_tick
>>
>> It should be easy to reproduce with any other program.
>
> Like this? Can I have your acked-by?
>
Yes. Works for me.

Acked-by: Stephane Eranian <eranian@xxxxxxxxxx>

> commit 58e57f4dd6164bdbd5bc1f7d7c1ba5eb104e9b32
> Author: Arnaldo Carvalho de Melo <acme@xxxxxxxxxx>
> 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 <eranian@xxxxxxxxxx>
> Â ÂCc: Frederic Weisbecker <fweisbec@xxxxxxxxx>
> Â ÂCc: Ingo Molnar <mingo@xxxxxxx>
> Â ÂCc: Mike Galbraith <efault@xxxxxx>
> Â ÂCc: Paul Mackerras <paulus@xxxxxxxxx>
> Â ÂCc: Peter Zijlstra <peterz@xxxxxxxxxxxxx>
> Â ÂCc: Stephane Eranian <eranian@xxxxxxxxxx>
> Â ÂCc: Tom Zanussi <tzanussi@xxxxxxxxx>
> Â ÂLKML-Reference: <new-submission>
> Â ÂSigned-off-by: Arnaldo Carvalho de Melo <acme@xxxxxxxxxx>
>
> diff --git a/tools/perf/util/hist.c b/tools/perf/util/hist.c
> index 3f43723..da2899e 100644
> --- a/tools/perf/util/hist.c
> +++ b/tools/perf/util/hist.c
> @@ -591,6 +591,7 @@ int hist_entry__snprintf(struct hist_entry *self, char *s, size_t size,
> Â{
> Â Â Â Âstruct sort_entry *se;
> Â Â Â Âu64 period, total, period_sys, period_us, period_guest_sys, period_guest_us;
> + Â Â Â u64 nr_events;
> Â Â Â Âconst char *sep = symbol_conf.field_sep;
> Â Â Â Âint ret;
>
> @@ -599,6 +600,7 @@ int hist_entry__snprintf(struct hist_entry *self, char *s, size_t size,
>
> Â Â Â Âif (pair_hists) {
> Â Â Â Â Â Â Â Âperiod = self->pair ? self->pair->period : 0;
> + Â Â Â Â Â Â Â nr_events = self->pair ? self->pair->nr_events : 0;
> Â Â Â Â Â Â Â Âtotal = pair_hists->stats.total_period;
> Â Â Â Â Â Â Â Âperiod_sys = self->pair ? self->pair->period_sys : 0;
> Â Â Â Â Â Â Â Âperiod_us = self->pair ? self->pair->period_us : 0;
> @@ -606,6 +608,7 @@ int hist_entry__snprintf(struct hist_entry *self, char *s, size_t size,
> Â Â Â Â Â Â Â Âperiod_guest_us = self->pair ? self->pair->period_guest_us : 0;
> Â Â Â Â} else {
> Â Â Â Â Â Â Â Âperiod = self->period;
> + Â Â Â Â Â Â Â nr_events = self->nr_events;
> Â Â Â Â Â Â Â Âtotal = session_total;
> Â Â Â Â Â Â Â Âperiod_sys = self->period_sys;
> Â Â Â Â Â Â Â Âperiod_us = self->period_us;
> @@ -646,9 +649,9 @@ int hist_entry__snprintf(struct hist_entry *self, char *s, size_t size,
>
> Â Â Â Âif (symbol_conf.show_nr_samples) {
> Â Â Â Â Â Â Â Âif (sep)
> - Â Â Â Â Â Â Â Â Â Â Â ret += snprintf(s + ret, size - ret, "%c%" PRIu64, *sep, period);
> + Â Â Â Â Â Â Â Â Â Â Â ret += snprintf(s + ret, size - ret, "%c%" PRIu64, *sep, nr_events);
> Â Â Â Â Â Â Â Âelse
> - Â Â Â Â Â Â Â Â Â Â Â ret += snprintf(s + ret, size - ret, "%11" PRIu64, period);
> + Â Â Â Â Â Â Â Â Â Â Â ret += snprintf(s + ret, size - ret, "%11" PRIu64, nr_events);
> Â Â Â Â}
>
> Â Â Â Âif (pair_hists) {
>
--
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to majordomo@xxxxxxxxxxxxxxx
More majordomo info at  http://vger.kernel.org/majordomo-info.html
Please read the FAQ at  http://www.tux.org/lkml/