[#QUARTZ-554] Trigger.getNextFireTime() returns date in the past

Quartz Scheduler

Trigger.getNextFireTime() returns date in the past

Created: 22/Jan/07 04:13 AM Updated: 21/Oct/07 03:17 PM

Component/s:

Triggers

Affects Version/s:

1.6

Fix Version/s:

1.6.1

File Attachments:

QUARTZ-554-2.patch (0.7 kb)
2.

QUARTZ-554.patch (0.7 kb)
3.

Quartz554Repro.java (1 kb)

Issue Links:

Related

This issue is related to:
	~~QUARTZ-543~~ updateAfterMisfire() not invoked by S...

Description

« Hide

Trigger.getNextFireTime() does not return the same result as Trigger.getFireTimeAfter(new Date()) when the startTime of the trigger is in the past. Consider the following program (just wrap it in a main class and it runs):

Properties props = new Properties();
props.put("org.quartz.scheduler.instanceName", "MyScheduler");
props.put("org.quartz.scheduler.instanceId", "1");
props.put("org.quartz.scheduler.rmi.export", "false");
props.put("org.quartz.scheduler.rmi.proxy", "false");
props.put("org.quartz.threadPool.class", "org.quartz.simpl.SimpleThreadPool");
props.put("org.quartz.threadPool.threadCount", "3");
props.put("org.quartz.jobStore.class", "org.quartz.simpl.RAMJobStore");
StdSchedulerFactory factory = new StdSchedulerFactory(props);

Scheduler scheduler = factory.getScheduler();
scheduler.start();
System.out.println("Scheduler has been started...");

Date now = new Date();
Calendar cal = Calendar.getInstance();
cal.setTime(now);
cal.set(Calendar.YEAR, 2004);
Date someTimeAgo = cal.getTime();

JobDetail jd = new JobDetail("jobname", "jobgroup", MyJob.class);
Trigger trig = new CronTrigger("triggername", "triggergroup", "jobname", "jobgroup", now, null, "0 00 21 ? * MON-FRI *");
trig.setMisfireInstruction(CronTrigger.MISFIRE_INSTRUCTION_DO_NOTHING);
scheduler.scheduleJob(jd, trig);

Date origNft = trig.getNextFireTime();

for (int i=0; i<10; i++) {
trig.setStartTime(someTimeAgo);
scheduler.rescheduleJob("triggername", "triggergroup", trig);
// trig.computeFirstFireTime(scheduler.getCalendar(trig.getCalendarName()));
System.out.println(origNft + " / " + trig.getNextFireTime() + " / " + trig.getFireTimeAfter(now));
}

scheduler.shutdown();
System.out.println("Scheduler has been stopped.");
}

public class MyJob implements Job {
public void execute(org.quartz.JobExecutionContext jobExecutionContext) throws org.quartz.JobExecutionException {
System.out.println("Job completed.");
}

The cron expression must be set to a time later in the day, so it will not occur during the test. I put 21 as an example (9 PM on the 24 hour clock). Ignore the loop and the Job class, they are not important here.

As you can see in the output, the first and third date are correct, whereas the second date is in the past. This is incorrect, as a "next fire time" can never be in the past.

BTW, the following may be a lead: if you comment out the job rescheduling and instead bring in the computeFirstFireTime line, which is commented out now, then the same error occurs.

Description

Trigger.getNextFireTime() does not return the same result as Trigger.getFireTimeAfter(new Date()) when the startTime of the trigger is in the past. Consider the following program (just wrap it in a main class and it runs): Properties props = new Properties(); props.put("org.quartz.scheduler.instanceName", "MyScheduler"); props.put("org.quartz.scheduler.instanceId", "1"); props.put("org.quartz.scheduler.rmi.export", "false"); props.put("org.quartz.scheduler.rmi.proxy", "false"); props.put("org.quartz.threadPool.class", "org.quartz.simpl.SimpleThreadPool"); props.put("org.quartz.threadPool.threadCount", "3"); props.put("org.quartz.jobStore.class", "org.quartz.simpl.RAMJobStore"); StdSchedulerFactory factory = new StdSchedulerFactory(props); Scheduler scheduler = factory.getScheduler(); scheduler.start(); System.out.println("Scheduler has been started..."); Date now = new Date(); Calendar cal = Calendar.getInstance(); cal.setTime(now); cal.set(Calendar.YEAR, 2004); Date someTimeAgo = cal.getTime(); JobDetail jd = new JobDetail("jobname", "jobgroup", MyJob.class); Trigger trig = new CronTrigger("triggername", "triggergroup", "jobname", "jobgroup", now, null, "0 00 21 ? * MON-FRI *"); trig.setMisfireInstruction(CronTrigger.MISFIRE_INSTRUCTION_DO_NOTHING); scheduler.scheduleJob(jd, trig); Date origNft = trig.getNextFireTime(); for (int i=0; i<10; i++) { trig.setStartTime(someTimeAgo); scheduler.rescheduleJob("triggername", "triggergroup", trig); // trig.computeFirstFireTime(scheduler.getCalendar(trig.getCalendarName())); System.out.println(origNft + " / " + trig.getNextFireTime() + " / " + trig.getFireTimeAfter(now)); } scheduler.shutdown(); System.out.println("Scheduler has been stopped."); } public class MyJob implements Job { public void execute(org.quartz.JobExecutionContext jobExecutionContext) throws org.quartz.JobExecutionException { System.out.println("Job completed."); } The cron expression must be set to a time later in the day, so it will not occur during the test. I put 21 as an example (9 PM on the 24 hour clock). Ignore the loop and the Job class, they are not important here. As you can see in the output, the first and third date are correct, whereas the second date is in the past. This is incorrect, as a "next fire time" can never be in the past. BTW, the following may be a lead: if you comment out the job rescheduling and instead bring in the computeFirstFireTime line, which is commented out now, then the same error occurs.

Show »

All

Comments

Change History

Sort Order:

[ Permlink | « Hide ]

Henri Yandell - [22/Jan/07 05:24 PM ]

I get the same result given Ulrich's code.

I deleted various unnecessary bits and moved to SimpleTrigger and the same bug/missing feature exists there. That file is attached.

Is the solution as simple as to change the getNextFireTime in SimpleTrigger and CronTrigger to:

public Date getNextFireTime() {
        while (nextFireTime.getTime() < System.currentTimeMillis() ) {
            nextFireTime = getFireTimeAfter( new Date() );
        }
        return nextFireTime;
    }

?

It does seem to fix the SimpleTrigger problem (and I suspect would for CronTrigger), but running the unit tests the following fails:

[junit] Testcase: testDifferentPriority took 0.006 sec
    [junit] Caused an ERROR
    [junit] Unable to store Job with name: 'JD' and group: 'DEFAULT', because one already exists with this identification.
    [junit] org.quartz.ObjectAlreadyExistsException: Unable to store Job with name: 'JD' and group: 'DEFAULT', because one already exists with this identification.
    [junit] at org.quartz.simpl.RAMJobStore.storeJob(RAMJobStore.java:222)

So obviously more going on than I grok currently.

[ Permlink | « Hide ]

Henri Yandell - [05/Feb/07 07:23 PM ]

Incidentally, this seems to also fix ~~QUARTZ-543~~.

Three tests seem to fail because of it. The first is easy to fix, the nextFireTime needs null protecting.

Then there's the second (which I commented on above) - it's because things are second based and I did a millisecond test. Adding a getSecond() test to the while statement does the trick there.

The third error is:

[junit] Testcase: testAcquireNextTrigger took 0.017 sec
    [junit] FAILED
    [junit] expected:<Trigger 'triggerGroup1.trigger2': triggerClass: 'org.quartz.SimpleTrigger isVolatile: false calendar: 'null' misfireInstruction: 0 nextFireTime: null> but was:<Trigger 'triggerGroup2.trigger1': triggerClass: 'org.quartz.SimpleTrigger isVolatile: false calendar: 'null' misfireInstruction: 0 nextFireTime: Mon Feb 05 17:15:53 PST 2007>
    [junit] junit.framework.AssertionFailedError: expected:<Trigger 'triggerGroup1.trigger2': triggerClass: 'org.quartz.SimpleTrigger isVolatile: false calendar: 'null' misfireInstruction: 0 nextFireTime: null> but was:<Trigger 'triggerGroup2.trigger1': triggerClass: 'org.quartz.SimpleTrigger isVolatile: false calendar: 'null' misfireInstruction: 0 nextFireTime: Mon Feb 05 17:15:53 PST 2007>
    [junit] at org.quartz.simpl.RAMJobStoreTest.testAcquireNextTrigger(RAMJobStoreTest.java:70)

Both the trigger being fired, and the nextFireTime are different. This test sets up a test with a start time in the past, so I'm suspicious that it may have been built to work with this bug without noticing.

[ Permlink | « Hide ]

Henri Yandell - [05/Feb/07 07:25 PM ]

Attaching fix for this issue - however it causes one of the unit tests to fail so may need more work, or the unit test may need adjusting.

[ Permlink | « Hide ]

Henri Yandell - [05/Feb/07 07:45 PM ]

Improved version (less object creation, cleaner code).

Looking at ~~QUARTZ-557~~, it might want the bit about getSeconds() to be replaced with misfireThreshold code.

[ Permlink | « Hide ]

James House - [17/Mar/07 12:14 AM ]

This one will warrant some thought. Although I follow what's being said, and the patch, I think there was a subtle reason for the behavior. (although it also obviously conflicts with some other expected behavior).

[ Permlink | « Hide ]

Henri Yandell - [30/Apr/07 04:41 PM ]

From James' email:

*****************************************************************************
The patch for ~~QUARTZ-554~~ fixes it to work the way the reporter expects
it to work, but it will break a number of things in the codebase, some
critical.

The method really does not mean "get the next time the trigger WILL
fire". It means "get the next fire time of the trigger". OK so that
sounds really silly, but the latter means get me the time that was
computed as the next fire time of the trigger when the trigger last
fired. OK, so that's still really ambiguous.

Consider this: A simple trigger A that repeats every 30 minutes
indefinitely. It fires at 10:00:00. nextFireTime is then computed as
10:30:00. If you retrieve trigger A at 10:25:00 and call
getNextFireTime, then 10:30:00 will be returned, as expected. Now
consider that the scheduler has only 2 threads in the threadpool, and
that when 10:30:00 arrives, there are already several (say 10) triggers
ready to fire. Trigger A is therefore not fired right at 10:30:00. It
may still not have fired at 10:36:00, depending on how long the jobs
run. If you retrieve trigger A at that time and call getNextFireTime()
it will still report 10:30:00. This is correct. 10:30:00 is still the
next time that the trigger was scheduled to fire. It is important that
the next fire time isn't automatically updated as the patch for
~~QUARTZ-554~~ proposes to do. This would fool with a lot of things. For
instance, the misfire handling will not be able to determine how many
firings the tirgger has missed (think of a trigger that fires every 10
seconds, and it's now a couple minutes late). This will goof up a few
of the misfire handling strategies. If you search the codebase for
usages of getNextFireTime, you'll see that there's a few other things it
will screw up.

I propose that the fix for ~~QUARTZ-554~~ is to clarify the JavaDoc on
getNextFireTime() - in particular, removing the words "will fire", and
replacing it with "is/was scheduled to fire". Also, recommend using
getFireTimeAfter(new Date()) if someone wants to know what the next time
the trigger is scheduled to fire after "now". Note though that that is
not sufficient, because the trigger could already be due to fire (even
if it's just a millisecond late, the answer will be a time in the
future, rather than the time a millisecond ago). If someone really
wants to know when the trigger is scheduled to be firing on or around
"now" I recommend using the TriggerUtils.computeFireTimesBetween(..)
method. Even still, the dates returned are the scheduled times. If
the scheduler is busy or down, then depending on the misfire strategy
selected for the trigger, the actual fire times the trigger has may be
very different. It may even only fire once in the window of time,
rather than 10 times, or whatever.
*****************************************************************************

So this issue is modified to being a documentation change.

[ Show » ]

Henri Yandell - [30/Apr/07 04:41 PM ] From James' email: ***************************************************************************** The patch for ~~QUARTZ-554~~ fixes it to work the way the reporter expects it to work, but it will break a number of things in the codebase, some critical. The method really does not mean "get the next time the trigger WILL fire". It means "get the next fire time of the trigger". OK so that sounds really silly, but the latter means get me the time that was computed as the next fire time of the trigger when the trigger last fired. OK, so that's still really ambiguous. Consider this: A simple trigger A that repeats every 30 minutes indefinitely. It fires at 10:00:00. nextFireTime is then computed as 10:30:00. If you retrieve trigger A at 10:25:00 and call getNextFireTime, then 10:30:00 will be returned, as expected. Now consider that the scheduler has only 2 threads in the threadpool, and that when 10:30:00 arrives, there are already several (say 10) triggers ready to fire. Trigger A is therefore not fired right at 10:30:00. It may still not have fired at 10:36:00, depending on how long the jobs run. If you retrieve trigger A at that time and call getNextFireTime() it will still report 10:30:00. This is correct. 10:30:00 is still the next time that the trigger was scheduled to fire. It is important that the next fire time isn't automatically updated as the patch for ~~QUARTZ-554~~ proposes to do. This would fool with a lot of things. For instance, the misfire handling will not be able to determine how many firings the tirgger has missed (think of a trigger that fires every 10 seconds, and it's now a couple minutes late). This will goof up a few of the misfire handling strategies. If you search the codebase for usages of getNextFireTime, you'll see that there's a few other things it will screw up. I propose that the fix for ~~QUARTZ-554~~ is to clarify the JavaDoc on getNextFireTime() - in particular, removing the words "will fire", and replacing it with "is/was scheduled to fire". Also, recommend using getFireTimeAfter(new Date()) if someone wants to know what the next time the trigger is scheduled to fire after "now". Note though that that is not sufficient, because the trigger could already be due to fire (even if it's just a millisecond late, the answer will be a time in the future, rather than the time a millisecond ago). If someone really wants to know when the trigger is scheduled to be firing on or around "now" I recommend using the TriggerUtils.computeFireTimesBetween(..) method. Even still, the dates returned are the scheduled times. If the scheduler is busy or down, then depending on the misfire strategy selected for the trigger, the actual fire times the trigger has may be very different. It may even only fire once in the window of time, rather than 10 times, or whatever. ***************************************************************************** So this issue is modified to being a documentation change.

[ Permlink | « Hide ]

Ulrich Mayring - [02/May/07 02:53 AM ]

Additional documentation may then be needed for the method trigger.setStartTime(). It should be made explicit that setting it to a time in the past may compute a next fire time for the trigger, that is also in the past. It should be explained whether this trigger will ever fire and when.

[ Permlink | « Hide ]

James House - [21/Oct/07 03:17 PM ]

Docs have been clarified as described in comments above.