CronTrigger is not triggered at correct time [SPR-7004]

[spring-projects-issues]

adi ofry opened SPR-7004 and commented

When running CronTrigger on short interval I get the task triggered sooner then requested and also get duplicates.

public void initScheduler() {
System.out.println("Got initScheduler");
taskExecutor = new ThreadPoolTaskScheduler();
taskExecutor.initialize();

taskExecutor.schedule(new Runnable() {
          @Override
     public void run() {
                                                                                                                                                                  System.out.println(new Date());				
     }
},new CronTrigger("0/5 * * * * ?"));

}

The output is:
Got initScheduler
Thu Mar 18 17:08:19 IST 2010
Thu Mar 18 17:08:24 IST 2010
Thu Mar 18 17:08:24 IST 2010
Thu Mar 18 17:08:25 IST 2010
Thu Mar 18 17:08:29 IST 2010
Thu Mar 18 17:08:30 IST 2010

---

Affects: 3.0.1

Attachments:

• spr-7004.zip (7.98 kB)

Issue Links:

• Spring TaskScheduler not accurate [SPR-6981] #11646 Spring TaskScheduler not accurate ("is duplicated by")
• Scheduled tasks seem to run twice [SPR-6859] #11525 Scheduled tasks seem to run twice

Referenced from: commits dea5918

[spring-projects-issues]

Juergen Hoeller commented

I can't reproduce this, unfortunately: Even on Windows XP and JDK 1.6.0, CronTrigger fires exactly every 5 minutes for me. Are there any special characteristics of your environment which might influence the triggering here?

Juergen

[spring-projects-issues]

adi ofry commented

My colleague reproduced it on windows machine. It doesn't happen on our Linux server.
It doesn't happen in every one, and notice it's 5 sec not minutes.
I also tested your calculation for next scheduling time which works fine, although scheduling itself is wrong. maybe its a JDK bug?

[spring-projects-issues]

Gabriel Forro commented

Recently I have played with the TaskScheduler and I have met this reported bug in the CronTrigger also. Task executions are duplicated (even triplicated) in a non deterministic way. The following rules can be applied:

• The problem is tied to short scheduled periods (5 seconds for example)
• The problem is present, if the task is very short (in my example the scheduled task just printed a message to the console). A 'Thread.sleep(3000)' call in the scheduled task prevents the task execution duplications.

Comments to different environments, which I have tried:

• The problem does not occur in Linux. I have tried Red Hat Enterprise with Kernel 2.6.9-78.0.8.EL with Java 1.5.0_16
• The problem occurs in Windows XP SP3. I have tried the following Java versions: 1.5.0_12-b04, 16.2-b04 (JDK 6 update 19). There are more task duplications in JDK 6.

I have attached a simple project (spr-7004.zip), which demonstrates the problem.

[spring-projects-issues]

Gabriel Forro commented

Simple project which demonstrates spr-7004

[spring-projects-issues]

Christophe Roudet commented

It happens when the task last less than one second, then you can have TriggerContext.lastActualExecutionTime and TriggerContext.lastActualExecutionTime equals seconds wise.
So I think, in CronTrigger.nextExecutionTime() you should add 1 second to the new Date if this date is equals to the TriggerContext.lastActualExecutionTime.

public Date nextExecutionTime(TriggerContext triggerContext) {
  Date date = triggerContext.lastCompletionTime();
  if (date == null) {
    date = new Date();
  } else if ((triggerContext.lastActualExecutionTime() != null) &&
   (triggerContext.lastActualExecutionTime().getTime()/1000 == date.getTime()/1000)) {
    date = new Date(date.getTime()+1000);
  }
  return this.sequenceGenerator.next(date);
}

[spring-projects-issues]

Juergen Hoeller commented

Hmm, CronSequenceGenerator increases the incoming date to the next full second already:

calendar.add(Calendar.SECOND, 1);
calendar.set(Calendar.MILLISECOND, 0);

This should prevent double-fires for the same second as-is, shouldn't it.
Are we having a timezone problem here, or some other reason why Calendar would misbehave?

Juergen

[spring-projects-issues]

Christophe Roudet commented

You are right for the adjustment to the next second.

It looks like the job can be fired a few milliseconds before its scheduled time, so it can also ends before its scheduled time.
I think it's a precision problem on windows.
Making sure that lastCompletionTime is greater or equals to scheduledExecutionTime in CronTrigger.nextExecutionTime() may solve the problem.

[spring-projects-issues]

Juergen Hoeller commented

Good catch! lastCompletionTime being before lastScheduledExecutionTime might well be the problem here, and certainly explains the observations above. I've also been able to reproduce the effect by artifically running tasks too early.

As a consequence, CronTrigger defensively protects itself against accidental re-fires if the previous task ran too early now. This will be available in tomorrow's 3.0.3 snapshot; feel free to give it an early try...

Juergen