Skip to content

Commit

Permalink
Fix restore handling in Terminal Logger (#9454)
Browse files Browse the repository at this point in the history
Fixes #9323

Context
There are 4 related problems that occur in the issue #9323:

1. The logger fails and throws an internal logger exception because of the wrong assumptions about restore target appearance in the build.
2. The internal logger exception is caught and causes the build to shut down all loggers, including terminal logger. Because it happens before the build finished event is produced or processed by terminal logger, the rendering thread is not finished, and it leads to an infinite hang.
3. The errors during restore are not logged.
4. There is inconsistency with showing the message error MSB4017. If the internal logger exception is thrown from one place it shows, from another - not. In the current situation the build and logger are shut downed, but the message did not appear, which is confusing. (see [Bug]: error MSB4017 is not shown consistently when the internal logger exception occurs. #9455)
Changes Made
Fixed first 2 errors:

Improved the handling of the restore such that there should not be throws. Only first restore that happens would be specially treated.
I added shutting down of the render thread when shutting down the logger.
Testing
locally tested, unit tests
  • Loading branch information
AR-May authored Nov 27, 2023
1 parent 31108ed commit 8e1af57
Showing 1 changed file with 19 additions and 9 deletions.
28 changes: 19 additions & 9 deletions src/MSBuild/TerminalLogger/TerminalLogger.cs
Original file line number Diff line number Diff line change
Expand Up @@ -131,9 +131,14 @@ public override string ToString()
/// </summary>
private bool _restoreFailed;

/// <summary>
/// True if restore happened and finished.
/// </summary>
private bool _restoreFinished = false;

/// <summary>
/// The project build context corresponding to the <c>Restore</c> initial target, or null if the build is currently
/// bot restoring.
/// not restoring.
/// </summary>
private ProjectContext? _restoreContext;

Expand Down Expand Up @@ -246,7 +251,10 @@ public void Initialize(IEventSource eventSource)
/// <inheritdoc/>
public void Shutdown()
{
_cts.Cancel();
_refresher?.Join();
Terminal.Dispose();
_cts.Dispose();
}

#endregion
Expand Down Expand Up @@ -337,12 +345,14 @@ private void ProjectStarted(object sender, ProjectStartedEventArgs e)
targetFramework = null;
}
_projects[c] = new(targetFramework);
}

if (e.TargetNames == "Restore")
{
_restoreContext = c;
_nodes[0] = new NodeStatus(e.ProjectFile!, null, "Restore", _projects[c].Stopwatch);
// First ever restore in the build is starting.
if (e.TargetNames == "Restore" && !_restoreFinished)
{
_restoreContext = c;
int nodeIndex = NodeIndexForContext(buildEventContext);
_nodes[nodeIndex] = new NodeStatus(e.ProjectFile!, null, "Restore", _projects[c].Stopwatch);
}
}
}

Expand Down Expand Up @@ -412,6 +422,7 @@ private void ProjectFinished(object sender, ProjectFinishedEventArgs e)
}

_restoreContext = null;
_restoreFinished = true;
}
// If this was a notable project build, we print it as completed only if it's produced an output or warnings/error.
else if (project.OutputPath is not null || project.BuildMessages is not null)
Expand Down Expand Up @@ -665,10 +676,9 @@ private void ErrorRaised(object sender, BuildErrorEventArgs e)
/// </summary>
private void ThreadProc()
{
while (!_cts.IsCancellationRequested)
// 1_000 / 30 is a poor approx of 30Hz
while (!_cts.Token.WaitHandle.WaitOne(1_000 / 30))
{
Thread.Sleep(1_000 / 30); // poor approx of 30Hz

lock (_lock)
{
DisplayNodes();
Expand Down

0 comments on commit 8e1af57

Please sign in to comment.