Redis 异常三连环

技术文章 > 解决问题 > Redis 异常三连环
#异常 #Redis #Java

本文针对一种特殊情况下的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中，如果你有不规范的分页调用，例如下面这种情况：

1
2
3
4
5
6
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，这两个错误执行过程看着都是正常的，所以按照经验先解决序列化的问题，解决这个问题后如何问题解决就说明是序列化导致的后续两个问题。

网上搜后两个问题时，大多数答案都不正确，但是在CSDN看到了一个答案：

这里通过分析源码找到了问题的原因，还提供了一个复现的例子，例子有点麻烦，所以我写了一个更简单的复现三个错误的例子：

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
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，这会导致下面的异常：

1
2
3
4
5
6
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 下面的代码被跳过：

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
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() 的代码如下：

1
2
3
4
5
6
7
8
9
10
11
12
@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") 时，看着很正常，但是会报错：

1
2
3
4
5
6
7
8
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") 就会报错：

1
2
3
4
5
6
7
8
9
10
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）导致的，后续发送的所有命令都收不到响应，都会是这个错误。

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

技术文章 > 解决问题 > Redis 异常三连环
#异常 #Redis #Java
Redis 异常三连环
https://blog.mybatis.io/post/20240604.html
作者
Liuzh
发布于
2024年6月4日
许可协议