本文针对一种特殊情况下的Reids连环异常,分别是下面三种异常:
- NullPointerException: Cannot read the array length because “arg” is null
- JedisDataException: ERR Protocol error: invalid bulk length
- JedisConnectionException: Unexpected end of stream.
先说个普遍适用的处理错误经验,当你发现日志最新出现的某个错误的时候,多往前翻翻日志,看看更早的时候有没有其他的错误,很多时候的错误都在更早的时候出现,这个错误看似不影响后续的使用,但是埋下了很多坑,等待时机合适就会爆发出来。如果你只关注最后产生直接感受的这个错误,很可能走弯路,百思不得其解。
这个问题还频繁出现在分页插件PageHelper中,如果你有不规范的分页调用,例如下面这种情况:
PageHelper.start(1, 10);
if(满足条件) {
result = mapper.select(params);
} else {
result = emptyList();
}
调用PageHelper时,你设置的分页信息已经绑定到线程,当满足条件执行 mybatis 查询时,分页信息会被消费并清除,当不满足条件时,分页信息仍然绑定在线程上,相当于埋了个雷,等其他请求再使用这个线程时,只要有查询,就会消费这里的分页信息,你的感受就是我没有调用分页,为什么查询被分页了?分页插件文档有 安全调用 的多种方式,而且后续版本为了方便识别这种错误,还支持在消费分页信息时,打印设置分页参数时的堆栈信息,通过堆栈信息可以识别不安全的调用方式。很多人吐槽PageHelper不安全,实际上都是不正确使用导致的,如果乱用,Java安全吗,把系统删了怎么办?JDBC安全吗,把库删了怎么办?
回归正题,某个项目在测试环境没有用Redis缓存,在线上环境配置了Redis缓存,之后就遇到了缓存的问题,从日志能看到莫名其妙的 Unexpected end of stream.
和 ERR Protocol error: invalid bulk length
错误信息,以及更靠前有明确其他错误提示的 java.io.NotSerializableException: com.example.SimpleValue
,并没有看到上面列的第一个异常。使用 arthas 监控时发现错误2和3时操作的 key
和错误1时完全不相关,所以前期处理的重点是错误2和3,这两个错误执行过程看着都是正常的,所以按照经验先解决序列化的问题,解决这个问题后如何问题解决就说明是序列化导致的后续两个问题。
网上搜后两个问题时,大多数答案都不正确,但是在****看到了一个答案:
- 关于spring-data操作redis报invalid-bulk-length的错误分析
这里通过分析源码找到了问题的原因,还提供了一个复现的例子,例子有点麻烦,所以我写了一个更简单的复现三个错误的例子:
import redis.clients.jedis.Jedis;
import redis.clients.jedis.JedisPool;
import redis.clients.jedis.JedisPoolConfig;
import java.nio.charset.StandardCharsets;
public class RedisErrorTest {
public static void main(String[] args) {
JedisPool pool = new JedisPool(new JedisPoolConfig(), "localhost");
try (Jedis jedis = pool.getResource()) {
try {
jedis.set("parent".getBytes(StandardCharsets.UTF_8), null);
} catch (Exception e) {
e.printStackTrace();
}
try {
jedis.set("hello", "world");
} catch (Exception e) {
e.printStackTrace();
}
try {
String val = jedis.get("hello");
System.out.println(val);
} catch (Exception e) {
e.printStackTrace();
}
}
pool.close();
}
}
错误的重点是 jedis.set("parent".getBytes(StandardCharsets.UTF_8), null);
这里设置了 null,这会导致下面的异常:
java.lang.NullPointerException: Cannot read the array length because "arg" is null
at redis.clients.jedis.Protocol.sendCommand(Protocol.java:99)
at redis.clients.jedis.Protocol.sendCommand(Protocol.java:84)
at redis.clients.jedis.Connection.sendCommand(Connection.java:127)
at redis.clients.jedis.BinaryClient.set(BinaryClient.java:110)
at queue.RedisErrorTest.main(RedisErrorTest.java:17)
这个异常会导致 jedis.set
下面的代码被跳过:
public String set(final byte[] key, final byte[] value) {
checkIsInMultiOrPipeline();
client.set(key, value);
//下面代码没有被执行
return client.getStatusCodeReply();
}
public String getStatusCodeReply() {
//因此不会执行 flush
flush();
pipelinedCommands--;
final byte[] resp = (byte[]) readProtocolWithCheckingBroken();
if (null == resp) {
return null;
} else {
return SafeEncoder.encode(resp);
}
}
protected void flush() {
try {
//这里也就无法执行了
outputStream.flush();
} catch (IOException ex) {
broken = true;
throw new JedisConnectionException(ex);
}
}
outputStream.flush()
的代码如下:
@Override
public void flush() throws IOException {
flushBuffer();
out.flush();
}
private void flushBuffer() throws IOException {
if (count > 0) {
out.write(buf, 0, count);
//这里不执行
count = 0;
}
}
由于 count 没有置0,等下个命令执行时会在上面未完成命令基础上继续写入。
继续使用这个jedis连接操作 jedis.set("hello", "world")
时,看着很正常,但是会报错:
redis.clients.jedis.exceptions.JedisDataException: ERR Protocol error: invalid bulk length
at redis.clients.jedis.Protocol.processError(Protocol.java:127)
at redis.clients.jedis.Protocol.process(Protocol.java:161)
at redis.clients.jedis.Protocol.read(Protocol.java:215)
at redis.clients.jedis.Connection.readProtocolWithCheckingBroken(Connection.java:340)
at redis.clients.jedis.Connection.getStatusCodeReply(Connection.java:239)
at redis.clients.jedis.Jedis.set(Jedis.java:121)
at queue.RedisErrorTest.main(RedisErrorTest.java:22)
此时当前连接已经不能正常响应了,后续再 jedis.get("hello")
就会报错:
redis.clients.jedis.exceptions.JedisConnectionException: Unexpected end of stream.
at redis.clients.util.RedisInputStream.ensureFill(RedisInputStream.java:199)
at redis.clients.util.RedisInputStream.readByte(RedisInputStream.java:40)
at redis.clients.jedis.Protocol.process(Protocol.java:151)
at redis.clients.jedis.Protocol.read(Protocol.java:215)
at redis.clients.jedis.Connection.readProtocolWithCheckingBroken(Connection.java:340)
at redis.clients.jedis.Connection.getBinaryBulkReply(Connection.java:259)
at redis.clients.jedis.Connection.getBulkReply(Connection.java:248)
at redis.clients.jedis.Jedis.get(Jedis.java:153)
at queue.RedisErrorTest.main(RedisErrorTest.java:27)
这个错误信息是因为没有收到服务器端响应(in.read() == -1
)导致的,后续发送的所有命令都收不到响应,都会是这个错误。
这个错误和前面普遍适用的经验一样,和分页插件遇到的问题类似,当你使用不对埋下雷时,解决炸雷是解决不了问题的,解决了埋雷的问题才能从根本解决问题。