^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 1) perf-trace(1)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 2) =============
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 3)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 4) NAME
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 5) ----
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 6) perf-trace - strace inspired tool
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 7)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 8) SYNOPSIS
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 9) --------
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 10) [verse]
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 11) 'perf trace'
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 12) 'perf trace record'
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 13)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 14) DESCRIPTION
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 15) -----------
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 16) This command will show the events associated with the target, initially
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 17) syscalls, but other system events like pagefaults, task lifetime events,
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 18) scheduling events, etc.
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 19)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 20) This is a live mode tool in addition to working with perf.data files like
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 21) the other perf tools. Files can be generated using the 'perf record' command
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 22) but the session needs to include the raw_syscalls events (-e 'raw_syscalls:*').
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 23) Alternatively, 'perf trace record' can be used as a shortcut to
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 24) automatically include the raw_syscalls events when writing events to a file.
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 25)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 26) The following options apply to perf trace; options to perf trace record are
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 27) found in the perf record man page.
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 28)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 29) OPTIONS
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 30) -------
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 31)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 32) -a::
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 33) --all-cpus::
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 34) System-wide collection from all CPUs.
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 35)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 36) -e::
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 37) --expr::
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 38) --event::
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 39) List of syscalls and other perf events (tracepoints, HW cache events,
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 40) etc) to show. Globbing is supported, e.g.: "epoll_*", "*msg*", etc.
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 41) See 'perf list' for a complete list of events.
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 42) Prefixing with ! shows all syscalls but the ones specified. You may
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 43) need to escape it.
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 44)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 45) --filter=<filter>::
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 46) Event filter. This option should follow an event selector (-e) which
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 47) selects tracepoint event(s).
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 48)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 49)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 50) -D msecs::
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 51) --delay msecs::
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 52) After starting the program, wait msecs before measuring. This is useful to
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 53) filter out the startup phase of the program, which is often very different.
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 54)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 55) -o::
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 56) --output=::
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 57) Output file name.
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 58)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 59) -p::
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 60) --pid=::
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 61) Record events on existing process ID (comma separated list).
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 62)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 63) -t::
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 64) --tid=::
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 65) Record events on existing thread ID (comma separated list).
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 66)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 67) -u::
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 68) --uid=::
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 69) Record events in threads owned by uid. Name or number.
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 70)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 71) -G::
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 72) --cgroup::
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 73) Record events in threads in a cgroup.
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 74)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 75) Look for cgroups to set at the /sys/fs/cgroup/perf_event directory, then
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 76) remove the /sys/fs/cgroup/perf_event/ part and try:
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 77)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 78) perf trace -G A -e sched:*switch
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 79)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 80) Will set all raw_syscalls:sys_{enter,exit}, pgfault, vfs_getname, etc
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 81) _and_ sched:sched_switch to the 'A' cgroup, while:
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 82)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 83) perf trace -e sched:*switch -G A
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 84)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 85) will only set the sched:sched_switch event to the 'A' cgroup, all the
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 86) other events (raw_syscalls:sys_{enter,exit}, etc are left "without"
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 87) a cgroup (on the root cgroup, sys wide, etc).
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 88)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 89) Multiple cgroups:
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 90)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 91) perf trace -G A -e sched:*switch -G B
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 92)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 93) the syscall ones go to the 'A' cgroup, the sched:sched_switch goes
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 94) to the 'B' cgroup.
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 95)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 96) --filter-pids=::
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 97) Filter out events for these pids and for 'trace' itself (comma separated list).
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 98)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 99) -v::
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 100) --verbose=::
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 101) Verbosity level.
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 102)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 103) --no-inherit::
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 104) Child tasks do not inherit counters.
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 105)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 106) -m::
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 107) --mmap-pages=::
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 108) Number of mmap data pages (must be a power of two) or size
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 109) specification with appended unit character - B/K/M/G. The
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 110) size is rounded up to have nearest pages power of two value.
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 111)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 112) -C::
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 113) --cpu::
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 114) Collect samples only on the list of CPUs provided. Multiple CPUs can be provided as a
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 115) comma-separated list with no space: 0,1. Ranges of CPUs are specified with -: 0-2.
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 116) In per-thread mode with inheritance mode on (default), Events are captured only when
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 117) the thread executes on the designated CPUs. Default is to monitor all CPUs.
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 118)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 119) --duration::
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 120) Show only events that had a duration greater than N.M ms.
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 121)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 122) --sched::
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 123) Accrue thread runtime and provide a summary at the end of the session.
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 124)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 125) --failure::
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 126) Show only syscalls that failed, i.e. that returned < 0.
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 127)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 128) -i::
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 129) --input::
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 130) Process events from a given perf data file.
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 131)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 132) -T::
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 133) --time::
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 134) Print full timestamp rather time relative to first sample.
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 135)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 136) --comm::
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 137) Show process COMM right beside its ID, on by default, disable with --no-comm.
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 138)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 139) -s::
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 140) --summary::
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 141) Show only a summary of syscalls by thread with min, max, and average times
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 142) (in msec) and relative stddev.
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 143)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 144) -S::
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 145) --with-summary::
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 146) Show all syscalls followed by a summary by thread with min, max, and
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 147) average times (in msec) and relative stddev.
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 148)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 149) --errno-summary::
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 150) To be used with -s or -S, to show stats for the errnos experienced by
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 151) syscalls, using only this option will trigger --summary.
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 152)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 153) --tool_stats::
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 154) Show tool stats such as number of times fd->pathname was discovered thru
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 155) hooking the open syscall return + vfs_getname or via reading /proc/pid/fd, etc.
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 156)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 157) -f::
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 158) --force::
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 159) Don't complain, do it.
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 160)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 161) -F=[all|min|maj]::
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 162) --pf=[all|min|maj]::
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 163) Trace pagefaults. Optionally, you can specify whether you want minor,
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 164) major or all pagefaults. Default value is maj.
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 165)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 166) --syscalls::
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 167) Trace system calls. This options is enabled by default, disable with
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 168) --no-syscalls.
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 169)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 170) --call-graph [mode,type,min[,limit],order[,key][,branch]]::
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 171) Setup and enable call-graph (stack chain/backtrace) recording.
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 172) See `--call-graph` section in perf-record and perf-report
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 173) man pages for details. The ones that are most useful in 'perf trace'
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 174) are 'dwarf' and 'lbr', where available, try: 'perf trace --call-graph dwarf'.
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 175)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 176) Using this will, for the root user, bump the value of --mmap-pages to 4
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 177) times the maximum for non-root users, based on the kernel.perf_event_mlock_kb
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 178) sysctl. This is done only if the user doesn't specify a --mmap-pages value.
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 179)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 180) --kernel-syscall-graph::
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 181) Show the kernel callchains on the syscall exit path.
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 182)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 183) --max-events=N::
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 184) Stop after processing N events. Note that strace-like events are considered
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 185) only at exit time or when a syscall is interrupted, i.e. in those cases this
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 186) option is equivalent to the number of lines printed.
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 187)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 188) --switch-on EVENT_NAME::
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 189) Only consider events after this event is found.
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 190)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 191) --switch-off EVENT_NAME::
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 192) Stop considering events after this event is found.
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 193)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 194) --show-on-off-events::
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 195) Show the --switch-on/off events too.
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 196)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 197) --max-stack::
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 198) Set the stack depth limit when parsing the callchain, anything
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 199) beyond the specified depth will be ignored. Note that at this point
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 200) this is just about the presentation part, i.e. the kernel is still
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 201) not limiting, the overhead of callchains needs to be set via the
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 202) knobs in --call-graph dwarf.
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 203)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 204) Implies '--call-graph dwarf' when --call-graph not present on the
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 205) command line, on systems where DWARF unwinding was built in.
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 206)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 207) Default: /proc/sys/kernel/perf_event_max_stack when present for
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 208) live sessions (without --input/-i), 127 otherwise.
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 209)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 210) --min-stack::
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 211) Set the stack depth limit when parsing the callchain, anything
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 212) below the specified depth will be ignored. Disabled by default.
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 213)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 214) Implies '--call-graph dwarf' when --call-graph not present on the
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 215) command line, on systems where DWARF unwinding was built in.
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 216)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 217) --print-sample::
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 218) Print the PERF_RECORD_SAMPLE PERF_SAMPLE_ info for the
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 219) raw_syscalls:sys_{enter,exit} tracepoints, for debugging.
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 220)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 221) --proc-map-timeout::
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 222) When processing pre-existing threads /proc/XXX/mmap, it may take a long time,
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 223) because the file may be huge. A time out is needed in such cases.
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 224) This option sets the time out limit. The default value is 500 ms.
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 225)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 226) --sort-events::
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 227) Do sorting on batches of events, use when noticing out of order events that
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 228) may happen, for instance, when a thread gets migrated to a different CPU
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 229) while processing a syscall.
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 230)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 231) --libtraceevent_print::
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 232) Use libtraceevent to print tracepoint arguments. By default 'perf trace' uses
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 233) the same beautifiers used in the strace-like enter+exit lines to augment the
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 234) tracepoint arguments.
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 235)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 236) --map-dump::
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 237) Dump BPF maps setup by events passed via -e, for instance the augmented_raw_syscalls
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 238) living in tools/perf/examples/bpf/augmented_raw_syscalls.c. For now this
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 239) dumps just boolean map values and integer keys, in time this will print in hex
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 240) by default and use BTF when available, as well as use functions to do pretty
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 241) printing using the existing 'perf trace' syscall arg beautifiers to map integer
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 242) arguments to strings (pid to comm, syscall id to syscall name, etc).
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 243)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 244)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 245) PAGEFAULTS
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 246) ----------
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 247)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 248) When tracing pagefaults, the format of the trace is as follows:
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 249)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 250) <min|maj>fault [<ip.symbol>+<ip.offset>] => <addr.dso@addr.offset> (<map type><addr level>).
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 251)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 252) - min/maj indicates whether fault event is minor or major;
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 253) - ip.symbol shows symbol for instruction pointer (the code that generated the
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 254) fault); if no debug symbols available, perf trace will print raw IP;
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 255) - addr.dso shows DSO for the faulted address;
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 256) - map type is either 'd' for non-executable maps or 'x' for executable maps;
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 257) - addr level is either 'k' for kernel dso or '.' for user dso.
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 258)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 259) For symbols resolution you may need to install debugging symbols.
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 260)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 261) Please be aware that duration is currently always 0 and doesn't reflect actual
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 262) time it took for fault to be handled!
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 263)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 264) When --verbose specified, perf trace tries to print all available information
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 265) for both IP and fault address in the form of dso@symbol+offset.
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 266)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 267) EXAMPLES
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 268) --------
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 269)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 270) Trace only major pagefaults:
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 271)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 272) $ perf trace --no-syscalls -F
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 273)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 274) Trace syscalls, major and minor pagefaults:
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 275)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 276) $ perf trace -F all
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 277)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 278) 1416.547 ( 0.000 ms): python/20235 majfault [CRYPTO_push_info_+0x0] => /lib/x86_64-linux-gnu/libcrypto.so.1.0.0@0x61be0 (x.)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 279)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 280) As you can see, there was major pagefault in python process, from
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 281) CRYPTO_push_info_ routine which faulted somewhere in libcrypto.so.
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 282)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 283) Trace the first 4 open, openat or open_by_handle_at syscalls (in the future more syscalls may match here):
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 284)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 285) $ perf trace -e open* --max-events 4
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 286) [root@jouet perf]# trace -e open* --max-events 4
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 287) 2272.992 ( 0.037 ms): gnome-shell/1370 openat(dfd: CWD, filename: /proc/self/stat) = 31
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 288) 2277.481 ( 0.139 ms): gnome-shell/3039 openat(dfd: CWD, filename: /proc/self/stat) = 65
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 289) 3026.398 ( 0.076 ms): gnome-shell/3039 openat(dfd: CWD, filename: /proc/self/stat) = 65
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 290) 4294.665 ( 0.015 ms): sed/15879 openat(dfd: CWD, filename: /etc/ld.so.cache, flags: CLOEXEC) = 3
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 291) $
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 292)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 293) Trace the first minor page fault when running a workload:
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 294)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 295) # perf trace -F min --max-stack=7 --max-events 1 sleep 1
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 296) 0.000 ( 0.000 ms): sleep/18006 minfault [__clear_user+0x1a] => 0x5626efa56080 (?k)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 297) __clear_user ([kernel.kallsyms])
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 298) load_elf_binary ([kernel.kallsyms])
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 299) search_binary_handler ([kernel.kallsyms])
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 300) __do_execve_file.isra.33 ([kernel.kallsyms])
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 301) __x64_sys_execve ([kernel.kallsyms])
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 302) do_syscall_64 ([kernel.kallsyms])
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 303) entry_SYSCALL_64 ([kernel.kallsyms])
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 304) #
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 305)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 306) Trace the next min page page fault to take place on the first CPU:
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 307)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 308) # perf trace -F min --call-graph=dwarf --max-events 1 --cpu 0
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 309) 0.000 ( 0.000 ms): Web Content/17136 minfault [js::gc::Chunk::fetchNextDecommittedArena+0x4b] => 0x7fbe6181b000 (?.)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 310) js::gc::FreeSpan::initAsEmpty (inlined)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 311) js::gc::Arena::setAsNotAllocated (inlined)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 312) js::gc::Chunk::fetchNextDecommittedArena (/usr/lib64/firefox/libxul.so)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 313) js::gc::Chunk::allocateArena (/usr/lib64/firefox/libxul.so)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 314) js::gc::GCRuntime::allocateArena (/usr/lib64/firefox/libxul.so)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 315) js::gc::ArenaLists::allocateFromArena (/usr/lib64/firefox/libxul.so)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 316) js::gc::GCRuntime::tryNewTenuredThing<JSString, (js::AllowGC)1> (inlined)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 317) js::AllocateString<JSString, (js::AllowGC)1> (/usr/lib64/firefox/libxul.so)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 318) js::Allocate<JSThinInlineString, (js::AllowGC)1> (inlined)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 319) JSThinInlineString::new_<(js::AllowGC)1> (inlined)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 320) AllocateInlineString<(js::AllowGC)1, unsigned char> (inlined)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 321) js::ConcatStrings<(js::AllowGC)1> (/usr/lib64/firefox/libxul.so)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 322) [0x18b26e6bc2bd] (/tmp/perf-17136.map)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 323) #
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 324)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 325) Trace the next two sched:sched_switch events, four block:*_plug events, the
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 326) next block:*_unplug and the next three net:*dev_queue events, this last one
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 327) with a backtrace of at most 16 entries, system wide:
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 328)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 329) # perf trace -e sched:*switch/nr=2/,block:*_plug/nr=4/,block:*_unplug/nr=1/,net:*dev_queue/nr=3,max-stack=16/
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 330) 0.000 :0/0 sched:sched_switch:swapper/2:0 [120] S ==> rcu_sched:10 [120]
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 331) 0.015 rcu_sched/10 sched:sched_switch:rcu_sched:10 [120] R ==> swapper/2:0 [120]
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 332) 254.198 irq/50-iwlwifi/680 net:net_dev_queue:dev=wlp3s0 skbaddr=0xffff93498051f600 len=66
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 333) __dev_queue_xmit ([kernel.kallsyms])
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 334) 273.977 :0/0 net:net_dev_queue:dev=wlp3s0 skbaddr=0xffff93498051f600 len=78
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 335) __dev_queue_xmit ([kernel.kallsyms])
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 336) 274.007 :0/0 net:net_dev_queue:dev=wlp3s0 skbaddr=0xffff93498051ff00 len=78
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 337) __dev_queue_xmit ([kernel.kallsyms])
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 338) 2930.140 kworker/u16:58/2722 block:block_plug:[kworker/u16:58]
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 339) 2930.162 kworker/u16:58/2722 block:block_unplug:[kworker/u16:58] 1
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 340) 4466.094 jbd2/dm-2-8/748 block:block_plug:[jbd2/dm-2-8]
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 341) 8050.123 kworker/u16:30/2694 block:block_plug:[kworker/u16:30]
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 342) 8050.271 kworker/u16:30/2694 block:block_plug:[kworker/u16:30]
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 343) #
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 344)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 345) SEE ALSO
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 346) --------
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 347) linkperf:perf-record[1], linkperf:perf-script[1]