Simplify inherited `IDisposable` logic due to Serilog

[andyleejordan]

Noted in #1474, a bunch of our factories used to abstract our logging setup during initialization are IDisposable and so have to call each other's Dispose() methods, all due to the fact that we need to call Serilog.Log.CloseAndFlush() at the end of the program. This is actually a place where referencing a global is perhaps a better pattern, since the logger is already global, but Serilog provides an even better option by passing the parameter dispose=true when using SerilogLoggerFactoryExtensions.AddSerilog(dispose=true).

[dkattan]

When I run Start-EditorServices from my application, I get the following error:

ERROR: Exception encountered starting EditorServices. Exception logged in D:\a\1\s\src\PowerShellEditorServices.Hosting\Commands\StartEditorServicesCommand.cs on line 246 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 logPath, Int32 minimumLogLevel, IObservable`1 hostLogger)
   at Microsoft.PowerShell.EditorServices.Hosting.EditorServicesRunner..ctor(HostLogger logger, EditorServicesConfig config, ISessionFileWriter sessionFileWriter, IReadOnlyCollection`1 loggersToUnsubscribe) in D:\a\1\s\src\PowerShellEditorServices.Hosting\Internal\EditorServicesRunner.cs:line 45
   at Microsoft.PowerShell.EditorServices.Hosting.EditorServicesLoader.LoadAndRunEditorServicesAsync() in D:\a\1\s\src\PowerShellEditorServices.Hosting\EditorServicesLoader.cs:line 204
   at Microsoft.PowerShell.EditorServices.Commands.StartEditorServicesCommand.EndProcessing() in D:\a\1\s\src\PowerShellEditorServices.Hosting\Commands\StartEditorServicesCommand.cs:line 241

I’ve added the same 4 Serilog Nuget packages, including serilog.extensions.logging and it still happens.

The only workaround is to add the PowerShellEditorServices csproj to my Solution, and then add it as a Project Reference. If I add it to my solution but don’t add it as a project reference, the error occurs.

For context, this has been happening for at least a year, but I forgot about it until this week when changes were made which should allow me to use the production build of PSES.

I don’t know if the proposed changes here would solve my issue, but I didn’t want to make a new issue when there was already one discussing Serilog.

[rjmholt]

See https://github.com/PowerShell/vscode-powershell/issues/2538#issuecomment-596825533

[dkattan]

See PowerShell/vscode-powershell#2538 (comment)

Thank you, at least I'm not crazy or the only one with this issue.

Serilog is not in my GAC but it is being used in the calling application. I suspect that is the issue.

[andyleejordan]

Perhaps we should prioritize dumping Serilog 🤔

[dkattan]

Perhaps we should prioritize dumping Serilog 🤔

I probably could have removed it in less time than I've spent debugging this.

[dkattan]

Interestingly enough, somebody just put a Pull Request into Serilog.Extensions.Logging an hour ago that may address this issue.

What if the problem is that this particular interface doesn't get exposed when called from a parent process running an incompatible .net core version, in my case .net 5.0

[dkattan]

I removed all references to Serilog and am now getting

DEBUG: Loaded into load context "PsesLoadContext" Microsoft.PowerShell.EditorServices.Hosting.PsesLoadContext #1: Microsoft.Extensions.DependencyInjection.Abstractions, Version=5.0.0.0, Culture=neutral, PublicKeyToken=adb9793829ddae60
DEBUG: Loader disposed
ERROR: Exception encountered starting EditorServices. Exception logged in C:\Users\dkattan\Source\Repos\PowerShellEditorServices\src\PowerShellEditorServices.Hosting\Commands\StartEditorServicesCommand.cs on line 246 in EndProcessing:
System.EntryPointNotFoundException: Entry point was not found.
   at System.Collections.Generic.IEnumerable`1.GetEnumerator()
   at System.Linq.Enumerable.Any[TSource](IEnumerable`1 source, Func`2 predicate)
   at Microsoft.Extensions.DependencyInjection.Extensions.ServiceCollectionDescriptorExtensions.TryAdd(IServiceCollection collection, ServiceDescriptor descriptor)
   at Microsoft.Extensions.DependencyInjection.OptionsServiceCollectionExtensions.AddOptions(IServiceCollection services)
   at OmniSharp.Extensions.JsonRpc.JsonRpcOptionsRegistryBase`1..ctor()
   at OmniSharp.Extensions.JsonRpc.JsonRpcServerOptionsBase`1..ctor()
   at OmniSharp.Extensions.LanguageServer.Protocol.LanguageProtocolRpcOptionsBase`1..ctor()
   at OmniSharp.Extensions.LanguageServer.Server.LanguageServerOptions..ctor()
   at OmniSharp.Extensions.LanguageServer.Server.LanguageServer.From(Action`1 optionsAction, IServiceProvider outerServiceProvider, CancellationToken cancellationToken)
   at OmniSharp.Extensions.LanguageServer.Server.LanguageServer.From(Action`1 optionsAction)
   at Microsoft.PowerShell.EditorServices.Server.PsesLanguageServer.StartAsync() in C:\Users\dkattan\Source\Repos\PowerShellEditorServices\src\PowerShellEditorServices\Server\PsesLanguageServer.cs:line 69
   at Microsoft.PowerShell.EditorServices.Hosting.EditorServicesRunner.CreateEditorServicesAndRunUntilShutdown() in C:\Users\dkattan\Source\Repos\PowerShellEditorServices\src\PowerShellEditorServices.Hosting\Internal\EditorServicesRunner.cs:line 183
   at Microsoft.PowerShell.EditorServices.Commands.StartEditorServicesCommand.EndProcessing() in C:\Users\dkattan\Source\Repos\PowerShellEditorServices\src\PowerShellEditorServices.Hosting\Commands\StartEditorServicesCommand.cs:line 241

Digging deeper, I think the overall problem might be the version of Serilog and Microsoft.Extensions.Logging that Omnisharp is using: https://github.com/OmniSharp/csharp-language-server-protocol/blob/231a53f5e6f59fdca88478ed3f44f832d68491c1/Directory.Build.targets#L20

https://github.com/OmniSharp/csharp-language-server-protocol/blob/231a53f5e6f59fdca88478ed3f44f832d68491c1/Directory.Build.targets#L33

[andyleejordan]

Hm very interesting, especially since we apparently use vastly different versions:

https://github.com/PowerShell/PowerShellEditorServices/blob/da481f250473df2c7c87de445d20593803ee7b4d/src/PowerShellEditorServices/PowerShellEditorServices.csproj#L31

https://github.com/PowerShell/PowerShellEditorServices/blob/da481f250473df2c7c87de445d20593803ee7b4d/src/PowerShellEditorServices/PowerShellEditorServices.csproj#L36

[andyleejordan]

I probably could have removed it in less time than I've spent debugging this.

I would 💯accept a PR replacing Serilog @dkattan, looking into it myself.

[nblumhardt]

Open to helping resolve this if it turns out to be worthwhile - a bit swamped on the Serilog side of things, so would need some tactical PRs that don't introduce a huge amount of churn (which makes the one @dkattan linked above a bit tricky to move forward with in a hurry).

Unfortunately, with Serilog right down the bottom of the dependency graph, this stuff is never fun :-) ... good luck, either way! 👍

[dkattan]

I got it to work!

I added the following NuGet packages to my application

• Microsoft.Extensions.Logging.Abstractions Version=5.0.0
• OmniSharp.Extensions.DebugAdapter.Server Version=0.19.2
• OmniSharp.Extensions.LanguageServer Version=0.19.2
• Serilog.Sinks.Async Version=1.5.0
• System.IO.FileSystem.Primitives Version=4.3.0

Then deleted everything in module\PowerShellEditorServices\bin\Common except Microsoft.PowerShell.EditorServices.dll and magically everything worked.

I believe the problem here to be here

We aren't checking the loaded assemblies to verify that we actually need to load the files before loading them.

The tip off was me watching the ordering of the loaded assemblies when it worked versus when it didn't.

When it worked it loaded in this order

1. Microsoft.PowerShell.EditorServices.dll
2. System.IO.FileSystem.Primitives.dll
3. OmniSharp.Extensions.LanguageServer.dll
4. Nerdbank.Streams.dll
5. OmniSharp.Extensions.JsonRpc.dll
6. MediatR.dll
7. OmniSharp.Extensions.LanguageProtocol.dll
8. System.Resources.ResourceManager.dll
9. Microsoft.Bcl.AsyncInterfaces.dll
10. System.Reactive.dll
11. System.Threading.Timer.dll
12. OmniSharp.Extensions.LanguageServer.Shared.dll
13. Microsoft.PowerShell.PSReadLine2.dll

When it didn't

1. Microsoft.PowerShell.EditorServices.dll
2. Microsoft.Extensions.Logging.Abstractions.dll <-- Already loaded
3. Microsoft.Extensions.Logging.dll <-- Already loaded

It wasn't that it was loading the incorrect version, the versions were identical, I think it has to do with my calling context having already loaded Serilog and a variety of other assemblies, and PSES attempting to load them again.

I think if I modify the aforementioned code to check if the assembly is already loaded before calling LoadFromAssemblyPath, we'll be good.