spring-framework icon indicating copy to clipboard operation
spring-framework copied to clipboard
verified publisher icon spring-projects

Spring AOP Proxy Not Working with BeanPostProcessor and FactoryBean Dependencies

Open java-lbb opened this issue 10 months ago • 8 comments

Description

When using Spring AOP to proxy a HelloService bean in combination with a custom BeanPostProcessor (MyPostProcessor) and a FactoryBean (MyFactoryBean), the AOP proxy is not applied to the target bean. The HelloService bean is returned as a plain Java object without any proxy applied. This issue occurs when the BeanPostProcessor has a dependency on another bean (GoodByeService in this case).

Expected Behavior

The HelloService bean should be proxied by AOP, and the following checks should return true:

AopUtils.isAopProxy(helloService) AopUtils.isJdkDynamicProxy(helloService) or AopUtils.isCglibProxy(helloService) The @AfterReturning advice in MyAspect should also be invoked when calling the sayHello method of HelloService.

Actual Behavior

The HelloService bean is not proxied. The following checks return false:

AopUtils.isAopProxy(helloService) AopUtils.isJdkDynamicProxy(helloService) AopUtils.isCglibProxy(helloService) Additionally, the @AfterReturning advice in MyAspect is not invoked.

Steps to Reproduce

Here is a minimal reproducible example:

  1. POM File
<project xmlns="http://maven.apache.org/POM/4.0.0"
         xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
         xsi:schemaLocation="http://maven.apache.org/POM/4.0.0 http://maven.apache.org/xsd/maven-4.0.0.xsd">
    <modelVersion>4.0.0</modelVersion>
    <artifactId>spring-aop</artifactId>
    <parent>
        <groupId>com.cj.lb</groupId>
        <artifactId>spring-exploration</artifactId>
        <version>1.0-SNAPSHOT</version>
    </parent>
    <properties>
        <spring-versrion>6.0.11</spring-versrion>
        <java.version>17</java.version>
        <project.build.sourceEncoding>UTF-8</project.build.sourceEncoding>
    </properties>

    <dependencies>
        <dependency>
            <groupId>org.springframework</groupId>
            <artifactId>spring-context</artifactId>
            <version>${spring-versrion}</version>
        </dependency>
        <dependency>
            <groupId>org.springframework</groupId>
            <artifactId>spring-aop</artifactId>
            <version>${spring-versrion}</version>
        </dependency>
        <dependency>
            <groupId>org.aspectj</groupId>
            <artifactId>aspectjweaver</artifactId>
            <version>1.9.5</version>
        </dependency>
    </dependencies>
</project>
  1. Configuration Class
@EnableAspectJAutoProxy
@Configuration
@ComponentScan
public class MyConfig {

    @Bean
    MyPostProcessor myPostProcessor(GoodByeService goodByeService) {
        MyPostProcessor myPostProcessor = new MyPostProcessor();
        myPostProcessor.setGoodByeService(goodByeService);
        return myPostProcessor;
    }

    @Bean
    MyFactoryBean myFactoryBean(HelloService helloService) {
        MyFactoryBean myFactoryBean = new MyFactoryBean();
        myFactoryBean.setHelloService(helloService);
        return myFactoryBean;
    }
}
  1. BeanPostProcessor
public class MyPostProcessor implements Ordered, BeanPostProcessor {

    private GoodByeService goodByeService;

    public GoodByeService getGoodByeService() {
        return goodByeService;
    }

    public void setGoodByeService(GoodByeService goodByeService) {
        this.goodByeService = goodByeService;
    }

    @Override
    public int getOrder() {
        return 0;
    }
}
  1. Service Classes
@Service
public class HelloServiceImpl implements HelloService {

    @Override
    public String sayHello() {
        String result = "hello world";
        System.out.println(result);
        return result;
    }
}

@Service
public class GoodByeServiceImpl implements GoodByeService {
    @Override
    public String sayGoodbye() {
        return "Goodbye";
    }
}
  1. FactoryBean
public class MyFactoryBean implements FactoryBean {

    private HelloService helloService;

    public HelloService getHelloService() {
        return helloService;
    }

    public void setHelloService(HelloService helloService) {
        this.helloService = helloService;
    }

    @Override
    public Object getObject() throws Exception {
        return new MyBean();
    }

    @Override
    public Class<?> getObjectType() {
        return MyBean.class;
    }

    public static class MyBean {
    }
}
  1. Aspect
@Component
@Aspect
public class MyAspect {

    @Pointcut("execution(* com.cj.lb.service.HelloService.sayHello(..))")
    public void pointcut() {}

    @AfterReturning(pointcut = "pointcut()", returning = "result")
    public void afterReturning(JoinPoint jp, Object result) {
        System.out.println("my aspect aop ...");
    }
}
  1. Main Class
public class Main {

    public static void main(String[] args) {
        AnnotationConfigApplicationContext context = new AnnotationConfigApplicationContext(MyConfig.class);

        HelloService helloService = context.getBean(HelloService.class);
        System.out.println("helloService.getClass() = " + helloService.getClass());

        System.out.println("Is AOP Proxy: " + AopUtils.isAopProxy(helloService));
        System.out.println("Is JDK Dynamic Proxy: " + AopUtils.isJdkDynamicProxy(helloService));
        System.out.println("Is CGLIB Proxy: " + AopUtils.isCglibProxy(helloService));

        context.close();
    }
}
  1. Output
helloService.getClass() = class com.cj.lb.service.impl.HelloServiceImpl
Is AOP Proxy: false
Is JDK Dynamic Proxy: false
Is CGLIB Proxy: false

Analysis and Workaround

The issue can be resolved by either of the following:

  1. Annotating the HelloService dependency in MyFactoryBean with @Lazy.
  2. Adding a proper generic type declaration for MyFactoryBean.

Question

Why does the presence of a BeanPostProcessor with dependencies interfere with the AOP proxy creation for HelloService? Is this a bug in Spring, or is there a specific configuration requirement that I missed?

Additional Context

This issue seems related to the bean initialization order or proxy creation timing, especially when BeanPostProcessor and FactoryBean dependencies are involved. Further clarification would be appreciated.

java-lbb avatar Mar 10 '25 10:03 java-lbb

@java-lbb cross-posted this on Stack Overflow where I answered with some additional analysis, e.g. explaining how @Lazy can help to work around the problem.

For your convenience, a reproducer is here: https://github.com/kriegaex/SO_AJ_SpringBeanPostProcessor_79505769

Activating @Lazy in both bean methods here makes the problem go away.

If you want to compare the extended log output for both variants, diff files

  • https://github.com/kriegaex/SO_AJ_SpringBeanPostProcessor_79505769/blob/master/no-lazy.txt and
  • https://github.com/kriegaex/SO_AJ_SpringBeanPostProcessor_79505769/blob/master/lazy.txt

to each other.

kriegaex avatar Apr 12 '25 06:04 kriegaex

Linking back to #34735, if it helps to have a reproducer. It is yet to be determined by the Spring developers, if these two issues are actually related.

kriegaex avatar Apr 12 '25 06:04 kriegaex

Based on your demo code, changing the following code will work:

@EnableAspectJAutoProxy
@Configuration
@ComponentScan
public class MyConfig {
  @Bean
  @Order(50)
  public static MyPostProcessor myPostProcessor(@Lazy GoodByeService goodByeService) {
    MyPostProcessor myPostProcessor = new MyPostProcessor();
    myPostProcessor.setGoodByeService(goodByeService);
    return myPostProcessor;
  }

  @Bean
  @Order(51)
  public static MyFactoryBean myFactoryBean(/*@Lazy*/ HelloService helloService) {
    MyFactoryBean myFactoryBean = new MyFactoryBean();
    myFactoryBean.setHelloService(helloService);
    return myFactoryBean;
  }
}

@Component
@Order(1)
@Aspect
public class MyAspect {
  @Pointcut("execution(* com.cj.lb.service.HelloService.sayHello(..))")
  public void interceptHello() {}

  @Pointcut("execution(* com.cj.lb.service.GoodByeService.sayGoodbye(..))")
  public void interceptGoodbye() {}

  @AfterReturning(pointcut = "interceptHello()", returning = "result")
  public void helloAdvice(JoinPoint jp, Object result) {
    System.out.println(jp);
  }

  @AfterReturning(pointcut = "interceptGoodbye()", returning = "result")
  public void goodbyeAdvice(JoinPoint jp, Object result) {
    System.out.println(jp);
  }
}

The reason is that myFactoryBean and myPostProcessor are initialized before Aspect, which makes it impossible to create the proxy correctly.

JoshuaChen avatar Apr 29 '25 22:04 JoshuaChen

@JoshuaChen, I tried this in my demo project, and it has no effect. I still need to use @Lazy for the @Beans.

kriegaex avatar Apr 30 '25 05:04 kriegaex

@kriegaex So sorry, I made a mistake, try the following code, the key is to make sure the log:

16:16:01 [main] TRACE o.s.c.a.ConfigurationClassEnhancer - Successfully enhanced com.cj.lb.MyAspect; enhanced class name is: com.cj.lb.MyAspect$$SpringCGLIB$$0
16:16:01 [main] TRACE o.s.c.a.ConfigurationClassPostProcessor - Replacing bean definition 'myAspect' existing class 'com.cj.lb.MyAspect' with enhanced class 'com.cj.lb.MyAspect$$SpringCGLIB$$0'

before

16:16:01 [main] DEBUG o.s.b.f.s.DefaultListableBeanFactory - Creating shared instance of singleton bean 'goodByeServiceImpl'
16:16:01 [main] TRACE o.s.b.f.s.DefaultListableBeanFactory - Creating instance of bean 'goodByeServiceImpl'
GoodByeServiceImpl constructor

@EnableAspectJAutoProxy
@ComponentScan
public class Main {

  public static void main(String[] args) {
    try (AnnotationConfigApplicationContext context = new AnnotationConfigApplicationContext(Main.class)) {
      HelloService helloService = context.getBean(HelloService.class);
      System.out.println("HelloService class:   " + helloService.getClass());
      System.out.println("Is AOP proxy:         " + AopUtils.isAopProxy(helloService));
      System.out.println("Is JDK proxy:         " + AopUtils.isJdkDynamicProxy(helloService));
      System.out.println("Is CGLIB proxy:       " + AopUtils.isCglibProxy(helloService));
      helloService.sayHello();

      GoodByeService goodbyeService = context.getBean(GoodByeService.class);
      System.out.println("GoodByeService class: " + goodbyeService.getClass());
      System.out.println("Is AOP proxy:         " + AopUtils.isAopProxy(goodbyeService));
      System.out.println("Is JDK proxy:         " + AopUtils.isJdkDynamicProxy(goodbyeService));
      System.out.println("Is CGLIB proxy:       " + AopUtils.isCglibProxy(goodbyeService));
      goodbyeService.sayGoodbye();
    }
  }
}

@Configuration
@Order(1)
@Aspect
public class MyAspect {
  @Pointcut("execution(* com.cj.lb.service.HelloService.sayHello(..))")
  public void interceptHello() {}

  @Pointcut("execution(* com.cj.lb.service.GoodByeService.sayGoodbye(..))")
  public void interceptGoodbye() {}

  @AfterReturning(pointcut = "interceptHello()", returning = "result")
  public void helloAdvice(JoinPoint jp, Object result) {
    System.out.println(jp);
  }

  @AfterReturning(pointcut = "interceptGoodbye()", returning = "result")
  public void goodbyeAdvice(JoinPoint jp, Object result) {
    System.out.println(jp);
  }
}

Do not use annotations at the MyConfig class level

public class MyConfig {

    @Bean
    public static MyPostProcessor myPostProcessor(/*@Lazy*/ GoodByeService goodByeService) {
        MyPostProcessor myPostProcessor = new MyPostProcessor();
        myPostProcessor.setGoodByeService(goodByeService);
        return myPostProcessor;
    }

    @Bean
    public static MyFactoryBean myFactoryBean(/*@Lazy*/ HelloService helloService) {
        MyFactoryBean myFactoryBean = new MyFactoryBean();
        myFactoryBean.setHelloService(helloService);
        return myFactoryBean;
    }

}

JoshuaChen avatar Apr 30 '25 08:04 JoshuaChen

@JoshuaChen, like this, the application does not even start but throws an error, which is no big surprise, because

  • an aspect is a @Component, not a @Configuration,
  • @Configuration, @EnableAspectJAutoProxy and @ComponentScan belong on the MyConfig configuration class, not on the main class or on an aspect.

I am grateful for trying to contribute helpful information here, but actually you are only polluting this issue, creating confusion.

kriegaex avatar Apr 30 '25 12:04 kriegaex

@kriegaex

um~ I don't know what the difference was between us.

https://github.com/JoshuaChen/SO_AJ_SpringBeanPostProcessor_79505769

My code is here, I compile and test it through IDEA, it works fine on my local. Here is its log:

BTW, I have mvn clear and then recompile


/Users/joshua/Library/Java/JavaVirtualMachines/azul-21.0.6/Contents/Home/bin/java -javaagent:/Users/joshua/Applications/IntelliJ IDEA Ultimate.app/Contents/lib/idea_rt.jar=60417 -Dfile.encoding=UTF-8 -Dsun.stdout.encoding=UTF-8 -Dsun.stderr.encoding=UTF-8 -classpath /Users/joshua/Code/test/SO_AJ_SpringBeanPostProcessor_79505769/target/classes:/Users/joshua/Code/repository/maven/org/springframework/spring-context/6.2.4/spring-context-6.2.4.jar:/Users/joshua/Code/repository/maven/org/springframework/spring-beans/6.2.4/spring-beans-6.2.4.jar:/Users/joshua/Code/repository/maven/org/springframework/spring-core/6.2.4/spring-core-6.2.4.jar:/Users/joshua/Code/repository/maven/org/springframework/spring-jcl/6.2.4/spring-jcl-6.2.4.jar:/Users/joshua/Code/repository/maven/org/springframework/spring-expression/6.2.4/spring-expression-6.2.4.jar:/Users/joshua/Code/repository/maven/io/micrometer/micrometer-observation/1.14.5/micrometer-observation-1.14.5.jar:/Users/joshua/Code/repository/maven/io/micrometer/micrometer-commons/1.14.5/micrometer-commons-1.14.5.jar:/Users/joshua/Code/repository/maven/org/springframework/spring-aop/6.2.4/spring-aop-6.2.4.jar:/Users/joshua/Code/repository/maven/org/aspectj/aspectjweaver/1.9.22.1/aspectjweaver-1.9.22.1.jar:/Users/joshua/Code/repository/maven/ch/qos/logback/logback-classic/1.4.6/logback-classic-1.4.6.jar:/Users/joshua/Code/repository/maven/ch/qos/logback/logback-core/1.4.6/logback-core-1.4.6.jar:/Users/joshua/Code/repository/maven/org/slf4j/slf4j-api/2.0.4/slf4j-api-2.0.4.jar com.cj.lb.Main
20:40:44,182 |-INFO in ch.qos.logback.classic.LoggerContext[default] - This is logback-classic version 1.4.6
20:40:44,200 |-INFO in ch.qos.logback.classic.LoggerContext[default] - Could NOT find resource [logback-test.xml]
20:40:44,203 |-INFO in ch.qos.logback.classic.LoggerContext[default] - Found resource [logback.xml] at [file:/Users/joshua/Code/test/SO_AJ_SpringBeanPostProcessor_79505769/target/classes/logback.xml]
20:40:44,262 |-INFO in ch.qos.logback.core.model.processor.AppenderModelHandler - Processing appender named [STDOUT]
20:40:44,262 |-INFO in ch.qos.logback.core.model.processor.AppenderModelHandler - About to instantiate appender of type [ch.qos.logback.core.ConsoleAppender]
20:40:44,285 |-WARN in ch.qos.logback.core.ConsoleAppender[STDOUT] - This appender no longer admits a layout as a sub-component, set an encoder instead.
20:40:44,285 |-WARN in ch.qos.logback.core.ConsoleAppender[STDOUT] - To ensure compatibility, wrapping your layout in LayoutWrappingEncoder.
20:40:44,285 |-WARN in ch.qos.logback.core.ConsoleAppender[STDOUT] - See also http://logback.qos.ch/codes.html#layoutInsteadOfEncoder for details
20:40:44,286 |-INFO in ch.qos.logback.classic.model.processor.LoggerModelHandler - Setting level of logger [org.springframework.beans] to TRACE
20:40:44,286 |-INFO in ch.qos.logback.classic.model.processor.LoggerModelHandler - Setting level of logger [org.springframework.context] to TRACE
20:40:44,286 |-INFO in ch.qos.logback.classic.model.processor.LoggerModelHandler - Setting level of logger [org.springframework.aop] to TRACE
20:40:44,286 |-INFO in ch.qos.logback.classic.model.processor.LoggerModelHandler - Setting level of logger [org.springframework.cglib] to TRACE
20:40:44,286 |-INFO in ch.qos.logback.classic.model.processor.LoggerModelHandler - Setting level of logger [org.springframework.aot] to TRACE
20:40:44,286 |-INFO in ch.qos.logback.classic.model.processor.RootLoggerModelHandler - Setting level of ROOT logger to INFO
20:40:44,286 |-INFO in ch.qos.logback.core.model.processor.AppenderRefModelHandler - Attaching appender named [STDOUT] to Logger[ROOT]
20:40:44,286 |-INFO in ch.qos.logback.core.model.processor.DefaultProcessor@2c34f934 - End of configuration.
20:40:44,287 |-INFO in ch.qos.logback.classic.joran.JoranConfigurator@12d3a4e9 - Registering current configuration as safe fallback point

20:40:44 [main] TRACE o.s.c.a.AnnotationConfigApplicationContext - Refreshing org.springframework.context.annotation.AnnotationConfigApplicationContext@1d548a08, started on Wed Apr 30 20:40:44 CST 2025
20:40:44 [main] DEBUG o.s.b.f.s.DefaultListableBeanFactory - Creating shared instance of singleton bean 'org.springframework.context.annotation.internalConfigurationAnnotationProcessor'
20:40:44 [main] TRACE o.s.b.f.s.DefaultListableBeanFactory - Creating instance of bean 'org.springframework.context.annotation.internalConfigurationAnnotationProcessor'
20:40:44 [main] TRACE o.s.b.f.s.DefaultListableBeanFactory - Eagerly caching bean 'org.springframework.context.annotation.internalConfigurationAnnotationProcessor' to allow for resolving potential circular references
20:40:44 [main] TRACE o.s.b.f.s.DefaultListableBeanFactory - Finished creating instance of bean 'org.springframework.context.annotation.internalConfigurationAnnotationProcessor'
20:40:44 [main] TRACE o.s.c.a.ClassPathBeanDefinitionScanner - Scanning file [/Users/joshua/Code/test/SO_AJ_SpringBeanPostProcessor_79505769/target/classes/com/cj/lb/Main.class]
20:40:44 [main] TRACE o.s.c.a.ClassPathBeanDefinitionScanner - Ignored because not matching any filter: file [/Users/joshua/Code/test/SO_AJ_SpringBeanPostProcessor_79505769/target/classes/com/cj/lb/Main.class]
20:40:44 [main] TRACE o.s.c.a.ClassPathBeanDefinitionScanner - Scanning file [/Users/joshua/Code/test/SO_AJ_SpringBeanPostProcessor_79505769/target/classes/com/cj/lb/MyAspect.class]
20:40:44 [main] DEBUG o.s.c.a.ClassPathBeanDefinitionScanner - Identified candidate component class: file [/Users/joshua/Code/test/SO_AJ_SpringBeanPostProcessor_79505769/target/classes/com/cj/lb/MyAspect.class]
20:40:44 [main] TRACE o.s.c.a.ClassPathBeanDefinitionScanner - Scanning file [/Users/joshua/Code/test/SO_AJ_SpringBeanPostProcessor_79505769/target/classes/com/cj/lb/MyConfig.class]
20:40:44 [main] TRACE o.s.c.a.ClassPathBeanDefinitionScanner - Ignored because not matching any filter: file [/Users/joshua/Code/test/SO_AJ_SpringBeanPostProcessor_79505769/target/classes/com/cj/lb/MyConfig.class]
20:40:44 [main] TRACE o.s.c.a.ClassPathBeanDefinitionScanner - Scanning file [/Users/joshua/Code/test/SO_AJ_SpringBeanPostProcessor_79505769/target/classes/com/cj/lb/MyFactoryBean$MyBean.class]
20:40:44 [main] TRACE o.s.c.a.ClassPathBeanDefinitionScanner - Ignored because not matching any filter: file [/Users/joshua/Code/test/SO_AJ_SpringBeanPostProcessor_79505769/target/classes/com/cj/lb/MyFactoryBean$MyBean.class]
20:40:44 [main] TRACE o.s.c.a.ClassPathBeanDefinitionScanner - Scanning file [/Users/joshua/Code/test/SO_AJ_SpringBeanPostProcessor_79505769/target/classes/com/cj/lb/MyFactoryBean.class]
20:40:44 [main] TRACE o.s.c.a.ClassPathBeanDefinitionScanner - Ignored because not matching any filter: file [/Users/joshua/Code/test/SO_AJ_SpringBeanPostProcessor_79505769/target/classes/com/cj/lb/MyFactoryBean.class]
20:40:44 [main] TRACE o.s.c.a.ClassPathBeanDefinitionScanner - Scanning file [/Users/joshua/Code/test/SO_AJ_SpringBeanPostProcessor_79505769/target/classes/com/cj/lb/MyPostProcessor.class]
20:40:44 [main] TRACE o.s.c.a.ClassPathBeanDefinitionScanner - Ignored because not matching any filter: file [/Users/joshua/Code/test/SO_AJ_SpringBeanPostProcessor_79505769/target/classes/com/cj/lb/MyPostProcessor.class]
20:40:44 [main] TRACE o.s.c.a.ClassPathBeanDefinitionScanner - Scanning file [/Users/joshua/Code/test/SO_AJ_SpringBeanPostProcessor_79505769/target/classes/com/cj/lb/service/GoodByeService.class]
20:40:44 [main] TRACE o.s.c.a.ClassPathBeanDefinitionScanner - Ignored because not matching any filter: file [/Users/joshua/Code/test/SO_AJ_SpringBeanPostProcessor_79505769/target/classes/com/cj/lb/service/GoodByeService.class]
20:40:44 [main] TRACE o.s.c.a.ClassPathBeanDefinitionScanner - Scanning file [/Users/joshua/Code/test/SO_AJ_SpringBeanPostProcessor_79505769/target/classes/com/cj/lb/service/GoodByeServiceImpl.class]
20:40:44 [main] DEBUG o.s.c.a.ClassPathBeanDefinitionScanner - Identified candidate component class: file [/Users/joshua/Code/test/SO_AJ_SpringBeanPostProcessor_79505769/target/classes/com/cj/lb/service/GoodByeServiceImpl.class]
20:40:44 [main] TRACE o.s.c.a.ClassPathBeanDefinitionScanner - Scanning file [/Users/joshua/Code/test/SO_AJ_SpringBeanPostProcessor_79505769/target/classes/com/cj/lb/service/HelloService.class]
20:40:44 [main] TRACE o.s.c.a.ClassPathBeanDefinitionScanner - Ignored because not matching any filter: file [/Users/joshua/Code/test/SO_AJ_SpringBeanPostProcessor_79505769/target/classes/com/cj/lb/service/HelloService.class]
20:40:44 [main] TRACE o.s.c.a.ClassPathBeanDefinitionScanner - Scanning file [/Users/joshua/Code/test/SO_AJ_SpringBeanPostProcessor_79505769/target/classes/com/cj/lb/service/HelloServiceImpl.class]
20:40:44 [main] DEBUG o.s.c.a.ClassPathBeanDefinitionScanner - Identified candidate component class: file [/Users/joshua/Code/test/SO_AJ_SpringBeanPostProcessor_79505769/target/classes/com/cj/lb/service/HelloServiceImpl.class]
20:40:44 [main] TRACE o.s.c.a.ConfigurationClassEnhancer - Successfully enhanced com.cj.lb.MyAspect; enhanced class name is: com.cj.lb.MyAspect$$SpringCGLIB$$0
20:40:44 [main] TRACE o.s.c.a.ConfigurationClassPostProcessor - Replacing bean definition 'myAspect' existing class 'com.cj.lb.MyAspect' with enhanced class 'com.cj.lb.MyAspect$$SpringCGLIB$$0'
20:40:44 [main] DEBUG o.s.b.f.s.DefaultListableBeanFactory - Creating shared instance of singleton bean 'org.springframework.context.event.internalEventListenerProcessor'
20:40:44 [main] TRACE o.s.b.f.s.DefaultListableBeanFactory - Creating instance of bean 'org.springframework.context.event.internalEventListenerProcessor'
20:40:44 [main] TRACE o.s.b.f.s.DefaultListableBeanFactory - Eagerly caching bean 'org.springframework.context.event.internalEventListenerProcessor' to allow for resolving potential circular references
20:40:44 [main] TRACE o.s.b.f.s.DefaultListableBeanFactory - Finished creating instance of bean 'org.springframework.context.event.internalEventListenerProcessor'
20:40:44 [main] DEBUG o.s.b.f.s.DefaultListableBeanFactory - Creating shared instance of singleton bean 'org.springframework.context.event.internalEventListenerFactory'
20:40:44 [main] TRACE o.s.b.f.s.DefaultListableBeanFactory - Creating instance of bean 'org.springframework.context.event.internalEventListenerFactory'
20:40:44 [main] TRACE o.s.b.f.s.DefaultListableBeanFactory - Eagerly caching bean 'org.springframework.context.event.internalEventListenerFactory' to allow for resolving potential circular references
20:40:44 [main] TRACE o.s.b.f.s.DefaultListableBeanFactory - Finished creating instance of bean 'org.springframework.context.event.internalEventListenerFactory'
20:40:44 [main] DEBUG o.s.b.f.s.DefaultListableBeanFactory - Creating shared instance of singleton bean 'org.springframework.context.annotation.internalAutowiredAnnotationProcessor'
20:40:44 [main] TRACE o.s.b.f.s.DefaultListableBeanFactory - Creating instance of bean 'org.springframework.context.annotation.internalAutowiredAnnotationProcessor'
20:40:44 [main] TRACE o.s.b.f.s.DefaultListableBeanFactory - Eagerly caching bean 'org.springframework.context.annotation.internalAutowiredAnnotationProcessor' to allow for resolving potential circular references
20:40:44 [main] TRACE o.s.b.f.s.DefaultListableBeanFactory - Finished creating instance of bean 'org.springframework.context.annotation.internalAutowiredAnnotationProcessor'
20:40:44 [main] DEBUG o.s.b.f.s.DefaultListableBeanFactory - Creating shared instance of singleton bean 'org.springframework.aop.config.internalAutoProxyCreator'
20:40:44 [main] TRACE o.s.b.f.s.DefaultListableBeanFactory - Creating instance of bean 'org.springframework.aop.config.internalAutoProxyCreator'
20:40:44 [main] TRACE o.s.b.f.s.DefaultListableBeanFactory - Eagerly caching bean 'org.springframework.aop.config.internalAutoProxyCreator' to allow for resolving potential circular references
20:40:44 [main] TRACE o.s.beans.CachedIntrospectionResults - Getting BeanInfo for class [org.springframework.aop.aspectj.annotation.AnnotationAwareAspectJAutoProxyCreator]
20:40:44 [main] TRACE o.s.beans.CachedIntrospectionResults - Caching PropertyDescriptors for class [org.springframework.aop.aspectj.annotation.AnnotationAwareAspectJAutoProxyCreator]
20:40:44 [main] TRACE o.s.beans.CachedIntrospectionResults - Found bean property 'advisorAdapterRegistry' of type [org.springframework.aop.framework.adapter.AdvisorAdapterRegistry]
20:40:44 [main] TRACE o.s.beans.CachedIntrospectionResults - Found bean property 'applyCommonInterceptorsFirst' of type [boolean]
20:40:44 [main] TRACE o.s.beans.CachedIntrospectionResults - Found bean property 'aspectJAdvisorFactory' of type [org.springframework.aop.aspectj.annotation.AspectJAdvisorFactory]
20:40:44 [main] TRACE o.s.beans.CachedIntrospectionResults - Found bean property 'beanClassLoader' of type [java.lang.ClassLoader]
20:40:44 [main] TRACE o.s.beans.CachedIntrospectionResults - Found bean property 'beanFactory' of type [org.springframework.beans.factory.BeanFactory]
20:40:44 [main] TRACE o.s.beans.CachedIntrospectionResults - Found bean property 'class' of type [java.lang.Class]
20:40:44 [main] TRACE o.s.beans.CachedIntrospectionResults - Found bean property 'customTargetSourceCreators' of type [[Lorg.springframework.aop.framework.autoproxy.TargetSourceCreator;]
20:40:44 [main] TRACE o.s.beans.CachedIntrospectionResults - Found bean property 'exposeProxy' of type [boolean]
20:40:44 [main] TRACE o.s.beans.CachedIntrospectionResults - Found bean property 'frozen' of type [boolean]
20:40:44 [main] TRACE o.s.beans.CachedIntrospectionResults - Found bean property 'includePatterns' of type [java.util.List]
20:40:44 [main] TRACE o.s.beans.CachedIntrospectionResults - Found bean property 'interceptorNames' of type [[Ljava.lang.String;]
20:40:44 [main] TRACE o.s.beans.CachedIntrospectionResults - Found bean property 'opaque' of type [boolean]
20:40:44 [main] TRACE o.s.beans.CachedIntrospectionResults - Found bean property 'optimize' of type [boolean]
20:40:44 [main] TRACE o.s.beans.CachedIntrospectionResults - Found bean property 'order' of type [int]
20:40:44 [main] TRACE o.s.beans.CachedIntrospectionResults - Found bean property 'proxyClassLoader' of type [java.lang.ClassLoader]
20:40:44 [main] TRACE o.s.beans.CachedIntrospectionResults - Found bean property 'proxyTargetClass' of type [boolean]
20:40:44 [main] TRACE o.s.b.f.s.DefaultListableBeanFactory - Finished creating instance of bean 'org.springframework.aop.config.internalAutoProxyCreator'
20:40:44 [main] TRACE o.s.c.a.AnnotationConfigApplicationContext - No 'messageSource' bean, using [Empty MessageSource]
20:40:44 [main] TRACE o.s.c.a.AnnotationConfigApplicationContext - No 'applicationEventMulticaster' bean, using [SimpleApplicationEventMulticaster]
20:40:44 [main] TRACE o.s.b.f.s.DefaultListableBeanFactory - Pre-instantiating singletons in org.springframework.beans.factory.support.DefaultListableBeanFactory@3246fb96: defining beans [org.springframework.context.annotation.internalConfigurationAnnotationProcessor,org.springframework.context.annotation.internalAutowiredAnnotationProcessor,org.springframework.context.event.internalEventListenerProcessor,org.springframework.context.event.internalEventListenerFactory,main,myAspect,goodByeServiceImpl,helloServiceImpl,org.springframework.aop.config.internalAutoProxyCreator]; root of factory hierarchy
20:40:44 [main] TRACE o.s.b.f.s.DefaultListableBeanFactory - Returning cached instance of singleton bean 'org.springframework.context.annotation.internalConfigurationAnnotationProcessor'
20:40:44 [main] TRACE o.s.b.f.s.DefaultListableBeanFactory - Returning cached instance of singleton bean 'org.springframework.context.annotation.internalAutowiredAnnotationProcessor'
20:40:44 [main] TRACE o.s.b.f.s.DefaultListableBeanFactory - Returning cached instance of singleton bean 'org.springframework.context.event.internalEventListenerProcessor'
20:40:44 [main] TRACE o.s.b.f.s.DefaultListableBeanFactory - Returning cached instance of singleton bean 'org.springframework.context.event.internalEventListenerFactory'
20:40:44 [main] DEBUG o.s.b.f.s.DefaultListableBeanFactory - Creating shared instance of singleton bean 'main'
20:40:44 [main] TRACE o.s.b.f.s.DefaultListableBeanFactory - Creating instance of bean 'main'
20:40:44 [main] DEBUG o.s.a.a.a.ReflectiveAspectJAdvisorFactory - Found AspectJ method: public void com.cj.lb.MyAspect.goodbyeAdvice(org.aspectj.lang.JoinPoint,java.lang.Object)
20:40:44 [main] DEBUG o.s.a.a.a.ReflectiveAspectJAdvisorFactory - Found AspectJ method: public void com.cj.lb.MyAspect.helloAdvice(org.aspectj.lang.JoinPoint,java.lang.Object)
20:40:44 [main] TRACE o.s.b.f.s.DefaultListableBeanFactory - Eagerly caching bean 'main' to allow for resolving potential circular references
20:40:44 [main] TRACE o.s.b.f.s.DefaultListableBeanFactory - Finished creating instance of bean 'main'
20:40:44 [main] DEBUG o.s.b.f.s.DefaultListableBeanFactory - Creating shared instance of singleton bean 'myAspect'
20:40:44 [main] TRACE o.s.b.f.s.DefaultListableBeanFactory - Creating instance of bean 'myAspect'
20:40:44 [main] TRACE o.s.b.f.s.DefaultListableBeanFactory - Eagerly caching bean 'myAspect' to allow for resolving potential circular references
20:40:44 [main] TRACE o.s.b.f.s.DefaultListableBeanFactory - Finished creating instance of bean 'myAspect'
20:40:44 [main] DEBUG o.s.b.f.s.DefaultListableBeanFactory - Creating shared instance of singleton bean 'goodByeServiceImpl'
20:40:44 [main] TRACE o.s.b.f.s.DefaultListableBeanFactory - Creating instance of bean 'goodByeServiceImpl'
GoodByeServiceImpl constructor
20:40:44 [main] TRACE o.s.b.f.s.DefaultListableBeanFactory - Eagerly caching bean 'goodByeServiceImpl' to allow for resolving potential circular references
20:40:44 [main] TRACE o.s.a.a.a.AnnotationAwareAspectJAutoProxyCreator - Creating implicit proxy for bean 'goodByeServiceImpl' with 0 common interceptors and 2 specific interceptors
20:40:44 [main] TRACE o.s.aop.framework.JdkDynamicAopProxy - Creating JDK dynamic proxy: SingletonTargetSource for target object [com.cj.lb.service.GoodByeServiceImpl@fcb4004]
20:40:44 [main] TRACE o.s.b.f.s.DefaultListableBeanFactory - Finished creating instance of bean 'goodByeServiceImpl'
20:40:44 [main] DEBUG o.s.b.f.s.DefaultListableBeanFactory - Creating shared instance of singleton bean 'helloServiceImpl'
20:40:44 [main] TRACE o.s.b.f.s.DefaultListableBeanFactory - Creating instance of bean 'helloServiceImpl'
HelloServiceImpl constructor
20:40:44 [main] TRACE o.s.b.f.s.DefaultListableBeanFactory - Eagerly caching bean 'helloServiceImpl' to allow for resolving potential circular references
20:40:44 [main] TRACE o.s.a.a.a.AnnotationAwareAspectJAutoProxyCreator - Creating implicit proxy for bean 'helloServiceImpl' with 0 common interceptors and 2 specific interceptors
20:40:44 [main] TRACE o.s.aop.framework.JdkDynamicAopProxy - Creating JDK dynamic proxy: SingletonTargetSource for target object [com.cj.lb.service.HelloServiceImpl@4cf8b2dc]
20:40:44 [main] TRACE o.s.b.f.s.DefaultListableBeanFactory - Finished creating instance of bean 'helloServiceImpl'
20:40:44 [main] TRACE o.s.b.f.s.DefaultListableBeanFactory - Returning cached instance of singleton bean 'org.springframework.aop.config.internalAutoProxyCreator'
20:40:44 [main] TRACE o.s.c.e.EventListenerMethodProcessor - No @EventListener annotations found on bean class: com.cj.lb.Main
20:40:44 [main] TRACE o.s.c.e.EventListenerMethodProcessor - No @EventListener annotations found on bean class: com.cj.lb.MyAspect$$SpringCGLIB$$0
20:40:44 [main] TRACE o.s.c.e.EventListenerMethodProcessor - No @EventListener annotations found on bean class: com.cj.lb.service.GoodByeServiceImpl
20:40:44 [main] TRACE o.s.c.e.EventListenerMethodProcessor - No @EventListener annotations found on bean class: com.cj.lb.service.HelloServiceImpl
20:40:44 [main] TRACE o.s.c.a.AnnotationConfigApplicationContext - No 'lifecycleProcessor' bean, using [DefaultLifecycleProcessor]
20:40:44 [main] TRACE o.s.b.f.s.DefaultListableBeanFactory - Returning cached instance of singleton bean 'lifecycleProcessor'
20:40:44 [main] TRACE o.s.b.f.s.DefaultListableBeanFactory - Returning cached instance of singleton bean 'helloServiceImpl'
HelloService class:   class jdk.proxy2.$Proxy22
Is AOP proxy:         true
Is JDK proxy:         true
Is CGLIB proxy:       false
Hello, world!
20:40:44 [main] TRACE o.s.b.f.s.DefaultListableBeanFactory - Returning cached instance of singleton bean 'myAspect'
execution(String com.cj.lb.service.HelloService.sayHello())
20:40:44 [main] TRACE o.s.b.f.s.DefaultListableBeanFactory - Returning cached instance of singleton bean 'goodByeServiceImpl'
GoodByeService class: class jdk.proxy2.$Proxy21
Is AOP proxy:         true
Is JDK proxy:         true
Is CGLIB proxy:       false
Goodbye, world!
execution(String com.cj.lb.service.GoodByeService.sayGoodbye())
20:40:44 [main] DEBUG o.s.c.a.AnnotationConfigApplicationContext - Closing org.springframework.context.annotation.AnnotationConfigApplicationContext@1d548a08, started on Wed Apr 30 20:40:44 CST 2025
20:40:44 [main] TRACE o.s.b.f.s.DefaultListableBeanFactory - Returning cached instance of singleton bean 'lifecycleProcessor'
20:40:44 [main] TRACE o.s.b.f.s.DefaultListableBeanFactory - Destroying singletons in org.springframework.beans.factory.support.DefaultListableBeanFactory@3246fb96: defining beans [org.springframework.context.annotation.internalConfigurationAnnotationProcessor,org.springframework.context.annotation.internalAutowiredAnnotationProcessor,org.springframework.context.event.internalEventListenerProcessor,org.springframework.context.event.internalEventListenerFactory,main,myAspect,goodByeServiceImpl,helloServiceImpl,org.springframework.aop.config.internalAutoProxyCreator]; root of factory hierarchy
20:40:44 [main] TRACE o.s.b.f.s.DisposableBeanAdapter - Invoking destroy() on bean with name 'org.springframework.aop.config.internalAutoProxyCreator'

Process finished with exit code 0

JoshuaChen avatar Apr 30 '25 12:04 JoshuaChen

@JoshuaChen, I had overlooked that you changed new AnnotationConfigApplicationContext(MyConfig.class) to new AnnotationConfigApplicationContext(Main.class). After applying that change, I can reproduce that you also got it working like that. I also cleaned up the somewhat chaotic scattering of annotations you created there, e.g. making the aspect a @Component again, not a @Configuration. It also still works without the @Order(1) annotation on the aspect.

The main change is that you removed @Configuration from the actual configuration class MyConfig where it really belongs, abusing the main class as a configuration class. I guess, this leads to the two @Beans being instantiated later than with a more canonical setup. Moving @Configuration back to MyConfig makes it fail again, which is why I call that workaround brittle. It could break anytime, so your suggestion, while working in this particular test case, seems unreliable. I still recommend to be explicit and use @Lazy for the beans in question. It is absolutely counter-intuitive to remove the config annotations from the config class and move them to the main class. BTW, also moving the @Bean methods to the main class, getting rid of the config class altogether, makes it break again.

Don't do this at home, kids!

kriegaex avatar May 01 '25 07:05 kriegaex