NuGet / Home

Repo for NuGet Client issues
Other
1.5k stars 252 forks source link

[Bug]: Slow Restores on Windows in GitHub Actions - Signature verification taking a long time #11548

Open NickCraver opened 2 years ago

NickCraver commented 2 years ago

NuGet Product Used

dotnet.exe

Product Version

6.0.101

Repro Steps & Context

Running an identical restore in GitHub Actions, times are dramatically higher on Windows agents (2019 and 2022 tested) vs. Ubuntu agents. Here's an example run of a 5m 39s restore on Windows vs a 16s restore on Ubuntu. It's only restoring a hand full of packages.

Here's an example PR testing various bits of this so you can see raw logs.

Important: setting NUGET_CERT_REVOCATION_MODE to offline indeed improves restore times substantially (down to 1m 22s in this case).

The verbose logs can be seen in this build. Also attaching here: Verbose Windows Logs.txt. Scroll to 2022-02-02T00:28:54.6709200Z for where the biggest time expenditure starts happening around package verification.

Side note: I lost the body of this issue trying to paste then directly previously (they're ~12.7MB for the restore, and the GitHub form limit is 65,536 - I recommend we don't advise people pasting logs here).

nkolev92 commented 2 years ago

Thanks for the details @NickCraver!

I've tweaked the title to include the verification part, to make this issue more discoverable for relevant keyword searches

nkolev92 commented 2 years ago

This is detectable even by the basic perf scripts https://github.com/NuGet/NuGet.Client/tree/dev/scripts/perftests on my local machine. OrchardCore-git.csv

Average drops from 29s -> 27s for the full restore, about 7% improvement.

Linux vs windows probably an unfair comparison for now, but the revocation change seem to have a huge impact on windows.

zivkan commented 2 years ago

From Team Triage Meeting: certificate revocation checks are a security feature to ensure that a compromised certificate was not used to impersonate a trusted entity. Package signature verification has been disabled on Linux and Mac, which explains some of the perf differences. Given the design of signed packages and X509 certificates, we don't see what actionable work we can do.

NickCraver commented 2 years ago

@zivkan This feature takes a restore from 1 minute 22 seconds to 5+ minutes and that's not a concern at all? Forget the fact it costs me literal dollars in build minutes and that really adds up at scale, it's a security issue because it's so bad my only performant option is to disable it.

There needs to be performance work invested here, or many people are going to do the same.

aortiz-msft commented 2 years ago

Reopening for feedback (upvotes) from the community.

AraHaan commented 2 years ago

I agree, when it comes to me on github actions (even though I get free minutes for open source) I expect my code to not take over 5 minutes to restore and then wait even longer for the possible chance a code change of mine might not compile. In that case I want to know the failure ASAP so it can be corrected. When it comes to CI's I could care less about security and more about things wasting my time and giving less time for me to work on more important things.

This is why I default my actions to ubuntu unless my code utilizes Windows Desktop stuff where I am forced to have wasted time.

loic-sharma commented 2 years ago

FYI for client team, @bartonjs suggested investigating this by enabling Windows' chain-building telemetry.

joelverhagen commented 2 years ago

I thought I had run into this on my project https://github.com/joelverhagen/MiniZip, but this environment variable NUGET_CERT_REVOCATION_MODE=offline does not seem to have a significant impact on Windows performance from my tests.

image

That being said, Windows restore does appear to be significantly slower for some reason. I tried to use the setting in @NickCraver's original post but maybe I messed something up: https://github.com/joelverhagen/MiniZip/blob/338a917f132603803ccd6a90101a774ca21f40b8/.github/workflows/build.yml#L15.

I made a gist for the program that collects these timings, in case it is helpful to others. https://gist.github.com/joelverhagen/dd9123a15716863bcfed21b2b30cb8d1