Jest: Taking 10 seconds on an empty repo,

[laggingreflex]

I'm new to jest and I heard about it being slow so I was expecting it. But the main project I integrated Jest in was actually taking upwards of 2 mins! I might be doing something wrong, but even on this empty test repo it's taking 10+ seconds: https://github.com/laggingreflex/jest-test

Do you want to request a _feature_ or report a _bug_?

Bug/question?

What is the current behavior?

Jest is taking upwards of 12 seconds on an empty repo - it only has 2 empty test files (empty describe and it with nothing in them), and no actual code or dependencies (other than jest).

If the current behavior is a bug, please provide the steps to reproduce and if possible a minimal repository on GitHub that we can npm install and npm test.

https://github.com/laggingreflex/jest-test

What is the expected behavior?

it should be faster...

Run Jest again with --debug and provide the full configuration it prints. Please mention your node and npm version and operating system.

{
  "testRegex": "(/tests/.*|/src/.*\\.test)\\.js",
  "rootDir": "C:\\Test\\jest-test",
  "name": "C:-Test-jest-test",
  "setupFiles": [],
  "testRunner": "C:\\Test\\jest-test\\node_modules\\jest-jasmine2\\build\\index.js",
  "scriptPreprocessor": "C:\\Test\\jest-test\\node_modules\\babel-jest\\build\\index.js",
  "usesBabelJest": true,
  "automock": false,
  "bail": false,
  "browser": false,
  "cacheDirectory": "C:\\Users\\x\\AppData\\Local\\Temp\\jest",
  "clearMocks": false,
  "coveragePathIgnorePatterns": [
    "\\\\node_modules\\\\"
  ],
  "coverageReporters": [
    "json",
    "text",
    "lcov",
    "clover"
  ],
  "globals": {},
  "haste": {
    "providesModuleNodeModules": []
  },
  "mocksPattern": "__mocks__",
  "moduleDirectories": [
    "node_modules"
  ],
  "moduleFileExtensions": [
    "js",
    "json",
    "jsx",
    "node"
  ],
  "moduleNameMapper": {},
  "modulePathIgnorePatterns": [],
  "noStackTrace": false,
  "notify": false,
  "preset": null,
  "preprocessorIgnorePatterns": [
    "\\\\node_modules\\\\"
  ],
  "resetModules": false,
  "testEnvironment": "jest-environment-jsdom",
  "testPathDirs": [
    "C:\\Test\\jest-test"
  ],
  "testPathIgnorePatterns": [
    "\\\\node_modules\\\\"
  ],
  "testURL": "about:blank",
  "timers": "real",
  "useStderr": false,
  "verbose": null,
  "watch": false,
  "cache": true,
  "watchman": true,
  "testcheckOptions": {
    "times": 100,
    "maxSize": 200
}

node -v
v6.9.0
npm -v
3.10.8
ver
Microsoft Windows [Version 10.0.14946]

[cpojer]

Is it possible your anti-virus software is invoked on every file system access within your project? Can you try whitelisting this folder and re-running Jest? This is a common problem on Windows.

[laggingreflex]

I disabled anti-virus completely, also disabled firewall and search indexing just to be sure and rebooted but still no improvement.

I tried a couple different options, Docker, Windows Ubuntu bash, and it does perform better in those (in some cases) down to 6 secs on this test project and on my original project from 2mins to 20 secs. But those systems seem to have problems of their own making them not ideal for development.

So this is definitely a Windows issue, but not related to anti-virus. Please let me know if and how I can help debug this further. I would really love to use Jest but natively on Windows!

[laggingreflex]

Comparison on other systems I tried and their shortcomings:

| OS/System | Time |
| --- | --- |
| Windows (native) | 12s |
| Docker with Node image and mounted volume (docker -v"%CD%:/test") | 10s |
| Docker with Node image and copying the contents (COPY . .) | 6s |
| Windows Ubuntu Bash (under /mnt/c) | 20s |
| Windows Ubuntu Bash (VolFs /home/) | 6s |

Windows Ubuntu Bash works best but only with VolFs which isn't ideal for development because files in that system don't work well with native Windows tools (editing outside of bash breaks them).

Docker works well but only when you copy the contents to the image, which won't work for active development. Unfortunately mounted volumes has it's own issues with Docker (on Windows at least) which causes it to be still slow. This is particularly visible on a bigger project.

Windows Ubuntu Bash with mounted filesystem (DriveFS /mnt/c/...), which is the ideal file system for active development, it's actually worse, taking 20 secs!

I saw improvement on my original project which was taking 2+ mins which has come down to ~20 secs with Docker and Windows Ubuntu Bash with native VolFs, but neither of those options seem ideal.

[cpojer]

On Windows we cannot use either watchman or the find binary so we fall back to using node.js to crawl the repo: https://github.com/facebook/jest/blob/master/packages/jest-haste-map/src/crawlers/node.js#L23 – if you can send a PR to make any of this faster, that would be awesome!

We have to do this on every startup of Jest, unfortunately, to do static analysis (like for the watch mode or for jest -o etc.).

[laggingreflex]

I found that it monitors .git folder by default. And it seems this happens on every file change too:

(putting console.log(directory) here))

Specifying "testPathDirs" resolves this, but it should ignore .git by default.

Although as you see, this by itself was still pretty quick. The delay almost certainly seems to be on the "RUNS". Could you please also point to the file where "RUNS" happen in the code. Thanks

[cpojer]

When Jest prints "RUNS" it means it is already running the code inside your tests. Maybe you can add some instrumentation (console.time(), console.timeEnd()) there?

[laggingreflex]

So I did

console.time('startSync');
console.time('startASync');
describe('simple', () => {
  it('test', () => {
    console.timeEnd('startASync');
  });
});
console.timeEnd('startSync');

 PASS  tests\test.js
  simple
    √ test (9ms)

Test Suites: 1 passed, 1 total
Tests:       1 passed, 1 total
Snapshots:   0 total
Time:        11.381s
Ran all test suites related to changed files.

Watch Usage
 › Press a to run all tests.
 › Press o to only run tests related to changed files.
 › Press p to filter by a filename regex pattern.
 › Press q to quit watch mode.
 › Press Enter to trigger a test run.
  console.log console.js:77
    startSync: 7.539ms

  console.log console.js:77
    startASync: 32.101ms

As seen, the time it takes to run, as reported by console.time (7-30ms) _and_ by Jest itself (√ test (9ms)), was expectedly within under a second.

But the RUNS still displays for 11 secs before it shows PASS. I found that here is where it prints RUNS. Now since console.log has an issue* so I just changed it to display Date.now. And did the same with PASS (which was here), and the difference was the same that it showed in Time: 11.381s

It's definitely doing something other than just running the test files between the time it displays RUNS and PASS

And since *console logs are globbed up by Jest and only shown at the end (bw any way to turn this off temporarily?) I can't tell whether it starts running the file as soon as it displays "RUNS" or after 11 secs, mainly in the last few seconds. I'm betting on the latter.

PS: Also notice the timers startASync = 32ms and startSync = 7.5ms, and the √ test (9ms), shouldn't it reflect the startASync time (the time it takes to get to the end an it)?

BTW, how much, according to you, should be the time taken ideally for this simple test? 1 sec? 5-6?

EDIT: Using Date.now (instead of console.time) and calculating diff to workaround that *console.log issue:

1477612721238 RUNS
1477612733199 PASS
1477612733142 startSync

PASS - RUNS = 11961
startSync - RUNS = 11904

The difference between when it prints RUNS and when it actually starts the test code (startSync) is 11 secs

[cpojer]

It just looked at it, the test run should certainly complete in less than a second. This is really odd.

Is it at all different if you do jest -i? If not, can you try to profile things earlier? Check out https://github.com/cpojer/jest/blob/master/packages/jest-cli/src/TestRunner.js#L1

[laggingreflex]

jest -i didn't help, unfortunately.

I did a node --prof, here's the processed file: processed2.txt

I've narrowed it down to the following statements that are causing the delay:

jest-cli/src/TestRunner.js#L304

// till here - 0.1s
return runTest(…)
  .then(()=>{
    // after here: 8s

jest-cli/src/runTest.js#L50

// till here - 0.5s
return TestRunner(…)
  .then(()=>{
    // after: 8s

jest-jasmine2/src/index.js#L110

// till here - 2s
runtime.requireModule(testPath);
// after: 7s

After this it goes into jest-runtime's requireModule which _execModule's a lot of modules (is that expected behaviour? even with autoMock:false?), so timing it didn't make sense, at least for the test file because lots of other module files are also collectively being loaded and might be what's causing the delay. Thoughts on this?

[cpojer]

Interesting. Are you using npm2? I would recommend to upgrade to yarn or npm3 to install Jest which will result in a lot fewer modules that will be required per context.

[cpojer]

Closing for now as I don't think this is actionable. If there are issues in Jest that we can fix, please comment here or send a PR and I'll reopen this issue.

[laggingreflex]

Sorry I couldn't debug this further earlier.

I was actually using npm3 and yarn. In fact in all these tests I had no other dependencies than Jest itself (which was set up via Lerna).

You didn't answer my question earlier: [...] After this it goes into jest-runtime's requireModule which _execModule's a *lot of modules* -- is that expected behaviour? even with autoMock:false? Shouldn't these modules only be loaded when autoMock:true?

[cpojer]

Jest does require a ton of modules, yes, but normally that shouldn't take more than ~10ms. The paths very much look like the node_modules folder wasn't deduplicated, which is really odd. You should only have jest-* modules on the top level of your node_modules folder. Would you mind wiping away node_modules and installing Jest again?

[Jacse]

I'm having the same problems on node 6.9.3 and npm 3.10.10. Only testing one simple file:

// src/lib/tests/jest-test.spec.js describe('wrapRequest', () => { it('should pass this test', () => { expect(1).toBe(1); }); });

````
jest "src/lib/tests/jest-test.spec.js"

PASS src\lib\tests\jest-test.spec.js (21.568s)
wrapRequest
√ should pass this test (9ms)

Test Suites: 1 passed, 1 total
Tests: 1 passed, 1 total
Snapshots: 0 total
Time: 45.878s
Ran all test suites matching "src/lib/tests/jest-test.spec.js".
````

46 seconds is outrageous. I have already tried nuking node_modules but no cigar. I am not using babel-jest. On Windows 10 x64 and using Jest 18.

[Jacse]

Consequent runs take ~7 seconds:
````
jest "src/lib/tests/jest-test.spec.js"

PASS src\lib\tests\jest-test.spec.js
wrapRequest
√ should pass this test (9ms)

Test Suites: 1 passed, 1 total
Tests: 1 passed, 1 total
Snapshots: 0 total
Time: 7.05s, estimated 22s
Ran all test suites matching "src/lib/tests/jest-test.spec.js".
````

[apieceofbart]

Same for me, I'm running enzyme example repo and it takes 7-10 seconds. The assertions itself takes only 50ms.
I'm running Windows 7, node 6.9.2, npm 3.10.9.
I will try to track it down - any suggestions?

[laggingreflex]

@apieceofbart You could start by confirming whether you're getting the same delays as me on breakpoints I mentioned above https://github.com/facebook/jest/issues/1986#issuecomment-256936218

Specially the last one:

jest-jasmine2/src/index.js#L110

// till here - 2s
runtime.requireModule(testPath);
// after: 7s

runtime.requireModule(testPath) here for me took 5s! The problem most likely lies somewhere around here.

[apieceofbart]

@laggingreflex thanks!
It's a bit different in my case.
This line, takes over 2s: https://github.com/facebook/jest/blob/master/packages/jest-cli/src/runTest.js#L32

From there till the end it's similar to your case. I will keep posting other findings.

[apieceofbart]

@laggingreflex
I can pretty much confirm your comment: https://github.com/facebook/jest/issues/1986#issuecomment-256936218
Most of the time is spent running _execModule for every module in node_modules (over 2170 files in enzyme example repo).
This is not the only performance issue but certainly the main problem.

[cpojer]

@apieceofbart can you try testEnvironment: "node" in the config? The 2s overhead is odd; I'm assuming it is because of loading jsdom.

Jest has to read files from disk to load and run them. What you are pointing to are the pieces of code that executes node modules and user code. It may be that your harddrive is very slow or your anti-virus scanner looks at all the node_modules. If you make an exception for your projects, all your tools may be faster.

[apieceofbart]

@cpojer

@apieceofbart can you try testEnvironment: "node" in the config? The 2s overhead is odd; I'm assuming it is because of loading jsdom.

bingo! This brings creating test env from 2s to 15ms. However this runtime.reqiureModule still takes around 2-3s. Also 'jest-runtime' constructor takes almost a second.

I have just bought a new SSD laptop and whitelisted my projects folder in anti-virus scanner (even removing the scan completely) and it doesn't help. Thanks for your concern, I will let you know if find anyhing.

[jkulak]

I had similar observation, running jest inside Docker on macOS with alpine-node image (and the app bootstrapped with create-react-app).

I was running yarn test -- --coverage to capture the time. I run the tests 5 times each, and below I present the average results.

Results

|Content location|Time (tests)|Done in (all)
| ------------- |-------------|----|
| content inside the container (COPY . /app) | ~2.1s | ~3.4s |
| content mounted from the host (-v $(pwd):/app) | ~9.6s | ~31.5s |

Reason

In my case, the cause was the well known problem of slow Docker mounts on macOS. The whole issue thread here: https://github.com/docker/for-mac/issues/77

Solution (until the mounts get faster)

For now, I just mount my ./src (-v $(pwd)/src:/app/src) directory, instead of the whole ./app (so local ./node_modules and ./package.json from inside the container are used). This allows tests to run fast, but adds a bit of extra work, when you need to install additional node package (you need to rebuild the image).

Question

I know, that my solution does not update ./.git inside the container, when I commit from the host. So far, I did not see any downsides of that (I am working on a tiny app). Are there any potential problems with my solution/work-around?

[laggingreflex]

For Windows, could this and various similar issues on yarn be related?: https://github.com/yarnpkg/yarn/issues/1496 https://github.com/yarnpkg/yarn/issues/990 (just a hunch, haven't checked these out in detail). In https://github.com/yarnpkg/yarn/pull/2958 OP mentioned a Windows specific nodejs bug in fs https://github.com/nodejs/node/issues/2069 that was only recently fixed (v7.1).

[stephenlautier]

We have a similar problem, we are importing stylefmt and it's taking around 4-5s to get resolved using console.time as below

console.time("stylefmt spec");
const style = require("stylefmt");
console.timeEnd("stylefmt spec");

It seems this happens when its using jest-resolve, when I used jasmine/node normally on the same exact project its taking around 1-2s

Not entirely sure if its related or if jest have a threshold but after loading this specific test its failing other tests without a message (however the tests alone works). This is the error im getting

 FAIL  src\utils\string.spec.ts
  ● Test suite failed to run

    Error: No message was provided

This is the last test I need to get working to switch to jest from jasmine which unfortunately its blocking me

update: last part was failing because of running in parallel for some reason, i had to use --runInBand otherwise they randomly fail

using

• Jest: 19.0.2
• Node: 7.8.0
• NPM: 4.4.4
• Windows 7

[Georg-W]

I am using Jest (and enzyme) in create-react-app and adding a --runInBand flag brought me from around 20 sec (only 8 tests) down to 3.3 sec. on a new Windows 10 maschine. Might be useful in other cases as well. I still feel that something is off with my setup but at least its not as bad.