31 Star 102 Fork 78

anolis / SysAK

Create your Gitee Account
Explore and code with more than 8 million developers,Free private repositories !:)
Sign up
Clone or Download
iosdiag.txt 14.40 KB
Copy Edit Web IDE Raw Blame History
guangshui.lgs authored 2022-07-05 02:16 . update doc/iosdiag.txt.
1. iosdiag
iosdiag (IO storage diagnostics tools), IO存储诊断工具,目前包括已实现的IO延迟诊断功能以及IO夯诊断功能
2. 代码目录结构(source/tools/combine/iosdiag目录下)
entry IO诊断功能入口代码
latency IO延迟诊断代码
hangdetect IO夯诊断代码
data_analysis IO诊断数据分析与结果输出代码
3. 编译
在编译sysak的之前,需要在执行configure配置的时候加上--enable-libbpf --enable-target-btf --enable-target-iosdiag才能编译进sysak
4. 运行
4.1 iosdiag latency
IO延迟诊断功能,由于基于eBPF实现,因此需要内核支持并启动eBPF,另外,因为程序运行要依赖内核btf文件,目前sysak仓库默认的只具备如下内核版本的btf:
3.10.0-1062.an7.x86_64
3.10.0-1160.11.1.el7.x86_64
3.10.0-1160.15.2.el7.x86_64
3.10.0-1160.2.1.el7.x86_64
3.10.0-1160.2.2.el7.x86_64
3.10.0-1160.6.1.el7.x86_64
3.10.0-1160.el7.x86_64
4.18.0-193.60.2.an8_2.x86_64
4.18.0-305.an8.x86_64
4.19.24-9.al7.x86_64
4.19.34-11.al7.x86_64
4.19.43-13.2.al7.x86_64
4.19.57-15.1.al7.x86_64
4.19.67-16.al7.x86_64
4.19.81-17.1.al7.x86_64
4.19.81-17.2.al7.x86_64
4.19.91-18.al7.x86_64
4.19.91-19.1.al7.x86_64
4.19.91-21.2.al7.x86_64
4.19.91-21.al7.x86_64
4.19.91-22.1.al7.x86_64
4.19.91-22.2.al7.x86_64
4.19.91-23.al7.x86_64
4.19.91-24.1.al7.x86_64
4.19.91-24.8.an7.x86_64
4.19.91-24.8.an8.x86_64
4.2 iosdiag hangdetect
IO夯诊断功能,目前支持如下内核版本:
3.10.0-1062.1.1.el7.x86_64
3.10.0-1062.12.1.el7.x86_64
3.10.0-1062.1.2.el7.x86_64
3.10.0-1062.18.1.el7.x86_64
3.10.0-1062.4.1.el7.x86_64
3.10.0-1062.4.2.el7.x86_64
3.10.0-1062.4.3.el7.x86_64
3.10.0-1062.7.1.el7.x86_64
3.10.0-1062.9.1.el7.x86_64
3.10.0-1062.el7.x86_64
3.10.0-1127.10.1.el7.x86_64
3.10.0-1127.13.1.el7.x86_64
3.10.0-1127.18.2.el7.x86_64
3.10.0-1127.19.1.el7.x86_64
3.10.0-1127.8.2.el7.x86_64
3.10.0-1127.el7.x86_64
3.10.0-1160.11.1.el7.x86_64
3.10.0-1160.15.2.el7.x86_64
3.10.0-1160.2.1.el7.x86_64
3.10.0-1160.2.2.el7.x86_64
3.10.0-1160.6.1.el7.x86_64
3.10.0-1160.el7.x86_64
3.10.0-862.14.4.el7.x86_64
3.10.0-957.21.3.el7.x86_64
4.19.24-9.al7.x86_64
4.19.81-17.1.al7.x86_64
4.19.81-17.2.al7.x86_64
4.19.91-18.al7.x86_64
4.19.91-19.1.al7.x86_64
4.19.91-19.2.al7.x86_64
4.19.91-21.2.al7.x86_64
4.19.91-21.al7.x86_64
4.19.91-22.1.al7.x86_64
4.19.91-22.2.al7.x86_64
4.19.91-23.4.an8.x86_64
4.19.91-23.al7.x86_64
4.19.91-24.1.al7.x86_64
4.19.91-24.8.an8.x86_64
4.19.91-24.al7.x86_64
4.19.91-25.an8.x86_64
5. 使用
5.1 参数说明
5.1.1 sysak iosdiag -h
Usage: sysak iosdiag [options] subcmd [cmdargs]]
subcmd:
latency, 执行io延迟诊断功能
hangdetect, 执行io夯诊断功能
cmdargs:
-h, 跟在子命令之后显示功能支持参数
options:
-u url, 指定url,将会通过curl命令把诊断日志文件打包上传到此url,不指定不上传
-s latency/hangdetect, 停止诊断
5.1.2 sysak iosdiag latency -h
Usage:
latency [OPTION] disk_devname 检测诊断IO延迟事件
latency -t ms disk_devname 指定超时IO的时间阈值(单位ms),IO时延诊断将过滤完成耗时超过此阈值的IO(默认1000ms)
latency -T sec disk_devname 指定诊断运行时长(单位秒)后自动退出(默认10秒)
latency -f log disk_devname 指定日志文件目录
e.g.
latency vda 诊断访问磁盘vda上耗时1000ms的IO,诊断10s后自动退出
latency -t 10 vda 诊断磁盘"vda"上的io延迟超过10ms的事件
latency -t 10 -T 30 vda 诊断访问磁盘vda上耗时10ms的IO,诊断30s后自动退出
5.1.3 sysak iosdiag hangdetect -h
Usage:
hangdetect [OPTION] disk_devname 检测诊断IO夯事件
hangdetect -t ms disk_devname 指定io夯的时间阈值,超过次时间的未完成的io将被认为是io夯被抓取出来(默认5000ms)
hangdetect -T sec disk_devname 指定诊断运行时长(单位秒)后自动退出(默认10秒)
hangdetect -f log disk_devname 指定日志文件目录
hangdetect -o disk_devname 一旦捕获到io夯程序自动退出
e.g.
hangdetect vda 诊断磁盘"vda"上的io夯事件
hangdetect -t 1000 vda 诊断磁盘"vda"上的io夯住1000ms的事件
hangdetect -t 1000 -o vda 诊断磁盘"vda"上的io夯住1000ms的事件,一经捕获立即退出
hangdetect -T 10 vda 诊断磁盘"vda"上的io夯住事件,诊断10秒后退出
5.2 输出说明
5.2.1 控制台输出---iolatency
运行命令:
sysak iosdiag latency -t 1 -T 20 vda
运行过程日志:
start iosdiag_virtblk load bpf
load iosdiag_virtblk bpf success
running...done
运行结果输出
两个维度,整体IO的延迟分布情况(以百分比展示整体IO的延迟点)+输出延迟最大的前TOPn个IO的最大延迟点以及总延迟
os(block):指IO在OS内核通用块层部分的耗时占比
os(driver):指IO在OS内核磁盘驱动部分的耗时占比
Disk:指IO在硬件磁盘侧的耗时占比
os(complete):指IO在OS内核中,IO消亡流程的耗时占比
```
6 IOs of disk vda over 1 ms, delay distribution:
os(block) delay: 1.639%
os(driver) delay: 0.042%
disk delay: 98.291%
os(complete) delay: 0.0%
The first 6 IOs with the largest delay, more details:
time comm pid iotype datalen abnormal(delay:totaldelay)
2021-11-23 11:27:53.960 kworker/u8:3 86783 WM 4096 disk delay (7.076:7.2 ms)
2021-11-23 11:27:53.960 kworker/u8:3 86783 WM 4096 disk delay (7.076:7.2 ms)
2021-11-23 11:27:53.960 kworker/u8:3 86783 WM 12288 disk delay (7.075:7.2 ms)
2021-11-23 11:27:53.960 kworker/u8:3 86783 WM 4096 disk delay (7.075:7.199 ms)
2021-11-23 11:27:53.960 kworker/u8:3 86783 WM 8192 disk delay (7.077:7.198 ms)
2021-11-23 11:27:53.960 kworker/u8:3 86783 WM 61440 disk delay (7.076:7.193 ms)
more details see /var/log/sysak/iosdiag/latency/result.log*
```
time:检测到延迟IO的时间
comm/pid:进程信息
iotype:此IO类型
datalen:IO大小
abnormal(delay:totaldelay):此IO异常点(此IO在此异常点的耗时:此IO总耗时)
5.2.2 日志文件说明
日志文件中的数据均以磁盘为单位以json数组的方式呈现
/var/log/sysak/iosdiag/latency/result.log
该日志文件描述的是每一个延迟IO的事件信息
```
{
"summary":[ //以磁盘为一个单位的数组
{
"diskname":"vda", //磁盘盘符
"slow ios":[ //每一个该磁盘下的io为一个单位的数组
{
"time":"2021-11-23 14:42:10.657", //检测到次超时IO的时间
"abnormal":"disk delay (145.56:256.88 ms)", //此IO的延迟最大的点(延迟最大的组件的延迟:总延迟)
"iotype":"W", //此IO类型
"sector":23695488, //此IO访问磁盘的具体偏移位置
"datalen":4096, //次IO访问磁盘的数据量
"comm":"kworker/u12:2", //发起此IO的进程
"pid":11943, //进程ID
"cpu":"2 -> 4 -> 4" //发起此IO的CPU -> 响应IO完成之后磁盘中断的CPU -> 磁盘IO完成后执行软中断的CPU
//如只显示一个CPU编号,说明发起IO和执行中断的CPU相同,要注意也有磁盘是没有软中断流程的
},
{第二个IO事件信息},
...
]
},
{第二个磁盘},
...
]
}
```
/var/log/sysak/iosdiag/latency/result.log.seq
该日志文件描述的是每一个延迟IO在各组建的延迟分布
```
{
"summary":[ //以磁盘为一个单位的数组
{
"diskname":"vda", //磁盘盘符
"slow ios":[ //每一个该磁盘下的io延迟信息为一个单位的数组
{
"time":"2021-11-23 14:42:10.657", //检测到次超时IO的时间
"totaldelay":256884, //此IO总耗时
"delays":[ //以此IO的每个组件的延迟情况为单位的数组,目前涉及的组建为:block、driver、disk、complete
{
"component":"block", //组建名
"delay":111300 //此IO在该组建的时延,单位us
},
{
"component":"driver",
"delay":25
},
{
"component":"disk",
"delay":145557
},
{
"component":"complete",
"delay":2
}
]
},
{第二个IO延迟信息},
...
]
},
{第二个磁盘},
...
]
}
```
/var/log/sysak/iosdiag/latency/result.log.stat
该日志文件描述的是在磁盘角度,所有IO的延迟分布统计信息
```
{
"summary":[ //以磁盘为一个单位的数组
{
"diskname":"vda", //磁盘盘符
"delays":[ //以每个组件的延迟情况为单位的数组,目前涉及的组建为:block、driver、disk、complete
{
"component":"os(block)", //组建名
"percent":"17.147%", //在捕获的该磁盘的IO中,经统计在此组件耗时的百分比
"max":143422, //在此组件的最大耗时,单位us
"min":76, //在此组件的最小耗时,单位us
"avg":24518 //在此组件的平均耗时,单位us
},
{"os(driver)" 延迟情况},
{"disk" 延迟情况},
{ "os(complete)" 延迟情况}
]
},
{第二个磁盘},
...
]
}
```
5.2.3 控制台输出---iohang
运行命令:
sysak iosdiag hangdetect -t 1 -T 10 vda(此处假设检测io夯住1ms的io)
hang detect stop!
控制台输出结果:
两个维度,整体IO夯分布情况(以百分比展示)+输出io夯住时长最大的前TOPn个IO
OS :指IO在OS内核夯住事件数的占比
Disk:指IO在磁盘夯住事件数的占比
```
402 IOs hung of disk vda2, IO hung distribution:
Disk delay: 100.0%
OS delay: 0.0%
The first 10 IOs with the largest delay, more details:
time comm pid iotype sector datalen abnormal file
2022-7-4 17:54:52.133 - - WRITE 27663632 4096 Disk(Waitting for disk handle) hang 0.005 s -
2022-7-4 17:54:52.133 - - WRITE 27663664 4096 Disk(Waitting for disk handle) hang 0.005 s -
2022-7-4 17:54:52.133 - - WRITE 27664088 4096 Disk(Waitting for disk handle) hang 0.005 s -
2022-7-4 17:54:52.133 - - WRITE 27664192 8192 Disk(Waitting for disk handle) hang 0.005 s -
2022-7-4 17:54:52.133 - - WRITE 27664240 4096 Disk(Waitting for disk handle) hang 0.005 s -
2022-7-4 17:54:52.133 - - WRITE 27663688 8192 Disk(Waitting for disk handle) hang 0.005 s -
2022-7-4 17:54:52.133 - - WRITE 27663752 4096 Disk(Waitting for disk handle) hang 0.005 s -
2022-7-4 17:54:52.133 - - WRITE 27663832 4096 Disk(Waitting for disk handle) hang 0.005 s -
2022-7-4 17:54:52.133 - - WRITE 27663848 4096 Disk(Waitting for disk handle) hang 0.005 s -
2022-7-4 17:54:52.133 - - WRITE 27663904 8192 Disk(Waitting for disk handle) hang 0.005 s -
more details see /var/log/sysak/iosdiag/hangdetect/result.log*
```
time:检测到IO夯的时间,往前推io夯住的时长,可以得到IO的发起时间
comm/pid:进程信息,需要跟-e参数才能展示,默认不展示
iotype:此IO类型
sector:IO起始扇区
datalen:IO大小
abnormal:此IO夯住点(夯住的原因)已夯住时长
file:夯住的io关联的文件,需要跟-e参数才能展示,如下所示,默认不展示
```
time comm pid iotype sector datalen abnormal file
2022-7-4 18:1:49.925 syslog-ng 37270 WRITE 27663216 4096 Disk(Waitting for disk handle) hang 0.005 s //var/log/journal/da4b86843a464cc18ac897729463ef74/system.journal
...
```
5.2.4 日志文件说明---iohang
日志文件中的数据均以磁盘为单位以json数组的方式呈现
/var/log/sysak/iosdiag/hangdetect/result.log
该日志文件描述的是每一个IO夯的事件信息
```
{
"summary":[ //以磁盘为一个单位的数组
{
"diskname":"vda", //磁盘盘符
"hung ios":[ //每一个该磁盘下的io为一个单位的数组
{
"time":"2022-7-4 18:1:49.921", //检测到此IO夯的时间
"abnormal":"Disk(Waitting for disk handle) hang 0.001 s", //此IO夯住点(夯住的原因)已夯住时长
"iotype":"WRITEW", //此IO类型
"sector":27658296, //此IO访问磁盘的具体偏移位置
"datalen":4096, //次IO访问磁盘的数据量
"iostate": "in_flight", //此io状态,in_flight表示未完成
"cpu": 1, //发起此IO的cpu
"comm": "syslog-ng", //发起此IO的进程,这一项可能因为获取不到为'-'
"pid": 37270, //进程ID,这一项可能因为获取不到为'-'
"file": "//var/log/journal/da4b86843a464cc18ac897729463ef74/system.journal" //此IO关联文件,这一项可能因为获取不到为'-'
},
{第二个IO事件信息},
...
]
},
{第二个磁盘},
...
]
}
```
/var/log/sysak/iosdiag/hangdetect/result.log.stat
该日志文件描述的是OS和磁盘夯住IO分布占比
```
{
"summary":[ //以磁盘为一个单位的数组
{
"diskname":"vda", //磁盘盘符
"hung ios":[ //每一个该磁盘下的io夯信息为一个单位的数组
{
"component": "OS", //统计夯在OS的io数
"count": 0, //此IO总耗时
"percent": "0.0%",
"max": 0,
"min": 0,
"avg": 0
},
{
"component": "Disk", //统计夯在磁盘的io数
"count": 437, //夯住的io数
"percent": "100.0%", //夯住的io占比
"max": 5412, //io夯住的最大时长us
"min": 1070, //io夯住的最小时长us
"avg": 3713 //io夯住的平均时长us
}
]
},
{第二个磁盘},
...
]
}
```
/var/log/sysak/iosdiag/hangdetect/result.log.seq
该日志文件描述的是每一个夯住IO的请求信息,展示的都是内核层面的信息,此处不在详细展开,有兴趣者可以参照具体的代码查阅
1
https://gitee.com/anolis/sysak.git
git@gitee.com:anolis/sysak.git
anolis
sysak
SysAK
opensource_branch

Search