Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

The VS Code extension often disconnects and can not reconnect without the entire extension host being restarted #112

Open
TMA-2 opened this issue Jan 21, 2025 · 0 comments

Comments

@TMA-2
Copy link

TMA-2 commented Jan 21, 2025

Describe the bug

This is a longer and more complicated one, so apologies for the length. As far as I understand it, if a long-running process using PSES (or something else?) causes an invoked method to fail more than 10 times, it tries over and over to re-connect using the same pipe name, but is never successful in my experience. This then requires a full restart of the VSCode extension host, taking up to a minute for the PowerShell extension terminal, PSES, and PowerShell Pro Tools to all restart. Clicking "Retry" on the "PowerShell Pro Tools session failed to start" error does not work, even when restarting the PowerShell extension first.

The code path appears to be:

Expected Behavior

The extension does not lose its connection, ideally. But, if it does, it successfully re-connects to the existing pipe name, or on that failing, prompts the user to restart the extension (similar to the existing error message with "Retry"), re-connects with a new pipe name (my understanding of pipes is nonexistant, so which of these is even possible I don't know!).

Also, the action initiated by the Retry button on the "PowerShell Pro Tools session failed to start" message might discard the existing pipe name and generate a new one, then restart the PoshTools server with it, and re-connect. Perhaps similarly to the "Restart current session" command for the official PowerShell extension. I think it already does, but just in case, it would check that PSES is running and contactable.

Actual Behavior

After sending the startup Import-Module and Start-PoshToolsServer commands 10 times, it fails, continuing to report "Error: connect ENOENT \.\pipe\xxx" messages for invoked methods in the output log. It seems to usually start with invoking GetPerformance since that's constantly running in the background every 5 seconds (see related issue #111)...

[11:0:13.204] Invoke method: GetPerformance Error sending data on named pipe. Error: connect ENOENT \\.\pipe\hupkvxbpdykt
[11:0:16.44] PowerShell Extension has restarted. Connecting.
[11:0:16.48] Importing module in PowerShell and starting server.
[11:0:17.69] Connecting named pipe to PoshTools server.
(Repeat)

Then, it reports "Reconnect depth exceeded" and fails... but still tries to invoke methods on the pipe, mostly GetPerformance when left alone every 5 seconds, otherwise user-triggered methods like GetHover, GetHistory, etc. continually throw the same error.

[11:0:48.186] Invoke method: GetPerformance Error sending data on named pipe. Error: connect ETIMEDOUT \\.\pipe\hupkvxbpdykt
[11:0:49.994] Reconnect depth exceeded. Connection failed.
(Repeat ad infinitum every 5 seconds until restarting the extension host)

Test

As one test (enabling the Modules view), due to the Get-Module -ListAvailable command seemingly taking more than 30 seconds to complete (I ran it separately and it returned after 25 seconds with >100 entries), this caused the expected timeout and attempted but failed disconnection, again seemingly due to GetPerformance being invoked every 5 seconds. I could be mistaken since my TS/JS understanding is nonexistant, but I would think a rough timeout of 50 seconds would be the case, as Reconnect() fails and returns when reconnectDepth > 10... i.e. 5 x 10? Either way, the PowerShell extension was still responsive, and had no logged errors, but as expected, there was an Invoke Method: GetPerformance Error reported first:

[14:48:2.465] Executing command: Get-Module -ListAvailable
[14:48:35.729] Invoke method: GetPerformance Error sending data on named pipe. Error: connect ETIMEDOUT \\.\pipe\cmgzqwijvncj

As another test, I left VS Code sitting with a PowerShell file open in the background, and when I returned to it 50 minutes later, it had once again disconnected. Looking at the log, it had taken roughly 9 minutes before the regular GetPerformance invocations started throwing named pipe errors:

[12:10:11.178] Starting PowerShell Pro Tools...
[12:10:45.604] Finishing extension activation.
[12:10:45.605] Connecting to PowerShell Editor Services.
[12:10:45.606] Importing module in PowerShell and starting server.
[12:10:46.606] Connecting named pipe to PoshTools server.
[12:10:46.612] Invoke method: Connect Error sending data on named pipe. Error: connect ENOENT \\.\pipe\gfsgvpbzmttm
[12:10:52.640] PowerShell Extension has restarted. Connecting.
[12:10:52.641] Importing module in PowerShell and starting server.
[12:10:53.648] Connecting named pipe to PoshTools server.
[12:10:53.676] Opening a runspace.
[12:10:53.802] Loading PowerShell Pro Tools module
[12:10:53.803] Executing command: Import-Module 'C:\Users\tma2\.vscode\extensions\ironmansoftware.powershellprotools-2024.12.0\Modules\PowerShellProTools.VSCode\PowerShellProTools.VSCode.psd1'
[12:10:53.908] Executing command: $Env:PSModulePath += ';C:\Users\tma2\.vscode\extensions\ironmansoftware.powershellprotools-2024.12.0\Modules\PowerShellProTools.VSCode\..'
[12:10:54.327] Executing command: [PowerShellProTools.IntelliSenseManager]::Isv3()
[12:10:54.396] Configuring runspace scheduler.
[12:10:54.402] Executing command: 
                Get-Runspace | ForEach-Object {
                    $h = $_.GetType().GetProperty('Host', [System.Reflection.BindingFlags]::Instance -bor [System.Reflection.BindingFlags]::NonPublic).GetValue($_)
                    if ($h.Name -eq 'Visual Studio Code Host') 
                    {
                        $_.Id
                    }
                }
            
[12:10:54.550] Found VS Code runspace: 4
[12:10:54.551] Executing command: [PowerShellProTools.IntelliSenseManager]::InitV3(4)
[12:10:54.808] Scheduling command for main runspace: Import-Module 'C:\Users\tma2\.vscode\extensions\ironmansoftware.powershellprotools-2024.12.0\Modules\PowerShellProTools.VSCode\PowerShellProTools.VSCode.psd1' -Scope Global
[12:10:55.86] Connected to PowerShell process.
[12:10:55.87] Connected to PowerShell process.
[12:10:55.88] Creating tree views.
[12:10:55.93] Starting code analysis.
[12:10:55.94] Started PowerShell Pro Tools process.
[12:10:55.128] Scheduling command for main runspace: Get-Variable | Out-PoshToolsVariable -PassThru -ExcludeAutomatic $False | ConvertTo-Json -Depth 1 -WarningAction SilentlyContinue
[12:10:56.148] Scheduling command for main runspace: [PowerShellToolsPro.VSCode.TreeViewService]::Instance.GetTreeViews() | ConvertTo-Json -WarningAction SilentlyContinue
[12:19:47.26] Invoke method: GetPerformance Error sending data on named pipe. Error: connect ETIMEDOUT \\.\pipe\gfsgvpbzmttm
...continued in the same vein...
[12:59:53.191] Invoke method: GetPerformance Error sending data on named pipe. Error: connect ETIMEDOUT \\.\pipe\gfsgvpbzmttm
[13:0:59.398] Reconnect depth exceeded. Connection failed.
(Continued "Connection failed" and "Error sending data" messages)

Interestingly, the PowerShell extension log threw an error at 12:11:42, before the first error above. Usually, there is no issue with the official PS extension / PSES timing out or displaying any errors when PS Pro Tools has this issue, but thought it apropos to include:

2025-01-17 12:11:42.250 [error] Error: write EPIPE undefined
2025-01-17 12:11:42.251 [error] Error: write EPIPE undefined
2025-01-17 12:11:42.251 [info] [PSES] [Error - 12:11:42 PM] Client PowerShell Editor Services Client: connection to server is erroring.
write EPIPE
2025-01-17 12:11:42.251 [info] [PSES] [Error - 12:11:42 PM] Client PowerShell Editor Services Client: connection to server is erroring.
write EPIPE
2025-01-17 12:11:42.251 [info] [PSES] [Error - 12:11:42 PM] Request textDocument/codeLens failed.
2025-01-17 12:11:42.251 [info] [PSES]   Message: write EPIPE
  Code: -32099 
2025-01-17 12:11:42.256 [info] Language service connection closed.
2025-01-17 12:11:42.257 [info] [PSES] [Error - 12:11:42 PM] Connection to PowerShell Editor Services (the Extension Terminal) was closed. See below prompt to restart!

Version

  • PowerShell 7.4.6
  • VS Code 1.96.21.96.4
  • PowerShell Extension 2024.5.2 and 2025.1.0 pre-release
  • PowerShell Pro Tools 2024.7.6 and 2024.12.0
@TMA-2 TMA-2 changed the title The extension often disconnects and can not reconnect without the entire VSCode extension host being restarted The VS Code extension often disconnects and can not reconnect without the entire extension host being restarted Jan 30, 2025
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

No branches or pull requests

2 participants