Something went wrong. Try again.
Linux kernel mirror (for testing) git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git
Something went wrong. Try again.
25 kB · 679 lines
at master
123456789101112131415161718192021222324252627282930313233343536373839404142434445464748495051525354555657585960616263646566676869707172737475767778798081828384858687888990919293949596979899100101102103104105106107108109110111112113114115116117118119120121122123124125126127128129130131132133134135136137138139140141142143144145146147148149150151152153154155156157158159160161162163164165166167168169170171172173174175176177178179180181182183184185186187188189190191192193194195196197198199200201202203204205206207208209210211212213214215216217218219220221222223224225226227228229230231232233234235236237238239240241242243244245246247248249250251252253254255256257258259260261262263264265266267268269270271272273274275276277278279280281282283284285286287288289290291292293294295296297298299300301302303304305306307308309310311312313314315316317318319320321322323324325326327328329330331332333334335336337338339340341342343344345346347348349350351352353354355356357358359360361362363364365366367368369370371372373374375376377378379380381382383384385386387388389390391392393394395396397398399400401402403404405406407408409410411412413414415416417418419420421422423424425426427428429430431432433434435436437438439440441442443444445446447448449450451452453454455456457458459460461462463464465466467468469470471472473474475476477478479480481482483484485486487488489490491492493494495496497498499500501502503504505506507508509510511512513514515516517518519520521522523524525526527528529530531532533534535536537538539540541542543544545546547548549550551552553554555556557558559560561562563564565566567568569570571572573574575576577578579580581582583584585586587588589590591592593594595596597598599600601602603604605606607608609610611612613614615616617618619620621622623624625626627628629630631632633634635636637638639640641642643644645646647648649650651652653654655656657658659660661662663664665666667668669670671672673674675676677678679680perf-script-python(1)====================
NAME----perf-script-python - Process trace data with a Python script
SYNOPSIS--------[verse]'perf script' [-s [Python]:script[.py] ]
DESCRIPTION-----------
This perf script option is used to process perf script data using perf'sbuilt-in Python interpreter. It reads and processes the input file anddisplays the results of the trace analysis implemented in the givenPython script, if any.
A QUICK EXAMPLE---------------
This section shows the process, start to finish, of creating a workingPython script that aggregates and extracts useful information from araw perf script stream. You can avoid reading the rest of thisdocument if an example is enough for you; the rest of the documentprovides more details on each step and lists the library functionsavailable to script writers.
This example actually details the steps that were used to create the'syscall-counts' script you see when you list the available perf scriptscripts via 'perf script -l'. As such, this script also shows how tointegrate your script into the list of general-purpose 'perf script'scripts listed by that command.
The syscall-counts script is a simple script, but demonstrates all thebasic ideas necessary to create a useful script. Here's an exampleof its output (syscall names are not yet supported, they will appearas numbers):
----syscall events:
event count---------------------------------------- -----------sys_write 455067sys_getdents 4072sys_close 3037sys_swapoff 1769sys_read 923sys_sched_setparam 826sys_open 331sys_newfstat 326sys_mmap 217sys_munmap 216sys_futex 141sys_select 102sys_poll 84sys_setitimer 12sys_writev 815 8sys_lseek 7sys_rt_sigprocmask 6sys_wait4 3sys_ioctl 3sys_set_robust_list 1sys_exit 156 1sys_access 1----
Basically our task is to keep a per-syscall tally that gets updatedevery time a system call occurs in the system. Our script will dothat, but first we need to record the data that will be processed bythat script. Theoretically, there are a couple of ways we could dothat:
- we could enable every event under the tracing/events/syscalls directory, but this is over 600 syscalls, well beyond the number allowable by perf. These individual syscall events will however be useful if we want to later use the guidance we get from the general-purpose scripts to drill down and get more detail about individual syscalls of interest.
- we can enable the sys_enter and/or sys_exit syscalls found under tracing/events/raw_syscalls. These are called for all syscalls; the 'id' field can be used to distinguish between individual syscall numbers.
For this script, we only need to know that a syscall was entered; wedon't care how it exited, so we'll use 'perf record' to record onlythe sys_enter events:
----# perf record -a -e raw_syscalls:sys_enter
^C[ perf record: Woken up 1 times to write data ][ perf record: Captured and wrote 56.545 MB perf.data (~2470503 samples) ]----
The options basically say to collect data for every syscall eventsystem-wide and multiplex the per-cpu output into a single stream.That single stream will be recorded in a file in the current directorycalled perf.data.
Once we have a perf.data file containing our data, we can use the -g'perf script' option to generate a Python script that will contain acallback handler for each event type found in the perf.data tracestream (for more details, see the STARTER SCRIPTS section).
----# perf script -g pythongenerated Python script: perf-script.py
The output file created also in the current directory is namedperf-script.py. Here's the file in its entirety:
# perf script event handlers, generated by perf script -g python# Licensed under the terms of the GNU GPL License version 2
# The common_* event handler fields are the most useful fields common to# all events. They don't necessarily correspond to the 'common_*' fields# in the format files. Those fields not available as handler params can# be retrieved using Python functions of the form common_*(context).# See the perf-script-python Documentation for the list of available functions.
import osimport sys
sys.path.append(os.environ['PERF_EXEC_PATH'] + \ '/scripts/python/Perf-Trace-Util/lib/Perf/Trace')
from perf_trace_context import *from Core import *
def trace_begin(): print "in trace_begin"
def trace_end(): print "in trace_end"
def raw_syscalls__sys_enter(event_name, context, common_cpu, common_secs, common_nsecs, common_pid, common_comm, id, args): print_header(event_name, common_cpu, common_secs, common_nsecs, common_pid, common_comm)
print "id=%d, args=%s\n" % \ (id, args),
def trace_unhandled(event_name, context, event_fields_dict): print ' '.join(['%s=%s'%(k,str(v))for k,v in sorted(event_fields_dict.items())])
def print_header(event_name, cpu, secs, nsecs, pid, comm): print "%-20s %5u %05u.%09u %8u %-20s " % \ (event_name, cpu, secs, nsecs, pid, comm),----
At the top is a comment block followed by some import statements and apath append which every perf script script should include.
Following that are a couple generated functions, trace_begin() andtrace_end(), which are called at the beginning and the end of thescript respectively (for more details, see the SCRIPT_LAYOUT sectionbelow).
Following those are the 'event handler' functions generated one forevery event in the 'perf record' output. The handler functions takethe form subsystem\__event_name, and contain named parameters, one foreach field in the event; in this case, there's only one event,raw_syscalls__sys_enter(). (see the EVENT HANDLERS section below formore info on event handlers).
The final couple of functions are, like the begin and end functions,generated for every script. The first, trace_unhandled(), is calledevery time the script finds an event in the perf.data file thatdoesn't correspond to any event handler in the script. This couldmean either that the record step recorded event types that it wasn'treally interested in, or the script was run against a trace file thatdoesn't correspond to the script.
The script generated by -g option simply prints a line for eachevent found in the trace stream i.e. it basically just dumps the eventand its parameter values to stdout. The print_header() function issimply a utility function used for that purpose. Let's rename thescript and run it to see the default output:
----# mv perf-script.py syscall-counts.py# perf script -s syscall-counts.py
raw_syscalls__sys_enter 1 00840.847582083 7506 perf id=1, args=raw_syscalls__sys_enter 1 00840.847595764 7506 perf id=1, args=raw_syscalls__sys_enter 1 00840.847620860 7506 perf id=1, args=raw_syscalls__sys_enter 1 00840.847710478 6533 npviewer.bin id=78, args=raw_syscalls__sys_enter 1 00840.847719204 6533 npviewer.bin id=142, args=raw_syscalls__sys_enter 1 00840.847755445 6533 npviewer.bin id=3, args=raw_syscalls__sys_enter 1 00840.847775601 6533 npviewer.bin id=3, args=raw_syscalls__sys_enter 1 00840.847781820 6533 npviewer.bin id=3, args=...----
Of course, for this script, we're not interested in printing everytrace event, but rather aggregating it in a useful way. So we'll getrid of everything to do with printing as well as the trace_begin() andtrace_unhandled() functions, which we won't be using. That leaves uswith this minimalistic skeleton:
----import osimport sys
sys.path.append(os.environ['PERF_EXEC_PATH'] + \ '/scripts/python/Perf-Trace-Util/lib/Perf/Trace')
from perf_trace_context import *from Core import *
def trace_end(): print "in trace_end"
def raw_syscalls__sys_enter(event_name, context, common_cpu, common_secs, common_nsecs, common_pid, common_comm, id, args):----
In trace_end(), we'll simply print the results, but first we need togenerate some results to print. To do that we need to have oursys_enter() handler do the necessary tallying until all events havebeen counted. A hash table indexed by syscall id is a good way tostore that information; every time the sys_enter() handler is called,we simply increment a count associated with that hash entry indexed bythat syscall id:
---- syscalls = autodict()
try: syscalls[id] += 1 except TypeError: syscalls[id] = 1----
The syscalls 'autodict' object is a special kind of Python dictionary(implemented in Core.py) that implements Perl's 'autovivifying' hashesin Python i.e. with autovivifying hashes, you can assign nested hashvalues without having to go to the trouble of creating intermediatelevels if they don't exist e.g syscalls[comm][pid][id] = 1 will createthe intermediate hash levels and finally assign the value 1 to thehash entry for 'id' (because the value being assigned isn't a hashobject itself, the initial value is assigned in the TypeErrorexception. Well, there may be a better way to do this in Python butthat's what works for now).
Putting that code into the raw_syscalls__sys_enter() handler, weeffectively end up with a single-level dictionary keyed on syscall idand having the counts we've tallied as values.
The print_syscall_totals() function iterates over the entries in thedictionary and displays a line for each entry containing the syscallname (the dictionary keys contain the syscall ids, which are passed tothe Util function syscall_name(), which translates the raw syscallnumbers to the corresponding syscall name strings). The output isdisplayed after all the events in the trace have been processed, bycalling the print_syscall_totals() function from the trace_end()handler called at the end of script processing.
The final script producing the output shown above is shown in itsentirety below (syscall_name() helper is not yet available, you canonly deal with id's for now):
----import osimport sys
sys.path.append(os.environ['PERF_EXEC_PATH'] + \ '/scripts/python/Perf-Trace-Util/lib/Perf/Trace')
from perf_trace_context import *from Core import *from Util import *
syscalls = autodict()
def trace_end(): print_syscall_totals()
def raw_syscalls__sys_enter(event_name, context, common_cpu, common_secs, common_nsecs, common_pid, common_comm, id, args): try: syscalls[id] += 1 except TypeError: syscalls[id] = 1
def print_syscall_totals(): if for_comm is not None: print "\nsyscall events for %s:\n\n" % (for_comm), else: print "\nsyscall events:\n\n",
print "%-40s %10s\n" % ("event", "count"), print "%-40s %10s\n" % ("----------------------------------------", \ "-----------"),
for id, val in sorted(syscalls.iteritems(), key = lambda(k, v): (v, k), \ reverse = True): print "%-40s %10d\n" % (syscall_name(id), val),----
The script can be run just as before:
# perf script -s syscall-counts.py
So those are the essential steps in writing and running a script. Theprocess can be generalized to any tracepoint or set of tracepointsyou're interested in - basically find the tracepoint(s) you'reinterested in by looking at the list of available events shown by'perf list' and/or look in /sys/kernel/tracing/events/ fordetailed event and field info, record the corresponding trace datausing 'perf record', passing it the list of interesting events,generate a skeleton script using 'perf script -g python' and modify thecode to aggregate and display it for your particular needs.
After you've done that you may end up with a general-purpose scriptthat you want to keep around and have available for future use. Bywriting a couple of very simple shell scripts and putting them in theright place, you can have your script listed alongside the otherscripts listed by the 'perf script -l' command e.g.:
----# perf script -lList of available trace scripts: wakeup-latency system-wide min/max/avg wakeup latency rw-by-file <comm> r/w activity for a program, by file rw-by-pid system-wide r/w activity----
A nice side effect of doing this is that you also then capture theprobably lengthy 'perf record' command needed to record the events forthe script.
To have the script appear as a 'built-in' script, you write two simplescripts, one for recording and one for 'reporting'.
The 'record' script is a shell script with the same base name as yourscript, but with -record appended. The shell script should be putinto the perf/scripts/python/bin directory in the kernel source tree.In that script, you write the 'perf record' command-line needed foryour script:
----# cat kernel-source/tools/perf/scripts/python/bin/syscall-counts-record
#!/bin/bashperf record -a -e raw_syscalls:sys_enter----
The 'report' script is also a shell script with the same base name asyour script, but with -report appended. It should also be located inthe perf/scripts/python/bin directory. In that script, you write the'perf script -s' command-line needed for running your script:
----# cat kernel-source/tools/perf/scripts/python/bin/syscall-counts-report
#!/bin/bash# description: system-wide syscall countsperf script -s ~/libexec/perf-core/scripts/python/syscall-counts.py----
Note that the location of the Python script given in the shell scriptis in the libexec/perf-core/scripts/python directory - this is wherethe script will be copied by 'make install' when you install perf.For the installation to install your script there, your script needsto be located in the perf/scripts/python directory in the kernelsource tree:
----# ls -al kernel-source/tools/perf/scripts/pythontotal 32drwxr-xr-x 4 trz trz 4096 2010-01-26 22:30 .drwxr-xr-x 4 trz trz 4096 2010-01-26 22:29 ..drwxr-xr-x 2 trz trz 4096 2010-01-26 22:29 bin-rw-r--r-- 1 trz trz 2548 2010-01-26 22:29 check-perf-script.pydrwxr-xr-x 3 trz trz 4096 2010-01-26 22:49 Perf-Trace-Util-rw-r--r-- 1 trz trz 1462 2010-01-26 22:30 syscall-counts.py----
Once you've done that (don't forget to do a new 'make install',otherwise your script won't show up at run-time), 'perf script -l'should show a new entry for your script:
----# perf script -lList of available trace scripts: wakeup-latency system-wide min/max/avg wakeup latency rw-by-file <comm> r/w activity for a program, by file rw-by-pid system-wide r/w activity syscall-counts system-wide syscall counts----
You can now perform the record step via 'perf script record':
# perf script record syscall-counts
and display the output using 'perf script report':
# perf script report syscall-counts
STARTER SCRIPTS---------------
You can quickly get started writing a script for a particular set oftrace data by generating a skeleton script using 'perf script -gpython' in the same directory as an existing perf.data trace file.That will generate a starter script containing a handler for each ofthe event types in the trace file; it simply prints every availablefield for each event in the trace file.
You can also look at the existing scripts in~/libexec/perf-core/scripts/python for typical examples showing how todo basic things like aggregate event data, print results, etc. Also,the check-perf-script.py script, while not interesting for its results,attempts to exercise all of the main scripting features.
EVENT HANDLERS--------------
When perf script is invoked using a trace script, a user-defined'handler function' is called for each event in the trace. If there'sno handler function defined for a given event type, the event isignored (or passed to a 'trace_unhandled' function, see below) and thenext event is processed.
Most of the event's field values are passed as arguments to thehandler function; some of the less common ones aren't - those areavailable as calls back into the perf executable (see below).
As an example, the following perf record command can be used to recordall sched_wakeup events in the system:
# perf record -a -e sched:sched_wakeup
Traces meant to be processed using a script should be recorded withthe above option: -a to enable system-wide collection.
The format file for the sched_wakeup event defines the following fields(see /sys/kernel/tracing/events/sched/sched_wakeup/format):
---- format: field:unsigned short common_type; field:unsigned char common_flags; field:unsigned char common_preempt_count; field:int common_pid;
field:char comm[TASK_COMM_LEN]; field:pid_t pid; field:int prio; field:int success; field:int target_cpu;----
The handler function for this event would be defined as:
----def sched__sched_wakeup(event_name, context, common_cpu, common_secs, common_nsecs, common_pid, common_comm, comm, pid, prio, success, target_cpu): pass----
The handler function takes the form subsystem__event_name.
The common_* arguments in the handler's argument list are the set ofarguments passed to all event handlers; some of the fields correspondto the common_* fields in the format file, but some are synthesized,and some of the common_* fields aren't common enough to to be passedto every event as arguments but are available as library functions.
Here's a brief description of each of the invariant event args:
event_name the name of the event as text context an opaque 'cookie' used in calls back into perf common_cpu the cpu the event occurred on common_secs the secs portion of the event timestamp common_nsecs the nsecs portion of the event timestamp common_pid the pid of the current task common_comm the name of the current process
All of the remaining fields in the event's format file havecounterparts as handler function arguments of the same name, as can beseen in the example above.
The above provides the basics needed to directly access every field ofevery event in a trace, which covers 90% of what you need to know towrite a useful trace script. The sections below cover the rest.
SCRIPT LAYOUT-------------
Every perf script Python script should start by setting up a Pythonmodule search path and 'import'ing a few support modules (see moduledescriptions below):
---- import os import sys
sys.path.append(os.environ['PERF_EXEC_PATH'] + \ '/scripts/python/Perf-Trace-Util/lib/Perf/Trace')
from perf_trace_context import * from Core import *----
The rest of the script can contain handler functions and supportfunctions in any order.
Aside from the event handler functions discussed above, every scriptcan implement a set of optional functions:
*trace_begin*, if defined, is called before any event is processed andgives scripts a chance to do setup tasks:
----def trace_begin(): pass----
*trace_end*, if defined, is called after all events have been processed and gives scripts a chance to do end-of-script tasks, such as display results:
----def trace_end(): pass----
*trace_unhandled*, if defined, is called after for any event that doesn't have a handler explicitly defined for it. The standard set of common arguments are passed into it:
----def trace_unhandled(event_name, context, event_fields_dict): pass----
*process_event*, if defined, is called for any non-tracepoint event
----def process_event(param_dict): pass----
*context_switch*, if defined, is called for any context switch
----def context_switch(ts, cpu, pid, tid, np_pid, np_tid, machine_pid, out, out_preempt, *x): pass----
*auxtrace_error*, if defined, is called for any AUX area tracing error
----def auxtrace_error(typ, code, cpu, pid, tid, ip, ts, msg, cpumode, *x): pass----
The remaining sections provide descriptions of each of the availablebuilt-in perf script Python modules and their associated functions.
AVAILABLE MODULES AND FUNCTIONS-------------------------------
The following sections describe the functions and variables availablevia the various perf script Python modules. To use the functions andvariables from the given module, add the corresponding 'from XXXXimport' line to your perf script script.
Core.py Module~~~~~~~~~~~~~~
These functions provide some essential functions to user scripts.
The *flag_str* and *symbol_str* functions provide human-readablestrings for flag and symbolic fields. These correspond to the stringsand values parsed from the 'print fmt' fields of the event formatfiles:
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 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
The *autodict* function returns a special kind of Pythondictionary that implements Perl's 'autovivifying' hashes in Pythoni.e. with autovivifying hashes, you can assign nested hash valueswithout having to go to the trouble of creating intermediate levels ifthey don't exist.
autodict() - returns an autovivifying dictionary instance
perf_trace_context Module~~~~~~~~~~~~~~~~~~~~~~~~~
Some of the 'common' fields in the event format file aren't all thatcommon, but need to be made accessible to user scripts nonetheless.
perf_trace_context defines a set of functions that can be used toaccess this data in the context of the current event. Each of thesefunctions expects a context variable, which is the same as thecontext variable passed into every tracepoint event handler as the secondargument. For non-tracepoint events, the context variable is also presentas perf_trace_context.perf_script_context .
common_pc(context) - returns common_preempt count for the current event common_flags(context) - returns common_flags for the current event common_lock_depth(context) - returns common_lock_depth for the current event perf_sample_insn(context) - returns the machine code instruction perf_set_itrace_options(context, itrace_options) - set --itrace options if they have not been set already perf_sample_srcline(context) - returns source_file_name, line_number perf_sample_srccode(context) - returns source_file_name, line_number, source_line perf_config_get(config_name) - returns the value of the named config item, or None if unset
Util.py Module~~~~~~~~~~~~~~
Various utility functions for use with perf script:
nsecs(secs, nsecs) - returns total nsecs given secs/nsecs pair nsecs_secs(nsecs) - returns whole secs portion given nsecs nsecs_nsecs(nsecs) - returns nsecs remainder given nsecs nsecs_str(nsecs) - returns printable string in the form secs.nsecs avg(total, n) - returns average given a sum and a total number of values
SUPPORTED FIELDS----------------
Currently supported fields:
ev_name, comm, id, stream_id, pid, tid, cpu, ip, time, period, phys_addr,addr, symbol, symoff, dso, time_enabled, time_running, values, callchain,brstack, brstacksym, datasrc, datasrc_decode, iregs, uregs,weight, transaction, raw_buf, attr, cpumode.
Fields that may also be present:
flags - sample flags flags_disp - sample flags display insn_cnt - instruction count for determining instructions-per-cycle (IPC) cyc_cnt - cycle count for determining IPC addr_correlates_sym - addr can correlate to a symbol addr_dso - addr dso addr_symbol - addr symbol addr_symoff - addr symbol offset
Some fields have sub items:
brstack: from, to, from_dsoname, to_dsoname, mispred, predicted, in_tx, abort, cycles.
brstacksym: items: from, to, pred, in_tx, abort (converted string)
For example,We can use this code to print brstack "from", "to", "cycles".
if 'brstack' in dict: for entry in dict['brstack']: print "from %s, to %s, cycles %s" % (entry["from"], entry["to"], entry["cycles"])
SEE ALSO--------linkperf:perf-script[1]