From e3da7157c5d2016c00ea2ca93e2645329ffa95ba Mon Sep 17 00:00:00 2001 From: Tomas Matousek Date: Fri, 15 Nov 2024 11:25:04 -0800 Subject: [PATCH] Improve failure reporting in tests --- .../dotnet-watch/HotReloadDotNetWatcher.cs | 10 +- .../HotReload/RuntimeProcessLauncherTests.cs | 282 ++++++++---------- 2 files changed, 130 insertions(+), 162 deletions(-) diff --git a/src/BuiltInTools/dotnet-watch/HotReloadDotNetWatcher.cs b/src/BuiltInTools/dotnet-watch/HotReloadDotNetWatcher.cs index 89124521e6f0..80b525fb1b0c 100644 --- a/src/BuiltInTools/dotnet-watch/HotReloadDotNetWatcher.cs +++ b/src/BuiltInTools/dotnet-watch/HotReloadDotNetWatcher.cs @@ -191,10 +191,6 @@ void FileChangedCallback(string path, ChangeKind kind) { ImmutableInterlocked.Update(ref changedFilesAccumulator, changedFiles => changedFiles.Add(changedFile)); } - else - { - Context.Reporter.Verbose($"Change ignored: {kind} '{path}'."); - } } fileChangedCallback = FileChangedCallback; @@ -455,6 +451,11 @@ async Task> CaptureChangedFilesSnapshot(ImmutableDict { // start next iteration unless shutdown is requested } + catch (Exception) when ((waitForFileChangeBeforeRestarting = false) == true) + { + // unreachable + throw new InvalidOperationException(); + } finally { // stop watching file changes: @@ -599,6 +600,7 @@ private async ValueTask WaitForFileChangeBeforeRestarting(FileWatcher fileWatche return new ChangedFile(new FileItem { FilePath = path, ContainingProjectPaths = [] }, kind); } + Context.Reporter.Verbose($"Change ignored: {kind} '{path}'."); return null; } diff --git a/test/dotnet-watch.Tests/HotReload/RuntimeProcessLauncherTests.cs b/test/dotnet-watch.Tests/HotReload/RuntimeProcessLauncherTests.cs index c4ab7b0db357..d13f9b78a633 100644 --- a/test/dotnet-watch.Tests/HotReload/RuntimeProcessLauncherTests.cs +++ b/test/dotnet-watch.Tests/HotReload/RuntimeProcessLauncherTests.cs @@ -3,6 +3,8 @@ #nullable enable +using System.Runtime.CompilerServices; + namespace Microsoft.DotNet.Watch.UnitTests; public class RuntimeProcessLauncherTests(ITestOutputHelper logger) : DotNetWatchTestBase(logger) @@ -14,6 +16,18 @@ public enum TriggerEvent WaitingForChanges, } + private record class RunningWatcher(Task Task, TestReporter Reporter, TestConsole Console, StrongBox ServiceHolder, CancellationTokenSource ShutdownSource) + { + public TestRuntimeProcessLauncher? Service => ServiceHolder.Value; + + public TaskCompletionSource CreateCompletionSource() + { + var source = new TaskCompletionSource(); + ShutdownSource.Token.Register(() => source.TrySetCanceled(ShutdownSource.Token)); + return source; + } + } + private TestAsset CopyTestAsset(string assetName, params object[] testParameters) => TestAssets.CopyTestAsset("WatchAppMultiProc", identifier: string.Join(";", testParameters)).WithSource(); @@ -53,6 +67,47 @@ private static async Task Launch(string projectPath, TestRuntime return await startOp(cancellationToken); } + private RunningWatcher StartWatcher(TestAsset testAsset, string[] args, string workingDirectory, string projectPath) + { + var console = new TestConsole(Logger); + var reporter = new TestReporter(Logger); + + var program = Program.TryCreate( + TestOptions.GetCommandLineOptions(["--verbose", ..args, "--project", projectPath]), + console, + TestOptions.GetEnvironmentOptions(workingDirectory, TestContext.Current.ToolsetUnderTest.DotNetHostPath, testAsset), + reporter, + out var errorCode); + + Assert.Equal(0, errorCode); + Assert.NotNull(program); + + var serviceHolder = new StrongBox(); + var factory = new TestRuntimeProcessLauncher.Factory(s => + { + serviceHolder.Value = s; + }); + + var watcher = Assert.IsType(program.CreateWatcher(factory)); + + var shutdownToken = new CancellationTokenSource(); + var watchTask = Task.Run(async () => + { + try + { + await watcher.WatchAsync(shutdownToken.Token); + } + catch (Exception e) + { + shutdownToken.Cancel(); + ((IReporter)reporter).Error($"Unexpected exception {e}"); + throw; + } + }); + + return new RunningWatcher(watchTask, reporter, console, serviceHolder, shutdownToken); + } + [Theory] [CombinatorialData] public async Task UpdateAndRudeEdit(TriggerEvent trigger) @@ -72,34 +127,12 @@ public async Task UpdateAndRudeEdit(TriggerEvent trigger) var libProject = Path.Combine(libDir, "Lib.csproj"); var libSource = Path.Combine(libDir, "Lib.cs"); - var console = new TestConsole(Logger); - var reporter = new TestReporter(Logger); - - var program = Program.TryCreate( - TestOptions.GetCommandLineOptions(["--verbose", "--non-interactive", "--project", hostProject]), - console, - TestOptions.GetEnvironmentOptions(workingDirectory, TestContext.Current.ToolsetUnderTest.DotNetHostPath, testAsset), - reporter, - out var errorCode); + var w = StartWatcher(testAsset, ["--non-interactive"], workingDirectory, hostProject); - Assert.Equal(0, errorCode); - Assert.NotNull(program); + var launchCompletionA = w.CreateCompletionSource(); + var launchCompletionB = w.CreateCompletionSource(); - TestRuntimeProcessLauncher? service = null; - var factory = new TestRuntimeProcessLauncher.Factory(s => - { - service = s; - }); - - var watcher = Assert.IsType(program.CreateWatcher(factory)); - - var watchCancellationSource = new CancellationTokenSource(); - var watchTask = watcher.WatchAsync(watchCancellationSource.Token); - - var launchCompletionA = new TaskCompletionSource(); - var launchCompletionB = new TaskCompletionSource(); - - reporter.RegisterAction(trigger switch + w.Reporter.RegisterAction(trigger switch { TriggerEvent.HotReloadSessionStarting => MessageDescriptor.HotReloadSessionStarting, TriggerEvent.HotReloadSessionStarted => MessageDescriptor.HotReloadSessionStarted, @@ -114,55 +147,54 @@ public async Task UpdateAndRudeEdit(TriggerEvent trigger) } // service should have been created before Hot Reload session started: - Assert.NotNull(service); + Assert.NotNull(w.Service); - Launch(serviceProjectA, service, workingDirectory, watchCancellationSource.Token).Wait(); + Launch(serviceProjectA, w.Service, workingDirectory, w.ShutdownSource.Token).Wait(); launchCompletionA.TrySetResult(); - Launch(serviceProjectB, service, workingDirectory, watchCancellationSource.Token).Wait(); + Launch(serviceProjectB, w.Service, workingDirectory, w.ShutdownSource.Token).Wait(); launchCompletionB.TrySetResult(); }); - var waitingForChanges = reporter.RegisterSemaphore(MessageDescriptor.WaitingForChanges); + var waitingForChanges = w.Reporter.RegisterSemaphore(MessageDescriptor.WaitingForChanges); var launchedProcessCount = 0; - reporter.RegisterAction(MessageDescriptor.LaunchedProcess, () => Interlocked.Increment(ref launchedProcessCount)); + w.Reporter.RegisterAction(MessageDescriptor.LaunchedProcess, () => Interlocked.Increment(ref launchedProcessCount)); - var changeHandled = reporter.RegisterSemaphore(MessageDescriptor.HotReloadChangeHandled); - var sessionStarted = reporter.RegisterSemaphore(MessageDescriptor.HotReloadSessionStarted); - var projectBaselinesUpdated = reporter.RegisterSemaphore(MessageDescriptor.ProjectBaselinesUpdated); - + var changeHandled = w.Reporter.RegisterSemaphore(MessageDescriptor.HotReloadChangeHandled); + var sessionStarted = w.Reporter.RegisterSemaphore(MessageDescriptor.HotReloadSessionStarted); + var projectBaselinesUpdated = w.Reporter.RegisterSemaphore(MessageDescriptor.ProjectBaselinesUpdated); await launchCompletionA.Task; await launchCompletionB.Task; // let the host process start: Log("Waiting for changes..."); - await waitingForChanges.WaitAsync(); + await waitingForChanges.WaitAsync(w.ShutdownSource.Token); Log("Waiting for session started..."); - await sessionStarted.WaitAsync(); + await sessionStarted.WaitAsync(w.ShutdownSource.Token); await MakeRudeEditChange(); Log("Waiting for changed handled ..."); - await changeHandled.WaitAsync(); + await changeHandled.WaitAsync(w.ShutdownSource.Token); // Wait for project baselines to be updated, so that we capture the new solution snapshot // and further changes are treated as another update. Log("Waiting for baselines updated..."); - await projectBaselinesUpdated.WaitAsync(); + await projectBaselinesUpdated.WaitAsync(w.ShutdownSource.Token); await MakeValidDependencyChange(); Log("Waiting for changed handled ..."); - await changeHandled.WaitAsync(); + await changeHandled.WaitAsync(w.ShutdownSource.Token); // clean up: Log("Shutting down"); - watchCancellationSource.Cancel(); + w.ShutdownSource.Cancel(); try { - await watchTask; + await w.Task; } catch (OperationCanceledException) { @@ -173,9 +205,9 @@ public async Task UpdateAndRudeEdit(TriggerEvent trigger) // Hot Reload shared dependency - should update both service projects async Task MakeValidDependencyChange() { - var hasUpdateSourceA = new TaskCompletionSource(); - var hasUpdateSourceB = new TaskCompletionSource(); - reporter.OnProjectProcessOutput += (projectPath, line) => + var hasUpdateSourceA = w.CreateCompletionSource(); + var hasUpdateSourceB = w.CreateCompletionSource(); + w.Reporter.OnProjectProcessOutput += (projectPath, line) => { if (line.Content.Contains("")) { @@ -228,8 +260,8 @@ public static void Common() // make a rude edit and check that the process is restarted async Task MakeRudeEditChange() { - var hasUpdateSource = new TaskCompletionSource(); - reporter.OnProjectProcessOutput += (projectPath, line) => + var hasUpdateSource = w.CreateCompletionSource(); + w.Reporter.OnProjectProcessOutput += (projectPath, line) => { if (projectPath == serviceProjectA && line.Content.Contains("Started A: 2")) { @@ -275,37 +307,15 @@ public async Task UpdateAppliedToNewProcesses(bool sharedOutput) var libProject = Path.Combine(libDir, "Lib.csproj"); var libSource = Path.Combine(libDir, "Lib.cs"); - var console = new TestConsole(Logger); - var reporter = new TestReporter(Logger); - - var program = Program.TryCreate( - TestOptions.GetCommandLineOptions(["--verbose", "--non-interactive", "--project", hostProject]), - console, - TestOptions.GetEnvironmentOptions(workingDirectory, TestContext.Current.ToolsetUnderTest.DotNetHostPath, testAsset), - reporter, - out var errorCode); - - Assert.Equal(0, errorCode); - Assert.NotNull(program); - - TestRuntimeProcessLauncher? service = null; - var factory = new TestRuntimeProcessLauncher.Factory(s => - { - service = s; - }); - - var watcher = Assert.IsType(program.CreateWatcher(factory)); - - var watchCancellationSource = new CancellationTokenSource(); - var watchTask = watcher.WatchAsync(watchCancellationSource.Token); + var w = StartWatcher(testAsset, ["--non-interactive"], workingDirectory, hostProject); - var waitingForChanges = reporter.RegisterSemaphore(MessageDescriptor.WaitingForChanges); - var changeHandled = reporter.RegisterSemaphore(MessageDescriptor.HotReloadChangeHandled); - var updatesApplied = reporter.RegisterSemaphore(MessageDescriptor.UpdatesApplied); + var waitingForChanges = w.Reporter.RegisterSemaphore(MessageDescriptor.WaitingForChanges); + var changeHandled = w.Reporter.RegisterSemaphore(MessageDescriptor.HotReloadChangeHandled); + var updatesApplied = w.Reporter.RegisterSemaphore(MessageDescriptor.UpdatesApplied); var hasUpdateA = new SemaphoreSlim(initialCount: 0); var hasUpdateB = new SemaphoreSlim(initialCount: 0); - reporter.OnProjectProcessOutput += (projectPath, line) => + w.Reporter.OnProjectProcessOutput += (projectPath, line) => { if (line.Content.Contains("")) { @@ -326,12 +336,12 @@ public async Task UpdateAppliedToNewProcesses(bool sharedOutput) // let the host process start: Log("Waiting for changes..."); - await waitingForChanges.WaitAsync(); + await waitingForChanges.WaitAsync(w.ShutdownSource.Token); // service should have been created before Hot Reload session started: - Assert.NotNull(service); + Assert.NotNull(w.Service); - await Launch(serviceProjectA, service, workingDirectory, watchCancellationSource.Token); + await Launch(serviceProjectA, w.Service, workingDirectory, w.ShutdownSource.Token); UpdateSourceFile(libSource, """ @@ -347,30 +357,30 @@ public static void Common() """); Log("Waiting for updated output from A ..."); - await hasUpdateA.WaitAsync(); + await hasUpdateA.WaitAsync(w.ShutdownSource.Token); // Host and ServiceA received updates: Log("Waiting for updates applied 1/2 ..."); - await updatesApplied.WaitAsync(); + await updatesApplied.WaitAsync(w.ShutdownSource.Token); Log("Waiting for updates applied 2/2 ..."); - await updatesApplied.WaitAsync(); + await updatesApplied.WaitAsync(w.ShutdownSource.Token); - await Launch(serviceProjectB, service, workingDirectory, watchCancellationSource.Token); + await Launch(serviceProjectB, w.Service, workingDirectory, w.ShutdownSource.Token); // ServiceB received updates: Log("Waiting for updates applied ..."); - await updatesApplied.WaitAsync(); + await updatesApplied.WaitAsync(w.ShutdownSource.Token); Log("Waiting for updated output from B ..."); - await hasUpdateB.WaitAsync(); + await hasUpdateB.WaitAsync(w.ShutdownSource.Token); // clean up: Log("Shutting down"); - watchCancellationSource.Cancel(); + w.ShutdownSource.Cancel(); try { - await watchTask; + await w.Task; } catch (OperationCanceledException) { @@ -397,37 +407,15 @@ public async Task HostRestart(UpdateLocation updateLocation) var libProject = Path.Combine(testAsset.Path, "Lib2", "Lib2.csproj"); var lib = Path.Combine(testAsset.Path, "Lib2", "Lib2.cs"); - var console = new TestConsole(Logger); - var reporter = new TestReporter(Logger); + var w = StartWatcher(testAsset, args: [], workingDirectory, hostProject); - var program = Program.TryCreate( - TestOptions.GetCommandLineOptions(["--verbose", "--project", hostProject]), - console, - TestOptions.GetEnvironmentOptions(workingDirectory, TestContext.Current.ToolsetUnderTest.DotNetHostPath, testAsset), - reporter, - out var errorCode); - - Assert.Equal(0, errorCode); - Assert.NotNull(program); - - TestRuntimeProcessLauncher? service = null; - var factory = new TestRuntimeProcessLauncher.Factory(s => - { - service = s; - }); - - var watcher = Assert.IsType(program.CreateWatcher(factory)); - - var watchCancellationSource = new CancellationTokenSource(); - var watchTask = watcher.WatchAsync(watchCancellationSource.Token); - - var waitingForChanges = reporter.RegisterSemaphore(MessageDescriptor.WaitingForChanges); - var changeHandled = reporter.RegisterSemaphore(MessageDescriptor.HotReloadChangeHandled); - var restartNeeded = reporter.RegisterSemaphore(MessageDescriptor.ApplyUpdate_ChangingEntryPoint); - var restartRequested = reporter.RegisterSemaphore(MessageDescriptor.RestartRequested); + var waitingForChanges = w.Reporter.RegisterSemaphore(MessageDescriptor.WaitingForChanges); + var changeHandled = w.Reporter.RegisterSemaphore(MessageDescriptor.HotReloadChangeHandled); + var restartNeeded = w.Reporter.RegisterSemaphore(MessageDescriptor.ApplyUpdate_ChangingEntryPoint); + var restartRequested = w.Reporter.RegisterSemaphore(MessageDescriptor.RestartRequested); var hasUpdate = new SemaphoreSlim(initialCount: 0); - reporter.OnProjectProcessOutput += (projectPath, line) => + w.Reporter.OnProjectProcessOutput += (projectPath, line) => { if (line.Content.Contains("")) { @@ -446,7 +434,7 @@ public async Task HostRestart(UpdateLocation updateLocation) // let the host process start: Log("Waiting for changes..."); - await waitingForChanges.WaitAsync(); + await waitingForChanges.WaitAsync(w.ShutdownSource.Token); switch (updateLocation) { @@ -465,7 +453,7 @@ public static void Print() // Host received Hot Reload updates: Log("Waiting for change handled ..."); - await changeHandled.WaitAsync(); + await changeHandled.WaitAsync(w.ShutdownSource.Token); break; case UpdateLocation.TopFunction: @@ -474,7 +462,7 @@ public static void Print() // Host received Hot Reload updates: Log("Waiting for change handled ..."); - await changeHandled.WaitAsync(); + await changeHandled.WaitAsync(w.ShutdownSource.Token); break; case UpdateLocation.TopLevel: @@ -483,23 +471,23 @@ public static void Print() // ⚠ ENC0118: Changing 'top-level code' might not have any effect until the application is restarted. Press "Ctrl + R" to restart. Log("Waiting for restart needed ..."); - await restartNeeded.WaitAsync(); + await restartNeeded.WaitAsync(w.ShutdownSource.Token); - console.PressKey(new ConsoleKeyInfo('R', ConsoleKey.R, shift: false, alt: false, control: true)); + w.Console.PressKey(new ConsoleKeyInfo('R', ConsoleKey.R, shift: false, alt: false, control: true)); Log("Waiting for restart requested ..."); - await restartRequested.WaitAsync(); + await restartRequested.WaitAsync(w.ShutdownSource.Token); break; } Log("Waiting updated output from Host ..."); - await hasUpdate.WaitAsync(); + await hasUpdate.WaitAsync(w.ShutdownSource.Token); // clean up: - watchCancellationSource.Cancel(); + w.ShutdownSource.Cancel(); try { - await watchTask; + await w.Task; } catch (OperationCanceledException) { @@ -518,48 +506,26 @@ public async Task RudeEditInProjectWithoutRunningProcess() var serviceSourceA2 = Path.Combine(serviceDirA, "A2.cs"); var serviceProjectA = Path.Combine(serviceDirA, "A.csproj"); - var console = new TestConsole(Logger); - var reporter = new TestReporter(Logger); - - var program = Program.TryCreate( - TestOptions.GetCommandLineOptions(["--verbose", "--non-interactive", "--project", hostProject]), - console, - TestOptions.GetEnvironmentOptions(workingDirectory, TestContext.Current.ToolsetUnderTest.DotNetHostPath, testAsset), - reporter, - out var errorCode); - - Assert.Equal(0, errorCode); - Assert.NotNull(program); - - TestRuntimeProcessLauncher? service = null; - var factory = new TestRuntimeProcessLauncher.Factory(s => - { - service = s; - }); - - var watcher = Assert.IsType(program.CreateWatcher(factory)); - - var watchCancellationSource = new CancellationTokenSource(); - var watchTask = watcher.WatchAsync(watchCancellationSource.Token); + var w = StartWatcher(testAsset, ["--non-interactive"], workingDirectory, hostProject); - var waitingForChanges = reporter.RegisterSemaphore(MessageDescriptor.WaitingForChanges); + var waitingForChanges = w.Reporter.RegisterSemaphore(MessageDescriptor.WaitingForChanges); - var changeHandled = reporter.RegisterSemaphore(MessageDescriptor.HotReloadChangeHandled); - var sessionStarted = reporter.RegisterSemaphore(MessageDescriptor.HotReloadSessionStarted); + var changeHandled = w.Reporter.RegisterSemaphore(MessageDescriptor.HotReloadChangeHandled); + var sessionStarted = w.Reporter.RegisterSemaphore(MessageDescriptor.HotReloadSessionStarted); // let the host process start: Log("Waiting for changes..."); - await waitingForChanges.WaitAsync(); + await waitingForChanges.WaitAsync(w.ShutdownSource.Token); // service should have been created before Hot Reload session started: - Assert.NotNull(service); + Assert.NotNull(w.Service); - var runningProject = await Launch(serviceProjectA, service, workingDirectory, watchCancellationSource.Token); + var runningProject = await Launch(serviceProjectA, w.Service, workingDirectory, w.ShutdownSource.Token); Log("Waiting for session started ..."); - await sessionStarted.WaitAsync(); + await sessionStarted.WaitAsync(w.ShutdownSource.Token); // Terminate the process: - await service.ProjectLauncher.TerminateProcessAsync(runningProject, CancellationToken.None); + await w.Service.ProjectLauncher.TerminateProcessAsync(runningProject, CancellationToken.None); // rude edit in A (changing assembly level attribute): UpdateSourceFile(serviceSourceA2, """ @@ -567,16 +533,16 @@ public async Task RudeEditInProjectWithoutRunningProcess() """); Log("Waiting for change handled ..."); - await changeHandled.WaitAsync(); + await changeHandled.WaitAsync(w.ShutdownSource.Token); - reporter.ProcessOutput.Contains("verbose ⌚ Rude edits detected but do not affect any running process"); - reporter.ProcessOutput.Contains($"verbose ❌ {serviceSourceA2}(1,12): error ENC0003: Updating 'attribute' requires restarting the application."); + w.Reporter.ProcessOutput.Contains("verbose ⌚ Rude edits detected but do not affect any running process"); + w.Reporter.ProcessOutput.Contains($"verbose ❌ {serviceSourceA2}(1,12): error ENC0003: Updating 'attribute' requires restarting the application."); // clean up: - watchCancellationSource.Cancel(); + w.ShutdownSource.Cancel(); try { - await watchTask; + await w.Task; } catch (OperationCanceledException) {