taskforcesh / bullmq

BullMQ - Message Queue and Batch processing for NodeJS and Python based on Redis
https://bullmq.io
MIT License
5.85k stars 378 forks source link

[Bug]: Jest did not exit one second after the test run has completed. #2650

Closed elyran closed 2 weeks ago

elyran commented 1 month ago

Version

v5.8.7

Platform

NodeJS

What happened?

Worker causes Jest to hang 30 seconds after the test ends.

How to reproduce.

  1. Spin up a Redis instance: docker run --rm -p 30001:6379 redis:7.2
  2. Run the following Jest test with: node --inspect ./node_modules/jest/bin/jest.js --runInBand src/queue/BullMQ.test.ts

The content of BullMQ.test.ts:

import { Worker } from 'bullmq';
const QUEUE_NAME = 'queue1';

describe(__filename, () => {
  it(`performs operations on a queue`, async () => {
    const worker = new Worker(
      QUEUE_NAME,
      async (job) => {
        // TODO: Handle the job.
      },
      {
        connection: {
          host: 'localhost',
          port: 30001,
        },
      },
    );
    await worker.waitUntilReady();

    // TODO: Add a job to the queue.

    await worker.close();
  });
});

Relevant log output

ken@ken-pc:~/tmp/proj1$ node --inspect ./node_modules/jest/bin/jest.js --runInBand src/queue/BullMQ.test.ts
Debugger listening on ws://127.0.0.1:9229/7d6260b6-bc10-4045-9f33-86ac62ebb6b2
For help, see: https://nodejs.org/en/docs/inspector
 PASS  src/queue/BullMQ.test.ts
  /home/ken/tmp/proj1/src/queue/BullMQ.test.ts
    ✓ performs operations on a queue (21 ms)

Test Suites: 1 passed, 1 total
Tests:       1 passed, 1 total
Snapshots:   0 total
Time:        2.537 s, estimated 3 s
Ran all test suites matching /src\/queue\/BullMQ.test.ts/i.
Jest did not exit one second after the test run has completed.

'This usually means that there are asynchronous operations that weren't stopped in your tests. Consider running Jest with `--detectOpenHandles` to troubleshoot this issue.
Done in 33.17s.

Code of Conduct

elyran commented 1 month ago

Please notice the timing. It's 30 seconds. I'd expect worker.close() to completely close Worker. What could it be? Thank you

manast commented 1 month ago

By default worker.close will wait for the current jobs to complete, maybe your jobs are not completing in the test, or taking too much time?

elyran commented 1 month ago

The reproduction code I've added to the issue is the exact copy / paste code that actually reproduces the appearant bug 🙃 No job dispatched, so that option is ruled out. Thank you though 🙏

On Tue, Jul 16, 2024, 12:20 Manuel Astudillo @.***> wrote:

By default worker.close will wait for the current jobs to complete, maybe your jobs are not completing in the test, or taking too much time?

— Reply to this email directly, view it on GitHub https://github.com/taskforcesh/bullmq/issues/2650#issuecomment-2230421538, or unsubscribe https://github.com/notifications/unsubscribe-auth/AAS4AOKII2UVKKGW27HOYFTZMTQU3AVCNFSM6AAAAABK3PH4EGVHI2DSMVQWIX3LMV43OSLTON2WKQ3PNVWWK3TUHMZDEMZQGQZDCNJTHA . You are receiving this because you authored the thread.Message ID: @.***>

manast commented 1 month ago

I have been able to reproduce this and after a few hours trying with wtfnode I managed to improve it a bit but it all seems to boil down in that IORedis is not able to close itself perfectly every time, it may be the case that eventually it closes all the sockets but not within that second that jest is expecting it to. So not sure how to handle it, unfortunately. I will merge a PR with my improvements anyway...

manast commented 1 month ago

Another thing, using --detectOpenHandles as Jests suggests does not work so well either, it does not give you any further information, BUT it does not give the error either so maybe a workaround is to use that flag all the time :)

elyran commented 1 month ago

I also tried with wtfnode, didn't notice.. And I do want the warning. I want to escalate the issue to IORedis, but I'm not sure how to make the code to reproduce it, isolate it. This clearly impacts BullMQ. Any suggestion?

manast commented 2 weeks ago

We could finally merge the PR #2656 after Dragonfly fixed an issue that prevented the tests from running. Hopefully the close sequence is more robust now.

manast commented 2 weeks ago

I am closing now, please re-open if it is not working for you.