一次非典型的CPU告警的排查

最新推荐文章于 2024-06-02 16:03:23 发布

原创

最新推荐文章于 2024-06-02 16:03:23 发布 · 894 阅读

4 ·

CC 4.0 BY-SA版权

文章标签：

#Java

本文记录了一次非典型的CPU告警排查过程，问题最终定位为由GC引起。通过`top`、`jstack`、`jmap`等工具分析，发现频繁的大对象分配导致GC暂停时间过长，特别是1M大小的byte数组。通过代码审查找到了初始化过大byte数组的源头，修复了问题。

最近线上频繁收到CPU超过阈值的告警, 很明显是哪里出了问题.

于是排查了一番, 到最后找到罪魁祸首的时候, 突然意识到这次是一次很有意思的"非典型"的CPU的问题, 所以这里特意记录一下.

为啥说它是非典型呢, 因为在我的经验里, 典型的CPU飙升通常都是业务代码里面有死循环, 或是某个RPC性能过低阻塞了大量线程等等,而这次的CPU问题却是由GC引起的, 因吹斯汀

来看看排查过程

（想自学习编程的小伙伴请搜索圈T社区，更多行业相关资讯更有行业相关免费视频教程。完全免费哦!）

找出占用CPU的线程

top

首先肯定是先看哪些线程占用CPU最高, 这个可以使用top命令:

top -Hp $pid -b -n 1|sed -n "7,17p"

   PID USER      PR  NI  VIRT  RES  SHR S %CPU %MEM    TIME+  COMMAND           
 94349 app     20   0 11.2g 5.0g  12m S 15.0 32.1 215:03.69 java              
 94357 app     20   0 11.2g 5.0g  12m S 15.0 32.1  88:22.39 java              
 94352 app     20   0 11.2g 5.0g  12m S 13.1 32.1 215:05.71 java              
 94350 app     20   0 11.2g 5.0g  12m S 11.2 32.1 215:04.86 java              
 94351 app     20   0 11.2g 5.0g  12m S 11.2 32.1 215:04.99 java              
 94935 app     20   0 11.2g 5.0g  12m S 11.2 32.1  63:11.75 java              
 94926 app     20   0 11.2g 5.0g  12m S  9.4 32.1  63:10.58 java              
 94927 app     20   0 11.2g 5.0g  12m S  5.6 32.1  63:06.89 java              
 94932 app     20   0 11.2g 5.0g  12m S  5.6 32.1  63:12.65 java              
 94939 app     20   0 11.2g 5.0g  12m S  5.6 32.1  63:01.75 java

$pid是我们对应的java进程的进程ID, sed -n “7,17p” 是取第7到第17行, 因为前7行都是top命令的头部信息, 所以第7到第17行就是该线程下最耗CPU的前10个线程了.

其中第一列的"pid"就是JVM里面对应的线程ID, 我们只需要用线程ID在jstack里面找到对应的线程就知道是谁在搞鬼了.

不过需注意的是top命令中的PID是十进制的, 而jstack里面的线程ID是十六进制的, 所以我们还需要做一个工作, 就是把上面的PID转成十六进制, 这里我只转换了最耗CPU的前3个:

[app@linux-v-l-02:/app/tmp/] $'%x\n' 94349 1708d [app@linux-v-l-02:/app/tmp/]$