Exception loading JWK, Read Timeout

[SondreODahl]

Expected Behavior

We have a micronaut service running in AWS ECS with three different jwksUrls for three different Cognito User Pools. We have configured jwks with 24h cache using micronaut-cache and have not disabled the micronaut client for jwks.
This should work with 3 different pools and not cause errors to be logged because the token is only correctly decoded by one of the jwks-values. At the moment it fires off three requests:
13:40:03.974 [default-eventLoopGroup-2-2] DEBUG i.m.h.client.netty.DefaultHttpClient - Sending HTTP GET to https://cognito-idp.eu-west-1.amazonaws.com/POOL_1/.well-known/jwks.json
13:40:03.979 [default-eventLoopGroup-2-2] DEBUG i.m.h.client.netty.DefaultHttpClient - Sending HTTP GET to https://cognito-idp.eu-west-1.amazonaws.com/POOL_2/.well-known/jwks.json
13:40:03.980 [default-eventLoopGroup-2-2] DEBUG i.m.h.client.netty.DefaultHttpClient - Sending HTTP GET to https://cognito-idp.eu-west-1.amazonaws.com/POOL_3/.well-known/jwks.json
Since we can see the request succeeding in production it means that the the HTTP GET for the right pool was successful. So the read timeout may suggest that one of the other requests is not closing of correctly.

Our configuration for micronaut security:

micronaut:
  application:
    name: demo
  security:
    enabled: true
    token:
      basic-auth:
        enabled: false
      jwt:
        enabled: true
        signatures:
          jwks:
            client1:
              url: https://cognito-idp.eu-west-1.amazonaws.com/POOL_1/.well-known/jwks.json
            client2: 
              url: https://cognito-idp.eu-west-1.amazonaws.com/POOL_2/.well-known/jwks.json
            client3:
              url: https://cognito-idp.eu-west-1.amazonaws.com/POOL_3/.well-known/jwks.json
      bearer:
        enabled: true
  caches:
    jwks:
      expire-after-write: 24h

Other configuration which may or may not be relevant:

  server:
    thread-selection: blocking
  http:
    client:
      max-content-length: 104857600 # 100mb max content length
      read-timeout: 60s
      connection-pool-idle-timeout: 55s
      pool:
        enabled: false
    jwks:
      expire-after-write: 24h

Actual Behaviour

In our production environment we keep seeing

Exception loading JWK from https://cognito-idp.eu-west-1.amazonaws.com/USER_POOL_ID/.well-known/jwks.json

// Full stack trace
io.micronaut.http.client.exceptions.ReadTimeoutException: Read Timeout
	at io.micronaut.http.client.exceptions.ReadTimeoutException.<clinit>(ReadTimeoutException.java:26)
	at io.micronaut.http.client.netty.DefaultHttpClient.lambda$exchange$15(DefaultHttpClient.java:920)
	at io.micronaut.core.execution.ImperativeExecutionFlowImpl.onErrorResume(ImperativeExecutionFlowImpl.java:112)
	at io.micronaut.core.execution.DelayedExecutionFlowImpl$OnErrorResume.apply(DelayedExecutionFlowImpl.java:393)
	at io.micronaut.core.execution.DelayedExecutionFlowImpl.work(DelayedExecutionFlowImpl.java:58)
	at io.micronaut.core.execution.DelayedExecutionFlowImpl.completeLazy(DelayedExecutionFlowImpl.java:80)
	at io.micronaut.core.execution.DelayedExecutionFlowImpl.completeExceptionally(DelayedExecutionFlowImpl.java:104)
	at io.micronaut.core.execution.ExecutionFlow.lambda$timeout$1(ExecutionFlow.java:191)
	at io.netty.util.concurrent.PromiseTask.runTask(PromiseTask.java:98)
	at io.netty.util.concurrent.ScheduledFutureTask.run(ScheduledFutureTask.java:160)
	at io.netty.util.concurrent.AbstractEventExecutor.runTask(AbstractEventExecutor.java:148)
	at io.netty.util.concurrent.AbstractEventExecutor.safeExecute(AbstractEventExecutor.java:141)
	at io.netty.util.concurrent.SingleThreadEventExecutor.runAllTasks(SingleThreadEventExecutor.java:535)
	at io.netty.channel.SingleThreadIoEventLoop.run(SingleThreadIoEventLoop.java:201)
	at io.netty.util.concurrent.SingleThreadEventExecutor$5.run(SingleThreadEventExecutor.java:1193)
	at io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74)
	at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)
	at java.base/java.lang.Thread.run(Unknown Source)

This happens every week, from 20 times to some thousand times on weeks with heavy load. It does not cause any actual errors, the tokens are validated correctly, but causes a lot of errors logs triggering alarms and causing unnecessary noise.
On previous versions of Micronaut and Micronaut Security we experienced this:
ERROR i.m.s.t.j.s.j.ResourceRetrieverJwksClient - Exception loading JWK from xxx java.net.SocketException: Closed by interrupt as in this issue: JWKS issue. It has now changed to the Read Timeout seen above.

I have made a clone of @yibo-long `s reproducer and have made a test which captures the error when it happens. However, I have struggled to reproduce it locally. I managed to do it for SocketException previously on older versions, but it seems to happen so rarely that I do not see it locally.
The error may be related to this discussion micronaut-core-jwks

Apologies for the messy issue, let me know if you need additional information.

Steps To Reproduce

See reproducer link. Configure the user pools in application.yml and get valid tokens for the test to use. Or start the service and execute requests against the /test-endpoint.
I have been unable to reproduce on the newest versions, but we still see these errors in production despite upgrading everything.

Environment Information

JDK: temurin-21
Kotlin: 2.2.21
KSP: 2.3.0
Gradle: 9.2
Docker Image:
eclipse-temurin:21.0.9_10-jre-alpine

Micronaut
Micronaut-security: 4.15.0
Micronaut-cache: 5.3.0 (with matching caffeine version)
core: 4.10.2

Example Application

https://github.com/SondreODahl/micronaut-jwks-read-timeout

Version

4.10.2

[MT-Jacobs]

We're experiencing the same issue in our application as well.

micronaut:
    security:
        enabled: true
        authentication: cookie
        token:
            cookie:
                cookie-name: _samplename
                enabled: true
            jwt:
                enabled: true
                signatures:
                        jwks:
                          oursolution:
                            url: ${oursolution.base-url}/v1/keys
                          external-oursolution:
                            url: ${external-oursolution.base-url}/v1/keys

[graemerocher]

@SondreODahl the linked repository 404s, can someone else provide a reproducer?

[SondreODahl]

I made it private by accident, sorry @graemerocher. Could you try accessing it again?

[SondreODahl]

After upgrading to a version with the fix, we are no longer seeing these error logs. Thank you!