* [BUG] perf: perf report -n shows bogus number of samples
@ 2011-02-08 23:34 Stephane Eranian
2011-02-17 15:23 ` Arnaldo Carvalho de Melo
0 siblings, 1 reply; 3+ messages in thread
From: Stephane Eranian @ 2011-02-08 23:34 UTC (permalink / raw)
To: Arnaldo Carvalho de Melo
Cc: LKML, mingo, Peter Zijlstra, Frédéric Weisbecker,
perfmon2-devel
Arnaldo,
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.
$ perf report -h
usage: perf report [<options>] <command>
-i, --input <file> input file name
-v, --verbose be more verbose (show symbol address, etc)
-D, --dump-raw-trace dump raw trace in ASCII
-k, --vmlinux <file> vmlinux pathname
--kallsyms <file>
kallsyms pathname
-f, --force don't complain, do it
-m, --modules load module symbols - WARNING: use only with
-k and LIVE kernel
-n, --show-nr-samples
Show a column with the number of samples
$ 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.
^ permalink raw reply [flat|nested] 3+ messages in thread* Re: [BUG] perf: perf report -n shows bogus number of samples 2011-02-08 23:34 [BUG] perf: perf report -n shows bogus number of samples Stephane Eranian @ 2011-02-17 15:23 ` Arnaldo Carvalho de Melo 2011-02-17 18:19 ` Stephane Eranian 0 siblings, 1 reply; 3+ messages in thread From: Arnaldo Carvalho de Melo @ 2011-02-17 15:23 UTC (permalink / raw) To: Stephane Eranian Cc: LKML, mingo, Peter Zijlstra, Frédéric Weisbecker, perfmon2-devel 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? commit 58e57f4dd6164bdbd5bc1f7d7c1ba5eb104e9b32 Author: Arnaldo Carvalho de Melo <acme@redhat.com> 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@google.com> Cc: Frederic Weisbecker <fweisbec@gmail.com> Cc: Ingo Molnar <mingo@elte.hu> Cc: Mike Galbraith <efault@gmx.de> Cc: Paul Mackerras <paulus@samba.org> Cc: Peter Zijlstra <peterz@infradead.org> Cc: Stephane Eranian <eranian@google.com> Cc: Tom Zanussi <tzanussi@gmail.com> LKML-Reference: <new-submission> Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com> 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) { ^ permalink raw reply related [flat|nested] 3+ messages in thread
* Re: [BUG] perf: perf report -n shows bogus number of samples 2011-02-17 15:23 ` Arnaldo Carvalho de Melo @ 2011-02-17 18:19 ` Stephane Eranian 0 siblings, 0 replies; 3+ messages in thread From: Stephane Eranian @ 2011-02-17 18:19 UTC (permalink / raw) To: Arnaldo Carvalho de Melo Cc: LKML, mingo, Peter Zijlstra, Frédéric Weisbecker, perfmon2-devel On Thu, Feb 17, 2011 at 4:23 PM, Arnaldo Carvalho de Melo <acme@redhat.com> 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@google.com> > commit 58e57f4dd6164bdbd5bc1f7d7c1ba5eb104e9b32 > Author: Arnaldo Carvalho de Melo <acme@redhat.com> > 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@google.com> > Cc: Frederic Weisbecker <fweisbec@gmail.com> > Cc: Ingo Molnar <mingo@elte.hu> > Cc: Mike Galbraith <efault@gmx.de> > Cc: Paul Mackerras <paulus@samba.org> > Cc: Peter Zijlstra <peterz@infradead.org> > Cc: Stephane Eranian <eranian@google.com> > Cc: Tom Zanussi <tzanussi@gmail.com> > LKML-Reference: <new-submission> > Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com> > > 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) { > ^ permalink raw reply [flat|nested] 3+ messages in thread
end of thread, other threads:[~2011-02-17 18:19 UTC | newest] Thread overview: 3+ messages (download: mbox.gz follow: Atom feed -- links below jump to the message on this page -- 2011-02-08 23:34 [BUG] perf: perf report -n shows bogus number of samples Stephane Eranian 2011-02-17 15:23 ` Arnaldo Carvalho de Melo 2011-02-17 18:19 ` Stephane Eranian
This is a public inbox, see mirroring instructions for how to clone and mirror all data and code used for this inbox