Redis 异常三连环

时间:2024-06-08 22:53:01

请添加图片描述

本文针对一种特殊情况下的Reids连环异常,分别是下面三种异常:

  1. NullPointerException: Cannot read the array length because “arg” is null
  2. JedisDataException: ERR Protocol error: invalid bulk length
  3. 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)导致的,后续发送的所有命令都收不到响应,都会是这个错误。

这个错误和前面普遍适用的经验一样,和分页插件遇到的问题类似,当你使用不对埋下雷时,解决炸雷是解决不了问题的,解决了埋雷的问题才能从根本解决问题。