diff --git a/src/client/Microsoft.Identity.Client/ClientApplicationBase.cs b/src/client/Microsoft.Identity.Client/ClientApplicationBase.cs index 1fb0b7ad15..36f590c332 100644 --- a/src/client/Microsoft.Identity.Client/ClientApplicationBase.cs +++ b/src/client/Microsoft.Identity.Client/ClientApplicationBase.cs @@ -38,8 +38,8 @@ public abstract partial class ClientApplicationBase : ApplicationBase, IClientAp internal ClientApplicationBase(ApplicationConfiguration config) : base(config) { - UserTokenCacheInternal = - config.UserTokenCacheInternalForTest ?? + UserTokenCacheInternal = + config.UserTokenCacheInternalForTest ?? new TokenCache( ServiceBundle, false, @@ -171,6 +171,15 @@ private async Task> GetAccountsInternalAsync(ApiIds apiId, { Guid correlationId = Guid.NewGuid(); RequestContext requestContext = CreateRequestContext(correlationId, cancellationToken); + + if (requestContext.Logger.IsLoggingEnabled(LogLevel.Info)) + { + requestContext.Logger.Info($"==== GetAccounts started - {apiId} ===="); + requestContext.Logger.InfoPii( + $"Account id filter: {homeAccountIdFilter}", + $"Account id filter: {!string.IsNullOrEmpty(homeAccountIdFilter)}"); + } + requestContext.ApiEvent = new ApiEvent(correlationId); requestContext.ApiEvent.ApiId = apiId; diff --git a/src/client/Microsoft.Identity.Client/PlatformsCommon/Shared/InMemoryPartitionedUserTokenCacheAccessor.cs b/src/client/Microsoft.Identity.Client/PlatformsCommon/Shared/InMemoryPartitionedUserTokenCacheAccessor.cs index 4292949d37..4e3800129b 100644 --- a/src/client/Microsoft.Identity.Client/PlatformsCommon/Shared/InMemoryPartitionedUserTokenCacheAccessor.cs +++ b/src/client/Microsoft.Identity.Client/PlatformsCommon/Shared/InMemoryPartitionedUserTokenCacheAccessor.cs @@ -223,17 +223,36 @@ public virtual List GetAllAccessTokens(string partitio /// It should only support external token caching, in the hope that the external token cache is partitioned. public virtual List GetAllRefreshTokens(string partitionKey = null, ILoggerAdapter requestlogger = null) { + List result; var logger = requestlogger ?? _logger; - logger.Always($"[Internal cache] Total number of cache partitions found while getting refresh tokens: {RefreshTokenCacheDictionary.Count}"); + logger.AlwaysPii( + $"[Internal cache] Total number of cache partitions found while getting refresh tokens: {RefreshTokenCacheDictionary.Count}. PartitionKey {partitionKey}", + $"[Internal cache] Total number of cache partitions found while getting refresh tokens: {RefreshTokenCacheDictionary.Count}. PartitionKey {!string.IsNullOrEmpty(partitionKey)}"); + if (string.IsNullOrEmpty(partitionKey)) { - return RefreshTokenCacheDictionary.SelectMany(dict => dict.Value).Select(kv => kv.Value).ToList(); + result = RefreshTokenCacheDictionary.SelectMany(dict => dict.Value).Select(kv => kv.Value).ToList(); + logger.Verbose(() => $"[Internal cache] GetAllRefreshTokens (no partition) found {result.Count} refresh tokens:"); + } else { RefreshTokenCacheDictionary.TryGetValue(partitionKey, out ConcurrentDictionary partition); - return partition?.Select(kv => kv.Value)?.ToList() ?? CollectionHelpers.GetEmptyList(); + + result = partition?.Select(kv => kv.Value)?.ToList() ?? CollectionHelpers.GetEmptyList(); + if (logger.IsLoggingEnabled(LogLevel.Verbose)) + { + logger.Verbose(() => $"[Internal cache] GetAllRefreshTokens (with partition - exists? {partition != null})) found {result.Count} refresh tokens:"); + if (RefreshTokenCacheDictionary.Count == 1 && result.Count == 0) + { + logger.VerbosePii( + () => $"[Internal cache] 0 RTs and 1 partition. Partition in cache is {RefreshTokenCacheDictionary.Keys.First()}", + () => "[Internal cache] 0 RTs and 1 partition] 0 RTs and 1 partition."); + } + } } + + return result; } /// WARNING: if partitionKey is null, this API is slow as it loads all tokens, not just from 1 partition. @@ -255,15 +274,37 @@ public virtual List GetAllIdTokens(string partitionKey = n /// It should only support external token caching, in the hope that the external token cache is partitioned. public virtual List GetAllAccounts(string partitionKey = null, ILoggerAdapter requestlogger = null) { + var logger = requestlogger ?? _logger; + List result; + + logger.AlwaysPii( + $"[Internal cache] Total number of cache partitions found while getting accounts: {AccountCacheDictionary.Count}. PartitionKey {partitionKey}", + $"[Internal cache] Total number of cache partitions found while getting accounts: {AccountCacheDictionary.Count}. PartitionKey {!string.IsNullOrEmpty(partitionKey)}"); + if (string.IsNullOrEmpty(partitionKey)) { - return AccountCacheDictionary.SelectMany(dict => dict.Value).Select(kv => kv.Value).ToList(); + result = AccountCacheDictionary.SelectMany(dict => dict.Value).Select(kv => kv.Value).ToList(); + logger.Verbose(() => $"[Internal cache] GetAllAccounts (no partition) found {result.Count} accounts."); } else { AccountCacheDictionary.TryGetValue(partitionKey, out ConcurrentDictionary partition); - return partition?.Select(kv => kv.Value)?.ToList() ?? CollectionHelpers.GetEmptyList(); + result = partition?.Select(kv => kv.Value)?.ToList() ?? CollectionHelpers.GetEmptyList(); + + if (logger.IsLoggingEnabled(LogLevel.Verbose)) + { + logger.Verbose(() => $"[Internal cache] GetAllAccounts (with partition - exists? {partition != null}) found {result.Count} accounts."); + if (AccountCacheDictionary.Count == 1 && result.Count == 0) + { + // get dictionary first key + logger.VerbosePii( + () => $"[Internal cache] 0 RTs and 1 partition. Partition in cache is {AccountCacheDictionary.Keys.First()}", + () => "[Internal cache] 0 RTs and 1 partition] 0 RTs and 1 partition."); + } + } } + + return result; } public virtual List GetAllAppMetadata() diff --git a/src/client/Microsoft.Identity.Client/TokenCache.ITokenCacheInternal.cs b/src/client/Microsoft.Identity.Client/TokenCache.ITokenCacheInternal.cs index 0b4f41cb5f..6a6525998b 100644 --- a/src/client/Microsoft.Identity.Client/TokenCache.ITokenCacheInternal.cs +++ b/src/client/Microsoft.Identity.Client/TokenCache.ITokenCacheInternal.cs @@ -90,7 +90,7 @@ async Task> IToke "client_credentials flow should not receive a refresh token"); Debug.Assert( - (requestParams.ApiId != ApiEvent.ApiIds.AcquireTokenForSystemAssignedManagedIdentity || + (requestParams.ApiId != ApiEvent.ApiIds.AcquireTokenForSystemAssignedManagedIdentity || requestParams.ApiId != ApiEvent.ApiIds.AcquireTokenForUserAssignedManagedIdentity), "Managed identity flow should not receive a refresh token"); @@ -152,7 +152,7 @@ async Task> IToke } } - + account = new Account( homeAccountId, username, @@ -195,7 +195,7 @@ async Task> IToke identityLogger: requestParams.RequestContext.Logger.IdentityLogger, piiLoggingEnabled: requestParams.RequestContext.Logger.PiiLoggingEnabled); - var measuredResultDuration = await StopwatchService.MeasureCodeBlockAsync( async () => + var measuredResultDuration = await StopwatchService.MeasureCodeBlockAsync(async () => { await tokenCacheInternal.OnBeforeAccessAsync(args).ConfigureAwait(false); await tokenCacheInternal.OnBeforeWriteAsync(args).ConfigureAwait(false); @@ -930,18 +930,21 @@ async Task> ITokenCacheInternal.GetAccountsAsync(Authentic // this will either be the home account ID or null, it can never be OBO assertion or tenant ID string partitionKey = CacheKeyFactory.GetKeyFromRequest(requestParameters); + logger.VerbosePii(() => $"[GetAccounts] PartitionKey: {partitionKey}. request.HomeAccountId {requestParameters.HomeAccountId}", () => ""); + var refreshTokenCacheItems = Accessor.GetAllRefreshTokens(partitionKey); var accountCacheItems = Accessor.GetAllAccounts(partitionKey); if (filterByClientId) { - FilterTokensByClientId(refreshTokenCacheItems); + refreshTokenCacheItems.FilterWithLogging(item => + string.Equals(item.ClientId, ClientId, StringComparison.OrdinalIgnoreCase), + logger, + "[GetAccounts] Filtering RTs by clientID", + true); } - if (logger.IsLoggingEnabled(LogLevel.Verbose)) - { - logger.Verbose(() => $"[GetAccounts] Found {refreshTokenCacheItems.Count} RTs and {accountCacheItems.Count} accounts in MSAL cache. "); - } + logger.Verbose(() => $"[GetAccounts] Found {refreshTokenCacheItems.Count} RTs and {accountCacheItems.Count} accounts in MSAL cache before env filtering."); // Multi-cloud support - must filter by environment. ISet allEnvironmentsInCache = new HashSet( @@ -969,15 +972,21 @@ async Task> ITokenCacheInternal.GetAccountsAsync(Authentic // since the authority in request is different from the authority used to get the token if (!requestParameters.AppConfig.MultiCloudSupportEnabled) { - refreshTokenCacheItems.RemoveAll(rt => !instanceMetadata.Aliases.ContainsOrdinalIgnoreCase(rt.Environment)); - accountCacheItems.RemoveAll(acc => !instanceMetadata.Aliases.ContainsOrdinalIgnoreCase(acc.Environment)); - } + refreshTokenCacheItems.FilterWithLogging( + rt => instanceMetadata.Aliases.ContainsOrdinalIgnoreCase(rt.Environment), + logger, + "[GetAccounts] Filtering RTs by environment", + true); - if (logger.IsLoggingEnabled(LogLevel.Verbose)) - { - logger.Verbose(() => $"[GetAccounts] Found {refreshTokenCacheItems.Count} RTs and {accountCacheItems.Count} accounts in MSAL cache after environment filtering. "); + accountCacheItems.FilterWithLogging( + a => instanceMetadata.Aliases.ContainsOrdinalIgnoreCase(a.Environment), + logger, + "[GetAccounts] Filtering accounts by environment", + true); } + logger.Verbose(() => $"[GetAccounts] Found {refreshTokenCacheItems.Count} RTs and {accountCacheItems.Count} accounts in MSAL cache after environment filtering. "); + IDictionary clientInfoToAccountMap = new Dictionary(); foreach (MsalRefreshTokenCacheItem rtItem in refreshTokenCacheItems) { @@ -1047,14 +1056,11 @@ async Task> ITokenCacheInternal.GetAccountsAsync(Authentic if (!string.IsNullOrEmpty(requestParameters.HomeAccountId)) { - accounts = accounts.Where(acc => acc.HomeAccountId.Identifier.Equals( - requestParameters.HomeAccountId, - StringComparison.OrdinalIgnoreCase)).ToList(); - - if (logger.IsLoggingEnabled(LogLevel.Verbose)) - { - logger.Verbose(() => $"Filtered by home account id. Remaining accounts {accounts.Count} "); - } + accounts.FilterWithLogging( + acc => acc.HomeAccountId.Identifier.Equals(requestParameters.HomeAccountId, StringComparison.OrdinalIgnoreCase), + logger, + "[GetAccounts] Filtering by accountID", + true); } return accounts; @@ -1287,7 +1293,7 @@ async Task ITokenCacheInternal.RemoveAccountAsync(IAccount account, Authenticati } RemoveAccountInternal(account, requestParameters.RequestContext); - + if (IsLegacyAdalCacheEnabled(requestParameters)) { CacheFallbackOperations.RemoveAdalUser( diff --git a/tests/Microsoft.Identity.Test.Integration.netcore/HeadlessTests/ClientCredentialsTests.WithRegion.cs b/tests/Microsoft.Identity.Test.Integration.netcore/HeadlessTests/ClientCredentialsTests.WithRegion.cs index 069f0978e7..96615c2776 100644 --- a/tests/Microsoft.Identity.Test.Integration.netcore/HeadlessTests/ClientCredentialsTests.WithRegion.cs +++ b/tests/Microsoft.Identity.Test.Integration.netcore/HeadlessTests/ClientCredentialsTests.WithRegion.cs @@ -125,17 +125,18 @@ private IConfidentialClientApplication BuildCCA( string region = ConfidentialClientApplication.AttemptRegionDiscovery) { var builder = ConfidentialClientApplicationBuilder.Create(settings.ClientId); - if (useClaims) - { - builder.WithClientAssertion(() => GetSignedClientAssertionUsingMsalInternal(settings.ClientId, GetClaims(settings))); - } - else - { - builder.WithCertificate(settings.GetCertificate()); - } + //if (useClaims) + //{ + // builder.WithClientAssertion(() => GetSignedClientAssertionUsingMsalInternal(settings.ClientId, GetClaims(settings))); + //} + //else + //{ + // builder.WithCertificate(settings.GetCertificate()); + //} builder.WithAuthority($@"https://{settings.Environment}/{settings.TenantId}") .WithInstanceDiscovery(settings.InstanceDiscoveryEndpoint) + .WithClientSecret(settings.GetSecret()) .WithTestLogging() .WithExperimentalFeatures(true) .WithHttpClientFactory(factory); diff --git a/tests/Microsoft.Identity.Test.Unit/PublicApiTests/ConfidentialClientApplicationTests.cs b/tests/Microsoft.Identity.Test.Unit/PublicApiTests/ConfidentialClientApplicationTests.cs index 2d261ca2ca..8684b1caf2 100644 --- a/tests/Microsoft.Identity.Test.Unit/PublicApiTests/ConfidentialClientApplicationTests.cs +++ b/tests/Microsoft.Identity.Test.Unit/PublicApiTests/ConfidentialClientApplicationTests.cs @@ -1829,11 +1829,13 @@ public async Task AcquireTokenOboAuthorityCheckTestAsync(string tenant) [DataRow(null)] public async Task ValidateGetAccountAsyncWithNullEmptyAccountIdAsync(string accountId) { + var testIdentiyLogger = new TestIdentityLogger(); using (var httpManager = new MockHttpManager()) { var app = ConfidentialClientApplicationBuilder.Create(TestConstants.ClientId) .WithClientSecret(TestConstants.ClientSecret) .WithHttpManager(httpManager) + .WithLogging(testIdentiyLogger) .BuildConcrete(); httpManager.AddInstanceDiscoveryMockHandler();