Merge pull request #218 from sungam3r/exception

Do not swallow exception from Audit

Author: nblumhardt

src/Serilog.Extensions.Logging/Extensions/Logging/SerilogLogger.cs

@@ -74,19 +74,23 @@ public void Log<TState>(LogLevel logLevel, EventId eventId, TState state, Except
             return;
         }
 
+        LogEvent? evt = null;
         try
         {
-            Write(level, eventId, state, exception, formatter);
+            evt = PrepareWrite(level, eventId, state, exception, formatter);
         }
         catch (Exception ex)
         {
             SelfLog.WriteLine($"Failed to write event through {typeof(SerilogLogger).Name}: {ex}");
         }
+
+        // Do not swallow exceptions from here because Serilog takes care of them in case of WriteTo and throws them back to the caller in case of AuditTo.
+        if (evt != null)
+            _logger.Write(evt);
     }
 
-    void Write<TState>(LogEventLevel level, EventId eventId, TState state, Exception exception, Func<TState, Exception, string> formatter)
+    LogEvent PrepareWrite<TState>(LogEventLevel level, EventId eventId, TState state, Exception exception, Func<TState, Exception, string> formatter)
     {
-        var logger = _logger;
         string? messageTemplate = null;
 
         var properties = new List<LogEventProperty>();
@@ -101,17 +105,17 @@ void Write<TState>(LogEventLevel level, EventId eventId, TState state, Exception
                 }
                 else if (property.Key.StartsWith("@"))
                 {
-                    if (logger.BindProperty(GetKeyWithoutFirstSymbol(DestructureDictionary, property.Key), property.Value, true, out var destructured))
+                    if (_logger.BindProperty(GetKeyWithoutFirstSymbol(DestructureDictionary, property.Key), property.Value, true, out var destructured))
                         properties.Add(destructured);
                 }
                 else if (property.Key.StartsWith("$"))
                 {
-                    if (logger.BindProperty(GetKeyWithoutFirstSymbol(StringifyDictionary, property.Key), property.Value?.ToString(), true, out var stringified))
+                    if (_logger.BindProperty(GetKeyWithoutFirstSymbol(StringifyDictionary, property.Key), property.Value?.ToString(), true, out var stringified))
                         properties.Add(stringified);
                 }
                 else
                 {
-                    if (logger.BindProperty(property.Key, property.Value, false, out var bound))
+                    if (_logger.BindProperty(property.Key, property.Value, false, out var bound))
                         properties.Add(bound);
                 }
             }
@@ -122,7 +126,7 @@ void Write<TState>(LogEventLevel level, EventId eventId, TState state, Exception
             if (messageTemplate == null && !stateTypeInfo.IsGenericType)
             {
                 messageTemplate = "{" + stateType.Name + ":l}";
-                if (logger.BindProperty(stateType.Name, AsLoggableValue(state, formatter), false, out var stateTypeProperty))
+                if (_logger.BindProperty(stateType.Name, AsLoggableValue(state, formatter), false, out var stateTypeProperty))
                     properties.Add(stateTypeProperty);
             }
         }
@@ -143,7 +147,7 @@ void Write<TState>(LogEventLevel level, EventId eventId, TState state, Exception
 
             if (propertyName != null)
             {
-                if (logger.BindProperty(propertyName, AsLoggableValue(state, formatter!), false, out var property))
+                if (_logger.BindProperty(propertyName, AsLoggableValue(state, formatter!), false, out var property))
                     properties.Add(property);
             }
         }
@@ -152,8 +156,7 @@ void Write<TState>(LogEventLevel level, EventId eventId, TState state, Exception
             properties.Add(CreateEventIdProperty(eventId));
 
         var parsedTemplate = MessageTemplateParser.Parse(messageTemplate ?? "");
-        var evt = new LogEvent(DateTimeOffset.Now, level, exception, parsedTemplate, properties);
-        logger.Write(evt);
+        return new LogEvent(DateTimeOffset.Now, level, exception, parsedTemplate, properties);
     }
 
     static object? AsLoggableValue<TState>(TState state, Func<TState, Exception, string> formatter)

test/Serilog.Extensions.Logging.Tests/SerilogLoggerTests.cs

@@ -7,6 +7,7 @@
 using Serilog.Debugging;
 using Serilog.Extensions.Logging.Tests.Support;
 using Xunit;
+using Serilog.Core;
 
 namespace Serilog.Extensions.Logging.Tests;
 
@@ -469,4 +470,27 @@ public void MismatchedMessageTemplateParameterCountIsHandled()
 
         Assert.Empty(sink.Writes);
     }
+
+    [Fact]
+    public void ExceptionFromAuditSinkIsUnhandled()
+    {
+        var serilogLogger = new LoggerConfiguration()
+            .AuditTo.Sink(new MySink())
+            .CreateLogger();
+
+        var provider = new SerilogLoggerProvider(serilogLogger);
+        var logger = provider.CreateLogger(Name);
+
+        var ex = Assert.Throws<AggregateException>(() => logger.LogInformation("Normal text"));
+        Assert.IsType<NotImplementedException>(ex.InnerException);
+        Assert.Equal("Oops", ex.InnerException.Message);
+    }
+
+    private class MySink : ILogEventSink
+    {
+        public void Emit(LogEvent logEvent)
+        {
+            throw new NotImplementedException("Oops");
+        }
+    }
 }