Address PR feedback - use Env.NewLine, comment strbld capacity

Author: rkeithhill

src/PowerShellEditorServices.Protocol/MessageProtocol/MessageReader.cs

@@ -113,9 +113,12 @@ public async Task<Message> ReadMessage()
             // Deserialize the message from the parsed JSON message
             Message parsedMessage = this.messageSerializer.DeserializeMessage(messageObject);
 
-            // Log message info
+            // Log message info - initial capacity for StringBuilder varies depending on whether
+            // the log level is Diagnostic where JsonRpc message payloads are logged and 
+            // vary from 1K up edited file size chars.  When not logging message payloads the 
+            // typical request log message is under 250 chars.
             var logStrBld =
-                new StringBuilder(512)
+                new StringBuilder(this.logger.MinimumConfiguredLogLevel == LogLevel.Diagnostic ? 4096 : 250)
                    .Append("Received ")
                    .Append(parsedMessage.MessageType)
                    .Append(" '").Append(parsedMessage.Method).Append("'");
@@ -127,17 +130,13 @@ public async Task<Message> ReadMessage()
 
             if (this.logger.MinimumConfiguredLogLevel == LogLevel.Diagnostic)
             {
+                // Log the JSON representation of the message payload at the Diagnostic log level
                 string jsonPayload = messageObject.ToString(Formatting.Indented);
-                logStrBld.Append("\r\n\r\n").Append(jsonPayload);
-
-                // Log the JSON representation of the message
-                this.logger.Write(LogLevel.Diagnostic, logStrBld.ToString());
-            }
-            else
-            {
-                this.logger.Write(LogLevel.Verbose, logStrBld.ToString());
+                logStrBld.Append(Environment.NewLine).Append(Environment.NewLine).Append(jsonPayload);
             }
 
+            this.logger.Write(LogLevel.Verbose, logStrBld.ToString());
+
             return parsedMessage;
         }
 

src/PowerShellEditorServices.Protocol/MessageProtocol/MessageWriter.cs

@@ -58,9 +58,12 @@ public async Task WriteMessage(Message messageToWrite)
                 this.messageSerializer.SerializeMessage(
                     messageToWrite);
 
-            // Log message info
+            // Log message info - initial capacity for StringBuilder varies depending on whether
+            // the log level is Diagnostic where JsonRpc message payloads are logged and 
+            // vary from 1K up 225K chars.  When not logging message payloads the typical response
+            // log message is under 250 chars.
             var logStrBld = 
-                new StringBuilder(512)
+                new StringBuilder(this.logger.MinimumConfiguredLogLevel == LogLevel.Diagnostic ? 4096 : 250)
                    .Append("Writing ")
                    .Append(messageToWrite.MessageType)
                    .Append(" '").Append(messageToWrite.Method).Append("'");
@@ -72,22 +75,18 @@ public async Task WriteMessage(Message messageToWrite)
 
             if (this.logger.MinimumConfiguredLogLevel == LogLevel.Diagnostic)
             {
+                // Log the JSON representation of the message payload at the Diagnostic log level
                 string jsonPayload = 
                     JsonConvert.SerializeObject(
                         messageObject,
                         Formatting.Indented,
                         Constants.JsonSerializerSettings);
 
-                logStrBld.Append("\r\n\r\n").Append(jsonPayload);
-
-                // Log the JSON representation of the message
-                this.logger.Write(LogLevel.Diagnostic, logStrBld.ToString());
-            }
-            else
-            {
-                this.logger.Write(LogLevel.Verbose, logStrBld.ToString());
+                logStrBld.Append(Environment.NewLine).Append(Environment.NewLine).Append(jsonPayload);
             }
 
+            this.logger.Write(LogLevel.Verbose, logStrBld.ToString());
+
             string serializedMessage =
                 JsonConvert.SerializeObject(
                     messageObject,

tools/PsesLogAnalyzer/Parse-PsesLog.ps1

@@ -12,6 +12,11 @@ function Parse-PsesLog {
         [string]
         $Path,
 
+        # Old log file format <= v1.9.0
+        [Parameter()]
+        [switch]
+        $OldLogFormat,
+
         # Hides the progress bar.
         [Parameter()]
         [switch]
@@ -22,10 +27,12 @@ function Parse-PsesLog {
         [switch]
         $SkipRpcMessageBody,
 
+        # Emit debug timing info on time to parse each log entry
         [Parameter()]
         [switch]
         $DebugTimingInfo,
 
+        # Threshold for emitting debug timing info. Default is 100 ms.
         [Parameter()]
         [int]
         $DebugTimingThresholdMs = 100
@@ -36,12 +43,22 @@ function Parse-PsesLog {
         $script:currentLineNum = 1
         $script:logEntryIndex = 0
 
-        # Example log entry start:
-        # 2018-11-24 12:26:58.302 [DIAGNOSTIC] tid:28 in 'ReadMessage' C:\Users\Keith\GitHub\rkeithhill\PowerShellEditorServices\src\PowerShellEditorServices.Protocol\MessageProtocol\MessageReader.cs:114:
-        $logEntryRegex =
-            [regex]::new(
-                '(?<ts>[^\[]+)\[(?<lev>([^\]]+))\]\s+tid:(?<tid>\d+)\s+in\s+''(?<meth>\w+)''\s+(?<file>..[^:]+):(?<line>\d+)',
-                [System.Text.RegularExpressions.RegexOptions]::Compiled -bor [System.Text.RegularExpressions.RegexOptions]::IgnoreCase)
+        if ($OldLogFormat) {
+            # Example old log entry start
+            # 2018-11-15 19:49:06.979 [NORMAL] C:\PowerShellEditorServices\src\PowerShellEditorServices.Host\EditorServicesHost.cs: In method 'StartLogging', line 160:
+            $logEntryRegex =
+                [regex]::new(
+                    '^(?<ts>[^\[]+)\[(?<lev>([^\]]+))\]\s+(?<file>..[^:]+):\s+In method\s+''(?<meth>\w+)'',\s+line\s+(?<line>\d+)',
+                    [System.Text.RegularExpressions.RegexOptions]::Compiled -bor [System.Text.RegularExpressions.RegexOptions]::IgnoreCase)
+        }
+        else {
+            # Example new log entry start:
+            # 2018-11-24 12:26:58.302 [DIAGNOSTIC] tid:28 in 'ReadMessage' C:\Users\Keith\GitHub\rkeithhill\PowerShellEditorServices\src\PowerShellEditorServices.Protocol\MessageProtocol\MessageReader.cs:114:
+            $logEntryRegex =
+                [regex]::new(
+                    '^(?<ts>[^\[]+)\[(?<lev>([^\]]+))\]\s+tid:(?<tid>\d+)\s+in\s+''(?<meth>\w+)''\s+(?<file>..[^:]+):(?<line>\d+)',
+                    [System.Text.RegularExpressions.RegexOptions]::Compiled -bor [System.Text.RegularExpressions.RegexOptions]::IgnoreCase)
+        }
 
         $filestream =
             [System.IO.FileStream]::new(
@@ -102,7 +119,7 @@ function Parse-PsesLog {
 
             $message = parseMessage $method
 
-            [PsesLogEntry]::new($script:logEntryIndex, $timestamp, $timestampStr, $logLevel, $threadId, $method, 
+            [PsesLogEntry]::new($script:logEntryIndex, $timestamp, $timestampStr, $logLevel, $threadId, $method,
                 $file, $lineNumber, $message.MessageType, $message.Message)
 
             if ($DebugTimingInfo) {