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

dotnet tool restore --interactive fails to restore tools from Artifacts unless I UseDotNet@2 Core 3.1.300 via global.json #13061

Closed
VictorioBerra opened this issue Jun 3, 2020 · 8 comments

Comments

@VictorioBerra
Copy link

Note

Issues in this repo are for tracking bugs, feature requests and questions for the tasks in this repo

For a list:
https://github.com/Microsoft/azure-pipelines-tasks/tree/master/Tasks

If you have an issue or request for the Azure Pipelines service, use developer community instead:

https://developercommunity.visualstudio.com/spaces/21/index.html )

Required Information

Entering this information will route you directly to the right team and expedite traction.

Question, Bug, or Feature?
Type: Bug

Enter Task Name: CmdLine or DotNetCoreCLI

list here (V# not needed):
https://github.com/Microsoft/azure-pipelines-tasks/tree/master/Tasks

Environment

Agent name: 'Hosted Agent'
Agent machine name: 'fv-az674'
Current agent version: '2.169.1'

Issue Description

Auth to artifact fails when restoring tools (and a normal dotnet restore too) unless I install a newer version of core. Did something get updated in Core 3.1.300 that fixes this?

NuGet.Config:

<?xml version="1.0" encoding="utf-8"?>
<configuration>
  <packageSources>
    <clear />
    <add key="IAMM" value="https://pkgs.dev.azure.com/SIEE/IAMM/_packaging/IAMM/nuget/v3/index.json" />
  </packageSources>
</configuration>

Pipeline that fails.

trigger:
- master

pool:
  vmImage: 'windows-latest'

steps:

- task: NuGetAuthenticate@0

- task: CmdLine@2
  displayName: 'Execute Cake Script'
  inputs:
    script: |
     dotnet tool restore --interactive
     dotnet cake

Pipeline that works (with a global.json using 3.1.300)

- task: NuGetAuthenticate@0

- task: UseDotNet@2
  displayName: Install .NET Core
  inputs:
    useGlobalJson: true

- task: CmdLine@2
  displayName: 'Execute Cake Script'
  inputs:
    script: |
      dotnet tool restore --interactive
      dotnet cake

Task logs

2020-06-03T16:45:09.3310611Z ##[section]Starting: Execute Cake Script
2020-06-03T16:45:09.3416578Z ==============================================================================
2020-06-03T16:45:09.3416881Z Task         : Command line
2020-06-03T16:45:09.3417188Z Description  : Run a command line script using Bash on Linux and macOS and cmd.exe on Windows
2020-06-03T16:45:09.3417481Z Version      : 2.164.2
2020-06-03T16:45:09.3417695Z Author       : Microsoft Corporation
2020-06-03T16:45:09.3418016Z Help         : https://docs.microsoft.com/azure/devops/pipelines/tasks/utility/command-line
2020-06-03T16:45:09.3418368Z ==============================================================================
2020-06-03T16:45:10.4511412Z Generating script.
2020-06-03T16:45:10.4889845Z ========================== Starting Command Output ===========================
2020-06-03T16:45:10.5146856Z ##[command]"C:\windows\system32\cmd.exe" /D /E:ON /V:OFF /S /C "CALL "d:\a\_temp\6e836ed0-7808-4dcb-bc58-f26f59ee34ca.cmd""
2020-06-03T16:45:16.9848633Z 
2020-06-03T16:45:17.0784976Z Welcome to .NET Core 3.1!
2020-06-03T16:45:17.0785371Z ---------------------
2020-06-03T16:45:17.0785625Z SDK Version: 3.1.202
2020-06-03T16:45:17.0785759Z 
2020-06-03T16:45:17.0788874Z Telemetry
2020-06-03T16:45:17.0789194Z ---------
2020-06-03T16:45:17.0792266Z 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.
2020-06-03T16:45:17.0793475Z 
2020-06-03T16:45:17.0793884Z Read more about .NET Core CLI Tools telemetry: https://aka.ms/dotnet-cli-telemetry
2020-06-03T16:45:17.0794364Z 
2020-06-03T16:45:17.0794826Z ----------------
2020-06-03T16:45:17.0795058Z Explore documentation: https://aka.ms/dotnet-docs
2020-06-03T16:45:17.0795398Z Report issues and find source on GitHub: https://github.com/dotnet/core
2020-06-03T16:45:17.0796083Z Find out what's new: https://aka.ms/dotnet-whats-new
2020-06-03T16:45:17.0796668Z Learn about the installed HTTPS developer cert: https://aka.ms/aspnet-core-https
2020-06-03T16:45:17.0797093Z Use 'dotnet --help' to see available commands or visit: https://aka.ms/dotnet-cli-docs
2020-06-03T16:45:17.0797450Z Write your first app: https://aka.ms/first-net-core-app
2020-06-03T16:45:17.0797781Z --------------------------------------------------------------------------------------
2020-06-03T16:45:38.6557290Z C:\Program Files\dotnet\sdk\3.1.202\NuGet.targets(124,5): error : Problem starting the plugin 'C:\Users\VssAdministrator\.nuget\plugins\netcore\CredentialProvider.Microsoft\CredentialProvider.Microsoft.dll'. Plugin 'CredentialProvider.Microsoft' failed within 6.361 seconds with exit code -1. [C:\Users\VssAdministrator\AppData\Local\Temp\tckqgfrc.nja\restore.csproj]
2020-06-03T16:45:38.8598216Z C:\Program Files\dotnet\sdk\3.1.202\NuGet.targets(124,5): error : Unable to load the service index for source https://pkgs.dev.azure.com/SIEE/IAMM/_packaging/IAMM/nuget/v3/index.json. [C:\Users\VssAdministrator\AppData\Local\Temp\tckqgfrc.nja\restore.csproj]
2020-06-03T16:45:38.8599346Z C:\Program Files\dotnet\sdk\3.1.202\NuGet.targets(124,5): error :   Response status code does not indicate success: 401 (Unauthorized). [C:\Users\VssAdministrator\AppData\Local\Temp\tckqgfrc.nja\restore.csproj]
2020-06-03T16:45:38.9752582Z 
2020-06-03T16:45:38.9774513Z Package "cake.tool" failed to restore, due to Microsoft.DotNet.ToolPackage.ToolPackageException: The tool package could not be restored.
2020-06-03T16:45:38.9775464Z    at Microsoft.DotNet.Tools.Tool.Install.ProjectRestorer.Restore(FilePath project, PackageLocation packageLocation, String verbosity)
2020-06-03T16:45:38.9776279Z    at Microsoft.DotNet.ToolPackage.ToolPackageInstaller.InstallPackageToExternalManagedLocation(PackageLocation packageLocation, PackageId packageId, VersionRange versionRange, String targetFramework, String verbosity)
2020-06-03T16:45:38.9778882Z    at Microsoft.DotNet.Tools.Tool.Restore.ToolRestoreCommand.InstallPackages(ToolManifestPackage package, Nullable`1 configFile)
2020-06-03T16:45:38.9779283Z 
2020-06-03T16:45:38.9779624Z Restore failed.
2020-06-03T16:45:39.1789940Z Run "dotnet tool restore" to make the "dotnet-cake" command available.
2020-06-03T16:45:39.2953522Z ##[error]Cmd.exe exited with code '1'.
2020-06-03T16:45:39.3333143Z ##[section]Finishing: Execute Cake Script

Troubleshooting

Checkout how to troubleshoot failures and collect debug logs: https://docs.microsoft.com/en-us/vsts/build-release/actions/troubleshooting

Error logs

[Insert error from the logs here for a quick overview]

@VictorioBerra VictorioBerra changed the title dotnet tool restore --interactive fails to restore tools from Artifacts unless I target Core 3.1.300 dotnet tool restore --interactive fails to restore tools from Artifacts unless I UseDotNet@2 Core 3.1.300 via global.json Jun 3, 2020
@apluche
Copy link

apluche commented Jun 3, 2020

Hi @VictorioBerra ,

It seems the credential provider is failing. Could you please use the NuGet installer task to ensure that you are on the latest version of nuget? And also make sure to have the latest DotNet version.

Additionally, could you try to follow the advice from this comment?

@VictorioBerra
Copy link
Author

@apluche Thanks for the super fast reply.

I have tried with the NuGetToolInstaller task:

Using version: 5.6.0
Found tool in cache: NuGet 5.6.0 x64
Using tool path: C:\hostedtoolcache\windows\NuGet\5.6.0\x64

Looks like it pulled the latest, but same issue. The dotnet tool restore fails.

I then modified my tool install task to this:

- task: CmdLine@2
  displayName: 'Execute Cake Script'
  inputs:
    script: |
      nuget locals http-cache -clear
      setx NUGET_PLUGIN_HANDSHAKE_TIMEOUT_IN_SECONDS=20
      setx NUGET_PLUGIN_REQUEST_TIMEOUT_IN_SECONDS=20
      dotnet tool restore --interactive
      dotnet cake

For reference, -c was invalid, I needed the full -clear. Same result, the dotnet tool restore fails:

2020-06-03T21:34:58.2973776Z ##[section]Starting: Execute Cake Script
2020-06-03T21:34:58.3119390Z ==============================================================================
2020-06-03T21:34:58.3119849Z Task         : Command line
2020-06-03T21:34:58.3120153Z Description  : Run a command line script using Bash on Linux and macOS and cmd.exe on Windows
2020-06-03T21:34:58.3120450Z Version      : 2.164.2
2020-06-03T21:34:58.3120661Z Author       : Microsoft Corporation
2020-06-03T21:34:58.3120972Z Help         : https://docs.microsoft.com/azure/devops/pipelines/tasks/utility/command-line
2020-06-03T21:34:58.3121338Z ==============================================================================
2020-06-03T21:34:59.3721216Z Generating script.
2020-06-03T21:34:59.4053403Z ========================== Starting Command Output ===========================
2020-06-03T21:34:59.4483733Z ##[command]"C:\windows\system32\cmd.exe" /D /E:ON /V:OFF /S /C "CALL "d:\a\_temp\d1f05d95-c1fc-4777-9d8a-3897f125c59e.cmd""
2020-06-03T21:35:01.8310765Z Clearing NuGet HTTP cache: C:\Users\VssAdministrator\AppData\Local\NuGet\v3-cache
2020-06-03T21:35:01.8329881Z Local resources cleared.
2020-06-03T21:35:01.9051180Z 
2020-06-03T21:35:01.9051745Z SUCCESS: Specified value was saved.
2020-06-03T21:35:01.9281158Z 
2020-06-03T21:35:01.9281622Z SUCCESS: Specified value was saved.
2020-06-03T21:35:10.4379235Z 
2020-06-03T21:35:10.5629552Z Welcome to .NET Core 3.1!
2020-06-03T21:35:10.5629867Z ---------------------
2020-06-03T21:35:10.5630122Z SDK Version: 3.1.202
2020-06-03T21:35:10.5630266Z 
2020-06-03T21:35:10.5632313Z Telemetry
2020-06-03T21:35:10.5632590Z ---------
2020-06-03T21:35:10.5633379Z 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.
2020-06-03T21:35:10.5634038Z 
2020-06-03T21:35:10.5634427Z Read more about .NET Core CLI Tools telemetry: https://aka.ms/dotnet-cli-telemetry
2020-06-03T21:35:10.5634772Z 
2020-06-03T21:35:10.5635026Z ----------------
2020-06-03T21:35:10.5635483Z Explore documentation: https://aka.ms/dotnet-docs
2020-06-03T21:35:10.5635888Z Report issues and find source on GitHub: https://github.com/dotnet/core
2020-06-03T21:35:10.5636687Z Find out what's new: https://aka.ms/dotnet-whats-new
2020-06-03T21:35:10.5637180Z Learn about the installed HTTPS developer cert: https://aka.ms/aspnet-core-https
2020-06-03T21:35:10.5638019Z Use 'dotnet --help' to see available commands or visit: https://aka.ms/dotnet-cli-docs
2020-06-03T21:35:10.5638459Z Write your first app: https://aka.ms/first-net-core-app
2020-06-03T21:35:10.5638767Z --------------------------------------------------------------------------------------
2020-06-03T21:35:31.8483578Z C:\Program Files\dotnet\sdk\3.1.202\NuGet.targets(124,5): error : Problem starting the plugin 'C:\Users\VssAdministrator\.nuget\plugins\netcore\CredentialProvider.Microsoft\CredentialProvider.Microsoft.dll'. Plugin 'CredentialProvider.Microsoft' failed within 6.490 seconds with exit code -1. [C:\Users\VssAdministrator\AppData\Local\Temp\ttsmf4m0.p3q\restore.csproj]
2020-06-03T21:35:32.3074269Z C:\Program Files\dotnet\sdk\3.1.202\NuGet.targets(124,5): error : Unable to load the service index for source https://pkgs.dev.azure.com/SIEE/IAMM/_packaging/IAMM/nuget/v3/index.json. [C:\Users\VssAdministrator\AppData\Local\Temp\ttsmf4m0.p3q\restore.csproj]
2020-06-03T21:35:32.3076095Z C:\Program Files\dotnet\sdk\3.1.202\NuGet.targets(124,5): error :   Response status code does not indicate success: 401 (Unauthorized). [C:\Users\VssAdministrator\AppData\Local\Temp\ttsmf4m0.p3q\restore.csproj]
2020-06-03T21:35:32.4440596Z 
2020-06-03T21:35:32.4462458Z Package "cake.tool" failed to restore, due to Microsoft.DotNet.ToolPackage.ToolPackageException: The tool package could not be restored.
2020-06-03T21:35:32.4463389Z    at Microsoft.DotNet.Tools.Tool.Install.ProjectRestorer.Restore(FilePath project, PackageLocation packageLocation, String verbosity)
2020-06-03T21:35:32.4466421Z    at Microsoft.DotNet.ToolPackage.ToolPackageInstaller.InstallPackageToExternalManagedLocation(PackageLocation packageLocation, PackageId packageId, VersionRange versionRange, String targetFramework, String verbosity)
2020-06-03T21:35:32.4467172Z    at Microsoft.DotNet.Tools.Tool.Restore.ToolRestoreCommand.InstallPackages(ToolManifestPackage package, Nullable`1 configFile)
2020-06-03T21:35:32.4467559Z 
2020-06-03T21:35:32.4467820Z Restore failed.
2020-06-03T21:35:32.6427401Z Run "dotnet tool restore" to make the "dotnet-cake" command available.
2020-06-03T21:35:32.7564893Z ##[error]Cmd.exe exited with code '1'.
2020-06-03T21:35:32.7963526Z ##[section]Finishing: Execute Cake Script

@apluche
Copy link

apluche commented Jun 3, 2020

@VictorioBerra ,

You'll need to set the variables as environment variables in your pipeline rather than in your script. The issue I can see here is that the credentialprovider is failing to start.

Please let me know if that helps, if not, I'll keep digging

@VictorioBerra
Copy link
Author

@apluche Success.

image

image

YAML

steps:

- task: NuGetToolInstaller@1

- task: NuGetAuthenticate@0

- task: CmdLine@2
  displayName: 'Execute Cake Script'
  inputs:
    script: |
      nuget locals http-cache -clear
      dotnet tool restore --interactive
      dotnet cake

Would you change anything else in the above pipeline?

@apluche
Copy link

apluche commented Jun 3, 2020

@VictorioBerra ,

I'm glad to hear that you are unblocked.

You may no longer need the NuGetToolInstaller so you can probably remove it from the pipeline. I'm not 100% familiar with dotnet, however, so the pipeline may still need the tool installer. It's worth testing if you can remove it. There isn't anything else that I see in your pipeline.

On another note, the script will always clear the cache before starting the restore. In operations where you restore large amounts of packages, this may slow you down. If having that cache clear doesn't impact your pipeline significantly, it is worth leaving in there.

@VictorioBerra
Copy link
Author

Thanks I have done the following:

image

And the pipeline is still successful. So it looks to me like the environment variables you posted are the real fix. I was curious about the NuGetToolInstall command because I did not think dotnet tool restore used NuGet.exe under the hood.

@apluche
Copy link

apluche commented Jun 3, 2020

Sometimes dotnet goes to nuget under the hood (I think nuget is shipped with dotnet) so I just wanted to cover all of the possibilities. Glad to hear you were able to delete those lines without having the pipeline fail.

If you need any other help, please let me know or create a new issue. If you do end up seeing another CredentialProvider.Microsoft\CredentialProvider.Microsoft issue, you can create an issue here: https://github.com/Microsoft/artifacts-credprovider/issues

@esond
Copy link

esond commented Jul 6, 2021

For all those that come after me:

I will be posting this response on a few issues that I frequented when troubleshooting a similar issue. This is not strictly related to this particular issue but someone may find it useful in the end.

In my case, we were having issues with intermittent packages not being restored from a nuget feed with a networking error, for example:

  Failed to download package 'System.Data.OleDb.4.7.0' from 'https://pkgs.dev.azure.com/acme/af808fc2-ae7d-42da-887a-ea7a78a65e52/_packaging/7648731a-3d0b-4888-816b-d229e1e80fd4/nuget/v3/flat2/system.data.oledb/4.7.0/system.data.oledb.4.7.0.nupkg'.
  The SSL connection could not be established, see inner exception.
    Unable to read data from the transport connection: An existing connection was forcibly closed by the remote host..
    An existing connection was forcibly closed by the remote host.

Multiple packages would fail, and the packages that failed would be different every time. We would also periodically see a dotnet tool restore command simply hang and never complete.

We eventually figured out that these issues only seemed to be occurring when multiple builds were happening in parallel on Azure DevOps. This led me to believe that perhaps there was some kind of rate-limiting happening against the Azure Artifacts server, because the solution in question had ~70 projects to be restored, thus making a lot of network calls.

I enabled caching of nuget packages to alleviate this, which seemed to solve the problem. Below is a template YAML that I have added for all build tasks in our pipeline, and this seems to work for us.

steps:
  - task: NuGetAuthenticate@0
    displayName: "Authenticate with NuGet"
    inputs:
      forceReinstallCredentialProvider: true

  - task: UseDotNet@2
    displayName: Install .NET Core
    inputs:
      useGlobalJson: true

  - task: Cache@2
    displayName: Cache NuGet packages
    inputs:
      key: "nuget | $(Agent.OS) | **/global.json, **/*.csproj"
      restoreKeys: "nuget | $(Agent.OS)"
      path: $(NUGET_PACKAGES)

Usage example:

jobs:
  - job: Compile
    displayName: "⚙ Compile"
    dependsOn: []
    steps:
      - template: setup-build-task.azure-pipelines.yml

      - task: CmdLine@2
        displayName: Restore, lint, and build
        inputs:
          script: "./build.cmd RestoreTools Restore Lint Compile --skip"

Godspeed. I had a hell of a few days with this one.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

No branches or pull requests

4 participants