Skip to content

Log properties initial value #4192

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Closed
aelij wants to merge 7 commits into from
Closed

Log properties initial value #4192

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
7 commits
Select commit Hold shift + click to select a range
3d55bd2
Log properties initial value
aelij Feb 21, 2019
5e83a29
Merge from master
aelij Feb 21, 2019
6a09e84
Update xlf files
aelij Feb 21, 2019
c65975a
Adding Environment, Toolset and Global sources
aelij Feb 21, 2019
63204ff
Fix order
aelij Feb 21, 2019
993b725
PR comments
aelij Feb 26, 2019
ad6efda
Skip logging properties when OnlyLogCriticalEvents is true
aelij Mar 31, 2019
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
27 changes: 21 additions & 6 deletions src/Build.UnitTests/Evaluation/Evaluator_Tests.cs
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -670,6 +670,7 @@ public void LogPropertyAssignments()
string testtargets = ObjectModelHelpers.CleanupFileContents(@"
<Project xmlns='msbuildnamespace'>
<PropertyGroup>
<GlobalProp>FinalValue</GlobalProp>
<Prop>OldValue</Prop>
<Prop>NewValue</Prop>
</PropertyGroup>
Expand All @@ -682,22 +683,35 @@ public void LogPropertyAssignments()
string testTargetPath = Path.Combine(targetDirectory, "test.proj");

bool originalValue = BuildParameters.WarnOnUninitializedProperty;

string oldEnvironmentValue = Environment.GetEnvironmentVariable("GlobalProp");

try
{
Environment.SetEnvironmentVariable("GlobalProp", "EnvironmentValue");

BuildParameters.WarnOnUninitializedProperty = true;
Directory.CreateDirectory(targetDirectory);
File.WriteAllText(testTargetPath, testtargets);

MockLogger logger = new MockLogger();
logger.Verbosity = LoggerVerbosity.Diagnostic;
ProjectCollection pc = new ProjectCollection();
ProjectCollection pc = new ProjectCollection(new Dictionary<string, string>
{
["GlobalProp"] = "GlobalValue"
});
pc.RegisterLogger(logger);
Project project = pc.LoadProject(testTargetPath);

bool result = project.Build();
Assert.True(result);
logger.AssertLogContains("Evaluation started");
logger.AssertLogContains("Property reassignment");
logger.AssertLogContains("Property initial value: $(GlobalProp)=\"EnvironmentValue\" Source: Environment");
logger.AssertLogContains("Property reassignment: $(GlobalProp)=\"GlobalValue\" (previous value: \"EnvironmentValue\") Source: Global");
logger.AssertLogContains("The \"GlobalProp\" property is a global property, and cannot be modified.");
logger.AssertLogContains($"Property initial value: $(Prop)=\"OldValue\" Source: {testTargetPath}");
logger.AssertLogContains($"Property reassignment: $(Prop)=\"NewValue\" (previous value: \"OldValue\") Source: {testTargetPath}");
logger.AssertLogContains($"Property initial value: $(VisualStudioVersion)=\"{MSBuildConstants.CurrentVisualStudioVersion}\" Source: Toolset");
logger.AssertLogContains("Evaluation finished");
logger.AssertLogContains("Prop");
logger.AssertLogContains("OldValue");
Expand All @@ -707,6 +721,7 @@ public void LogPropertyAssignments()
{
BuildParameters.WarnOnUninitializedProperty = originalValue;
FileUtilities.DeleteWithoutTrailingBackslash(targetDirectory, true);
Environment.SetEnvironmentVariable("GlobalProp", oldEnvironmentValue);
}
}

Expand Down Expand Up @@ -4388,10 +4403,10 @@ public void ThrownInvalidProjectExceptionProperlyHandled()
File.WriteAllText(primaryProject, projectContents);
File.WriteAllText(import, importContents);

InvalidProjectFileException ex = Assert.Throws<InvalidProjectFileException>( () =>
{
Project unused = new Project(primaryProject, null, null);
})
InvalidProjectFileException ex = Assert.Throws<InvalidProjectFileException>(() =>
{
Project unused = new Project(primaryProject, null, null);
})
;

Assert.Contains("<AnInvalidTopLevelElement>", ex.Message);
Expand Down
113 changes: 75 additions & 38 deletions src/Build/Evaluation/Evaluator.cs
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -151,7 +151,7 @@ internal class Evaluator<P, I, M, D>
/// The current build submission ID.
/// </summary>
private readonly int _submissionId;

private readonly EvaluationContext _evaluationContext;

/// <summary>
Expand Down Expand Up @@ -604,11 +604,23 @@ private static ProjectTargetInstance ReadNewTargetElement(ProjectTargetElement t
/// </summary>
private void Evaluate(ILoggingService loggingService, BuildEventContext buildEventContext)
{
string projectFile;
string projectFile = String.IsNullOrEmpty(_projectRootElement.ProjectFileLocation.File) ? "(null)" : _projectRootElement.ProjectFileLocation.File;
Comment thread
aelij marked this conversation as resolved.

using (_evaluationProfiler.TrackPass(EvaluationPass.TotalEvaluation))
{
ErrorUtilities.VerifyThrow(_data.EvaluationId == BuildEventContext.InvalidEvaluationId, "There is no prior evaluation ID. The evaluator data needs to be reset at this point");

_evaluationLoggingContext = new EvaluationLoggingContext(loggingService, buildEventContext, projectFile);
_data.EvaluationId = _evaluationLoggingContext.BuildEventContext.EvaluationId;

#if (!STANDALONEBUILD)
CodeMarkers.Instance.CodeMarker(CodeMarkerEvent.perfMSBuildProjectEvaluatePass0End);
#endif

_evaluationLoggingContext.LogProjectEvaluationStarted();

ErrorUtilities.VerifyThrow(_data.EvaluationId != BuildEventContext.InvalidEvaluationId, "Evaluation should produce an evaluation ID");

_logProjectImportedEvents = Traits.Instance.EscapeHatches.LogProjectImports;

ICollection<P> builtInProperties;
Expand All @@ -631,18 +643,6 @@ private void Evaluate(ILoggingService loggingService, BuildEventContext buildEve
}
}

#if (!STANDALONEBUILD)
CodeMarkers.Instance.CodeMarker(CodeMarkerEvent.perfMSBuildProjectEvaluatePass0End);
#endif
projectFile = String.IsNullOrEmpty(_projectRootElement.ProjectFileLocation.File) ? "(null)" : _projectRootElement.ProjectFileLocation.File;

_evaluationLoggingContext = new EvaluationLoggingContext(loggingService, buildEventContext, projectFile);
_data.EvaluationId = _evaluationLoggingContext.BuildEventContext.EvaluationId;

_evaluationLoggingContext.LogProjectEvaluationStarted();

ErrorUtilities.VerifyThrow(_data.EvaluationId != BuildEventContext.InvalidEvaluationId, "Evaluation should produce an evaluation ID");

#if MSBUILDENABLEVSPROFILING
string endPass0 = String.Format(CultureInfo.CurrentCulture, "Evaluate Project {0} - End Pass 0 (Initial properties)", projectFile);
DataCollection.CommentMarkProfile(8816, endPass0);
Expand Down Expand Up @@ -1009,7 +1009,7 @@ private void UpdateDefaultTargets(ProjectRootElement currentProjectOrImport)
private void EvaluatePropertyGroupElement(ProjectPropertyGroupElement propertyGroupElement)
{
using (_evaluationProfiler.TrackElement(propertyGroupElement))
{
{
if (EvaluateConditionCollectingConditionedProperties(propertyGroupElement, ExpanderOptions.ExpandProperties, ParserOptions.AllowProperties))
{
foreach (ProjectPropertyElement propertyElement in propertyGroupElement.Properties)
Expand Down Expand Up @@ -1256,8 +1256,10 @@ private ICollection<P> AddEnvironmentProperties()

foreach (ProjectPropertyInstance environmentProperty in _environmentProperties)
{
P predecessor = _data.GetProperty(environmentProperty.Name);
P property = _data.SetProperty(environmentProperty.Name, ((IProperty)environmentProperty).EvaluatedValueEscaped, false /* NOT global property */, false /* may NOT be a reserved name */);
environmentPropertiesList.Add(property);
LogPropertyAssignment(predecessor, property, PropertySources.Environment);
}

return environmentPropertiesList;
Expand All @@ -1272,7 +1274,7 @@ private ICollection<P> AddToolsetProperties()

foreach (ProjectPropertyInstance toolsetProperty in _data.Toolset.Properties.Values)
{
P property = _data.SetProperty(toolsetProperty.Name, ((IProperty)toolsetProperty).EvaluatedValueEscaped, false /* NOT global property */, false /* may NOT be a reserved name */);
P property = SetProperty(PropertySources.Toolset, toolsetProperty);
toolsetProperties.Add(property);
}

Expand All @@ -1282,8 +1284,8 @@ private ICollection<P> AddToolsetProperties()
// is most likely not a subtoolset now, we need to add VisualStudioVersion if its not already a property.
if (!_data.Properties.Contains(Constants.VisualStudioVersionPropertyName))
{
P subToolsetVersionProperty = _data.SetProperty(Constants.VisualStudioVersionPropertyName, MSBuildConstants.CurrentVisualStudioVersion, false /* NOT global property */, false /* may NOT be a reserved name */);
toolsetProperties.Add(subToolsetVersionProperty);
P property = SetProperty(PropertySources.Toolset, Constants.VisualStudioVersionPropertyName, MSBuildConstants.CurrentVisualStudioVersion);
toolsetProperties.Add(property);
}
}
else
Expand All @@ -1295,15 +1297,15 @@ private ICollection<P> AddToolsetProperties()
// set the property even if there is no matching sub-toolset.
if (!_data.Properties.Contains(Constants.SubToolsetVersionPropertyName))
{
P subToolsetVersionProperty = _data.SetProperty(Constants.SubToolsetVersionPropertyName, _data.SubToolsetVersion, false /* NOT global property */, false /* may NOT be a reserved name */);
toolsetProperties.Add(subToolsetVersionProperty);
P property = SetProperty(PropertySources.Toolset, Constants.SubToolsetVersionPropertyName, _data.SubToolsetVersion);
toolsetProperties.Add(property);
}

if (_data.Toolset.SubToolsets.TryGetValue(_data.SubToolsetVersion, out subToolset))
{
foreach (ProjectPropertyInstance subToolsetProperty in subToolset.Properties.Values)
{
P property = _data.SetProperty(subToolsetProperty.Name, ((IProperty)subToolsetProperty).EvaluatedValueEscaped, false /* NOT global property */, false /* may NOT be a reserved name */);
P property = SetProperty(PropertySources.Toolset, subToolsetProperty);
toolsetProperties.Add(property);
}
}
Expand All @@ -1326,7 +1328,7 @@ private ICollection<P> AddGlobalProperties()

foreach (ProjectPropertyInstance globalProperty in _data.GlobalPropertiesDictionary)
{
P property = _data.SetProperty(globalProperty.Name, ((IProperty)globalProperty).EvaluatedValueEscaped, true /* IS global property */, false /* may NOT be a reserved name */);
P property = SetProperty(PropertySources.Global, globalProperty, isGlobalProperty: true);
globalProperties.Add(property);
}

Expand Down Expand Up @@ -1397,19 +1399,52 @@ private void EvaluatePropertyElement(ProjectPropertyElement propertyElement)

P property = _data.SetProperty(propertyElement, evaluatedValue, predecessor);

if (predecessor != null)
if (!_evaluationLoggingContext.LoggingService.OnlyLogCriticalEvents)
{
LogPropertyReassignment(predecessor, property, propertyElement.Location.LocationString);
LogPropertyAssignment(predecessor, property, propertyElement.Location.LocationString);
}
}
}

private void LogPropertyReassignment(P predecessor, P property, string location)
private P SetProperty(string propertySource, ProjectPropertyInstance propertyInstance, bool isGlobalProperty = false, bool mayBeReserved = false)
{
string propertyName = propertyInstance.Name;
string propertyValue = ((IProperty)propertyInstance).EvaluatedValueEscaped;
return SetProperty(propertySource, propertyName, propertyValue, predecessor: null, isGlobalProperty, mayBeReserved);
}

private P SetProperty(string propertySource, string propertyName, string propertyValue, P predecessor = null, bool isGlobalProperty = false, bool mayBeReserved = false)
{
if (predecessor == null && !_evaluationLoggingContext.LoggingService.OnlyLogCriticalEvents)
{
predecessor = _data.GetProperty(propertyName);
}

P property = _data.SetProperty(propertyName, propertyValue, isGlobalProperty, mayBeReserved);

if (!_evaluationLoggingContext.LoggingService.OnlyLogCriticalEvents)
{
LogPropertyAssignment(predecessor, property, propertySource);
}

return property;
}

private void LogPropertyAssignment(P predecessor, P property, string location)
{
string newValue = property.EvaluatedValue;
string oldValue = predecessor.EvaluatedValue;
string oldValue = predecessor?.EvaluatedValue;

if (newValue != oldValue)
if (oldValue == null)
{
_evaluationLoggingContext.LogComment(
MessageImportance.Low,
"PropertyAssignment",
property.Name,
newValue,
location);
}
else if (newValue != oldValue)
{
_evaluationLoggingContext.LogComment(
MessageImportance.Low,
Expand Down Expand Up @@ -1755,7 +1790,7 @@ private void EvaluateImportElement(string directoryOfImportingFile, ProjectImpor
foreach (ProjectRootElement importedProjectRootElement in importedProjectRootElements)
{
_data.RecordImport(importElement, importedProjectRootElement, importedProjectRootElement.Version, sdkResult);

PerformDepthFirstPass(importedProjectRootElement);
}
}
Expand Down Expand Up @@ -1923,7 +1958,7 @@ private List<ProjectRootElement> ExpandAndLoadImports(string directoryOfImportin
var pathsToSearch = new string[fallbackSearchPathMatch.SearchPaths.Count + 1];
pathsToSearch[0] = prop?.EvaluatedValue; // The actual value of the property, with no fallbacks
fallbackSearchPathMatch.SearchPaths.CopyTo(pathsToSearch, 1); // The list of fallbacks, in order

string extensionPropertyRefAsString = fallbackSearchPathMatch.MsBuildPropertyFormat;

_evaluationLoggingContext.LogComment(MessageImportance.Low, "SearchPathsForMSBuildExtensionsPath",
Expand Down Expand Up @@ -2422,7 +2457,7 @@ private LoadImportsResult ExpandAndLoadImportsFromUnescapedImportExpression(stri
// can store the unescaped value. The only purpose of escaping is to
// avoid undesired splitting or expansion.
_importsSeen.Add(importFileUnescaped, importElement);
}
}
}

if (imports.Count > 0)
Expand Down Expand Up @@ -2677,20 +2712,22 @@ private void SetAllProjectsProperty()
{
P oldValue = _data.GetProperty(Constants.MSBuildAllProjectsPropertyName);

P newValue = _data.SetProperty(
SetProperty(
propertySource: string.Empty,
Constants.MSBuildAllProjectsPropertyName,
oldValue == null
? _lastModifiedProject.FullPath
: $"{_lastModifiedProject.FullPath};{oldValue.EvaluatedValue}",
isGlobalProperty: false,
mayBeReserved: false);

if (oldValue != null)
{
LogPropertyReassignment(oldValue, newValue, String.Empty);
}
oldValue);
}
}

private static class PropertySources
{
public const string Environment = nameof(Environment);
public const string Toolset = nameof(Toolset);
public const string Global = nameof(Global);
}
}

/// <summary>
Expand Down
5 changes: 4 additions & 1 deletion src/Build/Resources/Strings.resx
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -740,6 +740,9 @@
<value>MSB4192: The project file "{0}" is in the ".vcproj" file format, which MSBuild no longer supports. Please convert the project by opening it in the Visual Studio IDE or running the conversion tool, or use MSBuild 3.5 or earlier to build it.</value>
<comment>{StrBegin="MSB4192: "} LOC: ".vcproj" should not be localized</comment>
</data>
<data name="PropertyAssignment" UESanitized="false" Visibility="Public">
<value>Property initial value: $({0})="{1}" Source: {2}</value>
</data>
<data name="PropertyListHeader" UESanitized="false" Visibility="Public">
<value>Initial Properties:</value>
</data>
Expand All @@ -748,7 +751,7 @@
<comment>{StrBegin="MSB4148: "}</comment>
</data>
<data name="PropertyReassignment" UESanitized="false" Visibility="Public">
<value>Property reassignment: $({0})="{1}" (previous value: "{2}") at {3}</value>
<value>Property reassignment: $({0})="{1}" (previous value: "{2}") Source: {3}</value>
</data>
<data name="QualifiedMetadataInTransformNotAllowed" UESanitized="false" Visibility="Public">
<value>MSB4043: The item metadata reference "{0}" is invalid because it is qualified with an item name. Item metadata referenced in transforms do not need to be qualified, because the item name is automatically deduced from the items being transformed. Change "{0}" to "%({1})".</value>
Expand Down
9 changes: 7 additions & 2 deletions src/Build/Resources/xlf/Strings.cs.xlf
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -108,6 +108,11 @@
LOCALIZATION: Do not localize the following words: ProjectGraph, ProjectReference, ToolsVersion.
</note>
</trans-unit>
<trans-unit id="PropertyAssignment">
<source>Property initial value: $({0})="{1}" Source: {2}</source>
<target state="new">Property initial value: $({0})="{1}" Source: {2}</target>
<note />
</trans-unit>
<trans-unit id="UndeclaredMSBuildTasksNotAllowedInIsolatedGraphBuilds">
<source>MSB4254: The MSBuild task is building project(s) {0} which are not specified in the ProjectReference item. In isolated builds this probably means that the references are not explicitly specified as a ProjectReference item in "{1}"</source>
<target state="translated">MSB4254: Úloha MSBuild sestavuje projekty {0}, které nejsou zadané v položce ProjectReference. V izolovaných sestaveních to pravděpodobně znamená, že tyto odkazy nejsou v {1} explicitně zadané jako položka ProjectReference.</target>
Expand Down Expand Up @@ -2091,8 +2096,8 @@ Využití: Průměrné využití {0}: {1:###.0}</target>
<note>{StrBegin="MSB4232: "} Target, Include, Update, and Remove should not be localized and their casing should not be changed</note>
</trans-unit>
<trans-unit id="PropertyReassignment">
<source>Property reassignment: $({0})="{1}" (previous value: "{2}") at {3}</source>
<target state="translated">Opětovné přiřazení vlastnosti: $({0})={1} (předchozí hodnota: {2}) v {3}</target>
<source>Property reassignment: $({0})="{1}" (previous value: "{2}") Source: {3}</source>
<target state="needs-review-translation">Opětovné přiřazení vlastnosti: $({0})={1} (předchozí hodnota: {2}) v {3}</target>
<note />
</trans-unit>
<trans-unit id="CouldNotResolveSdk">
Expand Down
Loading