大厂真实案例,CPU 升高问题如何排查?五分钟掌握

开发 项目管理
这是一个比较大项目改动,改造的过程中涉及到了相当多下游接口的改动和相当多的依赖包。今天在上线发布后经过接口和功能验证,需求发布成功。

好久没写技术文章了,今天下班“早”,简单叨叨一篇。

早下班的原因说起来也有点搞笑,是因为健身时候杠铃把手上砸了个口子。砸伤当时我看了一眼,虽然很痛但骨头没事,竟然心中还有一丝庆幸。缝针吧,有点夸张,不处理吧,还挺深。于是,我在从医院处理完伤口后,有了这篇文章。

好了,言归正传。

CPU 升高问题案例

市面上通常对于 CPU 问题排查的案例面试比较少,基本上都在讲:如果 CPU 升到 100% 怎么办?

这确实是个高频问题,必须需要流利回答。之前也写过一篇文章,可以参考:

图片图片

重点问题!CPU利用率过高排查思路|原创

真实案例

这是一个今天发生的真实案例(相关信息已脱敏处理,不影响案例本质)。

问题如下:这是一个比较大项目改动,改造的过程中涉及到了相当多下游接口的改动和相当多的依赖包。今天在上线发布后经过接口和功能验证,需求发布成功。

但是接着,我发布完成后才发现机器的平均 CPU 负载升高,平均 CPU 负载几乎升高了有 5-8 %,最高负载更是超过了 CPU 安全水位线。如此多的改动,到底是什么导致了 CPU 负载的上升?

我自己用 python 花了张图,大概下面这个样子

图片图片

问题出现,CPU 升高

快速处理: 我先快速对比了一下 CPU 负载升高的时间点,和发布时间基本对应,基本可以判断是本次发布引起的。虽然并没有影响到业务,但是发现问题后,我还是第一时间做了回滚处理。

注意:发布过程中出现任何问题不要想排查问题原因,直接回滚,血泪教训的铁律

排查问题

我排查问题的思路如下:

  1. 由于想到本次变更有很多新接口的引入,也有一些接口的对比代码,会带来额外的性能消耗,所以我先对比了发布前后的接口远程调用情况,结果是调用量没有明显变化,RT 也正常。
  2. 服务也有 kafka 消息处理,同样检查消息组件情况,调用量没有变化。
  3. 会不会是 GC 太多导致?检查 JVM 情况,依旧正常,甚至还因为重启机器表现要比之前好……
  4. 因为用到了线程池,会不会是因为使用线程池不合理,或者有什么死循环之类的。检查活跃线程情况,依旧和发布前相似。
  5. 那只能考虑是因为引入的某个依赖引起的了,他导致了预期外的变化。

问题引入的依赖有很多,到底是哪个依赖引入的?我难道一个个下掉去排查吗?

排除法,这也确实是一种办法,只不过是太辛苦了,事倍功半。更不用说还需要下掉相关代码,还得不断去耗时发布,实在是繁琐。

怎么办呢?不卖关子了,直接上 Arthas。

Async-profiler

Arthas 使用 async-profiler 生成 CPU/内存火焰图进行性能分析,弥补了之前内存分析的不足。

async-profiler 是一款开源的 Java 性能分析工具,原理是基于 HotSpot 的 API,以微乎其微的性能开销收集程序运行中的堆栈信息、内存分配等信息进行分析。

官网:https://github.com/async-profiler/async-profiler

我们常用的是 CPU 性能分析和 Heap 内存分配分析。在进行 CPU 性能分析时,仅需要非常低的性能开销就可以进行分析。

在进行 Heap 分配分析时,async-profiler 工具会收集内存分配信息,而不是去检测占用 CPU 的代码。async-profiler 不使用侵入性的技术,例如字节码检测工具或者探针检测等,这也说明 async-profiler 的内存分配分析像 CPU 性能分析一样,不会产生太大的性能开销,同时也不用写出庞大的堆栈文件再去进行进一步处理,。

async-profiler 工具在采样后可以生成采样结果的日志报告,也可以生成 SVG 格式的火焰图。

图片图片

具体使用大家直接去官网看文档吧,有不懂留言。我这里直接说使用

使用 async-profiler 排查问题

进入测试服务器控制台,使用 JPS 命令查看 PID 信息。

➜  develop jps
2800 Jps
528 TestCode
2450 Launcher

假设运行程序的名是 TestCode,可以看到对应的 PID 是 528。

使用下面命令:

./profiler.sh -d 20 -f 528.svg 528

对 528 号进程采样20秒,然后得到生成的 528.svg 文件,然后我们使用浏览器打开这个文件,可以看到 CPU 的使用火焰图,如下(这里用网络图片代替):

图片图片

关于火焰图怎么看,一言以蔽之:火焰图里,横条越长,代表使用的越多,从下到上是调用堆栈信息。 在这个图里可以看到 main 方法上面的调用中 hotmethod3 方法的 CPU 使用是最多的,点击这个方法。还可能看到更详细的信息。

那么我们现在只需要查找 hotmethod3 使用的地方在哪里,就可以定位到问题代码。

当然,上面的是个代替 case,告诉你怎么看这个火焰图。真实的 case 要比这个更难排查。如下图,问题代码是个线程,是由某个类调用的:

图片图片

排查问题依赖引入

问题代码是一个 Thread 的 run 方法引起的,那么是谁调用的他呢?这个类的信息我打码了,假设为 ClassA。

但是排查代码,ClassA 根本没有被项目代码直接的调用,于是我找到了这个 CalssA 所属的依赖包 dep-demoA,看他是谁引入的。

./gradlew :项目名:dependencyInsight --dependency dep-demoA

这个命令会打出一个项目的依赖树,结果如下:

+--- com.ali:dep-demoA:1.0.0 (*)
\--- com.ali:dep-demoB:1.0.0
     \--- com.ali:dep-demoC:1.0.0

如上结果,项目中我是用的是 dep-demoC,结果他同时引入了 dep-demoB,我看了下这个 demoB,他很可能会跟 arthas 类似,通过 Java Agent技术和字节码增强技术以实现一定的功能,这对程序是非常有损耗的。(所以线上不能开 arthas)

尝试排除 demoB,代码如下:

all*.exclude group: "com.ali", module: "dep-demoB"

然后重启项目,CPU 负载下降,回归到正常水平,问题解决。

图片图片

责任编辑:武晓燕 来源: 后端开发技术
相关推荐

2021-06-07 09:51:22

原型模式序列化

2009-11-17 14:50:50

Oracle调优

2009-11-05 10:55:22

Visual Stud

2021-01-11 09:33:37

Maven数目项目

2017-01-10 09:07:53

tcpdumpGET请求

2021-01-13 09:23:23

优先队列React二叉堆

2018-01-08 16:19:04

微信程序轮播图

2009-11-16 10:53:30

Oracle Hint

2022-08-04 13:27:35

Pythonopenpyxl

2021-10-20 06:58:10

工具低代码无代码

2017-04-25 12:07:51

AndroidWebViewjs

2024-03-21 09:51:22

Python爬虫浏览网站

2020-06-16 08:47:53

磁盘

2023-07-31 11:37:05

经营分析模型

2020-12-17 10:00:16

Python协程线程

2021-01-29 11:25:57

Python爬山算法函数优化

2021-03-12 09:45:00

Python关联规则算法

2019-12-23 16:42:44

JavaScript前端开发

2020-12-07 11:23:32

Scrapy爬虫Python

2021-03-23 15:35:36

Adam优化语言
点赞
收藏

51CTO技术栈公众号