(一)简述
每天都收到磁盘iowait告警信息,尤其是日志服务器在进行大量的读写操作过程中,从而造成系统处于崩溃边缘,为查找磁盘iowait由于什么原因造成的以及后续的系统的优化点。centos有许多查找问题的工具,也有高级的。
I/O Wait 就是一个需要使用高级的工具来debug的问题,当然也有许多基本工具的高级用法。I/O wait的问题难以定位的原因 是因为我们有很多工具可以告诉你说I/O 受限了,但是并没有告诉你具体是哪些进程们引起的。
具体的思路如下:top 。查看由cpu一行浪费在iowait上的cpu百分比 =>iostat -x 2 5 查看某块磁盘正在被写入 => iotop 查找最高的磁盘I/O对应的进程 => lsof -p pid 查看通过一个进程打开所有文件或打开一个文件的所有进程。
(二)具体步骤如下:
(1)通过top命令来确认是否是I/O导致系统缓慢。
[root@iZ23iod5vslZ ~]# top top - 15:38:32 up 40 days, 5:59, 3 users, load average: 0.00, 0.01, 0.05 Tasks: 128 total, 1 running, 127 sleeping, 0 stopped, 0 zombie %Cpu(s): 0.4 us, 0.2 sy, 0.0 ni, 99.2 id, 98 wa, 0.0 hi, 0.0 si, 0.1 st KiB Mem: 32520424 total, 31492136 used, 1028288 free, 412772 buffers KiB Swap: 0 total, 0 used, 0 free. 25902892 cached Mem PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND 18988 root 20 0 11.647g 3.611g 7896 S 2.7 11.6 507:57.30 java 28 root 20 0 0 0 0 S 0.3 0.0 6:43.31 rcuos/3 1 root 20 0 49556 3412 1912 S 0.0 0.0 0:14.60 systemd 2 root 20 0 0 0 0 S 0.0 0.0 0:00.01 kthreadd 3 root 20 0 0 0 0 S 0.0 0.0 0:48.28 ksoftirqd/0 5 root 0 -20 0 0 0 S 0.0 0.0 0:00.00 kworker/0:0H 7 root rt 0 0 0 0 S 0.0 0.0 0:00.83 migration/0 8 root 20 0 0 0 0 S 0.0 0.0 0:00.00 rcu_bh 9 root 20 0 0 0 0 S 0.0 0.0 0:00.00 rcuob/0 10 root 20 0 0 0 0 S 0.0 0.0 0:00.00 rcuob/1 11 root 20 0 0 0 0 S 0.0 0.0 0:00.00 rcuob/2 12 root 20 0 0 0 0 S 0.0 0.0 0:00.00 rcuob/3 13 root 20 0 0 0 0 S 0.0 0.0 0:00.00 rcuob/4 14 root 20 0 0 0 0 S 0.0 0.0 0:00.00 rcuob/5 15 root 20 0 0 0 0 S 0.0 0.0 0:00.00 rcuob/6 16 root 20 0 0 0 0 S 0.0 0.0 0:00.00 rcuob/7
从Cpu一行我们可以看到浪费在I/O Wait上的CPU百分比;这个数字越高说明越多的CPU资源在等待I/O权限.具体的解释如下:
0.4% us 用户空间占用CPU的百分比。
0.2% sy 内核空间占用CPU的百分比。
0.0% ni 改变过优先级的进程占用CPU的百分比
2% id 空闲CPU百分比
98% wa IO等待占用CPU的百分比
0.0% hi 硬中断(Hardware IRQ)占用CPU的百分比
0.0% si 软中断(Software Interrupts)占用CPU的百分比
在这里CPU的使用比率和windows概念不同,如果你不理解用户空间和内核空间,需要充充电了
(2)通过iostat -x 3 3 查看那块磁盘正在被写入。
[root@iZ23iod5vslZ ~]# iostat -x 3 3 Linux 3.10.0-123.9.3.el7.x86_64 (iZ23iod5vslZ) 08/14/2017 _x86_64_ (4 CPU) avg-cpu: %user %nice %system %iowait %steal %idle 0.70 0.00 0.16 0.75 0.05 98.34 Device: rrqm/s wrqm/s r/s w/s rkB/s wkB/s avgrq-sz avgqu-sz await r_await w_await svctm %util xvda 0.00 21.18 0.32 18.33 9.94 195.06 21.98 0.08 4.11 11.44 3.98 1.54 2.88 xvdb 0.00 15.21 1.23 1.98 38.41 68.76 66.70 0.08 25.48 3.59 39.10 1.09 0.35 xvdc 0.00 0.07 0.00 0.91 0.00 36.25 79.43 0.10 106.88 12.53 106.92 1.33 0.12 avg-cpu: %user %nice %system %iowait %steal %idle 0.75 0.00 0.17 0.08 0.08 98.91 Device: rrqm/s wrqm/s r/s w/s rkB/s wkB/s avgrq-sz avgqu-sz await r_await w_await svctm %util xvda 0.00 2.33 0.00 0.67 0.00 12.00 36.00 0.00 5.50 0.00 5.50 5.50 0.37 xvdb 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 xvdc 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 avg-cpu: %user %nice %system %iowait %steal %idle 0.75 0.00 0.17 0.00 0.00 99.08 Device: rrqm/s wrqm/s r/s w/s rkB/s wkB/s avgrq-sz avgqu-sz await r_await w_await svctm %util xvda 0.00 3.33 0.00 1.67 0.00 34.67 41.60 0.01 3.00 0.00 3.00 1.60 100.27 xvdb 0.00 9.00 0.00 1.67 0.00 42.67 51.20 0.01 5.40 0.00 5.40 1.80 0.30 xvdc 0.00 0.33 0.00 0.67 0.00 4.00 12.00 0.00 2.00 0.00 2.00 2.00 0.13
每隔三秒更新一次,一共打印了三次。 -x时打印出扩展选项。第一次打印的信息可以被忽略,剩下的报告,都是基于上一次间隔的时间打印出来。
上述的列子中xvda的 %util(利用率)是100.27%,有进程往磁盘中写入数据。
(3)通过iotop查找高I/O对应的进程
[root@iZ23iod5vslZ ~]# iotop Total DISK READ : 0.00 B/s | Total DISK WRITE : 15.67 K/s Actual DISK READ: 0.00 B/s | Actual DISK WRITE: 0.00 B/s TID PRIO USER DISK READ DISK WRITE SWAPIN IO> COMMAND 18793 be/4 root 0.00 B/s 3.92 K/s 0.00 % 0.00 % java -Djava.util.logging.config.file=/usr/to~p org.apache.catalina.startup.Bootstrap start 18987 be/4 root 0.00 B/s 3.92 K/s 0.00 % 0.00 % cronolog /guojinbao/tomcat/logs/catalina.%Y-%m-%d.out 18796 be/4 root 0.00 B/s 3.92 K/s 0.00 % 0.00 % java -Djava.util.logging.config.file=/usr/to~p org.apache.catalina.startup.Bootstrap start 13193 be/4 root 0.00 B/s 3.92 K/s 0.00 % 0.00 % java -Djava.util.logging.config.file=/usr/to~p org.apache.catalina.startup.Bootstrap start 1 be/4 root 0.00 B/s 0.00 B/s 0.00 % 0.00 % systemd --switched-root --system --deserialize 22 2 be/4 root 0.00 B/s 0.00 B/s 0.00 % 0.00 % [kthreadd] 3 be/4 root 0.00 B/s 0.00 B/s 0.00 % 0.00 % [ksoftirqd/0] 16388 be/4 root 0.00 B/s 0.00 B/s 0.00 % 0.00 % AliYunDun 5 be/0 root 0.00 B/s 0.00 B/s 0.00 % 0.00 % [kworker/0:0H] 16390 be/4 root 0.00 B/s 0.00 B/s 0.00 % 0.00 % AliYunDun 7 rt/4 root 0.00 B/s 0.00 B/s 0.00 % 0.00 % [migration/0] 8 be/4 root 0.00 B/s 0.00 B/s 0.00 % 0.00 % [rcu_bh] 9 be/4 root 0.00 B/s 0.00 B/s 0.00 % 0.00 % [rcuob/0] 10 be/4 root 0.00 B/s 0.00 B/s 0.00 % 0.00 % [rcuob/1] 11 be/4 root 0.00 B/s 0.00 B/s 0.00 % 0.00 % [rcuob/2]
从上述的例子中可以看出进程号为cronolog18987占用了大量的磁盘IO
(4)通过lsof -p pid查找由那个文件引起的IOwait
[root@iZ23iod5vslZ ~]# lsof -p 18987 COMMAND PID USER FD TYPE DEVICE SIZE/OFF NODE NAME cronolog 18987 root cwd DIR 202,17 20480 2400258 /guojinbao/tomcat/logs cronolog 18987 root rtd DIR 202,1 4096 2 / cronolog 18987 root txt REG 202,1 48627 152798 /usr/local/sbin/cronolog cronolog 18987 root mem REG 202,1 2107600 132826 /usr/lib64/libc-2.17.so cronolog 18987 root mem REG 202,1 160240 132819 /usr/lib64/ld-2.17.so cronolog 18987 root 0r FIFO 0,8 0t0 42614018 pipe cronolog 18987 root 1w CHR 1,3 0t0 1028 /dev/null cronolog 18987 root 2u CHR 136,0 0t0 3 /dev/pts/0 (deleted) cronolog 18987 root 3w REG 202,17 5704875979 2400280 /guojinbao/tomcat/logs/catalina.2017-08-14.out
lsof 命令可以展示一个进程打开的所有文件,或者打开一个文件的所有进程。从这个列表中,我们可以找到具体是什么文件被写入,根据文件的大小和/proc中io文件的具体数据.
为了确认我们的怀疑,我们可以使用 /proc文件系统,每个进程目录下都有一个叫io的文件,里边保存这和iotop类似的信息
[root@iZ23iod5vslZ ~]# cat /proc/18987/io rchar: 58891582418 wchar: 58891579778 syscr: 46556085 syscw: 46556077 read_bytes: 212992 write_bytes: 59580235776 cancelled_write_bytes: 0
read_bytes和write_bytes是这个进程从磁盘读写的字节数。这个例子中cronolog读取了212992byte(0.2M)数据,写入了59580235776bytes(55.4G)数据到磁盘上。
(5)通过df -h /guojinbao来查看服务器那块磁盘的根目录
[root@iZ23iod5vslZ ~]# df -h /guojinbao/ Filesystem Size Used Avail Use% Mounted on /dev/xvdb1 45G 38G 4.7G 89% /guojinbao
最后,通过以上的信息我们可以放心的说lsof的结果就是我们要查找的文件