Add gzip support for v3 feeds to improve registration json file download performance

[OliverRC]

Since moving to VS2015 and Nuget 3 the Update-Package command takes an age to complete.
It just sits stuck on "Attempting to gather dependencies information"

Attempting to gather dependencies information for multiple packages with respect to project 'Local.ProjectName', targeting '.NETFramework,Version=v4.6.1'

Specifying an exact version or source makes not difference. Sits at this step for what seems like minutes.

[emgarten]

@OliverRC what version of NuGet are you using? The latest is 3.3.0.

[yishaigalatzer]

Also @OliverRC what sources are you using? Are you by any chance using a fileshare? See this blog for reference

[marisks]

It is really slow for me too. I have NuGet 3.3.0. And I am using different package sources:

• http://nuget.episerver.com/feed/packages.svc/
• internal company's NuGet source
• local folder

Is there a way do debug/trace what's happening?

[OliverRC]

I am using NuGet 3.3.0.
I do have 2 sources, nuget.org and an internally hosted Nuget feed. No fileshare.

We've always had 2 sources and prior to VS2015 and NuGet 3 it has been quick.
As @marisks has stated, is there any way of seeing what it's actually trying to do?

[yishaigalatzer]

There are two changes in NuGet 3.X compared to 2.X (for various scenarios, not just updates)

1. We access all sources, where before we might have just accessed the first one, so a second source being slow can cause things to go slower, but will be a more correct answer.
2. We collect all version information so we can run update in one step. If you have many many versions of available of a particular package on a slow source, this could make things slower. We have a plan for a fix by doing some sort of a Lazy/opportunistic downloading of version information and getting more as we need.

Things you can look into:

1. Use fiddler to see what requests are being made, at the gather phase this is mostly what is going on (of course fiddler wouldn't talk to your local source).
2. Follow the advice on the following blogs we released to improve local source speed. http://blog.nuget.org/20160113/Accelerate-your-NuGet.Server.html and http://blog.nuget.org/20150922/Accelerate-Package-Source.html
3. Consider looking into using project.json based projects (not applicable everywhere yet, but this is how we build our stuff), where updating packages is a lot simpler and can be done completely automatically at each build using a * notation. In this mode updating a package is a simple as changing the project.json file and nothing changes in your csproj files which makes things a lot clearner among other improvements. See github.com/nuget/nuget.client project for an example.
4. You can also clone the code above and look into it for your scenario and see where it is hanging.

[yishaigalatzer]

CC @johnataylor who is going to work on improving this in 3.4

[marisks]

I understood why it was slow for me. My "internal company's NuGet source" is available only in the company's network (or when using VPN). But I was updating packages from home and was not connected through VPN.

The only question is why NuGet is so slow in this case. Failure response is sent within 10-15 seconds, but NuGet is gathering dependency information for 15-20 minutes.

[yishaigalatzer]

Because it is making multiple request, and doesn’t recognize this feed is down. We plan to add a feature for detecting this and warning you in one of the future releases.

[OliverRC]

We access all sources, where before we might have just accessed the first one, so a second source being slow can cause things to go slower, but will be a more correct answer."

Does it enumerate all sources for each dependency?

I have read this, it doesn't however explain the level of "slowness".

1. Prior, we used the All aggregate source which to my understanding would have done something similar.
2. Both sources are quick from my machine in NuGet 2 so this does not explain the minutes it takes to "resolve dependencies"
3. Specifying -Source should at least help the initial package... the dependencies I guess still need to be checked against all sources

Consider looking into using project.json based projects

For WebAPI (MV6) I think these are all still in Preview.

We collect all version information so we can run update in one step.

What does this mean? Do you get ALL the versions of ALL dependencies from ALL sources?
So what if I have 100 versions of a package (say because of automated builds?)

Ultimately having to wait 5 minutes to update a package with 1 dependency indicates some issue,
Will use Fiddler to try see what is going on.

[yishaigalatzer]

1. Yes it does enumerate each source for each dependencies, and all versions, nuget 2 just picked the latest hoping it is going to work, and sometimes getting into long loops of retrying. NuGet 3 tries to collect the metadata upfront, so I would guess in your case the packages you are consuming have many many versions?
2. Specifying -source - Are you running powershell or nuget.exe please clarify
3. project.json I'm referring to has nothing to do with MVC 6. It is fully in RTM for projects using .csproj + UWP, PCL but can be used in console apps and class libraries as well as other application types (see how we build nuget.exe itself).

[OliverRC]

Yes it does enumerate each source for each dependencies, and all versions, nuget 2 just picked the latest hoping it is going to work, and sometimes getting into long loops of retrying. NuGet 3 tries to collect the metadata upfront, so I would guess in your case the packages you are consuming have many many versions?

I admit I probably don't 100% grasp the full complexity of the problem but from the outside this seems like an odd way of doing things.

In a package I clearly state which version my dependencies should be, why then would you need to enumerate ALL versions? Sure, semantic versioning can be tricky with ranges at all that but at a minimum we hint at the version required that still means only a subset needs to be enumerated.

I feel my particular problem comes from the fact that we have continuous integration which builds our internal packages on every check-in, meaning that we have lots of version... which (need to double check this) is causing the enumeration to be slow. That said I don't think this is an uncommon scenario.

We

[yishaigalatzer]

We completely agree and plan to improve on this on the next release.

In the meantime I have a few suggestions

1. For your ci feed have a policy that maintains a few last versions (say one week) and pin critical versions
2. Consider moving to the project.json model, which is how we believe CI updates should work (auto update on restore)

Regardless we are on the same page and plan to improve this. Work on this improvement has started already

[yishaigalatzer]

@OliverRC we have made a few strides in this area, but I'm not sure if we covered your scenario enough. Would you mind trying to use NuGet 3.4RC and tell us what you see so far?

https://dist.nuget.org/index.html

I'm keeping this open in 3.5 because we plan to keep investing in this area after the 3.4 release, but we would really like to know how much this impacted your scenario so far.

[johnataylor]

Couple of additional comments on this. With regards to doing a more intelligent range based request for the package version. We looked into this in some detail, and we actually have protocol that allows us to arrange package metadata for multiple versions more effectively (we effectively split the metadata into a tree and walk that if there is a very large number of versions.)

However, we have found it difficult to optimize this in the light of multiple sources. In fact difficult to fully leverage our own protocol. Consider fetching the metadata for a package X that depends on package Y from two sources A and B. When we look at source A we see versions of X and we see their dependencies on Y. Because we see those dependencies we know what not to get from A in terms of Y's metadata. However when we look at B we see more versions of X some of which imply that we should have technically gathered more metadata about Y from A. So given the assumption that we want to be able to resolve if we possible can we have a choice of either getting everything from everywhere or iterating and possibly going back to sources we've already been to to get more metadata. So far the implementation choice has been to gather everything from everywhere but do so in a concurrent way.

One immediate thing that would be done is divide the metadata between release and pre-release. Currently we mix these together. Separating these, with an assumption that for packages that have many, many versions many of those versions are pre-release, this would help.

In 3.4 we at least fixed the problem that the metadata wasn't gzipped. That was an unfortunate oversight in the initial releases of 3.x. gzipping the JSON can reduce it by as much as 80%.

[BMarques]

3.4 RC1 improved this issue considerably in comparison with 3.3, specially to find updates and consolidation but it's still slow, when it's "Attempting to gather dependency information". I normally have to go back to Visual Studio 2013 to update the nugets instantly.

[OliverRC]

Thanks for the work on this! I will try out the RC version and feedback

[bradphelan]

It's not fully integrated. PackageRefernece breaks many nugent packages. """Some examples of scenarios that will not be supported include content folders (we have introduced ContentFiles), XDT transforms, PowerShell scripts i.e. install.ps1 and uninstall.ps1 (only init.ps1 is supported)""" It's not ready for production. And nuget is doing NOTHING. It has already downloaded the assemblies. All it has to do is patch some project files and package.config files. In a solution of 60 projects it is exactly the same patch done to every single project. I am pretty sure it's making network requests for information that it all ready has thousands of times over or doing weird things with the visual studio DTE.

…

On Wed, 17 May 2017, 18:37 Justin Emgarten ***@***.***> wrote: @bradphelan <https://github.com/bradphelan> executing nuget actions includes the time it takes to add and remove assembly references and content files through Visual Studio. Network traffic is done at that point and there is relatively little happening in NuGet. The time here can be impacted by the size of the project and the number of assemblies being added. I suggest switching to *PackageReference* which is now supported for non-NETCore projects in Visual Studio 15.2. It works by writing out all references to a file on disk instead of using Visual Studio to add/remove each references, which is the bottle neck in packages.config. http://blog.nuget.org/20170316/NuGet-now-fully-integrated-into-MSBuild.html — You are receiving this because you were mentioned. Reply to this email directly, view it on GitHub <#1909 (comment)>, or mute the thread <https://github.com/notifications/unsubscribe-auth/AABE8uPco2CHNj9TOH_FiAzeb3Fu4krYks5r6yJcgaJpZM4HCI7w> .

[emgarten]

And nuget is doing NOTHING. It has already downloaded the assemblies. All it has to do is patch some project files and package.config files. In a solution of 60 projects it is exactly the same patch done to every single project. I am pretty sure it's making network requests for information that it all ready has thousands of times over or doing weird things with the visual studio DTE.

If you find this to be the case please open a new issue for it with details as to exactly where this is happening. I would be happy to fix this and improve the performance here for packages.config projects.

[bradphelan]

How to find "exactly where it is happening" All I see in the log is stuff like

I just can't imagine what an 8 core multi gigaherz processor is doing for 30 seconds as it attempts to update a 30 line config file. The CPU is pegged at 25% usage

How to get nuget to spit out more info that could help you find the source of the problem. I would gladly assist if you can provide any suggestions.

[bradphelan]

I have JetBrains profiler as well. If you can suggest exactly what I should be trying to profile I can have a go at that.

[bradphelan]

Strangely Nuget is hammering the assembly load mechanism as you can see.

I can't upload the actual profiler output because even when zipped it is 87MB

[bradphelan]

This issue might be related. Others have reported that allowing Nuget to add binding redirects is terribly slow. #1147

[bradphelan]

Turning off nuget generated binding redirects seems to speed the install. We are now at an average of 8 to 12 seconds per projects rather than 30 to 40 seconds. Something must be wrong with the binding redirect generation.

[durandt]

Hi,

I've been experiencing the same problem for about a couple of weeks.

Attempting to gather dependency information for package 'Microsoft.Owin.Security.OpenIdConnect.3.1.0' with respect to project 'MinITOAuth.Web', targeting '.NETFramework,Version=v4.5.2'
Gathering dependency information took 43,78 sec

It often takes around 30-40seconds. It does sometimes (rarely) take less than a couple of seconds.

I'm using VS2015 and NuGet 3.5.0

I have unchecked and then removed all of my custom config sources. I have even tried to install packages from the local disk instead of NuGet.

My custom NuGet package sources are:

https://api.nuget.org/v3/index.json
C:\Users<username>\NuGet

My Machine-wide package sources:

https://www.nuget.org/api/v2/curated-feeds/microsoftdotnet/

I recently installed the Service Fabric SDK to Visual Studio which added a machine-wide local Service Fabric package source. I've tried to remove the file from "C:\ProgramData\NuGet\Config\ServiceFabricSDK.config" but it keeps coming back when I launch VS, though it now points at nuget.org:
https://api.nuget.org/v3/index.json

Is there any easy way to see what NuGet is doing in 3.5.0?

[durandt]

I've just realized I could use the Verbose option of Install-Package:

PM> Install-Package Microsoft.Owin.Security.OpenIdConnect -Source Home -Verbose

Where Home is the name of my local repository.

See the attached log file for the output of the Verbose command.

Install-Package is performing many calls toward nuget.org and I'm wondering if this is what is supposed to happen.

nuget.log.txt

[ashotmuradian]

Increasing connections limit in devenv.exe.config file helped me:

...
<system.net>
  <!-- these 3 lines were already there -->
  <settings>
	<ipv6 enabled="true"/>
  </settings>
  <!-- I've added only these 3 lines -->
  <connectionManagement>
	<add address="*" maxconnection="256" />
  </connectionManagement>
</system.net>
...

Update: after the latest update 15.2 (26430.14), it's necessary to edit devenv.exe.config file again

[sandord]

Increasing connections limit in devenv.exe.config file helped me:

This is golden.

[bradphelan]

I tried that. It still took 17 minutes to update around 60 projects from one version of a nuget package to another

[oliverjanik]

Why is this closed? This is absolutely an issue. Today I was upgrading one of our dependencies. Nuget made about 1000 requests before it completed. This is getting worse with .Net Core as everything is split into millions of small packages.

[sandord]

Yeah, even though the increased connection limit speeds things up, it is anything but blazingly fast.

[OliverRC]

I think one thing that makes this very slow is the response time from the Nuget.org feed. This is just a snippet from a -verbose update-package command.

OK https://api.nuget.org/v3/registration2-gz/runtime.fedora.24-x64.runtime.native.system.security.cryptography/index.json 5095ms OK https://api.nuget.org/v3/registration2-gz/microsoft.bcl/index.json 6591ms OK https://api.nuget.org/v3/registration2-gz/runtime.debian.8-x64.runtime.native.system.security.cryptography/index.json 6511ms OK https://api.nuget.org/v3/registration2-gz/runtime.opensuse.42.1-x64.runtime.native.system.security.cryptography/index.json 5146ms OK https://api.nuget.org/v3/registration2-gz/runtime.opensuse.13.2-x64.runtime.native.system.security.cryptography/index.json 6108ms OK https://api.nuget.org/v3/registration2-gz/runtime.rhel.7-x64.runtime.native.system.security.cryptography/index.json 5558ms OK https://api.nuget.org/v3/registration2-gz/runtime.osx.10.10-x64.runtime.native.system.security.cryptography/index.json 6390ms OK https://api.nuget.org/v3/registration2-gz/runtime.ubuntu.14.04-x64.runtime.native.system.security.cryptography/index.json 5732ms OK https://api.nuget.org/v3/registration2-gz/runtime.ubuntu.16.04-x64.runtime.native.system.security.cryptography/index.json 5238ms OK https://api.nuget.org/v3/registration2-gz/microsoft.framework.configuration/index.json 5097ms OK https://api.nuget.org/v3/registration2-gz/runtime.ubuntu.16.10-x64.runtime.native.system.security.cryptography/index.json 5449ms OK https://api.nuget.org/v3/registration2-gz/validation/index.json 4312ms OK https://api.nuget.org/v3/registration2-gz/microsoft.framework.configurationmodel.interfaces/index.json 4928ms OK https://api.nuget.org/v3/registration2-gz/system.xml.xpath/index.json 4709ms

It makes 1000's of requests to https://api.nuget.org/v3 all of which are >4s each.
Seems like simply improving the response times on the feed would help things greatly.

[OliverRC]

This is NOT closed!

[ashclarke]

Agreed. Same issue here - custom package source (MyGet) and a super slow update time in VS2015.

1 package, updated in 11 projects, took 4 minutes 24 seconds.

Notes:

• I have also applied the maxconnection="256" change to devenv.exe.config.
• I attempted to skip binding redirects, as per this comment/issue, and I gained about 4.5 seconds (Time Elapsed: 00:04:19.9243998)

Nuget version
3.5.0.1484

VS Version
14.0.25431.01 Update 3

Output window log (TL;DR version - Only times)

Attempting to gather dependency information for package 'packagename.Package.1.0.0.169' with respect to project '...ProjectName...
Gathering dependency information took 5.46 sec
Resolving dependency information took 0 ms

Attempting to gather dependency information for package 'packagename.Package.1.0.0.169' with respect to project '...ProjectName...
Gathering dependency information took 1.57 sec
Resolving dependency information took 0 ms

Attempting to gather dependency information for package 'packagename.Package.1.0.0.169' with respect to project '...ProjectName...
Gathering dependency information took 646.19 ms
Resolving dependency information took 0 ms

Attempting to gather dependency information for package 'packagename.Package.1.0.0.169' with respect to project '...ProjectName...
Gathering dependency information took 121.82 ms
Resolving dependency information took 0 ms

Attempting to gather dependency information for package 'packagename.Package.1.0.0.169' with respect to project '...ProjectName...
Gathering dependency information took 145.29 ms
Resolving dependency information took 0 ms

Attempting to gather dependency information for package 'packagename.Package.1.0.0.169' with respect to project '...ProjectName...
Gathering dependency information took 115.17 ms
Resolving dependency information took 0 ms

Attempting to gather dependency information for package 'packagename.Package.1.0.0.169' with respect to project '...ProjectName...
Gathering dependency information took 134.14 ms
Resolving dependency information took 0 ms

Attempting to gather dependency information for package 'packagename.Package.1.0.0.169' with respect to project '...ProjectName...
Gathering dependency information took 141.49 ms
Resolving dependency information took 0 ms

Attempting to gather dependency information for package 'packagename.Package.1.0.0.169' with respect to project '...ProjectName...
Gathering dependency information took 674.13 ms
Resolving dependency information took 0 ms

Attempting to gather dependency information for package 'packagename.Package.1.0.0.169' with respect to project '...ProjectName...
Gathering dependency information took 229.16 ms
Resolving dependency information took 0 ms

Attempting to gather dependency information for package 'packagename.Package.1.0.0.169' with respect to project '...ProjectName...
Gathering dependency information took 215.6 ms
Resolving dependency information took 0 ms

Retrieving package 'packagename.Package 1.0.0.169' from 'orgnameMyGet'.
  GET https://www.myget.org/F/.../package/packagename.Package/1.0.0.169
Removed package 'packagename.Package.1.0.0.162' from 'packages.config'
  OK https://www.myget.org/F/.../package/packagename.Package/1.0.0.169 467ms

Executing nuget actions took 35.6 sec
Executing nuget actions took 19.92 sec
Executing nuget actions took 10.41 sec
Executing nuget actions took 14.48 sec
Executing nuget actions took 19.25 sec
Executing nuget actions took 14.05 sec
Executing nuget actions took 19.86 sec
Executing nuget actions took 19.84 sec
Executing nuget actions took 58.57 sec
Executing nuget actions took 18.26 sec
Executing nuget actions took 23.47 sec
========== Finished ==========
Time Elapsed: 00:04:24.4162187

[JackGrinningCat]

I just recently updated from VS2015 to VS2017.

Out Build server, Is using the version nuget 3.3.0.212.

This is the first time updating a package with vs2017, and it took around 59 seconds with a warning about lowest dependency. I removed the package and reinstalled the package.
Then it took around 15 seconds.

Open the Package Manager Console
Package Manager Console Host Version 4.2.0.2457

I restarted Visual Studio to check the reinstall behavior,

Gathering dependency information took 12,55 sec

Well that's my state. I think my dependency tree should be rather simple.
I would print the dependency tree, but nuget does not serve this ^^

So I guess there is an error, actually, the first time it took so long I closed Visual Studio. :)

Update: I was talking with an colleague about it. He commented it, that he got on the same day also problems but did go in the direction of our IT/Network. So tried the same case again. This time 5 seconds.
So I'm not hundred percent confident, where the problem is coming from. I raising issued at Nuget as it is the surface, but I lack the possibilities to analyse underlying problems.

It's like blaming the service people that the producer does not deliver one day before and I feel sorry for it.
But please help us: If you would provide a small engineering example how to pin-point underlying service problems, I would be the first to go to the our service providers and raise such objection there (like our internal nuget server, the old TFS nuget version, or the too complicated handling of the prerelease versions).

If a verbosity option or a measure option will help. The content and amount of such arising issues might drop.

[rollsch]

This takes at least 5-6 minutes per package on any aspnet project I have, even reinstalling existing packages takes minutes upon minutes. No network activity and no cpu activity, just sits there doing nothing.

I spent almost an hour fixing a package issue the other day as I had to re-install them a few times due to a path issue I had.

Drove me bonkers!

[patroza]

Yep, it's really frustrating. Dependency hell in it's own way.

Gathering dependency information took 15,71 min

Related? #4534

[jainaashish]

@patroza can you provide a repro solution where it takes 15 mins to gather dependencies? we can then further analyze it.

@rolandh As you mentioned no network activity or cpu activity, so it means it's not related to "attempt to gather dependency information....." step so would you mind opening another issue with detailed steps and repro solution?

[OliverRC]

@jainaashish I'd re-open this. It is not solved.

[patroza]

@jainaashish it happens a lot on WPF projects using packages.config targeting '.NETFramework,Version=v4.6.1', often the first one takes 1.5mins+, and the next one 3.5mins+.
Is there any diagnostic logging that I could enable and share somewhere?

Also once it goes into Uninstalling/Removing/Installing packages within an upgrade cycle, things are painfully slow and cpu+mem usage quite high, and VS not being responsive.

Initial issues were noted on 15.3, now i'm on 15.3.1 with similar experience.
Although it wasn't much better in any 15.x.

[emgarten]

Everyone who is still hitting issues with slow updates, please open a new issue and provide detailed repro steps. There are many different reasons why this could occur, the original problem this issue covered has been fixed.

Trying to track all possible scenarios, including those unrelated to NuGet in a single generic issue makes it difficult to plan and prioritize this work.

[rollsch]

Unfortunately I cannot easily reproduce it. All I can say is it occurs on WPF projects with 15+ nuget packages targeting 4.6.1

[OliverRC]

@emgarten I have a perfectly legitimate example of the potential issue.

Nuget.org is flippen slow:

https://api.nuget.org/v3/registration2-gz/runtime.debian.8-x64.runtime.native.system.security.cryptography/index.json 6511ms OK

6.5s to query 1 package! Now multiply that by the total number of packages and you can see why many of us are experiencing terrible performance.