LoggerException occurs when trying to use the same binary logger for evaluation and build

[RikkiGibson]

Context: The VS Code C# extension throws an exception when loading projects with setting "dotnet.projects.binaryLogPath" specified.

VS Code error log

2025-05-19 10:33:59.335 [info] [Error - 10:33:59 AM] [workspace/didChangeWatchedFiles] [LanguageServerProjectLoader] Error while loading c:\Users\rigibson\src\ConsoleApp5\Program.cs: Exception thrown: Microsoft.CodeAnalysis.MSBuild.RemoteInvocationException: An exception of type Microsoft.Build.Framework.LoggerException was thrown: Failed to write to log file "C:\Users\rigibson\AppData\Local\Programs\Microsoft VS Code\binlogs\LanguageServerDesignTimeBuild-df194f26-35a6-49fa-9bc4-a895752f774e-1.binlog". The process cannot access the file 'C:\Users\rigibson\AppData\Local\Programs\Microsoft VS Code\binlogs\LanguageServerDesignTimeBuild-df194f26-35a6-49fa-9bc4-a895752f774e-1.binlog' because it is being used by another process.
   at Microsoft.CodeAnalysis.MSBuild.RpcClient.InvokeCoreAsync(Int32 targetObject, String methodName, List`1 parameters, Type expectedReturnType, CancellationToken cancellationToken) in /_/src/Workspaces/MSBuild/Core/Rpc/RpcClient.cs:line 186
   at Microsoft.CodeAnalysis.MSBuild.RpcClient.InvokeAsync[T](Int32 targetObject, String methodName, List`1 parameters, CancellationToken cancellationToken) in /_/src/Workspaces/MSBuild/Core/Rpc/RpcClient.cs:line 135
   at Microsoft.CodeAnalysis.MSBuild.RemoteBuildHost.LoadProjectAsync(String projectFilePath, String projectContent, String languageName, CancellationToken cancellationToken) in /_/src/Workspaces/MSBuild/Core/Rpc/RemoteBuildHost.cs:line 41
   at Microsoft.CodeAnalysis.LanguageServer.HostWorkspace.FileBasedProgramsProjectSystem.TryLoadProjectInMSBuildHostAsync(BuildHostProcessManager buildHostProcessManager, String documentPath, CancellationToken cancellationToken) in /_/src/LanguageServer/Microsoft.CodeAnalysis.LanguageServer/HostWorkspace/FileBasedProgramsProjectSystem.cs:line 141
   at Microsoft.CodeAnalysis.LanguageServer.HostWorkspace.LanguageServerProjectLoader.ReloadProjectAsync(ProjectToLoad projectToLoad, ToastErrorReporter toastErrorReporter, BuildHostProcessManager buildHostProcessManager, CancellationToken cancellationToken) in /_/src/LanguageServer/Microsoft.CodeAnalysis.LanguageServer/HostWorkspace/LanguageServerProjectLoader.cs:line 208
2025-05-19 10:33:59.340 [info] [Info  - 10:33:59 AM] [workspace/didChangeWatchedFiles] [LanguageServerProjectLoader] Completed (re)load of all projects in 00:00:01.1469839
2025-05-19 10:33:59.341 [info] [Debug - 10:33:59 AM] [workspace/didChangeWatchedFiles] [BuildHost PID 10208] Sending a Shutdown request to the BuildHost.
2025-05-19 10:33:59.343 [info] [Error - 10:33:59 AM] [workspace/didChangeWatchedFiles] [BuildHost PID 10208] Exception while shutting down the BuildHost process. Microsoft.CodeAnalysis.MSBuild.RemoteInvocationException: An exception of type System.InvalidOperationException was thrown: Operation is not valid due to the current state of the object.
   at Microsoft.CodeAnalysis.MSBuild.RpcClient.InvokeCoreAsync(Int32 targetObject, String methodName, List`1 parameters, Type expectedReturnType, CancellationToken cancellationToken) in /_/src/Workspaces/MSBuild/Core/Rpc/RpcClient.cs:line 186
   at Microsoft.CodeAnalysis.MSBuild.BuildHostProcessManager.BuildHostProcess.DisposeAsync() in /_/src/Workspaces/MSBuild/Core/MSBuild/BuildHostProcessManager.cs:line 434
2025-05-19 10:33:59.343 [info] [Error - 10:33:59 AM] [workspace/didChangeWatchedFiles] 

What is happening is: BinaryLogger.Initialize is being called twice. Each time a write stream to the binlog file is opened. The second time, an IOException occurs because the first time locked the file.

Both calls to BinaryLogger.Initialize occur indirectly thru a single call to ProjectBuildManager.StartBatchBuild in Roslyn.

First call (thru ProjectBuildManager.cs#L231)

Microsoft.Build.dll!Microsoft.Build.Logging.BinaryLogger.Initialize(Microsoft.Build.Framework.IEventSource eventSource) Line 79	C#
Microsoft.Build.dll!Microsoft.Build.Evaluation.ProjectCollection.ReusableLogger.Initialize(Microsoft.Build.Framework.IEventSource eventSource, int nodeCount) Line 221	C#
Microsoft.Build.dll!Microsoft.Build.BackEnd.Logging.LoggingService.InitializeLogger(Microsoft.Build.Framework.ILogger logger, Microsoft.Build.Framework.IEventSource sourceForLogger) Line 982	C#
Microsoft.Build.dll!Microsoft.Build.BackEnd.Logging.LoggingService.RegisterDistributedLogger(Microsoft.Build.Framework.ILogger centralLogger, Microsoft.Build.Logging.LoggerDescription forwardingLogger) Line 578	C#
Microsoft.Build.dll!Microsoft.Build.BackEnd.Logging.LoggingService.RegisterLogger(Microsoft.Build.Framework.ILogger logger) Line 537	C#
Microsoft.Build.dll!Microsoft.Build.Evaluation.ProjectCollection.RegisterLoggerInternal(Microsoft.Build.Framework.ILogger logger) Line 1660	C#
Microsoft.Build.dll!Microsoft.Build.Evaluation.ProjectCollection.RegisterLoggers(System.Collections.Generic.IEnumerable<Microsoft.Build.Framework.ILogger> loggers) Line 1405	C#
Microsoft.Build.dll!Microsoft.Build.Evaluation.ProjectCollection.ProjectCollection(System.Collections.Generic.IDictionary<string, string> globalProperties, System.Collections.Generic.IEnumerable<Microsoft.Build.Framework.ILogger> loggers, System.Collections.Generic.IEnumerable<Microsoft.Build.Logging.ForwardingLoggerRecord> remoteLoggers, Microsoft.Build.Evaluation.ToolsetDefinitionLocations toolsetDefinitionLocations, int maxNodeCount, bool onlyLogCriticalEvents, bool loadProjectsReadOnly, bool useAsynchronousLogging, bool reuseProjectRootElementCache) Line 1127	C#
Microsoft.Build.dll!Microsoft.Build.Evaluation.ProjectCollection.ProjectCollection(System.Collections.Generic.IDictionary<string, string> globalProperties, System.Collections.Generic.IEnumerable<Microsoft.Build.Framework.ILogger> loggers, System.Collections.Generic.IEnumerable<Microsoft.Build.Logging.ForwardingLoggerRecord> remoteLoggers, Microsoft.Build.Evaluation.ToolsetDefinitionLocations toolsetDefinitionLocations, int maxNodeCount, bool onlyLogCriticalEvents, bool loadProjectsReadOnly) Line 1097	C#
Microsoft.Build.dll!Microsoft.Build.Evaluation.ProjectCollection.ProjectCollection(System.Collections.Generic.IDictionary<string, string> globalProperties, System.Collections.Generic.IEnumerable<Microsoft.Build.Framework.ILogger> loggers, System.Collections.Generic.IEnumerable<Microsoft.Build.Logging.ForwardingLoggerRecord> remoteLoggers, Microsoft.Build.Evaluation.ToolsetDefinitionLocations toolsetDefinitionLocations, int maxNodeCount, bool onlyLogCriticalEvents) Line 1092	C#
Microsoft.Build.dll!Microsoft.Build.Evaluation.ProjectCollection.ProjectCollection(System.Collections.Generic.IDictionary<string, string> globalProperties, System.Collections.Generic.IEnumerable<Microsoft.Build.Framework.ILogger> loggers, Microsoft.Build.Evaluation.ToolsetDefinitionLocations toolsetDefinitionLocations) Line 1080	C#
Microsoft.CodeAnalysis.Workspaces.MSBuild.BuildHost.dll!Microsoft.CodeAnalysis.MSBuild.ProjectBuildManager.StartBatchBuild(System.Collections.Generic.IDictionary<string, string> globalProperties) Line 231	C#
Microsoft.CodeAnalysis.Workspaces.MSBuild.BuildHost.dll!Microsoft.CodeAnalysis.MSBuild.BuildHost.CreateBuildManager() Line 122	C#
Microsoft.CodeAnalysis.Workspaces.MSBuild.BuildHost.dll!Microsoft.CodeAnalysis.MSBuild.BuildHost.LoadProjectCore(string projectFilePath, string projectContent, string languageName) Line 205	C#
Microsoft.CodeAnalysis.Workspaces.MSBuild.BuildHost.dll!Microsoft.CodeAnalysis.MSBuild.BuildHost.LoadProject(string projectFilePath, string projectContent, string languageName) Line 176	C#

Second call (thru ProjectBuildManager.cs#L243)

Microsoft.Build.dll!Microsoft.Build.Logging.BinaryLogger.Initialize(Microsoft.Build.Framework.IEventSource eventSource) Line 79	C#
Microsoft.Build.dll!Microsoft.Build.BackEnd.Logging.LoggingService.InitializeLogger(Microsoft.Build.Framework.ILogger logger, Microsoft.Build.Framework.IEventSource sourceForLogger) Line 986	C#
Microsoft.Build.dll!Microsoft.Build.BackEnd.Logging.LoggingService.RegisterDistributedLogger(Microsoft.Build.Framework.ILogger centralLogger, Microsoft.Build.Logging.LoggerDescription forwardingLogger) Line 578	C#
Microsoft.Build.dll!Microsoft.Build.BackEnd.Logging.LoggingService.RegisterLogger(Microsoft.Build.Framework.ILogger logger) Line 537	C#
Microsoft.Build.dll!Microsoft.Build.Execution.BuildManager.CreateLoggingService(System.Collections.Generic.IEnumerable<Microsoft.Build.Framework.ILogger> loggers, System.Collections.Generic.IEnumerable<Microsoft.Build.Logging.ForwardingLoggerRecord> forwardingLoggers, System.Collections.Generic.ISet<string> warningsAsErrors, System.Collections.Generic.ISet<string> warningsNotAsErrors, System.Collections.Generic.ISet<string> warningsAsMessages) Line 2000	C#
Microsoft.Build.dll!Microsoft.Build.Execution.BuildManager.BeginBuild.__InitializeLoggingService|64_0() Line 443	C#
Microsoft.Build.dll!Microsoft.Build.Execution.BuildManager.BeginBuild(Microsoft.Build.Execution.BuildParameters parameters) Line 360	C#
Microsoft.CodeAnalysis.Workspaces.MSBuild.BuildHost.dll!Microsoft.CodeAnalysis.MSBuild.ProjectBuildManager.StartBatchBuild(System.Collections.Generic.IDictionary<string, string> globalProperties) Line 243	C#
Microsoft.CodeAnalysis.Workspaces.MSBuild.BuildHost.dll!Microsoft.CodeAnalysis.MSBuild.BuildHost.CreateBuildManager() Line 122	C#
Microsoft.CodeAnalysis.Workspaces.MSBuild.BuildHost.dll!Microsoft.CodeAnalysis.MSBuild.BuildHost.LoadProjectCore(string projectFilePath, string projectContent, string languageName) Line 205	C#
Microsoft.CodeAnalysis.Workspaces.MSBuild.BuildHost.dll!Microsoft.CodeAnalysis.MSBuild.BuildHost.LoadProject(string projectFilePath, string projectContent, string languageName) Line 176	C#

From discussion with @dibarbet we believe this is a regression. In the past, the usage pattern shown in the linked code did not result in multiple initialization of the BinaryLogger. We were thus able to log both the evaluation and build of a project to the same binlog file at design time.

[baronfel]

What version of the MSBuild libraries are you using? I thought @surayya-MS had found/fixed a cause of multiple logger initialization a few weeks ago?

[RikkiGibson]

It looks like Roslyn's MSBuildHost uses MSBuildLocator which usually ends up loading the msbuild included in the SDK for the current project.

In my case, it was using SDK 10.0.100-preview.4.25204.5, and when I cracked the Microsoft.Build.dll in there, it had AssemblyInformationalVersion 17.15.0-preview-25203-02+06179d08bf90f1cdc6cc283b865adcdac457ea3c.

[surayya-MS]

@baronfel the fix you're talking about is in 17.14 18a02f8
It is not in 17.15 yet.
The problem there was that BinaryLogger was not attached. This issue looks different - BinaryLogger initialized twice

[YuliiaKovalova]

@RikkiGibson , could you please include repro steps to understand how to catch this exception on our machines?

[RikkiGibson]

My hope is that a unit test which imitates the usage pattern in StartBatchBuild will be enough to repro.

The way I happened to repro is (starting from VS Code with C#+DevKit latest stable installed):

• dotnet new console -o Repro
• Open Repro in VS Code
• Run command "Open Workspace Settings (JSON)"
• Insert the following

{
    "dotnet.projects.binaryLogPath": "C:/binlogs" // any absolute path you prefer will work
}

• Open Program.cs and wait a bit for the project to load. You may need to Reload Window to get the config changes to take effect.

You will get a popup saying C# projects failed to load, linking to logger output with stacks similar to the issue description.

Trouble with this way is, attaching to MSBuildHost is not straightforward. The only way I have done it, so far, is to build MSBuildHost from source. (Filed dotnet/roslyn#78654 to try and make this easier.)

FWIW, the Roslyn MSBuildHost uses MSBuildLocator to find the MSBuild it should use to build the user's project. So, if you know how to control which MSBuild it loads, you could possibly get it to load one that you built locally, which calls Debugger.Launch() when you want it to, or something similar.

[SimaTian]

Hello, I have a local reproduction and now I'm pondering about a fix. Your use case is perfectly reasonable and I believe we should support it. At the same time, I'm fairly sure it isn't a regression.
That being said I will do some more checks on an older branch - I have a suspicion that there might've been an error that dropped one of the binary loggers altogether.

Let me explain:
Binary logger as currently wired, doesn't support double initialization:

Microsoft.Build.dll!Microsoft.Build.Logging.BinaryLogger.Initialize(Microsoft.Build.Framework.IEventSource eventSource) Line 79	C#
Microsoft.Build.dll!Microsoft.Build.BackEnd.Logging.LoggingService.InitializeLogger(Microsoft.Build.Framework.ILogger logger, Microsoft.Build.Framework.IEventSource sourceForLogger) Line 986	C#
Microsoft.Build.dll!Microsoft.Build.BackEnd.Logging.LoggingService.RegisterDistributedLogger(Microsoft.Build.Framework.ILogger centralLogger, Microsoft.Build.Logging.LoggerDescription forwardingLogger) Line 578	C#

The missing link is the

Microsoft.Build.dll!Microsoft.Build.Evaluation.ProjectCollection.ReusableLogger.Initialize(Microsoft.Build.Framework.IEventSource eventSource, int nodeCount) Line 221	C#

Combined with the comment in Roslyn's Project Manager:
// The loggers are not inherited from the project collection, so specify both the
// binlog logger and the _batchBuildLogger for the build steps.

So Roslyn is passing the raw BinaryLogger, which doesn't support double initialization (and as far as I have checked, it never did - that particular piece of code is untouched since it's inception)

• if the path to log is specified, it will attempt to double-open a file and crash.
• if the path is not specified, it generates a random one so these don't clash and you end up with two separate binary logs.

Now how to fix it.

• I will discuss with team if there is something preventing us from exposing the ReusableLogger as a part of public API.
  • you could then do something like var msbuildLogger = new ProjectCollection.ReusableLogger(new BinaryLogger());
  • it is kind of weird, since it doubly-wraps the binary logger in a ReusableLogger during the evaluation step, but it works and it should have no performance impact.
  • it would require a minor change on our side and a minor change on your side.
• If you don't want to wait until we get the change in and roll it out, you can implement a ReusableLogger on your own - see ReusableLogger
  • Unfortunately the class is kind of clunky. Maybe there is a slimmer way to achieve the same thing for you scenario.
• We could maybe start doing the whole "inheriting the loggers from collection"
  • However I suspect that this is a can of worms that could spiral quite quickly.
• We could rewire the binaryLogger to support double initialization via append into the same file, similarly to what the ReusableLogger currently does.

I will update as soon as I have more information.

[SimaTian]

I checked out main branch for early-december end early november last year and the behavior is consistent - e.g. failing due to locked file.

[RikkiGibson]

Makes sense! Thank you for taking a look.

Making the logger support double initialization is going to be easiest for us, but, we might be able to call a ReusableLogger API via light-up (reflection or something), if that ends up being the preferred direction.

I think it would be some time before our MSBuildHost could directly reference an msbuild which has such a new API. I think the older versions would need to fall out of support--since our host needs to be able to load and use whichever msbuild is appropriate based on the user's installed SDK/global.json setup.

@dibarbet @JoeRobich for visibility.