一、环境准备
1、在第6节的基础上安装dstat
wget http://mirror.centos.org/centos/7/os/x86_64/Packages/dstat-0.7.2-12.el7.noarch.rpm rpm -ivh dstat-0.7.2-12.el7.noarch.rpm
2、故障现象
# 按下数字 1 切换到所有 CPU 的使用情况，观察一会儿按 Ctrl+C 结束
$ top
top - 05:56:23 up 17 days, 16:45, 2 users, load average: 2.00, 1.68, 1.39
Tasks: 247 total, 1 running, 79 sleeping, 0 stopped, 115 zombie
%Cpu0 : 0.0 us, 0.7 sy, 0.0 ni, 38.9 id, 60.5 wa, 0.0 hi, 0.0 si, 0.0 st
%Cpu1 : 0.0 us, 0.7 sy, 0.0 ni, 4.7 id, 94.6 wa, 0.0 hi, 0.0 si, 0.0 st
...
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
1 root 20 0 160072 9416 6752 S 0.0 0.1 0:38.59 systemd
...
①iowait太高，导致平均负载升高，并且达到了系统CPU的个数
②僵尸进程不断增多
二、iowait升高的原因分析
1、用dstat 命令同时查看cpu和i/o对比情况
（如 dstat 1 10 间隔1秒输出10组数据），通过结果可以发现iowait升高时，磁盘读请求（read）升高所以推断iowait升高是磁盘读导致
# 间隔 1 秒输出 10 组数据 $ 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 stl| read writ| recv send| in out | int csw 0 0 96 4 0|1219k 408k| 0 0 | 0 0 | 42 885 0 0 2 98 0| 34M 0 | 198B 790B| 0 0 | 42 138 0 0 0 100 0| 34M 0 | 66B 342B| 0 0 | 42 135 0 0 84 16 0|5633k 0 | 66B 342B| 0 0 | 52 177 0 3 39 58 0| 22M 0 | 66B 342B| 0 0 | 43 144 0 0 0 100 0| 34M 0 | 200B 450B| 0 0 | 46 147 0 0 2 98 0| 34M 0 | 66B 342B| 0 0 | 45 134 0 0 0 100 0| 34M 0 | 66B 342B| 0 0 | 39 131 0 0 83 17 0|5633k 0 | 66B 342B| 0 0 | 46 168 0 3 39 59 0| 22M 0 | 66B 342B| 0 0 | 37 134
实际测试截图如下
2、定位磁盘读的进程
使用top命令查看处于不可中断状态（D）的进程PID
# 观察一会儿按 Ctrl+C 结束 $ 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 ...
实际测试截图
3、查看对应进程的磁盘读写情况
使用pidstat命令，加上-d参数，可以看到i/o使用情况（如 pidstat -d -p <pid> 1 3）,发现处于不可中断状态的进程都没有进行磁盘读写
# -d 展示 I/O 统计数据，-p 指定进程号，间隔 1 秒输出 3 组数据 $ 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
实际测试截图
4、使用pidstat命令查看所有进程的i/o情况
但是去掉进程号，查看所有进程的i/o情况（pidstat -d 1 20），可以定位到进行磁盘读写的进程。我们知道进程访问磁盘，需要使用系统调用，
下面的重点就是找到该进程的系统调用
# 间隔 1 秒输出多组数据 (这里是 20 组) $ 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:47 UID PID kB_rd/s kB_wr/s kB_ccwr/s iodelay Command 06:48:48 0 6080 0.00 0.00 0.00 110 app 06:48:48 UID PID kB_rd/s kB_wr/s kB_ccwr/s iodelay Command 06:48:49 0 6081 0.00 0.00 0.00 191 app 06:48:49 UID PID kB_rd/s kB_wr/s kB_ccwr/s iodelay Command 06:48:50 UID PID kB_rd/s kB_wr/s kB_ccwr/s iodelay Command 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:51 UID PID kB_rd/s kB_wr/s kB_ccwr/s iodelay Command 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:52 UID PID kB_rd/s kB_wr/s kB_ccwr/s iodelay Command 06:48:53 0 6083 0.00 0.00 0.00 105 app ...
实际测试命令如下
[root@luoahong ~]# pidstat -d 1 20 Linux 3.10.0-957.5.1.el7.x86_64 (luoahong) 05/05/2019 _x86_64_ (2 CPU) 11:01:21 AM UID PID kB_rd/s kB_wr/s kB_ccwr/s iodelay Command 11:01:22 AM UID PID kB_rd/s kB_wr/s kB_ccwr/s iodelay Command 11:01:23 AM 0 12174 82431.50 0.00 0.00 0 app 11:01:23 AM 0 12175 30207.50 0.00 0.00 0 app ...... 11:01:35 AM UID PID kB_rd/s kB_wr/s kB_ccwr/s iodelay Command 11:01:36 AM UID PID kB_rd/s kB_wr/s kB_ccwr/s iodelay Command 11:01:37 AM UID PID kB_rd/s kB_wr/s kB_ccwr/s iodelay Command 11:01:38 AM 0 12180 47103.50 0.00 0.00 0 app 11:01:38 AM 0 12181 37375.50 0.00 0.00 0 app 11:01:38 AM UID PID kB_rd/s kB_wr/s kB_ccwr/s iodelay Command 11:01:39 AM 0 12180 768512.00 0.00 0.00 51 app 11:01:39 AM 0 12181 552448.50 0.00 0.00 49 app ...... Average: 0 12179 65307.42 0.00 0.00 0 app Average: 0 12180 65307.42 0.00 0.00 28 app Average: 0 12181 65307.42 0.00 0.00 29 app
5、使用strace查看进程的系统调用 strace -p <pid>
strace -p 6082 strace: attach: ptrace(PTRACE_SEIZE, 6082): Operation not permitted
实际测试截图
发现报了 strace:attach :ptrace(PTRACE_SIZE，6028)：Operation not peritted,说没有权限，我是使用的root权限，所以这个时候就要查看进程的状态是否正常
6、ps aux | grep <pid> 发现进程处于Z状态，已经变成了僵尸进程
所以不能进行系统调用分析了
ps aux | grep 6082 root 6082 0.0 0.0 0 0 pts/0 Z+ 13:43 0:00 [app] <defunct>
实际测试截图
7、既然top和pidstat都不能找出问题，使用基于事件记录的动态追踪工具
perf record -g $ perf report
要是你是centos系统，在容器外面把分析记录保存，到容器里面查看结果
操作：
（1）在centos系统上运行 perf record -g ，执行一会儿按ctrl+c停止
（2）把生成的perf.data（通常文件生成在命令执行的当前目录下，当然可以通过find | grep perf.data或 find / -name perf.data查看路径）文件拷贝到容器里面分析：
docker cp perf.data app:/tpm docker exec -i -t app bash cd /tmp/ apt-get update && apt-get install -y linux-perf linux-tools procps perf_4.9 report
8、看来罪魁祸首是app内部进行了磁盘的直接I/O啊!
open(disk, O_RDONLY|O_DIRECT|O_LARGEFILE, 0755)
然后观察调用栈信息，检查是否有磁盘读操作，这个案例是定位到了进行磁盘的直接读，当然也可以查看源码进行验证。因为我的centos系统用老师的 iowait镜像iowait升高不明显，所以使用的是iowait-new2镜像，可以得到想要的结果，但是这个镜像把我的系统能搞崩溃，所以我只能执行到cd /tmp/这步，下面那部就执行不下去了。但是整个分析过程还是理解了。
三、iowait升高解决方案
1、运行修改后的镜像包
# 首先删除原来的应用 $ docker rm -f app # 运行新的应用 $ docker run --privileged --name=app -itd feisky/app:iowait-fix1
2、在用top查看一下
top
top - 14:59:32 up 19 min, 1 user, load average: 0.15, 0.07, 0.05
Tasks: 545 total, 1 running, 130 sleeping, 0 stopped, 414 zombie
%Cpu(s): 0.3 us, 25.9 sy, 0.0 ni, 65.5 id, 0.5 wa, 0.0 hi, 7.7 si, 0.0 st
KiB Mem : 8056840 total, 6620396 free, 686076 used, 750368 buff/cache
KiB Swap: 2097148 total, 2097148 free, 0 used. 7029968 avail Mem
PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND
12967 root 20 0 0 0 0 Z 35.2 0.0 0:01.28 app
12968 root 20 0 0 0 0 Z 31.6 0.0 0:01.20 app
12961 root 20 0 162416 2728 1596 R 1.3 0.0 0:00.26 top
7473 root 20 0 227160 6356 4944 S 0.3 0.1 0:14.91 vmtoolsd
9369 root 20 0 851800 64620 25608 S 0.3 0.8 0:11.29 dockerd
9379 root 20 0 452964 36060 15040 S 0.3 0.4 0:12.83 containerd
9779 mysql 20 0 1119708 186364 5796 S 0.3 2.3 0:14.60 mysqld
10061 polkitd 20 0 1267680 210772 9336 S 0.3 2.6 0:15.74 mysqld
11341 root 20 0 0 0 0 S 0.3 0.0 0:06.97 kworker/0:1
1 root 20 0 43640 3952 2552 S 0.0 0.0 0:03.90 systemd
四、僵尸进程分析
1、找出父进程、然后在父进程里解决
# -a 表示输出命令行选项
# p 表 PID
# s 表示指定进程的父进程
[root@luoahong ~]# pstree -aps 12582
systemd,1 --switched-root --system --deserialize 22
└─containerd,9379
└─containerd-shim,12484 -namespace moby -workdir...
└─app,12502
└─(app,12582
2、查看修复后的源码文件
int status = 0;
for (;;) {
for (int i = 0; i < 2; i++) {
if(fork()== 0) {
sub_process();
}
}
sleep(5);
}
while(wait(&status)>0);
五、僵尸进程解决方案
1、运行修复后文件打包的镜像
# 先停止产生僵尸进程的 app $ docker rm -f app # 然后启动新的 app $ docker run --privileged --name=app -itd feisky/app:iowait-fix2
2、top命令查看
top
top - 13:36:25 up 2:27, 2 users, load average: 0.44, 0.23, 0.11
Tasks: 134 total, 2 running, 132 sleeping, 0 stopped, 0 zombie
%Cpu(s): 0.0 us, 12.5 sy, 0.0 ni, 83.2 id, 0.7 wa, 0.0 hi, 3.6 si, 0.0 st
KiB Mem : 8056840 total, 5975080 free, 832016 used, 1249744 buff/cache
KiB Swap: 2097148 total, 2097148 free, 0 used. 6880292 avail Mem
...
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
...
僵尸进程出现的原因是父进程没有回收子进程的资源出现的。解决办法是找到父进程，在父进程中处理，使用pstree查父进程，然后查看父进程的源码检查wait()/waitpid()的调用或SIGCHLD信号处理函数的注册