年年出妖事，一例由JSON解析导致的＂薛定谔BUG＂排查过程记录年年出妖事，一例由JSON解析导

前言做开发这么多年，也碰到无数的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运行，打上断点准备调试，测试同事操作下来，却又好了。
然后释放断点，正常运行。操作一会，又出现了相同报错。
继续打上断点，还是正常。
【年年出妖事，一例由JSON解析导致的"薛定谔BUG"排查过程记录】这个现象把同事整的有点懵，我在群里看到这个，觉得这个现象很有趣，结果竟然依赖于是否观测，这什么鬼。。

文章图片

我接过手看了下代码，我初步看下来也是完全没问题的。
代码我经过了精简和一些伪代码处理，如下所示：

public T executeLua(String luaName, Class 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 {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工具进行了查看执行结果

文章图片

然后继续反复执行，大概在按几十次回车之后，终于出现了一个报错：

文章图片

这就很诡异了有没有，同样的数据，同样的代码。执行几十次就出错了。
但是问题肯定是在fastjson这边了。接下去就是要破解这个问题的根源了。为了抓住这个原因，我还真舍不得马上升级。
排查（二）之前说到过调用的时候并没有加泛型，于是我抱着试一试的想法，给这个调用加上了泛型，参数换成了TypeReference

LuaResult result = executeLua("xxxx", new TypeReference>(){}, args);

再去断点，通过Evaluate工具去诊断，点了有上百次，都没出现那个错。
那这样就确定应该是泛型引起的了。通过搜索相关关键字，找到了一篇关于fastjson关于对于泛型解析的文章。大致意思就是：fastjson对于那些没有定义明确泛型类型的相同对象，会默认使用上一次泛型的类型。也就是说，fastjson会对相同对象的前一次的泛型定义进行缓存。
这样，我就能大致理解这个妖孽bug的偶发原因了。
为此，我特地在本地写了一段代码来模拟这个bug的产生。
大家也可以复制到本地来运行下，fastjson版本要为1.2.29。

public static void main(String... args) throws Exception { try { String json = "{\"code\":\"00\",\"msg\":\"成功\",\"data\":{\"xxx\":21,\"yyy\":5}}"; LuaResult result = JSON.parseObject(json, LuaResult.class); System.out.println(result); }catch (Exception e){ log.error("出错了", e); }try { String json1 = "{\"msg\":\"成功\",\"data\":\"31\",\"code\":\"00\"}"; LuaResult result = JSON.parseObject(json1, new TypeReference>(){}); System.out.println(result); }catch (Exception e){ log.error("出错了", e); }//上面2个没问题，到执行第三段的时候，就会必现 try { String json = "{\"code\":\"00\",\"msg\":\"成功\",\"data\":{\"xxx\":21,\"yyy\":5}}"; LuaResult result = JSON.parseObject(json, LuaResult.class); System.out.println(result); }catch (Exception e){ log.error("出错了", e); } }

执行后出现报错：

文章图片

有意思的是，只有三段代码是这个顺序的时候，才出错，把三段代码换个顺序，又正常了。
这下是一个必现的bug了。原形毕露！
由于项目使用的fastjson是1.2.29版本，我逐个版本升级，想知道到底是哪个版本会修复这个bug。在试到1.2.33版本时，这个bug终于没了。去github上找1.2.33这个版本的release信息，发现了作者修复了不使用参数泛型解析错误的issue。

文章图片

结论所以结论就是：这个薛定谔的bug就是因为fastjson在早期的版本中存在着对泛型解析的不严谨bug产生的。
既然都到这个程度了，那继续再深入研究发现，fastjson在1.2.33版本以下，对同一个对象的泛型存在着缓存现象。之前如果一直执行带泛型定义的LuaResult这是没问题的，如果前几个是带泛型的，后一个执行到不带泛型的，这就出现问题了。会按照上次缓存的泛型进行解析，由于前一次的泛型是Integer，所以不管这次json是什么数据，都会按照Integer类型去进行转换，所以就导致了can not cast to int这个错误。
至于为什么一开始，会出现类似于薛定谔的幻觉，现在也有了定论，这是因为测试同学的测试的顺序。正好debug的时候，没按照这个顺序执行，而正常运行的时候，是按照这个顺序执行的。我猜想这可能就是一个巧合。
知道了根源原因，修复起来只要升级到最新版本即可。
有人会觉得我绕了一大圈，直接升级就完事了。何必去究其原因。
一方面我觉得在技术上要严谨点，知其所以，更要知其所以然。二者我对这个如何产生的，抱有很大的兴趣（执念）。所以即便升级一个版本号就能解决，也要弄清楚来龙去脉。
如果大家喜欢类似的bug寻找过程的文章，也请在留言评论告诉我，我以后多安排一些。
我是铂赛东，一个有趣且有深度的开发，关注【元人部落】，里面会分享技术以及开源相关的内容。也会分享点生活观。