Spring-Boot: Missing logs on HTTP 500

[mindhaq]

When a controller throws an Exception, not all is logged as expected.

Description

When a spring boot controller throws an Exception, resulting in a HTTP 500 which returns (in case of a RestController) details about the error, Logbook logging is not what I would expect.

I'm talking about cases where DispatcherServlet is logging the error like this:

Servlet.service() for servlet [dispatcherServlet] in context with path [] threw exception [Request processing failed

Expected Behavior

Basic configuration: log request and response

With status strategy as below: log request and response

logbook:
  strategy: status-at-least

Actual Behavior

Basic configuration: only request gets logged

With status strategy as above: neither request nor response are logged

Steps to Reproduce

1. Spring-boot app with controller throwing an Exception
2. use default configuration for logbook, except for the case with the strategy, then change as above
3. curl the URL

Context

I want to log internal server errors including the request and response data.

Your Environment

• Version used: 2.0.0-RC.0
• Spring-Boot 2.0.8

[whiskeysierra]

Are you using ERROR dispatch? How do you produce the response in case of exceptions? Are you using @ExceptionHandler?

[mindhaq]

I created a minimal application showing the behaviour

https://github.com/mindhaq/logbook-logging-demo

No @ExceptionHandler, no special dispatch, just a RuntimeException in a @RestController.

[whiskeysierra]

If you don't handle the exception at all then it will become an error dispatch, i.e. filters are executed a second time with the DispatcherType.ERROR trying to delegate to an error page. By default you don't get any from Spring, iirc.

Error dispatch is a tricky beast to get right, especially with Logbook. See #32, #155 and #334. Past experiences can be best summarized as Don't use ERROR dispatch.

Instead I'd suggest to use custom @ExceptionHandlers or something like https://github.com/zalando/problem-spring-web.

[mindhaq]

Ok, so having an @ExceptionHandler returning HTTP 500 and maybe some error JSON (similar to problem or custom) would help with logging?

Maybe that should be part of the documentation for the spring-boot integration, it's not so obvious otherwise.

[whiskeysierra]

Ok, so having an @ExceptionHandler returning HTTP 500 and maybe some error JSON (similar to problem or custom) would help with logging?

Yes. But technically it's not so much about how you produce error responses but rather that the ERROR dispatch is not supported.

Maybe that should be part of the documentation for the spring-boot integration, it's not so obvious otherwise.

Yes, it should.

[mindhaq]

Ok, got it. Adding an @ExceptionHandler prevents the ERROR dispatch, and now logging happens as expected. See the following commit to my demo project:

mindhaq/logbook-logging-demo@dd14e81