Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Credential provider error with .NET Core SDK 3.1.100: Problem starting the plugin #162

Closed
jkeech opened this issue Dec 27, 2019 · 12 comments
Labels
backlog Azure Artifacts tag for items under consideration in our backlog bug Something isn't working redirect-to-dev-community

Comments

@jkeech
Copy link
Member

jkeech commented Dec 27, 2019

The credential provider works when using SDK 2.2.401, but fails on 3.1.100 on the same machine (just changing global.json). This is in a Debian 9 container (in a VS Online environment). The credential provider was installed as follows:

# Install Azure DevOps credential helper for dotnet restore.
wget -q https://raw.githubusercontent.com/microsoft/artifacts-credprovider/master/helpers/installcredprovider.sh -O installcredprovider.sh
chmod +x installcredprovider.sh
./installcredprovider.sh
rm installcredprovider.sh

Error on 3.1.100

$ dotnet restore --interactive
/home/vsonline/.dotnet/sdk/3.1.100/NuGet.targets(123,5): error : Problem starting the plugin '/home/vsonline/.nuget/plugins/netcore/CredentialProvider.Microsoft/CredentialProvider.Microsoft.dll'. No such file or directory [/home/vsonline/workspace/<redacted>]
/home/vsonline/.dotnet/sdk/3.1.100/NuGet.targets(123,5): error : Unable to load the service index for source <redacted>. [/home/vsonline/workspace/<redacted>]
/home/vsonline/.dotnet/sdk/3.1.100/NuGet.targets(123,5): error :   Response status code does not indicate success: 401 (Unauthorized). [/home/vsonline/workspace/<redacted>]
MSBUILD : error MSB1025: An internal failure occurred while running MSBuild.
Microsoft.Build.BackEnd.NodeFailedToLaunchException: No such file or directory
 ---> System.ComponentModel.Win32Exception (2): No such file or directory
   at System.Diagnostics.Process.ForkAndExecProcess(String filename, String[] argv, String[] envp, String cwd, Boolean redirectStdin, Boolean redirectStdout, Boolean redirectStderr, Boolean setCredentials, UInt32 userId, UInt32 groupId, UInt32[] groups, Int32& stdinFd, Int32& stdoutFd, Int32& stderrFd, Boolean usesTerminal, Boolean throwOnNoExec)
   at System.Diagnostics.Process.StartCore(ProcessStartInfo startInfo)
   at System.Diagnostics.Process.Start()
   at System.Diagnostics.Process.Start(ProcessStartInfo startInfo)
   at Microsoft.Build.BackEnd.NodeProviderOutOfProcBase.LaunchNode(String msbuildLocation, String commandLineArgs)
   --- End of inner exception stack trace ---
   at Microsoft.Build.BackEnd.NodeProviderOutOfProcBase.LaunchNode(String msbuildLocation, String commandLineArgs)
   at Microsoft.Build.BackEnd.NodeProviderOutOfProcBase.GetNode(String msbuildLocation, String commandLineArgs, Int32 nodeId, INodePacketFactory factory, Int64 hostHandshake, Int64 clientHandshake, NodeContextTerminateDelegate terminateNode)
   at Microsoft.Build.BackEnd.NodeProviderOutOfProc.CreateNode(Int32 nodeId, INodePacketFactory factory, NodeConfiguration configuration)
   at Microsoft.Build.BackEnd.NodeManager.AttemptCreateNode(INodeProvider nodeProvider, NodeConfiguration nodeConfiguration)
   at Microsoft.Build.BackEnd.NodeManager.CreateNode(NodeConfiguration configuration, NodeAffinity nodeAffinity)
   at Microsoft.Build.Execution.BuildManager.PerformSchedulingActions(IEnumerable`1 responses)
   at Microsoft.Build.Execution.BuildManager.HandleNewRequest(Int32 node, BuildRequestBlocker blocker)
   at Microsoft.Build.Execution.BuildManager.ProcessPacket(Int32 node, INodePacket packet)
   at Microsoft.Build.Execution.BuildManager.<>c__DisplayClass67_0.<Microsoft.Build.BackEnd.INodePacketHandler.PacketReceived>b__0()
   at Microsoft.Build.Execution.BuildManager.ProcessWorkQueue(Action action)
--- End of stack trace from previous location where exception was thrown ---
   at Microsoft.Build.Execution.BuildManager.EndBuild()
   at Microsoft.Build.CommandLine.MSBuildApp.BuildProject(String projectFile, String[] targets, String toolsVersion, Dictionary`2 globalProperties, Dictionary`2 restoreProperties, ILogger[] loggers, LoggerVerbosity verbosity, DistributedLoggerRecord[] distributedLoggerRecords, Int32 cpuCount, Boolean enableNodeReuse, TextWriter preprocessWriter, Boolean detailedSummary, ISet`1 warningsAsErrors, ISet`1 warningsAsMessages, Boolean enableRestore, ProfilerLogger profilerLogger, Boolean enableProfiler, Boolean interactive, Boolean isolateProjects, Boolean graphBuild, String[] inputResultsCaches, String outputResultsCache)

Edit: running with detailed logging gives this more specific stack trace on the plugin load, and I can confirm that the dll does exist:

/home/vsonline/.dotnet/sdk/3.1.100/NuGet.targets(123,5): error : Problem starting the plugin '/home/vsonline/.nuget/plugins/netcore/CredentialProvider.Microsoft/CredentialProvider.Microsoft.dll'. No such file or directory [/home/vsonline/workspace/<redacted>]
         System.ComponentModel.Win32Exception (2): No such file or directory
            at System.Diagnostics.Process.ForkAndExecProcess(String filename, String[] argv, String[] envp, String cwd, Boolean redirectStdin, Boolean redirectStdout, Boolean redirectStderr, Boolean setCredentials, UInt32 userId, UInt32 groupId, UInt32[] groups, Int32& stdinFd, Int32& stdoutFd, Int32& stderrFd, Boolean usesTerminal, Boolean throwOnNoExec)
            at System.Diagnostics.Process.StartCore(ProcessStartInfo startInfo)
            at System.Diagnostics.Process.Start()
            at NuGet.Protocol.Plugins.PluginProcess.Start()
            at NuGet.Protocol.Plugins.PluginFactory.CreatePluginAsync(String filePath, IEnumerable`1 arguments, IRequestHandlers requestHandlers, ConnectionOptions options, CancellationToken sessionCancellationToken)
            at NuGet.Protocol.Plugins.PluginFactory.GetOrCreateAsync(String filePath, IEnumerable`1 arguments, IRequestHandlers requestHandlers, ConnectionOptions options, CancellationToken sessionCancellationToken)
            at NuGet.Protocol.Plugins.PluginManager.TryCreatePluginAsync(PluginDiscoveryResult result, OperationClaim requestedOperationClaim, PluginRequestKey requestKey, String packageSourceRepository, JObject serviceIndex, CancellationToken cancellationToken)
$ ls -la /home/vsonline/.nuget/plugins/netcore/CredentialProvider.Microsoft/CredentialProvider.Microsoft.dll
-rwxr-xr-x 1 vsonline vsonline 117624 Nov  4 20:20 /home/vsonline/.nuget/plugins/netcore/CredentialProvider.Microsoft/CredentialProvider.Microsoft.dll

Success on 2.2.401

$ dotnet restore --interactive
      [CredentialProvider]DeviceFlow: <redacted>
      [CredentialProvider]ATTENTION: User interaction required. 
  
      **********************************************************************
  
      To sign in, use a web browser to open the page https://microsoft.com/devicelogin and enter the code <redacted> to authenticate.
  
      **********************************************************************

Dotnet info

$ dotnet --info
'.NET Core SDK (reflecting any global.json):
 Version:   3.1.100
 Commit:    cd82f021f4

Runtime Environment:
 OS Name:     debian
 OS Version:  9
 OS Platform: Linux
 RID:         debian.9-x64
 Base Path:   /home/vsonline/.dotnet/sdk/3.1.100/

Host (useful for support):
  Version: 3.1.0
  Commit:  65f04fb6db

.NET Core SDKs installed:
  1.1.14 [/home/vsonline/.dotnet/sdk]
  2.1.802 [/home/vsonline/.dotnet/sdk]
  2.2.402 [/home/vsonline/.dotnet/sdk]
  3.0.100 [/home/vsonline/.dotnet/sdk]
  3.1.100 [/home/vsonline/.dotnet/sdk]

.NET Core runtimes installed:
  Microsoft.AspNetCore.All 2.1.13 [/home/vsonline/.dotnet/shared/Microsoft.AspNetCore.All]
  Microsoft.AspNetCore.All 2.2.7 [/home/vsonline/.dotnet/shared/Microsoft.AspNetCore.All]
  Microsoft.AspNetCore.App 2.1.13 [/home/vsonline/.dotnet/shared/Microsoft.AspNetCore.App]
  Microsoft.AspNetCore.App 2.2.7 [/home/vsonline/.dotnet/shared/Microsoft.AspNetCore.App]
  Microsoft.AspNetCore.App 3.0.0 [/home/vsonline/.dotnet/shared/Microsoft.AspNetCore.App]
  Microsoft.AspNetCore.App 3.1.0 [/home/vsonline/.dotnet/shared/Microsoft.AspNetCore.App]
  Microsoft.NETCore.App 1.1.13 [/home/vsonline/.dotnet/shared/Microsoft.NETCore.App]
  Microsoft.NETCore.App 2.1.13 [/home/vsonline/.dotnet/shared/Microsoft.NETCore.App]
  Microsoft.NETCore.App 2.2.7 [/home/vsonline/.dotnet/shared/Microsoft.NETCore.App]
  Microsoft.NETCore.App 3.0.0 [/home/vsonline/.dotnet/shared/Microsoft.NETCore.App]
  Microsoft.NETCore.App 3.1.0 [/home/vsonline/.dotnet/shared/Microsoft.NETCore.App]

To install additional .NET Core runtimes or SDKs:
  https://aka.ms/dotnet-download
@jkeech
Copy link
Member Author

jkeech commented Dec 27, 2019

It looks like this might be a bigger issue with .NET Core SDK 3.1.100 on Ubuntu 18.04 / Debian 9.

@jkeech
Copy link
Member Author

jkeech commented Dec 27, 2019

Filed dotnet/core#4053 which might be related.

@yufeih
Copy link

yufeih commented Feb 25, 2020

I am also seeing this error on Mac, it occurs on both 3.1.100 and 3.0.100, but works no 2.2.402:

/usr/local/share/dotnet/sdk/3.1.100/NuGet.targets(123,5): error : Problem starting the plugin '/Users/yufeih/.nuget/plugins/netcore/CredentialProvider.Microsoft/CredentialProvider.Microsoft.dll'. Plugin 'CredentialProvider.Microsoft' failed within 5.049 seconds with exit code .

dotnet info:

.NET Core SDK (reflecting any global.json):
 Version:   3.1.100
 Commit:    cd82f021f4

Runtime Environment:
 OS Name:     Mac OS X
 OS Version:  10.15
 OS Platform: Darwin
 RID:         osx.10.15-x64
 Base Path:   /usr/local/share/dotnet/sdk/3.1.100/

Host (useful for support):
  Version: 3.1.0
  Commit:  65f04fb6db

.NET Core SDKs installed:
  2.2.402 [/usr/local/share/dotnet/sdk]
  3.0.100 [/usr/local/share/dotnet/sdk]
  3.1.100 [/usr/local/share/dotnet/sdk]

.NET Core runtimes installed:
  Microsoft.AspNetCore.All 2.2.7 [/usr/local/share/dotnet/shared/Microsoft.AspNetCore.All]
  Microsoft.AspNetCore.App 2.2.7 [/usr/local/share/dotnet/shared/Microsoft.AspNetCore.App]
  Microsoft.AspNetCore.App 3.0.0 [/usr/local/share/dotnet/shared/Microsoft.AspNetCore.App]
  Microsoft.AspNetCore.App 3.1.0 [/usr/local/share/dotnet/shared/Microsoft.AspNetCore.App]
  Microsoft.NETCore.App 2.1.14 [/usr/local/share/dotnet/shared/Microsoft.NETCore.App]
  Microsoft.NETCore.App 2.2.7 [/usr/local/share/dotnet/shared/Microsoft.NETCore.App]
  Microsoft.NETCore.App 3.0.0 [/usr/local/share/dotnet/shared/Microsoft.NETCore.App]
  Microsoft.NETCore.App 3.1.0 [/usr/local/share/dotnet/shared/Microsoft.NETCore.App]

To install additional .NET Core runtimes or SDKs:
  https://aka.ms/dotnet-download

@herenhuang herenhuang added triaged Azure Artifacts tag for items marked for follow-up by our team bug Something isn't working labels Jun 29, 2020
@dave-yotta
Copy link

dave-yotta commented Jul 17, 2020

@veleek
Copy link

veleek commented Aug 19, 2020

@jkeech - I have a devops pipeline using windows-latest that fails the same way so I don't believe this is isolated to Ubuntu.

Using SDK Version: 3.1.302

@herenhuang herenhuang added backlog Azure Artifacts tag for items under consideration in our backlog and removed triaged Azure Artifacts tag for items marked for follow-up by our team labels Aug 31, 2020
@chaoticsoftware
Copy link

I've started seeing this failure in my DevOps pipeline. Using SDK ver. 3.1.402 and NuGet 5.7.0. I think, for me this started after switching from a custom NuGet task to provide creds to private feed with the NuGet Authenticate task.
Also, what I don't quite understand is why this is failing the "dotnet build --no-restore" task, when the previous dotnet restore task succeeds.

@dave-yotta
Copy link

Just to let you guys know, there are a bunch of us over here: https://developercommunity.visualstudio.com/content/problem/1106610/sporadic-dotnet-restore-authentication-credentialp.html having this randomly break our azure devops pipelines.

Currently the advice from azure is a temporary workaround to increase timeouts manually on each pipeline, while we wait for a fix in this repo:

NUGET_PLUGIN_HANDSHAKE_TIMEOUT_IN_SECONDS: 60
NUGET_PLUGIN_REQUEST_TIMEOUT_IN_SECONDS: 60

Any idea how long this will take?

@chaoticsoftware
Copy link

I've started seeing this failure in my DevOps pipeline. Using SDK ver. 3.1.402 and NuGet 5.7.0. I think, for me this started after switching from a custom NuGet task to provide creds to private feed with the NuGet Authenticate task.
Also, what I don't quite understand is why this is failing the "dotnet build --no-restore" task, when the previous dotnet restore task succeeds.

UPDATE -- For me the issue was stemmed from some build tools (fetching during build itself, not restore), and as I understand the "dotnet restore" task that came before that would effectively clear out the auth context. So I managed to successfully fix my issue by reordering the tasks to do:

  • dotnet restore (takes care of auth by itself)
  • nuget authenticate
  • dotnet tool restore
  • dotnet build --no-restore

@dave-yotta
Copy link

dave-yotta commented Oct 15, 2020

  • nuget authenticate
  • dotnet tool restore

Are you sure? This issue is happening at a low repro rate. We have for example a failure on dotnet tool restore, only occasionally:

(Credential provider starting sucessfully)
image

(Directly followed by auth failure - nuget saying "problem starting the plugin")
image

Something like the credential provider not responding to the nuget plugin architecture soon enough, so it gets ignored at those times it's extra slow at responding.

@chaoticsoftware
Copy link

chaoticsoftware commented Oct 15, 2020 via email

@dave-yotta
Copy link

I am not sure what to take from the screenshots you posted Dave. But I’m also not certain that the issues you are facing are necessarily identical to what I was facing. Therefore the “solution” that worked for me may not be applicable to you. It did definitely solve my problem though.

-Sina

Sorry for being confusing - the issue is due to a timeout in NuGet waiting for a response from the credential provider. Just letting you know if you see this "problem starting the plugin" during a restore, it might go away and come back since it's a timing based problem - others have thought it fixed only to see it come back.

@github-actions
Copy link

In order to consolidate to fewer feedback channels, we've moved suggestions and issue reporting to Developer Community.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
backlog Azure Artifacts tag for items under consideration in our backlog bug Something isn't working redirect-to-dev-community
Projects
None yet
Development

No branches or pull requests

6 participants