Enhance Get-PsesRpcNotificationMessage/MessageResponseTimes to allow filtering by message name (#889)

* Enhance Get-PsesRpcMessageResponseTime to select specific message types

* Enhance Get-PsesRpcNotificationMessage to filter by message type

* Tweak help text

Author: rkeithhill

.vscode/launch.json

@@ -12,6 +12,12 @@
             "type": "coreclr",
             "request": "attach",
             "processId": "${command:pickProcess}"
+        },
+        {
+            "type": "PowerShell",
+            "request": "launch",
+            "name": "PowerShell Interactive Session",
+            "cwd": ""
         }
     ]
-}
+}

tools/PsesLogAnalyzer/Analyze.ps1

@@ -1,3 +1,22 @@
+<#
+.SYNOPSIS
+    Gets LSP notification messages sent from either server to the client or vice-versa.
+.DESCRIPTION
+    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'
+    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,15 +73,38 @@ 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
             }
         }
     }
 }
 
+<#
+.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 textDocument/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 +119,26 @@ 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(
+            "textDocument/codeAction",
+            "textDocument/codeLens",
+            "textDocument/documentSymbol",
+            "textDocument/foldingRange",
+            "textDocument/formatting",
+            "textDocument/hover",
+            "textDocument/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 +156,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 $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)
+                }
+            }
+        }
     }
 }