1. 25 2月, 2015 3 次提交
  2. 23 2月, 2015 13 次提交
  3. 19 2月, 2015 2 次提交
    • K
      perf tools: Construct LBR call chain · 384b6055
      Kan Liang 提交于
      LBR call stack only has user-space callchains. It is output in the
      PERF_SAMPLE_BRANCH_STACK data format. For kernel callchains, it's
      still in the form of PERF_SAMPLE_CALLCHAIN.
      
      The perf tool has to handle both data sources to construct a
      complete callstack.
      
      For the "perf report -D" option, both lbr and fp information will be
      displayed.
      
      A new call chain recording option "lbr" is introduced into the perf
      tool for LBR call stack. The user can use --call-graph lbr to get
      the call stack information from hardware.
      
      Here are some examples.
      
      When profiling bc(1) on Fedora 19:
      
        echo 'scale=2000; 4*a(1)' > cmd; perf record --call-graph lbr bc -l < cmd
      
      If enabling LBR, perf report output looks like:
      
          50.36%       bc  bc                 [.] bc_divide
                       |
                       --- bc_divide
                           execute
                           run_code
                           yyparse
                           main
                           __libc_start_main
                           _start
          33.66%       bc  bc                 [.] _one_mult
                       |
                       --- _one_mult
                           bc_divide
                           execute
                           run_code
                           yyparse
                           main
                           __libc_start_main
                           _start
           7.62%       bc  bc                 [.] _bc_do_add
                       |
                       --- _bc_do_add
                          |
                          |--99.89%-- 0x2000186a8
                           --0.11%-- [...]
           6.83%       bc  bc                 [.] _bc_do_sub
                       |
                       --- _bc_do_sub
                          |
                          |--99.94%-- bc_add
                          |          execute
                          |          run_code
                          |          yyparse
                          |          main
                          |          __libc_start_main
                          |          _start
                           --0.06%-- [...]
           0.46%       bc  libc-2.17.so       [.] __memset_sse2
                       |
                       --- __memset_sse2
                          |
                          |--54.13%-- bc_new_num
                          |          |
                          |          |--51.00%-- bc_divide
                          |          |          execute
                          |          |          run_code
                          |          |          yyparse
                          |          |          main
                          |          |          __libc_start_main
                          |          |          _start
                          |          |
                          |          |--30.46%-- _bc_do_sub
                          |          |          bc_add
                          |          |          execute
                          |          |          run_code
                          |          |          yyparse
                          |          |          main
                          |          |          __libc_start_main
                          |          |          _start
                          |          |
                          |           --18.55%-- _bc_do_add
                          |                     bc_add
                          |                     execute
                          |                     run_code
                          |                     yyparse
                          |                     main
                          |                     __libc_start_main
                          |                     _start
                          |
                           --45.87%-- bc_divide
                                     execute
                                     run_code
                                     yyparse
                                     main
                                     __libc_start_main
                                     _start
      
      If using FP, perf report output looks like:
      
        echo 'scale=2000; 4*a(1)' > cmd; perf record --call-graph fp bc -l < cmd
      
          50.49%       bc  bc                 [.] bc_divide
                       |
                       --- bc_divide
          33.57%       bc  bc                 [.] _one_mult
                       |
                       --- _one_mult
           7.61%       bc  bc                 [.] _bc_do_add
                       |
                       --- _bc_do_add
                           0x2000186a8
           6.88%       bc  bc                 [.] _bc_do_sub
                       |
                       --- _bc_do_sub
           0.42%       bc  libc-2.17.so       [.] __memcpy_ssse3_back
                       |
                       --- __memcpy_ssse3_back
      
      If using LBR, perf report -D output looks like:
      
      3458145275743 0x2fd750 [0xd8]: PERF_RECORD_SAMPLE(IP, 0x2): 9748/9748: 0x408ea8 period: 609644 addr: 0
      ... LBR call chain: nr:8
      .....  0: fffffffffffffe00
      .....  1: 0000000000408e50
      .....  2: 000000000040a458
      .....  3: 000000000040562e
      .....  4: 0000000000408590
      .....  5: 00000000004022c0
      .....  6: 00000000004015dd
      .....  7: 0000003d1cc21b43
      ... FP chain: nr:2
      .....  0: fffffffffffffe00
      .....  1: 0000000000408ea8
       ... thread: bc:9748
       ...... dso: /usr/bin/bc
      
      The LBR call stack has the following known limitations:
      
       - Zero length calls are not filtered out by the hardware
      
       - Exception handing such as setjmp/longjmp will have calls/returns not
         match
      
       - Pushing different return address onto the stack will have
         calls/returns not match
      
       - If callstack is deeper than the LBR, only the last entries are
         captured
      Tested-by: NJiri Olsa <jolsa@kernel.org>
      Signed-off-by: NKan Liang <kan.liang@intel.com>
      Signed-off-by: NPeter Zijlstra (Intel) <peterz@infradead.org>
      Cc: Adrian Hunter <adrian.hunter@intel.com>
      Cc: Arnaldo Carvalho de Melo <acme@kernel.org>
      Cc: Borislav Petkov <bp@suse.de>
      Cc: David Ahern <dsahern@gmail.com>
      Cc: Don Zickus <dzickus@redhat.com>
      Cc: Linus Torvalds <torvalds@linux-foundation.org>
      Cc: Namhyung Kim <namhyung@kernel.org>
      Cc: Paul Mackerras <paulus@samba.org>
      Cc: Simon Que <sque@chromium.org>
      Cc: Stephane Eranian <eranian@google.com>
      Link: http://lkml.kernel.org/r/1420482185-29830-3-git-send-email-kan.liang@intel.comSigned-off-by: NIngo Molnar <mingo@kernel.org>
      384b6055
    • K
      perf tools: Enable LBR call stack support · aad2b21c
      Kan Liang 提交于
      Currently, there are two call chain recording options, fp and dwarf.
      
      Haswell has a new feature that utilizes the existing LBR facility to
      record call chains. Kernel side LBR support code provides this as a
      third option to record call chains. This patch enables the lbr call
      stack support on the tooling side.
      
      LBR call stack has some limitations:
      
       - It reuses current LBR facility, so LBR call stack and branch record
         can not be enabled at the same time.
      
       - It is only available for user-space callchains.
      
      However, it also offers some advantages:
      
       - LBR call stack can work on user apps which don't have frame-pointers
         or dwarf debug info compiled. It is a good alternative when nothing
         else works.
      Tested-by: NJiri Olsa <jolsa@kernel.org>
      Signed-off-by: NKan Liang <kan.liang@intel.com>
      Signed-off-by: NPeter Zijlstra (Intel) <peterz@infradead.org>
      Cc: Adrian Hunter <adrian.hunter@intel.com>
      Cc: Anshuman Khandual <khandual@linux.vnet.ibm.com>
      Cc: Arnaldo Carvalho de Melo <acme@kernel.org>
      Cc: Cody P Schafer <cody@linux.vnet.ibm.com>
      Cc: David Ahern <dsahern@gmail.com>
      Cc: Don Zickus <dzickus@redhat.com>
      Cc: Jacob Shin <jacob.w.shin@gmail.com>
      Cc: Jiri Olsa <jolsa@redhat.com>
      Cc: Linus Torvalds <torvalds@linux-foundation.org>
      Cc: Masanari Iida <standby24x7@gmail.com>
      Cc: Namhyung Kim <namhyung@kernel.org>
      Cc: Paul Mackerras <paulus@samba.org>
      Cc: Rodrigo Campos <rodrigo@sdfg.com.ar>
      Cc: Stephane Eranian <eranian@google.com>
      Cc: Sukadev Bhattiprolu <sukadev@linux.vnet.ibm.com>
      Link: http://lkml.kernel.org/r/1420482185-29830-2-git-send-email-kan.liang@intel.comSigned-off-by: NIngo Molnar <mingo@kernel.org>
      aad2b21c
  4. 14 2月, 2015 3 次提交
    • A
      perf trace: Support --events foo:bar --no-syscalls · 726f3234
      Arnaldo Carvalho de Melo 提交于
      I.e. support tracing just tracepoints, without strace like
      raw_syscalls:*.
      
      [acme@ssdandy linux]$ trace --no-sys --ev sched:*exec,sched:*switch,sched:*exit usleep 1
        0.048 (     ): sched:sched_process_exec:filename=/usr/bin/usleep pid=27298 old_pid=27298)
        0.369 (     ): sched:sched_switch:usleep:27298 [120] S ==> swapper/5:0 [120])
        0.452 (     ): sched:sched_process_exit:comm=usleep pid=27298 prio=120)
      [acme@ssdandy linux]$
      
      TODO: remove that (...) thing when --no-syscalls is specified.
      
      Cc: Adrian Hunter <adrian.hunter@intel.com>
      Cc: Borislav Petkov <bp@suse.de>
      Cc: David Ahern <dsahern@gmail.com>
      Cc: Don Zickus <dzickus@redhat.com>
      Cc: Frederic Weisbecker <fweisbec@gmail.com>
      Cc: Jiri Olsa <jolsa@redhat.com>
      Cc: Mike Galbraith <efault@gmx.de>
      Cc: Namhyung Kim <namhyung@kernel.org>
      Cc: Peter Zijlstra <peterz@infradead.org>
      Cc: Stephane Eranian <eranian@google.com>
      Link: http://lkml.kernel.org/n/tip-vn0hsixsbhm31b2rpj97r96k@git.kernel.orgSigned-off-by: NArnaldo Carvalho de Melo <acme@redhat.com>
      726f3234
    • A
      perf trace: Allow mixing with other events · 14a052df
      Arnaldo Carvalho de Melo 提交于
      Basically adopting 'perf record' --event command line argument syntax:
      
       # trace -e \!mprotect,mmap,munmap,open,close,read,fstat,access,arch_prctl --event sched:*switch,sched:*exec,sched:*exit usleep 1
        0.048 (        ): sched:sched_process_exec:filename=/bin/usleep pid=24732 old_pid=24732)
        0.078 (0.002 ms): usleep/24732 brk(                          ) = 0x78f000
        0.430 (0.002 ms): usleep/24732 brk(                          ) = 0x78f000
        0.434 (0.003 ms): usleep/24732 brk(brk: 0x7b0000             ) = 0x7b0000
        0.438 (0.001 ms): usleep/24732 brk(                          ) = 0x7b0000
        0.460 (0.004 ms): usleep/24732 nanosleep(rqtp: 0x7ffff3696a40) ...
        0.460 (        ): sched:sched_switch:prev_comm=usleep prev_pid=24732 prev_prio=120 prev_state=S ==> next_comm=swapper/1 next_pid=0 next_prio=120)
        0.515 (0.058 ms): usleep/24732  ... [continued]: nanosleep()) = 0
        0.520 (0.000 ms): usleep/24732 exit_group(
        0.550 (        ): sched:sched_process_exit:comm=usleep pid=24732 prio=120)
       #
      
      Next steps, probably in this order:
      
      1) Use ordered_events code, the logic in trace needs the events to be
         time ordered when needed, i.e. when multiple CPUs are involved.
      
      2) Callchains!
      
      3) Automatically account for interruptions when saying how long things
         took.
      
      Cc: Adrian Hunter <adrian.hunter@intel.com>
      Cc: Borislav Petkov <bp@suse.de>
      Cc: David Ahern <dsahern@gmail.com>
      Cc: Don Zickus <dzickus@redhat.com>
      Cc: Frederic Weisbecker <fweisbec@gmail.com>
      Cc: Jiri Olsa <jolsa@redhat.com>
      Cc: Mike Galbraith <efault@gmx.de>
      Cc: Namhyung Kim <namhyung@kernel.org>
      Cc: Peter Zijlstra <peterz@infradead.org>
      Cc: Stephane Eranian <eranian@google.com>
      Link: http://lkml.kernel.org/n/tip-gpst8mph575yb4wgf91qibyb@git.kernel.orgSigned-off-by: NArnaldo Carvalho de Melo <acme@redhat.com>
      14a052df
    • A
      perf trace: Handle multiple threads better wrt syscalls being intermixed · e596663e
      Arnaldo Carvalho de Melo 提交于
       $ trace time taskset -c 0 usleep 1
         0.845 ( 0.021 ms): time/16722 wait4(upid: 4294967295, stat_addr: 0x7fff17f443d4, ru: 0x7fff17f44438 ) ...
         0.865 ( 0.008 ms): time/16723 execve(arg0: 140733595272004, arg1: 140733595272720, arg2: 140733595272768, arg3: 139755107218496, arg4: 7307199665339051828, arg5: 3) = -2
         2.395 ( 1.523 ms): taskset/16723 execve(arg0: 140733595272013, arg1: 140733595272720, arg2: 140733595272768, arg3: 139755107218496, arg4: 7307199665339051828, arg5: 3) = 0
         2.411 ( 0.002 ms): taskset/16723 brk(                                                                  ) = 0x1915000
         3.300 ( 0.058 ms): usleep/16723 nanosleep(rqtp: 0x7ffff4ada190                                        ) = 0
       <SNIP>
         3.305 ( 0.000 ms): usleep/16723 exit_group(
         3.363 ( 2.539 ms): time/16722  ... [continued]: wait4()) = 16723
         3.366 ( 0.001 ms): time/16722 rt_sigaction(sig: INT, act: 0x7fff17f44160, oact: 0x7fff17f44200, sigsetsize: 8) = 0
      
      We we're not seeing this line:
      
        0.845 ( 0.021 ms): time/16722 wait4(upid: 4294967295, stat_addr: 0x7fff17f443d4, ru: 0x7fff17f44438 ) ...
      
      just the one when it finishes:
      
        3.363 ( 2.539 ms): time/16722  ... [continued]: wait4()) = 16723
      
      Still some issues left till we move to ordered_samples when multiple
      CPUs/threads are involved...
      
      Cc: Adrian Hunter <adrian.hunter@intel.com>
      Cc: Borislav Petkov <bp@suse.de>
      Cc: David Ahern <dsahern@gmail.com>
      Cc: Don Zickus <dzickus@redhat.com>
      Cc: Frederic Weisbecker <fweisbec@gmail.com>
      Cc: Jiri Olsa <jolsa@redhat.com>
      Cc: Namhyung Kim <namhyung@kernel.org>
      Cc: Stephane Eranian <eranian@google.com>
      Link: http://lkml.kernel.org/n/tip-zq9x30a1ky3djqewqn2v3ja3@git.kernel.orgSigned-off-by: NArnaldo Carvalho de Melo <acme@redhat.com>
      e596663e
  5. 13 2月, 2015 19 次提交