Project-system: Solution load performance

Created on 29 Nov 2018 · 22Comments · Source: dotnet/project-system

This is an overarching issue that we're using to track solution load performance issues across VS against the new project system.

Metrics | Meaning
---|---
TTE (Time to Solution Explorer) | Time it takes from first open -> showing project tree in Solution Explorer.
TTL (Time to Language Service) | Time it takes from first open -> sending design-time build results (with mscorlib) to Roslyn).
TTD (Time to Dependency node) | Time it takes from first open -> show all results in the Dependency node in Solution Explorer.
TTT (Time to Test) | Time it takes from first open -> showing every test in Test Explorer.
TTB (Time to Branch Switch) | Time it takes to switch to a branch with project & file changes

Scenario | Meaning
---|---
Double-click | Double-clicking the project in Solution Explorer.
File -> Open | Opening the solution from an already opened VS.

CPU/Blocked/IO Time

Issues that affect the clock time of solution load due to high CPU usage, or blocked time due to IO, lock contention or awaited time.

% (Approx.) |Bug|Owner|Metric|Scenario|Notes
---:|---|-----|----|:------:|----|
~5000ms~|~ExtensionManagerService.ShouldDeletePendingUninstalls causes ~5 second UI delay after opening empty environment~|Extensibility|TTL|Both
~16%~|~Large amount of lock contention in dependency node~|Project|TTD|Both
15%|Perf: DependenciesTree UpdateTree logic (BuildTreeForSnapshotAsync) is way too expensive|Project|TTD|Both
~2%~|~Large amount of dictionary enumeration in dependency node~|Project|TTD|Both|PR #4365
~180ms~|~Environment.DeduplicateVariables is 3% of a UI delay opening an empty environment doing an incorrect comparison~|AzureDevOps|TTL|Both
? |Ensure that we only have a single design-time build on open|Project|TTL|Both
? |Inefficient way to create the first version of the dependencies tree after loading a project|Project|TTD|Both
~?~ |~Dependency node is doing lots of work on unload~|Project|TTB|Both
? |Investigating nominating restore during evaluation as well as design-time|Project|TTL|Both
? |Design-time builds in CPS are doing too much work because BuildingProject is set to true|Project|TTL|Both
? |~Large amount of lock contention in dependency node~|Project|TTD|Both|PR #4364
~?~ |~Investigate whether there is a benefit to merging dlls~|Project|TTE|Both

GC Time

Issues that affect GC time from all generations and large object heap (LOH), and issues that affect the peak working set of Visual Studio.

% (Approx.) |Bug|Owner|Metric|Scenario|Notes
---:|:---|:-----|:----|:------|----|
20%-60%|Consume reduced data from design-time build for dependencies node|Project|TTL|Both|
~20%~|~OOMFeedManager/DependencyNode.Package is responsible for 20% (233 MB) of all allocations during a large solution load~|Setup|TTL|Both
17.5%|PropertyChangedEventManager/WeakEventTable.Purge are responsible for 17.5% (170 MB) of allocations during solution load|WPF|TTE|Both
~13.5%~|~ExtractPropertyFunction allocates a huge amount of data during solution load~|MSBuild|TTE|Both
8%|ExpandPropertiesLeaveTypedAndEscaped (incorrectly) makes the assumption that it's ReuseableStringBuilder won't be resized|MSBuild|TTE|Both|
~7%~|~QueryStatus for "Start Debugging" allocates 7% (100 MB) of all allocations during solution load~|Solution|TTE|Both
6%|Communication between VS -> MSBuild is pushing 6% (100MB) of allocations onto the LOH|MSBuild|TTL|Both
5%|AvatarCache.Equals is allocating a huge amount of boxed "bytes"|Identity|TTL|Both
5.5%|FileWatcher indirectly creates ~42 MB of FileInfo's during solution load|IDE|TTL|Both
~5%~|~5% of overall allocations loading a large solution is the Project Id -> Project map in Roslyn~|Roslyn|TTL|Both|PR: https://github.com/dotnet/roslyn/pull/31405/
~4%~|~BuildUpToDateCheck.OnChanged allocates 4% of all data opening Roslyn.sln~|Project|TTE|Both|PR #4333
3.8%|Memory allocation in GetProjectItemSpecsFromSnapshot|Project|TTD|Both
~3.2%~|~OnOtherProjectDependenciesChanged allocates of 26 MB of temporary List during solution load~|Project|TTD|Both|PR #4334
~2.7%~|~Dependency node is boxing large number of enumerators allocating 2.7% during solution load~|Project|TTD|Both
2%|Use of PathHelper.MakeRelative consuming large amounts of memory on solution load|Project|TTD|Both
2.1%|InterningBinaryReader+Buffer allocates 16MB opening large solution|MSBuild|TTL|Both
~1.5%~|~Don't allocate RegEx Match objects~|MSBuild|TTL|Both|PR Microsoft/msbuild#3969
~1.3%~|~DependencyNodeComparer.GetHashCode is responsible for 1.3% of allocations during a large solution load~|Setup|TTD|Both
~1%~|~Getting filename/extension metadata allocations 1% of solution-wide design-time build~|MSBuild|TTL|Both
1%|MetadataReferenceHandler is allocating a lot trying to root the reference |Project|TTL|Both
~1%~|~Avoid allocations mutating tree~|CPS|TTE|Both|PR: https://devdiv.visualstudio.com/DevDiv/_git/CPS/pullrequest/152624
~1%~|~Avoid boxing IntPtr~|CPS|TTE|Both|PR: https://devdiv.visualstudio.com/DevDiv/_git/CPS/pullrequest/152620
? |Move away from returning file paths for dependency nodes that don't need it|Project|TTD|Both

Working Set

Issues that affect the stable working set (sizes of caches, data structures, etc) of Visual Studio. The higher the working set, the more likely the GC will run through all generations. Short term allocations that are affect the peak working set are tracked by GC Time

% (Approx.) |Bug|Owner|Metric|Scenario|Milestone|Notes
---:|---|-----|----|:------:|---|----|
~7%~ | ~Don't cache build results in BuildManager~ | CPS | TTE | Both
? | Dependencies node should share identical subtrees between projects | Project | TTD | Both
? | DependencyIDs create a lot of long, duplicate strings | Project | TTE | Both
2.7% | VisualStudioOptionsProcessor holds on to command-line string causing heap growth | Roslyn | TTE | Both
~0.6 - 2.5%~ | ~Many duplicate strings held by ProjectItemInstance.TaskItem._definingFileEscaped~ | MSBuild | TTL | Both
2.4% | Many duplicate strings held by Microsoft.Build.Execution.ProjectMetadataInstance._escapedValue | MSBuild | TTE | Both
2% | CPS wastes huge amount of memory (up to 2% of heap) storing rules names and paths | CPS | TTE | Both
~1%~ | ~Many duplicate strings held by MSBuildGlob.globRoot~ | MSBuild | TTE | Both
~6%~ | ~The dependencies tree uses quite lots of memory - TreeFlags~ | Project | TTE | Both | 16.0
~1%~ | ~TaskRegistry wastes up to 1% of the heap on duplicate strings~ | MSBuild | TTE | Both | 16.1
~15%~ | ~Metadata property storage is inefficient in VisualStudioProject~ | Roslyn | TTE | Both | 16.3 P2

Tenet-Performance Tracking Triage-Approved

Source

davkean

👍3 ❤1 🎉1

Most helpful comment

The two items owned by "Setup" have been merged in.

davkean on 10 Dec 2018

👍3

All 22 comments

Tagging myself to get mentions.

Pilchie on 30 Nov 2018

@jasonmalinowski Just merged in https://github.com/dotnet/roslyn/issues/31306.

davkean on 30 Nov 2018

Tagging myself to get mentions. @jjmew

jjmew on 5 Dec 2018

Also joining the tagging party

cartermp on 6 Dec 2018

In future, you can just use:

davkean on 6 Dec 2018

@jmarolf tagging myself for updates

jmarolf on 6 Dec 2018

As I am already subscribed to the whole project it doesn't help doing the subscribe since it just goes to the same place that all other notifications go :( . If you comment then you get a special notification sent by [email protected].

jjmew on 6 Dec 2018

Ah that makes sense.

davkean on 6 Dec 2018

I unsubscribed then resubscribed so now I'm subscribed to the thread, but the notifications still come from [email protected] :(

davidwengier on 6 Dec 2018

Look at the cc'd person, it gives you an indication of why you got a notification.

davkean on 6 Dec 2018

Ahh yes, it has [email protected] as the email, which would be enough to configure a rule against.

davidwengier on 7 Dec 2018

The two items owned by "Setup" have been merged in.

davkean on 10 Dec 2018

👍3

Solution folks has merged in the QueryStatus for "Start Debugging" allocations.

davkean on 18 Dec 2018

@drewnoakes Merged in a fix for Large amount of lock contention in dependency node.

davkean on 29 Dec 2018

Extensibility folks have fixed ExtensionManagerService.ShouldDeletePendingUninstalls causes ~5 second UI delay after opening empty environment.

davkean on 6 Jan 2019

Assigning myself here for the issues with Owner: MSBuild.

livarcocc on 15 Mar 2019

MSBuild has fixed TaskRegistry wastes up to 1% of the heap on duplicate strings

davkean on 23 Apr 2019

The WPF item _"PropertyChangedEventManager/WeakEventTable.Purge are responsible for 17.5% (170 MB) of allocations during solution load"_ was marked as fixed back in Janurary.