如何统计Spring应用中所有@PostConstruct方法的执行耗时

问题背景 #

在Spring应用中，需要统计所有标注@PostConstruct注解的方法的执行耗时，尝试两种AOP切面实现均出现问题：

• 第一种使用@within(javax.annotation.PostConstruct)作为切点，统计结果包含了Autowired依赖注入的耗时，不符合仅统计@PostConstruct方法本身的需求
• 第二种改用@annotation(javax.annotation.PostConstruct)作为切点，导致RedisTemplate等Bean实例化失败，抛出异常：

Caused by: org.springframework.beans.BeanInstantiationException: Failed to instantiate [org.springframework.data.redis.core.RedisTemplate]: Factory method 'redisTemplate' threw exception; nested exception is java.lang.NullPointerException

两种尝试的切面代码 #

第一种切面代码

@Component
@Aspect
@Order(1)
public class InspectorTime {
    private static final Logger LOG = LoggerFactory.getLogger(InspectorTime.class);

    @Around("@within(javax.annotation.PostConstruct)")
    public void beforePostConstruct(ProceedingJoinPoint joinPoint) throws Throwable {
        LOG.info("Before PostContract:{}", joinPoint.getSignature().getDeclaringType().toString());
        StopWatch stopWatch = new StopWatch();
        stopWatch.start();
        joinPoint.proceed(joinPoint.getArgs());
        stopWatch.stop();
        LOG.info("After PostContract:{}", joinPoint.getSignature().getDeclaringType().toString() + ", total time" + stopWatch.toString());
    }
}

第二种切面代码

@Component
@Aspect
@Order(1)
public class InspectorTime {
    private static final Logger logger = LoggerFactory.getLogger(InspectorTime.class);

    @Around("@annotation(javax.annotation.PostConstruct)")
    public Object logExecutionTime(ProceedingJoinPoint joinPoint) throws Throwable {
        long start = System.currentTimeMillis();
        Object proceed = joinPoint.proceed();
        long executionTime = System.currentTimeMillis() - start;
        logger.info("{}.{} executed in {} ms", joinPoint.getSignature().getDeclaringTypeName(),
                joinPoint.getSignature().getName(), executionTime);
        return proceed;
    }
}

问题分析 #

第一种切面的核心问题 #

@within切点表达式匹配的是类上标注了指定注解的所有方法，但@PostConstruct是方法级注解，不会标注在类上。这种写法无法正确匹配到@PostConstruct方法，反而可能误匹配其他类的方法，导致统计范围包含了Bean初始化过程中Autowired注入等前置逻辑的耗时，不符合需求。

第二种切面的核心问题 #

1. 切面执行顺序冲突：Spring通过InitDestroyAnnotationBeanPostProcessor调用@PostConstruct方法，而切面设置了@Order(1)（优先级过高），会在Spring完成Bean依赖注入前就拦截方法执行，导致方法内部依赖的Bean未初始化，抛出空指针异常。
2. 返回值处理（次要）：@PostConstruct方法本身无返回值，切面返回Object虽不会直接报错，但不符合方法原始签名规范。

解决方案 #

正确的切面实现 #

调整切面执行顺序，确保在Spring内置初始化处理器之后执行，同时保持切点表达式准确性：

@Component
@Aspect
// 设置最低优先级，让Spring先完成Bean依赖注入和内置初始化逻辑
@Order(Ordered.LOWEST_PRECEDENCE)
public class PostConstructTimeInspector {
    private static final Logger logger = LoggerFactory.getLogger(PostConstructTimeInspector.class);

    @Around("@annotation(javax.annotation.PostConstruct)")
    public Object logPostConstructExecutionTime(ProceedingJoinPoint joinPoint) throws Throwable {
        String beanClass = joinPoint.getSignature().getDeclaringTypeName();
        String methodName = joinPoint.getSignature().getName();
        
        long startTime = System.currentTimeMillis();
        try {
            // @PostConstruct方法无返回值，proceed()返回null，直接返回即可
            return joinPoint.proceed();
        } finally {
            long executionTime = System.currentTimeMillis() - startTime;
            logger.info("Bean [{}] @PostConstruct method [{}] executed in {} ms", 
                        beanClass, methodName, executionTime);
        }
    }
}

关键注意事项 #

• 切面优先级：使用Ordered.LOWEST_PRECEDENCE或较大数值作为@Order参数，确保切面在Spring内置的InitDestroyAnnotationBeanPostProcessor之后执行，避免Bean未完成依赖注入就被拦截。
• 切点准确性：@annotation(javax.annotation.PostConstruct)是匹配方法级@PostConstruct注解的正确方式，不要使用@within。
• 异常安全：使用finally块统计耗时，确保即使@PostConstruct方法抛出异常，也能记录执行时间。
• 返回值兼容：保持切面返回值与目标方法一致，@PostConstruct方法无返回值时，直接返回proceed()结果即可。

内容的提问来源于stack exchange，提问作者Hard Worker