lists.openwall.net   lists  /  announce  owl-users  owl-dev  john-users  john-dev  passwdqc-users  yescrypt  popa3d-users  /  oss-security  kernel-hardening  musl  sabotage  tlsify  passwords  /  crypt-dev  xvendor  /  Bugtraq  Full-Disclosure  linux-kernel  linux-netdev  linux-ext4  linux-hardening  linux-cve-announce  PHC 
Open Source and information security mailing list archives
 
Hash Suite: Windows password security audit tool. GUI, reports in PDF.
[<prev] [next>] [<thread-prev] [thread-next>] [day] [month] [year] [list]
Message-ID: <20170321142155.GC3641@kernel.org>
Date:   Tue, 21 Mar 2017 11:21:55 -0300
From:   Arnaldo Carvalho de Melo <acme@...nel.org>
To:     Taeung Song <treeze.taeung@...il.com>
Cc:     Arnaldo Carvalho de Melo <arnaldo.melo@...il.com>,
        linux-kernel@...r.kernel.org, Jiri Olsa <jolsa@...nel.org>,
        Namhyung Kim <namhyung@...nel.org>,
        Ingo Molnar <mingo@...nel.org>,
        Peter Zijlstra <peterz@...radead.org>,
        Wang Nan <wangnan0@...wei.com>,
        Masami Hiramatsu <mhiramat@...nel.org>,
        Jiri Olsa <jolsa@...hat.com>
Subject: Re: [PATCH 2/4] perf annotate: Avoid division by zero when
 calculating percent

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@...et ~]# 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@...et ~]# 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@...et ~]#

So, if we don't use -l/--print-line we get:

[root@...et ~]# 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@...et ~]#

I.e. one column per event in that group, and no -nan, all is well.

But if we ask for --lines it gets b0rked:

[root@...et ~]# 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@...et ~]#

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

Powered by blists - more mailing lists

Powered by Openwall GNU/*/Linux Powered by OpenVZ