zl程序教程

您现在的位置是:首页 >  其他

当前栏目

perf工具定位短时进程导致CPU升高案例

2023-09-14 09:15:14 时间

你使用 topvmstatpidstat等工具, 排査高CPU使用率的进程,然后再使用perf top工具,定位应用内部函数的问题 

我们知道,系统的CPU使用率,不仅包括进程用户态和内核态的运行,还包括中断处理、等待I/O以及内核线程等。所以,当你发现系统的CPU使用率很高的时候,不一定能找到相对应的高CPU使用率的进程。

 

案例分析


你的准备

本次案例基于Linux系统。我使用的案例环境如下所示:

机器配置:2 CPU, 8GB内存

ab (apache bench)是个常用的HTTP服务性能测试工具,这里同样用来模拟Nginx的客户端。

首先,在第一个终端,执行下面的命令运行NginxPHP应用,在第二个终端,使用curl访问http://[VM1IP]:10000,确认Nginx已正常启动。你应该可以看至It works!的响应。

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

接着,我们来测试一下这个Nginx服务的性能。在第二个终端运行下面的ab命令。要注意, 与上次操作不同的是,这次我们需要并发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 $>
4Copyright 1996 Adam Twiss, Zeus Technology Ltd,

Requests per second:	87.86 [#/sec] (mean)
Time per request:	1138.229 [ms] (mean)

ab的输出结果我们可以看到,Nginx能承受的每秒平均请求数只有87多一点,是不是感觉它的性能有点差。那么到底是哪里出了问题呢?我们再用toppidstat来观察一下。

这次,我们在第二个终端,将测试的并发请求数改成5,同时把请求时长设置为10分钟(-t 600)。这样当你在第一个终端使用性能分析工具时,Nginx的压力还是继续的。

继续在第二个终端运行ab命令:

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

然后,我们在第一个终端运行top命令,观察系统的CPU使用情况:

 观察top输出的进程列表可以发现,CPU使用率最高的进程也只不过才2.7%,看起来并不高。然而再看系统CPU使用率(%Cpu )这一行,你会发现,系统的整体CPU使用率是比较高的:用户CPU使用率(us)已经到了 80%,系统CPU15.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命令:

 

观察一会儿,你是不是发现,所有进程的CPU使用率也都不高啊,最高的DockerNginx也只有4%3%,即使所有进程的CPU使用率都加起来,也不过是21%,80%还差得远呢!

碰到这种问题就完全懵了:明明用户CPU使用率已经高达80%,但我却怎么都找不到是哪个进程的问题。到这里,你也可以想想,你是不是也遇到过这种情况?还能不能再做进一步的分析呢?

后来我发现,会出现这种情况,很可能是因为前面的分析漏了一些关键信息。你可以先暂停一 下,自己往上翻,重新操作检查一遍。或者,我们返回去重新运行top命令并且分析输出,看看能不能有新发现。

现在,我们回到终端,重新运行top命令,并观察一会

 这次从头开始看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使用情况 。

奇怪,居然没有任何输出。难道是pidstat命令出问题了吗?之前我说过,在怀疑性能工具出问题前,最好还是先用其他工具奴确认一下。那用什么工具呢? ps应该是最简单易用的。在终端里运行下面的命令,看看24344进程的状态:

 还是没有输出。现在终于发现问题,原来这个进程已经不存在了,所以pidstat就没有任何输出。既然进程都没了,那性能问题应该也跟着没了吧。我们再用top命令确认一下

好像又错了。结果还跟原来一样,用户CPU使用率还是高达80.9%,系统CPU接近15%,而空闲CPU只有2.8%, Running状态的进程有Nginxstress等。

可是,刚刚我们看到stress进程不存在了,怎么现在还在运行呢?再细看一下top的输出,原来,这次stress进程的PID跟前面不一样了,原来的PID 24344不见了,现在的是6779

进程的PID在变,这说明什么呢?在我看来,要么是这些进程在不停地重启,要么就是全新的进程,这无非也就两个原因:

•第一个原因,进程在不停地崩溃重启,比如因为段错误、配置错误等等,这时,进程在退出后可能又被监够统自动重启了。

•第二个原因,这些进程都是短视时进程,也就是在其他应用内部通过exec调用的外面命令。这些命令一般都只运行很短的时间就结束,你很难用top这种间隔时间较长的工具发现(上面的案例,我们碰巧发现了)

至于stress,我们前面提到过,它是常用的压力测试工具。它的PID在不断变化中,看起来像是被其他进程调用的短时进程。要想继续分析下去,还得找到它们的父进程。

要怎么査找一个进程的父进程呢?没错,用pstree就可以用树状形式显示所有进程之间的关系:

从这里可以看到,stress是被php-fpm调用的子进程,并且进程数量不止(这里是3 个)。找到父进程后,我们能进入app的内部分析了。

首先,当然应该去看看它的源码。运行下面的命令,把案例应用的源码拷贝到app目录,然后再执行grep查找是不是有代码再调用stress命令:

找到了,果然是app/index.php文件中直接调用了 stress命令。再来看看app/index.php的源代码:

可以看到,源码里对每个请求都会调用f stress命令,模拟I/O压力。从注释上看,stress 会通过writeunlinkI/O进程进行压测,看来,这应该就是系统CPU使用率升高的根源了。

不过,stress模拟的是I/O压力,而之前在top的输出中看到的,却一直是用户CPU和系统 CPU升高,并没见到iowait升高。这又是怎么回事呢? stress到底是不是CPU使用率升高的 原因呢? 我们还得继续往下走。从代码中可以看到,给请求加入verbose=1参数后,就可以查看stress 的输出。你先试试看,在第二个终端运行:

看错误消息 mkstemp failed: Permission denied , IXR. failed run completed in Os.原来 stress命令并没有成功,它因为权限问题失败退出了。看来,我们发现了fPHP调用外部 stress命令的bug:没有权限创建临时文件。

从这里我们可以猜测,正是由于权限错误,大量的stress进程在启动时初始化失败,进而导致 用户CPU使用率的升高。

分析出问题来源,下一步是不是就要开始优化了呢?当然不是!既然只是猜测,那就需要再确认 一下,这个猜测到底对不对,是不是真的有大量的stress进程。该用什么工具或指标呢? 我们前面已经用了 toppidstatpstree等工具,没有发现大量的stress进程。那么,还有什 么其他的工具可以用吗?

perf工具它可以用来分析CPU性能事件,用在这里就很合适。依旧在终端中运行perf record -g命令,并等一会儿(比如15秒)后按Ctrl+C退出。然后再 运行perf report查看报告:

这样,你就可以看到下图这个性能报告:

你看,stress占了所有CPU时钟事件的77%,stress调用调用栈中比例最高的,是随机数生成函数random()看来它的确就是CPU使用率升高的元凶了。随后的优化就很简单了,只 要修复权限问题,并减少或删除stress的调用,就可以减轻系统的CPU压力。 

 

当然,实际生产环境中的问题一般都要比这个案例复杂,在你找到触发瓶颈的命令行后,却可能发现,这个外部命令的调用过程是应用核心逻辑的一部分,并不能轻易减少或者删除。

这时,你就得继续排查,为什么被调用的命令,会导致CPU使用率升高或I/O升高等问题。

 

execsnoop

在这个案例中,我们使用了 top、pidstat、pstree等工具分析了系统CPU使用率高的问题, 并发现CPU升高是短时进程stress导致的,但是整个分析过程还是比较复杂的。对于这类问 题,有没有更好的方法监控呢?

execsnoop就是专为短时进程设计的工具。它通过ftrace实时监控进程的exec()行为, 并输出短时进程的基本信息,包括进程PID父进程PID命令行参数以及执行的结果。

比如,用execsnoop监控上述案例,就可以直接得到stress进程的父进程PID以及它的命令 行参数,并可以发现大量的stress进程在不停启动:

execsnoop所用的ftrace是一种常用的动态追踪技术,一般用于分析Linux内核的运行时行为 

 

小结


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

第一,应用里直接调用了其他二进制程序,这些程序通常运行时间比瞄较短,通过top等工具也不容易发现

第二 应用本身在不停地崩溃重启,而启动过程的资源初始化,但可能会占用相当多的 CPU

对于这类进程,我们可以用pstree或者execsnoop找到它们的父进程,再从父在的应用入手,排査问题的根源。