[BUG] serious `npm ci` performance regression in 7.21.0 #3676

KTamas · 2021-08-23T07:03:30Z

Is there an existing issue for this?

I have searched the existing issues

Current Behavior

time npm ci --no-audit --prefer-offline

npm@7.20.6:

added 3593 packages in 24s

________________________________________________________
Executed in   24.62 secs    fish           external
   usr time   26.91 secs  238.00 micros   26.91 secs
   sys time   23.69 secs  871.00 micros   23.69 secs

npm@7.21.0:

added 3593 packages in 37s

________________________________________________________
Executed in   37.41 secs    fish           external
   usr time   39.74 secs  264.00 micros   39.74 secs
   sys time   24.86 secs  933.00 micros   24.86 secs

i did an rm -rf node_modules && rm -rf workspaces/test/node_modules by hand each time and the cache is completely warm.

i tested this on my laptop (2019 16" MBP, Core i9, 64 GB RAM, internal SSD) but i see this slowdown in our CI as well (GitLab CI, custom GitLab runners on AWS, c5d.xlarge instances using docker machine)

Expected Behavior

npm@7.21.0 not be 50% slower

Steps To Reproduce

clone https://github.com/KTamas/npm7210-perf-regression
run npm ci --no-audit --prefer-offline (twice so the cache is warm)

Environment

OS: MacOS 11.5.2
Node: 16.7.0
npm: 7.20.6 and 7.21.0

The text was updated successfully, but these errors were encountered:

This doesn't change any functionality, but it optimizes a few extremely hot code paths for the input typically encountered during a large npm project installation. `String.normalize()` is cached, and trailing-slash removal is done with a single `String.slice()`, rather than multiple slices and `String.length` comparisons. It is extremely rare that any code path is ever hot enough for this kind of thing to be relevant enough to justify this sort of microoptimization, but these two issues resulted in a 40-50% install time increase in some cases, which is fairly dramatic. Fix: npm/cli#3676

This doesn't change any functionality, but it optimizes a few extremely hot code paths for the input typically encountered during a large npm project installation. `String.normalize()` is cached, and trailing-slash removal is done with a single `String.slice()`, rather than multiple slices and `String.length` comparisons. It is extremely rare that any code path is ever hot enough for this kind of thing to be relevant enough to justify this sort of microoptimization, but these two issues resulted in a 25-50% install time increase in some cases, which is fairly dramatic. Fix: npm/cli#3676

isaacs · 2021-08-26T16:18:06Z

Thanks for the clear reproduction case! Was able to track this down to two very hot code paths in node-tar that were doing more work than needed. Should be much improved in the next release.

KTamas · 2021-08-26T21:56:15Z

thanks!

KTamas · 2021-08-27T06:40:38Z

@isaacs this is quite an improvement but unfortunately still not quite the same level of performance as npm@7.20.6

re-ran the tests on node@16.8.0

npm@7.20.6


________________________________________________________
Executed in   27.28 secs    fish           external
   usr time   29.39 secs  261.00 micros   29.39 secs
   sys time   25.84 secs  872.00 micros   25.84 secs

npm@7.21.1


________________________________________________________
Executed in   31.78 secs    fish           external
   usr time   33.49 secs  228.00 micros   33.49 secs
   sys time   25.63 secs  887.00 micros   25.62 secs

i ran them several times so this is not within the margin of error.

edit: node@16.7.0 results are closer

npm@7.20.6


________________________________________________________
Executed in   28.43 secs    fish           external
   usr time   29.01 secs  186.00 micros   29.01 secs
   sys time   25.27 secs  797.00 micros   25.27 secs

npm@7.21.1


________________________________________________________
Executed in   30.15 secs    fish           external
   usr time   32.64 secs    0.40 millis   32.64 secs
   sys time   24.63 secs    1.25 millis   24.63 secs

don't mean to be splitting hairs here. but maybe there might still be some room for improvement?

totally understand if this is not a priority at this point though.

eljenso · 2021-09-27T18:46:47Z

I have come across a similar problem with a single package: material-design-icons

Here you'll find a repo for reproduction: https://github.com/eljenso/install-perf_material-design-icons
Those are my results for running npm ci with different versions of npm under node@14.17.6:

npm@7.20.6

$ time npm ci

added 1 package, and audited 2 packages in 3m

found 0 vulnerabilities
npm ci  159.45s user 27.88s system 123% cpu 2:31.24 total

npm@7.21.0

$ time npm ci

added 1 package, and audited 2 packages in 10m

found 0 vulnerabilities
npm ci  646.46s user 34.43s system 108% cpu 10:29.35 total

npm@7.24.1

$ time npm ci

added 1 package, and audited 2 packages in 4m

found 0 vulnerabilities
npm ci  234.08s user 30.42s system 117% cpu 3:44.50 total

But the most interesting results are when using different versions of npm@6.

npm@6.14.14

$ time npm ci
npm WARN prepare removing existing node_modules/ before installation
added 1 packages in 53.523s
npm ci  54.36s user 32.50s system 161% cpu 53.809 total

npm@6.14.15

$ time npm ci
npm WARN prepare removing existing node_modules/ before installation
added 1 packages in 649.631s
npm ci  671.23s user 38.71s system 109% cpu 10:49.97 total

In other words: upgrading to the latest version of npm@6 increased the time for npm ci tenfold.
As we are using still using npm@6, it would be great if the performance under npm@6 could be improved as well.

eljenso · 2021-10-13T10:08:11Z

@isaacs regarding my previous comment:
Is this performance regression issue something that can also be fixed for npm@6?

isaacs · 2021-10-18T23:10:27Z

As far as I can tell, the regression here is entirely due to making the tar extraction caching behavior sensitive to the fact that unicode-insensitive file systems exist. We're now doing a NFKD normalization on all filenames that are extracted, to avoid situations where files can clobber each other based on being different JavaScript string filenames that reference the same file due to unicode shenanigans. (See https://github.com/npm/node-tar/security/advisories?state=published)

So, even thought the impact is minimal in most cases, if you have a single package that extracts close to 90 thousand files, it adds up.

The good news is that the performance improvements in the versions since that change have bought back a lot of the perf regression from the security fix, but unfortunately not all of it. So this isn't a case where we caused a perf regression with a bug, then fixed the bug. It's that we fixed a class of security bugs, and in so doing caused an unavoidable (or at least, not easily avoidable) perf regression, and then fixed other bugs that were causing other unrelated performance issues. (Those were mostly regarding how we cache HTTP requests, and avoiding unnecessary HTTP cache revalidations.)

I'll think on this some more and see if we can work out a way to still make the same unicode-safe filesystem guarantees, with less of a performance hit. If that's not possible, then the choice may just be between "don't have 89k files in a single package", or "be vulnerable to unicode filename attacks in published packages".

KTamas · 2021-10-19T10:36:08Z

@isaacs thank you for the thoughtful and detailed reply, I really appreciate it!

isaacs · 2021-10-19T15:56:43Z

Oh, also, looks like we did optimize away at least some of the perf regression that the tar security fixes initially introduced, so my last comment was only mostly correct 😅 #3676 (comment)

@isaacs

This doesn't change any functionality, but it optimizes a few extremely hot code paths for the input typically encountered during a large npm project installation. `String.normalize()` is cached, and trailing-slash removal is done with a single `String.slice()`, rather than multiple slices and `String.length` comparisons. It is extremely rare that any code path is ever hot enough for this kind of thing to be relevant enough to justify this sort of microoptimization, but these two issues resulted in a 25-50% install time increase in some cases, which is fairly dramatic. Fix: npm/cli#3676 PR-URL: #286 Credit: @isaacs Close: #286 Reviewed-by: @wraithgar

@isaacs

This doesn't change any functionality, but it optimizes a few extremely hot code paths for the input typically encountered during a large npm project installation. `String.normalize()` is cached, and trailing-slash removal is done with a single `String.slice()`, rather than multiple slices and `String.length` comparisons. It is extremely rare that any code path is ever hot enough for this kind of thing to be relevant enough to justify this sort of microoptimization, but these two issues resulted in a 25-50% install time increase in some cases, which is fairly dramatic. Fix: npm/cli#3676 PR-URL: #286 Credit: @isaacs Close: #286 Reviewed-by: @wraithgar

KTamas added Bug thing that needs fixing Needs Triage needs review for next steps Release 7.x work is associated with a specific npm 7 release labels Aug 23, 2021

KTamas changed the title ~~[BUG] npm ci performance regression in v7.21.0~~ [BUG] serious npm ci performance regression in 7.21.0 Aug 23, 2021

isaacs mentioned this issue Aug 25, 2021

fix: perf regression on hot string munging path isaacs/node-tar#286

Merged

isaacs closed this as completed in isaacs/node-tar@edb8e9a Aug 26, 2021

qubyte mentioned this issue Sep 6, 2021

Caches dependencies to speed up CI runs. qubyte/qubyte-codes#386

Closed

lukekarrys mentioned this issue Nov 2, 2021

NPM Restore 15 times slower on versions > 6.14.13 #3939

Closed

1 task

theseion mentioned this issue Nov 17, 2021

[BUG] Tar is very slow on npm 6.14.15 isaacs/node-tar#293

Closed

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

[BUG] serious `npm ci` performance regression in 7.21.0 #3676

[BUG] serious `npm ci` performance regression in 7.21.0 #3676

KTamas commented Aug 23, 2021 •

edited

Loading

isaacs commented Aug 26, 2021

KTamas commented Aug 26, 2021

KTamas commented Aug 27, 2021 •

edited

Loading

eljenso commented Sep 27, 2021

eljenso commented Oct 13, 2021

isaacs commented Oct 18, 2021

KTamas commented Oct 19, 2021

isaacs commented Oct 19, 2021

[BUG] serious npm ci performance regression in 7.21.0 #3676

[BUG] serious npm ci performance regression in 7.21.0 #3676

Comments

KTamas commented Aug 23, 2021 • edited Loading

Is there an existing issue for this?

Current Behavior

Expected Behavior

Steps To Reproduce

Environment

isaacs commented Aug 26, 2021

KTamas commented Aug 26, 2021

KTamas commented Aug 27, 2021 • edited Loading

eljenso commented Sep 27, 2021

eljenso commented Oct 13, 2021

isaacs commented Oct 18, 2021

KTamas commented Oct 19, 2021

isaacs commented Oct 19, 2021

[BUG] serious `npm ci` performance regression in 7.21.0 #3676

[BUG] serious `npm ci` performance regression in 7.21.0 #3676

KTamas commented Aug 23, 2021 •

edited

Loading

KTamas commented Aug 27, 2021 •

edited

Loading