biolatency
Linux biolatency — Complete Learning Notes & Output Guide
biolatencyis an eBPF/BCC performance-analysis tool that measures the latency distribution of block device I/O (disk requests) and summarizes them as power-of-2 logarithmic histograms. Because calculations and aggregations happen entirely in kernel space via eBPF maps, it introduces negligible overhead even on systems processing tens of thousands of IOPS.
1. What is biolatency?
biolatency belongs to the BCC (BPF Compiler Collection) and libbpf-tools family, originally developed by Brendan Gregg.
Average disk latency (such as the await column in iostat) hides outliers. For example, an average latency of $3\,\text{ms}$ can hide the fact that $1\%$ of requests took $500\,\text{ms}$, causing application timeouts. biolatency resolves this by exposing the full latency distribution curve, showing both the common modes (cache hits vs. mechanical/flash fetches) and tail outliers.
It answers critical storage diagnostic questions:
- What is the true latency distribution of our block devices (SSDs, NVMe drives, HDDs)?
- Are slow queries caused by storage latency outliers or application-level thread stalls?
- How much time do I/O requests spend sitting in OS kernel queues before being dispatched to the hardware?
- Does latency differ between read operations and write operations on the same drive?
- Is a storage performance issue isolated to a single disk in an array or shared across all disks?
2. Installation
biolatency requires root privileges (sudo or CAP_BPF) and a kernel with eBPF enabled.
Debian / Ubuntu
sudo apt update
sudo apt install bpfcc-tools linux-headers-$(uname -r)
(On Debian and Ubuntu, BCC tools are placed in /usr/sbin/ with a -bpfcc suffix, e.g., biolatency-bpfcc).
RHEL / Rocky / AlmaLinux / CentOS
sudo dnf install bcc-tools kernel-devel-$(uname -r)
(Binaries reside in /usr/share/bcc/tools/biolatency).
Arch Linux
sudo pacman -S bcc-tools
Verify the installation:
sudo biolatency -h 2>/dev/null || sudo biolatency-bpfcc -h
3. Basic Syntax & Flags
sudo biolatency [options] [interval] [count]
Essential Command Flags
| Flag | Description | Practical Example |
|---|---|---|
interval |
Output summary interval in seconds. | sudo biolatency 5 |
count |
Number of interval outputs before exiting. | sudo biolatency 1 10 |
**-m, --milliseconds** |
Display latency buckets in milliseconds instead of the default microseconds. | sudo biolatency -m 5 1 |
**-T, --timestamp** |
Include a timestamp above each interval histogram. | sudo biolatency -T 1 |
**-Q, --queued** |
Include OS queuing delay in the latency measurement (measures queue wait + hardware service time). | sudo biolatency -Q |
**-D, --disks** |
Print an individual histogram per disk device. | sudo biolatency -D |
**-F, --flags** |
Print an individual histogram per set of I/O flags (reads vs. writes vs. sync). | sudo biolatency -F |
-d <disk> |
Filter tracing strictly to a specified disk device name (e.g., sda, nvme0n1). |
sudo biolatency -d nvme0n1 |
**-e, --extension** |
Print summary metrics (total time, operation count, average latency) beneath the histogram. | sudo biolatency -e |
**-j, --json** |
Output histogram data in JSON dictionary format for automated metrics collection. | sudo biolatency -j |
4. Anatomy of the Default Output
When executed without extra flags, biolatency records I/O requests and outputs a single microsecond histogram either upon Ctrl-C or at the specified interval:
sudo biolatency
Raw Output Example (Default: Microseconds)
Tracing block device I/O... Hit Ctrl-C to end.
^C
usecs : count distribution
0 -> 1 : 0 | |
2 -> 3 : 0 | |
4 -> 7 : 0 | |
8 -> 15 : 2 | |
16 -> 31 : 18 |* |
32 -> 63 : 142 |***** |
64 -> 127 : 1045 |****************************************|
128 -> 255 : 412 |*************** |
256 -> 511 : 84 |*** |
512 -> 1023 : 12 | |
1024 -> 2047 : 4 | |
2048 -> 4095 : 1 | |
Raw Output Example with Milliseconds (-m):
sudo biolatency -m 5 1
Tracing block device I/O... Hit Ctrl-C to end or wait 5 seconds.
msecs : count distribution
0 -> 1 : 45210 |****************************************|
2 -> 3 : 1204 |* |
4 -> 7 : 342 | |
8 -> 15 : 89 | |
16 -> 31 : 14 | |
32 -> 63 : 3 | |
64 -> 127 : 1 | |
5. Breakdown of Every Output Heading & Field
+---------------------+-----------------+------------------------------------------+
| Range (usecs/msecs) | count | distribution |
+---------------------+-----------------+------------------------------------------+
| 64 -> 127 | 1045 | |****************************************| |
+---------------------+-----------------+------------------------------------------+
5.1 usecs / msecs (Latency Range Bucket)
- Format:
lower_bound -> upper_bound(e.g.,64 -> 127,128 -> 255). - Meaning: The power-of-2 logarithmic interval representing the time elapsed from when an I/O request was dispatched to the device driver until the storage device returned completion.
- Without
-m: Measured in microseconds ($\mu\text{s}$). With
-m: Measured in milliseconds ($\text{ms}$).Bucket Logic: Buckets double in width at each step ($2^n \to 2^{n+1}-1$). This allows
biolatencyto track both sub-microsecond cache hits and multi-second disk stalls within a small, fixed-size memory array in the kernel.
5.2 count
- Format: Unsigned integer (e.g.,
1045,45210). - Meaning: The exact number of block I/O requests whose round-trip latency fell into that specific duration bracket during the measurement window.
5.3 distribution
- Format: ASCII bar graph enclosed in pipe symbols (
|***...|). - Meaning: A visual distribution bar normalized against the highest-count bucket in the histogram. The peak bucket is assigned the full 40-character bar width (
40asterisks*), and all other buckets scale proportionally.
6. Advanced Diagnostic Modes & Output Variations
6.1 Per-Disk Breakdown: biolatency -D
On servers with multiple block storage volumes (e.g., OS root drive on sda, data volume on sdb, fast scratch drive on nvme0n1), -D separates measurements by device:
sudo biolatency -D 5 1
Raw Output
disk = 'nvme0n1'
usecs : count distribution
0 -> 1 : 0 | |
16 -> 31 : 120 |** |
32 -> 63 : 1840 |****************************************|
64 -> 127 : 920 |******************** |
128 -> 255 : 45 | |
disk = 'sda'
usecs : count distribution
0 -> 1 : 0 | |
64 -> 127 : 14 |* |
128 -> 255 : 412 |****************************************|
256 -> 511 : 180 |***************** |
1024 -> 2047 : 95 |********* |
4096 -> 8191 : 8 | |
disk = '<device_name>': Indicates which physical or logical block device the subsequent histogram describes.- Diagnostic Interpretation: Instantly reveals performance asymmetries across drives. In the example above,
nvme0n1peaks at $32\text{--}63\,\mu\text{s}$, whilesdaclusters around $128\text{--}255\,\mu\text{s}$ with a tail extending past $4\,\text{ms}$.
6.2 Per-Flag / Operation Breakdown: biolatency -F
-F groups requests by operation type (reads vs. writes vs. sync/flush):
sudo biolatency -F 5 1
Raw Output
flags = 'R'
usecs : count distribution
32 -> 63 : 85 |***** |
64 -> 127 : 610 |****************************************|
128 -> 255 : 120 |******* |
flags = 'W'
usecs : count distribution
16 -> 31 : 420 |****************************************|
32 -> 63 : 180 |***************** |
64 -> 127 : 45 |**** |
flags = 'WS'
msecs : count distribution
4 -> 7 : 12 |***** |
8 -> 15 : 84 |****************************************|
16 -> 31 : 32 |*************** |
Explanation of Flag Labels
flags = 'R': Standard read operations.flags = 'W': Standard write operations.flags = 'WS'/flags = 'WM': Synchronous writes or writes with metadata/FUA flags (database WAL flushes, filesystem metadata updates). These typically have longer latencies because they must be committed directly to non-volatile media before returning.
6.3 Measuring OS Queuing Stalls: biolatency -Q
By default, biolatency measures on-device latency (time from device driver issue to completion).
Adding -Q includes OS queue wait time (time from when the kernel block layer allocates/inserts the request into the I/O queue until completion):
# Compare standard device latency vs queued latency
sudo biolatency -m 5 1
sudo biolatency -mQ 5 1
Comparing Outputs
Standard (Device Service Time Only):
msecs : count distribution
0 -> 1 : 45000 |****************************************|
2 -> 3 : 120 | |
With -Q (OS Queue Wait + Device Service Time):
msecs : count distribution
0 -> 1 : 12000 |********** |
2 -> 3 : 8500 |******* |
4 -> 7 : 18000 |**************** |
8 -> 15 : 45000 |****************************************|
16 -> 31 : 1200 |* |
- Diagnostic Significance: If the standard histogram shows fast latencies (
0 -> 1 ms), but running with-Qshifts the distribution into the8 -> 15 msrange, the physical disk is not slow—the kernel block queue is congested. Requests are sitting in software queues waiting for I/O tags or dispatch slots.
6.4 Summary Extension: biolatency -e
sudo biolatency -e 5 1
usecs : count distribution
64 -> 127 : 142 |****************************************|
128 -> 255 : 45 |************ |
total = 21450 us, count = 187, avg = 114 us
total: Cumulative time spent across all requests in microseconds or milliseconds.count: Total number of I/O operations recorded during the interval.avg: Mean latency across all operations during the interval ($\frac{\text{total}}{\text{count}}$).
7. How biolatency Works Internally
biolatency uses eBPF kprobes or kernel tracepoints in the block layer:
+-------------------------------------------------------------------------+
| KERNEL SPACE |
| |
| 1. Request Enqueued / Allocated: |
| - When -Q is used: Hooks tracepoint block:block_rq_insert |
| or blk_account_io_start() |
| - Without -Q: Hooks tracepoint block:block_rq_issue |
| or blk_mq_start_request() |
| - Stores: Key = struct request *req (or dev + sector) |
| Value = bpf_ktime_get_ns() |
| in BPF Hash Map: 'start' |
| |
| 2. Request Completed by Storage Hardware: |
| - Hooks tracepoint block:block_rq_complete |
| or blk_account_io_done() |
| - Looks up start timestamp from 'start' map |
| - Computes: delta = current_time - start_time |
| - Calculates bucket: slot = bpf_log2l(delta) |
| - Atomically increments bucket in BPF Histogram Map: 'dist' |
| - Deletes entry from 'start' map |
+-------------------------------------------------------------------------+
|
| Map read once per interval / Ctrl-C
v
+-------------------------------------------------------------------------+
| USER SPACE |
| Python/libbpf CLI: Formats 'dist' map into ASCII visual histogram |
+-------------------------------------------------------------------------+
Why Overhead is Negligible:
Unlike strace or biosnoop (which send individual events to user space), biolatency maintains the histogram counters directly inside an in-kernel BPF map. User space only reads the 64-element histogram array once per interval, generating virtually zero context switching overhead.
8. Diagnosing Storage Patterns with biolatency
Pattern A: High-Performance NVMe / SSD Profile
usecs : count distribution
16 -> 31 : 1420 |*** |
32 -> 63 : 18520 |****************************************|
64 -> 127 : 4500 |********* |
128 -> 255 : 120 | |
- Analysis: Fast, single-mode distribution peaking sharply between $32\text{--}63\,\mu\text{s}$. Sub-millisecond latency across all requests. Storage is healthy and responsive.
Pattern B: Bimodal Distribution (Cache Hits vs. Storage Media)
usecs : count distribution
16 -> 31 : 8400 |****************************************|
32 -> 63 : 1200 |***** |
64 -> 127 : 80 | |
128 -> 255 : 45 | |
512 -> 1023 : 210 |* |
1024 -> 2047 : 4200 |******************** |
2048 -> 4095 : 1800 |******** |
- Analysis: Two distinct peaks. The first peak at $16\text{--}31\,\mu\text{s}$ represents hardware on-disk write cache or battery-backed RAID controller hits. The second peak at $1\text{--}4\,\text{ms}$ represents requests that missed the cache and required physical media access.
Pattern C: Tail Latency Outlier Problem (The "Long Tail")
msecs : count distribution
0 -> 1 : 98000 |****************************************|
2 -> 3 : 120 | |
4 -> 7 : 45 | |
64 -> 127 : 8 | |
256 -> 511 : 14 | |
1024 -> 2047 : 3 | |
- Analysis:
iostatwould report an average latency of ~0.8 ms for this workload (looking healthy). However,biolatencyreveals that several operations stalled for 1 to 2 seconds. In a distributed database or microservice architecture, these tail latency outliers will stall worker threads and trigger request timeouts.
9. biolatency vs. iostat vs. biosnoop vs. ext4dist
| Dimension | biolatency |
iostat |
biosnoop |
ext4dist |
|---|---|---|---|---|
| Layer Traced | Block Device Driver | System /proc/diskstats |
Block Device Driver | Filesystem Layer (ext4 VFS) |
| Output Style | Logarithmic Histograms | Averages over intervals | Event-by-event stream | Logarithmic Histograms |
| Tail Latency Detection | Excellent (Shows outliers) | Poor (Hides in averages) | Excellent (Shows exact times) | Excellent (At VFS level) |
| Queue Time Breakdown | Yes (via -Q) |
Indirect (aqu-sz) |
Yes (via -Q) |
No |
| Process ID / Name | No (Aggregated by disk/flag) | No | Yes (PID, COMM) |
No |
| Page Cache Hits | No (Only block I/O) | No | No | Yes |
| Overhead | Negligible ($< 1\%$ on 100k IOPS) | Zero (Reads /proc) |
Moderate (Streams every I/O) | Negligible |
10. Real-World Troubleshooting Scenarios
Scenario A: Diagnosing Slow Database WAL Writes / Commits
A PostgreSQL or MySQL instance logs occasional transaction commit spikes exceeding $100\,\text{ms}$, but iostat reports average await = 2.5ms.
Run biolatency broken down by I/O flags:
sudo biolatency -m -F 5 1
Diagnosis: Look at the flags = 'WS' (Synchronous Write) section. If the histogram reveals a tail extending past $64\,\text{ms}$, the storage controller or NVMe drive is stalling on cache flushes or NAND garbage collection cycles during write bursts.
Scenario B: Distinguishing Device Bottlenecks from Software Queuing Delays
An application team reports high storage latency, and you need to determine whether the physical disk is slow or if the kernel I/O scheduler is backlogged.
Run two concurrent checks:
# Terminal 1: Hardware service latency only
sudo biolatency -m 5 1
# Terminal 2: Total latency including OS queuing
sudo biolatency -mQ 5 1
Diagnosis:
- If both show identical peaks at $15\,\text{ms}$: The bottleneck is in the storage hardware or SAN/cloud storage network.
- If Terminal 1 shows fast hardware completion ($0\text{--}1\,\text{ms}$), but Terminal 2 shows high latency ($16\text{--}31\,\text{ms}$): The storage hardware is fine, but requests are blocked in the Linux kernel block queue. Fix by checking I/O scheduler configurations (
none/mq-deadline), increasing queue depth, or resolving queue tag starvation.
11. Important Interview Questions & Answers
Q: Why is a latency histogram from biolatency more reliable than the average await metric from iostat?
Answer: Average metrics hide bimodal distributions and outlier spikes. If an application performs $9,990$ fast reads at $0.1\,\text{ms}$ and $10$ slow reads that stall for $1,000\,\text{ms}$, the calculated average latency is approximately $1.1\,\text{ms}$—which looks acceptable in iostat. However, those 10 stalled operations can block worker threads, trigger request timeouts, or cause connection drops. biolatency reveals the full distribution, highlighting the $1,000\,\text{ms}$ outliers in separate buckets.
Q: What does the -Q flag measure, and what does a discrepancy between biolatency and biolatency -Q tell you?
Answer: Without -Q, biolatency measures driver/hardware latency (from when a request is dispatched to the controller until completion). With -Q, it measures total latency starting from when the request was first created and queued in the OS block layer. A large discrepancy indicates that the physical drive is servicing requests quickly once it receives them, but requests are spending significant time stalled inside the Linux kernel's I/O scheduler or hardware dispatch queues, pointing to queue depth exhaustion or thread lock contention in the block layer.
Q: How does biolatency safely monitor systems running at 100,000+ IOPS without crashing or degrading performance?
Answer: biolatency maintains an in-kernel BPF hash map for tracking request issue timestamps and a small array map for the logarithmic histogram buckets. When a request completes, the duration is computed, mapped to a power-of-2 bucket via bpf_log2l(), and the bucket counter is incremented directly in kernel memory using atomic operations. No per-event data is copied across the kernel-user boundary into ring buffers; user space only reads the small, static histogram table once per report interval.
For an architectural breakdown of eBPF-based performance analysis and the design principles behind tools like biolatency, watch Performance Wins with BPF by Brendan Gregg. This presentation directly illustrates how in-kernel eBPF instrumentation eliminates the overhead of traditional tracing utilities.