diff --git a/src/Serilog.Extensions.Logging/Extensions/Logging/SerilogLoggerProvider.cs b/src/Serilog.Extensions.Logging/Extensions/Logging/SerilogLoggerProvider.cs index d6b18d1..93dce5f 100644 --- a/src/Serilog.Extensions.Logging/Extensions/Logging/SerilogLoggerProvider.cs +++ b/src/Serilog.Extensions.Logging/Extensions/Logging/SerilogLoggerProvider.cs @@ -102,9 +102,12 @@ public void Enrich(LogEvent logEvent, ILogEventPropertyFactory propertyFactory) } } + scopeItems?.Reverse(); + _externalScopeProvider?.ForEachScope((state, accumulatingLogEvent) => { - SerilogLoggerScope.EnrichWithStateAndCreateScopeItem(accumulatingLogEvent, propertyFactory, state, out var scopeItem); + SerilogLoggerScope.EnrichWithStateAndCreateScopeItem( + accumulatingLogEvent, propertyFactory, state, update: true, out var scopeItem); if (scopeItem != null) { @@ -115,7 +118,6 @@ public void Enrich(LogEvent logEvent, ILogEventPropertyFactory propertyFactory) if (scopeItems != null) { - scopeItems.Reverse(); logEvent.AddPropertyIfAbsent(new LogEventProperty(ScopePropertyName, new SequenceValue(scopeItems))); } } diff --git a/src/Serilog.Extensions.Logging/Extensions/Logging/SerilogLoggerScope.cs b/src/Serilog.Extensions.Logging/Extensions/Logging/SerilogLoggerScope.cs index b03e3e1..80f0f12 100644 --- a/src/Serilog.Extensions.Logging/Extensions/Logging/SerilogLoggerScope.cs +++ b/src/Serilog.Extensions.Logging/Extensions/Logging/SerilogLoggerScope.cs @@ -47,9 +47,9 @@ public void Dispose() } } - public void EnrichAndCreateScopeItem(LogEvent logEvent, ILogEventPropertyFactory propertyFactory, out LogEventPropertyValue? scopeItem) => EnrichWithStateAndCreateScopeItem(logEvent, propertyFactory, _state, out scopeItem); + public void EnrichAndCreateScopeItem(LogEvent logEvent, ILogEventPropertyFactory propertyFactory, out LogEventPropertyValue? scopeItem) => EnrichWithStateAndCreateScopeItem(logEvent, propertyFactory, _state, update: false, out scopeItem); - public static void EnrichWithStateAndCreateScopeItem(LogEvent logEvent, ILogEventPropertyFactory propertyFactory, object? state, out LogEventPropertyValue? scopeItem) + public static void EnrichWithStateAndCreateScopeItem(LogEvent logEvent, ILogEventPropertyFactory propertyFactory, object? state, bool update, out LogEventPropertyValue? scopeItem) { if (state == null) { @@ -63,8 +63,8 @@ public static void EnrichWithStateAndCreateScopeItem(LogEvent logEvent, ILogEven // Separate handling of this case eliminates boxing of Dictionary.Enumerator. scopeItem = null; foreach (var stateProperty in dictionary) - { - AddProperty(logEvent, propertyFactory, stateProperty.Key, stateProperty.Value); + { + AddProperty(logEvent, propertyFactory, stateProperty.Key, stateProperty.Value, update); } } else if (state is IEnumerable> stateProperties) @@ -79,7 +79,7 @@ public static void EnrichWithStateAndCreateScopeItem(LogEvent logEvent, ILogEven } else { - AddProperty(logEvent, propertyFactory, stateProperty.Key, stateProperty.Value); + AddProperty(logEvent, propertyFactory, stateProperty.Key, stateProperty.Value, update); } } } @@ -87,13 +87,13 @@ public static void EnrichWithStateAndCreateScopeItem(LogEvent logEvent, ILogEven else if (state is System.Runtime.CompilerServices.ITuple tuple && tuple.Length == 2 && tuple[0] is string s) { scopeItem = null; // Unless it's `FormattedLogValues`, these are treated as property bags rather than scope items. - AddProperty(logEvent, propertyFactory, s, tuple[1]); + AddProperty(logEvent, propertyFactory, s, tuple[1], update); } #else else if (state is ValueTuple tuple) { scopeItem = null; - AddProperty(logEvent, propertyFactory, tuple.Item1, tuple.Item2); + AddProperty(logEvent, propertyFactory, tuple.Item1, tuple.Item2, update); } #endif else @@ -102,14 +102,14 @@ public static void EnrichWithStateAndCreateScopeItem(LogEvent logEvent, ILogEven } } - static void AddProperty(LogEvent logEvent, ILogEventPropertyFactory propertyFactory, string key, object? value) + static void AddProperty(LogEvent logEvent, ILogEventPropertyFactory propertyFactory, string key, object? value, bool update) { - var destructureObject = false; + var destructureObjects = false; if (key.StartsWith('@')) { key = SerilogLogger.GetKeyWithoutFirstSymbol(SerilogLogger.DestructureDictionary, key); - destructureObject = true; + destructureObjects = true; } else if (key.StartsWith('$')) { @@ -117,7 +117,14 @@ static void AddProperty(LogEvent logEvent, ILogEventPropertyFactory propertyFact value = value?.ToString(); } - var property = propertyFactory.CreateProperty(key, value, destructureObject); - logEvent.AddPropertyIfAbsent(property); + var property = propertyFactory.CreateProperty(key, value, destructureObjects); + if (update) + { + logEvent.AddOrUpdateProperty(property); + } + else + { + logEvent.AddPropertyIfAbsent(property); + } } } diff --git a/test/Serilog.Extensions.Logging.Tests/SerilogLoggerTests.cs b/test/Serilog.Extensions.Logging.Tests/SerilogLoggerTests.cs index 274d8ed..6b27c5d 100644 --- a/test/Serilog.Extensions.Logging.Tests/SerilogLoggerTests.cs +++ b/test/Serilog.Extensions.Logging.Tests/SerilogLoggerTests.cs @@ -3,12 +3,14 @@ using System.Collections; using System.Diagnostics; +using Microsoft.Extensions.DependencyInjection; using Serilog.Events; using Microsoft.Extensions.Logging; using Serilog.Debugging; using Serilog.Extensions.Logging.Tests.Support; using Xunit; using Serilog.Core; +// ReSharper disable AccessToDisposedClosure namespace Serilog.Extensions.Logging.Tests; @@ -17,9 +19,9 @@ public class SerilogLoggerTest const string Name = "test"; const string TestMessage = "This is a test"; - static Tuple SetUp(LogLevel logLevel, IExternalScopeProvider? externalScopeProvider = null) + static Tuple SetUp(LogLevel logLevel, IExternalScopeProvider? externalScopeProvider = null) { - var sink = new SerilogSink(); + var sink = new CollectingSink(); var serilogLogger = new LoggerConfiguration() .WriteTo.Sink(sink) @@ -34,7 +36,7 @@ static Tuple SetUp(LogLevel logLevel, IExternalScope provider.SetScopeProvider(externalScopeProvider); } - return new Tuple(logger, sink); + return new Tuple(logger, sink); } [Fact] @@ -516,7 +518,7 @@ public void Dispose() } } } - + [Fact] public void MismatchedMessageTemplateParameterCountIsHandled() { @@ -579,4 +581,41 @@ public void TraceAndSpanIdsAreCaptured() Assert.Equal(Activity.Current.TraceId, evt.TraceId); Assert.Equal(Activity.Current.SpanId, evt.SpanId); } + + [Fact] + public void LoggingScopeReplacesPropertyInNestedScope() + { + var sink = new CollectingSink(); + using var logger = new LoggerConfiguration().WriteTo.Sink(sink).CreateLogger(); + + var services = new ServiceCollection(); + services.AddLogging(l => l.AddSerilog(logger)); + + using var serviceProvider = services.BuildServiceProvider(); + var msLogger = serviceProvider.GetRequiredService>(); + + using (msLogger.BeginScope(new Dictionary { { "EXECUTION_TAGS", "[TAG1]" } })) + { + msLogger.LogInformation("Message1"); + using (msLogger.BeginScope(new Dictionary { { "EXECUTION_TAGS", "[TAG2]" } })) + { + msLogger.LogInformation("Message2"); + } + } + + var logEvent = sink.Writes.FirstOrDefault(e => e.MessageTemplate.Text == "Message1"); + Assert.NotNull(logEvent); + AssertHasScalarProperty(logEvent, "EXECUTION_TAGS", "[TAG1]"); + + logEvent = sink.Writes.FirstOrDefault(e => e.MessageTemplate.Text == "Message2"); + Assert.NotNull(logEvent); + AssertHasScalarProperty(logEvent, "EXECUTION_TAGS", "[TAG2]"); + } + + static void AssertHasScalarProperty(LogEvent logEvent, string name, object? expectedValue) + { + Assert.True(logEvent.Properties.TryGetValue(name, out var result)); + var scalar = Assert.IsType(result); + Assert.Equal(expectedValue, scalar.Value); + } } diff --git a/test/Serilog.Extensions.Logging.Tests/SerilogLoggingBuilderExtensionsTests.cs b/test/Serilog.Extensions.Logging.Tests/SerilogLoggingBuilderExtensionsTests.cs index e30d017..f727a65 100644 --- a/test/Serilog.Extensions.Logging.Tests/SerilogLoggingBuilderExtensionsTests.cs +++ b/test/Serilog.Extensions.Logging.Tests/SerilogLoggingBuilderExtensionsTests.cs @@ -21,7 +21,7 @@ public void AddSerilogMustRegisterAnILoggerProvider() [Fact] public void AddSerilogMustRegisterAnILoggerProviderThatForwardsLogsToStaticSerilogLogger() { - var sink = new SerilogSink(); + var sink = new CollectingSink(); Log.Logger = new LoggerConfiguration() .WriteTo.Sink(sink) .CreateLogger(); @@ -39,7 +39,7 @@ public void AddSerilogMustRegisterAnILoggerProviderThatForwardsLogsToStaticSeril [Fact] public void AddSerilogMustRegisterAnILoggerProviderThatForwardsLogsToProvidedLogger() { - var sink = new SerilogSink(); + var sink = new CollectingSink(); var serilogLogger = new LoggerConfiguration() .WriteTo.Sink(sink) .CreateLogger(); diff --git a/test/Serilog.Extensions.Logging.Tests/Support/SerilogSink.cs b/test/Serilog.Extensions.Logging.Tests/Support/CollectingSink.cs similarity index 90% rename from test/Serilog.Extensions.Logging.Tests/Support/SerilogSink.cs rename to test/Serilog.Extensions.Logging.Tests/Support/CollectingSink.cs index d26aac5..7d9a64c 100644 --- a/test/Serilog.Extensions.Logging.Tests/Support/SerilogSink.cs +++ b/test/Serilog.Extensions.Logging.Tests/Support/CollectingSink.cs @@ -6,7 +6,7 @@ namespace Serilog.Extensions.Logging.Tests.Support; -public class SerilogSink : ILogEventSink +public class CollectingSink : ILogEventSink { public List Writes { get; set; } = new();