[Bug]: Build - Intermittent unit test failure from RunnerUtilities.RunProcessAndGetOutput() with stdout

[jrdodds]

Issue Description

This is an issue in the unit tests for the project.

There appears to be an issue with the unit test support method Microsoft.Build.UnitTests.Shared.RunnerUtilities.RunProcessAndGetOutput(). Intermittently on Windows, a unit test may fail to find the expected output. It appears that stdout is not completely captured before the process exits.

Steps to Reproduce

Currently there are no unit tests for the /preprocess and /targets switches that test the functionality¹. As part of the work for #7697 I am adding unit tests for the /preprocess and /targets switches for project files and for solution files.

I added the following unit test to src\MSBuild.UnitTests\XMake_Tests.cs:

        /// <summary>
        /// Given an empty project, the Preprocess switch should report an empty project.
        /// </summary>
        [Fact]
        public void PreprocessSwitchWithEmptyProject()
        {
            string[] arguments = { @"/pp", @"/nologo" };
            string project = @"<Project>" + Environment.NewLine + @"</Project>" + Environment.NewLine;
            string logContents = ExecuteMSBuildExeExpectSuccess(project, arguments: arguments);
            logContents.ShouldContain(@"<Project />");
        }

When running all unit tests from the command line (build.cmd -test) or in the Visual Studio Test Explorer, this unit test will sometimes fail on the logContents.ShouldContain(@"<Project />") verification because the output is missing from the string returned by ExecuteMSBuildExeExpectSuccess.

The call chain is
ExecuteMSBuildExeExpectSuccess -->
ExecuteMSBuildExe -->
RunnerUtilities.ExecMSBuild(string, out bool, ITestOutputHelper) -->
RunnerUtilities.ExecMSBuild(string, out bool, bool = false, ITestOutputHelper = null) -->
RunnerUtilities.RunProcessAndGetOutput

Expected Behavior

The unit test is expected to always succeed.

Actual Behavior

Intermittently the unit test will falsely fail.

(Unfortunately, the example unit test will probably not show the issue on the first attempt. 🙁)

Analysis

The issue happens on Windows 11 with both net7.0 and net472. On macOS 12 (Monterey) the issue doesn't present. I have not tested on Liunux.

The /preprocess and /targets switches differ from building a project because they write directly to Console.Out and don't use the configured logger(s).

In XMake.cs, as an experiment, I added explicit Flush() calls after the completion of the work for Preprocess and for Targets. This seemed to lessen the occurrence of the issue but it did not resolve the issue.

Versions & Configurations

No response

Footnotes

1. There are unit tests that test that the switches are recognized as part of handling the command line. ↩