Java服务问题快速排查指南

Posted 2022-11-09 小杨Vita

问题

收到服务内存占用过大告警，登录虚拟机使用top发现每隔几秒java进程占用的CPU就会暴增一次。

排查方向一：服务日志

1. 使用tail -fn 100 xxx.log查看服务日志，发现频繁打印连接mail服务器失败错误，根据错误堆栈信息定位到业务代码位置
2. 定位业务代码中的错误

排查方向二：JVM工具

若代码中未打印出错信息，可以考虑从jvm线程上入手。

1. 使用jps -mlv获取java服务pid
2. 使用top -H -p pid查看高占用线程（此时pid为tid），CPU打满时有10多个线程都占10%左右
3. 使用jstat -gc pid 1000及jstat -gcutil pid 1000查看gc情况，发现大约每隔1到2秒jvm进行一次minor gc，老年代空间几乎不变，怀疑业务逻辑导致不断创建、释放新对象
4. 记录步骤2中高占用率的几个线程tid，使用printf "%x\\n" tid将tid转为16进制
5. 使用jstack pid打印线程状态，观察未出现死锁，搜索上一步的16进制数对应的线程，发现繁忙线程果真大都是gc线程，同时参杂着自定义线程池的线程，找到running状态的线程，根据线程调用栈定位到代码中执行的位置
6. 业务代码中线程正在执行的是邮件发送操作，与方向一种错误位置吻合
7. 定位到错误根源：该机器未开启外网访问权限，而代码业务逻辑中检测邮件发送连接失败则直接扔回队列中重试，因为没有设定最大重试次数导致频繁创建邮件消息体，耗尽堆空间，打开外网后问题解决

辅助分析
使用jmap -dump:format=b,file=dump.bin pid生成堆转储文件，使用jhat dump.bin或复制到有VisualVM等分析工具的机器上进行分析，可以发现占用堆空间最大的是char[]数组，打开其中几个发现内容都是一致的，都是邮件发送的消息体。

扩展

1. 可以结合free、vmstat、iostat、netstat等系统命令进行分析排查
2. 将上述步骤写成脚本方便快速定位问题，网上已有不少例子，如 https://github.com/oldratlee/useful-scripts