ASP.NET vNext Logging improvements microbenchmark

Program.cs

using System;
using System.Diagnostics;
using System.Globalization;
using Microsoft.Framework.Logging;
using Microsoft.Framework.Logging.Console;

namespace SampleApp
{
    public class Program
    {
        private readonly ILogger _logger;

        public Program()
        {
            // a DI based application would get ILoggerFactory injected instead
            var factory = new LoggerFactory();

            // getting the logger immediately using the class's name is conventional
            _logger = factory.Create(typeof(Program).FullName);

            // providers may be added to an ILoggerFactory at any time, existing ILoggers are updated
#if !ASPNETCORE50
            factory.AddNLog(new global::NLog.LogFactory());
#endif
            factory.AddConsole();
            factory.AddConsole((category, logLevel) => logLevel >= LogLevel.Critical && category.Equals(typeof(Program).FullName));
        }

        public void Main(string[] args)
        {
            int streamIndex = 1;
            int count = 10;
            ulong id = 500;
            
            
            var sw = new Stopwatch();
            const int ITERS = 1000000;
            while (true)
            {
                Console.Write("A: ");
                sw.Restart();
                for (int i = 0; i < ITERS; i++)
                {
                    // Operation A
                    _logger.WriteVerbose("OnReceived({0}, {1}, {2})", streamIndex, count, id);
                }
                var elapsedA = sw.Elapsed;
                Console.WriteLine(elapsedA);
             
                GC.Collect();
                GC.WaitForPendingFinalizers();
                GC.Collect();
             
                Console.Write("B: ");
                sw.Restart();
                for (int i = 0; i < ITERS; i++)
                {
                    // Operation B
                    _logger.WriteVerbose2("OnReceived({0}, {1}, {2})", streamIndex, count, id);
                }
                var elapsedB = sw.Elapsed;
                Console.WriteLine(elapsedB);
             
                GC.Collect();
                GC.WaitForPendingFinalizers();
                GC.Collect();
             
                Console.WriteLine("A/B     : {0}",
                    elapsedA.TotalMilliseconds /
                    elapsedB.TotalMilliseconds);
                Console.WriteLine("B/A     : {0}",
                    elapsedB.TotalMilliseconds /
                    elapsedA.TotalMilliseconds);
                Console.WriteLine("(A-B)/A : {0}",
                    Math.Abs((elapsedA.TotalMilliseconds -
                              elapsedB.TotalMilliseconds) /
                             elapsedA.TotalMilliseconds));
                Console.WriteLine("(B-A)/B : {0}",
                    Math.Abs((elapsedB.TotalMilliseconds -
                              elapsedA.TotalMilliseconds) /
                             elapsedB.TotalMilliseconds));
                
                Console.WriteLine();
             
                Console.ReadLine();
            }
        }
    }
    
    public static class LoggerExtensions
    {
        private static readonly Func<object, Exception, string> TheMessage = (message, error) => (string)message;
    
        public static void WriteVerbose2<T1, T2, T3>(this ILogger logger, string format, T1 arg1, T2 arg2, T3 arg3)
        {
            if (logger.IsEnabled(LogLevel.Verbose))
            {
                logger.Write(LogLevel.Verbose, 0,
                    string.Format(CultureInfo.InvariantCulture, format, new object[] { arg1, arg2, arg3 }), null, TheMessage);
            }
        }
    }
}

Results

A: 00:00:00.8806144
B: 00:00:00.1702717
A/B     : 5.17181892234587
B/A     : 0.193355570837815
(A-B)/A : 0.806644429162185
(B-A)/B : 4.17181892234587


A: 00:00:01.0186282
B: 00:00:00.1662137
A/B     : 6.1284250335562
B/A     : 0.163174060957668
(A-B)/A : 0.836825939042332
(B-A)/B : 5.1284250335562


A: 00:00:01.0502144
B: 00:00:00.1692758
A/B     : 6.20416149266463
B/A     : 0.161182135761993
(A-B)/A : 0.838817864238007
(B-A)/B : 5.20416149266463