Skip to content

Commit 996fc65

Browse files
snakefootsnakefoot
authored
NLogLogger - Reduce allocation by not boxing EventId when CaptureEntireEventId = false (#319)
1 parent e2bffa9 commit 996fc65

4 files changed

Lines changed: 49 additions & 17 deletions

File tree

‎src/NLog.Extensions.Logging/Logging/NLogLogger.cs‎

Lines changed: 22 additions & 4 deletions
Original file line numberDiff line numberDiff line change
@@ -1,5 +1,6 @@
11
using System;
22
using System.Collections.Generic;
3+
using System.Linq;
34
using Microsoft.Extensions.Logging;
45
using NLog.MessageTemplates;
56

@@ -18,6 +19,7 @@ internal class NLogLogger : Microsoft.Extensions.Logging.ILogger
1819
internal const string OriginalFormatPropertyName = "{OriginalFormat}";
1920
private static readonly object EmptyEventId = default(EventId); // Cache boxing of empty EventId-struct
2021
private static readonly object ZeroEventId = default(EventId).Id; // Cache boxing of zero EventId-Value
22+
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
2123
private Tuple<string, string, string> _eventIdPropertyNames;
2224

2325
public NLogLogger(Logger logger, NLogProviderOptions options, NLogBeginScopeParser beginScopeParser)
@@ -326,7 +328,7 @@ private static void SetLogEventMessageFormatter(LogEventInfo logEvent, NLogMessa
326328

327329
private void CaptureEventId(LogEventInfo eventInfo, EventId eventId)
328330
{
329-
if (!_options.IgnoreEmptyEventId || eventId.Id != 0 || !String.IsNullOrEmpty(eventId.Name))
331+
if (_options.CaptureMessageProperties && (!_options.IgnoreEmptyEventId || eventId.Id != 0 || !String.IsNullOrEmpty(eventId.Name)))
330332
{
331333
// Attempt to reuse the same string-allocations based on the current <see cref="NLogProviderOptions.EventIdSeparator"/>
332334
var eventIdPropertyNames = _eventIdPropertyNames ?? new Tuple<string, string, string>(null, null, null);
@@ -338,12 +340,28 @@ private void CaptureEventId(LogEventInfo eventInfo, EventId eventId)
338340
}
339341

340342
var idIsZero = eventId.Id == 0;
341-
eventInfo.Properties[eventIdPropertyNames.Item2] = idIsZero ? ZeroEventId : eventId.Id;
342-
eventInfo.Properties[eventIdPropertyNames.Item3] = eventId.Name;
343-
eventInfo.Properties["EventId"] = idIsZero && eventId.Name == null ? EmptyEventId : eventId;
343+
var eventIdObj = idIsZero ? ZeroEventId : GetEventId(eventId.Id);
344+
eventInfo.Properties[eventIdPropertyNames.Item2] = eventIdObj;
345+
if (_options.CaptureEntireEventId)
346+
{
347+
eventInfo.Properties[eventIdPropertyNames.Item3] = eventId.Name;
348+
eventInfo.Properties["EventId"] = idIsZero && eventId.Name == null ? EmptyEventId : eventId;
349+
}
350+
else if (!string.IsNullOrEmpty(eventId.Name))
351+
{
352+
eventInfo.Properties[eventIdPropertyNames.Item3] = eventId.Name;
353+
}
344354
}
345355
}
346356

357+
private static object GetEventId(int eventId)
358+
{
359+
if (eventId >= 0 && eventId < EventIdBoxing.Length)
360+
return EventIdBoxing[eventId];
361+
else
362+
return eventId;
363+
}
364+
347365
private static Tuple<string, string, string> CreateEventIdPropertyNames(string eventIdSeparator)
348366
{
349367
var eventIdPropertyNames = new Tuple<string, string, string>(

‎src/NLog.Extensions.Logging/Logging/NLogProviderOptions.cs‎

Lines changed: 9 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -19,7 +19,7 @@ public class NLogProviderOptions
1919
public bool IgnoreEmptyEventId { get; set; } = true;
2020

2121
/// <summary>
22-
/// Enable structured logging by capturing message template parameters and inject into the <see cref="LogEventInfo.Properties" />-dictionary
22+
/// Enable structured logging by capturing message template parameters with support for "@" and "$". Enables use of ${message:raw=true}
2323
/// </summary>
2424
public bool CaptureMessageTemplates { get; set; } = true;
2525

@@ -74,6 +74,14 @@ public class NLogProviderOptions
7474
/// <remarks>Will only attempt to load NLog-LoggingConfiguration if valid section-name, and NLog-LoggingConfiguration has not been loaded already.</remarks>
7575
public string LoggingConfigurationSectionName { get; set; }
7676

77+
/// <summary>
78+
/// Enable additional capture of the entire <see cref="Microsoft.Extensions.Logging.EventId"/> as "EventId"-property.
79+
/// </summary>
80+
/// <remarks>
81+
/// Enabling capture of the entire "EventId" will increase memory allocation and gives a performance hit. Faster to use "EventId_Id" + "EventId_Name".
82+
/// </remarks>
83+
public bool CaptureEntireEventId { get; set; }
84+
7785
/// <summary>Initializes a new instance NLogProviderOptions with default values.</summary>
7886
public NLogProviderOptions()
7987
{

‎test/NLog.Extensions.Logging.Tests/Extensions/ConfigureExtensionsTests.cs‎

Lines changed: 17 additions & 11 deletions
Original file line numberDiff line numberDiff line change
@@ -31,21 +31,24 @@ public void AddNLog_LoggerFactory_LogInfo_ShouldLogToNLog()
3131
}
3232

3333
[Theory]
34-
[InlineData("EventId", "eventId2")]
35-
[InlineData("EventId_Name", "eventId2")]
36-
[InlineData("EventId_Id", "2")]
34+
[InlineData("EventId", "eventId_2", true)]
35+
[InlineData("EventId_Name", "eventId_2", true)]
36+
[InlineData("EventId_Id", "2", true)]
37+
[InlineData("EventId", "", false)]
38+
[InlineData("EventId_Name", "eventId_2", false)]
39+
[InlineData("EventId_Id", "2", false)]
3740
[Obsolete("Instead use ILoggingBuilder.AddNLog() or IHostBuilder.UseNLog()")]
38-
public void AddNLog_LoggerFactory_LogInfoWithEventId_ShouldLogToNLogWithEventId(string eventPropery, string expectedEventInLog)
41+
public void AddNLog_LoggerFactory_LogInfoWithEventId_ShouldLogToNLogWithEventId(string eventPropery, string expectedEventInLog, bool captureEntireEventId)
3942
{
4043
// Arrange
4144
var loggerFactory = new LoggerFactory();
4245
var config = CreateConfigWithMemoryTarget(out var memoryTarget, $"${{event-properties:{eventPropery}}} - ${{message}}");
4346

4447
// Act
45-
loggerFactory.AddNLog(new NLogProviderOptions { EventIdSeparator = "_" });
48+
loggerFactory.AddNLog(new NLogProviderOptions { EventIdSeparator = "_", CaptureEntireEventId = captureEntireEventId });
4649
LogManager.Configuration = config;
4750
var logger = loggerFactory.CreateLogger("logger1");
48-
logger.LogInformation(new EventId(2, "eventId2"), "test message with {0} arg", 1);
51+
logger.LogInformation(new EventId(2, "eventId_2"), "test message with {0} arg", 1);
4952

5053
// Assert
5154
AssertSingleMessage(memoryTarget, $"{expectedEventInLog} - test message with 1 arg");
@@ -95,15 +98,18 @@ public void AddNLog_LoggingBuilder_LogInfo_ShouldLogToNLog()
9598
}
9699

97100
[Theory]
98-
[InlineData("EventId", "eventId2")]
99-
[InlineData("EventId_Name", "eventId2")]
100-
[InlineData("EventId_Id", "2")]
101-
public void AddNLog_LoggingBuilder_LogInfoWithEventId_ShouldLogToNLogWithEventId(string eventPropery, string expectedEventInLog)
101+
[InlineData("EventId", "eventId2", true)]
102+
[InlineData("EventId_Name", "eventId2", true)]
103+
[InlineData("EventId_Id", "2", true)]
104+
[InlineData("EventId", "", false)]
105+
[InlineData("EventId_Name", "eventId2", false)]
106+
[InlineData("EventId_Id", "2", false)]
107+
public void AddNLog_LoggingBuilder_LogInfoWithEventId_ShouldLogToNLogWithEventId(string eventPropery, string expectedEventInLog, bool captureEntireEventId)
102108
{
103109
// Arrange
104110
ILoggingBuilder builder = new LoggingBuilderStub();
105111
var config = CreateConfigWithMemoryTarget(out var memoryTarget, $"${{event-properties:{eventPropery}}} - ${{message}}");
106-
var options = new NLogProviderOptions { EventIdSeparator = "_" };
112+
var options = new NLogProviderOptions { EventIdSeparator = "_", CaptureEntireEventId = captureEntireEventId };
107113

108114
// Act
109115
builder.AddNLog(config, options);

‎test/NLog.Extensions.Logging.Tests/nlog.config‎

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -8,7 +8,7 @@
88
<targets>
99
<!-- write logs to file -->
1010
<target xsi:type="Memory" name="target1"
11-
layout="${logger}|${uppercase:${level}}|${message} ${exception}|${event-properties:EventId}${event-properties:ParameterCount}${mdlc:item=scope1}" />
11+
layout="${logger}|${uppercase:${level}}|${message} ${exception}|${event-properties:EventId_Id}${event-properties:ParameterCount}${mdlc:item=scope1}" />
1212

1313
</targets>
1414

0 commit comments

Comments
 (0)