Skip to content
New issue

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

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

Already on GitHub? Sign in to your account

Error authenticating to Azure DevOps with OAuth "Application ... is configured for use by Azure Active Directory users only" #1297

Closed
hickford opened this issue Jun 18, 2023 · 15 comments · Fixed by #1321
Assignees
Labels
auth:microsoft Specific to Microsoft AAD/MSA authentication external Relating to an external partner, team, or library

Comments

@hickford
Copy link
Contributor

hickford commented Jun 18, 2023

I tried to authenticate to Azure DevOps with credential.azreposCredentialType=oauth. I'm using GCM 2.1.2 on Linux (installed with dotnet tool):

echo protocol=https\nhost=dev.azure.com\npath=matthickford0459/testdevazuredotcom/_git/testdevazuredotcom\nusername=matthickford0459\nwwwauth[]=Basic realm=\"https://tfsproduks1.visualstudio.com/\" | git -c credential.azreposCredentialType=oauth credential-manager get

gave me error

fatal: AADSTS9002332: Application '872cd9fa-d31f-45e0-9eab-6e460a02d1f1'(Visual Studio - Legacy) is configured for use by Azure Active Directory users only. Please do not use the /consumers endpoint to serve this request.

GCM trace:

16:04:33.468133 ...re/Application.cs:95 trace: [RunInternalAsync] Version: 2.1.2.0
16:04:33.525134 ...re/Application.cs:96 trace: [RunInternalAsync] Runtime: .NET 6.0.16
16:04:33.525284 ...re/Application.cs:97 trace: [RunInternalAsync] Platform: Linux (x86-64)
16:04:33.525326 ...re/Application.cs:98 trace: [RunInternalAsync] OSVersion: Linux penguin 5.15.112-19373-g62629859bf76 #1 SMP PREEMPT Sun Jun 11 18:47:30 PDT 2023 x86_64 GNU/Linux
16:04:33.525474 ...re/Application.cs:99 trace: [RunInternalAsync] AppPath: /home/matthickford/.dotnet/tools/git-credential-manager
16:04:33.525783 ...e/Application.cs:100 trace: [RunInternalAsync] InstallDir: /home/matthickford/.dotnet/tools/.store/git-credential-manager/2.1.2/git-credential-manager/2.1.2/tools/net6.0/any/
16:04:33.525965 ...e/Application.cs:101 trace: [RunInternalAsync] Arguments: get
16:04:33.893875 ...GitCommandBase.cs:33 trace: [ExecuteAsync] Start 'get' command...
16:04:33.978260 ...GitCommandBase.cs:47 trace: [ExecuteAsync] Detecting host provider for input:
16:04:33.998439 ...GitCommandBase.cs:48 trace: [ExecuteAsync] 	protocol=https
16:04:33.998613 ...GitCommandBase.cs:48 trace: [ExecuteAsync] 	host=dev.azure.com
16:04:33.998650 ...GitCommandBase.cs:48 trace: [ExecuteAsync] 	path=matthickford0459/testdevazuredotcom/_git/testdevazuredotcom
16:04:33.998682 ...GitCommandBase.cs:48 trace: [ExecuteAsync] 	username=matthickford0459
16:04:33.998714 ...GitCommandBase.cs:48 trace: [ExecuteAsync] 	wwwauth[]=Basic realm="https://tfsproduks1.visualstudio.com/"
16:04:34.033585 ...viderRegistry.cs:149 trace: [GetProviderAsync] Performing auto-detection of host provider.
16:04:34.035429 ...viderRegistry.cs:162 trace: [GetProviderAsync] Auto-detect probe timeout is 2 ms.
16:04:34.049731 ...viderRegistry.cs:170 trace: [GetProviderAsync] Checking against 4 host providers registered with priority 'Normal'.
16:04:34.053564 ...GitCommandBase.cs:50 trace: [ExecuteAsync] Host provider 'Azure Repos' was selected.
16:04:34.065690 ...sHostProvider.cs:403 trace: [UsePersonalAccessTokens] Azure Repos credential type override set to 'oauth'
16:04:34.077070 ...sHostProvider.cs:237 trace: [GetAzureAccessTokenAsync] Determining Microsoft Authentication authority for Azure DevOps organization 'matthickford0459'...
16:04:34.077914 ...AuthorityCache.cs:57 trace: [GetAuthority] Looking up cached authority for organization 'matthickford0459'...
16:04:34.175252 ...sHostProvider.cs:246 trace: [GetAzureAccessTokenAsync] Authority is 'https://login.microsoftonline.com/organizations'.
16:04:34.175459 ...sHostProvider.cs:268 trace: [GetAzureAccessTokenAsync] Looking up user for organization 'matthickford0459'...
16:04:34.177968 ...BindingManager.cs:94 trace: [GetBinding] Looking up organization binding for 'matthickford0459'...
16:04:34.199244 ...sHostProvider.cs:272 trace: [GetAzureAccessTokenAsync] User is 'matt.hickford@gmail.com'.
16:04:34.199502 ...sHostProvider.cs:275 trace: [GetAzureAccessTokenAsync] Getting Azure AD access token...
16:04:34.224146 ...Authentication.cs:66 trace: [GetTokenAsync] OS broker is not available or enabled.
16:04:34.313812 ...uthentication.cs:393 trace: [RegisterTokenCacheAsync] Configuring Microsoft Authentication token cache to instance shared with Microsoft developer tools...
16:04:34.684218 ...uthentication.cs:449 trace: [RegisterTokenCacheAsync] Microsoft developer tools token cache configured.
16:04:34.690610 ...uthentication.cs:296 trace: [GetAccessTokenSilentlyAsync] Attempting to acquire token silently for user 'matt.hickford@gmail.com'...
16:04:35.418439 ...pClientFactory.cs:60 trace: [CreateClient] Creating new HTTP client instance...
16:04:35.445055 ...pClientFactory.cs:80 trace: [CreateClient] Git's SSL/TLS backend is: OpenSsl
fatal: AADSTS9002332: Application '872cd9fa-d31f-45e0-9eab-6e460a02d1f1'(Visual Studio - Legacy) is configured for use by Azure Active Directory users only. Please do not use the /consumers endpoint to serve this request.
Trace ID: 4102503b-7ec5-4877-9760-668c81ed9c00
Correlation ID: 7f23d101-4258-4b26-a6ed-5da8218c82b0
Timestamp: 2023-06-18 15:04:39Z
   at Microsoft.Identity.Client.Internal.Requests.Silent.SilentRequest.ExecuteAsync(CancellationToken cancellationToken)
   at Microsoft.Identity.Client.Internal.Requests.RequestBase.RunAsync(CancellationToken cancellationToken)
   at Microsoft.Identity.Client.ApiConfig.Executors.ClientApplicationBaseExecutor.ExecuteAsync(AcquireTokenCommonParameters commonParameters, AcquireTokenSilentParameters silentParameters, CancellationToken cancellationToken)
   at GitCredentialManager.Authentication.MicrosoftAuthentication.GetAccessTokenSilentlyAsync(IPublicClientApplication app, String[] scopes, String userName)
   at GitCredentialManager.Authentication.MicrosoftAuthentication.GetTokenAsync(String authority, String clientId, Uri redirectUri, String[] scopes, String userName)
   at Microsoft.AzureRepos.AzureReposHostProvider.GetAzureAccessTokenAsync(Uri remoteUri, String userName)
   at Microsoft.AzureRepos.AzureReposHostProvider.GetCredentialAsync(InputArguments input)
   at GitCredentialManager.Commands.GetCommand.ExecuteInternalAsync(InputArguments input, IHostProvider provider)
   at GitCredentialManager.Commands.GitCommandBase.ExecuteAsync()
   at System.CommandLine.Invocation.CommandHandler.GetExitCodeAsync(Object value, InvocationContext context)
   at System.CommandLine.Invocation.ModelBindingCommandHandler.InvokeAsync(InvocationContext context)
   at System.CommandLine.Invocation.InvocationPipeline.<>c__DisplayClass4_0.<b__0>d.MoveNext()
--- End of stack trace from previous location ---
   at System.CommandLine.Builder.CommandLineBuilderExtensions.<>c__DisplayClass23_0.<b__0>d.MoveNext()
--- End of stack trace from previous location ---
   at System.CommandLine.Builder.CommandLineBuilderExtensions.<>c__DisplayClass16_0.<b__0>d.MoveNext()
--- End of stack trace from previous location ---
   at System.CommandLine.Builder.CommandLineBuilderExtensions.<>c__DisplayClass27_0.<b__1>d.MoveNext()
--- End of stack trace from previous location ---
   at System.CommandLine.Builder.CommandLineBuilderExtensions.<>c__DisplayClass25_0.<b__0>d.MoveNext()
--- End of stack trace from previous location ---
   at System.CommandLine.Builder.CommandLineBuilderExtensions.<>c.<b__24_0>d.MoveNext()
--- End of stack trace from previous location ---
   at System.CommandLine.Builder.CommandLineBuilderExtensions.<>c__DisplayClass22_0.<b__0>d.MoveNext()
--- End of stack trace from previous location ---
   at System.CommandLine.Builder.CommandLineBuilderExtensions.<>c__DisplayClass11_0.<b__0>d.MoveNext()
--- End of stack trace from previous location ---
   at System.CommandLine.Builder.CommandLineBuilderExtensions.<>c.<b__10_0>d.MoveNext()
--- End of stack trace from previous location ---
   at System.CommandLine.Builder.CommandLineBuilderExtensions.<>c__DisplayClass14_0.<b__0>d.MoveNext()

Workaround: credential.azreposCredentialType=pat works as expected

@hickford hickford changed the title Error "Application ... is configured for use by Azure Active Directory users only" when credential.azreposCredentialType=oauth Error authenticating to Azure DevOps with OAuth "Application ... is configured for use by Azure Active Directory users only" Jun 18, 2023
@ldennington
Copy link
Contributor

ldennington commented Jun 19, 2023

@mjcheetham can probably speak more on this, but it looks like MSAL is trying to acquire a token for matt.hickford@gmail.com and is running into issues with the Client App (which we share with VS). As a sanity check, is matt.hickford@gmail.com a Microsoft Account (I'm assuming it's not a work or school account)?

@hickford
Copy link
Contributor Author

Yes, an ordinary Microsoft account.

@mjcheetham
Copy link
Collaborator

@hickford could you please try setting the GCM_TRACE_MSAUTH=1 environment variable?

Note that these MSAL logs are very verbose, and may contain secrets. We do our best to ensure secrets are masked by default however.

Azure DevOps doesn't support the "v2" Microsoft identity platform, which unified the AAD and MSA models. Instead it uses "MSA passthrough" which is a hack to allow "v1" relying parties to accept both AAD and MSA tokens, by exchanging native MSA tokens for an AAD token from a 'fake' AAD tenant for all MSAs. (Yes, it's.. creative!)

The error here usually means we tried to use login.microsoftonline.com/common or /consumers as the authority.. but from you trace I can see already we're using /organizations which is correct for MSA-PT apps:

16:04:34.077914 ...AuthorityCache.cs:57 trace: [GetAuthority] Looking up cached authority for organization 'matthickford0459'...
16:04:34.175252 ...sHostProvider.cs:246 trace: [GetAzureAccessTokenAsync] Authority is 'https://login.microsoftonline.com/organizations'.

cc: @bgavrilMS

@mjcheetham mjcheetham added auth:microsoft Specific to Microsoft AAD/MSA authentication external Relating to an external partner, team, or library labels Jun 19, 2023
@bgavrilMS
Copy link

bgavrilMS commented Jun 20, 2023 via email

@hickford
Copy link
Contributor Author

hickford commented Jun 22, 2023

@mjcheetham @bgavrilMS To check my understanding, there appear to be two OAuth authorization servers you can use to authenticate Azure DevOps . Which does GCM uses?

  1. app.vssps.visualstudio.com https://learn.microsoft.com/en-us/azure/devops/integrate/get-started/authentication/oauth?view=azure-devops , apps registered at https://app.vsaex.visualstudio.com/app/register
  2. AAD https://learn.microsoft.com/en-us/azure/active-directory/develop/quickstart-register-app , apps registered in Azure Portal . This is the API called by the library MSAL.

@hickford
Copy link
Contributor Author

hickford commented Jun 22, 2023

@hickford could you please try setting the GCM_TRACE_MSAUTH=1 environment variable?

09:00:03.756179 ...re/Application.cs:95 trace: [RunInternalAsync] Version: 2.1.2.0
09:00:03.784643 ...re/Application.cs:96 trace: [RunInternalAsync] Runtime: .NET 6.0.18
09:00:03.784775 ...re/Application.cs:97 trace: [RunInternalAsync] Platform: Linux (x86-64)
09:00:03.784817 ...re/Application.cs:98 trace: [RunInternalAsync] OSVersion: Linux penguin 5.15.112-19373-g62629859bf76 #1 SMP PREEMPT Sun Jun 11 18:47:30 PDT 2023 x86_64 GNU/Linux
09:00:03.784885 ...re/Application.cs:99 trace: [RunInternalAsync] AppPath: /home/matthickford/.dotnet/tools/git-credential-manager
09:00:03.785327 ...e/Application.cs:100 trace: [RunInternalAsync] InstallDir: /home/matthickford/.dotnet/tools/.store/git-credential-manager/2.1.2/git-credential-manager/2.1.2/tools/net6.0/any/
09:00:03.785485 ...e/Application.cs:101 trace: [RunInternalAsync] Arguments: get
09:00:03.851632 ...GitCommandBase.cs:33 trace: [ExecuteAsync] Start 'get' command...
09:00:03.902567 ...GitCommandBase.cs:47 trace: [ExecuteAsync] Detecting host provider for input:
09:00:03.917334 ...GitCommandBase.cs:48 trace: [ExecuteAsync] 	protocol=https
09:00:03.917513 ...GitCommandBase.cs:48 trace: [ExecuteAsync] 	host=dev.azure.com
09:00:03.917551 ...GitCommandBase.cs:48 trace: [ExecuteAsync] 	path=matthickford0459/testdevazuredotcom/_git/testdevazuredotcom
09:00:03.917583 ...GitCommandBase.cs:48 trace: [ExecuteAsync] 	username=matthickford0459
09:00:03.917613 ...GitCommandBase.cs:48 trace: [ExecuteAsync] 	wwwauth[]=Basic realm="https://tfsproduks1.visualstudio.com/"
09:00:03.921198 ...viderRegistry.cs:149 trace: [GetProviderAsync] Performing auto-detection of host provider.
09:00:03.921347 ...viderRegistry.cs:162 trace: [GetProviderAsync] Auto-detect probe timeout is 2 ms.
09:00:03.922492 ...viderRegistry.cs:170 trace: [GetProviderAsync] Checking against 4 host providers registered with priority 'Normal'.
09:00:03.922790 ...GitCommandBase.cs:50 trace: [ExecuteAsync] Host provider 'Azure Repos' was selected.
09:00:03.923733 ...sHostProvider.cs:403 trace: [UsePersonalAccessTokens] Azure Repos credential type override set to 'oauth'
09:00:03.924615 ...sHostProvider.cs:237 trace: [GetAzureAccessTokenAsync] Determining Microsoft Authentication authority for Azure DevOps organization 'matthickford0459'...
09:00:03.924676 ...AuthorityCache.cs:57 trace: [GetAuthority] Looking up cached authority for organization 'matthickford0459'...
09:00:03.965598 ...sHostProvider.cs:246 trace: [GetAzureAccessTokenAsync] Authority is 'https://login.microsoftonline.com/organizations'.
09:00:03.965641 ...sHostProvider.cs:268 trace: [GetAzureAccessTokenAsync] Looking up user for organization 'matthickford0459'...
09:00:03.965911 ...BindingManager.cs:94 trace: [GetBinding] Looking up organization binding for 'matthickford0459'...
09:00:03.969803 ...sHostProvider.cs:272 trace: [GetAzureAccessTokenAsync] User is 'matt.hickford@gmail.com'.
09:00:03.969859 ...sHostProvider.cs:275 trace: [GetAzureAccessTokenAsync] Getting Azure AD access token...
09:00:03.974060 ...Authentication.cs:66 trace: [GetTokenAsync] OS broker is not available or enabled.
09:00:04.021264 ...uthentication.cs:393 trace: [RegisterTokenCacheAsync] Configuring Microsoft Authentication token cache to instance shared with Microsoft developer tools...
09:00:04.141824 ...uthentication.cs:449 trace: [RegisterTokenCacheAsync] Microsoft developer tools token cache configured.
09:00:04.143908 ...uthentication.cs:296 trace: [GetAccessTokenSilentlyAsync] Attempting to acquire token silently for user 'matt.hickford@gmail.com'...
09:00:04.153306 ...uthentication.cs:514 trace: [MSAL] [Info] False MSAL 4.52.0.0 MSAL.NetCore .NET 6.0.18 Linux 5.15.112-19373-g62629859bf76 #1 SMP PREEMPT Sun Jun 11 18:47:30 PDT 2023 [2023-06-22 08:00:04Z - 082eb1d7-91aa-4f5d-be10-b15a470b4590] MSAL MSAL.NetCore with assembly version '4.52.0.0'. CorrelationId(082eb1d7-91aa-4f5d-be10-b15a470b4590)
09:00:04.158655 ...uthentication.cs:514 trace: [MSAL] [Info] False MSAL 4.52.0.0 MSAL.NetCore .NET 6.0.18 Linux 5.15.112-19373-g62629859bf76 #1 SMP PREEMPT Sun Jun 11 18:47:30 PDT 2023 [2023-06-22 08:00:04Z - 082eb1d7-91aa-4f5d-be10-b15a470b4590] === AcquireTokenSilent Parameters ===
09:00:04.158719 ...uthentication.cs:514 trace: [MSAL] [Info] False MSAL 4.52.0.0 MSAL.NetCore .NET 6.0.18 Linux 5.15.112-19373-g62629859bf76 #1 SMP PREEMPT Sun Jun 11 18:47:30 PDT 2023 [2023-06-22 08:00:04Z - 082eb1d7-91aa-4f5d-be10-b15a470b4590] LoginHint provided: True
09:00:04.158779 ...uthentication.cs:514 trace: [MSAL] [Info] False MSAL 4.52.0.0 MSAL.NetCore .NET 6.0.18 Linux 5.15.112-19373-g62629859bf76 #1 SMP PREEMPT Sun Jun 11 18:47:30 PDT 2023 [2023-06-22 08:00:04Z - 082eb1d7-91aa-4f5d-be10-b15a470b4590] Account provided: False
09:00:04.158823 ...uthentication.cs:514 trace: [MSAL] [Info] False MSAL 4.52.0.0 MSAL.NetCore .NET 6.0.18 Linux 5.15.112-19373-g62629859bf76 #1 SMP PREEMPT Sun Jun 11 18:47:30 PDT 2023 [2023-06-22 08:00:04Z - 082eb1d7-91aa-4f5d-be10-b15a470b4590] ForceRefresh: False
09:00:04.162042 ...uthentication.cs:514 trace: [MSAL] [Info] False MSAL 4.52.0.0 MSAL.NetCore .NET 6.0.18 Linux 5.15.112-19373-g62629859bf76 #1 SMP PREEMPT Sun Jun 11 18:47:30 PDT 2023 [2023-06-22 08:00:04Z - 082eb1d7-91aa-4f5d-be10-b15a470b4590] 
=== Request Data ===
Authority Provided? - True
Scopes - 499b84ac-1321-427f-aa17-267ca6975798/.default
Extra Query Params Keys (space separated) - 
ApiId - AcquireTokenSilent
IsConfidentialClient - False
SendX5C - False
LoginHint ? False
IsBrokerConfigured - False
HomeAccountId - False
CorrelationId - 082eb1d7-91aa-4f5d-be10-b15a470b4590
UserAssertion set: False
LongRunningOboCacheKey set: False
Region configured: 

09:00:04.162442 ...uthentication.cs:514 trace: [MSAL] [Info] False MSAL 4.52.0.0 MSAL.NetCore .NET 6.0.18 Linux 5.15.112-19373-g62629859bf76 #1 SMP PREEMPT Sun Jun 11 18:47:30 PDT 2023 [2023-06-22 08:00:04Z - 082eb1d7-91aa-4f5d-be10-b15a470b4590] === Token Acquisition (SilentRequest) started:
Scopes: 499b84ac-1321-427f-aa17-267ca6975798/.default
Authority Host: login.microsoftonline.com
09:00:04.172939 ...uthentication.cs:514 trace: [MSAL] [Verbose] False MSAL 4.52.0.0 MSAL.NetCore .NET 6.0.18 Linux 5.15.112-19373-g62629859bf76 #1 SMP PREEMPT Sun Jun 11 18:47:30 PDT 2023 [2023-06-22 08:00:04Z - 082eb1d7-91aa-4f5d-be10-b15a470b4590] [Cache Session Manager] Entering the cache semaphore. Real semaphore: True. Count: 1
09:00:04.174268 ...uthentication.cs:514 trace: [MSAL] [Verbose] False MSAL 4.52.0.0 MSAL.NetCore .NET 6.0.18 Linux 5.15.112-19373-g62629859bf76 #1 SMP PREEMPT Sun Jun 11 18:47:30 PDT 2023 [2023-06-22 08:00:04Z - 082eb1d7-91aa-4f5d-be10-b15a470b4590] [Cache Session Manager] Entered cache semaphore
09:00:04.181849 ...uthentication.cs:514 trace: [MSAL] [Verbose] False MSAL 4.52.0.0 MSAL.NetCore .NET 6.0.18 Linux 5.15.112-19373-g62629859bf76 #1 SMP PREEMPT Sun Jun 11 18:47:30 PDT 2023 [2023-06-22 08:00:04Z] [Microsoft.Identity.Client.Extensions] Before access
Acquiring lock for token cache
09:00:04.182017 ...uthentication.cs:514 trace: [MSAL] [Verbose] False MSAL 4.52.0.0 MSAL.NetCore .NET 6.0.18 Linux 5.15.112-19373-g62629859bf76 #1 SMP PREEMPT Sun Jun 11 18:47:30 PDT 2023 [2023-06-22 08:00:04Z] [Microsoft.Identity.Client.Extensions] Before access, the store has changed
09:00:04.184049 ...uthentication.cs:514 trace: [MSAL] [Verbose] False MSAL 4.52.0.0 MSAL.NetCore .NET 6.0.18 Linux 5.15.112-19373-g62629859bf76 #1 SMP PREEMPT Sun Jun 11 18:47:30 PDT 2023 [2023-06-22 08:00:04Z] [Microsoft.Identity.Client.Extensions] Read '7104' bytes from storage
09:00:04.184069 ...uthentication.cs:514 trace: [MSAL] [Verbose] False MSAL 4.52.0.0 MSAL.NetCore .NET 6.0.18 Linux 5.15.112-19373-g62629859bf76 #1 SMP PREEMPT Sun Jun 11 18:47:30 PDT 2023 [2023-06-22 08:00:04Z] [Microsoft.Identity.Client.Extensions] Deserializing the store
09:00:04.240853 ...uthentication.cs:514 trace: [MSAL] [Always] False MSAL 4.52.0.0 MSAL.NetCore .NET 6.0.18 Linux 5.15.112-19373-g62629859bf76 #1 SMP PREEMPT Sun Jun 11 18:47:30 PDT 2023 [2023-06-22 08:00:04Z] [Internal cache] Clearing user token cache accessor.
09:00:04.241751 ...uthentication.cs:514 trace: [MSAL] [Verbose] False MSAL 4.52.0.0 MSAL.NetCore .NET 6.0.18 Linux 5.15.112-19373-g62629859bf76 #1 SMP PREEMPT Sun Jun 11 18:47:30 PDT 2023 [2023-06-22 08:00:04Z] [Microsoft.Identity.Client.Extensions] After access
09:00:04.241908 ...uthentication.cs:514 trace: [MSAL] [Verbose] False MSAL 4.52.0.0 MSAL.NetCore .NET 6.0.18 Linux 5.15.112-19373-g62629859bf76 #1 SMP PREEMPT Sun Jun 11 18:47:30 PDT 2023 [2023-06-22 08:00:04Z - 082eb1d7-91aa-4f5d-be10-b15a470b4590] [Cache Session Manager] Released cache semaphore
09:00:04.275115 ...uthentication.cs:514 trace: [MSAL] [Always] False MSAL 4.52.0.0 MSAL.NetCore .NET 6.0.18 Linux 5.15.112-19373-g62629859bf76 #1 SMP PREEMPT Sun Jun 11 18:47:30 PDT 2023 [2023-06-22 08:00:04Z] [Internal cache] Total number of cache partitions found while getting refresh tokens: 1
09:00:04.276857 ...uthentication.cs:514 trace: [MSAL] [Verbose] False MSAL 4.52.0.0 MSAL.NetCore .NET 6.0.18 Linux 5.15.112-19373-g62629859bf76 #1 SMP PREEMPT Sun Jun 11 18:47:30 PDT 2023 [2023-06-22 08:00:04Z - 082eb1d7-91aa-4f5d-be10-b15a470b4590] [GetAccounts] Found 1 RTs and 1 accounts in MSAL cache.
09:00:04.277061 ...uthentication.cs:514 trace: [MSAL] [Info] False MSAL 4.52.0.0 MSAL.NetCore .NET 6.0.18 Linux 5.15.112-19373-g62629859bf76 #1 SMP PREEMPT Sun Jun 11 18:47:30 PDT 2023 [2023-06-22 08:00:04Z - 082eb1d7-91aa-4f5d-be10-b15a470b4590] IsLegacyAdalCacheEnabled: yes
09:00:04.280576 ...uthentication.cs:514 trace: [MSAL] [Info] False MSAL 4.52.0.0 MSAL.NetCore .NET 6.0.18 Linux 5.15.112-19373-g62629859bf76 #1 SMP PREEMPT Sun Jun 11 18:47:30 PDT 2023 [2023-06-22 08:00:04Z - 082eb1d7-91aa-4f5d-be10-b15a470b4590] [Region discovery] Not using a regional authority.
09:00:04.280773 ...uthentication.cs:514 trace: [MSAL] [Verbose] False MSAL 4.52.0.0 MSAL.NetCore .NET 6.0.18 Linux 5.15.112-19373-g62629859bf76 #1 SMP PREEMPT Sun Jun 11 18:47:30 PDT 2023 [2023-06-22 08:00:04Z - 082eb1d7-91aa-4f5d-be10-b15a470b4590] [Instance Discovery] Tried to use network cache provider for login.microsoftonline.com. Success? False.
09:00:04.281087 ...uthentication.cs:514 trace: [MSAL] [Verbose] False MSAL 4.52.0.0 MSAL.NetCore .NET 6.0.18 Linux 5.15.112-19373-g62629859bf76 #1 SMP PREEMPT Sun Jun 11 18:47:30 PDT 2023 [2023-06-22 08:00:04Z - 082eb1d7-91aa-4f5d-be10-b15a470b4590] [Instance Discovery] Tried to use known metadata provider for login.microsoftonline.com. Success? True.
09:00:04.281202 ...uthentication.cs:514 trace: [MSAL] [Verbose] False MSAL 4.52.0.0 MSAL.NetCore .NET 6.0.18 Linux 5.15.112-19373-g62629859bf76 #1 SMP PREEMPT Sun Jun 11 18:47:30 PDT 2023 [2023-06-22 08:00:04Z - 082eb1d7-91aa-4f5d-be10-b15a470b4590] [GetAccounts] Found 1 RTs and 1 accounts in MSAL cache after environment filtering.
09:00:04.283081 ...uthentication.cs:514 trace: [MSAL] [Info] False MSAL 4.52.0.0 MSAL.NetCore .NET 6.0.18 Linux 5.15.112-19373-g62629859bf76 #1 SMP PREEMPT Sun Jun 11 18:47:30 PDT 2023 [2023-06-22 08:00:04Z - 082eb1d7-91aa-4f5d-be10-b15a470b4590] [Region discovery] Not using a regional authority.
09:00:04.283099 ...uthentication.cs:514 trace: [MSAL] [Verbose] False MSAL 4.52.0.0 MSAL.NetCore .NET 6.0.18 Linux 5.15.112-19373-g62629859bf76 #1 SMP PREEMPT Sun Jun 11 18:47:30 PDT 2023 [2023-06-22 08:00:04Z - 082eb1d7-91aa-4f5d-be10-b15a470b4590] [Instance Discovery] Tried to use network cache provider for login.microsoftonline.com. Success? False.
09:00:04.283116 ...uthentication.cs:514 trace: [MSAL] [Verbose] False MSAL 4.52.0.0 MSAL.NetCore .NET 6.0.18 Linux 5.15.112-19373-g62629859bf76 #1 SMP PREEMPT Sun Jun 11 18:47:30 PDT 2023 [2023-06-22 08:00:04Z - 082eb1d7-91aa-4f5d-be10-b15a470b4590] [Instance Discovery] Tried to use known metadata provider for login.microsoftonline.com. Success? True.
09:00:04.283290 ...uthentication.cs:514 trace: [MSAL] [Info] False MSAL 4.52.0.0 MSAL.NetCore .NET 6.0.18 Linux 5.15.112-19373-g62629859bf76 #1 SMP PREEMPT Sun Jun 11 18:47:30 PDT 2023 [2023-06-22 08:00:04Z - 082eb1d7-91aa-4f5d-be10-b15a470b4590] IsLegacyAdalCacheEnabled: yes
09:00:04.284090 ...uthentication.cs:514 trace: [MSAL] [Info] False MSAL 4.52.0.0 MSAL.NetCore .NET 6.0.18 Linux 5.15.112-19373-g62629859bf76 #1 SMP PREEMPT Sun Jun 11 18:47:30 PDT 2023 [2023-06-22 08:00:04Z - 082eb1d7-91aa-4f5d-be10-b15a470b4590] IsLegacyAdalCacheEnabled: yes
09:00:04.285338 ...uthentication.cs:514 trace: [MSAL] [Verbose] False MSAL 4.52.0.0 MSAL.NetCore .NET 6.0.18 Linux 5.15.112-19373-g62629859bf76 #1 SMP PREEMPT Sun Jun 11 18:47:30 PDT 2023 [2023-06-22 08:00:04Z - 082eb1d7-91aa-4f5d-be10-b15a470b4590] Attempting to acquire token using local cache.
09:00:04.287077 ...uthentication.cs:514 trace: [MSAL] [Always] False MSAL 4.52.0.0 MSAL.NetCore .NET 6.0.18 Linux 5.15.112-19373-g62629859bf76 #1 SMP PREEMPT Sun Jun 11 18:47:30 PDT 2023 [2023-06-22 08:00:04Z - 082eb1d7-91aa-4f5d-be10-b15a470b4590] [Internal cache] Total number of cache partitions found while getting access tokens: 1
09:00:04.287170 ...uthentication.cs:514 trace: [MSAL] [Always] False MSAL 4.52.0.0 MSAL.NetCore .NET 6.0.18 Linux 5.15.112-19373-g62629859bf76 #1 SMP PREEMPT Sun Jun 11 18:47:30 PDT 2023 [2023-06-22 08:00:04Z - 082eb1d7-91aa-4f5d-be10-b15a470b4590] [FindAccessTokenAsync] Discovered 1 access tokens in cache using partition key: 00000000-0000-0000-3ad1-9a77eea46e8a.9188040d-6c67-4c5b-b112-36a304b66dad
09:00:04.287724 ...uthentication.cs:514 trace: [MSAL] [Verbose] False MSAL 4.52.0.0 MSAL.NetCore .NET 6.0.18 Linux 5.15.112-19373-g62629859bf76 #1 SMP PREEMPT Sun Jun 11 18:47:30 PDT 2023 [2023-06-22 08:00:04Z - 082eb1d7-91aa-4f5d-be10-b15a470b4590] Filtering AT by tenant id - item count before: 1
09:00:04.287864 ...uthentication.cs:514 trace: [MSAL] [Verbose] False MSAL 4.52.0.0 MSAL.NetCore .NET 6.0.18 Linux 5.15.112-19373-g62629859bf76 #1 SMP PREEMPT Sun Jun 11 18:47:30 PDT 2023 [2023-06-22 08:00:04Z - 082eb1d7-91aa-4f5d-be10-b15a470b4590] Filtering AT by tenant id - item count after: 0
09:00:04.287874 ...uthentication.cs:514 trace: [MSAL] [Verbose] False MSAL 4.52.0.0 MSAL.NetCore .NET 6.0.18 Linux 5.15.112-19373-g62629859bf76 #1 SMP PREEMPT Sun Jun 11 18:47:30 PDT 2023 [2023-06-22 08:00:04Z - 082eb1d7-91aa-4f5d-be10-b15a470b4590] Filtering AT by home account id - item count before: 0
09:00:04.287878 ...uthentication.cs:514 trace: [MSAL] [Verbose] False MSAL 4.52.0.0 MSAL.NetCore .NET 6.0.18 Linux 5.15.112-19373-g62629859bf76 #1 SMP PREEMPT Sun Jun 11 18:47:30 PDT 2023 [2023-06-22 08:00:04Z - 082eb1d7-91aa-4f5d-be10-b15a470b4590] Filtering AT by home account id - item count after: 0
09:00:04.287954 ...uthentication.cs:514 trace: [MSAL] [Verbose] False MSAL 4.52.0.0 MSAL.NetCore .NET 6.0.18 Linux 5.15.112-19373-g62629859bf76 #1 SMP PREEMPT Sun Jun 11 18:47:30 PDT 2023 [2023-06-22 08:00:04Z - 082eb1d7-91aa-4f5d-be10-b15a470b4590] Filtering by token type - item count before: 0
09:00:04.287960 ...uthentication.cs:514 trace: [MSAL] [Verbose] False MSAL 4.52.0.0 MSAL.NetCore .NET 6.0.18 Linux 5.15.112-19373-g62629859bf76 #1 SMP PREEMPT Sun Jun 11 18:47:30 PDT 2023 [2023-06-22 08:00:04Z - 082eb1d7-91aa-4f5d-be10-b15a470b4590] Filtering by token type - item count after: 0
09:00:04.288124 ...uthentication.cs:514 trace: [MSAL] [Verbose] False MSAL 4.52.0.0 MSAL.NetCore .NET 6.0.18 Linux 5.15.112-19373-g62629859bf76 #1 SMP PREEMPT Sun Jun 11 18:47:30 PDT 2023 [2023-06-22 08:00:04Z - 082eb1d7-91aa-4f5d-be10-b15a470b4590] Not filtering by scopes, because there are no candidates
09:00:04.292727 ...uthentication.cs:514 trace: [MSAL] [Verbose] False MSAL 4.52.0.0 MSAL.NetCore .NET 6.0.18 Linux 5.15.112-19373-g62629859bf76 #1 SMP PREEMPT Sun Jun 11 18:47:30 PDT 2023 [2023-06-22 08:00:04Z - 082eb1d7-91aa-4f5d-be10-b15a470b4590] Not filtering AT by environment, because there are no candidates
09:00:04.293736 ...uthentication.cs:514 trace: [MSAL] [Verbose] False MSAL 4.52.0.0 MSAL.NetCore .NET 6.0.18 Linux 5.15.112-19373-g62629859bf76 #1 SMP PREEMPT Sun Jun 11 18:47:30 PDT 2023 [2023-06-22 08:00:04Z - 082eb1d7-91aa-4f5d-be10-b15a470b4590] [FindAccessTokenAsync] No tokens found for matching authority, client_id, user and scopes.
09:00:04.315644 ...uthentication.cs:514 trace: [MSAL] [Info] False MSAL 4.52.0.0 MSAL.NetCore .NET 6.0.18 Linux 5.15.112-19373-g62629859bf76 #1 SMP PREEMPT Sun Jun 11 18:47:30 PDT 2023 [2023-06-22 08:00:04Z - 082eb1d7-91aa-4f5d-be10-b15a470b4590] [Region discovery] Not using a regional authority.
09:00:04.315937 ...uthentication.cs:514 trace: [MSAL] [Verbose] False MSAL 4.52.0.0 MSAL.NetCore .NET 6.0.18 Linux 5.15.112-19373-g62629859bf76 #1 SMP PREEMPT Sun Jun 11 18:47:30 PDT 2023 [2023-06-22 08:00:04Z - 082eb1d7-91aa-4f5d-be10-b15a470b4590] [Instance Discovery] Tried to use network cache provider for login.microsoftonline.com. Success? False.
09:00:04.316435 ...uthentication.cs:514 trace: [MSAL] [Verbose] False MSAL 4.52.0.0 MSAL.NetCore .NET 6.0.18 Linux 5.15.112-19373-g62629859bf76 #1 SMP PREEMPT Sun Jun 11 18:47:30 PDT 2023 [2023-06-22 08:00:04Z - 082eb1d7-91aa-4f5d-be10-b15a470b4590] [Instance Discovery] Tried to use known metadata provider for login.microsoftonline.com. Success? True.
09:00:04.320902 ...uthentication.cs:514 trace: [MSAL] [Verbose] False MSAL 4.52.0.0 MSAL.NetCore .NET 6.0.18 Linux 5.15.112-19373-g62629859bf76 #1 SMP PREEMPT Sun Jun 11 18:47:30 PDT 2023 [2023-06-22 08:00:04Z - 082eb1d7-91aa-4f5d-be10-b15a470b4590] [FOCI] App is part of the family or unknown, looking for FRT.
09:00:04.322370 ...uthentication.cs:514 trace: [MSAL] [Always] False MSAL 4.52.0.0 MSAL.NetCore .NET 6.0.18 Linux 5.15.112-19373-g62629859bf76 #1 SMP PREEMPT Sun Jun 11 18:47:30 PDT 2023 [2023-06-22 08:00:04Z] [Internal cache] Total number of cache partitions found while getting refresh tokens: 1
09:00:04.322689 ...uthentication.cs:514 trace: [MSAL] [Always] False MSAL 4.52.0.0 MSAL.NetCore .NET 6.0.18 Linux 5.15.112-19373-g62629859bf76 #1 SMP PREEMPT Sun Jun 11 18:47:30 PDT 2023 [2023-06-22 08:00:04Z - 082eb1d7-91aa-4f5d-be10-b15a470b4590] [FindRefreshTokenAsync] Discovered 1 refresh tokens in cache using key: 00000000-0000-0000-3ad1-9a77eea46e8a.9188040d-6c67-4c5b-b112-36a304b66dad
09:00:04.322863 ...uthentication.cs:514 trace: [MSAL] [Verbose] False MSAL 4.52.0.0 MSAL.NetCore .NET 6.0.18 Linux 5.15.112-19373-g62629859bf76 #1 SMP PREEMPT Sun Jun 11 18:47:30 PDT 2023 [2023-06-22 08:00:04Z - 082eb1d7-91aa-4f5d-be10-b15a470b4590] Filtering RT by home account id - item count before: 1
09:00:04.322916 ...uthentication.cs:514 trace: [MSAL] [Verbose] False MSAL 4.52.0.0 MSAL.NetCore .NET 6.0.18 Linux 5.15.112-19373-g62629859bf76 #1 SMP PREEMPT Sun Jun 11 18:47:30 PDT 2023 [2023-06-22 08:00:04Z - 082eb1d7-91aa-4f5d-be10-b15a470b4590] Filtering RT by home account id - item count after: 1
09:00:04.322926 ...uthentication.cs:514 trace: [MSAL] [Verbose] False MSAL 4.52.0.0 MSAL.NetCore .NET 6.0.18 Linux 5.15.112-19373-g62629859bf76 #1 SMP PREEMPT Sun Jun 11 18:47:30 PDT 2023 [2023-06-22 08:00:04Z - 082eb1d7-91aa-4f5d-be10-b15a470b4590] Filtering RT by family id - item count before: 1
09:00:04.322963 ...uthentication.cs:514 trace: [MSAL] [Verbose] False MSAL 4.52.0.0 MSAL.NetCore .NET 6.0.18 Linux 5.15.112-19373-g62629859bf76 #1 SMP PREEMPT Sun Jun 11 18:47:30 PDT 2023 [2023-06-22 08:00:04Z - 082eb1d7-91aa-4f5d-be10-b15a470b4590] Filtering RT by family id - item count after: 1
09:00:04.322993 ...uthentication.cs:514 trace: [MSAL] [Info] False MSAL 4.52.0.0 MSAL.NetCore .NET 6.0.18 Linux 5.15.112-19373-g62629859bf76 #1 SMP PREEMPT Sun Jun 11 18:47:30 PDT 2023 [2023-06-22 08:00:04Z - 082eb1d7-91aa-4f5d-be10-b15a470b4590] [Region discovery] Not using a regional authority.
09:00:04.323011 ...uthentication.cs:514 trace: [MSAL] [Verbose] False MSAL 4.52.0.0 MSAL.NetCore .NET 6.0.18 Linux 5.15.112-19373-g62629859bf76 #1 SMP PREEMPT Sun Jun 11 18:47:30 PDT 2023 [2023-06-22 08:00:04Z - 082eb1d7-91aa-4f5d-be10-b15a470b4590] [Instance Discovery] Tried to use network cache provider for login.microsoftonline.com. Success? False.
09:00:04.323035 ...uthentication.cs:514 trace: [MSAL] [Verbose] False MSAL 4.52.0.0 MSAL.NetCore .NET 6.0.18 Linux 5.15.112-19373-g62629859bf76 #1 SMP PREEMPT Sun Jun 11 18:47:30 PDT 2023 [2023-06-22 08:00:04Z - 082eb1d7-91aa-4f5d-be10-b15a470b4590] [Instance Discovery] Tried to use known metadata provider for login.microsoftonline.com. Success? True.
09:00:04.323102 ...uthentication.cs:514 trace: [MSAL] [Info] False MSAL 4.52.0.0 MSAL.NetCore .NET 6.0.18 Linux 5.15.112-19373-g62629859bf76 #1 SMP PREEMPT Sun Jun 11 18:47:30 PDT 2023 [2023-06-22 08:00:04Z - 082eb1d7-91aa-4f5d-be10-b15a470b4590] [FindRefreshTokenAsync] Refresh token found in the cache? - True
09:00:04.323173 ...uthentication.cs:514 trace: [MSAL] [Verbose] False MSAL 4.52.0.0 MSAL.NetCore .NET 6.0.18 Linux 5.15.112-19373-g62629859bf76 #1 SMP PREEMPT Sun Jun 11 18:47:30 PDT 2023 [2023-06-22 08:00:04Z - 082eb1d7-91aa-4f5d-be10-b15a470b4590] [FOCI] FRT found? True
09:00:04.323615 ...uthentication.cs:514 trace: [MSAL] [Verbose] False MSAL 4.52.0.0 MSAL.NetCore .NET 6.0.18 Linux 5.15.112-19373-g62629859bf76 #1 SMP PREEMPT Sun Jun 11 18:47:30 PDT 2023 [2023-06-22 08:00:04Z - 082eb1d7-91aa-4f5d-be10-b15a470b4590] Refreshing access token...
09:00:04.324467 ...uthentication.cs:514 trace: [MSAL] [Info] False MSAL 4.52.0.0 MSAL.NetCore .NET 6.0.18 Linux 5.15.112-19373-g62629859bf76 #1 SMP PREEMPT Sun Jun 11 18:47:30 PDT 2023 [2023-06-22 08:00:04Z - 082eb1d7-91aa-4f5d-be10-b15a470b4590] [Instance Discovery] Instance discovery is enabled and will be performed
09:00:04.324488 ...uthentication.cs:514 trace: [MSAL] [Info] False MSAL 4.52.0.0 MSAL.NetCore .NET 6.0.18 Linux 5.15.112-19373-g62629859bf76 #1 SMP PREEMPT Sun Jun 11 18:47:30 PDT 2023 [2023-06-22 08:00:04Z - 082eb1d7-91aa-4f5d-be10-b15a470b4590] [Region discovery] Not using a regional authority.
09:00:04.325223 ...uthentication.cs:514 trace: [MSAL] [Verbose] False MSAL 4.52.0.0 MSAL.NetCore .NET 6.0.18 Linux 5.15.112-19373-g62629859bf76 #1 SMP PREEMPT Sun Jun 11 18:47:30 PDT 2023 [2023-06-22 08:00:04Z - 082eb1d7-91aa-4f5d-be10-b15a470b4590] [Instance Discovery] Tried to use network cache provider for login.microsoftonline.com. Success? False.
09:00:04.326100 ...uthentication.cs:514 trace: [MSAL] [Info] False MSAL 4.52.0.0 MSAL.NetCore .NET 6.0.18 Linux 5.15.112-19373-g62629859bf76 #1 SMP PREEMPT Sun Jun 11 18:47:30 PDT 2023 [2023-06-22 08:00:04Z - 082eb1d7-91aa-4f5d-be10-b15a470b4590] Fetching instance discovery from the network from host login.microsoftonline.com.
09:00:04.328481 ...uthentication.cs:514 trace: [MSAL] [Verbose] False MSAL 4.52.0.0 MSAL.NetCore .NET 6.0.18 Linux 5.15.112-19373-g62629859bf76 #1 SMP PREEMPT Sun Jun 11 18:47:30 PDT 2023 [2023-06-22 08:00:04Z - 082eb1d7-91aa-4f5d-be10-b15a470b4590] Starting [Oauth2Client] Sending GET request
09:00:04.329542 ...uthentication.cs:514 trace: [MSAL] [Verbose] False MSAL 4.52.0.0 MSAL.NetCore .NET 6.0.18 Linux 5.15.112-19373-g62629859bf76 #1 SMP PREEMPT Sun Jun 11 18:47:30 PDT 2023 [2023-06-22 08:00:04Z - 082eb1d7-91aa-4f5d-be10-b15a470b4590] Starting [HttpManager] ExecuteAsync
09:00:04.334500 ...uthentication.cs:514 trace: [MSAL] [Verbose] False MSAL 4.52.0.0 MSAL.NetCore .NET 6.0.18 Linux 5.15.112-19373-g62629859bf76 #1 SMP PREEMPT Sun Jun 11 18:47:30 PDT 2023 [2023-06-22 08:00:04Z - 082eb1d7-91aa-4f5d-be10-b15a470b4590] [HttpManager] Sending request. Method: GET. Host: https://login.microsoftonline.com.
09:00:04.335675 ...pClientFactory.cs:60 trace: [CreateClient] Creating new HTTP client instance...
09:00:04.352025 ...pClientFactory.cs:80 trace: [CreateClient] Git's SSL/TLS backend is: OpenSsl
09:00:04.674203 ...uthentication.cs:514 trace: [MSAL] [Verbose] False MSAL 4.52.0.0 MSAL.NetCore .NET 6.0.18 Linux 5.15.112-19373-g62629859bf76 #1 SMP PREEMPT Sun Jun 11 18:47:30 PDT 2023 [2023-06-22 08:00:04Z - 082eb1d7-91aa-4f5d-be10-b15a470b4590] [HttpManager] Received response. Status code: OK.
09:00:04.675196 ...uthentication.cs:514 trace: [MSAL] [Verbose] False MSAL 4.52.0.0 MSAL.NetCore .NET 6.0.18 Linux 5.15.112-19373-g62629859bf76 #1 SMP PREEMPT Sun Jun 11 18:47:30 PDT 2023 [2023-06-22 08:00:04Z - 082eb1d7-91aa-4f5d-be10-b15a470b4590] Finished [HttpManager] ExecuteAsync in 345 ms
09:00:04.675544 ...uthentication.cs:514 trace: [MSAL] [Verbose] False MSAL 4.52.0.0 MSAL.NetCore .NET 6.0.18 Linux 5.15.112-19373-g62629859bf76 #1 SMP PREEMPT Sun Jun 11 18:47:30 PDT 2023 [2023-06-22 08:00:04Z - 082eb1d7-91aa-4f5d-be10-b15a470b4590] Finished [Oauth2Client] Sending GET request in 347 ms
09:00:04.676587 ...uthentication.cs:514 trace: [MSAL] [Verbose] False MSAL 4.52.0.0 MSAL.NetCore .NET 6.0.18 Linux 5.15.112-19373-g62629859bf76 #1 SMP PREEMPT Sun Jun 11 18:47:30 PDT 2023 [2023-06-22 08:00:04Z - 082eb1d7-91aa-4f5d-be10-b15a470b4590] Starting [OAuth2Client] Deserializing response
09:00:04.698776 ...uthentication.cs:514 trace: [MSAL] [Verbose] False MSAL 4.52.0.0 MSAL.NetCore .NET 6.0.18 Linux 5.15.112-19373-g62629859bf76 #1 SMP PREEMPT Sun Jun 11 18:47:30 PDT 2023 [2023-06-22 08:00:04Z - 082eb1d7-91aa-4f5d-be10-b15a470b4590] Finished [OAuth2Client] Deserializing response in 22 ms
09:00:04.699810 ...uthentication.cs:514 trace: [MSAL] [Verbose] False MSAL 4.52.0.0 MSAL.NetCore .NET 6.0.18 Linux 5.15.112-19373-g62629859bf76 #1 SMP PREEMPT Sun Jun 11 18:47:30 PDT 2023 [2023-06-22 08:00:04Z - 082eb1d7-91aa-4f5d-be10-b15a470b4590] [Instance Discovery] Tried to use network cache provider for login.microsoftonline.com. Success? True.
09:00:04.699871 ...uthentication.cs:514 trace: [MSAL] [Verbose] False MSAL 4.52.0.0 MSAL.NetCore .NET 6.0.18 Linux 5.15.112-19373-g62629859bf76 #1 SMP PREEMPT Sun Jun 11 18:47:30 PDT 2023 [2023-06-22 08:00:04Z - 082eb1d7-91aa-4f5d-be10-b15a470b4590] [Instance Discovery] After hitting the discovery endpoint, the network provider found an entry for login.microsoftonline.com ? True.
09:00:04.714578 ...uthentication.cs:514 trace: [MSAL] [Info] False MSAL 4.52.0.0 MSAL.NetCore .NET 6.0.18 Linux 5.15.112-19373-g62629859bf76 #1 SMP PREEMPT Sun Jun 11 18:47:30 PDT 2023 [2023-06-22 08:00:04Z - 082eb1d7-91aa-4f5d-be10-b15a470b4590] Authority validation enabled? True.
09:00:04.715097 ...uthentication.cs:514 trace: [MSAL] [Info] False MSAL 4.52.0.0 MSAL.NetCore .NET 6.0.18 Linux 5.15.112-19373-g62629859bf76 #1 SMP PREEMPT Sun Jun 11 18:47:30 PDT 2023 [2023-06-22 08:00:04Z - 082eb1d7-91aa-4f5d-be10-b15a470b4590] Authority validation - is known env? True.
09:00:04.718557 ...uthentication.cs:514 trace: [MSAL] [Verbose] False MSAL 4.52.0.0 MSAL.NetCore .NET 6.0.18 Linux 5.15.112-19373-g62629859bf76 #1 SMP PREEMPT Sun Jun 11 18:47:30 PDT 2023 [2023-06-22 08:00:04Z - 082eb1d7-91aa-4f5d-be10-b15a470b4590] Starting TokenClient:SendTokenRequestAsync
09:00:04.724273 ...uthentication.cs:514 trace: [MSAL] [Verbose] False MSAL 4.52.0.0 MSAL.NetCore .NET 6.0.18 Linux 5.15.112-19373-g62629859bf76 #1 SMP PREEMPT Sun Jun 11 18:47:30 PDT 2023 [2023-06-22 08:00:04Z - 082eb1d7-91aa-4f5d-be10-b15a470b4590] [Token Client] Fetching MsalTokenResponse ....
09:00:04.724606 ...uthentication.cs:514 trace: [MSAL] [Verbose] False MSAL 4.52.0.0 MSAL.NetCore .NET 6.0.18 Linux 5.15.112-19373-g62629859bf76 #1 SMP PREEMPT Sun Jun 11 18:47:30 PDT 2023 [2023-06-22 08:00:04Z - 082eb1d7-91aa-4f5d-be10-b15a470b4590] Starting [Oauth2Client] Sending POST request
09:00:04.729788 ...uthentication.cs:514 trace: [MSAL] [Verbose] False MSAL 4.52.0.0 MSAL.NetCore .NET 6.0.18 Linux 5.15.112-19373-g62629859bf76 #1 SMP PREEMPT Sun Jun 11 18:47:30 PDT 2023 [2023-06-22 08:00:04Z - 082eb1d7-91aa-4f5d-be10-b15a470b4590] Starting [HttpManager] ExecuteAsync
09:00:04.730198 ...uthentication.cs:514 trace: [MSAL] [Verbose] False MSAL 4.52.0.0 MSAL.NetCore .NET 6.0.18 Linux 5.15.112-19373-g62629859bf76 #1 SMP PREEMPT Sun Jun 11 18:47:30 PDT 2023 [2023-06-22 08:00:04Z - 082eb1d7-91aa-4f5d-be10-b15a470b4590] [HttpManager] Sending request. Method: POST. Host: https://login.microsoftonline.com.
09:00:04.854058 ...uthentication.cs:514 trace: [MSAL] [Verbose] False MSAL 4.52.0.0 MSAL.NetCore .NET 6.0.18 Linux 5.15.112-19373-g62629859bf76 #1 SMP PREEMPT Sun Jun 11 18:47:30 PDT 2023 [2023-06-22 08:00:04Z - 082eb1d7-91aa-4f5d-be10-b15a470b4590] [HttpManager] Received response. Status code: BadRequest.
09:00:04.854290 ...uthentication.cs:514 trace: [MSAL] [Verbose] False MSAL 4.52.0.0 MSAL.NetCore .NET 6.0.18 Linux 5.15.112-19373-g62629859bf76 #1 SMP PREEMPT Sun Jun 11 18:47:30 PDT 2023 [2023-06-22 08:00:04Z - 082eb1d7-91aa-4f5d-be10-b15a470b4590] Finished [HttpManager] ExecuteAsync in 124 ms
09:00:04.854666 ...uthentication.cs:514 trace: [MSAL] [Info] False MSAL 4.52.0.0 MSAL.NetCore .NET 6.0.18 Linux 5.15.112-19373-g62629859bf76 #1 SMP PREEMPT Sun Jun 11 18:47:30 PDT 2023 [2023-06-22 08:00:04Z - 082eb1d7-91aa-4f5d-be10-b15a470b4590] Response status code does not indicate success: 400 (BadRequest).
09:00:04.854912 ...uthentication.cs:514 trace: [MSAL] [Warning] False MSAL 4.52.0.0 MSAL.NetCore .NET 6.0.18 Linux 5.15.112-19373-g62629859bf76 #1 SMP PREEMPT Sun Jun 11 18:47:30 PDT 2023 [2023-06-22 08:00:04Z - 082eb1d7-91aa-4f5d-be10-b15a470b4590] Request retry failed.
09:00:04.856722 ...uthentication.cs:514 trace: [MSAL] [Verbose] False MSAL 4.52.0.0 MSAL.NetCore .NET 6.0.18 Linux 5.15.112-19373-g62629859bf76 #1 SMP PREEMPT Sun Jun 11 18:47:30 PDT 2023 [2023-06-22 08:00:04Z - 082eb1d7-91aa-4f5d-be10-b15a470b4590] Finished [Oauth2Client] Sending POST request in 132 ms
09:00:04.857037 ...uthentication.cs:514 trace: [MSAL] [Verbose] False MSAL 4.52.0.0 MSAL.NetCore .NET 6.0.18 Linux 5.15.112-19373-g62629859bf76 #1 SMP PREEMPT Sun Jun 11 18:47:30 PDT 2023 [2023-06-22 08:00:04Z - 082eb1d7-91aa-4f5d-be10-b15a470b4590] [Oauth2Client] Processing error response
09:00:04.875587 ...uthentication.cs:514 trace: [MSAL] [Info] False MSAL 4.52.0.0 MSAL.NetCore .NET 6.0.18 Linux 5.15.112-19373-g62629859bf76 #1 SMP PREEMPT Sun Jun 11 18:47:30 PDT 2023 [2023-06-22 08:00:04Z - 082eb1d7-91aa-4f5d-be10-b15a470b4590] HttpStatusCode: 400: BadRequest
09:00:04.877526 ...uthentication.cs:514 trace: [MSAL] [Error] False MSAL 4.52.0.0 MSAL.NetCore .NET 6.0.18 Linux 5.15.112-19373-g62629859bf76 #1 SMP PREEMPT Sun Jun 11 18:47:30 PDT 2023 [2023-06-22 08:00:04Z - 082eb1d7-91aa-4f5d-be10-b15a470b4590] === Token Acquisition (1007) failed.
Host: login.microsoftonline.com.
09:00:04.878181 ...uthentication.cs:514 trace: [MSAL] [Error] False MSAL 4.52.0.0 MSAL.NetCore .NET 6.0.18 Linux 5.15.112-19373-g62629859bf76 #1 SMP PREEMPT Sun Jun 11 18:47:30 PDT 2023 [2023-06-22 08:00:04Z - 082eb1d7-91aa-4f5d-be10-b15a470b4590] Exception type: Microsoft.Identity.Client.MsalServiceException
, ErrorCode: invalid_request
HTTP StatusCode 400
CorrelationId 082eb1d7-91aa-4f5d-be10-b15a470b4590

09:00:04.880166 ...uthentication.cs:514 trace: [MSAL] [Verbose] False MSAL 4.52.0.0 MSAL.NetCore .NET 6.0.18 Linux 5.15.112-19373-g62629859bf76 #1 SMP PREEMPT Sun Jun 11 18:47:30 PDT 2023 [2023-06-22 08:00:04Z - 082eb1d7-91aa-4f5d-be10-b15a470b4590] Finished TokenClient:SendTokenRequestAsync in 161 ms
09:00:04.880735 ...uthentication.cs:514 trace: [MSAL] [Error] False MSAL 4.52.0.0 MSAL.NetCore .NET 6.0.18 Linux 5.15.112-19373-g62629859bf76 #1 SMP PREEMPT Sun Jun 11 18:47:30 PDT 2023 [2023-06-22 08:00:04Z - 082eb1d7-91aa-4f5d-be10-b15a470b4590] [FOCI] FRT refresh failed - other error.
09:00:04.881221 ...uthentication.cs:514 trace: [MSAL] [Warning] False MSAL 4.52.0.0 MSAL.NetCore .NET 6.0.18 Linux 5.15.112-19373-g62629859bf76 #1 SMP PREEMPT Sun Jun 11 18:47:30 PDT 2023 [2023-06-22 08:00:04Z - 082eb1d7-91aa-4f5d-be10-b15a470b4590] Refreshing the RT failed. Is the exception retryable? False. Is there an AT in the cache that is usable? False
09:00:04.881235 ...uthentication.cs:514 trace: [MSAL] [Warning] False MSAL 4.52.0.0 MSAL.NetCore .NET 6.0.18 Linux 5.15.112-19373-g62629859bf76 #1 SMP PREEMPT Sun Jun 11 18:47:30 PDT 2023 [2023-06-22 08:00:04Z - 082eb1d7-91aa-4f5d-be10-b15a470b4590] Failed to refresh the RT and cannot use existing AT (expired or missing).
09:00:04.881478 ...uthentication.cs:514 trace: [MSAL] [Verbose] False MSAL 4.52.0.0 MSAL.NetCore .NET 6.0.18 Linux 5.15.112-19373-g62629859bf76 #1 SMP PREEMPT Sun Jun 11 18:47:30 PDT 2023 [2023-06-22 08:00:04Z - 082eb1d7-91aa-4f5d-be10-b15a470b4590] Token cache could not satisfy silent request.
09:00:04.890886 ...uthentication.cs:514 trace: [MSAL] [Error] False MSAL 4.52.0.0 MSAL.NetCore .NET 6.0.18 Linux 5.15.112-19373-g62629859bf76 #1 SMP PREEMPT Sun Jun 11 18:47:30 PDT 2023 [2023-06-22 08:00:04Z - 082eb1d7-91aa-4f5d-be10-b15a470b4590] Exception type: Microsoft.Identity.Client.MsalServiceException
, ErrorCode: invalid_request
HTTP StatusCode 400
CorrelationId 082eb1d7-91aa-4f5d-be10-b15a470b4590

at Microsoft.Identity.Client.Internal.Requests.Silent.SilentRequest.ExecuteAsync(CancellationToken cancellationToken)
at Microsoft.Identity.Client.Internal.Requests.RequestBase.RunAsync(CancellationToken cancellationToken)
fatal: AADSTS9002332: Application '872cd9fa-d31f-45e0-9eab-6e460a02d1f1'(Visual Studio - Legacy) is configured for use by Azure Active Directory users only. Please do not use the /consumers endpoint to serve this request.
Trace ID: 66fa9f0e-e906-4243-a774-da49e3dd3e00
Correlation ID: 082eb1d7-91aa-4f5d-be10-b15a470b4590
Timestamp: 2023-06-22 08:00:05Z
at Microsoft.Identity.Client.Internal.Requests.Silent.SilentRequest.ExecuteAsync(CancellationToken cancellationToken)
at Microsoft.Identity.Client.Internal.Requests.RequestBase.RunAsync(CancellationToken cancellationToken)
at Microsoft.Identity.Client.ApiConfig.Executors.ClientApplicationBaseExecutor.ExecuteAsync(AcquireTokenCommonParameters commonParameters, AcquireTokenSilentParameters silentParameters, CancellationToken cancellationToken)
at GitCredentialManager.Authentication.MicrosoftAuthentication.GetAccessTokenSilentlyAsync(IPublicClientApplication app, String[] scopes, String userName)
at GitCredentialManager.Authentication.MicrosoftAuthentication.GetTokenAsync(String authority, String clientId, Uri redirectUri, String[] scopes, String userName)
at Microsoft.AzureRepos.AzureReposHostProvider.GetAzureAccessTokenAsync(Uri remoteUri, String userName)
at Microsoft.AzureRepos.AzureReposHostProvider.GetCredentialAsync(InputArguments input)
at GitCredentialManager.Commands.GetCommand.ExecuteInternalAsync(InputArguments input, IHostProvider provider)
at GitCredentialManager.Commands.GitCommandBase.ExecuteAsync()
at System.CommandLine.Invocation.CommandHandler.GetExitCodeAsync(Object value, InvocationContext context)
at System.CommandLine.Invocation.ModelBindingCommandHandler.InvokeAsync(InvocationContext context)
at System.CommandLine.Invocation.InvocationPipeline.<>c__DisplayClass4_0.<b__0>d.MoveNext()
--- End of stack trace from previous location ---
at System.CommandLine.Builder.CommandLineBuilderExtensions.<>c__DisplayClass23_0.<b__0>d.MoveNext()
--- End of stack trace from previous location ---
at System.CommandLine.Builder.CommandLineBuilderExtensions.<>c__DisplayClass16_0.<b__0>d.MoveNext()
--- End of stack trace from previous location ---
at System.CommandLine.Builder.CommandLineBuilderExtensions.<>c__DisplayClass27_0.<b__1>d.MoveNext()
--- End of stack trace from previous location ---
at System.CommandLine.Builder.CommandLineBuilderExtensions.<>c__DisplayClass25_0.<b__0>d.MoveNext()
--- End of stack trace from previous location ---
at System.CommandLine.Builder.CommandLineBuilderExtensions.<>c.<b__24_0>d.MoveNext()
--- End of stack trace from previous location ---
at System.CommandLine.Builder.CommandLineBuilderExtensions.<>c__DisplayClass22_0.<b__0>d.MoveNext()
--- End of stack trace from previous location ---
at System.CommandLine.Builder.CommandLineBuilderExtensions.<>c__DisplayClass11_0.<b__0>d.MoveNext()
--- End of stack trace from previous location ---
at System.CommandLine.Builder.CommandLineBuilderExtensions.<>c.<b__10_0>d.MoveNext()
--- End of stack trace from previous location ---
at System.CommandLine.Builder.CommandLineBuilderExtensions.<>c__DisplayClass14_0.<b__0>d.MoveNext()

@mjcheetham
Copy link
Collaborator

@mjcheetham @bgavrilMS To check my understanding, there appear to be two OAuth authorization servers you can use to authenticate Azure DevOps . Which does GCM uses?

  1. app.vssps.visualstudio.com https://learn.microsoft.com/en-us/azure/devops/integrate/get-started/authentication/oauth?view=azure-devops , apps registered at https://app.vsaex.visualstudio.com/app/register
  2. AAD https://learn.microsoft.com/en-us/azure/active-directory/develop/quickstart-register-app , apps registered in Azure Portal . This is the API called by the library MSAL.

GCM always uses MSAL + AAD to generate access tokens for Azure DevOps.

In oauth mode we directly use the access token in the Git Authorization header, whereas in pat mode (the default) we use that AAD AT to create an Azure DevOps PAT instead.

@mjcheetham
Copy link
Collaborator

Thanks for the logs @hickford! It looks like there's something strange going on inside of the MSAL account filtering with MSAs:


[GetAccessTokenSilentlyAsync] Attempting to acquire token silently for user 'matt.hickford@gmail.com'...
...
[MSAL] ... Total number of cache partitions found while getting refresh tokens: 1
[MSAL] ... [GetAccounts] Found 1 RTs and 1 accounts in MSAL cache.
...
[MSAL] ... [GetAccounts] Found 1 RTs and 1 accounts in MSAL cache after environment filtering.
...
[MSAL] ... [Internal cache] Total number of cache partitions found while getting access tokens: 1
[MSAL] ... [FindAccessTokenAsync] Discovered 1 access tokens in cache using partition key: 00000000-0000-0000-3ad1-9a77eea46e8a.9188040d-6c67-4c5b-b112-36a304b66dad
[MSAL] ... Filtering AT by tenant id - item count before: 1
[MSAL] ... Filtering AT by tenant id - item count after: 0
[MSAL] ... Filtering AT by home account id - item count before: 0
[MSAL] ... Filtering AT by home account id - item count after: 0
[MSAL] ... Filtering by token type - item count before: 0
[MSAL] ... Filtering by token type - item count after: 0
[MSAL] ... Not filtering by scopes, because there are no candidates
[MSAL] ... Not filtering AT by environment, because there are no candidates

@hickford
Copy link
Contributor Author

hickford commented Jun 22, 2023

In oauth mode we directly use the access token in the Git Authorization header, whereas in pat mode (the default) we use that AAD AT to create an Azure DevOps PAT instead.

@mjcheetham Thanks for the explanation. Why is the PAT preferred to access token? The scope is more limited?

@hickford
Copy link
Contributor Author

For completeness, here's the log from echo protocol=https\nhost=dev.azure.com\npath=matthickford0459/testdevazuredotcom/_git/testdevazuredotcom\nusername=matthickford0459\nwwwauth[]=Basic realm=\"https://tfsproduks1.visualstudio.com/\" | git -c credential.azreposCredentialType=pat credential-manager get with PAT

21:33:26.733288 ...re/Application.cs:95 trace: [RunInternalAsync] Version: 2.1.2.0
21:33:26.739127 ...re/Application.cs:96 trace: [RunInternalAsync] Runtime: .NET 6.0.18
21:33:26.739148 ...re/Application.cs:97 trace: [RunInternalAsync] Platform: Linux (x86-64)
21:33:26.739151 ...re/Application.cs:98 trace: [RunInternalAsync] OSVersion: Linux penguin 5.15.112-19373-g62629859bf76 #1 SMP PREEMPT Sun Jun 11 18:47:30 PDT 2023 x86_64 GNU/Linux
21:33:26.739158 ...re/Application.cs:99 trace: [RunInternalAsync] AppPath: /home/matthickford/.dotnet/tools/git-credential-manager
21:33:26.739195 ...e/Application.cs:100 trace: [RunInternalAsync] InstallDir: /home/matthickford/.dotnet/tools/.store/git-credential-manager/2.1.2/git-credential-manager/2.1.2/tools/net6.0/any/
21:33:26.739213 ...e/Application.cs:101 trace: [RunInternalAsync] Arguments: get
21:33:26.774166 ...GitCommandBase.cs:33 trace: [ExecuteAsync] Start 'get' command...
21:33:26.783980 ...GitCommandBase.cs:47 trace: [ExecuteAsync] Detecting host provider for input:
21:33:26.786022 ...GitCommandBase.cs:48 trace: [ExecuteAsync] 	protocol=https
21:33:26.786068 ...GitCommandBase.cs:48 trace: [ExecuteAsync] 	host=dev.azure.com
21:33:26.786071 ...GitCommandBase.cs:48 trace: [ExecuteAsync] 	path=matthickford0459/testdevazuredotcom/_git/testdevazuredotcom
21:33:26.786082 ...GitCommandBase.cs:48 trace: [ExecuteAsync] 	username=matthickford0459
21:33:26.786085 ...GitCommandBase.cs:48 trace: [ExecuteAsync] 	wwwauth[]=Basic realm="https://tfsproduks1.visualstudio.com/"
21:33:26.788999 ...viderRegistry.cs:149 trace: [GetProviderAsync] Performing auto-detection of host provider.
21:33:26.789155 ...viderRegistry.cs:162 trace: [GetProviderAsync] Auto-detect probe timeout is 2 ms.
21:33:26.790312 ...viderRegistry.cs:170 trace: [GetProviderAsync] Checking against 4 host providers registered with priority 'Normal'.
21:33:26.790638 ...GitCommandBase.cs:50 trace: [ExecuteAsync] Host provider 'Azure Repos' was selected.
21:33:26.791620 ...sHostProvider.cs:403 trace: [UsePersonalAccessTokens] Azure Repos credential type override set to 'pat'
21:33:26.791998 ...osHostProvider.cs:85 trace: [GetCredentialAsync] Looking for existing credential in store with service=https://dev.azure.com/matthickford0459 account=...
21:33:26.801784 ...osHostProvider.cs:90 trace: [GetCredentialAsync] No existing credentials found.
21:33:26.801837 ...osHostProvider.cs:93 trace: [GetCredentialAsync] Creating new credential...
21:33:26.803119 ...sHostProvider.cs:195 trace: [GeneratePersonalAccessTokenAsync] Determining Microsoft Authentication Authority...
21:33:26.809017 ...eDevOpsRestApi.cs:43 trace: [GetAuthorityAsync] HTTP: HEAD https://dev.azure.com/matthickford0459
21:33:26.810200 ...pClientFactory.cs:60 trace: [CreateClient] Creating new HTTP client instance...
21:33:26.812809 ...pClientFactory.cs:80 trace: [CreateClient] Git's SSL/TLS backend is: OpenSsl
21:33:27.103664 ...eDevOpsRestApi.cs:46 trace: [GetAuthorityAsync] HTTP: Response code ignored.
21:33:27.103699 ...eDevOpsRestApi.cs:47 trace: [GetAuthorityAsync] Inspecting headers...
21:33:27.104202 ...eDevOpsRestApi.cs:79 trace: [GetAuthorityAsync] Found X-VSS-ResourceTenant header with MSA tenant ID (empty GUID).
21:33:27.104447 ...sHostProvider.cs:197 trace: [GeneratePersonalAccessTokenAsync] Authority is 'https://login.microsoftonline.com/organizations'.
21:33:27.104458 ...sHostProvider.cs:200 trace: [GeneratePersonalAccessTokenAsync] Getting Azure AD access token...
21:33:27.106159 ...Authentication.cs:66 trace: [GetTokenAsync] OS broker is not available or enabled.
21:33:27.113246 ...uthentication.cs:393 trace: [RegisterTokenCacheAsync] Configuring Microsoft Authentication token cache to instance shared with Microsoft developer tools...
21:33:27.199843 ...uthentication.cs:449 trace: [RegisterTokenCacheAsync] Microsoft developer tools token cache configured.
21:33:27.207064 ...uthentication.cs:164 trace: [GetTokenAsync] Performing interactive auth with system web view...
21:33:27.213245 ...uthentication.cs:514 trace: [MSAL] [Info] False MSAL 4.52.0.0 MSAL.NetCore .NET 6.0.18 Linux 5.15.112-19373-g62629859bf76 #1 SMP PREEMPT Sun Jun 11 18:47:30 PDT 2023 [2023-06-22 20:33:27Z - 78a3eef5-95fd-43ca-80e8-fd821395a2b5] MSAL MSAL.NetCore with assembly version '4.52.0.0'. CorrelationId(78a3eef5-95fd-43ca-80e8-fd821395a2b5)
21:33:27.216968 ...uthentication.cs:514 trace: [MSAL] [Info] False MSAL 4.52.0.0 MSAL.NetCore .NET 6.0.18 Linux 5.15.112-19373-g62629859bf76 #1 SMP PREEMPT Sun Jun 11 18:47:30 PDT 2023 [2023-06-22 20:33:27Z - 78a3eef5-95fd-43ca-80e8-fd821395a2b5] DefaultBrowserOptions configured
21:33:27.217047 ...uthentication.cs:514 trace: [MSAL] [Info] False MSAL 4.52.0.0 MSAL.NetCore .NET 6.0.18 Linux 5.15.112-19373-g62629859bf76 #1 SMP PREEMPT Sun Jun 11 18:47:30 PDT 2023 [2023-06-22 20:33:27Z - 78a3eef5-95fd-43ca-80e8-fd821395a2b5] HtmlMessageSuccess? False
21:33:27.217079 ...uthentication.cs:514 trace: [MSAL] [Info] False MSAL 4.52.0.0 MSAL.NetCore .NET 6.0.18 Linux 5.15.112-19373-g62629859bf76 #1 SMP PREEMPT Sun Jun 11 18:47:30 PDT 2023 [2023-06-22 20:33:27Z - 78a3eef5-95fd-43ca-80e8-fd821395a2b5] HtmlMessageError? False
21:33:27.217154 ...uthentication.cs:514 trace: [MSAL] [Info] False MSAL 4.52.0.0 MSAL.NetCore .NET 6.0.18 Linux 5.15.112-19373-g62629859bf76 #1 SMP PREEMPT Sun Jun 11 18:47:30 PDT 2023 [2023-06-22 20:33:27Z - 78a3eef5-95fd-43ca-80e8-fd821395a2b5] BrowserRedirectSuccess? False
21:33:27.217193 ...uthentication.cs:514 trace: [MSAL] [Info] False MSAL 4.52.0.0 MSAL.NetCore .NET 6.0.18 Linux 5.15.112-19373-g62629859bf76 #1 SMP PREEMPT Sun Jun 11 18:47:30 PDT 2023 [2023-06-22 20:33:27Z - 78a3eef5-95fd-43ca-80e8-fd821395a2b5] BrowserRedirectError? False
21:33:27.217236 ...uthentication.cs:514 trace: [MSAL] [Info] False MSAL 4.52.0.0 MSAL.NetCore .NET 6.0.18 Linux 5.15.112-19373-g62629859bf76 #1 SMP PREEMPT Sun Jun 11 18:47:30 PDT 2023 [2023-06-22 20:33:27Z - 78a3eef5-95fd-43ca-80e8-fd821395a2b5] HidePrivacyPrompt False
21:33:27.217244 ...uthentication.cs:514 trace: [MSAL] [Info] False MSAL 4.52.0.0 MSAL.NetCore .NET 6.0.18 Linux 5.15.112-19373-g62629859bf76 #1 SMP PREEMPT Sun Jun 11 18:47:30 PDT 2023 [2023-06-22 20:33:27Z - 78a3eef5-95fd-43ca-80e8-fd821395a2b5] === InteractiveParameters Data ===
LoginHint provided: False
User provided: False
UseEmbeddedWebView: System
ExtraScopesToConsent: 
Prompt: select_account
HasCustomWebUi: False

21:33:27.219010 ...uthentication.cs:514 trace: [MSAL] [Info] False MSAL 4.52.0.0 MSAL.NetCore .NET 6.0.18 Linux 5.15.112-19373-g62629859bf76 #1 SMP PREEMPT Sun Jun 11 18:47:30 PDT 2023 [2023-06-22 20:33:27Z - 78a3eef5-95fd-43ca-80e8-fd821395a2b5]
=== Request Data ===
Authority Provided? - True
Scopes - 499b84ac-1321-427f-aa17-267ca6975798/.default
Extra Query Params Keys (space separated) -
ApiId - AcquireTokenInteractive
IsConfidentialClient - False
SendX5C - False
LoginHint ? False
IsBrokerConfigured - False
HomeAccountId - False
CorrelationId - 78a3eef5-95fd-43ca-80e8-fd821395a2b5
UserAssertion set: False
LongRunningOboCacheKey set: False
Region configured:

21:33:27.219217 ...uthentication.cs:514 trace: [MSAL] [Info] False MSAL 4.52.0.0 MSAL.NetCore .NET 6.0.18 Linux 5.15.112-19373-g62629859bf76 #1 SMP PREEMPT Sun Jun 11 18:47:30 PDT 2023 [2023-06-22 20:33:27Z - 78a3eef5-95fd-43ca-80e8-fd821395a2b5] === Token Acquisition (InteractiveRequest) started:
Scopes: 499b84ac-1321-427f-aa17-267ca6975798/.default
Authority Host: login.microsoftonline.com
21:33:27.220536 ...uthentication.cs:514 trace: [MSAL] [Info] False MSAL 4.52.0.0 MSAL.NetCore .NET 6.0.18 Linux 5.15.112-19373-g62629859bf76 #1 SMP PREEMPT Sun Jun 11 18:47:30 PDT 2023 [2023-06-22 20:33:27Z - 78a3eef5-95fd-43ca-80e8-fd821395a2b5] [Instance Discovery] Instance discovery is enabled and will be performed
21:33:27.220919 ...uthentication.cs:514 trace: [MSAL] [Info] False MSAL 4.52.0.0 MSAL.NetCore .NET 6.0.18 Linux 5.15.112-19373-g62629859bf76 #1 SMP PREEMPT Sun Jun 11 18:47:30 PDT 2023 [2023-06-22 20:33:27Z - 78a3eef5-95fd-43ca-80e8-fd821395a2b5] [Region discovery] Not using a regional authority.
21:33:27.221879 ...uthentication.cs:514 trace: [MSAL] [Verbose] False MSAL 4.52.0.0 MSAL.NetCore .NET 6.0.18 Linux 5.15.112-19373-g62629859bf76 #1 SMP PREEMPT Sun Jun 11 18:47:30 PDT 2023 [2023-06-22 20:33:27Z - 78a3eef5-95fd-43ca-80e8-fd821395a2b5] [Instance Discovery] Tried to use network cache provider for login.microsoftonline.com. Success? False.
21:33:27.222752 ...uthentication.cs:514 trace: [MSAL] [Info] False MSAL 4.52.0.0 MSAL.NetCore .NET 6.0.18 Linux 5.15.112-19373-g62629859bf76 #1 SMP PREEMPT Sun Jun 11 18:47:30 PDT 2023 [2023-06-22 20:33:27Z - 78a3eef5-95fd-43ca-80e8-fd821395a2b5] Fetching instance discovery from the network from host login.microsoftonline.com.
21:33:27.225051 ...uthentication.cs:514 trace: [MSAL] [Verbose] False MSAL 4.52.0.0 MSAL.NetCore .NET 6.0.18 Linux 5.15.112-19373-g62629859bf76 #1 SMP PREEMPT Sun Jun 11 18:47:30 PDT 2023 [2023-06-22 20:33:27Z - 78a3eef5-95fd-43ca-80e8-fd821395a2b5] Starting [Oauth2Client] Sending GET request
21:33:27.226074 ...uthentication.cs:514 trace: [MSAL] [Verbose] False MSAL 4.52.0.0 MSAL.NetCore .NET 6.0.18 Linux 5.15.112-19373-g62629859bf76 #1 SMP PREEMPT Sun Jun 11 18:47:30 PDT 2023 [2023-06-22 20:33:27Z - 78a3eef5-95fd-43ca-80e8-fd821395a2b5] Starting [HttpManager] ExecuteAsync
21:33:27.227493 ...uthentication.cs:514 trace: [MSAL] [Verbose] False MSAL 4.52.0.0 MSAL.NetCore .NET 6.0.18 Linux 5.15.112-19373-g62629859bf76 #1 SMP PREEMPT Sun Jun 11 18:47:30 PDT 2023 [2023-06-22 20:33:27Z - 78a3eef5-95fd-43ca-80e8-fd821395a2b5] [HttpManager] Sending request. Method: GET. Host: https://login.microsoftonline.com.
21:33:27.227556 ...pClientFactory.cs:60 trace: [CreateClient] Creating new HTTP client instance...
21:33:27.227613 ...pClientFactory.cs:80 trace: [CreateClient] Git's SSL/TLS backend is: OpenSsl
21:33:27.395144 ...uthentication.cs:514 trace: [MSAL] [Verbose] False MSAL 4.52.0.0 MSAL.NetCore .NET 6.0.18 Linux 5.15.112-19373-g62629859bf76 #1 SMP PREEMPT Sun Jun 11 18:47:30 PDT 2023 [2023-06-22 20:33:27Z - 78a3eef5-95fd-43ca-80e8-fd821395a2b5] [HttpManager] Received response. Status code: OK.
21:33:27.396978 ...uthentication.cs:514 trace: [MSAL] [Verbose] False MSAL 4.52.0.0 MSAL.NetCore .NET 6.0.18 Linux 5.15.112-19373-g62629859bf76 #1 SMP PREEMPT Sun Jun 11 18:47:30 PDT 2023 [2023-06-22 20:33:27Z - 78a3eef5-95fd-43ca-80e8-fd821395a2b5] Finished [HttpManager] ExecuteAsync in 170 ms
21:33:27.397770 ...uthentication.cs:514 trace: [MSAL] [Verbose] False MSAL 4.52.0.0 MSAL.NetCore .NET 6.0.18 Linux 5.15.112-19373-g62629859bf76 #1 SMP PREEMPT Sun Jun 11 18:47:30 PDT 2023 [2023-06-22 20:33:27Z - 78a3eef5-95fd-43ca-80e8-fd821395a2b5] Finished [Oauth2Client] Sending GET request in 172 ms
21:33:27.399357 ...uthentication.cs:514 trace: [MSAL] [Verbose] False MSAL 4.52.0.0 MSAL.NetCore .NET 6.0.18 Linux 5.15.112-19373-g62629859bf76 #1 SMP PREEMPT Sun Jun 11 18:47:30 PDT 2023 [2023-06-22 20:33:27Z - 78a3eef5-95fd-43ca-80e8-fd821395a2b5] Starting [OAuth2Client] Deserializing response
21:33:27.411771 ...uthentication.cs:514 trace: [MSAL] [Verbose] False MSAL 4.52.0.0 MSAL.NetCore .NET 6.0.18 Linux 5.15.112-19373-g62629859bf76 #1 SMP PREEMPT Sun Jun 11 18:47:30 PDT 2023 [2023-06-22 20:33:27Z - 78a3eef5-95fd-43ca-80e8-fd821395a2b5] Finished [OAuth2Client] Deserializing response in 12 ms
21:33:27.412881 ...uthentication.cs:514 trace: [MSAL] [Verbose] False MSAL 4.52.0.0 MSAL.NetCore .NET 6.0.18 Linux 5.15.112-19373-g62629859bf76 #1 SMP PREEMPT Sun Jun 11 18:47:30 PDT 2023 [2023-06-22 20:33:27Z - 78a3eef5-95fd-43ca-80e8-fd821395a2b5] [Instance Discovery] Tried to use network cache provider for login.microsoftonline.com. Success? True.
21:33:27.412954 ...uthentication.cs:514 trace: [MSAL] [Verbose] False MSAL 4.52.0.0 MSAL.NetCore .NET 6.0.18 Linux 5.15.112-19373-g62629859bf76 #1 SMP PREEMPT Sun Jun 11 18:47:30 PDT 2023 [2023-06-22 20:33:27Z - 78a3eef5-95fd-43ca-80e8-fd821395a2b5] [Instance Discovery] After hitting the discovery endpoint, the network provider found an entry for login.microsoftonline.com ? True.
21:33:27.415172 ...uthentication.cs:514 trace: [MSAL] [Info] False MSAL 4.52.0.0 MSAL.NetCore .NET 6.0.18 Linux 5.15.112-19373-g62629859bf76 #1 SMP PREEMPT Sun Jun 11 18:47:30 PDT 2023 [2023-06-22 20:33:27Z - 78a3eef5-95fd-43ca-80e8-fd821395a2b5] Authority validation enabled? True.
21:33:27.415226 ...uthentication.cs:514 trace: [MSAL] [Info] False MSAL 4.52.0.0 MSAL.NetCore .NET 6.0.18 Linux 5.15.112-19373-g62629859bf76 #1 SMP PREEMPT Sun Jun 11 18:47:30 PDT 2023 [2023-06-22 20:33:27Z - 78a3eef5-95fd-43ca-80e8-fd821395a2b5] Authority validation - is known env? True.
21:33:27.417362 ...uthentication.cs:514 trace: [MSAL] [Info] False MSAL 4.52.0.0 MSAL.NetCore .NET 6.0.18 Linux 5.15.112-19373-g62629859bf76 #1 SMP PREEMPT Sun Jun 11 18:47:30 PDT 2023 [2023-06-22 20:33:27Z - 78a3eef5-95fd-43ca-80e8-fd821395a2b5] Using system browser.
21:33:27.435948 ...uthentication.cs:514 trace: [MSAL] [Info] False MSAL 4.52.0.0 MSAL.NetCore .NET 6.0.18 Linux 5.15.112-19373-g62629859bf76 #1 SMP PREEMPT Sun Jun 11 18:47:30 PDT 2023 [2023-06-22 20:33:27Z - 78a3eef5-95fd-43ca-80e8-fd821395a2b5] Listening for authorization code on http://localhost:40323/
21:33:32.582683 ...uthentication.cs:514 trace: [MSAL] [Info] False MSAL 4.52.0.0 MSAL.NetCore .NET 6.0.18 Linux 5.15.112-19373-g62629859bf76 #1 SMP PREEMPT Sun Jun 11 18:47:30 PDT 2023 [2023-06-22 20:33:32Z - 78a3eef5-95fd-43ca-80e8-fd821395a2b5] Processing a response message to the browser. HttpStatus:OK
21:33:32.584173 ...uthentication.cs:514 trace: [MSAL] [Verbose] False MSAL 4.52.0.0 MSAL.NetCore .NET 6.0.18 Linux 5.15.112-19373-g62629859bf76 #1 SMP PREEMPT Sun Jun 11 18:47:30 PDT 2023 [2023-06-22 20:33:32Z - 78a3eef5-95fd-43ca-80e8-fd821395a2b5] HttpListner received a message on http://localhost:40323/
21:33:32.589801 ...uthentication.cs:514 trace: [MSAL] [Info] False MSAL 4.52.0.0 MSAL.NetCore .NET 6.0.18 Linux 5.15.112-19373-g62629859bf76 #1 SMP PREEMPT Sun Jun 11 18:47:30 PDT 2023 [2023-06-22 20:33:32Z - 78a3eef5-95fd-43ca-80e8-fd821395a2b5] An authorization code was retrieved from the /authorize endpoint.
21:33:32.590143 ...uthentication.cs:514 trace: [MSAL] [Info] False MSAL 4.52.0.0 MSAL.NetCore .NET 6.0.18 Linux 5.15.112-19373-g62629859bf76 #1 SMP PREEMPT Sun Jun 11 18:47:30 PDT 2023 [2023-06-22 20:33:32Z - 78a3eef5-95fd-43ca-80e8-fd821395a2b5] Exchanging the auth code for tokens.
21:33:32.590952 ...uthentication.cs:514 trace: [MSAL] [Info] False MSAL 4.52.0.0 MSAL.NetCore .NET 6.0.18 Linux 5.15.112-19373-g62629859bf76 #1 SMP PREEMPT Sun Jun 11 18:47:30 PDT 2023 [2023-06-22 20:33:32Z - 78a3eef5-95fd-43ca-80e8-fd821395a2b5] DefaultBrowserOptions configured
21:33:32.590989 ...uthentication.cs:514 trace: [MSAL] [Info] False MSAL 4.52.0.0 MSAL.NetCore .NET 6.0.18 Linux 5.15.112-19373-g62629859bf76 #1 SMP PREEMPT Sun Jun 11 18:47:30 PDT 2023 [2023-06-22 20:33:32Z - 78a3eef5-95fd-43ca-80e8-fd821395a2b5] HtmlMessageSuccess? False
21:33:32.590997 ...uthentication.cs:514 trace: [MSAL] [Info] False MSAL 4.52.0.0 MSAL.NetCore .NET 6.0.18 Linux 5.15.112-19373-g62629859bf76 #1 SMP PREEMPT Sun Jun 11 18:47:30 PDT 2023 [2023-06-22 20:33:32Z - 78a3eef5-95fd-43ca-80e8-fd821395a2b5] HtmlMessageError? False
21:33:32.591005 ...uthentication.cs:514 trace: [MSAL] [Info] False MSAL 4.52.0.0 MSAL.NetCore .NET 6.0.18 Linux 5.15.112-19373-g62629859bf76 #1 SMP PREEMPT Sun Jun 11 18:47:30 PDT 2023 [2023-06-22 20:33:32Z - 78a3eef5-95fd-43ca-80e8-fd821395a2b5] BrowserRedirectSuccess? False
21:33:32.591017 ...uthentication.cs:514 trace: [MSAL] [Info] False MSAL 4.52.0.0 MSAL.NetCore .NET 6.0.18 Linux 5.15.112-19373-g62629859bf76 #1 SMP PREEMPT Sun Jun 11 18:47:30 PDT 2023 [2023-06-22 20:33:32Z - 78a3eef5-95fd-43ca-80e8-fd821395a2b5] BrowserRedirectError? False
21:33:32.591030 ...uthentication.cs:514 trace: [MSAL] [Info] False MSAL 4.52.0.0 MSAL.NetCore .NET 6.0.18 Linux 5.15.112-19373-g62629859bf76 #1 SMP PREEMPT Sun Jun 11 18:47:30 PDT 2023 [2023-06-22 20:33:32Z - 78a3eef5-95fd-43ca-80e8-fd821395a2b5] HidePrivacyPrompt False
21:33:32.596600 ...uthentication.cs:514 trace: [MSAL] [Info] False MSAL 4.52.0.0 MSAL.NetCore .NET 6.0.18 Linux 5.15.112-19373-g62629859bf76 #1 SMP PREEMPT Sun Jun 11 18:47:30 PDT 2023 [2023-06-22 20:33:32Z - 78a3eef5-95fd-43ca-80e8-fd821395a2b5] === InteractiveParameters Data ===
LoginHint provided: False
User provided: False
UseEmbeddedWebView: System
ExtraScopesToConsent:
Prompt: select_account
HasCustomWebUi: False

21:33:32.601542 ...uthentication.cs:514 trace: [MSAL] [Verbose] False MSAL 4.52.0.0 MSAL.NetCore .NET 6.0.18 Linux 5.15.112-19373-g62629859bf76 #1 SMP PREEMPT Sun Jun 11 18:47:30 PDT 2023 [2023-06-22 20:33:32Z - 78a3eef5-95fd-43ca-80e8-fd821395a2b5] Starting TokenClient:SendTokenRequestAsync
21:33:32.612669 ...uthentication.cs:514 trace: [MSAL] [Verbose] False MSAL 4.52.0.0 MSAL.NetCore .NET 6.0.18 Linux 5.15.112-19373-g62629859bf76 #1 SMP PREEMPT Sun Jun 11 18:47:30 PDT 2023 [2023-06-22 20:33:32Z - 78a3eef5-95fd-43ca-80e8-fd821395a2b5] [Token Client] Fetching MsalTokenResponse ....
21:33:32.613244 ...uthentication.cs:514 trace: [MSAL] [Verbose] False MSAL 4.52.0.0 MSAL.NetCore .NET 6.0.18 Linux 5.15.112-19373-g62629859bf76 #1 SMP PREEMPT Sun Jun 11 18:47:30 PDT 2023 [2023-06-22 20:33:32Z - 78a3eef5-95fd-43ca-80e8-fd821395a2b5] Starting [Oauth2Client] Sending POST request
21:33:32.617323 ...uthentication.cs:514 trace: [MSAL] [Verbose] False MSAL 4.52.0.0 MSAL.NetCore .NET 6.0.18 Linux 5.15.112-19373-g62629859bf76 #1 SMP PREEMPT Sun Jun 11 18:47:30 PDT 2023 [2023-06-22 20:33:32Z - 78a3eef5-95fd-43ca-80e8-fd821395a2b5] Starting [HttpManager] ExecuteAsync
21:33:32.617446 ...uthentication.cs:514 trace: [MSAL] [Verbose] False MSAL 4.52.0.0 MSAL.NetCore .NET 6.0.18 Linux 5.15.112-19373-g62629859bf76 #1 SMP PREEMPT Sun Jun 11 18:47:30 PDT 2023 [2023-06-22 20:33:32Z - 78a3eef5-95fd-43ca-80e8-fd821395a2b5] [HttpManager] Sending request. Method: POST. Host: https://login.microsoftonline.com.
21:33:32.950365 ...uthentication.cs:514 trace: [MSAL] [Verbose] False MSAL 4.52.0.0 MSAL.NetCore .NET 6.0.18 Linux 5.15.112-19373-g62629859bf76 #1 SMP PREEMPT Sun Jun 11 18:47:30 PDT 2023 [2023-06-22 20:33:32Z - 78a3eef5-95fd-43ca-80e8-fd821395a2b5] [HttpManager] Received response. Status code: OK.
21:33:32.950980 ...uthentication.cs:514 trace: [MSAL] [Verbose] False MSAL 4.52.0.0 MSAL.NetCore .NET 6.0.18 Linux 5.15.112-19373-g62629859bf76 #1 SMP PREEMPT Sun Jun 11 18:47:30 PDT 2023 [2023-06-22 20:33:32Z - 78a3eef5-95fd-43ca-80e8-fd821395a2b5] Finished [HttpManager] ExecuteAsync in 333 ms
21:33:32.953053 ...uthentication.cs:514 trace: [MSAL] [Verbose] False MSAL 4.52.0.0 MSAL.NetCore .NET 6.0.18 Linux 5.15.112-19373-g62629859bf76 #1 SMP PREEMPT Sun Jun 11 18:47:30 PDT 2023 [2023-06-22 20:33:32Z - 78a3eef5-95fd-43ca-80e8-fd821395a2b5] Finished [Oauth2Client] Sending POST request in 339 ms
21:33:32.953277 ...uthentication.cs:514 trace: [MSAL] [Verbose] False MSAL 4.52.0.0 MSAL.NetCore .NET 6.0.18 Linux 5.15.112-19373-g62629859bf76 #1 SMP PREEMPT Sun Jun 11 18:47:30 PDT 2023 [2023-06-22 20:33:32Z - 78a3eef5-95fd-43ca-80e8-fd821395a2b5] Starting [OAuth2Client] Deserializing response
21:33:32.968528 ...uthentication.cs:514 trace: [MSAL] [Verbose] False MSAL 4.52.0.0 MSAL.NetCore .NET 6.0.18 Linux 5.15.112-19373-g62629859bf76 #1 SMP PREEMPT Sun Jun 11 18:47:30 PDT 2023 [2023-06-22 20:33:32Z - 78a3eef5-95fd-43ca-80e8-fd821395a2b5] Finished [OAuth2Client] Deserializing response in 15 ms
21:33:32.969358 ...uthentication.cs:514 trace: [MSAL] [Verbose] False MSAL 4.52.0.0 MSAL.NetCore .NET 6.0.18 Linux 5.15.112-19373-g62629859bf76 #1 SMP PREEMPT Sun Jun 11 18:47:30 PDT 2023 [2023-06-22 20:33:32Z - 78a3eef5-95fd-43ca-80e8-fd821395a2b5] Finished TokenClient:SendTokenRequestAsync in 367 ms
21:33:32.969926 ...uthentication.cs:514 trace: [MSAL] [Info] False MSAL 4.52.0.0 MSAL.NetCore .NET 6.0.18 Linux 5.15.112-19373-g62629859bf76 #1 SMP PREEMPT Sun Jun 11 18:47:30 PDT 2023 [2023-06-22 20:33:32Z - 78a3eef5-95fd-43ca-80e8-fd821395a2b5] Checking client info returned from the server..
21:33:32.970204 ...uthentication.cs:514 trace: [MSAL] [Info] False MSAL 4.52.0.0 MSAL.NetCore .NET 6.0.18 Linux 5.15.112-19373-g62629859bf76 #1 SMP PREEMPT Sun Jun 11 18:47:30 PDT 2023 [2023-06-22 20:33:32Z - 78a3eef5-95fd-43ca-80e8-fd821395a2b5] Saving token response to cache..
21:33:32.973145 ...uthentication.cs:514 trace: [MSAL] [Verbose] False MSAL 4.52.0.0 MSAL.NetCore .NET 6.0.18 Linux 5.15.112-19373-g62629859bf76 #1 SMP PREEMPT Sun Jun 11 18:47:30 PDT 2023 [2023-06-22 20:33:32Z - 78a3eef5-95fd-43ca-80e8-fd821395a2b5]
[MsalTokenResponse]
Error:
ErrorDescription:
Scopes: 499b84ac-1321-427f-aa17-267ca6975798/user_impersonation 499b84ac-1321-427f-aa17-267ca6975798/.default
ExpiresIn: 4769
RefreshIn:
AccessToken returned: True
AccessToken Type: Bearer
RefreshToken returned: True
IdToken returned: True
ClientInfo returned: True
FamilyId: 1
WamAccountId exists: False

21:33:32.989716 ...uthentication.cs:514 trace: [MSAL] [Info] False MSAL 4.52.0.0 MSAL.NetCore .NET 6.0.18 Linux 5.15.112-19373-g62629859bf76 #1 SMP PREEMPT Sun Jun 11 18:47:30 PDT 2023 [2023-06-22 20:33:32Z - 78a3eef5-95fd-43ca-80e8-fd821395a2b5] [Region discovery] Not using a regional authority.
21:33:32.989779 ...uthentication.cs:514 trace: [MSAL] [Verbose] False MSAL 4.52.0.0 MSAL.NetCore .NET 6.0.18 Linux 5.15.112-19373-g62629859bf76 #1 SMP PREEMPT Sun Jun 11 18:47:30 PDT 2023 [2023-06-22 20:33:32Z - 78a3eef5-95fd-43ca-80e8-fd821395a2b5] [Instance Discovery] Tried to use network cache provider for login.microsoftonline.com. Success? True.
21:33:32.990079 ...uthentication.cs:514 trace: [MSAL] [Verbose] False MSAL 4.52.0.0 MSAL.NetCore .NET 6.0.18 Linux 5.15.112-19373-g62629859bf76 #1 SMP PREEMPT Sun Jun 11 18:47:30 PDT 2023 [2023-06-22 20:33:32Z - 78a3eef5-95fd-43ca-80e8-fd821395a2b5] [SaveTokenResponseAsync] Entering token cache semaphore. Count Real semaphore: True. Count: 1.
21:33:32.990156 ...uthentication.cs:514 trace: [MSAL] [Verbose] False MSAL 4.52.0.0 MSAL.NetCore .NET 6.0.18 Linux 5.15.112-19373-g62629859bf76 #1 SMP PREEMPT Sun Jun 11 18:47:30 PDT 2023 [2023-06-22 20:33:32Z - 78a3eef5-95fd-43ca-80e8-fd821395a2b5] [SaveTokenResponseAsync] Entered token cache semaphore.
21:33:32.991639 ...uthentication.cs:514 trace: [MSAL] [Verbose] False MSAL 4.52.0.0 MSAL.NetCore .NET 6.0.18 Linux 5.15.112-19373-g62629859bf76 #1 SMP PREEMPT Sun Jun 11 18:47:30 PDT 2023 [2023-06-22 20:33:32Z] [Microsoft.Identity.Client.Extensions] Before access
Acquiring lock for token cache
21:33:32.991858 ...uthentication.cs:514 trace: [MSAL] [Verbose] False MSAL 4.52.0.0 MSAL.NetCore .NET 6.0.18 Linux 5.15.112-19373-g62629859bf76 #1 SMP PREEMPT Sun Jun 11 18:47:30 PDT 2023 [2023-06-22 20:33:32Z] [Microsoft.Identity.Client.Extensions] Before access, the store has changed
21:33:32.994941 ...uthentication.cs:514 trace: [MSAL] [Verbose] False MSAL 4.52.0.0 MSAL.NetCore .NET 6.0.18 Linux 5.15.112-19373-g62629859bf76 #1 SMP PREEMPT Sun Jun 11 18:47:30 PDT 2023 [2023-06-22 20:33:32Z] [Microsoft.Identity.Client.Extensions] Read '7297' bytes from storage
21:33:32.994957 ...uthentication.cs:514 trace: [MSAL] [Verbose] False MSAL 4.52.0.0 MSAL.NetCore .NET 6.0.18 Linux 5.15.112-19373-g62629859bf76 #1 SMP PREEMPT Sun Jun 11 18:47:30 PDT 2023 [2023-06-22 20:33:32Z] [Microsoft.Identity.Client.Extensions] Deserializing the store
21:33:33.003807 ...uthentication.cs:514 trace: [MSAL] [Always] False MSAL 4.52.0.0 MSAL.NetCore .NET 6.0.18 Linux 5.15.112-19373-g62629859bf76 #1 SMP PREEMPT Sun Jun 11 18:47:30 PDT 2023 [2023-06-22 20:33:33Z] [Internal cache] Clearing user token cache accessor.
21:33:33.004499 ...uthentication.cs:514 trace: [MSAL] [Info] False MSAL 4.52.0.0 MSAL.NetCore .NET 6.0.18 Linux 5.15.112-19373-g62629859bf76 #1 SMP PREEMPT Sun Jun 11 18:47:30 PDT 2023 [2023-06-22 20:33:33Z - 78a3eef5-95fd-43ca-80e8-fd821395a2b5] [SaveTokenResponseAsync] Saving AT in cache and removing overlapping ATs...
21:33:33.005919 ...uthentication.cs:514 trace: [MSAL] [Info] False MSAL 4.52.0.0 MSAL.NetCore .NET 6.0.18 Linux 5.15.112-19373-g62629859bf76 #1 SMP PREEMPT Sun Jun 11 18:47:30 PDT 2023 [2023-06-22 20:33:33Z - 78a3eef5-95fd-43ca-80e8-fd821395a2b5] Looking for scopes for the authority in the cache which intersect with 499b84ac-1321-427f-aa17-267ca6975798/.default
21:33:33.006161 ...uthentication.cs:514 trace: [MSAL] [Always] False MSAL 4.52.0.0 MSAL.NetCore .NET 6.0.18 Linux 5.15.112-19373-g62629859bf76 #1 SMP PREEMPT Sun Jun 11 18:47:30 PDT 2023 [2023-06-22 20:33:33Z] [Internal cache] Total number of cache partitions found while getting access tokens: 1
21:33:33.007338 ...uthentication.cs:514 trace: [MSAL] [Verbose] False MSAL 4.52.0.0 MSAL.NetCore .NET 6.0.18 Linux 5.15.112-19373-g62629859bf76 #1 SMP PREEMPT Sun Jun 11 18:47:30 PDT 2023 [2023-06-22 20:33:33Z - 78a3eef5-95fd-43ca-80e8-fd821395a2b5] Intersecting scopes found: System.Collections.Generic.HashSet`1[System.String]
21:33:33.007396 ...uthentication.cs:514 trace: [MSAL] [Info] False MSAL 4.52.0.0 MSAL.NetCore .NET 6.0.18 Linux 5.15.112-19373-g62629859bf76 #1 SMP PREEMPT Sun Jun 11 18:47:30 PDT 2023 [2023-06-22 20:33:33Z - 78a3eef5-95fd-43ca-80e8-fd821395a2b5] Intersecting scope entries count - 1
21:33:33.007442 ...uthentication.cs:514 trace: [MSAL] [Info] False MSAL 4.52.0.0 MSAL.NetCore .NET 6.0.18 Linux 5.15.112-19373-g62629859bf76 #1 SMP PREEMPT Sun Jun 11 18:47:30 PDT 2023 [2023-06-22 20:33:33Z - 78a3eef5-95fd-43ca-80e8-fd821395a2b5] Matching entries after filtering by user - 1
21:33:33.007594 ...uthentication.cs:514 trace: [MSAL] [Info] False MSAL 4.52.0.0 MSAL.NetCore .NET 6.0.18 Linux 5.15.112-19373-g62629859bf76 #1 SMP PREEMPT Sun Jun 11 18:47:30 PDT 2023 [2023-06-22 20:33:33Z - 78a3eef5-95fd-43ca-80e8-fd821395a2b5] [SaveTokenResponseAsync] Saving Id Token and Account in cache ...
21:33:33.008006 ...uthentication.cs:514 trace: [MSAL] [Info] False MSAL 4.52.0.0 MSAL.NetCore .NET 6.0.18 Linux 5.15.112-19373-g62629859bf76 #1 SMP PREEMPT Sun Jun 11 18:47:30 PDT 2023 [2023-06-22 20:33:33Z - 78a3eef5-95fd-43ca-80e8-fd821395a2b5] [SaveTokenResponseAsync] Saving RT in cache...
21:33:33.008282 ...uthentication.cs:514 trace: [MSAL] [Verbose] False MSAL 4.52.0.0 MSAL.NetCore .NET 6.0.18 Linux 5.15.112-19373-g62629859bf76 #1 SMP PREEMPT Sun Jun 11 18:47:30 PDT 2023 [2023-06-22 20:33:33Z - 78a3eef5-95fd-43ca-80e8-fd821395a2b5] Not saving to ADAL legacy cache.
21:33:33.008728 ...uthentication.cs:514 trace: [MSAL] [Always] False MSAL 4.52.0.0 MSAL.NetCore .NET 6.0.18 Linux 5.15.112-19373-g62629859bf76 #1 SMP PREEMPT Sun Jun 11 18:47:30 PDT 2023 [2023-06-22 20:33:33Z] [Internal cache] Total number of cache partitions found while getting refresh tokens: 1
21:33:33.010076 ...uthentication.cs:514 trace: [MSAL] [Verbose] False MSAL 4.52.0.0 MSAL.NetCore .NET 6.0.18 Linux 5.15.112-19373-g62629859bf76 #1 SMP PREEMPT Sun Jun 11 18:47:30 PDT 2023 [2023-06-22 20:33:33Z] [Microsoft.Identity.Client.Extensions] After access
21:33:33.010106 ...uthentication.cs:514 trace: [MSAL] [Verbose] False MSAL 4.52.0.0 MSAL.NetCore .NET 6.0.18 Linux 5.15.112-19373-g62629859bf76 #1 SMP PREEMPT Sun Jun 11 18:47:30 PDT 2023 [2023-06-22 20:33:33Z] [Microsoft.Identity.Client.Extensions] After access, cache in memory HasChanged
21:33:33.011218 ...uthentication.cs:514 trace: [MSAL] [Always] False MSAL 4.52.0.0 MSAL.NetCore .NET 6.0.18 Linux 5.15.112-19373-g62629859bf76 #1 SMP PREEMPT Sun Jun 11 18:47:30 PDT 2023 [2023-06-22 20:33:33Z] [Internal cache] Total number of cache partitions found while getting access tokens: 1
21:33:33.011364 ...uthentication.cs:514 trace: [MSAL] [Always] False MSAL 4.52.0.0 MSAL.NetCore .NET 6.0.18 Linux 5.15.112-19373-g62629859bf76 #1 SMP PREEMPT Sun Jun 11 18:47:30 PDT 2023 [2023-06-22 20:33:33Z] [Internal cache] Total number of cache partitions found while getting refresh tokens: 1
21:33:33.016202 ...uthentication.cs:514 trace: [MSAL] [Verbose] False MSAL 4.52.0.0 MSAL.NetCore .NET 6.0.18 Linux 5.15.112-19373-g62629859bf76 #1 SMP PREEMPT Sun Jun 11 18:47:30 PDT 2023 [2023-06-22 20:33:33Z] [Microsoft.Identity.Client.Extensions] Serializing '7297' bytes
21:33:33.050519 ...uthentication.cs:514 trace: [MSAL] [Always] False MSAL 4.52.0.0 MSAL.NetCore .NET 6.0.18 Linux 5.15.112-19373-g62629859bf76 #1 SMP PREEMPT Sun Jun 11 18:47:30 PDT 2023 [2023-06-22 20:33:33Z] [Internal cache] Total number of cache partitions found while getting access tokens: 1
21:33:33.050589 ...uthentication.cs:514 trace: [MSAL] [Always] False MSAL 4.52.0.0 MSAL.NetCore .NET 6.0.18 Linux 5.15.112-19373-g62629859bf76 #1 SMP PREEMPT Sun Jun 11 18:47:30 PDT 2023 [2023-06-22 20:33:33Z] [Internal cache] Total number of cache partitions found while getting refresh tokens: 1
21:33:33.051608 ...uthentication.cs:514 trace: [MSAL] [Verbose] False MSAL 4.52.0.0 MSAL.NetCore .NET 6.0.18 Linux 5.15.112-19373-g62629859bf76 #1 SMP PREEMPT Sun Jun 11 18:47:30 PDT 2023 [2023-06-22 20:33:33Z - 78a3eef5-95fd-43ca-80e8-fd821395a2b5] Total number of access tokens in cache: 1
Total number of refresh tokens in cache: 1
Token cache dump of the first 1 cache keys.
AT Cache Key: 1148142827-login.windows.net-accesstoken-872cd9fa-d31f-45e0-9eab-6e460a02d1f1-f8cdef31-a31e-4b4a-93e4-5f571e91255a-499b84ac-1321-427f-aa17-267ca6975798/user_impersonation 499b84ac-1321-427f-aa17-267ca6975798/.default

21:33:33.051711 ...uthentication.cs:514 trace: [MSAL] [Verbose] False MSAL 4.52.0.0 MSAL.NetCore .NET 6.0.18 Linux 5.15.112-19373-g62629859bf76 #1 SMP PREEMPT Sun Jun 11 18:47:30 PDT 2023 [2023-06-22 20:33:33Z - 78a3eef5-95fd-43ca-80e8-fd821395a2b5] [SaveTokenResponseAsync] Released token cache semaphore.
21:33:33.054711 ...uthentication.cs:514 trace: [MSAL] [Info] False MSAL 4.52.0.0 MSAL.NetCore .NET 6.0.18 Linux 5.15.112-19373-g62629859bf76 #1 SMP PREEMPT Sun Jun 11 18:47:30 PDT 2023 [2023-06-22 20:33:33Z - 78a3eef5-95fd-43ca-80e8-fd821395a2b5]
=== Token Acquisition finished successfully:
21:33:33.055772 ...uthentication.cs:514 trace: [MSAL] [Info] False MSAL 4.52.0.0 MSAL.NetCore .NET 6.0.18 Linux 5.15.112-19373-g62629859bf76 #1 SMP PREEMPT Sun Jun 11 18:47:30 PDT 2023 [2023-06-22 20:33:33Z - 78a3eef5-95fd-43ca-80e8-fd821395a2b5] AT expiration time: 06/22/2023 21:53:01 +00:00, scopes: 499b84ac-1321-427f-aa17-267ca6975798/user_impersonation 499b84ac-1321-427f-aa17-267ca6975798/.default. source: IdentityProvider
21:33:33.055882 ...uthentication.cs:514 trace: [MSAL] [Info] False MSAL 4.52.0.0 MSAL.NetCore .NET 6.0.18 Linux 5.15.112-19373-g62629859bf76 #1 SMP PREEMPT Sun Jun 11 18:47:30 PDT 2023 [2023-06-22 20:33:33Z - 78a3eef5-95fd-43ca-80e8-fd821395a2b5] Fetched access token from host login.microsoftonline.com.
21:33:33.056320 ...uthentication.cs:514 trace: [MSAL] [Always] False MSAL 4.52.0.0 MSAL.NetCore .NET 6.0.18 Linux 5.15.112-19373-g62629859bf76 #1 SMP PREEMPT Sun Jun 11 18:47:30 PDT 2023 [2023-06-22 20:33:33Z - 78a3eef5-95fd-43ca-80e8-fd821395a2b5]
[LogMetricsFromAuthResult] Cache Refresh Reason: NotApplicable
[LogMetricsFromAuthResult] DurationInCacheInMs: 51
[LogMetricsFromAuthResult] DurationTotalInMs: 5838
[LogMetricsFromAuthResult] DurationInHttpInMs: 498

21:33:33.056357 ...uthentication.cs:514 trace: [MSAL] [Always] False MSAL 4.52.0.0 MSAL.NetCore .NET 6.0.18 Linux 5.15.112-19373-g62629859bf76 #1 SMP PREEMPT Sun Jun 11 18:47:30 PDT 2023 [2023-06-22 20:33:33Z - 78a3eef5-95fd-43ca-80e8-fd821395a2b5] TokenEndpoint: ****
21:33:33.057653 ...sHostProvider.cs:207 trace: [GeneratePersonalAccessTokenAsync] Acquired Azure access token. Account='matt.hickford@gmail.com' Token=''
21:33:33.057671 ...sHostProvider.cs:216 trace: [GeneratePersonalAccessTokenAsync] Creating Azure DevOps PAT with scopes 'vso.code_write, vso.packaging'...
21:33:33.058545 ...DevOpsRestApi.cs:117 trace: [CreatePersonalAccessTokenAsync] Getting Azure DevOps Identity Service endpoint...
21:33:33.059738 ...DevOpsRestApi.cs:167 trace: [GetIdentityServiceUriAsync] HTTP: GET https://dev.azure.com/matthickford0459/_apis/ServiceDefinitions/LocationService2/951917AC-A960-4999-8464-E3F0AA25B381?api-version=1.0
21:33:33.464261 ...DevOpsRestApi.cs:171 trace: [GetIdentityServiceUriAsync] HTTP: Response 200 [OK]
21:33:33.476902 ...DevOpsRestApi.cs:119 trace: [CreatePersonalAccessTokenAsync] Identity Service endpoint is 'https://spsproduks1.vssps.visualstudio.com/A92941f2c-6d7a-4d96-b597-3887ab296f70/'.
21:33:33.476947 ...DevOpsRestApi.cs:123 trace: [CreatePersonalAccessTokenAsync] HTTP: POST https://spsproduks1.vssps.visualstudio.com/A92941f2c-6d7a-4d96-b597-3887ab296f70/_apis/token/sessiontokens?api-version=1.0&tokentype=compact
21:33:33.733337 ...DevOpsRestApi.cs:128 trace: [CreatePersonalAccessTokenAsync] HTTP: Response 200 [OK]
21:33:33.737978 ...sHostProvider.cs:221 trace: [GeneratePersonalAccessTokenAsync] PAT created. PAT='
'
21:33:33.738320 ...osHostProvider.cs:95 trace: [GetCredentialAsync] Credential created.
21:33:33.738464 ...nds/GetCommand.cs:39 trace: [ExecuteInternalAsync] Writing credentials to output:
21:33:33.738476 ...nds/GetCommand.cs:40 trace: [ExecuteInternalAsync] protocol=https
21:33:33.738479 ...nds/GetCommand.cs:40 trace: [ExecuteInternalAsync] host=dev.azure.com
21:33:33.738482 ...nds/GetCommand.cs:40 trace: [ExecuteInternalAsync] path=matthickford0459/testdevazuredotcom/_git/testdevazuredotcom
21:33:33.738484 ...nds/GetCommand.cs:40 trace: [ExecuteInternalAsync] username=matt.hickford@gmail.com
21:33:33.738487 ...nds/GetCommand.cs:40 trace: [ExecuteInternalAsync] password=********
21:33:33.738809 ...GitCommandBase.cs:54 trace: [ExecuteAsync] End 'get' command...

@Lds911 Lds911 linked a pull request Jun 23, 2023 that will close this issue
@mjcheetham
Copy link
Collaborator

Why is the PAT preferred to access token? The scope is more limited?

Historically PATs were the only option we supported. OAuth support was added around about the same time as the Windows broker support was added. There are still some issues to be ironed out (as you have found!) before we can switch the default. There's be some inertia here trying to fix some of the issues that span GCM+MSAL+Windows+AzureDevOps.

The scope of the PAT is also more limited, true. But PATs may have longer lifetimes that Microsoft identity access tokens (typically 1-8 hours).

@Asiftoor

This comment was marked as spam.

@Asiftoor

This comment was marked as spam.

@bgavrilMS
Copy link

bgavrilMS commented Jul 21, 2023

@mjcheetham, @ldennington - I was under the impression that GCM had this flow tested (OAuth with MSA account). Is there a regression.

MSAL has a non so great experience API usage for this, but still it will work. It's described here AzureAD/microsoft-authentication-library-for-dotnet#3077

@mjcheetham
Copy link
Collaborator

mjcheetham commented Jul 31, 2023

I've opened a PR to add the workaround in GCM for MSA silent auth: #1321

mjcheetham added a commit that referenced this issue Jul 31, 2023
When we have a Microsoft Account (MSA) in the cache and attempt to do a
silent authentication, if we're an MSA-PT app we need to specify the
special MSA transfer tenant ID to make sure we get the a token silently,
correctly.

See the
[issue](AzureAD/microsoft-authentication-library-for-dotnet#3077)
in the MSAL repo for more information.

Fixes: #1297
ldennington added a commit that referenced this issue Aug 1, 2023
**Changes since 2.2.2:**

- Fix a GCM/Git Trace2 file locking issue
  - Issue: #1323 
  - PR: #1340
- Remove symlinks to `git-credential-manager-core` exe
  - Issue: #1322
  - PR: #1327 
- Add fallback http uri to `diagnose` command
  - Issue: #1215
  - PR: #1339
- Workaround MSAL tenant issue with silent auth
  - Issue: #1297
  - PR: #1321
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
auth:microsoft Specific to Microsoft AAD/MSA authentication external Relating to an external partner, team, or library
Projects
None yet
5 participants