MSBuild_Logs directories created in source tree under normal operations

[ManickaP]

Recently when building specific test project (e.g. System.Net.Http.FunctionalTests) in https://github.com/dotnet/runtime, non-ignored MSBuild directories appear in my repository:

Common/tests/TestUtilities/MSBuild_Logs/
System.Net.Http/tests/FunctionalTests/MSBuild_Logs/

They contain files like:

MSBuild_pid-198959_a4f6509bcc1f4974a892834d2fe157c3.failure.txt

And the file content is:

UNHANDLED EXCEPTIONS FROM PROCESS 198959:
=====================
8/17/2021 8:40:20 PM
System.IO.IOException: Pipe is broken.
   at System.IO.Pipes.NamedPipeServerStream.CheckConnectOperationsServer()
   at System.IO.Pipes.NamedPipeServerStream.WaitForConnectionAsync(CancellationToken cancellationToken)
   at System.IO.Pipes.NamedPipeServerStream.WaitForConnectionAsync()
   at Microsoft.Build.BackEnd.NodeEndpointOutOfProcBase.PacketPumpProc()
===================

I do not have set any msbuild env vars in my environment, including MSBUILDDEBUGENGINE.

Might be related to #6639

OS: Linux x64

[ViktorHofer]

Happening for me as well locally.

[cdmihai]

@ViktorHofer, can you please describe your repro, and what OS it's on?

[ViktorHofer]

It happens randomly when building projects in dotnet/runtime with the dotnet.cmd wrapper script (which uses the RC1 repo local SDK instead of a globally installed one) on Windows.

Unfortunately don't have any more specific repro steps.

[rainersigwald]

My guess is these (benign?) crashes were happening all along, but the location changed. I think the location changing is bad and should be reverted (for the case where the user didn't opt into the MSBUILDDEBUGENGINE world).

[ViktorHofer]

That these crashes happened all along is my guess as well...

[rainersigwald]

We'll back the directory change out in #6787, but I'd like to know what's causing these crashes (I see them myself building the SDK repo).

[rainersigwald]

I'm actually seeing a different stack though. I'm on Windows:

UNHANDLED EXCEPTIONS FROM PROCESS 40100:
=====================
8/25/2021 9:34:36 AM
System.IO.IOException: Pipe is broken.
   at System.IO.Pipes.PipeStream.WriteAsyncCore(ReadOnlyMemory`1 buffer, CancellationToken cancellationToken) in System.IO.Pipes.dll:token 0x60000ec+0x33
   at System.IO.Pipes.PipeStream.WriteAsync(Byte[] buffer, Int32 offset, Int32 count, CancellationToken cancellationToken) in System.IO.Pipes.dll:token 0x60000e1+0x0
   at System.IO.Pipes.PipeStream.Write(Byte[] buffer, Int32 offset, Int32 count) in System.IO.Pipes.dll:token 0x60000df+0x0
   at Microsoft.Build.BackEnd.NodeEndpointOutOfProcBase.RunReadLoop(Stream localReadPipe, Stream localWritePipe, ConcurrentQueue`1 localPacketQueue, AutoResetEvent localPacketAvailable, AutoResetEvent localTerminatePacketPump) in Microsoft.Build.dll:token 0x600107a+0x1b8
===================

That makes it look like the scheduler node has exited while the worker still has packets that it is trying to send back. Maybe a rude exit, or a problem with ctrl-c cancellation of builds?

If it's a something-killed-the-scheduler situation, I don't know what we can do (other than swallowing the exception, but I'm not sure that's right: this shouldn't happen). But if it's that, why is it so common?

(Also it confused me for a while that RunReadLoop was doing a write operation; it should probably be renamed)