Spring 使用 fixedDelay 时调度程序冲突

Question

正如官方文档中所写

.. fixed delay, meaning that the period will be measured from the completion time of each preceding invocation

但是我遇到了麻烦。我的代码带有 fixedDelayString

@Scheduled(fixedDelayString = "${schedule.time:2000}")
public void tasksScheduler() {
    LOG.trace("starts");
    try {
        Thread.sleep(new Random().nextInt(5000));
    } catch (InterruptedException e) {
        e.printStackTrace();
    }
    LOG.trace("completed");
}

它在我的本地机器上有正确的顺序

2015-09-22 10:16:11,098 TRACE r.u.s.i.AutoRegistrationAccountScheduler [pool-3-thread-1] starts
2015-09-22 10:16:12,707 TRACE r.u.s.i.AutoRegistrationAccountScheduler [pool-3-thread-1] completed
2015-09-22 10:16:15,708 TRACE r.u.s.i.AutoRegistrationAccountScheduler [pool-3-thread-1] starts
2015-09-22 10:16:18,768 TRACE r.u.s.i.AutoRegistrationAccountScheduler [pool-3-thread-1] completed
2015-09-22 10:16:21,769 TRACE r.u.s.i.AutoRegistrationAccountScheduler [pool-3-thread-1] starts
2015-09-22 10:16:23,882 TRACE r.u.s.i.AutoRegistrationAccountScheduler [pool-3-thread-1] completed
2015-09-22 10:16:26,882 TRACE r.u.s.i.AutoRegistrationAccountScheduler [pool-3-thread-1] starts
2015-09-22 10:16:31,073 TRACE r.u.s.i.AutoRegistrationAccountScheduler [pool-3-thread-1] completed
2015-09-22 10:16:34,074 TRACE r.u.s.i.AutoRegistrationAccountScheduler [pool-3-thread-1] starts

但是我的服务器发生了冲突。服务器日志如下

2015-09-22 05:26:21,315 TRACE r.u.s.i.AutoRegistrationAccountScheduler [pool-3-thread-1] starts
2015-09-22 05:26:25,593 TRACE r.u.s.i.AutoRegistrationAccountScheduler [pool-3-thread-1] completed
2015-09-22 05:26:28,594 TRACE r.u.s.i.AutoRegistrationAccountScheduler [pool-3-thread-1] starts
2015-09-22 05:26:32,169 TRACE r.u.s.i.AutoRegistrationAccountScheduler [pool-3-thread-1] completed
2015-09-22 05:26:35,170 TRACE r.u.s.i.AutoRegistrationAccountScheduler [pool-3-thread-1] starts
2015-09-22 05:26:38,608 TRACE r.u.s.i.AutoRegistrationAccountScheduler [pool-3-thread-1] completed
2015-09-22 05:26:41,608 TRACE r.u.s.i.AutoRegistrationAccountScheduler [pool-3-thread-1] starts
2015-09-22 05:26:44,341 TRACE r.u.s.i.AutoRegistrationAccountScheduler [pool-3-thread-1] completed
2015-09-22 05:26:47,342 TRACE r.u.s.i.AutoRegistrationAccountScheduler [pool-3-thread-1] starts
2015-09-22 05:26:49,808 TRACE r.u.s.i.AutoRegistrationAccountScheduler [pool-6-thread-1] starts
2015-09-22 05:26:50,400 TRACE r.u.s.i.AutoRegistrationAccountScheduler [pool-6-thread-1] completed
2015-09-22 05:26:50,734 TRACE r.u.s.i.AutoRegistrationAccountScheduler [pool-3-thread-1] completed
2015-09-22 05:26:53,401 TRACE r.u.s.i.AutoRegistrationAccountScheduler [pool-6-thread-1] starts
2015-09-22 05:26:53,735 TRACE r.u.s.i.AutoRegistrationAccountScheduler [pool-3-thread-1] starts
2015-09-22 05:26:54,074 TRACE r.u.s.i.AutoRegistrationAccountScheduler [pool-6-thread-1] completed
2015-09-22 05:26:56,267 TRACE r.u.s.i.AutoRegistrationAccountScheduler [pool-3-thread-1] completed
2015-09-22 05:26:57,075 TRACE r.u.s.i.AutoRegistrationAccountScheduler [pool-6-thread-1] starts
2015-09-22 05:26:58,604 TRACE r.u.s.i.AutoRegistrationAccountScheduler [pool-6-thread-1] completed
2015-09-22 05:26:59,268 TRACE r.u.s.i.AutoRegistrationAccountScheduler [pool-3-thread-1] starts
2015-09-22 05:27:01,605 TRACE r.u.s.i.AutoRegistrationAccountScheduler [pool-6-thread-1] starts
2015-09-22 05:27:03,176 TRACE r.u.s.i.AutoRegistrationAccountScheduler [pool-6-thread-1] completed
2015-09-22 05:27:03,375 TRACE r.u.s.i.AutoRegistrationAccountScheduler [pool-3-thread-1] completed
2015-09-22 05:27:06,177 TRACE r.u.s.i.AutoRegistrationAccountScheduler [pool-6-thread-1] starts
2015-09-22 05:27:06,376 TRACE r.u.s.i.AutoRegistrationAccountScheduler [pool-3-thread-1] starts
2015-09-22 05:27:07,253 TRACE r.u.s.i.AutoRegistrationAccountScheduler [pool-6-thread-1] completed
2015-09-22 05:27:10,254 TRACE r.u.s.i.AutoRegistrationAccountScheduler [pool-6-thread-1] starts
2015-09-22 05:27:10,691 TRACE r.u.s.i.AutoRegistrationAccountScheduler [pool-3-thread-1] completed
2015-09-22 05:27:12,737 TRACE r.u.s.i.AutoRegistrationAccountScheduler [pool-6-thread-1] completed
2015-09-22 05:27:13,692 TRACE r.u.s.i.AutoRegistrationAccountScheduler [pool-3-thread-1] starts
2015-09-22 05:27:15,450 TRACE r.u.s.i.AutoRegistrationAccountScheduler [pool-3-thread-1] completed
2015-09-22 05:27:15,738 TRACE r.u.s.i.AutoRegistrationAccountScheduler [pool-6-thread-1] starts
2015-09-22 05:27:16,940 TRACE r.u.s.i.AutoRegistrationAccountScheduler [pool-6-thread-1] completed
2015-09-22 05:27:18,450 TRACE r.u.s.i.AutoRegistrationAccountScheduler [pool-3-thread-1] starts
2015-09-22 05:27:19,941 TRACE r.u.s.i.AutoRegistrationAccountScheduler [pool-6-thread-1] starts
2015-09-22 05:27:20,727 TRACE r.u.s.i.AutoRegistrationAccountScheduler [pool-3-thread-1] completed
2015-09-22 05:27:22,741 TRACE r.u.s.i.AutoRegistrationAccountScheduler [pool-6-thread-1] completed

我尝试将自定义调度程序定义为

<task:annotation-driven scheduler="myScheduler"/>
<task:scheduler id="myScheduler" pool-size="1"/>

但这对我没有帮助，碰撞仍然存在

2015-09-22 10:50:29, [myScheduler-1] starts
2015-09-22 10:50:32, [myScheduler-1] completed
2015-09-22 10:50:34, [myScheduler-1] starts
2015-09-22 10:50:36, [myScheduler-1] completed
2015-09-22 10:50:38, [myScheduler-1] starts
2015-09-22 10:50:39, [myScheduler-1] completed
2015-09-22 10:50:41, [myScheduler-1] starts
2015-09-22 10:50:42, [myScheduler-1] starts
2015-09-22 10:50:43, [myScheduler-1] completed
2015-09-22 10:50:45, [myScheduler-1] starts
2015-09-22 10:50:47, [myScheduler-1] completed
2015-09-22 10:50:47, [myScheduler-1] completed
2015-09-22 10:50:49, [myScheduler-1] starts
2015-09-22 10:50:49, [myScheduler-1] starts
2015-09-22 10:50:49, [myScheduler-1] completed
2015-09-22 10:50:51, [myScheduler-1] starts
2015-09-22 10:50:51, [myScheduler-1] completed
2015-09-22 10:50:53, [myScheduler-1] starts
2015-09-22 10:50:54, [myScheduler-1] completed
2015-09-22 10:50:56, [myScheduler-1] starts
2015-09-22 10:50:57, [myScheduler-1] completed
2015-09-22 10:50:59, [myScheduler-1] starts
2015-09-22 10:51:00, [myScheduler-1] completed
2015-09-22 10:51:02, [myScheduler-1] starts
2015-09-22 10:51:03, [myScheduler-1] completed
2015-09-22 10:51:04, [myScheduler-1] completed
2015-09-22 10:51:05, [myScheduler-1] starts
2015-09-22 10:51:06, [myScheduler-1] starts
2015-09-22 10:51:10, [myScheduler-1] completed
2015-09-22 10:51:10, [myScheduler-1] completed
2015-09-22 10:51:12, [myScheduler-1] starts
2015-09-22 10:51:12, [myScheduler-1] starts
2015-09-22 10:51:16, [myScheduler-1] completed
2015-09-22 10:51:17, [myScheduler-1] completed
2015-09-22 10:51:18, [myScheduler-1] starts
2015-09-22 10:51:19, [myScheduler-1] starts
2015-09-22 10:51:19, [myScheduler-1] completed
2015-09-22 10:51:19, [myScheduler-1] completed
2015-09-22 10:51:21, [myScheduler-1] starts

为什么 fixedDelay 如此工作？如何确保不会发生碰撞？

Answer 1

这是由于应用程序上下文的两次初始化。当我将日志消息添加到我的 bean 的构造函数时，我发现了它。

public AutoRegistrationAccountScheduler() {
    LOG.trace("I'm initialized! Time = " + new Date() + ", this = " + this);
}

而且我的日志中也有两行

2015-09-23 03:38:07,917 INFO o.s.w.c.ContextLoader [localhost-startStop-1] Root WebApplicationContext: initialization started
....
2015-09-23 03:38:22,112 INFO o.s.w.c.ContextLoader [pool-3-thread-1] Root WebApplicationContext: initialization started

然后我决定比较 tomcat 配置（本地和生产），发现有不必要的行是我第二个 Web 应用程序初始化的原因

<Context path="/" docBase="ROOT">
    <WatchedResource>WEB-INF/web.xml</WatchedResource>
</Context>

删除此行后一切如我所料。

Spring 使用 fixedDelay 时调度程序冲突

Spring scheduler collision when using fixedDelay

java

spring

scheduled-tasks

spring-scheduled