Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

.NET Core/.NET Standard build performance #2789

Closed
davkean opened this issue Sep 6, 2017 · 15 comments
Closed

.NET Core/.NET Standard build performance #2789

davkean opened this issue Sep 6, 2017 · 15 comments
Assignees
Labels
Tenet-Performance This issue affects the "Performance" tenet. Tracking Tracking a bug against another repo or a larger thematic issue tracking a group of work.
Milestone

Comments

@davkean
Copy link
Member

davkean commented Sep 6, 2017

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 dotnet/msbuild#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: dotnet/msbuild#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: dotnet/msbuild#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.
@davkean davkean added the Tenet-Performance This issue affects the "Performance" tenet. label Sep 6, 2017
@davkean davkean self-assigned this Sep 6, 2017
@davkean davkean added this to the 15.5 milestone Sep 6, 2017
@davkean davkean added the Tracking Tracking a bug against another repo or a larger thematic issue tracking a group of work. label Sep 6, 2017
@DamianEdwards
Copy link
Member

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

@davkean
Copy link
Member Author

davkean commented Sep 13, 2017

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

@DamianEdwards
Copy link
Member

There's dotnet/msbuild#2015 too

@davkean
Copy link
Member Author

davkean commented Sep 13, 2017

Hmm, need to understand why dotnet/msbuild#2192 hasn't moved the mile - does it only kick in on the .NET Core build?

@kiwiant
Copy link

kiwiant commented Sep 19, 2017

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).

radical pushed a commit to mono/msbuild that referenced this issue Oct 25, 2017
Fixes: dotnet#2434
Partially fixes: dotnet#2429

This change converts MSBuildNameIgnoreCaseComparer to a stateless comparer by implementing IConstrainedEqualityComparer, this avoids:

1. Creating a new comparer for every collection (saves ~1% of allocations)
2. Locking within Equals/GetHashCode (saves ~0.2% of allocations)

This saves approx 300ms running a design time build over the project called out in dotnet/project-system#2789.
@Pilchie Pilchie modified the milestones: 15.5, 15.6 Nov 1, 2017
@Pilchie
Copy link
Member

Pilchie commented Nov 1, 2017

Moving remaining work to 15.6.

@dasMulli
Copy link

dasMulli commented Dec 7, 2017

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
Copy link
Member Author

davkean commented Dec 7, 2017

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

@4creators
Copy link

4creators commented Jan 7, 2018

@davkean It seems there is one very good test of build infrastructure performance using dotnet coreclr repo : dotnet/msbuild#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
Copy link
Member Author

davkean commented Jan 7, 2018

@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
Copy link
Member

Pilchie commented Feb 12, 2018

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.

@Pilchie Pilchie modified the milestones: 15.6, 15.7 Feb 12, 2018
@NinoFloris
Copy link

NinoFloris commented Mar 9, 2018

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
Copy link
Member Author

davkean commented Apr 16, 2018

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/.

image

@Pilchie Pilchie removed this from the 15.7 milestone Apr 16, 2018
@Pilchie Pilchie added this to the 15.8 milestone Apr 16, 2018
@davkean
Copy link
Member Author

davkean commented May 23, 2018

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.

@davkean davkean closed this as completed May 23, 2018
@kiwiant
Copy link

kiwiant commented May 23, 2018

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

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Tenet-Performance This issue affects the "Performance" tenet. Tracking Tracking a bug against another repo or a larger thematic issue tracking a group of work.
Projects
None yet
Development

No branches or pull requests

7 participants