blktrace is a block layer IO tracing mechanism which provide detailed information about request queue operations up to user space.
blkparse will combine streams of events for various devices on various CPUs, and produce a formatted output the the event information.
It take the output of above tool blktrace and convert those information into fency readable form.
In the following, We will use those tools blktrace and blkparse to help us to observe sector numbers which has been written by fio requests.
We will use the fil to generate two diffenrt IO pattern requests, sequence write and random write.
Environment
OS: Ubuntu 14.04
Storage: NVME
FIO: fio-2.19-12-gb94d
blktrace: 2.0.0
blkparse: 1.1.0
you can use following commands to install blktrace and blkparse1
apt-get install -y blktrace
Experiment
Step1
In order to make the output of blkparse more easily to read, we set the numjobs to 1.
Following is my fio config1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19[global]
iodepth=256
numjobs=1
direct=1
time_based
runtime=120
group_reporting
size=5G
ioengine=libaio
filename=/dev/nvme1n1
[rw]
bs=4k
rw=randwrite
[sw]
bs=64k
rw=write
After we setup the fio config, use the fio to generate the IO request. In this example, we ask the fio to generate the IO via sequence write pattern.1
fio ${path_of_config} section=sw
During the experiment, you can use the tool iostat to monitor the I/O information about the device we want to observe.
Step2
Open other terminal and use blktrace to collection the data, there are two parameter we need to use,
First one is -d, which indicate what target device blktrace will monitor to.
Second, is -w, we use it to limit the time (seconds) how long blktrace will run.
So, our final command looks like below.1
blktrace -d /dev/nvme1n1 -w 60
In the end of blktrace, you can discover some new files has created by blktrace and its prefix name is nvme1n1.blktrac.xx
The number of files is depends how may CPUs in your system.
1 | -rw-r--r-- 1 root root 821152 Jun 2 10:39 nvme1n1.blktrace.0 |
Step3
Now, we can use the blkparse to regenerate human-readable output form the output we get via blktrace before.
We need to indicate source files, you can just use the device name without .blktrace.xx, for example,
nvmen1, it will search all files which match the pattern nvmen1.blktrace.xx and put together to analyze.
Then, the -f option used to foramt the output data, you can find more about it via man blkparse
1 | OUTPUT DESCRIPTION AND FORMATTING |
For our observation, we use %5T.%9t, %p, %C, %a, %S\n to format our result containing timestamp, command, process ID, action and sequence number.
Since the data I/O contains many action, such as complete, queued, inserted..ect. we can use option -a to filter actions, you can find more info via man blktrace.
In this case, we use the write to filter the actions.
In the end, use the -o options to indicate the output file name.
1 | barrier: barrier attribute |
The command will look like below and it will output the result to file output.txt.
1 | blkparse nvme1n1 -f "%5T.%9t, %p, %C, %a, %S\n" -a write -o output.txt |
open the file, the result looks like1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29 0.000000000, 22890, fio, Q, 1720960
0.000001857, 22890, fio, G, 1720960
0.000005803, 22890, fio, I, 1720960
0.000009234, 22890, fio, D, 1720960
0.000036821, 0, swapper/0, C, 1996928
0.000067519, 22890, fio, Q, 1721088
0.000068538, 22890, fio, G, 1721088
0.000071531, 22890, fio, I, 1721088
0.000073102, 22890, fio, D, 1721088
0.000093464, 0, swapper/0, C, 1994624
0.000123806, 0, swapper/0, C, 1785472
0.000147436, 22892, fio, C, 1784576
0.000159977, 22891, fio, C, 1997312
0.000166653, 22891, fio, Q, 2006912
0.000167632, 22891, fio, G, 2006912
0.000169422, 22891, fio, I, 2006912
0.000171178, 22891, fio, D, 2006912
0.000188830, 22892, fio, Q, 1817728
0.000189783, 22892, fio, G, 1817728
0.000191405, 22892, fio, I, 1817728
0.000192830, 22892, fio, D, 1817728
0.000202367, 22891, fio, Q, 2007040
0.000203160, 22891, fio, G, 2007040
0.000205969, 22891, fio, I, 2007040
0.000207524, 22891, fio, D, 2007040
0.000227655, 22892, fio, Q, 1817856
0.000228457, 22892, fio, G, 1817856
0.000231936, 22892, fio, I, 1817856
....
Since the fio will fork to two process to handle the process, we use the grep to focus on one specific process (pid=22892).
1 | grep "22892, fio" output.txt | more |
Now, the result seems good, we can discover the sequence number (fifth column) is increasing.
One thing we need to care about is the row which action is “C”, which means the completed, since we don’t know how NVME handle those request and reply to upper layer. we only need to focus on other action. such as “Q (queued This notes intent to queue i/o at the given location. No real requests exists yet.)” or “I (inserted A request is being sent to the i/o scheduler for addition to the internal queue and later service by the driver. The request is fully formed at this time)”.
1 | 0.000147436, 22892, fio, C, 1784576 |
Now, we can do all above command again and change the section to rw for fio using the randon write pattern. The blkparse result will show the random sequence number.
Summary
In this article, we try to use tools blktrace and blkparse to analysiz the block level I/O for fio request.
We observe the filed sequence number to make sure thhat the fio can generate the sequence or random according to its config.