Home: "A task was canceled" errors when restoring packages from a private feed and nuget.org using xplat authentication plugin

[nicolasvan]

Details about Problem

• Nuget.exe (4.8.1, 4.9.2, 4.9.3)
• https://github.com/Microsoft/artifacts-credprovider/ (v0.1.12 configured by setting the VSS_NUGET_EXTERNAL_FEED_ENDPOINTS environment variable as per https://github.com/Microsoft/artifacts-credprovider#environment-variables)
• Windows 10 1809, Windows Server 2019

When doing a nuget.exe restore against a solution using packages.config and restoring packages from the public nuget feed (https://api.nuget.org/v3/index.json) as well as a private Azure Devops feed (v3), we are getting random errors like these:

WARNING: Unable to find version '<version>' of package '<private package>'.
  https://api.nuget.org/v3/index.json: Package '<private package>.<version>' is not found on source 'https://api.nuget.org/v3/index.json'.
  https://xxxxx.pkgs.visualstudio.com/_packaging/Main/nuget/v3/index.json: Unable to load the service index for source https://xxxxx.pkgs.visualstudio.com/_packaging/Main/nuget/v3/index.json.
  A task was canceled.

When that happens, all of the packages hosted on our private feed fail to restore (with the same warning message). The packages coming from nuget.org are all restored fine.

After looking at the code and playing with it a little, my understanding of what is happening is:

• Packages that are publicly available on nuget.org get downloaded from nuget.org fine and the task to download the same packages from our private feed gets canceled. (by https://github.com/NuGet/NuGet.Client/blob/2c11555b33f9b5531308d83810763f92360a59ab/src/NuGet.Core/NuGet.PackageManagement/PackageDownloader.cs#L131). Fair enough.
• But one of the task that is looking for one of those package on our private feed might have gone as far as requesting credentials, starting up the xplat authentication plugin and eventually got canceled at various stages of the plugin Handshake/GetOperationsClaim flow.... (because the linkedTokenSource being canceled is being passed all the way down... I guess?). Not sure if this leaves the plugin in a broken state or if nuget somehow caches that credentials cannot be retrieved for the private feed?

^^ This is some seriously wild guessing based on running debug builds of nuget.exe along with hacking at the authentication plugin to get it to print some verbose logs to a file. I might be completely wrong...

Commenting out linkedTokenSource.Cancel(); make the errors go away. (I'm not suggesting this as a proper fix though 😉)

Detailed repro steps so we can see the same problem

I think this should be fairly easy to reproduce, provided that you have a nuget feed that requires authentication:

1. Have a solution with multiple packages.config with packages needing to be restored from both nuget.org and a private feed.
2. Use the https://github.com/Microsoft/artifacts-credprovider plugin
3. in powershell

$env:VSS_NUGET_EXTERNAL_FEED_ENDPOINTS = ' {"endpointCredentials": [{"endpoint":"<your-private-feed>", "username":"<your-username>", "password":"<your-access-token>"}]}'

# Keep rerunning these commands until you get a failure:
Remove-Item packages -force -recurse
nuget.exe locals -clear all;
nuget.exe restore -verbosity detailed

I have a solution with 20 packages coming from nuget.org and 7 from our private feed. I'd say this fail 50% of the time _on my machine_. Although it's been a working a lot better when running from Visual Studio with the debugger attached 😞...

Other suggested things

Verbose Logs

There's nothing more when running with -verbosity detailed other than the warning message printed above...

Workarounds

• Adding -DisableParallelProcessing to nuget restore makes the problem go away.

[rrelyea]

This appears to happen with a combination of NuGet 4.8+ and the new azure artifacts credential provider.
The two teams are digging into the issue. /cc @dtivel @alexmullans

[rrelyea]

@dtivel is working on nuget fix. Hope to fix in 4.9.x sometime very soon. Likely by end of next week.

[dtivel]

The bug is here. IRequestHandler instances are singletons. The CancellationToken passed to HandleResponseAsync(...) is per-request, but because of the bug and race conditions, one inbound request was incorrectly sharing the CancellationToken for another inbound request.

[dtivel]

See https://github.com/Microsoft/artifacts-credprovider/issues/77 for updates.