[dotnet-watch] Misc test fixes (#45575)

tmat · tmat · commit 91f9c5e878b8 · 2025-01-06T15:15:00.000-08:00
diff --git a/src/BuiltInTools/dotnet-watch/HotReloadDotNetWatcher.cs b/src/BuiltInTools/dotnet-watch/HotReloadDotNetWatcher.cs
@@ -121,9 +121,10 @@ public override async Task WatchAsync(CancellationToken shutdownCancellationToke
                         };
                     }
 
-                    if (!await BuildProjectAsync(rootProjectOptions.ProjectPath, rootProjectOptions.BuildArguments, iterationCancellationToken))
+                    var (buildSucceeded, buildOutput, _) = await BuildProjectAsync(rootProjectOptions.ProjectPath, rootProjectOptions.BuildArguments, iterationCancellationToken);
+                    BuildUtilities.ReportBuildOutput(Context.Reporter, buildOutput, buildSucceeded, projectDisplay: rootProjectOptions.ProjectPath);
+                    if (!buildSucceeded)
                     {
-                        // error has been reported:
                         continue;
                     }
 
@@ -334,7 +335,12 @@ void FileChangedCallback(ChangedPath change)
                                     var buildResults = await Task.WhenAll(
                                         projectsToRebuild.Values.Select(projectPath => BuildProjectAsync(projectPath, rootProjectOptions.BuildArguments, iterationCancellationToken)));
 
-                                    if (buildResults.All(success => success))
+                                    foreach (var (success, output, projectPath) in buildResults)
+                                    {
+                                        BuildUtilities.ReportBuildOutput(Context.Reporter, output, success, projectPath);
+                                    }
+
+                                    if (buildResults.All(result => result.success))
                                     {
                                         break;
                                     }
@@ -815,7 +821,8 @@ await FileWatcher.WaitForFileChangeAsync(
             }
         }
 
-        private async Task<bool> BuildProjectAsync(string projectPath, IReadOnlyList<string> buildArguments, CancellationToken cancellationToken)
+        private async Task<(bool success, ImmutableArray<OutputLine> output, string projectPath)> BuildProjectAsync(
+            string projectPath, IReadOnlyList<string> buildArguments, CancellationToken cancellationToken)
         {
             var buildOutput = new List<OutputLine>();
 
@@ -834,17 +841,10 @@ private async Task<bool> BuildProjectAsync(string projectPath, IReadOnlyList<str
                 Arguments = ["build", projectPath, "-consoleLoggerParameters:NoSummary;Verbosity=minimal", .. buildArguments]
             };
 
-            Context.Reporter.Output($"Building '{projectPath}' ...");
+            Context.Reporter.Output($"Building {projectPath} ...");
 
             var exitCode = await ProcessRunner.RunAsync(processSpec, Context.Reporter, isUserApplication: false, launchResult: null, cancellationToken);
-            BuildUtilities.ReportBuildOutput(Context.Reporter, buildOutput, verboseOutput: exitCode == 0);
-
-            if (exitCode == 0)
-            {
-                Context.Reporter.Output("Build succeeded.");
-            }
-
-            return exitCode == 0;
+            return (exitCode == 0, buildOutput.ToImmutableArray(), projectPath);
         }
 
         private string GetRelativeFilePath(string path)
diff --git a/src/BuiltInTools/dotnet-watch/Internal/MsBuildFileSetFactory.cs b/src/BuiltInTools/dotnet-watch/Internal/MsBuildFileSetFactory.cs
@@ -63,7 +63,7 @@ internal class MSBuildFileSetFactory(
                     reporter.Output($"MSBuild output from target '{TargetName}':");
                 }
 
-                BuildUtilities.ReportBuildOutput(reporter, capturedOutput, verboseOutput: success);
+                BuildUtilities.ReportBuildOutput(reporter, capturedOutput, success, projectDisplay: null);
                 if (!success)
                 {
                     return null;
diff --git a/src/BuiltInTools/dotnet-watch/Internal/ProcessRunner.cs b/src/BuiltInTools/dotnet-watch/Internal/ProcessRunner.cs
@@ -87,6 +87,15 @@ public static async Task<int> RunAsync(ProcessSpec processSpec, IReporter report
                 try
                 {
                     await process.WaitForExitAsync(processTerminationToken);
+
+                    // ensures that all process output has been reported:
+                    try
+                    {
+                        process.WaitForExit();
+                    }
+                    catch
+                    {
+                    }
                 }
                 catch (OperationCanceledException)
                 {
diff --git a/src/BuiltInTools/dotnet-watch/Utilities/BuildUtilities.cs b/src/BuiltInTools/dotnet-watch/Utilities/BuildUtilities.cs
@@ -7,14 +7,25 @@ namespace Microsoft.DotNet.Watch;
 
 internal static partial class BuildUtilities
 {
+    private const string BuildEmoji = "🔨";
     private static readonly Regex s_buildDiagnosticRegex = GetBuildDiagnosticRegex();
 
     [GeneratedRegex(@"[^:]+: (error|warning) [A-Za-z]+[0-9]+: .+")]
     private static partial Regex GetBuildDiagnosticRegex();
 
-    public static void ReportBuildOutput(IReporter reporter, IEnumerable<OutputLine> buildOutput, bool verboseOutput)
+    public static void ReportBuildOutput(IReporter reporter, IEnumerable<OutputLine> buildOutput, bool success, string? projectDisplay)
     {
-        const string BuildEmoji = "🔨";
+        if (projectDisplay != null)
+        {
+            if (success)
+            {
+                reporter.Output($"Build succeeded: {projectDisplay}", BuildEmoji);
+            }
+            else
+            {
+                reporter.Output($"Build failed: {projectDisplay}", BuildEmoji);
+            }
+        }
 
         foreach (var (line, isError) in buildOutput)
         {
@@ -33,7 +44,7 @@ public static void ReportBuildOutput(IReporter reporter, IEnumerable<OutputLine>
                     reporter.Warn(line);
                 }
             }
-            else if (verboseOutput)
+            else if (success)
             {
                 reporter.Verbose(line, BuildEmoji);
             }
diff --git a/test/dotnet-watch.Tests/HotReload/ApplyDeltaTests.cs b/test/dotnet-watch.Tests/HotReload/ApplyDeltaTests.cs
@@ -249,9 +249,8 @@ class AppUpdateHandler
 
             await App.AssertOutputLineStartsWith("Updated");
 
-            AssertEx.Contains(
-                "dotnet watch ⚠ [WatchHotReloadApp (net9.0)] Expected to find a static method 'ClearCache' or 'UpdateApplication' on type 'AppUpdateHandler, WatchHotReloadApp, Version=1.0.0.0, Culture=neutral, PublicKeyToken=null' but neither exists.",
-                App.Process.Output);
+            await App.WaitUntilOutputContains(
+                $"dotnet watch ⚠ [WatchHotReloadApp ({ToolsetInfo.CurrentTargetFramework})] Expected to find a static method 'ClearCache' or 'UpdateApplication' on type 'AppUpdateHandler, WatchHotReloadApp, Version=1.0.0.0, Culture=neutral, PublicKeyToken=null' but neither exists.");
         }
 
         [Theory]
@@ -290,13 +289,11 @@ class AppUpdateHandler
 
             await App.AssertOutputLineStartsWith("Updated");
 
-            AssertEx.Contains(
-                "dotnet watch ⚠ [WatchHotReloadApp (net9.0)] Exception from 'System.Action`1[System.Type[]]': System.InvalidOperationException: Bug!",
-                App.Process.Output);
+            await App.WaitUntilOutputContains($"dotnet watch ⚠ [WatchHotReloadApp ({ToolsetInfo.CurrentTargetFramework})] Exception from 'System.Action`1[System.Type[]]': System.InvalidOperationException: Bug!");
 
             if (verbose)
             {
-                AssertEx.Contains("dotnet watch 🕵️ [WatchHotReloadApp (net9.0)] Deltas applied.", App.Process.Output);
+                await App.WaitUntilOutputContains($"dotnet watch 🕵️ [WatchHotReloadApp ({ToolsetInfo.CurrentTargetFramework})] Deltas applied.");
             }
             else
             {
@@ -352,7 +349,7 @@ public async Task BlazorWasm(bool projectSpecifiesCapabilities)
                 """;
 
             UpdateSourceFile(Path.Combine(testAsset.Path, "Pages", "Index.razor"), newSource);
-            await App.AssertOutputLineStartsWith(MessageDescriptor.HotReloadSucceeded, "blazorwasm (net9.0)");
+            await App.AssertOutputLineStartsWith(MessageDescriptor.HotReloadSucceeded, $"blazorwasm ({ToolsetInfo.CurrentTargetFramework})");
 
             // check project specified capapabilities:
             if (projectSpecifiesCapabilities)
@@ -415,8 +412,8 @@ public async Task Razor_Component_ScopedCssAndStaticAssets()
             await App.AssertOutputLineStartsWith("dotnet watch 🔥 Hot reload change handled");
 
             App.AssertOutputContains($"dotnet watch ⌚ Handling file change event for scoped css file {scopedCssPath}.");
-            App.AssertOutputContains($"dotnet watch ⌚ [RazorClassLibrary (net9.0)] No refresh server.");
-            App.AssertOutputContains($"dotnet watch ⌚ [RazorApp (net9.0)] Refreshing browser.");
+            App.AssertOutputContains($"dotnet watch ⌚ [RazorClassLibrary ({ToolsetInfo.CurrentTargetFramework})] No refresh server.");
+            App.AssertOutputContains($"dotnet watch ⌚ [RazorApp ({ToolsetInfo.CurrentTargetFramework})] Refreshing browser.");
             App.AssertOutputContains($"dotnet watch 🔥 Hot reload of scoped css succeeded.");
             App.AssertOutputContains($"dotnet watch ⌚ No C# changes to apply.");
             App.Process.ClearOutput();
@@ -427,7 +424,7 @@ public async Task Razor_Component_ScopedCssAndStaticAssets()
             await App.AssertOutputLineStartsWith("dotnet watch 🔥 Hot reload change handled");
 
             App.AssertOutputContains($"dotnet watch ⌚ Sending static file update request for asset 'app.css'.");
-            App.AssertOutputContains($"dotnet watch ⌚ [RazorApp (net9.0)] Refreshing browser.");
+            App.AssertOutputContains($"dotnet watch ⌚ [RazorApp ({ToolsetInfo.CurrentTargetFramework})] Refreshing browser.");
             App.AssertOutputContains($"dotnet watch 🔥 Hot Reload of static files succeeded.");
             App.AssertOutputContains($"dotnet watch ⌚ No C# changes to apply.");
             App.Process.ClearOutput();
@@ -625,6 +622,7 @@ public static void PrintDirectoryName([CallerFilePathAttribute] string filePath
         [Fact(Skip = "https://github.com/dotnet/sdk/issues/42850")]
         public async Task Aspire()
         {
+            var tfm = ToolsetInfo.CurrentTargetFramework;
             var testAsset = TestAssets.CopyTestAsset("WatchAspire")
                 .WithSource();
 
@@ -650,8 +648,8 @@ public async Task Aspire()
             await App.AssertOutputLineStartsWith("dotnet watch 🔥 Hot reload change handled");
 
             App.AssertOutputContains("Using Aspire process launcher.");
-            App.AssertOutputContains(MessageDescriptor.HotReloadSucceeded, "WatchAspire.AppHost (net10.0)");
-            App.AssertOutputContains(MessageDescriptor.HotReloadSucceeded, "WatchAspire.ApiService (net10.0)");
+            App.AssertOutputContains(MessageDescriptor.HotReloadSucceeded, $"WatchAspire.AppHost ({tfm})");
+            App.AssertOutputContains(MessageDescriptor.HotReloadSucceeded, $"WatchAspire.ApiService ({tfm})");
 
             // Only one browser should be launched (dashboard). The child process shouldn't launch a browser.
             Assert.Equal(1, App.Process.Output.Count(line => line.StartsWith("dotnet watch ⌚ Launching browser: ")));
@@ -677,16 +675,16 @@ public async Task Aspire()
             // We don't have means to gracefully terminate process on Windows, see https://github.com/dotnet/runtime/issues/109432
             if (RuntimeInformation.IsOSPlatform(OSPlatform.Windows))
             {
-                App.AssertOutputContains("dotnet watch ❌ [WatchAspire.ApiService (net9.0)] Exited with error code -1");
+                App.AssertOutputContains($"dotnet watch ❌ [WatchAspire.ApiService ({tfm})] Exited with error code -1");
             }
             else
             {
                 // Unix process may return exit code = 128 + SIGTERM
-                // dotnet watch ❌ [WatchAspire.ApiService (net9.0)] Exited with error code 143
-                App.AssertOutputContains("[WatchAspire.ApiService (net9.0)] Exited");
+                // Exited with error code 143
+                App.AssertOutputContains($"[WatchAspire.ApiService ({tfm})] Exited");
             }
 
-            App.AssertOutputContains($"dotnet watch ⌚ Building '{serviceProjectPath}' ...");
+            App.AssertOutputContains($"dotnet watch ⌚ Building {serviceProjectPath} ...");
             App.AssertOutputContains("error CS0246: The type or namespace name 'WeatherForecast' could not be found");
             App.Process.ClearOutput();
 
@@ -695,9 +693,9 @@ public async Task Aspire()
                 serviceSourcePath,
                 originalSource.Replace("WeatherForecast", "WeatherForecast2"));
 
-            await App.AssertOutputLineStartsWith("dotnet watch ⌚ [WatchAspire.ApiService (net9.0)] Capabilities");
+            await App.AssertOutputLineStartsWith($"dotnet watch ⌚ [WatchAspire.ApiService ({tfm})] Capabilities");
 
-            App.AssertOutputContains("dotnet watch ⌚ Build succeeded.");
+            App.AssertOutputContains($"dotnet watch 🔨 Build succeeded: {serviceProjectPath}");
             App.AssertOutputContains("dotnet watch 🔥 Project baselines updated.");
             App.AssertOutputContains($"dotnet watch ⭐ Starting project: {serviceProjectPath}");
 
@@ -708,15 +706,15 @@ public async Task Aspire()
             // We don't have means to gracefully terminate process on Windows, see https://github.com/dotnet/runtime/issues/109432
             if (RuntimeInformation.IsOSPlatform(OSPlatform.Windows))
             {
-                await App.AssertOutputLineStartsWith("dotnet watch ❌ [WatchAspire.ApiService (net9.0)] Exited with error code -1");
-                await App.AssertOutputLineStartsWith("dotnet watch ❌ [WatchAspire.AppHost (net9.0)] Exited with error code -1");
+                await App.AssertOutputLineStartsWith($"dotnet watch ❌ [WatchAspire.ApiService ({tfm})] Exited with error code -1");
+                await App.AssertOutputLineStartsWith($"dotnet watch ❌ [WatchAspire.AppHost ({tfm})] Exited with error code -1");
             }
             else
             {
                 // Unix process may return exit code = 128 + SIGTERM
-                // dotnet watch ❌ [WatchAspire.ApiService (net9.0)] Exited with error code 143
-                await App.AssertOutputLine(line => line.Contains("[WatchAspire.ApiService (net9.0)] Exited"), failure: _ => false);
-                await App.AssertOutputLine(line => line.Contains("[WatchAspire.AppHost (net9.0)] Exited"), failure: _ => false);
+                // Exited with error code 143
+                await App.AssertOutputLine(line => line.Contains($"[WatchAspire.ApiService ({tfm})] Exited"), failure: _ => false);
+                await App.AssertOutputLine(line => line.Contains($"[WatchAspire.AppHost ({tfm})] Exited"), failure: _ => false);
             }
 
             await App.AssertOutputLineStartsWith("dotnet watch ⭐ Waiting for server to shutdown ...");
diff --git a/test/dotnet-watch.Tests/Utilities/AwaitableProcess.cs b/test/dotnet-watch.Tests/Utilities/AwaitableProcess.cs
@@ -131,7 +131,7 @@ private void OnData(object sender, DataReceivedEventArgs args)
                 line = line.StripTerminalLoggerProgressIndicators();
             }
 
-            WriteTestOutput($"{DateTime.Now}: post: '{line}'");
+            WriteTestOutput(line);
             _source.Post(line);
         }
 
diff --git a/test/dotnet-watch.Tests/Watch/Utilities/WatchableApp.cs b/test/dotnet-watch.Tests/Watch/Utilities/WatchableApp.cs
@@ -44,6 +44,7 @@ public async ValueTask WaitUntilOutputContains(string message)
         {
             if (!Process.Output.Any(line => line.Contains(message)))
             {
+                Logger.WriteLine($"[TEST] Test waiting for output: '{message}'");
                 _ = await AssertOutputLine(line => line.Contains(message));
             }
         }

Original file line number	Diff line number	Diff line change
`@@ -121,9 +121,10 @@ public override async Task WatchAsync(CancellationToken shutdownCancellationToke`
`121`	`121`	`};`
`122`	`122`	`}`
`123`	`123`
`124`		`- if (!await BuildProjectAsync(rootProjectOptions.ProjectPath, rootProjectOptions.BuildArguments, iterationCancellationToken))`
	`124`	`+ var (buildSucceeded, buildOutput, _) = await BuildProjectAsync(rootProjectOptions.ProjectPath, rootProjectOptions.BuildArguments, iterationCancellationToken);`
	`125`	`+ BuildUtilities.ReportBuildOutput(Context.Reporter, buildOutput, buildSucceeded, projectDisplay: rootProjectOptions.ProjectPath);`
	`126`	`+ if (!buildSucceeded)`
`125`	`127`	`{`
`126`		`- // error has been reported:`
`127`	`128`	`continue;`
`128`	`129`	`}`
`129`	`130`
`@@ -334,7 +335,12 @@ void FileChangedCallback(ChangedPath change)`
`334`	`335`	`var buildResults = await Task.WhenAll(`
`335`	`336`	`projectsToRebuild.Values.Select(projectPath => BuildProjectAsync(projectPath, rootProjectOptions.BuildArguments, iterationCancellationToken)));`
`336`	`337`
`337`		`- if (buildResults.All(success => success))`
	`338`	`+ foreach (var (success, output, projectPath) in buildResults)`
	`339`	`+ {`
	`340`	`+ BuildUtilities.ReportBuildOutput(Context.Reporter, output, success, projectPath);`
	`341`	`+ }`
	`342`	`+`
	`343`	`+ if (buildResults.All(result => result.success))`
`338`	`344`	`{`
`339`	`345`	`break;`
`340`	`346`	`}`
`@@ -815,7 +821,8 @@ await FileWatcher.WaitForFileChangeAsync(`
`815`	`821`	`}`
`816`	`822`	`}`
`817`	`823`
`818`		`- private async Task<bool> BuildProjectAsync(string projectPath, IReadOnlyList<string> buildArguments, CancellationToken cancellationToken)`
	`824`	`+ private async Task<(bool success, ImmutableArray<OutputLine> output, string projectPath)> BuildProjectAsync(`
	`825`	`+ string projectPath, IReadOnlyList<string> buildArguments, CancellationToken cancellationToken)`
`819`	`826`	`{`
`820`	`827`	`var buildOutput = new List<OutputLine>();`
`821`	`828`
`@@ -834,17 +841,10 @@ private async Task<bool> BuildProjectAsync(string projectPath, IReadOnlyList<str`
`834`	`841`	`Arguments = ["build", projectPath, "-consoleLoggerParameters:NoSummary;Verbosity=minimal", .. buildArguments]`
`835`	`842`	`};`
`836`	`843`
`837`		`- Context.Reporter.Output($"Building '{projectPath}' ...");`
	`844`	`+ Context.Reporter.Output($"Building {projectPath} ...");`
`838`	`845`
`839`	`846`	`var exitCode = await ProcessRunner.RunAsync(processSpec, Context.Reporter, isUserApplication: false, launchResult: null, cancellationToken);`
`840`		`- BuildUtilities.ReportBuildOutput(Context.Reporter, buildOutput, verboseOutput: exitCode == 0);`
`841`		`-`
`842`		`- if (exitCode == 0)`
`843`		`- {`
`844`		`- Context.Reporter.Output("Build succeeded.");`
`845`		`- }`
`846`		`-`
`847`		`- return exitCode == 0;`
	`847`	`+ return (exitCode == 0, buildOutput.ToImmutableArray(), projectPath);`
`848`	`848`	`}`
`849`	`849`
`850`	`850`	`private string GetRelativeFilePath(string path)`
Original file line number	Diff line number	Diff line change
`@@ -63,7 +63,7 @@ internal class MSBuildFileSetFactory(`
`63`	`63`	`reporter.Output($"MSBuild output from target '{TargetName}':");`
`64`	`64`	`}`
`65`	`65`
`66`		`- BuildUtilities.ReportBuildOutput(reporter, capturedOutput, verboseOutput: success);`
	`66`	`+ BuildUtilities.ReportBuildOutput(reporter, capturedOutput, success, projectDisplay: null);`
`67`	`67`	`if (!success)`
`68`	`68`	`{`
`69`	`69`	`return null;`
Original file line number	Diff line number	Diff line change
`@@ -87,6 +87,15 @@ public static async Task<int> RunAsync(ProcessSpec processSpec, IReporter report`
`87`	`87`	`try`
`88`	`88`	`{`
`89`	`89`	`await process.WaitForExitAsync(processTerminationToken);`
	`90`	`+`
	`91`	`+ // ensures that all process output has been reported:`
	`92`	`+ try`
	`93`	`+ {`
	`94`	`+ process.WaitForExit();`
	`95`	`+ }`
	`96`	`+ catch`
	`97`	`+ {`
	`98`	`+ }`
`90`	`99`	`}`
`91`	`100`	`catch (OperationCanceledException)`
`92`	`101`	`{`
Original file line number	Diff line number	Diff line change
`@@ -7,14 +7,25 @@ namespace Microsoft.DotNet.Watch;`
`7`	`7`
`8`	`8`	`internal static partial class BuildUtilities`
`9`	`9`	`{`
	`10`	`+ private const string BuildEmoji = "🔨";`
`10`	`11`	`private static readonly Regex s_buildDiagnosticRegex = GetBuildDiagnosticRegex();`
`11`	`12`
`12`	`13`	`[GeneratedRegex(@"[^:]+: (error\|warning) [A-Za-z]+[0-9]+: .+")]`
`13`	`14`	`private static partial Regex GetBuildDiagnosticRegex();`
`14`	`15`
`15`		`- public static void ReportBuildOutput(IReporter reporter, IEnumerable<OutputLine> buildOutput, bool verboseOutput)`
	`16`	`+ public static void ReportBuildOutput(IReporter reporter, IEnumerable<OutputLine> buildOutput, bool success, string? projectDisplay)`
`16`	`17`	`{`
`17`		`- const string BuildEmoji = "🔨";`
	`18`	`+ if (projectDisplay != null)`
	`19`	`+ {`
	`20`	`+ if (success)`
	`21`	`+ {`
	`22`	`+ reporter.Output($"Build succeeded: {projectDisplay}", BuildEmoji);`
	`23`	`+ }`
	`24`	`+ else`
	`25`	`+ {`
	`26`	`+ reporter.Output($"Build failed: {projectDisplay}", BuildEmoji);`
	`27`	`+ }`
	`28`	`+ }`
`18`	`29`
`19`	`30`	`foreach (var (line, isError) in buildOutput)`
`20`	`31`	`{`
`@@ -33,7 +44,7 @@ public static void ReportBuildOutput(IReporter reporter, IEnumerable<OutputLine>`
`33`	`44`	`reporter.Warn(line);`
`34`	`45`	`}`
`35`	`46`	`}`
`36`		`- else if (verboseOutput)`
	`47`	`+ else if (success)`
`37`	`48`	`{`
`38`	`49`	`reporter.Verbose(line, BuildEmoji);`
`39`	`50`	`}`
Original file line number	Diff line number	Diff line change
`@@ -131,7 +131,7 @@ private void OnData(object sender, DataReceivedEventArgs args)`
`131`	`131`	`line = line.StripTerminalLoggerProgressIndicators();`
`132`	`132`	`}`
`133`	`133`
`134`		`- WriteTestOutput($"{DateTime.Now}: post: '{line}'");`
	`134`	`+ WriteTestOutput(line);`
`135`	`135`	`_source.Post(line);`
`136`	`136`	`}`
`137`	`137`
Original file line number	Diff line number	Diff line change
`@@ -44,6 +44,7 @@ public async ValueTask WaitUntilOutputContains(string message)`
`44`	`44`	`{`
`45`	`45`	`if (!Process.Output.Any(line => line.Contains(message)))`
`46`	`46`	`{`
	`47`	`+ Logger.WriteLine($"[TEST] Test waiting for output: '{message}'");`
`47`	`48`	`_ = await AssertOutputLine(line => line.Contains(message));`
`48`	`49`	`}`
`49`	`50`	`}`