10

I've started using WebClient and I'm adding logging of request/response and I'm using filter method when constructing WebClient:

WebClient.builder()
    .baseUrl(properties.getEndpoint())
    .filter((request, next) -> {
        // logging
        request.body()
    })
    .build();

I'm able to access url, http method, headers but I've a problem with getting raw request body as body() method of request returns BodyInserter (BodyInserter<?, ? super ClientHttpRequest> body().

How to convert BodyInserter to String representation of request body? Alternatively, how to properly log whole request/response while also being able to hash potential credentials in it?

Andreas
  • 4,989
  • 32
  • 40
  • This to my knowledge not possible because webflux is a wrapper round a netty client and a body inserter is just a passed lambda function that is to be executed when the actual request is made. – Toerktumlare Jul 19 '19 at 18:33
  • 1
    Any sensible alternative then? There has to be a way of relatively easy request/response logging with possibility of customisation – Marcin Necsord Szulc Jul 20 '19 at 21:10
  • Why does there have to be? I have never felt the nead to log bodies in requests. That is an opinion based opinion from you that there ”has to be something that logs the body easy”. Why do you have to log the body. State your case. – Toerktumlare Jul 20 '19 at 21:58
  • And then open an issue at spring stating why you need it and they might implement it. – Toerktumlare Jul 20 '19 at 22:06
  • At some point you pass the request body to the web client. Can you do the logging at that point? – Martin Tarjányi Jul 23 '19 at 10:56
  • 2
    I would have to add logging per method or implement wrapper around WebClient which does not sound like a good solution to me. I want a centralised place for logging http request/response which I can share between multiple applications inside the network – Marcin Necsord Szulc Jul 23 '19 at 11:07
  • 1
    @ThomasAndolf That is an opinion based opinion from you that nobody should want to log the body in an easy way, because you personally have never felt the need to log bodies in requests. :) IMHO it actually does make sense a lot, if you want to audit/debug, what was actually sent over the wire and standard logging doesn't cut it, because you have to mask credentials (because of PCI compliance for instance) – Stefan Haberl Jun 25 '20 at 19:12
  • @StefanHaberl that was exactly what i wrote, it is MY opinion, and i wanted to hear HIS case. I, and only ME no one else, just me, considers logging for debugging is a code smell and debuggers should be used. But that is MY personal opinion, and NO ONE elses. And logging requests just for logging a request, you should log what is needed by authorities for auditing, usually this does NOT include logging full requests, logging full requests is a security issue in accordance to GDPR that non compliant values are accidentally logged. – Toerktumlare Jun 25 '20 at 19:19

3 Answers3

2

You can create your own wrapper/proxy class around the JSON encoder and intercept the serialized body before it is sent into the intertubes.

This blog post shows how to log the JSON payloads of WebClient requests and responses

Specifically, you would extend the encodeValue method (or encodeValues in case of streaming data) of Jackson2JsonEncoder. Then you can do with that data what you wish, such as logging etc. And you could even do this conditionally based on environment/profile

This custom logging-encoder can be specified when creating the WebClient, by codecs:

 CustomBodyLoggingEncoder bodyLoggingEncoder = new CustomBodyLoggingEncoder();
 WebClient.builder()
          .codecs(clientDefaultCodecsConfigurer -> {
             clientDefaultCodecsConfigurer.defaultCodecs().jackson2JsonEncoder(bodyLoggingEncoder);
             clientDefaultCodecsConfigurer.defaultCodecs().jackson2JsonDecoder(new Jackson2JsonDecoder(new ObjectMapper(), MediaType.APPLICATION_JSON));
          })
          ...

Update 2020/7/3:

Here is a rushed example applying the same principle but for a decoder:

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);
        }
    }
}

You would configure that along with the encoder using the codecs builder method on WebClient. Of course this above only works assuming your data is being deserialized to a Mono. But override other methods if you need it. Also I'm just stdout'ing the resulting JSON there, but you could pass in a Consumer<String> or something for the decoder to send the string to for example, or just log from there ; up to you.

A word of warning that in it's current form this is going to be doubling your memory usage, as it's buffering the entire response. If you can send that byte data off to another process/thread to write to log file or some output stream (or Flux even) immediately, you could avoid buffering the whole payload in memory.

rewolf
  • 5,143
  • 2
  • 37
  • 48
  • This works great for capturing the serialized request body, but I'm a little bit lost when it comes to capturing the response body before it is deserialized. Any advice? – Stefan Haberl Jun 30 '20 at 08:03
  • @StefanHaberl Added more about response logging – rewolf Jul 03 '20 at 06:33
1

Request body could be accessed when BodyInserter writes to ReactiveHttpOutputMessage. So just create a FilterFunction and create new request from existing but for body set new BodyInserser () overriding method insert see example below. Response and Request payloads could be read multiple times since those are buffered in DataBuffers

public class TracingExchangeFilterFunction implements ExchangeFilterFunction {
 
 
        return next.exchange(buildTraceableRequest(request))
                .flatMap(response ->
                        response.body(BodyExtractors.toDataBuffers())
                                .next()
                                .doOnNext(dataBuffer -> traceResponse(response, dataBuffer))
                                .thenReturn(response)) ;
    }

    private ClientRequest buildTraceableRequest( 
            final ClientRequest clientRequest) {
        return ClientRequest.from(clientRequest).body(
                new BodyInserter<>() {
                    @Override
                    public Mono<Void> insert(
                            final ClientHttpRequest outputMessage,
                            final Context context) {
                        return clientRequest.body().insert(
                                new ClientHttpRequestDecorator(outputMessage) {
                                    @Override
                                    public Mono<Void> writeWith(final Publisher<? extends DataBuffer> body) {
                                        return super.writeWith(
                                                from(body).doOnNext(buffer ->
                                                        traceRequest(clientRequest, buffer)));
                                    }
                                }, context);
                    }
                }).build();
    }

    private void traceRequest(ClientRequest clientRequest, DataBuffer buffer) {
        final ByteBuf byteBuf = NettyDataBufferFactory.toByteBuf(buffer);
        final byte[] bytes = ByteBufUtil.getBytes(byteBuf);
        // do some tracing e.g. new String(bytes)
    }


    private void traceResponse(ClientResponse response, DataBuffer dataBuffer) {
        final byte[] bytes = new byte[dataBuffer.readableByteCount()];
        dataBuffer.read(bytes);
        // do some tracing e.g. new String(bytes)
    }
}
Oleg Maksymuk
  • 293
  • 1
  • 9
0

Try setting the following properties:

logging.level.org.springframework.web.reactive.function.client.ExchangeFunctions=TRACE
logging.level.reactor.netty.http.client.HttpClient: DEBUG
spring.http.log-request-details=true
Justice
  • 354
  • 3
  • 11