CLOVER🍀

That was when it all began.

Jestでテストが並列に動作していることを確認してみる

これは、なにをしたくて書いたもの?

Jestはデフォルトでテストを並列に実行するというので、動作を確認しておきたいなと思いまして。

JestのCLIのオプションを確認する

JestのCLIのオプションを見てみます。

Jest CLI Options · Jest

以下の2つの項目が関連しそうです。

--maxWorkersはテストを実行するためにワーカープールが生成する、ワーカーの最大数を指定するそうです。
デフォルトでは動作しているホストのCPU数から1を引いた値(CPUがひとつなら1)となり、--watchを指定したウォッチモードでは
ホストのCPUの半分に設定されるようです。
このオプションは、パーセンテージでの指定(--maxWorkers=50%など)も可能です。

--runInBandは、ワーカーの数を1にします。--maxWorkers=1と同じです。

maxWorkersは設定ファイルでも指定できそうです。

Configuring Jest / maxWorkers [number | string]

なお、並列で実行されるのはファイル単位(テストコード単位)で、ファイル内にあるテストはシーケンシャルに実行されるようです。

テストを並行に実行したい場合は、テストをtestではなくtest.concurrentを使って書くようです。

test.concurrent(name, fn, timeout)

こちらの設定は、--maxConcurrencyで行うようです。

今回はtest.concurrentについてはパスしておきます。

テストコードを用意して、実際にどのように動いているのか確認してみたいと思います。使ったJestのバージョンは、29.7.0です。

環境

今回の環境は、こちら。

$ node --version
v18.18.0


$ npm --version
9.8.1

CPUは8個あります。

$ grep processor /proc/cpuinfo
processor       : 0
processor       : 1
processor       : 2
processor       : 3
processor       : 4
processor       : 5
processor       : 6
processor       : 7

準備

まずは、Node.jsプロジェクトを作成します。ソースコードはTypeScriptで書くことにします。

$ npm init -y
$ npm i -D typescript
$ npm i -D prettier
$ npm i -D @types/node@v18

Jestとesbuild、esbuild-jestのインストール。

$ npm i -D jest @types/jest
$ npm i -D esbuild esbuild-jest

テストコードは、testディレクトリに置くことにします。

$ mkdir test

依存関係。

  "devDependencies": {
    "@types/jest": "^29.5.5",
    "@types/node": "^18.18.1",
    "esbuild": "^0.19.4",
    "esbuild-jest": "^0.5.0",
    "jest": "^29.7.0",
    "prettier": "^3.0.3",
    "typescript": "^5.2.2"
  }

scripts

  "scripts": {
    "typecheck": "tsc --project .",
    "typecheck:watch": "tsc --project . --watch",
    "test": "jest",
    "format": "prettier --write test"
  },

各種設定ファイル。

tsconfig.json

{
  "compilerOptions": {
    "target": "esnext",
    "module": "commonjs",
    "moduleResolution": "node",
    "lib": ["esnext"],
    "baseUrl": "./test",
    "noEmit": true,
    "strict": true,
    "forceConsistentCasingInFileNames": true,
    "noFallthroughCasesInSwitch": true,
    "noImplicitOverride": true,
    "noImplicitReturns": true,
    "noPropertyAccessFromIndexSignature": true,
    "esModuleInterop": true
  },
  "include": [
    "test"
  ]
}

.prettierrc.json

{
  "singleQuote": true,
  "printWidth": 120
}

jest.config.js

module.exports = {
  testEnvironment: 'node',
  transform: {
    "^.+\\.tsx?$": "esbuild-jest"
  }
};

Jestは、npx jestで実行することにしましょう。

テストコードを書いてみる

まずはテストコードをひとつ用意してみます。

test/test1.test.ts

import { basename } from 'node:path';
import { setTimeout } from 'node:timers/promises';

jest.setTimeout(10 * 1000);

const testBaseName = basename(__filename);
const currentDir = process.cwd();

test(`${testBaseName}: test1`, async () => {
  console.log(
    `[${testBaseName}] jest worker id = ${process.env['JEST_WORKER_ID']}, pid = ${
      process.pid
    }, path = ${process.argv[1].replace(currentDir + '/', '')}`,
  );
  await setTimeout(2 * 1000);
});

test(`${testBaseName}: test2`, async () => {
  console.log(
    `[${testBaseName}] jest worker id = ${process.env['JEST_WORKER_ID']}, pid = ${
      process.pid
    }, path = ${process.argv[1].replace(currentDir + '/', '')}`,
  );
  await setTimeout(2 * 1000);
});

各テストでは、2秒ずつスリープさせています。

JEST_WORKER_IDというのは、Jestのワーカープロセスに1から割り当てられる数字で、こちらを参照できる環境変数です。

Environment Variables · Jest

今回は、JestのワーカーID、プロセスのid、プロセスの実行パスをそれぞれ出力してみます。

では

$ npx jest
  console.log
    [test1.test.ts] jest worker id = 1, pid = 18771, path = node_modules/.bin/jest

      at Object.<anonymous> (test/test1.test.ts:7:11)

  console.log
    [test1.test.ts] jest worker id = 1, pid = 18771, path = node_modules/.bin/jest

      at Object.<anonymous> (test/test1.test.ts:13:11)

 PASS  test/test1.test.ts
  ✓ test1.test.ts: test1 (2018 ms)
  ✓ test1.test.ts: test2 (2008 ms)

Test Suites: 1 passed, 1 total
Tests:       2 passed, 2 total
Snapshots:   0 total
Time:        4.341 s, estimated 5 s
Ran all test suites.

4秒少々かかりました。同じプロセスで実行されていますね。

テストコードを増やしてみる

では、このテストコードをコピーして増やしてみます。

$ cp test/test1.test.ts test/test2.test.ts
$ cp test/test1.test.ts test/test3.test.ts

3ファイルにしてみました。

もう1度、テストを実行してみます。

$ npx jest

結果はこのようになり、4秒少々なので並列に実行されたようです。

 PASS  test/test1.test.ts
  ● Console

    console.log
      [test1.test.ts] jest worker id = 3, pid = 19089, path = node_modules/jest-worker/build/workers/processChild.js

      at Object.<anonymous> (test/test1.test.ts:7:11)

    console.log
      [test1.test.ts] jest worker id = 3, pid = 19089, path = node_modules/jest-worker/build/workers/processChild.js

      at Object.<anonymous> (test/test1.test.ts:13:11)

 PASS  test/test3.test.ts
  ● Console

    console.log
      [test3.test.ts] jest worker id = 1, pid = 19077, path = node_modules/jest-worker/build/workers/processChild.js

      at Object.<anonymous> (test/test3.test.ts:7:11)

    console.log
      [test3.test.ts] jest worker id = 1, pid = 19077, path = node_modules/jest-worker/build/workers/processChild.js

      at Object.<anonymous> (test/test3.test.ts:13:11)

 PASS  test/test2.test.ts
  ● Console

    console.log
      [test2.test.ts] jest worker id = 2, pid = 19078, path = node_modules/jest-worker/build/workers/processChild.js

      at Object.<anonymous> (test/test2.test.ts:7:11)

    console.log
      [test2.test.ts] jest worker id = 2, pid = 19078, path = node_modules/jest-worker/build/workers/processChild.js

      at Object.<anonymous> (test/test2.test.ts:13:11)


Test Suites: 3 passed, 3 total
Tests:       6 passed, 6 total
Snapshots:   0 total
Time:        4.693 s, estimated 5 s
Ran all test suites.

JestのワーカーID、PIDもそれぞれ異なります。また、実行されているファイルがprocessChild.jsになりました。

ここで、--maxWorkersを指定してみましょう。2つのプロセスにしてみます。

$ npx jest --maxWorkers=2

test1.test.tstest3.test.tsが同じプロセス(Jestワーカー)で実行されるようになりました。

 PASS  test/test3.test.ts
  ● Console

    console.log
      [test3.test.ts] jest worker id = 1, pid = 19245, path = node_modules/jest-worker/build/workers/processChild.js

      at Object.<anonymous> (test/test3.test.ts:7:11)

    console.log
      [test3.test.ts] jest worker id = 1, pid = 19245, path = node_modules/jest-worker/build/workers/processChild.js

      at Object.<anonymous> (test/test3.test.ts:13:11)

 PASS  test/test2.test.ts
  ● Console

    console.log
      [test2.test.ts] jest worker id = 2, pid = 19246, path = node_modules/jest-worker/build/workers/processChild.js

      at Object.<anonymous> (test/test2.test.ts:7:11)

    console.log
      [test2.test.ts] jest worker id = 2, pid = 19246, path = node_modules/jest-worker/build/workers/processChild.js

      at Object.<anonymous> (test/test2.test.ts:13:11)

 PASS  test/test1.test.ts
  ● Console

    console.log
      [test1.test.ts] jest worker id = 1, pid = 19245, path = node_modules/jest-worker/build/workers/processChild.js

      at Object.<anonymous> (test/test1.test.ts:7:11)

    console.log
      [test1.test.ts] jest worker id = 1, pid = 19245, path = node_modules/jest-worker/build/workers/processChild.js

      at Object.<anonymous> (test/test1.test.ts:13:11)


Test Suites: 3 passed, 3 total
Tests:       6 passed, 6 total
Snapshots:   0 total
Time:        8.703 s
Ran all test suites.

実行時間としても、2倍(ひとつはシーケンシャルだから)になっています。

今度は、--runInBandを指定してみましょう。

$ npx jest --runInBand

完全にシーケンシャルになりましたね。

$ npx jest --runInBand
 PASS  test/test2.test.ts
  ● Console

    console.log
      [test2.test.ts] jest worker id = 1, pid = 19341, path = node_modules/.bin/jest

      at Object.<anonymous> (test/test2.test.ts:7:11)

    console.log
      [test2.test.ts] jest worker id = 1, pid = 19341, path = node_modules/.bin/jest

      at Object.<anonymous> (test/test2.test.ts:13:11)

 PASS  test/test3.test.ts
  ● Console

    console.log
      [test3.test.ts] jest worker id = 1, pid = 19341, path = node_modules/.bin/jest

      at Object.<anonymous> (test/test3.test.ts:7:11)

    console.log
      [test3.test.ts] jest worker id = 1, pid = 19341, path = node_modules/.bin/jest

      at Object.<anonymous> (test/test3.test.ts:13:11)

 PASS  test/test1.test.ts
  ● Console

    console.log
      [test1.test.ts] jest worker id = 1, pid = 19341, path = node_modules/.bin/jest

      at Object.<anonymous> (test/test1.test.ts:7:11)

    console.log
      [test1.test.ts] jest worker id = 1, pid = 19341, path = node_modules/.bin/jest

      at Object.<anonymous> (test/test1.test.ts:13:11)


Test Suites: 3 passed, 3 total
Tests:       6 passed, 6 total
Snapshots:   0 total
Time:        12.605 s, estimated 13 s
Ran all test suites.

これで、基本的な動作は確認できたかなと思います。

デフォルト値を確認する

デフォルト値も確認してみましょう。デフォルトでは、CPU数から1引いた数のワーカー数になるという話でした。

今回の動作環境のCPU数は8なので、8ファイル用意するとひとつだけ同じプロセスになって実行時間が2倍になるはずですね。

ファイルを増やしてみます。

$ for ((i=4; i < 9; i++)) do cp test/test1.test.ts test/test${i}.test.ts; done
$ ls -1 test
test1.test.ts
test2.test.ts
test3.test.ts
test4.test.ts
test5.test.ts
test6.test.ts
test7.test.ts
test8.test.ts

確認。

$ npx jest

結果。

$ npx jest
 PASS  test/test1.test.ts
  ● Console

    console.log
      [test1.test.ts] jest worker id = 6, pid = 20083, path = node_modules/jest-worker/build/workers/processChild.js

      at Object.<anonymous> (test/test1.test.ts:7:11)

    console.log
      [test1.test.ts] jest worker id = 6, pid = 20083, path = node_modules/jest-worker/build/workers/processChild.js

      at Object.<anonymous> (test/test1.test.ts:13:11)

 PASS  test/test2.test.ts
  ● Console

    console.log
      [test2.test.ts] jest worker id = 7, pid = 20099, path = node_modules/jest-worker/build/workers/processChild.js

      at Object.<anonymous> (test/test2.test.ts:7:11)

    console.log
      [test2.test.ts] jest worker id = 7, pid = 20099, path = node_modules/jest-worker/build/workers/processChild.js

      at Object.<anonymous> (test/test2.test.ts:13:11)

 PASS  test/test6.test.ts
  ● Console

    console.log
      [test6.test.ts] jest worker id = 3, pid = 20056, path = node_modules/jest-worker/build/workers/processChild.js

      at Object.<anonymous> (test/test6.test.ts:7:11)

    console.log
      [test6.test.ts] jest worker id = 3, pid = 20056, path = node_modules/jest-worker/build/workers/processChild.js

      at Object.<anonymous> (test/test6.test.ts:13:11)

 PASS  test/test7.test.ts
  ● Console

    console.log
      [test7.test.ts] jest worker id = 2, pid = 20055, path = node_modules/jest-worker/build/workers/processChild.js

      at Object.<anonymous> (test/test7.test.ts:7:11)

    console.log
      [test7.test.ts] jest worker id = 2, pid = 20055, path = node_modules/jest-worker/build/workers/processChild.js

      at Object.<anonymous> (test/test7.test.ts:13:11)

 PASS  test/test8.test.ts
  ● Console

    console.log
      [test8.test.ts] jest worker id = 1, pid = 20054, path = node_modules/jest-worker/build/workers/processChild.js

      at Object.<anonymous> (test/test8.test.ts:7:11)

    console.log
      [test8.test.ts] jest worker id = 1, pid = 20054, path = node_modules/jest-worker/build/workers/processChild.js

      at Object.<anonymous> (test/test8.test.ts:13:11)

 PASS  test/test4.test.ts
  ● Console

    console.log
      [test4.test.ts] jest worker id = 5, pid = 20074, path = node_modules/jest-worker/build/workers/processChild.js

      at Object.<anonymous> (test/test4.test.ts:7:11)

    console.log
      [test4.test.ts] jest worker id = 5, pid = 20074, path = node_modules/jest-worker/build/workers/processChild.js

      at Object.<anonymous> (test/test4.test.ts:13:11)

 PASS  test/test5.test.ts
  ● Console

    console.log
      [test5.test.ts] jest worker id = 4, pid = 20068, path = node_modules/jest-worker/build/workers/processChild.js

      at Object.<anonymous> (test/test5.test.ts:7:11)

    console.log
      [test5.test.ts] jest worker id = 4, pid = 20068, path = node_modules/jest-worker/build/workers/processChild.js

      at Object.<anonymous> (test/test5.test.ts:13:11)

 PASS  test/test3.test.ts
  ● Console

    console.log
      [test3.test.ts] jest worker id = 6, pid = 20083, path = node_modules/jest-worker/build/workers/processChild.js

      at Object.<anonymous> (test/test3.test.ts:7:11)

    console.log
      [test3.test.ts] jest worker id = 6, pid = 20083, path = node_modules/jest-worker/build/workers/processChild.js

      at Object.<anonymous> (test/test3.test.ts:13:11)


Test Suites: 8 passed, 8 total
Tests:       16 passed, 16 total
Snapshots:   0 total
Time:        9.143 s
Ran all test suites.

今回は、test1.test.tstest3.test.tsが同じワーカーになりました。

 PASS  test/test1.test.ts
  ● Console

    console.log
      [test1.test.ts] jest worker id = 6, pid = 20083, path = node_modules/jest-worker/build/workers/processChild.js

      at Object.<anonymous> (test/test1.test.ts:7:11)

    console.log
      [test1.test.ts] jest worker id = 6, pid = 20083, path = node_modules/jest-worker/build/workers/processChild.js

      at Object.<anonymous> (test/test1.test.ts:13:11)


 PASS  test/test3.test.ts
  ● Console

    console.log
      [test3.test.ts] jest worker id = 6, pid = 20083, path = node_modules/jest-worker/build/workers/processChild.js

      at Object.<anonymous> (test/test3.test.ts:7:11)

    console.log
      [test3.test.ts] jest worker id = 6, pid = 20083, path = node_modules/jest-worker/build/workers/processChild.js

      at Object.<anonymous> (test/test3.test.ts:13:11)

ソースコードから確認してみる

ソースコードも少し見てみましょう。

ワーカー数のデフォルト値を決めているのは、このあたりのようですね。

https://github.com/jestjs/jest/blob/v29.7.0/packages/jest-repl/src/cli/runtime-cli.ts#L83

--watchでCPU数の半分になるというのは、こちらですね。

https://github.com/jestjs/jest/blob/v29.7.0/packages/jest-config/src/getMaxWorkers.ts#L38

--maxWorkers--runInBandの解釈はこのあたりです。

https://github.com/jestjs/jest/blob/v29.7.0/packages/jest-config/src/getMaxWorkers.ts#L27-L32

こう見ると、--runInBand--maxWorkers=1が同義なこともわかりますね。

ワーカーによるテストの実行はこちら。

https://github.com/jestjs/jest/blob/v29.7.0/packages/jest-runner/src/testWorker.ts#L88-L108

そこからテストコードを読み込んで実行しているのは、このあたりですね。

jest/packages/jest-runner/src/runTest.ts at v29.7.0 · jestjs/jest · GitHub

今回は見ていませんが、テストの並行実行についてはこのあたりを見るとよさそうです。

https://github.com/jestjs/jest/blob/v29.7.0/packages/jest-circus/src/run.ts#L137-L158

おわりに

CPU数次第ですが、Jestでテストが並列に実行されることを確認してみました。

遊んでいる時はファイル数が少なかったり、あまり意識したりしていなかったので、あらためて見返してメモ的に書いておきました。
こうすると思い出しやすいでしょう、的な。

それにしても、こういう動作だとデータベースといった、共有リソースの操作には気をつけないといけないということですね。