容易踩坑的地方:
1、服务异步化后很多步骤都会依赖于异步RPC调用的结果,这时需要特别注意一点,如果是使用基于NIO(比如Netty)的异步RPC,则返回结果是由IO线程负责设置的,即回调方法由IO线程触发,CompletableFuture同步回调(如thenApply、thenAccept等无Async后缀的方法)如果依赖的异步RPC调用的返回结果,那么这些同步回调将运行在IO线程上,而整个服务只有一个IO线程池,这时需要保证同步回调中不能有阻塞等耗时过长的逻辑,否则在这些逻辑执行完成前,IO线程将一直被占用,影响整个服务的响应
2、同步方法(即不带Async后缀的方法)有两种情况。
- 如果注册时被依赖的操作已经执行完成,则直接由当前线程执行。
- 如果注册时被依赖的操作还未执行完,则由回调线程执行。
异步方法(即带Async后缀的方法):可以选择是否传递线程池参数Executor运行在指定线程池中;当不传递Executor时,会使用ForkJoinPool中的共用线程池CommonPool(CommonPool的大小是CPU核数-1,如果是IO密集的应用,线程数可能成为瓶颈)
ExecutorService threadPool1 = new ThreadPoolExecutor(10, 10, 0L, TimeUnit.MILLISECONDS, new ArrayBlockingQueue<>(100));
CompletableFuture<String> future1 = CompletableFuture.supplyAsync(() -> {
System.out.println("supplyAsync 执行线程:" + Thread.currentThread().getName());
//业务操作
return "";
}, threadPool1);
//此时,如果future1中的业务操作已经执行完毕并返回,则该thenApply直接由当前main线程执行;否则,将会由执行以上业务操作的threadPool1中的线程执行。
future1.thenApply(value -> {
System.out.println("thenApply 执行线程:" + Thread.currentThread().getName());
return value + "1";
});
//使用ForkJoinPool中的共用线程池CommonPool
future1.thenApplyAsync(value -> {
//do something
return value + "1";
});
//使用指定线程池
future1.thenApplyAsync(value -> {
//do something
return value + "1";
}, threadPool1);
3、异步回调要传线程池
前面提到,异步回调方法可以选择是否传递线程池参数Executor,这里我们建议强制传线程池,且根据实际情况做线程池隔离。
当不传递线程池时,会使用ForkJoinPool中的公共线程池CommonPool,这里所有调用将共用该线程池,核心线程数=处理器数量-1(单核核心线程数为1),所有异步回调都会共用该CommonPool,核心与非核心业务都竞争同一个池中的线程,很容易成为系统瓶颈。手动传递线程池参数可以更方便的调节参数,并且可以给不同的业务分配不同的线程池,以求资源隔离,减少不同业务之间的相互干扰
4、线程池循环引用会导致死锁
如代码块所示,doGet方法第三行通过supplyAsync向threadPool1请求线程,并且内部子任务又向threadPool1请求线程。threadPool1大小为10,当同一时刻有10个请求到达,则threadPool1被打满,子任务请求线程时进入阻塞队列排队,但是父任务的完成又依赖于子任务,这时由于子任务得不到线程,父任务无法完成。主线程执行cf1.join()进入阻塞状态,并且永远无法恢复
public Object doGet() {
ExecutorService threadPool1 = new ThreadPoolExecutor(10, 10, 0L, TimeUnit.MILLISECONDS, new ArrayBlockingQueue<>(100));
CompletableFuture cf1 = CompletableFuture.supplyAsync(() -> {
//do sth
return CompletableFuture.supplyAsync(() -> {
System.out.println("child");
return "child";
}, threadPool1).join();//子任务
}, threadPool1);
return cf1.join();
}
5、异常获取
由于异步执行的任务在其他线程上执行,而异常信息存储在线程栈中,因此当前线程除非阻塞等待返回结果,否则无法通过try\catch捕获异常。CompletableFuture提供了异常捕获回调exceptionally,相当于同步调用中的try\catch。使用方法如下所示
@Autowired
private UserService userService;
public CompletableFuture<Integer> getCancelTypeAsync(long orderId) {
CompletableFuture<UserInfo> result= userService.getUser(orderId);//业务方法,内部会发起异步rpc调用
return result.exceptionally(err -> {//通过exceptionally 捕获异常,打印日志并返回默认值
log.error("userService.getUser Exception orderId={}", orderId, err);
return 0;
});
}
有一点需要注意,CompletableFuture在回调方法中对异常进行了包装。大部分异常会封装成CompletionException后抛出,真正的异常存储在cause属性中,因此如果调用链中经过了回调方法处理那么就需要用Throwable.getCause()方法提取真正的异常。但是,有些情况下会直接返回真正的异常
@Autowired
private UserService userService;
public CompletableFuture<Integer> getCancelTypeAsync(long orderId) {
CompletableFuture<UserInfo> resultFuture= userService.getUser(orderId);//业务方法,内部会发起异步rpc调用
return resultFuture.thenApply(result -> {//这里增加了一个回调方法thenApply,如果发生异常thenApply内部会通过new CompletionException(throwable) 对异常进行包装
//这里是一些业务操作
})
.exceptionally(err -> {//通过exceptionally 捕获异常,这里的err已经被thenApply包装过,因此需要通过Throwable.getCause()提取异常
log.error("userService.getUser Exception orderId={}", orderId, ExceptionUtils.extractRealException(err));
return 0;
});
}
public class ExceptionUtils {
public static Throwable extractRealException(Throwable throwable) {
//这里判断异常类型是否为CompletionException、ExecutionException,如果是则进行提取,否则直接返回。
if (throwable instanceof CompletionException || throwable instanceof ExecutionException) {
if (throwable.getCause() != null) {
return throwable.getCause();
}
}
return throwable;
}
}
问题描述:
某个时间段,多台服务器大量出现接口超时的情况。之后自行恢复
排查过程:
- 某一时间段内大量请求超时的情况,且是不同的接口,之后又恢复正常
- 查询该时间段内的请求调用情况,发现有一个流量徒增的情况,
- 然后对请求进行分类汇总,发现流量的增加主要是涉及到一个接口上,所以重点就看了下改接口的内部逻辑
- 发现接口使用的是一个completableFuture多线程合并请求的一个功能,通过调研发现comletableFurture默认使用的线程池是公共默认线程池
- 所以结论及时此接口请求量徒增,导致暂用大量的公共线程,导致其他接口拿不到线程的问题
- 解决就是此接口自定一个私有的线程池,来进行业务的隔离
查询该时间段服务响应情况,发现很多后端服务响应时间超级慢 60s加,之后nginx大量尝试后端服务,直至诊断服务不可用,nginx直接返回502.
多个后端服务均60s+,抽查了几个业务代码功能,发现并不是接口性能问题。
排查了网络问题,网络也无问题
排查了cpu情况,cpu使用率也无问题
最后怀疑是某一个接口卡死,导致其他接口线程等待,造成很多接口都无法正常响应
为了确认是否是这个原因,对改时间段的有问题的请求进行了次数汇总,发现一个合并请求的接口发生问题的次数明显很高,所以重点排查
该服务业务代码采用了 CompletableFuture 来并发处理多个请求
1、这个是一个http 请求合并接口,响应时间等于最后一个http 请求完成时间
2、接口内使用CompletableFuture,没有设置过线程池,所以默认线程池大小为cpu 核数。
3、短时间大量请求过来先堵塞CompletableFuture的默认线程池CommonPool线程池,最后造成 502
但为什么一直没问题,突然有问题呢?
流量徒增引起,可能和市场投放有关,导致接口请求并发数该时间段远远大于日常请求并发数
优化:
1、使用CompletableFuture,设置过线程池,配置线程数100
2、对Http请求设置响应超时时间
final ExecutorService executorService = Executors.newFixedThreadPool(100);
@PostMapping("/combine")
@ApiOperation(value = "接口合并")
public BaseDtoResponse<Map<String, String>> combine(HttpServletRequest req,
@RequestBody List<CombineRequest> request) {
Map<String, String> headers = new HashMap<>();
for (HeaderEnum headerEnum : HeaderEnum.values()) {
headers.put(headerEnum.getKey(), req.getHeader(headerEnum.getKey()));
}
Map<String, String> map = new ConcurrentHashMap<>();
// request.parallelStream().forEach(v -> resolve(headers, v, map));
long start = System.currentTimeMillis();
List<CompletableFuture> futures = Lists.newArrayList();
for (CombineRequest r : request) {
futures.add(CompletableFuture.runAsync(() -> {
long end = System.currentTimeMillis();
log.info("combine.combine.time1:{}",(end - start));
DefaultHttpParam defaultHttpParam = new DefaultHttpParam();
defaultHttpParam.setHeaders(headers);
defaultHttpParam.setUrl(r.getUrl());
defaultHttpParam.setBody(r.getBody());
defaultHttpParam.setMethod(r.getMethod());
try {
String resp = HttpClient.send(defaultHttpParam);
map.put(r.getMethod() + " " + r.getUrl(), resp);
log.info("combine.combine.getMethod:{},getUrl{},getBody:{},headers:{},resp:{}",r.getMethod(),r.getUrl(),r.getBody(),JSON.toJSONString(headers), resp);
} catch (IOException e) {
log.info("combine.combine.error: {}", e);
}
},executorService).thenRunAsync(() -> {
long end = System.currentTimeMillis();
log.info("combine.combine.time2:{}",(end - start));
},executorService));
}
CompletableFuture.allOf(futures.toArray(new CompletableFuture[0])).thenRun(() -> {
long end = System.currentTimeMillis();
log.info("combine.combine.time3:{}",(end - start));
}).join();
return ResponseFormatterHelper.success(map);
}