案例
环境准备
# 先删除上次启动的案例
[root@local_sa_192-168-1-6 ~]# docker rm -f app
# 重新运行案例
[root@local_sa_192-168-1-6 ~]# docker run --privileged --name=app -itd feisky/app:iowait
iowait分析
1.安装dstat
提到iowait升高，首先会想要查询系统的I/O情况
那么什么工具可以查询系统的I/O情况呢？
dstat，可以同时查看CPU和I/O这两种资源的使用情况，便于对比分析
# 安装dstat
[root@local_sa_192-168-1-6 ~]# yum install dstat -y
2.dstat工具
# 间隔1秒输出10组数据
[root@local_sa_192-168-1-6 ~]# dstat 1 10
You did not select any stats, using -cdngy by default.
----total-cpu-usage---- -dsk/total- -net/total- ---paging-- ---system--
usr sys idl wai hiq siq| read writ| recv send| in out | int csw
0 0 100 0 0 0| 17k 934B| 0 0 | 0 0 | 44 76
0 1 0 99 0 0| 77M 0 | 114B 1004B| 0 0 | 421 241
0 1 0 99 0 0| 75M 4096B| 54B 42B| 0 0 | 457 413
0 1 29 70 0 0| 55M 4096B| 221B 358B| 0 0 | 336 234
1 1 50 49 0 0| 64M 0 | 54B 374B| 0 0 | 417 285
0 1 18 81 0 0| 93M 0 | 54B 374B| 0 0 | 527 293
0 0 50 50 0 0| 16M 0 | 114B 358B| 0 0 | 136 137
0 0 50 50 0 0| 23M 0 | 54B 358B| 0 0 | 161 138
0 1 51 49 0 0| 79M 0 | 114B 358B| 0 0 | 492 301
0 1 30 70 0 0| 111M 0 | 114B 358B| 0 0 | 603 267
1 1 0 98 0 1| 89M 0 | 114B 358B| 0 0 | 456 280
# 输出结果分析
每当iowait（wai）升高时，磁盘的读请求（read）都会很大
这说明iowait的升高跟磁盘的读请求有关，很可能就是磁盘读导致的
3.那到底是哪个进程在读磁盘呢？
进程状态
D 是Disk Sleep的缩写，也就是不可中断状态睡眠，一般表示进程正在跟硬件交互，并且交互过程不允许被其他进程或中断打断
# 所以直接看进程状态为D的进程，这里可以看到4345 4344进程号
[root@local_sa_192-168-1-6 ~]# top
PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND
4340 root 20 0 44676 4048 3432 R 0.3 0.0 0:00.05 top
4345 root 20 0 37280 33624 860 D 0.3 0.0 0:00.01 app
4344 root 20 0 37280 33624 860 D 0.3 0.4 0:00.01 app
4.进程的资源使用情况可以使用pidstat，不过这次记得加上-d参数，以便输出I/O使用情况
# -d 展示I/O统计数据，-p指定进程号，间隔1秒输出3组数据
[root@local_sa_192-168-1-6 ~]# pidstat -d -p 4344 1 3
06:38:50 UID PID kB_rd/s kB_wr/s kB_ccwr/s iodelay Command
06:38:51 0 4344 0.00 0.00 0.00 0 app
06:38:52 0 4344 0.00 0.00 0.00 0 app
06:38:53 0 4344 0.00 0.00 0.00 0 app
# 输出结果分析
kB_rd 表示每秒读的KB数
kB_wr 表示每秒写的KB数
iodelay 表示I/O的延迟（单位是时钟周期）
它们都是0，那就表示此时没有任何的读写，说明问题不是4344进程导致的
用同样的方法分析进程4345，它也没有任何磁盘读写
5.继续使用pidstat，但这次去掉进程号，干脆就来观察所有进程的I/O使用情况
# 间隔1秒输出多组数据 (这里是20组)
[root@local_sa_192-168-1-6 ~]# pidstat -d 1 20
...
06:48:46 UID PID kB_rd/s kB_wr/s kB_ccwr/s iodelay Command
06:48:47 0 4615 0.00 0.00 0.00 1 kworker/u4:1
06:48:47 0 6080 32768.00 0.00 0.00 170 app
06:48:47 0 6081 32768.00 0.00 0.00 184 app
06:48:48 0 6080 0.00 0.00 0.00 110 app
06:48:49 0 6081 0.00 0.00 0.00 191 app
06:48:51 0 6082 32768.00 0.00 0.00 0 app
06:48:51 0 6083 32768.00 0.00 0.00 0 app
06:48:52 0 6082 32768.00 0.00 0.00 184 app
06:48:52 0 6083 32768.00 0.00 0.00 175 app
06:48:53 0 6083 0.00 0.00 0.00 105 app
...
# 输出结果分析
观察一会儿可以发现，的确是app进程在进行磁盘读，并且每秒读的数据有32MB，看来就是app的问题
不过，app进程到底在执行啥I/O操作呢？
需要回顾一下进程用户态和进程内核态的区别
进程既可以在用户空间运行，又可以在内核空间中运行
进程在用户空间运行时，被称为【进程的用户态】
而陷入内核空间的时候，被称为【进程的内核态】
从用户态到内核态的转变，需要通过【系统调用】来完成
所以接下来，重点就是找出app进程的系统调用了
6.strace正是最常用的跟踪进程系统调用的工具
从pidstat的输出中拿到进程的PID号
比如6082，然后在终端中运行strace命令，并用-p参数指定PID号
[root@local_sa_192-168-1-6 ~]# strace -p 6082
strace: attach: ptrace(PTRACE_SEIZE, 6082): Operation not permitted
# 输出结果分析
root用户执行的居然说权限不足
一般遇到这种问题时，可以先检查一下进程的状态是否正常
[root@local_sa_192-168-1-6 ~]# ps aux | grep 6082
root 6082 0.0 0.0 0 0 pts/0 Z+ 13:43 0:00 [app] <defunct>
# 输出结果分析
进程6082已经变成了Z状态，也就是僵尸进程
僵尸进程都是已经退出的进程，所以就没法儿继续分析它的系统调用
系统iowait的问题还在继续，但是top、pidstat这类工具已经不能给出更多的信息了
7.基于事件记录的动态追踪工具perf
# 注意，centos7中由于使用了容器环境，需要把报告拷贝到容器中去分析
# 在宿主机上生成perf.data数据
[root@local_sa_192-168-1-6 ~]# perf record -g
# 拷贝数据到容器中
[root@local_sa_192-168-1-6 ~]# docker cp perf.data app:/tmp
[root@local_sa_192-168-1-6 ~]# docker exec -i -t app bash
root@2e2f18f5ba75:/app# cd /tmp/
root@2e2f18f5ba75:/tmp# apt-get update && apt-get install -y linux-perf linux-tools procps
root@2e2f18f5ba75:/tmp# chown root.root perf.data
root@2e2f18f5ba75:/tmp# perf_4.9 report
按回车键展开调用栈，就会得到下面这张调用关系图
这个图里的swapper是内核中的调度进程，可以先忽略掉
app的确在通过系统调用sys_read()读取数据
并且从new_sync_read和blkdev_direct_IO能看出，进程正在对磁盘进行直接读
也就是绕过了系统缓存，每个读请求都会从磁盘直接读，这就可以解释我们观察到的iowait升高了
罪魁祸首是app内部进行了磁盘的直接I/O啊
8.修复源码文件app.c
来应该从代码层面分析，究竟是哪里出现了直接读请求。
查看源码文件app.c，发现它果然使用O_DIRECT选项打开磁盘，于是绕过了系统缓存，直接对磁盘进行读写
open(disk, O_RDONLY|O_DIRECT|O_LARGEFILE, 0755)
直接读写磁盘，对I/O敏感型应用（比如数据库系统）是很友好的
因为可以在应用中，直接控制磁盘的读写
但在大部分情况下，最好还是通过系统缓存来优化磁盘I/O，删除O_DIRECT这个选项
# 首先删除原来的应用
[root@local_sa_192-168-1-6 ~]# docker rm -f app
# 运行新的应用
[root@local_sa_192-168-1-6 ~]# docker run --privileged --name=app -itd feisky/app:iowait-fix1
再用 top 检查一下
[root@local_sa_192-168-1-6 ~]# top
top - 14:59:32 up 19 min, 1 user, load average: 0.15, 0.07, 0.05
Tasks: 137 total, 1 running, 72 sleeping, 0 stopped, 12 zombie
%Cpu0 : 0.0 us, 1.7 sy, 0.0 ni, 98.0 id, 0.3 wa, 0.0 hi, 0.0 si, 0.0 st
%Cpu1 : 0.0 us, 1.3 sy, 0.0 ni, 98.7 id, 0.0 wa, 0.0 hi, 0.0 si, 0.0 st
iowait已经非常低了，只有0.3%，说明刚才的改动已经成功修复了iowait高的问题
仔细观察僵尸进程的数量，发现僵尸进程还在不断的增长中...
僵尸进程
僵尸进程是因为父进程没有回收子进程的资源而出现的，
那么，要解决掉它们，就要找到它们的根儿，也就是找出父进程，然后在父进程里解决
1.父进程的找法最简单的就是运行pstree命令
# -a 表示输出命令行选项
# -p 表 PID
# -s 表示指定进程的父进程
[root@local_sa_192-168-1-6 ~]# pstree -aps 3084
systemd,1
└─dockerd,15006 -H fd://
└─docker-containe,15024 --config /var/run/docker/containerd/containerd.toml
└─docker-containe,3991 -namespace moby -workdir...
└─app,4009
└─(app,3084)
# 输出结果解释
会发现3084号进程的父进程是4009，也就是app应用
2.查看app应用程序的代码
看看子进程结束的处理是否正确，比如有没有调用wait()或waitpid()，有没有注册SIGCHLD信号的处理函数
查看修复iowait后的源码文件app-fix1.c，找到子进程的创建和清理的地方
int status = 0;
for (;;) {
for (int i = 0; i < 2; i++) {
if(fork()== 0) {
sub_process();
}
}
sleep(5);
}
while(wait(&status)>0);
这段代码虽然看起来调用了wait()函数等待子进程结束
但却错误地把wait()放到了for死循环的外面
也就是说，wait()函数实际上并没被调用到
把它挪到for循环的里面就可以了
3.修复
# 先停止产生僵尸进程的 app
[root@local_sa_192-168-1-6 ~]# docker rm -f app
# 然后启动新的 app
[root@local_sa_192-168-1-6 ~]# docker run --privileged --name=app -itd feisky/app:iowait-fix2
4.启动后，再用top最后来检查一遍
$ top
top - 15:00:44 up 20 min, 1 user, load average: 0.05, 0.05, 0.04
Tasks: 125 total, 1 running, 72 sleeping, 0 stopped, 0 zombie
%Cpu0 : 0.0 us, 1.7 sy, 0.0 ni, 98.3 id, 0.0 wa, 0.0 hi, 0.0 si, 0.0 st
%Cpu1 : 0.0 us, 1.3 sy, 0.0 ni, 98.7 id, 0.0 wa, 0.0 hi, 0.0 si, 0.0 st
...
PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND
3198 root 20 0 4376 840 780 S 0.3 0.0 0:00.01 app
2 root 20 0 0 0 0 S 0.0 0.0 0:00.00 kthreadd
3 root 20 0 0 0 0 I 0.0 0.0 0:00.41 kworker/0:0
...
僵尸进程（Z 状态）没有了，iowait也是0，问题终于全部解决了
小结
在这里用一个多进程的案例，分析系统等待I/O的CPU使用率（也就是 iowait%）升高的情况
虽然这个案例是磁盘I/O导致了iowait升高，
不过，iowait高不一定代表I/O有性能瓶颈
当系统中只有I/O类型的进程在运行时，iowait也会很高
但实际上，磁盘的读写远没有达到性能瓶颈的程度
因此，碰到iowait升高时，需要先用dstat、pidstat等工具，确认是不是磁盘I/O的问题
然后再找是哪些进程导致了I/O
等待I/O的进程一般是不可中断状态，所以用ps命令找到的D状态（即不可中断状态）的进程，多为可疑进程
但这个案例中，在I/O操作后，进程又变成了僵尸进程，所以不能用strace直接分析这个进程的系统调用
这种情况下，用perf工具，来分析系统的CPU时钟事件
最终发现是直接I/O导致的问题
这时，再检查源码中对应位置的问题，就很轻松了
而僵尸进程的问题相对容易排查，使用pstree找出父进程后，去查看父进程的代码
检查wait()/waitpid()的调用，或是SIGCHLD信号处理函数的注册就行了