开发者社区> 无毁的湖光> 正文
阿里云
为了无法计算的价值
打开APP
阿里云APP内打开

解Bug之路-串包Bug

简介:
+关注继续查看

解Bug之路-串包Bug

笔者很热衷于解决Bug,同时比较擅长(网络/协议)部分,所以经常被唤去解决一些网络IO方面的Bug。现在就挑一个案例出来,写出分析思路,以飨读者,希望读者在以后的工作中能够少踩点坑。

串包Bug现场

前置故障Redis超时

由于某个系统大量的hget、hset操作将Redis拖垮,通过监控发现Redis的CPU和IO有大量的尖刺,CPU示意图下图所示:
输入图片说明
CPU达到了100%,导致很多Redis请求处理不及时,其它业务系统都频繁爆出readTimeOut。此时,紧急将这个做大量hget、hset的系统kill,过了一段时间,Redis的CPU恢复平稳。

一波未平,一波又起

就在我们以为事件平息的时候,线上爆出登录后的用户名称不正确。同时错误日志里面也有大量的Redis返回不正确的报错。尤为奇葩的是,系统获取一个已经存在的key,例如get User123456Name,返回的竟然是redis的成功返回OK。示意图如下:

Jedis.sendCommand:get User123456Name
Jedis.return:OK
    or
Jedis.sendCommand:get User123456Name
Jedis.return:user789

我们发现此情况时,联系op将Redis集群的所有Key紧急delete,当时监控示意图:
输入图片说明
当重启后,我们再去线上观察的时候,发现错误依然存在,神奇的是,这种错误发生的频率会随着时间的增加而递减。到最后刷个10分钟页面才会出现这种错,示意图如下所示:
输入图片说明
既然如此,那只能祭出重启大法,把出错的业务系统全部重启了一遍。
重启之后,线上恢复正常,一切Okay。

Bug复盘

此次Bug是由Redis本身Server负载太高超时引起的。Bug的现象是通过Jedis去取对应的Key值,得不到预期的结果,简而言之包乱了,串包了。

缩小Bug范围

首先:Redis是全球久经考验的系统,这样的串包不应该是Redis的问题。
第二:Redis刷新了key后Bug依然存在,而业务系统重启了之后Okay。
第三:笔者在错误日志中发现一个现象,A系统只可能打印出属于A系统的json串结构(redis存的是json)。
很明显,是业务系统的问题,如果是Redis本身的问题,那么在很大概率上A系统会接收到B系统的json串结构。

业务系统问题定位

业务系统用的是Jedis,这同样也是一个久经考验的库,出现此问题的可能性不大。那么问题肯定是出在运用Jedis的姿势上。
于是笔者找到了下面一段代码:

public Object invoke(Object proxy,Method method,Object[] args) throws Throwable{
    JedisClient jedisClient = jedisPool.getResource();   
    try{
      return method.invoke(jedisClient,args);  
    } catch(Exception e){
      logger.error("invoke redis error",e);   
      throw e;   
    }finally {
        if(jedisClient != null){
            // 问题处在下面这句
            jedisPool.returnResource(jedisClient);
        }
    }
}

当时我就觉得很奇怪,笔者自己写的,阅读过的连接池的代码都没有将抛异常的连接放回池里。就以Druid为例,如果是网络IO等fatal级别的异常,直接抛弃连接。这里把jedisClient连接返回去感觉就是出问题的关键。

Bug推理

笔者意识到,之所以串包可能是由于jedisClient里面可能有残余的数据,导致读取的时候读取到此数据,从而造成串包的现象。

串包原因

正常情况下的redis交互

先上Jedis源码

public String get(final String key) {
    checkIsInMulti();
    client.sendCommand(Protocol.Command.GET, key);
    return client.getBulkReply();
}

Jedis本身用的是Bio,上述源码的过程示意图如下:
输入图片说明

出错的业务系统的redis交互

输入图片说明
由于Redis本身在高负载状态,导致没能及时相应command请求,从而导致readTimeOut异常。

复用这个出错链接导致出错

在Redis响应了上一个command后,把数据传到了对应command的socket,进而被inputream给buffer起来。而这个command由于超时失败了。
输入图片说明
这样,inputStream里面就有个上个命令留下来的数据。
下一次业务操作在此拿到这个连接的时候,就会出现下面的情况。
输入图片说明
再下面的命令get user789Key会拿到get user456Key的结果,依次类推,则出现串包的现象。

串包过程图

输入图片说明
上图中相同颜色的矩形对应的数据是一致的。但是由于Redis超时,导致数据串了。

为什么get操作返回OK

上图很明显的解释了为什么一个get操作会返回OK的现象。因为其上一个操作是set操作,它返回的OK被get操作读取到,于是就有了这种现象。

为什么会随着时间的收敛而频率降低

因为在调用Redis出错后,业务系统有一层拦截器会拦截到业务层的出错,同时给这个JedisClient的错误个数+1,当错误个数>3的时候,会将其从池中踢掉。这样这种串了的连接会越来越少,导致Bug原来越难以出现。

在每次调用之前清理下inputstream可行否

不行,因为Redis可能在你清理inputstream后,你下次读取前把数据给传回来。

怎么避免这种现象?

抛出这种IO异常的连接直接给扔掉,不要放到池子里面。

怎么从协议层面避免这种现象

对每次发送的命令都加一个随机的packetId,然后结果返回回来的时候将这个packetId带回来。在客户端每次接收到数据的时候,获取包中的packetId和之前发出的packetId相比较,如下代码所示:

if(oldPacketId != packetIdFromData){
     throw new RuntimeException("串包");
}

总结

至少在笔者遇到的场景中,出现IO异常的连接都必须被抛掉废弃,因为你永远不知道在你复用的那一刻,socket或者inputstream的buffer中到底有没有上一次命令遗留的数据。
当然如果刻意的去构造协议,能够通过packetId之类的手段把收发状态重新调整为一致也是可以的,这无疑增加了很高的复杂度。所以废弃连接重建是最简单有效的方法。

原文链接

https://my.oschina.net/alchemystar/blog/888086

版权声明:本文内容由阿里云实名注册用户自发贡献,版权归原作者所有,阿里云开发者社区不拥有其著作权,亦不承担相应法律责任。具体规则请查看《阿里云开发者社区用户服务协议》和《阿里云开发者社区知识产权保护指引》。如果您发现本社区中有涉嫌抄袭的内容,填写侵权投诉表单进行举报,一经查实,本社区将立刻删除涉嫌侵权内容。

相关文章
从源码角度,分析PG事务号分配机制和防止事务号回卷
从源码角度,分析PG事务号分配机制和防止事务号回卷
97 0
【5G NR】手机身份证号IMEI与IMEISV
手机上的“IMEI”是指国际移动设备识别码(IMEI),通常称为手机序列号。它用于识别移动网络中的各个独立手机和其他移动通信设备,相当于手机身份证号,它是全球唯一的。
100 0
宏宝莱:快销企业的上云之路
四平宏宝莱饮品股份有限公司(以下简称宏宝莱)始建于1992年,经过多年不懈努力,宏宝莱行销区域遍及东北、华北、华东等全国大部分区域,多次被评为最受消费者喜爱饮料及冷饮品牌之一。
12066 0
FFMPEG实现H264的解码(从源代码角度)
农历2014年底了,将前段时间工作中研究的FFMPEG解码H264流程在此做一下整理,也算作年终技术总结了! H264解码原理: H264的原理参考另一篇博文 http://blog.csdn.net/rootusers/article/details/43563133 H264分为NAL(...
3084 0
2.2.5 使用 plugin
除了 loader 外,plugin 是另一个扩展 webpack 能力的方式。于 loader 专注于处理资源内容的转换不同,plugin 的功能范围更广,更为灵活强大。 plugin 的存在是为了实现那些 loader 实现不了或者不适合在 loader 中实现的功能。
733 0
Ffmpeg简介
<div class="bct fc05 fc11 nbw-blog ztag"> <p><a rel="nofollow" href="http://www.ffmpeg.com.cn/index.php/%E9%A6%96%E9%A1%B5">http://www.ffmpeg.com.cn/index.php/%E9%A6%96%E9%A1%B5</a></p> <p>FFmpeg i
1640 0
9i index bug.txt 之2
9i index bug.txt 之21.接着以上的测试:SQL> SELECT object_id FROM dba_objects WHERE object_name = 'I_T1_A'; OBJECT_ID----------     45851    ...
534 0
work log 7.23--- 7.27
2007.7.23--- 2007.7.27 ¶ Working 23/7 Write E.164 format convetor functions 24/7 Read UdpTrafficGen? requirement from Chen, it need to be enhanced.
626 0
+关注
无毁的湖光
无论多么艰难的时刻,都不要忘记。辉煌的未来,在你的眼中闪耀!
22
文章
0
问答
文章排行榜
最热
最新
相关电子书
更多
低代码开发师(初级)实战教程
立即下载
阿里巴巴DevOps 最佳实践手册
立即下载
冬季实战营第三期:MySQL数据库进阶实战
立即下载