一、環境准備
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信號處理函數的注冊