系統出現大量不可中斷程序與殭屍程序
程序狀態
當 iowait 升高時,程序很可能因為得不到硬體的響應,而長時間處於不可中斷狀態。從 ps 或者 top 命令的輸出中,它們都處於 D 狀態,也就是不可中斷狀態;
top 和 ps 是最常用的檢視程序狀態的工具,下面是一個 top 命令輸出的示例,S 列(也就是 Status 列)表示程序的狀態。
$ top PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND 28961 root 20 0 43816 3148 4040 R 3.2 0.0 0:00.01 top 620 root 20 0 37280 33676 908 D 0.3 0.4 0:00.01 app 1 root 20 0 160072 9416 6752 S 0.0 0.1 0:37.64 systemd 1896 root 20 0 0 0 0 Z 0.0 0.0 0:00.00 devapp 2 root 20 0 0 0 0 S 0.0 0.0 0:00.10 kthreadd 4 root 0 -20 0 0 0 I 0.0 0.0 0:00.00 kworker/0:0H 6 root 0 -20 0 0 0 I 0.0 0.0 0:00.00 mm_percpu_wq 7 root 20 0 0 0 0 S 0.0 0.0 0:06.37 ksoftirqd/0
R 是 Running 或 Runnable 的縮寫,表示程序在 CPU 的就緒佇列中,正在執行或者正在等待執行。
D 是 Disk Sleep 的縮寫,也就是不可中斷狀態睡眠(Uninterruptible Sleep),一般表示程序正在跟硬體互動,並且互動過程不允許被其他程序或中斷打斷
Z 是 Zombie 的縮寫,它表示殭屍程序,也就是程序實際上已經結束了,但是父程序還沒有回收它的資源(比如程序的描述符、PID 等)。
S 是 Interruptible Sleep 的縮寫,也就是可中斷狀態睡眠,表示程序因為等待某個事件而被系統掛起。當程序等待的事件發生時,它會被喚醒並進入 R 狀態。
I 是 Idle 的縮寫,也就是空閒狀態,用在不可中斷睡眠的核心執行緒上。前面說了,硬體互動導致的不可中斷程序用 D 表示,但對某些核心執行緒來說,它們有可能實際上並沒有任何負載,用 Idle 正是為了區分這種情況。要注意,D 狀態的程序會導致平均負載升高, I 狀態的程序卻不會。
程序還包括下面這 2 個狀態。
第一個是 T 或者 t,也就是 Stopped 或 Traced 的縮寫,表示程序處於暫停或者跟蹤狀態。向一個程序傳送 SIGSTOP 訊號,它就會因響應這個訊號變成暫停狀態(Stopped);再向它傳送 SIGCONT 訊號,程序又會恢復執行(如果程序是終端裡直接啟動的,則需要你用 fg 命令,恢復到前臺執行)。而當使用偵錯程式(如 gdb)除錯一個程序時,在使用斷點中斷程序後,程序就會變成跟蹤狀態,這其實也是一種特殊的暫停狀態,只不過你可以用偵錯程式來跟蹤並按需要控制程序的執行。
另一個是 X,也就是 Dead 的縮寫,表示程序已經消亡,所以你不會在 top 或者 ps 命令中看到它。
S 表示可中斷睡眠狀態
D 表示不可中斷睡眠狀態
s 表示這個程序是一個會話的領導程序
+ 表示前臺程序組。
程序組表示一組相互關聯的程序,比如每個子程序都是父程序所在組的成員;而會話是指共享同一個控制終端的一個或多個程序組。
不可中斷狀態,這其實是為了保證程序資料與硬體狀態一致,並且正常情況下,不可中斷狀態在很短時間內就會結束。所以,短時的不可中斷狀態程序,我們一般可以忽略。
殭屍程序,這是多程序應用很容易碰到的問題。正常情況下,當一個程序建立了子程序後,它應該通過系統呼叫 wait() 或者 waitpid() 等待子程序結束,回收子程序的資源;而子程序在結束時,會向它的父程序傳送 SIGCHLD 訊號,所以,父程序還可以註冊 SIGCHLD 訊號的處理函式,非同步回收資源。如果父程序沒這麼做,或是子程序執行太快,父程序還沒來得及處理子程序狀態,子程序就已經提前退出,那這時的子程序就會變成殭屍程序。
通常,殭屍程序持續的時間都比較短,在父程序回收它的資源後就會消亡;或者在父程序退出後,由 init 程序回收後也會消亡。一旦父程序沒有處理子程序的終止,還一直保持執行狀態,那麼子程序就會一直處於殭屍狀態。大量的殭屍程序會用盡 PID 程序號,導致新程序不能建立,所以這種情況一定要避免。
示例,不同的系統執行可能IO會有一些差異
docker run --privileged --name=app -itd feisky/app:iowait
用 top 看一下系統的資源使用情況
# 按下數字 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 ...
先看第一行的平均負載( Load Average),過去 1 分鐘、5 分鐘和 15 分鐘內的平均負載在依次減小,說明平均負載正在升高;而 1 分鐘內的平均負載已經達到系統的 CPU 個數,說明系統很可能已經有了效能瓶頸。
再看第二行的 Tasks,有 1 個正在執行的程序,但殭屍程序比較多,而且還在不停增加,說明有子程序在退出時沒被清理。
接下來看兩個 CPU 的使用率情況,使用者 CPU 和系統 CPU 都不高,但 iowait 分別是 60.5% 和 94.6%,好像有點兒不正常。
最後再看每個程序的情況, CPU 使用率最高的程序只有 0.3%,看起來並不高;但有兩個程序處於 D 狀態,它們可能在等待 I/O,但光憑這裡並不能確定是它們導致了 iowait 升高。
暴露兩個問題
第一點,iowait 太高了,導致系統的平均負載升高,甚至達到了系統 CPU 的個數。
第二點,殭屍程序在不斷增多,說明有程式沒能正確清理子程序的資源。
查詢系統的 I/O 情況。使用dstat ,它的好處是,可以同時檢視 CPU 和 I/O 這兩種資源的使用情況
# 間隔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
從 dstat 的輸出,可以看到,每當 iowait 升高(wai)時,磁碟的讀請求(read)都會很大。這說明 iowait 的升高跟磁碟的讀請求有關,很可能就是磁碟讀導致的。
執行 top 命令,觀察 D 狀態的程序:
# 觀察一會兒按 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 ...
從 top 的輸出找到 D 狀態程序的 PID,可以發現,這個介面裡有兩個 D 狀態的程序,PID 分別是 4344 和 4345。
在終端裡執行下面的 pidstat 命令,並用 -p 4344 引數指定程序號:
# -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
在這個輸出中, kB_rd 表示每秒讀的 KB 數, kB_wr 表示每秒寫的 KB 數,iodelay 表示 I/O 的延遲(單位是時鐘週期)。它們都是 0,那就表示此時沒有任何的讀寫,說明問題不是 4344 程序導致的。
可是,用同樣的方法分析程序 4345,會發現,它也沒有任何磁碟讀寫。繼續使用 pidstat,但這次去掉程序號,乾脆就來觀察所有程序的 I/O 使用情況。
# 間隔 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 ...
觀察一會兒可以發現,的確是 app 程序在進行磁碟讀,並且每秒讀的資料有 32 MB,看來就是 app 的問題。這裡,程序想要訪問磁碟,就必須使用系統呼叫,所以接下來,重點就是找出 app 程序的系統呼叫了。
strace 正是最常用的跟蹤程序系統呼叫的工具。所以,我們從 pidstat 的輸出中拿到程序的 PID 號,比如 6082,然後在終端中執行 strace 命令,並用 -p 引數指定 PID 號:
$ strace -p 6082 strace: attach: ptrace(PTRACE_SEIZE, 6082): Operation not permitted
strace 命令居然失敗了,並且命令報出的錯誤是沒有許可權。一般遇到這種問題時,先檢查一下程序的狀態是否正常。比如,繼續在終端中執行 ps 命令,並使用 grep 找出剛才的 6082 號程序:
$ 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 這類工具已經不能給出更多的資訊了。可以用 perf top 看看有沒有新發現。再或者,在終端中執行 perf record,持續一會兒(例如 15 秒),然後按 Ctrl+C 退出,再執行 perf report 檢視報告:
$ perf record -g $ perf report
接著,找到我們關注的 app 程序,按回車鍵展開呼叫棧,
可以發現, app 的確在通過系統呼叫 sys_read() 讀取資料。並且從 new_sync_read 和 blkdev_direct_IO 能看出,程序正在對磁碟進行直接讀,也就是繞過了系統快取,每個讀請求都會從磁碟直接讀,這就可以解釋觀察到的 iowait 升高了。app 內部進行了磁碟的直接 I/O 啊!找到問題的程式碼修復就好
再用 top 檢查一下:
$ 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 ... PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND 3084 root 20 0 0 0 0 Z 1.3 0.0 0:00.04 app 3085 root 20 0 0 0 0 Z 1.3 0.0 0:00.04 app 1 root 20 0 159848 9120 6724 S 0.0 0.1 0:09.03 systemd 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.40 kworker/0:0 ...
殭屍程序還在。仔細觀察殭屍程序的數量,你會鬱悶地發現,殭屍程序還在不斷的增長中。
接下來,我們就來處理殭屍程序的問題。既然殭屍程序是因為父程序沒有回收子程序的資源而出現的,也就是要找出父程序,然後在父程序裡解決。
ps -aux | grep Z USER PID %CPU %MEM VSZ RSS TTY STAT START TIME COMMAND root 15714 0.0 0.0 0 0 pts/0 Z+ 19:57 0:00 [app] <defunct> root 15715 0.0 0.0 0 0 pts/0 Z+ 19:57 0:00 [app] <defunct> root 15716 0.0 0.0 0 0 pts/0 Z+ 19:57 0:00 [app] <defunct> root 15718 0.0 0.0 112728 972 pts/0 R+ 19:57 0:00 grep --color=auto Z [root@linux-xingnengyouhua ~]# pstree | grep app |-containerd-+-containerd-shim-+-app---50*[app] [root@linux-xingnengyouhua ~]# pstree -aps 15716 systemd,1 --switched-root --system --deserialize 22 └─containerd,5515 └─containerd-shim,15626 -namespace moby -workdir /var/lib/containerd/io.containerd.runtime.v1.linux/moby/9424f80735a14e301c5eb7df72cd2751db090d6e657319f47d6bd47b94e70a65 -address... └─app,15643 -d /dev/sda1 -s 37108864 -c 20 └─(app,15716)
檢視 app 應用程式的程式碼,看看子程序結束的處理是否正確,比如有沒有呼叫 wait() 或 waitpid() ,抑或是,有沒有註冊 SIGCHLD 訊號的處理函式。
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() 函式實際上並沒被呼叫到
修改後重啟檢視
$ 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 ...