Closed rainersigwald closed 1 month ago
Have been able to reproduce the issue:
MSBUILDLOGIMPORTS
and MSBUILDDEBUGENGINE
environment variables.<path to devenv.exe> <solution_name>
Have we validated that @JanKrivanek's change actually fixes this?
Binlogs obtained from VS have always been deficient and missing info. The Project System Tools extension was especially bad, but even the MSBUILDDEBUGENGINE=1 mode produces no evaluation and I thought it's because CPS evaluates separately from builds.
See related:
I don't think MuxLogger is the problem. I have an environment where MuxLogger is present but still the binlogs have the full information.
Another way to test this is set the env variable MSBUILDLOGPROPERTIESANDITEMSAFTEREVALUATION=1 and see if it fixes things. If it does then yes, it indicates a legacy logger is present.
But I suspect it won't fix it.
Binlogs obtained from VS have always been deficient and missing info. The Project System Tools extension was especially bad, but even the MSBUILDDEBUGENGINE=1 mode produces no evaluation and I thought it's because CPS evaluates separately from builds.
there will be no evaluation in the logs of build, because it already happened, but there should be a log with evaluations in it, and this one seems to be that one . . . except they're incomplete.
I've never understood how are evaluations separate from build? How is it implemented?
The ProjectInstance
(or Project
) can be created and evaluated standalone. They can then be used to issue build requests.
That's how those 2 events get executed separately.
I'll double/triple check and debug the scenario next week (away from my devbox now) to confirm the theory.
Reopening as fix introduced VS perf regression - we will need to fix that one in coordination with the fix
We'll need to investigate the hidden root-cause, in order to prevent the perf regression after fix.
First we'll need to find stable repro - steps:
Run the following - to enable binlogging and collect them:
$env:MSBUILDDEBUGENGINE = 1
> $env:MSBUILDDEBUGPATH="C:\MSBuildReproLogs"
> & "devenv.exe" MySolution.sln
<Run full rebuild from GUI>
Check the binlog - evaluation result of a project should normally contain properties and items:
If they are missing - issue reproduces.
If issue doesn't reproduce, try:
> $env:MSBUILDNOINPROCNODE="1"
Once repro is found, we'll need previous - unbroken instance
pskill msbuild
and pskill dotnet
will do the job)Once we have 2 versions to compare - we'll need to look into behavior differences
IncludeEvaluationPropertiesAndItems
https://github.com/dotnet/msbuild/blob/bd46115a1d330e758e6a53798c71efe0f8bb7c0a/src/Build/BackEnd/Components/Logging/LoggingService.cs#L555-L573$env:MSBUILDDEBUGONSTART="1"
MSBUILDNOINPROCNODE
above) - so that we can rely on breaking into external process. Otherwise - if we'd need to debug the msbuild code run within the VS process - we'd need to inject custom built MSBuild bits (and add Debugger.Launch()
into the property), or attach to VS and use 'Function breakpoint' (see later). We might likely need any of those techniques in a later steps anyway (see next steps), but we might be able to avoid now.sink.IncludeEvaluationPropertiesAndItems
values differ between the casesMuxLogger
is the one logger causing the difference: https://github.com/dotnet/msbuild/blob/bd46115a1d330e758e6a53798c71efe0f8bb7c0a/src/Utilities/MuxLogger.cs#L187MuxLogger
differently - if that's proved culprit) we'll need our custom msbuild bits - as we need to break into InitializeLogger
- which runs in the main node. Other option is to attach debugger to VS process and add unresolved Function breakpoint (Debug -> New Breakpoint -> Function Breakpoint) and specify the InitializeLogger function - it might though get some efforts to get working correctlyMuxLogger
is the culprit - we need to set breakpoint on its IncludeEvaluationPropertiesAndItems
setter and see what code did call it in the 'before regression VS version' and see if that code is not called in 'after regression VS version'If any of the above steps doesn't work - please do not continue with further steps (as they might expect the previous steps are true) - instead we'll need to figure adjustment of investigation.
No matter disabling msbuild in-proc node or not, this issue could be reproduced with older VS versions, even back to 17.0.0. VS 2019(16.11.38) also has this issue. It means this issue has existed for a long time.
With Jan's help, I looked into which loggers are registered and which of these call IEventSource4.IncludeEvaluationPropertiesAndItems() in Initialize(IEventSource eventSource) of the loggers through debugging with $env:MSBuildDebugBuildManagerOnStart="1"
. The registered loggers are:
$env:MSBUILDDEBUGENGINE=1
.IncludeEvaluationPropertiesAndItems
of EventSourceSink with the value false
was from the MuxLogger.Initialize(IEventSource eventSource)
. The breakpoint added to the setter of MuxLogger's property IncludeEvaluationPropertiesAndItems
was never hit and it was false by default. https://github.com/dotnet/msbuild/blob/bd46115a1d330e758e6a53798c71efe0f8bb7c0a/src/Utilities/MuxLogger.cs#L185-L188 was not run to set IncludeEvaluationPropertiesAndItems
of EventSourceSink and caused the issue. Thank you @GangWang01!
Let's dig more into why the fix for this causes perf regression - what are the other registered loggers in VS and what are their setting of IncludeEvaluationPropertiesAndItems
?
Enabling binary logger by setting $env:MSBUILDNOINPROCNODE="1"
interfered the investigation. It didn't simulate the case in VS perf tests.
Without enabling binary logger, I found the loggers below were registered that was different from the investigation.
eventSource4.IncludeEvaluationPropertiesAndItems()
directly https://github.com/dotnet/msbuild/blob/1b1df9e39b8c576d33d8964c7f4a64716fd46371/src/Build/BackEnd/BuildManager/BuildManager.cs#L3300. This logger may cause the perf regression with the fix.
I am in possession of a binlog that looks like this
So it did evaluation, including firing the import events AND EMBEDDING THE FILES but somehow didn't report post-evaluation item and property states?