How to Trace Slow Synchronous File I/O Operations in Linux Using fileslower

Linux storage subsystems frequently appear healthy under high-level monitoring utilities like vmstat or iostat, yet database transactions, web servers, or containerized applications can experience severe micro-stalls. These tail-latency spikes often stem from individual synchronous file operations—such as an fsync flushing dirty metadata blocks or a process reading an un-cached index block from a fragmented filesystem. While filesystem-specific tools (like ext4slower or xfsslower) target specific filesystem drivers, the BCC tool fileslower hooks into the Virtual Filesystem Switch (VFS) layer to catch slow file I/O operations across all mounted filesystems.

Understanding How fileslower Hooks the Virtual Filesystem Switch

The Linux Virtual Filesystem Switch (VFS) serves as the universal abstraction layer mediating between user-space system calls and underlying filesystem drivers (ext4, XFS, Btrfs, NFS, ZFS, and OverlayFS). fileslower instruments VFS functions directly using extended Berkeley Packet Filters (eBPF):

• Entry Hook: When an application initiates a synchronous read or write via vfs_read() or vfs_write(), an eBPF kprobe records a nanosecond timestamp alongside the file descriptor, file path, and process ID.
• Exit Hook: When the VFS function completes and returns to user space, a kretprobe computes the exact elapsed time.
• In-Kernel Filtering: If the elapsed duration is shorter than the user’s configured threshold (e.g. 10 ms), the kernel immediately discards the event. Only operations that breach the threshold are transferred to user space, ensuring near-zero runtime overhead.

Installing the BCC Tools Suite

To run fileslower, ensure the BPF Compiler Collection package and kernel headers are installed:

# Ubuntu / Debian
sudo apt-get update
sudo apt-get install -y bpfcc-tools linux-headers-$(uname -r)

# RHEL 9 / Rocky Linux 9 / AlmaLinux
sudo dnf install -y bcc-tools kernel-devel-$(uname -r)

# Verify executable binary path
which fileslower || which /usr/share/bcc/tools/fileslower

Running fileslower to Detect Tail-Latency Outliers

Launch fileslower specifying a minimum latency threshold in milliseconds. If omitted, the default threshold is 10 ms:

# Trace file I/O operations slower than 10 ms system-wide
sudo /usr/share/bcc/tools/fileslower 10

# Capture severe stalls slower than 50 ms
sudo /usr/share/bcc/tools/fileslower 50

# Trace operations for a specific process ID (PID 14220)
sudo /usr/share/bcc/tools/fileslower -p 14220 5

When an operation exceeds the specified duration, fileslower prints a diagnostic entry:

TIME(s)  COMM             PID     D BYTES   OFFSET_KB LAT(ms) FILENAME
05:36:12 postgres         28104   R 8192    1048576   48.21   base/16384/2619
05:36:19 redis-server     1190    W 64      0         18.44   appendonly.aof
05:36:28 rsyslogd         980     W 4096    128       24.12   syslog
05:36:44 dockerd          2104    R 16384   524288    72.85   layer.tar

Interpreting Output Columns and Direction Types

Each recorded entry provides forensic detail into the offending operation:

• TIME(s): Local timestamp when the VFS call completed.
• COMM: Process command name responsible for the request.
• PID: Process identifier.
• D (Direction): R for synchronous read, W for synchronous write.
• BYTES: Number of bytes transferred.
• OFFSET_KB: File offset position in kilobytes where the I/O began.
• LAT(ms): Actual duration of the synchronous call in milliseconds.
• FILENAME: Full pathname or relative filename accessed.

Distinguishing Filesystem Latency from Block Device Saturation

When fileslower flags persistent latency spikes, follow this diagnostic progression:

1. Correlate with biosnoop: Run biosnoop simultaneously. If block-layer operations match the high latencies reported by fileslower, the physical SSD, NVMe drive, or SAN volume is saturated.
2. Page Cache Starvation: If small 8 KB reads on database files take 40+ ms, database worker threads are missing the kernel page cache and stalling on physical random disk seeks. Increase RAM or tune database buffer pool parameters.
3. Metadata Lock Contention: If writes to log files take 20+ ms despite low disk utilization, filesystem journal lock contention or un-flushed write barriers (barrier=1) may be delaying commit acknowledgments.

Using fileslower empowers systems administrators to isolate slow file accesses, identify storage bottlenecks, and resolve latency regressions across production Linux environments.