Project-system: .NET Core/.NET Standard build performance

[davkean]

This is an overarching issue that I'm using to track evaluation/build performance issues across all repos. This has a .NET Core/.NET Standard focus, but due to overlap, improvements such as https://github.com/Microsoft/msbuild/issues/1276, will improve all project types.

Notes:

• Due to the behavior of projects inheriting their project references' evaluation cost during a build, evaluation is overwhelmingly the largest cost. It is also affects all scenarios inside and outside of VS. All focus should be on reducing this cost first, followed by design-time build task/target time, then full build (both VS and CLI) task/target time.
• In huge solutions, I'm seeing GC CPU time from 15% - 25%. For these, we should focus on evaluation allocations and get this to under 10%.
• In small solutions, I'm seeing evaluation time, in particular disk walks, disk lookups and expressions be problematic. Focus should be reducing number of globs, and removing unnecessary expressions especially ones that use property functions.

Evaluation

Long evaluation times increases almost all scenarios including project load, adding/removing files, build, time-to-intellisense. Because both project systems will block the UI thread waiting for this - single project evaluation should be 20-50 ms.

CPU Time

Breakdown: Overhead of evaluation is too high for design-time build

% |Bug|Owner|Scenario|Notes
---:|---|---|:---:|---|
~30-50%~|~For large projects with globs, MSBuild takes up to 30% - 50% of a build searching the disk~|MSBuild|All
~10-60%~|~Avoid double evaluation of all ProjectReferences~|MSBuild|All|~In PR: https://github.com/Microsoft/msbuild/pull/2595.~
~30-50%~|~Early evaluation of invalid DefaultCompileItems recursive itemgroup performance issue during incremental builds~|MSBuild|VS only|Affects evaluation inside VS process when project is opt'd out of globs. Just need CPS to consume new option.
~9-20%~|~Adding .NET Standard reference assemblies is consuming lots of time in build~|.NET|All|Note, this is with globs turned off
30%|Performance: reduce overhead of computing full path for items from globs|MSBuild|VS only
_|~Performance inside Project.GetAllGlobs~|MSBuild|VS only|
3-20% |IndexOfAny/ProbablyContains/InitializeProbabilisticMap is showing up on radar|MSBuild/.NET|All|Needs investigation, could be reduced once globbing speed up.
~0-13.0%~|~Normalize include and exclude specs before file walking~|MSBuild|All
5-11%|Builds are spending lots of time of CPU just sleeping|MSBuild|All
~10%~|~Optimize away separate evaluation for /restore when the restore didn't actually pull down new props/targets~|~CLI~|
3.5%|Importing Microsoft.CodeAnalysis.targets costs ~3.5% of evaluation time of solution-wide design-time build|Roslyn|All
3%|Projects are paying 3% of evaluation of a solution-wide design-time build importing targets they don't use|MSBuild|All
2.8%|MSBuild throws thousands of first-chance exceptions evaluating projects with certain types of property functions|MSBuild|All|This was reduced here: https://github.com/Microsoft/msbuild/pull/2833.
2.5%|2.5% of CPU time in build is spent evaluating unnecessary Exists() in conditions for a solution-wide design-time build|MSBuild|All
1.6%|Calculating $(TargetPlatformSdkPath)/$(TargetPlatformDisplayName) takes up 1.6% of evaluation of a solution-wide design-time build|MSBuild|All
~1.4%~|~Calculating $(FrameworkPathOverride) takes up to 1.4% of evaluation of a solution-wide design-time build~|MSBuild|All|Done
~1.3%~|~Calculating $(CodeAnalysisPath)/$(CodeAnalysisStaticAnalysisDirectory) in Microsoft.CodeAnalysis.targets takes up 1.3% of evaluation of a solution-wide design-time build~|Roslyn|All|In PR.
1.2%|Non-trivial amount of lock contention|MSBuild|All|Note this is just CPU time calling Monitor.Enter - blocked thread time will be much higher. MSBuildNameIgnoreCaseComparer portion of this was addressed.
~1.0%~|~Resolving ToolsVersion costs 1% of a build and 2% of all allocations~|MSBuild|All
1.0%|Calculating $(_DebugSymbolsOutputPath) takes up 1% of evaluation of a solution-wide design-time build|MSBuild|All
~0.9%~|~MSBuild is still opt'ing into the legacy GetFullPath behavior~|MSBuild|All|We need a bug against VS to also opt in
0.7%|Calculating $(_DirectoryBuildPropsBasePath)/$(_DirectoryBuildTargetsBasePath) takes up 0.7% of evaluation of a solution-wide design-time build|MSBuild|All
~0.5%~|~Calculating whether a .NET Standard library ref is a facade costs 0.5% of solution-wide design time build~|.NET|All

Memory

% |Bug|Owner|Scenario|Notes
---:|---|---|:---:|---|
11.5%|Lookup/ItemDictionary make up a huge amount of allocations/CPU item |MSBuild|All
4.8%|ExpandExpressionCaptureIntoStringBuilder is spending ~4.8% of allocations resizing the string builder|MSBuild|All
5-9%|LazyOperation.Apply can allocate 5% to 9% opening a solution|MSBuild|All
~2.6 - 5.5%~|~ItemFragment.CreateFileMatcher allocating 2.6% of solution-wide design-time build just getting directory name~|MSBuild|All
~3.0%~|~Reduce allocations in ExpandExpressionCaptureIntoStringBuilder~|MSBuild|All
~2.7%~|~FileMatcher is allocating twice it needs to due to using Directory.GetFiles/GetDirectories~|.NET|All|Fixed in .NET Framework 4.7.2
~2.4%~|~Large allocation via GetEnvironmentVariables~|MSBuild|All|This was cut in half
~2.0%~|~Resolving ToolsVersion costs 1% of a build and 2% of all allocations~|MSBuild|All
~0.5% - 1.7%~|~Globbing is boxing enumerators causing 0.5% of all allocations opening solution~|MSBuild|All
~2.0%~|~ProcessItemSpec allocating 2.0% of all allocations~|MSBuild|All
~%0-2.0%~|~Avoid iterator/list allocations when parsing projects~|MSBuild|All
~1.6%~|~Remove short-lived List allocations from SplitSemiColonSeparatedList~|MSBuild|All
~1.5%~|~Do not allocate in TaskItem.GetHashCode~|MSBuild|All
~0.4 - 1.4%~|~Large amount of allocations during evaluation due to boxing of KeyedObject~|MSBuild|All
~1.4%~|~Reduce allocations in Lookup.GetItems~|MSBuild|All
~1.3%~|~Updating conditioned properties is adding 1.3% of evaluation allocations~|MSBuild|All|We've opted out of this in CPS.
~1.2%~|~Unnecessary List instantiation~|MSBuild|All
~1.0%~|~Getting filename/extension metadata allocations 1% of solution-wide design-time build~|~MSBuild~|~All~
1.0%|Don't read comments when reading imports|MSBuild|All
~1.0%~|~MSBuildNameIgnoreCaseComparer is allocating 1% of a solution-wide design-time build~|MSBuild|All
~0.8%~|~ProjectInstance.GetItemsByItemTypeAndEvaluatedInclude allocates ~0.8% of open solution~|MSBuild|VS only
~0.7%~|~TaskItemSpecFilenameComparer.Compare allocations 0.7% of a solution-wide design-time build~|MSBuild|All
0.6%|MSBuild is boxing 25 MB worth of ImmutableList/List enumerators|MSBuild|All
~0.4%~|~Remove unneeded allocations in ItemSpec.MatchesItem~|MSBuild|All
~0.2%~|~Remove enumerator boxing~|MSBuild|All
~0.2%~|~Remove boxed enumerator allocation~|MSBuild|All

Build

Long build times increases F5, project load (legacy), editing (legacy) and time-to-intellisense. Because the legacy project system blocks the UI thread waiting for this - a single project design-time build should be 100-200ms.

CPU Time

Breakdown (design-time build): Overhead of SDK build targets is too high for design-time builds
Breakdown (normal build): Overhead of SDK build targets is too high for a normal build

Term|Meaning
---|---
CLI build|Command-line build of a project or a solution
Design-time build|Design-time build of a single project
VS build|Visual Studio build of a project or a solution

% |Bug|Owner|CLI build|Design-time build|VS build|Notes
---:|---|---|:---:|:---:|:---:|---|
0-33%|Loading NuGet/JSON.NET binaries adds ~130ms to a build|CLI|●|||Node reuse does not help. Hurts single project build significantly.
~25%~|~improve NuGet.targets perf for implicit restore~|NuGet|●|||
~20%~|~Use msbuild /restore instead of a separate process~|CLI|●|||
17%|_ComputeLockFileReferences/RunResolvePackageDependencies should be faster when projects are up-to-date|CLI|●|●|●|
~12%~|~Add reference metadata to indicate that RAR can skip dependency searching~|MSBuild|●|●|●|
7%|FindReferenceAssembliesForReferences accounts for 7% of a design-time build|MSBuild|●|●|●|
5.6%|Facades with references versioned 0.0.0.0 cause lots of issues for RAR|.NET|●|●|●|
~5%~|~5% of a build is due ResolveAssemblyReferences's cache checking~|MSBuild|●|●|●|Ended up only winning ~1%
0.6%|_GenerateCompileDependencyCache is still consuming non-trivial time in design-time build|MSBuild|●|●|●|
~0.1%~|~GetInstalledSDKLocations runs in every project regardless of whether they even target a Windows SDK~|MSBuild|●|●|●|
_|MSBuild has non-trivial overhead due to JIT'ing|MSBuild|●|||Node reuse does not help.
_|~Two versions of JSON.NET are being loaded during a build~|CLI|●|||Node reuse does not help.
_|Design-time builds in CPS are doing too much work because BuildingProject is set to true|MSBuild||●
_|~.NET Core-based projects are not using the RAR cache in design-time builds~|Project||●

Memory

% |Bug|Owner|CLI build|Design-time build|VS build|Notes
---:|---|---|:---:|:---:|:---:|---|
~20%~|~Reduce AssemblyName allocations~|MSBuild|●|●|●|
~11%~|~Avoid cloning AssemblyName~|MSBuild|●|●|●|
~6.5%~|~ResolvePackageDependencies is producing 6.5% of allocations in a build~|CLI|●|●|●|
~3.7%~|~FileUtilities.HasExtension allocating 3.7% of a solution build~|MSBuild|●|●|●|
~3.7%~|~ResolveNuGetPackageAssets allocates 3.7% of solution-wide design-time build~|CLI|●|●|●|
~3.3%~|~ConflictResolver.ResolveConflict is ~3.3% of all allocations in solution-wide design-time build~|CLI|●|●|●|
~0.3%~|~NuGet.ProjectModel reads column/line information producing 15 MB of unneeded garbage~|NuGet|●|●|●|

Customer action items:

• Remove <PackageReference/> to NETStandard.Library.NETFramework - this has been replaced with functionality as part of .NET Core 2.0 SDK.
• Upgrade to 2.1 of .NETStandard.Library.

[DamianEdwards]

Should we like this to the issue on MSBuild for RAR perf too?

[davkean]

Targets, including RAR, are linked from Overhead of SDK build targets is too high for a normal build.

[DamianEdwards]

There's microsoft/msbuild#2015 too

[davkean]

Hmm, need to understand why https://github.com/Microsoft/msbuild/pull/2192 hasn't moved the mile - does it only kick in on the .NET Core build?

[kiwiant]

Here is a real world example of the difference between the two web sites building on VS 2017 15.3.4 with an SSD. Full clean was performed before running each test of a full solution rebuild (including the test projects):

Solution A (.NET Framework 4.7, 2,555 .cs files, 20 projects) - rebuild time 0:31

Solution B (.NET Core 2.0, 827 .cs files, 19 projects) - rebuild time 2:13 (1:44 with ESET AV 6.5.2107.1 disabled).

[Pilchie]

Moving remaining work to 15.6.

[dasMulli]

The efforts so far have lead to a significant improvement for incremental builds!
Using https://github.com/dasMulli/cli-incremental-perf-testbed, unscientific measurements for incremental builds (macOS 10.13.1, time dotnet build --no-restore) are:

| run / version | 2.0.3 | 2.1.3-preview-007232 | 2.2.0-preview1-007736 |
|-----------------|-------|----------------------|-----------------------|
| initial | 1m17s | 56s | 41s |
| 1st inremental | 55s | 36s | 22s |
| 2nd incremental | 1m3s | 37s | 23s |
| 3rd incremental | 52s | 34s | 22s |

Thanks for the continued effort! ❤️ 🍻

[davkean]

@dasMulli Thanks! As you can see, we're making some pretty significant progress in 2.2 - more coming.

[4creators]

@davkean It seems there is one very good test of build infrastructure performance using dotnet coreclr repo : https://github.com/Microsoft/msbuild/issues/2843

up-to-date check takes 55% of clean build time. In numbers:

• clean build time for managed tests only: 16:27.30
• up-to-date check for managed tests only without any build action: 09:04.63

[davkean]

@4creators At the moment we're focusing on reducing process overhead (enabling the C# compiler server and also MSBuild node reuse on .NET Core/dotnet). Afterwhich we're looking at reducing up-to-date builds. It would be interesting to see if CoreCLR's issues are due to their custom build or just merely MSBuild overhead. I suspect both are at fault.

[Pilchie]

Moving to 15.7. We've made a lot of progress here in 15.6, and more is already underway for 15.7. However, we also need to take stock and re-evaluate/re-profile to see what the current largest costs are.

[NinoFloris]

Thanks for all the work that landed in 2.1.0-preview1, It's highly appreciated!

I'd actually like to help with a few of these issues so new info around latest hotspots is very welcome, as it's hard to profile on osx.

[davkean]

As a heads up, more improvements have been made in Preview 2 - https://blogs.msdn.microsoft.com/dotnet/2018/04/11/announcing-net-core-2-1-preview-2/.

[davkean]

At this point, we've spent a large effort improving performance across build, solution load, branch switching and few other areas for VS 15.5, 15.6, 15.7 and continuing to do so in 15.8. Post 15.8 it will continue to be a focus. At this point, this overarching bug has now outlived its usefulness and we're no longer using it to drive issues. Each individual issue that it pointed out has individual bugs and we'll be using those to track them.

[kiwiant]

Agreed. Thanks for all the hard work on this. Performance is orders of magnitude better now.