记一次线上cpu飙升100%的排查过程

大家好，我是烤鸭：

   最近没怎么写技术文章，还是得回归下初心，正好前几天出现个线上问题，记录下排查过程。

问题描述

某个时间点，接收到接口响应慢报警。

过一会收到服务器cpu可用率低(<10%)报警。

去cat上查看发现younggc次数频繁。

排查思路

• 业务代码近期没改动和发版，出现问题大概率是中间件或者环境问题(服务器硬件或网络)。

• 尝试回滚代码和扩容机器。

• 输出堆栈日志和gc快照，调整jvm参数。

排查结果

• 中间件和网络：

  使用到的中间件包括 es、redis、mysql，分别去监控和连接查看，没问题。

  网络也在机器上测试，没问题。

• 回滚和扩容

  尝试回滚到上一个稳定版本和增加扩容机器。

  还是有问题。

• 输出堆栈日志和gc快照，调整jvm参数。

  其实堆栈日志是可以解决问题的，不过当天晚上排查的时候，没有过度关注业务方法，导致错过了问题根源。

  gc快照分析结果，发现是tomcat的一个初始化对象占有较多（跟问题无关）。

总结

cpu升高和gc频繁，其实是两个问题，都可能会引起服务不可用。

单纯的cpu升高，基本确认是死循环问题，抓到对应的堆栈信息即可。

#抓取进程中cpu消耗高的线程
top -Hp pid
#线程id转成十六进制
printf '%x\n' tid
#抓取java线程堆栈
jstak-l pid

而gc频需要查看gc日志，是否引起oom。

实时查看gc情况，每隔5s打印一下gc情况。

jstat -gcutil pid 5000

输出gc快照。

jmap -dump:format=b,file=/data/dump.hprof pid

然后使用eclipse mat 或者 jprofiler 进行分析。

血泪教训

当天忽略了堆栈日志，过多的关注在gc上。

排查问题的思维定式，排查思路和实际执行不严谨，以致于错过问题根源。

运行了几年的代码都没出问题，不代表代码本身没问题，以堆栈日志和gc日志为准。

根本原因就是数据库脏数据触发了代码中一个死循环bug(运行了一年才发现，也是醉了)