From f5ad8c6855db5c26e4cc33764aef74985539c0c6 Mon Sep 17 00:00:00 2001 From: James Newton-King Date: Mon, 3 Jul 2023 12:54:04 +0800 Subject: [PATCH 1/5] Improve LoggerFactory debugging --- .../src/LoggerFactory.cs | 16 ++++++++++++++ .../src/LoggerFactoryOptions.cs | 3 ++- .../src/LoggerFilterOptions.cs | 22 +++++++++++++++++++ 3 files changed, 40 insertions(+), 1 deletion(-) diff --git a/src/libraries/Microsoft.Extensions.Logging/src/LoggerFactory.cs b/src/libraries/Microsoft.Extensions.Logging/src/LoggerFactory.cs index 305860f6e9161..96c966e43a319 100644 --- a/src/libraries/Microsoft.Extensions.Logging/src/LoggerFactory.cs +++ b/src/libraries/Microsoft.Extensions.Logging/src/LoggerFactory.cs @@ -4,7 +4,9 @@ using System; using System.Collections.Concurrent; using System.Collections.Generic; +using System.Diagnostics; using System.Diagnostics.CodeAnalysis; +using System.Linq; using Microsoft.Extensions.DependencyInjection; using Microsoft.Extensions.Options; @@ -13,6 +15,8 @@ namespace Microsoft.Extensions.Logging /// /// Produces instances of classes based on the given providers. /// + [DebuggerDisplay("{DebuggerToString(),nq}")] + [DebuggerTypeProxy(typeof(LoggerFactoryDebugView))] public class LoggerFactory : ILoggerFactory { private readonly ConcurrentDictionary _loggers = new ConcurrentDictionary(StringComparer.Ordinal); @@ -314,5 +318,17 @@ public void AddProvider(ILoggerProvider provider) _loggerFactory.AddProvider(provider); } } + + private string DebuggerToString() + { + return $"Providers = {_providerRegistrations.Count}"; + } + + internal sealed class LoggerFactoryDebugView(LoggerFactory loggerFactory) + { + public List Providers => loggerFactory._providerRegistrations.Select(r => r.Provider).ToList(); + public bool Disposed => loggerFactory._disposed; + public LoggerFilterOptions FilterOptions => loggerFactory._filterOptions; + } } } diff --git a/src/libraries/Microsoft.Extensions.Logging/src/LoggerFactoryOptions.cs b/src/libraries/Microsoft.Extensions.Logging/src/LoggerFactoryOptions.cs index fbc0e2f46e114..996f08cf264e0 100644 --- a/src/libraries/Microsoft.Extensions.Logging/src/LoggerFactoryOptions.cs +++ b/src/libraries/Microsoft.Extensions.Logging/src/LoggerFactoryOptions.cs @@ -1,13 +1,14 @@ // Licensed to the .NET Foundation under one or more agreements. // The .NET Foundation licenses this file to you under the MIT license. -using System.Collections.Generic; +using System.Diagnostics; namespace Microsoft.Extensions.Logging { /// /// The options for a LoggerFactory. /// + [DebuggerDisplay("ActivityTrackingOptions = {ActivityTrackingOptions}")] public class LoggerFactoryOptions { /// diff --git a/src/libraries/Microsoft.Extensions.Logging/src/LoggerFilterOptions.cs b/src/libraries/Microsoft.Extensions.Logging/src/LoggerFilterOptions.cs index 3c8165e4d2371..24ea2b3230f45 100644 --- a/src/libraries/Microsoft.Extensions.Logging/src/LoggerFilterOptions.cs +++ b/src/libraries/Microsoft.Extensions.Logging/src/LoggerFilterOptions.cs @@ -2,12 +2,14 @@ // The .NET Foundation licenses this file to you under the MIT license. using System.Collections.Generic; +using System.Diagnostics; namespace Microsoft.Extensions.Logging { /// /// The options for a LoggerFilter. /// + [DebuggerDisplay("{DebuggerToString(),nq}")] public class LoggerFilterOptions { /// @@ -32,5 +34,25 @@ public LoggerFilterOptions() { } // Concrete representation of the rule list internal List RulesInternal { get; } = new List(); + + private string DebuggerToString() + { + string debugText = $"Rules = {Rules.Count}"; + if (MinLevel != LogLevel.None) + { + debugText += $", MinLevel = {MinLevel}"; + } + else + { + // Display "Enabled = false". This makes it clear that the entire ILogger + // is disabled and nothing is written. + // + // If "MinLevel = None" was displayed then someone could think that the + // min level is disabled and everything is written. + debugText += $", Enabled = false"; + } + + return debugText; + } } } From e6ab1add3c16a2f664241a5a2e9f07c4e66aa541 Mon Sep 17 00:00:00 2001 From: James Newton-King Date: Mon, 3 Jul 2023 14:44:37 +0800 Subject: [PATCH 2/5] Improve LoggerFactory and Logger debugging --- .../Logging/DebuggerDisplayFormatting.cs | 41 ++++---- .../src/Logger.cs | 98 ++++++++++++++++++- .../src/LoggerFactory.cs | 4 +- .../src/LoggerFilterOptions.cs | 2 +- .../src/LoggerInformation.cs | 4 +- 5 files changed, 124 insertions(+), 25 deletions(-) diff --git a/src/libraries/Common/src/Extensions/Logging/DebuggerDisplayFormatting.cs b/src/libraries/Common/src/Extensions/Logging/DebuggerDisplayFormatting.cs index 6b82ecbab5309..a72def069cbe1 100644 --- a/src/libraries/Common/src/Extensions/Logging/DebuggerDisplayFormatting.cs +++ b/src/libraries/Common/src/Extensions/Logging/DebuggerDisplayFormatting.cs @@ -8,6 +8,28 @@ namespace Microsoft.Extensions.Logging internal static class DebuggerDisplayFormatting { internal static string DebuggerToString(string name, ILogger logger) + { + LogLevel? minimumLevel = CalculateEnabledLogLevel(logger); + + var debugText = $@"Name = ""{name}"""; + if (minimumLevel != null) + { + debugText += $", MinLevel = {minimumLevel}"; + } + else + { + // Display "Enabled = false". This makes it clear that the entire ILogger + // is disabled and nothing is written. + // + // If "MinLevel = None" was displayed then someone could think that the + // min level is disabled and everything is written. + debugText += $", Enabled = false"; + } + + return debugText; + } + + internal static LogLevel? CalculateEnabledLogLevel(ILogger logger) { ReadOnlySpan logLevels = stackalloc LogLevel[] { @@ -19,7 +41,7 @@ internal static string DebuggerToString(string name, ILogger logger) LogLevel.Trace, }; - LogLevel minimumLevel = LogLevel.None; + LogLevel? minimumLevel = null; // Check log level from highest to lowest. Report the lowest log level. foreach (LogLevel logLevel in logLevels) @@ -32,22 +54,7 @@ internal static string DebuggerToString(string name, ILogger logger) minimumLevel = logLevel; } - var debugText = $@"Name = ""{name}"""; - if (minimumLevel != LogLevel.None) - { - debugText += $", MinLevel = {minimumLevel}"; - } - else - { - // Display "Enabled = false". This makes it clear that the entire ILogger - // is disabled and nothing is written. - // - // If "MinLevel = None" was displayed then someone could think that the - // min level is disabled and everything is written. - debugText += $", Enabled = false"; - } - - return debugText; + return minimumLevel; } } } diff --git a/src/libraries/Microsoft.Extensions.Logging/src/Logger.cs b/src/libraries/Microsoft.Extensions.Logging/src/Logger.cs index 1bed6fb67b146..52b707cd563ad 100644 --- a/src/libraries/Microsoft.Extensions.Logging/src/Logger.cs +++ b/src/libraries/Microsoft.Extensions.Logging/src/Logger.cs @@ -4,10 +4,13 @@ using System; using System.Collections.Generic; using System.Diagnostics; +using System.Linq; +using System.Xml.Linq; namespace Microsoft.Extensions.Logging { [DebuggerDisplay("{DebuggerToString(),nq}")] + [DebuggerTypeProxy(typeof(LoggerDebugView))] internal sealed class Logger : ILogger { private readonly string _categoryName; @@ -150,15 +153,104 @@ static bool LoggerIsEnabled(LogLevel logLevel, ILogger logger, ref List exceptions) + { + throw new AggregateException( + message: "An error occurred while writing to logger(s).", innerExceptions: exceptions); + } + internal string DebuggerToString() { return DebuggerDisplayFormatting.DebuggerToString(_categoryName, this); } - private static void ThrowLoggingError(List exceptions) + private sealed class LoggerDebugView(Logger logger) { - throw new AggregateException( - message: "An error occurred while writing to logger(s).", innerExceptions: exceptions); + public string Name => logger._categoryName; + + // The list of providers includes the full list of configured providers from the logger factory. + // It then mentions the min level and enable status of each provider for this logger. + public List Providers + { + get + { + List providers = new List(); + for (int i = 0; i < logger.Loggers.Length; i++) + { + LoggerInformation loggerInfo = logger.Loggers[i]; + string providerName = ProviderAliasUtilities.GetAlias(loggerInfo.ProviderType) ?? loggerInfo.ProviderType.Name; + MessageLogger? messageLogger = logger.MessageLoggers?.FirstOrDefault(messageLogger => messageLogger.Logger == loggerInfo.Logger); + + providers.Add(new LoggerProviderDebugView(providerName, messageLogger)); + } + + return providers; + } + } + + public LogLevel? MinLevel => DebuggerDisplayFormatting.CalculateEnabledLogLevel(logger); + + public bool Enabled => DebuggerDisplayFormatting.CalculateEnabledLogLevel(logger) != null; + } + + [DebuggerDisplay("{DebuggerToString(),nq}")] + private sealed class LoggerProviderDebugView(string providerName, MessageLogger? messageLogger) + { + public string Name => providerName; + public LogLevel? LogLevel => CalculateEnabledLogLevel(messageLogger); + public bool Enabled => CalculateEnabledLogLevel(messageLogger) != null; + + private static LogLevel? CalculateEnabledLogLevel(MessageLogger? logger) + { + if (logger == null) + { + return null; + } + + ReadOnlySpan logLevels = stackalloc LogLevel[] + { + Logging.LogLevel.Critical, + Logging.LogLevel.Error, + Logging.LogLevel.Warning, + Logging.LogLevel.Information, + Logging.LogLevel.Debug, + Logging.LogLevel.Trace, + }; + + LogLevel? minimumLevel = null; + + // Check log level from highest to lowest. Report the lowest log level. + foreach (LogLevel logLevel in logLevels) + { + if (!logger.Value.IsEnabled(logLevel)) + { + break; + } + + minimumLevel = logLevel; + } + + return minimumLevel; + } + + private string DebuggerToString() + { + var debugText = $@"Name = ""{providerName}"""; + if (LogLevel != null) + { + debugText += $", LogLevel = {LogLevel}"; + } + else + { + // Display "Enabled = false". This makes it clear that the entire ILogger + // is disabled and nothing is written. + // + // If "MinLevel = None" was displayed then someone could think that the + // min level is disabled and everything is written. + debugText += $", Enabled = false"; + } + return debugText; + } } private sealed class Scope : IDisposable diff --git a/src/libraries/Microsoft.Extensions.Logging/src/LoggerFactory.cs b/src/libraries/Microsoft.Extensions.Logging/src/LoggerFactory.cs index 96c966e43a319..2cb0994acc167 100644 --- a/src/libraries/Microsoft.Extensions.Logging/src/LoggerFactory.cs +++ b/src/libraries/Microsoft.Extensions.Logging/src/LoggerFactory.cs @@ -321,10 +321,10 @@ public void AddProvider(ILoggerProvider provider) private string DebuggerToString() { - return $"Providers = {_providerRegistrations.Count}"; + return $"Providers = {_providerRegistrations.Count}, {_filterOptions.DebuggerToString()}"; } - internal sealed class LoggerFactoryDebugView(LoggerFactory loggerFactory) + private sealed class LoggerFactoryDebugView(LoggerFactory loggerFactory) { public List Providers => loggerFactory._providerRegistrations.Select(r => r.Provider).ToList(); public bool Disposed => loggerFactory._disposed; diff --git a/src/libraries/Microsoft.Extensions.Logging/src/LoggerFilterOptions.cs b/src/libraries/Microsoft.Extensions.Logging/src/LoggerFilterOptions.cs index 24ea2b3230f45..41e86e63be2d1 100644 --- a/src/libraries/Microsoft.Extensions.Logging/src/LoggerFilterOptions.cs +++ b/src/libraries/Microsoft.Extensions.Logging/src/LoggerFilterOptions.cs @@ -35,7 +35,7 @@ public LoggerFilterOptions() { } // Concrete representation of the rule list internal List RulesInternal { get; } = new List(); - private string DebuggerToString() + internal string DebuggerToString() { string debugText = $"Rules = {Rules.Count}"; if (MinLevel != LogLevel.None) diff --git a/src/libraries/Microsoft.Extensions.Logging/src/LoggerInformation.cs b/src/libraries/Microsoft.Extensions.Logging/src/LoggerInformation.cs index 1a0a01acdcb3b..92ba4775dbb87 100644 --- a/src/libraries/Microsoft.Extensions.Logging/src/LoggerInformation.cs +++ b/src/libraries/Microsoft.Extensions.Logging/src/LoggerInformation.cs @@ -8,7 +8,7 @@ namespace Microsoft.Extensions.Logging { internal readonly struct MessageLogger { - public MessageLogger(ILogger logger, string? category, string? providerTypeFullName, LogLevel? minLevel, Func? filter) + public MessageLogger(ILogger logger, string category, string? providerTypeFullName, LogLevel? minLevel, Func? filter) { Logger = logger; Category = category; @@ -19,7 +19,7 @@ public MessageLogger(ILogger logger, string? category, string? providerTypeFullN public ILogger Logger { get; } - public string? Category { get; } + public string Category { get; } private string? ProviderTypeFullName { get; } From 3f60a3af5e3f5e806029d06704247fea3f74446d Mon Sep 17 00:00:00 2001 From: James Newton-King Date: Mon, 3 Jul 2023 15:07:25 +0800 Subject: [PATCH 3/5] Clean up --- src/libraries/Microsoft.Extensions.Logging/src/Logger.cs | 1 - 1 file changed, 1 deletion(-) diff --git a/src/libraries/Microsoft.Extensions.Logging/src/Logger.cs b/src/libraries/Microsoft.Extensions.Logging/src/Logger.cs index 52b707cd563ad..f24ba6f3daf8e 100644 --- a/src/libraries/Microsoft.Extensions.Logging/src/Logger.cs +++ b/src/libraries/Microsoft.Extensions.Logging/src/Logger.cs @@ -5,7 +5,6 @@ using System.Collections.Generic; using System.Diagnostics; using System.Linq; -using System.Xml.Linq; namespace Microsoft.Extensions.Logging { From c438778418039b956cd900d8026394bdc7493259 Mon Sep 17 00:00:00 2001 From: James Newton-King Date: Mon, 3 Jul 2023 21:43:38 +0800 Subject: [PATCH 4/5] Add scopes --- .../src/Logger.cs | 46 +++++++++---------- .../src/LoggerFilterOptions.cs | 11 +++-- 2 files changed, 30 insertions(+), 27 deletions(-) diff --git a/src/libraries/Microsoft.Extensions.Logging/src/Logger.cs b/src/libraries/Microsoft.Extensions.Logging/src/Logger.cs index f24ba6f3daf8e..bd751d3e299fc 100644 --- a/src/libraries/Microsoft.Extensions.Logging/src/Logger.cs +++ b/src/libraries/Microsoft.Extensions.Logging/src/Logger.cs @@ -186,9 +186,22 @@ public List Providers return providers; } } + public List? Scopes + { + get + { + var scopeProvider = logger.ScopeLoggers?.FirstOrDefault().ExternalScopeProvider; + if (scopeProvider == null) + { + return null; + } + List scopes = new List(); + scopeProvider.ForEachScope((scope, scopes) => scopes!.Add(scope), scopes); + return scopes; + } + } public LogLevel? MinLevel => DebuggerDisplayFormatting.CalculateEnabledLogLevel(logger); - public bool Enabled => DebuggerDisplayFormatting.CalculateEnabledLogLevel(logger) != null; } @@ -196,8 +209,7 @@ public List Providers private sealed class LoggerProviderDebugView(string providerName, MessageLogger? messageLogger) { public string Name => providerName; - public LogLevel? LogLevel => CalculateEnabledLogLevel(messageLogger); - public bool Enabled => CalculateEnabledLogLevel(messageLogger) != null; + public LogLevel LogLevel => CalculateEnabledLogLevel(messageLogger) ?? LogLevel.None; private static LogLevel? CalculateEnabledLogLevel(MessageLogger? logger) { @@ -208,12 +220,12 @@ private sealed class LoggerProviderDebugView(string providerName, MessageLogger? ReadOnlySpan logLevels = stackalloc LogLevel[] { - Logging.LogLevel.Critical, - Logging.LogLevel.Error, - Logging.LogLevel.Warning, - Logging.LogLevel.Information, - Logging.LogLevel.Debug, - Logging.LogLevel.Trace, + LogLevel.Critical, + LogLevel.Error, + LogLevel.Warning, + LogLevel.Information, + LogLevel.Debug, + LogLevel.Trace, }; LogLevel? minimumLevel = null; @@ -234,21 +246,7 @@ private sealed class LoggerProviderDebugView(string providerName, MessageLogger? private string DebuggerToString() { - var debugText = $@"Name = ""{providerName}"""; - if (LogLevel != null) - { - debugText += $", LogLevel = {LogLevel}"; - } - else - { - // Display "Enabled = false". This makes it clear that the entire ILogger - // is disabled and nothing is written. - // - // If "MinLevel = None" was displayed then someone could think that the - // min level is disabled and everything is written. - debugText += $", Enabled = false"; - } - return debugText; + return $@"Name = ""{providerName}"", LogLevel = {LogLevel}"; } } diff --git a/src/libraries/Microsoft.Extensions.Logging/src/LoggerFilterOptions.cs b/src/libraries/Microsoft.Extensions.Logging/src/LoggerFilterOptions.cs index 41e86e63be2d1..b19970ca64c16 100644 --- a/src/libraries/Microsoft.Extensions.Logging/src/LoggerFilterOptions.cs +++ b/src/libraries/Microsoft.Extensions.Logging/src/LoggerFilterOptions.cs @@ -37,10 +37,10 @@ public LoggerFilterOptions() { } internal string DebuggerToString() { - string debugText = $"Rules = {Rules.Count}"; + string debugText; if (MinLevel != LogLevel.None) { - debugText += $", MinLevel = {MinLevel}"; + debugText = $"MinLevel = {MinLevel}"; } else { @@ -49,7 +49,12 @@ internal string DebuggerToString() // // If "MinLevel = None" was displayed then someone could think that the // min level is disabled and everything is written. - debugText += $", Enabled = false"; + debugText = $"Enabled = false"; + } + + if (Rules.Count > 0) + { + debugText += $", Rules = {Rules.Count}"; } return debugText; From f6030ad3bb6dd23361face896d68525c3cf74291 Mon Sep 17 00:00:00 2001 From: James Newton-King Date: Tue, 4 Jul 2023 06:44:29 +0800 Subject: [PATCH 5/5] Update src/libraries/Microsoft.Extensions.Logging/src/Logger.cs --- src/libraries/Microsoft.Extensions.Logging/src/Logger.cs | 1 + 1 file changed, 1 insertion(+) diff --git a/src/libraries/Microsoft.Extensions.Logging/src/Logger.cs b/src/libraries/Microsoft.Extensions.Logging/src/Logger.cs index bd751d3e299fc..1443230297fbb 100644 --- a/src/libraries/Microsoft.Extensions.Logging/src/Logger.cs +++ b/src/libraries/Microsoft.Extensions.Logging/src/Logger.cs @@ -186,6 +186,7 @@ public List Providers return providers; } } + public List? Scopes { get