From c09a5377388631ca55730b0b15b0d3da2ab8d380 Mon Sep 17 00:00:00 2001 From: Kirill Osenkov Date: Sun, 4 Apr 2021 17:25:10 -0700 Subject: [PATCH 01/14] Don't log BuildEventArgs.Message where it can be reconstructed. For most BuildEventArgs we can completely reconstruct the message text from the other fields. Do not allocate and log the Message string in this case, and override Message implementation to recover the message lazily on demand. This way the message never needs to be allocated to travel across nodes or written/read into binlog. It is only materialized when a console/file logger requests it. For cases where LazyFormattedBuildEventArgs has Arguments, don't flatten and materialize the Message during node packet translation or binlog write/read. The two improvements above help significantly reduce string allocations, the number of strings logged and the string size. Smaller strings means that deduplication can do a better job reusing strings, and as such most large strings simply dissolve. Strings before: Total size: 7,770,723, Count: 33,648, Largest: 55,401 Strings after: Total size: 1,382,154, Count: 18,701, Largest: 10,197 Increment the binlog file format version to 13. Write LazyFormattedBuildEventArgs.Arguments array into the binlog if present. Do not persist Importance for BuildEventArgs that ignore it or where it defaults to low. Do not write ThreadId into the binlog as it's never used. Introduce the internal field BuildEventArgs.RawMessage to expose the underlying message field and avoid the side effects of calling Message (which formats using the Arguments). Add Condition, EvaluatedCondition and OriginallySucceeded on TargetSkippedEventArgs so we can recover the message. Do not sort item metadata when writing a binlog. We want binlogs to be fully roundtrippable and not lose any information. This is useful for unit-tests that compare against text logs and verify that played back logs are fully identical. Add a new ILoggingService.LogCommentFromText overload that accepts a string and arguments. This allows us to cache resource strings instead of retrieving them every time. Do not allocate or set Message when creating ProjectStarted, ProjectFinished, TargetStarted, TargetFinished, TaskStarted or TaskFinished. Following the pattern set for TaskParameterEventArgs, inject the logic to format resource strings into BuildEventArgs using a static delegate. Later we can refactor and find a better pattern for this, but this works for now. For TargetSkipped, log either OriginallySucceeded or Condition/EvaluatedCondition, and don't log the Message. When logging input files and output files for skipped targets, do not concatenate them into huge semicolon-separated strings, but log a TaskParameterEventArgs instead. Introduce two new kinds of TaskParameter: TargetSkippedInputs and TargetSkippedOutputs. However as this is a flat list of files with no itemType, log itemType as null. Adjust the GetParameterText() logic to not write an extra indent or itemType if it is null. Implement manual node packet translation for ProjectImported, TargetSkipped and Telemetry event args to avoid TranslateDotNet and binary formatter. --- .../net/Microsoft.Build.Framework.cs | 16 ++ .../netstandard/Microsoft.Build.Framework.cs | 16 ++ .../BackEnd/MockLoggingService.cs | 11 ++ .../BuildEventArgsSerialization_Tests.cs | 24 ++- .../Components/Logging/ILoggingService.cs | 12 ++ .../Components/Logging/LoggingContext.cs | 12 ++ .../Logging/LoggingServiceLogMethods.cs | 76 ++------ .../IntrinsicTasks/ItemGroupLoggingHelper.cs | 43 +++- .../RequestBuilder/TargetBuilder.cs | 9 +- .../Components/RequestBuilder/TargetEntry.cs | 10 +- .../Logging/BinaryLogger/BinaryLogger.cs | 5 +- .../BinaryLogger/BuildEventArgsFieldFlags.cs | 4 +- .../BinaryLogger/BuildEventArgsFields.cs | 2 + .../BinaryLogger/BuildEventArgsReader.cs | 104 ++++++---- .../BinaryLogger/BuildEventArgsWriter.cs | 184 ++++++++++-------- src/Framework/BuildEventArgs.cs | 57 +++++- src/Framework/LazyFormattedBuildEventArgs.cs | 11 +- src/Framework/ProjectFinishedEventArgs.cs | 19 ++ src/Framework/ProjectImportedEventArgs.cs | 35 +++- src/Framework/ProjectStartedEventArgs.cs | 31 +++ .../PropertyReassignmentEventArgs.cs | 19 ++ src/Framework/TargetFinishedEventArgs.cs | 21 +- src/Framework/TargetSkippedEventArgs.cs | 83 +++++++- src/Framework/TargetStartedEventArgs.cs | 40 ++++ src/Framework/TaskFinishedEventArgs.cs | 19 ++ src/Framework/TaskParameterEventArgs.cs | 6 +- src/Framework/TaskStartedEventArgs.cs | 19 ++ src/Framework/TelemetryEventArgs.cs | 32 +++ src/Shared/LogMessagePacketBase.cs | 32 ++- 29 files changed, 739 insertions(+), 213 deletions(-) diff --git a/ref/Microsoft.Build.Framework/net/Microsoft.Build.Framework.cs b/ref/Microsoft.Build.Framework/net/Microsoft.Build.Framework.cs index 00db63a067d..d8a78e04125 100644 --- a/ref/Microsoft.Build.Framework/net/Microsoft.Build.Framework.cs +++ b/ref/Microsoft.Build.Framework/net/Microsoft.Build.Framework.cs @@ -38,6 +38,7 @@ public abstract partial class BuildEventArgs : System.EventArgs public Microsoft.Build.Framework.BuildEventContext BuildEventContext { get { throw null; } set { } } public string HelpKeyword { get { throw null; } } public virtual string Message { get { throw null; } protected set { } } + protected internal string RawMessage { get { throw null; } set { } } protected internal System.DateTime RawTimestamp { get { throw null; } set { } } public string SenderName { get { throw null; } } public int ThreadId { get { throw null; } } @@ -340,6 +341,8 @@ public partial interface ITaskItem2 : Microsoft.Build.Framework.ITaskItem } public partial class LazyFormattedBuildEventArgs : Microsoft.Build.Framework.BuildEventArgs { + [System.NonSerializedAttribute] + protected object locker; protected LazyFormattedBuildEventArgs() { } public LazyFormattedBuildEventArgs(string message, string helpKeyword, string senderName) { } public LazyFormattedBuildEventArgs(string message, string helpKeyword, string senderName, System.DateTime eventTimestamp, params object[] messageArgs) { } @@ -408,6 +411,7 @@ public partial class ProjectFinishedEventArgs : Microsoft.Build.Framework.BuildS protected ProjectFinishedEventArgs() { } public ProjectFinishedEventArgs(string message, string helpKeyword, string projectFile, bool succeeded) { } public ProjectFinishedEventArgs(string message, string helpKeyword, string projectFile, bool succeeded, System.DateTime eventTimestamp) { } + public override string Message { get { throw null; } } public string ProjectFile { get { throw null; } } public bool Succeeded { get { throw null; } } } @@ -431,6 +435,7 @@ public partial class ProjectStartedEventArgs : Microsoft.Build.Framework.BuildSt public ProjectStartedEventArgs(string message, string helpKeyword, string projectFile, string targetNames, System.Collections.IEnumerable properties, System.Collections.IEnumerable items, System.DateTime eventTimestamp) { } public System.Collections.Generic.IDictionary GlobalProperties { get { throw null; } } public System.Collections.IEnumerable Items { get { throw null; } } + public override string Message { get { throw null; } } public Microsoft.Build.Framework.BuildEventContext ParentProjectBuildEventContext { get { throw null; } } public string ProjectFile { get { throw null; } } public int ProjectId { get { throw null; } } @@ -452,6 +457,7 @@ public partial class PropertyReassignmentEventArgs : Microsoft.Build.Framework.B public PropertyReassignmentEventArgs() { } public PropertyReassignmentEventArgs(string propertyName, string previousValue, string newValue, string location, string message, string helpKeyword = null, string senderName = null, Microsoft.Build.Framework.MessageImportance importance = Microsoft.Build.Framework.MessageImportance.Low) { } public string Location { get { throw null; } set { } } + public override string Message { get { throw null; } } public string NewValue { get { throw null; } set { } } public string PreviousValue { get { throw null; } set { } } public string PropertyName { get { throw null; } set { } } @@ -558,6 +564,7 @@ public partial class TargetFinishedEventArgs : Microsoft.Build.Framework.BuildSt public TargetFinishedEventArgs(string message, string helpKeyword, string targetName, string projectFile, string targetFile, bool succeeded) { } public TargetFinishedEventArgs(string message, string helpKeyword, string targetName, string projectFile, string targetFile, bool succeeded, System.Collections.IEnumerable targetOutputs) { } public TargetFinishedEventArgs(string message, string helpKeyword, string targetName, string projectFile, string targetFile, bool succeeded, System.DateTime eventTimestamp, System.Collections.IEnumerable targetOutputs) { } + public override string Message { get { throw null; } } public string ProjectFile { get { throw null; } } public bool Succeeded { get { throw null; } } public string TargetFile { get { throw null; } } @@ -570,6 +577,10 @@ public partial class TargetSkippedEventArgs : Microsoft.Build.Framework.BuildMes public TargetSkippedEventArgs() { } public TargetSkippedEventArgs(string message, params object[] messageArgs) { } public Microsoft.Build.Framework.TargetBuiltReason BuildReason { get { throw null; } set { } } + public string Condition { get { throw null; } set { } } + public string EvaluatedCondition { get { throw null; } set { } } + public override string Message { get { throw null; } } + public bool OriginallySucceeded { get { throw null; } set { } } public string ParentTarget { get { throw null; } set { } } public string TargetFile { get { throw null; } set { } } public string TargetName { get { throw null; } set { } } @@ -581,6 +592,7 @@ public partial class TargetStartedEventArgs : Microsoft.Build.Framework.BuildSta public TargetStartedEventArgs(string message, string helpKeyword, string targetName, string projectFile, string targetFile, string parentTarget, Microsoft.Build.Framework.TargetBuiltReason buildReason, System.DateTime eventTimestamp) { } public TargetStartedEventArgs(string message, string helpKeyword, string targetName, string projectFile, string targetFile, string parentTarget, System.DateTime eventTimestamp) { } public Microsoft.Build.Framework.TargetBuiltReason BuildReason { get { throw null; } } + public override string Message { get { throw null; } } public string ParentTarget { get { throw null; } } public string ProjectFile { get { throw null; } } public string TargetFile { get { throw null; } } @@ -600,6 +612,7 @@ public partial class TaskFinishedEventArgs : Microsoft.Build.Framework.BuildStat protected TaskFinishedEventArgs() { } public TaskFinishedEventArgs(string message, string helpKeyword, string projectFile, string taskFile, string taskName, bool succeeded) { } public TaskFinishedEventArgs(string message, string helpKeyword, string projectFile, string taskFile, string taskName, bool succeeded, System.DateTime eventTimestamp) { } + public override string Message { get { throw null; } } public string ProjectFile { get { throw null; } } public bool Succeeded { get { throw null; } } public string TaskFile { get { throw null; } } @@ -621,6 +634,8 @@ public enum TaskParameterMessageKind TaskOutput = 1, AddItem = 2, RemoveItem = 3, + SkippedTargetInputs = 4, + SkippedTargetOutputs = 5, } public partial class TaskPropertyInfo { @@ -637,6 +652,7 @@ public partial class TaskStartedEventArgs : Microsoft.Build.Framework.BuildStatu protected TaskStartedEventArgs() { } public TaskStartedEventArgs(string message, string helpKeyword, string projectFile, string taskFile, string taskName) { } public TaskStartedEventArgs(string message, string helpKeyword, string projectFile, string taskFile, string taskName, System.DateTime eventTimestamp) { } + public override string Message { get { throw null; } } public string ProjectFile { get { throw null; } } public string TaskFile { get { throw null; } } public string TaskName { get { throw null; } } diff --git a/ref/Microsoft.Build.Framework/netstandard/Microsoft.Build.Framework.cs b/ref/Microsoft.Build.Framework/netstandard/Microsoft.Build.Framework.cs index 7b0fbb39d15..2fd1301abb1 100644 --- a/ref/Microsoft.Build.Framework/netstandard/Microsoft.Build.Framework.cs +++ b/ref/Microsoft.Build.Framework/netstandard/Microsoft.Build.Framework.cs @@ -38,6 +38,7 @@ public abstract partial class BuildEventArgs : System.EventArgs public Microsoft.Build.Framework.BuildEventContext BuildEventContext { get { throw null; } set { } } public string HelpKeyword { get { throw null; } } public virtual string Message { get { throw null; } protected set { } } + protected internal string RawMessage { get { throw null; } set { } } protected internal System.DateTime RawTimestamp { get { throw null; } set { } } public string SenderName { get { throw null; } } public int ThreadId { get { throw null; } } @@ -340,6 +341,8 @@ public partial interface ITaskItem2 : Microsoft.Build.Framework.ITaskItem } public partial class LazyFormattedBuildEventArgs : Microsoft.Build.Framework.BuildEventArgs { + [System.NonSerializedAttribute] + protected object locker; protected LazyFormattedBuildEventArgs() { } public LazyFormattedBuildEventArgs(string message, string helpKeyword, string senderName) { } public LazyFormattedBuildEventArgs(string message, string helpKeyword, string senderName, System.DateTime eventTimestamp, params object[] messageArgs) { } @@ -407,6 +410,7 @@ public partial class ProjectFinishedEventArgs : Microsoft.Build.Framework.BuildS protected ProjectFinishedEventArgs() { } public ProjectFinishedEventArgs(string message, string helpKeyword, string projectFile, bool succeeded) { } public ProjectFinishedEventArgs(string message, string helpKeyword, string projectFile, bool succeeded, System.DateTime eventTimestamp) { } + public override string Message { get { throw null; } } public string ProjectFile { get { throw null; } } public bool Succeeded { get { throw null; } } } @@ -430,6 +434,7 @@ public partial class ProjectStartedEventArgs : Microsoft.Build.Framework.BuildSt public ProjectStartedEventArgs(string message, string helpKeyword, string projectFile, string targetNames, System.Collections.IEnumerable properties, System.Collections.IEnumerable items, System.DateTime eventTimestamp) { } public System.Collections.Generic.IDictionary GlobalProperties { get { throw null; } } public System.Collections.IEnumerable Items { get { throw null; } } + public override string Message { get { throw null; } } public Microsoft.Build.Framework.BuildEventContext ParentProjectBuildEventContext { get { throw null; } } public string ProjectFile { get { throw null; } } public int ProjectId { get { throw null; } } @@ -451,6 +456,7 @@ public partial class PropertyReassignmentEventArgs : Microsoft.Build.Framework.B public PropertyReassignmentEventArgs() { } public PropertyReassignmentEventArgs(string propertyName, string previousValue, string newValue, string location, string message, string helpKeyword = null, string senderName = null, Microsoft.Build.Framework.MessageImportance importance = Microsoft.Build.Framework.MessageImportance.Low) { } public string Location { get { throw null; } set { } } + public override string Message { get { throw null; } } public string NewValue { get { throw null; } set { } } public string PreviousValue { get { throw null; } set { } } public string PropertyName { get { throw null; } set { } } @@ -557,6 +563,7 @@ public partial class TargetFinishedEventArgs : Microsoft.Build.Framework.BuildSt public TargetFinishedEventArgs(string message, string helpKeyword, string targetName, string projectFile, string targetFile, bool succeeded) { } public TargetFinishedEventArgs(string message, string helpKeyword, string targetName, string projectFile, string targetFile, bool succeeded, System.Collections.IEnumerable targetOutputs) { } public TargetFinishedEventArgs(string message, string helpKeyword, string targetName, string projectFile, string targetFile, bool succeeded, System.DateTime eventTimestamp, System.Collections.IEnumerable targetOutputs) { } + public override string Message { get { throw null; } } public string ProjectFile { get { throw null; } } public bool Succeeded { get { throw null; } } public string TargetFile { get { throw null; } } @@ -569,6 +576,10 @@ public partial class TargetSkippedEventArgs : Microsoft.Build.Framework.BuildMes public TargetSkippedEventArgs() { } public TargetSkippedEventArgs(string message, params object[] messageArgs) { } public Microsoft.Build.Framework.TargetBuiltReason BuildReason { get { throw null; } set { } } + public string Condition { get { throw null; } set { } } + public string EvaluatedCondition { get { throw null; } set { } } + public override string Message { get { throw null; } } + public bool OriginallySucceeded { get { throw null; } set { } } public string ParentTarget { get { throw null; } set { } } public string TargetFile { get { throw null; } set { } } public string TargetName { get { throw null; } set { } } @@ -580,6 +591,7 @@ public partial class TargetStartedEventArgs : Microsoft.Build.Framework.BuildSta public TargetStartedEventArgs(string message, string helpKeyword, string targetName, string projectFile, string targetFile, string parentTarget, Microsoft.Build.Framework.TargetBuiltReason buildReason, System.DateTime eventTimestamp) { } public TargetStartedEventArgs(string message, string helpKeyword, string targetName, string projectFile, string targetFile, string parentTarget, System.DateTime eventTimestamp) { } public Microsoft.Build.Framework.TargetBuiltReason BuildReason { get { throw null; } } + public override string Message { get { throw null; } } public string ParentTarget { get { throw null; } } public string ProjectFile { get { throw null; } } public string TargetFile { get { throw null; } } @@ -599,6 +611,7 @@ public partial class TaskFinishedEventArgs : Microsoft.Build.Framework.BuildStat protected TaskFinishedEventArgs() { } public TaskFinishedEventArgs(string message, string helpKeyword, string projectFile, string taskFile, string taskName, bool succeeded) { } public TaskFinishedEventArgs(string message, string helpKeyword, string projectFile, string taskFile, string taskName, bool succeeded, System.DateTime eventTimestamp) { } + public override string Message { get { throw null; } } public string ProjectFile { get { throw null; } } public bool Succeeded { get { throw null; } } public string TaskFile { get { throw null; } } @@ -620,6 +633,8 @@ public enum TaskParameterMessageKind TaskOutput = 1, AddItem = 2, RemoveItem = 3, + SkippedTargetInputs = 4, + SkippedTargetOutputs = 5, } public partial class TaskPropertyInfo { @@ -636,6 +651,7 @@ public partial class TaskStartedEventArgs : Microsoft.Build.Framework.BuildStatu protected TaskStartedEventArgs() { } public TaskStartedEventArgs(string message, string helpKeyword, string projectFile, string taskFile, string taskName) { } public TaskStartedEventArgs(string message, string helpKeyword, string projectFile, string taskFile, string taskName, System.DateTime eventTimestamp) { } + public override string Message { get { throw null; } } public string ProjectFile { get { throw null; } } public string TaskFile { get { throw null; } } public string TaskName { get { throw null; } } diff --git a/src/Build.UnitTests/BackEnd/MockLoggingService.cs b/src/Build.UnitTests/BackEnd/MockLoggingService.cs index 4b1857121e1..d428e3fdac6 100644 --- a/src/Build.UnitTests/BackEnd/MockLoggingService.cs +++ b/src/Build.UnitTests/BackEnd/MockLoggingService.cs @@ -300,6 +300,17 @@ public void LogCommentFromText(BuildEventContext buildEventContext, MessageImpor _writer(message); } + /// + public void LogCommentFromText(BuildEventContext buildEventContext, MessageImportance importance, string message, params object[] messageArgs) + { + if (messageArgs?.Length > 0) + { + message = string.Format(message, messageArgs); + } + + _writer(message); + } + /// /// Logs a pre-formed build event /// diff --git a/src/Build.UnitTests/BuildEventArgsSerialization_Tests.cs b/src/Build.UnitTests/BuildEventArgsSerialization_Tests.cs index 16b4cb0e035..c8f1761ac0b 100644 --- a/src/Build.UnitTests/BuildEventArgsSerialization_Tests.cs +++ b/src/Build.UnitTests/BuildEventArgsSerialization_Tests.cs @@ -16,6 +16,12 @@ namespace Microsoft.Build.UnitTests { public class BuildEventArgsSerializationTests { + public BuildEventArgsSerializationTests() + { + // touch the type so that static constructor runs + _ = ItemGroupLoggingHelper.ItemGroupIncludeLogMessagePrefix; + } + [Fact] public void RoundtripBuildStartedEventArgs() { @@ -62,7 +68,7 @@ public void RoundtripProjectStartedEventArgs() { var args = new ProjectStartedEventArgs( projectId: 42, - message: "Project started message", + message: "Project \"test.proj\" (Build target(s)):", helpKeyword: "help", projectFile: "C:\\test.proj", targetNames: "Build", @@ -431,7 +437,7 @@ public void RoundtripProjectImportedEventArgs() public void RoundtripTargetSkippedEventArgs() { var args = new TargetSkippedEventArgs( - "Message") + "Target \"target\" skipped. Previously built unsuccessfully.") { BuildEventContext = BuildEventContext.Invalid, ProjectFile = "foo.csproj", @@ -473,13 +479,13 @@ public void RoundTripEnvironmentVariableReadEventArgs() public void RoundTripPropertyReassignmentEventArgs() { var args = new PropertyReassignmentEventArgs( - propertyName: Guid.NewGuid().ToString(), - previousValue: Guid.NewGuid().ToString(), - newValue: Guid.NewGuid().ToString(), - location: Guid.NewGuid().ToString(), - message: Guid.NewGuid().ToString(), - helpKeyword: Guid.NewGuid().ToString(), - senderName: Guid.NewGuid().ToString()); + propertyName: "a", + previousValue: "b", + newValue: "c", + location: "d", + message: "Property reassignment: $(a)=\"c\" (previous value: \"b\") at d", + helpKeyword: "e", + senderName: "f"); Roundtrip(args, e => e.PropertyName, diff --git a/src/Build/BackEnd/Components/Logging/ILoggingService.cs b/src/Build/BackEnd/Components/Logging/ILoggingService.cs index ef3db37b022..7d489ca8b21 100644 --- a/src/Build/BackEnd/Components/Logging/ILoggingService.cs +++ b/src/Build/BackEnd/Components/Logging/ILoggingService.cs @@ -297,6 +297,18 @@ bool IncludeTaskInputs /// Importance level of the message /// message to log void LogCommentFromText(BuildEventContext buildEventContext, MessageImportance importance, string message); + + /// + /// Log a comment from a format string and arguments + /// + /// Event context information which describes who is logging the event + /// How important is the message, this will determine which verbosities the message will show up on. + /// The higher the importance the lower the verbosity needs to be for the message to be seen + /// Message to log + /// Message formatting arguments + /// BuildEventContext is null + /// Message is null + void LogCommentFromText(BuildEventContext buildEventContext, MessageImportance importance, string message, params object[] messageArgs); #endregion #region Log events diff --git a/src/Build/BackEnd/Components/Logging/LoggingContext.cs b/src/Build/BackEnd/Components/Logging/LoggingContext.cs index f32379d29c4..6194726d5f4 100644 --- a/src/Build/BackEnd/Components/Logging/LoggingContext.cs +++ b/src/Build/BackEnd/Components/Logging/LoggingContext.cs @@ -134,6 +134,18 @@ internal void LogCommentFromText(MessageImportance importance, string message) _loggingService.LogCommentFromText(_eventContext, importance, message); } + /// + /// Helper method to create a message build event from a string + /// + /// Importance level of the message + /// Message to log + /// Format string arguments + internal void LogCommentFromText(MessageImportance importance, string message, params object[] messageArgs) + { + ErrorUtilities.VerifyThrow(_isValid, "must be valid"); + _loggingService.LogCommentFromText(_eventContext, importance, message, messageArgs); + } + /// /// Log an error /// diff --git a/src/Build/BackEnd/Components/Logging/LoggingServiceLogMethods.cs b/src/Build/BackEnd/Components/Logging/LoggingServiceLogMethods.cs index 6dcf39925d2..8556802ed0a 100644 --- a/src/Build/BackEnd/Components/Logging/LoggingServiceLogMethods.cs +++ b/src/Build/BackEnd/Components/Logging/LoggingServiceLogMethods.cs @@ -56,7 +56,7 @@ public void LogCommentFromText(BuildEventContext buildEventContext, MessageImpor { lock (_lockObject) { - this.LogCommentFromText(buildEventContext, importance, message, null); + this.LogCommentFromText(buildEventContext, importance, message, messageArgs: null); } } @@ -82,8 +82,8 @@ public void LogCommentFromText(BuildEventContext buildEventContext, MessageImpor BuildMessageEventArgs buildEvent = new BuildMessageEventArgs ( message, - null, - "MSBuild", + helpKeyword: null, + senderName: "MSBuild", importance, DateTime.UtcNow, messageArgs @@ -577,21 +577,6 @@ public BuildEventContext LogProjectStarted(BuildEventContext nodeBuildEventConte ErrorUtilities.VerifyThrow(parentBuildEventContext != null, "Need a parentBuildEventContext"); - string message = string.Empty; - string projectFilePath = Path.GetFileName(projectFile); - - // Check to see if the there are any specific target names to be built. - // If targetNames is null or empty then we will be building with the - // default targets. - if (!String.IsNullOrEmpty(targetNames)) - { - message = ResourceUtilities.FormatResourceStringIgnoreCodeAndKeyword("ProjectStartedPrefixForTopLevelProjectWithTargetNames", projectFilePath, targetNames); - } - else - { - message = ResourceUtilities.FormatResourceStringIgnoreCodeAndKeyword("ProjectStartedPrefixForTopLevelProjectWithDefaultTargets", projectFilePath); - } - ErrorUtilities.VerifyThrow(_configCache.Value.HasConfiguration(projectInstanceId), "Cannot find the project configuration while injecting non-serialized data from out-of-proc node."); var buildRequestConfiguration = _configCache.Value[projectInstanceId]; @@ -604,7 +589,7 @@ public BuildEventContext LogProjectStarted(BuildEventContext nodeBuildEventConte var buildEvent = new ProjectStartedEventArgs ( projectInstanceId, - message, + message: null, helpKeyword: null, projectFile, targetNames, @@ -635,12 +620,10 @@ public void LogProjectFinished(BuildEventContext projectBuildEventContext, strin { ErrorUtilities.VerifyThrow(projectBuildEventContext != null, "projectBuildEventContext"); - string message = ResourceUtilities.FormatResourceStringIgnoreCodeAndKeyword(success ? "ProjectFinishedSuccess" : "ProjectFinishedFailure", Path.GetFileName(projectFile)); - ProjectFinishedEventArgs buildEvent = new ProjectFinishedEventArgs ( - message, - null, // no help keyword + message: null, + helpKeyword: null, projectFile, success ); @@ -681,36 +664,12 @@ public BuildEventContext LogTargetStarted(BuildEventContext projectBuildEventCon BuildEventContext.InvalidTaskId ); - string message = String.Empty; if (!OnlyLogCriticalEvents) { - if (String.Equals(projectFile, projectFileOfTargetElement, StringComparison.OrdinalIgnoreCase)) - { - if (!String.IsNullOrEmpty(parentTargetName)) - { - message = ResourceUtilities.FormatResourceStringIgnoreCodeAndKeyword("TargetStartedProjectDepends", targetName, projectFile, parentTargetName); - } - else - { - message = ResourceUtilities.FormatResourceStringIgnoreCodeAndKeyword("TargetStartedProjectEntry", targetName, projectFile); - } - } - else - { - if (!String.IsNullOrEmpty(parentTargetName)) - { - message = ResourceUtilities.FormatResourceStringIgnoreCodeAndKeyword("TargetStartedFileProjectDepends", targetName, projectFileOfTargetElement, projectFile, parentTargetName); - } - else - { - message = ResourceUtilities.FormatResourceStringIgnoreCodeAndKeyword("TargetStartedFileProjectEntry", targetName, projectFileOfTargetElement, projectFile); - } - } - TargetStartedEventArgs buildEvent = new TargetStartedEventArgs ( - message, - null, // no help keyword + message: null, + helpKeyword: null, targetName, projectFile, projectFileOfTargetElement, @@ -744,12 +703,10 @@ public void LogTargetFinished(BuildEventContext targetBuildEventContext, string { ErrorUtilities.VerifyThrow(targetBuildEventContext != null, "targetBuildEventContext is null"); - string message = ResourceUtilities.FormatResourceStringIgnoreCodeAndKeyword(success ? "TargetFinishedSuccess" : "TargetFinishedFailure", targetName, Path.GetFileName(projectFile)); - TargetFinishedEventArgs buildEvent = new TargetFinishedEventArgs ( - message, - null, // no help keyword + message: null, + helpKeyword: null, targetName, projectFile, projectFileOfTargetElement, @@ -780,8 +737,8 @@ public void LogTaskStarted(BuildEventContext taskBuildEventContext, string taskN { TaskStartedEventArgs buildEvent = new TaskStartedEventArgs ( - ResourceUtilities.FormatResourceStringIgnoreCodeAndKeyword("TaskStarted", taskName), - null, // no help keyword + message: null, + helpKeyword: null, projectFile, projectFileOfTaskNode, taskName @@ -820,8 +777,8 @@ public BuildEventContext LogTaskStarted2(BuildEventContext targetBuildEventConte { TaskStartedEventArgs buildEvent = new TaskStartedEventArgs ( - ResourceUtilities.FormatResourceStringIgnoreCodeAndKeyword("TaskStarted", taskName), - null, // no help keyword + message: null, + helpKeyword: null, projectFile, projectFileOfTaskNode, taskName @@ -850,12 +807,11 @@ public void LogTaskFinished(BuildEventContext taskBuildEventContext, string task if (!OnlyLogCriticalEvents) { ErrorUtilities.VerifyThrow(taskBuildEventContext != null, "taskBuildEventContext is null"); - string message = ResourceUtilities.FormatResourceStringIgnoreCodeAndKeyword(success ? "TaskFinishedSuccess" : "TaskFinishedFailure", taskName); TaskFinishedEventArgs buildEvent = new TaskFinishedEventArgs ( - message, - null, // no help keyword + message: null, + helpKeyword: null, projectFile, projectFileOfTaskNode, taskName, diff --git a/src/Build/BackEnd/Components/RequestBuilder/IntrinsicTasks/ItemGroupLoggingHelper.cs b/src/Build/BackEnd/Components/RequestBuilder/IntrinsicTasks/ItemGroupLoggingHelper.cs index 2b8d80d306c..7aee58f9c17 100644 --- a/src/Build/BackEnd/Components/RequestBuilder/IntrinsicTasks/ItemGroupLoggingHelper.cs +++ b/src/Build/BackEnd/Components/RequestBuilder/IntrinsicTasks/ItemGroupLoggingHelper.cs @@ -32,6 +32,8 @@ internal static class ItemGroupLoggingHelper internal static string ItemGroupRemoveLogMessage = ResourceUtilities.GetResourceString("ItemGroupRemoveLogMessage"); internal static string OutputItemParameterMessagePrefix = ResourceUtilities.GetResourceString("OutputItemParameterMessagePrefix"); internal static string TaskParameterPrefix = ResourceUtilities.GetResourceString("TaskParameterPrefix"); + internal static string SkipTargetUpToDateInputs = ResourceUtilities.FormatResourceStringIgnoreCodeAndKeyword("SkipTargetUpToDateInputs", string.Empty); + internal static string SkipTargetUpToDateOutputs = ResourceUtilities.FormatResourceStringIgnoreCodeAndKeyword("SkipTargetUpToDateOutputs", string.Empty); /// /// by itself doesn't have the implementation @@ -40,6 +42,7 @@ internal static class ItemGroupLoggingHelper /// static ItemGroupLoggingHelper() { + BuildEventArgs.ResourceStringFormatter = ResourceUtilities.FormatResourceStringIgnoreCodeAndKeyword; TaskParameterEventArgs.MessageGetter = GetTaskParameterText; TaskParameterEventArgs.DictionaryFactory = ArrayDictionary.Create; } @@ -71,17 +74,43 @@ internal static string GetParameterText(string prefix, string parameterName, ILi // If it's just one entry in the list, and it's not a task item with metadata, keep it on one line like a scalar bool specialTreatmentForSingle = (parameterValue.Count == 1 && !firstEntryIsTaskItemWithSomeCustomMetadata); - if (!specialTreatmentForSingle) + // If the parameterName is not specified, no need to have an extra indent. + // Without parameterName: + // + // Input files: + // a.txt + // b.txt + // + // With parameterName: + // + // Input files: + // ParamName= + // a.txt + // b.txt + string indent = " "; + if (parameterName == null) { - sb.Append("\n "); + indent = " "; } - sb.Append(parameterName); - sb.Append('='); - if (!specialTreatmentForSingle) { sb.Append("\n"); + if (parameterName != null) + { + sb.Append(" "); + } + } + + if (parameterName != null) + { + sb.Append(parameterName); + sb.Append('='); + + if (!specialTreatmentForSingle) + { + sb.Append("\n"); + } } bool truncateTaskInputs = Traits.Instance.EscapeHatches.TruncateTaskInputs; @@ -95,7 +124,7 @@ internal static string GetParameterText(string prefix, string parameterName, ILi if (!specialTreatmentForSingle) { - sb.Append(" "); + sb.Append(indent); } AppendStringFromParameterValue(sb, parameterValue[i], logItemMetadata); @@ -263,6 +292,8 @@ internal static string GetTaskParameterText(TaskParameterMessageKind messageKind TaskParameterMessageKind.RemoveItem => ItemGroupRemoveLogMessage, TaskParameterMessageKind.TaskInput => TaskParameterPrefix, TaskParameterMessageKind.TaskOutput => OutputItemParameterMessagePrefix, + TaskParameterMessageKind.SkippedTargetInputs => SkipTargetUpToDateInputs, + TaskParameterMessageKind.SkippedTargetOutputs => SkipTargetUpToDateOutputs, _ => throw new NotImplementedException($"Unsupported {nameof(TaskParameterMessageKind)} value: {messageKind}") }; diff --git a/src/Build/BackEnd/Components/RequestBuilder/TargetBuilder.cs b/src/Build/BackEnd/Components/RequestBuilder/TargetBuilder.cs index 79142963436..21bdf35cb01 100644 --- a/src/Build/BackEnd/Components/RequestBuilder/TargetBuilder.cs +++ b/src/Build/BackEnd/Components/RequestBuilder/TargetBuilder.cs @@ -555,17 +555,14 @@ 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. - var skippedTargetEventArgs = new TargetSkippedEventArgs( - ResourceUtilities.GetResourceString(targetResult.ResultCode == TargetResultCode.Success - ? "TargetAlreadyCompleteSuccess" - : "TargetAlreadyCompleteFailure"), - currentTargetEntry.Name) + var skippedTargetEventArgs = new TargetSkippedEventArgs(message: null) { BuildEventContext = _projectLoggingContext.BuildEventContext, TargetName = currentTargetEntry.Name, TargetFile = currentTargetEntry.Target.Location.File, ParentTarget = currentTargetEntry.ParentEntry?.Target.Name, - BuildReason = currentTargetEntry.BuildReason + BuildReason = currentTargetEntry.BuildReason, + OriginallySucceeded = targetResult.ResultCode == TargetResultCode.Success }; _projectLoggingContext.LogBuildEvent(skippedTargetEventArgs); diff --git a/src/Build/BackEnd/Components/RequestBuilder/TargetEntry.cs b/src/Build/BackEnd/Components/RequestBuilder/TargetEntry.cs index e63167fef65..f7543d5d91d 100644 --- a/src/Build/BackEnd/Components/RequestBuilder/TargetEntry.cs +++ b/src/Build/BackEnd/Components/RequestBuilder/TargetEntry.cs @@ -368,17 +368,15 @@ internal List GetDependencies(ProjectLoggingContext project // target. In the Task builder (and original Task Engine), a Task Skipped message would be logged in // the context of the target, not the task. This should be the same, especially given that we // wish to allow batching on the condition of a target. - var skippedTargetEventArgs = new TargetSkippedEventArgs( - ResourceUtilities.GetResourceString("TargetSkippedFalseCondition"), - _target.Name, - _target.Condition, - expanded) + var skippedTargetEventArgs = new TargetSkippedEventArgs(message: null) { BuildEventContext = projectLoggingContext.BuildEventContext, TargetName = _target.Name, TargetFile = _target.Location.File, ParentTarget = ParentEntry?.Target?.Name, - BuildReason = BuildReason + BuildReason = BuildReason, + Condition = _target.Condition, + EvaluatedCondition = expanded }; projectLoggingContext.LogBuildEvent(skippedTargetEventArgs); diff --git a/src/Build/Logging/BinaryLogger/BinaryLogger.cs b/src/Build/Logging/BinaryLogger/BinaryLogger.cs index c9515e817f5..72ae2c75ac2 100644 --- a/src/Build/Logging/BinaryLogger/BinaryLogger.cs +++ b/src/Build/Logging/BinaryLogger/BinaryLogger.cs @@ -45,7 +45,10 @@ public sealed class BinaryLogger : ILogger // - new record kind: TaskParameterEventArgs // version 12: // - add GlobalProperties, Properties and Items on ProjectEvaluationFinished - internal const int FileFormatVersion = 12; + // version 13: + // - don't log Message where it can be recovered + // - log arguments for LazyFormattedBuildEventArgs + internal const int FileFormatVersion = 13; private Stream stream; private BinaryWriter binaryWriter; diff --git a/src/Build/Logging/BinaryLogger/BuildEventArgsFieldFlags.cs b/src/Build/Logging/BinaryLogger/BuildEventArgsFieldFlags.cs index b17ecc2b62a..dbaec774e03 100644 --- a/src/Build/Logging/BinaryLogger/BuildEventArgsFieldFlags.cs +++ b/src/Build/Logging/BinaryLogger/BuildEventArgsFieldFlags.cs @@ -22,6 +22,8 @@ internal enum BuildEventArgsFieldFlags LineNumber = 1 << 10, ColumnNumber = 1 << 11, EndLineNumber = 1 << 12, - EndColumnNumber = 1 << 13 + EndColumnNumber = 1 << 13, + Arguments = 1 << 14, + Importance = 1 << 15 } } diff --git a/src/Build/Logging/BinaryLogger/BuildEventArgsFields.cs b/src/Build/Logging/BinaryLogger/BuildEventArgsFields.cs index ab65f79438e..be6bfe622a5 100644 --- a/src/Build/Logging/BinaryLogger/BuildEventArgsFields.cs +++ b/src/Build/Logging/BinaryLogger/BuildEventArgsFields.cs @@ -11,11 +11,13 @@ internal class BuildEventArgsFields public BuildEventArgsFieldFlags Flags { get; set; } public string Message { get; set; } + public object[] Arguments { get; set; } public BuildEventContext BuildEventContext { get; set; } public int ThreadId { get; set; } public string HelpKeyword { get; set; } public string SenderName { get; set; } public DateTime Timestamp { get; set; } + public MessageImportance Importance { get; set; } = MessageImportance.Low; public string Subcategory { get; set; } public string Code { get; set; } diff --git a/src/Build/Logging/BinaryLogger/BuildEventArgsReader.cs b/src/Build/Logging/BinaryLogger/BuildEventArgsReader.cs index d6675d9eb7b..748f520aca4 100644 --- a/src/Build/Logging/BinaryLogger/BuildEventArgsReader.cs +++ b/src/Build/Logging/BinaryLogger/BuildEventArgsReader.cs @@ -257,9 +257,7 @@ private void ReadStringRecord() private BuildEventArgs ReadProjectImportedEventArgs() { - var fields = ReadBuildEventArgsFields(); - // Read unused Importance, it defaults to Low - ReadInt32(); + var fields = ReadBuildEventArgsFields(readImportance: true); bool importIgnored = false; @@ -275,7 +273,8 @@ private BuildEventArgs ReadProjectImportedEventArgs() var e = new ProjectImportedEventArgs( fields.LineNumber, fields.ColumnNumber, - fields.Message); + fields.Message, + fields.Arguments); SetCommonFields(e, fields); @@ -289,16 +288,27 @@ private BuildEventArgs ReadProjectImportedEventArgs() private BuildEventArgs ReadTargetSkippedEventArgs() { - var fields = ReadBuildEventArgsFields(); - // Read unused Importance, it defaults to Low - ReadInt32(); + var fields = ReadBuildEventArgsFields(readImportance: true); + var targetFile = ReadOptionalString(); var targetName = ReadOptionalString(); var parentTarget = ReadOptionalString(); + + string condition = null; + string evaluatedCondition = null; + bool originallySucceeded = false; + if (fileFormatVersion >= 13) + { + condition = ReadOptionalString(); + evaluatedCondition = ReadOptionalString(); + originallySucceeded = ReadBoolean(); + } + var buildReason = (TargetBuiltReason)ReadInt32(); var e = new TargetSkippedEventArgs( - fields.Message); + fields.Message, + fields.Arguments); SetCommonFields(e, fields); @@ -307,6 +317,9 @@ private BuildEventArgs ReadTargetSkippedEventArgs() e.TargetName = targetName; e.ParentTarget = parentTarget; e.BuildReason = buildReason; + e.Condition = condition; + e.EvaluatedCondition = evaluatedCondition; + e.OriginallySucceeded = originallySucceeded; return e; } @@ -562,7 +575,8 @@ private BuildEventArgs ReadBuildErrorEventArgs() fields.Message, fields.HelpKeyword, fields.SenderName, - fields.Timestamp); + fields.Timestamp, + fields.Arguments); e.BuildEventContext = fields.BuildEventContext; e.ProjectFile = fields.ProjectFile; return e; @@ -584,7 +598,8 @@ private BuildEventArgs ReadBuildWarningEventArgs() fields.Message, fields.HelpKeyword, fields.SenderName, - fields.Timestamp); + fields.Timestamp, + fields.Arguments); e.BuildEventContext = fields.BuildEventContext; e.ProjectFile = fields.ProjectFile; return e; @@ -592,8 +607,7 @@ private BuildEventArgs ReadBuildWarningEventArgs() private BuildEventArgs ReadBuildMessageEventArgs() { - var fields = ReadBuildEventArgsFields(); - var importance = (MessageImportance)ReadInt32(); + var fields = ReadBuildEventArgsFields(readImportance: true); var e = new BuildMessageEventArgs( fields.Subcategory, @@ -606,8 +620,9 @@ private BuildEventArgs ReadBuildMessageEventArgs() fields.Message, fields.HelpKeyword, fields.SenderName, - importance, - fields.Timestamp); + fields.Importance, + fields.Timestamp, + fields.Arguments); e.BuildEventContext = fields.BuildEventContext; e.ProjectFile = fields.ProjectFile; return e; @@ -615,15 +630,14 @@ private BuildEventArgs ReadBuildMessageEventArgs() private BuildEventArgs ReadTaskCommandLineEventArgs() { - var fields = ReadBuildEventArgsFields(); - var importance = (MessageImportance)ReadInt32(); + var fields = ReadBuildEventArgsFields(readImportance: true); var commandLine = ReadOptionalString(); var taskName = ReadOptionalString(); var e = new TaskCommandLineEventArgs( commandLine, taskName, - importance, + fields.Importance, fields.Timestamp); e.BuildEventContext = fields.BuildEventContext; e.ProjectFile = fields.ProjectFile; @@ -632,9 +646,7 @@ private BuildEventArgs ReadTaskCommandLineEventArgs() private BuildEventArgs ReadTaskParameterEventArgs() { - var fields = ReadBuildEventArgsFields(); - // Read unused Importance, it defaults to Low - ReadInt32(); + var fields = ReadBuildEventArgsFields(readImportance: true); var kind = (TaskParameterMessageKind)ReadInt32(); var itemType = ReadDeduplicatedString(); @@ -653,8 +665,7 @@ private BuildEventArgs ReadTaskParameterEventArgs() private BuildEventArgs ReadCriticalBuildMessageEventArgs() { - var fields = ReadBuildEventArgsFields(); - var importance = (MessageImportance)ReadInt32(); + var fields = ReadBuildEventArgsFields(readImportance: true); var e = new CriticalBuildMessageEventArgs( fields.Subcategory, @@ -667,7 +678,8 @@ private BuildEventArgs ReadCriticalBuildMessageEventArgs() fields.Message, fields.HelpKeyword, fields.SenderName, - fields.Timestamp); + fields.Timestamp, + fields.Arguments); e.BuildEventContext = fields.BuildEventContext; e.ProjectFile = fields.ProjectFile; return e; @@ -675,8 +687,7 @@ private BuildEventArgs ReadCriticalBuildMessageEventArgs() private BuildEventArgs ReadEnvironmentVariableReadEventArgs() { - var fields = ReadBuildEventArgsFields(); - var importance = (MessageImportance)ReadInt32(); + var fields = ReadBuildEventArgsFields(readImportance: true); var environmentVariableName = ReadDeduplicatedString(); @@ -685,7 +696,7 @@ private BuildEventArgs ReadEnvironmentVariableReadEventArgs() fields.Message, fields.HelpKeyword, fields.SenderName, - importance); + fields.Importance); SetCommonFields(e, fields); return e; @@ -693,8 +704,8 @@ private BuildEventArgs ReadEnvironmentVariableReadEventArgs() private BuildEventArgs ReadPropertyReassignmentEventArgs() { - var fields = ReadBuildEventArgsFields(); - var importance = (MessageImportance)ReadInt32(); + var fields = ReadBuildEventArgsFields(readImportance: true); + string propertyName = ReadDeduplicatedString(); string previousValue = ReadDeduplicatedString(); string newValue = ReadDeduplicatedString(); @@ -708,7 +719,7 @@ private BuildEventArgs ReadPropertyReassignmentEventArgs() fields.Message, fields.HelpKeyword, fields.SenderName, - importance); + fields.Importance); SetCommonFields(e, fields); return e; @@ -716,8 +727,7 @@ private BuildEventArgs ReadPropertyReassignmentEventArgs() private BuildEventArgs ReadUninitializedPropertyReadEventArgs() { - var fields = ReadBuildEventArgsFields(); - var importance = (MessageImportance)ReadInt32(); + var fields = ReadBuildEventArgsFields(readImportance: true); string propertyName = ReadDeduplicatedString(); var e = new UninitializedPropertyReadEventArgs( @@ -725,7 +735,7 @@ private BuildEventArgs ReadUninitializedPropertyReadEventArgs() fields.Message, fields.HelpKeyword, fields.SenderName, - importance); + fields.Importance); SetCommonFields(e, fields); return e; @@ -733,8 +743,8 @@ private BuildEventArgs ReadUninitializedPropertyReadEventArgs() private BuildEventArgs ReadPropertyInitialValueSetEventArgs() { - var fields = ReadBuildEventArgsFields(); - var importance = (MessageImportance)ReadInt32(); + var fields = ReadBuildEventArgsFields(readImportance: true); + string propertyName = ReadDeduplicatedString(); string propertyValue = ReadDeduplicatedString(); string propertySource = ReadDeduplicatedString(); @@ -746,7 +756,7 @@ private BuildEventArgs ReadPropertyInitialValueSetEventArgs() fields.Message, fields.HelpKeyword, fields.SenderName, - importance); + fields.Importance); SetCommonFields(e, fields); return e; @@ -770,7 +780,7 @@ private void ReadDiagnosticFields(BuildEventArgsFields fields) fields.EndColumnNumber = ReadInt32(); } - private BuildEventArgsFields ReadBuildEventArgsFields() + private BuildEventArgsFields ReadBuildEventArgsFields(bool readImportance = false) { BuildEventArgsFieldFlags flags = (BuildEventArgsFieldFlags)ReadInt32(); var result = new BuildEventArgsFields(); @@ -846,6 +856,23 @@ private BuildEventArgsFields ReadBuildEventArgsFields() result.EndColumnNumber = ReadInt32(); } + if ((flags & BuildEventArgsFieldFlags.Arguments) != 0) + { + int count = ReadInt32(); + object[] arguments = new object[count]; + for (int i = 0; i < count; i++) + { + arguments[i] = ReadDeduplicatedString(); + } + + result.Arguments = arguments; + } + + if ((fileFormatVersion < 13 && readImportance) || (fileFormatVersion >= 13 && (flags & BuildEventArgsFieldFlags.Importance) != 0)) + { + result.Importance = (MessageImportance)ReadInt32(); + } + return result; } @@ -1007,6 +1034,11 @@ private IEnumerable ReadProjectItems() } } } + + if (list.Count == 0) + { + list = null; + } } else { diff --git a/src/Build/Logging/BinaryLogger/BuildEventArgsWriter.cs b/src/Build/Logging/BinaryLogger/BuildEventArgsWriter.cs index 5774a80a27f..316fe33ebd6 100644 --- a/src/Build/Logging/BinaryLogger/BuildEventArgsWriter.cs +++ b/src/Build/Logging/BinaryLogger/BuildEventArgsWriter.cs @@ -5,6 +5,7 @@ using System.Collections; using System.Collections.Generic; using System.Diagnostics; +using System.Globalization; using System.IO; using System.Linq; using Microsoft.Build.BackEnd.Logging; @@ -134,6 +135,42 @@ public void Write(BuildEventArgs e) currentRecordStream.SetLength(0); } +/* +Base types and inheritance ("EventArgs" suffix omitted): + +Build + Telemetry + LazyFormattedBuild + BuildMessage + CriticalBuildMessage + EnvironmentVariableRead + MetaprojectGenerated + ProjectImported + PropertyInitialValueSet + PropertyReassignment + TargetSkipped + TaskCommandLine + TaskParameter + UninitializedPropertyRead + BuildStatus + TaskStarted + TaskFinished + TargetStarted + TargetFinished + ProjectStarted + ProjectFinished + BuildStarted + BuildFinished + ProjectEvaluationStarted + ProjectEvaluationFinished + BuildError + BuildWarning + CustomBuild + ExternalProjectStarted + ExternalProjectFinished + +*/ + private void WriteCore(BuildEventArgs e) { switch (e) @@ -262,7 +299,7 @@ private void Write(ProjectEvaluationFinishedEventArgs e) private void Write(ProjectStartedEventArgs e) { Write(BinaryLogRecordKind.ProjectStarted); - WriteBuildEventArgsFields(e); + WriteBuildEventArgsFields(e, writeMessage: false); if (e.ParentProjectBuildEventContext == null) { @@ -298,7 +335,7 @@ private void Write(ProjectStartedEventArgs e) private void Write(ProjectFinishedEventArgs e) { Write(BinaryLogRecordKind.ProjectFinished); - WriteBuildEventArgsFields(e); + WriteBuildEventArgsFields(e, writeMessage: false); WriteDeduplicatedString(e.ProjectFile); Write(e.Succeeded); } @@ -306,7 +343,7 @@ private void Write(ProjectFinishedEventArgs e) private void Write(TargetStartedEventArgs e) { Write(BinaryLogRecordKind.TargetStarted); - WriteBuildEventArgsFields(e); + WriteBuildEventArgsFields(e, writeMessage: false); WriteDeduplicatedString(e.TargetName); WriteDeduplicatedString(e.ProjectFile); WriteDeduplicatedString(e.TargetFile); @@ -317,7 +354,7 @@ private void Write(TargetStartedEventArgs e) private void Write(TargetFinishedEventArgs e) { Write(BinaryLogRecordKind.TargetFinished); - WriteBuildEventArgsFields(e); + WriteBuildEventArgsFields(e, writeMessage: false); Write(e.Succeeded); WriteDeduplicatedString(e.ProjectFile); WriteDeduplicatedString(e.TargetFile); @@ -328,7 +365,7 @@ private void Write(TargetFinishedEventArgs e) private void Write(TaskStartedEventArgs e) { Write(BinaryLogRecordKind.TaskStarted); - WriteBuildEventArgsFields(e); + WriteBuildEventArgsFields(e, writeMessage: false); WriteDeduplicatedString(e.TaskName); WriteDeduplicatedString(e.ProjectFile); WriteDeduplicatedString(e.TaskFile); @@ -337,7 +374,7 @@ private void Write(TaskStartedEventArgs e) private void Write(TaskFinishedEventArgs e) { Write(BinaryLogRecordKind.TaskFinished); - WriteBuildEventArgsFields(e); + WriteBuildEventArgsFields(e, writeMessage: false); Write(e.Succeeded); WriteDeduplicatedString(e.TaskName); WriteDeduplicatedString(e.ProjectFile); @@ -374,62 +411,22 @@ private void Write(BuildWarningEventArgs e) private void Write(BuildMessageEventArgs e) { - if (e is TaskParameterEventArgs taskParameter) - { - Write(taskParameter); - return; - } - - if (e is CriticalBuildMessageEventArgs criticalBuildMessage) - { - Write(criticalBuildMessage); - return; - } - - if (e is TaskCommandLineEventArgs taskCommandLine) - { - Write(taskCommandLine); - return; - } - - if (e is ProjectImportedEventArgs projectImported) - { - Write(projectImported); - return; - } - - if (e is TargetSkippedEventArgs targetSkipped) - { - Write(targetSkipped); - return; - } - - if (e is PropertyReassignmentEventArgs propertyReassignment) - { - Write(propertyReassignment); - return; - } - - if (e is UninitializedPropertyReadEventArgs uninitializedPropertyRead) - { - Write(uninitializedPropertyRead); - return; - } - - if (e is EnvironmentVariableReadEventArgs environmentVariableRead) - { - Write(environmentVariableRead); - return; - } - - if (e is PropertyInitialValueSetEventArgs propertyInitialValueSet) + switch (e) { - Write(propertyInitialValueSet); - return; + case TaskParameterEventArgs taskParameter: Write(taskParameter); break; + case ProjectImportedEventArgs projectImported: Write(projectImported); break; + case TargetSkippedEventArgs targetSkipped: Write(targetSkipped); break; + case PropertyReassignmentEventArgs propertyReassignment: Write(propertyReassignment); break; + case TaskCommandLineEventArgs taskCommandLine: Write(taskCommandLine); break; + case UninitializedPropertyReadEventArgs uninitializedPropertyRead: Write(uninitializedPropertyRead); break; + case EnvironmentVariableReadEventArgs environmentVariableRead: Write(environmentVariableRead); break; + case PropertyInitialValueSetEventArgs propertyInitialValueSet: Write(propertyInitialValueSet); break; + case CriticalBuildMessageEventArgs criticalBuildMessage: Write(criticalBuildMessage); break; + default: // actual BuildMessageEventArgs + Write(BinaryLogRecordKind.Message); + WriteMessageFields(e, writeImportance: true); + break; } - - Write(BinaryLogRecordKind.Message); - WriteMessageFields(e); } private void Write(ProjectImportedEventArgs e) @@ -444,10 +441,13 @@ private void Write(ProjectImportedEventArgs e) private void Write(TargetSkippedEventArgs e) { Write(BinaryLogRecordKind.TargetSkipped); - WriteMessageFields(e); + WriteMessageFields(e, writeMessage: false); WriteDeduplicatedString(e.TargetFile); WriteDeduplicatedString(e.TargetName); WriteDeduplicatedString(e.ParentTarget); + WriteDeduplicatedString(e.Condition); + WriteDeduplicatedString(e.EvaluatedCondition); + Write(e.OriginallySucceeded); Write((int)e.BuildReason); } @@ -460,7 +460,7 @@ private void Write(CriticalBuildMessageEventArgs e) private void Write(PropertyReassignmentEventArgs e) { Write(BinaryLogRecordKind.PropertyReassignment); - WriteMessageFields(e); + WriteMessageFields(e, writeMessage: false, writeImportance: true); WriteDeduplicatedString(e.PropertyName); WriteDeduplicatedString(e.PreviousValue); WriteDeduplicatedString(e.NewValue); @@ -470,14 +470,14 @@ private void Write(PropertyReassignmentEventArgs e) private void Write(UninitializedPropertyReadEventArgs e) { Write(BinaryLogRecordKind.UninitializedPropertyRead); - WriteMessageFields(e); + WriteMessageFields(e, writeImportance: true); WriteDeduplicatedString(e.PropertyName); } private void Write(PropertyInitialValueSetEventArgs e) { Write(BinaryLogRecordKind.PropertyInitialValueSet); - WriteMessageFields(e); + WriteMessageFields(e, writeImportance: true); WriteDeduplicatedString(e.PropertyName); WriteDeduplicatedString(e.PropertyValue); WriteDeduplicatedString(e.PropertySource); @@ -486,14 +486,14 @@ private void Write(PropertyInitialValueSetEventArgs e) private void Write(EnvironmentVariableReadEventArgs e) { Write(BinaryLogRecordKind.EnvironmentVariableRead); - WriteMessageFields(e); + WriteMessageFields(e, writeImportance: true); WriteDeduplicatedString(e.EnvironmentVariableName); } private void Write(TaskCommandLineEventArgs e) { Write(BinaryLogRecordKind.TaskCommandLine); - WriteMessageFields(e); + WriteMessageFields(e, writeMessage: false, writeImportance: true); WriteDeduplicatedString(e.CommandLine); WriteDeduplicatedString(e.TaskName); } @@ -518,7 +518,7 @@ private void WriteBaseFields(BuildEventArgs e, BuildEventArgsFieldFlags flags) { if ((flags & BuildEventArgsFieldFlags.Message) != 0) { - WriteDeduplicatedString(e.Message); + WriteDeduplicatedString(e.RawMessage); } if ((flags & BuildEventArgsFieldFlags.BuildEventContext) != 0) @@ -547,10 +547,10 @@ private void WriteBaseFields(BuildEventArgs e, BuildEventArgsFieldFlags flags) } } - private void WriteMessageFields(BuildMessageEventArgs e, bool writeMessage = true) + private void WriteMessageFields(BuildMessageEventArgs e, bool writeMessage = true, bool writeImportance = false) { var flags = GetBuildEventArgsFieldFlags(e, writeMessage); - flags = GetMessageFlags(e, flags); + flags = GetMessageFlags(e, flags, writeMessage, writeImportance); Write((int)flags); @@ -596,10 +596,23 @@ private void WriteMessageFields(BuildMessageEventArgs e, bool writeMessage = tru Write(e.EndColumnNumber); } - Write((int)e.Importance); + if ((flags & BuildEventArgsFieldFlags.Arguments) != 0) + { + Write(e.RawArguments.Length); + for (int i = 0; i < e.RawArguments.Length; i++) + { + string argument = Convert.ToString(e.RawArguments[i], CultureInfo.CurrentCulture); + WriteDeduplicatedString(argument); + } + } + + if ((flags & BuildEventArgsFieldFlags.Importance) != 0) + { + Write((int)e.Importance); + } } - private static BuildEventArgsFieldFlags GetMessageFlags(BuildMessageEventArgs e, BuildEventArgsFieldFlags flags) + private static BuildEventArgsFieldFlags GetMessageFlags(BuildMessageEventArgs e, BuildEventArgsFieldFlags flags, bool writeMessage = true, bool writeImportance = false) { if (e.Subcategory != null) { @@ -641,6 +654,16 @@ private static BuildEventArgsFieldFlags GetMessageFlags(BuildMessageEventArgs e, flags |= BuildEventArgsFieldFlags.EndColumnNumber; } + if (writeMessage && e.RawArguments != null && e.RawArguments.Length > 0) + { + flags |= BuildEventArgsFieldFlags.Arguments; + } + + if (writeImportance && e.Importance != MessageImportance.Low) + { + flags |= BuildEventArgsFieldFlags.Importance; + } + return flags; } @@ -668,10 +691,11 @@ private static BuildEventArgsFieldFlags GetBuildEventArgsFieldFlags(BuildEventAr flags |= BuildEventArgsFieldFlags.SenderName; } - if (e.ThreadId > 0) - { - flags |= BuildEventArgsFieldFlags.ThreadId; - } + // ThreadId never seems to be used or useful for anything. + //if (e.ThreadId > 0) + //{ + // flags |= BuildEventArgsFieldFlags.ThreadId; + //} if (e.Timestamp != default(DateTime)) { @@ -841,10 +865,12 @@ private void Write(ITaskItem item, bool writeMetadata = true) nameValueListBuffer.Add(kvp); } - if (nameValueListBuffer.Count > 1) - { - nameValueListBuffer.Sort((l, r) => StringComparer.OrdinalIgnoreCase.Compare(l.Key, r.Key)); - } + // Don't sort metadata because we want the binary log to be fully roundtrippable + // and we need to preserve the original order. + //if (nameValueListBuffer.Count > 1) + //{ + // nameValueListBuffer.Sort((l, r) => StringComparer.OrdinalIgnoreCase.Compare(l.Key, r.Key)); + //} WriteNameValueList(); diff --git a/src/Framework/BuildEventArgs.cs b/src/Framework/BuildEventArgs.cs index 06e71865122..3f70c7d9e2f 100644 --- a/src/Framework/BuildEventArgs.cs +++ b/src/Framework/BuildEventArgs.cs @@ -2,8 +2,10 @@ // Licensed under the MIT license. See LICENSE file in the project root for full license information. using System; +using System.Globalization; using System.Runtime.Serialization; using System.IO; +using System.Text; using Microsoft.Build.Shared; namespace Microsoft.Build.Framework @@ -128,7 +130,7 @@ protected internal DateTime RawTimestamp public int ThreadId => threadId; /// - /// Text of event. + /// Text of event. /// public virtual string Message { @@ -136,6 +138,16 @@ public virtual string Message protected set => message = value; } + /// + /// Exposes the underlying message field without side-effects. + /// Used for serialization. + /// + protected internal string RawMessage + { + get => message; + set => message = value; + } + /// /// Custom help keyword associated with event. /// @@ -246,7 +258,48 @@ private void SetBuildEventContextDefaultAfterSerialization(StreamingContext sc) buildEventContext = BuildEventContext.Invalid; } } -#endregion + #endregion + /// + /// This is the default stub implementation, only here as a safeguard. + /// Actual logic is injected from Microsoft.Build.dll to replace this. + /// This is used by the Message property overrides to reconstruct the + /// message lazily on demand. + /// + internal static Func ResourceStringFormatter = (string resourceName, string[] arguments) => + { + var sb = new StringBuilder(); + sb.Append(resourceName); + sb.Append("("); + + bool notFirst = false; + foreach (var argument in arguments) + { + if (notFirst) + { + sb.Append(","); + } + else + { + notFirst = true; + } + + sb.Append(argument); + } + + sb.Append(")"); + return sb.ToString(); + }; + + /// + /// Shortcut method to mimic the original logic of creating the formatted strings. + /// + /// Name of the resource string. + /// Optional list of arguments to pass to the formatted string. + /// The concatenated formatted string. + internal static string FormatResourceStringIgnoreCodeAndKeyword(string resourceName, params string[] arguments) + { + return ResourceStringFormatter(resourceName, arguments); + } } } diff --git a/src/Framework/LazyFormattedBuildEventArgs.cs b/src/Framework/LazyFormattedBuildEventArgs.cs index ccc6e2494c3..ae7be349bd4 100644 --- a/src/Framework/LazyFormattedBuildEventArgs.cs +++ b/src/Framework/LazyFormattedBuildEventArgs.cs @@ -19,6 +19,15 @@ public class LazyFormattedBuildEventArgs : BuildEventArgs /// private object[] arguments; + /// + /// Exposes the underlying arguments field to serializers. + /// + internal object[] RawArguments + { + get => arguments; + set => arguments = value; + } + /// /// Stores the original culture for String.Format. /// @@ -34,7 +43,7 @@ public class LazyFormattedBuildEventArgs : BuildEventArgs /// Lock object. /// [NonSerialized] - private Object locker; + protected Object locker; /// /// This constructor allows all event data to be initialized. diff --git a/src/Framework/ProjectFinishedEventArgs.cs b/src/Framework/ProjectFinishedEventArgs.cs index 5c0cee0f259..1aa08dbd263 100644 --- a/src/Framework/ProjectFinishedEventArgs.cs +++ b/src/Framework/ProjectFinishedEventArgs.cs @@ -109,5 +109,24 @@ internal override void CreateFromStream(BinaryReader reader, int version) /// True if project built successfully, false otherwise /// public bool Succeeded => succeeded; + + public override string Message + { + get + { + if (RawMessage == null) + { + lock (locker) + { + if (RawMessage == null) + { + RawMessage = FormatResourceStringIgnoreCodeAndKeyword(Succeeded ? "ProjectFinishedSuccess" : "ProjectFinishedFailure", Path.GetFileName(ProjectFile)); + } + } + } + + return RawMessage; + } + } } } diff --git a/src/Framework/ProjectImportedEventArgs.cs b/src/Framework/ProjectImportedEventArgs.cs index 59772d062cf..b9c5a7a6cae 100644 --- a/src/Framework/ProjectImportedEventArgs.cs +++ b/src/Framework/ProjectImportedEventArgs.cs @@ -2,6 +2,8 @@ // Licensed under the MIT license. See LICENSE file in the project root for full license information. using System; +using System.IO; +using Microsoft.Build.Shared; namespace Microsoft.Build.Framework { @@ -28,7 +30,20 @@ public ProjectImportedEventArgs string message, params object[] messageArgs ) - : base(null, null, null, lineNumber, columnNumber, 0, 0, message, null, null, MessageImportance.Low, DateTime.UtcNow, messageArgs) + : base( + subcategory: null, + code: null, + file: null, + lineNumber: lineNumber, + columnNumber: columnNumber, + endLineNumber: 0, + endColumnNumber: 0, + message: message, + helpKeyword: null, + senderName: null, + importance: MessageImportance.Low, + eventTimestamp: DateTime.UtcNow, + messageArgs: messageArgs) { } @@ -51,5 +66,23 @@ public ProjectImportedEventArgs /// no matches, or a conditioned import that evaluated to false. /// public bool ImportIgnored { get; set; } + + internal override void WriteToStream(BinaryWriter writer) + { + base.WriteToStream(writer); + + writer.WriteOptionalString(UnexpandedProject); + writer.WriteOptionalString(ImportedProjectFile); + writer.Write(ImportIgnored); + } + + internal override void CreateFromStream(BinaryReader reader, int version) + { + base.CreateFromStream(reader, version); + + UnexpandedProject = reader.ReadOptionalString(); + ImportedProjectFile = reader.ReadOptionalString(); + ImportIgnored = reader.ReadBoolean(); + } } } diff --git a/src/Framework/ProjectStartedEventArgs.cs b/src/Framework/ProjectStartedEventArgs.cs index 2de82ffe9cb..0de7b555f68 100644 --- a/src/Framework/ProjectStartedEventArgs.cs +++ b/src/Framework/ProjectStartedEventArgs.cs @@ -482,5 +482,36 @@ private void SetDefaultsAfterSerialization(StreamingContext sc) } } #endregion + + public override string Message + { + get + { + if (RawMessage == null) + { + lock (locker) + { + if (RawMessage == null) + { + string projectFilePath = Path.GetFileName(ProjectFile); + + // Check to see if the there are any specific target names to be built. + // If targetNames is null or empty then we will be building with the + // default targets. + if (!string.IsNullOrEmpty(TargetNames)) + { + RawMessage = FormatResourceStringIgnoreCodeAndKeyword("ProjectStartedPrefixForTopLevelProjectWithTargetNames", projectFilePath, TargetNames); + } + else + { + RawMessage = FormatResourceStringIgnoreCodeAndKeyword("ProjectStartedPrefixForTopLevelProjectWithDefaultTargets", projectFilePath); + } + } + } + } + + return RawMessage; + } + } } } diff --git a/src/Framework/PropertyReassignmentEventArgs.cs b/src/Framework/PropertyReassignmentEventArgs.cs index 7f9ccb491a5..42642a593bd 100644 --- a/src/Framework/PropertyReassignmentEventArgs.cs +++ b/src/Framework/PropertyReassignmentEventArgs.cs @@ -64,5 +64,24 @@ public PropertyReassignmentEventArgs() /// The location of the reassignment. /// public string Location { get; set; } + + public override string Message + { + get + { + if (RawMessage == null) + { + lock (locker) + { + if (RawMessage == null) + { + RawMessage = FormatResourceStringIgnoreCodeAndKeyword("PropertyReassignment", PropertyName, NewValue, PreviousValue, Location); + } + } + } + + return RawMessage; + } + } } } diff --git a/src/Framework/TargetFinishedEventArgs.cs b/src/Framework/TargetFinishedEventArgs.cs index fae6bbd1c9b..435475eb4c7 100644 --- a/src/Framework/TargetFinishedEventArgs.cs +++ b/src/Framework/TargetFinishedEventArgs.cs @@ -159,7 +159,7 @@ internal override void CreateFromStream(BinaryReader reader, int version) public bool Succeeded => succeeded; /// - /// Project file associated with event. + /// Project file associated with event. /// public string ProjectFile => projectFile; @@ -176,5 +176,24 @@ public IEnumerable TargetOutputs get => targetOutputs; set => targetOutputs = value; } + + public override string Message + { + get + { + if (RawMessage == null) + { + lock (locker) + { + if (RawMessage == null) + { + RawMessage = FormatResourceStringIgnoreCodeAndKeyword(Succeeded ? "TargetFinishedSuccess" : "TargetFinishedFailure", targetName, Path.GetFileName(projectFile)); + } + } + } + + return RawMessage; + } + } } } diff --git a/src/Framework/TargetSkippedEventArgs.cs b/src/Framework/TargetSkippedEventArgs.cs index d934e187334..5bad19a7251 100644 --- a/src/Framework/TargetSkippedEventArgs.cs +++ b/src/Framework/TargetSkippedEventArgs.cs @@ -2,6 +2,8 @@ // Licensed under the MIT license. See LICENSE file in the project root for full license information. using System; +using System.IO; +using Microsoft.Build.Shared; namespace Microsoft.Build.Framework { @@ -26,7 +28,20 @@ public TargetSkippedEventArgs string message, params object[] messageArgs ) - : base(null, null, null, 0, 0, 0, 0, message, null, null, MessageImportance.Low, DateTime.UtcNow, messageArgs) + : base( + subcategory: null, + code: null, + file: null, + lineNumber: 0, + columnNumber: 0, + endLineNumber: 0, + endColumnNumber: 0, + message: message, + helpKeyword: null, + senderName: null, + importance: MessageImportance.Low, + eventTimestamp: DateTime.UtcNow, + messageArgs: messageArgs) { } @@ -49,5 +64,71 @@ public TargetSkippedEventArgs /// Why the parent target built this target. /// public TargetBuiltReason BuildReason { get; set; } + + public bool OriginallySucceeded { get; set; } + + public string Condition { get; set; } + + public string EvaluatedCondition { get; set; } + + internal override void WriteToStream(BinaryWriter writer) + { + base.WriteToStream(writer); + + writer.WriteOptionalString(TargetName); + writer.WriteOptionalString(ParentTarget); + writer.WriteOptionalString(TargetFile); + writer.WriteOptionalString(Condition); + writer.WriteOptionalString(EvaluatedCondition); + writer.Write7BitEncodedInt((int)BuildReason); + writer.Write(OriginallySucceeded); + } + + internal override void CreateFromStream(BinaryReader reader, int version) + { + base.CreateFromStream(reader, version); + + TargetName = reader.ReadOptionalString(); + ParentTarget = reader.ReadOptionalString(); + TargetFile = reader.ReadOptionalString(); + Condition = reader.ReadOptionalString(); + EvaluatedCondition = reader.ReadOptionalString(); + BuildReason = (TargetBuiltReason)reader.Read7BitEncodedInt(); + OriginallySucceeded = reader.ReadBoolean(); + } + + public override string Message + { + get + { + if (RawMessage == null) + { + lock (locker) + { + if (RawMessage == null) + { + if (Condition != null) + { + RawMessage = FormatResourceStringIgnoreCodeAndKeyword( + "TargetSkippedFalseCondition", + TargetName, + Condition, + EvaluatedCondition); + } + else + { + RawMessage = FormatResourceStringIgnoreCodeAndKeyword( + OriginallySucceeded + ? "TargetAlreadyCompleteSuccess" + : "TargetAlreadyCompleteFailure", + TargetName); + } + } + } + } + + return RawMessage; + } + } } } diff --git a/src/Framework/TargetStartedEventArgs.cs b/src/Framework/TargetStartedEventArgs.cs index 5d2b3b11dbd..e615e4f1461 100644 --- a/src/Framework/TargetStartedEventArgs.cs +++ b/src/Framework/TargetStartedEventArgs.cs @@ -175,5 +175,45 @@ internal override void CreateFromStream(BinaryReader reader, int version) /// Why this target was built by its parent. /// public TargetBuiltReason BuildReason => buildReason; + + public override string Message + { + get + { + if (RawMessage == null) + { + lock (locker) + { + if (RawMessage == null) + { + if (string.Equals(projectFile, targetFile, StringComparison.OrdinalIgnoreCase)) + { + if (!string.IsNullOrEmpty(parentTarget)) + { + RawMessage = FormatResourceStringIgnoreCodeAndKeyword("TargetStartedProjectDepends", targetName, projectFile, parentTarget); + } + else + { + RawMessage = FormatResourceStringIgnoreCodeAndKeyword("TargetStartedProjectEntry", targetName, projectFile); + } + } + else + { + if (!string.IsNullOrEmpty(parentTarget)) + { + RawMessage = FormatResourceStringIgnoreCodeAndKeyword("TargetStartedFileProjectDepends", targetName, targetFile, projectFile, parentTarget); + } + else + { + RawMessage = FormatResourceStringIgnoreCodeAndKeyword("TargetStartedFileProjectEntry", targetName, targetFile, projectFile); + } + } + } + } + } + + return RawMessage; + } + } } } diff --git a/src/Framework/TaskFinishedEventArgs.cs b/src/Framework/TaskFinishedEventArgs.cs index ca969f10712..f0c3b8d7dcf 100644 --- a/src/Framework/TaskFinishedEventArgs.cs +++ b/src/Framework/TaskFinishedEventArgs.cs @@ -137,5 +137,24 @@ internal override void CreateFromStream(BinaryReader reader, int version) /// MSBuild file where this task was defined. /// public string TaskFile => taskFile; + + public override string Message + { + get + { + if (RawMessage == null) + { + lock (locker) + { + if (RawMessage == null) + { + RawMessage = FormatResourceStringIgnoreCodeAndKeyword(Succeeded ? "TaskFinishedSuccess" : "TaskFinishedFailure", TaskName); + } + } + } + + return RawMessage; + } + } } } diff --git a/src/Framework/TaskParameterEventArgs.cs b/src/Framework/TaskParameterEventArgs.cs index f53363237ce..b4efc953e84 100644 --- a/src/Framework/TaskParameterEventArgs.cs +++ b/src/Framework/TaskParameterEventArgs.cs @@ -17,6 +17,8 @@ public enum TaskParameterMessageKind TaskOutput, AddItem, RemoveItem, + SkippedTargetInputs, + SkippedTargetOutputs } /// @@ -84,7 +86,7 @@ internal override void CreateFromStream(BinaryReader reader, int version) RawTimestamp = reader.ReadTimestamp(); BuildEventContext = reader.ReadOptionalBuildEventContext(); Kind = (TaskParameterMessageKind)reader.Read7BitEncodedInt(); - ItemType = reader.ReadString(); + ItemType = reader.ReadOptionalString(); Items = ReadItems(reader); } @@ -131,7 +133,7 @@ internal override void WriteToStream(BinaryWriter writer) writer.WriteTimestamp(RawTimestamp); writer.WriteOptionalBuildEventContext(BuildEventContext); writer.Write7BitEncodedInt((int)Kind); - writer.Write(ItemType); + writer.WriteOptionalString(ItemType); WriteItems(writer, Items); } diff --git a/src/Framework/TaskStartedEventArgs.cs b/src/Framework/TaskStartedEventArgs.cs index 039ef4b2b81..ce50a3b7723 100644 --- a/src/Framework/TaskStartedEventArgs.cs +++ b/src/Framework/TaskStartedEventArgs.cs @@ -122,5 +122,24 @@ internal override void CreateFromStream(BinaryReader reader, int version) /// MSBuild file where this task was defined. /// public string TaskFile => taskFile; + + public override string Message + { + get + { + if (RawMessage == null) + { + lock (locker) + { + if (RawMessage == null) + { + RawMessage = FormatResourceStringIgnoreCodeAndKeyword("TaskStarted", TaskName); + } + } + } + + return RawMessage; + } + } } } diff --git a/src/Framework/TelemetryEventArgs.cs b/src/Framework/TelemetryEventArgs.cs index 8b6b50e68de..3557981135e 100644 --- a/src/Framework/TelemetryEventArgs.cs +++ b/src/Framework/TelemetryEventArgs.cs @@ -3,6 +3,8 @@ using System; using System.Collections.Generic; +using System.IO; +using Microsoft.Build.Shared; namespace Microsoft.Build.Framework { @@ -21,5 +23,35 @@ public sealed class TelemetryEventArgs : BuildEventArgs /// Gets or sets a list of properties associated with the event. /// public IDictionary Properties { get; set; } = new Dictionary(); + + internal override void WriteToStream(BinaryWriter writer) + { + base.WriteToStream(writer); + + writer.WriteOptionalString(EventName); + int count = Properties?.Count ?? 0; + writer.Write7BitEncodedInt(count); + + foreach (var kvp in Properties) + { + writer.Write(kvp.Key); + writer.Write(kvp.Value); + } + } + + internal override void CreateFromStream(BinaryReader reader, int version) + { + base.CreateFromStream(reader, version); + + EventName = reader.ReadOptionalString(); + int count = reader.Read7BitEncodedInt(); + + for (int i = 0; i < count; i++) + { + string key = reader.ReadString(); + string value = reader.ReadString(); + Properties.Add(key, value); + } + } } } diff --git a/src/Shared/LogMessagePacketBase.cs b/src/Shared/LogMessagePacketBase.cs index 449f54c4dd2..536d31986cb 100644 --- a/src/Shared/LogMessagePacketBase.cs +++ b/src/Shared/LogMessagePacketBase.cs @@ -113,7 +113,22 @@ internal enum LoggingEventType : int /// /// Event is a ProjectEvaluationFinishedEventArgs /// - ProjectEvaluationFinishedEvent = 15 + ProjectEvaluationFinishedEvent = 15, + + /// + /// Event is a ProjectImportedEventArgs + /// + ProjectImportedEvent = 16, + + /// + /// Event is a TargetSkippedEventArgs + /// + TargetSkipped = 17, + + /// + /// Event is a TelemetryEventArgs + /// + Telemetry = 18, } #endregion @@ -512,6 +527,9 @@ private BuildEventArgs GetBuildEventArgFromId() LoggingEventType.TaskParameterEvent => new TaskParameterEventArgs(0, null, null, true, default), LoggingEventType.ProjectEvaluationStartedEvent => new ProjectEvaluationStartedEventArgs(), LoggingEventType.ProjectEvaluationFinishedEvent => new ProjectEvaluationFinishedEventArgs(), + LoggingEventType.ProjectImportedEvent => new ProjectImportedEventArgs(), + LoggingEventType.TargetSkipped => new TargetSkippedEventArgs(), + LoggingEventType.Telemetry => new TelemetryEventArgs(), #endif _ => throw new InternalErrorException("Should not get to the default of GetBuildEventArgFromId ID: " + _eventType) }; @@ -558,6 +576,18 @@ private LoggingEventType GetLoggingEventId(BuildEventArgs eventArg) { return LoggingEventType.ProjectEvaluationStartedEvent; } + else if (eventType == typeof(ProjectImportedEventArgs)) + { + return LoggingEventType.ProjectImportedEvent; + } + else if (eventType == typeof(TargetSkippedEventArgs)) + { + return LoggingEventType.TargetSkipped; + } + else if (eventType == typeof(TelemetryEventArgs)) + { + return LoggingEventType.Telemetry; + } #endif else if (eventType == typeof(TargetStartedEventArgs)) { From c9b5e2e067f082980eff014bfbdca0b701233755 Mon Sep 17 00:00:00 2001 From: Kirill Osenkov Date: Sun, 4 Apr 2021 17:26:59 -0700 Subject: [PATCH 02/14] Log TaskParameterEventArgs for inputs/outputs of TargetSkipped When logging input files and output files for skipped targets, do not concatenate them into huge semicolon-separated strings, but log a TaskParameterEventArgs instead. Introduce two new kinds of TaskParameter: TargetSkippedInputs and TargetSkippedOutputs. This way the smaller strings are deduplicated better. --- .../RequestBuilder/TargetUpToDateChecker.cs | 43 ++++++++----------- 1 file changed, 18 insertions(+), 25 deletions(-) diff --git a/src/Build/BackEnd/Components/RequestBuilder/TargetUpToDateChecker.cs b/src/Build/BackEnd/Components/RequestBuilder/TargetUpToDateChecker.cs index 46e86a679c9..335dcf77097 100644 --- a/src/Build/BackEnd/Components/RequestBuilder/TargetUpToDateChecker.cs +++ b/src/Build/BackEnd/Components/RequestBuilder/TargetUpToDateChecker.cs @@ -4,6 +4,7 @@ using System; using System.Collections.Generic; using System.IO; +using System.Linq; using Microsoft.Build.Collections; using Microsoft.Build.Evaluation; @@ -340,31 +341,23 @@ private static string GetIncrementalBuildReason(DependencyAnalysisLogDetail logD /// private void LogUniqueInputsAndOutputs() { - var targetInputKeys = _uniqueTargetInputs.Keys; - var targetOutputKeys = _uniqueTargetOutputs.Keys; - - var maxContentLength = Math.Max(LengthSum(targetInputKeys), LengthSum(targetOutputKeys)); - var maxSeparatorLength = Math.Max(targetInputKeys.Count, targetOutputKeys.Count); - - using (var sb = new ReuseableStringBuilder(maxContentLength + maxSeparatorLength)) - { - _loggingService.LogComment(_buildEventContext, MessageImportance.Low, "SkipTargetUpToDateInputs", sb.AppendSeparated(';', targetInputKeys).ToString()); - - sb.Clear(); - - _loggingService.LogComment(_buildEventContext, MessageImportance.Low, "SkipTargetUpToDateOutputs", sb.AppendSeparated(';', targetOutputKeys).ToString()); - } - - int LengthSum(ICollection collection) - { - var sum = 0; - foreach (var targetInput in collection) - { - sum += targetInput.Length; - } - - return sum; - } + var args = ItemGroupLoggingHelper.CreateTaskParameterEventArgs( + _buildEventContext, + TaskParameterMessageKind.SkippedTargetInputs, + itemType: null, + _uniqueTargetInputs.Keys.ToArray(), + logItemMetadata: false, + DateTime.UtcNow); + _loggingService.LogBuildEvent(args); + + args = ItemGroupLoggingHelper.CreateTaskParameterEventArgs( + _buildEventContext, + TaskParameterMessageKind.SkippedTargetOutputs, + itemType: null, + _uniqueTargetOutputs.Keys.ToArray(), + logItemMetadata: false, + DateTime.UtcNow); + _loggingService.LogBuildEvent(args); } /// From ace9956fe7be5cf06a8c9568fb406009c3327597 Mon Sep 17 00:00:00 2001 From: Kirill Osenkov Date: Sun, 4 Apr 2021 17:28:01 -0700 Subject: [PATCH 03/14] Do not allocate a single string for Task Parameter For scalar task parameters, log a string with arguments instead of concatenating it into a single string such as "TaskParameter:a=b". --- src/Build/BackEnd/TaskExecutionHost/TaskExecutionHost.cs | 7 +++++-- 1 file changed, 5 insertions(+), 2 deletions(-) diff --git a/src/Build/BackEnd/TaskExecutionHost/TaskExecutionHost.cs b/src/Build/BackEnd/TaskExecutionHost/TaskExecutionHost.cs index dc75cd9496e..f6a291d929c 100644 --- a/src/Build/BackEnd/TaskExecutionHost/TaskExecutionHost.cs +++ b/src/Build/BackEnd/TaskExecutionHost/TaskExecutionHost.cs @@ -1344,6 +1344,8 @@ private bool InternalSetTaskParameter(TaskPropertyInfo parameter, IList paramete return InternalSetTaskParameter(parameter, (object)parameterValue); } + private static readonly string TaskParameterFormatString = ItemGroupLoggingHelper.TaskParameterPrefix + "{0}={1}"; + /// /// Given an instantiated task, this helper method sets the specified parameter /// @@ -1355,7 +1357,6 @@ object parameterValue { bool success = false; - // Logging currently enabled only by an env var. if (LogTaskInputs && !_taskLoggingContext.LoggingService.OnlyLogCriticalEvents) { // If the type is a list, we already logged the parameters @@ -1363,7 +1364,9 @@ object parameterValue { _taskLoggingContext.LogCommentFromText( MessageImportance.Low, - ItemGroupLoggingHelper.TaskParameterPrefix + parameter.Name + "=" + ItemGroupLoggingHelper.GetStringFromParameterValue(parameterValue)); + TaskParameterFormatString, + parameter.Name, + ItemGroupLoggingHelper.GetStringFromParameterValue(parameterValue)); } } From 66acffdd8bff96e247d33e7cba372ad14098d097 Mon Sep 17 00:00:00 2001 From: Kirill Osenkov Date: Sun, 4 Apr 2021 17:30:35 -0700 Subject: [PATCH 04/14] Do not log property reassignment for MSBuildAllProjects These concatenated strings are huge and are almost never useful. Cache resource strings during evaluation instead of retrieving them every time. --- src/Build/Evaluation/Evaluator.cs | 38 +++++++++++++------ .../PropertyTrackingEvaluatorDataWrapper.cs | 19 ++++++++-- 2 files changed, 43 insertions(+), 14 deletions(-) diff --git a/src/Build/Evaluation/Evaluator.cs b/src/Build/Evaluation/Evaluator.cs index 22107d15fcc..9c5d4fc2159 100644 --- a/src/Build/Evaluation/Evaluator.cs +++ b/src/Build/Evaluation/Evaluator.cs @@ -1201,7 +1201,7 @@ private void AddToolsetProperties() // set the property even if there is no matching sub-toolset. if (!_data.Properties.Contains(Constants.SubToolsetVersionPropertyName)) { - _data.SetProperty(Constants.SubToolsetVersionPropertyName, _data.SubToolsetVersion, false /* NOT global property */, false /* may NOT be a reserved name */); + _data.SetProperty(Constants.SubToolsetVersionPropertyName, _data.SubToolsetVersion, false /* NOT global property */, false /* may NOT be a reserved name */); } if (_data.Toolset.SubToolsets.TryGetValue(_data.SubToolsetVersion, out SubToolset subToolset)) @@ -1315,6 +1315,13 @@ private void LogPropertyReassignment(P predecessor, P property, string location) string newValue = property.EvaluatedValue; string oldValue = predecessor?.EvaluatedValue; + if (string.Equals(property.Name, "MSBuildAllProjects", StringComparison.OrdinalIgnoreCase)) + { + // There's a huge perf cost to logging this and it increases the binlog size significantly. + // Meanwhile the usefulness of logging this is very low. + return; + } + if (newValue != oldValue) { _evaluationLoggingContext.LogComment( @@ -1659,6 +1666,15 @@ private List ExpandAndLoadImports(string directoryOfImportin return allProjects; } + private static readonly string CouldNotResolveSdk = ResourceUtilities.GetResourceString("CouldNotResolveSdk"); + private static readonly string ProjectImported = ResourceUtilities.GetResourceString("ProjectImported"); + private static readonly string ProjectImportSkippedEmptyFile = ResourceUtilities.GetResourceString("ProjectImportSkippedEmptyFile"); + private static readonly string ProjectImportSkippedExpressionEvaluatedToEmpty = ResourceUtilities.GetResourceString("ProjectImportSkippedExpressionEvaluatedToEmpty"); + private static readonly string ProjectImportSkippedFalseCondition = ResourceUtilities.GetResourceString("ProjectImportSkippedFalseCondition"); + private static readonly string ProjectImportSkippedInvalidFile = ResourceUtilities.GetResourceString("ProjectImportSkippedInvalidFile"); + private static readonly string ProjectImportSkippedMissingFile = ResourceUtilities.GetResourceString("ProjectImportSkippedMissingFile"); + private static readonly string ProjectImportSkippedNoMatches = ResourceUtilities.GetResourceString("ProjectImportSkippedNoMatches"); + /// /// Load and parse the specified project import, which may have wildcards, /// into one or more ProjectRootElements, if it's Condition evaluates to true @@ -1685,7 +1701,7 @@ private List ExpandAndLoadImports(string directoryOfImportin ProjectImportedEventArgs eventArgs = new ProjectImportedEventArgs( importElement.Location.Line, importElement.Location.Column, - ResourceUtilities.GetResourceString("ProjectImportSkippedFalseCondition"), + ProjectImportSkippedFalseCondition, importElement.Project, importElement.ContainingProject.FullPath, importElement.Location.Line, @@ -1778,7 +1794,7 @@ private List ExpandAndLoadImports(string directoryOfImportin ProjectImportedEventArgs eventArgs = new ProjectImportedEventArgs( importElement.Location.Line, importElement.Location.Column, - ResourceUtilities.GetResourceString("CouldNotResolveSdk"), + CouldNotResolveSdk, sdkReference.ToString()) { BuildEventContext = _evaluationLoggingContext.BuildEventContext, @@ -1948,7 +1964,7 @@ ProjectRootElement InnerCreate(string _, ProjectRootElementCacheBase __) ProjectImportedEventArgs eventArgs = new ProjectImportedEventArgs( importElement.Location.Line, importElement.Location.Column, - ResourceUtilities.GetResourceString("ProjectImportSkippedExpressionEvaluatedToEmpty"), + ProjectImportSkippedExpressionEvaluatedToEmpty, unescapedExpression, importElement.ContainingProject.FullPath, importElement.Location.Line, @@ -1971,7 +1987,7 @@ ProjectRootElement InnerCreate(string _, ProjectRootElementCacheBase __) bool atleastOneImportIgnored = false; bool atleastOneImportEmpty = false; - + foreach (string importExpressionEscapedItem in ExpressionShredder.SplitSemiColonSeparatedList(importExpressionEscaped)) { string[] importFilesEscaped = null; @@ -2003,7 +2019,7 @@ ProjectRootElement InnerCreate(string _, ProjectRootElementCacheBase __) ProjectImportedEventArgs eventArgs = new ProjectImportedEventArgs( importElement.Location.Line, importElement.Location.Column, - ResourceUtilities.GetResourceString("ProjectImportSkippedNoMatches"), + ProjectImportSkippedNoMatches, importExpressionEscapedItem, importElement.ContainingProject.FullPath, importElement.Location.Line, @@ -2151,7 +2167,7 @@ ProjectRootElement InnerCreate(string _, ProjectRootElementCacheBase __) ProjectImportedEventArgs eventArgs = new ProjectImportedEventArgs( importElement.Location.Line, importElement.Location.Column, - ResourceUtilities.GetResourceString("ProjectImported"), + ProjectImported, importedProjectElement.FullPath, importElement.ContainingProject.FullPath, importElement.Location.Line, @@ -2185,7 +2201,7 @@ ProjectRootElement InnerCreate(string _, ProjectRootElementCacheBase __) ProjectImportedEventArgs eventArgs = new ProjectImportedEventArgs( importElement.Location.Line, importElement.Location.Column, - ResourceUtilities.GetResourceString("ProjectImportSkippedMissingFile"), + ProjectImportSkippedMissingFile, importFileUnescaped, importElement.ContainingProject.FullPath, importElement.Location.Line, @@ -2217,14 +2233,14 @@ ProjectRootElement InnerCreate(string _, ProjectRootElementCacheBase __) // If IgnoreEmptyImports is enabled, check if the file is considered empty // ignoreImport = true; - ignoreImportResource = "ProjectImportSkippedEmptyFile"; + ignoreImportResource = ProjectImportSkippedEmptyFile; } else if ((_loadSettings & ProjectLoadSettings.IgnoreInvalidImports) != 0) { // If IgnoreInvalidImports is enabled, log all other non-handled exceptions and continue // ignoreImport = true; - ignoreImportResource = "ProjectImportSkippedInvalidFile"; + ignoreImportResource = ProjectImportSkippedInvalidFile; } if (ignoreImport) @@ -2235,7 +2251,7 @@ ProjectRootElement InnerCreate(string _, ProjectRootElementCacheBase __) ProjectImportedEventArgs eventArgs = new ProjectImportedEventArgs( importElement.Location.Line, importElement.Location.Column, - ResourceUtilities.GetResourceString(ignoreImportResource), + ignoreImportResource, importFileUnescaped, importElement.ContainingProject.FullPath, importElement.Location.Line, diff --git a/src/Build/Evaluation/PropertyTrackingEvaluatorDataWrapper.cs b/src/Build/Evaluation/PropertyTrackingEvaluatorDataWrapper.cs index 0630cd6407b..6e3dc3a3ec7 100644 --- a/src/Build/Evaluation/PropertyTrackingEvaluatorDataWrapper.cs +++ b/src/Build/Evaluation/PropertyTrackingEvaluatorDataWrapper.cs @@ -259,18 +259,31 @@ private void TrackPropertyInitialValueSet(P property, PropertySource source) /// The location of this property's reassignment. private void TrackPropertyReassignment(P predecessor, P property, string location) { - if ((_settings & PropertyTrackingSetting.PropertyReassignment) != PropertyTrackingSetting.PropertyReassignment) return; + if ((_settings & PropertyTrackingSetting.PropertyReassignment) != PropertyTrackingSetting.PropertyReassignment) + { + return; + } + + if (string.Equals(property.Name, "MSBuildAllProjects", StringComparison.OrdinalIgnoreCase)) + { + // There's a huge perf cost to logging this and it increases the binlog size significantly. + // Meanwhile the usefulness of logging this is very low. + return; + } string newValue = property.EvaluatedValue; string oldValue = predecessor.EvaluatedValue; - if (newValue == oldValue) return; + if (newValue == oldValue) + { + return; + } var args = new PropertyReassignmentEventArgs( property.Name, oldValue, newValue, location, - ResourceUtilities.FormatResourceStringIgnoreCodeAndKeyword("PropertyReassignment", property.Name, newValue, oldValue, location)); + message: null); args.BuildEventContext = _evaluationLoggingContext.BuildEventContext; _evaluationLoggingContext.LogBuildEvent(args); From b6540bcbcff5a656035dca4a67b088dad269f586 Mon Sep 17 00:00:00 2001 From: Kirill Osenkov Date: Sun, 4 Apr 2021 17:52:10 -0700 Subject: [PATCH 05/14] Cache resource strings in RAR logging. Instead of retrieving resource strings every time, cache them, reduce allocations and concatenations. No need to use a resource string to just add 4/8/10/12 spaces. Primarily this avoids concatenating the final string into a single string, but instead keeps the message separate from the arguments until the final string is requested. Don't log the image runtime version if it's v4.0.30319 as it's the overwhelming default and carries no useful information. Use better terminology for inclusion and exclusion lists. This change looks extensive, but is pretty mechanical. Hard to review, but a significant improvement to allocations and RAR logging overhead. --- .../ResolveAssemblyReference.cs | 560 +++++++++++------- 1 file changed, 338 insertions(+), 222 deletions(-) diff --git a/src/Tasks/AssemblyDependency/ResolveAssemblyReference.cs b/src/Tasks/AssemblyDependency/ResolveAssemblyReference.cs index f0062776ba5..8896a215e0d 100644 --- a/src/Tasks/AssemblyDependency/ResolveAssemblyReference.cs +++ b/src/Tasks/AssemblyDependency/ResolveAssemblyReference.cs @@ -56,6 +56,96 @@ public class ResolveAssemblyReference : TaskExtension /// public ResolveAssemblyReference() { + Strings.Initialize(Log); + } + + private static class Strings + { + public const string FourSpaces = " "; + public const string EightSpaces = " "; + public const string TenSpaces = " "; + public const string TwelveSpaces = " "; + + public static string ConsideredAndRejectedBecauseFusionNamesDidntMatch; + public static string ConsideredAndRejectedBecauseNoFile; + public static string ConsideredAndRejectedBecauseNotAFileNameOnDisk; + public static string ConsideredAndRejectedBecauseNotInGac; + public static string ConsideredAndRejectedBecauseTargetDidntHaveFusionName; + public static string Dependency; + public static string FormattedAssemblyInfo; + public static string FoundRelatedFile; + public static string FoundSatelliteFile; + public static string FoundScatterFile; + public static string ImageRuntimeVersion; + public static string IsAWinMdFile; + public static string LogAttributeFormat; + public static string LogTaskPropertyFormat; + public static string NoBecauseParentReferencesFoundInGac; + public static string NotCopyLocalBecauseConflictVictim; + public static string NotCopyLocalBecauseEmbedded; + public static string NotCopyLocalBecauseFrameworksFiles; + public static string NotCopyLocalBecauseIncomingItemAttributeOverrode; + public static string NotCopyLocalBecausePrerequisite; + public static string NotCopyLocalBecauseReferenceFoundInGAC; + public static string PrimaryReference; + public static string RemappedReference; + public static string RequiredBy; + public static string Resolved; + public static string ResolvedFrom; + public static string SearchedAssemblyFoldersEx; + public static string SearchPath; + public static string TargetedProcessorArchitectureDoesNotMatch; + public static string UnificationByAppConfig; + public static string UnificationByAutoUnify; + public static string UnificationByFrameworkRetarget; + public static string UnifiedDependency; + public static string UnifiedPrimaryReference; + + internal static void Initialize(TaskLoggingHelper log) + { + if (Resolved != null) + { + return; + } + + string GetResource(string name) => log.GetResourceMessage(name); + string GetResourceFourSpaces(string name) => FourSpaces + log.GetResourceMessage(name); + + ConsideredAndRejectedBecauseFusionNamesDidntMatch = EightSpaces + GetResource("ResolveAssemblyReference.ConsideredAndRejectedBecauseFusionNamesDidntMatch"); + ConsideredAndRejectedBecauseNoFile = EightSpaces + GetResource("ResolveAssemblyReference.ConsideredAndRejectedBecauseNoFile"); + ConsideredAndRejectedBecauseNotAFileNameOnDisk = EightSpaces + GetResource("ResolveAssemblyReference.ConsideredAndRejectedBecauseNotAFileNameOnDisk"); + ConsideredAndRejectedBecauseNotInGac = EightSpaces + GetResource("ResolveAssemblyReference.ConsideredAndRejectedBecauseNotInGac"); + ConsideredAndRejectedBecauseTargetDidntHaveFusionName = EightSpaces + GetResource("ResolveAssemblyReference.ConsideredAndRejectedBecauseTargetDidntHaveFusionName"); + Dependency = GetResource("ResolveAssemblyReference.Dependency"); + FormattedAssemblyInfo = GetResourceFourSpaces("ResolveAssemblyReference.FormattedAssemblyInfo"); + FoundRelatedFile = GetResourceFourSpaces("ResolveAssemblyReference.FoundRelatedFile"); + FoundSatelliteFile = GetResourceFourSpaces("ResolveAssemblyReference.FoundSatelliteFile"); + FoundScatterFile = GetResourceFourSpaces("ResolveAssemblyReference.FoundScatterFile"); + ImageRuntimeVersion = GetResourceFourSpaces("ResolveAssemblyReference.ImageRuntimeVersion"); + IsAWinMdFile = GetResourceFourSpaces("ResolveAssemblyReference.IsAWinMdFile"); + LogAttributeFormat = EightSpaces + GetResource("ResolveAssemblyReference.LogAttributeFormat"); + LogTaskPropertyFormat = GetResource("ResolveAssemblyReference.LogTaskPropertyFormat"); + NoBecauseParentReferencesFoundInGac = GetResourceFourSpaces("ResolveAssemblyReference.NoBecauseParentReferencesFoundInGac"); + NotCopyLocalBecauseConflictVictim = GetResourceFourSpaces("ResolveAssemblyReference.NotCopyLocalBecauseConflictVictim"); + NotCopyLocalBecauseEmbedded = GetResourceFourSpaces("ResolveAssemblyReference.NotCopyLocalBecauseEmbedded"); + NotCopyLocalBecauseFrameworksFiles = GetResourceFourSpaces("ResolveAssemblyReference.NotCopyLocalBecauseFrameworksFiles"); + NotCopyLocalBecauseIncomingItemAttributeOverrode = GetResourceFourSpaces("ResolveAssemblyReference.NotCopyLocalBecauseIncomingItemAttributeOverrode"); + NotCopyLocalBecausePrerequisite = GetResourceFourSpaces("ResolveAssemblyReference.NotCopyLocalBecausePrerequisite"); + NotCopyLocalBecauseReferenceFoundInGAC = GetResourceFourSpaces("ResolveAssemblyReference.NotCopyLocalBecauseReferenceFoundInGAC"); + PrimaryReference = GetResource("ResolveAssemblyReference.PrimaryReference"); + RemappedReference = GetResourceFourSpaces("ResolveAssemblyReference.RemappedReference"); + RequiredBy = GetResourceFourSpaces("ResolveAssemblyReference.RequiredBy"); + Resolved = GetResourceFourSpaces("ResolveAssemblyReference.Resolved"); + ResolvedFrom = GetResourceFourSpaces("ResolveAssemblyReference.ResolvedFrom"); + SearchedAssemblyFoldersEx = EightSpaces + GetResource("ResolveAssemblyReference.SearchedAssemblyFoldersEx"); + SearchPath = EightSpaces + GetResource("ResolveAssemblyReference.SearchPath"); + TargetedProcessorArchitectureDoesNotMatch = EightSpaces + GetResource("ResolveAssemblyReference.TargetedProcessorArchitectureDoesNotMatch"); + UnificationByAppConfig = GetResourceFourSpaces("ResolveAssemblyReference.UnificationByAppConfig"); + UnificationByAutoUnify = GetResourceFourSpaces("ResolveAssemblyReference.UnificationByAutoUnify"); + UnificationByFrameworkRetarget = GetResourceFourSpaces("ResolveAssemblyReference.UnificationByFrameworkRetarget"); + UnifiedDependency = GetResource("ResolveAssemblyReference.UnifiedDependency"); + UnifiedPrimaryReference = GetResource("ResolveAssemblyReference.UnifiedPrimaryReference"); + } } #region Properties @@ -1201,8 +1291,9 @@ internal static string ByteArrayToString(byte[] a) /// private void LogReferenceDependenciesAndSourceItemsToStringBuilder(string fusionName, Reference conflictCandidate, StringBuilder log) { - ErrorUtilities.VerifyThrowInternalNull(conflictCandidate, "ConflictCandidate"); - log.Append(ResourceUtilities.FormatResourceStringIgnoreCodeAndKeyword("ResolveAssemblyReference.FourSpaceIndent", ResourceUtilities.FormatResourceStringIgnoreCodeAndKeyword("ResolveAssemblyReference.ReferenceDependsOn", fusionName, conflictCandidate.FullPath))); + ErrorUtilities.VerifyThrowInternalNull(conflictCandidate, nameof(conflictCandidate)); + log.Append(Strings.FourSpaces); + log.Append(ResourceUtilities.FormatResourceStringIgnoreCodeAndKeyword("ResolveAssemblyReference.ReferenceDependsOn", fusionName, conflictCandidate.FullPath)); if (conflictCandidate.IsPrimary) { @@ -1212,7 +1303,10 @@ private void LogReferenceDependenciesAndSourceItemsToStringBuilder(string fusion } else { - log.AppendLine().Append(ResourceUtilities.FormatResourceStringIgnoreCodeAndKeyword("ResolveAssemblyReference.EightSpaceIndent", ResourceUtilities.FormatResourceStringIgnoreCodeAndKeyword("ResolveAssemblyReference.UnResolvedPrimaryItemSpec", conflictCandidate.PrimarySourceItem))); + log + .AppendLine() + .Append(Strings.EightSpaces) + .Append(ResourceUtilities.FormatResourceStringIgnoreCodeAndKeyword("ResolveAssemblyReference.UnResolvedPrimaryItemSpec", conflictCandidate.PrimarySourceItem)); } } @@ -1230,12 +1324,12 @@ private void LogReferenceDependenciesAndSourceItemsToStringBuilder(string fusion /// The means by which messages should be logged. private void LogDependeeReferenceToStringBuilder(Reference dependeeReference, StringBuilder log) { - log.AppendLine().AppendLine(ResourceUtilities.FormatResourceStringIgnoreCodeAndKeyword("ResolveAssemblyReference.EightSpaceIndent", dependeeReference.FullPath)); + log.AppendLine().Append(Strings.EightSpaces).AppendLine(dependeeReference.FullPath); - log.Append(ResourceUtilities.FormatResourceStringIgnoreCodeAndKeyword("ResolveAssemblyReference.TenSpaceIndent", ResourceUtilities.FormatResourceStringIgnoreCodeAndKeyword("ResolveAssemblyReference.PrimarySourceItemsForReference", dependeeReference.FullPath))); + log.Append(Strings.TenSpaces).Append(ResourceUtilities.FormatResourceStringIgnoreCodeAndKeyword("ResolveAssemblyReference.PrimarySourceItemsForReference", dependeeReference.FullPath)); foreach (ITaskItem sourceItem in dependeeReference.GetSourceItems()) { - log.AppendLine().Append(ResourceUtilities.FormatResourceStringIgnoreCodeAndKeyword("ResolveAssemblyReference.TwelveSpaceIndent", sourceItem.ItemSpec)); + log.AppendLine().Append(Strings.TwelveSpaces).Append(sourceItem.ItemSpec); } } @@ -1314,151 +1408,152 @@ private MessageImportance ChooseReferenceLoggingImportance(Reference reference) /// private void LogInputs() { - if (Traits.Instance.EscapeHatches.LogTaskInputs) + if (Traits.Instance.EscapeHatches.LogTaskInputs || Silent) { // the inputs will be logged automatically anyway, avoid duplication in the logs return; } - if (!Silent) - { - Log.LogMessageFromResources(MessageImportance.Low, "ResolveAssemblyReference.LogTaskPropertyFormat", "TargetFrameworkMoniker"); - Log.LogMessageFromResources(MessageImportance.Low, "ResolveAssemblyReference.FourSpaceIndent", _targetedFrameworkMoniker); + string indent = Strings.FourSpaces; + string property = Strings.LogTaskPropertyFormat; + MessageImportance importance = MessageImportance.Low; - Log.LogMessageFromResources(MessageImportance.Low, "ResolveAssemblyReference.LogTaskPropertyFormat", "TargetFrameworkMonikerDisplayName"); - Log.LogMessageFromResources(MessageImportance.Low, "ResolveAssemblyReference.FourSpaceIndent", TargetFrameworkMonikerDisplayName); + Log.LogMessage(importance, property, "TargetFrameworkMoniker"); + Log.LogMessage(importance, indent + _targetedFrameworkMoniker); - Log.LogMessageFromResources(MessageImportance.Low, "ResolveAssemblyReference.LogTaskPropertyFormat", "TargetedRuntimeVersion"); - Log.LogMessageFromResources(MessageImportance.Low, "ResolveAssemblyReference.FourSpaceIndent", _targetedRuntimeVersionRawValue); + Log.LogMessage(importance, property, "TargetFrameworkMonikerDisplayName"); + Log.LogMessage(importance, indent + TargetFrameworkMonikerDisplayName); - Log.LogMessageFromResources(MessageImportance.Low, "ResolveAssemblyReference.LogTaskPropertyFormat", "Assemblies"); - foreach (ITaskItem item in Assemblies) - { - Log.LogMessageFromResources(MessageImportance.Low, "ResolveAssemblyReference.FourSpaceIndent", item.ItemSpec); - LogAttribute(item, ItemMetadataNames.privateMetadata); - LogAttribute(item, ItemMetadataNames.hintPath); - LogAttribute(item, ItemMetadataNames.specificVersion); - LogAttribute(item, ItemMetadataNames.embedInteropTypes); - LogAttribute(item, ItemMetadataNames.executableExtension); - LogAttribute(item, ItemMetadataNames.subType); - } + Log.LogMessage(importance, property, "TargetedRuntimeVersion"); + Log.LogMessage(importance, indent + _targetedRuntimeVersionRawValue); - Log.LogMessageFromResources(MessageImportance.Low, "ResolveAssemblyReference.LogTaskPropertyFormat", "AssemblyFiles"); - foreach (ITaskItem item in AssemblyFiles) - { - Log.LogMessageFromResources(MessageImportance.Low, "ResolveAssemblyReference.FourSpaceIndent", item.ItemSpec); - LogAttribute(item, ItemMetadataNames.privateMetadata); - LogAttribute(item, ItemMetadataNames.fusionName); - } + Log.LogMessage(importance, property, "Assemblies"); + foreach (ITaskItem item in Assemblies) + { + Log.LogMessage(importance, indent + item.ItemSpec); + LogAttribute(item, ItemMetadataNames.privateMetadata); + LogAttribute(item, ItemMetadataNames.hintPath); + LogAttribute(item, ItemMetadataNames.specificVersion); + LogAttribute(item, ItemMetadataNames.embedInteropTypes); + LogAttribute(item, ItemMetadataNames.executableExtension); + LogAttribute(item, ItemMetadataNames.subType); + } + + Log.LogMessage(importance, property, "AssemblyFiles"); + foreach (ITaskItem item in AssemblyFiles) + { + Log.LogMessage(importance, indent + item.ItemSpec); + LogAttribute(item, ItemMetadataNames.privateMetadata); + LogAttribute(item, ItemMetadataNames.fusionName); + } - Log.LogMessageFromResources(MessageImportance.Low, "ResolveAssemblyReference.LogTaskPropertyFormat", "CandidateAssemblyFiles"); - foreach (string file in CandidateAssemblyFiles) + Log.LogMessage(importance, property, "CandidateAssemblyFiles"); + foreach (string file in CandidateAssemblyFiles) + { + try { - try + if (FileUtilities.HasExtension(file, _allowedAssemblyExtensions)) { - if (FileUtilities.HasExtension(file, _allowedAssemblyExtensions)) - { - Log.LogMessageFromResources(MessageImportance.Low, "ResolveAssemblyReference.FourSpaceIndent", file); - } - } - catch (Exception e) when (ExceptionHandling.IsIoRelatedException(e)) - { - throw new InvalidParameterValueException("CandidateAssemblyFiles", file, e.Message); + Log.LogMessage(importance, indent + file); } } - - Log.LogMessageFromResources(MessageImportance.Low, "ResolveAssemblyReference.LogTaskPropertyFormat", "TargetFrameworkDirectories"); - Log.LogMessageFromResources(MessageImportance.Low, "ResolveAssemblyReference.FourSpaceIndent", String.Join(",", TargetFrameworkDirectories)); - - Log.LogMessageFromResources(MessageImportance.Low, "ResolveAssemblyReference.LogTaskPropertyFormat", "InstalledAssemblyTables"); - foreach (ITaskItem installedAssemblyTable in InstalledAssemblyTables) + catch (Exception e) when (ExceptionHandling.IsIoRelatedException(e)) { - Log.LogMessageFromResources(MessageImportance.Low, "ResolveAssemblyReference.FourSpaceIndent", installedAssemblyTable); - LogAttribute(installedAssemblyTable, ItemMetadataNames.frameworkDirectory); + throw new InvalidParameterValueException("CandidateAssemblyFiles", file, e.Message); } + } - Log.LogMessageFromResources(MessageImportance.Low, "ResolveAssemblyReference.LogTaskPropertyFormat", "IgnoreInstalledAssemblyTable"); - Log.LogMessageFromResources(MessageImportance.Low, "ResolveAssemblyReference.FourSpaceIndent", _ignoreDefaultInstalledAssemblyTables); + Log.LogMessage(importance, property, "TargetFrameworkDirectories"); + Log.LogMessage(importance, indent + String.Join(",", TargetFrameworkDirectories)); - Log.LogMessageFromResources(MessageImportance.Low, "ResolveAssemblyReference.LogTaskPropertyFormat", "SearchPaths"); - foreach (string path in SearchPaths) - { - Log.LogMessageFromResources(MessageImportance.Low, "ResolveAssemblyReference.FourSpaceIndent", path); - } + Log.LogMessage(importance, property, "InstalledAssemblyTables"); + foreach (ITaskItem installedAssemblyTable in InstalledAssemblyTables) + { + Log.LogMessage(importance, indent + installedAssemblyTable); + LogAttribute(installedAssemblyTable, ItemMetadataNames.frameworkDirectory); + } - Log.LogMessageFromResources(MessageImportance.Low, "ResolveAssemblyReference.LogTaskPropertyFormat", "AllowedAssemblyExtensions"); - foreach (string allowedAssemblyExtension in _allowedAssemblyExtensions) - { - Log.LogMessageFromResources(MessageImportance.Low, "ResolveAssemblyReference.FourSpaceIndent", allowedAssemblyExtension); - } + Log.LogMessage(importance, property, "IgnoreInstalledAssemblyTable"); + Log.LogMessage(importance, indent + _ignoreDefaultInstalledAssemblyTables); - Log.LogMessageFromResources(MessageImportance.Low, "ResolveAssemblyReference.LogTaskPropertyFormat", "AllowedRelatedFileExtensions"); - foreach (string allowedRelatedFileExtension in _relatedFileExtensions) - { - Log.LogMessageFromResources(MessageImportance.Low, "ResolveAssemblyReference.FourSpaceIndent", allowedRelatedFileExtension); - } + Log.LogMessage(importance, property, "SearchPaths"); + foreach (string path in SearchPaths) + { + Log.LogMessage(importance, indent + path); + } + + Log.LogMessage(importance, property, "AllowedAssemblyExtensions"); + foreach (string allowedAssemblyExtension in _allowedAssemblyExtensions) + { + Log.LogMessage(importance, indent + allowedAssemblyExtension); + } - Log.LogMessageFromResources(MessageImportance.Low, "ResolveAssemblyReference.LogTaskPropertyFormat", "AppConfigFile"); - Log.LogMessageFromResources(MessageImportance.Low, "ResolveAssemblyReference.FourSpaceIndent", AppConfigFile); + Log.LogMessage(importance, property, "AllowedRelatedFileExtensions"); + foreach (string allowedRelatedFileExtension in _relatedFileExtensions) + { + Log.LogMessage(importance, indent + allowedRelatedFileExtension); + } - Log.LogMessageFromResources(MessageImportance.Low, "ResolveAssemblyReference.LogTaskPropertyFormat", "AutoUnify"); - Log.LogMessageFromResources(MessageImportance.Low, "ResolveAssemblyReference.FourSpaceIndent", AutoUnify.ToString()); + Log.LogMessage(importance, property, "AppConfigFile"); + Log.LogMessage(importance, indent + AppConfigFile); - Log.LogMessageFromResources(MessageImportance.Low, "ResolveAssemblyReference.LogTaskPropertyFormat", "CopyLocalDependenciesWhenParentReferenceInGac"); - Log.LogMessageFromResources(MessageImportance.Low, "ResolveAssemblyReference.FourSpaceIndent", _copyLocalDependenciesWhenParentReferenceInGac); + Log.LogMessage(importance, property, "AutoUnify"); + Log.LogMessage(importance, indent + AutoUnify.ToString()); - Log.LogMessageFromResources(MessageImportance.Low, "ResolveAssemblyReference.LogTaskPropertyFormat", "FindDependencies"); - Log.LogMessageFromResources(MessageImportance.Low, "ResolveAssemblyReference.FourSpaceIndent", _findDependencies); + Log.LogMessage(importance, property, "CopyLocalDependenciesWhenParentReferenceInGac"); + Log.LogMessage(importance, indent + _copyLocalDependenciesWhenParentReferenceInGac); - Log.LogMessageFromResources(MessageImportance.Low, "ResolveAssemblyReference.LogTaskPropertyFormat", "TargetProcessorArchitecture"); - Log.LogMessageFromResources(MessageImportance.Low, "ResolveAssemblyReference.FourSpaceIndent", TargetProcessorArchitecture); + Log.LogMessage(importance, property, "FindDependencies"); + Log.LogMessage(importance, indent + _findDependencies); - Log.LogMessageFromResources(MessageImportance.Low, "ResolveAssemblyReference.LogTaskPropertyFormat", "StateFile"); - Log.LogMessageFromResources(MessageImportance.Low, "ResolveAssemblyReference.FourSpaceIndent", StateFile); + Log.LogMessage(importance, property, "TargetProcessorArchitecture"); + Log.LogMessage(importance, indent + TargetProcessorArchitecture); - Log.LogMessageFromResources(MessageImportance.Low, "ResolveAssemblyReference.LogTaskPropertyFormat", "InstalledAssemblySubsetTables"); - foreach (ITaskItem installedAssemblySubsetTable in InstalledAssemblySubsetTables) - { - Log.LogMessageFromResources(MessageImportance.Low, "ResolveAssemblyReference.FourSpaceIndent", installedAssemblySubsetTable); - LogAttribute(installedAssemblySubsetTable, ItemMetadataNames.frameworkDirectory); - } + Log.LogMessage(importance, property, "StateFile"); + Log.LogMessage(importance, indent + StateFile); - Log.LogMessageFromResources(MessageImportance.Low, "ResolveAssemblyReference.LogTaskPropertyFormat", "IgnoreInstalledAssemblySubsetTable"); - Log.LogMessageFromResources(MessageImportance.Low, "ResolveAssemblyReference.FourSpaceIndent", _ignoreDefaultInstalledAssemblySubsetTables); + Log.LogMessage(importance, property, "InstalledAssemblySubsetTables"); + foreach (ITaskItem installedAssemblySubsetTable in InstalledAssemblySubsetTables) + { + Log.LogMessage(importance, indent + installedAssemblySubsetTable); + LogAttribute(installedAssemblySubsetTable, ItemMetadataNames.frameworkDirectory); + } - Log.LogMessageFromResources(MessageImportance.Low, "ResolveAssemblyReference.LogTaskPropertyFormat", "TargetFrameworkSubsets"); - foreach (string subset in _targetFrameworkSubsets) - { - Log.LogMessageFromResources(MessageImportance.Low, "ResolveAssemblyReference.FourSpaceIndent", subset); - } + Log.LogMessage(importance, property, "IgnoreInstalledAssemblySubsetTable"); + Log.LogMessage(importance, indent + _ignoreDefaultInstalledAssemblySubsetTables); - Log.LogMessageFromResources(MessageImportance.Low, "ResolveAssemblyReference.LogTaskPropertyFormat", "FullTargetFrameworkSubsetNames"); - foreach (string subset in FullTargetFrameworkSubsetNames) - { - Log.LogMessageFromResources(MessageImportance.Low, "ResolveAssemblyReference.FourSpaceIndent", subset); - } + Log.LogMessage(importance, property, "TargetFrameworkSubsets"); + foreach (string subset in _targetFrameworkSubsets) + { + Log.LogMessage(importance, indent + subset); + } - Log.LogMessageFromResources(MessageImportance.Low, "ResolveAssemblyReference.LogTaskPropertyFormat", "ProfileName"); - Log.LogMessageFromResources(MessageImportance.Low, "ResolveAssemblyReference.FourSpaceIndent", ProfileName); + Log.LogMessage(importance, property, "FullTargetFrameworkSubsetNames"); + foreach (string subset in FullTargetFrameworkSubsetNames) + { + Log.LogMessage(importance, indent + subset); + } - Log.LogMessageFromResources(MessageImportance.Low, "ResolveAssemblyReference.LogTaskPropertyFormat", "FullFrameworkFolders"); - foreach (string fullFolder in FullFrameworkFolders) - { - Log.LogMessageFromResources(MessageImportance.Low, "ResolveAssemblyReference.FourSpaceIndent", fullFolder); - } + Log.LogMessage(importance, property, "ProfileName"); + Log.LogMessage(importance, indent + ProfileName); - Log.LogMessageFromResources(MessageImportance.Low, "ResolveAssemblyReference.LogTaskPropertyFormat", "LatestTargetFrameworkDirectories"); - foreach (string latestFolder in _latestTargetFrameworkDirectories) - { - Log.LogMessageFromResources(MessageImportance.Low, "ResolveAssemblyReference.FourSpaceIndent", latestFolder); - } + Log.LogMessage(importance, property, "FullFrameworkFolders"); + foreach (string fullFolder in FullFrameworkFolders) + { + Log.LogMessage(importance, indent + fullFolder); + } - Log.LogMessageFromResources(MessageImportance.Low, "ResolveAssemblyReference.LogTaskPropertyFormat", "ProfileTablesLocation"); - foreach (ITaskItem profileTable in FullFrameworkAssemblyTables) - { - Log.LogMessageFromResources(MessageImportance.Low, "ResolveAssemblyReference.FourSpaceIndent", profileTable); - LogAttribute(profileTable, ItemMetadataNames.frameworkDirectory); - } + Log.LogMessage(importance, property, "LatestTargetFrameworkDirectories"); + foreach (string latestFolder in _latestTargetFrameworkDirectories) + { + Log.LogMessage(importance, indent + latestFolder); + } + + Log.LogMessage(importance, property, "ProfileTablesLocation"); + foreach (ITaskItem profileTable in FullFrameworkAssemblyTables) + { + Log.LogMessage(importance, indent + profileTable); + LogAttribute(profileTable, ItemMetadataNames.frameworkDirectory); } } @@ -1472,7 +1567,7 @@ private void LogAttribute(ITaskItem item, string metadataName) string metadataValue = item.GetMetadata(metadataName); if (!string.IsNullOrEmpty(metadataValue)) { - Log.LogMessageFromResources(MessageImportance.Low, "ResolveAssemblyReference.EightSpaceIndent", Log.FormatResourceString("ResolveAssemblyReference.LogAttributeFormat", metadataName, metadataValue)); + Log.LogMessage(MessageImportance.Low, Strings.LogAttributeFormat, metadataName, metadataValue); } } @@ -1488,22 +1583,22 @@ private void LogPrimaryOrDependency(Reference reference, string fusionName, Mess { if (reference.IsUnified) { - Log.LogMessageFromResources(importance, "ResolveAssemblyReference.UnifiedPrimaryReference", fusionName); + Log.LogMessage(importance, Strings.UnifiedPrimaryReference, fusionName); } else { - Log.LogMessageFromResources(importance, "ResolveAssemblyReference.PrimaryReference", fusionName); + Log.LogMessage(importance, Strings.PrimaryReference, fusionName); } } else { if (reference.IsUnified) { - Log.LogMessageFromResources(importance, "ResolveAssemblyReference.UnifiedDependency", fusionName); + Log.LogMessage(importance, Strings.UnifiedDependency, fusionName); } else { - Log.LogMessageFromResources(importance, "ResolveAssemblyReference.Dependency", fusionName); + Log.LogMessage(importance, Strings.Dependency, fusionName); } } @@ -1514,16 +1609,16 @@ private void LogPrimaryOrDependency(Reference reference, string fusionName, Mess case UnificationReason.BecauseOfBindingRedirect: if (AutoUnify) { - Log.LogMessageFromResources(importance, "ResolveAssemblyReference.FourSpaceIndent", Log.FormatResourceString("ResolveAssemblyReference.UnificationByAutoUnify", unificationVersion.version, unificationVersion.referenceFullPath)); + Log.LogMessage(importance, Strings.UnificationByAutoUnify, unificationVersion.version, unificationVersion.referenceFullPath); } else { - Log.LogMessageFromResources(importance, "ResolveAssemblyReference.FourSpaceIndent", Log.FormatResourceString("ResolveAssemblyReference.UnificationByAppConfig", unificationVersion.version, _appConfigFile, unificationVersion.referenceFullPath)); + Log.LogMessage(importance, Strings.UnificationByAppConfig, unificationVersion.version, _appConfigFile, unificationVersion.referenceFullPath); } break; case UnificationReason.FrameworkRetarget: - Log.LogMessageFromResources(importance, "ResolveAssemblyReference.FourSpaceIndent", Log.FormatResourceString("ResolveAssemblyReference.UnificationByFrameworkRetarget", unificationVersion.version, unificationVersion.referenceFullPath)); + Log.LogMessage(importance, Strings.UnificationByFrameworkRetarget, unificationVersion.version, unificationVersion.referenceFullPath); break; case UnificationReason.DidntUnify: @@ -1537,7 +1632,7 @@ private void LogPrimaryOrDependency(Reference reference, string fusionName, Mess foreach (AssemblyRemapping remapping in reference.RemappedAssemblyNames()) { - Log.LogMessageFromResources(importance, "ResolveAssemblyReference.FourSpaceIndent", Log.FormatResourceString("ResolveAssemblyReference.RemappedReference", remapping.From.FullName, remapping.To.FullName)); + Log.LogMessage(importance, Strings.RemappedReference, remapping.From.FullName, remapping.To.FullName); } } @@ -1584,12 +1679,21 @@ private void LogReferenceErrors(Reference reference, MessageImportance importanc if (reference.IsPrimary && !dependencyProblem) { // Treat it as a warning - Log.LogWarning(null, warningCode, helpKeyword, null, 0, 0, 0, 0, messageOnly); + Log.LogWarning( + subcategory: null, + warningCode, + helpKeyword, + file: null, + lineNumber: 0, + columnNumber: 0, + endLineNumber: 0, + endColumnNumber: 0, + message: messageOnly); } else { // Just show the the message as a comment. - Log.LogMessageFromResources(importance, "ResolveAssemblyReference.FourSpaceIndent", messageOnly); + Log.LogMessage(importance, Strings.FourSpaces + messageOnly); } } } @@ -1605,8 +1709,8 @@ private void LogFullName(Reference reference, MessageImportance importance) if (reference.IsResolved) { - Log.LogMessageFromResources(importance, "ResolveAssemblyReference.FourSpaceIndent", Log.FormatResourceString("ResolveAssemblyReference.Resolved", reference.FullPath)); - Log.LogMessageFromResources(importance, "ResolveAssemblyReference.FourSpaceIndent", Log.FormatResourceString("ResolveAssemblyReference.ResolvedFrom", reference.ResolvedSearchPath)); + Log.LogMessage(importance, Strings.Resolved, reference.FullPath); + Log.LogMessage(importance, Strings.ResolvedFrom, reference.ResolvedSearchPath); } } @@ -1650,10 +1754,10 @@ private void LogAssembliesConsideredAndRejected(Reference reference, string fusi if (lastSearchPath != location.SearchPath) { lastSearchPath = location.SearchPath; - Log.LogMessageFromResources(importance, "ResolveAssemblyReference.EightSpaceIndent", Log.FormatResourceString("ResolveAssemblyReference.SearchPath", lastSearchPath)); + Log.LogMessage(importance, Strings.SearchPath, lastSearchPath); if (logAssemblyFoldersMinimal) { - Log.LogMessageFromResources(importance, "ResolveAssemblyReference.EightSpaceIndent", Log.FormatResourceString("ResolveAssemblyReference.SearchedAssemblyFoldersEx")); + Log.LogMessage(importance, Strings.SearchedAssemblyFoldersEx); } } @@ -1664,33 +1768,38 @@ private void LogAssembliesConsideredAndRejected(Reference reference, string fusi { if (!logAssemblyFoldersMinimal) { - Log.LogMessageFromResources(importance, "ResolveAssemblyReference.EightSpaceIndent", Log.FormatResourceString("ResolveAssemblyReference.ConsideredAndRejectedBecauseNoFile", location.FileNameAttempted)); + Log.LogMessage(importance, Strings.ConsideredAndRejectedBecauseNoFile, location.FileNameAttempted); } break; } case NoMatchReason.FusionNamesDidNotMatch: - Log.LogMessageFromResources(importance, "ResolveAssemblyReference.EightSpaceIndent", Log.FormatResourceString("ResolveAssemblyReference.ConsideredAndRejectedBecauseFusionNamesDidntMatch", location.FileNameAttempted, location.AssemblyName.FullName, fusionName)); + Log.LogMessage(importance, Strings.ConsideredAndRejectedBecauseFusionNamesDidntMatch, location.FileNameAttempted, location.AssemblyName.FullName, fusionName); break; case NoMatchReason.TargetHadNoFusionName: - Log.LogMessageFromResources(importance, "ResolveAssemblyReference.EightSpaceIndent", Log.FormatResourceString("ResolveAssemblyReference.ConsideredAndRejectedBecauseTargetDidntHaveFusionName", location.FileNameAttempted)); + Log.LogMessage(importance, Strings.ConsideredAndRejectedBecauseTargetDidntHaveFusionName, location.FileNameAttempted); break; case NoMatchReason.NotInGac: - Log.LogMessageFromResources(importance, "ResolveAssemblyReference.EightSpaceIndent", Log.FormatResourceString("ResolveAssemblyReference.ConsideredAndRejectedBecauseNotInGac", location.FileNameAttempted)); + Log.LogMessage(importance, Strings.ConsideredAndRejectedBecauseNotInGac, location.FileNameAttempted); break; case NoMatchReason.NotAFileNameOnDisk: { if (!logAssemblyFoldersMinimal) { - Log.LogMessageFromResources(importance, "ResolveAssemblyReference.EightSpaceIndent", Log.FormatResourceString("ResolveAssemblyReference.ConsideredAndRejectedBecauseNotAFileNameOnDisk", location.FileNameAttempted)); + Log.LogMessage(importance, Strings.ConsideredAndRejectedBecauseNotAFileNameOnDisk, location.FileNameAttempted); } break; } case NoMatchReason.ProcessorArchitectureDoesNotMatch: - Log.LogMessageFromResources(importance, "ResolveAssemblyReference.EightSpaceIndent", Log.FormatResourceString("ResolveAssemblyReference.TargetedProcessorArchitectureDoesNotMatch", location.FileNameAttempted, location.AssemblyName.AssemblyName.ProcessorArchitecture.ToString(), _targetProcessorArchitecture)); + Log.LogMessage( + importance, + Strings.TargetedProcessorArchitectureDoesNotMatch, + location.FileNameAttempted, + location.AssemblyName.AssemblyName.ProcessorArchitecture.ToString(), + _targetProcessorArchitecture); break; default: Debug.Assert(false, "Should have handled this case."); @@ -1712,7 +1821,7 @@ private void LogDependees(Reference reference, MessageImportance importance) ICollection dependees = reference.GetSourceItems(); foreach (ITaskItem dependee in dependees) { - Log.LogMessageFromResources(importance, "ResolveAssemblyReference.FourSpaceIndent", Log.FormatResourceString("ResolveAssemblyReference.RequiredBy", dependee.ItemSpec)); + Log.LogMessage(importance, Strings.RequiredBy, dependee.ItemSpec); } } } @@ -1730,7 +1839,7 @@ private void LogRelatedFiles(Reference reference, MessageImportance importance) { foreach (string relatedFileExtension in reference.GetRelatedFileExtensions()) { - Log.LogMessageFromResources(importance, "ResolveAssemblyReference.FourSpaceIndent", Log.FormatResourceString("ResolveAssemblyReference.FoundRelatedFile", reference.FullPathWithoutExtension + relatedFileExtension)); + Log.LogMessage(importance, Strings.FoundRelatedFile, reference.FullPathWithoutExtension + relatedFileExtension); } } } @@ -1745,12 +1854,12 @@ private void LogSatellites(Reference reference, MessageImportance importance) { foreach (string satelliteFile in reference.GetSatelliteFiles()) { - Log.LogMessageFromResources(importance, "ResolveAssemblyReference.FourSpaceIndent", Log.FormatResourceString("ResolveAssemblyReference.FoundSatelliteFile", satelliteFile)); + Log.LogMessage(importance, Strings.FoundSatelliteFile, satelliteFile); } } /// - /// Log the satellite files. + /// Log scatter files. /// /// The reference. /// The importance of the message. @@ -1758,7 +1867,7 @@ private void LogScatterFiles(Reference reference, MessageImportance importance) { foreach (string scatterFile in reference.GetScatterFiles()) { - Log.LogMessageFromResources(importance, "ResolveAssemblyReference.FourSpaceIndent", Log.FormatResourceString("ResolveAssemblyReference.FoundScatterFile", scatterFile)); + Log.LogMessage(importance, Strings.FoundScatterFile, scatterFile); } } @@ -1778,32 +1887,32 @@ private void LogCopyLocalState(Reference reference, MessageImportance importance break; case CopyLocalState.NoBecausePrerequisite: - Log.LogMessageFromResources(importance, "ResolveAssemblyReference.FourSpaceIndent", Log.FormatResourceString("ResolveAssemblyReference.NotCopyLocalBecausePrerequisite")); + Log.LogMessage(importance, Strings.NotCopyLocalBecausePrerequisite); break; case CopyLocalState.NoBecauseReferenceItemHadMetadata: - Log.LogMessageFromResources(importance, "ResolveAssemblyReference.FourSpaceIndent", Log.FormatResourceString("ResolveAssemblyReference.NotCopyLocalBecauseIncomingItemAttributeOverrode")); + Log.LogMessage(importance, Strings.NotCopyLocalBecauseIncomingItemAttributeOverrode); break; case CopyLocalState.NoBecauseFrameworkFile: - Log.LogMessageFromResources(importance, "ResolveAssemblyReference.FourSpaceIndent", Log.FormatResourceString("ResolveAssemblyReference.NotCopyLocalBecauseFrameworksFiles")); + Log.LogMessage(importance, Strings.NotCopyLocalBecauseFrameworksFiles); break; case CopyLocalState.NoBecauseReferenceResolvedFromGAC: case CopyLocalState.NoBecauseReferenceFoundInGAC: - Log.LogMessageFromResources(importance, "ResolveAssemblyReference.FourSpaceIndent", Log.FormatResourceString("ResolveAssemblyReference.NotCopyLocalBecauseReferenceFoundInGAC")); + Log.LogMessage(importance, Strings.NotCopyLocalBecauseReferenceFoundInGAC); break; case CopyLocalState.NoBecauseConflictVictim: - Log.LogMessageFromResources(importance, "ResolveAssemblyReference.FourSpaceIndent", Log.FormatResourceString("ResolveAssemblyReference.NotCopyLocalBecauseConflictVictim")); + Log.LogMessage(importance, Strings.NotCopyLocalBecauseConflictVictim); break; case CopyLocalState.NoBecauseEmbedded: - Log.LogMessageFromResources(importance, "ResolveAssemblyReference.FourSpaceIndent", Log.FormatResourceString("ResolveAssemblyReference.NotCopyLocalBecauseEmbedded")); + Log.LogMessage(importance, Strings.NotCopyLocalBecauseEmbedded); break; case CopyLocalState.NoBecauseParentReferencesFoundInGAC: - Log.LogMessageFromResources(importance, "ResolveAssemblyReference.FourSpaceIndent", Log.FormatResourceString("ResolveAssemblyReference.NoBecauseParentReferencesFoundInGac")); + Log.LogMessage(importance, Strings.NoBecauseParentReferencesFoundInGac); break; default: @@ -1820,11 +1929,15 @@ private void LogImageRuntime(Reference reference, MessageImportance importance) { if (!reference.IsUnresolvable && !reference.IsBadImage) { - Log.LogMessageFromResources(importance, "ResolveAssemblyReference.FourSpaceIndent", Log.FormatResourceString("ResolveAssemblyReference.ImageRuntimeVersion", reference.ImageRuntime)); + // Don't log the overwhelming default as it just pollutes the logs. + if (reference.ImageRuntime != "v4.0.30319") + { + Log.LogMessage(importance, Strings.ImageRuntimeVersion, reference.ImageRuntime); + } if (reference.IsWinMDFile) { - Log.LogMessageFromResources(importance, "ResolveAssemblyReference.FourSpaceIndent", Log.FormatResourceString("ResolveAssemblyReference.IsAWinMdFile")); + Log.LogMessage(importance, Strings.IsAWinMdFile); } } } @@ -1844,14 +1957,14 @@ private void LogConflict(Reference reference, string fusionName, StringBuilder l { Debug.Assert(!reference.IsPrimary, "A primary reference should never lose a conflict because of version. This is an insoluble conflict instead."); string message = Log.FormatResourceString("ResolveAssemblyReference.ConflictHigherVersionChosen", reference.ConflictVictorName); - log.AppendLine().Append(ResourceUtilities.FormatResourceStringIgnoreCodeAndKeyword("ResolveAssemblyReference.FourSpaceIndent", message)); + log.AppendLine().Append(Strings.FourSpaces).Append(message); break; } case ConflictLossReason.WasNotPrimary: { string message = Log.FormatResourceString("ResolveAssemblyReference.ConflictPrimaryChosen", reference.ConflictVictorName, fusionName); - log.AppendLine().Append(ResourceUtilities.FormatResourceStringIgnoreCodeAndKeyword("ResolveAssemblyReference.FourSpaceIndent", message)); + log.AppendLine().Append(Strings.FourSpaces).Append(message); break; } @@ -2035,7 +2148,7 @@ ReadMachineTypeFromPEHeader readMachineTypeFromPEHeader // Validate the contents of the InstalledAssemblyTables parameter. AssemblyTableInfo[] installedAssemblyTableInfo = GetInstalledAssemblyTableInfo(_ignoreDefaultInstalledAssemblyTables, _installedAssemblyTables, new GetListPath(RedistList.GetRedistListPathsFromDisk), TargetFrameworkDirectories); - AssemblyTableInfo[] whiteListSubsetTableInfo = null; + AssemblyTableInfo[] inclusionListSubsetTableInfo = null; InstalledAssemblies installedAssemblies = null; RedistList redistList = null; @@ -2045,7 +2158,7 @@ ReadMachineTypeFromPEHeader readMachineTypeFromPEHeader redistList = RedistList.GetRedistList(installedAssemblyTableInfo); } - Dictionary blackList = null; + Dictionary exclusionList = null; // The name of the subset if it is generated or the name of the profile. This will be used for error messages and logging. string subsetOrProfileName = null; @@ -2053,21 +2166,21 @@ ReadMachineTypeFromPEHeader readMachineTypeFromPEHeader // Are we targeting a profile bool targetingProfile = !String.IsNullOrEmpty(ProfileName) && ((FullFrameworkFolders.Length > 0) || (FullFrameworkAssemblyTables.Length > 0)); bool targetingSubset = false; - List whiteListErrors = new List(); - List whiteListErrorFilesNames = new List(); + List inclusionListErrors = new List(); + List inclusionListErrorFilesNames = new List(); // Check for partial success in GetRedistList and log any tolerated exceptions. - if (redistList?.Count > 0 || targetingProfile || ShouldUseSubsetBlackList()) + if (redistList?.Count > 0 || targetingProfile || ShouldUseSubsetExclusionList()) { // If we are not targeting a dev 10 profile and we have the required components to generate a orcas style subset, do so - if (!targetingProfile && ShouldUseSubsetBlackList()) + if (!targetingProfile && ShouldUseSubsetExclusionList()) { // Based in the target framework subset names find the paths to the files - SubsetListFinder whiteList = new SubsetListFinder(_targetFrameworkSubsets); - whiteListSubsetTableInfo = GetInstalledAssemblyTableInfo(IgnoreDefaultInstalledAssemblySubsetTables, InstalledAssemblySubsetTables, new GetListPath(whiteList.GetSubsetListPathsFromDisk), TargetFrameworkDirectories); - if (whiteListSubsetTableInfo.Length > 0 && (redistList?.Count > 0)) + SubsetListFinder inclusionList = new SubsetListFinder(_targetFrameworkSubsets); + inclusionListSubsetTableInfo = GetInstalledAssemblyTableInfo(IgnoreDefaultInstalledAssemblySubsetTables, InstalledAssemblySubsetTables, new GetListPath(inclusionList.GetSubsetListPathsFromDisk), TargetFrameworkDirectories); + if (inclusionListSubsetTableInfo.Length > 0 && (redistList?.Count > 0)) { - blackList = redistList.GenerateBlackList(whiteListSubsetTableInfo, whiteListErrors, whiteListErrorFilesNames); + exclusionList = redistList.GenerateBlackList(inclusionListSubsetTableInfo, inclusionListErrors, inclusionListErrorFilesNames); } else { @@ -2075,7 +2188,7 @@ ReadMachineTypeFromPEHeader readMachineTypeFromPEHeader } // Could get into this situation if the redist list files were full of junk and no assemblies were read in. - if (blackList == null) + if (exclusionList == null) { Log.LogWarningWithCodeFromResources("ResolveAssemblyReference.NoRedistAssembliesToGenerateExclusionList"); } @@ -2093,15 +2206,15 @@ ReadMachineTypeFromPEHeader readMachineTypeFromPEHeader AssemblyTableInfo[] fullRedistAssemblyTableInfo = null; RedistList fullFrameworkRedistList = null; - HandleProfile(installedAssemblyTableInfo /*This is the table info related to the profile*/, out fullRedistAssemblyTableInfo, out blackList, out fullFrameworkRedistList); + HandleProfile(installedAssemblyTableInfo /*This is the table info related to the profile*/, out fullRedistAssemblyTableInfo, out exclusionList, out fullFrameworkRedistList); // Make sure the redist list and the installedAsemblyTableInfo structures point to the full framework, we replace the installedAssemblyTableInfo // which contained the information about the profile redist files with the one from the full framework because when doing anything with the RAR cache // we want to use the full frameworks redist list. Essentailly after generating the exclusion list the job of the profile redist list is done. redistList = fullFrameworkRedistList; - // Save the profile redist list file locations as the whiteList - whiteListSubsetTableInfo = installedAssemblyTableInfo; + // Save the profile redist list file locations as the inclusionList + inclusionListSubsetTableInfo = installedAssemblyTableInfo; // Set the installed assembly table to the full redist list values installedAssemblyTableInfo = fullRedistAssemblyTableInfo; @@ -2129,10 +2242,10 @@ ReadMachineTypeFromPEHeader readMachineTypeFromPEHeader } // Some files may have been skipped. Log warnings for these. - for (int i = 0; i < whiteListErrors.Count; ++i) + for (int i = 0; i < inclusionListErrors.Count; ++i) { - Exception e = whiteListErrors[i]; - string filename = whiteListErrorFilesNames[i]; + Exception e = inclusionListErrors[i]; + string filename = inclusionListErrorFilesNames[i]; // Give the user a warning about the bad file (or files). Log.LogWarningWithCodeFromResources("ResolveAssemblyReference.InvalidInstalledAssemblySubsetTablesFile", filename, SubsetListFinder.SubsetListFolder, e.Message); @@ -2251,7 +2364,7 @@ ReadMachineTypeFromPEHeader readMachineTypeFromPEHeader excludedReferencesExist = false; if (redistList?.Count > 0) { - excludedReferencesExist = dependencyTable.MarkReferencesForExclusion(blackList); + excludedReferencesExist = dependencyTable.MarkReferencesForExclusion(exclusionList); } } catch (InvalidOperationException e) @@ -2289,7 +2402,7 @@ out autoUnifiedRemappedAssemblyReferences excludedReferencesExist = false; if (redistList?.Count > 0) { - excludedReferencesExist = dependencyTable.MarkReferencesForExclusion(blackList); + excludedReferencesExist = dependencyTable.MarkReferencesForExclusion(exclusionList); } } catch (InvalidOperationException e) @@ -2403,7 +2516,7 @@ out _copyLocalFiles // Log the results. success = LogResults(dependencyTable, idealAssemblyRemappings, idealAssemblyRemappingsIdentities, generalResolutionExceptions); - DumpTargetProfileLists(installedAssemblyTableInfo, whiteListSubsetTableInfo, dependencyTable); + DumpTargetProfileLists(installedAssemblyTableInfo, inclusionListSubsetTableInfo, dependencyTable); if (processorArchitecture != SystemProcessorArchitecture.None && _warnOrErrorOnTargetArchitectureMismatch != WarnOrErrorOnTargetArchitectureMismatchBehavior.None) { @@ -2563,13 +2676,13 @@ internal static Version SetTargetedRuntimeVersion(string targetedRuntimeVersionR /// /// Installed assembly info of the profile redist lists /// Installed assemblyInfo for the full framework redist lists - /// Generated exclusion list + /// Generated exclusion list /// Redist list which will contain the full framework redist list. - private void HandleProfile(AssemblyTableInfo[] installedAssemblyTableInfo, out AssemblyTableInfo[] fullRedistAssemblyTableInfo, out Dictionary blackList, out RedistList fullFrameworkRedistList) + private void HandleProfile(AssemblyTableInfo[] installedAssemblyTableInfo, out AssemblyTableInfo[] fullRedistAssemblyTableInfo, out Dictionary exclusionList, out RedistList fullFrameworkRedistList) { // Redist list which will contain the full framework redist list. fullFrameworkRedistList = null; - blackList = null; + exclusionList = null; fullRedistAssemblyTableInfo = null; // Make sure the framework directory is on the FullFrameworkTablesLocation if it is being used. @@ -2590,18 +2703,18 @@ private void HandleProfile(AssemblyTableInfo[] installedAssemblyTableInfo, out A fullFrameworkRedistList = RedistList.GetRedistList(fullRedistAssemblyTableInfo); if (fullFrameworkRedistList != null) { - // Generate the black list by determining what assemblies are in the full framework but not in the profile. - // The installedAssemblyTableInfo is the list of xml files for the Client Profile redist, these are the whitelist xml files. + // Generate the exclusion list by determining what assemblies are in the full framework but not in the profile. + // The installedAssemblyTableInfo is the list of xml files for the Client Profile redist, these are the inclusionList xml files. Log.LogMessageFromResources("ResolveAssemblyReference.ProfileExclusionListWillBeGenerated"); // Any errors reading the profile redist list will already be logged, we do not need to re-log the errors here. - List whiteListErrors = new List(); - List whiteListErrorFilesNames = new List(); - blackList = fullFrameworkRedistList.GenerateBlackList(installedAssemblyTableInfo, whiteListErrors, whiteListErrorFilesNames); + List inclusionListErrors = new List(); + List inclusionListErrorFilesNames = new List(); + exclusionList = fullFrameworkRedistList.GenerateBlackList(installedAssemblyTableInfo, inclusionListErrors, inclusionListErrorFilesNames); } // Could get into this situation if the redist list files were full of junk and no assemblies were read in. - if (blackList == null) + if (exclusionList == null) { Log.LogWarningWithCodeFromResources("ResolveAssemblyReference.NoRedistAssembliesToGenerateExclusionList"); } @@ -2696,60 +2809,63 @@ private bool VerifyInputConditions() /// /// Log the target framework subset information. /// - private void DumpTargetProfileLists(AssemblyTableInfo[] installedAssemblyTableInfo, AssemblyTableInfo[] whiteListSubsetTableInfo, ReferenceTable referenceTable) + private void DumpTargetProfileLists(AssemblyTableInfo[] installedAssemblyTableInfo, AssemblyTableInfo[] inclusionListSubsetTableInfo, ReferenceTable referenceTable) { - if (installedAssemblyTableInfo != null) + if (installedAssemblyTableInfo == null) { - string dumpFrameworkSubsetList = Environment.GetEnvironmentVariable("MSBUILDDUMPFRAMEWORKSUBSETLIST"); + return; + } - if (dumpFrameworkSubsetList != null) - { - Log.LogMessageFromResources(MessageImportance.Low, "ResolveAssemblyReference.TargetFrameworkSubsetLogHeader"); + string dumpFrameworkSubsetList = Environment.GetEnvironmentVariable("MSBUILDDUMPFRAMEWORKSUBSETLIST"); + if (dumpFrameworkSubsetList == null) + { + return; + } - Log.LogMessageFromResources(MessageImportance.Low, "ResolveAssemblyReference.TargetFrameworkRedistLogHeader"); - foreach (AssemblyTableInfo redistInfo in installedAssemblyTableInfo) - { - if (redistInfo != null) - { - Log.LogMessageFromResources(MessageImportance.Low, "ResolveAssemblyReference.FourSpaceIndent", Log.FormatResourceString("ResolveAssemblyReference.FormattedAssemblyInfo", redistInfo.Path)); - } - } + Log.LogMessageFromResources(MessageImportance.Low, "ResolveAssemblyReference.TargetFrameworkSubsetLogHeader"); - Log.LogMessageFromResources(MessageImportance.Low, "ResolveAssemblyReference.TargetFrameworkWhiteListLogHeader"); - if (whiteListSubsetTableInfo != null) - { - foreach (AssemblyTableInfo whiteListInfo in whiteListSubsetTableInfo) - { - if (whiteListInfo != null) - { - Log.LogMessageFromResources(MessageImportance.Low, "ResolveAssemblyReference.FourSpaceIndent", Log.FormatResourceString("ResolveAssemblyReference.FormattedAssemblyInfo", whiteListInfo.Path)); - } - } - } + Log.LogMessageFromResources(MessageImportance.Low, "ResolveAssemblyReference.TargetFrameworkRedistLogHeader"); + foreach (AssemblyTableInfo redistInfo in installedAssemblyTableInfo) + { + if (redistInfo != null) + { + Log.LogMessage(MessageImportance.Low, Strings.FormattedAssemblyInfo, redistInfo.Path); + } + } - if (referenceTable.ListOfExcludedAssemblies != null) + Log.LogMessageFromResources(MessageImportance.Low, "ResolveAssemblyReference.TargetFrameworkWhiteListLogHeader"); + if (inclusionListSubsetTableInfo != null) + { + foreach (AssemblyTableInfo inclusionListInfo in inclusionListSubsetTableInfo) + { + if (inclusionListInfo != null) { - Log.LogMessageFromResources(MessageImportance.Low, "ResolveAssemblyReference.TargetFrameworkExclusionListLogHeader"); - foreach (string assemblyFullName in referenceTable.ListOfExcludedAssemblies) - { - Log.LogMessageFromResources(MessageImportance.Low, "ResolveAssemblyReference.FourSpaceIndent", assemblyFullName); - } + Log.LogMessage(MessageImportance.Low, Strings.FormattedAssemblyInfo, inclusionListInfo.Path); } } } + + if (referenceTable.ListOfExcludedAssemblies != null) + { + Log.LogMessageFromResources(MessageImportance.Low, "ResolveAssemblyReference.TargetFrameworkExclusionListLogHeader"); + foreach (string assemblyFullName in referenceTable.ListOfExcludedAssemblies) + { + Log.LogMessageFromResources(MessageImportance.Low, "ResolveAssemblyReference.FourSpaceIndent", assemblyFullName); + } + } } /// - /// Determine if a black list should be used or not + /// Determine if an exclusion list should be used or not /// - /// The black list should only be used if there are TargetFrameworkSubsets to use or TargetFrameworkProfiles. + /// The exclusion list should only be used if there are TargetFrameworkSubsets to use or TargetFrameworkProfiles. /// - /// 1) If we find a Full or equivalent marker in the list of subsets passed in we do not want to generate a black list even if installedAssemblySubsets are passed in - /// 2) If we are ignoring the default installed subset tables and we have not passed in any additional subset tables, we do not want to generate a black list - /// 3) If no targetframework subsets were passed in and no additional subset tables were passed in, we do not want to generate a blacklist + /// 1) If we find a Full or equivalent marker in the list of subsets passed in we do not want to generate an exclusion list even if installedAssemblySubsets are passed in + /// 2) If we are ignoring the default installed subset tables and we have not passed in any additional subset tables, we do not want to generate an exclusion list + /// 3) If no targetframework subsets were passed in and no additional subset tables were passed in, we do not want to generate an exclusion list /// - /// True if we should generate a black list, false if a blacklist should not be generated - private bool ShouldUseSubsetBlackList() + /// True if we should generate an exclusion list + private bool ShouldUseSubsetExclusionList() { // Check for full subset names in the passed in list of subsets to search for foreach (string fullSubsetName in _fullTargetFrameworkSubsetNames) @@ -2774,7 +2890,7 @@ private bool ShouldUseSubsetBlackList() } // No subset names were passed in to search for in the targetframework directories and no installed subset tables were provided, we have nothing to use to - // generate the black list with, so do not continue. + // generate the exclusion list with, so do not continue. if (_targetFrameworkSubsets.Length == 0 && _installedAssemblySubsetTables.Length == 0) { return false; From 95021b14a940c4168c605c9776c859fe3762c759 Mon Sep 17 00:00:00 2001 From: Kirill Osenkov Date: Sun, 4 Apr 2021 17:52:57 -0700 Subject: [PATCH 06/14] Cache resource strings in the Copy task. --- src/Tasks/Copy.cs | 37 ++++++++++++++++++++++++++++--------- 1 file changed, 28 insertions(+), 9 deletions(-) diff --git a/src/Tasks/Copy.cs b/src/Tasks/Copy.cs index 67d779798e7..ba793b673d6 100644 --- a/src/Tasks/Copy.cs +++ b/src/Tasks/Copy.cs @@ -47,8 +47,27 @@ public class Copy : TaskExtension, ICancelableTask public Copy() { RetryDelayMilliseconds = RetryDelayMillisecondsDefault; + + if (DidNotCopyBecauseOfFileMatch == null) + { + CreatesDirectory = Log.GetResourceMessage("Copy.CreatesDirectory"); + DidNotCopyBecauseOfFileMatch = Log.GetResourceMessage("Copy.DidNotCopyBecauseOfFileMatch"); + FileComment = Log.GetResourceMessage("Copy.FileComment"); + HardLinkComment = Log.GetResourceMessage("Copy.HardLinkComment"); + RetryingAsFileCopy = Log.GetResourceMessage("Copy.RetryingAsFileCopy"); + RemovingReadOnlyAttribute = Log.GetResourceMessage("Copy.RemovingReadOnlyAttribute"); + SymbolicLinkComment = Log.GetResourceMessage("Copy.SymbolicLinkComment"); + } } + private static string CreatesDirectory; + private static string DidNotCopyBecauseOfFileMatch; + private static string FileComment; + private static string HardLinkComment; + private static string RetryingAsFileCopy; + private static string RemovingReadOnlyAttribute; + private static string SymbolicLinkComment; + #region Properties private readonly CancellationTokenSource _cancellationTokenSource = new CancellationTokenSource(); @@ -233,7 +252,7 @@ private void LogDiagnostic(string message, params object[] messageArgs) { if (!FileSystems.Default.DirectoryExists(destinationFolder)) { - Log.LogMessageFromResources(MessageImportance.Normal, "Copy.CreatesDirectory", destinationFolder); + Log.LogMessage(MessageImportance.Normal, CreatesDirectory, destinationFolder); Directory.CreateDirectory(destinationFolder); } @@ -255,11 +274,11 @@ private void LogDiagnostic(string message, params object[] messageArgs) // If we want to create hard or symbolic links, then try that first if (UseHardlinksIfPossible) { - TryCopyViaLink("Copy.HardLinkComment", MessageImportance.Normal, sourceFileState, destinationFileState, ref destinationFileExists, out linkCreated, ref errorMessage, (source, destination, errMessage) => NativeMethods.MakeHardLink(destination, source, ref errorMessage)); + TryCopyViaLink(HardLinkComment, MessageImportance.Normal, sourceFileState, destinationFileState, ref destinationFileExists, out linkCreated, ref errorMessage, (source, destination, errMessage) => NativeMethods.MakeHardLink(destination, source, ref errorMessage)); } else if (UseSymboliclinksIfPossible) { - TryCopyViaLink("Copy.SymbolicLinkComment", MessageImportance.Normal, sourceFileState, destinationFileState, ref destinationFileExists, out linkCreated, ref errorMessage, (source, destination, errMessage) => NativeMethods.MakeSymbolicLink(destination, source, ref errorMessage)); + TryCopyViaLink(SymbolicLinkComment, MessageImportance.Normal, sourceFileState, destinationFileState, ref destinationFileExists, out linkCreated, ref errorMessage, (source, destination, errMessage) => NativeMethods.MakeSymbolicLink(destination, source, ref errorMessage)); } if (ErrorIfLinkFails && !linkCreated) @@ -275,7 +294,7 @@ private void LogDiagnostic(string message, params object[] messageArgs) // Do not log a fake command line as well, as it's superfluous, and also potentially expensive string sourceFilePath = FileUtilities.GetFullPathNoThrow(sourceFileState.Name); string destinationFilePath = FileUtilities.GetFullPathNoThrow(destinationFileState.Name); - Log.LogMessageFromResources(MessageImportance.Normal, "Copy.FileComment", sourceFilePath, destinationFilePath); + Log.LogMessage(MessageImportance.Normal, FileComment, sourceFilePath, destinationFilePath); File.Copy(sourceFileState.Name, destinationFileState.Name, true); } @@ -296,7 +315,7 @@ private void LogDiagnostic(string message, params object[] messageArgs) private void TryCopyViaLink(string linkComment, MessageImportance messageImportance, FileState sourceFileState, FileState destinationFileState, ref bool destinationFileExists, out bool linkCreated, ref string errorMessage, Func createLink) { // Do not log a fake command line as well, as it's superfluous, and also potentially expensive - Log.LogMessageFromResources(MessageImportance.Normal, linkComment, sourceFileState.Name, destinationFileState.Name); + Log.LogMessage(MessageImportance.Normal, linkComment, sourceFileState.Name, destinationFileState.Name); if (!OverwriteReadOnlyFiles) { @@ -315,7 +334,7 @@ private void TryCopyViaLink(string linkComment, MessageImportance messageImporta if (!linkCreated) { // This is only a message since we don't want warnings when copying to network shares etc. - Log.LogMessageFromResources(messageImportance, "Copy.RetryingAsFileCopy", sourceFileState.Name, destinationFileState.Name, errorMessage); + Log.LogMessage(messageImportance, RetryingAsFileCopy, sourceFileState.Name, destinationFileState.Name, errorMessage); } } @@ -331,7 +350,7 @@ private void MakeFileWriteable(FileState file, bool logActivity) { if (logActivity) { - Log.LogMessageFromResources(MessageImportance.Low, "Copy.RemovingReadOnlyAttribute", file.Name); + Log.LogMessage(MessageImportance.Low, RemovingReadOnlyAttribute, file.Name); } File.SetAttributes(file.Name, FileAttributes.Normal); @@ -683,9 +702,9 @@ private bool DoCopyIfNecessary(FileState sourceFileState, FileState destinationF // If we got here, then the file's time and size match AND // the user set the SkipUnchangedFiles flag which means we // should skip matching files. - Log.LogMessageFromResources( + Log.LogMessage( MessageImportance.Low, - "Copy.DidNotCopyBecauseOfFileMatch", + DidNotCopyBecauseOfFileMatch, sourceFileState.Name, destinationFileState.Name, "SkipUnchangedFiles", From c191e15806c0842fd1e76610e68a97f9ea684045 Mon Sep 17 00:00:00 2001 From: Kirill Osenkov Date: Sun, 4 Apr 2021 17:53:45 -0700 Subject: [PATCH 07/14] Use named arguments. --- src/Framework/BuildMessageEventArgs.cs | 2 +- src/Framework/BuildStatusEventArgs.cs | 2 +- src/Framework/TaskCommandLineEventArgs.cs | 2 +- src/Shared/TaskLoggingHelper.cs | 12 ++++++------ 4 files changed, 9 insertions(+), 9 deletions(-) diff --git a/src/Framework/BuildMessageEventArgs.cs b/src/Framework/BuildMessageEventArgs.cs index 7a73a533151..23282a1db87 100644 --- a/src/Framework/BuildMessageEventArgs.cs +++ b/src/Framework/BuildMessageEventArgs.cs @@ -176,7 +176,7 @@ public BuildMessageEventArgs MessageImportance importance, DateTime eventTimestamp ) - : this(subcategory, code, file, lineNumber, columnNumber, endLineNumber, endColumnNumber, message, helpKeyword, senderName, importance, eventTimestamp, null) + : this(subcategory, code, file, lineNumber, columnNumber, endLineNumber, endColumnNumber, message, helpKeyword, senderName, importance, eventTimestamp, messageArgs: null) { // do nothing } diff --git a/src/Framework/BuildStatusEventArgs.cs b/src/Framework/BuildStatusEventArgs.cs index 0d096f830ef..c8c3b1d35e1 100644 --- a/src/Framework/BuildStatusEventArgs.cs +++ b/src/Framework/BuildStatusEventArgs.cs @@ -61,7 +61,7 @@ protected BuildStatusEventArgs string senderName, DateTime eventTimestamp ) - : this(message, helpKeyword, senderName, eventTimestamp, null) + : this(message, helpKeyword, senderName, eventTimestamp, messageArgs: null) { // do nothing } diff --git a/src/Framework/TaskCommandLineEventArgs.cs b/src/Framework/TaskCommandLineEventArgs.cs index 63f1edada11..4a6f1af686e 100644 --- a/src/Framework/TaskCommandLineEventArgs.cs +++ b/src/Framework/TaskCommandLineEventArgs.cs @@ -67,7 +67,7 @@ public TaskCommandLineEventArgs MessageImportance importance, DateTime eventTimestamp ) - : base(commandLine, null, taskName, importance, eventTimestamp) + : base(commandLine, helpKeyword: null, taskName, importance, eventTimestamp) { // do nothing } diff --git a/src/Shared/TaskLoggingHelper.cs b/src/Shared/TaskLoggingHelper.cs index a4f4a164193..9d9fdc1c1b4 100644 --- a/src/Shared/TaskLoggingHelper.cs +++ b/src/Shared/TaskLoggingHelper.cs @@ -282,12 +282,12 @@ public void LogMessage(MessageImportance importance, string message, params obje BuildMessageEventArgs e = new BuildMessageEventArgs ( - message, // message - null, // help keyword - TaskName, // sender - importance, // importance - DateTime.UtcNow, // timestamp - messageArgs // message arguments + message, + helpKeyword: null, + senderName: TaskName, + importance, + DateTime.UtcNow, + messageArgs ); // If BuildEngine is null, task attempted to log before it was set on it, From da331c9780fb262626a4b003df6697cfd531d1fc Mon Sep 17 00:00:00 2001 From: Kirill Osenkov Date: Sun, 4 Apr 2021 18:11:18 -0700 Subject: [PATCH 08/14] Add NOPERFORMANCESUMMARY switch for console loggers. Allows to turn off perf summary even in diagnostic mode. Useful for diffing logs (as the perf numbers will be different when playing back a binlog). --- src/Build/Logging/BaseConsoleLogger.cs | 7 +++++-- 1 file changed, 5 insertions(+), 2 deletions(-) diff --git a/src/Build/Logging/BaseConsoleLogger.cs b/src/Build/Logging/BaseConsoleLogger.cs index 1768e7b3145..70d0477ad3a 100644 --- a/src/Build/Logging/BaseConsoleLogger.cs +++ b/src/Build/Logging/BaseConsoleLogger.cs @@ -908,14 +908,14 @@ public virtual void Initialize(IEventSource eventSource, int nodeCount) /// Available events. public virtual void Initialize(IEventSource eventSource) { - ParseParameters(); - // Always show perf summary for diagnostic verbosity. if (IsVerbosityAtLeast(LoggerVerbosity.Diagnostic)) { this.showPerfSummary = true; } + ParseParameters(); + showTargetOutputs = !String.IsNullOrEmpty(Environment.GetEnvironmentVariable("MSBUILDTARGETOUTPUTLOGGING")); if (showOnlyWarnings || showOnlyErrors) @@ -975,6 +975,9 @@ internal virtual bool ApplyParameter(string parameterName, string parameterValue case "PERFORMANCESUMMARY": showPerfSummary = true; return true; + case "NOPERFORMANCESUMMARY": + showPerfSummary = false; + return true; case "NOSUMMARY": ShowSummary = false; return true; From e270fea3f9f2b442faa563d1408cc591e6de9e09 Mon Sep 17 00:00:00 2001 From: Kirill Osenkov Date: Sun, 4 Apr 2021 18:12:15 -0700 Subject: [PATCH 09/14] Add TestLoggingForSkippedTargetInputsAndOutputs --- .../BackEnd/TargetBuilder_Tests.cs | 37 +++++++++++++++++++ 1 file changed, 37 insertions(+) diff --git a/src/Build.UnitTests/BackEnd/TargetBuilder_Tests.cs b/src/Build.UnitTests/BackEnd/TargetBuilder_Tests.cs index fe416e2e901..3b4d5164eb9 100644 --- a/src/Build.UnitTests/BackEnd/TargetBuilder_Tests.cs +++ b/src/Build.UnitTests/BackEnd/TargetBuilder_Tests.cs @@ -198,6 +198,43 @@ public void TestDependencyBuildWithError() Assert.Equal(TargetResultCode.Success, resultsCache.GetResultForRequest(entry.Request)["Baz"].ResultCode); } + [Fact] + public void TestLoggingForSkippedTargetInputsAndOutputs() + { + string projectContents = @" + + + + +"; + + using (var env = TestEnvironment.Create()) + { + var files = env.CreateTestProjectWithFiles(projectContents, new[] { "a.txt", "b.txt", "c.txt" }); + var fileA = new FileInfo(files.CreatedFiles[0]); + var fileB = new FileInfo(files.CreatedFiles[1]); + var fileC = new FileInfo(files.CreatedFiles[2]); + + var now = DateTime.UtcNow; + fileA.LastWriteTimeUtc = now - TimeSpan.FromSeconds(10); + fileB.LastWriteTimeUtc = now - TimeSpan.FromSeconds(10); + fileC.LastWriteTimeUtc = now; + + var logger = files.BuildProjectExpectSuccess(); + var logText = logger.FullLog.Replace("\r\n", "\n"); + + var expected = @" +Skipping target ""Build"" because all output files are up-to-date with respect to the input files. +Input files: + a.txt + b.txt +Output files: c.txt +Done building target ""Build"" in project ""build.proj"".".Replace("\r\n", "\n"); + + logText.ShouldContainWithoutWhitespace(expected); + } + } + /// /// Ensure that skipped targets only infer outputs once /// From 6fea5650ee1598f3e45a85751c8741b3e3fe868f Mon Sep 17 00:00:00 2001 From: Kirill Osenkov Date: Sun, 4 Apr 2021 18:13:23 -0700 Subject: [PATCH 10/14] Compare console logs after binary logging roundtrip. Turns out we didn't have good coverage for Serial and Parallel console loggers. Include them in the binary logger roundtrip so we verify that logs from playing back a binlog are exactly identical to the logs from the real build. --- src/Build.UnitTests/BinaryLogger_Tests.cs | 35 +++++++++++++++++++++-- 1 file changed, 32 insertions(+), 3 deletions(-) diff --git a/src/Build.UnitTests/BinaryLogger_Tests.cs b/src/Build.UnitTests/BinaryLogger_Tests.cs index 8deb4db94b7..3dd4465ed3a 100644 --- a/src/Build.UnitTests/BinaryLogger_Tests.cs +++ b/src/Build.UnitTests/BinaryLogger_Tests.cs @@ -1,5 +1,8 @@ using System; +using System.Text; +using Microsoft.Build.BackEnd.Logging; using Microsoft.Build.Logging; +using Shouldly; using Xunit; using Xunit.Abstractions; @@ -78,19 +81,45 @@ public void TestBinaryLoggerRoundtrip(string projectText) var mockLogFromBuild = new MockLogger(); - // build and log into binary logger and mockLogger1 - ObjectModelHelpers.BuildProjectExpectSuccess(projectText, binaryLogger, mockLogFromBuild); + var serialFromBuildText = new StringBuilder(); + var serialFromBuild = new SerialConsoleLogger(Framework.LoggerVerbosity.Diagnostic, t => serialFromBuildText.Append(t), colorSet: null, colorReset: null); + serialFromBuild.Parameters = "NOPERFORMANCESUMMARY"; + + var parallelFromBuildText = new StringBuilder(); + var parallelFromBuild = new ParallelConsoleLogger(Framework.LoggerVerbosity.Diagnostic, t => parallelFromBuildText.Append(t), colorSet: null, colorReset: null); + parallelFromBuild.Parameters = "NOPERFORMANCESUMMARY"; + + // build and log into binary logger, mock logger, serial and parallel console loggers + ObjectModelHelpers.BuildProjectExpectSuccess(projectText, binaryLogger, mockLogFromBuild, serialFromBuild, parallelFromBuild); var mockLogFromPlayback = new MockLogger(); + var serialFromPlaybackText = new StringBuilder(); + var serialFromPlayback = new SerialConsoleLogger(Framework.LoggerVerbosity.Diagnostic, t => serialFromPlaybackText.Append(t), colorSet: null, colorReset: null); + serialFromPlayback.Parameters = "NOPERFORMANCESUMMARY"; + + var parallelFromPlaybackText = new StringBuilder(); + var parallelFromPlayback = new ParallelConsoleLogger(Framework.LoggerVerbosity.Diagnostic, t => parallelFromPlaybackText.Append(t), colorSet: null, colorReset: null); + parallelFromPlayback.Parameters = "NOPERFORMANCESUMMARY"; + var binaryLogReader = new BinaryLogReplayEventSource(); mockLogFromPlayback.Initialize(binaryLogReader); + serialFromPlayback.Initialize(binaryLogReader); + parallelFromPlayback.Initialize(binaryLogReader); // read the binary log and replay into mockLogger2 binaryLogReader.Replay(_logFile); // the binlog will have more information than recorded by the text log - Assert.Contains(mockLogFromBuild.FullLog, mockLogFromPlayback.FullLog); + mockLogFromPlayback.FullLog.ShouldContainWithoutWhitespace(mockLogFromBuild.FullLog); + + var serialExpected = serialFromBuildText.ToString(); + var serialActual = serialFromPlaybackText.ToString(); + var parallelExpected = parallelFromBuildText.ToString(); + var parallelActual = parallelFromPlaybackText.ToString(); + + serialActual.ShouldContainWithoutWhitespace(serialExpected); + parallelActual.ShouldContainWithoutWhitespace(parallelExpected); } [Fact] From 1de22cdd815fa1ca7361ca884206caade5bbb8fc Mon Sep 17 00:00:00 2001 From: Kirill Osenkov Date: Sun, 4 Apr 2021 18:48:13 -0700 Subject: [PATCH 11/14] Add more coverage for console logs from binlog playback. Record a binlog every time we build using TestEnvironment, as well as parallel and serial console logs. After the build, playback the binlog into a new serial and console logs and diff the results. This ensures that all events that happen during our test can be correctly played back from a binlog and result in the exact same output. I leave a switch to turn it off for individual tests, but if these prove noisy we can turn this validation off entirely by default (and only turn it back on locally when working on logging related changes). I did have to turn it off for TreatWarningsAsErrorsWhenBuildingSameProjectMultipleTimes because the binlog contained an extra property MSBuildLastTaskResult=true. I'm not exactly sure what is happening there, but one theory is the console log sees the state where that property is not set, then it's being mutated, then the binary log observes the state. Since two logs capture live data from ProjectEvaluationFinished, and access at different times, it may be that this is a case where the evaluation mutates in between. We need to be on the lookout for more cases like this and maybe turn this validation off by default. But it does give us a ton of free coverage for Serial and Parallel loggers. Most of the tests actually only exercise the MockLogger, so it's nice to test the real text loggers too. I measured the overall duration of "build.cmd -test" and got inconclusive numbers. I think there's no obvious evidence that this change slows down the test run by any significant amount. The durations I got are: 07:34.6 07:38.8 06:45.4 06:52.5 08:09.7 07:28.4 06:49.7 07:32.5 and I'm intentionally not telling which one is which to illustrate that there is no obvious slowdown. --- .../WarningsAsMessagesAndErrors_Tests.cs | 4 +- src/Shared/UnitTests/EngineTestEnvironment.cs | 130 ++++++++++++++++-- 2 files changed, 123 insertions(+), 11 deletions(-) diff --git a/src/Build.UnitTests/WarningsAsMessagesAndErrors_Tests.cs b/src/Build.UnitTests/WarningsAsMessagesAndErrors_Tests.cs index 15344781043..d83d61361fa 100644 --- a/src/Build.UnitTests/WarningsAsMessagesAndErrors_Tests.cs +++ b/src/Build.UnitTests/WarningsAsMessagesAndErrors_Tests.cs @@ -59,7 +59,7 @@ public void TreatWarningsAsErrorsWhenBuildingSameProjectMultipleTimes() "); - MockLogger logger = project1.BuildProjectExpectFailure(); + MockLogger logger = project1.BuildProjectExpectFailure(validateLoggerRoundtrip: false); VerifyBuildErrorEvent(logger); } @@ -153,7 +153,7 @@ public void TreatWarningsAsMessagesWhenBuildingSameProjectMultipleTimes() "); - MockLogger logger = project1.BuildProjectExpectSuccess(); + MockLogger logger = project1.BuildProjectExpectSuccess(validateLoggerRoundtrip: false); VerifyBuildMessageEvent(logger); } diff --git a/src/Shared/UnitTests/EngineTestEnvironment.cs b/src/Shared/UnitTests/EngineTestEnvironment.cs index cc55034df19..4641dc5e2b3 100644 --- a/src/Shared/UnitTests/EngineTestEnvironment.cs +++ b/src/Shared/UnitTests/EngineTestEnvironment.cs @@ -1,11 +1,18 @@ // Copyright (c) Microsoft. All rights reserved. // Licensed under the MIT license. See LICENSE file in the project root for full license information. +using System; using System.Collections.Generic; using System.IO; +using System.Linq; using System.Reflection; +using System.Text; +using Microsoft.Build.BackEnd.Logging; using Microsoft.Build.Evaluation; using Microsoft.Build.Execution; +using Microsoft.Build.Framework; +using Microsoft.Build.Logging; +using Microsoft.Build.Shared; using Shouldly; namespace Microsoft.Build.UnitTests @@ -119,15 +126,15 @@ public class TransientTestProjectWithFiles : TransientTestState CreatedFiles = Helpers.CreateFilesInDirectory(TestRoot, files); } - internal MockLogger BuildProjectExpectFailure(IDictionary globalProperties = null, string toolsVersion = null) + internal MockLogger BuildProjectExpectFailure(IDictionary globalProperties = null, string toolsVersion = null, bool validateLoggerRoundtrip = true) { - BuildProject(globalProperties, toolsVersion, out MockLogger logger).ShouldBeFalse(); + BuildProject(globalProperties, toolsVersion, out MockLogger logger, validateLoggerRoundtrip).ShouldBeFalse(); return logger; } - internal MockLogger BuildProjectExpectSuccess(IDictionary globalProperties = null, string toolsVersion = null) + internal MockLogger BuildProjectExpectSuccess(IDictionary globalProperties = null, string toolsVersion = null, bool validateLoggerRoundtrip = true) { - BuildProject(globalProperties, toolsVersion, out MockLogger logger).ShouldBeTrue(); + BuildProject(globalProperties, toolsVersion, out MockLogger logger, validateLoggerRoundtrip).ShouldBeTrue(); return logger; } @@ -136,15 +143,120 @@ public override void Revert() _folder.Revert(); } - private bool BuildProject(IDictionary globalProperties, string toolsVersion, out MockLogger logger) + private IEnumerable<(ILogger logger, Func textGetter)> GetLoggers() { - logger = new MockLogger(); + var result = new List<(ILogger logger, Func textGetter)>(); - using (ProjectCollection projectCollection = new ProjectCollection()) + result.Add(GetMockLogger()); + result.Add(GetBinaryLogger()); + +#if MICROSOFT_BUILD_ENGINE_UNITTESTS + result.Add(GetSerialLogger()); + result.Add(GetParallelLogger()); +#endif + + return result; + } + + private (ILogger logger, Func textGetter) GetMockLogger() + { + var logger = new MockLogger(); + return (logger, () => logger.FullLog); + } + +#if MICROSOFT_BUILD_ENGINE_UNITTESTS + + private (ILogger, Func) GetSerialLogger() + { + var sb = new StringBuilder(); + var serialFromBuild = new SerialConsoleLogger(LoggerVerbosity.Diagnostic, t => sb.Append(t), colorSet: null, colorReset: null); + serialFromBuild.Parameters = "NOPERFORMANCESUMMARY"; + return (serialFromBuild, () => sb.ToString()); + } + + private (ILogger, Func) GetParallelLogger() + { + var sb = new StringBuilder(); + var parallelFromBuild = new ParallelConsoleLogger(LoggerVerbosity.Diagnostic, t => sb.Append(t), colorSet: null, colorReset: null); + parallelFromBuild.Parameters = "NOPERFORMANCESUMMARY"; + return (parallelFromBuild, () => sb.ToString()); + } + +#endif + + private (ILogger, Func) GetBinaryLogger() + { + var binaryLogger = new BinaryLogger(); + string binaryLoggerFilePath = Path.GetFullPath(Path.Combine(TestRoot, Guid.NewGuid().ToString() + ".binlog")); + binaryLogger.CollectProjectImports = BinaryLogger.ProjectImportsCollectionMode.None; + binaryLogger.Parameters = binaryLoggerFilePath; + return (binaryLogger, null); + } + + private bool BuildProject( + IDictionary globalProperties, + string toolsVersion, + out MockLogger mockLogger, + bool validateLoggerRoundtrip = true) + { + var expectedLoggerPairs = validateLoggerRoundtrip ? GetLoggers() : new[] { GetMockLogger() }; + var expectedLoggers = expectedLoggerPairs.Select(l => l.logger).ToArray(); + mockLogger = expectedLoggers.OfType().First(); + var binaryLogger = expectedLoggers.OfType().FirstOrDefault(); + + try { - Project project = new Project(ProjectFile, globalProperties, toolsVersion, projectCollection); + using (ProjectCollection projectCollection = new ProjectCollection()) + { + Project project = new Project(ProjectFile, globalProperties, toolsVersion, projectCollection); + return project.Build(expectedLoggers); + } + } + finally + { + if (binaryLogger != null) + { + string binaryLoggerFilePath = binaryLogger.Parameters; + + var actualLoggerPairs = GetLoggers().Where(l => l.logger is not BinaryLogger).ToArray(); + expectedLoggerPairs = expectedLoggerPairs.Where(l => l.logger is not BinaryLogger).ToArray(); + + PlaybackBinlog(binaryLoggerFilePath, actualLoggerPairs.Select(k => k.logger).ToArray()); + FileUtilities.DeleteNoThrow(binaryLoggerFilePath); + + var pairs = expectedLoggerPairs.Zip(actualLoggerPairs, (expected, actual) => (expected, actual)); - return project.Build(logger); + foreach (var pair in pairs) + { + var expectedText = pair.expected.textGetter(); + var actualText = pair.actual.textGetter(); + actualText.ShouldContainWithoutWhitespace(expectedText); + } + } + } + } + + private static void PlaybackBinlog(string binlogFilePath, params ILogger[] loggers) + { + var replayEventSource = new BinaryLogReplayEventSource(); + + foreach (var logger in loggers) + { + if (logger is INodeLogger nodeLogger) + { + nodeLogger.Initialize(replayEventSource, 1); + } + else + { + logger.Initialize(replayEventSource); + } + } + + replayEventSource.Replay(binlogFilePath); + + foreach (var logger in loggers) + { + logger.Shutdown(); } } } From 785ffa172a295249d05f4f7d7de96890e49538e2 Mon Sep 17 00:00:00 2001 From: Kirill Osenkov Date: Sun, 4 Apr 2021 19:50:56 -0700 Subject: [PATCH 12/14] Fix test to work on unix. --- src/Build.UnitTests/BuildEventArgsSerialization_Tests.cs | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/src/Build.UnitTests/BuildEventArgsSerialization_Tests.cs b/src/Build.UnitTests/BuildEventArgsSerialization_Tests.cs index c8f1761ac0b..f1b59b48e1f 100644 --- a/src/Build.UnitTests/BuildEventArgsSerialization_Tests.cs +++ b/src/Build.UnitTests/BuildEventArgsSerialization_Tests.cs @@ -70,7 +70,7 @@ public void RoundtripProjectStartedEventArgs() projectId: 42, message: "Project \"test.proj\" (Build target(s)):", helpKeyword: "help", - projectFile: "C:\\test.proj", + projectFile: Path.Combine("a", "test.proj"), targetNames: "Build", properties: new List() { new DictionaryEntry("Key", "Value") }, items: new List() { new DictionaryEntry("Key", new MyTaskItem() { ItemSpec = "TestItemSpec" }) }, From 2410c417066c4f51d93652552221b97009ada612 Mon Sep 17 00:00:00 2001 From: Kirill Osenkov Date: Thu, 8 Apr 2021 13:45:29 -0700 Subject: [PATCH 13/14] Fix typo: HelpHeyword -> HelpKeyword. This is safe because the enum is internal and the current name isn't used anywhere. --- src/Build/Logging/BinaryLogger/BuildEventArgsFieldFlags.cs | 2 +- src/Build/Logging/BinaryLogger/BuildEventArgsReader.cs | 4 ++-- src/Build/Logging/BinaryLogger/BuildEventArgsWriter.cs | 4 ++-- 3 files changed, 5 insertions(+), 5 deletions(-) diff --git a/src/Build/Logging/BinaryLogger/BuildEventArgsFieldFlags.cs b/src/Build/Logging/BinaryLogger/BuildEventArgsFieldFlags.cs index dbaec774e03..a9f311ad1fd 100644 --- a/src/Build/Logging/BinaryLogger/BuildEventArgsFieldFlags.cs +++ b/src/Build/Logging/BinaryLogger/BuildEventArgsFieldFlags.cs @@ -10,7 +10,7 @@ internal enum BuildEventArgsFieldFlags { None = 0, BuildEventContext = 1 << 0, - HelpHeyword = 1 << 1, + HelpKeyword = 1 << 1, Message = 1 << 2, SenderName = 1 << 3, ThreadId = 1 << 4, diff --git a/src/Build/Logging/BinaryLogger/BuildEventArgsReader.cs b/src/Build/Logging/BinaryLogger/BuildEventArgsReader.cs index 748f520aca4..47c1f6d8306 100644 --- a/src/Build/Logging/BinaryLogger/BuildEventArgsReader.cs +++ b/src/Build/Logging/BinaryLogger/BuildEventArgsReader.cs @@ -1,4 +1,4 @@ -// Copyright (c) Microsoft. All rights reserved. +// Copyright (c) Microsoft. All rights reserved. // Licensed under the MIT license. See LICENSE file in the project root for full license information. using System; @@ -801,7 +801,7 @@ private BuildEventArgsFields ReadBuildEventArgsFields(bool readImportance = fals result.ThreadId = ReadInt32(); } - if ((flags & BuildEventArgsFieldFlags.HelpHeyword) != 0) + if ((flags & BuildEventArgsFieldFlags.HelpKeyword) != 0) { result.HelpKeyword = ReadDeduplicatedString(); } diff --git a/src/Build/Logging/BinaryLogger/BuildEventArgsWriter.cs b/src/Build/Logging/BinaryLogger/BuildEventArgsWriter.cs index 316fe33ebd6..b3fec8d101d 100644 --- a/src/Build/Logging/BinaryLogger/BuildEventArgsWriter.cs +++ b/src/Build/Logging/BinaryLogger/BuildEventArgsWriter.cs @@ -531,7 +531,7 @@ private void WriteBaseFields(BuildEventArgs e, BuildEventArgsFieldFlags flags) Write(e.ThreadId); } - if ((flags & BuildEventArgsFieldFlags.HelpHeyword) != 0) + if ((flags & BuildEventArgsFieldFlags.HelpKeyword) != 0) { WriteDeduplicatedString(e.HelpKeyword); } @@ -677,7 +677,7 @@ private static BuildEventArgsFieldFlags GetBuildEventArgsFieldFlags(BuildEventAr if (e.HelpKeyword != null) { - flags |= BuildEventArgsFieldFlags.HelpHeyword; + flags |= BuildEventArgsFieldFlags.HelpKeyword; } if (writeMessage) From ca456adfda8e5bc7fe26dfcad7e963ff3cb63cb8 Mon Sep 17 00:00:00 2001 From: Kirill Osenkov Date: Thu, 8 Apr 2021 13:54:09 -0700 Subject: [PATCH 14/14] Add GetResourceEightSpaces Also make a separate bool field initialized. --- .../ResolveAssemblyReference.cs | 23 +++++++++++-------- 1 file changed, 14 insertions(+), 9 deletions(-) diff --git a/src/Tasks/AssemblyDependency/ResolveAssemblyReference.cs b/src/Tasks/AssemblyDependency/ResolveAssemblyReference.cs index 8896a215e0d..169eebec17a 100644 --- a/src/Tasks/AssemblyDependency/ResolveAssemblyReference.cs +++ b/src/Tasks/AssemblyDependency/ResolveAssemblyReference.cs @@ -101,21 +101,26 @@ private static class Strings public static string UnifiedDependency; public static string UnifiedPrimaryReference; + private static bool initialized = false; + internal static void Initialize(TaskLoggingHelper log) { - if (Resolved != null) + if (initialized) { return; } + initialized = true; + string GetResource(string name) => log.GetResourceMessage(name); string GetResourceFourSpaces(string name) => FourSpaces + log.GetResourceMessage(name); + string GetResourceEightSpaces(string name) => EightSpaces + log.GetResourceMessage(name); - ConsideredAndRejectedBecauseFusionNamesDidntMatch = EightSpaces + GetResource("ResolveAssemblyReference.ConsideredAndRejectedBecauseFusionNamesDidntMatch"); - ConsideredAndRejectedBecauseNoFile = EightSpaces + GetResource("ResolveAssemblyReference.ConsideredAndRejectedBecauseNoFile"); - ConsideredAndRejectedBecauseNotAFileNameOnDisk = EightSpaces + GetResource("ResolveAssemblyReference.ConsideredAndRejectedBecauseNotAFileNameOnDisk"); - ConsideredAndRejectedBecauseNotInGac = EightSpaces + GetResource("ResolveAssemblyReference.ConsideredAndRejectedBecauseNotInGac"); - ConsideredAndRejectedBecauseTargetDidntHaveFusionName = EightSpaces + GetResource("ResolveAssemblyReference.ConsideredAndRejectedBecauseTargetDidntHaveFusionName"); + ConsideredAndRejectedBecauseFusionNamesDidntMatch = GetResourceEightSpaces("ResolveAssemblyReference.ConsideredAndRejectedBecauseFusionNamesDidntMatch"); + ConsideredAndRejectedBecauseNoFile = GetResourceEightSpaces("ResolveAssemblyReference.ConsideredAndRejectedBecauseNoFile"); + ConsideredAndRejectedBecauseNotAFileNameOnDisk = GetResourceEightSpaces("ResolveAssemblyReference.ConsideredAndRejectedBecauseNotAFileNameOnDisk"); + ConsideredAndRejectedBecauseNotInGac = GetResourceEightSpaces("ResolveAssemblyReference.ConsideredAndRejectedBecauseNotInGac"); + ConsideredAndRejectedBecauseTargetDidntHaveFusionName = GetResourceEightSpaces("ResolveAssemblyReference.ConsideredAndRejectedBecauseTargetDidntHaveFusionName"); Dependency = GetResource("ResolveAssemblyReference.Dependency"); FormattedAssemblyInfo = GetResourceFourSpaces("ResolveAssemblyReference.FormattedAssemblyInfo"); FoundRelatedFile = GetResourceFourSpaces("ResolveAssemblyReference.FoundRelatedFile"); @@ -123,7 +128,7 @@ internal static void Initialize(TaskLoggingHelper log) FoundScatterFile = GetResourceFourSpaces("ResolveAssemblyReference.FoundScatterFile"); ImageRuntimeVersion = GetResourceFourSpaces("ResolveAssemblyReference.ImageRuntimeVersion"); IsAWinMdFile = GetResourceFourSpaces("ResolveAssemblyReference.IsAWinMdFile"); - LogAttributeFormat = EightSpaces + GetResource("ResolveAssemblyReference.LogAttributeFormat"); + LogAttributeFormat = GetResourceEightSpaces("ResolveAssemblyReference.LogAttributeFormat"); LogTaskPropertyFormat = GetResource("ResolveAssemblyReference.LogTaskPropertyFormat"); NoBecauseParentReferencesFoundInGac = GetResourceFourSpaces("ResolveAssemblyReference.NoBecauseParentReferencesFoundInGac"); NotCopyLocalBecauseConflictVictim = GetResourceFourSpaces("ResolveAssemblyReference.NotCopyLocalBecauseConflictVictim"); @@ -137,9 +142,9 @@ internal static void Initialize(TaskLoggingHelper log) RequiredBy = GetResourceFourSpaces("ResolveAssemblyReference.RequiredBy"); Resolved = GetResourceFourSpaces("ResolveAssemblyReference.Resolved"); ResolvedFrom = GetResourceFourSpaces("ResolveAssemblyReference.ResolvedFrom"); - SearchedAssemblyFoldersEx = EightSpaces + GetResource("ResolveAssemblyReference.SearchedAssemblyFoldersEx"); + SearchedAssemblyFoldersEx = GetResourceEightSpaces("ResolveAssemblyReference.SearchedAssemblyFoldersEx"); SearchPath = EightSpaces + GetResource("ResolveAssemblyReference.SearchPath"); - TargetedProcessorArchitectureDoesNotMatch = EightSpaces + GetResource("ResolveAssemblyReference.TargetedProcessorArchitectureDoesNotMatch"); + TargetedProcessorArchitectureDoesNotMatch = GetResourceEightSpaces("ResolveAssemblyReference.TargetedProcessorArchitectureDoesNotMatch"); UnificationByAppConfig = GetResourceFourSpaces("ResolveAssemblyReference.UnificationByAppConfig"); UnificationByAutoUnify = GetResourceFourSpaces("ResolveAssemblyReference.UnificationByAutoUnify"); UnificationByFrameworkRetarget = GetResourceFourSpaces("ResolveAssemblyReference.UnificationByFrameworkRetarget");