perf script can dump raw event data, but it’s often a firehose. You need to tailor its output to see the signal in the noise.
Let’s say you’re tracking context switches (context-switches) and page faults (page-faults) to understand system churn.
Here’s a raw dump:
# To get the raw data, use:
perf record -e context-switches,page-faults -a sleep 10
perf script > raw_events.txt
This raw_events.txt will be packed with every single event, making it hard to spot trends.
To make this actionable, we need to tell perf script how to present the data.
The key is the --output-format or -F option. It takes a comma-separated list of fields.
For our example, we want to see the timestamp, the event type, the process name, and the thread ID.
perf script -F comm,tid,event,time > custom_output.txt
This custom_output.txt will look something like this:
bash 12345 page-faults 123.456789
bash 12345 context-switches 123.460123
bash 12345 page-faults 123.478901
nginx 67890 page-faults 123.500000
nginx 67890 page-faults 123.501000
bash 12345 context-switches 123.510000
This is much more digestible. We can see which processes are causing faults and when switches are happening.
But what if we want to filter during the script dump? That’s where --filter comes in.
Suppose we only care about page faults from the nginx process.
perf script -F comm,tid,event,time --filter 'comm == "nginx" && event == "page-faults"' > nginx_faults.txt
The filter syntax is C-like. You can use ==, !=, <, >, <=, >=, && (AND), || (OR), and !.
This nginx_faults.txt will only contain lines like:
nginx 67890 page-faults 123.500000
nginx 67890 page-faults 123.501000
It’s not just about filtering events; you can also filter based on kernel symbols or user-space symbols.
Let’s say you’re interested in events happening within the sys_read system call.
First, you need to record system call entry/exit events. perf can do this with syscalls:sys_enter_* or syscalls:sys_exit_*.
perf record -e 'syscalls:sys_enter_read' -a sleep 5
perf script -F comm,tid,sym,time --filter 'sym == "sys_read"' > sys_read_events.txt
The sym field is crucial here for symbol names.
The time field shows the event’s timestamp. If you want to see relative time from the start of the recording, use elapsed.
perf script -F comm,tid,event,elapsed > relative_time.txt
This relative_time.txt would show timestamps starting from 0.
You can also get the instruction pointer (IP) with the ip field. This is useful for correlating events to specific code locations.
perf script -F comm,tid,event,ip,time > ip_events.txt
The output might look like:
bash 12345 page-faults 0xffffffff81234567 123.456789
When you need to see the exact location of events in your code, the dso (Dynamic Shared Object) field is invaluable. It shows the library or executable the IP belongs to.
perf script -F comm,tid,event,ip,dso,time > dso_events.txt
The dso field would show something like [kernel.vmlinux] or [libc-2.31.so].
If you’re debugging a specific thread, you can use the tid field in your filters.
perf script -F comm,tid,event,time --filter 'tid == 12345' > thread_12345_events.txt
This gives you a focused view on a single thread’s activity.
The power of perf script’s custom output lies in combining these fields and filters. You can pinpoint specific activities within your system by selecting precisely the data you need.
What most people don’t realize is that the event field is not just the event name; it can also be a specific tracepoint name (e.g., sched:sched_switch) or even a raw event code if you’re digging deep. For tracepoints, the event name often includes the probe name itself.
The next hurdle you’ll likely face is correlating perf events with your application’s source code, which often involves using perf annotate.