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