Spring Scheduled 定时任务没有准时执行

1、问题现象

可以看到同一个定时任务，每天的执行开始时间都是不同的。这个定时任务正确的开始执行时间是0点开始执行，但是有的在执行的时候都是2点了。真正开始执行时间和设置的定时时间偏差较大。
这个是真实配置的定时时间。

2、问题溯源

从问题现象的图上面可知道，每次定时任务延迟的时间都不一样，而且有时是准确执行，有时是延迟执行。且定时任务能正常执行，但是执行的时间和配置的时间不对，也就是说配置是没问题，有问题可能是Spring的scheduled问题，那么Spring的scheduled是如何处理定时任务的呢，这时就要带着这个问题去看Spring处理scheduled的源码了。
首先DeBug启动一个定时任务，看他的整个调用链。看到其调用链类似这样。

可以看到整个调用链起始地方，即Spring启动的流程方法，refresh()(整个Spring启动流程最核心的方法)。
然后在往下找，会看到finshRefresh()，这方法表示整个Spring的启动流程基本上完成，在这个方法中，会调用一些监听Spring初始化完成ApplicationContext容器的监听者。而Spring的Scheduled就是依赖Spring的监听器模式来实现定时任务的发现和注册。
下面直接调到采用依赖Spring的监听器模式处理定时任务的发现和注册的地方
org.springframework.scheduling.annotation.ScheduledAnnotationBeanPostProcessor#onApplicationEvent。

@Override
public void onApplicationEvent(ContextRefreshedEvent event) {
    if (event.getApplicationContext() == this.applicationContext) {
        // Running in an ApplicationContext -> register tasks this late...
        // giving other ContextRefreshedEvent listeners a chance to perform
        // their work at the same time (e.g. Spring Batch's job registration).
        finishRegistration();
    }
}

下面就是出现上面这种场景的问题所在了，在finishRegistration()方法中，会对taskScheduled这个属性设置值，这个本质上就是一个线程池，用来处理处理定时任务的。正常来说，如果程序中没有指定线程池的配置，也就是Spring的Scheduled的默认线程池配置，其线程池的线程数默认为1，也就是说默认情况下，Spring用来处理定时任务的线程只有一个。如果有定时的处理时间占用时间比较长，那么就会导致下一个定时任务，即使到达了配置的定时时间，也不会立即执行，而是等到前面一个任务处理完成了，才会进行处理。

Spring中Scheduled使用的线程池实际上就是ScheduledThreadPoolExecutor这个线程池，由于只有一个线程处理任务，且是定时任务，因此Spring在启动时只是将定时任务添加到队列中。等真正的任务时间到了之后在交由工作线程进行处理。启动时，将任务添加到队列的位置在java.util.concurrent.ThreadPoolExecutor#ensurePrestart。

void ensurePrestart() {
    int wc = workerCountOf(ctl.get());
    if (wc < corePoolSize)
        addWorker(null, true);
    else if (wc == 0)
        addWorker(null, false);
}

3、问题复现

那么，既然发现了问题所在，我们可以复现一下，到底是不是咱们发现的这个问题。下面是我测试的demo代码。

@Configuration
public class TaskDemo {
    @Scheduled(cron = "0 56 15 * * ?")
    public void test() throws InterruptedException {
        System.out.println("11111：" + LocalDateTime.now().toString());
        Thread.sleep(2 * 60 * 1000);
    }

    @Scheduled(cron = "0 57 15 * * ?")
    public void test1() {
        System.out.println("222：" + LocalDateTime.now().toString());
    }
}

输出结果为：

按照理想情况下，我配置的定时任务test和test1的执行时间应该都是准时的。但是实际上执行时间，因为在test这个定时任务中进行了延迟睡眠2min，而test1的实际执行时间是在test最终执行完成后，才进行执行的。

4、解决方案

既然，默认的Scheduled的线程池中线程的数量为1，那么我们不妨将其增大，让更多的线程来处理定时任务即可。而Spring的Scheduled提供了对线程池的处理扩展。
回到上面说到的设置taskScheduled的地方，即finishRegistration()方法出，在这个方法中，有个判断逻辑即获取有没有或者实现SchedulingConfigurer的bean。如果有的话可以在SchedulingConfigurer中对register的属性进行设置，而taskScheduled就是register的一个属性。而SchedulingConfigurer中就一个方法。而且会在finishRegistration()中执行SchedulingConfigurer的configureTasks(ScheduledTaskRegistrar taskRegistrar)方法。

private void finishRegistration() {
    if (this.scheduler != null) {
        this.registrar.setScheduler(this.scheduler);
    }

    if (this.beanFactory instanceof ListableBeanFactory) {
        Map<String, SchedulingConfigurer> beans =
            ((ListableBeanFactory) this.beanFactory).getBeansOfType(SchedulingConfigurer.class);
        List<SchedulingConfigurer> configurers = new ArrayList<>(beans.values());
        AnnotationAwareOrderComparator.sort(configurers);
        for (SchedulingConfigurer configurer : configurers) {
            configurer.configureTasks(this.registrar);
        }
    }
    //......省略
    this.registrar.afterPropertiesSet();
}
@FunctionalInterface
public interface SchedulingConfigurer {

	/**
	 * Callback allowing a {@link org.springframework.scheduling.TaskScheduler
	 * TaskScheduler} and specific {@link org.springframework.scheduling.config.Task Task}
	 * instances to be registered against the given the {@link ScheduledTaskRegistrar}.
	 * @param taskRegistrar the registrar to be configured.
	 */
	void configureTasks(ScheduledTaskRegistrar taskRegistrar);

}

下面是我加了配置的一个demo。在这个demo中，我将线程池的核心线程数设置为10。

@Configuration
public class TestConfig implements SchedulingConfigurer {
    @Override
    public void configureTasks(ScheduledTaskRegistrar taskRegistrar) {
        taskRegistrar.setScheduler(Executors.newScheduledThreadPool(10));
    }
}

加完配置之后的执行结果：

@Configuration
public class TaskDemo {

    @Scheduled(cron = "0 03 16 * * ?")
    public void test() throws InterruptedException {
        System.out.println("11111：" + LocalDateTime.now().toString());
        Thread.sleep(2 * 60 * 1000);
    }

    @Scheduled(cron = "0 04 16 * * ?")
    public void test1() {
        System.out.println("222：" + LocalDateTime.now().toString());
    }
}