Spring REST using Jackson - 400 bad request logging

I have spring REST set up fine using Jackson/JSON and everything works.

But I knowingly introduced an error in the structure of the message which resulted in a 400 - Bad Request. But there was no log output on the server. The error I would be expecting would be something like "Jackson unknown property exception" or whatever but it was caught and a 400 error was sent to the client, but no log of the exception on the server.

I don't want to debug everything on the server clearly, but I want Spring network level exceptions like this clearly labelled as error.

What is the correct way to switch this on?

Thanks!

@ExceptionHandler
@ResponseStatus(HttpStatus.BAD_REQUEST)
public void handle(HttpMessageNotReadableException e) {
    logger.warn("Returning HTTP 400 Bad Request", e);
}

Building on @Jukka's answer, you can enable this globally for all controllers using @ControllerAdvice (introduced in Spring 3.2). It does require a little code on your end, but in my experience you usually end up needing a global error handling configuration anyways and this allows you to set breakpoints / easily inspect the problems.

An example of this is below:

@ControllerAdvice
public class ControllerConfig {

    @ExceptionHandler
    @ResponseStatus(HttpStatus.BAD_REQUEST)
    public void handle(HttpMessageNotReadableException e) {
        log.warn("Returning HTTP 400 Bad Request", e);
        throw e;
    }
}

In case anyone else stumbles on this issue, the following worked for me in Spring Boot 2 / Spring 5 and didn't require a code change.

I set the log level for org.springframework.web.servlet.mvc.method.annotation to DEBUG. In my case I was seeing 400 responses in my client code but no logging on the server side (even with a custom error handler). After changing that log level the problem was obvious:

DEBUG 172.19.0.16     cs              2018-Jun-08 20:55:08.415 [https-jsse-nio-443-exec-9] - method.annotation.RequestResponseBodyMethodProcessor[line ?] - Read [class java.lang.String] as "application/xml;charset=UTF-8" with [org.springframework.http.converter.xml.MarshallingHttpMessageConverter@2de50ee4]
DEBUG 172.19.0.16     cs              2018-Jun-08 20:55:08.418 [https-jsse-nio-443-exec-9] - method.annotation.ServletInvocableHandlerMethod[line ?] - Failed to resolve argument 0 of type 'java.lang.String'
org.springframework.beans.TypeMismatchException: Failed to convert value of type 'core.dto.RequestDTO' to required type 'java.lang.String'

In my case, the problem was in my @ControllerAdvice-annoted class, which extended ResponseEntityExceptionHandler. As I got that handler code from some random tutorial about custom exception handling, I didn't bother to check what that superclass was doing (my custom exception handling worked just fine).

The problem is ResponseEntityExceptionHandler.handleException() handles MethodArgumentNotValidException along with other Spring MVC exceptions, delegating handling logic to specific handle- methods. As I did not provide an implementation for any of such methods (in this case handleMethodArgumentNotValid()) to return my own response body, I ended up with the default implementation that returns a response with null body :).

Solution

Override the methods you need or don't extend that class at all.

Check ResponseEntityExceptionHandler docs for the list of hanler- methods implemented.