Spring RestTemplate Request/Response Logging

1. Overview

In this tutorial, we’re going to learn how to implement efficient RestTemplate request/response logging. This is especially useful to debug exchange between two servers.

Unfortunately, Spring Boot doesn’t provide an easy way to inspect or log a simple JSON response body.

We’re going to explore several methods to log either HTTP headers or, which is the most interesting part, the HTTP body.

Note: the Spring RestTemplate will be deprecated, to be replaced by the WebClient. You can find a similar article using WebClient here: Logging Spring WebClient Calls.

2. Basic Logging With RestTemplate

Let’s start configuring the RestTemplate logger in the application.properties file:

logging.level.org.springframework.web.client.RestTemplate=DEBUG

As a result, we can see only basic information like the request URL, method, body, and response status:

o.s.w.c.RestTemplate - HTTP POST http://localhost:8082/spring-rest/persons
o.s.w.c.RestTemplate - Accept=[text/plain, application/json, application/*+json, */*]
o.s.w.c.RestTemplate - Writing [my request body] with org.springframework.http.converter.StringHttpMessageConverter
o.s.w.c.RestTemplate - Response 200 OK

However, the response body isn’t logged here, which is unfortunate because it’s the most interesting part.

To solve this, we’ll choose either Apache HttpClient or a Spring interceptor.

3. Logging Headers/Body With Apache HttpClient

First, we have to make RestTemplate use the Apache HttpClient implementation.

We’ll need the Maven dependency:

<dependency>
    <groupId>org.apache.httpcomponents.core5</groupId>
    <artifactId>httpcore5</artifactId>
    <version>5.2.1</version>
</dependency>

When creating the RestTemplate instance, we should tell it we’re using Apache HttpClient:

RestTemplate restTemplate = new RestTemplate();
restTemplate.setRequestFactory(new HttpComponentsClientHttpRequestFactory());

Then, let’s configure the client logger in the application.properties file:

logging.level.org.apache.http=DEBUG
logging.level.httpclient.wire=DEBUG

Now we can see both request/response headers and body:

    o.a.http.headers - http-outgoing-0 >> POST /spring-rest/persons HTTP/1.1
    o.a.http.headers - http-outgoing-0 >> Accept: text/plain, application/json, application/*+json, */*
// ... more request headers
    o.a.http.headers - http-outgoing-0 >> User-Agent: Apache-HttpClient/4.5.9 (Java/1.8.0_171)
    o.a.http.headers - http-outgoing-0 >> Accept-Encoding: gzip,deflate
org.apache.http.wire - http-outgoing-0 >> "POST /spring-rest/persons HTTP/1.1[\r][\n]"
org.apache.http.wire - http-outgoing-0 >> "Accept: text/plain, application/json, application/*+json, */*[\r][\n]"
org.apache.http.wire - http-outgoing-0 >> "Content-Type: text/plain;charset=ISO-8859-1[\r][\n]"
// ... more request headers
org.apache.http.wire - http-outgoing-0 >> "[\r][\n]"
org.apache.http.wire - http-outgoing-0 >> "my request body"
org.apache.http.wire - http-outgoing-0 << "HTTP/1.1 200 [\r][\n]"
org.apache.http.wire - http-outgoing-0 << "Content-Type: application/json[\r][\n]"
// ... more response headers
org.apache.http.wire - http-outgoing-0 << "Connection: keep-alive[\r][\n]"
org.apache.http.wire - http-outgoing-0 << "[\r][\n]"
org.apache.http.wire - http-outgoing-0 << "21[\r][\n]"
org.apache.http.wire - http-outgoing-0 << "["Lucie","Jackie","Danesh","Tao"][\r][\n]"

However, these logs are verbose and not handy to debug.

We’ll see how to solve this in the following chapter.

4. Logging Body With a RestTemplate Interceptor

As another solution, we can configure interceptors for RestTemplate.

4.1. Logging Interceptor Implementation

First, let’s create a new LoggingInterceptor to customize our logs. This interceptor logs the request body as a simple byte array. However, for the response, we have to read the entire body stream:

public class LoggingInterceptor implements ClientHttpRequestInterceptor {

    static Logger LOGGER = LoggerFactory.getLogger(LoggingInterceptor.class);

    @Override
    public ClientHttpResponse intercept(
      HttpRequest req, byte[] reqBody, ClientHttpRequestExecution ex) throws IOException {
        LOGGER.debug("Request body: {}", new String(reqBody, StandardCharsets.UTF_8));
        ClientHttpResponse response = ex.execute(req, reqBody);
        InputStreamReader isr = new InputStreamReader(
          response.getBody(), StandardCharsets.UTF_8);
        String body = new BufferedReader(isr).lines()
            .collect(Collectors.joining("\n"));
        LOGGER.debug("Response body: {}", body);
        return response;
    }
}

Beware, this interceptor has an impact on the response content itself, as we’ll discover in the next chapter.

4.2. Using Interceptor With RestTemplate

Now, we must deal with a streaming problem: As the interceptor consumes the response stream, our client application will see an empty response body.

To avoid that, we should use BufferingClientHttpRequestFactory: it buffers stream content into memory. This way, it can be read twice: once by our interceptor, and a second time by our client application:

ClientHttpRequestFactory factory = 
        new BufferingClientHttpRequestFactory(new SimpleClientHttpRequestFactory());
        RestTemplate restTemplate = new RestTemplate(factory);

However, the use of this factory involves a performance drawback, which we’ll describe in the next subsection.

Then we can add our logging interceptor to the RestTemplate instance — we’ll append it after the existing interceptors, if any:

List<ClientHttpRequestInterceptor> interceptors = restTemplate.getInterceptors();
if (CollectionUtils.isEmpty(interceptors)) {
    interceptors = new ArrayList<>();
}
interceptors.add(new LoggingInterceptor());
restTemplate.setInterceptors(interceptors);

As a result, only the necessary information is present in the logs:

c.b.r.l.LoggingInterceptor - Request body: my request body
c.b.r.l.LoggingInterceptor - Response body: ["Lucie","Jackie","Danesh","Tao"]

4.3. RestTemplate Interceptor Drawback

A mentioned before, the use of BufferingClientHttpRequestFactory has a serious drawback: it undoes the benefits of streaming. As a consequence, loading the entire body data into memory could expose our application to performance issues. Worse, it can lead to OutOfMemoryError.

To prevent this, one possible option is to assume that these verbose logs would be turned off when the data volume scales up, which typically happens in production. For example, we can use a buffered RestTemplate instance only if DEBUG level is enabled on our logger:

RestTemplate restTemplate = null;
if (LOGGER.isDebugEnabled()) {
    ClientHttpRequestFactory factory 
    = new BufferingClientHttpRequestFactory(new SimpleClientHttpRequestFactory());
    restTemplate = new RestTemplate(factory);
} else {
    restTemplate = new RestTemplate();
}

Similarly, we’ll ensure that our interceptor only reads the response when DEBUG logging is enabled:

if (LOGGER.isDebugEnabled()) {
    InputStreamReader isr = new InputStreamReader(response.getBody(), StandardCharsets.UTF_8);
    String body = new BufferedReader(isr)
        .lines()
        .collect(Collectors.joining("\n"));
    LOGGER.debug("Response body: {}", body);
}

5. Conclusion

RestTemplate request/response logging is not a straightforward matter, as Spring Boot doesn’t include it out-of-the-box.

Fortunately, we’ve seen that we can use the Apache HttpClient logger to get a verbose trace of exchanged data.

Or, we can implement a custom interceptor to get more human-readable logs. However, this can induce performance drawbacks for large data volumes.