OBO and Silent token acquisition does not read from disk cache when persistence is enabled

[derisen]

Core Library

MSAL Node (@azure/msal-node)

Core Library Version

1.14.5

Wrapper Library

Not Applicable

Wrapper Library Version

N/A

Public or Confidential Client?

Public, Confidential

Description

Silent token acquisition with MSAL Node (either via acquireTokenSilent or one of the internal methods that make use of the cache e.g. acquireCachedToken, readAccessTokenFromCacheForOBO etc.) does not trigger a cache read from disk when cache persistence is enabled. To trigger it, the developer must call one of the getAccount* APIs (see). While this may not be a bug per se, the usage is unintuitive and potentially misleading, as not all token acquisition APIs require or make use of the account object (e.g. acquireTokenOnBehalfOf). Even in the case of using acquireTokenSilent directly where expecting getAccount* APIs to be called beforehand is reasonable, developers may still find other (perhaps cheaper) means of retrieving and supplying an account object to the relevant API.

Error Message

N/A

Msal Logs

[Thu, 22 Dec 2022 18:29:26 GMT] : @azure/[email protected] : Info - acquireTokenOnBehalfOf called [Thu, 22 Dec 2022 18:29:26 GMT] : @azure/[email protected] : Verbose - initializeRequestScopes called [Thu, 22 Dec 2022 18:29:26 GMT] : [da92d27e-d8a5-4dc9-a192-e6e73b59d5e4] : @azure/[email protected] : Verbose - buildOauthClientConfiguration called [Thu, 22 Dec 2022 18:29:26 GMT] : [da92d27e-d8a5-4dc9-a192-e6e73b59d5e4] : @azure/[email protected] : Verbose - building oauth client configuration with the authority: https://login.microsoftonline.com/TENANT_ID [Thu, 22 Dec 2022 18:29:26 GMT] : [da92d27e-d8a5-4dc9-a192-e6e73b59d5e4] : @azure/[email protected] : Verbose - createAuthority called [Thu, 22 Dec 2022 18:29:26 GMT] : @azure/[email protected] : Trace - Retrieving all cache keys [Thu, 22 Dec 2022 18:29:26 GMT] : @azure/[email protected] : Trace - Getting cache key-value store [Thu, 22 Dec 2022 18:29:26 GMT] : @azure/[email protected] : Verbose - Attempting to get cloud discovery metadata in the config
[Thu, 22 Dec 2022 18:29:26 GMT] : @azure/[email protected] : Verbose - Did not find cloud discovery metadata in the config... Attempting to get cloud discovery metadata from the cache. [Thu, 22 Dec 2022 18:29:26 GMT] : @azure/[email protected] : Verbose - Did not find cloud discovery metadata in the cache... Attempting to get cloud discovery metadata from the network.
[Thu, 22 Dec 2022 18:29:26 GMT] : @azure/[email protected] : Verbose - Attempting to find a match between the developer's authority and the CloudInstanceDiscoveryMetadata returned from the network request. [Thu, 22 Dec 2022 18:29:26 GMT] : @azure/[email protected] : Verbose - cloud discovery metadata was successfully returned from getCloudDiscoveryMetadataFromNetwork() [Thu, 22 Dec 2022 18:29:26 GMT] : @azure/[email protected] : Trace - Getting cache key-value store [Thu, 22 Dec 2022 18:29:26 GMT] : @azure/[email protected] : Trace - Setting cache key value store [Thu, 22 Dec 2022 18:29:26 GMT] : [da92d27e-d8a5-4dc9-a192-e6e73b59d5e4] : @azure/[email protected] : Verbose - On behalf of client created [Thu, 22 Dec 2022 18:29:26 GMT] : @azure/[email protected] : Trace - Retrieving all cache keys [Thu, 22 Dec 2022 18:29:26 GMT] : @azure/[email protected] : Trace - Getting cache key-value store [Thu, 22 Dec 2022 18:29:26 GMT] : [da92d27e-d8a5-4dc9-a192-e6e73b59d5e4] : @azure/[email protected] : Info - SilentFlowClient:acquireCachedToken - No access token found in cache for the given properties. [Thu, 22 Dec 2022 18:29:26 GMT] : @azure/[email protected] : Trace - Getting cache key-value store [Thu, 22 Dec 2022 18:29:27 GMT] : [da92d27e-d8a5-4dc9-a192-e6e73b59d5e4] : @azure/[email protected] : Verbose - Persistence enabled, calling beforeCacheAccess [Thu, 22 Dec 2022 18:29:27 GMT] : @azure/[email protected] : Trace - Deserializing JSON to in-memory cache [Thu, 22 Dec 2022 18:29:27 GMT] : @azure/[email protected] : Trace - Reading cache snapshot from disk [Thu, 22 Dec 2022 18:29:27 GMT] : @azure/[email protected] : Trace - Overlaying input cache with the default cache [Thu, 22 Dec 2022 18:29:27 GMT] : @azure/[email protected] : Trace - Setting in-memory cache [Thu, 22 Dec 2022 18:29:27 GMT] : @azure/[email protected] : Trace - Getting cache key-value store [Thu, 22 Dec 2022 18:29:27 GMT] : @azure/[email protected] : Trace - Setting cache key value store [Thu, 22 Dec 2022 18:29:27 GMT] : @azure/[email protected] : Trace - Getting cache key-value store [Thu, 22 Dec 2022 18:29:27 GMT] : @azure/[email protected] : Trace - Setting cache key value store [Thu, 22 Dec 2022 18:29:27 GMT] : @azure/[email protected] : Trace - Getting cache key-value store [Thu, 22 Dec 2022 18:29:27 GMT] : @azure/[email protected] : Trace - Setting cache key value store [Thu, 22 Dec 2022 18:29:27 GMT] : @azure/[email protected] : Trace - Retrieving all cache keys [Thu, 22 Dec 2022 18:29:27 GMT] : @azure/[email protected] : Trace - Getting cache key-value store [Thu, 22 Dec 2022 18:29:27 GMT] : @azure/[email protected] : Trace - Getting cache key-value store [Thu, 22 Dec 2022 18:29:27 GMT] : @azure/[email protected] : Trace - Retrieving all cache keys [Thu, 22 Dec 2022 18:29:27 GMT] : @azure/[email protected] : Trace - Getting cache key-value store [Thu, 22 Dec 2022 18:29:27 GMT] : @azure/[email protected] : Trace - Getting cache key-value store [Thu, 22 Dec 2022 18:29:27 GMT] : @azure/[email protected] : Trace - Getting cache key-value store [Thu, 22 Dec 2022 18:29:27 GMT] : @azure/[email protected] : Trace - Retrieving all cache keys [Thu, 22 Dec 2022 18:29:27 GMT] : @azure/[email protected] : Trace - Getting cache key-value store [Thu, 22 Dec 2022 18:29:27 GMT] : @azure/[email protected] : Trace - Getting cache key-value store [Thu, 22 Dec 2022 18:29:27 GMT] : @azure/[email protected] : Trace - Getting cache key-value store [Thu, 22 Dec 2022 18:29:27 GMT] : @azure/[email protected] : Trace - Retrieving all cache keys [Thu, 22 Dec 2022 18:29:27 GMT] : @azure/[email protected] : Trace - Getting cache key-value store [Thu, 22 Dec 2022 18:29:27 GMT] : @azure/[email protected] : Trace - Getting cache key-value store [Thu, 22 Dec 2022 18:29:27 GMT] : @azure/[email protected] : Trace - Getting cache key-value store [Thu, 22 Dec 2022 18:29:27 GMT] : @azure/[email protected] : Trace - Setting cache key value store [Thu, 22 Dec 2022 18:29:27 GMT] : @azure/[email protected] : Trace - Getting cache key-value store [Thu, 22 Dec 2022 18:29:27 GMT] : @azure/[email protected] : Trace - Setting cache key value store [Thu, 22 Dec 2022 18:29:27 GMT] : @azure/[email protected] : Trace - Getting cache key-value store [Thu, 22 Dec 2022 18:29:27 GMT] : @azure/[email protected] : Trace - Setting cache key value store [Thu, 22 Dec 2022 18:29:27 GMT] : [da92d27e-d8a5-4dc9-a192-e6e73b59d5e4] : @azure/[email protected] : Verbose - Persistence enabled, calling afterCacheAccess [Thu, 22 Dec 2022 18:29:27 GMT] : @azure/[email protected] : Trace - Serializing in-memory cache [Thu, 22 Dec 2022 18:29:27 GMT] : @azure/[email protected] : Trace - Getting in-memory cache [Thu, 22 Dec 2022 18:29:27 GMT] : @azure/[email protected] : Trace - Getting cache key-value store [Thu, 22 Dec 2022 18:29:27 GMT] : @azure/[email protected] : Trace - Reading cache snapshot from disk [Thu, 22 Dec 2022 18:29:27 GMT] : @azure/[email protected] : Trace - Merging in-memory cache with cache snapshot [Thu, 22 Dec 2022 18:29:27 GMT] : @azure/[email protected] : Trace - Remove updated entries in cache

MSAL Configuration

const cca = new msal.ConfidentialClientApplication({
    auth: {
        clientId: "CLIENT_ID",
        authority: "https://login.microsoftonline.com/TENANT_ID",
        clientSecret: "CLIENT_SECRET",
    },
    cache: {
        cachePlugin: require('./cachePlugin')('./cache.json')
    },
    system: {
        loggerOptions: {
            loggerCallback(loglevel, message, containsPii) {
                console.log(message);
            },
            piiLoggingEnabled: false,
            logLevel: msal.LogLevel.Trace,
        }
    }
});

Relevant Code Snippets

app.get('/getOboToken', async (req, res, next) => {
    try {
        const oboRequest = {
            oboAssertion: req.headers.authorization.split(' ')[1],
            scopes: ["user.read", "offline_access"],
        };

        const response = await cca.acquireTokenOnBehalfOf(oboRequest);

        res.send(response);
    } catch(error) {
        next(error)
    }
});

Reproduction Steps

For acquireTokenOnBehalfOf:

1. Grab the msal-node on-behalf-of sample
2. Configure cache persistence via a cache plugin.
3. Configure the client app to use acquireTokenSilent
4. Run the flow end to end once.
5. Restart the service app.
6. Run the flow again, expect the service app to retrieve the token from cache (i.e. response.fromCache: true)

For acquireTokenSilent:

1. Grab the msal-node silent-flow sample
2. Configure cache persistence via a cache plugin.
3. Configure session persistence via a session middleware (e.g. express-session)
4. Save the account object in session after acquireTokenByCode
5. Next time when calling acquireTokenSilent, use the account object in the session (comment out any lines where getAccount* is called)
6. Restart the app, and attempt acquireTokenSilent again
7. Expect the token to be retrieved from cache (i.e. response.fromCache: true)

Expected Behavior

When cache persistence is enabled, retrieving tokens from cache should read from disk beforehand by default

Identity Provider

Azure AD / MSA

Browsers Affected (Select all that apply)

None (Server)

Regression

No response

Source

Internal (Microsoft)

[tnorling]

Thanks @derisen! This does look like a bug though I'd like @sameerag to chime in here as well. Let's discuss after the new year.

[sruthiy4347]

Is this issue fixed? I am also running into the same scenario. Using acquireTokenOnBehalfOf with a custom distributed cache plugin. But the beforecacheaccesss is not called

[Sheeley7]

I am also seeing this issue with msal-node. Tried creating a basic FilePersistence example and acquireTokenSilent gives: "No refresh token found in the cache. Please sign-in."

const filePersistence = await FilePersistence.create(filePath);
      
const pca = PublicClientApplication({
        auth: {
          clientId: "CLIENT_ID",
        },
        cache: {
          cachePlugin: new PersistenceCachePlugin(filePersistence),
        },
      })

[kevinbailey25]

We're also still seeing this issue using the DistributedCachePlugin. Any update on any progress on this?

[derisen]

@kevinbailey25 not yet I'm afraid. Please continue calling getAccount() APIs beforehand in the meantime.

cc @bgavrilMS @Robbie-Microsoft

[bgavrilMS]

@Robbie-Microsoft - did you fix this ?

[Robbie-Microsoft]

@bgavrilMS All the msal-node confidential client flows have this issue. I fixed it in the client credential flow in this PR. Dogan had reservations about applying the fix to Silent flow and OBO flow due to performance reasons. See his comment here.

[bgavrilMS]

It's better be slow and correct than fast and incorrect.

Let's please repurpose this work item to track work for Silent and OBO.

[bgavrilMS]

@Robbie-Microsoft - assigning to you to close

[sameerag]

Shouldn't this apply to PCA also? I think we landed at:

• Check in-memory for account
• If fails, then refresh the in-memory cache from the persistent cache
• Check in-memory again
• Handle success/error accordingly

The idea is to not go check the disk always for perf concerns. Is there any possibility in-memory is out of date? In those cases, we will have an error. This is the part I would like to clarify.

Is this in compliance with how we do this in other MSALs too? cc @bgavrilMS

[bgavrilMS]

If perf is an issue, we should come up with a 2-layer cache: memory cache (L1) and persistent cache (L2). This is what we have in .NET for confidential client. For public client a disk access is very fast, I am not aware of perf considerations.

So MSAL should always load from the cache and it's the cache's responsibility to be "fast".