linux-kernel.vger.kernel.org archive mirror
 help / color / mirror / Atom feed
* perf stat stddev reporting broken since "perf stat: Introduce read_counters function"
@ 2016-01-18 17:59 Mel Gorman
  2016-01-19  7:42 ` Jiri Olsa
  0 siblings, 1 reply; 5+ messages in thread
From: Mel Gorman @ 2016-01-18 17:59 UTC (permalink / raw)
  To: Jiri Olsa; +Cc: Arnaldo Carvalho de Melo, LKML

I noticed that perf stat in 4.4 is not printing stddev figures as
expected and bisected it to commit 106a94a0f8c2 ("perf stat: Introduce
read_counters function").

# Kernel 4.4
# make clean && make prefix=/usr && ./perf stat -r 5 sleep 1
 Performance counter stats for 'sleep 1' (5 runs):

          0.466683      task-clock (msec)         #    0.000 CPUs utilized
                 1      context-switches          #    0.002 M/sec
                 1      cpu-migrations            #    0.002 M/sec
                66      page-faults               #    0.144 M/sec
         1,630,220      cycles                    #    3.562 GHz
   <not supported>      stalled-cycles-frontend
   <not supported>      stalled-cycles-backend
           902,686      instructions              #    0.66  insns per cycle
           185,692      branches                  #  405.786 M/sec
             8,640      branch-misses             #    4.63% of all branches

       1.000855883 seconds time elapsed           ( +-  0.01% )

# git checkout 106a94a0f8c207ef4113ce7e32f34a00b3b174e7^
 Performance counter stats for 'sleep 1' (5 runs):

          0.397939      task-clock (msec)         #    0.000 CPUs utilized            ( +-  3.37% )
                 1      context-switches          #    0.003 M/sec
                 0      cpu-migrations            #    0.000 K/sec
                67      page-faults               #    0.169 M/sec                    ( +-  0.56% )
         1,360,763      cycles                    #    3.420 GHz                      ( +-  2.14% )
   <not supported>      stalled-cycles-frontend
   <not supported>      stalled-cycles-backend
           903,901      instructions              #    0.66  insns per cycle          ( +-  0.24% )
           186,472      branches                  #  468.595 M/sec                    ( +-  0.29% )
             8,599      branch-misses             #    4.61% of all branches          ( +-  0.77% )

       1.000761882 seconds time elapsed                                               ( +-  0.00% )

# git checkout 106a94a0f8c207ef4113ce7e32f34a00b3b174e7

 Performance counter stats for 'sleep 1' (5 runs):

          0.583178      task-clock (msec)         #    0.001 CPUs utilized
                 1      context-switches          #    0.002 M/sec
                 0      cpu-migrations            #    0.000 K/sec
                67      page-faults               #    0.141 M/sec
         1,224,416      cycles                    #    2.585 GHz
   <not supported>      stalled-cycles-frontend
   <not supported>      stalled-cycles-backend
           892,568      instructions              #    0.68  insns per cycle
           184,975      branches                  #  390.554 M/sec
             8,512      branch-misses             #    4.57% of all branches

       1.000889249 seconds time elapsed                                          ( +-  0.01% )

I checked and current master in Linus' tree is also broken. Is this
change in documented perf stat behaviour intentional?

-- 
Mel Gorman
SUSE Labs

^ permalink raw reply	[flat|nested] 5+ messages in thread

* Re: perf stat stddev reporting broken since "perf stat: Introduce read_counters function"
  2016-01-18 17:59 perf stat stddev reporting broken since "perf stat: Introduce read_counters function" Mel Gorman
@ 2016-01-19  7:42 ` Jiri Olsa
  2016-01-19  8:16   ` Jiri Olsa
  0 siblings, 1 reply; 5+ messages in thread
From: Jiri Olsa @ 2016-01-19  7:42 UTC (permalink / raw)
  To: Mel Gorman; +Cc: Jiri Olsa, Arnaldo Carvalho de Melo, LKML

On Mon, Jan 18, 2016 at 05:59:46PM +0000, Mel Gorman wrote:
> I noticed that perf stat in 4.4 is not printing stddev figures as
> expected and bisected it to commit 106a94a0f8c2 ("perf stat: Introduce
> read_counters function").
> 
> # Kernel 4.4
> # make clean && make prefix=/usr && ./perf stat -r 5 sleep 1
>  Performance counter stats for 'sleep 1' (5 runs):
> 
>           0.466683      task-clock (msec)         #    0.000 CPUs utilized
>                  1      context-switches          #    0.002 M/sec
>                  1      cpu-migrations            #    0.002 M/sec
>                 66      page-faults               #    0.144 M/sec
>          1,630,220      cycles                    #    3.562 GHz
>    <not supported>      stalled-cycles-frontend
>    <not supported>      stalled-cycles-backend
>            902,686      instructions              #    0.66  insns per cycle
>            185,692      branches                  #  405.786 M/sec
>              8,640      branch-misses             #    4.63% of all branches
> 
>        1.000855883 seconds time elapsed           ( +-  0.01% )
> 
> # git checkout 106a94a0f8c207ef4113ce7e32f34a00b3b174e7^
>  Performance counter stats for 'sleep 1' (5 runs):
> 
>           0.397939      task-clock (msec)         #    0.000 CPUs utilized            ( +-  3.37% )
>                  1      context-switches          #    0.003 M/sec
>                  0      cpu-migrations            #    0.000 K/sec
>                 67      page-faults               #    0.169 M/sec                    ( +-  0.56% )
>          1,360,763      cycles                    #    3.420 GHz                      ( +-  2.14% )
>    <not supported>      stalled-cycles-frontend
>    <not supported>      stalled-cycles-backend
>            903,901      instructions              #    0.66  insns per cycle          ( +-  0.24% )
>            186,472      branches                  #  468.595 M/sec                    ( +-  0.29% )
>              8,599      branch-misses             #    4.61% of all branches          ( +-  0.77% )
> 
>        1.000761882 seconds time elapsed                                               ( +-  0.00% )
> 
> # git checkout 106a94a0f8c207ef4113ce7e32f34a00b3b174e7
> 
>  Performance counter stats for 'sleep 1' (5 runs):
> 
>           0.583178      task-clock (msec)         #    0.001 CPUs utilized
>                  1      context-switches          #    0.002 M/sec
>                  0      cpu-migrations            #    0.000 K/sec
>                 67      page-faults               #    0.141 M/sec
>          1,224,416      cycles                    #    2.585 GHz
>    <not supported>      stalled-cycles-frontend
>    <not supported>      stalled-cycles-backend
>            892,568      instructions              #    0.68  insns per cycle
>            184,975      branches                  #  390.554 M/sec
>              8,512      branch-misses             #    4.57% of all branches
> 
>        1.000889249 seconds time elapsed                                          ( +-  0.01% )
> 
> I checked and current master in Linus' tree is also broken. Is this
> change in documented perf stat behaviour intentional?

nope, not intentional.. I'll check on that, thanks for reporting

jirka

^ permalink raw reply	[flat|nested] 5+ messages in thread

* Re: perf stat stddev reporting broken since "perf stat: Introduce read_counters function"
  2016-01-19  7:42 ` Jiri Olsa
@ 2016-01-19  8:16   ` Jiri Olsa
  2016-01-19  9:38     ` Mel Gorman
  0 siblings, 1 reply; 5+ messages in thread
From: Jiri Olsa @ 2016-01-19  8:16 UTC (permalink / raw)
  To: Mel Gorman; +Cc: Jiri Olsa, Arnaldo Carvalho de Melo, LKML

On Tue, Jan 19, 2016 at 08:42:28AM +0100, Jiri Olsa wrote:

SNIP

> > 
> >  Performance counter stats for 'sleep 1' (5 runs):
> > 
> >           0.583178      task-clock (msec)         #    0.001 CPUs utilized
> >                  1      context-switches          #    0.002 M/sec
> >                  0      cpu-migrations            #    0.000 K/sec
> >                 67      page-faults               #    0.141 M/sec
> >          1,224,416      cycles                    #    2.585 GHz
> >    <not supported>      stalled-cycles-frontend
> >    <not supported>      stalled-cycles-backend
> >            892,568      instructions              #    0.68  insns per cycle
> >            184,975      branches                  #  390.554 M/sec
> >              8,512      branch-misses             #    4.57% of all branches
> > 
> >        1.000889249 seconds time elapsed                                          ( +-  0.01% )
> > 
> > I checked and current master in Linus' tree is also broken. Is this
> > change in documented perf stat behaviour intentional?
> 
> nope, not intentional.. I'll check on that, thanks for reporting

for some reason we initialized the stat every iteration,
(the call is also wrong because it's called only over the
first res_stats[0])

attached patch works for me, could you please test?
I'll run more tests and put it in my queue

thanks,
jirka


---
diff --git a/tools/perf/util/stat.c b/tools/perf/util/stat.c
index 2f901d15e063..2b58edccd56f 100644
--- a/tools/perf/util/stat.c
+++ b/tools/perf/util/stat.c
@@ -310,7 +310,6 @@ int perf_stat_process_counter(struct perf_stat_config *config,
 	int i, ret;
 
 	aggr->val = aggr->ena = aggr->run = 0;
-	init_stats(ps->res_stats);
 
 	if (counter->per_pkg)
 		zero_per_pkg(counter);

^ permalink raw reply related	[flat|nested] 5+ messages in thread

* Re: perf stat stddev reporting broken since "perf stat: Introduce read_counters function"
  2016-01-19  8:16   ` Jiri Olsa
@ 2016-01-19  9:38     ` Mel Gorman
  2016-01-19  9:57       ` Jiri Olsa
  0 siblings, 1 reply; 5+ messages in thread
From: Mel Gorman @ 2016-01-19  9:38 UTC (permalink / raw)
  To: Jiri Olsa; +Cc: Jiri Olsa, Arnaldo Carvalho de Melo, LKML

On Tue, Jan 19, 2016 at 09:16:23AM +0100, Jiri Olsa wrote:
> On Tue, Jan 19, 2016 at 08:42:28AM +0100, Jiri Olsa wrote:
> 
> SNIP
> 
> > > 
> > >  Performance counter stats for 'sleep 1' (5 runs):
> > > 
> > >           0.583178      task-clock (msec)         #    0.001 CPUs utilized
> > >                  1      context-switches          #    0.002 M/sec
> > >                  0      cpu-migrations            #    0.000 K/sec
> > >                 67      page-faults               #    0.141 M/sec
> > >          1,224,416      cycles                    #    2.585 GHz
> > >    <not supported>      stalled-cycles-frontend
> > >    <not supported>      stalled-cycles-backend
> > >            892,568      instructions              #    0.68  insns per cycle
> > >            184,975      branches                  #  390.554 M/sec
> > >              8,512      branch-misses             #    4.57% of all branches
> > > 
> > >        1.000889249 seconds time elapsed                                          ( +-  0.01% )
> > > 
> > > I checked and current master in Linus' tree is also broken. Is this
> > > change in documented perf stat behaviour intentional?
> > 
> > nope, not intentional.. I'll check on that, thanks for reporting
> 
> for some reason we initialized the stat every iteration,
> (the call is also wrong because it's called only over the
> first res_stats[0])
> 
> attached patch works for me, could you please test?
> I'll run more tests and put it in my queue
> 

That works for me too, thanks. Feel free to put this on the patch;

Tested-by: Mel Gorman <mgorman@techsingularity.net>

When you send it through, can you make sure it has the following please?

Cc: stable@vger.kernel.org # v4.2+

-- 
Mel Gorman
SUSE Labs

^ permalink raw reply	[flat|nested] 5+ messages in thread

* Re: perf stat stddev reporting broken since "perf stat: Introduce read_counters function"
  2016-01-19  9:38     ` Mel Gorman
@ 2016-01-19  9:57       ` Jiri Olsa
  0 siblings, 0 replies; 5+ messages in thread
From: Jiri Olsa @ 2016-01-19  9:57 UTC (permalink / raw)
  To: Mel Gorman; +Cc: Jiri Olsa, Arnaldo Carvalho de Melo, LKML

On Tue, Jan 19, 2016 at 09:38:12AM +0000, Mel Gorman wrote:
> On Tue, Jan 19, 2016 at 09:16:23AM +0100, Jiri Olsa wrote:
> > On Tue, Jan 19, 2016 at 08:42:28AM +0100, Jiri Olsa wrote:
> > 
> > SNIP
> > 
> > > > 
> > > >  Performance counter stats for 'sleep 1' (5 runs):
> > > > 
> > > >           0.583178      task-clock (msec)         #    0.001 CPUs utilized
> > > >                  1      context-switches          #    0.002 M/sec
> > > >                  0      cpu-migrations            #    0.000 K/sec
> > > >                 67      page-faults               #    0.141 M/sec
> > > >          1,224,416      cycles                    #    2.585 GHz
> > > >    <not supported>      stalled-cycles-frontend
> > > >    <not supported>      stalled-cycles-backend
> > > >            892,568      instructions              #    0.68  insns per cycle
> > > >            184,975      branches                  #  390.554 M/sec
> > > >              8,512      branch-misses             #    4.57% of all branches
> > > > 
> > > >        1.000889249 seconds time elapsed                                          ( +-  0.01% )
> > > > 
> > > > I checked and current master in Linus' tree is also broken. Is this
> > > > change in documented perf stat behaviour intentional?
> > > 
> > > nope, not intentional.. I'll check on that, thanks for reporting
> > 
> > for some reason we initialized the stat every iteration,
> > (the call is also wrong because it's called only over the
> > first res_stats[0])
> > 
> > attached patch works for me, could you please test?
> > I'll run more tests and put it in my queue
> > 
> 
> That works for me too, thanks. Feel free to put this on the patch;
> 
> Tested-by: Mel Gorman <mgorman@techsingularity.net>
> 
> When you send it through, can you make sure it has the following please?
> 
> Cc: stable@vger.kernel.org # v4.2+

will do, thanks

jirka

^ permalink raw reply	[flat|nested] 5+ messages in thread

end of thread, other threads:[~2016-01-19  9:57 UTC | newest]

Thread overview: 5+ messages (download: mbox.gz follow: Atom feed
-- links below jump to the message on this page --
2016-01-18 17:59 perf stat stddev reporting broken since "perf stat: Introduce read_counters function" Mel Gorman
2016-01-19  7:42 ` Jiri Olsa
2016-01-19  8:16   ` Jiri Olsa
2016-01-19  9:38     ` Mel Gorman
2016-01-19  9:57       ` Jiri Olsa

This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox;
as well as URLs for NNTP newsgroup(s).