Search code examples
javaspringaopaspectjspring-aop

Adding AOP to Spring Boot process changes object returned by method to null


I want to add AOP for logging purposes to my Spring Boot application. But it seems to change my application's behavior in unexpected ways.

For example, my application has a method, doThis(), which creates a MyObject instance:

MyObject myObect = doThis();  // a non-null myObject is returned from doThis()

That works great and myObject is populated as expected with an instance returned from doThis(). But I want the doThis() method to also log some messages via AOP.

So then I add the following aspect class:

@Aspect
public class LoggingAspect {

    private static final Logger logger = LoggerFactory.getLogger(LoggingAspect.class);

    @Around("execution(* my.service.package.*.*(..))")
    public void log(ProceedingJoinPoint joinPoint) throws Throwable {
        logger.info("before");
        joinPoint.proceed();
        logger.info("after");
    }
}

And I also add this configuration class:

@Configuration
@ComponentScan(basePackages = "my.service.package")
@EnableAspectJAutoProxy
public class AppConfig {
    @Bean
    public LoggingAspect aspect() {
        return new LoggingAspect();
    }
}

However, now when I run my app, the logging statements do appear, as expected - but now that same exact doThis() method apparently returns a null object:

MyObject myObect = doThis(); // myObject is now unexplainedly null

But that's not true! What I mean by that is when I set a breakpoint on the last line of doThis(), the MyObject instance it is just about to return is very clearly not null. It has been created and populated within the doThis() method. So where did it go? Why did myObject not get populated when doThis() clearly returned a non-null MyObject instance?

It seems like the aspect is somehow nullifying the object returned from doThis(). Has anyone seen this before? Is there any way around it?

I believe the first * in my execution statement is supposed to indicate that the intercepted method can have any return type. But yet the returned value from my intercepted method seems to get somehow changed to null.

I'm working on how I can create a "minimal reproducible example", per the comment, which I'll add here, but this seems like perhaps a fairly standard AOP use case, so throwing it out there in the meantime in case someone may have some insight.


Solution

  • You made a simple beginner's AOP mistake: Your @Around advice proceeds, but does not return the result of the proceed() call. Your advice method has a void return type, your intercepted target method has not. So the advice implicitly returns null. By the way, for primitive types like int this would not even work and throw exceptions because of incompatible return types. I was actually surprised that Spring AOP, weirdly enough, even intercepts non-void methods if the around-advice returns void, because AFAIR native AspectJ would not match non-void methods in this case.

    So what can you do?

    • Either keep the @Around advice, if you really think you need it. Usually, this is only the case if you want to do more than log things, e.g. modify method parameters or return values, handle exceptions or other things potentially changing the control flow:

      @Around("execution(* my.service.package.*.*(..))")
      public Object log(ProceedingJoinPoint joinPoint) throws Throwable {
        logger.info("[BEFORE] " + joinPoint);
        try {
          return joinPoint.proceed();
        }
        finally {
          logger.info("[AFTER] " + joinPoint);
        }
      }
      
    • Or keep it simple and just use a pair of @Before and @After advice methods, if there is no need to transfer data from one advice to the other. This is much simpler, because you do not need to proceed, use try-finally or return anything:

      @Before("execution(* my.service.package.*.*(..))")
      public void logBefore(JoinPoint joinPoint) {
        logger.info("[BEFORE] " + joinPoint);
      }
      
      @After("execution(* my.service.package.*.*(..))")
      public void logAfter(JoinPoint joinPoint) {
        logger.info("[AFTER] " + joinPoint);
      }
      

      Here, you could also factor out the duplicate pointcut expression into its own @Pointcut and simply refer to it from both advice methods.