Skip to content
This repository has been archived by the owner on Jun 30, 2023. It is now read-only.

AcquireTokenSilentAsync fails to refresh access tokens #1477

Closed
7 tasks
sourcefile opened this issue Jan 10, 2019 · 23 comments
Closed
7 tasks

AcquireTokenSilentAsync fails to refresh access tokens #1477

sourcefile opened this issue Jan 10, 2019 · 23 comments

Comments

@sourcefile
Copy link

Which Version of ADAL are you using ?
Note that to get help, you need to run the latest preview or non-preview version
For MSAL, please log issues to https://github.com/AzureAD/microsoft-authentication-library-for-dotnet

ADAL 4.4.2

Which platform has the issue?

Xamarin.Forms / Xamarin.Android

What authentication flow has the issue?

  • Desktop / Mobile
    • Interactive
    • Integrated Windows Auth
    • Username Password
    • Device code flow (browserless)
  • Web App
    • Authorization code
    • OBO
  • Web API
    • OBO

Other? - please describe;
Mobile -> Silent Authentication

Repro
When using below code in combination with the MS Authenticator Broker, the app seems to be unable to silently refresh the access token after it expires.

1.) Install broker
2.) Start application
3.) Sign in with the correct account. Everything works, data is retrieved as expected.
4.) Wait an hour for the access token to expire
5.) Start a new call to the same resource. AcquireTokenSilentAsync fails, forcing the user to go through interaction with the broker.

By providing the UserId, I can minimize the impact on the user. However, they still see the broker activities pass by and some of our applications are required to run in the background for longer periods with constant data transfer, so this workaround is not viable for me at the time.

public async Task EnsureLoggedInAsync()
{
    var context = new AuthenticationContext($"https://login.microsoftonline.com/{_tenantId}");
    var tokens = context.TokenCache.ReadItems().Where(t => t.Resource == _resource);
    var userId = tokens.GroupBy(t => t.DisplayableId).Count() == 1 ? new UserIdentifier(tokens.GroupBy(t => t.DisplayableId).Single().First().DisplayableId, UserIdentifierType.RequiredDisplayableId) : null;

    try
    {
        if (userId == null)
        {
            User = await context.AcquireTokenSilentAsync(_resource, _clientId);
        }
        else
        {
            User = await context.AcquireTokenSilentAsync(_resource, _clientId, userId);
        }
    }
    catch (AdalException ex)
    {
    
        if (ex.ErrorCode == AdalError.FailedToAcquireTokenSilently || ex.ErrorCode == AdalError.InteractionRequired)
        {

            var param = new PlatformParameters(CrossCurrentActivity.Current.Activity, _useBroker, PromptBehavior.Auto);
            if (userId == null)
            {
                User = await context.AcquireTokenAsync(_resource, _clientId, new Uri(_redirectUri), param);
            }
            else
            {
                User = await context.AcquireTokenAsync(_resource, _clientId, new Uri(_redirectUri), param, userId);
            }
        }
        else
        {
            // Unexpected kind of AdalException. Throw
            throw;
        }
    }

Expected behavior
AcquireTokenSilentAsync should be able to retrieve a new access token after the previous one expires

Actual behavior
AcquireTokenSilentAsync fails, forcing an interactive refresh.

Possible Solution

Additional context/ Logs / Screenshots
I did notice in the logs caching the refresh token is skipped because of missing ClientInfo. However, I can't find no such property for me to manipulate from my code.

Logs:

[Mono] Assembly Ref addref Microsoft.IdentityModel.Clients.ActiveDirectory[0x710543cf00] -> System.Core[0x7105570900]: 8
[] 2019-01-10T06:52:07.3923390Z: 650c5fbe-2865-4563-abc3-3d8396061c84 - AdalLoggerBase.cs: ADAL PCL.Android with assembly version '4.4.2.0', file version '4.4.2.0' and informational version '4.4.2' is running...
[] 2019-01-10T06:52:07.4517570Z: 650c5fbe-2865-4563-abc3-3d8396061c84 - AdalLoggerBase.cs: === Token Acquisition started: 
[] 	CacheType: null
[] 	Authentication Target: User
[] 	, Authority Host: login.microsoftonline.com

[Mono] Assembly Ref addref System.Runtime.Serialization[0x710d096b00] -> System.Core[0x7105570900]: 10
[] 2019-01-10T06:52:09.1940290Z: 650c5fbe-2865-4563-abc3-3d8396061c84 - AdalLoggerBase.cs: Loading from cache.
[] 2019-01-10T06:52:09.2130760Z: 650c5fbe-2865-4563-abc3-3d8396061c84 - AdalLoggerBase.cs: Looking up cache for a token...
[] 2019-01-10T06:52:09.2282010Z: 650c5fbe-2865-4563-abc3-3d8396061c84 - AdalLoggerBase.cs: No matching token was found in the cache
[] 2019-01-10T06:52:09.2288330Z: 650c5fbe-2865-4563-abc3-3d8396061c84 - AdalLoggerBase.cs: Checking MSAL cache for user token cache

[] 2019-01-10T06:52:09.2497610Z: 650c5fbe-2865-4563-abc3-3d8396061c84 - AdalLoggerBase.cs: Looking up cache for a token...
[] 2019-01-10T06:52:09.2502830Z: 650c5fbe-2865-4563-abc3-3d8396061c84 - AdalLoggerBase.cs: No matching token was found in the cache
[] 2019-01-10T06:52:09.2504970Z: 650c5fbe-2865-4563-abc3-3d8396061c84 - AdalLoggerBase.cs: Checking MSAL cache for user token cache
[] 2019-01-10T06:52:09.2520870Z: 650c5fbe-2865-4563-abc3-3d8396061c84 - AdalLoggerBase.cs: Looking up cache for a token...
[] 2019-01-10T06:52:09.2525360Z: 650c5fbe-2865-4563-abc3-3d8396061c84 - AdalLoggerBase.cs: No matching token was found in the cache
[] 2019-01-10T06:52:09.2527490Z: 650c5fbe-2865-4563-abc3-3d8396061c84 - AdalLoggerBase.cs: Checking MSAL cache for user token cache
[] 2019-01-10T06:52:09.2549190Z: 650c5fbe-2865-4563-abc3-3d8396061c84 - AdalLoggerBase.cs: Looking up cache for a token...
[] 2019-01-10T06:52:09.2554510Z: 650c5fbe-2865-4563-abc3-3d8396061c84 - AdalLoggerBase.cs: No matching token was found in the cache
[] 2019-01-10T06:52:09.2558070Z: 650c5fbe-2865-4563-abc3-3d8396061c84 - AdalLoggerBase.cs: Checking MSAL cache for user token cache
[] 2019-01-10T06:52:09.2580330Z: 650c5fbe-2865-4563-abc3-3d8396061c84 - AdalLoggerBase.cs: Looking up cache for a token...
[] 2019-01-10T06:52:09.2586130Z: 650c5fbe-2865-4563-abc3-3d8396061c84 - AdalLoggerBase.cs: No matching token was found in the cache
[] 2019-01-10T06:52:09.2588920Z: 650c5fbe-2865-4563-abc3-3d8396061c84 - AdalLoggerBase.cs: Checking MSAL cache for user token cache
[] 2019-01-10T06:52:09.2604860Z: 650c5fbe-2865-4563-abc3-3d8396061c84 - AdalLoggerBase.cs: Looking up cache for a token...
[] 2019-01-10T06:52:09.2609130Z: 650c5fbe-2865-4563-abc3-3d8396061c84 - AdalLoggerBase.cs: No matching token was found in the cache
[] 2019-01-10T06:52:09.2611180Z: 650c5fbe-2865-4563-abc3-3d8396061c84 - AdalLoggerBase.cs: Checking MSAL cache for user token cache
[] 2019-01-10T06:52:09.2668270Z: 650c5fbe-2865-4563-abc3-3d8396061c84 - AdalLoggerBase.cs: No token matching arguments found in the cache
[] 2019-01-10T06:52:09.2939640Z: 650c5fbe-2865-4563-abc3-3d8396061c84 - AdalLoggerBase.cs: Exception type: Microsoft.IdentityModel.Clients.ActiveDirectory.AdalSilentTokenAcquisitionException
[] , ErrorCode: failed_to_acquire_token_silently
[] 
[]   at Microsoft.IdentityModel.Clients.ActiveDirectory.Internal.Flows.AcquireTokenSilentHandler.SendTokenRequestAsync () [0x00022] in <0ca7acd3a30a40188ed7532e0d2c13ab>:0 
[]   at Microsoft.IdentityModel.Clients.ActiveDirectory.Internal.Flows.AcquireTokenHandlerBase+<CheckAndAcquireTokenUsingBrokerAsync>d__55.MoveNext () [0x0009a] in <0ca7acd3a30a40188ed7532e0d2c13ab>:0 
[] --- End of stack trace from previous location where exception was thrown ---
[]   at Microsoft.IdentityModel.Clients.ActiveDirectory.Internal.Flows.AcquireTokenHandlerBase+<RunAsync>d__53.MoveNext () [0x004b1] in <0ca7acd3a30a40188ed7532e0d2c13ab>:0 
[] 2019-01-10T06:52:09.3066100Z: 2b620fc9-90ce-4c3f-8969-1d728f134b5b - AdalLoggerBase.cs: ADAL PCL.Android with assembly version '4.4.2.0', file version '4.4.2.0' and informational version '4.4.2' is running...
[] 2019-01-10T06:52:09.3073190Z: 2b620fc9-90ce-4c3f-8969-1d728f134b5b - AdalLoggerBase.cs: === Token Acquisition started: 
[] 	CacheType: null
[] 	Authentication Target: User
[] 	, Authority Host: login.microsoftonline.com
[] 2019-01-10T06:52:09.3161010Z: 2b620fc9-90ce-4c3f-8969-1d728f134b5b - AdalLoggerBase.cs: Loading from cache.
[] 2019-01-10T06:52:09.3178620Z: 2b620fc9-90ce-4c3f-8969-1d728f134b5b - AdalLoggerBase.cs: Looking up cache for a token...
[] 2019-01-10T06:52:09.3183870Z: 2b620fc9-90ce-4c3f-8969-1d728f134b5b - AdalLoggerBase.cs: No matching token was found in the cache
[] 2019-01-10T06:52:09.3186650Z: 2b620fc9-90ce-4c3f-8969-1d728f134b5b - AdalLoggerBase.cs: Checking MSAL cache for user token cache
[] 2019-01-10T06:52:09.3202210Z: 2b620fc9-90ce-4c3f-8969-1d728f134b5b - AdalLoggerBase.cs: Looking up cache for a token...
[] 2019-01-10T06:52:09.3206980Z: 2b620fc9-90ce-4c3f-8969-1d728f134b5b - AdalLoggerBase.cs: No matching token was found in the cache
[] 2019-01-10T06:52:09.3209990Z: 2b620fc9-90ce-4c3f-8969-1d728f134b5b - AdalLoggerBase.cs: Checking MSAL cache for user token cache
[] 2019-01-10T06:52:09.3227690Z: 2b620fc9-90ce-4c3f-8969-1d728f134b5b - AdalLoggerBase.cs: Looking up cache for a token...
[] 2019-01-10T06:52:09.3232400Z: 2b620fc9-90ce-4c3f-8969-1d728f134b5b - AdalLoggerBase.cs: No matching token was found in the cache
[] 2019-01-10T06:52:09.3234660Z: 2b620fc9-90ce-4c3f-8969-1d728f134b5b - AdalLoggerBase.cs: Checking MSAL cache for user token cache
[] 2019-01-10T06:52:09.3250270Z: 2b620fc9-90ce-4c3f-8969-1d728f134b5b - AdalLoggerBase.cs: Looking up cache for a token...
[] 2019-01-10T06:52:09.3254660Z: 2b620fc9-90ce-4c3f-8969-1d728f134b5b - AdalLoggerBase.cs: No matching token was found in the cache
[] 2019-01-10T06:52:09.3256680Z: 2b620fc9-90ce-4c3f-8969-1d728f134b5b - AdalLoggerBase.cs: Checking MSAL cache for user token cache
[] 2019-01-10T06:52:09.3272730Z: 2b620fc9-90ce-4c3f-8969-1d728f134b5b - AdalLoggerBase.cs: Looking up cache for a token...
[] 2019-01-10T06:52:09.3277690Z: 2b620fc9-90ce-4c3f-8969-1d728f134b5b - AdalLoggerBase.cs: No matching token was found in the cache
[] 2019-01-10T06:52:09.3280600Z: 2b620fc9-90ce-4c3f-8969-1d728f134b5b - AdalLoggerBase.cs: Checking MSAL cache for user token cache
[] 2019-01-10T06:52:09.3297970Z: 2b620fc9-90ce-4c3f-8969-1d728f134b5b - AdalLoggerBase.cs: Looking up cache for a token...
[] 2019-01-10T06:52:09.3302390Z: 2b620fc9-90ce-4c3f-8969-1d728f134b5b - AdalLoggerBase.cs: No matching token was found in the cache
[] 2019-01-10T06:52:09.3304420Z: 2b620fc9-90ce-4c3f-8969-1d728f134b5b - AdalLoggerBase.cs: Checking MSAL cache for user token cache

[] 2019-01-10T06:52:09.4228360Z: 2b620fc9-90ce-4c3f-8969-1d728f134b5b - AdalLoggerBase.cs: Broker supports to add user through app
[] 2019-01-10T06:52:09.4603100Z: 2b620fc9-90ce-4c3f-8969-1d728f134b5b - AdalLoggerBase.cs: Broker supports to add user through app
[] 2019-01-10T06:52:09.4612820Z: 2b620fc9-90ce-4c3f-8969-1d728f134b5b - AdalLoggerBase.cs: It switched to broker for context: nl.ns.ccm.spikes.SecuredToDo
[] 2019-01-10T06:52:09.4627300Z: 2b620fc9-90ce-4c3f-8969-1d728f134b5b - AdalLoggerBase.cs: User is not specified for background token request
[] 2019-01-10T06:52:09.4636020Z: 2b620fc9-90ce-4c3f-8969-1d728f134b5b - AdalLoggerBase.cs: Token is not returned from backgroud call
[] 2019-01-10T06:52:09.4641460Z: 2b620fc9-90ce-4c3f-8969-1d728f134b5b - AdalLoggerBase.cs: Launch activity for Authenticator
[] 2019-01-10T06:52:09.4647260Z: 2b620fc9-90ce-4c3f-8969-1d728f134b5b - AdalLoggerBase.cs: Starting Authentication Activity
[] 2019-01-10T06:52:09.4652870Z: 2b620fc9-90ce-4c3f-8969-1d728f134b5b - AdalLoggerBase.cs: Initial request to authenticator
[] 2019-01-10T06:52:09.9696200Z: 2b620fc9-90ce-4c3f-8969-1d728f134b5b - AdalLoggerBase.cs: Calling activity pid:18465 tid:18625uid:10437

[] 2019-01-10T06:52:15.3897030Z: 00000000-0000-0000-0000-000000000000 - AdalLoggerBase.cs: Received Activity Result(2004)

[] 2019-01-10T06:52:15.4463210Z: 2b620fc9-90ce-4c3f-8969-1d728f134b5b - AdalLoggerBase.cs: Storing token in the cache...

[] 2019-01-10T06:52:15.4522010Z: 2b620fc9-90ce-4c3f-8969-1d728f134b5b - AdalLoggerBase.cs: An item was stored in the cache

[] 2019-01-10T06:52:15.4668290Z: 00000000-0000-0000-0000-000000000000 - AdalLoggerBase.cs: Client Info is missing. Skipping MSAL refresh token cache write

[] 2019-01-10T06:52:15.4950760Z: 2b620fc9-90ce-4c3f-8969-1d728f134b5b - AdalLoggerBase.cs: === Token Acquisition finished successfully. An access token was returned: Expiration Time: 10-1-2019 07:52:13 +00:00
[] 2019-01-10T06:52:15.5069270Z: 00000000-0000-0000-0000-000000000000 - AdalLoggerBase.cs: Serializing token cache with 1 items.
@sourcefile
Copy link
Author

Any update on this? As mentioned in the issue, it's quite a big problem for one of our application. Any help on the matter would be greatly appreciated.

@jmprieur
Copy link
Contributor

@bgavrilMS : this is similar to some of the issues you are investigating?

@bgavrilMS
Copy link
Member

Possibly. @sourcefile - could you please update to ADAL 4.5 and repost the logs (you can email them at [email protected] as they might contain PII). We've added a few fixes in this area in ADAL 4.5 and also we have added a LOT more logging to understand how the broker is failing.

@sourcefile
Copy link
Author

I tried upgrading to ADAL 4.5 and running again. Unfortunately, the issue still persists.

As requested, I’ve submitted the authenticator logs. The ID is BQ3AH6QZ.

As a side note, I should inform you there is also a support ticket running from Azure regarding this topic. To prevent those issues from going out of sync, I'll add this ticket ID as well: 119012125000270

@bgavrilMS
Copy link
Member

Hi @sourcefile - I would require the ADAL logs again please, not the Authenticator logs.

I am not sure where you've submitted the logs - could you just post them here if they have no PII or send them via email?

@sourcefile
Copy link
Author

Hi @bgavrilMS I've submitted the logs via the option in the MS Authenticator itself ([Help]-->[Send Logs]).

At any rate, I made a retry since I focussed on the Authenticator logs last time. The ADAL logs are below:

[] 2019-01-24T12:10:45.7076190Z: f0c8ecbb-3461-4649-9f30-a429b9a51b10 - AdalLoggerBase.cs: Loading from cache.
[] 2019-01-24T12:10:45.7398650Z: f0c8ecbb-3461-4649-9f30-a429b9a51b10 - AdalLoggerBase.cs: Looking up cache for a token...
[] 2019-01-24T12:10:45.7606500Z: f0c8ecbb-3461-4649-9f30-a429b9a51b10 - AdalLoggerBase.cs: No matching token was found in the cache
[] 2019-01-24T12:10:45.7612460Z: f0c8ecbb-3461-4649-9f30-a429b9a51b10 - AdalLoggerBase.cs: Checking MSAL cache for user token cache
[] 2019-01-24T12:10:45.7839710Z: f0c8ecbb-3461-4649-9f30-a429b9a51b10 - AdalLoggerBase.cs: Looking up cache for a token...
[] 2019-01-24T12:10:45.7845060Z: f0c8ecbb-3461-4649-9f30-a429b9a51b10 - AdalLoggerBase.cs: No matching token was found in the cache
[] 2019-01-24T12:10:45.7847380Z: f0c8ecbb-3461-4649-9f30-a429b9a51b10 - AdalLoggerBase.cs: Checking MSAL cache for user token cache
[] 2019-01-24T12:10:45.7866350Z: f0c8ecbb-3461-4649-9f30-a429b9a51b10 - AdalLoggerBase.cs: Looking up cache for a token...
[] 2019-01-24T12:10:45.7872410Z: f0c8ecbb-3461-4649-9f30-a429b9a51b10 - AdalLoggerBase.cs: No matching token was found in the cache
[] 2019-01-24T12:10:45.7891780Z: f0c8ecbb-3461-4649-9f30-a429b9a51b10 - AdalLoggerBase.cs: Checking MSAL cache for user token cache
[] 2019-01-24T12:10:45.7912190Z: f0c8ecbb-3461-4649-9f30-a429b9a51b10 - AdalLoggerBase.cs: Looking up cache for a token...
[] 2019-01-24T12:10:45.7917980Z: f0c8ecbb-3461-4649-9f30-a429b9a51b10 - AdalLoggerBase.cs: No matching token was found in the cache
[] 2019-01-24T12:10:45.7921140Z: f0c8ecbb-3461-4649-9f30-a429b9a51b10 - AdalLoggerBase.cs: Checking MSAL cache for user token cache
[] 2019-01-24T12:10:45.7937710Z: f0c8ecbb-3461-4649-9f30-a429b9a51b10 - AdalLoggerBase.cs: Looking up cache for a token...
[] 2019-01-24T12:10:45.7942960Z: f0c8ecbb-3461-4649-9f30-a429b9a51b10 - AdalLoggerBase.cs: No matching token was found in the cache
[] 2019-01-24T12:10:45.7945520Z: f0c8ecbb-3461-4649-9f30-a429b9a51b10 - AdalLoggerBase.cs: Checking MSAL cache for user token cache
[] 2019-01-24T12:10:45.7960560Z: f0c8ecbb-3461-4649-9f30-a429b9a51b10 - AdalLoggerBase.cs: Looking up cache for a token...
[] 2019-01-24T12:10:45.7965600Z: f0c8ecbb-3461-4649-9f30-a429b9a51b10 - AdalLoggerBase.cs: No matching token was found in the cache
[] 2019-01-24T12:10:45.7969060Z: f0c8ecbb-3461-4649-9f30-a429b9a51b10 - AdalLoggerBase.cs: Checking MSAL cache for user token cache
[] 2019-01-24T12:10:45.8530720Z: f0c8ecbb-3461-4649-9f30-a429b9a51b10 - AdalLoggerBase.cs: BrokerProxy: Found the Authenticator on the device
[] 2019-01-24T12:10:45.8733120Z: f0c8ecbb-3461-4649-9f30-a429b9a51b10 - AdalLoggerBase.cs: BrokerProxy: Broker supports adding accounts
[] 2019-01-24T12:10:45.8979120Z: f0c8ecbb-3461-4649-9f30-a429b9a51b10 - AdalLoggerBase.cs: BrokerProxy: Broker supports adding accounts
[] 2019-01-24T12:10:45.8986840Z: f0c8ecbb-3461-4649-9f30-a429b9a51b10 - AdalLoggerBase.cs: It switched to broker for context: nl.ns.ccm.spikes.securedtodo
[] 2019-01-24T12:10:45.8996700Z: f0c8ecbb-3461-4649-9f30-a429b9a51b10 - AdalLoggerBase.cs: User is not specified for background token request
[] 2019-01-24T12:10:45.9002040Z: f0c8ecbb-3461-4649-9f30-a429b9a51b10 - AdalLoggerBase.cs: Token is not returned from backgroud call
[] 2019-01-24T12:10:45.9005510Z: f0c8ecbb-3461-4649-9f30-a429b9a51b10 - AdalLoggerBase.cs: Launch activity for Authenticator
[] 2019-01-24T12:10:45.9008120Z: f0c8ecbb-3461-4649-9f30-a429b9a51b10 - AdalLoggerBase.cs: Starting Authentication Activity
[] 2019-01-24T12:10:45.9010840Z: f0c8ecbb-3461-4649-9f30-a429b9a51b10 - AdalLoggerBase.cs: Initial request to authenticator
[] 2019-01-24T12:10:46.5784270Z: f0c8ecbb-3461-4649-9f30-a429b9a51b10 - AdalLoggerBase.cs: Calling activity pid:32319 tid:32457uid:10455
[] 2019-01-24T12:11:04.5247790Z: 00000000-0000-0000-0000-000000000000 - AdalLoggerBase.cs: Received Activity Result(2004)
[] 2019-01-24T12:11:04.5981780Z: f0c8ecbb-3461-4649-9f30-a429b9a51b10 - AdalLoggerBase.cs: Storing token in the cache...
[] 2019-01-24T12:11:04.6257200Z: 00000000-0000-0000-0000-000000000000 - AdalLoggerBase.cs: Client Info is missing. Skipping MSAL refresh token cache write
[] 2019-01-24T12:11:04.6591210Z: f0c8ecbb-3461-4649-9f30-a429b9a51b10 - AdalLoggerBase.cs: === Token Acquisition finished successfully. An access token was returned: Expiration Time: 24-1-2019 13:11:03 +00:00
[] 2019-01-24T12:11:04.6682370Z: 00000000-0000-0000-0000-000000000000 - AdalLoggerBase.cs: Serializing token cache with 1 items.

-- After accesstoken has expired --

[] 2019-01-24T13:12:15.9762790Z: 00000000-0000-0000-0000-000000000000 - AdalLoggerBase.cs: Deserialized 1 items to token cache.
[] 2019-01-24T13:12:16.0004490Z: b1f8c115-fd12-4a18-8923-75e72015e984 - AdalLoggerBase.cs: BrokerProxy: Getting the Android context
[] 2019-01-24T13:12:16.0029770Z: b1f8c115-fd12-4a18-8923-75e72015e984 - AdalLoggerBase.cs: ADAL PCL.Android with assembly version '4.5.0.0', file version '4.5.0.0' and informational version '4.5.0' is running...
[] 2019-01-24T13:12:16.0039020Z: b1f8c115-fd12-4a18-8923-75e72015e984 - AdalLoggerBase.cs: === Token Acquisition started: 
[] 	CacheType: Microsoft.IdentityModel.Clients.ActiveDirectory.TokenCache (1 items)
[] 	Authentication Target: User
[] 	, Authority Host: login.microsoftonline.com
[] 2019-01-24T13:12:16.0058560Z: b1f8c115-fd12-4a18-8923-75e72015e984 - AdalLoggerBase.cs: Loading from cache.
[] 2019-01-24T13:12:16.0122510Z: 00000000-0000-0000-0000-000000000000 - AdalLoggerBase.cs: Deserialized 1 items to token cache.
[] 2019-01-24T13:12:16.0132220Z: b1f8c115-fd12-4a18-8923-75e72015e984 - AdalLoggerBase.cs: Looking up cache for a token...
[] 2019-01-24T13:12:16.0208390Z: b1f8c115-fd12-4a18-8923-75e72015e984 - AdalLoggerBase.cs: An item matching the requested resource was found in the cache
[] 2019-01-24T13:12:16.0278690Z: b1f8c115-fd12-4a18-8923-75e72015e984 - AdalLoggerBase.cs: An expired or near expiry token was found in the cache
[] 2019-01-24T13:12:16.0333840Z: b1f8c115-fd12-4a18-8923-75e72015e984 - AdalLoggerBase.cs: An old item was removed from the cache
[] 2019-01-24T13:12:16.0345750Z: b1f8c115-fd12-4a18-8923-75e72015e984 - AdalLoggerBase.cs: Looking up cache for a token...
[] 2019-01-24T13:12:16.0356070Z: b1f8c115-fd12-4a18-8923-75e72015e984 - AdalLoggerBase.cs: No matching token was found in the cache
[] 2019-01-24T13:12:16.0361020Z: b1f8c115-fd12-4a18-8923-75e72015e984 - AdalLoggerBase.cs: Checking MSAL cache for user token cache
[] 2019-01-24T13:12:16.0395960Z: b1f8c115-fd12-4a18-8923-75e72015e984 - AdalLoggerBase.cs: Looking up cache for a token...
[] 2019-01-24T13:12:16.0401840Z: b1f8c115-fd12-4a18-8923-75e72015e984 - AdalLoggerBase.cs: No matching token was found in the cache
[] 2019-01-24T13:12:16.0405850Z: b1f8c115-fd12-4a18-8923-75e72015e984 - AdalLoggerBase.cs: Checking MSAL cache for user token cache
[] 2019-01-24T13:12:16.0424730Z: b1f8c115-fd12-4a18-8923-75e72015e984 - AdalLoggerBase.cs: Looking up cache for a token...
[] 2019-01-24T13:12:16.0430430Z: b1f8c115-fd12-4a18-8923-75e72015e984 - AdalLoggerBase.cs: No matching token was found in the cache
[] 2019-01-24T13:12:16.0434360Z: b1f8c115-fd12-4a18-8923-75e72015e984 - AdalLoggerBase.cs: Checking MSAL cache for user token cache
[] 2019-01-24T13:12:16.0463190Z: b1f8c115-fd12-4a18-8923-75e72015e984 - AdalLoggerBase.cs: Looking up cache for a token...
[] 2019-01-24T13:12:16.0469140Z: b1f8c115-fd12-4a18-8923-75e72015e984 - AdalLoggerBase.cs: No matching token was found in the cache
[] 2019-01-24T13:12:16.0472990Z: b1f8c115-fd12-4a18-8923-75e72015e984 - AdalLoggerBase.cs: Checking MSAL cache for user token cache
[] 2019-01-24T13:12:16.0497000Z: b1f8c115-fd12-4a18-8923-75e72015e984 - AdalLoggerBase.cs: Looking up cache for a token...
[] 2019-01-24T13:12:16.0501660Z: b1f8c115-fd12-4a18-8923-75e72015e984 - AdalLoggerBase.cs: No matching token was found in the cache
[] 2019-01-24T13:12:16.0505940Z: b1f8c115-fd12-4a18-8923-75e72015e984 - AdalLoggerBase.cs: Checking MSAL cache for user token cache
[] 2019-01-24T13:12:16.0574490Z: b1f8c115-fd12-4a18-8923-75e72015e984 - AdalLoggerBase.cs: No token matching arguments found in the cache
[] 2019-01-24T13:12:16.0892240Z: b1f8c115-fd12-4a18-8923-75e72015e984 - AdalLoggerBase.cs: Exception type: Microsoft.IdentityModel.Clients.ActiveDirectory.AdalSilentTokenAcquisitionException
[] , ErrorCode: failed_to_acquire_token_silently
[] 
[]   at Microsoft.IdentityModel.Clients.ActiveDirectory.Internal.Flows.AcquireTokenSilentHandler.SendTokenRequestAsync () [0x0001d] in C:\agent1\_work\70\s\src\Microsoft.IdentityModel.Clients.ActiveDirectory\Internal\Flows\AcquireTokenSilentHandler.cs:64 
[]   at Microsoft.IdentityModel.Clients.ActiveDirectory.Internal.Flows.AcquireTokenHandlerBase+<CheckAndAcquireTokenUsingBrokerAsync>d__60.MoveNext () [0x0009a] in C:\agent1\_work\70\s\src\Microsoft.IdentityModel.Clients.ActiveDirectory\Internal\Flows\AcquireTokenHandlerBase.cs:257 
[] --- End of stack trace from previous location where exception was thrown ---
[]   at Microsoft.IdentityModel.Clients.ActiveDirectory.Internal.Flows.AcquireTokenHandlerBase+<RunAsync>d__58.MoveNext () [0x00469] in C:\agent1\_work\70\s\src\Microsoft.IdentityModel.Clients.ActiveDirectory\Internal\Flows\AcquireTokenHandlerBase.cs:195 
[] 2019-01-24T13:12:16.0937460Z: 00000000-0000-0000-0000-000000000000 - AdalLoggerBase.cs: Serializing token cache with 0 items.
[] 2019-01-24T13:12:16.1059970Z: c05e8c87-3ec0-41e6-8b58-eb3376c2b2ae - AdalLoggerBase.cs: BrokerProxy: Getting the Android context
[] 2019-01-24T13:12:16.1069890Z: c05e8c87-3ec0-41e6-8b58-eb3376c2b2ae - AdalLoggerBase.cs: ADAL PCL.Android with assembly version '4.5.0.0', file version '4.5.0.0' and informational version '4.5.0' is running...
[] 2019-01-24T13:12:16.1075930Z: c05e8c87-3ec0-41e6-8b58-eb3376c2b2ae - AdalLoggerBase.cs: === Token Acquisition started: 
[] 	CacheType: Microsoft.IdentityModel.Clients.ActiveDirectory.TokenCache (0 items)
[] 	Authentication Target: User
[] 	, Authority Host: login.microsoftonline.com
[] 2019-01-24T13:12:16.1084710Z: c05e8c87-3ec0-41e6-8b58-eb3376c2b2ae - AdalLoggerBase.cs: Loading from cache.
[] 2019-01-24T13:12:16.1101740Z: 00000000-0000-0000-0000-000000000000 - AdalLoggerBase.cs: Deserialized 0 items to token cache.
[] 2019-01-24T13:12:16.1109650Z: c05e8c87-3ec0-41e6-8b58-eb3376c2b2ae - AdalLoggerBase.cs: Looking up cache for a token...
[] 2019-01-24T13:12:16.1114490Z: c05e8c87-3ec0-41e6-8b58-eb3376c2b2ae - AdalLoggerBase.cs: No matching token was found in the cache
[] 2019-01-24T13:12:16.1118150Z: c05e8c87-3ec0-41e6-8b58-eb3376c2b2ae - AdalLoggerBase.cs: Checking MSAL cache for user token cache
[] 2019-01-24T13:12:16.1135980Z: c05e8c87-3ec0-41e6-8b58-eb3376c2b2ae - AdalLoggerBase.cs: Looking up cache for a token...
[] 2019-01-24T13:12:16.1140470Z: c05e8c87-3ec0-41e6-8b58-eb3376c2b2ae - AdalLoggerBase.cs: No matching token was found in the cache
[] 2019-01-24T13:12:16.1145240Z: c05e8c87-3ec0-41e6-8b58-eb3376c2b2ae - AdalLoggerBase.cs: Checking MSAL cache for user token cache
[] 2019-01-24T13:12:16.1162530Z: c05e8c87-3ec0-41e6-8b58-eb3376c2b2ae - AdalLoggerBase.cs: Looking up cache for a token...
[] 2019-01-24T13:12:16.1166990Z: c05e8c87-3ec0-41e6-8b58-eb3376c2b2ae - AdalLoggerBase.cs: No matching token was found in the cache
[] 2019-01-24T13:12:16.1169740Z: c05e8c87-3ec0-41e6-8b58-eb3376c2b2ae - AdalLoggerBase.cs: Checking MSAL cache for user token cache
[] 2019-01-24T13:12:16.1187090Z: c05e8c87-3ec0-41e6-8b58-eb3376c2b2ae - AdalLoggerBase.cs: Looking up cache for a token...
[] 2019-01-24T13:12:16.1192780Z: c05e8c87-3ec0-41e6-8b58-eb3376c2b2ae - AdalLoggerBase.cs: No matching token was found in the cache
[] 2019-01-24T13:12:16.1196580Z: c05e8c87-3ec0-41e6-8b58-eb3376c2b2ae - AdalLoggerBase.cs: Checking MSAL cache for user token cache
[] 2019-01-24T13:12:16.1213600Z: c05e8c87-3ec0-41e6-8b58-eb3376c2b2ae - AdalLoggerBase.cs: Looking up cache for a token...
[] 2019-01-24T13:12:16.1218130Z: c05e8c87-3ec0-41e6-8b58-eb3376c2b2ae - AdalLoggerBase.cs: No matching token was found in the cache
[] 2019-01-24T13:12:16.1220920Z: c05e8c87-3ec0-41e6-8b58-eb3376c2b2ae - AdalLoggerBase.cs: Checking MSAL cache for user token cache
[] 2019-01-24T13:12:16.1239210Z: c05e8c87-3ec0-41e6-8b58-eb3376c2b2ae - AdalLoggerBase.cs: Looking up cache for a token...
[] 2019-01-24T13:12:16.1245490Z: c05e8c87-3ec0-41e6-8b58-eb3376c2b2ae - AdalLoggerBase.cs: No matching token was found in the cache
[] 2019-01-24T13:12:16.1248600Z: c05e8c87-3ec0-41e6-8b58-eb3376c2b2ae - AdalLoggerBase.cs: Checking MSAL cache for user token cache
[] 2019-01-24T13:12:16.1409020Z: c05e8c87-3ec0-41e6-8b58-eb3376c2b2ae - AdalLoggerBase.cs: BrokerProxy: Found the Authenticator on the device
[] 2019-01-24T13:12:16.1495590Z: c05e8c87-3ec0-41e6-8b58-eb3376c2b2ae - AdalLoggerBase.cs: BrokerProxy: Broker supports adding accounts
[] 2019-01-24T13:12:16.1605310Z: c05e8c87-3ec0-41e6-8b58-eb3376c2b2ae - AdalLoggerBase.cs: BrokerProxy: Broker supports adding accounts
[] 2019-01-24T13:12:16.1610930Z: c05e8c87-3ec0-41e6-8b58-eb3376c2b2ae - AdalLoggerBase.cs: It switched to broker for context: nl.ns.ccm.spikes.securedtodo
[] 2019-01-24T13:12:16.1613460Z: c05e8c87-3ec0-41e6-8b58-eb3376c2b2ae - AdalLoggerBase.cs: User is specified for background token request
[] 2019-01-24T13:12:16.1699550Z: c05e8c87-3ec0-41e6-8b58-eb3376c2b2ae - AdalLoggerBase.cs: BrokerProxy: Getting the broker work and school accounts 
[] 2019-01-24T13:12:16.1736820Z: c05e8c87-3ec0-41e6-8b58-eb3376c2b2ae - AdalLoggerBase.cs: BrokerProxy: finding account...
[] 2019-01-24T13:12:16.1746940Z: c05e8c87-3ec0-41e6-8b58-eb3376c2b2ae - AdalLoggerBase.cs: BrokerProxy: Found account based on the broker account name? False
[] 2019-01-24T13:12:16.1756860Z: c05e8c87-3ec0-41e6-8b58-eb3376c2b2ae - AdalLoggerBase.cs: Target account is not found
[] 2019-01-24T13:12:16.1772560Z: c05e8c87-3ec0-41e6-8b58-eb3376c2b2ae - AdalLoggerBase.cs: Token is not returned from backgroud call
[] 2019-01-24T13:12:16.1774740Z: c05e8c87-3ec0-41e6-8b58-eb3376c2b2ae - AdalLoggerBase.cs: Launch activity for Authenticator
[] 2019-01-24T13:12:16.1776520Z: c05e8c87-3ec0-41e6-8b58-eb3376c2b2ae - AdalLoggerBase.cs: Starting Authentication Activity
[] 2019-01-24T13:12:16.1778230Z: c05e8c87-3ec0-41e6-8b58-eb3376c2b2ae - AdalLoggerBase.cs: Initial request to authenticator
[] 2019-01-24T13:12:16.7746040Z: c05e8c87-3ec0-41e6-8b58-eb3376c2b2ae - AdalLoggerBase.cs: Calling activity pid:32319 tid:7122uid:10455
[] 2019-01-24T13:12:18.2471480Z: 00000000-0000-0000-0000-000000000000 - AdalLoggerBase.cs: Received Activity Result(2004)
[] 2019-01-24T13:12:18.2527150Z: c05e8c87-3ec0-41e6-8b58-eb3376c2b2ae - AdalLoggerBase.cs: Storing token in the cache...
[] 2019-01-24T13:12:18.2536860Z: c05e8c87-3ec0-41e6-8b58-eb3376c2b2ae - AdalLoggerBase.cs: An item was stored in the cache
[] 2019-01-24T13:12:18.2962570Z: 00000000-0000-0000-0000-000000000000 - AdalLoggerBase.cs: Client Info is missing. Skipping MSAL refresh token cache write
[] 2019-01-24T13:12:18.2983090Z: c05e8c87-3ec0-41e6-8b58-eb3376c2b2ae - AdalLoggerBase.cs: === Token Acquisition finished successfully. An access token was returned: Expiration Time: 24-1-2019 14:12:17 +00:00
[] 2019-01-24T13:12:18.2987660Z: 00000000-0000-0000-0000-000000000000 - AdalLoggerBase.cs: Serializing token cache with 1 items.

@bgavrilMS
Copy link
Member

Thank you @sourcefile .

First - please make sure that all the permissions are set correctly for the app, as described in our wiki: . The GET_ACCOUNTS permission is no longer sufficient. To be granted access to an account, apps should either use AccountManager.newChooseAccountIntent() or an authenticator-specific method. After getting access to accounts, an app can can call AccountManager.getAccounts() to access them.

If they are, first thing to do is to remove them and add them back. We've had cases where just "disappear".

Otherwise, It looks like a similar problem that one of our teams is also facing - @arielbh had a look at this recently (thanks Ariel!)

There seems to be a breaking change in Android 8.0 which is affecting this. https://developer.android.com/about/versions/oreo/android-8.0-changes#aaad which states

". The GET_ACCOUNTS permission is no longer sufficient. To be granted access to an account, apps should either use AccountManager.newChooseAccountIntent() or an authenticator-specific method. After getting access to accounts, an app can can call AccountManager.getAccounts() to access them."

I'll liaise with the ADAL for Android team to see if we can call a method on the Authenticator to get those accounts instead.

@bgavrilMS
Copy link
Member

bgavrilMS commented Jan 25, 2019

@sourcefile - could you try to run this piece of code in your app please and tell me what is being returned? Please make sure that you have unset and re-set the permissions on the app:

GET_ACCOUNTS
USE_CREDENTIALS
MANAGE_ACCOUNTS

            string WORK_AND_SCHOOL_TYPE = "com.microsoft.workaccount";
            var accManager = AccountManager.Get(Application.Context);
            // Any accounts returned? Possibly not
            Account[] accounts = accManager.GetAccountsByType(WORK_AND_SCHOOL_TYPE);

    
            // The Android docs state that "unless the authenticator owns the accounts or the user grants that access" GetAccounts will return an empty array.

            // The docs state that you should call NewChooseAccountIntent so that the user grants access
            Intent intent = AccountManager.NewChooseAccountIntent(null, null, new[] { WORK_AND_SCHOOL_TYPE }, null, null, null, null);
            StartActivity(intent);

            // Now you should have access
            var accounts2 = accManager.GetAccountsByType(WORK_AND_SCHOOL_TYPE);

The strange thing is that my Authenticator returns the accounts everytime, and I tried on my Samsung Galaxy which is running a pretty new version of Android...

@sourcefile
Copy link
Author

@bgavrilMS This is what I'm getting after pasting the snippet in MainActivity.cs.

First, I get a pop-up asking me to select an account. This is an android native pop-up, not the authenticator (I guess that's to be expected since we're calling Android APIs here) Both accounts here are expected. One is my work account (the redacted one), the other is the test account for the purpose of this issue.

screenshot-1548663382834

After selecting the account, This is the contents of the accounts2 variable:

{Account {[email protected], type=com.microsoft.workaccount}}

As far as I can tell, the account exists, while it's accesstoken is valid. I'm currently waiting for the token to expire, but my current theory is the account is deleted during or after the attempt to refresh silently.

@bgavrilMS
Copy link
Member

@sourcefile - and before the pop-up, was the accounts variable an empty array or null? The AT will expire in 1h.

@sourcefile
Copy link
Author

@bgavrilMS Both variables were filled with the account. I also checked before the attempt to silently refresh and directly after but before falling back to interactive login. Every time both variables contain the account

@bgavrilMS
Copy link
Member

bgavrilMS commented Feb 5, 2019

I keep looking and looking at the stack trace and the logs and I can't fully piece together was has happened.

It looks like after the token expiration the flow was:

  1. Check the token cache - an AT is found, but is is expired (OK)
  2. There is no RT in the token cache (expected, the RT is on the broker), so delete the expired AT as well.
  3. Token cache logic ends, now try to use the broker
  4. See if the broker can be invoked. This does 2 checks - firstly if you have configured broker use via PlatformParamters and secondly if the broker is installed etc.

From what I see in the logs, the only explanation is that you haven't configured broker use in PlatformParamters. I see in your code snipped that you use a variable for this, so is it possible that you have not set it to true for this particular call ?

Otherwise, I have added more logging to ADAL, and I have a nupkg on myget that you can try and might provide more clues. There are instructions here on how to install it if you need them

@sourcefile
Copy link
Author

Hi @bgavrilMS,

Thanks for your mentioning of PlatformParameters. Although the use of broker is always set to true via a constant variable, I did not send the PlatformParams when trying to authenticate silent, resulting in the logging below.

---------- Initial run ----------
[] 2019-02-07T08:27:11.5160230Z: fb0cc5c1-0602-4229-9a9f-fe533f259c8e - AdalLoggerBase.cs: Loading from cache.
[] 2019-02-07T08:27:11.5377430Z: fb0cc5c1-0602-4229-9a9f-fe533f259c8e - AdalLoggerBase.cs: Looking up cache for a token...
[] 2019-02-07T08:27:11.5534960Z: fb0cc5c1-0602-4229-9a9f-fe533f259c8e - AdalLoggerBase.cs: No matching token was found in the cache
[] 2019-02-07T08:27:11.5540780Z: fb0cc5c1-0602-4229-9a9f-fe533f259c8e - AdalLoggerBase.cs: Checking MSAL cache for user token cache
[] 2019-02-07T08:27:11.5773000Z: fb0cc5c1-0602-4229-9a9f-fe533f259c8e - AdalLoggerBase.cs: A match was found in the MSAL cache ? False
[] 2019-02-07T08:27:11.5779370Z: fb0cc5c1-0602-4229-9a9f-fe533f259c8e - AdalLoggerBase.cs: Looking up cache for a token...
[] 2019-02-07T08:27:11.5781770Z: fb0cc5c1-0602-4229-9a9f-fe533f259c8e - AdalLoggerBase.cs: No matching token was found in the cache
[] 2019-02-07T08:27:11.5785290Z: fb0cc5c1-0602-4229-9a9f-fe533f259c8e - AdalLoggerBase.cs: Checking MSAL cache for user token cache
[] 2019-02-07T08:27:11.5797780Z: fb0cc5c1-0602-4229-9a9f-fe533f259c8e - AdalLoggerBase.cs: A match was found in the MSAL cache ? False
[] 2019-02-07T08:27:11.5805340Z: fb0cc5c1-0602-4229-9a9f-fe533f259c8e - AdalLoggerBase.cs: Looking up cache for a token...
[] 2019-02-07T08:27:11.5807970Z: fb0cc5c1-0602-4229-9a9f-fe533f259c8e - AdalLoggerBase.cs: No matching token was found in the cache
[] 2019-02-07T08:27:11.5809670Z: fb0cc5c1-0602-4229-9a9f-fe533f259c8e - AdalLoggerBase.cs: Checking MSAL cache for user token cache
[] 2019-02-07T08:27:11.5821220Z: fb0cc5c1-0602-4229-9a9f-fe533f259c8e - AdalLoggerBase.cs: A match was found in the MSAL cache ? False
[] 2019-02-07T08:27:11.5825510Z: fb0cc5c1-0602-4229-9a9f-fe533f259c8e - AdalLoggerBase.cs: Looking up cache for a token...
[] 2019-02-07T08:27:11.5827740Z: fb0cc5c1-0602-4229-9a9f-fe533f259c8e - AdalLoggerBase.cs: No matching token was found in the cache
[] 2019-02-07T08:27:11.5829410Z: fb0cc5c1-0602-4229-9a9f-fe533f259c8e - AdalLoggerBase.cs: Checking MSAL cache for user token cache
[] 2019-02-07T08:27:11.5840630Z: fb0cc5c1-0602-4229-9a9f-fe533f259c8e - AdalLoggerBase.cs: A match was found in the MSAL cache ? False
[] 2019-02-07T08:27:11.5845040Z: fb0cc5c1-0602-4229-9a9f-fe533f259c8e - AdalLoggerBase.cs: Looking up cache for a token...
[] 2019-02-07T08:27:11.5847310Z: fb0cc5c1-0602-4229-9a9f-fe533f259c8e - AdalLoggerBase.cs: No matching token was found in the cache
[] 2019-02-07T08:27:11.5848970Z: fb0cc5c1-0602-4229-9a9f-fe533f259c8e - AdalLoggerBase.cs: Checking MSAL cache for user token cache
[] 2019-02-07T08:27:11.5861020Z: fb0cc5c1-0602-4229-9a9f-fe533f259c8e - AdalLoggerBase.cs: A match was found in the MSAL cache ? False
[] 2019-02-07T08:27:11.5865410Z: fb0cc5c1-0602-4229-9a9f-fe533f259c8e - AdalLoggerBase.cs: Looking up cache for a token...
[] 2019-02-07T08:27:11.5868250Z: fb0cc5c1-0602-4229-9a9f-fe533f259c8e - AdalLoggerBase.cs: No matching token was found in the cache
[] 2019-02-07T08:27:11.5870420Z: fb0cc5c1-0602-4229-9a9f-fe533f259c8e - AdalLoggerBase.cs: Checking MSAL cache for user token cache
[] 2019-02-07T08:27:11.5886970Z: fb0cc5c1-0602-4229-9a9f-fe533f259c8e - AdalLoggerBase.cs: A match was found in the MSAL cache ? False
[] 2019-02-07T08:27:11.5900510Z: fb0cc5c1-0602-4229-9a9f-fe533f259c8e - AdalLoggerBase.cs: Either a token was not found or an exception was thrown.
[] 2019-02-07T08:27:11.5920060Z: fb0cc5c1-0602-4229-9a9f-fe533f259c8e - AdalLoggerBase.cs: Is Android Broker use configured via PlatformParamters? False
[] 2019-02-07T08:27:11.5925200Z: fb0cc5c1-0602-4229-9a9f-fe533f259c8e - AdalLoggerBase.cs: Can invoke broker? False
[] 2019-02-07T08:27:11.5927060Z: fb0cc5c1-0602-4229-9a9f-fe533f259c8e - AdalLoggerBase.cs: Cannot invoke the broker directly, may require install ...
[] 2019-02-07T08:27:11.5959880Z: fb0cc5c1-0602-4229-9a9f-fe533f259c8e - AdalLoggerBase.cs: Check and AcquireToken using broker 
[] 2019-02-07T08:27:11.5971270Z: fb0cc5c1-0602-4229-9a9f-fe533f259c8e - AdalLoggerBase.cs: Broker invocation is NOT required
[] 2019-02-07T08:27:11.5981530Z: fb0cc5c1-0602-4229-9a9f-fe533f259c8e - AdalLoggerBase.cs: No token matching arguments found in the cache
[] 2019-02-07T08:27:11.6252860Z: fb0cc5c1-0602-4229-9a9f-fe533f259c8e - AdalLoggerBase.cs: Exception type: Microsoft.IdentityModel.Clients.ActiveDirectory.AdalSilentTokenAcquisitionException
[] , ErrorCode: failed_to_acquire_token_silently
[] 
[]   at Microsoft.IdentityModel.Clients.ActiveDirectory.Internal.Flows.AcquireTokenSilentHandler.SendTokenRequestAsync () [0x0001d] in C:\agent2\_work\43\s\src\Microsoft.IdentityModel.Clients.ActiveDirectory\Internal\Flows\AcquireTokenSilentHandler.cs:64 
[]   at Microsoft.IdentityModel.Clients.ActiveDirectory.Internal.Flows.AcquireTokenHandlerBase+<CheckAndAcquireTokenUsingBrokerAsync>d__60.MoveNext () [0x000df] in C:\agent2\_work\43\s\src\Microsoft.IdentityModel.Clients.ActiveDirectory\Internal\Flows\AcquireTokenHandlerBase.cs:269 
[] --- End of stack trace from previous location where exception was thrown ---
[]   at Microsoft.IdentityModel.Clients.ActiveDirectory.Internal.Flows.AcquireTokenHandlerBase+<RunAsync>d__58.MoveNext () [0x004bd] in C:\agent2\_work\43\s\src\Microsoft.IdentityModel.Clients.ActiveDirectory\Internal\Flows\AcquireTokenHandlerBase.cs:202 
[] 2019-02-07T08:27:11.6557870Z: e375602f-b33b-4660-b076-3c163b451e2f - AdalLoggerBase.cs: BrokerProxy: Getting the Android context
[] 2019-02-07T08:27:11.6568990Z: e375602f-b33b-4660-b076-3c163b451e2f - AdalLoggerBase.cs: ADAL PCL.Android with assembly version '4.5.1.0', file version '4.5.1.0' and informational version '4.5.1-internal03601dev' is running...
[] 2019-02-07T08:27:11.6575330Z: e375602f-b33b-4660-b076-3c163b451e2f - AdalLoggerBase.cs: === Token Acquisition started: 
[] 	CacheType: Microsoft.IdentityModel.Clients.ActiveDirectory.TokenCache (0 items)
[] 	Authentication Target: User
[] 	, Authority Host: login.microsoftonline.com
[] 2019-02-07T08:27:11.6672760Z: e375602f-b33b-4660-b076-3c163b451e2f - AdalLoggerBase.cs: Loading from cache.
[] 2019-02-07T08:27:11.6689240Z: e375602f-b33b-4660-b076-3c163b451e2f - AdalLoggerBase.cs: Looking up cache for a token...
[] 2019-02-07T08:27:11.6693520Z: e375602f-b33b-4660-b076-3c163b451e2f - AdalLoggerBase.cs: No matching token was found in the cache
[] 2019-02-07T08:27:11.6695220Z: e375602f-b33b-4660-b076-3c163b451e2f - AdalLoggerBase.cs: Checking MSAL cache for user token cache
[] 2019-02-07T08:27:11.6706650Z: e375602f-b33b-4660-b076-3c163b451e2f - AdalLoggerBase.cs: A match was found in the MSAL cache ? False
[] 2019-02-07T08:27:11.6710870Z: e375602f-b33b-4660-b076-3c163b451e2f - AdalLoggerBase.cs: Looking up cache for a token...
[] 2019-02-07T08:27:11.6713150Z: e375602f-b33b-4660-b076-3c163b451e2f - AdalLoggerBase.cs: No matching token was found in the cache
[] 2019-02-07T08:27:11.6714810Z: e375602f-b33b-4660-b076-3c163b451e2f - AdalLoggerBase.cs: Checking MSAL cache for user token cache
[] 2019-02-07T08:27:11.6726660Z: e375602f-b33b-4660-b076-3c163b451e2f - AdalLoggerBase.cs: A match was found in the MSAL cache ? False
[] 2019-02-07T08:27:11.6731440Z: e375602f-b33b-4660-b076-3c163b451e2f - AdalLoggerBase.cs: Looking up cache for a token...
[] 2019-02-07T08:27:11.6733710Z: e375602f-b33b-4660-b076-3c163b451e2f - AdalLoggerBase.cs: No matching token was found in the cache
[] 2019-02-07T08:27:11.6735450Z: e375602f-b33b-4660-b076-3c163b451e2f - AdalLoggerBase.cs: Checking MSAL cache for user token cache
[] 2019-02-07T08:27:11.6746490Z: e375602f-b33b-4660-b076-3c163b451e2f - AdalLoggerBase.cs: A match was found in the MSAL cache ? False
[] 2019-02-07T08:27:11.6750830Z: e375602f-b33b-4660-b076-3c163b451e2f - AdalLoggerBase.cs: Looking up cache for a token...
[] 2019-02-07T08:27:11.6753060Z: e375602f-b33b-4660-b076-3c163b451e2f - AdalLoggerBase.cs: No matching token was found in the cache
[] 2019-02-07T08:27:11.6754700Z: e375602f-b33b-4660-b076-3c163b451e2f - AdalLoggerBase.cs: Checking MSAL cache for user token cache
[] 2019-02-07T08:27:11.6767360Z: e375602f-b33b-4660-b076-3c163b451e2f - AdalLoggerBase.cs: A match was found in the MSAL cache ? False
[] 2019-02-07T08:27:11.6772370Z: e375602f-b33b-4660-b076-3c163b451e2f - AdalLoggerBase.cs: Looking up cache for a token...
[] 2019-02-07T08:27:11.6774680Z: e375602f-b33b-4660-b076-3c163b451e2f - AdalLoggerBase.cs: No matching token was found in the cache
[] 2019-02-07T08:27:11.6776660Z: e375602f-b33b-4660-b076-3c163b451e2f - AdalLoggerBase.cs: Checking MSAL cache for user token cache
[] 2019-02-07T08:27:11.6789800Z: e375602f-b33b-4660-b076-3c163b451e2f - AdalLoggerBase.cs: A match was found in the MSAL cache ? False
[] 2019-02-07T08:27:11.6794740Z: e375602f-b33b-4660-b076-3c163b451e2f - AdalLoggerBase.cs: Looking up cache for a token...
[] 2019-02-07T08:27:11.6796970Z: e375602f-b33b-4660-b076-3c163b451e2f - AdalLoggerBase.cs: No matching token was found in the cache
[] 2019-02-07T08:27:11.6798570Z: e375602f-b33b-4660-b076-3c163b451e2f - AdalLoggerBase.cs: Checking MSAL cache for user token cache
[] 2019-02-07T08:27:11.6810070Z: e375602f-b33b-4660-b076-3c163b451e2f - AdalLoggerBase.cs: A match was found in the MSAL cache ? False
[] 2019-02-07T08:27:11.6813880Z: e375602f-b33b-4660-b076-3c163b451e2f - AdalLoggerBase.cs: Either a token was not found or an exception was thrown.
[] 2019-02-07T08:27:11.6819010Z: e375602f-b33b-4660-b076-3c163b451e2f - AdalLoggerBase.cs: Is Android Broker use configured via PlatformParamters? True
[] 2019-02-07T08:27:11.7552970Z: e375602f-b33b-4660-b076-3c163b451e2f - AdalLoggerBase.cs: BrokerProxy: Found the Authenticator on the device
[] 2019-02-07T08:27:11.7667130Z: e375602f-b33b-4660-b076-3c163b451e2f - AdalLoggerBase.cs: BrokerProxy: CheckAccount. Getting authenticator types 16
[] 2019-02-07T08:27:11.7717090Z: e375602f-b33b-4660-b076-3c163b451e2f - AdalLoggerBase.cs: BrokerProxy: Getting the account list 0
[] 2019-02-07T08:27:11.7724500Z: e375602f-b33b-4660-b076-3c163b451e2f - AdalLoggerBase.cs: BrokerProxy: Package name is com.azure.authenticator
[] 2019-02-07T08:27:11.7843590Z: e375602f-b33b-4660-b076-3c163b451e2f - AdalLoggerBase.cs: BrokerProxy: Broker supports adding accounts
[] 2019-02-07T08:27:11.7850090Z: e375602f-b33b-4660-b076-3c163b451e2f - AdalLoggerBase.cs: Can invoke broker? True
[] 2019-02-07T08:27:11.7853690Z: e375602f-b33b-4660-b076-3c163b451e2f - AdalLoggerBase.cs: Trying to acquire a token using the broker...
[] 2019-02-07T08:27:11.8300410Z: e375602f-b33b-4660-b076-3c163b451e2f - AdalLoggerBase.cs: BrokerProxy: CheckAccount. Getting authenticator types 16
[] 2019-02-07T08:27:11.8346560Z: e375602f-b33b-4660-b076-3c163b451e2f - AdalLoggerBase.cs: BrokerProxy: Getting the account list 0
[] 2019-02-07T08:27:11.8359670Z: e375602f-b33b-4660-b076-3c163b451e2f - AdalLoggerBase.cs: BrokerProxy: Package name is com.azure.authenticator
[] 2019-02-07T08:27:11.8410090Z: e375602f-b33b-4660-b076-3c163b451e2f - AdalLoggerBase.cs: BrokerProxy: Broker supports adding accounts
[] 2019-02-07T08:27:11.8436940Z: e375602f-b33b-4660-b076-3c163b451e2f - AdalLoggerBase.cs: It switched to broker for context
[] 2019-02-07T08:27:11.8458740Z: e375602f-b33b-4660-b076-3c163b451e2f - AdalLoggerBase.cs: User is not specified for background token request
[] 2019-02-07T08:27:11.8465570Z: e375602f-b33b-4660-b076-3c163b451e2f - AdalLoggerBase.cs: Token is not returned from backgroud call
[] 2019-02-07T08:27:11.8469070Z: e375602f-b33b-4660-b076-3c163b451e2f - AdalLoggerBase.cs: Launch activity for Authenticator
[] 2019-02-07T08:27:11.8472460Z: e375602f-b33b-4660-b076-3c163b451e2f - AdalLoggerBase.cs: Starting Authentication Activity
[] 2019-02-07T08:27:11.8475770Z: e375602f-b33b-4660-b076-3c163b451e2f - AdalLoggerBase.cs: Initial request to authenticator
[] 2019-02-07T08:27:12.8999000Z: e375602f-b33b-4660-b076-3c163b451e2f - AdalLoggerBase.cs: Calling activity pid:30091 tid:30404uid:10464
[] 2019-02-07T08:27:29.7428540Z: 00000000-0000-0000-0000-000000000000 - AdalLoggerBase.cs: Client Info is missing. Skipping MSAL refresh token cache write
[] 2019-02-07T08:27:29.7929860Z: e375602f-b33b-4660-b076-3c163b451e2f - AdalLoggerBase.cs: === Token Acquisition finished successfully. An access token was returned: Expiration Time: 7-2-2019 09:27:28 +00:00
[] 2019-02-07T08:27:29.8054260Z: 00000000-0000-0000-0000-000000000000 - AdalLoggerBase.cs: Serializing token cache with 1 items.

---------- Access token expired ----------

[] 2019-02-07T10:33:44.1555220Z: 93d58f2c-02cc-4e72-bcb6-f063c3db4855 - AdalLoggerBase.cs: Loading from cache.
[] 2019-02-07T10:33:44.1631430Z: 00000000-0000-0000-0000-000000000000 - AdalLoggerBase.cs: Deserialized 1 items to token cache.
[] 2019-02-07T10:33:44.1991480Z: 93d58f2c-02cc-4e72-bcb6-f063c3db4855 - AdalLoggerBase.cs: Looking up cache for a token...
[] 2019-02-07T10:33:44.2384910Z: 93d58f2c-02cc-4e72-bcb6-f063c3db4855 - AdalLoggerBase.cs: An item matching the requested resource was found in the cache
[] 2019-02-07T10:33:44.2438140Z: 93d58f2c-02cc-4e72-bcb6-f063c3db4855 - AdalLoggerBase.cs: A matching entry was found in the cache
[] 2019-02-07T10:33:44.2623460Z: 93d58f2c-02cc-4e72-bcb6-f063c3db4855 - AdalLoggerBase.cs: An expired or near expiry token was found in the cache
[] 2019-02-07T10:33:44.2690660Z: 93d58f2c-02cc-4e72-bcb6-f063c3db4855 - AdalLoggerBase.cs: An old item was removed from the cache
[] 2019-02-07T10:33:44.2710080Z: 93d58f2c-02cc-4e72-bcb6-f063c3db4855 - AdalLoggerBase.cs: Looking up cache for a token...
[] 2019-02-07T10:33:44.2752360Z: 93d58f2c-02cc-4e72-bcb6-f063c3db4855 - AdalLoggerBase.cs: No matching token was found in the cache
[] 2019-02-07T10:33:44.2759330Z: 93d58f2c-02cc-4e72-bcb6-f063c3db4855 - AdalLoggerBase.cs: Checking MSAL cache for user token cache
[] 2019-02-07T10:33:44.3148060Z: 93d58f2c-02cc-4e72-bcb6-f063c3db4855 - AdalLoggerBase.cs: A match was found in the MSAL cache ? False
[] 2019-02-07T10:33:44.3162370Z: 93d58f2c-02cc-4e72-bcb6-f063c3db4855 - AdalLoggerBase.cs: Looking up cache for a token...
[] 2019-02-07T10:33:44.3172160Z: 93d58f2c-02cc-4e72-bcb6-f063c3db4855 - AdalLoggerBase.cs: No matching token was found in the cache
[] 2019-02-07T10:33:44.3178430Z: 93d58f2c-02cc-4e72-bcb6-f063c3db4855 - AdalLoggerBase.cs: Checking MSAL cache for user token cache
[] 2019-02-07T10:33:44.3214600Z: 93d58f2c-02cc-4e72-bcb6-f063c3db4855 - AdalLoggerBase.cs: A match was found in the MSAL cache ? False
[] 2019-02-07T10:33:44.3223540Z: 93d58f2c-02cc-4e72-bcb6-f063c3db4855 - AdalLoggerBase.cs: Looking up cache for a token...
[] 2019-02-07T10:33:44.3229290Z: 93d58f2c-02cc-4e72-bcb6-f063c3db4855 - AdalLoggerBase.cs: No matching token was found in the cache
[] 2019-02-07T10:33:44.3233560Z: 93d58f2c-02cc-4e72-bcb6-f063c3db4855 - AdalLoggerBase.cs: Checking MSAL cache for user token cache
[] 2019-02-07T10:33:44.3255620Z: 93d58f2c-02cc-4e72-bcb6-f063c3db4855 - AdalLoggerBase.cs: A match was found in the MSAL cache ? False
[] 2019-02-07T10:33:44.3266660Z: 93d58f2c-02cc-4e72-bcb6-f063c3db4855 - AdalLoggerBase.cs: Looking up cache for a token...
[] 2019-02-07T10:33:44.3275120Z: 93d58f2c-02cc-4e72-bcb6-f063c3db4855 - AdalLoggerBase.cs: No matching token was found in the cache
[] 2019-02-07T10:33:44.3282420Z: 93d58f2c-02cc-4e72-bcb6-f063c3db4855 - AdalLoggerBase.cs: Checking MSAL cache for user token cache
[] 2019-02-07T10:33:44.3316870Z: 93d58f2c-02cc-4e72-bcb6-f063c3db4855 - AdalLoggerBase.cs: A match was found in the MSAL cache ? False
[] 2019-02-07T10:33:44.3327490Z: 93d58f2c-02cc-4e72-bcb6-f063c3db4855 - AdalLoggerBase.cs: Looking up cache for a token...
[] 2019-02-07T10:33:44.3336980Z: 93d58f2c-02cc-4e72-bcb6-f063c3db4855 - AdalLoggerBase.cs: No matching token was found in the cache
[] 2019-02-07T10:33:44.3344080Z: 93d58f2c-02cc-4e72-bcb6-f063c3db4855 - AdalLoggerBase.cs: Checking MSAL cache for user token cache
[] 2019-02-07T10:33:44.3375540Z: 93d58f2c-02cc-4e72-bcb6-f063c3db4855 - AdalLoggerBase.cs: A match was found in the MSAL cache ? False
[] 2019-02-07T10:33:44.3390710Z: 93d58f2c-02cc-4e72-bcb6-f063c3db4855 - AdalLoggerBase.cs: Either a token was not found or an exception was thrown.
[] 2019-02-07T10:33:44.3416210Z: 93d58f2c-02cc-4e72-bcb6-f063c3db4855 - AdalLoggerBase.cs: Is Android Broker use configured via PlatformParamters? False
[] 2019-02-07T10:33:44.3424360Z: 93d58f2c-02cc-4e72-bcb6-f063c3db4855 - AdalLoggerBase.cs: Can invoke broker? False
[] 2019-02-07T10:33:44.3429840Z: 93d58f2c-02cc-4e72-bcb6-f063c3db4855 - AdalLoggerBase.cs: Cannot invoke the broker directly, may require install ...
[] 2019-02-07T10:33:44.3508790Z: 93d58f2c-02cc-4e72-bcb6-f063c3db4855 - AdalLoggerBase.cs: Check and AcquireToken using broker 
[] 2019-02-07T10:33:44.3519970Z: 93d58f2c-02cc-4e72-bcb6-f063c3db4855 - AdalLoggerBase.cs: Broker invocation is NOT required
[] 2019-02-07T10:33:44.3539060Z: 93d58f2c-02cc-4e72-bcb6-f063c3db4855 - AdalLoggerBase.cs: No token matching arguments found in the cache
[] 2019-02-07T10:33:44.4091640Z: 93d58f2c-02cc-4e72-bcb6-f063c3db4855 - AdalLoggerBase.cs: Exception type: Microsoft.IdentityModel.Clients.ActiveDirectory.AdalSilentTokenAcquisitionException
[] , ErrorCode: failed_to_acquire_token_silently
[] 
[]   at Microsoft.IdentityModel.Clients.ActiveDirectory.Internal.Flows.AcquireTokenSilentHandler.SendTokenRequestAsync () [0x0001d] in C:\agent2\_work\43\s\src\Microsoft.IdentityModel.Clients.ActiveDirectory\Internal\Flows\AcquireTokenSilentHandler.cs:64 
[]   at Microsoft.IdentityModel.Clients.ActiveDirectory.Internal.Flows.AcquireTokenHandlerBase+<CheckAndAcquireTokenUsingBrokerAsync>d__60.MoveNext () [0x000df] in C:\agent2\_work\43\s\src\Microsoft.IdentityModel.Clients.ActiveDirectory\Internal\Flows\AcquireTokenHandlerBase.cs:269 
[] --- End of stack trace from previous location where exception was thrown ---
[]   at Microsoft.IdentityModel.Clients.ActiveDirectory.Internal.Flows.AcquireTokenHandlerBase+<RunAsync>d__58.MoveNext () [0x004bd] in C:\agent2\_work\43\s\src\Microsoft.IdentityModel.Clients.ActiveDirectory\Internal\Flows\AcquireTokenHandlerBase.cs:202 
[] 2019-02-07T10:33:44.4171520Z: 00000000-0000-0000-0000-000000000000 - AdalLoggerBase.cs: Serializing token cache with 0 items.
[] 2019-02-07T10:33:49.2752800Z: 6dd1c399-75eb-4ff0-9282-0af52299cb2f - AdalLoggerBase.cs: BrokerProxy: Getting the Android context
[] 2019-02-07T10:33:49.2778690Z: 6dd1c399-75eb-4ff0-9282-0af52299cb2f - AdalLoggerBase.cs: ADAL PCL.Android with assembly version '4.5.1.0', file version '4.5.1.0' and informational version '4.5.1-internal03601dev' is running...
[] 2019-02-07T10:33:49.2796510Z: 6dd1c399-75eb-4ff0-9282-0af52299cb2f - AdalLoggerBase.cs: === Token Acquisition started: 
[] 	CacheType: Microsoft.IdentityModel.Clients.ActiveDirectory.TokenCache (0 items)
[] 	Authentication Target: User
[] 	, Authority Host: login.microsoftonline.com
[] 2019-02-07T10:33:49.2988160Z: 6dd1c399-75eb-4ff0-9282-0af52299cb2f - AdalLoggerBase.cs: Loading from cache.
[] 2019-02-07T10:33:49.3023980Z: 00000000-0000-0000-0000-000000000000 - AdalLoggerBase.cs: Deserialized 0 items to token cache.
[] 2019-02-07T10:33:49.3037290Z: 6dd1c399-75eb-4ff0-9282-0af52299cb2f - AdalLoggerBase.cs: Looking up cache for a token...
[] 2019-02-07T10:33:49.3045460Z: 6dd1c399-75eb-4ff0-9282-0af52299cb2f - AdalLoggerBase.cs: No matching token was found in the cache
[] 2019-02-07T10:33:49.3050960Z: 6dd1c399-75eb-4ff0-9282-0af52299cb2f - AdalLoggerBase.cs: Checking MSAL cache for user token cache
[] 2019-02-07T10:33:49.3083870Z: 6dd1c399-75eb-4ff0-9282-0af52299cb2f - AdalLoggerBase.cs: A match was found in the MSAL cache ? False
[] 2019-02-07T10:33:49.3096580Z: 6dd1c399-75eb-4ff0-9282-0af52299cb2f - AdalLoggerBase.cs: Looking up cache for a token...
[] 2019-02-07T10:33:49.3103060Z: 6dd1c399-75eb-4ff0-9282-0af52299cb2f - AdalLoggerBase.cs: No matching token was found in the cache
[] 2019-02-07T10:33:49.3107800Z: 6dd1c399-75eb-4ff0-9282-0af52299cb2f - AdalLoggerBase.cs: Checking MSAL cache for user token cache
[] 2019-02-07T10:33:49.3137950Z: 6dd1c399-75eb-4ff0-9282-0af52299cb2f - AdalLoggerBase.cs: A match was found in the MSAL cache ? False
[] 2019-02-07T10:33:49.3155170Z: 6dd1c399-75eb-4ff0-9282-0af52299cb2f - AdalLoggerBase.cs: Looking up cache for a token...
[] 2019-02-07T10:33:49.3169040Z: 6dd1c399-75eb-4ff0-9282-0af52299cb2f - AdalLoggerBase.cs: No matching token was found in the cache
[] 2019-02-07T10:33:49.3175590Z: 6dd1c399-75eb-4ff0-9282-0af52299cb2f - AdalLoggerBase.cs: Checking MSAL cache for user token cache
[] 2019-02-07T10:33:49.3204960Z: 6dd1c399-75eb-4ff0-9282-0af52299cb2f - AdalLoggerBase.cs: A match was found in the MSAL cache ? False
[] 2019-02-07T10:33:49.3215410Z: 6dd1c399-75eb-4ff0-9282-0af52299cb2f - AdalLoggerBase.cs: Looking up cache for a token...
[] 2019-02-07T10:33:49.3221080Z: 6dd1c399-75eb-4ff0-9282-0af52299cb2f - AdalLoggerBase.cs: No matching token was found in the cache
[] 2019-02-07T10:33:49.3225800Z: 6dd1c399-75eb-4ff0-9282-0af52299cb2f - AdalLoggerBase.cs: Checking MSAL cache for user token cache
[] 2019-02-07T10:33:49.3262360Z: 6dd1c399-75eb-4ff0-9282-0af52299cb2f - AdalLoggerBase.cs: A match was found in the MSAL cache ? False
[] 2019-02-07T10:33:49.3274220Z: 6dd1c399-75eb-4ff0-9282-0af52299cb2f - AdalLoggerBase.cs: Looking up cache for a token...
[] 2019-02-07T10:33:49.3278530Z: 6dd1c399-75eb-4ff0-9282-0af52299cb2f - AdalLoggerBase.cs: No matching token was found in the cache
[] 2019-02-07T10:33:49.3282590Z: 6dd1c399-75eb-4ff0-9282-0af52299cb2f - AdalLoggerBase.cs: Checking MSAL cache for user token cache
[] 2019-02-07T10:33:49.3302750Z: 6dd1c399-75eb-4ff0-9282-0af52299cb2f - AdalLoggerBase.cs: A match was found in the MSAL cache ? False
[] 2019-02-07T10:33:49.3310550Z: 6dd1c399-75eb-4ff0-9282-0af52299cb2f - AdalLoggerBase.cs: Looking up cache for a token...
[] 2019-02-07T10:33:49.3317280Z: 6dd1c399-75eb-4ff0-9282-0af52299cb2f - AdalLoggerBase.cs: No matching token was found in the cache
[] 2019-02-07T10:33:49.3323050Z: 6dd1c399-75eb-4ff0-9282-0af52299cb2f - AdalLoggerBase.cs: Checking MSAL cache for user token cache
[] 2019-02-07T10:33:49.3344750Z: 6dd1c399-75eb-4ff0-9282-0af52299cb2f - AdalLoggerBase.cs: A match was found in the MSAL cache ? False
[] 2019-02-07T10:33:49.3351630Z: 6dd1c399-75eb-4ff0-9282-0af52299cb2f - AdalLoggerBase.cs: Either a token was not found or an exception was thrown.
[] 2019-02-07T10:33:49.3360920Z: 6dd1c399-75eb-4ff0-9282-0af52299cb2f - AdalLoggerBase.cs: Is Android Broker use configured via PlatformParamters? True
[] 2019-02-07T10:33:49.4081750Z: 6dd1c399-75eb-4ff0-9282-0af52299cb2f - AdalLoggerBase.cs: BrokerProxy: Found the Authenticator on the device
[] 2019-02-07T10:33:49.4221790Z: 6dd1c399-75eb-4ff0-9282-0af52299cb2f - AdalLoggerBase.cs: BrokerProxy: CheckAccount. Getting authenticator types 16
[] 2019-02-07T10:33:49.4276640Z: 6dd1c399-75eb-4ff0-9282-0af52299cb2f - AdalLoggerBase.cs: BrokerProxy: Getting the account list 0
[] 2019-02-07T10:33:49.4285360Z: 6dd1c399-75eb-4ff0-9282-0af52299cb2f - AdalLoggerBase.cs: BrokerProxy: Package name is com.azure.authenticator
[] 2019-02-07T10:33:49.4411350Z: 6dd1c399-75eb-4ff0-9282-0af52299cb2f - AdalLoggerBase.cs: BrokerProxy: Broker supports adding accounts
[] 2019-02-07T10:33:49.4418260Z: 6dd1c399-75eb-4ff0-9282-0af52299cb2f - AdalLoggerBase.cs: Can invoke broker? True
[] 2019-02-07T10:33:49.4422400Z: 6dd1c399-75eb-4ff0-9282-0af52299cb2f - AdalLoggerBase.cs: Trying to acquire a token using the broker...
[] 2019-02-07T10:33:49.4706980Z: 6dd1c399-75eb-4ff0-9282-0af52299cb2f - AdalLoggerBase.cs: BrokerProxy: CheckAccount. Getting authenticator types 16
[] 2019-02-07T10:33:49.4736680Z: 6dd1c399-75eb-4ff0-9282-0af52299cb2f - AdalLoggerBase.cs: BrokerProxy: Getting the account list 0
[] 2019-02-07T10:33:49.4743110Z: 6dd1c399-75eb-4ff0-9282-0af52299cb2f - AdalLoggerBase.cs: BrokerProxy: Package name is com.azure.authenticator
[] 2019-02-07T10:33:49.4803160Z: 6dd1c399-75eb-4ff0-9282-0af52299cb2f - AdalLoggerBase.cs: BrokerProxy: Broker supports adding accounts
[] 2019-02-07T10:33:49.4823510Z: 6dd1c399-75eb-4ff0-9282-0af52299cb2f - AdalLoggerBase.cs: It switched to broker for context
[] 2019-02-07T10:33:49.4833980Z: 6dd1c399-75eb-4ff0-9282-0af52299cb2f - AdalLoggerBase.cs: User is specified for background token request
[] 2019-02-07T10:33:49.4875870Z: 6dd1c399-75eb-4ff0-9282-0af52299cb2f - AdalLoggerBase.cs: BrokerProxy: Getting the broker work and school accounts 
[] 2019-02-07T10:33:49.4909720Z: 6dd1c399-75eb-4ff0-9282-0af52299cb2f - AdalLoggerBase.cs: BrokerProxy: finding account...
[] 2019-02-07T10:33:49.4915880Z: 6dd1c399-75eb-4ff0-9282-0af52299cb2f - AdalLoggerBase.cs: BrokerProxy: Found account based on the broker account name? False
[] 2019-02-07T10:33:49.4928220Z: 6dd1c399-75eb-4ff0-9282-0af52299cb2f - AdalLoggerBase.cs: Target account is not found
[] 2019-02-07T10:33:49.4983600Z: 6dd1c399-75eb-4ff0-9282-0af52299cb2f - AdalLoggerBase.cs: Token is not returned from backgroud call
[] 2019-02-07T10:33:49.4989380Z: 6dd1c399-75eb-4ff0-9282-0af52299cb2f - AdalLoggerBase.cs: Launch activity for Authenticator
[] 2019-02-07T10:33:49.4994290Z: 6dd1c399-75eb-4ff0-9282-0af52299cb2f - AdalLoggerBase.cs: Starting Authentication Activity
[] 2019-02-07T10:33:49.4999200Z: 6dd1c399-75eb-4ff0-9282-0af52299cb2f - AdalLoggerBase.cs: Initial request to authenticator
[] 2019-02-07T10:33:50.0501220Z: 6dd1c399-75eb-4ff0-9282-0af52299cb2f - AdalLoggerBase.cs: Calling activity pid:14430 tid:14480uid:10464
[] 2019-02-07T10:33:51.4939910Z: 00000000-0000-0000-0000-000000000000 - AdalLoggerBase.cs: Received Activity Result(2004)
[] 2019-02-07T10:33:51.5415990Z: 6dd1c399-75eb-4ff0-9282-0af52299cb2f - AdalLoggerBase.cs: Storing token in the cache...
[] 2019-02-07T10:33:51.5451320Z: 6dd1c399-75eb-4ff0-9282-0af52299cb2f - AdalLoggerBase.cs: An item was stored in the cache
[] 2019-02-07T10:33:51.5584070Z: 00000000-0000-0000-0000-000000000000 - AdalLoggerBase.cs: Client Info is missing. Skipping MSAL refresh token cache write
[] 2019-02-07T10:33:51.5860850Z: 6dd1c399-75eb-4ff0-9282-0af52299cb2f - AdalLoggerBase.cs: === Token Acquisition finished successfully. An access token was returned: Expiration Time: 7-2-2019 11:33:49 +00:00
[] 2019-02-07T10:33:51.5920640Z: 00000000-0000-0000-0000-000000000000 - AdalLoggerBase.cs: Serializing token cache with 1 items.

After adjusting the code a bit to add the PlatformParameters to the silent call, I end up with the following logging (note this logging is only the refresh attempt):

[] 2019-02-07T11:50:50.5004940Z: 0977568f-ae96-4e2f-8b6c-28ef24b7e9df - AdalLoggerBase.cs: Loading from cache.
[] 2019-02-07T11:50:50.5110980Z: 00000000-0000-0000-0000-000000000000 - AdalLoggerBase.cs: Deserialized 1 items to token cache.
[] 2019-02-07T11:50:50.5240530Z: 0977568f-ae96-4e2f-8b6c-28ef24b7e9df - AdalLoggerBase.cs: Looking up cache for a token...
[] 2019-02-07T11:50:50.5384930Z: 0977568f-ae96-4e2f-8b6c-28ef24b7e9df - AdalLoggerBase.cs: An item matching the requested resource was found in the cache
[] 2019-02-07T11:50:50.5422510Z: 0977568f-ae96-4e2f-8b6c-28ef24b7e9df - AdalLoggerBase.cs: A matching entry was found in the cache
[] 2019-02-07T11:50:50.5525380Z: 0977568f-ae96-4e2f-8b6c-28ef24b7e9df - AdalLoggerBase.cs: An expired or near expiry token was found in the cache
[] 2019-02-07T11:50:50.5569320Z: 0977568f-ae96-4e2f-8b6c-28ef24b7e9df - AdalLoggerBase.cs: An old item was removed from the cache
[] 2019-02-07T11:50:50.5587920Z: 0977568f-ae96-4e2f-8b6c-28ef24b7e9df - AdalLoggerBase.cs: Looking up cache for a token...
[] 2019-02-07T11:50:50.5621190Z: 0977568f-ae96-4e2f-8b6c-28ef24b7e9df - AdalLoggerBase.cs: No matching token was found in the cache
[] 2019-02-07T11:50:50.5629980Z: 0977568f-ae96-4e2f-8b6c-28ef24b7e9df - AdalLoggerBase.cs: Checking MSAL cache for user token cache
[] 2019-02-07T11:50:50.5855690Z: 0977568f-ae96-4e2f-8b6c-28ef24b7e9df - AdalLoggerBase.cs: A match was found in the MSAL cache ? False
[] 2019-02-07T11:50:50.5862110Z: 0977568f-ae96-4e2f-8b6c-28ef24b7e9df - AdalLoggerBase.cs: Looking up cache for a token...
[] 2019-02-07T11:50:50.5864950Z: 0977568f-ae96-4e2f-8b6c-28ef24b7e9df - AdalLoggerBase.cs: No matching token was found in the cache
[] 2019-02-07T11:50:50.5866950Z: 0977568f-ae96-4e2f-8b6c-28ef24b7e9df - AdalLoggerBase.cs: Checking MSAL cache for user token cache
[] 2019-02-07T11:50:50.5881180Z: 0977568f-ae96-4e2f-8b6c-28ef24b7e9df - AdalLoggerBase.cs: A match was found in the MSAL cache ? False
[] 2019-02-07T11:50:50.5886340Z: 0977568f-ae96-4e2f-8b6c-28ef24b7e9df - AdalLoggerBase.cs: Looking up cache for a token...
[] 2019-02-07T11:50:50.5889260Z: 0977568f-ae96-4e2f-8b6c-28ef24b7e9df - AdalLoggerBase.cs: No matching token was found in the cache
[] 2019-02-07T11:50:50.5892200Z: 0977568f-ae96-4e2f-8b6c-28ef24b7e9df - AdalLoggerBase.cs: Checking MSAL cache for user token cache
[] 2019-02-07T11:50:50.5908900Z: 0977568f-ae96-4e2f-8b6c-28ef24b7e9df - AdalLoggerBase.cs: A match was found in the MSAL cache ? False
[] 2019-02-07T11:50:50.5919620Z: 0977568f-ae96-4e2f-8b6c-28ef24b7e9df - AdalLoggerBase.cs: Looking up cache for a token...
[] 2019-02-07T11:50:50.5925400Z: 0977568f-ae96-4e2f-8b6c-28ef24b7e9df - AdalLoggerBase.cs: No matching token was found in the cache
[] 2019-02-07T11:50:50.5928080Z: 0977568f-ae96-4e2f-8b6c-28ef24b7e9df - AdalLoggerBase.cs: Checking MSAL cache for user token cache
[] 2019-02-07T11:50:50.5947470Z: 0977568f-ae96-4e2f-8b6c-28ef24b7e9df - AdalLoggerBase.cs: A match was found in the MSAL cache ? False
[] 2019-02-07T11:50:50.5952440Z: 0977568f-ae96-4e2f-8b6c-28ef24b7e9df - AdalLoggerBase.cs: Looking up cache for a token...
[] 2019-02-07T11:50:50.5954810Z: 0977568f-ae96-4e2f-8b6c-28ef24b7e9df - AdalLoggerBase.cs: No matching token was found in the cache
[] 2019-02-07T11:50:50.5956460Z: 0977568f-ae96-4e2f-8b6c-28ef24b7e9df - AdalLoggerBase.cs: Checking MSAL cache for user token cache
[] 2019-02-07T11:50:50.5972970Z: 0977568f-ae96-4e2f-8b6c-28ef24b7e9df - AdalLoggerBase.cs: A match was found in the MSAL cache ? False
[] 2019-02-07T11:50:50.5983210Z: 0977568f-ae96-4e2f-8b6c-28ef24b7e9df - AdalLoggerBase.cs: Either a token was not found or an exception was thrown.
[] 2019-02-07T11:50:50.6000470Z: 0977568f-ae96-4e2f-8b6c-28ef24b7e9df - AdalLoggerBase.cs: Is Android Broker use configured via PlatformParamters? True
[] 2019-02-07T11:50:50.6594900Z: 0977568f-ae96-4e2f-8b6c-28ef24b7e9df - AdalLoggerBase.cs: BrokerProxy: Found the Authenticator on the device
[] 2019-02-07T11:50:50.6658830Z: 0977568f-ae96-4e2f-8b6c-28ef24b7e9df - AdalLoggerBase.cs: BrokerProxy: CheckAccount. Getting authenticator types 16
[] 2019-02-07T11:50:50.6695000Z: 0977568f-ae96-4e2f-8b6c-28ef24b7e9df - AdalLoggerBase.cs: BrokerProxy: Getting the account list 0
[] 2019-02-07T11:50:50.6700220Z: 0977568f-ae96-4e2f-8b6c-28ef24b7e9df - AdalLoggerBase.cs: BrokerProxy: Package name is com.azure.authenticator
[] 2019-02-07T11:50:50.6798840Z: 0977568f-ae96-4e2f-8b6c-28ef24b7e9df - AdalLoggerBase.cs: BrokerProxy: Broker supports adding accounts
[] 2019-02-07T11:50:50.6803650Z: 0977568f-ae96-4e2f-8b6c-28ef24b7e9df - AdalLoggerBase.cs: Can invoke broker? True
[] 2019-02-07T11:50:50.6805970Z: 0977568f-ae96-4e2f-8b6c-28ef24b7e9df - AdalLoggerBase.cs: Trying to acquire a token using the broker...
[] 2019-02-07T11:50:50.7071250Z: 0977568f-ae96-4e2f-8b6c-28ef24b7e9df - AdalLoggerBase.cs: BrokerProxy: CheckAccount. Getting authenticator types 16
[] 2019-02-07T11:50:50.7091980Z: 0977568f-ae96-4e2f-8b6c-28ef24b7e9df - AdalLoggerBase.cs: BrokerProxy: Getting the account list 0
[] 2019-02-07T11:50:50.7097880Z: 0977568f-ae96-4e2f-8b6c-28ef24b7e9df - AdalLoggerBase.cs: BrokerProxy: Package name is com.azure.authenticator
[] 2019-02-07T11:50:50.7122400Z: 0977568f-ae96-4e2f-8b6c-28ef24b7e9df - AdalLoggerBase.cs: BrokerProxy: Broker supports adding accounts
[] 2019-02-07T11:50:50.7138300Z: 0977568f-ae96-4e2f-8b6c-28ef24b7e9df - AdalLoggerBase.cs: It switched to broker for context
[] 2019-02-07T11:50:50.7146060Z: 0977568f-ae96-4e2f-8b6c-28ef24b7e9df - AdalLoggerBase.cs: User is specified for background token request
[] 2019-02-07T11:50:50.7185900Z: 0977568f-ae96-4e2f-8b6c-28ef24b7e9df - AdalLoggerBase.cs: BrokerProxy: Getting the broker work and school accounts 
[] 2019-02-07T11:50:50.7216410Z: 0977568f-ae96-4e2f-8b6c-28ef24b7e9df - AdalLoggerBase.cs: BrokerProxy: finding account...
[] 2019-02-07T11:50:50.7221450Z: 0977568f-ae96-4e2f-8b6c-28ef24b7e9df - AdalLoggerBase.cs: BrokerProxy: Found account based on the broker account name? False
[] 2019-02-07T11:50:50.7227790Z: 0977568f-ae96-4e2f-8b6c-28ef24b7e9df - AdalLoggerBase.cs: Target account is not found
[] 2019-02-07T11:50:50.7242190Z: 0977568f-ae96-4e2f-8b6c-28ef24b7e9df - AdalLoggerBase.cs: Token is not returned from backgroud call
[] 2019-02-07T11:50:50.7245150Z: 0977568f-ae96-4e2f-8b6c-28ef24b7e9df - AdalLoggerBase.cs: Launch activity for Authenticator
[] 2019-02-07T11:50:50.7247750Z: 0977568f-ae96-4e2f-8b6c-28ef24b7e9df - AdalLoggerBase.cs: Starting Authentication Activity
[] 2019-02-07T11:50:50.7249820Z: 0977568f-ae96-4e2f-8b6c-28ef24b7e9df - AdalLoggerBase.cs: Initial request to authenticator
[] 2019-02-07T11:50:50.7540290Z: 0977568f-ae96-4e2f-8b6c-28ef24b7e9df - AdalLoggerBase.cs: Exception type: Microsoft.IdentityModel.Clients.ActiveDirectory.AdalSilentTokenAcquisitionException
[] , ErrorCode: failed_to_acquire_token_silently
[] 
[]   at Microsoft.IdentityModel.Clients.ActiveDirectory.Internal.Platform.AndroidBroker.AcquireTokenInternal (System.Collections.Generic.IDictionary`2[TKey,TValue] brokerPayload) [0x00232] in C:\agent2\_work\43\s\src\Microsoft.IdentityModel.Clients.ActiveDirectory\Platforms\android\AndroidBroker.cs:169 
[]   at Microsoft.IdentityModel.Clients.ActiveDirectory.Internal.Platform.AndroidBroker+<>c__DisplayClass11_0.<AcquireTokenUsingBrokerAsync>b__0 () [0x00000] in C:\agent2\_work\43\s\src\Microsoft.IdentityModel.Clients.ActiveDirectory\Platforms\android\AndroidBroker.cs:78 
[]   at System.Threading.Tasks.Task.InnerInvoke () [0x0000f] in <d4a23bbd2f544c30a48c44dd622ce09f>:0 
[]   at System.Threading.Tasks.Task.Execute () [0x00000] in <d4a23bbd2f544c30a48c44dd622ce09f>:0 
[] --- End of stack trace from previous location where exception was thrown ---
[]   at Microsoft.IdentityModel.Clients.ActiveDirectory.Internal.Platform.AndroidBroker+<AcquireTokenUsingBrokerAsync>d__11.MoveNext () [0x0006d] in C:\agent2\_work\43\s\src\Microsoft.IdentityModel.Clients.ActiveDirectory\Platforms\android\AndroidBroker.cs:78 
[] 2019-02-07T11:50:50.7635830Z: 0977568f-ae96-4e2f-8b6c-28ef24b7e9df - AdalLoggerBase.cs: Exception type: Microsoft.IdentityModel.Clients.ActiveDirectory.AdalSilentTokenAcquisitionException
[] , ErrorCode: failed_to_acquire_token_silently
[] 
[]   at Microsoft.IdentityModel.Clients.ActiveDirectory.Internal.Platform.AndroidBroker.AcquireTokenInternal (System.Collections.Generic.IDictionary`2[TKey,TValue] brokerPayload) [0x00232] in C:\agent2\_work\43\s\src\Microsoft.IdentityModel.Clients.ActiveDirectory\Platforms\android\AndroidBroker.cs:169 
[]   at Microsoft.IdentityModel.Clients.ActiveDirectory.Internal.Platform.AndroidBroker+<>c__DisplayClass11_0.<AcquireTokenUsingBrokerAsync>b__0 () [0x00000] in C:\agent2\_work\43\s\src\Microsoft.IdentityModel.Clients.ActiveDirectory\Platforms\android\AndroidBroker.cs:78 
[]   at System.Threading.Tasks.Task.InnerInvoke () [0x0000f] in <d4a23bbd2f544c30a48c44dd622ce09f>:0 
[]   at System.Threading.Tasks.Task.Execute () [0x00000] in <d4a23bbd2f544c30a48c44dd622ce09f>:0 
[] --- End of stack trace from previous location where exception was thrown ---
[]   at Microsoft.IdentityModel.Clients.ActiveDirectory.Internal.Platform.AndroidBroker+<AcquireTokenUsingBrokerAsync>d__11.MoveNext () [0x000cf] in C:\agent2\_work\43\s\src\Microsoft.IdentityModel.Clients.ActiveDirectory\Platforms\android\AndroidBroker.cs:83 
[] --- End of stack trace from previous location where exception was thrown ---
[]   at Microsoft.IdentityModel.Clients.ActiveDirectory.Internal.Flows.AcquireTokenHandlerBase+<RunAsync>d__58.MoveNext () [0x003cd] in C:\agent2\_work\43\s\src\Microsoft.IdentityModel.Clients.ActiveDirectory\Internal\Flows\AcquireTokenHandlerBase.cs:194 
[] 2019-02-07T11:50:50.7676410Z: 00000000-0000-0000-0000-000000000000 - AdalLoggerBase.cs: Serializing token cache with 0 items.
[] 2019-02-07T11:51:01.4135980Z: c9c99bb5-7b22-4f71-a35f-4d2627b6ee93 - AdalLoggerBase.cs: BrokerProxy: Getting the Android context
[] 2019-02-07T11:51:01.4159830Z: c9c99bb5-7b22-4f71-a35f-4d2627b6ee93 - AdalLoggerBase.cs: ADAL PCL.Android with assembly version '4.5.1.0', file version '4.5.1.0' and informational version '4.5.1-internal03601dev' is running...
[] 2019-02-07T11:51:01.4174440Z: c9c99bb5-7b22-4f71-a35f-4d2627b6ee93 - AdalLoggerBase.cs: === Token Acquisition started: 
[] 	CacheType: Microsoft.IdentityModel.Clients.ActiveDirectory.TokenCache (0 items)
[] 	Authentication Target: User
[] 	, Authority Host: login.microsoftonline.com
[] 2019-02-07T11:51:01.4372690Z: c9c99bb5-7b22-4f71-a35f-4d2627b6ee93 - AdalLoggerBase.cs: Loading from cache.
[] 2019-02-07T11:51:01.4417260Z: 00000000-0000-0000-0000-000000000000 - AdalLoggerBase.cs: Deserialized 0 items to token cache.
[] 2019-02-07T11:51:01.4431010Z: c9c99bb5-7b22-4f71-a35f-4d2627b6ee93 - AdalLoggerBase.cs: Looking up cache for a token...
[] 2019-02-07T11:51:01.4446400Z: c9c99bb5-7b22-4f71-a35f-4d2627b6ee93 - AdalLoggerBase.cs: No matching token was found in the cache
[] 2019-02-07T11:51:01.4450040Z: c9c99bb5-7b22-4f71-a35f-4d2627b6ee93 - AdalLoggerBase.cs: Checking MSAL cache for user token cache
[] 2019-02-07T11:51:01.4483820Z: c9c99bb5-7b22-4f71-a35f-4d2627b6ee93 - AdalLoggerBase.cs: A match was found in the MSAL cache ? False
[] 2019-02-07T11:51:01.4495370Z: c9c99bb5-7b22-4f71-a35f-4d2627b6ee93 - AdalLoggerBase.cs: Looking up cache for a token...
[] 2019-02-07T11:51:01.4500010Z: c9c99bb5-7b22-4f71-a35f-4d2627b6ee93 - AdalLoggerBase.cs: No matching token was found in the cache
[] 2019-02-07T11:51:01.4503320Z: c9c99bb5-7b22-4f71-a35f-4d2627b6ee93 - AdalLoggerBase.cs: Checking MSAL cache for user token cache
[] 2019-02-07T11:51:01.4538060Z: c9c99bb5-7b22-4f71-a35f-4d2627b6ee93 - AdalLoggerBase.cs: A match was found in the MSAL cache ? False
[] 2019-02-07T11:51:01.4550470Z: c9c99bb5-7b22-4f71-a35f-4d2627b6ee93 - AdalLoggerBase.cs: Looking up cache for a token...
[] 2019-02-07T11:51:01.4555520Z: c9c99bb5-7b22-4f71-a35f-4d2627b6ee93 - AdalLoggerBase.cs: No matching token was found in the cache
[] 2019-02-07T11:51:01.4558840Z: c9c99bb5-7b22-4f71-a35f-4d2627b6ee93 - AdalLoggerBase.cs: Checking MSAL cache for user token cache
[] 2019-02-07T11:51:01.4599470Z: c9c99bb5-7b22-4f71-a35f-4d2627b6ee93 - AdalLoggerBase.cs: A match was found in the MSAL cache ? False
[] 2019-02-07T11:51:01.4610270Z: c9c99bb5-7b22-4f71-a35f-4d2627b6ee93 - AdalLoggerBase.cs: Looking up cache for a token...
[] 2019-02-07T11:51:01.4614770Z: c9c99bb5-7b22-4f71-a35f-4d2627b6ee93 - AdalLoggerBase.cs: No matching token was found in the cache
[] 2019-02-07T11:51:01.4618250Z: c9c99bb5-7b22-4f71-a35f-4d2627b6ee93 - AdalLoggerBase.cs: Checking MSAL cache for user token cache
[] 2019-02-07T11:51:01.4653260Z: c9c99bb5-7b22-4f71-a35f-4d2627b6ee93 - AdalLoggerBase.cs: A match was found in the MSAL cache ? False
[] 2019-02-07T11:51:01.4707410Z: c9c99bb5-7b22-4f71-a35f-4d2627b6ee93 - AdalLoggerBase.cs: Looking up cache for a token...
[] 2019-02-07T11:51:01.4711380Z: c9c99bb5-7b22-4f71-a35f-4d2627b6ee93 - AdalLoggerBase.cs: No matching token was found in the cache
[] 2019-02-07T11:51:01.4713750Z: c9c99bb5-7b22-4f71-a35f-4d2627b6ee93 - AdalLoggerBase.cs: Checking MSAL cache for user token cache
[] 2019-02-07T11:51:01.4734110Z: c9c99bb5-7b22-4f71-a35f-4d2627b6ee93 - AdalLoggerBase.cs: A match was found in the MSAL cache ? False
[] 2019-02-07T11:51:01.4741060Z: c9c99bb5-7b22-4f71-a35f-4d2627b6ee93 - AdalLoggerBase.cs: Looking up cache for a token...
[] 2019-02-07T11:51:01.4744380Z: c9c99bb5-7b22-4f71-a35f-4d2627b6ee93 - AdalLoggerBase.cs: No matching token was found in the cache
[] 2019-02-07T11:51:01.4746790Z: c9c99bb5-7b22-4f71-a35f-4d2627b6ee93 - AdalLoggerBase.cs: Checking MSAL cache for user token cache
[] 2019-02-07T11:51:01.4764740Z: c9c99bb5-7b22-4f71-a35f-4d2627b6ee93 - AdalLoggerBase.cs: A match was found in the MSAL cache ? False
[] 2019-02-07T11:51:01.4773970Z: c9c99bb5-7b22-4f71-a35f-4d2627b6ee93 - AdalLoggerBase.cs: Either a token was not found or an exception was thrown.
[] 2019-02-07T11:51:01.4780740Z: c9c99bb5-7b22-4f71-a35f-4d2627b6ee93 - AdalLoggerBase.cs: Is Android Broker use configured via PlatformParamters? True
[] 2019-02-07T11:51:01.4965150Z: c9c99bb5-7b22-4f71-a35f-4d2627b6ee93 - AdalLoggerBase.cs: BrokerProxy: Found the Authenticator on the device
[] 2019-02-07T11:51:01.5019390Z: c9c99bb5-7b22-4f71-a35f-4d2627b6ee93 - AdalLoggerBase.cs: BrokerProxy: CheckAccount. Getting authenticator types 16
[] 2019-02-07T11:51:01.5043280Z: c9c99bb5-7b22-4f71-a35f-4d2627b6ee93 - AdalLoggerBase.cs: BrokerProxy: Getting the account list 0
[] 2019-02-07T11:51:01.5049050Z: c9c99bb5-7b22-4f71-a35f-4d2627b6ee93 - AdalLoggerBase.cs: BrokerProxy: Package name is com.azure.authenticator
[] 2019-02-07T11:51:01.5085990Z: c9c99bb5-7b22-4f71-a35f-4d2627b6ee93 - AdalLoggerBase.cs: BrokerProxy: Broker supports adding accounts
[] 2019-02-07T11:51:01.5090360Z: c9c99bb5-7b22-4f71-a35f-4d2627b6ee93 - AdalLoggerBase.cs: Can invoke broker? True
[] 2019-02-07T11:51:01.5092100Z: c9c99bb5-7b22-4f71-a35f-4d2627b6ee93 - AdalLoggerBase.cs: Trying to acquire a token using the broker...
[] 2019-02-07T11:51:01.5148880Z: c9c99bb5-7b22-4f71-a35f-4d2627b6ee93 - AdalLoggerBase.cs: BrokerProxy: CheckAccount. Getting authenticator types 16
[] 2019-02-07T11:51:01.5172090Z: c9c99bb5-7b22-4f71-a35f-4d2627b6ee93 - AdalLoggerBase.cs: BrokerProxy: Getting the account list 0
[] 2019-02-07T11:51:01.5177480Z: c9c99bb5-7b22-4f71-a35f-4d2627b6ee93 - AdalLoggerBase.cs: BrokerProxy: Package name is com.azure.authenticator
[] 2019-02-07T11:51:01.5199340Z: c9c99bb5-7b22-4f71-a35f-4d2627b6ee93 - AdalLoggerBase.cs: BrokerProxy: Broker supports adding accounts
[] 2019-02-07T11:51:01.5205090Z: c9c99bb5-7b22-4f71-a35f-4d2627b6ee93 - AdalLoggerBase.cs: It switched to broker for context
[] 2019-02-07T11:51:01.5210520Z: c9c99bb5-7b22-4f71-a35f-4d2627b6ee93 - AdalLoggerBase.cs: User is specified for background token request
[] 2019-02-07T11:51:01.5217100Z: c9c99bb5-7b22-4f71-a35f-4d2627b6ee93 - AdalLoggerBase.cs: BrokerProxy: Getting the broker work and school accounts 
[] 2019-02-07T11:51:01.5241240Z: c9c99bb5-7b22-4f71-a35f-4d2627b6ee93 - AdalLoggerBase.cs: BrokerProxy: finding account...
[] 2019-02-07T11:51:01.5245890Z: c9c99bb5-7b22-4f71-a35f-4d2627b6ee93 - AdalLoggerBase.cs: BrokerProxy: Found account based on the broker account name? False
[] 2019-02-07T11:51:01.5247870Z: c9c99bb5-7b22-4f71-a35f-4d2627b6ee93 - AdalLoggerBase.cs: Target account is not found
[] 2019-02-07T11:51:01.5249600Z: c9c99bb5-7b22-4f71-a35f-4d2627b6ee93 - AdalLoggerBase.cs: Token is not returned from backgroud call
[] 2019-02-07T11:51:01.5251250Z: c9c99bb5-7b22-4f71-a35f-4d2627b6ee93 - AdalLoggerBase.cs: Launch activity for Authenticator
[] 2019-02-07T11:51:01.5252960Z: c9c99bb5-7b22-4f71-a35f-4d2627b6ee93 - AdalLoggerBase.cs: Starting Authentication Activity
[] 2019-02-07T11:51:01.5254680Z: c9c99bb5-7b22-4f71-a35f-4d2627b6ee93 - AdalLoggerBase.cs: Initial request to authenticator
[] 2019-02-07T11:51:02.1972730Z: c9c99bb5-7b22-4f71-a35f-4d2627b6ee93 - AdalLoggerBase.cs: Calling activity pid:20829 tid:20872uid:10464
[] 2019-02-07T11:51:03.5737440Z: 00000000-0000-0000-0000-000000000000 - AdalLoggerBase.cs: Received Activity Result(2004)
[] 2019-02-07T11:51:03.6173580Z: c9c99bb5-7b22-4f71-a35f-4d2627b6ee93 - AdalLoggerBase.cs: Storing token in the cache...
[] 2019-02-07T11:51:03.6196550Z: c9c99bb5-7b22-4f71-a35f-4d2627b6ee93 - AdalLoggerBase.cs: An item was stored in the cache
[] 2019-02-07T11:51:03.6333060Z: 00000000-0000-0000-0000-000000000000 - AdalLoggerBase.cs: Client Info is missing. Skipping MSAL refresh token cache write
[] 2019-02-07T11:51:03.6719250Z: c9c99bb5-7b22-4f71-a35f-4d2627b6ee93 - AdalLoggerBase.cs: === Token Acquisition finished successfully. An access token was returned: Expiration Time: 7-2-2019 12:51:02 +00:00
[] 2019-02-07T11:51:03.6778090Z: 00000000-0000-0000-0000-000000000000 - AdalLoggerBase.cs: Serializing token cache with 1 items.

If I'm reading the logger right, it seems to fail because the broker is unable to determine which account is supposed to be used. I find that odd since I'm explicitly setting the UserIdentifier when calling.

Since a lot has happened since this thread began, I will post the latest version of my code as well. Please let me know if you find anything else.

public class AndroidAuthenticationService : IAuthenticationService
    {

        private const string _tenantId = "<REDACTED>";
        private const string _clientId = "<REDACTED>";
        private const string _redirectUri = "msauth://<REDACTED>";
        private const string _resource = "<REDACTED>";
        private const bool _useBroker = true;

        public AndroidAuthenticationService()
        {
        }

        public AuthenticationResult User { get; private set; }

        public async Task EnsureLoggedInAsync()
        {
            var context = new AuthenticationContext($"https://login.microsoftonline.com/{_tenantId}");
            var tokens = context.TokenCache.ReadItems().Where(t => t.Resource == _resource);
            var userId = tokens.GroupBy(t => t.DisplayableId).Count() == 1 ? new UserIdentifier(tokens.GroupBy(t => t.DisplayableId).Single().First().DisplayableId, UserIdentifierType.RequiredDisplayableId) : null;

            var param = new PlatformParameters(CrossCurrentActivity.Current.Activity, _useBroker, PromptBehavior.Auto);

            try
            {
                if (userId == null)
                {
                    User = await context.AcquireTokenSilentAsync(_resource, _clientId);
                }
                else
                {
                    User = await context.AcquireTokenSilentAsync(_resource, _clientId, userId, param);
                }
            }
            catch (AdalException ex)
            {
            
                if (ex.ErrorCode == AdalError.FailedToAcquireTokenSilently || ex.ErrorCode == AdalError.InteractionRequired)
                {
                    if (userId == null)
                    {
                        User = await context.AcquireTokenAsync(_resource, _clientId, new Uri(_redirectUri), param);
                    }
                    else
                    {
                        User = await context.AcquireTokenAsync(_resource, _clientId, new Uri(_redirectUri), param, userId);
                    }
                }
                else
                {
                    // Unexpected kind of AdalException. Throw
                    throw;
                }
            }
        }

@bgavrilMS
Copy link
Member

Ok, now it seems to not be able to get the accounts from the broker. Could you try to run the code from earlier and try again please? This is:

  string WORK_AND_SCHOOL_TYPE = "com.microsoft.workaccount";
            var accManager = AccountManager.Get(Application.Context);
            // Any accounts returned? Possibly not
            Account[] accounts = accManager.GetAccountsByType(WORK_AND_SCHOOL_TYPE);

    
            // The Android docs state that "unless the authenticator owns the accounts or the user grants that access" GetAccounts will return an empty array.

            // The docs state that you should call NewChooseAccountIntent so that the user grants access
            Intent intent = AccountManager.NewChooseAccountIntent(null, null, new[] { WORK_AND_SCHOOL_TYPE }, null, null, null, null);
            StartActivity(intent);

            // Now you should have access
            var accounts2 = accManager.GetAccountsByType(WORK_AND_SCHOOL_TYPE);

I'm also adding @trwalke who might be able to help, as I'm on holiday and traveling starting tomorrow.

@Anubhab1991
Copy link

Anubhab1991 commented Feb 12, 2019

Any updates on this?
I am trying to achieve the same but the AcquireTokenSilentAsync methods gives me a exception saying that there is no token is cache and then opening MSAuthenticator and closing it up.

PFB my code

public async Task<AuthenticationResult> Authenticate2(string authority, string resource, string clientId, string returnUri, Activity CallActivity)
        {
            var authContext = new AuthenticationContext(authority);
            AuthenticationResult authResult;
            string WORK_AND_SCHOOL_TYPE = "com.microsoft.workaccount";
            var accManager = AccountManager.Get(Application.Context);
            var accounts = accManager.GetAccountsByType(WORK_AND_SCHOOL_TYPE);

            try
            {
                authResult = await authContext.AcquireTokenSilentAsync(resource, clientId, new UserIdentifier(accounts[0].Name, UserIdentifierType.RequiredDisplayableId));
                return authResult;
            }
            catch (AdalException adalException)
            {
                if (adalException.ErrorCode == AdalError.FailedToAcquireTokenSilently
                        || adalException.ErrorCode == AdalError.InteractionRequired)
                {
                    var result = await authContext.AcquireTokenAsync(resource, clientId, new Uri(ConfigData.RedirectUrl),
                                                                     new PlatformParameters(CallActivity, true, PromptBehavior.Auto), new UserIdentifier(accounts[0].Name, UserIdentifierType.RequiredDisplayableId));

                    return result;
                }
                return null;
            }
            catch (Exception ex)
            {
                Crashes.TrackError(ex);
                return null;
            }
            finally
            {
                //authContext.TokenCache.Clear();
            }
        }

What i cant understand is why it is removing from token cache and then again trying to open MSAuthenticator to get new token as shown in Bold below.

`[Mono] Assembly Ref addref System.ServiceModel.Internals[0x729645e100] -> System[0x7296788380]: 10
[Mono] Assembly Ref addref System.Runtime.Serialization[0x7296136e80] -> System.Core[0x72a75a0e00]: 7
[] 2019-02-12T05:56:07.1705320Z: 077d50b0-0e7d-4025-8c94-eaaea46e1168 - AdalLoggerBase.cs: Loading from cache.
[] 2019-02-12T05:56:07.2507750Z: 00000000-0000-0000-0000-000000000000 - AdalLoggerBase.cs: Deserialized 1 items to token cache.
[] 2019-02-12T05:56:07.2600450Z: 077d50b0-0e7d-4025-8c94-eaaea46e1168 - AdalLoggerBase.cs: Looking up cache for a token...
[] 2019-02-12T05:56:07.3609000Z: 077d50b0-0e7d-4025-8c94-eaaea46e1168 - AdalLoggerBase.cs: Cross Tenant refresh token was found in the cache
[] 2019-02-12T05:56:07.3635660Z: 077d50b0-0e7d-4025-8c94-eaaea46e1168 - AdalLoggerBase.cs: An old item was removed from the cache

[] 2019-02-12T05:56:07.3641900Z: 077d50b0-0e7d-4025-8c94-eaaea46e1168 - AdalLoggerBase.cs: Looking up cache for a token...
[] 2019-02-12T05:56:07.3644410Z: 077d50b0-0e7d-4025-8c94-eaaea46e1168 - AdalLoggerBase.cs: No matching token was found in the cache
[] 2019-02-12T05:56:07.3646630Z: 077d50b0-0e7d-4025-8c94-eaaea46e1168 - AdalLoggerBase.cs: Checking MSAL cache for user token cache
[Mono] DllImport searching in: '__Internal' ('(null)').
[Mono] Searching for 'java_interop_jnienv_call_boolean_method'.
[Mono] Probing 'java_interop_jnienv_call_boolean_method'.
[Mono] Found as 'java_interop_jnienv_call_boolean_method'.
[] 2019-02-12T05:56:07.3825280Z: 077d50b0-0e7d-4025-8c94-eaaea46e1168 - AdalLoggerBase.cs: Looking up cache for a token...
[] 2019-02-12T05:56:07.3827970Z: 077d50b0-0e7d-4025-8c94-eaaea46e1168 - AdalLoggerBase.cs: No matching token was found in the cache
[] 2019-02-12T05:56:07.3830080Z: 077d50b0-0e7d-4025-8c94-eaaea46e1168 - AdalLoggerBase.cs: Checking MSAL cache for user token cache
[] 2019-02-12T05:56:07.3838680Z: 077d50b0-0e7d-4025-8c94-eaaea46e1168 - AdalLoggerBase.cs: Looking up cache for a token...
[] 2019-02-12T05:56:07.3841040Z: 077d50b0-0e7d-4025-8c94-eaaea46e1168 - AdalLoggerBase.cs: No matching token was found in the cache
[] 2019-02-12T05:56:07.3843080Z: 077d50b0-0e7d-4025-8c94-eaaea46e1168 - AdalLoggerBase.cs: Checking MSAL cache for user token cache
[] 2019-02-12T05:56:07.3851450Z: 077d50b0-0e7d-4025-8c94-eaaea46e1168 - AdalLoggerBase.cs: Looking up cache for a token...
[] 2019-02-12T05:56:07.3853780Z: 077d50b0-0e7d-4025-8c94-eaaea46e1168 - AdalLoggerBase.cs: No matching token was found in the cache
[] 2019-02-12T05:56:07.3855740Z: 077d50b0-0e7d-4025-8c94-eaaea46e1168 - AdalLoggerBase.cs: Checking MSAL cache for user token cache
[] 2019-02-12T05:56:07.3863520Z: 077d50b0-0e7d-4025-8c94-eaaea46e1168 - AdalLoggerBase.cs: Looking up cache for a token...
[] 2019-02-12T05:56:07.3865770Z: 077d50b0-0e7d-4025-8c94-eaaea46e1168 - AdalLoggerBase.cs: No matching token was found in the cache
[] 2019-02-12T05:56:07.3867670Z: 077d50b0-0e7d-4025-8c94-eaaea46e1168 - AdalLoggerBase.cs: Checking MSAL cache for user token cache
[] 2019-02-12T05:56:07.3915790Z: 077d50b0-0e7d-4025-8c94-eaaea46e1168 - AdalLoggerBase.cs: No token matching arguments found in the cache
[] 2019-02-12T05:56:07.4193820Z: 077d50b0-0e7d-4025-8c94-eaaea46e1168 - AdalLoggerBase.cs: Exception type: Microsoft.IdentityModel.Clients.ActiveDirectory.AdalSilentTokenAcquisitionException
[] , ErrorCode: failed_to_acquire_token_silently
[]
[] at Microsoft.IdentityModel.Clients.ActiveDirectory.Internal.Flows.AcquireTokenSilentHandler.SendTokenRequestAsync () [0x00022] in <6269183206ac414a8cca2a85975fef3c>:0
[] at Microsoft.IdentityModel.Clients.ActiveDirectory.Internal.Flows.AcquireTokenHandlerBase+d__55.MoveNext () [0x0009a] in <6269183206ac414a8cca2a85975fef3c>:0
[] --- End of stack trace from previous location where exception was thrown ---
[] at Microsoft.IdentityModel.Clients.ActiveDirectory.Internal.Flows.AcquireTokenHandlerBase+d__53.MoveNext () [0x004b1] in <6269183206ac414a8cca2a85975fef3c>:0
[] 2019-02-12T05:56:07.4241570Z: 00000000-0000-0000-0000-000000000000 - AdalLoggerBase.cs: Serializing token cache with 0 items.
[Mono] DllImport searching in: '__Internal' ('(null)').
[Mono] Searching for 'java_interop_jnienv_call_void_method'.
[Mono] Probing 'java_interop_jnienv_call_void_method'.
[Mono] Found as 'java_interop_jnienv_call_void_method'.
Resolved pending breakpoint at '/Users/anubhab.mishra/Projects/TemplateApp/TemplateApp/Authentication/Authenticator.cs:51,1' to void TemplateApp.Authentication.Authenticator.d__0.MoveNext () [0x00368].
[] 2019-02-12T05:56:23.6264640Z: 85cf4448-3291-4cb1-bde0-893fbd9bad6b - AdalLoggerBase.cs: ADAL PCL.Android with assembly version '4.4.1.0', file version '4.4.1.0' and informational version '4.4.1' is running...
[] 2019-02-12T05:56:23.6276740Z: 85cf4448-3291-4cb1-bde0-893fbd9bad6b - AdalLoggerBase.cs: === Token Acquisition started:
[] CacheType: null
[] Authentication Target: User
[] , Authority Host: login.microsoftonline.com
[] 2019-02-12T05:56:23.6403570Z: 85cf4448-3291-4cb1-bde0-893fbd9bad6b - AdalLoggerBase.cs: Loading from cache.
[] 2019-02-12T05:56:23.6420080Z: 00000000-0000-0000-0000-000000000000 - AdalLoggerBase.cs: Deserialized 0 items to token cache.
[] 2019-02-12T05:56:23.6426270Z: 85cf4448-3291-4cb1-bde0-893fbd9bad6b - AdalLoggerBase.cs: Looking up cache for a token...
[] 2019-02-12T05:56:23.6430010Z: 85cf4448-3291-4cb1-bde0-893fbd9bad6b - AdalLoggerBase.cs: No matching token was found in the cache
[] 2019-02-12T05:56:23.6433330Z: 85cf4448-3291-4cb1-bde0-893fbd9bad6b - AdalLoggerBase.cs: Checking MSAL cache for user token cache
[] 2019-02-12T05:56:23.6447240Z: 85cf4448-3291-4cb1-bde0-893fbd9bad6b - AdalLoggerBase.cs: Looking up cache for a token...
[] 2019-02-12T05:56:23.6451740Z: 85cf4448-3291-4cb1-bde0-893fbd9bad6b - AdalLoggerBase.cs: No matching token was found in the cache
[] 2019-02-12T05:56:23.6454670Z: 85cf4448-3291-4cb1-bde0-893fbd9bad6b - AdalLoggerBase.cs: Checking MSAL cache for user token cache
[] 2019-02-12T05:56:23.6466770Z: 85cf4448-3291-4cb1-bde0-893fbd9bad6b - AdalLoggerBase.cs: Looking up cache for a token...
[] 2019-02-12T05:56:23.6470460Z: 85cf4448-3291-4cb1-bde0-893fbd9bad6b - AdalLoggerBase.cs: No matching token was found in the cache
[] 2019-02-12T05:56:23.6473390Z: 85cf4448-3291-4cb1-bde0-893fbd9bad6b - AdalLoggerBase.cs: Checking MSAL cache for user token cache
[] 2019-02-12T05:56:23.6484860Z: 85cf4448-3291-4cb1-bde0-893fbd9bad6b - AdalLoggerBase.cs: Looking up cache for a token...
[] 2019-02-12T05:56:23.6489100Z: 85cf4448-3291-4cb1-bde0-893fbd9bad6b - AdalLoggerBase.cs: No matching token was found in the cache
[] 2019-02-12T05:56:23.6492090Z: 85cf4448-3291-4cb1-bde0-893fbd9bad6b - AdalLoggerBase.cs: Checking MSAL cache for user token cache
[] 2019-02-12T05:56:23.6503360Z: 85cf4448-3291-4cb1-bde0-893fbd9bad6b - AdalLoggerBase.cs: Looking up cache for a token...
[] 2019-02-12T05:56:23.6506970Z: 85cf4448-3291-4cb1-bde0-893fbd9bad6b - AdalLoggerBase.cs: No matching token was found in the cache
[] 2019-02-12T05:56:23.6509860Z: 85cf4448-3291-4cb1-bde0-893fbd9bad6b - AdalLoggerBase.cs: Checking MSAL cache for user token cache
[] 2019-02-12T05:56:23.6521190Z: 85cf4448-3291-4cb1-bde0-893fbd9bad6b - AdalLoggerBase.cs: Looking up cache for a token...
[] 2019-02-12T05:56:23.6524760Z: 85cf4448-3291-4cb1-bde0-893fbd9bad6b - AdalLoggerBase.cs: No matching token was found in the cache
[] 2019-02-12T05:56:23.6527610Z: 85cf4448-3291-4cb1-bde0-893fbd9bad6b - AdalLoggerBase.cs: Checking MSAL cache for user token cache
[Mono] Assembly Ref addref Mono.Android[0x72a75a0600] -> System.Xml[0x7296136f80]: 4
[Mono] DllImport searching in: '__Internal' ('(null)').
[Mono] Searching for 'java_interop_jnienv_call_int_method_a'.
[Mono] Probing 'java_interop_jnienv_call_int_method_a'.
[Mono] Found as 'java_interop_jnienv_call_int_method_a'.
[Mono] DllImport searching in: '__Internal' ('(null)').
[Mono] Searching for 'java_interop_jnienv_new_byte_array'.
[Mono] Probing 'java_interop_jnienv_new_byte_array'.
[Mono] Found as 'java_interop_jnienv_new_byte_array'.
[Mono] DllImport searching in: '__Internal' ('(null)').
[Mono] Searching for 'java_interop_jnienv_set_byte_array_region'.
[Mono] Probing 'java_interop_jnienv_set_byte_array_region'.
[Mono] Found as 'java_interop_jnienv_set_byte_array_region'.
[] 2019-02-12T05:56:23.7450490Z: 85cf4448-3291-4cb1-bde0-893fbd9bad6b - AdalLoggerBase.cs: Broker supports to add user through app
[] 2019-02-12T05:56:23.7688900Z: 85cf4448-3291-4cb1-bde0-893fbd9bad6b - AdalLoggerBase.cs: Broker supports to add user through app
[] 2019-02-12T05:56:23.7694180Z: 85cf4448-3291-4cb1-bde0-893fbd9bad6b - AdalLoggerBase.cs: It switched to broker for context: com.test.mytestApp
[] 2019-02-12T05:56:23.7703970Z: 85cf4448-3291-4cb1-bde0-893fbd9bad6b - AdalLoggerBase.cs: User is specified for background token request
[] 2019-02-12T05:56:23.8315150Z: 85cf4448-3291-4cb1-bde0-893fbd9bad6b - AdalLoggerBase.cs: Received result from Authenticator
[] 2019-02-12T05:56:24.3554570Z: 85cf4448-3291-4cb1-bde0-893fbd9bad6b - AdalLoggerBase.cs: Exception type: Java.Lang.IllegalArgumentException
[]
[] at Java.Interop.JniEnvironment+InstanceMethods.CallObjectMethod (Java.Interop.JniObjectReference instance, Java.Interop.JniMethodInfo method, Java.Interop.JniArgumentValue* args) [0x00069] in :0
[] at Android.Runtime.JNIEnv.CallObjectMethod (System.IntPtr jobject, System.IntPtr jmethod, Android.Runtime.JValue* parms) [0x0000e] in :0
[] at Android.Accounts.IAccountManagerFutureInvoker.GetResult (System.Int64 timeout, Java.Util.Concurrent.TimeUnit unit) [0x0006d] in :0
[] at Microsoft.IdentityModel.Clients.ActiveDirectory.Internal.Platform.BrokerProxy.GetAuthTokenInBackground (Microsoft.IdentityModel.Clients.ActiveDirectory.Internal.Platform.AuthenticationRequest request, Android.App.Activity callerActivity) [0x000c9] in <6269183206ac414a8cca2a85975fef3c>:0
[] --- End of managed Java.Lang.IllegalArgumentException stack trace ---
[] java.lang.IllegalArgumentException: Caller package name or UID is not set.
[] at android.accounts.AccountManager.convertErrorToException(AccountManager.java:2508)
[] at android.accounts.AccountManager.-wrap0(Unknown Source:0)
[] at android.accounts.AccountManager$AmsTask$Response.onError(AccountManager.java:2347)
[] at android.accounts.IAccountManagerResponse$Stub.onTransact(IAccountManagerResponse.java:69)
[] at android.os.Binder.execTransact(Binder.java:682)
[]
[] 2019-02-12T05:56:24.3559520Z: 85cf4448-3291-4cb1-bde0-893fbd9bad6b - AdalLoggerBase.cs: Returning result from Authenticator
[] 2019-02-12T05:56:24.3562370Z: 85cf4448-3291-4cb1-bde0-893fbd9bad6b - AdalLoggerBase.cs: Token is not returned from backgroud call
[] 2019-02-12T05:56:24.3565000Z: 85cf4448-3291-4cb1-bde0-893fbd9bad6b - AdalLoggerBase.cs: Launch activity for Authenticator
[] 2019-02-12T05:56:24.3568020Z: 85cf4448-3291-4cb1-bde0-893fbd9bad6b - AdalLoggerBase.cs: Starting Authentication Activity
[] 2019-02-12T05:56:24.3571310Z: 85cf4448-3291-4cb1-bde0-893fbd9bad6b - AdalLoggerBase.cs: Initial request to authenticator
[] 2019-02-12T05:56:24.4404090Z: 85cf4448-3291-4cb1-bde0-893fbd9bad6b - AdalLoggerBase.cs: Calling activity pid:1925 tid:2009uid:10286
[ViewRootImpl@f849235[LoginActivity]] MSG_WINDOW_FOCUS_CHANGED 0
[OpenGLRenderer] eglDestroySurface = 0x72aee28af0
[ViewRootImpl@f849235[LoginActivity]] Relayout returned: old=[0,0][1080,2220] new=[0,0][1080,2220] result=0x5 surface={valid=false 0} changed=true
[ViewRootImpl@f849235[LoginActivity]] Relayout returned: old=[0,0][1080,2220] new=[0,0][1080,2220] result=0x1 surface={valid=false 0} changed=false
[] 2019-02-12T05:56:26.7093560Z: 00000000-0000-0000-0000-000000000000 - AdalLoggerBase.cs: Received Activity Result(2004)
[Mono] DllImport searching in: '__Internal' ('(null)').
[Mono] Searching for 'java_interop_jnienv_call_long_method_a'.
[Mono] Probing 'java_interop_jnienv_call_long_method_a'.
[Mono] Found as 'java_interop_jnienv_call_long_method_a'.
[] 2019-02-12T05:56:26.7611520Z: 85cf4448-3291-4cb1-bde0-893fbd9bad6b - AdalLoggerBase.cs: Storing token in the cache...
[] 2019-02-12T05:56:26.7625990Z: 85cf4448-3291-4cb1-bde0-893fbd9bad6b - AdalLoggerBase.cs: An item was stored in the cache
[Surface] sf_framedrop debug : 0x4f4c, game : false, logging : 0
[ViewRootImpl@f849235[LoginActivity]] Relayout returned: old=[0,0][1080,2220] new=[0,0][1080,2220] result=0x7 surface={valid=true 492150988800} changed=true
[] 2019-02-12T05:56:26.7710070Z: 00000000-0000-0000-0000-000000000000 - AdalLoggerBase.cs: Client Info is missing. Skipping MSAL refresh token cache write
[mali_winsys] EGLint new_window_surface(egl_winsys_display *, void *, EGLSurface, EGLConfig, egl_winsys_surface **, egl_color_buffer_format *, EGLBoolean) returns 0x3000, [1080x2220]-format:1
[OpenGLRenderer] eglCreateWindowSurface = 0x72aee28af0
[ViewRootImpl@f849235[LoginActivity]] MSG_WINDOW_FOCUS_CHANGED 1
[InputMethodManager] Starting input: tba=android.view.inputmethod.EditorInfo@e75a295 nm : com.test.mytestApp ic=null
[InputMethodManager] startInputInner - mService.startInputOrWindowGainedFocus
[] 2019-02-12T05:56:26.7901320Z: 85cf4448-3291-4cb1-bde0-893fbd9bad6b - AdalLoggerBase.cs: === Token Acquisition finished successfully. An access token was returned: Expiration Time: 12/02/2019 06:56:25 +00:00
[] 2019-02-12T05:56:26.7936230Z: 00000000-0000-0000-0000-000000000000 - AdalLoggerBase.cs: Serializing token cache with 1 items.
12/02/2019 06:56:25 +00:00
[Mono] Assembly Ref addref Xamarin.Android.Support.Core.UI[0x72a7593c80] -> Java.Interop[0x72a75a0b80]: 6
[Mono] Assembly Ref addref Xamarin.Android.Support.Design[0x72a7593e00] -> Java.Interop[0x72a75a0b80]: 7
[Mono] Assembly Ref addref Xamarin.Android.Support.Design[0x72a7593e00] -> Xamarin.Android.Support.Core.UI[0x72a7593c80]: 4
[ViewRootImpl@9b66b0a[MainActivity]] setView = DecorView@b04cf7b[MainActivity] TM=true MM=false
[ViewRootImpl@f849235[LoginActivity]] MSG_WINDOW_FOCUS_CHANGED 0
[InputMethodManager] Not IME target window, ignoring
[ViewRootImpl@9b66b0a[MainActivity]] dispatchAttachedToWindow
[Surface] sf_framedrop debug : 0x4f4c, game : false, logging : 0
[ViewRootImpl@9b66b0a[MainActivity]] Relayout returned: old=[0,0][0,0] new=[0,0][1080,2220] result=0x7 surface={valid=true 491855880192} changed=true
[mali_winsys] EGLint new_window_surface(egl_winsys_display *, void *, EGLSurface, EGLConfig, egl_winsys_surface **, egl_color_buffer_format *, EGLBoolean) returns 0x3000, [1080x2220]-format:1
[OpenGLRenderer] eglCreateWindowSurface = 0x72aee293b0
[ViewRootImpl@9b66b0a[MainActivity]] Relayout returned: old=[0,0][1080,2220] new=[0,0][1080,2220] result=0x3 surface={valid=true 491855880192} changed=false
[zygote64] Do partial code cache collection, code=30KB, data=29KB
[zygote64] After code cache collection, code=30KB, data=29KB
[zygote64] Increasing code cache capacity to 128KB
[ViewRootImpl@9b66b0a[MainActivity]] MSG_RESIZED_REPORT: frame=Rect(0, 0 - 1080, 2220) ci=Rect(0, 72 - 0, 0) vi=Rect(0, 72 - 0, 0) or=1
[ViewRootImpl@9b66b0a[MainActivity]] MSG_WINDOW_FOCUS_CHANGED 1
[InputMethodManager] Starting input: tba=android.view.inputmethod.EditorInfo@6c0e63f nm : com.test.mytestApp ic=null
[InputMethodManager] startInputInner - mService.startInputOrWindowGainedFocus
[OpenGLRenderer] eglDestroySurface = 0x72aee28af0
[ViewRootImpl@f849235[LoginActivity]] Relayout returned: old=[0,0][1080,2220] new=[0,0][1080,2220] result=0x5 surface={valid=false 0} changed=true
[zygote64] Do partial code cache collection, code=31KB, data=40KB
[zygote64] After code cache collection, code=31KB, data=40KB
[zygote64] Increasing code cache capacity to 256KB
[zygote64] Compiler allocated 9MB to compile void android.widget.TextView.(android.content.Context, android.util.AttributeSet, int, int)

`

@Anubhab1991
Copy link

@bgavrilMS @trwalke any updates on this thread?

@trwalke
Copy link
Member

trwalke commented Feb 15, 2019

Hi @Anubhab1991 I am looking at your issue at the moment and I will have an update for you shortly.
Thanks

@trwalke
Copy link
Member

trwalke commented Feb 20, 2019

@sourcefile were you able to run the code that @bgavrilMS sent you?
@Anubhab1991 I am unable to replicate the token being removed from the cache. However, the broker should not be returning a refresh token to you at all. only an access token.

@Anubhab1991 can you make a successful interactive authentication call and verify if a refresh token was sent back to you in the AuthenticationResult object? can you also send the logs of this call?

@sourcefile
Copy link
Author

Hi @trwalke and @bgavrilMS

I tried the snippet Bogdan provided, but again to no success. As far as I can see, the first time I log in, the account variables are empty. Personally, I'm not surprised as it is the first time the application starts.

After logging in and waiting the usual hour, I try to refresh. I run Bogdans snippet before attempting to collect a new access token from the broker. At this stage, both account variables contain one account (the correct account), but refreshing silently is still failing.

I'm still using Bogdans internal MyGet version of the ADAL package to avoid introducing too many moving parts. Please let me know if you need any more information.

@sourcefile
Copy link
Author

Hi @bgavrilMS
After our debugging session, I did some more tests to make sure the solution was working. One thing I noticed is the proposed workaround only works when the ADAL project is referenced. When using the NuGet package, this fix doesn't work. Right now, I have no idea what's causing this to happen.

While waiting for a more clean fix, we will implement this workaround in our solution, and reference the project directly. Thanks for all your help with this!

@bgavrilMS
Copy link
Member

That is quite strange. Might be a timing issue?

@sourcefile
Copy link
Author

I don't think so. I've triggered the pop-up several times in a single testrun and it still fails. Could it be since the code in the NuGet package is pre-compiled as opposed to including the project where it will compile at the same time as the rest of the app?

@bgavrilMS
Copy link
Member

The Android team are working hard to make the broker compatible with MSAL, our next-gen auth library. We're focusing resources on improving the experience in MSAL (e.g. bypass the account picker by using a background service), so I'm going to close this issue.

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

No branches or pull requests

5 participants