Skip to content

Commit

Permalink
Allow disabling logging of task parameters and item metadata (#5268)
Browse files Browse the repository at this point in the history 
This enables fine-grained control over whether:

 * to log log each parameter (whether input or output)
 * or whether to log item metadata for each ITaskItem[] parameter.

When LogTaskInputs is set the default behavior is still to log all parameters and all item metadata for ITaskItem[] parameters. Since this is very verbose and hurts performance without adding any useful information it is valuable to be able to turn this logging off in certain situations.

This approach allows controlling logging via setting simple properties or environment variables.

I've identified the specific tasks and parameters that we want to restrict logging for that would give us the most gains without losing any significant useful info:

https://github.com/KirillOsenkov/MSBuildStructuredLog/wiki/Task-Parameter-Logging
  • Loading branch information
@KirillOsenkov
KirillOsenkov authored May 1, 2020
1 parent 2cee6d0 commit c7c447b
Show file tree
Hide file tree
Showing 7 changed files with 92 additions and 25 deletions.
2 changes: 2 additions & 0 deletions ref/Microsoft.Build.Framework/net/Microsoft.Build.Framework.cs
View file
Original file line number Diff line number Diff line change
Expand Up @@ -571,6 +571,8 @@ public TaskFinishedEventArgs(string message, string helpKeyword, string projectF
public partial class TaskPropertyInfo
{
public TaskPropertyInfo(string name, System.Type typeOfParameter, bool output, bool required) { }
public bool Log { get { throw null; } set { } }
public bool LogItemMetadata { get { throw null; } set { } }
public string Name { get { throw null; } }
public bool Output { get { throw null; } }
public System.Type PropertyType { get { throw null; } }
Expand Down
2 changes: 2 additions & 0 deletions ref/Microsoft.Build.Framework/netstandard/Microsoft.Build.Framework.cs
View file
Original file line number Diff line number Diff line change
Expand Up @@ -570,6 +570,8 @@ public TaskFinishedEventArgs(string message, string helpKeyword, string projectF
public partial class TaskPropertyInfo
{
public TaskPropertyInfo(string name, System.Type typeOfParameter, bool output, bool required) { }
public bool Log { get { throw null; } set { } }
public bool LogItemMetadata { get { throw null; } set { } }
public string Name { get { throw null; } }
public bool Output { get { throw null; } }
public System.Type PropertyType { get { throw null; } }
Expand Down
6 changes: 4 additions & 2 deletions src/Build/BackEnd/Components/RequestBuilder/IntrinsicTasks/ItemGroupIntrinsicTask.cs
View file
Original file line number Diff line number Diff line change
Expand Up @@ -220,7 +220,8 @@ private void ExecuteAdd(ProjectItemGroupTaskItemInstance child, ItemBucket bucke
var itemGroupText = ItemGroupLoggingHelper.GetParameterText(
ItemGroupLoggingHelper.ItemGroupIncludeLogMessagePrefix,
child.ItemType,
itemsToAdd);
itemsToAdd,
logItemMetadata: true);
LoggingContext.LogCommentFromText(MessageImportance.Low, itemGroupText);
}

Expand Down Expand Up @@ -261,7 +262,8 @@ private void ExecuteRemove(ProjectItemGroupTaskItemInstance child, ItemBucket bu
var itemGroupText = ItemGroupLoggingHelper.GetParameterText(
ItemGroupLoggingHelper.ItemGroupRemoveLogMessage,
child.ItemType,
itemsToRemove);
itemsToRemove,
logItemMetadata: true);
LoggingContext.LogCommentFromText(MessageImportance.Low, itemGroupText);
}

Expand Down
23 changes: 10 additions & 13 deletions src/Build/BackEnd/Components/RequestBuilder/IntrinsicTasks/ItemGroupLoggingHelper.cs
View file
Original file line number Diff line number Diff line change
Expand Up @@ -27,14 +27,6 @@ internal static class ItemGroupLoggingHelper
/// </summary>
internal static int parameterLimit = 200;

/// <summary>
/// Gets a text serialized value of a parameter for logging.
/// </summary>
internal static string GetParameterText(string prefix, string parameterName, params object[] parameterValues)
{
return GetParameterText(prefix, parameterName, (IList)parameterValues);
}

internal static string ItemGroupIncludeLogMessagePrefix = ResourceUtilities.GetResourceString("ItemGroupIncludeLogMessagePrefix");
internal static string ItemGroupRemoveLogMessage = ResourceUtilities.GetResourceString("ItemGroupRemoveLogMessage");
internal static string OutputItemParameterMessagePrefix = ResourceUtilities.GetResourceString("OutputItemParameterMessagePrefix");
Expand All @@ -43,7 +35,7 @@ internal static string GetParameterText(string prefix, string parameterName, par
/// <summary>
/// Gets a text serialized value of a parameter for logging.
/// </summary>
internal static string GetParameterText(string prefix, string parameterName, IList parameterValue)
internal static string GetParameterText(string prefix, string parameterName, IList parameterValue, bool logItemMetadata = true)
{
if (parameterValue == null || parameterValue.Count == 0)
{
Expand Down Expand Up @@ -94,7 +86,7 @@ internal static string GetParameterText(string prefix, string parameterName, ILi
sb.Append(" ");
}

AppendStringFromParameterValue(sb, parameterValue[i]);
AppendStringFromParameterValue(sb, parameterValue[i], logItemMetadata);

if (!specialTreatmentForSingle && i < parameterValue.Count - 1)
{
Expand All @@ -118,7 +110,7 @@ internal static string GetParameterText(string prefix, string parameterName, ILi
/// First line is already indented.
/// Indent of any subsequent line should be 12 spaces.
/// </summary>
internal static string GetStringFromParameterValue(object parameterValue)
internal static string GetStringFromParameterValue(object parameterValue, bool logItemMetadata = true)
{
// fast path for the common case
if (parameterValue is string valueText)
Expand All @@ -128,7 +120,7 @@ internal static string GetStringFromParameterValue(object parameterValue)

using (var sb = new ReuseableStringBuilder())
{
AppendStringFromParameterValue(sb, parameterValue);
AppendStringFromParameterValue(sb, parameterValue, logItemMetadata);
return sb.ToString();
}
}
Expand All @@ -138,7 +130,7 @@ internal static string GetStringFromParameterValue(object parameterValue)
[ThreadStatic]
private static List<KeyValuePair<string, string>> keyValuePairList;

private static void AppendStringFromParameterValue(ReuseableStringBuilder sb, object parameterValue)
private static void AppendStringFromParameterValue(ReuseableStringBuilder sb, object parameterValue, bool logItemMetadata = true)
{
if (parameterValue is string text)
{
Expand All @@ -148,6 +140,11 @@ private static void AppendStringFromParameterValue(ReuseableStringBuilder sb, ob
{
sb.Append(item.ItemSpec);

if (!logItemMetadata)
{
return;
}

var customMetadata = item.CloneCustomMetadata();
int count = customMetadata.Count;

Expand Down
53 changes: 43 additions & 10 deletions src/Build/BackEnd/TaskExecutionHost/TaskExecutionHost.cs
View file
Original file line number Diff line number Diff line change
Expand Up @@ -427,15 +427,17 @@ bool ITaskExecutionHost.GatherTaskOutputs(string parameterName, ElementLocation
// grab the outputs from the task's designated output parameter (which is a .NET property)
Type type = parameter.PropertyType;

EnsureParameterInitialized(parameter, _batchBucket.Lookup);

if (TaskParameterTypeVerifier.IsAssignableToITask(type))
{
ITaskItem[] outputs = GetItemOutputs(parameter);
GatherTaskItemOutputs(outputTargetIsItem, outputTargetName, outputs, parameterLocation);
GatherTaskItemOutputs(outputTargetIsItem, outputTargetName, outputs, parameterLocation, parameter);
}
else if (TaskParameterTypeVerifier.IsValueTypeOutputParameter(type))
{
string[] outputs = GetValueOutputs(parameter);
GatherArrayStringAndValueOutputs(outputTargetIsItem, outputTargetName, outputs, parameterLocation);
GatherArrayStringAndValueOutputs(outputTargetIsItem, outputTargetName, outputs, parameterLocation, parameter);
}
else
{
Expand Down Expand Up @@ -1042,6 +1044,8 @@ out bool parameterSet
{
Type parameterType = parameter.PropertyType;

EnsureParameterInitialized(parameter, _batchBucket.Lookup);

// try to set the parameter
if (TaskParameterTypeVerifier.IsValidScalarInputParameter(parameterType))
{
Expand Down Expand Up @@ -1222,6 +1226,29 @@ ex is FormatException || // bad string representation of a type
return success;
}

private void EnsureParameterInitialized(TaskPropertyInfo parameter, Lookup lookup)
{
if (parameter.Initialized)
{
return;
}

parameter.Initialized = true;

string taskAndParameterName = _taskName + "_" + parameter.Name;
string key = "DisableLogTaskParameter_" + taskAndParameterName;
string metadataKey = "DisableLogTaskParameterItemMetadata_" + taskAndParameterName;

if (string.Equals(lookup.GetProperty(key)?.EvaluatedValue, "true", StringComparison.OrdinalIgnoreCase))
{
parameter.Log = false;
}
else if (string.Equals(lookup.GetProperty(metadataKey)?.EvaluatedValue, "true", StringComparison.OrdinalIgnoreCase))
{
parameter.LogItemMetadata = false;
}
}

/// <summary>
/// Given an instantiated task, this helper method sets the specified vector parameter. Vector parameters can be composed
/// of multiple item vectors. The semicolon is the only separator allowed, and white space around the semicolon is
Expand Down Expand Up @@ -1283,12 +1310,16 @@ out bool taskParameterSet
/// </remarks>
private bool InternalSetTaskParameter(TaskPropertyInfo parameter, IList parameterValue)
{
if (LogTaskInputs && !_taskLoggingContext.LoggingService.OnlyLogCriticalEvents && parameterValue.Count > 0)
if (LogTaskInputs &&
!_taskLoggingContext.LoggingService.OnlyLogCriticalEvents &&
parameterValue.Count > 0 &&
parameter.Log)
{
string parameterText = ItemGroupLoggingHelper.GetParameterText(
ItemGroupLoggingHelper.TaskParameterPrefix,
parameter.Name,
parameterValue);
parameterValue,
parameter.LogItemMetadata);
_taskLoggingContext.LogCommentFromText(MessageImportance.Low, parameterText);
}

Expand Down Expand Up @@ -1370,7 +1401,7 @@ object parameterValue
/// <summary>
/// Gets task item outputs
/// </summary>
private void GatherTaskItemOutputs(bool outputTargetIsItem, string outputTargetName, ITaskItem[] outputs, ElementLocation parameterLocation)
private void GatherTaskItemOutputs(bool outputTargetIsItem, string outputTargetName, ITaskItem[] outputs, ElementLocation parameterLocation, TaskPropertyInfo parameter)
{
// if the task has generated outputs (if it didn't, don't do anything)
if (outputs != null)
Expand Down Expand Up @@ -1425,12 +1456,13 @@ private void GatherTaskItemOutputs(bool outputTargetIsItem, string outputTargetN
}
}

if (LogTaskInputs && !_taskLoggingContext.LoggingService.OnlyLogCriticalEvents && outputs.Length > 0)
if (LogTaskInputs && !_taskLoggingContext.LoggingService.OnlyLogCriticalEvents && outputs.Length > 0 && parameter.Log)
{
string parameterText = ItemGroupLoggingHelper.GetParameterText(
ItemGroupLoggingHelper.OutputItemParameterMessagePrefix,
outputTargetName,
outputs);
outputs,
parameter.LogItemMetadata);

_taskLoggingContext.LogCommentFromText(MessageImportance.Low, parameterText);
}
Expand Down Expand Up @@ -1483,7 +1515,7 @@ private void GatherTaskItemOutputs(bool outputTargetIsItem, string outputTargetN
/// <summary>
/// Gather task outputs in array form
/// </summary>
private void GatherArrayStringAndValueOutputs(bool outputTargetIsItem, string outputTargetName, string[] outputs, ElementLocation parameterLocation)
private void GatherArrayStringAndValueOutputs(bool outputTargetIsItem, string outputTargetName, string[] outputs, ElementLocation parameterLocation, TaskPropertyInfo parameter)
{
// if the task has generated outputs (if it didn't, don't do anything)
if (outputs != null)
Expand All @@ -1501,12 +1533,13 @@ private void GatherArrayStringAndValueOutputs(bool outputTargetIsItem, string ou
}
}

if (LogTaskInputs && !_taskLoggingContext.LoggingService.OnlyLogCriticalEvents && outputs.Length > 0)
if (LogTaskInputs && !_taskLoggingContext.LoggingService.OnlyLogCriticalEvents && outputs.Length > 0 && parameter.Log)
{
string parameterText = ItemGroupLoggingHelper.GetParameterText(
ItemGroupLoggingHelper.OutputItemParameterMessagePrefix,
outputTargetName,
outputs);
outputs,
parameter.LogItemMetadata);
_taskLoggingContext.LogCommentFromText(MessageImportance.Low, parameterText);
}
}
Expand Down
15 changes: 15 additions & 0 deletions src/Framework/TaskPropertyInfo.cs
View file
Original file line number Diff line number Diff line change
Expand Up @@ -46,5 +46,20 @@ public TaskPropertyInfo(string name, Type typeOfParameter, bool output, bool req
/// This task parameter is required (analogous to the [Required] attribute)
/// </summary>
public bool Required { get; private set; }

/// <summary>
/// This task parameter should be logged when LogTaskInputs is set. Defaults to true.
/// </summary>
public bool Log { get; set; } = true;

/// <summary>
/// When this task parameter is an item list, determines whether to log item metadata. Defaults to true.
/// </summary>
public bool LogItemMetadata { get; set; } = true;

/// <summary>
/// Whether the Log and LogItemMetadata properties have been assigned already.
/// </summary>
internal bool Initialized = false;
}
}
16 changes: 16 additions & 0 deletions src/Tasks/Microsoft.Common.props
View file
Original file line number Diff line number Diff line change
Expand Up @@ -174,4 +174,20 @@ Copyright (C) Microsoft Corporation. All rights reserved.
<NuGetPropsFile Condition="'$(NuGetPropsFile)'==''">$(MSBuildToolsPath)\NuGet.props</NuGetPropsFile>
</PropertyGroup>
<Import Condition="Exists('$(NuGetPropsFile)')" Project="$(NuGetPropsFile)" />

<PropertyGroup Condition=" '$(MSBuildLogVerboseTaskParameters)' != 'true' ">
<DisableLogTaskParameter_ConvertToAbsolutePath_Path>true</DisableLogTaskParameter_ConvertToAbsolutePath_Path>
<DisableLogTaskParameter_FindUnderPath_OutOfPath>true</DisableLogTaskParameter_FindUnderPath_OutOfPath>
<DisableLogTaskParameter_RemoveDuplicates_Inputs>true</DisableLogTaskParameter_RemoveDuplicates_Inputs>
<DisableLogTaskParameterItemMetadata_ConvertToAbsolutePath_AbsolutePaths>true</DisableLogTaskParameterItemMetadata_ConvertToAbsolutePath_AbsolutePaths>
<DisableLogTaskParameterItemMetadata_Copy_CopiedFiles>true</DisableLogTaskParameterItemMetadata_Copy_CopiedFiles>
<DisableLogTaskParameterItemMetadata_Copy_DestinationFiles>true</DisableLogTaskParameterItemMetadata_Copy_DestinationFiles>
<DisableLogTaskParameterItemMetadata_Copy_SourceFiles>true</DisableLogTaskParameterItemMetadata_Copy_SourceFiles>
<DisableLogTaskParameterItemMetadata_FindUnderPath_Files>true</DisableLogTaskParameterItemMetadata_FindUnderPath_Files>
<DisableLogTaskParameterItemMetadata_FindUnderPath_InPath>true</DisableLogTaskParameterItemMetadata_FindUnderPath_InPath>
<DisableLogTaskParameterItemMetadata_GenerateResource_FilesWritten>true</DisableLogTaskParameterItemMetadata_GenerateResource_FilesWritten>
<DisableLogTaskParameterItemMetadata_Hash_ItemsToHash>true</DisableLogTaskParameterItemMetadata_Hash_ItemsToHash>
<DisableLogTaskParameterItemMetadata_RemoveDuplicates_Filtered>true</DisableLogTaskParameterItemMetadata_RemoveDuplicates_Filtered>
<DisableLogTaskParameterItemMetadata_WriteLinesToFile_Lines>true</DisableLogTaskParameterItemMetadata_WriteLinesToFile_Lines>
</PropertyGroup>
</Project>

0 comments on commit c7c447b

Please sign in to comment.