Enhance DefaultResponseErrorHandler to allow logging complete error response body #27552
Description
Affects: 5.2.14.RELEASE
This enhancement request is related to following Stack Overflow question.
https://stackoverflow.com/questions/69475757/how-to-print-complete-error-message-when-logging-an-exception/69527775
Problem Statement:
When using RestTemplate to call any REST API and it returns any 4xx or 5xx HTTP error code along with message body, complete message body is not getting logged if we simply catch and log the Exception object.
Here is a minimum reproducible example:
import lombok.extern.slf4j.Slf4j; import org.junit.jupiter.api.Test; import org.springframework.web.client.HttpClientErrorException; import org.springframework.web.client.RestTemplate; @Slf4j public class RestTemplateTest { @Test void shouldPrintErrorForRestTemplate() { RestTemplate restTemplate = new RestTemplate(); try { restTemplate.getForEntity("http://hellosmilep.free.beeceptor.com/error/notfound", String.class); } catch (Exception e) { log.error("Error calling REST API", e); } } }Output:
10:28:11.347 [main] ERROR com.smilep.java.webapp.RestTemplateTest - Error calling REST API org.springframework.web.client.HttpClientErrorException$NotFound: 404 Not Found: [{ "glossary": { "title": "example glossary", "GlossDiv": { "title": "S", "GlossList": { "GlossEntry": { "ID": "SGML", "SortAs": "SGML", "Glo... (593 bytes)] at org.springframework.web.client.HttpClientErrorException.create(HttpClientErrorException.java:113) at org.springframework.web.client.DefaultResponseErrorHandler.handleError(DefaultResponseErrorHandler.java:184) at org.springframework.web.client.DefaultResponseErrorHandler.handleError(DefaultResponseErrorHandler.java:125) at org.springframework.web.client.ResponseErrorHandler.handleError(ResponseErrorHandler.java:63) at org.springframework.web.client.RestTemplate.handleResponse(RestTemplate.java:780) at org.springframework.web.client.RestTemplate.doExecute(RestTemplate.java:738) at org.springframework.web.client.RestTemplate.execute(RestTemplate.java:672) at org.springframework.web.client.RestTemplate.getForEntity(RestTemplate.java:340) at com.smilep.java.webapp.RestTemplateTest.shouldPrintErrorForRestTemplate(RestTemplateTest.java:15) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:498) at org.junit.platform.commons.util.ReflectionUtils.invokeMethod(ReflectionUtils.java:686) at org.junit.jupiter.engine.execution.MethodInvocation.proceed(MethodInvocation.java:60) at org.junit.jupiter.engine.execution.InvocationInterceptorChain$ValidatingInvocation.proceed(InvocationInterceptorChain.java:131) at org.junit.jupiter.engine.extension.TimeoutExtension.intercept(TimeoutExtension.java:149) at org.junit.jupiter.engine.extension.TimeoutExtension.interceptTestableMethod(TimeoutExtension.java:140) at org.junit.jupiter.engine.extension.TimeoutExtension.interceptTestMethod(TimeoutExtension.java:84) at org.junit.jupiter.engine.execution.ExecutableInvoker$ReflectiveInterceptorCall.lambda$ofVoidMethod$0(ExecutableInvoker.java:115) at org.junit.jupiter.engine.execution.ExecutableInvoker.lambda$invoke$0(ExecutableInvoker.java:105) at org.junit.jupiter.engine.execution.InvocationInterceptorChain$InterceptedInvocation.proceed(InvocationInterceptorChain.java:106) at org.junit.jupiter.engine.execution.InvocationInterceptorChain.proceed(InvocationInterceptorChain.java:64) at org.junit.jupiter.engine.execution.InvocationInterceptorChain.chainAndInvoke(InvocationInterceptorChain.java:45) at org.junit.jupiter.engine.execution.InvocationInterceptorChain.invoke(InvocationInterceptorChain.java:37) at org.junit.jupiter.engine.execution.ExecutableInvoker.invoke(ExecutableInvoker.java:104) at org.junit.jupiter.engine.execution.ExecutableInvoker.invoke(ExecutableInvoker.java:98) at org.junit.jupiter.engine.descriptor.TestMethodTestDescriptor.lambda$invokeTestMethod$6(TestMethodTestDescriptor.java:212) at org.junit.platform.engine.support.hierarchical.ThrowableCollector.execute(ThrowableCollector.java:73) at org.junit.jupiter.engine.descriptor.TestMethodTestDescriptor.invokeTestMethod(TestMethodTestDescriptor.java:208) at org.junit.jupiter.engine.descriptor.TestMethodTestDescriptor.execute(TestMethodTestDescriptor.java:137) at org.junit.jupiter.engine.descriptor.TestMethodTestDescriptor.execute(TestMethodTestDescriptor.java:71) at org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$5(NodeTestTask.java:135) at org.junit.platform.engine.support.hierarchical.ThrowableCollector.execute(ThrowableCollector.java:73) at org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$7(NodeTestTask.java:125) at org.junit.platform.engine.support.hierarchical.Node.around(Node.java:135) at org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$8(NodeTestTask.java:123) at org.junit.platform.engine.support.hierarchical.ThrowableCollector.execute(ThrowableCollector.java:73) at org.junit.platform.engine.support.hierarchical.NodeTestTask.executeRecursively(NodeTestTask.java:122) at org.junit.platform.engine.support.hierarchical.NodeTestTask.execute(NodeTestTask.java:80) at java.util.ArrayList.forEach(ArrayList.java:1257) at org.junit.platform.engine.support.hierarchical.SameThreadHierarchicalTestExecutorService.invokeAll(SameThreadHierarchicalTestExecutorService.java:38) at org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$5(NodeTestTask.java:139) at org.junit.platform.engine.support.hierarchical.ThrowableCollector.execute(ThrowableCollector.java:73) at org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$7(NodeTestTask.java:125) at org.junit.platform.engine.support.hierarchical.Node.around(Node.java:135) at org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$8(NodeTestTask.java:123) at org.junit.platform.engine.support.hierarchical.ThrowableCollector.execute(ThrowableCollector.java:73) at org.junit.platform.engine.support.hierarchical.NodeTestTask.executeRecursively(NodeTestTask.java:122) at org.junit.platform.engine.support.hierarchical.NodeTestTask.execute(NodeTestTask.java:80) at java.util.ArrayList.forEach(ArrayList.java:1257) at org.junit.platform.engine.support.hierarchical.SameThreadHierarchicalTestExecutorService.invokeAll(SameThreadHierarchicalTestExecutorService.java:38) at org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$5(NodeTestTask.java:139) at org.junit.platform.engine.support.hierarchical.ThrowableCollector.execute(ThrowableCollector.java:73) at org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$7(NodeTestTask.java:125) at org.junit.platform.engine.support.hierarchical.Node.around(Node.java:135) at org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$8(NodeTestTask.java:123) at org.junit.platform.engine.support.hierarchical.ThrowableCollector.execute(ThrowableCollector.java:73) at org.junit.platform.engine.support.hierarchical.NodeTestTask.executeRecursively(NodeTestTask.java:122) at org.junit.platform.engine.support.hierarchical.NodeTestTask.execute(NodeTestTask.java:80) at org.junit.platform.engine.support.hierarchical.SameThreadHierarchicalTestExecutorService.submit(SameThreadHierarchicalTestExecutorService.java:32) at org.junit.platform.engine.support.hierarchical.HierarchicalTestExecutor.execute(HierarchicalTestExecutor.java:57) at org.junit.platform.engine.support.hierarchical.HierarchicalTestEngine.execute(HierarchicalTestEngine.java:51) at org.junit.platform.launcher.core.DefaultLauncher.execute(DefaultLauncher.java:248) at org.junit.platform.launcher.core.DefaultLauncher.lambda$execute$5(DefaultLauncher.java:211) at org.junit.platform.launcher.core.DefaultLauncher.withInterceptedStreams(DefaultLauncher.java:226) at org.junit.platform.launcher.core.DefaultLauncher.execute(DefaultLauncher.java:199) at org.junit.platform.launcher.core.DefaultLauncher.execute(DefaultLauncher.java:132) at com.intellij.junit5.JUnit5IdeaTestRunner.startRunnerWithArgs(JUnit5IdeaTestRunner.java:71) at com.intellij.rt.junit.IdeaTestRunner$Repeater.startRunnerWithArgs(IdeaTestRunner.java:33) at com.intellij.rt.junit.JUnitStarter.prepareStreamsAndStart(JUnitStarter.java:235) at com.intellij.rt.junit.JUnitStarter.main(JUnitStarter.java:54) You can notice response message is truncated with "Glo... (593 bytes)] in above stack trace.
Benefits of the enhancement:
Though, we can catch HttpClientErrorException and use getResponseBodyAsString() to read response body but I think we should be able to configure the size of error message to be logged before truncation kicks in when logging Exception object.
- This would be helpful in those cases where we are not interested in catching specific exceptions when using
RestTemplate. - It will also reduce the boilerplate code to read the complete error response body from exception and log it.
Root Cause of this issue:
Currently, DefaultResponseErrorHandler class has hardcoded size of 200 after which it truncates the error response body.
Rather than the consumers writing custom response error handlers, it would be much better if this hardcoded maxChars size can be made configurable.