Azure-pipelines-tasks: Nuget installer task fails while restoring from VSTS package management

[cilerler]

Nuget Installer task is failing when attempting to restore package from VSTS package management. Local restore works fine. You may find the log below.

Same is actually a same issue with #2159 except packages are still in the system.

Log from the build

2016-08-01T13:45:01.5179422Z Checking if artifacts directory exists: C:\a\1\a
2016-08-01T13:45:01.5189421Z Creating artifacts directory.
2016-08-01T13:45:01.5189421Z Checking if test results directory exists: C:\a\1\TestResults
2016-08-01T13:45:01.5199424Z Creating test results directory.
2016-08-01T13:45:01.5209432Z Creating binaries directory.
2016-08-01T13:45:01.5539403Z Starting: Get sources
2016-08-01T13:45:01.5639476Z Entering GitSourceProvider.PrepareRepositoryAsync
2016-08-01T13:45:01.5639476Z Repository type=GitHub
2016-08-01T13:45:01.5639476Z localPath=C:\a\1\s
2016-08-01T13:45:01.5639476Z clean=True
2016-08-01T13:45:01.5639476Z sourceBranch=master
2016-08-01T13:45:01.5649432Z sourceVersion=8450fb4c166fadce4a0741f4a649ded8a4932215
2016-08-01T13:45:01.5649432Z Syncing repository: organization/repository (Git)
2016-08-01T13:45:01.5659445Z repository url=https://github.com/organization/repository.git
2016-08-01T13:45:01.5679419Z checkoutSubmodules=True
2016-08-01T13:45:01.6369421Z Starting clone
2016-08-01T13:45:05.5603593Z Checking out 8450fb4c166fadce4a0741f4a649ded8a4932215 to C:\a\1\s with submodules
2016-08-01T13:45:05.7063595Z Checked out branch master for repository organization/repository at commit 8450fb4c166fadce4a0741f4a649ded8a4932215
2016-08-01T13:45:05.7213563Z Leaving GitSourceProvider.PrepareRepositoryAsync
2016-08-01T13:45:05.8833588Z Running tasks
2016-08-01T13:45:05.9153566Z Starting task: NuGet restore **\*.sln
2016-08-01T13:45:05.9773572Z Set workingFolder to default: C:\LR\MMS\Services\Mms\TaskAgentProvisioner\Tools\agents\1.103.1\tasks\NuGetInstaller\0.2.5
2016-08-01T13:45:06.4118697Z ##[debug]agent.workFolder=C:\a
2016-08-01T13:45:06.4138700Z ##[debug]loading inputs and endpoints
2016-08-01T13:45:06.4148687Z ##[debug]loading ENDPOINT_AUTH_HTTPS://GITHUB.COM/organization/repository.GIT
2016-08-01T13:45:06.4158700Z ##[debug]loading ENDPOINT_AUTH_PARAMETER_HTTPS://GITHUB.COM/organization/repository.GIT_PASSWORD
2016-08-01T13:45:06.4168695Z ##[debug]loading ENDPOINT_AUTH_PARAMETER_HTTPS://GITHUB.COM/organization/repository.GIT_USERNAME
2016-08-01T13:45:06.4168695Z ##[debug]loading ENDPOINT_AUTH_PARAMETER_SYSTEMVSSCONNECTION_ACCESSTOKEN
2016-08-01T13:45:06.4178691Z ##[debug]loading ENDPOINT_AUTH_SCHEME_HTTPS://GITHUB.COM/organization/repository.GIT
2016-08-01T13:45:06.4178691Z ##[debug]loading ENDPOINT_AUTH_SCHEME_SYSTEMVSSCONNECTION
2016-08-01T13:45:06.4188696Z ##[debug]loading ENDPOINT_AUTH_SYSTEMVSSCONNECTION
2016-08-01T13:45:06.4188696Z ##[debug]loading INPUT_NOCACHE
2016-08-01T13:45:06.4200031Z ##[debug]loading INPUT_NUGETCONFIGPATH
2016-08-01T13:45:06.4200031Z ##[debug]loading INPUT_PRECREDPROVIDERNUGET
2016-08-01T13:45:06.4208690Z ##[debug]loading INPUT_RESTOREMODE
2016-08-01T13:45:06.4208690Z ##[debug]loading INPUT_SOLUTION
2016-08-01T13:45:06.4218695Z ##[debug]loading INPUT_VERBOSITY
2016-08-01T13:45:06.4218695Z ##[debug]loaded 13
2016-08-01T13:45:06.5978691Z ##[debug]check path : C:\LR\MMS\Services\Mms\TaskAgentProvisioner\Tools\agents\1.103.1\tasks\NuGetInstaller\0.2.5\task.json
2016-08-01T13:45:06.5988743Z ##[debug]set resource file to: C:\LR\MMS\Services\Mms\TaskAgentProvisioner\Tools\agents\1.103.1\tasks\NuGetInstaller\0.2.5\task.json
2016-08-01T13:45:06.5988743Z ##[debug]system.culture=en-US
2016-08-01T13:45:06.6018685Z ##[debug]solution=C:\a\1\s\**\*.sln
2016-08-01T13:45:06.6028695Z ##[debug]System.DefaultWorkingDirectory=C:\a\1\s
2016-08-01T13:45:06.6028695Z ##[debug]Matching glob pattern: C:\a\1\s\**\*.sln
2016-08-01T13:45:06.6038698Z ##[debug]Index of first wildcard: 9
2016-08-01T13:45:06.6038698Z ##[debug]find root dir: C:\a\1
2016-08-01T13:45:06.6378737Z ##[debug]find C:\a\1
2016-08-01T13:45:06.6388739Z ##[debug]177 matches.
2016-08-01T13:45:06.6608690Z ##[debug]noCache=false
2016-08-01T13:45:06.6608690Z ##[debug]nuGetRestoreArgs=null
2016-08-01T13:45:06.6618689Z ##[debug]verbosity=Detailed
2016-08-01T13:45:06.6618689Z ##[debug]preCredProviderNuGet=false
2016-08-01T13:45:06.6628696Z ##[debug]restoreMode=restore
2016-08-01T13:45:06.6628696Z ##[debug]nugetConfigPath=C:\a\1\s\.nuget\NuGet.config
2016-08-01T13:45:06.6638688Z ##[debug]check path : C:\a\1\s\.nuget\NuGet.config
2016-08-01T13:45:06.6638688Z ##[debug]nugetConfigPath=C:\a\1\s\.nuget\NuGet.config
2016-08-01T13:45:06.6648695Z ##[debug]build.sourcesDirectory=C:\a\1\s
2016-08-01T13:45:06.6648695Z ##[debug]nugetConfigPathpath supplied :true
2016-08-01T13:45:06.6658693Z ##[debug]nuGetPath=null
2016-08-01T13:45:06.6658693Z ##[debug]nuGetPath=null
2016-08-01T13:45:06.6668693Z ##[debug]build.sourcesDirectory=C:\a\1\s
2016-08-01T13:45:06.6668693Z ##[debug]nuGetPathpath supplied :true
2016-08-01T13:45:06.6668693Z ##[debug]SYSTEMVSSCONNECTION=https://organization.visualstudio.com/
2016-08-01T13:45:06.6678692Z ##[debug]Agent.HomeDirectory=C:\LR\MMS\Services\Mms\TaskAgentProvisioner\Tools\agents\1.103.1
2016-08-01T13:45:06.6678692Z ##[debug]looking for tool NuGet
2016-08-01T13:45:06.6688696Z ##[debug]looking for tool variant nuget.exe
2016-08-01T13:45:06.6688696Z ##[debug]checking C:\LR\MMS\Services\Mms\TaskAgentProvisioner\Tools\agents\1.103.1\externals\nuget\nuget.exe
2016-08-01T13:45:06.6698794Z ##[debug]checking C:\LR\MMS\Services\Mms\TaskAgentProvisioner\Tools\agents\1.103.1\agent\Worker\Tools\NuGetCredentialProvider\nuget.exe
2016-08-01T13:45:06.6698794Z ##[debug]checking C:\LR\MMS\Services\Mms\TaskAgentProvisioner\Tools\agents\1.103.1\agent\Worker\Tools\nuget.exe
2016-08-01T13:45:06.6708689Z ##[debug]Agent.HomeDirectory=C:\LR\MMS\Services\Mms\TaskAgentProvisioner\Tools\agents\1.103.1
2016-08-01T13:45:06.6708689Z ##[debug]looking for tool CredentialProvider.TeamBuild.exe
2016-08-01T13:45:06.6718694Z ##[debug]looking for tool variant CredentialProvider.TeamBuild.exe
2016-08-01T13:45:06.6718694Z ##[debug]checking C:\LR\MMS\Services\Mms\TaskAgentProvisioner\Tools\agents\1.103.1\externals\nuget\CredentialProvider.TeamBuild.exe
2016-08-01T13:45:06.6728768Z ##[debug]checking C:\LR\MMS\Services\Mms\TaskAgentProvisioner\Tools\agents\1.103.1\agent\Worker\Tools\NuGetCredentialProvider\CredentialProvider.TeamBuild.exe
2016-08-01T13:45:06.6728768Z ##[debug]Getting credentials for local feeds
2016-08-01T13:45:06.6738695Z SYSTEMVSSCONNECTION exists true
2016-08-01T13:45:06.6738695Z ##[debug]SYSTEMVSSCONNECTION exists true
2016-08-01T13:45:06.6738695Z ##[debug]Got auth token
2016-08-01T13:45:06.6758700Z ##[debug]discovered URL prefixes: https://organization.visualstudio.com/,https://organization.pkgs.visualstudio.com/
2016-08-01T13:45:06.6758700Z ##[debug]NuGetTasks.ExtraUrlPrefixesForTesting=undefined
2016-08-01T13:45:06.6778786Z ##[debug]C:\LR\MMS\Services\Mms\TaskAgentProvisioner\Tools\agents\1.103.1\agent\Worker\Tools\nuget.exe arg: restore
2016-08-01T13:45:06.6788695Z ##[debug]C:\LR\MMS\Services\Mms\TaskAgentProvisioner\Tools\agents\1.103.1\agent\Worker\Tools\nuget.exe arg: -NonInteractive
2016-08-01T13:45:06.6788695Z ##[debug]C:\LR\MMS\Services\Mms\TaskAgentProvisioner\Tools\agents\1.103.1\agent\Worker\Tools\nuget.exe pathArg: C:\a\1\s\Master.sln
2016-08-01T13:45:06.6798694Z ##[debug]C:\LR\MMS\Services\Mms\TaskAgentProvisioner\Tools\agents\1.103.1\agent\Worker\Tools\nuget.exe arg: C:\a\1\s\Master.sln
2016-08-01T13:45:06.6798694Z ##[debug]C:\LR\MMS\Services\Mms\TaskAgentProvisioner\Tools\agents\1.103.1\agent\Worker\Tools\nuget.exe arg: -ConfigFile
2016-08-01T13:45:06.6808696Z ##[debug]C:\LR\MMS\Services\Mms\TaskAgentProvisioner\Tools\agents\1.103.1\agent\Worker\Tools\nuget.exe pathArg: C:\a\1\s\.nuget\NuGet.config
2016-08-01T13:45:06.6808696Z ##[debug]C:\LR\MMS\Services\Mms\TaskAgentProvisioner\Tools\agents\1.103.1\agent\Worker\Tools\nuget.exe arg: C:\a\1\s\.nuget\NuGet.config
2016-08-01T13:45:06.6818694Z ##[debug]C:\LR\MMS\Services\Mms\TaskAgentProvisioner\Tools\agents\1.103.1\agent\Worker\Tools\nuget.exe arg: -Verbosity
2016-08-01T13:45:06.6818694Z ##[debug]C:\LR\MMS\Services\Mms\TaskAgentProvisioner\Tools\agents\1.103.1\agent\Worker\Tools\nuget.exe arg: Detailed
2016-08-01T13:45:06.6828695Z ##[debug]exec tool: C:\LR\MMS\Services\Mms\TaskAgentProvisioner\Tools\agents\1.103.1\agent\Worker\Tools\nuget.exe
2016-08-01T13:45:06.6828695Z ##[debug]Arguments:
2016-08-01T13:45:06.6828695Z ##[debug]   restore
2016-08-01T13:45:06.6838695Z ##[debug]   -NonInteractive
2016-08-01T13:45:06.6838695Z ##[debug]   C:\a\1\s\Master.sln
2016-08-01T13:45:06.6848695Z ##[debug]   -ConfigFile
2016-08-01T13:45:06.6848695Z ##[debug]   C:\a\1\s\.nuget\NuGet.config
2016-08-01T13:45:06.6858696Z ##[debug]   -Verbosity
2016-08-01T13:45:06.6858696Z ##[debug]   Detailed
2016-08-01T13:45:06.6868697Z [command]C:\LR\MMS\Services\Mms\TaskAgentProvisioner\Tools\agents\1.103.1\agent\Worker\Tools\nuget.exe restore -NonInteractive C:\a\1\s\Master.sln -ConfigFile C:\a\1\s\.nuget\NuGet.config -Verbosity Detailed
2016-08-01T13:45:07.8514182Z MSBuild auto-detection: using msbuild version '14.0' from 'C:\Program Files (x86)\MSBuild\14.0\bin'. Use option -MSBuildVersion to force nuget to use a specific version of MSBuild.
2016-08-01T13:45:08.1504617Z Feeds used:
2016-08-01T13:45:08.1504617Z   C:\Users\buildguest\AppData\Local\NuGet\Cache
2016-08-01T13:45:08.1515429Z   https://api.nuget.org/v3/index.json
2016-08-01T13:45:08.1515429Z   https://organization.pkgs.visualstudio.com/DefaultCollection/_packaging/Main/nuget/v3/index.json
2016-08-01T13:45:08.1524628Z   C:\Program Files (x86)\Microsoft SDKs\NuGetPackages\
2016-08-01T13:45:08.1524628Z   C:\Program Files\Microsoft SDKs\Service Fabric\packages\
2016-08-01T13:45:08.2554601Z Restoring NuGet package CommonServiceLocator.1.3.0.
...
...
2016-08-01T13:45:19.7696749Z Restoring NuGet package DataFileStorage.1.0.0-ci-20160801-124646.
...
...
2016-08-01T13:45:22.5073213Z WARNING: Unable to find version '1.0.0-ci-20160801-124646' of package 'DataFileStorage'.
...
...
2016-08-01T13:45:36.8442475Z Unable to find version '1.0.0-ci-20160801-124646' of package 'DataFileStorage'.
2016-08-01T13:45:36.8812480Z ##[debug]rc:1
2016-08-01T13:45:36.8812480Z ##[debug]success:false
2016-08-01T13:45:36.8892471Z ##[error]Error: C:\LR\MMS\Services\Mms\TaskAgentProvisioner\Tools\agents\1.103.1\agent\Worker\Tools\nuget.exe failed with return code: 1
2016-08-01T13:45:36.8902468Z ##[error]Packages failed to install
2016-08-01T13:45:36.8912472Z ##[debug]task result: Failed
2016-08-01T13:45:36.8912472Z ##[error]Return code: 1
2016-08-01T13:45:36.9322478Z Finishing task: NuGetInstaller
2016-08-01T13:45:36.9422476Z ##[error]System.Exception: Task NuGetInstaller failed. This caused the job to fail. Look at the logs for the task for more details.
2016-08-01T13:45:36.9432469Z ##[error]   at Microsoft.TeamFoundation.DistributedTask.Worker.JobRunner.Run(IJobContext jobContext, IJobRequest job, IJobExtension jobExtension, CancellationTokenSource tokenSource)

[cilerler]

It is a confirmed known issue and MSFT is working on it.
Here is the service blog link Failures while restoring nuget packages in Visual Studio Team Services – 8/1 – Investigating

[cilerler]

Issue has been resolved

[vitorgrs]

Well, not solved. Still having problems...

[ericsciple]

@vitorgrs please open an issue with details - we'll get routed to the correct folks