[Bug]: Error: could not renew lock for job XXXX

[fb-sean]

trafficstars

Version

5.45.2

Platform

NodeJS

What happened?

After some time, I randomly get the error:

search-api  | Error: could not renew lock for job 290070
search-api  |     at /app/node_modules/bullmq/dist/cjs/classes/worker.js:766:40
search-api  |     at process.processTicksAndRejections (node:internal/process/task_queues:95:5)
search-api  |     at async Worker.extendLocks (/app/node_modules/bullmq/dist/cjs/classes/worker.js:756:9)
search-api  |     at async Timeout._onTimeout (/app/node_modules/bullmq/dist/cjs/classes/worker.js:706:29)

And

search-api  | Error: Missing lock for job 290070. moveToFinished
search-api  |     at Scripts.finishedErrors (/app/node_modules/bullmq/dist/cjs/classes/scripts.js:1077:24)
search-api  |     at Scripts.moveToFinished (/app/node_modules/bullmq/dist/cjs/classes/scripts.js:434:24)
search-api  |     at process.processTicksAndRejections (node:internal/process/task_queues:95:5)
search-api  |     at async /app/node_modules/bullmq/dist/cjs/classes/job.js:507:26
search-api  |     at async handleFailed (/app/node_modules/bullmq/dist/cjs/classes/worker.js:492:40)
search-api  |     at async /app/node_modules/bullmq/dist/cjs/classes/worker.js:521:32
search-api  |     at async Worker.retryIfFailed (/app/node_modules/bullmq/dist/cjs/classes/worker.js:742:24)

I have no idea where this comes from and why this comes.

I'm using bullmq with a normal redis connector. It's running inside of docker and also only running as 1 instance.

How to reproduce.

I dont have a basic example where this happens. This would be my basic code tho

import {Queue, Worker} from 'bullmq';
import Redis from './RedisCache';
import type RedisClient from 'ioredis';
import {TWorkerEvent} from '@Types/RedisQueue';

export default class RedisQueue {
    private static _instance: RedisQueue;
    private readonly _redis: RedisClient;
    private readonly _queue: Queue;
    private readonly _worker: Worker;
    private readonly _jobs: Record<string, TWorkerEvent>;

    private constructor(redis: RedisClient) {
        this._redis = redis;
        this._queue = new Queue(process.env.QUEUE_NAME, {
            connection: this._redis,
        });
        this._jobs = {};
        this._worker = new Worker(
            process.env.QUEUE_NAME,
            async (job) => {
                if (job && job.name) {
                    if (this._jobs[job.name]) {
                        await this._jobs[job.name](job.data);
                    }
                }
            },
            {
                connection: this._redis,
                limiter: {
                    max: 30,
                    duration: 1000,
                },
            }
        );
    }

    public static getInstance(): RedisQueue {
        if (!RedisQueue._instance) {
            RedisQueue._instance = new RedisQueue(Redis.getInstance().getClient());
        }
        return RedisQueue._instance;
    }

    public async addJob(jobName: string, data: Record<string, unknown>): Promise<void> {
        await this._queue.add(jobName, data);
    }

    public listenTo(jobName: string, callback: TWorkerEvent, maxPerSecond: number = 1000): void {
        this._jobs[jobName] = callback;
    }
}

Relevant log output

search-api  | Error: could not renew lock for job 290070
search-api  |     at /app/node_modules/bullmq/dist/cjs/classes/worker.js:766:40
search-api  |     at process.processTicksAndRejections (node:internal/process/task_queues:95:5)
search-api  |     at async Worker.extendLocks (/app/node_modules/bullmq/dist/cjs/classes/worker.js:756:9)
search-api  |     at async Timeout._onTimeout (/app/node_modules/bullmq/dist/cjs/classes/worker.js:706:29)
search-api  | Error: could not renew lock for job 290070
search-api  |     at /app/node_modules/bullmq/dist/cjs/classes/worker.js:766:40
search-api  |     at process.processTicksAndRejections (node:internal/process/task_queues:95:5)
search-api  |     at async Worker.extendLocks (/app/node_modules/bullmq/dist/cjs/classes/worker.js:756:9)
search-api  |     at async Timeout._onTimeout (/app/node_modules/bullmq/dist/cjs/classes/worker.js:706:29)
search-api  | Error: could not renew lock for job 290070
search-api  |     at /app/node_modules/bullmq/dist/cjs/classes/worker.js:766:40
search-api  |     at process.processTicksAndRejections (node:internal/process/task_queues:95:5)
search-api  |     at async Worker.extendLocks (/app/node_modules/bullmq/dist/cjs/classes/worker.js:756:9)
search-api  |     at async Timeout._onTimeout (/app/node_modules/bullmq/dist/cjs/classes/worker.js:706:29)
search-api  | Error: could not renew lock for job 290070
search-api  |     at /app/node_modules/bullmq/dist/cjs/classes/worker.js:766:40
search-api  |     at process.processTicksAndRejections (node:internal/process/task_queues:95:5)
search-api  |     at async Worker.extendLocks (/app/node_modules/bullmq/dist/cjs/classes/worker.js:756:9)
search-api  |     at async Timeout._onTimeout (/app/node_modules/bullmq/dist/cjs/classes/worker.js:706:29)
search-api  | Error: could not renew lock for job 290070
search-api  |     at /app/node_modules/bullmq/dist/cjs/classes/worker.js:766:40
search-api  |     at process.processTicksAndRejections (node:internal/process/task_queues:95:5)
search-api  |     at async Worker.extendLocks (/app/node_modules/bullmq/dist/cjs/classes/worker.js:756:9)
search-api  |     at async Timeout._onTimeout (/app/node_modules/bullmq/dist/cjs/classes/worker.js:706:29)
search-api  | Error: could not renew lock for job 290070
search-api  |     at /app/node_modules/bullmq/dist/cjs/classes/worker.js:766:40
search-api  |     at process.processTicksAndRejections (node:internal/process/task_queues:95:5)
search-api  |     at async Worker.extendLocks (/app/node_modules/bullmq/dist/cjs/classes/worker.js:756:9)
search-api  |     at async Timeout._onTimeout (/app/node_modules/bullmq/dist/cjs/classes/worker.js:706:29)
search-api  | Error: could not renew lock for job 290070
search-api  |     at /app/node_modules/bullmq/dist/cjs/classes/worker.js:766:40
search-api  |     at process.processTicksAndRejections (node:internal/process/task_queues:95:5)
search-api  |     at async Worker.extendLocks (/app/node_modules/bullmq/dist/cjs/classes/worker.js:756:9)
search-api  |     at async Timeout._onTimeout (/app/node_modules/bullmq/dist/cjs/classes/worker.js:706:29)
search-api  | Error: Missing lock for job 290070. moveToFinished
search-api  |     at Scripts.finishedErrors (/app/node_modules/bullmq/dist/cjs/classes/scripts.js:1077:24)
search-api  |     at Scripts.moveToFinished (/app/node_modules/bullmq/dist/cjs/classes/scripts.js:434:24)
search-api  |     at process.processTicksAndRejections (node:internal/process/task_queues:95:5)
search-api  |     at async /app/node_modules/bullmq/dist/cjs/classes/job.js:507:26
search-api  |     at async handleFailed (/app/node_modules/bullmq/dist/cjs/classes/worker.js:492:40)
search-api  |     at async /app/node_modules/bullmq/dist/cjs/classes/worker.js:521:32
search-api  |     at async Worker.retryIfFailed (/app/node_modules/bullmq/dist/cjs/classes/worker.js:742:24)

Code of Conduct

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

[manast]

Here you can get some information to start with: https://docs.bullmq.io/guide/troubleshooting#missing-locks

[manast]

Most likely your job stalled, some other worker managed to process it and then it failed because the first worker managed to complete the job (as it was not really stalled, just blocking NodeJS event loop).

[fb-sean]

That sounds interesting, I'm pretty new to all that so thanks for the direct explanation I will check that out!

[fb-sean]

We added now lockDuration: 30000, lockRenewTime: 15000

But its still happening and now even after 5 minutes of running.

[manast]

If you do not need a lot of concurrency you can try sandboxed processors (https://docs.bullmq.io/guide/workers/sandboxed-processors), the best would be to make sure your process function does not block the NodeJS event loop, there are different techniques to achieve it.