上一节我们学习了CPU使用率是什么,并且使用案例练习使用top、vmstat、pidstat等工具,排查高CPU使用率的进程,然后再使用perf top工具定位应用内部函数的问题。那么,高CPU使用率的问题是不是就很容易排查呢,实际上不是的;
我们知道,系统的CPU使用率,不仅包含进程用户态和内核态的运行,还包括中断处理、等待I/O以及内核线程等。所以,当你发现系统的CPU使用率很高的时候,不一定能找到相对应的高CPU使用率的进程;
这次,我们还是用一个Nginx + PHP的Web服务的案例,来分析这种情况;
案例分析
准备
今天依然是探究系统CPU使用率高的情况,因此这次实验的准备工作,与上一节基本相同,区别是在于案例使用的docker镜像不同;
以下案例基于Ubuntu 18.04, 同样适用于其他的Linux系统。使用的案例环境如下所示:
-
机器配置: 2CPU, 8GB内存
-
预先安装docker、sysstat、perf、ab等工具
ab(apache bench)是一个常见的HTTP服务性能测试工具,这里用来模拟Nginx的客户端;
由于Nginx和PHP配置比较麻烦,将他们打包成了两个Docker镜像,这样,只需要运行两个容器,就可以得到模拟环境;
从上图可以看到,其中一台用 作Web服务器,来模拟性能问题;另一台用作Web服务器的客户端,来给Web服务器增加压力请求。使用两台虚拟机时为了相互隔离,避免"交叉感染";
操作和分析
首先,我们再第一个终端,执行下面的命令运行Nginx和PHP应用:
|
|
然后在终端二,使用curl访问http://192.168.44.138:10000/, 确认Nginx已经正常启动。正常可以看到It works!的响应;
接着,我们来测试这个Nginx服务的性能。在第二个终端运行下面的ab命令。要注意,与上次操作不同的是,这次我们需要并发100个请求测试Nginx性能,总共测试1000个请求;
|
|
|
|
从ab的输出结果我们可以看到,Nginx能承受的每秒平均请求数,只有162多一点,感觉性能有点差是吧。那么,到底是哪里出了问题呢?我们再用top
和pidstat
来观察一下。
这次,我们在终端二,将测试的请求数改为5,同时把请求时长设置为10分钟(-t 600), 这样,用终端一使用性能分析工具时,Nginx压力还是继续的;
|
|
然后,我们在终端一运行top命令,观察系统CPU使用情况;
观察top输出的进程列表可以发现,CPU使用率最高的进程也只不过才6%,看起来并不高;
然而,再看系统CPU使用率,系统整体CPU利用率是比较高的:用户CPU使用率 (us)已经到了61.2%, 系统CPU为28.3, 而空闲CPU(id)则只有5.4%。
为什么用户CPU使用率会这么高呢?重新分析一下进程列表,看看有没有可疑进程:
- dockerd进程是用来运行容器的,1.7%的CPU看起来正常;
- Nginx和php-fpm是运行Web服务的,他们回占用一些CPU也不意外,并且3.7%的CPU使用率也不算高;
- 后面的进程,只有0.3%的CPU使用率,并且看起来不像是会导致用户CPU使用率到达61.2%
这就比较奇怪了,明明用户CPU使用率已经到了61.2%, 但是我们找了一圈进程列表,还是没有找到高CPU使用率的进程。看来是top不管用了,那我们还有其他工具可以查看进程CPU使用情况。如pidstat, 可以用它来分析进程的CPU使用情况。
观察了一下,所有进程的CPU使用率也都不高啊,最高的nginx和phph-fpm也只有5%和4%, 即使列表所有进程的CPU使用率加起来也才32%, 离61%差的也有点多呢;
以前的时候,碰到这种问题就完全懵了:明明CPU使用率已经高达64.8%, 但是怎么都找不到是哪个进程的问题,这类情况能否做进一步的分析呢?
再次分析
后来会发现,会出现这种情况,很可能是因为前面的分析漏掉了一些关键信息;我们可以一起返回去分析top的输出,看看能不能有一些新发现;
|
|
这次从头开始看top的每行输出,Task这一行看起来就比较奇怪,就绪队列中居然有7个Running状态的进程(7 running),是不是有点多了呢?
回想一下ab测试的参数,并发请求数是5.再看进程列表里,php-fpm的数量也是5,再加上Nginx, redis-server等好像有7个进程也不奇怪,但是真的是这样吗?
再仔细看进程列表,这次主要看Running(R)状态的进程。你有没有发现,Nginx和所有的php-fpm都处于Sleep(S)状态,而真正处于Running(R)状态,却是几个stress进程。这几个stress进程就比较奇怪了,需要进一步分析;
我们还是用pidstat来分析这几个进程,并且使用-p选项执行进程的PID。 首先,从上面的top结果中,找到这几个进程的PID。比如,先随便找一个24344, 然后用pidstat命令来看一下它的CPU使用情况;
没有什么输出,我们再用ps工具去交叉确认一下, 使用ps去查看进程是简单易用的,在终端里面运行下面的命令,看看24344进程的状态:
还是没有输出,现在终于发现这个问题,原来是这个进程已经不存在了,所以pidstat就没有任何输出。既然进程都没了,那性能问题应该也没了吧,然后我们用top再去验证一下:
好像又错了。结果还和原来一样,用户的CPU使用率还是高达62.9%, 系统CPU接近28%, 空闲CPU只有2.8%, Running状态的进程有Nginx, Stress等。
可是,我们刚刚看到的stress进程不存在了,怎么现在还在运行呢?细看一下, stree进程的PID已经发生变化了。
进程的PID在变,这说明什么呢? 一般说来,要么是这些进程在不停地重启,要么就是全新的进程,这无非也就是两个原因:
- 第一个原因,进程在不停地崩溃重启,比如因为段错误、配置错误等等,这时,进程在退出后可能又被监控系统自动重启了;
- 第二个原因,这些进程都是短时进程,也即是在其他应用内部通过exec调用的外面命令。这些命令一般都只是运行很短时间就会结束,我们很难用top这种间隔比较长的工具来发现;
至于stress, 前面提到过,它是一个常见的压力测试工具。它的PID在不断变化中,看起来像是被其他进程调用的短时进程。要想再继续分析下去,还得找到它们的父进程;
要怎么查找一个进程的父进程呢?没错,就是用pstree就可以用树状形式显示所有进程之间的关系:
从这里可以看到。stress是被php-fpm调用的子进程,而且进程数量不止一个(这里是2个)。找到父进程后,我们能进入app的内部分析了;
首先,当然应该去看看它的源码。运行下面的命令,把案例应用的源码拷贝到app目录,然后再执行grep查找是不是有代码在调用stress命令:
找到了,果然是app/index.php文件里面直接调用了stress命令;
再来看app/index.php的源代码:
|
|
可以看到,源码里面对每个请求都会调用一个stress命令,模拟I/O压力。从注释来看,stress会通过write()和unlink()来对I/O进程进行压测,看来,这应该就是系统CPU使用率升高的根源了;
不过stree模拟的是I/O压力,而之前在top输出中看到的,却一直是用户CPU和系统CPU升高,并没有看到iowait升高,这又是什么回事呢?stree到底是不是CPU使用率升高的原因呢?
我们还得继续往下走,从代码中可以看到,给请求加入verbose=1参数后,就可以查看stress的输出了。我们先试试看,在终端二运行:
curl http://192.168.44.138:10000/?verbose=1
看错误消息 mkstemp failed: Permission denied , 以及failed run completed in 0s。原来,stress命令并没有成功,他因为权限问题失败退出了。看来,我们发现了一个PHP调用外部命令的bug: 没有权限创建临时文件;
从这里我们可以猜测,正是由于权限错误,大量的stress进程在启动初始化时失败,进而导致用户CPU使用率的升高。
分析出问题来源,下一步是不是就要开始优化了呢?当然不是,既然只是猜测,那就需要再确认一下,这个猜测到底对不对,是不是真的有大量的stress进程。那该用什么工具或者指标呢?
可以使用上一节提到的perf, 它可以用来分析CPU性能事件,用在这里就很合适。依旧在第一个终端中运行perf record -g命令,并等待一会儿(比如15s)后按Ctrl + C退出,然后再用perf report查看报告;
|
|
可以看到,stress占了所有CPU时钟事件的一半以上,而stress调用调用栈中比例最高的,是随机数生成函数random(), 看来它就是CPU使用率升高的元凶了。随后的优化就很简单了,只需要修复权限问题,并减少或删除stress的调用,就可以降低系统的CPU压力;
当然,实际生产环境中的问题远比这个case复杂,在你找到触发瓶颈的命令行后,却可能发现,这个外部命令的调用过程实际是应用核心逻辑的一部分,并不能轻易减少或者删除。这时候,我们就得继续排查,为什么调用的命令,会导致CPU使用率升高或者I/O升高等问题。这些复杂案例,后面会涉及到;
最后,本案例结束时,需要清理环境:
|
|
execsnoop
在这个案例中,我们使用了top、pidstat、pstree等工具分析了系统CPU使用率高的问题,并发现CPU升高是短时进程stress导致的,但是整个分析过程是比较复杂的。对于此类问题,有没有办法更好的监控呢?
execsnoop就是一个专为短时进程设计的工具。它通过ftrace实时监控进程的exec()行为,并输出短时进程的基本信息,包括进程ID、父进程ID、命令行参数以及执行的结果。
比如,用execsnoop监控上述案例,就可以直接得到stress进程的父进程ID以及它的命令行参数,并可以发现大量的stress进程在不停启动:
execsnoop 所用的 ftrace 是一种常用的动态追踪技术,一般用于分析 Linux 内核的运行时行为.
小结
碰到常规问题无法解释的CPU使用率情况时,首先要想到有可能是短时应用导致的问题,比如可能是以下两种情况:
- 第一,应用里直接调用了其他的二进制,这些程序通常运行时间比较短,通过top等工具也不容易发现;
- 第二,应用本身在不停地崩溃重启,而启动过程的资源初始化,很可能会占用相当多的CPU;
对于这类进程,我们可以用pstree或者execanoop找到它们的父进程,再从父进程所在的应用入手,排查问题的根源;