Support for LevelSwith in KeyValuePairSettings (serilog#1020)

* add support for declaring a named LoggingLevelSwitch

key="level-switch:foo" value="Information" will create an instance of LoggingLevelSwitch named foo with initial level Information

* add support for using a previously declared LoggingLevelSwitch to control MinimumLevel

key="minimum-level:controlled-by" value="foo" will set MinimumLevel.ControlledBy with the previously declared named level-switch

* [WIP] unit test for passing controlLevelSwitch to a sink

* [Refactoring] extracted methods to make it clearer

KeyValuePairSettings.ParseVariableDeclarationDirectives and KeyValuePairSettings.LookUpVariable

* add the possibility to pass a declared LoggingLevelSwitch to a sink

Passing a parameter directive the name of a declared Switch will pass it to the configuration method

* add support for level-switch:Switch1 - value = "" and interpret it as level=information

* Minor edits/typos in the unit tests

* Change brittle tests in order not to rely on reflection to acces brittle private field

* Simplify the code around "creating a new LoggingLevelSwitch"
+ throw a "nicer" error message when referencing an undeclared LoggingLevelSwitch

* Add support for referencing a LoggingLevelSwitch from a minimul level override

key="serilog:minimum-level:override:System" value ="switchName" will bind the override to a switch that may be controlled through the sink

* Enforce declaration of switch as level-switch:$switchName
... and use $ also when referencing the declared swith
This helps disambiguate between a variable and the minimum level for a switch ... and makes sure noone is goind to declared a switch with name "Information"

* Minor tweaks after review

* Explicitly throw a helpful FormatException when specifiying a level-switch with a switch name not starting with a $ sign

* Minor refactoring of ParseNamedLevelSwitchDeclarationDirectives
use Dictionary.Add() instead of Dictionary[] to make it mor explicit that uniqueness is implied

* Refactoring : use TryGetValue instead of ContainsKey

* Refactoring : renamed LookUpSwitchByNameOrThrow to LookUpSwitchByName for consistency

src/Serilog/Settings/KeyValuePairs/KeyValuePairSettings.cs

@@ -14,20 +14,24 @@
 
 using System;
 using System.Collections.Generic;
+using System.Collections.ObjectModel;
 using System.Linq;
 using System.Reflection;
 using System.Text.RegularExpressions;
 using Serilog.Configuration;
+using Serilog.Core;
 using Serilog.Events;
 
 namespace Serilog.Settings.KeyValuePairs
 {
     class KeyValuePairSettings : ILoggerSettings
     {
         const string UsingDirective = "using";
+        const string LevelSwitchDirective = "level-switch";
         const string AuditToDirective = "audit-to";
         const string WriteToDirective = "write-to";
         const string MinimumLevelDirective = "minimum-level";
+        const string MinimumLevelControlledByDirective = "minimum-level:controlled-by";
         const string EnrichWithDirective = "enrich";
         const string EnrichWithPropertyDirective = "enrich:with-property";
         const string FilterDirective = "filter";
@@ -37,13 +41,17 @@ class KeyValuePairSettings : ILoggerSettings
         const string MinimumLevelOverrideDirectivePrefix = "minimum-level:override:";
 
         const string CallableDirectiveRegex = @"^(?<directive>audit-to|write-to|enrich|filter):(?<method>[A-Za-z0-9]*)(\.(?<argument>[A-Za-z0-9]*)){0,1}$";
+        const string LevelSwitchDeclarationDirectiveRegex = @"^level-switch:(?<switchName>.*)$";
+        const string LevelSwitchNameRegex = @"^\$[A-Za-z]+[A-Za-z0-9]*$";
 
         static readonly string[] _supportedDirectives =
         {
             UsingDirective,
+            LevelSwitchDirective,
             AuditToDirective,
             WriteToDirective,
             MinimumLevelDirective,
+            MinimumLevelControlledByDirective,
             EnrichWithPropertyDirective,
             EnrichWithDirective,
             FilterDirective
@@ -81,6 +89,8 @@ public void Configure(LoggerConfiguration loggerConfiguration)
                 .Where(k => _supportedDirectives.Any(k.StartsWith))
                 .ToDictionary(k => k, k => _settings[k]);
 
+            var declaredLevelSwitches = ParseNamedLevelSwitchDeclarationDirectives(directives);
+
             string minimumLevelDirective;
             LogEventLevel minimumLevel;
             if (directives.TryGetValue(MinimumLevelDirective, out minimumLevelDirective) &&
@@ -96,14 +106,28 @@ public void Configure(LoggerConfiguration loggerConfiguration)
                 loggerConfiguration.Enrich.WithProperty(name, enrichProperyDirective.Value);
             }
 
-           foreach (var minimumLevelOverrideDirective in directives.Where(dir =>
+            string minimumLevelControlledByLevelSwitchName;
+            if (directives.TryGetValue(MinimumLevelControlledByDirective, out minimumLevelControlledByLevelSwitchName))
+            {
+                var globalMinimumLevelSwitch = LookUpSwitchByName(minimumLevelControlledByLevelSwitchName, declaredLevelSwitches);
+                loggerConfiguration.MinimumLevel.ControlledBy(globalMinimumLevelSwitch);
+            }
+
+            foreach (var minimumLevelOverrideDirective in directives.Where(dir =>
                 dir.Key.StartsWith(MinimumLevelOverrideDirectivePrefix) && dir.Key.Length > MinimumLevelOverrideDirectivePrefix.Length))
             {
+                var namespacePrefix = minimumLevelOverrideDirective.Key.Substring(MinimumLevelOverrideDirectivePrefix.Length);
+
                 LogEventLevel overriddenLevel;
-                if (Enum.TryParse(minimumLevelOverrideDirective.Value, out overriddenLevel)) {
-                    var namespacePrefix = minimumLevelOverrideDirective.Key.Substring(MinimumLevelOverrideDirectivePrefix.Length);
+                if (Enum.TryParse(minimumLevelOverrideDirective.Value, out overriddenLevel))
+                {
                     loggerConfiguration.MinimumLevel.Override(namespacePrefix, overriddenLevel);
                 }
+                else
+                {
+                    var overrideSwitch = LookUpSwitchByName(minimumLevelOverrideDirective.Value, declaredLevelSwitches);
+                    loggerConfiguration.MinimumLevel.Override(namespacePrefix, overrideSwitch);
+                }
             }
 
             var matchCallables = new Regex(CallableDirectiveRegex);
@@ -135,12 +159,74 @@ where matchCallables.IsMatch(wt.Key)
                         .GroupBy(call => call.MethodName)
                         .ToList();
 
-                    ApplyDirectives(calls, methods, CallableDirectiveReceivers[receiverGroup.Key](loggerConfiguration));
+                    ApplyDirectives(calls, methods, CallableDirectiveReceivers[receiverGroup.Key](loggerConfiguration), declaredLevelSwitches);
                 }
             }
         }
 
-        static void ApplyDirectives(List<IGrouping<string, ConfigurationMethodCall>> directives, IList<MethodInfo> configurationMethods, object loggerConfigMethod)
+        internal static bool IsValidSwitchName(string input)
+        {
+            return Regex.IsMatch(input, LevelSwitchNameRegex);
+        }
+
+        static IReadOnlyDictionary<string, LoggingLevelSwitch> ParseNamedLevelSwitchDeclarationDirectives(Dictionary<string, string> directives)
+        {
+            var matchLevelSwitchDeclarations = new Regex(LevelSwitchDeclarationDirectiveRegex);
+
+            var switchDeclarationDirectives = (from wt in directives
+                                               where matchLevelSwitchDeclarations.IsMatch(wt.Key)
+                                               let match = matchLevelSwitchDeclarations.Match(wt.Key)
+                                               select new
+                                               {
+                                                   SwitchName = match.Groups["switchName"].Value,
+                                                   InitialSwitchLevel = wt.Value
+                                               }).ToList();
+
+            var namedSwitches = new Dictionary<string, LoggingLevelSwitch>();
+            foreach (var switchDeclarationDirective in switchDeclarationDirectives)
+            {
+                var switchName = switchDeclarationDirective.SwitchName;
+                var switchInitialLevel = switchDeclarationDirective.InitialSwitchLevel;
+                // switchName must be something like $switch to avoid ambiguities
+                if (!IsValidSwitchName(switchName))
+                {
+                    throw new FormatException($"\"{switchName}\" is not a valid name for a Level Switch declaration. Level switch must be declared with a '$' sign, like \"level-switch:$switchName\"");
+                }
+                LoggingLevelSwitch newSwitch;
+                if (string.IsNullOrEmpty(switchInitialLevel))
+                {
+                    newSwitch = new LoggingLevelSwitch();
+                }
+                else
+                {
+                    var initialLevel = (LogEventLevel)SettingValueConversions.ConvertToType(switchInitialLevel, typeof(LogEventLevel));
+                    newSwitch = new LoggingLevelSwitch(initialLevel);
+                }
+                namedSwitches.Add(switchName, newSwitch);
+            }
+            return new ReadOnlyDictionary<string, LoggingLevelSwitch>(namedSwitches);
+        }
+
+        static LoggingLevelSwitch LookUpSwitchByName(string switchName, IReadOnlyDictionary<string, LoggingLevelSwitch> declaredLevelSwitches)
+        {
+            if (declaredLevelSwitches.TryGetValue(switchName, out var levelSwitch))
+            {
+                return levelSwitch;
+            }
+
+            throw new InvalidOperationException($"No LoggingLevelSwitch has been declared with name \"{switchName}\". You might be missing a key \"{LevelSwitchDirective}:{switchName}\"");
+        }
+
+        static object ConvertOrLookupByName(string valueOrSwitchName, Type type, IReadOnlyDictionary<string, LoggingLevelSwitch> declaredSwitches)
+        {
+            if (type == typeof(LoggingLevelSwitch))
+            {
+                return LookUpSwitchByName(valueOrSwitchName, declaredSwitches);
+            }
+            return SettingValueConversions.ConvertToType(valueOrSwitchName, type);
+        }
+
+        static void ApplyDirectives(List<IGrouping<string, ConfigurationMethodCall>> directives, IList<MethodInfo> configurationMethods, object loggerConfigMethod, IReadOnlyDictionary<string, LoggingLevelSwitch> declaredSwitches)
         {
             foreach (var directiveInfo in directives)
             {
@@ -151,7 +237,7 @@ static void ApplyDirectives(List<IGrouping<string, ConfigurationMethodCall>> dir
 
                     var call = (from p in target.GetParameters().Skip(1)
                                 let directive = directiveInfo.FirstOrDefault(s => s.ArgumentName == p.Name)
-                                select directive == null ? p.DefaultValue : SettingValueConversions.ConvertToType(directive.Value, p.ParameterType)).ToList();
+                                select directive == null ? p.DefaultValue : ConvertOrLookupByName(directive.Value, p.ParameterType, declaredSwitches)).ToList();
 
                     call.Insert(0, loggerConfigMethod);
 

test/Serilog.Tests/Settings/KeyValuePairSettingsTests.cs

@@ -8,6 +8,7 @@
 using Serilog.Tests.Support;
 using TestDummies;
 using Serilog.Configuration;
+using Serilog.Core;
 using Serilog.Formatting;
 
 namespace Serilog.Tests.Settings
@@ -152,5 +153,173 @@ public void TestMinimumLevelOverrides()
             Assert.NotNull(evt);
         }
 
+        [Theory]
+        [InlineData("$switchName", true)]
+        [InlineData("$SwitchName", true)]
+        [InlineData("$switch1", true)]
+        [InlineData("$sw1tch0", true)]
+        [InlineData("$SWITCHNAME", true)]
+        [InlineData("$$switchname", false)]
+        [InlineData("$switchname$", false)]
+        [InlineData("switch$name", false)]
+        [InlineData("$", false)]
+        [InlineData("", false)]
+        [InlineData(" ", false)]
+        [InlineData("$1switch", false)]
+        [InlineData("$switch_name", false)]
+        public void LoggingLevelSwitchNameValidityScenarios(string switchName, bool expectedValid)
+        {
+            Assert.True(KeyValuePairSettings.IsValidSwitchName(switchName) == expectedValid,
+                $"expected IsValidSwitchName({switchName}) to return {expectedValid} ");
+        }
+
+        [Fact]
+        public void LoggingLevelSwitchWithInvalidNameThrowsFormatException()
+        {
+            var settings = new Dictionary<string, string>
+            {
+                ["level-switch:switchNameNotStartingWithDollar"] = "Warning",
+            };
+
+            var ex = Assert.Throws<FormatException>(() =>  new LoggerConfiguration()
+                .ReadFrom.KeyValuePairs(settings));
+
+            Assert.Contains("\"switchNameNotStartingWithDollar\"", ex.Message);
+            Assert.Contains("'$' sign", ex.Message);
+            Assert.Contains("\"level-switch:$switchName\"", ex.Message);
+        }
+
+        [Fact]
+        public void LoggingLevelSwitchIsConfigured()
+        {
+            var settings = new Dictionary<string, string>
+            {
+                ["level-switch:$switch1"] = "Warning",
+                ["minimum-level:controlled-by"] = "$switch1",
+            };
+
+            LogEvent evt = null;
+
+            var log = new LoggerConfiguration()
+                .ReadFrom.KeyValuePairs(settings)
+                .WriteTo.Sink(new DelegatingSink(e => evt = e))
+                .CreateLogger();
+
+            log.Write(Some.DebugEvent());
+            Assert.True(evt is null, "LoggingLevelSwitch initial level was Warning. It should not log Debug messages");
+            log.Write(Some.InformationEvent());
+            Assert.True(evt is null, "LoggingLevelSwitch initial level was Warning. It should not log Information messages");
+            log.Write(Some.WarningEvent());
+            Assert.True(evt != null, "LoggingLevelSwitch initial level was Warning. It should log Warning messages");
+        }
+
+        [Fact]
+        public void SettingMinimumLevelControlledByToAnUndeclaredSwitchThrows()
+        {
+            var settings = new Dictionary<string, string>
+            {
+                ["level-switch:$switch1"] = "Information",
+                ["minimum-level:controlled-by"] = "$switch2",
+            };
+
+            var ex = Assert.Throws<InvalidOperationException>(() =>
+                new LoggerConfiguration()
+                    .ReadFrom.KeyValuePairs(settings)
+                    .CreateLogger());
+            Assert.Contains("$switch2", ex.Message);
+            Assert.Contains("level-switch:$switch2", ex.Message);
+        }
+
+        [Fact]
+        public void LoggingLevelSwitchIsPassedToSinks()
+        {
+            var settings = new Dictionary<string, string>
+            {
+                ["level-switch:$switch1"] = "Information",
+                ["minimum-level:controlled-by"] = "$switch1",
+                ["using:TestDummies"] = typeof(DummyLoggerConfigurationExtensions).GetTypeInfo().Assembly.FullName,
+                ["write-to:DummyWithLevelSwitch.controlLevelSwitch"] = "$switch1"
+            };
+
+            LogEvent evt = null;
+
+            var log = new LoggerConfiguration()
+                .ReadFrom.KeyValuePairs(settings)
+                .WriteTo.Sink(new DelegatingSink(e => evt = e))
+                .CreateLogger();
+
+            Assert.False(DummyWithLevelSwitchSink.ControlLevelSwitch == null, "Sink ControlLevelSwitch should have been initialized");
+
+            var controlSwitch = DummyWithLevelSwitchSink.ControlLevelSwitch;
+            Assert.NotNull(controlSwitch);
+
+            log.Write(Some.DebugEvent());
+            Assert.True(evt is null, "LoggingLevelSwitch initial level was information. It should not log Debug messages");
+
+            controlSwitch.MinimumLevel = LogEventLevel.Debug;
+            log.Write(Some.DebugEvent());
+            Assert.True(evt != null, "LoggingLevelSwitch level was changed to Debug. It should log Debug messages");
+        }
+
+        [Fact]
+        public void ReferencingAnUndeclaredSwitchInSinkThrows()
+        {
+            var settings = new Dictionary<string, string>
+            {
+                ["level-switch:$switch1"] = "Information",
+                ["minimum-level:controlled-by"] = "$switch1",
+                ["using:TestDummies"] = typeof(DummyLoggerConfigurationExtensions).GetTypeInfo().Assembly.FullName,
+                ["write-to:DummyWithLevelSwitch.controlLevelSwitch"] = "$switch2"
+            };
+
+            var ex = Assert.Throws<InvalidOperationException>(() =>
+                new LoggerConfiguration()
+                    .ReadFrom.KeyValuePairs(settings)
+                    .CreateLogger());
+            Assert.Contains("$switch2", ex.Message);
+            Assert.Contains("level-switch:", ex.Message);
+        }
+
+
+        [Fact]
+        public void LoggingLevelSwitchCanBeUsedForMinimumLevelOverrides()
+        {
+            var settings = new Dictionary<string, string>
+            {
+                ["minimum-level"] = "Debug",
+                ["level-switch:$specificSwitch"] = "Warning",
+                ["minimum-level:override:System"] = "$specificSwitch",
+                ["using:TestDummies"] = typeof(DummyLoggerConfigurationExtensions).GetTypeInfo().Assembly.FullName,
+                ["write-to:DummyWithLevelSwitch.controlLevelSwitch"] = "$specificSwitch"
+            };
+
+            LogEvent evt = null;
+
+            var log = new LoggerConfiguration()
+                .ReadFrom.KeyValuePairs(settings)
+                .WriteTo.Sink(new DelegatingSink(e => evt = e))
+                .CreateLogger();
+
+            var systemLogger = log.ForContext(Constants.SourceContextPropertyName, "System.Bar");
+
+            log.Write(Some.InformationEvent());
+            Assert.False(evt is null, "Minimul level is Debug. It should log Information messages");
+
+            evt = null;
+
+            systemLogger.Write(Some.InformationEvent());
+            Assert.True(evt is null, "LoggingLevelSwitch initial level was Warning for logger System.*. It should not log Information messages for SourceContext System.Bar");
+
+            systemLogger.Write(Some.WarningEvent());
+            Assert.False(evt is null, "LoggingLevelSwitch initial level was Warning for logger System.*. It should log Warning messages for SourceContext System.Bar");
+
+            evt = null;
+            var controlSwitch = DummyWithLevelSwitchSink.ControlLevelSwitch;
+
+            controlSwitch.MinimumLevel = LogEventLevel.Information;
+            systemLogger.Write(Some.InformationEvent());
+            Assert.False(evt is null, "LoggingLevelSwitch level was changed to Information for logger System.*. It should now log Information events for SourceContext System.Bar.");
+        }
+
     }
 }

test/Serilog.Tests/Support/Some.cs

@@ -57,6 +57,11 @@ public static LogEvent DebugEvent(DateTimeOffset? timestamp = null)
             return LogEvent(timestamp, LogEventLevel.Debug);
         }
 
+        public static LogEvent WarningEvent(DateTimeOffset? timestamp = null)
+        {
+            return LogEvent(timestamp, LogEventLevel.Warning);
+        }
+
         public static LogEventProperty LogEventProperty()
         {
             return new LogEventProperty(String(), new ScalarValue(Int()));

test/TestDummies/DummyLoggerConfigurationExtensions.cs

@@ -3,6 +3,7 @@
 using Serilog.Events;
 using Serilog.Formatting;
 using Serilog.Configuration;
+using Serilog.Core;
 
 namespace TestDummies
 {
@@ -42,6 +43,14 @@ public static LoggerConfiguration DummyRollingFile(
             return loggerSinkConfiguration.Sink(new DummyRollingFileAuditSink(), restrictedToMinimumLevel);
         }
 
+        public static LoggerConfiguration DummyWithLevelSwitch(
+            this LoggerSinkConfiguration loggerSinkConfiguration,
+            LogEventLevel restrictedToMinimumLevel = LevelAlias.Minimum,
+            LoggingLevelSwitch controlLevelSwitch = null)
+        {
+            return loggerSinkConfiguration.Sink(new DummyWithLevelSwitchSink(controlLevelSwitch), restrictedToMinimumLevel);
+        }
+
         public static LoggerConfiguration Dummy(
             this LoggerSinkConfiguration loggerSinkConfiguration,
             Action<LoggerSinkConfiguration> wrappedSinkAction)
@@ -52,4 +61,4 @@ public static LoggerConfiguration Dummy(
                 wrappedSinkAction);
         }
     }
-}
+}