Age | Commit message (Collapse) | Author |
|
It's useful to print the branch counter information for each jump in
the brstackinsn when it's available.
Add a new field 'brcntr' to display the branch counter information.
By default, the abbreviation will be used to indicate the branch
counter. In the verbose mode, the real event name is shown.
$ perf script -F +brstackinsn,+brcntr
# Branch counter abbr list:
# branch-instructions:ppp = A
# branch-misses = B
# '-' No event occurs
# '+' Event occurrences may be lost due to branch counter saturated
tchain_edit 332203 3366329.405674: 53030 branch-instructions:ppp: 401781 f3+0x2c (home/sdp/test/tchain_edit)
f3+31:
0000000000401774 insn: eb 04 br_cntr: AA # PRED 5 cycles [5]
000000000040177a insn: 81 7d fc 0f 27 00 00
0000000000401781 insn: 7e e3 br_cntr: A # PRED 1 cycles [6] 2.00 IPC
0000000000401766 insn: 8b 45 fc
0000000000401769 insn: 83 e0 01
000000000040176c insn: 85 c0
000000000040176e insn: 74 06 br_cntr: A # PRED 1 cycles [7] 4.00 IPC
0000000000401776 insn: 83 45 fc 01
000000000040177a insn: 81 7d fc 0f 27 00 00
0000000000401781 insn: 7e e3 br_cntr: A # PRED 7 cycles [14] 0.43 IPC
$ perf script -F +brstackinsn,+brcntr -v
tchain_edit 332203 3366329.405674: 53030 branch-instructions:ppp: 401781 f3+0x2c (/home/sdp/os.linux.perf.test-suite/kernels/lbr_kernel/tchain_edit)
f3+31:
0000000000401774 insn: eb 04 br_cntr: branch-instructions:ppp 2 branch-misses 0 # PRED 5 cycles [5]
000000000040177a insn: 81 7d fc 0f 27 00 00
0000000000401781 insn: 7e e3 br_cntr: branch-instructions:ppp 1 branch-misses 0 # PRED 1 cycles [6] 2.00 IPC
0000000000401766 insn: 8b 45 fc
0000000000401769 insn: 83 e0 01
000000000040176c insn: 85 c0
000000000040176e insn: 74 06 br_cntr: branch-instructions:ppp 1 branch-misses 0 # PRED 1 cycles [7] 4.00 IPC
0000000000401776 insn: 83 45 fc 01
000000000040177a insn: 81 7d fc 0f 27 00 00
0000000000401781 insn: 7e e3 br_cntr: branch-instructions:ppp 1 branch-misses 0 # PRED 7 cycles [14] 0.43 IPC
Originally-by: Tinghao Zhang <tinghao.zhang@intel.com>
Reviewed-by: Andi Kleen <ak@linux.intel.com>
Signed-off-by: Kan Liang <kan.liang@linux.intel.com>
Acked-by: Namhyung Kim <namhyung@kernel.org>
Cc: Adrian Hunter <adrian.hunter@intel.com>
Cc: Ian Rogers <irogers@google.com>
Cc: Ingo Molnar <mingo@kernel.org>
Cc: Peter Zijlstra <peterz@infradead.org>
Cc: Stephane Eranian <eranian@google.com>
Link: https://lore.kernel.org/r/20240813160208.2493643-9-kan.liang@linux.intel.com
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
|
|
Similarly to other subcommands (like report, top), it would be handy to
provide a path for addr2line command.
Signed-off-by: Martin Liska <martin.liska@hey.com>
Cc: Ian Rogers <irogers@google.com>
Link: https://lore.kernel.org/r/eadc3e36-029d-4848-9d69-272fe5a83a26@foxlink.cz
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
|
|
Support capstone output for the '-F +brstackinsn' branch dump.
The new output is enabled with the new field 'brstackdisasm'.
This was possible before with --xed, but now also allow it for users
that don't have xed using the builtin capstone support.
Before:
perf record -b emacs -Q --batch '()'
perf script -F +brstackinsn
...
emacs 55778 1814366.755945: 151564 cycles:P: 7f0ab2d17192 intel_check_word.constprop.0+0x162 (/usr/lib64/ld-linux-x86-64.s> intel_check_word.constprop.0+237:
00007f0ab2d1711d insn: 75 e6 # PRED 3 cycles [3]
00007f0ab2d17105 insn: 73 51
00007f0ab2d17107 insn: 48 89 c1
00007f0ab2d1710a insn: 48 39 ca
00007f0ab2d1710d insn: 73 96
00007f0ab2d1710f insn: 48 8d 04 11
00007f0ab2d17113 insn: 48 d1 e8
00007f0ab2d17116 insn: 49 8d 34 c1
00007f0ab2d1711a insn: 44 3a 06
00007f0ab2d1711d insn: 75 e6 # PRED 3 cycles [6] 3.00 IPC
00007f0ab2d17105 insn: 73 51 # PRED 1 cycles [7] 1.00 IPC
00007f0ab2d17158 insn: 48 8d 50 01
00007f0ab2d1715c insn: eb 92 # PRED 1 cycles [8] 2.00 IPC
00007f0ab2d170f0 insn: 48 39 ca
00007f0ab2d170f3 insn: 73 b0 # PRED 1 cycles [9] 2.00 IPC
After (perf must be compiled with capstone):
perf script -F +brstackdisasm
...
emacs 55778 1814366.755945: 151564 cycles:P: 7f0ab2d17192 intel_check_word.constprop.0+0x162 (/usr/lib64/ld-linux-x86-64.s> intel_check_word.constprop.0+237:
00007f0ab2d1711d jne intel_check_word.constprop.0+0xd5 # PRED 3 cycles [3]
00007f0ab2d17105 jae intel_check_word.constprop.0+0x128
00007f0ab2d17107 movq %rax, %rcx
00007f0ab2d1710a cmpq %rcx, %rdx
00007f0ab2d1710d jae intel_check_word.constprop.0+0x75
00007f0ab2d1710f leaq (%rcx, %rdx), %rax
00007f0ab2d17113 shrq $1, %rax
00007f0ab2d17116 leaq (%r9, %rax, 8), %rsi
00007f0ab2d1711a cmpb (%rsi), %r8b
00007f0ab2d1711d jne intel_check_word.constprop.0+0xd5 # PRED 3 cycles [6] 3.00 IPC
00007f0ab2d17105 jae intel_check_word.constprop.0+0x128 # PRED 1 cycles [7] 1.00 IPC
00007f0ab2d17158 leaq 1(%rax), %rdx
00007f0ab2d1715c jmp intel_check_word.constprop.0+0xc0 # PRED 1 cycles [8] 2.00 IPC
00007f0ab2d170f0 cmpq %rcx, %rdx
00007f0ab2d170f3 jae intel_check_word.constprop.0+0x75 # PRED 1 cycles [9] 2.00 IPC
Reviewed-by: Adrian Hunter <adrian.hunter@intel.com>
Signed-off-by: Andi Kleen <ak@linux.intel.com>
Link: https://lore.kernel.org/r/20240401210925.209671-3-ak@linux.intel.com
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
|
|
Now '--insn-trace' accept a argument to specify the output format:
- raw: display raw instructions.
- disasm: display mnemonic instructions (if capstone is installed).
$ sudo perf script --insn-trace=raw
ls 1443864 [006] 2275506.209908875: 7f216b426100 _start+0x0 (/usr/lib/x86_64-linux-gnu/ld-2.31.so) insn: 48 89 e7
ls 1443864 [006] 2275506.209908875: 7f216b426103 _start+0x3 (/usr/lib/x86_64-linux-gnu/ld-2.31.so) insn: e8 e8 0c 00 00
ls 1443864 [006] 2275506.209908875: 7f216b426df0 _dl_start+0x0 (/usr/lib/x86_64-linux-gnu/ld-2.31.so) insn: f3 0f 1e fa
$ sudo perf script --insn-trace=disasm
ls 1443864 [006] 2275506.209908875: 7f216b426100 _start+0x0 (/usr/lib/x86_64-linux-gnu/ld-2.31.so) movq %rsp, %rdi
ls 1443864 [006] 2275506.209908875: 7f216b426103 _start+0x3 (/usr/lib/x86_64-linux-gnu/ld-2.31.so) callq _dl_start+0x0
ls 1443864 [006] 2275506.209908875: 7f216b426df0 _dl_start+0x0 (/usr/lib/x86_64-linux-gnu/ld-2.31.so) illegal instruction
ls 1443864 [006] 2275506.209908875: 7f216b426df4 _dl_start+0x4 (/usr/lib/x86_64-linux-gnu/ld-2.31.so) pushq %rbp
ls 1443864 [006] 2275506.209908875: 7f216b426df5 _dl_start+0x5 (/usr/lib/x86_64-linux-gnu/ld-2.31.so) movq %rsp, %rbp
ls 1443864 [006] 2275506.209908875: 7f216b426df8 _dl_start+0x8 (/usr/lib/x86_64-linux-gnu/ld-2.31.so) pushq %r15
Signed-off-by: Changbin Du <changbin.du@huawei.com>
Reviewed-by: Adrian Hunter <adrian.hunter@intel.com>
Cc: changbin.du@gmail.com
Cc: Thomas Richter <tmricht@linux.ibm.com>
Cc: Andi Kleen <ak@linux.intel.com>
Signed-off-by: Namhyung Kim <namhyung@kernel.org>
Link: https://lore.kernel.org/r/20240217074046.4100789-5-changbin.du@huawei.com
|
|
In addition to the 'insn' field, this adds a new field 'disasm' to
display mnemonic instructions instead of the raw code.
$ sudo perf script -F +disasm
perf-exec 1443864 [006] 2275506.209848: psb: psb offs: 0 0 [unknown] ([unknown])
perf-exec 1443864 [006] 2275506.209848: cbr: cbr: 41 freq: 4100 MHz (114%) 0 [unknown] ([unknown])
ls 1443864 [006] 2275506.209905: 1 branches:uH: 7f216b426100 _start+0x0 (/usr/lib/x86_64-linux-gnu/ld-2.31.so) movq %rsp, %rdi
ls 1443864 [006] 2275506.209908: 1 branches:uH: 7f216b426103 _start+0x3 (/usr/lib/x86_64-linux-gnu/ld-2.31.so) callq _dl_start+0x0
Signed-off-by: Changbin Du <changbin.du@huawei.com>
Reviewed-by: Adrian Hunter <adrian.hunter@intel.com>
Cc: changbin.du@gmail.com
Cc: Thomas Richter <tmricht@linux.ibm.com>
Cc: Andi Kleen <ak@linux.intel.com>
Signed-off-by: Namhyung Kim <namhyung@kernel.org>
Link: https://lore.kernel.org/r/20240217074046.4100789-4-changbin.du@huawei.com
|
|
This adds a new 'dsoff' field to print dso offset for resolved symbols,
and the offset is appended to dso name.
Default output:
$ perf script
ls 2695501 3011030.487017: 500000 cycles: 152cc73ef4b5 get_common_indices.constprop.0+0x155 (/usr/lib/x86_64-linux-gnu/ld-2.31.so)
ls 2695501 3011030.487018: 500000 cycles: ffffffff99045b3e [unknown] ([unknown])
ls 2695501 3011030.487018: 500000 cycles: ffffffff9968e107 [unknown] ([unknown])
ls 2695501 3011030.487018: 500000 cycles: ffffffffc1f54afb [unknown] ([unknown])
ls 2695501 3011030.487018: 500000 cycles: ffffffff9968382f [unknown] ([unknown])
ls 2695501 3011030.487019: 500000 cycles: ffffffff99e00094 [unknown] ([unknown])
ls 2695501 3011030.487019: 500000 cycles: 152cc718a8d0 __errno_location@plt+0x0 (/usr/lib/x86_64-linux-gnu/libselinux.so.1)
Display 'dsoff' field:
$ perf script -F +dsoff
ls 2695501 3011030.487017: 500000 cycles: 152cc73ef4b5 get_common_indices.constprop.0+0x155 (/usr/lib/x86_64-linux-gnu/ld-2.31.so+0x1c4b5)
ls 2695501 3011030.487018: 500000 cycles: ffffffff99045b3e [unknown] ([unknown])
ls 2695501 3011030.487018: 500000 cycles: ffffffff9968e107 [unknown] ([unknown])
ls 2695501 3011030.487018: 500000 cycles: ffffffffc1f54afb [unknown] ([unknown])
ls 2695501 3011030.487018: 500000 cycles: ffffffff9968382f [unknown] ([unknown])
ls 2695501 3011030.487019: 500000 cycles: ffffffff99e00094 [unknown] ([unknown])
ls 2695501 3011030.487019: 500000 cycles: 152cc718a8d0 __errno_location@plt+0x0 (/usr/lib/x86_64-linux-gnu/libselinux.so.1+0x68d0)
ls 2695501 3011030.487019: 500000 cycles: ffffffff992a6db0 [unknown] ([unknown])
Signed-off-by: Changbin Du <changbin.du@huawei.com>
Acked-by: Adrian Hunter <adrian.hunter@intel.com>
Cc: Alexander Shishkin <alexander.shishkin@linux.intel.com>
Cc: Hui Wang <hw.huiwang@huawei.com>
Cc: Ian Rogers <irogers@google.com>
Cc: Ingo Molnar <mingo@redhat.com>
Cc: Jiri Olsa <jolsa@kernel.org>
Cc: Mark Rutland <mark.rutland@arm.com>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: Peter Zijlstra <peterz@infradead.org>
Link: https://lore.kernel.org/r/20230418031825.1262579-4-changbin.du@huawei.com
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
|
|
The 'perf script' documentation is missing the fields option for Retire
Latency. Add it.
Signed-off-by: Kan Liang <kan.liang@linux.intel.com>
Cc: Andi Kleen <ak@linux.intel.com>
Cc: Ian Rogers <irogers@google.com>
Cc: Ingo Molnar <mingo@redhat.com>
Cc: Peter Zijlstra <peterz@infradead.org>
Cc: Stephane Eranian <eranian@google.com>
Link: https://lore.kernel.org/r/20230206162100.3329395-2-kan.liang@linux.intel.com
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
|
|
There's no field for the cgroup, let's add one. To do that, users need to
specify --all-cgroup option for perf record to capture the cgroup info.
$ perf record --all-cgroups -- true
$ perf script -F comm,pid,cgroup
true 337112 /user.slice/user-657345.slice/user@657345.service/...
true 337112 /user.slice/user-657345.slice/user@657345.service/...
true 337112 /user.slice/user-657345.slice/user@657345.service/...
true 337112 /user.slice/user-657345.slice/user@657345.service/...
If it's recorded without the --all-cgroups, it'd complain.
$ perf script -F comm,pid,cgroup
Samples for 'cycles:u' event do not have CGROUP attribute set. Cannot print 'cgroup' field.
Hint: run 'perf record --all-cgroups ...'
Signed-off-by: Namhyung Kim <namhyung@kernel.org>
Cc: Adrian Hunter <adrian.hunter@intel.com>
Cc: Ian Rogers <irogers@google.com>
Cc: Ingo Molnar <mingo@kernel.org>
Cc: Jiri Olsa <jolsa@kernel.org>
Cc: Peter Zijlstra <peterz@infradead.org>
Cc: Stephane Eranian <eranian@google.com>
Link: https://lore.kernel.org/r/20230126213610.3381147-1-namhyung@kernel.org
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
|
|
In the context of LBR stitching documentation.
Signed-off-by: Ian Rogers <irogers@google.com>
Acked-by: Kan Liang <kan.liang@linux.intel.com>
Cc: Adrian Hunter <adrian.hunter@intel.com>
Cc: Alexander Shishkin <alexander.shishkin@linux.intel.com>
Cc: Ali Saidi <alisaidi@amazon.com>
Cc: Ingo Molnar <mingo@redhat.com>
Cc: James Clark <james.clark@arm.com>
Cc: Jiri Olsa <jolsa@kernel.org>
Cc: Leo Yan <leo.yan@linaro.org>
Cc: Mark Rutland <mark.rutland@arm.com>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: Peter Zijlstra <peterz@infradead.org>
Cc: Ravi Bangoria <ravi.bangoria@amd.com>
Cc: Sandipan Das <sandipan.das@amd.com>
Link: https://lore.kernel.org/r/20230119201036.156441-1-irogers@google.com
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
|
|
Move common guest options into include files. Use attribute substitution to
customize an example, using "[verse]" to define the block instead of a
"literal" block which does not permit substitution.
Signed-off-by: Adrian Hunter <adrian.hunter@intel.com>
Cc: Ian Rogers <irogers@google.com>
Cc: Jiri Olsa <jolsa@kernel.org>
Cc: Namhyung Kim <namhyung@kernel.org>
Link: https://lore.kernel.org/r/20220811170411.84154-4-adrian.hunter@intel.com
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
|
|
The 'perf script' documentation is missing several options relating to
guests. Add them.
Fixes: 15a108af1a18b597 ("perf script: Allow specifying the files to process guest samples")
Signed-off-by: Adrian Hunter <adrian.hunter@intel.com>
Cc: Ian Rogers <irogers@google.com>
Cc: Jiri Olsa <jolsa@kernel.org>
Cc: Namhyung Kim <namhyung@kernel.org>
Link: https://lore.kernel.org/r/20220811170411.84154-2-adrian.hunter@intel.com
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
|
|
Amend "perf insert" to "perf inject".
Fixes: e28fb159f1163e76 ("perf script: Add machine_pid and vcpu")
Signed-off-by: Adrian Hunter <adrian.hunter@intel.com>
Acked-by: Ian Rogers <irogers@google.com>
Cc: Adrian Hunter <adrian.hunter@intel.com>
Cc: Jiri Olsa <jolsa@kernel.org>
Cc: Namhyung Kim <namhyung@kernel.org>
Link: https://lore.kernel.org/r/20220809123258.9086-1-adrian.hunter@intel.com
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
|
|
Add fields machine_pid and vcpu. These are displayed only if machine_pid is
non-zero.
Signed-off-by: Adrian Hunter <adrian.hunter@intel.com>
Cc: Andi Kleen <ak@linux.intel.com>
Cc: Ian Rogers <irogers@google.com>
Cc: Jiri Olsa <jolsa@kernel.org>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: kvm@vger.kernel.org
Link: https://lore.kernel.org/r/20220711093218.10967-16-adrian.hunter@intel.com
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
|
|
When reviewing the results of perf inject, it is useful to be able to see
the events in the order they appear in the file.
So add --dump-unsorted-raw-trace option to do an unsorted dump.
Signed-off-by: Adrian Hunter <adrian.hunter@intel.com>
Acked-by: Ian Rogers <irogers@google.com>
Cc: Andi Kleen <ak@linux.intel.com>
Cc: Jiri Olsa <jolsa@kernel.org>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: kvm@vger.kernel.org
Link: https://lore.kernel.org/r/20220711093218.10967-8-adrian.hunter@intel.com
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
|
|
Add an option to indicate that guest code can be found in the hypervisor
process.
Signed-off-by: Adrian Hunter <adrian.hunter@intel.com>
Cc: Andi Kleen <ak@linux.intel.com>
Cc: Ian Rogers <irogers@google.com>
Cc: Jiri Olsa <jolsa@kernel.org>
Cc: Leo Yan <leo.yan@linaro.org>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: kvm@vger.kernel.org
Link: https://lore.kernel.org/r/20220517131011.6117-5-adrian.hunter@intel.com
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
|
|
When analyzing with 'perf script', it's useful to understand the
captured instruction and the next sequential instruction.
To calculate the address of the next sequential instruction, the length
of the captured instruction is required.
For example, you can’t know the next sequential instruction after an
unconditional branch unless you calculate that based on its length.
For branch stacks, 'perf script' only prints the instruction bytes with
'brstackinsn', but lacks the instruction length.
Add 'brstackinsnlen' to print the instruction length.
$ perf script -F ip,brstackinsn,brstackinsnlen --xed
7fa555be8f75
_start:
00007fa555be8090 mov %rsp, %rdi ilen: 3
00007fa555be8093 callq 0x7fa555be8ea0 ilen: 5 # PRED 102 cycles [102] 0.02 IPC
_dl_start+38:
00007fa555be8ec6 movq %rdx,0x227853(%rip) ilen: 7
00007fa555be8ecd leaq 0x227f94(%rip),%rdx ilen: 7
Signed-off-by: Kan Liang <kan.liang@linux.intel.com>
Cc: Ahmad Yasin <ahmad.yasin@intel.com>
Cc: Andi Kleen <ak@linux.intel.com>
Cc: Ingo Molnar <mingo@redhat.com>
Cc: Jiri Olsa <jolsa@kernel.org>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: Peter Zijlstra <peterz@infradead.org>
Cc: Xing Zhengjun <zhengjun.xing@linux.intel.com>
Link: https://lore.kernel.org/r/1647871212-184070-1-git-send-email-kan.liang@linux.intel.com
[ Added the new field to tools/perf/Documentation/perf-script.txt ]
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
|
|
Amend the display to include D and t flags in the same way as the x flag.
Signed-off-by: Adrian Hunter <adrian.hunter@intel.com>
Cc: Alexander Shishkin <alexander.shishkin@linux.intel.com>
Cc: Andi Kleen <ak@linux.intel.com>
Cc: Jiri Olsa <jolsa@redhat.com>
Link: https://lore.kernel.org/r/20220124084201.2699795-21-adrian.hunter@intel.com
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
|
|
The instruction latency information can be recorded on
some platforms, e.g., the Intel Sapphire Rapids server. With both memory
latency (weight) and the new instruction latency information, users can
easily locate the expensive load instructions, and also understand the time
spent in different stages. The users can optimize their applications in
different pipeline stages.
Add a new field "ins_lat" to filter the instruction latency information,
which is available with sample type PERF_SAMPLE_WEIGHT_STRUCT.
Signed-off-by: Kan Liang <kan.liang@linux.intel.com>
Cc: Andi Kleen <ak@linux.intel.com>
Cc: Jiri Olsa <jolsa@redhat.com>
Cc: Joe Mario <jmario@redhat.com>
Link: https://lore.kernel.org/r/1632929894-102778-2-git-send-email-kan.liang@linux.intel.com
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
|
|
The option --list-dlfilters does use a string value.
Signed-off-by: Adrian Hunter <adrian.hunter@intel.com>
Cc: Jiri Olsa <jolsa@redhat.com>
Fixes: 638e2b9984ee1b ("perf script Add option to list dlfilters")
Link: https //lore.kernel.org/r/20210811101036.17986-4-adrian.hunter@intel.com
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
|
|
Add option --dlarg to pass arguments to dlfilters. The --dlarg option can
be repeated to pass more than 1 argument.
Signed-off-by: Adrian Hunter <adrian.hunter@intel.com>
Cc: Andi Kleen <ak@linux.intel.com>
Cc: Ingo Molnar <mingo@redhat.com>
Cc: Jiri Olsa <jolsa@redhat.com>
Cc: Kan Liang <kan.liang@linux.intel.com>
Cc: Leo Yan <leo.yan@linaro.org>
Cc: Mark Rutland <mark.rutland@arm.com>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: Peter Zijlstra <peterz@infradead.org>
Link: https://lore.kernel.org/r/20210627131818.810-5-adrian.hunter@intel.com
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
|
|
Add option --list-dlfilters to list dlfilters in the current directory or
the exec-path e.g. ~/libexec/perf-core/dlfilters. Use with option -v (must
come before option --list-dlfilters) to show long descriptions.
Signed-off-by: Adrian Hunter <adrian.hunter@intel.com>
Cc: Andi Kleen <ak@linux.intel.com>
Cc: Ingo Molnar <mingo@redhat.com>
Cc: Jiri Olsa <jolsa@redhat.com>
Cc: Kan Liang <kan.liang@linux.intel.com>
Cc: Leo Yan <leo.yan@linaro.org>
Cc: Mark Rutland <mark.rutland@arm.com>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: Peter Zijlstra <peterz@infradead.org>
Link: https://lore.kernel.org/r/20210627131818.810-4-adrian.hunter@intel.com
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
|
|
In some cases, users want to filter very large amounts of data (e.g.
from AUX area tracing like Intel PT) looking for something specific.
While scripting such as Python can be used, Python is 10 to 20 times
slower than C. So define a C API so that custom filters can be written
and loaded.
Signed-off-by: Adrian Hunter <adrian.hunter@intel.com>
Cc: Andi Kleen <ak@linux.intel.com>
Cc: Ingo Molnar <mingo@redhat.com>
Cc: Jiri Olsa <jolsa@redhat.com>
Cc: Kan Liang <kan.liang@linux.intel.com>
Cc: Leo Yan <leo.yan@linaro.org>
Cc: Mark Rutland <mark.rutland@arm.com>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: Peter Zijlstra <peterz@infradead.org>
Link: https://lore.kernel.org/r/20210627131818.810-2-adrian.hunter@intel.com
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
|
|
Add 'g' (guest) for VM-Entry and 'h' (host) for VM-Exit.
Fixes: c025d46cd932c ("perf script: Add branch types for VM-Entry and VM-Exit")
Signed-off-by: Adrian Hunter <adrian.hunter@intel.com>
Cc: Jiri Olsa <jolsa@redhat.com>
Link: http://lore.kernel.org/lkml/20210521175127.27264-1-adrian.hunter@intel.com
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
|
|
'perf script' supports '-S' or '--symbol' options to only list the
records for these symbols. A symbol is typically a name or hex address.
If it's hex address, it is the start address of one symbol.
While it would be useful if we can filter trace records by any hex
address (not only the start address of symbol). So now we support
filtering trace records by more conditions, such as:
- symbol name
- start address of symbol
- any hexadecimal address
- address range
The comparison order is defined as:
1. symbol name comparison
2. symbol start address comparison.
3. any hexadecimal address comparison.
4. address range comparison.
The idea is if we can get a valid address from -S list, we add the
address to addr_list for address comparison otherwise we still leave
it to sym_list for symbol comparison.
Some examples:
root@kbl-ppc:~# ./perf script -S ffffffff9a477308
perf 8562 [000] 347303.578858: 1 cycles: ffffffff9a477308 native_write_msr+0x8 ([kernel.kallsyms])
perf 8562 [000] 347303.578860: 1 cycles: ffffffff9a477308 native_write_msr+0x8 ([kernel.kallsyms])
perf 8562 [000] 347303.578861: 11 cycles: ffffffff9a477308 native_write_msr+0x8 ([kernel.kallsyms])
perf 8562 [001] 347303.578903: 1 cycles: ffffffff9a477308 native_write_msr+0x8 ([kernel.kallsyms])
perf 8562 [001] 347303.578905: 1 cycles: ffffffff9a477308 native_write_msr+0x8 ([kernel.kallsyms])
perf 8562 [001] 347303.578906: 15 cycles: ffffffff9a477308 native_write_msr+0x8 ([kernel.kallsyms])
perf 8562 [002] 347303.578952: 1 cycles: ffffffff9a477308 native_write_msr+0x8 ([kernel.kallsyms])
perf 8562 [002] 347303.578953: 1 cycles: ffffffff9a477308 native_write_msr+0x8 ([kernel.kallsyms])
Filter the traced records by hex address ffffffff9a477308.
root@kbl-ppc:~# ./perf script -S ffffffff9a4dd4ce,ffffffff9a4d2de9,ffffffff9a6bf9f4
perf 8562 [001] 347303.578911: 311706 cycles: ffffffff9a6bf9f4 __kmalloc_node+0x204 ([kernel.kallsyms])
perf 8562 [002] 347303.578960: 354477 cycles: ffffffff9a4d2de9 sched_setaffinity+0x49 ([kernel.kallsyms])
perf 8562 [003] 347303.579015: 450958 cycles: ffffffff9a4dd4ce dequeue_task_fair+0x1ae ([kernel.kallsyms])
Filter the traced records by hex address ffffffff9a4dd4ce, ffffffff9a4d2de9, ffffffff9a6bf9f4.
root@kbl-ppc:~# ./perf script -S ffffffff9a477309 --addr-range 16
perf 8562 [000] 347303.578863: 291 cycles: ffffffff9a47730a native_write_msr+0xa ([kernel.kallsyms])
perf 8562 [001] 347303.578907: 411 cycles: ffffffff9a47730a native_write_msr+0xa ([kernel.kallsyms])
perf 8562 [002] 347303.578956: 462 cycles: ffffffff9a47730f native_write_msr+0xf ([kernel.kallsyms])
perf 8562 [003] 347303.579010: 497 cycles: ffffffff9a47730f native_write_msr+0xf ([kernel.kallsyms])
perf 8562 [004] 347303.579059: 429 cycles: ffffffff9a47730f native_write_msr+0xf ([kernel.kallsyms])
perf 8562 [005] 347303.579109: 408 cycles: ffffffff9a47730a native_write_msr+0xa ([kernel.kallsyms])
perf 8562 [006] 347303.579159: 460 cycles: ffffffff9a47730f native_write_msr+0xf ([kernel.kallsyms])
perf 8562 [007] 347303.579213: 436 cycles: ffffffff9a47730f native_write_msr+0xf ([kernel.kallsyms])
Filter the traced records from address range [ffffffff9a477309, ffffffff9a477309 + 15].
root@kbl-ppc:~# ./perf script -S "ffffffff9b163046,rcu_nmi_exit"
perf 8562 [004] 347303.579060: 12013 cycles: ffffffff9b163046 exc_nmi+0x166 ([kernel.kallsyms])
perf 8562 [007] 347303.579214: 12138 cycles: ffffffff9b165944 rcu_nmi_exit+0x34 ([kernel.kallsyms])
Filter by address + symbol
Signed-off-by: Jin Yao <yao.jin@linux.intel.com>
Tested-by: Arnaldo Carvalho de Melo <acme@redhat.com>
Cc: Alexander Shishkin <alexander.shishkin@linux.intel.com>
Cc: Andi Kleen <ak@linux.intel.com>
Cc: Jin Yao <yao.jin@intel.com>
Cc: Jiri Olsa <jolsa@kernel.org>
Cc: Kan Liang <kan.liang@linux.intel.com>
Cc: Peter Zijlstra <peterz@infradead.org>
Link: http://lore.kernel.org/lkml/20210207080935.31784-2-yao.jin@linux.intel.com
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
|
|
Other perf tool builtins already supported a DSO filter.
For example:
$ perf report --dsos a,b,c
which only considers symbols in these dsos.
Now the DSO filter is supported in 'perf script':
root@kbl-ppc:~# ./perf script --dsos "[kernel.kallsyms]"
perf 18123 [000] 6142863.075104: 1 cycles: ffffffff9ca77308 native_write_msr+0x8 ([kernel.kallsyms])
perf 18123 [000] 6142863.075107: 1 cycles: ffffffff9ca77308 native_write_msr+0x8 ([kernel.kallsyms])
perf 18123 [000] 6142863.075108: 10 cycles: ffffffff9ca77308 native_write_msr+0x8 ([kernel.kallsyms])
perf 18123 [000] 6142863.075109: 273 cycles: ffffffff9ca7730a native_write_msr+0xa ([kernel.kallsyms])
perf 18123 [000] 6142863.075110: 7684 cycles: ffffffff9ca3c9c0 native_sched_clock+0x50 ([kernel.kallsyms])
perf 18123 [000] 6142863.075112: 213017 cycles: ffffffff9d765a92 syscall_exit_to_user_mode+0x32 ([kernel.kallsyms])
perf 18123 [001] 6142863.075156: 1 cycles: ffffffff9ca77308 native_write_msr+0x8 ([kernel.kallsyms])
perf 18123 [001] 6142863.075158: 1 cycles: ffffffff9ca77308 native_write_msr+0x8 ([kernel.kallsyms])
perf 18123 [001] 6142863.075159: 17 cycles: ffffffff9ca77308 native_write_msr+0x8 ([kernel.kallsyms])
Committer testing:
$ perf script
ls 2364888 29303.010949: 1 cycles:u: ffffffffa4bbc6a9 [unknown] ([unknown])
ls 2364888 29303.010957: 1 cycles:u: ffffffffa429ef48 [unknown] ([unknown])
ls 2364888 29303.010961: 1 cycles:u: ffffffffa4260133 [unknown] ([unknown])
ls 2364888 29303.010964: 5 cycles:u: ffffffffa429efad [unknown] ([unknown])
ls 2364888 29303.010967: 41 cycles:u: ffffffffa42a4586 [unknown] ([unknown])
ls 2364888 29303.010972: 435 cycles:u: ffffffffa429efe0 [unknown] ([unknown])
ls 2364888 29303.010978: 5142 cycles:u: 7f9b95bc2abf __GI___tunables_init+0x11f (/usr/lib64/ld-2.32.so)
ls 2364888 29303.011006: 38551 cycles:u: ffffffffa4290f61 [unknown] ([unknown])
ls 2364888 29303.011486: 238234 cycles:u: 7f9b95bb7741 _dl_relocate_object+0xa71 (/usr/lib64/ld-2.32.so)
ls 2364888 29303.011937: 415870 cycles:u: 7f9b95a1c80e __strcoll_l+0xe (/usr/lib64/libc-2.32.so)
$
Before:
$ perf script --dsos /usr/lib64/libc-2.32.so |& head -5
Error: unknown option `dsos'
Usage: perf script [<options>]
or: perf script [<options>] record <script> [<record-options>] <command>
or: perf script [<options>] report <script> [script-args]
$
After:
$ perf script --dsos /usr/lib64/libc-2.32.so
ls 2364888 29303.011937: 415870 cycles:u: 7f9b95a1c80e __strcoll_l+0xe (/usr/lib64/libc-2.32.so)
$
Signed-off-by: Jin Yao <yao.jin@linux.intel.com>
Acked-by: Jiri Olsa <jolsa@kernel.org>
Tested-by: Arnaldo Carvalho de Melo <acme@redhat.com>
Cc: Alexander Shishkin <alexander.shishkin@linux.intel.com>
Cc: Andi Kleen <ak@linux.intel.com>
Cc: Jin Yao <yao.jin@intel.com>
Cc: Kan Liang <kan.liang@linux.intel.com>
Cc: Peter Zijlstra <peterz@infradead.org>
Link: http://lore.kernel.org/lkml/20210124232750.19170-2-yao.jin@linux.intel.com
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
|
|
Display sampled code page sizes when PERF_SAMPLE_CODE_PAGE_SIZE was set.
For example:
# perf script --fields comm,event,ip,code_page_size
dtlb mem-loads:uP: 445777 4K
dtlb mem-loads:uP: 40f724 4K
dtlb mem-loads:uP: 474926 4K
dtlb mem-loads:uP: 401075 4K
dtlb mem-loads:uP: 401095 4K
dtlb mem-loads:uP: 401095 4K
dtlb mem-loads:uP: 4010cc 4K
dtlb mem-loads:uP: 440b6f 4K
#
Signed-off-by: Stephane Eranian <eranian@google.com>
Acked-by: Jiri Olsa <jolsa@redhat.com>
Acked-by: Namhyung Kim <namhyung@kernel.org>
Cc: Andi Kleen <ak@linux.intel.com>
Cc: Ingo Molnar <mingo@kernel.org>
Cc: Mark Rutland <mark.rutland@arm.com>
Cc: Michael Ellerman <mpe@ellerman.id.au>
Cc: Will Deacon <will@kernel.org>
Link: https://lore.kernel.org/r/20210105195752.43489-5-kan.liang@linux.intel.com
Signed-off-by: Kan Liang <kan.liang@linux.intel.com>
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
|
|
Display the data page size if it is available and asked by the user:
Can be configured by the user, for example:
perf script --fields comm,event,phys_addr,data_page_size
dtlb mem-loads:uP: 3fec82ea8 4K
dtlb mem-loads:uP: 3fec82e90 4K
dtlb mem-loads:uP: 3e23700a4 4K
dtlb mem-loads:uP: 3fec82f20 4K
dtlb mem-loads:uP: 3e23700a4 4K
dtlb mem-loads:uP: 3b4211bec 4K
dtlb mem-loads:uP: 382205dc0 2M
dtlb mem-loads:uP: 36fa082c0 2M
dtlb mem-loads:uP: 377607340 2M
dtlb mem-loads:uP: 330010180 2M
dtlb mem-loads:uP: 33200fd80 2M
dtlb mem-loads:uP: 31b012b80 2M
Signed-off-by: Kan Liang <kan.liang@linux.intel.com>
Acked-by: Jiri Olsa <jolsa@redhat.com>
Acked-by: Namhyung Kim <namhyung@kernel.org>
Cc: Andi Kleen <ak@linux.intel.com>
Cc: Mark Rutland <mark.rutland@arm.com>
Cc: Michael Ellerman <mpe@ellerman.id.au>
Cc: Stephane Eranian <eranian@google.com>
Cc: Will Deacon <will@kernel.org>
Link: http://lore.kernel.org/lkml/20201216185805.9981-2-kan.liang@linux.intel.com
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
|
|
Consistent with other new events, add an option to perf script to
display text poke events and ksymbol events. Both text poke events and
ksymbol events are displayed because some text pokes (e.g. ftrace
trampolines) have corresponding ksymbol events.
Signed-off-by: Adrian Hunter <adrian.hunter@intel.com>
Cc: Alexander Shishkin <alexander.shishkin@linux.intel.com>
Cc: Borislav Petkov <bp@alien8.de>
Cc: H. Peter Anvin <hpa@zytor.com>
Cc: Jiri Olsa <jolsa@redhat.com>
Cc: Leo Yan <leo.yan@linaro.org>
Cc: Mark Rutland <mark.rutland@arm.com>
Cc: Masami Hiramatsu <mhiramat@kernel.org>
Cc: Mathieu Poirier <mathieu.poirier@linaro.org>
Cc: Peter Zijlstra <peterz@infradead.org>
Cc: Steven Rostedt (VMware) <rostedt@goodmis.org>
Cc: x86@kernel.org
Link: http://lore.kernel.org/lkml/20200512121922.8997-15-adrian.hunter@intel.com
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
|
|
With the LBR stitching approach, the reconstructed LBR call stack can
break the HW limitation. However, it may reconstruct invalid call stacks
in some cases, e.g. exception handing such as setjmp/longjmp. Also, it
may impact the processing time especially when the number of samples
with stitched LBRs are huge.
Add an option to enable the approach.
Committer testing:
Using the same perf.data as with the latest cset committer testing
section:
$ perf script --stitch-lbr
<SNIP>
tchain_edit 11131 15164.984292: 437491 cycles:u:
401106 f43+0x0 (/wb/tchain_edit)
40114c f42+0x18 (/wb/tchain_edit)
401172 f41+0xe (/wb/tchain_edit)
401194 f40+0x0 (/wb/tchain_edit)
40119b f39+0x0 (/wb/tchain_edit)
4011a2 f38+0x0 (/wb/tchain_edit)
4011a9 f37+0x0 (/wb/tchain_edit)
4011b0 f36+0x0 (/wb/tchain_edit)
4011b7 f35+0x0 (/wb/tchain_edit)
4011be f34+0x0 (/wb/tchain_edit)
4011c5 f33+0x0 (/wb/tchain_edit)
4011cc f32+0x0 (/wb/tchain_edit)
401207 f31+0x34 (/wb/tchain_edit)
401212 f30+0x0 (/wb/tchain_edit)
401219 f29+0x0 (/wb/tchain_edit)
401220 f28+0x0 (/wb/tchain_edit)
401227 f27+0x0 (/wb/tchain_edit)
40122e f26+0x0 (/wb/tchain_edit)
401235 f25+0x0 (/wb/tchain_edit)
40123c f24+0x0 (/wb/tchain_edit)
401243 f23+0x0 (/wb/tchain_edit)
40124a f22+0x0 (/wb/tchain_edit)
401251 f21+0x0 (/wb/tchain_edit)
401258 f20+0x0 (/wb/tchain_edit)
40125f f19+0x0 (/wb/tchain_edit)
401266 f18+0x0 (/wb/tchain_edit)
40126d f17+0x0 (/wb/tchain_edit)
401274 f16+0x0 (/wb/tchain_edit)
40127b f15+0x0 (/wb/tchain_edit)
401282 f14+0x0 (/wb/tchain_edit)
401289 f13+0x0 (/wb/tchain_edit)
401290 f12+0x0 (/wb/tchain_edit)
401297 f11+0x0 (/wb/tchain_edit)
40129e f10+0x0 (/wb/tchain_edit)
4012a5 f9+0x0 (/wb/tchain_edit)
4012ac f8+0x0 (/wb/tchain_edit)
4012b3 f7+0x0 (/wb/tchain_edit)
4012ba f6+0x0 (/wb/tchain_edit)
4012c1 f5+0x0 (/wb/tchain_edit)
4012c8 f4+0x0 (/wb/tchain_edit)
4012cf f3+0x0 (/wb/tchain_edit)
4012d6 f2+0x0 (/wb/tchain_edit)
4012dd f1+0x0 (/wb/tchain_edit)
4012e4 main+0x0 (/wb/tchain_edit)
7f41a5016f41 __libc_start_main+0xf1 (/usr/lib64/libc-2.29.so)
<SNIP>
$
Signed-off-by: Kan Liang <kan.liang@linux.intel.com>
Reviewed-by: Andi Kleen <ak@linux.intel.com>
Acked-by: Jiri Olsa <jolsa@redhat.com>
Tested-by: Arnaldo Carvalho de Melo <acme@redhat.com>
Cc: Adrian Hunter <adrian.hunter@intel.com>
Cc: Alexey Budankov <alexey.budankov@linux.intel.com>
Cc: Mathieu Poirier <mathieu.poirier@linaro.org>
Cc: Michael Ellerman <mpe@ellerman.id.au>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: Pavel Gerasimov <pavel.gerasimov@intel.com>
Cc: Peter Zijlstra <peterz@infradead.org>
Cc: Ravi Bangoria <ravi.bangoria@linux.ibm.com>
Cc: Stephane Eranian <eranian@google.com>
Cc: Vitaly Slobodskoy <vitaly.slobodskoy@intel.com>
Link: http://lore.kernel.org/lkml/20200319202517.23423-15-kan.liang@linux.intel.com
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
|
|
Capture both that this option exists and that symbols can be hexadecimal
addresses.
Signed-off-by: Ian Rogers <irogers@google.com>
Suggested-by: Arnaldo Carvalho de Melo <acme@redhat.com>
Cc: Alexander Shishkin <alexander.shishkin@linux.intel.com>
Cc: Jiri Olsa <jolsa@redhat.com>
Cc: Mark Rutland <mark.rutland@arm.com>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: Peter Zijlstra <peterz@infradead.org>
Cc: Stephane Eranian <eranian@google.com>
Link: http://lore.kernel.org/lkml/20200402174130.140319-1-irogers@google.com
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
|
|
The --show-cgroup-events option is to print CGROUP events in the
output like others.
Committer testing:
[root@seventh ~]# perf record --all-cgroups --namespaces /wb/cgtest
[ perf record: Woken up 1 times to write data ]
[ perf record: Captured and wrote 0.039 MB perf.data (487 samples) ]
[root@seventh ~]# perf script --show-cgroup-events | grep PERF_RECORD_CGROUP -B2 -A2
swapper 0 0.000000: PERF_RECORD_CGROUP cgroup: 1 /
perf 12145 11200.440730: 1 cycles: ffffffffb900d58b __intel_pmu_enable_all.constprop.0+0x3b (/lib/modules/5.6.0-rc6-00008-gfe2413eefd7f/build/vmlinux)
perf 12145 11200.440733: 1 cycles: ffffffffb900d58b __intel_pmu_enable_all.constprop.0+0x3b (/lib/modules/5.6.0-rc6-00008-gfe2413eefd7f/build/vmlinux)
--
cgtest 12145 11200.440739: 193472 cycles: ffffffffb90f6fbc commit_creds+0x1fc (/lib/modules/5.6.0-rc6-00008-gfe2413eefd7f/build/vmlinux)
cgtest 12145 11200.440790: 2691608 cycles: 7fa2cb43019b _dl_sysdep_start+0x7cb (/usr/lib64/ld-2.29.so)
cgtest 12145 11200.440962: PERF_RECORD_CGROUP cgroup: 83 /sub
cgtest 12147 11200.441054: 1 cycles: ffffffffb900d58b __intel_pmu_enable_all.constprop.0+0x3b (/lib/modules/5.6.0-rc6-00008-gfe2413eefd7f/build/vmlinux)
cgtest 12147 11200.441057: 1 cycles: ffffffffb900d58b __intel_pmu_enable_all.constprop.0+0x3b (/lib/modules/5.6.0-rc6-00008-gfe2413eefd7f/build/vmlinux)
--
cgtest 12148 11200.441103: 10227 cycles: ffffffffb9a0153d end_repeat_nmi+0x48 (/lib/modules/5.6.0-rc6-00008-gfe2413eefd7f/build/vmlinux)
cgtest 12148 11200.441106: 273295 cycles: ffffffffb99ecbc7 copy_page+0x7 (/lib/modules/5.6.0-rc6-00008-gfe2413eefd7f/build/vmlinux)
cgtest 12147 11200.441133: PERF_RECORD_CGROUP cgroup: 88 /sub/cgrp1
cgtest 12147 11200.441143: 2788845 cycles: ffffffffb94676c2 security_genfs_sid+0x102 (/lib/modules/5.6.0-rc6-00008-gfe2413eefd7f/build/vmlinux)
cgtest 12148 11200.441162: PERF_RECORD_CGROUP cgroup: 93 /sub/cgrp2
cgtest 12148 11200.441182: 2669546 cycles: 401020 _init+0x20 (/wb/cgtest)
cgtest 12149 11200.441247: 1 cycles: ffffffffb900d58b __intel_pmu_enable_all.constprop.0+0x3b (/lib/modules/5.6.0-rc6-00008-gfe2413eefd7f/build/vmlinux)
[root@seventh ~]#
Signed-off-by: Namhyung Kim <namhyung@kernel.org>
Tested-by: Arnaldo Carvalho de Melo <acme@redhat.com>
Cc: Alexander Shishkin <alexander.shishkin@linux.intel.com>
Cc: Jiri Olsa <jolsa@redhat.com>
Cc: Mark Rutland <mark.rutland@arm.com>
Cc: Peter Zijlstra <peterz@infradead.org>
Link: http://lore.kernel.org/lkml/20200325124536.2800725-10-namhyung@kernel.org
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
|
|
For some kind of analysis a deltatime output is more human friendly and
reduce the cognitive load for further analysis.
The following output demonstrate the new option "deltatime": calculate
the time difference in relation to the previous event.
$ perf script --deltatime
test 2525 [001] 0.000000: sdt_libev:ev_add: (5635e72a5ebd)
test 2525 [001] 0.000091: sdt_libev:epoll_wait_enter: (5635e72a76a9)
test 2525 [001] 1.000051: sdt_libev:epoll_wait_return: (5635e72a772e) arg1=1
test 2525 [001] 0.000685: sdt_libev:ev_add: (5635e72a5ebd)
test 2525 [001] 0.000048: sdt_libev:epoll_wait_enter: (5635e72a76a9)
test 2525 [001] 1.000104: sdt_libev:epoll_wait_return: (5635e72a772e) arg1=1
test 2525 [001] 0.003895: sdt_libev:epoll_wait_enter: (5635e72a76a9)
test 2525 [001] 0.996034: sdt_libev:epoll_wait_return: (5635e72a772e) arg1=1
test 2525 [001] 0.000058: sdt_libev:epoll_wait_enter: (5635e72a76a9)
test 2525 [001] 1.000004: sdt_libev:epoll_wait_return: (5635e72a772e) arg1=1
test 2525 [001] 0.000064: sdt_libev:epoll_wait_enter: (5635e72a76a9)
test 2525 [001] 0.999934: sdt_libev:epoll_wait_return: (5635e72a772e) arg1=1
test 2525 [001] 0.000056: sdt_libev:epoll_wait_enter: (5635e72a76a9)
test 2525 [001] 0.999930: sdt_libev:epoll_wait_return: (5635e72a772e) arg1=1
Committer testing:
So go from default output to --reltime and then this new --deltatime, to
contrast the various timestamp presentation modes for a random perf.data file I
had laying around:
[root@five ~]# perf script --reltime | head
perf 442394 [000] 0.000000: 16 cycles: ffffffff9706e544 native_write_msr+0x4 (/usr/lib/debug/lib/modules/5.5.10-200.fc31.x86_64/vmlinux)
perf 442394 [000] 0.000002: 16 cycles: ffffffff9706e544 native_write_msr+0x4 (/usr/lib/debug/lib/modules/5.5.10-200.fc31.x86_64/vmlinux)
perf 442394 [000] 0.000004: 16 cycles: ffffffff9706e544 native_write_msr+0x4 (/usr/lib/debug/lib/modules/5.5.10-200.fc31.x86_64/vmlinux)
perf 442394 [000] 0.000006: 128 cycles: ffffffff972415a1 perf_event_update_userpage+0x1 (/usr/lib/debug/lib/modules/5.5.10-200.fc31.x86_64/vmlinux)
perf 442394 [000] 0.000009: 2597 cycles: ffffffff97463785 cap_task_setscheduler+0x5 (/usr/lib/debug/lib/modules/5.5.10-200.fc31.x86_64/vmlinux)
perf 442394 [001] 0.000036: 16 cycles: ffffffff9706e544 native_write_msr+0x4 (/usr/lib/debug/lib/modules/5.5.10-200.fc31.x86_64/vmlinux)
perf 442394 [001] 0.000038: 16 cycles: ffffffff9706e544 native_write_msr+0x4 (/usr/lib/debug/lib/modules/5.5.10-200.fc31.x86_64/vmlinux)
perf 442394 [001] 0.000040: 16 cycles: ffffffff9706e544 native_write_msr+0x4 (/usr/lib/debug/lib/modules/5.5.10-200.fc31.x86_64/vmlinux)
perf 442394 [001] 0.000041: 224 cycles: ffffffff9700a53a perf_ibs_handle_irq+0x1da (/usr/lib/debug/lib/modules/5.5.10-200.fc31.x86_64/vmlinux)
perf 442394 [001] 0.000044: 4439 cycles: ffffffff97120d85 put_prev_entity+0x45 (/usr/lib/debug/lib/modules/5.5.10-200.fc31.x86_64/vmlinux)
[root@five ~]# perf script --deltatime | head
perf 442394 [000] 0.000000: 16 cycles: ffffffff9706e544 native_write_msr+0x4 (/usr/lib/debug/lib/modules/5.5.10-200.fc31.x86_64/vmlinux)
perf 442394 [000] 0.000002: 16 cycles: ffffffff9706e544 native_write_msr+0x4 (/usr/lib/debug/lib/modules/5.5.10-200.fc31.x86_64/vmlinux)
perf 442394 [000] 0.000001: 16 cycles: ffffffff9706e544 native_write_msr+0x4 (/usr/lib/debug/lib/modules/5.5.10-200.fc31.x86_64/vmlinux)
perf 442394 [000] 0.000001: 128 cycles: ffffffff972415a1 perf_event_update_userpage+0x1 (/usr/lib/debug/lib/modules/5.5.10-200.fc31.x86_64/vmlinux)
perf 442394 [000] 0.000002: 2597 cycles: ffffffff97463785 cap_task_setscheduler+0x5 (/usr/lib/debug/lib/modules/5.5.10-200.fc31.x86_64/vmlinux)
perf 442394 [001] 0.000027: 16 cycles: ffffffff9706e544 native_write_msr+0x4 (/usr/lib/debug/lib/modules/5.5.10-200.fc31.x86_64/vmlinux)
perf 442394 [001] 0.000002: 16 cycles: ffffffff9706e544 native_write_msr+0x4 (/usr/lib/debug/lib/modules/5.5.10-200.fc31.x86_64/vmlinux)
perf 442394 [001] 0.000001: 16 cycles: ffffffff9706e544 native_write_msr+0x4 (/usr/lib/debug/lib/modules/5.5.10-200.fc31.x86_64/vmlinux)
perf 442394 [001] 0.000001: 224 cycles: ffffffff9700a53a perf_ibs_handle_irq+0x1da (/usr/lib/debug/lib/modules/5.5.10-200.fc31.x86_64/vmlinux)
perf 442394 [001] 0.000002: 4439 cycles: ffffffff97120d85 put_prev_entity+0x45 (/usr/lib/debug/lib/modules/5.5.10-200.fc31.x86_64/vmlinux)
[root@five ~]# perf script | head
perf 442394 [000] 7600.157861: 16 cycles: ffffffff9706e544 native_write_msr+0x4 (/usr/lib/debug/lib/modules/5.5.10-200.fc31.x86_64/vmlinux)
perf 442394 [000] 7600.157864: 16 cycles: ffffffff9706e544 native_write_msr+0x4 (/usr/lib/debug/lib/modules/5.5.10-200.fc31.x86_64/vmlinux)
perf 442394 [000] 7600.157866: 16 cycles: ffffffff9706e544 native_write_msr+0x4 (/usr/lib/debug/lib/modules/5.5.10-200.fc31.x86_64/vmlinux)
perf 442394 [000] 7600.157867: 128 cycles: ffffffff972415a1 perf_event_update_userpage+0x1 (/usr/lib/debug/lib/modules/5.5.10-200.fc31.x86_64/vmlinux)
perf 442394 [000] 7600.157870: 2597 cycles: ffffffff97463785 cap_task_setscheduler+0x5 (/usr/lib/debug/lib/modules/5.5.10-200.fc31.x86_64/vmlinux)
perf 442394 [001] 7600.157897: 16 cycles: ffffffff9706e544 native_write_msr+0x4 (/usr/lib/debug/lib/modules/5.5.10-200.fc31.x86_64/vmlinux)
perf 442394 [001] 7600.157900: 16 cycles: ffffffff9706e544 native_write_msr+0x4 (/usr/lib/debug/lib/modules/5.5.10-200.fc31.x86_64/vmlinux)
perf 442394 [001] 7600.157901: 16 cycles: ffffffff9706e544 native_write_msr+0x4 (/usr/lib/debug/lib/modules/5.5.10-200.fc31.x86_64/vmlinux)
perf 442394 [001] 7600.157903: 224 cycles: ffffffff9700a53a perf_ibs_handle_irq+0x1da (/usr/lib/debug/lib/modules/5.5.10-200.fc31.x86_64/vmlinux)
perf 442394 [001] 7600.157906: 4439 cycles: ffffffff97120d85 put_prev_entity+0x45 (/usr/lib/debug/lib/modules/5.5.10-200.fc31.x86_64/vmlinux)
[root@five ~]#
Andi suggested we better implement it as a new field, i.e. -F deltatime, like:
[root@five ~]# perf script -F deltatime
Invalid field requested.
Usage: perf script [<options>]
or: perf script [<options>] record <script> [<record-options>] <command>
or: perf script [<options>] report <script> [script-args]
or: perf script [<options>] <script> [<record-options>] <command>
or: perf script [<options>] <top-script> [script-args]
-F, --fields <str> comma separated output fields prepend with 'type:'. +field to add and -field to remove.Valid types: hw,sw,trace,raw,synth. Fields: comm,tid,pid,time,cpu,event,trace,ip,sym,dso,addr,symoff,srcline,period,iregs,uregs,brstack,brstacksym,flags,bpf-output,brstackinsn,brstackoff,callindent,insn,insnlen,synth,phys_addr,metric,misc,ipc
[root@five ~]#
I.e. we have -F for maximum flexibility:
[root@five ~]# perf script -F comm,pid,cpu,time | head
perf 442394 [000] 7600.157861:
perf 442394 [000] 7600.157864:
perf 442394 [000] 7600.157866:
perf 442394 [000] 7600.157867:
perf 442394 [000] 7600.157870:
perf 442394 [001] 7600.157897:
perf 442394 [001] 7600.157900:
perf 442394 [001] 7600.157901:
perf 442394 [001] 7600.157903:
perf 442394 [001] 7600.157906:
[root@five ~]#
But since we already have --reltime, having --deltatime, documented one after
the other is sensible.
Signed-off-by: Hagen Paul Pfeifer <hagen@jauu.net>
Tested-by: Arnaldo Carvalho de Melo <acme@redhat.com>
Cc: Adrian Hunter <adrian.hunter@intel.com>
Cc: Andi Kleen <ak@linux.intel.com>
Cc: Jiri Olsa <jolsa@kernel.org>
Link: http://lore.kernel.org/lkml/20200204173709.489161-1-hagen@jauu.net
[ Added 'perf script' man page entry for --deltatime ]
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
|
|
Add references to Intel PT man page in man pages of associated tools.
Signed-off-by: Adrian Hunter <adrian.hunter@intel.com>
Tested-by: Arnaldo Carvalho de Melo <acme@redhat.com>
Cc: Andi Kleen <ak@linux.intel.com>
Cc: Jiri Olsa <jolsa@redhat.com>
Link: http://lore.kernel.org/lkml/20200311122034.3697-3-adrian.hunter@intel.com
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
|
|
Counterpart of --switch-on:
# perf record -e sched:*,syscalls:sys_*_nanosleep sleep 1
[ perf record: Woken up 36 times to write data ]
[ perf record: Captured and wrote 0.032 MB perf.data (10 samples) ]
#
# perf script
:20918 20918 [002] 109866.143696: sched:sched_waking: comm=perf pid=20919 prio=120 target_cpu=001
:20918 20918 [002] 109866.143702: sched:sched_wakeup: perf:20919 [120] success=1 CPU:001
sleep 20919 [001] 109866.144081: sched:sched_process_exec: filename=/usr/bin/sleep pid=20919 old_pid=20919
sleep 20919 [001] 109866.144408: syscalls:sys_enter_nanosleep: rqtp: 0x7ffc2384fef0, rmtp: 0x00000000
sleep 20919 [001] 109866.144411: sched:sched_stat_runtime: comm=sleep pid=20919 runtime=521249 [ns] vruntime=202919398131 [n>
sleep 20919 [001] 109866.144412: sched:sched_switch: sleep:20919 [120] S ==> swapper/1:0 [120]
swapper 0 [001] 109867.144568: sched:sched_waking: comm=sleep pid=20919 prio=120 target_cpu=001
swapper 0 [001] 109867.144586: sched:sched_wakeup: sleep:20919 [120] success=1 CPU:001
sleep 20919 [001] 109867.144614: syscalls:sys_exit_nanosleep: 0x0
sleep 20919 [001] 109867.144753: sched:sched_process_exit: comm=sleep pid=20919 prio=120
#
# perf script --switch-off syscalls:sys_exit_nanosleep
:20918 20918 [002] 109866.143696: sched:sched_waking: comm=perf pid=20919 prio=120 target_cpu=001
:20918 20918 [002] 109866.143702: sched:sched_wakeup: perf:20919 [120] success=1 CPU:001
sleep 20919 [001] 109866.144081: sched:sched_process_exec: filename=/usr/bin/sleep pid=20919 old_pid=20919
sleep 20919 [001] 109866.144408: syscalls:sys_enter_nanosleep: rqtp: 0x7ffc2384fef0, rmtp: 0x00000000
sleep 20919 [001] 109866.144411: sched:sched_stat_runtime: comm=sleep pid=20919 runtime=521249 [ns] vruntime=202919398131 [n>
sleep 20919 [001] 109866.144412: sched:sched_switch: sleep:20919 [120] S ==> swapper/1:0 [120]
swapper 0 [001] 109867.144568: sched:sched_waking: comm=sleep pid=20919 prio=120 target_cpu=001
swapper 0 [001] 109867.144586: sched:sched_wakeup: sleep:20919 [120] success=1 CPU:001
sleep 20919 [001] 109867.144753: sched:sched_process_exit: comm=sleep pid=20919 prio=120
#
# perf script --switch-on syscalls:sys_enter_nanosleep --switch-off syscalls:sys_exit_nanosleep
sleep 20919 [001] 109866.144411: sched:sched_stat_runtime: comm=sleep pid=20919 runtime=521249 [ns] vruntime=202919398131 [n>
sleep 20919 [001] 109866.144412: sched:sched_switch: sleep:20919 [120] S ==> swapper/1:0 [120]
swapper 0 [001] 109867.144568: sched:sched_waking: comm=sleep pid=20919 prio=120 target_cpu=001
swapper 0 [001] 109867.144586: sched:sched_wakeup: sleep:20919 [120] success=1 CPU:001
#
# perf script --switch-on syscalls:sys_enter_nanosleep --switch-off syscalls:sys_exit_nanosleep --show-on-off
sleep 20919 [001] 109866.144408: syscalls:sys_enter_nanosleep: rqtp: 0x7ffc2384fef0, rmtp: 0x00000000
sleep 20919 [001] 109866.144411: sched:sched_stat_runtime: comm=sleep pid=20919 runtime=521249 [ns] vruntime=202919398131 [n>
sleep 20919 [001] 109866.144412: sched:sched_switch: sleep:20919 [120] S ==> swapper/1:0 [120]
swapper 0 [001] 109867.144568: sched:sched_waking: comm=sleep pid=20919 prio=120 target_cpu=001
swapper 0 [001] 109867.144586: sched:sched_wakeup: sleep:20919 [120] success=1 CPU:001
sleep 20919 [001] 109867.144614: syscalls:sys_exit_nanosleep: 0x0
#
Now think about using this together with 'perf probe' to create custom on/off
events in your app :-)
Cc: Adrian Hunter <adrian.hunter@intel.com>
Cc: Florian Weimer <fweimer@redhat.com>
Cc: Jiri Olsa <jolsa@kernel.org>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: William Cohen <wcohen@redhat.com>
Link: https://lkml.kernel.org/n/tip-li3j01c4tmj9kw6ydsl8swej@git.kernel.org
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
|
|
One may want to see the --switch-on event as well, allow for that, using
the previous cset example:
# perf script --switch-on syscalls:sys_enter_nanosleep --show-on-off
sleep 13638 [001] 108237.582286: syscalls:sys_enter_nanosleep: rqtp: 0x7fff1948ac40, rmtp: 0x00000000
sleep 13638 [001] 108237.582289: sched:sched_stat_runtime: comm=sleep pid=13638 runtime=578104 [ns] vruntime=202889459556 [ns]
sleep 13638 [001] 108237.582291: sched:sched_switch: sleep:13638 [120] S ==> swapper/1:0 [120]
swapper 0 [001] 108238.582428: sched:sched_waking: comm=sleep pid=13638 prio=120 target_cpu=001
swapper 0 [001] 108238.582458: sched:sched_wakeup: sleep:13638 [120] success=1 CPU:001
sleep 13638 [001] 108238.582698: sched:sched_stat_runtime: comm=sleep pid=13638 runtime=173915 [ns] vruntime=202889633471 [ns]
sleep 13638 [001] 108238.582782: sched:sched_process_exit: comm=sleep pid=13638 prio=120
#
# perf script --switch-on syscalls:sys_enter_nanosleep
sleep 13638 [001] 108237.582289: sched:sched_stat_runtime: comm=sleep pid=13638 runtime=578104 [ns] vruntime=202889459556 [ns]
sleep 13638 [001] 108237.582291: sched:sched_switch: sleep:13638 [120] S ==> swapper/1:0 [120]
swapper 0 [001] 108238.582428: sched:sched_waking: comm=sleep pid=13638 prio=120 target_cpu=001
swapper 0 [001] 108238.582458: sched:sched_wakeup: sleep:13638 [120] success=1 CPU:001
sleep 13638 [001] 108238.582698: sched:sched_stat_runtime: comm=sleep pid=13638 runtime=173915 [ns] vruntime=202889633471 [ns]
sleep 13638 [001] 108238.582782: sched:sched_process_exit: comm=sleep pid=13638 prio=120
#
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
Cc: Adrian Hunter <adrian.hunter@intel.com>
Cc: Jiri Olsa <jolsa@kernel.org>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: William Cohen <wcohen@redhat.com>
Cc: Florian Weimer <fweimer@redhat.com>
Link: https://lkml.kernel.org/n/tip-0omwwoywj1v63gu8cz0tr0cy@git.kernel.org
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
|
|
Sometime we want to only consider events after something happens, so
allow discarding events till such events is found, e.g.:
Record all scheduler tracepoints and the sys_enter_nanosleep syscall
event for the 'sleep 1' workload:
# perf record -e sched:*,syscalls:sys_enter_nanosleep sleep 1
[ perf record: Woken up 31 times to write data ]
[ perf record: Captured and wrote 0.032 MB perf.data (10 samples) ]
#
So we have these events in the generated perf data file:
# perf evlist
sched:sched_kthread_stop
sched:sched_kthread_stop_ret
sched:sched_waking
sched:sched_wakeup
sched:sched_wakeup_new
sched:sched_switch
sched:sched_migrate_task
sched:sched_process_free
sched:sched_process_exit
sched:sched_wait_task
sched:sched_process_wait
sched:sched_process_fork
sched:sched_process_exec
sched:sched_stat_wait
sched:sched_stat_sleep
sched:sched_stat_iowait
sched:sched_stat_blocked
sched:sched_stat_runtime
sched:sched_pi_setprio
sched:sched_move_numa
sched:sched_stick_numa
sched:sched_swap_numa
sched:sched_wake_idle_without_ipi
syscalls:sys_enter_nanosleep
# Tip: use 'perf evlist --trace-fields' to show fields for tracepoint events
#
Then show all of the events that actually took place in this 'perf record' session:
# perf script
:13637 13637 [002] 108237.581529: sched:sched_waking: comm=perf pid=13638 prio=120 target_cpu=001
:13637 13637 [002] 108237.581537: sched:sched_wakeup: perf:13638 [120] success=1 CPU:001
sleep 13638 [001] 108237.581992: sched:sched_process_exec: filename=/usr/bin/sleep pid=13638 old_pid=13638
sleep 13638 [001] 108237.582286: syscalls:sys_enter_nanosleep: rqtp: 0x7fff1948ac40, rmtp: 0x00000000
sleep 13638 [001] 108237.582289: sched:sched_stat_runtime: comm=sleep pid=13638 runtime=578104 [ns] vruntime=202889459556 [ns]
sleep 13638 [001] 108237.582291: sched:sched_switch: sleep:13638 [120] S ==> swapper/1:0 [120]
swapper 0 [001] 108238.582428: sched:sched_waking: comm=sleep pid=13638 prio=120 target_cpu=001
swapper 0 [001] 108238.582458: sched:sched_wakeup: sleep:13638 [120] success=1 CPU:001
sleep 13638 [001] 108238.582698: sched:sched_stat_runtime: comm=sleep pid=13638 runtime=173915 [ns] vruntime=202889633471 [ns]
sleep 13638 [001] 108238.582782: sched:sched_process_exit: comm=sleep pid=13638 prio=120
#
Now lets see only the ones that took place after a certain "marker":
# perf script --switch-on syscalls:sys_enter_nanosleep
sleep 13638 [001] 108237.582289: sched:sched_stat_runtime: comm=sleep pid=13638 runtime=578104 [ns] vruntime=202889459556 [ns]
sleep 13638 [001] 108237.582291: sched:sched_switch: sleep:13638 [120] S ==> swapper/1:0 [120]
swapper 0 [001] 108238.582428: sched:sched_waking: comm=sleep pid=13638 prio=120 target_cpu=001
swapper 0 [001] 108238.582458: sched:sched_wakeup: sleep:13638 [120] success=1 CPU:001
sleep 13638 [001] 108238.582698: sched:sched_stat_runtime: comm=sleep pid=13638 runtime=173915 [ns] vruntime=202889633471 [ns]
sleep 13638 [001] 108238.582782: sched:sched_process_exit: comm=sleep pid=13638 prio=120
#
Cc: Adrian Hunter <adrian.hunter@intel.com>
Cc: Florian Weimer <fweimer@redhat.com>
Cc: Jiri Olsa <jolsa@kernel.org>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: William Cohen <wcohen@redhat.com>
Link: https://lkml.kernel.org/n/tip-f1oo0ufdhrkx6nhy2lj1ierm@git.kernel.org
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
|
|
Clarify that a metric is based on events, not referring to itself. Also
some improvements with the sentences.
Signed-off-by: Andi Kleen <ak@linux.intel.com>
Cc: Jiri Olsa <jolsa@kernel.org>
Link: http://lkml.kernel.org/r/20190711181922.18765-3-andi@firstfloor.org
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
|
|
The --max-blocks description was using the old name brstackasm. Use
brstackinsn instead.
Signed-off-by: Andi Kleen <ak@linux.intel.com>
Cc: Jiri Olsa <jolsa@kernel.org>
Link: http://lkml.kernel.org/r/20190711181922.18765-1-andi@firstfloor.org
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
|
|
Currently only a single explicit time range is accepted. Add support for
multiple ranges separated by spaces, which requires the string to be
quoted. Update the time utils test accordingly.
Signed-off-by: Adrian Hunter <adrian.hunter@intel.com>
Cc: Jin Yao <yao.jin@linux.intel.com>
Cc: Jiri Olsa <jolsa@redhat.com>
Link: http://lkml.kernel.org/r/20190604130017.31207-20-adrian.hunter@intel.com
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
|
|
Correct some punctuation and spelling and correct the format to show
that the time resolution is nanoseconds not microseconds.
Signed-off-by: Adrian Hunter <adrian.hunter@intel.com>
Cc: Jin Yao <yao.jin@linux.intel.com>
Cc: Jiri Olsa <jolsa@redhat.com>
Link: http://lkml.kernel.org/r/20190604130017.31207-16-adrian.hunter@intel.com
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
|
|
Add field 'ipc' to display instructions-per-cycle.
Example:
perf record -e intel_pt/cyc/u ls
perf script --insn-trace --xed -F+ipc,-dso,-cpu,-tid
ls 2670177.697113434: 7f0dfdbcd090 _start+0x0 mov %rsp, %rdi IPC: 0.00 (1/877)
ls 2670177.697113434: 7f0dfdbcd093 _start+0x3 callq 0x7f0dfdbce030
ls 2670177.697113434: 7f0dfdbce030 _dl_start+0x0 pushq %rbp
ls 2670177.697113434: 7f0dfdbce031 _dl_start+0x1 mov %rsp, %rbp
ls 2670177.697113434: 7f0dfdbce034 _dl_start+0x4 pushq %r15
ls 2670177.697113434: 7f0dfdbce036 _dl_start+0x6 pushq %r14
ls 2670177.697113434: 7f0dfdbce038 _dl_start+0x8 pushq %r13
ls 2670177.697113434: 7f0dfdbce03a _dl_start+0xa pushq %r12
ls 2670177.697113434: 7f0dfdbce03c _dl_start+0xc mov %rdi, %r12
ls 2670177.697113434: 7f0dfdbce03f _dl_start+0xf pushq %rbx
ls 2670177.697113434: 7f0dfdbce040 _dl_start+0x10 sub $0x38, %rsp
ls 2670177.697113434: 7f0dfdbce044 _dl_start+0x14 rdtsc
ls 2670177.697113434: 7f0dfdbce046 _dl_start+0x16 mov %eax, %eax
ls 2670177.697113434: 7f0dfdbce048 _dl_start+0x18 shl $0x20, %rdx
ls 2670177.697113434: 7f0dfdbce04c _dl_start+0x1c or %rax, %rdx
ls 2670177.697114471: 7f0dfdbce04f _dl_start+0x1f movq 0x27e22(%rip), %rax IPC: 0.00 (15/1685)
ls 2670177.697116177: 7f0dfdbce056 _dl_start+0x26 movq %rdx, 0x27683(%rip) IPC: 0.00 (1/881)
Note, the IPC values are low due to page faults at the beginning of
execution. The additional cycles are due to the time to enter the
kernel, not the actual kernel page fault handler.
Signed-off-by: Adrian Hunter <adrian.hunter@intel.com>
Tested-by: Arnaldo Carvalho de Melo <acme@redhat.com>
Cc: Jiri Olsa <jolsa@redhat.com>
Link: http://lkml.kernel.org/r/20190520113728.14389-9-adrian.hunter@intel.com
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
|
|
Add the --show-bpf-events command line option to show the eBPF related events:
PERF_RECORD_KSYMBOL
PERF_RECORD_BPF_EVENT
Usage:
# perf record -a
...
# perf script --show-bpf-events
...
swapper 0 [000] 0.000000: PERF_RECORD_KSYMBOL ksymbol event with addr ffffffffc0ef971d len 229 type 1 flags 0x0 name bpf_prog_2a142ef67aaad174
swapper 0 [000] 0.000000: PERF_RECORD_BPF_EVENT bpf event with type 1, flags 0, id 36
...
Committer testing:
# perf script --show-bpf-events | egrep -i 'PERF_RECORD_(BPF|KSY)'
0 PERF_RECORD_KSYMBOL ksymbol event with addr ffffffffc029a6c3 len 229 type 1 flags 0x0 name bpf_prog_7be49e3934a125ba
0 PERF_RECORD_BPF_EVENT bpf event with type 1, flags 0, id 47
0 PERF_RECORD_KSYMBOL ksymbol event with addr ffffffffc029c1ae len 229 type 1 flags 0x0 name bpf_prog_2a142ef67aaad174
0 PERF_RECORD_BPF_EVENT bpf event with type 1, flags 0, id 48
0 PERF_RECORD_KSYMBOL ksymbol event with addr ffffffffc02ddd1c len 229 type 1 flags 0x0 name bpf_prog_7be49e3934a125ba
0 PERF_RECORD_BPF_EVENT bpf event with type 1, flags 0, id 49
0 PERF_RECORD_KSYMBOL ksymbol event with addr ffffffffc02dfc11 len 229 type 1 flags 0x0 name bpf_prog_2a142ef67aaad174
0 PERF_RECORD_BPF_EVENT bpf event with type 1, flags 0, id 50
0 PERF_RECORD_KSYMBOL ksymbol event with addr ffffffffc045da0a len 229 type 1 flags 0x0 name bpf_prog_7be49e3934a125ba
0 PERF_RECORD_BPF_EVENT bpf event with type 1, flags 0, id 51
0 PERF_RECORD_KSYMBOL ksymbol event with addr ffffffffc04ef4b4 len 229 type 1 flags 0x0 name bpf_prog_2a142ef67aaad174
0 PERF_RECORD_BPF_EVENT bpf event with type 1, flags 0, id 52
0 PERF_RECORD_KSYMBOL ksymbol event with addr ffffffffc09e15da len 229 type 1 flags 0x0 name bpf_prog_7be49e3934a125ba
0 PERF_RECORD_BPF_EVENT bpf event with type 1, flags 0, id 53
0 PERF_RECORD_KSYMBOL ksymbol event with addr ffffffffc0d2b1a3 len 229 type 1 flags 0x0 name bpf_prog_2a142ef67aaad174
0 PERF_RECORD_BPF_EVENT bpf event with type 1, flags 0, id 54
0 PERF_RECORD_KSYMBOL ksymbol event with addr ffffffffc0fd9850 len 381 type 1 flags 0x0 name bpf_prog_819967866022f1e1_sys_enter
0 PERF_RECORD_BPF_EVENT bpf event with type 1, flags 0, id 179
0 PERF_RECORD_KSYMBOL ksymbol event with addr ffffffffc0feb1ec len 191 type 1 flags 0x0 name bpf_prog_c1bd85c092d6e4aa_sys_exit
0 PERF_RECORD_BPF_EVENT bpf event with type 1, flags 0, id 180
^C[root@quaco pt]# perf evlist
intel_pt//ku
dummy:u
#
Signed-off-by: Jiri Olsa <jolsa@kernel.org>
Acked-by: Song Liu <songliubraving@fb.com>
Tested-by: Arnaldo Carvalho de Melo <acme@redhat.com>
Cc: Adrian Hunter <adrian.hunter@intel.com>
Cc: Alexander Shishkin <alexander.shishkin@linux.intel.com>
Cc: Andi Kleen <ak@linux.intel.com>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: Peter Zijlstra <peterz@infradead.org>
Cc: Stanislav Fomichev <sdf@google.com>
Link: http://lkml.kernel.org/r/20190508132010.14512-11-jolsa@kernel.org
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
|
|
When comparing time stamps in 'perf script' traces it can be annoying to
work with the full perf time stamps.
Add a --reltime option that displays time stamps relative to the trace
start to make it easier to read the traces.
Note: not currently supported for --time. Report an error in this
case.
Before:
% perf script
swapper 0 [000] 245402.891216: 1 cycles:ppp: ffffffffa0068814 native_write_msr+0x4 ([kernel.kallsyms])
swapper 0 [000] 245402.891223: 1 cycles:ppp: ffffffffa0068814 native_write_msr+0x4 ([kernel.kallsyms])
swapper 0 [000] 245402.891227: 5 cycles:ppp: ffffffffa0068814 native_write_msr+0x4 ([kernel.kallsyms])
swapper 0 [000] 245402.891231: 41 cycles:ppp: ffffffffa0068816 native_write_msr+0x6 ([kernel.kallsyms])
swapper 0 [000] 245402.891235: 355 cycles:ppp: ffffffffa000dd51 intel_bts_enable_local+0x21 ([kernel.kallsyms])
swapper 0 [000] 245402.891239: 3084 cycles:ppp: ffffffffa0a0150a end_repeat_nmi+0x48 ([kernel.kallsyms])
After:
% perf script --reltime
swapper 0 [000] 0.000000: 1 cycles:ppp: ffffffffa0068814 native_write_msr+0x4 ([kernel.kallsyms])
swapper 0 [000] 0.000006: 1 cycles:ppp: ffffffffa0068814 native_write_msr+0x4 ([kernel.kallsyms])
swapper 0 [000] 0.000010: 5 cycles:ppp: ffffffffa0068814 native_write_msr+0x4 ([kernel.kallsyms])
swapper 0 [000] 0.000014: 41 cycles:ppp: ffffffffa0068816 native_write_msr+0x6 ([kernel.kallsyms])
swapper 0 [000] 0.000018: 355 cycles:ppp: ffffffffa000dd51 intel_bts_enable_local+0x21 ([kernel.kallsyms])
swapper 0 [000] 0.000022: 3084 cycles:ppp: ffffffffa0a0150a end_repeat_nmi+0x48 ([kernel.kallsyms])
Committer notes:
Do not use 'time' as the name of a variable, as this breaks the build on
older glibcs:
cc1: warnings being treated as errors
builtin-script.c: In function 'perf_sample__fprintf_start':
builtin-script.c:691: warning: declaration of 'time' shadows a global declaration
/usr/include/time.h:187: warning: shadowed declaration is here
Signed-off-by: Andi Kleen <ak@linux.intel.com>
Tested-by: Arnaldo Carvalho de Melo <acme@redhat.com>
Acked-by: Jiri Olsa <jolsa@kernel.org>
LPU-Reference: 20190314225002.30108-8-andi@firstfloor.org
Link: https://lkml.kernel.org/n/tip-bpahyi6pr9r399mvihu65fvc@git.kernel.org
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
|
|
Add support to add/remove fields for specific event types in -F option.
It's now possible to use '+-' after event type, like:
# cat > test.c
#include <stdio.h>
int main(void)
{
printf("Hello world\n");
while(1) {}
}
^D
# gcc -g -o test test.c
# perf probe -x test 'test.c:5'
# perf record -e '{cpu/cpu-cycles,period=10000/,probe_test:main}:S' ./test
...
# perf script -Ftrace:+period,-cpu
test 3859 396291.117343: 10275 cpu/cpu-cycles,period=10000/: 7f..
test 3859 396291.118234: 11041 cpu/cpu-cycles,period=10000/: ffffff..
test 3859 396291.118234: 1 probe_test:main:
test 3859 396291.118248: 8668 cpu/cpu-cycles,period=10000/: ffffff..
test 3859 396291.118263: 10139 cpu/cpu-cycles,period=10000/: ffffff..
Committer testing:
Couldn't make the test above work, but tested it with:
# perf probe -x hello main
Added new event:
probe_hello:main (on main in /home/acme/c/hello)
You can now use it in all perf tools, such as:
perf record -e probe_hello:main -aR sleep 1
# perf record -e probe_hello:main ./hello
hello, world
[ perf record: Woken up 1 times to write data ]
[ perf record: Captured and wrote 0.025 MB perf.data (1 samples) ]
# perf script
hello 21454 [002] 254116.874005: probe_hello:main: (401126)
#
# perf script -Ftrace:+period,-cpu
hello 21454 254116.874005: 1 probe_hello:main: (401126)
Signed-off-by: Jiri Olsa <jolsa@kernel.org>
Tested-by: Arnaldo Carvalho de Melo <acme@redhat.com>
Cc: Alexander Shishkin <alexander.shishkin@linux.intel.com>
Cc: Andi Kleen <ak@linux.intel.com>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: Peter Zijlstra <peterz@infradead.org>
Link: http://lkml.kernel.org/r/20190220122800.864-4-jolsa@kernel.org
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
|
|
When looking at PT or brstackinsn traces with 'perf script' it can be
very useful to see the source code. This adds a simple facility to print
them with 'perf script', if the information is available through dwarf
% perf record ...
% perf script -F insn,ip,sym,srccode
...
4004c6 main
5 for (i = 0; i < 10000000; i++)
4004cd main
5 for (i = 0; i < 10000000; i++)
4004c6 main
5 for (i = 0; i < 10000000; i++)
4004cd main
5 for (i = 0; i < 10000000; i++)
4004cd main
5 for (i = 0; i < 10000000; i++)
4004cd main
5 for (i = 0; i < 10000000; i++)
4004cd main
5 for (i = 0; i < 10000000; i++)
4004cd main
5 for (i = 0; i < 10000000; i++)
4004b3 main
6 v++;
% perf record -b ...
% perf script -F insn,ip,sym,srccode,brstackinsn
...
main+22:
0000000000400543 insn: e8 ca ff ff ff # PRED
|18 f1();
f1:
0000000000400512 insn: 55
|10 {
0000000000400513 insn: 48 89 e5
0000000000400516 insn: b8 00 00 00 00
|11 f2();
000000000040051b insn: e8 d6 ff ff ff # PRED
f2:
00000000004004f6 insn: 55
|5 {
00000000004004f7 insn: 48 89 e5
00000000004004fa insn: 8b 05 2c 0b 20 00
|6 c = a / b;
0000000000400500 insn: 8b 0d 2a 0b 20 00
0000000000400506 insn: 99
0000000000400507 insn: f7 f9
0000000000400509 insn: 89 05 29 0b 20 00
000000000040050f insn: 90
|7 }
0000000000400510 insn: 5d
0000000000400511 insn: c3 # PRED
f1+14:
0000000000400520 insn: b8 00 00 00 00
|12 f2();
0000000000400525 insn: e8 cc ff ff ff # PRED
f2:
00000000004004f6 insn: 55
|5 {
00000000004004f7 insn: 48 89 e5
00000000004004fa insn: 8b 05 2c 0b 20 00
|6 c = a / b;
Not supported for callchains currently, would need some layout changes
there.
Committer notes:
Fixed the build on Alpine Linux (3.4 .. 3.8) by addressing this
warning:
In file included from util/srccode.c:19:0:
/usr/include/sys/fcntl.h:1:2: error: #warning redirecting incorrect #include <sys/fcntl.h> to <fcntl.h> [-Werror=cpp]
#warning redirecting incorrect #include <sys/fcntl.h> to <fcntl.h>
^~~~~~~
cc1: all warnings being treated as errors
Signed-off-by: Andi Kleen <ak@linux.intel.com>
Tested-by: Jiri Olsa <jolsa@kernel.org>
Link: http://lkml.kernel.org/r/20181204001848.24769-1-andi@firstfloor.org
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
|
|
Add a ftrace style --graph-function argument to 'perf script' that
allows to print itrace function calls only below a given function. This
makes it easier to find the code of interest in a large trace.
% perf record -e intel_pt//k -a sleep 1
% perf script --graph-function group_sched_in --call-trace
perf 900 [000] 194167.205652203: ([kernel.kallsyms]) group_sched_in
perf 900 [000] 194167.205652203: ([kernel.kallsyms]) __x86_indirect_thunk_rax
perf 900 [000] 194167.205652203: ([kernel.kallsyms]) event_sched_in.isra.107
perf 900 [000] 194167.205652203: ([kernel.kallsyms]) perf_event_set_state.part.71
perf 900 [000] 194167.205652203: ([kernel.kallsyms]) perf_event_update_time
perf 900 [000] 194167.205652203: ([kernel.kallsyms]) perf_pmu_disable
perf 900 [000] 194167.205652203: ([kernel.kallsyms]) perf_log_itrace_start
perf 900 [000] 194167.205652203: ([kernel.kallsyms]) __x86_indirect_thunk_rax
perf 900 [000] 194167.205652203: ([kernel.kallsyms]) perf_event_update_userpage
perf 900 [000] 194167.205652203: ([kernel.kallsyms]) calc_timer_values
perf 900 [000] 194167.205652203: ([kernel.kallsyms]) sched_clock_cpu
perf 900 [000] 194167.205652203: ([kernel.kallsyms]) __x86_indirect_thunk_rax
perf 900 [000] 194167.205652203: ([kernel.kallsyms]) arch_perf_update_userpage
perf 900 [000] 194167.205652203: ([kernel.kallsyms]) __fentry__
perf 900 [000] 194167.205652203: ([kernel.kallsyms]) using_native_sched_clock
perf 900 [000] 194167.205652203: ([kernel.kallsyms]) sched_clock_stable
perf 900 [000] 194167.205652203: ([kernel.kallsyms]) perf_pmu_enable
perf 900 [000] 194167.205652203: ([kernel.kallsyms]) __x86_indirect_thunk_rax
swapper 0 [001] 194167.205660693: ([kernel.kallsyms]) group_sched_in
swapper 0 [001] 194167.205660693: ([kernel.kallsyms]) __x86_indirect_thunk_rax
swapper 0 [001] 194167.205660693: ([kernel.kallsyms]) event_sched_in.isra.107
swapper 0 [001] 194167.205660693: ([kernel.kallsyms]) perf_event_set_state.part.71
swapper 0 [001] 194167.205660693: ([kernel.kallsyms]) perf_event_update_time
swapper 0 [001] 194167.205660693: ([kernel.kallsyms]) perf_pmu_disable
swapper 0 [001] 194167.205660693: ([kernel.kallsyms]) perf_log_itrace_start
swapper 0 [001] 194167.205660693: ([kernel.kallsyms]) __x86_indirect_thunk_rax
swapper 0 [001] 194167.205660693: ([kernel.kallsyms]) perf_event_update_userpage
swapper 0 [001] 194167.205660693: ([kernel.kallsyms]) calc_timer_values
swapper 0 [001] 194167.205660693: ([kernel.kallsyms]) sched_clock_cpu
swapper 0 [001] 194167.205660693: ([kernel.kallsyms]) __x86_indirect_thunk_rax
swapper 0 [001] 194167.205660693: ([kernel.kallsyms]) arch_perf_update_userpage
swapper 0 [001] 194167.205660693: ([kernel.kallsyms]) __fentry__
swapper 0 [001] 194167.205660693: ([kernel.kallsyms]) using_native_sched_clock
swapper 0 [001] 194167.205660693: ([kernel.kallsyms]) sched_clock_stable
Signed-off-by: Andi Kleen <ak@linux.intel.com>
Tested-by: Arnaldo Carvalho de Melo <acme@redhat.com>
Tested-by: Leo Yan <leo.yan@linaro.org>
Acked-by: Jiri Olsa <jolsa@kernel.org>
Cc: Kim Phillips <kim.phillips@arm.com>
Link: http://lkml.kernel.org/r/20180920180540.14039-5-andi@firstfloor.org
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
|
|
Add short cut options to print PT call trace and call-ret-trace, for
calls and call and returns. Roughly corresponds to ftrace function
tracer and function graph tracer.
Just makes these common use cases nicer to use.
% perf record -a -e intel_pt// sleep 1
% perf script --call-trace
perf 900 [000] 194167.205652203: ([kernel.kallsyms]) perf_pmu_enable
perf 900 [000] 194167.205652203: ([kernel.kallsyms]) __x86_indirect_thunk_rax
perf 900 [000] 194167.205652203: ([kernel.kallsyms]) event_filter_match
perf 900 [000] 194167.205652203: ([kernel.kallsyms]) group_sched_in
perf 900 [000] 194167.205652203: ([kernel.kallsyms]) __x86_indirect_thunk_rax
perf 900 [000] 194167.205652203: ([kernel.kallsyms]) event_sched_in.isra.107
perf 900 [000] 194167.205652203: ([kernel.kallsyms]) perf_event_set_state.part.71
perf 900 [000] 194167.205652203: ([kernel.kallsyms]) perf_event_update_time
perf 900 [000] 194167.205652203: ([kernel.kallsyms]) perf_pmu_disable
perf 900 [000] 194167.205652203: ([kernel.kallsyms]) perf_log_itrace_start
perf 900 [000] 194167.205652203: ([kernel.kallsyms]) __x86_indirect_thunk_rax
perf 900 [000] 194167.205652203: ([kernel.kallsyms]) perf_event_update_userpage
% perf script --call-ret-trace
perf 900 [000] 194167.205652203: tr strt ([unknown]) pt_config
perf 900 [000] 194167.205652203: return ([kernel.kallsyms]) pt_config
perf 900 [000] 194167.205652203: return ([kernel.kallsyms]) pt_event_add
perf 900 [000] 194167.205652203: call ([kernel.kallsyms]) perf_pmu_enable
perf 900 [000] 194167.205652203: return ([kernel.kallsyms]) perf_pmu_nop_void
perf 900 [000] 194167.205652203: return ([kernel.kallsyms]) event_sched_in.isra.107
perf 900 [000] 194167.205652203: call ([kernel.kallsyms]) __x86_indirect_thunk_rax
perf 900 [000] 194167.205652203: return ([kernel.kallsyms]) perf_pmu_nop_int
perf 900 [000] 194167.205652203: return ([kernel.kallsyms]) group_sched_in
perf 900 [000] 194167.205652203: call ([kernel.kallsyms]) event_filter_match
perf 900 [000] 194167.205652203: return ([kernel.kallsyms]) event_filter_match
perf 900 [000] 194167.205652203: call ([kernel.kallsyms]) group_sched_in
perf 900 [000] 194167.205652203: call ([kernel.kallsyms]) __x86_indirect_thunk_rax
perf 900 [000] 194167.205652203: return ([kernel.kallsyms]) perf_pmu_nop_txn
perf 900 [000] 194167.205652203: call ([kernel.kallsyms]) event_sched_in.isra.107
perf 900 [000] 194167.205652203: call ([kernel.kallsyms]) perf_event_set_state.part.71
Signed-off-by: Andi Kleen <ak@linux.intel.com>
Tested-by: Arnaldo Carvalho de Melo <acme@redhat.com>
Tested-by: Leo Yan <leo.yan@linaro.org>
Acked-by: Jiri Olsa <jolsa@kernel.org>
Cc: Kim Phillips <kim.phillips@arm.com>
Link: http://lkml.kernel.org/r/20180920180540.14039-4-andi@firstfloor.org
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
|
|
Add a --insn-trace short hand option for decoding and disassembling
instruction streams for intel_pt. This automatically pipes the output
into the xed disassembler to generate disassembled instructions. This
just makes this use model much nicer to use.
Before
% perf record -e intel_pt// ...
% perf script --itrace=i0ns --ns -F +insn,-event,-period | xed -F insn: -A -64
swapper 0 [000] 17276.429606186: ffffffff81010486 pt_config ([kernel.kallsyms]) nopl %eax, (%rax,%rax,1)
swapper 0 [000] 17276.429606186: ffffffff8101048b pt_config ([kernel.kallsyms]) add $0x10, %rsp
swapper 0 [000] 17276.429606186: ffffffff8101048f pt_config ([kernel.kallsyms]) popq %rbx
swapper 0 [000] 17276.429606186: ffffffff81010490 pt_config ([kernel.kallsyms]) popq %rbp
swapper 0 [000] 17276.429606186: ffffffff81010491 pt_config ([kernel.kallsyms]) popq %r12
swapper 0 [000] 17276.429606186: ffffffff81010493 pt_config ([kernel.kallsyms]) popq %r13
swapper 0 [000] 17276.429606186: ffffffff81010495 pt_config ([kernel.kallsyms]) popq %r14
swapper 0 [000] 17276.429606186: ffffffff81010497 pt_config ([kernel.kallsyms]) popq %r15
swapper 0 [000] 17276.429606186: ffffffff81010499 pt_config ([kernel.kallsyms]) retq
swapper 0 [000] 17276.429606186: ffffffff8101063e pt_event_add ([kernel.kallsyms]) cmpl $0x1, 0x1b0(%rbx)
swapper 0 [000] 17276.429606186: ffffffff81010645 pt_event_add ([kernel.kallsyms]) mov $0xffffffea, %eax
swapper 0 [000] 17276.429606186: ffffffff8101064a pt_event_add ([kernel.kallsyms]) mov $0x0, %edx
swapper 0 [000] 17276.429606186: ffffffff8101064f pt_event_add ([kernel.kallsyms]) popq %rbx
swapper 0 [000] 17276.429606186: ffffffff81010650 pt_event_add ([kernel.kallsyms]) cmovnz %edx, %eax
swapper 0 [000] 17276.429606186: ffffffff81010653 pt_event_add ([kernel.kallsyms]) jmp 0xffffffff81010635
swapper 0 [000] 17276.429606186: ffffffff81010635 pt_event_add ([kernel.kallsyms]) retq
swapper 0 [000] 17276.429606186: ffffffff8115e687 event_sched_in.isra.107 ([kernel.kallsyms]) test %eax, %eax
Now:
% perf record -e intel_pt// ...
% perf script --insn-trace --xed
... same output ...
XED needs to be installed with:
$ git clone https://github.com/intelxed/mbuild.git mbuild
$ git clone https://github.com/intelxed/xed
$ cd xed
$ ./mfile.py
$ ./mfile.py examples
$ sudo ./mfile.py --prefix=/usr/local install
$ sudo cp obj/examples/xed /usr/local/bin
$ xed | head -3
ERROR: required argument(s) were missing
Copyright (C) 2017, Intel Corporation. All rights reserved.
XED version: [v10.0-328-g7d62c8c49b7b]
$
Signed-off-by: Andi Kleen <ak@linux.intel.com>
Tested-by: Arnaldo Carvalho de Melo <acme@redhat.com>
Acked-by: Jiri Olsa <jolsa@kernel.org>
Link: http://lkml.kernel.org/r/20180920180540.14039-2-andi@firstfloor.org
[ Fixed up whitespace damage, added the 'mfile.py examples + cp obj/examples/xed ... ]
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
|
|
Append 'p' sign to 'S' tag designating the type of context switch out event so
'Sp' means preemption context switch. Documentation is extended to cover
new presentation changes.
$ perf script --show-switch-events -F +misc -I -i perf.data:
hdparm 4073 [004] U 762.198265: 380194 cycles:ppp: 7faf727f5a23 strchr (/usr/lib64/ld-2.26.so)
hdparm 4073 [004] K 762.198366: 441572 cycles:ppp: ffffffffb9218435 alloc_set_pte (/lib/modules/4.16.0-rc6+/build/vmlinux)
hdparm 4073 [004] S 762.198391: PERF_RECORD_SWITCH_CPU_WIDE OUT next pid/tid: 0/0
swapper 0 [004] 762.198392: PERF_RECORD_SWITCH_CPU_WIDE IN prev pid/tid: 4073/4073
swapper 0 [004] Sp 762.198477: PERF_RECORD_SWITCH_CPU_WIDE OUT preempt next pid/tid: 4073/4073
hdparm 4073 [004] 762.198478: PERF_RECORD_SWITCH_CPU_WIDE IN prev pid/tid: 0/0
swapper 0 [007] K 762.198514: 2303073 cycles:ppp: ffffffffb98b0c66 intel_idle (/lib/modules/4.16.0-rc6+/build/vmlinux)
swapper 0 [007] Sp 762.198561: PERF_RECORD_SWITCH_CPU_WIDE OUT preempt next pid/tid: 1134/1134
kworker/u16:18 1134 [007] 762.198562: PERF_RECORD_SWITCH_CPU_WIDE IN prev pid/tid: 0/0
kworker/u16:18 1134 [007] S 762.198567: PERF_RECORD_SWITCH_CPU_WIDE OUT next pid/tid: 0/0
Signed-off-by: Alexey Budankov <alexey.budankov@linux.intel.com>
Tested-by: Arnaldo Carvalho de Melo <acme@redhat.com>
Cc: Alexander Shishkin <alexander.shishkin@linux.intel.com>
Cc: Andi Kleen <ak@linux.intel.com>
Cc: Jiri Olsa <jolsa@redhat.com>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: Peter Zijlstra <peterz@infradead.org>
Link: http://lkml.kernel.org/r/5fc65ce7-8ca5-53ae-8858-8ddd27290575@linux.intel.com
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
|
|
Adding --show-round-event to display PERF_RECORD_FINISHED_ROUND events
like:
# perf script --show-round-events 2>/dev/null
yes 8591 [002] 124177.397597: 18 cpu/mem-stores/P: ff...
yes 8591 [002] 124177.397615: 1 cpu/mem-loads,ldlat=30/P: ff...
PERF_RECORD_FINISHED_ROUND
perf 10380 [001] 124177.397622: 6 cpu/mem-loads,ldlat=30/P: ff...
PERF_RECORD_FINISHED_ROUND
swapper 0 [000] 124177.400518: 88 cpu/mem-stores/P: ff...
swapper 0 [000] 124177.400521: 88 cpu/mem-stores/P: ff...
Signed-off-by: Jiri Olsa <jolsa@kernel.org>
Tested-by: Arnaldo Carvalho de Melo <acme@redhat.com>
Cc: Alexander Shishkin <alexander.shishkin@linux.intel.com>
Cc: David Ahern <dsahern@gmail.com>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: Peter Zijlstra <peterz@infradead.org>
Link: http://lkml.kernel.org/r/20180206181813.10943-4-jolsa@kernel.org
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
|