Emit eval props if requested by any sink

[JanKrivanek]

Fixes #10225, #1976

Context

The eval props/items were not attached to ProjectEvaluationFinishedEventargs if any logger didn't request IncludeEvaluationPropertiesAndItems

In case of VS - the MuxLogger is attached as well. So in case that one doesn't set the property (it might be a recent change in VS - I'm not sure) - the values are not being sent neither to binary logger.

Changes Made

Make sure the values are emitted and attached if any logger requests them

Testing

Manual (VS with injected Msbuild)
Experimental VS insertion: https://devdiv.visualstudio.com/DevDiv/_git/VS/pullrequest/558711
Experimental VS insertion for the version which can add properties on both event types: https://devdiv.visualstudio.com/DevDiv/_git/VS/pullrequest/565788 (yet another: https://devdiv.visualstudio.com/DevDiv/_git/VS/pullrequest/566698)

Notes

The change was introduced long ago - 794abcb - and it mentiones possible regression concerns if applied to all loggers. I might not have understood it properly - but it seems the concern is more about ProjectEvaluationStartedEventArgs - which do not attach the props/items anymore. Having extra data in ProjectEvaluationFinishedEventargs even for loggers do not requesting it feels like very low opportunity for breakage (somebody would need to explicitly break on non-null data).
FYI @KirillOsenkov - in case my thinking is flawed

[rainersigwald]

Does this result in big duplication for the console/text loggers at diag? That's the biggest concern off the top of my head right now.

[JanKrivanek]

Does this result in big duplication for the console/text loggers at diag? That's the biggest concern off the top of my head right now.

This should be identical. Console loggers already have it:

msbuild/src/Build/Logging/BaseConsoleLogger.cs

Lines 953 to 957 in a9efffc

	bool logPropertiesAndItemsAfterEvaluation = Traits.Instance.EscapeHatches.LogPropertiesAndItemsAfterEvaluation ?? true;
	if (logPropertiesAndItemsAfterEvaluation && eventSource is IEventSource4 eventSource4)
	{
	eventSource4.IncludeEvaluationPropertiesAndItems();
	}

Plus they pull data from ProjectEvaluationStarted if it's not in ProjectEvaluationFinished

BUT - I now see that IncludeEvaluationPropertiesAndItems actually means: "Should the items and props be included in ProjectEvaluationFinished OR in ProjectEvaluationStarted?". Them being in ProjectEvaluationFinished is not a problem. However them NOT being in ProjectEvaluationStarted might possibly be a problem for some legacy loggers.

So we now have 2 options:

• [Current PR] - Go forward with the props/items being only in ProjectEvaluationFinished. And allow flipping to legacy behavior (for a legacy loggers) with explicit trait. This way we'll be able to eventualy get rid of the confusing conditional logic and it's propagation. BuildChecks as well will need the new behavior.
• [No change. Request investigation from VS] - Keep the logic which flips the behavior base on presence of legacy logger. We'd need to find out why MuxLogger has the IncludeEvaluationPropertiesAndItems set to false. I'm guessing it's change on the calling side (in VS) - as we do not set the property in our code.

[KirillOsenkov]

I thought this was determining whether the properties and items are logged at ProjectEvaluationFinished vs. legacy ProjectStarted.

Some legacy loggers (like Azure DevOps pipelines distributed logger) expected them to be on ProjectStarted, and crashed with NullReferenceException when they didn't find them.

I don't think they're ever on ProjectEvaluationStarted.

[KirillOsenkov]

I remember MuxLogger had these as false but somehow this was never the problem. I think something else is going on.

Also as an option we can keep this PR, and just ensure that ProjectStartedEventArgs has empty arrays for properties and items, instead of null. I regret not having done this in the first place.

[KirillOsenkov]

But overall I don't think this is a safe change to make. This is pretty much equivalent to always turning it on (it's as if there's always an imaginary logger present that requests it).

[KirillOsenkov]

This one describes what was going on - it's basically the inverse of this PR:
#6520

[KirillOsenkov]

See related:
#6498

[JanKrivanek]

I remember MuxLogger had these as false but somehow this was never the problem. I think something else is going on.

I cannot wrap my head around how would that work. Perhaps viewer used to get the props from ProjectStartedEventArgs?
Or something obvious is escaping before my eyes

Also as an option we can keep this PR, and just ensure that ProjectStartedEventArgs has empty arrays for properties and items, instead of null. I regret not having done this in the first place.

I added ensuring non-null values.
It still would not prevent the problem described here #6498 (comment)
but the problematic logger fixed their implementation soon after the original problem - and it can now handle nulls fine: https://github.com/microsoft/azure-pipelines-msbuild-logger/blob/56a61f46a2b0f1b037dd42532dfd09144b1df26f/MSBuild.Logger/BuildConfiguration.cs#L40-L50

There is still a risk that some existing logger relies on specific properties being always available in ProjectStartedEventArgs - the workaround for such would be explicit setting of MSBUILDLOGPROPERTIESANDITEMSAFTEREVALUATION to 0/false.

[KirillOsenkov]

I like this change - I should have done that long ago.

We should debug why we don't get eval in VS - want to be absolutely sure it's because of a bad logger present. I clearly remember looking at this and MuxLogger wasn't the issue, but I might have been mistaken.

[KirillOsenkov]

I think this was my investigation:
#4044

[KirillOsenkov]

See also:
#7219 (comment)

[KirillOsenkov]

See also:
#4048

[JanKrivanek]

Experimental VS insertion: https://devdiv.visualstudio.com/DevDiv/_git/VS/pullrequest/558711

[JanKrivanek]

Tested with VS with this PR inserted (installers: https://devdiv.visualstudio.com/DevDiv/_build/results?buildId=9745016&view=ms.vss-build-web.run-extensions-tab)

tl;dr;: The issue is present and resolved with this PR
However it can have impact on legacy loggers that expect the props/items in ProjectStartedEventArgs. Given there is a workaround (MSBUILDLOGPROPERTIESANDITEMSAFTEREVALUATION or ChangeWave) - we might want to go forward and then work with possible affected partners (as move from consuming props from ProjectStartedEventArgs to consuming them from ProjectEvaluationFinishedEventArgs requires minimal code changes).

note: For each scenario it's important to start fresh (killing msbuild nodes, or at least change code and rebuild) - to prevent the results to be served from cache!

This PR as is

> $env:MSBUILDDEBUGPATH="C:\temp\ConsoleApplication3\logs"
> $env:MSBUILDDEBUGENGINE = 1
> $env:MSBUILDLOGIMPORTS = 1
> & "C:\Program Files\Microsoft Visual Studio\2022\Preview\Common7\IDE\devenv.exe" "C:\temp\ConsoleApplication3\ConsoleApplication3.sln"

Issue is not present:

Opt-out props after eval

> $env:MSBUILDLOGPROPERTIESANDITEMSAFTEREVALUATION = 0

Issue is present (by design - as data is explicitly opted out):

ChangeWave opt-out

> $env:MSBUILDLOGPROPERTIESANDITEMSAFTEREVALUATION = ''
> $env:MSBUILDDISABLEFEATURESFROMVERSION = '17.12'

FYI: @olgaark, @yuehuang010

[JanKrivanek]

Or there is another - more conservative - approach: send props on ProjectStartedEventArgs if all loggers are legacy, send them on ProjectEvaluationFinishedEventArgs if all loggers are enlightened and in the mixture case send the props on both events. I'll work on this (+ measure) in 2 weeks

[KirillOsenkov]

A page I wrote to document the whole business around enlightening loggers:
https://github.com/KirillOsenkov/MSBuildStructuredLog/wiki/Reading-project-properties-and-items-from-a-logger

[AR-May]

LGTM

[f-alizada]

I have left couple of questions to understand the reasoning of tests changes but overall no questions.

[f-alizada]

Let's revert the change and investigate later per:
https://devdiv.visualstudio.com/DefaultCollection/DevDiv/_workitems/edit/2173921

[f-alizada]

Sorry wrong PR :)