一次线上Redis类转换异常排查引发的思考

程序员文章站 2022-05-03 22:24:11

之前同事反馈说线上遇到Redis反序列化异常问题，异常如下：已知信息如下：该异常不是必现的，偶尔才会出现；出现该异常后重启应用或者过一会就好了；序列化协议使用了hessian。因为偶尔出现，首先看了报异常那块业务逻辑是不是有问题，看了一遍也发现什么问题。看了下对应日志，发现是在Redis读 ......

之前同事反馈说线上遇到redis反序列化异常问题，异常如下：

xxxclass1 cannot be cast to xxxclass2

已知信息如下：

该异常不是必现的，偶尔才会出现；
出现该异常后重启应用或者过一会就好了；
序列化协议使用了hessian。

因为偶尔出现，首先看了报异常那块业务逻辑是不是有问题，看了一遍也发现什么问题。看了下对应日志，发现是在redis读超时之后才出现的该异常，因此怀疑redis client操作逻辑那块导致的（公司架构组对redis做了一层封装），发现获取/释放redis连接如下代码：

 1 try {
 2     jedis = jedispool.getresource();
 3     // jedis业务读写操作
 4 } catch (exception e) {
 5     // 异常处理
 6 } finally {
 7     if (jedis != null) {
 8         // 归还给连接池
 9         jedispool.returnresourceobject(jedis);
10     }
11 }

初步认定原因为：发生了读写超时的连接，直接归还给连接池，下次使用该连接时读取到了上一次redis返回的数据。因此本地验证下，示例代码如下：

 1 @data
 2 @noargsconstructor
 3 @allargsconstructor
 4 static class person implements serializable {
 5     private string name;
 6     private int age;
 7 }
 8 @data
 9 @noargsconstructor
10 @allargsconstructor
11 static class dog implements serializable {
12     private string name;
13 }
14 
15 public static void main(string[] args) throws exception {
16     jedispoolconfig config = new jedispoolconfig();
17     config.setmaxtotal(1);
18     jedispool jedispool = new jedispool(config, "192.168.193.133", 6379, 2000, "123456");
19 
20     jedis jedis = jedispool.getresource();
21     jedis.set("key1".getbytes(), serialize(new person("luoxn28", 26)));
22     jedis.set("key2".getbytes(), serialize(new dog("tom")));
23     jedispool.returnresourceobject(jedis);
24 
25     try {
26         jedis = jedispool.getresource();
27         person person = deserialize(jedis.get("key1".getbytes()), person.class);
28         system.out.println(person);
29     } catch (exception e) {
30         // 发生了异常之后，未对该连接做任何处理
31         system.out.println(e.getmessage());
32     } finally {
33         if (jedis != null) {
34             jedispool.returnresourceobject(jedis);
35         }
36     }
37 
38     try {
39         jedis = jedispool.getresource();
40         dog dog = deserialize(jedis.get("key2".getbytes()), dog.class);
41         system.out.println(dog);
42     } catch (exception e) {
43         system.out.println(e.getmessage());
44     } finally {
45         if (jedis != null) {
46             jedispool.returnresourceobject(jedis);
47         }
48     }
49 }

连接超时时间设置2000ms，为了方便测试，可以在redis服务器上使用gdb命令断住redis进程（如果redis部署在linux系统上的话，还可以使用iptable命令在防火墙禁止某个回包），比如在执行 jedis.get("key1".getbytes() 代码前，对redis进程使用gdb命令断住，那么就会导致读取超时，然后就会触发如下异常：

person cannot be cast to dog

既然已经知道了该问题原因并且本地复现了该问题，对应解决方案是，在发生异常时归还给连接池时关闭该连接即可(jedis.close内部已经做了判断)，代码如下：

 1 try {
 2     jedis = jedispool.getresource();
 3     // jedis业务读写操作
 4 } catch (exception e) {
 5     // 异常处理
 6 } finally {
 7     if (jedis != null) {
 8         // 归还给连接池
 9         jedis.close();
10     }
11 }

至此，该问题解决。注意，因为使用了hessian序列化（其包含了类型信息，类似的有java本身序列化机制），所有会报类转换异常；如果使用了json序列化（其只包含对象属性信息），反序列化时不会报异常，只不过因为不同类的属性不同，会导致反序列化后的对象属性为空或者属性值混乱，使用时会导致问题，并且这种问题因为没有报异常所以更不容易发现。

既然说到了redis的连接，要知道的是，redis基于resp(redis serialization protocol)协议来通信，并且通信方式是停等方式，也就说一次通信独占一个连接直到client读取到返回结果之后才能释放该连接让其他线程使用。小伙伴们可以思考一下，redis通信能否像dubbo那样使用单连接+序列号（标识单次通信）通信方式呢？理论上是可以的，不过由于resp协议中并没有一个"序列号"的字段，所以直接靠原生的通信方法来实现是不现实的。不过我们可以通过echo命令传递并返回"序列号"+正常的读写方式来实现，这里要保证二者执行的原子性，可以通过lua脚本或者事务来实现，事务方式如下：

multi
echo "唯一序列号"
get key1
exec

然后客户端收到的结果是一个 [ "唯一序列号", "value1" ]的列表，你可以根据前一项识别出这是你发送的哪个请求。

为什么redis通信方式并没有采用类似于dubbo这种通信方式呢，个人认为有以下几点：

使用停等这种通信方式实现简单，并且协议字段尽可能紧凑；
redis都是内存操作，处理性能较强，停等协议不会造成客户端等待时间较长；
目前来看，通信方式这块不是redis使用上的性能瓶颈，这一点很重要。