Showing posts with label troubleshooting. Show all posts
Showing posts with label troubleshooting. Show all posts

Monday, 14 November 2016

Redis Cluster - How to fix a cluster which is in broken state after migration

Sometimes in redis cluster, we need to expand the redis cluster by adding more machines. This is accomplished by adding more machines, making them as part of the cluster and resharding the existing cluster as explained here.

However, many times, the cluster is stuck in an inconsistent state when there is an error in resharding. This can happen because of many reasons like sudden termination of reshard script, redis timeout error while moving slots(in case the keys are too big), or if a key already exists in the target database(because it involves migration).

There is no quick fix to these problems, and one would have to understand the internals of how a slot movement happens.

But there is a general rule on what can be done to try to fix if a redis cluster is stuck in an inconsistent state during reshard/migration.

The following two are important ways to fix a cluster which was broken because of migration.


Run the Fix Script

Fixing a resharding error can be done by running the fix script provided by redis.
It can be run using

./redis-trib.rb fix 127.0.0.1:7000

We will need to change the ip address and port as per your configuration. Also, you only need to provide the ip address/port of only a single node which is part of the cluster. The configuration of the other nodes are read automatically by the script.


If the above cannot fix the cluster state, then you can follow the below step.

Setting the Cluster slots to a particular node.

Manually checking the keys in the unstable slot, and setting the slot to be served by a particular slot. We can execute the "cluster nodes" command on all the nodes and see if any slot in set in a migrating/importing state. If we are sure a slot belongs to a particular node and the node holds and serves the data for that slot, we can set the slot to that node by executing the cluster setslot <slot> node <nodeid> command as described here.

If a node 127.0.0.1:7000 does not have the correct configuration as per cluster nodes command executed on it, and it shows that the slot 1000 is with some other node, but for all other nodes, it shows that it is with the node with node id abcdefgghasgdkashd, then we need to correct the configuration of that node(127.0.0.1:7000). It can be executing like  the following.

redis-cli -h 127.0.0.1 -p 7001 cluster setslot 1000 node abcdefgghasgdkashd

The above command just assures the node 127.0.0.1:7000 that the slot 1000 is served by the node with node id abcdefgghasgdkashd, and that the node 127.0.0.1 should correct its configuration to affect the below.

Note that you need to run it if you are sure that all other nodes agree to it with their cluster nodes command, and you are sure that the data for slot 1000 resides in the node abcdefgghasgdkashd.


Friday, 11 November 2016

redis cluster - slave sync with master failed - client scheduled to be closed ASAP for overcoming of output buffer limits.

Sometimes while working with redis cluster, and while the master-slave replication happens, sometimes slave is not able to sync itself to the master.
While syncing, the slave's connection to the master breaks again and again.

The following are the logs on the slave instance(IP:Port are masked).

10 Nov 17:09:20.387 * Connecting to MASTER IP1:PORT1
10 Nov 17:09:20.387 * MASTER <-> SLAVE sync started
10 Nov 17:09:20.387 * Non blocking connect for SYNC fired the event.
10 Nov 17:09:20.387 * Master replied to PING, replication can continue...
10 Nov 17:09:20.388 * Trying a partial resynchronization (request 479e75d20ac03150de943a24d9b61300b6fa59d0:266086101935).
10 Nov 17:09:20.894 * Full resync from master: 479e75d20ac03150de943a24d9b61300b6fa59d0:266259284057
10 Nov 17:09:20.894 * Discarding previously cached master state.
10 Nov 17:10:31.281 * MASTER <-> SLAVE sync: receiving 3811948917 bytes from master
10 Nov 17:10:40.138 * MASTER <-> SLAVE sync: Flushing old data
10 Nov 17:11:11.933 * MASTER <-> SLAVE sync: Loading DB in memory
10 Nov 17:12:37.115 * MASTER <-> SLAVE sync: Finished with success
10 Nov 17:12:37.849 # Connection with master lost.
10 Nov 17:12:37.849 * Caching the disconnected master state.
10 Nov 17:12:38.866 * Connecting to MASTER IP1:PORT1
10 Nov 17:12:38.866 * MASTER <-> SLAVE sync started
10 Nov 17:12:38.866 * Non blocking connect for SYNC fired the event.

The error keeps repeating itself.
Somehow the error above does not give much clue. Just when the master-slave sync succeeds, connection with master is lost.

Looking at the master logs give more clue.
Below are master logs.

10 Nov 17:09:20.383 * Slave IP2:PORT2 asks for synchronization
10 Nov 17:09:20.383 * Unable to partial resync with slave IP2:PORT2 for lack of backlog (Slave request was: 266086101935).
10 Nov 17:09:20.383 * Starting BGSAVE for SYNC with target: disk
10 Nov 17:09:20.889 * Background saving started by pid 37651
10 Nov 17:10:30.557 * DB saved on disk
10 Nov 17:10:30.844 * RDB: 283 MB of memory used by copy-on-write
10 Nov 17:10:31.276 * Background saving terminated with success
10 Nov 17:10:39.561 * Synchronization with slave IP2:PORT2 succeeded
10 Nov 17:11:09.060 # Client id=2292912 addr=IP2:23666 fd=233 name= age=109 idle=9 flags=S db=0 sub=0 psub=0 multi=-1 qbuf=0 qbuf-free=0 obl=0 oll=7104 omem=127259816 events=rw cmd=psync scheduled to be closed ASAP for overcoming of output buffer limits.
10 Nov 17:11:09.160 # Connection with slave IP2:PORT2 lost.
10 Nov 17:12:38.861 * Slave IP2:PORT2 asks for synchronization
10 Nov 17:12:38.861 * Unable to partial resync with slave IP2:PORT2 for lack of backlog (Slave request was: 266261610586).
10 Nov 17:12:38.861 * Starting BGSAVE for SYNC with target: disk


The Key part is cmd=psync scheduled to be closed ASAP for overcoming of output buffer limits.

It seems to show that the slave connection was closed as it reached output buffer limits for the master.
Somehow we need to fix this.
There is a setting in the conf file
client-output-buffer-limit slave 256mb 64mb 60

Reading the excellent documentation seems to suggest that the two limits, 256 mb and 64 mb are two limits, hard limits and soft limits. If the client connection for slave exceeds 256 mb or exceeds 64 mb continuously for 60 seconds.

We can either increase this setting, and restart the master server, but it seems too much of an effort and a risk and restarting a master may make its outdated slave trying to become a master.
Thankfully, this can be changed at runtime by executing the following command on master server.


redis-cli -h MASTER_IP -p MASTER_PORT CONFIG get client-output-buffer-limit

It gives the output as 
1) "client-output-buffer-limit"
2) "normal 0 0 0 slave 268435456 67108864 60 pubsub 33554432 8388608 60"

Notice that the hard and soft limits for slave is 256 MB/64 MB (268435456/67108864 bytes)
We will update it to  1 GB/256 MB(1073741824/268435456 bytes) by executing the following command.


redis-cli -h MASTER_IP -p MASTER_PORT CONFIG set client-output-buffer-limit "normal 0 0 0 slave 1073741824 268435456 60 pubsub 33554432 8388608 60"

Note that depending on how far your slave is lagging behind the master and how fast your slave is able to consume the data from the master while syncing, you may have to increase the limit to more than 1GB/256 MB. Just be sure to go through the excellent documentation of client-output-buffer-limit in redis.conf.

After executing this command, we see that the slave succeeds in syncing with the master and does not give any other error.  


Below are the logs on slave after executing the command.

10 Nov 17:15:58.692 * MASTER <-> SLAVE sync started
10 Nov 17:15:58.692 * Non blocking connect for SYNC fired the event.
10 Nov 17:15:58.692 * Master replied to PING, replication can continue...
10 Nov 17:15:58.692 * Trying a partial resynchronization (request 479e75d20ac03150de943a24d9b61300b6fa59d0:266435075281).
10 Nov 17:15:59.195 * Full resync from master: 479e75d20ac03150de943a24d9b61300b6fa59d0:266612963059
10 Nov 17:15:59.195 * Discarding previously cached master state.
10 Nov 17:17:10.490 * MASTER <-> SLAVE sync: receiving 3811953308 bytes from master
10 Nov 17:17:19.613 * MASTER <-> SLAVE sync: Flushing old data
10 Nov 17:17:53.203 * MASTER <-> SLAVE sync: Loading DB in memory
10 Nov 17:19:19.332 * MASTER <-> SLAVE sync: Finished with success
10 Nov 18:01:31.139 * Background saving started by pid 16989


:)

Saturday, 24 September 2016

Redis Error - Can't save in background : fork: Cannot allocate memory

Redis periodically saves its data in memory onto the disk for backup in the form of rdb file. This is helpful in recovering the data if redis restarts or for backup purposes.
Sometimes while saving the data, redis may give the error: "Can't save in background : fork: Cannot allocate memory".



This error can come if redis has enough memory for the data, but not for saving the rdb file.
For this, you need to check a system param named "sysctl vm.overcommit_memory". Its value should be set to 1 instead of 0 by the command "sysctl vm.overcommit_memory=1" as shown below.



After setting this value, the background save can be successfully started, and it does not give an error.
The Below are the logs after the value was set to 1 and after starting background save.



Note that this error only comes when all three conditions hold

  • redis memory is close to or more than half of allocated memory/system memory(memory is 32+GB and 27 GB is left).
  • vm.overcommit_memory is set to 0
  • when redis does a background save.



Also, to make sure that this setting persists even when the redis machine restarts, it needs to be set in "/etc/sysctl.conf" file.

More details here