来源丨经授权转自 元人部落(ID:jishuyuanren)
作者丨铂赛东
给大家分享一个BUG排查经历,看完之后,一个字:真的是绝了!
做开发这么多年,也碰到无数的bug了。不过再复杂的bug,只要仔细去研读代码,加上debug,总能找到原因。
但是最近公司内碰到的这一个bug,这个bug初看很简单,但是非常妖孽,在一段时间内我甚至是百思不得其解。在长达几天的时间内,复现的概率非常低。几乎难以抓住任何踪迹。
所以这篇文章就非常写实的来记录一下此Bug的发现和排查整个过程。
起因
同事之前做了个需求,提交测试。测试同事在测的一半的时候。发现了后台的一个报错
com.alibaba.fastjson.JSONException: can not cast to String, value : {"code":"00","msg":"成功","data":{这里是正确的数据}}
at com.alibaba.fastjson.util.TypeUtils.castToInt(TypeUtils.java:564) ~[fastjson-1.2.29.jar:na]
at com.alibaba.fastjson.serializer.IntegerCodec.deserialze(IntegerCodec.java:89) ~[fastjson-1.2.29.jar:na]
一看就知道这错很简单,就是一个fastjson的转换类型的报错。接受的json和要转化的类型不匹配造成的。基本上检查下代码,一眼就能解决的。
结果同事看了好一会儿,都没发现哪有问题。
然后远程在测试环境debug运行,打上断点准备调试,测试同事操作下来,却又好了。
然后释放断点,正常运行。操作一会,又出现了相同报错。
继续打上断点,还是正常。
这个现象把同事整的有点懵,我在群里看到这个,觉得这个现象很有趣,结果竟然依赖于是否观测,这什么鬼。。
我接过手看了下代码,我初步看下来也是完全没问题的。
代码我经过了精简和一些伪代码处理,如下所示:
public <T> T executeLua(String luaName, Class<T> c, Object... args){
String json = 执行器.执行(luaName,args);
log.info("执行结果为:{}",json);
T resut = JSON.parseObject(json, c);
return result;
}
调用的时候如此调用:
LuaResult result = executeLua("xxxx", LuaResult.class, args);
而返回对象的泛型T则是一个LuaResult对象,其结构也很简单:
public class LuaResult<T> {
protected String code;
protected String msg;
protected T data;
}
根据打印出来的json结果来看,返回的数据是正确的结果,并且是完全匹配LuaResult对象这个结构的。
虽然在调用的时候没加泛型,但是由于前面代码并用不到LuaResult里的data,所以解析出来依旧保留了JsonObject的类型。从运行的角度上来说,是完全没问题的。我也用本地的main方法用相同的数据跑了下,是完全能正常解析的。
甚至于我在本地试了循环解析多次,多线程去解析,都是没问题的。
那为什么一到服务器环境就偶发性的报错呢?
我也决定远程debug下,我不相信会有薛定谔的bug这么一说。
我远程打上断点,测试同事开始做业务,一切完全正常。
于是我去掉断点,在没过多久后,测试同事给我发来了报错的截图。一切还真的和之前的同事如出一辙。。。
这下我也凌乱了,这么简单的报错,看不出问题也就罢了,还没法调试??而打出的日志返回的json字符串,又都完全是正常的业务返回数据。
太妖孽。
排查(一)
首先可以肯定的是返回数据是完全正确的,这点在日志打印的时候就可以看到。不存在低级失误,json不匹配返回类型这一说。
那问题很明显了,就是fastjson的解析问题,而项目使用的fastjson的版本相对较老,为1.2.29版本。
但是问题究竟在哪,本来很简单的错,但是在数据和结构都完全正确的情况下偶发性的报出,就显得很诡异了。
而且我根本就不相信在debug的时候恢复正常,在正常运行时就会有问题这种事实。
而且在接下来这个bug就像消失了一样,无论是debug启动还是正常启动,都不再出现了。
看到这,肯定会有人说,这还不简单。换个json解析框架,或是升级fastjson不就行了。
对于换框架来说,私下有和同事聊过换成jackson。首先系统内多处要改,其次即便换了,问题不再复现了。但对于问题而言,等于是绕过去了,而没有真正意义上正面去解决。而我本身对这个bug的根源非常感兴趣。所以不打算换,正面刚。
对于升级fastjson,其实有猜测过是因为fastjson的某些bug导致。但是得拿出证据,否则升级之后就算不复发,也不能证明是因为升级了fastjson而修复的,因为这个bug是极其偶发的。也就是说,还是得找到确定的根源问题。不能只依靠长时间的观测而去证明是否修复。
终于在一个偶然的机会,我在debug中终于断点捕捉到了一次。
这也就说明了,不存在薛定谔bug这么一说,至少我在观测时能捕捉到。
断点的地方在以下这个位置(部分业务数据做了一些改动)
//json为:{"code":"00","msg":"成功","data":{"xxx":21,"yyy":5}}
//c为LuaResult.class
T resut = JSON.parseObject(json, c);
用IDEA的Evaluate工具进行了查看执行结果