Spring Top

I just announced the new Learn Spring course, focused on the fundamentals of Spring 5 and Spring Boot 2:

>> CHECK OUT THE COURSE
REST Top

I just announced the new Learn Spring course, focused on the fundamentals of Spring 5 and Spring Boot 2:

>> CHECK OUT THE COURSE

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</groupId>
    <artifactId>httpclient</artifactId>
    <version>4.5.12</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.

As always, the source code for this article is available over on GitHub in the test folder. The example uses the RestTemplate in a live test for the REST endpoint defined in the same project.

Spring bottom

I just announced the new Learn Spring course, focused on the fundamentals of Spring 5 and Spring Boot 2:

>> CHECK OUT THE COURSE
REST bottom

I just announced the new Learn Spring course, focused on the fundamentals of Spring 5 and Spring Boot 2:

>> CHECK OUT THE COURSE
6 Comments
Oldest
Newest
Inline Feedbacks
View all comments
Libor
Libor
4 months ago

Hello, there is a slight issue with the a custom response logging interceptor. The interceptor consumes the response inputstream, so there is nothing more to consume for actual response converter and therefore response.getBody() returns null, when the interceptor is used. One solution is to use BufferingClientHttpRequestFactory to save the inputstream in a byte array so it can be consumed multiple times. Unfortunately, by doing this, you loose streaming feature so you have to be careful about OOM error for large responses (like downloading large files). I solved this by subclassing BufferingClientHttpRequestFactory and turned off buffering selectively when I expected a… Read more »

Loredana Crusoveanu
4 months ago
Reply to  Libor

Hi Libor,
Thanks for the feedback.
Practically speaking, we’ll log the body of an API response only in development for debugging purposes, not in production. In other words, there would not be a lot of scenarios where you’ll consume the response again after logging it.
Having said that, this is a good point, and we’ll update the article to warn of it and add an alternative as you suggested.
Cheers.

SunilManaja
SunilManaja
4 months ago

Thank you.
Can you please share details how can we do the same for WebClient

Loredana Crusoveanu
4 months ago
Reply to  SunilManaja

Hi Sunil,

We have an article on the WebClient here: https://www.baeldung.com/spring-log-webclient-calls I’ll add a link to it in this article as well.

Cheers.

Chris Witte
Chris Witte
4 months ago

When using this LoggingInterceptor with RestTemplate, the logged response is correct. unfortunately, the interceptor consumes the inputStream, and the originating client does not get the response body.

Loredana Crusoveanu
4 months ago
Reply to  Chris Witte

Thanks for the note, Chris, we’ll update the article.

Comments are closed on this article!