Spring 容器启动耗时统计

为了了解 Spring 为什么会启动那么久，于是看了看怎么统计一下加载 Bean 的耗时。

极简版

几行代码搞定。

import org.springframework.beans.BeansException;
import org.springframework.beans.factory.config.BeanPostProcessor;import java.util.HashMap;
import java.util.Map;public class SpringBeanAnalyse implements BeanPostProcessor {private static final Map<String, Long> mapBeanTime = new HashMap<>();@Overridepublic Object postProcessBeforeInitialization(Object bean, String beanName) throws BeansException {mapBeanTime.put(beanName, System.currentTimeMillis());return bean;}@Overridepublic Object postProcessAfterInitialization(Object bean, String beanName) throws BeansException {Long begin = mapBeanTime.get(beanName);if (begin != null) {long ell = System.currentTimeMillis() - begin;System.out.println(beanName + " 耗时: " + ell);}return bean;}
}

使用方法：

@Bean
SpringBeanAnalyse SpringBeanAnalyse() {return new SpringBeanAnalyse();
}

效果如图：

问题是没有排序，看比较费劲。

高配版

于是，高配版出场了。它更为成熟壮健，并有排序功能。

原理

Bean 启动时间抓取，主要是围绕 Spring Bean 生命周期。BeanPostProcessor 相关方法

1. postProcessBeforeInstantiation: 实例化前
2. postProcessAfterInstantiation: 实例化后
3. postProcessBeforeInitialization: 初始化前
4. postProcessAfterInitialization: 初始化后

注意：实现MergedBeanDefinitionPostProcessor, 主要是为了调整当前 BeanPostProcessor的执行顺序到最后, 具体参考BeanPostProcessor注册流程

org.springframework.context.support.AbstractApplicationContext#refresh
org.springframework.context.support.AbstractApplicationContext#registerBeanPostProcessors
org.springframework.context.support.PostProcessorRegistrationDelegate#registerBeanPostProcessors

，详见

源码

首先是一个 Bean。

import lombok.AllArgsConstructor;
import lombok.Builder;
import lombok.Data;
import lombok.NoArgsConstructor;@Builder
@Data
@AllArgsConstructor
@NoArgsConstructor
class Statistics {private String beanName;private long beforeInstantiationTime;private long afterInstantiationTime;private long beforeInitializationTime;private long afterInitializationTime;public long calculateTotalCostTime() {return calculateInstantiationCostTime() + calculateInitializationCostTime();}public long calculateInstantiationCostTime() {return afterInstantiationTime - beforeInstantiationTime;}public long calculateInitializationCostTime() {return afterInitializationTime - beforeInitializationTime;}public String toConsoleString() {return "\t" + getBeanName() + "\t" + calculateTotalCostTime() + "\t\n";}
}

StartupTimeMetric源码：

import com.ajaxjs.util.logger.LogHelper;
import org.springframework.beans.BeansException;
import org.springframework.beans.factory.config.InstantiationAwareBeanPostProcessor;
import org.springframework.beans.factory.support.MergedBeanDefinitionPostProcessor;
import org.springframework.beans.factory.support.RootBeanDefinition;
import org.springframework.context.ApplicationListener;
import org.springframework.context.event.ContextRefreshedEvent;
import org.springframework.core.PriorityOrdered;import java.util.*;
import java.util.concurrent.atomic.AtomicBoolean;
import java.util.stream.Collectors;/*** 用于调优的处理器*/
public class StartupTimeMetric implements InstantiationAwareBeanPostProcessor, PriorityOrdered, ApplicationListener<ContextRefreshedEvent>, MergedBeanDefinitionPostProcessor {private static final LogHelper LOGGER = LogHelper.getLog(StartupTimeMetric.class);private final Map<String, Statistics> statisticsMap = new TreeMap<>();/*** InstantiationAwareBeanPostProcessor 中自定义的方法 在方法实例化之前执行 Bean 对象还没有*/@Overridepublic Object postProcessBeforeInstantiation(Class beanClass, String beanName) throws BeansException {String beanClassName = beanClass.getName();Statistics s = Statistics.builder().beanName(beanClassName).build();s.setBeforeInstantiationTime(System.currentTimeMillis());statisticsMap.put(beanClassName, s);return null;}/*** InstantiationAwareBeanPostProcessor 中自定义的方法 在方法实例化之后执行 Bean 对象已经创建出来了*/@Overridepublic boolean postProcessAfterInstantiation(Object bean, String beanName) throws BeansException {String beanClassName = bean.getClass().getName();Statistics s = statisticsMap.get(beanClassName);if (s != null)s.setAfterInstantiationTime(System.currentTimeMillis());return true;}/*** BeanPostProcessor 接口中的方法 在 Bean 的自定义初始化方法之前执行 Bean 对象已经存在了*/@Overridepublic Object postProcessBeforeInitialization(Object bean, String beanName) throws BeansException {String beanClassName = bean.getClass().getName();Statistics s = statisticsMap.getOrDefault(beanClassName, Statistics.builder().beanName(beanClassName).build());s.setBeforeInitializationTime(System.currentTimeMillis());statisticsMap.putIfAbsent(beanClassName, s);return bean;}/*** BeanPostProcessor 接口中的方法 在 Bean 的自定义初始化方法执行完成之后执行 Bean 对象已经存在了*/@Overridepublic Object postProcessAfterInitialization(Object bean, String beanName) throws BeansException {String beanClassName = bean.getClass().getName();Statistics s = statisticsMap.get(beanClassName);if (s != null)s.setAfterInitializationTime(System.currentTimeMillis());return bean;}@Overridepublic int getOrder() {return PriorityOrdered.HIGHEST_PRECEDENCE;}private static final AtomicBoolean START_LOCK = new AtomicBoolean(false);@Overridepublic void onApplicationEvent(ContextRefreshedEvent event) {LOGGER.info("Spring 容器启动完成");if (START_LOCK.compareAndSet(false, true)) {List<Statistics> sList = statisticsMap.values().stream().sorted(Comparator.comparing(Statistics::calculateTotalCostTime).reversed()).collect(Collectors.toList());StringBuilder sb = new StringBuilder();sList.forEach(_s -> sb.append(_s.toConsoleString()));LOGGER.info("ApplicationStartupTimeMetric:\n" + sb);}}@Overridepublic void postProcessMergedBeanDefinition(RootBeanDefinition beanDefinition, Class<?> beanType, String beanName) {}
}

参见《应用启动加速-并发初始化spring bean》