redis主从复制（1）— 慢查询导致复制中断

redis的异常行为是一件令人头疼的问题。redis提供的错误日志只提供了一些server的运行状态信息，而没有server在故障现场的操作日志，比如执行了什么命令，命令操作对象的数据结构信息。如果redis也有mysql的slow-log，那么很多性能和故障问题也很容易处理。
1、redis rdb
在redis2.8版本以前，redis主从数据复制在生产上存在一个严重的问题。当主从连接断开时，redis slave会请请求master重传数据，进行全量的rdb重传。对于大数据集和高并发的redis实例，会引起redis阻塞相当长的时间，甚至导致redis不能处理任何客户端的请求。（redis latency）。

1）redis开启bgsave，调用fork创建一个子进程，然后对数据集进行copy-on-write。fork（）产生的子进程需要复制父进程的地址空间（页表）。比如在页大小为4KB的linux系统上，24GB的redis数据集，需要一个24GB/4KB*8=48MB的页表。子进程复制页表（read-only状态）的时候，redis主进程（父进程）不能处理写入请求。bgsave和aofrewrite的实现过程可以查看rdb.c和aof.c文件.

2）如果数据集较大，系统内存不是很充足，rdb会导致swap，redis性能非常低下。

2、2.8版本出现复制中断现象
而2.8版本实现了增量复制，利用缓冲区实现了断点续传，避免出现rdb重传。虽然psync不成功的情况，也会进行rdb重传。
下文要讲述的问题与rdb/aof并无多大关系，而下面的日志是在redis2.8.8上发生的复制中断的问题。
具体日志信息如下：
error log of slave

[181852] 12 Mar 20:31:34.695 # MASTER timeout: no data nor PING received...
[181852] 12 Mar 20:31:34.696 # Connection with master lost.
[181852] 12 Mar 20:31:34.696 * Caching the disconnected master state.
[181852] 12 Mar 20:31:34.697 * Connecting to MASTER 192.168.0.197:6384
[181852] 12 Mar 20:31:34.697 * MASTER <-> SLAVE sync started
[181852] 12 Mar 20:31:37.697 * Non blocking connect for SYNC fired the event.
[181852] 12 Mar 20:31:37.698 * Master replied to PING, replication can continue...
[181852] 12 Mar 20:31:37.698 * Trying a partial resynchronization (request 
737d5014a4916a0fcabfcbeef337fdc0d552a44a:64363916219).
[181852] 12 Mar 20:31:37.699 * Successful partial resynchronization with master.
[181852] 12 Mar 20:31:37.700 * MASTER <-> SLAVE sync: Master accepted a Partial Resynchronization.

errorerror log of master

[189366] 12 Mar 20:31:35.788 # Connection with slave 192.168.0.174:6384 lost.
[189366] 12 Mar 20:31:37.698 * Slave asks for synchronization
[189366] 12 Mar 20:31:37.699 * Partial resynchronization request accepted. Sending 135901 bytes of backlog starting from 
offset 64363916219.

3、客户端异常：

在应用客户端发生了什么呢？开发告诉我，应用程序端（PHP）出现大量的“Redis server went away”。

4、master-slave的基本行为
1）首先，slave（第34s）日志显示没有收到master的数据或者ping信息，slave重新连接master。
2）接着，master（第35s）日志提示从库断开了连接。
3）在第37秒，主从的日志均显示复制连接重现建立成功，并开始psync增量复制。

5、寻找问题的蛛丝马迹
1）机器上的其它的主从复制都很正常，没有复制断开的状况，排除了网络故障原因。
2）master机器上的流量突然上升，而从库的网卡流量比较正常。这说明master突然有数据大量读取。
3）master自身堵住了，没有rdb和aofrewr。那么只有redis的慢查询了，通过slowlog get 10。果不其然，存在大量的keys*操作，导致了复制中断。

“Redis server went away”的原因也也很明显，大量的慢查询导致redis server堵塞，不能立即响应redis客户端的请求而出现连接超时。

附加话题：redis复制超时
https://github.com/antirez/redis/issues/918

Since the master -> slave channel is one-way in Redis, currently replication timeout is only up to the slave. Basically this is what happens:
 
The master normally sends the replication stream to the slave.
The master also PINGs the slave from time to time, to make sure that even when no new data is available to be transmitted to the slave, the slave still get some news from the master.
Because of this, there is always data going from master to slave, so the slave will be able to detect when the connection is down and reconnect if possible.
 
On the master side, if we don't get an error from the socket, we keep sending data. The output buffer can get too large, but the limits in Redis 2.6 will detect that and close the connection with the slave.

转自：http://mdba.cn/?p=787