Ten bpftrace One Liners That Replace a Week of Guessing

Share
Ten bpftrace One Liners That Replace a Week of Guessing. Abstract tooling illustration in orange and dark grey on debugly.dev

The request was slow but the CPU was idle, which is the sentence that ends most application level profilers, because they only see the process thinking, and the process was not thinking. It was waiting, on the kernel, on the disk, on the network, and the waiting is invisible from userspace. The kernel, meanwhile, observes every wait, because the wait happens inside it, and bpftrace is the shortest path from that observation to a number.

bpftrace compiles small programs into eBPF and runs them in the kernel, attaching to tracepoints, kprobes and uprobes, and printing aggregates. The overhead is small enough to run in production, which is the property that matters, because the latency you are chasing only happens in production.

This was Ubuntu 24.04 with bpftrace on Linux 6.8. The one liners below are the ones I actually use.

The syntax in one breath

A bpftrace program is probes, a filter and an action, separated by braces and semicolons. Probes name the event, like a syscall entry or exit, a scheduler switch or a block request. The action usually updates a map, and the built in histograms turn millions of events into a readable distribution. You do not need more than that for the recipes here.

Latency of a syscall, as a histogram

The highest value pattern is entry to exit latency:

bpftrace -e 'kprobe:do_sys_openat2 { @s[tid] = nsecs; }
kretprobe:do_sys_openat2 /@s[tid]/ { @ns = hist(nsecs - @s[tid]); delete(@s[tid]); }'

Swap the function for the syscall or kernel path you suspect and you have its latency distribution in production. A histogram with a second mode at a high latency is the stall, visible as a bump rather than as a guess.

Off CPU time, the wait you cannot see

When CPU is idle and requests are slow, the question is where the time went off CPU. The scheduler tracepoints give it:

bpftrace -e 'tracepoint:sched:sched_switch { @off[prev_comm] = nsecs; }
tracepoint:sched:sched_wakeup /@off[args->pid]/ { ... }'

The exact fields vary by version, but the idea is to timestamp when a thread stops running and measure until it runs again, per process. The resulting histogram is the off CPU latency, the scheduler's view of your stalls, and it routinely names the victim of a lock or an IO wait that no application profiler can see.

Block IO latency

For storage suspicions, time the block layer:

bpftrace -e 'tracepoint:block:block_rq_issue { @q[tid] = nsecs; }
tracepoint:block:block_rq_complete /@q[tid]/ { @us = hist((nsecs - @q[tid]) / 1000); delete(@q[tid]); }'

A disk that reports healthy averages but shows a millisecond tail in this histogram is the tail your p99 feels, per p99 and why averages lie.

New process and fork rate

When the task count is the mystery, watch creation live:

bpftrace -e 'tracepoint:sched:sched_process_fork { @forks[comm] = count(); }'

A process forking in a loop shows up immediately, which is the live view of the leak in fork retry resource temporarily unavailable.

TCP retransmits, the loss counter

bpftrace -e 'kprobe:tcp_retransmit_skb { @rt[comm] = count(); }'

Retransmits are the kernel admitting loss, and per process attribution tells you which workload is bleeding on the wire, separating your service from the noisy neighbour.

The discipline of the one liner

The recipes matter less than the posture they enable, and I want to name the habits that make them trustworthy.

Run them bounded, with a timeout or a Ctrl-C after a representative window, because a histogram over the incident window is a fact and a histogram over everything is a average.

Read histograms, not counters. A count tells you something happened. A distribution tells you it has a shape, and the shape, a bimodal bump, a long tail, is the diagnosis. The counter is the symptom and the histogram is the partition.

Compare against a good window. The same one liner during healthy traffic gives the baseline shape, and the diff between the two shapes is the change, which is most of what latency debugging is.

And respect the production boundary: these attach to kernel events and read no data contents by default, which is why they are acceptable where a payload capturing tool would not be, but the same care applies, bounded windows and no exporting of more than the aggregate.

When to reach for the neighbours

bpftrace is the kernel's view. When the stall is inside your language runtime, the event loop or the GC, the runtime's own profiler is sharper, per event loop lag. When the question is which function burns CPU, perf is the tool, per perf record. The skill is choosing the layer that owns the missing time, and bpftrace owns the layer where the application is innocent and the request is still slow.

The rule

When the process is idle and the request is slow, the time is in the kernel, and the kernel already observes it. One line histograms of syscall latency, off CPU time, block IO and retransmits turn the invisible wait into a distribution with a shape, in production, without restarting anything.

The shape is the diagnosis. The average was never going to tell you, and the week of guessing is ten one liners, run bounded, read as histograms, and compared against the good window.

It is also worth saying what these one liners do to an incident conversation, because the social effect is real. A latency dispute between the application team and the platform team is usually an exchange of beliefs, each side certain the other's layer is slow. A histogram of off CPU time or block IO latency, captured during the incident window, ends the exchange, because it is the kernel's own attribution and neither team wrote it. The tool is not just faster than guessing. It is neutral, and neutrality is what turns a blame conversation back into a measurement conversation, which is the only kind that ends.