java ScheduledThreadPoolExecutor 明显超过设定时间

Question

简化展示

public class SchedulerIssueShowcase {

    private static final int delay = 5000;
    private static final ScheduledThreadPoolExecutor threadPoolExecutorScheduler = new ScheduledThreadPoolExecutor(4);

    @UIThread
    public void schedule() {
        threadPoolExecutorScheduler.schedule(() -> Log.debug("Started after delay"), delay, TimeUnit.MILLISECONDS);
    }

}

它是 java 14 桌面应用程序。我们有大约 1% 的客户报告计划任务的执行开始延迟（调试行作为执行的第一行似乎已经延迟）长达几分钟而不是 5 秒。 会是什么原因？我能想到的唯一原因是主机过载，这是有效的选择，但不知何故我不太确定。

问题

你能想出更多的理由吗？ 你会如何调试它？

Answer 1

您创建了池大小为 4 的 ScheduledThreadPoolExecutor，因此它一次最多只能运行 4 个任务，即使有更多项目超过了预期的启动延迟。其余的将不得不等待执行程序线程之一可用。您可以使用以下简单代码进行演示，该代码记录活动线程数并计算每个线程的任务数：

// import java.util.concurrent.atomic.AtomicInteger;
int delay = 5000;

ScheduledThreadPoolExecutor threadPoolExecutorScheduler = new ScheduledThreadPoolExecutor(4);
var threads = new ConcurrentHashMap<String,AtomicInteger>();
for (int i = 0; i < 10; i++) {
    threadPoolExecutorScheduler.schedule(() -> {
       String tName = Thread.currentThread().getName();
       threads.computeIfAbsent(tName, tn -> new AtomicInteger()).incrementAndGet();
       System.out.println(tName+" Start threads#"+threads.size() + " = "+threads);
       try {Thread.sleep(20000); } catch(Exception lost) {}
       System.out.println(tName+" END");
       }
       , delay, TimeUnit.MILLISECONDS);
}

提交10个任务，延迟5秒，可以看到最大线程数为4，后6个任务只有前4个完成才能启动。

pool-1-thread-2 Start threads#1 = {pool-1-thread-3=1, pool-1-thread-2=1, pool-1-thread-4=1}
pool-1-thread-4 Start threads#3 = {pool-1-thread-3=1, pool-1-thread-2=1, pool-1-thread-4=1}
pool-1-thread-3 Start threads#2 = {pool-1-thread-3=1, pool-1-thread-2=1, pool-1-thread-4=1}
pool-1-thread-1 Start threads#4 = {pool-1-thread-1=1, pool-1-thread-3=1, pool-1-thread-2=1, pool-1-thread-4=1}
pool-1-thread-2 END
pool-1-thread-2 Start threads#4 = {pool-1-thread-1=1, pool-1-thread-3=1, pool-1-thread-2=2, pool-1-thread-4=1}
pool-1-thread-3 END
pool-1-thread-3 Start threads#4 = {pool-1-thread-1=1, pool-1-thread-3=2, pool-1-thread-2=2, pool-1-thread-4=1}
pool-1-thread-4 END
pool-1-thread-4 Start threads#4 = {pool-1-thread-1=1, pool-1-thread-3=2, pool-1-thread-2=2, pool-1-thread-4=2}
pool-1-thread-1 END
pool-1-thread-1 Start threads#4 = {pool-1-thread-1=2, pool-1-thread-3=2, pool-1-thread-2=2, pool-1-thread-4=2}
pool-1-thread-2 END
pool-1-thread-2 Start threads#4 = {pool-1-thread-1=2, pool-1-thread-3=2, pool-1-thread-2=3, pool-1-thread-4=2}
pool-1-thread-3 END
pool-1-thread-3 Start threads#4 = {pool-1-thread-1=2, pool-1-thread-3=3, pool-1-thread-2=3, pool-1-thread-4=2}
pool-1-thread-4 END
pool-1-thread-1 END
pool-1-thread-2 END
pool-1-thread-3 END

您已经达到了同时运行太多任务的地步——这要么是任务中的缺陷，要么您可能需要考虑不同的线程/执行器服务策略。根据@Basil Bourque 的回答项目，LOOM 可以让处理变得更容易。

使用像 Eclipse 这样不错的 IDE 进一步诊断/调试，添加日志语句（可能不是 log4j！），并使用堆栈跟踪（jstack <pid> 或控制台中的 CTRL-Break）等其他信息来帮助您识别代码失败了。

Answer 2

您严重误解了 5 秒争论的性质。这不是超时。恰恰相反，这是一个延迟。您提交的任务在开始它的工作之前等待五秒钟。阅读the Javadoc。

您的代码没有限制任务需要多长时间。

至于为什么您的某些任务比其他任务花费更长的时间，显然我们无法在不了解您的代码库、您的计算机硬件和软件以及您的部署场景（包括网络和数据库性能）的情况下进行诊断。

在某些情况下，使用 Project Loom 提供的新 virtual threads，并发任务将得到巨大改进。 Project Loom 技术的一个正在进行中的实验性构建现已推出，构建于早期访问 Java 18 之上。请参阅 Ron Pressler 或 Alan Bateman 的谈话和采访。