??? 上一節講了 CPU 使用率是什么，并通過一個案例教你使用 top、vmstat、pidstat 等工具，排查高 CPU 使用率的進程，然后再使用 perf top 工具，定位應用內部函數的問題。不過就有人留言了，說似乎感覺高 CPU 使用率的問題，還是挺容易排查的。那是不是所有 CPU 使用率高的問題，都可以這么分析呢？我想，你的答案應該是否定的。

??? 回顧前面的內容，我們知道，系統的 CPU 使用率，不僅包括進程用戶態和內核態的運行， 還包括中斷處理、等待 I/O 以及內核線程等。所以，當你發現系統的 CPU 使用率很高的 時候，不一定能找到相對應的高 CPU 使用率的進程。

案例分析

準備

探究系統 CPU 使用率高的情況，所以這次實驗的準備工作，與上節課的準備工作基本相同，差別在于案例所用的 Docker 鏡像不同。

預先安裝 docker、sysstat、perf、ab 等工具，如 yum install docker.io sysstat linux-tools-common apache2-utils ，ab(apache bench)是一個常用的 HTTP 服務性能測試工具，這里同樣用來模擬 Nginx 的客戶端。由于 Nginx 和 PHP 的配置比較麻煩，我把它們打包成了兩個 Docker 鏡像，這樣只需要運行兩個容器，就可以得到模擬環境。

??? 其中一臺用作 Web 服務器，來模擬性能問題；另一臺用作 Web 服務器的客戶端，來給 Web 服務增加壓力請求。使用兩臺虛擬機是為了相互隔離，避免“交叉感染”。

docker run --name nginx -p 10000:80 -itd feisky/nginx:sp docker run --name phpfpm -itd --network container:nginx feisky/php-fpm:sp訪問第一臺機器 [root@bzhl ~]# curl http://23.106.155.240:10000/ It works!

測試

??? 我們來測試一下這個 Nginx 服務的性能。在第二個終端運行下面的 ab 命令。要注意，與上次操作不同的是，這次我們需要并發 100 個請求測試 Nginx 性能，總共測試1000 個請求。

[root@bzhl ~]# ab -c 100 -n 1000 http://23.106.155.240:10000/Complete requests: 1000 Failed requests: 0 Total transferred: 172000 bytes HTML transferred: 9000 bytes Requests per second: 112.08 [#/sec] (mean) Time per request: 892.222 [ms] (mean) Time per request: 8.922 [ms] (mean, across all concurrent requests) Transfer rate: 18.83 [Kbytes/sec] received

??? 從 ab 的輸出結果我們可以看到，Nginx 能承受的每秒平均請求數，只有 112.08多一點，是不是感覺它的性能有點差呀。那么，到底是哪里出了問題呢？我們再用 top 和 pidstat 來觀察一下。這次，我們在第二個終端，將測試的并發請求數改成 5，同時把請求時長設置為 10 分鐘(-t 600)。這樣，當你在第一個終端使用性能分析工具時， Nginx 的壓力還是繼續的。繼續在第二個終端運行 ab 命令：

??? 然后，我們在第一個終端運行 top 命令，觀察系統的 CPU 使用情況：

top - 11:22:55 up 35 days, 21:36, 1 user, load average: 1.28, 0.52, 0.22 Tasks: 119 total, 6 running, 74 sleeping, 0 stopped, 0 zombie %Cpu0 : 60.4 us, 14.7 sy, 0.0 ni, 24.6 id, 0.0 wa, 0.0 hi, 0.4 si, 0.0 st %Cpu1 : 59.6 us, 15.7 sy, 0.0 ni, 22.3 id, 0.0 wa, 0.0 hi, 2.4 si, 0.0 st KiB Mem : 2057308 total, 152184 free, 366672 used, 1538452 buff/cache KiB Swap: 524284 total, 523760 free, 524 used. 1402364 avail MemPID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND 32020 101 20 0 33104 3692 2276 S 3.7 0.2 0:01.67 nginx 2743 bin 20 0 336696 16064 8392 S 2.7 0.8 0:00.95 php-fpm 2752 bin 20 0 336696 16064 8392 S 2.3 0.8 0:00.96 php-fpm 2755 bin 20 0 336696 16064 8392 S 2.3 0.8 0:00.90 php-fpm 2738 bin 20 0 336696 16064 8392 S 2.0 0.8 0:00.95 php-fpm 2766 bin 20 0 336696 16064 8392 S 2.0 0.8 0:00.91 php-fpm 31726 root 20 0 655612 77988 39920 S 1.3 3.8 0:15.71 dockerd 31970 root 20 0 108756 8400 4504 S 1.3 0.4 0:00.87 containerd-shim10 root 20 0 0 0 0 R 0.3 0.0 0:47.50 rcu_sched 6094 root 20 0 221712 20704 7596 S 0.3 1.0 32:23.52 python1 root 20 0 125520 5220 3828 S 0.0 0.3 1:40.77 systemd

??? 觀察 top 輸出的進程列表可以發現，CPU 使用率最高的進程也只不過才3.7%，看起來并不高。然而，再看系統 CPU 使用率( %Cpu )這一行，你會發現，系統的整體 CPU 使用率是比較高的：用戶 CPU 使用率(us)已經到了 60%，系統 CPU 為 15.1%，而空閑 CPU(id)則只有 29%。為什么用戶 CPU 使用率這么高呢？我們再重新分析一下進程列表，看看有沒有可疑進程：

docker-containerd 進程是用來運行容器的，2.7% 的 CPU 使用率看起來正常；

Nginx 和 php-fpm 是運行 Web 服務的，它們會占用一些 CPU 也不意外，并且 2% 的CPU 使用率也不算高；

??? 再往下看，后面的進程呢，只有 0.3% 的 CPU 使用率，看起來不太像會導致用戶 CPU 使用率達到 80%。那就奇怪了，明明用戶 CPU 使用率都 80% 了，可我們挨個分析了一遍進程列表，還是找不到高 CPU 使用率的進程。看來 top 是不管用了，那還有其他工具可以查看進程 CPU 使用情況嗎？不知道你記不記得我們的老朋友 pidstat，它可以用來分析進程的 CPU 使用情況。

[root@doit ~]# pidstat 1 Linux 4.20.0-1.el7.elrepo.x86_64 (doit) 07/14/2019 _x86_64_ (2 CPU)11:41:56 AM UID PID %usr %system %guest %wait %CPU CPU Command 11:41:57 AM 0 16 0.00 0.97 0.00 0.00 0.97 1 ksoftirqd/1 11:41:57 AM 1 7110 0.00 0.97 0.00 3.88 0.97 1 php-fpm 11:41:57 AM 1 7115 0.97 1.94 0.00 4.85 2.91 1 php-fpm 11:41:57 AM 1 7123 0.00 1.94 0.00 2.91 1.94 0 php-fpm 11:41:57 AM 1 7127 0.00 0.97 0.00 2.91 0.97 1 php-fpm 11:41:57 AM 1 7137 0.97 1.94 0.00 4.85 2.91 0 php-fpm 11:41:57 AM 0 24569 0.00 0.97 0.00 0.00 0.97 1 pidstat 11:41:57 AM 1 24780 0.00 2.91 0.00 0.00 2.91 1 php-fpm 11:41:57 AM 0 31726 0.97 0.00 0.00 0.00 0.97 1 dockerd 11:41:57 AM 0 31970 0.00 1.94 0.00 0.00 1.94 0 containerd-shim 11:41:57 AM 101 32020 0.97 1.94 0.00 11.65 2.91 0 nginx[root@doit ~]# uptime 11:42:56 up 35 days, 21:56, 1 user, load average: 2.82, 1.33, 0.81

??? 觀察一會兒，你是不是發現，所有進程的 CPU 使用率也都不高啊，最高的 Docker 和Nginx 也只有 4% 和 3%，即使所有進程的 CPU 使用率都加起來，也不過是 21%，離80% 還差得遠呢！后來我發現，會出現這種情況，很可能是因為前面的分析漏了一些關鍵信息。你可以先暫 停一下，自己往上翻，重新操作檢查一遍。或者，我們一起返回去分析 top 的輸出，看看能不能有新發現。現在，我們回到第一個終端，重新運行 top 命令，并觀察一會兒

top - 11:49:53 up 35 days, 22:03, 2 users, load average: 4.12, 3.15, 1.84 Tasks: 128 total, 4 running, 82 sleeping, 0 stopped, 0 zombie %Cpu(s): 49.5 us, 12.6 sy, 0.0 ni, 36.7 id, 0.0 wa, 0.0 hi, 1.2 si, 0.0 st KiB Mem : 2057308 total, 93240 free, 374216 used, 1589852 buff/cache KiB Swap: 524284 total, 523760 free, 524 used. 1389000 avail MemPID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND 32020 101 20 0 33104 3692 2276 S 2.6 0.2 0:21.73 nginx 12098 bin 20 0 336696 16064 8392 S 2.0 0.8 0:06.72 php-fpm 12124 bin 20 0 336696 16064 8392 S 2.0 0.8 0:06.70 php-fpm 31970 root 20 0 108756 8220 4504 S 2.0 0.4 0:13.37 containerd-shim 12075 bin 20 0 336696 16064 8392 S 1.7 0.8 0:06.89 php-fpm 12080 bin 20 0 336696 16064 8392 S 1.7 0.8 0:06.89 php-fpm 12083 bin 20 0 336696 16064 8392 S 1.7 0.8 0:06.66 php-fpm 31726 root 20 0 655612 77920 39920 S 1.0 3.8 0:22.63 dockerd16 root 20 0 0 0 0 S 0.7 0.0 0:14.97 ksoftirqd/1 31383 bin 20 0 0 0 0 R 0.3 0.0 0:00.01 stress

??? 這次從頭開始看 top 的每行輸出，咦？Tasks 這一行看起來有點奇怪，就緒隊列中居然有6 個 Running 狀態的進程(6 running)，是不是有點多呢？回想一下 ab 測試的參數，并發請求數是 5。再看進程列表里， php-fpm 的數量也是 5， 再加上 Nginx，好像同時有 6 個進程也并不奇怪。但真的是這樣嗎？

??? 再仔細看進程列表，這次主要看 Running(R) 狀態的進程。你有沒有發現， Nginx 和所有的 php-fpm 都處于 Sleep(S)狀態，而真正處于 Running(R)狀態的，卻是幾個stress 進程。這幾個 stress 進程就比較奇怪了，需要我們做進一步的分析。

我們還是使用 pidstat 來分析這幾個進程，并且使用 -p 選項指定進程的 PID。首先，從上面 top 的結果中，找到這幾個進程的 PID。比如，先隨便找一個 24344，然后用 pidstat 命令看一下它的 CPU 使用情況：

[root@doit ~]# pidstat -p 31383 Linux 4.20.0-1.el7.elrepo.x86_64 (doit) 07/14/2019 _x86_64_ (2 CPU) 11:50:40 AM UID PID %usr %system %guest %wait %CPU CPU Command 奇怪，居然沒有任何輸出。難道是 pidstat 命令出問題了嗎？之前我說過，在懷疑性能工具出問題前，最好還是先用其他工具交叉確認一下。那用什么工具呢？ ps 應該是最簡單易用的。我們在終端里運行下面的命令，看看 24344 進程的狀態：[root@doit ~]# ps aux |grep 31383 root 483 0.0 0.1 112720 2344 pts/1 S+ 11:51 0:00 grep --color=auto 31383

還是沒有輸出。現在終于發現問題，原來這個進程已經不存在了，所以 pidstat 就沒有任何輸出。既然進程都沒了，那性能問題應該也跟著沒了吧。我們再用? top? 命令確認一下：

top - 11:53:11 up 35 days, 22:06, 2 users, load average: 2.46, 2.27, 1.71 Tasks: 126 total, 6 running, 75 sleeping, 0 stopped, 2 zombie %Cpu(s): 53.8 us, 13.9 sy, 0.0 ni, 31.2 id, 0.0 wa, 0.0 hi, 1.0 si, 0.0 st KiB Mem : 2057308 total, 125672 free, 353916 used, 1577720 buff/cache KiB Swap: 524284 total, 523760 free, 524 used. 1412436 avail MemPID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND 32020 101 20 0 33104 3692 2276 R 2.7 0.2 0:23.15 nginx489 bin 20 0 336696 16064 8392 S 2.3 0.8 0:00.94 php-fpm484 bin 20 0 336696 16064 8392 S 2.0 0.8 0:00.88 php-fpm502 bin 20 0 336696 16064 8392 R 2.0 0.8 0:00.91 php-fpm500 bin 20 0 336696 16064 8392 S 1.7 0.8 0:00.88 php-fpm511 bin 20 0 336696 16064 8392 R 1.7 0.8 0:00.86 php-fpm 31970 root 20 0 108756 8340 4504 S 1.7 0.4 0:14.18 containerd-shim 31726 root 20 0 655612 77920 39920 S 1.0 3.8 0:23.15 dockerd10 root 20 0 0 0 0 I 0.3 0.0 0:49.25 rcu_sched 11768 bin 20 0 8188 1624 540 R 0.3 0.1 0:00.01 stress

好像又錯了。結果還跟原來一樣，用戶 CPU 使用率還是高達 80.9%，系統 CPU 接近15%，而空閑 CPU 只有 2.8%，Running 狀態的進程有 Nginx、stress 等。

可是，剛剛我們看到 stress 進程不存在了，怎么現在還在運行呢？再細看一下 top 的輸出，原來，這次 stress 進程的 PID 跟前面不一樣了，原來的 PID 24344 不見了，現在的是 6779。

進程的 PID 在變，這說明什么呢？在我看來，要么是這些進程在不停地重啟，要么就是全新的進程，這無非也就兩個原因：

第一個原因，進程在不停地崩潰重啟，比如因為段錯誤、配置錯誤等等，這時，進程在退出后可能又被監控系統自動重啟了。

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

至于 stress，我們前面提到過，它是一個常用的壓力測試工具。它的 PID 在不斷變化中， 看起來像是被其他進程調用的短時進程。要想繼續分析下去，還得找到它們的父進程。

要怎么查找一個進程的父進程呢？沒錯，用 pstree 就可以用樹狀形式顯示所有進程之間的關系：

[root@doit ~]# pstree |grep stress| | | |-php-fpm---sh---stress---stress

從這里可以看到，stress 是被 php-fpm 調用的子進程，并且進程數量不止一個(這里是3 個)。找到父進程后，我們能進入 app 的內部分析了。

首先，當然應該去看看它的源碼。運行下面的命令，把案例應用的源碼拷貝到 app 目錄， 然后再執行 grep 查找是不是有代碼再調用 stress 命令：

[root@doit ~]# docker cp phpfpm:/app . grep 查找看看是不是有代碼在調用 stress 命令[root@doit ~]# 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 的源代碼：

[root@doit ~]# 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 命令，模擬 I/O 壓力。從注釋上看， stress 會通過 write() 和 unlink() 對 I/O 進程進行壓測，看來，這應該就是系統 CPU 使用率升高的根源了。

不過，stress 模擬的是 I/O 壓力，而之前在 top 的輸出中看到的，卻一直是用戶 CPU 和系統 CPU 升高，并沒見到 iowait 升高。這又是怎么回事呢？stress 到底是不是 CPU 使

用率升高的原因呢？

我們還得繼續往下走。從代碼中可以看到，給請求加入 verbose=1 參數后，就可以查看stress 的輸出。你先試試看，在第二個終端運行：

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

看錯誤消息 mkstemp failed: Permission denied ，以及 failed run completed in 0s。原來 stress 命令并沒有成功，它因為權限問題失敗退出了。看來，我們發現了一個 PHP 調用外部 stress 命令的 bug：沒有權限創建臨時文件。

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

分析出問題來源，下一步是不是就要開始優化了呢？當然不是！既然只是猜測，那就需要 再確認一下，這個猜測到底對不對，是不是真的有大量的 stress 進程。該用什么工具或指標呢？

我們前面已經用了 top、pidstat、pstree 等工具，沒有發現大量的 stress 進程。那么， 還有什么其他的工具可以用嗎？

還記得上一期提到的 perf 嗎？它可以用來分析 CPU 性能事件，用在這里就很合適。依舊在第一個終端中運行 perf record -g 命令 ，并等待一會兒(比如 15 秒)后按 Ctrl+C 退出。然后再運行 perf report 查看報告：

[root@doit ~]# perf record -g ^C[ perf record: Woken up 13 times to write data ] [ perf record: Captured and wrote 3.548 MB perf.data (25041 samples) ][root@doit ~]# perf report

　　你看，stress 占了所有 CPU 時鐘事件的 77%，而 stress 調用調用棧中比例最高的，是隨機數生成函數 random()，看來它的確就是 CPU 使用率升高的元兇了。隨后的優化就很簡單了，只要修復權限問題，并減少或刪除 stress 的調用，就可以減輕系統的 CPU 壓力。

　　當然，實際生產環境中的問題一般都要比這個案例復雜，在你找到觸發瓶頸的命令行后， 卻可能發現，這個外部命令的調用過程是應用核心邏輯的一部分，并不能輕易減少或者刪除。這時，你就得繼續排查，為什么被調用的命令，會導致 CPU 使用率升高或 I/O 升高等問題。這些復雜場景的案例，我會在后面的綜合實戰里詳細分析。最后，在案例結束時，不要忘了清理環境，執行下面的 Docker 命令，停止案例中用到的Nginx 進程：

?docker rm -f nginx phpfpm?

execsnoop

在這個案例中，我們使用了 top、pidstat、pstree 等工具分析了系統 CPU 使用率高的問題，并發現 CPU 升高是短時進程 stress 導致的，但是整個分析過程還是比較復雜的。對于這類問題，有沒有更好的方法監控呢？

execsnoop 就是一個專為短時進程設計的工具。它通過 ftrace 實時監控進程的 exec() 行為，并輸出短時進程的基本信息，包括進程 PID、父進程 PID、命令行參數以及執行的結果。

比如，用 execsnoop 監控上述案例，就可以直接得到 stress 進程的父進程 PID 以及它的命令行參數，并可以發現大量的 stress 進程在不停啟動：

git clone --depth 1 https://github.com/brendangregg/perf-tools [root@doit perf-tools]# ./execsnoop

execsnoop 所用的 ftrace 是一種常用的動態追蹤技術，一般用于分析 Linux 內核的運行時行為，后面課程我也會詳細介紹并帶你使用。

小結

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

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

　　第二，應用本身在不停地崩潰重啟，而啟動過程的資源初始化，很可能會占用相當多的CPU。

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

perf record -ag -- sleep 2;perf report

總結

以上是生活随笔為你收集整理的4 系统的 CPU 使用率很高，但为啥却找不到高 CPU的应用？的全部內容，希望文章能夠幫你解決所遇到的問題。

如果覺得生活随笔網站內容還不錯，歡迎將生活随笔推薦給好友。