大家好,我是烤鸭:
最近没怎么写技术文章,还是得回归下初心,正好前几天出现个线上问题,记录下排查过程。
问题描述
某个时间点,接收到接口响应慢报警。
过一会收到服务器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(运行了一年才发现,也是醉了)