某日发现定时任务线程池中的所有线程全部阻塞:
代码如下:
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30 31 32 33 34 35
| private final ExecutorService royalFlushExecutor = Executors.newFixedThreadPool(RoyalFlush.THREAD_NUM, new NamedThreadFactory("royalFlushExecutor", false));
@Override public List<StockRoyalFlushDto> fetchRoyalFlushData(List<StockBaseInfoEntity> stockBaseInfoEntities) { String currentTime = DateUtil.currentTimeStr();
List<StockRoyalFlushDto> results = new ArrayList<>();
List<Future<StockRoyalFlushDto>> futures = new ArrayList<>();
System.setProperty("https.protocols", "TLSv1,TLSv1.1,TLSv1.2");
AtomicInteger current = new AtomicInteger(0); for (StockBaseInfoEntity stockBaseInfoEntity : stockBaseInfoEntities) { String url = String.format(String.format(RoyalFlush.AI_URL, stockBaseInfoEntity.getCode() + RoyalFlush.QUERY)); futures.add(royalFlushExecutor.submit(() -> { log.info("royalFlushData-当前进度:{}/{}-启动时间:{}", current.getAndIncrement(), stockBaseInfoEntities.size(), currentTime); return fetchAndParseData(stockBaseInfoEntity, url); })); }
for (Future<StockRoyalFlushDto> future : futures) { try { StockRoyalFlushDto stockRoyalFlushDto = future.get(1, java.util.concurrent.TimeUnit.SECONDS); if (stockRoyalFlushDto != null) { results.add(stockRoyalFlushDto); } } catch (Exception e) { log.error("royalFlushData-任务执行失败:{} e:{}", e.getMessage(), e.toString()); } }
return results; }
|
尝试复现,发现一段时间后1号线程池不见了:
定位排查
使用ps aux | grep java能够定位进程号,当然日志的INFO后面就是进程id,为22385
使用top -H -p命令找到该进程:
使用jstack查看线程状态及堆栈信息:
1
| jstack 22385 | grep -C 50 22426
|
能看到线程是RUNNABLE状态,下意识可能认为RUNNABLE状态并没有执行,但RUNNABLE还被分为Running和Ready两种状态。
也就是说,处于RUNNABLE状态的线程有可能正在运行,也有可能没有正在执行、等待分配CPU资源。
因此,一个处于RUNNING状态的线程,当运行到任务一半时,执行该线程的CPU被调度去做其他事情,则该线程暂时不运行。但它的状态不变,还是RUNNABLE,因为它有可能随时被调度回来继续执行任务。
源码排查及修正
定位了逻辑入口后,看依赖方法的底层代码,发现timeout为-1,即不超时:
在原有代码第90行的上方加上超时时间:
问题顺利解决,其实官方文档也有提示,一定进行修改防止把系统拖死。
总结
- 远程调用一定设置超时时间
- 线程池中的线程被阻塞了,尽管取结果时配置了超时,但也只是取逻辑可以往下走,执行线程还是在那里阻塞着
- 最新版本的Java,jstack可以不用把线程转为8进制即可查询
- 日志打印线程信息重要性,不要随便用sout打信息