Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jest spends half its time importing jest-snapshot even when it isn’t used #9554

Open
andersk opened this issue Feb 11, 2020 · 11 comments
Open

Comments

@andersk
Copy link
Contributor

andersk commented Feb 11, 2020

🐛 Bug Report

I did some profiling on a directory of 500 empty tests and discovered that Jest is spending 50% of its time importing jest-snapshot into every test environment. Then I wrote a quick and dirty patch that rips jest-snapshot out of jest-jasmine2 and jest-runtime, and observed that it makes my tests run twice as fast (39.706s → 19.941s)!

Obviously we can’t actually rip jest-snapshot out, but if we could import it lazily, we could get a large speedup on projects with many small test files that don’t use snapshot testing.

To Reproduce

In an empty directory:

mkdir __tests__
for i in {000..499}; do echo "test(\"test $i\", () => {});" > __tests__/test$i.js; done
echo '{ "testEnvironment": "node" }' > jest.config.json
jest --runInBand

(Running tests serially with --runInBand gave me much more stable benchmark results.)

Expected behavior

Jest should be faster! 🙂

Link to repl or repo (highly encouraged)

https://github.com/andersk/500-empty-jest-tests

envinfo

  System:
    OS: Linux 5.5 NixOS 20.03 (Markhor) 20.03pre212208.8130f3c1c2b (Markhor)
    CPU: (12) x64 Intel(R) Core(TM) i7-10710U CPU @ 1.10GHz
  Binaries:
    Node: 12.15.0 - ~/.nix-profile/bin/node
    Yarn: 1.22.0 - ~/.yarn/bin/yarn
    npm: 6.13.4 - ~/.nix-profile/bin/npm
  npmPackages:
    jest: ^25.1.0 => 25.1.0 
@SimenB
Copy link
Member

SimenB commented Feb 11, 2020

Hey @andersk, thanks for digging into this! We do most of our importing lazily, but the modules that are evaluated inside the user's sandbox (like jest-snapshot) are explicitly blacklisted from this:
https://github.com/facebook/jest/blob/017264f6730d7e99fe0f054d799574e47a802c08/scripts/build.js#L43

For some background, you can read through #3786, tl;dr being that users might mess with the globals (like Array.prototype) and that should never affect Jest's internals. And we need to evaluate these modules in the user's sandbox so instanceof works correctly etc.


That said, the speedup you're seeing is very tempting, so I think we should definitely investigate this. I wonder if making the implementations of the matchers and snapshot state lazy would help - e.g. only setting up serializers, state etc if snapshot matchers are actually called. I'll try to find some time digging into this, thank you for a short and sweet reproduction!

@andersk
Copy link
Contributor Author

andersk commented Feb 19, 2020

Yeah, ignoring the blacklist for @babel/plugin-transform-modules-commonjs similarly halves the running time on this benchmark:

--- a/scripts/build.js
+++ b/scripts/build.js
@@ -143,7 +143,8 @@ function buildFile(file, silent) {
       options.plugins.push(
         require.resolve('./babel-plugin-jest-native-globals')
       );
-    } else {
+    }
+    {
       options.plugins = options.plugins.map(plugin => {
         if (
           Array.isArray(plugin) &&

So now I’m curious, what exactly does this blacklist accomplish in the way of preventing test code from messing with Jest internals? It means that lots of Jest code gets loaded before the test code has a chance to run—but the loaded code still refers to globals that the test code could interfere with, so how does that help?

@github-actions
Copy link

This issue is stale because it has been open for 1 year with no activity. Remove stale label or comment or this will be closed in 14 days.

@github-actions github-actions bot added the Stale label Feb 25, 2022
@andersk
Copy link
Contributor Author

andersk commented Feb 25, 2022

Still an issue in current main (1bbe6fb). Ignoring the lazy-loading blacklist speeds up the run by 2× (21.9 s → 11.8 s).

@github-actions github-actions bot removed the Stale label Feb 26, 2022
@SimenB
Copy link
Member

SimenB commented Feb 26, 2022

Would you be able to look into what specifically is slow when loading jest-snapshot? I.e. is it loading dependencies or is it some other setup it does? If other setup, we can probably make that lazy

@mhnaeem
Copy link
Contributor

mhnaeem commented Mar 11, 2022

@SimenB I got a chance to take a look at this issue and it seems that the largest source of slowdown is the babel packages inside the packages/jest-snapshot/src/InlineSnapshots.ts file. I tried very basic profiling, if I lazy load all the babel packages inside that file then the jest-snapshot package takes ~5.4% of the total
time. Without lazy loading the jest-snapshot takes ~28.2% of the total time.

The screenshots below are comparing InlineSnapshots.js file

Without Lazy Loading:
Screenshot 2022-03-11 at 12 19 13 AM

With Lazy Loading:
Screenshot 2022-03-11 at 12 21 26 AM

@SimenB
Copy link
Member

SimenB commented Mar 11, 2022

jest-snapshot tries to load e.g. prettier and chalk outside of the sandbox, maybe we should do the same for babel?

EDIT: No, we already try to: https://github.com/facebook/jest/blob/199f9811ae68b15879cbe18b7ef7ebd61eefcf23/packages/jest-snapshot/src/InlineSnapshots.ts#L20-L37

@mhnaeem
Copy link
Contributor

mhnaeem commented Mar 11, 2022

@SimenB I tried doing it this way (snippet below), since my test case was very singular in just trying to figure out what was causing the slowdown I haven't considered any other side effects from this change. Such as users messing with globals like you mentioned.

var _types = () => {
  const data = require('@babel/types');

  _types = function () {
    return data;
  };

  return data;
}

@benjaminjkraft
Copy link
Contributor

This seems to still be pretty slow. But it looks like at this point, the toplevel import is okay as long as it's a requireOutside (which can be cached across test cases); the issue is that there's also a regular import. Removing that gets the original repro (with --runInBand) from ~40s to ~25s on my laptop, which is almost as much as ripping out jest-snapshot entirely. If we could do the same for a bunch of other plausibly-stateless packages used by jest itself [1], that can get us down to at least 13s, although I'm not certain how safe that is.

[1] I'm testing with 'expect', 'semver', 'picomatch', 'micromatch', 'jest-diff', 'source-map-support', 'jest-matcher-utils', '@jest/expect', 'jest-snapshot' ('chalk' is already required outside the VM).

andersk added a commit to andersk/jest that referenced this issue Dec 26, 2022
Refs jestjs#9554.

Signed-off-by: Anders Kaseorg <andersk@mit.edu>
Copy link

This issue is stale because it has been open for 1 year with no activity. Remove stale label or comment or this will be closed in 30 days.

@github-actions github-actions bot added the Stale label Dec 13, 2023
@andersk
Copy link
Contributor Author

andersk commented Dec 13, 2023

Still an issue in current main (e54c0eb). Something now breaks if you ignore the lazy-loading exclude list completely, but reducing it speeds up the run from 38.564 s to 22.439 s:

--- a/scripts/buildUtils.mjs
+++ b/scripts/buildUtils.mjs
@@ -138,8 +138,7 @@ export function getPackagesWithTsConfig() {
   );
 }
 
-export const INLINE_REQUIRE_EXCLUDE_LIST =
-  /packages\/expect|(jest-(circus|diff|get-type|jasmine2|matcher-utils|message-util|regex-util|snapshot))|pretty-format\//;
+export const INLINE_REQUIRE_EXCLUDE_LIST = /jest-circus/;
 
 export const copyrightSnippet = `
 /**

@github-actions github-actions bot removed the Stale label Dec 13, 2023
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

No branches or pull requests

4 participants