redis / ioredis

🚀 A robust, performance-focused, and full-featured Redis client for Node.js.
MIT License
14.07k stars 1.19k forks source link

Disconnecting a blocking client with dragonfly takes 2 seconds #1820

Closed manast closed 3 months ago

manast commented 9 months ago

I managed to produce an issue when testing Dragonfly, namely that it takes quite accurately 2 seconds to disconnect a Redis client that has issued a blocking command.

How to reproduce

Run a local dragonfly server using the following (tested on MacOs, epoll is needed in MacOs):

docker run -p 6379:6379 --ulimit memlock=-1 docker.dragonflydb.io/dragonflydb/dragonfly --force_epoll

Then run this js script:

const IORedis = require("ioredis");

const client = new IORedis();

client.xread("BLOCK", 10000, "STREAMS", "test", "$");

setTimeout(() => {
  console.log("Waiting for disconnect...");
  const start = Date.now();

  client.once("end", () => {
    console.log("Disconnected after", Date.now() - start, "ms");
  });

  client.disconnect();
}, 20);

Results in the following:

node block-client-disconnect.js
Waiting for disconnect...
Disconnected after 2003 ms
/Users/manuelastudillo/Dev/taskforce/bullmq-bugs/node_modules/ioredis/built/redis/event_handler.js:189
        self.flushQueue(new Error(utils_1.CONNECTION_CLOSED_ERROR_MSG));
                        ^

Error: Connection is closed.
    at close (/Users/manuelastudillo/Dev/taskforce/bullmq-bugs/node_modules/ioredis/built/redis/event_handler.js:189:25)
    at Socket.<anonymous> (/Users/manuelastudillo/Dev/taskforce/bullmq-bugs/node_modules/ioredis/built/redis/event_handler.js:156:20)
    at Object.onceWrapper (node:events:628:26)
    at Socket.emit (node:events:525:35)
    at TCP.<anonymous> (node:net:313:12)

Node.js v18.10.0

Using a standard Redis server disconnects in 3ms. If we skip issuing the blocking command, it also disconnects in 3ms using Dragonfly.

I don't know if this is an issue with dragonfly or IORedis, I can crosslink this issue if it results to be an issue with Dragonfly.

Why is this important?

When running BullMQ tests you normally need to disconnect after every test. If the test required a blocking command, the extra 2 seconds make the test timeout in some cases, but still even if it didn't timeout the tests would run much slower.

manast commented 9 months ago

UPDATE: I tried with node-redis and it does not exhibit this behavior:


const { createClient } = require("redis");
const client = new createClient();
client.connect();

client.xRead([
    {
      key: 'test',
      id: "$"
    }
  ], {
    BLOCK: 10000
  })

setTimeout(() => {
  console.log("Waiting for disconnect...");
  const start = Date.now();

  client.once("end", () => {
    console.log("Disconnected after", Date.now() - start, "ms");
  });

  client.disconnect();
}, 20);
 node block-client-disconnect.js
Waiting for disconnect...
Disconnected after 6 ms
/Users/manuelastudillo/Dev/taskforce/bullmq-bugs/node_modules/@redis/client/dist/lib/client/index.js:465
        this.#queue.flushAll(new errors_1.DisconnectsClientError());
                             ^

DisconnectsClientError: Disconnects client
    at Commander.disconnect (/Users/manuelastudillo/Dev/taskforce/bullmq-bugs/node_modules/@redis/client/dist/lib/client/index.js:465:30)
    at Timeout._onTimeout (/Users/manuelastudillo/Dev/taskforce/bullmq-bugs/block-client-disconnect.js:25:10)
    at listOnTimeout (node:internal/timers:564:17)
    at process.processTimers (node:internal/timers:507:7)

Node.js v18.10.0
romange commented 9 months ago

@manast Thank you for finding this! We are investigating whether it's on Dragonfly side.

adiholden commented 9 months ago

@manast We found the problem, it's in Dragonfly and we are working on a fix. Thank you.

manast commented 3 months ago

Closed as this was fixed long time ago.