From 2f13a51ac93426515469c3e7213f2d345ef5de1e Mon Sep 17 00:00:00 2001 From: huoshan12345 Date: Tue, 1 Apr 2025 22:48:47 +0800 Subject: [PATCH 1/3] using ForEachScopeReversed for IExternalScopeProvider --- .../Logging/SerilogLoggerProvider.cs | 18 ++++++++++-- .../SerilogLoggerTests.cs | 29 +++++++++++++++++++ 2 files changed, 45 insertions(+), 2 deletions(-) diff --git a/src/Serilog.Extensions.Logging/Extensions/Logging/SerilogLoggerProvider.cs b/src/Serilog.Extensions.Logging/Extensions/Logging/SerilogLoggerProvider.cs index 93dce5f..a4c69bd 100644 --- a/src/Serilog.Extensions.Logging/Extensions/Logging/SerilogLoggerProvider.cs +++ b/src/Serilog.Extensions.Logging/Extensions/Logging/SerilogLoggerProvider.cs @@ -104,10 +104,10 @@ public void Enrich(LogEvent logEvent, ILogEventPropertyFactory propertyFactory) scopeItems?.Reverse(); - _externalScopeProvider?.ForEachScope((state, accumulatingLogEvent) => + _externalScopeProvider?.ForEachScopeReversed((state, accumulatingLogEvent) => { SerilogLoggerScope.EnrichWithStateAndCreateScopeItem( - accumulatingLogEvent, propertyFactory, state, update: true, out var scopeItem); + accumulatingLogEvent, propertyFactory, state, update: false, out var scopeItem); if (scopeItem != null) { @@ -150,3 +150,17 @@ public ValueTask DisposeAsync() } #endif } + +file static class Extensions +{ + public static void ForEachScopeReversed(this IExternalScopeProvider provider, Action callback, TState state) + { + var list = new List<(object?, TState)>(); + provider.ForEachScope((m, n) => list.Add((m, n)), state); + + for (var i = list.Count - 1; i >= 0; i--) + { + callback(list[i].Item1, list[i].Item2); + } + } +} diff --git a/test/Serilog.Extensions.Logging.Tests/SerilogLoggerTests.cs b/test/Serilog.Extensions.Logging.Tests/SerilogLoggerTests.cs index 6b27c5d..610e74c 100644 --- a/test/Serilog.Extensions.Logging.Tests/SerilogLoggerTests.cs +++ b/test/Serilog.Extensions.Logging.Tests/SerilogLoggerTests.cs @@ -618,4 +618,33 @@ static void AssertHasScalarProperty(LogEvent logEvent, string name, object? expe var scalar = Assert.IsType(result); Assert.Equal(expectedValue, scalar.Value); } + + [Theory] + [InlineData(true)] + [InlineData(false)] + public void LoggingScopeShouldNotReplacePropertyInLogEvent(bool withExternalScopeProvider) + { + var sink = new CollectingSink(); + using var logger = new LoggerConfiguration().WriteTo.Sink(sink).CreateLogger(); + var serilogLoggerProvider = new SerilogLoggerProvider(logger); + + var services = new ServiceCollection(); + services.AddLogging(l => l.AddSerilog(logger)); + + using var serviceProvider = services.BuildServiceProvider(); + var msLogger = withExternalScopeProvider + ? serviceProvider.GetRequiredService>() + : serilogLoggerProvider.CreateLogger(Name); + + using (msLogger.BeginScope(new Dictionary { { "Value", 1 } })) + using (msLogger.BeginScope(new Dictionary { { "Value", 2 } })) + { + msLogger.LogInformation("Value: {Value}", 3); + } + + var logEvent = sink.Writes.First(); + var value = (logEvent.Properties["Value"] as ScalarValue)?.Value; + + Assert.Equal(3, value); + } } From 9663c49ad602e14eda12b67493c188cb5d63f9ed Mon Sep 17 00:00:00 2001 From: huoshan12345 Date: Sun, 14 Sep 2025 18:47:52 -0230 Subject: [PATCH 2/3] fix conflict --- .../Logging/SerilogLoggerProvider.cs | 19 ++++++++++-- .../SerilogLoggerTests.cs | 29 +++++++++++++++++++ 2 files changed, 46 insertions(+), 2 deletions(-) diff --git a/src/Serilog.Extensions.Logging/Extensions/Logging/SerilogLoggerProvider.cs b/src/Serilog.Extensions.Logging/Extensions/Logging/SerilogLoggerProvider.cs index 2ad7738..d314c3b 100644 --- a/src/Serilog.Extensions.Logging/Extensions/Logging/SerilogLoggerProvider.cs +++ b/src/Serilog.Extensions.Logging/Extensions/Logging/SerilogLoggerProvider.cs @@ -105,13 +105,13 @@ public void Enrich(LogEvent logEvent, ILogEventPropertyFactory propertyFactory) scopeCollector.ReverseItems(); - _externalScopeProvider?.ForEachScope(static (state, parameters) => + _externalScopeProvider?.ForEachScopeReversed(static (state, parameters) => { SerilogLoggerScope.EnrichWithStateAndCreateScopeItem( parameters.LogEvent, parameters.PropertyFactory, state, - update: true, + update: false, out var scopeItem); if (scopeItem != null) @@ -177,3 +177,18 @@ public void AddItem(LogEventPropertyValue scopeItem) } } } + + +file static class Extensions +{ + public static void ForEachScopeReversed(this IExternalScopeProvider provider, Action callback, TState state) + { + var list = new List<(object?, TState)>(); + provider.ForEachScope((m, n) => list.Add((m, n)), state); + + for (var i = list.Count - 1; i >= 0; i--) + { + callback(list[i].Item1, list[i].Item2); + } + } +} diff --git a/test/Serilog.Extensions.Logging.Tests/SerilogLoggerTests.cs b/test/Serilog.Extensions.Logging.Tests/SerilogLoggerTests.cs index bbbfb14..3ef97e5 100644 --- a/test/Serilog.Extensions.Logging.Tests/SerilogLoggerTests.cs +++ b/test/Serilog.Extensions.Logging.Tests/SerilogLoggerTests.cs @@ -634,4 +634,33 @@ public void ConflictingEventIdTemplatePropertyIsIgnored() var recordedEventId = Assert.IsType(recordedEventIdPropertyValue.Value); Assert.Equal(loggedEventId, recordedEventId); } + + [Theory] + [InlineData(true)] + [InlineData(false)] + public void LoggingScopeShouldNotReplacePropertyInLogEvent(bool withExternalScopeProvider) + { + var sink = new CollectingSink(); + using var logger = new LoggerConfiguration().WriteTo.Sink(sink).CreateLogger(); + var serilogLoggerProvider = new SerilogLoggerProvider(logger); + + var services = new ServiceCollection(); + services.AddLogging(l => l.AddSerilog(logger)); + + using var serviceProvider = services.BuildServiceProvider(); + var msLogger = withExternalScopeProvider + ? serviceProvider.GetRequiredService>() + : serilogLoggerProvider.CreateLogger(Name); + + using (msLogger.BeginScope(new Dictionary { { "Value", 1 } })) + using (msLogger.BeginScope(new Dictionary { { "Value", 2 } })) + { + msLogger.LogInformation("Value: {Value}", 3); + } + + var logEvent = sink.Writes.First(); + var value = (logEvent.Properties["Value"] as ScalarValue)?.Value; + + Assert.Equal(3, value); + } } From fd56b9861f8f57373fc53c08216c524bc07c454c Mon Sep 17 00:00:00 2001 From: huoshan12345 Date: Sun, 14 Sep 2025 19:01:30 -0230 Subject: [PATCH 3/3] use ThreadLocal as cache --- .../Logging/SerilogLoggerProvider.cs | 18 +++++++++++++++--- 1 file changed, 15 insertions(+), 3 deletions(-) diff --git a/src/Serilog.Extensions.Logging/Extensions/Logging/SerilogLoggerProvider.cs b/src/Serilog.Extensions.Logging/Extensions/Logging/SerilogLoggerProvider.cs index d314c3b..9f66537 100644 --- a/src/Serilog.Extensions.Logging/Extensions/Logging/SerilogLoggerProvider.cs +++ b/src/Serilog.Extensions.Logging/Extensions/Logging/SerilogLoggerProvider.cs @@ -181,14 +181,26 @@ public void AddItem(LogEventPropertyValue scopeItem) file static class Extensions { + public static void TryClear(this List list) + { + if (list.Count > 0) + list.Clear(); + } + + private static readonly ThreadLocal> _list = new(() => []); + public static void ForEachScopeReversed(this IExternalScopeProvider provider, Action callback, TState state) { - var list = new List<(object?, TState)>(); - provider.ForEachScope((m, n) => list.Add((m, n)), state); + var list = _list.Value!; + list.TryClear(); + + provider.ForEachScope((m, _) => list.Add(m), state); for (var i = list.Count - 1; i >= 0; i--) { - callback(list[i].Item1, list[i].Item2); + callback(list[i], state); } + + list.TryClear(); } }