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

[andersk]

🐛 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! :slightly_smiling_face:

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]

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]

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[bot]]

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.

[andersk]

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

[SimenB]

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]

@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:

With Lazy Loading:

[SimenB]

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]

@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]

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).

[github-actions[bot]]

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.

[andersk]

Still an issue in current main (e54c0ebb048e10331345dbe99f8ec07654a43f1c). 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 = `
 /**