Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

CronTime will fail to calculate a 'next time' of a repeating job, if the next time is inside of a DST forward jump. #638

Closed
GijsvandenHoven opened this issue Dec 15, 2022 · 1 comment

Comments

@GijsvandenHoven
Copy link
Contributor

Description

With reference to #467 , if you have a job that should trigger next on a point in time that does not really exist due to a DST jump, there will be an infinite loop (1).

I was able to set up a test that makes this happen for a 'weekly' and 'daily' job, but not an 'hourly' job (?!).
I used Sinon Fake Timers to simulate the passing of time. This seems to have no relevant side effects to the bug, other than causing an infinite loop instead of an Error after 5 seconds.

For example, 02:30 AM on March 26 2023 in Europe/Amsterdam. (DST will jump that day from 2 to 3 AM).
The reason for this is most likely because a luxon DateTime does not exist for 2:30 AM on this day. Because on timestamp x the time is 01:59:59.999 and on timestamp x+1 the time is 03:00:00.000.

Which causes the code in _getNextDateFrom in time.js to fail, because it (if understood it correctly) attempts to move towards a DateTime that is incrementally closer to a point in time that matches the parameters created from the Cron string.

If I add a console.log(date.toISO()) at the top of that while loop, a pattern seems to emerge (2): It tries to match the 2nd hour on the 25th day, because the cron string tells it to, but it will never find it because Luxon jumps ahead for any point in time inside of a DST forward jump.

Below is a mocha test set that reproduces the problem i'm talking about. Due to DST being involved, it may be timezone sensitive. I have tried to fix the cronJob creation to a timezone, but the timestamp for the FakeTimer in the beforeEach might need modification based on your personal timezone offsets.

import * as FakeTimers from "@sinonjs/fake-timers";
import { CronJob } from "cron";

// Optional, used to show timestamps for clarity with every would-be-console.log.
const Logger = {
    info: function(string) {
        const now = new Date();
        const padding = (num) => num >= 10 ? num.toString() : '0' + num
        // toISOString knockoff, but preserves the timezone local time.
        const [ yyyy, MM, dd, HH, mm, ss, zzzz ] = [
            now.getFullYear(), now.getMonth() + 1, now.getDate(),
            now.getHours(), now.getMinutes(), now.getSeconds(), now.getMilliseconds()
        ].map(padding);
        const ms = zzzz < 100 ? '0' + zzzz : zzzz;

        const day = `${yyyy}-${MM}-${dd}`;
        const time = `${HH}:${mm}:${ss}.${ms}`;
        console.log(`${day} ${time}:: ${string}`);
    }
}

describe('cron bug', function() {

    this.timeout(10 ** 12)

    let clock;
    beforeEach(() => {
        clock = FakeTimers.install({
            // pick any date 14 days removed from a DST forward jump.
            // For the Europe/Amsterdam timezone, the DST jump is March 25th 2AM in 2029.
            now: new Date("2029-03-11T02:00:00.000")
        });
    })

    it("reproduces a cron bug with a weekly interval", async() => {
        Logger.info('time 1');
        // make the timezone match your local time.
        // Create a cronjob that repeats on a weekly basis, on a point in time that is skipped by the DST forward jump.
        const cj = new CronJob("0 30 2 * * 0", () => Logger.info('cron callback tick'), null, true, 'Europe/Amsterdam');

        // go forward a half hour minus one ms, 1 tick removed from the first activation
        clock.tick(1000 * 60 * 30 - 1);
        Logger.info('time 2');
        clock.tick(1); // should result in 'cron callback tick'.
        Logger.info('time 3');
        clock.tick(1000 * 3600 * 24 * 7 - 1); // jump forward a week minus 1 tick
        Logger.info('time 4');
        clock.tick(1); // infinite loop in CronTime::_getNextDateFrom(). Normally an error would be thrown after 5s, but time doesn't tick right now...
        Logger.info('time 5');

        cj.stop();
    });

    it("reproduces a cron bug with a daily interval", async() => {
        Logger.info('time 1');
        clock.tick(1000 * 60 * 30 - 1); // 1 ms before the time
        clock.tick(1000 * 3600 * 24 * 12); // 2 days before the 'bug day'
        Logger.info('time 2')
        // make the timezone match your local time.
        // Create a cronjob that repeats on a daily basis, on a point in time that is skipped by the DST forward jump.
        const cj = new CronJob("0 30 2 * * *", () => Logger.info('cron callback tick'), null, true, 'Europe/Amsterdam');

        // go forward a single tick, it should activate
        clock.tick(1);
        Logger.info('time 3');
        clock.tick(1000 * 3600 * 24 - 1); // 1 ms before the next activation
        Logger.info('time 4')
        clock.tick(1); // after activating 'this' job (1 day before bug day) it tries to calculate the 'next' which goes wrong, because it does not exit.
        Logger.info('time 5'); // never reached.

        cj.stop();
    });

    it("Cannot reproduce a cron bug with an hourly interval", async() => {
        Logger.info('time 1');
        clock.tick(1000 * 60 * 30 - 1); // 1 ms before an activation
        clock.tick(1000 * 3600 * 24 * 13); // 1 day 1 ms before the 'bug day'
        clock.tick(1000 * 3600 * 22); // 2 hours 1 ms before the 'bug hour'
        Logger.info('time 2');
        // make the timezone match your local time.
        // Create a cronjob that repeats on a daily basis, on a point in time that is skipped by the DST forward jump.
        const cj = new CronJob("0 30 * * * *", () => Logger.info('cron callback tick'), null, true, 'Europe/Amsterdam');

        clock.tick(1); // next activation is 1hr before 'bug hour'
        Logger.info('time 3');
        clock.tick(1000 * 3600 - 1); // next activation is 1ms before 'bug hour'
        Logger.info('time 4');
        clock.tick(1); // this should break if it followed the pattern of the previous tests... but it doesn't?
        Logger.info('time 5');
        for (let i = 0; i < 100; ++i) { // nope, we're fine!
            clock.tick(1000 * 3600 - 1)
            Logger.info(`time ${i + 5}`)
            clock.tick(1)
        }

        cj.stop();
    });

    afterEach(() => {
        clock.uninstall();
    });
})

Screenshots

(1)
webstorm64_nC8fMFkVQu

(2)
webstorm64_CF7nWwfB6W

Additional information

Currently trying to detect and correct for DST forward jumps, might submit a PR. It is possible to detect this happening by inspecting the 'expected' and 'actual' hours and minutes before and after a 'plus' call on DateTime. If they do not match (and didnt wrap from 24 or 60 to 0), then time has shifted forward.

@intcreator
Copy link
Collaborator

closing as fixed by your PR. thanks for your help on this!

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

2 participants