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

Android + Broker - interactive auth is forced when requesting different resources #1353

Closed
1 task done
EldinHb opened this issue Oct 25, 2018 · 30 comments
Closed
1 task done

Comments

@EldinHb
Copy link

EldinHb commented Oct 25, 2018

Which Version of ADAL are you using ?
4.3

Which platform has the issue?
Xamarin.Android

What authentication flow has the issue?

  • Desktop / Mobile
    • Interactive

Repro
While using the broker to authenticate users the tokencache does not have a refreshtoken.

See code:

if (authContext.TokenCache.ReadItems().Any())
    authContext = new AuthenticationContext(authContext.TokenCache.ReadItems().First().Authority);
else
    var authContext = new AuthenticationContext(authority);

var uri = new Uri(redirectUri);
var platformParams = new PlatformParameters(Plugin.CurrentActivity.CrossCurrentActivity.Current.Activity, true);
authResult = await authContext.AcquireTokenAsync(resource, clientId, uri, platformParams);

Expected behavior
TokenCache has a RefreshToken that is not null.

Actual behavior
RefreshToken in TokenCache is null when using a broker. When platformParams.UseBroker = false; the behavior is as expected and RefreshToken in TokenCache is not null.

@jmprieur
Copy link
Contributor

@eldin66 :
What are you trying to do? What is your scenario?

I believe that what you observe is the expected behavior as, when an app uses the broker, the Refresh token is really stored and refreshed by the broker itself. (ADAL delegates token acquisition to the broker)

Did you ever see that the Refresh token was not null?
cc: @jennyf19

@EldinHb
Copy link
Author

EldinHb commented Oct 26, 2018

@jmprieur
In our scenario the user should be able to login with the broker (this works), then the token should get refreshed if necessary to reduce the amount of logins the user should do. However, the TokenCache RefreshToken is null so we cannot refresh the session meaning the user has to login every time the token expires or gets removed.

Did you ever see that the Refresh token was not null?
Yes, this works perfectly on Xamarin.iOS. Which is why I thought it is a bug on the Android version.

@jmprieur
Copy link
Contributor

@eldin66 : @jennyf19 will confirm, but I believe that the reason why the refresh token is kept locally in ADAL.NET for Xamarin.iOS, is otherwise the application would be interrupted to display the broker app, and therefore the experience would not be good. On Android, this is not needed as apps can be called in the background, and therefore the Refresh token is kept in the broker.

Again do you see the access token not being refreshed silently on Android (that would be a bug). The fact that the implementation is different (the refreshment is done by the broker, not the application), should not matter app developers?

@EldinHb
Copy link
Author

EldinHb commented Oct 29, 2018

@jmprieur
Okay, that makes sense, and no it does not really matter for me how it gets refreshed.

The token does not get refreshed silently on Android when using the broker.

@jmprieur jmprieur added bug and removed By Design labels Oct 29, 2018
@jmprieur
Copy link
Contributor

@jennyf19 : The token does not get refreshed silently on Android when using the broker.

@EldinHb
Copy link
Author

EldinHb commented Oct 30, 2018

Are you able to give an ETA for this bugfix? This so we can decide how to move forward with our planning.

@jmprieur
Copy link
Contributor

@jennyf19 is looking at it.

@EldinHb
Copy link
Author

EldinHb commented Nov 5, 2018

Any update on this issue?

Edit: Oops, accidentally closed issue when commenting.

@EldinHb EldinHb closed this as completed Nov 5, 2018
@EldinHb EldinHb reopened this Nov 5, 2018
@jennyf19
Copy link
Contributor

jennyf19 commented Nov 6, 2018

@eldin66 we've been prioritizing msal issues. I will get to this asap.

@EldinHb
Copy link
Author

EldinHb commented Nov 6, 2018

Thanks for the update.

@EldinHb
Copy link
Author

EldinHb commented Dec 11, 2018

Is there an approximate ETA available for this bug?

@jennyf19
Copy link
Contributor

@eldin66 Sorry for the delay. @bgavrilMS is working on another broker issue and will keep you updated. thanks.

@jennyf19 jennyf19 assigned bgavrilMS and unassigned jennyf19 Dec 11, 2018
@bgavrilMS
Copy link
Member

Hi @eldin66 - just a quick update here. We've had several users report an issue on Android, when using the broker. It seems that the bug repros when the application is set to access multiple resources. I am still trying to repro this, but a rough repro scenario is:

  1. Configure an app to allow acess to 2 resources (e.g. Microsoft Graph and Power BI)
  2. Acquire token interactive for resource1 (the consent screen that appears shows that we are actually requesting a token for both resources, which is expected)
  3. Acquire Token Silent for resource2

Actual: the silent call fails
Expected: the silent call should return the token

Impact: if the silent call fails, apps typically fallback to an interactive call => user prompt for password again.

@EldinHb
Copy link
Author

EldinHb commented Dec 17, 2018

Hi @bgavrilMS , Thanks for the update. This is is indeed the case for us. First we access Microsoft Graph and then SharePoint.

@bgavrilMS
Copy link
Member

bgavrilMS commented Dec 17, 2018

Hi @eldin66, I have another update. I've inspected the logs of an internal user who also has this problem and I can now conclude there is a failure when calling the broker. I am reaching out to the broker team for further investigation (the broker code is not public, so I can't reference an issue, so I will keep this issue open).

I also found a minor problem in the way the ADAL token cache behaves, but I don't think it is as significant as the broker failure - #1463

The failure in the log if you'd like to confirm:

AdalLoggerBase.cs: User is specified for background token request
AdalLoggerBase.cs: Received result from Authenticator (BAD LOG Message, it has not received anything)
AdalLoggerBase.cs: Exception type: Java.Lang.IllegalArgumentException
12-11 14:43:14.421 E/        ( 6178):
12-11 14:43:14.421 E/        ( 6178):   at Java.Interop.JniEnvironment+InstanceMethods.CallObjectMethod (Java.Interop.JniObjectReference instance, Java.Interop.JniMethodInfo method, Java.Interop.JniArgumentValue* args) [0x00069] in <0ad2222fd7074badb5de547b1521aab0>:0
12-11 14:43:14.421 E/        ( 6178):   at Android.Runtime.JNIEnv.CallObjectMethod (System.IntPtr jobject, System.IntPtr jmethod, Android.Runtime.JValue* parms) [0x0000e] in :0
12-11 14:43:14.421 E/        ( 6178):   at Android.Accounts.IAccountManagerFutureInvoker.GetResult (System.Int64 timeout, Java.Util.Concurrent.TimeUnit unit) [0x0006d] in :0
12-11 14:43:14.421 E/        ( 6178):   at Microsoft.IdentityModel.Clients.ActiveDirectory.Internal.Platform.BrokerProxy.GetAuthTokenInBackground (Microsoft.IdentityModel.Clients.ActiveDirectory.Internal.Platform.AuthenticationRequest request, Android.App.Activity callerActivity) [0x000c9] in <243c572443ef40ad8dce3a888e14c5d4>:0
12-11 14:43:14.421 E/        ( 6178):   --- End of managed Java.Lang.IllegalArgumentException stack trace ---
12-11 14:43:14.421 E/        ( 6178): java.lang.IllegalArgumentException: Caller package name or UID is not set.
12-11 14:43:14.421 E/        ( 6178):  at android.accounts.AccountManager.convertErrorToException(AccountManager.java:2202)
12-11 14:43:14.421 E/        ( 6178):  at android.accounts.AccountManager.-wrap0(AccountManager.java)
12-11 14:43:14.421 E/        ( 6178):  at android.accounts.AccountManager$AmsTask$Response.onError(AccountManager.java:2041)
12-11 14:43:14.421 E/        ( 6178):  at android.accounts.IAccountManagerResponse$Stub.onTransact(IAccountManagerResponse.java:69)
12-11 14:43:14.421 E/        ( 6178):  at android.os.Binder.execTransact(Binder.java:573)

@bgavrilMS bgavrilMS changed the title Xamarin.Android: RefreshToken null when using broker. Android + Broker - interactive auth is forced when requesting different resources Dec 17, 2018
@bgavrilMS
Copy link
Member

I have a potential fix for one of the 2 causes of failure. Please try it out from:

https://www.myget.org/feed/aad-clients-nightly/package/nuget/Microsoft.IdentityModel.Clients.ActiveDirectory/4.4.2-internal35102fix1353

This fix should decrease the number of interactive logins by quite a bit, but it does not fix the entire problem. It focuses on fixing the ADAL token cache, so scenarios such as:

  1. Acquire Token Interactive for Resource1 - OK
  2. Acquire Token Silent for Resource2 - still fails, it will revert to an interactive flow
  3. Acquire Token Silent for Resource1 - used to fail and revert to interactive flow, now OK

Since the ADAL token cache does not hold on to the refresh token, it can only serve access tokens, which have a default expiration of 1h. After than 1h, the silent requests will fail and your code should redirect to interactive requests.

I'll update the thread when the I manage to meet with the Authenticator team.

@EldinHb
Copy link
Author

EldinHb commented Dec 18, 2018

I’m currently on vacation and sadly don’t have my gear with me to check. I’ll be back at work on 5 January but maybe I can test it before that.

Happy holidays and have a great new year :)

@bgavrilMS
Copy link
Member

Enjoy your holiday @eldin66, most of us will be out of office soon as well.

There are several customers impacted by this issue and you are the first to report it on GitHub, so I'll keep on adding details here.

@EldinHb
Copy link
Author

EldinHb commented Jan 10, 2019

I am back from my holidays. Do you still need me to test for you or did you already make progress?

@bgavrilMS
Copy link
Member

Hi @eldin66 , welcome back! We made some progress in the sense that we added 2 potential fixes and a lot of logging :). It seems that everyone experiencing broker issues is actually facing a different problem.

Could I ask you to try this package please? https://www.myget.org/feed/aad-clients-nightly/package/nuget/Microsoft.IdentityModel.Clients.ActiveDirectory/4.4.2-internal01002fix1353

Please make sure to turn on all logging, see https://github.com/AzureAD/azure-activedirectory-library-for-dotnet/wiki/Logging-in-ADAL.Net if in doubt.

@EldinHb
Copy link
Author

EldinHb commented Jan 11, 2019

Thank you @bgavrilMS :).

I have tried the nightly package and it seems that the problem has been partially fixed. The token now refreshes silently after an app restart. The only problem that remains is that during the initial login the user has to authenticate twice. Here are the logs:

[zygote] Do partial code cache collection, code=253KB, data=176KB
[zygote] After code cache collection, code=253KB, data=176KB
[zygote] Increasing code cache capacity to 1024KB
[] 2019-01-11T11:32:02.6712620Z: 00000000-0000-0000-0000-000000000000 - AdalLoggerBase.cs: Deserialized 0 items to token cache.
Information 2019-01-11T11:32:02.6717810Z: 00000000-0000-0000-0000-000000000000 - AdalLoggerBase.cs: Deserialized 0 items to token cache.
[] 2019-01-11T11:32:02.6725590Z: ccad1fe6-f7d9-457b-9b54-cf9f607428e3 - AdalLoggerBase.cs: BrokerProxy: Getting the Android context
Verbose 2019-01-11T11:32:02.6728680Z: ccad1fe6-f7d9-457b-9b54-cf9f607428e3 - AdalLoggerBase.cs: BrokerProxy: Getting the Android context
[] 2019-01-11T11:32:02.6736780Z: ccad1fe6-f7d9-457b-9b54-cf9f607428e3 - AdalLoggerBase.cs: ADAL PCL.Android with assembly version '4.4.2.0', file version '4.4.2.0' and informational version '4.4.2-internal01002fix1353' is running...
Information 2019-01-11T11:32:02.6739150Z: ccad1fe6-f7d9-457b-9b54-cf9f607428e3 - AdalLoggerBase.cs: ADAL PCL.Android with assembly version '4.4.2.0', file version '4.4.2.0' and informational version '4.4.2-internal01002fix1353' is running...
[] 2019-01-11T11:32:02.6744230Z: ccad1fe6-f7d9-457b-9b54-cf9f607428e3 - AdalLoggerBase.cs: === Token Acquisition started: 
[] 	CacheType: null
[] 	Authentication Target: User
[] 	, Authority Host: login.windows.net
Information 2019-01-11T11:32:02.6746360Z: ccad1fe6-f7d9-457b-9b54-cf9f607428e3 - AdalLoggerBase.cs: === Token Acquisition started:
	Authority: https://login.windows.net/common/
	Resource: https://graph.microsoft.com
	ClientId: xxx-xxx-xxx-xx
	CacheType: null
	Authentication Target: User
	
[] 2019-01-11T11:32:02.6757760Z: ccad1fe6-f7d9-457b-9b54-cf9f607428e3 - AdalLoggerBase.cs: Loading from cache.
Verbose 2019-01-11T11:32:02.6760970Z: ccad1fe6-f7d9-457b-9b54-cf9f607428e3 - AdalLoggerBase.cs: Loading from cache.
[] 2019-01-11T11:32:02.6776820Z: 00000000-0000-0000-0000-000000000000 - AdalLoggerBase.cs: Deserialized 0 items to token cache.
Information 2019-01-11T11:32:02.6779750Z: 00000000-0000-0000-0000-000000000000 - AdalLoggerBase.cs: Deserialized 0 items to token cache.
[] 2019-01-11T11:32:02.6786500Z: ccad1fe6-f7d9-457b-9b54-cf9f607428e3 - AdalLoggerBase.cs: Looking up cache for a token...
Verbose 2019-01-11T11:32:02.6789210Z: ccad1fe6-f7d9-457b-9b54-cf9f607428e3 - AdalLoggerBase.cs: Looking up cache for a token...
[] 2019-01-11T11:32:02.6842850Z: ccad1fe6-f7d9-457b-9b54-cf9f607428e3 - AdalLoggerBase.cs: No matching token was found in the cache
Information 2019-01-11T11:32:02.6847840Z: ccad1fe6-f7d9-457b-9b54-cf9f607428e3 - AdalLoggerBase.cs: No matching token was found in the cache
[] 2019-01-11T11:32:02.6852100Z: ccad1fe6-f7d9-457b-9b54-cf9f607428e3 - AdalLoggerBase.cs: Checking MSAL cache for user token cache
Information 2019-01-11T11:32:02.6854470Z: ccad1fe6-f7d9-457b-9b54-cf9f607428e3 - AdalLoggerBase.cs: Checking MSAL cache for user token cache
[] 2019-01-11T11:32:02.7132180Z: ccad1fe6-f7d9-457b-9b54-cf9f607428e3 - AdalLoggerBase.cs: Looking up cache for a token...
Verbose 2019-01-11T11:32:02.7136090Z: ccad1fe6-f7d9-457b-9b54-cf9f607428e3 - AdalLoggerBase.cs: Looking up cache for a token...
[] 2019-01-11T11:32:02.7140150Z: ccad1fe6-f7d9-457b-9b54-cf9f607428e3 - AdalLoggerBase.cs: No matching token was found in the cache
Information 2019-01-11T11:32:02.7142450Z: ccad1fe6-f7d9-457b-9b54-cf9f607428e3 - AdalLoggerBase.cs: No matching token was found in the cache
[] 2019-01-11T11:32:02.7144770Z: ccad1fe6-f7d9-457b-9b54-cf9f607428e3 - AdalLoggerBase.cs: Checking MSAL cache for user token cache
Information 2019-01-11T11:32:02.7146690Z: ccad1fe6-f7d9-457b-9b54-cf9f607428e3 - AdalLoggerBase.cs: Checking MSAL cache for user token cache
[] 2019-01-11T11:32:02.7163710Z: ccad1fe6-f7d9-457b-9b54-cf9f607428e3 - AdalLoggerBase.cs: Looking up cache for a token...
Verbose 2019-01-11T11:32:02.7166480Z: ccad1fe6-f7d9-457b-9b54-cf9f607428e3 - AdalLoggerBase.cs: Looking up cache for a token...
[] 2019-01-11T11:32:02.7169840Z: ccad1fe6-f7d9-457b-9b54-cf9f607428e3 - AdalLoggerBase.cs: No matching token was found in the cache
Information 2019-01-11T11:32:02.7171990Z: ccad1fe6-f7d9-457b-9b54-cf9f607428e3 - AdalLoggerBase.cs: No matching token was found in the cache
[] 2019-01-11T11:32:02.7174290Z: ccad1fe6-f7d9-457b-9b54-cf9f607428e3 - AdalLoggerBase.cs: Checking MSAL cache for user token cache
Information 2019-01-11T11:32:02.7176370Z: ccad1fe6-f7d9-457b-9b54-cf9f607428e3 - AdalLoggerBase.cs: Checking MSAL cache for user token cache
[] 2019-01-11T11:32:02.7191530Z: ccad1fe6-f7d9-457b-9b54-cf9f607428e3 - AdalLoggerBase.cs: Looking up cache for a token...
Verbose 2019-01-11T11:32:02.7194200Z: ccad1fe6-f7d9-457b-9b54-cf9f607428e3 - AdalLoggerBase.cs: Looking up cache for a token...
[] 2019-01-11T11:32:02.7197400Z: ccad1fe6-f7d9-457b-9b54-cf9f607428e3 - AdalLoggerBase.cs: No matching token was found in the cache
Information 2019-01-11T11:32:02.7199480Z: ccad1fe6-f7d9-457b-9b54-cf9f607428e3 - AdalLoggerBase.cs: No matching token was found in the cache
[] 2019-01-11T11:32:02.7201770Z: ccad1fe6-f7d9-457b-9b54-cf9f607428e3 - AdalLoggerBase.cs: Checking MSAL cache for user token cache
Information 2019-01-11T11:32:02.7203530Z: ccad1fe6-f7d9-457b-9b54-cf9f607428e3 - AdalLoggerBase.cs: Checking MSAL cache for user token cache
[] 2019-01-11T11:32:02.7218520Z: ccad1fe6-f7d9-457b-9b54-cf9f607428e3 - AdalLoggerBase.cs: Looking up cache for a token...
Verbose 2019-01-11T11:32:02.7221190Z: ccad1fe6-f7d9-457b-9b54-cf9f607428e3 - AdalLoggerBase.cs: Looking up cache for a token...
[] 2019-01-11T11:32:02.7224740Z: ccad1fe6-f7d9-457b-9b54-cf9f607428e3 - AdalLoggerBase.cs: No matching token was found in the cache
Information 2019-01-11T11:32:02.7227010Z: ccad1fe6-f7d9-457b-9b54-cf9f607428e3 - AdalLoggerBase.cs: No matching token was found in the cache
[] 2019-01-11T11:32:02.7229420Z: ccad1fe6-f7d9-457b-9b54-cf9f607428e3 - AdalLoggerBase.cs: Checking MSAL cache for user token cache
Information 2019-01-11T11:32:02.7231360Z: ccad1fe6-f7d9-457b-9b54-cf9f607428e3 - AdalLoggerBase.cs: Checking MSAL cache for user token cache
[] 2019-01-11T11:32:02.7246930Z: ccad1fe6-f7d9-457b-9b54-cf9f607428e3 - AdalLoggerBase.cs: Looking up cache for a token...
Verbose 2019-01-11T11:32:02.7250870Z: ccad1fe6-f7d9-457b-9b54-cf9f607428e3 - AdalLoggerBase.cs: Looking up cache for a token...
[] 2019-01-11T11:32:02.7254530Z: ccad1fe6-f7d9-457b-9b54-cf9f607428e3 - AdalLoggerBase.cs: No matching token was found in the cache
Information 2019-01-11T11:32:02.7256580Z: ccad1fe6-f7d9-457b-9b54-cf9f607428e3 - AdalLoggerBase.cs: No matching token was found in the cache
[] 2019-01-11T11:32:02.7258850Z: ccad1fe6-f7d9-457b-9b54-cf9f607428e3 - AdalLoggerBase.cs: Checking MSAL cache for user token cache
Information 2019-01-11T11:32:02.7260730Z: ccad1fe6-f7d9-457b-9b54-cf9f607428e3 - AdalLoggerBase.cs: Checking MSAL cache for user token cache
[] 2019-01-11T11:32:02.7776590Z: ccad1fe6-f7d9-457b-9b54-cf9f607428e3 - AdalLoggerBase.cs: BrokerProxy: Found the Authenticator on the device
Verbose 2019-01-11T11:32:02.7780200Z: ccad1fe6-f7d9-457b-9b54-cf9f607428e3 - AdalLoggerBase.cs: BrokerProxy: Found the Authenticator on the device
[] 2019-01-11T11:32:02.7986430Z: ccad1fe6-f7d9-457b-9b54-cf9f607428e3 - AdalLoggerBase.cs: BrokerProxy: Broker supports adding accounts
Verbose 2019-01-11T11:32:02.7990040Z: ccad1fe6-f7d9-457b-9b54-cf9f607428e3 - AdalLoggerBase.cs: BrokerProxy: Broker supports adding accounts
[] 2019-01-11T11:32:02.8421670Z: ccad1fe6-f7d9-457b-9b54-cf9f607428e3 - AdalLoggerBase.cs: BrokerProxy: Broker supports adding accounts
Verbose 2019-01-11T11:32:02.8427650Z: ccad1fe6-f7d9-457b-9b54-cf9f607428e3 - AdalLoggerBase.cs: BrokerProxy: Broker supports adding accounts
[] 2019-01-11T11:32:02.8438180Z: ccad1fe6-f7d9-457b-9b54-cf9f607428e3 - AdalLoggerBase.cs: It switched to broker for context: com.debble.debbleintranet
Verbose 2019-01-11T11:32:02.8443760Z: ccad1fe6-f7d9-457b-9b54-cf9f607428e3 - AdalLoggerBase.cs: It switched to broker for context: com.debble.debbleintranet
[] 2019-01-11T11:32:02.8462430Z: ccad1fe6-f7d9-457b-9b54-cf9f607428e3 - AdalLoggerBase.cs: User is not specified for background token request
Verbose 2019-01-11T11:32:02.8466170Z: ccad1fe6-f7d9-457b-9b54-cf9f607428e3 - AdalLoggerBase.cs: User is not specified for background token request
[] 2019-01-11T11:32:02.8469270Z: ccad1fe6-f7d9-457b-9b54-cf9f607428e3 - AdalLoggerBase.cs: Token is not returned from backgroud call
Verbose 2019-01-11T11:32:02.8471080Z: ccad1fe6-f7d9-457b-9b54-cf9f607428e3 - AdalLoggerBase.cs: Token is not returned from backgroud call
[] 2019-01-11T11:32:02.8473140Z: ccad1fe6-f7d9-457b-9b54-cf9f607428e3 - AdalLoggerBase.cs: Launch activity for Authenticator
Verbose 2019-01-11T11:32:02.8474910Z: ccad1fe6-f7d9-457b-9b54-cf9f607428e3 - AdalLoggerBase.cs: Launch activity for Authenticator
[] 2019-01-11T11:32:02.8477130Z: ccad1fe6-f7d9-457b-9b54-cf9f607428e3 - AdalLoggerBase.cs: Starting Authentication Activity
Verbose 2019-01-11T11:32:02.8478760Z: ccad1fe6-f7d9-457b-9b54-cf9f607428e3 - AdalLoggerBase.cs: Starting Authentication Activity
[] 2019-01-11T11:32:02.8481460Z: ccad1fe6-f7d9-457b-9b54-cf9f607428e3 - AdalLoggerBase.cs: Initial request to authenticator
Verbose 2019-01-11T11:32:02.8483150Z: ccad1fe6-f7d9-457b-9b54-cf9f607428e3 - AdalLoggerBase.cs: Initial request to authenticator
[] 2019-01-11T11:32:02.9113720Z: ccad1fe6-f7d9-457b-9b54-cf9f607428e3 - AdalLoggerBase.cs: Calling activity pid:7688 tid:7732uid:10143
Verbose 2019-01-11T11:32:02.9117580Z: ccad1fe6-f7d9-457b-9b54-cf9f607428e3 - AdalLoggerBase.cs: Calling activity pid:7688 tid:7732uid:10143
[OpenGLRenderer] endAllActiveAnimators on 0x89379a80 (RippleDrawable) with handle 0x8211be40
[] 2019-01-11T11:32:04.7966500Z: 00000000-0000-0000-0000-000000000000 - AdalLoggerBase.cs: Received Activity Result(2004)
Information 2019-01-11T11:32:04.7970590Z: 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'.
[zygote] Explicit concurrent copying GC freed 7910(826KB) AllocSpace objects, 17(468KB) LOS objects, 50% free, 1745KB/3MB, paused 270us total 31.163ms
[Mono] GC_TAR_BRIDGE bridges 268 objects 324 opaque 63 colors 268 colors-bridged 268 colors-visible 268 xref 9 cache-hit 0 cache-semihit 0 cache-miss 0 setup 0.12ms tarjan 0.51ms scc-setup 0.15ms gather-xref 0.01ms xref-setup 0.02ms cleanup 0.07ms
[Mono] GC_BRIDGE: Complete, was running for 35.30ms
[Mono] GC_MINOR: (Nursery full) time 12.47ms, stw 13.37ms promoted 424K major size: 3680K in use: 2598K los size: 11264K in use: 8458K
[] 2019-01-11T11:32:04.9392940Z: ccad1fe6-f7d9-457b-9b54-cf9f607428e3 - AdalLoggerBase.cs: Storing token in the cache...
Verbose 2019-01-11T11:32:04.9399800Z: ccad1fe6-f7d9-457b-9b54-cf9f607428e3 - AdalLoggerBase.cs: Storing token in the cache...
[] 2019-01-11T11:32:04.9431010Z: ccad1fe6-f7d9-457b-9b54-cf9f607428e3 - AdalLoggerBase.cs: An item was stored in the cache
Verbose 2019-01-11T11:32:04.9435080Z: ccad1fe6-f7d9-457b-9b54-cf9f607428e3 - AdalLoggerBase.cs: An item was stored in the cache
[] 2019-01-11T11:32:04.9640180Z: 00000000-0000-0000-0000-000000000000 - AdalLoggerBase.cs: Client Info is missing. Skipping MSAL refresh token cache write
Information 2019-01-11T11:32:04.9644580Z: 00000000-0000-0000-0000-000000000000 - AdalLoggerBase.cs: Client Info is missing. Skipping MSAL refresh token cache write
[] 2019-01-11T11:32:04.9667040Z: xxx - AdalLoggerBase.cs: === Token Acquisition finished successfully. An access token was returned: Expiration Time: 11-1-2019 12:10:41 +00:00
Information 2019-01-11T11:32:04.9670140Z: xxx - AdalLoggerBase.cs: === Token Acquisition finished successfully. An access token was returned: Expiration Time: 11-1-2019 12:10:41 +00:00Access Token Hash: xxx
	 User id: xxx
[] 2019-01-11T11:32:04.9675480Z: 00000000-0000-0000-0000-000000000000 - AdalLoggerBase.cs: Serializing token cache with 1 items.
Information 2019-01-11T11:32:04.9678150Z: 00000000-0000-0000-0000-000000000000 - AdalLoggerBase.cs: Serializing token cache with 1 items.
[] 2019-01-11T11:32:05.3841820Z: 00000000-0000-0000-0000-000000000000 - AdalLoggerBase.cs: Deserialized 1 items to token cache.
Information 2019-01-11T11:32:05.3845620Z: 00000000-0000-0000-0000-000000000000 - AdalLoggerBase.cs: Deserialized 1 items to token cache.
[] 2019-01-11T11:32:05.3902400Z: 00000000-0000-0000-0000-000000000000 - AdalLoggerBase.cs: Deserialized 1 items to token cache.
Information 2019-01-11T11:32:05.3906060Z: 00000000-0000-0000-0000-000000000000 - AdalLoggerBase.cs: Deserialized 1 items to token cache.
[] 2019-01-11T11:32:05.3913660Z: f90152b3-d3a7-4248-8589-86584c18f5e1 - AdalLoggerBase.cs: BrokerProxy: Getting the Android context
Verbose 2019-01-11T11:32:05.3916760Z: f90152b3-d3a7-4248-8589-86584c18f5e1 - AdalLoggerBase.cs: BrokerProxy: Getting the Android context
[] 2019-01-11T11:32:05.3925200Z: f90152b3-d3a7-4248-8589-86584c18f5e1 - AdalLoggerBase.cs: ADAL PCL.Android with assembly version '4.4.2.0', file version '4.4.2.0' and informational version '4.4.2-internal01002fix1353' is running...
Information 2019-01-11T11:32:05.3927640Z: f90152b3-d3a7-4248-8589-86584c18f5e1 - AdalLoggerBase.cs: ADAL PCL.Android with assembly version '4.4.2.0', file version '4.4.2.0' and informational version '4.4.2-internal01002fix1353' is running...
[] 2019-01-11T11:32:05.3932530Z: f90152b3-d3a7-4248-8589-86584c18f5e1 - AdalLoggerBase.cs: === Token Acquisition started: 
[] 	CacheType: null
[] 	Authentication Target: User
[] 	, Authority Host: login.windows.net
Information 2019-01-11T11:32:05.3934880Z: xxxx - AdalLoggerBase.cs: === Token Acquisition started:
	Authority: https://login.windows.net/xxx/
	Resource: https://xxx.sharepoint.com
	ClientId: xxx-xxx-xxx-xxx
	CacheType: null
	Authentication Target: User
	
[] 2019-01-11T11:32:05.3943830Z: xxx - AdalLoggerBase.cs: Loading from cache.
Verbose 2019-01-11T11:32:05.3946040Z: xxx - AdalLoggerBase.cs: Loading from cache.
[] 2019-01-11T11:32:05.4002140Z: 00000000-0000-0000-0000-000000000000 - AdalLoggerBase.cs: Deserialized 1 items to token cache.
Information 2019-01-11T11:32:05.4005900Z: 00000000-0000-0000-0000-000000000000 - AdalLoggerBase.cs: Deserialized 1 items to token cache.
[] 2019-01-11T11:32:05.4013210Z: f90152b3-d3a7-4248-8589-86584c18f5e1 - AdalLoggerBase.cs: Looking up cache for a token...
Verbose 2019-01-11T11:32:05.4016590Z: xxx - AdalLoggerBase.cs: Looking up cache for a token...
[] 2019-01-11T11:32:05.4116880Z: f90152b3-d3a7-4248-8589-86584c18f5e1 - AdalLoggerBase.cs: Broker scenario - RT is held by the broker and the request is for a different resource. Ignoring the cache. 
Information 2019-01-11T11:32:05.4120930Z: x-x-x-x-x - AdalLoggerBase.cs: Broker scenario - RT is held by the broker and the request is for a different resource. Ignoring the cache. 
[] 2019-01-11T11:32:05.4125750Z: xxx - AdalLoggerBase.cs: Looking up cache for a token...
Verbose 2019-01-11T11:32:05.4128420Z: xxx - AdalLoggerBase.cs: Looking up cache for a token...
[] 2019-01-11T11:32:05.4196930Z: xxx - AdalLoggerBase.cs: Broker scenario - RT is held by the broker and the request is for a different resource. Ignoring the cache. 
Information 2019-01-11T11:32:05.4200960Z: xxx- AdalLoggerBase.cs: Broker scenario - RT is held by the broker and the request is for a different resource. Ignoring the cache. 
[] 2019-01-11T11:32:05.4205670Z: xxx - AdalLoggerBase.cs: Looking up cache for a token...
Verbose 2019-01-11T11:32:05.4208060Z: xxx - AdalLoggerBase.cs: Looking up cache for a token...
[] 2019-01-11T11:32:05.4212580Z: xxx - AdalLoggerBase.cs: No matching token was found in the cache
Information 2019-01-11T11:32:05.4215710Z: xxx - AdalLoggerBase.cs: No matching token was found in the cache
[] 2019-01-11T11:32:05.4218880Z: f90152b3-d3a7-4248-8589-86584c18f5e1 - AdalLoggerBase.cs: Checking MSAL cache for user token cache
Information 2019-01-11T11:32:05.4221320Z: f90152b3-d3a7-4248-8589-86584c18f5e1 - AdalLoggerBase.cs: Checking MSAL cache for user token cache
[] 2019-01-11T11:32:05.4238660Z: f90152b3-d3a7-4248-8589-86584c18f5e1 - AdalLoggerBase.cs: Looking up cache for a token...
Verbose 2019-01-11T11:32:05.4241910Z: f90152b3-d3a7-4248-8589-86584c18f5e1 - AdalLoggerBase.cs: Looking up cache for a token...
[] 2019-01-11T11:32:05.4310030Z: f90152b3-d3a7-4248-8589-86584c18f5e1 - AdalLoggerBase.cs: Broker scenario - RT is held by the broker and the request is for a different resource. Ignoring the cache. 
Information 2019-01-11T11:32:05.4314510Z: f90152b3-d3a7-4248-8589-86584c18f5e1 - AdalLoggerBase.cs: Broker scenario - RT is held by the broker and the request is for a different resource. Ignoring the cache. 
[] 2019-01-11T11:32:05.4319370Z: f90152b3-d3a7-4248-8589-86584c18f5e1 - AdalLoggerBase.cs: Looking up cache for a token...
Verbose 2019-01-11T11:32:05.4322230Z: f90152b3-d3a7-4248-8589-86584c18f5e1 - AdalLoggerBase.cs: Looking up cache for a token...
[] 2019-01-11T11:32:05.4327520Z: f90152b3-d3a7-4248-8589-86584c18f5e1 - AdalLoggerBase.cs: No matching token was found in the cache
Information 2019-01-11T11:32:05.4330230Z: f90152b3-d3a7-4248-8589-86584c18f5e1 - AdalLoggerBase.cs: No matching token was found in the cache
[] 2019-01-11T11:32:05.4333250Z: f90152b3-d3a7-4248-8589-86584c18f5e1 - AdalLoggerBase.cs: Checking MSAL cache for user token cache
Information 2019-01-11T11:32:05.4335440Z: f90152b3-d3a7-4248-8589-86584c18f5e1 - AdalLoggerBase.cs: Checking MSAL cache for user token cache
[] 2019-01-11T11:32:05.4352950Z: f90152b3-d3a7-4248-8589-86584c18f5e1 - AdalLoggerBase.cs: Looking up cache for a token...
Verbose 2019-01-11T11:32:05.4356230Z: f90152b3-d3a7-4248-8589-86584c18f5e1 - AdalLoggerBase.cs: Looking up cache for a token...
[] 2019-01-11T11:32:05.4361900Z: f90152b3-d3a7-4248-8589-86584c18f5e1 - AdalLoggerBase.cs: No matching token was found in the cache
Information 2019-01-11T11:32:05.4364910Z: f90152b3-d3a7-4248-8589-86584c18f5e1 - AdalLoggerBase.cs: No matching token was found in the cache
[] 2019-01-11T11:32:05.4368040Z: f90152b3-d3a7-4248-8589-86584c18f5e1 - AdalLoggerBase.cs: Checking MSAL cache for user token cache
Information 2019-01-11T11:32:05.4370510Z: f90152b3-d3a7-4248-8589-86584c18f5e1 - AdalLoggerBase.cs: Checking MSAL cache for user token cache
[] 2019-01-11T11:32:05.4489710Z: f90152b3-d3a7-4248-8589-86584c18f5e1 - AdalLoggerBase.cs: BrokerProxy: Found the Authenticator on the device
Verbose 2019-01-11T11:32:05.4493170Z: f90152b3-d3a7-4248-8589-86584c18f5e1 - AdalLoggerBase.cs: BrokerProxy: Found the Authenticator on the device
[] 2019-01-11T11:32:05.4570340Z: f90152b3-d3a7-4248-8589-86584c18f5e1 - AdalLoggerBase.cs: BrokerProxy: Broker supports adding accounts
Verbose 2019-01-11T11:32:05.4573920Z: f90152b3-d3a7-4248-8589-86584c18f5e1 - AdalLoggerBase.cs: BrokerProxy: Broker supports adding accounts
[] 2019-01-11T11:32:05.4661070Z: f90152b3-d3a7-4248-8589-86584c18f5e1 - AdalLoggerBase.cs: BrokerProxy: Broker supports adding accounts
Verbose 2019-01-11T11:32:05.4664650Z: f90152b3-d3a7-4248-8589-86584c18f5e1 - AdalLoggerBase.cs: BrokerProxy: Broker supports adding accounts
[] 2019-01-11T11:32:05.4669130Z: f90152b3-d3a7-4248-8589-86584c18f5e1 - AdalLoggerBase.cs: It switched to broker for context: xxx
Verbose 2019-01-11T11:32:05.4671560Z: f90152b3-d3a7-4248-8589-86584c18f5e1 - AdalLoggerBase.cs: It switched to broker for context: xxx
[] 2019-01-11T11:32:05.4674630Z: f90152b3-d3a7-4248-8589-86584c18f5e1 - AdalLoggerBase.cs: User is specified for background token request
Verbose 2019-01-11T11:32:05.4676520Z: f90152b3-d3a7-4248-8589-86584c18f5e1 - AdalLoggerBase.cs: User is specified for background token request
[] 2019-01-11T11:32:05.4734350Z: f90152b3-d3a7-4248-8589-86584c18f5e1 - AdalLoggerBase.cs: BrokerProxy: Getting the broker work and school accounts 
Information 2019-01-11T11:32:05.4738340Z: f90152b3-d3a7-4248-8589-86584c18f5e1 - AdalLoggerBase.cs: BrokerProxy: Getting the broker work and school accounts 
[] 2019-01-11T11:32:05.4783530Z: f90152b3-d3a7-4248-8589-86584c18f5e1 - AdalLoggerBase.cs: BrokerProxy: finding account...
Verbose 2019-01-11T11:32:05.4787680Z: f90152b3-d3a7-4248-8589-86584c18f5e1 - AdalLoggerBase.cs: BrokerProxy: Finding Account 15176dc1-7bb8-44c0-b8a8-e492b87284a0
[] 2019-01-11T11:32:05.4791220Z: f90152b3-d3a7-4248-8589-86584c18f5e1 - AdalLoggerBase.cs: BrokerProxy: Found account based on the broker account name? False
Verbose 2019-01-11T11:32:05.4792970Z: f90152b3-d3a7-4248-8589-86584c18f5e1 - AdalLoggerBase.cs: BrokerProxy: Found account based on the broker account name? False
[] 2019-01-11T11:32:05.4804990Z: f90152b3-d3a7-4248-8589-86584c18f5e1 - AdalLoggerBase.cs: Target account is not found
Warning 2019-01-11T11:32:05.4826280Z: f90152b3-d3a7-4248-8589-86584c18f5e1 - AdalLoggerBase.cs: Target account is not found
[] 2019-01-11T11:32:05.4830850Z: f90152b3-d3a7-4248-8589-86584c18f5e1 - AdalLoggerBase.cs: Token is not returned from backgroud call
Verbose 2019-01-11T11:32:05.4833270Z: f90152b3-d3a7-4248-8589-86584c18f5e1 - AdalLoggerBase.cs: Token is not returned from backgroud call
[] 2019-01-11T11:32:05.4835960Z: f90152b3-d3a7-4248-8589-86584c18f5e1 - AdalLoggerBase.cs: Launch activity for Authenticator
Verbose 2019-01-11T11:32:05.4837920Z: f90152b3-d3a7-4248-8589-86584c18f5e1 - AdalLoggerBase.cs: Launch activity for Authenticator
[] 2019-01-11T11:32:05.4840140Z: f90152b3-d3a7-4248-8589-86584c18f5e1 - AdalLoggerBase.cs: Starting Authentication Activity
Verbose 2019-01-11T11:32:05.4841790Z: f90152b3-d3a7-4248-8589-86584c18f5e1 - AdalLoggerBase.cs: Starting Authentication Activity
[] 2019-01-11T11:32:05.4843800Z: f90152b3-d3a7-4248-8589-86584c18f5e1 - AdalLoggerBase.cs: Initial request to authenticator
Verbose 2019-01-11T11:32:05.4845390Z: f90152b3-d3a7-4248-8589-86584c18f5e1 - AdalLoggerBase.cs: Initial request to authenticator
Error 2019-01-11T11:32:05.4857860Z: f90152b3-d3a7-4248-8589-86584c18f5e1 - AdalLoggerBase.cs: Can't invoke the broker in interactive mode because this is a silent flow
[] 2019-01-11T11:32:05.5108120Z: f90152b3-d3a7-4248-8589-86584c18f5e1 - 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) [0x001f4] in C:\agent1\_work\70\s\src\Microsoft.IdentityModel.Clients.ActiveDirectory\Platforms\android\AndroidBroker.cs:162 
[]   at Microsoft.IdentityModel.Clients.ActiveDirectory.Internal.Platform.AndroidBroker+<>c__DisplayClass11_0.<AcquireTokenUsingBrokerAsync>b__0 () [0x00000] in C:\agent1\_work\70\s\src\Microsoft.IdentityModel.Clients.ActiveDirectory\Platforms\android\AndroidBroker.cs:76 
[]   at System.Threading.Tasks.Task.InnerInvoke () [0x0000f] in <fe08c003e91342eb83df1ca48302ddbb>:0 
[]   at System.Threading.Tasks.Task.Execute () [0x00000] in <fe08c003e91342eb83df1ca48302ddbb>: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:\agent1\_work\70\s\src\Microsoft.IdentityModel.Clients.ActiveDirectory\Platforms\android\AndroidBroker.cs:76 
Error 2019-01-11T11:32:05.5125170Z: f90152b3-d3a7-4248-8589-86584c18f5e1 - AdalLoggerBase.cs: Microsoft.IdentityModel.Clients.ActiveDirectory.AdalSilentTokenAcquisitionException: Failed to acquire token silently as no token was found in the cache. Call method AcquireToken
  at Microsoft.IdentityModel.Clients.ActiveDirectory.Internal.Platform.AndroidBroker.AcquireTokenInternal (System.Collections.Generic.IDictionary`2[TKey,TValue] brokerPayload) [0x001f4] in C:\agent1\_work\70\s\src\Microsoft.IdentityModel.Clients.ActiveDirectory\Platforms\android\AndroidBroker.cs:162 
  at Microsoft.IdentityModel.Clients.ActiveDirectory.Internal.Platform.AndroidBroker+<>c__DisplayClass11_0.<AcquireTokenUsingBrokerAsync>b__0 () [0x00000] in C:\agent1\_work\70\s\src\Microsoft.IdentityModel.Clients.ActiveDirectory\Platforms\android\AndroidBroker.cs:76 
  at System.Threading.Tasks.Task.InnerInvoke () [0x0000f] in <fe08c003e91342eb83df1ca48302ddbb>:0 
  at System.Threading.Tasks.Task.Execute () [0x00000] in <fe08c003e91342eb83df1ca48302ddbb>: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:\agent1\_work\70\s\src\Microsoft.IdentityModel.Clients.ActiveDirectory\Platforms\android\AndroidBroker.cs:76 
	ErrorCode: failed_to_acquire_token_silently
[] 2019-01-11T11:32:05.5198030Z: f90152b3-d3a7-4248-8589-86584c18f5e1 - 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) [0x001f4] in C:\agent1\_work\70\s\src\Microsoft.IdentityModel.Clients.ActiveDirectory\Platforms\android\AndroidBroker.cs:162 
[]   at Microsoft.IdentityModel.Clients.ActiveDirectory.Internal.Platform.AndroidBroker+<>c__DisplayClass11_0.<AcquireTokenUsingBrokerAsync>b__0 () [0x00000] in C:\agent1\_work\70\s\src\Microsoft.IdentityModel.Clients.ActiveDirectory\Platforms\android\AndroidBroker.cs:76 
[]   at System.Threading.Tasks.Task.InnerInvoke () [0x0000f] in <fe08c003e91342eb83df1ca48302ddbb>:0 
[]   at System.Threading.Tasks.Task.Execute () [0x00000] in <fe08c003e91342eb83df1ca48302ddbb>: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:\agent1\_work\70\s\src\Microsoft.IdentityModel.Clients.ActiveDirectory\Platforms\android\AndroidBroker.cs:81 
[] --- End of stack trace from previous location where exception was thrown ---
[]   at Microsoft.IdentityModel.Clients.ActiveDirectory.Internal.Flows.AcquireTokenHandlerBase+<RunAsync>d__53.MoveNext () [0x0038e] in C:\agent1\_work\70\s\src\Microsoft.IdentityModel.Clients.ActiveDirectory\Internal\Flows\AcquireTokenHandlerBase.cs:185 
Error 2019-01-11T11:32:05.5202140Z: f90152b3-d3a7-4248-8589-86584c18f5e1 - AdalLoggerBase.cs: Microsoft.IdentityModel.Clients.ActiveDirectory.AdalSilentTokenAcquisitionException: Failed to acquire token silently as no token was found in the cache. Call method AcquireToken
  at Microsoft.IdentityModel.Clients.ActiveDirectory.Internal.Platform.AndroidBroker.AcquireTokenInternal (System.Collections.Generic.IDictionary`2[TKey,TValue] brokerPayload) [0x001f4] in C:\agent1\_work\70\s\src\Microsoft.IdentityModel.Clients.ActiveDirectory\Platforms\android\AndroidBroker.cs:162 
  at Microsoft.IdentityModel.Clients.ActiveDirectory.Internal.Platform.AndroidBroker+<>c__DisplayClass11_0.<AcquireTokenUsingBrokerAsync>b__0 () [0x00000] in C:\agent1\_work\70\s\src\Microsoft.IdentityModel.Clients.ActiveDirectory\Platforms\android\AndroidBroker.cs:76 
  at System.Threading.Tasks.Task.InnerInvoke () [0x0000f] in <fe08c003e91342eb83df1ca48302ddbb>:0 
  at System.Threading.Tasks.Task.Execute () [0x00000] in <fe08c003e91342eb83df1ca48302ddbb>: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:\agent1\_work\70\s\src\Microsoft.IdentityModel.Clients.ActiveDirectory\Platforms\android\AndroidBroker.cs:81 
--- End of stack trace from previous location where exception was thrown ---
  at Microsoft.IdentityModel.Clients.ActiveDirectory.Internal.Flows.AcquireTokenHandlerBase+<RunAsync>d__53.MoveNext () [0x0038e] in C:\agent1\_work\70\s\src\Microsoft.IdentityModel.Clients.ActiveDirectory\Internal\Flows\AcquireTokenHandlerBase.cs:185 
	ErrorCode: failed_to_acquire_token_silently
[] 2019-01-11T11:32:05.5340250Z: 00000000-0000-0000-0000-000000000000 - AdalLoggerBase.cs: Deserialized 1 items to token cache.
Information 2019-01-11T11:32:05.5344040Z: 00000000-0000-0000-0000-000000000000 - AdalLoggerBase.cs: Deserialized 1 items to token cache.
[] 2019-01-11T11:32:05.5402590Z: 00000000-0000-0000-0000-000000000000 - AdalLoggerBase.cs: Deserialized 1 items to token cache.
Information 2019-01-11T11:32:05.5406300Z: 00000000-0000-0000-0000-000000000000 - AdalLoggerBase.cs: Deserialized 1 items to token cache.
[] 2019-01-11T11:32:05.5416900Z: 50cd0c20-194c-4861-b627-092c27ebffe0 - AdalLoggerBase.cs: BrokerProxy: Getting the Android context
Verbose 2019-01-11T11:32:05.5419760Z: 50cd0c20-194c-4861-b627-092c27ebffe0 - AdalLoggerBase.cs: BrokerProxy: Getting the Android context
[] 2019-01-11T11:32:05.5427670Z: 50cd0c20-194c-4861-b627-092c27ebffe0 - AdalLoggerBase.cs: ADAL PCL.Android with assembly version '4.4.2.0', file version '4.4.2.0' and informational version '4.4.2-internal01002fix1353' is running...
Information 2019-01-11T11:32:05.5429850Z: 50cd0c20-194c-4861-b627-092c27ebffe0 - AdalLoggerBase.cs: ADAL PCL.Android with assembly version '4.4.2.0', file version '4.4.2.0' and informational version '4.4.2-internal01002fix1353' is running...
[] 2019-01-11T11:32:05.5434240Z: 50cd0c20-194c-4861-b627-092c27ebffe0 - AdalLoggerBase.cs: === Token Acquisition started: 
[] 	CacheType: null
[] 	Authentication Target: User
[] 	, Authority Host: login.windows.net
Information 2019-01-11T11:32:05.5435930Z: 50cd0c20-194c-4861-b627-092c27ebffe0 - AdalLoggerBase.cs: === Token Acquisition started:
	Authority: https://login.windows.net/xxx/
	Resource: https://xxx.sharepoint.com
	ClientId: xxx
	CacheType: null
	Authentication Target: User
	
[] 2019-01-11T11:32:05.5444820Z: 50cd0c20-194c-4861-b627-092c27ebffe0 - AdalLoggerBase.cs: Loading from cache.
Verbose 2019-01-11T11:32:05.5446450Z: 50cd0c20-194c-4861-b627-092c27ebffe0 - AdalLoggerBase.cs: Loading from cache.
[] 2019-01-11T11:32:05.5501670Z: 00000000-0000-0000-0000-000000000000 - AdalLoggerBase.cs: Deserialized 1 items to token cache.
Information 2019-01-11T11:32:05.5505040Z: 00000000-0000-0000-0000-000000000000 - AdalLoggerBase.cs: Deserialized 1 items to token cache.
[] 2019-01-11T11:32:05.5511740Z: 50cd0c20-194c-4861-b627-092c27ebffe0 - AdalLoggerBase.cs: Looking up cache for a token...
Verbose 2019-01-11T11:32:05.5513810Z: 50cd0c20-194c-4861-b627-092c27ebffe0 - AdalLoggerBase.cs: Looking up cache for a token...
[] 2019-01-11T11:32:05.5577190Z: 50cd0c20-194c-4861-b627-092c27ebffe0 - AdalLoggerBase.cs: Broker scenario - RT is held by the broker and the request is for a different resource. Ignoring the cache. 
Information 2019-01-11T11:32:05.5581600Z: 50cd0c20-194c-4861-b627-092c27ebffe0 - AdalLoggerBase.cs: Broker scenario - RT is held by the broker and the request is for a different resource. Ignoring the cache. 
[] 2019-01-11T11:32:05.5586160Z: 50cd0c20-194c-4861-b627-092c27ebffe0 - AdalLoggerBase.cs: Looking up cache for a token...
Verbose 2019-01-11T11:32:05.5588430Z: 50cd0c20-194c-4861-b627-092c27ebffe0 - AdalLoggerBase.cs: Looking up cache for a token...
[] 2019-01-11T11:32:05.5652120Z: 50cd0c20-194c-4861-b627-092c27ebffe0 - AdalLoggerBase.cs: Broker scenario - RT is held by the broker and the request is for a different resource. Ignoring the cache. 
Information 2019-01-11T11:32:05.5655900Z: 50cd0c20-194c-4861-b627-092c27ebffe0 - AdalLoggerBase.cs: Broker scenario - RT is held by the broker and the request is for a different resource. Ignoring the cache. 
[] 2019-01-11T11:32:05.5660560Z: 50cd0c20-194c-4861-b627-092c27ebffe0 - AdalLoggerBase.cs: Looking up cache for a token...
Verbose 2019-01-11T11:32:05.5662820Z: 50cd0c20-194c-4861-b627-092c27ebffe0 - AdalLoggerBase.cs: Looking up cache for a token...
[] 2019-01-11T11:32:05.5666840Z: 50cd0c20-194c-4861-b627-092c27ebffe0 - AdalLoggerBase.cs: No matching token was found in the cache
Information 2019-01-11T11:32:05.5669110Z: 50cd0c20-194c-4861-b627-092c27ebffe0 - AdalLoggerBase.cs: No matching token was found in the cache
[] 2019-01-11T11:32:05.5671320Z: 50cd0c20-194c-4861-b627-092c27ebffe0 - AdalLoggerBase.cs: Checking MSAL cache for user token cache
Information 2019-01-11T11:32:05.5673000Z: 50cd0c20-194c-4861-b627-092c27ebffe0 - AdalLoggerBase.cs: Checking MSAL cache for user token cache
[] 2019-01-11T11:32:05.5688130Z: 50cd0c20-194c-4861-b627-092c27ebffe0 - AdalLoggerBase.cs: Looking up cache for a token...
Verbose 2019-01-11T11:32:05.5691130Z: 50cd0c20-194c-4861-b627-092c27ebffe0 - AdalLoggerBase.cs: Looking up cache for a token...
[] 2019-01-11T11:32:05.5755610Z: 50cd0c20-194c-4861-b627-092c27ebffe0 - AdalLoggerBase.cs: Broker scenario - RT is held by the broker and the request is for a different resource. Ignoring the cache. 
Information 2019-01-11T11:32:05.5759680Z: 50cd0c20-194c-4861-b627-092c27ebffe0 - AdalLoggerBase.cs: Broker scenario - RT is held by the broker and the request is for a different resource. Ignoring the cache. 
[] 2019-01-11T11:32:05.5764070Z: 50cd0c20-194c-4861-b627-092c27ebffe0 - AdalLoggerBase.cs: Looking up cache for a token...
Verbose 2019-01-11T11:32:05.5766050Z: 50cd0c20-194c-4861-b627-092c27ebffe0 - AdalLoggerBase.cs: Looking up cache for a token...
[] 2019-01-11T11:32:05.5769590Z: 50cd0c20-194c-4861-b627-092c27ebffe0 - AdalLoggerBase.cs: No matching token was found in the cache
Information 2019-01-11T11:32:05.5771410Z: 50cd0c20-194c-4861-b627-092c27ebffe0 - AdalLoggerBase.cs: No matching token was found in the cache
[] 2019-01-11T11:32:05.5773350Z: 50cd0c20-194c-4861-b627-092c27ebffe0 - AdalLoggerBase.cs: Checking MSAL cache for user token cache
Information 2019-01-11T11:32:05.5774930Z: 50cd0c20-194c-4861-b627-092c27ebffe0 - AdalLoggerBase.cs: Checking MSAL cache for user token cache
[] 2019-01-11T11:32:05.5790010Z: 50cd0c20-194c-4861-b627-092c27ebffe0 - AdalLoggerBase.cs: Looking up cache for a token...
Verbose 2019-01-11T11:32:05.5792900Z: 50cd0c20-194c-4861-b627-092c27ebffe0 - AdalLoggerBase.cs: Looking up cache for a token...
[] 2019-01-11T11:32:05.5797410Z: 50cd0c20-194c-4861-b627-092c27ebffe0 - AdalLoggerBase.cs: No matching token was found in the cache
Information 2019-01-11T11:32:05.5799500Z: 50cd0c20-194c-4861-b627-092c27ebffe0 - AdalLoggerBase.cs: No matching token was found in the cache
[] 2019-01-11T11:32:05.5801650Z: 50cd0c20-194c-4861-b627-092c27ebffe0 - AdalLoggerBase.cs: Checking MSAL cache for user token cache
Information 2019-01-11T11:32:05.5803270Z: 50cd0c20-194c-4861-b627-092c27ebffe0 - AdalLoggerBase.cs: Checking MSAL cache for user token cache
[] 2019-01-11T11:32:05.5912870Z: 50cd0c20-194c-4861-b627-092c27ebffe0 - AdalLoggerBase.cs: BrokerProxy: Found the Authenticator on the device
Verbose 2019-01-11T11:32:05.5916410Z: 50cd0c20-194c-4861-b627-092c27ebffe0 - AdalLoggerBase.cs: BrokerProxy: Found the Authenticator on the device
[] 2019-01-11T11:32:05.5985140Z: 50cd0c20-194c-4861-b627-092c27ebffe0 - AdalLoggerBase.cs: BrokerProxy: Broker supports adding accounts
Verbose 2019-01-11T11:32:05.5988380Z: 50cd0c20-194c-4861-b627-092c27ebffe0 - AdalLoggerBase.cs: BrokerProxy: Broker supports adding accounts
[] 2019-01-11T11:32:05.6064210Z: 50cd0c20-194c-4861-b627-092c27ebffe0 - AdalLoggerBase.cs: BrokerProxy: Broker supports adding accounts
Verbose 2019-01-11T11:32:05.6067490Z: 50cd0c20-194c-4861-b627-092c27ebffe0 - AdalLoggerBase.cs: BrokerProxy: Broker supports adding accounts
[] 2019-01-11T11:32:05.6071100Z: 50cd0c20-194c-4861-b627-092c27ebffe0 - AdalLoggerBase.cs: It switched to broker for context: com.debble.debbleintranet
Verbose 2019-01-11T11:32:05.6072630Z: 50cd0c20-194c-4861-b627-092c27ebffe0 - AdalLoggerBase.cs: It switched to broker for context: com.debble.debbleintranet
[] 2019-01-11T11:32:05.6074610Z: 50cd0c20-194c-4861-b627-092c27ebffe0 - AdalLoggerBase.cs: User is not specified for background token request
Verbose 2019-01-11T11:32:05.6076130Z: 50cd0c20-194c-4861-b627-092c27ebffe0 - AdalLoggerBase.cs: User is not specified for background token request
[] 2019-01-11T11:32:05.6078500Z: 50cd0c20-194c-4861-b627-092c27ebffe0 - AdalLoggerBase.cs: Token is not returned from backgroud call
Verbose 2019-01-11T11:32:05.6080040Z: 50cd0c20-194c-4861-b627-092c27ebffe0 - AdalLoggerBase.cs: Token is not returned from backgroud call
[] 2019-01-11T11:32:05.6082520Z: 50cd0c20-194c-4861-b627-092c27ebffe0 - AdalLoggerBase.cs: Launch activity for Authenticator
Verbose 2019-01-11T11:32:05.6084100Z: 50cd0c20-194c-4861-b627-092c27ebffe0 - AdalLoggerBase.cs: Launch activity for Authenticator
[] 2019-01-11T11:32:05.6086020Z: 50cd0c20-194c-4861-b627-092c27ebffe0 - AdalLoggerBase.cs: Starting Authentication Activity
Verbose 2019-01-11T11:32:05.6087650Z: 50cd0c20-194c-4861-b627-092c27ebffe0 - AdalLoggerBase.cs: Starting Authentication Activity
[] 2019-01-11T11:32:05.6089580Z: 50cd0c20-194c-4861-b627-092c27ebffe0 - AdalLoggerBase.cs: Initial request to authenticator
Verbose 2019-01-11T11:32:05.6091170Z: 50cd0c20-194c-4861-b627-092c27ebffe0 - AdalLoggerBase.cs: Initial request to authenticator
[] 2019-01-11T11:32:05.6335020Z: 50cd0c20-194c-4861-b627-092c27ebffe0 - AdalLoggerBase.cs: Calling activity pid:7688 tid:7787uid:10143
Verbose 2019-01-11T11:32:05.6337980Z: 50cd0c20-194c-4861-b627-092c27ebffe0 - AdalLoggerBase.cs: Calling activity pid:7688 tid:7787uid:10143
[] 2019-01-11T11:32:08.3056350Z: 00000000-0000-0000-0000-000000000000 - AdalLoggerBase.cs: Received Activity Result(2004)
Information 2019-01-11T11:32:08.3059730Z: 00000000-0000-0000-0000-000000000000 - AdalLoggerBase.cs: Received Activity Result(2004)
[] 2019-01-11T11:32:08.3100560Z: 50cd0c20-194c-4861-b627-092c27ebffe0 - AdalLoggerBase.cs: Storing token in the cache...
Verbose 2019-01-11T11:32:08.3104050Z: 50cd0c20-194c-4861-b627-092c27ebffe0 - AdalLoggerBase.cs: Storing token in the cache...
[] 2019-01-11T11:32:08.3108240Z: 50cd0c20-194c-4861-b627-092c27ebffe0 - AdalLoggerBase.cs: An item was stored in the cache
Verbose 2019-01-11T11:32:08.3110380Z: 50cd0c20-194c-4861-b627-092c27ebffe0 - AdalLoggerBase.cs: An item was stored in the cache
[] 2019-01-11T11:32:08.3136130Z: 00000000-0000-0000-0000-000000000000 - AdalLoggerBase.cs: Client Info is missing. Skipping MSAL refresh token cache write
Information 2019-01-11T11:32:08.3139760Z: 00000000-0000-0000-0000-000000000000 - AdalLoggerBase.cs: Client Info is missing. Skipping MSAL refresh token cache write
[] 2019-01-11T11:32:08.3160020Z: 50cd0c20-194c-4861-b627-092c27ebffe0 - AdalLoggerBase.cs: === Token Acquisition finished successfully. An access token was returned: Expiration Time: 11-1-2019 12:10:50 +00:00
Information 2019-01-11T11:32:08.3162420Z: 50cd0c20-194c-4861-b627-092c27ebffe0 - AdalLoggerBase.cs: === Token Acquisition finished successfully. An access token was returned: Expiration Time: 11-1-2019 12:10:50 +00:00Access Token Hash: xxx
	 User id: xxx
[] 2019-01-11T11:32:08.3167750Z: 00000000-0000-0000-0000-000000000000 - AdalLoggerBase.cs: Serializing token cache with 2 items.
Information 2019-01-11T11:32:08.3169830Z: 00000000-0000-0000-0000-000000000000 - AdalLoggerBase.cs: Serializing token cache with 2 items.
Microsoft.IdentityModel.Clients.ActiveDirectory.AdalSilentTokenAcquisitionException: Failed to acquire token silently as no token was found in the cache. Call method AcquireToken
  at Microsoft.IdentityModel.Clients.ActiveDirectory.Internal.Platform.AndroidBroker.AcquireTokenInternal (System.Collections.Generic.IDictionary`2[TKey,TValue] brokerPayload) [0x001f4] in C:\agent1\_work\70\s\src\Microsoft.IdentityModel.Clients.ActiveDirectory\Platforms\android\AndroidBroker.cs:162 
  at Microsoft.IdentityModel.Clients.ActiveDirectory.Internal.Platform.AndroidBroker+<>c__DisplayClass11_0.<AcquireTokenUsingBrokerAsync>b__0 () [0x00000] in C:\agent1\_work\70\s\src\Microsoft.IdentityModel.Clients.ActiveDirectory\Platforms\android\AndroidBroker.cs:76 
  at System.Threading.Tasks.Task.InnerInvoke () [0x0000f] in <fe08c003e91342eb83df1ca48302ddbb>:0 
  at System.Threading.Tasks.Task.Execute () [0x00000] in <fe08c003e91342eb83df1ca48302ddbb>: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:\agent1\_work\70\s\src\Microsoft.IdentityModel.Clients.ActiveDirectory\Platforms\android\AndroidBroker.cs:81 
--- End of stack trace from previous location where exception was thrown ---
  at Microsoft.IdentityModel.Clients.ActiveDirectory.Internal.Flows.AcquireTokenHandlerBase+<RunAsync>d__53.MoveNext () [0x0069c] in C:\agent1\_work\70\s\src\Microsoft.IdentityModel.Clients.ActiveDirectory\Internal\Flows\AcquireTokenHandlerBase.cs:218 
--- End of stack trace from previous location where exception was thrown ---
  at Microsoft.IdentityModel.Clients.ActiveDirectory.AuthenticationContext+<AcquireTokenSilentCommonAsync>d__40.MoveNext () [0x0007b] in C:\agent1\_work\70\s\src\Microsoft.IdentityModel.Clients.ActiveDirectory\AuthenticationContext.cs:517 
--- End of stack trace from previous location where exception was thrown ---
  at Microsoft.IdentityModel.Clients.ActiveDirectory.AuthenticationContext+<AcquireTokenSilentAsync>d__28.MoveNext () [0x00044] in C:\agent1\_work\70\s\src\Microsoft.IdentityModel.Clients.ActiveDirectory\AuthenticationContext.cs:311 
--- End of stack trace from previous location where exception was thrown ---
  at Droid.Authenticator+<AuthenticateSilent>d__14.MoveNext () [0x000de] in /Users/eldin/Work/Droid/CustomComponents/Authenticator.cs:151 
	ErrorCode: failed_to_acquire_token_silently

@bgavrilMS
Copy link
Member

Thank you.

When you perform the AcquireTokenSilent call, what do you provide as user identifier / login hint? I believe you provide the UniqueID, but in fact the UPN (the email) should be provided. The reason is that we need to identify the account to be used in teh silent call on the broker side.

This is known to you from the interactive call as result.UserInfo.DisplayableId;

Here is a code sample that I have and is working:

private async void acquireTokenSilentButton_Click(object sender, EventArgs e)

@EldinHb
Copy link
Author

EldinHb commented Jan 11, 2019

I did use the UniqueID. I changed it to use the UPN and the application behaves the same.

This is my exact code for the silent call:

var authContext = new AuthenticationContext(authority);
if (authContext.TokenCache.ReadItems().Any())
           authContext = new AuthenticationContext(authContext.TokenCache.ReadItems().First().Authority);

var userId = new UserIdentifier(id, UserIdentifierType.UniqueId);
var testUserId = new UserIdentifier(userName, UserIdentifierType.OptionalDisplayableId);
var platformParams = new PlatformParameters(Plugin.CurrentActivity.CrossCurrentActivity.Current.Activity, UseBroker);
AuthenticationResult authResult = await authContext.AcquireTokenSilentAsync(resource, clientId, testUserId, platformParams);

@bgavrilMS
Copy link
Member

Hi @eldin66 - appologies for the late response. I think we managed to fix this issue in ADAL 4.5 - please try it out. Consider clearing the cache first to start fresh.

There is another issue with ADAL + broker, but it doesn't seem to affect you #1477

@EldinHb
Copy link
Author

EldinHb commented Feb 5, 2019

Hi @bgavrilMS, no worries. I will test it out asap and report my findings.

@EldinHb
Copy link
Author

EldinHb commented Feb 7, 2019

Hi @bgavrilMS, I tested version 4.5 and can confirm that the issue has been partially fixed. The token now gets silently refreshed after an app restart, for us this was the most important fix here. Thank you!

The issue that still remains is that the user has to login twice on initial login. Once using https://login.windows.net/ and second time https://graph.microsoft.com.

@bgavrilMS
Copy link
Member

Not sure I fully understand what you mean by your last statement. I assume that you need to login once for Sharepoint and once for Graph?

I expect that if you get a token for resource R1 interactively, then you should be able to perform silent calls to get tokens for R2 (and R1 of course).

Are you making the silent calls explicitly?

@EldinHb
Copy link
Author

EldinHb commented Feb 7, 2019

Yes, that is exactly what I mean. After we interactively got the token for R1, we cannot get the token silently for R2. It works on iOS and not on Android.

@bgavrilMS
Copy link
Member

I'm going to be out of office for the next ~2 weeks and won't be able to look into this. @jmprieur, @trwalke - can you help ? I already modified our Android sample app to use the broker and to acquire tokens for 2 different resources, which seems to work. So something else is going on here...

@jmprieur jmprieur self-assigned this Jun 6, 2019
@jmprieur
Copy link
Contributor

jmprieur commented Jun 6, 2019

Closing as duplicate of #1601 which is being fixed.

@jmprieur jmprieur closed this as completed Jun 6, 2019
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

4 participants