Automattic / kue

Kue is a priority job queue backed by redis, built for node.js.
http://automattic.github.io/kue
MIT License
9.45k stars 862 forks source link

Done too quick? #1141

Open BarryCarlyon opened 6 years ago

BarryCarlyon commented 6 years ago

I have observed the following:

queue.process('SOMENAME', 1, function(job, done) {
    done();
    //rest of task
});

Basically done is called literally after the job goes active.

The job gets stuck in "active" and thus the task doesn't accept new process'es because it thinks it's still running the job in done() that kue didn't mark as done.

I'm thinking some sort of redis latency (I do have a few keys in the stack).

But wanted to check if I'm doing something wrong or is it a bug?

The job in question appears to complete it's tasks ok, since the done() is independent of the task, It's just the done() thats tripping up.

I've observed this on other tasks that I have, those I ended up throwing a timer on it, so it doesn't done() so quick (5 second count where I call progress() whilst it ticks to done()'ing).

popey456963 commented 6 years ago

When generating a lot of fairly quick jobs, we are also seeing this issue. Our code looks something like:

queue.process('query', 1024, async (job, done) => {
  job.progress(5, 100); job.log('Job started.')
  await (new Query(job, done)).update()

  job.progress(95, 100); job.log('Finishing up...')
  fs.appendFile('../../log.txt', `[QUERY-${job.id}] Finished updating ${job.data.ip}:${job.data.port}\n`, (err) => { if (err) console.log(err) })

  job.progress(100, 100); job.log('Finished.')
  setTimeout(done, 10 * 1000)
})

If we generate a number of jobs, we see this in the GUI:

Where the 532 active jobs eventually time out after 10 minutes, even with a ten second pause on job completion. No such problem seems to occur with job.progress.

Interestingly, the Node process handles done() correctly, and the process is complete. It's just the Redis backend that struggles to keepup.

popey456963 commented 6 years ago
if( self.job === null || self.job && self.job.id && self.job.id !== jobId ) {
  console.warn(self.job === null, self.job && self.job.id && self.job.id !== jobId)
  console.warn( 'This job has already been finished, ignoring execution of done callback' );
  job.log( 'This job has already been finished, ignoring execution of done callback' );
  // return;
}

This is the code which breaks the done() function. /lib/queue/worker.js:170