Fix flaky WhenSpecificDataSourceIsIgnoredViaIgnoreMessageProperty

src/Platform/Microsoft.Testing.Platform/Helpers/System/SystemConsole.cs

@@ -8,6 +8,8 @@ internal sealed class SystemConsole : IConsole
     private const int WriteBufferSize = 256;
     private static readonly StreamWriter CaptureConsoleOutWriter;
 
+    internal static TextWriter ConsoleOut { get; }
+
     /// <summary>
     /// Gets the height of the buffer area.
     /// </summary>
@@ -25,16 +27,21 @@ internal sealed class SystemConsole : IConsole
 
     private bool _suppressOutput;
 
-    static SystemConsole() =>
+    static SystemConsole()
+    {
+        // This is the console that the ITerminal will be writing to.
+        // So, this is what NonAnsiTerminal need to "lock" on regardless of whether it changed later.
+        ConsoleOut = Console.Out;
         // From https://github.com/dotnet/runtime/blob/main/src/libraries/System.Console/src/System/Console.cs#L236
         CaptureConsoleOutWriter = new StreamWriter(
             stream: Console.OpenStandardOutput(),
-            encoding: Console.Out.Encoding,
+            encoding: ConsoleOut.Encoding,
             bufferSize: WriteBufferSize,
             leaveOpen: true)
         {
             AutoFlush = true,
         };
+    }
 
     // the following event does not make sense in the mobile scenarios, user cannot ctrl+c
     // but can just kill the app in the device via a gesture

src/Platform/Microsoft.Testing.Platform/OutputDevice/Terminal/NonAnsiTerminal.cs

@@ -14,7 +14,6 @@ internal sealed class NonAnsiTerminal : ITerminal
 {
     private readonly IConsole _console;
     private readonly ConsoleColor _defaultForegroundColor;
-    private readonly StringBuilder _stringBuilder = new();
     private bool _isBatching;
 
     public NonAnsiTerminal(IConsole console)
@@ -28,52 +27,16 @@ public NonAnsiTerminal(IConsole console)
     public int Height => _console.IsOutputRedirected ? int.MaxValue : _console.BufferHeight;
 
     public void Append(char value)
-    {
-        if (_isBatching)
-        {
-            _stringBuilder.Append(value);
-        }
-        else
-        {
-            _console.Write(value);
-        }
-    }
+        => _console.Write(value);
 
     public void Append(string value)
-    {
-        if (_isBatching)
-        {
-            _stringBuilder.Append(value);
-        }
-        else
-        {
-            _console.Write(value);
-        }
-    }
+        => _console.Write(value);
 
     public void AppendLine()
-    {
-        if (_isBatching)
-        {
-            _stringBuilder.AppendLine();
-        }
-        else
-        {
-            _console.WriteLine();
-        }
-    }
+        => _console.WriteLine();
 
     public void AppendLine(string value)
-    {
-        if (_isBatching)
-        {
-            _stringBuilder.AppendLine(value);
-        }
-        else
-        {
-            _console.WriteLine(value);
-        }
-    }
+        => _console.WriteLine(value);
 
     public void AppendLink(string path, int? lineNumber)
     {
@@ -85,26 +48,10 @@ public void AppendLink(string path, int? lineNumber)
     }
 
     public void SetColor(TerminalColor color)
-    {
-        if (_isBatching)
-        {
-            _console.Write(_stringBuilder.ToString());
-            _stringBuilder.Clear();
-        }
-
-        _console.SetForegroundColor(ToConsoleColor(color));
-    }
+        => _console.SetForegroundColor(ToConsoleColor(color));
 
     public void ResetColor()
-    {
-        if (_isBatching)
-        {
-            _console.Write(_stringBuilder.ToString());
-            _stringBuilder.Clear();
-        }
-
-        _console.SetForegroundColor(_defaultForegroundColor);
-    }
+        => _console.SetForegroundColor(_defaultForegroundColor);
 
     public void ShowCursor()
     {
@@ -116,20 +63,48 @@ public void HideCursor()
         // nop
     }
 
+    // TODO: Refactor NonAnsiTerminal and AnsiTerminal such that we don't need StartUpdate/StopUpdate.
+    // It's much better if we use lock C# keyword instead of manually calling Monitor.Enter/Exit
+    // Using lock also ensures we don't accidentally have `await`s in between that could cause Exit to be on a different thread.
     public void StartUpdate()
     {
         if (_isBatching)
         {
             throw new InvalidOperationException(PlatformResources.ConsoleIsAlreadyInBatchingMode);
         }
 
-        _stringBuilder.Clear();
+        bool lockTaken = false;
+        // SystemConsole.ConsoleOut is set only once in static ctor.
+        // So we are sure we will be doing Monitor.Exit on the same instance.
+        // Note that we need to lock on System.Out for batching to work correctly.
+        // Consider the following scenario:
+        // 1. We call StartUpdate
+        // 2. We call a Write("A")
+        // 3. User calls Console.Write("B") from another thread.
+        // 4. We call a Write("C").
+        // 5. We call StopUpdate.
+        // The expectation is that we see either ACB, or BAC, but not ABC.
+        // Basically, when doing batching, we want to ensure that everything we write is
+        // written continuously, without anything in-between.
+        // One option (and we used to do it), is that we append to a StringBuilder while batching
+        // Then at StopUpdate, we write the whole string at once.
+        // This works to some extent, but we cannot get it to work when SetColor kicks in.
+        // Console methods will internally lock on Console.Out, so we are locking on the same thing.
+        // This locking is the easiest way to get coloring to work correctly while preventing
+        // interleaving with user's calls to Console.Write methods.
+        Monitor.Enter(SystemConsole.ConsoleOut, ref lockTaken);
+        if (!lockTaken)
+        {
+            // Can this happen? :/
+            throw new InvalidOperationException();
+        }
+
         _isBatching = true;
     }
 
     public void StopUpdate()
     {
-        _console.Write(_stringBuilder.ToString());
+        Monitor.Exit(SystemConsole.ConsoleOut);
         _isBatching = false;
     }
 

test/IntegrationTests/MSTest.Acceptance.IntegrationTests/IgnoreTests.cs

@@ -66,55 +66,35 @@ public async Task WhenSpecificDataSourceIsIgnoredViaIgnoreMessageProperty()
 
         // Assert
         testHostResult.AssertExitCodeIs(ExitCodes.Success);
-        testHostResult.AssertOutputContains("""
-            TestInitialize: TestMethod1 (0)
-            TestCleanup: TestMethod1 (0)
-            """);
-
-        testHostResult.AssertOutputContains("""
-            TestInitialize: TestMethod1 (2)
-            TestCleanup: TestMethod1 (2)
-            """);
-
-        testHostResult.AssertOutputContains("""
-            TestInitialize: TestMethod2 (0)
-            TestCleanup: TestMethod2 (0)
-            """);
-
-        testHostResult.AssertOutputContains("""
-            TestInitialize: TestMethod2 (1)
-            TestCleanup: TestMethod2 (1)
-            """);
-
-        testHostResult.AssertOutputContains("""
-            TestInitialize: TestMethod2 (2)
-            TestCleanup: TestMethod2 (2)
-            """);
-
-        testHostResult.AssertOutputContains("""
-            TestInitialize: TestMethod3 (0)
-            TestCleanup: TestMethod3 (0)
-            """);
-
-        testHostResult.AssertOutputContains("""
-            TestInitialize: TestMethod3 (2)
-            TestCleanup: TestMethod3 (2)
-            """);
-
-        testHostResult.AssertOutputContains("""
-            TestInitialize: TestMethod4 (0)
-            TestCleanup: TestMethod4 (0)
-            """);
-
-        testHostResult.AssertOutputContains("""
-            TestInitialize: TestMethod4 (1)
-            TestCleanup: TestMethod4 (1)
-            """);
-
-        testHostResult.AssertOutputContains("""
-            TestInitialize: TestMethod4 (2)
-            TestCleanup: TestMethod4 (2)
-            """);
+        testHostResult.AssertOutputContains("TestInitialize: TestMethod1 (0)");
+        testHostResult.AssertOutputContains("TestCleanup: TestMethod1 (0)");
+
+        testHostResult.AssertOutputContains("TestInitialize: TestMethod1 (2)");
+        testHostResult.AssertOutputContains("TestCleanup: TestMethod1 (2)");
+
+        testHostResult.AssertOutputContains("TestInitialize: TestMethod2 (0)");
+        testHostResult.AssertOutputContains("TestCleanup: TestMethod2 (0)");
+
+        testHostResult.AssertOutputContains("TestInitialize: TestMethod2 (1)");
+        testHostResult.AssertOutputContains("TestCleanup: TestMethod2 (1)");
+
+        testHostResult.AssertOutputContains("TestInitialize: TestMethod2 (2)");
+        testHostResult.AssertOutputContains("TestCleanup: TestMethod2 (2)");
+
+        testHostResult.AssertOutputContains("TestInitialize: TestMethod3 (0)");
+        testHostResult.AssertOutputContains("TestCleanup: TestMethod3 (0)");
+
+        testHostResult.AssertOutputContains("TestInitialize: TestMethod3 (2)");
+        testHostResult.AssertOutputContains("TestCleanup: TestMethod3 (2)");
+
+        testHostResult.AssertOutputContains("TestInitialize: TestMethod4 (0)");
+        testHostResult.AssertOutputContains("TestCleanup: TestMethod4 (0)");
+
+        testHostResult.AssertOutputContains("TestInitialize: TestMethod4 (1)");
+        testHostResult.AssertOutputContains("TestCleanup: TestMethod4 (1)");
+
+        testHostResult.AssertOutputContains("TestInitialize: TestMethod4 (2)");
+        testHostResult.AssertOutputContains("TestCleanup: TestMethod4 (2)");
 
         testHostResult.AssertOutputContains("skipped TestMethod1");
         testHostResult.AssertOutputContains("skipped TestMethod2");