CODEWITHSUNDEEP
javaspringspring-booterror-handlingresttemplate
Smile
Smile

Reputation: 4088

How to print complete error message when logging an exception generated by RestTemplate?

We have a Spring-Boot (2.3.10.RELEASE) based application which calls many REST APIs using RestTemplate.

In case, any REST API returns any 4xx or 5xx HTTP error code along with message body, complete message body is not getting logged.

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. How to log the complete error response body?

I know I can do something like below to print the error response body but it will be too much of boilerplate code to be added in many classes (and also in other applications).

if(e instanceof HttpClientErrorException) {
    log.error("response body : " + ((HttpClientErrorException) e).getResponseBodyAsString());
}

  1. Is there any way by which logging Exception object would log complete error response message body instead of truncating with ... (593 bytes)]?

  2. Is there some default size limit in java after which it truncates any message in error log? If yes, how to change it?

Update :

After jccampanero's answer, I had raised this issue with Spring team to make this logging message size limit configurable. They have removed the limit altogether. This change should be available in some future version of Spring.

Upvotes: 5

Views: 2392

Answers (2)

jccampanero
jccampanero

Reputation: 53391

By default, RestTemplate uses DefaultErrorHandler for processing errors.

In the implementation of this class, the different handleError methods - see for instance this - rely on the getErrorMessage method:

/**
  * Return error message with details from the response body, possibly truncated:
  * <pre>
  * 404 Not Found: [{'id': 123, 'message': 'my very long... (500 bytes)]
  * </pre>
  */
private String getErrorMessage(
    int rawStatusCode, String statusText, @Nullable byte[] responseBody, @Nullable Charset charset) {


  String preface = rawStatusCode + " " + statusText + ": ";
  if (ObjectUtils.isEmpty(responseBody)) {
    return preface + "[no body]";
  }


  if (charset == null) {
    charset = StandardCharsets.UTF_8;
  }
  int maxChars = 200;


  if (responseBody.length < maxChars * 2) {
    return preface + "[" + new String(responseBody, charset) + "]";
  }


  try {
    Reader reader = new InputStreamReader(new ByteArrayInputStream(responseBody), charset);
    CharBuffer buffer = CharBuffer.allocate(maxChars);
    reader.read(buffer);
    reader.close();
    buffer.flip();
    return preface + "[" + buffer.toString() + "... (" + responseBody.length + " bytes)]";
  }
  catch (IOException ex) {
    // should never happen
    throw new IllegalStateException(ex);
  }
}

As you can see, this is method the one that actually truncates the message.

In order to provide the full message, you can your own provided ResponseErrorHandler implementation.

For instance, reusing the code implement in DefaultErrorHandler:

import java.io.IOException;
import java.nio.charset.Charset;
import java.nio.charset.StandardCharsets;

import org.springframework.http.HttpHeaders;
import org.springframework.http.HttpStatus;
import org.springframework.http.client.ClientHttpResponse;
import org.springframework.lang.Nullable;
import org.springframework.util.ObjectUtils;
import org.springframework.web.client.DefaultResponseErrorHandler;
import org.springframework.web.client.HttpClientErrorException;
import org.springframework.web.client.HttpServerErrorException;
import org.springframework.web.client.UnknownHttpStatusCodeException;

public class CustomRestTemplateResponseErrorHandler extends DefaultResponseErrorHandler {
  
  // This overloaded method version is only available since Spring 5.0
  // For previous versions of the library you can override
  // handleError(ClientHttpResponse response) instead
  @Override
  protected void handleError(ClientHttpResponse response, HttpStatus statusCode) throws IOException {
    String statusText = response.getStatusText();
    HttpHeaders headers = response.getHeaders();
    byte[] body = getResponseBody(response);
    Charset charset = getCharset(response);
    String message = getErrorMessage(statusCode.value(), statusText, body, charset);

    switch (statusCode.series()) {
      case CLIENT_ERROR:
        throw HttpClientErrorException.create(message, statusCode, statusText, headers, body, charset);
      case SERVER_ERROR:
        throw HttpServerErrorException.create(message, statusCode, statusText, headers, body, charset);
      default:
        throw new UnknownHttpStatusCodeException(message, statusCode.value(), statusText, headers, body, charset);
    }
  }

  /**
   * Return error message with details from the response body:
   * <pre>
   * 404 Not Found: [{'id': 123, 'message': 'actual mesage']
   * </pre>
   *
   * In contrast to <code>DefaultResponseErrorHandler</code>, the message will not be truncated.
   */
  private String getErrorMessage(
      int rawStatusCode, String statusText, @Nullable byte[] responseBody, @Nullable Charset charset) {

    String preface = rawStatusCode + " " + statusText + ": ";
    if (ObjectUtils.isEmpty(responseBody)) {
      return preface + "[no body]";
    }

    if (charset == null) {
      charset = StandardCharsets.UTF_8;
    }

    // return the message without truncation
    return preface + "[" + new String(responseBody, charset) + "]";
  }
}

Then, configure RestTemplate to use this custom ResponseErrorHandler:

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();
        ResponseErrorHandler errorHandler = new CustomRestTemplateResponseErrorHandler();
        restTemplate.setErrorHandler(errorHandler);

        try {
            restTemplate.getForEntity("http://hellosmilep.free.beeceptor.com/error/notfound", String.class);
        } catch (Exception e) {
            log.error("Error calling REST API", e);
        }
    }
}

Please, see this related SO question or this article for further examples.

Upvotes: 6

Deepak
Deepak

Reputation: 21

In place of doing an if you can catch an HttpClientErrorException, so with that you can avoid boiler plate

@Test
void shouldPrintErrorForRestTemplate() {
    try {

        RestTemplate restTemplate = new RestTemplate();
        restTemplate.getForEntity("http://hellosmilep.free.beeceptor.com/error/notfound", String.class);

    } catch(HttpClientErrorException e) {
        log.error(e.getResponseBodyAsString(),e);
    }catch (Exception e) {
        log.error("Error calling REST API", e);
    }
}

Upvotes: 1

Related Questions