How do I log out the body of a failed response to a Spring WebFlux WebClient request while returning the response to the caller?

Question

I'm very new to reactive programming and I have a REST service that takes a request and then calls to another API using the WebFlux WebClient. When the API responds with a 4xx or 5xx response, I want to log the response body in my service, and then pass on the response to the caller. I've found a number of ways to handle logging the response, but they generally return Mono.error to the caller, which is not what I want to do. I have this almost working, but when I make the request to my service, while I get back the 4xx code that the API returned, my client just hangs waiting for the body of the response, and the service never seems to complete processing the stream. I'm using Spring Boot version 2.2.4.RELEASE.

Here's what I've got:

Controller:

@PostMapping(path = "create-order")
public Mono<ResponseEntity<OrderResponse>> createOrder(@Valid @RequestBody CreateOrderRequest createOrderRequest) {
    return orderService.createOrder(createOrderRequest);
}

Service:

public Mono<ResponseEntity<OrderResponse>> createOrder(CreateOrderRequest createOrderRequest) {
    return this.webClient
            .mutate()
            .filter(OrderService.errorHandlingFilter(ORDERS_URI, createOrderRequest))
            .build()
            .post()
            .uri(ORDERS_URI)
            .contentType(MediaType.APPLICATION_JSON)
            .bodyValue(createOrderRequest)
            .exchange()
            .flatMap(response -> response.toEntity(OrderResponse.class));
}

public static ExchangeFilterFunction errorHandlingFilter(String uri, CreateOrderRequest request) {
    return ExchangeFilterFunction.ofResponseProcessor(clientResponse -> {
        if (clientResponse.statusCode() != null && (clientResponse.statusCode().is5xxServerError() || clientResponse.statusCode().is4xxClientError())) {
            return clientResponse.bodyToMono(String.class)
                    .flatMap(errorBody -> OrderService.logResponseError(clientResponse, uri, request, errorBody));
        } else {
            return Mono.just(clientResponse);
        }
    });
}

static Mono<ClientResponse> logResponseError(ClientResponse response, String attemptedUri, CreateOrderRequest orderRequest, String responseBody) {
    ObjectMapper objectMapper = new ObjectMapper();
    objectMapper.setSerializationInclusion(JsonInclude.Include.NON_NULL);
    try {
        log.error("Response code {} received when attempting to hit {}, request:{}, response:{}",
                response.rawStatusCode(), attemptedUri, objectMapper.writeValueAsString(orderRequest),
                responseBody);
    } catch (JsonProcessingException e) {
        log.error("Error attempting to serialize request object when reporting on error for request to {}, with code:{} and response:{}",
                attemptedUri, response.rawStatusCode(), responseBody);
    }
    return Mono.just(response);
}

As you can see, I'm simply trying to return a Mono of the original response from the logResponseError method. For my testing, I'm submitting a body with a bad element which results in a 422 Unprocessable Entity response from the ORDERS_URI endpoint in the API I'm calling. But for some reason, while the client that called the create-order endpoint receives the 422, it never receives the body. If I change the return in the logResponseError method to be

return Mono.error(new Exception("Some error"));

I receive a 500 at the client, and the request completes. If anyone knows why it won't complete when I try to send back the response itself, I would love to know what I'm doing wrong.

123 123 · Accepted Answer · 2020-05-06T12:17:41

Can't have your cake and eat it too!

The issue here is that you are trying to consume the body of the response twice, which is not allowed. Normally you would get an error for doing so.

Once in

return clientResponse.bodyToMono(String.class)

but also in

response.toEntity(OrderResponse.class)

which actually runs

@Override
public <T> Mono<ResponseEntity<T>> toEntity(Class<T> bodyType) {
    return WebClientUtils.toEntity(this, bodyToMono(bodyType));
}

So one solution would be to process the ResponseEntity instead of the ClientResponse as follows since you don't actually want to do any reactive stuff with the body

public Mono<ResponseEntity<OrderResponse>> createOrder(CreateOrderRequest createOrderRequest) {
    return this.webClient
            //no need for mutate unless you already have things specified in 
            //base webclient?
            .post()
            .uri(ORDERS_URI)
            .contentType(MediaType.APPLICATION_JSON)
            .bodyValue(createOrderRequest)
            .exchange()
            //Here you map the response to an entity first
            .flatMap(response -> response.toEntity(OrderResponse.class))
            //Then run the errorHandler to do whatever
            //Use doOnNext since there isn't any reason to return anything
            .doOnNext(response -> 
                errorHandler(ORDERS_URI,createOrderRequest,response));

}

//Void doesn't need to return
public static void  errorHandler(String uri, CreateOrderRequest request,ResponseEntity<?> response) {
    if( response.getStatusCode().is5xxServerError() 
        || response.getStatusCode().is4xxClientError())
            //run log method if 500 or 400
            OrderService.logResponseError(response, uri, request);
}

//No need for redundant final param as already in response
static void logResponseError(ResponseEntity<?> response, String attemptedUri, CreateOrderRequest orderRequest) {
    //Do the log stuff
    ObjectMapper objectMapper = new ObjectMapper();
    objectMapper.setSerializationInclusion(JsonInclude.Include.NON_NULL);
    try {
        log.error("Response code {} received when attempting to hit {}, request:{}, response:{}",
                response.getStatusCodeValue(), attemptedUri, objectMapper.writeValueAsString(orderRequest),
                response.getBody());
    } catch (JsonProcessingException e) {
        log.error("Error attempting to serialize request object when reporting on error for request to {}, with code:{} and response:{}",
                attemptedUri, response.getStatusCodeValue(), response.getBody());
    }
}

Note that there isn't really a reason to use the ExchangeFilter since you aren't actually doing any filtering, just performing an action based off the response

How do I log out the body of a failed response to a Spring WebFlux WebClient request while returning the response to the caller?

1 Answers