How to get Spring @ControllerAdvice work with other custom Spring @Aspect?

Question

I have a custom logger using @Aspect that I wish it always run at the last so that no matter what response returned from the controller, it will be logged to the database (so I put an @Order(1) on this aspect). And I have also written an error handler using @ControllerAdvice that handles all unexpected exceptions and returns 500 with a custom response body, and I want this to be logged by the logger as well so I put an @Order(2) on it, however looks like putting @Order annotation does not arrange the orders between Spring Aspect and Spring ControllerAdvice, so how do I let my error handler always run before the logger? (of course, without turning my error handler to another Spring Aspect)

Answer 1

I've been looking and debugging for your main problem. I didn't find the answer of your question about @Order, but I'll share with you my thinking (second part of this post)

Have you considered using Interceptor?

They provide way to log actions before you enter the controller, and after the @ControllerAdvice is executed, if there is one.

@Component
public class WebInterceptor extends HandlerInterceptorAdapter {

    private Logger logger = LoggerFactory.getLogger(WebInterceptor.class);

    @Override
    public boolean preHandle(HttpServletRequest request, HttpServletResponse response, Object handler) throws Exception {
        logger.error("WebInterceptor prehandle is now logged");
        return super.preHandle(request, response, handler);
    }

    @Override
    public void afterCompletion(HttpServletRequest request, HttpServletResponse response, Object handler, Exception ex) throws Exception {
        logger.error("WebInterceptor after completion is now logged");
        super.afterCompletion(request, response, handler, ex);
    }
}

To activate this Interceptor, you need to create a new @Configuration class, implementing WebMvcConfigurer:

@Configuration
public class AppConfig implements WebMvcConfigurer {

    @Autowired
    private WebInterceptor webInterceptor;

    @Override
    public void addInterceptors(InterceptorRegistry registry) {
        registry.addInterceptor(webInterceptor).addPathPatterns("/user");
    }
}

I've created a simple Controller and ControllerAdvice for the test:

@RestController
public class WebController {
    @GetMapping("/user")
    public String user() {
        throw new IllegalArgumentException("my bad");
    }
}


@RestControllerAdvice
@Order(2)
public class WebAdvice {

    private Logger logger = LoggerFactory.getLogger(WebAdvice.class);

    @ExceptionHandler(RuntimeException.class)
    @ResponseStatus(HttpStatus.INTERNAL_SERVER_ERROR)
    public void handle(RuntimeException e) {
        logger.error("ControllerAdvice is now logged");
    }
}

And the result is:

WebAdvice handle is now logged
WebInterceptor after completion is now logged

You can also have a look to this if you need to log the requests: https://www.baeldung.com/spring-http-logging

Here is what I've found about Order, Aspect and ControllerAdvice

You are right, there is no precedence between an @ControllerAdvice and a @Aspect, well kind of...

I couldn't find out why (not yet), but when an @Aspect in pointing on a @Controller method, then the point cut will be executed before the @ControllerAdvice, no matter the Order you set

@Aspect
@Component
@Order(1)
public class MyAspect {

    private Logger logger = LoggerFactory.getLogger(MyAspect.class);

    @After("execution(* WebController.user(..))")
    public void afterLog() {
        logger.error("Aspect is now logged");
    }
}

@RestControllerAdvice
@Order(2)
public class WebAdvice {

    private Logger logger = LoggerFactory.getLogger(WebAdvice.class);

    @ExceptionHandler(RuntimeException.class)
    @ResponseStatus(HttpStatus.INTERNAL_SERVER_ERROR)
    public void handle(RuntimeException e) {
        logger.error("ControllerAdvice is now logged");
    }
}

If you Get http://localhost:8080/user the result will be :

Aspect is now logged
ControllerAdvice is now logged

But I've found something interesting: If you set a pointcut @After the @ControllerAdvice then you have the aspect being executed after the controllerAdvice:

@Aspect
@Component
@Order(1)
public class MyAspect {

    private Logger logger = LoggerFactory.getLogger(MyAspect.class);

    @After("execution(* WebAdvice.handle(..)) || execution(* WebController.user(..))")
    public void afterLog() {
        logger.error("Aspect is now logged");
    }
}

It is executed 2 times. One after the Controller, and one after the Advice.

Aspect is now logged
ControllerAdvice is now logged
Aspect is now logged

Maybe this could fit your needs, but I don't really find this as an elegant solution...

The thing that still need to be solved:

• Finding a way to have a precedence over Aspect and ControllerAdvice

Hope it helps anyway. If I find something better, I'll let you know.