Add more logging to GetAccounts by id

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<IEnumerable<IAccount>> 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;
 

src/client/Microsoft.Identity.Client/PlatformsCommon/Shared/InMemoryPartitionedUserTokenCacheAccessor.cs

@@ -223,17 +223,36 @@ public virtual List<MsalAccessTokenCacheItem> GetAllAccessTokens(string partitio
         /// It should only support external token caching, in the hope that the external token cache is partitioned.
         public virtual List<MsalRefreshTokenCacheItem> GetAllRefreshTokens(string partitionKey = null, ILoggerAdapter requestlogger = null)
         {
+            List<MsalRefreshTokenCacheItem> 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<string, MsalRefreshTokenCacheItem> partition);
-                return partition?.Select(kv => kv.Value)?.ToList() ?? CollectionHelpers.GetEmptyList<MsalRefreshTokenCacheItem>();
+
+                result = partition?.Select(kv => kv.Value)?.ToList() ?? CollectionHelpers.GetEmptyList<MsalRefreshTokenCacheItem>();
+                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<MsalIdTokenCacheItem> GetAllIdTokens(string partitionKey = n
         /// It should only support external token caching, in the hope that the external token cache is partitioned.
         public virtual List<MsalAccountCacheItem> GetAllAccounts(string partitionKey = null, ILoggerAdapter requestlogger = null)
         {
+            var logger = requestlogger ?? _logger;
+            List<MsalAccountCacheItem> 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<string, MsalAccountCacheItem> partition);
-                return partition?.Select(kv => kv.Value)?.ToList() ?? CollectionHelpers.GetEmptyList<MsalAccountCacheItem>();
+                result = partition?.Select(kv => kv.Value)?.ToList() ?? CollectionHelpers.GetEmptyList<MsalAccountCacheItem>();
+
+                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<MsalAppMetadataCacheItem> GetAllAppMetadata()

src/client/Microsoft.Identity.Client/TokenCache.ITokenCacheInternal.cs

@@ -90,7 +90,7 @@ async Task<Tuple<MsalAccessTokenCacheItem, MsalIdTokenCacheItem, Account>> 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<Tuple<MsalAccessTokenCacheItem, MsalIdTokenCacheItem, Account>> IToke
                     }
                 }
 
-                
+
                 account = new Account(
                   homeAccountId,
                   username,
@@ -195,7 +195,7 @@ async Task<Tuple<MsalAccessTokenCacheItem, MsalIdTokenCacheItem, Account>> 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<IEnumerable<IAccount>> 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<string> allEnvironmentsInCache = new HashSet<string>(
@@ -969,15 +972,21 @@ async Task<IEnumerable<IAccount>> 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<string, Account> clientInfoToAccountMap = new Dictionary<string, Account>();
             foreach (MsalRefreshTokenCacheItem rtItem in refreshTokenCacheItems)
             {
@@ -1047,14 +1056,11 @@ async Task<IEnumerable<IAccount>> 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(

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);

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();