本文永久链接: https://www.xtplayer.cn/linux/disk/blktrace-btt-test-io/

平时我们在 Linux 上查看磁盘 I/O 性能,可能我们首先就会想到 iostat 命令(包含于 sysstat 软件包中)或者 iotop 命令。iostat 或者 iotop 仅提供了汇总的简单视图,其中很重要的参数就是 await,await 表示单个 I/O 所需的平均时间,但它同时包含了 I/O Scheduler 所消耗的时间和硬件所消耗的时间,所以不能作为硬件性能的指标。如果需要知道更多的细节数据,iostat 将无法满足需求。我们需要更强大的工具来深入了解 I/O 性能问题,我们需要用到 blktrace。

blktrace 提供了对通用块层(block layer)的 I/O 跟踪机制,它能抓取详细的 I/O 请求(request),并发送到用户态空间。

blktrace 主要由 3 部分组成:

  • 内核组件
  • 将内核的 I/O 跟踪信息记录到用户空间的实用程序
  • 分析和查看跟踪信息的实用程序

blktrace 在通过调试文件系统(中继)传递的缓冲区中接收来自内核的数据。每个被跟踪的设备都在挂载目录中为 debugfs 创建了一个文件,debugfs 挂载目录默认是:/sys/kernel/debug

blktrace 的原理

一个 I/O 请求,从应用层到底层块设备,路径如下图所示:

从上图可以看出 I/O 路径是很复杂,将 I/O 路径简化一下,大致为:

一个 I/O 请求进入 block layer 之后,可能会经历下面的过程:

  • Remap: 可能被 DM(Device Mapper) 或 MD(Multiple Device, Software RAID) remap 到其它设备;
  • Split: 可能会因为 I/O 请求与扇区边界未对齐、或者 size 太大而被分拆 (split) 成多个物理 I/O;
  • Merge: 可能会因为与其它 I/O 请求的物理位置相邻而合并 (merge) 成一个 I/O;
  • 被 I/O Scheduler 依照调度策略发送给 Driver;
  • 被 Driver 提交给硬件,经过 HBA、电缆(光纤、网线等)、交换机(SAN 或网络),最后到达存储设备,设备完成 I/O 请求之后再返回结果。

blktrace 总体架构

blktrace 事件输出

  • 第一个字段:8,0 这个字段是设备号 major device ID 和 minor device ID。
  • 第二个字段:3 表示 CPU
  • 第三个字段:11 序列号
  • 第四个字段:0.009507758 Time Stamp 是时间偏移
  • 第五个字段:PID 本次 I/O 对应的进程 ID
  • 第六个字段:Event,这个字段非常重要,反映了 I/O 进行到了那一步
  • 第七个字段:R 表示 Read, W 是 Write,D 表示 block,B 表示 Barrier Operation
  • 第八个字段:223490+56,表示的是起始 block number 和 number of blocks,即我们常说的 Offset 和 Size
  • 第九个字段:进程名

其中第六个字段非常有用:每一个字母都代表了 I/O 请求所经历的某个阶段。

最重要的几个阶段

Q – 即将生成 I/O 请求
|
G – I/O 请求生成
|
I – I/O 请求进入 I/O Scheduler 队列
|
D – I/O 请求进入 Driver
|
C – I/O 请求执行完毕

根据以上步骤对应的时间戳就可以计算出 I/O 请求在每个阶段所消耗的时间:

  • Q2G – 生成 I/O 请求所消耗的时间,包括 remap 和 split 的时间;
  • G2I – I/O 请求进入 I/O Scheduler 所消耗的时间,包括 merge 的时间;
  • I2D – I/O 请求在 I/O Scheduler 中等待的时间,可以作为 I/O Scheduler 性能的指标;
  • D2C – I/O 请求在 Driver 和硬件上所消耗的时间,可以作为硬件性能的指标;
  • Q2C – 整个 I/O 请求所消耗的时间(Q2I + I2D + D2C = Q2C),相当于 iostat 的 await。

整个 I/O 路径,分成很多段,每一段开始的时候,都会有一个时间戳,根据上一段开始的时间和下一段开始的时间,就可以得到 I/O 路径各段花费的时间。service time,也就是反应块设备处理能力的指标,就是从 D 到 C 所花费的时间,简称 D2C。而 iostat 输出中的 await,即整个 I/O 从生成请求到 I/O 请求执行完毕,即从 Q 到 C 所花费的时间,我们简称 Q2C。我们知道 Linux 有 I/O scheduler,调度器的效率如何,I2D 是重要的指标。

这只是 blktrace 输出的一个部分,很明显,我们还能拿到 offset 和 size,根据 offset,我们能拿到某一段时间里,应用程序都访问了整个块设备的那些 block,从而绘制出块设备访问轨迹图。另外还有 size 和第七个字段(Read or Write),我们可以知道 I/O size 的分布直方图。对于本文来讲,我们就是要根据 blktrace 来获取这些信息。

blktrace event 速查表

  • A remap 对于栈式设备,进来的 I/O 将被重新映射到 I/O 栈中的具体设备。
  • X split 对于做了 Raid 或进行了 device mapper(dm) 的设备,进来的 I/O 可能需要切割,然后发送给不同的设备。
  • Q queued I/O 进入 block layer,将要被 request 代码处理(即将生成 I/O 请求)。
  • G get request I/O 请求(request)生成,为 I/O 分配一个 request 结构体。
  • M back merge 之前已经存在的 I/O request 的终止 block 号,和该 I/O 的起始 block 号一致,就会合并,也就是向后合并。
  • F front merge 之前已经存在的 I/O request 的起始 block 号,和该 I/O 的终止 block 号一致,就会合并,也就是向前合并。
  • I inserted I/O 请求被插入到 I/O scheduler 队列。
  • S sleep 没有可用的 request 结构体,也就是 I/O 满了,只能等待有 request 结构体完成释放。
  • P plug 当一个 I/O 入队一个空队列时,Linux 会锁住这个队列,不处理该 I/O,这样做是为了等待一会,看有没有新的 I/O 进来,可以合并。
  • U unplug 当队列中已经有 I/O request 时,会放开这个队列,准备向磁盘驱动发送该 I/O。这个动作的触发条件是:超时(plug 的时候,会设置超时时间);或者是有一些 I/O 在队列中(多于 1 个 I/O)。
  • D issued I/O 将会被传送给磁盘驱动程序处理。
  • C complete I/O 处理被磁盘处理完成。

blktrace 汇总输出

安装 blktrace

  1. centos

    yum install blktrace
  2. ubuntu

    apt-get install blktrace

    blktrace 用法

接下来简单介绍这些工具的使用,这三个命令都包含在 blktrace 中,使用 blktrace 需要挂载 debugfs。

mount -t debugfs debugfs /sys/kernel/debug

查看实时数据

(可选) 利用 blktrace 查看实时数据的方法,假设要看的硬盘为 sdb。

blktrace -d /dev/sdb -o – | blkparse -i –

这个命令会持续输出,可按 ctrl+C 停止。也可以先用如下命令采集信息,待所有信息采集完毕后,统一分析所有采集到的数据。搜集信息的命令如下:

blktrace 收集数据

利用 blktrace 把数据记录在文件里,以供事后分析。

blktrace -d /dev/sdb

默认的输出文件名是 sdb.blktrace.<cpu>,每个 CPU 对应一个文件,也可以用 -o 参数指定自己的输出文件名。

-rw-r--r-- 1 manu manu  1.3M Jul  6 19:58 sdb.blktrace.0
-rw-r--r-- 1 manu manu 823K Jul 6 19:58 sdb.blktrace.1
-rw-r--r-- 1 manu manu 2.8M Jul 6 19:58 sdb.blktrace.10
-rw-r--r-- 1 manu manu 1.9M Jul 6 19:58 sdb.blktrace.11
-rw-r--r-- 1 manu manu 474K Jul 6 19:58 sdb.blktrace.12
-rw-r--r-- 1 manu manu 271K Jul 6 19:58 sdb.blktrace.13
-rw-r--r-- 1 manu manu 578K Jul 6 19:58 sdb.blktrace.14
-rw-r--r-- 1 manu manu 375K Jul 6 19:58 sdb.blktrace.15
-rw-r--r-- 1 manu manu 382K Jul 6 19:58 sdb.blktrace.16
-rw-r--r-- 1 manu manu 478K Jul 6 19:58 sdb.blktrace.17
-rw-r--r-- 1 manu manu 839K Jul 6 19:58 sdb.blktrace.18
-rw-r--r-- 1 manu manu 848K Jul 6 19:58 sdb.blktrace.19
-rw-r--r-- 1 manu manu 1.6M Jul 6 19:58 sdb.blktrace.2
-rw-r--r-- 1 manu manu 652K Jul 6 19:58 sdb.blktrace.20
-rw-r--r-- 1 manu manu 738K Jul 6 19:58 sdb.blktrace.21
-rw-r--r-- 1 manu manu 594K Jul 6 19:58 sdb.blktrace.22
-rw-r--r-- 1 manu manu 527K Jul 6 19:58 sdb.blktrace.23
-rw-r--r-- 1 manu manu 1005K Jul 6 19:58 sdb.blktrace.3
-rw-r--r-- 1 manu manu 1.2M Jul 6 19:58 sdb.blktrace.4
-rw-r--r-- 1 manu manu 511K Jul 6 19:58 sdb.blktrace.5
-rw-r--r-- 1 manu manu 2.3M Jul 6 19:58 sdb.blktrace.6
-rw-r--r-- 1 manu manu 1.3M Jul 6 19:58 sdb.blktrace.7
-rw-r--r-- 1 manu manu 2.1M Jul 6 19:58 sdb.blktrace.8
-rw-r--r-- 1 manu manu 1.1M Jul 6 19:58 sdb.blktrace.9

blkparse 用法

有了 blktrace 收集的数据,我们可以通过 blkparse -i sdb 来分析采集的数据:

8,16   7     2147     0.999400390 630169  I   W 447379872 + 8 [kworker/u482:0]
8,16 7 2148 0.999400653 630169 I W 447380040 + 8 [kworker/u482:0]
8,16 7 2149 0.999401057 630169 I W 447380088 + 16 [kworker/u482:0]
8,16 7 2150 0.999401364 630169 I W 447380176 + 8 [kworker/u482:0]
8,16 7 2151 0.999401521 630169 I W 453543312 + 8 [kworker/u482:0]
8,16 7 2152 0.999401843 630169 I W 453543328 + 8 [kworker/u482:0]
8,16 7 2153 0.999402195 630169 U N [kworker/u482:0] 14
8,16 6 5648 0.999403047 16921 C W 347875880 + 8 [0]
8,16 6 5649 0.999406293 16921 D W 301856632 + 8 [ceph-osd]
8,16 6 5650 0.999421040 16921 C W 354834456 + 8 [0]
8,16 6 5651 0.999423900 16921 D W 301857280 + 8 [ceph-osd]
8,16 7 2154 0.999442195 630169 A W 425409840 + 8 <- (8,22) 131806512
8,16 7 2155 0.999442601 630169 Q W 425409840 + 8 [kworker/u482:0]
8,16 7 2156 0.999444277 630169 G W 425409840 + 8 [kworker/u482:0]
8,16 7 2157 0.999445177 630169 P N [kworker/u482:0]
8,16 7 2158 0.999446341 630169 I W 425409840 + 8 [kworker/u482:0]
8,16 7 2159 0.999446773 630169 UT N [kworker/u482:0] 1
8,16 6 5652 0.999452685 16921 C W 354834520 + 8 [0]
8,16 6 5653 0.999455613 16921 D W 301857336 + 8 [ceph-osd]
8,16 6 5654 0.999470425 16921 C W 393228176 + 8 [0]
8,16 6 5655 0.999474127 16921 D W 411554968 + 8 [ceph-osd]
8,16 6 5656 0.999488551 16921 C W 393228560 + 8 [0]
8,16 6 5657 0.999491549 16921 D W 411556112 + 8 [ceph-osd]
8,16 6 5658 0.999594849 16923 C W 393230152 + 16 [0]
8,16 6 5659 0.999604038 16923 D W 432877368 + 8 [ceph-osd]
8,16 6 5660 0.999610322 16923 C W 487390128 + 8 [0]
8,16 6 5661 0.999614654 16923 D W 432879632 + 8 [ceph-osd]
8,16 6 5662 0.999628284 16923 C W 487391344 + 8 [0]
8,16 6 5663 0.999632014 16923 D W 432879680 + 8 [ceph-osd]
8,16 6 5664 0.999646122 16923 C W 293759504 + 8 [0]

blkparse 只是将 blktrace 保存的数据转成可以人工阅读的格式,由于数据量通常很大,人工分析并不轻松。因此接下来需要使用 btt 对 blktrace 保存的数据进行自动分析。

btt 用法

  1. 首先,需要使用 blkparse 工具将可以将 blktrace 收集的对应不同 cpu 的多个文件聚合成一个文件:

    blkparse -i sdb -d sdb.blktrace.bin
  2. 然后使用 btt 分析 sdb.blktrace.bin,可以获得类似以下数据信息:

==================== All Devices ====================

ALL MIN AVG MAX N
--------------- ------------- ------------- ------------- -----------

Q2Q 0.000000001 0.000159747 0.025292639 62150
Q2G 0.000000233 0.000001380 0.000056343 52423
G2I 0.000000146 0.000027084 0.005031317 48516
Q2M 0.000000142 0.000000751 0.000021613 9728
I2D 0.000000096 0.001534463 0.022469688 52423
M2D 0.000000647 0.002617691 0.022445412 5821
D2C 0.000046189 0.000779355 0.007860766 62151
Q2C 0.000051089 0.002522832 0.026096657 62151

==================== Device Overhead ====================

DEV | Q2G G2I Q2M I2D D2C
---------- | --------- --------- --------- --------- ---------
( 8, 16) | 0.0461% 0.8380% 0.0047% 51.3029% 30.8921%
---------- | --------- --------- --------- --------- ---------
Overall | 0.0461% 0.8380% 0.0047% 51.3029% 30.8921%

==================== Device Merge Information ====================

DEV | #Q #D Ratio | BLKmin BLKavg BLKmax Total
---------- | -------- -------- ------- | -------- -------- -------- --------
( 8, 16) | 62151 52246 1.2 | 1 20 664 1051700

==================== Device Q2Q Seek Information ====================

DEV | NSEEKS MEAN MEDIAN | MODE
---------- | --------------- --------------- --------------- | ---------------
( 8, 16) | 62151 42079658.0 0 | 0(17159)
---------- | --------------- --------------- --------------- | ---------------
Overall | NSEEKS MEAN MEDIAN | MODE
Average | 62151 42079658.0 0 | 0(17159)

==================== Device D2D Seek Information ====================

DEV | NSEEKS MEAN MEDIAN | MODE
---------- | --------------- --------------- --------------- | ---------------
( 8, 16) | 52246 39892356.2 0 | 0(9249)
---------- | --------------- --------------- --------------- | ---------------
Overall | NSEEKS MEAN MEDIAN | MODE
Average | 52246 39892356.2 0 | 0(9249)

注意: D2C 和 Q2C,一个是表征块设备性能的关键指标,另一个是客户发起请求到收到响应的时间。可以看出 D2C 平均在 0.000779355 秒,即 0.7 毫秒 Q2C 平均在 0.002522832 秒,即 2.5 毫秒,

无论是 service time 还是客户感知到的 await time,都是非常短。但是 D2C 花费的时间只占整个 Q2C 的 30%,51% 以上的时间花费在 I2D。下面我们看下 D2C 和 Q2C 随着时间的分布情况:

参考文档

http://duch.mimuw.edu.pl/~lichota/09-10/Optymalizacja-open-source/Materialy/10%20-%20Dysk/gelato_ICE06apr_blktrace_brunelle_hp.pdf
http://wiki.dreamrunner.org/public_html/Low_Latency_Programming/blktrace.html
http://fibrevillage.com/storage/531-how-to-use-blktrace-and-btt-to-debug-and-tune-disk-io-on-linux
http://wiki.dreamrunner.org/public_html/Low_Latency_Programming/blktrace.html
https://bean-li.github.io/blktrace-to-report/