作者:京东零售 宋维飞
本文记录了在大促前针对SpringBoot应用启动速度过慢而采取的优化方案,主要介绍了如何定位启动速度慢的阻塞点,以及如何解决这些问题。希望可以帮助大家了解如何定位该类问题以及提供一些解决此类问题的思路。下文介绍的JSF为京东内部RPC框架,类似于阿里的Dubbo(本文使用的SpringBoot版本为2.6.2)
1.广告投放平台核心应用生产环境单台机器部署需要400-500s,加上镜像下载时间大约1分钟,整体耗时接近10分钟,应用部署时间过长会带来诸多问题,例如上线遇到问题需要进行快速回滚,启动时间过长会延长恢复时间,影响业务的连续性。
2.会导致整个应用的发布时间变长,目前我们这个应用有上百个容器,单次部署编排时间超过半个小时,上线等待时间过长;另一个问题是在测试预发环境联调修改一次编译+部署就要十几分钟,严重影响联调进度,浪费了很多时间。
3.综上所述,可以看出对应用的启动速度优化刻不容缓,浪费时间就是在浪费生命,所以我们必须要做些什么,下面通过一张图先来看下旧的生产集群发布的概况。
要想排查应用启动速度过慢的问题,需要先定位到是哪里慢,乍看这句话,就和没说一样,其实就是陈述一下事实😀,下面介绍几种常见的排查方法:
1、使用SpringBoot的监控actuator
SpringBoot的actuator是一个监控和管理SpringBoot应用的框架,它提供了许多内置的端点,允许你访问应用程序的运行时信息,如健康检查、环境属性、日志、指标、线程转储等,所以我们可以使用其中的一个端点startup去查看整个应用中所有bean的启动耗时。
但是这种模式下也有个弊端,就是每个bean的加载耗时其实是不准确的,比如A开头的bean,他的总计耗时会非常的长,原因是因为在这个bean里面去加载其他bean的耗时也会累加到这个bean上,导致数据不准确,所以该方案只能当做参考。(具体该组件的使用方式可以参考该链接 点试试 )
2、根据应用的启动日志分析
这个方法对于项目启动日志比较少的情况有一定的效果,可以在应用启动时通过开启debug日志来逐秒分析,查看启动日志打印的空白秒,就可以大概定位到阻塞点,定位到耗时的地方后再具体问题具体分析,但是对于大型项目,启动一次有几万行的启动日志,人工直接分析费时费力,而且还不好定位问题,所以此方法不具有普适性。虽然不好用,但是我们也是可以用一下的,通过这个方面我们定位到了两处阻塞点。
2.1 Tomcat启动扫描TLD文件优化
因为我们使用的是外置Tomcat容器,通过查看启动日志发现Tomcat启动日志打印的时间和Tomcat引导Spring容器启动中间隔了几十秒没有额外的日志,只有一行 org.apache.jasper.servlet.TldScanner.scanJars: At least one JAR was scanned for TLDs yet none were found. Enable debug logging for this logger to find out which JAR was scanned for TLDs,因为没有别的日志,只能从这行日志开刀,看这行日志大体的意思是Tomcat在启动时尝试扫描某些JAR文件以查找TLD文件,但没有找到。
那么Tomcat在启动的时候为什么要扫描TLD文件(什么是TLD文件?点击这里了解 ),Tomcat 作为 Servlet 规范的实现者,它在应用启动的时候会扫描 Jar 包里面的 .tld 文件,加载里面定义的标签库,但是,我们项目没有使用 JSP 作为 Web 页面的模板,为了加快应用的启动速度,我们可以把 Tomcat 里面的这个功能给关掉那么如何关闭这个扫描以提高启动速度?,通过查阅文档发现可以修改Tomcat的catalina.properties文件,修改一个配置项tomcat.util.scan.StandardJarScanFilter.jarsToSkip设置值为 *.jar就可以关闭扫描。
2.2 应用启动Hbase异步预热
通过debug日志发现另一个地方有大约6s的空白,通过查看前后关联日志发现是在初始化Hbase配置的时候出现的,我们项目中使用的Hbase在应用启动后第一次访问会非常慢,原因是在第一次请求时需要缓存元数据到本地,导致接口超时,所以后来就改成了启动时,实现SmartInitializingSingleton的afterSingletonsInstantiated接口去预热,但是最早实现的时候使用了localhost线程,所以会阻塞主流程,优化方案很简单,就是改成起一个异步线程去预热。
3、使用自定义BeanPostProcessor方案
3.1 @JsfConsumer消费者异步导出
通过上面两项优化,我们的应用启动速度有了稍许改善,但是上面的都还是小试牛刀,下面要讲的才是真正解决启动速度过慢的方案。
我们知道Spring容器启动大体可分为Bean定义的扫描和注册、bean的实例化、属性注入、bean的后置处理等,其实真正耗时的部分基本都在bean的后置处理部分,当然有时候对于Bean定义扫描范围过大也可能会带来一定的耗时,但是这块不是本文章的重点部分 ,我们暂时先忽略,那如何去定位是哪些bean的后置处理过慢,我们可以通过增加两个BeanPostProcess来实现。
通过自定义BeanPostProcess,我们可以在每个bean的初始化前后加埋点,这样就可以统计出单个bean初始化的耗时情况,具体的方案是使用两个BeanPostProcess,分别是TimeCostPriorityOrderedBeanPostProcessor、ZLowOrderTimeCostBeanPostProcessor,下面分别来介绍这两个后置处理器的作用。
我们知道BeanPostProcessor其实有两个回调方法,我们可以简单的称它们为before和after方法,TimeCostPriorityOrderedBeanPostProcessor是一个高优先级的后置处理器,所以会优先执行,我们可以用它来监控容器中所有bean执行BeanPostProcessor的before方法的执行耗时,具体实现也很简单,就是在这个后置处理器的before方法里面先记录下每个bean的执行的初始时间,然后在after方法里面计算结束时间,中间的差值就是每个bean执行所有BeanPostProcessor的耗时,具体代码如下
另外一个后置处理器是ZLowOrderTimeCostBeanPostProcessor ,他基本会最后执行,原因是他没有实现优先级接口,同时类名还是Z开头的,我们可以用它来监控容器中所有bean执行BeanPostProcessor的after方法的执行耗时,具体实现方式和上文类似,下面直接贴出源码
通过在项目中增加上面的两个BeanPostProcessor,我们重新启动应用后,发现有很多bean的初始化时间都超过了50ms,再进一步观察后会发现,这些加载慢的bean基本都有一个共同的特征,那就是这些bean的属性上面或多或少都带有@JsfConsumer注解,那么为什么属性上带有@JsfConsumer注解会导致这个bean初始化变慢,显而易见,肯定是这个注解对应的驱动类做了什么特殊操作导致了变慢,下面我们来分析一下。
1.我们项目中引用了大约170+的JSF consumer接口,@JsfConsumer注解是我们内部自己定义的一个针对Cosnumer接口使用的注解,他的使用方式很简单,只需要在引用的接口上打上这个注解,内部的starter会自动的帮你去做consumer的refer,在RPC调用中,我们作为消费者去调用生产者,其实我们只是依赖了一个接口,需要在启动的时候调用refer方法帮我们去生成代理对象我们才能发起调用,通过翻阅starter的源码发现是通过一个BeanPostProcessor的postProcessBeforeInitialization方法去做的,源码如下
2、通过分析上面的代码,可以发现唯一耗时的地方只可能在refer方法的调用,所以修改stater源码,在refer方法执行的前后打印日志,重新部署后查看日志,发现果然就是这个方法执行很慢,有的接口甚至达到了十几秒,因为spring容器的初始化是单线程执行,这些时间累加起来就是一个很大的量级,随即阅读JSF源码,探究一下为什么会慢。
3、通过从refer方法进入,一步步探究,最终找到了和服务端建立连接的代码,,这个方法的大体流程就是找到这个接口所有的提供者,和这些提供者所在的机器建立长连接用于后续的通信,建立的时候使用了多线程,但是如果一个接口对应的提供者太多,或者某些提供者机器不健康了,就可能会导致整个建立连接的时间过长。
4、分析出原因以后,解决方案也就很简单了,既然JSF在建立连接的时候使用了线程池,那我们就可以在上面再套一层线程池,这样refer方法的执行就不会阻塞后续其他流程的执行,只需要保证在应用启动成功之前我们的异步线程都执行完成即可,具体改动如下
3.2 魔改JSF自带的ConsumerBean
1、我们项目中除了上述通过@JsfConsumer注解生成客户端代理外,还有另外一种方式来生成客户端代理,那就是借助JSF自身提供的ConsumerBean类,该类实现了FactoryBean接口,可以将每个Jsf Consumer的配置都生成一个BeanDefinition实例,同时设置BeanDefinition的beanClass属性来使用它,使用这种方法可以确保生成的bean一定是单例的,防止上面那种方式可能存在不同类的同一个JSF Consumer配置不一致的情况。
2、熟悉Spring源码的小伙伴都知道,容器刷新的时候会使用BeanDefinition里面的beanClass属性来实例化对象,这里我们指定这个属性为ConsumerBean.class,等到容器刷新初始化对象完成后,会继续判断该对象是否实现了FactoryBean接口,我们用的这个肯定实现了,然后会触发该对象getObject方法调用,那么我们就看下JSF自带的这个FactoryBean的getObject方法都做了些什么,源码如下
3、还是熟悉的配方,和我们上面分析的调用refer方法一模一样,因为consumer初始化的核心就是通过refer方法生成代理对象,然后客户端持有代理对象,使用的时候通过代理对象去发起远程调用,但是这里有个关键问题就是之前的refer方法是我们自己控制的,我们可以任意去修改调用他的位置,但是现在的是JSF自己提供的,我们没法修改JSF的源码,而且他的触发是容器回调的,那我们该怎么办?
4、其实这个时候我们可以想一下,refer方法慢,我们想加速,可以和上面一样使用异步模式,但是异步的代码写在哪里,其次是这个方法是容器回调触发,如果我们开启了异步,那容器就得不到真实的引用,会导致错误,那应该怎么解决?
5、这个时候代理的作用就显示出来了,我们其实可以先给容器返回一个我们自己生成的代理对象,然后我们这个代理对象再包装原来refer产生的对象,这样客户端实际持有的是我们自己生成的代理对象,而不是JSF refer方法产生的代理对象,剩下的最后一步就是仿照原来的ConsumerBean魔改一个我们自己的版本,将getObject方法的逻辑改为使用线程池导出,同时先返回一个自己的代理对象,其实这种提前返回代理的思想也适用于其他一些场景。
6、我们可以通过一个流程图来梳理一下上面说的流程。
7、魔改后的源码如下,供大家参考
4、玄学-Tomcat版本问题?
1、我们的这个应用在不同的环境存在两套tomcat版本,分别为8.0.53和8.5.42,通过分析不同版本的tomcat启动的debug日志可以发现,在8.5.42版本下,Spring在实例化对象的时候比在8.0.53版本下慢,每个bean都慢一点点,我们项目中一共2900+bean,所以就导致不同的tomcat版本也影响启动速度,这块怀疑是高版本的Tomcat对于类加载的方式可能有变化导致,换到低版本以后速度就会变快。
5、金钱的力量
1、不同的机房对于应用的启动速度也会有一些影响,如果使用的机器是一些老旧过保的机器,也会对应用的启动速度有影响,使用旧机器也无法保障应用的稳定性,可以将应用迁移到高性能的新机房去,这样可以加快应用启动的速度。
2、在京东内部对比发现,两个不同的机房对于同一个应用启动速度差距非常大,在新机房里面比旧机房快至少20%。
下面我们来总结一下我们都做了什么
1、Tomcat启动关闭TLD文件扫描。
2、应用启动Hbase预热异步化,其实这块我们可以应用到其他场景,大家可以检查下自己的项目启动的时候有没有同步预热的场景。
3、Jsf Consumer客户端代理bean异步生成,此处主要核心在于使用一个自定义代理对象提前返回引用,这种思想我们也可以应用到其他需要异步初始化对象的地方去,具体可以参考3.2节的流程图。
4、不同Tomcat版本对于应用启动速度的影响。
5、更换到高性能机房对于启动速度的提升。
通过上述的几项优化过后,应用的启动速度得到了大幅改善,下图展示是一个简略的新旧对比,可以看到应用的启动速度从之前400-500秒到现在的130-150s,提升了近60%多。
(优化后)