Spring定时任务的一个坑

最近遇到一个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

日志可以看出来,定时任务使用了10个线程

最佳实践

  • 定时任务不能执行耗时任务,阻塞其他任务的执行
  • 可以使用自定义线程池

参考

©著作权归作者所有,转载或内容合作请联系作者
  • 序言:七十年代末,一起剥皮案震惊了整个滨河市,随后出现的几起案子,更是在滨河造成了极大的恐慌,老刑警刘岩,带你破解...
    沈念sama阅读 212,222评论 6 493
  • 序言:滨河连续发生了三起死亡事件,死亡现场离奇诡异,居然都是意外死亡,警方通过查阅死者的电脑和手机,发现死者居然都...
    沈念sama阅读 90,455评论 3 385
  • 文/潘晓璐 我一进店门,熙熙楼的掌柜王于贵愁眉苦脸地迎上来,“玉大人,你说我怎么就摊上这事。” “怎么了?”我有些...
    开封第一讲书人阅读 157,720评论 0 348
  • 文/不坏的土叔 我叫张陵,是天一观的道长。 经常有香客问我,道长,这世上最难降的妖魔是什么? 我笑而不...
    开封第一讲书人阅读 56,568评论 1 284
  • 正文 为了忘掉前任,我火速办了婚礼,结果婚礼上,老公的妹妹穿的比我还像新娘。我一直安慰自己,他们只是感情好,可当我...
    茶点故事阅读 65,696评论 6 386
  • 文/花漫 我一把揭开白布。 她就那样静静地躺着,像睡着了一般。 火红的嫁衣衬着肌肤如雪。 梳的纹丝不乱的头发上,一...
    开封第一讲书人阅读 49,879评论 1 290
  • 那天,我揣着相机与录音,去河边找鬼。 笑死,一个胖子当着我的面吹牛,可吹牛的内容都是我干的。 我是一名探鬼主播,决...
    沈念sama阅读 39,028评论 3 409
  • 文/苍兰香墨 我猛地睁开眼,长吁一口气:“原来是场噩梦啊……” “哼!你这毒妇竟也来了?” 一声冷哼从身侧响起,我...
    开封第一讲书人阅读 37,773评论 0 268
  • 序言:老挝万荣一对情侣失踪,失踪者是张志新(化名)和其女友刘颖,没想到半个月后,有当地人在树林里发现了一具尸体,经...
    沈念sama阅读 44,220评论 1 303
  • 正文 独居荒郊野岭守林人离奇死亡,尸身上长有42处带血的脓包…… 初始之章·张勋 以下内容为张勋视角 年9月15日...
    茶点故事阅读 36,550评论 2 327
  • 正文 我和宋清朗相恋三年,在试婚纱的时候发现自己被绿了。 大学时的朋友给我发了我未婚夫和他白月光在一起吃饭的照片。...
    茶点故事阅读 38,697评论 1 341
  • 序言:一个原本活蹦乱跳的男人离奇死亡,死状恐怖,灵堂内的尸体忽然破棺而出,到底是诈尸还是另有隐情,我是刑警宁泽,带...
    沈念sama阅读 34,360评论 4 332
  • 正文 年R本政府宣布,位于F岛的核电站,受9级特大地震影响,放射性物质发生泄漏。R本人自食恶果不足惜,却给世界环境...
    茶点故事阅读 40,002评论 3 315
  • 文/蒙蒙 一、第九天 我趴在偏房一处隐蔽的房顶上张望。 院中可真热闹,春花似锦、人声如沸。这庄子的主人今日做“春日...
    开封第一讲书人阅读 30,782评论 0 21
  • 文/苍兰香墨 我抬头看了看天上的太阳。三九已至,却和暖如春,着一层夹袄步出监牢的瞬间,已是汗流浃背。 一阵脚步声响...
    开封第一讲书人阅读 32,010评论 1 266
  • 我被黑心中介骗来泰国打工, 没想到刚下飞机就差点儿被人妖公主榨干…… 1. 我叫王不留,地道东北人。 一个月前我还...
    沈念sama阅读 46,433评论 2 360
  • 正文 我出身青楼,却偏偏与公主长得像,于是被迫代替她去往敌国和亲。 传闻我的和亲对象是个残疾皇子,可洞房花烛夜当晚...
    茶点故事阅读 43,587评论 2 350

推荐阅读更多精彩内容