使用CompletableFuture并行调用时最后请求耗时过长的原因

云上老周

2026-7-9

问题

我尝试使用CompletableFuture.supplyAsync方法发起多次并行调用，自定义了核心线程数为5的固定线程池，代码如下：

ExecutorService customExecutor = Executors.newFixedThreadPool(5,new ThreadFactoryBuilder()
    .setNameFormat("EXECUTOR-%d")
    .setThreadFactory(Executors.defaultThreadFactory())
    .build());

long start = System.currentTimeMillis();
List<CompletableFuture<Customer>> graphQLCalls = Lists.newArrayList();
for (String id : ids) {
  System.out.println(id);
  graphQLCalls.add(CompletableFuture.supplyAsync(
      () -> graphQLService.postGraphQLQuery(id), customExecutor));
}

CompletableFuture<?>[] futureResultArray = graphQLCalls.toArray(new CompletableFuture<?>[0]);
CompletableFuture<Void> combinedFuture = CompletableFuture.allOf(futureResultArray);
combinedFuture.get();
LOGGER.info("Completed multiple parallel calls: " + (System.currentTimeMillis() - start));

但从执行日志来看，每次执行中最后完成的请求耗时总是远长于其他请求，日志示例如下：

2023-10-03 11:55:31.647  INFO 20776 --- [ ODS-EXECUTOR-1] a.RestClient: POST DOWNSTREAM SUCCESS: Time Taken by Downstream System :78ms
2023-10-03 11:55:31.666  INFO 20776 --- [ ODS-EXECUTOR-2] a.RestClient: POST DOWNSTREAM SUCCESS: Time Taken by Downstream System :97ms
2023-10-03 11:55:31.734  INFO 20776 --- [ ODS-EXECUTOR-0] a.RestClient: POST DOWNSTREAM SUCCESS: Time Taken by Downstream System :165ms
2023-10-03 11:55:33.011  INFO 20776 --- [ ODS-EXECUTOR-3] a.RestClient: POST DOWNSTREAM SUCCESS: Time Taken by Downstream System :1442ms

2023-10-03 13:41:15.164  INFO 20776 --- [EXECUTOR-0] c.RestClient  : POST DOWNSTREAM SUCCESS: Time Taken by Downstream System :194ms
2023-10-03 13:41:15.330  INFO 20776 --- [EXECUTOR-2] c.RestClient  : POST DOWNSTREAM SUCCESS: Time Taken by Downstream System :360ms
2023-10-03 13:41:18.008  INFO 20776 --- [EXECUTOR-1] c.RestClient  : POST DOWNSTREAM SUCCESS: Time Taken by Downstream System :3038ms

请问为何最后一条请求总是耗时更长？

分析与解决

下游服务限流/排队：多数后端服务会对并发请求做限流控制，短时间内大量请求涌入时，后续请求会被放入服务端队列等待处理，直接导致耗时陡增。如果你的ids数量远大于线程池核心线程数5，超出的任务会先进入线程池的无界队列，待前面的任务完成后才会被执行，此时下游服务可能已积累大量待处理请求，进一步拉长了这个任务的处理时间。
线程池任务队列调度延迟：Executors.newFixedThreadPool默认使用无界LinkedBlockingQueue，当任务数量超过核心线程数时，任务会被暂存到队列中。最后完成的任务大概率是队列中最后一个被调度的，它的启动时间本身就远晚于前面的任务，再加上下游处理时间，总耗时自然看起来更长。
下游服务资源瓶颈：最后执行的请求可能恰好遇到下游服务的资源耗尽情况，比如数据库连接池占满、CPU/内存使用率过高，导致处理速度大幅下降，进而出现耗时异常的情况。
“最后完成”的认知偏差：你看到的是最后完成的请求而非最后提交的请求，并行执行时任务耗时本就有差异，总有一个任务会最晚完成，但结合你多次执行的日志来看，这种异常耗时并非随机事件，更倾向于前面三种场景。

验证与优化建议：

统计ids的数量，若超过5，在postGraphQLQuery方法开头添加启动日志，确认最后完成的任务是否启动时间明显滞后。
直接模拟并发请求调用下游接口，验证是否存在限流或排队机制。
若ids数量不大，可将线程池核心线程数调整为与ids数量一致，观察是否还会出现耗时异常的情况。

内容的提问来源于stack exchange，提问作者uniQ