Re: [PATCH v3 06/11] perf, tools, stat: Support JSON metrics in perf stat

[Arnaldo Carvalho de Melo]

Em Tue, Sep 05, 2017 at 03:16:12PM -0300, Arnaldo Carvalho de Melo escreveu:
> Em Tue, Sep 05, 2017 at 03:09:19PM -0300, Arnaldo Carvalho de Melo escreveu:
> > Em Mon, Sep 04, 2017 at 10:37:25AM -0700, Andi Kleen escreveu:
> > > On Mon, Sep 04, 2017 at 02:11:28PM -0300, Arnaldo Carvalho de Melo wrote:
> > > > Em Thu, Aug 31, 2017 at 12:40:31PM -0700, Andi Kleen escreveu:
> > > > > The actual JSON metrics are in a separate pull request.
> > > > 
> > > > Yeah, I noticed when trying to test it :-\
> > > > 
> > > > Was this pull req submitted?
> > > 
> > > Not yet. I was waiting to finish review.
> > > 
> > > It makes perf crash until you apply the metricgroup patchkit first.
> > > 
> > > But you can get it here
> > > 
> > > git://git.kernel.org/pub/scm/linux/kernel/git/ak/linux-misc.git perf/intel-json-metrics-2
> > 
> > Ok, so I tried installing the Broadwell ones (one of my test machines)
> > and got into:
> > 
> > [root@jouet ~]# perf stat -M Pipeline flops
> > bpf: builtin compilation failed: -95, try external compiler

further info:

[acme@jouet linux]$ perf stat -v -M GFLOPs sleep 1
Using CPUID GenuineIntel-6-3D
metric expr ( 1*( fp_arith_inst_retired.scalar_single + fp_arith_inst_retired.scalar_double ) + 2* fp_arith_inst_retired.128b_packed_double + 4*( fp_arith_inst_retired.128b_packed_single + fp_arith_inst_retired.256b_packed_double ) + 8* fp_arith_inst_retired.256b_packed_single ) / 1000000000 / duration_time for GFLOPs
found event fp_arith_inst_retired.scalar_single
found event fp_arith_inst_retired.scalar_double
found event fp_arith_inst_retired.128b_packed_double
found event fp_arith_inst_retired.128b_packed_single
found event fp_arith_inst_retired.256b_packed_double
found event fp_arith_inst_retired.256b_packed_single
found event duration_time
adding {fp_arith_inst_retired.scalar_single,fp_arith_inst_retired.scalar_double,fp_arith_inst_retired.128b_packed_double,fp_arith_inst_retired.128b_packed_single,fp_arith_inst_retired.256b_packed_double,fp_arith_inst_retired.256b_packed_single,duration_time}:W
fp_arith_inst_retired.scalar_single -> cpu/umask=0x2,period=2000003,event=0xc7/
fp_arith_inst_retired.scalar_double -> cpu/umask=0x1,period=2000003,event=0xc7/
fp_arith_inst_retired.128b_packed_double -> cpu/umask=0x4,period=2000003,event=0xc7/
fp_arith_inst_retired.128b_packed_single -> cpu/umask=0x8,period=2000003,event=0xc7/
fp_arith_inst_retired.256b_packed_double -> cpu/umask=0x10,period=2000003,event=0xc7/
fp_arith_inst_retired.256b_packed_single -> cpu/umask=0x20,period=2000003,event=0xc7/
Cannot set up events {fp_arith_inst_retired.scalar_single,fp_arith_inst_retired.scalar_double,fp_arith_inst_retired.128b_packed_double,fp_arith_inst_retired.128b_packed_single,fp_arith_inst_retired.256b_packed_double,fp_arith_inst_retired.256b_packed_single,duration_time}:W

 Usage: perf stat [<options>] [<command>]

    -M, --metrics <metric/metric group list>
                          monitor specified metrics or metric groups (separated by ,)
[acme@jouet linux]$ 

Humm, so it uses that duration_time and that gets added only later?

/me tries with all the patches:

Yeah:

[acme@jouet linux]$ perf stat -M GFLOPs sleep 1

 Performance counter stats for 'sleep 1':

                 0      fp_arith_inst_retired.scalar_single:u                                   
                 3      fp_arith_inst_retired.scalar_double:u                                   
                 0      fp_arith_inst_retired.128b_packed_double:u                                   
                 0      fp_arith_inst_retired.128b_packed_single:u                                   
                 0      fp_arith_inst_retired.256b_packed_double:u                                     (40.86%)
     <not counted>      fp_arith_inst_retired.256b_packed_single:u                                     (0.00%)
                 0      duration_time:u                                             

       1.003398909 seconds time elapsed

[acme@jouet linux]$

With --metric-only I get nothing, what am I doing wrong?

[acme@jouet linux]$ perf stat -M GFLOPs --metric-only sleep 1

 Performance counter stats for 'sleep 1':

GFLOPs               
                                         

       1.003217768 seconds time elapsed

[acme@jouet linux]$

I just rebuilt the tools completely from scratch, deleting the build
dir, to see if this was some build artifact, didn't help, I still get
just the time elapsed.

Now with -v:

[acme@jouet linux]$ perf stat -v -M GFLOPs --metric-only sleep 1
Using CPUID GenuineIntel-6-3D
metric expr ( 1*( fp_arith_inst_retired.scalar_single + fp_arith_inst_retired.scalar_double ) + 2* fp_arith_inst_retired.128b_packed_double + 4*( fp_arith_inst_retired.128b_packed_single + fp_arith_inst_retired.256b_packed_double ) + 8* fp_arith_inst_retired.256b_packed_single ) / 1000000000 / duration_time for GFLOPs
found event fp_arith_inst_retired.scalar_single
found event fp_arith_inst_retired.scalar_double
found event fp_arith_inst_retired.128b_packed_double
found event fp_arith_inst_retired.128b_packed_single
found event fp_arith_inst_retired.256b_packed_double
found event fp_arith_inst_retired.256b_packed_single
found event duration_time
adding {fp_arith_inst_retired.scalar_single,fp_arith_inst_retired.scalar_double,fp_arith_inst_retired.128b_packed_double,fp_arith_inst_retired.128b_packed_single,fp_arith_inst_retired.256b_packed_double,fp_arith_inst_retired.256b_packed_single,duration_time}:W
fp_arith_inst_retired.scalar_single -> cpu/umask=0x2,period=2000003,event=0xc7/
fp_arith_inst_retired.scalar_double -> cpu/umask=0x1,period=2000003,event=0xc7/
fp_arith_inst_retired.128b_packed_double -> cpu/umask=0x4,period=2000003,event=0xc7/
fp_arith_inst_retired.128b_packed_single -> cpu/umask=0x8,period=2000003,event=0xc7/
fp_arith_inst_retired.256b_packed_double -> cpu/umask=0x10,period=2000003,event=0xc7/
fp_arith_inst_retired.256b_packed_single -> cpu/umask=0x20,period=2000003,event=0xc7/
Warning:
kernel.perf_event_paranoid=2, trying to fall back to excluding kernel samples
Warning:
kernel.perf_event_paranoid=2, trying to fall back to excluding kernel samples
Warning:
kernel.perf_event_paranoid=2, trying to fall back to excluding kernel samples
Warning:
kernel.perf_event_paranoid=2, trying to fall back to excluding kernel samples
Warning:
kernel.perf_event_paranoid=2, trying to fall back to excluding kernel samples
Weak group for fp_arith_inst_retired.scalar_single:u/7 failed
Warning:
kernel.perf_event_paranoid=2, trying to fall back to excluding kernel samples
Warning:
kernel.perf_event_paranoid=2, trying to fall back to excluding kernel samples
fp_arith_inst_retired.scalar_single:u: 0 2137416 524337
fp_arith_inst_retired.scalar_double:u: 0 1525387 1525387
fp_arith_inst_retired.128b_packed_double:u: 0 2429065 2429065
fp_arith_inst_retired.128b_packed_single:u: 0 2429065 2429065
fp_arith_inst_retired.256b_packed_double:u: 0 2429065 1904728
fp_arith_inst_retired.256b_packed_single:u: 0 2429065 903678
duration_time:u: 0 2394375 2394375

 Performance counter stats for 'sleep 1':

fp_arith_inst_retired.scalar_single not found
GFLOPs               
fp_arith_inst_retired.scalar_single not found
                     

       1.005367355 seconds time elapsed

[acme@jouet linux]$


We need to improve these messages...

As root for that Summary more:

[acme@jouet linux]$ sudo ~acme/bin/perf stat -M Summary --metric-only -a sleep 1

 Performance counter stats for 'system wide':

Instructions         CPI                  CLKS                 CPU_Utilization      GFLOPs               SMT_2T_Utilization   Kernel_Utilization   
134707420.0              0.0            698757419.0              0.1                 0.0                 0.3                 0.4            

       1.003365814 seconds time elapsed

[acme@jouet linux]$ 

- Arnaldo