Identity cache logger updates

src/client/Microsoft.Identity.Client/Cache/CacheSessionManager.cs

@@ -127,7 +127,9 @@ private async Task RefreshCacheForReadOperationsAsync()
                                   suggestedCacheExpiry: null,
                                   correlationId: _requestParams.RequestContext.CorrelationId, 
                                   requestScopes: _requestParams.Scope, 
-                                  requestTenantId: _requestParams.AuthorityManager.OriginalAuthority.TenantId);
+                                  requestTenantId: _requestParams.AuthorityManager.OriginalAuthority.TenantId,
+                                  msalIdentityLogger: _requestParams.RequestContext.Logger.MsalIdentityLogger,
+                                  piiLoggingEnabled: _requestParams.RequestContext.Logger.PiiLoggingEnabled);
 
                                 stopwatch.Start();
                                 await TokenCacheInternal.OnBeforeAccessAsync(args).ConfigureAwait(false);
@@ -151,7 +153,9 @@ private async Task RefreshCacheForReadOperationsAsync()
                                   suggestedCacheExpiry: null,
                                   correlationId: _requestParams.RequestContext.CorrelationId,
                                   requestScopes: _requestParams.Scope,
-                                  requestTenantId: _requestParams.AuthorityManager.OriginalAuthority.TenantId);
+                                  requestTenantId: _requestParams.AuthorityManager.OriginalAuthority.TenantId,
+                                  msalIdentityLogger: _requestParams.RequestContext.Logger.MsalIdentityLogger,
+                                  piiLoggingEnabled: _requestParams.RequestContext.Logger.PiiLoggingEnabled);
 
                                 await TokenCacheInternal.OnAfterAccessAsync(args).ConfigureAwait(false);
                                 RequestContext.ApiEvent.DurationInCacheInMs += stopwatch.ElapsedMilliseconds;

src/client/Microsoft.Identity.Client/Internal/Logger/ILoggerAdapter.cs

@@ -3,6 +3,7 @@
 
 using System.Runtime.CompilerServices;
 using Microsoft.Identity.Client.Internal.Logger;
+using Microsoft.IdentityModel.Abstractions;
 
 namespace Microsoft.Identity.Client.Core
 {
@@ -12,6 +13,7 @@ internal interface ILoggerAdapter
         bool IsDefaultPlatformLoggingEnabled { get; }
         string ClientName { get; }
         string ClientVersion { get; }
+        IIdentityLogger MsalIdentityLogger { get; }
 
         /// <summary>
         /// For expensive logging messages (e.g. when the log message evaluates a variable), 

src/client/Microsoft.Identity.Client/Internal/Logger/IdentityLoggerAdapter.cs

@@ -13,14 +13,12 @@ namespace Microsoft.Identity.Client.Internal.Logger
 #if !XAMARINMAC20
     internal class IdentityLoggerAdapter : ILoggerAdapter
     {
-        private readonly IIdentityLogger _identityLogger;
-        private string _clientInfo;
         private string _correlationId;
-
         public bool PiiLoggingEnabled { get; }
         public bool IsDefaultPlatformLoggingEnabled { get; } = false;
         public string ClientName { get; }
         public string ClientVersion { get; }
+        public IIdentityLogger MsalIdentityLogger { get; }
 
         internal IdentityLoggerAdapter(
             IIdentityLogger identityLogger,
@@ -31,12 +29,10 @@ internal IdentityLoggerAdapter(
         {
             ClientName = clientName;
             ClientVersion = clientVersion;
-            _identityLogger = identityLogger;
+            MsalIdentityLogger = new MsalIdentityLogger(identityLogger, correlationId, clientName, clientVersion, enablePiiLogging);
             _correlationId = correlationId.Equals(Guid.Empty)
                     ? string.Empty
                     : " - " + correlationId;
-
-            _clientInfo = LoggerHelper.GetClientInfo(clientName, clientVersion);
 
             PiiLoggingEnabled = enablePiiLogging;
         }
@@ -57,17 +53,19 @@ public void Log(LogLevel logLevel, string messageWithPii, string messageScrubbed
         {
             if (IsLoggingEnabled(logLevel))
             {
+                string messageToLog = LoggerHelper.GetMessageToLog(messageWithPii, messageScrubbed, PiiLoggingEnabled);
+
                 LogEntry entry = new LogEntry();
                 entry.EventLogLevel = LoggerHelper.GetEventLogLevel(logLevel);
                 entry.CorrelationId = _correlationId;
-                entry.Message = LoggerHelper.FormatLogMessage(messageWithPii, messageScrubbed, PiiLoggingEnabled, _correlationId, _clientInfo);
-                _identityLogger.Log(entry);
+                entry.Message = messageToLog;
+                MsalIdentityLogger.Log(entry);
             }
         }
 
         public bool IsLoggingEnabled(LogLevel logLevel)
         {
-            return _identityLogger.IsEnabled(LoggerHelper.GetEventLogLevel(logLevel));
+            return MsalIdentityLogger.IsEnabled(LoggerHelper.GetEventLogLevel(logLevel));
         }
 
         public DurationLogHelper LogBlockDuration(string measuredBlockName, LogLevel logLevel = LogLevel.Verbose)

src/client/Microsoft.Identity.Client/Internal/Logger/LegacyIdentityLoggerAdapter.cs

@@ -5,14 +5,13 @@
 using System.Diagnostics.Tracing;
 using System.Runtime.CompilerServices;
 using Microsoft.Identity.Client.Core;
+using Microsoft.IdentityModel.Abstractions;
 
 namespace Microsoft.Identity.Client.Internal.Logger
 {
     internal class LegacyIdentityLoggerAdapter : ILoggerAdapter
     {
         LogLevel _minLogLevel = LogLevel.Always;
-        LogCallback _logCallback;
-        private string _clientInfo;
         private string _correlationId;
 
         public bool PiiLoggingEnabled { get; }
@@ -21,9 +20,11 @@ internal class LegacyIdentityLoggerAdapter : ILoggerAdapter
         public string ClientName { get; }
         public string ClientVersion { get; }
 
+        public IIdentityLogger MsalIdentityLogger { get; }
+
         public bool IsLoggingEnabled(LogLevel logLevel)
         {
-            return _logCallback != null && logLevel <= _minLogLevel;
+            return MsalIdentityLogger.IsEnabled(LoggerHelper.GetEventLogLevel(logLevel));
         }
 
         internal LegacyIdentityLoggerAdapter(
@@ -41,20 +42,25 @@ internal LegacyIdentityLoggerAdapter(
                     ? string.Empty
                     : " - " + correlationId;
 
-            _clientInfo = LoggerHelper.GetClientInfo(clientName, clientVersion);
-
             PiiLoggingEnabled = enablePiiLogging;
-            _logCallback = loggingCallback;
             _minLogLevel = logLevel;
             IsDefaultPlatformLoggingEnabled = isDefaultPlatformLoggingEnabled;
+            MsalIdentityLogger = new MsalLegacyIdentityLogger(loggingCallback, correlationId, clientName, clientVersion, enablePiiLogging, logLevel);
         }
 
         public void Log(LogLevel logLevel, string messageWithPii, string messageScrubbed)
         {
             if (IsLoggingEnabled(logLevel))
             {
-                string message = LoggerHelper.FormatLogMessage(messageWithPii, messageScrubbed, PiiLoggingEnabled, _correlationId, _clientInfo);
-                _logCallback.Invoke(logLevel, message, !string.IsNullOrEmpty(messageWithPii) ? true : false);
+                string messageToLog = LoggerHelper.GetMessageToLog(messageWithPii, messageScrubbed, PiiLoggingEnabled);
+
+                LogEntry entry = new LogEntry();
+                entry.EventLogLevel = LoggerHelper.GetEventLogLevel(logLevel);
+                entry.CorrelationId = _correlationId;
+                entry.Message = messageToLog;
+                MsalIdentityLogger.Log(entry);
+                //string message = LoggerHelper.FormatLogMessage(messageToLog, PiiLoggingEnabled, _correlationId, _clientInfo);
+                //_logCallback.Invoke(logLevel, message, !string.IsNullOrEmpty(messageWithPii) ? true : false);
             }
         }
 

src/client/Microsoft.Identity.Client/Internal/Logger/LoggerHelper.cs

@@ -78,25 +78,25 @@ public static ILoggerAdapter CreateLogger(
             return "Unknown SKU";
         });
 
-        public static string FormatLogMessage(string messageWithPii, string messageScrubbed, bool piiEnabled, string correlationId, string clientInformation)
+        public static string FormatLogMessage(string message, bool piiEnabled, string correlationId, string clientInformation)
         {
-            bool messageWithPiiExists = !string.IsNullOrWhiteSpace(messageWithPii);
-            // If we have a message with PII, and PII logging is enabled, use the PII message, else use the scrubbed message.
-            bool isLoggingPii = messageWithPiiExists && piiEnabled;
-            string messageToLog = isLoggingPii ? messageWithPii : messageScrubbed;
+            //bool messageWithPiiExists = !string.IsNullOrWhiteSpace(messageWithPii);
+            //// If we have a message with PII, and PII logging is enabled, use the PII message, else use the scrubbed message.
+            //bool isLoggingPii = messageWithPiiExists && piiEnabled;
+            //string messageToLog = isLoggingPii ? messageWithPii : messageScrubbed;
 
             return string.Format(
                 CultureInfo.InvariantCulture,
                 "{0} MSAL {1} {2} {3} {4} [{5}{6}]{7} {8}",
-                isLoggingPii,
+                piiEnabled,
                 s_msalVersionLazy.Value,
                 s_skuLazy.Value,
                 s_runtimeVersionLazy.Value,
                 s_osLazy.Value,
                 DateTime.UtcNow.ToString("u"),
                 correlationId,
                 clientInformation,
-                messageToLog);
+                message);
         }
 
         internal static string GetPiiScrubbedExceptionDetails(Exception ex)
@@ -154,5 +154,13 @@ public static EventLogLevel GetEventLogLevel(LogLevel logLevel)
 
             return (EventLogLevel)((int)logLevel + 2);
         }
+
+        public static string GetMessageToLog(string messageWithPii, string messageScrubbed, bool piiLoggingEnabled)
+        {
+            bool messageWithPiiExists = !string.IsNullOrWhiteSpace(messageWithPii);
+            // If we have a message with PII, and PII logging is enabled, use the PII message, else use the scrubbed message.
+            bool isLoggingPii = messageWithPiiExists && piiLoggingEnabled;
+            return isLoggingPii ? messageWithPii : messageScrubbed;
+        }
     }
 }

src/client/Microsoft.Identity.Client/Internal/Logger/MsalIdentityLogger.cs

@@ -0,0 +1,45 @@
+// Copyright (c) Microsoft Corporation. All rights reserved.
+// Licensed under the MIT License.
+
+using System;
+using Microsoft.IdentityModel.Abstractions;
+
+namespace Microsoft.Identity.Client.Internal.Logger
+{
+#if !XAMARINMAC20
+    //This class is used to wrap the functionality of the configured IIdentityLogger to add additional MSAL client information when logging messages.
+    internal class MsalIdentityLogger : IIdentityLogger
+    {
+        private readonly IIdentityLogger _identityLogger;
+        private readonly string _correlationId;
+        private readonly string _clientInformation;
+        private readonly bool _piiLoggingEnabled;
+
+        internal MsalIdentityLogger(IIdentityLogger identityLogger, Guid correlationId, string clientName, string clientVersion, bool enablePiiLogging)
+        {
+            _identityLogger = identityLogger;
+            _correlationId = correlationId.Equals(Guid.Empty)
+                ? string.Empty
+                : " - " + correlationId;
+            _clientInformation = LoggerHelper.GetClientInfo(clientName, clientVersion);
+            _piiLoggingEnabled = enablePiiLogging;
+        }
+
+        public bool IsEnabled(EventLogLevel eventLevel)
+        {
+            return _identityLogger.IsEnabled(eventLevel);
+        }
+
+        public void Log(LogEntry entry)
+        {
+            entry.Message = LoggerHelper.FormatLogMessage(
+                                            entry.Message, 
+                                            _piiLoggingEnabled, 
+                                            string.IsNullOrEmpty(entry.CorrelationId) ? entry.CorrelationId : _correlationId, 
+                                            _clientInformation);
+
+            _identityLogger.Log(entry);
+        }
+    }
+#endif
+}

src/client/Microsoft.Identity.Client/Internal/Logger/MsalLegacyIdentityLogger.cs

@@ -0,0 +1,64 @@
+// Copyright (c) Microsoft Corporation. All rights reserved.
+// Licensed under the MIT License.
+
+using System;
+using System.Collections.Generic;
+using System.Linq;
+using System.Text;
+using System.Threading.Tasks;
+using Microsoft.IdentityModel.Abstractions;
+
+namespace Microsoft.Identity.Client.Internal.Logger
+{
+    internal class MsalLegacyIdentityLogger : IIdentityLogger
+    {
+        private LogCallback _logCallback;
+        private readonly string _correlationId;
+        private readonly string _clientInformation;
+        private readonly bool _piiLoggingEnabled;
+        private readonly LogLevel _minLogLevel;
+
+        public MsalLegacyIdentityLogger(
+            LogCallback logCallback,
+            Guid correlationId,
+            string clientName,
+            string clientVersion,
+            bool enablePiiLogging,
+            LogLevel minLogLevel)
+        {
+            _correlationId = correlationId.Equals(Guid.Empty)
+                ? string.Empty
+                : " - " + correlationId;
+            _clientInformation = LoggerHelper.GetClientInfo(clientName, clientVersion);
+            _piiLoggingEnabled = enablePiiLogging;
+            _logCallback = logCallback;
+            _minLogLevel = minLogLevel;
+        }
+
+        public bool IsEnabled(EventLogLevel eventLevel)
+        {
+            return _logCallback != null && GetLogLevel(eventLevel) <= _minLogLevel;
+        }
+
+        public void Log(LogEntry entry)
+        {
+            string formattedMessage = LoggerHelper.FormatLogMessage(
+                                            entry.Message,
+                                            _piiLoggingEnabled,
+                                            string.IsNullOrEmpty(entry.CorrelationId) ? entry.CorrelationId : _correlationId,
+                                            _clientInformation);
+
+            _logCallback.Invoke(GetLogLevel(entry.EventLogLevel), formattedMessage, _piiLoggingEnabled);
+        }
+
+        private LogLevel GetLogLevel(EventLogLevel eventLogLevel)
+        {
+            //MSAL does not have a critical log level so it is combined with the error level
+            if (eventLogLevel == EventLogLevel.LogAlways)
+            {
+                return LogLevel.Always;
+            }
+            return (LogLevel)((int)eventLogLevel - 2);
+        }
+    }
+}

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

@@ -167,7 +167,9 @@ async Task<Tuple<MsalAccessTokenCacheItem, MsalIdTokenCacheItem, Account>> IToke
                             cancellationToken: requestParams.RequestContext.UserCancellationToken,
                             correlationId: requestParams.RequestContext.CorrelationId, 
                             requestScopes: requestParams.Scope,
-                            requestTenantId: requestParams.AuthorityManager.OriginalAuthority.TenantId);
+                            requestTenantId: requestParams.AuthorityManager.OriginalAuthority.TenantId,
+                            msalIdentityLogger: requestParams.RequestContext.Logger.MsalIdentityLogger,
+                            piiLoggingEnabled: requestParams.RequestContext.Logger.PiiLoggingEnabled);
 
                         Stopwatch sw = Stopwatch.StartNew();
 
@@ -237,8 +239,9 @@ async Task<Tuple<MsalAccessTokenCacheItem, MsalIdTokenCacheItem, Account>> IToke
                             cancellationToken: requestParams.RequestContext.UserCancellationToken,
                             correlationId: requestParams.RequestContext.CorrelationId, 
                             requestScopes: requestParams.Scope,
-                            requestTenantId: requestParams.AuthorityManager.OriginalAuthority.TenantId);
-
+                            requestTenantId: requestParams.AuthorityManager.OriginalAuthority.TenantId,
+                            msalIdentityLogger: requestParams.RequestContext.Logger.MsalIdentityLogger,
+                            piiLoggingEnabled: requestParams.RequestContext.Logger.PiiLoggingEnabled);
 
                         Stopwatch sw = Stopwatch.StartNew();
                         await tokenCacheInternal.OnAfterAccessAsync(args).ConfigureAwait(false);
@@ -728,7 +731,9 @@ internal async Task ExpireAllAccessTokensForTestAsync()
                             cancellationToken: default,
                             correlationId: default,
                             requestScopes: null,
-                            requestTenantId: null);
+                            requestTenantId: null,
+                            msalIdentityLogger: null,
+                            piiLoggingEnabled: false);
 
                 await tokenCacheInternal.OnAfterAccessAsync(args).ConfigureAwait(false);
             }
@@ -1147,7 +1152,9 @@ async Task ITokenCacheInternal.RemoveAccountAsync(IAccount account, Authenticati
                             cancellationToken: requestParameters.RequestContext.UserCancellationToken,
                             correlationId: requestParameters.RequestContext.CorrelationId,
                             requestScopes: requestParameters.Scope,
-                            requestTenantId: requestParameters.AuthorityManager.OriginalAuthority.TenantId);
+                            requestTenantId: requestParameters.AuthorityManager.OriginalAuthority.TenantId,
+                            msalIdentityLogger: requestParameters.RequestContext.Logger.MsalIdentityLogger,
+                            piiLoggingEnabled: requestParameters.RequestContext.Logger.PiiLoggingEnabled);
 
 
                         await tokenCacheInternal.OnBeforeAccessAsync(args).ConfigureAwait(false);
@@ -1181,7 +1188,9 @@ async Task ITokenCacheInternal.RemoveAccountAsync(IAccount account, Authenticati
                            cancellationToken: requestParameters.RequestContext.UserCancellationToken,
                            correlationId: requestParameters.RequestContext.CorrelationId,
                            requestScopes: requestParameters.Scope,
-                           requestTenantId: requestParameters.AuthorityManager.OriginalAuthority.TenantId);
+                           requestTenantId: requestParameters.AuthorityManager.OriginalAuthority.TenantId,
+                           msalIdentityLogger: requestParameters.RequestContext.Logger.MsalIdentityLogger,
+                            piiLoggingEnabled: requestParameters.RequestContext.Logger.PiiLoggingEnabled);
 
 
                         await tokenCacheInternal.OnAfterAccessAsync(args).ConfigureAwait(false);