Home: NuGet Package Manager UI for Solution is slow because restore is run for every project instead of after all projects are updated

[bradphelan]

Details about Problem

Currently Nuget PackageReference type project are still very slow and customers reported same project restored several times over and over again, which not only slows also causes many repeated network calls.
So need of smarter/streamlined restore process which only restore n projects in O(n) runtime which means we restore each project only once.
Runtime analysis: This is best we can achieve, we can't go better than this because each project from input need to be evaluated at least once. We're also doing all in memory evaluation in parallel for more performance gain.
This change decreased runtime by %50 for large test solutions like OrchardCore and another one which is contributed by user to us.
OrchardCore (158 projects) upgrade package is now 34 sec
Before it was between : 1min 4 sec to 7 min 12 sec. This big variation happen due to ordering which projects are evaluated because of same project restored several times, but now it's more consistent because restore happen just once per project.
So improvement for upgrade/downgrade is between about 2- 14 times faster, which is great and more sub-optimization are coming soon.

The PR#3559 to fix for this problem contains commits for fixing #9224 downgrade error problem too. Please check it this PR#3553 for description.

PM UI upgrade/downgrade actions:

_Before improvement verbose downgrade log:_ 25 sec.
https://gist.github.com/erdembayar/06574b16e8395f2fcd308df480d5dc55
In above log you'll find Restoring packages for C:\Users\eryondon\Downloads\nuget-sample-master\nuget-sample-master\A\Dtwt\Dtwt.csproj... 2 times, that means Dtwt.csproj project was restored 2 times.

_Before improvement verbose upgrade log:_ 26 sec.
https://gist.github.com/erdembayar/b8b465842e164603a12fb20a9df6e3b7
In above log you'll find Restoring packages for C:\Users\eryondon\Downloads\nuget-sample-master\nuget-sample-master\A\Dtwt\Dtwt.csproj... 2 times, that means Dtwt.csproj project was restored 2 times.

_After improvement verbose downgrade log:_ 14 sec which down from 25 sec.
https://gist.github.com/erdembayar/286bc50683668656467c3f12ff3f5481
But now you'll see Dtwt.csproj project was restored 1 only time.

_After improvement verbose upgrade log:_ 12 sec which is 60% down from 26 sec.
https://gist.github.com/erdembayar/00f881be9f421479e1fdb59e323105cd
But now you'll see Dtwt.csproj project was restored 1 only time.

PM UI update action:

_Before improvement verbose upgrade log:_
https://gist.github.com/erdembayar/31badeb81717955048c57ca42e08e7cb
ConsoleApp1.csproj... was restored 2 times.

_After improvement verbose upgrade log:_
https://gist.github.com/erdembayar/ee05724bd7a5281408014f641e93760e
ConsoleApp1.csproj... was restored only 1 time.

PM Consolidate:

_After improvement verbose upgrade log:_
https://gist.github.com/erdembayar/62f3b7c6210abd1f00eac9884609d9a8
ConsoleApp1.csproj... was restored only 1 time.

_PM UI Uninstall is 2 times faster now for OrchardCore solution._
Before https://gist.github.com/erdembayar/2ba554f169e4f078baa61976affa62d4 2 min 1 seconds.
After https://gist.github.com/erdembayar/2f9aebfbdc78e31d229a03223c8b1888 58 seconds.

Note: Before Preview build integrated action time telemetry event was emitted for each individual project restore evaluation, but now it's emitted once for whole solution or several projects. So you might see less number of this events but might see some of them is much longer duration than previously. It might skew your averages if anyone use for any purpose I am not aware of it.

---

Details about Problem

I upgraded to PackageReference because previous complaints about Nuget being SLOW was met with the response that I should upgrade to PackageReference because it is super fast

Microsoft Visual Studio Professional 2017 
Version 15.3.5
VisualStudio.15.Release/15.3.5+26730.16
Microsoft .NET Framework
Version 4.7.02046

Installed Version: Professional

Visual Basic 2017   00370-10200-08842-AA207
Microsoft Visual Basic 2017

Visual C# 2017   00370-10200-08842-AA207
Microsoft Visual C# 2017

Visual C++ 2017   00370-10200-08842-AA207
Microsoft Visual C++ 2017

Visual F# 4.1   00370-10200-08842-AA207
Microsoft Visual F# 4.1

Application Insights Tools for Visual Studio Package   8.8.00712.1
Application Insights Tools for Visual Studio

ASP.NET and Web Tools 2017   15.0.30726.0
ASP.NET and Web Tools 2017

ASP.NET Core Razor Language Services   1.0
Provides languages services for ASP.NET Core Razor.

ASP.NET Template Engine 2017   15.0.30726.0
ASP.NET Template Engine 2017

ASP.NET Web Frameworks and Tools 2017   5.2.50601.0
For additional information, visit https://www.asp.net/

Azure App Service Tools v3.0.0   15.0.30728.0
Azure App Service Tools v3.0.0

Common Azure Tools   1.10
Provides common services for use by Azure Mobile Services and Microsoft Azure Tools.

EditProj   1.0
This packages allows you to edit project files without the need to unload them first.

JavaScript Language Service   2.0
JavaScript Language Service

JetBrains ReSharper Ultimate 2017.2    Build 109.0.20170824.131346
JetBrains ReSharper Ultimate package for Microsoft Visual Studio. For more information about ReSharper Ultimate, visit http://www.jetbrains.com/resharper. Copyright © 2017 JetBrains, Inc.

JustDecompilePackage2017 Extension   1.0
JustDecompilePackage2017 Visual Studio Extension Detailed Info

Microsoft Azure Tools   2.9
Microsoft Azure Tools for Microsoft Visual Studio 2017 - v2.9.50719.1

Microsoft Continuous Delivery Tools for Visual Studio   0.3
Simplifying the configuration of continuous build integration and continuous build delivery from within the Visual Studio IDE.

Microsoft JVM Debugger   1.0
Provides support for connecting the Visual Studio debugger to JDWP compatible Java Virtual Machines

Microsoft MI-Based Debugger   1.0
Provides support for connecting Visual Studio to MI compatible debuggers

Microsoft Visual C++ Wizards   1.0
Microsoft Visual C++ Wizards

Multilingual App Toolkit   4.0
Multilingual App Toolkit helps you localize your Windows Store app by providing file management, pseudo and machine translation, translation editor, and build integration. http://aka.ms/matinstall

NuGet Package Manager   4.3.1
NuGet Package Manager in Visual Studio. For more information about NuGet, visit http://docs.nuget.org/.

Project File Tools   1.0.1
Provides Intellisense and other tooling for XML based project files such as .csproj and .vbproj files.

SQL Server Data Tools   15.1.61707.200
Microsoft SQL Server Data Tools

TargetFrameworkMigrator   1.0
Bulk Change .Net Projects Target Frameworks

TypeScript   2.3.4.0
TypeScript tools for Visual Studio

Visual Studio Code Debug Adapter Host Package   1.0
Interop layer for hosting Visual Studio Code debug adapters in Visual Studio

VSColorOutput   2.5.1
Color output for build and debug windows - http://mike-ward.net/vscoloroutput

VsVim   2.4.1.0
VsVim is a Vim emulator for Visual Studio

WebJobs Tools v1.0.0   15.0.30901.0
WebJobs Tools v1.0.0

OS version (i.e. win10 v1607 (14393.321)):

win10

Detailed repro steps so we can see the same problem

Create a solution in VS2017 with many projects.
goto the nuget packages for solution UI
Add a nuget packge to all projects at once.
You will see that instead of package restore being run once at the end it is
run many many times.
See the attached log for my project

Verbose Logs

https://gist.github.com/bradphelan/daab6cf4bcf2037de065b6d3d2172577

[anangaur]

/cc: @rrelyea @jainaashish
https://twitter.com/GeoffreyHuntley/status/917714192752304128

[emgarten]

The UI verifies that all projects are restored successfully for each project change, if it fails things are rolled back.

This could probably be improved with some clever restore batching, optimistically restoring the entire solution and assuming it will just work, or by removing the rollback behavior for PackageReference.

The workaround for this is to set package versions using a common .props file that all projects import. This allows you to update all packages by changing a single file.

[nkolev92]

Similar feedback provided by https://developercommunity.visualstudio.com/content/problem/599921/nuget-package-manager-slow-on-a-large-solution-for.html

[Seltzer]

For the love of god, please fix this because NuGet is hilariously unusable at the moment!!

NuGet will be turning 10 this year and it's still riddled with performance issues. Incidentally, 10 years is about the amount of time required for the Updates tab to load in VS.

[gregpakes]

I cannot believe this isn't getting more attention. It is literally unusable in a larger solution.

[anangaur]

/cc: @rconard, @cristinamanum (to verify this issue in CPVM context)

[nkolev92]

CPVM will suffer from the same problem @anangaur.
I have it on my list of general perf issues.

[nkolev92]

Note for the implementer.
As suggested above, it should be safe to batch all updates and only run 1 restore.
In fact that's arguably better than the current experience given the transitivity of PackageReference and how changes in child projects will affect the restore in parent projects.

[nkolev92]

I think there's also a correctness element here in addition to perf, see #9224

[erdembayar]

Hi. I start working on this problem.
Sorry I know this very late for working on this problem.
Currently I can't reproduce this problem on my local with VS 2019 16.7 Preview 3.1.
@bradphelan @Seltzer @gregpakes Can someone share me solution code where I can reproduce this problem?

Here is my sample solution with 20 projects used for my test:
https://github.com/erdembayar/NugetTestProj

Here is my restore log:
https://github.com/erdembayar/NugetTestProj/blob/master/NugetLog.txt

[gregpakes]

@erdembayar So we have 300 projects. I think that might be where you are falling over.

[Seltzer]

@erdembayar We only have 44 projects but to better reflect reality, you'll probably want to add more than jQuery and JSON .NET to each project. I'll attempt to upload a sample sln which vaguely matches our one sometime in the next few days.

I've never properly investigated it myself so I'm not sure what the exact cause is but it definitely feels like there's an algorithm with unintended exponential complexity somewhere in the mix and it probably suffers due to some combination of number of projects and number of NuGet refs per project. If it's firing off n^2 network calls or something for routine operations, that would explain a lot.

Anyway, thanks for giving this some attention :)

[nkolev92]

I synced up with @erdembayar.

The challenge is when we have multiple PackageReference projects referencing each other.

Let's take for example a simple sln with 2 projects.
Parent -> Child, and each one of the the 2 have the exact same packages, regardless of the number of packages.

If we try to install a new package to both projects at the same time, we'd run separate restores for each project and it's parents.

• So say we chose Child first.
  We'll do a restore for Child + Parent and validate that they are ok with the change.

• Then we do Parent second.
  We run a restore for Parent with the change to make sure they are ok with the change.

Now, we do sort projects in a dependency order, so it's not going to be undeterministic, but it arguably more frequently than we need.

So the algorithm is going to be n * m at worst, where n is the number of projects, while m is the parent count of each project.

We are not making extra network calls, but we are wasting some cycles.

Code pointers:

• Gather Actions - https://github.com/NuGet/NuGet.Client/blob/df00340c27f8fb257bf6ec3eee5f60521d56e707/src/NuGet.Clients/NuGet.PackageManagement.UI/Actions/UIActionEngine.cs#L840-L851
• Execute Actions https://github.com/NuGet/NuGet.Client/blob/df00340c27f8fb257bf6ec3eee5f60521d56e707/src/NuGet.Clients/NuGet.PackageManagement.UI/Actions/UIActionEngine.cs#L788

The suggestion is to batch all the PackageReference changes into one, and only restore each project once.

This will have different correctness characteristics from before, but I'd argue that it's better this way because of https://github.com/NuGet/Home/issues/9224.

[erdembayar]

@erdembayar We only have 44 projects but to better reflect reality, you'll probably want to add more than jQuery and JSON .NET to each project. I'll attempt to upload a sample sln which vaguely matches our one sometime in the next few days.

I've never properly investigated it myself so I'm not sure what the exact cause is but it definitely feels like there's an algorithm with unintended exponential complexity somewhere in the mix and it probably suffers due to some combination of number of projects and number of NuGet refs per project. If it's firing off n^2 network calls or something for routine operations, that would explain a lot.

Anyway, thanks for giving this some attention :)

@Seltzer Just in case checking. Would you be able to create sample? I have 1 small sample which I am working on, but more samples are welcome to cover all possible cases.

[Seltzer]

Hi @erdembayar, sorry for the delay. I've created a sample solution based on our codebase and added you and @nkolev92 as collaborators to its repo.

I timed 3 mins for the Updates tab to load the first time, and 1 min for it to load after restarting VS and 1 min for it load a third time after closing and reopening 'Manage NuGet Packages for Solution' with no changes. For performing a single update, waiting a minute isn't a huge issue but if it becomes more painful when doing multiple updates.

I haven't had the chance to benchmark the actual addition/update of dependencies as above but feel free to test it out with that sln.

Also, please let us know if you think we're doing anything wrong. That code is kinda old and we had to do some slightly dubious things to support projects being used both in the context of their own self-contained solutions as well as in larger mono-repo solutions.

Cheers,
Nathan

[nkolev92]

Hey @Seltzer,

Thanks for the hard work creating that repro solution.
Are any of the projects PackageReference? Quickly clicking through the repo, I see mostly packages.config projects.

[Seltzer]

Oops, I accidentally based the sample on the pre-PackageReference branch of our codebase. I've now migrated as many projects as possible to PackageReference, so that's basically all of them except for the ASP .NET projects which the VS migration tool can't handle.

I've added:

• SeltzerSample.sln which contains all 42 mixed packages.config/PackageRef projects with ?? installed packages, 89 pending updates and 20 consolidations
• SeltzerSamplePackageRef.sln which contains the PackageRef-only subset of the above - that's 24 projects with ?? installed packages, 35 pending updates and 5 consolidations.

Hopefully this will help. When I get a chance after work, I'll try to come up with some concrete examples of packages being slow to add/upgrade though it might be harder as we have fewer projects than others, esp. once you ignore the packages.config ones.

[erdembayar]

@Seltzer I don't see any new repository.
What is the name of it?

[nkolev92]

We sync-ed up offline, I provided the link. :)