Merge pull request #43 from nblumhardt/fix-minimum-level-overrides

Fix minimum level overrides in reloadable loggers

Author: nblumhardt

src/Serilog.Extensions.Hosting/Extensions/Hosting/CachingReloadableLogger.cs

@@ -76,7 +76,6 @@ public ILogger ForContext(IEnumerable<ILogEventEnricher> enrichers)
             if (_frozen)
                 return _cached.ForContext(enrichers);
 
-
             if (_reloadableLogger.CreateChild(
                 _root,
                 this,
@@ -100,25 +99,46 @@ public ILogger ForContext(string propertyName, object value, bool destructureObj
             if (_frozen)
                 return _cached.ForContext(propertyName, value, destructureObjects);
 
-            // There's a trade-off, here. Changes to destructuring configuration won't be picked up, but,
-            // it's better to not extend the lifetime of `value` or pass it between threads unexpectedly.
-            var eager = ReloadLogger();
-            if (!eager.BindProperty(propertyName, value, destructureObjects, out var property))
-                return this;
-
-            var enricher = new FixedPropertyEnricher(property);
+            ILogger child;
+            if (value == null || value is string || value.GetType().IsPrimitive || value.GetType().IsEnum)
+            {
+                // Safe to extend the lifetime of `value` by closing over it.
+                // This ensures `SourceContext` is passed through appropriately and triggers minimum level overrides.
+                if (_reloadableLogger.CreateChild(
+                    _root,
+                    this,
+                    _cached,
+                    p => p.ForContext(propertyName, value, destructureObjects),
+                    out child,
+                    out var newRoot,
+                    out var newCached,
+                    out var frozen))
+                {
+                    Update(newRoot, newCached, frozen);
+                }
+            }
+            else
+            {
+                // It's not safe to extend the lifetime of `value` or pass it unexpectedly between threads.
+                // Changes to destructuring configuration won't be picked up by the cached logger.
+                var eager = ReloadLogger();
+                if (!eager.BindProperty(propertyName, value, destructureObjects, out var property))
+                    return this;
+
+                var enricher = new FixedPropertyEnricher(property);
 
-            if (_reloadableLogger.CreateChild(
-                _root,
-                this,
-                _cached,
-                p => p.ForContext(enricher),
-                out var child,
-                out var newRoot,
-                out var newCached,
-                out var frozen))
-            {
-                Update(newRoot, newCached, frozen);
+                if (_reloadableLogger.CreateChild(
+                    _root,
+                    this,
+                    _cached,
+                    p => p.ForContext(enricher),
+                    out child,
+                    out var newRoot,
+                    out var newCached,
+                    out var frozen))
+                {
+                    Update(newRoot, newCached, frozen);
+                }
             }
 
             return child;

test/Serilog.Extensions.Hosting.Tests/LoggerSettingsConfigurationExtensionsTests.cs

@@ -1,5 +1,7 @@
-using Microsoft.Extensions.DependencyInjection;
+using System.Collections.Generic;
+using Microsoft.Extensions.DependencyInjection;
 using Serilog.Core;
+using Serilog.Events;
 using Serilog.Extensions.Hosting.Tests.Support;
 using Xunit;
 
@@ -10,10 +12,10 @@ public class LoggerSettingsConfigurationExtensionsTests
         [Fact]
         public void SinksAreInjectedFromTheServiceProvider()
         {
-            var sink = new SerilogSink();
+            var emittedEvents = new List<LogEvent>();
 
             var serviceCollection = new ServiceCollection();
-            serviceCollection.AddSingleton<ILogEventSink>(sink);
+            serviceCollection.AddSingleton<ILogEventSink>(new ListSink(emittedEvents));
             using var services = serviceCollection.BuildServiceProvider();
 
             using var logger = new LoggerConfiguration()
@@ -22,7 +24,7 @@ public void SinksAreInjectedFromTheServiceProvider()
 
             logger.Information("Hello, world!");
 
-            var evt = Assert.Single(sink.Writes);
+            var evt = Assert.Single(emittedEvents);
             Assert.Equal("Hello, world!", evt!.MessageTemplate.Text);
         }
     }

test/Serilog.Extensions.Hosting.Tests/ReloadableLoggerTests.cs

@@ -1,5 +1,10 @@
 #if !NO_RELOADABLE_LOGGER
 
+using System.Collections.Generic;
+using System.Linq;
+using Serilog.Core;
+using Serilog.Events;
+using Serilog.Extensions.Hosting.Tests.Support;
 using Xunit;
 
 namespace Serilog.Extensions.Hosting.Tests
@@ -33,6 +38,70 @@ public void CachingReloadableLoggerRemainsUsableAfterFreezing()
             contextual.Information("Third");
             contextual.Information("Fourth"); // No crash :-)
         }
+
+        [Fact]
+        public void ReloadableLoggerRespectsMinimumLevelOverrides()
+        {
+            var emittedEvents = new List<LogEvent>();
+            var logger = new LoggerConfiguration()
+                .MinimumLevel.Override("Test", LogEventLevel.Warning)
+                .WriteTo.Sink(new ListSink(emittedEvents))
+                .CreateBootstrapLogger();
+
+            var limited = logger
+                .ForContext("X", 1)
+                .ForContext(Constants.SourceContextPropertyName, "Test.Stuff");
+            
+            var notLimited = logger.ForContext<ReloadableLoggerTests>();
+            
+            foreach (var context in new[] { limited, notLimited })
+            {
+                // Suppressed by both sinks
+                context.Debug("First");
+
+                // Suppressed by the limited logger
+                context.Information("Second");
+                
+                // Emitted by both loggers
+                context.Warning("Third");
+            }
+            
+            Assert.Equal(3, emittedEvents.Count);
+            Assert.Equal(2, emittedEvents.Count(le => le.Level == LogEventLevel.Warning));
+        }
+
+        [Fact]
+        public void ReloadableLoggersRecordEnrichment()
+        {
+            var emittedEvents = new List<LogEvent>();
+            
+            var logger = new LoggerConfiguration()
+                .WriteTo.Sink(new ListSink(emittedEvents))
+                .CreateBootstrapLogger();
+
+            var outer = logger
+                .ForContext("A", new object());
+            var inner = outer.ForContext("B", "test");
+            
+            inner.Information("First");
+            
+            logger.Reload(lc => lc.WriteTo.Sink(new ListSink(emittedEvents)));
+            
+            inner.Information("Second");
+
+            logger.Freeze();
+            
+            inner.Information("Third");
+            
+            outer.ForContext("B", "test").Information("Fourth");
+            
+            logger.ForContext("A", new object())
+                .ForContext("B", "test")
+                .Information("Fifth");
+            
+            Assert.Equal(5, emittedEvents.Count);
+            Assert.All(emittedEvents, e => Assert.Equal(2, e.Properties.Count));
+        }
     }
 }
 

test/Serilog.Extensions.Hosting.Tests/Support/SerilogSink.cs renamed to test/Serilog.Extensions.Hosting.Tests/Support/ListSink.cs

@@ -7,13 +7,18 @@
 
 namespace Serilog.Extensions.Hosting.Tests.Support
 {
-    public class SerilogSink : ILogEventSink
+    public class ListSink : ILogEventSink
     {
-        public List<LogEvent> Writes { get; set; } = new List<LogEvent>();
+        readonly List<LogEvent> _list;
+
+        public ListSink(List<LogEvent> list)
+        {
+            _list = list;
+        }
 
         public void Emit(LogEvent logEvent)
         {
-            Writes.Add(logEvent);
+            _list.Add(logEvent);
         }
     }
 }