jest runtime slower then non-bazel

[jbedard]

Mostly due to fs sandboxing. The readlinkSync call in nextHopSync fails and throws on most invocations causing substantial cpu usage calculating stack traces.

1. Minimize work when calculating stack traces (reduced test time by 50%): perf: prevent preparing stack traces in fs *Sync patches rules_js#546
2. reduce directory traversing: perf: cache fs patch fs lookups  rules_js#569
3. avoid work when outside the sandbox, cache more: perf: fs performance improvements rules_js#1007

[gregmagolan]

Measure 3 things:

• non-bazel
• rules_js with patches and no sandbox
• rules_nodejs with patches and no sandbox

[gregmagolan]

also measure: Is the patches overhead a one-time start-up cost or does is scale with number of test cases/specs

[jbedard]

Overall the times with vs without the patches scale along with the number of tests, which I assume means number of files loaded. With a single test it seems about 8% slower, with 2k tests it was about 5% slower (using the best times with ~5 tries, very inaccurate but consistent enough I'll trust them).

[rc-glean]

Curious whether aspect's "mac as local dev" customers|partners|users prefer to disable sandboxing on mac per bazelbuild/bazel#8230 (comment). Confirming that we also tried --experimental_reuse_sandbox_directories and it doesn't seem to help.

Some anecdata: one of our jest test suites (Glean closed source) running under aspect takes ~6x longer to execute with the sandbox enabled vs not. 1 minute vs 6 minutes.

[tbarrella]

Hello, I wanted to provide something to help repro two sources of slowness: https://github.com/tbarrella/jest-large

Setup slowness

I'm concerned about Jest setup time, which includes crawling that seems unoptimized for Bazel: bazel-contrib/rules_nodejs#2817 (comment)

In a large codebase, I've observed up to ~15s setup time within Bazel, compared to a ~1s setup time without Bazel (with the Jest cache). By "setup" I mean time between Jest startup and running the first test, inferred from the total time minus the "Test: _s" output

With this smaller repro, I found (on a mac)

• ~3s setup with Bazel
• <2s setup without Bazel, no cache
• <1s setup without Bazel, with cache

I think in a TypeScript codebase, with JavaScript transpiled by ts_project, the crawling time is doubled due to Jest seeing both .js and .ts files

guardedReadLink

I couldn't repro it, but a possible source of long setup time seems to be deep stacks during crawling. I've seen

• This line in handleDirent is called with something like /private/var/tmp/_bazel_tbarrella/0abc/execroot/_main/bazel-out/darwin_arm64-fastbuild/bin/app/jest_/jest.runfiles/_main/packages/a/lib/dist/a/b/c.js
• readHopLink is then called repeatedly like this
  • /private/var/tmp/_bazel_tbarrella/0abc/execroot/_main/bazel-out/darwin_arm64-fastbuild/bin/app/jest_/jest.runfiles/_main/packages/a/lib/dist
  • /private/var/tmp/_bazel_tbarrella/0abc/execroot/_main/bazel-out/darwin_arm64-fastbuild/bin/app/jest_/jest.runfiles/_main/packages/a/lib
  • /private/var/tmp/_bazel_tbarrella/0abc/execroot/_main/bazel-out/darwin_arm64-fastbuild/bin/app/jest_/jest.runfiles/_main/packages/a
  • ...
  • /private/var/tmp
  • /private/var
  • /private
• In between each readHopLink, this line in nextHop is being called with link = HOP_NON_LINK

File import slowness

With this repro I found test execution time to take

• ~65s+ with Bazel
• ~10s without Bazel

A couple suspected culprits from profiling before I made this repro:

• resolve/sync
• path.normalize