Dependencies erroneously loaded from GAC first in Windows PowerShell

[dammejed]

Issue Description

Powershell services appears to crash on launch with 'Missing method exception:'

Exception calling "StartLogging" with "2" argument(s): "Method not found: 'Serilog.LoggerConfiguration Serilog.Configuration.LoggerSinkConfiguration.Wrap(Serilog.Configuration.LoggerSinkConfiguration, System.Func`2<Serilog.Core.ILogEventSink,Serilog.Core.ILogEventSink>, System.Action`1<Serilog.Configuration.LoggerSinkConfiguration>, Serilog.Events.LogEventLevel, Serilog.Core.LoggingLevelSwitch)'."
   at System.Management.Automation.ExceptionHandlingOps.CheckActionPreference(FunctionContext funcContext, Exception exception)
   at System.Management.Automation.Interpreter.ActionCallInstruction`2.Run(InterpretedFrame frame)
   at System.Management.Automation.Interpreter.EnterTryCatchFinallyInstruction.Run(InterpretedFrame frame)
   at System.Management.Automation.Interpreter.EnterTryCatchFinallyInstruction.Run(InterpretedFrame frame)
   at System.Management.Automation.Interpreter.Interpreter.Run(InterpretedFrame frame)
   at System.Management.Automation.Interpreter.LightLambda.RunVoid1[T0](T0 arg0)
   at System.Management.Automation.PSScriptCmdlet.RunClause(Action`1 clause, Object dollarUnderbar, Object inputToProcess)
   at System.Management.Automation.PSScriptCmdlet.DoEndProcessing()
   at System.Management.Automation.CommandProcessorBase.Complete()
Method not found: 'Serilog.LoggerConfiguration Serilog.Configuration.LoggerSinkConfiguration.Wrap(Serilog.Configuration.LoggerSinkConfiguration, System.Func`2<Serilog.Core.ILogEventSink,Serilog.Core.ILogEventSink>, System.Action`1<Serilog.Configuration.LoggerSinkConfiguration>, Serilog.Events.LogEventLevel, Serilog.Core.LoggingLevelSwitch)'.
   at Serilog.LoggerConfigurationAsyncExtensions.Async(LoggerSinkConfiguration loggerSinkConfiguration, Action`1 configure, IAsyncLogEventSinkMonitor monitor, Int32 bufferSize, Boolean blockWhenFull)
   at Microsoft.PowerShell.EditorServices.Utility.Logging.Builder.Build()
   at Microsoft.PowerShell.EditorServices.Host.EditorServicesHost.StartLogging(String logFilePath, LogLevel logLevel)
   at CallSite.Target(Closure , CallSite , Object , Object , Object )

Attached Logs

Powershell-logs.zip

Environment Information

Visual Studio Code

Name	Version
Operating System	Windows_NT x64 10.0.17763
VSCode	1.36.1
PowerShell Extension Version	2019.5.0

PowerShell Information

Name	Value
PSVersion	5.1.17763.316
PSEdition	Desktop
PSCompatibleVersions	1.0 2.0 3.0 4.0 5.0 5.1.17763.316
BuildVersion	10.0.17763.316
CLRVersion	4.0.30319.42000
WSManStackVersion	3.0
PSRemotingProtocolVersion	2.3
SerializationVersion	1.1.0.1

Visual Studio Code Extensions

Visual Studio Code Extensions(Click to Expand)

Extension	Author	Version
csharp	ms-vscode	1.21.0
gitblame	waderyan	2.8.1
powershell	ms-vscode	2019.5.0
prettier-vscode	esbenp	1.9.0
tslint	eg2	1.0.44
vscode-antlr4	mike-lischke	2.1.1
vsliveshare	ms-vsliveshare	1.0.540

[SydneyhSmith]

Hi @dammejed thanks for opening an issue, we often see start-up issues when system configuration like group policy, execution policy or antivirus are in place...your error message is a bit different from the one we typically see in this case but I am wondering if you are operating in a restricted system?

[dammejed]

@SydneyhSmith There are undoubtedly GPOs applied to my machine, but none I'm aware of that would restrict powershell execution. I already checked the guide for installations in restricted environments,
and I had no requirement to approve the module for execution.

The logs show that, at the very least, the entry point for that PS module is entered, which I would assume means that the execution policy isn't restricting things, correct?

#-- Start up PowerShellEditorServices ----------------------------------------
VERBOSE: Importing PowerShellEditorServices
VERBOSE: Loading module from path 'C:\Users\jeff.dammeyer\.vscode\extensions\ms-vscode.powershell-2019.5.0\modules\PowerShellEditorServices\PowerShellEditorServices.psd1'.
VERBOSE: Loading module from path 'C:\Users\jeff.dammeyer\.vscode\extensions\ms-vscode.powershell-2019.5.0\modules\PowerShellEditorServices\PowerShellEditorServices.psm1'.
VERBOSE: Exporting function 'Start-EditorServicesHost'.
VERBOSE: Exporting function 'Compress-LogDir'.
VERBOSE: Exporting function 'Get-PowerShellEditorServicesVersion'.
VERBOSE: Importing function 'Compress-LogDir'.
VERBOSE: Importing function 'Get-PowerShellEditorServicesVersion'.
VERBOSE: Importing function 'Start-EditorServicesHost'.
PowerShell Integrated Console
VERBOSE: Invoking Start-EditorServicesHost

[dammejed]

On a hunch, I checked if I had the dependency mentioned in the exception (Serilog) in my GAC, and it turns out I did, version 2.0.0.0. I uninstalled Serilog from the GAC, and the extension now works as expected.

I'm not sure why the GAC version was used, given that it's clearly not the minimum version needed, but it is what it is, I suppose.

I can close this issue, since I'm no longer affected, or I can leave it open if that's (managing the correct dependency versions) something you want to tackle. Let me know!

[rjmholt]

Ah nice hunch! It's a bug on our part then; we only add the types we immediately call into on startup and let them load their dependencies as they go. From this it sounds like that's fragile and we should eagerly load everything (although in PS 6+ this isn't a problem actually)

[TylerLeonhardt]

Yeah since the .NET Framework loads from the GAC first, we'll probably need to load everything ourselves... Would be a great opportunity to try to take advantage of the RequiredAssemblies field in our module manifest

[rjmholt]

I know this is the older issue, but #2538 has some more pertinent discussion so I'll deduplicate to that and pin that one.

Loading from the GAC first is a by-design behaviour in .NET Framework that we can't work around and the issue is that Serilog's assembly versioning is deliberately broken.

The solution for us is likely to remove Serilog.