Skip to content

ToolTasks Don't Log MSB4181 When Terminated #6968

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Merged
merged 5 commits into from
Oct 31, 2021
Merged

ToolTasks Don't Log MSB4181 When Terminated #6968

Show file tree
Hide file tree
Changes from 1 commit
Commits
Show all changes
5 commits
Select commit Hold shift + click to select a range
e06a995
Tooltasks return !HasLoggedErrors when terminated
benvillalobos Oct 14, 2021
61f1a3e
Revert "Tooltasks return !HasLoggedErrors when terminated"
benvillalobos Oct 18, 2021
8598f27
Don't log MSB4181 when a task is cancelled.
benvillalobos Oct 18, 2021
1650c0c
Tidy up MSB4181 conditions
benvillalobos Oct 19, 2021
997c703
Add regression test
benvillalobos Oct 22, 2021
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
13 changes: 7 additions & 6 deletions src/Tasks.UnitTests/Exec_Tests.cs
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -154,13 +154,13 @@ public void Timeout()
exec.Timeout = 5;
bool result = exec.Execute();

Assert.False(result);
Assert.Equal(expectedExitCode, exec.ExitCode);
// When a tooltask times out, it behaves the same as when it is cancelled and returns !Log.HasLoggedErrors
result.ShouldBeTrue();
exec.ExitCode.ShouldBe(expectedExitCode);
((MockEngine)exec.BuildEngine).AssertLogContains("MSB5002");
Assert.Equal(1, ((MockEngine)exec.BuildEngine).Warnings);

((MockEngine)exec.BuildEngine).Warnings.ShouldBe(1);
// ToolTask does not log an error on timeout.
Assert.Equal(0, ((MockEngine)exec.BuildEngine).Errors);
((MockEngine)exec.BuildEngine).Errors.ShouldBe(0);
}

[Fact]
Expand All @@ -171,7 +171,8 @@ public void TimeoutFailsEvenWhenExitCodeIsIgnored()
exec.IgnoreExitCode = true;
bool result = exec.Execute();

result.ShouldBeFalse();
// When a tooltask times out, it behaves the same as when it is cancelled and returns !Log.HasLoggedErrors
result.ShouldBeTrue();
MockEngine mockEngine = (MockEngine)exec.BuildEngine;
mockEngine.AssertLogContains("MSB5002");
mockEngine.Warnings.ShouldBe(1);
Expand Down
2 changes: 1 addition & 1 deletion src/Utilities/ToolTask.cs
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -1522,7 +1522,7 @@ public override bool Execute()
// Raise a comment event to notify that the process completed
if (_terminatedTool)
{
return false;
return !Log.HasLoggedErrors;
Copy link
Member

@rainersigwald rainersigwald Oct 18, 2021

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This definitely solves the problem but I'm not sure it's conceptually right: the task was cancelled before completion, so shouldn't it return false as in I did not succeed?

Is the "was cancellation requested" state available at the time when we check failure/has-logged-error and log the new message?

Copy link
Member Author

@benvillalobos benvillalobos Oct 18, 2021

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Is the "was cancellation requested" state available at the time when we check failure/has-logged-error and log the new message?

This is the code that logs the warning
https://github.com/dotnet/msbuild/blob/main/src/Utilities/ToolTask.cs#L939-L949

Can a task be cancelled outside of the user's control? That's not something I considered when writing this.

It really depends how we want to view this task. I see a tooltask being (manually) cancelled as "I didn't fail, so as long as I didn't log an error I'm good"

Copy link
Member

@rainersigwald rainersigwald Oct 18, 2021

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I was thinking more like wrapping a if (!_cancellationToken.IsCancellationRequested) around the actual error message here:

msbuild/src/Build/BackEnd/Components/RequestBuilder/TaskBuilder.cs

Lines 940 to 958 in a7d5790

IBuildEngine be = host.TaskInstance.BuildEngine;
if (taskReturned && !taskResult && !taskLoggingContext.HasLoggedErrors && (be is TaskHost th ? th.BuildRequestsSucceeded : false) && (be is IBuildEngine7 be7 ? !be7.AllowFailureWithoutError : true))
{
if (_continueOnError == ContinueOnError.WarnAndContinue)
{
taskLoggingContext.LogWarning(null,
new BuildEventFileInfo(_targetChildInstance.Location),
"TaskReturnedFalseButDidNotLogError",
_taskNode.Name);
taskLoggingContext.LogComment(MessageImportance.Normal, "ErrorConvertedIntoWarning");
}
else
{
taskLoggingContext.LogError(new BuildEventFileInfo(_targetChildInstance.Location),
"TaskReturnedFalseButDidNotLogError",
_taskNode.Name);
}
}

(but I didn't validate that that actually worked).

My mental model for a task is "return true: everything completed satisfactorily. return false: something somewhere went wrong". But it's a bit ambiguous.

Copy link
Member Author

@benvillalobos benvillalobos Oct 18, 2021

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

My mental model for a task is "return true: everything completed satisfactorily. return false: something somewhere went wrong". But it's a bit ambiguous.

I'm a bit confused here. The RemoveDir change is a good example. It used to return true only if all the directories were successfully deleted. That PR is pushing for having it return true even if some directories weren't deleted, so long as we didn't log an error. which is somewhere in the middle of "return true: everything completed satisfactorily. return false: something somewhere went wrong"

I like your suggested solution better though since it's less break-y, so I'll give that a shot.

Copy link
Member Author

@benvillalobos benvillalobos Oct 18, 2021

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Your idea works 🚀 and avoids a fundamental change to all tooltasks. Not exactly sure how to test this though, my local test runs a sleep.exe that wouldn't exist in a unit test. Any ideas?

Copy link
Member

@rainersigwald rainersigwald Oct 18, 2021

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

We have a helper for that, try something like:

msbuild/src/Build.UnitTests/BackEnd/BuildManager_Tests.cs

Lines 1523 to 1533 in a7d5790

public void CancelledBuild()
{
Console.WriteLine("Starting CancelledBuild test that is known to hang.");
string contents = CleanupFileContents(@"
<Project xmlns='msbuildnamespace' ToolsVersion='msbuilddefaulttoolsversion'>
<Target Name='test'>
<Exec Command='" + Helpers.GetSleepCommand(TimeSpan.FromSeconds(60)) + @"'/>
<Message Text='[errormessage]'/>
</Target>
</Project>
");

}
else if (ExitCode != 0)
{
Expand Down