关于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找到它们的父进程，再从父进程所在的应用入手，排查问题的根源