大促系统优化之应用启动速度优化实践
作者:京东零售 宋维飞
一、前言
本文记录了在大促前针对SpringBoot应用启动速度过慢而采取的优化方案,主要介绍了如何定位启动速度慢的阻塞点,以及如何解决这些问题。希望可以帮助大家了解如何定位该类问题以及提供一些解决此类问题的思路。(本文使用的SpringBoot版本为2.6.2,JSF版本为1.7.6-HOTFIX-T2)
二、问题背景

三、解决方案
要想排查应用启动速度过慢的问题,需要先定位到是哪里慢,乍看这句话,就和没说一样,其实就是陈述一下事实😀,下面介绍几种常见的排查方法:
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就可以关闭扫描 但是我们的Tomcat都是打到镜像里面的,并没有给我们暴露修改配置参数的入口,通过查看行云的帮助文档,发现可以在启动脚本start_before.sh文件里面使用sed命令进行修改
sed -i '$a\tomcat.util.scan.StandardJarScanFilter.jarsToSkip=*.jar' /export/Domains/jdos应用名.jd.com/server1/conf/catalina.properties
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的耗时,具体代码如下
@Component
@Slf4j
public class TimeCostPriorityOrderedBeanPostProcessor implements BeanPostProcessor, PriorityOrdered {
private Map<String, Long> costMap = Maps.newConcurrentMap();
@Override
public Object postProcessBeforeInitialization(Object bean, String beanName) throws BeansException {
costMap.put(beanName, System.currentTimeMillis());
return bean;
}
@Override
public Object postProcessAfterInitialization(Object bean, String beanName) throws BeansException {
if (costMap.containsKey(beanName)) {
Long start = costMap.get(beanName);