Redis Cluster:Too many Cluster redirections异常
一、现象:我们的redis私有云,对外提供了redis-standalone, redis-sentinel, redis-cluster三种类型的redis服务。其中redis-cluster, 使用的版本是 Redis Cluster 3.0.2, 客户端是jedis 2.7.2。有人在使用时候,业务的日志中发现了一些异常(Too many Cluster redirections)。二、je
一、现象:
我们的redis私有云,对外提供了redis-standalone, redis-sentinel, redis-cluster三种类型的redis服务。
其中redis-cluster, 使用的版本是 Redis Cluster 3.0.2, 客户端是jedis 2.7.2。
有人在使用时候,业务的日志中发现了一些异常(Too many Cluster redirections)。
二、jedis源码分析:
先从jedis源码中找到这个异常,这段异常是在JedisClusterCommand类中
Java代码
- if (redirections <= 0) {
- throw new JedisClusterMaxRedirectionsException("Too many Cluster redirections? key=" + key);
- }
-
if (redirections <= 0) {
-
throw new JedisClusterMaxRedirectionsException("Too many Cluster redirections? key=" + key);
-
}
在jedis中调用redis-cluster使用的JedisCluster类,所有api的调用方式类似如下:
Java代码
- public String set(final String key, final String value) {
- return new JedisClusterCommand<String>(connectionHandler, maxRedirections) {
- @Override
- public String execute(Jedis connection) {
- return connection.set(key, value);
- }
- }.run(key);
- }
-
public String set(final String key, final String value) {
-
return new JedisClusterCommand<String>(connectionHandler, maxRedirections) {
-
@Override
-
public String execute(Jedis connection) {
-
return connection.set(key, value);
-
}
-
}.run(key);
-
}
所以重点代码在JedisClusterCommand这个类里,重要代码如下:
Java代码
- public T run(int keyCount, String... keys) {
- if (keys == null || keys.length == 0) {
- throw new JedisClusterException("No way to dispatch this command to Redis Cluster.");
- }
- if (keys.length > 1) {
- int slot = JedisClusterCRC16.getSlot(keys[0]);
- for (int i = 1; i < keyCount; i++) {
- int nextSlot = JedisClusterCRC16.getSlot(keys[i]);
- if (slot != nextSlot) {
- throw new JedisClusterException("No way to dispatch this command to Redis Cluster "
- + "because keys have different slots.");
- }
- }
- }
- return runWithRetries(SafeEncoder.encode(keys[0]), this.redirections, false, false);
- }
- private T runWithRetries(byte[] key, int redirections, boolean tryRandomNode, boolean asking) {
- if (redirections <= 0) {
- JedisClusterMaxRedirectionsException exception = new JedisClusterMaxRedirectionsException(
- "Too many Cluster redirections? key=" + SafeEncoder.encode(key));
- throw exception;
- }
- Jedis connection = null;
- try {
- if (asking) {
- // TODO: Pipeline asking with the original command to make it
- // faster....
- connection = askConnection.get();
- connection.asking();
- // if asking success, reset asking flag
- asking = false;
- } else {
- if (tryRandomNode) {
- connection = connectionHandler.getConnection();
- } else {
- connection = connectionHandler.getConnectionFromSlot(JedisClusterCRC16.getSlot(key));
- }
- }
- return execute(connection);
- } catch (JedisConnectionException jce) {
- if (tryRandomNode) {
- // maybe all connection is down
- throw jce;
- }
- // release current connection before recursion
- releaseConnection(connection);
- connection = null;
- // retry with random connection
- return runWithRetries(key, redirections - 1, true, asking);
- } catch (JedisRedirectionException jre) {
- // if MOVED redirection occurred,
- if (jre instanceof JedisMovedDataException) {
- // it rebuilds cluster's slot cache
- // recommended by Redis cluster specification
- this.connectionHandler.renewSlotCache(connection);
- }
- // release current connection before recursion or renewing
- releaseConnection(connection);
- connection = null;
- if (jre instanceof JedisAskDataException) {
- asking = true;
- askConnection.set(this.connectionHandler.getConnectionFromNode(jre.getTargetNode()));
- } else if (jre instanceof JedisMovedDataException) {
- } else {
- throw new JedisClusterException(jre);
- }
- return runWithRetries(key, redirections - 1, false, asking);
- } finally {
- releaseConnection(connection);
- }
- }
-
public T run(int keyCount, String... keys) {
-
if (keys == null || keys.length == 0) {
-
throw new JedisClusterException("No way to dispatch this command to Redis Cluster.");
-
}
-
if (keys.length > 1) {
-
int slot = JedisClusterCRC16.getSlot(keys[0]);
-
for (int i = 1; i < keyCount; i++) {
-
int nextSlot = JedisClusterCRC16.getSlot(keys[i]);
-
if (slot != nextSlot) {
-
throw new JedisClusterException("No way to dispatch this command to Redis Cluster "
-
+ "because keys have different slots.");
-
}
-
}
-
}
-
return runWithRetries(SafeEncoder.encode(keys[0]), this.redirections, false, false);
-
}
-
private T runWithRetries(byte[] key, int redirections, boolean tryRandomNode, boolean asking) {
-
if (redirections <= 0) {
-
JedisClusterMaxRedirectionsException exception = new JedisClusterMaxRedirectionsException(
-
"Too many Cluster redirections? key=" + SafeEncoder.encode(key));
-
throw exception;
-
}
-
Jedis connection = null;
-
try {
-
if (asking) {
-
// TODO: Pipeline asking with the original command to make it
-
// faster....
-
connection = askConnection.get();
-
connection.asking();
-
// if asking success, reset asking flag
-
asking = false;
-
} else {
-
if (tryRandomNode) {
-
connection = connectionHandler.getConnection();
-
} else {
-
connection = connectionHandler.getConnectionFromSlot(JedisClusterCRC16.getSlot(key));
-
}
-
}
-
return execute(connection);
-
} catch (JedisConnectionException jce) {
-
if (tryRandomNode) {
-
// maybe all connection is down
-
throw jce;
-
}
-
// release current connection before recursion
-
releaseConnection(connection);
-
connection = null;
-
// retry with random connection
-
return runWithRetries(key, redirections - 1, true, asking);
-
} catch (JedisRedirectionException jre) {
-
// if MOVED redirection occurred,
-
if (jre instanceof JedisMovedDataException) {
-
// it rebuilds cluster's slot cache
-
// recommended by Redis cluster specification
-
this.connectionHandler.renewSlotCache(connection);
-
}
-
// release current connection before recursion or renewing
-
releaseConnection(connection);
-
connection = null;
-
if (jre instanceof JedisAskDataException) {
-
asking = true;
-
askConnection.set(this.connectionHandler.getConnectionFromNode(jre.getTargetNode()));
-
} else if (jre instanceof JedisMovedDataException) {
-
} else {
-
throw new JedisClusterException(jre);
-
}
-
return runWithRetries(key, redirections - 1, false, asking);
-
} finally {
-
releaseConnection(connection);
-
}
-
}
代码解释:
1. 所有jedis.set这样的调用,都用JedisClusterCommand包装起来(模板方法)
2. 如果操作的是多个不同的key, 会抛出如下异常,因为redis-cluster不支持key的批量操作(可以通过其他方法解决,以后会介绍):
Java代码
- throw new JedisClusterException("No way to dispatch this command to Redis Cluster because keys have different slots.");
throw new JedisClusterException("No way to dispatch this command to Redis Cluster because keys have different slots.");
3. 参数解释
Java代码
- private T runWithRetries(byte[] key, int redirections, boolean tryRandomNode, boolean asking) {
private T runWithRetries(byte[] key, int redirections, boolean tryRandomNode, boolean asking) {
(1) key: 不多说了
(2) redirections: 节点调转次数(实际可以看做是重试次数)
(3) tryRandomNode: 是否从redis cluster随机选一个节点进行操作
(4) asking: 是否发生了asking问题
4. 逻辑说明:
正常逻辑:
(1) asking = true: 获取asking对应的jedis, 然后用这个jedis操作。
(2) tryRandomNode= true: 从jedis连接池随机获取一个可用的jedis, 然后用这个jedis操作。
(3) 都不是:直接用key->slot->jedis,直接找到key对应的jedis, 然后用这个jedis操作。
异常逻辑:
(1) JedisConnectionException: 连接出了问题,连接断了、超时等等,tryRandomNode= true,递归调用本函数
(2) JedisRedirectionException分两种:
---JedisMovedDataException: 节点迁移了,重新renew本地slot对redis节点的对应Map
---JedisAskDataException: 数据迁移,发生asking问题, 获取asking的Jedis
此过程最多循环redirections次。
异常含义:试了redirections次(上述),仍然没有完成redis操作。
三、原因猜测:
1. 超时比较多,默认超时时间是2秒。
(1). 网络原因:比如是否存在跨机房、网络割接等等。
(2). 慢查询,因为redis是单线程,如果有慢查询的话,会阻塞住之后的操作。
(3). value值过大?
(4). aof 重写/rdb fork发生?
2. 节点之间关系发生变化,会发生JedisMovedDataException
(1)在linux上的redis的配置文件中的 bind 参数所绑定的ip如果是 127.0.0.1 但测试时却是使用该主机的局域网地址会导致 redirection异常 ,
所以bind参数应该绑定主机的实际ip。
3. 数据在节点之间迁移,会发生JedisAskDataException
四、定位方法:
看了一下redis的日志第三节中的2,3并未发生,应该是超时的情况。
异常发生在2015-10-19 04:34:30左右,给出如下异常key值
Java代码
- key=v11Pay|huid|wlunm99_561555097
- key=play_anchorroom_info_529460
- key=v11Pay|huid|qq-qhncnxujax
- key=play_anchor_info_qq-luzvfcftnf
- key=play_anchor_info_qq-luzvfcftnf
- key=play_anchorroom_info_550649
- key=play_anchor_info_qq-cfrkukhdsd
- key=play_anchor_info_qq-rbufgcqbvk
-
key=v11Pay|huid|wlunm99_561555097
-
key=play_anchorroom_info_529460
-
key=v11Pay|huid|qq-qhncnxujax
-
key=play_anchor_info_qq-luzvfcftnf
-
key=play_anchor_info_qq-luzvfcftnf
-
key=play_anchorroom_info_550649
-
key=play_anchor_info_qq-cfrkukhdsd
-
key=play_anchor_info_qq-rbufgcqbvk
经过查询,这些key都同时定位在一个redis实例上,于是看了一下这个redis实例的日志(与异常时间点对应),发现如下:AOF fsync发生了异常,以经验看是本地IO使用较大造成的。
Java代码
- 17932:M 19 Oct 04:35:30.010 * Asynchronous AOF fsync is taking too long (disk is busy?). Writing the AOF buffer without waiting for fsync to complete, this may slow down Redis.
- 17932:M 19 Oct 04:35:41.087 * Asynchronous AOF fsync is taking too long (disk is busy?). Writing the AOF buffer without waiting for fsync to complete, this may slow down Redis.
- 17932:M 19 Oct 04:35:47.044 * Asynchronous AOF fsync is taking too long (disk is busy?). Writing the AOF buffer without waiting for fsync to complete, this may slow down Redis.
- 17932:M 19 Oct 10:15:51.463 * Starting automatic rewriting of AOF on 1795% growth
-
17932:M 19 Oct 04:35:30.010 * Asynchronous AOF fsync is taking too long (disk is busy?). Writing the AOF buffer without waiting for fsync to complete, this may slow down Redis.
-
17932:M 19 Oct 04:35:41.087 * Asynchronous AOF fsync is taking too long (disk is busy?). Writing the AOF buffer without waiting for fsync to complete, this may slow down Redis.
-
17932:M 19 Oct 04:35:47.044 * Asynchronous AOF fsync is taking too long (disk is busy?). Writing the AOF buffer without waiting for fsync to complete, this may slow down Redis.
-
17932:M 19 Oct 10:15:51.463 * Starting automatic rewriting of AOF on 1795% growth
看了一下tsar的历史记录:tsar --io -n 2 | head -200
Java代码
- Time rrqms wrqms rs ws rsecs wsecs rqsize qusize await svctm util
- 19/10/15-04:00 0.00 164.08 0.01 34.52 0.04 745.15 21.58 0.00 25.30 4.13 14.26
- 19/10/15-04:05 40.38 1.1K 218.49 78.39 13.9K 4.9K 64.55 7.00 24.63 2.80 83.19
- 19/10/15-04:10 37.15 1.0K 360.58 71.91 13.4K 4.3K 42.04 6.00 14.67 1.70 73.34
- 19/10/15-04:15 1.99 1.5K 21.98 115.38 588.69 6.6K 53.12 5.00 39.86 1.98 27.14
- 19/10/15-04:20 40.17 1.0K 278.00 76.79 10.4K 4.2K 42.32 4.00 11.48 1.60 56.85
- 19/10/15-04:25 78.28 861.13 381.34 62.33 14.3K 3.6K 41.40 4.00 9.85 1.51 66.78
- 19/10/15-04:30 81.64 913.85 402.37 55.35 15.1K 3.8K 42.18 4.00 9.47 1.41 64.71
- 19/10/15-04:35 21.92 888.72 145.97 58.00 16.2K 3.7K 99.71 4.00 20.57 3.63 74.04
- 19/10/15-04:40 39.72 474.01 169.01 48.26 14.3K 2.0K 77.09 3.00 17.83 4.14 89.89
- 19/10/15-04:45 47.02 537.60 149.41 41.50 16.7K 2.3K 101.55 3.00 18.27 4.21 80.35
-
Time rrqms wrqms rs ws rsecs wsecs rqsize qusize await svctm util
-
19/10/15-04:00 0.00 164.08 0.01 34.52 0.04 745.15 21.58 0.00 25.30 4.13 14.26
-
19/10/15-04:05 40.38 1.1K 218.49 78.39 13.9K 4.9K 64.55 7.00 24.63 2.80 83.19
-
19/10/15-04:10 37.15 1.0K 360.58 71.91 13.4K 4.3K 42.04 6.00 14.67 1.70 73.34
-
19/10/15-04:15 1.99 1.5K 21.98 115.38 588.69 6.6K 53.12 5.00 39.86 1.98 27.14
-
19/10/15-04:20 40.17 1.0K 278.00 76.79 10.4K 4.2K 42.32 4.00 11.48 1.60 56.85
-
19/10/15-04:25 78.28 861.13 381.34 62.33 14.3K 3.6K 41.40 4.00 9.85 1.51 66.78
-
19/10/15-04:30 81.64 913.85 402.37 55.35 15.1K 3.8K 42.18 4.00 9.47 1.41 64.71
-
19/10/15-04:35 21.92 888.72 145.97 58.00 16.2K 3.7K 99.71 4.00 20.57 3.63 74.04
-
19/10/15-04:40 39.72 474.01 169.01 48.26 14.3K 2.0K 77.09 3.00 17.83 4.14 89.89
-
19/10/15-04:45 47.02 537.60 149.41 41.50 16.7K 2.3K 101.55 3.00 18.27 4.21 80.35
于是发现从4点开始IO开销一直增大,以经验看应该是有定时任务(都是托管的机器,上面还有别人的应用),于是发现了如下,是一个nginx合并的脚本,本地IO开销较大。
Java代码
- 00 04 * * * sh /opt/script/logcron.sh
- 00 04 * * * sh /opt/script/logremove.sh
-
00 04 * * * sh /opt/script/logcron.sh
-
00 04 * * * sh /opt/script/logremove.sh
五、解决方法:
(1) 和使用方沟通一下,他们完全把redis当做memcache用,也就是允许断电后数据丢失,重新从数据源获取数据写到缓存,因此关闭了aof配置(此方法不治本)
(2) 定时脚本下线或者优化。(最终采用此方法)
更多推荐
所有评论(0)