关于java:年年出妖事一例由JSON解析导致的薛定谔BUG排查过程记录

3次阅读

共计 4321 个字符,预计需要花费 11 分钟才能阅读完成。

前言

做开发这么多年,也碰到有数的 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 工具进行了查看执行后果

而后持续重复执行,大略在按几十次回车之后,终于呈现了一个报错:

这就很诡异了有没有,同样的数据,同样的代码。执行几十次就出错了。

然而问题必定是在 fastjson 这边了。接下去就是要破解这个问题的本源了。为了抓住这个起因,我还真舍不得马上降级。

排查(二)

之前说到过调用的时候并没有加泛型,于是我抱着试一试的想法,给这个调用加上了泛型,参数换成了 TypeReference

LuaResult<Map<String,Object>> result = executeLua("xxxx", new TypeReference<LuaResult<Map<String,Object>>>(){}, 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<Integer> result = JSON.parseObject(json1, new TypeReference<LuaResult<Integer>>(){});
        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 寻找过程的文章,也请在留言评论通知我,我当前多安顿一些。

我是铂赛东,一个乏味且有深度的开发,关注【元人部落】,外面会分享技术以及开源相干的内容。也会分享点生活观。

正文完
 0