linux/tools/perf/Documentation/perf-script.txt

390 lines
14 KiB
Plaintext
Raw Normal View History

perf-script(1)
=============
NAME
----
perf-script - Read perf.data (created by perf record) and display trace output
SYNOPSIS
--------
[verse]
'perf script' [<options>]
'perf script' [<options>] record <script> [<record-options>] <command>
'perf script' [<options>] report <script> [script-args]
'perf script' [<options>] <script> <required-script-args> [<record-options>] <command>
'perf script' [<options>] <top-script> [script-args]
DESCRIPTION
-----------
This command reads the input file and displays the trace recorded.
There are several variants of perf script:
'perf script' to see a detailed trace of the workload that was
recorded.
You can also run a set of pre-canned scripts that aggregate and
summarize the raw trace data in various ways (the list of scripts is
available via 'perf script -l'). The following variants allow you to
record and run those scripts:
'perf script record <script> <command>' to record the events required
for 'perf script report'. <script> is the name displayed in the
output of 'perf script --list' i.e. the actual script name minus any
language extension. If <command> is not specified, the events are
recorded using the -a (system-wide) 'perf record' option.
'perf script report <script> [args]' to run and display the results
of <script>. <script> is the name displayed in the output of 'perf
script --list' i.e. the actual script name minus any language
extension. The perf.data output from a previous run of 'perf script
record <script>' is used and should be present for this command to
succeed. [args] refers to the (mainly optional) args expected by
the script.
'perf script <script> <required-script-args> <command>' to both
record the events required for <script> and to run the <script>
using 'live-mode' i.e. without writing anything to disk. <script>
is the name displayed in the output of 'perf script --list' i.e. the
actual script name minus any language extension. If <command> is
not specified, the events are recorded using the -a (system-wide)
'perf record' option. If <script> has any required args, they
should be specified before <command>. This mode doesn't allow for
optional script args to be specified; if optional script args are
desired, they can be specified using separate 'perf script record'
and 'perf script report' commands, with the stdout of the record step
piped to the stdin of the report script, using the '-o -' and '-i -'
options of the corresponding commands.
'perf script <top-script>' to both record the events required for
<top-script> and to run the <top-script> using 'live-mode'
i.e. without writing anything to disk. <top-script> is the name
displayed in the output of 'perf script --list' i.e. the actual
script name minus any language extension; a <top-script> is defined
as any script name ending with the string 'top'.
[<record-options>] can be passed to the record steps of 'perf script
record' and 'live-mode' variants; this isn't possible however for
<top-script> 'live-mode' or 'perf script report' variants.
See the 'SEE ALSO' section for links to language-specific
information on how to write and run your own trace scripts.
OPTIONS
-------
<command>...::
Any command you can specify in a shell.
-D::
--dump-raw-trace=::
Display verbose dump of the trace data.
-L::
--Latency=::
Show latency attributes (irqs/preemption disabled, etc).
-l::
--list=::
Display a list of available trace scripts.
-s ['lang']::
--script=::
Process trace data with the given script ([lang]:script[.ext]).
If the string 'lang' is specified in place of a script name, a
list of supported languages will be displayed instead.
-g::
--gen-script=::
Generate perf-script.[ext] starter script for given language,
using current perf.data.
-a::
Force system-wide collection. Scripts run without a <command>
normally use -a by default, while scripts run with a <command>
normally don't - this option allows the latter to be run in
system-wide mode.
-i::
--input=::
Input file name. (default: perf.data unless stdin is a fifo)
-d::
--debug-mode::
Do various checks like samples ordering and lost events.
-F::
--fields::
perf script: Support custom field selection for output Allow a user to select which fields to print to stdout for event data. Options include comm (command name), tid (thread id), pid (process id), time (perf timestamp), cpu, event (for event name), and trace (for trace data). Default is set to maintain compatibility with current output; this feature does alter output format slightly -- no '-' between command and pid/tid. Thanks to Frederic Weisbecker for detailed suggestions on this approach. Examples (output compressed) 1. trace, default format perf record -ga -e sched:sched_switch perf script swapper 0 [000] 537.037184: sched_switch: prev_comm=swapper prev_pid=0... sshd 1675 [000] 537.037309: sched_switch: prev_comm=sshd prev_pid=1675... netstat 1692 [001] 537.038664: sched_switch: prev_comm=netstat prev_pid=1692... 2. trace, custom format perf record -ga -e sched:sched_switch perf script -f comm,pid,time,trace <--- omitting cpu and event name swapper 0 537.037184: prev_comm=swapper prev_pid=0 prev_prio=120 ... sshd 1675 537.037309: prev_comm=sshd prev_pid=1675 prev_prio=120 ... netstat 1692 537.038664: prev_comm=netstat prev_pid=1692 prev_prio=120 ... Acked-by: Frederic Weisbecker <fweisbec@gmail.com> Cc: Frederic Weisbecker <fweisbec@gmail.com> Cc: Ingo Molnar <mingo@elte.hu> Cc: Paul Mackerras <paulus@samba.org> Cc: Peter Zijlstra <peterz@infradead.org> Cc: Thomas Gleixner <tglx@linutronix.de> LKML-Reference: <1299734608-5223-5-git-send-email-daahern@cisco.com> Signed-off-by: David Ahern <daahern@cisco.com> Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2011-03-10 13:23:26 +08:00
Comma separated list of fields to print. Options are:
perf script: Add field option 'flags' to print sample flags Instruction tracing will typically have access to information about the instruction being executed for a particular ip sample. Some of that information will be available in the 'flags' member of struct perf_sample. With the addition of transactions events synthesis to Instruction Tracing options, there is a need to be able easily to see the flags because they show whether the ip is at the start, commit or abort of a tranasaction. Consequently add an option to display the flags. The flags are "bcrosyiABEx" which stand for branch, call, return, conditional, system, asynchronous, interrupt, transaction abort, trace begin, trace end, and in transaction, respectively. Example using Intel PT: perf script -fip,time,event,sym,addr,flags ... 1288.721584105: branches:u: bo 401146 main => 401152 main 1288.721584105: transactions: x 0 401164 main 1288.721584105: branches:u: bx 40117c main => 40119b main 1288.721584105: branches:u: box 4011a4 main => 40117e main 1288.721584105: branches:u: bcx 401187 main => 401094 g ... 1288.721591645: branches:u: bx 4010c4 g => 4010cb g 1288.721591645: branches:u: brx 4010cc g => 401189 main 1288.721591645: transactions: 0 4011a6 main 1288.721593199: branches:u: b 4011a9 main => 4011af main 1288.721593199: branches:u: bo 4011bc main => 40113e main 1288.721593199: branches:u: b 401150 main => 40115a main 1288.721593199: transactions: x 0 401164 main 1288.721593199: branches:u: bx 40117c main => 40119b main 1288.721593199: branches:u: box 4011a4 main => 40117e main 1288.721593199: branches:u: bcx 401187 main => 40105e f ... 1288.722284747: branches:u: brx 401093 f => 401189 main 1288.722284747: branches:u: box 4011a4 main => 40117e main 1288.722284747: branches:u: bcx 401187 main => 40105e f 1288.722285883: transactions: bA 0 401071 f 1288.722285883: branches:u: bA 401071 f => 40116a main 1288.722285883: branches:u: bE 40116a main => 0 [unknown] 1288.722297174: branches:u: bB 0 [unknown] => 40116a main ... Signed-off-by: Adrian Hunter <adrian.hunter@intel.com> Cc: David Ahern <dsahern@gmail.com> Cc: Frederic Weisbecker <fweisbec@gmail.com> Cc: Jiri Olsa <jolsa@redhat.com> Cc: Namhyung Kim <namhyung@gmail.com> Cc: Peter Zijlstra <peterz@infradead.org> Cc: Stephane Eranian <eranian@google.com> Link: http://lkml.kernel.org/r/1428594864-29309-26-git-send-email-adrian.hunter@intel.com Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2015-04-09 23:54:05 +08:00
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.
Field list can be prepended with the type, trace, sw or hw,
perf script: Add support for H/W and S/W events Custom fields set for each type by prepending field argument with type. For file with multiple event types (e.g., trace and S/W) display of an event type suppressed by setting output fields to "". e.g., perf record -ga -e sched:sched_switch -e cpu-clock -c 10000000 -R -- sleep 1 perf script openssl 11496 [000] 9711.807107: cpu-clock-msecs: ffffffff810c22dc arch_local_irq_restore ([kernel.kallsyms]) ffffffff810c518c __alloc_pages_nodemask ([kernel.kallsyms]) ffffffff810297b2 pte_alloc_one ([kernel.kallsyms]) ffffffff810d8b98 __pte_alloc ([kernel.kallsyms]) ffffffff810daf07 handle_mm_fault ([kernel.kallsyms]) ffffffff8138763a do_page_fault ([kernel.kallsyms]) ffffffff81384a65 page_fault ([kernel.kallsyms]) 7f6130507d70 asn1_check_tlen (/lib64/libcrypto.so.1.0.0c) 0 () openssl 11496 [000] 9711.808042: sched_switch: prev_comm=openssl ... kworker/0:0 4 [000] 9711.808067: sched_switch: prev_comm=kworker/... swapper 0 [001] 9711.808090: sched_switch: prev_comm=kworker/... sshd 11451 [001] 9711.808185: sched_switch: prev_comm=sshd pre... swapper 0 [001] 9711.816155: cpu-clock-msecs: ffffffff81023609 native_safe_halt ([kernel.kallsyms]) ffffffff8100132a cpu_idle ([kernel.kallsyms]) ffffffff8137cf9b start_secondary ([kernel.kallsyms]) openssl 11496 [000] 9711.817104: cpu-clock-msecs: 7f61304ad723 AES_cbc_encrypt (/lib64/libcrypto.so.1.0.0c) 7fff3402f950 () 12f0debc9a785634 () swapper 0 [001] 9711.826155: cpu-clock-msecs: ffffffff81023609 native_safe_halt ([kernel.kallsyms]) ffffffff8100132a cpu_idle ([kernel.kallsyms]) ffffffff8137cf9b start_secondary ([kernel.kallsyms]) To suppress trace events within the file and use default output for S/W events: perf script -f trace: or to suppress S/W events and do default display for trace events: perf script -f sw: Custom field selections: perf script -f sw:comm,tid,time -f trace:time,trace openssl 11496 9711.797162: swapper 0 9711.807071: openssl 11496 9711.807107: 9711.808042: prev_comm=openssl prev_pid=11496 prev_prio=120 prev_state=R ... 9711.808067: prev_comm=kworker/0:0 prev_pid=4 prev_prio=120 prev_state=S ... 9711.808090: prev_comm=kworker/0:0 prev_pid=0 prev_prio=120 prev_state=R ... 9711.808185: prev_comm=sshd prev_pid=11451 prev_prio=120 prev_state=S ==>... swapper 0 9711.816155: openssl 11496 9711.817104: swapper 0 9711.826155: Acked-by: Frederic Weisbecker <fweisbec@gmail.com> Cc: Frederic Weisbecker <fweisbec@gmail.com> Cc: Ingo Molnar <mingo@elte.hu> Cc: Paul Mackerras <paulus@samba.org> Cc: Peter Zijlstra <peterz@infradead.org> Cc: Thomas Gleixner <tglx@linutronix.de> LKML-Reference: <1299734608-5223-7-git-send-email-daahern@cisco.com> Signed-off-by: David Ahern <daahern@cisco.com> Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2011-03-10 13:23:28 +08:00
to indicate to which event type the field list applies.
e.g., -F sw:comm,tid,time,ip,sym and -F trace:time,cpu,trace
perf script: Add support for dumping symbols Add option to dump symbols found in events. e.g., perf script -f comm,pid,tid,time,trace,sym swapper 0/0 537.037184: prev_comm=swapper prev_pid=0 prev_prio=120... ffffffff81030350 perf_trace_sched_switch ([kernel.kallsyms]) ffffffff81382ac5 schedule ([kernel.kallsyms]) ffffffff8100134a cpu_idle ([kernel.kallsyms]) ffffffff81370b39 rest_init ([kernel.kallsyms]) ffffffff81696c23 start_kernel ([kernel.kallsyms].init.text) ffffffff816962af x86_64_start_reservations ([kernel.kallsyms].init.text) ffffffff816963b9 x86_64_start_kernel ([kernel.kallsyms].init.text) sshd 1675/1675 537.037309: prev_comm=sshd prev_pid=1675 prev_prio=120... ffffffff81030350 perf_trace_sched_switch ([kernel.kallsyms]) ffffffff81382ac5 schedule ([kernel.kallsyms]) ffffffff813837aa schedule_hrtimeout_range_clock ([kernel.kallsyms]) ffffffff81383886 schedule_hrtimeout_range ([kernel.kallsyms]) ffffffff8110c4f9 poll_schedule_timeout ([kernel.kallsyms]) ffffffff8110cd20 do_select ([kernel.kallsyms]) ffffffff8110ced8 core_sys_select ([kernel.kallsyms]) ffffffff8110d00d sys_select ([kernel.kallsyms]) ffffffff81002bc2 system_call ([kernel.kallsyms]) 7f1647e56e93 __GI_select (/lib64/libc-2.12.90.so) netstat 1692/1692 537.038664: prev_comm=netstat prev_pid=1692 prev_prio=... ffffffff81030350 perf_trace_sched_switch ([kernel.kallsyms]) ffffffff81382ac5 schedule ([kernel.kallsyms]) ffffffff81002c3a sysret_careful ([kernel.kallsyms]) 7f7a6cd1b210 __GI___libc_read (/lib64/libc-2.12.90.so) Acked-by: Frederic Weisbecker <fweisbec@gmail.com> Cc: Frederic Weisbecker <fweisbec@gmail.com> Cc: Ingo Molnar <mingo@elte.hu> Cc: Paul Mackerras <paulus@samba.org> Cc: Peter Zijlstra <peterz@infradead.org> Cc: Thomas Gleixner <tglx@linutronix.de> LKML-Reference: <1299734608-5223-6-git-send-email-daahern@cisco.com> Signed-off-by: David Ahern <daahern@cisco.com> Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2011-03-10 13:23:27 +08:00
perf script -F <fields>
is equivalent to:
perf script -F trace:<fields> -F sw:<fields> -F hw:<fields>
i.e., the specified fields apply to all event types if the type string
is not given.
perf script: Allow adding and removing fields With 'perf script' it is common that we just want to add or remove a field. Currently this requires figuring out the long list of default fields and specifying them first, and then adding/removing the new field. This patch adds a new + - syntax to merely add or remove fields, that allows more succint and clearer command lines For example to remove the comm field from PMU samples: Previously $ perf script -F tid,cpu,time,event,sym,ip,dso,period | head -1 swapper 0 [000] 504345.383126: 1 cycles: ffffffff90060c66 native_write_msr ([kernel.kallsyms]) with the new syntax perf script -F -comm | head -1 0 [000] 504345.383126: 1 cycles: ffffffff90060c66 native_write_msr ([kernel.kallsyms]) The new syntax cannot be mixed with normal overriding. v2: Fix example in description. Use tid vs pid. No functional changes. v3: Don't skip initialization when user specified explicit type. v4: Rebase. Remove empty line. Committer testing: # perf record -a usleep 1 [ perf record: Woken up 1 times to write data ] [ perf record: Captured and wrote 1.748 MB perf.data (14 samples) ] Without a explicit field list specified via -F, defaults to: # perf script | head -2 perf 6338 [000] 18467.058607: 1 cycles: ffffffff89060c36 native_write_msr (/lib/modules/4.11.0-rc8+/build/vmlinux) swapper 0 [001] 18467.058617: 1 cycles: ffffffff89060c36 native_write_msr (/lib/modules/4.11.0-rc8+/build/vmlinux) # Which is equivalent to: # perf script -F comm,tid,cpu,time,period,event,ip,sym,dso | head -2 perf 6338 [000] 18467.058607: 1 cycles: ffffffff89060c36 native_write_msr (/lib/modules/4.11.0-rc8+/build/vmlinux) swapper 0 [001] 18467.058617: 1 cycles: ffffffff89060c36 native_write_msr (/lib/modules/4.11.0-rc8+/build/vmlinux) # So if we want to remove the comm, as in your original example, we would have to figure out the default field list and remove ' comm' from it: # perf script -F tid,cpu,time,period,event,ip,sym,dso | head -2 6338 [000] 18467.058607: 1 cycles: ffffffff89060c36 native_write_msr (/lib/modules/4.11.0-rc8+/build/vmlinux) 0 [001] 18467.058617: 1 cycles: ffffffff89060c36 native_write_msr (/lib/modules/4.11.0-rc8+/build/vmlinux) # With your patch this becomes simpler, one can remove fields by prefixing them with '-': # perf script -F -comm | head -2 6338 [000] 18467.058607: 1 cycles: ffffffff89060c36 native_write_msr (/lib/modules/4.11.0-rc8+/build/vmlinux) 0 [001] 18467.058617: 1 cycles: ffffffff89060c36 native_write_msr (/lib/modules/4.11.0-rc8+/build/vmlinux) # Signed-off-by: Andi Kleen <ak@linux.intel.com> Acked-by: Jiri Olsa <jolsa@kernel.org> Tested-by: Arnaldo Carvalho de Melo <acme@redhat.com> Tested-by: Milian Wolff <milian.wolff@kdab.com> Link: http://lkml.kernel.org/r/20170602154810.15875-1-andi@firstfloor.org Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2017-06-02 23:48:10 +08:00
In addition to overriding fields, it is also possible to add or remove
fields from the defaults. For example
-F -cpu,+insn
removes the cpu field and adds the insn field. Adding/removing fields
cannot be mixed with normal overriding.
The arguments are processed in the order received. A later usage can
reset a prior request. e.g.:
-F trace: -F comm,tid,time,ip,sym
The first -F suppresses trace events (field list is ""), but then the
second invocation sets the fields to comm,tid,time,ip,sym. In this case a
warning is given to the user:
"Overriding previous field request for all events."
Alternatively, consider the order:
-F comm,tid,time,ip,sym -F trace:
The first -F sets the fields for all events and the second -F
suppresses trace events. The user is given a warning message about
the override, and the result of the above is that only S/W and H/W
events are displayed with the given fields.
For the 'wildcard' option if a user selected field is invalid for an
event type, a message is displayed to the user that the option is
ignored for that type. For example:
$ perf script -F comm,tid,trace
'trace' not valid for hardware events. Ignoring.
'trace' not valid for software events. Ignoring.
Alternatively, if the type is given an invalid field is specified it
is an error. For example:
perf script -v -F sw:comm,tid,trace
'trace' not valid for software events.
At this point usage is displayed, and perf-script exits.
perf script: Add field option 'flags' to print sample flags Instruction tracing will typically have access to information about the instruction being executed for a particular ip sample. Some of that information will be available in the 'flags' member of struct perf_sample. With the addition of transactions events synthesis to Instruction Tracing options, there is a need to be able easily to see the flags because they show whether the ip is at the start, commit or abort of a tranasaction. Consequently add an option to display the flags. The flags are "bcrosyiABEx" which stand for branch, call, return, conditional, system, asynchronous, interrupt, transaction abort, trace begin, trace end, and in transaction, respectively. Example using Intel PT: perf script -fip,time,event,sym,addr,flags ... 1288.721584105: branches:u: bo 401146 main => 401152 main 1288.721584105: transactions: x 0 401164 main 1288.721584105: branches:u: bx 40117c main => 40119b main 1288.721584105: branches:u: box 4011a4 main => 40117e main 1288.721584105: branches:u: bcx 401187 main => 401094 g ... 1288.721591645: branches:u: bx 4010c4 g => 4010cb g 1288.721591645: branches:u: brx 4010cc g => 401189 main 1288.721591645: transactions: 0 4011a6 main 1288.721593199: branches:u: b 4011a9 main => 4011af main 1288.721593199: branches:u: bo 4011bc main => 40113e main 1288.721593199: branches:u: b 401150 main => 40115a main 1288.721593199: transactions: x 0 401164 main 1288.721593199: branches:u: bx 40117c main => 40119b main 1288.721593199: branches:u: box 4011a4 main => 40117e main 1288.721593199: branches:u: bcx 401187 main => 40105e f ... 1288.722284747: branches:u: brx 401093 f => 401189 main 1288.722284747: branches:u: box 4011a4 main => 40117e main 1288.722284747: branches:u: bcx 401187 main => 40105e f 1288.722285883: transactions: bA 0 401071 f 1288.722285883: branches:u: bA 401071 f => 40116a main 1288.722285883: branches:u: bE 40116a main => 0 [unknown] 1288.722297174: branches:u: bB 0 [unknown] => 40116a main ... Signed-off-by: Adrian Hunter <adrian.hunter@intel.com> Cc: David Ahern <dsahern@gmail.com> Cc: Frederic Weisbecker <fweisbec@gmail.com> Cc: Jiri Olsa <jolsa@redhat.com> Cc: Namhyung Kim <namhyung@gmail.com> Cc: Peter Zijlstra <peterz@infradead.org> Cc: Stephane Eranian <eranian@google.com> Link: http://lkml.kernel.org/r/1428594864-29309-26-git-send-email-adrian.hunter@intel.com Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2015-04-09 23:54:05 +08:00
The flags field is synthesized and may have a value when Instruction
Trace decoding. The flags are "bcrosyiABEx" which stand for branch,
call, return, conditional, system, asynchronous, interrupt,
transaction abort, trace begin, trace end, and in transaction,
perf script: Print sample flags more nicely The flags field is synthesized and may have a value when Instruction Trace decoding. The flags are "bcrosyiABEx" which stand for branch, call, return, conditional, system, asynchronous, interrupt, transaction abort, trace begin, trace end, and in transaction, respectively. Change the display so that known combinations of flags are printed more nicely e.g.: "call" for "bc", "return" for "br", "jcc" for "bo", "jmp" for "b", "int" for "bci", "iret" for "bri", "syscall" for "bcs", "sysret" for "brs", "async" for "by", "hw int" for "bcyi", "tx abrt" for "bA", "tr strt" for "bB", "tr end" for "bE". However the "x" flag will be displayed separately in those cases e.g. "jcc (x)" for a condition branch within a transaction. Example: perf record -e intel_pt//u ls perf script --ns -F comm,cpu,pid,tid,time,ip,addr,sym,dso,symoff,flags ... ls 3689/3689 [001] 2062.020965237: jcc 7f06a958847a _dl_sysdep_start+0xfa (/lib/x86_64-linux-gnu/ld-2.19.so) => 7f06a9588450 _dl_sysdep_start+0xd0 (/lib/x86_64-linux-gnu/ld-2.19.so) ls 3689/3689 [001] 2062.020965237: jmp 7f06a9588461 _dl_sysdep_start+0xe1 (/lib/x86_64-linux-gnu/ld-2.19.so) => 7f06a95885a0 _dl_sysdep_start+0x220 (/lib/x86_64-linux-gnu/ld-2.19.so) ls 3689/3689 [001] 2062.020965237: jmp 7f06a95885a4 _dl_sysdep_start+0x224 (/lib/x86_64-linux-gnu/ld-2.19.so) => 7f06a9588470 _dl_sysdep_start+0xf0 (/lib/x86_64-linux-gnu/ld-2.19.so) ls 3689/3689 [001] 2062.020965904: call 7f06a95884c3 _dl_sysdep_start+0x143 (/lib/x86_64-linux-gnu/ld-2.19.so) => 7f06a9589140 brk+0x0 (/lib/x86_64-linux-gnu/ld-2.19.so) ls 3689/3689 [001] 2062.020965904: syscall 7f06a958914a brk+0xa (/lib/x86_64-linux-gnu/ld-2.19.so) => 0 [unknown] ([unknown]) ls 3689/3689 [001] 2062.020966237: tr strt 0 [unknown] ([unknown]) => 7f06a958914c brk+0xc (/lib/x86_64-linux-gnu/ld-2.19.so) ls 3689/3689 [001] 2062.020966237: return 7f06a9589165 brk+0x25 (/lib/x86_64-linux-gnu/ld-2.19.so) => 7f06a95884c8 _dl_sysdep_start+0x148 (/lib/x86_64-linux-gnu/ld-2.19.so) ls 3689/3689 [001] 2062.020966237: jcc 7f06a95884d7 _dl_sysdep_start+0x157 (/lib/x86_64-linux-gnu/ld-2.19.so) => 7f06a95885f0 _dl_sysdep_start+0x270 (/lib/x86_64-linux-gnu/ld-2.19.so) ls 3689/3689 [001] 2062.020966237: call 7f06a95885f0 _dl_sysdep_start+0x270 (/lib/x86_64-linux-gnu/ld-2.19.so) => 7f06a958ac50 strlen+0x0 (/lib/x86_64-linux-gnu/ld-2.19.so) ls 3689/3689 [001] 2062.020966237: jcc 7f06a958ac6e strlen+0x1e (/lib/x86_64-linux-gnu/ld-2.19.so) => 7f06a958ac60 strlen+0x10 (/lib/x86_64-linux-gnu/ld-2.19.so) ... Signed-off-by: Adrian Hunter <adrian.hunter@intel.com> Acked-by: Andi Kleen <ak@linux.intel.com> Tested-by: Arnaldo Carvalho de Melo <acme@redhat.com> Cc: Jiri Olsa <jolsa@redhat.com> Link: http://lkml.kernel.org/r/1466689258-28493-2-git-send-email-adrian.hunter@intel.com Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2016-06-23 21:40:56 +08:00
respectively. Known combinations of flags are printed more nicely e.g.
"call" for "bc", "return" for "br", "jcc" for "bo", "jmp" for "b",
"int" for "bci", "iret" for "bri", "syscall" for "bcs", "sysret" for "brs",
"async" for "by", "hw int" for "bcyi", "tx abrt" for "bA", "tr strt" for "bB",
"tr end" for "bE". However the "x" flag will be display separately in those
cases e.g. "jcc (x)" for a condition branch within a transaction.
perf script: Add field option 'flags' to print sample flags Instruction tracing will typically have access to information about the instruction being executed for a particular ip sample. Some of that information will be available in the 'flags' member of struct perf_sample. With the addition of transactions events synthesis to Instruction Tracing options, there is a need to be able easily to see the flags because they show whether the ip is at the start, commit or abort of a tranasaction. Consequently add an option to display the flags. The flags are "bcrosyiABEx" which stand for branch, call, return, conditional, system, asynchronous, interrupt, transaction abort, trace begin, trace end, and in transaction, respectively. Example using Intel PT: perf script -fip,time,event,sym,addr,flags ... 1288.721584105: branches:u: bo 401146 main => 401152 main 1288.721584105: transactions: x 0 401164 main 1288.721584105: branches:u: bx 40117c main => 40119b main 1288.721584105: branches:u: box 4011a4 main => 40117e main 1288.721584105: branches:u: bcx 401187 main => 401094 g ... 1288.721591645: branches:u: bx 4010c4 g => 4010cb g 1288.721591645: branches:u: brx 4010cc g => 401189 main 1288.721591645: transactions: 0 4011a6 main 1288.721593199: branches:u: b 4011a9 main => 4011af main 1288.721593199: branches:u: bo 4011bc main => 40113e main 1288.721593199: branches:u: b 401150 main => 40115a main 1288.721593199: transactions: x 0 401164 main 1288.721593199: branches:u: bx 40117c main => 40119b main 1288.721593199: branches:u: box 4011a4 main => 40117e main 1288.721593199: branches:u: bcx 401187 main => 40105e f ... 1288.722284747: branches:u: brx 401093 f => 401189 main 1288.722284747: branches:u: box 4011a4 main => 40117e main 1288.722284747: branches:u: bcx 401187 main => 40105e f 1288.722285883: transactions: bA 0 401071 f 1288.722285883: branches:u: bA 401071 f => 40116a main 1288.722285883: branches:u: bE 40116a main => 0 [unknown] 1288.722297174: branches:u: bB 0 [unknown] => 40116a main ... Signed-off-by: Adrian Hunter <adrian.hunter@intel.com> Cc: David Ahern <dsahern@gmail.com> Cc: Frederic Weisbecker <fweisbec@gmail.com> Cc: Jiri Olsa <jolsa@redhat.com> Cc: Namhyung Kim <namhyung@gmail.com> Cc: Peter Zijlstra <peterz@infradead.org> Cc: Stephane Eranian <eranian@google.com> Link: http://lkml.kernel.org/r/1428594864-29309-26-git-send-email-adrian.hunter@intel.com Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2015-04-09 23:54:05 +08:00
perf script: Add callindent option Based on patches from Andi Kleen. When printing PT instruction traces with perf script it is rather useful to see some indentation for the call tree. This patch adds a new callindent field to perf script that prints spaces for the function call stack depth. We already have code to track the function call stack for PT, that we can reuse with minor modifications. The resulting output is not quite as nice as ftrace yet, but a lot better than what was there before. Note there are some corner cases when the thread stack gets code confused and prints incorrect indentation. Even with that it is fairly useful. When displaying kernel code traces it is recommended to run as root, as otherwise perf doesn't understand the kernel addresses properly, and may not reset the call stack correctly on kernel boundaries. Example output: sudo perf-with-kcore record eg2 -a -e intel_pt// -- sleep 1 sudo perf-with-kcore script eg2 --ns -F callindent,time,comm,pid,sym,ip,addr,flags,cpu --itrace=cre | less ... swapper 0 [000] 5830.389116586: call irq_exit ffffffff8104d620 smp_call_function_single_interrupt+0x30 => ffffffff8107e720 irq_exit swapper 0 [000] 5830.389116586: call idle_cpu ffffffff8107e769 irq_exit+0x49 => ffffffff810a3970 idle_cpu swapper 0 [000] 5830.389116586: return idle_cpu ffffffff810a39b7 idle_cpu+0x47 => ffffffff8107e76e irq_exit swapper 0 [000] 5830.389116586: call tick_nohz_irq_exit ffffffff8107e7bd irq_exit+0x9d => ffffffff810f2fc0 tick_nohz_irq_exit swapper 0 [000] 5830.389116919: call __tick_nohz_idle_enter ffffffff810f2fe0 tick_nohz_irq_exit+0x20 => ffffffff810f28d0 __tick_nohz_idle_enter swapper 0 [000] 5830.389116919: call ktime_get ffffffff810f28f1 __tick_nohz_idle_enter+0x21 => ffffffff810e9ec0 ktime_get swapper 0 [000] 5830.389116919: call read_tsc ffffffff810e9ef6 ktime_get+0x36 => ffffffff81035070 read_tsc swapper 0 [000] 5830.389116919: return read_tsc ffffffff81035084 read_tsc+0x14 => ffffffff810e9efc ktime_get swapper 0 [000] 5830.389116919: return ktime_get ffffffff810e9f46 ktime_get+0x86 => ffffffff810f28f6 __tick_nohz_idle_enter swapper 0 [000] 5830.389116919: call sched_clock_idle_sleep_event ffffffff810f290b __tick_nohz_idle_enter+0x3b => ffffffff810a7380 sched_clock_idle_sleep_event swapper 0 [000] 5830.389116919: call sched_clock_cpu ffffffff810a738b sched_clock_idle_sleep_event+0xb => ffffffff810a72e0 sched_clock_cpu swapper 0 [000] 5830.389116919: call sched_clock ffffffff810a734d sched_clock_cpu+0x6d => ffffffff81035750 sched_clock swapper 0 [000] 5830.389116919: call native_sched_clock ffffffff81035754 sched_clock+0x4 => ffffffff81035640 native_sched_clock swapper 0 [000] 5830.389116919: return native_sched_clock ffffffff8103568c native_sched_clock+0x4c => ffffffff81035759 sched_clock swapper 0 [000] 5830.389116919: return sched_clock ffffffff8103575c sched_clock+0xc => ffffffff810a7352 sched_clock_cpu swapper 0 [000] 5830.389116919: return sched_clock_cpu ffffffff810a7356 sched_clock_cpu+0x76 => ffffffff810a7390 sched_clock_idle_sleep_event swapper 0 [000] 5830.389116919: return sched_clock_idle_sleep_event ffffffff810a7391 sched_clock_idle_sleep_event+0x11 => ffffffff810f2910 __tick_nohz_idle_enter ... Signed-off-by: Adrian Hunter <adrian.hunter@intel.com> Acked-by: Andi Kleen <ak@linux.intel.com> Tested-by: Arnaldo Carvalho de Melo <acme@redhat.com> Cc: Jiri Olsa <jolsa@redhat.com> Link: http://lkml.kernel.org/r/1466689258-28493-4-git-send-email-adrian.hunter@intel.com Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2016-06-23 21:40:58 +08:00
The callindent field is synthesized and may have a value when
Instruction Trace decoding. For calls and returns, it will display the
name of the symbol indented with spaces to reflect the stack depth.
When doing instruction trace decoding insn and insnlen give the
instruction bytes and the instruction length of the current
instruction.
The synth field is used by synthesized events which may be created when
Instruction Trace decoding.
Finally, a user may not set fields to none for all event types.
i.e., -F "" is not allowed.
The brstack output includes branch related information with raw addresses using the
perf script: Add 'brstackinsn' for branch stacks Implement printing instruction sequences as hex dump for branch stacks. This relies on the x86 instruction decoder used by the PT decoder to find the lengths of instructions to dump them individually. This is good enough for pattern matching. This allows to study hot paths for individual samples, together with branch misprediction and cycle count / IPC information if available (on Skylake systems). % perf record -b ... % perf script -F brstackinsn ... read_hpet+67: ffffffff9905b843 insn: 74 ea # PRED ffffffff9905b82f insn: 85 c9 ffffffff9905b831 insn: 74 12 ffffffff9905b833 insn: f3 90 ffffffff9905b835 insn: 48 8b 0f ffffffff9905b838 insn: 48 89 ca ffffffff9905b83b insn: 48 c1 ea 20 ffffffff9905b83f insn: 39 f2 ffffffff9905b841 insn: 89 d0 ffffffff9905b843 insn: 74 ea # PRED Only works when no special branch filters are specified. Occasionally the path does not reach up to the sample IP, as the LBRs may be frozen before executing a final jump. In this case we print a special message. The instruction dumper piggy backs on the existing infrastructure from the IP PT decoder. An earlier iteration of this patch relied on a disassembler, but this version only uses the existing instruction decoder. Committer note: Added hint about how to get suitable perf.data files for use with '-F brstackinsm': $ perf record usleep 1 [ perf record: Woken up 1 times to write data ] [ perf record: Captured and wrote 0.018 MB perf.data (8 samples) ] $ $ perf script -F brstackinsn Display of branch stack assembler requested, but non all-branch filter set Hint: run 'perf record -b ...' $ Signed-off-by: Andi Kleen <ak@linux.intel.com> Tested-by: Arnaldo Carvalho de Melo <acme@redhat.com> Cc: Jiri Olsa <jolsa@kernel.org> Cc: Michael Ellerman <mpe@ellerman.id.au> Link: http://lkml.kernel.org/r/20170223234634.583-1-andi@firstfloor.org Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2017-02-24 07:46:34 +08:00
/v/v/v/v/cycles syntax in the following order:
FROM: branch source instruction
TO : branch target instruction
M/P/-: M=branch target mispredicted or branch direction was mispredicted, P=target predicted or direction predicted, -=not supported
X/- : X=branch inside a transactional region, -=not in transaction region or not supported
A/- : A=TSX abort entry, -=not aborted region or not supported
perf script: Add 'brstackinsn' for branch stacks Implement printing instruction sequences as hex dump for branch stacks. This relies on the x86 instruction decoder used by the PT decoder to find the lengths of instructions to dump them individually. This is good enough for pattern matching. This allows to study hot paths for individual samples, together with branch misprediction and cycle count / IPC information if available (on Skylake systems). % perf record -b ... % perf script -F brstackinsn ... read_hpet+67: ffffffff9905b843 insn: 74 ea # PRED ffffffff9905b82f insn: 85 c9 ffffffff9905b831 insn: 74 12 ffffffff9905b833 insn: f3 90 ffffffff9905b835 insn: 48 8b 0f ffffffff9905b838 insn: 48 89 ca ffffffff9905b83b insn: 48 c1 ea 20 ffffffff9905b83f insn: 39 f2 ffffffff9905b841 insn: 89 d0 ffffffff9905b843 insn: 74 ea # PRED Only works when no special branch filters are specified. Occasionally the path does not reach up to the sample IP, as the LBRs may be frozen before executing a final jump. In this case we print a special message. The instruction dumper piggy backs on the existing infrastructure from the IP PT decoder. An earlier iteration of this patch relied on a disassembler, but this version only uses the existing instruction decoder. Committer note: Added hint about how to get suitable perf.data files for use with '-F brstackinsm': $ perf record usleep 1 [ perf record: Woken up 1 times to write data ] [ perf record: Captured and wrote 0.018 MB perf.data (8 samples) ] $ $ perf script -F brstackinsn Display of branch stack assembler requested, but non all-branch filter set Hint: run 'perf record -b ...' $ Signed-off-by: Andi Kleen <ak@linux.intel.com> Tested-by: Arnaldo Carvalho de Melo <acme@redhat.com> Cc: Jiri Olsa <jolsa@kernel.org> Cc: Michael Ellerman <mpe@ellerman.id.au> Link: http://lkml.kernel.org/r/20170223234634.583-1-andi@firstfloor.org Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2017-02-24 07:46:34 +08:00
cycles
The brstacksym is identical to brstack, except that the FROM and TO addresses are printed in a symbolic form if possible.
perf script: Add 'brstackinsn' for branch stacks Implement printing instruction sequences as hex dump for branch stacks. This relies on the x86 instruction decoder used by the PT decoder to find the lengths of instructions to dump them individually. This is good enough for pattern matching. This allows to study hot paths for individual samples, together with branch misprediction and cycle count / IPC information if available (on Skylake systems). % perf record -b ... % perf script -F brstackinsn ... read_hpet+67: ffffffff9905b843 insn: 74 ea # PRED ffffffff9905b82f insn: 85 c9 ffffffff9905b831 insn: 74 12 ffffffff9905b833 insn: f3 90 ffffffff9905b835 insn: 48 8b 0f ffffffff9905b838 insn: 48 89 ca ffffffff9905b83b insn: 48 c1 ea 20 ffffffff9905b83f insn: 39 f2 ffffffff9905b841 insn: 89 d0 ffffffff9905b843 insn: 74 ea # PRED Only works when no special branch filters are specified. Occasionally the path does not reach up to the sample IP, as the LBRs may be frozen before executing a final jump. In this case we print a special message. The instruction dumper piggy backs on the existing infrastructure from the IP PT decoder. An earlier iteration of this patch relied on a disassembler, but this version only uses the existing instruction decoder. Committer note: Added hint about how to get suitable perf.data files for use with '-F brstackinsm': $ perf record usleep 1 [ perf record: Woken up 1 times to write data ] [ perf record: Captured and wrote 0.018 MB perf.data (8 samples) ] $ $ perf script -F brstackinsn Display of branch stack assembler requested, but non all-branch filter set Hint: run 'perf record -b ...' $ Signed-off-by: Andi Kleen <ak@linux.intel.com> Tested-by: Arnaldo Carvalho de Melo <acme@redhat.com> Cc: Jiri Olsa <jolsa@kernel.org> Cc: Michael Ellerman <mpe@ellerman.id.au> Link: http://lkml.kernel.org/r/20170223234634.583-1-andi@firstfloor.org Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2017-02-24 07:46:34 +08:00
When brstackinsn is specified the full assembler sequences of branch sequences for each sample
is printed. This is the full execution path leading to the sample. This is only supported when the
sample was recorded with perf record -b or -j any.
perf script: Support -F brstackoff,dso The idea here is to make AutoFDO easier in cloud environment with ASLR. It's easiest to show how this is useful by example. I built a small test akin to "while(1) { do_nothing(); }" where the do_nothing function is loaded from a dso: $ cat burncpu.cpp #include <dlfcn.h> int main() { void* handle = dlopen("./dso.so", RTLD_LAZY); if (!handle) return -1; typedef void (*fp)(); fp do_nothing = (fp) dlsym(handle, "do_nothing"); while(1) { do_nothing(); } } $ cat dso.cpp extern "C" void do_nothing() {} $ cat build.sh #!/bin/bash g++ -shared dso.cpp -o dso.so g++ burncpu.cpp -o burncpu -ldl I sampled the execution of this program with perf record -b. Using the existing "brstack,dso", we get absolute addresses that are affected by ASLR, and could be different on different hosts. The address does not uniquely identify a branch/target in the binary: $ perf script -F brstack,dso | sed 's/\/0 /\/0\n/g' | grep burncpu | grep dso.so | head -n 1 0x7f967139b6aa(/tmp/burncpu/dso.so)/0x4006b1(/tmp/burncpu/exe)/P/-/-/0 Using the existing "brstacksym,dso" is a little better, because the symbol plus offset and dso name *does* uniquely identify a branch/target in the binary. Ultimately, however, AutoFDO wants a simple offset into the binary, so we'd have to undo all the work perf did to symbolize in the first place: $ perf script -F brstacksym,dso | sed 's/\/0 /\/0\n/g' | grep burncpu | grep dso.so | head -n 1 do_nothing+0x5(/tmp/burncpu/dso.so)/main+0x44(/tmp/burncpu/exe)/P/-/-/0 With the new "brstackoff,dso" we get what we need: a simple offset into a specific dso/binary that uniquely identifies a branch/target: $ perf script -F brstackoff,dso | sed 's/\/0 /\/0\n/g' | grep burncpu | grep dso.so | head -n 1 0x6aa(/tmp/burncpu/dso.so)/0x4006b1(/tmp/burncpu/exe)/P/-/-/0 Signed-off-by: Mark Santaniello <marksan@fb.com> Tested-by: Arnaldo Carvalho de Melo <acme@redhat.com> Cc: Alexander Shishkin <alexander.shishkin@linux.intel.com> Cc: Peter Zijlstra <peterz@infradead.org> Link: http://lkml.kernel.org/r/20170619163825.2012979-2-marksan@fb.com [ Updated documentation about 'brstackoff' using text from above ] Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2017-06-20 00:38:25 +08:00
The brstackoff field will print an offset into a specific dso/binary.
perf script: Allow computing 'perf stat' style metrics Add support for computing 'perf stat' style metrics in 'perf script'. When using leader sampling we can get metrics for each sampling period by computing formulas over the values of the different group members. This allows things like fine grained IPC tracking through sampling, much more fine grained than with 'perf stat'. The metric is still averaged over the sampling period, it is not just for the sampling point. This patch adds a new metric output field for 'perf script' that uses the existing 'perf stat' metrics infrastructure to compute any metrics supported by 'perf stat'. For example to sample IPC: $ perf record -e '{ref-cycles,cycles,instructions}:S' -a sleep 1 $ perf script -F metric,ip,sym,time,cpu,comm ... alsa-sink-ALC32 [000] 42815.856074: 7fd65937d6cc [unknown] alsa-sink-ALC32 [000] 42815.856074: 7fd65937d6cc [unknown] alsa-sink-ALC32 [000] 42815.856074: 7fd65937d6cc [unknown] alsa-sink-ALC32 [000] 42815.856074: metric: 0.13 insn per cycle swapper [000] 42815.857961: ffffffff81655df0 __schedule swapper [000] 42815.857961: ffffffff81655df0 __schedule swapper [000] 42815.857961: ffffffff81655df0 __schedule swapper [000] 42815.857961: metric: 0.23 insn per cycle qemu-system-x86 [000] 42815.858130: ffffffff8165ad0e _raw_spin_unlock_irqrestore qemu-system-x86 [000] 42815.858130: ffffffff8165ad0e _raw_spin_unlock_irqrestore qemu-system-x86 [000] 42815.858130: ffffffff8165ad0e _raw_spin_unlock_irqrestore qemu-system-x86 [000] 42815.858130: metric: 0.46 insn per cycle :4972 [000] 42815.858312: ffffffffa080e5f2 vmx_vcpu_run :4972 [000] 42815.858312: ffffffffa080e5f2 vmx_vcpu_run :4972 [000] 42815.858312: ffffffffa080e5f2 vmx_vcpu_run :4972 [000] 42815.858312: metric: 0.45 insn per cycle TopDown: This requires disabling SMT if you have it enabled, because SMT would require sampling per core, which is not supported. $ perf record -e '{ref-cycles,topdown-fetch-bubbles,\ topdown-recovery-bubbles,\ topdown-slots-retired,topdown-total-slots,\ topdown-slots-issued}:S' -a sleep 1 $ perf script --header -I -F cpu,ip,sym,event,metric,period ... [000] 121108 ref-cycles: ffffffff8165222e copy_user_enhanced_fast_string [000] 190350 topdown-fetch-bubbles: ffffffff8165222e copy_user_enhanced_fast_string [000] 2055 topdown-recovery-bubbles: ffffffff8165222e copy_user_enhanced_fast_string [000] 148729 topdown-slots-retired: ffffffff8165222e copy_user_enhanced_fast_string [000] 144324 topdown-total-slots: ffffffff8165222e copy_user_enhanced_fast_string [000] 160852 topdown-slots-issued: ffffffff8165222e copy_user_enhanced_fast_string [000] metric: 33.0% frontend bound [000] metric: 3.5% bad speculation [000] metric: 25.8% retiring [000] metric: 37.7% backend bound [000] 112112 ref-cycles: ffffffff8165aec8 _raw_spin_lock_irqsave [000] 357222 topdown-fetch-bubbles: ffffffff8165aec8 _raw_spin_lock_irqsave [000] 3325 topdown-recovery-bubbles: ffffffff8165aec8 _raw_spin_lock_irqsave [000] 323553 topdown-slots-retired: ffffffff8165aec8 _raw_spin_lock_irqsave [000] 270507 topdown-total-slots: ffffffff8165aec8 _raw_spin_lock_irqsave [000] 341226 topdown-slots-issued: ffffffff8165aec8 _raw_spin_lock_irqsave [000] metric: 33.0% frontend bound [000] metric: 2.9% bad speculation [000] metric: 29.9% retiring [000] metric: 34.2% backend bound ... v2: Use evsel->priv for new fields Port to new base line, support fp output. Handle stats in ->stats, not ->priv Minor cleanups Extra explanation about the use of the term 'averaging', from Andi in the thread in the Link: tag below: <quote Andi> The current samples contains the sum of event counts for a sampling period. EventA-1 EventA-2 EventA-3 EventA-4 EventB-1 EventB-2 EventC-3 gap with no events overflow |-----------------------------------------------------------------| period-start period-end ^ ^ | | previous sample current sample So EventA = 4 and EventB = 3 at the sample point I generate a metric, let's say EventA / EventB. It applies to the whole period. But the metric is over a longer time which does not have the same behavior. For example the gap above doesn't have any events, while they are clustered at the beginning and end of the sample period. But we're summing everything together. The metric doesn't know that the gap is different than the busy period. That's what I'm trying to express with averaging. </quote> Signed-off-by: Andi Kleen <ak@linux.intel.com> Acked-by: Jiri Olsa <jolsa@kernel.org> Link: http://lkml.kernel.org/r/20171117214300.32746-4-andi@firstfloor.org Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2017-11-18 05:43:00 +08:00
With the metric option perf script can compute metrics for
sampling periods, similar to perf stat. This requires
specifying a group with multiple metrics with the :S option
for perf record. perf will sample on the first event, and
compute metrics for all the events in the group. Please note
that the metric computed is averaged over the whole sampling
period, not just for the sample point.
For sample events it's possible to display misc field with -F +misc option,
following letters are displayed for each bit:
perf script: Extend misc field decoding with switch out event type 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>
2018-04-09 15:26:46 +08:00
PERF_RECORD_MISC_KERNEL K
PERF_RECORD_MISC_USER U
PERF_RECORD_MISC_HYPERVISOR H
PERF_RECORD_MISC_GUEST_KERNEL G
PERF_RECORD_MISC_GUEST_USER g
PERF_RECORD_MISC_MMAP_DATA* M
PERF_RECORD_MISC_COMM_EXEC E
PERF_RECORD_MISC_SWITCH_OUT S
PERF_RECORD_MISC_SWITCH_OUT_PREEMPT Sp
$ perf script -F +misc ...
sched-messaging 1414 K 28690.636582: 4590 cycles ...
sched-messaging 1407 U 28690.636600: 325620 cycles ...
sched-messaging 1414 K 28690.636608: 19473 cycles ...
misc field ___________/
perf script: Add support for dumping symbols Add option to dump symbols found in events. e.g., perf script -f comm,pid,tid,time,trace,sym swapper 0/0 537.037184: prev_comm=swapper prev_pid=0 prev_prio=120... ffffffff81030350 perf_trace_sched_switch ([kernel.kallsyms]) ffffffff81382ac5 schedule ([kernel.kallsyms]) ffffffff8100134a cpu_idle ([kernel.kallsyms]) ffffffff81370b39 rest_init ([kernel.kallsyms]) ffffffff81696c23 start_kernel ([kernel.kallsyms].init.text) ffffffff816962af x86_64_start_reservations ([kernel.kallsyms].init.text) ffffffff816963b9 x86_64_start_kernel ([kernel.kallsyms].init.text) sshd 1675/1675 537.037309: prev_comm=sshd prev_pid=1675 prev_prio=120... ffffffff81030350 perf_trace_sched_switch ([kernel.kallsyms]) ffffffff81382ac5 schedule ([kernel.kallsyms]) ffffffff813837aa schedule_hrtimeout_range_clock ([kernel.kallsyms]) ffffffff81383886 schedule_hrtimeout_range ([kernel.kallsyms]) ffffffff8110c4f9 poll_schedule_timeout ([kernel.kallsyms]) ffffffff8110cd20 do_select ([kernel.kallsyms]) ffffffff8110ced8 core_sys_select ([kernel.kallsyms]) ffffffff8110d00d sys_select ([kernel.kallsyms]) ffffffff81002bc2 system_call ([kernel.kallsyms]) 7f1647e56e93 __GI_select (/lib64/libc-2.12.90.so) netstat 1692/1692 537.038664: prev_comm=netstat prev_pid=1692 prev_prio=... ffffffff81030350 perf_trace_sched_switch ([kernel.kallsyms]) ffffffff81382ac5 schedule ([kernel.kallsyms]) ffffffff81002c3a sysret_careful ([kernel.kallsyms]) 7f7a6cd1b210 __GI___libc_read (/lib64/libc-2.12.90.so) Acked-by: Frederic Weisbecker <fweisbec@gmail.com> Cc: Frederic Weisbecker <fweisbec@gmail.com> Cc: Ingo Molnar <mingo@elte.hu> Cc: Paul Mackerras <paulus@samba.org> Cc: Peter Zijlstra <peterz@infradead.org> Cc: Thomas Gleixner <tglx@linutronix.de> LKML-Reference: <1299734608-5223-6-git-send-email-daahern@cisco.com> Signed-off-by: David Ahern <daahern@cisco.com> Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2011-03-10 13:23:27 +08:00
-k::
--vmlinux=<file>::
vmlinux pathname
--kallsyms=<file>::
kallsyms pathname
--symfs=<directory>::
Look for files with symbols relative to this directory.
-G::
--hide-call-graph::
When printing symbols do not display call chain.
perf script: Support custom field selection for output Allow a user to select which fields to print to stdout for event data. Options include comm (command name), tid (thread id), pid (process id), time (perf timestamp), cpu, event (for event name), and trace (for trace data). Default is set to maintain compatibility with current output; this feature does alter output format slightly -- no '-' between command and pid/tid. Thanks to Frederic Weisbecker for detailed suggestions on this approach. Examples (output compressed) 1. trace, default format perf record -ga -e sched:sched_switch perf script swapper 0 [000] 537.037184: sched_switch: prev_comm=swapper prev_pid=0... sshd 1675 [000] 537.037309: sched_switch: prev_comm=sshd prev_pid=1675... netstat 1692 [001] 537.038664: sched_switch: prev_comm=netstat prev_pid=1692... 2. trace, custom format perf record -ga -e sched:sched_switch perf script -f comm,pid,time,trace <--- omitting cpu and event name swapper 0 537.037184: prev_comm=swapper prev_pid=0 prev_prio=120 ... sshd 1675 537.037309: prev_comm=sshd prev_pid=1675 prev_prio=120 ... netstat 1692 537.038664: prev_comm=netstat prev_pid=1692 prev_prio=120 ... Acked-by: Frederic Weisbecker <fweisbec@gmail.com> Cc: Frederic Weisbecker <fweisbec@gmail.com> Cc: Ingo Molnar <mingo@elte.hu> Cc: Paul Mackerras <paulus@samba.org> Cc: Peter Zijlstra <peterz@infradead.org> Cc: Thomas Gleixner <tglx@linutronix.de> LKML-Reference: <1299734608-5223-5-git-send-email-daahern@cisco.com> Signed-off-by: David Ahern <daahern@cisco.com> Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2011-03-10 13:23:26 +08:00
perf script: Add option to stop printing callchain Allow user to specify list of symbols which cause the dump of callchains to stop at that symbol. Committer notes: Testing it: # perf record -ag usleep 1 [ perf record: Woken up 1 times to write data ] [ perf record: Captured and wrote 1.177 MB perf.data (33 samples) ] # # # Without it: # # perf script swapper 0 [000] 9693.370039: 1 cycles:ppp: 2072ad x86_pmu_enable (/usr/lib/debug/lib/modules/4.8.8-300.fc25.x86_64/vmlinux) 3a29d7 perf_pmu_enable.part.90 (/usr/lib/debug/lib/modules/4.8.8-300.fc25.x86_64/vmlinux) 3a713a ctx_resched (/usr/lib/debug/lib/modules/4.8.8-300.fc25.x86_64/vmlinux) 3a76c1 __perf_event_enable (/usr/lib/debug/lib/modules/4.8.8-300.fc25.x86_64/vmlinux) 3a0390 event_function (/usr/lib/debug/lib/modules/4.8.8-300.fc25.x86_64/vmlinux) 3a1cff remote_function (/usr/lib/debug/lib/modules/4.8.8-300.fc25.x86_64/vmlinux) 326978 flush_smp_call_function_queue (/usr/lib/debug/lib/modules/4.8.8-300.fc25.x86_64/vmlinux) 327413 generic_smp_call_function_single_interrupt (/usr/lib/debug/lib/modules/4.8.8-300.fc25.x86_64/vmlinux) 249b37 smp_call_function_single_interrupt (/usr/lib/debug/lib/modules/4.8.8-300.fc25.x86_64/vmlinux) a04b2c call_function_single_interrupt (/usr/lib/debug/lib/modules/4.8.8-300.fc25.x86_64/vmlinux) 889427 cpuidle_enter (/usr/lib/debug/lib/modules/4.8.8-300.fc25.x86_64/vmlinux) 2e534a call_cpuidle (/usr/lib/debug/lib/modules/4.8.8-300.fc25.x86_64/vmlinux) 2e5730 cpu_startup_entry (/usr/lib/debug/lib/modules/4.8.8-300.fc25.x86_64/vmlinux) 9f5167 rest_init (/usr/lib/debug/lib/modules/4.8.8-300.fc25.x86_64/vmlinux) 137ffeb start_kernel ([kernel.vmlinux].init.text) 137f2ca x86_64_start_reservations ([kernel.vmlinux].init.text) 137f419 x86_64_start_kernel ([kernel.vmlinux].init.text) swapper 0 [000] 9693.370044: 1 cycles:ppp: 20ca1b intel_pmu_handle_irq (/usr/lib/debug/lib/modules/4.8.8-300.fc25.x86_64/vmlinux) 205b0c perf_event_nmi_handler (/usr/lib/debug/lib/modules/4.8.8-300.fc25.x86_64/vmlinux) 22a14a nmi_handle (/usr/lib/debug/lib/modules/4.8.8-300.fc25.x86_64/vmlinux) 22a6b3 default_do_nmi (/usr/lib/debug/lib/modules/4.8.8-300.fc25.x86_64/vmlinux) 22a83c do_nmi (/usr/lib/debug/lib/modules/4.8.8-300.fc25.x86_64/vmlinux) a03fb1 end_repeat_nmi (/usr/lib/debug/lib/modules/4.8.8-300.fc25.x86_64/vmlinux) 3a29d7 perf_pmu_enable.part.90 (/usr/lib/debug/lib/modules/4.8.8-300.fc25.x86_64/vmlinux) 3a713a ctx_resched (/usr/lib/debug/lib/modules/4.8.8-300.fc25.x86_64/vmlinux) 3a76c1 __perf_event_enable (/usr/lib/debug/lib/modules/4.8.8-300.fc25.x86_64/vmlinux) 3a0390 event_function (/usr/lib/debug/lib/modules/4.8.8-300.fc25.x86_64/vmlinux) 3a1cff remote_function (/usr/lib/debug/lib/modules/4.8.8-300.fc25.x86_64/vmlinux) 326978 flush_smp_call_function_queue (/usr/lib/debug/lib/modules/4.8.8-300.fc25.x86_64/vmlinux) 327413 generic_smp_call_function_single_interrupt (/usr/lib/debug/lib/modules/4.8.8-300.fc25.x86_64/vmlinux) 249b37 smp_call_function_single_interrupt (/usr/lib/debug/lib/modules/4.8.8-300.fc25.x86_64/vmlinux) a04b2c call_function_single_interrupt (/usr/lib/debug/lib/modules/4.8.8-300.fc25.x86_64/vmlinux) 889427 cpuidle_enter (/usr/lib/debug/lib/modules/4.8.8-300.fc25.x86_64/vmlinux) 2e534a call_cpuidle (/usr/lib/debug/lib/modules/4.8.8-300.fc25.x86_64/vmlinux) 2e5730 cpu_startup_entry (/usr/lib/debug/lib/modules/4.8.8-300.fc25.x86_64/vmlinux) 9f5167 rest_init (/usr/lib/debug/lib/modules/4.8.8-300.fc25.x86_64/vmlinux) 137ffeb start_kernel ([kernel.vmlinux].init.text) 137f2ca x86_64_start_reservations ([kernel.vmlinux].init.text) # # # Using it to see just what are the calls from the 'remote_function' function: # # perf script --stop-bt remote_function swapper 0 [000] 9693.370039: 1 cycles:ppp: 2072ad x86_pmu_enable (/usr/lib/debug/lib/modules/4.8.8-300.fc25.x86_64/vmlinux) 3a29d7 perf_pmu_enable.part.90 (/usr/lib/debug/lib/modules/4.8.8-300.fc25.x86_64/vmlinux) 3a713a ctx_resched (/usr/lib/debug/lib/modules/4.8.8-300.fc25.x86_64/vmlinux) 3a76c1 __perf_event_enable (/usr/lib/debug/lib/modules/4.8.8-300.fc25.x86_64/vmlinux) 3a0390 event_function (/usr/lib/debug/lib/modules/4.8.8-300.fc25.x86_64/vmlinux) 3a1cff remote_function (/usr/lib/debug/lib/modules/4.8.8-300.fc25.x86_64/vmlinux) swapper 0 [000] 9693.370044: 1 cycles:ppp: 20ca1b intel_pmu_handle_irq (/usr/lib/debug/lib/modules/4.8.8-300.fc25.x86_64/vmlinux) 205b0c perf_event_nmi_handler (/usr/lib/debug/lib/modules/4.8.8-300.fc25.x86_64/vmlinux) 22a14a nmi_handle (/usr/lib/debug/lib/modules/4.8.8-300.fc25.x86_64/vmlinux) 22a6b3 default_do_nmi (/usr/lib/debug/lib/modules/4.8.8-300.fc25.x86_64/vmlinux) 22a83c do_nmi (/usr/lib/debug/lib/modules/4.8.8-300.fc25.x86_64/vmlinux) a03fb1 end_repeat_nmi (/usr/lib/debug/lib/modules/4.8.8-300.fc25.x86_64/vmlinux) 3a29d7 perf_pmu_enable.part.90 (/usr/lib/debug/lib/modules/4.8.8-300.fc25.x86_64/vmlinux) 3a713a ctx_resched (/usr/lib/debug/lib/modules/4.8.8-300.fc25.x86_64/vmlinux) 3a76c1 __perf_event_enable (/usr/lib/debug/lib/modules/4.8.8-300.fc25.x86_64/vmlinux) 3a0390 event_function (/usr/lib/debug/lib/modules/4.8.8-300.fc25.x86_64/vmlinux) 3a1cff remote_function (/usr/lib/debug/lib/modules/4.8.8-300.fc25.x86_64/vmlinux) Signed-off-by: David Ahern <dsa@cumulusnetworks.com> Tested-by: Arnaldo Carvalho de Melo <acme@redhat.com> Cc: Jiri Olsa <jolsa@kernel.org> Cc: Namhyung Kim <namhyung@kernel.org> Cc: Peter Zijlstra <peterz@infradead.org> Link: http://lkml.kernel.org/r/1480104021-36275-1-git-send-email-dsahern@gmail.com Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2016-11-26 04:00:21 +08:00
--stop-bt::
Stop display of callgraph at these symbols
-C::
--cpu:: Only report samples for the list of CPUs provided. Multiple CPUs can
be provided as a comma-separated list with no space: 0,1. Ranges of
CPUs are specified with -: 0-2. Default is to report samples on all
CPUs.
-c::
--comms=::
Only display events for these comms. CSV that understands
file://filename entries.
--pid=::
Only show events for given process ID (comma separated list).
--tid=::
Only show events for given thread ID (comma separated list).
perf tools: Make perf.data more self-descriptive (v8) The goal of this patch is to include more information about the host environment into the perf.data so it is more self-descriptive. Overtime, profiles are captured on various machines and it becomes hard to track what was recorded, on what machine and when. This patch provides a way to solve this by extending the perf.data file with basic information about the host machine. To add those extensions, we leverage the feature bits capabilities of the perf.data format. The change is backward compatible with existing perf.data files. We define the following useful new extensions: - HEADER_HOSTNAME: the hostname - HEADER_OSRELEASE: the kernel release number - HEADER_ARCH: the hw architecture - HEADER_CPUDESC: generic CPU description - HEADER_NRCPUS: number of online/avail cpus - HEADER_CMDLINE: perf command line - HEADER_VERSION: perf version - HEADER_TOPOLOGY: cpu topology - HEADER_EVENT_DESC: full event description (attrs) - HEADER_CPUID: easy-to-parse low level CPU identication The small granularity for the entries is to make it easier to extend without breaking backward compatiblity. Many entries are provided as ASCII strings. Perf report/script have been modified to print the basic information as easy-to-parse ASCII strings. Extended information about CPU and NUMA topology may be requested with the -I option. Thanks to David Ahern for reviewing and testing the many versions of this patch. $ perf report --stdio # ======== # captured on : Mon Sep 26 15:22:14 2011 # hostname : quad # os release : 3.1.0-rc4-tip # perf version : 3.1.0-rc4 # arch : x86_64 # nrcpus online : 4 # nrcpus avail : 4 # cpudesc : Intel(R) Core(TM)2 Quad CPU Q6600 @ 2.40GHz # cpuid : GenuineIntel,6,15,11 # total memory : 8105360 kB # cmdline : /home/eranian/perfmon/official/tip/build/tools/perf/perf record date # event : name = cycles, type = 0, config = 0x0, config1 = 0x0, config2 = 0x0, excl_usr = 0, excl_kern = 0, id = { 29, 30, 31, # HEADER_CPU_TOPOLOGY info available, use -I to display # HEADER_NUMA_TOPOLOGY info available, use -I to display # ======== # ... $ perf report --stdio -I # ======== # captured on : Mon Sep 26 15:22:14 2011 # hostname : quad # os release : 3.1.0-rc4-tip # perf version : 3.1.0-rc4 # arch : x86_64 # nrcpus online : 4 # nrcpus avail : 4 # cpudesc : Intel(R) Core(TM)2 Quad CPU Q6600 @ 2.40GHz # cpuid : GenuineIntel,6,15,11 # total memory : 8105360 kB # cmdline : /home/eranian/perfmon/official/tip/build/tools/perf/perf record date # event : name = cycles, type = 0, config = 0x0, config1 = 0x0, config2 = 0x0, excl_usr = 0, excl_kern = 0, id = { 29, 30, 31, # sibling cores : 0-3 # sibling threads : 0 # sibling threads : 1 # sibling threads : 2 # sibling threads : 3 # node0 meminfo : total = 8320608 kB, free = 7571024 kB # node0 cpu list : 0-3 # ======== # ... Reviewed-by: David Ahern <dsahern@gmail.com> Tested-by: David Ahern <dsahern@gmail.com> Cc: David Ahern <dsahern@gmail.com> Cc: Ingo Molnar <mingo@elte.hu> Cc: Peter Zijlstra <peterz@infradead.org> Cc: Robert Richter <robert.richter@amd.com> Cc: Andi Kleen <ak@linux.intel.com> Link: http://lkml.kernel.org/r/20110930134040.GA5575@quad Signed-off-by: Stephane Eranian <eranian@google.com> [ committer notes: Use --show-info in the tools as was in the docs, rename perf_header_fprintf_info to perf_file_section__fprintf_info, fixup conflict with f69b64f7 "perf: Support setting the disassembler style" ] Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2011-09-30 21:40:40 +08:00
-I::
--show-info::
Display extended information about the perf.data file. This adds
information which may be very large and thus may clutter the display.
It currently includes: cpu and numa topology of the host system.
It can only be used with the perf script report mode.
--show-kernel-path::
Try to resolve the path of [kernel.kallsyms]
--show-task-events
Display task related events (e.g. FORK, COMM, EXIT).
--show-mmap-events
Display mmap related events (e.g. MMAP, MMAP2).
perf script: Add script print support for namespace events Introduce a new option to display events of type PERF_RECORD_NAMESPACES and update perf-script documentation accordingly. Shown below is output (trimmed) of perf script command with the newly introduced option, on perf.data generated with perf record command using --namespaces option. $ perf script --show-namespace-events swapper 0 [000] 0.000000: PERF_RECORD_NAMESPACES 1/1 - nr_namespaces: 7 [0/net: 3/0xf000001c, 1/uts: 3/0xeffffffe, 2/ipc: 3/0xefffffff, 3/pid: 3/0xeffffffc, 4/user: 3/0xeffffffd, 5/mnt: 3/0xf0000000, 6/cgroup: 3/0xeffffffb] swapper 0 [000] 0.000000: PERF_RECORD_NAMESPACES 2/2 - nr_namespaces: 7 [0/net: 3/0xf000001c, 1/uts: 3/0xeffffffe, 2/ipc: 3/0xefffffff, 3/pid: 3/0xeffffffc, 4/user: 3/0xeffffffd, 5/mnt: 3/0xf0000000, 6/cgroup: 3/0xeffffffb] Commiter notes: Testing it: Investigating that double PERF_RECORD_NAMESPACES for the 19155 pid/tid... Its more than that, there are two PERF_RECORD_COMM as well, and with zeroed timestamps, so probably a synthesizing artifact... # perf script --show-task --show-namespace <SNIP> perf 0 [000] 0.000000: PERF_RECORD_COMM: perf:19154/19154 perf 0 [000] 0.000000: PERF_RECORD_FORK(19155:19155):(19154:19154) perf 0 [000] 0.000000: PERF_RECORD_NAMESPACES 19155/19155 - nr_namespaces: 7 [0/net: 3/0xf0000081, 1/uts: 3/0xeffffffe, 2/ipc: 3/0xefffffff, 3/pid: 3/0xeffffffc, 4/user: 3/0xeffffffd, 5/mnt: 3/0xf0000000, 6/cgroup: 3/0xeffffffb] perf 0 [000] 0.000000: PERF_RECORD_COMM: perf:19155/19155 perf 0 [000] 0.000000: PERF_RECORD_COMM: perf:19155/19155 perf 0 [000] 0.000000: PERF_RECORD_NAMESPACES 19155/19155 - nr_namespaces: 7 [0/net: 3/0xf0000081, 1/uts: 3/0xeffffffe, 2/ipc: 3/0xefffffff, 3/pid: 3/0xeffffffc, 4/user: 3/0xeffffffd, 5/mnt: 3/0xf0000000, 6/cgroup: 3/0xeffffffb] swapper 0 [000] 3110.881834: 1 cycles: ffffffffa7060bf6 native_write_msr (/lib/modules/4.11.0-rc1+/build/vmlinux) <SNIP> Signed-off-by: Hari Bathini <hbathini@linux.vnet.ibm.com> Tested-by: Arnaldo Carvalho de Melo <acme@redhat.com> Acked-by: Jiri Olsa <jolsa@kernel.org> Cc: Alexander Shishkin <alexander.shishkin@linux.intel.com> Cc: Alexei Starovoitov <ast@fb.com> Cc: Ananth N Mavinakayanahalli <ananth@linux.vnet.ibm.com> Cc: Aravinda Prasad <aravinda@linux.vnet.ibm.com> Cc: Brendan Gregg <brendan.d.gregg@gmail.com> Cc: Daniel Borkmann <daniel@iogearbox.net> Cc: Eric Biederman <ebiederm@xmission.com> Cc: Peter Zijlstra <peterz@infradead.org> Cc: Sargun Dhillon <sargun@sargun.me> Cc: Steven Rostedt <rostedt@goodmis.org> Link: http://lkml.kernel.org/r/148891932627.25309.1941587059154176221.stgit@hbathini.in.ibm.com Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2017-03-08 04:42:06 +08:00
--show-namespace-events
Display namespace events i.e. events of type PERF_RECORD_NAMESPACES.
--show-switch-events
Display context switch events i.e. events of type PERF_RECORD_SWITCH or
PERF_RECORD_SWITCH_CPU_WIDE.
--show-lost-events
Display lost events i.e. events of type PERF_RECORD_LOST.
--show-round-events
Display finished round events i.e. events of type PERF_RECORD_FINISHED_ROUND.
--demangle::
Demangle symbol names to human readable form. It's enabled by default,
disable with --no-demangle.
--demangle-kernel::
Demangle kernel symbol names to human readable form (for C++ kernels).
--header
Show perf.data header.
--header-only
Show only perf.data header.
--itrace::
Options for decoding instruction tracing data. The options are:
include::itrace.txt[]
To disable decoding entirely, use --no-itrace.
--full-source-path::
Show the full path for source files for srcline output.
--max-stack::
Set the stack depth limit when parsing the callchain, anything
beyond the specified depth will be ignored. This is a trade-off
between information loss and faster processing especially for
workloads that can have a very long callchain stack.
Note that when using the --itrace option the synthesized callchain size
will override this value if the synthesized callchain size is bigger.
Default: 127
--ns::
Use 9 decimal places when displaying time (i.e. show the nanoseconds)
-f::
--force::
Don't do ownership validation.
perf script: Add option to specify time window of interest Add option to allow user to control analysis window. e.g., collect data for some amount of time and analyze a segment of interest within that window. Committer notes: Testing it: # perf evlist -v cycles:ppp: size: 112, { sample_period, sample_freq }: 4000, sample_type: IP|TID|TIME|CALLCHAIN|CPU|PERIOD, disabled: 1, inherit: 1, mmap: 1, comm: 1, freq: 1, task: 1, precise_ip: 3, sample_id_all: 1, exclude_guest: 1, mmap2: 1, comm_exec: 1 # # perf script --hide-call-graph | head -15 swapper 0 [0] 9693.370039: 1 cycles:ppp: ffffffffb90072ad x86_pmu_enable (.../4.8.8-300.fc25.x86_64/vmlinux) swapper 0 [0] 9693.370044: 1 cycles:ppp: ffffffffb900ca1b intel_pmu_handle_irq (.../4.8.8-300.fc25.x86_64/vmlinux) swapper 0 [0] 9693.370046: 7 cycles:ppp: ffffffffb902fd93 native_sched_clock (.../4.8.8-300.fc25.x86_64/vmlinux) swapper 0 [0] 9693.370048: 126 cycles:ppp: ffffffffb902fd93 native_sched_clock (.../4.8.8-300.fc25.x86_64/vmlinux) swapper 0 [0] 9693.370049: 2701 cycles:ppp: ffffffffb902fd93 native_sched_clock (.../4.8.8-300.fc25.x86_64/vmlinux) swapper 0 [0] 9693.370051: 58823 cycles:ppp: ffffffffb90cd2e0 idle_cpu (.../4.8.8-300.fc25.x86_64/vmlinux) swapper 0 [1] 9693.370059: 1 cycles:ppp: ffffffffb91a713a ctx_resched (.../4.8.8-300.fc25.x86_64/vmlinux) swapper 0 [1] 9693.370062: 1 cycles:ppp: ffffffffb900ca1b intel_pmu_handle_irq (.../4.8.8-300.fc25.x86_64/vmlinux) swapper 0 [1] 9693.370064: 13 cycles:ppp: ffffffffb902fd93 native_sched_clock (.../4.8.8-300.fc25.x86_64/vmlinux) swapper 0 [1] 9693.370065: 250 cycles:ppp: ffffffffb902fd93 native_sched_clock (.../4.8.8-300.fc25.x86_64/vmlinux) swapper 0 [1] 9693.370067: 5269 cycles:ppp: ffffffffb902fe79 sched_clock (.../4.8.8-300.fc25.x86_64/vmlinux) swapper 0 [1] 9693.370069: 114602 cycles:ppp: ffffffffb90c1c5a atomic_notifier_call_chain (.../4.8.8-300.fc25.x86_64/vmlinux) perf 5124 [2] 9693.370076: 1 cycles:ppp: ffffffffb91a76c1 __perf_event_enable (.../4.8.8-300.fc25.x86_64/vmlinux) perf 5124 [2] 9693.370091: 1 cycles:ppp: ffffffffb900ca1b intel_pmu_handle_irq (.../4.8.8-300.fc25.x86_64/vmlinux) perf 5124 [2] 9693.370095: 3 cycles:ppp: ffffffffb902fd93 native_sched_clock (.../4.8.8-300.fc25.x86_64/vmlinux) # # perf script --hide-call-graph --time ,9693.370048 swapper 0 [0] 9693.370039: 1 cycles:ppp: ffffffffb90072ad x86_pmu_enable (.../4.8.8-300.fc25.x86_64/vmlinux) swapper 0 [0] 9693.370044: 1 cycles:ppp: ffffffffb900ca1b intel_pmu_handle_irq (.../4.8.8-300.fc25.x86_64/vmlinux) swapper 0 [0] 9693.370046: 7 cycles:ppp: ffffffffb902fd93 native_sched_clock (.../4.8.8-300.fc25.x86_64/vmlinux) # perf script --hide-call-graph --time 9693.370064,9693.370076 swapper 0 [1] 9693.370064: 13 cycles:ppp: ffffffffb902fd93 native_sched_clock (.../4.8.8-300.fc25.x86_64/vmlinux) swapper 0 [1] 9693.370065: 250 cycles:ppp: ffffffffb902fd93 native_sched_clock (.../4.8.8-300.fc25.x86_64/vmlinux) swapper 0 [1] 9693.370067: 5269 cycles:ppp: ffffffffb902fe79 sched_clock (.../4.8.8-300.fc25.x86_64/vmlinux) swapper 0 [1] 9693.370069: 114602 cycles:ppp: ffffffffb90c1c5a atomic_notifier_call_chain (.../4.8.8-300.fc25.x86_64/vmlinux) # Signed-off-by: David Ahern <dsahern@gmail.com> Tested-by: Arnaldo Carvalho de Melo <acme@redhat.com> Acked-by: Namhyung Kim <namhyung@kernel.org> Cc: Jiri Olsa <jolsa@kernel.org> Cc: Peter Zijlstra <peterz@infradead.org> Link: http://lkml.kernel.org/r/1480439746-42695-4-git-send-email-dsahern@gmail.com Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2016-11-30 01:15:43 +08:00
--time::
Only analyze samples within given time window: <start>,<stop>. Times
have the format seconds.microseconds. If start is not given (i.e., time
string is ',x.y') then analysis starts at the beginning of the file. If
stop time is not given (i.e, time string is 'x.y,') then analysis goes
to end of file.
Also support time percent with multipe time range. Time string is
'a%/n,b%/m,...' or 'a%-b%,c%-%d,...'.
For example:
Select the second 10% time slice:
perf script --time 10%/2
Select from 0% to 10% time slice:
perf script --time 0%-10%
Select the first and second 10% time slices:
perf script --time 10%/1,10%/2
Select from 0% to 10% and 30% to 40% slices:
perf script --time 0%-10%,30%-40%
perf script: Add 'brstackinsn' for branch stacks Implement printing instruction sequences as hex dump for branch stacks. This relies on the x86 instruction decoder used by the PT decoder to find the lengths of instructions to dump them individually. This is good enough for pattern matching. This allows to study hot paths for individual samples, together with branch misprediction and cycle count / IPC information if available (on Skylake systems). % perf record -b ... % perf script -F brstackinsn ... read_hpet+67: ffffffff9905b843 insn: 74 ea # PRED ffffffff9905b82f insn: 85 c9 ffffffff9905b831 insn: 74 12 ffffffff9905b833 insn: f3 90 ffffffff9905b835 insn: 48 8b 0f ffffffff9905b838 insn: 48 89 ca ffffffff9905b83b insn: 48 c1 ea 20 ffffffff9905b83f insn: 39 f2 ffffffff9905b841 insn: 89 d0 ffffffff9905b843 insn: 74 ea # PRED Only works when no special branch filters are specified. Occasionally the path does not reach up to the sample IP, as the LBRs may be frozen before executing a final jump. In this case we print a special message. The instruction dumper piggy backs on the existing infrastructure from the IP PT decoder. An earlier iteration of this patch relied on a disassembler, but this version only uses the existing instruction decoder. Committer note: Added hint about how to get suitable perf.data files for use with '-F brstackinsm': $ perf record usleep 1 [ perf record: Woken up 1 times to write data ] [ perf record: Captured and wrote 0.018 MB perf.data (8 samples) ] $ $ perf script -F brstackinsn Display of branch stack assembler requested, but non all-branch filter set Hint: run 'perf record -b ...' $ Signed-off-by: Andi Kleen <ak@linux.intel.com> Tested-by: Arnaldo Carvalho de Melo <acme@redhat.com> Cc: Jiri Olsa <jolsa@kernel.org> Cc: Michael Ellerman <mpe@ellerman.id.au> Link: http://lkml.kernel.org/r/20170223234634.583-1-andi@firstfloor.org Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2017-02-24 07:46:34 +08:00
--max-blocks::
Set the maximum number of program blocks to print with brstackasm for
each sample.
--per-event-dump::
Create per event files with a "perf.data.EVENT.dump" name instead of
printing to stdout, useful, for instance, for generating flamegraphs.
perf script: Add --inline option for debugging The --inline option is to show inlined functions in callchains. For example: $ perf script a.out 5644 11611.467597: 309961 cycles:u: 790 main (/home/namhyung/tmp/perf/a.out) 20511 __libc_start_main (/usr/lib/libc-2.25.so) 8ba _start (/home/namhyung/tmp/perf/a.out) ... $ perf script --inline a.out 5644 11611.467597: 309961 cycles:u: 790 main (/home/namhyung/tmp/perf/a.out) std::__detail::_Adaptor<std::linear_congruential_engine<unsigned long, 16807ul, 0ul, 2147483647ul>, double>::operator() std::uniform_real_distribution<double>::operator()<std::linear_congruential_engine<unsigned long, 16807ul, 0ul, 2147483647ul> > std::uniform_real_distribution<double>::operator()<std::linear_congruential_engine<unsigned long, 16807ul, 0ul, 2147483647ul> > main 20511 __libc_start_main (/usr/lib/libc-2.25.so) 8ba _start (/home/namhyung/tmp/perf/a.out) ... Reviewed-and-tested-by: Milian Wolff <milian.wolff@kdab.com> Signed-off-by: Namhyung Kim <namhyung@kernel.org> Cc: Arnaldo Carvalho de Melo <acme@kernel.org> Cc: Arnaldo Carvalho de Melo <acme@redhat.com> Cc: Jin Yao <yao.jin@linux.intel.com> Cc: Jiri Olsa <jolsa@kernel.org> Cc: Jiri Olsa <jolsa@redhat.com> Cc: Linus Torvalds <torvalds@linux-foundation.org> Cc: Milian Wolff <milian.wolff@kdab.com> Cc: Peter Zijlstra <peterz@infradead.org> Cc: Thomas Gleixner <tglx@linutronix.de> Cc: kernel-team@lge.com Link: http://lkml.kernel.org/r/20170524062129.32529-5-namhyung@kernel.org Signed-off-by: Ingo Molnar <mingo@kernel.org>
2017-05-24 14:21:26 +08:00
--inline::
If a callgraph address belongs to an inlined function, the inline stack
will be printed. Each entry has function name and file/line. Enabled by
default, disable with --no-inline.
perf script: Add --inline option for debugging The --inline option is to show inlined functions in callchains. For example: $ perf script a.out 5644 11611.467597: 309961 cycles:u: 790 main (/home/namhyung/tmp/perf/a.out) 20511 __libc_start_main (/usr/lib/libc-2.25.so) 8ba _start (/home/namhyung/tmp/perf/a.out) ... $ perf script --inline a.out 5644 11611.467597: 309961 cycles:u: 790 main (/home/namhyung/tmp/perf/a.out) std::__detail::_Adaptor<std::linear_congruential_engine<unsigned long, 16807ul, 0ul, 2147483647ul>, double>::operator() std::uniform_real_distribution<double>::operator()<std::linear_congruential_engine<unsigned long, 16807ul, 0ul, 2147483647ul> > std::uniform_real_distribution<double>::operator()<std::linear_congruential_engine<unsigned long, 16807ul, 0ul, 2147483647ul> > main 20511 __libc_start_main (/usr/lib/libc-2.25.so) 8ba _start (/home/namhyung/tmp/perf/a.out) ... Reviewed-and-tested-by: Milian Wolff <milian.wolff@kdab.com> Signed-off-by: Namhyung Kim <namhyung@kernel.org> Cc: Arnaldo Carvalho de Melo <acme@kernel.org> Cc: Arnaldo Carvalho de Melo <acme@redhat.com> Cc: Jin Yao <yao.jin@linux.intel.com> Cc: Jiri Olsa <jolsa@kernel.org> Cc: Jiri Olsa <jolsa@redhat.com> Cc: Linus Torvalds <torvalds@linux-foundation.org> Cc: Milian Wolff <milian.wolff@kdab.com> Cc: Peter Zijlstra <peterz@infradead.org> Cc: Thomas Gleixner <tglx@linutronix.de> Cc: kernel-team@lge.com Link: http://lkml.kernel.org/r/20170524062129.32529-5-namhyung@kernel.org Signed-off-by: Ingo Molnar <mingo@kernel.org>
2017-05-24 14:21:26 +08:00
SEE ALSO
--------
linkperf:perf-record[1], linkperf:perf-script-perl[1],
linkperf:perf-script-python[1]