Skip to content

Commit

Permalink
Speed up incremental package asset resolution (#2020)
Browse files Browse the repository at this point in the history
Whenever project.assets.json changes (or more rarely, a setting influencing
ResolvePackageAssets changes), write out a binary cache file for the next
incremental build. The file has only the items that used by the build and
they are written in a format that can be deserialized to MSBuild ITaskItem[]
with minimal time and allocation.

On top of that, we merge ReportAssetsLogMessages into ResolvePackageAssets, 
which allows for project.assets.json to not be read at all if it has not
changed.

However, design time build still uses old ReportAssetsLogMessages like old
ResolvePackageDepdencies. Fixing the design time perf will be done separately
in coordination with project system.

In order to ensure consistent behavior between incremental builds and full
builds, and to ensure maximal test coverage of cache reading and writing, a 
full build will write out the cache and then read from it as an incremental
build would.
  • Loading branch information
nguerrera authored Mar 16, 2018
1 parent b80a93a commit f878ddb
Show file tree
Hide file tree
Showing 11 changed files with 862 additions and 268 deletions.
60 changes: 1 addition & 59 deletions src/Tasks/Common/DiagnosticsHelper.cs
Original file line number Diff line number Diff line change
Expand Up @@ -14,12 +14,6 @@ namespace Microsoft.NET.Build.Tasks
internal sealed class DiagnosticsHelper
{
private readonly List<ITaskItem> _diagnosticMessages = new List<ITaskItem>();
private readonly ILog _log;

public DiagnosticsHelper(ILog log)
{
_log = log;
}

public ITaskItem[] GetDiagnosticMessages() => _diagnosticMessages.ToArray();

Expand All @@ -33,8 +27,7 @@ public ITaskItem Add(
int endLine,
int endColumn,
string targetFrameworkMoniker,
string packageId,
bool logToMSBuild = true)
string packageId)
{
string itemspec =
(string.IsNullOrEmpty(targetFrameworkMoniker) ? string.Empty : $"{targetFrameworkMoniker}/") +
Expand All @@ -59,58 +52,7 @@ public ITaskItem Add(

_diagnosticMessages.Add(diagnostic);

if (logToMSBuild)
{
LogToMSBuild(diagnosticCode, message, filePath, severity, startLine, startColumn, endLine, endColumn);
}

return diagnostic;
}

private void LogToMSBuild(string diagnosticCode, string message, string filePath, DiagnosticMessageSeverity severity, int startLine, int startColumn, int endLine, int endColumn)
{
switch (severity)
{
case DiagnosticMessageSeverity.Error:
_log.LogError(
subcategory: null,
errorCode: diagnosticCode,
helpKeyword: null,
file: filePath,
lineNumber: startLine,
columnNumber: startColumn,
endLineNumber: endLine,
endColumnNumber: endColumn,
message: message);
break;

case DiagnosticMessageSeverity.Warning:
_log.LogWarning(
subcategory: null,
warningCode: diagnosticCode,
helpKeyword: null,
file: filePath,
lineNumber: startLine,
columnNumber: startColumn,
endLineNumber: endLine,
endColumnNumber: endColumn,
message: message);
break;

case DiagnosticMessageSeverity.Info:
_log.LogMessage(
subcategory: null,
code: diagnosticCode,
helpKeyword: null,
file: filePath,
lineNumber: startLine,
columnNumber: startColumn,
endLineNumber: endLine,
endColumnNumber: endColumn,
importance: MessageImportance.Normal,
message: message);
break;
}
}
}
}
Original file line number Diff line number Diff line change
@@ -0,0 +1,80 @@
// Copyright (c) .NET Foundation and contributors. All rights reserved.
// Licensed under the MIT license. See LICENSE file in the project root for full license information.

using FluentAssertions;
using Microsoft.Build.Framework;
using System;
using System.Linq;
using System.Reflection;
using Xunit;

namespace Microsoft.NET.Build.Tasks.UnitTests
{
public class GivenAResolvePackageAssetsTask
{
[Fact]
public void ItHashesAllParameters()
{
var inputProperties = typeof(ResolvePackageAssets)
.GetProperties(BindingFlags.DeclaredOnly | BindingFlags.Instance | BindingFlags.Public)
.Where(p => !p.IsDefined(typeof(OutputAttribute)))
.OrderBy(p => p.Name, StringComparer.Ordinal);

var requiredProperties = inputProperties
.Where(p => p.IsDefined(typeof(RequiredAttribute)));

var task = new ResolvePackageAssets();

// Initialize all required properties as a genuine task invocation would. We do this
// because HashSettings need not defend against required parameters being null.
foreach (var property in requiredProperties)
{
property.PropertyType.Should().Be(
typeof(string),
because: $"this test hasn't been updated to handle non-string required task parameters like {property.Name}");

property.SetValue(task, "_");
}

byte[] oldHash;
try
{
oldHash = task.HashSettings();
}
catch (ArgumentNullException)
{
Assert.True(
false,
"HashSettings is likely not correctly handling null value of one or more optional task parameters");

throw; // unreachable
}

foreach (var property in inputProperties)
{
switch (property.PropertyType)
{
case var t when t == typeof(bool):
property.SetValue(task, true);
break;

case var t when t == typeof(string):
property.SetValue(task, property.Name);
break;

default:
Assert.True(false, $"{property.Name} is not a bool or string. Update the test code to handle that.");
throw null; // unreachable
}

byte[] newHash = task.HashSettings();
newHash.Should().NotBeEquivalentTo(
oldHash,
because: $"{property.Name} should be included in hash.");

oldHash = newHash;
}
}
}
}

Original file line number Diff line number Diff line change
Expand Up @@ -16,37 +16,32 @@ public class GivenThatWeReportAssetsLogMessages
[Fact]
public void ItReportsDiagnosticsWithMinimumData()
{
var log = new MockLog();
string lockFileContent = CreateDefaultLockFileSnippet(
logs: new string[] {
CreateLog(NuGetLogCode.NU1000, LogLevel.Warning, "Sample warning")
}
);

var task = GetExecutedTaskFromContents(lockFileContent, log);
var task = GetExecutedTaskFromContents(lockFileContent);

task.DiagnosticMessages.Should().HaveCount(1);
log.Messages.Should().HaveCount(1);
}

[Theory]
[InlineData(null)]
[InlineData(new object[] { new string[0] })]
public void ItReportsZeroDiagnosticsWithNoLogs(string [] logsJson)
{
var log = new MockLog();
string lockFileContent = CreateDefaultLockFileSnippet(logsJson);

var task = GetExecutedTaskFromContents(lockFileContent, log);
var task = GetExecutedTaskFromContents(lockFileContent);

task.DiagnosticMessages.Should().BeEmpty();
log.Messages.Should().BeEmpty();
}

[Fact]
public void ItReportsDiagnosticsMetadataWithLogs()
{
var log = new MockLog();
string lockFileContent = CreateDefaultLockFileSnippet(
logs: new string[] {
CreateLog(NuGetLogCode.NU1000, LogLevel.Error, "Sample error",
Expand All @@ -59,9 +54,8 @@ public void ItReportsDiagnosticsMetadataWithLogs()
}
);

var task = GetExecutedTaskFromContents(lockFileContent, log);
var task = GetExecutedTaskFromContents(lockFileContent);

log.Messages.Should().HaveCount(2);
task.DiagnosticMessages.Should().HaveCount(2);

Action<string,string,string> checkMetadata = (key, val1, val2) => {
Expand All @@ -85,7 +79,6 @@ public void ItReportsDiagnosticsMetadataWithLogs()
[InlineData(new string[] { ".NETCoreApp,Version=v1.0" }, "LibA", ".NETCoreApp,Version=v1.0", "LibA/1.2.3")]
public void ItReportsDiagnosticsWithAllTargetLibraryCases(string[] targetGraphs, string libraryId, string expectedTarget, string expectedPackage)
{
var log = new MockLog();
string lockFileContent = CreateDefaultLockFileSnippet(
logs: new string[] {
CreateLog(NuGetLogCode.NU1000, LogLevel.Warning, "Sample warning",
Expand All @@ -95,9 +88,8 @@ public void ItReportsDiagnosticsWithAllTargetLibraryCases(string[] targetGraphs,
}
);

var task = GetExecutedTaskFromContents(lockFileContent, log);
var task = GetExecutedTaskFromContents(lockFileContent);

log.Messages.Should().HaveCount(1);
task.DiagnosticMessages.Should().HaveCount(1);
var item = task.DiagnosticMessages.First();

Expand All @@ -108,7 +100,6 @@ public void ItReportsDiagnosticsWithAllTargetLibraryCases(string[] targetGraphs,
[Fact]
public void ItHandlesInfoLogLevels()
{
var log = new MockLog();
string lockFileContent = CreateDefaultLockFileSnippet(
logs: new string[] {
CreateLog(NuGetLogCode.NU1000, LogLevel.Information, "Sample message"),
Expand All @@ -118,9 +109,8 @@ public void ItHandlesInfoLogLevels()
}
);

var task = GetExecutedTaskFromContents(lockFileContent, log);
var task = GetExecutedTaskFromContents(lockFileContent);

log.Messages.Should().HaveCount(4);
task.DiagnosticMessages.Should().HaveCount(4);

task.DiagnosticMessages
Expand All @@ -133,7 +123,6 @@ public void ItHandlesInfoLogLevels()
[InlineData(new string[] { ".NETCoreApp,Version=v1.0" }, "LibA")]
public void ItHandlesMultiTFMScenarios(string[] targetGraphs, string libraryId)
{
var log = new MockLog();
string lockFileContent = CreateLockFileSnippet(
targets: new string[] {
CreateTarget(".NETCoreApp,Version=v1.0", TargetLibA, TargetLibB, TargetLibC),
Expand All @@ -151,14 +140,11 @@ public void ItHandlesMultiTFMScenarios(string[] targetGraphs, string libraryId)
}
);

var task = GetExecutedTaskFromContents(lockFileContent, log);
var task = GetExecutedTaskFromContents(lockFileContent);

// a diagnostic for each target graph...
task.DiagnosticMessages.Should().HaveCount(targetGraphs.Length);

// ...but only one is logged
log.Messages.Should().HaveCount(1);

task.DiagnosticMessages
.Select(item => item.GetMetadata(MetadataKeys.ParentTarget))
.Should().Contain(targetGraphs);
Expand All @@ -171,7 +157,6 @@ public void ItHandlesMultiTFMScenarios(string[] targetGraphs, string libraryId)
[Fact]
public void ItSkipsInvalidEntries()
{
var log = new MockLog();
string lockFileContent = CreateDefaultLockFileSnippet(
logs: new string[] {
CreateLog(NuGetLogCode.NU1000, LogLevel.Error, "Sample error that will be invalid"),
Expand All @@ -180,9 +165,8 @@ public void ItSkipsInvalidEntries()
);
lockFileContent = lockFileContent.Replace("NU1000", "CA1000");

var task = GetExecutedTaskFromContents(lockFileContent, log);
var task = GetExecutedTaskFromContents(lockFileContent);

log.Messages.Should().HaveCount(1);
task.DiagnosticMessages.Should().HaveCount(1);

task.DiagnosticMessages
Expand All @@ -202,15 +186,15 @@ private static string CreateDefaultLockFileSnippet(string[] logs = null) =>
logs: logs
);

private ReportAssetsLogMessages GetExecutedTaskFromContents(string lockFileContents, MockLog logger)
private ReportAssetsLogMessages GetExecutedTaskFromContents(string lockFileContents)
{
var lockFile = TestLockFiles.CreateLockFile(lockFileContents);
return GetExecutedTask(lockFile, logger);
return GetExecutedTask(lockFile);
}

private ReportAssetsLogMessages GetExecutedTask(LockFile lockFile, MockLog logger)
private ReportAssetsLogMessages GetExecutedTask(LockFile lockFile)
{
var task = new ReportAssetsLogMessages(lockFile, logger)
var task = new ReportAssetsLogMessages(lockFile)
{
ProjectAssetsFile = lockFile.Path,
};
Expand Down
17 changes: 6 additions & 11 deletions src/Tasks/Microsoft.NET.Build.Tasks/ReportAssetsLogMessages.cs
Original file line number Diff line number Diff line change
Expand Up @@ -9,9 +9,9 @@
namespace Microsoft.NET.Build.Tasks
{
/// <summary>
/// Report Log Messages in the assets file to MSBuild and raise them as
/// DiagnosticMessage items that can be consumed downstream (e.g. by the
/// dependency node in the solution explorer)
/// Raise log messages in the assets file as DiagnosticMessage items
/// that can be consumed downstream (e.g. by the dependency node in
/// the solution explorer)
/// </summary>
public sealed class ReportAssetsLogMessages : TaskBase
{
Expand Down Expand Up @@ -40,15 +40,14 @@ public string ProjectAssetsFile

public ReportAssetsLogMessages()
{
_diagnostics = new DiagnosticsHelper(new MSBuildLog(Log));
_diagnostics = new DiagnosticsHelper();
}

#region Test Support

internal ReportAssetsLogMessages(LockFile lockFile, ILog logger)
internal ReportAssetsLogMessages(LockFile lockFile) : this()
{
_lockFile = lockFile;
_diagnostics = new DiagnosticsHelper(logger);
}

#endregion
Expand Down Expand Up @@ -76,7 +75,6 @@ protected override void ExecuteCore()

private void AddMessage(IAssetsLogMessage message)
{
var logToMsBuild = true;
var targetGraphs = message.GetTargetGraphs(LockFile);

targetGraphs = targetGraphs.Any() ? targetGraphs : new LockFileTarget[] { null };
Expand All @@ -95,10 +93,7 @@ private void AddMessage(IAssetsLogMessage message)
message.EndLineNumber,
message.EndColumnNumber,
target?.Name,
targetLib == null ? null : $"{targetLib.Name}/{targetLib.Version.ToNormalizedString()}",
logToMsBuild);

logToMsBuild = false; // only write first instance of this diagnostic to msbuild
targetLib == null ? null : $"{targetLib.Name}/{targetLib.Version.ToNormalizedString()}");
}
}

Expand Down
Loading

0 comments on commit f878ddb

Please sign in to comment.