PSES frequently gets stuck in a loop and never recovers

[mattpwhite]

System Details

Win10 1703

code -v

1.23.0
7c7da59c2333a1306c41e6e7b68d7f0caa7b3d45
x64

$pseditor.EditorServicesVersion

Major  Minor  Build  Revision
-----  -----  -----  --------
1      7      0      0

code --list-extensions --show-versions

DotJoshJohnson.xml@2.2.0
k--kato.docomment@0.1.0
kalitaalexey.vscode-rust@0.4.2
luggage66.VBScript@0.0.2
mohsen1.prettify-json@0.0.3
ms-python.python@2018.4.0
ms-vscode.cpptools@0.17.3
ms-vscode.csharp@1.15.2
ms-vscode.PowerShell@1.7.0
robertohuertasm.vscode-icons@7.23.0
Shan.code-settings-sync@2.9.2

$psversiontable

Name                           Value
----                           -----
PSVersion                      5.1.15063.1088
PSEdition                      Desktop
PSCompatibleVersions           {1.0, 2.0, 3.0, 4.0...}
BuildVersion                   10.0.15063.1088
CLRVersion                     4.0.30319.42000
WSManStackVersion              3.0
PSRemotingProtocolVersion      2.3
SerializationVersion           1.1.0.1

With great frequency, communication between the VS Code extension and PSES seems to get "stuck". Basically all extension functionality (formatting, IntelliSense, F12) ceases to work and I get the same series of log messages repeated every ~10 seconds. The log messages repeat even when no changes are being made. All I can do is restart the session and hope for the best. Restarting is hit or miss in terms of recovering.

I wish I was able to repro this reliably, but I can't. It more likely to happen with large files (several thousand lines of code or more). It also seems more likely to occur with large workspaces (hundreds of files, hundreds of thousands of lines of mixed PS and C# across ~100 modules). I get that these numbers may be on the high side, but I know that it can work. After a fairly lengthy initialization period it often works/performs reasonably for some period of time, and then breaks.

Here's a sample of what I get repeating in the logs:

2018-05-30 21:31:18 [VERBOSE] - Method "WriteMessage" at line 61 of C:\projects\powershelleditorservices\src\PowerShellEditorServices.Protocol\MessageProtocol\MessageWriter.cs

    Writing Response 'codeLens/resolve' with id 179

2018-05-30 21:31:18 [VERBOSE] - Method "WriteMessage" at line 61 of C:\projects\powershelleditorservices\src\PowerShellEditorServices.Protocol\MessageProtocol\MessageWriter.cs

    Writing Event 'textDocument/publishDiagnostics'

2018-05-30 21:31:18 [VERBOSE] - Method "ReadMessage" at line 123 of C:\projects\powershelleditorservices\src\PowerShellEditorServices.Protocol\MessageProtocol\MessageReader.cs

    Received Event 'textDocument/didChange'

2018-05-30 21:31:18 [VERBOSE] - Method "ResolveFilePath" at line 378 of C:\projects\powershelleditorservices\src\PowerShellEditorServices\Workspace\Workspace.cs

    Resolved path: c:\local\git\powershell\modules\Vdi3\Vdi3.psm1

2018-05-30 21:31:18 [VERBOSE] - Method "ReadMessage" at line 123 of C:\projects\powershelleditorservices\src\PowerShellEditorServices.Protocol\MessageProtocol\MessageReader.cs

    Received Event '$/cancelRequest'

2018-05-30 21:31:18 [ERROR] - Method "DispatchMessage" at line 147 of C:\projects\powershelleditorservices\src\PowerShellEditorServices.Protocol\MessageProtocol\MessageDispatcher.cs

    MessageDispatcher: No handler registered for Event type '$/cancelRequest'

2018-05-30 21:31:18 [VERBOSE] - Method "ReadMessage" at line 123 of C:\projects\powershelleditorservices\src\PowerShellEditorServices.Protocol\MessageProtocol\MessageReader.cs

    Received Request 'textDocument/codeLens' with id 180

2018-05-30 21:31:18 [VERBOSE] - Method "ResolveFilePath" at line 378 of C:\projects\powershelleditorservices\src\PowerShellEditorServices\Workspace\Workspace.cs

    Resolved path: c:\local\git\powershell\modules\Vdi3\Vdi3.psm1

2018-05-30 21:31:18 [VERBOSE] - Method "InvokeProviders" at line 71 of C:\projects\powershelleditorservices\src\PowerShellEditorServices\Components\FeatureComponentBase.cs

    Invocation of provider 'Microsoft.PowerShell.EditorServices.CodeLenses.ReferencesCodeLensPr
ovider' completed in 0ms.

2018-05-30 21:31:18 [VERBOSE] - Method "InvokeProviders" at line 71 of C:\projects\powershelleditorservices\src\PowerShellEditorServices\Components\FeatureComponentBase.cs

    Invocation of provider 'Microsoft.PowerShell.EditorServices.CodeLenses.PesterCodeLensProvid
er' completed in 0ms.

2018-05-30 21:31:18 [VERBOSE] - Method "WriteMessage" at line 61 of C:\projects\powershelleditorservices\src\PowerShellEditorServices.Protocol\MessageProtocol\MessageWriter.cs

    Writing Response 'textDocument/codeLens' with id 180

2018-05-30 21:31:18 [VERBOSE] - Method "ReadMessage" at line 123 of C:\projects\powershelleditorservices\src\PowerShellEditorServices.Protocol\MessageProtocol\MessageReader.cs

    Received Event '$/cancelRequest'

2018-05-30 21:31:18 [ERROR] - Method "DispatchMessage" at line 147 of C:\projects\powershelleditorservices\src\PowerShellEditorServices.Protocol\MessageProtocol\MessageDispatcher.cs

    MessageDispatcher: No handler registered for Event type '$/cancelRequest'

2018-05-30 21:31:18 [VERBOSE] - Method "ReadMessage" at line 123 of C:\projects\powershelleditorservices\src\PowerShellEditorServices.Protocol\MessageProtocol\MessageReader.cs

    Received Request 'textDocument/codeLens' with id 181

2018-05-30 21:31:18 [VERBOSE] - Method "ResolveFilePath" at line 378 of C:\projects\powershelleditorservices\src\PowerShellEditorServices\Workspace\Workspace.cs

    Resolved path: c:\local\git\powershell\modules\Vdi3\Vdi3.psm1

2018-05-30 21:31:18 [VERBOSE] - Method "InvokeProviders" at line 71 of C:\projects\powershelleditorservices\src\PowerShellEditorServices\Components\FeatureComponentBase.cs

    Invocation of provider 'Microsoft.PowerShell.EditorServices.CodeLenses.ReferencesCodeLensPr
ovider' completed in 0ms.

2018-05-30 21:31:18 [VERBOSE] - Method "InvokeProviders" at line 71 of C:\projects\powershelleditorservices\src\PowerShellEditorServices\Components\FeatureComponentBase.cs

    Invocation of provider 'Microsoft.PowerShell.EditorServices.CodeLenses.PesterCodeLensProvid
er' completed in 0ms.

2018-05-30 21:31:18 [VERBOSE] - Method "WriteMessage" at line 61 of C:\projects\powershelleditorservices\src\PowerShellEditorServices.Protocol\MessageProtocol\MessageWriter.cs

    Writing Response 'textDocument/codeLens' with id 181

2018-05-30 21:31:18 [VERBOSE] - Method "ReadMessage" at line 123 of C:\projects\powershelleditorservices\src\PowerShellEditorServices.Protocol\MessageProtocol\MessageReader.cs

    Received Request 'textDocument/codeAction' with id 182

2018-05-30 21:31:18 [VERBOSE] - Method "WriteMessage" at line 61 of C:\projects\powershelleditorservices\src\PowerShellEditorServices.Protocol\MessageProtocol\MessageWriter.cs

    Writing Response 'textDocument/codeAction' with id 182

2018-05-30 21:31:18 [VERBOSE] - Method "ReadMessage" at line 123 of C:\projects\powershelleditorservices\src\PowerShellEditorServices.Protocol\MessageProtocol\MessageReader.cs

    Received Event 'textDocument/didChange'

2018-05-30 21:31:18 [VERBOSE] - Method "ResolveFilePath" at line 378 of C:\projects\powershelleditorservices\src\PowerShellEditorServices\Workspace\Workspace.cs

    Resolved path: c:\local\git\powershell\modules\Vdi3\Vdi3.psm1

2018-05-30 21:31:18 [VERBOSE] - Method "ReadMessage" at line 123 of C:\projects\powershelleditorservices\src\PowerShellEditorServices.Protocol\MessageProtocol\MessageReader.cs

    Received Event 'textDocument/didChange'

2018-05-30 21:31:18 [VERBOSE] - Method "ResolveFilePath" at line 378 of C:\projects\powershelleditorservices\src\PowerShellEditorServices\Workspace\Workspace.cs

    Resolved path: c:\local\git\powershell\modules\Vdi3\Vdi3.psm1

2018-05-30 21:31:18 [VERBOSE] - Method "ReadMessage" at line 123 of C:\projects\powershelleditorservices\src\PowerShellEditorServices.Protocol\MessageProtocol\MessageReader.cs

    Received Event 'textDocument/didChange'

2018-05-30 21:31:18 [VERBOSE] - Method "ResolveFilePath" at line 378 of C:\projects\powershelleditorservices\src\PowerShellEditorServices\Workspace\Workspace.cs

    Resolved path: c:\local\git\powershell\modules\Vdi3\Vdi3.psm1

2018-05-30 21:31:18 [VERBOSE] - Method "ReadMessage" at line 123 of C:\projects\powershelleditorservices\src\PowerShellEditorServices.Protocol\MessageProtocol\MessageReader.cs

    Received Event 'textDocument/didChange'

2018-05-30 21:31:18 [VERBOSE] - Method "ResolveFilePath" at line 378 of C:\projects\powershelleditorservices\src\PowerShellEditorServices\Workspace\Workspace.cs

    Resolved path: c:\local\git\powershell\modules\Vdi3\Vdi3.psm1

2018-05-30 21:31:18 [VERBOSE] - Method "ReadMessage" at line 123 of C:\projects\powershelleditorservices\src\PowerShellEditorServices.Protocol\MessageProtocol\MessageReader.cs

    Received Event '$/cancelRequest'

2018-05-30 21:31:18 [ERROR] - Method "DispatchMessage" at line 147 of C:\projects\powershelleditorservices\src\PowerShellEditorServices.Protocol\MessageProtocol\MessageDispatcher.cs

    MessageDispatcher: No handler registered for Event type '$/cancelRequest'

2018-05-30 21:31:18 [VERBOSE] - Method "ReadMessage" at line 123 of C:\projects\powershelleditorservices\src\PowerShellEditorServices.Protocol\MessageProtocol\MessageReader.cs

    Received Request 'textDocument/codeLens' with id 183

2018-05-30 21:31:18 [VERBOSE] - Method "ResolveFilePath" at line 378 of C:\projects\powershelleditorservices\src\PowerShellEditorServices\Workspace\Workspace.cs

    Resolved path: c:\local\git\powershell\modules\Vdi3\Vdi3.psm1

2018-05-30 21:31:18 [VERBOSE] - Method "InvokeProviders" at line 71 of C:\projects\powershelleditorservices\src\PowerShellEditorServices\Components\FeatureComponentBase.cs

    Invocation of provider 'Microsoft.PowerShell.EditorServices.CodeLenses.ReferencesCodeLensPr
ovider' completed in 0ms.

2018-05-30 21:31:18 [VERBOSE] - Method "InvokeProviders" at line 71 of C:\projects\powershelleditorservices\src\PowerShellEditorServices\Components\FeatureComponentBase.cs

    Invocation of provider 'Microsoft.PowerShell.EditorServices.CodeLenses.PesterCodeLensProvid
er' completed in 0ms.

2018-05-30 21:31:18 [VERBOSE] - Method "WriteMessage" at line 61 of C:\projects\powershelleditorservices\src\PowerShellEditorServices.Protocol\MessageProtocol\MessageWriter.cs

    Writing Response 'textDocument/codeLens' with id 183

2018-05-30 21:31:18 [VERBOSE] - Method "ReadMessage" at line 123 of C:\projects\powershelleditorservices\src\PowerShellEditorServices.Protocol\MessageProtocol\MessageReader.cs

    Received Event '$/cancelRequest'

2018-05-30 21:31:18 [ERROR] - Method "DispatchMessage" at line 147 of C:\projects\powershelleditorservices\src\PowerShellEditorServices.Protocol\MessageProtocol\MessageDispatcher.cs

    MessageDispatcher: No handler registered for Event type '$/cancelRequest'

2018-05-30 21:31:18 [VERBOSE] - Method "ReadMessage" at line 123 of C:\projects\powershelleditorservices\src\PowerShellEditorServices.Protocol\MessageProtocol\MessageReader.cs

    Received Request 'textDocument/codeLens' with id 184

2018-05-30 21:31:18 [VERBOSE] - Method "ResolveFilePath" at line 378 of C:\projects\powershelleditorservices\src\PowerShellEditorServices\Workspace\Workspace.cs

    Resolved path: c:\local\git\powershell\modules\Vdi3\Vdi3.psm1

2018-05-30 21:31:18 [VERBOSE] - Method "InvokeProviders" at line 71 of C:\projects\powershelleditorservices\src\PowerShellEditorServices\Components\FeatureComponentBase.cs

    Invocation of provider 'Microsoft.PowerShell.EditorServices.CodeLenses.ReferencesCodeLensPr
ovider' completed in 0ms.

2018-05-30 21:31:18 [VERBOSE] - Method "InvokeProviders" at line 71 of C:\projects\powershelleditorservices\src\PowerShellEditorServices\Components\FeatureComponentBase.cs

    Invocation of provider 'Microsoft.PowerShell.EditorServices.CodeLenses.PesterCodeLensProvid
er' completed in 0ms.

2018-05-30 21:31:18 [VERBOSE] - Method "WriteMessage" at line 61 of C:\projects\powershelleditorservices\src\PowerShellEditorServices.Protocol\MessageProtocol\MessageWriter.cs

    Writing Response 'textDocument/codeLens' with id 184

2018-05-30 21:31:18 [VERBOSE] - Method "ReadMessage" at line 123 of C:\projects\powershelleditorservices\src\PowerShellEditorServices.Protocol\MessageProtocol\MessageReader.cs

    Received Request 'textDocument/codeAction' with id 185

2018-05-30 21:31:18 [VERBOSE] - Method "WriteMessage" at line 61 of C:\projects\powershelleditorservices\src\PowerShellEditorServices.Protocol\MessageProtocol\MessageWriter.cs

    Writing Response 'textDocument/codeAction' with id 185

2018-05-30 21:31:18 [VERBOSE] - Method "ReadMessage" at line 123 of C:\projects\powershelleditorservices\src\PowerShellEditorServices.Protocol\MessageProtocol\MessageReader.cs

    Received Event 'textDocument/didChange'

2018-05-30 21:31:18 [VERBOSE] - Method "ResolveFilePath" at line 378 of C:\projects\powershelleditorservices\src\PowerShellEditorServices\Workspace\Workspace.cs

    Resolved path: c:\local\git\powershell\modules\Vdi3\Vdi3.psm1

2018-05-30 21:31:18 [VERBOSE] - Method "ReadMessage" at line 123 of C:\projects\powershelleditorservices\src\PowerShellEditorServices.Protocol\MessageProtocol\MessageReader.cs

    Received Event '$/cancelRequest'

2018-05-30 21:31:18 [ERROR] - Method "DispatchMessage" at line 147 of C:\projects\powershelleditorservices\src\PowerShellEditorServices.Protocol\MessageProtocol\MessageDispatcher.cs

    MessageDispatcher: No handler registered for Event type '$/cancelRequest'

2018-05-30 21:31:18 [VERBOSE] - Method "ReadMessage" at line 123 of C:\projects\powershelleditorservices\src\PowerShellEditorServices.Protocol\MessageProtocol\MessageReader.cs

    Received Request 'textDocument/codeLens' with id 186

2018-05-30 21:31:18 [VERBOSE] - Method "ResolveFilePath" at line 378 of C:\projects\powershelleditorservices\src\PowerShellEditorServices\Workspace\Workspace.cs

    Resolved path: c:\local\git\powershell\modules\Vdi3\Vdi3.psm1

2018-05-30 21:31:18 [VERBOSE] - Method "InvokeProviders" at line 71 of C:\projects\powershelleditorservices\src\PowerShellEditorServices\Components\FeatureComponentBase.cs

    Invocation of provider 'Microsoft.PowerShell.EditorServices.CodeLenses.ReferencesCodeLensPr
ovider' completed in 0ms.

2018-05-30 21:31:18 [VERBOSE] - Method "InvokeProviders" at line 71 of C:\projects\powershelleditorservices\src\PowerShellEditorServices\Components\FeatureComponentBase.cs

    Invocation of provider 'Microsoft.PowerShell.EditorServices.CodeLenses.PesterCodeLensProvid
er' completed in 0ms.

2018-05-30 21:31:18 [VERBOSE] - Method "WriteMessage" at line 61 of C:\projects\powershelleditorservices\src\PowerShellEditorServices.Protocol\MessageProtocol\MessageWriter.cs

    Writing Response 'textDocument/codeLens' with id 186

2018-05-30 21:31:18 [VERBOSE] - Method "ReadMessage" at line 123 of C:\projects\powershelleditorservices\src\PowerShellEditorServices.Protocol\MessageProtocol\MessageReader.cs

    Received Event '$/cancelRequest'

2018-05-30 21:31:18 [ERROR] - Method "DispatchMessage" at line 147 of C:\projects\powershelleditorservices\src\PowerShellEditorServices.Protocol\MessageProtocol\MessageDispatcher.cs

    MessageDispatcher: No handler registered for Event type '$/cancelRequest'

2018-05-30 21:31:18 [VERBOSE] - Method "ReadMessage" at line 123 of C:\projects\powershelleditorservices\src\PowerShellEditorServices.Protocol\MessageProtocol\MessageReader.cs

    Received Request 'textDocument/codeLens' with id 187

2018-05-30 21:31:18 [VERBOSE] - Method "ResolveFilePath" at line 378 of C:\projects\powershelleditorservices\src\PowerShellEditorServices\Workspace\Workspace.cs

    Resolved path: c:\local\git\powershell\modules\Vdi3\Vdi3.psm1

2018-05-30 21:31:18 [VERBOSE] - Method "InvokeProviders" at line 71 of C:\projects\powershelleditorservices\src\PowerShellEditorServices\Components\FeatureComponentBase.cs

    Invocation of provider 'Microsoft.PowerShell.EditorServices.CodeLenses.ReferencesCodeLensPr
ovider' completed in 0ms.

2018-05-30 21:31:18 [VERBOSE] - Method "InvokeProviders" at line 71 of C:\projects\powershelleditorservices\src\PowerShellEditorServices\Components\FeatureComponentBase.cs

    Invocation of provider 'Microsoft.PowerShell.EditorServices.CodeLenses.PesterCodeLensProvid
er' completed in 0ms.

2018-05-30 21:31:18 [VERBOSE] - Method "WriteMessage" at line 61 of C:\projects\powershelleditorservices\src\PowerShellEditorServices.Protocol\MessageProtocol\MessageWriter.cs

    Writing Response 'textDocument/codeLens' with id 187

2018-05-30 21:31:18 [VERBOSE] - Method "ReadMessage" at line 123 of C:\projects\powershelleditorservices\src\PowerShellEditorServices.Protocol\MessageProtocol\MessageReader.cs

    Received Request 'textDocument/codeAction' with id 188

2018-05-30 21:31:18 [VERBOSE] - Method "WriteMessage" at line 61 of C:\projects\powershelleditorservices\src\PowerShellEditorServices.Protocol\MessageProtocol\MessageWriter.cs

    Writing Response 'textDocument/codeAction' with id 188

2018-05-30 21:31:18 [VERBOSE] - Method "ReadMessage" at line 123 of C:\projects\powershelleditorservices\src\PowerShellEditorServices.Protocol\MessageProtocol\MessageReader.cs

    Received Event '$/cancelRequest'

2018-05-30 21:31:18 [ERROR] - Method "DispatchMessage" at line 147 of C:\projects\powershelleditorservices\src\PowerShellEditorServices.Protocol\MessageProtocol\MessageDispatcher.cs

    MessageDispatcher: No handler registered for Event type '$/cancelRequest'

2018-05-30 21:31:18 [VERBOSE] - Method "ReadMessage" at line 123 of C:\projects\powershelleditorservices\src\PowerShellEditorServices.Protocol\MessageProtocol\MessageReader.cs

    Received Request 'codeLens/resolve' with id 189

2018-05-30 21:31:18 [VERBOSE] - Method "ResolveFilePath" at line 378 of C:\projects\powershelleditorservices\src\PowerShellEditorServices\Workspace\Workspace.cs

    Resolved path: c:\local\git\powershell\modules\Vdi3\Vdi3.psm1

2018-05-30 21:31:18 [VERBOSE] - Method "WriteMessage" at line 61 of C:\projects\powershelleditorservices\src\PowerShellEditorServices.Protocol\MessageProtocol\MessageWriter.cs

    Writing Response 'codeLens/resolve' with id 189

2018-05-30 21:31:18 [VERBOSE] - Method "ReadMessage" at line 123 of C:\projects\powershelleditorservices\src\PowerShellEditorServices.Protocol\MessageProtocol\MessageReader.cs

    Received Event '$/cancelRequest'

2018-05-30 21:31:18 [ERROR] - Method "DispatchMessage" at line 147 of C:\projects\powershelleditorservices\src\PowerShellEditorServices.Protocol\MessageProtocol\MessageDispatcher.cs

    MessageDispatcher: No handler registered for Event type '$/cancelRequest'

2018-05-30 21:31:18 [VERBOSE] - Method "ReadMessage" at line 123 of C:\projects\powershelleditorservices\src\PowerShellEditorServices.Protocol\MessageProtocol\MessageReader.cs

    Received Request 'codeLens/resolve' with id 190

2018-05-30 21:31:18 [VERBOSE] - Method "ResolveFilePath" at line 378 of C:\projects\powershelleditorservices\src\PowerShellEditorServices\Workspace\Workspace.cs

    Resolved path: c:\local\git\powershell\modules\Vdi3\Vdi3.psm1

2018-05-30 21:31:19 [VERBOSE] - Method "DelayThenInvokeDiagnostics" at line 1499 of C:\projects\powershelleditorservices\src\PowerShellEditorServices.Protocol\Server\LanguageServer.cs

    Analyzing script file: c:\local\git\powershell\modules\Vdi3\Vdi3.psm1

2018-05-30 21:31:20 [VERBOSE] - Method "GetDiagnosticRecordsAsync" at line 417 of C:\projects\powershelleditorservices\src\PowerShellEditorServices\Analysis\AnalysisService.cs

    Found 3 violations

2018-05-30 21:31:20 [VERBOSE] - Method "DelayThenInvokeDiagnostics" at line 1503 of C:\projects\powershelleditorservices\src\PowerShellEditorServices.Protocol\Server\LanguageServer.cs

    Analysis complete.

[rjmholt]

Aha! Thanks so much for this report. There's a general awareness of this and we've been looking at improving the performance of PSES, but I think the logs you've attached here could be really helpful. /cc @tylerl0706

[Falconne]

I started getting this problem after the most recent VS Code update. It occurs when trying to auto format the document or use code completion. The status bar will show the message "Formatting PowerShell document" for over a minute, without any formatting or code completion happening. This is what I have:

--[ code -v
1.25.1
1dfc5e557209371715f655691b1235b6b26a06be
x64

--[ code --list-extensions --show-versions | fgrep PowerShell
ms-vscode.PowerShell@1.8.1

Here is a relevant snippet from the log when this happens:

2018-07-18 12:13:53.725 [ERROR] C:\PowerShellEditorServices\src\PowerShellEditorServices\Session\PowerShellContext.cs: In method 'ExecuteCommand', line 564:
    Execution of the following command(s) completed with errors:

        Microsoft.PowerShell.Core\Get-Command isOurCompanyName -ErrorAction Ignore



2018-07-18 12:13:53.726 [ERROR] C:\PowerShellEditorServices\src\PowerShellEditorServices.Protocol\MessageProtocol\MessageDispatcher.cs: In method 'DispatchMessage', line 147:
    MessageDispatcher: No handler registered for Event type '$/cancelRequest'

2018-07-18 12:14:39.618 [ERROR] C:\PowerShellEditorServices\src\PowerShellEditorServices.Protocol\MessageProtocol\MessageDispatcher.cs: In method 'DispatchMessage', line 147:
    MessageDispatcher: No handler registered for Event type '$/cancelRequest'

2018-07-18 12:14:39.621 [ERROR] C:\PowerShellEditorServices\src\PowerShellEditorServices.Protocol\MessageProtocol\MessageDispatcher.cs: In method 'DispatchMessage', line 147:
    MessageDispatcher: No handler registered for Event type '$/cancelRequest'

2018-07-18 13:51:12.153 [ERROR] C:\PowerShellEditorServices\src\PowerShellEditorServices.Protocol\MessageProtocol\MessageDispatcher.cs: In method 'DispatchMessage', line 147:
    MessageDispatcher: No handler registered for Event type '$/cancelRequest'

2018-07-18 13:51:24.919 [ERROR] C:\PowerShellEditorServices\src\PowerShellEditorServices.Protocol\MessageProtocol\MessageDispatcher.cs: In method 'DispatchMessage', line 147:
    MessageDispatcher: No handler registered for Event type '$/cancelRequest'

2018-07-18 13:52:09.518 [ERROR] C:\PowerShellEditorServices\src\PowerShellEditorServices\Session\PowerShellContext.cs: In method 'ExecuteCommand', line 564:
    Execution of the following command(s) completed with errors:

        Microsoft.PowerShell.Core\Get-Command isEnvVarTrue -ErrorAction Ignore



2018-07-18 13:52:09.519 [ERROR] C:\PowerShellEditorServices\src\PowerShellEditorServices.Protocol\MessageProtocol\MessageDispatcher.cs: In method 'DispatchMessage', line 147:
    MessageDispatcher: No handler registered for Event type '$/cancelRequest'

2018-07-18 13:52:10.234 [ERROR] C:\PowerShellEditorServices\src\PowerShellEditorServices\Session\PowerShellContext.cs: In method 'ExecuteCommand', line 564:
    Execution of the following command(s) completed with errors:

        Microsoft.PowerShell.Core\Get-Command isEnvVarTrue -ErrorAction Ignore



2018-07-18 13:52:11.401 [ERROR] C:\PowerShellEditorServices\src\PowerShellEditorServices\Session\PowerShellContext.cs: In method 'ExecuteCommand', line 564:
    Execution of the following command(s) completed with errors:

        Microsoft.PowerShell.Core\Get-Command isOurCompanyName -ErrorAction Ignore



2018-07-18 13:52:11.770 [ERROR] C:\PowerShellEditorServices\src\PowerShellEditorServices\Session\PowerShellContext.cs: In method 'ExecuteCommand', line 564:
    Execution of the following command(s) completed with errors:

        Microsoft.PowerShell.Core\Get-Command isOurCompanyName -ErrorAction Ignore



2018-07-18 13:52:26.498 [ERROR] C:\PowerShellEditorServices\src\PowerShellEditorServices\Session\PowerShellContext.cs: In method 'ExecuteCommand', line 564:
    Execution of the following command(s) completed with errors:

        Microsoft.PowerShell.Core\Get-Command isEnvVarTrue -ErrorAction Ignore



2018-07-18 13:52:26.499 [ERROR] C:\PowerShellEditorServices\src\PowerShellEditorServices.Protocol\MessageProtocol\MessageDispatcher.cs: In method 'DispatchMessage', line 147:
    MessageDispatcher: No handler registered for Event type '$/cancelRequest'

2018-07-18 13:52:26.878 [ERROR] C:\PowerShellEditorServices\src\PowerShellEditorServices\Session\PowerShellContext.cs: In method 'ExecuteCommand', line 564:
    Execution of the following command(s) completed with errors:

        Microsoft.PowerShell.Core\Get-Command isEnvVarTrue -ErrorAction Ignore

isOurCompanyName and isEnvVarTrue are functions in the script I was editing at the time; other scripts show different functions in the log when this occurs. As described in the original post, everything's usually working after a fresh start, but after a couple of attempts to auto-format, or a few minutes of normal usage, the problem manifests.

[Falconne]

Never mind, after turning on verbose logging I can see the problem is the new PS script analyser that has recently been updated in the PSES version that comes with this extension causing the delay. The scripts I was looking at are large, ~2000 lines and it seems the script analysis is taking around 45 seconds to do its thing. It runs on every formatting or code completion request, causing the hangs.

I see a lot of changes have happened to the code analysis in the recent release of PSES. I don't need script analysis so I've disabled it and now I'm back to previous performance levels.

[rjmholt]

@Falconne we believe we've addressed the top issue, but without a known cause it's hard to be sure.

Making script analysis less impactful on the rest of the experience is something that we've been working away at in the background, but requires some architectural work.

[Falconne]

@rjmholt I'll try script analysis again periodically to see how it goes. It would help if that ran in a background thread instead of blocking document formatting and code completion... which don't seem to need it anyway?

[rjmholt]

Yes, script analysis already runs asynchronously as a task. (Threading not being chosen because it didn't originally exist cross-platform).

The problem seems to be more that message handling itself is not as asynchronous as it could be, meaning messages still block and cannot be interrupted. But fixing that properly is a large architectural change, which we need to be careful with since PowerShell itself doesn't really handle threading so well.

[mattpwhite]

At least for me, the problem does not appear to be related to script analysis. Disabling it in the VS Code options does not have a meaningful impact, and I haven't observed any changes in newer versions of the extension since I filed this issue.

Since the PSES process is generally pegged when this issue is occurring, I thought attaching a profiler might suggest something. A cursory look suggests almost all the time is being spent (re-)parsing PowerShell files (on disk) to service CodeLens requests. See below (the collapsed threads are Serilog waiting for stuff to log and ReadKey waiting for keystrokes):

So, I tried turning off CodeLens in VS Code. This is unfortunate because I find it super useful, but it does seem to have had the desired effect. IntelliSense keeps working and I don't have a powershell process burning a core at all times.

This is very speculative, but I'm guessing that because I'm typically working with large files (4 digit loc) and workspaces (6 digit loc) re-parsing things is very expensive and it's easy to build up a backlog where everything seems to stop working. That would naturally lead to a question of whether the any of these parsing results could be cached in a way that would allow PSES to "keep up". Or maybe I have no idea what I'm talking about, I'm not very familiar with the extension or PSES code bases.

[mattpwhite]

I probably spoke too soon. Disabling CodeLens definitely helped, but the extension still has a lot of trouble keeping up. It seems like operations often have trouble finishing within what appears to be a timeout from VS Code for things like IntelliSense completion. Will try to dig further if that's helpful...

[rjmholt]

@mattpwhite thanks for that really great analysis! Definitely agreed we need to cache codelens as much as possible (see PowerShell/PowerShellEditorServices#678).

VSCode controls sending CodeLens messages, so we have no choice but to improve the way we deal with them. I think step 1 is to improve caching, and step 2 will probably be a way of cancelling/rejecting code lens messages.

If you find any other useful information, please keep us updated!

[mattpwhite]

If I saw some low hanging fruit (and I do), would it be OK to send over a PR or two to improve perf?

[TylerLeonhardt]

@mattpwhite absolutely! PRs always welcome 😊

Sorry we haven't been looking into this at the moment. We've been pulled to work on porting Windows PowerShell modules and in my free time, I'm working to get PSReadLine into the extension (with @SeeminglyScience).

After PSReadLine is in, perf is my number one goal.

I appreciate any extra hands 😊

[rjmholt]

+1 on what @tylerl0706 said