Added support for structured logging parameter names extracted from M…

…icrosoft FormattedLogValues
NLog · Aug 5, 2017 · 91a58b4 · 91a58b4
1 parent 0fc0e50
commit 91a58b4
Show file tree

Hide file tree

Showing 4 changed files with 50 additions and 12 deletions.
diff --git a/src/NLog.Extensions.Logging/NLogLogger.cs b/src/NLog.Extensions.Logging/NLogLogger.cs
@@ -1,4 +1,5 @@
 using System;
+using System.Collections.Generic;
 using Microsoft.Extensions.Logging;
 
 namespace NLog.Extensions.Logging
@@ -31,8 +32,8 @@ public void Log<TState>(Microsoft.Extensions.Logging.LogLevel logLevel, EventId
                 {
                     throw new ArgumentNullException(nameof(formatter));
                 }
-                var message = formatter(state, exception);
 
+                var message = formatter(state, exception);
                 if (!string.IsNullOrEmpty(message))
                 {
                     //message arguments are not needed as it is already checked that the loglevel is enabled.
@@ -57,6 +58,24 @@ public void Log<TState>(Microsoft.Extensions.Logging.LogLevel logLevel, EventId
                         eventInfo.Properties[eventIdPropertyNames.Item3] = eventId.Name;
                         eventInfo.Properties["EventId"] = (eventId.Id == 0 && eventId.Name == null) ? _emptyEventId : eventId;
                     }
+
+                    if (_options.EnableStructuredLogging)
+                    {
+                        var messageTemplate = state as IReadOnlyList<KeyValuePair<string, object>>;
+                        if (messageTemplate != null && messageTemplate.Count > 1)
+                        {
+                            // More than a single parameter (last parameter is the {OriginalFormat})
+                            for (int i = 0; i < messageTemplate.Count; ++i)
+                            {
+                                var parameter = messageTemplate[i];
+                                if (i == 0 && parameter.Key.Length == 1 && parameter.Key[0] >= '0' && parameter.Key[0] <= '9')
+                                    break;  // Looks like normal string.Format, skip capture
+
+                                eventInfo.Properties[parameter.Key] = parameter.Value;
+                            }
+                        }
+                    }
+
                     _logger.Log(eventInfo);
                 }
             }

diff --git a/src/NLog.Extensions.Logging/NLogProviderOptions.cs b/src/NLog.Extensions.Logging/NLogProviderOptions.cs
@@ -17,6 +17,11 @@ public class NLogProviderOptions
         /// </summary>
         public bool IgnoreEmptyEventId { get; set; }
 
+        /// <summary>
+        /// Attempt to capture parameter names and values and insert into <see cref="LogEventInfo.Properties" />-dictionary
+        /// </summary>
+        public bool EnableStructuredLogging { get; set; }
+
         /// <summary>Initializes a new instance of the <see cref="T:System.Object" /> class.</summary>
         public NLogProviderOptions()
         {

diff --git a/test/LoggerTests.cs b/test/LoggerTests.cs
@@ -24,7 +24,6 @@ public void TestInit()
 
             var target = GetTarget();
             Assert.Equal("NLog.Extensions.Logging.Tests.LoggerTests.Runner|DEBUG|init runner |0", target.Logs.FirstOrDefault());
-
         }
 
         [Fact]
@@ -34,7 +33,24 @@ public void TestEventId()
 
             var target = GetTarget();
             Assert.Equal("NLog.Extensions.Logging.Tests.LoggerTests.Runner|DEBUG|message with id |20", target.Logs.FirstOrDefault());
-
+        }
+
+        [Fact]
+        public void TestParameters()
+        {
+            GetRunner().LogDebugWithParameters();
+
+            var target = GetTarget();
+            Assert.Equal("NLog.Extensions.Logging.Tests.LoggerTests.Runner|DEBUG|message with id and 1 parameters |20", target.Logs.FirstOrDefault());
+        }
+
+        [Fact]
+        public void TestStructuredLogging()
+        {
+            GetRunner().LogDebugWithStructuredParameters();
+
+            var target = GetTarget();
+            Assert.Equal("NLog.Extensions.Logging.Tests.LoggerTests.Runner|DEBUG|message with id and ParameterValue |20ParameterValue", target.Logs.FirstOrDefault());
         }
 
         private static Runner GetRunner()
@@ -52,10 +68,6 @@ private static MemoryTarget GetTarget()
             return target;
         }
 
-
-
-
-
         private static IServiceProvider BuildDi()
         {
             var services = new ServiceCollection();
@@ -66,12 +78,11 @@ private static IServiceProvider BuildDi()
             var serviceProvider = services.BuildServiceProvider();
             var loggerFactory = serviceProvider.GetRequiredService<ILoggerFactory>();
 
-            loggerFactory.AddNLog();
+            loggerFactory.AddNLog(new NLogProviderOptions() { EnableStructuredLogging = true });
             loggerFactory.ConfigureNLog("nlog.config");
             return serviceProvider;
         }
 
-
         public class Runner
         {
             private readonly ILogger<Runner> _logger;
@@ -81,7 +92,6 @@ public Runner(ILoggerFactory fac)
                 _logger = fac.CreateLogger<Runner>();
             }
 
-
             public void LogDebugWithId()
             {
                 _logger.LogDebug(20, "message with id");
@@ -92,6 +102,11 @@ public void LogDebugWithParameters()
                 _logger.LogDebug(20, "message with id and {0} parameters", 1);
             }
 
+            public void LogDebugWithStructuredParameters()
+            {
+                _logger.LogDebug(20, "message with id and {ParameterName}", "ParameterValue");
+            }
+
             public void LogWithScope()
             {
                 using (_logger.BeginScope("scope1"))
@@ -103,7 +118,6 @@ public void LogWithScope()
             public void Init()
             {
                 _logger.LogDebug("init runner");
-
             }
         }
     }

diff --git a/test/nlog.config b/test/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}" />
+            layout="${logger}|${uppercase:${level}}|${message} ${exception}|${event-properties:EventId}${event-properties:ParameterName}" />
 
   </targets>