Spring WebClient Body Logging

Logging the serialized request and response

2020-07-09 (Updated: 2021-02-14)

Sometimes for various reasons it's valuable to see how a model is serialized into JSON or how a response looks before being deserialized into a Java class.

With the Spring WebClient it's not trivial to see how to do this. For the majority of use-cases this is not a difficult thing to do and I will show how to do it for request bodies as well as response bodies.

This article is targeting the following products and versions:

Spring Boot	2.4.2
Java	11
JUnit	5

The accompanying source code is available here:

/rewolf/blog-spring-webclient-payload-logger

Custom Codecs

When building the WebClient there is an option to provide the codecs that will be used for encoding and decoding (AKA serializing/deserializing) request/responses. Because these codecs are responsible for the de/serialization stage, they have access to the raw data for/from the wire.

The principle shown here will make use of this fact by providing as codecs, wrapper classes around the default encoder and decoder. To do this, the WebClient might be created as shown below:


WebClient webClient = WebClient.builder()
                               .baseUrl(configuration.getServerBasePath())
                               .codecs(codecConfigurer -> {
                                    codecConfigurer.defaultCodecs().jackson2JsonEncoder(loggingEncoder);
                                    codecConfigurer.defaultCodecs().jackson2JsonDecoder(loggingDecoder);
                               })
                               .build();

Logging the Serialized Request

By default WebClient is configured with the Jackson2JsonEncoder. The method that does most of the work, which we're interested in, is encodeValue() located in the abstract superclass AbstractJackson2Encoder.

Note: This method is called for Mono objects and for each object in a non-streaming Flux. Streaming Flux data would not be processed by this method and therefore will not work with the form of the approach shown here.

We will need to also provide a way for our encoder to send the serial data out after serialization. One way we can do this is to provide a Consumer to the class as a callback for logging. With this in mind, we could wrap the default JSON encoder in a subclass as follows:

public class LoggingJsonEncoder extends Jackson2JsonEncoder {
    private final Consumer<byte[]> payloadConsumer;

    public LoggingJsonEncoder(final Consumer<byte[]> payloadConsumer) {
        this.payloadConsumer = payloadConsumer;
    }

    @Override
    public DataBuffer encodeValue(final Object value, final DataBufferFactory bufferFactory,
                                  final ResolvableType valueType, @Nullable final MimeType mimeType, @Nullable final Map<String, Object> hints) {

        // Encode/Serialize data to JSON
        final DataBuffer data = super.encodeValue(value, bufferFactory, valueType, mimeType, hints);

        // Interception: Generate Signature and inject header into request
        bodyConsumer.accept(ByteUtils.extractBytesAndReset(data));

        // Return the data as normal
        return data;
    }
}

The class is very simple. We wrap the encodeValue() method and delegate the encoding job to the original superclass body in Line 13. From the resulting DataBuffer we can then extract the byte data and pass it along to the interested party via the Consumer that was passed in during construction. The juice for extracting the bytes is shown below, and is defined separately as it is used in the next example too.

static byte[] extractBytesAndReset(final DataBuffer data) {
    final byte[] bytes = new byte[data.readableByteCount()];
    data.read(bytes);
    data.readPosition(0);
    return bytes;
}

The important line to note is Line 4, where the read position is reset to 0. This allows the WebClient to continue on as it usually would.

Logging the Response (Pre-deserialization)

A similar approach is used for exposing the payload data of the response in serialized form. In this case we will wrap the default decoder, Jackson2JsonDecoder.

NOTE: This example only shows the solution in the case the data is decoded to a Mono (ie. usage of bodyToMono()) by overriding decodeToMono() on the decoder. Doing this for a Flux output is more involved and not covered right now.

Below you can see the custom decoder that exposes the response payload in serialized form (just before deserialization).

public class LoggingJsonDecoder extends Jackson2JsonDecoder {
    private final Consumer<byte[]> payloadConsumer;

    public LoggingJsonEncoder(final Consumer<byte[]> payloadConsumer) {
        this.payloadConsumer = payloadConsumer;
    }

    @Override
    public Mono<Object> decodeToMono(final Publisher<DataBuffer> input, final ResolvableType elementType, final MimeType mimeType, final Map<String, Object> hints) {
        // Buffer for bytes from each published DataBuffer
        final ByteArrayOutputStream payload = new ByteArrayOutputStream();

        // Augment the Flux, and intercept each group of bytes buffered
        final Flux<DataBuffer> interceptor = Flux.from(input)
                                                 .doOnNext(buffer -> bufferBytes(payload, buffer))
                                                 .doOnComplete(() -> payloadConsumer.accept(payload.toByteArray()));

        // Return the original method, giving our augmented Publisher
        return super.decodeToMono(interceptor, elementType, mimeType, hints);
    }

    private void bufferBytes(final ByteArrayOutputStream bao, final DataBuffer buffer) {
        try {
            bao.write(ByteUtils.extractBytesAndReset(buffer));
        } catch (IOException e) {
            throw new RuntimeException(e);
        }
    }
}

The decodeToMono() method receives a Publisher from which the data flows from the network stream. The payload is provided in sequential DataBuffer objects. This custom decoder extracts the bytes from each of these DataBuffer objects (in the doOnNext callback) and buffers them in an array. Finally when the Publisher is finished (in the doOnComplete callback), the full byte array is sent to the provided Consumer. extractBytesAndReset() is the same as from the previous section.

Verifying with Tests

If you care whether something works, it's best to write a test. So in order to show how to use these examples as well as verifying they work, I've done so with two JUnit 5 tests. Obviously in the real world you would possibly configure the WebClient as a Bean, and you wouldn't want to be using block() in reactive code very much, but for tests this is ok.

For these tests, to make mocking responses and capturing payloads easy, we'll use MockWebServer.

@Test
@DisplayName("Should log the same JSON as received by the server for the request")
public void postPayloadLoggedAfterEncoding() throws Exception {
    mockBackEnd.enqueue(new MockResponse().setBody("").addHeader("Content-Type", "application/json"));
    final StringBuffer loggedJsonBuffer = new StringBuffer();
    final LoggingJsonEncoder encoder = new LoggingJsonEncoder(
            data -> loggedJsonBuffer.append(new String(data)));
    final WebClient webClient = WebClient.builder()
                                   .baseUrl("http://localhost:" + mockBackEnd.getPort() + "/")
                                   .codecs(c -> c.defaultCodecs().jackson2JsonEncoder(encoder))
                                   .build();

    webClient.post()
             .uri("/aa")
             .contentType(MediaType.APPLICATION_JSON)
             .body(BodyInserters.fromValue(TEST_DATA))
             .exchangeToMono(r -> r.releaseBody())
             .block();

    final String transmittedJson = mockBackEnd.takeRequest().getBody().readString(StandardCharsets.UTF_8);
    assertEquals(transmittedJson, loggedJsonBuffer.toString());
}

The first test tests capturing of the encoded request payload. Lines 6-7 setup our custom encoder with a Consumer that interprets the byte data as a String and saves that String to a StringBuffer which is used in the assertion later. Line 16 specifies the object to be serialized as JSON. Line 21 shows the assertion that the string data received by the mock server is the same as what was logged into the StringBuffer by our custom encoder.

@Test
@DisplayName("Should log the same data as sent by the server in the response")
public void responseLoggedBeforeDecoding() throws Exception {
    final StringBuffer loggedJsonBuffer = new StringBuffer();
    final LoggingJsonDecoder decoder = new LoggingJsonDecoder(
            data -> loggedJsonBuffer.append(new String(data)));
    WebClient webClient = WebClient.builder()
                                   .baseUrl("http://localhost:" + mockBackEnd.getPort() + "/")
                                   .codecs(c -> c.defaultCodecs().jackson2JsonDecoder(decoder))
                                   .build();
    final String responseJsonStub = new ObjectMapper().writeValueAsString(TEST_DATA);
    mockBackEnd.enqueue(new MockResponse()
                                .setBody(responseJsonStub)
                                .addHeader("Content-Type", "application/json"));

    final TestModel parsedData = webClient.get()
                                          .uri("/aa")
                                          .accept(MediaType.APPLICATION_JSON)
                                          .exchangeToMono(r -> r.bodyToMono(TestModel.class))
                                          .block();

    mockBackEnd.takeRequest();
    assertEquals(TEST_DATA, parsedData);
    assertEquals(responseJsonStub, loggedJsonBuffer.toString());
}

The second test tests the capturing of the response data before deserialization. The mock server is setup to return a serialized form of our data (Line 13). Our decoder is created in Lines 5-6 to write the captured payload data as a String to a StringBuffer. The request is made to the WebClient, which receives a response from the mock server. We instruct the WebClient in Line 19 to convert the payload into a Mono of our model class. This will trigger the decodeToMono method in our decoder. Finally, in Line 24 we compare the logged data from our decoder with the data we gave to the mock server.

WARNING: Logging the payloads like this will have memory impact as you are buffering all the same data, as well as some performance impact. This is not recommended for Prod environments but can be very useful in development or test environments. Use your Spring @Profiles to configure WebClient with/without logging per-environment.

Summary

In the above we learned the following:

We can get a handle on payload data by providing our own codecs to WebClient.
This approach in the version proposed here does not work for streaming data.
This can be configured in a Spring application to only use the custom codecs in Development or Test environments (for example, using Spring Profiles)

If this was helpful, has some issues or is lacking, please feel free to comment below!

The accompanying source code is available here:

/rewolf/blog-spring-webclient-payload-logger