Pipe is broken exception in MSBuildWorkspace tests #77040
Description
We're seeing this randomly in CI, often in our Spanish queue:
System.AggregateException : An error occurred while writing to logger(s). (Workspace failure Failure:[BuildHost PID 996] Exception while shutting down the BuildHost process.
System.IO.IOException: Pipe is broken.
at System.IO.Pipes.PipeStream.CheckWriteOperations()
at System.IO.Pipes.PipeStream.FlushAsync(CancellationToken cancellationToken)
--- End of stack trace from previous location ---
at System.IO.StreamWriter.<FlushAsyncInternal>g__Core|79_0(Boolean flushStream, Boolean flushEncoder, CancellationToken cancellationToken)
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 166
at Microsoft.CodeAnalysis.MSBuild.BuildHostProcessManager.BuildHostProcess.DisposeAsync() in /_/src/Workspaces/MSBuild/Core/MSBuild/BuildHostProcessManager.cs:line 434)
---- System.Exception : Workspace failure Failure:[BuildHost PID 996] Exception while shutting down the BuildHost process.
System.IO.IOException: Pipe is broken.
at System.IO.Pipes.PipeStream.CheckWriteOperations()
at System.IO.Pipes.PipeStream.FlushAsync(CancellationToken cancellationToken)
--- End of stack trace from previous location ---
at System.IO.StreamWriter.<FlushAsyncInternal>g__Core|79_0(Boolean flushStream, Boolean flushEncoder, CancellationToken cancellationToken)
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 166
at Microsoft.CodeAnalysis.MSBuild.BuildHostProcessManager.BuildHostProcess.DisposeAsync() in /_/src/Workspaces/MSBuild/Core/MSBuild/BuildHostProcessManager.cs:line 434
Seguimiento de la pila:
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.LoggerExtensions.Log(ILogger logger, LogLevel logLevel, EventId eventId, Exception exception, String message, Object[] args)
at Microsoft.Extensions.Logging.LoggerExtensions.Log(ILogger logger, LogLevel logLevel, Exception exception, String message, Object[] args)
at Microsoft.Extensions.Logging.LoggerExtensions.LogError(ILogger logger, Exception exception, String message, Object[] args)
at Microsoft.CodeAnalysis.MSBuild.BuildHostProcessManager.BuildHostProcess.DisposeAsync() in /_/src/Workspaces/MSBuild/Core/MSBuild/BuildHostProcessManager.cs:line 443
at Microsoft.CodeAnalysis.MSBuild.BuildHostProcessManager.DisposeAsync() in /_/src/Workspaces/MSBuild/Core/MSBuild/BuildHostProcessManager.cs:line 162
at Microsoft.CodeAnalysis.MSBuild.MSBuildProjectLoader.LoadProjectInfoAsync(String projectFilePath, ProjectMap projectMap, IProgress`1 progress, ILogger msbuildLogger, CancellationToken cancellationToken) in /_/src/Workspaces/MSBuild/Core/MSBuild/MSBuildProjectLoader.cs:line 295
at Microsoft.CodeAnalysis.MSBuild.MSBuildWorkspace.OpenProjectAsync(String projectFilePath, ILogger msbuildLogger, IProgress`1 progress, CancellationToken cancellationToken) in /_/src/Workspaces/MSBuild/Core/MSBuild/MSBuildWorkspace.cs:line 251
at Microsoft.CodeAnalysis.MSBuild.UnitTests.NetCoreTests.TestOpenProject_NetCoreApp() in /_/src/Workspaces/MSBuild/Test/NetCoreTests.cs:line 80
--- End of stack trace from previous location ---
----- Inner Stack Trace -----
at Microsoft.CodeAnalysis.MSBuild.UnitTests.MSBuildWorkspaceTestBase.<>c.<CreateMSBuildWorkspace>b__14_0(Object s, WorkspaceDiagnosticEventArgs e) in /_/src/Workspaces/MSBuild/Test/MSBuildWorkspaceTestBase.cs:line 154
at Microsoft.CodeAnalysis.Workspace.<>c.<OnWorkspaceFailed>b__242_0(EventHandler`1 handler, ValueTuple`2 arg) in /_/src/Workspaces/Core/Portable/Workspace/Workspace_Events.cs:line 103
at Roslyn.Utilities.EventMap.Registry`1.Invoke[TArg](Action`2 invoker, TArg arg) in /_/src/Workspaces/SharedUtilitiesAndExtensions/Compiler/Core/Utilities/EventMap.cs:line 109
at Roslyn.Utilities.EventMap.EventHandlerSet`1.RaiseEvent[TArg](Action`2 invoker, TArg arg) in /_/src/Workspaces/SharedUtilitiesAndExtensions/Compiler/Core/Utilities/EventMap.cs:line 170
at Microsoft.CodeAnalysis.Workspace.OnWorkspaceFailed(WorkspaceDiagnostic diagnostic) in /_/src/Workspaces/Core/Portable/Workspace/Workspace_Events.cs:line 103
at Microsoft.CodeAnalysis.MSBuild.MSBuildWorkspace.OnWorkspaceFailed(WorkspaceDiagnostic diagnostic) in /_/src/Workspaces/MSBuild/Core/MSBuild/MSBuildWorkspace.cs:line 110
at Microsoft.CodeAnalysis.MSBuild.DiagnosticReporter.Report(WorkspaceDiagnostic diagnostic) in /_/src/Workspaces/MSBuild/Core/MSBuild/DiagnosticReporter.cs:line 54
at Microsoft.CodeAnalysis.MSBuild.DiagnosticReporterLoggerProvider.Logger.Log[TState](LogLevel logLevel, EventId eventId, TState state, Exception exception, Func`3 formatter) in /_/src/Workspaces/MSBuild/Core/MSBuild/DiagnosticReporterLoggerProvider.cs:line 59
The stack here is a bit confusing to diagnose, so here's the series of events:
- We are trying to shut down the BuildHost process. While we are calling Dispose on the BuildHostProcess here:
- This causes us to call into the build host to tell it to shut down here:
roslyn/src/Workspaces/MSBuild/Core/MSBuild/BuildHostProcessManager.cs
Lines 428 to 448 in 40ec700
- That call to the build host threw a "Pipe is broken" IO exception.
- That exception was caught, and the _logger?.LogError() above runs.
- The logger we create in MSBuildWorkspace raises this as a WorkspaceFailed event.
- The unit tests hook WorkspaceFailed, and throw an exception here:
- Microsoft.Extensions.Logging then catches that exception and throws a new exception saying an error occurred while writing to the logger, with the Exception thrown in WorkspaceFailed being the inner exception.
It's unclear from me if something caused the pipe to break first, or simply the other process is shutting down and we're converting a failure in that case that's expected to something that's unexpected. We could replace that LogError with a LogTrace or something that won't raise WorkspaceFailed, but that might be masking the root cause here.