最近新人在开发我的项目过程中革新了很多代码,启动过程中发现十分慢,于是我进去帮忙排查,简略记录下;
我的项目启动我开启了 debug 日志,发现次要耗时卡在 jooq 下面;
2023-06-16 19:43:31,346 [main] DEBUG o.s.b.f.s.DefaultListableBeanFactory - Autowiring by type from bean name 'dslContext' via factory method to bean named 'jooqConfiguration'
2023-06-16 19:43:31,957 [main] DEBUG o.s.b.f.s.DefaultListableBeanFactory - Eagerly caching bean 'dslContext' to allow for resolving potential circular references
2023-06-16 19:43:32,182 [main] DEBUG o.s.b.f.s.DefaultListableBeanFactory - Returning cached instance of singleton bean 'org.springframework.transaction.config.internalTransactionAdvisor'
2023-06-16 19:43:32,183 [main] DEBUG o.s.b.f.s.DefaultListableBeanFactory - Returning cached instance of singleton bean 'org.springframework.transaction.config.internalTransactionAdvisor'
2023-06-16 19:51:45,172 [main] DEBUG o.s.b.f.s.DefaultListableBeanFactory - Finished creating instance of bean 'dslContext'
2023-06-16 19:51:45,173 [main] DEBUG o.s.b.f.s.DefaultListableBeanFactory - Returning cached instance of singleton bean 'jooqConfiguration'
2023-06-16 19:51:45,173 [main] DEBUG o.s.b.f.s.DefaultListableBeanFactory - Returning cached instance of singleton bean 'spring.jooq-org.springframework.boot.autoconfigure.jooq.JooqProperties'
2023-06-16 19:51:45,173 [main] DEBUG o.s.b.f.s.DefaultListableBeanFactory - Returning cached instance of singleton bean 'org.springframework.boot.autoconfigure.jooq.JooqAutoConfiguration'
2023-06-16 19:51:45,173 [main] DEBUG o.s.b.f.s.DefaultListableBeanFactory - Returning cached instance of singleton bean 'dataSourceConnectionProvider'
2023-06-16 19:51:45,173 [main] DEBUG o.s.b.f.s.DefaultListableBeanFactory - Returning cached instance of singleton bean 'transactionProvider'
发现实现 dslcontext 用了足足 8 分钟
2023-06-16 19:43:32,183 [main] DEBUG o.s.b.f.s.DefaultListableBeanFactory - Returning cached instance of singleton bean 'org.springframework.transaction.config.internalTransactionAdvisor'
2023-06-16 19:51:45,172 [main] DEBUG o.s.b.f.s.DefaultListableBeanFactory - Finished creating instance of bean 'dslContext'
深刻排查一下 dslContext 为啥这么慢,升入源码通过条件断点看了下,发现次要耗时在
org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory#applyBeanPostProcessorsAfterInitialization
目前来看 AnnotationAwareAspectJAutoProxyCreator 的处理器,该处理器会扫描 dslContext 中的办法,并逐个判断以后的形式是否须要动静代理。dslContext 中蕴含约几百上千的办法启动天然会很慢;
我的项目中之前就存在 jooq,为啥忽然扫描了;
diff 比对革新的代码发现新增了 @Aspect 切面代码,而且扫码全工程门路,导致很慢
@Pointcut("execution( * com.alibaba.xxx..*(..))")
public void getMethods() {}
切面匹配是一个耗时的工作,最好缩小范畴,匹配的表达式越准确越好;
例子不难,思路很明确,最近在眼睛 chatgpt 插件联合 RPA 看下这类场景能不能自动化,提高效率,还在摸索 ing,后续有机会分享下;