之前一直时不时收到公司报警邮件:提示一个应用部署的机器CPU负载告警和线程池队列超过阈值。
今天又收到了,决定好好排查处理一下。
一:让运维同事帮忙保留现场dump线程和内存
二:重启应用 以免影响调用方体验
业务分析:
各业务方会上报订单的不同节点:下单,支付,审核,出库等,这些上报请求过来的时候我们是先塞到MQ队列里。
然后专门的模块从MQ中取出数据然后放到线程池中做具体的业务逻辑:触达消息,订阅快递公司等
代码分析:
创建线程池的代码:new ThreadPoolExecutor(coreSize,maxSize,0L,TimeUnit.MILLISECONDS,new LinkedBlockingQueue<Runnable>());
采用的是默认的LinkedBlockingQueue 没有指定大小,所以这里默认的大小是Interger.MAX_VALUE
内存分析:
jmap -histo:live pid | more:命令辅助MAT分析内存:
发现两个比较大的对象:LinkedBlockingQueue 和HashSet
线程分析:
由于应用已经重启,所以没法用jstack命令,无法查看虚拟机内每一条线程正在执行的方法堆栈集合,用来定位线程出现长时间停顿的原因。
所以使用了fastthread.io网站来分析线程
发现线程就是在处理上面提到的大对象HashSet,并且是在查询key是否存在
问题定位:
分析代码发现:业务逻辑中为了避免同一订单的统一节点流水重复的上报,我们有一个HashSet 用来存放:订单号-节点编号 元素,因为HashSet存放的元素
不可重复,所以保证了同一订单的统一节点只会存入一次。比如订单的下单节点为:0001,支付节点为:0002,审核节点为:0003,出库节点为:0004.
订单号为100013232456,那么下单事件上报时 就会有一条“100013232456-0001”的节点存放在HashSet中,该订单重复上报下单节点时,判断已有“100013232456-0001”
这个元素,则直接返回,不处理后续逻辑
伪代码为:
if(set.contains(key))
{
return;
}
else()
{
//发送微信小程序触达消息
}
每天定时清空set的内容。
讨论后分析得出的结论为:
因为是线程池处理的任务,作为共享资源HashSet没有做同步处理,多线程共同操作了HashSet,因为其底层就是HashMap,不是线程安全的。
考虑到CPU的持续高负载,联想到之前看到的源码分析中讲到过HashMap在扩容时可能形成循环链表。导致contains()方法死循环。
BUG修复:
把HashSet换成ConcurrentHashMap,把每个key对应的Value写死为:1,这样调用KetSet()方法时 返回的效果和HashSet一样,排重。
总结线上JVM问题排查:
一.CPU占用飙高
1.top命令找到占用CPU异常高的JAVA进程PID
2.ps -mp pid -o THREAD,tid,time 命令查出该java进程的线程列表,找出异常占用cpu的线程
3.把查出的十进制tid 转化成 十六进制数
4.jstack pid |grep tid -A 30 命令定位代码位置
或者1.ps -ef | grep tomcat ——>pid
2.top -H -p pid 查看某进程中线程使用cpu的情况
3.已经知道了是tomcat进程中哪个线程占用CPU高 thread-aaa
4.jstack pid ————> 查看到该线程的状态
5.结合并发编程中 线程状态信息分析
二.OOM异常
看异常日志是堆内存OOM(对象占用过多,-Xmx参数过小),
还是方法区(永久代)OOM(加载的类文件过大,-XX:MaxPermSize)
1.top命令找到占用CPU异常高的JAVA进程PID
2.jmap -histo:live [pid] 分析具体的对象数目和占用内存大小,从而定位代码。
3.jmap -dump:live,format=b,file=xxx [pid] 将当前Java进程的内存占用情况导出来,然后利用MAT工具分析是否存在内存泄 漏
GCeasy.io网址分析GC日志