起因: 手上的一个spring项目启动耗时超级长,启动后查看花费的时间,一共花了426849毫秒,换算近7.11415分钟。
1,观察日志初步排查问题,发现系统卡在此处不动了。。。
2,继续等待日志,发现在启动过程中加载阿里数据库连接池DruidDataSource耗时近4分钟。
3,由此怀疑是连接池配置问题,去除所有初始化的参数,保留连接信息(driverClassName,url,username,password),启动耗时39282毫秒, 0.6547 分
4,继续排查连接池配置,放出几个初始化参数,再重新启动服务,发现耗时又出现将近7分钟,由此可发现问题出现在此。
5,查看Druid的官方文档,配置推荐https://github.com/alibaba/dr...
查询官网文档:
initialSize 默认值是0 初始化时建立物理连接的个数,初始化发生在显示调用init方法,或者第一次getConnection时
初始化配置了500的个数,Spring启动过程就需要花费大量的时间去初始化创建连接,导致系统启动超级的慢。
准确定位到初始化参数问题,导致项目启动耗时如此之长久。
原先<property name="initialSize" value="500" />
修改后<property name="initialSize" value="50" />
此次优化效果如下:
系统启动性能优化(前后耗时对比):
优化前:spring项目启动耗时426849毫秒,大约7分钟。
优化后:spring项目启动耗时185613毫秒,大约3分钟,启动性能提升2倍多。
极致情况下,开发人员本地启动服务,可直接删掉initialSize参数配置,启动性能还可在原基础上提升20秒左右。
启动这个项目,一次可提速近3分钟。
将近3分钟的启动时长,对于项目来说还是太长了,继续深度优化。
6,监控日志发现加载线程池出现耗时将近(从18s到27s)10秒
2022-03-01 16:47:18 [RMI TCP Connection(5)-127.0.0.1] INFO bs2.xxxxxxxxx.orm.core.SQLExecutor - 2441 query select from xxxxxxx
2022-03-01 16:47:27 [RMI TCP Connection(5)-127.0.0.1] INFO org.springframework.xxxxx.concurrent.ThreadPoolTaskExecutor - Initializing 'txxxxkxecutor'
定位到系统使用xml配置线程池,在初始化的时候直接加载,导致耗时增加,于是修改加载为lazy-init
7,继续监控日志,在webApplication初始化时停留了一分多钟。
16:33:40.811 [NettyClientSelector_1] DEBUG i.n.u.i.JavassistTypeParameterMatcherGenerator - Generated: io.netty.util.internal.__matchers__.com.alibaba.xxxxxmq.remoting.protocol.RemotingCommandMatcher
2022-03-01 16:34:48 [RMI TCP Connection(3)-127.0.0.1] INFO org.springframework.web.context.ContextLoader - Root WebApplicationContext: initialization completed in 104988 ms
2022-03-01 16:34:52 [RMI TCP Connection(3)-127.0.0.1] INFO rsLog - com.baison.bap.resource.StringResourceLoader starting load
8,定位到是由于spring的bean加载,启动过程中加载了大量的bean类,于是在bean.xml文件中,进行懒加载配置。
优化后,耗时已经到1分多钟了,这下启动起来瞬间就爽了。
此次优化效果如下:
系统启动性能优化(前后耗时对比):
优化前:spring项目启动耗时426849毫秒,大约7分钟。
优化后:spring项目启动耗时99505毫秒,大约1分半,启动性能提升将近5倍。
启动这个项目,一次可提速近5分钟,平均下来用在这些项目启动的时间上面,每天可以节省几十分钟。