From 9fc84d126ba61e7f3aa6b2d965dac1aeddb40a7e Mon Sep 17 00:00:00 2001 From: Ivan Maximov Date: Fri, 10 Mar 2023 19:53:07 +0300 Subject: [PATCH 1/2] Do not swallow exception from Audit --- .../Extensions/Logging/SerilogLogger.cs | 9 ++++--- .../SerilogLoggerTests.cs | 24 +++++++++++++++++++ 2 files changed, 30 insertions(+), 3 deletions(-) diff --git a/src/Serilog.Extensions.Logging/Extensions/Logging/SerilogLogger.cs b/src/Serilog.Extensions.Logging/Extensions/Logging/SerilogLogger.cs index 9c79bcd..18aaed8 100644 --- a/src/Serilog.Extensions.Logging/Extensions/Logging/SerilogLogger.cs +++ b/src/Serilog.Extensions.Logging/Extensions/Logging/SerilogLogger.cs @@ -74,18 +74,20 @@ public void Log(LogLevel logLevel, EventId eventId, TState state, Except return; } + bool parsed = false; try { - Write(level, eventId, state, exception, formatter); + Write(level, eventId, state, exception, formatter, out parsed); } - catch (Exception ex) + catch (Exception ex) when (!parsed) { SelfLog.WriteLine($"Failed to write event through {typeof(SerilogLogger).Name}: {ex}"); } } - void Write(LogEventLevel level, EventId eventId, TState state, Exception exception, Func formatter) + void Write(LogEventLevel level, EventId eventId, TState state, Exception exception, Func formatter, out bool parsed) { + parsed = false; var logger = _logger; string? messageTemplate = null; @@ -153,6 +155,7 @@ void Write(LogEventLevel level, EventId eventId, TState state, Exception var parsedTemplate = MessageTemplateParser.Parse(messageTemplate ?? ""); var evt = new LogEvent(DateTimeOffset.Now, level, exception, parsedTemplate, properties); + parsed = true; logger.Write(evt); } diff --git a/test/Serilog.Extensions.Logging.Tests/SerilogLoggerTests.cs b/test/Serilog.Extensions.Logging.Tests/SerilogLoggerTests.cs index fcaf1f8..94da8bb 100644 --- a/test/Serilog.Extensions.Logging.Tests/SerilogLoggerTests.cs +++ b/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(() => logger.LogInformation("Normal text")); + Assert.IsType(ex.InnerException); + Assert.Equal("Oops", ex.InnerException.Message); + } + + private class MySink : ILogEventSink + { + public void Emit(LogEvent logEvent) + { + throw new NotImplementedException("Oops"); + } + } } From 6da75a2b8608d965d130fee72deccd8f2d78a862 Mon Sep 17 00:00:00 2001 From: Ivan Maximov Date: Sat, 11 Mar 2023 08:45:16 +0300 Subject: [PATCH 2/2] rewrite --- .../Extensions/Logging/SerilogLogger.cs | 28 +++++++++---------- 1 file changed, 14 insertions(+), 14 deletions(-) diff --git a/src/Serilog.Extensions.Logging/Extensions/Logging/SerilogLogger.cs b/src/Serilog.Extensions.Logging/Extensions/Logging/SerilogLogger.cs index 18aaed8..1bf4bab 100644 --- a/src/Serilog.Extensions.Logging/Extensions/Logging/SerilogLogger.cs +++ b/src/Serilog.Extensions.Logging/Extensions/Logging/SerilogLogger.cs @@ -74,21 +74,23 @@ public void Log(LogLevel logLevel, EventId eventId, TState state, Except return; } - bool parsed = false; + LogEvent? evt = null; try { - Write(level, eventId, state, exception, formatter, out parsed); + evt = PrepareWrite(level, eventId, state, exception, formatter); } - catch (Exception ex) when (!parsed) + 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(LogEventLevel level, EventId eventId, TState state, Exception exception, Func formatter, out bool parsed) + LogEvent PrepareWrite(LogEventLevel level, EventId eventId, TState state, Exception exception, Func formatter) { - parsed = false; - var logger = _logger; string? messageTemplate = null; var properties = new List(); @@ -103,17 +105,17 @@ void Write(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); } } @@ -124,7 +126,7 @@ void Write(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); } } @@ -145,7 +147,7 @@ void Write(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); } } @@ -154,9 +156,7 @@ void Write(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); - parsed = true; - logger.Write(evt); + return new LogEvent(DateTimeOffset.Now, level, exception, parsedTemplate, properties); } static object? AsLoggableValue(TState state, Func formatter)