Skip to content

Commit

Permalink
Improve plugin exception logging (dotnet#6368)
Browse files Browse the repository at this point in the history 
Context
Treat project cache exceptions similar to how MSBuild treats exceptions from ILogger.Initialize and ILogger.Shutdown. This avoids the "file an issue against the MSBuild team" console messages.
Treat errors logged by the project cache similar to how MSBuild treats errors logged by tasks. Which is to check whether they logged an error and if yes, shut the build down (project cache does not do "continue on error").

Changes Made
Adds a ProjectCacheException which gets handled similarly to LoggerException

Testing
Beefed up the existing exception handling tests to also assert what happens when the project cache logs errors instead of throwing exceptions.

Co-authored-by: Rainer Sigwald <[email protected]>
  • Loading branch information
@cdmihai @rainersigwald
cdmihai and rainersigwald authored Apr 27, 2021
1 parent 117a9cb commit 79bef82
Show file tree
Hide file tree
Showing 24 changed files with 439 additions and 146 deletions.
6 changes: 6 additions & 0 deletions ref/Microsoft.Build/net/Microsoft.Build.cs
View file
Original file line number Diff line number Diff line change
Expand Up @@ -1475,6 +1475,12 @@ internal ProjectCacheDescriptor() { }
public static Microsoft.Build.Experimental.ProjectCache.ProjectCacheDescriptor FromInstance(Microsoft.Build.Experimental.ProjectCache.ProjectCachePluginBase pluginInstance, System.Collections.Generic.IReadOnlyCollection<Microsoft.Build.Graph.ProjectGraphEntryPoint> entryPoints, Microsoft.Build.Graph.ProjectGraph projectGraph, System.Collections.Generic.IReadOnlyDictionary<string, string> pluginSettings = null) { throw null; }
public string GetDetailedDescription() { throw null; }
}
public sealed partial class ProjectCacheException : System.Exception
{
internal ProjectCacheException() { }
public string ErrorCode { get { throw null; } }
public bool HasBeenLoggedByProjectCache { get { throw null; } }
}
public abstract partial class ProjectCachePluginBase
{
protected ProjectCachePluginBase() { }
Expand Down
6 changes: 6 additions & 0 deletions ref/Microsoft.Build/netstandard/Microsoft.Build.cs
View file
Original file line number Diff line number Diff line change
Expand Up @@ -1469,6 +1469,12 @@ internal ProjectCacheDescriptor() { }
public static Microsoft.Build.Experimental.ProjectCache.ProjectCacheDescriptor FromInstance(Microsoft.Build.Experimental.ProjectCache.ProjectCachePluginBase pluginInstance, System.Collections.Generic.IReadOnlyCollection<Microsoft.Build.Graph.ProjectGraphEntryPoint> entryPoints, Microsoft.Build.Graph.ProjectGraph projectGraph, System.Collections.Generic.IReadOnlyDictionary<string, string> pluginSettings = null) { throw null; }
public string GetDetailedDescription() { throw null; }
}
public sealed partial class ProjectCacheException : System.Exception
{
internal ProjectCacheException() { }
public string ErrorCode { get { throw null; } }
public bool HasBeenLoggedByProjectCache { get { throw null; } }
}
public abstract partial class ProjectCachePluginBase
{
protected ProjectCachePluginBase() { }
Expand Down
133 changes: 91 additions & 42 deletions src/Build.UnitTests/ProjectCache/ProjectCacheTests.cs
View file
Original file line number Diff line number Diff line change
Expand Up @@ -192,14 +192,20 @@ char Chr(int projectNumber)
}

[Flags]
public enum ExceptionLocations
public enum ErrorLocations
{
Constructor = 1 << 0,
BeginBuildAsync = 1 << 1,
GetCacheResultAsync = 1 << 2,
EndBuildAsync = 1 << 3
}

public enum ErrorKind
{
Exception,
LoggedError
}

public class InstanceMockCache : ProjectCachePluginBase
{
private readonly GraphCacheResponse? _testData;
Expand Down Expand Up @@ -791,27 +797,31 @@ public static IEnumerable<object[]> CacheExceptionLocationsTestData
{
get
{
yield return new object[]{ExceptionLocations.Constructor};
// Plugin constructors cannot log errors, they can only throw exceptions.
yield return new object[] { ErrorLocations.Constructor, ErrorKind.Exception };

yield return new object[]{ExceptionLocations.BeginBuildAsync};
yield return new object[]{ExceptionLocations.BeginBuildAsync | ExceptionLocations.GetCacheResultAsync};
yield return new object[]{ExceptionLocations.BeginBuildAsync | ExceptionLocations.GetCacheResultAsync | ExceptionLocations.EndBuildAsync};
yield return new object[]{ExceptionLocations.BeginBuildAsync | ExceptionLocations.EndBuildAsync};
foreach (var errorKind in new[]{ErrorKind.Exception, ErrorKind.LoggedError})
{
yield return new object[] { ErrorLocations.BeginBuildAsync, errorKind };
yield return new object[] { ErrorLocations.BeginBuildAsync | ErrorLocations.GetCacheResultAsync, errorKind };
yield return new object[] { ErrorLocations.BeginBuildAsync | ErrorLocations.GetCacheResultAsync | ErrorLocations.EndBuildAsync, errorKind };
yield return new object[] { ErrorLocations.BeginBuildAsync | ErrorLocations.EndBuildAsync, errorKind };

yield return new object[]{ExceptionLocations.GetCacheResultAsync};
yield return new object[]{ExceptionLocations.GetCacheResultAsync | ExceptionLocations.EndBuildAsync};
yield return new object[] { ErrorLocations.GetCacheResultAsync, errorKind };
yield return new object[] { ErrorLocations.GetCacheResultAsync | ErrorLocations.EndBuildAsync, errorKind };

yield return new object[]{ExceptionLocations.EndBuildAsync};
yield return new object[] { ErrorLocations.EndBuildAsync, errorKind };
}
}
}

[Theory]
[MemberData(nameof(CacheExceptionLocationsTestData))]
public void EngineShouldHandleExceptionsFromCachePluginViaBuildParameters(ExceptionLocations exceptionLocations)
public void EngineShouldHandleExceptionsFromCachePluginViaBuildParameters(ErrorLocations errorLocations, ErrorKind errorKind)
{
_env.DoNotLaunchDebugger();

SetEnvironmentForExceptionLocations(exceptionLocations);
SetEnvironmentForErrorLocations(errorLocations, errorKind.ToString());

var project = _env.CreateFile("1.proj", @$"
<Project>
Expand Down Expand Up @@ -842,36 +852,59 @@ public void EngineShouldHandleExceptionsFromCachePluginViaBuildParameters(Except
// Plugin construction, initialization, and query all end up throwing in BuildManager.ExecuteSubmission and thus
// mark the submission as failed with exception.
var exceptionsThatEndUpInBuildResult =
ExceptionLocations.Constructor | ExceptionLocations.BeginBuildAsync | ExceptionLocations.GetCacheResultAsync;
ErrorLocations.Constructor | ErrorLocations.BeginBuildAsync | ErrorLocations.GetCacheResultAsync;

if ((exceptionsThatEndUpInBuildResult & exceptionLocations) != 0)
if ((exceptionsThatEndUpInBuildResult & errorLocations) != 0)
{
buildResult.OverallResult.ShouldBe(BuildResultCode.Failure);
buildResult.Exception.Message.ShouldContain("Cache plugin exception from");
buildResult.Exception.ShouldNotBeNull();
buildResult.Exception.ShouldBeOfType<ProjectCacheException>();

if (errorKind == ErrorKind.Exception)
{
buildResult.Exception.InnerException!.ShouldNotBeNull();
buildResult.Exception.InnerException!.Message.ShouldContain("Cache plugin exception from");
}
else
{
buildResult.Exception.InnerException.ShouldBeNull();
}
}

// BuildManager.EndBuild calls plugin.EndBuild, so if only plugin.EndBuild fails it means everything else passed,
// so the build submission should be successful.
if (exceptionLocations == ExceptionLocations.EndBuildAsync)
if (errorLocations == ErrorLocations.EndBuildAsync)
{
buildResult.OverallResult.ShouldBe(BuildResultCode.Success);
}
else
{
buildResult.OverallResult.ShouldBe(BuildResultCode.Failure);
}
}
finally
{
// These exceptions prevent the creation of a plugin so there's no plugin to shutdown.
var exceptionsThatPreventEndBuildFromThrowing = ExceptionLocations.Constructor |
ExceptionLocations.BeginBuildAsync;
var exceptionsThatPreventEndBuildFromThrowing = ErrorLocations.Constructor |
ErrorLocations.BeginBuildAsync;

if ((exceptionLocations & exceptionsThatPreventEndBuildFromThrowing) != 0 ||
!exceptionLocations.HasFlag(ExceptionLocations.EndBuildAsync))
if ((errorLocations & exceptionsThatPreventEndBuildFromThrowing) != 0 ||
!errorLocations.HasFlag(ErrorLocations.EndBuildAsync))
{
Should.NotThrow(() => buildSession!.Dispose());
}
else if (exceptionLocations.HasFlag(ExceptionLocations.EndBuildAsync))
else if (errorLocations.HasFlag(ErrorLocations.EndBuildAsync))
{
var e = Should.Throw<Exception>(() => buildSession!.Dispose());
e.Message.ShouldContain("Cache plugin exception from EndBuildAsync");
var e = Should.Throw<ProjectCacheException>(() => buildSession!.Dispose());

if (errorKind == ErrorKind.Exception)
{
e.InnerException!.ShouldNotBeNull();
e.InnerException!.Message.ShouldContain("Cache plugin exception from EndBuildAsync");
}
else
{
e.InnerException.ShouldBeNull();
}
}
else
{
Expand All @@ -882,9 +915,9 @@ public void EngineShouldHandleExceptionsFromCachePluginViaBuildParameters(Except
logger.BuildFinishedEvents.First().Succeeded.ShouldBeFalse();

// Plugin query must happen after plugin init. So if plugin init fails, then the plugin should not get queried.
var exceptionsThatShouldPreventCacheQueryAndEndBuildAsync = ExceptionLocations.Constructor | ExceptionLocations.BeginBuildAsync;
var exceptionsThatShouldPreventCacheQueryAndEndBuildAsync = ErrorLocations.Constructor | ErrorLocations.BeginBuildAsync;

if ((exceptionsThatShouldPreventCacheQueryAndEndBuildAsync & exceptionLocations) != 0)
if ((exceptionsThatShouldPreventCacheQueryAndEndBuildAsync & errorLocations) != 0)
{
logger.FullLog.ShouldNotContain($"{AssemblyMockCache}: GetCacheResultAsync for");
logger.FullLog.ShouldNotContain($"{AssemblyMockCache}: EndBuildAsync");
Expand All @@ -895,17 +928,21 @@ public void EngineShouldHandleExceptionsFromCachePluginViaBuildParameters(Except
StringShouldContainSubstring(logger.FullLog, $"{AssemblyMockCache}: EndBuildAsync", expectedOccurrences: 1);
}

// TODO: this ain't right now is it?
logger.FullLog.ShouldNotContain("Cache plugin exception");
logger.FullLog.ShouldNotContain("Cache plugin exception from");

if (errorKind == ErrorKind.LoggedError)
{
logger.FullLog.ShouldContain("Cache plugin logged error from");
}
}

[Theory]
[MemberData(nameof(CacheExceptionLocationsTestData))]
public void EngineShouldHandleExceptionsFromCachePluginViaGraphBuild(ExceptionLocations exceptionLocations)
public void EngineShouldHandleExceptionsFromCachePluginViaGraphBuild(ErrorLocations errorLocations, ErrorKind errorKind)
{
_env.DoNotLaunchDebugger();

SetEnvironmentForExceptionLocations(exceptionLocations);
SetEnvironmentForErrorLocations(errorLocations, errorKind.ToString());

var graph = Helpers.CreateProjectGraph(
_env,
Expand Down Expand Up @@ -945,10 +982,21 @@ public void EngineShouldHandleExceptionsFromCachePluginViaGraphBuild(ExceptionLo

// Static graph build initializes and tears down the cache plugin so all cache plugin exceptions should end up in the GraphBuildResult
buildResult.OverallResult.ShouldBe(BuildResultCode.Failure);
buildResult.Exception.Message.ShouldContain("Cache plugin exception from");

// TODO: this ain't right now is it?
logger.FullLog.ShouldNotContain("Cache plugin exception");
buildResult.Exception.ShouldBeOfType<ProjectCacheException>();

if (errorKind == ErrorKind.Exception)
{
buildResult.Exception.InnerException!.ShouldNotBeNull();
buildResult.Exception.InnerException!.Message.ShouldContain("Cache plugin exception from");
}

logger.FullLog.ShouldNotContain("Cache plugin exception from");

if (errorKind == ErrorKind.LoggedError)
{
logger.FullLog.ShouldContain("Cache plugin logged error from");
}
}
finally
{
Expand All @@ -958,17 +1006,17 @@ public void EngineShouldHandleExceptionsFromCachePluginViaGraphBuild(ExceptionLo

logger.BuildFinishedEvents.First().Succeeded.ShouldBeFalse();

var exceptionsThatShouldPreventCacheQueryAndEndBuildAsync = ExceptionLocations.Constructor | ExceptionLocations.BeginBuildAsync;
var exceptionsThatShouldPreventCacheQueryAndEndBuildAsync = ErrorLocations.Constructor | ErrorLocations.BeginBuildAsync;

if ((exceptionsThatShouldPreventCacheQueryAndEndBuildAsync & exceptionLocations) != 0)
if ((exceptionsThatShouldPreventCacheQueryAndEndBuildAsync & errorLocations) != 0)
{
logger.FullLog.ShouldNotContain($"{AssemblyMockCache}: GetCacheResultAsync for");
logger.FullLog.ShouldNotContain($"{AssemblyMockCache}: EndBuildAsync");
}
else
{
// There's two projects, so there should be two cache queries logged ... unless a cache queries throws an exception. That ends the build.
var expectedQueryOccurrences = exceptionLocations.HasFlag(ExceptionLocations.GetCacheResultAsync)
var expectedQueryOccurrences = errorLocations.HasFlag(ErrorLocations.GetCacheResultAsync)
? 1
: 2;

Expand All @@ -995,7 +1043,7 @@ public void EndBuildShouldGetCalledOnceWhenItThrowsExceptionsFromGraphBuilds()
</Target>
</Project>".Cleanup());

SetEnvironmentForExceptionLocations(ExceptionLocations.EndBuildAsync);
SetEnvironmentForErrorLocations(ErrorLocations.EndBuildAsync, ErrorKind.Exception.ToString());

using var buildSession = new Helpers.BuildManagerSession(
_env,
Expand All @@ -1014,7 +1062,8 @@ public void EndBuildShouldGetCalledOnceWhenItThrowsExceptionsFromGraphBuilds()
});

buildResult!.OverallResult.ShouldBe(BuildResultCode.Failure);
buildResult.Exception.Message.ShouldContain("Cache plugin exception from EndBuildAsync");
buildResult.Exception.InnerException!.ShouldNotBeNull();
buildResult.Exception.InnerException!.Message.ShouldContain("Cache plugin exception from EndBuildAsync");

buildSession.Dispose();

Expand All @@ -1027,15 +1076,15 @@ private static void StringShouldContainSubstring(string aString, string substrin
Regex.Matches(aString, substring).Count.ShouldBe(expectedOccurrences);
}

private void SetEnvironmentForExceptionLocations(ExceptionLocations exceptionLocations)
private void SetEnvironmentForErrorLocations(ErrorLocations errorLocations, string errorKind)
{
foreach (var enumValue in Enum.GetValues(typeof(ExceptionLocations)))
foreach (var enumValue in Enum.GetValues(typeof(ErrorLocations)))
{
var typedValue = (ExceptionLocations) enumValue;
if (exceptionLocations.HasFlag(typedValue))
var typedValue = (ErrorLocations) enumValue;
if (errorLocations.HasFlag(typedValue))
{
var exceptionLocation = typedValue.ToString();
_env.SetEnvironmentVariable(exceptionLocation, "1");
_env.SetEnvironmentVariable(exceptionLocation, errorKind);
_output.WriteLine($"Set exception location: {exceptionLocation}");
}
}
Expand Down
24 changes: 15 additions & 9 deletions src/Build/BackEnd/BuildManager/BuildManager.cs
View file
Original file line number Diff line number Diff line change
Expand Up @@ -1279,11 +1279,14 @@ private void AutomaticallyDetectAndInstantiateProjectCacheServiceForVisualStudio
_buildParameters.ProjectCacheDescriptor == null)
{
_projectCacheServiceInstantiatedByVSWorkaround = true;
ErrorUtilities.VerifyThrowInvalidOperation(
ProjectCacheItems.Count == 1,
"OnlyOneCachePluginMustBeSpecified",
string.Join("; ", ProjectCacheItems.Values.Select(c => c.PluginPath)));

if (ProjectCacheItems.Count != 1)
{
ProjectCacheException.ThrowForMSBuildIssueWithTheProjectCache(
"OnlyOneCachePluginMustBeSpecified",
string.Join("; ", ProjectCacheItems.Values.Select(c => c.PluginPath)));
}

// Plugin needs the graph root (aka top BuildSubmission path, aka the solution path when in VS) which, under VS, is accessible
// only by evaluating the submission and retrieving the 'SolutionPath' property set by VS. This is also the reason why
// this method cannot be called from BeginBuild, because no build submissions are available there to extract the solution path from.
Expand All @@ -1300,6 +1303,7 @@ private void AutomaticallyDetectAndInstantiateProjectCacheServiceForVisualStudio
ErrorUtilities.VerifyThrow(
solutionPath != null && !string.IsNullOrWhiteSpace(solutionPath) && solutionPath != "*Undefined*",
$"Expected VS to set a valid SolutionPath property but got: {solutionPath}");

ErrorUtilities.VerifyThrow(
FileSystems.Default.FileExists(solutionPath),
$"Solution file does not exist: {solutionPath}");
Expand Down Expand Up @@ -1943,16 +1947,18 @@ private DisposablePluginService SearchAndInitializeProjectCachePluginFromGraph(P
return new DisposablePluginService(null);
}

ErrorUtilities.VerifyThrowInvalidOperation(
cacheItems.Count == 1,
"OnlyOneCachePluginMustBeSpecified",
string.Join("; ", cacheItems.Select(ci => ci.PluginPath)));
if (cacheItems.Count != 1)
{
ProjectCacheException.ThrowForMSBuildIssueWithTheProjectCache(
"OnlyOneCachePluginMustBeSpecified",
string.Join("; ", cacheItems.Select(ci => ci.PluginPath)));
}

var nodesWithoutCacheItems = nodeToCacheItems.Where(kvp => kvp.Value.Length == 0).ToArray();

if (nodesWithoutCacheItems.Length > 0)
{
ErrorUtilities.ThrowInvalidOperation(
ProjectCacheException.ThrowForMSBuildIssueWithTheProjectCache(
"NotAllNodesDefineACacheItem",
ItemTypeNames.ProjectCachePlugin,
string.Join(", ", nodesWithoutCacheItems.Select(kvp => kvp.Key.ProjectInstance.FullPath)));
Expand Down
Loading

0 comments on commit 79bef82

Please sign in to comment.