btrfsslower - Trace slow btrfs file operations, with per-event details. btrfsslower [-h] [-j] [-p PID] [min_ms] This tool traces common btrfs file operations: reads, writes, opens, and syncs. It measures the time spent in these operations, and prints details for each that exceeded a threshold. WARNING: See the OVERHEAD section. By default, a minimum millisecond threshold of 10 is used. If a threshold of 0 is used, all events are printed (warning: verbose). Since this works by tracing the btrfs_file_operations interface functions, it will need updating to match any changes to these functions. Since this uses BPF, only the root user can use this tool. CONFIG_BPF and bcc. -p PID Trace this PID only.

min_ms Minimum I/O latency (duration) to trace, in milliseconds. Default is 10 ms.

Trace synchronous file reads and writes slower than 10 ms: # btrfsslower

Trace slower than 1 ms: # btrfsslower 1

Trace slower than 1 ms, and output just the fields in parsable format (csv): # btrfsslower -j 1

Trace all file reads and writes (warning: the output will be verbose): # btrfsslower 0

Trace slower than 1 ms, for PID 181 only: # btrfsslower -p 181 1

TIME(s) Time of I/O completion since the first I/O seen, in seconds.

COMM Process name.

PID Process ID.

T Type of operation. R == read, W == write, O == open, S == fsync.

OFF_KB File offset for the I/O, in Kbytes.

BYTES Size of I/O, in bytes.

LAT(ms) Latency (duration) of I/O, measured from when it was issued by VFS to the filesystem, to when it completed. This time is inclusive of block device I/O, file system CPU cycles, file system locks, run queue latency, etc. It's a more accurate measure of the latency suffered by applications performing file system I/O, than to measure this down at the block device interface.

FILENAME A cached kernel file name (comes from dentry->d_iname).

ENDTIME_us Completion timestamp, microseconds (-j only).

OFFSET_b File offset, bytes (-j only).

LATENCY_us Latency (duration) of the I/O, in microseconds (-j only).

This adds low-overhead instrumentation to btrfs writes and fsyncs, as well as all system reads and opens (due to the current implementation of the btrfs_file_operations interface). Particularly, all reads and writes from the file system cache will incur extra overhead while tracing. Such reads and writes can be very frequent (depending on the workload; eg, 1M/sec), at which point the overhead of this tool may become noticeable. Measure and quantify before use. If this continues to be a problem, consider switching to a tool that prints in-kernel summaries only, such as btrfsdist(8).

Note that the overhead of this tool should be less than fileslower(8), as this tool targets btrfs functions only, and not all file read/write paths (which can include socket I/O).

This is from bcc. https://github.com/iovisor/bcc

Also look in the bcc distribution for a companion _examples.txt file containing example usage, output, and commentary for this tool.

Linux Unstable - in development. Brendan Gregg btrfsdist(8), biosnoop(8), funccount(8), fileslower(8)