when coverage is enabled, jest takes 40x more time to run

[capaj]

Unfortunately I can't share the whole project, but to illustrate:

capaj@capaj-Inspiron-7548:~/git_projects/be/frontend-be.com$ nr jest ChatSessionsStore

> [email protected] jest /home/capaj/git_projects/be/frontend-be.com
> node environment/scripts/jest.js -i "ChatSessionsStore"

 PASS  test/Stores/WebSockets/ChatSessionsStore.test.js
  ✓ should properly store assigned session (8ms)
  ✓ should save conversation in related session (6ms)
  ✓ should properly store retrieved session (2ms)
  ✓ when sending conversation should save conversation in related session (4ms)
  ✓ when receiving conversation via web socket should save conversation in related session (8ms)
  ✓ when receiving conversation via web socket should deserialize date values (2ms)
  ✓ when closing chat session it should update chat session status (4ms)
  ✓ when receiving client typing should update clientTyping when client is typing (2ms)
  ✓ when receiving client typing should update clientTyping when client is not typing (5ms)
  ✓ ADD_TAG_SESSION should add tag to session (4ms)
  ✓ REMOVE_TAG_SESSION should add tag to session (3ms)

Test Suites: 1 passed, 1 total
Tests:       11 passed, 11 total
Snapshots:   0 total
Time:        4.432s
Ran all test suites matching "ChatSessionsStore".
capaj@capaj-Inspiron-7548:~/git_projects/be/frontend-be.com$ nr jest ChatSessionsStore

> [email protected] jest /home/capaj/git_projects/be/frontend-be.com
> node environment/scripts/jest.js -i --coverage "ChatSessionsStore"

 PASS  test/Stores/WebSockets/ChatSessionsStore.test.js (172.797s)
  ✓ should properly store assigned session (9ms)
  ✓ should save conversation in related session (6ms)
  ✓ should properly store retrieved session (3ms)
  ✓ when sending conversation should save conversation in related session (4ms)
  ✓ when receiving conversation via web socket should save conversation in related session (8ms)
  ✓ when receiving conversation via web socket should deserialize date values (2ms)
  ✓ when closing chat session it should update chat session status (3ms)
  ✓ when receiving client typing should update clientTyping when client is typing (2ms)
  ✓ when receiving client typing should update clientTyping when client is not typing (5ms)
  ✓ ADD_TAG_SESSION should add tag to session (3ms)
  ✓ REMOVE_TAG_SESSION should add tag to session (3ms)

-------------------------|----------|----------|----------|----------|----------------|
File                     |  % Stmts | % Branch |  % Funcs |  % Lines |Uncovered Lines |
-------------------------|----------|----------|----------|----------|----------------|
All files                |    36.47 |    27.98 |     41.1 |     26.9 |                |
 environment             |    66.67 |       50 |      100 |    66.67 |                |
  polyfills.js           |    66.67 |       50 |      100 |    66.67 |            5,6 |
 src                     |    27.27 |    21.43 |        0 |    14.29 |                |
  Routes.js              |    27.27 |    21.43 |        0 |    14.29 |... 13,15,16,19 |
 src/Constants           |      100 |       75 |      100 |      100 |                |
  AppConstants.js        |      100 |       75 |      100 |      100 |                |
  livechat.js            |      100 |       75 |      100 |      100 |                |
 src/Dispatcher          |    88.89 |    58.14 |      100 |      100 |                |
  AppDispatcher.js       |    87.88 |    55.17 |      100 |      100 |                |
  Dispatcher.js          |    90.48 |    64.29 |      100 |      100 |                |
 src/Library             |    15.61 |     4.35 |        9 |    15.53 |                |
  Finch.js               |     15.4 |     4.11 |     8.16 |    15.31 |... 7,1028,1031 |
  invariant.js           |    27.27 |       25 |       50 |       50 |          43,44 |
 src/Stores              |    59.58 |    52.67 |     53.9 |    44.05 |                |
  ApplicationStore.js    |    50.49 |    50.85 |       50 |    38.96 |... 314,316,317 |
  ChannelsStore.js       |    62.86 |    49.21 |    54.17 |    51.22 |... 136,137,141 |
  StatusesStore.js       |    80.56 |    61.76 |    76.92 |       70 |       39,47,55 |
  Store.js               |    72.73 |    56.41 |       80 |    55.56 |... 42,50,58,66 |
  TagStore.js            |       70 |       60 |    42.86 |    55.56 |    36,37,42,45 |
  UserStore.js           |    48.15 |       50 |    48.39 |    32.14 |... 224,226,227 |
  global.js              |    58.82 |    45.45 |    16.67 |    56.25 |... 18,21,22,23 |
 src/Stores/Care         |     24.2 |    22.78 |     39.8 |    14.22 |                |
  DetailTypesStore.js    |      100 |      100 |      100 |      100 |                |
  TabsStore.js           |    38.61 |    29.58 |    53.49 |     31.4 |... 558,560,563 |
  ViewsStore.js          |    14.89 |    17.24 |    29.09 |     3.25 |... 774,776,777 |
 src/Stores/WebSockets   |    72.27 |    55.88 |    82.61 |    69.15 |                |
  ChatSessionsStore.js   |    72.27 |    55.88 |    82.61 |    69.15 |... 235,238,241 |
 src/Utils               |    44.44 |    16.67 |    27.27 |       50 |                |
  datetime.js            |    41.18 |        0 |       20 |     37.5 |... 27,28,31,39 |
  rainbowUnicorn.js      |    46.43 |    22.22 |    33.33 |       75 |          74,82 |
 test                    |    65.71 |     37.5 |    16.67 |    65.63 |                |
  globals.js             |    59.26 |        0 |        0 |    59.26 |... 70,74,80,81 |
  propagateProperties.js |     87.5 |       75 |      100 |      100 |                |
 test/dataProvider       |      100 |      100 |      100 |      100 |                |
  liveChatSession.js     |      100 |      100 |      100 |      100 |                |
  requestPaths.js        |      100 |      100 |      100 |      100 |                |
-------------------------|----------|----------|----------|----------|----------------|
Test Suites: 1 passed, 1 total
Tests:       11 passed, 11 total
Snapshots:   0 total
Time:        175.203s
Ran all test suites matching "ChatSessionsStore".

this is on jest 18.1.0

[cpojer]

Unfortunately without more info there is nothing at all we can do to help. Please send us a repro.

At Facebook we use coverage on thousands of test suites and we have not experienced similar issues. However, @DmitriiAbramov did run into some issues with babel in the latest version of Jest. Does this repro in Jest 18.0.0?

[thymikee]

Also @DmitriiAbramov is working on async coverage reporters which should make it even faster for larger test suites, but it's just a start: #2512

[aaronabramov]

some of the reasons why coverage can be slow:

1. it's a cold run and cache is not generated, so we're transforming/instrumenting every file from scratch (next run should be faster)
2. you have a lot of vendor files (or maybe node_modules that are included for some reason) and they all get instrumented. you can use collectCoverageFrom config to specify where you can collect coverage from
3. You use collectCoverageFrom and there's a lot of files that are missing tests, these will be staticly analyzed and covered, but unfortunately there's no way to parallelize those and it has to be done in one thread, which is slow. but as @thymikee mentioned we might be able to fix it soon.
4. There is a babel issue with code formatting that eats a lot of memory (Code size limit bump (#4965) in babel-generator causes issues for very large files babel/babel#5081) but i don't think it's the case here

[aaronabramov]

actually it doesn't look like you're covering a lot of files, so i assume it's either the cache issue or a bug on our side.
What kind of machine are you running it on? how many cores? is it still slow if you run it again? is it the same slow if you run it with --no-cache flag?

[bcoe]

@jwbay @DmitriiAbramov @hzoo (@ party, sorry).

note about caching and performance

One thing worth noting about how nyc itself improves performance, is that we cache an instrumented source file the first time we observe it using caching-transform:

https://github.com/istanbuljs/nyc/blob/master/index.js#L94

This results in a significant improvement in test speeds, given that tests tend to require the same files a ridiculous number of times.

In the case of the npm CLI, when nyc began caching by default, we saw tests go from taking an hour to run, to 15 minutes (about three minutes longer than the un-instrumented times).

I know babel itself has a cache? is there a way we could take advantage of this in Jests' test-suite, and projects that rely on Jest?

[cpojer]

@bcoe we cache transform results after the first run in Jest as well, so we are doing all of this already.

[cpojer]

Also, weren't you supposed to be on vacation? ;D

[aaronabramov]

there's one thing we can improve actually.
Right now we would transform the same file multiple times if it's required in multiple worker processes at the same time.

here's an example:

worker 1	worker 2
require('react')	require('react')
check cache	check cache
no cache entry found	no cache entry found
start transforming	start transforming
finish transforming	finish transforming
write cache file
	write cache file again
execute	execute

so in some cases we transform the same file multiple time. we can probably fix it by using a file system lock.

worker 1	worker 2
require('react')	require('react')
check cache	check cache
no cache entry found	no cache entry found
check for react.lock file
not found, create react.lock file
	check for react.lock file
	found. transform the next file in the queue, wait for react to be transformed by other worker
transform react
write cache file
execute
	check react.lock again
	check cache
	react cache found
	execute

[cpojer]

@DmitriiAbramov we should probably do that; yes, but at the same time I don't think that has significant impact on performance. I guess it can be tested easily by running Jest with -i.

[KathiresanRamkumar]

How to run a case multiple times multiple source files in jest?@cpojer

[github-actions]

This issue has been automatically locked since there has not been any recent activity after it was closed. Please open a new issue for related bugs.
Please note this issue tracker is not a help forum. We recommend using StackOverflow or our discord channel for questions.