SpringBoot：為什麼我的定時任務不執行？

在SpringBoot中可以通過@Scheduled 註解來定義一個定時任務, 但是有時候你可能會發現有的定時任務到時間了卻沒有執行，但是又不是每次都不執行，這是怎麼回事？

下面這段代碼定義了一個每隔十秒鐘執行一次的定時任務:

<code>@Component
public class ScheduledTaskDemo {
    private static final Logger logger = LoggerFactory.getLogger(ScheduledTaskDemo.class);

    @Scheduled(cron = "0/10 * * * * *")
    public void execute() {
        logger.info("Scheduled task is running... ...");
    }
}/<code>

此時啟動SpringBoot應用, 可以在控制檯看到這個定時任務每隔10秒鐘打印一條log

2017-12-21 22:20:20.832 INFO 7424 --- [ main] s.b.c.e.t.TomcatEmbeddedServletContainer : Tomcat started on port(s): 8000 (http) 2017-12-21 22:20:20.859 INFO 7424 --- [ main] com.example.demo.DemoApplication : Started DemoApplication in 12.134 seconds (JVM running for 14.156) 2017-12-21 22:20:30.002 INFO 7424 --- [pool-1-thread-1] c.e.demo.scheduled.ScheduledTaskDemo : Scheduled task is running... ... 2017-12-21 22:20:40.001 INFO 7424 --- [pool-1-thread-1] c.e.demo.scheduled.ScheduledTaskDemo : Scheduled task is running... ... 2017-12-21 22:20:50.002 INFO 7424 --- [pool-1-thread-1] c.e.demo.scheduled.ScheduledTaskDemo : Scheduled task is running... ...

但是, 一切還沒結束.

如果沒有相關log顯示, 檢查是否在入口類或者Configuration類上添加了@EnableScheduling註解

在上面的相關代碼中, 我們使用cron表達式來指定定時任務的執行時間點, 即從0秒開始, 每隔10秒鐘執行一次, 現在我們再加一個定時任務:

<code>@Component
public class SecondScheduledTaskDemo {
    private static final Logger logger = LoggerFactory.getLogger(ScheduledTaskDemo.class);

    @Scheduled(cron = "0/10 * * * * *")
    public void second() {
        logger.info("Second scheduled task is starting... ...");
        logger.info("Second scheduled task is ending... ...");
    }

}/<code>

現在再啟動SpringBoot應用, 再看log:

2017-12-21 23:12:20.007 INFO 13208 --- [pool-1-thread-1] c.e.demo.scheduled.ScheduledTaskDemo : First scheduled task is starting... ... 2017-12-21 23:12:35.013 INFO 13208 --- [pool-1-thread-1] c.e.demo.scheduled.ScheduledTaskDemo : First scheduled task is ending... ... 2017-12-21 23:12:35.016 INFO 13208 --- [pool-1-thread-1] c.e.demo.scheduled.SecondScheduledTaskDemo : Second scheduled task is starting... ... 2017-12-21 23:12:35.016 INFO 13208 --- [pool-1-thread-1] c.e.demo.scheduled.SecondScheduledTaskDemo : Second scheduled task is ending... ... 2017-12-21 23:12:40.000 INFO 13208 --- [pool-1-thread-1] c.e.demo.scheduled.ScheduledTaskDemo : First scheduled task is starting... ... 2017-12-21 23:12:55.001 INFO 13208 --- [pool-1-thread-1] c.e.demo.scheduled.ScheduledTaskDemo : First scheduled task is ending... ... 2017-12-21 23:12:55.002 INFO 13208 --- [pool-1-thread-1] c.e.demo.scheduled.SecondScheduledTaskDemo : Second scheduled task is starting... ... 2017-12-21 23:12:55.002 INFO 13208 --- [pool-1-thread-1] c.e.demo.scheduled.SecondScheduledTaskDemo : Second scheduled task is ending... ...

注意log中定時任務執行的時間點, 第二個定時任務原本應該每隔10秒鐘執行一次, 但是從23:12:20到23:13:55, 本該執行4次, 確只執行了2次.

難道是cron表達式不對?

No.

為了找到原因, 我們從@Scheduled註解的源碼開始找:

<code> *
 * 
Processing of {@code @Scheduled} annotations is performed by
 * registering a {@link ScheduledAnnotationBeanPostProcessor}. This can be
 * done manually or, more conveniently, through the {@code <annotation-driven>}
 * element or @{@link EnableScheduling} annotation.
 *
/<code>

劃重點, 每一個有@Scheduled註解的方法都會被註冊為一個ScheduledAnnotationBeanPostProcessor, 再接著往下看ScheduledAnnotationBeanPostProcessor:

<code>\t/**
\t * Set the {@link org.springframework.scheduling.TaskScheduler} that will invoke
\t * the scheduled methods, or a {@link java.util.concurrent.ScheduledExecutorService}
\t * to be wrapped as a TaskScheduler.
\t * 
If not specified, default scheduler resolution will apply: searching for a
\t * unique {@link TaskScheduler} bean in the context, or for a {@link TaskScheduler}
\t * bean named "taskScheduler" otherwise; the same lookup will also be performed for
\t * a {@link ScheduledExecutorService} bean. If neither of the two is resolvable,
\t * a local single-threaded default scheduler will be created within the registrar.
\t * @see #DEFAULT_TASK_SCHEDULER_BEAN_NAME
\t */
\tpublic void setScheduler(Object scheduler) {
\t\tthis.scheduler = scheduler;
\t}
/<code>

重點來了, 注意這句話:

If neither of the two is resolvable, a local single-threaded default scheduler will be created within the registrar.

這句話意味著, 如果我們不主動配置我們需要的TaskScheduler, SpringBoot會默認使用一個單線程的scheduler來處理我們用@Scheduled註解實現的定時任務, 到此我們剛才的問題就可以理解了:

23:12:20, 第一個定時任務在線程pool-1-thread-1開始執行, 由於我們沒有配置scheduler, 目前這個線程池pool-1裡只有一個線程, 在打印了starting日誌之後, 這個線程開始sleep;第二個定時任務也準備執行, 但是線程池已經沒有多餘線程了, 只能等待.

23:12:30, 第一個定時任務還在sleep, 第二個定時任務還在等待.

23:12:35, 第一個定時任務sleep結束, 打印ending日誌並結束, 此時線程池空閒, 第二個定時任務從等待狀態直接開始執行, 執行結束之後, 線程池空閒.

23:12:40, 線程池空閒, 第一個定時任務執行, 打印starting日誌, 開始sleep.

注意, 這裡也有可能執行第二個定時任務, 看CPU了.

... ...

搞清楚這個流程之後, 解決這個問題就很簡單了.

根據剛才註釋的描述, 我們只需要提供一個滿足我們需要的TaskScheduler並註冊到context中就可以了.

<code>@Configuration
public class ScheduledTaskConfiguration implements SchedulingConfigurer {

    /**
     * Callback allowing a {@link TaskScheduler
     * TaskScheduler} and specific {@link Task Task}
     * instances to be registered against the given the {@link ScheduledTaskRegistrar}
     *
     * @param taskRegistrar the registrar to be configured.
     */
    @Override
    public void configureTasks(ScheduledTaskRegistrar taskRegistrar) {
        final ThreadPoolTaskScheduler taskScheduler = new ThreadPoolTaskScheduler();
        taskScheduler.setPoolSize(2);
        taskScheduler.initialize();
        taskRegistrar.setTaskScheduler(taskScheduler);
    }
}/<code>

上面的代碼提供了一個線程池大小為2的taskScheduler, 現在再啟動下SpringBoot看看效果.

2017-12-21 23:28:30.001 INFO 7972 --- [TaskScheduler-1] c.e.demo.scheduled.ScheduledTaskDemo : Second scheduled task is starting... ... 2017-12-21 23:28:30.001 INFO 7972 --- [TaskScheduler-2] c.e.demo.scheduled.ScheduledTaskDemo : First scheduled task is starting... ... 2017-12-21 23:28:30.002 INFO 7972 --- [TaskScheduler-1] c.e.demo.scheduled.ScheduledTaskDemo : Second scheduled task is ending... ... 2017-12-21 23:28:40.001 INFO 7972 --- [TaskScheduler-1] c.e.demo.scheduled.ScheduledTaskDemo : Second scheduled task is starting... ... 2017-12-21 23:28:40.001 INFO 7972 --- [TaskScheduler-1] c.e.demo.scheduled.ScheduledTaskDemo : Second scheduled task is ending... ... 2017-12-21 23:28:45.002 INFO 7972 --- [TaskScheduler-2] c.e.demo.scheduled.ScheduledTaskDemo : First scheduled task is ending... ...

可以看到, 當線程池裡有兩個線程的時候, 這兩個定時任務各自按照預定的時間進行觸發, 互不影響了.

作者：jwenjian
原文鏈接：https://juejin.im/post/5e687620e51d4526ed66c5b0

閱讀更多 追逐仰望星空 的文章

關鍵字: 源碼 註解 Java虛擬機