[Bug]: upsertJobSchedule not updating data

[FabioNappi]

Version

v5.41.3

Platform

NodeJS

What happened?

Trying to update an existing jobSchedule is not working as expected: the scheduler itself seems to have updated data, but the actual jobs data is not always updated as well.

In my case I execute the following:

await queue.upsertJobScheduler('my-schedule', {
    every: 20000,
}, {
    name: 'my-name',
    data: { key: 'value' },
})

The schedule is correctly created and jobs executed as expected. Then I try to update the schedule as follows:

await queue.upsertJobScheduler('my-schedule', {
    every: 20000,
}, {
    name: 'my-name',
    data: { anotherKey: 'another-value' },
})

Now the schedule is updated correctly (I'm getting info with queue.getJobSchedulers()), but the jobs are executed with "old" data (i.e. { key: 'value' })

NOTE: this happens from the 2nd update and on. The creation and the first update work fine.

How to reproduce.

No response

Relevant log output

Code of Conduct

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

[cann0nball]

I can confirm this behavior. It seems it's trying to update the previous job repeat, that already finished, leaving the next scheduled one untouched.

It seems to work correctly, if I set prevMillis to Date.now(), but that has other side effects, like job not starting immediately, even with every.

This issue, together with #3063 means there's currently no way to update the existing jobs, or we're doing something wrong?

[fabion-subbyx]

Thanks @cann0nball for your workaround proposal, unfortunately it doesn't seem to work consistently on my laptop. I agree with you that JobSchedules are currently not reliable therefore not usable.

I hope the team will fix the scheduling issues in the next release.

[FabioNappi]

In the end my workaround was to use deprecated APIs: add to the queue a job with the repeat options (insert) and then remove it with removeRepeatableByKey and re-add it again with new data (update).

It works as expected and is reliable.

[manast]

We are trying to reproduce this issue in a test case and if we can we will make a fix.

[marcolubian]

I'm experiencing the same issue and I confirm that the workaround of setting prevMillis to Date.now() doesn't work effectively, it works 2-3 times but then the job schedulation is not upserted/refreshed anymore.

Even removing and recreating the scheduled job doesn't seem to work (rif. 3063)

[enyineer]

Does this also affect upserting a JobScheduler with new RepeatOptions?

I'm trying to upsert every for an existing JobScheduler when a user changes a check-interval in the UI, but this doesn't seem to actually update the Repeat-Settings for the Job.

[FabioNappi]

@enyineer yes. Both job data and repeat options are not updated by the upsert.

[enyineer]

@manast sorry to bother you, but is there anything we could help you with to get this fixed? It seems to be a general problem. Sorry if I've missed something :)

[manast]

I wrote a test with the best of my ability to cover this scenario, the test is passing, so what I would need is some code that reproduces the issue so that we can further investigate it. https://github.com/taskforcesh/bullmq/pull/3281

[enyineer]

Could it be passing because of the fix in #3197 / #3203? I have the feeling this might be related to this issue without having a really good understanding of the inner workings of BullMQ.

[manast]

@enyineer could be, in any case I added another test case which is also passing, and this help us cover possible regressions. Please update to the latest version and this issue should be resolved.

[cann0nball]

I've tried with the latest version (5.53.1) and it doesn't fix the issue we have. Also tried to reproduce with a test, but couldn't. Surprisingly, with a short offset, like 100ms, it works as it should. { every: 5000 offset: 100 },

Could it be related to the redis we use, or maybe something in the config? Is there anything else we can do, except migrate to the old scheduled jobs implementation?

[manast]

@cann0nball do you have a test that reproduces it?

[FabioNappi]

@manast here is a script that reproduces the bug. It happens in just a few iterations (like the third one in my output)

import {Queue, Worker} from 'bullmq'
import {Redis} from 'ioredis'

const REDIS_HOST = 'localhost'
const REDIS_PORT = 6379
const REDIS_PASSWORD = ''
const REDIS_DB = 11

const redisClient = new Redis({
  host: REDIS_HOST,
  port: REDIS_PORT,
  password: REDIS_PASSWORD,
  db: REDIS_DB,
  maxRetriesPerRequest: null,
})
  .on('connect', () => console.log('Connected to Redis'))
  .on('error', e => console.log(`Failed to connect to Redis: ${e.message}`))

const queueName = 'queue-name'
const jobScheduledId = 'my-schedule'
const jobQueue = new Queue(queueName, {connection: redisClient})

const main = async iteration => {
  const jobWorker = new Worker(
    queueName,
    job => {
      const elapsedTime = ((Date.now() - start) / 1000).toFixed(1)
      console.log(`Elapsed ${elapsedTime}s:`, JSON.stringify({name: job.name, data: job.data}))
    },
    {connection: redisClient},
  )
  // create schedule
  await jobQueue.upsertJobScheduler(
    jobScheduledId,
    {
      every: 2000,
    },
    {
      name: 'my-name-1',
      data: {key: 'first'},
    },
  )
  const start = Date.now()
  console.log('--- first upsert ---')

  // wait a couple of executions, then upsert
  await new Promise(resolve => setTimeout(resolve, 10_000))
  await jobQueue.upsertJobScheduler(
    jobScheduledId,
    {
      every: 2000,
    },
    {
      name: 'my-name-2',
      data: {key: 'second'},
    },
  )
  console.log('--- second upsert ---')

  // wait a couple of executions, then upsert
  await new Promise(resolve => setTimeout(resolve, 10_000))
  await jobQueue.upsertJobScheduler(
    jobScheduledId,
    {
      every: 2000,
    },
    {
      name: 'my-name-3',
      data: {key: 'third'},
    },
  )
  console.log('--- third upsert ---')

  // keep alive
  await new Promise(resolve => setTimeout(resolve, 10_000))
  await jobWorker.close()
  console.log(`=== End iteration ${iteration} ===\n`)
}

for (let index = 1; index <= 10; index++) {
  await main(index)
}
await redisClient.quit()

Output

Connected to Redis
--- first upsert ---
Elapsed 5.1s: {"name":"my-name-1","data":{"key":"first"}}
Elapsed 8.0s: {"name":"my-name-1","data":{"key":"first"}}
--- second upsert ---
Elapsed 10.0s: {"name":"my-name-2","data":{"key":"second"}}
Elapsed 12.1s: {"name":"my-name-2","data":{"key":"second"}}
Elapsed 14.1s: {"name":"my-name-2","data":{"key":"second"}}
Elapsed 16.0s: {"name":"my-name-2","data":{"key":"second"}}
Elapsed 18.0s: {"name":"my-name-2","data":{"key":"second"}}
--- third upsert ---
Elapsed 20.0s: {"name":"my-name-3","data":{"key":"third"}}
Elapsed 22.0s: {"name":"my-name-3","data":{"key":"third"}}
Elapsed 24.1s: {"name":"my-name-3","data":{"key":"third"}}
Elapsed 26.1s: {"name":"my-name-3","data":{"key":"third"}}
Elapsed 28.1s: {"name":"my-name-3","data":{"key":"third"}}
=== End iteration 1 ===

--- first upsert ---
Elapsed 0.0s: {"name":"my-name-1","data":{"key":"first"}}
Elapsed 2.1s: {"name":"my-name-1","data":{"key":"first"}}
Elapsed 4.1s: {"name":"my-name-1","data":{"key":"first"}}
Elapsed 6.0s: {"name":"my-name-1","data":{"key":"first"}}
Elapsed 8.0s: {"name":"my-name-1","data":{"key":"first"}}
--- second upsert ---
Elapsed 10.0s: {"name":"my-name-2","data":{"key":"second"}}
Elapsed 12.1s: {"name":"my-name-2","data":{"key":"second"}}
Elapsed 14.0s: {"name":"my-name-2","data":{"key":"second"}}
Elapsed 16.0s: {"name":"my-name-2","data":{"key":"second"}}
Elapsed 18.1s: {"name":"my-name-2","data":{"key":"second"}}
--- third upsert ---
Elapsed 20.0s: {"name":"my-name-3","data":{"key":"third"}}
Elapsed 22.0s: {"name":"my-name-3","data":{"key":"third"}}
Elapsed 24.1s: {"name":"my-name-3","data":{"key":"third"}}
Elapsed 26.1s: {"name":"my-name-3","data":{"key":"third"}}
Elapsed 28.1s: {"name":"my-name-3","data":{"key":"third"}}
Elapsed 30.0s: {"name":"my-name-3","data":{"key":"third"}}
=== End iteration 2 ===

--- first upsert ---
Elapsed 2.1s: {"name":"my-name-3","data":{"key":"third"}}
Elapsed 4.1s: {"name":"my-name-3","data":{"key":"third"}}
Elapsed 6.0s: {"name":"my-name-3","data":{"key":"third"}}
Elapsed 8.0s: {"name":"my-name-3","data":{"key":"third"}}
--- second upsert ---
Elapsed 10.0s: {"name":"my-name-2","data":{"key":"second"}}
Elapsed 12.0s: {"name":"my-name-2","data":{"key":"second"}}
Elapsed 14.0s: {"name":"my-name-2","data":{"key":"second"}}
Elapsed 16.0s: {"name":"my-name-2","data":{"key":"second"}}
Elapsed 18.1s: {"name":"my-name-2","data":{"key":"second"}}
--- third upsert ---
Elapsed 20.0s: {"name":"my-name-3","data":{"key":"third"}}
Elapsed 22.0s: {"name":"my-name-3","data":{"key":"third"}}
Elapsed 24.0s: {"name":"my-name-3","data":{"key":"third"}}
Elapsed 26.1s: {"name":"my-name-3","data":{"key":"third"}}
Elapsed 28.1s: {"name":"my-name-3","data":{"key":"third"}}
Elapsed 30.0s: {"name":"my-name-3","data":{"key":"third"}}
=== End iteration 3 ===

--- first upsert ---
Elapsed 2.1s: {"name":"my-name-3","data":{"key":"third"}}
Elapsed 4.1s: {"name":"my-name-3","data":{"key":"third"}}
Elapsed 6.0s: {"name":"my-name-3","data":{"key":"third"}}
Elapsed 8.1s: {"name":"my-name-3","data":{"key":"third"}}
--- second upsert ---
Elapsed 10.0s: {"name":"my-name-2","data":{"key":"second"}}
Elapsed 12.1s: {"name":"my-name-2","data":{"key":"second"}}
Elapsed 14.1s: {"name":"my-name-2","data":{"key":"second"}}
Elapsed 16.0s: {"name":"my-name-2","data":{"key":"second"}}
Elapsed 18.1s: {"name":"my-name-2","data":{"key":"second"}}
--- third upsert ---
Elapsed 20.0s: {"name":"my-name-3","data":{"key":"third"}}
Elapsed 22.1s: {"name":"my-name-3","data":{"key":"third"}}
Elapsed 24.1s: {"name":"my-name-3","data":{"key":"third"}}
Elapsed 26.1s: {"name":"my-name-3","data":{"key":"third"}}
Elapsed 28.0s: {"name":"my-name-3","data":{"key":"third"}}
=== End iteration 4 ===

--- first upsert ---
Elapsed 0.0s: {"name":"my-name-1","data":{"key":"first"}}
Elapsed 2.1s: {"name":"my-name-1","data":{"key":"first"}}
Elapsed 4.1s: {"name":"my-name-1","data":{"key":"first"}}
Elapsed 6.0s: {"name":"my-name-1","data":{"key":"first"}}
Elapsed 8.1s: {"name":"my-name-1","data":{"key":"first"}}
--- second upsert ---
Elapsed 10.0s: {"name":"my-name-2","data":{"key":"second"}}
Elapsed 12.0s: {"name":"my-name-2","data":{"key":"second"}}
Elapsed 14.1s: {"name":"my-name-2","data":{"key":"second"}}
Elapsed 16.0s: {"name":"my-name-2","data":{"key":"second"}}
Elapsed 18.1s: {"name":"my-name-2","data":{"key":"second"}}
--- third upsert ---
Elapsed 20.0s: {"name":"my-name-3","data":{"key":"third"}}
Elapsed 22.1s: {"name":"my-name-3","data":{"key":"third"}}
Elapsed 24.0s: {"name":"my-name-3","data":{"key":"third"}}
Elapsed 26.1s: {"name":"my-name-3","data":{"key":"third"}}
Elapsed 28.1s: {"name":"my-name-3","data":{"key":"third"}}
=== End iteration 5 ===

--- first upsert ---
Elapsed 0.0s: {"name":"my-name-1","data":{"key":"first"}}
Elapsed 2.1s: {"name":"my-name-1","data":{"key":"first"}}
Elapsed 4.0s: {"name":"my-name-1","data":{"key":"first"}}
Elapsed 6.1s: {"name":"my-name-1","data":{"key":"first"}}
Elapsed 8.0s: {"name":"my-name-1","data":{"key":"first"}}
--- second upsert ---
Elapsed 10.0s: {"name":"my-name-2","data":{"key":"second"}}
Elapsed 12.1s: {"name":"my-name-2","data":{"key":"second"}}
Elapsed 14.0s: {"name":"my-name-2","data":{"key":"second"}}
Elapsed 16.1s: {"name":"my-name-2","data":{"key":"second"}}
Elapsed 18.0s: {"name":"my-name-2","data":{"key":"second"}}
--- third upsert ---
Elapsed 20.0s: {"name":"my-name-3","data":{"key":"third"}}
Elapsed 22.1s: {"name":"my-name-3","data":{"key":"third"}}
Elapsed 24.0s: {"name":"my-name-3","data":{"key":"third"}}
Elapsed 26.1s: {"name":"my-name-3","data":{"key":"third"}}
Elapsed 28.1s: {"name":"my-name-3","data":{"key":"third"}}
Elapsed 30.0s: {"name":"my-name-3","data":{"key":"third"}}
=== End iteration 6 ===

--- first upsert ---
Elapsed 2.1s: {"name":"my-name-3","data":{"key":"third"}}
Elapsed 4.0s: {"name":"my-name-3","data":{"key":"third"}}
Elapsed 6.1s: {"name":"my-name-3","data":{"key":"third"}}
Elapsed 8.0s: {"name":"my-name-3","data":{"key":"third"}}
--- second upsert ---
Elapsed 10.0s: {"name":"my-name-2","data":{"key":"second"}}
Elapsed 12.1s: {"name":"my-name-2","data":{"key":"second"}}
Elapsed 14.0s: {"name":"my-name-2","data":{"key":"second"}}
Elapsed 16.1s: {"name":"my-name-2","data":{"key":"second"}}
Elapsed 18.0s: {"name":"my-name-2","data":{"key":"second"}}
--- third upsert ---
Elapsed 20.0s: {"name":"my-name-3","data":{"key":"third"}}
Elapsed 22.1s: {"name":"my-name-3","data":{"key":"third"}}
Elapsed 24.1s: {"name":"my-name-3","data":{"key":"third"}}
Elapsed 26.0s: {"name":"my-name-3","data":{"key":"third"}}
Elapsed 28.1s: {"name":"my-name-3","data":{"key":"third"}}
=== End iteration 7 ===

--- first upsert ---
Elapsed 0.0s: {"name":"my-name-1","data":{"key":"first"}}
Elapsed 2.1s: {"name":"my-name-1","data":{"key":"first"}}
Elapsed 4.0s: {"name":"my-name-1","data":{"key":"first"}}
Elapsed 6.1s: {"name":"my-name-1","data":{"key":"first"}}
Elapsed 8.0s: {"name":"my-name-1","data":{"key":"first"}}
--- second upsert ---
Elapsed 10.0s: {"name":"my-name-2","data":{"key":"second"}}
Elapsed 12.1s: {"name":"my-name-2","data":{"key":"second"}}
Elapsed 14.0s: {"name":"my-name-2","data":{"key":"second"}}
Elapsed 16.1s: {"name":"my-name-2","data":{"key":"second"}}
Elapsed 18.1s: {"name":"my-name-2","data":{"key":"second"}}
--- third upsert ---
Elapsed 20.0s: {"name":"my-name-3","data":{"key":"third"}}
Elapsed 22.0s: {"name":"my-name-3","data":{"key":"third"}}
Elapsed 24.1s: {"name":"my-name-3","data":{"key":"third"}}
Elapsed 26.1s: {"name":"my-name-3","data":{"key":"third"}}
Elapsed 28.1s: {"name":"my-name-3","data":{"key":"third"}}
=== End iteration 8 ===

--- first upsert ---
Elapsed 0.0s: {"name":"my-name-1","data":{"key":"first"}}
Elapsed 2.1s: {"name":"my-name-1","data":{"key":"first"}}
Elapsed 4.0s: {"name":"my-name-1","data":{"key":"first"}}
Elapsed 6.0s: {"name":"my-name-1","data":{"key":"first"}}
Elapsed 8.1s: {"name":"my-name-1","data":{"key":"first"}}
--- second upsert ---
Elapsed 10.0s: {"name":"my-name-2","data":{"key":"second"}}
Elapsed 12.0s: {"name":"my-name-2","data":{"key":"second"}}
Elapsed 14.0s: {"name":"my-name-2","data":{"key":"second"}}
Elapsed 16.1s: {"name":"my-name-2","data":{"key":"second"}}
Elapsed 18.0s: {"name":"my-name-2","data":{"key":"second"}}
--- third upsert ---
Elapsed 20.0s: {"name":"my-name-3","data":{"key":"third"}}
Elapsed 22.1s: {"name":"my-name-3","data":{"key":"third"}}
Elapsed 24.0s: {"name":"my-name-3","data":{"key":"third"}}
Elapsed 26.1s: {"name":"my-name-3","data":{"key":"third"}}
Elapsed 28.1s: {"name":"my-name-3","data":{"key":"third"}}
=== End iteration 9 ===

--- first upsert ---
Elapsed 0.0s: {"name":"my-name-1","data":{"key":"first"}}
Elapsed 2.1s: {"name":"my-name-1","data":{"key":"first"}}
Elapsed 4.0s: {"name":"my-name-1","data":{"key":"first"}}
Elapsed 6.1s: {"name":"my-name-1","data":{"key":"first"}}
Elapsed 8.0s: {"name":"my-name-1","data":{"key":"first"}}
--- second upsert ---
Elapsed 10.0s: {"name":"my-name-2","data":{"key":"second"}}
Elapsed 12.1s: {"name":"my-name-2","data":{"key":"second"}}
Elapsed 14.1s: {"name":"my-name-2","data":{"key":"second"}}
Elapsed 16.0s: {"name":"my-name-2","data":{"key":"second"}}
Elapsed 18.0s: {"name":"my-name-2","data":{"key":"second"}}
--- third upsert ---
Elapsed 20.0s: {"name":"my-name-3","data":{"key":"third"}}
Elapsed 22.1s: {"name":"my-name-3","data":{"key":"third"}}
Elapsed 24.0s: {"name":"my-name-3","data":{"key":"third"}}
Elapsed 26.1s: {"name":"my-name-3","data":{"key":"third"}}
Elapsed 28.1s: {"name":"my-name-3","data":{"key":"third"}}
=== End iteration 10 ===

[manast]

The problem should be resolved with this PR: https://github.com/taskforcesh/bullmq/pull/3446 that has been already released.