From 3ea3c4996ce70371dd188278a0aba84c10415ff3 Mon Sep 17 00:00:00 2001 From: Rainer Sigwald Date: Tue, 19 Dec 2023 12:28:36 -0600 Subject: [PATCH 1/7] When time increases by a digit, overwrite NodeStatus Fixes #9562 by triggering a full-line redraw when the length of the duration string increases. --- src/MSBuild.UnitTests/NodeStatus_Tests.cs | 18 +++++++++--------- src/MSBuild/TerminalLogger/NodesFrame.cs | 14 ++++++++++---- 2 files changed, 19 insertions(+), 13 deletions(-) diff --git a/src/MSBuild.UnitTests/NodeStatus_Tests.cs b/src/MSBuild.UnitTests/NodeStatus_Tests.cs index 50ae7b38a51..c979d5c5b1a 100644 --- a/src/MSBuild.UnitTests/NodeStatus_Tests.cs +++ b/src/MSBuild.UnitTests/NodeStatus_Tests.cs @@ -1,4 +1,4 @@ -// Licensed to the .NET Foundation under one or more agreements. +// Licensed to the .NET Foundation under one or more agreements. // The .NET Foundation licenses this file to you under the MIT license. using System; @@ -31,32 +31,32 @@ public NodeStatus_Tests() [Fact] public async Task EverythingFits() { - NodesFrame frame = new(new[] { _status }, width: 80, height: 5); + NodesFrame frame = new([_status], width: 80, height: 5); - await Verify(frame.RenderNodeStatus(_status).ToString()); + await Verify(frame.RenderNodeStatus(0).ToString()); } [Fact] public async Task TargetIsTruncatedFirst() { - NodesFrame frame = new(new[] { _status }, width: 45, height: 5); + NodesFrame frame = new([_status], width: 45, height: 5); - await Verify(frame.RenderNodeStatus(_status).ToString()); + await Verify(frame.RenderNodeStatus(0).ToString()); } [Fact] public async Task NamespaceIsTruncatedNext() { - NodesFrame frame = new(new[] { _status }, width: 40, height: 5); + NodesFrame frame = new([_status], width: 40, height: 5); - await Verify(frame.RenderNodeStatus(_status).ToString()); + await Verify(frame.RenderNodeStatus(0).ToString()); } [Fact] public async Task GoesToProject() { - NodesFrame frame = new(new[] { _status }, width: 10, height: 5); + NodesFrame frame = new([_status], width: 10, height: 5); - await Verify(frame.RenderNodeStatus(_status).ToString()); + await Verify(frame.RenderNodeStatus(0).ToString()); } } diff --git a/src/MSBuild/TerminalLogger/NodesFrame.cs b/src/MSBuild/TerminalLogger/NodesFrame.cs index 144288950fa..6e5f90d581e 100644 --- a/src/MSBuild/TerminalLogger/NodesFrame.cs +++ b/src/MSBuild/TerminalLogger/NodesFrame.cs @@ -17,6 +17,7 @@ internal sealed class NodesFrame private const int MaxColumn = 120; private readonly NodeStatus[] _nodes; + private readonly int[] _durationLength; private readonly StringBuilder _renderBuilder = new(); @@ -30,6 +31,7 @@ public NodesFrame(NodeStatus?[] nodes, int width, int height) Height = height; _nodes = new NodeStatus[nodes.Length]; + _durationLength = new int[nodes.Length]; foreach (NodeStatus? status in nodes) { @@ -40,12 +42,16 @@ public NodesFrame(NodeStatus?[] nodes, int width, int height) } } - internal ReadOnlySpan RenderNodeStatus(NodeStatus status) + internal ReadOnlySpan RenderNodeStatus(int i) { + NodeStatus status = _nodes[i]; + string durationString = ResourceUtilities.FormatResourceStringIgnoreCodeAndKeyword( "DurationDisplay", status.Stopwatch.Elapsed.TotalSeconds); + _durationLength[i] = durationString.Length; + string project = status.Project; string? targetFramework = status.TargetFramework; string target = status.Target; @@ -91,14 +97,14 @@ public string Render(NodesFrame previousFrame) int i = 0; for (; i < NodesCount; i++) { - ReadOnlySpan needed = RenderNodeStatus(_nodes[i]); + ReadOnlySpan needed = RenderNodeStatus(i); // Do we have previous node string to compare with? if (previousFrame.NodesCount > i) { - if (previousFrame._nodes[i] == _nodes[i]) + if (previousFrame._nodes[i] == _nodes[i] && // Same everything except time, AND + previousFrame._durationLength[i] == _durationLength[i]) // same number of digits in time { - // Same everything except time string durationString = ResourceUtilities.FormatResourceStringIgnoreCodeAndKeyword("DurationDisplay", _nodes[i].Stopwatch.Elapsed.TotalSeconds); sb.Append($"{AnsiCodes.SetCursorHorizontal(MaxColumn)}{AnsiCodes.MoveCursorBackward(durationString.Length)}{durationString}"); } From 35460fdd849b38b541639f3d08d8b299ce61b3e2 Mon Sep 17 00:00:00 2001 From: Rainer Sigwald Date: Tue, 19 Dec 2023 13:32:27 -0600 Subject: [PATCH 2/7] Introduce StopwatchAbstraction --- src/MSBuild.UnitTests/MockStopwatch.cs | 34 +++++++++++++++++++ src/MSBuild.UnitTests/NodeStatus_Tests.cs | 2 +- src/MSBuild/TerminalLogger/NodeStatus.cs | 6 ++-- src/MSBuild/TerminalLogger/NodesFrame.cs | 4 +-- src/MSBuild/TerminalLogger/Project.cs | 2 +- .../TerminalLogger/StopwatchAbstraction.cs | 12 +++++++ src/MSBuild/TerminalLogger/SystemStopwatch.cs | 24 +++++++++++++ src/MSBuild/TerminalLogger/TerminalLogger.cs | 2 +- 8 files changed, 78 insertions(+), 8 deletions(-) create mode 100644 src/MSBuild.UnitTests/MockStopwatch.cs create mode 100644 src/MSBuild/TerminalLogger/StopwatchAbstraction.cs create mode 100644 src/MSBuild/TerminalLogger/SystemStopwatch.cs diff --git a/src/MSBuild.UnitTests/MockStopwatch.cs b/src/MSBuild.UnitTests/MockStopwatch.cs new file mode 100644 index 00000000000..8c65821140f --- /dev/null +++ b/src/MSBuild.UnitTests/MockStopwatch.cs @@ -0,0 +1,34 @@ +// 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.Logging.TerminalLogger; + +namespace Microsoft.Build.CommandLine.UnitTests; + +internal sealed class MockStopwatch : StopwatchAbstraction +{ + public override double ElapsedSeconds + { + get + { + return _elapsed; + } + } + + public override void Start() + { + IsStarted = true; + Tick(); + } + + public override void Stop() => IsStarted = false; + + public bool IsStarted { get; private set; } + + private double _elapsed = 0d; + + public void Tick(double seconds = 0.1) + { + _elapsed += seconds; + } +} diff --git a/src/MSBuild.UnitTests/NodeStatus_Tests.cs b/src/MSBuild.UnitTests/NodeStatus_Tests.cs index c979d5c5b1a..42e821c4ae6 100644 --- a/src/MSBuild.UnitTests/NodeStatus_Tests.cs +++ b/src/MSBuild.UnitTests/NodeStatus_Tests.cs @@ -21,7 +21,7 @@ namespace Microsoft.Build.CommandLine.UnitTests; [UsesVerify] public class NodeStatus_Tests { - private readonly NodeStatus _status = new("Namespace.Project", "TargetFramework", "Target", new()); + private readonly NodeStatus _status = new("Namespace.Project", "TargetFramework", "Target", new MockStopwatch()); public NodeStatus_Tests() { diff --git a/src/MSBuild/TerminalLogger/NodeStatus.cs b/src/MSBuild/TerminalLogger/NodeStatus.cs index c82a3d106d7..d199edc461c 100644 --- a/src/MSBuild/TerminalLogger/NodeStatus.cs +++ b/src/MSBuild/TerminalLogger/NodeStatus.cs @@ -14,9 +14,9 @@ internal class NodeStatus public string Project { get; } public string? TargetFramework { get; } public string Target { get; } - public Stopwatch Stopwatch { get; } + public StopwatchAbstraction Stopwatch { get; } - public NodeStatus(string project, string? targetFramework, string target, Stopwatch stopwatch) + public NodeStatus(string project, string? targetFramework, string target, StopwatchAbstraction stopwatch) { Project = project; TargetFramework = targetFramework; @@ -35,7 +35,7 @@ obj is NodeStatus status && public override string ToString() { - string duration = Stopwatch.Elapsed.TotalSeconds.ToString("F1"); + string duration = Stopwatch.ElapsedSeconds.ToString("F1"); return string.IsNullOrEmpty(TargetFramework) ? string.Format("{0}{1} {2} ({3}s)", diff --git a/src/MSBuild/TerminalLogger/NodesFrame.cs b/src/MSBuild/TerminalLogger/NodesFrame.cs index 6e5f90d581e..bba5a1374c6 100644 --- a/src/MSBuild/TerminalLogger/NodesFrame.cs +++ b/src/MSBuild/TerminalLogger/NodesFrame.cs @@ -48,7 +48,7 @@ internal ReadOnlySpan RenderNodeStatus(int i) string durationString = ResourceUtilities.FormatResourceStringIgnoreCodeAndKeyword( "DurationDisplay", - status.Stopwatch.Elapsed.TotalSeconds); + status.Stopwatch.ElapsedSeconds); _durationLength[i] = durationString.Length; @@ -105,7 +105,7 @@ public string Render(NodesFrame previousFrame) if (previousFrame._nodes[i] == _nodes[i] && // Same everything except time, AND previousFrame._durationLength[i] == _durationLength[i]) // same number of digits in time { - string durationString = ResourceUtilities.FormatResourceStringIgnoreCodeAndKeyword("DurationDisplay", _nodes[i].Stopwatch.Elapsed.TotalSeconds); + string durationString = ResourceUtilities.FormatResourceStringIgnoreCodeAndKeyword("DurationDisplay", _nodes[i].Stopwatch.ElapsedSeconds); sb.Append($"{AnsiCodes.SetCursorHorizontal(MaxColumn)}{AnsiCodes.MoveCursorBackward(durationString.Length)}{durationString}"); } else diff --git a/src/MSBuild/TerminalLogger/Project.cs b/src/MSBuild/TerminalLogger/Project.cs index 5ed03039bcc..f7f57c57b8b 100644 --- a/src/MSBuild/TerminalLogger/Project.cs +++ b/src/MSBuild/TerminalLogger/Project.cs @@ -24,7 +24,7 @@ public Project(string? targetFramework) /// /// A stopwatch to time the build of the project. /// - public Stopwatch Stopwatch { get; } = Stopwatch.StartNew(); + public StopwatchAbstraction Stopwatch { get; } = SystemStopwatch.StartNew(); /// /// Full path to the primary output of the project, if known. diff --git a/src/MSBuild/TerminalLogger/StopwatchAbstraction.cs b/src/MSBuild/TerminalLogger/StopwatchAbstraction.cs new file mode 100644 index 00000000000..8b365517a6a --- /dev/null +++ b/src/MSBuild/TerminalLogger/StopwatchAbstraction.cs @@ -0,0 +1,12 @@ +// Licensed to the .NET Foundation under one or more agreements. +// The .NET Foundation licenses this file to you under the MIT license. + +namespace Microsoft.Build.Logging.TerminalLogger; + +internal abstract class StopwatchAbstraction +{ + public abstract void Start(); + public abstract void Stop(); + + public abstract double ElapsedSeconds { get; } +} diff --git a/src/MSBuild/TerminalLogger/SystemStopwatch.cs b/src/MSBuild/TerminalLogger/SystemStopwatch.cs new file mode 100644 index 00000000000..2f03092971c --- /dev/null +++ b/src/MSBuild/TerminalLogger/SystemStopwatch.cs @@ -0,0 +1,24 @@ +// Licensed to the .NET Foundation under one or more agreements. +// The .NET Foundation licenses this file to you under the MIT license. + +using System.Diagnostics; + +namespace Microsoft.Build.Logging.TerminalLogger; + +internal sealed class SystemStopwatch : StopwatchAbstraction +{ + private Stopwatch _stopwatch = new (); + + public override double ElapsedSeconds => _stopwatch.Elapsed.TotalSeconds; + + public override void Start() => _stopwatch.Start(); + public override void Stop() => _stopwatch.Stop(); + + public static StopwatchAbstraction StartNew() + { + SystemStopwatch wallClockStopwatch = new(); + wallClockStopwatch.Start(); + + return wallClockStopwatch; + } +} diff --git a/src/MSBuild/TerminalLogger/TerminalLogger.cs b/src/MSBuild/TerminalLogger/TerminalLogger.cs index 221d6e4e4fa..0aada4c5ebf 100644 --- a/src/MSBuild/TerminalLogger/TerminalLogger.cs +++ b/src/MSBuild/TerminalLogger/TerminalLogger.cs @@ -358,7 +358,7 @@ private void ProjectFinished(object sender, ProjectFinishedEventArgs e) { EraseNodes(); - string duration = project.Stopwatch.Elapsed.TotalSeconds.ToString("F1"); + string duration = project.Stopwatch.ElapsedSeconds.ToString("F1"); ReadOnlyMemory? outputPath = project.OutputPath; string projectFile = e.ProjectFile is not null ? From 5e2442415c32e6b8a12fee99c4cdc1b53169d702 Mon Sep 17 00:00:00 2001 From: Rainer Sigwald Date: Tue, 19 Dec 2023 13:54:22 -0600 Subject: [PATCH 3/7] Use MockStopwatch and turn off scrubbing of timestamps in tl tests --- ...ritesWithNewTargetFramework.Linux.verified.txt | 4 ++-- ...rwritesWithNewTargetFramework.OSX.verified.txt | 4 ++-- ...tesWithNewTargetFramework.Windows.verified.txt | 4 ++-- ...ts.DisplayNodesShowsCurrent.Linux.verified.txt | 2 +- ...ests.DisplayNodesShowsCurrent.OSX.verified.txt | 2 +- ....DisplayNodesShowsCurrent.Windows.verified.txt | 2 +- ...ts.PrintBuildSummary_Failed.Linux.verified.txt | 2 +- ...ests.PrintBuildSummary_Failed.OSX.verified.txt | 2 +- ....PrintBuildSummary_Failed.Windows.verified.txt | 2 +- ...ildSummary_FailedWithErrors.Linux.verified.txt | 4 ++-- ...BuildSummary_FailedWithErrors.OSX.verified.txt | 4 ++-- ...dSummary_FailedWithErrors.Windows.verified.txt | 4 ++-- ...mmary_SucceededWithWarnings.Linux.verified.txt | 4 ++-- ...Summary_SucceededWithWarnings.OSX.verified.txt | 4 ++-- ...ary_SucceededWithWarnings.Windows.verified.txt | 4 ++-- ...intImmediateMessage_Skipped.Linux.verified.txt | 2 +- ...PrintImmediateMessage_Skipped.OSX.verified.txt | 2 +- ...tImmediateMessage_Skipped.Windows.verified.txt | 2 +- ...intImmediateMessage_Success.Linux.verified.txt | 2 +- ...PrintImmediateMessage_Success.OSX.verified.txt | 2 +- ...tImmediateMessage_Success.Windows.verified.txt | 2 +- ...ateWarningMessage_Succeeded.Linux.verified.txt | 4 ++-- ...diateWarningMessage_Succeeded.OSX.verified.txt | 4 ++-- ...eWarningMessage_Succeeded.Windows.verified.txt | 4 ++-- ...r_Tests.PrintRestore_Failed.Linux.verified.txt | 4 ++-- ...ger_Tests.PrintRestore_Failed.OSX.verified.txt | 2 +- ...Tests.PrintRestore_Failed.Windows.verified.txt | 4 ++-- ...Restore_SuccessWithWarnings.Linux.verified.txt | 4 ++-- ...ntRestore_SuccessWithWarnings.OSX.verified.txt | 2 +- ...store_SuccessWithWarnings.Windows.verified.txt | 4 ++-- ...rintsBuildSummary_Succeeded.Linux.verified.txt | 2 +- ....PrintsBuildSummary_Succeeded.OSX.verified.txt | 2 +- ...ntsBuildSummary_Succeeded.Windows.verified.txt | 2 +- src/MSBuild.UnitTests/TerminalLogger_Tests.cs | 15 +++------------ src/MSBuild/TerminalLogger/Project.cs | 14 ++++++++++++-- src/MSBuild/TerminalLogger/TerminalLogger.cs | 4 +++- 36 files changed, 67 insertions(+), 64 deletions(-) diff --git a/src/MSBuild.UnitTests/Snapshots/TerminalLogger_Tests.DisplayNodesOverwritesWithNewTargetFramework.Linux.verified.txt b/src/MSBuild.UnitTests/Snapshots/TerminalLogger_Tests.DisplayNodesOverwritesWithNewTargetFramework.Linux.verified.txt index fe12f4e9dec..7e605333ed6 100644 --- a/src/MSBuild.UnitTests/Snapshots/TerminalLogger_Tests.DisplayNodesOverwritesWithNewTargetFramework.Linux.verified.txt +++ b/src/MSBuild.UnitTests/Snapshots/TerminalLogger_Tests.DisplayNodesOverwritesWithNewTargetFramework.Linux.verified.txt @@ -1,5 +1,5 @@ ]9;4;3;\[?25l - project tfName Build (0.0s) + project tfName Build (0.2s) [?25h[?25l - project tf2 Build (0.0s) + project tf2 Build (0.2s) [?25h \ No newline at end of file diff --git a/src/MSBuild.UnitTests/Snapshots/TerminalLogger_Tests.DisplayNodesOverwritesWithNewTargetFramework.OSX.verified.txt b/src/MSBuild.UnitTests/Snapshots/TerminalLogger_Tests.DisplayNodesOverwritesWithNewTargetFramework.OSX.verified.txt index 8d078e61f5c..5018115c62a 100644 --- a/src/MSBuild.UnitTests/Snapshots/TerminalLogger_Tests.DisplayNodesOverwritesWithNewTargetFramework.OSX.verified.txt +++ b/src/MSBuild.UnitTests/Snapshots/TerminalLogger_Tests.DisplayNodesOverwritesWithNewTargetFramework.OSX.verified.txt @@ -1,5 +1,5 @@ [?25l - project tfName Build (0.0s) + project tfName Build (0.2s) [?25h[?25l - project tf2 Build (0.0s) + project tf2 Build (0.2s) [?25h \ No newline at end of file diff --git a/src/MSBuild.UnitTests/Snapshots/TerminalLogger_Tests.DisplayNodesOverwritesWithNewTargetFramework.Windows.verified.txt b/src/MSBuild.UnitTests/Snapshots/TerminalLogger_Tests.DisplayNodesOverwritesWithNewTargetFramework.Windows.verified.txt index fe12f4e9dec..7e605333ed6 100644 --- a/src/MSBuild.UnitTests/Snapshots/TerminalLogger_Tests.DisplayNodesOverwritesWithNewTargetFramework.Windows.verified.txt +++ b/src/MSBuild.UnitTests/Snapshots/TerminalLogger_Tests.DisplayNodesOverwritesWithNewTargetFramework.Windows.verified.txt @@ -1,5 +1,5 @@ ]9;4;3;\[?25l - project tfName Build (0.0s) + project tfName Build (0.2s) [?25h[?25l - project tf2 Build (0.0s) + project tf2 Build (0.2s) [?25h \ No newline at end of file diff --git a/src/MSBuild.UnitTests/Snapshots/TerminalLogger_Tests.DisplayNodesShowsCurrent.Linux.verified.txt b/src/MSBuild.UnitTests/Snapshots/TerminalLogger_Tests.DisplayNodesShowsCurrent.Linux.verified.txt index 1f7b782f2ef..ccfb1bac3a5 100644 --- a/src/MSBuild.UnitTests/Snapshots/TerminalLogger_Tests.DisplayNodesShowsCurrent.Linux.verified.txt +++ b/src/MSBuild.UnitTests/Snapshots/TerminalLogger_Tests.DisplayNodesShowsCurrent.Linux.verified.txt @@ -1,3 +1,3 @@ ]9;4;3;\[?25l - project Build (0.0s) + project Build (0.2s) [?25h \ No newline at end of file diff --git a/src/MSBuild.UnitTests/Snapshots/TerminalLogger_Tests.DisplayNodesShowsCurrent.OSX.verified.txt b/src/MSBuild.UnitTests/Snapshots/TerminalLogger_Tests.DisplayNodesShowsCurrent.OSX.verified.txt index 143745dea40..c671e994c3e 100644 --- a/src/MSBuild.UnitTests/Snapshots/TerminalLogger_Tests.DisplayNodesShowsCurrent.OSX.verified.txt +++ b/src/MSBuild.UnitTests/Snapshots/TerminalLogger_Tests.DisplayNodesShowsCurrent.OSX.verified.txt @@ -1,3 +1,3 @@ [?25l - project Build (0.0s) + project Build (0.2s) [?25h \ No newline at end of file diff --git a/src/MSBuild.UnitTests/Snapshots/TerminalLogger_Tests.DisplayNodesShowsCurrent.Windows.verified.txt b/src/MSBuild.UnitTests/Snapshots/TerminalLogger_Tests.DisplayNodesShowsCurrent.Windows.verified.txt index 1f7b782f2ef..ccfb1bac3a5 100644 --- a/src/MSBuild.UnitTests/Snapshots/TerminalLogger_Tests.DisplayNodesShowsCurrent.Windows.verified.txt +++ b/src/MSBuild.UnitTests/Snapshots/TerminalLogger_Tests.DisplayNodesShowsCurrent.Windows.verified.txt @@ -1,3 +1,3 @@ ]9;4;3;\[?25l - project Build (0.0s) + project Build (0.2s) [?25h \ No newline at end of file diff --git a/src/MSBuild.UnitTests/Snapshots/TerminalLogger_Tests.PrintBuildSummary_Failed.Linux.verified.txt b/src/MSBuild.UnitTests/Snapshots/TerminalLogger_Tests.PrintBuildSummary_Failed.Linux.verified.txt index e397b179c6b..b863cb67194 100644 --- a/src/MSBuild.UnitTests/Snapshots/TerminalLogger_Tests.PrintBuildSummary_Failed.Linux.verified.txt +++ b/src/MSBuild.UnitTests/Snapshots/TerminalLogger_Tests.PrintBuildSummary_Failed.Linux.verified.txt @@ -1,4 +1,4 @@ ]9;4;3;\[?25l [?25h -Build failed in 0.0s +Build failed in 5.0s ]9;4;0;\ \ No newline at end of file diff --git a/src/MSBuild.UnitTests/Snapshots/TerminalLogger_Tests.PrintBuildSummary_Failed.OSX.verified.txt b/src/MSBuild.UnitTests/Snapshots/TerminalLogger_Tests.PrintBuildSummary_Failed.OSX.verified.txt index 5dac0df45b6..c36142ab71a 100644 --- a/src/MSBuild.UnitTests/Snapshots/TerminalLogger_Tests.PrintBuildSummary_Failed.OSX.verified.txt +++ b/src/MSBuild.UnitTests/Snapshots/TerminalLogger_Tests.PrintBuildSummary_Failed.OSX.verified.txt @@ -1,3 +1,3 @@ [?25l [?25h -Build failed in 0.0s +Build failed in 5.0s diff --git a/src/MSBuild.UnitTests/Snapshots/TerminalLogger_Tests.PrintBuildSummary_Failed.Windows.verified.txt b/src/MSBuild.UnitTests/Snapshots/TerminalLogger_Tests.PrintBuildSummary_Failed.Windows.verified.txt index e397b179c6b..b863cb67194 100644 --- a/src/MSBuild.UnitTests/Snapshots/TerminalLogger_Tests.PrintBuildSummary_Failed.Windows.verified.txt +++ b/src/MSBuild.UnitTests/Snapshots/TerminalLogger_Tests.PrintBuildSummary_Failed.Windows.verified.txt @@ -1,4 +1,4 @@ ]9;4;3;\[?25l [?25h -Build failed in 0.0s +Build failed in 5.0s ]9;4;0;\ \ No newline at end of file diff --git a/src/MSBuild.UnitTests/Snapshots/TerminalLogger_Tests.PrintBuildSummary_FailedWithErrors.Linux.verified.txt b/src/MSBuild.UnitTests/Snapshots/TerminalLogger_Tests.PrintBuildSummary_FailedWithErrors.Linux.verified.txt index 0041a7257fe..11e72f94fbf 100644 --- a/src/MSBuild.UnitTests/Snapshots/TerminalLogger_Tests.PrintBuildSummary_FailedWithErrors.Linux.verified.txt +++ b/src/MSBuild.UnitTests/Snapshots/TerminalLogger_Tests.PrintBuildSummary_FailedWithErrors.Linux.verified.txt @@ -1,6 +1,6 @@ -]9;4;3;\ project failed with errors (0.0s) +]9;4;3;\ project failed with errors (0.2s) directory/file(1,2,3,4): error AA0000: Error! [?25l [?25h -Build failed with errors in 0.0s +Build failed with errors in 5.0s ]9;4;0;\ \ No newline at end of file diff --git a/src/MSBuild.UnitTests/Snapshots/TerminalLogger_Tests.PrintBuildSummary_FailedWithErrors.OSX.verified.txt b/src/MSBuild.UnitTests/Snapshots/TerminalLogger_Tests.PrintBuildSummary_FailedWithErrors.OSX.verified.txt index cf0d8f1d6c9..bc476784fbb 100644 --- a/src/MSBuild.UnitTests/Snapshots/TerminalLogger_Tests.PrintBuildSummary_FailedWithErrors.OSX.verified.txt +++ b/src/MSBuild.UnitTests/Snapshots/TerminalLogger_Tests.PrintBuildSummary_FailedWithErrors.OSX.verified.txt @@ -1,5 +1,5 @@ - project failed with errors (0.0s) + project failed with errors (0.2s) directory/file(1,2,3,4): error AA0000: Error! [?25l [?25h -Build failed with errors in 0.0s +Build failed with errors in 5.0s diff --git a/src/MSBuild.UnitTests/Snapshots/TerminalLogger_Tests.PrintBuildSummary_FailedWithErrors.Windows.verified.txt b/src/MSBuild.UnitTests/Snapshots/TerminalLogger_Tests.PrintBuildSummary_FailedWithErrors.Windows.verified.txt index 0041a7257fe..11e72f94fbf 100644 --- a/src/MSBuild.UnitTests/Snapshots/TerminalLogger_Tests.PrintBuildSummary_FailedWithErrors.Windows.verified.txt +++ b/src/MSBuild.UnitTests/Snapshots/TerminalLogger_Tests.PrintBuildSummary_FailedWithErrors.Windows.verified.txt @@ -1,6 +1,6 @@ -]9;4;3;\ project failed with errors (0.0s) +]9;4;3;\ project failed with errors (0.2s) directory/file(1,2,3,4): error AA0000: Error! [?25l [?25h -Build failed with errors in 0.0s +Build failed with errors in 5.0s ]9;4;0;\ \ No newline at end of file diff --git a/src/MSBuild.UnitTests/Snapshots/TerminalLogger_Tests.PrintBuildSummary_SucceededWithWarnings.Linux.verified.txt b/src/MSBuild.UnitTests/Snapshots/TerminalLogger_Tests.PrintBuildSummary_SucceededWithWarnings.Linux.verified.txt index 86c02fdb8df..aeec26abf26 100644 --- a/src/MSBuild.UnitTests/Snapshots/TerminalLogger_Tests.PrintBuildSummary_SucceededWithWarnings.Linux.verified.txt +++ b/src/MSBuild.UnitTests/Snapshots/TerminalLogger_Tests.PrintBuildSummary_SucceededWithWarnings.Linux.verified.txt @@ -1,6 +1,6 @@ -]9;4;3;\ project succeeded with warnings (0.0s) +]9;4;3;\ project succeeded with warnings (0.2s) directory/file(1,2,3,4): warning AA0000: Warning! [?25l [?25h -Build succeeded with warnings in 0.0s +Build succeeded with warnings in 5.0s ]9;4;0;\ \ No newline at end of file diff --git a/src/MSBuild.UnitTests/Snapshots/TerminalLogger_Tests.PrintBuildSummary_SucceededWithWarnings.OSX.verified.txt b/src/MSBuild.UnitTests/Snapshots/TerminalLogger_Tests.PrintBuildSummary_SucceededWithWarnings.OSX.verified.txt index 43510237153..3b6fcaf238d 100644 --- a/src/MSBuild.UnitTests/Snapshots/TerminalLogger_Tests.PrintBuildSummary_SucceededWithWarnings.OSX.verified.txt +++ b/src/MSBuild.UnitTests/Snapshots/TerminalLogger_Tests.PrintBuildSummary_SucceededWithWarnings.OSX.verified.txt @@ -1,5 +1,5 @@ - project succeeded with warnings (0.0s) + project succeeded with warnings (0.2s) directory/file(1,2,3,4): warning AA0000: Warning! [?25l [?25h -Build succeeded with warnings in 0.0s +Build succeeded with warnings in 5.0s diff --git a/src/MSBuild.UnitTests/Snapshots/TerminalLogger_Tests.PrintBuildSummary_SucceededWithWarnings.Windows.verified.txt b/src/MSBuild.UnitTests/Snapshots/TerminalLogger_Tests.PrintBuildSummary_SucceededWithWarnings.Windows.verified.txt index 86c02fdb8df..aeec26abf26 100644 --- a/src/MSBuild.UnitTests/Snapshots/TerminalLogger_Tests.PrintBuildSummary_SucceededWithWarnings.Windows.verified.txt +++ b/src/MSBuild.UnitTests/Snapshots/TerminalLogger_Tests.PrintBuildSummary_SucceededWithWarnings.Windows.verified.txt @@ -1,6 +1,6 @@ -]9;4;3;\ project succeeded with warnings (0.0s) +]9;4;3;\ project succeeded with warnings (0.2s) directory/file(1,2,3,4): warning AA0000: Warning! [?25l [?25h -Build succeeded with warnings in 0.0s +Build succeeded with warnings in 5.0s ]9;4;0;\ \ No newline at end of file diff --git a/src/MSBuild.UnitTests/Snapshots/TerminalLogger_Tests.PrintImmediateMessage_Skipped.Linux.verified.txt b/src/MSBuild.UnitTests/Snapshots/TerminalLogger_Tests.PrintImmediateMessage_Skipped.Linux.verified.txt index e6169b4e163..d5e6b72e894 100644 --- a/src/MSBuild.UnitTests/Snapshots/TerminalLogger_Tests.PrintImmediateMessage_Skipped.Linux.verified.txt +++ b/src/MSBuild.UnitTests/Snapshots/TerminalLogger_Tests.PrintImmediateMessage_Skipped.Linux.verified.txt @@ -1,4 +1,4 @@ ]9;4;3;\[?25l [?25h -Build succeeded in 0.0s +Build succeeded in 5.0s ]9;4;0;\ \ No newline at end of file diff --git a/src/MSBuild.UnitTests/Snapshots/TerminalLogger_Tests.PrintImmediateMessage_Skipped.OSX.verified.txt b/src/MSBuild.UnitTests/Snapshots/TerminalLogger_Tests.PrintImmediateMessage_Skipped.OSX.verified.txt index de2ebf4c55e..4d414bf90bf 100644 --- a/src/MSBuild.UnitTests/Snapshots/TerminalLogger_Tests.PrintImmediateMessage_Skipped.OSX.verified.txt +++ b/src/MSBuild.UnitTests/Snapshots/TerminalLogger_Tests.PrintImmediateMessage_Skipped.OSX.verified.txt @@ -1,3 +1,3 @@ [?25l [?25h -Build succeeded in 0.0s +Build succeeded in 5.0s diff --git a/src/MSBuild.UnitTests/Snapshots/TerminalLogger_Tests.PrintImmediateMessage_Skipped.Windows.verified.txt b/src/MSBuild.UnitTests/Snapshots/TerminalLogger_Tests.PrintImmediateMessage_Skipped.Windows.verified.txt index e6169b4e163..d5e6b72e894 100644 --- a/src/MSBuild.UnitTests/Snapshots/TerminalLogger_Tests.PrintImmediateMessage_Skipped.Windows.verified.txt +++ b/src/MSBuild.UnitTests/Snapshots/TerminalLogger_Tests.PrintImmediateMessage_Skipped.Windows.verified.txt @@ -1,4 +1,4 @@ ]9;4;3;\[?25l [?25h -Build succeeded in 0.0s +Build succeeded in 5.0s ]9;4;0;\ \ No newline at end of file diff --git a/src/MSBuild.UnitTests/Snapshots/TerminalLogger_Tests.PrintImmediateMessage_Success.Linux.verified.txt b/src/MSBuild.UnitTests/Snapshots/TerminalLogger_Tests.PrintImmediateMessage_Success.Linux.verified.txt index 86eed92792e..75842281bfb 100644 --- a/src/MSBuild.UnitTests/Snapshots/TerminalLogger_Tests.PrintImmediateMessage_Success.Linux.verified.txt +++ b/src/MSBuild.UnitTests/Snapshots/TerminalLogger_Tests.PrintImmediateMessage_Success.Linux.verified.txt @@ -1,5 +1,5 @@ ]9;4;3;\The plugin credential provider could not acquire credentials.Authentication may require manual action. Consider re-running the command with --interactive for `dotnet`, /p:NuGetInteractive="true" for MSBuild or removing the -NonInteractive switch for `NuGet` [?25l [?25h -Build succeeded in 0.0s +Build succeeded in 5.0s ]9;4;0;\ \ No newline at end of file diff --git a/src/MSBuild.UnitTests/Snapshots/TerminalLogger_Tests.PrintImmediateMessage_Success.OSX.verified.txt b/src/MSBuild.UnitTests/Snapshots/TerminalLogger_Tests.PrintImmediateMessage_Success.OSX.verified.txt index acf188a70ce..1e10e7fc988 100644 --- a/src/MSBuild.UnitTests/Snapshots/TerminalLogger_Tests.PrintImmediateMessage_Success.OSX.verified.txt +++ b/src/MSBuild.UnitTests/Snapshots/TerminalLogger_Tests.PrintImmediateMessage_Success.OSX.verified.txt @@ -1,4 +1,4 @@ The plugin credential provider could not acquire credentials.Authentication may require manual action. Consider re-running the command with --interactive for `dotnet`, /p:NuGetInteractive="true" for MSBuild or removing the -NonInteractive switch for `NuGet` [?25l [?25h -Build succeeded in 0.0s +Build succeeded in 5.0s diff --git a/src/MSBuild.UnitTests/Snapshots/TerminalLogger_Tests.PrintImmediateMessage_Success.Windows.verified.txt b/src/MSBuild.UnitTests/Snapshots/TerminalLogger_Tests.PrintImmediateMessage_Success.Windows.verified.txt index 86eed92792e..75842281bfb 100644 --- a/src/MSBuild.UnitTests/Snapshots/TerminalLogger_Tests.PrintImmediateMessage_Success.Windows.verified.txt +++ b/src/MSBuild.UnitTests/Snapshots/TerminalLogger_Tests.PrintImmediateMessage_Success.Windows.verified.txt @@ -1,5 +1,5 @@ ]9;4;3;\The plugin credential provider could not acquire credentials.Authentication may require manual action. Consider re-running the command with --interactive for `dotnet`, /p:NuGetInteractive="true" for MSBuild or removing the -NonInteractive switch for `NuGet` [?25l [?25h -Build succeeded in 0.0s +Build succeeded in 5.0s ]9;4;0;\ \ No newline at end of file diff --git a/src/MSBuild.UnitTests/Snapshots/TerminalLogger_Tests.PrintImmediateWarningMessage_Succeeded.Linux.verified.txt b/src/MSBuild.UnitTests/Snapshots/TerminalLogger_Tests.PrintImmediateWarningMessage_Succeeded.Linux.verified.txt index d3967bfd576..512b5b78d7e 100644 --- a/src/MSBuild.UnitTests/Snapshots/TerminalLogger_Tests.PrintImmediateWarningMessage_Succeeded.Linux.verified.txt +++ b/src/MSBuild.UnitTests/Snapshots/TerminalLogger_Tests.PrintImmediateWarningMessage_Succeeded.Linux.verified.txt @@ -1,9 +1,9 @@ ]9;4;3;\directory/file(1,2,3,4): warning AA0000: [CredentialProvider]DeviceFlow: https://testfeed/index.json directory/file(1,2,3,4): warning AA0000: [CredentialProvider]ATTENTION: User interaction required.**********************************************************************To sign in, use a web browser to open the page https://devicelogin and enter the code XXXXXX to authenticate.********************************************************************** - project succeeded with warnings (0.0s) + project succeeded with warnings (0.2s) directory/file(1,2,3,4): warning AA0000: [CredentialProvider]DeviceFlow: https://testfeed/index.json directory/file(1,2,3,4): warning AA0000: [CredentialProvider]ATTENTION: User interaction required.**********************************************************************To sign in, use a web browser to open the page https://devicelogin and enter the code XXXXXX to authenticate.********************************************************************** [?25l [?25h -Build succeeded with warnings in 0.0s +Build succeeded with warnings in 5.0s ]9;4;0;\ \ No newline at end of file diff --git a/src/MSBuild.UnitTests/Snapshots/TerminalLogger_Tests.PrintImmediateWarningMessage_Succeeded.OSX.verified.txt b/src/MSBuild.UnitTests/Snapshots/TerminalLogger_Tests.PrintImmediateWarningMessage_Succeeded.OSX.verified.txt index 42c777b8c11..0b5a2d831c1 100644 --- a/src/MSBuild.UnitTests/Snapshots/TerminalLogger_Tests.PrintImmediateWarningMessage_Succeeded.OSX.verified.txt +++ b/src/MSBuild.UnitTests/Snapshots/TerminalLogger_Tests.PrintImmediateWarningMessage_Succeeded.OSX.verified.txt @@ -1,8 +1,8 @@ directory/file(1,2,3,4): warning AA0000: [CredentialProvider]DeviceFlow: https://testfeed/index.json directory/file(1,2,3,4): warning AA0000: [CredentialProvider]ATTENTION: User interaction required.**********************************************************************To sign in, use a web browser to open the page https://devicelogin and enter the code XXXXXX to authenticate.********************************************************************** - project succeeded with warnings (0.0s) + project succeeded with warnings (0.2s) directory/file(1,2,3,4): warning AA0000: [CredentialProvider]DeviceFlow: https://testfeed/index.json directory/file(1,2,3,4): warning AA0000: [CredentialProvider]ATTENTION: User interaction required.**********************************************************************To sign in, use a web browser to open the page https://devicelogin and enter the code XXXXXX to authenticate.********************************************************************** [?25l [?25h -Build succeeded with warnings in 0.0s +Build succeeded with warnings in 5.0s diff --git a/src/MSBuild.UnitTests/Snapshots/TerminalLogger_Tests.PrintImmediateWarningMessage_Succeeded.Windows.verified.txt b/src/MSBuild.UnitTests/Snapshots/TerminalLogger_Tests.PrintImmediateWarningMessage_Succeeded.Windows.verified.txt index d3967bfd576..512b5b78d7e 100644 --- a/src/MSBuild.UnitTests/Snapshots/TerminalLogger_Tests.PrintImmediateWarningMessage_Succeeded.Windows.verified.txt +++ b/src/MSBuild.UnitTests/Snapshots/TerminalLogger_Tests.PrintImmediateWarningMessage_Succeeded.Windows.verified.txt @@ -1,9 +1,9 @@ ]9;4;3;\directory/file(1,2,3,4): warning AA0000: [CredentialProvider]DeviceFlow: https://testfeed/index.json directory/file(1,2,3,4): warning AA0000: [CredentialProvider]ATTENTION: User interaction required.**********************************************************************To sign in, use a web browser to open the page https://devicelogin and enter the code XXXXXX to authenticate.********************************************************************** - project succeeded with warnings (0.0s) + project succeeded with warnings (0.2s) directory/file(1,2,3,4): warning AA0000: [CredentialProvider]DeviceFlow: https://testfeed/index.json directory/file(1,2,3,4): warning AA0000: [CredentialProvider]ATTENTION: User interaction required.**********************************************************************To sign in, use a web browser to open the page https://devicelogin and enter the code XXXXXX to authenticate.********************************************************************** [?25l [?25h -Build succeeded with warnings in 0.0s +Build succeeded with warnings in 5.0s ]9;4;0;\ \ No newline at end of file diff --git a/src/MSBuild.UnitTests/Snapshots/TerminalLogger_Tests.PrintRestore_Failed.Linux.verified.txt b/src/MSBuild.UnitTests/Snapshots/TerminalLogger_Tests.PrintRestore_Failed.Linux.verified.txt index 1df7926cf3f..fde469843b0 100644 --- a/src/MSBuild.UnitTests/Snapshots/TerminalLogger_Tests.PrintRestore_Failed.Linux.verified.txt +++ b/src/MSBuild.UnitTests/Snapshots/TerminalLogger_Tests.PrintRestore_Failed.Linux.verified.txt @@ -1,4 +1,4 @@ -directory/file(1,2,3,4): error AA0000: Restore Failed +]9;4;3;\directory/file(1,2,3,4): error AA0000: Restore Failed -Build failed with errors in 0.0s +Build failed with errors in 5.0s ]9;4;0;\ \ No newline at end of file diff --git a/src/MSBuild.UnitTests/Snapshots/TerminalLogger_Tests.PrintRestore_Failed.OSX.verified.txt b/src/MSBuild.UnitTests/Snapshots/TerminalLogger_Tests.PrintRestore_Failed.OSX.verified.txt index c4d47333679..f912378dc48 100644 --- a/src/MSBuild.UnitTests/Snapshots/TerminalLogger_Tests.PrintRestore_Failed.OSX.verified.txt +++ b/src/MSBuild.UnitTests/Snapshots/TerminalLogger_Tests.PrintRestore_Failed.OSX.verified.txt @@ -1,3 +1,3 @@ directory/file(1,2,3,4): error AA0000: Restore Failed -Build failed with errors in 0.0s +Build failed with errors in 5.0s diff --git a/src/MSBuild.UnitTests/Snapshots/TerminalLogger_Tests.PrintRestore_Failed.Windows.verified.txt b/src/MSBuild.UnitTests/Snapshots/TerminalLogger_Tests.PrintRestore_Failed.Windows.verified.txt index 1df7926cf3f..fde469843b0 100644 --- a/src/MSBuild.UnitTests/Snapshots/TerminalLogger_Tests.PrintRestore_Failed.Windows.verified.txt +++ b/src/MSBuild.UnitTests/Snapshots/TerminalLogger_Tests.PrintRestore_Failed.Windows.verified.txt @@ -1,4 +1,4 @@ -directory/file(1,2,3,4): error AA0000: Restore Failed +]9;4;3;\directory/file(1,2,3,4): error AA0000: Restore Failed -Build failed with errors in 0.0s +Build failed with errors in 5.0s ]9;4;0;\ \ No newline at end of file diff --git a/src/MSBuild.UnitTests/Snapshots/TerminalLogger_Tests.PrintRestore_SuccessWithWarnings.Linux.verified.txt b/src/MSBuild.UnitTests/Snapshots/TerminalLogger_Tests.PrintRestore_SuccessWithWarnings.Linux.verified.txt index bc7006945a4..927084af0f3 100644 --- a/src/MSBuild.UnitTests/Snapshots/TerminalLogger_Tests.PrintRestore_SuccessWithWarnings.Linux.verified.txt +++ b/src/MSBuild.UnitTests/Snapshots/TerminalLogger_Tests.PrintRestore_SuccessWithWarnings.Linux.verified.txt @@ -1,4 +1,4 @@ -directory/file(1,2,3,4): warning AA0000: Restore with Warning +]9;4;3;\directory/file(1,2,3,4): warning AA0000: Restore with Warning -Build succeeded with warnings in 0.0s +Build succeeded with warnings in 5.0s ]9;4;0;\ \ No newline at end of file diff --git a/src/MSBuild.UnitTests/Snapshots/TerminalLogger_Tests.PrintRestore_SuccessWithWarnings.OSX.verified.txt b/src/MSBuild.UnitTests/Snapshots/TerminalLogger_Tests.PrintRestore_SuccessWithWarnings.OSX.verified.txt index 8756e2b3be2..430fce9be26 100644 --- a/src/MSBuild.UnitTests/Snapshots/TerminalLogger_Tests.PrintRestore_SuccessWithWarnings.OSX.verified.txt +++ b/src/MSBuild.UnitTests/Snapshots/TerminalLogger_Tests.PrintRestore_SuccessWithWarnings.OSX.verified.txt @@ -1,3 +1,3 @@ directory/file(1,2,3,4): warning AA0000: Restore with Warning -Build succeeded with warnings in 0.0s +Build succeeded with warnings in 5.0s diff --git a/src/MSBuild.UnitTests/Snapshots/TerminalLogger_Tests.PrintRestore_SuccessWithWarnings.Windows.verified.txt b/src/MSBuild.UnitTests/Snapshots/TerminalLogger_Tests.PrintRestore_SuccessWithWarnings.Windows.verified.txt index bc7006945a4..927084af0f3 100644 --- a/src/MSBuild.UnitTests/Snapshots/TerminalLogger_Tests.PrintRestore_SuccessWithWarnings.Windows.verified.txt +++ b/src/MSBuild.UnitTests/Snapshots/TerminalLogger_Tests.PrintRestore_SuccessWithWarnings.Windows.verified.txt @@ -1,4 +1,4 @@ -directory/file(1,2,3,4): warning AA0000: Restore with Warning +]9;4;3;\directory/file(1,2,3,4): warning AA0000: Restore with Warning -Build succeeded with warnings in 0.0s +Build succeeded with warnings in 5.0s ]9;4;0;\ \ No newline at end of file diff --git a/src/MSBuild.UnitTests/Snapshots/TerminalLogger_Tests.PrintsBuildSummary_Succeeded.Linux.verified.txt b/src/MSBuild.UnitTests/Snapshots/TerminalLogger_Tests.PrintsBuildSummary_Succeeded.Linux.verified.txt index e6169b4e163..d5e6b72e894 100644 --- a/src/MSBuild.UnitTests/Snapshots/TerminalLogger_Tests.PrintsBuildSummary_Succeeded.Linux.verified.txt +++ b/src/MSBuild.UnitTests/Snapshots/TerminalLogger_Tests.PrintsBuildSummary_Succeeded.Linux.verified.txt @@ -1,4 +1,4 @@ ]9;4;3;\[?25l [?25h -Build succeeded in 0.0s +Build succeeded in 5.0s ]9;4;0;\ \ No newline at end of file diff --git a/src/MSBuild.UnitTests/Snapshots/TerminalLogger_Tests.PrintsBuildSummary_Succeeded.OSX.verified.txt b/src/MSBuild.UnitTests/Snapshots/TerminalLogger_Tests.PrintsBuildSummary_Succeeded.OSX.verified.txt index de2ebf4c55e..4d414bf90bf 100644 --- a/src/MSBuild.UnitTests/Snapshots/TerminalLogger_Tests.PrintsBuildSummary_Succeeded.OSX.verified.txt +++ b/src/MSBuild.UnitTests/Snapshots/TerminalLogger_Tests.PrintsBuildSummary_Succeeded.OSX.verified.txt @@ -1,3 +1,3 @@ [?25l [?25h -Build succeeded in 0.0s +Build succeeded in 5.0s diff --git a/src/MSBuild.UnitTests/Snapshots/TerminalLogger_Tests.PrintsBuildSummary_Succeeded.Windows.verified.txt b/src/MSBuild.UnitTests/Snapshots/TerminalLogger_Tests.PrintsBuildSummary_Succeeded.Windows.verified.txt index e6169b4e163..d5e6b72e894 100644 --- a/src/MSBuild.UnitTests/Snapshots/TerminalLogger_Tests.PrintsBuildSummary_Succeeded.Windows.verified.txt +++ b/src/MSBuild.UnitTests/Snapshots/TerminalLogger_Tests.PrintsBuildSummary_Succeeded.Windows.verified.txt @@ -1,4 +1,4 @@ ]9;4;3;\[?25l [?25h -Build succeeded in 0.0s +Build succeeded in 5.0s ]9;4;0;\ \ No newline at end of file diff --git a/src/MSBuild.UnitTests/TerminalLogger_Tests.cs b/src/MSBuild.UnitTests/TerminalLogger_Tests.cs index 9d764455e9a..464a78b07f8 100644 --- a/src/MSBuild.UnitTests/TerminalLogger_Tests.cs +++ b/src/MSBuild.UnitTests/TerminalLogger_Tests.cs @@ -11,6 +11,7 @@ using System.Threading; using System.Threading.Tasks; using Microsoft.Build.BackEnd.Logging; +using Microsoft.Build.CommandLine.UnitTests; using Microsoft.Build.Evaluation; using Microsoft.Build.Framework; using Microsoft.Build.Logging; @@ -41,8 +42,6 @@ public class TerminalLogger_Tests : IEventSource, IDisposable private VerifySettings _settings = new(); - private static Regex s_elapsedTime = new($@"\d+{Regex.Escape(CultureInfo.CurrentCulture.NumberFormat.NumberDecimalSeparator)}\ds", RegexOptions.Compiled); - public TerminalLogger_Tests() { _mockTerminal = new Terminal(_outputWriter); @@ -50,17 +49,9 @@ public TerminalLogger_Tests() _terminallogger.Initialize(this, _nodeCount); - UseProjectRelativeDirectory("Snapshots"); + _terminallogger.CreateStopwatch = () => new MockStopwatch(); - // Scrub timestamps on intermediate execution lines, - // which are subject to the vagaries of the test machine - // and OS scheduler. - _settings.AddScrubber(static lineBuilder => - { - string line = lineBuilder.ToString(); - lineBuilder.Clear(); - lineBuilder.Append(s_elapsedTime.Replace(line, "0.0s")); - }); + UseProjectRelativeDirectory("Snapshots"); } #region IEventSource implementation diff --git a/src/MSBuild/TerminalLogger/Project.cs b/src/MSBuild/TerminalLogger/Project.cs index f7f57c57b8b..3f027249782 100644 --- a/src/MSBuild/TerminalLogger/Project.cs +++ b/src/MSBuild/TerminalLogger/Project.cs @@ -16,15 +16,25 @@ internal sealed class Project /// Initialized a new with the given . /// /// The target framework of the project or null if not multi-targeting. - public Project(string? targetFramework) + public Project(string? targetFramework, StopwatchAbstraction? stopwatch) { TargetFramework = targetFramework; + + if (stopwatch is not null) + { + stopwatch.Start(); + Stopwatch = stopwatch; + } + else + { + Stopwatch = SystemStopwatch.StartNew(); + } } /// /// A stopwatch to time the build of the project. /// - public StopwatchAbstraction Stopwatch { get; } = SystemStopwatch.StartNew(); + public StopwatchAbstraction Stopwatch { get; } /// /// Full path to the primary output of the project, if known. diff --git a/src/MSBuild/TerminalLogger/TerminalLogger.cs b/src/MSBuild/TerminalLogger/TerminalLogger.cs index 0aada4c5ebf..f317fd6c1b8 100644 --- a/src/MSBuild/TerminalLogger/TerminalLogger.cs +++ b/src/MSBuild/TerminalLogger/TerminalLogger.cs @@ -57,6 +57,8 @@ public ProjectContext(BuildEventContext context) internal const TerminalColor TargetFrameworkColor = TerminalColor.Cyan; + internal Func? CreateStopwatch = null; + /// /// Protects access to state shared between the logger callbacks and the rendering thread. /// @@ -318,7 +320,7 @@ private void ProjectStarted(object sender, ProjectStartedEventArgs e) { targetFramework = null; } - _projects[c] = new(targetFramework); + _projects[c] = new(targetFramework, CreateStopwatch?.Invoke()); // First ever restore in the build is starting. if (e.TargetNames == "Restore" && !_restoreFinished) From 15536e9da150e76c9192b5948d66cf257f4e206c Mon Sep 17 00:00:00 2001 From: Rainer Sigwald Date: Tue, 19 Dec 2023 14:00:18 -0600 Subject: [PATCH 4/7] Emit build-started events in PrintRestore tests Without these, the total build elapsed time was surprisingly high (from a timestamp-0 base). --- src/MSBuild.UnitTests/TerminalLogger_Tests.cs | 4 ++++ 1 file changed, 4 insertions(+) diff --git a/src/MSBuild.UnitTests/TerminalLogger_Tests.cs b/src/MSBuild.UnitTests/TerminalLogger_Tests.cs index 464a78b07f8..d900e087f9b 100644 --- a/src/MSBuild.UnitTests/TerminalLogger_Tests.cs +++ b/src/MSBuild.UnitTests/TerminalLogger_Tests.cs @@ -272,6 +272,8 @@ public Task PrintImmediateMessage_Skipped() [Fact] public Task PrintRestore_Failed() { + BuildStarted?.Invoke(_eventSender, MakeBuildStartedEventArgs()); + bool succeeded = false; ErrorRaised?.Invoke(_eventSender, MakeErrorEventArgs("Restore Failed")); @@ -284,6 +286,8 @@ public Task PrintRestore_Failed() [Fact] public Task PrintRestore_SuccessWithWarnings() { + BuildStarted?.Invoke(_eventSender, MakeBuildStartedEventArgs()); + bool succeeded = true; WarningRaised?.Invoke(_eventSender, MakeWarningEventArgs("Restore with Warning")); From cde27684573dcb0bb13481e3622d22c99c9d2b1e Mon Sep 17 00:00:00 2001 From: Rainer Sigwald Date: Tue, 19 Dec 2023 14:16:26 -0600 Subject: [PATCH 5/7] Add regression test for timestamp length --- ...playNodesOverwritesTime.Linux.verified.txt | 3 ++ ...isplayNodesOverwritesTime.OSX.verified.txt | 3 ++ ...ayNodesOverwritesTime.Windows.verified.txt | 3 ++ src/MSBuild.UnitTests/TerminalLogger_Tests.cs | 39 ++++++++++++++++++- 4 files changed, 46 insertions(+), 2 deletions(-) create mode 100644 src/MSBuild.UnitTests/Snapshots/TerminalLogger_Tests.DisplayNodesOverwritesTime.Linux.verified.txt create mode 100644 src/MSBuild.UnitTests/Snapshots/TerminalLogger_Tests.DisplayNodesOverwritesTime.OSX.verified.txt create mode 100644 src/MSBuild.UnitTests/Snapshots/TerminalLogger_Tests.DisplayNodesOverwritesTime.Windows.verified.txt diff --git a/src/MSBuild.UnitTests/Snapshots/TerminalLogger_Tests.DisplayNodesOverwritesTime.Linux.verified.txt b/src/MSBuild.UnitTests/Snapshots/TerminalLogger_Tests.DisplayNodesOverwritesTime.Linux.verified.txt new file mode 100644 index 00000000000..2e9f63be66c --- /dev/null +++ b/src/MSBuild.UnitTests/Snapshots/TerminalLogger_Tests.DisplayNodesOverwritesTime.Linux.verified.txt @@ -0,0 +1,3 @@ +]9;4;3;\[?25l + project Build (111.2s) +[?25h \ No newline at end of file diff --git a/src/MSBuild.UnitTests/Snapshots/TerminalLogger_Tests.DisplayNodesOverwritesTime.OSX.verified.txt b/src/MSBuild.UnitTests/Snapshots/TerminalLogger_Tests.DisplayNodesOverwritesTime.OSX.verified.txt new file mode 100644 index 00000000000..dc43e217d65 --- /dev/null +++ b/src/MSBuild.UnitTests/Snapshots/TerminalLogger_Tests.DisplayNodesOverwritesTime.OSX.verified.txt @@ -0,0 +1,3 @@ +[?25l + project Build (111.2s) +[?25h \ No newline at end of file diff --git a/src/MSBuild.UnitTests/Snapshots/TerminalLogger_Tests.DisplayNodesOverwritesTime.Windows.verified.txt b/src/MSBuild.UnitTests/Snapshots/TerminalLogger_Tests.DisplayNodesOverwritesTime.Windows.verified.txt new file mode 100644 index 00000000000..2e9f63be66c --- /dev/null +++ b/src/MSBuild.UnitTests/Snapshots/TerminalLogger_Tests.DisplayNodesOverwritesTime.Windows.verified.txt @@ -0,0 +1,3 @@ +]9;4;3;\[?25l + project Build (111.2s) +[?25h \ No newline at end of file diff --git a/src/MSBuild.UnitTests/TerminalLogger_Tests.cs b/src/MSBuild.UnitTests/TerminalLogger_Tests.cs index d900e087f9b..80353d7ab31 100644 --- a/src/MSBuild.UnitTests/TerminalLogger_Tests.cs +++ b/src/MSBuild.UnitTests/TerminalLogger_Tests.cs @@ -200,8 +200,6 @@ private void InvokeLoggerCallbacksForSimpleProject(bool succeeded, Action additi additionalCallbacks(); - Thread.Sleep(1_000); - TaskFinished?.Invoke(_eventSender, MakeTaskFinishedEventArgs(_projectFile, "Task", succeeded)); TargetFinished?.Invoke(_eventSender, MakeTargetFinishedEventArgs(_projectFile, "Build", succeeded)); @@ -328,6 +326,43 @@ public void DisplayNodesShowsCurrent() }); } + [Fact] + public void DisplayNodesOverwritesTime() + { + List stopwatches = new(); + + Func? createStopwatch = _terminallogger.CreateStopwatch; + + try + { + _terminallogger.CreateStopwatch = () => + { + MockStopwatch stopwatch = new(); + stopwatches.Add(stopwatch); + return stopwatch; + }; + + InvokeLoggerCallbacksForSimpleProject(succeeded: false, async () => + { + foreach (var stopwatch in stopwatches) + { + // Tick time forward by at least 10 seconds, + // as a regression test for https://github.com/dotnet/msbuild/issues/9562 + stopwatch.Tick(111.0); + } + + _terminallogger.DisplayNodes(); + + await Verify(_outputWriter.ToString(), _settings).UniqueForOSPlatform(); + }); + } + finally + { + _terminallogger.CreateStopwatch = createStopwatch; + } + } + + [Fact] public async Task DisplayNodesOverwritesWithNewTargetFramework() { From 9c0df3c013964953cd296fa54435901a3d819efb Mon Sep 17 00:00:00 2001 From: Rainer Sigwald Date: Tue, 19 Dec 2023 14:26:23 -0600 Subject: [PATCH 6/7] Preserve Verify artifacts in PR builds Based on https://github.com/VerifyTests/Verify/blob/52606c47a07b0c10e53fcfa9809a4e5eb181f51a/docs/wiz/Linux_Other_Cli_xUnit_AzureDevOps.md#getting-received-in-output-on-azure-devops * Add double quotes around echo argument * Use forward slash on *nix Co-authored-by: Ladi Prosek --- .vsts-dotnet-ci.yml | 61 +++++++++++++++++++++++++++++++++++++++++++++ 1 file changed, 61 insertions(+) diff --git a/.vsts-dotnet-ci.yml b/.vsts-dotnet-ci.yml index d538f655a85..922df9717a7 100644 --- a/.vsts-dotnet-ci.yml +++ b/.vsts-dotnet-ci.yml @@ -35,6 +35,11 @@ jobs: mergeTestResults: true continueOnError: true condition: always() + - task: CmdLine@2 + displayName: 'Set flag to publish Verify *.received.* files when test step fails' + condition: failed() + inputs: + script: 'echo "##vso[task.setvariable variable=publishverify]Yes"' - task: PublishBuildArtifacts@1 displayName: 'Publish Artifact: logs' inputs: @@ -49,6 +54,22 @@ jobs: ArtifactName: 'FullOnWindows test logs' continueOnError: true condition: always() + - task: CopyFiles@2 + condition: eq(variables['publishverify'], 'Yes') + displayName: 'Copy Verify *.received.* files to Artifact Staging' + inputs: + contents: '**\*.received.*' + targetFolder: '$(Build.ArtifactStagingDirectory)\Verify' + cleanTargetFolder: true + overWrite: true + - task: PublishBuildArtifacts@1 + displayName: 'Publish Verify *.received.* files as Artifacts' + name: 'verifypublish' + condition: eq(variables['publishverify'], 'Yes') + inputs: + PathtoPublish: '$(Build.ArtifactStagingDirectory)\Verify' + ArtifactName: 'Windows-on-full Verify $(System.JobAttempt)' + - job: BootstrapMSBuildOnCoreWindows displayName: "Windows Core" @@ -185,6 +206,11 @@ jobs: mergeTestResults: true continueOnError: true condition: always() + - task: CmdLine@2 + displayName: 'Set flag to publish Verify *.received.* files when test step fails' + condition: failed() + inputs: + script: 'echo "##vso[task.setvariable variable=publishverify]Yes"' - task: PublishBuildArtifacts@1 displayName: 'Publish Artifact: logs' inputs: @@ -199,6 +225,21 @@ jobs: ArtifactName: 'CoreOnLinux test logs' continueOnError: true condition: always() + - task: CopyFiles@2 + condition: eq(variables['publishverify'], 'Yes') + displayName: 'Copy Verify *.received.* files to Artifact Staging' + inputs: + contents: '**/*.received.*' + targetFolder: '$(Build.ArtifactStagingDirectory)/Verify' + cleanTargetFolder: true + overWrite: true + - task: PublishBuildArtifacts@1 + displayName: 'Publish Verify *.received.* files as Artifacts' + name: 'verifypublish' + condition: eq(variables['publishverify'], 'Yes') + inputs: + PathtoPublish: '$(Build.ArtifactStagingDirectory)/Verify' + ArtifactName: 'Linux Verify $(System.JobAttempt)' - job: CoreOnMac displayName: "macOS Core" @@ -219,6 +260,11 @@ jobs: mergeTestResults: true continueOnError: true condition: always() + - task: CmdLine@2 + displayName: 'Set flag to publish Verify *.received.* files when test step fails' + condition: failed() + inputs: + script: 'echo "##vso[task.setvariable variable=publishverify]Yes"' - task: PublishBuildArtifacts@1 displayName: 'Publish Artifact: logs' inputs: @@ -233,5 +279,20 @@ jobs: ArtifactName: 'CoreOnMac test logs' continueOnError: true condition: always() + - task: CopyFiles@2 + condition: eq(variables['publishverify'], 'Yes') + displayName: 'Copy Verify *.received.* files to Artifact Staging' + inputs: + contents: '**/*.received.*' + targetFolder: '$(Build.ArtifactStagingDirectory)/Verify' + cleanTargetFolder: true + overWrite: true + - task: PublishBuildArtifacts@1 + displayName: 'Publish Verify *.received.* files as Artifacts' + name: 'verifypublish' + condition: eq(variables['publishverify'], 'Yes') + inputs: + PathtoPublish: '$(Build.ArtifactStagingDirectory)/Verify' + ArtifactName: 'macOS Verify $(System.JobAttempt)' - template: /eng/common/templates/jobs/source-build.yml From ef18b606d8f6a7f26172eca79ccd7a9681cf38e6 Mon Sep 17 00:00:00 2001 From: Rainer Sigwald Date: Wed, 20 Dec 2023 05:47:03 -0600 Subject: [PATCH 7/7] Switch to tuple Co-authored-by: Ladi Prosek --- src/MSBuild/TerminalLogger/NodesFrame.cs | 18 ++++++++---------- 1 file changed, 8 insertions(+), 10 deletions(-) diff --git a/src/MSBuild/TerminalLogger/NodesFrame.cs b/src/MSBuild/TerminalLogger/NodesFrame.cs index bba5a1374c6..33fbf2c8d42 100644 --- a/src/MSBuild/TerminalLogger/NodesFrame.cs +++ b/src/MSBuild/TerminalLogger/NodesFrame.cs @@ -16,8 +16,7 @@ internal sealed class NodesFrame { private const int MaxColumn = 120; - private readonly NodeStatus[] _nodes; - private readonly int[] _durationLength; + private readonly (NodeStatus nodeStatus, int durationLength)[] _nodes; private readonly StringBuilder _renderBuilder = new(); @@ -30,27 +29,26 @@ public NodesFrame(NodeStatus?[] nodes, int width, int height) Width = Math.Min(width, MaxColumn); Height = height; - _nodes = new NodeStatus[nodes.Length]; - _durationLength = new int[nodes.Length]; + _nodes = new (NodeStatus, int)[nodes.Length]; foreach (NodeStatus? status in nodes) { if (status is not null) { - _nodes[NodesCount++] = status; + _nodes[NodesCount++].nodeStatus = status; } } } internal ReadOnlySpan RenderNodeStatus(int i) { - NodeStatus status = _nodes[i]; + NodeStatus status = _nodes[i].nodeStatus; string durationString = ResourceUtilities.FormatResourceStringIgnoreCodeAndKeyword( "DurationDisplay", status.Stopwatch.ElapsedSeconds); - _durationLength[i] = durationString.Length; + _nodes[i].durationLength = durationString.Length; string project = status.Project; string? targetFramework = status.TargetFramework; @@ -102,10 +100,10 @@ public string Render(NodesFrame previousFrame) // Do we have previous node string to compare with? if (previousFrame.NodesCount > i) { - if (previousFrame._nodes[i] == _nodes[i] && // Same everything except time, AND - previousFrame._durationLength[i] == _durationLength[i]) // same number of digits in time + if (previousFrame._nodes[i] == _nodes[i]) { - string durationString = ResourceUtilities.FormatResourceStringIgnoreCodeAndKeyword("DurationDisplay", _nodes[i].Stopwatch.ElapsedSeconds); + // Same everything except time, AND same number of digits in time + string durationString = ResourceUtilities.FormatResourceStringIgnoreCodeAndKeyword("DurationDisplay", _nodes[i].nodeStatus.Stopwatch.ElapsedSeconds); sb.Append($"{AnsiCodes.SetCursorHorizontal(MaxColumn)}{AnsiCodes.MoveCursorBackward(durationString.Length)}{durationString}"); } else