Visual Studio 2017 PowerShellHostProcessException: Timed out to create and initialize the process

[George Chakhidze]

After upgrading to PoshTools 5.0.1, opening solution that contains PowerShell project, always displays this error message:

---

PowerShell Tools for Visual Studio Error

Failed to initialize PowerShell Tools for Visual StudioPowerShellTools.ServiceManagement.PowerShellHostProcessException: Timed out to create and initialize the process 5096

at PowerShellTools.ServiceManagement.PowershellHostProcessHelper.CreatePowerShellHostProcess(String powershellVersion, Int32 port)

at PowerShellTools.ServiceManagement.ConnectionManager.OpenClientConnection()

at PowerShellTools.ServiceManagement.ConnectionManager..ctor()

at PowerShellTools.PowerShellToolsPackage.<InitializePowerShellHostAsync>d__47.MoveNext()

--- End of stack trace from previous location where exception was thrown ---

at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)

at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)

at PowerShellTools.PowerShellToolsPackage.<InitializeInternalAsync>d__43.MoveNext()

--- End of stack trace from previous location where exception was thrown ---

at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)

at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)

at PowerShellTools.PowerShellToolsPackage.<InitializeAsync>d__39.MoveNext()

OK

‌

Installed software:

Visual Studio 2017 version 15.9.17

PowerShell Tools for Visual Studio 5.0.1

Windows PowerShell 5.1.17763.771

PowerShell Core 6.2.3

[Adam Driscoll]

Are you trying to run Powershell Core 6.2.3 or Windows PowerShell? If you haven’t changed any settings it should be running Windows PowerShell. I’m going to get a patch release out to increase the timeout here and improve some logging around the startup. If you could upgrade to 5.0.2 tomorrow and give this a shot again, that would be awesome.

[George Chakhidze]

I’ve upgraded to 5.0.2 and now it got worse: I have to wait longer for error message to appear.

Running Windows PowerShell (x64).

Profile loading, Script analyzer and Tab completion all disabled.

Diagnostic logging is enabled, but “%AppData%\PowerShell Tools for Visual Studio\log.txt” is empty.

[Adam Driscoll]

That is weird that logging isn’t working…In 5.0.3, you’ll be able to set the host timeout. I knocked it back down to the original of 5 seconds which should be more than enough in most circumstances.

Can you do me a favor go to Options->General and set OverrideExecutionPolicyConfiguration to false? I know this can cause problems in some environments.

Can you also go and check-in Event Viewer to see if there are any app crashes that refer to PowerShell?

Finally, do you have .NET 4.7.2 installed by chance?

‌

[George Chakhidze]

Disabled OverrideExecutionPolicyConfiguration, tried again, got exactly same exception.

No crashes in Event Viewer.

.NET 4.8 is installed.

[George Chakhidze]

I’ve extracted powershell.exe command line using SysInternals Process Monitor and tried to launch it (while Visual Studio was still running), this is the output:

> "C:\WINDOWS\system32\WindowsPowerShell\v1.0\powershell.exe" -NoExit -NoProfile -NonInteractive -Command "& { Import-Module 'c:\program files (x86)\visual studio\2017\enterprise\common7\ide\extensions\34n2itrb.w5f\HostService.dll'; Start-HostService -Port 2566 -DevEnvProcessId 16712 -ReadyEventName 'VsPowershellToolProcess:092e6bc1-2da7-4fd4-926a-1d8d1c419f6b' }"
Channel: 2566.
Server port: 2596
Failed to create service host. Status(StatusCode=Unavailable, Detail="failed to connect to all addresses")

netstat output shows that Visual Studio is listening on port 2566, but nobody is listening on 2596.

[Adam Driscoll]

Nice debugging. 5.0.3 has an option to show the PowerShell host so you’ll be able to see this info easier. Visual Studio should be listening on 2596.

Can you download DebugView and see if you have any logs in there? https://docs.microsoft.com/en-us/sysinternals/downloads/debugview

It’s unclear to me why file logging isn’t working but PoshTools also writes it’s logs to the debug stream in Windows. Maybe that will give some more information into why VS is failing to listen on that port.

‌

[George Chakhidze]

This is debug output:

‌

[1192] PowerShellTools.HostService.ServiceCommon: [Pipeline Execution Thread] INFO  PowerShellTools.HostService.ServiceCommon (null) - Initializing debugging engine service ... 
[1192] PowerShellTools.HostService.ServiceCommon: [Pipeline Execution Thread] INFO  PowerShellTools.HostService.ServiceCommon (null) - Initializing run space with debugger 
[1192] PowerShellTools.HostService.ServiceCommon: [Pipeline Execution Thread] INFO  PowerShellTools.HostService.ServiceCommon (null) - Providing $profile variable to the local runspace. 
[1192] PowerShellTools.HostService.ServiceCommon: [Pipeline Execution Thread] INFO  PowerShellTools.HostService.ServiceCommon (null) - Done initializing runspace 
[1192] HostService.StartHostServiceCommand: [Pipeline Execution Thread] ERROR HostService.StartHostServiceCommand (null) - Failed to create service host. 
[1192] Grpc.Core.RpcException: Status(StatusCode=Unavailable, Detail="failed to connect to all addresses") 
[1192]    at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw() 
[1192]    at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task) 
[1192]    at Grpc.Core.Internal.AsyncCall`2.UnaryCall(TRequest msg) 
[1192]    at Grpc.Core.DefaultCallInvoker.BlockingUnaryCall[TRequest,TResponse](Method`2 method, String host, CallOptions options, TRequest request) 
[1192]    at Grpc.Core.Interceptors.InterceptingCallInvoker.<BlockingUnaryCall>b__3_0[TRequest,TResponse](TRequest req, ClientInterceptorContext`2 ctx) 
[1192]    at Grpc.Core.ClientBase.ClientBaseConfiguration.ClientBaseConfigurationInterceptor.BlockingUnaryCall[TRequest,TResponse](TRequest request, ClientInterceptorContext`2 context, BlockingUnaryCallContinuation`2 continuation) 
[1192]    at Grpc.Core.Interceptors.InterceptingCallInvoker.BlockingUnaryCall[TRequest,TResponse](Method`2 method, String host, CallOptions options, TRequest request) 
[1192]    at HostProtocol.StartupService.StartupServiceClient.notifyPort(intMessage request, CallOptions options) 
[1192]    at HostService.StartHostServiceCommand.ProcessRecord()

‌

[George Chakhidze]

I’ve created a simple gRPC client/server console app and turned on verbose gRPC logging using GRPC_TRACE=all and GRPC_VERBOSITY=DEBUG env vars, and, turns out that gRPC was attempting to connect to localhost via corporate proxy (?!)

I1107 13:27:19.282248 0 T:\src\github\grpc\workspace_csharp_ext_windows_x64\src\core\ext\filters\client_channel\http_connect_handshaker.cc:298: Connecting to server 127.0.0.1:2614 via HTTP proxy ipv4:xx.xx.xx.xx:8080

I had set up “http_proxy” environment variable for npm, git and other tools, but forgot to create “no_proxy” as well. After setting no_proxy=localhost, it works. PoshTools works as well.

There is a channel option to bypass proxy: grpc.enable_http_proxy https://grpc.github.io/grpc/core/group__grpc__arg__keys.html#gaa3f69f6e1e789e36d2d9c6083fec0257

Can be set in C# code:

Channel channel = new Channel("localhost:21551", ChannelCredentials.Insecure, new[] { new ChannelOption("grpc.enable_http_proxy", 0) });

‌

[Adam Driscoll]

Fantastic. Thank you for debugging that. That is so helpful

[Adam Driscoll]

I've included the proxy options in PoshTools. Please reopen this issue if you still experience the problem in 5.0.5 or later.