diff --git a/src/PowerShellEditorServices.Protocol/MessageProtocol/MessageReader.cs b/src/PowerShellEditorServices.Protocol/MessageProtocol/MessageReader.cs index 66f75c375..dcf7aaa94 100644 --- a/src/PowerShellEditorServices.Protocol/MessageProtocol/MessageReader.cs +++ b/src/PowerShellEditorServices.Protocol/MessageProtocol/MessageReader.cs @@ -110,20 +110,32 @@ public async Task ReadMessage() // Get the JObject for the JSON content JObject messageObject = JObject.Parse(messageContent); - // Load the message - this.logger.Write( - LogLevel.Diagnostic, - string.Format( - "READ MESSAGE:\r\n\r\n{0}", - messageObject.ToString(Formatting.Indented))); - - // Return the parsed message + // Deserialize the message from the parsed JSON message Message parsedMessage = this.messageSerializer.DeserializeMessage(messageObject); - this.logger.Write( - LogLevel.Verbose, - $"Received {parsedMessage.MessageType} '{parsedMessage.Method}'" + - (!string.IsNullOrEmpty(parsedMessage.Id) ? $" with id {parsedMessage.Id}" : string.Empty)); + // Log message info - initial capacity for StringBuilder varies depending on whether + // the log level is Diagnostic where JsonRpc message payloads are logged and vary in size + // from 1K up to the edited file size. When not logging message payloads, the typical + // request log message size is under 256 chars. + var logStrBld = + new StringBuilder(this.logger.MinimumConfiguredLogLevel == LogLevel.Diagnostic ? 4096 : 256) + .Append("Received ") + .Append(parsedMessage.MessageType) + .Append(" '").Append(parsedMessage.Method).Append("'"); + + if (!string.IsNullOrEmpty(parsedMessage.Id)) + { + logStrBld.Append(" with id ").Append(parsedMessage.Id); + } + + 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(Environment.NewLine).Append(Environment.NewLine).Append(jsonPayload); + } + + this.logger.Write(LogLevel.Verbose, logStrBld.ToString()); return parsedMessage; } diff --git a/src/PowerShellEditorServices.Protocol/MessageProtocol/MessageWriter.cs b/src/PowerShellEditorServices.Protocol/MessageProtocol/MessageWriter.cs index c618fa104..f2082efba 100644 --- a/src/PowerShellEditorServices.Protocol/MessageProtocol/MessageWriter.cs +++ b/src/PowerShellEditorServices.Protocol/MessageProtocol/MessageWriter.cs @@ -58,20 +58,34 @@ public async Task WriteMessage(Message messageToWrite) this.messageSerializer.SerializeMessage( messageToWrite); - this.logger.Write( - LogLevel.Verbose, - $"Writing {messageToWrite.MessageType} '{messageToWrite.Method}'" + - (!string.IsNullOrEmpty(messageToWrite.Id) ? $" with id {messageToWrite.Id}" : string.Empty)); - - // Log the JSON representation of the message - this.logger.Write( - LogLevel.Diagnostic, - string.Format( - "WRITE MESSAGE:\r\n\r\n{0}", + // Log message info - initial capacity for StringBuilder varies depending on whether + // the log level is Diagnostic where JsonRpc message payloads are logged and vary + // in size from 1K up to 225K chars. When not logging message payloads, the typical + // response log message size is under 256 chars. + var logStrBld = + new StringBuilder(this.logger.MinimumConfiguredLogLevel == LogLevel.Diagnostic ? 4096 : 256) + .Append("Writing ") + .Append(messageToWrite.MessageType) + .Append(" '").Append(messageToWrite.Method).Append("'"); + + if (!string.IsNullOrEmpty(messageToWrite.Id)) + { + logStrBld.Append(" with id ").Append(messageToWrite.Id); + } + + 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))); + Constants.JsonSerializerSettings); + + logStrBld.Append(Environment.NewLine).Append(Environment.NewLine).Append(jsonPayload); + } + + this.logger.Write(LogLevel.Verbose, logStrBld.ToString()); string serializedMessage = JsonConvert.SerializeObject( diff --git a/src/PowerShellEditorServices/Utility/PsesLogger.cs b/src/PowerShellEditorServices/Utility/PsesLogger.cs index b60ea603b..e7dd29e9e 100644 --- a/src/PowerShellEditorServices/Utility/PsesLogger.cs +++ b/src/PowerShellEditorServices/Utility/PsesLogger.cs @@ -15,7 +15,7 @@ public class PsesLogger : ILogger /// The standard log template for all log entries. /// private static readonly string s_logMessageTemplate = - "[{LogLevelName:l}] tid:{ThreadId} in '{CallerName:l}' {CallerSourceFile:l} (line {CallerLineNumber}):{IndentedLogMsg:l}"; + "[{LogLevelName:l}] tid:{ThreadId} in '{CallerName:l}' {CallerSourceFile:l}: line {CallerLineNumber}{IndentedLogMsg:l}"; /// /// The name of the ERROR log level. diff --git a/tools/PsesLogAnalyzer/.vscode/launch.json b/tools/PsesLogAnalyzer/.vscode/launch.json new file mode 100644 index 000000000..cca4ceb41 --- /dev/null +++ b/tools/PsesLogAnalyzer/.vscode/launch.json @@ -0,0 +1,14 @@ +{ + // Use IntelliSense to learn about possible attributes. + // Hover to view descriptions of existing attributes. + // For more information, visit: https://go.microsoft.com/fwlink/?linkid=830387 + "version": "0.2.0", + "configurations": [ + { + "type": "PowerShell", + "request": "launch", + "name": "PowerShell Interactive Session", + "cwd": "" + } + ] +} diff --git a/tools/PsesLogAnalyzer/Analyze.ps1 b/tools/PsesLogAnalyzer/Analyze.ps1 new file mode 100644 index 000000000..19c942845 --- /dev/null +++ b/tools/PsesLogAnalyzer/Analyze.ps1 @@ -0,0 +1,213 @@ +function Get-PsesRpcNotificationMessage { + [CmdletBinding(DefaultParameterSetName = "PsesLogEntry")] + param( + # Specifies a path to one or more PSES EditorServices log files. + [Parameter(Mandatory = $true, Position = 0, ParameterSetName = "Path")] + [Alias("PSPath")] + [ValidateNotNullOrEmpty()] + [string] + $Path, + + # Specifies PsesLogEntry objects to analyze. + [Parameter(Mandatory = $true, Position = 0, ParameterSetName = "PsesLogEntry", ValueFromPipeline = $true)] + [ValidateNotNull()] + [psobject[]] + $LogEntry, + + # Specifies a filter for either client or server sourced notifications. By default both are output. + [Parameter()] + [ValidateSet('Client', 'Server')] + [string] + $Source + ) + + begin { + if ($PSCmdlet.ParameterSetName -eq "Path") { + $logEntries = Parse-PsesLog $Path + } + } + + process { + if ($PSCmdlet.ParameterSetName -eq "PsesLogEntry") { + $logEntries = $LogEntry + } + + foreach ($entry in $logEntries) { + if ($entry.LogMessageType -eq 'Notification') { + if (!$Source -or ($entry.Message.Source -eq $Source)) { + $entry + } + } + } + } +} + +function Get-PsesRpcMessageResponseTime { + [CmdletBinding(DefaultParameterSetName = "PsesLogEntry")] + param( + # Specifies a path to one or more PSES EditorServices log files. + [Parameter(Mandatory=$true, Position=0, ParameterSetName="Path")] + [Alias("PSPath")] + [ValidateNotNullOrEmpty()] + [string] + $Path, + + # Specifies PsesLogEntry objects to analyze. + [Parameter(Mandatory=$true, Position=0, ParameterSetName="PsesLogEntry", ValueFromPipeline=$true)] + [ValidateNotNull()] + [psobject[]] + $LogEntry + ) + + begin { + if ($PSCmdlet.ParameterSetName -eq "Path") { + $logEntries = Parse-PsesLog $Path + } + } + + process { + if ($PSCmdlet.ParameterSetName -eq "PsesLogEntry") { + $logEntries += $LogEntry + } + } + + end { + # Populate $requests hashtable with request timestamps + $requests = @{} + $logEntries | + Where-Object LogMessageType -match Request | + Foreach-Object { $requests[$_.Message.Id] = $_.Timestamp } + + $res = $logEntries | + Where-Object LogMessageType -match Response | + Foreach-Object { + $elapsedMilliseconds = [int]($_.Timestamp - $requests[$_.Message.Id]).TotalMilliseconds + [PsesLogEntryElapsed]::new($_, $elapsedMilliseconds) + } + + $res + } +} + +function Get-PsesScriptAnalysisCompletionTime { + [CmdletBinding(DefaultParameterSetName = "PsesLogEntry")] + param( + # Specifies a path to one or more PSES EditorServices log files. + [Parameter(Mandatory = $true, Position = 0, ParameterSetName = "Path")] + [Alias("PSPath")] + [ValidateNotNullOrEmpty()] + [string] + $Path, + + # Specifies PsesLogEntry objects to analyze. + [Parameter(Mandatory = $true, Position = 0, ParameterSetName = "PsesLogEntry", ValueFromPipeline = $true)] + [ValidateNotNull()] + [psobject[]] + $LogEntry + ) + + begin { + if ($PSCmdlet.ParameterSetName -eq "Path") { + $logEntries = Parse-PsesLog $Path + } + } + + process { + if ($PSCmdlet.ParameterSetName -eq "PsesLogEntry") { + $logEntries = $LogEntry + } + + foreach ($entry in $logEntries) { + if (($entry.LogMessageType -eq 'Log') -and ($entry.Message.Data -match '^\s*Script analysis of.*\[(?\d+)ms\]\s*$')) { + $elapsedMilliseconds = [int]$matches["ms"] + [PsesLogEntryElapsed]::new($entry, $elapsedMilliseconds) + } + } + } +} + +function Get-PsesIntelliSenseCompletionTime { + [CmdletBinding(DefaultParameterSetName = "PsesLogEntry")] + param( + # Specifies a path to one or more PSES EditorServices log files. + [Parameter(Mandatory = $true, Position = 0, ParameterSetName = "Path")] + [Alias("PSPath")] + [ValidateNotNullOrEmpty()] + [string] + $Path, + + # Specifies PsesLogEntry objects to analyze. + [Parameter(Mandatory = $true, Position = 0, ParameterSetName = "PsesLogEntry", ValueFromPipeline = $true)] + [ValidateNotNull()] + [psobject[]] + $LogEntry + ) + + begin { + if ($PSCmdlet.ParameterSetName -eq "Path") { + $logEntries = Parse-PsesLog $Path + } + } + + process { + if ($PSCmdlet.ParameterSetName -eq "PsesLogEntry") { + $logEntries = $LogEntry + } + + foreach ($entry in $logEntries) { + # IntelliSense completed in 320ms. + if (($entry.LogMessageType -eq 'Log') -and ($entry.Message.Data -match '^\s*IntelliSense completed in\s+(?\d+)ms.\s*$')) { + $elapsedMilliseconds = [int]$matches["ms"] + [PsesLogEntryElapsed]::new($entry, $elapsedMilliseconds) + } + } + } +} + +function Get-PsesMessage { + [CmdletBinding(DefaultParameterSetName = "PsesLogEntry")] + param( + # Specifies a path to one or more PSES EditorServices log files. + [Parameter(Mandatory = $true, Position = 0, ParameterSetName = "Path")] + [Alias("PSPath")] + [ValidateNotNullOrEmpty()] + [string] + $Path, + + # Specifies PsesLogEntry objects to analyze. + [Parameter(Mandatory = $true, Position = 0, ParameterSetName = "PsesLogEntry", ValueFromPipeline = $true)] + [ValidateNotNull()] + [psobject[]] + $LogEntry, + + # Specifies the log level entries to return. Default returns Normal and above. + # Use StrictMatch to return only the specified log level entries. + [Parameter()] + [PsesLogLevel] + $LogLevel = $([PsesLogLevel]::Normal), + + # Use StrictMatch to return only the specified log level entries. + [Parameter()] + [switch] + $StrictMatch + ) + + begin { + if ($PSCmdlet.ParameterSetName -eq "Path") { + $logEntries = Parse-PsesLog $Path + } + } + + process { + if ($PSCmdlet.ParameterSetName -eq "PsesLogEntry") { + $logEntries = $LogEntry + } + + foreach ($entry in $logEntries) { + if (($StrictMatch -and ($entry.LogLevel -eq $LogLevel)) -or + (!$StrictMatch -and ($entry.LogLevel -ge $LogLevel))) { + $entry + } + } + } +} diff --git a/tools/PsesLogAnalyzer/Parse-PsesLog.ps1 b/tools/PsesLogAnalyzer/Parse-PsesLog.ps1 new file mode 100644 index 000000000..83263e2b7 --- /dev/null +++ b/tools/PsesLogAnalyzer/Parse-PsesLog.ps1 @@ -0,0 +1,267 @@ + +$peekBuf = $null +$currentLineNum = 0 +$logEntryIndex = 0 + +function Parse-PsesLog { + param( + # Specifies a path to a PSES EditorServices log file. + [Parameter(Mandatory=$true, Position=0)] + [Alias("PSPath")] + [ValidateNotNullOrEmpty()] + [string] + $Path, + + # Old log file format <= v1.9.0 + [Parameter()] + [switch] + $OldLogFormat, + + # Hides the progress bar. + [Parameter()] + [switch] + $HideProgress, + + # Skips conversion from JSON & storage of the JsonRpc message body which can be large. + [Parameter()] + [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 + ) + + begin { + $script:peekBuf = $null + $script:currentLineNum = 1 + $script:logEntryIndex = 0 + + 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( + '^(?[^\[]+)\[(?([^\]]+))\]\s+(?..[^:]+):\s+In method\s+''(?\w+)'',\s+line\s+(?\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: line 114 + $logEntryRegex = + [regex]::new( + '^(?[^\[]+)\[(?([^\]]+))\]\s+tid:(?\d+)\s+in\s+''(?\w+)''\s+(?..[^:]+):\s+line\s+(?\d+)', + [System.Text.RegularExpressions.RegexOptions]::Compiled -bor [System.Text.RegularExpressions.RegexOptions]::IgnoreCase) + } + + $filestream = + [System.IO.FileStream]::new( + $Path, + [System.IO.FileMode]:: Open, + [System.IO.FileAccess]::Read, + [System.IO.FileShare]::ReadWrite, + 4096, + [System.IO.FileOptions]::SequentialScan) + + $streamReader = [System.IO.StreamReader]::new($filestream, [System.Text.Encoding]::UTF8) + + function nextLine() { + if ($null -ne $peekBuf) { + $line = $peekBuf + $script:peekBuf = $null + } + else { + $line = $streamReader.ReadLine() + } + + $script:currentLineNum++ + $line + } + + function peekLine() { + if ($null -ne $peekBuf) { + $line = $peekBuf; + } + else { + $line = $script:peekBuf = $streamReader.ReadLine() + } + + $line + } + + function parseLogEntryStart([string]$line) { + if ($DebugTimingInfo) { + $sw = [System.Diagnostics.Stopwatch]::StartNew() + } + + while ($line -notmatch $logEntryRegex) { + Write-Warning "Ignoring line:${currentLineNum} '$line'" + $line = nextLine + } + + if (!$HideProgress -and ($script:logEntryIndex % 50 -eq 0)) { + Write-Progress "Processing log entry ${script:logEntryIndex} on line: ${script:currentLineNum}" + } + + [string]$timestampStr = $matches["ts"] + [DateTime]$timestamp = $timestampStr + [PsesLogLevel]$logLevel = $matches["lev"] + [int]$threadId = $matches["tid"] + [string]$method = $matches["meth"] + [string]$file = $matches["file"] + [int]$lineNumber = $matches["line"] + + $message = parseLogMessage $method + + [PsesLogEntry]::new($script:logEntryIndex, $timestamp, $timestampStr, $logLevel, $threadId, $method, + $file, $lineNumber, $message.LogMessageType, $message.LogMessage) + + if ($DebugTimingInfo) { + $sw.Stop() + if ($sw.ElapsedMilliseconds -gt $DebugTimingThresholdMs) { + Write-Warning "Time to parse log entry ${script:logEntryIndex} - $($sw.ElapsedMilliseconds) ms" + } + } + + $script:logEntryIndex++ + } + + function parseLogMessage([string]$Method) { + $result = [PSCustomObject]@{ + LogMessageType = [PsesLogMessageType]::Log + LogMessage = $null + } + + $line = nextLine + if ($null -eq $line) { + Write-Warning "$($MyInvocation.MyCommand.Name) encountered end of file early." + return $result + } + + if (($Method -eq 'ReadMessage') -and + ($line -match '^\s+Received Request ''(?[^'']+)'' with id (?\d+)')) { + $result.LogMessageType = [PsesLogMessageType]::Request + $msg = $matches["msg"] + $id = $matches["id"] + $json = parseLogMessageBodyAsJson + $result.LogMessage = [PsesJsonRpcMessage]::new($msg, $id, $json.Data, $json.DataSize) + } + elseif (($Method -eq 'ReadMessage') -and + ($line -match '^\s+Received event ''(?[^'']+)''')) { + $result.LogMessageType = [PsesLogMessageType]::Notification + $msg = $matches["msg"] + $json = parseLogMessageBodyAsJson + $result.LogMessage = [PsesNotificationMessage]::new($msg, [PsesNotificationSource]::Client, $json.Data, $json.DataSize) + } + elseif (($Method -eq 'WriteMessage') -and + ($line -match '^\s+Writing Response ''(?[^'']+)'' with id (?\d+)')) { + $result.LogMessageType = [PsesLogMessageType]::Response + $msg = $matches["msg"] + $id = $matches["id"] + $json = parseLogMessageBodyAsJson + $result.LogMessage = [PsesJsonRpcMessage]::new($msg, $id, $json.Data, $json.DataSize) + } + elseif (($Method -eq 'WriteMessage') -and + ($line -match '^\s+Writing event ''(?[^'']+)''')) { + $result.LogMessageType = [PsesLogMessageType]::Notification + $msg = $matches["msg"] + $json = parseLogMessageBodyAsJson + $result.LogMessage = [PsesNotificationMessage]::new($msg, [PsesNotificationSource]::Server, $json.Data, $json.DataSize) + } + else { + if ($line -match '^\s+Exception: ') { + $result.LogMessageType = [PsesLogMessageType]::Exception + } + elseif ($line -match '^\s+Handled exception: ') { + $result.LogMessageType = [PsesLogMessageType]::HandledException + } + else { + $result.LogMessageType = [PsesLogMessageType]::Log + } + + $body = parseLogMessageBody $line + $result.LogMessage = [PsesLogMessage]::new($body) + } + + $result + } + + function parseLogMessageBody([string]$startLine = '', [switch]$Discard) { + if (!$Discard) { + $strBld = [System.Text.StringBuilder]::new($startLine, 4096) + $newLine = "`r`n" + } + + try { + while ($true) { + $peekLine = peekLine + if ($null -eq $peekLine) { + break + } + + if (($peekLine.Length -gt 0) -and ($peekLine[0] -ne ' ') -and ($peekLine -match $logEntryRegex)) { + break + } + + $nextLine = nextLine + if (!$Discard) { + [void]$strBld.Append($nextLine).Append($newLine) + } + } + } + catch { + Write-Error "Failed parsing message body with error: $_" + } + + if (!$Discard) { + $msgBody = $strBld.ToString().Trim() + $msgBody + } + else { + $startLine + } + } + + function parseLogMessageBodyAsJson() { + $result = [PSCustomObject]@{ + Data = $null + DataSize = 0 + } + + $obj = $null + + if ($SkipRpcMessageBody) { + parseLogMessageBody -Discard + return $result + } + + $result.Data = parseLogMessageBody + $result.DataSize = $result.Data.Length + + try { + $result.Data = $result.Data.Trim() | ConvertFrom-Json + } + catch { + Write-Error "Failed parsing JSON message body with error: $_" + } + + $result + } + } + + process { + while ($null -ne ($line = nextLine)) { + parseLogEntryStart $line + } + } + + end { + if ($streamReader) { $streamReader.Dispose() } + } +} diff --git a/tools/PsesLogAnalyzer/PsesLogAnalyzer.format.ps1xml b/tools/PsesLogAnalyzer/PsesLogAnalyzer.format.ps1xml new file mode 100644 index 000000000..5c6ba1823 --- /dev/null +++ b/tools/PsesLogAnalyzer/PsesLogAnalyzer.format.ps1xml @@ -0,0 +1,123 @@ + + + + PsesLogEntry + + PsesLogEntry + + + + + + 6 + right + + + + 24 + left + + + + 5 + right + + + + 15 + left + + + + 11 + left + + + + left + + + + + + + Index + + + TimestampStr + + + ThreadId + + + LogMessageType + + + LogLevel + + + ($_.Message -split "`r`n")[0] + + + + + + + + + PsesLogEntryElapsed + + PsesLogEntryElapsed + + + + + + 6 + right + + + + 24 + left + + + + 5 + right + + + + 13 + right + + + + left + + + + + + + Index + + + TimestampStr + + + ThreadId + + + $_.ElapsedMilliseconds + + + $_.Message + + + + + + + + diff --git a/tools/PsesLogAnalyzer/PsesLogAnalyzer.psd1 b/tools/PsesLogAnalyzer/PsesLogAnalyzer.psd1 new file mode 100644 index 000000000..10c225ee7 --- /dev/null +++ b/tools/PsesLogAnalyzer/PsesLogAnalyzer.psd1 @@ -0,0 +1,130 @@ +# +# Module manifest for module 'Pses-LogAnalyzer' +# +# Generated by: Keith +# +# Generated on: 11/23/2018 +# + +@{ + +# Script module or binary module file associated with this manifest. +RootModule = 'PsesLogAnalyzer.psm1' + +# Version number of this module. +ModuleVersion = '1.0.0' + +# Supported PSEditions +# CompatiblePSEditions = @() + +# ID used to uniquely identify this module +GUID = '99116548-ad0f-4087-a425-7edab3aa9e57' + +# Author of this module +Author = 'Microsoft' + +# Company or vendor of this module +CompanyName = 'Microsoft' + +# Copyright statement for this module +Copyright = '(c) 2018 Microsoft. All rights reserved.' + +# Description of the functionality provided by this module +Description = 'PowerShellEditorServices log file parser and analysis commands.' + +# Minimum version of the PowerShell engine required by this module +PowerShellVersion = '5.1' + +# Name of the PowerShell host required by this module +# PowerShellHostName = '' + +# Minimum version of the PowerShell host required by this module +# PowerShellHostVersion = '' + +# Minimum version of Microsoft .NET Framework required by this module. This prerequisite is valid for the PowerShell Desktop edition only. +# DotNetFrameworkVersion = '' + +# Minimum version of the common language runtime (CLR) required by this module. This prerequisite is valid for the PowerShell Desktop edition only. +# CLRVersion = '' + +# Processor architecture (None, X86, Amd64) required by this module +# ProcessorArchitecture = '' + +# Modules that must be imported into the global environment prior to importing this module +# RequiredModules = @() + +# Assemblies that must be loaded prior to importing this module +# RequiredAssemblies = @() + +# Script files (.ps1) that are run in the caller's environment prior to importing this module. +# ScriptsToProcess = @() + +# Type files (.ps1xml) to be loaded when importing this module +# TypesToProcess = @() + +# Format files (.ps1xml) to be loaded when importing this module +FormatsToProcess = @('PsesLogAnalyzer.format.ps1xml') + +# Modules to import as nested modules of the module specified in RootModule/ModuleToProcess +# NestedModules = @() + +# Functions to export from this module, for best performance, do not use wildcards and do not delete the entry, use an empty array if there are no functions to export. +FunctionsToExport = @( + 'Parse-PsesLog', + 'Get-PsesRpcMessageResponseTime', + 'Get-PsesRpcNotificationMessage', + 'Get-PsesScriptAnalysisCompletionTime', + 'Get-PsesIntelliSenseCompletionTime', + 'Get-PsesMessage' +) + +# Cmdlets to export from this module, for best performance, do not use wildcards and do not delete the entry, use an empty array if there are no cmdlets to export. +CmdletsToExport = @() + +# Variables to export from this module +VariablesToExport = '' + +# Aliases to export from this module, for best performance, do not use wildcards and do not delete the entry, use an empty array if there are no aliases to export. +AliasesToExport = @() + +# DSC resources to export from this module +# DscResourcesToExport = @() + +# List of all modules packaged with this module +# ModuleList = @() + +# List of all files packaged with this module +# FileList = @() + +# Private data to pass to the module specified in RootModule/ModuleToProcess. This may also contain a PSData hashtable with additional module metadata used by PowerShell. +PrivateData = @{ + + PSData = @{ + + # Tags applied to this module. These help with module discovery in online galleries. + # Tags = @() + + # A URL to the license for this module. + # LicenseUri = '' + + # A URL to the main website for this project. + # ProjectUri = '' + + # A URL to an icon representing this module. + # IconUri = '' + + # ReleaseNotes of this module + # ReleaseNotes = '' + + } # End of PSData hashtable + +} # End of PrivateData hashtable + +# HelpInfo URI of this module +# HelpInfoURI = '' + +# Default prefix for commands exported from this module. Override the default prefix using Import-Module -Prefix. +# DefaultCommandPrefix = '' + +} + diff --git a/tools/PsesLogAnalyzer/PsesLogAnalyzer.psm1 b/tools/PsesLogAnalyzer/PsesLogAnalyzer.psm1 new file mode 100644 index 000000000..700946c40 --- /dev/null +++ b/tools/PsesLogAnalyzer/PsesLogAnalyzer.psm1 @@ -0,0 +1,3 @@ +. $PSScriptRoot\Types.ps1 +. $PSScriptRoot\Parse-PsesLog.ps1 +. $PSScriptRoot\Analyze.ps1 diff --git a/tools/PsesLogAnalyzer/Types.ps1 b/tools/PsesLogAnalyzer/Types.ps1 new file mode 100644 index 000000000..dd7a9fa1a --- /dev/null +++ b/tools/PsesLogAnalyzer/Types.ps1 @@ -0,0 +1,154 @@ +enum PsesLogLevel { + Diagnostic + Verbose + Normal + Warning + Error +} + +enum PsesLogMessageType { + Log + Exception + HandledException + Request + Response + Notification +} + +enum PsesNotificationSource { + Unknown + Client + Server +} + +class PsesLogMessage { + [string]$Data + [int]$DataSize + + PsesLogMessage([string]$Data) { + $this.Data = $Data + $this.DataSize = $Data.Length + } + + [string] ToString() { + $ofs = '' + $ellipsis = if ($this.Data.Length -ge 100) { "..." } else { "" } + return "$($this.Data[0..99])$ellipsis, DataSize: $($this.Data.Length)" + } +} + +class PsesJsonRpcMessage { + [string]$Name + [int]$Id + [psobject]$Data + [int]$DataSize + + PsesJsonRpcMessage([string]$Name, [int]$Id, [psobject]$Data, [int]$DataSize) { + $this.Name = $Name + $this.Id = $Id + $this.Data = $Data + $this.DataSize = $DataSize + } + + [string] ToString() { + return "Name: $($this.Name) Id: $($this.Id), DataSize: $($this.DataSize)" + } +} + +class PsesNotificationMessage { + [string]$Name + [PsesNotificationSource]$Source + [psobject]$Data + [int]$DataSize + + PsesNotificationMessage([string]$Name, [PsesNotificationSource]$Source, [psobject]$Data, [int]$DataSize) { + $this.Name = $Name + $this.Source = $Source + $this.Data = $Data + $this.DataSize = $DataSize + } + + [string] ToString() { + if (($this.Name -eq '$/cancelRequest') -and ($this.Data -ne $null)) { + return "Name: $($this.Name) Source: $($this.Source), Id: $($this.Data.params.id)" + } + + return "Name: $($this.Name) Source: $($this.Source), DataSize: $($this.DataSize)" + } +} + +class PsesLogEntry { + [int]$Index + [DateTime]$Timestamp + [string]$TimestampStr + [PsesLogLevel]$LogLevel + [int]$ThreadId + [string]$Method + [string]$File + [int]$LineNumber + [PsesLogMessageType]$LogMessageType + [psobject]$Message + + PsesLogEntry( + [int] + $Index, + [DateTime] + $Timestamp, + [string] + $TimestampStr, + [PsesLogLevel] + $LogLevel, + [int] + $ThreadId, + [string] + $Method, + [string] + $File, + [int] + $LineNumber, + [PsesLogMessageType] + $LogMessageType, + [psobject] + $Message) { + + $this.Index = $Index + $this.Timestamp = $Timestamp + $this.TimestampStr = $TimestampStr + $this.LogLevel = $LogLevel + $this.ThreadId = $ThreadId + $this.Method = $Method + $this.File = $File + $this.LineNumber = $LineNumber + $this.LogMessageType = $LogMessageType + $this.Message = $Message + } +} + +class PsesLogEntryElapsed { + [int]$Index + [DateTime]$Timestamp + [string]$TimestampStr + [int]$ElapsedMilliseconds + [PsesLogLevel]$LogLevel + [int]$ThreadId + [string]$Method + [string]$File + [int]$LineNumber + [PsesLogMessageType]$LogMessageType + [psobject]$Message + + PsesLogEntryElapsed([PsesLogEntry]$LogEntry, [int]$ElapsedMilliseconds) { + $this.Index = $LogEntry.Index + $this.Timestamp = $LogEntry.Timestamp + $this.TimestampStr = $LogEntry.TimestampStr + $this.LogLevel = $LogEntry.LogLevel + $this.ThreadId = $LogEntry.ThreadId + $this.Method = $LogEntry.Method + $this.File = $LogEntry.File + $this.LineNumber = $LogEntry.LineNumber + $this.LogMessageType = $LogEntry.LogMessageType + $this.Message = $LogEntry.Message + + $this.ElapsedMilliseconds = $ElapsedMilliseconds + } +}