Merge pull request serilog#960 from nblumhardt/efficient-output-prope…

…rties

Output template formatting harness

test/Serilog.PerformanceTests/Harness.cs

@@ -62,5 +62,17 @@ public void Pipeline()
         {
             BenchmarkRunner.Run<PipelineBenchmark>();
         }
+
+        [Fact]
+        public void OutputTemplateRendering()
+        {
+            BenchmarkRunner.Run<OutputTemplateRenderingBenchmark>();
+        }
+
+        [Fact]
+        public void MessageTemplateRenderingBenchmark()
+        {
+            BenchmarkRunner.Run<MessageTemplateRenderingBenchmark>();
+        }
     }
 }

test/Serilog.PerformanceTests/MessageTemplateRenderingBenchmark.cs

@@ -0,0 +1,41 @@
+using BenchmarkDotNet.Attributes;
+using System.IO;
+using Serilog.Events;
+using Serilog.PerformanceTests.Support;
+
+namespace Serilog.PerformanceTests
+{
+    /// <summary>
+    /// Determines the cost of rendering a message template.
+    /// </summary>
+    public class MessageTemplateRenderingBenchmark
+    {
+        static readonly LogEvent NoProperties =
+            Some.InformationEvent("This template has no properties");
+
+        static readonly LogEvent VariedProperties =
+            Some.InformationEvent("Processed {@Position} for {Task} in {Elapsed:000} ms",
+                new { Latitude = 25, Longitude = 134 }, "Benchmark", 34);
+
+        readonly StringWriter _output = new StringWriter();
+
+        [Setup]
+        public void Setup()
+        {
+            _output.GetStringBuilder().Length = 0;
+            _output.GetStringBuilder().Capacity = 1024; // Only a few dozen chars actually needed here.
+        }
+
+        [Benchmark]
+        public void TemplateWithNoProperties()
+        {
+            NoProperties.MessageTemplate.Render(NoProperties.Properties, _output);
+        }
+
+        [Benchmark]
+        public void TemplateWithVariedProperties()
+        {
+            VariedProperties.MessageTemplate.Render(VariedProperties.Properties, _output);
+        }
+    }
+}

test/Serilog.PerformanceTests/OutputTemplateRenderingBenchmark.cs

@@ -0,0 +1,35 @@
+using BenchmarkDotNet.Attributes;
+using System.Globalization;
+using System.IO;
+using Serilog.Events;
+using Serilog.Formatting.Display;
+using Serilog.PerformanceTests.Support;
+
+namespace Serilog.PerformanceTests
+{
+    /// <summary>
+    /// Determines the cost of rendering an event out to one of the typical text targets,
+    /// like the console or a text file.
+    /// </summary>
+    public class OutputTemplateRenderingBenchmark
+    {
+        const string DefaultFileOutputTemplate = "{Timestamp:yyyy-MM-dd HH:mm:ss.fff zzz} [{Level}] {Message}{NewLine}{Exception}";
+        static readonly LogEvent HelloWorldEvent = Some.InformationEvent("Hello, {Name}", "World");
+        static readonly MessageTemplateTextFormatter Formatter = new MessageTemplateTextFormatter(DefaultFileOutputTemplate, CultureInfo.InvariantCulture);
+
+        readonly StringWriter _output = new StringWriter();
+
+        [Setup]
+        public void Setup()
+        {
+            _output.GetStringBuilder().Length = 0;
+            _output.GetStringBuilder().Capacity = 1024; // Only a few dozen chars actually needed here.
+        }
+
+        [Benchmark]
+        public void FormatToOutput()
+        {
+            Formatter.Format(HelloWorldEvent, _output);
+        }
+    }
+}

test/Serilog.PerformanceTests/Support/Some.cs

@@ -1,19 +1,17 @@
 using System;
-using System.Collections.Generic;
-using System.IO;
-using System.Linq;
-using System.Threading;
 using Serilog.Events;
-using Serilog.Parsing;
 
 namespace Serilog.PerformanceTests.Support
 {
     static class Some
     {
-        public static LogEvent InformationEvent()
+        public static LogEvent InformationEvent(string messageTemplate = "Hello, world!", params object[] propertyValues)
         {
-            return new LogEvent(DateTime.Now, LogEventLevel.Information,
-                null, new MessageTemplate(Enumerable.Empty<MessageTemplateToken>()), Enumerable.Empty<LogEventProperty>());
+            var logger = new LoggerConfiguration().CreateLogger();
+#pragma warning disable Serilog004 // Constant MessageTemplate verifier
+            logger.BindMessageTemplate(messageTemplate, propertyValues, out var parsedTemplate, out var boundProperties);
+#pragma warning restore Serilog004 // Constant MessageTemplate verifier
+            return new LogEvent(DateTime.Now, LogEventLevel.Information, null, parsedTemplate, boundProperties);
         }
 
     }