A Better Way

Welcome!

Everything below this point is a bit outdated, and I highly recommend checking out this post: https://stevenpg.com/posts/request-body-with-spring-webclient/

In this page, I briefly go over a MUCH better option for logging Spring Webclient in 2024 and beyond, something I've been using for 2+ years.

All of my production applications that were originally logged with the method below have been migrated over.

Either way, the methods listed here still work if you prefer them!

Good luck with your logging journey!

About Spring WebClient

Spring is going Reactive. You only need to take one look at the talks featured at the Spring One 2020 conference to see that Reactive Web and functional programming paradigms in Java and Spring were at the forefront.

One of the interesting issues with doing things in a non-blocking manner is that simple things like logging can sometimes become a little bit more complicated. Because you don't know exactly WHEN the data will be available, you can't really just toss it into a log the same way you'd do it with something like Spring's RestTemplate. (Speaking of RestTemplate, it looks like it's targeted for deprecation! https://docs.spring.io/spring-framework/docs/current/javadoc-api/index.html?org/springframework/web/client/RestTemplate.html)

As per the documentation, we ought to be using org.springframework.web.reactive.client.WebClient for our outbound API calls nowadays, especially because it provides the ability for us to utilize blocking and non-blocking methods.

Now anyone who has used Spring WebClient can attest to the fact that retrieving the request content or response content can sometimes be a little bit difficult, especially if you're looking for a specific format.

There's dozens of unanswered Stack Overflow posts that have the same response, check out Baeldung's article on the subject: https://www.baeldung.com/spring-log-webclient-calls.

Now Baeldung has saved my butt more times than I can count, in side projects AND professionally. However, the article doesn't show much more than basic implementation examples. What's missing is the example output, and sharing the caveats that aren't mentioned in the article.

So without further ado, here's a walk-through of the best method (in my opinion) to do request and response logging (with the HTTP body) in Spring Webclient, with examples, comments and output.

Netty logging is included in Baeldung's post but isn't nearly as granular as the Jetty HTTP client. The very first step is adding the required dependency that will give us access to the underlying HTTP client.

The Code

# Gradle    
implementation group: 'org.eclipse.jetty', name: 'jetty-reactive-httpclient', version: '1.1.4'

# Maven
<dependency>
    <groupId>org.eclipse.jetty</groupId>
    <artifactId>jetty-reactive-httpclient</artifactId>
    <version>1.1.4</version>
</dependency>

Once we have access to the classes we need, there's two components that need to be built.

The first is our enhance method. This method takes a Request and gives a request back, allowing us to intercept and log all of the pieces we care about.

Here's an example enhance method and it's output:

// org.eclipse.jetty.client.api.Request
private Request enhance(Request inboundRequest) {
    StringBuilder log = new StringBuilder();
    // Request Logging
    inboundRequest.onRequestBegin(request ->
            log.append("Request: \n")
            .append("URI: ")
            .append(request.getURI())
            .append("\n")
            .append("Method: ")
            .append(request.getMethod()));
    inboundRequest.onRequestHeaders(request -> {
        log.append("\nHeaders:\n");
        for (HttpField header : request.getHeaders()) {
            log.append("\t\t" + header.getName() + " : " + header.getValue() + "\n");
        }
    });
    inboundRequest.onRequestContent((request, content) ->
            log.append("Body: \n\t")
            .append(content.toString()));
    log.append("\n");

    // Response Logging
    inboundRequest.onResponseBegin(response ->
            log.append("Response:\n")
            .append("Status: ")
            .append(response.getStatus())
            .append("\n"));
    inboundRequest.onResponseHeaders(response -> {
       log.append("Headers:\n");
       for (HttpField header : response.getHeaders()) {
           log.append("\t\t" + header.getName() + " : " + header.getValue() + "\n");
       }
    });
    inboundRequest.onResponseContent(((response, content) -> {
        var bufferAsString = StandardCharsets.UTF_8.decode(content).toString();
        log.append("Response Body:\n" + bufferAsString);
    }));

    // Add actual log invocation
    logger.info("HTTP ->\n");
    inboundRequest.onRequestSuccess(request -> logger.info(log.toString()));
    inboundRequest.onResponseSuccess(response -> logger.info(log.toString()));

    // Return original request
    return inboundRequest;
}

The request object provides plenty of hooks to reach in and grab the data you are looking to log. Interface docs are here -> https://www.eclipse.org/jetty/javadoc/9.4.8.v20171121/org/eclipse/jetty/client/api/Request.html

To get our enhance method executed during the invocation of our WebClient, we're going to create our own HttpClient and use it in place of the default JettyClientHttpConnector. Here's an example bean that provides the WebClient:

@Bean
public WebClient jettyHttpClient() {
    SslContextFactory.Client sslContextFactory = new SslContextFactory.Client();
    HttpClient httpClient = new HttpClient(sslContextFactory) {
        @Override
        public Request newRequest(URI uri) {
            Request request = super.newRequest(uri);
            return enhance(request);
        }
    };
    return WebClient.builder().clientConnector(new JettyClientHttpConnector(httpClient)).build();
}

The Output

Now using the WebClient that we've seeded with our underlying HttpClient, we get the following output:

2020-10-08 15:00:00.000  INFO 2100 --- [   @cafebabe-37] 
c.s.l.examples.JettyWebClient            : 
Request: 
URI: http://httpbin.org/get
Method: GET
Headers:
        Accept-Encoding : gzip
        User-Agent : Jetty/9.4.31.v20200723
        Accept : */*
        Host : httpbin.org
Response:
Status: 200
Headers:
        Date : Thu, 08 Oct 2020 20:24:17 GMT
        Content-Type : application/json
        Content-Length : 297
        Connection : keep-alive
        Server : gunicorn/19.9.0
        Access-Control-Allow-Origin : *
        Access-Control-Allow-Credentials : true
Response Body:
{
  "args": {}, 
  "headers": {
    "Accept": "*/*", 
    "Accept-Encoding": "gzip", 
    "Host": "httpbin.org", 
    "User-Agent": "Jetty/9.4.31.v20200723", 
    "X-Amzn-Trace-Id": "Root=1-5f7f7571-    157328ac70a3bd900bc1c8bc"
  }, 
  "origin": "12.345.678.91", 
  "url": "http://httpbin.org/get"
}

One of the benefits of using this approach over the Netty approach is that no log changes need to be made for this to show up. It also allows you to save off data from each request if needed.

My goal with this post was to demystify the implementation that gives us the most granular control over the request and response data.

The code above is available in a full working application located in the following repository: https://github.com/StevenPG/logging-with-webclient