Update to Serilog 4.x, remove some allocations

serilog-extensions-logging.sln.DotSettings

@@ -1,2 +1,3 @@
 <wpf:ResourceDictionary xml:space="preserve" xmlns:x="http://schemas.microsoft.com/winfx/2006/xaml" xmlns:s="clr-namespace:System;assembly=mscorlib" xmlns:ss="urn:shemas-jetbrains-com:settings-storage-xaml" xmlns:wpf="http://schemas.microsoft.com/winfx/2006/xaml/presentation">
+	<s:Boolean x:Key="/Default/UserDictionary/Words/=enricher/@EntryIndexedValue">True</s:Boolean>
 	<s:Boolean x:Key="/Default/UserDictionary/Words/=stringified/@EntryIndexedValue">True</s:Boolean></wpf:ResourceDictionary>

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

@@ -93,30 +93,33 @@ LogEvent PrepareWrite<TState>(LogEventLevel level, EventId eventId, TState state
     {
         string? messageTemplate = null;
 
-        var properties = new List<LogEventProperty>();
+        var properties = new Dictionary<string, LogEventPropertyValue>();
 
         if (state is IEnumerable<KeyValuePair<string, object>> structure)
         {
             foreach (var property in structure)
             {
-                if (property.Key == SerilogLoggerProvider.OriginalFormatPropertyName && property.Value is string value)
+                if (property is { Key: SerilogLoggerProvider.OriginalFormatPropertyName, Value: string value })
                 {
                     messageTemplate = value;
                 }
                 else if (property.Key.StartsWith("@"))
                 {
                     if (_logger.BindProperty(GetKeyWithoutFirstSymbol(DestructureDictionary, property.Key), property.Value, true, out var destructured))
-                        properties.Add(destructured);
+                        properties.Add(destructured.Name, destructured.Value);
                 }
                 else if (property.Key.StartsWith("$"))
                 {
                     if (_logger.BindProperty(GetKeyWithoutFirstSymbol(StringifyDictionary, property.Key), property.Value?.ToString(), true, out var stringified))
-                        properties.Add(stringified);
+                        properties.Add(stringified.Name, stringified.Value);
                 }
                 else
                 {
-                    if (_logger.BindProperty(property.Key, property.Value, false, out var bound))
-                        properties.Add(bound);
+                    // Simple micro-optimization for the most common and reliably scalar values; could go further here.
+                    if (property.Value is null or string or int or long && LogEventProperty.IsValidName(property.Key))
+                        properties.Add(property.Key, new ScalarValue(property.Value));
+                    else if (_logger.BindProperty(property.Key, property.Value, false, out var bound))
+                        properties.Add(bound.Name, bound.Value);
                 }
             }
 
@@ -127,7 +130,7 @@ LogEvent PrepareWrite<TState>(LogEventLevel level, EventId eventId, TState state
             {
                 messageTemplate = "{" + stateType.Name + ":l}";
                 if (_logger.BindProperty(stateType.Name, AsLoggableValue(state, formatter), false, out var stateTypeProperty))
-                    properties.Add(stateTypeProperty);
+                    properties.Add(stateTypeProperty.Name, stateTypeProperty.Value);
             }
         }
 
@@ -150,19 +153,19 @@ LogEvent PrepareWrite<TState>(LogEventLevel level, EventId eventId, TState state
             if (propertyName != null)
             {
                 if (_logger.BindProperty(propertyName, AsLoggableValue(state, formatter!), false, out var property))
-                    properties.Add(property);
+                    properties.Add(property.Name, property.Value);
             }
         }
 
-        if (eventId.Id != 0 || eventId.Name != null)
-            properties.Add(CreateEventIdProperty(eventId));
+        if (eventId != default)
+            properties.Add("EventId", CreateEventIdPropertyValue(eventId));
 
         var (traceId, spanId) = Activity.Current is { } activity ?
             (activity.TraceId, activity.SpanId) :
             (default(ActivityTraceId), default(ActivitySpanId));
 
         var parsedTemplate = MessageTemplateParser.Parse(messageTemplate ?? "");
-        return new LogEvent(DateTimeOffset.Now, level, exception, parsedTemplate, properties, traceId, spanId);
+        return LogEvent.UnstableAssembleFromParts(DateTimeOffset.Now, level, exception, parsedTemplate, properties, traceId, spanId);
     }
 
     static object? AsLoggableValue<TState>(TState state, Func<TState, Exception?, string>? formatter)
@@ -173,7 +176,7 @@ LogEvent PrepareWrite<TState>(LogEventLevel level, EventId eventId, TState state
         return stateObj ?? state;
     }
 
-    internal static LogEventProperty CreateEventIdProperty(EventId eventId)
+    internal static StructureValue CreateEventIdPropertyValue(EventId eventId)
     {
         var properties = new List<LogEventProperty>(2);
 
@@ -191,6 +194,6 @@ internal static LogEventProperty CreateEventIdProperty(EventId eventId)
             properties.Add(new LogEventProperty("Name", new ScalarValue(eventId.Name)));
         }
 
-        return new LogEventProperty("EventId", new StructureValue(properties));
+        return new StructureValue(properties);
     }
 }

src/Serilog.Extensions.Logging/Extensions/Logging/SerilogLoggerProvider.cs

@@ -21,7 +21,7 @@ public class SerilogLoggerProvider : ILoggerProvider, ILogEventEnricher, ISuppor
     // May be null; if it is, Log.Logger will be lazily used
     readonly ILogger? _logger;
     readonly Action? _dispose;
-    private IExternalScopeProvider? _externalScopeProvider;
+    IExternalScopeProvider? _externalScopeProvider;
 
     /// <summary>
     /// Construct a <see cref="SerilogLoggerProvider"/>.

src/Serilog.Extensions.Logging/Extensions/Logging/SerilogLoggerScope.cs

@@ -49,68 +49,64 @@ public void Dispose()
 
     public void EnrichAndCreateScopeItem(LogEvent logEvent, ILogEventPropertyFactory propertyFactory, out LogEventPropertyValue? scopeItem)
     {
-        void AddProperty(string key, object? value)
-        {
-            var destructureObject = false;
-
-            if (key.StartsWith("@"))
-            {
-                key = SerilogLogger.GetKeyWithoutFirstSymbol(SerilogLogger.DestructureDictionary, key);
-                destructureObject = true;
-            }
-            else if (key.StartsWith("$"))
-            {
-                key = SerilogLogger.GetKeyWithoutFirstSymbol(SerilogLogger.StringifyDictionary, key);
-                value = value?.ToString();
-            }
-
-            var property = propertyFactory.CreateProperty(key, value, destructureObject);
-            logEvent.AddPropertyIfAbsent(property);
-        }
-
         if (_state == null)
         {
             scopeItem = null;
             return;
         }
 
-        // Eliminates boxing of Dictionary<TKey, TValue>.Enumerator for the most common use case
         if (_state is Dictionary<string, object> dictionary)
         {
-            scopeItem = null; // Unless it's `FormattedLogValues`, these are treated as property bags rather than scope items.
-
+            // Separate handling of this case eliminates boxing of Dictionary<TKey, TValue>.Enumerator.
+            scopeItem = null;
             foreach (var stateProperty in dictionary)
             {
-                if (stateProperty.Key == SerilogLoggerProvider.OriginalFormatPropertyName && stateProperty.Value is string)
-                    scopeItem = new ScalarValue(_state.ToString());
-                else
-                    AddProperty(stateProperty.Key, stateProperty.Value);
+                AddProperty(logEvent, propertyFactory, stateProperty.Key, stateProperty.Value);
             }
         }
         else if (_state is IEnumerable<KeyValuePair<string, object>> stateProperties)
         {
-            scopeItem = null; // Unless it's `FormattedLogValues`, these are treated as property bags rather than scope items.
-
+            scopeItem = null;
             foreach (var stateProperty in stateProperties)
             {
-                if (stateProperty.Key == SerilogLoggerProvider.OriginalFormatPropertyName && stateProperty.Value is string)
+                if (stateProperty is { Key: SerilogLoggerProvider.OriginalFormatPropertyName, Value: string })
+                {
+                    // `_state` is most likely `FormattedLogValues` (a MEL internal type).
                     scopeItem = new ScalarValue(_state.ToString());
+                }
                 else
-                    AddProperty(stateProperty.Key, stateProperty.Value);
+                {
+                    AddProperty(logEvent, propertyFactory, stateProperty.Key, stateProperty.Value);
+                }
             }
         }
         else if (_state is ValueTuple<string, object?> tuple)
         {
-            scopeItem = null; // Unless it's `FormattedLogValues`, these are treated as property bags rather than scope items.
-
-            if (tuple.Item1 == SerilogLoggerProvider.OriginalFormatPropertyName && tuple.Item2 is string)
-                scopeItem = new ScalarValue(_state.ToString());
-            else
-                AddProperty(tuple.Item1, tuple.Item2);
+            scopeItem = null;
+            AddProperty(logEvent, propertyFactory, tuple.Item1, tuple.Item2);
         }
         else
         {
             scopeItem = propertyFactory.CreateProperty(NoName, _state).Value;
         }
     }
+
+    static void AddProperty(LogEvent logEvent, ILogEventPropertyFactory propertyFactory, string key, object? value)
+    {
+        var destructureObject = false;
+
+        if (key.StartsWith("@"))
+        {
+            key = SerilogLogger.GetKeyWithoutFirstSymbol(SerilogLogger.DestructureDictionary, key);
+            destructureObject = true;
+        }
+        else if (key.StartsWith("$"))
+        {
+            key = SerilogLogger.GetKeyWithoutFirstSymbol(SerilogLogger.StringifyDictionary, key);
+            value = value?.ToString();
+        }
+
+        var property = propertyFactory.CreateProperty(key, value, destructureObject);
+        logEvent.AddPropertyIfAbsent(property);
+    }
 }

src/Serilog.Extensions.Logging/Serilog.Extensions.Logging.csproj

@@ -29,7 +29,7 @@
     <None Include="..\..\assets\serilog-extension-nuget.png" Pack="true" PackagePath="" Visible="false" />
     <None Include="..\..\README.md" Pack="true" PackagePath="\" Visible="false" />
     <PackageReference Include="Microsoft.SourceLink.GitHub" Version="1.1.1" PrivateAssets="All" />
-    <PackageReference Include="Serilog" Version="3.1.1" />
+    <PackageReference Include="Serilog" Version="4.0.0-*" />
     <!-- The version of this reference must match the major and minor components of the package version prefix. -->
     <PackageReference Include="Microsoft.Extensions.Logging" Version="8.0.0" />
     <PackageReference Include="Nullable" Version="1.3.1" PrivateAssets="All" />

test/Serilog.Extensions.Logging.Benchmarks/LogEventBenchmark.cs

@@ -20,46 +20,93 @@
 
 #pragma warning disable xUnit1013 // Public method should be marked as test
 
-namespace Serilog.Extensions.Logging.Benchmarks
+namespace Serilog.Extensions.Logging.Benchmarks;
+
+[MemoryDiagnoser]
+public class LogEventBenchmark
 {
-    [MemoryDiagnoser]
-    public class LogEventBenchmark
+    class Person
+    {
+        public string? Name { get; set; }
+        public int Age { get; set; }
+        public override string ToString() => "Fixed text";
+    }
+
+    readonly IMelLogger _melLogger;
+    readonly Person _bob, _alice;
+    readonly ILogger _underlyingLogger;
+
+    public LogEventBenchmark()
+    {
+        _underlyingLogger = new LoggerConfiguration().CreateLogger();
+        _melLogger = new SerilogLoggerProvider(_underlyingLogger).CreateLogger(GetType().FullName!);
+        _bob = new Person { Name = "Bob", Age = 42 };
+        _alice = new Person { Name = "Alice", Age = 42 };
+    }
+
+    [Fact]
+    public void Benchmark()
+    {
+        BenchmarkRunner.Run<LogEventBenchmark>();
+    }
+
+    [Benchmark(Baseline = true)]
+    public void SerilogOnly()
+    {
+        _underlyingLogger.Information("Hello!");
+    }
+
+    [Benchmark]
+    public void SimpleEvent()
+    {
+        _melLogger.LogInformation("Hello!");
+    }
+
+    [Benchmark]
+    public void Template()
+    {
+        _melLogger.LogInformation("Hello, {Property1}!", 42);
+    }
+
+    [Benchmark]
+    public void StringScope()
+    {
+        using var scope = _melLogger.BeginScope("Scope1");
+        _melLogger.LogInformation("Hello!");
+    }
+
+    [Benchmark]
+    public void TemplateScope()
+    {
+        using var scope = _melLogger.BeginScope("Scope1 {Property1}", 42);
+        _melLogger.LogInformation("Hello!");
+    }
+
+    [Benchmark]
+    public void TupleScope()
+    {
+        using var scope = _melLogger.BeginScope(("Property1", 42));
+        _melLogger.LogInformation("Hello!");
+    }
+
+    [Benchmark]
+    public void DictionaryScope()
+    {
+        // Note that allocations here include the dictionary and boxed int.
+        using var scope = _melLogger.BeginScope(new Dictionary<string, object> { ["Property1"] = 42 });
+        _melLogger.LogInformation("Hello!");
+    }
+
+    [Benchmark]
+    public void Capturing()
+    {
+        _melLogger.LogInformation("Hi {@User} from {$Me}", _bob, _alice);
+    }
+
+    [Benchmark]
+    public void CapturingScope()
     {
-        private class Person
-        {
-            public string? Name { get; set; }
-            public int Age { get; set; }
-            public override string ToString() => "Fixed text";
-        }
-
-        readonly IMelLogger _melLogger;
-        readonly Person _bob, _alice;
-
-        public LogEventBenchmark()
-        {
-            var underlyingLogger = new LoggerConfiguration().CreateLogger();
-            _melLogger = new SerilogLoggerProvider(underlyingLogger).CreateLogger(GetType().FullName!);
-            _bob = new Person { Name = "Bob", Age = 42 };
-            _alice = new Person { Name = "Alice", Age = 42 };
-        }
-
-        [Fact]
-        public void Benchmark()
-        {
-            BenchmarkRunner.Run<LogEventBenchmark>();
-        }
-
-        [Benchmark]
-        public void LogInformation()
-        {
-            _melLogger.LogInformation("Hi {@User} from {$Me}", _bob, _alice);
-        }
-
-        [Benchmark]
-        public void LogInformationScoped()
-        {
-            using (var scope = _melLogger.BeginScope("Hi {@User} from {$Me}", _bob, _alice))
-                _melLogger.LogInformation("Hi");
-        }
+        using var scope = _melLogger.BeginScope("Hi {@User} from {$Me}", _bob, _alice);
+        _melLogger.LogInformation("Hi");
     }
 }

test/Serilog.Extensions.Logging.Benchmarks/Serilog.Extensions.Logging.Benchmarks.csproj

@@ -13,7 +13,7 @@
     <PackageReference Include="Microsoft.NET.Test.Sdk" Version="17.8.0" />
     <PackageReference Include="xunit.runner.visualstudio" Version="2.5.3" PrivateAssets="All" />
     <PackageReference Include="xunit" Version="2.6.1" />
-    <PackageReference Include="BenchmarkDotNet" Version="0.13.10" />
+    <PackageReference Include="BenchmarkDotNet" Version="0.13.12" />
   </ItemGroup>
 
 </Project>

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

@@ -500,9 +500,9 @@ public IDisposable Push(object? state)
             return scope;
         }
 
-        private class Scope : IDisposable
+        class Scope : IDisposable
         {
-            public bool IsDisposed { get; set; } = false;
+            public bool IsDisposed { get; set; }
             public object? Value { get; set; }
 
             public Scope(object? value)
@@ -525,8 +525,7 @@ public void Dispose()
     public void LowAndHighNumberedEventIdsAreMapped(int id)
     {
         var orig = new EventId(id, "test");
-        var mapped = SerilogLogger.CreateEventIdProperty(orig);
-        var value = Assert.IsType<StructureValue>(mapped.Value);
+        var value = SerilogLogger.CreateEventIdPropertyValue(orig);
         Assert.Equal(2, value.Properties.Count);
         var idValue = value.Properties.Single(p => p.Name == "Id").Value;
         var scalar = Assert.IsType<ScalarValue>(idValue);