From c56a2e18dbd0f71618cc59c0a8ba749cdd294f4d Mon Sep 17 00:00:00 2001 From: Kirill Osenkov Date: Sun, 2 May 2021 19:20:10 -0700 Subject: [PATCH 1/6] Add TargetSkipReason and OriginalBuildEventContext to TargetSkippedEventArgs We weren't logging TargetSkippedEventArgs in two cases: when the target was satisfied from cache (previously built), or when the outputs were up-to-date. We were logging simple messages. Switch to logging TargetSkippedEventArgs in these cases as well. Add a new TargetSkipReason enum to indicate why the target was skipped. Store and serialize it for node packet translator and binary logger. When logging a TargetSkippedEventArgs because a target was built previously it is also useful to find the original target invocation (e.g. to see the target outputs). Add OriginalBuildEventContext to TargetResult and ensure it is translated properly. Add OriginalBuildEventContext on TargetSkippedEventArgs and serialize that as well (both node packet translator and binary logger). Note that if the target didn't build because the Condition was false, the OriginalBuildEventContext will be a project context, not a target context. We have to increment the binlog file format version to 14 to add the two new fields. Implement BuildEventContext.ToString() for easier debugging. Add an internal setter for Importance on BuildMessageEventArgs. We were missing unit-tests for node packet translation of TargetSkippedEventArgs. Add test. Fixes https://github.com/dotnet/msbuild/issues/5475 --- .../net/Microsoft.Build.Framework.cs | 11 +++ .../netstandard/Microsoft.Build.Framework.cs | 11 +++ .../BackEnd/NodePackets_Tests.cs | 42 ++++++++- .../BackEnd/TargetResult_Tests.cs | 7 +- .../BuildEventArgsSerialization_Tests.cs | 17 +++- .../Communications/TranslatorExtensions.cs | 15 ++- .../Components/Logging/NodeLoggingContext.cs | 26 ++++-- .../RequestBuilder/TargetBuilder.cs | 5 +- .../Components/RequestBuilder/TargetEntry.cs | 14 +-- .../RequestBuilder/TargetUpToDateChecker.cs | 16 +++- src/Build/BackEnd/Shared/TargetResult.cs | 15 ++- .../Logging/BinaryLogger/BinaryLogger.cs | 5 +- .../BinaryLogger/BuildEventArgsReader.cs | 10 ++ .../BinaryLogger/BuildEventArgsWriter.cs | 2 + src/Framework/BuildEventContext.cs | 4 + src/Framework/BuildMessageEventArgs.cs | 6 +- src/Framework/TargetSkippedEventArgs.cs | 91 ++++++++++++++++--- src/Shared/BinaryTranslator.cs | 2 +- 18 files changed, 253 insertions(+), 46 deletions(-) diff --git a/ref/Microsoft.Build.Framework/net/Microsoft.Build.Framework.cs b/ref/Microsoft.Build.Framework/net/Microsoft.Build.Framework.cs index d8a78e04125..061002c138c 100644 --- a/ref/Microsoft.Build.Framework/net/Microsoft.Build.Framework.cs +++ b/ref/Microsoft.Build.Framework/net/Microsoft.Build.Framework.cs @@ -70,6 +70,7 @@ public BuildEventContext(int submissionId, int nodeId, int evaluationId, int pro public override int GetHashCode() { throw null; } public static bool operator ==(Microsoft.Build.Framework.BuildEventContext left, Microsoft.Build.Framework.BuildEventContext right) { throw null; } public static bool operator !=(Microsoft.Build.Framework.BuildEventContext left, Microsoft.Build.Framework.BuildEventContext right) { throw null; } + public override string ToString() { throw null; } } public partial class BuildFinishedEventArgs : Microsoft.Build.Framework.BuildStatusEventArgs { @@ -580,11 +581,21 @@ public TargetSkippedEventArgs(string message, params object[] messageArgs) { } public string Condition { get { throw null; } set { } } public string EvaluatedCondition { get { throw null; } set { } } public override string Message { get { throw null; } } + public Microsoft.Build.Framework.BuildEventContext OriginalBuildEventContext { get { throw null; } set { } } public bool OriginallySucceeded { get { throw null; } set { } } public string ParentTarget { get { throw null; } set { } } + public Microsoft.Build.Framework.TargetSkipReason SkipReason { get { throw null; } set { } } public string TargetFile { get { throw null; } set { } } public string TargetName { get { throw null; } set { } } } + public enum TargetSkipReason + { + None = 0, + PreviouslyBuiltSuccessfully = 1, + PreviouslyBuiltUnsuccessfully = 2, + OutputsUpToDate = 3, + ConditionWasFalse = 4, + } public partial class TargetStartedEventArgs : Microsoft.Build.Framework.BuildStatusEventArgs { protected TargetStartedEventArgs() { } diff --git a/ref/Microsoft.Build.Framework/netstandard/Microsoft.Build.Framework.cs b/ref/Microsoft.Build.Framework/netstandard/Microsoft.Build.Framework.cs index 2fd1301abb1..886bdd29f73 100644 --- a/ref/Microsoft.Build.Framework/netstandard/Microsoft.Build.Framework.cs +++ b/ref/Microsoft.Build.Framework/netstandard/Microsoft.Build.Framework.cs @@ -70,6 +70,7 @@ public BuildEventContext(int submissionId, int nodeId, int evaluationId, int pro public override int GetHashCode() { throw null; } public static bool operator ==(Microsoft.Build.Framework.BuildEventContext left, Microsoft.Build.Framework.BuildEventContext right) { throw null; } public static bool operator !=(Microsoft.Build.Framework.BuildEventContext left, Microsoft.Build.Framework.BuildEventContext right) { throw null; } + public override string ToString() { throw null; } } public partial class BuildFinishedEventArgs : Microsoft.Build.Framework.BuildStatusEventArgs { @@ -579,11 +580,21 @@ public TargetSkippedEventArgs(string message, params object[] messageArgs) { } public string Condition { get { throw null; } set { } } public string EvaluatedCondition { get { throw null; } set { } } public override string Message { get { throw null; } } + public Microsoft.Build.Framework.BuildEventContext OriginalBuildEventContext { get { throw null; } set { } } public bool OriginallySucceeded { get { throw null; } set { } } public string ParentTarget { get { throw null; } set { } } + public Microsoft.Build.Framework.TargetSkipReason SkipReason { get { throw null; } set { } } public string TargetFile { get { throw null; } set { } } public string TargetName { get { throw null; } set { } } } + public enum TargetSkipReason + { + None = 0, + PreviouslyBuiltSuccessfully = 1, + PreviouslyBuiltUnsuccessfully = 2, + OutputsUpToDate = 3, + ConditionWasFalse = 4, + } public partial class TargetStartedEventArgs : Microsoft.Build.Framework.BuildStatusEventArgs { protected TargetStartedEventArgs() { } diff --git a/src/Build.UnitTests/BackEnd/NodePackets_Tests.cs b/src/Build.UnitTests/BackEnd/NodePackets_Tests.cs index a3137f5b399..6dbbeeffd38 100644 --- a/src/Build.UnitTests/BackEnd/NodePackets_Tests.cs +++ b/src/Build.UnitTests/BackEnd/NodePackets_Tests.cs @@ -52,6 +52,7 @@ public void VerifyEventType() BuildErrorEventArgs error = new BuildErrorEventArgs("SubCategoryForSchemaValidationErrors", "MSB4000", "file", 1, 2, 3, 4, "message", "help", "sender"); TargetStartedEventArgs targetStarted = new TargetStartedEventArgs("message", "help", "targetName", "ProjectFile", "targetFile"); TargetFinishedEventArgs targetFinished = new TargetFinishedEventArgs("message", "help", "targetName", "ProjectFile", "targetFile", true); + TargetSkippedEventArgs targetSkipped = CreateTargetSkipped(); ProjectStartedEventArgs projectStarted = new ProjectStartedEventArgs(-1, "message", "help", "ProjectFile", "targetNames", null, null, null); ProjectFinishedEventArgs projectFinished = new ProjectFinishedEventArgs("message", "help", "ProjectFile", true); ExternalProjectStartedEventArgs externalStartedEvent = new ExternalProjectStartedEventArgs("message", "help", "senderName", "projectFile", "targetNames"); @@ -69,6 +70,7 @@ public void VerifyEventType() VerifyLoggingPacket(error, LoggingEventType.BuildErrorEvent); VerifyLoggingPacket(targetStarted, LoggingEventType.TargetStartedEvent); VerifyLoggingPacket(targetFinished, LoggingEventType.TargetFinishedEvent); + VerifyLoggingPacket(targetSkipped, LoggingEventType.TargetSkipped); VerifyLoggingPacket(projectStarted, LoggingEventType.ProjectStartedEvent); VerifyLoggingPacket(projectFinished, LoggingEventType.ProjectFinishedEvent); VerifyLoggingPacket(evaluationStarted, LoggingEventType.ProjectEvaluationStartedEvent); @@ -174,6 +176,26 @@ private static TaskParameterEventArgs CreateTaskParameter() return result; } + private static TargetSkippedEventArgs CreateTargetSkipped() + { + var result = new TargetSkippedEventArgs(message: null) + { + BuildReason = TargetBuiltReason.DependsOn, + SkipReason = TargetSkipReason.PreviouslyBuiltSuccessfully, + BuildEventContext = CreateBuildEventContext(), + OriginalBuildEventContext = CreateBuildEventContext(), + Condition = "$(Condition) == 'true'", + EvaluatedCondition = "'true' == 'true'", + Importance = MessageImportance.Normal, + OriginallySucceeded = true, + ProjectFile = "1.proj", + TargetFile = "1.proj", + TargetName = "Build", + ParentTarget = "ParentTarget" + }; + return result; + } + /// /// Tests serialization of LogMessagePacket with each kind of event type. /// @@ -207,7 +229,8 @@ public void TestTranslation() new ProjectFinishedEventArgs("message", "help", "ProjectFile", true), new ExternalProjectStartedEventArgs("message", "help", "senderName", "projectFile", "targetNames"), CreateProjectEvaluationStarted(), - CreateProjectEvaluationFinished() + CreateProjectEvaluationFinished(), + CreateTargetSkipped() }; foreach (BuildEventArgs arg in testArgs) @@ -412,6 +435,23 @@ private void CompareLogMessagePackets(LogMessagePacket left, LogMessagePacket ri Assert.Equal(leftTargetStarted.TargetName, rightTargetStarted.TargetName); break; + case LoggingEventType.TargetSkipped: + TargetSkippedEventArgs leftTargetSkipped = left.NodeBuildEvent.Value.Value as TargetSkippedEventArgs; + TargetSkippedEventArgs rightTargetSkipped = right.NodeBuildEvent.Value.Value as TargetSkippedEventArgs; + Assert.Equal(leftTargetSkipped.BuildReason, rightTargetSkipped.BuildReason); + Assert.Equal(leftTargetSkipped.SkipReason, rightTargetSkipped.SkipReason); + Assert.Equal(leftTargetSkipped.BuildEventContext, rightTargetSkipped.BuildEventContext); + Assert.Equal(leftTargetSkipped.OriginalBuildEventContext, rightTargetSkipped.OriginalBuildEventContext); + Assert.Equal(leftTargetSkipped.Condition, rightTargetSkipped.Condition); + Assert.Equal(leftTargetSkipped.EvaluatedCondition, rightTargetSkipped.EvaluatedCondition); + Assert.Equal(leftTargetSkipped.Importance, rightTargetSkipped.Importance); + Assert.Equal(leftTargetSkipped.OriginallySucceeded, rightTargetSkipped.OriginallySucceeded); + Assert.Equal(leftTargetSkipped.ProjectFile, rightTargetSkipped.ProjectFile); + Assert.Equal(leftTargetSkipped.TargetFile, rightTargetSkipped.TargetFile); + Assert.Equal(leftTargetSkipped.TargetName, rightTargetSkipped.TargetName); + Assert.Equal(leftTargetSkipped.ParentTarget, rightTargetSkipped.ParentTarget); + break; + case LoggingEventType.TaskCommandLineEvent: TaskCommandLineEventArgs leftCommand = left.NodeBuildEvent.Value.Value as TaskCommandLineEventArgs; TaskCommandLineEventArgs rightCommand = right.NodeBuildEvent.Value.Value as TaskCommandLineEventArgs; diff --git a/src/Build.UnitTests/BackEnd/TargetResult_Tests.cs b/src/Build.UnitTests/BackEnd/TargetResult_Tests.cs index 346da6846b9..67950cf5716 100644 --- a/src/Build.UnitTests/BackEnd/TargetResult_Tests.cs +++ b/src/Build.UnitTests/BackEnd/TargetResult_Tests.cs @@ -89,8 +89,12 @@ public void TestTranslationNoException() { TaskItem item = new TaskItem("foo", "bar.proj"); item.SetMetadata("a", "b"); + var buildEventContext = new Framework.BuildEventContext(1, 2, 3, 4, 5, 6, 7); - TargetResult result = new TargetResult(new TaskItem[] { item }, BuildResultUtilities.GetStopWithErrorResult()); + TargetResult result = new TargetResult( + new TaskItem[] { item }, + BuildResultUtilities.GetStopWithErrorResult(), + buildEventContext); ((ITranslatable)result).Translate(TranslationHelpers.GetWriteTranslator()); TargetResult deserializedResult = TargetResult.FactoryForDeserialization(TranslationHelpers.GetReadTranslator()); @@ -98,6 +102,7 @@ public void TestTranslationNoException() Assert.Equal(result.ResultCode, deserializedResult.ResultCode); Assert.True(TranslationHelpers.CompareCollections(result.Items, deserializedResult.Items, TaskItemComparer.Instance)); Assert.True(TranslationHelpers.CompareExceptions(result.Exception, deserializedResult.Exception)); + Assert.Equal(result.OriginalBuildEventContext, deserializedResult.OriginalBuildEventContext); } /// diff --git a/src/Build.UnitTests/BuildEventArgsSerialization_Tests.cs b/src/Build.UnitTests/BuildEventArgsSerialization_Tests.cs index f1b59b48e1f..aa1c2b4679d 100644 --- a/src/Build.UnitTests/BuildEventArgsSerialization_Tests.cs +++ b/src/Build.UnitTests/BuildEventArgsSerialization_Tests.cs @@ -443,20 +443,31 @@ public void RoundtripTargetSkippedEventArgs() ProjectFile = "foo.csproj", TargetName = "target", ParentTarget = "bar", - BuildReason = TargetBuiltReason.DependsOn + BuildReason = TargetBuiltReason.DependsOn, + SkipReason = TargetSkipReason.PreviouslyBuiltSuccessfully, + Condition = "$(condition) == true", + EvaluatedCondition = "true == true", + OriginalBuildEventContext = new BuildEventContext(1, 2, 3, 4, 5, 6, 7), + OriginallySucceeded = false, + TargetFile = "foo.csproj" }; Roundtrip(args, + e => e.BuildEventContext.ToString(), e => e.ParentTarget, e => e.Importance.ToString(), e => e.LineNumber.ToString(), e => e.ColumnNumber.ToString(), - e => e.LineNumber.ToString(), e => e.Message, e => e.ProjectFile, e => e.TargetFile, e => e.TargetName, - e => e.BuildReason.ToString()); + e => e.BuildReason.ToString(), + e => e.SkipReason.ToString(), + e => e.Condition, + e => e.EvaluatedCondition, + e => e.OriginalBuildEventContext.ToString(), + e => e.OriginallySucceeded.ToString()); } [Fact] diff --git a/src/Build/BackEnd/Components/Communications/TranslatorExtensions.cs b/src/Build/BackEnd/Components/Communications/TranslatorExtensions.cs index 4116039458a..f10fbf8dc50 100644 --- a/src/Build/BackEnd/Components/Communications/TranslatorExtensions.cs +++ b/src/Build/BackEnd/Components/Communications/TranslatorExtensions.cs @@ -4,10 +4,11 @@ using System; using System.Collections.Concurrent; using System.Linq; +using System.Reflection; using Microsoft.Build.Collections; using Microsoft.Build.Execution; +using Microsoft.Build.Framework; using Microsoft.Build.Shared; -using System.Reflection; namespace Microsoft.Build.BackEnd { @@ -103,5 +104,17 @@ public static T FactoryForDeserializingTypeWithName(this ITranslator translat return (T) targetInstanceChild; } + + public static void TranslateOptionalBuildEventContext(this ITranslator translator, ref BuildEventContext buildEventContext) + { + if (translator.Mode == TranslationDirection.ReadFromStream) + { + buildEventContext = translator.Reader.ReadOptionalBuildEventContext(); + } + else + { + translator.Writer.WriteOptionalBuildEventContext(buildEventContext); + } + } } } diff --git a/src/Build/BackEnd/Components/Logging/NodeLoggingContext.cs b/src/Build/BackEnd/Components/Logging/NodeLoggingContext.cs index 05c5ae53708..bfc351502cd 100644 --- a/src/Build/BackEnd/Components/Logging/NodeLoggingContext.cs +++ b/src/Build/BackEnd/Components/Logging/NodeLoggingContext.cs @@ -80,18 +80,26 @@ internal void LogRequestHandledFromCache(BuildRequest request, BuildRequestConfi { ProjectLoggingContext projectLoggingContext = LogProjectStarted(request, configuration); - // When pulling a request from the cache, we want to make sure we log a task skipped message for any targets which - // were used to build the request including default and inital targets. + // When pulling a request from the cache, we want to make sure we log a target skipped event for any targets which + // were used to build the request including default and initial targets. foreach (string target in configuration.GetTargetsUsedToBuildRequest(request)) { - projectLoggingContext.LogComment - ( - MessageImportance.Low, - result[target].ResultCode == TargetResultCode.Failure ? "TargetAlreadyCompleteFailure" : "TargetAlreadyCompleteSuccess", - target - ); + var targetResult = result[target]; + bool isFailure = targetResult.ResultCode == TargetResultCode.Failure; - if (result[target].ResultCode == TargetResultCode.Failure) + var skippedTargetEventArgs = new TargetSkippedEventArgs(message: null) + { + BuildEventContext = projectLoggingContext.BuildEventContext, + TargetName = target, + BuildReason = TargetBuiltReason.None, + SkipReason = isFailure ? TargetSkipReason.PreviouslyBuiltUnsuccessfully : TargetSkipReason.PreviouslyBuiltSuccessfully, + OriginallySucceeded = !isFailure, + OriginalBuildEventContext = (targetResult as TargetResult)?.OriginalBuildEventContext + }; + + projectLoggingContext.LogBuildEvent(skippedTargetEventArgs); + + if (targetResult.ResultCode == TargetResultCode.Failure) { break; } diff --git a/src/Build/BackEnd/Components/RequestBuilder/TargetBuilder.cs b/src/Build/BackEnd/Components/RequestBuilder/TargetBuilder.cs index 617fea73b47..e882ec2047d 100644 --- a/src/Build/BackEnd/Components/RequestBuilder/TargetBuilder.cs +++ b/src/Build/BackEnd/Components/RequestBuilder/TargetBuilder.cs @@ -564,6 +564,7 @@ private bool CheckSkipTarget(ref bool stopProcessingStack, TargetEntry currentTa { // If we've already dealt with this target and it didn't skip, let's log appropriately // Otherwise we don't want anything more to do with it. + bool success = targetResult.ResultCode == TargetResultCode.Success; var skippedTargetEventArgs = new TargetSkippedEventArgs(message: null) { BuildEventContext = _projectLoggingContext.BuildEventContext, @@ -571,7 +572,9 @@ private bool CheckSkipTarget(ref bool stopProcessingStack, TargetEntry currentTa TargetFile = currentTargetEntry.Target.Location.File, ParentTarget = currentTargetEntry.ParentEntry?.Target.Name, BuildReason = currentTargetEntry.BuildReason, - OriginallySucceeded = targetResult.ResultCode == TargetResultCode.Success + OriginallySucceeded = success, + SkipReason = success ? TargetSkipReason.PreviouslyBuiltSuccessfully : TargetSkipReason.PreviouslyBuiltSuccessfully, + OriginalBuildEventContext = targetResult.OriginalBuildEventContext }; _projectLoggingContext.LogBuildEvent(skippedTargetEventArgs); diff --git a/src/Build/BackEnd/Components/RequestBuilder/TargetEntry.cs b/src/Build/BackEnd/Components/RequestBuilder/TargetEntry.cs index f7543d5d91d..b11f674ffab 100644 --- a/src/Build/BackEnd/Components/RequestBuilder/TargetEntry.cs +++ b/src/Build/BackEnd/Components/RequestBuilder/TargetEntry.cs @@ -354,7 +354,10 @@ internal List GetDependencies(ProjectLoggingContext project if (!condition) { - _targetResult = new TargetResult(Array.Empty(), new WorkUnitResult(WorkUnitResultCode.Skipped, WorkUnitActionCode.Continue, null)); + _targetResult = new TargetResult( + Array.Empty(), + new WorkUnitResult(WorkUnitResultCode.Skipped, WorkUnitActionCode.Continue, null), + projectLoggingContext.BuildEventContext); _state = TargetEntryState.Completed; if (!projectLoggingContext.LoggingService.OnlyLogCriticalEvents) @@ -640,14 +643,11 @@ internal async Task ExecuteTarget(ITaskBuilder taskBuilder, BuildRequestEntry re } finally { - - - // log the last target finished since we now have the target outputs. - targetLoggingContext?.LogTargetBatchFinished(projectFullPath, targetSuccess, targetOutputItems?.Count > 0 ? targetOutputItems : null); - + // log the last target finished since we now have the target outputs. + targetLoggingContext?.LogTargetBatchFinished(projectFullPath, targetSuccess, targetOutputItems?.Count > 0 ? targetOutputItems : null); } - _targetResult = new TargetResult(targetOutputItems.ToArray(), aggregateResult); + _targetResult = new TargetResult(targetOutputItems.ToArray(), aggregateResult, targetLoggingContext?.BuildEventContext); if (aggregateResult.ResultCode == WorkUnitResultCode.Failed && aggregateResult.ActionCode == WorkUnitActionCode.Stop) { diff --git a/src/Build/BackEnd/Components/RequestBuilder/TargetUpToDateChecker.cs b/src/Build/BackEnd/Components/RequestBuilder/TargetUpToDateChecker.cs index 335dcf77097..9013bc11272 100644 --- a/src/Build/BackEnd/Components/RequestBuilder/TargetUpToDateChecker.cs +++ b/src/Build/BackEnd/Components/RequestBuilder/TargetUpToDateChecker.cs @@ -233,9 +233,17 @@ out ItemDictionary upToDateTargetInputs if (result == DependencyAnalysisResult.SkipUpToDate) { - _loggingService.LogComment(_buildEventContext, MessageImportance.Normal, - "SkipTargetBecauseOutputsUpToDate", - TargetToAnalyze.Name); + var skippedTargetEventArgs = new TargetSkippedEventArgs(message: null) + { + BuildEventContext = _buildEventContext, + TargetName = TargetToAnalyze.Name, + BuildReason = TargetBuiltReason.None, + SkipReason = TargetSkipReason.OutputsUpToDate, + OriginallySucceeded = true, + Importance = MessageImportance.Normal + }; + + _loggingService.LogBuildEvent(skippedTargetEventArgs); // Log the target inputs & outputs if (!_loggingService.OnlyLogCriticalEvents) @@ -337,7 +345,7 @@ private static string GetIncrementalBuildReason(DependencyAnalysisLogDetail logD /// /// Extract only the unique inputs and outputs from all the inputs and outputs gathered - /// during depedency analysis + /// during dependency analysis /// private void LogUniqueInputsAndOutputs() { diff --git a/src/Build/BackEnd/Shared/TargetResult.cs b/src/Build/BackEnd/Shared/TargetResult.cs index 3eb907062e7..8f7dd4f444e 100644 --- a/src/Build/BackEnd/Shared/TargetResult.cs +++ b/src/Build/BackEnd/Shared/TargetResult.cs @@ -44,17 +44,24 @@ public class TargetResult : ITargetResult, ITranslatable /// private CacheInfo _cacheInfo; + /// + /// The (possibly null) from the original target build + /// + private BuildEventContext _originalBuildEventContext; + /// /// Initializes the results with specified items and result. /// /// The items produced by the target. /// The overall result for the target. - internal TargetResult(TaskItem[] items, WorkUnitResult result) + /// The original build event context from when the target was first built, if available. Can be null. + internal TargetResult(TaskItem[] items, WorkUnitResult result, BuildEventContext originalBuildEventContext = null) { ErrorUtilities.VerifyThrowArgumentNull(items, nameof(items)); ErrorUtilities.VerifyThrowArgumentNull(result, nameof(result)); _items = items; _result = result; + _originalBuildEventContext = originalBuildEventContext; } /// @@ -130,6 +137,11 @@ internal WorkUnitResult WorkUnitResult get => _result; } + /// + /// The (possibly null) from the original target build + /// + internal BuildEventContext OriginalBuildEventContext => _originalBuildEventContext; + /// /// Sets or gets a flag indicating whether or not a failure results should cause the build to fail. /// @@ -253,6 +265,7 @@ private void InternalTranslate(ITranslator translator) translator.Translate(ref _result, WorkUnitResult.FactoryForDeserialization); translator.Translate(ref _targetFailureDoesntCauseBuildFailure); translator.Translate(ref _afterTargetsHaveFailed); + translator.TranslateOptionalBuildEventContext(ref _originalBuildEventContext); TranslateItems(translator); } diff --git a/src/Build/Logging/BinaryLogger/BinaryLogger.cs b/src/Build/Logging/BinaryLogger/BinaryLogger.cs index 6bcd2951e2d..dac426db8b4 100644 --- a/src/Build/Logging/BinaryLogger/BinaryLogger.cs +++ b/src/Build/Logging/BinaryLogger/BinaryLogger.cs @@ -48,7 +48,10 @@ public sealed class BinaryLogger : ILogger // version 13: // - don't log Message where it can be recovered // - log arguments for LazyFormattedBuildEventArgs - internal const int FileFormatVersion = 13; + // - TargetSkippedEventArgs: added OriginallySucceeded, Condition, EvaluatedCondition + // version 14: + // - TargetSkippedEventArgs: added SkipReason, OriginalBuildEventContext + internal const int FileFormatVersion = 14; private Stream stream; private BinaryWriter binaryWriter; diff --git a/src/Build/Logging/BinaryLogger/BuildEventArgsReader.cs b/src/Build/Logging/BinaryLogger/BuildEventArgsReader.cs index 47c1f6d8306..e9a48bd592f 100644 --- a/src/Build/Logging/BinaryLogger/BuildEventArgsReader.cs +++ b/src/Build/Logging/BinaryLogger/BuildEventArgsReader.cs @@ -297,6 +297,8 @@ private BuildEventArgs ReadTargetSkippedEventArgs() string condition = null; string evaluatedCondition = null; bool originallySucceeded = false; + TargetSkipReason skipReason = TargetSkipReason.None; + BuildEventContext originalBuildEventContext = null; if (fileFormatVersion >= 13) { condition = ReadOptionalString(); @@ -306,6 +308,12 @@ private BuildEventArgs ReadTargetSkippedEventArgs() var buildReason = (TargetBuiltReason)ReadInt32(); + if (fileFormatVersion >= 14) + { + skipReason = (TargetSkipReason)ReadInt32(); + originalBuildEventContext = binaryReader.ReadOptionalBuildEventContext(); + } + var e = new TargetSkippedEventArgs( fields.Message, fields.Arguments); @@ -320,6 +328,8 @@ private BuildEventArgs ReadTargetSkippedEventArgs() e.Condition = condition; e.EvaluatedCondition = evaluatedCondition; e.OriginallySucceeded = originallySucceeded; + e.SkipReason = skipReason; + e.OriginalBuildEventContext = originalBuildEventContext; return e; } diff --git a/src/Build/Logging/BinaryLogger/BuildEventArgsWriter.cs b/src/Build/Logging/BinaryLogger/BuildEventArgsWriter.cs index 20cd4232cb2..01c81ddba8c 100644 --- a/src/Build/Logging/BinaryLogger/BuildEventArgsWriter.cs +++ b/src/Build/Logging/BinaryLogger/BuildEventArgsWriter.cs @@ -454,6 +454,8 @@ private void Write(TargetSkippedEventArgs e) WriteDeduplicatedString(e.EvaluatedCondition); Write(e.OriginallySucceeded); Write((int)e.BuildReason); + Write((int)e.SkipReason); + binaryWriter.WriteOptionalBuildEventContext(e.OriginalBuildEventContext); } private void Write(CriticalBuildMessageEventArgs e) diff --git a/src/Framework/BuildEventContext.cs b/src/Framework/BuildEventContext.cs index edde77d5fbb..0cda93d76c6 100644 --- a/src/Framework/BuildEventContext.cs +++ b/src/Framework/BuildEventContext.cs @@ -306,5 +306,9 @@ private bool InternalEquals(BuildEventContext buildEventContext) } #endregion + public override string ToString() + { + return $"Node={NodeId} Submission={SubmissionId} ProjectContext={ProjectContextId} ProjectInstance={ProjectInstanceId} Eval={EvaluationId} Target={TargetId} Task={TaskId}"; + } } } diff --git a/src/Framework/BuildMessageEventArgs.cs b/src/Framework/BuildMessageEventArgs.cs index 23282a1db87..58f069d23d6 100644 --- a/src/Framework/BuildMessageEventArgs.cs +++ b/src/Framework/BuildMessageEventArgs.cs @@ -302,7 +302,11 @@ internal override void CreateFromStream(BinaryReader reader, int version) /// /// Importance of the message /// - public MessageImportance Importance => importance; + public MessageImportance Importance + { + get => importance; + internal set => importance = value; + } /// /// The custom sub-type of the event. diff --git a/src/Framework/TargetSkippedEventArgs.cs b/src/Framework/TargetSkippedEventArgs.cs index 5bad19a7251..d34e468ff32 100644 --- a/src/Framework/TargetSkippedEventArgs.cs +++ b/src/Framework/TargetSkippedEventArgs.cs @@ -7,6 +7,37 @@ namespace Microsoft.Build.Framework { + /// + /// A reason why a target was skipped. + /// + public enum TargetSkipReason + { + /// + /// The target was not skipped or the skip reason was unknown. + /// + None, + + /// + /// The target previously built successfully. + /// + PreviouslyBuiltSuccessfully, + + /// + /// The target previously built unsuccessfully. + /// + PreviouslyBuiltUnsuccessfully, + + /// + /// All the target outputs were up-to-date with respect to their inputs. + /// + OutputsUpToDate, + + /// + /// The condition on the target was evaluated as false. + /// + ConditionWasFalse + } + /// /// Arguments for the target skipped event. /// @@ -45,6 +76,11 @@ params object[] messageArgs { } + /// + /// The reason why the target was skipped. + /// + public TargetSkipReason SkipReason { get; set; } + /// /// Gets or sets the name of the target being skipped. /// @@ -65,10 +101,24 @@ params object[] messageArgs /// public TargetBuiltReason BuildReason { get; set; } + /// + /// Whether the target succeeded originally. + /// public bool OriginallySucceeded { get; set; } + /// + /// describing the original build of the target, or null if not available. + /// + public BuildEventContext OriginalBuildEventContext { get; set; } + + /// + /// The condition expression on the target declaration. + /// public string Condition { get; set; } + /// + /// The value of the condition expression as it was evaluated. + /// public string EvaluatedCondition { get; set; } internal override void WriteToStream(BinaryWriter writer) @@ -81,7 +131,9 @@ internal override void WriteToStream(BinaryWriter writer) writer.WriteOptionalString(Condition); writer.WriteOptionalString(EvaluatedCondition); writer.Write7BitEncodedInt((int)BuildReason); + writer.Write7BitEncodedInt((int)SkipReason); writer.Write(OriginallySucceeded); + writer.WriteOptionalBuildEventContext(OriginalBuildEventContext); } internal override void CreateFromStream(BinaryReader reader, int version) @@ -94,7 +146,9 @@ internal override void CreateFromStream(BinaryReader reader, int version) Condition = reader.ReadOptionalString(); EvaluatedCondition = reader.ReadOptionalString(); BuildReason = (TargetBuiltReason)reader.Read7BitEncodedInt(); + SkipReason = (TargetSkipReason)reader.Read7BitEncodedInt(); OriginallySucceeded = reader.ReadBoolean(); + OriginalBuildEventContext = reader.ReadOptionalBuildEventContext(); } public override string Message @@ -107,22 +161,29 @@ public override string Message { if (RawMessage == null) { - if (Condition != null) - { - RawMessage = FormatResourceStringIgnoreCodeAndKeyword( - "TargetSkippedFalseCondition", - TargetName, - Condition, - EvaluatedCondition); - } - else + RawMessage = SkipReason switch { - RawMessage = FormatResourceStringIgnoreCodeAndKeyword( - OriginallySucceeded - ? "TargetAlreadyCompleteSuccess" - : "TargetAlreadyCompleteFailure", - TargetName); - } + TargetSkipReason.PreviouslyBuiltSuccessfully or TargetSkipReason.PreviouslyBuiltUnsuccessfully => + FormatResourceStringIgnoreCodeAndKeyword( + OriginallySucceeded + ? "TargetAlreadyCompleteSuccess" + : "TargetAlreadyCompleteFailure", + TargetName), + + TargetSkipReason.ConditionWasFalse => + FormatResourceStringIgnoreCodeAndKeyword( + "TargetSkippedFalseCondition", + TargetName, + Condition, + EvaluatedCondition), + + TargetSkipReason.OutputsUpToDate => + FormatResourceStringIgnoreCodeAndKeyword( + "SkipTargetBecauseOutputsUpToDate", + TargetName), + + _ => SkipReason.ToString() + }; } } } diff --git a/src/Shared/BinaryTranslator.cs b/src/Shared/BinaryTranslator.cs index 6c2b6337393..97734d07fb2 100644 --- a/src/Shared/BinaryTranslator.cs +++ b/src/Shared/BinaryTranslator.cs @@ -189,7 +189,7 @@ public void Translate(ref byte[] byteArray) } else { - byteArray = new byte[0]; + byteArray = Array.Empty(); } } From 65a6e2147e8ebb7f9e5c845278ae236d442df05d Mon Sep 17 00:00:00 2001 From: Kirill Osenkov Date: Sun, 2 May 2021 19:48:28 -0700 Subject: [PATCH 2/6] Can't use Array.Empty() in .NET 3.5. --- src/Shared/BinaryTranslator.cs | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/src/Shared/BinaryTranslator.cs b/src/Shared/BinaryTranslator.cs index 97734d07fb2..6c2b6337393 100644 --- a/src/Shared/BinaryTranslator.cs +++ b/src/Shared/BinaryTranslator.cs @@ -189,7 +189,7 @@ public void Translate(ref byte[] byteArray) } else { - byteArray = Array.Empty(); + byteArray = new byte[0]; } } From 7bb849ae43ee279ed6d3c2d811fe75de9e205d72 Mon Sep 17 00:00:00 2001 From: Kirill Osenkov Date: Mon, 3 May 2021 18:18:59 -0700 Subject: [PATCH 3/6] Fix skip reason. --- src/Build/BackEnd/Components/RequestBuilder/TargetBuilder.cs | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/src/Build/BackEnd/Components/RequestBuilder/TargetBuilder.cs b/src/Build/BackEnd/Components/RequestBuilder/TargetBuilder.cs index e882ec2047d..49232b46b9e 100644 --- a/src/Build/BackEnd/Components/RequestBuilder/TargetBuilder.cs +++ b/src/Build/BackEnd/Components/RequestBuilder/TargetBuilder.cs @@ -573,7 +573,7 @@ private bool CheckSkipTarget(ref bool stopProcessingStack, TargetEntry currentTa ParentTarget = currentTargetEntry.ParentEntry?.Target.Name, BuildReason = currentTargetEntry.BuildReason, OriginallySucceeded = success, - SkipReason = success ? TargetSkipReason.PreviouslyBuiltSuccessfully : TargetSkipReason.PreviouslyBuiltSuccessfully, + SkipReason = success ? TargetSkipReason.PreviouslyBuiltSuccessfully : TargetSkipReason.PreviouslyBuiltUnsuccessfully, OriginalBuildEventContext = targetResult.OriginalBuildEventContext }; From 454959c05cc1f202b9db459356a9b8d747a0301f Mon Sep 17 00:00:00 2001 From: Kirill Osenkov Date: Mon, 3 May 2021 19:11:27 -0700 Subject: [PATCH 4/6] Add comment explaining when TargetResult.OriginalBuildEventContext can be null. --- src/Build/BackEnd/Shared/TargetResult.cs | 8 +++++++- 1 file changed, 7 insertions(+), 1 deletion(-) diff --git a/src/Build/BackEnd/Shared/TargetResult.cs b/src/Build/BackEnd/Shared/TargetResult.cs index 8f7dd4f444e..4969cdb7664 100644 --- a/src/Build/BackEnd/Shared/TargetResult.cs +++ b/src/Build/BackEnd/Shared/TargetResult.cs @@ -54,7 +54,13 @@ public class TargetResult : ITargetResult, ITranslatable /// /// The items produced by the target. /// The overall result for the target. - /// The original build event context from when the target was first built, if available. Can be null. + /// The original build event context from when the target was first built, if available. + /// Non-null when creating a after building the target initially (or skipping due to false condition). + /// Null when the is being created in other scenarios: + /// * Target that never ran because a dependency had an error + /// * in when Cancellation was requested + /// * in ProjectCache.CacheResult.ConstructBuildResult + /// internal TargetResult(TaskItem[] items, WorkUnitResult result, BuildEventContext originalBuildEventContext = null) { ErrorUtilities.VerifyThrowArgumentNull(items, nameof(items)); From 0c26b4e38b47a81bf85b141f7aad2fd554cf9bf6 Mon Sep 17 00:00:00 2001 From: Kirill Osenkov Date: Mon, 3 May 2021 20:41:25 -0700 Subject: [PATCH 5/6] Forgot to set SkipReason ConditionWasFalse. --- src/Build/BackEnd/Components/RequestBuilder/TargetEntry.cs | 1 + 1 file changed, 1 insertion(+) diff --git a/src/Build/BackEnd/Components/RequestBuilder/TargetEntry.cs b/src/Build/BackEnd/Components/RequestBuilder/TargetEntry.cs index b11f674ffab..1314a3c173a 100644 --- a/src/Build/BackEnd/Components/RequestBuilder/TargetEntry.cs +++ b/src/Build/BackEnd/Components/RequestBuilder/TargetEntry.cs @@ -378,6 +378,7 @@ internal List GetDependencies(ProjectLoggingContext project TargetFile = _target.Location.File, ParentTarget = ParentEntry?.Target?.Name, BuildReason = BuildReason, + SkipReason = TargetSkipReason.ConditionWasFalse, Condition = _target.Condition, EvaluatedCondition = expanded }; From 21efdb6ea429115f1cab10724dd57a540b61b692 Mon Sep 17 00:00:00 2001 From: Kirill Osenkov Date: Tue, 4 May 2021 14:12:31 -0700 Subject: [PATCH 6/6] Add a check that TargetSkipReason is set --- src/Build/Logging/BinaryLogger/BuildEventArgsWriter.cs | 2 ++ 1 file changed, 2 insertions(+) diff --git a/src/Build/Logging/BinaryLogger/BuildEventArgsWriter.cs b/src/Build/Logging/BinaryLogger/BuildEventArgsWriter.cs index 01c81ddba8c..51a003098da 100644 --- a/src/Build/Logging/BinaryLogger/BuildEventArgsWriter.cs +++ b/src/Build/Logging/BinaryLogger/BuildEventArgsWriter.cs @@ -445,6 +445,8 @@ private void Write(ProjectImportedEventArgs e) private void Write(TargetSkippedEventArgs e) { + ErrorUtilities.VerifyThrow(e.SkipReason != TargetSkipReason.None, "TargetSkippedEventArgs.SkipReason needs to be set"); + Write(BinaryLogRecordKind.TargetSkipped); WriteMessageFields(e, writeMessage: false); WriteDeduplicatedString(e.TargetFile);