[dev] cli tests are really slow


(Brian Olore) #1

npm run test (on a 2012 MacBook Air) takes 20 minutes. Is this normal? It looks like it takes 10+ min on travis.

I am wondering if anyone has looked into speeding this up and if they had any suggestions on where to start poking. I am interested in making this faster.

<snip>
total ........................................... 4787/4796

  4787 passing (23m)
  9 pending

real    22m40.378s
user    17m20.408s
sys     2m34.679s
$ npm --versions
{ npm: '6.1.0',
  ares: '1.14.0',
  cldr: '33.0',
  http_parser: '2.8.0',
  icu: '61.1',
  modules: '64',
  napi: '3',
  nghttp2: '1.29.0',
  node: '10.1.0',
  openssl: '1.1.0h',
  tz: '2018c',
  unicode: '10.0',
  uv: '1.20.2',
  v8: '6.6.346.27-node.6',
  zlib: '1.2.11' }

$ node -p process.platform
darwin

(Brian Olore) #2

I’m wondering if related to how the test output is written and rimraf’d. Maybe we are disk-bound here? My machine has SSD, maybe its worse on a spinning disk?

Also not sure what use the tmpdir() is… seems like most tests aren’t using it. For example, intest/need-npm5-update/need-only-update-save-optional/update-save.js

var pkg = path.resolve(__dirname, 'update-save')
...
...
function cleanup () {
  process.chdir(osenv.tmpdir())
  rimraf.sync(pkg)
}

I don’t think the chdir does anything. Many tests are written like this. Seems like either a partially implemented idea, or a vestige.

The rimraf in this case is deleting the output directory which gets created in the same dir as the test file (which seems like a mistake IMO). My guess is the intention was for it to go to the tmpdir.

I am still learning about tap, but if anyone has pointers on how to possibly make this better/faster, I’m all ears.


(Brian Olore) #3

Some more debugging -

Time seems to be mostly spent in lines like this

  common.npm(['install', '--save', 'file://' + installme], EXEC_OPTS, function (er, code, stdout, stderr) {

And not in rimraf or others. So that’s good… I think.

It bugs me that this command alone takes 17s to run: npm run tap -- test/tap/shrinkwrap-save-with-existing-dev-deps.js


(Kat Marchán) #4

We’re very aware of how long the test suite tends to run, and there’s a lot of reasons for this. I don’t believe the filesystem access or even the sync operations by themselves are the reason for the bulk of the slowdown.

The biggest ones as far as I’m concerned are:

  1. It’s mostly an integration test suite with relatively few unit tests, so most tests run an entire npm subprocess, usually one per assertion. Even when we don’t run a subprocess, npm.load() is actually a super heavy operation.
  2. The test suite is very old and sometimes hard to refactor. The tests themselves are important, but the test suite is so big, it would be a hugely time-consuming task.
  3. The test suite is hard to parallelize because so many tests were written with linear execution in mind.

There’s a lot of thoughts @iarna and I have floated around about how to fix this, but it hasn’t been on our radar. We mostly just settled on waiting patiently for Travis, specially since we do biweekly releases, so the wait isn’t usually very painful unless something breaks while putting a release together on release day.

If you’re interested in putting the effort into refactoring chunks of the test suite, that would be wonderful, but be warned it would probably be a lot of effort to go through, and there’s only so much you could do until we’ve added unit-testable APIs for things. It’s likely something you won’t really be able to do right now, tbh.

There’s a couple of things we’ve been talking about doing that should make this easier, though:

  1. Yanking out the tree builder into a standalone thing that’s easier to run and test against. You can already kind of do this, but I find it trickier to test.
  2. Yanking out the npm config stuff so it can work by itself. This one’s really obnoxious and we’ve been chipping at it recently. I’m still laying some of the groundwork for this with recent stuff.

(Brian Olore) #5

Thanks @zkat. I appreciate you taking the time to layout some of the problems and thoughts you’ve had. I’m going to keep poking at it.


(Rebecca Turner) #6

The test suite used to take close to twice as long before our last go round on it, but as @zkat at says, there’s still a lot of work to be done. (Back then, Travis would take approaching two hours to give us a green, with fewer Node.js versions being tested. It was awful.)

There are a few concrete things you can do right now to move things forward:

make things more parallel

Make a new folder that holds tests known to be safe to run in parallel. Make the test lifecycles run it with tap -J (which tells tap to use all available cores). Start moving tests there. The first candidates for this are the unit-* tests, which should already be 100% safe to do this with.

I started this ages ago in the iarna/concurrent-tests branch but it’s incomplete and… I’m not sure of its current status. I’d be happy if you wanted to take that branch over. :grin:

Things that result in this not being parallel-safe:

  1. Tests which rely on the 00-config-setup.js being run first. (To ensure a test does not rely on this, run zz-cleanup.js followed by the test. If it works, it doesn’t rely on it.)
  2. Tests that use the same temporary directories. I think we’ve got all of these, but there might be one or two lingering.
  3. Tests that listen on the same ports as one another. This is common for npm-registry-mock tests. The solution to these is to port them to use fake-registry (documented here, example of use here). The biggest blocker to its use as a drop-in replacement for npm-registry-mock is that it doesn’t provide the built in fixtures that npm-registry-mock does. If you decide to look at this latter bit, please talk to me first, as there are some twisty details.
  4. Tests that otherwise listen on fixed ports. There are a few and they probably can all be ported to fake-registry.

reduce disk i/o

I’ve been meaning to add a layer on top of tacks that provides a mock for fs that reads directly from the tacks data structure. This would save us from having to write our test fixtures out to disk. Tacks is our library that manages fixture folders it provides functions to turn data structures into directories of files, and it provides a tool for turning a directory on disk into JS uses that library. That’s the basis of the script to generate our test scaffolding: maketest.


(Brian Olore) #7

Thanks @iarna! This is great info.

Using iarna/concurrent-tests -

Running only unit & integration tests:

"test-tap": "npm run tap -- \"test/unit/*.js\" \"test/integration/*.js\"",

Without -J

"tap": "tap --reporter=classic --timeout 300",
  2916 passing (5m)
  12 failing

real	5m29.566s
user	4m56.782s
sys	0m48.321s

With -J (parallel)

"tap": "tap --reporter=classic --timeout 300 -J",
  2916 passing (3m)
  12 failing

real	2m49.163s
user	7m4.773s
sys	1m3.270s

Wow! This is definitely something to build on. It’s almost 50% faster (on my 4cpu machine). Again this is not the bulk of the tests, but it’s a start.

The failing tests were mostly expecting Numbers but getting Strings. I’ll check and see whats up with those. I merged in latest, without conflict, but maybe something went wrong.

Side note: I had to run this with VSCode closed as it was trying to track the tmp directories that were created and destroyed in test/ during the run and eating lots of CPU


(Rebecca Turner) #8

You didn’t say how you did this, so fyi: We don’t use merge commits, instead we would rebase the branch on latest or release-next. (I’ve just rebased iarna/concurrent-tests on release-next and pushed it up.)

Probably things are failing due to the changes made in my commits, it is all very WIP and I haven’t looked at it in a while… let’s see, last commit was… :astonished:2017-01-18, ok a VERY long time.


(system) #9

This topic was automatically closed 3 days after the last reply. New replies are no longer allowed.


(Rebecca Turner) #10