kachow6
kachow6

Reputation: 1711

ioredis connection keeps resetting when connecting to local redis cluster from docker container

I have a docker compose containerized client/server node app that is failing to create a stable connection to a redis cluster I have running on my local environment. The redis cluster has 6 nodes (3 master, 3 replica configuration) running on my local machine. Every time I start my app and attempt to connect to redis, the connect event is spammed and I get the following error on my client:

Proxy error: Could not proxy request /check-login from localhost:3000 to http://server.
See https://nodejs.org/api/errors.html#errors_common_system_errors for more information (ECONNRESET)

I have made sure to configure the redis cluster to have the settings protected-mode to no and bind to 0.0.0.0 to allow remote access to the cluster. I have confirmed that I can access the cluster locally by pinging one of the cluster nodes redis-cli -h 127.0.0.1 -p 30001:

127.0.0.1:30001> ping
PONG
127.0.0.1:30001> exit

I am setting my REDIS_HOSTS environment to be "host.docker.internal:30001,host.docker.internal:30005,host.docker.internal:30006". This should allow me to connect to my redis cluster running at 127.0.0.1 on my host machine. My node application code:

const Redis = require("ioredis");

const hosts = process.env.REDIS_HOSTS.split(",").map((connection) => {
  const [host, port] = connection.split(":");

  return {
    host,
    port,
  };
});

const client = new Redis.Cluster(hosts, {
  enableAutoPipelining: true,
  slotsRefreshTimeout: 100000,
});

client.on("error", (error) => {
  console.log("redis connection failed: ", error);
});

client.on("connect", () => {
  console.log("redis connection established");
});

module.exports = client;

My ioredis logs:

2022-02-11T23:52:09.970Z ioredis:cluster status: [empty] -> connecting
info: Listening on port 80
2022-02-11T23:52:15.449Z ioredis:cluster resolved hostname host.docker.internal to IP 192.168.65.2
2022-02-11T23:52:15.476Z ioredis:cluster:connectionPool Reset with [
  { host: '192.168.65.2', port: 30001 },
  { host: '192.168.65.2', port: 30002 },
  { host: '192.168.65.2', port: 30003 }
]
2022-02-11T23:52:15.482Z ioredis:cluster:connectionPool Connecting to 192.168.65.2:30001 as master
2022-02-11T23:52:15.504Z ioredis:redis status[192.168.65.2:30001]: [empty] -> wait
2022-02-11T23:52:15.511Z ioredis:cluster:connectionPool Connecting to 192.168.65.2:30002 as master
2022-02-11T23:52:15.517Z ioredis:redis status[192.168.65.2:30002]: [empty] -> wait
2022-02-11T23:52:15.519Z ioredis:cluster:connectionPool Connecting to 192.168.65.2:30003 as master
2022-02-11T23:52:15.521Z ioredis:redis status[192.168.65.2:30003]: [empty] -> wait
2022-02-11T23:52:15.530Z ioredis:cluster getting slot cache from 192.168.65.2:30002
2022-02-11T23:52:15.541Z ioredis:redis status[192.168.65.2:30002 (ioredis-cluster(refresher))]: [empty] -> wait
2022-02-11T23:52:15.590Z ioredis:redis status[192.168.65.2:30002 (ioredis-cluster(refresher))]: wait -> connecting
2022-02-11T23:52:15.603Z ioredis:redis queue command[192.168.65.2:30002 (ioredis-cluster(refresher))]: 0 -> cluster([ 'slots' ])
2022-02-11T23:52:15.614Z ioredis:cluster:subscriber selected a subscriber 192.168.65.2:30001
2022-02-11T23:52:15.621Z ioredis:redis status[192.168.65.2:30001 (ioredis-cluster(subscriber))]: [empty] -> wait
2022-02-11T23:52:15.622Z ioredis:cluster:subscriber started
2022-02-11T23:52:15.734Z ioredis:redis status[192.168.65.2:30002 (ioredis-cluster(refresher))]: connecting -> connect
2022-02-11T23:52:15.737Z ioredis:redis status[192.168.65.2:30002 (ioredis-cluster(refresher))]: connect -> ready
2022-02-11T23:52:15.739Z ioredis:connection set the connection name [ioredis-cluster(refresher)]
2022-02-11T23:52:15.742Z ioredis:redis write command[192.168.65.2:30002 (ioredis-cluster(refresher))]: 0 -> client([ 'setname', 'ioredis-cluster(refresher)' ])
2022-02-11T23:52:15.749Z ioredis:connection send 1 commands in offline queue
2022-02-11T23:52:15.750Z ioredis:redis write command[192.168.65.2:30002 (ioredis-cluster(refresher))]: 0 -> cluster([ 'slots' ])
2022-02-11T23:52:15.781Z ioredis:cluster cluster slots result count: 3
2022-02-11T23:52:15.783Z ioredis:cluster cluster slots result [0]: slots 0~5460 served by [ '127.0.0.1:30001', '127.0.0.1:30004' ]
2022-02-11T23:52:15.788Z ioredis:cluster cluster slots result [1]: slots 5461~10922 served by [ '127.0.0.1:30002', '127.0.0.1:30005' ]
2022-02-11T23:52:15.792Z ioredis:cluster cluster slots result [2]: slots 10923~16383 served by [ '127.0.0.1:30003', '127.0.0.1:30006' ]
2022-02-11T23:52:15.849Z ioredis:cluster:connectionPool Reset with [
  { host: '127.0.0.1', port: 30001, readOnly: false },
  { host: '127.0.0.1', port: 30004, readOnly: true },
  { host: '127.0.0.1', port: 30002, readOnly: false },
  { host: '127.0.0.1', port: 30005, readOnly: true },
  { host: '127.0.0.1', port: 30003, readOnly: false },
  { host: '127.0.0.1', port: 30006, readOnly: true }
]
2022-02-11T23:52:15.850Z ioredis:cluster:connectionPool Disconnect 192.168.65.2:30001 because the node does not hold any slot
2022-02-11T23:52:15.851Z ioredis:redis status[192.168.65.2:30001]: wait -> close
2022-02-11T23:52:15.851Z ioredis:connection skip reconnecting since the connection is manually closed.
2022-02-11T23:52:15.852Z ioredis:redis status[192.168.65.2:30001]: close -> end
2022-02-11T23:52:15.857Z ioredis:cluster:connectionPool Remove 192.168.65.2:30001 from the pool
2022-02-11T23:52:15.858Z ioredis:cluster:connectionPool Disconnect 192.168.65.2:30002 because the node does not hold any slot
2022-02-11T23:52:15.858Z ioredis:redis status[192.168.65.2:30002]: wait -> close
2022-02-11T23:52:15.859Z ioredis:connection skip reconnecting since the connection is manually closed.
2022-02-11T23:52:15.859Z ioredis:redis status[192.168.65.2:30002]: close -> end
2022-02-11T23:52:15.861Z ioredis:cluster:connectionPool Remove 192.168.65.2:30002 from the pool
2022-02-11T23:52:15.861Z ioredis:cluster:connectionPool Disconnect 192.168.65.2:30003 because the node does not hold any slot
2022-02-11T23:52:15.861Z ioredis:redis status[192.168.65.2:30003]: wait -> close
2022-02-11T23:52:15.865Z ioredis:connection skip reconnecting since the connection is manually closed.
2022-02-11T23:52:15.866Z ioredis:redis status[192.168.65.2:30003]: close -> end
2022-02-11T23:52:15.866Z ioredis:cluster:connectionPool Remove 192.168.65.2:30003 from the pool
2022-02-11T23:52:15.867Z ioredis:cluster:connectionPool Connecting to 127.0.0.1:30001 as master
2022-02-11T23:52:15.869Z ioredis:redis status[127.0.0.1:30001]: [empty] -> wait
2022-02-11T23:52:15.871Z ioredis:cluster:connectionPool Connecting to 127.0.0.1:30004 as slave
2022-02-11T23:52:15.873Z ioredis:redis status[127.0.0.1:30004]: [empty] -> wait
2022-02-11T23:52:15.874Z ioredis:cluster:connectionPool Connecting to 127.0.0.1:30002 as master
2022-02-11T23:52:15.877Z ioredis:redis status[127.0.0.1:30002]: [empty] -> wait
2022-02-11T23:52:15.877Z ioredis:cluster:connectionPool Connecting to 127.0.0.1:30005 as slave
2022-02-11T23:52:15.882Z ioredis:redis status[127.0.0.1:30005]: [empty] -> wait
2022-02-11T23:52:15.883Z ioredis:cluster:connectionPool Connecting to 127.0.0.1:30003 as master
2022-02-11T23:52:15.885Z ioredis:redis status[127.0.0.1:30003]: [empty] -> wait
2022-02-11T23:52:15.886Z ioredis:cluster:connectionPool Connecting to 127.0.0.1:30006 as slave
2022-02-11T23:52:15.887Z ioredis:redis status[127.0.0.1:30006]: [empty] -> wait
2022-02-11T23:52:15.893Z ioredis:cluster status: connecting -> connect
2022-02-11T23:52:15.904Z ioredis:redis status[127.0.0.1:30002]: wait -> connecting
2022-02-11T23:52:15.906Z ioredis:redis queue command[127.0.0.1:30002]: 0 -> cluster([ 'info' ])
2022-02-11T23:52:15.916Z ioredis:cluster:subscriber subscriber has left, selecting a new one...
2022-02-11T23:52:15.917Z ioredis:redis status[192.168.65.2:30001 (ioredis-cluster(subscriber))]: wait -> close
2022-02-11T23:52:15.918Z ioredis:connection skip reconnecting since the connection is manually closed.
2022-02-11T23:52:15.918Z ioredis:redis status[192.168.65.2:30001 (ioredis-cluster(subscriber))]: close -> end
2022-02-11T23:52:15.919Z ioredis:cluster:subscriber selected a subscriber 127.0.0.1:30004
2022-02-11T23:52:15.921Z ioredis:redis status[127.0.0.1:30004 (ioredis-cluster(subscriber))]: [empty] -> wait
2022-02-11T23:52:16.000Z ioredis:connection error: { Error: connect ECONNREFUSED 127.0.0.1:30002
    at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1148:16)
  errno: -111,
  code: 'ECONNREFUSED',
  syscall: 'connect',
  address: '127.0.0.1',
  port: 30002 }
2022-02-11T23:52:16.030Z ioredis:redis status[127.0.0.1:30002]: connecting -> close
2022-02-11T23:52:16.031Z ioredis:connection skip reconnecting because `retryStrategy` is not a function
2022-02-11T23:52:16.032Z ioredis:redis status[127.0.0.1:30002]: close -> end
2022-02-11T23:52:16.034Z ioredis:cluster:connectionPool Remove 127.0.0.1:30002 from the pool
2022-02-11T23:52:16.036Z ioredis:cluster Ready check failed (Error: Connection is closed.
    at close (/usr/src/app/node_modules/ioredis/built/redis/event_handler.js:184:25)
    at Socket.<anonymous> (/usr/src/app/node_modules/ioredis/built/redis/event_handler.js:155:20)
    at Object.onceWrapper (events.js:520:26)
    at Socket.emit (events.js:400:28)
    at Socket.emit (domain.js:470:12)
    at TCP.<anonymous> (net.js:675:12)). Reconnecting...
2022-02-11T23:52:16.042Z ioredis:cluster status: connect -> disconnecting
...

Upvotes: 7

Views: 10617

Answers (1)

kachow6
kachow6

Reputation: 1711

The clue to the solution was found in the following log snippet:

2022-02-11T23:52:15.750Z ioredis:redis write command[192.168.65.2:30002 (ioredis-cluster(refresher))]: 0 -> cluster([ 'slots' ])
2022-02-11T23:52:15.781Z ioredis:cluster cluster slots result count: 3
2022-02-11T23:52:15.783Z ioredis:cluster cluster slots result [0]: slots 0~5460 served by [ '127.0.0.1:30001', '127.0.0.1:30004' ]
2022-02-11T23:52:15.788Z ioredis:cluster cluster slots result [1]: slots 5461~10922 served by [ '127.0.0.1:30002', '127.0.0.1:30005' ]
2022-02-11T23:52:15.792Z ioredis:cluster cluster slots result [2]: slots 10923~16383 served by [ '127.0.0.1:30003', '127.0.0.1:30006' ]

The internal redis cluster network was still communicating between nodes on network address 127.0.0.1, creating the connect ECONNREFUSED errors when the ioredis client attempted to use those network mappings to establish the cluster connection.

I had to use the natMap option in the ioredis client to remap the internal cluster network connections to the network address of the docker container:

let natMap = {};
const localHost = "127.0.0.1";

const hosts = process.env.REDIS_HOSTS.split(",").map((connection) => {
  const [host, port] = connection.split(":");

  // assign nat host address mappings
  // when accessing local redis cluster from containerized network
  natMap[`${localHost}:${port}`] = { host, port };

  return {
    host,
    port,
  };
});

// natMap output
// {
//   "127.0.0.1:30001": { host: "docker.internal.network", port: 30001 },
//   "127.0.0.1:30002": { host: "docker.internal.network", port: 30002 },
//   "127.0.0.1:30003": { host: "docker.internal.network", port: 30003 },
// }

// create redis cluster client
const client = new Redis.Cluster(hosts, {
  enableAutoPipelining: true,
  slotsRefreshTimeout: 100000,
  natMap,
});

Upvotes: 8

Related Questions