Is:
https://github.com/spring-projects/spring-boot/blob/9b0cdac97aded723ef003cd9c503a9792e586848/spring-boot-project/spring-boot-actuator/src/main/java/org/springframework/boot/actuate/endpoint/web/servlet/AbstractWebMvcEndpointHandlerMapping.java#L292-L294
Should be:
catch (InvalidEndpointRequestException ex) {
throw new BadOperationRequestException(ex.getReason(), ex);
}
I tried to invoke the loggers endpoint with an unsupported value. The call failed as expected, but the stacktrace in the server logs did not contain the actual cause of the exception. IMO there is no reason to swallow the cause there/in most places. If the exception is intentionally swallowed there, then there should be a comment, why it is swallowed.
I used spring-boot 2.3.9, but it is still present in the code.
Comment From: wilkinsona
The exception isn't logged at all by default. That's generally a good thing as it helps a malicious client from performing a denial of service by repeatedly sending malformed requests that would then flood the logs with exception stack traces. Even with org.springframework configured with debug logging, the exception stack trace isn't logged:
2021-03-19 15:12:15.886 DEBUG 75024 --- [nio-8080-exec-1] o.s.web.servlet.DispatcherServlet : POST "/actuator/loggers/com.example", parameters={}
2021-03-19 15:12:15.893 DEBUG 75024 --- [nio-8080-exec-1] s.b.a.e.w.s.WebMvcEndpointHandlerMapping : Mapped to Actuator web endpoint 'loggers-name'
2021-03-19 15:12:15.931 DEBUG 75024 --- [nio-8080-exec-1] m.m.a.RequestResponseBodyMethodProcessor : Read "application/json;charset=UTF-8" to [{configuredLevel=orange}]
2021-03-19 15:12:18.823 DEBUG 75024 --- [nio-8080-exec-1] .w.s.m.a.ResponseStatusExceptionResolver : Resolved [org.springframework.boot.actuate.endpoint.web.servlet.AbstractWebMvcEndpointHandlerMapping$BadOperationRequestException: Parameter mapping failure]
2021-03-19 15:12:18.824 DEBUG 75024 --- [nio-8080-exec-1] o.s.web.servlet.DispatcherServlet : Completed 400 BAD_REQUEST
2021-03-19 15:12:18.843 DEBUG 75024 --- [nio-8080-exec-1] o.s.web.servlet.DispatcherServlet : "ERROR" dispatch for POST "/error", parameters={}
2021-03-19 15:12:18.846 DEBUG 75024 --- [nio-8080-exec-1] s.w.s.m.m.a.RequestMappingHandlerMapping : Mapped to org.springframework.boot.autoconfigure.web.servlet.error.BasicErrorController#error(HttpServletRequest)
2021-03-19 15:12:18.859 DEBUG 75024 --- [nio-8080-exec-1] o.s.w.s.m.m.a.HttpEntityMethodProcessor : Using 'application/json', given [application/json, */*;q=0.5] and supported [application/json, application/*+json, application/json, application/*+json]
2021-03-19 15:12:18.859 DEBUG 75024 --- [nio-8080-exec-1] o.s.w.s.m.m.a.HttpEntityMethodProcessor : Writing [{timestamp=Fri Mar 19 15:12:18 GMT 2021, status=400, error=Bad Request, message=, path=/actuator/log (truncated)...]
2021-03-19 15:12:18.918 DEBUG 75024 --- [nio-8080-exec-1] o.s.web.servlet.DispatcherServlet : Exiting from "ERROR" dispatch, status 400
To make sure that we understand the behaviour that you have described, what logging have you enabled so that the BadOperationRequestException's stack trace is logged?
Comment From: ST-DDT
To make sure that we understand the behaviour that you have described, what logging have you enabled so that the BadOperationRequestException's stack trace is logged?
That logging code is included in my own custom error handling.
The exception isn't logged at all by default.
That's true, but I had to implement a custom error handling that follows a specific style for my project.
That error handling has a config option to enable (debug) logging of the 4xx exception stacktraces to allow other developers gaining a few hints why their call has been rejected with a HTTP-400.
The thought behind this feature is, that sometimes there are strange exceptions only happen in production and you cannot attach a debugger there, but you get at least a stacktrace that should help you to reproduce it locally.
I encountered such a HTTP-400 from the loggers endpoint and tried using that option to know what I did wrong.
Here the result of a dummy call without any customization:
$ curl localhost:8080/actuator/loggers/de -d '{"configuredLevel":"ALL"}' -H "Content-Type: application/json"
{"timestamp":"2021-03-19T15:39:02.802+00:00","status":400,"error":"Bad Request","message":"","path":"/actuator/loggers/de"}
As you can see, the result doesn't contain any useful information about the error.
The "debug" logs at least mention something about a Parameter mapping failure, which still is pretty vague.
Unfortunately, I don't get any more information about the cause of the error even if I turn on full debug/trace logging.
TRACE org.springframework.boot.web.servlet.filter.OrderedRequestContextFilter - Bound request context to thread: org.apache.catalina.connector.RequestFacade@58bf31d5
TRACE org.springframework.web.servlet.DispatcherServlet - POST "/actuator/loggers/de", parameters={}, headers={masked} in DispatcherServlet 'dispatcherServlet'
TRACE org.springframework.boot.actuate.endpoint.web.servlet.WebMvcEndpointHandlerMapping - Mapped to Actuator web endpoint 'loggers-name'
TRACE org.springframework.web.servlet.mvc.method.annotation.RequestResponseBodyMethodProcessor - Read "application/json;charset=UTF-8" to [{configuredLevel=ALL}]
TRACE org.springframework.web.servlet.mvc.method.annotation.ServletInvocableHandlerMethod - Arguments: [org.apache.catalina.connector.RequestFacade@58bf31d5, {configuredLevel=ALL}]
DEBUG org.springframework.web.servlet.mvc.annotation.ResponseStatusExceptionResolver - Resolved [org.springframework.boot.actuate.endpoint.web.servlet.AbstractWebMvcEndpointHandlerMapping$BadOperationRequestException: Parameter mapping failure]
TRACE org.springframework.web.servlet.DispatcherServlet - No view rendering, null ModelAndView returned.
DEBUG org.springframework.web.servlet.DispatcherServlet - Completed 400 BAD_REQUEST, headers={}
TRACE org.springframework.boot.web.servlet.filter.OrderedRequestContextFilter - Cleared thread-bound request context: org.apache.catalina.connector.RequestFacade@58bf31d5
TRACE org.springframework.boot.web.servlet.filter.OrderedRequestContextFilter - Bound request context to thread: org.apache.catalina.core.ApplicationHttpRequest@4b056f53
TRACE org.springframework.web.servlet.DispatcherServlet - "ERROR" dispatch for POST "/error", parameters={}, headers={masked} in DispatcherServlet 'dispatcherServlet'
TRACE org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerMapping - 2 matching mappings: [{ /error}, { /error, produces [text/html]}]
TRACE org.springframework.beans.factory.support.DefaultListableBeanFactory - Returning cached instance of singleton bean 'basicErrorController'
TRACE org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerMapping - Mapped to org.springframework.boot.autoconfigure.web.servlet.error.BasicErrorController#error(HttpServletRequest)
TRACE org.springframework.web.servlet.mvc.method.annotation.ServletInvocableHandlerMethod - Arguments: [org.apache.catalina.core.ApplicationHttpRequest@4b056f53]
DEBUG org.springframework.web.servlet.mvc.method.annotation.HttpEntityMethodProcessor - Using 'application/json', given [*/*] and supported [application/json, application/*+json, application/json, application/*+json]
TRACE org.springframework.web.servlet.mvc.method.annotation.HttpEntityMethodProcessor - Writing [{timestamp=Fri Mar 19 16:48:36 CET 2021, status=400, error=Bad Request, message=, path=/actuator/loggers/de}]
TRACE org.springframework.web.servlet.DispatcherServlet - No view rendering, null ModelAndView returned.
DEBUG org.springframework.web.servlet.DispatcherServlet - Exiting from "ERROR" dispatch, status 400, headers={masked}
TRACE org.springframework.boot.web.servlet.filter.OrderedRequestContextFilter - Cleared thread-bound request context: org.apache.catalina.core.ApplicationHttpRequest@4b056f53
It is totally fine, that the stacktrace does not get logged anywhere by default, but please attach the cause to the BadOperationRequestException so that I can write custom exception handling, that is capable of logging the full exception on demand.
Comment From: ST-DDT
See also: Exception handlers should preserve the original exceptions
Comment From: ST-DDT
Thanks