Early evaluation of invalid DefaultCompileItems recursive itemgroup performance issue during incremental builds

[jeromelaban]

Using the solution provided here: https://github.com/jeromelaban/MicrosoftIssues/tree/master/MsBuildEarlyEvalIssue,

it is possible to determine that the first invocation of LazyItemEvaluator.GetAllItems evaluates this Compile item group while DefaultLanguageSourceExtension and DefaultItemExcludes are not defined.

This has the effect of recursively and unconditionally search all files in the project's folder, even in the bin and obj folders, and the ret variable in the GetAllItems method contains all these files.

When building Xamarin.Android projects (because of Google SDKs java imports), or other project that a very deep file structure in the obj or bin folder, this recursive enumeration takes quite a long time to complete, and its result is seemingly discarded afterwards.

I'm also assuming this can be a big problem perf in VS, where design-time builds reload each targetframework to evaluate its content, where in some profiling sessions, ntfs.sys shows up regularly in perfview.

[davkean]

Help me understand this, you are saying that despite the condition being false, we're still evaluating the glob?

[jeromelaban]

I'm not sure about the condition evaluation.

The behavior I'm seeing is ret returning a lot of files that don't match *.cs (e.g. pdb files in the obj folder) that come from this ItemGroup, and I'm guessing the only way this can happen is if DefaultLanguageSourceExtension is not set.

In a solution of mine that has a big Xamarin.Android project, this ret variable contains about 5000 items.

The strange part is if DefaultLanguageSourceExtension is not set, EnableDefaultItems should also not be defined, so I'm a bit confused by the behavior, because the ItemGroup should not be evaluated yet clearly is.

From the outside though, GetItems is behaving as expected, considering the sample sets EnableDefaultItems to false

[jeromelaban]

I've tried to poke around the issue, and for using the sample solution above, loading a project that takes 1.3s with today's latest master, I'm down to 570ms.

The issue is indeed related to the evaluation of item operations for which the condition is false.

See this commit: jeromelaban@b476fa6

That being said, I'm not certain of the impact of this change, I'll dig deeper to see if it fails some tests.

Edit: if I exclude the JIT Time, the processing of the same project is down from 570ms to about 50ms, on a second run of the same msbuild project loading, but in a different app domain to avoid internal msbuild caching.

[davkean]

@jeromelaban You are right, what it appears to be doing is the following:

                        // Tell the lazy evaluator to compute the items and add them to _data
                        IList<LazyItemEvaluator<P, I, M, D>.ItemData> items = lazyEvaluator.GetAllItems();
                        // Don't box via IEnumerator and foreach; cache count so not to evaluate via interface each iteration
                        var itemsCount = items.Count;
                        for (var i = 0; i < itemsCount; i++)
                        {
                            var itemData = items[i];
                            if (itemData.ConditionResult)
                            {
                                _data.AddItem(itemData.Item);

                                if (_data.ShouldEvaluateForDesignTime)
                                {
                                    _data.AddToAllEvaluatedItemsList(itemData.Item);
                                }
                            }

                            if (_data.ShouldEvaluateForDesignTime)
                            {
                                _data.AddItemIgnoringCondition(itemData.Item);
                            }
                        }

                        // lazy evaluator can be collected now, the rest of evaluation does not need it anymore
                        lazyEvaluator = null;

It looks like we should be pushing that block into GetAllItems().

@cdmihai was there a reason it was written like this?

[jeromelaban]

@davkean I did not notice the design-time implication of this. This may explain the very long delay I'm seeing in VS2017 when requesting a build, and that nothing happens until an msbuild process is done processing all the files (that can last about a minute). After that step, the nuget restore step starts, then the build starts.

[davkean]

That would be something else, can you report recording it?

[cdmihai]

The lazy item implementation follows the implementation that existed before. From what I can tell, "Design Time Evaluations" (evaluations started via the Project class) gather more evaluation data than "Build Time Evaluation" (evaluations triggered via the ProjectInstance class).

The current lazy item evaluator mimics the behaviour that existed before: When evaluation is done by the Project class, Project.Data.ShouldEvaluateForDesign is hardcoded to true. This causes evaluation of itemgroups and items even when their condition is false, and also causes gathering more data. Here are snippets from the legacy code:

• ItemGroup condition ignored: https://github.com/Microsoft/msbuild/blob/v14.0.25420.1-ish/src/XMakeBuildEngine/Evaluation/Evaluator.cs#L1212
• Item condition ignored: https://github.com/Microsoft/msbuild/blob/v14.0.25420.1-ish/src/XMakeBuildEngine/Evaluation/Evaluator.cs#L1584
• Project.ItemsIgnoringCondition, Project.AllEvaluatedItems and others (Project.ConditionedProperties, Project.AllEvaluatedItemDefinitionMetadata) get populated: https://github.com/Microsoft/msbuild/blob/v14.0.25420.1-ish/src/XMakeBuildEngine/Evaluation/Evaluator.cs#L1779-L1798

I don't understand the requirements for this extra data collection. It probably enables various analysis in VS (@lifengl).
If the extra data provided by "Design Time Evaluations" is not needed anymore by VS, we can allow turning off Project.Data.ShouldEvaluateForDesign to avoid the CPU / memory waste.

Internal usages of these APIs (MSFT internal links). Maybe they are stale and work just as well with APIs available to ProjectInstance.
http://index/?leftProject=Microsoft.Build&leftSymbol=rxlmvtaoqs4l&file=Definition%5CProject.cs
http://index/?leftProject=Microsoft.Build&leftSymbol=y5xmgdq1vxhm&file=Definition%5CProject.cs
http://index/?leftProject=Microsoft.Build&leftSymbol=ezznkg6tnsyl&file=Definition%5CProject.cs
http://index/?leftProject=Microsoft.Build&leftSymbol=cgin8wlvma8t&file=Definition%5CProject.cs

[jeromelaban]

This solution demonstrates the issue, when loading the solution in VS after having built it once.

[lifengl]

I don't remember CPS need resolve items excluded by conditions. I wonder it might be used by traditional projects which wants to show all items in different configurations? + @AArnott

Anyway, it sounds that some features may want to know all files listed in the project no matter the condition. Globbings defined inside SDK are completely different beast. A project may want to disable them, and choose their own way to include items. Resolving them might break the expectation of those features using ItemsIgnoringCondition in a different way.

[AArnott]

As I recall, the legacy project system evaluates all items without regard to condition. CPS does not do this AFAIK. I can't think of any good reason why CPS should ever read items whose condition is false.
I think the legacy project system did this because it couldn't handle items appearing and disappearing from evaluation without explicit changes to them by the project system. But CPS can handle it just fine.

[lifengl]

Thanks, Andrew. That matches what I thought. @davkean: maybe this can partially explain why evaluation is still slow after disabling globbings in .Net Core projects? @cdmihai , is it possible to suppress this behavior through some flags?

[jeromelaban]

@lifengl, running a small profiling session using the original sample of this issue, here's what comes out of the top native contributors for the second run of "dotnet build":

The wall clock time is 3.5 seconds for these samples.

[cdmihai]

@lifengl

Currently it is hardcoded to always ignore conditions if you are evaluating via Project. The easiest way to turn this behaviour off is via a new ProjectLoadSettings value. Would this work for you?
However, if you set this, all the data that is dependent on conditions not being evaluated (like ItemsIgnoringConditions) will be empty.

[lifengl]

I think it will work for us. Is it possible to get a private build to test with this disabled?

[davkean]

This has been fixed on the MSBuild side, it still needs to be consumed by CPS.

[kzu]

I know this is old @davkean, but it was mentioned in a devcom feedback at https://developercommunity.visualstudio.com/comments/130197/view.html and I'm interested in knowing whether this ended up shipping.

[davkean]

We turned this on for CPS-based project. Legacy project system builds its tree ignoring all conditions, so will run into this problem.

[davkean]

Note, if you walk through the session @kzu we log evaluation times for CPS which will confirm/deny.

[kzu]

Thanks for the info, +1!

On Wed, Nov 21, 2018, 6:26 PM David Kean ***@***.***> wrote: Note, if you walk through the session @kzu <https://github.com/kzu> we log evaluation times for CPS which will confirm/deny. — You are receiving this because you were mentioned. Reply to this email directly, view it on GitHub <#2502 (comment)>, or mute the thread <https://github.com/notifications/unsubscribe-auth/AAKW6wut3qr4gB_WyQK-1DK5BsfidDnvks5uxcUMgaJpZM4PQWWV> .

--

…

-- @kzu from mobile