记录一次生产CPU使用率100%问题排查

问题背景

四月中旬生产环境的服务器频繁爆出cpu使用率100%的警告，起初这个业务线不是我负责，也就没有深入了解问题。后边，负责这个业务线的同事离职了，这件事就落在我这边了。然后，开始长达两个月的问题排查和解决方案制定的历程，感叹离职的同事错过了这次学习的机会！

问题分析

在计算机上能引起cpu使用率100%的原因不外乎以下几种：

计算密集型业务，需要进行大量计算导致CPU使用率过高
死循环，代码级别的bug（这种一般在上生产环境之前就应该排查出来，要么是测试的锅，要么是测试的锅，要么是测试的锅）
内存耗尽，JVM频繁执行full gc 最终导致CPU使用率过高
其他原因，比如这次我遇到的使用kafka过程中，不断的进行reblance导致CPU使用率过高

在我们的业务中不存在什么计算，只是进行数据类型的转换、数据关联、数据入库和简单的数据比对。也就不算是计算密集型业务，剩下就只能从剩下的可能性中排查。
当然，如果存在死循环那么CPU使用率应该是一条直线，不会说服务不重启的情况下CPU的使用率降下来。这种可能性也就排除了。
在这里就需要排查内存！内存！内存！

第一篇排查服务器内存使用情况

1、top命令查看进程占用内存使用情况

执行命令 top -c 查看进程使用资源情况显示如下：

从这个图中可以看到整个资源使用情况，以及各个进程资源使用情况。当然还可以使用不同的列对进程进行排序：

P：按%CPU使用率排行
T：按MITE+排行
M：按%MEM排行

上面的截图中看不出来进程18069占用内存还是不小的，但是还达不到执行full gc的情况。因为我们设置的jvm内存最大是6g，也还可以，能接受。
当然这个是我们最后调整过的，之前是2g。在后边进行问题排查的时候暂时设置为6g，后来发现这个对于我们的服务来说也算是比较合适的值。

2、jstat查看进程jvm内存使用情况

从上一步中可以看出来CPU使用率高的进程，接下来就是看一下进程的JVM的垃圾回收情况
1、 jstat -gc 进程号时间间隔次数

从这个截图可以看到JVM的各个区域的使用情况。当然了，问题已经解决了这边就没有那么高的次数了，在修复之前这个都是十几万的次数，每秒都在增加。
2、jstat -gcutil 进程号间隔次数

相比较这个命令现实的更加简洁直观

通过jstat命令排查出来我们的服务full gc频次过高，此时就有必要进行内存分析

3、jmap命令获取堆栈数据

jmap -dump:live,format=b,file=自定义名称.hprof 进程号
通过使用这个命令可以获取当前堆栈数据，然后就是进行内存的分析

4、mat工具分析内存

关于mat使用方式，自行百度在这里不做详细说明。
通过mat工具分析出来大量的对象得不到及时的释放，无形中有点内存泄漏的赶脚

5、代码分析

首先对JVM内存参数调整，2g->6g。先缓解一下报警，也有可能真的是jvm的内存设置太小造成的，至少给排查问题以充足的时间。但是好静不长，只坚持了一个晚上，大量CPU使用率100%报警又来了！

6、代码分析

通过以上四步基本可以判定是大量对象得不到释放，怀疑是代码有问题。进行代码分析
1、mat结果锁定代码位置：mat分析结果表明在使用kafka发送消息的时候大量的producer对象不能及时释放，怀疑和使用的方式有问题。在我们的业务中存在使用CompletionService多线程消费消息再发送消息的功能，其中就有用到take这个方法进行阻塞，每次达到一定批量释放。因此怀疑这个地方有一定的问题！（这里一直有一个疑问没有搞明白，CompletionService在线程执行结束到take执行这段时间，线程引用的对象会不会释放？本人认为不会释放，领导认为会释放，截止目前没有搞清楚）
2、修改代码上线：将CompletionService换成原生的线程池，上线发布！

服务刚上线，马上就尴尬了，CPU使用100%报警马上就来

第二篇排查线程堆栈

top 命令查看进程的线程信息

top命令获取CPU使用率最高的线程

命令：top

通过这个命令可以看到CPU使用率最高的进程

top -Hp 进程号查看进程的所有的线程信息

命令：top -Hp 18069

这个命令查看CPU使用率最高的线程

jstack 进程号 | grep -C 上下行数线程号

命令：jstack 18069 | grep -C 100 2846
由于问题已经解决这里就不展示截图，有问题可以显示出来是那行代码引起的CPU使用过高

通过堆栈信息的排查，可以看出来是kafka一直在进行rebalance引起CPU使用率100%

结语

通过上面一通骚操作基本上排查出来问题。首先是排查内存，频发full gc。在解决full gc之后，发现CPU使用率仍然很高。后来再进行堆栈信息排查才发现是使用kafka消费消息的方案不对引起的。至此CPU使用率100%的问题已经排查出来，具体的解决方案，将在后边的文章中讲述。