dotnet
Emit eval props if requested by any sink
Fixes #10225
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
Notes
The change was introduced long ago - https://github.com/dotnet/msbuild/commit/794abcbb005017cf3a75850a9f001419bb47bd38 - 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
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.
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:
https://github.com/dotnet/msbuild/blob/a9efffc4de9609e9ecb45c6c2d41487a4ed70d6f/src/Build/Logging/BaseConsoleLogger.cs#L953-L957
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
MuxLoggerhas theIncludeEvaluationPropertiesAndItemsset tofalse. I'm guessing it's change on the calling side (in VS) - as we do not set the property in our code.
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.
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.
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).
This one describes what was going on - it's basically the inverse of this PR: https://github.com/dotnet/msbuild/pull/6520
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 https://github.com/dotnet/msbuild/issues/6498#issuecomment-860970125 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.
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.
I think this was my investigation: https://github.com/dotnet/msbuild/issues/4044
See also: https://github.com/dotnet/msbuild/issues/7219#issuecomment-1513812893
Experimental VS insertion: https://devdiv.visualstudio.com/DevDiv/_git/VS/pullrequest/558711
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
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
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
