某接口cpu使用率异常排查记录

1. 问题现象：

某项目跑在

p01~02

2台ECS上，主要用途是聚合服务，给H5页面提供直接访问的接口。

最近版本新增加了接口

wechat/mp/qrcode

，用途是根据请求参数生成小程序二维码，以swoole+lumen方式对外服务

接口上线后，cpu使用率逐步上升，直至100%；同时请求响应时长也逐步攀升

上图是问题期间

p01

cpu使用率，几个下降过程是因为上线（会重启服务进程）或者手动重启服务进程；后面发现

p01 p02

cpu基本打满，临时加了

p03 p04

2台ecs以降低问题的影响。

2. 初步分析

对于cpu使用率居高不下的进程，通常做法是先大致看下系统调用，看cpu时间都耗在哪个上面：

strace -p {pid} -c

位居第一的是

brk

系统调用，占用了接近90%的时间

搜索

brk

的作用：

更通俗一点说，

malloc

小于128k的内存，使用

brk

分配内存，将

_edata

往高地址推(只分配虚拟空间，不对应物理内存(因此没有初始化)，第一次读/写数据时，引起内核缺页中断，内核才分配对应的物理内存，然后虚拟地址空间建立映射关系)

到这里，当时的第一反应是有资源未正确释放，导致内存泄漏，于是去捋了一遍接口代码，发现代码是这样的：

$curl = new Curl();
        $curl->setHeader('Content-Type', 'application/json; charset=utf-8');
        $curl->post('https://api.weixin.qq.com/wxa/getwxacodeunlimit?access_token=' . $accessToken, $params);

        if ($curl->error) {
            ...
        }

        if (is_object($curl->response)) {
            ...
        }

        $img = base64_encode($curl->response);           

发现

$curl

没有执行close操作，而服务本身以swoole方式对外提供服务，未正确close可能会导致内存泄漏，故简单的认为是这个原因导致；

在增加了

$curl->close()

后，上线，发现问题依旧，尴尬 ￣□￣｜｜。。。

3. 深入分析

重新思考了下，既然

$curl->close()

未能解决问题，说明很大概率问题不是出在代码，而是其他组件。

再次通过

strace

命令观察了进程的系统调用，这次没有使用

-c

统计参数，而是直接输出，发现个有意思的事：

如上图，

Line 988

在读取了

/etc/pki/tls/certs/ca-bundle.crt

文件后，就产生了大量的

brk

系统调用，截图下方还有成百上千个；

ca-bundle.crt

是服务器上存储的所有根证书文件,4700行左右

仔细观察

brk

的参数，发现在有规律的周期重复，到这里，初步怀疑是这个阶段不停的在分配内存，然后释放；而且很可能是每请求一次，就会多一组相同变量的分配、释放操作，所以才会导致brk地址周期性的重复。

通过系统调用，可以发现问题出在TLS握手阶段；既然如此，那不验证证书信息，是不是就可以绕过这些来源不明的

brk

系统调用？遂再次尝试修复bug，在代码层面增加了一行

$curl->setOpt(CURLOPT_SSL_VERIFYPEER, false);           

上线后，问题消失。

4. 查找root cause

经过上面的处理，问题已经修复，但并没有找到root cause,只是一个绕过的方式，而且关闭验证证书的话，也存在中间人攻击的风险，不是长久之策，还是得找到 root cause.

再次回到问题，我写了一个临时脚本，以死循环的方式用同样的代码去请求美篇的一个https接口，然后观察cpu以及系统调用。

在这期间，通过搜索，发现通过

gdb

可以打印线程具体执行的方法：

遂在

poster04

上安装了

gdb

通过以下命令查看：

gdb -q --batch -ex "thread apply all bt” -p `pidof tmem`           

很可惜的是，当时的结果没有截图，用一个正常的截图来看看大致效果：

当时的现象是，在握手阶段，发现有

PL11_CreateManagedGenericObject()

方法调用，该方法属于

nss

库

nss

是一个底层密码学库，包括 TLS 实现

到这里，已经怀疑是

nss

库的问题，于是和运维同学沟通，将

curl

的

NSS

库替换为

OpenSSL

再次运行临时脚本，发现问题消失。

由于临时脚本非swoole方式运行，为了排除swoole的问题，通过将

p04

ECS上的代码手动修改，重启，恢复到问题发生时的状态，观察了一段时间后，发现问题没有出现。

至此，问题根因找到，属于

nss

库的bug导致

在后续的搜索中，

https://bugzilla.redhat.com/show_bug.cgi?id=1659108

这里可以看到有相同的问题现象，也确认了是

nss

库在读取ca文件时，某个版本中，原本固定长度的数组变成了无限增长的数组，导致内存泄漏，进而导致分配、释放内存消耗了大量cpu。

5. 后记

在整个排查过程中，其实不是如文中所说这么顺畅，期间也遇到了一团乱麻的时候，不知道问题出在哪。

前期花了大量时间排查、验证代码，没有特别敢怀疑基础库的问题

幸运的是，后面搜索到了几篇非常有帮助的文章，对排查问题提供了很大帮助，也进一步理清了思路，一步一步逼近真相:)

参考：

1. 一种内存泄露检查和定位的方法 https://blog.51cto.com/xiamachao/1929118
2. 频繁分配释放内存导致的性能问题的分析 https://cloud.tencent.com/developer/article/1420726
3. Linux内存分配小结--malloc、brk、mmap https://blog.csdn.net/gfgdsg/article/details/42709943