神奇的Redis延迟

最近在做某业务Redis的缩容工作，涉及到数据迁移，而Redis的数据迁移看起来蛮简单的，一对一的数据迁移只需要在slave行配置masterauth
和slaveof 两个参数即可，当然迁移过程中涉及到其它特殊情况需要特殊处理外。

以上几个步骤都做好后，
就等着实例的切换了，不过在实例切换前我们还要检查同步情况、数据一致性等。在检查实例同步情况的时候发现了奇怪的现象：在迁移的540个实例中有个别实例(20个)
lag 比较高，而且还有增加的趋势，奇怪的是offset值一直是0。
slave0:ip=xxxx,port=xxxx,state=online,offset=0,lag=38392

经过观察一段时间后，发现这个现象并没有消失，而且 lag 也是随着时间的增加在增加，offset值始终保持0。难道这个数据slave一直没有应用？ 
cli 上 slave 后发现slave的 dbsize 和master 的dbsize 基本一致；monitor slave
也发现有命令正常同步；master set 一个key，在slave 上也能正确的读取到这个key；在看看slave 上的日志:
[13739] 10 Aug 15:49:46.017 * Connecting to MASTER xxxx.xxxx.xxx:xxx
[13739] 10 Aug 15:49:46.017 * MASTER <-> SLAVE sync started
[13739] 10 Aug 15:49:46.018 * Non blocking connect for SYNC fired the event.
[13739] 10 Aug 15:49:46.032 * Master replied to PING, replication can
continue...
[13739] 10 Aug 15:49:46.092 * Partial resynchronization not possible (no cached
master)
[13739] 10 Aug 15:49:46.120 # Unexpected reply to PSYNC from master: -LOADING
Redisis loading the dataset in memory
[13739] 10 Aug 15:49:46.120 * Retrying with SYNC...
[13739] 10 Aug 15:49:46.641 * MASTER <-> SLAVE sync: receiving 26845995 bytes
frommaster
[13739] 10 Aug 15:49:47.276 * MASTER <-> SLAVE sync: Flushing old data
[13739] 10 Aug 15:49:47.276 * MASTER <-> SLAVE sync: Loading DB in memory
[13739] 10 Aug 15:49:47.620 * MASTER <-> SLAVE sync: Finished with success
[13739] 10 Aug 15:49:47.621 * Background append only file rewriting started by
pid 22605
[22605] 10 Aug 15:49:48.724 * SYNC append only file rewrite performed
[22605] 10 Aug 15:49:48.725 * AOF rewrite: 0 MB of memory used by copy-on-write
[13739] 10 Aug 15:49:48.822 * Background AOF rewrite terminated with success
[13739] 10 Aug 15:49:48.822 * Parent diff successfully flushed to the rewritten
AOF (1148bytes)
[13739] 10 Aug 15:49:48.822 * Background AOF rewrite finished successfully
看起来似乎好像也正常 :(

那么问题来了，既然我们的数据能正常同步，为什么master 上看到的信息显示slave一直在延迟呢？难道？ 
打开代码找到这个lag 、offset的计算方式：
if (slave->replstate == SLAVE_STATE_ONLINE)
lag = time(NULL) - slave->repl_ack_time;

info = sdscatprintf(info,
"slave%d:ip=%s,port=%d,state=%s,"
"offset=%lld,lag=%ld\r\n",
slaveid,slaveip,slave->slave_listening_port,state,
slave->repl_ack_off, lag);
long long repl_ack_off; /* Replication ack offset, if this is a slave. */
long long repl_ack_time;/* Replication ack time, if this is a slave. */

可以发现这个lag 是通过master 的当前时间减去slave 通过ACK上报上来的时间得到的，到这里可以怀疑是 slave 一直没有 ACK ？

这里通过到lag，offset值正常的master 节点执行 monitor 命令可以发现，这些实例的slave 确实是有发送 ACK 命令回来的
，而这种看上去似乎异常的节点确实是没有ACK返回 。

到这里似乎找到了问题的关键了，那么为什么这种看似异常的slave 不发送ACK 给master 呢？这个还是得一层一层的扒开slave运行的面纱。

再次查看slave 运行日志，并且和其它实例对比，貌似可以发现一些不太相同的地方：

通过上图可以看到，能正常发送ACK给master实例的日志多了几行日志，而这些日志或许就是发送与不发送ACK的关键所在。

通过查看源码得到如下信息： 
replicationCron 函数每秒执行一次，如果当前实例有配置masterhost，那么会去检查同步的状态 server.repl_state ，
如果这个状态 为： REPL_STATE_CONNECT /* Must connect to master */，那么会尝试和Master 建立连接
connectWithMaster()，如果连接建立正常，那么和master 进行数据同步 syncWithMaster()，并更新初次发送PING
包给Master，等待Master
会用PONG，当收到Master的回应，并且进行AUTH等操作后，slave会尝试进行部分同步，当部分同步不成功时会进行全同步
slaveTryPartialResynchronization(),而这个函数里边发送的同步指令就是 PSYNC 指令，当master 回应的不是
+FULLRESYNC 或者 +CONTINUE时，那么统一的认为Master 不认识PSYNC
指令，而这时，为了兼容老版本的同步方式，这里会用SYNC指令重新发给Master。
psync_result = slaveTryPartialResynchronization(fd);
if (psync_result == PSYNC_CONTINUE) {
redisLog(REDIS_NOTICE, "MASTER <-> SLAVE sync: Master accepted a Partial
Resynchronization.");
return;
}
/* Fall back to SYNC if needed. Otherwise psync_result == PSYNC_FULLRESYNC
* and the server.repl_master_runid and repl_master_initial_offset are
* already populated. */
if (psync_result == PSYNC_NOT_SUPPORTED) {
redisLog(REDIS_NOTICE,"Retrying with SYNC...");
}

执行玩指令后，如果成功了就会继续进行后面的步骤，全同步接收RDB，FLUSHDB，LOADRDB等步骤。

到这里就可以解释两个实例输出的日志不太一致的地方，可以认为一个实例使用了PSYNC的同步方式，另个一个实例使用了SYNC
的方式。使用了SYNC同步方式的实例 server.repl_master_initial_offset = -1 , 而 使用了PSYNC 同步方式的实例
server.repl_master_initial_offset = 1 。（关于这个变量可以通过 gdb 工具进行验证，gdb有风险且用且珍惜~）

而现在回到发送ACK函数的地方:
/* Send ACK to master from time to time.
* Note that we do not send periodic acks to masters that don't
* support PSYNC and replication offsets. */
if (server.masterhost && server.master &&
!(server.master->flags & CLIENT_PRE_PSYNC))
replicationSendAck();
#define CLIENT_PRE_PSYNC (1<<16) /* Instance don't understand PSYNC. */

也就是说使用SYNC 同步方式的实例 (server.master->flags & CLIENT_PRE_PSYNC)
这个条件是不满足的，所以这个函数不会被执行。

为什么slave 不发送ACK给 master 的根本原因找到了，是因为 slave使用的同步方式为SYNC 方式。 
那么使用PSYNC 和 SYNC 时，master 会做不同的处理么？对同步数据有什么影响？show me the code :
{"sync",syncCommand,1,"ars",0,NULL,0,0,0,0,0},
{"psync",syncCommand,3,"ars",0,NULL,0,0,0,0,0},

if (!strcasecmp(c->argv[0]->ptr,"psync")) {
if (masterTryPartialResynchronization(c) == C_OK) {
server.stat_sync_partial_ok++;
return; /* No full resync needed, return. */
} else {
char *master_replid = c->argv[1]->ptr;
if (master_replid[0] != '?') server.stat_sync_partial_err++;
}
} else {
/* If a slave uses SYNC, we are dealing with an old implementation
* of the replication protocol (like redis-cli --slave). Flag the client
* so that we don't expect to receive REPLCONF ACK feedbacks. */
----这里也表明，使用了SYNC 方式的，master 也不期望slave 发送 ACK 回来
c->flags |= CLIENT_PRE_PSYNC;
}

可以看到，master对PSYNC和SYNC 两种同步方式的入口一致，不同的就是PSYNC 可以进行部分同步，而SYNC只能进行完全同步。

小结： 
redis slave 同步数据的方式有两种，PSYNC 和 SYNC ，当slave 使用PSYNC
同步数据失败时，会尝试使用SYNC方式同步，而使用SYNC方式同步数据时，并不会给Master 发送ACK 数据，导致master 上看到slave 的lag
信息不准确。

lag 这个值不一定能用来确定一个slave 是否有延迟，延迟多长时间。我们可以根据 master_last_io_seconds
来判断这个slave是否有延迟；或者我们需要通过外围的监控来发现。

• « 上一篇：Apache RocketMQ官方文档中文精简版-事务消息示例
• » 下一篇：RocketMQ手册