Automattic / kue

Kue is a priority job queue backed by redis, built for node.js.
http://automattic.github.io/kue
MIT License
9.45k stars 862 forks source link

Error: Connection is closed when shutdown ioredis cluster #1246

Open joebowbeer opened 4 years ago

joebowbeer commented 4 years ago

I am seeing an UnhandledPromiseRejectionWarning (Error: Connection is closed) when calling kue shutdown. This happens when I'm using an ioredis client with an ElastiCache cluster.

See debug output below. It looks like quit is being called twice.

I think I can see where this is happening:

https://github.com/Automattic/kue/blob/master/lib/kue.js#L396

First redis.reset() calls quit and then quit is called again in the next line.

020-06-21T23:31:44.314Z ioredis:cluster status: ready -> disconnecting
2020-06-21T23:31:44.314Z ioredis:cluster:subscriber stopped
2020-06-21T23:31:44.315Z ioredis:redis write command[]: 0 -> quit([])
2020-06-21T23:31:44.315Z ioredis:redis status[cluster-staging-0001-002]: wait -> connecting
2020-06-21T23:31:44.315Z ioredis:redis status[cluster-staging-0001-003]: wait -> connecting
2020-06-21T23:31:44.316Z ioredis:cluster status: ready -> disconnecting
2020-06-21T23:31:44.316Z ioredis:redis status[cluster-staging-0001-002]: wait -> close
2020-06-21T23:31:44.316Z ioredis:connection skip reconnecting since the connection is manually closed.
2020-06-21T23:31:44.316Z ioredis:redis status[cluster-staging-0001-002]: close -> end
2020-06-21T23:31:44.316Z ioredis:cluster:subscriber stopped
2020-06-21T23:31:44.316Z ioredis:redis write command[]: 0 -> quit([])
2020-06-21T23:31:44.316Z ioredis:redis status[cluster-staging-0001-002]: wait -> connecting
2020-06-21T23:31:44.317Z ioredis:redis status[cluster-staging-0001-003]: wait -> connecting
2020-06-21T23:31:44.317Z ioredis:redis status[cluster-staging-0001-002]: connecting -> end
2020-06-21T23:31:44.317Z ioredis:redis status[cluster-staging-0001-003]: connecting -> end
2020-06-21T23:31:44.317Z ioredis:redis status[cluster-staging-0001-002]: connecting -> end
2020-06-21T23:31:44.318Z ioredis:redis status[cluster-staging-0001-003]: connecting -> end
2020-06-21T23:31:44.318Z ioredis:cluster:connectionPool Remove cluster-staging-0001-002
2020-06-21T23:31:44.318Z ioredis:cluster:connectionPool Remove cluster-staging-0001-003
2020-06-21T23:31:44.318Z ioredis:cluster:connectionPool Remove cluster-staging-0001-002
2020-06-21T23:31:44.318Z ioredis:cluster:connectionPool Remove cluster-staging-0001-003
queue shutdown complete
2020-06-21T23:31:44.319Z ioredis:redis status[]: ready -> close
2020-06-21T23:31:44.319Z ioredis:connection skip reconnecting since the connection is manually closed.
2020-06-21T23:31:44.319Z ioredis:redis status[]: close -> end
2020-06-21T23:31:44.319Z ioredis:cluster:connectionPool Remove cluster-staging-0001-001
2020-06-21T23:31:44.319Z ioredis:cluster status: disconnecting -> close
2020-06-21T23:31:44.320Z ioredis:redis status[]: ready -> close
2020-06-21T23:31:44.320Z ioredis:connection skip reconnecting since the connection is manually closed.
2020-06-21T23:31:44.320Z ioredis:redis status[]: close -> end
2020-06-21T23:31:44.320Z ioredis:cluster:connectionPool Remove cluster-staging-0001-001
2020-06-21T23:31:44.320Z ioredis:cluster status: disconnecting -> close
Redis connection close
2020-06-21T23:31:44.321Z ioredis:cluster status: close -> end
2020-06-21T23:31:44.336Z ioredis:connection error: Error: Client network socket disconnected before secure TLS connection was established
    at connResetException (internal/errors.js:609:14)
    at TLSSocket.onConnectEnd (_tls_wrap.js:1547:19)
    at Object.onceWrapper (events.js:421:28)
    at TLSSocket.emit (events.js:327:22)
    at endReadableNT (_stream_readable.js:1221:12)
    at processTicksAndRejections (internal/process/task_queues.js:84:21) {
  code: 'ECONNRESET',
  path: undefined,
  host: 'cluster-staging-0001-002',
  port: 6379,
  localAddress: undefined
}
2020-06-21T23:31:44.337Z ioredis:redis status[cluster-staging-0001-002]: connecting -> close
2020-06-21T23:31:44.338Z ioredis:connection skip reconnecting since the connection is manually closed.
2020-06-21T23:31:44.338Z ioredis:redis status[cluster-staging-0001-002]: close -> end
(node:1) UnhandledPromiseRejectionWarning: Error: Connection is closed.
    at close (/usr/src/app/node_modules/ioredis/built/redis/event_handler.js:179:25)
    at TLSSocket.<anonymous> (/usr/src/app/node_modules/ioredis/built/redis/event_handler.js:146:20)
    at Object.onceWrapper (events.js:422:26)
    at TLSSocket.emit (events.js:327:22)
    at net.js:674:12
    at TCP.done (_tls_wrap.js:567:7)