问题起因:客户反馈每晚凌晨会有很多消息推送延时很久
解决步骤:
1、通过反应单子发现busi_task任务创建时间和完成时间延时很多
2、按小时分别统计任务生成数量 和 完成数量,发现凌晨1点开始完成数量比生成数量少很多,直到凌晨3、4点才慢慢恢复
3、通过任务完成耗时并没有发现很多耗时的任务,所以不是某个任务业务处理慢导致(其实这个问题还是执行业务时间很长,只是当时还没加耗时统计)
4、任务执行方式由一台服务扫描后异步推送至MQ,另一台服务器消费MQ消息,发现推送时间正常,消费时间延时很久,说明确实是消费服务器处理很慢。
5、因为凌晨3、4点恢复了,所以早上没法分析具体原因,直到周六早上还是堆积状态,这才可以查看线程快照。终于找到有很多线程 java.lang.Thread.State: TIMED_WAITING (sleeping),查看原因在等待锁
6、找到原因是代码中在释放锁在return语句之前,导致同一个邮箱被堵住了,解决方案是把释放锁代码放在try finnally中。这样无论如何都会释放锁。重新发布后问题解决了。
问题总结:
1、为什么只在凌晨1点开始
通过分析emailSend类型数据量,发现凌晨1点生成数据量比其他时间多很多,所以集中爆发了
2、为什么后续又会自动慢慢恢复
通过查看锁获取代码发现锁60秒后会自动释放,因此任务还是可以继续跑,只是占用的时间比较多,所有任务共同使用线程池,导致处理其他任务的线程数量变少。故而整体消费速度变慢导致任务延时严重,当emailSend类型数据逐渐跑完,整体消费速度慢慢的就恢复了。