Missing response log for GET request for Webflux integration

[hcsun]

logbook/logbook-spring-webflux/src/main/java/org/zalando/logbook/spring/webflux/LogbookWebFilter.java

Line 41 in 01c8a81

.doOnSuccess(it -> triggerStageChange(stage, serverRequest, serverResponse)) // ensure response has been written

Hi, we really appreciate that Logbook has Webflux support and doing the integration. During the integration, we found out that the response log might not be written down. Here are our finding:

For the GET request, the state transitions in LogbookWebFilter.java might not be complete. So the last write() might not be called in the triggerStageChange.

private void triggerStageChange(AtomicReference<Object> stage, ServerRequest request, ServerResponse response) {
    stage.updateAndGet(throwingUnaryOperator(s -> {
      if (s instanceof Logbook) return ((Logbook) s).process(request);
      if (s instanceof Logbook.RequestWritingStage) return ((Logbook.RequestWritingStage) s).write().process(response);
      if (s instanceof Logbook.ResponseWritingStage) ((Logbook.ResponseWritingStage) s).write();
      return null;
    }));
  }

A further look in the four calls to triggerStageChange shows that the getBody() in BufferingServerHttpRequest is not being triggered during the entire processing for the GET request, so we are missing one of the triggerStageChange calls by using the buffer hook.

We are using undertow server, here is how we get the Logbook and register the web filter:

  @Bean
  public Logbook getLogbook() {
    return Logbook.builder().build();
  }

  @Bean
  public WebFilter logbookServerFilter(final Logbook logbook) {
    return new LogbookWebFilter(logbook);
  }

We are not sure if we are missing other initial steps thus causing the missing getBody(). @sokomishalov , could you help to confirm what we saw here?

A simple trick seems to fix the issue by adding an additional triggerStageChange after the last doOnSuccess:

  return Mono
    .just(exchange)
    .doOnNext((e) -> triggerStageChange(stage, serverRequest, serverResponse))
    .map(e -> exchange
            .mutate()
            .request(new BufferingServerHttpRequest(e.getRequest(), serverRequest, bytes -> triggerStageChange(stage, serverRequest, serverResponse)))
            .response(new BufferingServerHttpResponse(e.getResponse(), serverResponse, bytes -> triggerStageChange(stage, serverRequest, serverResponse)))
            .build()
    )
    .flatMap(chain::filter)
    .doOnSuccess(it -> triggerStageChange(stage, serverRequest, serverResponse)) // ensure response has been written
    .doOnSuccess(it -> triggerStageChange(stage, serverRequest, serverResponse)) // Force to trigger stage change again
    .then();

Looks like it does no harm to other requests like PUT/POST. But we are not sure if it is the right way to do it.