Spring定时任务的一个坑

十毛

发布于 2019-03-27 14:58:14

1K0

发布于 2019-03-27 14:58:14

文章被收录于专栏：用户1337634的专栏用户1337634的专栏

最近遇到一个Spring定时任务没有及时启动，经常过30分钟以上才执行。最后定位原因，是因为所有的Spring定时任务共用同一个线程，如果有一个线程耗时太长，会导致后续定时任务阻塞。

好奇怪

排查问题，发现定时器设置正确（每分钟执行一次），而且在任务的第一行就输出日志。

@Scheduled(fixedRate = 60 * 1000)

[2019-01-10 18:13:56.913][pool-6-thread-1][INFO][Crontab:91][][]: start to run task crontab
[2019-01-10 18:13:56.938][pool-6-thread-1][INFO][Crontab:91][][]: start to run task crontab
[2019-01-10 18:38:49.103][pool-6-thread-1][INFO][Crontab:91][][]: start to run task crontab
[2019-01-10 18:38:49.119][pool-6-thread-1][INFO][Crontab:91][][]: start to run task crontab
[2019-01-10 19:02:40.755][pool-6-thread-1][INFO][Crontab:91][][]: start to run task crontab
[2019-01-10 19:02:40.770][pool-6-thread-1][INFO][Crontab:91][][]: start to run task crontab
[2019-01-10 19:29:02.527][pool-6-thread-1][INFO][Crontab:91][][]: start to run task crontab
[2019-01-10 19:29:02.551][pool-6-thread-1][INFO][Crontab:91][][]: start to run task crontab
[2019-01-10 19:56:53.597][pool-6-thread-1][INFO][Crontab:91][][]: start to run task crontab
[2019-01-10 19:56:53.615][pool-6-thread-1][INFO][Crontab:91][][]: start to run task crontab
[2019-01-10 20:24:05.241][pool-6-thread-1][INFO][Crontab:91][][]: start to run task crontab
[2019-01-10 20:24:05.262][pool-6-thread-1][INFO][Crontab:91][][]: start to run task crontab
[2019-01-10 20:39:22.504][pool-6-thread-1][INFO][Crontab:91][][]: start to run task crontab
[2019-01-10 21:22:02.099][pool-6-thread-1][INFO][Crontab:91][][]: start to run task crontab
[2019-01-10 21:22:02.116][pool-6-thread-1][INFO][Crontab:91][][]: start to run task crontab
[2019-01-10 21:48:19.265][pool-6-thread-1][INFO][Crontab:91][][]: start to run task crontab
[2019-01-10 21:48:19.277][pool-6-thread-1][INFO][Crontab:91][][]: start to run task crontab

日志显示，一般过了20~30分钟，会连续执行两次任务。 看起来是Spring定时任务出错了，感觉有点崩溃，不能相信Spring会出现这么简单的错误。但是事实又这么明显

再思考

从日志来看，执行定时任务的线程名是 pool-6-thread-1，属于某一个线程池。那么可能是线程池的线程数不够，那么找到这个线程之前在做的事情就知道为什么这个线程一直没来执行定时任务

执行命令：

grep pool-6-thread-1 all.log

果然找到问题，原来pool-6-thread-1线程在执行另外一个耗时很长的任务

问题定位

Spring定时任务默认使用的SingleThreadScheduledExecutor，所有任务共用一个线程，所以会互相等待。

protected void scheduleTasks() {
    if (this.taskScheduler == null) {
        //使用的是SingleThreadScheduledExecutor（只有一个线程）
        this.localExecutor = Executors.newSingleThreadScheduledExecutor();
        this.taskScheduler = new ConcurrentTaskScheduler(this.localExecutor);
    }
    if (this.triggerTasks != null) {
        for (TriggerTask task : this.triggerTasks) {
            addScheduledTask(scheduleTriggerTask(task));
        }
    }
    if (this.cronTasks != null) {
        for (CronTask task : this.cronTasks) {
            addScheduledTask(scheduleCronTask(task));
        }
    }
    if (this.fixedRateTasks != null) {
        for (IntervalTask task : this.fixedRateTasks) {
            addScheduledTask(scheduleFixedRateTask(task));
        }
    }
    if (this.fixedDelayTasks != null) {
        for (IntervalTask task : this.fixedDelayTasks) {
            addScheduledTask(scheduleFixedDelayTask(task));
        }
    }
}

解决办法

最简单的办法就是减少定时任务耗时，但是本文还介绍另外一种 自定义定时任务线程池，实现方式如下：

增加两个注解：@EnableAsync和@Async

@EnableScheduling
@EnableAsync
public class Crontab {

    @Scheduled(fixedRate = 60)
    @Async
    public void doTask() {
        log.info("start to run task crontab");
        try {
            Thread.sleep(10000);
        } catch (InterruptedException e) {
            e.printStackTrace();
        }
    }
}

配置线程池

<task:annotation-driven scheduler="crontab-scheduler"/>
<task:scheduler id="crontab-scheduler" pool-size="10"/>

运行结果

[2019-01-10 22:31:24.120][crontab-scheduler-3][INFO][Crontab:91][][]: start to run task crontab
[2019-01-10 22:31:24.180][crontab-scheduler-2][INFO][Crontab:91][][]: start to run task crontab
[2019-01-10 22:31:24.240][crontab-scheduler-4][INFO][Crontab:91][][]: start to run task crontab
[2019-01-10 22:31:24.300][crontab-scheduler-7][INFO][Crontab:91][][]: start to run task crontab
[2019-01-10 22:31:24.360][crontab-scheduler-6][INFO][Crontab:91][][]: start to run task crontab
[2019-01-10 22:31:24.420][crontab-scheduler-5][INFO][Crontab:91][][]: start to run task crontab
[2019-01-10 22:31:24.480][crontab-scheduler-9][INFO][Crontab:91][][]: start to run task crontab
[2019-01-10 22:31:24.540][crontab-scheduler-10][INFO][Crontab:91][][]: start to run task crontab
[2019-01-10 22:31:24.600][crontab-scheduler-8][INFO][Crontab:91][][]: start to run task crontab
[2019-01-10 22:31:34.100][crontab-scheduler-1][INFO][Crontab:91][][]: start to run task crontab