Comment 4 for bug 632427

Revision history for this message
dirk (australiandeveloper) wrote : Re: [Bug 632427] Re: @On causes Job to run twice

I think it's not that likely that this is a problem with the JVM otherwise
I'm sure it would have been fixed by now. My guess is that it's something to
do with the date calculation. But here are the details of my JVM and the box
that it's running on:

$ java -version
java version "1.6.0_12"
Java(TM) SE Runtime Environment (build 1.6.0_12-b04)
Java HotSpot(TM) Client VM (build 11.2-b01, mixed mode, sharing)

$ uname -a
Linux boludo 2.6.21.7-2.ec2.v1.2.fc8xen #1 SMP Fri Nov 20 19:22:36 EST 2009
i686 GNU/Linux

$ cat /etc/debian_version
5.0.4

On Thu, Sep 9, 2010 at 10:12 AM, Erwan Loisant <email address hidden> wrote:

> which JVM are you using ?
>
> --
> @On causes Job to run twice
> https://bugs.launchpad.net/bugs/632427
> You received this bug notification because you are a direct subscriber
> of the bug.
>
> Status in play framework: New
>
> Bug description:
> There is a bug in the Jobs mechanism that causes jobs annotated with @On to
> sometimes run twice. This is causing emails in an application I have to be
> sent twice.
>
> When the Job has finished running, the _finally method is invoked:
> @Override
> public void _finally() {
> super._finally();
> if (executor == JobsPlugin.executor) {
> JobsPlugin.scheduleForCRON(this);
> }
> }
>
> This results in a call to scheduleForCRON(), which schedules the next
> invocation of the job by working out the difference in time between now and
> when it should next run using Time.parseCRONExpression(cron).
>
> Date now = new Date();
> cron = Expression.evaluate(cron, cron).toString();
> Date nextDate = Time.parseCRONExpression(cron);
> long delay = nextDate.getTime() - now.getTime();
> executor.schedule((Callable<V>)job, delay,
> TimeUnit.MILLISECONDS);
>
> A problem occurs if Time.parseCRONExpression returns a value that is a few
> milli-seconds less than it should be, or if the ScheduledThreadPoolExecutor
> runs the job slightly earlier than it should. Then when the job finishes,
> the job will be rescheduled for it's next invocation that is only a few
> milli-seconds later.
>
> For example, the job is scheduled to run at 4:00am.
> ScheduledThreadPoolExecutor runs it at 3:00:59.543. When the job is
> complete, _finally() is called which in turn calls scheduleForCRON(), which
> works out the difference between now and 4:00am. If this happens fast
> enough, it is not yet 4:00 am, so the job is scheduled to run a few
> milli-seconds later, and runs again at 4:00:00.034
>
> One solution would be to make sure that the variable delay is not less than
> one second:
>
> public static <V> void scheduleForCRON(Job<V> job) {
> if (job.getClass().isAnnotationPresent(On.class)) {
> String cron = job.getClass().getAnnotation(On.class).value();
> if (cron.startsWith("cron.")) {
> cron = Play.configuration.getProperty(cron);
> }
> if (cron != null && !cron.equals("")) {
> try {
> cron = Expression.evaluate(cron, cron).toString();
> Date nextDate = Time.parseCRONExpression(cron);
> long delay = nextDate.getTime() -
> System.currentTimeMillis();
> while(delay < 1000) {
> Thread.sleep(delay);
> delay = nextDate.getTime() -
> System.currentTimeMillis();
> }
> executor.schedule((Callable<V>)job, delay,
> TimeUnit.MILLISECONDS);
> job.executor = executor;
> } catch (Exception ex) {
> throw new UnexpectedException(ex);
> }
> } else {
> Logger.info("Skipping job %s, cron expression is not
> defined", job.getClass().getName());
> }
> }
> }
>
> To unsubscribe from this bug, go to:
> https://bugs.launchpad.net/play/+bug/632427/+subscribe
>