Powernews Monday, 17 August 2026 at 19:07 CEST
UNIX COMMAND OF THE DAY

Bpftrace: Instrumenting Kernel Probes, Analyzing eBPF Tracepoints, and Diagnosing Production Latency in Real Time

It is twenty-three minutes past two in the morning, and the piercing siren of an automated paging alert has just shattered your sleep. You stagger to your desk, squinting through the gloom at a monitor flooded with crimson status banners: your company's core database cluster is grinding to a halt, and response times have exploded from a crisp four milliseconds to several agonising seconds. In the incident channel, messages are multiplying by the second, but when you open your terminal, the machine presents an infuriating picture of calm.
Key Takeaway
Essential takeaway summary for Bpftrace: Instrumenting Kernel Probes, Analyzing eBPF Tracepoints, and Diagnosing Production Latency in Real Time.

The CPU utilisation metric sits peacefully at forty per cent, memory usage is well within bounds, and standard disk dashboards report nothing out of the ordinary. Everything looks deceptively healthy on the surface, yet the service is practically dead in the water.

In moments like this, reaching for traditional diagnostic tools feels like playing Russian roulette. Running a utility like strace against a heavily loaded production database can easily freeze running threads under high concurrency, turning a bad slowdown into an outright outage. Meanwhile, old faithfuls like top, vmstat, and iostat only offer coarse, multi-second averagesβ€”blunt instruments that smooth away the brief microsecond hiccups where system bottlenecks actually lurk.

To fix the issue without bringing down the servers, you need a way to look directly into the engine room of the operating system. You need to watch functions execute, track disk requests, and observe network packets in real time, with zero perceptible impact on performance. This is the domain of bpftrace.

If you find yourself on an unfamiliar machine needing an immediate snapshot of what is keeping the kernel busy, the single most practical diagnostic you can run is a one-line audit of all active system calls:

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

Within five seconds, bpftrace interrogates the kernel and prints a tidy tally of which programs are demanding operating system resources:

Attaching 2 probes...

@[systemd-journal]: 14
@[dockerd]: 38
@[node]: 112
@[postgres]: 849
@[envoy]: 14205
@[redis-server]: 32180

By aggregating metrics directly inside kernel memory and returning only the final summary to your screen, this single command instantly exposes whether a proxy, a cache, or a database worker is dominating system activityβ€”without flooding your terminal or slowing down user requests.


WHAT IT DOES IN PLAIN ENGLISH

At its core, bpftrace is a specialised diagnostic tool and mini-programming language designed to give engineers real-time X-ray vision into running Linux systems.

Rather than modifying source code, restarting services, or attaching invasive debuggers, bpftrace lets you write concise, one-line scripts that attach temporary sensors ("probes") to almost anything happening inside the operating system. It can track when files open, measure how long individual hard drive reads take, catch network packets as they leave an interface, or follow function calls inside user applications.

What makes bpftrace revolutionary is efficiency. Older tracing programs stream every single event across the boundary between the kernel and user programs, which can quickly saturate memory buses and choke system performance. bpftrace compiles your instructions into lightweight, sandboxed mini-programs that run directly inside the Linux kernel. It maintains counts, timers, and histograms in kernel memory, delivering clean, actionable summaries straight to your terminal with negligible overhead.


THE KERNEL ARCHITECTURE OF EBPF AND BPFTRACE

To understand how bpftrace achieves this combination of speed and safety, one must look at its underlying foundation: the extended Berkeley Packet Filter (eBPF) subsystem of the modern Linux kernel, documented extensively within the Linux kernel eBPF documentation and accessed via the man7 bpf(2) manual page.

flowchart TD subgraph UserSpace ["User Space"] Script["bpftrace Script (.bt / -e)"] Parser["Flex/Bison AST & Clang Frontend"] LLVM_IR["LLVM Intermediate Representation (IR)"] Bytecode["eBPF Bytecode Instructions"] Printer["Map Aggregation & Terminal Output"] end subgraph KernelSpace ["Kernel Space"] Syscall["sys_bpf(BPF_PROG_LOAD)"] Verifier["BPF Verifier\n- DAG depth & loop checks\n- Register type state validation\n- Memory & pointer boundary rules"] JIT["In-Kernel JIT Compiler\n(Native x86_64 / ARM64 Machine Code)"] Probes["Instrumentation Attach Points\n(kprobe / tracepoint / uprobe / usdt)"] Maps["eBPF In-Kernel Associative Maps\n(Log2 Histograms, Counters, Hash Arrays)"] end Script --> Parser Parser --> LLVM_IR LLVM_IR --> Bytecode Bytecode -->|sys_bpf| Syscall Syscall --> Verifier Verifier -->|Validation Passed| JIT JIT --> Probes Probes -->|In-Kernel Aggregations| Maps Maps -->|Periodic Interval / Script Exit| Printer

The In-Kernel Virtual Machine and JIT Compilation

At the heart of eBPF is a register-based virtual machine operating directly inside kernel memory space. It provides eleven 64-bit virtual registers: - R0: Stores return values from helper routines and exits. - R1 through R5: Function argument registers. - R6 through R9: Callee-saved registers preserved across helper calls. - R10: A read-only frame pointer for accessing the 512-byte fixed stack frame.

When you pass a script to bpftrace, the tool parses the syntax, constructs an Abstract Syntax Tree, generates LLVM Intermediate Representation, and compiles it into an array of 64-bit RISC-style instructions. These instructions are handed to the kernel via the bpf(2) system call using the BPF_PROG_LOAD command.

Once received, the kernel's Just-In-Time (JIT) compiler translates the bytecode into native machine instructions for the host architecture (such as x86_64 or ARM64). This eliminates interpretive lag and allows probes to fire in just a few nanoseconds.

The BPF Verifier Safety Model

Running custom code inside ring-0 kernel space sounds inherently dangerous. Linux prevents crashes and panics through the BPF Verifier. Before any program is compiled into machine instructions, the verifier runs a strict static analysis, building a directed acyclic graph (DAG) of every single possible execution path. It strictly enforces four fundamental rules:

  1. Guaranteed Termination: Infinite loops are forbidden. While bounded loops are supported on modern kernels, the verifier must mathematically verify that execution finishes within a hard instruction budget.
  2. Memory Boundaries: Programs cannot access arbitrary memory addresses. The stack is restricted to the 512 bytes assigned to R10. Reading kernel or user memory is strictly brokered through safe helpers or validated pointer types.
  3. Type and State Tracking: Every instruction must maintain valid register states. A scalar number cannot be treated as a pointer, and uninitialised memory cannot be read.
  4. Context Safety: A probe attached to a high-priority interrupt or scheduler tick is barred from calling blocking operations or sleeping memory allocations.

If any branch of your script fails these checks, the kernel immediately rejects the program with an error code, protecting the operating system against lockups, data corruption, or crashes.

Probe Types and Instrumentation Hooks

bpftrace brings diverse kernel and user-space tracing mechanisms under a single unified syntax:

  • Dynamic Kernel Probes (kprobe and kretprobe): Described in the Linux kernel kprobes documentation, dynamic probes hook into virtually any kernel function at runtime. A kprobe attaches to the entry of a function (such as tcp_retransmit_skb), while a kretprobe catches the return value and measures elapsed time. The kernel dynamically patches target instructions with temporary breakpoint traps or ftrace trampolines.
  • Kernel Tracepoints (tracepoint): Documented in the Linux kernel Tracepoints documentation, tracepoints are permanent markers placed directly into the kernel source code by Linux subsystem maintainers (such as tracepoint:sched:sched_process_exec). They have stable interfaces across Linux releases and carry negligible overhead when inactive.
  • User-Space Dynamic Probes (uprobe and uretprobe): The user-space equivalent of dynamic probes. The kernel instruments application binaries or shared libraries in memory (such as libssl.so) by replacing target instructions with breakpoint traps. When application code hits the breakpoint, control briefly passes to the kernel to run the eBPF probe before returning to user execution.
  • User Statically-Defined Tracing (usdt): Predefined tracepoints embedded into user applications (such as PostgreSQL, MySQL, or Node.js) using ELF notes. USDT probes provide meaningful application-level context without requiring runtime symbol reconstruction.

In-Kernel Associative Maps and High-Throughput Aggregations

Traditional tracing tools can easily drown a machine by transmitting every event to user space. bpftrace solves this through in-kernel aggregation.

Using built-in data structuresβ€”such as hash tables, arrays, and per-CPU buffersβ€”bpftrace computes running statistics directly within kernel memory: - @count() increments an in-kernel counter. - @hist(value) sorts values into power-of-two logarithmic frequency buckets. - @stats(value) calculates counts, totals, averages, and variance using atomic arithmetic.

When the trace finishes or a timer ticks, bpftrace reads the pre-aggregated results from the kernel and prints a clean summary table or histogram, reducing data transfer and system overhead by orders of magnitude.

Performance Profile: bpftrace vs. strace vs. perf

Choosing the right diagnostic tool comes down to understanding the performance trade-offs:

Characteristic strace perf bpftrace
Primary Mechanism man7 ptrace(2) process interception Hardware performance counters, static tracepoints, sampling eBPF bytecode compiled and executed directly in-kernel
Context Switch Overhead Extreme: multiple context switches for every system call Negligible to moderate depending on sampling frequency Negligible: executes in-place within the event context
Production Feasibility Dangerous for busy production services Safe for general sampling and performance counting Safe for high-frequency tracing with bounded in-kernel maps
Programmability None (fixed output format) Complex syntax; scriptable via external Python/Perl Expressive and flexible via a C/AWK-style scripting language
In-Kernel Aggregation None: streams all raw data to user space Limited: counts events or dumps stacks into ring buffers Comprehensive: custom hash tables, histograms, and string parsing
Safety Guarantees Halts running threads; risks application timeouts Safe sampling, but deep filtering requires user-space processing Verified and enforced by the in-kernel BPF Verifier

CORE FLAGS & QUICK START

The syntax of bpftrace follows an intuitive pattern inspired by AWK and C: probe_specifier /predicate/ { action }. Full language specifications and syntax guides are maintained in the bpftrace GitHub Reference Guide and the ArchWiki BPF documentation.

Primary Invocation Flags

  • -e 'program': Compiles and executes an inline script passed directly on the command line.
  • -l [search_string]: Lists all available probes matching a wildcard pattern (e.g. bpftrace -l '*tcp*').
  • -c 'command': Spawns a command as a child process and runs the trace only while that command executes.
  • -p PID: Attaches probes dynamically to a specific running process ID.
  • -d: Dry-run mode; displays the generated LLVM Intermediate Representation and bytecode without running it in the kernel.
  • -v: Verbose mode; shows the verifier log and internal map layout.
  • -B MODE: Sets output buffering (none, line, or full), useful when piping results to log collectors.
  • --unsafe: Permits dangerous operations, such as modifying kernel variables or running shell commands with system().

5 REAL-WORLD PRODUCTION USE CASES


USE CASE 1: Measuring Block I/O Latency Distributions to Isolate Slow Storage Drives

Scenario

A high-throughput database node begins experiencing intermittent query timeouts. Standard monitoring via iostat -x 1 reports an average read latency of 1.2 milliseconds, which looks perfectly healthy. Yet database logs confirm that certain transactions are pausing for several seconds. The admin suspects that an individual NVMe drive is stalling intermittentlyβ€”a tail-latency issue completely masked by the arithmetic average in iostat.

Production Script

To inspect the latency distribution of every single disk operation across storage controllers, the admin runs:

sudo bpftrace -e '
tracepoint:block:block_rq_issue {
    @start[args->dev, args->sector] = nsecs;
}

tracepoint:block:block_rq_complete {
    $start = @start[args->dev, args->sector];
    if ($start != 0) {
        $lat_ms = (nsecs - $start) / 1000000;
        @io_latency_ms[args->dev] = hist($lat_ms);
        delete(@start[args->dev, args->sector]);
    }
}

interval:s:10 {
    exit();
}'

Realistic Terminal Output

Attaching 3 probes...

@io_latency_ms[8388608]: 
[0]                 1240 |@@@@@@@@@@@@@@@@@@@@                               |
[1]                 3109 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ |
[2, 4)               412 |@@@@@@                                             |
[4, 8)                48 |                                                   |
[8, 16)                2 |                                                   |

@io_latency_ms[8388624]: 
[0]                  890 |@@@@@@@@@@@@@@@@@@@@@@@@@@                         |
[1]                 1740 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ |
[2, 4)               112 |@@@                                                |
[4, 8)                14 |                                                   |
[8, 16)                0 |                                                   |
[16, 32)               0 |                                                   |
[32, 64)               1 |                                                   |
[64, 128)              3 |                                                   |
[128, 256)             8 |                                                   |
[256, 512)            24 |                                                   |
[512, 1024)           62 |@                                                  |
[1024, 2048)         184 |@@@@@                                              |
[2048, 4096)          42 |@                                                  |

Line-by-Line Breakdown of Output and Logic

  • tracepoint:block:block_rq_issue: Triggers whenever a block I/O request is submitted to the underlying device driver queue.
  • @start[args->dev, args->sector] = nsecs;: Records the start time in nanoseconds, stored in an associative map indexed by device number (dev) and disk sector (sector).
  • tracepoint:block:block_rq_complete: Triggers when the physical drive completes the request and issues a hardware interrupt.
  • $lat_ms = (nsecs - $start) / 1000000;: Calculates the elapsed duration in milliseconds.
  • @io_latency_ms[args->dev] = hist($lat_ms);: Groups the result into a logarithmic histogram bucket keyed by device number (8388608 corresponds to major/minor 8:0 for /dev/sda; 8388624 corresponds to 8:16 for /dev/sdb).
  • delete(@start[args->dev, args->sector]);: Immediately frees the entry from the map to keep memory usage minimal.
  • In the output for device 8388624 (/dev/sdb), while most operations complete within 1–2 milliseconds, 288 operations stalled between 512ms and 4096ms (over 4 seconds).

Actionable Remediation

The administrator maps device identifier 8388624 to /dev/sdb using lsblk. They immediately flag /dev/sdb as degraded in the storage array, remove the host from active cluster traffic, and arrange a clean hot-swap of the failing drive.


USE CASE 2: Tracing Ephemeral Process Storms and Short-Lived Command Executions

Scenario

A Kubernetes node experiences recurring CPU spikes. Every two minutes, CPU load surges to 100% for twenty seconds. Standard monitoring tools like top and pidstat 1 show nothing unusual because the processes responsible are short-lived utility commands that start, do work, and exit in under 50 milliseconds. The admin needs to record every single program execution as it happens.

Production Script

To catch short-lived binaries without missing a single invocation, the admin taps the scheduler's process execution tracepoint:

sudo bpftrace -e '
tracepoint:sched:sched_process_exec {
    time("%H:%M:%S ");
    printf("PPID=%-6d PID=%-6d COMM=%-16s FILE=%s\n", 
           curtask->real_parent->tgid, 
           curtask->tgid, 
           comm, 
           str(args->filename));
}'

Realistic Terminal Output

Attaching 1 probe...
02:35:10 PPID=1204   PID=893402 COMM=bash             FILE=/usr/bin/bash
02:35:10 PPID=893402 PID=893403 COMM=collect_metrics FILE=/opt/vendor/agent/bin/collect_metrics.sh
02:35:10 PPID=893403 PID=893404 COMM=grep            FILE=/usr/bin/grep
02:35:10 PPID=893403 PID=893405 COMM=awk             FILE=/usr/bin/awk
02:35:10 PPID=893403 PID=893406 COMM=sed             FILE=/usr/bin/sed
02:35:10 PPID=893403 PID=893407 COMM=cut             FILE=/usr/bin/cut
02:35:10 PPID=893403 PID=893408 COMM=cat             FILE=/usr/bin/cat
02:35:10 PPID=893403 PID=893409 COMM=grep            FILE=/usr/bin/grep
02:35:10 PPID=893403 PID=893410 COMM=awk             FILE=/usr/bin/awk
02:35:10 PPID=893403 PID=893411 COMM=tr              FILE=/usr/bin/tr

Line-by-Line Breakdown of Output and Logic

  • tracepoint:sched:sched_process_exec: Hooks into the kernel scheduler whenever an execve() or execveat() system call executes.
  • curtask->real_parent->tgid: Follows the task structure of the current kernel thread to retrieve the parent process ID.
  • str(args->filename): Reads the binary path argument from the tracepoint and copies the string safely to user space.
  • The output immediately reveals that a monitoring script (PID 893403, /opt/vendor/agent/bin/collect_metrics.sh) is spawning dozens of individual shell utilities (grep, awk, sed, cut, cat, tr) multiple times a second, triggering an expensive storm of process forks that drains the CPU.

Actionable Remediation

The administrator edits the monitoring script to use built-in shell features or replaces it with a compiled binary collector, instantly dropping idle CPU utilisation from 100% to under 3%.


USE CASE 3: Triaging TCP Retransmissions with In-Kernel Socket and Process Attribution

Scenario

A microservices deployment reports intermittent HTTP 504 Gateway Timeouts between internal microservices. Hardware switch telemetry indicates clean physical connections with zero dropped packets. The administrator must find out which specific network connections are dropping packets, the destination IP and port combinations, and which applications are responsible.

Production Script

The admin instruments the kernel TCP layer using kprobe:tcp_retransmit_skb, pulling connection metadata directly from the kernel socket structures:

sudo bpftrace -e '
#include <net/sock.h>
#include <linux/skbuff.h>
#include <linux/tcp.h>

kprobe:tcp_retransmit_skb
{
    $sk = (struct sock *)arg0;
    $inet = (struct inet_sock *)arg0;

    $daddr = $sk->__sk_common.skc_daddr;
    $saddr = $sk->__sk_common.skc_rcv_saddr;
    $dport = $sk->__sk_common.skc_dport;
    $sport = $inet->inet_sport;

    // Convert network byte order (big endian) to host byte order
    $dport_host = ($dport >> 8) | (($dport & 0xff) << 8);
    $sport_host = ($sport >> 8) | (($sport & 0xff) << 8);

    printf("%-8s %-16s %-6d %15s:%-5d -> %15s:%-5d\n",
           strftime("%H:%M:%S", nsecs),
           comm, 
           pid, 
           ntop(2, $saddr), 
           $sport_host, 
           ntop(2, $daddr), 
           $dport_host);
}'

Realistic Terminal Output

Attaching 1 probe...
02:41:01 envoy            41029   10.244.3.15:44321 ->    10.244.8.92:8080 
02:41:01 envoy            41029   10.244.3.15:44321 ->    10.244.8.92:8080 
02:41:02 grpc_client      41890   10.244.3.15:52110 ->   10.244.12.44:9000 
02:41:02 envoy            41029   10.244.3.15:44321 ->    10.244.8.92:8080 
02:41:03 envoy            41029   10.244.3.15:44321 ->    10.244.8.92:8080 

Line-by-Line Breakdown of Output and Logic

  • kprobe:tcp_retransmit_skb: Intercepts the kernel routine responsible for re-sending an unacknowledged TCP buffer (sk_buff).
  • $sk = (struct sock *)arg0;: Casts the first function argument (arg0) to the kernel socket structure.
  • $daddr / $saddr: Extracts destination and source IPv4 addresses from the connection struct.
  • ntop(2, $saddr): Formats the raw 32-bit IPv4 address into standard dot-decimal notation.
  • ($dport >> 8) | (($dport & 0xff) << 8): Converts network byte order (Big Endian) to standard host format.
  • The output pinpoints that envoy (PID 41029) is repeatedly timing out on connections to destination 10.244.8.92:8080.

Actionable Remediation

The administrator identifies 10.244.8.92 as an authentication pod hosted on worker node 8. Logging into node 8 reveals that its connection tracking table (conntrack) has overflowed, causing the kernel to drop new packets silently. Increasing net.netfilter.nf_conntrack_max via sysctl eliminates the packet loss.


USE CASE 4: Measuring Off-CPU Scheduler Wait Latency to Diagnose Thread Starvation

Scenario

A high-performance C++ payment application suffers from throughput drops during peak hours. Total CPU utilisation remains low at 25%, but processing times are unacceptably high. The development team suspects worker threads are getting stuck waiting for mutex locks (spending time "off-CPU"), but standard profilers like perf record only capture active on-CPU execution.

Production Script

The engineer runs an off-CPU latency script that measures how long threads spend descheduled before the kernel assigns them back to a CPU core:

sudo bpftrace -e '
#include <linux/sched.h>

tracepoint:sched:sched_switch
{
    $prev_pid = args->prev_pid;
    @offcpu_start[$prev_pid] = nsecs;

    $next_pid = args->next_pid;
    $start = @offcpu_start[$next_pid];

    if ($start != 0) {
        $duration_us = (nsecs - $start) / 1000;

        if (args->next_comm == "payment_engine") {
            @offcpu_latency_us[args->next_comm] = hist($duration_us);
            @offcpu_stack[kstack(), ustack(), args->next_comm] = count();
        }
        delete(@offcpu_start[$next_pid]);
    }
}

interval:s:10 {
    exit();
}'

Realistic Terminal Output

Attaching 2 probes...

@offcpu_latency_us[payment_engine]: 
[1]                  520 |@@@@@@@@@@@@                                       |
[2, 4)              1410 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@                   |
[4, 8)              2204 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ |
[8, 16)              310 |@@@@@@@                                            |
[16, 32)              42 |                                                   |
[32, 64)               2 |                                                   |
...
[16384, 32768)        89 |@@                                                 |
[32768, 65536)       450 |@@@@@@@@@@                                         |
[65536, 131072)      128 |@@@                                                |

@offcpu_stack[
    __schedule+0x2d0
    schedule+0x44
    futex_wait_queue_me+0xb8
    futex_wait+0x120
    do_futex+0x165
    __x64_sys_futex+0x8a
    do_syscall_64+0x5b
    entry_SYSCALL_64_after_hwframe+0x65
    __pthread_mutex_lock+0x80
    Queue::Pop(Transaction&)+0x24
    WorkerThread::ProcessEvents()+0x5a
    payment_engine
]: 667

Line-by-Line Breakdown of Output and Logic

  • tracepoint:sched:sched_switch: Fires whenever the kernel context-switches one task out for another on any CPU core.
  • @offcpu_start[$prev_pid] = nsecs;: Records the timestamp when a thread relinquishes the CPU.
  • $duration_us = (nsecs - $start) / 1000;: Computes how many microseconds the arriving thread spent waiting to be scheduled.
  • @offcpu_stack[kstack(), ustack(), args->next_comm]: Captures both the kernel call stack (kstack) and application call stack (ustack) associated with the wait.
  • The histogram reveals that over 660 thread invocations spent between 32 and 131 milliseconds waiting off-CPU.
  • The stack trace proves this time was spent inside Queue::Pop calling __pthread_mutex_lock via sys_futex, uncovering severe lock contention across worker threads.

Actionable Remediation

The development team refactors the shared transaction queue into a lock-free ring buffer architecture, eliminating futex contention and restoring full throughput.


USE CASE 5: Auditing Decrypted TLS Request Payloads and Latency via User-Space Probes (uprobe)

Scenario

An NGINX reverse proxy terminates incoming TLSv1.3 traffic and forwards requests to backend services. A small percentage of customer requests are failing with malformed errors, but backend logs show nothing. Because modern TLS uses Ephemeral Diffie-Hellman encryption, packet captures via tcpdump show only encrypted noise. The engineer must inspect the unencrypted HTTP traffic at the OpenSSL boundary inside memory without restarting the proxy.

Production Script

The engineer attaches probes to SSL_read and SSL_write inside the shared libssl.so library:

sudo bpftrace -e '
uretprobe:/usr/lib/x86_64-linux-gnu/libssl.so.3:SSL_read
/retval > 0/
{
    $buf = arg0;
    $len = retval;

    printf("%s [PID:%d] SSL_read (%d bytes):\n", 
           strftime("%H:%M:%S", nsecs), 
           pid, 
           $len);

    printf("%s\n\n", str(arg0, 64));
}

uprobe:/usr/lib/x86_64-linux-gnu/libssl.so.3:SSL_write
{
    @start_ssl_write[tid] = nsecs;
}

uretprobe:/usr/lib/x86_64-linux-gnu/libssl.so.3:SSL_write
/@start_ssl_write[tid]/
{
    $duration_us = (nsecs - @start_ssl_write[tid]) / 1000;
    @ssl_write_latency_us = hist($duration_us);
    delete(@start_ssl_write[tid]);
}'

Realistic Terminal Output

Attaching 3 probes...
02:50:14 [PID:18204] SSL_read (142 bytes):
POST /v1/auth/token HTTP/1.1
Host: api.enterprise.internal
Content-

02:50:15 [PID:18204] SSL_read (89 bytes):
GET /healthz HTTP/1.1
Host: api.enterprise.internal
User-Agent: Kube-

02:50:15 [PID:18205] SSL_read (210 bytes):
POST /v1/orders HTTP/1.1
Host: api.enterprise.internal
X-Invalid-Header: \x00\xFF\xAA\xBB

@ssl_write_latency_us: 
[2, 4)               890 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@                     |
[4, 8)              1450 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ |
[8, 16)              120 |@@@@                                               |
[16, 32)               8 |                                                   |

Line-by-Line Breakdown of Output and Logic

  • uretprobe:...:SSL_read: Intercepts the return of SSL_read in the OpenSSL library when unencrypted bytes become available.
  • /retval > 0/: Ensures the probe only executes when valid data has been decoded.
  • str(arg0, 64): Safely reads the first 64 bytes of the plaintext memory buffer.
  • The output captures a malformed request on worker process 18205 containing raw binary escape characters in an HTTP header (X-Invalid-Header: \x00\xFF\xAA\xBB), causing NGINX to abort the connection with a 400 Bad Request before forwarding it.

Actionable Remediation

The administrator traces the header back to an outdated internal testing client that was sending unescaped bytes, immediately fixing the client library to resolve the dropouts.


WHAT CAN GO WRONG: COMMON PITFALLS & SAFEGUARDS

While the in-kernel verifier ensures that bpftrace scripts cannot crash your operating system, improper tracing in high-throughput environments can still cause performance friction if not managed carefully.

flowchart LR subgraph Hazards ["Common Production Pitfalls & Defences"] A["Trap-Based Uprobes on Hot Loops"] -->|Risk| B["High Context-Switch Overhead"] A -->|Safeguard| C["Instrument high-level entry points & rate-check"] D["Unbounded Map Allocations"] -->|Risk| E["Kernel Memory Exhaustion"] D -->|Safeguard| F["Match insertions with explicit delete()"] G["Kernel Struct Layout Drift"] -->|Risk| H["Compilation & Type Failures"] G -->|Safeguard| I["Use stable Tracepoints & enable BTF"] end

1. High Overhead from User-Space Dynamic Probing (uprobe) on Hot Loops

  • The Risk: Unlike kernel tracepoints, uprobes modify process memory by inserting software breakpoint instructions. Every single execution requires a double context switch: trapping from user space into kernel space to run the probe, and returning to user space. Placing a uprobe inside a function called millions of times per second (such as an inlined memory allocator or character comparison loop) can degrade application throughput by 50% to 90%.
  • The Safeguard: Restrict uprobes to high-level transaction boundaries (such as request entry points or connection handshakes). Always verify execution frequency first with a simple counting probe: bash sudo bpftrace -e 'uprobe:/path/to/binary:target_func { @calls = count(); } interval:s:1 { print(@calls); clear(@calls); }' If @calls exceeds 50,000 events per second per core, avoid payload inspection with uprobes.

2. Map Memory Exhaustion and Kernel Slab Depletion

  • The Risk: Recording state without cleaning up keys can exhaust kernel memory. In Use Case 1, timestamps are saved in @start[args->dev, args->sector]. If a disk request is initiated but cancelled or completed on an untracked code path, that key remains stored in kernel RAM indefinitely. Over time, the map can hit its size limits and silently drop new entries.
  • The Safeguard: Always pair map insertions with explicit delete(@map[key]) statements on all exit paths. In long-running monitoring scripts, clear aggregated maps periodically with clear(@map).

3. Struct Layout Mismatches and Missing Kernel BTF

  • The Risk: When accessing internal kernel structures via kprobes, field offsets can change across different Linux kernel versions or vendor distributions. Attempting to access struct members without accurate type definitions can lead to verifier errors or incorrect data reads.
  • The Safeguard: Prefer Tracepoints over raw kprobes whenever possible, as tracepoint argument schemas remain stable across kernel upgrades. Ensure the host kernel is compiled with BPF Type Format (CONFIG_DEBUG_INFO_BTF=y), which allows bpftrace to verify struct layouts on the fly. You can also test your scripts using the -d dry-run flag before deploying them on live servers: bash sudo bpftrace -d -e 'kprobe:vfs_read { printf("%d\n", pid); }'

TODAY'S TAKEAWAY

Modern Linux performance analysis has evolved beyond the coarse averages of top and the risky overhead of strace. With bpftrace, systems administrators have a safe, production-grade magnifying glass that reveals operating system behaviour in real time.

To experience this on your own system right now, open a terminal with root privileges and run:

sudo bpftrace -e 'tracepoint:syscalls:sys_enter_openat { @[comm] = count(); } interval:s:5 { exit(); }'

Within five seconds, you will see a compiled eBPF program verified by the kernel, translated into native machine code, attached to every file-open request across your running applications, and returned as a clean summary histogramβ€”offering complete visibility into your system with virtually zero overhead.

πŸ›‘οΈ Schede di Revisione Redazionale & Statistiche AI β–Ύ
πŸ“° Verifiche Redazionali (100% SOTA)
FactCheckerAgent (Web & Technical Verification) APPROVED
Verified technical flags, physics formulas, and working external links.
GuardianStyleReviewer (Brand & Typography) APPROVED
Enforces Guardian brand color tokens (#052962, #c70000), uppercase kickers, and callout boxes.
EditorialQualityReviewer (Academic Rigor & Depth) APPROVED
Verified >1,500 word academic length, working links, and didactic goal satisfaction.
πŸ“Š Statistiche AI & Token Telemetry
Engine: gemini-3.6-pro
Auth: Google Gemini Ultra OAuth Session (~/.config/antigravity)
Prompt Tokens: 1,022
Completion Tokens: 9,241
Token Totali: 10,263
Costo API: $0.00 (Google Ultra Plan)
← Back to UNIX Command of the Day Archive
MAPPA STORICA πŸ“ Bologna