Skip to content

Commit a1f4262

Browse files
JanKrivanekJanKrivanek
authored
Emit eval props if requested by any sink (#10243)
* Emit eval props if requested by any sink * Ensure non-null props/items on ProjectStartedEventArgs * Hide change behind changewave * Fix unit tests * Fix failing unit test * Add argument name in tests * Fix style * Fix tests * Enable independent eval props population on ProjectStarted and EvaluationFinished events * Prevent SO Exception * Fix unit tests * Reintroduce skipping the tests on core
1 parent 48e81c6 commit a1f4262

15 files changed

Lines changed: 176 additions & 93 deletions

File tree

‎documentation/wiki/ChangeWaves.md‎

Lines changed: 1 addition & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -28,6 +28,7 @@ A wave of features is set to "rotate out" (i.e. become standard functionality) t
2828
- [Convert.ToString during a property evaluation uses the InvariantCulture for all types](https://github.com/dotnet/msbuild/pull/9874)
2929
- [Fix oversharing of build results in ResultsCache](https://github.com/dotnet/msbuild/pull/9987)
3030
- [Add ParameterName and PropertyName to TaskParameterEventArgs](https://github.com/dotnet/msbuild/pull/10130)
31+
- [Emit eval props if requested by any sink](https://github.com/dotnet/msbuild/pull/10243)
3132

3233
### 17.10
3334
- [AppDomain configuration is serialized without using BinFmt](https://github.com/dotnet/msbuild/pull/9320) - feature can be opted out only if [BinaryFormatter](https://learn.microsoft.com/en-us/dotnet/api/system.runtime.serialization.formatters.binary.binaryformatter) is allowed at runtime by editing `MSBuild.runtimeconfig.json`

‎src/Build.UnitTests/BackEnd/BuildManager_Tests.cs‎

Lines changed: 40 additions & 19 deletions
Original file line numberDiff line numberDiff line change
@@ -82,7 +82,7 @@ public BuildManager_Tests(ITestOutputHelper output)
8282
EnableNodeReuse = false
8383
};
8484
_buildManager = new BuildManager();
85-
_projectCollection = new ProjectCollection();
85+
_projectCollection = new ProjectCollection(globalProperties: null, _parameters.Loggers, ToolsetDefinitionLocations.Default);
8686

8787
_env = TestEnvironment.Create(output);
8888
_inProcEnvCheckTransientEnvironmentVariable = _env.SetEnvironmentVariable("MSBUILDINPROCENVCHECK", "1");
@@ -137,8 +137,8 @@ public void SimpleBuild()
137137
_logger.AssertLogContains("[success]");
138138
Assert.Single(_logger.ProjectStartedEvents);
139139

140-
ProjectStartedEventArgs projectStartedEvent = _logger.ProjectStartedEvents[0];
141-
Dictionary<string, string> properties = ExtractProjectStartedPropertyList(projectStartedEvent.Properties);
140+
ProjectEvaluationFinishedEventArgs evalFinishedEvent = _logger.EvaluationFinishedEvents[0];
141+
Dictionary<string, string> properties = ExtractProjectStartedPropertyList(evalFinishedEvent.Properties);
142142

143143
Assert.True(properties.TryGetValue("InitialProperty1", out string propertyValue));
144144
Assert.Equal("InitialProperty1", propertyValue);
@@ -254,8 +254,8 @@ public void SimpleGraphBuild()
254254
_logger.AssertLogContains("[success]");
255255
_logger.ProjectStartedEvents.Count.ShouldBe(1);
256256

257-
ProjectStartedEventArgs projectStartedEvent = _logger.ProjectStartedEvents[0];
258-
Dictionary<string, string> properties = ExtractProjectStartedPropertyList(projectStartedEvent.Properties);
257+
ProjectEvaluationFinishedEventArgs evalFinishedEvent = _logger.EvaluationFinishedEvents[0];
258+
Dictionary<string, string> properties = ExtractProjectStartedPropertyList(evalFinishedEvent.Properties);
259259

260260
properties.TryGetValue("InitialProperty1", out string propertyValue).ShouldBeTrue();
261261
propertyValue.ShouldBe("InitialProperty1", StringCompareShould.IgnoreCase);
@@ -571,8 +571,8 @@ public void InProcForwardPropertiesFromChild()
571571
_logger.AssertLogContains("[success]");
572572
Assert.Single(_logger.ProjectStartedEvents);
573573

574-
ProjectStartedEventArgs projectStartedEvent = _logger.ProjectStartedEvents[0];
575-
Dictionary<string, string> properties = ExtractProjectStartedPropertyList(projectStartedEvent.Properties);
574+
ProjectEvaluationFinishedEventArgs evalFinishedEvent = _logger.EvaluationFinishedEvents[0];
575+
Dictionary<string, string> properties = ExtractProjectStartedPropertyList(evalFinishedEvent.Properties);
576576

577577
Assert.True(properties.TryGetValue("InitialProperty1", out string propertyValue));
578578
Assert.Equal("InitialProperty1", propertyValue);
@@ -611,8 +611,8 @@ public void InProcMsBuildForwardAllPropertiesFromChild()
611611
_logger.AssertLogContains("[success]");
612612
Assert.Single(_logger.ProjectStartedEvents);
613613

614-
ProjectStartedEventArgs projectStartedEvent = _logger.ProjectStartedEvents[0];
615-
Dictionary<string, string> properties = ExtractProjectStartedPropertyList(projectStartedEvent.Properties);
614+
ProjectEvaluationFinishedEventArgs evalFinishedEvent = _logger.EvaluationFinishedEvents[0];
615+
Dictionary<string, string> properties = ExtractProjectStartedPropertyList(evalFinishedEvent.Properties);
616616

617617
Assert.True(properties.TryGetValue("InitialProperty1", out string propertyValue));
618618
Assert.Equal("InitialProperty1", propertyValue);
@@ -655,8 +655,8 @@ public void MsBuildForwardAllPropertiesFromChildLaunchChildNode()
655655
_logger.AssertLogContains("[success]");
656656
Assert.Single(_logger.ProjectStartedEvents);
657657

658-
ProjectStartedEventArgs projectStartedEvent = _logger.ProjectStartedEvents[0];
659-
Dictionary<string, string> properties = ExtractProjectStartedPropertyList(projectStartedEvent.Properties);
658+
ProjectEvaluationFinishedEventArgs evalFinishedEvent = _logger.EvaluationFinishedEvents[0];
659+
Dictionary<string, string> properties = ExtractProjectStartedPropertyList(evalFinishedEvent.Properties);
660660

661661
Assert.True(properties.TryGetValue("InitialProperty1", out string propertyValue));
662662
Assert.Equal("InitialProperty1", propertyValue);
@@ -704,7 +704,15 @@ public void OutOfProcNodeForwardCertainproperties()
704704
var data = new BuildRequestData(project.FullPath, new Dictionary<string, string>(),
705705
MSBuildDefaultToolsVersion, Array.Empty<string>(), null);
706706

707-
BuildResult result = _buildManager.Build(_parameters, data);
707+
// We need to recreate build parameters to ensure proper capturing of newly set environment variables
708+
BuildParameters parameters = new BuildParameters
709+
{
710+
ShutdownInProcNodeOnBuildFinish = true,
711+
Loggers = new ILogger[] { _logger },
712+
EnableNodeReuse = false
713+
};
714+
715+
BuildResult result = _buildManager.Build(parameters, data);
708716
Assert.Equal(BuildResultCode.Success, result.OverallResult);
709717
_logger.AssertLogContains("[success]");
710718
Assert.Single(_logger.ProjectStartedEvents);
@@ -760,11 +768,21 @@ public void OutOfProcNodeForwardCertainpropertiesAlsoGetResultsFromCache()
760768
_env.SetEnvironmentVariable("MsBuildForwardPropertiesFromChild", "InitialProperty3;IAMNOTREAL");
761769
_env.SetEnvironmentVariable("MSBUILDNOINPROCNODE", "1");
762770

771+
_env.SetEnvironmentVariable("MSBUILDLOGPROPERTIESANDITEMSAFTEREVALUATION", "0");
772+
763773
var project = CreateProject(contents, null, _projectCollection, false);
764774
var data = new BuildRequestData(project.FullPath, new Dictionary<string, string>(),
765775
MSBuildDefaultToolsVersion, Array.Empty<string>(), null);
766776

767-
BuildResult result = _buildManager.Build(_parameters, data);
777+
// We need to recreate build parameters to ensure proper capturing of newly set environment variables
778+
BuildParameters parameters = new BuildParameters
779+
{
780+
ShutdownInProcNodeOnBuildFinish = true,
781+
Loggers = new ILogger[] { _logger },
782+
EnableNodeReuse = false
783+
};
784+
785+
BuildResult result = _buildManager.Build(parameters, data);
768786
Assert.Equal(BuildResultCode.Success, result.OverallResult);
769787
_logger.AssertLogContains("[success]");
770788
Assert.Equal(3, _logger.ProjectStartedEvents.Count);
@@ -785,7 +803,8 @@ public void OutOfProcNodeForwardCertainpropertiesAlsoGetResultsFromCache()
785803
Assert.Equal("InitialProperty3", propertyValue);
786804

787805
projectStartedEvent = _logger.ProjectStartedEvents[2];
788-
Assert.Null(projectStartedEvent.Properties);
806+
properties = ExtractProjectStartedPropertyList(projectStartedEvent.Properties);
807+
(properties == null || properties.Count == 0).ShouldBeTrue();
789808
}
790809

791810
/// <summary>
@@ -822,7 +841,7 @@ public void ForwardNoPropertiesLaunchChildNode()
822841

823842
ProjectStartedEventArgs projectStartedEvent = _logger.ProjectStartedEvents[0];
824843
Dictionary<string, string> properties = ExtractProjectStartedPropertyList(projectStartedEvent.Properties);
825-
Assert.Null(properties);
844+
(properties == null || properties.Count == 0).ShouldBeTrue();
826845
}
827846

828847
/// <summary>
@@ -919,7 +938,7 @@ public void ForwardNoPropertiesLaunchChildNodeDefault()
919938

920939
ProjectStartedEventArgs projectStartedEvent = _logger.ProjectStartedEvents[0];
921940
Dictionary<string, string> properties = ExtractProjectStartedPropertyList(projectStartedEvent.Properties);
922-
Assert.Null(properties);
941+
(properties == null || properties.Count == 0).ShouldBeTrue();
923942
}
924943

925944
/// <summary>
@@ -3475,9 +3494,11 @@ private static string BuildAndCheckCache(BuildManager localBuildManager, IEnumer
34753494
/// </summary>
34763495
private static Dictionary<string, string> ExtractProjectStartedPropertyList(IEnumerable properties)
34773496
{
3478-
// Gather a sorted list of all the properties.
3479-
return properties?.Cast<DictionaryEntry>()
3480-
.ToDictionary(prop => (string)prop.Key, prop => (string)prop.Value, StringComparer.OrdinalIgnoreCase);
3497+
Dictionary<string, string> propertiesLookup = new Dictionary<string, string>(StringComparer.OrdinalIgnoreCase);
3498+
Internal.Utilities.EnumerateProperties(properties, propertiesLookup,
3499+
static (dict, kvp) => dict.Add(kvp.Key, kvp.Value));
3500+
3501+
return propertiesLookup;
34813502
}
34823503

34833504
/// <summary>

‎src/Build.UnitTests/BackEnd/MockLoggingService.cs‎

Lines changed: 13 additions & 6 deletions
Original file line numberDiff line numberDiff line change
@@ -215,14 +215,21 @@ public bool IncludeEvaluationProfile
215215
set { }
216216
}
217217

218-
/// <summary>
219-
/// Log properties and items on ProjectEvaluationFinishedEventArgs
220-
/// instead of ProjectStartedEventArgs.
221-
/// </summary>
222-
public bool IncludeEvaluationPropertiesAndItems
218+
/// <inheritdoc cref="ILoggingService.SetIncludeEvaluationPropertiesAndItemsInEvents"/>
219+
public void SetIncludeEvaluationPropertiesAndItemsInEvents(bool inProjectStartedEvent,
220+
bool inEvaluationFinishedEvent)
221+
{ }
222+
223+
/// <inheritdoc cref="ILoggingService.IncludeEvaluationPropertiesAndItemsInProjectStartedEvent"/>
224+
public bool IncludeEvaluationPropertiesAndItemsInProjectStartedEvent
225+
{
226+
get => false;
227+
}
228+
229+
/// <inheritdoc cref="ILoggingService.IncludeEvaluationPropertiesAndItemsInEvaluationFinishedEvent"/>
230+
public bool IncludeEvaluationPropertiesAndItemsInEvaluationFinishedEvent
223231
{
224232
get => false;
225-
set { }
226233
}
227234

228235
/// <summary>

‎src/Build.UnitTests/ConsoleLogger_Tests.cs‎

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -277,7 +277,7 @@ public void ErrorMessageWithMultiplePropertiesInMessage(bool includeEvaluationPr
277277

278278
if (includeEvaluationPropertiesAndItems)
279279
{
280-
pc.Collection.LoggingService.IncludeEvaluationPropertiesAndItems = true;
280+
pc.Collection.LoggingService.SetIncludeEvaluationPropertiesAndItemsInEvents(inProjectStartedEvent: false, inEvaluationFinishedEvent: true);
281281
}
282282

283283
var project = env.CreateTestProjectWithFiles(@"

‎src/Build/BackEnd/BuildManager/BuildManager.cs‎

Lines changed: 2 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -2757,7 +2757,8 @@ private NodeConfiguration GetNodeConfiguration()
27572757
, new LoggingNodeConfiguration(
27582758
loggingService.IncludeEvaluationMetaprojects,
27592759
loggingService.IncludeEvaluationProfile,
2760-
loggingService.IncludeEvaluationPropertiesAndItems,
2760+
loggingService.IncludeEvaluationPropertiesAndItemsInProjectStartedEvent,
2761+
loggingService.IncludeEvaluationPropertiesAndItemsInEvaluationFinishedEvent,
27612762
loggingService.IncludeTaskInputs));
27622763
}
27632764

‎src/Build/BackEnd/Components/Logging/ILoggingService.cs‎

Lines changed: 15 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -200,12 +200,24 @@ bool IncludeEvaluationProfile
200200

201201
/// <summary>
202202
/// Should properties and items be logged on <see cref="ProjectEvaluationFinishedEventArgs"/>
203-
/// instead of <see cref="ProjectStartedEventArgs"/>?
203+
/// or/and <see cref="ProjectStartedEventArgs"/>?
204204
/// </summary>
205-
bool IncludeEvaluationPropertiesAndItems
205+
void SetIncludeEvaluationPropertiesAndItemsInEvents(bool inProjectStartedEvent, bool inEvaluationFinishedEvent);
206+
207+
/// <summary>
208+
/// Indicates whether properties and items should be logged on <see cref="ProjectStartedEventArgs"/>.
209+
/// </summary>
210+
bool IncludeEvaluationPropertiesAndItemsInProjectStartedEvent
211+
{
212+
get;
213+
}
214+
215+
/// <summary>
216+
/// Indicates whether properties and items should be logged on <see cref="ProjectEvaluationFinishedEventArgs"/>.
217+
/// </summary>
218+
bool IncludeEvaluationPropertiesAndItemsInEvaluationFinishedEvent
206219
{
207220
get;
208-
set;
209221
}
210222

211223
/// <summary>

‎src/Build/BackEnd/Components/Logging/LoggingService.cs‎

Lines changed: 65 additions & 26 deletions
Original file line numberDiff line numberDiff line change
@@ -201,12 +201,6 @@ internal partial class LoggingService : ILoggingService, INodePacketHandler
201201
/// </summary>
202202
private bool? _includeEvaluationProfile;
203203

204-
/// <summary>
205-
/// Whether properties and items should be logged on <see cref="ProjectEvaluationFinishedEventArgs"/>
206-
/// instead of <see cref="ProjectStartedEventArgs"/>.
207-
/// </summary>
208-
private bool? _includeEvaluationPropertiesAndItems;
209-
210204
/// <summary>
211205
/// Whether to include task inputs in task events.
212206
/// </summary>
@@ -541,33 +535,77 @@ public bool IncludeTaskInputs
541535
set => _includeTaskInputs = value;
542536
}
543537

544-
/// <summary>
545-
/// Should properties and items be logged on <see cref="ProjectEvaluationFinishedEventArgs"/>
546-
/// instead of <see cref="ProjectStartedEventArgs"/>?
547-
/// </summary>
548-
public bool IncludeEvaluationPropertiesAndItems
538+
/// <inheritdoc cref="ILoggingService.SetIncludeEvaluationPropertiesAndItemsInEvents"/>
539+
public void SetIncludeEvaluationPropertiesAndItemsInEvents(bool inProjectStartedEvent, bool inEvaluationFinishedEvent)
549540
{
550-
get
541+
_evalDataBehaviorSet = true;
542+
IncludeEvaluationPropertiesAndItemsInEvaluationFinishedEvent = inEvaluationFinishedEvent;
543+
IncludeEvaluationPropertiesAndItemsInProjectStartedEvent = inProjectStartedEvent;
544+
}
545+
546+
private bool _evalDataBehaviorSet;
547+
private bool _includeEvaluationPropertiesAndItemsInProjectStartedEvent;
548+
private bool _includeEvaluationPropertiesAndItemsInEvaluationFinishedEvent;
549+
private void InferEvalDataBehavior()
550+
{
551+
if (_evalDataBehaviorSet)
551552
{
552-
if (_includeEvaluationPropertiesAndItems == null)
553+
return;
554+
}
555+
// Set this right away - to prevent SO exception in case of any future refactoring
556+
// that would refer to the IncludeEvaluation... properties here
557+
_evalDataBehaviorSet = true;
558+
559+
bool? escapeHatch = Traits.Instance.EscapeHatches.LogPropertiesAndItemsAfterEvaluation;
560+
if (escapeHatch.HasValue)
561+
{
562+
IncludeEvaluationPropertiesAndItemsInEvaluationFinishedEvent = escapeHatch.Value;
563+
IncludeEvaluationPropertiesAndItemsInProjectStartedEvent = !escapeHatch.Value;
564+
}
565+
else
566+
{
567+
var sinks = _eventSinkDictionary.Values.OfType<EventSourceSink>().ToList();
568+
569+
if (ChangeWaves.AreFeaturesEnabled(ChangeWaves.Wave17_12))
553570
{
554-
var escapeHatch = Traits.Instance.EscapeHatches.LogPropertiesAndItemsAfterEvaluation;
555-
if (escapeHatch.HasValue)
556-
{
557-
_includeEvaluationPropertiesAndItems = escapeHatch.Value;
558-
}
559-
else
560-
{
561-
var sinks = _eventSinkDictionary.Values.OfType<EventSourceSink>();
562-
// .All() on an empty list defaults to true, we want to default to false
563-
_includeEvaluationPropertiesAndItems = sinks.Any() && sinks.All(sink => sink.IncludeEvaluationPropertiesAndItems);
564-
}
571+
// If any logger requested the data - we need to emit them
572+
IncludeEvaluationPropertiesAndItemsInEvaluationFinishedEvent =
573+
sinks.Any(sink => sink.IncludeEvaluationPropertiesAndItems);
574+
// If any logger didn't request the data - hence it's likely legacy logger
575+
// - we need to populate the data in legacy way
576+
IncludeEvaluationPropertiesAndItemsInProjectStartedEvent =
577+
sinks.Any(sink => !sink.IncludeEvaluationPropertiesAndItems);
565578
}
579+
else
580+
{
581+
bool allSinksIncludeEvalData = sinks.Any() && sinks.All(sink => sink.IncludeEvaluationPropertiesAndItems);
582+
583+
IncludeEvaluationPropertiesAndItemsInEvaluationFinishedEvent = allSinksIncludeEvalData;
584+
IncludeEvaluationPropertiesAndItemsInProjectStartedEvent = !allSinksIncludeEvalData;
585+
}
586+
}
587+
}
566588

567-
return _includeEvaluationPropertiesAndItems ?? false;
589+
/// <inheritdoc cref="ILoggingService.IncludeEvaluationPropertiesAndItemsInProjectStartedEvent"/>
590+
public bool IncludeEvaluationPropertiesAndItemsInProjectStartedEvent
591+
{
592+
get
593+
{
594+
InferEvalDataBehavior();
595+
return _includeEvaluationPropertiesAndItemsInProjectStartedEvent;
568596
}
597+
private set => _includeEvaluationPropertiesAndItemsInProjectStartedEvent = value;
598+
}
569599

570-
set => _includeEvaluationPropertiesAndItems = value;
600+
/// <inheritdoc cref="ILoggingService.IncludeEvaluationPropertiesAndItemsInEvaluationFinishedEvent"/>
601+
public bool IncludeEvaluationPropertiesAndItemsInEvaluationFinishedEvent
602+
{
603+
get
604+
{
605+
InferEvalDataBehavior();
606+
return _includeEvaluationPropertiesAndItemsInEvaluationFinishedEvent;
607+
}
608+
private set => _includeEvaluationPropertiesAndItemsInEvaluationFinishedEvent = value;
571609
}
572610

573611
/// <summary>
@@ -609,6 +647,7 @@ public ICollection<string> GetWarningsNotAsErrors(BuildEventContext context)
609647
return GetWarningsForProject(context, _warningsNotAsErrorsByProject, WarningsNotAsErrors);
610648
}
611649

650+
612651
/// <summary>
613652
/// Returns a collection of warnings to be demoted to messages for the specified build context.
614653
/// </summary>

‎src/Build/BackEnd/Components/Logging/ProjectLoggingContext.cs‎

Lines changed: 2 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -96,7 +96,7 @@ private ProjectLoggingContext(
9696

9797
// If we are only logging critical events lets not pass back the items or properties
9898
if (!LoggingService.OnlyLogCriticalEvents &&
99-
!LoggingService.IncludeEvaluationPropertiesAndItems &&
99+
LoggingService.IncludeEvaluationPropertiesAndItemsInProjectStartedEvent &&
100100
(!LoggingService.RunningOnRemoteNode || LoggingService.SerializeAllProperties))
101101
{
102102
if (projectProperties is null)
@@ -116,7 +116,7 @@ private ProjectLoggingContext(
116116
}
117117

118118
if (projectProperties != null &&
119-
!LoggingService.IncludeEvaluationPropertiesAndItems &&
119+
LoggingService.IncludeEvaluationPropertiesAndItemsInProjectStartedEvent &&
120120
propertiesToSerialize?.Length > 0 &&
121121
!LoggingService.SerializeAllProperties)
122122
{

0 commit comments

Comments
 (0)