R0KernelPath
module 069 / 262

Tracing & Profiling: ftrace, perf, strace, ltrace

See exactly what your kernel is doing — from individual syscalls to CPU flamegraphs — using the professional tracing tools that Linux developers live inside.

~18h focused study10 concepts

Overview

Every program you run is, at its core, a series of requests to the kernel. A web server "does networking" by calling socket(), bind(), listen(), accept(). A database "does storage" by calling open(), read(), write(), fsync(). The kernel's job is to honor those requests safely and efficiently. But when something goes wrong — a mysterious slowdown, a hang, a crash — how do you see what actually happened? This module teaches you to observe the running system with surgical precision.

Linux ships with a world-class, production-safe observability stack that is largely unknown outside performance engineering circles. strace and ltrace let you watch a process's every interaction with the kernel and its libraries in real time. perf is a Swiss Army knife that can count hardware CPU events, record call-chain samples, and tell you exactly which function is burning your cycles. ftrace is the kernel's own built-in tracing framework — a flight recorder wired directly into thousands of points inside kernel code. Together they form a hierarchy from "what is this process asking the kernel to do?" all the way to "which exact line of kernel C is this CPU executing right now?"

The observability mindset is as important as any individual tool. A skilled systems programmer doesn't guess where a performance problem is. They form a hypothesis, instrument the system to test it, interpret the data without confirmation bias, and iterate. Brendan Gregg's USE (Utilization, Saturation, Errors) and RED (Rate, Errors, Duration) methodologies are examples of this disciplined approach. Every tool in this module is a different lens on the same running system; knowing which lens to reach for — and why — separates debugging by intuition from debugging by understanding.

This module takes you from the outermost layer (process-level syscall tracing) through library tracing, sampling profilers, event-based profiling, and into the kernel's own tracing infrastructure. By the end you will be able to produce flame graphs of a production process, attach kprobes to arbitrary kernel functions, and read ftrace output to understand scheduling, interrupts, and locking behavior at microsecond resolution.

why this matters for the kernel

Linux kernel contributors are expected to understand performance implications of the code they write. A patch that introduces a new code path into the scheduler, the memory allocator, or a filesystem must not regress latency or throughput. Reviewers will ask: "Did you measure this? What does perf say?" Without fluency in these tools you cannot answer that question, and your patches will be held up or rejected. Every significant kernel contribution from the last decade has been accompanied by perf stat or perf record output in the cover letter or mailing list thread.

Beyond patch review, these tools are how kernel developers find bugs. ftrace's function_graph tracer has been used to diagnose scheduler bugs, lock contention, interrupt storms, and spurious wakeups. kprobes let you add printf-style debugging to a running production kernel without rebooting. strace is frequently the first tool a kernel developer reaches for when a userspace program misbehaves in a way that implicates a kernel change. Mastering this toolchain means you can navigate the kernel's behavior confidently — you will have proof, not conjecture.

Linux Observability Tool Layers

rendering diagram…

Each observability tool taps into the kernel at a different layer. strace and ltrace intercept at process boundaries using ptrace. perf bridges userspace and kernel via the perf_events subsystem, consuming hardware PMU events, tracepoints, and kprobes. ftrace lives entirely inside the kernel, zero-cost when idle thanks to dynamic nop patching. All paths converge on human-readable output: perf report, flame graphs, trace_pipe, and trace-cmd recordings.

The concepts

01The Tracing Stack: A Map of the Territory

Before diving into individual tools, it helps to see the whole landscape. The Linux observability stack is layered, and each layer answers a different question.

At the outermost layer, strace and ltrace sit entirely in userspace and use the ptrace(2) system call to intercept every kernel call (strace) or every dynamic library call (ltrace) made by a target process. These tools work by stopping the target on every event, which makes them safe but slow — often 10–100× slower than normal execution. They are diagnostic tools, not production monitoring tools.

One layer deeper, perf bridges userspace and the kernel. It uses a kernel subsystem called perf_events (sometimes called Performance Counters for Linux, or PCL). perf can operate in two modes: counting mode (hardware counters tell you totals at the end) and sampling mode (the CPU generates an interrupt every N events and perf records a stack sample). Sampling overhead is tunable and can be made very low — perf is routinely run on production systems.

Deeper still, ftrace lives entirely inside the kernel. It uses the compiler's -pg flag (or, on modern kernels, CONFIG_DYNAMIC_FTRACE) to insert a call-site stub at the entry of every kernel function. At boot time those stubs are patched to nop instructions for zero overhead. When you enable tracing for a function, the kernel patches that nop back to a call ftrace_caller instruction on-the-fly, without stopping the system. This is the mechanism behind function_tracer, function_graph_tracer, event tracing, and kprobes.

Finally, tracepoints are explicit, hand-placed hooks inside kernel source code. The kernel maintainers add them at important decision points — e.g., sched_switch, block_rq_issue, net_dev_xmit. These are stable ABI, meaning they survive kernel upgrades without breaking tools that use them. eBPF programs, perf, ftrace, and SystemTap all consume tracepoints.

Think of it this way: strace/ltrace are like listening at the door of the kernel's office. perf is like looking at the office's security camera footage. ftrace is like being inside the office with a notebook. Tracepoints are like sticky notes the kernel developers left for you on every important desk.

# The conceptual layering — check what's available on your system
ls /sys/kernel/debug/tracing/           # ftrace infrastructure
ls /sys/kernel/debug/tracing/events/    # available tracepoints
perf list                               # all perf event types
cat /proc/sys/kernel/perf_event_paranoid  # 0=all, 1=no raw hw, 2=no kernel, 3=disabled

02strace: Watching Every Kernel Request

strace is probably the most important debugging tool a Linux programmer can know. It uses ptrace(PTRACE_SYSCALL) to intercept every system call: the kernel stops the process just before the syscall executes and just after it returns, handing control to strace which prints the call and its arguments.

The output format is: syscall(arg1, arg2, ...) = return_value. strace decodes the numeric constants for you (O_RDONLY|O_CLOEXEC instead of 524288), truncates long strings with ..., and translates error numbers to names (ENOENT, EACCES).

Reading strace output is a skill. The most useful patterns:

  • open("/etc/ld.so.cache", O_RDONLY|O_CLOEXEC) = 3 — file opened successfully, fd=3
  • open("/usr/lib/libc.so.6", ...) = -1 ENOENT — file not found
  • read(3, "ELF\2\1\1\0...", 832) = 832 — read 832 bytes from fd 3
  • mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f... — anonymous mapping

Key flags to know:

  • -e trace=file — only file-related syscalls
  • -e trace=network — only network syscalls
  • -p PID — attach to a running process
  • -f — follow child processes (fork/exec)
  • -c — count mode: print a summary table of syscall counts and time at exit
  • -T — show time spent in each syscall
  • -tt — prepend timestamps
  • -o file — write output to file instead of stderr
  • -y — resolve file descriptors to paths

A worked example: you have a program that fails silently. strace ./myprogram reveals it's trying to open("/etc/config.d/myapp.conf", ...) = -1 ENOENT. Mystery solved without touching a single line of code.

Performance cost: each syscall requires two ptrace stops, two context switches user→kernel→user, and one write to stderr. For programs that make thousands of syscalls per second (a busy network server), strace is not appropriate for long-term use. The -c summary mode is slightly cheaper.

Under the hood: ptrace works by setting a flag in the task's thread_info struct (TIF_SYSCALL_TRACE). The kernel's syscall entry/exit paths check this flag. If set, the kernel calls ptrace_report_syscall() which sends a SIGTRAP to the tracer (strace), causing the tracer to wake up, inspect the tracee's registers (where syscall number and arguments live), then resume the tracee.

/* compile: gcc -o demo demo.c */
#include <fcntl.h>
#include <unistd.h>
int main(void) {
    int fd = open("/nonexistent", O_RDONLY);
    if (fd == -1) return 1;
    close(fd);
    return 0;
}

/* Run: strace -e trace=openat,close ./demo
   Output:
   openat(AT_FDCWD, "/nonexistent", O_RDONLY) = -1 ENOENT (No such file or directory)
   +++ exited with 1 +++

   Note: open(2) is implemented via openat on modern kernels.
*/

/* Count all syscalls of a long-running program: */
/* strace -c -p $(pgrep nginx | head -1) */

03ltrace: Library Call Tracing

ltrace does for dynamic library calls what strace does for system calls. It intercepts calls to shared libraries — malloc, printf, strlen, pthread_mutex_lock, SSL_read, etc. — by overwriting the PLT (Procedure Linkage Table) entries in the target process with breakpoint instructions.

Why this matters: many performance problems and bugs are not in syscalls but in library behavior. A program might call strlen a million times on the same string, or hold a pthread_mutex_lock across a slow operation, or call malloc and free in a tight loop when it should be reusing a buffer. strace would show none of this; ltrace reveals all of it.

PLT mechanics (brief): when a program is compiled against libc, calls to printf are compiled as call printf@plt. The PLT entry contains a jump through the GOT (Global Offset Table). The dynamic linker patches the GOT at load time to point to the real function. ltrace patches those GOT entries to point to breakpoint stubs instead.

Usage mirrors strace:

  • ltrace ./myprogram
  • ltrace -e malloc+free ./myprogram — only malloc/free
  • ltrace -c ./myprogram — count mode summary
  • ltrace -l libssl.so.* ./curl https://... — only libssl calls

ltrace output example:

malloc(1024)       = 0x55a1b2c3d000
strcpy(0x55a1..., "hello world") = 0x55a1...
printf("Result: %s\n", "hello world") = 15
free(0x55a1b2c3d000) = <void>

Limitation: ltrace only sees dynamically-linked calls. Statically-linked binaries (like many Go programs or musl-linked C programs) are invisible to ltrace. It also doesn't see calls between two functions within the same shared library — only cross-library PLT crossings.

Performance cost: similar to strace — one breakpoint per call. Not suitable for production profiling of high-frequency library calls.

/* gcc -o ltrace_demo ltrace_demo.c */
#include <stdio.h>
#include <stdlib.h>
#include <string.h>

int main(void) {
    for (int i = 0; i < 5; i++) {
        char *buf = malloc(64);
        snprintf(buf, 64, "iteration %d", i);
        printf("%s\n", buf);
        free(buf);
    }
    return 0;
}

/* ltrace -e malloc+free+snprintf+printf ./ltrace_demo
   malloc(64)  = 0x...
   snprintf(0x..., 64, "iteration %d", 0) = 11
   printf("%s\n", "iteration 0") = 12
   free(0x...) = <void>
   ...repeated 5 times...

   Pattern to notice: malloc+free in every loop iteration.
   A real optimization would move the allocation outside the loop.
*/

04perf stat: Counting Hardware Events

perf stat runs a program (or attaches to a PID) and counts hardware performance events using the CPU's built-in Performance Monitoring Unit (PMU). Modern CPUs have dedicated counters that increment every time something happens: a cache miss, a branch misprediction, a TLB shootdown, a cycle elapsed, an instruction retired.

The key metrics and what they mean:

  • instructions — total instructions retired (completed without being squashed)
  • cycles — total CPU cycles consumed
  • IPC (instructions per cycle) — instructions ÷ cycles. Modern CPUs can theoretically execute 4+ instructions/cycle. An IPC near 1.0 is decent; near 0.3 suggests the CPU is stalling waiting for memory.
  • cache-misses — L1/L2/LLC (Last Level Cache) misses. An LLC miss means the data had to come from DRAM, costing ~100ns instead of ~1ns.
  • branch-misses — mispredicted branches. The CPU speculatively executes the wrong path and has to flush the pipeline — typically a 15–20 cycle penalty.
  • page-faults — major (disk I/O needed) or minor (page table entry needed)
  • context-switches — how often the scheduler preempted this process

Reading the output:

 Performance counter stats for './matrix_multiply':
        2,145,678,432      instructions              #    1.87  insn per cycle
        1,147,983,021      cycles
              821,432      cache-misses              #    0.42% of all cache refs
               12,840      branch-misses             #    0.03% of all branches
               1.023 s     elapsed

Here: IPC=1.87 is healthy; cache-miss rate 0.42% is excellent; branch-miss 0.03% is excellent. This is a compute-bound program running efficiently.

Contrast with a cache-unfriendly program:

        3,211,223,111      instructions              #    0.18  insn per cycle
       17,840,334,220      cycles
          412,345,123      cache-misses              #   38.2% of all cache refs

IPC=0.18 — the CPU is doing almost nothing useful, just waiting for DRAM on almost every memory access.

Multiplexing: CPUs have a limited number of physical counters (typically 4–8 general-purpose + some fixed). If you request more events than there are counters, the kernel multiplexes them: it rotates which events are being counted on a schedule and extrapolates the totals. This introduces estimation error, shown as the (xx.xx%) at the end of each line.

Useful flags:

  • perf stat -d ./prog — detailed: adds L1/LLC/branch stats
  • perf stat -r 5 ./prog — repeat 5 times, show mean ± stddev
  • perf stat -e cycles,instructions,cache-misses ./prog — custom event list
  • perf stat -a sleep 5 — system-wide, all CPUs, 5 seconds
/* Two versions of array sum — column-major vs row-major access.
   Demonstrates cache effects measurable with perf stat.
   gcc -O2 -o cache_demo cache_demo.c */
#include <stdio.h>
#include <stdlib.h>
#include <string.h>

#define N 4096
static int mat[N][N];

long row_sum(void) {
    long s = 0;
    for (int i = 0; i < N; i++)
        for (int j = 0; j < N; j++)
            s += mat[i][j];   /* row-major: sequential, cache-friendly */
    return s;
}

long col_sum(void) {
    long s = 0;
    for (int i = 0; i < N; i++)
        for (int j = 0; j < N; j++)
            s += mat[j][i];   /* col-major: strided, cache-hostile */
    return s;
}

int main(void) {
    memset(mat, 1, sizeof(mat));
    printf("row: %ld\n", row_sum());
    printf("col: %ld\n", col_sum());
    return 0;
}

/* perf stat -d ./cache_demo
   row_sum: ~0.05s,  IPC~3.5, LLC-miss rate <1%
   col_sum: ~0.80s,  IPC~0.3, LLC-miss rate >40%
   Same computation, 16× slower due to cache misses alone. */

05perf record & perf report: Sampling Profiler

perf record turns perf into a sampling profiler. It tells the CPU's PMU: "every N cycles (or every N cache misses, etc.), generate a hardware interrupt". When the interrupt fires, the kernel records the current instruction pointer — and optionally the full call stack — to a ring buffer. After the program exits (or you press Ctrl-C), the data is written to perf.data.

perf report reads perf.data and shows you a ranked list of where samples were found. Each sample represents the CPU spending time at that location. The more samples at a function, the more time the CPU spent there.

Call-graph collection is the critical step most beginners skip. Without -g, you only see which function the CPU was in, but not how it got there. With -g (or --call-graph=dwarf for accurate unwinding), you see the full call chain. This is what makes flame graphs possible.

Unwinding methods:

  • --call-graph=fp — frame pointer unwinding. Fast, but requires -fno-omit-frame-pointer at compile time. Most distro packages strip frame pointers for optimization.
  • --call-graph=dwarf — uses DWARF debug info (.eh_frame section). Accurate even without frame pointers. Writes larger data. Works on most system libraries.
  • --call-graph=lbr — uses the CPU's Last Branch Record hardware (Intel only). No overhead, limited depth (~32 frames).

Annotate: perf annotate function_name shows the source (if debug info is available) or assembly, with the percentage of samples on each line/instruction. This tells you not just which function is hot, but which instruction inside it is the bottleneck.

perf top: like top but for CPU profiling — live, updating view of the hottest functions system-wide. Invaluable for diagnosing sudden CPU spikes.

Kernel symbols: to see kernel function names instead of [unknown], you need either:

  • sudo perf record (root access to kernel samples)
  • echo 0 > /proc/sys/kernel/perf_event_paranoid (temporarily)
  • CONFIG_KALLSYMS=y in the kernel build
  • The kernel's vmlinux file or a kernel-debuginfo package
# Compile with frame pointers and debug info
gcc -O2 -g -fno-omit-frame-pointer -o myapp myapp.c

# Record 30 seconds of samples at 99Hz with call graphs
# (99Hz, not 100Hz, to avoid lockstep with timer interrupts)
perf record -F 99 -g -- ./myapp

# Or attach to a running process
perf record -F 99 -g -p $(pgrep myapp) -- sleep 30

# Explore interactively (arrow keys, Enter to drill down)
perf report

# Non-interactive: show flat profile
perf report --stdio --no-children | head -40

# Annotate a specific hot function
perf annotate hot_function --stdio

# See call graph for a specific symbol
perf report --call-graph --symbol-filter hot_function

# Live profiling (top-like)
sudo perf top -F 99 -g

06Flame Graphs: Turning Stack Samples into Pictures

A flame graph is a visualization invented by Brendan Gregg that solves a fundamental problem: perf report gives you a tree of call stacks, but large call trees are hard to navigate. A flame graph collapses all samples into a single SVG image where:

  • The X axis is the total population of samples, sorted alphabetically (NOT time — left-to-right order is alphabetical, not temporal).
  • The Y axis is call depth — the bottom is the root, the top is the leaf (the function the CPU was actually in).
  • The width of each rectangle is proportional to the fraction of samples that include that function in the call stack.
  • Color is arbitrary (or can encode CPU type, or JIT vs native, depending on the variant).

How to read a flame graph: look for wide plateaus near the top. A wide rectangle means many samples were taken with that function on the stack — i.e., the CPU spent a lot of time there. A plateau that is wide at the top but narrows toward the base means many different code paths converged on that hot function. Narrow spikes reaching high are deep recursion with few samples — usually fine.

The three-step workflow with Brendan Gregg's FlameGraph scripts:

  1. perf record -F 99 -g -- ./prog — capture samples
  2. perf script — convert perf.data to text format
  3. stackcollapse-perf.pl → flamegraph.pl — generate SVG

The resulting SVG is interactive in a browser: click a box to zoom in, hover for percentages, search (Ctrl-F) to highlight all frames matching a regex.

Variants:

  • CPU flame graph (most common) — samples taken on CPU cycles
  • Off-CPU flame graph — samples taken when the thread is not running (blocked in I/O, sleep, lock wait). Requires tracing scheduler events, not hardware counters.
  • Memory flame graph — samples on malloc calls, showing allocation hot paths
  • Differential flame graph — subtracts one profile from another, showing what got worse/better between two versions

Icicle graphs: same data, flipped upside-down. Some people find them more natural to read since the widest part (root) is at the top, like a tree.

# Install FlameGraph scripts (Brendan Gregg's repo)
git clone https://github.com/brendangregg/FlameGraph /opt/FlameGraph
export PATH=$PATH:/opt/FlameGraph

# Full workflow: record, fold, visualize
perf record -F 99 -ag --call-graph=dwarf -- ./myapp  # -a = all CPUs
perf script > /tmp/out.perf
stackcollapse-perf.pl /tmp/out.perf > /tmp/out.folded
flamegraph.pl /tmp/out.folded > /tmp/flamegraph.svg

# Open in browser
open /tmp/flamegraph.svg   # macOS
xdg-open /tmp/flamegraph.svg  # Linux desktop

# Differential flame graph: before vs after a change
flamegraph.pl --negate /tmp/before.folded > /tmp/delta.svg
# (blue = improved, red = regressed)

# Tip: for kernel + userspace combined view on Linux:
perf record -F 99 -ag --call-graph=dwarf -- sleep 30
# You'll see both kernel frames (e.g. [k] schedule) and
# userspace frames (e.g. [.] malloc) in the same graph.

07ftrace: The Kernel's Own Flight Recorder

ftrace ("function tracer") is a tracing framework built into the Linux kernel itself. It was merged in kernel 2.6.27 (2008) and has grown into the backbone of in-kernel observability. Unlike perf and strace which work from outside, ftrace instruments the kernel from inside — it can trace scheduler decisions, interrupt handling, memory allocator calls, and more.

The control interface is the filesystem: everything in ftrace is exposed through /sys/kernel/debug/tracing/ (mounted as debugfs or tracefs). This is a deliberate design choice — no new syscalls needed, just file reads and writes. You enable tracing by writing to files; you read traces by reading files.

Key files:

  • current_tracer — which tracer is active (nop, function, function_graph, irqsoff, preemptoff, blk)
  • available_tracers — list of compiled-in tracers
  • tracing_on — 1 to enable, 0 to pause without losing the buffer
  • trace — read the current trace buffer
  • trace_pipe — streaming version of trace (blocks, like tail -f)
  • set_ftrace_filter — limit tracing to specific functions (glob patterns supported)
  • set_ftrace_pid — limit tracing to a specific PID
  • buffer_size_kb — size of per-CPU ring buffers

The function tracer records every kernel function call. This is extremely noisy (millions of events per second on a busy system) but can be filtered:

echo 'tcp_*' > set_ftrace_filter   # only tcp_* functions
echo function > current_tracer
echo 1 > tracing_on
sleep 1
echo 0 > tracing_on
cat trace

The function_graph tracer shows function entry AND exit with indentation, making it look like a call tree with timing. This is invaluable for understanding the sequence of events inside a kernel subsystem.

Dynamic ftrace: the magic behind zero-overhead-when-disabled is in CONFIG_DYNAMIC_FTRACE. The compiler inserts a call fentry (x86) or bl ftrace_caller (ARM64) at the start of every kernel function. At boot, the kernel patches all these to nop. When you enable tracing for a function, the kernel does a live text patch, replacing nop with the real call. This live patching is done atomically using stop_machine() — briefly stopping all CPUs simultaneously so no CPU is executing the instruction being modified.

trace-cmd is a userspace front-end to ftrace that wraps the /sys/kernel/debug/tracing/ interface into a friendlier CLI and binary recording format. kernelshark is a GUI for viewing trace-cmd recordings.

#!/bin/bash
# Minimal ftrace script: trace scheduler wakeup latency
# Must be run as root

TRACING=/sys/kernel/debug/tracing

# Save and restore state
ORIG_TRACER=$(cat $TRACING/current_tracer)

# Setup
echo 0 > $TRACING/tracing_on
echo nop > $TRACING/current_tracer     # reset
echo > $TRACING/trace                  # clear buffer
echo 8192 > $TRACING/buffer_size_kb   # 8MB per-CPU buffer

# Enable function_graph tracer, filtered to ext4 functions
echo 'ext4_*' > $TRACING/set_ftrace_filter
echo function_graph > $TRACING/current_tracer
echo 1 > $TRACING/tracing_on

# Do something that touches ext4
dd if=/dev/zero of=/tmp/testfile bs=4k count=256 2>/dev/null

echo 0 > $TRACING/tracing_on

# Show first 50 lines of trace
head -50 $TRACING/trace

# Cleanup
echo nop > $TRACING/current_tracer
echo > $TRACING/set_ftrace_filter
echo $ORIG_TRACER > $TRACING/current_tracer

# Sample output lines:
# 1)   0.540 us    |  ext4_file_write_iter() {
# 1)   0.123 us    |    ext4_write_checks();
# 1)   2.340 us    |    ext4_journal_start_sb() {
# 1)   0.089 us    |      jbd2__journal_start();
# 1)   2.451 us    |    }

08Tracepoints: Stable Kernel Instrumentation Points

While ftrace's function tracer can trace any kernel function, those are internal implementation details that can change between kernel versions. Tracepoints are different: they are explicitly placed by kernel developers at semantically meaningful locations and are considered a stable ABI. Tools built on tracepoints continue to work across kernel versions.

A tracepoint is defined using the DEFINE_EVENT and TRACE_EVENT macros in kernel source. These macros generate:

  1. An inline probe function that checks if anyone is listening
  2. A ring buffer write path for when listeners are attached
  3. A print format for human-readable output
  4. BPF program attachment points

Important tracepoint subsystems (browse them at /sys/kernel/debug/tracing/events/):

  • sched/ — sched_switch, sched_wakeup, sched_migrate_task
  • irq/ — irq_handler_entry, irq_handler_exit
  • block/ — block_rq_issue, block_rq_complete, block_bio_queue
  • net/ — net_dev_xmit, net_dev_queue, netif_receive_skb
  • kmem/ — kmalloc, kfree, mm_page_alloc
  • syscalls/ — sys_enter_*, sys_exit_* (one per syscall!)
  • ext4/, btrfs/ — filesystem-specific events

Enabling a tracepoint via sysfs:

# Enable the sched_switch tracepoint
echo 1 > /sys/kernel/debug/tracing/events/sched/sched_switch/enable
cat /sys/kernel/debug/tracing/trace_pipe &
# ... do something ...
echo 0 > /sys/kernel/debug/tracing/events/sched/sched_switch/enable

Filtering: each tracepoint event has a filter file. You write boolean expressions in a simple language:

echo 'prev_state == 1' > /sys/.../sched_switch/filter  # only when going to sleep
echo 'common_pid == 1234' > /sys/.../filter  # only PID 1234

Tracepoints from perf: perf record -e sched:sched_switch -ag records scheduler context switches with full call stacks. This is the basis for off-CPU profiling.

In-kernel tracepoint definition (for kernel developers):

/* In include/trace/events/mysubsystem.h */
TRACE_EVENT(my_event,
    TP_PROTO(struct task_struct *t, int val),
    TP_ARGS(t, val),
    TP_STRUCT__entry(
        __field(pid_t, pid)
        __field(int,   val)
    ),
    TP_fast_assign(
        __entry->pid = t->pid;
        __entry->val = val;
    ),
    TP_printfmt("pid=%d val=%d", __entry->pid, __entry->val)
);

/* In your kernel code: */
trace_my_event(current, some_value);  /* zero cost if no listener */
#!/bin/bash
# Observe system call entry/exit via tracepoints
# Shows every execve() call system-wide — great for security auditing

TRACING=/sys/kernel/debug/tracing

echo 0 > $TRACING/tracing_on
echo > $TRACING/trace

# Enable syscall enter/exit tracepoints for execve
echo 1 > $TRACING/events/syscalls/sys_enter_execve/enable
echo 1 > $TRACING/events/syscalls/sys_exit_execve/enable

echo 1 > $TRACING/tracing_on
echo "Watching execve for 5 seconds..."
sleep 5
echo 0 > $TRACING/tracing_on

cat $TRACING/trace | grep -v '^#'

# Cleanup
echo 0 > $TRACING/events/syscalls/sys_enter_execve/enable
echo 0 > $TRACING/events/syscalls/sys_exit_execve/enable

# Output looks like:
# bash-1234 [001] .... 12345.678: sys_enter_execve: filename: "/usr/bin/ls" ...
# ls-5678   [001] .... 12345.679: sys_exit_execve:  ret=0

09kprobes and uprobes: Dynamic Instrumentation

Tracepoints are placed by kernel developers at planned locations. But what if you want to trace a function that has no tracepoint? kprobes (kernel probes) let you attach a handler to any kernel instruction dynamically, without recompiling or rebooting.

How kprobes work: when you register a kprobe on address X, the kernel:

  1. Saves the instruction at X
  2. Replaces it with a breakpoint instruction (int3 on x86, BRK on ARM64)
  3. When the CPU hits the breakpoint, the breakpoint handler calls your registered pre_handler function
  4. Then single-steps the original instruction
  5. Then calls your post_handler
  6. Then resumes normal execution

This is all done with zero preparation to the target code — it works on any kernel function, including those in modules.

kretprobes (return probes) work similarly but fire when a function returns, allowing you to capture return values and measure function latency.

Writing a kprobe as a kernel module:

#include <linux/kprobes.h>

static int pre_handler(struct kprobe *p, struct pt_regs *regs) {
    pr_info("kprobe: hit do_sys_openat2, ip=%lx\n", (long)p->addr);
    return 0;
}

static struct kprobe kp = {
    .symbol_name = "do_sys_openat2",
    .pre_handler = pre_handler,
};

static int __init kprobe_init(void) { return register_kprobe(&kp); }
static void __exit kprobe_exit(void) { unregister_kprobe(&kp); }
module_init(kprobe_init);
module_exit(kprobe_exit);

kprobes via ftrace/perf interface (no module needed):

# Create a kprobe event on do_sys_openat2, capturing the filename arg
echo 'p:myprobe do_sys_openat2 filename=+0(%si):string' > \
    /sys/kernel/debug/tracing/kprobe_events
echo 1 > /sys/kernel/debug/tracing/events/kprobes/myprobe/enable
cat /sys/kernel/debug/tracing/trace_pipe

uprobes are the userspace equivalent: you can attach probes to any instruction in any userspace binary or library. The syntax in the tracing interface uses /path/to/binary:offset. uprobes are how many USDT (User-level Statically Defined Tracing) implementations work on Linux.

eBPF + kprobes: the modern way to use kprobes productively is to attach eBPF programs instead of kernel modules. Tools like bpftrace and BCC provide high-level languages for writing kprobe handlers that can aggregate data in kernel-space histograms, avoiding the cost of sending every event to userspace.

Safety: kprobes refuse to instrument certain critical sections (kprobes blacklist). Writing a bad kprobe handler can panic the kernel. But read-only observation using pt_regs to inspect arguments is generally safe.

# kprobe via the perf-probe interface — no kernel module needed
# Probe vfs_read and print the count argument (3rd arg = rdx on x86-64)

# Add the probe
sudo perf probe --add 'vfs_read count:u64'

# Record 10 seconds of vfs_read events with call graphs
sudo perf record -e probe:vfs_read -ag -- sleep 10

# Report
sudo perf report

# Alternatively, via ftrace kprobe_events:
# p:vfs_read_probe vfs_read count=%dx:u64
# Then enable and read trace_pipe as shown above

# bpftrace one-liner (modern approach if bpftrace is installed):
# sudo bpftrace -e 'kprobe:vfs_read { @[comm] = hist(arg2); }'
# This prints a histogram of read sizes, grouped by process name.

# List available probe points matching a pattern:
sudo perf probe -L vfs_read         # show source lines
sudo perf probe --funcs | grep tcp_ # list all tcp_ functions

10The Observability Mindset: How to Actually Diagnose Problems

Having tools is not the same as knowing how to use them. Expert performance engineers follow a disciplined methodology that prevents the most common mistake: premature optimization based on intuition rather than measurement.

Step 1: Define the problem precisely. "The app is slow" is not a problem statement. "The 99th percentile latency for API endpoint /search increased from 50ms to 800ms after last Tuesday's deploy" is a problem statement. Precise metrics tell you what to measure and when you've solved it.

Step 2: Start from the outside and work in. This is the "top-down" methodology:

  1. Is the machine under CPU, memory, or I/O pressure? (top, vmstat, iostat, free)
  2. Is the process using excessive CPU? (perf top, perf stat)
  3. Is it waiting on I/O? (strace -c, off-CPU profiling)
  4. Is it spending time in syscalls? (perf stat -e syscalls:...)
  5. Which function is the CPU hot in? (perf record -g, flame graph)
  6. Which instruction within that function? (perf annotate)
  7. Is it a kernel issue? (ftrace, kprobes)

Step 3: Form a hypothesis and test it. "I think the slowness is due to lock contention in the thread pool." Test: enable the lock tracepoints, measure time in mutex_lock via kretprobe. If your hypothesis is wrong, discard it and form a new one.

Step 4: Make one change at a time. If you change three things simultaneously and performance improves, you don't know which change helped.

Brendan Gregg's USE Method for resource analysis:

  • Utilization — how busy is the resource? (CPU at 95% utilization)
  • Saturation — is work queuing up? (run queue depth > number of CPUs)
  • Errors — are there error events? (network packet drops, disk I/O errors) Apply to every resource: CPUs, memory, disks, network interfaces, bus (PCIe), I/O controllers.

The RED Method for service analysis:

  • Rate — requests per second
  • Errors — error rate
  • Duration — latency distribution (especially percentiles: p50, p99, p999)

Beware observer effects: strace makes your program 10–100× slower. That slowness can mask or create different bugs. If strace shows nothing, the bug might be the overhead of strace changing timing. Switch to perf (lower overhead) or ftrace tracepoints (sub-microsecond overhead) when precision matters.

#!/bin/bash
# Practical triage script: initial diagnosis of a slow process
# Usage: ./triage.sh <PID>

PID=${1:-$(pgrep -n myapp)}
echo "=== Triage for PID $PID ==="

echo "--- Syscall summary (10 seconds) ---"
strace -c -p "$PID" &
STRACE_PID=$!
sleep 10
kill $STRACE_PID 2>/dev/null
wait $STRACE_PID 2>/dev/null

echo "--- CPU profile (10 seconds) ---"
perf stat -p "$PID" -- sleep 10 2>&1 | \
    grep -E 'instructions|cycles|cache-miss|branch-miss|IPC'

echo "--- Flame graph ---"
perf record -F 99 -g -p "$PID" -- sleep 10
perf script | /opt/FlameGraph/stackcollapse-perf.pl | \
    /opt/FlameGraph/flamegraph.pl > /tmp/triage-${PID}.svg
echo "Flame graph written to /tmp/triage-${PID}.svg"

echo "--- Open file descriptors ---"
ls -la /proc/$PID/fd | wc -l

echo "--- Memory maps ---"
cat /proc/$PID/status | grep -E 'VmRSS|VmSwap|Threads'

Key insights

  • ✦strace/ltrace are for diagnosis, not production monitoring — their ptrace overhead can be 100× slower. Use perf or ftrace when you need low-overhead observation.
  • ✦IPC (instructions per cycle) from perf stat is the single most revealing number for CPU efficiency: below ~0.5 almost always means memory-bound, above ~2.0 means compute-bound. Fix memory-bound code first.
  • ✦Flame graphs encode TIME as WIDTH, not height. A wide plateau at the top of a stack means that function consumed CPU. Height means call depth — impressive looking tall flames are often less important than wide flat ones.
  • ✦ftrace is zero-cost when disabled: dynamic ftrace patches function preambles to nop instructions at boot. Enabling a trace dynamically patches them back — a live, atomic, no-reboot, no-recompile operation.
  • ✦Tracepoints are a stable kernel ABI; kernel function names are not. Build long-term observability tools on tracepoints, not raw kprobes, when stability matters.
  • ✦The observer effect is real: changing the observation tool changes the system behavior. strace is so slow it can cause timeouts. Match tool overhead to the sensitivity of what you're measuring.
  • ✦kprobes let you add printf-style debugging to any kernel function in a running production system without rebooting — this is one of the most powerful capabilities Linux exposes to kernel developers.
  • ✦Profiling without call graphs (-g flag in perf) is almost useless for real debugging. Always collect call graphs, even though the data is larger.

Common pitfalls

  • ⚠Running strace on a production server under load and wondering why everything slowed down — the ptrace overhead is enormous. Use 'strace -c -p PID' for a short summary window, then detach.
  • ⚠Forgetting -fno-omit-frame-pointer when compiling code you intend to profile with perf --call-graph=fp. The resulting profile shows only leaf functions with no call chains, making flame graphs useless.
  • ⚠Reading flame graph width as time from left to right. The X-axis is sorted alphabetically, not temporally. Left-to-right order tells you nothing about execution order.
  • ⚠Profiling a debug build (-O0) and then trying to optimize based on the results. The optimizer changes code structure dramatically; always profile the same optimization level you'll ship.
  • ⚠Using perf record with -F 1000 (1kHz) on a high-frequency interrupt path, creating profiling overhead that itself perturbs the system. 99Hz is usually sufficient and has negligible overhead.
  • ⚠Forgetting to clear the ftrace buffer between experiments ('echo > /sys/kernel/debug/tracing/trace'). Old trace data contaminates new measurements.
  • ⚠Interpreting strace's 'time spent' column as wall-clock time. It measures time inside the kernel syscall, not total process delay including userspace between syscalls.
  • ⚠Writing a kprobe that does expensive work (memory allocation, printk in a tight loop) on a high-frequency kernel path, causing latency spikes or even system hangs.

Practice

  1. 01
    easy

    Write a C program that opens a file, reads it in 1-byte chunks, and closes it. Run it with 'strace -c' and identify the dominant syscall. Then rewrite it to read in 4096-byte chunks and compare the strace -c output. Measure the wall-clock speedup with 'time'. Explain the relationship between syscall count and performance.

  2. 02
    easy

    Using perf stat -d, measure the cache-miss rate of two programs: (1) a row-major matrix traversal and (2) a column-major matrix traversal (use the cache_demo.c example from this module as a starting point). Use a 4096x4096 int matrix. Report the LLC-load-misses count and the IPC for each version. Then explain in one paragraph why the column-major version is slower in terms of CPU microarchitecture.

  3. 03
    medium

    Profile a real program with a known hot path: write a program that sorts 10 million integers using qsort(), then profiles it. Use 'perf record -F 99 -g' and generate a flame graph. Identify the top 3 functions by sample count. Then change qsort to a hand-written merge sort and compare the flame graphs. Are the hot functions the same?

  4. 04
    medium

    Use ftrace's function_graph tracer to trace what happens in the kernel when you call open('/tmp/testfile', O_RDONLY). Filter to 'do_sys_openat2' and 'vfs_*' functions. From the output, list every VFS function called in order and draw a call tree on paper. Then look up two of those functions in the kernel source at elixir.bootlin.com.

  5. 05
    hard

    Create an off-CPU flame graph that shows where a process spends time BLOCKED (not on CPU). Write a program with two threads: one that holds a mutex for 10ms, releases it for 1ms, in a loop. The other thread tries to acquire the mutex constantly. Use 'perf record -e sched:sched_switch -ag --call-graph=dwarf' to capture scheduler events, then generate a flame graph. The blocking should show up as wide flames rooted in futex_wait or pthread_mutex_lock.

  6. 06
    hard

    Write a kernel module that uses a kretprobe on 'vfs_read' to measure the distribution of return values (bytes read per call). Print a histogram to the kernel log when the module is unloaded. Load it, run 'cat /var/log/syslog', unload the module, and read dmesg to see the histogram. Bonus: modify it to only count reads from processes named 'cat'.

Resources

✎Brendan Gregg's perf Examples
articlefree

The single most comprehensive reference for perf usage in practice, with dozens of real examples. Brendan Gregg is the world authority on Linux performance tools.

✎Linux Flame Graphs
articlefree

The canonical introduction to flame graphs by their inventor, with explanations of all variants and links to the FlameGraph scripts.

📄ftrace - Function Tracer (kernel documentation)
docsfree

The official kernel documentation for ftrace, covering every available tracer and every sysfs knob. Authoritative and thorough.

📄kprobes Documentation
docsfree

Official kernel docs explaining kprobes internals, the API, and usage examples. Essential reading before writing a kprobe module.

📄strace man page
docsfree

Michael Kerrisk's man7.org has the most complete and readable Linux man pages. The strace page covers every flag with examples.

📕Systems Performance: Enterprise and the Cloud (2nd ed.)
bookpaidBrendan Gregg, Addison-Wesley, 2020

The definitive book on Linux performance analysis. Covers every tool in this module at expert depth, plus the USE/RED methodologies and hardware architecture context.

📕BPF Performance Tools
bookpaidBrendan Gregg, Addison-Wesley, 2019

The follow-up to Systems Performance focused on eBPF/BCC/bpftrace — the modern evolution of kprobes and tracepoints. Read after mastering this module.

✎LWN: An introduction to ftrace
articlefree

Steven Rostedt (ftrace's author) explaining how ftrace works from the inside. Unique insight into design decisions and implementation details.

✎Tracing the Linux Kernel — bootlin training slides
articlefree

Free slides from Bootlin's (Free Electrons) professional kernel debugging training. Covers ftrace, perf, and kprobes with lab exercises.

📄perf Tutorial — perf wiki
docsfree

The official perf tutorial maintained alongside the kernel. Good starting point for understanding perf_events concepts.

✎Linux Tracing Systems and How They Fit Together — Julia Evans
articlefree

An exceptionally clear conceptual map of the entire Linux tracing ecosystem — a great complement to this module for seeing how all the pieces connect.

✎Kernel function tracing with kprobes — LWN
articlefree

The original LWN article introducing kprobes when they were merged. Historical perspective and clear explanation of the mechanism.

Checkpoints — you can now…

  • ✓You can run 'strace -c' on any program and interpret the top 3 syscalls by time to explain why they dominate.
  • ✓You can compile a C program with -fno-omit-frame-pointer and produce a valid flame graph SVG using perf record and the FlameGraph scripts.
  • ✓You can use 'perf stat -d' output to distinguish between a memory-bound and a compute-bound program by looking at IPC and LLC-miss rate.
  • ✓You can enable a specific ftrace tracer (function_graph), filter it to a kernel subsystem, trigger an event, capture the trace, and explain the call tree in the output.
  • ✓You can list all available tracepoints on your system, enable one (e.g., sched:sched_switch), capture events from it, and explain each field in the output line.
  • ✓You can write a 'perf probe' command to attach a dynamic kprobe to a kernel function and record the value of one of its arguments.
  • ✓Given a performance complaint, you can articulate a structured diagnosis plan using the USE method — naming which resource to check first and which tool to use for each resource.