Fix default logging filters - rely on LoggerFilterOptions (#2223)

src/Azure.Functions.Cli/Actions/HostActions/StartHostAction.cs

@@ -182,8 +182,16 @@ private async Task<IWebHost> BuildWebHost(ScriptApplicationHostOptions hostOptio
                 .ConfigureLogging(loggingBuilder =>
                 {
                     loggingBuilder.ClearProviders();
+                    loggingBuilder.Services.AddSingleton<ILoggerProvider>(p =>
+                    {
+                        //Cache LoggerFilterOptions to be used by the logger to filter logs based on content
+                        var filterOptions = p.GetService<IOptions<LoggerFilterOptions>>().Value;
+                        // Set min level to SystemLogDefaultLogLevel.
+                        filterOptions.MinLevel = loggingFilterHelper.SystemLogDefaultLogLevel;
+                        return new ColoredConsoleLoggerProvider(loggingFilterHelper, filterOptions);
+                    });
                     // This is needed to filter system logs only for known categories
-                    loggingBuilder.AddFilter<ColoredConsoleLoggerProvider>((category, level) => Utilities.SystemLoggingFilter(category, level, LogLevel.Trace)).AddProvider(new ColoredConsoleLoggerProvider(loggingFilterHelper));
+                    loggingBuilder.AddDefaultWebJobsFilters<ColoredConsoleLoggerProvider>(LogLevel.Trace);
                 })
                 .ConfigureServices((context, services) => services.AddSingleton<IStartup>(new Startup(context, hostOptions, CorsOrigins, CorsCredentials, EnableAuth, loggingFilterHelper)))
                 .Build();

src/Azure.Functions.Cli/Actions/HostActions/Startup.cs

@@ -1,5 +1,4 @@
 using System;
-using System.Collections.Generic;
 using Azure.Functions.Cli.Actions.HostActions.WebHost.Security;
 using Azure.Functions.Cli.Diagnostics;
 using Azure.Functions.Cli.ExtensionBundle;
@@ -16,6 +15,7 @@
 using Microsoft.Extensions.Configuration;
 using Microsoft.Extensions.DependencyInjection;
 using Microsoft.Extensions.Logging;
+using Microsoft.Extensions.Options;
 
 namespace Azure.Functions.Cli.Actions.HostActions
 {
@@ -78,13 +78,13 @@ public IServiceProvider ConfigureServices(IServiceCollection services)
                 o.IsSelfHost = _hostOptions.IsSelfHost;
                 o.SecretsPath = _hostOptions.SecretsPath;
             });
-
+            
             services.AddSingleton<IConfigureBuilder<IConfigurationBuilder>>(_ => new ExtensionBundleConfigurationBuilder(_hostOptions));
             services.AddSingleton<IConfigureBuilder<IConfigurationBuilder>, DisableConsoleConfigurationBuilder>();
             services.AddSingleton<IConfigureBuilder<ILoggingBuilder>>(_ => new LoggingBuilder(_loggingFilterHelper));
             if (GlobalCoreToolsSettings.CurrentWorkerRuntime == WorkerRuntime.dotnet)
             {
-                services.AddSingleton<IConfigureBuilder<IConfigurationBuilder>>(_ => new UserSecretsConfigurationBuilder(_hostOptions.ScriptPath, _loggingFilterHelper));
+                services.AddSingleton<IConfigureBuilder<IConfigurationBuilder>>((provider) => new UserSecretsConfigurationBuilder(_hostOptions.ScriptPath, _loggingFilterHelper, provider.GetService<IOptions<LoggerFilterOptions>>().Value));
             }
 
             services.AddSingleton<IDependencyValidator, ThrowingDependencyValidator>();

src/Azure.Functions.Cli/Common/Utilities.cs

@@ -24,13 +24,6 @@ internal static class Utilities
     {
         public const string LogLevelSection = "loglevel";
         public const string LogLevelDefaultSection = "Default";
-        internal static readonly string[] SystemCategoryPrefixes = new[]
-        {
-            "Microsoft.Azure.WebJobs.",
-            "Function.",
-            "Worker.",
-            "Host."
-        };
 
         internal static void PrintLogo()
         {
@@ -189,36 +182,20 @@ internal static string EnsureCoreToolsLocalData()
             return localPath;
         }
 
-        internal static LogLevel GetHostJsonDefaultLogLevel(IConfigurationRoot hostJsonConfig)
-        {
-            string defaultLogLevelKey = ConfigurationPath.Combine(ConfigurationSectionNames.JobHost, ConfigurationSectionNames.Logging, LogLevelSection, LogLevelDefaultSection);
-            try
-            {
-                if (Enum.TryParse(typeof(LogLevel), hostJsonConfig[defaultLogLevelKey].ToString(), true, out object outLevel))
-                {
-                    return (LogLevel)outLevel;
-                }
-            }
-            catch
-            {
-            }
-            // Default log level
-            return LogLevel.Information;
-        }
-
-        internal static bool LogLevelExists(IConfigurationRoot hostJsonConfig, string category)
+        internal static bool LogLevelExists(IConfigurationRoot hostJsonConfig, string category, out LogLevel outLogLevel)
         {
             string categoryKey = ConfigurationPath.Combine(ConfigurationSectionNames.JobHost, ConfigurationSectionNames.Logging, LogLevelSection, category);
             try
             {
-                if (Enum.TryParse(typeof(LogLevel), hostJsonConfig[categoryKey], true, out object outLevel))
+                if (Enum.TryParse(hostJsonConfig[categoryKey], true, out outLogLevel))
                 {
                     return true;
                 }
             }
             catch 
             { 
             }
+            outLogLevel = LogLevel.Information;
             return false;
         }
 
@@ -247,7 +224,9 @@ internal static bool JobHostConfigSectionExists(IConfigurationRoot hostJsonConfi
         /// <returns></returns>
         internal static bool DefaultLoggingFilter(string category, LogLevel actualLevel, LogLevel userLogMinLevel, LogLevel systemLogMinLevel)
         {
-            if (LogCategories.IsFunctionUserCategory(category) || category.Equals(WorkerConstants.FunctionConsoleLogCategoryName, StringComparison.OrdinalIgnoreCase))
+            if (LogCategories.IsFunctionUserCategory(category)
+                || LogCategories.IsFunctionCategory(category)
+                || category.Equals(WorkerConstants.FunctionConsoleLogCategoryName, StringComparison.OrdinalIgnoreCase))
             {
                 return actualLevel >= userLogMinLevel;
             }
@@ -260,28 +239,9 @@ internal static bool DefaultLoggingFilter(string category, LogLevel actualLevel,
             return actualLevel >= userLogMinLevel;
         }
 
-        /// <summary>
-        /// Returns true for user logs >= Trace level. Returns false, if log level is explicitly set to None.
-        /// </summary>
-        /// <param name="actualLevel"></param>
-        /// <returns></returns>
-        internal static bool UserLoggingFilter(LogLevel actualLevel)
-        {
-            if (actualLevel == LogLevel.None)
-            {
-                return false;
-            }
-            return actualLevel >= LogLevel.Trace;
-        }
-
-        internal static bool SystemLoggingFilter(string category, LogLevel actualLevel, LogLevel minLevel)
-        {
-            return actualLevel >= minLevel && IsSystemLogCategory(category);
-        }
-
         internal static bool IsSystemLogCategory(string category)
         {
-            return SystemCategoryPrefixes.Where(p => category.StartsWith(p)).Any();
+            return ScriptConstants.SystemLogCategoryPrefixes.Where(p => category.StartsWith(p)).Any();
         }
 
         internal static IConfigurationRoot BuildHostJsonConfigutation(ScriptApplicationHostOptions hostOptions)

src/Azure.Functions.Cli/Diagnostics/ColoredConsoleLogger.cs

@@ -14,18 +14,53 @@ public class ColoredConsoleLogger : ILogger
         private readonly bool _verboseErrors;
         private readonly string _category;
         private readonly LoggingFilterHelper _loggingFilterHelper;
+        private readonly LoggerFilterOptions _loggerFilterOptions;
         private readonly string[] allowedLogsPrefixes = new string[] { "Worker process started and initialized.", "Host lock lease acquired by instance ID" };
+        private static readonly LoggerRuleSelector RuleSelector = new LoggerRuleSelector();
+        private static readonly Type ProviderType = typeof(ColoredConsoleLoggerProvider);
 
-        public ColoredConsoleLogger(string category, LoggingFilterHelper loggingFilterHelper)
+        public ColoredConsoleLogger(string category, LoggingFilterHelper loggingFilterHelper, LoggerFilterOptions loggerFilterOptions)
         {
             _category = category;
-            _loggingFilterHelper = loggingFilterHelper;
+            _loggerFilterOptions = loggerFilterOptions ?? throw new ArgumentNullException(nameof(loggerFilterOptions));
+            _loggingFilterHelper = loggingFilterHelper ?? throw new ArgumentNullException(nameof(loggingFilterHelper));
             _verboseErrors = StaticSettings.IsDebug;
         }
 
+        internal LoggerFilterRule SelectRule(string categoryName, LoggerFilterOptions loggerFilterOptions)
+        {
+            RuleSelector.Select(loggerFilterOptions, ProviderType, categoryName,
+                out LogLevel? minLevel, out Func<string, string, LogLevel, bool> filter);
+
+            return new LoggerFilterRule(ProviderType.FullName, categoryName, minLevel, filter);
+        }
+
+        internal bool IsEnabled(string category, LogLevel logLevel)
+        {
+            LoggerFilterRule filterRule = SelectRule(category, _loggerFilterOptions);
+
+            if (filterRule.LogLevel != null && logLevel < filterRule.LogLevel)
+            {
+                return false;
+            }
+            if (filterRule.Filter != null)
+            {
+                bool enabled = filterRule.Filter(ProviderType.FullName, category, logLevel);
+                if (!enabled)
+                {
+                    return false;
+                }
+            }
+            if (filterRule.LogLevel != null)
+            {
+                return Utilities.DefaultLoggingFilter(category, logLevel, filterRule.LogLevel.Value, filterRule.LogLevel.Value);
+            }
+            return Utilities.DefaultLoggingFilter(category, logLevel, _loggingFilterHelper.UserLogDefaultLogLevel, _loggingFilterHelper.SystemLogDefaultLogLevel);
+        }
+
         public bool IsEnabled(LogLevel logLevel)
         {
-            return _loggingFilterHelper.IsEnabled(_category, logLevel);
+            return IsEnabled(_category, logLevel);
         }
 
         public void Log<TState>(LogLevel logLevel, EventId eventId, TState state, Exception exception, Func<TState, Exception, string> formatter)
@@ -55,12 +90,7 @@ private void LogToConsole(LogLevel logLevel, Exception exception, string formatt
         {
             foreach (var line in GetMessageString(logLevel, formattedMessage, exception))
             {
-                var outputline = $"{line}";
-                if (_loggingFilterHelper.VerboseLogging)
-                {
-                    outputline = $"[{DateTime.UtcNow}] {outputline}";
-                }
-                ColoredConsole.WriteLine($"{outputline}");
+                ColoredConsole.WriteLine($"[{DateTime.UtcNow.ToString("yyyy'-'MM'-'dd'T'HH':'mm':'ss'.'fff")}] {line}");
             }
         }
 

src/Azure.Functions.Cli/Diagnostics/ColoredConsoleLoggerProvider.cs

@@ -6,15 +6,17 @@ namespace Azure.Functions.Cli.Diagnostics
     public class ColoredConsoleLoggerProvider : ILoggerProvider
     {
         private readonly LoggingFilterHelper _loggingFilterHelper;
+        private readonly LoggerFilterOptions _loggerFilterOptions;
 
-        public ColoredConsoleLoggerProvider(LoggingFilterHelper loggingFilterHelper)
+        public ColoredConsoleLoggerProvider(LoggingFilterHelper loggingFilterHelper, LoggerFilterOptions loggerFilterOptions)
         {
-            _loggingFilterHelper = loggingFilterHelper;
+            _loggerFilterOptions = loggerFilterOptions ?? throw new ArgumentNullException(nameof(loggerFilterOptions));
+            _loggingFilterHelper = loggingFilterHelper ?? throw new ArgumentNullException(nameof(loggingFilterHelper));
         }
 
         public ILogger CreateLogger(string categoryName)
         {
-            return new ColoredConsoleLogger(categoryName, _loggingFilterHelper);
+            return new ColoredConsoleLogger(categoryName, _loggingFilterHelper, _loggerFilterOptions);
         }
 
         public void Dispose()

src/Azure.Functions.Cli/Diagnostics/LoggerRuleSelector.cs

@@ -0,0 +1,87 @@
+// Copyright (c) .NET Foundation. All rights reserved.
+// Licensed under the MIT License. See License.txt in the project root for license information.
+
+// This file is modified copy of: 
+// https://github.com/aspnet/Logging/blob/cc350d7ef616ef292c1b4ae7130b8c2b45fc1164/src/Microsoft.Extensions.Logging/LoggerRuleSelector.cs.
+
+using System;
+
+namespace Microsoft.Extensions.Logging
+{
+    internal class LoggerRuleSelector
+    {
+        public void Select(LoggerFilterOptions options, Type providerType, string category, out LogLevel? minLevel, out Func<string, string, LogLevel, bool> filter)
+        {
+            filter = null;
+            minLevel = options.MinLevel;
+
+            // Filter rule selection:
+            // 1. Select rules for current logger type, if there is none, select ones without logger type specified
+            // 2. Select rules with longest matching categories
+            // 3. If there nothing matched by category take all rules without category
+            // 3. If there is only one rule use it's level and filter
+            // 4. If there are multiple rules use last
+            // 5. If there are no applicable rules use global minimal level
+
+            LoggerFilterRule current = null;
+            foreach (var rule in options.Rules)
+            {
+                if (IsBetter(rule, current, null, category))
+                {
+                    current = rule;
+                }
+            }
+
+            if (current != null)
+            {
+                filter = current.Filter;
+                minLevel = current.LogLevel;
+            }
+        }
+
+        private static bool IsBetter(LoggerFilterRule rule, LoggerFilterRule current, string logger, string category)
+        {
+            // Skip rules with inapplicable type or category
+            if (rule.ProviderName != null && rule.ProviderName != logger)
+            {
+                return false;
+            }
+
+            if (rule.CategoryName != null && !category.StartsWith(rule.CategoryName, StringComparison.OrdinalIgnoreCase))
+            {
+                return false;
+            }
+
+            if (current?.ProviderName != null)
+            {
+                if (rule.ProviderName == null)
+                {
+                    return false;
+                }
+            }
+            else
+            {
+                // We want to skip category check when going from no provider to having provider
+                if (rule.ProviderName != null)
+                {
+                    return true;
+                }
+            }
+
+            if (current?.CategoryName != null)
+            {
+                if (rule.CategoryName == null)
+                {
+                    return false;
+                }
+
+                if (current.CategoryName.Length > rule.CategoryName.Length)
+                {
+                    return false;
+                }
+            }
+
+            return true;
+        }
+    }
+}

src/Azure.Functions.Cli/Diagnostics/LoggingBuilder.cs

@@ -5,6 +5,7 @@
 using Microsoft.Azure.WebJobs.Script;
 using Microsoft.Extensions.DependencyInjection;
 using Microsoft.Extensions.Logging;
+using Microsoft.Extensions.Options;
 
 namespace Azure.Functions.Cli.Diagnostics
 {
@@ -19,7 +20,14 @@ public LoggingBuilder(LoggingFilterHelper loggingFilterHelper)
 
         public void Configure(ILoggingBuilder builder)
         {
-            _loggingFilterHelper.AddConsoleLoggingProvider(builder);
+            builder.Services.AddSingleton<ILoggerProvider>(p =>
+            {
+                //Cache LoggerFilterOptions to be used by the logger to filter logs based on content
+                var filterOptions = p.GetService<IOptions<LoggerFilterOptions>>();
+                return new ColoredConsoleLoggerProvider(_loggingFilterHelper, filterOptions.Value);
+            });
+
+            builder.AddFilter<ColoredConsoleLoggerProvider>((category, level) => true);
 
             builder.Services.AddSingleton<TelemetryClient>(provider =>
             {