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

[Arnaldo Carvalho de Melo]

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@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/