Sl4j logger does not log when it used in conjunction with ResponseEntityExceptionHandler for catching exceptions

Question

I have used @ControllerAdvice to create a catch-all exception handler to catch all exceptions and log accordingly. However, for some reason, the sl4j logger fails to log to console. The same logger works every other place in my application but it does not work in the catch-all exception handler.

@ControllerAdvice
@Slf4j
public class CatchAllExceptionHandler extends ResponseEntityExceptionHandler {

  private ResponseEntity<Object> buildResponseEntity(ApiError apiError) {
    return new ResponseEntity<>(apiError, apiError.getStatus());
  }

  @ExceptionHandler(Exception.class)
  public ResponseEntity<Object> catchAllExceptionHandler(Exception ex) {
    ApiError apiError =
        ApiError.builder()
            .status(HttpStatus.INTERNAL_SERVER_ERROR)
            .message("An internal service issue")
            .debugMessage(ex.getMessage())
            .build();
    log.debug("An issue has occurred, {}, {}", kv("message", ex.getMessage()),
        kv("trace", ex.getStackTrace()));
    return buildResponseEntity(apiError);
  }
}

Sl4j from Lombok has been used but I am not sure if this has anything to do with Lombok. I can see that the superclass (ResponseEntityExceptionHandler) has its own logger so I don't think any weird variable hiding is happening, but I am not sure.

I am pretty sure my logging profile and configuration is correct as it's working any other places except inside this catch-all exception handler. It just simply does not print anything in logs.

UPDATE:

I can use logger from the superclass and it works. However, it uses apache commons-logging which is missing some specific methods I need here.

Answer 1

Spring boot default log level is info so debug logs are getting suppressed. I slightly modified your code to reproduce the issue.

@ExceptionHandler(Exception.class)
public ResponseEntity<Object> catchAllExceptionHandler(Exception ex) {
  log.info("******");
  log.debug("An issue has occurred, {}", ex.getMessage());
  log.info("An issue has occurred, {}", ex.getMessage());
  log.info("******");
  return ResponseEntity.status(500).build();
}

Output from above code:
See only info logs got printed.

2020-09-03 22:25:45.065  INFO c.e.demo.main.CatchAllExceptionHandler   : ******
2020-09-03 22:25:45.065  INFO c.e.demo.main.CatchAllExceptionHandler   : An issue has occurred, test exception
2020-09-03 22:25:45.065  INFO c.e.demo.main.CatchAllExceptionHandler   : ******

Solution 1:
Change log.debug to log.info or log.warn or log.error. This suites more in your case.

Solution 2:
Add a property to enable debug log for CatchAllExceptionHandler in your application.properties.

logging.level.com.example.demo.main.CatchAllExceptionHandler=debug

Output after adding above property:

2020-09-03 22:36:05.389  INFO c.e.demo.main.CatchAllExceptionHandler   : ******
2020-09-03 22:36:05.389 DEBUG c.e.demo.main.CatchAllExceptionHandler   : An issue has occurred, test exception
2020-09-03 22:36:05.389  INFO c.e.demo.main.CatchAllExceptionHandler   : An issue has occurred, test exception
2020-09-03 22:36:05.389  INFO c.e.demo.main.CatchAllExceptionHandler   : ******