blktrace is used to analyze I/O-access, it provides more a more detailed look at I/O-usage than other tools like iotop and iostat.
Analyzing I/O patterns with blktrace is done in two steps. First use blktrace
to log operations, then use blkparse
to show a detailed report on the recorded data.
Record I/O-events on the blockdevice /dev/sda
for five seconds:
blktrace -w 5 -d /dev/sda
Print contents of the logfile to stdout (use -s switch to show per-program statistics at the end):
blkparse -i sda.blktrace.0 -s
Another option is to pass data into blkparse
straigt away to enable live viewing:
blktrace -d /dev/sda -o - | blkparse -i -
After recording the data blktrace shows a small summary of the recorded events:
=== sda === CPU 0: 3 events, 1 KiB data CPU 1: 145 events, 7 KiB data CPU 2: 6 events, 1 KiB data CPU 3: 3 events, 1 KiB data CPU 4: 295 events, 14 KiB data CPU 5: 0 events, 0 KiB data CPU 6: 0 events, 0 KiB data CPU 7: 10 events, 1 KiB data Total: 462 events (dropped 0), 22 KiB data
Since blkparse shows a huge amount of information we chose to only show small excerpts below.
Each event gets a single line in the first section of the log. By default the following elements are shown in order:
major and minor | major,minor device numbers (as shown in lsblk) |
cpu | cpu-core |
sequence | sequencenumber is |
pid | unix process id |
action | one of is described in detail in the documentation |
rwbs | 'r' for read, 'w' for write, 'd' for discard (for more details see the documentation) |
starting block + number of blocks | Block the operation is starting at and the number of blocks affected respectively |
8,0 1 2 0.000001084 5069 Q W 240054272 + 2048 [dd] 8,0 1 8 0.000058101 5069 Q W 240056320 + 2048 [dd] 8,0 1 13 0.000110909 5069 Q W 240058368 + 2048 [dd] 8,0 1 14 0.000113330 5069 G W 240058368 + 2048 [dd] 8,0 1 16 0.000162283 5069 Q W 240060416 + 2048 [dd] 8,0 1 17 0.000164598 5069 G W 240060416 + 2048 [dd] 8,0 1 28 0.000243672 5069 I W 240058368 + 2048 [dd] 8,0 1 29 0.000243966 5069 I W 240060416 + 2048 [dd] 8,0 1 36 0.000255103 5069 D W 240058368 + 2048 [dd] 8,0 1 37 0.000259523 5069 D W 240060416 + 2048 [dd]
When the -s
flag is set additional, per-process statistics are also displayed.
dd (5069) Reads Queued: 0, 0KiB Writes Queued: 8, 5,696KiB Read Dispatches: 0, 0KiB Write Dispatches: 8, 4,884KiB Reads Requeued: 0 Writes Requeued: 0 Reads Completed: 0, 0KiB Writes Completed: 0, 0KiB Read Merges: 0, 0KiB Write Merges: 0, 0KiB IO unplugs: 1 Timer unplugs: 0 Allocation wait: 0 Allocation wait: 0 Dispatch wait: 0 Dispatch wait: 0 Completion wait: 0 Completion wait: 0
A summary is shown at the very end of blkparse's output.
Total (sda): Reads Queued: 0, 0KiB Writes Queued: 41, 10,904KiB Read Dispatches: 0, 0KiB Write Dispatches: 20, 10,092KiB Reads Requeued: 0 Writes Requeued: 0 Reads Completed: 0, 0KiB Writes Completed: 21, 10,092KiB Read Merges: 0, 0KiB Write Merges: 21, 84KiB IO unplugs: 12 Timer unplugs: 0 Throughput (R/W): 0KiB/s / 3,285KiB/s Events (sda): 352 entries Skips: 0 forward (0 - 0.0%)