如何排查线上CPU飙高的问题

86次阅读
没有评论

共计 3245 个字符,预计需要花费 9 分钟才能阅读完成。

这篇文章给大家分享的是有关如何排查线上 CPU 飙高的问题的内容。丸趣 TV 小编觉得挺实用的,因此分享给大家做个参考,一起跟随丸趣 TV 小编过来看看吧。

前段时间我们新上了一个新的应用,因为流量一直不大,集群 QPS 大概只有 5 左右,写接口的 rt 在 30ms 左右。

因为最近接入了新的业务,业务方给出的数据是日常 QPS 可以达到 2000,大促峰值 QPS 可能会达到 1 万。

所以,为了评估水位,我们进行了一次压测。压测过程中发现,当单机 QPS 达到 200 左右时,接口的 rt 没有明显变化,但是 CPU 利用率急剧升高,直到被打满。

压测停止后,CPU 利用率立刻降了下来。

于是开始排查是什么导致了 CPU 的飙高。

问题排查与解决

在压测期间,登录到机器,开始排查问题。

本案例的排查过程使用的阿里开源的 Arthas 工具进行的,不使用 Arthas,使用 JDK 自带的命令也是可以。

在开始排查之前,可以先看一下 CPU 的使用情况,最简单的就是使用 top 命令直接查看:

top - 10:32:38 up 11 days, 17:56, 0 users, load average: 0.84, 0.33, 0.18 Tasks: 23 total, 1 running, 21 sleeping, 0 stopped, 1 zombie %Cpu(s): 95.5 us, 2.2 sy, 0.0 ni, 76.3 id, 0.0 wa, 0.0 hi, 0.0 si, 6.1 st KiB Mem : 8388608 total, 4378768 free, 3605932 used, 403908 buff/cache KiB Swap: 0 total, 0 free, 0 used. 4378768 avail Mem PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND 3480 admin 20 0 7565624 2.9g 8976 S 241.2 35.8 649:07.23 java 1502 root 20 0 401768 40228 9084 S 1.0 0.5 39:21.65 ilogtail 181964 root 20 0 3756408 104392 8464 S 0.7 1.2 0:39.38 java 496 root 20 0 2344224 14108 4396 S 0.3 0.2 52:22.25 staragentd 1400 admin 20 0 2176952 229156 5940 S 0.3 2.7 31:13.13 java 235514 root 39 19 2204632 15704 6844 S 0.3 0.2 55:34.43 argusagent 236226 root 20 0 55836 9304 6888 S 0.3 0.1 12:01.91 systemd-journ

可以看到,进程 ID 为 3480 的 Java 进程占用的 CPU 比较高,基本可以断定是应用代码执行过程中消耗了大量 CPU,接下来开始排查具体是哪个线程,哪段代码比较耗 CPU。

首先,下载 Arthas 命令:

curl -L http://start.alibaba-inc.com/install.sh | sh

启动

./as.sh

使用 Arthas 命令 thread -n 3 -i 1000 查看当前 最忙(耗 CPU)的三个线程:

通过上面的堆栈信息,可以看出,占用 CPU 资源的线程主要是卡在 JDBC 底层的 TCP 套接字读取上。连续执行了很多次,发现很多线程都是卡在这个地方。

通过分析调用链,发现这个地方是我代码中有数据库的 insert,并且使用 TDDL(阿里内部的分布式数据库中间件)来创建 sequence,在 sequence 的创建过程中需要和数据库有交互。

但是,基于对 TDDL 的了解,TDDL 每次从数据库中查询 sequence 序列的时候,默认会取出 1000 条,缓存在本地,只有用完之后才会再从数据库获取下一个 1000 条序列。

按理说我们的压测 QPS 只有 300 左右,不应该这么频繁的何数据库交互才对。但是,经过多次使用 Arthas 的查看,发现大部分 CPU 都耗尽在这里。

于是开始排查代码问题。最终发现了一个很傻的问题,那就是我们的 sequence 创建和使用有问题:

public Long insert(T dataObject) { if (dataObject.getId() == null) { Long id = next(); dataObject.setId(id); } if (sqlSession.insert(getNamespace() +  .insert , dataObject)   0) { return dataObject.getId(); } else { return null; } } public Sequence sequence() { return SequenceBuilder.create() .name(getTableName()) .sequenceDao(sequenceDao) .build(); } /** *  获取下一个主键 ID * * @return */ protected Long next() { try { return sequence().nextValue(); } catch (SequenceException e) { throw new RuntimeException(e); } }

是因为,我们每次 insert 语句都重新 build 了一个新的 sequence,这就导致本地缓存就被丢掉了,所以每次都会去数据库中重新拉取 1000 条,但是只是用了一条,下一次就又重新取了 1000 条,周而复始。

于是,调整了代码,把 Sequence 实例的生成改为在应用启动时初始化一次。这样后面在获取 sequence 的时候,不会每次都和数据库交互,而是先查本地缓存,本地缓存的耗尽了才会再和数据库交互,获取新的 sequence。

public abstract class BaseMybatisDAO implements InitializingBean { @Override public void afterPropertiesSet() throws Exception { sequence = SequenceBuilder.create().name(getTableName()).sequenceDao(sequenceDao).build(); } }

通过实现 InitializingBean,并且重写 afterPropertiesSet() 方法,在这个方法中进行 Sequence 的初始化。

改完以上代码,提交进行验证。通过监控数据可以看出优化后,数据库的读 RT 有明显下降:

sequence 的写操作 QPS 也有明显下降:

于是我们开始了新的一轮压测,但是发现,CPU 的使用率还是很高,压测的 QPS 还是上不去,于是重新使用 Arthas 查看线程的情况。

发现了一个新的比较耗费 CPU 的线程的堆栈,这里面主要是因为我们用到了一个联调工具,该工具预发布默认开启了 TDDL 的采集(官方文档中描述为预发布默认不开启 TDDL 采集,但是实际上会采集)。

这个工具在打印日志过程中会进行脱敏,脱敏框架会调用 Google 的 re2j 进行正则表达式的匹配。

因为我的操作中 TDDL 操作比较多,默认采集大量 TDDL 日志并且进行脱敏处理,确实比较耗费 CPU。

所以,通过在预发布中关闭 DP 对 TDDL 的采集,即可解决该问题。

感谢各位的阅读!关于“如何排查线上 CPU 飙高的问题”这篇文章就分享到这里了,希望以上内容可以对大家有一定的帮助,让大家可以学到更多知识,如果觉得文章不错,可以把它分享出去让更多的人看到吧!

正文完
 
丸趣
版权声明:本站原创文章,由 丸趣 2023-08-25发表,共计3245字。
转载说明:除特殊说明外本站除技术相关以外文章皆由网络搜集发布,转载请注明出处。
评论(没有评论)