search

microsoft / artifacts-credprovider

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

random 401 during noninteractive nuget.exe runs #135

Closed quasarea closed 5 years ago

quasarea commented 5 years ago

I have nuget executable (5.2.0.6090) in same folder that credential provider (0.1.19) is.

I call the same command, using the same user (generic account) across few nodes.

 ..\Build\NuGet\Client\NuGet.exe install -NonInteractive -ConfigFile ..\Build\NuGet\NuGet.Config -Prerelease -Framework net472 -ExcludeVersion -DependencyVersion Lowest -OutputDirectory ..\Build\Packages MyBuildTools -Version 1.0.4
 Feeds used:
   C:\Users\username\.nuget\packages\
   https://pkgs.dev.azure.com/Company/_packaging/CompanyFeed/nuget/v3/index.json

 Attempting to gather dependency information for package 'MyBuildTools.1.0.4' with respect to project '..\Build\Packages', targeting '.NETFramework,Version=v4.7.2'
 MSBuild auto-detection: using msbuild version '15.9.21.664' from 'C:\Program Files (x86)\Microsoft Visual Studio\2017\Professional\MSBuild\15.0\bin'.
 WARNING: The plugin credential provider could not acquire credentials. Authentication may require manual action. Consider re-running the command with --interactive for `dotnet`, /p:NuGetInteractive="true" for MSBuild or removing the -NonInteractive switch for `NuGet`
 WARNING: The credential plugin model used by 'M:\CurrentModule\Build\NuGet\Client\CredentialProvider.Microsoft.exe' is deprecated. Please contact the provider of the plugin for an alternative. More information about the recommended plugin model can be found at 'https://aka.ms/nuget-cross-platform-authentication-plugin'.
 Unable to load the service index for source https://pkgs.dev.azure.com/Company/_packaging/CompanyFeed/nuget/v3/index.json.
   Response status code does not indicate success: 401 (Unauthorized).

NuGet.Config

<?xml version="1.0" encoding="utf-8"?>
<configuration>
  <packageSources>
    <add key="Company" value="https://pkgs.dev.azure.com/Company/_packaging/CompanyFeed/nuget/v3/index.json" />
  </packageSources>
  <packageRestore>
    <add key="enabled" value="True" />
    <add key="automatic" value="True" />
  </packageRestore>
  <bindingRedirects>
    <add key="skip" value="False" />
  </bindingRedirects>
  <apikeys>
  </apikeys>
  <disabledPackageSources>
    <add key="nuget.org" value="true" />
    <add key="development" value="true" />
  </disabledPackageSources>
</configuration>

I do 

SET NUGET_CREDENTIALPROVIDER_LOG_PATH=c:\jenkins\workspace\company\build\nuget-#22.log

before the run. If it's successful I get:

[09:56:49.120 12540 Minimal] Log starts at 2019-10-09 09:56:49Z
[09:56:49.871 12540 Verbose] ADAL FileCache disabled by environment variable, using the DefaultShared TokenCache
[09:56:49.879 12540 Verbose] SessionToken cache location: C:\Users\username\AppData\Local\MicrosoftCredentialProvider\SessionTokenCache.dat
[09:56:49.890 12540 Verbose] Running in stand-alone mode
[09:56:49.893 12540 Verbose] Command-line v0.1.19: ..\..\..\Build\NuGet\Client\CredentialProvider.Microsoft.exe  -nonInteractive -uri https://Company.pkgs.visualstudio.com/_packaging/CompanyFeed/nuget/v3/index.json
[09:56:49.909 12540 Verbose] Handling auth request, Uri: https://Company.pkgs.visualstudio.com/_packaging/CompanyFeed/nuget/v3/index.json, IsRetry: False, IsNonInteractive: True, CanShowDialog: False
[09:56:49.910 12540 Verbose] URI: https://Company.pkgs.visualstudio.com/_packaging/CompanyFeed/nuget/v3/index.json
[09:56:49.911 12540 Verbose] VstsBuildTaskServiceEndpointCredentialProvider - This credential provider must be run under the Team Build tasks for NuGet with external endpoint credentials. Appropriate environment variable needs to be set.
[09:56:49.912 12540 Verbose] Skipping NuGetCredentialProvider.CredentialProviders.VstsBuildTaskServiceEndpoint.VstsBuildTaskServiceEndpointCredentialProvider, cannot provide credentials for https://Company.pkgs.visualstudio.com/_packaging/CompanyFeed/nuget/v3/index.json
[09:56:49.913 12540 Verbose] VstsBuildTaskCredentialProvider - This credential provider must be run under the Team Build tasks for NuGet. Appropriate environment variables must be set.
[09:56:49.913 12540 Verbose] Skipping NuGetCredentialProvider.CredentialProviders.VstsBuildTask.VstsBuildTaskCredentialProvider, cannot provide credentials for https://Company.pkgs.visualstudio.com/_packaging/CompanyFeed/nuget/v3/index.json
[09:56:49.918 12540 Verbose] IsRetry: False
[09:56:50.129 12540 Verbose] Found cached SessionToken for https://Company.pkgs.visualstudio.com/_packaging/CompanyFeed/nuget/v3/index.json
[09:56:50.130 12540    Info] Username: VssSessionToken
[09:56:50.131 12540    Info] Password: a.b.c

odd bit here is that I migrated Company.pkgs.visualstudio.com to pkgs.dev.azure.com few weeks ago

when failing log is the same as succesful one, but then expands:

[09:45:27.287  4876 Minimal] Log starts at 2019-10-09 09:45:27Z
[09:45:28.282  4876 Verbose] ADAL FileCache disabled by environment variable, using the DefaultShared TokenCache
[09:45:28.293  4876 Verbose] SessionToken cache location: C:\Users\username\AppData\Local\MicrosoftCredentialProvider\SessionTokenCache.dat
[09:45:28.302  4876 Verbose] Running in stand-alone mode
[09:45:28.306  4876 Verbose] Command-line v0.1.19: ..\..\..\Build\NuGet\Client\CredentialProvider.Microsoft.exe  -nonInteractive -uri https://Company.pkgs.visualstudio.com/_packaging/CompanyFeed/nuget/v3/index.json
[09:45:28.318  4876 Verbose] Handling auth request, Uri: https://Company.pkgs.visualstudio.com/_packaging/CompanyFeed/nuget/v3/index.json, IsRetry: False, IsNonInteractive: True, CanShowDialog: False
[09:45:28.319  4876 Verbose] URI: https://Company.pkgs.visualstudio.com/_packaging/CompanyFeed/nuget/v3/index.json
[09:45:28.321  4876 Verbose] VstsBuildTaskServiceEndpointCredentialProvider - This credential provider must be run under the Team Build tasks for NuGet with external endpoint credentials. Appropriate environment variable needs to be set.
[09:45:28.321  4876 Verbose] Skipping NuGetCredentialProvider.CredentialProviders.VstsBuildTaskServiceEndpoint.VstsBuildTaskServiceEndpointCredentialProvider, cannot provide credentials for https://Company.pkgs.visualstudio.com/_packaging/CompanyFeed/nuget/v3/index.json
[09:45:28.322  4876 Verbose] VstsBuildTaskCredentialProvider - This credential provider must be run under the Team Build tasks for NuGet. Appropriate environment variables must be set.
[09:45:28.322  4876 Verbose] Skipping NuGetCredentialProvider.CredentialProviders.VstsBuildTask.VstsBuildTaskCredentialProvider, cannot provide credentials for https://Company.pkgs.visualstudio.com/_packaging/CompanyFeed/nuget/v3/index.json
[09:45:28.329  4876 Verbose] IsRetry: False
[09:45:28.555  4876 Verbose] Found cached SessionToken for https://Company.pkgs.visualstudio.com/_packaging/CompanyFeed/nuget/v3/index.json
[09:45:28.556  4876    Info] Username: VssSessionToken
[09:45:28.557  4876    Info] Password: a.b.c
[Verbose] [CredentialProvider]ADAL FileCache disabled by environment variable, using the DefaultShared TokenCache
[Verbose] [CredentialProvider]SessionToken cache location: C:\Users\username\AppData\Local\MicrosoftCredentialProvider\SessionTokenCache.dat
[Verbose] [CredentialProvider]Command-line v0.1.5: "C:\Program Files (x86)\Microsoft Visual Studio\2017\Professional\Common7\IDE\CommonExtensions\Microsoft\NuGet\Plugins\CredentialProvider.Microsoft\CredentialProvider.Microsoft.exe" -Plugin
[Verbose] [CredentialProvider]Running in plug-in mode
[Verbose] [CredentialProvider]Handling 'Request' 'Initialize' - {"ClientVersion":"5.2.0","Culture":"en-GB","RequestTimeout":"00:00:05"}
[Verbose] [CredentialProvider]Sending response: '{"ResponseCode":0}'
[Verbose] [CredentialProvider]Handling 'Request' 'GetOperationClaims' - {}
[Verbose] [CredentialProvider]Sending response: '{"Claims":[1]}'
[Verbose] [CredentialProvider]Handling 'Request' 'SetLogLevel' - {"LogLevel":"Information"}
[09:47:40.672 10724 Minimal] Log starts at 2019-10-09 09:47:40Z
[09:47:40.685 10724 Verbose] ADAL FileCache disabled by environment variable, using the DefaultShared TokenCache
[09:47:40.693 10724 Verbose] SessionToken cache location: C:\Users\username\AppData\Local\MicrosoftCredentialProvider\SessionTokenCache.dat
[09:47:40.701 10724 Verbose] Running in stand-alone mode
[09:47:40.704 10724 Verbose] Command-line v0.1.19: "M:\CurrentModule\Build\NuGet\Client\CredentialProvider.Microsoft.exe" -uri https://pkgs.dev.azure.com/Company/_packaging/CompanyFeed/nuget/v3/index.json -nonInteractive
[09:47:40.711 10724 Verbose] Handling auth request, Uri: https://pkgs.dev.azure.com/Company/_packaging/CompanyFeed/nuget/v3/index.json, IsRetry: False, IsNonInteractive: True, CanShowDialog: False
[09:47:40.711 10724 Verbose] URI: https://pkgs.dev.azure.com/Company/_packaging/CompanyFeed/nuget/v3/index.json
[09:47:40.713 10724 Verbose] VstsBuildTaskServiceEndpointCredentialProvider - This credential provider must be run under the Team Build tasks for NuGet with external endpoint credentials. Appropriate environment variable needs to be set.
[09:47:40.713 10724 Verbose] Skipping NuGetCredentialProvider.CredentialProviders.VstsBuildTaskServiceEndpoint.VstsBuildTaskServiceEndpointCredentialProvider, cannot provide credentials for https://pkgs.dev.azure.com/Company/_packaging/CompanyFeed/nuget/v3/index.json
[09:47:40.714 10724 Verbose] VstsBuildTaskCredentialProvider - This credential provider must be run under the Team Build tasks for NuGet. Appropriate environment variables must be set.
[09:47:40.714 10724 Verbose] Skipping NuGetCredentialProvider.CredentialProviders.VstsBuildTask.VstsBuildTaskCredentialProvider, cannot provide credentials for https://pkgs.dev.azure.com/Company/_packaging/CompanyFeed/nuget/v3/index.json
[09:47:40.819 10724 Verbose] GET https://pkgs.dev.azure.com/Company/_packaging/CompanyFeed/nuget/v3/index.json
[09:47:41.044 10724 Verbose] IsRetry: False
[09:47:41.240 10724 Verbose] Could not find cached SessionToken for https://pkgs.dev.azure.com/Company/_packaging/CompanyFeed/nuget/v3/index.json
[09:47:41.255 10724 Verbose] GET https://pkgs.dev.azure.com/Company/_packaging/CompanyFeed/nuget/v3/index.json
[09:47:41.348 10724 Verbose] Found AAD Authority from 401 headers: https://login.windows.net/425a5546-5a6e-4f1b-ab62-23d91d07d893
[09:47:41.349 10724 Verbose] VstsCredentialProvider - Using AAD authority: https://login.windows.net/425a5546-5a6e-4f1b-ab62-23d91d07d893
[09:47:41.350 10724 Verbose] VstsCredentialProvider - Attempting to acquire bearer token using provider 'ADAL Cache'
[09:47:41.589 10724 Verbose] VstsCredentialProvider - Bearer token provider 'ADAL Cache' didn't acquire a token
[09:47:41.591 10724 Verbose] VstsCredentialProvider - Attempting to acquire bearer token using provider 'ADAL Windows Integrated Authentication'
[09:47:42.362 10724    Info] VstsCredentialProvider - Acquired bearer token using 'ADAL Windows Integrated Authentication'
[09:47:42.364 10724    Info] VstsCredentialProvider - Attempting to exchange the bearer token for an Azure DevOps session token.
[09:47:42.369 10724 Verbose] Requesting a SelfDescribing token valid for duration 04:00:00, valid until 09/10/2019 13:47:42 UTC. Note that the generated token may have different validity than requested.
[09:47:42.378 10724 Verbose] GET https://pkgs.dev.azure.com/Company/_packaging/CompanyFeed/nuget/v3/index.json
[09:47:42.998 10724 Verbose] VstsCredentialProvider - Found SessionToken for https://pkgs.dev.azure.com/Company/_packaging/CompanyFeed/nuget/v3/index.json
[09:47:42.999 10724 Verbose] Caching SessionToken for https://pkgs.dev.azure.com/Company/_packaging/CompanyFeed/nuget/v3/index.json
[09:47:43.008 10724    Info] Username: VssSessionToken
[09:47:43.009 10724    Info] Password: a.d.e

Last password here has same front, but different two other bits, while initial password is same

quasarea commented 5 years ago

also it is odd how first and last output of Command-line differs:

[09:45:28.306  4876 Verbose]
Command-line v0.1.19: 
 ..\..\..\Build\NuGet\Client\CredentialProvider.Microsoft.exe
  -nonInteractive
 -uri https://Company.pkgs.visualstudio.com/_packaging/CompanyFeed/nuget/v3/index.json
[09:47:40.704 10724 Verbose]
 Command-line v0.1.19: 
 "M:\CurrentModule\Build\NuGet\Client\CredentialProvider.Microsoft.exe"
 -uri https://pkgs.dev.azure.com/Company/_packaging/CompanyFeed/nuget/v3/index.json
 -nonInteractive
jmyersmsft commented 5 years ago

I think there are a few things getting mixed up here:

It looks like NuGet is trying to use the "old-style" credential provider mechanism with this, the "new-style" credential provider plugin. If you want a standalone instance of the credential provider, I would move it to a folder which is neither the same folder nor a subfolder of the folder that contains nuget.exe, and set the environment variable NUGET_PLUGIN_PATHS to the absolute path (including file name) to CredentialProvider.Microsoft.exe. Alternatively, follow the instructions in the README to install to the central user location

I think the runs which are succeeding are succeeding for a reason unrelated to authentication, such as having all packages not accessible from some source without authentication already cached