YGC 耗时10S+,导致本机提供服务超时异常
Young GC 期间,导致应用 stop the word,影响了应用提供正常服务,导致服务调用方超时。
一. 现象
同事调用我方提供的服务接口,采用的是job轮询方式,依次调用。如果调用服务超时,会中断job,导致无法轮询至结束。
二. 问题追踪
首先打开cat 查询当前应用,查看当前应用服务期间是否抛错,是否因为服务本身异常,导致无法超时。
1. Problem页面显示一切正常。
2. 打开对应服务接口统计情况,显示服务调用有一个调用失败,如下图所示。
但是又无法追踪到具体哪个服务IP异常,接口统计仅仅记录的是调用方的调用情况,服务方仅仅是超时,但是服务还是最后结果正常,服务耗时超过了10S而已。因为公司默认的接口超时未10S,超过10S接口调用方,返回接口超时。服务方程序正常。
3. 打开Transaction页面,查服务最长的SOA2Service ,如下图所示,服务市场11S+。
进入具体transaction,查询具体哪个步骤耗时过长,如下图所示。可以发现,总耗时11S+,业务逻辑耗时10.9S ,但是真正执行的逻辑才0.5S不到。这部分时间应该是耗费在GC stop the word 。
查询到当前服务机器IP,如下图所示。
- 点开Heartbet ,查看机器健康状况,发现当前机器YGC 耗时在10S左右,刚好吻合消失的时间差。
5. 下载当前机器的DUMP,查看具体是内存消耗情况,如下图所示。可以发现 **bag-task-translation-pool-1** 线程池耗费内存最大,高达1.8G,占总内存的93%。
-
定位当前代码,发现代码异常。
当前业务代码原本逻辑是,当前按固定的时间频次,提交执行任务。采用了ScheduledThreadPoolExecutor 线程池,使用了scheduleAtFixedRate,每个1S提交执行任务。问题出现在,如果当前任务在1S内没有执行完,则后续会不断提交任务,导致bag-task-translation-pool-1 内存不断膨胀,GC 耗时过长。
三. 解决办法
解决办法非常简单,调整scheduleAtFixedRate为scheduleWithFixedDelay,scheduleWithFixedDelay 是等待上一个任务执行完,再执行下一个任务,串行执行任务。
四. 总结
考虑全某一段代码适用的场景,对执行的代码怀有敬畏之心。
串行执行任务。