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

Question

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.

Please provide a [mcve]. Have you confirmed `myService.doThis()` returns `null`? — Sotirios Delimanolis, Feb 01 '22 at 16:02
`myService.doThis()` actually returns an entity object. And the aspect seems to work. But it doesn't work when I actually try to save the returned entity object. — Woodchuck, Feb 01 '22 at 16:04
The interesting thing is that doThis() does seem to return null - but only after I add the Aspect code. — Woodchuck, Feb 01 '22 at 16:10
OK. I modified the question, as the issues seems a little more straightforward, though just as confounding. — Woodchuck, Feb 01 '22 at 17:23

score 4 · Accepted Answer · answered Feb 02 '22 at 02:00

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.

Works great - thanks! I had actually taken my example directly from a book I bought, "Spring Start Here". Tried a few times and couldn't figure out why it wasn't working! — Woodchuck, Feb 03 '22 at 14:11
I quickly downloaded the free source code package for that book and can see that your aspect was taken from chapter 6, example 1. In that context, the example is correct, because the service methods it is trying to intercept both have `void` return types. The logging aspect is being evolved in examples 2-7, and everywhere in those it returns `Object`, just like my solution. So copying & pasting example code into a target application it does not fit into is a bad idea. At least, finish reading and try to fully understand that chapter, before you do that. — kriegaex, Feb 04 '22 at 01:42

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

1 Answers1