From 0ebf5f31799626c11ead6cbebef72f7dc49c164c Mon Sep 17 00:00:00 2001 From: Kirill Osenkov Date: Fri, 28 May 2021 12:19:44 -0700 Subject: [PATCH] Add TargetSkipReason and OriginalBuildEventContext to TargetSkippedEventArgs (#6402) 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 #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 | 28 ++++-- .../RequestBuilder/TargetBuilder.cs | 5 +- .../Components/RequestBuilder/TargetEntry.cs | 15 +-- .../RequestBuilder/TargetUpToDateChecker.cs | 16 +++- src/Build/BackEnd/Shared/TargetResult.cs | 21 ++++- .../Logging/BinaryLogger/BinaryLogger.cs | 5 +- .../BinaryLogger/BuildEventArgsReader.cs | 10 ++ .../BinaryLogger/BuildEventArgsWriter.cs | 4 + src/Framework/BuildEventContext.cs | 4 + src/Framework/BuildMessageEventArgs.cs | 6 +- src/Framework/TargetSkippedEventArgs.cs | 91 ++++++++++++++++--- 17 files changed, 262 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 d65dea4e3a2..541cc8cc6b9 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); @@ -176,6 +178,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. /// @@ -209,7 +231,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) @@ -414,6 +437,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 0f4e8056159..f0ab15a20a8 100644 --- a/src/Build.UnitTests/BuildEventArgsSerialization_Tests.cs +++ b/src/Build.UnitTests/BuildEventArgsSerialization_Tests.cs @@ -447,20 +447,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 0b55b80359a..6852343e9be 100644 --- a/src/Build/BackEnd/Components/Logging/NodeLoggingContext.cs +++ b/src/Build/BackEnd/Components/Logging/NodeLoggingContext.cs @@ -86,18 +86,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 - ); - - if (result[target].ResultCode == TargetResultCode.Failure) + var targetResult = result[target]; + bool isFailure = targetResult.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 21bdf35cb01..6b4b24dfa81 100644 --- a/src/Build/BackEnd/Components/RequestBuilder/TargetBuilder.cs +++ b/src/Build/BackEnd/Components/RequestBuilder/TargetBuilder.cs @@ -555,6 +555,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, @@ -562,7 +563,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.PreviouslyBuiltUnsuccessfully, + 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..1314a3c173a 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) @@ -375,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 }; @@ -640,14 +644,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..4969cdb7664 100644 --- a/src/Build/BackEnd/Shared/TargetResult.cs +++ b/src/Build/BackEnd/Shared/TargetResult.cs @@ -44,17 +44,30 @@ 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. + /// 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)); ErrorUtilities.VerifyThrowArgumentNull(result, nameof(result)); _items = items; _result = result; + _originalBuildEventContext = originalBuildEventContext; } /// @@ -130,6 +143,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 +271,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 27d6706108c..f5c0d7a8f94 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..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); @@ -454,6 +456,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 79d8a5177a9..e84c9ed6c02 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() + }; } } }