redis 普通客户端请求超过client-output-buffer-limit限制，导致主从连接断开的问题

一、问题

今天收到报警，两个节点之间连接断了，登录节点查看信息，发现已经恢复，好像并没有问题。

但是查看这两个redis节点的日志如下：

可以看出第一个节点收到主节点断开的消息，然后自己成为主库。之后又收到主节点好了的消息，就又把master让给了之前的主节点，开始复制主节点的数据。

（按理来说主节点起来之后不应该直接抢走master，不然会丢失数据，这里先不作讨论（ps:还没找到原因*^*））

再查看另外一个节点的日志：

可以看出，其中有一句报错信息

omem=67108864 events=r cmd=hgetall scheduled to be closed ASAP for overcoming of output buffer limits

可以看出，主库在接收到一次hgetall命令之后，占用输出缓冲区64M的内存（67108864B=64MB），超出了缓冲区的限制，所以马上把 hgetall scheduled 关闭了。（ASAP表示越快越好, adv 副词）

之后就看到它跟从库的连接断了，，，

二、查看资料

对于Redis服务器的输出（也就是命令的返回值）来说，其大小通常是不可控制的。有可能一个简单的命令，能够产生体积庞大的返回数据。另外也有可能因为执行了太多命令，导致产生返回数据的速率超过了往客户端发送的速率，这是也会导致服务器堆积大量消息，从而导致输出缓冲区越来越大，占用过多内存，甚至导致系统崩溃。

所幸，Redis设置了一些保护机制来避免这种情况的出现，不同类型的客户端有不同的限制参数。限制方式有如下两种：

• 大小限制，当某一个客户端的缓冲区超过某一个大小值时，直接关闭这个客户端的连接；

• 持续性限制，当某一个客户端的缓冲区持续一段时间占用过大空间时，会直接关闭客户端连接。

我们来看看配置文件关于客户端输出缓冲区的配置：

client-output-buffer-limit normal 0 0 0

client-output-buffer-limit slave 256mb 64mb 60

client-output-buffer-limit pubsub 8mb 2mb 60

后面三个参数分别表示 最大限制 最小限制 最小限制的持续时间

不同客户端有不同策略，策略如下：

• 对于普通客户端来说，限制为0，也就是不限制。因为普通客户端通常采用阻塞式的消息应答模式，何谓阻塞式呢？如：发送请求，等待返回，再发送请求，再等待返回。这种模式下，通常不会导致Redis服务器输出缓冲区的堆积膨胀；

• 对于Pub/Sub客户端（也就是发布/订阅模式），大小限制是8M，当输出缓冲区超过8M时，会关闭连接。持续性限制是，当客户端缓冲区大小持续60秒超过2M，则关闭客户端连接；

• 对于slave客户端来说，大小限制是256M，持续性限制是当客户端缓冲区大小持续60秒超过64M，则关闭客户端连接。

上述三种规则都是可以修改的。可以通过CONFIG SET 命令设置或者直接修改redis.conf文件。

下面提供一种临时解决问题的方法，保证服务的可用性。

临时解决

# 获取当前配置
$ redis-cli -h xxx -p xxx -a xxx config get client-output-buffer-limit 
1) "client-output-buffer-limit"
2) "normal 67108864 33554432 10 slave 4294967296 2147483648 1200 pubsub 33554432 8388608 60"
# 修改配置
$ redis-cli -h xxx -p xxx -a xxx config  set client-output-buffer-limit "normal 67108864 33554432 10 slave 8294967296 2147483648 1200 pubsub 33554432 8388608 60"
OK

三、对比分析

找到我们的关于输出缓冲区的配置如下：

client-output-buffer-limit normal 64mb 32mb 10
client-output-buffer-limit slave 4096mb 2048mb 1200
client-output-buffer-limit pubsub 32mb 8mb 60

可以看到，我们的普通客户端的输出缓冲区是有配置的，超过64M就会关闭连接。

但是这个是普通客户端超过缓冲区限制，为啥会导致从库断开连接呢？？

继续观察日志，发现一个问题：

这是在从库上第一条日志：（33482 redis-4.0.12）

152440:S 19 Sep 14:37:24.578 * FAIL message received from 28fb85e0ea37a8e2ef016e5be71d2713e8edf1ce about 58c5ef7e9c0e53c6097f5f52c504f083a2b1e09b
152440:S 19 Sep 14:37:24.581 # Start of election delayed for 511 milliseconds (rank #0, offset) 337640614161).//日志打印了选举延迟511毫秒之后执行，并打印当前从节点复制偏移量
152440:S 19 Sep 14:37:25.159 # Starting a failover election for epoch 61.
152440:S 19 Sep 14:37:25.166 # Failover election won: I'm the new master.
152440:S 19 Sep 14:37:25.166 # configEpoch set to 61 after successful failover

这是主库上的日志:

148054:M 19 Sep 14:37:05.672 # Client id=11774588 addr=10.114.2.22:55968 fd=276 name= age=0 idle=0 flags=N db=0 sub=0 psub=0 multi=-1 qbuf=0 qbuf-free=32768 obl=16378 oll=4090 omem=67108870 events=r cmd=hgetall scheduled to be closed ASAP for overcoming of output buffer limits.
148054:M 19 Sep 14:37:30.510 # Connection with slave 10.136.169.48:33504 lost.
148054:M 19 Sep 14:37:32.990 # Client id=11774590 addr=?:0 fd=76 name= age=0 idle=0 flags=N db=0 sub=0 psub=0 multi=-1 qbuf=14 qbuf-free=32754 obl=16378 oll=4090 omem=67108870 events=r cmd=hgetall scheduled to be closed ASAP for overcoming of output buffer limits.

注意观察时间点，就可以发现：

• 152440:S 19 Sep 14:37:24.578 从库被告知主库已经fail
• 152440:S 19 Sep 14:37:24.581——14:37:25.166 从库通过投票来成为新的master

---

• 148054:M 19 Sep 14:37:05.672 主库接收到hgetall命令，超出缓冲区限制，将该客户端连接关闭
• 148054:M 19 Sep 14:37:30.510 主库发现与从库的连接断开

说明主库在正常的接受客户端的请求，突然收到一个 hgetall 命令，请求哈希表里的全部数据。但是返回的数据量太大，超出了设置的普通客户端输出缓冲区，主库阻塞住。导致集群中28fb85e0ea37a8e2ef016e5be71d2713e8edf1ce节点检测不到该主库，所以将其主观下线，开始投票进行选举。在进行选举的过程中，主库还是被阻塞的，没有接收到消息，所以最后被客观下线了。。。。。。

从库收到主库下线的消息是28fb85e0ea37a8e2ef016e5be71d2713e8edf1ce节点发来的，该节点的日志如下：

153411:M 19 Sep 14:37:24.574 * Marking node 58c5ef7e9c0e53c6097f5f52c504f083a2b1e09b as failing (quorum reached).
153411:M 19 Sep 14:37:25.163 # Failover auth granted to d05842ddde2279be6a15d98e4a1fde211cf33edb for epoch 61

看到该节点在14:37:24.574将58c5ef7e9c0e53c6097f5f52c504f083a2b1e09b节点（也就是刚才的主库）设置成了failing状态。然后投票给了从库。
根据redis集群的主从切换原理，这期间应该是发生了投票啥的，所以应该观察一下其他主节点的日志信息，看看其他主节点做了啥。（不用看从库，因为只有主库才有资格进行投票）

观察了几个主节点，全是这样的信息：

152200:M 19 Sep 14:37:24.578 * FAIL message received from 28fb85e0ea37a8e2ef016e5be71d2713e8edf1ce about 58c5ef7e9c0e53c6097f5f52c504f083a2b1e09b
152200:M 19 Sep 14:37:25.163 # Failover auth granted to d05842ddde2279be6a15d98e4a1fde211cf33edb for epoch 61

152260:M 19 Sep 14:37:24.578 * FAIL message received from 28fb85e0ea37a8e2ef016e5be71d2713e8edf1ce about 58c5ef7e9c0e53c6097f5f52c504f083a2b1e09b
152260:M 19 Sep 14:37:25.162 # Failover auth granted to d05842ddde2279be6a15d98e4a1fde211cf33edb for epoch 61

152320:M 19 Sep 14:37:24.578 * FAIL message received from 28fb85e0ea37a8e2ef016e5be71d2713e8edf1ce about 58c5ef7e9c0e53c6097f5f52c504f083a2b1e09b
152320:M 19 Sep 14:37:25.163 # Failover auth granted to d05842ddde2279be6a15d98e4a1fde211cf33edb for epoch 61

这些信息是收到28fb85e0ea37a8e2ef016e5be71d2713e8edf1ce节点对故障节点的客观下线之后，开始投票选举一个从节点来代替之前的故障节点成为主节点。

(quorum reached)是啥意思？
quorum reached 表示达到一半以上的投票，可以尝试对节点客观下线
通知集群内所有的节点标记故障节点为客观下线状态并立刻生效。

在有日志记录28fb85e0ea37a8e2ef016e5be71d2713e8edf1ce节点广播 58c5ef7e9c0e53c6097f5f52c504f083a2b1e09b节点客观下线之前，各个主节点内部已经对故障节点进行了主观下线，并在主节点内通信交流。

只是28fb85e0ea37a8e2ef016e5be71d2713e8edf1ce节点首先收集到大于一半主节点关于故障节点的pfail信息，下线报告链表第一个达到条件（在cluster-node-time*2时间内收集到一半以上槽节点的下线报告），所以由它来广播客观下线的信息。

注意：cluster-nodetimeout

如果在cluster-node-time*2时间内无法收集到一半以上槽节点的下线报告，那么之前的下线报告将会过期，也就是说主观下线上报的速度追赶不上
下线报告过期的速度，那么故障节点将永远无法被标记为客观下线从而导致故障转移失败。因此不建议将cluster-node-time设置得过小。

客观下线信息发出之后，就开始进行故障恢复和转移。。。

但是再仔细观察日志，发现这个主从切换有点频繁和奇怪，这个放在下一篇博文中讨论 https://blog.csdn.net/damanchen/article/details/101075977