Merge pull request #40 from nblumhardt/reloadable-logger-fixes

Fix freezing of CachingReloadableLoggers

Author: nblumhardt

samples/SimpleServiceSample/Program.cs

@@ -7,25 +7,14 @@
 
 namespace SimpleServiceSample
 {
-    public class Program
+    public static class Program
     {
-        public static Action<IConfigurationBuilder> BuildConfiguration =
-            builder => builder
-                .SetBasePath(Directory.GetCurrentDirectory())
-                .AddJsonFile("appsettings.json", optional: false, reloadOnChange: true)
-                .AddJsonFile($"appsettings.{Environment.GetEnvironmentVariable("ASPNETCORE_ENVIRONMENT") ?? "Production"}.json", optional: true)
-                .AddEnvironmentVariables();
-
         public static int Main(string[] args)
         {
-            var builder = new ConfigurationBuilder();
-            BuildConfiguration(builder);
-
             Log.Logger = new LoggerConfiguration()
-                .ReadFrom.Configuration(builder.Build())
                 .Enrich.FromLogContext()
                 .WriteTo.Console()
-                .CreateLogger();
+                .CreateBootstrapLogger();
 
             try
             {
@@ -47,6 +36,9 @@ public static int Main(string[] args)
         public static IHostBuilder CreateHostBuilder(string[] args) =>
             Host.CreateDefaultBuilder(args)
                 .ConfigureServices(services => services.AddHostedService<PrintTimeService>())
-                .UseSerilog();
+                .UseSerilog((context, services, loggerConfiguration) => loggerConfiguration
+                    .ReadFrom.Configuration(context.Configuration)
+                    .Enrich.FromLogContext()
+                    .WriteTo.Console());
     }
 }

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

@@ -128,8 +128,7 @@ public ILogger ForContext<TSource>()
         {
             if (_frozen)
                 return _cached.ForContext<TSource>();
-
-
+            
             if (_reloadableLogger.CreateChild(
                 _root,
                 this,
@@ -171,12 +170,15 @@ void Update(ILogger newRoot, ILogger newCached, bool frozen)
         {
             _root = newRoot;
             _cached = newCached;
-            _frozen = frozen;
 
             // https://github.com/dotnet/runtime/issues/20500#issuecomment-284774431
-            // Publish `_cached` and `_frozen`. This is useful here because it means that once the logger is frozen - which
+            // Publish `_cached` and then `_frozen`. This is useful here because it means that once the logger is frozen - which
             // we always expect - reads don't require any synchronization/interlocked instructions.
             Interlocked.MemoryBarrierProcessWide();
+
+            _frozen = frozen;
+
+            Interlocked.MemoryBarrierProcessWide();
         }
 
         public void Write(LogEvent logEvent)

src/Serilog.Extensions.Hosting/Extensions/Hosting/ReloadableLogger.cs

@@ -80,7 +80,7 @@ public Logger Freeze()
                     throw new InvalidOperationException("The logger is already frozen.");
 
                 _frozen = true;
-                
+
                 // https://github.com/dotnet/runtime/issues/20500#issuecomment-284774431
                 // Publish `_logger` and `_frozen`. This is useful here because it means that once the logger is frozen - which
                 // we always expect - reads don't require any synchronization/interlocked instructions.
@@ -368,12 +368,21 @@ public bool BindProperty(string propertyName, object value, bool destructureObje
         [MethodImpl(MethodImplOptions.AggressiveInlining)]
         (ILogger, bool) UpdateForCaller(ILogger root, ILogger cached, IReloadableLogger caller, out ILogger newRoot, out ILogger newCached, out bool frozen)
         {
+            if (_frozen)
+            {
+                // If we're frozen, then the caller hasn't observed this yet and should update.
+                newRoot = _logger;
+                newCached = caller.ReloadLogger();
+                frozen = true;
+                return (newCached, true);
+            }
+
             if (cached != null && root == _logger)
             {
                 newRoot = default;
                 newCached = default;
-                frozen = _frozen;
-                return (cached, frozen); // If we're frozen, then the caller hasn't observed this yet and should update.
+                frozen = false;
+                return (cached, false);
             }
 
             newRoot = _logger;

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

@@ -20,6 +20,19 @@ public void AFrozenLoggerYieldsSerilogLoggers()
             nested = contextual.ForContext("test", "test");
             Assert.IsType<Core.Logger>(nested);
         }
+        
+        [Fact]
+        public void CachingReloadableLoggerRemainsUsableAfterFreezing()
+        {
+            var logger = new LoggerConfiguration().CreateBootstrapLogger();
+            var contextual = logger.ForContext<ReloadableLoggerTests>();
+            contextual.Information("First");
+            logger.Reload(c => c);
+            logger.Freeze();
+            contextual.Information("Second");
+            contextual.Information("Third");
+            contextual.Information("Fourth"); // No crash :-)
+        }
     }
 }