导读
本文记录作者升级到 JDK 11 后遇到的 FastJSON 序列化问题,以及详细的排查过程。
0. 写在前面的省流版
升级到JDK 11后,类加载顺序有所改动,同名的类在多个jar中,导致实际加载的类不一样,因此序列化的结果不一样。
1. 现象
消防群客户反馈。@客户服务(CCO) 出现批量买家反馈,现在订单页面无法发起纠纷,申请后就报错。辛苦帮忙看下。
2. 解决过程
今天有发布,第一时间回滚,分两批每批30台回滚。6分钟完成回滚,故障恢复,及时止血,没有进一步恶化。3. 问题排查
机器不在线
问题现象:确实发布过程中有报警,报7001端口不在,但这个问题不是引起线上问题的核心原因。发布过程中我登录到已经发布的报警机器上看,发现该台机器的hsf服务都在正常提供服务,hsf在线率也都在线,MQ消息消费正常,所以暂时忽略了该问题。后面反思了下,确实对于服务型应用,7001端口不在也还好,因为一定会启动一个800X的端口,不影响正常服务调用。但是依然存在一个问题,就是当HSF服务优雅上下线的时候,启动脚本需要调用固定端口号进行online和offline,因此这时候就会有问题。所以在今天,重新发布的时候,还是要排查下这个问题。排查过程:首先在预发看 jvm的参数。然后看了下这个进程占用的端口。盲狙到是不是 sandbox-agent的问题。联系到负责人先把这个插件删掉,但沟通下来,这个插件只会部署在预发,好像并不会影响到线下和线上环境。继续联想到这次改造,同时也对Springboot版本进行了升级,升级到 2.5.6版本。其中对于端口这块改动会不会比较大,或者有更优先级的配置影响。在对着配置研究了会,好像这个配置也是兼容的,diamond或者其他service.cue上都没有啥配置改动,因此也应该不是配置项改动导致的。突然灵光乍现了下,好像我在应用启动的时候加了这个东西:new SpringApplicationBuilder(DestinyApplication.class) .web(WebApplicationType.NONE) // 指定应用不是 Web 应用 .profiles(DiamondProfiles.load()) .run(args);就这一行代码,看看是不是给 .web(WebApplicationType.NONE) 端口干坏了。果然是这个鬼东西加的,当时加这个好像是什么原因来着,我把这行删除了,果然应用就起不起来了。看了下启动的过程,基本上的启动好后一直没有成功,然后触发aone的重新部署,就这样循环。很明显这个现象是health.sh没做好。在controller里面加上。@Controller public static OkController { @ResponseBody @RequestMapping("/ok.jsp") public String ok() { return "success"; } /** * 健康检查,系统部署需要 * 请不要删除!! */ @GetMapping("/checkpreload.htm") public @ResponseBody String checkPreload() { return "success"; } }配置一行配置。icbusession.authorization.exclude-paths=/favicon.ico,/checkpreload.htm,/status.taobao,/ok.jsp端口问题解决。FastJson解析问题
问题复现因为回滚的太快,测试同学在进行复现的时候,大部分都掉进上面这个优雅上下线的问题去了。抽丝剥茧后,最终还原了事件的真相。PC端没有问题,仅仅在APP端才会出现这个问题。因为在售后域,PC和APP的差别基本上就一层Mtop的hsf接口的问题,底层调用的HSF服务基本都是统一的,所以我们开发同学在自测的过程基本上都是回归下PC看看没问题了,大概率就认为没问题。--这是犯了经验主义错误,后续还是要认认真真下一个beta包,安卓和IOS都走一遍在发布。BETA没有发现的问题,是因为这个问题实际没有产生任何Java的异常,报错的是一个业务异常的校验。{"memo":"min refund limit","resultCode":{"code":-27,"message":"min refund limit","success":false},"success":false}我们原本认定这种是业务校验异常,无需关心。-- 后续对业务异常也进行监控,如果有大批量上涨,也需要引起重视。好了,不卖关子了,开始分析这个问题并复现。问题推导,首先多端问题先怀疑前端发布,不过最近没发布,后端回滚后止血,那就应该不是前端的问题。售后的提交的数据的报错。测试在预发复现后,看到对应日志。仔细分析这段前端传入的JSON:{"oldPostIssueRequestDTO":{"authorizedViewCommunication":false,"businessType":"XXX","buyerInfo":{"email":"cxw20180809@126.com"},"destinyTraceId":"XXX-84ba-68ad2b62690c","device":"IOS","issueReasonId":1022,"memo":"qqq","operation":"abortOrder","operatorAccountId":XXX,"operatorAliMemberId":CCC,"operatorType":"buyer","orderId":"XXX","payerList":[{"availableTaxAmount":{"amount":0.00,"cent":0,"centFactor":100,"currency":"USD","currencyCode":"USD"},"cardTailNo":"5164","currency":"USD","finNumber":["XXX"],"forexRefundAmount":{"amount":0.30,"cent":30,"centFactor":100,"currency":"USD","currencyCode":"USD"},"fundAmount"{"amount":0.00,"cent":0,"centFactor":100,"currency":"USD","currencyCode":"USD"},"online":true,"originPayMethod":"CREDIT_CARD_PAY","payContractId":"CCC","payGmtCreate":1724210447000,"payGmtCreateStr":"2024-08-20 20:20","payMethod":"CREDIT_CARD_PAY","payProcessFeeAmount":{"amount":0.01,"cent":1,"centFactor":100,"currency":"USD","currencyCode":"USD"},"payStep":"ADVANCE","payerName":"null null","rate":1,"refundAmount":{"amount":0.30,"cent":30,"centFactor":100,"currency":"USD","currencyCode":"USD"},"taxAmount":{"amount":0.00,"cent":0,"centFactor":100,"currency":"USD","currencyCode":"USD"},"termFundArrived":false}],"refundAmount":{"amount":0.00,"cent":0,"centFactor":100,"currency":"USD","currencyCode":"USD"}}}各位只需要关注最后一行。这很明显是前端没把退款金额传过来导致的啊。正当我要找前端理论的时候。我又看到一行日志。我们开发的一个好习惯,就是在MTOP请求过来的时候,先打印一行日志,我们MTOP接口入参是一个String,这里面明明是带着 amount的啊。这里面的amount的值是在哪里被抹平的呢?带着这个疑惑,我把每次调用的链路的地方都打了一行日志。从MtopTradeIssueViewService的时候还是带amount值的,在IssueApplicationService的时候就没有了。看着这长长的调用链路,我又陷入了沉思,这么多层调用着实有点离谱,后续流程我没有继续画了。已知MtopTradeIssueViewService的string是对的,然后IssueApplicationService的不对。我于是在每一个service上面都打了一下入参,看看到底是哪里的问题。当我开始思考是不是区域化路由给我的amount的值给抹平了的时候,结论又给我整不明白了。看日志在第一个调用的时候,值就没有了。TradeIssueViewRegionFacade。然后我继续在第一个类里面增加日志,看看具体是哪里的问题。结果再一次给我震惊了。fun parsePostIssueRequestDTO(request: String): PostIssueRequestDTO? { var postIssueRequestDTO: PostIssueRequestDTO? = null try { postIssueRequestDTO = JSON.parseObject(request, PostIssueRequestDTO::class.java) } catch (e: Throwable) { logger.error("MtopIssueViewService.parsePostIssueRequestDTO parse request error.$request", e) } if (postIssueRequestDTO == null) { logger.error("MtopIssueViewService.parsePostIssueRequestDTO provideEvidenceForm is null.$request") } return postIssueRequestDTO}对,你没看错,就是这行。JSON.parseObject(request, PostIssueRequestDTO::class.java)本地复现第一反应是我的FastJson是不是被谁给仲裁了。<dependency> <groupId>com.alibaba</groupId> <artifactId>fastjson</artifactId> <version>1.2.68.noneautotype</version></dependency>看了下线上也是这个版本啊,相关引入fastjson的包也没有变化?这怎么查???debug出问题的类,发现确实用的也是这个版本的。本地复现,本地根本复现不了啊!!!我本地parseObject的是有 amount 啊。改动范围review本次改动其实是比较大的,从Springboot应用迁移到 pandoraboot应用。同时迭代java8升级java11。同时我还升级了下 Springboot的版本,升级到了 2.5.6 。这回归范围一下子大的有点无边无际了。依赖二方库的改动反序列化的这个类:PostIssueRequestDTO ,是我们代码一方库的类。线上用的是更低一个版本的。我一开始怀疑是这个二方库的问题,我发布的时候顺手勾了下java11,是不是这个锅。等我重新用java8发布了一个snapshot的二方库,好像也没有影响。这时候我们前端提醒我,为什么PC不报错呢。对啊,因为PC在我们后端的前端应用moirai中,这里的parse好像没问题,那我在这个应用里面,升级到我怀疑的二方库版本,发现还是正常。那只能排除掉是这个二方库升级导致的反序列化异常。JDK11的改动这个怀疑是有点没道理的,因为我们应用大部分已经升级到JDK11了,也没听说遇到这种问题的。但谨慎起见,我保障了和前端应用Moirai(即PC可以正常反序列化的应用)一样的Java的版本。多次尝试后,发现和JDK的版本没啥关系。而且好像也不能在降级回Java8。仔细review前端传的字符串传了两个refundAmount,一个是仅仅只带amount的,另一个是带了 amount 又带了 cent的。从结果来看,传了cent的反序列化成功了,没传cent的就被抹成0了。Money类分析这个类不对劲。我们来看下这个类。com.alibaba.intl.commons.framework.type.Money坐标在这里:作者是ChengLi,也就是我们的CTO。这个类在我们国际站用的还是比较多的。这个类的属性不多:public Money implements Serializable, Comparable { /** * Comment for <code>serialVersionUID</code> */ private static final long serialVersionUID = 6009335074727417445L; /** * 缺省的币种代码,为CNY(人民币)。 */ public static final String DEFAULT_CURRENCY_CODE = "CNY"; /** * 缺省的取整模式,为<code>BigDecimal.ROUND_HALF_EVEN * (四舍五入,当小数为0.5时,则取最近的偶数)。 */ public static final int DEFAULT_ROUNDING_MODE = BigDecimal.ROUND_HALF_EVEN; /** * 一组可能的元/分换算比例。 * <p> * 此处,“分”是指货币的最小单位,“元”是货币的最常用单位, 不同的币种有不同的元/分换算比例,如人民币是100,而日元为1。 */ private static final int[] centFactors = new int[] { 1, 10, 100, 1000 }; /** * 金额,以分为单位。 */ private long cent; /** * 币种。 */ private Currency currency; /** * 币种代码 */ private String currencyCode;}然后我们丢失的amount呢,其实这个并不是一个字段,仅有get和set方法。// Bean方法 ==================================================== /** * 获取本货币对象代表的金额数。 * * @return 金额数,以元为单位。 */ public BigDecimal getAmount() { return BigDecimal.valueOf(cent, currency.getDefaultFractionDigits()); } /** * 设置本货币对象代表的金额数。 * * @param amount 金额数,以元为单位。 */ public void setAmount(BigDecimal amount) { if (amount != null) { cent = rounding(amount.movePointRight(2), BigDecimal.ROUND_HALF_EVEN); } }看到这里,我又陷入了深深的疑惑,这之前又是怎么反序列化成功的?不应该都传cent么???FastJson分析当排除了所有不可能,拿结果只有一个,那就是看起来是FastJson的问题。好在作者在阿里,直接钉钉上咨询了下 高铁。高铁老师的建议是先升级FastJson到最新版本。我升级到2.0.52版本。然后老师建议我用FastJson2,然后把所以用JSON的地方改一下包名类名,FastJson和FastJson2是可以同时存在的。这里安利一波FastJson2,效果杠杠的。<dependency> <groupId>com.alibaba.fastjson2</groupId> <artifactId>fastjson2</artifactId> <version>2.0.52</version></dependency>import com.alibaba.fastjson2.*升级了之后,问题依旧啊......就是toString稍微精简了些。FastJson代码探究那没办法了,只能要么让前端加一下cent,要么debug下FastJson。来吧,逃也逃不过去,具体的源码精度我后面放在ParseObject的文章里面。这里记录下关键的几个结论和发现问题的点。首先,我本地是可以反序列化money的类的,aone的机器反序列化money的类,amount值会被抹平。然后慢慢对比这两处,哪里是不一致的,然后一点点排查。aone的机器就是我们部署在服务器的机器,即和正式环境的基本一致。首先怀疑是ASM的问题我本地代码aone机器一个是ASM的一个是JavaBean的。和高铁老师沟通后,建议关掉我本地的ASM在试下,然后看看能不能在Fastjson2上面复现。搞到现在高铁老师都开始怀疑是不是这个类Java11没兼容好。-_-||fastjson2可以通过参数把asm关了,比如加上JVM启动参数 -Dfastjson2.creator=reflect。然后怀疑ClassLoader的问题aone之所以没有执行ASM,是因为有一行代码执行后关闭了。我本地都是同一个ClassLoader,就执行了ASM。aone机器上因为是pandoraboot的ClassLoader,所以认为是外部类了,就没执行ASM。BeanInfo问题本来以为是这个问题,本地也换成javaBean之后,发现好像没啥变化,本地还是可以反序列化amount,aone机器还是不能反序列化amount。然后在继续跟JavaBeanInfo的时候发现了端倪,我本机是有三个字段的,但是aone机器上只有两个。给个口子,有兴趣的同学可以看一眼。com.alibaba.fastjson.util.JavaBeanInfo#build(java.lang.Class<?>, java.lang.reflect.Type, com.alibaba.fastjson.PropertyNamingStrategy, boolean, boolean, boolean)代码不带大家细读了,放几张关键的图。Fastjson在反序列化的时候,除了属性值,也回去读method里面的get/set方法,来映射这个值,这也解释了我之前的疑惑,为什么没有属性值也能反序列化回来。终见端倪我本机aone机器不多不少,这个method就少了,setAmount这个function。这个类不对劲,这个类的method少了一个。通过ClassLoader查看加载类。getProtectionDomain().getCodeSource().getLocation()发现来自于这里:打开这个二方库:这个jar只重写了这个class 我都不知道为什么要这么做。然后这个类,没有setAmount。真相大白打印下依赖树。真的有这个类,然后线上机器是没有的。把这个jar排除掉,问题解决。4. 总结
这个问题确实是有些匪夷所思,并且排查的时候有点容易没有头绪。我罕见的debug了8个小时,废寝忘食。收获还是满满的,中间排查ClassLoader的问题的时候,想到了之前的ForkJoinPool的问题,差点被回旋的飞镖扎到。最后还是要给高铁老师点个赞,真大神。作者:河影
来源-微信公众号:阿里云开发者
出处:https://mp.weixin.qq.com/s/t3nq03MxL0HWzQFx62P9Cg