[Bug]: Delayed jobs are not triggered on time

[lindesvard]

Version

v5.8.7

Platform

NodeJS

What happened?

I have a queue with 2 types (createEvent, createSessionEnd).

For each request I get to my api I create a new queue item event. This will trigger immediately.

Inside the this job I check if a session exists:

• If no session is found I will create a delayed job create-session-end (30 minutes)
• If it exists I will find the delayed job and change the delayed time (look code snippet below)

if (sessionEnd) {
    // update the delay time with additional 30 minutes if we get a new event within this session
    const diff = Date.now() - sessionEnd.job.timestamp;
    await sessionEnd.job.changeDelay(diff + SESSION_END_TIMEOUT);
  } else {
    eventsQueue.add(
      'event',
      {
        type: 'createSessionEnd',
        payload: sessionEndPayload,
      },
      {
        delay: SESSION_END_TIMEOUT,
        jobId: `sessionEnd:${projectId}:${sessionEndPayload.deviceId}:${Date.now()}`,
      }
    );
}

The delayed job is not always triggered on time and can take several hours before it gets triggered (some delayed jobs never gets triggered).

I have no problems with the createEvent job at all. It get triggered right away. None of these jobs are heavy. Usually takes 10-100ms to run.

edit/addition: Worth to mention, I have also cron jobs running each 10s without any problems or delays.

How to reproduce.

I dont have a reproducing example but I have some questions so I might understand the problem more.

Will the createEvent job block the delayed job?
I get 10 new jobs a second. Each of these jobs creates a delayed session end job. I would assume that if a createSessionEnd jobs delayed time is over it would have higher priority than the createEvent. Is this assumption true?

I have tried to throw workers at the queue but it does not look like its taking any delayed job. All workers are just picking createEvent jobs even tho I hade 100+ delayed job with its delayed time passed several hours.

The delayed time

Is it correct assumption that job.timestamp + job.delay = The time it should get triggered?

Best way to debug this?

Is there any good way of debugging this? Would love any input or guidance. This might be a related ticket #2466 but update of bullmq didnt seem to help it.

Relevant log output

none for now

Code of Conduct

• I agree to follow this project's Code of Conduct

[lindesvard]

Tried to remove the delayed event and re-add it instead of changing the delay and this seems to solve the issue.

Then I would draw the conclusion that either something is wrong with changeDelay or I might missunderstand how to use it.

My assumption is the following.

• I create a delayed job 10:00 with a delay of 30 minutes delay: 1000 * 60 * 30.
• Now this job has delay: 1_800_000
• 10:15 I want to extend the delayed event 30 minutes again. Here I do job.changeDelay((now - timestamp) + 1_800_000)
• This will add a new delay value based on the creation timestamp
• If I look at a job with hgetall and add timestamp + delay I get the correct date when it should be executed but it does not happen.

[roggervalf]

hi @lindesvard, changeDelay takes current timestamp to apply the new delay. What I'm understanding is that you probably want to reset those 30 minutes instrad of adding 30 minutes to the remaining delay. If my first assumption is right, you only need to do job.changeDelay(1_800_000).

[lindesvard]

hi @lindesvard, changeDelay takes current timestamp to apply the new delay. What I'm understanding is that you probably want to reset those 30 minutes instrad of adding 30 minutes to the remaining delay. If my first assumption is right, you only need to do job.changeDelay(1_800_000).

Oh didn't feel intuitive to use same delay each time. But will give it a try.

Thanks for fast reply

[lindesvard]

@roggervalf looks like its working. Will close this!

[manast]

Maybe a better name would have been "resetDelay" instead of "changeDelay" actually...

[manast]

@roggervalf a candidate for deprecation I think.

[lindesvard]

Wouldn't this be solve if changeDelay actually got the delay as if it were calculated relative from the job.timestamp?

Then job.timestamp + job.delay would equal to runAt

[manast]

@lindesvard for me that would be awkward, as you call changeDelay for example with 30 seconds, and that would be 30 seconds from when the job was added to the queue, which could potentially even be back in time.

[lindesvard]

@manast I don't see the problem here but might be missing some deeper understanding.

Either way, resetDelay naming explains what happens here better

Thanks for a fantastic library!