diff --git a/src/Serilog.Extensions.Logging/Extensions/Logging/EventIdPropertyCache.cs b/src/Serilog.Extensions.Logging/Extensions/Logging/EventIdPropertyCache.cs new file mode 100644 index 0000000..d2159f3 --- /dev/null +++ b/src/Serilog.Extensions.Logging/Extensions/Logging/EventIdPropertyCache.cs @@ -0,0 +1,97 @@ +// Copyright (c) Serilog Contributors +// +// Licensed under the Apache License, Version 2.0 (the "License"); +// you may not use this file except in compliance with the License. +// You may obtain a copy of the License at +// +// http://www.apache.org/licenses/LICENSE-2.0 +// +// Unless required by applicable law or agreed to in writing, software +// distributed under the License is distributed on an "AS IS" BASIS, +// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +// See the License for the specific language governing permissions and +// limitations under the License. + +namespace Serilog.Extensions.Logging; + +using System.Collections.Concurrent; +using Microsoft.Extensions.Logging; +using Serilog.Events; + +class EventIdPropertyCache +{ + readonly int _maxCachedProperties; + readonly ConcurrentDictionary _propertyCache = new(); + + int _count; + + public EventIdPropertyCache(int maxCachedProperties = 1024) + { + _maxCachedProperties = maxCachedProperties; + } + + public LogEventProperty GetOrCreateProperty(in EventId eventId) + { + var eventKey = new EventKey(eventId); + + LogEventProperty? property; + + if (_count >= _maxCachedProperties) + { + if (!_propertyCache.TryGetValue(eventKey, out property)) + { + property = CreateProperty(in eventKey); + } + } + else + { + if (!_propertyCache.TryGetValue(eventKey, out property)) + { + // GetOrAdd is moved to a separate method to prevent closure allocation + property = GetOrAddCore(in eventKey); + } + } + + return property; + } + + static LogEventProperty CreateProperty(in EventKey eventKey) + { + var properties = new List(2); + + if (eventKey.Id != 0) + { + properties.Add(new LogEventProperty("Id", new ScalarValue(eventKey.Id))); + } + + if (eventKey.Name != null) + { + properties.Add(new LogEventProperty("Name", new ScalarValue(eventKey.Name))); + } + + return new LogEventProperty("EventId", new StructureValue(properties)); + } + + LogEventProperty GetOrAddCore(in EventKey eventKey) => + _propertyCache.GetOrAdd( + eventKey, + key => + { + Interlocked.Increment(ref _count); + + return CreateProperty(in key); + }); + + readonly record struct EventKey + { + public EventKey(EventId eventId) + { + Id = eventId.Id; + Name = eventId.Name; + } + + public int Id { get; } + + public string? Name { get; } + } +} diff --git a/src/Serilog.Extensions.Logging/Extensions/Logging/SerilogLogger.cs b/src/Serilog.Extensions.Logging/Extensions/Logging/SerilogLogger.cs index 3aa7fb1..a21d631 100644 --- a/src/Serilog.Extensions.Logging/Extensions/Logging/SerilogLogger.cs +++ b/src/Serilog.Extensions.Logging/Extensions/Logging/SerilogLogger.cs @@ -28,14 +28,10 @@ internal static string GetKeyWithoutFirstSymbol(ConcurrentDictionary new LogEventProperty("Id", new ScalarValue(n))) - .ToArray(); - public SerilogLogger( SerilogLoggerProvider provider, ILogger? logger = null, @@ -155,7 +151,7 @@ LogEvent PrepareWrite(LogEventLevel level, EventId eventId, TState state } if (eventId.Id != 0 || eventId.Name != null) - properties.Add(CreateEventIdProperty(eventId)); + properties.Add(_eventIdPropertyCache.GetOrCreateProperty(in eventId)); var (traceId, spanId) = Activity.Current is { } activity ? (activity.TraceId, activity.SpanId) : @@ -172,25 +168,4 @@ LogEvent PrepareWrite(LogEventLevel level, EventId eventId, TState state stateObj = formatter(state, null); return stateObj ?? state; } - - internal static LogEventProperty CreateEventIdProperty(EventId eventId) - { - var properties = new List(2); - - if (eventId.Id != 0) - { - if (eventId.Id >= 0 && eventId.Id < LowEventIdValues.Length) - // Avoid some allocations - properties.Add(LowEventIdValues[eventId.Id]); - else - properties.Add(new LogEventProperty("Id", new ScalarValue(eventId.Id))); - } - - if (eventId.Name != null) - { - properties.Add(new LogEventProperty("Name", new ScalarValue(eventId.Name))); - } - - return new LogEventProperty("EventId", new StructureValue(properties)); - } } diff --git a/test/Serilog.Extensions.Logging.Benchmarks/LogEventBenchmark.cs b/test/Serilog.Extensions.Logging.Benchmarks/LogEventBenchmark.cs index 995d462..6393348 100644 --- a/test/Serilog.Extensions.Logging.Benchmarks/LogEventBenchmark.cs +++ b/test/Serilog.Extensions.Logging.Benchmarks/LogEventBenchmark.cs @@ -34,6 +34,7 @@ private class Person readonly IMelLogger _melLogger; readonly Person _bob, _alice; + readonly EventId _eventId = new EventId(1, "Test"); public LogEventBenchmark() { @@ -61,5 +62,16 @@ public void LogInformationScoped() using (var scope = _melLogger.BeginScope("Hi {@User} from {$Me}", _bob, _alice)) _melLogger.LogInformation("Hi"); } + + [Benchmark] + public void LogInformation_WithEventId() + { + this._melLogger.Log( + LogLevel.Information, + _eventId, + "Hi {@User} from {$Me}", + _bob, + _alice); + } } } diff --git a/test/Serilog.Extensions.Logging.Tests/EventIdPropertyCacheTests.cs b/test/Serilog.Extensions.Logging.Tests/EventIdPropertyCacheTests.cs new file mode 100644 index 0000000..9949cbf --- /dev/null +++ b/test/Serilog.Extensions.Logging.Tests/EventIdPropertyCacheTests.cs @@ -0,0 +1,114 @@ +// Copyright (c) Serilog Contributors +// +// Licensed under the Apache License, Version 2.0 (the "License"); +// you may not use this file except in compliance with the License. +// You may obtain a copy of the License at +// +// http://www.apache.org/licenses/LICENSE-2.0 +// +// Unless required by applicable law or agreed to in writing, software +// distributed under the License is distributed on an "AS IS" BASIS, +// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +// See the License for the specific language governing permissions and +// limitations under the License. + +using Microsoft.Extensions.Logging; +using Serilog.Events; +using Xunit; + +namespace Serilog.Extensions.Logging.Tests; + +public class EventIdPropertyCacheTests +{ + [Fact] + public void CreatesPropertyWithCorrectIdAndName() + { + // Arrange + const int id = 101; + const string name = "TestEvent"; + var eventId = new EventId(id, name); + + var cache = new EventIdPropertyCache(); + + // Act + var eventProperty = cache.GetOrCreateProperty(eventId); + + // Assert + var value = Assert.IsType(eventProperty.Value); + + Assert.Equal(2, value.Properties.Count); + + var idValue = value.Properties.Single(property => property.Name == "Id").Value; + var nameValue = value.Properties.Single(property => property.Name == "Name").Value; + + var scalarId = Assert.IsType(idValue); + var scalarName = Assert.IsType(nameValue); + + Assert.Equal(id, scalarId.Value); + Assert.Equal(name, scalarName.Value); + } + + [Fact] + public void EventsWithDSameKeysHaveSameReferences() + { + // Arrange + var cache = new EventIdPropertyCache(); + + // Act + var property1 = cache.GetOrCreateProperty(new EventId(1, "Name1")); + var property2 = cache.GetOrCreateProperty(new EventId(1, "Name1")); + + // Assert + Assert.Same(property1, property2); + } + + [Theory] + [InlineData(1, "SomeName", 1, "AnotherName")] + [InlineData(1, "SomeName", 2, "SomeName")] + [InlineData(1, "SomeName", 2, "AnotherName")] + public void EventsWithDifferentKeysHaveDifferentReferences(int firstId, string firstName, int secondId, string secondName) + { + // Arrange + var cache = new EventIdPropertyCache(); + + // Act + var property1 = cache.GetOrCreateProperty(new EventId(firstId, firstName)); + var property2 = cache.GetOrCreateProperty(new EventId(secondId, secondName)); + + // Assert + Assert.NotSame(property1, property2); + } + + + [Fact] + public void WhenLimitIsNotOverSameEventsHaveSameReferences() + { + // Arrange + var eventId = new EventId(101, "test"); + var cache = new EventIdPropertyCache(); + + // Act + var property1 = cache.GetOrCreateProperty(eventId); + var property2 = cache.GetOrCreateProperty(eventId); + + // Assert + Assert.Same(property1, property2); + } + + [Fact] + public void WhenLimitIsOverSameEventsHaveDifferentReferences() + { + // Arrange + var cache = new EventIdPropertyCache(maxCachedProperties: 1); + cache.GetOrCreateProperty(new EventId(1, "InitialEvent")); + + var eventId = new EventId(101, "DifferentEvent"); + + // Act + var property1 = cache.GetOrCreateProperty(eventId); + var property2 = cache.GetOrCreateProperty(eventId); + + // Assert + Assert.NotSame(property1, property2); + } +} diff --git a/test/Serilog.Extensions.Logging.Tests/SerilogLoggerTests.cs b/test/Serilog.Extensions.Logging.Tests/SerilogLoggerTests.cs index 84bba82..b23f8f9 100644 --- a/test/Serilog.Extensions.Logging.Tests/SerilogLoggerTests.cs +++ b/test/Serilog.Extensions.Logging.Tests/SerilogLoggerTests.cs @@ -517,22 +517,6 @@ public void Dispose() } } - [Theory] - [InlineData(1)] - [InlineData(10)] - [InlineData(48)] - [InlineData(100)] - public void LowAndHighNumberedEventIdsAreMapped(int id) - { - var orig = new EventId(id, "test"); - var mapped = SerilogLogger.CreateEventIdProperty(orig); - var value = Assert.IsType(mapped.Value); - Assert.Equal(2, value.Properties.Count); - var idValue = value.Properties.Single(p => p.Name == "Id").Value; - var scalar = Assert.IsType(idValue); - Assert.Equal(id, scalar.Value); - } - [Fact] public void MismatchedMessageTemplateParameterCountIsHandled() {