From d26e2a61e3de5da78d723bc4b2e07dac0aa190f9 Mon Sep 17 00:00:00 2001 From: Keith Hill Date: Sat, 23 Mar 2019 15:48:17 -0600 Subject: [PATCH 1/3] Enhance Get-PsesRpcMessageResponseTime to select specific message types --- .vscode/launch.json | 8 +++- tools/PsesLogAnalyzer/Analyze.ps1 | 68 +++++++++++++++++++++++++------ 2 files changed, 63 insertions(+), 13 deletions(-) diff --git a/.vscode/launch.json b/.vscode/launch.json index 4f2d4abab..8d993c480 100644 --- a/.vscode/launch.json +++ b/.vscode/launch.json @@ -12,6 +12,12 @@ "type": "coreclr", "request": "attach", "processId": "${command:pickProcess}" + }, + { + "type": "PowerShell", + "request": "launch", + "name": "PowerShell Interactive Session", + "cwd": "" } ] -} \ No newline at end of file +} diff --git a/tools/PsesLogAnalyzer/Analyze.ps1 b/tools/PsesLogAnalyzer/Analyze.ps1 index 19c942845..45faa1af0 100644 --- a/tools/PsesLogAnalyzer/Analyze.ps1 +++ b/tools/PsesLogAnalyzer/Analyze.ps1 @@ -42,6 +42,26 @@ function Get-PsesRpcNotificationMessage { } } +<# +.SYNOPSIS + Outputs the response time for message LSP message. +.DESCRIPTION + Outputs the response time for message LSP message. Use the MessageNamePattern to + limit the response time output to a specific message (or pattern of messages). +.EXAMPLE + C:\> Get-PsesRpcMessageResponseTime $log + Gets the response time of all LSP messages. +.EXAMPLE + C:\> Get-PsesRpcMessageResponseTime $log -MessageName foldingRange + Gets the response time of all foldingRange LSP messages. +.EXAMPLE + C:\> Get-PsesRpcMessageResponseTime $log -Pattern 'textDocument/.*Formatting' + Gets the response time of all formatting LSP messages. +.INPUTS + System.String or PsesLogEntry +.OUTPUTS + PsesLogEntryElapsed +#> function Get-PsesRpcMessageResponseTime { [CmdletBinding(DefaultParameterSetName = "PsesLogEntry")] param( @@ -56,7 +76,20 @@ function Get-PsesRpcMessageResponseTime { [Parameter(Mandatory=$true, Position=0, ParameterSetName="PsesLogEntry", ValueFromPipeline=$true)] [ValidateNotNull()] [psobject[]] - $LogEntry + $LogEntry, + + # Specifies a specific LSP message for which to get response times. + [Parameter(Position=1)] + [ValidateSet("codeAction", "codeLens", "documentSymbol", "formatting", "hover", "foldingRange", + "rangeFormatting")] + [string] + $MessageName, + + # Specifies a regular expression pattern that filters the output based on the message name + # e.g. 'textDocument/.*Formatting' + [Parameter()] + [string] + $Pattern ) begin { @@ -74,18 +107,29 @@ function Get-PsesRpcMessageResponseTime { 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 + foreach ($entry in $logEntries) { + if (($entry.LogMessageType -ne 'Request') -and ($entry.LogMessageType -ne 'Response')) { continue } + + if ((!$MessageName -or ($entry.Message.Name -eq "textDocument/$MessageName")) -and + (!$Pattern -or ($entry.Message.Name -match $Pattern))) { + + $key = "$($entry.Message.Name)-$($entry.Message.Id)" + if ($entry.LogMessageType -eq 'Request') { + $requests[$key] = $entry + } + else { + $request = $requests[$key] + if (!$request) { + Write-Warning "No corresponding request for response: $($entry.Message)" + continue + } + + $elapsedMilliseconds = [int]($entry.Timestamp - $request.Timestamp).TotalMilliseconds + [PsesLogEntryElapsed]::new($entry, $elapsedMilliseconds) + } + } + } } } From 7e26b85562d925416ba654512bcbeeb943496c2a Mon Sep 17 00:00:00 2001 From: Keith Hill Date: Sat, 23 Mar 2019 16:37:22 -0600 Subject: [PATCH 2/3] Enhance Get-PsesRpcNotificationMessage to filter by message type --- tools/PsesLogAnalyzer/Analyze.ps1 | 65 +++++++++++++++++++++++++++---- 1 file changed, 57 insertions(+), 8 deletions(-) diff --git a/tools/PsesLogAnalyzer/Analyze.ps1 b/tools/PsesLogAnalyzer/Analyze.ps1 index 45faa1af0..5f24209f6 100644 --- a/tools/PsesLogAnalyzer/Analyze.ps1 +++ b/tools/PsesLogAnalyzer/Analyze.ps1 @@ -1,3 +1,22 @@ +<# +.SYNOPSIS + Gets LSP notification messages sent from either PSES to the client or vice-versa. +.DESCRIPTION + Gets LSP notification messages sent from either PSES to the client or vice-versa. +.EXAMPLE + C:\> Get-PsesRpcNotificationMessage $log + Gets all LSP notification messages in the specified log. +.EXAMPLE + C:\> Get-PsesRpcNotificationMessage $log -MessageName $/cancelRequest + Gets all LSP $/cancelRequest notification messages in the specified log. +.EXAMPLE + C:\> Get-PsesRpcNotificationMessage $log -Pattern powershell/.* + Gets all LSP powershell notification messages in the specified log. +.INPUTS + System.String or PsesLogEntry +.OUTPUTS + PsesLogEntry +#> function Get-PsesRpcNotificationMessage { [CmdletBinding(DefaultParameterSetName = "PsesLogEntry")] param( @@ -14,6 +33,27 @@ function Get-PsesRpcNotificationMessage { [psobject[]] $LogEntry, + # Specifies a specific LSP notification. + [Parameter(Position=1)] + [ValidateSet( + "$/cancelRequest", + "initialized", + "powerShell/executionStatusChanged", + "textDocument/didChange", + "textDocument/didClose", + "textDocument/didOpen", + "textDocument/didSave", + "textDocument/publishDiagnostics", + "workspace/didChangeConfiguration")] + [string] + $MessageName, + + # Specifies a regular expression pattern that filters the output based on the message name + # e.g. 'cancelRequest' + [Parameter()] + [string] + $Pattern, + # Specifies a filter for either client or server sourced notifications. By default both are output. [Parameter()] [ValidateSet('Client', 'Server')] @@ -33,10 +73,13 @@ function Get-PsesRpcNotificationMessage { } foreach ($entry in $logEntries) { - if ($entry.LogMessageType -eq 'Notification') { - if (!$Source -or ($entry.Message.Source -eq $Source)) { - $entry - } + if ($entry.LogMessageType -ne 'Notification') { continue } + + if ((!$MessageName -or ($entry.Message.Name -eq $MessageName)) -and + (!$Pattern -or ($entry.Message.Name -match $Pattern)) -and + (!$Source -or ($entry.Message.Source -eq $Source))) { + + $entry } } } @@ -52,7 +95,7 @@ function Get-PsesRpcNotificationMessage { C:\> Get-PsesRpcMessageResponseTime $log Gets the response time of all LSP messages. .EXAMPLE - C:\> Get-PsesRpcMessageResponseTime $log -MessageName foldingRange + C:\> Get-PsesRpcMessageResponseTime $log -MessageName textDocument/foldingRange Gets the response time of all foldingRange LSP messages. .EXAMPLE C:\> Get-PsesRpcMessageResponseTime $log -Pattern 'textDocument/.*Formatting' @@ -80,8 +123,14 @@ function Get-PsesRpcMessageResponseTime { # Specifies a specific LSP message for which to get response times. [Parameter(Position=1)] - [ValidateSet("codeAction", "codeLens", "documentSymbol", "formatting", "hover", "foldingRange", - "rangeFormatting")] + [ValidateSet( + "textDocument/codeAction", + "textDocument/codeLens", + "textDocument/documentSymbol", + "textDocument/foldingRange", + "textDocument/formatting", + "textDocument/hover", + "textDocument/rangeFormatting")] [string] $MessageName, @@ -111,7 +160,7 @@ function Get-PsesRpcMessageResponseTime { foreach ($entry in $logEntries) { if (($entry.LogMessageType -ne 'Request') -and ($entry.LogMessageType -ne 'Response')) { continue } - if ((!$MessageName -or ($entry.Message.Name -eq "textDocument/$MessageName")) -and + if ((!$MessageName -or ($entry.Message.Name -eq $MessageName)) -and (!$Pattern -or ($entry.Message.Name -match $Pattern))) { $key = "$($entry.Message.Name)-$($entry.Message.Id)" From eacc919fa6c223de598542151fc92734202d3c29 Mon Sep 17 00:00:00 2001 From: Keith Hill Date: Sat, 23 Mar 2019 16:47:21 -0600 Subject: [PATCH 3/3] Tweak help text --- tools/PsesLogAnalyzer/Analyze.ps1 | 6 +++--- 1 file changed, 3 insertions(+), 3 deletions(-) diff --git a/tools/PsesLogAnalyzer/Analyze.ps1 b/tools/PsesLogAnalyzer/Analyze.ps1 index 5f24209f6..bb0eb8682 100644 --- a/tools/PsesLogAnalyzer/Analyze.ps1 +++ b/tools/PsesLogAnalyzer/Analyze.ps1 @@ -1,13 +1,13 @@ <# .SYNOPSIS - Gets LSP notification messages sent from either PSES to the client or vice-versa. + Gets LSP notification messages sent from either server to the client or vice-versa. .DESCRIPTION - Gets LSP notification messages sent from either PSES to the client or vice-versa. + Gets LSP notification messages sent from either server to the client or vice-versa. .EXAMPLE C:\> Get-PsesRpcNotificationMessage $log Gets all LSP notification messages in the specified log. .EXAMPLE - C:\> Get-PsesRpcNotificationMessage $log -MessageName $/cancelRequest + C:\> Get-PsesRpcNotificationMessage $log -MessageName '$/cancelRequest' Gets all LSP $/cancelRequest notification messages in the specified log. .EXAMPLE C:\> Get-PsesRpcNotificationMessage $log -Pattern powershell/.*