Extension crashes when targeting PowerShell 5.1 (PowerShellEditorServices DryIoc error)

[prpercival]

Prerequisites

• I have written a descriptive issue title.
• I have searched all open and closed issues to ensure it has not already been reported.
• I have read the troubleshooting guide.
• I am sure this issue is with the extension itself and does not reproduce in a standalone PowerShell instance.
• I have verified that I am using the latest version of Visual Studio Code and the PowerShell extension.
• If this is a security issue, I have read the security issue reporting guidance.

Summary

Hi,

Starting the VS Code extension with

"powershell.powerShellDefaultVersion": "Windows PowerShell (x64)"

causes the extension to crash, it works fine with PowerShell 7.2.6, but I need to use PowerShell 5.1 for certain legacy scripts.

This message appears in the terminal at startup. Similar to this issue here, but none of the resolutions for that thread worked. I have attempted to reinstall VS Code and the PowerShell extension but neither have worked. Additionally, I have another computer that has both VS Code and the extension installed and I cannot reproduce the error on it.

Exception encountered starting EditorServices. Exception logged in D:\a\_work\1\s\src\PowerShellEditorServices.Hosting\Commands\StartEditorServicesCommand.cs on line 238 in EndProcessing:
System.AggregateException: An error occurred while writing to logger(s). ---> DryIoc.ContainerException: code: Error.WaitForScopedServiceIsCreatedTimeoutExpired;
message: DryIoc has waited for the creation of the scoped or singleton service by the "other party" for the  ticks without the completion.
You may call `exception.TryGetDetails(container)` to get the details of the problematic service registration.
The error means that either the "other party" is the parallel thread which has started but is unable to finish the creation of the service in the provided amount of time.
Or more likely the "other party"  is the same thread and there is an undetected recursive dependency or
the scoped service creation is failed with the exception and the exception was catched but you are trying to resolve the failed service again.
For all those reasons DryIoc has a timeout to prevent the infinite waiting.
You may change the default timeout via `Scope.WaitForScopedServiceIsCreatedTimeoutTicks=NewNumberOfTicks`
   at DryIoc.ContainerException.WithDetails(Object details, Int32 error, Object arg0, Object arg1, Object arg2, Object arg3)
   at DryIoc.Scope.WaitForItemIsSet(ImMapEntry`1 itemRef)
   at DryIoc.Factory.GetExpressionOrDefault(Request request)
   at DryIoc.Container.ResolveAndCacheKeyed(Int32 serviceTypeHash, Type serviceType, Object serviceKey, IfUnresolved ifUnresolved, Object scopeName, Type requiredServiceType, Request preResolveParent, Object[] args)
   at DryIoc.Container.DryIoc.IResolver.Resolve(Type serviceType, Object serviceKey, IfUnresolved ifUnresolved, Type requiredServiceType, Request preResolveParent, Object[] args)
   at DryIoc.Interpreter.InterpretResolveMethod(IResolverContext resolver, IList`1 callArgs, Object paramExprs, Object paramValues, ParentLambdaArgs parentArgs, Boolean useFec, Object& result)
   at DryIoc.Interpreter.TryInterpretMethodCall(IResolverContext r, Expression expr, Object paramExprs, Object paramValues, ParentLambdaArgs parentArgs, Boolean useFec, Object& result)
   at DryIoc.Interpreter.TryInterpret(IResolverContext r, Expression expr, Object paramExprs, Object paramValues, ParentLambdaArgs parentArgs, Boolean useFec, Object& result)
   at DryIoc.Interpreter.TryInterpretNestedLambdaBodyAndUnwrapException(IResolverContext r, Expression bodyExpr, Object paramExprs, Object paramValues, ParentLambdaArgs parentArgs, Boolean useFec)
   at DryIoc.Interpreter.<>c__DisplayClass3_0.<TryInterpretNestedLambda>b__0()
   at DryIoc.Interpreter.<>c__DisplayClass5_0`1.<ConvertFunc>b__0()
   at System.Lazy`1.CreateValue()
   at System.Lazy`1.LazyInitValue()
   at OmniSharp.Extensions.JsonRpc.ResponseRouter.SendNotification[T](String method, T params)
   at OmniSharp.Extensions.LanguageServer.Server.Logging.LanguageServerLogger.Log[TState](LogLevel logLevel, EventId eventId, TState state, Exception exception, Func`3 formatter)
   at Microsoft.Extensions.Logging.Logger.<Log>g__LoggerLog|12_0[TState](LogLevel logLevel, EventId eventId, ILogger logger, Exception exception, Func`3 formatter, List`1& exceptions, TState& state)
   --- End of inner exception stack trace ---
   at Microsoft.Extensions.Logging.Logger.ThrowLoggingError(List`1 exceptions)
   at Microsoft.Extensions.Logging.Logger.Log[TState](LogLevel logLevel, EventId eventId, TState state, Exception exception, Func`3 formatter)
   at Microsoft.Extensions.Logging.Logger`1.Microsoft.Extensions.Logging.ILogger.Log[TState](LogLevel logLevel, EventId eventId, TState state, Exception exception, Func`3 formatter)
   at Microsoft.Extensions.Logging.LoggerExtensions.Log(ILogger logger, LogLevel logLevel, EventId eventId, Exception exception, String message, Object[] args)
   at OmniSharp.Extensions.JsonRpc.OutputHandler.<.ctor>b__13_3(Exception e)
   at System.Reactive.Linq.ObservableImpl.Do`1.Actions._.OnError(Exception error)
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
   at System.Reactive.Stubs.<>c.<.cctor>b__2_1(Exception ex)
   at System.Reactive.AnonymousSafeObserver`1.OnError(Exception error)
   at System.Reactive.Sink`1.ForwardOnError(Exception error)
   at System.Reactive.Linq.ObservableImpl.Do`1.Actions._.OnError(Exception error)
   at System.Reactive.Sink`2.OnError(Exception error)
   at System.Reactive.Linq.ObservableImpl.ThrowImmediate`1.Run(IObserver`1 observer)
   at System.Reactive.BasicProducer`1.SubscribeRaw(IObserver`1 observer, Boolean enableSafeguard)
   at System.Reactive.Linq.ObservableImpl.Defer`1._.Run()
   at System.Reactive.Producer`2.SubscribeRaw(IObserver`1 observer, Boolean enableSafeguard)
   at System.Reactive.Linq.ObservableImpl.Do`1.Actions.Run(_ sink)
   at System.Reactive.Concurrency.Scheduler.<>c__75`1.<ScheduleAction>b__75_0(IScheduler _, ValueTuple`2 tuple)
   at System.Reactive.Concurrency.CurrentThreadScheduler.Schedule[TState](TState state, TimeSpan dueTime, Func`3 action)
   at System.Reactive.Concurrency.LocalScheduler.Schedule[TState](TState state, Func`3 action)
   at System.Reactive.Concurrency.Scheduler.ScheduleAction[TState](IScheduler scheduler, TState state, Action`1 action)
   at System.Reactive.Producer`2.SubscribeRaw(IObserver`1 observer, Boolean enableSafeguard)
   at OmniSharp.Extensions.JsonRpc.OutputHandler..ctor(PipeWriter pipeWriter, ISerializer serializer, IEnumerable`1 outputFilters, IScheduler scheduler, ILogger`1 logger, IActivityTracingStrategy activityTracingStrategy)
   at DryIoc.Interpreter.TryInterpretAndUnwrapContainerException(IResolverContext r, Expression expr, Boolean useFec, Object& result)
   at DryIoc.Factory.ApplyReuse(Expression serviceExpr, Request request)
   at DryIoc.Factory.GetExpressionOrDefault(Request request)
   at DryIoc.FactoryMethod.<>c__DisplayClass10_0.<Constructor>b__0(Request request)
   at DryIoc.ReflectionFactory.CreateExpressionOrDefault(Request request)
   at DryIoc.Factory.GetExpressionOrDefault(Request request)
   at DryIoc.ReflectionFactory.CreateExpressionOrDefault(Request request)
   at DryIoc.Factory.GetExpressionOrDefault(Request request)
   at DryIoc.Container.ResolveAndCache(Int32 serviceTypeHash, Type serviceType, IfUnresolved ifUnresolved)
   at DryIoc.Container.DryIoc.IResolver.Resolve(Type serviceType, IfUnresolved ifUnresolved)
   at DryIoc.Resolver.Resolve[TService](IResolver resolver, IfUnresolved ifUnresolved)
   at OmniSharp.Extensions.LanguageServer.Server.LanguageServer.<From>d__37.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at Microsoft.PowerShell.EditorServices.Server.PsesLanguageServer.<StartAsync>d__14.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at Microsoft.PowerShell.EditorServices.Hosting.EditorServicesRunner.<CreateEditorServicesAndRunUntilShutdown>d__9.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at Microsoft.PowerShell.EditorServices.Commands.StartEditorServicesCommand.EndProcessing()
---> (Inner Exception #0) DryIoc.ContainerException: code: Error.WaitForScopedServiceIsCreatedTimeoutExpired;
message: DryIoc has waited for the creation of the scoped or singleton service by the "other party" for the  ticks without the completion.
You may call `exception.TryGetDetails(container)` to get the details of the problematic service registration.
The error means that either the "other party" is the parallel thread which has started but is unable to finish the creation of the service in the provided amount of time.
Or more likely the "other party"  is the same thread and there is an undetected recursive dependency or
the scoped service creation is failed with the exception and the exception was catched but you are trying to resolve the failed service again.
For all those reasons DryIoc has a timeout to prevent the infinite waiting.
You may change the default timeout via `Scope.WaitForScopedServiceIsCreatedTimeoutTicks=NewNumberOfTicks`
   at DryIoc.ContainerException.WithDetails(Object details, Int32 error, Object arg0, Object arg1, Object arg2, Object arg3)
   at DryIoc.Scope.WaitForItemIsSet(ImMapEntry`1 itemRef)
   at DryIoc.Factory.GetExpressionOrDefault(Request request)
   at DryIoc.Container.ResolveAndCacheKeyed(Int32 serviceTypeHash, Type serviceType, Object serviceKey, IfUnresolved ifUnresolved, Object scopeName, Type requiredServiceType, Request preResolveParent, Object[] args)
   at DryIoc.Container.DryIoc.IResolver.Resolve(Type serviceType, Object serviceKey, IfUnresolved ifUnresolved, Type requiredServiceType, Request preResolveParent, Object[] args)
   at DryIoc.Interpreter.InterpretResolveMethod(IResolverContext resolver, IList`1 callArgs, Object paramExprs, Object paramValues, ParentLambdaArgs parentArgs, Boolean useFec, Object& result)
   at DryIoc.Interpreter.TryInterpretMethodCall(IResolverContext r, Expression expr, Object paramExprs, Object paramValues, ParentLambdaArgs parentArgs, Boolean useFec, Object& result)
   at DryIoc.Interpreter.TryInterpret(IResolverContext r, Expression expr, Object paramExprs, Object paramValues, ParentLambdaArgs parentArgs, Boolean useFec, Object& result)
   at DryIoc.Interpreter.TryInterpretNestedLambdaBodyAndUnwrapException(IResolverContext r, Expression bodyExpr, Object paramExprs, Object paramValues, ParentLambdaArgs parentArgs, Boolean useFec)
   at DryIoc.Interpreter.<>c__DisplayClass3_0.<TryInterpretNestedLambda>b__0()
   at DryIoc.Interpreter.<>c__DisplayClass5_0`1.<ConvertFunc>b__0()
   at System.Lazy`1.CreateValue()
   at System.Lazy`1.LazyInitValue()
   at OmniSharp.Extensions.JsonRpc.ResponseRouter.SendNotification[T](String method, T params)
   at OmniSharp.Extensions.LanguageServer.Server.Logging.LanguageServerLogger.Log[TState](LogLevel logLevel, EventId eventId, TState state, Exception exception, Func`3 formatter)
   at Microsoft.Extensions.Logging.Logger.<Log>g__LoggerLog|12_0[TState](LogLevel logLevel, EventId eventId, ILogger logger, Exception exception, Func`3 formatter, List`1& exceptions, TState& state)<---

PowerShell Version

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

Visual Studio Code Version

1.71.2
74b1f979648cc44d385a2286793c226e611f59e7
x64

Extension Version

[email protected]

Steps to Reproduce

1. Open VS Code
2. Make sure VS Code PowerShell extension is targeting 5.1
3. CTRL + SHIFT + P and then type >PowerShell: Show Session Menu
4. Extension will attempt to load and then throw the error in the description
5. Extensions crashes and cannot be restarted until you exit VS Code

Visuals

No response

Logs

EditorServices.log
error.txt
ps_extension_output.txt
ps_editor_services_output.txt

[andyleejordan]

Hm...could you list out more environment details? I'm specifically curious what PowerShell modules might be installed, or other code running during startup, such as in your profile(s).

[prpercival]

Sure, here is a list of my installed modules and my PowerShell profile.

Get-InstalledModule.txt
Microsoft.PowerShell_profile.txt

[andyleejordan]

Ah, interesting, I notice you're importing the chocolatey profile too. Can you comment out everything in your profile and see if this repros?

[prpercival]

It looks like it still happens if everything is commented out in the profile and also if I actually delete the profile file as well.

[andyleejordan]

Do you have any other profiles? What's the output of $PROFILE | Get-Member -Type NoteProperty (and then the contents of the four file paths listed)?

[prpercival]

Output is below, the only file that exists is the last one (which I attached the contents of earlier), C:\Users\ppercival\Documents\WindowsPowerShell\Microsoft.PowerShell_profile.ps1

$PROFILE | Get-Member -Type NoteProperty


   TypeName: System.String

Name                   MemberType   Definition
----                   ----------   ----------
AllUsersAllHosts       NoteProperty string AllUsersAllHosts=C:\Windows\System32\WindowsPowerShell\v1.0\profile.ps1
AllUsersCurrentHost    NoteProperty string AllUsersCurrentHost=C:\Windows\System32\WindowsPowerShell\v1.0\Microsoft.PowerShell_profile.ps1
CurrentUserAllHosts    NoteProperty string CurrentUserAllHosts=C:\Users\ppercival\Documents\WindowsPowerShell\profile.ps1
CurrentUserCurrentHost NoteProperty string CurrentUserCurrentHost=C:\Users\ppercival\Documents\WindowsPowerShell\Microsoft.PowerShell_profile.ps1

[andyleejordan]

Well, that at least rules out profiles. Maybe try bisecting the modules? That is, uninstall half at a time progressively to find if it stops reproducing.

[andyleejordan]

Ok...after a lot of (re-)investigation, we seem to have determined that this issue occurs when multiple versions of the System.Threading.Extensions assembly are installed to the GAC. From the logs you helpfully provided, we see:

2022-09-19 14:38:05.659 -05:00 [VRB] Loaded 'System.Threading.Tasks.Extensions, Version=4.2.0.0, Culture=neutral, PublicKeyToken=cc7b13ffcd2ddd51' from 'C:\WINDOWS\Microsoft.Net\assembly\GAC_MSIL\System.Threading.Tasks.Extensions\v4.0_4.2.0.0__cc7b13ffcd2ddd51\System.Threading.Tasks.Extensions.dll'

2022-09-19 14:38:05.659 -05:00 [VRB] Loaded 'System.Threading.Tasks.Extensions, Version=4.2.0.1, Culture=neutral, PublicKeyToken=cc7b13ffcd2ddd51' from 'C:\WINDOWS\Microsoft.Net\assembly\GAC_MSIL\System.Threading.Tasks.Extensions\v4.0_4.2.0.1__cc7b13ffcd2ddd51\System.Threading.Tasks.Extensions.dll'

Note that's both 4.2.0.0, and 4.2.0.1. To be honest, both should work, but look at the actual error underneath (which ages ago I talked about with OmniSharp's developer, but didn't quite understand what was going on):

2022-09-19 14:38:06.019 -05:00 [FTL] unhandled exception
System.MissingMethodException: Method not found: 'System.Threading.Tasks.ValueTask`1<!0> System.Threading.Channels.ChannelReader`1.ReadAsync(System.Threading.CancellationToken)'.
   at OmniSharp.Extensions.JsonRpc.OutputHandler.<ProcessOutputStream>d__19.MoveNext()
   at System.Runtime.CompilerServices.AsyncTaskMethodBuilder.Start[TStateMachine](TStateMachine& stateMachine)
   at OmniSharp.Extensions.JsonRpc.OutputHandler.ProcessOutputStream(CancellationToken cancellationToken)
   at System.Reactive.Linq.QueryLanguage.StartAsyncImpl(Func`1 actionAsync, IScheduler scheduler)

There is a type identity issue causing the ReadAsync method to not be found because the "expected" location of it doesn't exist (as it's expecting just one System.Threading.Tasks.Extensions assembly to provide System.Threading.Tasks.ValueTask...but there are two loaded).

This seems to be the same issue as seen in #3462 and #3827.

We are figuring out how to fix it, but it's complicated 😳

Note that when this issues does not occur, we see System.Threading.Tasks.Extensions v4.2.0.1 being loaded from the extension's directory not from the GAC:

[andyleejordan]

Yay! @SeeminglyScience and I can successfully repro this (finally). First we downloaded System.Threading.Tasks.Extensions v4.5.4 (which is assembly version 4.2.0.1) and installed it to the GAC with gacutil.exe /i C:\Users\andschwa\Desktop\System.Threading.Tasks.Extensions.dll. This alone did not break anything, though it was noted that an assembly load resolve event was fired for 4.2.0.0 and that was supplied from the extension directory, not the GAC.

Then we downloaded and installed System.Threading.Tasks.Extensions v4.5.2 (which is assembly version 4.2.0.0) and also installed it to the GAC. This reproduced the error!

I believe if we can repro it, we're well on our way to (finally) fixing it.

[andyleejordan]

So what's happening is OmniSharp is referencing System.Threading.Tasks.Extensions 4.2.0.1, since that's what their manifests reference, but then when it actually loads System.Threading.Channels (which appears to have lied about its dependencies) 4.2.0.0 gets loaded instead, which then causes OmniSharp to bonk.

So a potentially dangerous "workaround" would be to run gacutil /u System.Threading.Tasks.Extensions which will UNINSTALL these assemblies from the GAC, and so cause the one we have in the extension's directory to be loaded. It'll still ask for 4.2.0.0, but since it's no longer in the GAC, the actually correct 4.2.0.1 gets loaded:

2022-10-04 14:03:28.848 -07:00 [VRB] Loading System.Threading.Tasks.Extensions, Version=4.2.0.0, Culture=neutral, PublicKeyToken=cc7b13ffcd2ddd51 from PSES dependency dir into LoadFile context
2022-10-04 14:03:28.867 -07:00 [VRB] Loaded 'System.Threading.Tasks.Extensions, Version=4.2.0.1, Culture=neutral, PublicKeyToken=cc7b13ffcd2ddd51' from 'C:\Users\andschwa\src\PowerShellEditorServices\module\PowerShellEditorServices\bin\Common\System.Threading.Tasks.Extensions.dll'

We think that OmniSharp needs to update its dependency on System.Threading.Channels which it currently has at 4.7.1, which unfortunately is the broken version that references 4.2.0.1 of System.Threading.Tasks.Extensions in its manifest, but in reality fires a resolve event for 4.2.0.0, which when present (such as being installed to the GAC by some other application) causes this whole problem.

I'll try to build PSES against OmniSharp with an updated dependency, and if it works, get @david-driscoll to roll out a new version for us. We shall see.

[andyleejordan]

Just a small update, it does not require both versions of System.Threading.Tasks.Extensions present in the GAC to crash, it requires just the 4.2.0.0, which is erroneously asked for by System.Threading.Channels.

[prpercival]

I was provided a preview .vsix for the extension and that resolved the issue. I can now debug as expected using PowerShell 5.1. Thanks again for all the help!

[ALIENQuake]

@andschwa Seeing you in action like this brings hope that VSCode PowerShell Extention has a bright future. Thank you!

[ghost]

Thank you for your comment, but please note that this issue has been closed for over a week. For better visibility, consider opening a new issue with a link to this instead.

[andyleejordan]

Thanks so much @ALIENQuake ❤️ I was just so, so glad to get to the bottom of this one!

[brwilkinson]

Is this issue resolved, since I am still seeing similar behavior with WMF 5.1 across a few different machines?

[ghost]

Thank you for your comment, but please note that this issue has been closed for over a week. For better visibility, consider opening a new issue with a link to this instead.