首页 > 利用blktrace分析磁盘I/O

利用blktrace分析磁盘I/O

原文:https://blog.csdn.net/ygtlovezf/article/details/80528300

blktrace对于分析block I/O是个非常好的工具,本篇文章记录了如何使用blktrace。

blktrace原理

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

blktrace主要由3部分组成:

内核部分

  • 记录内核到用户空间的I/O追踪信息的程序
  • 分析、展示I/O追踪信息的程序
  • 主要在block layer实现,抓取的数据通过debugfs来传递。每个被跟踪的设备都有一个在debugfs挂载目录的文件。debugfs挂载目录默认是:/sys/kernel/debug

用官方的一张图来直观的展现:

一个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包
    yum
    install
    blktrace
    
  • 追踪指定设备的I/O
    [root@k8s-slave9 longterm_io]
    # blktrace -d /dev/sde
    ^C=== sde ===CPU  0:                   38 events,        2 KiB dataCPU  1:                    1 events,        1 KiB dataCPU  2:                  232 events,       11 KiB dataCPU  3:                    2 events,        1 KiB dataCPU  4:                   41 events,        2 KiB data...Total:                   567 events (dropped 0),       27 KiB data
    

-d 指定具体的设备名

上面是抓取一段时间后,Ctrl+C中止的。也可以指定时间:-w

blktrace执行完之后,会生产很多文件,每个CPU都会有一个文件,文件名组成:<设备名>.blktrace.,如下:

[root@k8s-slave9 longterm_io]ls
sde.blktrace.0   sde.blktrace.12  sde.blktrace.16  sde.blktrace.2   sde.blktrace.23  sde.blktrace.27  sde.blktrace.30  sde.blktrace.34  sde.blktrace.38  sde.blktrace.6
...

抓取IO信息,完成了第一步,我们要分析这些I/O,就需要下面的工具。

blkparse分析数据

  • 解析IO追踪信息

    blkparse是一个会把不同CPU的I/O trace文件合并,并解析、格式化输出为对用户可读友好IO信息的工具。

    先把上面生成的所有CPU I/O trace文件合并成一个文件:

    [root@k8s-slave9 longterm_io]
    # blkparse -i sde -d sde.blktrace.bin
    Input
    file
    sde.blktrace.0 added
    Input
    file
    sde.blktrace.1 added
    Input
    file
    sde.blktrace.2 added
    Input
    file
    sde.blktrace.3 added
    Input
    file
    sde.blktrace.4 added
    ...
    -----------------------------第一个IO开始8,64  35        1     0.000000000 28378  A   W 470236984 + 40 <- (8,65) 470234936  
    8,64  35        2     0.000000670 28378  Q   W 470236984 + 40 [kworker
    /u82
    :1]  
    8,64  35        3     0.000005125 28378  G   W 470236984 + 40 [kworker
    /u82
    :1]  
    8,64  35        4     0.000005443 28378  P   N [kworker
    /u82
    :1]  
    8,64  35        5     0.000009123 28378  I   W 470236984 + 40 [kworker
    /u82
    :1]  
    8,64  35        6     0.000009978 28378  U   N [kworker
    /u82
    :1] 1  
    8,64  35        7     0.000010638 28378  D   W 470236984 + 40 [kworker
    /u82
    :1]  
    8,64  31        1     0.207382887     0  C   W 470236984 + 40 [0]
    -----------------------------第一个IO完成
    -----------------------------第二个IO开始8,64   2        1    10.239998442  4861  A FWFSM 469242512 + 2 <- (8,65) 469240464 
    8,64   2        2    10.239999862  4861  Q FWFSM 469242512 + 2 [kworker
    /2
    :0H]  
    8,64   2        3    10.240004505  4861  G FWFSM 469242512 + 2 [kworker
    /2
    :0H]  
    8,64   2        4    10.240005325  4861  P   N [kworker
    /2
    :0H]  
    8,64   2        5    10.240007109  4861  I FWFSM 469242512 + 2 [kworker
    /2
    :0H]  
    8,64   2        6    10.240008795  4861  U   N [kworker
    /2
    :0H] 1  
    8,64   4        1    10.482792539     0  D WFSM 469242512 + 2 [swapper
    /0
    ]  
    8,64   8        1    10.492646670     0  C WFSM 469242512 + 2 [0]
    -----------------------------第二个IO完成
    ...
    CPU0 (sde): 
    Reads Queued:           1,        8KiB     Writes Queued:           3,      172KiB 
    Read Dispatches:        1,        8KiB     Write Dispatches:        3,      172KiB 
    Reads Requeued:         0         Writes Requeued:         0 
    Reads Completed:        1,        8KiB     Writes Completed:        3,      172KiB
    Read Merges:            0,        0KiB     Write Merges:            0,        0KiB
    Read depth:             1             Write depth:             4
    IO unplugs:             4             Timer unplugs:           0
    ...
    Total (sde): 
    Reads Queued:          23,      184KiB     Writes Queued:          41,      652KiB
    Read Dispatches:       23,      184KiB     Write Dispatches:       36,      653KiB 
    Reads Requeued:         0         Writes Requeued:         0 
    Reads Completed:       23,      184KiB     Writes Completed:       53,      653KiB
    Read Merges:            0,        0KiB     Write Merges:            5,       91KiB 
    IO unplugs:            57             Timer unplugs:           0
    Throughput (R
    /W
    ): 0KiB
    /s
    / 1KiB
    /s
    Events (sde): 500 entries
    Skips: 0 forward (0 -   0.0%)
    

    中间那段I/O处理阶段说明:

    第一列:设备号 主设备号,次设备号

    第二列:CPU

    第三列:顺序号

    第五列:时间戳

    第六列:PID 进程号

    第七列:具体事件

    第八列:具体的读写操作

       W:WriteR:ReadS:SyncFWF:第一个F是Flush,W还是Write,第二个F是FUA(force unit acess)M:MetadataD:DiscardB:Barrier从抓取的I/O来看,所有I2D耗时比较长的都是FWFSM的操作。
    

    第九列:磁盘起始块+操作的块的数量

    第十列:进程名或具体的命令

    通过这些输出,我们就可以明确看到,每个阶段的具体耗时,就可以定位I/O慢在哪个阶段,也是需要深入的分析什么原因导致的。

  • 具体动作(或事件)的字母代表意义:

    • A remap 对于栈式设备,进来的I/O将被重新映射到I/O栈中的具体设备
    • X split 对于做了Raid或进行了device mapper(dm)的设备,进来的IO可能需要切割,然后发送给不同的设备
    • Q queued I/O进入block layer,将要被request代码处理(即将生成IO请求)
    • 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处理被磁盘处理完成。

btt分析数据

   blkparse只是将blktrace数据转成可以人工阅读的格式,由于数据量通常很大,人工分析并不轻松。btt是对blktrace数据进行自动分析的工具。
  • 使用btt解析数据,查看I/O的整体情况

    [root@k8s-slave9 longterm_io]
    # btt -i sde.blktrace.bin
    ==================== All Devices ====================ALL           MIN           AVG           MAX           N
    --------------- ------------- ------------- ------------- -----------Q2Q               0.000002013   7.354920889  30.208019079          63
    Q2G               0.000000889   0.000003898   0.000016826          59
    G2I               0.000000591   0.000003383   0.000035937          59
    Q2M               0.000000333   0.000001295   0.000002440           5
    I2D               0.000000503   0.065649284   0.252996244          59
    M2D               0.000003840   0.000011816   0.000017717           5
    D2C               0.000128883   0.056202494   0.254664063          64
    Q2C               0.000131324   0.116730664   0.262633229          64==================== Device Overhead ====================DEV |       Q2G       G2I       Q2M       I2D       D2C
    ---------- | --------- --------- --------- --------- ---------(  8, 64) |   0.0031%   0.0027%   0.0001%  51.8462%  48.1472%
    ---------- | --------- --------- --------- --------- ---------Overall |   0.0031%   0.0027%   0.0001%  51.8462%  48.1472%==================== Device Merge Information ====================DEV |      
    #Q       #D   Ratio |   BLKmin   BLKavg   BLKmax    Total
    ---------- | -------- -------- ------- | -------- -------- -------- --------(  8, 64) |       64       59     1.1 |        2       28      176     1675
    ...
    

    第一个表的第一列是具体的I/O阶段,第二、三、四列分别是最小耗时、平均耗时、最大耗时(单位:s),第五列是I/O数。

    第二个表是对第一个表做了耗时统计,看看整个I/O阶段,哪个阶段耗时占用最多。

    第三个表是进行合并的信息,但是从内容来看,没有merge信息啊。后面有所有I/O中操作的块数量的最小值、平均值、最大值。

    IO处理阶段:

    Q2Q: 相邻两次进入通用块层的I/O间隔

    Q2G:I/O进入block layer到I/O请求(request)生成的时间

    G2I :I/O请求生成到被插入I/O请求队列(request queue)的时间

    Q2M:I/O进入block层到该I/O被和已存在的I/O请求合并的时间

    I2D :I/O请求进入request queue队到分发到设备驱动的时间

    M2D:I/O合并成I/O请求到分发到设备驱动的时间

    D2C:I/O分到到设备驱动到设备处理完成时间

    在上述过程中,Q2M、M2D两个阶段不是必然发生的,只有可以merge的I/O才会进行合并。

  • 生产不同维度的报告

    查看所有I/O D2C阶段的具体延时: (-l参数将会分析D2C阶段延迟,该参数后是具体的输出文件名)

    [root@k8s-slave9 longterm_io]
    # btt -i sde.blktrace.bin -l sde.d2c_latency
    ==================== All Devices ====================ALL           MIN           AVG           MAX           N
    --------------- ------------- ------------- ------------- -----------Q2Q               0.000002013   7.354920889  30.208019079          63
    Q2G               0.000000889   0.000003898   0.000016826          59
    G2I               0.000000591   0.000003383   0.000035937          59
    Q2M               0.000000333   0.000001295   0.000002440           5
    I2D               0.000000503   0.065649284   0.252996244          59
    M2D               0.000003840   0.000011816   0.000017717           5
    D2C               0.000128883   0.056202494   0.254664063          64
    Q2C               0.000131324   0.116730664   0.262633229          64
    ...
    

    执行完上面的命令后,会有如下文件生成:

    [root@k8s-slave9 longterm_io]
    # ls *.dat
    8,64_iops_fp.dat  8,64_mbps_fp.dat  sde.d2c_latency_8,64_d2c.dat  sys_iops_fp.dat  sys_mbps_fp.dat
    

    如上输出,可以看到:有这段时间的IOPS统计(8,64_iops_fp.dat、sys_iops_fp.dat)、带宽统计(8,64_mbps_fp.dat、sys_mbps_fp.dat)、延迟统计(sde.d2c_latency_8,64_d2c.dat)

    我们看看这些文件:

    每个时间点的I
    /O
    个数:
    [root@k8s-slave9 longterm_io]
    # cat sys_iops_fp.dat
    0 1
    10 1
    31 1
    40 1
    44 1
    66 1
    70 1
    100 5
    ...每个时间点的带宽:
    [root@k8s-slave9 longterm_io]
    # cat sys_mbps_fp.dat
    0 0.019531
    10 0.000977
    31 0.031250
    40 0.000977
    44 0.003906
    66 0.015625
    70 0.002441
    100 0.048828
    ...每个时间点的D2C阶段延迟:
    [root@k8s-slave9 longterm_io]
    # cat sde.d2c_latency_8,64_d2c.dat
    0.207383 0.207372
    10.492647 0.009854
    31.439889 0.207854
    40.700689 0.009720
    44.381372 0.206810
    44.381372 0.206810
    66.564038 0.004049
    70.907380 0.008502
    100.047822 0.207767
    ...
    

    其中,第一列是时间戳,第二列是具体的内容

    查看所有I/O的size、offset等信息:(-B参数将会输出具体的block号,包括起始block、终止block)

    [root@k8s-slave9 longterm_io]
    # btt -i sde.blktrace.bin -B sde.offset
    ==================== All Devices ====================ALL           MIN           AVG           MAX           N
    --------------- ------------- ------------- ------------- -----------Q2Q               0.000002013   7.354920889  30.208019079          63
    Q2G               0.000000889   0.000003898   0.000016826          59
    G2I               0.000000591   0.000003383   0.000035937          59
    Q2M               0.000000333   0.000001295   0.000002440           5
    I2D               0.000000503   0.065649284   0.252996244          59
    M2D               0.000003840   0.000011816   0.000017717           5
    D2C               0.000128883   0.056202494   0.254664063          64
    Q2C               0.000131324   0.116730664   0.262633229          64
    ...
    

    上述命令将输出如下的文件:

    [root@k8s-slave9 longterm_io]
    # ls | grep offset
    sde.offset_8,64_c.dat
    sde.offset_8,64_r.dat
    sde.offset_8,64_w.dat
    xxx_r.dat:读操作相关信息
    xxx_w.dat:写操作相关信息xxx_c.dat:所有操作,读写都有
    

    我们看看写操作:

    [root@k8s-slave9 longterm_io]
    # cat sde.offset_8,64_w.dat0.000010638 470236984 47023702410.482792539 469242512 46924251431.232035019 470237016 47023708040.690968712 469242514 46924251644.174561925 703299792 70329980066.559989117 470237072 47023710470.898878399 469242516 46924252199.840054977 470237096 470237152100.864256898 703277841 703277843...
    

    其中第一列是时间戳,第二列是I/O操作的起始block号,第三列是I/O操作的终止block号。

参考

https://www.mimuw.edu.pl/~lichota/09-10/Optymalizacja-open-source/Materialy/10 - Dysk/gelato_ICE06apr_blktrace_brunelle_hp.pdf

http://fibrevillage.com/storage/539-blktrace-and-btt-example-to-debug-and-tune-disk-i-o-on-linux

更多相关:

  • 1.分类Category的使用// 给MJPerson类添加分类 @interface MJPerson : NSObject - (void)run; @end@implementation MJPerson - (void)abc{} - (void)run{NSLog(@"MJPerson - run");} + (void)...

  • 首先概括一下这几个概念。其中SM(Streaming Multiprocessor)和SP(streaming Processor)是硬件层次的,其中一个SM可以包含多个SP。thread是一个线程,多个thread组成一个线程块block,多个block又组成一个线程网格grid。 现在就说一下一个kenerl函数是怎么执行的。一...

  • 下面的程序输出什么?思考一下 #include // Driver Code int main() {{int x = 10, y = 20;{// The outer block contains// declaration of x and// y, so following statement// is va...

  • 限流器是后台服务中十分重要的组件,在实际的业务场景中使用居多,其设计在微服务、网关、和一些后台服务中会经常遇到。限流器的作用是用来限制其请求的速率,保护后台响应服务,以免服务过载导致服务不可用现象出现。限流器的实现方法有很多种,例如 Token Bucket、滑动窗口法、Leaky Bucket等。在 Golang 库中官方给我们提供...

  • HTTP和HTTPSHTTP协议(HyperText Transfer Protocol,超文本传输协议):是一种发布和接收 HTML页面的方法。HTTPS(Hypertext Transfer Protocol over Secure Socket Layer)简单讲是HTTP的安全版,在HTTP下加入SSL层。SSL(Secure...

  •     注意!!!(修改于2020年7月18日)   在安卓9.0以下或者IOS10.X以下手机端H5页面不支持,在这两种情况下的系统只能使用ajax或者原生js请求后台数据 报错截图如下 报错内容: {"message": "Network Error","name": "Error","stack": "Err...

  • 一.  GET_POST与开发者工具 1.      浏览器的基本工作规则 浏览器请求访问服务器,服务器返回数据 (1)    请求的格式 GET:长度不能大于2k参数明文显示在地址栏,不保密,通常用在查询请求 POST:长度可以很大,参数写在请求体内,相对保密,通常用是提交内容的请求 上图中a.com是域名,x...

  • JSP相当于在HTML页面中加上Java代码,一般在标签中放入主要代码。 在JSP里用<%...%>把Java代码包含起来的。   Servlet的生命周期: ①被服务器实例化后,容器运行init方法。 ②当请求(Request)到达时,运行service方法,service方法会运行与请求对应的doXXX方法(d...

  • 主要是在bluestore的实例上执行低级管理操作的使用程序,是ceph bluestore的管理工具 命令 help显示帮助信息fsck [--deep]对bluestore元数据进行一致性检查。如果指定了–deep,还要读取所有对象数据并验证校验和repair运行一致性检查 并修复我们可以发生的任何错误bluefs-ex...

  • iOS获取设备唯一标识的各种方法?IDFA、IDFV、UDID分别是什么含义?iOS获取设备ID总结IDFA解释 关于UUID的理解 : 英文名称是:Universally Unique Identifier,翻译过来就是通用唯一标识符。 UUID是指在一台机器上生成的数字,它保证对在同一时空中的所有机器都是唯一的。通常平台会提...

  • Running Your Application 原文演示了怎样在真机和模拟器上运行你的App。 原文链接:http://developer.android.com/training/basics/firstapp/running-app.html 译文链接:http://android.toolib.net/training/bas...

  • 转:http://blog.csdn.net/zhouzhuan2008/article/details/11053877   目录 MTD总概述MTD数据结构 MTD相关层实现 MTD,Memory Technology Device即内存技术设备 字符设备和块设备的区别在于前者只能被顺序读写,后者可以随机访问;同时,两者读写数...

  • 设备管理器架构 ----Windows Embedded CE 6.0 R3   原文:http://msdn.microsoft.com/en-us/library/ee484004(v=WinEmbedded.60).aspx   设备管理器运行在Windows Embedded CE操作系统下,跟踪加载的驱动及其接口。它从内核中...