HTTP response with Flux has missing closing array

[stefanos-kalantzis]

Hi,

I have the following HTTP endpoint:

@Get("/{resourceName}/{resourceId}")
public Flux<ResourceDto> getAll(@PathVariable ResourceName resourceName, @PathVariable String resourceId) {
    return service.findAllBy(resourceName, resourceId);
}

The service is eventually calling a Cassandra DB, which returns a MappedReactiveResultSet, which implements Publisher.

I'm experiencing an inconsistent problem, that 1 every 20 requests (not precisely) the response does not contain the closing array character ].

So, instead of [{...}] the client gets [{...}.

Of course, since this is a Flux response, there is no Content-Length header in the response, but Transfer-Encoding: chunked instead.

I did a wireshark capture, and indeed in the cases of the missing ], the response ends with a 0 right after the last }.

Maybe interesting, is that in the cases that it does work, the ] is sent in a new TCP packet, as a single extra byte. So the TCP trace in the working case, looks like:

116
[{...}

1
]

0

So, my question is in which direction should I investigate this further, and how. I don't know where the problem could be (Reactor, Micronaut, Cassandra, ?). What nature of problem could cause this?

I will create a demo repository if needed, but I wanted to ask first, maybe there's something obvious for people more versed in the reactive world.

---

Of course, if I change the HTTP response to Mono<List<ResourceDto>>, then it changes to a Content-Length mode, and it works consistently correctly.

[yawkat]

do you know if Publisher.onComplete is being called? if so, this just sounds like a bug, and you can transform this to an issue.

[stefanos-kalantzis]

ok, yeah sure I'll prepare a repo :)

[stefanos-kalantzis]

In the process of creating the demo repository, I discovered that the problem was caused by a logger that I had put inside an HttpFilter.

The logger was logback, using a synchronous appender. I now realize that this is wrong, and I should be using an asynchronous appender instead. (yes with an async appender the issue goes away)

I could also reproduce the behavior by replacing the logger call with Thread.sleed(10); inside the HttpFilter:

Now I'm wondering if this is how the framework should behave in case of a blocking call (or even some slow algorithm?)... Should it fail like this, or just be (very) slow but correct?

---

Side question, is using an async logger a hidden requirement when using Reactor in Micronaut?

I could find anything related in the docs of micronaut-core nor micronaut-reactor.

[yawkat]

blocking on the event loop is generally a bad thing, and can lead to subtle issues like this. But i hadn't seen it happen with a logger before, and it's a bit concerning that it can happen so easily. I'm not sure we can do much about it. you can find issues like this with blockhound.

[stefanos-kalantzis]

Please ignore what I wrote above, IntelliJ was playing tricks on me. After switching my debugging efforts to command-line, I managed to isolate the issue.

Here's the repo that reproduces the issue: https://github.com/stefanos-kalantzis/mn-flux-response-bug

(The bug is related to enabling tracing-zipkin)

[stefanos-kalantzis]

I created an issue: #8454