Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

errors thrown by the fetch function are cached and returned upon next call #257

Closed
jgehrcke opened this issue Aug 13, 2021 · 6 comments · Fixed by #268
Closed

errors thrown by the fetch function are cached and returned upon next call #257

jgehrcke opened this issue Aug 13, 2021 · 6 comments · Fixed by #268
Labels

Comments

@jgehrcke
Copy link

jgehrcke commented Aug 13, 2021

When using cache: true and when the fetcher function (the one that performs the HTTP GET request) throws an error then the error is cached. Upon the next call to client.getSigningKey(kid) (with the same kid) the fetcher function then is not executed again, but the same error object is thrown again.

To reproduce this and narrow this down I have been using this lovely HTTP client test service: httpbin.org, with the following JWKS URL:

http:https://httpbin.org/status/500,501,502,503,504,505,506,400,401,402,403 -- this generates a random response using one of the status codes of those provided in the URL.

Example error for when a 501 Not Implemented response is returned:

2021-08-13T07:59:51.252Z error: NOT IMPLEMENTED: JwksError: NOT IMPLEMENTED
    at JwksClient.getKeys (/snip/node_modules/jwks-rsa/src/JwksClient.js:49:1)
    at processTicksAndRejections (node:internal/process/task_queues:96:5)
    at JwksClient.getSigningKeys (/snip/node_modules/jwks-rsa/src/JwksClient.js:54:1)
    at JwksClient.getSigningKey (/snip/node_modules/jwks-rsa/src/JwksClient.js:72:1)

Let's look at JwksClient.js:49:1. We use the 2.0.4 release, i.e. the request error is (re)thrown in this line of code:
https://github.com/auth0/node-jwks-rsa/blob/v2.0.4/src/JwksClient.js#L49

With cache: false and repetitive execution of const key = await client.getSigningKey(kid); I get alternating errors between attempts. That is, the HTTP request is actually performed for each attempt.

With cache: true and repetitive execution of const key = await client.getSigningKey(kid); I always get the same error thrown, corresponding to the same http error response (probably until the cache item expires). The probability for the testing service to return the same response across N attempts quickly converges to zero with each attempt. So that appeared fishy, and I suspected the error to be cached.

I went a little deeper and used a custom fetcher function (via fetcher: customfunc) to throw an artificial error. I did put a timestamp into the error message. With cache: true and repetitive execution of const key = await client.getSigningKey(kid); the same timestamp popped up in the error thrown at JwksClient.js:49:1. This is an unambiguous indicator that the fetcher function was not executed across attempts, but that it's indeed the error object that was cached and returned/rethrown again.

I had a super brief look at https://github.com/jfromaniello/lru-memoizer and the README / code does not seem to comment on errors.

What was the expected behavior?

Only 'good' results should be cached, i.e. those that appear to be a JSON Web Key Set.

I want to comment on this statement in the current README:

Even if caching is enabled the library will call the JWKS endpoint if the kid is not available in the cache, because a key rotation could have taken place.

This does not seem to happen. When even the initial JWKS endpoint fetch fails with an error then certainly no key for kid is in the cache. The next time that key is required the JWKS endpoint fetch needs to be executed, bypassing the cache. Instead, the error from the cache is re-used. In that sense, the cache worsens situations.

I don't want to be negative here but I still believe that it's worth expressing that I am surprised to find this in such a popular library -- I don't feel comfortable putting this caching solution into production.

Reproduction

Wanted to drop this here quickly -- can provide repro at some other time if absolutely required.

For the repro I used import jwt from "express-jwt"; and

jwt({
  secret: jwksRsa.expressJwtSecret({
    cache: true,
    rateLimit: true,
    jwksRequestsPerMinute: 5,
    jwksUri: "http:https://httpbin.org/status/500,501,502,503,504,505,506,400,401,402,403"
}),

The problem might be in here:

const handleSigningKeyError = (err, cb) => {

Environment

  • Version of this library used: 2.0.4
  • Which framework are you using, if applicable: express
@jgehrcke
Copy link
Author

Btw, I tried using handleSigningKeyError: errhandler to see if maybe this can be used for a workaround. But it's after the cache. Makes sense, because: https://github.com/auth0/node-jwks-rsa/blob/v2.0.4/src/wrappers/cache.js#L9

load: client.getSigningKey.bind(client),

@jgehrcke
Copy link
Author

As another workaround I tried returning a dummy JWKS using a single kid from the custom fetcher func. With the idea that this kid is certainly not the one requested. But even then the result was cached and re-used.

jgehrcke added a commit to opstrace/opstrace that referenced this issue Aug 13, 2021
For detecting auth0/node-jwks-rsa#257
it makes sense to have timestamps in error messages.

Signed-off-by: Dr. Jan-Philip Gehrcke <[email protected]>
jgehrcke added a commit to opstrace/opstrace that referenced this issue Aug 13, 2021
Also see
auth0/node-jwks-rsa#257

completely backing out of the cache would
be too much work right now.

Signed-off-by: Dr. Jan-Philip Gehrcke <[email protected]>
jgehrcke added a commit to opstrace/opstrace that referenced this issue Aug 13, 2021
For detecting auth0/node-jwks-rsa#257
it makes sense to have timestamps in error messages.

Signed-off-by: Dr. Jan-Philip Gehrcke <[email protected]>
jgehrcke added a commit to opstrace/opstrace that referenced this issue Aug 13, 2021
Also see
auth0/node-jwks-rsa#257

completely backing out of the cache would
be too much work right now.

Signed-off-by: Dr. Jan-Philip Gehrcke <[email protected]>
jgehrcke added a commit to opstrace/opstrace that referenced this issue Aug 13, 2021
For detecting auth0/node-jwks-rsa#257
it makes sense to have timestamps in error messages.

Signed-off-by: Dr. Jan-Philip Gehrcke <[email protected]>
jgehrcke added a commit to opstrace/opstrace that referenced this issue Aug 13, 2021
Also see
auth0/node-jwks-rsa#257

completely backing out of the cache would
be too much work right now.

Signed-off-by: Dr. Jan-Philip Gehrcke <[email protected]>
@jnysteen
Copy link

I'm currently facing the same issue.
Looking through old, closed issues, I stumbled upon #110 .
Maybe some of the fix suggestions in the comments works for this issue as well? I'm planning on trying soon.

@adamjmcgrath
Copy link
Contributor

Hi @jgehrcke - thanks for raising this.

Yep - that behaviour doesn't look right. Will investigate this and update this thread with any findings

@adamjmcgrath
Copy link
Contributor

Have raised a PR to fix it #268

This issue was caused when we moved to a sync lru-memoizer because we started caching the Promise rather than the result of the Promise, so if the first request failed a rejected promise was cached and reused. Switching back to an async one has resolved the issue, because we cache the async result.

Looking through old, closed issues, I stumbled upon #110 .

Oddly enough, we were using the async memoizer at the time but there was an underlying issue with the memoizer library that caused #110.

@jnysteen
Copy link

jnysteen commented Oct 8, 2021

Great, thanks!

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Projects
None yet
Development

Successfully merging a pull request may close this issue.

3 participants