實驗環境
OS:Ubuntu 18.04
CPU:2 Cores
Memory:4G
檢視OS版本
$ cat /etc/os-release
NAME="Ubuntu"
VERSION="18.04.4 LTS (Bionic Beaver)"
ID=ubuntu
ID_LIKE=debian
PRETTY_NAME="Ubuntu 18.04.4 LTS"
VERSION_ID="18.04"
HOME_URL="https://www.ubuntu.com/"
SUPPORT_URL="https://help.ubuntu.com/"
BUG_REPORT_URL="https://bugs.launchpad.net/ubuntu/"
PRIVACY_POLICY_URL="https://www.ubuntu.com/legal/terms-and-policies/privacy-policy"
VERSION_CODENAME=bionic
UBUNTU_CODENAME=bionic
檢視CPU個數
$ cat /proc/cpuinfo | grep "model name"
model name : Intel(R) Core(TM) i5-8350U CPU @ 1.70GHz
model name : Intel(R) Core(TM) i5-8350U CPU @ 1.70GHz
檢視記憶體資訊
$ free -m
total used free shared buff/cache available
Mem: 3944 128 3309 0 506 3601
Swap: 2047
檢視OS資訊
$ cat /etc/os-release
NAME="Ubuntu"
VERSION="18.04.4 LTS (Bionic Beaver)"
ID=ubuntu
ID_LIKE=debian
PRETTY_NAME="Ubuntu 18.04.4 LTS"
VERSION_ID="18.04"
HOME_URL="https://www.ubuntu.com/"
SUPPORT_URL="https://help.ubuntu.com/"
BUG_REPORT_URL="https://bugs.launchpad.net/ubuntu/"
PRIVACY_POLICY_URL="https://www.ubuntu.com/legal/terms-and-policies/privacy-policy"
VERSION_CODENAME=bionic
UBUNTU_CODENAME=bionic
檢視系統資訊
$ uname -a
Linux aaa_ubuntu 4.15.0-112-generic #113-Ubuntu SMP Thu Jul 9 23:41:39 UTC 2020 x86_64 x86_64 x86_64 GNU/Linux
檢視平均負載
顯示的數值為最近1分鐘,5分鐘,15分鐘内的變化,從中可以看出趨勢。
$ uptime
17:03:14 up 13 min, 1 user, load average: 0.00, 0.02, 0.03
或者用 top 指令:
持續觀察變化(或者使用 top 指令):
$ watch -d uptime
平均負載越高,說明系統越繁忙,但系統繁忙不代表CPU繁忙。
說明
平均負載:機關時間内,系統處于可運作狀态和不可中斷狀态的平均活躍程序數。
可運作狀态:正在使用CPU或等待使用CPU(R狀态,Running or Runnable)
不可中斷狀态:處于核心關鍵流程且不可被中斷,最常見為等待硬體響應(D狀态,Uninterruptible sleep)
理想狀态下,系統多少CPU就同時運作多少程序,平均負載 <= CPU Core數(一般在平均負載到達70%時要留意)。(但我不清楚在開啟了超線程之後,這個公式應該進行怎樣的調整)。
當平均負載 > CPU Core數時,就會發生超載。
平均負載升高的原因
存在CPU密集型程序
特征:CPU使用率很高
上圖顯示系統負載接近3, 2個 cpu 使用率都為100%,其中有3個程序占用了大量 cpu
$ mpstat -P ALL 1
Linux 4.15.0-112-generic (aaa_ubuntu) 08/15/2020 _x86_64_ (2 CPU)
06:02:55 PM CPU %usr %nice %sys %iowait %irq %soft %steal %guest %gnice %idle
06:02:56 PM all 100.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00
06:02:56 PM 0 100.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00
06:02:56 PM 1 100.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00
06:02:56 PM CPU %usr %nice %sys %iowait %irq %soft %steal %guest %gnice %idle
06:02:57 PM all 100.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00
06:02:57 PM 0 100.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00
06:02:57 PM 1 100.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00
06:02:57 PM CPU %usr %nice %sys %iowait %irq %soft %steal %guest %gnice %idle
06:02:58 PM all 100.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00
06:02:58 PM 0 100.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00
06:02:58 PM 1 100.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00
上圖顯示 每個 cpu 的使用率,跟 top 顯示的一緻。
$ pidstat -u 1
Linux 4.15.0-112-generic (aaa_ubuntu) 08/15/2020 _x86_64_ (2 CPU)
06:03:21 PM UID PID %usr %system %guest %wait %CPU CPU Command
06:03:22 PM 1000 2902 70.30 0.00 0.00 28.71 70.30 0 stress
06:03:22 PM 1000 2903 59.41 0.00 0.00 40.59 59.41 1 stress
06:03:22 PM 1000 2904 69.31 0.00 0.00 31.68 69.31 1 stress
06:03:22 PM UID PID %usr %system %guest %wait %CPU CPU Command
06:03:23 PM 1000 2902 72.00 0.00 0.00 29.00 72.00 1 stress
06:03:23 PM 1000 2903 61.00 0.00 0.00 38.00 61.00 0 stress
06:03:23 PM 1000 2904 64.00 0.00 0.00 34.00 64.00 1 stress
06:03:23 PM UID PID %usr %system %guest %wait %CPU CPU Command
06:03:24 PM 1000 2727 0.00 1.00 0.00 0.00 1.00 0 sshd
06:03:24 PM 1000 2902 55.00 0.00 0.00 45.00 55.00 1 stress
06:03:24 PM 1000 2903 79.00 0.00 0.00 21.00 79.00 0 stress
06:03:24 PM 1000 2904 65.00 0.00 0.00 36.00 65.00 1 stress
06:03:24 PM 1000 2911 0.00 1.00 0.00 1.00 1.00 0 pidstat
上圖顯示共有3個程序占用了 cpu,由于 cpu 隻有2個,任一時刻最多隻有2個程序處于 running 狀态,其餘可運作程序需要等待 cpu,是以 %wait 不為0。
存在 I/O 密集型程序
上圖可知,系統負載超過6, 2個 cpu 的 us 使用率極低,sy 使用率不高,但是 iowait(wa)很高。
隻有一個程序 stress-ng-hdd 占用了最高的 cpu,但也隻有 23.6%
$ mpstat -P ALL 1
Linux 4.15.0-112-generic (aaa_ubuntu) 08/15/2020 _x86_64_ (2 CPU)
07:02:52 PM CPU %usr %nice %sys %iowait %irq %soft %steal %guest %gnice %idle
07:02:53 PM all 0.00 0.00 19.05 76.19 0.00 4.76 0.00 0.00 0.00 0.00
07:02:53 PM 0 1.11 0.00 7.78 84.44 0.00 6.67 0.00 0.00 0.00 0.00
07:02:53 PM 1 0.00 0.00 30.86 64.20 0.00 3.70 0.00 0.00 0.00 1.23
07:02:53 PM CPU %usr %nice %sys %iowait %irq %soft %steal %guest %gnice %idle
07:02:54 PM all 0.56 0.00 13.41 82.68 0.00 2.79 0.00 0.00 0.00 0.56
07:02:54 PM 0 0.00 0.00 17.71 82.29 0.00 0.00 0.00 0.00 0.00 0.00
07:02:54 PM 1 0.00 0.00 8.64 85.19 0.00 6.17 0.00 0.00 0.00 0.00
07:02:54 PM CPU %usr %nice %sys %iowait %irq %soft %steal %guest %gnice %idle
07:02:55 PM all 0.00 0.00 16.48 72.16 0.00 1.70 0.00 0.00 0.00 9.66
07:02:55 PM 0 1.05 0.00 26.32 72.63 0.00 0.00 0.00 0.00 0.00 0.00
07:02:55 PM 1 0.00 0.00 3.75 72.50 0.00 2.50 0.00 0.00 0.00 21.25
上圖證明大部分時候,cpu 處于 iowait 狀态。
iowait:當系統出現大量 I/O 請求時, cpu(s) 處于空閑狀态的占比
換言之,iowait 導緻的系統負載升高,說明存在 I/O 密集型程序
$ vmstat 1
procs -----------memory---------- ---swap-- -----io---- -system-- ------cpu-----
r b swpd free buff cache si so bi bo in cs us sy id wa st
2 1 0 1649524 98996 2143636 0 0 62 22164 204 395 14 3 74 9 0
1 3 0 2177632 98996 1615300 0 0 0 346208 847 1510 0 33 25 42 0
1 3 0 1981540 98996 1811240 0 0 0 452688 652 2349 0 20 7 73 0
1 1 0 1763932 98996 2029080 0 0 0 249856 737 3307 1 9 16 75 0
1 2 0 1834548 98996 1958472 0 0 0 305152 853 800 0 27 13 60 0
1 2 0 1981648 98996 1811244 0 0 0 424104 1469 2600 1 25 5 69 0
1 1 0 1820168 98996 1972576 0 0 0 319488 1023 4004 0 10 7 84 0
上圖中的 bo清單示每秒發送到塊裝置的塊數。這裡 bo 的數值很高,說明系統在不停對裝置進行寫入操作。
iowait 的一個誤區:認為 iowait 高就代表系統有問題。
實際上,iowait 高,隻不過是表示系統有大量 I/O,但是 cpu 相當空閑。
以下在相同的 I/O 壓力下,加入了 cpu 密集型程序後,可以使得 iowait 歸 0。
上圖可知,系統負載超高,2個 cpu 占滿,但 iowait (wa) 為0.
$ vmstat 1
procs -----------memory---------- ---swap-- -----io---- -system-- ------cpu-----
r b swpd free buff cache si so bi bo in cs us sy id wa st
7 4 0 2600296 100532 1190628 0 0 57 32733 310 618 15 5 69 11 0
6 5 0 2280636 100540 1510400 0 0 0 297180 7457 13156 64 37 0 0 0
8 0 0 1979456 100540 1811496 0 0 0 308292 8827 16074 63 37 0 0 0
6 5 0 2487384 100540 1303244 0 0 0 4136 6161 18759 75 26 0 0 0
6 1 0 2831760 100540 959420 0 0 0 200224 5428 11782 67 33 0 0 0
7 0 0 2493116 100544 1297968 0 0 0 348316 4865 8087 68 33 0 0 0
6 1 0 2129112 100556 1662036 0 0 0 336748 4807 7636 67 33 0 0 0
6 5 0 1979488 100564 1811568 0 0 0 166660 6162 14022 65 35 0 0 0
10 0 0 2951312 100564 839928 0 0 0 81340 5637 15043 67 34 0 0 0
10 0 0 2653460 100592 1137528 0 0 0 288684 6314 11247 69 31 0 0 0
7 1 0 2336184 100600 1454700 0 0 0 333828 3902 6083 71 30 0 0 0
上圖可知,bo 列值很高,證明仍然在進行大量的寫裝置操作,us列值很高,證明有程式使用了大量 cpu。
在高頻 I/O 時間段内,cpu 并不空閑,是以 iowait 為0
存在大量處于可運作狀态的程序
特征:running 隊列過長(或R狀态程序過多),CPU使用率高,但每個程序的CPU使用率不高
上圖可見系統負載 > 9,2個 cpu 占滿,11個 running 程序,其中10個程序占用 cpu 的總和接近了 2個 cpu。
$ pidstat -u 1
Linux 4.15.0-112-generic (aaa_ubuntu) 08/15/2020 _x86_64_ (2 CPU)
06:22:17 PM UID PID %usr %system %guest %wait %CPU CPU Command
06:22:18 PM 1000 2547 18.27 0.00 0.00 75.00 18.27 1 stress
06:22:18 PM 1000 2548 19.23 0.00 0.00 75.96 19.23 0 stress
06:22:18 PM 1000 2549 20.19 0.00 0.00 78.85 20.19 1 stress
06:22:18 PM 1000 2550 19.23 0.00 0.00 76.92 19.23 1 stress
06:22:18 PM 1000 2551 19.23 0.00 0.00 76.92 19.23 1 stress
06:22:18 PM 1000 2552 19.23 0.00 0.00 76.92 19.23 0 stress
06:22:18 PM 1000 2553 19.23 0.00 0.00 76.92 19.23 0 stress
06:22:18 PM 1000 2554 19.23 0.00 0.00 77.88 19.23 0 stress
06:22:18 PM 1000 2555 19.23 0.00 0.00 77.88 19.23 0 stress
06:22:18 PM 1000 2556 19.23 0.00 0.00 76.92 19.23 1 stress
06:22:18 PM UID PID %usr %system %guest %wait %CPU CPU Command
06:22:19 PM 1000 2547 21.00 0.00 0.00 82.00 21.00 1 stress
06:22:19 PM 1000 2548 20.00 0.00 0.00 80.00 20.00 0 stress
06:22:19 PM 1000 2549 19.00 0.00 0.00 80.00 19.00 1 stress
06:22:19 PM 1000 2550 20.00 0.00 0.00 80.00 20.00 1 stress
06:22:19 PM 1000 2551 20.00 0.00 0.00 80.00 20.00 1 stress
06:22:19 PM 1000 2552 20.00 0.00 0.00 81.00 20.00 0 stress
06:22:19 PM 1000 2553 19.00 0.00 0.00 80.00 19.00 0 stress
06:22:19 PM 1000 2554 20.00 0.00 0.00 79.00 20.00 0 stress
06:22:19 PM 1000 2555 20.00 0.00 0.00 80.00 20.00 0 stress
06:22:19 PM 1000 2556 20.00 0.00 0.00 80.00 20.00 1 stress
06:22:19 PM 1000 2609 0.00 1.00 0.00 0.00 1.00 1 pidstat
%wait 高,表示程序等待CPU的時間長。(注意,pidstat 中的 %wait 跟 top指令中的 wait 不一樣,top的 wait 指的是 iowait)
由此可知,這些程序大部分時候都在等待 cpu。
存在大量處于可運作狀态的線程
當系統存在大量可運作線程時,就算可運作程序很少,也會造成 system load 升高。
上圖可看出 load average 很高,目前隻有一個程序處于 running 狀态,cpu sy 比 cpu us 要高,這個 sysbench 的程序占用了最多的 cpu。
$ pidstat -u 1 -p 2806
Linux 4.15.0-112-generic (aaa_ubuntu) 08/15/2020 _x86_64_ (2 CPU)
05:16:32 PM UID PID %usr %system %guest %wait %CPU CPU Command
05:16:33 PM 1000 2806 60.00 100.00 0.00 0.00 100.00 0 sysbench
05:16:34 PM 1000 2806 61.00 100.00 0.00 0.00 100.00 0 sysbench
05:16:35 PM 1000 2806 54.00 100.00 0.00 0.00 100.00 0 sysbench
05:16:36 PM 1000 2806 56.00 100.00 0.00 0.00 100.00 0 sysbench
05:16:37 PM 1000 2806 58.00 100.00 0.00 0.00 100.00 0 sysbench
05:16:38 PM 1000 2806 69.00 100.00 0.00 0.00 100.00 0 sysbench
上圖每秒列印一次 sysbench 程序的 cpu 使用率,可看出确實占用了大量 cpu。
$ pidstat -ut 1 -p 2806
Linux 4.15.0-112-generic (aaa_ubuntu) 08/15/2020 _x86_64_ (2 CPU)
05:17:04 PM UID TGID TID %usr %system %guest %wait %CPU CPU Command
05:17:05 PM 1000 2806 - 64.00 100.00 0.00 0.00 100.00 0 sysbench
05:17:05 PM 1000 - 2806 0.00 0.00 0.00 0.00 0.00 0 |__sysbench
05:17:05 PM 1000 - 2807 8.00 14.00 0.00 49.00 22.00 1 |__sysbench
05:17:05 PM 1000 - 2808 3.00 19.00 0.00 51.00 22.00 1 |__sysbench
05:17:05 PM 1000 - 2809 7.00 9.00 0.00 64.00 16.00 0 |__sysbench
05:17:05 PM 1000 - 2810 9.00 8.00 0.00 63.00 17.00 0 |__sysbench
05:17:05 PM 1000 - 2811 6.00 11.00 0.00 68.00 17.00 1 |__sysbench
05:17:05 PM 1000 - 2812 8.00 16.00 0.00 42.00 24.00 1 |__sysbench
05:17:05 PM 1000 - 2813 8.00 10.00 0.00 63.00 18.00 0 |__sysbench
05:17:05 PM 1000 - 2814 3.00 20.00 0.00 56.00 23.00 1 |__sysbench
05:17:05 PM 1000 - 2815 5.00 11.00 0.00 67.00 16.00 0 |__sysbench
05:17:05 PM 1000 - 2816 8.00 10.00 0.00 65.00 18.00 0 |__sysbench
05:17:05 PM UID TGID TID %usr %system %guest %wait %CPU CPU Command
05:17:06 PM 1000 2806 - 58.00 100.00 0.00 0.00 100.00 0 sysbench
05:17:06 PM 1000 - 2806 0.00 0.00 0.00 0.00 0.00 0 |__sysbench
05:17:06 PM 1000 - 2807 6.00 12.00 0.00 57.00 18.00 1 |__sysbench
05:17:06 PM 1000 - 2808 4.00 15.00 0.00 61.00 19.00 1 |__sysbench
05:17:06 PM 1000 - 2809 6.00 14.00 0.00 53.00 20.00 0 |__sysbench
05:17:06 PM 1000 - 2810 6.00 14.00 0.00 60.00 20.00 0 |__sysbench
05:17:06 PM 1000 - 2811 6.00 13.00 0.00 65.00 19.00 1 |__sysbench
05:17:06 PM 1000 - 2812 4.00 14.00 0.00 58.00 18.00 1 |__sysbench
05:17:06 PM 1000 - 2813 5.00 14.00 0.00 57.00 19.00 0 |__sysbench
05:17:06 PM 1000 - 2814 6.00 13.00 0.00 66.00 19.00 1 |__sysbench
05:17:06 PM 1000 - 2815 6.00 15.00 0.00 63.00 21.00 0 |__sysbench
05:17:06 PM 1000 - 2816 9.00 11.00 0.00 55.00 20.00 0 |__sysbench
上圖加上 -t 選項後,列印了 sysbench 内部線程的 cpu 使用率,可以看出 %wait 很高,這代表各個線程等待 cpu 的時間很長。
檢視線程上下文切換
上圖可知存在大量可運作的線程導緻系統負載升高
$ mpstat -P ALL 1
Linux 4.15.0-112-generic (aaa_ubuntu) 08/15/2020 _x86_64_ (2 CPU)
06:42:13 PM CPU %usr %nice %sys %iowait %irq %soft %steal %guest %gnice %idle
06:42:14 PM all 36.00 0.00 64.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00
06:42:14 PM 0 31.68 0.00 68.32 0.00 0.00 0.00 0.00 0.00 0.00 0.00
06:42:14 PM 1 40.00 0.00 60.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00
06:42:14 PM CPU %usr %nice %sys %iowait %irq %soft %steal %guest %gnice %idle
06:42:15 PM all 34.00 0.00 66.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00
06:42:15 PM 0 32.00 0.00 68.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00
06:42:15 PM 1 36.00 0.00 64.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00
06:42:15 PM CPU %usr %nice %sys %iowait %irq %soft %steal %guest %gnice %idle
06:42:16 PM all 30.50 0.00 69.50 0.00 0.00 0.00 0.00 0.00 0.00 0.00
06:42:16 PM 0 31.00 0.00 69.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00
06:42:16 PM 1 30.00 0.00 70.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00
上圖可知,大部分 cpu 用于 kernel (%sys 比 %usr 高很多)
$ vmstat 1
procs -----------memory---------- ---swap-- -----io---- -system-- ------cpu-----
r b swpd free buff cache si so bi bo in cs us sy id wa st
8 0 0 3266356 96552 536796 0 0 36 393 3394 3068 38 13 47 1 0
7 0 0 3266376 96552 536796 0 0 0 0 39782 943369 33 67 1 0 0
8 0 0 3266376 96552 536796 0 0 0 0 38650 909726 30 70 0 0 0
10 0 0 3266376 96552 536796 0 0 0 0 38048 971882 31 69 0 0 0
7 0 0 3266376 96552 536796 0 0 0 0 39544 962102 30 70 0 0 0
8 0 0 3266376 96552 536796 0 0 0 0 39163 917229 28 72 0 0 0
8 0 0 3266376 96552 536796 0 0 0 0 39437 1003420 30 70 0 0 0
10 0 0 3266376 96552 536796 0 0 0 0 42390 939651 27 73 0 0 0
8 0 0 3266376 96552 536796 0 0 0 0 43100 977931 34 66 0 0 0
9 0 0 3266376 96552 536796 0 0 0 0 40550 971362 36 64 0 0 0
6 0 0 3266376 96552 536796 0 0 0 0 39410 947462 29 71 0 0 0
8 0 0 3266376 96552 536796 0 0 0 0 40276 944977 28 72 0 0 0
上圖可知,上下文切換次數超高(cs 對應列), 中斷數也很高(in 對應列)
$ pidstat -wt 1 -p 2938
Linux 4.15.0-112-generic (aaa_ubuntu) 08/15/2020 _x86_64_ (2 CPU)
05:17:44 PM UID TGID TID cswch/s nvcswch/s Command
05:17:45 PM 1000 2938 - 0.00 0.00 sysbench
05:17:45 PM 1000 - 2806 0.00 0.00 |__sysbench
05:17:45 PM 1000 - 2807 10785.00 77586.00 |__sysbench
05:17:45 PM 1000 - 2808 8773.00 72765.00 |__sysbench
05:17:45 PM 1000 - 2809 10349.00 82741.00 |__sysbench
05:17:45 PM 1000 - 2810 9048.00 77654.00 |__sysbench
05:17:45 PM 1000 - 2811 11500.00 81969.00 |__sysbench
05:17:45 PM 1000 - 2812 10458.00 81610.00 |__sysbench
05:17:45 PM 1000 - 2813 6844.00 85061.00 |__sysbench
05:17:45 PM 1000 - 2814 11279.00 82209.00 |__sysbench
05:17:45 PM 1000 - 2815 11345.00 75471.00 |__sysbench
05:17:45 PM 1000 - 2816 9282.00 82881.00 |__sysbench
05:17:45 PM UID TGID TID cswch/s nvcswch/s Command
05:17:46 PM 1000 2938 - 0.00 0.00 sysbench
05:17:46 PM 1000 - 2806 0.00 0.00 |__sysbench
05:17:46 PM 1000 - 2807 8328.00 82343.00 |__sysbench
05:17:46 PM 1000 - 2808 7356.00 84236.00 |__sysbench
05:17:46 PM 1000 - 2809 8468.00 77616.00 |__sysbench
05:17:46 PM 1000 - 2810 10228.00 82942.00 |__sysbench
05:17:46 PM 1000 - 2811 10503.00 82221.00 |__sysbench
05:17:46 PM 1000 - 2812 12488.00 75746.00 |__sysbench
05:17:46 PM 1000 - 2813 10551.00 84009.00 |__sysbench
05:17:46 PM 1000 - 2814 11311.00 81515.00 |__sysbench
05:17:46 PM 1000 - 2815 6739.00 74858.00 |__sysbench
05:17:46 PM 1000 - 2816 9154.00 84515.00 |__sysbench
上圖列印的是 sysbench 程序内線程的上下文切換情況。
cswch:自願上下文切換次數,當所需資源不可用時就會出現。
nvcswch:非自願上下文切換次數,當任務所分派的 cpu 時間分片用完後,就會被要求強制放棄 cpu。(或者被更高優先級的搶占)
上圖顯示 nvcwsch 很大,說明同一時間,系統存在大量可運作的線程,但是 cpu 不足,導緻頻繁切換線程上下文。線程上下文切換也是需要消耗系統 cpu 的,是以 cpu sy 很高。
之前通過 vmstat 檢視到中斷數也很高,可以通過指令 watch -d cat /proc/interrupts 來确定是哪種硬中斷導緻。
上圖可知,RES 重排程中斷增長很快,RES 中斷用于不停喚醒空閑 CPU 來處理任務(隻在多 CPU 系統才存在),說明了上下文頻繁切換(這裡是線程上下文)。
檢視短程序導緻CPU升高
上圖可知,cpu 使用率頗高,但是 top 清單中沒有出現高 cpu 的程序。
$ mpstat -P ALL 1
Linux 4.15.0-112-generic (aaa_ubuntu) 08/16/2020 _x86_64_ (2 CPU)
04:35:37 PM CPU %usr %nice %sys %iowait %irq %soft %steal %guest %gnice %idle
04:35:38 PM all 19.10 0.00 0.50 5.03 0.00 0.50 0.00 0.00 0.00 74.87
04:35:38 PM 0 36.63 0.00 0.00 2.97 0.00 0.99 0.00 0.00 0.00 59.41
04:35:38 PM 1 2.04 0.00 1.02 6.12 0.00 0.00 0.00 0.00 0.00 90.82
04:35:38 PM CPU %usr %nice %sys %iowait %irq %soft %steal %guest %gnice %idle
04:35:39 PM all 34.18 0.00 1.02 4.08 0.00 0.00 0.00 0.00 0.00 60.71
04:35:39 PM 0 22.45 0.00 1.02 4.08 0.00 1.02 0.00 0.00 0.00 71.43
04:35:39 PM 1 45.36 0.00 1.03 4.12 0.00 0.00 0.00 0.00 0.00 49.48
04:35:39 PM CPU %usr %nice %sys %iowait %irq %soft %steal %guest %gnice %idle
04:35:40 PM all 50.75 0.00 1.51 2.51 0.00 0.50 0.00 0.00 0.00 44.72
04:35:40 PM 0 10.20 0.00 1.02 5.10 0.00 0.00 0.00 0.00 0.00 83.67
04:35:40 PM 1 91.00 0.00 1.00 0.00 0.00 1.00 0.00 0.00 0.00 7.00
04:35:40 PM CPU %usr %nice %sys %iowait %irq %soft %steal %guest %gnice %idle
04:35:41 PM all 51.53 0.00 1.02 3.57 0.00 0.00 0.00 0.00 0.00 43.88
04:35:41 PM 0 62.63 0.00 2.02 1.01 0.00 0.00 0.00 0.00 0.00 34.34
04:35:41 PM 1 40.00 0.00 1.00 6.00 0.00 0.00 0.00 0.00 0.00 53.00
04:35:41 PM CPU %usr %nice %sys %iowait %irq %soft %steal %guest %gnice %idle
04:35:42 PM all 51.01 0.00 1.52 3.03 0.00 0.00 0.00 0.00 0.00 44.44
04:35:42 PM 0 67.33 0.00 1.98 1.98 0.00 0.00 0.00 0.00 0.00 28.71
04:35:42 PM 1 34.38 0.00 1.04 4.17 0.00 0.00 0.00 0.00 0.00 60.42
上圖可知,2個 cpu 大部分時間确實是花費在使用者态程式的執行上。
$ pidstat -u 1
Linux 4.15.0-112-generic (aaa_ubuntu) 08/16/2020 _x86_64_ (2 CPU)
04:38:20 PM UID PID %usr %system %guest %wait %CPU CPU Command
04:38:21 PM 0 217 0.00 1.00 0.00 0.00 1.00 0 kworker/0:1H
04:38:21 PM 0 337 0.00 1.00 0.00 0.00 1.00 0 jbd2/sda2-8
04:38:21 PM 0 819 5.00 1.00 0.00 0.00 6.00 0 snapd
04:38:21 PM 1000 3821 1.00 0.00 0.00 0.00 1.00 0 pidstat
04:38:21 PM 0 3825 2.00 0.00 0.00 0.00 2.00 0 stress
04:38:21 PM UID PID %usr %system %guest %wait %CPU CPU Command
04:38:22 PM 0 819 5.94 0.00 0.00 0.00 5.94 0 snapd
04:38:22 PM 0 1951 0.00 0.99 0.00 0.00 0.99 0 kworker/u4:0
04:38:22 PM 0 3829 1.98 0.00 0.00 0.00 1.98 0 stress
04:38:22 PM UID PID %usr %system %guest %wait %CPU CPU Command
04:38:23 PM 0 819 7.00 0.00 0.00 0.00 7.00 0 snapd
04:38:23 PM 1000 2446 0.00 1.00 0.00 0.00 1.00 0 sshd
04:38:23 PM UID PID %usr %system %guest %wait %CPU CPU Command
04:38:24 PM 0 8 0.00 1.00 0.00 0.00 1.00 0 rcu_sched
04:38:24 PM 0 215 0.00 1.00 0.00 0.00 1.00 1 kworker/1:1H
04:38:24 PM 0 819 5.00 1.00 0.00 0.00 6.00 0 snapd
04:38:24 PM 0 3833 2.00 0.00 0.00 0.00 2.00 1 stress
04:38:24 PM UID PID %usr %system %guest %wait %CPU CPU Command
04:38:25 PM 0 819 6.00 0.00 0.00 0.00 6.00 0 snapd
04:38:25 PM 1000 2446 0.00 1.00 0.00 0.00 1.00 0 sshd
04:38:25 PM 1000 3821 0.00 1.00 0.00 1.00 1.00 0 pidstat
04:38:25 PM 0 3837 1.00 0.00 0.00 0.00 1.00 0 stress
04:38:25 PM UID PID %usr %system %guest %wait %CPU CPU Command
04:38:26 PM 0 337 0.00 1.00 0.00 1.00 1.00 1 jbd2/sda2-8
04:38:26 PM 0 819 6.00 1.00 0.00 0.00 7.00 0 snapd
04:38:26 PM 0 3841 1.00 0.00 0.00 0.00 1.00 1 stress
上圖沒有發現使用大量 cpu 的程序。
這時候就需要懷疑一下是不是短程序在作怪。可以使用以下工具來檢視。
這個腳本可以直接使用,不需要其他依賴或者安裝。
perf-tools/execsnoop
# ./execsnoop -t
Tracing exec()s. Ctrl-C to end.
Instrumenting sys_execve
TIMEs PID PPID ARGS
2770.354823 7359 7355 gawk -v o=1 -v opt_name=0 -v name= -v opt_duration=0 [...]
2770.356679 7360 7358 cat -v trace_pipe
2771.141217 7362 7361 new_child_proc-7362 [001] .... 2771.141217: execsnoop_sys_execve: (SyS_execve+0x0/0x40)
2771.142194 7363 7362 /usr/bin/stress -c 1 -t 1
2772.141682 7366 7365 new_child_proc-7366 [001] .... 2772.141682: execsnoop_sys_execve: (SyS_execve+0x0/0x40)
2772.142493 7367 7366 /usr/bin/stress -c 1 -t 1
2773.143181 7370 7369 new_child_proc-7370 [001] .... 2773.143181: execsnoop_sys_execve: (SyS_execve+0x0/0x40)
2773.144564 7371 7370 /usr/bin/stress -c 1 -t 1
2774.143527 7374 7373 new_child_proc-7374 [001] .... 2774.143527: execsnoop_sys_execve: (SyS_execve+0x0/0x40)
2774.144244 7375 7374 /usr/bin/stress -c 1 -t 1
2775.143685 7378 7377 new_child_proc-7378 [000] .... 2775.143685: execsnoop_sys_execve: (SyS_execve+0x0/0x40)
2775.144391 7379 7378 /usr/bin/stress -c 1 -t 1
2777.147780 7382 7381 new_child_proc-7382 [001] .... 2777.147780: execsnoop_sys_execve: (SyS_execve+0x0/0x40)
2777.148508 7383 7382 /usr/bin/stress -c 1 -t 1
2778.148406 7386 7385 new_child_proc-7386 [001] .... 2778.148406: execsnoop_sys_execve: (SyS_execve+0x0/0x40)
2778.149217 7387 7386 /usr/bin/stress -c 1 -t 1
2779.148549 7390 7389 new_child_proc-7390 [001] .... 2779.148549: execsnoop_sys_execve: (SyS_execve+0x0/0x40)
2779.149486 7391 7390 /usr/bin/stress -c 1 -t 1
上圖可知,大約每隔1s,就會産生一個新的程序,這個程序又調用了 system 方法來産生另外一個子程序
"/usr/bin/stress -c 1 -t 1"
$ ps aux | grep 7355
root 8210 0.0 0.0 13136 1028 pts/1 S+ 16:57 0:00 grep --color=auto 7355
$ ps aux | grep 7359
root 8224 0.0 0.0 13136 1008 pts/1 S+ 16:57 0:00 grep --color=auto 7359
但如果使用 ps 來查找這些程序的話,又會發現它們都不存在。很明顯,這些都是短時程序。
但是,從上圖可以看到這些短程序,都包含 new_child_proc 。
上圖通過 watch -d “pstree -p | grep new_child_proc” 可以看到這些短時程序,都是由父程序 pid=2502 産生的。
$ ps aux | grep 2502
root 2502 0.0 0.0 4376 1108 pts/0 S+ 16:32 0:00 ./new_child_proc
root 10527 0.0 0.0 13136 1060 pts/1 S+ 17:05 0:00 grep --color=auto 2502
上圖可以确定這個程序确實存在。kill 了它後就正常了。
檢視僵屍程序
上圖可知,目前系統存在大量僵屍程序。
$ ps aux | grep Z+
root 10962 0.0 0.0 0 0 pts/0 Z+ 17:17 0:00 [new_zombie_proc] <defunct>
root 10965 0.0 0.0 0 0 pts/0 Z+ 17:17 0:00 [new_zombie_proc] <defunct>
root 10966 0.0 0.0 0 0 pts/0 Z+ 17:17 0:00 [new_zombie_proc] <defunct>
root 10967 0.0 0.0 0 0 pts/0 Z+ 17:17 0:00 [new_zombie_proc] <defunct>
root 10968 0.0 0.0 0 0 pts/0 Z+ 17:17 0:00 [new_zombie_proc] <defunct>
root 10969 0.0 0.0 0 0 pts/0 Z+ 17:17 0:00 [new_zombie_proc] <defunct>
...
$ ps aux | grep Z+ | wc -l
685
Z+ 表示僵屍程序。
上圖可知,僵屍程序數量很多。
$ pstree -p | grep new_zombie_proc | head -n 10
|-sshd(942)-+-sshd(1979)---sshd(2180)---bash(2182)---sudo(2241)---bash(2243)---new_zombie_proc(10961)-+-new_zombie_proc(+
| | |-new_zombie_proc(+
| | |-new_zombie_proc(+
| | |-new_zombie_proc(+
| | |-new_zombie_proc(+
| | |-new_zombie_proc(+
| | |-new_zombie_proc(+
| | |-new_zombie_proc(+
| | |-new_zombie_proc(+
| | |-new_zombie_proc(+
上圖可以看到僵屍程序的父程序為 pid=10961。
# strace -p 10961
strace: Process 10961 attached
restart_syscall(<... resuming interrupted nanosleep ...>) = 0
clone(child_stack=NULL, flags=CLONE_CHILD_CLEARTID|CLONE_CHILD_SETTID|SIGCHLD, child_tidptr=0x7f851507d790) = 12020
nanosleep({tv_sec=1, tv_nsec=0}, {tv_sec=0, tv_nsec=999992096}) = ? ERESTART_RESTARTBLOCK (Interrupted by signal)
--- SIGCHLD {si_signo=SIGCHLD, si_code=CLD_EXITED, si_pid=12020, si_uid=0, si_status=0, si_utime=0, si_stime=0} ---
restart_syscall(<... resuming interrupted nanosleep ...>) = 0
clone(child_stack=NULL, flags=CLONE_CHILD_CLEARTID|CLONE_CHILD_SETTID|SIGCHLD, child_tidptr=0x7f851507d790) = 12021
nanosleep({tv_sec=1, tv_nsec=0}, {tv_sec=0, tv_nsec=999992340}) = ? ERESTART_RESTARTBLOCK (Interrupted by signal)
--- SIGCHLD {si_signo=SIGCHLD, si_code=CLD_EXITED, si_pid=12021, si_uid=0, si_status=0, si_utime=0, si_stime=0} ---
restart_syscall(<... resuming interrupted nanosleep ...>) = 0
clone(child_stack=NULL, flags=CLONE_CHILD_CLEARTID|CLONE_CHILD_SETTID|SIGCHLD, child_tidptr=0x7f851507d790) = 12022
nanosleep({tv_sec=1, tv_nsec=0}, {tv_sec=0, tv_nsec=999957790}) = ? ERESTART_RESTARTBLOCK (Interrupted by signal)
--- SIGCHLD {si_signo=SIGCHLD, si_code=CLD_EXITED, si_pid=12022, si_uid=0, si_status=0, si_utime=0, si_stime=0} ---
restart_syscall(<... resuming interrupted nanosleep ...>^Cstrace: Process 10961 detached
<detached ...>
上圖使用 strace 可以探查到 pid=10961 的程序使用的 syscall。
# strace -c -p 10961
strace: Process 10961 attached
^Cstrace: Process 10961 detached
% time seconds usecs/call calls errors syscall
------ ----------- ----------- --------- --------- ----------------
81.59 0.000195 49 4 clone
13.39 0.000032 8 4 restart_syscall
5.02 0.000012 3 4 4 nanosleep
------ ----------- ----------- --------- --------- ----------------
100.00 0.000239 12 4 total
這裡顯示的是一段時間内 syscall 的統計。kill 掉 pid=10961 的程序後,所有僵屍程序都消失了。
産生僵屍程序是因為子程序退出後,父程序沒有調用 wait(…),導緻子程序的資訊還一直殘留。當父程序被 kill 後,這些子程序會被當成孤立程序,然後挂接到 init 程序下,由 init 程序進行收割。