One feed not working - Frequent 500 Internal Server Errors.

I have one particular feed on my ProGet instance that results in a very lengthy pause before downloading items, to the point of being unable to install packages within Visual Studio.

The feed is the new index format (v3.3+) and fiddler logs tell me that other feeds return fine.

GET /nuget/MyFeed1/FindPackagesById()?id='Apache.NMS.ActiveMQ' HTTP/1.1
DataServiceVersion: 1.0;NetFx
MaxDataServiceVersion: 2.0;NetFx
User-Agent: NuGet VS Packages Dialog/2.8.50926.663 (Microsoft Windows NT 6.1.7601 Service Pack 1, VS Professional/12.0)
NuGet-ProjectGuids: {FAE04EC0-301F-11D3-BF4B-00C04F79EFBC}
Accept: application/atom+xml,application/xml
Accept-Charset: UTF-8
Host: starlizard-nuget:8081
Accept-Encoding: gzip, deflate

After 30 seconds delay...

HTTP/1.1 500 Internal Server Error
Cache-Control: private
Content-Length: 35
Content-Type: text/plain; charset=utf-8
Server: Microsoft-HTTPAPI/2.0
X-AspNet-Version: 4.0.30319
X-UA-Compatible: IE=edge
X-ProGet-Version: 3.4.0.7
Date: Mon, 12 Jan 2015 20:08:49 GMT

Occasionally it works but with a very large delay (20+ seconds) - seems as if once it waits for longer than 30 seconds, proget hits a timeout and throws a 500 error.

The feed has approx 3,000 packages but I wouldn't have thought it that's near its maximum?

Cheers,

James

Product: ProGet
Version: 3.4.0

I've restarted the ProGet service to no avail.

I have the same problem. It started when I upgraded to version 3.3.12, but neither a downgrade nor an upgrade have solved it. I only have one feed so I don't know if the problem is only on that one. I have about 1500 packages in my feed. I have tried both a re-installation and a restart.

If it helps, on that feed we have:

Caching: Enabled
Symbol Server: Enabled (Symbol files are stripped)
Type: NuGet

Fredrik, I worked around this issue by creating a new Feed with a connector to my old feed.

My connector address I used was "http://localhost:8081/nuget/MySlowFeed"

Now everything works as expected (Symbols etc untested)

We've not been able to reproduce this behavior even with thousands of packages. What version of SQL Server are you using, and is it located on the same physical server as the web application?

We have identified some indexing issues with some queries and will release a fix for those in 3.4.1, but as we so far can't explain this behavior, it may not help this problem specifically.

I am using SQL Server Express x64 12.0 (I download the "without Embedded SQL Server" binaries from your site) installed locally on the same machine as the ProGet Service.

I might be able to add more details tomorrow.

Strange. The only other thing I can think of is a deadlock issue. Do you know if the feed is also being updated at the same time? (adding, deleting packages, etc) That shouldn't cause issues like this, but it's something else to check.

I don't know much about SQL Server and how it works, but we are running it on the same machine. The first time I installed ProGet I downloaded the version with SQL Server, when upgrading I have used the version without. Connecting to the server and running select @@version shows: Microsoft SQL Server 2005 - 9.00.5000.00 (Intel X86).

I tried version ProGet 3.4.1 and it is slightly better. I don't get any 500 errors any longer but the package download takes a very long time. I have 40 packages in my application and after a few minutes it times out and I have to restart the "nuget restore" operation. After doing this a few times I have installed all my packages.

We rarely write to the package feed, only a few times a day, so that shouldn't be causing any problems.

I can add that looking in the task manager I see SQL Server using 50% CPU a lot of the time, the server have 2 cores so that mean 100% on one of them.

That shouldn't be the case. Legacy feeds did tend to hit the database pretty hard when there were lots of packages, but that was one of the main reasons we changed it. If you have access to SQL Server Management Studio, you can bring up the Activity Monitor (right-click on the name of the server in the Object Explorer tree), and expand the Recent Expensive Queries tab. If it's a ProGet query that's using those resources, that should tell us what it is.

Looks like it is the problem, looking in the "Recent Expensive Queries" I can see the following:

SELECT * FROM [Packages_Extended] WHERE [Feed_Id] = @Feed_Id ORDER BY [Package_Id]
Average duration (ms) 25723

And

SELECT P.* FROM @PackageIds I INNER JOIN [Packages_Extended] P ON P.[Feed_Id] = @Feed_Id AND P.[Package_Id] = I.[Package_Id] ORDER BY [Package_Id]

Average duration (ms) 127

And some other entries at around 20 ms.

Thanks for that. The ORDER BY clause is a little questionable in there - that should help narrow things down a lot. I'll let you know when we have learned more.

We've identified the issue. There was one line of code in the package download handler that survived many code reviews and debugging sessions from before the performance overhaul of 3.3.0. In current versions it was causing every row in the packages table for a feed to be iterated when one was downloaded. Needless to say, this is not optimal, and we will have a fix in 3.4.2 today, along with fixes for other more minor issues we've found.

Thanks to everyone for the help in tracking this down!

Version 3.4.2 works great, thanks!