Introduced CaptureMessageParameters to skip allocating Parameters-array

CHANGELOG.MD

@@ -2,6 +2,12 @@
 
 Date format: (year/month/day)
 
+### Version 5.3.4 (2023/09/06)
+
+**Improvements**
+- [#687](https://github.com/NLog/NLog.Extensions.Logging/pull/687): Introduced CaptureMessageParameters to skip allocating Parameters-array (@snakefoot)
+- [#687](https://github.com/NLog/NLog.Extensions.Logging/pull/687): Updated to NLog v5.2.4 (@snakefoot)
+
 ### Version 5.3.3 (2023/08/05)
 
 **Improvements**

build.ps1

@@ -2,7 +2,7 @@
 # creates NuGet package at \artifacts
 dotnet --version
 
-$versionPrefix = "5.3.3"
+$versionPrefix = "5.3.4"
 $versionSuffix = ""
 $versionFile = $versionPrefix + "." + ${env:APPVEYOR_BUILD_NUMBER}
 $versionProduct = $versionPrefix;

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

@@ -59,10 +59,11 @@ private LogEventInfo CreateLogEventInfo<TState>(LogLevel nLogLogLevel, EventId e
                     var messageParameters = NLogMessageParameterList.TryParse(messagePropertyList);
                     if (messageParameters.Count == 0)
                     {
-                        var logEvent = LogEventInfo.Create(nLogLogLevel, _logger.Name, formatter(state, exception));
+                        var logEvent = TryParsePostionalMessageTemplate(nLogLogLevel, messagePropertyList, messageParameters)
+                            ?? CaputureBasicLogEvent(nLogLogLevel, formatter(state, exception), messagePropertyList, messageParameters);
                         CaptureEventIdProperties(logEvent, eventId);
                         return logEvent;
-                    }
+}
                     else
                     {
                         var logEvent = TryParseMessageTemplate(nLogLogLevel, messagePropertyList, messageParameters)
@@ -103,7 +104,7 @@ private LogEventInfo TryParseMessageTemplate(LogLevel nLogLogLevel, IReadOnlyLis
         {
             if (messageParameters.HasMessageTemplateSyntax(_options.ParseMessageTemplates))
             {
-                var originalMessage = messageParameters?.GetOriginalMessage(messageProperties);
+                var originalMessage = messageParameters.GetOriginalMessage(messageProperties);
                 var logEvent = new LogEventInfo(nLogLogLevel, _logger.Name, null, originalMessage, SingleItemArray);
                 var messageTemplateParameters = logEvent.MessageTemplateParameters;   // Forces parsing of OriginalMessage
                 if (messageTemplateParameters.Count > 0)
@@ -119,18 +120,75 @@ private LogEventInfo TryParseMessageTemplate(LogLevel nLogLogLevel, IReadOnlyLis
             return null;    // Parsing not needed
         }
 
+        private LogEventInfo TryParsePostionalMessageTemplate(LogLevel nLogLogLevel, IReadOnlyList<KeyValuePair<string, object>> messageProperties, NLogMessageParameterList messageParameters)
+        {
+            if (messageParameters.IsPositional && _options.ParseMessageTemplates)
+            {
+                string originalMessage = TryParsePositionalParameters(messageProperties, out var parameters);
+                if (originalMessage != null)
+                {
+                    return new LogEventInfo(nLogLogLevel, _logger.Name, null, originalMessage, parameters);
+                }
+            }
+
+            return null;
+        }
+
         private LogEventInfo CaptureMessageTemplate(LogLevel nLogLogLevel, string message, IReadOnlyList<KeyValuePair<string, object>> messageProperties, NLogMessageParameterList messageParameters)
         {
             // Parsing not needed, we take the fast route 
             var originalMessage = messageParameters.GetOriginalMessage(messageProperties) ?? message;
-            var logEvent = new LogEventInfo(nLogLogLevel, _logger.Name, originalMessage, messageParameters);
-            if (!ReferenceEquals(originalMessage, message))
+            var logEvent = new LogEventInfo(nLogLogLevel, _logger.Name, message, originalMessage, messageParameters.IsPositional ? Array.Empty<MessageTemplateParameter>() : messageParameters);
+            if (_options.CaptureMessageParameters && !ReferenceEquals(originalMessage, message))
             {
-                SetLogEventMessageFormatter(logEvent, messageParameters, message);
+                var parameterCount = messageParameters.Count;
+                if (parameterCount > 0)
+                {
+                    var parameters = new object[parameterCount];
+                    for (int i = 0; i < parameterCount; ++i)
+                        parameters[i] = messageParameters[i].Value;
+                    logEvent.Parameters = parameters;
+                }
             }
             return logEvent;
         }
 
+        private LogEventInfo CaputureBasicLogEvent(LogLevel nLogLogLevel, string formattedMessage, IReadOnlyList<KeyValuePair<string, object>> messageProperties, NLogMessageParameterList messageParameters)
+        {
+            if (messageParameters.IsPositional && _options.CaptureMessageParameters)
+            {
+                string originalMessage = TryParsePositionalParameters(messageProperties, out var parameters);
+                var logEvent = new LogEventInfo(nLogLogLevel, _logger.Name, formattedMessage, originalMessage ?? formattedMessage, Array.Empty<MessageTemplateParameter>());
+                logEvent.Parameters = parameters;
+                return logEvent;
+            }
+            else
+            {
+                return new LogEventInfo(nLogLogLevel, _logger.Name, formattedMessage, formattedMessage, Array.Empty<MessageTemplateParameter>());
+            }
+        }
+
+        private static string TryParsePositionalParameters(IReadOnlyList<KeyValuePair<string, object>> messageProperties, out object[] parameters)
+        {
+            var parameterCount = messageProperties.Count;
+            var parameterIndex = 0;
+            parameters = new object[parameterCount - 1];
+            string originalMessage = null;
+            for (int i = 0; i < parameterCount; ++i)
+            {
+                var parameter = messageProperties[i];
+                if (OriginalFormatPropertyName.Equals(parameter.Key))
+                {
+                    originalMessage = parameter.Value.ToString();
+                }
+                else
+                {
+                    parameters[parameterIndex++] = parameter.Value;
+                }
+            }
+            return originalMessage;
+        }
+
         /// <summary>
         /// Allocates object[]-array for <see cref="LogEventInfo.Parameters"/> after checking
         /// for mismatch between Microsoft Extension Logging and NLog Message Template Parser
@@ -284,16 +342,6 @@ private static int FindMaxIndex(MessageTemplateParameters messageTemplateParamet
             return maxIndex;
         }
 
-        private static void SetLogEventMessageFormatter(LogEventInfo logEvent, NLogMessageParameterList messageTemplateParameters, string formattedMessage)
-        {
-            var parameters = new object[messageTemplateParameters.Count + 1];
-            for (int i = 0; i < parameters.Length - 1; ++i)
-                parameters[i] = messageTemplateParameters[i].Value;
-            parameters[parameters.Length - 1] = formattedMessage;
-            logEvent.Parameters = parameters;
-            logEvent.MessageFormatter = (l) => (string)l.Parameters[l.Parameters.Length - 1];
-        }
-
         private void CaptureEventIdProperties(LogEventInfo logEvent, EventId eventId)
         {
             var captureEventId = _options.CaptureEventId;

src/NLog.Extensions.Logging/Logging/NLogMessageParameterList.cs

@@ -10,22 +10,28 @@ namespace NLog.Extensions.Logging
     /// </summary>
     internal class NLogMessageParameterList : IList<MessageTemplateParameter>
     {
-        private readonly IReadOnlyList<KeyValuePair<string, object>> _parameterList;
-        private static readonly NLogMessageParameterList EmptyList = new NLogMessageParameterList(Array.Empty<KeyValuePair<string, object>>(), default, default, default);
-        private static readonly NLogMessageParameterList OriginalMessageList = new NLogMessageParameterList(new[] { new KeyValuePair<string, object>(NLogLogger.OriginalFormatPropertyName, string.Empty) }, 0, default, default);
+        private static readonly NLogMessageParameterList EmptyList = new NLogMessageParameterList(Array.Empty<KeyValuePair<string, object>>(), default, default, default, default);
+        private static readonly NLogMessageParameterList EmptyPositionalList = new NLogMessageParameterList(Array.Empty<KeyValuePair<string, object>>(), default, default, default, isPositional: true);
+        private static readonly NLogMessageParameterList OriginalMessageList = new NLogMessageParameterList(new[] { new KeyValuePair<string, object>(NLogLogger.OriginalFormatPropertyName, string.Empty) }, 0, default, default, default);
 
+        private readonly IReadOnlyList<KeyValuePair<string, object>> _parameterList;
         private readonly int? _originalMessageIndex;
-
-        public bool HasComplexParameters => _hasMessageTemplateCapture || _isMixedPositional;
         private readonly bool _hasMessageTemplateCapture;
         private readonly bool _isMixedPositional;
+        private readonly bool _isPositional;
+
+        public bool HasComplexParameters => _hasMessageTemplateCapture || _isMixedPositional;
+        public bool IsPositional => _isPositional;
+        public int Count => _parameterList.Count - (_originalMessageIndex.HasValue ? 1 : 0);
+        public bool IsReadOnly => true;
 
-        private NLogMessageParameterList(IReadOnlyList<KeyValuePair<string, object>> parameterList, int? originalMessageIndex, bool hasMessageTemplateCapture, bool isMixedPositional)
+        private NLogMessageParameterList(IReadOnlyList<KeyValuePair<string, object>> parameterList, int? originalMessageIndex, bool hasMessageTemplateCapture, bool isMixedPositional, bool isPositional)
         {
             _parameterList = parameterList;
             _originalMessageIndex = originalMessageIndex;
             _hasMessageTemplateCapture = hasMessageTemplateCapture;
             _isMixedPositional = isMixedPositional;
+            _isPositional = isPositional;
         }
 
         /// <summary>
@@ -43,16 +49,16 @@ public static NLogMessageParameterList TryParse(IReadOnlyList<KeyValuePair<strin
                 {
                     if (isPositional)
                     {
-                        return EmptyList;   // Skip allocation, will not capture LogEventInfo.Parameters-array
+                        return EmptyPositionalList;   // Skip allocation, not needed to create Parameters-array
                     }
                     else
                     {
-                        return new NLogMessageParameterList(parameterList, originalMessageIndex, hasMessageTemplateCapture, isMixedPositional);
+                        return new NLogMessageParameterList(parameterList, originalMessageIndex, hasMessageTemplateCapture, isMixedPositional, isPositional);
                     }
                 }
                 else
                 {
-                    return new NLogMessageParameterList(CreateValidParameterList(parameterList), originalMessageIndex, hasMessageTemplateCapture, isMixedPositional || isPositional);
+                    return new NLogMessageParameterList(CreateValidParameterList(parameterList), originalMessageIndex, hasMessageTemplateCapture, isMixedPositional || isPositional, isPositional);
                 }      
             }
             else if (parameterCount == 1)
@@ -105,7 +111,7 @@ private static bool IsValidParameterList(IReadOnlyList<KeyValuePair<string, obje
                 {
                     if (!isPositional)
                         isMixedPositional = i != 0;
-                    isMixedPositional = isMixedPositional || i != (firstChar - '0');
+                    isMixedPositional |= i != (firstChar - '0');
                     isPositional = true;
                 }
                 else
@@ -201,10 +207,6 @@ private static CaptureType GetCaptureType(char firstChar)
                 return CaptureType.Normal;
         }
 
-        public int Count => _parameterList.Count - (_originalMessageIndex.HasValue ? 1 : 0);
-
-        public bool IsReadOnly => true;
-
         public void Add(MessageTemplateParameter item)
         {
             throw new NotSupportedException();

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

@@ -35,6 +35,11 @@ public class NLogProviderOptions
         /// </summary>
         public bool CaptureMessageProperties { get; set; } = true;
 
+        /// <summary>
+        /// Enable capture of <see cref="LogEventInfo.Parameters"/> from the ILogger-State-object. Only relevant when <see cref="CaptureMessageTemplates"/> = true
+        /// </summary>
+        public bool CaptureMessageParameters { get; set; }
+
         /// <summary>
         /// Use the NLog engine for parsing the message template (again) and format using the NLog formatter
         /// </summary>

src/NLog.Extensions.Logging/NLog.Extensions.Logging.csproj

@@ -77,14 +77,13 @@ List of major changes in NLog 5.0: https://nlog-project.org/2021/08/25/nlog-5-0-
   </PropertyGroup>
 
   <ItemGroup>
-    <PackageReference Include="NLog" Version="5.2.3" />
+    <PackageReference Include="NLog" Version="5.2.4" />
     <PackageReference Include="Microsoft.SourceLink.GitHub" Version="1.1.1" PrivateAssets="All" />
   </ItemGroup>
   <ItemGroup Condition=" '$(TargetFramework)' == 'net461' ">
     <PackageReference Include="Microsoft.Extensions.Logging" Version="2.1.0" />
     <PackageReference Include="Microsoft.Extensions.Configuration.Abstractions" Version="2.1.0" />
     <Reference Include="System" />
-    <Reference Include="Microsoft.CSharp" />
   </ItemGroup>
   <ItemGroup Condition=" '$(TargetFramework)' == 'netstandard1.3' ">
     <PackageReference Include="Microsoft.Extensions.Configuration.Abstractions" Version="1.0.0" />

test/NLog.Extensions.Hosting.Tests/NLog.Extensions.Hosting.Tests.csproj

@@ -23,7 +23,7 @@
   </ItemGroup>
 
   <ItemGroup>
-    <PackageReference Include="Microsoft.NET.Test.Sdk" Version="17.7.0" />
+    <PackageReference Include="Microsoft.NET.Test.Sdk" Version="17.7.2" />
     <PackageReference Include="xunit" Version="2.4.0" />
     <PackageReference Include="xunit.runner.visualstudio" Version="2.4.3" />
   </ItemGroup>

test/NLog.Extensions.Logging.Tests/LoggerTests.cs

@@ -240,6 +240,80 @@ public void TestWithEmptyMessageAndNullException()
             Assert.Equal("NLog.Extensions.Logging.Tests.LoggerTests.Runner|DEBUG||EventId=20", runner.LastTargetMessage);
         }
 
+        [Fact]
+        public void TestPositionalCaptureMessageParameters()
+        {
+            LogEventInfo logEvent = null;
+            var debugTarget = new MethodCallTarget("output", (l, args) => logEvent = l);
+            var runner = GetRunner<Runner>(new NLogProviderOptions() { CaptureMessageParameters = true }, debugTarget);
+            string formatString = "{0,8:S} {1,8:S}";
+            runner.Logger.LogDebug(formatString, "Hello", "World");
+
+            Assert.NotNull(logEvent);
+            Assert.Equal("   Hello    World", logEvent.FormattedMessage);
+            Assert.Equal(formatString, logEvent.Message);
+            Assert.NotNull(logEvent.Parameters);
+            Assert.Equal(2, logEvent.Parameters.Length);
+            Assert.Equal("Hello", logEvent.Parameters[0]);
+            Assert.Equal("World", logEvent.Parameters[1]);
+
+            var messageParameters = logEvent.MessageTemplateParameters;
+            Assert.True(messageParameters.IsPositional);
+            Assert.Equal(2, messageParameters.Count);
+            Assert.Equal("Hello", messageParameters[0].Value);
+            Assert.Equal("S", messageParameters[0].Format);
+            Assert.Equal("World", messageParameters[1].Value);
+            Assert.Equal("S", messageParameters[1].Format);
+        }
+
+        [Fact]
+        public void TestParseMessageTemplates()
+        {
+            LogEventInfo logEvent = null;
+            var debugTarget = new MethodCallTarget("output", (l, args) => logEvent = l);
+            var runner = GetRunner<Runner>(new NLogProviderOptions() { ParseMessageTemplates = true }, debugTarget);
+            var messageTemplate = "message with {ParameterCount} parameters";
+            runner.Logger.LogDebug(messageTemplate, "1");
+
+            Assert.NotNull(logEvent);
+            Assert.Equal(messageTemplate, logEvent.Message);
+            Assert.NotNull(logEvent.Parameters);
+            Assert.Single(logEvent.Parameters);
+            Assert.Equal("1", logEvent.Parameters[0]);
+
+            var messageParameters = logEvent.MessageTemplateParameters;
+            Assert.False(messageParameters.IsPositional);
+            Assert.Equal(1, messageParameters.Count);
+            Assert.Equal("ParameterCount", messageParameters[0].Name);
+            Assert.Equal("1", messageParameters[0].Value);
+        }
+
+        [Fact]
+        public void TestPositionalParseMessageTemplates()
+        {
+            LogEventInfo logEvent = null;
+            var debugTarget = new MethodCallTarget("output", (l, args) => logEvent = l);
+            var runner = GetRunner<Runner>(new NLogProviderOptions() { ParseMessageTemplates = true }, debugTarget);
+            string formatString = "{0,8:S} {1,8:S}";
+            runner.Logger.LogDebug(formatString, "Hello", "World");
+
+            Assert.NotNull(logEvent);
+            Assert.Equal("   Hello    World", logEvent.FormattedMessage);
+            Assert.Equal(formatString, logEvent.Message);
+            Assert.NotNull(logEvent.Parameters);
+            Assert.Equal(2, logEvent.Parameters.Length);
+            Assert.Equal("Hello", logEvent.Parameters[0]);
+            Assert.Equal("World", logEvent.Parameters[1]);
+
+            var messageParameters = logEvent.MessageTemplateParameters;
+            Assert.True(messageParameters.IsPositional);
+            Assert.Equal(2, messageParameters.Count);
+            Assert.Equal("Hello", messageParameters[0].Value);
+            Assert.Equal("S", messageParameters[0].Format);
+            Assert.Equal("World", messageParameters[1].Value);
+            Assert.Equal("S", messageParameters[1].Format);
+        }
+
         private Runner GetRunner()
         {
             return base.GetRunner<Runner>();

test/NLog.Extensions.Logging.Tests/NLog.Extensions.Logging.Tests.csproj

@@ -15,7 +15,7 @@
   </PropertyGroup>
 
   <ItemGroup>
-    <PackageReference Include="Microsoft.NET.Test.Sdk" Version="17.7.0" />
+    <PackageReference Include="Microsoft.NET.Test.Sdk" Version="17.7.2" />
     <PackageReference Include="xunit" Version="2.4.0" />
     <PackageReference Include="xunit.runner.visualstudio" Version="2.4.3" />
   </ItemGroup>

test/NLog.Extensions.Logging.Tests/NLogMessageParameterListTests.cs

@@ -58,6 +58,7 @@ public void CreateNLogMessageParameterDifferentCaptureTypes()
             Assert.Equal(new MessageTemplateParameter("b", 2, null, CaptureType.Stringify), list[1]);
             Assert.Equal(new MessageTemplateParameter("c", 3, null, CaptureType.Serialize), list[2]);
             Assert.True(list.HasComplexParameters);
+            Assert.False(list.IsPositional);
         }
 
         [Fact]
@@ -73,6 +74,7 @@ public void CreateNLogMessageParameterIsPositional()
 
             Assert.Empty(list);
             Assert.False(list.HasComplexParameters);
+            Assert.True(list.IsPositional);
         }
 
         [Fact]