Changes to threading from Micronaut 4.4 to 4.5?

[kevin-wise]

We're in the process of upgrading to Micronaut 4.x from Micronaut 3.10. We had everything working in 4.4.3 but before we finished testing, 4.5.0 came out. So we tried upgrading to that and we started getting all kinds of strange behavior. We had 3 microservices upgraded and saw 3 completely different behaviors, but all of them failing where they worked fine in 4.4. Is there anything you can think of that would explain this?

One of the services started throwing:

io.micronaut.http.client.exceptions.HttpClientException: You are trying to run a BlockingHttpClient operation on a netty event loop thread. This is a common cause for bugs: Event loops should never be blocked. You can either mark your controller as @ExecuteOn(TaskExecutors.BLOCKING), or use the reactive HTTP client to resolve this bug. There is also a configuration option to disable this check if you are certain a blocking operation is fine here.
	at io.micronaut.http.client.netty.DefaultHttpClient$1.exchange(DefaultHttpClient.java:550)

Another started throwing

java.lang.InterruptedException: null
	at java.base/java.util.concurrent.CompletableFuture.reportGet(CompletableFuture.java:386)
	at java.base/java.util.concurrent.CompletableFuture.get(CompletableFuture.java:2073)

The only thing that seems to be in common is that threads are involved. Was there any change to threading?

[graemerocher]

no but we added blocking detection if you are blocking the event loop. As per the error message add @ExecuteOn(TaskExecutors.BLOCKING) are configure the server to always offload work off the event loop

[yawkat]

I think blocking detection is older than 4.4

[kevin-wise]

We have micronaut.server.thread-selection=BLOCKING. Isn't that equivalent to having @ExecuteOn(TaskExecutors.BLOCKING) on every controller?

[graemerocher]

please provide a example that reproduces the issue

[kevin-wise]

Finally getting back to this, and I want to make sure I understand. If I want every controller method to run on BLOCKING, what is the minimum needed to make that happen? My understand was that it was sufficient to add micronaut.server.thread-selection: BLOCKING. Is that correct, or does it also require annotations?

[kevin-wise]

we added blocking detection if you are blocking the event loop

Also, is there a log I could enable to see if it's hitting the blocking operation detection you mentioned?

[kevin-wise]

I think what's going on is I have a RolesFinder implementation which reads the roles from a database, which is a blocking operation. It worked fine with 4.4 but with 4.6 something is interrupting the thread.

[kevin-wise]

Ok, I think I finally figured out what's going on. At least, I figured out a key difference between 4.4 and 4.6.

In 4.4, it uses JwtTokenValidator, which has .subscribeOn(scheduler) using a BLOCKING scheduler.
In 4.6, it uses NimbusReactiveJsonWebTokenValidator which just uses the Netty event loop group thread (no subscribeOn).

I'm not really sure what's interrupting the thread in my case, but obvious it's not ideal to run blocking operations in the event loop. Can we get NimbusReactiveJsonWebTokenValidator to use a scheduler? Or at least give us the option to use a scheduler?

On a side note, in 4.6 both JwtTokenValidator and NimbusReactiveJsonWebTokenValidator are being instantiated when beans get a list of TokenValidator beans. So in reality both token validators will run (see screenshots below when stopped at a breakpoint). I doubt this is what was intended based on the comments in micronaut-projects/micronaut-security@0579b8a.

For example, TokenAuthenticationValidator iterates over the tokenValidators then picks the first one. That may not always be the reactive one.

[kevin-wise]

@sdelamo since micronaut-projects/micronaut-security#1693 was your PR, I figured you might like to know about this finding. Both the fact that NimbusReactiveJsonWebTokenValidator changed which thread RolesFinder runs on, and also that JwtTokenValidator is still running even though it appears it shouldn't be.

Let me know if you want me to write up bug(s) for these

[kevin-wise]

I just realized why this would cause my thread to be interrupted--
Because io.micronaut.security.token.TokenAuthenticationFetcher#fetchAuthentication calls

        return Flux.fromIterable(tokens)
            .flatMap(tokenValue -> Flux.fromIterable(tokenValidators)
                .flatMap(tokenValidator -> tokenValidator.validateToken(tokenValue, request))
                .next()
    ...

So, both token validators actually get called (because of Flux.fromIterable(tokenValidators)) but then the second one gets discarded (because of .next()) and I'm 99% sure that Flux ends up interupting the thread of the second when only the first result is consumed and the subsequent results are cancelled.

In my case it's causing side effects because the RolesFinder implementation also calls Redis which has it's own threading, and that is also getting interupted, throwing exceptions.

So, I think the fix for my problem is to provide some mechanism to ensure that JwtTokenValidator and NimbusReactiveJsonWebTokenValidator don't both run at the same time, or at least order NimbusReactiveJsonWebTokenValidator before JwtTokenValidator. Disabling JwtTokenValidator is a start, but if someone ever needed to implement their own TokenValidator implementation, they would need some way to disable NimbusReactiveJsonWebTokenValidator as well; and @Replace-ing it won't work because it's marked @Internal and is package-private.

[kevin-wise]

I went ahead and wrote them both up
micronaut-projects/micronaut-security#1845
micronaut-projects/micronaut-security#1846