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

简介: 1. 问题现象:某项目跑在 p01~02 2台ECS上,主要用途是聚合服务,给H5页面提供直接访问的接口。最近版本新增加了接口 wechat/mp/qrcode,用途是根据请求参数生成小程序二维码,以swoole+lumen方式对外服务接口上线后,cpu使用率逐步上升,直至100%;同时请求响应时长也逐步攀升上图是问题期间p01cpu使用率,几个下降过程是因为上线(会重启服务进程)或者手动重启服务进程;后面发现p01 p02cpu基本打满,临时加了 p03 p04 2台ecs以降低问题的影响。

1. 问题现象:

某项目跑在 p01~02 2台ECS上,主要用途是聚合服务,给H5页面提供直接访问的接口。
最近版本新增加了接口 wechat/mp/qrcode,用途是根据请求参数生成小程序二维码,以swoole+lumen方式对外服务
接口上线后,cpu使用率逐步上升,直至100%;同时请求响应时长也逐步攀升

case_cpu

上图是问题期间p01cpu使用率,几个下降过程是因为上线(会重启服务进程)或者手动重启服务进程;后面发现p01 p02cpu基本打满,临时加了 p03 p04 2台ecs以降低问题的影响。

2. 初步分析

对于cpu使用率居高不下的进程,通常做法是先大致看下系统调用,看cpu时间都耗在哪个上面:
strace -p {pid} -c

case_strace-c

位居第一的是 brk 系统调用,占用了接近90%的时间

搜索brk的作用:

case_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统计参数,而是直接输出,发现个有意思的事:

case_strace

如上图,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`

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

case_gdb

当时的现象是,在握手阶段,发现有 PL11_CreateManagedGenericObject()方法调用,该方法属于nss

case_nss

nss是一个底层密码学库,包括 TLS 实现
到这里,已经怀疑是nss库的问题,于是和运维同学沟通,将curlNSS库替换为OpenSSL
再次运行临时脚本,发现问题消失。
由于临时脚本非swoole方式运行,为了排除swoole的问题,通过将p04ECS上的代码手动修改,重启,恢复到问题发生时的状态,观察了一段时间后,发现问题没有出现。
至此,问题根因找到,属于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
目录
相关文章
|
2月前
|
Arthas 缓存 测试技术
【记录问题排查系列】记录CPU飙高问题排查过程篇(1)
【记录问题排查系列】记录CPU飙高问题排查过程篇
37 0
|
3月前
|
Shell
我来教你如何将cpu使用率up起来(shell脚本[含注释])
我来教你如何将cpu使用率up起来(shell脚本[含注释])
139 0
|
5月前
|
安全 Windows
一次简单的服务器 cpu 占用率高的快速排查实战
一次简单的服务器 cpu 占用率高的快速排查实战
|
3月前
|
Arthas 测试技术
Arthas排查生产环境CPU飚高问题
Arthas排查生产环境CPU飚高问题
Arthas排查生产环境CPU飚高问题
|
4月前
|
Linux
模拟Linux服务器高cpu使用率
模拟Linux服务器高cpu使用率
|
1月前
|
监控 Java Linux
疯狂飙高!怎么排查CPU导致系统反应缓慢的问题?
疯狂飙高!怎么排查CPU导致系统反应缓慢的问题?
|
2月前
|
弹性计算 Linux 数据安全/隐私保护
Linux【问题记录 01】阿里云CPU使用率 100% ECS 同时连接数峰值 25k+ 问题排查无果(附阿里云重新初始化云盘详细步骤)
Linux【问题记录 01】阿里云CPU使用率 100% ECS 同时连接数峰值 25k+ 问题排查无果(附阿里云重新初始化云盘详细步骤)
70 0
|
2月前
|
XML Java API
Android App开发之创建JNI接口获取CPU指令集讲解及实战(附源码 简单易懂)
Android App开发之创建JNI接口获取CPU指令集讲解及实战(附源码 简单易懂)
24 0
|
2月前
当Hologres实例的CPU使用率长期保持在100%时
当Hologres实例的CPU使用率长期保持在100%时
65 2
|
4月前
|
Java 调度
服务器常见问题排查(一)——cpu占用高、上下文频繁切换、频繁GC
文章主要讨论了服务器中常见性能问题的一些排查思路,这篇文章主要讨论了CPU负载过高,频繁GC和频繁切换上线文这三个问题。
231 0
服务器常见问题排查(一)——cpu占用高、上下文频繁切换、频繁GC

相关产品

  • 云迁移中心