關於linux系統CPU篇--->不容易發現的占用CPU較高進程


1.系統的CPU使用率,不僅包括進程用戶態和內核態的運行,還包括中斷處理,等待IO以及內核線程等等。所以,當你發現系統的CPU使用率很高的時候,不一定能找到相對應的高CPU使用率的進程

2.案例分析,排查定位不容易發現的高消耗CPU的進程

 (1).案例准備工作:兩台裝有linux系統的虛擬機,一台用作web服務器,一台用作web服務器的客戶端

 (2).預先安裝docker,sysstat,perf,ab等工具,ab裝在客戶端機器上,其他的安裝在web服務器端

 (3).在第一台機器(web服務器),執行docker命令,運行nginx和PHP:

   docker run --name nginx -p 10000:80 -itd feisky/nginx:sp

   docker run --name phpfpm -itd --network container:nginx feisky/php-fpm:sp

(4).在第二台機器上使用curl訪問,確認nginx正常啟動:

# 192.168.0.10 是第一台虛擬機的 IP 地址
$ curl http://192.168.0.10:10000/
It works!

(5).用ab測試nginx服務的性能,並發100個請求測試nginx性能,總共測試1000個請求:

  # 並發 100 個請求測試 Nginx 性能,總共測試 1000 個請求

$ ab -c 100 -n 1000 http://192.168.0.10:10000/
This is ApacheBench, Version 2.3 <$Revision: 1706008 $>
Copyright 1996 Adam Twiss, Zeus Technology Ltd,
...
Requests per second: 87.86 [#/sec] (mean)
Time per request: 1138.229 [ms] (mean)
...

從ab的輸出結果中,發現nginx能承受的每秒平均請求數只有87多一點,感覺性能有點差,那么,到底是哪出現的問題呢?我們再用top和pidstat觀察下

(6).這次,在第二個終端,將測試的並發請求數改成5,同時把請求時長設為10分鍾,便於測試中分析

   $ ab -c 5 -t 600 http://192.168.0.10:10000/

(7).在第一個終端運行TOP命令,觀察系統的CPU使用情況: 

$ top
...
%Cpu(s): 80.8 us, 15.1 sy, 0.0 ni, 2.8 id, 0.0 wa, 0.0 hi, 1.3 si, 0.0 st
...

PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND
6882 root 20 0 8456 5052 3884 S 2.7 0.1 0:04.78 docker-containe
6947 systemd+ 20 0 33104 3716 2340 S 2.7 0.0 0:04.92 nginx
7494 daemon 20 0 336696 15012 7332 S 2.0 0.2 0:03.55 php-fpm
7495 daemon 20 0 336696 15160 7480 S 2.0 0.2 0:03.55 php-fpm
10547 daemon 20 0 336696 16200 8520 S 2.0 0.2 0:03.13 php-fpm
10155 daemon 20 0 336696 16200 8520 S 1.7 0.2 0:03.12 php-fpm
10552 daemon 20 0 336696 16200 8520 S 1.7 0.2 0:03.12 php-fpm
15006 root 20 0 1168608 66264 37536 S 1.0 0.8 9:39.51 dockerd
4323 root 20 0 0 0 0 I 0.3 0.0 0:00.87 kworker/u4:1
...

觀察TOP的輸出,CPU使用率最高的進程只有2.7%,看起來並不高,再看系統CPU使用率這一行,你會發現,系統整體CPU使用率是比較高的:用戶CPU使用率達到80%,系統CPU使用率15.1%

為什么用戶CPU使用率這么高呢,重新分析一下進程列表,並沒有發現可疑進程

這時候,我們可以用pidstat,它可以用來分析進程的CPU使用情況

接下來,在第一台機器上,運行pidstat 命令

# 間隔 1 秒輸出一組數據(按 Ctrl+C 結束)
$ pidstat 1
...
04:36:24 UID PID %usr %system %guest %wait %CPU CPU Command
04:36:25 0 6882 1.00 3.00 0.00 0.00 4.00 0 docker-containe
04:36:25 101 6947 1.00 2.00 0.00 1.00 3.00 1 nginx
04:36:25 1 14834 1.00 1.00 0.00 1.00 2.00 0 php-fpm
04:36:25 1 14835 1.00 1.00 0.00 1.00 2.00 0 php-fpm
04:36:25 1 14845 0.00 2.00 0.00 2.00 2.00 1 php-fpm
04:36:25 1 14855 0.00 1.00 0.00 1.00 1.00 1 php-fpm
04:36:25 1 14857 1.00 2.00 0.00 1.00 3.00 0 php-fpm
04:36:25 0 15006 0.00 1.00 0.00 0.00 1.00 0 dockerd
04:36:25 0 15801 0.00 1.00 0.00 0.00 1.00 1 pidstat
04:36:25 1 17084 1.00 0.00 0.00 2.00 1.00 0 stress
04:36:25 0 31116 0.00 1.00 0.00 0.00 1.00 0 atopacctd
...

從pidstat 輸出中,並沒有發現占用CPU很高的進程,即使所有進程的CPU使用率加起來,也不過21%,離80%還差的遠

明明系統CPU使用率很高,達到了80%,為什么找不到占用CPU使用率高的進程呢?

很可能是因為前面的分析漏了一些關鍵信息,返回去分析TOP的輸出,看看能不能有新的發現:

在第一台機器上,繼續執行TOP命令:

$ top
top - 04:58:24 up 14 days, 15:47, 1 user, load average: 3.39, 3.82, 2.74
Tasks: 149 total, 6 running, 93 sleeping, 0 stopped, 0 zombie
%Cpu(s): 77.7 us, 19.3 sy, 0.0 ni, 2.0 id, 0.0 wa, 0.0 hi, 1.0 si, 0.0 st
KiB Mem : 8169348 total, 2543916 free, 457976 used, 5167456 buff/cache
KiB Swap: 0 total, 0 free, 0 used. 7363908 avail Mem

PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND
6947 systemd+ 20 0 33104 3764 2340 S 4.0 0.0 0:32.69 nginx
6882 root 20 0 12108 8360 3884 S 2.0 0.1 0:31.40 docker-containe
15465 daemon 20 0 336696 15256 7576 S 2.0 0.2 0:00.62 php-fpm
15466 daemon 20 0 336696 15196 7516 S 2.0 0.2 0:00.62 php-fpm
15489 daemon 20 0 336696 16200 8520 S 2.0 0.2 0:00.62 php-fpm
6948 systemd+ 20 0 33104 3764 2340 S 1.0 0.0 0:00.95 nginx
15006 root 20 0 1168608 65632 37536 S 1.0 0.8 9:51.09 dockerd
15476 daemon 20 0 336696 16200 8520 S 1.0 0.2 0:00.61 php-fpm
15477 daemon 20 0 336696 16200 8520 S 1.0 0.2 0:00.61 php-fpm
24340 daemon 20 0 8184 1616 536 R 1.0 0.0 0:00.01 stress
24342 daemon 20 0 8196 1580 492 R 1.0 0.0 0:00.01 stress
24344 daemon 20 0 8188 1056 492 R 1.0 0.0 0:00.01 stress
24347 daemon 20 0 8184 1356 540 R 1.0 0.0 0:00.01 stress
...

從top的輸出,可以發現,就緒隊列中居然有6個running狀態的進程,是不是有點多呢?

回想下ab測試的參數,並發請求數是5,再看進程列表,php-fpm的數量也是5,再加上nginx,好像同時6個進程也不奇怪。

再仔細觀察進程列表,發現php-fpm 的進程狀態都是 S(休眠),而真正處於R狀態的進程,卻是幾個stress進程,這幾個stress進程比較奇怪,需要我們進一步分析

還是使用pidstat來分析這幾個進程,並且使用 -p指定進程的PID.從上面的top中,找到幾個進程的PID,用pidstat命令看一下它的CPU使用情況:

$ pidstat -p 24344

16:14:55 UID PID %usr %system %guest %wait %CPU CPU Command

奇怪,居然沒有任何輸出,再使用ps ,查看24344進程的狀態:

# 從所有進程中查找 PID 是 24344 的進程
$ ps aux | grep 24344
root 9628 0.0 0.0 14856 1096 pts/0 S+ 16:15 0:00 grep --color=auto 24344

還是沒有任何輸出,現在終於發現,原來這個進程已經不存在了,所以pidstat沒有任何輸出,既然進程沒了,那性能問題應該解決了吧,再用TOP命令確認下

$ top
...
%Cpu(s): 80.9 us, 14.9 sy, 0.0 ni, 2.8 id, 0.0 wa, 0.0 hi, 1.3 si, 0.0 st
...

PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND
6882 root 20 0 12108 8360 3884 S 2.7 0.1 0:45.63 docker-containe
6947 systemd+ 20 0 33104 3764 2340 R 2.7 0.0 0:47.79 nginx
3865 daemon 20 0 336696 15056 7376 S 2.0 0.2 0:00.15 php-fpm
6779 daemon 20 0 8184 1112 556 R 0.3 0.0 0:00.01 stress
...

從TOP輸出中,發現用戶CPU使用率還是高達80%,系統CPU接近15%,空閑只有2.8%,RUNNING狀態的進程有Nginx,stress

可是,剛剛看到的stress進程不存在了,原來這次stress進程的PID跟前面不一樣了,原來的PID 24344不見了,現在的是6779。

進程PID在變,說明什么呢?要么是進程在不斷重啟,要么就是全新的進程,無非也就是兩個原因:

(1).第一個原因,進程在不停的崩潰重啟,比如因為段錯誤,配置錯誤等等

(2).進程都是短時進程,也就是其他應用內部通過exec調用的外部命令,這些命令一般都只會運行很短時間就會結束,很難用top這種間隔時間比較長的工具發現(上面的案例,我們碰巧發現了)

至於stress,它是一個常用的壓力測試工具,它的PID在不斷變化中,看起來像是被其他進程調用的短時進程,要想繼續分析下去,需要找到它們的父進程

用pstree就可以用樹狀形式顯示所有進程之間的關系:

$ pstree | grep stress
|-docker-containe-+-php-fpm-+-php-fpm---sh---stress
| |-3*[php-fpm---sh---stress---stress]

從輸出結果可以看出,streess是被php-fpm調用的子進程,並且數量不只一個(3個),找到父進程后,就能進入app內部分析了

當然我們應該去看看它的源碼。運行下面的命令把源碼拷貝到app目錄,然后再執行grep查看是不是有代碼在調用stress命令:

# 拷貝源碼到本地
$ docker cp phpfpm:/app .

# grep 查找看看是不是有代碼在調用 stress 命令
$ grep stress -r app
app/index.php:// fake I/O with stress (via write()/unlink()).
app/index.php:$result = exec("/usr/local/bin/stress -t 1 -d 1 2>&1", $output, $status);

果然是 app/index.php文件直接調用了stress命令

再來看看app/index.php的源代碼:

$ cat app/index.php
<?php
// fake I/O with stress (via write()/unlink()).
$result = exec("/usr/local/bin/stress -t 1 -d 1 2>&1", $output, $status);
if (isset($_GET["verbose"]) && $_GET["verbose"]==1 && $status != 0) {
echo "Server internal error: ";
print_r($output);
} else {
echo "It works!";
}
?>

可以看到,源碼里每個請求都會調用stress命令,模擬IO壓力。從注釋上看,stress會通過write()和unlink()對IO進行壓測。看來,這就是CPU使用率升高的根源

不過,stress模擬的是IO壓力,而之前top中輸出的,卻一直是用戶CPU和系統CPU升高,並沒有iowait升高。這又是怎么回事呢?Stress到底是不是CPU使用率升高的原因呢?

我們還得繼續往下分析,給請求加上verbose=1參數后,就可以查看stress的輸出。先試試看,在第二台機器運行:

$ curl http://192.168.0.10:10000?verbose=1
Server internal error: Array
(
[0] => stress: info: [19607] dispatching hogs: 0 cpu, 0 io, 0 vm, 1 hdd
[1] => stress: FAIL: [19608] (563) mkstemp failed: Permission denied
[2] => stress: FAIL: [19607] (394) <-- worker 19608 returned error 1
[3] => stress: WARN: [19607] (396) now reaping child worker processes
[4] => stress: FAIL: [19607] (400) kill error: No such process
[5] => stress: FAIL: [19607] (451) failed run completed in 0s
)

看錯誤消息,原來stress命令並沒有成功,它因為權限問題失敗退出了。看來,我們發現了PHP調用外部stress命令的bug:沒有權限創建臨時文件

從這里我們可以猜測,正是由於權限錯誤,大量的stress進程在啟動時初始化失敗,進而導致用戶CPU使用率升高

前面,我們用了top.pidstat,pstress,沒有發現大量的stress進程,那么,還有什么其他的工具可以用嗎?

還記得之前的perf嗎?它可以用來分析CPU性能事件,用在這里很合適,在第一個終端中運行perf record -g 命令,並等待一會(比如15秒)后按ctrc+c退出。然后再運行perf report查看

# 記錄性能事件,等待大約 15 秒后按 Ctrl+C 退出
$ perf record -g

# 查看報告
$ perf report

這樣就可以看到下圖這個性能報告:

從報告輸出中可以看到,stress調用棧中比例最高,是隨機數生成random(),看來他的確就是CPU使用率升高的元凶了。

優化很簡單,只要修復權限問題,並減少或刪除stress調用,就可以減輕系統的CPU壓力。

案例結束后,記得清理環境:

docker rm -f nginx php-fpm

總結:

 碰到常規問題無法解釋CPU使用率情況時,首先要想到的是短時應用導致的問題,比如有可能是下面這兩種情況:

   (1).應用里直接調用了其他二進制程序,這些程序通常運行時間比較短,通過top等工具也不容易發現

   (2).應用本身在不停的崩潰重啟,而啟動過程的資源初始化,很可能會占用相當多的CPU

   對於這類進程,我們可以用pstree或者execsnoop找到它們的父進程,再從父進程所在的應用入手,排查問題的根源

 


免責聲明!

本站轉載的文章為個人學習借鑒使用,本站對版權不負任何法律責任。如果侵犯了您的隱私權益,請聯系本站郵箱yoyou2525@163.com刪除。



 
粵ICP備18138465號   © 2018-2025 CODEPRJ.COM