-
Notifications
You must be signed in to change notification settings - Fork 1.2k
New issue
Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.
By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.
Already on GitHub? Sign in to your account
Cluster mode connections growing over time #1449
Comments
To give an idea, since I created this issue yesterday (about 17hours ago) the number of connections went from ~180 to ~280 Might be useful to know that out of our 16 servers, 8 are for production and 8 are for beta. Whenever we redeploy to the beta servers, the connections barely changes, which seems to hint that our production servers are using pretty much all the connections. So I'm guessing that work load probably have an impact
|
Maybe somehow related to duplication of connection introduced in 4.9.5 (#867): |
Maybe I'm reading this wrong, but should it seems the duplicate connection should have a different connection name, which I'm not seeing in the |
Yes, you are right, connection name should contain "refresher", but does not in your case. |
I've just instrumented our code to log on |
We are logging tons of |
I added
|
Here's logs of the booting sequence Not sure if a problem but I find it interesting that it initially connects to all nodes as master and waits for first refresh to determine which really are master and which are slaves. 2021-10-29 17:41:14.520 +00:00: 2021-10-29T17:41:14.520Z ioredis:cluster status: [empty] -> connecting
--
2021-10-29 17:41:14.521 +00:00: 2021-10-29T17:41:14.521Z ioredis:cluster resolved hostname mx-prod-app-redis-0001-001.mx-prod-app-redis.gzcra2.usw2.cache.amazonaws.com to IP mx-prod-app-redis-0001-001.mx-prod-app-redis.gzcra2.usw2.cache.amazonaws.com
2021-10-29 17:41:14.521 +00:00: 2021-10-29T17:41:14.521Z ioredis:cluster resolved hostname mx-prod-app-redis-0001-002.mx-prod-app-redis.gzcra2.usw2.cache.amazonaws.com to IP mx-prod-app-redis-0001-002.mx-prod-app-redis.gzcra2.usw2.cache.amazonaws.com
2021-10-29 17:41:14.521 +00:00: 2021-10-29T17:41:14.521Z ioredis:cluster resolved hostname mx-prod-app-redis-0002-001.mx-prod-app-redis.gzcra2.usw2.cache.amazonaws.com to IP mx-prod-app-redis-0002-001.mx-prod-app-redis.gzcra2.usw2.cache.amazonaws.com
2021-10-29 17:41:14.521 +00:00: 2021-10-29T17:41:14.521Z ioredis:cluster resolved hostname mx-prod-app-redis-0002-002.mx-prod-app-redis.gzcra2.usw2.cache.amazonaws.com to IP mx-prod-app-redis-0002-002.mx-prod-app-redis.gzcra2.usw2.cache.amazonaws.com
2021-10-29 17:41:14.522 +00:00: 2021-10-29T17:41:14.522Z ioredis:cluster status: [empty] -> connecting
2021-10-29 17:41:14.522 +00:00: 2021-10-29T17:41:14.522Z ioredis:cluster resolved hostname mx-prod-app-redis-0001-001.mx-prod-app-redis.gzcra2.usw2.cache.amazonaws.com to IP mx-prod-app-redis-0001-001.mx-prod-app-redis.gzcra2.usw2.cache.amazonaws.com
2021-10-29 17:41:14.522 +00:00: 2021-10-29T17:41:14.522Z ioredis:cluster resolved hostname mx-prod-app-redis-0001-002.mx-prod-app-redis.gzcra2.usw2.cache.amazonaws.com to IP mx-prod-app-redis-0001-002.mx-prod-app-redis.gzcra2.usw2.cache.amazonaws.com
2021-10-29 17:41:14.522 +00:00: 2021-10-29T17:41:14.522Z ioredis:cluster resolved hostname mx-prod-app-redis-0002-001.mx-prod-app-redis.gzcra2.usw2.cache.amazonaws.com to IP mx-prod-app-redis-0002-001.mx-prod-app-redis.gzcra2.usw2.cache.amazonaws.com
2021-10-29 17:41:14.522 +00:00: 2021-10-29T17:41:14.522Z ioredis:cluster resolved hostname mx-prod-app-redis-0002-002.mx-prod-app-redis.gzcra2.usw2.cache.amazonaws.com to IP mx-prod-app-redis-0002-002.mx-prod-app-redis.gzcra2.usw2.cache.amazonaws.com
2021-10-29 17:41:14.523 +00:00: 2021-10-29T17:41:14.523Z ioredis:cluster status: [empty] -> connecting
2021-10-29 17:41:14.523 +00:00: 2021-10-29T17:41:14.523Z ioredis:cluster resolved hostname mx-prod-app-redis-0001-001.mx-prod-app-redis.gzcra2.usw2.cache.amazonaws.com to IP mx-prod-app-redis-0001-001.mx-prod-app-redis.gzcra2.usw2.cache.amazonaws.com
2021-10-29 17:41:14.523 +00:00: 2021-10-29T17:41:14.523Z ioredis:cluster resolved hostname mx-prod-app-redis-0001-002.mx-prod-app-redis.gzcra2.usw2.cache.amazonaws.com to IP mx-prod-app-redis-0001-002.mx-prod-app-redis.gzcra2.usw2.cache.amazonaws.com
2021-10-29 17:41:14.524 +00:00: 2021-10-29T17:41:14.524Z ioredis:cluster resolved hostname mx-prod-app-redis-0002-001.mx-prod-app-redis.gzcra2.usw2.cache.amazonaws.com to IP mx-prod-app-redis-0002-001.mx-prod-app-redis.gzcra2.usw2.cache.amazonaws.com
2021-10-29 17:41:14.524 +00:00: 2021-10-29T17:41:14.524Z ioredis:cluster resolved hostname mx-prod-app-redis-0002-002.mx-prod-app-redis.gzcra2.usw2.cache.amazonaws.com to IP mx-prod-app-redis-0002-002.mx-prod-app-redis.gzcra2.usw2.cache.amazonaws.com
2021-10-29 17:41:14.524 +00:00: 2021-10-29T17:41:14.524Z ioredis:cluster status: [empty] -> connecting
2021-10-29 17:41:14.524 +00:00: 2021-10-29T17:41:14.524Z ioredis:cluster resolved hostname mx-prod-app-redis-0001-001.mx-prod-app-redis.gzcra2.usw2.cache.amazonaws.com to IP mx-prod-app-redis-0001-001.mx-prod-app-redis.gzcra2.usw2.cache.amazonaws.com
2021-10-29 17:41:14.524 +00:00: 2021-10-29T17:41:14.524Z ioredis:cluster resolved hostname mx-prod-app-redis-0001-002.mx-prod-app-redis.gzcra2.usw2.cache.amazonaws.com to IP mx-prod-app-redis-0001-002.mx-prod-app-redis.gzcra2.usw2.cache.amazonaws.com
2021-10-29 17:41:14.524 +00:00: 2021-10-29T17:41:14.524Z ioredis:cluster resolved hostname mx-prod-app-redis-0002-001.mx-prod-app-redis.gzcra2.usw2.cache.amazonaws.com to IP mx-prod-app-redis-0002-001.mx-prod-app-redis.gzcra2.usw2.cache.amazonaws.com
2021-10-29 17:41:14.524 +00:00: 2021-10-29T17:41:14.524Z ioredis:cluster resolved hostname mx-prod-app-redis-0002-002.mx-prod-app-redis.gzcra2.usw2.cache.amazonaws.com to IP mx-prod-app-redis-0002-002.mx-prod-app-redis.gzcra2.usw2.cache.amazonaws.com
2021-10-29 17:41:15.464 +00:00: 2021-10-29T17:41:15.464Z ioredis:cluster:connectionPool Reset with [ { port: 6379, host: 'mx-prod-app-redis-0001-001.mx-prod-app-redis.gzcra2.usw2.cache.amazonaws.com' }, { port: 6379, host: 'mx-prod-app-redis-0001-002.mx-prod-app-redis.gzcra2.usw2.cache.amazonaws.com' }, { port: 6379, host: 'mx-prod-app-redis-0002-001.mx-prod-app-redis.gzcra2.usw2.cache.amazonaws.com' }, { port: 6379, host: 'mx-prod-app-redis-0002-002.mx-prod-app-redis.gzcra2.usw2.cache.amazonaws.com' }]
2021-10-29 17:41:15.464 +00:00: 2021-10-29T17:41:15.464Z ioredis:cluster:connectionPool Connecting to mx-prod-app-redis-0001-001.mx-prod-app-redis.gzcra2.usw2.cache.amazonaws.com:6379 as master
2021-10-29 17:41:15.465 +00:00: 2021-10-29T17:41:15.465Z ioredis:redis status[mx-prod-app-redis-0001-001.mx-prod-app-redis.gzcra2.usw2.cache.amazonaws.com:6379 (cache)]: [empty] -> wait
2021-10-29 17:41:15.472 +00:00: info: ioredis:cluster:node
2021-10-29 17:41:15.473 +00:00: 2021-10-29T17:41:15.473Z ioredis:cluster:connectionPool Connecting to mx-prod-app-redis-0001-002.mx-prod-app-redis.gzcra2.usw2.cache.amazonaws.com:6379 as master
2021-10-29 17:41:15.473 +00:00: 2021-10-29T17:41:15.473Z ioredis:redis status[mx-prod-app-redis-0001-002.mx-prod-app-redis.gzcra2.usw2.cache.amazonaws.com:6379 (cache)]: [empty] -> wait
2021-10-29 17:41:15.475 +00:00: info: ioredis:cluster:node
2021-10-29 17:41:15.475 +00:00: 2021-10-29T17:41:15.475Z ioredis:cluster:connectionPool Connecting to mx-prod-app-redis-0002-001.mx-prod-app-redis.gzcra2.usw2.cache.amazonaws.com:6379 as master
2021-10-29 17:41:15.476 +00:00: 2021-10-29T17:41:15.475Z ioredis:redis status[mx-prod-app-redis-0002-001.mx-prod-app-redis.gzcra2.usw2.cache.amazonaws.com:6379 (cache)]: [empty] -> wait
2021-10-29 17:41:15.477 +00:00: info: ioredis:cluster:node
2021-10-29 17:41:15.478 +00:00: 2021-10-29T17:41:15.478Z ioredis:cluster:connectionPool Connecting to mx-prod-app-redis-0002-002.mx-prod-app-redis.gzcra2.usw2.cache.amazonaws.com:6379 as master
2021-10-29 17:41:15.478 +00:00: 2021-10-29T17:41:15.478Z ioredis:redis status[mx-prod-app-redis-0002-002.mx-prod-app-redis.gzcra2.usw2.cache.amazonaws.com:6379 (cache)]: [empty] -> wait
2021-10-29 17:41:15.480 +00:00: info: ioredis:cluster:node
2021-10-29 17:41:15.480 +00:00: 2021-10-29T17:41:15.480Z ioredis:cluster getting slot cache from mx-prod-app-redis-0002-002.mx-prod-app-redis.gzcra2.usw2.cache.amazonaws.com:6379
2021-10-29 17:41:15.481 +00:00: 2021-10-29T17:41:15.481Z ioredis:redis status[mx-prod-app-redis-0002-002.mx-prod-app-redis.gzcra2.usw2.cache.amazonaws.com:6379 (ioredis-cluster(refresher):cache)]: [empty] -> wait
2021-10-29 17:41:15.483 +00:00: 2021-10-29T17:41:15.482Z ioredis:redis status[mx-prod-app-redis-0002-002.mx-prod-app-redis.gzcra2.usw2.cache.amazonaws.com:6379 (ioredis-cluster(refresher):cache)]: wait -> connecting
2021-10-29 17:41:15.483 +00:00: 2021-10-29T17:41:15.483Z ioredis:redis queue command[mx-prod-app-redis-0002-002.mx-prod-app-redis.gzcra2.usw2.cache.amazonaws.com:6379 (ioredis-cluster(refresher):cache)]: 0 -> cluster([ 'slots' ])
2021-10-29 17:41:15.484 +00:00: 2021-10-29T17:41:15.484Z ioredis:cluster:subscriber selected a subscriber mx-prod-app-redis-0001-002.mx-prod-app-redis.gzcra2.usw2.cache.amazonaws.com:6379
2021-10-29 17:41:15.484 +00:00: 2021-10-29T17:41:15.484Z ioredis:redis status[mx-prod-app-redis-0001-002.mx-prod-app-redis.gzcra2.usw2.cache.amazonaws.com:6379 (ioredis-cluster(subscriber):cache)]: [empty] -> wait
2021-10-29 17:41:15.484 +00:00: 2021-10-29T17:41:15.484Z ioredis:cluster:subscriber started
2021-10-29 17:41:15.484 +00:00: 2021-10-29T17:41:15.484Z ioredis:cluster:connectionPool Reset with [ { port: 6379, host: 'mx-prod-app-redis-0001-001.mx-prod-app-redis.gzcra2.usw2.cache.amazonaws.com' }, { port: 6379, host: 'mx-prod-app-redis-0001-002.mx-prod-app-redis.gzcra2.usw2.cache.amazonaws.com' }, { port: 6379, host: 'mx-prod-app-redis-0002-001.mx-prod-app-redis.gzcra2.usw2.cache.amazonaws.com' }, { port: 6379, host: 'mx-prod-app-redis-0002-002.mx-prod-app-redis.gzcra2.usw2.cache.amazonaws.com' }]
2021-10-29 17:41:15.484 +00:00: 2021-10-29T17:41:15.484Z ioredis:cluster:connectionPool Connecting to mx-prod-app-redis-0001-001.mx-prod-app-redis.gzcra2.usw2.cache.amazonaws.com:6379 as master
2021-10-29 17:41:15.485 +00:00: 2021-10-29T17:41:15.485Z ioredis:redis status[mx-prod-app-redis-0001-001.mx-prod-app-redis.gzcra2.usw2.cache.amazonaws.com:6379 (locks)]: [empty] -> wait
2021-10-29 17:41:15.503 +00:00: info: ioredis:cluster:node
2021-10-29 17:41:15.503 +00:00: 2021-10-29T17:41:15.503Z ioredis:cluster:connectionPool Connecting to mx-prod-app-redis-0001-002.mx-prod-app-redis.gzcra2.usw2.cache.amazonaws.com:6379 as master
2021-10-29 17:41:15.504 +00:00: 2021-10-29T17:41:15.504Z ioredis:redis status[mx-prod-app-redis-0001-002.mx-prod-app-redis.gzcra2.usw2.cache.amazonaws.com:6379 (locks)]: [empty] -> wait
2021-10-29 17:41:15.506 +00:00: info: ioredis:cluster:node
2021-10-29 17:41:15.506 +00:00: 2021-10-29T17:41:15.506Z ioredis:cluster:connectionPool Connecting to mx-prod-app-redis-0002-001.mx-prod-app-redis.gzcra2.usw2.cache.amazonaws.com:6379 as master
2021-10-29 17:41:15.507 +00:00: 2021-10-29T17:41:15.507Z ioredis:redis status[mx-prod-app-redis-0002-001.mx-prod-app-redis.gzcra2.usw2.cache.amazonaws.com:6379 (locks)]: [empty] -> wait
2021-10-29 17:41:15.509 +00:00: info: ioredis:cluster:node
2021-10-29 17:41:15.509 +00:00: 2021-10-29T17:41:15.509Z ioredis:cluster:connectionPool Connecting to mx-prod-app-redis-0002-002.mx-prod-app-redis.gzcra2.usw2.cache.amazonaws.com:6379 as master
2021-10-29 17:41:15.509 +00:00: 2021-10-29T17:41:15.509Z ioredis:redis status[mx-prod-app-redis-0002-002.mx-prod-app-redis.gzcra2.usw2.cache.amazonaws.com:6379 (locks)]: [empty] -> wait
2021-10-29 17:41:15.511 +00:00: info: ioredis:cluster:node
2021-10-29 17:41:15.512 +00:00: 2021-10-29T17:41:15.512Z ioredis:cluster getting slot cache from mx-prod-app-redis-0002-002.mx-prod-app-redis.gzcra2.usw2.cache.amazonaws.com:6379
2021-10-29 17:41:15.512 +00:00: 2021-10-29T17:41:15.512Z ioredis:redis status[mx-prod-app-redis-0002-002.mx-prod-app-redis.gzcra2.usw2.cache.amazonaws.com:6379 (ioredis-cluster(refresher):locks)]: [empty] -> wait
2021-10-29 17:41:15.513 +00:00: 2021-10-29T17:41:15.513Z ioredis:redis status[mx-prod-app-redis-0002-002.mx-prod-app-redis.gzcra2.usw2.cache.amazonaws.com:6379 (ioredis-cluster(refresher):locks)]: wait -> connecting
2021-10-29 17:41:15.513 +00:00: 2021-10-29T17:41:15.513Z ioredis:redis queue command[mx-prod-app-redis-0002-002.mx-prod-app-redis.gzcra2.usw2.cache.amazonaws.com:6379 (ioredis-cluster(refresher):locks)]: 0 -> cluster([ 'slots' ])
2021-10-29 17:41:15.513 +00:00: 2021-10-29T17:41:15.513Z ioredis:cluster:subscriber selected a subscriber mx-prod-app-redis-0001-001.mx-prod-app-redis.gzcra2.usw2.cache.amazonaws.com:6379
2021-10-29 17:41:15.513 +00:00: 2021-10-29T17:41:15.513Z ioredis:redis status[mx-prod-app-redis-0001-001.mx-prod-app-redis.gzcra2.usw2.cache.amazonaws.com:6379 (ioredis-cluster(subscriber):locks)]: [empty] -> wait
2021-10-29 17:41:15.513 +00:00: 2021-10-29T17:41:15.513Z ioredis:cluster:subscriber started
2021-10-29 17:41:15.514 +00:00: 2021-10-29T17:41:15.514Z ioredis:cluster:connectionPool Reset with [ { port: 6379, host: 'mx-prod-app-redis-0001-001.mx-prod-app-redis.gzcra2.usw2.cache.amazonaws.com' }, { port: 6379, host: 'mx-prod-app-redis-0001-002.mx-prod-app-redis.gzcra2.usw2.cache.amazonaws.com' }, { port: 6379, host: 'mx-prod-app-redis-0002-001.mx-prod-app-redis.gzcra2.usw2.cache.amazonaws.com' }, { port: 6379, host: 'mx-prod-app-redis-0002-002.mx-prod-app-redis.gzcra2.usw2.cache.amazonaws.com' }]
2021-10-29 17:41:15.514 +00:00: 2021-10-29T17:41:15.514Z ioredis:cluster:connectionPool Connecting to mx-prod-app-redis-0001-001.mx-prod-app-redis.gzcra2.usw2.cache.amazonaws.com:6379 as master
2021-10-29 17:41:15.514 +00:00: 2021-10-29T17:41:15.514Z ioredis:redis status[mx-prod-app-redis-0001-001.mx-prod-app-redis.gzcra2.usw2.cache.amazonaws.com:6379 (publisher)]: [empty] -> wait
2021-10-29 17:41:15.516 +00:00: info: ioredis:cluster:node
2021-10-29 17:41:15.516 +00:00: 2021-10-29T17:41:15.516Z ioredis:cluster:connectionPool Connecting to mx-prod-app-redis-0001-002.mx-prod-app-redis.gzcra2.usw2.cache.amazonaws.com:6379 as master
2021-10-29 17:41:15.517 +00:00: 2021-10-29T17:41:15.517Z ioredis:redis status[mx-prod-app-redis-0001-002.mx-prod-app-redis.gzcra2.usw2.cache.amazonaws.com:6379 (publisher)]: [empty] -> wait
2021-10-29 17:41:15.519 +00:00: info: ioredis:cluster:node
2021-10-29 17:41:15.519 +00:00: 2021-10-29T17:41:15.519Z ioredis:cluster:connectionPool Connecting to mx-prod-app-redis-0002-001.mx-prod-app-redis.gzcra2.usw2.cache.amazonaws.com:6379 as master
2021-10-29 17:41:15.519 +00:00: 2021-10-29T17:41:15.519Z ioredis:redis status[mx-prod-app-redis-0002-001.mx-prod-app-redis.gzcra2.usw2.cache.amazonaws.com:6379 (publisher)]: [empty] -> wait
2021-10-29 17:41:15.521 +00:00: info: ioredis:cluster:node
2021-10-29 17:41:15.522 +00:00: 2021-10-29T17:41:15.522Z ioredis:cluster:connectionPool Connecting to mx-prod-app-redis-0002-002.mx-prod-app-redis.gzcra2.usw2.cache.amazonaws.com:6379 as master
2021-10-29 17:41:15.522 +00:00: 2021-10-29T17:41:15.522Z ioredis:redis status[mx-prod-app-redis-0002-002.mx-prod-app-redis.gzcra2.usw2.cache.amazonaws.com:6379 (publisher)]: [empty] -> wait
2021-10-29 17:41:15.524 +00:00: info: ioredis:cluster:node
2021-10-29 17:41:15.524 +00:00: 2021-10-29T17:41:15.524Z ioredis:cluster getting slot cache from mx-prod-app-redis-0001-002.mx-prod-app-redis.gzcra2.usw2.cache.amazonaws.com:6379
2021-10-29 17:41:15.525 +00:00: 2021-10-29T17:41:15.525Z ioredis:redis status[mx-prod-app-redis-0001-002.mx-prod-app-redis.gzcra2.usw2.cache.amazonaws.com:6379 (ioredis-cluster(refresher):publisher)]: [empty] -> wait
2021-10-29 17:41:15.525 +00:00: 2021-10-29T17:41:15.525Z ioredis:redis status[mx-prod-app-redis-0001-002.mx-prod-app-redis.gzcra2.usw2.cache.amazonaws.com:6379 (ioredis-cluster(refresher):publisher)]: wait -> connecting
2021-10-29 17:41:15.525 +00:00: 2021-10-29T17:41:15.525Z ioredis:redis queue command[mx-prod-app-redis-0001-002.mx-prod-app-redis.gzcra2.usw2.cache.amazonaws.com:6379 (ioredis-cluster(refresher):publisher)]: 0 -> cluster([ 'slots' ])
2021-10-29 17:41:15.525 +00:00: 2021-10-29T17:41:15.525Z ioredis:cluster:subscriber selected a subscriber mx-prod-app-redis-0001-001.mx-prod-app-redis.gzcra2.usw2.cache.amazonaws.com:6379
2021-10-29 17:41:15.525 +00:00: 2021-10-29T17:41:15.525Z ioredis:redis status[mx-prod-app-redis-0001-001.mx-prod-app-redis.gzcra2.usw2.cache.amazonaws.com:6379 (ioredis-cluster(subscriber):publisher)]: [empty] -> wait
2021-10-29 17:41:15.525 +00:00: 2021-10-29T17:41:15.525Z ioredis:cluster:subscriber started
2021-10-29 17:41:15.526 +00:00: 2021-10-29T17:41:15.526Z ioredis:cluster:connectionPool Reset with [ { port: 6379, host: 'mx-prod-app-redis-0001-001.mx-prod-app-redis.gzcra2.usw2.cache.amazonaws.com' }, { port: 6379, host: 'mx-prod-app-redis-0001-002.mx-prod-app-redis.gzcra2.usw2.cache.amazonaws.com' }, { port: 6379, host: 'mx-prod-app-redis-0002-001.mx-prod-app-redis.gzcra2.usw2.cache.amazonaws.com' }, { port: 6379, host: 'mx-prod-app-redis-0002-002.mx-prod-app-redis.gzcra2.usw2.cache.amazonaws.com' }]
2021-10-29 17:41:15.526 +00:00: 2021-10-29T17:41:15.526Z ioredis:cluster:connectionPool Connecting to mx-prod-app-redis-0001-001.mx-prod-app-redis.gzcra2.usw2.cache.amazonaws.com:6379 as master
2021-10-29 17:41:15.526 +00:00: 2021-10-29T17:41:15.526Z ioredis:redis status[mx-prod-app-redis-0001-001.mx-prod-app-redis.gzcra2.usw2.cache.amazonaws.com:6379 (subscriber)]: [empty] -> wait
2021-10-29 17:41:15.529 +00:00: info: ioredis:cluster:node
2021-10-29 17:41:15.529 +00:00: 2021-10-29T17:41:15.529Z ioredis:cluster:connectionPool Connecting to mx-prod-app-redis-0001-002.mx-prod-app-redis.gzcra2.usw2.cache.amazonaws.com:6379 as master
2021-10-29 17:41:15.529 +00:00: 2021-10-29T17:41:15.529Z ioredis:redis status[mx-prod-app-redis-0001-002.mx-prod-app-redis.gzcra2.usw2.cache.amazonaws.com:6379 (subscriber)]: [empty] -> wait
2021-10-29 17:41:15.531 +00:00: info: ioredis:cluster:node
2021-10-29 17:41:15.531 +00:00: 2021-10-29T17:41:15.531Z ioredis:cluster:connectionPool Connecting to mx-prod-app-redis-0002-001.mx-prod-app-redis.gzcra2.usw2.cache.amazonaws.com:6379 as master
2021-10-29 17:41:15.532 +00:00: 2021-10-29T17:41:15.532Z ioredis:redis status[mx-prod-app-redis-0002-001.mx-prod-app-redis.gzcra2.usw2.cache.amazonaws.com:6379 (subscriber)]: [empty] -> wait
2021-10-29 17:41:15.534 +00:00: info: ioredis:cluster:node
2021-10-29 17:41:15.534 +00:00: 2021-10-29T17:41:15.534Z ioredis:cluster:connectionPool Connecting to mx-prod-app-redis-0002-002.mx-prod-app-redis.gzcra2.usw2.cache.amazonaws.com:6379 as master
2021-10-29 17:41:15.534 +00:00: 2021-10-29T17:41:15.534Z ioredis:redis status[mx-prod-app-redis-0002-002.mx-prod-app-redis.gzcra2.usw2.cache.amazonaws.com:6379 (subscriber)]: [empty] -> wait
2021-10-29 17:41:15.536 +00:00: info: ioredis:cluster:node
2021-10-29 17:41:15.536 +00:00: 2021-10-29T17:41:15.536Z ioredis:cluster getting slot cache from mx-prod-app-redis-0001-001.mx-prod-app-redis.gzcra2.usw2.cache.amazonaws.com:6379
2021-10-29 17:41:15.537 +00:00: 2021-10-29T17:41:15.537Z ioredis:redis status[mx-prod-app-redis-0001-001.mx-prod-app-redis.gzcra2.usw2.cache.amazonaws.com:6379 (ioredis-cluster(refresher):subscriber)]: [empty] -> wait
2021-10-29 17:41:15.537 +00:00: 2021-10-29T17:41:15.537Z ioredis:redis status[mx-prod-app-redis-0001-001.mx-prod-app-redis.gzcra2.usw2.cache.amazonaws.com:6379 (ioredis-cluster(refresher):subscriber)]: wait -> connecting
2021-10-29 17:41:15.537 +00:00: 2021-10-29T17:41:15.537Z ioredis:redis queue command[mx-prod-app-redis-0001-001.mx-prod-app-redis.gzcra2.usw2.cache.amazonaws.com:6379 (ioredis-cluster(refresher):subscriber)]: 0 -> cluster([ 'slots' ])
2021-10-29 17:41:15.537 +00:00: 2021-10-29T17:41:15.537Z ioredis:cluster:subscriber selected a subscriber mx-prod-app-redis-0002-002.mx-prod-app-redis.gzcra2.usw2.cache.amazonaws.com:6379
2021-10-29 17:41:15.538 +00:00: 2021-10-29T17:41:15.537Z ioredis:redis status[mx-prod-app-redis-0002-002.mx-prod-app-redis.gzcra2.usw2.cache.amazonaws.com:6379 (ioredis-cluster(subscriber):subscriber)]: [empty] -> wait
2021-10-29 17:41:15.538 +00:00: 2021-10-29T17:41:15.538Z ioredis:cluster:subscriber started
2021-10-29 17:41:15.631 +00:00: 2021-10-29T17:41:15.631Z ioredis:redis status[10.18.75.185:6379 (ioredis-cluster(refresher):subscriber)]: connecting -> connect
2021-10-29 17:41:15.632 +00:00: 2021-10-29T17:41:15.632Z ioredis:redis status[10.18.75.185:6379 (ioredis-cluster(refresher):subscriber)]: connect -> ready
2021-10-29 17:41:15.632 +00:00: 2021-10-29T17:41:15.632Z ioredis:connection set the connection name [ioredis-cluster(refresher):subscriber]
2021-10-29 17:41:15.632 +00:00: 2021-10-29T17:41:15.632Z ioredis:redis write command[10.18.75.185:6379 (ioredis-cluster(refresher):subscriber)]: 0 -> client([ 'setname', 'ioredis-cluster(refresher):subscriber' ])
2021-10-29 17:41:15.633 +00:00: 2021-10-29T17:41:15.633Z ioredis:connection send 1 commands in offline queue
2021-10-29 17:41:15.633 +00:00: 2021-10-29T17:41:15.633Z ioredis:redis write command[10.18.75.185:6379 (ioredis-cluster(refresher):subscriber)]: 0 -> cluster([ 'slots' ])
2021-10-29 17:41:15.635 +00:00: 2021-10-29T17:41:15.635Z ioredis:redis status[10.18.85.21:6379 (ioredis-cluster(refresher):locks)]: connecting -> connect
2021-10-29 17:41:15.635 +00:00: 2021-10-29T17:41:15.635Z ioredis:redis status[10.18.85.21:6379 (ioredis-cluster(refresher):locks)]: connect -> ready
2021-10-29 17:41:15.635 +00:00: 2021-10-29T17:41:15.635Z ioredis:connection set the connection name [ioredis-cluster(refresher):locks]
2021-10-29 17:41:15.635 +00:00: 2021-10-29T17:41:15.635Z ioredis:redis write command[10.18.85.21:6379 (ioredis-cluster(refresher):locks)]: 0 -> client([ 'setname', 'ioredis-cluster(refresher):locks' ])
2021-10-29 17:41:15.635 +00:00: 2021-10-29T17:41:15.635Z ioredis:connection send 1 commands in offline queue
2021-10-29 17:41:15.636 +00:00: 2021-10-29T17:41:15.635Z ioredis:redis write command[10.18.85.21:6379 (ioredis-cluster(refresher):locks)]: 0 -> cluster([ 'slots' ])
2021-10-29 17:41:15.637 +00:00: 2021-10-29T17:41:15.637Z ioredis:redis status[10.18.81.137:6379 (ioredis-cluster(refresher):publisher)]: connecting -> connect
2021-10-29 17:41:15.637 +00:00: 2021-10-29T17:41:15.637Z ioredis:redis status[10.18.81.137:6379 (ioredis-cluster(refresher):publisher)]: connect -> ready
2021-10-29 17:41:15.637 +00:00: 2021-10-29T17:41:15.637Z ioredis:connection set the connection name [ioredis-cluster(refresher):publisher]
2021-10-29 17:41:15.637 +00:00: 2021-10-29T17:41:15.637Z ioredis:redis write command[10.18.81.137:6379 (ioredis-cluster(refresher):publisher)]: 0 -> client([ 'setname', 'ioredis-cluster(refresher):publisher' ])
2021-10-29 17:41:15.637 +00:00: 2021-10-29T17:41:15.637Z ioredis:connection send 1 commands in offline queue
2021-10-29 17:41:15.638 +00:00: 2021-10-29T17:41:15.638Z ioredis:redis write command[10.18.81.137:6379 (ioredis-cluster(refresher):publisher)]: 0 -> cluster([ 'slots' ])
2021-10-29 17:41:15.639 +00:00: 2021-10-29T17:41:15.639Z ioredis:redis status[10.18.85.21:6379 (ioredis-cluster(refresher):cache)]: connecting -> connect
2021-10-29 17:41:15.639 +00:00: 2021-10-29T17:41:15.639Z ioredis:redis status[10.18.85.21:6379 (ioredis-cluster(refresher):cache)]: connect -> ready
2021-10-29 17:41:15.639 +00:00: 2021-10-29T17:41:15.639Z ioredis:connection set the connection name [ioredis-cluster(refresher):cache]
2021-10-29 17:41:15.639 +00:00: 2021-10-29T17:41:15.639Z ioredis:redis write command[10.18.85.21:6379 (ioredis-cluster(refresher):cache)]: 0 -> client([ 'setname', 'ioredis-cluster(refresher):cache' ])
2021-10-29 17:41:15.640 +00:00: 2021-10-29T17:41:15.640Z ioredis:connection send 1 commands in offline queue
2021-10-29 17:41:15.640 +00:00: 2021-10-29T17:41:15.640Z ioredis:redis write command[10.18.85.21:6379 (ioredis-cluster(refresher):cache)]: 0 -> cluster([ 'slots' ])
2021-10-29 17:41:15.642 +00:00: 2021-10-29T17:41:15.642Z ioredis:cluster cluster slots result count: 2
2021-10-29 17:41:15.643 +00:00: 2021-10-29T17:41:15.642Z ioredis:cluster cluster slots result [0]: slots 8192~16383 served by [ 'mx-prod-app-redis-0002-002.mx-prod-app-redis.gzcra2.usw2.cache.amazonaws.com:6379', 'mx-prod-app-redis-0002-001.mx-prod-app-redis.gzcra2.usw2.cache.amazonaws.com:6379']
2021-10-29 17:41:15.644 +00:00: 2021-10-29T17:41:15.644Z ioredis:cluster cluster slots result [1]: slots 0~8191 served by [ 'mx-prod-app-redis-0001-002.mx-prod-app-redis.gzcra2.usw2.cache.amazonaws.com:6379', 'mx-prod-app-redis-0001-001.mx-prod-app-redis.gzcra2.usw2.cache.amazonaws.com:6379']
2021-10-29 17:41:15.657 +00:00: 2021-10-29T17:41:15.657Z ioredis:cluster:connectionPool Reset with [ { host: 'mx-prod-app-redis-0002-002.mx-prod-app-redis.gzcra2.usw2.cache.amazonaws.com', port: 6379, readOnly: false }, { host: 'mx-prod-app-redis-0002-001.mx-prod-app-redis.gzcra2.usw2.cache.amazonaws.com', port: 6379, readOnly: true }, { host: 'mx-prod-app-redis-0001-002.mx-prod-app-redis.gzcra2.usw2.cache.amazonaws.com', port: 6379, readOnly: false }, { host: 'mx-prod-app-redis-0001-001.mx-prod-app-redis.gzcra2.usw2.cache.amazonaws.com', port: 6379, readOnly: true }]
2021-10-29 17:41:15.658 +00:00: 2021-10-29T17:41:15.658Z ioredis:cluster:connectionPool Change role of mx-prod-app-redis-0002-001.mx-prod-app-redis.gzcra2.usw2.cache.amazonaws.com:6379 to slave
2021-10-29 17:41:15.658 +00:00: 2021-10-29T17:41:15.658Z ioredis:redis status[mx-prod-app-redis-0002-001.mx-prod-app-redis.gzcra2.usw2.cache.amazonaws.com:6379 (locks)]: wait -> connecting
2021-10-29 17:41:15.658 +00:00: 2021-10-29T17:41:15.658Z ioredis:redis queue command[mx-prod-app-redis-0002-001.mx-prod-app-redis.gzcra2.usw2.cache.amazonaws.com:6379 (locks)]: 0 -> readonly([])
2021-10-29 17:41:15.658 +00:00: 2021-10-29T17:41:15.658Z ioredis:cluster:connectionPool Change role of mx-prod-app-redis-0001-001.mx-prod-app-redis.gzcra2.usw2.cache.amazonaws.com:6379 to slave
2021-10-29 17:41:15.658 +00:00: 2021-10-29T17:41:15.658Z ioredis:redis status[mx-prod-app-redis-0001-001.mx-prod-app-redis.gzcra2.usw2.cache.amazonaws.com:6379 (locks)]: wait -> connecting
2021-10-29 17:41:15.658 +00:00: 2021-10-29T17:41:15.658Z ioredis:redis queue command[mx-prod-app-redis-0001-001.mx-prod-app-redis.gzcra2.usw2.cache.amazonaws.com:6379 (locks)]: 0 -> readonly([])
2021-10-29 17:41:15.659 +00:00: 2021-10-29T17:41:15.659Z ioredis:cluster status: connecting -> connect
2021-10-29 17:41:15.659 +00:00: 2021-10-29T17:41:15.659Z ioredis:redis status[mx-prod-app-redis-0001-002.mx-prod-app-redis.gzcra2.usw2.cache.amazonaws.com:6379 (locks)]: wait -> connecting
2021-10-29 17:41:15.660 +00:00: 2021-10-29T17:41:15.660Z ioredis:redis queue command[mx-prod-app-redis-0001-002.mx-prod-app-redis.gzcra2.usw2.cache.amazonaws.com:6379 (locks)]: 0 -> cluster([ 'info' ])
2021-10-29 17:41:15.662 +00:00: 2021-10-29T17:41:15.662Z ioredis:cluster cluster slots result count: 2
2021-10-29 17:41:15.663 +00:00: 2021-10-29T17:41:15.663Z ioredis:cluster cluster slots result [0]: slots 8192~16383 served by [ 'mx-prod-app-redis-0002-002.mx-prod-app-redis.gzcra2.usw2.cache.amazonaws.com:6379', 'mx-prod-app-redis-0002-001.mx-prod-app-redis.gzcra2.usw2.cache.amazonaws.com:6379']
2021-10-29 17:41:15.664 +00:00: 2021-10-29T17:41:15.664Z ioredis:cluster cluster slots result [1]: slots 0~8191 served by [ 'mx-prod-app-redis-0001-002.mx-prod-app-redis.gzcra2.usw2.cache.amazonaws.com:6379', 'mx-prod-app-redis-0001-001.mx-prod-app-redis.gzcra2.usw2.cache.amazonaws.com:6379']
2021-10-29 17:41:15.679 +00:00: 2021-10-29T17:41:15.679Z ioredis:cluster:connectionPool Reset with [ { host: 'mx-prod-app-redis-0002-002.mx-prod-app-redis.gzcra2.usw2.cache.amazonaws.com', port: 6379, readOnly: false }, { host: 'mx-prod-app-redis-0002-001.mx-prod-app-redis.gzcra2.usw2.cache.amazonaws.com', port: 6379, readOnly: true }, { host: 'mx-prod-app-redis-0001-002.mx-prod-app-redis.gzcra2.usw2.cache.amazonaws.com', port: 6379, readOnly: false }, { host: 'mx-prod-app-redis-0001-001.mx-prod-app-redis.gzcra2.usw2.cache.amazonaws.com', port: 6379, readOnly: true }]
2021-10-29 17:41:15.679 +00:00: 2021-10-29T17:41:15.679Z ioredis:cluster:connectionPool Change role of mx-prod-app-redis-0002-001.mx-prod-app-redis.gzcra2.usw2.cache.amazonaws.com:6379 to slave
2021-10-29 17:41:15.679 +00:00: 2021-10-29T17:41:15.679Z ioredis:redis status[mx-prod-app-redis-0002-001.mx-prod-app-redis.gzcra2.usw2.cache.amazonaws.com:6379 (publisher)]: wait -> connecting
2021-10-29 17:41:15.680 +00:00: 2021-10-29T17:41:15.680Z ioredis:redis queue command[mx-prod-app-redis-0002-001.mx-prod-app-redis.gzcra2.usw2.cache.amazonaws.com:6379 (publisher)]: 0 -> readonly([])
2021-10-29 17:41:15.680 +00:00: 2021-10-29T17:41:15.680Z ioredis:cluster:connectionPool Change role of mx-prod-app-redis-0001-001.mx-prod-app-redis.gzcra2.usw2.cache.amazonaws.com:6379 to slave
2021-10-29 17:41:15.680 +00:00: 2021-10-29T17:41:15.680Z ioredis:redis status[mx-prod-app-redis-0001-001.mx-prod-app-redis.gzcra2.usw2.cache.amazonaws.com:6379 (publisher)]: wait -> connecting
2021-10-29 17:41:15.680 +00:00: 2021-10-29T17:41:15.680Z ioredis:redis queue command[mx-prod-app-redis-0001-001.mx-prod-app-redis.gzcra2.usw2.cache.amazonaws.com:6379 (publisher)]: 0 -> readonly([])
2021-10-29 17:41:15.680 +00:00: 2021-10-29T17:41:15.680Z ioredis:cluster status: connecting -> connect
2021-10-29 17:41:15.680 +00:00: 2021-10-29T17:41:15.680Z ioredis:redis status[mx-prod-app-redis-0002-002.mx-prod-app-redis.gzcra2.usw2.cache.amazonaws.com:6379 (publisher)]: wait -> connecting
2021-10-29 17:41:15.680 +00:00: 2021-10-29T17:41:15.680Z ioredis:redis queue command[mx-prod-app-redis-0002-002.mx-prod-app-redis.gzcra2.usw2.cache.amazonaws.com:6379 (publisher)]: 0 -> cluster([ 'info' ])
2021-10-29 17:41:15.682 +00:00: 2021-10-29T17:41:15.682Z ioredis:cluster cluster slots result count: 2
2021-10-29 17:41:15.682 +00:00: 2021-10-29T17:41:15.682Z ioredis:cluster cluster slots result [0]: slots 8192~16383 served by [ 'mx-prod-app-redis-0002-002.mx-prod-app-redis.gzcra2.usw2.cache.amazonaws.com:6379', 'mx-prod-app-redis-0002-001.mx-prod-app-redis.gzcra2.usw2.cache.amazonaws.com:6379']
2021-10-29 17:41:15.704 +00:00: 2021-10-29T17:41:15.704Z ioredis:cluster cluster slots result [1]: slots 0~8191 served by [ 'mx-prod-app-redis-0001-002.mx-prod-app-redis.gzcra2.usw2.cache.amazonaws.com:6379', 'mx-prod-app-redis-0001-001.mx-prod-app-redis.gzcra2.usw2.cache.amazonaws.com:6379']
2021-10-29 17:41:15.719 +00:00: 2021-10-29T17:41:15.719Z ioredis:cluster:connectionPool Reset with [ { host: 'mx-prod-app-redis-0002-002.mx-prod-app-redis.gzcra2.usw2.cache.amazonaws.com', port: 6379, readOnly: false }, { host: 'mx-prod-app-redis-0002-001.mx-prod-app-redis.gzcra2.usw2.cache.amazonaws.com', port: 6379, readOnly: true }, { host: 'mx-prod-app-redis-0001-002.mx-prod-app-redis.gzcra2.usw2.cache.amazonaws.com', port: 6379, readOnly: false }, { host: 'mx-prod-app-redis-0001-001.mx-prod-app-redis.gzcra2.usw2.cache.amazonaws.com', port: 6379, readOnly: true }]
2021-10-29 17:41:15.720 +00:00: 2021-10-29T17:41:15.720Z ioredis:cluster:connectionPool Change role of mx-prod-app-redis-0002-001.mx-prod-app-redis.gzcra2.usw2.cache.amazonaws.com:6379 to slave
2021-10-29 17:41:15.720 +00:00: 2021-10-29T17:41:15.720Z ioredis:redis status[mx-prod-app-redis-0002-001.mx-prod-app-redis.gzcra2.usw2.cache.amazonaws.com:6379 (cache)]: wait -> connecting
2021-10-29 17:41:15.720 +00:00: 2021-10-29T17:41:15.720Z ioredis:redis queue command[mx-prod-app-redis-0002-001.mx-prod-app-redis.gzcra2.usw2.cache.amazonaws.com:6379 (cache)]: 0 -> readonly([])
2021-10-29 17:41:15.720 +00:00: 2021-10-29T17:41:15.720Z ioredis:cluster:connectionPool Change role of mx-prod-app-redis-0001-001.mx-prod-app-redis.gzcra2.usw2.cache.amazonaws.com:6379 to slave
2021-10-29 17:41:15.720 +00:00: 2021-10-29T17:41:15.720Z ioredis:redis status[mx-prod-app-redis-0001-001.mx-prod-app-redis.gzcra2.usw2.cache.amazonaws.com:6379 (cache)]: wait -> connecting
2021-10-29 17:41:15.720 +00:00: 2021-10-29T17:41:15.720Z ioredis:redis queue command[mx-prod-app-redis-0001-001.mx-prod-app-redis.gzcra2.usw2.cache.amazonaws.com:6379 (cache)]: 0 -> readonly([])
2021-10-29 17:41:15.720 +00:00: 2021-10-29T17:41:15.720Z ioredis:cluster status: connecting -> connect
2021-10-29 17:41:15.721 +00:00: 2021-10-29T17:41:15.721Z ioredis:redis status[mx-prod-app-redis-0002-002.mx-prod-app-redis.gzcra2.usw2.cache.amazonaws.com:6379 (cache)]: wait -> connecting
2021-10-29 17:41:15.721 +00:00: 2021-10-29T17:41:15.721Z ioredis:redis queue command[mx-prod-app-redis-0002-002.mx-prod-app-redis.gzcra2.usw2.cache.amazonaws.com:6379 (cache)]: 0 -> cluster([ 'info' ])
2021-10-29 17:41:15.748 +00:00: 2021-10-29T17:41:15.748Z ioredis:cluster cluster slots result count: 2
2021-10-29 17:41:15.748 +00:00: 2021-10-29T17:41:15.748Z ioredis:cluster cluster slots result [0]: slots 0~8191 served by [ 'mx-prod-app-redis-0001-002.mx-prod-app-redis.gzcra2.usw2.cache.amazonaws.com:6379', 'mx-prod-app-redis-0001-001.mx-prod-app-redis.gzcra2.usw2.cache.amazonaws.com:6379']
2021-10-29 17:41:15.748 +00:00: 2021-10-29T17:41:15.748Z ioredis:cluster cluster slots result [1]: slots 8192~16383 served by [ 'mx-prod-app-redis-0002-002.mx-prod-app-redis.gzcra2.usw2.cache.amazonaws.com:6379', 'mx-prod-app-redis-0002-001.mx-prod-app-redis.gzcra2.usw2.cache.amazonaws.com:6379']
2021-10-29 17:41:15.761 +00:00: 2021-10-29T17:41:15.761Z ioredis:cluster:connectionPool Reset with [ { host: 'mx-prod-app-redis-0001-002.mx-prod-app-redis.gzcra2.usw2.cache.amazonaws.com', port: 6379, readOnly: false }, { host: 'mx-prod-app-redis-0001-001.mx-prod-app-redis.gzcra2.usw2.cache.amazonaws.com', port: 6379, readOnly: true }, { host: 'mx-prod-app-redis-0002-002.mx-prod-app-redis.gzcra2.usw2.cache.amazonaws.com', port: 6379, readOnly: false }, { host: 'mx-prod-app-redis-0002-001.mx-prod-app-redis.gzcra2.usw2.cache.amazonaws.com', port: 6379, readOnly: true }]
2021-10-29 17:41:15.762 +00:00: 2021-10-29T17:41:15.762Z ioredis:cluster:connectionPool Change role of mx-prod-app-redis-0001-001.mx-prod-app-redis.gzcra2.usw2.cache.amazonaws.com:6379 to slave
2021-10-29 17:41:15.762 +00:00: 2021-10-29T17:41:15.762Z ioredis:redis status[mx-prod-app-redis-0001-001.mx-prod-app-redis.gzcra2.usw2.cache.amazonaws.com:6379 (subscriber)]: wait -> connecting
2021-10-29 17:41:15.762 +00:00: 2021-10-29T17:41:15.762Z ioredis:redis queue command[mx-prod-app-redis-0001-001.mx-prod-app-redis.gzcra2.usw2.cache.amazonaws.com:6379 (subscriber)]: 0 -> readonly([])
2021-10-29 17:41:15.762 +00:00: 2021-10-29T17:41:15.762Z ioredis:cluster:connectionPool Change role of mx-prod-app-redis-0002-001.mx-prod-app-redis.gzcra2.usw2.cache.amazonaws.com:6379 to slave
2021-10-29 17:41:15.762 +00:00: 2021-10-29T17:41:15.762Z ioredis:redis status[mx-prod-app-redis-0002-001.mx-prod-app-redis.gzcra2.usw2.cache.amazonaws.com:6379 (subscriber)]: wait -> connecting
2021-10-29 17:41:15.762 +00:00: 2021-10-29T17:41:15.762Z ioredis:redis queue command[mx-prod-app-redis-0002-001.mx-prod-app-redis.gzcra2.usw2.cache.amazonaws.com:6379 (subscriber)]: 0 -> readonly([])
2021-10-29 17:41:15.762 +00:00: 2021-10-29T17:41:15.762Z ioredis:cluster status: connecting -> connect
2021-10-29 17:41:15.762 +00:00: 2021-10-29T17:41:15.762Z ioredis:redis status[mx-prod-app-redis-0001-002.mx-prod-app-redis.gzcra2.usw2.cache.amazonaws.com:6379 (subscriber)]: wait -> connecting
2021-10-29 17:41:15.763 +00:00: 2021-10-29T17:41:15.763Z ioredis:redis queue command[mx-prod-app-redis-0001-002.mx-prod-app-redis.gzcra2.usw2.cache.amazonaws.com:6379 (subscriber)]: 0 -> cluster([ 'info' ])
2021-10-29 17:41:15.768 +00:00: 2021-10-29T17:41:15.768Z ioredis:redis status[10.18.85.21:6379 (ioredis-cluster(refresher):cache)]: ready -> close
2021-10-29 17:41:15.768 +00:00: 2021-10-29T17:41:15.768Z ioredis:connection skip reconnecting since the connection is manually closed.
2021-10-29 17:41:15.768 +00:00: 2021-10-29T17:41:15.768Z ioredis:redis status[10.18.85.21:6379 (ioredis-cluster(refresher):cache)]: close -> end
2021-10-29 17:41:15.769 +00:00: 2021-10-29T17:41:15.768Z ioredis:redis status[10.18.81.137:6379 (ioredis-cluster(refresher):publisher)]: ready -> close
2021-10-29 17:41:15.769 +00:00: 2021-10-29T17:41:15.769Z ioredis:connection skip reconnecting since the connection is manually closed.
2021-10-29 17:41:15.769 +00:00: 2021-10-29T17:41:15.769Z ioredis:redis status[10.18.81.137:6379 (ioredis-cluster(refresher):publisher)]: close -> end
2021-10-29 17:41:15.769 +00:00: 2021-10-29T17:41:15.769Z ioredis:redis status[10.18.85.21:6379 (ioredis-cluster(refresher):locks)]: ready -> close
2021-10-29 17:41:15.769 +00:00: 2021-10-29T17:41:15.769Z ioredis:connection skip reconnecting since the connection is manually closed.
2021-10-29 17:41:15.769 +00:00: 2021-10-29T17:41:15.769Z ioredis:redis status[10.18.85.21:6379 (ioredis-cluster(refresher):locks)]: close -> end
2021-10-29 17:41:15.803 +00:00: 2021-10-29T17:41:15.803Z ioredis:redis status[10.18.75.185:6379 (ioredis-cluster(refresher):subscriber)]: ready -> close
2021-10-29 17:41:15.803 +00:00: 2021-10-29T17:41:15.803Z ioredis:connection skip reconnecting since the connection is manually closed.
2021-10-29 17:41:15.803 +00:00: 2021-10-29T17:41:15.803Z ioredis:redis status[10.18.75.185:6379 (ioredis-cluster(refresher):subscriber)]: close -> end
2021-10-29 17:41:15.805 +00:00: 2021-10-29T17:41:15.805Z ioredis:redis status[10.18.75.185:6379 (locks)]: connecting -> connect
2021-10-29 17:41:15.805 +00:00: 2021-10-29T17:41:15.805Z ioredis:redis write command[10.18.75.185:6379 (locks)]: 0 -> info([])
2021-10-29 17:41:15.807 +00:00: 2021-10-29T17:41:15.807Z ioredis:redis status[10.18.81.137:6379 (locks)]: connecting -> connect
2021-10-29 17:41:15.807 +00:00: 2021-10-29T17:41:15.807Z ioredis:redis write command[10.18.81.137:6379 (locks)]: 0 -> info([])
2021-10-29 17:41:15.808 +00:00: 2021-10-29T17:41:15.808Z ioredis:redis status[10.18.62.156:6379 (locks)]: connecting -> connect
2021-10-29 17:41:15.809 +00:00: 2021-10-29T17:41:15.809Z ioredis:redis write command[10.18.62.156:6379 (locks)]: 0 -> info([])
2021-10-29 17:41:15.810 +00:00: 2021-10-29T17:41:15.810Z ioredis:redis status[10.18.62.156:6379 (publisher)]: connecting -> connect
2021-10-29 17:41:15.810 +00:00: 2021-10-29T17:41:15.810Z ioredis:redis write command[10.18.62.156:6379 (publisher)]: 0 -> info([])
2021-10-29 17:41:15.811 +00:00: 2021-10-29T17:41:15.811Z ioredis:redis status[10.18.75.185:6379 (publisher)]: connecting -> connect
2021-10-29 17:41:15.812 +00:00: 2021-10-29T17:41:15.811Z ioredis:redis write command[10.18.75.185:6379 (publisher)]: 0 -> info([])
2021-10-29 17:41:15.813 +00:00: 2021-10-29T17:41:15.813Z ioredis:redis status[10.18.85.21:6379 (publisher)]: connecting -> connect
2021-10-29 17:41:15.813 +00:00: 2021-10-29T17:41:15.813Z ioredis:redis write command[10.18.85.21:6379 (publisher)]: 0 -> info([])
2021-10-29 17:41:15.818 +00:00: 2021-10-29T17:41:15.817Z ioredis:redis status[10.18.75.185:6379 (locks)]: connect -> ready
2021-10-29 17:41:15.818 +00:00: 2021-10-29T17:41:15.818Z ioredis:connection set the connection name [locks]
2021-10-29 17:41:15.818 +00:00: 2021-10-29T17:41:15.818Z ioredis:redis write command[10.18.75.185:6379 (locks)]: 0 -> client([ 'setname', 'locks' ])
2021-10-29 17:41:15.818 +00:00: 2021-10-29T17:41:15.818Z ioredis:connection set the connection to readonly mode
2021-10-29 17:41:15.818 +00:00: 2021-10-29T17:41:15.818Z ioredis:redis write command[10.18.75.185:6379 (locks)]: 0 -> readonly([])
2021-10-29 17:41:15.818 +00:00: 2021-10-29T17:41:15.818Z ioredis:connection send 1 commands in offline queue
2021-10-29 17:41:15.818 +00:00: 2021-10-29T17:41:15.818Z ioredis:redis write command[10.18.75.185:6379 (locks)]: 0 -> readonly([])
2021-10-29 17:41:15.819 +00:00: 2021-10-29T17:41:15.819Z ioredis:redis status[10.18.81.137:6379 (locks)]: connect -> ready
2021-10-29 17:41:15.819 +00:00: 2021-10-29T17:41:15.819Z ioredis:connection set the connection name [locks]
2021-10-29 17:41:15.819 +00:00: 2021-10-29T17:41:15.819Z ioredis:redis write command[10.18.81.137:6379 (locks)]: 0 -> client([ 'setname', 'locks' ])
2021-10-29 17:41:15.819 +00:00: 2021-10-29T17:41:15.819Z ioredis:connection send 1 commands in offline queue
2021-10-29 17:41:15.820 +00:00: 2021-10-29T17:41:15.820Z ioredis:redis write command[10.18.81.137:6379 (locks)]: 0 -> cluster([ 'info' ])
2021-10-29 17:41:15.820 +00:00: 2021-10-29T17:41:15.820Z ioredis:redis status[10.18.62.156:6379 (locks)]: connect -> ready
2021-10-29 17:41:15.820 +00:00: 2021-10-29T17:41:15.820Z ioredis:connection set the connection name [locks]
2021-10-29 17:41:15.821 +00:00: 2021-10-29T17:41:15.820Z ioredis:redis write command[10.18.62.156:6379 (locks)]: 0 -> client([ 'setname', 'locks' ])
2021-10-29 17:41:15.821 +00:00: 2021-10-29T17:41:15.821Z ioredis:connection set the connection to readonly mode
2021-10-29 17:41:15.821 +00:00: 2021-10-29T17:41:15.821Z ioredis:redis write command[10.18.62.156:6379 (locks)]: 0 -> readonly([])
2021-10-29 17:41:15.821 +00:00: 2021-10-29T17:41:15.821Z ioredis:connection send 1 commands in offline queue
2021-10-29 17:41:15.821 +00:00: 2021-10-29T17:41:15.821Z ioredis:redis write command[10.18.62.156:6379 (locks)]: 0 -> readonly([])
2021-10-29 17:41:15.822 +00:00: 2021-10-29T17:41:15.822Z ioredis:redis status[10.18.62.156:6379 (publisher)]: connect -> ready
2021-10-29 17:41:15.822 +00:00: 2021-10-29T17:41:15.822Z ioredis:connection set the connection name [publisher]
2021-10-29 17:41:15.822 +00:00: 2021-10-29T17:41:15.822Z ioredis:redis write command[10.18.62.156:6379 (publisher)]: 0 -> client([ 'setname', 'publisher' ])
2021-10-29 17:41:15.822 +00:00: 2021-10-29T17:41:15.822Z ioredis:connection set the connection to readonly mode
2021-10-29 17:41:15.822 +00:00: 2021-10-29T17:41:15.822Z ioredis:redis write command[10.18.62.156:6379 (publisher)]: 0 -> readonly([])
2021-10-29 17:41:15.822 +00:00: 2021-10-29T17:41:15.822Z ioredis:connection send 1 commands in offline queue
2021-10-29 17:41:15.822 +00:00: 2021-10-29T17:41:15.822Z ioredis:redis write command[10.18.62.156:6379 (publisher)]: 0 -> readonly([])
2021-10-29 17:41:15.823 +00:00: 2021-10-29T17:41:15.823Z ioredis:redis status[10.18.75.185:6379 (publisher)]: connect -> ready
2021-10-29 17:41:15.823 +00:00: 2021-10-29T17:41:15.823Z ioredis:connection set the connection name [publisher]
2021-10-29 17:41:15.823 +00:00: 2021-10-29T17:41:15.823Z ioredis:redis write command[10.18.75.185:6379 (publisher)]: 0 -> client([ 'setname', 'publisher' ])
2021-10-29 17:41:15.823 +00:00: 2021-10-29T17:41:15.823Z ioredis:connection set the connection to readonly mode
2021-10-29 17:41:15.824 +00:00: 2021-10-29T17:41:15.824Z ioredis:redis write command[10.18.75.185:6379 (publisher)]: 0 -> readonly([])
2021-10-29 17:41:15.824 +00:00: 2021-10-29T17:41:15.824Z ioredis:connection send 1 commands in offline queue
2021-10-29 17:41:15.824 +00:00: 2021-10-29T17:41:15.824Z ioredis:redis write command[10.18.75.185:6379 (publisher)]: 0 -> readonly([])
2021-10-29 17:41:15.824 +00:00: 2021-10-29T17:41:15.824Z ioredis:redis status[10.18.85.21:6379 (publisher)]: connect -> ready
2021-10-29 17:41:15.825 +00:00: 2021-10-29T17:41:15.824Z ioredis:connection set the connection name [publisher]
2021-10-29 17:41:15.825 +00:00: 2021-10-29T17:41:15.825Z ioredis:redis write command[10.18.85.21:6379 (publisher)]: 0 -> client([ 'setname', 'publisher' ])
2021-10-29 17:41:15.825 +00:00: 2021-10-29T17:41:15.825Z ioredis:connection send 1 commands in offline queue
2021-10-29 17:41:15.825 +00:00: 2021-10-29T17:41:15.825Z ioredis:redis write command[10.18.85.21:6379 (publisher)]: 0 -> cluster([ 'info' ])
2021-10-29 17:41:15.826 +00:00: 2021-10-29T17:41:15.826Z ioredis:redis status[10.18.75.185:6379 (cache)]: connecting -> connect
2021-10-29 17:41:15.826 +00:00: 2021-10-29T17:41:15.826Z ioredis:redis write command[10.18.75.185:6379 (cache)]: 0 -> info([])
2021-10-29 17:41:15.828 +00:00: 2021-10-29T17:41:15.828Z ioredis:redis status[10.18.62.156:6379 (cache)]: connecting -> connect
2021-10-29 17:41:15.828 +00:00: 2021-10-29T17:41:15.828Z ioredis:redis write command[10.18.62.156:6379 (cache)]: 0 -> info([])
2021-10-29 17:41:15.829 +00:00: 2021-10-29T17:41:15.829Z ioredis:redis status[10.18.85.21:6379 (cache)]: connecting -> connect
2021-10-29 17:41:15.830 +00:00: 2021-10-29T17:41:15.829Z ioredis:redis write command[10.18.85.21:6379 (cache)]: 0 -> info([])
2021-10-29 17:41:15.831 +00:00: 2021-10-29T17:41:15.831Z ioredis:redis status[10.18.75.185:6379 (subscriber)]: connecting -> connect
2021-10-29 17:41:15.831 +00:00: 2021-10-29T17:41:15.831Z ioredis:redis write command[10.18.75.185:6379 (subscriber)]: 0 -> info([])
2021-10-29 17:41:15.832 +00:00: 2021-10-29T17:41:15.832Z ioredis:cluster status: connect -> ready
2021-10-29 17:41:15.833 +00:00: 2021-10-29T17:41:15.833Z ioredis:cluster status: connect -> ready
2021-10-29 17:41:15.833 +00:00: 2021-10-29T17:41:15.833Z ioredis:redis status[10.18.75.185:6379 (cache)]: connect -> ready
2021-10-29 17:41:15.833 +00:00: 2021-10-29T17:41:15.833Z ioredis:connection set the connection name [cache]
2021-10-29 17:41:15.834 +00:00: 2021-10-29T17:41:15.834Z ioredis:redis write command[10.18.75.185:6379 (cache)]: 0 -> client([ 'setname', 'cache' ])
2021-10-29 17:41:15.834 +00:00: 2021-10-29T17:41:15.834Z ioredis:connection set the connection to readonly mode
2021-10-29 17:41:15.834 +00:00: 2021-10-29T17:41:15.834Z ioredis:redis write command[10.18.75.185:6379 (cache)]: 0 -> readonly([])
2021-10-29 17:41:15.834 +00:00: 2021-10-29T17:41:15.834Z ioredis:connection send 1 commands in offline queue
2021-10-29 17:41:15.834 +00:00: 2021-10-29T17:41:15.834Z ioredis:redis write command[10.18.75.185:6379 (cache)]: 0 -> readonly([])
2021-10-29 17:41:15.835 +00:00: 2021-10-29T17:41:15.835Z ioredis:redis status[10.18.62.156:6379 (cache)]: connect -> ready
2021-10-29 17:41:15.835 +00:00: 2021-10-29T17:41:15.835Z ioredis:connection set the connection name [cache]
2021-10-29 17:41:15.835 +00:00: 2021-10-29T17:41:15.835Z ioredis:redis write command[10.18.62.156:6379 (cache)]: 0 -> client([ 'setname', 'cache' ])
2021-10-29 17:41:15.835 +00:00: 2021-10-29T17:41:15.835Z ioredis:connection set the connection to readonly mode
2021-10-29 17:41:15.835 +00:00: 2021-10-29T17:41:15.835Z ioredis:redis write command[10.18.62.156:6379 (cache)]: 0 -> readonly([])
2021-10-29 17:41:15.835 +00:00: 2021-10-29T17:41:15.835Z ioredis:connection send 1 commands in offline queue
2021-10-29 17:41:15.835 +00:00: 2021-10-29T17:41:15.835Z ioredis:redis write command[10.18.62.156:6379 (cache)]: 0 -> readonly([])
2021-10-29 17:41:15.836 +00:00: 2021-10-29T17:41:15.836Z ioredis:redis status[10.18.85.21:6379 (cache)]: connect -> ready
2021-10-29 17:41:15.836 +00:00: 2021-10-29T17:41:15.836Z ioredis:connection set the connection name [cache]
2021-10-29 17:41:15.836 +00:00: 2021-10-29T17:41:15.836Z ioredis:redis write command[10.18.85.21:6379 (cache)]: 0 -> client([ 'setname', 'cache' ])
2021-10-29 17:41:15.836 +00:00: 2021-10-29T17:41:15.836Z ioredis:connection send 1 commands in offline queue
2021-10-29 17:41:15.837 +00:00: 2021-10-29T17:41:15.837Z ioredis:redis write command[10.18.85.21:6379 (cache)]: 0 -> cluster([ 'info' ])
2021-10-29 17:41:15.838 +00:00: 2021-10-29T17:41:15.838Z ioredis:redis status[10.18.81.137:6379 (subscriber)]: connecting -> connect
2021-10-29 17:41:15.838 +00:00: 2021-10-29T17:41:15.838Z ioredis:redis write command[10.18.81.137:6379 (subscriber)]: 0 -> info([])
2021-10-29 17:41:15.839 +00:00: 2021-10-29T17:41:15.839Z ioredis:redis status[10.18.62.156:6379 (subscriber)]: connecting -> connect
2021-10-29 17:41:15.840 +00:00: 2021-10-29T17:41:15.840Z ioredis:redis write command[10.18.62.156:6379 (subscriber)]: 0 -> info([])
2021-10-29 17:41:15.840 +00:00: 2021-10-29T17:41:15.840Z ioredis:cluster status: connect -> ready
2021-10-29 17:41:15.841 +00:00: 2021-10-29T17:41:15.841Z ioredis:redis status[10.18.81.137:6379 (subscriber)]: connect -> ready
2021-10-29 17:41:15.841 +00:00: 2021-10-29T17:41:15.841Z ioredis:connection set the connection name [subscriber]
2021-10-29 17:41:15.841 +00:00: 2021-10-29T17:41:15.841Z ioredis:redis write command[10.18.81.137:6379 (subscriber)]: 0 -> client([ 'setname', 'subscriber' ])
2021-10-29 17:41:15.841 +00:00: 2021-10-29T17:41:15.841Z ioredis:connection send 1 commands in offline queue
2021-10-29 17:41:15.842 +00:00: 2021-10-29T17:41:15.841Z ioredis:redis write command[10.18.81.137:6379 (subscriber)]: 0 -> cluster([ 'info' ])
2021-10-29 17:41:15.842 +00:00: 2021-10-29T17:41:15.842Z ioredis:redis status[10.18.75.185:6379 (subscriber)]: connect -> ready
2021-10-29 17:41:15.842 +00:00: 2021-10-29T17:41:15.842Z ioredis:connection set the connection name [subscriber]
2021-10-29 17:41:15.842 +00:00: 2021-10-29T17:41:15.842Z ioredis:redis write command[10.18.75.185:6379 (subscriber)]: 0 -> client([ 'setname', 'subscriber' ])
2021-10-29 17:41:15.843 +00:00: 2021-10-29T17:41:15.843Z ioredis:connection set the connection to readonly mode
2021-10-29 17:41:15.843 +00:00: 2021-10-29T17:41:15.843Z ioredis:redis write command[10.18.75.185:6379 (subscriber)]: 0 -> readonly([])
2021-10-29 17:41:15.843 +00:00: 2021-10-29T17:41:15.843Z ioredis:connection send 1 commands in offline queue
2021-10-29 17:41:15.843 +00:00: 2021-10-29T17:41:15.843Z ioredis:redis write command[10.18.75.185:6379 (subscriber)]: 0 -> readonly([])
2021-10-29 17:41:15.843 +00:00: 2021-10-29T17:41:15.843Z ioredis:cluster status: connect -> ready
2021-10-29 17:41:15.844 +00:00: 2021-10-29T17:41:15.844Z ioredis:redis status[10.18.62.156:6379 (subscriber)]: connect -> ready
2021-10-29 17:41:15.844 +00:00: 2021-10-29T17:41:15.844Z ioredis:connection set the connection name [subscriber]
2021-10-29 17:41:15.844 +00:00: 2021-10-29T17:41:15.844Z ioredis:redis write command[10.18.62.156:6379 (subscriber)]: 0 -> client([ 'setname', 'subscriber' ])
2021-10-29 17:41:15.845 +00:00: 2021-10-29T17:41:15.845Z ioredis:connection set the connection to readonly mode
2021-10-29 17:41:15.845 +00:00: 2021-10-29T17:41:15.845Z ioredis:redis write command[10.18.62.156:6379 (subscriber)]: 0 -> readonly([])
2021-10-29 17:41:15.845 +00:00: 2021-10-29T17:41:15.845Z ioredis:connection send 1 commands in offline queue
2021-10-29 17:41:15.854 +00:00: 2021-10-29T17:41:15.845Z ioredis:redis write command[10.18.62.156:6379 (subscriber)]: 0 -> readonly([])
</details> |
I enabled Out of the blue it seems the whole cluster decided to reconnect, I don't see any errors prior
|
Well that was a fun ride... turns out a few months ago one of our Devs started creating new redis cluster connection on a certain request... |
We've recently been seeing huge slowdowns on our servers. We can't totally blame on redis yet, but we've noticed a huge amount of connections on our redis instance
It seems to go down only when we restart the servers.
For context, we have roughly 16 servers running all creating 4 connections each to the cluster.
The connections are long-lived (aka we never create new ones during the process). So I can only assume something in the reconnection behavior maybe isn't cleaning up the previous connections.
We are currently using ioredis version 4.19.2. I'll look at updating to latest see if it helps, but I haven't seen anything in the changelog that would suggest a fix. I also stumbled on #1295 which was closed for lack of more info.
I can provide as much info as I can. Not sure I can run
DEBUG=ioredis:*
on our production servers, but here's what we have from cloudwatch for the past 3 months where we sometimes peak over 700 connectionsI also ran
client list
on our redis instance a few hours after restarting many of our servers if it can help. We can see that a single addr can have multiple connections to the same topic(name)The text was updated successfully, but these errors were encountered: