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