^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 1) perf-script-python(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-script-python - Process trace data with a Python script
^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 script' [-s [Python]:script[.py] ]
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 12)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 13) DESCRIPTION
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 14) -----------
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 15)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 16) This perf script option is used to process perf script data using perf's
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 17) built-in Python interpreter. It reads and processes the input file and
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 18) displays the results of the trace analysis implemented in the given
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 19) Python script, if any.
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 20)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 21) A QUICK EXAMPLE
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 22) ---------------
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 23)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 24) This section shows the process, start to finish, of creating a working
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 25) Python script that aggregates and extracts useful information from a
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 26) raw perf script stream. You can avoid reading the rest of this
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 27) document if an example is enough for you; the rest of the document
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 28) provides more details on each step and lists the library functions
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 29) available to script writers.
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 30)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 31) This example actually details the steps that were used to create the
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 32) 'syscall-counts' script you see when you list the available perf script
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 33) scripts via 'perf script -l'. As such, this script also shows how to
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 34) integrate your script into the list of general-purpose 'perf script'
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 35) scripts listed by that command.
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 36)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 37) The syscall-counts script is a simple script, but demonstrates all the
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 38) basic ideas necessary to create a useful script. Here's an example
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 39) of its output (syscall names are not yet supported, they will appear
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 40) as numbers):
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 41)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 42) ----
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 43) syscall events:
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 44)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 45) event count
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 46) ---------------------------------------- -----------
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 47) sys_write 455067
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 48) sys_getdents 4072
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 49) sys_close 3037
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 50) sys_swapoff 1769
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 51) sys_read 923
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 52) sys_sched_setparam 826
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 53) sys_open 331
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 54) sys_newfstat 326
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 55) sys_mmap 217
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 56) sys_munmap 216
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 57) sys_futex 141
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 58) sys_select 102
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 59) sys_poll 84
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 60) sys_setitimer 12
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 61) sys_writev 8
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 62) 15 8
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 63) sys_lseek 7
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 64) sys_rt_sigprocmask 6
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 65) sys_wait4 3
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 66) sys_ioctl 3
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 67) sys_set_robust_list 1
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 68) sys_exit 1
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 69) 56 1
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 70) sys_access 1
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 71) ----
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 72)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 73) Basically our task is to keep a per-syscall tally that gets updated
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 74) every time a system call occurs in the system. Our script will do
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 75) that, but first we need to record the data that will be processed by
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 76) that script. Theoretically, there are a couple of ways we could do
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 77) that:
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 78)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 79) - we could enable every event under the tracing/events/syscalls
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 80) directory, but this is over 600 syscalls, well beyond the number
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 81) allowable by perf. These individual syscall events will however be
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 82) useful if we want to later use the guidance we get from the
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 83) general-purpose scripts to drill down and get more detail about
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 84) individual syscalls of interest.
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 85)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 86) - we can enable the sys_enter and/or sys_exit syscalls found under
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 87) tracing/events/raw_syscalls. These are called for all syscalls; the
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 88) 'id' field can be used to distinguish between individual syscall
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 89) numbers.
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 90)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 91) For this script, we only need to know that a syscall was entered; we
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 92) don't care how it exited, so we'll use 'perf record' to record only
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 93) the sys_enter events:
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 94)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 95) ----
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 96) # perf record -a -e raw_syscalls:sys_enter
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 97)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 98) ^C[ perf record: Woken up 1 times to write data ]
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 99) [ perf record: Captured and wrote 56.545 MB perf.data (~2470503 samples) ]
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 100) ----
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 101)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 102) The options basically say to collect data for every syscall event
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 103) system-wide and multiplex the per-cpu output into a single stream.
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 104) That single stream will be recorded in a file in the current directory
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 105) called perf.data.
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 106)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 107) Once we have a perf.data file containing our data, we can use the -g
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 108) 'perf script' option to generate a Python script that will contain a
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 109) callback handler for each event type found in the perf.data trace
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 110) stream (for more details, see the STARTER SCRIPTS section).
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 111)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 112) ----
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 113) # perf script -g python
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 114) generated Python script: perf-script.py
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 115)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 116) The output file created also in the current directory is named
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 117) perf-script.py. Here's the file in its entirety:
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 118)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 119) # perf script event handlers, generated by perf script -g python
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 120) # Licensed under the terms of the GNU GPL License version 2
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 121)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 122) # The common_* event handler fields are the most useful fields common to
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 123) # all events. They don't necessarily correspond to the 'common_*' fields
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 124) # in the format files. Those fields not available as handler params can
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 125) # be retrieved using Python functions of the form common_*(context).
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 126) # See the perf-script-python Documentation for the list of available functions.
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 127)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 128) import os
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 129) import sys
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 130)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 131) sys.path.append(os.environ['PERF_EXEC_PATH'] + \
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 132) '/scripts/python/Perf-Trace-Util/lib/Perf/Trace')
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 133)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 134) from perf_trace_context import *
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 135) from Core import *
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 136)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 137) def trace_begin():
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 138) print "in trace_begin"
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 139)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 140) def trace_end():
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 141) print "in trace_end"
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 142)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 143) def raw_syscalls__sys_enter(event_name, context, common_cpu,
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 144) common_secs, common_nsecs, common_pid, common_comm,
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 145) id, args):
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 146) print_header(event_name, common_cpu, common_secs, common_nsecs,
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 147) common_pid, common_comm)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 148)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 149) print "id=%d, args=%s\n" % \
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 150) (id, args),
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 151)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 152) def trace_unhandled(event_name, context, event_fields_dict):
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 153) print ' '.join(['%s=%s'%(k,str(v))for k,v in sorted(event_fields_dict.items())])
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 154)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 155) def print_header(event_name, cpu, secs, nsecs, pid, comm):
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 156) print "%-20s %5u %05u.%09u %8u %-20s " % \
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 157) (event_name, cpu, secs, nsecs, pid, comm),
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 158) ----
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 159)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 160) At the top is a comment block followed by some import statements and a
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 161) path append which every perf script script should include.
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 162)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 163) Following that are a couple generated functions, trace_begin() and
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 164) trace_end(), which are called at the beginning and the end of the
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 165) script respectively (for more details, see the SCRIPT_LAYOUT section
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 166) below).
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 167)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 168) Following those are the 'event handler' functions generated one for
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 169) every event in the 'perf record' output. The handler functions take
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 170) the form subsystem__event_name, and contain named parameters, one for
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 171) each field in the event; in this case, there's only one event,
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 172) raw_syscalls__sys_enter(). (see the EVENT HANDLERS section below for
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 173) more info on event handlers).
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 174)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 175) The final couple of functions are, like the begin and end functions,
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 176) generated for every script. The first, trace_unhandled(), is called
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 177) every time the script finds an event in the perf.data file that
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 178) doesn't correspond to any event handler in the script. This could
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 179) mean either that the record step recorded event types that it wasn't
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 180) really interested in, or the script was run against a trace file that
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 181) doesn't correspond to the script.
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 182)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 183) The script generated by -g option simply prints a line for each
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 184) event found in the trace stream i.e. it basically just dumps the event
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 185) and its parameter values to stdout. The print_header() function is
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 186) simply a utility function used for that purpose. Let's rename the
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 187) script and run it to see the default output:
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 188)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 189) ----
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 190) # mv perf-script.py syscall-counts.py
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 191) # perf script -s syscall-counts.py
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 192)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 193) raw_syscalls__sys_enter 1 00840.847582083 7506 perf id=1, args=
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 194) raw_syscalls__sys_enter 1 00840.847595764 7506 perf id=1, args=
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 195) raw_syscalls__sys_enter 1 00840.847620860 7506 perf id=1, args=
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 196) raw_syscalls__sys_enter 1 00840.847710478 6533 npviewer.bin id=78, args=
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 197) raw_syscalls__sys_enter 1 00840.847719204 6533 npviewer.bin id=142, args=
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 198) raw_syscalls__sys_enter 1 00840.847755445 6533 npviewer.bin id=3, args=
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 199) raw_syscalls__sys_enter 1 00840.847775601 6533 npviewer.bin id=3, args=
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 200) raw_syscalls__sys_enter 1 00840.847781820 6533 npviewer.bin id=3, args=
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 201) .
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 202) .
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 203) .
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 204) ----
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 205)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 206) Of course, for this script, we're not interested in printing every
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 207) trace event, but rather aggregating it in a useful way. So we'll get
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 208) rid of everything to do with printing as well as the trace_begin() and
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 209) trace_unhandled() functions, which we won't be using. That leaves us
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 210) with this minimalistic skeleton:
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 211)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 212) ----
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 213) import os
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 214) import sys
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 215)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 216) sys.path.append(os.environ['PERF_EXEC_PATH'] + \
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 217) '/scripts/python/Perf-Trace-Util/lib/Perf/Trace')
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 218)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 219) from perf_trace_context import *
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 220) from Core import *
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 221)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 222) def trace_end():
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 223) print "in trace_end"
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 224)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 225) def raw_syscalls__sys_enter(event_name, context, common_cpu,
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 226) common_secs, common_nsecs, common_pid, common_comm,
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 227) id, args):
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 228) ----
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 229)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 230) In trace_end(), we'll simply print the results, but first we need to
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 231) generate some results to print. To do that we need to have our
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 232) sys_enter() handler do the necessary tallying until all events have
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 233) been counted. A hash table indexed by syscall id is a good way to
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 234) store that information; every time the sys_enter() handler is called,
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 235) we simply increment a count associated with that hash entry indexed by
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 236) that syscall id:
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 237)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 238) ----
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 239) syscalls = autodict()
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 240)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 241) try:
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 242) syscalls[id] += 1
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 243) except TypeError:
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 244) syscalls[id] = 1
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 245) ----
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 246)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 247) The syscalls 'autodict' object is a special kind of Python dictionary
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 248) (implemented in Core.py) that implements Perl's 'autovivifying' hashes
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 249) in Python i.e. with autovivifying hashes, you can assign nested hash
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 250) values without having to go to the trouble of creating intermediate
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 251) levels if they don't exist e.g syscalls[comm][pid][id] = 1 will create
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 252) the intermediate hash levels and finally assign the value 1 to the
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 253) hash entry for 'id' (because the value being assigned isn't a hash
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 254) object itself, the initial value is assigned in the TypeError
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 255) exception. Well, there may be a better way to do this in Python but
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 256) that's what works for now).
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 257)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 258) Putting that code into the raw_syscalls__sys_enter() handler, we
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 259) effectively end up with a single-level dictionary keyed on syscall id
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 260) and having the counts we've tallied as values.
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 261)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 262) The print_syscall_totals() function iterates over the entries in the
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 263) dictionary and displays a line for each entry containing the syscall
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 264) name (the dictionary keys contain the syscall ids, which are passed to
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 265) the Util function syscall_name(), which translates the raw syscall
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 266) numbers to the corresponding syscall name strings). The output is
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 267) displayed after all the events in the trace have been processed, by
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 268) calling the print_syscall_totals() function from the trace_end()
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 269) handler called at the end of script processing.
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 270)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 271) The final script producing the output shown above is shown in its
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 272) entirety below (syscall_name() helper is not yet available, you can
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 273) only deal with id's for now):
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 274)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 275) ----
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 276) import os
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 277) import sys
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 278)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 279) sys.path.append(os.environ['PERF_EXEC_PATH'] + \
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 280) '/scripts/python/Perf-Trace-Util/lib/Perf/Trace')
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 281)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 282) from perf_trace_context import *
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 283) from Core import *
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 284) from Util import *
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 285)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 286) syscalls = autodict()
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 287)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 288) def trace_end():
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 289) print_syscall_totals()
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 290)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 291) def raw_syscalls__sys_enter(event_name, context, common_cpu,
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 292) common_secs, common_nsecs, common_pid, common_comm,
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 293) id, args):
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 294) try:
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 295) syscalls[id] += 1
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 296) except TypeError:
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 297) syscalls[id] = 1
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 298)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 299) def print_syscall_totals():
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 300) if for_comm is not None:
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 301) print "\nsyscall events for %s:\n\n" % (for_comm),
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 302) else:
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 303) print "\nsyscall events:\n\n",
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 304)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 305) print "%-40s %10s\n" % ("event", "count"),
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 306) print "%-40s %10s\n" % ("----------------------------------------", \
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 307) "-----------"),
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 308)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 309) for id, val in sorted(syscalls.iteritems(), key = lambda(k, v): (v, k), \
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 310) reverse = True):
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 311) print "%-40s %10d\n" % (syscall_name(id), val),
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 312) ----
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 313)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 314) The script can be run just as before:
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 315)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 316) # perf script -s syscall-counts.py
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 317)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 318) So those are the essential steps in writing and running a script. The
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 319) process can be generalized to any tracepoint or set of tracepoints
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 320) you're interested in - basically find the tracepoint(s) you're
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 321) interested in by looking at the list of available events shown by
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 322) 'perf list' and/or look in /sys/kernel/debug/tracing/events/ for
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 323) detailed event and field info, record the corresponding trace data
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 324) using 'perf record', passing it the list of interesting events,
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 325) generate a skeleton script using 'perf script -g python' and modify the
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 326) code to aggregate and display it for your particular needs.
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 327)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 328) After you've done that you may end up with a general-purpose script
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 329) that you want to keep around and have available for future use. By
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 330) writing a couple of very simple shell scripts and putting them in the
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 331) right place, you can have your script listed alongside the other
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 332) scripts listed by the 'perf script -l' command e.g.:
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 333)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 334) ----
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 335) # perf script -l
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 336) List of available trace scripts:
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 337) wakeup-latency system-wide min/max/avg wakeup latency
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 338) rw-by-file <comm> r/w activity for a program, by file
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 339) rw-by-pid system-wide r/w activity
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 340) ----
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 341)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 342) A nice side effect of doing this is that you also then capture the
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 343) probably lengthy 'perf record' command needed to record the events for
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 344) the script.
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 345)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 346) To have the script appear as a 'built-in' script, you write two simple
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 347) scripts, one for recording and one for 'reporting'.
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 348)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 349) The 'record' script is a shell script with the same base name as your
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 350) script, but with -record appended. The shell script should be put
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 351) into the perf/scripts/python/bin directory in the kernel source tree.
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 352) In that script, you write the 'perf record' command-line needed for
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 353) your script:
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 354)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 355) ----
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 356) # cat kernel-source/tools/perf/scripts/python/bin/syscall-counts-record
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 357)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 358) #!/bin/bash
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 359) perf record -a -e raw_syscalls:sys_enter
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 360) ----
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 361)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 362) The 'report' script is also a shell script with the same base name as
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 363) your script, but with -report appended. It should also be located in
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 364) the perf/scripts/python/bin directory. In that script, you write the
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 365) 'perf script -s' command-line needed for running your script:
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 366)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 367) ----
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 368) # cat kernel-source/tools/perf/scripts/python/bin/syscall-counts-report
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 369)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 370) #!/bin/bash
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 371) # description: system-wide syscall counts
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 372) perf script -s ~/libexec/perf-core/scripts/python/syscall-counts.py
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 373) ----
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 374)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 375) Note that the location of the Python script given in the shell script
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 376) is in the libexec/perf-core/scripts/python directory - this is where
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 377) the script will be copied by 'make install' when you install perf.
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 378) For the installation to install your script there, your script needs
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 379) to be located in the perf/scripts/python directory in the kernel
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 380) source tree:
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 381)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 382) ----
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 383) # ls -al kernel-source/tools/perf/scripts/python
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 384) total 32
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 385) drwxr-xr-x 4 trz trz 4096 2010-01-26 22:30 .
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 386) drwxr-xr-x 4 trz trz 4096 2010-01-26 22:29 ..
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 387) drwxr-xr-x 2 trz trz 4096 2010-01-26 22:29 bin
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 388) -rw-r--r-- 1 trz trz 2548 2010-01-26 22:29 check-perf-script.py
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 389) drwxr-xr-x 3 trz trz 4096 2010-01-26 22:49 Perf-Trace-Util
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 390) -rw-r--r-- 1 trz trz 1462 2010-01-26 22:30 syscall-counts.py
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 391) ----
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 392)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 393) Once you've done that (don't forget to do a new 'make install',
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 394) otherwise your script won't show up at run-time), 'perf script -l'
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 395) should show a new entry for your script:
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 396)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 397) ----
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 398) # perf script -l
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 399) List of available trace scripts:
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 400) wakeup-latency system-wide min/max/avg wakeup latency
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 401) rw-by-file <comm> r/w activity for a program, by file
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 402) rw-by-pid system-wide r/w activity
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 403) syscall-counts system-wide syscall counts
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 404) ----
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 405)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 406) You can now perform the record step via 'perf script record':
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 407)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 408) # perf script record syscall-counts
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 409)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 410) and display the output using 'perf script report':
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 411)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 412) # perf script report syscall-counts
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 413)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 414) STARTER SCRIPTS
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 415) ---------------
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 416)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 417) You can quickly get started writing a script for a particular set of
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 418) trace data by generating a skeleton script using 'perf script -g
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 419) python' in the same directory as an existing perf.data trace file.
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 420) That will generate a starter script containing a handler for each of
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 421) the event types in the trace file; it simply prints every available
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 422) field for each event in the trace file.
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 423)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 424) You can also look at the existing scripts in
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 425) ~/libexec/perf-core/scripts/python for typical examples showing how to
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 426) do basic things like aggregate event data, print results, etc. Also,
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 427) the check-perf-script.py script, while not interesting for its results,
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 428) attempts to exercise all of the main scripting features.
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 429)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 430) EVENT HANDLERS
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 431) --------------
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 432)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 433) When perf script is invoked using a trace script, a user-defined
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 434) 'handler function' is called for each event in the trace. If there's
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 435) no handler function defined for a given event type, the event is
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 436) ignored (or passed to a 'trace_unhandled' function, see below) and the
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 437) next event is processed.
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 438)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 439) Most of the event's field values are passed as arguments to the
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 440) handler function; some of the less common ones aren't - those are
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 441) available as calls back into the perf executable (see below).
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 442)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 443) As an example, the following perf record command can be used to record
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 444) all sched_wakeup events in the system:
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 445)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 446) # perf record -a -e sched:sched_wakeup
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 447)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 448) Traces meant to be processed using a script should be recorded with
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 449) the above option: -a to enable system-wide collection.
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 450)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 451) The format file for the sched_wakep event defines the following fields
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 452) (see /sys/kernel/debug/tracing/events/sched/sched_wakeup/format):
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 453)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 454) ----
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 455) format:
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 456) field:unsigned short common_type;
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 457) field:unsigned char common_flags;
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 458) field:unsigned char common_preempt_count;
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 459) field:int common_pid;
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 460)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 461) field:char comm[TASK_COMM_LEN];
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 462) field:pid_t pid;
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 463) field:int prio;
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 464) field:int success;
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 465) field:int target_cpu;
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 466) ----
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 467)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 468) The handler function for this event would be defined as:
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 469)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 470) ----
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 471) def sched__sched_wakeup(event_name, context, common_cpu, common_secs,
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 472) common_nsecs, common_pid, common_comm,
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 473) comm, pid, prio, success, target_cpu):
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 474) pass
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 475) ----
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 476)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 477) The handler function takes the form subsystem__event_name.
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 478)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 479) The common_* arguments in the handler's argument list are the set of
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 480) arguments passed to all event handlers; some of the fields correspond
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 481) to the common_* fields in the format file, but some are synthesized,
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 482) and some of the common_* fields aren't common enough to to be passed
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 483) to every event as arguments but are available as library functions.
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 484)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 485) Here's a brief description of each of the invariant event args:
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 486)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 487) event_name the name of the event as text
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 488) context an opaque 'cookie' used in calls back into perf
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 489) common_cpu the cpu the event occurred on
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 490) common_secs the secs portion of the event timestamp
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 491) common_nsecs the nsecs portion of the event timestamp
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 492) common_pid the pid of the current task
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 493) common_comm the name of the current process
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 494)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 495) All of the remaining fields in the event's format file have
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 496) counterparts as handler function arguments of the same name, as can be
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 497) seen in the example above.
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 498)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 499) The above provides the basics needed to directly access every field of
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 500) every event in a trace, which covers 90% of what you need to know to
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 501) write a useful trace script. The sections below cover the rest.
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 502)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 503) SCRIPT LAYOUT
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 504) -------------
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 505)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 506) Every perf script Python script should start by setting up a Python
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 507) module search path and 'import'ing a few support modules (see module
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 508) descriptions below):
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 509)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 510) ----
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 511) import os
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 512) import sys
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 513)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 514) sys.path.append(os.environ['PERF_EXEC_PATH'] + \
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 515) '/scripts/python/Perf-Trace-Util/lib/Perf/Trace')
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 516)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 517) from perf_trace_context import *
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 518) from Core import *
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 519) ----
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 520)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 521) The rest of the script can contain handler functions and support
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 522) functions in any order.
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 523)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 524) Aside from the event handler functions discussed above, every script
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 525) can implement a set of optional functions:
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 526)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 527) *trace_begin*, if defined, is called before any event is processed and
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 528) gives scripts a chance to do setup tasks:
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 529)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 530) ----
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 531) def trace_begin():
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 532) pass
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 533) ----
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 534)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 535) *trace_end*, if defined, is called after all events have been
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 536) processed and gives scripts a chance to do end-of-script tasks, such
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 537) as display results:
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 538)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 539) ----
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 540) def trace_end():
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 541) pass
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 542) ----
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 543)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 544) *trace_unhandled*, if defined, is called after for any event that
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 545) doesn't have a handler explicitly defined for it. The standard set
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 546) of common arguments are passed into it:
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 547)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 548) ----
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 549) def trace_unhandled(event_name, context, event_fields_dict):
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 550) pass
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 551) ----
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 552)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 553) The remaining sections provide descriptions of each of the available
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 554) built-in perf script Python modules and their associated functions.
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 555)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 556) AVAILABLE MODULES AND FUNCTIONS
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 557) -------------------------------
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 558)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 559) The following sections describe the functions and variables available
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 560) via the various perf script Python modules. To use the functions and
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 561) variables from the given module, add the corresponding 'from XXXX
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 562) import' line to your perf script script.
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 563)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 564) Core.py Module
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 565) ~~~~~~~~~~~~~~
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 566)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 567) These functions provide some essential functions to user scripts.
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 568)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 569) The *flag_str* and *symbol_str* functions provide human-readable
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 570) strings for flag and symbolic fields. These correspond to the strings
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 571) and values parsed from the 'print fmt' fields of the event format
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 572) files:
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 573)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 574) flag_str(event_name, field_name, field_value) - returns the string representation corresponding to field_value for the flag field field_name of event event_name
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 575) symbol_str(event_name, field_name, field_value) - returns the string representation corresponding to field_value for the symbolic field field_name of event event_name
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 576)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 577) The *autodict* function returns a special kind of Python
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 578) dictionary that implements Perl's 'autovivifying' hashes in Python
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 579) i.e. with autovivifying hashes, you can assign nested hash values
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 580) without having to go to the trouble of creating intermediate levels if
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 581) they don't exist.
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 582)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 583) autodict() - returns an autovivifying dictionary instance
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 584)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 585)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 586) perf_trace_context Module
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 587) ~~~~~~~~~~~~~~~~~~~~~~~~~
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 588)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 589) Some of the 'common' fields in the event format file aren't all that
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 590) common, but need to be made accessible to user scripts nonetheless.
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 591)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 592) perf_trace_context defines a set of functions that can be used to
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 593) access this data in the context of the current event. Each of these
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 594) functions expects a context variable, which is the same as the
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 595) context variable passed into every event handler as the second
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 596) argument.
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 597)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 598) common_pc(context) - returns common_preempt count for the current event
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 599) common_flags(context) - returns common_flags for the current event
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 600) common_lock_depth(context) - returns common_lock_depth for the current event
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 601)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 602) Util.py Module
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 603) ~~~~~~~~~~~~~~
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 604)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 605) Various utility functions for use with perf script:
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 606)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 607) nsecs(secs, nsecs) - returns total nsecs given secs/nsecs pair
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 608) nsecs_secs(nsecs) - returns whole secs portion given nsecs
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 609) nsecs_nsecs(nsecs) - returns nsecs remainder given nsecs
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 610) nsecs_str(nsecs) - returns printable string in the form secs.nsecs
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 611) avg(total, n) - returns average given a sum and a total number of values
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 612)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 613) SUPPORTED FIELDS
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 614) ----------------
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 615)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 616) Currently supported fields:
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 617)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 618) ev_name, comm, pid, tid, cpu, ip, time, period, phys_addr, addr,
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 619) symbol, dso, time_enabled, time_running, values, callchain,
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 620) brstack, brstacksym, datasrc, datasrc_decode, iregs, uregs,
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 621) weight, transaction, raw_buf, attr.
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 622)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 623) Some fields have sub items:
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 624)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 625) brstack:
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 626) from, to, from_dsoname, to_dsoname, mispred,
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 627) predicted, in_tx, abort, cycles.
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 628)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 629) brstacksym:
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 630) items: from, to, pred, in_tx, abort (converted string)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 631)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 632) For example,
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 633) We can use this code to print brstack "from", "to", "cycles".
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 634)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 635) if 'brstack' in dict:
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 636) for entry in dict['brstack']:
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 637) print "from %s, to %s, cycles %s" % (entry["from"], entry["to"], entry["cycles"])
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 638)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 639) SEE ALSO
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 640) --------
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 641) linkperf:perf-script[1]
Orange Pi5 kernel
Deprecated Linux kernel 5.10.110 for OrangePi 5/5B/5+ boards
3 Commits
0 Branches
0 Tags