目录
一、背景
某天开心的上班,突然产品找到我,说咱们有个查询接口,最长需要分钟级才有响应,已经被业务方骂惨了,需要优化,赶紧的。
二、排查及解决
于是我吭哧吭哧的开始排查,记录下我得排查过程:
- 梳理代码,把怀疑对象定在了一个rpc接口调用上,页面实操,接着拿到traceId去全链路追踪平台去看调用链路,发现罪魁祸首好像并不是rpc接口调用,而是在接口内部;
2. 理出可能耗时的关键步骤,借用StopWatch和日志打点记录其耗时;
3. 定位到耗时最长的代码逻辑
//方法1:线程池定义
private final static ExecutorService executorService = new ThreadPoolExecutor(8, 200, 0L, TimeUnit.MILLISECONDS,
new LinkedBlockingQueue<>(1024), new ThreadFactoryBuilder().setNameFormat
("PromoDisplayScheduleController-pool-%d").build(),
new ThreadPoolExecutor.AbortPolicy());
//关键耗时代码
shopCode2SkuSet.forEach((shopCode, skuSet) -> {
executorService.submit(() -> {
//省略其它逻辑......
Map<String, StoreSkuDTO> storeSkuDTOMap = skuReadManager.mGetStoreSku(merchantCode, shopCode,skuSet);
});
});
//方法2:线程池定义
private final static ExecutorService executorService = new ThreadPoolExecutor(8, 200, 0L, TimeUnit.MILLISECONDS,
new LinkedBlockingQueue<>(1024), new ThreadFactoryBuilder().setNameFormat
("PromoDisplayScheduleController-pool-%d").build(),
new ThreadPoolExecutor.AbortPolicy());
//关键耗时代码
List<List<String>> partition = Lists.partition(skuList, 50);
for (List<String> skuCodeList : partition) {
executorService.execute(() -> {
//rpc远程调用
Result<List<StoreSkuDTO>> mGetRes = shopSkuServiceClient.getStroeSku(skuCodeList, shopCode, merchantCode);
});
}
分析代码:
发现是方法1中利用一个线程池去并发调用方法2,方法2内部使用线程池去多线程调用外部rpc接口,这个写法比较奇怪,之前也没有见过,于是仔细研究了一下代码,最终问题定位:
分析数据情况,发现外层线程池平均会处理40个任务,内层线程池平均处理15个任务,内层方法中rpc接口调用平均耗时5s(没办法,忍着吧,其它团队开发),外层和内层线程池参数均为:核心线程数8,最大线程数200,任务队列1024。当一次接口调用来临时,首先走到外层线程池调用,由8个核心线程执行8个任务,其余任务放入任务队列,外层核心线程调用的任务中会调用内层方法,然后走到内层线程池调用,同样是8个核心线程执行8个任务,其余任务放入任务队列,理想情况下,内层线程池只需要每个核心线程执行2个任务,所以外层核心线程执行的每个任务时长应该在10s,而外层线程池只需要每个核心线程执行5个任务,所以整个多线程执行完毕耗时在50s左右,这也是导致接口过慢的罪魁祸首。
解决:
分析到原因之后,解决方法就比较简单粗暴了,将任务队列调小或者将核心线程数调大(视具体业务情况来定,一般是将任务队列调小,毕竟核心线程是不会被销毁的,耗资源,但也要注意是否会造成线程池超负荷,从而丢弃任务),不让任务有进入到任务队列的机会,这样整个多线程执行完毕耗时在5s左右,也就是rpc接口调用耗时的时长。