Getting "loaded_keys": -1 when using jwk_url

[derTuca]

Hi. I am trying to use jwk_url using FusionAuth's endpoint (response example down below), but when I try to do I get am error saying that kid not found in JWKs, even though I have verified manually and it is there.

On server start I saw the following log, and the loaded_keys struck me as weird:

{"level":"info","ts":1688560980.1593323,"logger":"http.authentication.providers.jwt","msg":"using JWKs from URL","url":"http://fusionauth:9011/.well-known/jwks.json","loaded_keys":-1}

My config looks as follows:

(auth_token) {
    jwtauth {
        jwk_url "http://fusionauth:9011/.well-known/jwks.json"
        issuer_whitelist VALUE
        audience_whitelist VALUE
        user_claims sub email preferred_username
    }
}

Response of http://fusionauth:9011/.well-known/jwks.json:

{
  "keys" : [
    {
      "alg" : "RS256",
      "e" : "AQAB",
      "kid" : "VALUE",
      "kty" : "RSA",
      "n" : "VALUE",
      "use" : "sig",
      "x5c" : [
        "VALUE"
      ],
      "x5t" : "VALUE",
      "x5t#S256" : "VALUE"
    }
  ]
}

I am using version 0.9.0 of the caddy-jwt module with caddy 2.6.4.

[ggicci]

Hi @derTuca, thanks for the error report. BTW, could you please paste the full log. There should be another line printing the underlying error by this line of code. It can help to address the problem

[derTuca]

So it seems the main issue was with my configuration (more specifically with the fact that the auth service was not started before caddy so the get keys request failed). I do think that it would be helpful to log that it could not connect to the JWK endpoint or retry, if possible.

I am attaching the full logs of the server with the auth service stopped:

{"level":"info","ts":1688979735.4398363,"msg":"using provided configuration","config_file":"/etc/caddy/Caddyfile","config_adapter":"caddyfile"}
{"level":"info","ts":1688979735.4476557,"logger":"admin","msg":"admin endpoint started","address":"localhost:2019","enforce_origin":false,"origins":["//localhost:2019","//[::1]:2019","//127.0.0.1:2019"]}
{"level":"info","ts":1688979735.4479823,"logger":"tls.cache.maintenance","msg":"started background certificate maintenance","cache":"0xc00080ab60"}
{"level":"info","ts":1688979735.4490936,"logger":"http.authentication.providers.jwt","msg":"using JWKs from URL","url":"http://fusionauth:9011/.well-known/jwks.json","loaded_keys":-1}
{"level":"info","ts":1688979735.4502099,"logger":"http.authentication.providers.jwt","msg":"using JWKs from URL","url":"http://fusionauth:9011/.well-known/jwks.json","loaded_keys":-1}
{"level":"info","ts":1688979735.4513462,"logger":"http.authentication.providers.jwt","msg":"using JWKs from URL","url":"http://fusionauth:9011/.well-known/jwks.json","loaded_keys":-1}
{"level":"info","ts":1688979735.4527519,"logger":"http.authentication.providers.jwt","msg":"using JWKs from URL","url":"http://fusionauth:9011/.well-known/jwks.json","loaded_keys":-1}
{"level":"info","ts":1688979735.4548805,"logger":"http.authentication.providers.jwt","msg":"using JWKs from URL","url":"http://fusionauth:9011/.well-known/jwks.json","loaded_keys":-1}
{"level":"info","ts":1688979735.4564853,"logger":"http.authentication.providers.jwt","msg":"using JWKs from URL","url":"http://fusionauth:9011/.well-known/jwks.json","loaded_keys":-1}
{"level":"info","ts":1688979735.4567363,"logger":"http.log","msg":"server running","name":"srv0","protocols":["h1","h2","h3"]}
{"level":"info","ts":1688979735.4568272,"logger":"tls","msg":"cleaning storage unit","description":"FileStorage:/data/caddy"}
{"level":"info","ts":1688979735.4568708,"logger":"tls","msg":"finished cleaning storage units"}
{"level":"info","ts":1688979735.4569373,"msg":"autosaved config (load with --resume flag)","file":"/config/caddy/autosave.json"}
{"level":"info","ts":1688979735.4569728,"msg":"serving initial configuration"}
{"level":"error","ts":1688979741.034906,"logger":"http.authentication.providers.jwt","msg":"invalid token","token_string":"TKENSTR","error":"key provider 0 failed: key specified by kid \"KID\" not found in JWKs"}
{"level":"error","ts":1688979741.0349588,"logger":"http.handlers.authentication","msg":"auth provider returned error","provider":"jwt","error":"key provider 0 failed: key specified by kid \"KID\" not found in JWKs"}

[ddl-ebrown]

FYI - this seems like a fundamental issue with the caching behavior. It's absolutely necessary in any complex environment to assume that the JWKS endpoint may be intermittently available (or that keys might change over the lifetime of the Caddy server).

So I think it would be helpful to have a way to control the JWKS cache validation to make this production ready

[ddl-ebrown]

Furthermore, it would be nice to configure the behavior so that if a kid isn't valid for the given token, that a refresh of the tokens are triggered on the backend. This could address some of the intermittent connectivity problems.

[ddl-ebrown]

Thanks for taking a look at this and putting up a PR so quickly! I think we probably don't want to fail in the Validate call though.

I have a small changeset at https://github.com/cerebrotech/caddy-jwt/pull/2/files that I'm testing now to make sure it behaves the way I would expect.

Thanks again for your help!

[ggicci]

Close since #52 #56 had been merged.