「テストが遅い・不安定」の正体はテストではなかった — Vitest の testTimeout に何が課金されているか

7600 件ほどのテストがある Vitest のスイートで、ときどき赤くなるテストがありました。「フルスイートだと 4 件落ちるが、単体で走らせると通る。もう一度フルスイートを回すと今度は全部通る」という、いかにも順序依存っぽい壊れ方です。

結論から書くと、4 件見つかった原因のどれも「テストの仕事」ではありませんでした。テストの実行時間として計測され、testTimeout に課金されていたのは、ソケットの往復・モジュールの読み込み・並列時のディスク競合・使っていない DOM 環境の構築でした。テスト自体は速いままです。

同じ勘違いをしやすいと思うので、切り分けの手順と 4 件の中身を残しておきます。

まず「状態汚染」を消す

最初の症状を見たとき、真っ先に疑ったのは他の spec からの状態汚染でした。ここは推測せずに確かめられます。

Vitest の isolate は既定で true です。実際に 2 つの spec ファイルに process.pid を出力させて走らせると、PID が違います。globalThis も共有されません。

PID-B 29441 GLOBAL undefined
PID-A 29500 GLOBAL undefined

つまり spec ファイルごとに別プロセスで、他の spec がこちらのモジュール状態・env・cwd に触ることは仕組み上できません。--sequence.shuffle.files を 6 シード回しても、当該 spec は一度も落ちませんでした。

順序依存の線が消えると、残るのは「時間」しかありません。 ここから先は全部、時間の計測の話になります。

犯人 1: ソケットの往復

決め手は、実は最初のバグ報告そのものに書いてありました。

問題のファイルは 11 テストで、内訳は 純粋な関数を叩く 6 件 と fetch で実サーバを叩く 5 件。落ちた回、純粋な 6 件は全部通り、実サーバ側の 5 件中 4 件が落ちていました。同じファイル・同じプロセス・同じ瞬間です。2 つのグループの違いは、TCP のラウンドトリップを通るかどうかだけでした。

このテストが検証していたのは Express のミドルウェアで、その中身は正規表現と path.resolve の比較だけの決定的な処理です。それを確かめるために、毎回 app.listen(0) で本物のサーバを立て、ポートを読み、fetch を投げていました。ラウンドトリップは純粋な assertion に比べて event loop の回転を桁違いに必要とします。 ランナーが混んだ瞬間の犠牲者になるのは、いつもこちらです。

ソケットをやめて、プロセス内で Express を叩くようにしました。fastify の light-my-request を薄く包むだけです。

export function appRequest(app: Express) {
  return async (url: string, init: AppRequestInit = {}): Promise<Response> => {
    const res = await inject(app, {
      method: init.method ?? "GET",
      url,
      ...(init.headers ? { headers: init.headers } : {}),
      ...(init.body === undefined ? {} : { payload: init.body }),
    });
    const body = BODYLESS_STATUSES.has(res.statusCode) ? null : res.rawPayload;
    return new Response(body, { status: res.statusCode, headers: toHeaders(res.headers) });
  };
}

返すのは本物の Response にしました。こうすると status / headers.get() / json() / arrayBuffer() が今までの fetch と同じに読めるので、各 spec の assertion は原則そのまま移せます。ハンドラチェーンは本物のまま（express.json()、ルーティング、静的配信、Range の 206 / 416）で、ソケットだけがメモリ上になります。

同じ形をしていた 13 spec を移行しました。1 ファイルだけ移行していません。子プロセスを spawn して、その子が HTTP で繋いでくる spec です。あれは実際に listen しているサーバが要ります。

ハマりどころ: new Response(body, { status }) は 200〜599 の外を拒否します。「ボディを持てないステータス」として 101 や 103 を並べても、RangeError になるだけで扱えません。実際に扱えるのは 204 / 205 / 304 の 3 つです。

犯人 2: モジュールの読み込み

別のファイルでは「ローカルでは決定的に 15 秒でタイムアウトするのに、CI は green」という報告が来ていました。

スイート全体で 300ms を超えるテストを実測して並べたところ、妙な形が見えました。同じファイルの中で最初の 1 本だけ 2453ms、残り 30 本は 2〜10ms。その 1 本を計測器で割ると、こうです。

import=2132ms  mount=18ms  flush=2ms

2.4 秒の正体は await import("…/GridView.vue") でした。テスト本体（や it が await するヘルパ）の中でコンポーネントを import すると、そのモジュールグラフ全体の transform が走ります。キャッシュされるので払うのは一度きりですが、払わされるのはそのファイルで最初に走ったテストで、しかもそれが testTimeout に課金されます。

「ローカルだけ決定的に落ちる」理由もこれで説明がつきます。transform キャッシュはメインプロセスで spec ファイル間に共有されます。単体実行では対象のモジュール群を冷えた状態から全部払うので最初のテストが極端に重くなり、フルスイートでは他の spec が先に温めるので間に合ってしまう、という差です。

直し方は、モジュールスコープで一度だけ読むだけです。

// At module scope, not inside a test. Measured on this file: the import was 2132ms while the
// mount it feeds was 18ms — so the first test to run was billed two seconds of module loading
// against `testTimeout`, and on a loaded runner that is what crossed 15s. Collection
// has no per-test budget, so the same work costs nothing here.
const GridView = (await import("../../../src/components/GridView.vue")).default;

collection フェーズにはテストごとの予算がないので、同じ仕事がタダになります。効果は分かりやすく出ました（各ファイルの最遅テスト）。

この 4 本だけで 27.5 秒が約 0.1 秒になりました。ちなみに 11 秒だった cellChromeColors は、15 秒の上限まで残り 4 秒。次に CI を赤くするのはこれでした。

例外がひとつあります。 vi.doMock と vi.resetModules はホイストされないので、後から import しないとモックが効きません。それらの spec は意図的にテスト内 import のままにしておく必要があります（vi.mock はホイストされるので関係ありません）。一律に「テスト内 import は禁止」と直すと壊れます。

犯人 3: 並列時のディスク競合

3 つめは、601 個のファイルを作って全部読み返す規模テストです。フルスイートでは 5.4 秒と 9.7 秒かかっていました。

ここも中身を割って測ると、犯人は製品コードではありませんでした。

setup(write 601 files)=60ms  sweep=208ms  perFile=0.35ms

単体なら 271ms です。フルスイートでは約 19 ワーカーが同じディスクを取り合うので、20〜36 倍に伸びていました。テストのロジックが遅いのでも、製品コードが遅いのでもありません。

これは「速くする」問題ではなく「正しく予算を与える」問題だと判断して、このテストにだけ明示的な testTimeout を与えました。601 という数はこのテストの主張そのものなので、そこは減らしていません。

大事なのは、なぜその数字なのかをコメントに残すことです。数字だけ置くと、次の人が「なんとなく」動かせてしまいます。

// A per-test timeout, not the 15s baseline. This test writes 601 files and the sweep reads all
// 601 back, and that 1200-operation floor is REAL disk rather than work this process controls:
// alone it costs 271ms (setup 60ms, sweep 208ms — 0.35ms/file, so the sweep itself is not slow),
// but under the full suite ~19 workers share one disk and the same test took 5.4s and 9.7s on
// two samples. Kept at 601 deliberately: the count is the claim this test makes.
it("gets through a directory of many transcripts", async () => { /* ... */ }, 60_000);

犯人 4: 使っていない jsdom

最後は毛色が違って、フレークではなく純粋な無駄です。

vitest.config.ts の environment は "jsdom" にしてありました。DOM を使うフロントエンドの spec にはそれで正しいのですが、サーバー側の spec 285 本のうち 153 本が、fs と子プロセスしか触らないのに jsdom を立てていました。132 本は既に // @vitest-environment node を宣言済みで、残りが漏れていただけです。

30 本を抜き出して比べると、こうなりました（テスト結果はどちらも 476 passed で同一）。

environment はワーカー合計の CPU 時間です。1 ファイルあたり約 1.1 秒、153 本で約 170 秒を捨てていました。直すのは 1 行です。

// @vitest-environment node
import { describe, it, expect } from "vitest";

ここで注意したこと: DOM 系の語（window、document など）を含む 22 本は個別に確認しました。結果は全部散文中の単語でした。tmux の “window”、レート制限の “window”、コメント中の “document”。grep の結果を機械的に信じて除外していたら、直せるものを取りこぼしていたところです。

測るときのコツ

最後に、この作業で効いた計測の話を 2 つだけ。

Vitest のサマリ行を読む。 Duration の内訳に出る transform / import / environment / tests は、それぞれ別の犯人を指します。今回で言えば犯人 2 は import、犯人 4 は environment に出ていました。tests だけ見ていると「テストは速いのに全体が遅い」で止まります。

手元のコア数で判断しない。 20 コアのマシンでは、削った CPU が並列に吸収されて wall-clock がほとんど動きません。GitHub Actions のコア数に近い --maxWorkers=4 で測り直すと、Duration の中央値が 84.30s → 62.88s になりました。CI で効くかどうかは、CI に近い条件で測らないと分かりません。

「マシンが混んでいたから」で片付けたくなる場面は多いのですが、その一言を言う前に、テストの時間として計上されているものの内訳を一度割ってみる価値はありました。4 件のうち 3 件は、割った瞬間に犯人が出てきました。