diff --git a/src/BuiltInTools/dotnet-watch/Build/BuildReporter.cs b/src/BuiltInTools/dotnet-watch/Build/BuildReporter.cs index 2bd96b5f3eb6..f062e112d457 100644 --- a/src/BuiltInTools/dotnet-watch/Build/BuildReporter.cs +++ b/src/BuiltInTools/dotnet-watch/Build/BuildReporter.cs @@ -102,7 +102,7 @@ private void Write(string message) public void ReportOutput() { _logger.LogInformation("MSBuild output:"); - BuildOutput.ReportBuildOutput(_logger, Messages, success: false, projectDisplay: null); + BuildOutput.ReportBuildOutput(_logger, Messages, success: false); } } } diff --git a/src/BuiltInTools/dotnet-watch/CommandLine/EnvironmentOptions.cs b/src/BuiltInTools/dotnet-watch/CommandLine/EnvironmentOptions.cs index 72f787332533..d0e84844de86 100644 --- a/src/BuiltInTools/dotnet-watch/CommandLine/EnvironmentOptions.cs +++ b/src/BuiltInTools/dotnet-watch/CommandLine/EnvironmentOptions.cs @@ -12,21 +12,16 @@ internal enum TestFlags RunningAsTest = 1 << 0, MockBrowser = 1 << 1, - /// - /// Elevates the severity of from . - /// - ElevateWaitingForChangesMessageSeverity = 1 << 2, - /// /// Instead of using to watch for Ctrl+C, Ctlr+R, and other keys, read from standard input. /// This allows tests to trigger key based events. /// - ReadKeyFromStdin = 1 << 3, + ReadKeyFromStdin = 1 << 2, /// /// Redirects the output of the launched browser process to watch output. /// - RedirectBrowserOutput = 1 << 4, + RedirectBrowserOutput = 1 << 3, } internal sealed record EnvironmentOptions( diff --git a/src/BuiltInTools/dotnet-watch/HotReload/HotReloadDotNetWatcher.cs b/src/BuiltInTools/dotnet-watch/HotReload/HotReloadDotNetWatcher.cs index 38e313f6f746..565bc7f9062b 100644 --- a/src/BuiltInTools/dotnet-watch/HotReload/HotReloadDotNetWatcher.cs +++ b/src/BuiltInTools/dotnet-watch/HotReload/HotReloadDotNetWatcher.cs @@ -82,8 +82,7 @@ public async Task WatchAsync(CancellationToken shutdownCancellationToken) { var rootProjectOptions = _context.RootProjectOptions; - var (buildSucceeded, buildOutput, _) = await BuildProjectAsync(rootProjectOptions.ProjectPath, rootProjectOptions.BuildArguments, iterationCancellationToken); - BuildOutput.ReportBuildOutput(_context.BuildLogger, buildOutput, buildSucceeded, projectDisplay: rootProjectOptions.ProjectPath); + var buildSucceeded = await BuildProjectAsync(rootProjectOptions.ProjectPath, rootProjectOptions.BuildArguments, iterationCancellationToken); if (!buildSucceeded) { continue; @@ -189,7 +188,7 @@ void FileChangedCallback(ChangedPath change) fileChangedCallback = FileChangedCallback; fileWatcher.OnFileChange += fileChangedCallback; - ReportWatchingForChanges(); + _context.Logger.Log(MessageDescriptor.WaitingForChanges); // Hot Reload loop - exits when the root process needs to be restarted. bool extendTimeout = false; @@ -328,15 +327,19 @@ void FileChangedCallback(ChangedPath change) fileWatcher.SuppressEvents = true; try { - var buildResults = await Task.WhenAll( - projectsToRebuild.Select(projectPath => BuildProjectAsync(projectPath, rootProjectOptions.BuildArguments, iterationCancellationToken))); - - foreach (var (success, output, projectPath) in buildResults) + // Build projects sequentially to avoid failed attempts to overwrite dependent project outputs. + // TODO: Ideally, dotnet build would be able to build multiple projects. https://github.com/dotnet/sdk/issues/51311 + var success = true; + foreach (var projectPath in projectsToRebuild) { - BuildOutput.ReportBuildOutput(_context.BuildLogger, output, success, projectPath); + success = await BuildProjectAsync(projectPath, rootProjectOptions.BuildArguments, iterationCancellationToken); + if (!success) + { + break; + } } - if (buildResults.All(result => result.success)) + if (success) { break; } @@ -772,12 +775,6 @@ internal static IEnumerable NormalizePathChanges(IEnumerable item != null) .Select(item => item!.Value); - private void ReportWatchingForChanges() - { - _context.Logger.Log(MessageDescriptor.WaitingForChanges - .WithSeverityWhen(MessageSeverity.Output, _context.EnvironmentOptions.TestFlags.HasFlag(TestFlags.ElevateWaitingForChangesMessageSeverity))); - } - private void ReportFileChanges(IReadOnlyList changedFiles) { Report(kind: ChangeKind.Add); @@ -823,6 +820,9 @@ private async ValueTask EvaluateRootProjectAsync(bool restore, { cancellationToken.ThrowIfCancellationRequested(); + _context.Logger.LogInformation("Evaluating projects ..."); + var stopwatch = Stopwatch.StartNew(); + var result = EvaluationResult.TryCreate( _context.RootProjectOptions.ProjectPath, _context.RootProjectOptions.BuildArguments, @@ -832,6 +832,8 @@ private async ValueTask EvaluateRootProjectAsync(bool restore, restore, cancellationToken); + _context.Logger.LogInformation("Evaluation completed in {Time}s.", stopwatch.Elapsed.TotalSeconds.ToString("0.0")); + if (result != null) { return result; @@ -846,31 +848,43 @@ await FileWatcher.WaitForFileChangeAsync( } } - private async Task<(bool success, ImmutableArray output, string projectPath)> BuildProjectAsync( - string projectPath, IReadOnlyList buildArguments, CancellationToken cancellationToken) + private async Task BuildProjectAsync(string projectPath, IReadOnlyList buildArguments, CancellationToken cancellationToken) { - var buildOutput = new List(); + List? capturedOutput = _context.EnvironmentOptions.TestFlags != TestFlags.None ? [] : null; var processSpec = new ProcessSpec { Executable = _context.EnvironmentOptions.MuxerPath, WorkingDirectory = Path.GetDirectoryName(projectPath)!, IsUserApplication = false, - OnOutput = line => - { - lock (buildOutput) + + // Capture output if running in a test environment. + // If the output is not captured dotnet build will show live build progress. + OnOutput = capturedOutput != null + ? line => { - buildOutput.Add(line); + lock (capturedOutput) + { + capturedOutput.Add(line); + } } - }, + : null, + // pass user-specified build arguments last to override defaults: Arguments = ["build", projectPath, "-consoleLoggerParameters:NoSummary;Verbosity=minimal", .. buildArguments] }; _context.BuildLogger.Log(MessageDescriptor.Building, projectPath); - var exitCode = await _context.ProcessRunner.RunAsync(processSpec, _context.Logger, launchResult: null, cancellationToken); - return (exitCode == 0, buildOutput.ToImmutableArray(), projectPath); + var success = await _context.ProcessRunner.RunAsync(processSpec, _context.Logger, launchResult: null, cancellationToken) == 0; + + if (capturedOutput != null) + { + _context.BuildLogger.Log(success ? MessageDescriptor.BuildSucceeded : MessageDescriptor.BuildFailed, projectPath); + BuildOutput.ReportBuildOutput(_context.BuildLogger, capturedOutput, success); + } + + return success; } private string GetRelativeFilePath(string path) diff --git a/src/BuiltInTools/dotnet-watch/HotReload/IncrementalMSBuildWorkspace.cs b/src/BuiltInTools/dotnet-watch/HotReload/IncrementalMSBuildWorkspace.cs index f4f3f499aec2..65ab6089466c 100644 --- a/src/BuiltInTools/dotnet-watch/HotReload/IncrementalMSBuildWorkspace.cs +++ b/src/BuiltInTools/dotnet-watch/HotReload/IncrementalMSBuildWorkspace.cs @@ -15,6 +15,7 @@ namespace Microsoft.DotNet.Watch; internal sealed class IncrementalMSBuildWorkspace : Workspace { private readonly ILogger _logger; + private int _solutionUpdateId; public IncrementalMSBuildWorkspace(ILogger logger) : base(MSBuildMefHostServices.DefaultServices, WorkspaceKind.MSBuild) @@ -35,6 +36,9 @@ public IncrementalMSBuildWorkspace(ILogger logger) public async Task UpdateProjectConeAsync(string rootProjectPath, CancellationToken cancellationToken) { + _logger.LogInformation("Loading projects ..."); + + var stopwatch = Stopwatch.StartNew(); var oldSolution = CurrentSolution; var loader = new MSBuildProjectLoader(this); @@ -94,9 +98,11 @@ public async Task UpdateProjectConeAsync(string rootProjectPath, CancellationTok .WithCompilationOutputInfo(newProjectInfo.CompilationOutputInfo)); } - await ReportSolutionFilesAsync(SetCurrentSolution(newSolution), cancellationToken); + await UpdateSolutionAsync(newSolution, operationDisplayName: "project update", cancellationToken); UpdateReferencesAfterAdd(); + _logger.LogInformation("Projects loaded in {Time}s.", stopwatch.Elapsed.TotalSeconds.ToString("0.0")); + ProjectReference MapProjectReference(ProjectReference pr) // Only C# and VB projects are loaded by the MSBuildProjectLoader, so some references might be missing. // When a new project is added along with a new project reference the old project id is also null. @@ -154,6 +160,8 @@ public async ValueTask UpdateFileContentAsync(IEnumerable changedFi var newText = await GetSourceTextAsync(changedFile.FilePath, oldText.Encoding, oldText.ChecksumAlgorithm, cancellationToken); + _logger.LogDebug("Updating document text of '{FilePath}'.", changedFile.FilePath); + updatedSolution = textDocument switch { Document document => document.WithText(newText).Project.Solution, @@ -166,7 +174,7 @@ public async ValueTask UpdateFileContentAsync(IEnumerable changedFi updatedSolution = RemoveDocuments(updatedSolution, documentsToRemove); - await ReportSolutionFilesAsync(SetCurrentSolution(updatedSolution), cancellationToken); + await UpdateSolutionAsync(updatedSolution, operationDisplayName: "document update", cancellationToken); } private static Solution RemoveDocuments(Solution solution, IEnumerable ids) @@ -217,10 +225,21 @@ private static async ValueTask GetSourceTextAsync(string filePath, E return null; } - public async Task ReportSolutionFilesAsync(Solution solution, CancellationToken cancellationToken) + private Task UpdateSolutionAsync(Solution newSolution, string operationDisplayName, CancellationToken cancellationToken) + => ReportSolutionFilesAsync(SetCurrentSolution(newSolution), Interlocked.Increment(ref _solutionUpdateId), operationDisplayName, cancellationToken); + + private async Task ReportSolutionFilesAsync(Solution solution, int updateId, string operationDisplayName, CancellationToken cancellationToken) { #if DEBUG _logger.LogDebug("Solution: {Path}", solution.FilePath); + + if (!_logger.IsEnabled(LogLevel.Debug)) + { + return; + } + + _logger.LogDebug("Solution after {Operation}: v{Version}", operationDisplayName, updateId); + foreach (var project in solution.Projects) { _logger.LogDebug(" Project: {Path}", project.FilePath); diff --git a/src/BuiltInTools/dotnet-watch/UI/BuildOutput.cs b/src/BuiltInTools/dotnet-watch/UI/BuildOutput.cs index 50474d870ca6..ab32830bd6ab 100644 --- a/src/BuiltInTools/dotnet-watch/UI/BuildOutput.cs +++ b/src/BuiltInTools/dotnet-watch/UI/BuildOutput.cs @@ -13,20 +13,8 @@ internal static partial class BuildOutput [GeneratedRegex(@"[^:]+: (error|warning) [A-Za-z]+[0-9]+: .+")] private static partial Regex GetBuildDiagnosticRegex(); - public static void ReportBuildOutput(ILogger logger, IEnumerable buildOutput, bool success, string? projectDisplay) + public static void ReportBuildOutput(ILogger logger, IEnumerable buildOutput, bool success) { - if (projectDisplay != null) - { - if (success) - { - logger.Log(MessageDescriptor.BuildSucceeded, projectDisplay); - } - else - { - logger.Log(MessageDescriptor.BuildFailed, projectDisplay); - } - } - foreach (var (line, isError) in buildOutput) { if (isError) diff --git a/src/BuiltInTools/dotnet-watch/UI/IReporter.cs b/src/BuiltInTools/dotnet-watch/UI/IReporter.cs index 319fcc1740b0..4224aefb4855 100644 --- a/src/BuiltInTools/dotnet-watch/UI/IReporter.cs +++ b/src/BuiltInTools/dotnet-watch/UI/IReporter.cs @@ -186,7 +186,7 @@ public MessageDescriptor WithSeverityWhen(MessageSeverity severity, bool conditi public static readonly MessageDescriptor ProjectsRestarted = Create("Projects restarted ({0})", Emoji.HotReload, MessageSeverity.Verbose); public static readonly MessageDescriptor ProjectDependenciesDeployed = Create("Project dependencies deployed ({0})", Emoji.HotReload, MessageSeverity.Verbose); public static readonly MessageDescriptor FixBuildError = Create("Fix the error to continue or press Ctrl+C to exit.", Emoji.Watch, MessageSeverity.Warning); - public static readonly MessageDescriptor WaitingForChanges = Create("Waiting for changes", Emoji.Watch, MessageSeverity.Verbose); + public static readonly MessageDescriptor WaitingForChanges = Create("Waiting for changes", Emoji.Watch, MessageSeverity.Output); public static readonly MessageDescriptor LaunchedProcess = Create("Launched '{0}' with arguments '{1}': process id {2}", Emoji.Launch, MessageSeverity.Verbose); public static readonly MessageDescriptor HotReloadChangeHandled = Create("Hot reload change handled in {0}ms.", Emoji.HotReload, MessageSeverity.Verbose); public static readonly MessageDescriptor HotReloadSucceeded = Create(LogEvents.HotReloadSucceeded, Emoji.HotReload); diff --git a/src/BuiltInTools/dotnet-watch/Watch/MsBuildFileSetFactory.cs b/src/BuiltInTools/dotnet-watch/Watch/MsBuildFileSetFactory.cs index d1c580ecb386..6de60206c1d2 100644 --- a/src/BuiltInTools/dotnet-watch/Watch/MsBuildFileSetFactory.cs +++ b/src/BuiltInTools/dotnet-watch/Watch/MsBuildFileSetFactory.cs @@ -73,7 +73,7 @@ internal sealed class EvaluationResult(IReadOnlyDictionary fil Logger.LogInformation("MSBuild output from target '{TargetName}':", TargetName); } - BuildOutput.ReportBuildOutput(Logger, capturedOutput, success, projectDisplay: null); + BuildOutput.ReportBuildOutput(Logger, capturedOutput, success); if (!success) { return null; diff --git a/test/dotnet-watch.Tests/HotReload/ApplyDeltaTests.cs b/test/dotnet-watch.Tests/HotReload/ApplyDeltaTests.cs index 501ce980b20f..10aedaf15a30 100644 --- a/test/dotnet-watch.Tests/HotReload/ApplyDeltaTests.cs +++ b/test/dotnet-watch.Tests/HotReload/ApplyDeltaTests.cs @@ -755,7 +755,7 @@ class AppUpdateHandler App.DotnetWatchArgs.Clear(); } - App.Start(testAsset, [], testFlags: TestFlags.ElevateWaitingForChangesMessageSeverity); + App.Start(testAsset, []); await App.WaitForOutputLineContaining(MessageDescriptor.WaitingForChanges);