test(FN-5008): complete Steps 3-5 attribution tests and docs
Fusion-Task-Id: FN-5008 Fusion-Task-Lineage: a5f8c651-c3a3-49b9-911f-51c1cd493b4c
This commit is contained in:
committed by
gsxdsm
parent
4f75dca020
commit
43f57f145c
@@ -1040,7 +1040,7 @@ Mesh configuration and post-provision managed-node operations are registered sep
|
||||
|
||||
### Run Audit API
|
||||
The run-audit system records every mutation performed by the engine across four domains:
|
||||
- **Database** — task:create, task:update, task:move, etc. Node handoff/recovery emits structured events: `node:handoff:parked` (handoff denied/parked), `node:handoff:reassign-local` (local takeover approved), `node:handoff:reassign-any` (any-healthy takeover approved), and `node:lease:recovered` (abandoned lease cleared and task requeued).
|
||||
- **Database** — task:create, task:update, task:move, etc. Node handoff/recovery emits structured events: `node:handoff:parked` (handoff denied/parked), `node:handoff:reassign-local` (local takeover approved), `node:handoff:reassign-any` (any-healthy takeover approved), and `node:lease:recovered` (abandoned lease cleared and task requeued). Scheduler dispatch contention also emits `scheduler:dispatch-queued-concurrency` (debounced per task+reason): metadata includes `bindingGates` (`maxConcurrent`/`maxWorktrees`/`semaphore`), per-gate `{ used, limit, slack }`, `holders`, and computed `available`.
|
||||
- **Git** — worktree:create, commit:create, merge:resolve, merge:audit-failure, and worktrunk lifecycle events (`worktree:worktrunk-install|create|sync|prune|remove`, plus `worktree:worktrunk-fallback`, `worktree:worktrunk-failure`, and `worktree:worktrunk-fallback-native`). Worktrunk events share metadata `{ op, binaryPath?, worktreePath?, durationMs?, exitCode?, stderrPreview?, installSource?, prunedCount? }` with `installSource` (`"release-binary" | "cargo"`) limited to successful `worktree:worktrunk-install` events and `prunedCount` limited to successful prune events when known. `worktree:worktrunk-install` is emitted only for true install actions; cache hits, configured `worktrunk.binaryPath` overrides, and `$PATH` resolutions intentionally remain silent. Dirty post-merge audit outcomes emit `merge:audit-failure` with metadata `{ mode, strategy, action, reason, issueCount, duplicateSubjectCount, touchedFileOverlapCount, verificationPassed, auditTargetLabel }`.
|
||||
- **Git / `merge:file-scope-violation`** — emitted by the merger when `FileScopeViolationError` aborts a squash. `target` is the task ID; metadata includes `stagedFiles`, `declaredScope`, `resetLabel`, `stagedFileCount`, and `declaredScopeCount`. Consumed by `fileScopeInvariantFailuresPerDay` in `GET /api/health/reliability` (FN-4360).
|
||||
- **Database / `task:auto-recover-misrouted-foreign-commit`** — emitted per dropped misrouted commit during FN-4948 contamination recovery. `target` is the recovering task; metadata carries `{ droppedSha, foreignTaskId, paths }`.
|
||||
@@ -1049,6 +1049,8 @@ The run-audit system records every mutation performed by the engine across four
|
||||
|
||||
Events are tied to specific run IDs for end-to-end traceability.
|
||||
|
||||
For scheduler concurrency diagnostics, the queued reason now names the active limiter(s) and usage (for example `gate=maxConcurrent ...`). Read `metadata.bindingGates` first to identify the limiter. `holders.maxConcurrent` and `holders.maxWorktrees` are current `in-progress` task IDs; `holders.semaphore` mirrors that set but semaphore slots can also be consumed by triage/merge agents outside `in-progress`. So if `semaphore.used` exceeds the visible holder list, that usually indicates non-execution agents are legitimately consuming shared capacity (not stale accounting). Identical task+reason states are deduped; a newly emitted line/event indicates limiter identity or usage changed.
|
||||
|
||||
**Run audit endpoints:**
|
||||
- `GET /api/agents/:id/runs/:runId/audit` — Returns audit trail for a specific agent run
|
||||
- Query params: `?domain=database|git|filesystem|sandbox` for filtering
|
||||
|
||||
@@ -72,6 +72,7 @@ function createMockStore(overrides: Partial<TaskStore> = {}): TaskStore {
|
||||
moveTask: vi.fn().mockResolvedValue(undefined),
|
||||
parseFileScopeFromPrompt: vi.fn().mockResolvedValue([]),
|
||||
logEntry: vi.fn().mockResolvedValue(undefined),
|
||||
recordRunAuditEvent: vi.fn().mockResolvedValue(undefined),
|
||||
getRootDir: vi.fn().mockReturnValue("/test/project"),
|
||||
getTasksDir: vi.fn().mockReturnValue("/test/project/.fusion/tasks"),
|
||||
on: vi.fn(),
|
||||
@@ -950,6 +951,180 @@ describe("Scheduler", () => {
|
||||
});
|
||||
});
|
||||
|
||||
describe("FN-5008: concurrency-gate attribution", () => {
|
||||
it("logs maxConcurrent as the sole binding gate", async () => {
|
||||
vi.mocked(existsSync).mockReturnValue(true);
|
||||
vi.mocked(readFile).mockResolvedValue("# Task\nDo something");
|
||||
|
||||
const tasks = [
|
||||
createMockTask({ id: "FN-A", column: "in-progress" }),
|
||||
createMockTask({ id: "FN-B", column: "todo", dependencies: [] }),
|
||||
createMockTask({ id: "FN-C", column: "todo", dependencies: [] }),
|
||||
];
|
||||
const store = createMockStore({
|
||||
listTasks: vi.fn().mockResolvedValue(tasks),
|
||||
getSettings: vi.fn().mockResolvedValue({ maxConcurrent: 2, maxWorktrees: 4 }),
|
||||
});
|
||||
|
||||
const scheduler = new Scheduler(store);
|
||||
(scheduler as any).running = true;
|
||||
await scheduler.schedule();
|
||||
|
||||
const call = (store.logEntry as ReturnType<typeof vi.fn>).mock.calls.find((c: unknown[]) => c[0] === "FN-C");
|
||||
expect(String(call?.[1])).toContain("gate=maxConcurrent");
|
||||
expect(String(call?.[1])).toContain("maxConcurrent used=1/2");
|
||||
expect(String(call?.[1])).toContain("holders: FN-A");
|
||||
});
|
||||
|
||||
it("logs maxWorktrees as the sole binding gate", async () => {
|
||||
vi.mocked(existsSync).mockReturnValue(true);
|
||||
vi.mocked(readFile).mockResolvedValue("# Task\nDo something");
|
||||
|
||||
const tasks = [
|
||||
createMockTask({ id: "FN-A", column: "in-progress" }),
|
||||
createMockTask({ id: "FN-B", column: "in-progress" }),
|
||||
createMockTask({ id: "FN-C", column: "todo", dependencies: [] }),
|
||||
createMockTask({ id: "FN-D", column: "todo", dependencies: [] }),
|
||||
];
|
||||
const store = createMockStore({
|
||||
listTasks: vi.fn().mockResolvedValue(tasks),
|
||||
getSettings: vi.fn().mockResolvedValue({ maxConcurrent: 10, maxWorktrees: 3 }),
|
||||
});
|
||||
|
||||
const scheduler = new Scheduler(store);
|
||||
(scheduler as any).running = true;
|
||||
await scheduler.schedule();
|
||||
|
||||
const call = (store.logEntry as ReturnType<typeof vi.fn>).mock.calls.find((c: unknown[]) => c[0] === "FN-D");
|
||||
expect(String(call?.[1])).toContain("gate=maxWorktrees");
|
||||
expect(String(call?.[1])).toContain("maxWorktrees used=2/3");
|
||||
expect(String(call?.[1])).toContain("holders: FN-A, FN-B");
|
||||
});
|
||||
|
||||
it("logs semaphore as the sole binding gate", async () => {
|
||||
vi.mocked(existsSync).mockReturnValue(true);
|
||||
vi.mocked(readFile).mockResolvedValue("# Task\nDo something");
|
||||
|
||||
const semaphore = new AgentSemaphore(1);
|
||||
const tasks = [
|
||||
createMockTask({ id: "FN-A", column: "todo", dependencies: [] }),
|
||||
createMockTask({ id: "FN-B", column: "todo", dependencies: [] }),
|
||||
];
|
||||
const store = createMockStore({
|
||||
listTasks: vi.fn().mockResolvedValue(tasks),
|
||||
getSettings: vi.fn().mockResolvedValue({ maxConcurrent: 10, maxWorktrees: 10 }),
|
||||
});
|
||||
|
||||
const scheduler = new Scheduler(store, { semaphore });
|
||||
(scheduler as any).running = true;
|
||||
await scheduler.schedule();
|
||||
|
||||
const call = (store.logEntry as ReturnType<typeof vi.fn>).mock.calls.find((c: unknown[]) => c[0] === "FN-B");
|
||||
expect(String(call?.[1])).toContain("gate=semaphore");
|
||||
expect(String(call?.[1])).toContain("semaphore used=0/1");
|
||||
expect(String(call?.[1])).toContain("semaphore slots may include triage/merge agents outside in-progress");
|
||||
});
|
||||
|
||||
it("lists tied binding gates in stable order", async () => {
|
||||
vi.mocked(existsSync).mockReturnValue(true);
|
||||
vi.mocked(readFile).mockResolvedValue("# Task\nDo something");
|
||||
|
||||
const semaphore = new AgentSemaphore(2);
|
||||
const tasks = [
|
||||
createMockTask({ id: "FN-A", column: "in-progress" }),
|
||||
createMockTask({ id: "FN-B", column: "todo", dependencies: [] }),
|
||||
createMockTask({ id: "FN-C", column: "todo", dependencies: [] }),
|
||||
];
|
||||
const store = createMockStore({
|
||||
listTasks: vi.fn().mockResolvedValue(tasks),
|
||||
getSettings: vi.fn().mockResolvedValue({ maxConcurrent: 2, maxWorktrees: 2 }),
|
||||
});
|
||||
|
||||
const scheduler = new Scheduler(store, { semaphore });
|
||||
(scheduler as any).running = true;
|
||||
await scheduler.schedule();
|
||||
|
||||
const call = (store.logEntry as ReturnType<typeof vi.fn>).mock.calls.find((c: unknown[]) => c[0] === "FN-C");
|
||||
expect(String(call?.[1])).toContain("gate=maxConcurrent, maxWorktrees");
|
||||
});
|
||||
|
||||
it("dedupes unchanged queued-concurrency logs and audit events", async () => {
|
||||
vi.mocked(existsSync).mockReturnValue(true);
|
||||
vi.mocked(readFile).mockResolvedValue("# Task\nDo something");
|
||||
|
||||
const tasks = [
|
||||
createMockTask({ id: "FN-A", column: "in-progress" }),
|
||||
createMockTask({ id: "FN-B", column: "todo", dependencies: [] }),
|
||||
createMockTask({ id: "FN-C", column: "todo", dependencies: [] }),
|
||||
];
|
||||
const store = createMockStore({
|
||||
listTasks: vi.fn().mockResolvedValue(tasks),
|
||||
getSettings: vi.fn().mockResolvedValue({ maxConcurrent: 2, maxWorktrees: 4 }),
|
||||
});
|
||||
|
||||
const scheduler = new Scheduler(store);
|
||||
(scheduler as any).running = true;
|
||||
await scheduler.schedule();
|
||||
await scheduler.schedule();
|
||||
|
||||
const concurrencyReasonCalls = (store.logEntry as ReturnType<typeof vi.fn>).mock.calls.filter(
|
||||
(call: unknown[]) => call[0] === "FN-C" && String(call[1]).includes("queued — concurrency limit reached"),
|
||||
);
|
||||
expect(concurrencyReasonCalls).toHaveLength(1);
|
||||
|
||||
const auditCalls = (store.recordRunAuditEvent as ReturnType<typeof vi.fn>).mock.calls.filter(
|
||||
(call: unknown[]) => (call[0] as { mutationType?: string } | undefined)?.mutationType === "scheduler:dispatch-queued-concurrency",
|
||||
);
|
||||
expect(auditCalls).toHaveLength(1);
|
||||
expect(auditCalls[0]?.[0]?.metadata?.bindingGates).toEqual(["maxConcurrent"]);
|
||||
});
|
||||
|
||||
it("re-logs and re-audits when binding gate changes", async () => {
|
||||
vi.mocked(existsSync).mockReturnValue(true);
|
||||
vi.mocked(readFile).mockResolvedValue("# Task\nDo something");
|
||||
|
||||
const firstPass = [
|
||||
createMockTask({ id: "FN-A", column: "in-progress" }),
|
||||
createMockTask({ id: "FN-B", column: "todo", dependencies: [] }),
|
||||
createMockTask({ id: "FN-C", column: "todo", dependencies: [] }),
|
||||
];
|
||||
const secondPass = [
|
||||
createMockTask({ id: "FN-A", column: "in-progress" }),
|
||||
createMockTask({ id: "FN-B", column: "in-progress" }),
|
||||
createMockTask({ id: "FN-C", column: "todo", dependencies: [] }),
|
||||
createMockTask({ id: "FN-E", column: "todo", dependencies: [] }),
|
||||
];
|
||||
|
||||
let phase = 1;
|
||||
const listTasks = vi.fn().mockImplementation(async () => (phase === 1 ? firstPass : secondPass));
|
||||
const getSettings = vi
|
||||
.fn()
|
||||
.mockImplementation(async () => (phase === 1 ? { maxConcurrent: 2, maxWorktrees: 4 } : { maxConcurrent: 10, maxWorktrees: 3 }));
|
||||
|
||||
const store = createMockStore({ listTasks, getSettings });
|
||||
|
||||
const scheduler = new Scheduler(store);
|
||||
(scheduler as any).running = true;
|
||||
await scheduler.schedule();
|
||||
phase = 2;
|
||||
await scheduler.schedule();
|
||||
|
||||
const concurrencyReasonCalls = (store.logEntry as ReturnType<typeof vi.fn>).mock.calls.filter(
|
||||
(call: unknown[]) => String(call[1]).includes("queued — concurrency limit reached"),
|
||||
);
|
||||
expect(concurrencyReasonCalls).toHaveLength(2);
|
||||
expect(String(concurrencyReasonCalls[0]?.[1])).toContain("gate=maxConcurrent");
|
||||
expect(String(concurrencyReasonCalls[1]?.[1])).toContain("gate=maxWorktrees");
|
||||
|
||||
const auditCalls = (store.recordRunAuditEvent as ReturnType<typeof vi.fn>).mock.calls.filter(
|
||||
(call: unknown[]) => (call[0] as { mutationType?: string } | undefined)?.mutationType === "scheduler:dispatch-queued-concurrency",
|
||||
);
|
||||
expect(auditCalls).toHaveLength(2);
|
||||
expect(auditCalls[0]?.[0]?.metadata?.bindingGates).toEqual(["maxConcurrent"]);
|
||||
expect(auditCalls[1]?.[0]?.metadata?.bindingGates).toEqual(["maxWorktrees"]);
|
||||
});
|
||||
});
|
||||
|
||||
describe("priority-aware todo dispatch", () => {
|
||||
it("schedules eligible todo tasks by priority desc then createdAt asc", async () => {
|
||||
vi.mocked(existsSync).mockReturnValue(true);
|
||||
|
||||
Reference in New Issue
Block a user