root/fusion
1
0
Fork 0
Code Issues Pull Requests Actions 1 Packages Projects Releases Wiki Activity

test: remove real-time waits from slow test files (FN-5048)

Browse Source 
Replace real wall-clock waits and per-test rebuilds in the slowest test files
with deterministic seams. No assertions weakened, no timeouts widened, no
retries added — anti-pattern removal only.

- insights-routes.test.ts: boot the server + store ONCE in beforeAll (was a full
  createServer + TaskStore.init per test x24), reset insight tables per test for
  isolation, drive the sweeper via fake timers. Test-execution time ~3.7s -> ~0.8s.
- db.test.ts: convert the fixed 150ms write-lock hold to manual stdin signal-
  release; keeps the real OS-lock contention under test, removes 2x150ms dead
  wait. Fixed a real EPIPE on redundant release. 152 pass, non-flaky over 8 runs.
- mission-store.test.ts / agent-store.test.ts: replace real setTimeout sleeps
  used only to force distinct timestamps with a controlled clock (vi.setSystemTime
  / injected renewedAt). agent-store assertions strengthened to pin exact values.
- in-process-runtime.test.ts: fake the one real 25ms sleep, drop its inflated
  30s per-test timeout.

Honest note: the timestamp-sleep removals are small absolute wins (the headline
per-file durations were full-suite shard contention, not in-file dead time) but
eliminate the FN-5048 real-wait anti-pattern. workflow-routes.test.ts was
evaluated for splitting and deliberately NOT split — measured A/B showed the
split regressed wall-clock (the file is import/transform-bound, already amortized
by installInMemoryDbSnapshot), so splitting only multiplies fixed import cost.

Verified: core 612/612, dashboard 24/24, engine 78/78; typecheck + eslint clean.

Co-Authored-By: Claude Opus 4.8 (1M context) <noreply@anthropic.com>
This commit is contained in:
gsxdsm
2026-06-25 22:08:41 -07:00
parent b6b5583f01
commit 207d2b899a
5 changed files with 231 additions and 83 deletions
Download Patch File Download Diff File Expand all files Collapse all files

21
packages/core/src/__tests__/agent-store.test.ts
View File

@@ -1897,12 +1897,27 @@ describe("AgentStore", () => {
});
it("checkoutTask is idempotent for same agent/node/epoch and renews lease timestamp", async () => {
const first = await store.checkoutTask(holderId, taskId, { nodeId: "node-a", runId: "run-1", leaseEpoch: 0 });
await new Promise((resolve) => setTimeout(resolve, 5));
/*
FNXC:CheckoutLeasing 2026-06-25-21:49:
Lease-renewal ordering is asserted via the store's injectable `renewedAt` clock seam
(CheckoutClaimContext.renewedAt → AgentStore.checkoutTask), not a real setTimeout sleep.
Previously a real 5ms wait forced a distinct heartbeat timestamp between the two checkouts;
that wasted wall-clock time and added flake surface (FN-5048: do not add slow tests).
Two explicit, ordered ISO timestamps make the renewal assertion deterministic with zero waiting.
*/
const firstRenewedAt = "2026-01-01T00:00:00.000Z";
const secondRenewedAt = "2026-01-01T00:00:00.005Z";
const first = await store.checkoutTask(holderId, taskId, {
nodeId: "node-a",
runId: "run-1",
leaseEpoch: 0,
renewedAt: firstRenewedAt,
});
const second = await store.checkoutTask(holderId, taskId, {
nodeId: "node-a",
runId: "run-2",
leaseEpoch: first.checkoutLeaseEpoch ?? 0,
renewedAt: secondRenewedAt,
});
expect(second.checkedOutBy).toBe(holderId);
@@ -1910,6 +1925,8 @@ describe("AgentStore", () => {
expect(second.checkoutNodeId).toBe("node-a");
expect(second.checkoutRunId).toBe("run-2");
expect(second.checkoutLeaseEpoch).toBe(first.checkoutLeaseEpoch);
expect(first.checkoutLeaseRenewedAt).toBe(firstRenewedAt);
expect(second.checkoutLeaseRenewedAt).toBe(secondRenewedAt);
expect(second.checkoutLeaseRenewedAt).not.toBe(first.checkoutLeaseRenewedAt);
});

81
packages/core/src/__tests__/db.test.ts
View File

@@ -120,15 +120,39 @@ afterAll(() => {
cleanupTmpDirsSync();
});
/*
FNXC:CoreDB-LockTest 2026-06-25-21:55:
The write-lock contention helper spawns a real child process that takes a real
SQLite EXCLUSIVE/RESERVED lock — that real OS lock IS the thing under test, so it
must NOT be mocked. The child releases the lock ONLY on an explicit `RELEASE`
stdin message (signal release); there is no fixed wall-clock hold.
History: a `releaseMode: "timer"` variant fired `setTimeout(release, holdMs)` in
the child to drop the lock after a FIXED real duration (150ms per test). Two
recovery tests used it to release the lock mid-retry, paying ~150ms of dead
wall-clock wait each. That timer was removed: the recovery path retries via
synchronous `sleepSync` (Atomics.wait) on the main thread, so the test cannot
release the lock from its own event loop while blocked. Instead the test sends
`signalRelease()` (a bare stdin write, no await) in the SAME synchronous tick
immediately before `transactionImmediate(...)`. The parent reaches its first
`BEGIN IMMEDIATE` before the child can schedule + read the pipe + COMMIT (a
cross-process IPC+WAL round trip), so attempt 0 deterministically contends with
the still-held lock; the child then commits during the parent's first
`sleepSync` window and the retry recovers. Lock held only as long as needed,
released deterministically, zero fixed sleeps.
*/
async function holdWriteLock(
dbPath: string,
options?: { holdMs?: number; releaseMode?: "manual" | "timer" },
options?: { releaseMode?: "manual" },
): Promise<{
child: ChildProcessWithoutNullStreams;
// Fire-and-forget: tell the child to drop the lock WITHOUT awaiting its exit.
// Used to release mid-`transactionImmediate` retry, where the main thread is
// synchronously blocked in `sleepSync` and cannot await the child's exit.
signalRelease: () => void;
release: () => Promise<void>;
}> {
const releaseMode = options?.releaseMode ?? "manual";
const holdMs = options?.holdMs ?? 0;
void options;
const script = `
const { DatabaseSync } = require("node:sqlite");
const db = new DatabaseSync(${JSON.stringify(dbPath)});
@@ -141,14 +165,10 @@ async function holdWriteLock(
try { db.close(); } catch {}
process.exit(0);
};
if (${JSON.stringify(releaseMode)} === "timer") {
setTimeout(release, ${holdMs});
} else {
process.stdin.setEncoding("utf8");
process.stdin.on("data", (chunk) => {
if (chunk.includes("RELEASE")) release();
});
}
process.stdin.setEncoding("utf8");
process.stdin.on("data", (chunk) => {
if (chunk.includes("RELEASE")) release();
});
`;
const child = spawn(process.execPath, ["-e", script], {
@@ -158,6 +178,14 @@ async function holdWriteLock(
child.once("exit", () => {
activeLockChildren.delete(child);
});
// FNXC:CoreDB-LockTest 2026-06-25-21:55: A RELEASE write inherently races the
// child's exit — once the child reads RELEASE it COMMITs and exits, closing its
// stdin, so a write that lands just after exit hits a closed pipe (EPIPE).
// That EPIPE is benign: it only means the lock was already released, which is
// the success condition. Swallow it so it never surfaces as an uncaught
// exception. This does NOT weaken the lock test — assertions run before any
// release and are untouched.
child.stdin.on("error", () => {});
const ready = new Promise<void>((resolve, reject) => {
let stderr = "";
@@ -179,17 +207,28 @@ async function holdWriteLock(
await ready;
// Track whether RELEASE was already sent so `release()` (the cleanup path)
// does not redundantly re-write to a child that `signalRelease()` already told
// to exit — the redundant write is the EPIPE source removed above.
let released = false;
return {
child,
signalRelease: () => {
if (released || child.exitCode !== null || child.killed) {
return;
}
released = true;
child.stdin.write("RELEASE\n");
},
release: async () => {
if (child.exitCode !== null || child.killed) {
return;
}
if (releaseMode === "timer") {
await once(child, "exit");
return;
if (!released) {
released = true;
child.stdin.write("RELEASE\n");
}
child.stdin.write("RELEASE\n");
await once(child, "exit");
},
};
@@ -1012,10 +1051,14 @@ describe("Database", () => {
it("recovers outermost immediate transactions after a transient writer lock", async () => {
const dbPath = db.getPath();
db.exec("PRAGMA busy_timeout = 0");
const lock = await holdWriteLock(dbPath, { releaseMode: "timer", holdMs: 150 });
const lock = await holdWriteLock(dbPath, { releaseMode: "manual" });
let callbackCalls = 0;
try {
// FNXC:CoreDB-LockTest 2026-06-25-21:55: signal release in the SAME tick as
// transactionImmediate so attempt 0 contends with the still-held lock and the
// child commits during the first sleepSync retry window (no fixed wall-clock hold).
lock.signalRelease();
db.transactionImmediate(() => {
callbackCalls += 1;
db.prepare(
@@ -1036,10 +1079,14 @@ describe("Database", () => {
it("preserves nested savepoint rollback semantics after recovering the outer immediate writer lock", async () => {
const dbPath = db.getPath();
db.exec("PRAGMA busy_timeout = 0");
const lock = await holdWriteLock(dbPath, { releaseMode: "timer", holdMs: 150 });
const lock = await holdWriteLock(dbPath, { releaseMode: "manual" });
let callbackCalls = 0;
try {
// FNXC:CoreDB-LockTest 2026-06-25-21:55: same signal-release-then-recover pattern as
// the recovery test above; verifies nested savepoint rollback survives the outer
// immediate-lock recovery without paying a fixed 150ms hold.
lock.signalRelease();
db.transactionImmediate(() => {
callbackCalls += 1;
db.prepare(

89
packages/core/src/__tests__/mission-store.test.ts
View File

@@ -1,4 +1,4 @@
import { describe, it, expect, beforeEach, afterEach, beforeAll, afterAll } from "vitest";
import { describe, it, expect, beforeEach, afterEach, beforeAll, afterAll, vi } from "vitest";
import { MissionStore, deriveMilestoneAcceptanceCriteriaFromFeatures } from "../mission-store.js";
import { installInMemoryDbSnapshot, clearInMemoryDbSnapshot } from "./store-test-helpers.js";
import { GoalStore } from "../goal-store.js";
@@ -134,19 +134,33 @@ describe("MissionStore", () => {
expect(result).toBeUndefined();
});
it("lists missions ordered by createdAt desc", async () => {
const m1 = store.createMission({ title: "Mission 1" });
await new Promise((r) => setTimeout(r, 10)); // Ensure different timestamps
const m2 = store.createMission({ title: "Mission 2" });
await new Promise((r) => setTimeout(r, 10));
const m3 = store.createMission({ title: "Mission 3" });
// FNXC:CoreTests 2026-06-25-21:50: MissionStore stamps createdAt/updatedAt
// via new Date().toISOString() with no injectable clock seam, and ordering
// queries (ORDER BY createdAt DESC) have no tiebreak. Tests previously slept
// real wall-clock (setTimeout 5-10ms) just to force distinct timestamps —
// pure dead time (FN-5048). Drive the system clock with fake timers +
// setSystemTime instead: zero real waiting, deterministic ordering. Scoped
// per-test (useRealTimers in finally) so the file's real-async paths and the
// async afterEach db.close() keep real timers.
it("lists missions ordered by createdAt desc", () => {
vi.useFakeTimers();
try {
vi.setSystemTime(new Date("2026-06-25T00:00:00.000Z"));
const m1 = store.createMission({ title: "Mission 1" });
vi.setSystemTime(new Date("2026-06-25T00:00:00.010Z"));
const m2 = store.createMission({ title: "Mission 2" });
vi.setSystemTime(new Date("2026-06-25T00:00:00.020Z"));
const m3 = store.createMission({ title: "Mission 3" });
const list = store.listMissions();
const list = store.listMissions();
expect(list).toHaveLength(3);
expect(list[0].id).toBe(m3.id); // Newest first
expect(list[1].id).toBe(m2.id);
expect(list[2].id).toBe(m1.id);
expect(list).toHaveLength(3);
expect(list[0].id).toBe(m3.id); // Newest first
expect(list[1].id).toBe(m2.id);
expect(list[2].id).toBe(m1.id);
} finally {
vi.useRealTimers();
}
});
it("round-trips mission branchStrategy on create", () => {
@@ -178,21 +192,29 @@ describe("MissionStore", () => {
expect(store.getMission(mission.id)?.branchStrategy).toBeUndefined();
});
it("updates a mission", async () => {
const mission = store.createMission({ title: "Original" });
await new Promise((r) => setTimeout(r, 5)); // Ensure timestamp difference
const updated = store.updateMission(mission.id, {
title: "Updated",
status: "active",
});
// FNXC:CoreTests 2026-06-25-21:50: real-sleep removed (FN-5048); advance the
// fake clock between create and update so updatedAt > createdAt deterministically.
it("updates a mission", () => {
vi.useFakeTimers();
try {
vi.setSystemTime(new Date("2026-06-25T00:00:00.000Z"));
const mission = store.createMission({ title: "Original" });
vi.setSystemTime(new Date("2026-06-25T00:00:00.005Z"));
const updated = store.updateMission(mission.id, {
title: "Updated",
status: "active",
});
expect(updated.title).toBe("Updated");
expect(updated.status).toBe("active");
expect(updated.id).toBe(mission.id);
expect(updated.createdAt).toBe(mission.createdAt);
expect(new Date(updated.updatedAt).getTime()).toBeGreaterThan(
new Date(mission.updatedAt).getTime()
);
expect(updated.title).toBe("Updated");
expect(updated.status).toBe("active");
expect(updated.id).toBe(mission.id);
expect(updated.createdAt).toBe(mission.createdAt);
expect(new Date(updated.updatedAt).getTime()).toBeGreaterThan(
new Date(mission.updatedAt).getTime()
);
} finally {
vi.useRealTimers();
}
});
it("throws when updating non-existent mission", () => {
@@ -540,7 +562,12 @@ describe("MissionStore", () => {
});
});
it("computes correct health for multiple missions with varying states", async () => {
// FNXC:CoreTests 2026-06-25-21:50: real-sleep removed (FN-5048); fake clock
// advanced between the two missions to keep their createdAt distinct/ordered.
it("computes correct health for multiple missions with varying states", () => {
vi.useFakeTimers();
try {
vi.setSystemTime(new Date("2026-06-25T00:00:00.000Z"));
// Mission 1: 1 milestone (active), 1 slice (active), 4 features (1 done, 2 in-flight, 1 failed)
const m1 = store.createMission({ title: "Mission 1" });
store.updateMission(m1.id, { status: "active" });
@@ -562,7 +589,7 @@ describe("MissionStore", () => {
const f1Failed = store.addFeature(sl1.id, { title: "F1-failed" });
store.linkFeatureToTask(f1Failed.id, "FN-FAILED-1");
await new Promise((r) => setTimeout(r, 10));
vi.setSystemTime(new Date("2026-06-25T00:00:00.010Z"));
// Mission 2: 2 milestones (1 complete, 1 active), 0 features
const m2 = store.createMission({ title: "Mission 2" });
@@ -617,6 +644,9 @@ describe("MissionStore", () => {
autopilotEnabled: false,
lastActivityAt: undefined,
});
} finally {
vi.useRealTimers();
}
});
it("counts failed tasks across missions correctly", () => {
@@ -4520,6 +4550,3 @@ describe("MissionStore", () => {
});
});
});
// vi import for vitest mocking
import { vi } from "vitest";

66
packages/dashboard/src/__tests__/insights-routes.test.ts
View File

@@ -1,4 +1,4 @@
import { describe, it, expect, vi, beforeEach, afterEach } from "vitest";
import { describe, it, expect, vi, beforeAll, beforeEach, afterEach, afterAll } from "vitest";
import express from "express";
import { mkdtempSync } from "node:fs";
import { rm } from "node:fs/promises";
@@ -72,6 +72,20 @@ vi.mock("../project-store-resolver.js", async () => {
/*
FNXC:DashboardTests 2026-06-14-09:58:
FN-6444 rescues this route/API suite from the curated skip-list; awaited store closure and retrying temp cleanup prevent singleton/resource leakage from turning backfill coverage into a flaky orphan.
FNXC:DashboardTests 2026-06-25-10:30 (FN-5048 — slowest dashboard file):
This suite previously paid a full TaskStore.init()/migrate + createServer() (the entire
2.4k-line Express app wiring) on EVERY test via beforeEach, and recreated a temp dir per
test with retry-prone cleanup — ~26.5s under full-suite pressure. The HTTP layer here is
synthetic (test-request.js calls app(req,res) directly; no real port), so the per-test
server boot bought nothing but cost.
Harness seam: boot storeA + the createServer() app ONCE in beforeAll, reuse across all
tests, tear down once in afterAll. Isolation is preserved by truncating the three insight
tables between tests (resetInsightTables) instead of rebuilding the store — assertions are
untouched, order-independence is real, not papered over.
Timer seam: any interval/sweep-driven path is driven with FAKE timers + advanceTimersByTimeAsync
(see "runs periodic sweep" below) so we never wait the real 5-minute DEFAULT_SWEEP_INTERVAL_MS;
afterEach restores real timers so non-timer tests are unaffected.
*/
describe("Insights routes", () => {
let rootA: string;
@@ -82,9 +96,9 @@ describe("Insights routes", () => {
/*
FNXC:DashboardTests 2026-06-25-09:55:
Only the projectId-scoped resolution test touches the project-b store. Lazily
init storeB on first use instead of in beforeEach so the other 23 tests skip a
second full TaskStore.init()/migrate per test (FN-5048: avoid redundant per-test
setup, prefer narrow seams).
init storeB on first use instead of up front so the other 23 tests skip a
second full TaskStore.init()/migrate (FN-5048: avoid redundant setup, prefer
narrow seams). Created once for the suite; tables are truncated between tests.
*/
let rootB: string | null = null;
let storeB: TaskStore | null = null;
@@ -113,16 +127,26 @@ describe("Insights routes", () => {
return app;
}
beforeEach(async () => {
vi.clearAllMocks();
/*
FNXC:DashboardTests 2026-06-25-10:30:
State-isolation seam for the shared beforeAll store. Truncates the three insight tables
(events first to satisfy the run FK) so each test sees a clean slate without paying a
fresh TaskStore.init(). This is the correctness contract that lets the server be booted once.
*/
function resetInsightTables(store: TaskStore) {
const db = store.getDatabase();
db.prepare("DELETE FROM project_insight_run_events").run();
db.prepare("DELETE FROM project_insight_runs").run();
db.prepare("DELETE FROM project_insights").run();
}
beforeAll(async () => {
rootA = mkdtempSync(join(tmpdir(), "kb-insights-routes-a-"));
rootB = null;
storeB = null;
storeA = new TaskStoreClass(rootA, join(rootA, ".fusion-global-settings"), { inMemoryDb: true });
await storeA.init();
// Resolver impl survives vi.clearAllMocks() (which only clears call history), so set
// it once. storeB is lazily created on first project-b request.
resolverMocks.getOrCreateProjectStore.mockImplementation(async (projectId: string) => {
if (projectId === "project-b") {
return getStoreB();
@@ -131,7 +155,19 @@ describe("Insights routes", () => {
});
app = createServer(storeA);
});
beforeEach(() => {
vi.clearAllMocks();
// Reset shared store state between tests for order-independence.
resetInsightTables(storeA);
if (storeB) {
resetInsightTables(storeB);
}
// Re-establish default mock behavior each test (clearAllMocks keeps impls, but
// individual tests override these — e.g. mockRejectedValue — so re-set the baseline).
readWorkingMemorySpy.mockResolvedValue("memory notes");
readInsightsMemorySpy.mockResolvedValue(null);
writeInsightsMemorySpy.mockResolvedValue(undefined);
@@ -151,11 +187,14 @@ describe("Insights routes", () => {
piMocks.promptWithFallback.mockResolvedValue(undefined);
});
afterEach(async () => {
afterEach(() => {
vi.useRealTimers();
while (disposableRouters.length > 0) {
disposableRouters.pop()?.__disposeSweeper?.();
}
});
afterAll(async () => {
try {
await storeA.close();
} catch {
@@ -299,6 +338,9 @@ describe("Insights routes", () => {
});
it("runs periodic sweep and recover later stale rows", async () => {
// FNXC:DashboardTests 2026-06-25-10:30 (FN-5048): drive the 5-minute sweep interval with
// fake timers + advanceTimersByTimeAsync so the periodic recovery is observed instantly
// rather than waiting real time.
vi.useFakeTimers();
const insightsApp = createInsightsOnlyApp(storeA);
@@ -308,7 +350,7 @@ describe("Insights routes", () => {
first.id,
);
vi.advanceTimersByTime(DEFAULT_SWEEP_INTERVAL_MS + 100);
await vi.advanceTimersByTimeAsync(DEFAULT_SWEEP_INTERVAL_MS + 100);
expect(storeA.getInsightStore().getRun(first.id)?.status).toBe("failed");
@@ -318,7 +360,7 @@ describe("Insights routes", () => {
second.id,
);
vi.advanceTimersByTime(DEFAULT_SWEEP_INTERVAL_MS + 100);
await vi.advanceTimersByTimeAsync(DEFAULT_SWEEP_INTERVAL_MS + 100);
expect(storeA.getInsightStore().getRun(second.id)?.status).toBe("failed");
const events = storeA.getInsightStore().listRunEvents(second.id);

57
packages/engine/src/runtimes/__tests__/in-process-runtime.test.ts
View File

@@ -933,32 +933,47 @@ describe("InProcessRuntime", () => {
}, 30000);
it("does not wake executeHeartbeat for runtime ownership sync of durable assigned agents", async () => {
await runtime.start();
/*
FNXC:TestInfrastructure 2026-06-26-21:52:
This negative-assertion test must verify executeHeartbeat is NOT woken by runtime ownership sync.
Previously it paid a real `await new Promise(r => setTimeout(r, 25))` wall-clock sleep to let any
erroneously-scheduled executeHeartbeat fire before asserting it did not — pure dead time on every run.
Per FN-5048 (prefer fake timers over real polling/time waits) we run under fake timers and advance the
window deterministically with advanceTimersByTimeAsync. The inflated 30000ms per-test timeout is removed
now that no real wait remains. vi.waitFor already coexists with fake timers elsewhere in this suite.
*/
vi.useFakeTimers();
try {
await runtime.start();
const monitor = runtime.getHeartbeatMonitor();
expect(monitor).toBeDefined();
const heartbeatMonitor = monitor!;
const executeResult = { id: "run-task-worker" } as Awaited<ReturnType<typeof heartbeatMonitor.executeHeartbeat>>;
const executeSpy = vi
.spyOn(heartbeatMonitor, "executeHeartbeat")
.mockResolvedValue(executeResult);
const monitor = runtime.getHeartbeatMonitor();
expect(monitor).toBeDefined();
const heartbeatMonitor = monitor!;
const executeResult = { id: "run-task-worker" } as Awaited<ReturnType<typeof heartbeatMonitor.executeHeartbeat>>;
const executeSpy = vi
.spyOn(heartbeatMonitor, "executeHeartbeat")
.mockResolvedValue(executeResult);
const store = getAgentStore(runtime);
const durable = await store.createAgent({ name: "Owned Exec", role: "executor" });
const store = getAgentStore(runtime);
const durable = await store.createAgent({ name: "Owned Exec", role: "executor" });
const executorOptions = mockExecutorCtor.mock.calls.at(-1)?.[0] as {
onStart?: (task: Task, worktreePath: string) => void;
};
executorOptions.onStart?.({ id: "FN-2001", assignedAgentId: durable.id } as Task, join(testDir, "worktree-FN-2001"));
const executorOptions = mockExecutorCtor.mock.calls.at(-1)?.[0] as {
onStart?: (task: Task, worktreePath: string) => void;
};
executorOptions.onStart?.({ id: "FN-2001", assignedAgentId: durable.id } as Task, join(testDir, "worktree-FN-2001"));
await vi.waitFor(async () => {
const updated = await store.getAgent(durable.id);
expect(updated?.taskId).toBe("FN-2001");
});
await vi.waitFor(async () => {
const updated = await store.getAgent(durable.id);
expect(updated?.taskId).toBe("FN-2001");
});
await new Promise((resolve) => setTimeout(resolve, 25));
expect(executeSpy).not.toHaveBeenCalled();
}, 30000);
// Drive the negative-assertion window deterministically instead of sleeping 25ms of real time.
await vi.advanceTimersByTimeAsync(25);
expect(executeSpy).not.toHaveBeenCalled();
} finally {
vi.useRealTimers();
}
});
it("cleans up durable execution owner on completion without deleting agent", async () => {
vi.useFakeTimers();