Synchronize watched process and reporter output printing (#46141)

src/BuiltInTools/dotnet-watch/Internal/BrowserSpecificReporter.cs

@@ -1,8 +1,6 @@
 // Licensed to the .NET Foundation under one or more agreements.
 // The .NET Foundation licenses this file to you under the MIT license.
 
-using Microsoft.Build.Graph;
-
 namespace Microsoft.DotNet.Watch;
 
 internal sealed class BrowserSpecificReporter(int browserId, IReporter underlyingReporter) : IReporter
@@ -12,14 +10,8 @@ internal sealed class BrowserSpecificReporter(int browserId, IReporter underlyin
     public bool IsVerbose
         => underlyingReporter.IsVerbose;
 
-    public bool EnableProcessOutputReporting
-        => false;
-
-    public void ReportProcessOutput(ProjectGraphNode project, OutputLine line)
-        => throw new InvalidOperationException();
-
     public void ReportProcessOutput(OutputLine line)
-        => throw new InvalidOperationException();
+        => underlyingReporter.ReportProcessOutput(line);
 
     public void Report(MessageDescriptor descriptor, string prefix, object?[] args)
         => underlyingReporter.Report(descriptor, _prefix + prefix, args);

src/BuiltInTools/dotnet-watch/Internal/ConsoleReporter.cs

@@ -1,8 +1,6 @@
 // Licensed to the .NET Foundation under one or more agreements.
 // The .NET Foundation licenses this file to you under the MIT license.
 
-using Microsoft.Build.Graph;
-
 namespace Microsoft.DotNet.Watch
 {
     /// <summary>
@@ -15,16 +13,15 @@ internal sealed class ConsoleReporter(IConsole console, bool verbose, bool quiet
         public bool IsQuiet { get; } = quiet;
         public bool SuppressEmojis { get; } = suppressEmojis;
 
-        private readonly object _writeLock = new();
-
-        public bool EnableProcessOutputReporting
-            => false;
+        private readonly Lock _writeLock = new();
 
         public void ReportProcessOutput(OutputLine line)
-            => throw new InvalidOperationException();
-
-        public void ReportProcessOutput(ProjectGraphNode project, OutputLine line)
-            => throw new InvalidOperationException();
+        {
+            lock (_writeLock)
+            {
+                (line.IsError ? console.Error : console.Out).WriteLine(line.Content);
+            }
+        }
 
         private void WriteLine(TextWriter writer, string message, ConsoleColor? color, string emoji)
         {

src/BuiltInTools/dotnet-watch/Internal/IReporter.cs

@@ -86,13 +86,19 @@ public bool IsVerbose
             => false;
 
         /// <summary>
-        /// True to call <see cref="ReportProcessOutput"/> when launched process writes to standard output.
+        /// If true, the output of the process will be prefixed with the project display name.
         /// Used for testing.
         /// </summary>
-        bool EnableProcessOutputReporting { get; }
+        public bool PrefixProcessOutput
+            => false;
 
+        /// <summary>
+        /// Reports the output of a process that is being watched.
+        /// </summary>
+        /// <remarks>
+        /// Not used to report output of dotnet-build processed launched by dotnet-watch to build or evaluate projects.
+        /// </remarks>
         void ReportProcessOutput(OutputLine line);
-        void ReportProcessOutput(ProjectGraphNode project, OutputLine line);
 
         void Report(MessageDescriptor descriptor, params object?[] args)
             => Report(descriptor, prefix: "", args);

src/BuiltInTools/dotnet-watch/Internal/NullReporter.cs

@@ -1,8 +1,6 @@
 // Licensed to the .NET Foundation under one or more agreements.
 // The .NET Foundation licenses this file to you under the MIT license.
 
-using Microsoft.Build.Graph;
-
 namespace Microsoft.DotNet.Watch
 {
     /// <summary>
@@ -11,20 +9,15 @@ namespace Microsoft.DotNet.Watch
     /// </summary>
     internal sealed class NullReporter : IReporter
     {
-        private NullReporter()
-        { }
-
         public static IReporter Singleton { get; } = new NullReporter();
 
-        public bool EnableProcessOutputReporting
-            => false;
+        private NullReporter()
+        {
+        }
 
         public void ReportProcessOutput(OutputLine line)
-            => throw new InvalidOperationException();
-
-        public void ReportProcessOutput(ProjectGraphNode project, OutputLine line)
-            => throw new InvalidOperationException();
-
+        {
+        }
 
         public void Report(MessageDescriptor descriptor, string prefix, object?[] args)
         {

src/BuiltInTools/dotnet-watch/Internal/ProcessRunner.cs

@@ -31,11 +31,10 @@ public static async Task<int> RunAsync(ProcessSpec processSpec, IReporter report
 
             var onOutput = processSpec.OnOutput;
 
-            // allow tests to watch for application output:
-            if (reporter.EnableProcessOutputReporting)
-            {
-                onOutput += line => reporter.ReportProcessOutput(line);
-            }
+            // If output isn't already redirected (build invocation) we redirect it to the reporter.
+            // The reporter synchronizes the output of the process with the reporter output,
+            // so that the printed lines don't interleave.
+            onOutput ??= line => reporter.ReportProcessOutput(line);
 
             using var process = CreateProcess(processSpec, onOutput, state, reporter);
 
@@ -186,7 +185,7 @@ private static Process CreateProcess(ProcessSpec processSpec, Action<OutputLine>
                     FileName = processSpec.Executable,
                     UseShellExecute = false,
                     WorkingDirectory = processSpec.WorkingDirectory,
-                    RedirectStandardOutput =  onOutput != null,
+                    RedirectStandardOutput = onOutput != null,
                     RedirectStandardError = onOutput != null,
                 }
             };

src/BuiltInTools/dotnet-watch/Internal/ProjectSpecificReporter.cs

@@ -12,14 +12,9 @@ internal sealed class ProjectSpecificReporter(ProjectGraphNode node, IReporter u
     public bool IsVerbose
         => underlyingReporter.IsVerbose;
 
-    public bool EnableProcessOutputReporting
-        => underlyingReporter.EnableProcessOutputReporting;
-
-    public void ReportProcessOutput(ProjectGraphNode project, OutputLine line)
-        => underlyingReporter.ReportProcessOutput(project, line);
-
     public void ReportProcessOutput(OutputLine line)
-        => ReportProcessOutput(node, line);
+        => underlyingReporter.ReportProcessOutput(
+            underlyingReporter.PrefixProcessOutput ? line with { Content = $"[{_projectDisplayName}] {line.Content}" } : line);
 
     public void Report(MessageDescriptor descriptor, string prefix, object?[] args)
         => underlyingReporter.Report(descriptor, $"[{_projectDisplayName}] {prefix}", args);

test/dotnet-watch.Tests/HotReload/RuntimeProcessLauncherTests.cs

@@ -3,7 +3,6 @@
 
 #nullable enable
 
-using System.Collections.Immutable;
 using System.Runtime.CompilerServices;
 
 namespace Microsoft.DotNet.Watch.UnitTests;
@@ -142,6 +141,8 @@ public async Task UpdateAndRudeEdit(TriggerEvent trigger)
     {
         var testAsset = CopyTestAsset("WatchAppMultiProc", trigger);
 
+        var tfm = ToolsetInfo.CurrentTargetFramework;
+
         var workingDirectory = testAsset.Path;
         var hostDir = Path.Combine(testAsset.Path, "Host");
         var hostProject = Path.Combine(hostDir, "Host.csproj");
@@ -219,18 +220,18 @@ async Task MakeValidDependencyChange()
         {
             var hasUpdateSourceA = w.CreateCompletionSource();
             var hasUpdateSourceB = w.CreateCompletionSource();
-            w.Reporter.OnProjectProcessOutput += (projectPath, line) =>
+            w.Reporter.OnProcessOutput += line =>
             {
                 if (line.Content.Contains("<Updated Lib>"))
                 {
-                    if (projectPath == serviceProjectA)
+                    if (line.Content.StartsWith($"[A ({tfm})]"))
                     {
                         if (!hasUpdateSourceA.Task.IsCompleted)
                         {
                             hasUpdateSourceA.SetResult();
                         }
                     }
-                    else if (projectPath == serviceProjectB)
+                    else if (line.Content.StartsWith($"[B ({tfm})]"))
                     {
                         if (!hasUpdateSourceB.Task.IsCompleted)
                         {
@@ -239,7 +240,7 @@ async Task MakeValidDependencyChange()
                     }
                     else
                     {
-                        Assert.Fail("Only service projects should be updated");
+                        Assert.Fail($"Only service projects should be updated: '{line.Content}'");
                     }
                 }
             };
@@ -273,9 +274,9 @@ public static void Common()
         async Task MakeRudeEditChange()
         {
             var hasUpdateSource = w.CreateCompletionSource();
-            w.Reporter.OnProjectProcessOutput += (projectPath, line) =>
+            w.Reporter.OnProcessOutput += line =>
             {
-                if (projectPath == serviceProjectA && line.Content.Contains("Started A: 2"))
+                if (line.Content.StartsWith($"[A ({tfm})]") && line.Content.Contains("Started A: 2"))
                 {
                     hasUpdateSource.SetResult();
                 }
@@ -300,6 +301,7 @@ async Task MakeRudeEditChange()
     public async Task UpdateAppliedToNewProcesses(bool sharedOutput)
     {
         var testAsset = CopyTestAsset("WatchAppMultiProc", sharedOutput);
+        var tfm = ToolsetInfo.CurrentTargetFramework;
 
         if (sharedOutput)
         {
@@ -325,21 +327,21 @@ public async Task UpdateAppliedToNewProcesses(bool sharedOutput)
 
         var hasUpdateA = new SemaphoreSlim(initialCount: 0);
         var hasUpdateB = new SemaphoreSlim(initialCount: 0);
-        w.Reporter.OnProjectProcessOutput += (projectPath, line) =>
+        w.Reporter.OnProcessOutput += line =>
         {
             if (line.Content.Contains("<Updated Lib>"))
             {
-                if (projectPath == serviceProjectA)
+                if (line.Content.StartsWith($"[A ({tfm})]"))
                 {
                     hasUpdateA.Release();
                 }
-                else if (projectPath == serviceProjectB)
+                else if (line.Content.StartsWith($"[B ({tfm})]"))
                 {
                     hasUpdateB.Release();
                 }
                 else
                 {
-                    Assert.Fail("Only service projects should be updated");
+                    Assert.Fail($"Only service projects should be updated: '{line.Content}'");
                 }
             }
         };
@@ -398,6 +400,7 @@ public enum UpdateLocation
     public async Task HostRestart(UpdateLocation updateLocation)
     {
         var testAsset = CopyTestAsset("WatchAppMultiProc", updateLocation);
+        var tfm = ToolsetInfo.CurrentTargetFramework;
 
         var workingDirectory = testAsset.Path;
         var hostDir = Path.Combine(testAsset.Path, "Host");
@@ -414,17 +417,17 @@ public async Task HostRestart(UpdateLocation updateLocation)
         var restartRequested = w.Reporter.RegisterSemaphore(MessageDescriptor.RestartRequested);
 
         var hasUpdate = new SemaphoreSlim(initialCount: 0);
-        w.Reporter.OnProjectProcessOutput += (projectPath, line) =>
+        w.Reporter.OnProcessOutput += line =>
         {
             if (line.Content.Contains("<Updated>"))
             {
-                if (projectPath == hostProject)
+                if (line.Content.StartsWith($"[Host ({tfm})]"))
                 {
                     hasUpdate.Release();
                 }
                 else
                 {
-                    Assert.Fail("Only service projects should be updated");
+                    Assert.Fail($"Only service projects should be updated: '{line.Content}'");
                 }
             }
         };

test/dotnet-watch.Tests/MsBuildFileSetFactoryTest.cs

@@ -10,7 +10,7 @@ public class MsBuildFileSetFactoryTest(ITestOutputHelper output)
         private readonly TestReporter _reporter = new(output);
         private readonly TestAssetsManager _testAssets = new(output);
 
-        private string MuxerPath
+        private static string MuxerPath
             => TestContext.Current.ToolsetUnderTest.DotNetHostPath;
 
         private static string InspectPath(string path, string rootDir)
@@ -327,9 +327,6 @@ public async Task ProjectReferences_Graph()
 
             var options = TestOptions.GetEnvironmentOptions(workingDirectory: testDirectory, muxerPath: MuxerPath);
 
-            var output = new List<string>();
-            _reporter.OnProcessOutput += line => output.Add(line.Content);
-
             var filesetFactory = new MSBuildFileSetFactory(projectA, buildArguments: ["/p:_DotNetWatchTraceOutput=true"], options, _reporter);
 
             var result = await filesetFactory.TryCreateAsync(requireProjectGraph: null, CancellationToken.None);
@@ -365,7 +362,7 @@ public async Task ProjectReferences_Graph()
                     "Collecting watch items from 'F'",
                     "Collecting watch items from 'G'",
                 ],
-                output.Where(l => l.Contains("Collecting watch items from")).Select(l => l.Trim()).Order());
+                _reporter.Messages.Where(l => l.text.Contains("Collecting watch items from")).Select(l => l.text.Trim()).Order());
         }
 
         [Fact]
@@ -386,17 +383,14 @@ public async Task MsbuildOutput()
 
             var options = TestOptions.GetEnvironmentOptions(workingDirectory: Path.GetDirectoryName(project1Path)!, muxerPath: MuxerPath);
 
-            var output = new List<string>();
-            _reporter.OnProcessOutput += line => output.Add($"{(line.IsError ? "[stderr]" : "[stdout]")} {line.Content}");
-
             var factory = new MSBuildFileSetFactory(project1Path, buildArguments: [], options, _reporter);
             var result = await factory.TryCreateAsync(requireProjectGraph: null, CancellationToken.None);
             Assert.Null(result);
 
-            // note: msbuild prints errors to stdout:
+            // note: msbuild prints errors to stdout, we match the pattern and report as error:
             AssertEx.Equal(
-                $"[stdout] {project1Path} : error NU1201: Project Project2 is not compatible with net462 (.NETFramework,Version=v4.6.2). Project Project2 supports: netstandard2.1 (.NETStandard,Version=v2.1)",
-                output.Single(l => l.Contains("error NU1201")));
+                (MessageSeverity.Error, $"{project1Path} : error NU1201: Project Project2 is not compatible with net462 (.NETFramework,Version=v4.6.2). Project Project2 supports: netstandard2.1 (.NETStandard,Version=v2.1)"),
+                _reporter.Messages.Single(l => l.text.Contains("error NU1201")));
         }
 
         private Task<EvaluationResult> Evaluate(TestAsset projectPath)

test/dotnet-watch.Tests/Utilities/MockReporter.cs

@@ -3,21 +3,15 @@
 
 #nullable enable
 
-using Microsoft.Build.Graph;
-
 namespace Microsoft.DotNet.Watch.UnitTests;
 
 internal class MockReporter : IReporter
 {
     public readonly List<string> Messages = [];
 
-    public bool EnableProcessOutputReporting => false;
-
     public void ReportProcessOutput(OutputLine line)
-    => throw new InvalidOperationException();
-
-    public void ReportProcessOutput(ProjectGraphNode project, OutputLine line)
-        => throw new InvalidOperationException();
+    {
+    }
 
     public void Report(MessageDescriptor descriptor, string prefix, object?[] args)
     {