Clean up logging somewhat

src/OmniSharp.Abstractions/Logging/BaseLogger.cs

@@ -0,0 +1,116 @@
+using System;
+using Microsoft.Extensions.Logging;
+
+namespace OmniSharp.Logging
+{
+    public abstract class BaseLogger : ILogger
+    {
+        protected readonly string CategoryName;
+        private readonly bool _addHeader;
+        private readonly Func<string, LogLevel, bool> _filter;
+        private readonly CachedStringBuilder _cachedBuilder;
+
+        private static readonly string s_padding = new string(' ', 8);
+        private static readonly string s_newLinePlusPadding = Environment.NewLine + s_padding;
+
+        protected BaseLogger(string categoryName, Func<string, LogLevel, bool> filter = null, bool addHeader = true)
+        {
+            this.CategoryName = categoryName;
+            this._filter = filter;
+            this._addHeader = addHeader;
+            this._cachedBuilder = new CachedStringBuilder();
+        }
+
+        protected abstract void WriteMessage(LogLevel logLevel, string message);
+
+        private string CreateMessage(LogLevel logLevel, string messageText, Exception exception)
+        {
+            var builder = _cachedBuilder.Acquire();
+            try
+            {
+                if (!string.IsNullOrEmpty(messageText))
+                {
+                    if (_addHeader)
+                    {
+                        builder.Append(GetLogLevelPrefix(logLevel));
+                        builder.Append(this.CategoryName);
+                        builder.AppendLine();
+
+                        builder.Append(s_padding);
+                        var length = builder.Length;
+                        builder.Append(messageText);
+                        builder.Replace(Environment.NewLine, s_newLinePlusPadding, length, messageText.Length);
+                    }
+                    else
+                    {
+                        builder.Append(messageText);
+                    }
+                }
+
+                if (exception != null)
+                {
+                    if (builder.Length > 0)
+                    {
+                        builder.AppendLine();
+                    }
+
+                    builder.Append(exception.ToString());
+                }
+
+                return builder.ToString();
+            }
+            finally
+            {
+                _cachedBuilder.Release(builder);
+            }
+        }
+
+        private static string GetLogLevelPrefix(LogLevel logLevel)
+        {
+            switch (logLevel)
+            {
+                case LogLevel.Trace:
+                    return "[trce]: ";
+                case LogLevel.Debug:
+                    return "[dbug]: ";
+                case LogLevel.Information:
+                    return "[info]: ";
+                case LogLevel.Warning:
+                    return "[warn]: ";
+                case LogLevel.Error:
+                    return "[fail]: ";
+                case LogLevel.Critical:
+                    return "[crit]: ";
+                default:
+                    throw new ArgumentOutOfRangeException(nameof(LogLevel));
+            }
+        }
+
+        public void Log<TState>(LogLevel logLevel, EventId eventId, TState state, Exception exception, Func<TState, Exception, string> formatter)
+        {
+            if (!IsEnabled(logLevel))
+            {
+                return;
+            }
+
+            var messageText = formatter(state, exception);
+            if (!string.IsNullOrEmpty(messageText) || exception != null)
+            {
+                var message = CreateMessage(logLevel, messageText, exception);
+                WriteMessage(logLevel, message);
+            }
+        }
+
+        public bool IsEnabled(LogLevel logLevel) =>
+            _filter != null
+                ? _filter(this.CategoryName, logLevel)
+                : true;
+
+        public IDisposable BeginScope<TState>(TState state) => new NoopDisposable();
+
+        private class NoopDisposable : IDisposable
+        {
+            public void Dispose() { }
+        }
+    }
+}

src/OmniSharp.Abstractions/Utilities/CachedStringBuilder.cs

@@ -0,0 +1,35 @@
+using System;
+using System.Text;
+
+namespace OmniSharp
+{
+    public struct CachedStringBuilder
+    {
+        [ThreadStatic]
+        private static StringBuilder g_builder;
+
+        public StringBuilder Acquire()
+        {
+            var builder = g_builder;
+            g_builder = null;
+
+            if (builder == null)
+            {
+                builder = new StringBuilder();
+            }
+
+            return builder;
+        }
+
+        public void Release(StringBuilder builder)
+        {
+            builder.Clear();
+            if (builder.Capacity > 1024)
+            {
+                builder.Capacity = 1024;
+            }
+
+            g_builder = builder;
+        }
+    }
+}

src/OmniSharp.Host/Middleware/LoggingMiddleware.cs

@@ -11,11 +11,13 @@ public class LoggingMiddleware
     {
         private readonly RequestDelegate _next;
         private readonly ILogger _logger;
+        private readonly CachedStringBuilder _cachedBuilder;
 
         public LoggingMiddleware(RequestDelegate next, ILoggerFactory loggerFactory)
         {
             _next = next;
             _logger = loggerFactory.CreateLogger<LoggingMiddleware>();
+            _cachedBuilder = new CachedStringBuilder();
         }
 
         public async Task Invoke(HttpContext context)
@@ -33,7 +35,6 @@ public async Task Invoke(HttpContext context)
                 await requestBody.CopyToAsync(context.Request.Body);
 
                 LogRequest(context);
-
             }
 
             var stopwatch = Stopwatch.StartNew();
@@ -47,43 +48,66 @@ public async Task Invoke(HttpContext context)
                 await context.Response.Body.CopyToAsync(responseBody);
 
             }
-            _logger.LogInformation(context.Request.Path + ": " + context.Response.StatusCode + " " + stopwatch.ElapsedMilliseconds + "ms");
+
+            _logger.LogInformation($"{context.Request.Path}: {context.Response.StatusCode} {stopwatch.ElapsedMilliseconds}ms");
         }
 
         private void LogRequest(HttpContext context)
         {
-            _logger.LogDebug("************ Request ************");
-            _logger.LogDebug(string.Format("{0} - {1}", context.Request.Method, context.Request.Path));
-            _logger.LogDebug("************ Headers ************");
-
-            foreach (var headerGroup in context.Request.Headers)
+            var builder = _cachedBuilder.Acquire();
+            try
             {
-                foreach (var header in headerGroup.Value)
+                builder.AppendLine("************ Request ************");
+                builder.AppendLine($"{context.Request.Method} - {context.Request.Path}");
+                builder.AppendLine("************ Headers ************");
+
+                foreach (var headerGroup in context.Request.Headers)
                 {
-                    _logger.LogDebug(string.Format("{0} - {1}", headerGroup.Key, header));
+                    foreach (var header in headerGroup.Value)
+                    {
+                        builder.AppendLine($"{headerGroup.Key} - {header}");
+                    }
                 }
-            }
 
-            context.Request.Body.Position = 0;
+                context.Request.Body.Position = 0;
+
+                builder.AppendLine("************  Body ************");
 
-            _logger.LogDebug("************  Body ************");
-            var reader = new StreamReader(context.Request.Body);
-            var content = reader.ReadToEnd();
-            _logger.LogDebug(content);
+                var reader = new StreamReader(context.Request.Body);
+                var content = reader.ReadToEnd();
 
-            context.Request.Body.Position = 0;
+                builder.Append(content);
+                _logger.LogDebug(builder.ToString());
+
+                context.Request.Body.Position = 0;
+            }
+            finally
+            {
+                _cachedBuilder.Release(builder);
+            }
         }
 
         private void LogResponse(HttpContext context)
         {
-            _logger.LogDebug("************  Response ************ ");
+            var builder = _cachedBuilder.Acquire();
+            try
+            {
+                builder.AppendLine("************  Response ************ ");
+
+                context.Response.Body.Position = 0;
 
-            context.Response.Body.Position = 0;
+                var reader = new StreamReader(context.Response.Body);
+                var content = reader.ReadToEnd();
 
-            var reader = new StreamReader(context.Response.Body);
-            var content = reader.ReadToEnd();
-            _logger.LogDebug(content);
-            context.Response.Body.Position = 0;
+                builder.Append(content);
+                _logger.LogDebug(builder.ToString());
+
+                context.Response.Body.Position = 0;
+            }
+            finally
+            {
+                _cachedBuilder.Release(builder);
+            }
         }
     }
 

src/OmniSharp.MSBuild/MSBuildProjectSystem.cs

@@ -65,7 +65,7 @@ public class MSBuildProjectSystem : IProjectSystem
             _metadataReferenceCache = metadataReferenceCache;
 
             _projects = new ProjectFileInfoCollection();
-            _logger = loggerFactory.CreateLogger("OmniSharp#MSBuild");
+            _logger = loggerFactory.CreateLogger<MSBuildProjectSystem>();
         }
 
         public void Initalize(IConfiguration configuration)
@@ -281,7 +281,7 @@ private ProjectFileInfo CreateProjectFileInfo(string projectFilePath, bool isUni
 
             try
             {
-                projectFileInfo = ProjectFileInfo.Create(projectFilePath, _environment.Path, _loggerFactory.CreateLogger("OmniSharp#ProjectFileInfo"), _options, diagnostics, isUnityProject);
+                projectFileInfo = ProjectFileInfo.Create(projectFilePath, _environment.Path, _loggerFactory.CreateLogger<ProjectFileInfo>(), _options, diagnostics, isUnityProject);
 
                 if (projectFileInfo == null)
                 {

src/OmniSharp.Stdio/Logging/StdioLogger.cs

@@ -1,81 +1,36 @@
 using System;
 using Microsoft.Extensions.Logging;
+using OmniSharp.Logging;
 using OmniSharp.Stdio.Protocol;
 using OmniSharp.Stdio.Services;
 
 namespace OmniSharp.Stdio.Logging
 {
-    internal class StdioLogger : ILogger
+    internal class StdioLogger : BaseLogger
     {
-        private readonly object _lock = new object();
         private readonly ISharedTextWriter _writer;
-        private readonly string _name;
-        private readonly Func<string, LogLevel, bool> _filter;
 
-        internal StdioLogger(ISharedTextWriter writer, string name, Func<string, LogLevel, bool> filter)
+        internal StdioLogger(ISharedTextWriter writer, string categoryName, Func<string, LogLevel, bool> filter)
+            : base(categoryName, filter, addHeader: false)
         {
             _writer = writer;
-            _name = name;
-            _filter = filter;
         }
 
-        public IDisposable BeginScope<TState>(TState state)
+        protected override void WriteMessage(LogLevel logLevel, string message)
         {
-            return new NoopDisposable();
-        }
-
-        public bool IsEnabled(LogLevel logLevel)
-        {
-            return _filter(this._name, logLevel);
-        }
-
-        public void Log<TState>(LogLevel logLevel, EventId eventId, TState state, Exception exception, Func<TState, Exception, string> formatter)
-        {
-            if (!IsEnabled(logLevel))
-            {
-                return;
-            }
-            string text = string.Empty;
-
-            if (formatter != null)
-            {
-                text = formatter(state, exception);
-            }
-            else
-            {
-                if (state != null)
-                {
-                    text += state;
-                }
-                if (exception != null)
-                {
-                    text = text + Environment.NewLine + exception;
-                }
-            }
-
-            if (string.IsNullOrEmpty(text))
-            {
-                return;
-            }
-
             var packet = new EventPacket()
             {
                 Event = "log",
                 Body = new
                 {
                     LogLevel = logLevel.ToString().ToUpperInvariant(),
-                    Name = this._name,
-                    Message = text
+                    Name = this.CategoryName,
+                    Message = message
                 }
             };
 
             // don't block the logger
             _writer.WriteLineAsync(packet);
         }
-
-        private class NoopDisposable : IDisposable
-        {
-            public void Dispose() { }
-        }
     }
 }