NLogLogger - Reduce allocation by not boxing EventId when CaptureEnti…

…reEventId = false
NLog · Aug 20, 2019 · 952ba47 · 952ba47
1 parent 407e66f
commit 952ba47
Show file tree

Hide file tree

Showing 4 changed files with 43 additions and 15 deletions.
diff --git a/src/NLog.Extensions.Logging/Logging/NLogLogger.cs b/src/NLog.Extensions.Logging/Logging/NLogLogger.cs
@@ -1,5 +1,6 @@
 using System;
 using System.Collections.Generic;
+using System.Linq;
 using Microsoft.Extensions.Logging;
 using NLog.MessageTemplates;
 
@@ -18,6 +19,7 @@ internal class NLogLogger : Microsoft.Extensions.Logging.ILogger
         internal const string OriginalFormatPropertyName = "{OriginalFormat}";
         private static readonly object EmptyEventId = default(EventId);    // Cache boxing of empty EventId-struct
         private static readonly object ZeroEventId = default(EventId).Id;  // Cache boxing of zero EventId-Value
+        private static readonly object[] EventIdBoxing = Enumerable.Range(0, 50).Select(v => (object)v).ToArray();  // Most EventIds in the ASP.NET Core Engine is below 50
         private Tuple<string, string, string> _eventIdPropertyNames;
 
         public NLogLogger(Logger logger, NLogProviderOptions options, NLogBeginScopeParser beginScopeParser)
@@ -339,12 +341,28 @@ private void CaptureEventId(LogEventInfo eventInfo, EventId eventId)
                 }
 
                 var idIsZero = eventId.Id == 0;
-                eventInfo.Properties[eventIdPropertyNames.Item2] = idIsZero ? ZeroEventId : eventId.Id;
-                eventInfo.Properties[eventIdPropertyNames.Item3] = eventId.Name;
-                eventInfo.Properties["EventId"] = idIsZero && eventId.Name == null ? EmptyEventId : eventId;
+                var eventIdObj = idIsZero ? ZeroEventId : GetEventId(eventId.Id);
+                eventInfo.Properties[eventIdPropertyNames.Item2] = eventIdObj;
+                if (_options.CaptureEntireEventId)
+                {
+                    eventInfo.Properties[eventIdPropertyNames.Item3] = eventId.Name;
+                    eventInfo.Properties["EventId"] = idIsZero && eventId.Name == null ? EmptyEventId : eventId;
+                }
+                else if (!string.IsNullOrEmpty(eventId.Name))
+                {
+                    eventInfo.Properties[eventIdPropertyNames.Item3] = eventId.Name;
+                }
             }
         }
 
+        private static object GetEventId(int eventId)
+        {
+            if (eventId >= 0 && eventId < EventIdBoxing.Length)
+                return EventIdBoxing[eventId];
+            else
+                return eventId;
+        }
+
         private static Tuple<string, string, string> CreateEventIdPropertyNames(string eventIdSeparator)
         {
             var eventIdPropertyNames = new Tuple<string, string, string>(

diff --git a/src/NLog.Extensions.Logging/Logging/NLogProviderOptions.cs b/src/NLog.Extensions.Logging/Logging/NLogProviderOptions.cs
@@ -15,9 +15,7 @@ public class NLogProviderOptions
         /// <summary>
         /// Skip allocation of <see cref="LogEventInfo.Properties" />-dictionary
         /// </summary>
-        /// <remarks>
-        /// using
-        ///     <c>default(EventId)</c></remarks>
+        /// <remarks>using <c>default(EventId)</c></remarks>
         public bool IgnoreEmptyEventId { get; set; }
 
         /// <summary>
@@ -43,9 +41,17 @@ public class NLogProviderOptions
         /// <summary>
         /// Shutdown NLog on dispose of the <see cref="NLogLoggerProvider"/>
         /// </summary>
-        public bool ShutdownOnDispose { get; set; } 
+        public bool ShutdownOnDispose { get; set; }
+
+        /// <summary>
+        /// Enable additional capture of the entire <see cref="Microsoft.Extensions.Logging.EventId"/> as "EventId"-property.
+        /// </summary>
+        /// <remarks>
+        /// Enabling capture of the entire "EventId" will increase memory allocation and gives a performance hit. Faster to use "EventId_Id" + "EventId_Name".
+        /// </remarks>
+        public bool CaptureEntireEventId { get; set; }
 
-        /// <summary>Initializes a new instance of the <see cref="T:System.Object" /> class.</summary>
+        /// <summary>Initializes a new instance of the <see cref="NLogProviderOptions" /> class.</summary>
         public NLogProviderOptions()
         {
             EventIdSeparator = "_";
@@ -54,6 +60,7 @@ public NLogProviderOptions()
             CaptureMessageProperties = true;
             ParseMessageTemplates = false;
             IncludeScopes = true;
+            CaptureEntireEventId = false;
         }
 
         /// <summary>

diff --git a/test/NLog.Extensions.Logging.Tests/Extensions/ConfigureExtensionsTests.cs b/test/NLog.Extensions.Logging.Tests/Extensions/ConfigureExtensionsTests.cs
@@ -30,20 +30,23 @@ public void AddNLog_LoggerFactory_LogInfo_ShouldLogToNLog()
         }
 
         [Theory]
-        [InlineData("EventId", "eventId2")]
-        [InlineData("EventId_Name", "eventId2")]
-        [InlineData("EventId_Id", "2")]
-        public void AddNLog_LoggerFactory_LogInfoWithEventId_ShouldLogToNLogWithEventId(string eventPropery, string expectedEventInLog)
+        [InlineData("EventId", "eventId_2", true)]
+        [InlineData("EventId_Name", "eventId_2", true)]
+        [InlineData("EventId_Id", "2", true)]
+        [InlineData("EventId", "", false)]
+        [InlineData("EventId_Name", "eventId_2", false)]
+        [InlineData("EventId_Id", "2", false)]
+        public void AddNLog_LoggerFactory_LogInfoWithEventId_ShouldLogToNLogWithEventId(string eventPropery, string expectedEventInLog, bool captureEntireEventId)
         {
             // Arrange
             var loggerFactory = new LoggerFactory();
             var config = CreateConfigWithMemoryTarget(out var memoryTarget, $"${{event-properties:{eventPropery}}} - ${{message}}");
 
             // Act
-            loggerFactory.AddNLog(new NLogProviderOptions { EventIdSeparator = "_" });
+            loggerFactory.AddNLog(new NLogProviderOptions { EventIdSeparator = "_", CaptureEntireEventId = captureEntireEventId });
             LogManager.Configuration = config;
             var logger = loggerFactory.CreateLogger("logger1");
-            logger.LogInformation(new EventId(2, "eventId2"), "test message with {0} arg", 1);
+            logger.LogInformation(new EventId(2, "eventId_2"), "test message with {0} arg", 1);
 
             // Assert
             AssertSingleMessage(memoryTarget, $"{expectedEventInLog} - test message with 1 arg");

diff --git a/test/NLog.Extensions.Logging.Tests/nlog.config b/test/NLog.Extensions.Logging.Tests/nlog.config
@@ -8,7 +8,7 @@
   <targets>
     <!-- write logs to file -->
     <target xsi:type="Memory" name="target1"
-            layout="${logger}|${uppercase:${level}}|${message} ${exception}|${event-properties:EventId}${event-properties:ParameterCount}${mdlc:item=scope1}" />
+            layout="${logger}|${uppercase:${level}}|${message} ${exception}|${event-properties:EventId_Id}${event-properties:ParameterCount}${mdlc:item=scope1}" />
 
   </targets>