From b230746b6c955b45175979a3a631ad9d7bd712ef Mon Sep 17 00:00:00 2001 From: David Wilson Date: Thu, 27 Aug 2015 15:16:11 -0700 Subject: [PATCH] Add basic diagnostic logging support This change adds basic logging support to the Editor Services console host for diagnostic output. It also includes some basic tests to verify the logging capabilities. This logging framework may be switched out in the future for a more robust solution. --- src/PowerShellEditorServices.Host/Program.cs | 20 ++ .../Message/MessageParser.cs | 7 + .../Message/MessageWriter.cs | 17 +- .../PowerShellEditorServices.csproj | 1 + .../Utility/Logger.cs | 180 ++++++++++++++++++ .../PowerShellEditorServices.Test.csproj | 1 + .../Utility/LoggerTests.cs | 123 ++++++++++++ 7 files changed, 348 insertions(+), 1 deletion(-) create mode 100644 src/PowerShellEditorServices/Utility/Logger.cs create mode 100644 test/PowerShellEditorServices.Test/Utility/LoggerTests.cs diff --git a/src/PowerShellEditorServices.Host/Program.cs b/src/PowerShellEditorServices.Host/Program.cs index d6ac8f619..da123dbec 100644 --- a/src/PowerShellEditorServices.Host/Program.cs +++ b/src/PowerShellEditorServices.Host/Program.cs @@ -4,6 +4,7 @@ // using Microsoft.PowerShell.EditorServices.Transport.Stdio; +using Microsoft.PowerShell.EditorServices.Utility; using System; using System.Diagnostics; using System.Linq; @@ -38,11 +39,30 @@ static void Main(string[] args) } } #endif + // Catch unhandled exceptions for logging purposes + AppDomain.CurrentDomain.UnhandledException += CurrentDomain_UnhandledException; + + // Initialize the logger + // TODO: Set the level based on command line parameter + Logger.Initialize(minimumLogLevel: LogLevel.Verbose); + Logger.Write(LogLevel.Normal, "PowerShell Editor Services Host started!"); // TODO: Select host, console host, and transport based on command line arguments IHost host = new StdioHost(); host.Start(); } + + static void CurrentDomain_UnhandledException( + object sender, + UnhandledExceptionEventArgs e) + { + // Log the exception + Logger.Write( + LogLevel.Error, + string.Format( + "FATAL UNHANDLED EXCEPTION:\r\n\r\n{0}", + e.ExceptionObject.ToString())); + } } } diff --git a/src/PowerShellEditorServices.Transport.Stdio/Message/MessageParser.cs b/src/PowerShellEditorServices.Transport.Stdio/Message/MessageParser.cs index 6cdc3a616..b1e142130 100644 --- a/src/PowerShellEditorServices.Transport.Stdio/Message/MessageParser.cs +++ b/src/PowerShellEditorServices.Transport.Stdio/Message/MessageParser.cs @@ -45,6 +45,13 @@ public MessageBase ParseMessage(string messageJson) // Parse the JSON string to a JObject JObject messageObject = JObject.Parse(messageJson); + // Log the message + Logger.Write( + LogLevel.Verbose, + string.Format( + "PARSE MESSAGE:\r\n\r\n{0}", + messageObject.ToString(Formatting.Indented))); + // Get the message type and name from the JSON object if (!this.TryGetMessageTypeAndName( messageObject, diff --git a/src/PowerShellEditorServices.Transport.Stdio/Message/MessageWriter.cs b/src/PowerShellEditorServices.Transport.Stdio/Message/MessageWriter.cs index 443ec77f4..4bafaf5f1 100644 --- a/src/PowerShellEditorServices.Transport.Stdio/Message/MessageWriter.cs +++ b/src/PowerShellEditorServices.Transport.Stdio/Message/MessageWriter.cs @@ -5,6 +5,7 @@ using Microsoft.PowerShell.EditorServices.Utility; using Newtonsoft.Json; +using Newtonsoft.Json.Linq; using System.IO; using System.Text; @@ -18,6 +19,10 @@ public class MessageWriter private bool includeContentLength; private MessageTypeResolver messageTypeResolver; + private JsonSerializer loggingSerializer = + JsonSerializer.Create( + Constants.JsonSerializerSettings); + #endregion #region Constructors @@ -57,8 +62,18 @@ public void WriteMessage(MessageBase messageToWrite) // Insert the message's type name before serializing messageToWrite.PayloadType = messageTypeName; + // Log the JSON representation of the message + Logger.Write( + LogLevel.Verbose, + string.Format( + "WRITE MESSAGE:\r\n\r\n{0}", + JsonConvert.SerializeObject( + messageToWrite, + Formatting.Indented, + Constants.JsonSerializerSettings))); + // Serialize the message - string serializedMessage = + string serializedMessage = JsonConvert.SerializeObject( messageToWrite, Constants.JsonSerializerSettings); diff --git a/src/PowerShellEditorServices/PowerShellEditorServices.csproj b/src/PowerShellEditorServices/PowerShellEditorServices.csproj index cce64db17..91d056b18 100644 --- a/src/PowerShellEditorServices/PowerShellEditorServices.csproj +++ b/src/PowerShellEditorServices/PowerShellEditorServices.csproj @@ -90,6 +90,7 @@ + diff --git a/src/PowerShellEditorServices/Utility/Logger.cs b/src/PowerShellEditorServices/Utility/Logger.cs new file mode 100644 index 000000000..0d8e89909 --- /dev/null +++ b/src/PowerShellEditorServices/Utility/Logger.cs @@ -0,0 +1,180 @@ +// +// Copyright (c) Microsoft. All rights reserved. +// Licensed under the MIT license. See LICENSE file in the project root for full license information. +// + +using System; +using System.IO; +using System.Runtime.CompilerServices; +using System.Text; + +namespace Microsoft.PowerShell.EditorServices.Utility +{ + /// + /// Defines the level indicators for log messages. + /// + public enum LogLevel + { + /// + /// Indicates a verbose log message. + /// + Verbose, + + /// + /// Indicates a normal, non-verbose log message. + /// + Normal, + + /// + /// Indicates a warning message. + /// + Warning, + + /// + /// Indicates an error message. + /// + Error + } + + /// + /// Provides a simple logging interface. May be replaced with a + /// more robust solution at a later date. + /// + public static class Logger + { + private static LogWriter logWriter; + + /// + /// Initializes the Logger for the current session. + /// + /// + /// Optional. Specifies the path at which log messages will be written. + /// + /// + /// Optional. Specifies the minimum log message level to write to the log file. + /// + public static void Initialize( + string logFilePath = "EditorServices.log", + LogLevel minimumLogLevel = LogLevel.Normal) + { + if (logWriter != null) + { + logWriter.Dispose(); + } + + // TODO: Parameterize this + logWriter = + new LogWriter( + minimumLogLevel, + logFilePath, + true); + } + + /// + /// Closes the Logger. + /// + public static void Close() + { + if (logWriter != null) + { + logWriter.Dispose(); + } + } + + /// + /// Writes a message to the log file. + /// + /// The level at which the message will be written. + /// The message text to be written. + /// The name of the calling method. + /// The source file path where the calling method exists. + /// The line number of the calling method. + public static void Write( + LogLevel logLevel, + string logMessage, + [CallerMemberName] string callerName = null, + [CallerFilePath] string callerSourceFile = null, + [CallerLineNumber] int callerLineNumber = 0) + { + if (logWriter != null) + { + logWriter.Write( + logLevel, + logMessage, + callerName, + callerSourceFile, + callerLineNumber); + } + } + } + + internal class LogWriter : IDisposable + { + private TextWriter textWriter; + private LogLevel minimumLogLevel = LogLevel.Verbose; + + public LogWriter(LogLevel minimumLogLevel, string logFilePath, bool deleteExisting) + { + this.minimumLogLevel = minimumLogLevel; + + // Ensure that we have a usable log file path + if (!Path.IsPathRooted(logFilePath)) + { + logFilePath = + Path.Combine( + AppDomain.CurrentDomain.BaseDirectory, + logFilePath); + } + + // Open the log file for writing with UTF8 encoding + this.textWriter = + new StreamWriter( + new FileStream( + logFilePath, + deleteExisting ? + FileMode.Create : + FileMode.Append), + Encoding.UTF8); + } + + public void Write( + LogLevel logLevel, + string logMessage, + string callerName = null, + string callerSourceFile = null, + int callerLineNumber = 0) + { + if (logLevel >= this.minimumLogLevel) + { + // Print the timestamp and log level + this.textWriter.WriteLine( + "{0} [{1}] - Method \"{2}\" at line {3} of {4}\r\n", + DateTime.Now, + logLevel.ToString().ToUpper(), + callerName, + callerLineNumber, + callerSourceFile); + + // Print out indented message lines + foreach (var messageLine in logMessage.Split('\n')) + { + this.textWriter.WriteLine(" " + messageLine.TrimEnd()); + } + + // Finish with a newline and flush the writer + this.textWriter.WriteLine(); + this.textWriter.Flush(); + } + } + + public void Dispose() + { + if (this.textWriter != null) + { + this.textWriter.Flush(); + this.textWriter.Dispose(); + this.textWriter = null; + } + } + } +} diff --git a/test/PowerShellEditorServices.Test/PowerShellEditorServices.Test.csproj b/test/PowerShellEditorServices.Test/PowerShellEditorServices.Test.csproj index bc4a81fc8..787df9c8f 100644 --- a/test/PowerShellEditorServices.Test/PowerShellEditorServices.Test.csproj +++ b/test/PowerShellEditorServices.Test/PowerShellEditorServices.Test.csproj @@ -64,6 +64,7 @@ + diff --git a/test/PowerShellEditorServices.Test/Utility/LoggerTests.cs b/test/PowerShellEditorServices.Test/Utility/LoggerTests.cs new file mode 100644 index 000000000..ec2bdba9c --- /dev/null +++ b/test/PowerShellEditorServices.Test/Utility/LoggerTests.cs @@ -0,0 +1,123 @@ +// +// Copyright (c) Microsoft. All rights reserved. +// Licensed under the MIT license. See LICENSE file in the project root for full license information. +// + +using Microsoft.PowerShell.EditorServices.Utility; +using System; +using System.IO; +using System.Linq; +using System.Text; +using Xunit; + +namespace Microsoft.PowerShell.EditorServices.Test.Utility +{ + public class LoggerTests + { + private const string testMessage = "This is a test log message."; + private readonly string logFilePath = + Path.Combine( + AppDomain.CurrentDomain.BaseDirectory, + "Test.log"); + + [Fact] + public void WritesNormalLogMessage() + { + this.AssertWritesMessageAtLevel(LogLevel.Normal); + } + + [Fact] + public void WritesVerboseLogMessage() + { + this.AssertWritesMessageAtLevel(LogLevel.Verbose); + } + + [Fact] + public void WritesWarningLogMessage() + { + this.AssertWritesMessageAtLevel(LogLevel.Warning); + } + + [Fact] + public void WritesErrorLogMessage() + { + this.AssertWritesMessageAtLevel(LogLevel.Error); + } + + [Fact] + public void CanExcludeMessagesBelowNormalLevel() + { + this.AssertExcludesMessageBelowLevel(LogLevel.Normal); + } + + [Fact] + public void CanExcludeMessagesBelowWarningLevel() + { + this.AssertExcludesMessageBelowLevel(LogLevel.Warning); + } + + [Fact] + public void CanExcludeMessagesBelowErrorLevel() + { + this.AssertExcludesMessageBelowLevel(LogLevel.Error); + } + + #region Helper Methods + + private void AssertWritesMessageAtLevel(LogLevel logLevel) + { + // Write a message at the desired level + Logger.Initialize(logFilePath, LogLevel.Verbose); + Logger.Write(logLevel, testMessage); + + // Read the contents and verify that it's there + string logContents = this.ReadLogContents(); + Assert.Contains(this.GetLogLevelName(logLevel), logContents); + Assert.Contains(testMessage, logContents); + } + + private void AssertExcludesMessageBelowLevel(LogLevel minimumLogLevel) + { + Logger.Initialize(logFilePath, minimumLogLevel); + + // Get all possible log levels + LogLevel[] allLogLevels = + Enum.GetValues(typeof(LogLevel)) + .Cast() + .ToArray(); + + // Write a message at each log level + foreach (var logLevel in allLogLevels) + { + Logger.Write((LogLevel)logLevel, testMessage); + } + + // Make sure all excluded log levels aren't in the contents + string logContents = this.ReadLogContents(); + for (int i = 0; i < (int)minimumLogLevel; i++) + { + LogLevel logLevel = allLogLevels[i]; + Assert.DoesNotContain(this.GetLogLevelName(logLevel), logContents); + } + } + + private string GetLogLevelName(LogLevel logLevel) + { + return logLevel.ToString().ToUpper(); + } + + private string ReadLogContents() + { + Logger.Close(); + + return + string.Join( + "\r\n", + File.ReadAllLines( + logFilePath, + Encoding.UTF8)); + } + + #endregion + } +}