2012-09-27 07:05:56 +08:00
|
|
|
perf-trace(1)
|
|
|
|
|
=============
|
|
|
|
|
|
|
|
|
|
NAME
|
|
|
|
|
----
|
|
|
|
|
perf-trace - strace inspired tool
|
|
|
|
|
|
|
|
|
|
SYNOPSIS
|
|
|
|
|
--------
|
|
|
|
|
[verse]
|
|
|
|
|
'perf trace'
|
2013-09-29 03:13:01 +08:00
|
|
|
'perf trace record'
|
2012-09-27 07:05:56 +08:00
|
|
|
|
|
|
|
|
DESCRIPTION
|
|
|
|
|
-----------
|
|
|
|
|
This command will show the events associated with the target, initially
|
|
|
|
|
syscalls, but other system events like pagefaults, task lifetime events,
|
|
|
|
|
scheduling events, etc.
|
|
|
|
|
|
2013-09-29 03:13:01 +08:00
|
|
|
This is a live mode tool in addition to working with perf.data files like
|
|
|
|
|
the other perf tools. Files can be generated using the 'perf record' command
|
|
|
|
|
but the session needs to include the raw_syscalls events (-e 'raw_syscalls:*').
|
|
|
|
|
Alernatively, the 'perf trace record' can be used as a shortcut to
|
|
|
|
|
automatically include the raw_syscalls events when writing events to a file.
|
|
|
|
|
|
|
|
|
|
The following options apply to perf trace; options to perf trace record are
|
|
|
|
|
found in the perf record man page.
|
2012-09-27 07:05:56 +08:00
|
|
|
|
|
|
|
|
OPTIONS
|
|
|
|
|
-------
|
|
|
|
|
|
2013-08-21 01:15:45 +08:00
|
|
|
-a::
|
2012-09-27 07:05:56 +08:00
|
|
|
--all-cpus::
|
|
|
|
|
System-wide collection from all CPUs.
|
|
|
|
|
|
2013-08-09 23:28:31 +08:00
|
|
|
-e::
|
|
|
|
|
--expr::
|
|
|
|
|
List of events to show, currently only syscall names.
|
2013-08-21 23:56:21 +08:00
|
|
|
Prefixing with ! shows all syscalls but the ones specified. You may
|
|
|
|
|
need to escape it.
|
2013-08-09 23:28:31 +08:00
|
|
|
|
2013-08-19 23:01:10 +08:00
|
|
|
-o::
|
|
|
|
|
--output=::
|
|
|
|
|
Output file name.
|
|
|
|
|
|
2012-09-27 07:05:56 +08:00
|
|
|
-p::
|
|
|
|
|
--pid=::
|
|
|
|
|
Record events on existing process ID (comma separated list).
|
|
|
|
|
|
2013-08-21 01:15:45 +08:00
|
|
|
-t::
|
2012-09-27 07:05:56 +08:00
|
|
|
--tid=::
|
|
|
|
|
Record events on existing thread ID (comma separated list).
|
|
|
|
|
|
2013-08-21 01:15:45 +08:00
|
|
|
-u::
|
2012-09-27 07:05:56 +08:00
|
|
|
--uid=::
|
|
|
|
|
Record events in threads owned by uid. Name or number.
|
|
|
|
|
|
2013-08-23 03:49:54 +08:00
|
|
|
-v::
|
|
|
|
|
--verbose=::
|
|
|
|
|
Verbosity level.
|
|
|
|
|
|
2013-08-21 01:15:45 +08:00
|
|
|
-i::
|
2012-09-27 07:05:56 +08:00
|
|
|
--no-inherit::
|
|
|
|
|
Child tasks do not inherit counters.
|
|
|
|
|
|
2013-08-21 01:15:45 +08:00
|
|
|
-m::
|
2012-09-27 07:05:56 +08:00
|
|
|
--mmap-pages=::
|
2013-09-01 18:36:13 +08:00
|
|
|
Number of mmap data pages (must be a power of two) or size
|
|
|
|
|
specification with appended unit character - B/K/M/G. The
|
|
|
|
|
size is rounded up to have nearest pages power of two value.
|
2012-09-27 07:05:56 +08:00
|
|
|
|
2013-08-21 01:15:45 +08:00
|
|
|
-C::
|
2012-09-27 07:05:56 +08:00
|
|
|
--cpu::
|
|
|
|
|
Collect samples only on 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.
|
|
|
|
|
In per-thread mode with inheritance mode on (default), Events are captured only when
|
|
|
|
|
the thread executes on the designated CPUs. Default is to monitor all CPUs.
|
|
|
|
|
|
perf trace: Add duration filter
Example:
[acme@sandy linux]$ perf trace --duration 0.025 usleep 1
2.221 ( 0.958 ms): 6724 execve(arg0: 140733557168278, arg1: 140733557178768, arg2: 16134304, arg3: 140733557167840, arg4: 7955998171588342573, arg5: 6723) = -2
3.690 ( 1.443 ms): 6724 execve(arg0: 140733557168295, arg1: 140733557178768, arg2: 16134304, arg3: 140733557167840, arg4: 7955998171588342573, arg5: 6723) = 0
3.979 ( 0.048 ms): 6724 open(filename: 208733843841, flags: 0, mode: 1 ) = 3
4.071 ( 0.075 ms): 6724 open(filename: 139744419925673, flags: 0, mode: 0 ) = 3
4.318 ( 0.056 ms): 6724 nanosleep(rqtp: 140734030404608, rmtp: 0 ) = 0
[acme@sandy linux]$ perf trace --duration 0.100 usleep 1
1.143 ( 1.021 ms): 6726 execve(arg0: 140736323962279, arg1: 140736323972752, arg2: 34926752, arg3: 140736323961824, arg4: 7955998171588342573, arg5: 6725) = 0
[acme@sandy linux]$
Cherry picked from tmp.perf/trace2 branch.
Cc: David Ahern <dsahern@gmail.com>
Cc: Frederic Weisbecker <fweisbec@gmail.com>
Cc: Jiri Olsa <jolsa@redhat.com>
Cc: Mike Galbraith <efault@gmx.de>
Cc: Namhyung Kim <namhyung@gmail.com>
Cc: Paul Mackerras <paulus@samba.org>
Cc: Peter Zijlstra <peterz@infradead.org>
Cc: Stephane Eranian <eranian@google.com>
Cc: Thomas Gleixner <tglx@linutronix.de>
Link: http://lkml.kernel.org/n/tip-oslw2j2958we9qf0ctra4whd@git.kernel.org
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2012-10-08 20:56:00 +08:00
|
|
|
--duration:
|
|
|
|
|
Show only events that had a duration greater than N.M ms.
|
|
|
|
|
|
2012-10-18 04:13:12 +08:00
|
|
|
--sched:
|
|
|
|
|
Accrue thread runtime and provide a summary at the end of the session.
|
|
|
|
|
|
2013-08-29 12:29:52 +08:00
|
|
|
-i
|
|
|
|
|
--input
|
|
|
|
|
Process events from a given perf data file.
|
|
|
|
|
|
2013-09-05 02:37:43 +08:00
|
|
|
-T
|
|
|
|
|
--time
|
|
|
|
|
Print full timestamp rather time relative to first sample.
|
|
|
|
|
|
perf trace: Add option to show process COMM
Enabled by default, disable with --no-comm, e.g.:
181.821 (0.001 ms): deja-dup-monit/10784 recvmsg(fd: 8, msg: 0x7fff4342baf0, flags: PEEK|TRUNC|CMSG_CLOEXEC ) = 20
181.824 (0.001 ms): deja-dup-monit/10784 geteuid( ) = 1000
181.825 (0.001 ms): deja-dup-monit/10784 getegid( ) = 1000
181.834 (0.002 ms): deja-dup-monit/10784 recvmsg(fd: 8, msg: 0x7fff4342baf0, flags: CMSG_CLOEXEC ) = 20
181.836 (0.001 ms): deja-dup-monit/10784 geteuid( ) = 1000
181.838 (0.001 ms): deja-dup-monit/10784 getegid( ) = 1000
181.705 (0.003 ms): evolution-addr/10924 recvmsg(fd: 10, msg: 0x7fff17dc6990, flags: PEEK|TRUNC|CMSG_CLOEXEC) = 1256
181.710 (0.002 ms): evolution-addr/10924 geteuid( ) = 1000
181.712 (0.001 ms): evolution-addr/10924 getegid( ) = 1000
181.727 (0.003 ms): evolution-addr/10924 recvmsg(fd: 10, msg: 0x7fff17dc6990, flags: CMSG_CLOEXEC ) = 1256
181.731 (0.001 ms): evolution-addr/10924 geteuid( ) = 1000
181.734 (0.001 ms): evolution-addr/10924 getegid( ) = 1000
181.908 (0.002 ms): evolution-addr/10924 recvmsg(fd: 10, msg: 0x7fff17dc6990, flags: PEEK|TRUNC|CMSG_CLOEXEC) = 20
181.913 (0.001 ms): evolution-addr/10924 geteuid( ) = 1000
181.915 (0.001 ms): evolution-addr/10924 getegid( ) = 1000
181.930 (0.003 ms): evolution-addr/10924 recvmsg(fd: 10, msg: 0x7fff17dc6990, flags: CMSG_CLOEXEC ) = 20
181.934 (0.001 ms): evolution-addr/10924 geteuid( ) = 1000
181.937 (0.001 ms): evolution-addr/10924 getegid( ) = 1000
220.718 (0.010 ms): at-spi2-regist/10715 sendmsg(fd: 3, msg: 0x7fffdb8756c0, flags: NOSIGNAL ) = 200
220.741 (0.000 ms): dbus-daemon/10711 ... [continued]: epoll_wait()) = 1
220.759 (0.004 ms): dbus-daemon/10711 recvmsg(fd: 11, msg: 0x7ffff94594d0, flags: CMSG_CLOEXEC ) = 200
220.780 (0.002 ms): dbus-daemon/10711 recvmsg(fd: 11, msg: 0x7ffff94594d0, flags: CMSG_CLOEXEC ) = 200
220.788 (0.001 ms): dbus-daemon/10711 recvmsg(fd: 11, msg: 0x7ffff94594d0, flags: CMSG_CLOEXEC ) = -1 EAGAIN Resource temporarily unavailable
220.760 (0.004 ms): at-spi2-regist/10715 sendmsg(fd: 3, msg: 0x7fffdb8756c0, flags: NOSIGNAL ) = 200
220.771 (0.023 ms): perf/26347 open(filename: 0xf2e780, mode: 15918976 ) = 19
220.850 (0.002 ms): perf/26347 close(fd: 19 ) = 0
Cc: 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: Mike Galbraith <efault@gmx.de>
Cc: Paul Mackerras <paulus@samba.org>
Cc: Peter Zijlstra <peterz@infradead.org>
Cc: Stephane Eranian <eranian@google.com>
Link: http://lkml.kernel.org/n/tip-6be5jvnkdzjptdrebfn5263n@git.kernel.org
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2013-09-12 23:35:21 +08:00
|
|
|
--comm::
|
|
|
|
|
Show process COMM right beside its ID, on by default, disable with --no-comm.
|
|
|
|
|
|
2013-11-13 00:31:15 +08:00
|
|
|
-s::
|
2013-10-09 11:26:53 +08:00
|
|
|
--summary::
|
2013-11-13 00:31:15 +08:00
|
|
|
Show only a summary of syscalls by thread with min, max, and average times
|
|
|
|
|
(in msec) and relative stddev.
|
|
|
|
|
|
|
|
|
|
-S::
|
|
|
|
|
--with-summary::
|
|
|
|
|
Show all syscalls followed by a summary by thread with min, max, and
|
|
|
|
|
average times (in msec) and relative stddev.
|
2013-10-09 11:26:53 +08:00
|
|
|
|
2013-09-28 05:06:19 +08:00
|
|
|
--tool_stats::
|
|
|
|
|
Show tool stats such as number of times fd->pathname was discovered thru
|
|
|
|
|
hooking the open syscall return + vfs_getname or via reading /proc/pid/fd, etc.
|
|
|
|
|
|
2014-06-27 00:14:25 +08:00
|
|
|
-F=[all|min|maj]::
|
|
|
|
|
--pf=[all|min|maj]::
|
|
|
|
|
Trace pagefaults. Optionally, you can specify whether you want minor,
|
|
|
|
|
major or all pagefaults. Default value is maj.
|
|
|
|
|
|
|
|
|
|
PAGEFAULTS
|
|
|
|
|
----------
|
|
|
|
|
|
|
|
|
|
When tracing pagefaults, the format of the trace is as follows:
|
|
|
|
|
|
|
|
|
|
<min|maj>fault [<ip.symbol>+<ip.offset>] => <addr.dso@addr.offset> (<map type><addr level>).
|
|
|
|
|
|
|
|
|
|
- min/maj indicates whether fault event is minor or major;
|
|
|
|
|
- ip.symbol shows symbol for instruction pointer (the code that generated the
|
|
|
|
|
fault); if no debug symbols available, perf trace will print raw IP;
|
|
|
|
|
- addr.dso shows DSO for the faulted address;
|
|
|
|
|
- map type is either 'd' for non-executable maps or 'x' for executable maps;
|
|
|
|
|
- addr level is either 'k' for kernel dso or '.' for user dso.
|
|
|
|
|
|
|
|
|
|
For symbols resolution you may need to install debugging symbols.
|
|
|
|
|
|
|
|
|
|
Please be aware that duration is currently always 0 and doesn't reflect actual
|
|
|
|
|
time it took for fault to be handled!
|
|
|
|
|
|
|
|
|
|
When --verbose specified, perf trace tries to print all available information
|
|
|
|
|
for both IP and fault address in the form of dso@symbol+offset.
|
|
|
|
|
|
|
|
|
|
EXAMPLES
|
|
|
|
|
--------
|
|
|
|
|
|
|
|
|
|
Trace syscalls, major and minor pagefaults:
|
|
|
|
|
|
|
|
|
|
$ perf trace -F all
|
|
|
|
|
|
|
|
|
|
1416.547 ( 0.000 ms): python/20235 majfault [CRYPTO_push_info_+0x0] => /lib/x86_64-linux-gnu/libcrypto.so.1.0.0@0x61be0 (x.)
|
|
|
|
|
|
|
|
|
|
As you can see, there was major pagefault in python process, from
|
|
|
|
|
CRYPTO_push_info_ routine which faulted somewhere in libcrypto.so.
|
|
|
|
|
|
2012-09-27 07:05:56 +08:00
|
|
|
SEE ALSO
|
|
|
|
|
--------
|
|
|
|
|
linkperf:perf-record[1], linkperf:perf-script[1]
|