背景信息:
遇到一个IO异常飙升的问题,IO起飞后系统响应异常缓慢,看不到现场一直无法定位问题,检查对应时间点应用日志也没有发现异常的访问,这种问题怎么办呢?
1,采集系统IO,确认IO异常发生在系统盘,还是数据盘,使用系统自带的iostat即可采集
# iostat -d 3 -k -x -t 30
06/12/2018 09:52:33 AM
Device: rrqm/s wrqm/s r/s w/s rkB/s wkB/s avgrq-sz avgqu-sz await svctm %util
xvda 0.00 0.39 0.08 0.70 1.97 5.41 18.81 0.03 44.14 1.08 0.08
xvdb 0.00 0.00 0.00 0.00 0.00 0.00 8.59 0.00 1.14 1.09 0.00
06/12/2018 09:52:36 AM
Device: rrqm/s wrqm/s r/s w/s rkB/s wkB/s avgrq-sz avgqu-sz await svctm %util
xvda 0.00 0.00 0.00 0.67 0.00 2.68 8.00 0.00 1.00 0.50 0.03
xvdb 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00
每隔3秒采集一次磁盘io,输出时间,一共采集30次,想一直抓的话把30去掉即可,注意磁盘空余量
通过这个命令我们可以确认如下信息:
- 问题发生的时间
- 哪块盘发生的io
- 磁盘的 IOPS( r/s w/s)以及吞吐量( rkB/s wkB/s )
2,确认哪块盘发生了IO还不够,再抓一下发生IO的进程,需要安装 iotop 进行捕获
# iotop -b -o -d 3 -t -qqq -n 30
10:18:41 7024 be/4 root 0.00 B/s 2.64 M/s 0.00 % 93.18 % fio -direct=1 -iodepth=128 -rw=randwrite -ioengine=libaio -bs=1k -size=1G -numjobs=1 -runtime=1000 -group_reporting -filename=iotest -name=Rand_Write_Testing
每隔3秒采集一次,一共采集30次,静默模式,只显示有io发生的进程
通过这个命令我们可以确认如下信息:
- 问题发生的时间
- 产生IO的进程id以及进程参数(command)
- 进程产生的吞吐量(如果有多个可以把qqq去掉可显示总量)
- 进程占用当前IO的百分比
俗话说得好,光说不练假把式,我们实操来看一下(涉及用户进程信息,没有得到客户授权因此以fio为演示)
3, 使用 fio 进行 IO 压测,详细参数我就不讲了,有兴趣的同学看下块存储性能
压测窗口:
# fio -direct=1 -iodepth=128 -rw=randwrite -ioengine=libaio -bs=1k -size=1G -numjobs=1 -runtime=1000 -group_reporting -filename=iotest -name=Rand_Write_Testing
Rand_Write_Testing: (g=0): rw=randwrite, bs=1K-1K/1K-1K/1K-1K, ioengine=libaio, iodepth=128
fio-2.0.13
Starting 1 process
^Cbs: 1 (f=1): [w] [8.5% done] [0K/2722K/0K /s] [0 /2722 /0 iops] [eta 05m:53s]
fio: terminating on signal 2
Rand_Write_Testing: (groupid=0, jobs=1): err= 0: pid=11974: Tue Jun 12 10:36:30 2018
write: io=88797KB, bw=2722.8KB/s, iops=2722 , runt= 32613msec
......
iotop窗口:
# iotop -n 10 -b -o -d 3 -t -qqq
10:36:03 11974 be/4 root 0.00 B/s 2.63 M/s 0.00 % 93.95 % fio -direct=1 -iodepth=128 -rw=randwrite -ioengine=libaio -bs=1k -size=1G -numjobs=1 -runtime=1000 -group_reporting -filename=iotest -name=Rand_Write_Testing
10:36:06 11974 be/4 root 0.00 B/s 2.64 M/s 0.00 % 92.68 % fio -direct=1 -iodepth=128 -rw=randwrite -ioengine=libaio -bs=1k -size=1G -numjobs=1 -runtime=1000 -group_reporting -filename=iotest -name=Rand_Write_Testing
iostat窗口:
# iostat -d 3 -k -x -t 10
Linux 2.6.32-431.23.3.el6.x86_64 (test) 06/12/2018 _x86_64_ (1 CPU)
06/12/2018 10:36:03 AM
Device: rrqm/s wrqm/s r/s w/s rkB/s wkB/s avgrq-sz avgqu-sz await svctm %util
xvda 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00
xvdb 0.00 10.80 0.00 2823.69 0.00 2837.63 2.01 132.97 47.00 0.37 104.53
06/12/2018 10:36:06 AM
Device: rrqm/s wrqm/s r/s w/s rkB/s wkB/s avgrq-sz avgqu-sz await svctm %util
xvda 0.00 0.00 0.00 2.76 0.00 11.03 8.00 0.00 1.62 0.62 0.17
xvdb 0.00 17.24 0.00 2788.28 0.00 2805.17 2.01 131.50 47.20 0.37 103.45
通过输出结果的时间点进行对比分析,相对于 fio 的 IOPS,吞吐量 跟 iotop 以及 iostat 监控到的数据是一致。因此,看到这,您已经学会怎么查消耗IO的进程了
注意:为了压测的慢一些我特意把bs设置为1k,这样执行的时间会比较久,fio压测详见前面的块存储性能
牧原辣么长!怎么可能到这就结束了呢!
心细的同学可能发现 iotop 输出不带年月日,如果抓日志的时间超过24小时,时间重复怎么办?
彩弹:
# iotop -b -o -d 1 -qqq |awk '{ print $0"\t" strftime("%Y-%m-%d-%H:%M:%S",systime()) } '
16209 be/4 root 0.00 B/s 2.64 M/s 0.00 % 93.72 % fio -direct=1 -iodepth=128 -rw=randwrite -ioengine=libaio -bs=1k -size=1G -numjobs=1 -runtime=1000 -group_reporting -filename=iotest -name=Rand_Write_Testing 2018-06-12-10:54:10
16209 be/4 root 0.00 B/s 2.63 M/s 0.00 % 93.61 % fio -direct=1 -iodepth=128 -rw=randwrite -ioengine=libaio -bs=1k -size=1G -numjobs=1 -runtime=1000 -group_reporting -filename=iotest -name=Rand_Write_Testing 2018-06-12-10:54:11
详细参数就不讲了,大家可以看下输出结果行最后一列是年月日时分秒,那么 IO 消耗的始作俑者会查了吗?