microsoft / artifacts-credprovider

The Azure Artifacts Credential Provider enables dotnet, NuGet.exe, and MSBuild to interactively acquire credentials for Azure Artifacts feeds.
MIT License
768 stars 705 forks source link

Intermittent Plugin Failed to Start Error in Azure Pipelines #192

Closed schultetwin1 closed 4 years ago

schultetwin1 commented 4 years ago

We are running into intermittent "plugin failed to start" issues when downloading packages using dotnet in our CI pipeline on Azure DevOps.

Versions Windows 10 Build Agent Nuget Authenticate Task Version: 0.167.1 Nuget Version: 5.6.0.6591 .NET Core SDK Version: 3.1.301

Here is a snippet of the error

F:\ASBUILD18_work_tool\dotnet\sdk\3.1.301\NuGet.targets(128,5): error : Problem starting the plugin 'f:\ADOAgentTemp.nuget\plugins\netcore\CredentialProvider.Microsoft\CredentialProvider.Microsoft.dll'. Plugin 'CredentialProvider.Microsoft' failed within 5.467 seconds with exit code -1. [F:\ASBUILD18_work\1\s\HeadTracking\Test\HetBench\src\cli\cli.csproj] F:\ASBUILD18_work_tool\dotnet\sdk\3.1.301\NuGet.targets(128,5): error : Unable to load the service index for source https://microsoft.pkgs.visualstudio.com/Analog/_packaging/Microsoft.SRaaS/nuget/v3/index.json. [F:\ASBUILD18_work\1\s\HeadTracking\Test\HetBench\src\cli\cli.csproj] F:\ASBUILD18_work_tool\dotnet\sdk\3.1.301\NuGet.targets(128,5): error : Response status code does not indicate success: 401 (Unauthorized).

Here is the original command that was run

dotnet build -maxCpuCount:1 -nodeReuse:false dirs.proj --configuration Release --output F:\ASBUILD18_work\1\s\Build\Debug\WinX64\HeadTracking\Test\HetBench\bin "-p:Platform=Any CPU"

The weird thing is, we run this pipeline all the time and this error only pops up every once in awhile. One item of note: This pipeline is building using a build system (ninja) that spins off multiple processes. These processes could be dotnet builds or nuget pulls of packages. My first thought is they might be conflicting with each other?

schultetwin1 commented 4 years ago

One note, I saw this happen with Nuget Authenticate Task Version: 0.167.2 as well.

lukeschlather commented 4 years ago

Not sure if this is the same issue: https://developercommunity.visualstudio.com/content/problem/1014284/nuget-restore-fails-due-to-credentialprovidermicro.html

schultetwin1 commented 4 years ago

Thanks for the pointer Luke! It looks like that issue is a little different since they are not getting the 401 HTTP error.

That being said, the logging guidelines in there are helpful. I have turned on those same logs for our pipeline to see if that sheds any more light on the issue.

satbai commented 4 years ago

Since the plugin failed to start "within 5.467 seconds", as a workaround, you could try use the following NuGet environment variables to extend the timeout and see if you stop seeing the issue. I believe the default for these is 5 seconds.

NUGET_PLUGIN_HANDSHAKE_TIMEOUT_IN_SECONDS NUGET_PLUGIN_REQUEST_TIMEOUT_IN_SECONDS

I think the dotnet version you're using has all the recent fixes the NuGet team worked on in this area. If you run dotnet nuget --version is the nuget version 5.5.x or greater? If not, it looks like there's a newer dotnet SDK version available.

FYI @nkolev92, @rrelyea from the NuGet team, this is a new "Plugin failed to start" issue with dotnet 3.1.301.

nkolev92 commented 4 years ago

Logs would help us investigate. https://github.com/NuGet/Home/wiki/Plugin-Diagnostic-Logging.

We haven't seen too much of this recently.

schultetwin1 commented 4 years ago

Here are some logs! They are very short so I can actually just copy/paste them here

artifacts-credprovider.log

[16:30:29.430  8964 Minimal] Log starts at 2020-06-17 16:30:29Z
[16:30:29.533  8964 Verbose] ADAL FileCache disabled by environment variable, using the DefaultShared TokenCache
[16:30:29.601  8964 Verbose] SessionToken cache location: f:\ADOAgentTemp\AppData\Local\MicrosoftCredentialProvider\SessionTokenCache.dat

NuGet_PluginLogFor_dotnet_8d812dbbcf0b368.log

{"now":"2020-06-17T16:30:20.3362050Z","type":"stopwatch","message":{"frequency":10000000}}
{"now":"2020-06-17T16:30:24.9934563Z","type":"assembly","message":{"assembly full name":"NuGet.Protocol, Version=5.6.0.5, Culture=neutral, PublicKeyToken=31bf3856ad364e35","entry assembly full name":"MSBuild, Version=15.1.0.0, Culture=neutral, PublicKeyToken=b03f5f7f11d50a3a","file version":"5.6.0.6591","informational version":"5.6.0-rtm.6591+636570e68732c1f718ede9ca07802d7b1cc69aa0.636570e68732c1f718ede9ca07802d7b1cc69aa0"}}
{"now":"2020-06-17T16:30:24.9961979Z","type":"machine","message":{"logical processor count":16}}
{"now":"2020-06-17T16:30:24.9964659Z","type":"environment variables","message":{}}
{"now":"2020-06-17T16:30:25.0015653Z","type":"process","message":{"process ID":13432,"process name":"dotnet","process start time":"2020-06-17T16:30:17.3733284Z"}}
{"now":"2020-06-17T16:30:25.0770447Z","type":"thread pool","message":{"worker thread minimum count":16,"worker thread maximum count":32767,"completion port thread minimum count":16,"completion port thread maximum count":1000}}
{"now":"2020-06-17T16:30:25.1145222Z","type":"plugin instance","message":{"plugin ID":"d948bf0b6b544c71a9c161721d1f9740","state":"Started","process ID":8964}}
{"now":"2020-06-17T16:30:25.1349043Z","type":"communication","message":{"request ID":"500b978b-a8c7-4d87-81f0-8d864efc76e7","method":"Handshake","type":"Request","state":"Sending"}}
{"now":"2020-06-17T16:30:25.1685281Z","type":"communication","message":{"request ID":"500b978b-a8c7-4d87-81f0-8d864efc76e7","method":"Handshake","type":"Request","state":"Sent"}}
{"now":"2020-06-17T16:30:30.1566590Z","type":"task","message":{"request ID":"500b978b-a8c7-4d87-81f0-8d864efc76e7","method":"Handshake","type":"Cancel","state":"Queued"}}
{"now":"2020-06-17T16:30:30.1590476Z","type":"task","message":{"request ID":"500b978b-a8c7-4d87-81f0-8d864efc76e7","method":"Handshake","type":"Cancel","state":"Executing","current task ID":1}}
{"now":"2020-06-17T16:30:30.1607677Z","type":"communication","message":{"request ID":"500b978b-a8c7-4d87-81f0-8d864efc76e7","method":"Handshake","type":"Cancel","state":"Sending"}}
{"now":"2020-06-17T16:30:30.1610365Z","type":"communication","message":{"request ID":"500b978b-a8c7-4d87-81f0-8d864efc76e7","method":"Handshake","type":"Cancel","state":"Sent"}}
{"now":"2020-06-17T16:30:30.1610745Z","type":"task","message":{"request ID":"500b978b-a8c7-4d87-81f0-8d864efc76e7","method":"Handshake","type":"Cancel","state":"Completed","current task ID":1}}
{"now":"2020-06-17T16:30:31.3348368Z","type":"plugin instance","message":{"plugin ID":"d948bf0b6b544c71a9c161721d1f9740","state":"Exited","process ID":8964}}

NuGet_PluginLogFor_dotnet_8d812dbbfcf7e15.log

{"now":"2020-06-17T16:30:29.7004943Z","type":"stopwatch","message":{"frequency":10000000}}
{"now":"2020-06-17T16:30:29.7060232Z","type":"assembly","message":{"assembly full name":"NuGet.Protocol, Version=5.3.0.4, Culture=neutral, PublicKeyToken=31bf3856ad364e35","file version":"5.3.0.6251","informational version":"5.3.0+b75150f2f4127a77a166c9552845e86fb24a3282.b75150f2f4127a77a166c9552845e86fb24a3282"}}
{"now":"2020-06-17T16:30:30.0633909Z","type":"machine","message":{"logical processor count":16}}
{"now":"2020-06-17T16:30:30.0637761Z","type":"environment variables","message":{}}
{"now":"2020-06-17T16:30:30.0653373Z","type":"process","message":{"process ID":8964,"process name":"dotnet"}}
{"now":"2020-06-17T16:30:30.0951714Z","type":"thread pool","message":{"worker thread minimum count":16,"worker thread maximum count":32767,"completion port thread minimum count":16,"completion port thread maximum count":1000}}
nkolev92 commented 4 years ago

The plugin seems to never receive the handshake request, that's weird :/

I don't recall seeing these symptoms before.

@satbai anything ring a bell?

nkolev92 commented 4 years ago

A thing to consider on the plugin end would be updating to newer versions of NuGet.Protocol. I don't recall the exact changes in 5.4, but maybe there's something there that improves the reliability.

satbai commented 4 years ago

Thanks! I'll make the change to update NuGet.Protocol - should be able to do it later today.

In the meantime, maybe increasing the handshake timeout with NUGET_PLUGIN_HANDSHAKE_TIMEOUT_IN_SECONDS will help?

nkolev92 commented 4 years ago

Yeah @schultetwin1 try that out.

Looking at the symptoms, I'm not sure how much/if that'll help, but worth a shot for sure :)

Consider collecting the logs even with an increased timeout, just in case it fails.

schultetwin1 commented 4 years ago

@satbai and @nkolev92 you've got it! I'll update the timeout to 60 seconds and leave the logging turned on. I'll let you know the results.

schultetwin1 commented 4 years ago

One other interesting tidbit. It always happens with just one source (for those internal to Microsoft, you maybe able to view that source here: https://dev.azure.com/Microsoft/Analog/_packaging?_a=feed&feed=Microsoft.SRaaS)

schultetwin1 commented 4 years ago

Scratch that, I spoke too soon. We are seeing this error with other sources as well. All ADO sources though (which are the only sources we authenticate with)

schultetwin1 commented 4 years ago

Just FYI, I was able to see the version of tools on the build machines. It looks like it's

dotnet nuget = NuGet Command Line 5.6.0.5 nuget = NuGet Version: 5.6.0.6591

So maybe it's the fact we are using Nuget 5.6?

lukeschlather commented 4 years ago

I've seen the same error on 5.5.1 (and your original report says 5.5.1.) My belief is that it's caching related, or related to some state in the Azure Devops nuget auth itself related to a specific account, rather than being a client problem. So I'm also suspicious of most of the "fixes." I'm concerned most of the "fixes" happened to bust the cache or something. So though the error did stop in direct response to the change, it didn't fix the underlying issue.

schultetwin1 commented 4 years ago

@lukeschlather thanks for the pointer on the original report. I edited that. I thought we were using 5.5.1 because that's what the nuget tool installer was installing, but it looks like the DotNet tool installer then installs a newer version of nuget.exe later.

So though the error did stop in direct response to the change, it didn't fix the underlying issue.

I'm not sure I follow. What is "the change" in this sentence? I have not said the error stopped.

lukeschlather commented 4 years ago

If you're using the DotNetToolInstaller@1 with no arguments it was upgraded to 5.6 on May 19th. When did you start having this issue? I was seeing the same intermittent issue on 5.5.1 prior to that on May 5th, and I have read reports of issues that sound very similar going back much earlier than that.

The earlier reports I have read all claim that it's fixed in the latest version of nuget, so it seems that there have been a series of changes focused on fixing this issue and it's I'm a little suspicious if there is some underlying stateful/caching bug that those fixes happened to suppress but did not fix.

lukeschlather commented 4 years ago

FWIW I tried reproducing on 5.6 with my setup and it ran 3 times without incident in a way that did reproduce the issue on 5.5.1 a month and a half ago.

nkolev92 commented 4 years ago

@lukeschlather

If you are having any sort of "task was cancelled" issues, the logs would help us investigate.

https://github.com/NuGet/Home/wiki/Plugin-Diagnostic-Logging.

lukeschlather commented 4 years ago

The experience I had was when I added all the diagnostic logging and debugging info asked for, the problem magically disappeared. So my pipeline just has the debug logging enabled now.

https://developercommunity.visualstudio.com/content/problem/1014284/nuget-restore-fails-due-to-credentialprovidermicro.html

There's a private Microsoft-only comment on the above issue that has my full logs attached to them. However they were uninteresting and I can't reproduce the issue anymore.

satbai commented 4 years ago

New version of the cred provider has been released with updated NuGet.Protocol version https://github.com/microsoft/artifacts-credprovider/releases/tag/v0.1.24

schultetwin1 commented 4 years ago

Awesome, thank you @satbai

I've installed the new release on my machine to test. And then we'll need to get this new release into the NuGetAuthenticate plugin, since that's how we get this bits onto our build machines.

satbai commented 4 years ago

I'll update NuGetAuthenticate as well, but heads up, the release process for that will take a little longer.

schultetwin1 commented 4 years ago

No worries, I understand how that goes. Thank you for pushing this through so quickly. I'll let you know if we continue to see errors (both with the 60 second delay, which change I just got in and once them new NuGetAuthenticate task is released)

schultetwin1 commented 4 years ago

So about a week after my change to increase timeouts (setting NUGET_PLUGIN_HANDSHAKE_TIMEOUT_IN_SECONDS to 60 seconds) and we have not seen this error since then. Maybe it was an actual timeout?

lukeschlather commented 4 years ago

Has the fix for NuGetAuthenticate rolled out? I just saw this yesterday:

2020-06-23T21:54:20.8979743Z ##[error]/usr/share/dotnet/sdk/3.1.301/NuGet.targets(128,5): Error : Problem starting the plugin '/home/vsts/.nuget/plugins/netcore/CredentialProvider.Microsoft/CredentialProvider.Microsoft.dll'. Plugin 'CredentialProvider.Microsoft' failed within 5.044 seconds with exit code .
2020-06-23T21:54:20.8992604Z /usr/share/dotnet/sdk/3.1.301/NuGet.targets(128,5): error : Problem starting the plugin '/home/vsts/.nuget/plugins/netcore/CredentialProvider.Microsoft/CredentialProvider.Microsoft.dll'. Plugin 'CredentialProvider.Microsoft' failed within 5.044 seconds with exit code . [/home/vsts/work/1/s/ManagementDevice/WarehouseStation/WarehouseStation.sln]
2020-06-23T21:54:21.0887806Z ##[error]/usr/share/dotnet/sdk/3.1.301/NuGet.targets(128,5): Error : Unable to load the service index for source https://pkgs.dev.azure.com/strivr/_packaging/StrivrNugetFeed/nuget/v3/index.json.
  Response status code does not indicate success: 401 (Unauthorized).
2020-06-23T21:54:21.0890316Z /usr/share/dotnet/sdk/3.1.301/NuGet.targets(128,5): error : Unable to load the service index for source https://pkgs.dev.azure.com/strivr/_packaging/StrivrNugetFeed/nuget/v3/index.json. [/home/vsts/work/1/s/MySolution.sln]
2020-06-23T21:54:21.0892058Z /usr/share/dotnet/sdk/3.1.301/NuGet.targets(128,5): error :   Response status code does not indicate success: 401 (Unauthorized). [/home/vsts/work/1/s/MySolution.sln]
lukeschlather commented 4 years ago

This is what I have in my ADO pipeline:

      - task: PowerShell@2
        inputs:
          targetType: 'inline'
          script: |
            $tempdir = [IO.Path]::GetTempPath()

            $env:NUGET_PLUGIN_LOG_DIRECTORY_PATH = Join-Path $tempdir "pluginlog"
            $env:NUGET_CREDENTIALPROVIDER_LOG_PATH = Join-Path $env:NUGET_PLUGIN_LOG_DIRECTORY_PATH "artifacts-credprovider.log"
            $env:NUGET_PLUGIN_ENABLE_LOG = "true"

            if (Test-Path -LiteralPath $env:NUGET_PLUGIN_LOG_DIRECTORY_PATH) {
                Remove-Item -Recurse -Force -LiteralPath $env:NUGET_PLUGIN_LOG_DIRECTORY_PATH
            }

            [IO.Directory]::CreateDirectory($env:NUGET_PLUGIN_LOG_DIRECTORY_PATH) | Out-Null

            Write-Host "##vso[task.setvariable variable=NUGET_CREDENTIALPROVIDER_LOG_PATH]$env:NUGET_CREDENTIALPROVIDER_LOG_PATH"
            Write-Host "##vso[task.setvariable variable=NUGET_PLUGIN_ENABLE_LOG]$env:NUGET_PLUGIN_ENABLE_LOG"
            Write-Host "##vso[task.setvariable variable=NUGET_PLUGIN_LOG_DIRECTORY_PATH]$env:NUGET_PLUGIN_LOG_DIRECTORY_PATH"

      - task: NuGetToolInstaller@1
        displayName: 'Update NuGet'
        inputs:
          checkLatest: true

      - task: NuGetAuthenticate@0

      - task: DotNetCoreCLI@2
        displayName: 'Build Solution'
        inputs:
          command: build
          projects: 'MySolution.sln'
          nugetConfigPath: 'NuGet.Config'
          arguments: --configuration $(buildConfiguration) --runtime ubuntu-x64
        env:
          BuildNumber: $(Build.BuildNumber)

I had previously added this command after nuget authenticate per the discussion in the developercommunity thread I linked earlier:

      - task: PowerShell@2
        displayName: 'Test Nuget Auth'
        inputs:
          targetType: 'inline'
          script: |
            dotnet /home/vsts/.nuget/plugins/netcore/CredentialProvider.Microsoft/CredentialProvider.Microsoft.dll -RedactPassword -Verbosity Debug -Uri $env:SYSTEM_TEAMFOUNDATIONCOLLECTIONURI

^ This command had completely eliminated the timeouts; however last week the command broke and just started throwing errors so I had to remove it to unblock my pipeline, but now I'm back to seeing these intermittent errors.

satbai commented 4 years ago

The update to the NuGet Authenticate task has not been rolled out yet. Did you try increasing the timeout?

lukeschlather commented 4 years ago

I have not. Are you changing the default timeout?

lukeschlather commented 4 years ago

Is there any way Azure Devops can instrument the task so that this is detectable on the nuget service end? If there are latency issues with the ADO nuget service that seems like something they should be able to detect and fix.

lukeschlather commented 4 years ago

As a paying customer I would expect them to treat it as an outage.

satbai commented 4 years ago

We could consider increasing the timeout with the variables in the nuget authenticate task itself automatically so customers didn't have to do it themselves. @nkolev92 do you see a problem with that from the nuget side?

FYI @edgarrs

davidhjones commented 4 years ago

I am also seeing this issue -- Nuget v.5.6.0, Cred Provider 0.1.23 (Nuget Authenticate step will not install 0.1.24 even with reinstall option set).

I have set the env variables on my build VMs -- will report back if I see this issue again.

Strandfelt commented 4 years ago

Seeing this issue very often with dotnet tool install commands on Azure DevOps hosted agents. I will try setting the NUGET_PLUGIN_HANDSHAKE_TIMEOUT_IN_SECONDS variable to 60 and return here if the problem persists.

schultetwin1 commented 4 years ago

@satbai - Just coming back with a month update.

We added the following two env vars to our builds:

NUGET_PLUGIN_HANDSHAKE_TIMEOUT_IN_SECONDS=60
NUGET_PLUGIN_REQUEST_TIMEOUT_IN_SECONDS=60

This did seem to greatly reduce the number of "plugin failed to start" errors but it did not get rid of them. In the last month we've seen this error happen twice (or hundreds of builds). I've downloaded the nuget and credprovider logs and uploaded them here. Here is the output from dotnet:

cmd.exe /C "cd /D C:\agent\_work\1\s\HeadTracking\Test\DAGit && dotnet build -maxCpuCount:1 -nodeReuse:false DAGit.sln --configuration Release --output C:\agent\_work\1\s\Build\Release\WinX64\HeadTracking\Test\DAGit\bin "-p:Platform=Any CPU""
Microsoft (R) Build Engine version 16.6.0+5ff7b0c9e for .NET Core
Copyright (C) Microsoft Corporation. All rights reserved.

  Determining projects to restore...
  Restored C:\agent\_work\1\s\HeadTracking\Test\DAGit\src\Core\DAGit.Core.csproj (in 6.51 sec).
  Restored C:\agent\_work\1\s\Common\Test\GroundTruth\Charon\Recording\Recording.csproj (in 6.62 sec).
  Restored C:\agent\_work\1\s\Common\Test\GroundTruth\Charon\Common\Common.csproj (in 7.12 sec).
C:\agent\_work\_tool\dotnet\sdk\3.1.302\NuGet.targets(128,5): error : Problem starting the plugin 'C:\Users\AzDevOps\.nuget\plugins\netcore\CredentialProvider.Microsoft\CredentialProvider.Microsoft.dll'. Plugin 'CredentialProvider.Microsoft' failed within 62.149 seconds with exit code -1. [C:\agent\_work\1\s\HeadTracking\Test\DAGit\DAGit.sln]
C:\agent\_work\_tool\dotnet\sdk\3.1.302\NuGet.targets(128,5): error : Problem starting the plugin 'C:\Users\AzDevOps\.nuget\plugins\netcore\CredentialProvider.Microsoft\CredentialProvider.Microsoft.dll'. Plugin 'CredentialProvider.Microsoft' failed within 62.149 seconds with exit code -1. [C:\agent\_work\1\s\HeadTracking\Test\DAGit\DAGit.sln]
C:\agent\_work\_tool\dotnet\sdk\3.1.302\NuGet.targets(128,5): error :   Plugin 'CredentialProvider.Microsoft' failed within 62.149 seconds with exit code -1. [C:\agent\_work\1\s\HeadTracking\Test\DAGit\DAGit.sln]
C:\agent\_work\_tool\dotnet\sdk\3.1.302\NuGet.targets(128,5): error :   A task was canceled. [C:\agent\_work\1\s\HeadTracking\Test\DAGit\DAGit.sln]
  Retrying 'FindPackagesByIdAsync' for source 'https://microsoft.pkgs.visualstudio.com/8115054f-1c74-4928-a9ab-de4769e7d6ae/_packaging/ba09f610-8053-4c83-b1e9-f1648aa3042d/nuget/v3/flat2/taef.managed/index.json'.
  Response status code does not indicate success: 401 (Unauthorized).

I'd like to suggest we re-open this issue, but I'll leave that up to you and the rest of your team. Thanks! Let me know if you need anymore info.

Windows-Release-NuGet-Cred-Logs-1 (3).zip

satbai commented 4 years ago

FYI @samuelkoppes @herenhuang @edgarrs @phil-hodgson for triage regarding the latest update.

schultetwin1 commented 4 years ago

Just a FYI, this is still happening though it's rare.

dwilsonbst commented 4 years ago

I am also still seeing this issue, although infrequently. Happened on 9/14/20 a few times in a row, then fine since. I'll attempt the work around as a band aid long term, but hoping someone could shed some light on an actual fix. Thanks.

mattgrande commented 3 years ago

Just chiming in that I've been seeing this issue as well recently. I tried adding forceReinstallCredentialProvider: true to my NuGetAuthenticate, to no avail (as recommended here). I'll try extending the timeout and report back.

Edit: Extending the timeout seems to have resolved the issue for me, but I'm worried I've just kicked the can a few months into the future.

dazinator commented 3 years ago

I have a vanilla azure devops pipeline with only the following two steps, running on a hosted agent (windows-latest) and I see this issue occur on the second step (dotnet) after nuget authenticate step runs successfully.

- task: NuGetAuthenticate@0
    displayName: 'nuget authenticate'

  - task: DotNetCoreCLI@2    
    displayName: 'Install DetectMergedPullRequest'
    inputs:
      command: custom
      custom: tool
      arguments: 'install -g DetectMergedPullRequest --add-source https://pkgs.dev.azure.com/uniun/_packaging/Deployment/nuget/v3/index.json --version 0.1.0-*'

and the error:

Welcome to .NET Core 3.1!
---------------------
SDK Version: 3.1.300

Telemetry
---------
The .NET Core tools collect usage data in order to help us improve your experience. The data is anonymous. It is collected by Microsoft and shared with the community. You can opt-out of telemetry by setting the DOTNET_CLI_TELEMETRY_OPTOUT environment variable to '1' or 'true' using your favorite shell.

Read more about .NET Core CLI Tools telemetry: https://aka.ms/dotnet-cli-telemetry

----------------
Explore documentation: https://aka.ms/dotnet-docs
Report issues and find source on GitHub: https://github.com/dotnet/core
Find out what's new: https://aka.ms/dotnet-whats-new
Learn about the installed HTTPS developer cert: https://aka.ms/aspnet-core-https
Use 'dotnet --help' to see available commands or visit: https://aka.ms/dotnet-cli-docs
Write your first app: https://aka.ms/first-net-core-app
--------------------------------------------------------------------------------------
C:\Program Files\dotnet\sdk\3.1.300\NuGet.targets(128,5): error : Problem starting the plugin 'C:\Users\VssAdministrator\.nuget\plugins\netcore\CredentialProvider.Microsoft\CredentialProvider.Microsoft.dll'. Plugin 'CredentialProvider.Microsoft' failed within 5.465 seconds with exit code -1. [C:\Users\VssAdministrator\AppData\Local\Temp\juohhwml.qo4\restore.csproj]
C:\Program Files\dotnet\sdk\3.1.300\NuGet.targets(128,5): error : Unable to load the service index for source https://pkgs.dev.azure.com/uniun/_packaging/Deployment/nuget/v3/index.json. [C:\Users\VssAdministrator\AppData\Local\Temp\juohhwml.qo4\restore.csproj]
C:\Program Files\dotnet\sdk\3.1.300\NuGet.targets(128,5): error :   Response status code does not indicate success: 401 (Unauthorized). [C:\Users\VssAdministrator\AppData\Local\Temp\juohhwml.qo4\restore.csproj]
The tool package could not be restored.
Tool 'detectmergedpullrequest' failed to install. This failure may have been caused by:

* You are attempting to install a preview release and did not use the --version option to specify the version.
* A package by this name was found, but it was not a .NET Core tool.
* The required NuGet feed cannot be accessed, perhaps because of an Internet connection problem.
* You mistyped the name of the tool.

For more reasons, including package naming enforcement, visit https://aka.ms/failure-installing-tool
##[error]Error: The process 'C:\Program Files\dotnet\dotnet.exe' failed with exit code 1
Info: Azure Pipelines hosted agents have been updated and now contain .Net 5.x SDK/Runtime along with the older .Net Core version which are currently lts. Unless you have locked down a SDK version for your project(s), 5.x SDK might be picked up which might have breaking behavior as compared to previous versions. You can learn more about the breaking changes here: https://docs.microsoft.com/en-us/dotnet/core/tools/ and https://docs.microsoft.com/en-us/dotnet/core/compatibility/ . To learn about more such changes and troubleshoot, refer here: https://docs.microsoft.com/en-us/azure/devops/pipelines/tasks/build/dotnet-core-cli?view=azure-devops#troubleshooting
##[error]Dotnet command failed with non-zero exit code on the following projects : 
Finishing: Install DetectMergedPullRequest

Adding the following variables to the pipeline fixes it.

variables:
  NUGET_PACKAGES: $(Pipeline.Workspace)/.nuget/packages
  # see https://developercommunity.visualstudio.com/content/problem/899022/dotnetcorecli-5.html
  NUGET_PLUGIN_HANDSHAKE_TIMEOUT_IN_SECONDS: 30 
  NUGET_PLUGIN_REQUEST_TIMEOUT_IN_SECONDS: 30

Is this the intended usage?

lukeschlather commented 3 years ago

One of our pipelines is having this issue again, intermittently.

BlairMcc commented 3 years ago

One of our pipelines is having this issue again, intermittently.

Same here, seeing a spike in these errors the last few hours, currently we have not implemented any of the workarounds detailed in this thread

lukeschlather commented 3 years ago

I created a problem on the ADO developer community https://developercommunity2.visualstudio.com/t/intermittent-nuget-authentication-failures/1336781?from=email

bhuwan-agarwal commented 3 years ago
##[error]C:\Program Files\dotnet\sdk\5.0.102\NuGet.targets(131,5): Error : Problem starting the plugin 'C:\Users\VssAdministrator\.nuget\plugins\netcore\CredentialProvider.Microsoft\CredentialProvider.Microsoft.dll'. Plugin 'CredentialProvider.Microsoft' failed within 6.200 seconds with exit code -1.
##[debug]Processed: ##vso[task.logissue type=Error;sourcepath=C:\Program Files\dotnet\sdk\5.0.102\NuGet.targets;linenumber=131;columnnumber=5;code=;]Problem starting the plugin 'C:\Users\VssAdministrator\.nuget\plugins\netcore\CredentialProvider.Microsoft\CredentialProvider.Microsoft.dll'. Plugin 'CredentialProvider.Microsoft' failed within 6.200 seconds with exit code -1.
ewan-dgc commented 3 years ago

getting the same issue, added the 30sec timeout. seems to improve but not completely fix.

kuradac commented 2 years ago

Restarting the self-hosted agents seemed to work for us.

MisinformedDNA commented 1 year ago

I'm getting this on windows-2022 and DotNetCoreCLI@2. Supposedly there was a fix, but I'm still getting an error under 6 seconds.