2024.4.0: Unable to start when using Windows PowerShell if older Serilog is already present

[ajacks88]

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

Attempting to launch vscode's powershell extension and get an error. Googling found others with the same issue.

PowerShell Version

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

Visual Studio Code Version

1.95.1
x64

Extension Version

[email protected]

Steps to Reproduce

Launch vscode, get the following error:

Exception encountered starting EditorServices. Exception logged in C:__w\1\s\src\PowerShellEditorServices.Hosting\Commands\StartEditorServicesCommand.cs on line 239 in EndProcessing:
System.MissingMethodException: Method not found: 'Microsoft.Extensions.Logging.ILoggerFactory Serilog.SerilogLoggerFactoryExtensions.AddSerilog(Microsoft.Extensions.Logging.ILoggerFactory, Serilog.ILogger, Boolean)'.
at Microsoft.PowerShell.EditorServices.Hosting.EditorServicesServerFactory.Create(String logDirectoryPath, Int32 minimumLogLevel, IObservable1 hostLogger) at Microsoft.PowerShell.EditorServices.Hosting.EditorServicesRunner..ctor(HostLogger logger, EditorServicesConfig config, ISessionFileWriter sessionFileWriter, IReadOnlyCollection1 loggersToUnsubscribe)
at Microsoft.PowerShell.EditorServices.Hosting.EditorServicesLoader.LoadAndRunEditorServicesAsync()
at Microsoft.PowerShell.EditorServices.Commands.StartEditorServicesCommand.EndProcessing()

Visuals

No response

Logs

No response

[JustinGrote]

@ajacks88 thanks for your submission!

We can't reproduce, maybe you can help us narrow down your environment. The nature of this error almost always means that something else in your environment is loading an older or otherwise incompatible Microsoft.Extensions.Logging assembly before the PowerShell Editor Services starts.

1. If you Use Install Specific Version to rollback, does the issue still persist?
   
2. If you switch your session to PowerShell 7, does the issue persist?
3. Do you have anything in your profile? If you disable your profile in the vscode settings, does the issue still occur?

CC @andyleejordan for 👀

[JustinGrote]

@andyleejordan I think it might be time for us to start catching these methodNotFound exceptions during startup and reporting some added guidance in this regard.

[Azburkabas]

I have the same problem. After update to v.2024.4.0 it can not load powershell 5.1 sessions (powershell 7 works but I need pwsh 5.1).

Error code:
The terminal process "C:\WINDOWS\SysWOW64\WindowsPowerShell\v1.0\powershell.exe '-NoProfile', '-ExecutionPolicy', 'Bypass', '-Command', 'Import-Module 'c:\Users\xxxxxxxxx.vscode\extensions\ms-vscode.powershell-2024.5.0\modules\PowerShellEditorServices\PowerShellEditorServices.psd1'; Start-EditorServices -HostName 'Visual Studio Code Host' -HostProfileId 'Microsoft.VSCode' -HostVersion '2024.5.0' -BundledModulesPath 'c:\Users\xxxxxxxx.vscode\extensions\ms-vscode.powershell-2024.5.0\modules' -EnableConsoleRepl -StartupBanner "PowerShell Extension v2024.5.0
Copyright (c) Microsoft Corporation.

https://aka.ms/vscode-powershell
Type 'help' to get help.
" -LogLevel 'Normal' -LogPath 'c:\Users\xxxxxxx\AppData\Roaming\Code\User\globalStorage\ms-vscode.powershell\logs\1730969275-a948b417-6923-477c-a612-450319746a041730968940191' -SessionDetailsPath 'c:\Users\xxxxxx\AppData\Roaming\Code\User\globalStorage\ms-vscode.powershell\sessions\PSES-VSCode-21020-286160.json' -FeatureFlags @() '" terminated with exit code: 1.

[ERROR] - PowerShell Language Server process didn't start!

When i roll back to v2024.2.2 it works just fine.

[Phillip-Ian]

Nothing new to add, just reinforcing the issue. Exact same symptoms, and rolling back to v2024.2.2 did the trick.

[JustinGrote]

@ajacks88 @Phillip-Ian @Azburkabas we can't reproduce this anywhere, so we have to figure out what is different about your environment.

• Have you tried with PowerShell 7 and do you still have the same problem? A reminder that PS 5.1 is best effort support but we certainly aren't making any moves to actively break it.
• Have you tried on another computer, preferably with a clean profile and a clean modules folder with no third party modules installed?
• If the "other computer" works, we will need a list of your installed modules and maybe we can identify an early loader, but in PS 5.1 we don't have access to isolation tech that we have in 7 and are possibly unlikely to solve an incompatability with that specific module and will recommend you use 7 instead (you can still author 5.1 scripts in 7)

[ferjea01]

Same problem, as @Phillip-Ian proposed, I rolledback to v2024.2.2 and all good

[JustinGrote]

@ferjea01 thanks! As previously stated we can't reproduce so if you can provide the info requested here:
#5084 (comment)

It might help us narrow it down.

[Azburkabas]

• a

Hi, i wrote above that powershell 7 works, but i needed pws 5.1 for all msonline/graph etc... pws modules.

I tried uninstalling vscode and cleaning all config folders and install everyting from scratch (with no other vs code extensions except powershell extension and it still didn't work). Reverting to v2024.2.2. works just fine

[ferjea01]

Hi @JustinGrote ,

We need powershell 5.1 for Windows related module (msmq and iis stuff such as webbinding, appPool configuration, etc) .
The most important modules we use are WebAdministration and SqlServer, Microsoft.SqlServer.Smo and System.Messaging.

My collegue also had the same problem on his computer.

We have theses modules installed :
5.1.2 Azure
0.5.0 Azure.AnalysisServices
4.2.1 Azure.Storage
5.7.0 AzureRM
0.6.6 AzureRM.AnalysisServices
5.1.2 AzureRM.ApiManagement
0.1.3 AzureRM.ApplicationInsights
4.3.2 AzureRM.Automation
4.0.4 AzureRM.Backup
4.0.6 AzureRM.Batch
0.14.1 AzureRM.Billing
4.2.2 AzureRM.Cdn
0.9.4 AzureRM.CognitiveServices
4.6.0 AzureRM.Compute
0.3.1 AzureRM.Consumption
0.2.5 AzureRM.ContainerInstance
1.0.4 AzureRM.ContainerRegistry
4.2.2 AzureRM.DataFactories
0.5.3 AzureRM.DataFactoryV2
4.2.3 AzureRM.DataLakeAnalytics
5.2.0 AzureRM.DataLakeStore
4.0.4 AzureRM.DevTestLabs
4.1.2 AzureRM.Dns
0.3.2 AzureRM.EventGrid
0.6.3 AzureRM.EventHub
4.1.2 AzureRM.HDInsight
4.0.4 AzureRM.Insights
3.1.2 AzureRM.IotHub
4.3.0 AzureRM.KeyVault
4.0.3 AzureRM.LogicApp
0.17.2 AzureRM.MachineLearning
0.4.2 AzureRM.MachineLearningCompute
0.2.1 AzureRM.MarketplaceOrdering
0.9.2 AzureRM.Media
5.4.2 AzureRM.Network
4.1.1 AzureRM.NotificationHubs
4.3.2 AzureRM.OperationalInsights
4.1.4 AzureRM.PowerBIEmbedded
4.6.0 AzureRM.Profile
4.1.2 AzureRM.RecoveryServices
4.1.2 AzureRM.RecoveryServices.Backup
0.2.4 AzureRM.RecoveryServices.SiteRec.
4.1.2 AzureRM.RedisCache
0.3.3 AzureRM.Relay
5.5.2 AzureRM.Resources
0.16.3 AzureRM.Scheduler
4.1.2 AzureRM.ServerManagement
0.6.4 AzureRM.ServiceBus
0.3.4 AzureRM.ServiceFabric
5.0.6 AzureRM.SiteRecovery
4.4.0 AzureRM.Sql
4.2.3 AzureRM.Storage
4.0.4 AzureRM.StreamAnalytics
4.0.1 AzureRM.Tags
4.0.3 AzureRM.TrafficManager
4.0.2 AzureRM.UsageAggregates
4.2.2 AzureRM.Websites
2.2.1.5 PSWindowsUpdate
22.2.0 SqlServer

We have Windows 10 Enterprise 22h2 19045.5011. Could any security update created that glitch?

[andyleejordan]

Hm, this was tested against Microsoft Windows Server 2022 10.0.20348.

@dkattan was hitting almost this exact same failure scenario with the "mission method" from the logger in https://github.com/PowerShell/PowerShellEditorServices/issues/1477#issuecomment-863154520...seems like there's an incompatible version of Serilog in the GAC on these versions of Windows where it's failing, and that's getting picked up before our own, and we did bump the versions of Serilog twice.

In my opinion @JustinGrote and @SeeminglyScience we should dump Serilog and Microsoft.Extensions.Logging entirely, since we're required to keep it up-to-date, but doing so results in package incompatibles for 5.1 thanks to the GAC. We just need to minimize our dependencies entirely.

[JustinGrote]

@andyleejordan been working extensively on a logging rewrite on another branch, so I know a lot of the internals here.

MEL is part of the omnisharp LSP server so I don't think we can ditch that, but we can ditch serilog for sure in favor of a simple MEL fileprovider, or, in my model, I've been transitioning the logging to go over the LSP as logMessage once the bootstrap completes. MEL and Serilog both get ALC'd in PS7 but obviously not doable in 5.1

EDIT: I can write a provider for Rob's dependency-less bootstrap logger to continue file logging there to replace Serilog, since all it's used for is the file log (and logs would be duplicated after LSP startup, both local and remote, so we can probably reduce the severity to warning for the local log just to capture exceptions that would not make it over the LSP logger connection.

[andyleejordan]

Yeah, MEL looks like it will stick around for a bit. Serilog should really go though. While there are hits for Serilog in OmniSharp as far as I can tell they're only in tests, so if we get rid of it, I think it's gone.

I would much prefer logging over LSP anyway, and yes as you say, just keep a file (probably not even on by default?) for logs pre-LSP for when we need to debug that bit. If we make that diagnostic only it can probably be a dead simple file logger.

[andyleejordan]

Also we'd get to resolve PowerShell/PowerShellEditorServices#1477 since that IDisposable mess exists just thanks to Serilog being under the covers.

ALSO: We don't even use Serilog the way it's meant to be. It has all this purpose for structured logging and we just send it garbage.

[JustinGrote]

#2538 reopened for historical as well, should be addressed and closed with whatever PR fixes this.

[JustinGrote]

For anyone else potentially experiencing this issue, please capture a diagnostic trace and upload to this issue. If you aren't getting the MEL logger exception, your issue may be different, but this is most likely being caused by the Serilog version bump as @andyleejordan noted.

[JustinGrote]

Hopefully PowerShell/PowerShellEditorServices#2197 fixes this. In the meantime please downgrade to the previous version.

[JustinGrote]

Hey everyone, thanks for your patience, @andyleejordan should get out a preview release tomorrow that should have this fixed, we will notify here and if you still have issues let us know.

[jsantoro339as]

After updating the extension to the preview release I now get the following error

hell.EditorServices.Commands.StartEditorServicesCommand.EndProcessing()

== Press any key to close terminal ==
Start-EditorServices : Method not found: 'Microsoft.Extensions.Logging.ILoggerFactory Serialog.SerialogLoggerFactoryExtensions.AddSerialog(Microsoft.Extensions.Logging.ILoggerFactory, Serialog.ILogger, Boolean)'.
At line:1 char:148
+...ices.psd1'; Start-EditorServices -HostName 'Visual Studio Code Host' ...
+
+ CategoryInfo : NotSpecified: (Microsoft.Power...ServicesCommand:StartEditorServicesCommand) [Start-EditorServices], MissingMethodException
+ FullyQualifiedErrorId : PowerShellEditorServicesError,Microsoft.PowerShell.EditorServices.Commands.StartEditorServicesCommand

[JustinGrote]

@jsantoro339as the new prerelease hasn't been released yet, very soon! We ran into an internal verification build problem, I expect @andyleejordan will get that sorted today or tomorrow.

[JustinGrote]

It's out! Go to your extensions and choose "switch to pre-release" in the right click menu and let us know if this fixes it for you!

[jsantoro339as]

@JustinGrote Yes, I just updated it and it is working again. Thank you team, for addressing the issue and getting the fix out.

[andyleejordan]

So glad to hear it!

[andyleejordan]

Hey @ajacks88 @Azburkabas @Phillip-Ian the fix for this is in the pre-release version of the extension, can you all please give it a try? Thanks!