问题现象:
生产环境中,客户反馈在启动服务系统后,首次交易存在5秒以上的延迟现象,后续每次交易会避免这时间。
问题分析:
- 此类问题,从经验上看,通常对于首次的耗时,最常见的就是可能考虑到有需要首次加载或初始化资源的场景时会产生这个问题,所以目前需要分析出,代码执行过程中的耗时点;
- 由于开发人员无法在生产上debug,通过增加了业务层调用代码日志的方式,来跟踪了首次交易的耗时过程,体现在一个调用第三方架构来实现beancopy功能的地方;
- 通过增加日志方法,只能大致知道一个宽泛的耗时方法,但是这个方法的调用过程详细耗时点没有办法得知,所以对于这类问题,尤其是生产环境,我们需要掌握一些分析此类问题的工具,下面来介绍一些工具,如jdk的jstack可以打印java方法栈调用情况,也可以使用阿里的arthas通过trace来跟踪方法调用;
- 首先此类问题只出现在首次调用,通过arthas跟踪没有一次性跟踪到,需要动态多次跟踪,但是后续的交易无法重现问题现象,所以考虑到首次交易会出现一个5秒以上的耗时,可以通过jstack快速的抓取快照的方式,每隔1秒多次抓取,来分析方法栈调用链情况;
- 得到的结果如下:
6.通过调用栈分析,阻塞点是在类加载后读取jar包的地方,这个问题目前就可能是多个方面的因素导致的了,可能是生产环境中存储io方面本身存在问题,也可能是jvm在解析war读取jar的过程中存在缓慢,要确认这几个方面的因素,就需要分别验证;
7.由于客户docker容器内未安装可功能跟踪系统调用的工具如(strace、perf)等,先验证是否由于war中记载jar慢导致的,通过本地模拟此类代码,在idea工程中直接启动验证(非war包形式,通过启动引导类加载工程),现场并不存在这个缓慢的过程;但是通过maven将工程打成war包后,通过java -jar XXX.war方式启动,首次交易就出现明显的耗时过程;
8.所以问题可以初步断定,这个现象可能和打成war后,启动服务的存在关系,所以将生产工程启动方式调整,并且将工程文件通过解压后的web部署方式部署,启动后首次验证,问题解决;
9.对于这个问题,在一些资料中也查到了其他开发者的反馈,如这个https://github.com/spring-projects/spring-boot/issues/16471 ,
这个国外大神也提出了同样的问题,并且在git上也提供了验证的工程代码,感兴趣可以下载验证下,同时这个反馈中也提供了几种通过代码层的规避方案可以尝试;
10.所以这个问题的分析,总结下,我们需要掌握的思路之外,还需要对一些工具的使用非常熟悉,并且可以掌握通过现象来搜索问题解决方案的本领;