基础：某个应用的CPU使用率高达100%，该怎么处理

墨蓝 2022-09-16 14:23 171阅读 0赞

# CPU使用率 #

> CPU使用率，就是CPU被使用的比例，也就是空闲之外的使用比例

*  Linux是一个多任务的操作系统，会将每个CPU的时间划分为很短的时间片，再通过调度器轮流分配给各个任务使用，因此造成多任务同时运行的错觉。
 *  为了维护CPU时间，Linux通过事先定义的节拍率(内核中表示为HZ)，触发时间中断，并使用全局变量Jiffes记录了开机以来的节拍数。每发生一次时间中断，Jiffies的值就加1
 *  节拍率HZ是内核的可配选项，可以设置为100、250、1000等。不同的系统可能设置不同数值，可以通过/boot/config内核选项来查看它的配置值，比如下面查询中，节拍率设置成了250，也就是每秒钟触发250次时间中断

$ grep 'CONFIG_HZ=' /boot/config-$(uname -r)
    CONFIG_HZ=250

*  同时，正因为节拍率HZ是内核选项，所以用户空间程序不能直接访问。为了方便用户空间程序，内核还提供了一个用户空间节拍器，它总是固定为100，也就是1/100.这样，用户空间程序就不需要关心内核中HZ被设置成了多少，因为它看到的是总固定值USER\_HZ

Linux通过`//proc`虚拟文件系统，向用户空间提供了系统内部状态的信息，而`/proc/stat`提供的就是系统的CPU和任务统计信息。比如，如果你只关注CPU的话，可以执行下面的某类：

# 只保留各个CPU的数据
    $ cat /proc/stat | grep ^cpu
         us      ni    sys     id     wa  hi  si  st guest  gnice
    cpu  590084 4268 1235478 5762130 17246 0 5748 0 0 0
    cpu0 146707 1930 298457 1453246 3132 0 1311 0 0 0
    cpu1 137571 903 296183 1460387 5409 0 1398 0 0 0
    cpu2 173608 595 344495 1381436 3463 0 1396 0 0 0
    cpu3 132196 839 296342 1467060 5241 0 1642 0 0 0

*  其中，第⼀列表示的是 CPU 编号，如cpu0、cpu1 ，⽽第⼀⾏没有编号的 cpu ，表示的是所有  
    CPU 的累加。
 *  其他列则表示不同场景下 CPU 的累加节拍数，它的单位是 USER\_HZ，也就是 10 ms（1/100秒），所以这其实就是不同场景下的 CPU 时间
    
     *  user（通常缩写为 us），代表⽤户态 CPU 时间。注意，它不包括下⾯的 nice 时间，但包括了 guest 时间
     *  nice（通常缩写为 ni），代表低优先级⽤户态 CPU 时间，也就是进程的 nice 值被调整为 1-19 之间时的 CPU 时间。这⾥注意，nice 可取值范围是 -20 到 19，数值越⼤，优先级反⽽越低。
     *  system（通常缩写为sys），代表内核态 CPU 时间
     *  idle（通常缩写为id），代表空闲时间。注意，它不包括等待 I/O 的时间（iowait）。
     *  iowait（通常缩写为 wa），代表等待 I/O 的 CPU 时间。
     *  irq（通常缩写为 hi），代表处理硬中断的 CPU 时间。
     *  softirq（通常缩写为 si），代表处理软中断的 CPU 时间。
     *  steal（通常缩写为 st），代表当系统运⾏在虚拟机中的时候，被其他虚拟机占⽤的 CPU 时间。
     *  guest（通常缩写为 guest），代表通过虚拟化运⾏其他操作系统的时间，也就是运⾏虚拟机的 CPU 时间。
     *  guest\_nice（通常缩写为 gnice），代表以低优先级运⾏虚拟机的时间。

⽽我们通常所说的 CPU 使⽤率，就是除了空闲时间外的其他时间占总 CPU 时间的百分⽐，⽤公式来表示就是：

C P U 使 用 率 = 1 − 空 闲 时 间 总 C P U 时 间 CPU使用率 =\{ 1 -\\frac\{空闲时间\}\{总CPU时间\}\} CPU使用率=1−总CPU时间空闲时间

当然，如果你直接使用/proc/stat的数据（也就是开机以来的节拍累加值），算出来的式开机以来的平均CPU使用率，一般没有参考价值

所以，为了计算CPU使用率，性能工具一般都会取间隔一段时间（比如3s）的两次值，作差后，再计算出这段时间内的平均CPU使用率，即：

平 均 C P U 使 用 率 = 1 − 空 闲 时 间 n e w − 空 闲 时 间 o l d 总 C P U 时 间 n e w − 总 C P U 时 间 o l d 平均CPU使用率 =\{ 1 -\\frac\{空闲时间\_\{new\}-空闲时间\_\{old\}\}\{总CPU时间\_\{new\}-总CPU时间\_\{old\}\}\} 平均CPU使用率=1−总CPU时间new−总CPU时间old空闲时间new−空闲时间old

这个公式，就是我们用各种性能工具所看到的CPU使用率的实际计算方法。

现在，我们知道了系统CPU使用率的计算方法，那进程呢？跟系统的指标类似，Linux也给每个进程提供了运行情况的统计，也就是/proc/\[pid\]/stat。

> 问题：是不是说要查看CPU的使用率式，就必须先读取/proc/stat和/proc/\[pid\]/stat这两个文件，然后再按照上面的公式计算出来呢？

当然不是，Linux上提供了各种各样的性能分析工具已经计算好了。

不过要注意，**性能分析工具给出的都是间隔一段时间的平均CPU使用率，所以要注意间隔时间的设置**。当要用多个工具比对时，先保证它们用的是相同的时间间隔。

比如，关于top和ps这两个工具报告的CPU使用率，默认的结果不一样，因为top默认使用的是3s时间间隔，而ps使用的是进程的整个生命周期

# 怎么查看CPU使用率 #

top和ps是最常用的查看CPU使用率的工具：

*  top显示了系统总体的CPU和内存使用情况，以及各个进程的资源使用情况 （top看的是系统总使用率，不一定能发现问题）
 *  ps显示了每个进程的资源使用情况

// 默认每3s刷新一次
    $ top
    
    top - 23:45:48 up  5:42,  1 user,  load average: 17.91, 17.19, 16.67
    任务: 309 total,   1 running, 308 sleeping,   0 stopped,   0 zombie
    %Cpu(s): 15.6 us, 72.0 sy,  0.0 ni, 12.2 id,  0.0 wa,  0.0 hi,  0.2 si,  0.0 st
    MiB Mem :   7932.9 total,   5464.2 free,   1015.7 used,   1453.0 buff/cache
    MiB Swap:   2048.0 total,   2048.0 free,      0.0 used.   6633.9 avail Mem 
    
     进程号 USER      PR  NI    VIRT    RES    SHR    %CPU  %MEM     TIME+ COMMAND                                                   
      12049 root      20   0   35832  10508   8876 S 328.9   0.1 281:28.74 sysbench                                                  
       2187 oceanst+  20   0  275040  64816  37504 S   9.0   0.8   2:38.67 Xorg                                                      
       2318 oceanst+  20   0 4243652 253908 111472 S   5.6   3.1   1:50.21 gnome-shell                                               
       2659 oceanst+  20   0 1053268  69880  51056 S   3.7   0.9   1:17.22 gnome-terminal-                                           
         11 root      20   0       0      0      0 I   0.7   0.0   0:12.64 rcu_sched                                                 
       2470 oceanst+  20   0  295076  41768  30668 S   0.3   0.5   0:33.54 vmtoolsd                                                  
      15246 root      20   0   15096   4052   3284 R   0.3   0.0   0:00.05 top

*  这个输出结果中，**第三⾏ %Cpu 就是系统的 CPU 使⽤率**，具体每⼀列的含义上⼀节都讲过，只是把CPU时间变换成了CPU使⽤率。不过需要注意，top 默认显示的是所有 CPU 的平均值，这个时候你只需要**按下数字 1** ，就可以切换到每个 CPU 的使⽤率了。
 *  继续往下看，空⽩⾏之后是进程的实时信息，**每个进程都有⼀个 %CPU 列，表示进程的 CPU 使⽤率。它是⽤户态和内核态  
    CPU 使⽤率的总和**，包括进程⽤户空间使⽤的 CPU、通过系统调⽤执⾏的内核空间 CPU 、以及在就绪队列等待运⾏的CPU。在虚拟化环境中，它还包括了运⾏虚拟机占⽤的 CPU。

所以，到这⾥我们可以发现， top 并没有细分进程的⽤户态CPU和内核态 CPU。

> 问题： 那要怎么查看每个进程的详细情况呢？

pidstat 是⼀个专⻔分析每个进程 CPU 使⽤情况的⼯具

# 每隔1秒输出⼀组数据，共输出5组
    $ pidstat 1 5
    Linux 5.8.0-48-generic (oceanstar) 	2021年10月21日 	_x86_64_	(4 CPU)
    
    23时50分37秒   UID       PID    %usr %system  %guest   %wait    %CPU   CPU  Command
    23时50分38秒  1000      2187    0.99    1.98    0.00    0.00    2.97     0  Xorg
    23时50分38秒  1000      2318    0.99    0.99    0.00    0.00    1.98     3  gnome-shell
    23时50分38秒  1000      2659    0.99    0.99    0.00    0.00    1.98     3  gnome-terminal-
    23时50分38秒     0     15212    0.00    0.99    0.00    0.00    0.99     1  kworker/1:2-events
    23时50分38秒     0     15250    0.00    1.98    0.00    0.00    1.98     2  pidstat
    
    ...
    
    
    平均时间:   UID       PID    %usr %system  %guest   %wait    %CPU   CPU  Command
    平均时间:     0        11    0.00    0.20    0.00    0.00    0.20     -  rcu_sched
    平均时间:  1000      2187    0.80    0.80    0.00    0.20    1.59     -  Xorg
    平均时间:  1000      2318    0.80    0.40    0.00    0.20    1.20     -  gnome-shell
    平均时间:  1000      2659    0.60    0.20    0.00    0.20    0.80     -  gnome-terminal-
    平均时间:     0     15217    0.00    0.20    0.00    0.00    0.20     -  kworker/2:0-events
    平均时间:     0     15251    0.80    1.59    0.00    0.00    2.39     -  pidstat

上面命令一间隔1s展示了进程的5组CPU使用率：

*  ⽤户态CPU使⽤率 （%usr）；
 *  内核态CPU使⽤率（%system）；
 *  运⾏虚拟机CPU使⽤率（%guest）；
 *  等待 CPU使⽤率（%wait）；
 *  以及总的CPU使⽤率（%CPU）。

最后的 Average 部分，还计算了 5 组数据的平均值。

# CPU使用率过高怎么办？ #

> 通过top、ps、pidstat等工具，就能够找到CPU使用率较高的进程。接下来的问题是，占用CPU的到底是代码里的哪个函数呢？

你可能会想到使用GDB，但是GDB并不适合在性能分析的早期使用，因为GDB调试程序会中断程序的运行，这在线上环境是不允许的。所以，GDB只适合用在性能分析的后期，当你找出了出问题的大致函数后，线下再借助它来进一步调试函数内部的问题

我们可以使用perf来第一时间分析进程的CPU问题。 perf是Linux 2.6.31 以后内置的性能分析工具。它以性能事件采样为基础，线下再借助它来进一步调试函数内部的问题。

*  比如，`perf top` 可以实时显式占用CPU时钟最多的函数或者指令，因此可以用来查找热点函数：

$ perf top
    Samples: 833 of event 'cpu-clock', Event count (approx.): 97742399
    Overhead Shared Object Symbol
    7.28% perf [.] 0x00000000001f78a4
    4.72% [kernel] [k] vsnprintf
    4.32% [kernel] [k] module_get_kallsym
    3.65% [kernel] [k] _raw_spin_unlock_irqrestore

*  输出结果中，第⼀⾏包含三个数据，分别是采样数（Samples）、事件类型（event）和事件总数量（Event count）。
    
     *  ⽐如这个例⼦中，perf 总共采集了 833 个 CPU 时钟事件，⽽总事件数则为 97742399。
     *  **采样数**需要特别关注。。如果采样数过少（⽐如只有⼗⼏个），那下⾯的排序和百分⽐就没什么实际参考价值了。
 *  再往下看是⼀个表格式样的数据，每⼀⾏包含四列，分别是：
    
     *  第⼀列 Overhead ，是该符号的性能事件在所有采样中的⽐例，⽤百分⽐来表示。
     *  第⼆列 Shared ，是该函数或者指令所在的动态共享对象(Dynamic Shared Object)，比如内核、进程名、动态链接库名、内核模块名等
     *  第三列 Object，是动态共享对象的类型，比如\[.\] 表示用户空间的可执行程序、或者动态链接库，而`[k]`则表示内核空间
     *  第四列 Symbol，即符号名，也就是函数名。当函数名未知是，用十六进制的地址来表示
     *  还是以上⾯的输出为例，我们可以看到，占⽤ CPU 时钟最多的是 perf ⼯具⾃身，不过它的⽐例也只有 7.28%，说明系统并没有 CPU 性能问题
 *  比如，perf record和 perf report。 perf top 虽然实时展示了系统的性能信息，但它的缺点是并不保存数据，也就⽆法⽤于离线或者后续的分析。⽽ perf record 则提供了保存数据的功能，保存后的数据，需要你⽤ perf report 解析展示

$ perf record # 按Ctrl+C终⽌采样
    [ perf record: Woken up 1 times to write data ]
    [ perf record: Captured and wrote 0.452 MB perf.data (6093 samples) ]
    $ perf report # 展示类似于perf top的报告
    Samples: 59K of event 'cpu-clock:pppH', Event count (approx.): 14843250000
    Overhead  Command          Shared Object                 Symbol
       4.90%  php-fpm          libm-2.24.so                  [.] sqrt
       3.83%  php-fpm          php-fpm                       [.] execute_ex
       3.60%  php-fpm          php-fpm                       [.] add_function
       3.22%  php-fpm          php-fpm                       [.] 0x000000000094ede0
       3.01%  php-fpm          [kernel.kallsyms]             [k] __prepare_exit_to_usermode
       1.93%  php-fpm          php-fpm                       [.] 0x00000000008c4a6c
       1.91%  php-fpm          php-fpm                       [.] 0x00000000008c4ae5
       1.90%  php-fpm          php-fpm                       [.] 0x00000000009513cc
       1.79%  php-fpm          php-fpm                       [.] 0x00000000008c4a64
       1.62%  php-fpm          php-fpm                       [.] 0x000000000098de23
       1.26%  php-fpm          php-fpm                       [.] 0x00000000008cda08

# 案例：找出CPU使用率高的是由哪个函数引起的 #

下⾯我们就以 Nginx + PHP 的 Web 服务为例，来看看当你发现 CPU 使⽤率过⾼的问题后，要怎么使⽤ top 等⼯具找出异常的进程，⼜要怎么利⽤ perf 找出引发性能问题的函数。

## 准备 ##

*  机器配置：2 CPU，8GB 内存
 *  预先安装 docker、sysstat、perf、ab 等⼯具
    
     *  ab（apache bench）是一个常用的**HTTP服务性能测试工具**，这里用来模拟Ngnix的客户端。
     *  由于Ngnix和PHP的配置比较麻烦，请用[Docker 镜像][Docker]操作，这样只需要运行两个容器，就可以得模拟环境

apt install docker.io sysstat linux-tools-common apache2-utils

注意，这里需要用到两台虚拟机:

*  一台用作web服务器，来模拟性能问题
 *  一台用作web服务器的客户端，来给web服务增加压力请求

使用两台虚拟机是为了相互隔离，避免“交叉感染”(电脑太慢了，就不隔离了，实际测试的时候应该尽量避免感染)

![在这里插入图片描述][watermark_type_ZHJvaWRzYW5zZmFsbGJhY2s_shadow_50_text_Q1NETiBAT2NlYW4mJlN0YXI_size_10_color_FFFFFF_t_70_g_se_x_16]  
注意：下⾯的所有命令，都默认假设以 root ⽤户运⾏，

## 操作和分析 ##

1.  ⾸先，在第⼀个终端执⾏下⾯的命令来运⾏ Nginx 和 PHP 应⽤：

$ docker run --name nginx -p 10000:80 -itd feisky/nginx
    $ docker run --name phpfpm -itd --network container:nginx feisky/php-fpm

1.  然后，在第⼆个终端使⽤ curl 访问 http://\[VM1的IP\]:10000，确认 Nginx 已正常启动。你应该可以看到 It works! 的响应。

# 192.168.0.10是第⼀台虚拟机的IP地址
    $ curl http://127.0.0.1:10000/
    It works!

1.  接着，我们来测试⼀下这个 Nginx 服务的性能。在第⼆个终端运⾏下⾯的 ab 命令：

# 并发10个请求测试Nginx性能，总共测试100个请求
    $ ab -c 10 -n 100 http://127.0.0.1:10000/
    This is ApacheBench, Version 2.3 <$Revision: 1706008 $>
    Copyright 1996 Adam Twiss, Zeus Technology Ltd,pe
    ...
    Requests per second:    41.22 [#/sec] (mean)
    Time per request:       242.616 [ms] (mean)
    
    ...

从ab的输出结果我们可以看到，Nginx能承受的每秒平均请求数为 41.22。我们将测试的请求总数加到10000，在第二个终端：

$ ab -c 10 -n 10000 http://127.0.0.1:10000/

接着，回到第⼀个终端运⾏ top 命令，并按下数字 1 ，切换到每个 CPU 的使⽤率：  
![在这里插入图片描述][watermark_type_ZHJvaWRzYW5zZmFsbGJhY2s_shadow_50_text_Q1NETiBAT2NlYW4mJlN0YXI_size_20_color_FFFFFF_t_70_g_se_x_16]  
这⾥可以看到，系统中有⼏个 php-fpm 进程的 CPU 使⽤率加起来接近 400%；⽽每个 CPU 的⽤户使⽤率（us）也已经超过了 98%，接近饱和。这样，我们就可以确认，正是⽤户空间的 php-fpm 进程，导致CPU 使⽤率骤升。

那再往下⾛，怎么知道是 php-fpm 的哪个函数导致了 CPU 使⽤率升⾼呢？我们来⽤ perf 分析⼀下。在第⼀个终端运⾏下⾯的perf命令：

# -g开启调⽤关系分析，-p指定php-fpm的进程号3235
    $ perf top -g -p 3235

按⽅向键切换到 php-fpm，再按下回⻋键展开 php-fpm 的调⽤关系，你会发现，调⽤关系最终到了 sqrt 和 add\_function。看

![在这里插入图片描述][watermark_type_ZHJvaWRzYW5zZmFsbGJhY2s_shadow_50_text_Q1NETiBAT2NlYW4mJlN0YXI_size_16_color_FFFFFF_t_70_g_se_x_16]

> 遇到的问题：没有看到函数名称，只是看到了十六进制的东西
> 
>  *  原因：这是分析docker容器应用时常会碰到的一个问题，因为容器应用所依赖的库都在镜像里面
>  *  解决思路：
>     
>      *  在容器外面构建相同路径的依赖库。这种方法不推荐，一是因为找出这些依赖比较麻烦，更重要的是构建这些路径会污染虚拟机的环境
>      *  在容器外面把分析记录保存下来，到容器里面再去查看结果，这样库和符号的路径就是对的了‘
>  *  操作：
>     
>      *  在系统上运行 `perf record -g -p < pid >`，执行一会儿(比如5s)，然后ctrl+c停止
>         
>          *  \-i 导入的数据文件名称，如果没有则默认为perf.data
>          *  \-g 生成函数调用关系图，此时内核要打开CONFIG\_KALLSYMS；用户空间库或者执行文件需要带符号信息(not stripped)，编译选项需要加上-g。
>      *  把生成的perf.data(这个文件生成在执行命令的当前目录下, find / -name perf.data)文件拷贝到容器里面去分析：
>         
>          *  `docker cp perf.data phpfpm:/tmp`
>          *  `docker exec -i -t phpfpm bash`
>             
>              *  $ `cd /tmp/`
>              *  $ `apt-get update && apt-get install -y linux-perf linux-tools procps`
>              *  $ `perf_4.9 report`
>             
>                 incompatible file format (rerun with -v to learn more)   ???? 这个问题怎么解决
>          *  注意：最后运⾏的⼯具名字是容器内部安装的版本 perf\_4.9，⽽不是 perf 命令，这是因为 perf 会去跟内核的版本进⾏匹配，但镜像⾥⾯安装的perf版本有可能跟虚拟机的内核版本不⼀致。[安装perf后，执行perf命令报错。][perf_perf]

我们拷⻉出 Nginx 应⽤的源码，看看是不是调⽤了这两个函数：

# 从容器phpfpm中将PHP源码拷⻉出来
    $ docker cp phpfpm:/app .
    # 使⽤grep查找函数调⽤
    $ grep sqrt -r app/ #找到了sqrt调⽤
    app/index.php: $x += sqrt($x);
    $ grep add_function -r app/ #没找到add_function调⽤，这其实是PHP内置函数

OK，原来只有 sqrt 函数在 app/index.php ⽂件中调⽤了。那最后⼀步，我们就该看看这个⽂件的源码了  
![在这里插入图片描述][b6cdbe9c72624a50b16d622d960b268a.png]

修复之后也打包成立一个镜像，可以如下运行它：

# 停⽌原来的应⽤
    $ docker rm -f nginx phpfpm
    # 运⾏优化后的应⽤
    $ docker run --name nginx -p 10000:80 -itd feisky/nginx:cpu-fix
    $ docker run --name phpfpm -itd --network container:nginx feisky/php-fpm:cpu-fix

接着，到第⼆个终端来验证⼀下修复后的效果。⾸先Ctrl+C停⽌之前的ab命令后，再运⾏下⾯的命令：

$ ab -c 10 -n 10000 http://10.240.0.5:10000/
    ...
    Complete requests: 10000
    Failed requests: 0
    Total transferred: 1720000 bytes
    HTML transferred: 90000 bytes
    Requests per second:    2838.99 [#/sec] (mean)
    Time per request:       3.522 [ms] (mean)
    Time per request: 0.447 [ms] (mean, across all concurrent requests)
    Transfer rate: 375.75 [Kbytes/sec] received

从这⾥你可以发现，现在每秒的平均请求数，已经从原来的几十变成了 2838.99

> 感觉：这么多并发一下子就返回了，而之前要等很久才能测试完全部压测

## 小结 ##

CPU使用率是最直观也是最常用的系统性能指标，更是我们在排查性能问题时，通常会关注的第一个指标。所以我们要熟悉它的含义，需要弄清楚⽤户（%user）、Nice（%nice）、系统（%system） 、等待 I/O（%iowait） 、中断（%irq）以及软中断（%softirq）这⼏种不同 CPU 的使⽤率。⽐如说

*  用户CPU和Nice CPU高，说明用户态进程占用了较多的CPU，所以应该着重排查进程的性能问题
 *  系统CPU高，说明内核态占用了较多的CPU，所以应该着重排查内核线程或者系统调用的性能问题
 *  IO等待CPU高，说明等待IO的时间比较长，所以应该排查系统存储是不是出现了IO问题
 *  软中断和硬中断高，说明软中断或者硬中断的处理程序占用了较多的CPU，所以应该着重排查内核中的中断服务程序

**碰到 CPU 使⽤率升⾼的问题，你可以借助 top、pidstat 等⼯具，确认引发 CPU 性能问题的来源；再使⽤ perf 等⼯具，排查出引起性能问题的具体函数**。

# 案例：系统CPU使用率很高，但是不一定能找到相对应的高CPU使用率的进程 #

通过上面我们可以知道，系统的CPU使用率，不仅包括进程用户态和内核态的运行，还包括中断处理、等待IO以及内核线程等，不一定能找到相对应的高CPU使用率的进程。

## 准备 ##

准备和上面一样，只是操作的容器不一样

## 操作和分析 ##

⾸先，我们在第⼀个终端，执⾏下⾯的命令运⾏ 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

然后，在第⼆个终端，使⽤ curl 访问 http://\[VM1的IP\]:10000，确认 Nginx 已正常启动。你应该可以看到 It works! 的响应。

# 192.168.0.10是第⼀台虚拟机的IP地址
    $ curl http://127.0.0.1:10000/
    It works!

接着，我们来测试⼀下这个 Nginx 服务的性能。在第⼆个终端运⾏下⾯的 ab 命令。要注意，与上次操作不同的是，这次我们  
需要并发100个请求测试Nginx性能，总共测试1000个请求。

# 并发100个请求测试Nginx性能，总共测试1000个请求
    $ ab -c 100 -n 1000 http://127.0.0.1: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 来观察⼀下。

这次，我们在第⼆个终端，将测试的并发请求数改成5，同时把请求时⻓设置为10分钟（-t 600）。这样，当你在第⼀个终端使⽤性能分析⼯具时， Nginx 的压⼒还是继续的。

继续在第⼆个终端运⾏ ab 命令：

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

然后，我们在第⼀个终端运⾏ 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

*  观察 top 输出的进程列表可以发现，CPU 使⽤率最⾼的进程也只不过才 2.7%，看起来并不⾼。
 *  然⽽，再看系统 CPU 使⽤率（ %Cpu ）这⼀⾏，你会发现，系统的整体 CPU 使⽤率是⽐较⾼的：⽤户 CPU 使⽤率（us）已经到了 80%，系统 CPU 为 15.1%，⽽空闲 CPU （id）则只有 2.8%。

为什么⽤户 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 使⽤情况。

接下来，我们还是在第⼀个终端，运⾏ 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

观察⼀会⼉，你是不是发现，所有进程的 CPU 使⽤率也都不⾼啊，最⾼的 Docker 和 Nginx 也只有 4% 和 3%，即使所有进程的 CPU 使⽤率都加起来，也不过是 21%，离 80% 还差得远呢！

> 明明⽤户 CPU 使⽤率已经⾼达 80%，为什么却怎么都找不到是哪个进程的问题？？？

会出现这种情况，很可能是因为前⾯的分析漏了⼀些关键信息。

现在，我们回到第⼀个终端，重新运⾏ 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 的每⾏输出，咦？Tasks 这⼀⾏看起来有点奇怪，就绪队列中居然有 6 个 Running 状态的进程（6running），是不是有点多呢？
 *  回想⼀下 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 使⽤情况：

$ pidstat -p 24344
    16:14:55 UID PID %usr %system %guest %wait %CPU CPU Comman

*  奇怪，居然没有任何输出。难道是pidstat 命令出问题了吗？**在怀疑性能⼯具出问题前，最好还是先⽤其他⼯具交叉确认⼀下**。那⽤什么⼯具呢？ 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

*  好像⼜错了。结果还跟原来⼀样，⽤户 CPU 使⽤率还是⾼达 80.9%，系统 CPU 接近 15%，⽽空闲 CPU 只有2.8%，Running 状态的进程有 Nginx、stress等。
 *  可是，刚刚我们看到stress 进程不存在了，怎么现在还在运⾏呢？再细看⼀下 top 的输出，原来，这次 stress 进程的 PID 跟前⾯不⼀样了，原来的 PID 24344 不⻅了，现在的是 6779。

进程的PID在变，这说明什么呢？要么是这些进程在不停的重启，要么就是全新的进程，这无非也就是两个原因：

*  第一个原因：进程在不停的崩溃重启，比如因为段错误、配置错误等等。这时，进程在退出之后可能又被监控系统自动重启了
 *  第二个原因：这些进程当时短时进程，也就是在其他应用内部通过exec调用的外面命令。这些命令一般都只允许很短的时间就会结束，你很难用top这种间隔时间⽐较⻓的⼯具发现（上⾯的案例，我们碰巧发现了）。

要想继续分析下去，我们必须先找到stress的父进程。

> 要怎么查找一个进程的父进程呢？

可以用`pstree`以树状形式显示所有进程之间的关系：

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

从这⾥可以看到，stress 是被 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 命令，模拟 I/O 压⼒。
 *  从注释上看，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
    )

*  看错误消息 mkstemp failed: Permission denied ，以及 failed run completed in 0s。原来 stress 命令并没有成功，它因为权限问题失败退出了。看来，我们发现了⼀个 PHP 调⽤外部 stress 命令的 bug：没有权限创建临时⽂件。
 *  从这里我们可以猜测，正是由于权限错误，大量的stress进程在启动时初始化失败，进而导致用户CPU使用率的升高

分析出问题来源，下⼀步是不是就要开始优化了呢？当然不是！既然只是猜测，那就需要再确认⼀下，这个猜测到底对不对，是不是真的有⼤量的 stress 进程。该⽤什么⼯具或指标呢？

*  我们前⾯已经⽤了 top、pidstat、pstree 等⼯具，没有发现⼤量的 stress 进程。那么，还有什么其他的⼯具可以⽤吗？
 *  可以用CPU性能分析工具perf：

# 记录性能事件，等待⼤约15秒后按 Ctrl+C 退出
    $ perf record -g
    # 查看报告
    $ perf report

*  这样，你就可以看到下图这个性能报告：  
    ![在这里插入图片描述][watermark_type_ZHJvaWRzYW5zZmFsbGJhY2s_shadow_50_text_Q1NETiBAT2NlYW4mJlN0YXI_size_13_color_FFFFFF_t_70_g_se_x_16]
 *  从上面可以看出，stress 占了所有CPU时钟事件的 77%，⽽ stress 调⽤调⽤栈中⽐例最⾼的，是随机数⽣成函数 random()，看来它的确就是 CPU 使⽤率升⾼的元凶了。随后的优化就很简单了，只要修复权限问题，并减少或删除 stress 的调⽤，就可以减轻系统的 CPU 压⼒。

最后，在案例结束时，不要忘了清理环境，执⾏下⾯的 Docker 命令，停⽌案例中⽤到的 Nginx 进程：

$ docker rm -f nginx phpfpm

## execsnoop ##

> 在上面案例中，我们使用率top、pidstat、pstress等工具分析了系统CPU使用率高的问题，发现CPU升高是由短时进程stress导致的，但是整个分析过程比较复杂。对于这类问题，有没有更好的解决方法呢？

*  execsnoop就是一个专门为短时进程设计的工具。它通过ftrace实时监控进程的exec()行为，并输出短时进程的基本信息。包括进程PID、父进程PID、命令行参数以及执行的结果
 *  execsnoop所用的ftrace是一种常用的动态追踪技术，一般用于分析Linux内核的运行时行为。

⽐如，⽤ execsnoop 监控上述案例，就可以直接得到 stress 进程的⽗进程 PID 以及它的命令⾏参数，并可以发现⼤量的stress 进程在不停启动：

# 按 Ctrl+C 结束
    $ execsnoop
    PCOMM PID PPID RET ARGS
    sh 30394 30393 0
    stress 30396 30394 0 /usr/local/bin/stress -t 1 -d 1
    sh 30398 30393 0
    stress 30399 30398 0 /usr/local/bin/stress -t 1 -d 1
    sh 30402 30400 0
    stress 30403 30402 0 /usr/local/bin/stress -t 1 -d 1
    sh 30405 30393 0
    stress 30407 30405 0 /usr/local/bin/stress -t 1 -d 1

## 小结 ##

碰到常规问题无法解释的CPU使用率情况，首先要想到的有可能是短时应用导致的问题，比如有可能是如下两种情况：

*  第一，**应用里直接调用了其他二进制程序，这些程序通常运行时间比较短，通过top等工具也不容易发现**
 *  第二，**应用程序本身在不停的崩溃重启，而启动过程的资源初始化，很肯能会占用相当多的CPU**

对于这类进程，我们可以⽤ pstree 或者 execsnoop 找到它们的⽗进程，再从⽗进程所在的应⽤⼊⼿，排查问题的根源。 （另一个工具是perf top）

[Docker]: https://github.com/feiskyer/linux-perf-examples/tree/master/nginx-high-cpu
[watermark_type_ZHJvaWRzYW5zZmFsbGJhY2s_shadow_50_text_Q1NETiBAT2NlYW4mJlN0YXI_size_10_color_FFFFFF_t_70_g_se_x_16]: /images/20220828/21b805007ab9425cb27fbbfdda03a82e.png
[watermark_type_ZHJvaWRzYW5zZmFsbGJhY2s_shadow_50_text_Q1NETiBAT2NlYW4mJlN0YXI_size_20_color_FFFFFF_t_70_g_se_x_16]: /images/20220828/5117b6e7aceb4c10abdb969cd475ed45.png
[watermark_type_ZHJvaWRzYW5zZmFsbGJhY2s_shadow_50_text_Q1NETiBAT2NlYW4mJlN0YXI_size_16_color_FFFFFF_t_70_g_se_x_16]: /images/20220828/8d617ead5afc4e02b24b6d8a1af56b3c.png
[perf_perf]: https://blog.csdn.net/sinat_35866463/article/details/103476997
[b6cdbe9c72624a50b16d622d960b268a.png]: /images/20220828/8827a297725d45699372337f895d5f23.png
[watermark_type_ZHJvaWRzYW5zZmFsbGJhY2s_shadow_50_text_Q1NETiBAT2NlYW4mJlN0YXI_size_13_color_FFFFFF_t_70_g_se_x_16]: /images/20220828/e3d91390bc744503a81810e22224c31e.png