Re: [PATCH 2/4] perf annotate: Avoid division by zero when calculating percent

[Taeung Song]

On 03/21/2017 11:21 PM, Arnaldo Carvalho de Melo wrote:
> Em Tue, Mar 21, 2017 at 11:14:07AM -0300, Arnaldo Carvalho de Melo escreveu:
> > Em Tue, Mar 21, 2017 at 07:20:20AM +0900, Taeung Song escreveu:
> > > And,
> > > I tested by perf-stat on the same situation as below.
> > >
> > >   $ perf stat -e "{cycles,page-faults,branch-misses}" ./old <input.txt
> > >   6623856
> >
> > Please always try to spell out all the steps needed to get to some
> > result, for instance, in this case the info above, that you are asking
> > for three counters to be recorded at once probably has the key to
> > reproduce this, as I think that you may run your workload and sometimes
> > not get one page fault, leading tho that division by zero, but I have to
> > try to reproduce it now that I have this clue.
>
> Bingo!
>
> [root@jouet ~]# perf record -e "{cycles,page-faults,branch-misses}" usleep 1
> [ perf record: Woken up 1 times to write data ]
> [ perf record: Captured and wrote 0.020 MB perf.data (20 samples) ]
> [root@jouet ~]# perf annotate -l --stdio 2>&1 | grep -w nan | head
>   100.00    -nan  100.00 msr.h:104
>     0.00    -nan    0.00 :	  ffffffff81060bf0:       mov    %edi,%ecx
>     0.00    -nan    0.00 :	  ffffffff81060bf2:       mov    %esi,%eax
>     0.00    -nan    0.00 :	  ffffffff81060bf4:       wrmsr
>  msr.h:104  100.00    -nan  100.00 :	  ffffffff81060bf6:       nopl   0x0(%rax,%rax,1)
>     0.00    -nan    0.00 :	  ffffffff81060bfb:       retq
>     0.00    -nan    0.00 :	  ffffffff81060bfc:       push   %rbp
>     0.00    -nan    0.00 :	  ffffffff81060bfd:       mov    %esi,%eax
>     0.00    -nan    0.00 :	  ffffffff81060bff:       mov    %rdx,%rsi
>     0.00    -nan    0.00 :	  ffffffff81060c02:       shl    $0x20,%rsi
> [root@jouet ~]#
>
> So, if we don't use -l/--print-line we get:
>
> [root@jouet ~]# perf annotate --stdio --no-source native_write_msr
>  Percent                 |      Source code & Disassembly of vmlinux for cycles (3 samples)
> -------------------------------------------------------------------------------------------
>                          :      ffffffff81060bf0 <native_write_msr>:
>                          :      __wrmsr():
>     0.00    0.00    0.00 :        ffffffff81060bf0:       mov    %edi,%ecx
>     0.00    0.00    0.00 :        ffffffff81060bf2:       mov    %esi,%eax
>     0.00    0.00    0.00 :        ffffffff81060bf4:       wrmsr
>                          :      arch_static_branch():
>   100.00    0.00  100.00 :        ffffffff81060bf6:       nopl   0x0(%rax,%rax,1)
>                          :      native_write_msr():
>     0.00    0.00    0.00 :        ffffffff81060bfb:       retq
>     0.00    0.00    0.00 :        ffffffff81060bfc:       push   %rbp
>     0.00    0.00    0.00 :        ffffffff81060bfd:       mov    %esi,%eax
>     0.00    0.00    0.00 :        ffffffff81060bff:       mov    %rdx,%rsi
>     0.00    0.00    0.00 :        ffffffff81060c02:       shl    $0x20,%rsi
>     0.00    0.00    0.00 :        ffffffff81060c06:       mov    %eax,%edx
>     0.00    0.00    0.00 :        ffffffff81060c08:       mov    %rsp,%rbp
>     0.00    0.00    0.00 :        ffffffff81060c0b:       or     %rdx,%rsi
>     0.00    0.00    0.00 :        ffffffff81060c0e:       xor    %edx,%edx
>     0.00    0.00    0.00 :        ffffffff81060c10:       callq  ffffffff81457df0 <do_trace_write_msr>
>     0.00    0.00    0.00 :        ffffffff81060c15:       pop    %rbp
>     0.00    0.00    0.00 :        ffffffff81060c16:       retq
> [root@jouet ~]#
>
> I.e. one column per event in that group, and no -nan, all is well.

The reason is the below if statement at util/annotate.c:910.

881 double disasm__calc_percent(struct annotation *notes, int evidx, s64 
offset,
...
904                 struct sym_hist *h = annotation__histogram(notes, 
evidx);
905                 unsigned int hits = 0;
906
907                 while (offset < end)
908                         hits += h->addr[offset++];
909
910                 if (h->sum) {
911                         *nr_samples = hits;
912                         percent = 100.0 * hits / h->sum;
913                 }
914         }

The if statement 'if (h->sum)' prevent division by zero, so all is well.

So I sent this patch because of same reason
adding the if statement 'if (h->sum)' in symbol__get_source_line().

But will resend v2 with more clearly commit log message!
I think previous log message is a bit insufficient..

Thanks,
Taeung

> But if we ask for --lines it gets b0rked:
>
> [root@jouet ~]# perf annotate --stdio --no-source native_write_msr --print-line
>
> Sorted summary for file /lib/modules/4.11.0-rc2+/build/vmlinux
> ----------------------------------------------
>
>   100.00    -nan  100.00 msr.h:104
>  Percent                 |      Source code & Disassembly of vmlinux for cycles (3 samples)
> -------------------------------------------------------------------------------------------
>                          :      ffffffff81060bf0 <native_write_msr>:
>                          :      __wrmsr():
>     0.00    -nan    0.00 :        ffffffff81060bf0:       mov    %edi,%ecx
>     0.00    -nan    0.00 :        ffffffff81060bf2:       mov    %esi,%eax
>     0.00    -nan    0.00 :        ffffffff81060bf4:       wrmsr
>                          :      arch_static_branch():
>  msr.h:104  100.00    -nan  100.00 :      ffffffff81060bf6:       nopl   0x0(%rax,%rax,1)
>                          :      native_write_msr():
>     0.00    -nan    0.00 :        ffffffff81060bfb:       retq
>     0.00    -nan    0.00 :        ffffffff81060bfc:       push   %rbp
>     0.00    -nan    0.00 :        ffffffff81060bfd:       mov    %esi,%eax
>     0.00    -nan    0.00 :        ffffffff81060bff:       mov    %rdx,%rsi
>     0.00    -nan    0.00 :        ffffffff81060c02:       shl    $0x20,%rsi
>     0.00    -nan    0.00 :        ffffffff81060c06:       mov    %eax,%edx
>     0.00    -nan    0.00 :        ffffffff81060c08:       mov    %rsp,%rbp
>     0.00    -nan    0.00 :        ffffffff81060c0b:       or     %rdx,%rsi
>     0.00    -nan    0.00 :        ffffffff81060c0e:       xor    %edx,%edx
>     0.00    -nan    0.00 :        ffffffff81060c10:       callq  ffffffff81457df0 <do_trace_write_msr>
>     0.00    -nan    0.00 :        ffffffff81060c15:       pop    %rbp
>     0.00    -nan    0.00 :        ffffffff81060c16:       retq
> [root@jouet ~]#
>
> I don't have that much time to continue pursuing this, try to continue
> investigating, I'll try to help and to fix this later.
>
> - Arnaldo