ResponseEntityExceptionHandler is ignored [SPR-17521]

[spring-projects-issues]

Marrache Mickael opened SPR-17521 and commented

When upgrading Spring Boot from version 2.0.4 to 2.0.6, the Spring dependencies are upgraded from version 5.0.8 to 5.0.10.

With the new version, my @ControllerAdvice is ignored, while it is not with the previous version.

 

@ControllerAdvice
public class RestExceptionHandler extends ResponseEntityExceptionHandler {
}

Moreover, I observe new warnings in the logs:

2018-11-20 12:50:16.703 WARN 3316 --- [qtp124323713-18] .m.m.a.ExceptionHandlerExceptionResolver : Resolved [java.lang.IllegalArgumentException: Page index must not be less than zero!]

 

---

Affects: 5.0.9

Attachments:

• spring-issue-test.zip (4.98 kB)

Referenced from: commits spring-attic/spring-framework-issues@d98f55a, spring-attic/spring-framework-issues@b281f0e

[spring-projects-issues]

Marrache Mickael commented

I confirm this behavior occurs since version 5.0.9. I changed the affected version.

[spring-projects-issues]

Rossen Stoyanchev commented

I can't think of anything that would have changed the treatment of @ControllerAdvice for exception handling in 5.0.9 and I couldn't reproduce the issue either. Using this sample code with the server running I get this:

$ curl -v http://localhost:8080/test
*   Trying 127.0.0.1...
* TCP_NODELAY set
* Connected to localhost (127.0.0.1) port 8080 (#0)
> GET /test HTTP/1.1
> Host: localhost:8080
> User-Agent: curl/7.58.0
> Accept: */*
> 
< HTTP/1.1 400 Bad Request
< Date: Tue, 20 Nov 2018 19:46:57 GMT
< Content-Type: text/plain;charset=iso-8859-1
< Content-Length: 59
< Server: Jetty(9.3.3.v20150827)
< 
* Connection #0 to host localhost left intact
Handled: java.lang.IllegalArgumentException: argument error

As for the extra warning should have been addressed with #21916.

[spring-projects-issues]

Marrache Mickael commented

I checked again, the issue appears when upgrading Spring Boot from 2.0.4 to 2.0.5.

Also, I am using Jetty - not sure if that may have an impact.

May it be related to Spring Boot auto configuration then and not Spring?

[spring-projects-issues]

Rossen Stoyanchev commented

It could be an issue in Boot but at this point, please provide demo code, or instructions how to reproduce.

[spring-projects-issues]

Marrache Mickael commented

I attached a sample project reproducing the issue.

[spring-projects-issues]

Rossen Stoyanchev commented

Hm, it doesn't seem to reproduce the issue for me (I tired 2.0.6 as well).

On startup I see the method is detected:

2018-11-21 09:09:32.296  INFO 807 --- [           main] .m.m.a.ExceptionHandlerExceptionResolver : Detected @ExceptionHandler methods in restExceptionHandler

For the request, I see the exception getting resolved through it:

2018-11-21 09:10:35.381 DEBUG 807 --- [tp2059282367-20] o.s.web.servlet.DispatcherServlet        : DispatcherServlet with name 'dispatcherServlet' processing GET request for [/test]
2018-11-21 09:10:35.384 DEBUG 807 --- [tp2059282367-20] s.w.s.m.m.a.RequestMappingHandlerMapping : Looking up handler method for path /test
2018-11-21 09:10:35.386 DEBUG 807 --- [tp2059282367-20] s.w.s.m.m.a.RequestMappingHandlerMapping : Returning handler method [public void com.test.TestController.handle()]
2018-11-21 09:10:35.386 DEBUG 807 --- [tp2059282367-20] o.s.web.servlet.DispatcherServlet        : Last-Modified value for [/test] is: -1
2018-11-21 09:10:35.397 DEBUG 807 --- [tp2059282367-20] .m.m.a.ExceptionHandlerExceptionResolver : Invoking @ExceptionHandler method: protected org.springframework.http.ResponseEntity<java.lang.Object> com.test.RestExceptionHandler.handleBadRequest(java.lang.RuntimeException,org.springframework.web.context.request.WebRequest)
2018-11-21 09:10:41.526 DEBUG 807 --- [tp2059282367-20] o.s.w.s.m.m.a.HttpEntityMethodProcessor  : Written [com.test.ErrorMessage@2711bec7] as "application/json" using [org.springframework.http.converter.json.MappingJackson2HttpMessageConverter@2af4129d]
2018-11-21 09:10:41.527  WARN 807 --- [tp2059282367-20] .m.m.a.ExceptionHandlerExceptionResolver : Resolved [java.lang.IllegalArgumentException: argument error]
2018-11-21 09:10:41.527 DEBUG 807 --- [tp2059282367-20] o.s.web.servlet.DispatcherServlet        : Null ModelAndView returned to DispatcherServlet with name 'dispatcherServlet': assuming HandlerAdapter completed request handling
2018-11-21 09:10:41.527 DEBUG 807 --- [tp2059282367-20] o.s.web.servlet.DispatcherServlet        : Successfully completed request

And the response:

$ curl -v http://localhost:8080/test
*   Trying 127.0.0.1...
* TCP_NODELAY set
* Connected to localhost (127.0.0.1) port 8080 (#0)
> GET /test HTTP/1.1
> Host: localhost:8080
> User-Agent: curl/7.58.0
> Accept: */*
> 
< HTTP/1.1 400 Bad Request
< Date: Wed, 21 Nov 2018 14:10:35 GMT
< Content-Type: application/json;charset=utf-8
< Transfer-Encoding: chunked
< 
* Connection #0 to host localhost left intact
{"code":400,"message":"argument error"}

[spring-projects-issues]

Rossen Stoyanchev commented

I've added the source to the issues repository https://github.com/spring-projects/spring-framework-issues/tree/master/SPR-17521-2.

[spring-projects-issues]

Marrache Mickael commented

Yes this is the observed behavior. If you try with v2.0.4 you will see something else (what I expect).

In the logs you added, there is no entry logged by RestExceptionHandler (i.e. my custom handler). With v2.0.4, the entry exists.

[spring-projects-issues]

Rossen Stoyanchev commented

I'm sorry but your project does not demonstrate the stated issue of "@ControllerAdvice is ignored".

The RestExceptionHandler is detected on startup:

Detected @ExceptionHandler methods in restExceptionHandler

It is invoked at runtime:

Invoking @ExceptionHandler method: protected org.springframework.http.ResponseEntity<java.lang.Object> com.test.RestExceptionHandler.handleBadRequest(java.lang.RuntimeException,org.springframework.web.context.request.WebRequest)

The server returned the expected 400 response with error details.

I've also used a breakpoint to verify it is being called.

The log entry from RestExceptionHandler does appear once logging for com.test is set to DEBUG.

[spring-projects-issues]

Marrache Mickael commented

You're right... for some reason the warning caused me to think that, not sure why I didn't reach the breakpoint with my debugger.

Sorry for your time...

[spring-projects-issues]

Rossen Stoyanchev commented

Ok no problem.