Log when Restore gets an HTTP 404 for a version when the package is listed on the feed

[donnie-msft]

Bug

Fixes: NuGet/Home#13460

Regression? Last working version:

Description

I've tested Kartheek's branch, and since he's got higher priority issues right now, wanted to create the PR on his behalf.

What I've found is that, Azure DevOps (ADO) with upstream sources can return a 404 (not a 401) when a package exists but ADO permissions are not granted to the user to save the requested package version to the local feed.

My testing shows adding this simple logging is extremely useful as it provides a message to help a customer diagnose where the feed failed to find a package.

Normal verbosity

With normal verbosity,
Old behavior: MSB4181: The "Restore Task" task returned false but did not log an error.
New behavior :

C:\Program Files\Microsoft Visual Studio\2022\IntPreview\Common7\IDE\CommonExtensions\Microsoft\NuGet\NuGet.targets(170
,5): error : The feed 'my-test [https://pkgs.dev.azure.com/azure-public/vside/_packaging/my-test/nuget/v3/i
ndex.json]' lists package 'Microsoft.VisualStudio.ProjectSystem.Analyzers.17.10.221' but multiple attempts to download
the nupkg have failed. The feed is either invalid or required packages were removed while the current operation was in
progress. Verify the package exists on the feed and try again. [C:\apps\Prototypes\ListViewSample\ListViewSample.sln]

Detailed verbosity

With detailed verbosity, the error message is shown immediately after the full URL.

PR Checklist

• PR has a meaningful title

• PR has a linked issue.

• Described changes

• Tests

  • Automated tests added
  • OR
  • Test exception
  • OR
  • N/A

• Documentation

  • Documentation PR or issue filled
  • OR
  • N/A

[kartheekp-ms]

Thanks a lot, @donnie-msft, for helping with the testing. I was not sure how to reproduce MSB4181: The "Restore Task" task returned false but did not log an error in the tests to ensure that my change actually works and no longer raises this error. Your testing gave me confidence that the change will work as expected once it is integrated into dotnet, msbuild, etc.

[kartheekp-ms]

Thanks to @nkolev92 for providing pointers to the code in NuGet/Home#13460 (comment). The detailed information really helped to understand the root cause of the bug.

There was one statement in that linked comment that I thought I could explain here:

Not sure why InvalidCacheProtocolException in particular gets ignored.

From what I understand, looking at the code, InvalidCacheProtocolException is ignored here because the caller ResolverUtility.FindLibraryEntryAsync has logic to try downloading the package twice. The first time when PackageNotFoundProtocolException is thrown, the code in the first catch block at the caller invalidates the cache and does a retry. That's why the exception is not logged at the callee but instead logged at the caller.

Hence, in this PR, the exception is logged to the logger at the caller in the second catch block that handles the PackageNotFoundProtocolException.

[nkolev92]

This change is missing a log code.
It should've probably been NU1301 like the other ones, or potentially a new one.

[nkolev92]

Thinking about it more, this scenario is distinct enough, where I think it could use a separate code.

[jebriede]

Approving with minor suggestion about test name.