microsoft / artifacts-credprovider

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

Failed to acquire session token: System.IO.IOException: Cannot create cache because a file or directory with the same name already exists #432

Closed Haard30 closed 1 year ago

Haard30 commented 1 year ago

Description

Using artifacts-credprovider v1.0.8 as credential provider for Nuget 6.2.1.2, we routinely encounter following problem when running nuget restore.

[CredentialProvider]Failed to acquire session token: System.IO.IOException: Cannot create "C:\Users\<user>\AppData\Local\.IdentityService\msal_<authority>.cache" because a file or directory with the same name already exists.

We had a brief look at the artifacts-credprovider code and wondered if the SessionTokenCache might be conflicting with MSAL but we are not experts in this codebase and weren't able to debug it further. This seems like an unexpected behavior but in case we are wrong, we have provided full stack trace after redacting internal information.

Command

nuget restore c:\<path-to-cache>\packages.config -NoCache -PackagesDirectory c:\<path-to-cache> -PackageSaveMode nuspec -DirectDownload -Verbosity detailed -Source <source-feed-URI>

Environment variables

NUGET_CREDENTIALPROVIDERS_PATH=C:\<path-to-tools>\plugins\netfx\CredentialProvider.Microsoft\
NUGET_CREDENTIALPROVIDER_MSAL_ENABLED=TRUE
NUGET_CREDENTIALPROVIDER_MSAL_FILECACHE_ENABLED=TRUE
NUGET_CREDENTIALPROVIDER_MSAL_FILECACHE_LOCATION=C:\Users\<user>\AppData\Local\.IdentityService\msal_<authority>.cache
NUGET_HTTP_CACHE_PATH=C:\<path-to-tools>\v3-cache
NUGET_NETCORE_PLUGIN_PATHS=<path-to-credprovider>\credprovider\plugins\netcore\CredentialProvider.Microsoft\CredentialProvider.Microsoft.dll
NUGET_NETFX_PLUGIN_PATHS=<path-to-credprovider>\credprovider\plugins\netfx\CredentialProvider.Microsoft\CredentialProvider.Microsoft.exe
NUGET_PACKAGES=C:\<path-to-tools>\packages\
NUGET_PLUGINS_CACHE_PATH=C:\<path-to-tools>\plugins-cache

Nuget output and Stack Trace

NuGet Version: 6.2.1.2
Restoring NuGet package <package.version>.
Using CredentialProvider.Microsoft.exe as a credential provider plugin.
    [CredentialProvider.154540]Running in plug-in mode
    [CredentialProvider.154540]Command-line v1.0.8+54e5949f3366893fafe27bf34ce6f3da24ac3ca7: "CredentialProvider.Microsoft.exe" -Plugin
    [CredentialProvider.154540]Handling 'Request' 'Initialize'. Time elapsed in ms: 3 - Payload: {"ClientVersion":"6.2.1","Culture":"en-US","RequestTimeout":"00:00:05"}
    [CredentialProvider.154540]Sending response: 'Request' 'Initialize'. Time elapsed in ms: 4
    [CredentialProvider.154540]Time elapsed in milliseconds after sending response 'Request' 'Initialize': 5
    [CredentialProvider.154540]Handling 'Request' 'GetOperationClaims'. Time elapsed in ms: 0 - Payload: {}
    [CredentialProvider.154540]Sending response: 'Request' 'GetOperationClaims'. Time elapsed in ms: 7
    [CredentialProvider.154540]Time elapsed in milliseconds after sending response 'Request' 'GetOperationClaims': 22
    [CredentialProvider.154540]Handling 'Request' 'SetLogLevel'. Time elapsed in ms: 1 - Payload: {"LogLevel":"Debug"}
    [CredentialProvider]Sending response: 'Request' 'SetLogLevel'. Time elapsed in ms: 1
    [CredentialProvider]Time elapsed in milliseconds after sending response 'Request' 'SetLogLevel': 4
    [CredentialProvider]Handling 'Request' 'GetAuthenticationCredentials'. Time elapsed in ms: 3 - Payload: {"Uri":"<source-feed-URI>","IsRetry":false,"IsNonInteractive":false,"CanShowDialog":true}
    [CredentialProvider]Creating a progress reporter with interval: 00:00:02
    [CredentialProvider]Handling auth request, Uri: <source-feed-URI>, IsRetry: False, IsNonInteractive: False, CanShowDialog: True
    [CredentialProvider]URI: <source-feed-URI>
    [CredentialProvider]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.
    [CredentialProvider]Skipping NuGetCredentialProvider.CredentialProviders.VstsBuildTaskServiceEndpoint.VstsBuildTaskServiceEndpointCredentialProvider, cannot provide credentials for <source-feed-URI>
    [CredentialProvider]VstsBuildTaskCredentialProvider - This credential provider must be run under the Team Build tasks for NuGet. Appropriate environment variables must be set.
    [CredentialProvider]Skipping NuGetCredentialProvider.CredentialProviders.VstsBuildTask.VstsBuildTaskCredentialProvider, cannot provide credentials for <source-feed-URI>
    [CredentialProvider]VstsCredentialProvider - Matched well-known Azure DevOps Service hostname: <service-hostname>
    [CredentialProvider]Using NuGetCredentialProvider.CredentialProviders.Vsts.VstsCredentialProvider to try to get credentials for <source-feed-URI>.
    [CredentialProvider]IsRetry: False
    [CredentialProvider]Could not find cached SessionToken for <source-feed-URI>
    [CredentialProvider]GET <source-feed-URI>
    [CredentialProvider]Found AAD Authority from 401 headers: https://login.windows.net/<authority>
    [CredentialProvider]VstsCredentialProvider - Using AAD authority: https://login.windows.net/<authority>
WARNING: The credential plugin model used by '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'.
    [CredentialProvider]Using MSAL cache at C:\Users\<user>\AppData\Local\.IdentityService\msal_<authority>.cache
    [CredentialProvider]Failed to acquire session token: System.IO.IOException: Cannot create "C:\Users\<user>\AppData\Local\.IdentityService\msal_<authority>.cache" because a file or directory with the same name already exists.
   at System.IO.__Error.WinIOError(Int32 errorCode, String maybeFullPath)
   at System.IO.Directory.InternalCreateDirectory(String fullPath, String path, Object dirSecurityObj, Boolean checkHost)
   at System.IO.Directory.InternalCreateDirectoryHelper(String path, Boolean checkHost)
   at Microsoft.Identity.Client.Extensions.Msal.CrossPlatLock..ctor(String lockfilePath, Int32 lockFileRetryDelay, Int32 lockFileRetryCount)
   at Microsoft.Identity.Client.Extensions.Msal.MsalCacheHelper.CreateCrossPlatLock(StorageCreationProperties storageCreationProperties)
   at Microsoft.Identity.Client.Extensions.Msal.MsalCacheHelper.<CreateAsync>d__23.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at Microsoft.Artifacts.Authentication.MsalCache.<GetMsalCacheHelperAsync>d__3.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at NuGetCredentialProvider.CredentialProviders.Vsts.MsalTokenProvidersFactory.<GetAsync>d__3.MoveNext() in D:\a\_work\1\s\CredentialProvider.Microsoft\CredentialProviders\Vsts\MsalTokenProvidersFactory.cs:line 29
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at NuGetCredentialProvider.CredentialProviders.Vsts.VstsCredentialProvider.<HandleRequestAsync>d__8.MoveNext() in D:\a\_work\1\s\CredentialProvider.Microsoft\CredentialProviders\Vsts\VstsCredentialProvider.cs:line 102
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
   at NuGetCredentialProvider.RequestHandlers.GetAuthenticationCredentialsRequestHandler.<HandleRequestAsync>d__5.MoveNext() in D:\a\_work\1\s\CredentialProvider.Microsoft\RequestHandlers\GetAuthenticationCredentialsRequestHandler.cs:line 82
    [CredentialProvider]Sending response: 'Request' 'GetAuthenticationCredentials'. Time elapsed in ms: 214
    [CredentialProvider]Time elapsed in milliseconds after sending response 'Request' 'GetAuthenticationCredentials': 217
CredentialProvider.Microsoft: Unhandled Exception: PowerArgs.ValidationArgException: detailed is not a valid value for type LogLevel, options are Debug, Verbose, Information, Minimal, Warning, Error
CredentialProvider.Microsoft:    at PowerArgs.ArgRevivers.ReviveEnum(Type t, String value, Boolean ignoreCase)
CredentialProvider.Microsoft:    at PowerArgs.CommandLineArgument.Revive(String commandLineValue)
CredentialProvider.Microsoft:    at PowerArgs.CommandLineArgument.Populate(HookContext context)
CredentialProvider.Microsoft:    at PowerArgs.CommandLineArgument.PopulateArguments(List`1 arguments, HookContext context)
CredentialProvider.Microsoft:    at PowerArgs.Args.ParseInternal(CommandLineArgumentsDefinition definition, String[] input)
CredentialProvider.Microsoft:    at PowerArgs.Args.<>c__DisplayClass13_0.<ParseAction>b__0()
CredentialProvider.Microsoft:    at PowerArgs.Args.Execute[T](Func`1 argsProcessingCode)
CredentialProvider.Microsoft:    at PowerArgs.Args.ParseAction(CommandLineArgumentsDefinition definition, String[] args)
CredentialProvider.Microsoft:    at PowerArgs.Args.ParseAction(Type t, String[] args)
CredentialProvider.Microsoft:    at PowerArgs.Args.Parse(Type t, String[] args)
CredentialProvider.Microsoft:    at PowerArgs.Args.Parse[T](String[] args)
CredentialProvider.Microsoft:    at PowerArgs.Args.<>c__DisplayClass22_0`1.<ParseAsync>b__0()
CredentialProvider.Microsoft:    at System.Threading.Tasks.Task`1.InnerInvoke()
CredentialProvider.Microsoft:    at System.Threading.Tasks.Task.Execute()
CredentialProvider.Microsoft: --- End of stack trace from previous location where exception was thrown ---
CredentialProvider.Microsoft:    at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
CredentialProvider.Microsoft:    at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
CredentialProvider.Microsoft:    at NuGetCredentialProvider.Program.<Main>d__11.MoveNext() in D:\a\_work\1\s\CredentialProvider.Microsoft\Program.cs:line 65
CredentialProvider.Microsoft: --- End of stack trace from previous location where exception was thrown ---
CredentialProvider.Microsoft:    at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
CredentialProvider.Microsoft:    at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
CredentialProvider.Microsoft:    at NuGetCredentialProvider.Program.<Main>(String[] args)
Unable to find version '<version>' of package '<package>'.
  <source-feed-URI>: Unable to load the service index for source <source-feed-URI>.
  Response status code does not indicate success: 401 (Unauthorized).

Errors in packages.config projects
    Unable to find version '<version>' of package '<package>'.
      <source-feed-URI>: Unable to load the service index for source <source-feed-URI>.
      Response status code does not indicate success: 401 (Unauthorized).
    Unable to find version '<version>' of package '<package>'.
      <source-feed-URI>: Unable to load the service index for source <source-feed-URI>.
      Response status code does not indicate success: 401 (Unauthorized).

NuGet Config files used:
    c:\<project-root>\NuGet.Config
    C:\Users\<user>\AppData\Roaming\NuGet\NuGet.Config
    C:\Program Files (x86)\NuGet\Config\Microsoft.VisualStudio.FallbackLocation.config
    C:\Program Files (x86)\NuGet\Config\Microsoft.VisualStudio.Offline.config

Feeds used:
    <source-feed-URI>
JohnSchmeichel commented 1 year ago

NUGET_CREDENTIALPROVIDER_MSAL_FILECACHE_LOCATION is expecting a directory and will use msal.cache as the file name, so if that environment variable points to an already existing file then you'll get this error. I need to check the history to see if these semantics have changed between token caches between ADAL and MSAL, but as far as I know the MSAL cache behavior (expecting a directory path) have not changed.

JohnSchmeichel commented 1 year ago

Looks like behavior has changed from previous versions, and specifying the full file path was supported.

JohnSchmeichel commented 1 year ago

Published 1.0.9 (not as latest), can you install the new version to see if it resolves your issue?

iex "& { $(irm https://aka.ms/install-artifacts-credprovider.ps1) } -AddNetfx -Version 1.0.9 -Force"
Haard30 commented 1 year ago

Published 1.0.9 (not as latest), can you install the new version to see if it resolves your issue?

iex "& { $(irm https://aka.ms/install-artifacts-credprovider.ps1) } -AddNetfx -Version 1.0.9 -Force"

The fix is working and we no longer get that error with 1.0.9. Thank you so much John for looking into this. Really appreciate it! 😃