search

git-ecosystem / git-credential-manager

Secure, cross-platform Git credential storage with authentication to GitHub, Azure Repos, and other popular Git hosting services.
Other
6.81k stars 1.78k forks source link

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

Closed hickford closed 1 year ago

hickford commented 1 year ago

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

ldennington commented 1 year ago

@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 commented 1 year ago

Yes, an ordinary Microsoft account.

mjcheetham commented 1 year ago

@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

bgavrilMS commented 1 year ago

MSAL logs do not contain secrets, it never logs tokens or passwords etc. At most they can contain private data such as email address.

Sent from Outlook for iOShttps://aka.ms/o0ukef

From: Matthew John Cheetham @.> Sent: Monday, June 19, 2023 11:47:10 PM To: git-ecosystem/git-credential-manager @.> Cc: Bogdan Gavril @.>; Mention @.> Subject: Re: [git-ecosystem/git-credential-manager] Error authenticating to Azure DevOps with OAuth "Application ... is configured for use by Azure Active Directory users only" (Issue #1297)

@hickfordhttps://github.com/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: @bgavrilMShttps://github.com/bgavrilMS

— Reply to this email directly, view it on GitHubhttps://github.com/git-ecosystem/git-credential-manager/issues/1297#issuecomment-1597848314, or unsubscribehttps://github.com/notifications/unsubscribe-auth/AC5UN2ETU65ELWQ7OFNU5SDXMDJG5ANCNFSM6AAAAAAZK6I4H4. You are receiving this because you were mentioned.Message ID: @.***>

hickford commented 1 year ago

@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 commented 1 year ago

@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 commented 1 year ago

@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 commented 1 year ago

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 commented 1 year ago

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 commented 1 year ago

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...
mjcheetham commented 1 year ago

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 commented 1 year ago

Sir sir help me I am new account and guide code and all features please help my email address asiftoor049@gmail.com

Asiftoor commented 1 year ago

Guide all features

bgavrilMS commented 1 year ago

@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 https://github.com/AzureAD/microsoft-authentication-library-for-dotnet/issues/3077

mjcheetham commented 1 year ago

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