diff --git a/packages/core/src/__tests__/agent-store.test.ts b/packages/core/src/__tests__/agent-store.test.ts index a4b08795d6..05b5e0572a 100644 --- a/packages/core/src/__tests__/agent-store.test.ts +++ b/packages/core/src/__tests__/agent-store.test.ts @@ -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); }); diff --git a/packages/core/src/__tests__/db.test.ts b/packages/core/src/__tests__/db.test.ts index fa7ed0da74..ff22b388ac 100644 --- a/packages/core/src/__tests__/db.test.ts +++ b/packages/core/src/__tests__/db.test.ts @@ -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; }> { - 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((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( diff --git a/packages/core/src/__tests__/mission-store.test.ts b/packages/core/src/__tests__/mission-store.test.ts index c74e57e1ac..0c4cdfd823 100644 --- a/packages/core/src/__tests__/mission-store.test.ts +++ b/packages/core/src/__tests__/mission-store.test.ts @@ -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"; diff --git a/packages/dashboard/src/__tests__/insights-routes.test.ts b/packages/dashboard/src/__tests__/insights-routes.test.ts index ed9f38d16f..eb7d33e3a6 100644 --- a/packages/dashboard/src/__tests__/insights-routes.test.ts +++ b/packages/dashboard/src/__tests__/insights-routes.test.ts @@ -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); diff --git a/packages/engine/src/runtimes/__tests__/in-process-runtime.test.ts b/packages/engine/src/runtimes/__tests__/in-process-runtime.test.ts index f4c3aaf39a..950ae8b189 100644 --- a/packages/engine/src/runtimes/__tests__/in-process-runtime.test.ts +++ b/packages/engine/src/runtimes/__tests__/in-process-runtime.test.ts @@ -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>; - 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>; + 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();