Linux bpftrace — Complete Learning Notes & Output Guide

bpftrace is a high-level tracing language for Linux extended Berkeley Packet Filters (eBPF). Inspired by awk, C, and ancestor tracers like DTrace and SystemTap, bpftrace lets you write compact, one-line or scripted probes to dissect kernel and user-space operations with negligible runtime overhead.

---

1. What is bpftrace?

Where BCC requires writing multi-line C code wrapped in Python boilerplate, and strace causes massive performance degradation through ptrace context switches, bpftrace provides an expressive, high-level domain-specific language (DSL).

It answers immediate operational questions:

• Which process is issuing slow synchronous writes to disk?
• What is the latency distribution of VFS reads or database queries?
• How many bytes are being read per process, system-wide?
• Which kernel functions are failing, and what error codes are they returning?
• What does the full kernel or user call stack look like when a specific lock is contested?

---

2. Installation

bpftrace requires root privileges (sudo or CAP_BPF / CAP_SYS_ADMIN) and a Linux kernel with eBPF enabled (Linux 4.9+ minimum, 5.4+ recommended).

Debian / Ubuntu

sudo apt update
sudo apt install bpftrace

RHEL / Rocky / AlmaLinux / CentOS

sudo dnf install bpftrace

Arch Linux

sudo pacman -S bpftrace

Verify:

bpftrace --version

---

3. Architecture & Probe Types

bpftrace compiles high-level scripts into eBPF bytecode in memory using LLVM, sends it to the kernel's eBPF verifier, and attaches to various instrumentation points.

               +-------------------------------------------+
               |             bpftrace Script               |
               |  kprobe:vfs_read { @[comm] = count(); }   |
               +-------------------------------------------+
                                     |
                                     v
               +-------------------------------------------+
               |        LLVM / bpftrace Compiler           |
               |           (AST -> BPF Bytecode)           |
               +-------------------------------------------+
                                     |
                                     | bpf(BPF_PROG_LOAD)
                                     v
+-------------------------------------------------------------------------+
|                              KERNEL SPACE                               |
|                                                                         |
|   +-----------------------------------------------------------------+   |
|   |                       In-Kernel Verifier                        |   |
|   +-----------------------------------------------------------------+   |
|                                    |                                    |
|                                    v                                    |
|   +-----------------------------------------------------------------+   |
|   |                      Attach Points                              |   |
|   |   * kprobe / kretprobe   (Dynamic kernel functions)             |   |
|   |   * tracepoint           (Static stable kernel tracepoints)     |   |
|   |   * uprobe / uretprobe   (User-space function entry/returns)    |   |
|   |   * usdt                 (User-level static trace markers)      |   |
|   |   * profile / interval   (Time-based sampling engines)          |   |
|   |   * software / hardware  (Kernel counters and CPU PMUs)         |   |
|   +-----------------------------------------------------------------+   |
|                                    |                                    |
|                                    v                                    |
|   +-----------------------------------------------------------------+   |
|   |         BPF Maps (Aggregations, Counts, Histograms)             |   |
|   +-----------------------------------------------------------------+   |
+-------------------------------------------------------------------------+

Core Probe Syntax

probe_type:probe_name [/filter/] { actions; }

• probe_type:probe_name: What event to intercept (e.g., tracepoint:syscalls:sys_enter_openat).
• /filter/: Optional conditional predicate (e.g., /pid == 1234/ or /comm == "python3"/).
• { actions; }: Code to execute when the probe fires (e.g., recording timestamps, updating maps).

---

4. Built-in Variables & Functions Cheat Sheet

Built-in Variables

Variable	Type	Description
pid	uint64	Process ID of the current thread (in the root namespace).
tid	uint64	Thread ID (LWP ID) of the current thread.
uid	uint64	User ID of the process.
comm	string	Process or command name (first 16 chars of task_struct->comm).
nsecs	uint64	Monotonic timestamp in nanoseconds since boot.
cpu	uint32	Logical CPU core ID running the probe.
kstack	string	Kernel call stack trace.
ustack	string	User-space call stack trace.
args	struct	Tracepoint arguments pointer (auto-populated for static tracepoints).
retval	int64	Return value of the probed function (valid only in kretprobe / uretprobe).

Core Aggregation Functions

Function	Purpose	Example
count()	Counts the number of times the probe fired.	@[comm] = count();
sum(n)	Accumulates the numeric value $n$.	@[comm] = sum(args->count);
avg(n)	Computes the running average of value $n$.	@[comm] = avg(args->count);
**min(n) / max(n)**	Records the minimum or maximum observed value.	@[comm] = max(nsecs - @start[tid]);
hist(n)	Creates an in-kernel power-of-2 logarithmic histogram.	@lat = hist(nsecs - @start[tid]);
lhist(n, min, max, step)	Creates a linear histogram within defined bounds.	@sizes = lhist(args->count, 0, 4096, 512);
delete(@map[key])	Removes an entry from a map to free memory.	delete(@start[tid]);
clear(@map)	Flushes all entries from a map.	clear(@start);
zero(@map)	Sets all values in a map to zero without deleting keys.	zero(@counts);

---

5. Understanding bpftrace Output Formats

---

5.1 Logarithmic Histogram Output: hist()

One of bpftrace's signature features is generating low-overhead, in-kernel latency distributions.

Example Probe: VFS Read Latency

sudo bpftrace -e '
kprobe:vfs_read {
    @start[tid] = nsecs;
}
kretprobe:vfs_read /@start[tid]/ {
    @latency_us = hist((nsecs - @start[tid]) / 1000);
    delete(@start[tid]);
}'

Raw Output

Attaching 2 probes...
^C

@latency_us: 
[0, 1]              1042 |****************************************|
[2, 3]               312 |************                            |
[4, 7]                84 |***                                     |
[8, 15]               19 |                                        |
[16, 31]               5 |                                        |
[32, 63]               2 |                                        |
[64, 127]              0 |                                        |
[128, 255]             1 |                                        |

Detailed Breakdown of the Histogram

+--------------+---------+------------------------------------------+
| Bucket Range | Count   | ASCII Distribution Bar                   |
+--------------+---------+------------------------------------------+
| [0, 1]       | 1042    | |****************************************| |
+--------------+---------+------------------------------------------+

• Bucket Range ([0, 1], [4, 7]): The range of observed values (in this case, microseconds). Each bucket doubles in size (power of 2), bounding measurements from zero to infinity without allocating dynamic arrays.
• Count (1042, 312): The total number of events that fell within that exact interval.
• ASCII Distribution Bar: A visual indicator normalized against the largest bucket (1042 = 100% of the bar width).
• Diagnostic Interpretation: A healthy read cache clusters heavily in [0, 1] or [2, 3] $\mu\text{s}$. The single read in [128, 255] $\mu\text{s}$ reveals an outlier—a disk seek or block cache miss.

---

5.2 Multi-Key Map Output

Maps in bpftrace can use multiple keys (tuples) to correlate operations across processes, system calls, or filenames:

Example Probe: System Calls by Process and Error Code

sudo bpftrace -e '
tracepoint:raw_syscalls:sys_exit /args->ret < 0/ {
    @[comm, -args->ret] = count();
}'

Raw Output

Attaching 1 probe...
^C

@[cat, 2]: 1
@[git, 2]: 4
@[nginx, 11]: 82
@[python3, 2]: 14
@[python3, 13]: 3

Detailed Breakdown of Map Fields

• comm (cat, nginx, python3): The process name triggering the failing syscall.
• -args->ret (2, 11, 13): The absolute value of the returned negative errno integer:
• 2 = ENOENT (No such file or directory)
• 11 = EAGAIN / EWOULDBLOCK (Resource temporarily unavailable; typical in non-blocking event loops)

• 13 = EACCES (Permission denied)

• Value (1, 82, 14): Number of times that specific process failed with that specific error code.

• Diagnostic Interpretation: nginx has 82 non-blocking poll misses (EAGAIN), which is normal. python3 has 3 permission denied (EACCES) errors, pointing to a configuration or file permissions issue.

---

5.3 Live Streaming Output: printf()

bpftrace supports formatted printing to inspect events as they happen:

Example Probe: Real-time Block I/O Size Monitoring

sudo bpftrace -e '
tracepoint:block:block_rq_issue {
    printf("%-8d %-16s %-6s %llu bytes\n", pid, comm, args->rwbs, args->bytes);
}'

Raw Output

Attaching 1 probe...
4512     python3          W      4096 bytes
4512     python3          W      8192 bytes
1420     dockerd          R      16384 bytes
891      jbd2/sda2-8      WS     4096 bytes

Detailed Breakdown of Fields

• 4512: Process ID issuing the I/O.
• python3: The command name.
• **W / R / WS**: Block I/O flags (W = Write, R = Read, WS = Synchronous Write / Journal flush).
• bytes: The raw size of the requested block I/O operation.

---

6. Essential bpftrace Diagnostic One-Liners

These production-ready one-liners diagnose common system performance problems:

1. Count System Calls by Process

sudo bpftrace -e 'tracepoint:raw_syscalls:sys_enter { @[comm] = count(); }'

2. Read Throughput (Bytes) by Process

sudo bpftrace -e 'tracepoint:syscalls:sys_exit_read /args->ret > 0/ { @[comm] = sum(args->ret); }'

3. Trace Process Execution (execve) with Arguments

sudo bpftrace -e 'tracepoint:syscalls:sys_enter_execve { join(args->argv); }'

4. Disk Latency (ms) by Process Name

sudo bpftrace -e '
tracepoint:block:block_rq_issue { @start[args->dev, args->sector] = nsecs; }
tracepoint:block:block_rq_complete /@start[args->dev, args->sector]/ {
    @[comm] = hist((nsecs - @start[args->dev, args->sector]) / 1000000);
    delete(@start[args->dev, args->sector]);
}'

5. Profile On-CPU Stack Traces at 99 Hertz

sudo bpftrace -e 'profile:hz:99 { @[kstack] = count(); }'

6. Detect Who is Sending Signals (e.g., SIGKILL, SIGTERM)

sudo bpftrace -e '
tracepoint:syscalls:sys_enter_kill {
    printf("PID %d (%s) sent signal %d to PID %d\n", pid, comm, args->sig, args->pid);
}'

---

7. Writing Multi-Line bpftrace Scripts

For complex tracing, write scripts in standalone .bt files with an executable shebang:

File: tcp_connect_latency.bt

#!/usr/bin/env bpftrace

#include <net/sock.h>
#include <linux/tcp.h>

BEGIN {
    printf("Tracing outbound TCP connect latency... Hit Ctrl-C to end.\n");
    printf("%-8s %-16s %-15s %-5s %s\n", "PID", "COMM", "RADDR", "RPORT", "LAT(ms)");
}

kprobe:tcp_v4_connect {
    @start[tid] = nsecs;
    $sk = (struct sock *)arg0;
    @sock[tid] = $sk;
}

kretprobe:tcp_v4_connect /@start[tid]/ {
    $dur = (nsecs - @start[tid]) / 1000000;
    $sk = @sock[tid];
    $daddr = ntop($sk->__sk_common.skc_daddr);
    $dport = bswap($sk->__sk_common.skc_dport);

    if ($dur > 10) { // Filter: highlight connections taking longer than 10ms
        printf("%-8d %-16s %-15s %-5d %llu\n", pid, comm, $daddr, $dport, $dur);
    }

    delete(@start[tid]);
    delete(@sock[tid]);
}

END {
    clear(@start);
    clear(@sock);
    printf("Tracing ended.\n");
}

Run it directly:

sudo chmod +x tcp_connect_latency.bt
sudo ./tcp_connect_latency.bt

---

8. Listing and Inspecting Probes

To discover available probe points and their arguments on your system:

Search for Available Tracepoints

bpftrace -l 'tracepoint:syscalls:sys_enter_*'
bpftrace -l 'tracepoint:block:*'

Inspect Tracepoint Arguments Struct

bpftrace -lv 'tracepoint:syscalls:sys_enter_openat'

Output:

tracepoint:syscalls:sys_enter_openat
    int __syscall_nr
    int dfd
    const char * filename
    int flags
    umode_t mode

(These field names can be accessed directly in your scripts via args->filename, args->flags, etc.)

---

9. bpftrace vs. BCC vs. strace vs. perf

Dimension	bpftrace	BCC	strace	perf
Language	Custom awk-like DSL	Python + inline C	Standard CLI flags	Standard CLI / scripting
Overhead	Very Low	Low	Very High ($10\times-100\times$)	Low
Primary Use Case	Fast ad-hoc troubleshooting, one-liners	Complex agents, multi-map tools	Tracing user/kernel syscall boundary	Hardware counters, CPU sampling
Kernel Compilation	JIT via LLVM in memory	JIT via LLVM in memory	None (uses ptrace)	Kernel-native
Histograms in Kernel	Yes (hist(), lhist())	Yes	No	No
Safe for Production	Yes	Yes	No (high overhead on busy nodes)	Yes

---

10. Important Interview Questions & Answers

Q: Why is delete(@map[key]) critical when measuring latency in kretprobe?

Answer: When calculating latency, an entry is created in an eBPF associative map on function entry (kprobe) using the Thread ID (tid) as the key and the current timestamp (nsecs) as the value. On function exit (kretprobe), the duration is calculated. If you do not explicitly delete the entry via delete(@start[tid]), the map will continuously grow in kernel memory with stale threads, eventually running out of allocated map entries and leaking memory.

Q: Why is tid used as the key for timing maps instead of pid?

Answer: In Linux, pid represents the thread group ID (the process ID), while tid represents the individual thread ID (the task's unique Kernel LWP ID). In a multi-threaded application, multiple threads execute functions concurrently within the same process. Using pid would cause threads of the same process to overwrite each other's timestamps in the timing map, corrupting the latency calculations. tid guarantees thread isolation.

Q: What are the differences between a tracepoint and a kprobe in bpftrace?

Answer:

• tracepoint: A static trace marker placed explicitly in the Linux kernel source code by kernel developers. Tracepoints have stable APIs across kernel releases, well-documented argument structures, and minimal overhead.
• kprobe: A dynamic probe that can attach to almost any arbitrary instruction or function entry point inside the compiled kernel. Kprobes are not guaranteed to be stable across kernel versions (function names, arguments, and inlining can change), but they allow you to inspect private or uninstrumented kernel functions where no static tracepoints exist.

---