Spring WebFlux - statusCode is null in a WebFilter

Question

Currently developing with Spring Boot 2.0.4 a WebFilter that logs HTTP request and response informations (URL, response status code, duration, etc) in a Spring WebFlux application.

Works fine except that exchange.getResponse().getStatusCode() remains null.

Tried two different impls of filter(ServerWebExchange exchange, WebFilterChain chain), first one:

return chain.filter(exchange).doAfterTerminate(
        () -> System.out.println("Status=" + exchange.getResponse().getStatusCode()));

Second one:

    Mono<Void> filtered = chain.filter(exchange);
    exchange.getResponse().beforeCommit(() -> {
        System.out.println("Status=" + exchange.getResponse().getStatusCode());
        return Mono.empty();
    });
    return filtered;

Also tried various orders on the filter: none, @Order(100000), @Order(-100000).

Status code remains null.

What is the proper implementation?

Update 1

Wrote a minimalistic working example based on KevH solution, see https://github.com/fbeaufume/webflux-filter-sample but it's not working yet, the status is still null. The MWE exposes two REST endpoints: /hello and /pause/1000 (a 1 sec pause).

Note that when called the pause endpoint logs:

11:06:20.644  INFO 9536 --- [ctor-http-nio-2] com.adeliosys.sample.LogFilter           : Request [/pause/1000] started, traceId [bb3fe67d-170b-4070-837d-816fe1420a1f]
11:06:20.673  INFO 9536 --- [ctor-http-nio-2] com.adeliosys.sample.HelloController     : Pausing for 1000 msec
11:06:21.683  INFO 9536 --- [     parallel-2] com.adeliosys.sample.LogFilter           : Request [/pause/1000] completed, statusCode [null], time [1039], traceId [bb3fe67d-170b-4070-837d-816fe1420a1f]
11:06:21.684  INFO 9536 --- [     parallel-2] com.adeliosys.sample.HelloController     : Paused for 1000 msec

I'm surprised that the second message of the filter is displayed before the second message of the endpoint.

Update 2

It seems that the filter implementation using doAfterTerminate (or similar methods) was correct, but this correctly retrieves the HTTP response status only with REST controller methods that use a ResponseEntity in the return type.

Not supported (i.e. status is null): void, Mono<Void>, String, Mono<String>, MyBean, Mono<MyBean>, etc.

Supported (i.e. status is 200): ReponseEntity<Void>, Mono<ResponseEntity<Void>>, ReponseEntity<String>, Mono<ResponseEntity<String>>, ReponseEntity<MyBean>, Mono<ResponseEntity<MyBean>>, etc.

Bug?

Spring Boot 2.0.5 has the same behavior.

Update 3

Opened an issue on the subject, see https://jira.spring.io/browse/SPR-17368

Kevin Hussey · Accepted Answer · 2018-10-09 23:16:21Z

2

You can try doAfterSuccessOrError

@Override
    public Mono<Void> filter(ServerWebExchange exchange, WebFilterChain chain) {
        String traceId = UUID.randomUUID().toString();
        long startTime = System.currentTimeMillis();
        String path = exchange.getRequest().getURI().getPath();
        System.out.printf("Request[%s] started, trace_id[%s]", path, traceId);

        return chain.filter(exchange)
                .doAfterSuccessOrError((r, t) -> {
                    System.out.printf("Request[%s], completed, status_code[%s], time[%d], trace_id[%s]", path,
                            exchange.getResponse().getStatusCode(), System.currentTimeMillis() - startTime, traceId);
                })
                .subscriberContext(Context.of(String.class, traceId));
    }

sample output

Request[/logrequest] started, trace_id[b45b550a-b9ad-4323-a850-cb085a78a086] Request[/logrequest], completed, status_code[202], time[41], trace_id[b45b550a-b9ad-4323-a850-cb085a78a086]

edit: Unsure exactly why this doesn't work but here are two work arounds both have a ResponseEntity

@GetMapping("/hello")
    public Mono<ResponseEntity<String>> publicHello() {
        return Mono.just(ResponseEntity.ok("Hello world!"));
    }

    @GetMapping("/pause/{duration}")
    @ResponseStatus(HttpStatus.ACCEPTED)
    public Mono<Void> pause2(@PathVariable long duration) {
        LOGGER.info("Pausing for {} msec", duration);
        return (duration > 0 ? Mono.delay(Duration.ofMillis(duration)) : Mono.empty())
                .then()
                .doFinally(s -> LOGGER.info("Paused for {} msec", duration));
    }

edited Oct 9, 2018 at 23:16

answered Oct 5, 2018 at 22:42

Kevin Hussey

1,7121 gold badge13 silver badges19 bronze badges

Sign up to request clarification or add additional context in comments.

5 Comments

Florian Beaufumé Over a year ago

Does not work, the status is still null: Request[/pause2/1000], completed, status_code[null], time[1010], trace_id[7fa1d55c-d042-4e1c-9eb8-396816e19298]

Kevin Hussey Over a year ago

Can you add your response handler? I suspect it’s not the webfilter. Or else the most basic GET request, and see if that works. As you can see from above it does actually work.

Florian Beaufumé Over a year ago

Added Update 1 in the post, with a MWE. Thank you for your time. :)

Florian Beaufumé Over a year ago

Thanks for the extra info. Using a ResponseEntity in "/hello" fixes the null status in the filter. But your proposal for "/pause/{duration}" will not work as-is since no one subscribes the Mono, so the delay is not used. Turns out my very first filter was correct. It's just that it does not support all WebFlux return types... WebFlux bug? More update to come.

Kevin Hussey Over a year ago

@FlorianBeaufumé you asked about how to get response status in your filter, update your handler with @ResponseStatus(200) etc and it should work.

Collectives™ on Stack Overflow

Spring WebFlux - statusCode is null in a WebFilter

1 Answer 1

5 Comments

Your Answer

Hot Network Questions

Collectives™ on Stack Overflow

1 Answer 1

5 Comments

Your Answer

Sign up or log in

Post as a guest

Related