Cron server being delayed by multiple minutes using setTimeout()

Question

I currently have a running 'cron' server. It is supposed to execute all the timed commands whom need to be run in the future. This is the only thing that server does.

What works: Running the functions on a my own laptop, everything is executed in time.

What is broken: Running functions over multiple days on the server.

My code is all placed in an express project(Node) so calls can be made by other servers to add more 'crons'

Folder layout:

app.js
-api/
--crons/
---router.js
---functions.js
--.../

In the functions file my functions to add a cron and execute it are kept.

const _ = require('lodash');
const Crons = [];
const moment = require('moment');

const functions = {

 addCron: (toExecute, dateTime, id, name) => {
    console.log('Cron', dateTime, name, id);
    const now = new Date().getTime();
    const then = new Date(dateTime).getTime();
    const diff = Math.max(then - now, 0);

    let cronJob;
    if (diff >= Math.pow(2, 31)) {
      if(functions.get(name)) {

      }
      cronJob = setTimeout(() => {
        functions.remove(name);
        functions.addCron(toExecute, dateTime, id, name);
      }, diff);
      Crons.push({
        name: name,
        job: cronJob
      });
    } else {
      if(functions.get(name)) {
        functions.remove(name);
      }
      cronJob = setTimeout(() => {
        console.log(`Started cron: ${name} at ${new Date()}`);
        toExecute(id);
        functions.remove(name);
      }, diff);
      Crons.push({
        name: name,
        job: cronJob
      });
    }

  }
};

module.exports = functions;

Currently my logs when I run this locally show me that all functions are executed approximately 1 millisecond too late(which is fine). And the logs on the live server show me that functions are beign run 7 minutes more late each day.

The logs

1|cronserver | 2017-06-30 18:00:07.195000000: Cron 2017-07-01T17:00:00.000Z YQkWN6BmX8eqzQHC9startCheck YQkWN6BmX8eqzQHC9
1|cronserver | 2017-06-30 18:00:07.195000000: Cron 2017-07-01T17:30:00.000Z 7c2yPyfjKDuujKQjhstartCheck 7c2yPyfjKDuujKQjh
1|cronserver | 2017-06-30 18:00:07.196000000: Cron 2017-07-02T17:00:00.000Z PQKoboRpSkWeTufSdstartCheck PQKoboRpSkWeTufSd
1|cronserver | 2017-06-30 18:00:07.196000000: Cron 2017-07-02T17:30:00.000Z yLFaAjACB9uNPd4YvstartCheck yLFaAjACB9uNPd4Yv
1|cronserver | 2017-06-30 18:00:07.199000000: Cron 2017-07-01T17:30:00.000Z YQkWN6BmX8eqzQHC9start YQkWN6BmX8eqzQHC9
1|cronserver | 2017-06-30 18:00:07.199000000: Cron 2017-07-01T18:00:00.000Z 7c2yPyfjKDuujKQjhstart 7c2yPyfjKDuujKQjh
1|cronserver | 2017-06-30 18:00:07.199000000: Cron 2017-07-02T17:30:00.000Z PQKoboRpSkWeTufSdstart PQKoboRpSkWeTufSd
1|cronserver | 2017-06-30 18:00:07.199000000: Cron 2017-07-02T18:00:00.000Z yLFaAjACB9uNPd4Yvstart yLFaAjACB9uNPd4Yv
1|cronserver | 2017-07-01 17:07:32.253000000: Started cron: YQkWN6BmX8eqzQHC9startCheck at Sat Jul 01 2017 17:07:32 GMT+0000 (UTC)
1|cronserver | 2017-07-01 17:37:33.160000000: Started cron: 7c2yPyfjKDuujKQjhstartCheck at Sat Jul 01 2017 17:37:33 GMT+0000 (UTC)
1|cronserver | 2017-07-01 17:37:33.161000000: Started cron: YQkWN6BmX8eqzQHC9start at Sat Jul 01 2017 17:37:33 GMT+0000 (UTC)
1|cronserver | 2017-07-01 18:07:34.070000000: Started cron: 7c2yPyfjKDuujKQjhstart at Sat Jul 01 2017 18:07:34 GMT+0000 (UTC)
1|cronserver | 2017-07-02 17:14:24.678000000: Started cron: PQKoboRpSkWeTufSdstartCheck at Sun Jul 02 2017 17:14:24 GMT+0000 (UTC)
1|cronserver | 2017-07-02 17:44:25.587000000: Started cron: yLFaAjACB9uNPd4YvstartCheck at Sun Jul 02 2017 17:44:25 GMT+0000 (UTC)
1|cronserver | 2017-07-02 17:44:25.588000000: Started cron: PQKoboRpSkWeTufSdstart at Sun Jul 02 2017 17:44:25 GMT+0000 (UTC)
1|cronserver | 2017-07-02 18:14:26.496000000: Started cron: yLFaAjACB9uNPd4Yvstart at Sun Jul 02 2017 18:14:26 GMT+0000 (UTC)

The only thing this server does is running those functions. Any help would be greatly appreciated.

TL;DR My setTimout functions are running late. How can I solve this problem

what is `functions.remove`? Are you ever clearing `Crons`? Your current code increases it withtout limit: it would progressively slow everything down... — dfogni, Jul 05 '17 at 16:48
Functions.remove is a function that stops the timeout and removes it from the crons array. This isused to cancel crons — mitchken, Jul 06 '17 at 07:02

score 1 · Answer 1 · answered Jul 05 '17 at 21:48

setTimeout only gets executed once, so I would not consider this a "cron job", but instead a job you want to execute once sometime in the future. Leaving that aside, setTimeout is not meant to be exact and there are multiple known reasons why your setTimeout timer executes at the wrong time. how setTimeout works is that it creates an event in the event queue and it's not until the queue frees up that it executes your code, as explained here. I could easily see a situation where if you have multiple setTimeout functions running it will cause delays in when they execute. Or more likely you have some other memory leak issue, that is just bubbling up here.

Regardless there are many other options for accomplishing what you are trying to do. I've used node-cron for actual cron jobs and its pretty sweet. There are also multiple ways for running single jobs on their own queues such as Kue or RabbitMQ.

Doesn't node cron use setTimeout in it's own functions? So how can they be more precise? — mitchken, Jul 06 '17 at 07:08
Here are pretty similar discussions https://github.com/kelektiv/node-cron/issues/218 and https://github.com/node-schedule/node-schedule/issues/368 - They discuss running thousands of setTimeout's at a time with minimal delays. Most likely in the code that is executed is running sync code that is clogging up the event loop. I would suggest having your cron job and the code that actually gets executed running on different processes. — jjbskir, Jul 06 '17 at 14:15

Cron server being delayed by multiple minutes using setTimeout()

1 Answers1