perf(test): add timing telemetry, cold-start probe, and baseline snapshot
- ci-test-shard.mjs: --write-timings aggregation into scripts/test-timings.json (bucketed, newer-snapshot-protected, corrupt-shard tolerant) and --cold-start-probe; CI shard invocations emit vitest json timings - test-changed.mjs: structured mode/reason telemetry line (+ --print-mode) - pr-checks.yml: upload per-shard timing artifacts - baseline: docs/test-speed-baseline-2026-06-03.md (core 41s, engine 179s, cli 49s; cold-start ~1.3-1.8s/process => U8 gate: worthwhile-not-urgent)
This commit is contained in:
gsxdsm
14
.github/workflows/pr-checks.yml
vendored
14
.github/workflows/pr-checks.yml
vendored
@@ -85,3 +85,17 @@ jobs:
|
||||
|
||||
- name: Test (deterministic shard)
|
||||
run: pnpm test:ci:shard --shard ${{ matrix.shard }} --total 4
|
||||
|
||||
# U1 (R4): each shard emits per-file vitest JSON timing reporter output
|
||||
# under .timings/. Upload as an artifact so the timing snapshot can be
|
||||
# refreshed locally/from the default branch via
|
||||
# `node scripts/ci-test-shard.mjs --write-timings`. We do NOT commit the
|
||||
# snapshot from PR branches — refresh is manual/scheduled only.
|
||||
- name: Upload per-shard test timings
|
||||
if: always()
|
||||
uses: actions/upload-artifact@v4
|
||||
with:
|
||||
name: test-timings-shard-${{ matrix.shard }}
|
||||
path: .timings/timings-*.json
|
||||
if-no-files-found: ignore
|
||||
retention-days: 14
|
||||
|
||||
4
.gitignore
vendored
4
.gitignore
vendored
@@ -77,3 +77,7 @@ fusion.db-shm
|
||||
# Capacitor mobile platform directories (generated by `cap add`)
|
||||
packages/dashboard/ios/
|
||||
packages/dashboard/android/
|
||||
|
||||
# Per-shard vitest JSON timing reporter outputs (raw; merged into
|
||||
# scripts/test-timings.json via `ci-test-shard.mjs --write-timings`).
|
||||
.timings/
|
||||
|
||||
@@ -1,5 +1,7 @@
|
||||
# FN-5048 Test-Speed Audit
|
||||
|
||||
> **Refreshed baseline (2026-06-03):** see `docs/test-speed-baseline-2026-06-03.md` for the U1 machine-readable per-file timing snapshot, refreshed top-10 offenders, and the cold-start/transform-cost probe feeding the U8 vitest-4 gate.
|
||||
|
||||
## Scope and method
|
||||
- Related baseline context:
|
||||
- `docs/test-audit-report.md` (prior workspace test audit baseline)
|
||||
|
||||
149
docs/test-speed-baseline-2026-06-03.md
Normal file
149
docs/test-speed-baseline-2026-06-03.md
Normal file
@@ -0,0 +1,149 @@
|
||||
# Test-Speed Baseline — 2026-06-03 (U1 refresh)
|
||||
|
||||
Successor to `docs/test-speed-audit-FN-5048.md`. This baseline is captured from the
|
||||
machine-readable per-file timing telemetry added in U1 of
|
||||
`docs/plans/2026-06-03-001-perf-test-suite-speedup-plan.md`. It feeds the U6
|
||||
(duration-based sharding), U7 (slow-test triage), and U8 (vitest 4.x gate)
|
||||
decisions.
|
||||
|
||||
## Method
|
||||
|
||||
- Per-file durations come from vitest's `--reporter=json` output
|
||||
(`endTime − startTime` per test file), merged into `scripts/test-timings.json`
|
||||
via `node scripts/ci-test-shard.mjs --write-timings`.
|
||||
- Cold-start overhead comes from `node scripts/ci-test-shard.mjs --cold-start-probe <pkg>`,
|
||||
which runs one cheap test file and reports `wallClock − sum(testDurations)`.
|
||||
- Worker caps were left at defaults (no `FUSION_TEST_*` / `VITEST_MAX_WORKERS`
|
||||
overrides), per FN-5048.
|
||||
- Capture invocations (one per package/lane):
|
||||
- `pnpm --filter @fusion/core exec vitest run --silent=passed-only --reporter=dot --reporter=json --outputFile.json=...`
|
||||
- `pnpm --filter @fusion/engine exec vitest run ... --project=engine-default --project=engine-reliability`
|
||||
- `pnpm --filter @runfusion/fusion exec vitest run ...`
|
||||
- dashboard curated lanes via `run-vitest-with-heap.mjs` for
|
||||
`dashboard-api-quality` and `dashboard-app-quality-components-a`
|
||||
(the dashboard `test` script is a 14-lane chain; two representative lanes
|
||||
were captured for the snapshot — a full lane sweep is a follow-up).
|
||||
|
||||
Note: per-file durations are summed wall-clock per file; because files run in
|
||||
parallel, the **sum across files exceeds the run wall-clock**. The per-file
|
||||
numbers are correct for *relative ranking* (which file is heaviest), which is
|
||||
what U6/U7 consume. The "run wall-clock" column below is the real elapsed time.
|
||||
|
||||
## Per-package run totals (wall-clock, this capture)
|
||||
|
||||
| Package | Run wall-clock | Test files | Σ per-file (parallel) | Notes |
|
||||
|---|---:|---:|---:|---|
|
||||
| `@fusion/core` | **41.1s** | 264 | 185.2s | default project |
|
||||
| `@fusion/engine` | **178.7s** | 521 | 273.3s | engine-default + engine-reliability |
|
||||
| `@runfusion/fusion` (cli) | **48.9s** | 92 | 32.0s | default project |
|
||||
| `@fusion/dashboard` (api-quality lane) | 46.7s | 58 | — | one curated lane |
|
||||
| `@fusion/dashboard` (app components-a lane) | 27.6s | 44 | — | one curated lane |
|
||||
|
||||
Snapshot (`scripts/test-timings.json`) `capturedAt`: `2026-06-03T23:45:49Z`,
|
||||
covering 4 packages.
|
||||
|
||||
For context, the prior FN-5048 baseline measured core ~26s, engine ~93s,
|
||||
cli ~14s, dashboard ~360s (full multi-project). These were captured on a
|
||||
different machine/load; treat the two baselines as independent snapshots, not a
|
||||
trend line. Engine and core are larger here because the executed test inventory
|
||||
has grown (engine now 521 files across default+reliability).
|
||||
|
||||
## Top-10 slowest files per major package
|
||||
|
||||
(Σ per-file wall-clock, bucketed to 100ms in the snapshot.)
|
||||
|
||||
### @fusion/core
|
||||
| File | Σ duration |
|
||||
|---|---:|
|
||||
| src/__tests__/agent-store.test.ts | 11.6s |
|
||||
| src/__tests__/mission-store.test.ts | 10.7s |
|
||||
| src/__tests__/db.test.ts | 10.1s |
|
||||
| src/__tests__/task-documents.test.ts | 8.3s |
|
||||
| src/__tests__/run-audit.test.ts | 6.9s |
|
||||
| src/__tests__/store-merge-queue.test.ts | 5.2s |
|
||||
| src/__tests__/mission-integration.test.ts | 4.8s |
|
||||
| src/__tests__/run-audit.integration.test.ts | 4.6s |
|
||||
| src/__tests__/plugin-loader.test.ts | 4.5s |
|
||||
| src/__tests__/mission-factory-parity.integration.test.ts | 4.2s |
|
||||
|
||||
### @fusion/engine
|
||||
| File | Σ duration |
|
||||
|---|---:|
|
||||
| src/__tests__/reliability-interactions/shared-branch-group-lifecycle.test.ts | 13.9s |
|
||||
| src/__tests__/reliability-interactions/branch-group-automerge-precedence.test.ts | 9.0s |
|
||||
| src/__tests__/merger-ai.test.ts | 8.7s |
|
||||
| src/__tests__/reliability-interactions/branch-group-merge-routing.test.ts | 8.4s |
|
||||
| src/__tests__/reliability-interactions/branch-group-promotion-gate.test.ts | 8.4s |
|
||||
| src/runtimes/__tests__/in-process-runtime.test.ts | 7.8s |
|
||||
| src/__tests__/reliability-interactions/branch-group-promotion.test.ts | 6.1s |
|
||||
| src/__tests__/reliability-interactions/integration-worktree-state.test.ts | 4.9s |
|
||||
| src/__tests__/self-healing-already-merged.real-git.test.ts | 4.9s |
|
||||
| src/__tests__/branch-conflicts-recovery.test.ts | 4.5s |
|
||||
|
||||
### @runfusion/fusion (cli)
|
||||
| File | Σ duration |
|
||||
|---|---:|
|
||||
| src/__tests__/extension.test.ts | 7.0s |
|
||||
| src/commands/__tests__/init.test.ts | 3.4s |
|
||||
| src/__tests__/bin.test.ts | 3.2s |
|
||||
| src/__tests__/extension-task-tools.test.ts | 1.7s |
|
||||
| src/commands/dashboard-tui/__tests__/app.test.tsx | 1.6s |
|
||||
| src/__tests__/vitest-workspace-resolution.test.ts | 1.4s |
|
||||
| src/commands/__tests__/chat.test.ts | 1.3s |
|
||||
| src/__tests__/research-extension-tools.test.ts | 1.1s |
|
||||
| src/__tests__/extension-github-tracking.test.ts | 0.5s |
|
||||
| src/commands/__tests__/dashboard.test.ts | 0.5s |
|
||||
|
||||
### @fusion/dashboard (captured curated lanes)
|
||||
| File | Σ duration |
|
||||
|---|---:|
|
||||
| src/__tests__/routes-agents.test.ts | 11.2s |
|
||||
| src/__tests__/routes-git.test.ts | 9.4s |
|
||||
| src/__tests__/routes-planning.test.ts | 5.6s |
|
||||
| app/components/__tests__/FileEditor.test.tsx | 5.1s |
|
||||
| app/components/__tests__/NewTaskModal.test.tsx | 3.4s |
|
||||
| app/components/__tests__/ChatView.rooms.test.tsx | 2.8s |
|
||||
| src/__tests__/routes-github.test.ts | 2.8s |
|
||||
| src/__tests__/setup-routes.test.ts | 2.6s |
|
||||
| src/__tests__/routes-secrets-sync.test.ts | 2.5s |
|
||||
| src/__tests__/websocket.test.ts | 2.1s |
|
||||
|
||||
## Cold-start / transform-cost probe (U8 gate input)
|
||||
|
||||
`overhead = wallClock − sum(per-file test durations)` for a single cheap test file.
|
||||
|
||||
| Package | Probe file | Wall | Test time | Overhead |
|
||||
|---|---|---:|---:|---:|
|
||||
| `@fusion/engine` | src/__tests__/pi.test.ts | 1843ms | 23ms | **1820ms** |
|
||||
| `@fusion/core` | src/__tests__/db.test.ts | 13944ms | 12337ms | 1607ms |
|
||||
| `@fusion/dashboard` | src/__tests__/sse.test.ts | 1349ms | 24ms | **1325ms** |
|
||||
| `@runfusion/fusion` (cli) | src/__tests__/bin.test.ts | 6292ms | 5354ms | 938ms |
|
||||
|
||||
The cleanest signals are engine and dashboard, where the probe file's own test
|
||||
time is ~24ms so almost all wall-clock is startup: **~1.3–1.8s of fixed
|
||||
per-process overhead** (vitest boot + transform + collect + worker spawn). The
|
||||
engine run breakdown confirms this is dominated by transform (~0.8s) and collect
|
||||
(~1.0s). The core/cli probes auto-selected heavier files (path-length heuristic,
|
||||
not runtime), so their overhead figure is conservative but consistent (~0.9–1.6s).
|
||||
|
||||
## Conclusion — U8 gate signal
|
||||
|
||||
Fixed per-process startup/transform overhead is **~1.3–1.8s per vitest
|
||||
invocation**. In the inner loop (one or two packages) and full per-package runs
|
||||
this is a small fraction of total wall-clock (engine 178s, core 41s), so it is
|
||||
**not the top contributor** for those paths. However, the repo runs **~25
|
||||
separate vitest processes** across packages, plugins, and the dashboard's 14-lane
|
||||
chain; at ~1.5s each that is **~35–40s of pure cold-start tax aggregated across a
|
||||
full CI/`test:full` sweep**, paid on every run with no cross-process sharing in
|
||||
vitest 3.2.
|
||||
|
||||
Read against the U8 gate ("is cold-start/transform cost a top contributor
|
||||
blocking the targets?"): for single-package inner-loop runs, **no** — wall-clock
|
||||
is dominated by individual heavy integration tests (engine branch-group/real-git
|
||||
suites, core stores, dashboard route suites), which U7 triage targets. For the
|
||||
aggregate full-suite/CI path the cold-start tax is **material but second-order**
|
||||
(~10% of full-suite wall-clock), making the vitest-4 `fsModuleCache` upgrade a
|
||||
**worthwhile-but-not-urgent** lever — recommend proceeding with U3 (overhead
|
||||
trim), U5 (config tuning), U6 (duration sharding), and U7 (slow-test triage)
|
||||
first, then re-evaluating the U8 gate once those land, since they shrink both the
|
||||
per-process count and the heavy-test tail that currently dominate.
|
||||
205
scripts/__tests__/ci-test-shard-timings.test.mjs
Normal file
205
scripts/__tests__/ci-test-shard-timings.test.mjs
Normal file
@@ -0,0 +1,205 @@
|
||||
/**
|
||||
* Unit tests for the U1 timing-telemetry aggregation built into
|
||||
* scripts/ci-test-shard.mjs.
|
||||
*
|
||||
* Runner: node --test scripts/__tests__/ci-test-shard-timings.test.mjs
|
||||
*/
|
||||
|
||||
import test from "node:test";
|
||||
import assert from "node:assert/strict";
|
||||
import { mkdtempSync, mkdirSync, writeFileSync, readFileSync, rmSync } from "node:fs";
|
||||
import { tmpdir } from "node:os";
|
||||
import path from "node:path";
|
||||
|
||||
import {
|
||||
bucketDuration,
|
||||
attributeTestFile,
|
||||
extractFileDurations,
|
||||
buildTimingsSnapshot,
|
||||
writeTimings,
|
||||
TIMINGS_SNAPSHOT_RELATIVE,
|
||||
} from "../ci-test-shard.mjs";
|
||||
|
||||
const PACKAGES = [
|
||||
{ name: "@fusion/core", dir: "packages/core" },
|
||||
{ name: "@fusion/engine", dir: "packages/engine" },
|
||||
];
|
||||
|
||||
function makeReport(projectRoot, files) {
|
||||
// files: Array<{ rel: string, durationMs: number }>
|
||||
return {
|
||||
testResults: files.map(({ rel, durationMs }) => ({
|
||||
name: path.join(projectRoot, rel),
|
||||
startTime: 1000,
|
||||
endTime: 1000 + durationMs,
|
||||
assertionResults: [],
|
||||
})),
|
||||
};
|
||||
}
|
||||
|
||||
function tmpRoot() {
|
||||
return mkdtempSync(path.join(tmpdir(), "fusion-timings-test-"));
|
||||
}
|
||||
|
||||
test("bucketDuration rounds to nearest 100ms, floors non-zero to one bucket", () => {
|
||||
assert.equal(bucketDuration(0), 0);
|
||||
assert.equal(bucketDuration(40), 100); // sub-bucket non-zero floors up
|
||||
assert.equal(bucketDuration(149), 100);
|
||||
assert.equal(bucketDuration(150), 200);
|
||||
assert.equal(bucketDuration(1234), 1200);
|
||||
assert.equal(bucketDuration(-5), 0);
|
||||
});
|
||||
|
||||
test("attributeTestFile maps absolute paths to owning package, repo-relative", () => {
|
||||
const root = "/repo";
|
||||
const got = attributeTestFile("/repo/packages/core/src/__tests__/a.test.ts", PACKAGES, root);
|
||||
assert.deepEqual(got, { pkg: "@fusion/core", file: "packages/core/src/__tests__/a.test.ts" });
|
||||
assert.equal(attributeTestFile("/repo/tools/x.test.ts", PACKAGES, root), null);
|
||||
});
|
||||
|
||||
test("extractFileDurations sums per-file durations and tolerates bad rows", () => {
|
||||
const root = "/repo";
|
||||
const report = {
|
||||
testResults: [
|
||||
{ name: "/repo/packages/core/a.test.ts", startTime: 0, endTime: 250 },
|
||||
{ name: "/repo/packages/core/a.test.ts", startTime: 250, endTime: 500 }, // same file, summed
|
||||
{ name: "/repo/packages/engine/b.test.ts", startTime: 0, endTime: 700 },
|
||||
{ name: 42, startTime: 0, endTime: 1 }, // bad name
|
||||
{ name: "/repo/packages/core/c.test.ts", startTime: 500, endTime: 100 }, // end<start ignored
|
||||
{ name: "/repo/outside/d.test.ts", startTime: 0, endTime: 5 }, // unattributable
|
||||
],
|
||||
};
|
||||
const byPkg = extractFileDurations(report, PACKAGES, root);
|
||||
assert.equal(byPkg.get("@fusion/core").get("packages/core/a.test.ts"), 500);
|
||||
assert.equal(byPkg.get("@fusion/engine").get("packages/engine/b.test.ts"), 700);
|
||||
assert.ok(!byPkg.get("@fusion/core").has("packages/core/c.test.ts"));
|
||||
});
|
||||
|
||||
test("buildTimingsSnapshot merges two shard JSON fixtures, sums per file, buckets", () => {
|
||||
const root = tmpRoot();
|
||||
try {
|
||||
const f1 = path.join(root, "s1.json");
|
||||
const f2 = path.join(root, "s2.json");
|
||||
writeFileSync(f1, JSON.stringify(makeReport(root, [
|
||||
{ rel: "packages/core/src/__tests__/a.test.ts", durationMs: 240 },
|
||||
{ rel: "packages/engine/src/__tests__/b.test.ts", durationMs: 1010 },
|
||||
])));
|
||||
writeFileSync(f2, JSON.stringify(makeReport(root, [
|
||||
// same file as f1 → durations sum across shards before bucketing
|
||||
{ rel: "packages/core/src/__tests__/a.test.ts", durationMs: 60 },
|
||||
])));
|
||||
|
||||
const snap = buildTimingsSnapshot([f1, f2], { projectRoot: root, packages: PACKAGES, capturedAt: "2026-06-03T00:00:00.000Z" });
|
||||
assert.equal(snap.capturedAt, "2026-06-03T00:00:00.000Z");
|
||||
// 240 + 60 = 300 → bucketed to 300
|
||||
assert.equal(snap.packages["@fusion/core"].files["packages/core/src/__tests__/a.test.ts"], 300);
|
||||
// 1010 → 1000
|
||||
assert.equal(snap.packages["@fusion/engine"].files["packages/engine/src/__tests__/b.test.ts"], 1000);
|
||||
} finally {
|
||||
rmSync(root, { recursive: true, force: true });
|
||||
}
|
||||
});
|
||||
|
||||
test("buildTimingsSnapshot tolerates a corrupt shard file: skips it, keeps others", () => {
|
||||
const root = tmpRoot();
|
||||
try {
|
||||
const good = path.join(root, "good.json");
|
||||
const bad = path.join(root, "bad.json");
|
||||
writeFileSync(good, JSON.stringify(makeReport(root, [
|
||||
{ rel: "packages/core/x.test.ts", durationMs: 300 },
|
||||
])));
|
||||
writeFileSync(bad, "{not valid json");
|
||||
|
||||
const snap = buildTimingsSnapshot([bad, good, path.join(root, "missing.json")], {
|
||||
projectRoot: root,
|
||||
packages: PACKAGES,
|
||||
capturedAt: "2026-06-03T00:00:00.000Z",
|
||||
});
|
||||
assert.equal(snap.packages["@fusion/core"].files["packages/core/x.test.ts"], 300);
|
||||
} finally {
|
||||
rmSync(root, { recursive: true, force: true });
|
||||
}
|
||||
});
|
||||
|
||||
test("buildTimingsSnapshot omits a zero-test package entirely (no zero entry)", () => {
|
||||
const root = tmpRoot();
|
||||
try {
|
||||
const f = path.join(root, "s.json");
|
||||
writeFileSync(f, JSON.stringify(makeReport(root, [
|
||||
{ rel: "packages/core/y.test.ts", durationMs: 200 },
|
||||
])));
|
||||
const snap = buildTimingsSnapshot([f], { projectRoot: root, packages: PACKAGES, capturedAt: "2026-06-03T00:00:00.000Z" });
|
||||
assert.ok(snap.packages["@fusion/core"]);
|
||||
assert.ok(!("@fusion/engine" in snap.packages));
|
||||
} finally {
|
||||
rmSync(root, { recursive: true, force: true });
|
||||
}
|
||||
});
|
||||
|
||||
test("writeTimings writes snapshot to scripts/test-timings.json under a project root", () => {
|
||||
const root = tmpRoot();
|
||||
try {
|
||||
const inputDir = path.join(root, ".timings");
|
||||
mkdirSync(inputDir, { recursive: true });
|
||||
writeFileSync(path.join(inputDir, "timings-shard1-0.json"), JSON.stringify(makeReport(root, [
|
||||
{ rel: "packages/core/z.test.ts", durationMs: 500 },
|
||||
])));
|
||||
const snapshotPath = path.join(root, TIMINGS_SNAPSHOT_RELATIVE);
|
||||
const result = writeTimings({
|
||||
projectRoot: root,
|
||||
inputDir,
|
||||
snapshotPath,
|
||||
packages: PACKAGES,
|
||||
capturedAt: "2026-06-03T00:00:00.000Z",
|
||||
});
|
||||
assert.equal(result.written, true);
|
||||
const written = JSON.parse(readFileSync(snapshotPath, "utf8"));
|
||||
assert.equal(written.packages["@fusion/core"].files["packages/core/z.test.ts"], 500);
|
||||
} finally {
|
||||
rmSync(root, { recursive: true, force: true });
|
||||
}
|
||||
});
|
||||
|
||||
test("writeTimings refuses to overwrite a newer snapshot", () => {
|
||||
const root = tmpRoot();
|
||||
try {
|
||||
const inputDir = path.join(root, ".timings");
|
||||
mkdirSync(inputDir, { recursive: true });
|
||||
writeFileSync(path.join(inputDir, "timings-shard1-0.json"), JSON.stringify(makeReport(root, [
|
||||
{ rel: "packages/core/z.test.ts", durationMs: 500 },
|
||||
])));
|
||||
const snapshotPath = path.join(root, "snap.json");
|
||||
// Existing snapshot dated in the future.
|
||||
writeFileSync(snapshotPath, JSON.stringify({ capturedAt: "2999-01-01T00:00:00.000Z", packages: { keep: { files: {} } } }));
|
||||
|
||||
const result = writeTimings({
|
||||
projectRoot: root,
|
||||
inputDir,
|
||||
snapshotPath,
|
||||
packages: PACKAGES,
|
||||
capturedAt: "2026-06-03T00:00:00.000Z",
|
||||
});
|
||||
assert.equal(result.written, false);
|
||||
assert.equal(result.reason, "newer-snapshot");
|
||||
// Original untouched.
|
||||
const after = JSON.parse(readFileSync(snapshotPath, "utf8"));
|
||||
assert.equal(after.capturedAt, "2999-01-01T00:00:00.000Z");
|
||||
} finally {
|
||||
rmSync(root, { recursive: true, force: true });
|
||||
}
|
||||
});
|
||||
|
||||
test("writeTimings warns and does not write when there are no input files", () => {
|
||||
const root = tmpRoot();
|
||||
try {
|
||||
const result = writeTimings({
|
||||
projectRoot: root,
|
||||
inputDir: path.join(root, ".timings-empty"),
|
||||
snapshotPath: path.join(root, "snap.json"),
|
||||
});
|
||||
assert.equal(result.written, false);
|
||||
assert.equal(result.reason, "no-inputs");
|
||||
} finally {
|
||||
rmSync(root, { recursive: true, force: true });
|
||||
}
|
||||
});
|
||||
@@ -27,6 +27,7 @@ import {
|
||||
cleanupIsolatedHomePath,
|
||||
knownIsolatedHomeBasenames,
|
||||
__setCleanupRmSyncForTests,
|
||||
emitModeDecision,
|
||||
} from "../test-changed.mjs";
|
||||
|
||||
import { mkdirSync, writeFileSync, mkdtempSync, rmSync, existsSync } from "node:fs";
|
||||
@@ -826,3 +827,33 @@ test("createIsolatedHomeEnv: records raw/realpath basenames in allow-list set",
|
||||
|
||||
cleanupIsolatedHomePath(isolatedHome);
|
||||
});
|
||||
|
||||
// ---------------------------------------------------------------------------
|
||||
// R5: mode-decision telemetry
|
||||
// ---------------------------------------------------------------------------
|
||||
|
||||
test("emitModeDecision: changed plan reports changed-packages reason + package count", () => {
|
||||
const lines = [];
|
||||
const line = emitModeDecision({ mode: "changed", packages: ["a", "b", "c"] }, (l) => lines.push(l));
|
||||
assert.equal(line, "[test-changed] mode=changed reason=changed-packages packages=3");
|
||||
assert.deepEqual(lines, [line]);
|
||||
});
|
||||
|
||||
test("emitModeDecision: full plan surfaces the decideExecutionPlan reason, packages=0", () => {
|
||||
assert.equal(
|
||||
emitModeDecision({ mode: "full", reason: "missing-comparison-base" }, () => {}),
|
||||
"[test-changed] mode=full reason=missing-comparison-base packages=0",
|
||||
);
|
||||
assert.equal(
|
||||
emitModeDecision({ mode: "full", reason: "shared-infra-changed" }, () => {}),
|
||||
"[test-changed] mode=full reason=shared-infra-changed packages=0",
|
||||
);
|
||||
});
|
||||
|
||||
test("emitModeDecision: distinct full reasons round-trip from decideExecutionPlan", () => {
|
||||
const full = decideExecutionPlan({ forceFullSuite: false, comparisonBase: null });
|
||||
assert.equal(emitModeDecision(full, () => {}), "[test-changed] mode=full reason=missing-comparison-base packages=0");
|
||||
|
||||
const forced = decideExecutionPlan({ forceFullSuite: true });
|
||||
assert.equal(emitModeDecision(forced, () => {}), "[test-changed] mode=full reason=forced packages=0");
|
||||
});
|
||||
|
||||
@@ -14,7 +14,7 @@
|
||||
*/
|
||||
|
||||
import { spawnSync } from "node:child_process";
|
||||
import { globSync } from "node:fs";
|
||||
import { globSync, readFileSync, writeFileSync, readdirSync, mkdirSync, renameSync } from "node:fs";
|
||||
import { cpus } from "node:os";
|
||||
import path from "node:path";
|
||||
import { fileURLToPath } from "node:url";
|
||||
@@ -361,7 +361,310 @@ function entryLabel(entry) {
|
||||
return entry.name;
|
||||
}
|
||||
|
||||
// ---------------------------------------------------------------------------
|
||||
// Timing telemetry aggregation (U1 / R4)
|
||||
// ---------------------------------------------------------------------------
|
||||
|
||||
/** @type {string} Repo-relative path of the committed timing snapshot. */
|
||||
export const TIMINGS_SNAPSHOT_RELATIVE = "scripts/test-timings.json";
|
||||
|
||||
/** @type {number} Durations are rounded to this bucket (ms) to suppress noise. */
|
||||
export const DURATION_BUCKET_MS = 100;
|
||||
|
||||
/**
|
||||
* Round a raw duration (ms) to the nearest DURATION_BUCKET_MS, with a floor of
|
||||
* one bucket for any non-zero duration so sub-bucket files are not lost.
|
||||
*
|
||||
* @param {number} durationMs
|
||||
* @returns {number}
|
||||
*/
|
||||
export function bucketDuration(durationMs, bucket = DURATION_BUCKET_MS) {
|
||||
if (!Number.isFinite(durationMs) || durationMs <= 0) return 0;
|
||||
const rounded = Math.round(durationMs / bucket) * bucket;
|
||||
return rounded === 0 ? bucket : rounded;
|
||||
}
|
||||
|
||||
/**
|
||||
* Map an absolute or repo-relative test-file path to its owning package name,
|
||||
* using the workspace dir→name table. Returns { pkg, file } where `file` is
|
||||
* repo-relative, or null when the file is outside any known package.
|
||||
*
|
||||
* @param {string} filePath
|
||||
* @param {Array<{ name: string, dir: string }>} packages
|
||||
* @param {string} projectRoot
|
||||
*/
|
||||
export function attributeTestFile(filePath, packages, projectRoot = process.cwd()) {
|
||||
const relative = path.isAbsolute(filePath)
|
||||
? path.relative(projectRoot, filePath)
|
||||
: filePath;
|
||||
const normalized = relative.split(path.sep).join("/");
|
||||
// Longest dir first so nested packages win over their parents.
|
||||
const sorted = [...packages].sort((a, b) => b.dir.length - a.dir.length);
|
||||
for (const pkg of sorted) {
|
||||
if (normalized === pkg.dir || normalized.startsWith(`${pkg.dir}/`)) {
|
||||
return { pkg: pkg.name, file: normalized };
|
||||
}
|
||||
}
|
||||
return null;
|
||||
}
|
||||
|
||||
/**
|
||||
* Parse one vitest `--reporter=json` output object and return per-file
|
||||
* durations attributed to packages. Tolerant of partial/odd shapes.
|
||||
*
|
||||
* @param {unknown} report Parsed JSON reporter output.
|
||||
* @param {Array<{ name: string, dir: string }>} packages
|
||||
* @param {string} projectRoot
|
||||
* @returns {Map<string, Map<string, number>>} pkg → (file → durationMs)
|
||||
*/
|
||||
export function extractFileDurations(report, packages, projectRoot = process.cwd()) {
|
||||
const byPackage = new Map();
|
||||
const results = report && typeof report === "object" ? report.testResults : null;
|
||||
if (!Array.isArray(results)) return byPackage;
|
||||
|
||||
for (const entry of results) {
|
||||
if (!entry || typeof entry.name !== "string") continue;
|
||||
const start = Number(entry.startTime);
|
||||
const end = Number(entry.endTime);
|
||||
if (!Number.isFinite(start) || !Number.isFinite(end) || end < start) continue;
|
||||
const attributed = attributeTestFile(entry.name, packages, projectRoot);
|
||||
if (!attributed) continue;
|
||||
const { pkg, file } = attributed;
|
||||
if (!byPackage.has(pkg)) byPackage.set(pkg, new Map());
|
||||
const files = byPackage.get(pkg);
|
||||
files.set(file, (files.get(file) ?? 0) + (end - start));
|
||||
}
|
||||
|
||||
return byPackage;
|
||||
}
|
||||
|
||||
/**
|
||||
* Build a fresh timing snapshot object from a set of per-shard JSON reporter
|
||||
* files. Missing/corrupt files are warned about and skipped (exit 0 path).
|
||||
*
|
||||
* @param {string[]} outputFiles Absolute paths to vitest JSON reporter outputs.
|
||||
* @param {{ projectRoot?: string, capturedAt?: string, packages?: Array<{name:string,dir:string}> }} [options]
|
||||
* @returns {{ capturedAt: string, packages: Record<string, { files: Record<string, number> }> }}
|
||||
*/
|
||||
export function buildTimingsSnapshot(outputFiles, options = {}) {
|
||||
const projectRoot = options.projectRoot ?? process.cwd();
|
||||
const packages = options.packages ?? listWorkspaceTestPackages({ projectRoot });
|
||||
const capturedAt = options.capturedAt ?? new Date().toISOString();
|
||||
|
||||
/** @type {Map<string, Map<string, number>>} */
|
||||
const merged = new Map();
|
||||
|
||||
for (const outputFile of outputFiles) {
|
||||
let report;
|
||||
try {
|
||||
report = JSON.parse(readFileSync(outputFile, "utf8"));
|
||||
} catch (err) {
|
||||
const message = err instanceof Error ? err.message : String(err);
|
||||
console.warn(`[ci-test-shard] skipping unreadable timing file ${outputFile}: ${message}`);
|
||||
continue;
|
||||
}
|
||||
|
||||
const perFile = extractFileDurations(report, packages, projectRoot);
|
||||
for (const [pkg, files] of perFile) {
|
||||
if (!merged.has(pkg)) merged.set(pkg, new Map());
|
||||
const target = merged.get(pkg);
|
||||
for (const [file, duration] of files) {
|
||||
target.set(file, (target.get(file) ?? 0) + duration);
|
||||
}
|
||||
}
|
||||
}
|
||||
|
||||
const packagesOut = {};
|
||||
for (const pkg of [...merged.keys()].sort()) {
|
||||
const files = merged.get(pkg);
|
||||
if (files.size === 0) continue; // zero-test package → no entry
|
||||
const filesOut = {};
|
||||
for (const file of [...files.keys()].sort()) {
|
||||
filesOut[file] = bucketDuration(files.get(file));
|
||||
}
|
||||
packagesOut[pkg] = { files: filesOut };
|
||||
}
|
||||
|
||||
return { capturedAt, packages: packagesOut };
|
||||
}
|
||||
|
||||
/**
|
||||
* Read an existing snapshot (or null when absent/corrupt).
|
||||
* @param {string} snapshotPath
|
||||
*/
|
||||
export function readTimingsSnapshot(snapshotPath) {
|
||||
try {
|
||||
const parsed = JSON.parse(readFileSync(snapshotPath, "utf8"));
|
||||
if (parsed && typeof parsed === "object" && typeof parsed.capturedAt === "string") {
|
||||
return parsed;
|
||||
}
|
||||
return null;
|
||||
} catch {
|
||||
return null;
|
||||
}
|
||||
}
|
||||
|
||||
/**
|
||||
* Discover candidate vitest JSON reporter output files in a directory.
|
||||
* Looks for files matching `*timings*.json` (the convention CI shards write).
|
||||
*
|
||||
* @param {string} dir
|
||||
* @returns {string[]} absolute paths
|
||||
*/
|
||||
export function discoverTimingFiles(dir) {
|
||||
let entries = [];
|
||||
try {
|
||||
entries = readdirSync(dir, { withFileTypes: true });
|
||||
} catch {
|
||||
return [];
|
||||
}
|
||||
return entries
|
||||
.filter((e) => e.isFile() && /timings.*\.json$/.test(e.name))
|
||||
.map((e) => path.join(dir, e.name))
|
||||
.sort();
|
||||
}
|
||||
|
||||
/**
|
||||
* Merge per-shard JSON reporter outputs into the committed snapshot.
|
||||
* Refuses to overwrite a snapshot whose capturedAt is newer than this run's.
|
||||
*
|
||||
* @param {{ inputDir?: string, inputs?: string[], projectRoot?: string, snapshotPath?: string, capturedAt?: string }} [options]
|
||||
* @returns {{ written: boolean, snapshot: object, reason?: string }}
|
||||
*/
|
||||
export function writeTimings(options = {}) {
|
||||
const projectRoot = options.projectRoot ?? process.cwd();
|
||||
const snapshotPath = options.snapshotPath ?? path.join(projectRoot, TIMINGS_SNAPSHOT_RELATIVE);
|
||||
const inputs = options.inputs
|
||||
?? discoverTimingFiles(options.inputDir ?? path.join(projectRoot, ".timings"));
|
||||
|
||||
if (inputs.length === 0) {
|
||||
console.warn("[ci-test-shard] no timing input files found; snapshot unchanged.");
|
||||
return { written: false, snapshot: readTimingsSnapshot(snapshotPath) ?? null, reason: "no-inputs" };
|
||||
}
|
||||
|
||||
const capturedAt = options.capturedAt ?? new Date().toISOString();
|
||||
const snapshot = buildTimingsSnapshot(inputs, { projectRoot, capturedAt, packages: options.packages });
|
||||
|
||||
if (Object.keys(snapshot.packages).length === 0) {
|
||||
console.warn("[ci-test-shard] timing inputs yielded zero packages; snapshot unchanged.");
|
||||
return { written: false, snapshot, reason: "empty" };
|
||||
}
|
||||
|
||||
const existing = readTimingsSnapshot(snapshotPath);
|
||||
if (existing && new Date(existing.capturedAt).getTime() > new Date(capturedAt).getTime()) {
|
||||
console.warn(
|
||||
`[ci-test-shard] existing snapshot (${existing.capturedAt}) is newer than this run (${capturedAt}); refusing to overwrite.`,
|
||||
);
|
||||
return { written: false, snapshot: existing, reason: "newer-snapshot" };
|
||||
}
|
||||
|
||||
mkdirSync(path.dirname(snapshotPath), { recursive: true });
|
||||
const tmp = `${snapshotPath}.tmp.${process.pid}`;
|
||||
writeFileSync(tmp, `${JSON.stringify(snapshot, null, 2)}\n`, "utf8");
|
||||
renameSync(tmp, snapshotPath);
|
||||
const pkgCount = Object.keys(snapshot.packages).length;
|
||||
console.log(`[ci-test-shard] wrote ${TIMINGS_SNAPSHOT_RELATIVE} (${pkgCount} packages, capturedAt ${capturedAt}).`);
|
||||
return { written: true, snapshot };
|
||||
}
|
||||
|
||||
/**
|
||||
* Cold-start probe: measure per-package vitest startup-to-first-test overhead.
|
||||
* Runs `vitest run <oneCheapFile>` with the JSON reporter, then estimates
|
||||
* overhead = totalWallClockMs − sum(per-file test durations).
|
||||
*
|
||||
* @param {string} packageName
|
||||
* @param {{ projectRoot?: string, env?: NodeJS.ProcessEnv, testFile?: string }} [options]
|
||||
* @returns {{ packageName: string, wallClockMs: number, testDurationMs: number, overheadMs: number, testFile: string|null }}
|
||||
*/
|
||||
export function runColdStartProbe(packageName, options = {}) {
|
||||
const projectRoot = options.projectRoot ?? process.cwd();
|
||||
const env = options.env ?? process.env;
|
||||
const packages = listWorkspaceTestPackages({ projectRoot });
|
||||
const pkg = packages.find((p) => p.name === packageName);
|
||||
if (!pkg) {
|
||||
throw new Error(`[ci-test-shard] cold-start-probe: unknown package "${packageName}"`);
|
||||
}
|
||||
|
||||
// Pick the cheapest (smallest) test file as the probe target unless given.
|
||||
let testFile = options.testFile ?? null;
|
||||
if (!testFile) {
|
||||
const candidates = globSync("**/__tests__/**/*.test.{ts,tsx,mjs}", {
|
||||
cwd: path.join(projectRoot, pkg.dir),
|
||||
nodir: true,
|
||||
exclude: (p) => p.startsWith("dist/") || p.includes("/dist/") || /\.slow\./.test(p),
|
||||
});
|
||||
testFile = candidates.sort((a, b) => a.length - b.length)[0] ?? null;
|
||||
}
|
||||
if (!testFile) {
|
||||
throw new Error(`[ci-test-shard] cold-start-probe: no test file found for ${packageName}`);
|
||||
}
|
||||
|
||||
const outputFile = path.join(projectRoot, ".timings", `coldstart-${packageName.replace(/[^a-z0-9]+/gi, "-")}.json`);
|
||||
mkdirSync(path.dirname(outputFile), { recursive: true });
|
||||
|
||||
const start = Date.now();
|
||||
// NB: no `--` before flags (cac mis-parse); mirror the virtual-shard pattern.
|
||||
spawnSync(
|
||||
"pnpm",
|
||||
[
|
||||
"--filter",
|
||||
packageName,
|
||||
"exec",
|
||||
"vitest",
|
||||
"run",
|
||||
testFile,
|
||||
"--reporter=dot",
|
||||
"--reporter=json",
|
||||
`--outputFile.json=${outputFile}`,
|
||||
],
|
||||
{ cwd: projectRoot, stdio: "inherit", env },
|
||||
);
|
||||
const wallClockMs = Date.now() - start;
|
||||
|
||||
let testDurationMs = 0;
|
||||
const perFile = (() => {
|
||||
try {
|
||||
return extractFileDurations(JSON.parse(readFileSync(outputFile, "utf8")), packages, projectRoot);
|
||||
} catch {
|
||||
return new Map();
|
||||
}
|
||||
})();
|
||||
for (const files of perFile.values()) {
|
||||
for (const duration of files.values()) testDurationMs += duration;
|
||||
}
|
||||
|
||||
return {
|
||||
packageName,
|
||||
testFile,
|
||||
wallClockMs,
|
||||
testDurationMs: Math.round(testDurationMs),
|
||||
overheadMs: Math.max(0, Math.round(wallClockMs - testDurationMs)),
|
||||
};
|
||||
}
|
||||
|
||||
export function main(argv = process.argv.slice(2), env = process.env) {
|
||||
if (argv.includes("--write-timings")) {
|
||||
const dirIdx = argv.indexOf("--inputs-dir");
|
||||
const inputDir = dirIdx >= 0 ? argv[dirIdx + 1] : undefined;
|
||||
writeTimings({ inputDir });
|
||||
return;
|
||||
}
|
||||
|
||||
if (argv.includes("--cold-start-probe")) {
|
||||
const pkgIdx = argv.indexOf("--cold-start-probe");
|
||||
const packageName = argv[pkgIdx + 1];
|
||||
if (!packageName || packageName.startsWith("--")) {
|
||||
throw new Error("Usage: node scripts/ci-test-shard.mjs --cold-start-probe <package-name>");
|
||||
}
|
||||
const result = runColdStartProbe(packageName, { env });
|
||||
console.log(
|
||||
`[ci-test-shard] cold-start probe ${result.packageName}: wall=${result.wallClockMs}ms ` +
|
||||
`tests=${result.testDurationMs}ms overhead=${result.overheadMs}ms (file ${result.testFile})`,
|
||||
);
|
||||
console.log(JSON.stringify(result));
|
||||
return;
|
||||
}
|
||||
|
||||
const { shard, total } = parseShardArgs(argv, env);
|
||||
const shardEntries = selectShardPackages(listWorkspaceTestPackages(), shard, total);
|
||||
|
||||
@@ -382,6 +685,20 @@ export function main(argv = process.argv.slice(2), env = process.env) {
|
||||
run("pnpm", ["sync:fusion-skill:check"], { env: shardEnv });
|
||||
ensureTestArtifacts(process.cwd());
|
||||
|
||||
// Per-shard timing telemetry (U1 / R4): each test invocation also emits a
|
||||
// vitest JSON reporter file under .timings/. These are uploaded as CI
|
||||
// artifacts and consumed by `--write-timings` to refresh the snapshot.
|
||||
// Reporters are appended as CLI flags following the same no-`--` quirk as the
|
||||
// virtual `--shard` forwarding; package `test` scripts already pass
|
||||
// `--reporter=dot`, and vitest accepts multiple `--reporter` flags.
|
||||
const timingsDir = path.join(process.cwd(), ".timings");
|
||||
mkdirSync(timingsDir, { recursive: true });
|
||||
let invocationIndex = 0;
|
||||
const timingFlags = () => {
|
||||
const outputFile = path.join(timingsDir, `timings-shard${shard}-${invocationIndex++}.json`);
|
||||
return ["--reporter=json", `--outputFile.json=${outputFile}`];
|
||||
};
|
||||
|
||||
// Group entries: plain packages run together in one pnpm invocation;
|
||||
// virtual (sharded) entries each get their own vitest --shard invocation.
|
||||
const plain = shardEntries.filter((e) => !e.shardCount);
|
||||
@@ -389,7 +706,7 @@ export function main(argv = process.argv.slice(2), env = process.env) {
|
||||
|
||||
if (plain.length > 0) {
|
||||
const filters = plain.flatMap((e) => ["--filter", e.name]);
|
||||
run("pnpm", [...filters, "test"], { env: shardEnv });
|
||||
run("pnpm", [...filters, "test", ...timingFlags()], { env: shardEnv });
|
||||
}
|
||||
|
||||
for (const entry of virtual) {
|
||||
@@ -402,7 +719,7 @@ export function main(argv = process.argv.slice(2), env = process.env) {
|
||||
// silently disabled and every shard runs the full suite.
|
||||
run(
|
||||
"pnpm",
|
||||
["--filter", entry.name, "test", `--shard=${entry.shardIndex}/${entry.shardCount}`],
|
||||
["--filter", entry.name, "test", `--shard=${entry.shardIndex}/${entry.shardCount}`, ...timingFlags()],
|
||||
{ env: shardEnv },
|
||||
);
|
||||
}
|
||||
|
||||
@@ -840,6 +840,25 @@ export function decideExecutionPlan({
|
||||
};
|
||||
}
|
||||
|
||||
/**
|
||||
* R5: Emit one structured line describing why the inner loop chose its mode.
|
||||
* Shape: `[test-changed] mode=<changed|full> reason=<reason> packages=<n>`.
|
||||
*
|
||||
* For changed plans the reason is `changed-packages`; for full plans the
|
||||
* reason mirrors decideExecutionPlan's reason field.
|
||||
*
|
||||
* @param {{ mode: string, reason?: string, packages?: string[] }} plan
|
||||
* @param {(line: string) => void} [log]
|
||||
* @returns {string} the emitted line (for testing)
|
||||
*/
|
||||
export function emitModeDecision(plan, log = console.log) {
|
||||
const reason = plan.mode === "changed" ? (plan.reason ?? "changed-packages") : (plan.reason ?? "unknown");
|
||||
const packageCount = plan.mode === "changed" ? (plan.packages?.length ?? 0) : 0;
|
||||
const line = `[test-changed] mode=${plan.mode} reason=${reason} packages=${packageCount}`;
|
||||
log(line);
|
||||
return line;
|
||||
}
|
||||
|
||||
export function normalizeForwardedArgs(argv) {
|
||||
const normalized = [];
|
||||
|
||||
@@ -864,6 +883,26 @@ export function main(argv = process.argv.slice(2)) {
|
||||
|
||||
const forwardedArgs = normalizeForwardedArgs(argv);
|
||||
|
||||
// Dry mode-decision probe (R5): compute and print the mode/reason line without
|
||||
// running tests. Used by `node scripts/test-changed.mjs --print-mode`.
|
||||
if (argv.includes("--print-mode") || argv.includes("--help")) {
|
||||
const baseBranch = getBaseBranch();
|
||||
const comparisonBase = detectComparisonBase(baseBranch);
|
||||
const changedFiles = comparisonBase ? changedFilesSince(comparisonBase) : null;
|
||||
const workspacePackages = listWorkspacePackageInfos();
|
||||
const packageNameByDir = listWorkspacePackages(workspacePackages);
|
||||
const reverseDependencyMap = buildReverseDependencyMap(workspacePackages);
|
||||
const plan = decideExecutionPlan({
|
||||
forceFullSuite,
|
||||
comparisonBase,
|
||||
changedFiles,
|
||||
packageNameByDir,
|
||||
reverseDependencyMap,
|
||||
});
|
||||
emitModeDecision(plan);
|
||||
return;
|
||||
}
|
||||
|
||||
run("pnpm", ["sync:fusion-skill:check"]);
|
||||
ensureTestArtifacts(rootDir);
|
||||
|
||||
@@ -891,6 +930,9 @@ export function main(argv = process.argv.slice(2)) {
|
||||
reverseDependencyMap,
|
||||
});
|
||||
|
||||
// R5: structured mode-decision telemetry so fast-path hit rate is observable.
|
||||
emitModeDecision(plan);
|
||||
|
||||
if (plan.mode === "full") {
|
||||
if (plan.reason === "missing-comparison-base") {
|
||||
console.log(`[test-changed] could not resolve merge-base with ${baseBranch}; running full suite.`);
|
||||
|
||||
1000
scripts/test-timings.json
Normal file
1000
scripts/test-timings.json
Normal file
File diff suppressed because it is too large
Load Diff
Reference in New Issue
Block a user