[Bug] OBO token is not refreshed when it has expired

[jmprieur]

Logs and Network traces Without logs or traces, it is unlikely that the team can investigate your issue. Capturing logs and network traces is described at https://github.com/AzureAD/microsoft-authentication-library-for-dotnet/wiki/logging

Which Version of MSAL are you using ? MSAL.NET 4.29

Platform .NET Core

What authentication flow has the issue?

• Web API
  • [ x ] OBO

Repro

See https://github.com/AzureAD/microsoft-identity-web/compare/jmprieur/repro_obo_rt. This is simulating a long running process in a web API, or a feature like OneDrive that creates albums for the user who is no longer signed-in. This requires the OBO token to be refreshed, (which is possible until the refresh token expires).

A controller action calls RegisterPeriodicCallbackForLongProcessing() which itself registers a callback (with a timer)

        /// <summary>
        /// This methods the processing of user data where the web API periodically checks the user
        /// date (think of OneDrive producing albums)
        /// </summary>
        private void RegisterPeriodicCallbackForLongProcessing()
        {
            // Get the token incoming to the web API - we could do better here.
            var token = (HttpContext.Items["JwtSecurityTokenUsedToCallWebAPI"] as JwtSecurityToken).RawData;

            // Build the URL to the callback controller, based on the request.
            var request = HttpContext.Request;
            string url = request.Scheme + "://" + request.Host + request.Path.Value.Replace("todolist", "callback");

            // Setup a timer so that the API calls back the callback every 10 mins.
            Timer timer = new Timer(async (state) =>
            {
                HttpClient httpClient = new HttpClient();
                httpClient.DefaultRequestHeaders.Add("Authorization", $"bearer {token}");
                var message = await httpClient.GetAsync(url);
            }, null, 1000, 1000 * 60 * 10);
        }

The callback is defined in another controller CallbackController

       [HttpGet]
        public async Task GetAsync()
        {
            _logger.LogWarning($"Callback called {DateTime.Now}");
            string owner = User.GetDisplayName();
            // Below is for testing multi-tenants
            var result = await _tokenAcquisition.GetAuthenticationResultForUserAsync(new string[] { "user.read" }).ConfigureAwait(false); // for testing OBO

            if (result.AuthenticationResultMetadata.TokenSource == Microsoft.Identity.Client.TokenSource.IdentityProvider)
            {
              _logger.LogWarning($"OBO access token refreshed {DateTime.Now}");
            }
        }

Expected behavior Passing the same (expired) incoming token (as a key), given that there is a refresh token associated to the (expired) OBO access token that was generated from the incoming (expired) token, this OBO token should be refreshed, and the long running process should happen for ever (as the refresh token will also be refreshed). See the protocol documentation for On behalf of. The refresh token is returned (when offline_access is requested), for this scenario.

Therefore , with the repro code above, we should see, after 1h, a log warning "OBO access token refreshed "

Actual behavior EVO does not accept the incoming (expired) token, of course, but MSAL.NET doesn't even attempt to refresh the OBO access token, and there is an exception.

Microsoft.Identity.Client.MsalUiRequiredException HResult=0x80131500 Message=AADSTS500133: Assertion is not within its valid time range. Ensure that the access token is not expired before using it for user assertion, or request a new token. Current time: 2021-04-17T19:50:21.6663073Z, expiry time of assertion 2021-04-17T19:50:15.0000000Z. Trace ID: ee96f1de-d755-46e7-811e-aba122bd4700 Correlation ID: 1a64be83-e614-444a-a7ce-7c2f570cf35a Timestamp: 2021-04-17 19:50:21Z Source=Microsoft.Identity.Client StackTrace: at Microsoft.Identity.Client.Internal.Requests.RequestBase.HandleTokenRefreshError(MsalServiceException e, MsalAccessTokenCacheItem cachedAccessTokenItem) at Microsoft.Identity.Client.Internal.Requests.OnBehalfOfRequest.d2.MoveNext() at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw() at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task) at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task) at System.Runtime.CompilerServices.ConfiguredTaskAwaitable`1.ConfiguredTaskAwaiter.GetResult() at Microsoft.Identity.Client.Internal.Requests.RequestBase.d13.MoveNext() at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw() at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task) at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task) at System.Runtime.CompilerServices.ConfiguredTaskAwaitable1.ConfiguredTaskAwaiter.GetResult() at Microsoft.Identity.Client.ApiConfig.Executors.ConfidentialClientExecutor.<ExecuteAsync>d__4.MoveNext() at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw() at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task) at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task) at System.Runtime.CompilerServices.ConfiguredTaskAwaitable1.ConfiguredTaskAwaiter.GetResult() at Microsoft.Identity.Web.TokenAcquisition.d__26.MoveNext() in C:\gh\microsoft-identity-web\src\Microsoft.Identity.Web\TokenAcquisition.cs:line 631

This exception was originally thrown at this call stack: Microsoft.Identity.Client.Internal.Requests.RequestBase.HandleTokenRefreshError(Microsoft.Identity.Client.MsalServiceException, Microsoft.Identity.Client.Cache.Items.MsalAccessTokenCacheItem) Microsoft.Identity.Client.Internal.Requests.OnBehalfOfRequest.ExecuteAsync(System.Threading.CancellationToken) System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw() System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(System.Threading.Tasks.Task) System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(System.Threading.Tasks.Task) System.Runtime.CompilerServices.ConfiguredTaskAwaitable.ConfiguredTaskAwaiter.GetResult() Microsoft.Identity.Client.Internal.Requests.RequestBase.RunAsync(System.Threading.CancellationToken) System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw() System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(System.Threading.Tasks.Task) System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(System.Threading.Tasks.Task) ... [Call Stack Truncated]

[SirElTomato]

Would it be possible to schedule a call to go through this to see where the problem is? This has been ongoing for a long time

[bgavrilMS]

Yes, let's meet

[jennyf19]

@SirElTomato which access token are you using as the cache key for the long running process? Is it the token that you got from AcquireTokenOnBehalfOfUser or the token sent to your web API by the client? nevermind, see you answered this above. what do you do with the user object? how is it stored between calls to the api?

[SirElTomato]

I have tried it with both. Which should I be using? Currently I am updating the user object with the new access token which I get from the AcquireTokenOnBehalfOf call.

[jennyf19]

You should be using the token sent to your web API by the client as the cache key. Using the token from AcquireTokenOnBehalfOfUser will not work.

[lukaspechar]

@bgavrilMS thanks for the chat yesterday. I'm just going to update the thread here. Unfortunately the cache table is empty again. Something seems to be cleaning it up.

[bgavrilMS]

I was under the impression that you are not even running your asp.net website after 1h. Could it be some Cosmos cleanup policy that gets rid of it?

[jennyf19]

Can someone provide a summary of the discussion yesterday? thanks. @bgavrilMS @SirElTomato @lukaspechar

[SirElTomato]

Sure.

• Switch provider which is used to create the Graph Client. I am now using a DelegateAuthenticationProvider instead of OnBehalfOfProvider. There seemed to be an issue with OnBehalfOfProvider although I'm not sure what:

          var authProvider = new DelegateAuthenticationProvider((request) =>
          {
              request.Headers.Authorization =
                  new System.Net.Http.Headers.AuthenticationHeaderValue("Bearer", token.AccessToken);
  
              return Task.CompletedTask;
          });
  
          var graphClient = new GraphServiceClient(authProvider);

• Ensure original jwt assertion from client is used as the token stored on our user object.

      public async Task GetAccessTokenWithJWT(string userId, IEnumerable<string> scopes, string jwt)
      {
          await AquireTokenOnBehalfOf(scopes, jwt);
          var user = _userRepo.GetByIdAndPartitionKeyOrDefault(userId, userId);
          user.MicrosoftIdentity = jwt;
  
          _userRepo.Update(user);
      }

• Ensure the correct scope(s) is used in the GetAccessTokenWithJWT (and subsequently the AcquireTokenOnBehalfOf) call. In this case it was "mail.read".

We then executed the code with the changes.

• Acquired a token for the user
• Checked that only 1 entry was created on the cosmos cache container
• Checked that the correct token was stored on the user object for future use
• Ensured that when we retrieved a token again that it came from the cache and subsequently used it to call graph api
• Changed the expiry date value of the access token in the cache so that it had expired, tried to get a new token and ensured that it used the identity provider to get a new token (suggesting it used the refresh token) and subsequently used it to call graph api

This all worked great and proved that the caching and refreshing of tokens was working correctly.

Lukas then tried it again yesterday (the following day) and found that the cache was empty and therefore it failed when trying to retrieve a token.

---

We also discussed:

• Changing the confidential client application to be per request instead of a singleton which has been changed.
• How revoking of tokens would work in OBO flow. (instruct the user to revoke consent from the account portal, clear the original jwt token from the user object and remove associated tokens in the cache using the custom set key of the cache when this becomes available #2733).
• Refresh tokens work for 3 months, should handle MsalUiRequiredException to prompt re-consent from the client.

[SirElTomato]

Found that TTL was set on the cosmos cache container, have removed this so expect it to work now.

[jmprieur]

Thanks for the update @SirElTomato

[SirElTomato]

Trying to test it but running into issues with various microsoft nuget packages, currently I am experiencing this

[SirElTomato]

All working, forgot to say you can close this. Thanks for all your help.