diff --git a/.changeset/fn-7528-task-performance-capture.md b/.changeset/fn-7528-task-performance-capture.md new file mode 100644 index 0000000000..c460beaa73 --- /dev/null +++ b/.changeset/fn-7528-task-performance-capture.md @@ -0,0 +1,7 @@ +--- +"@runfusion/fusion": minor +--- + +summary: Capture a structured performance snapshot when an agent task completes. +category: feature +dev: New AgentReflectionService.captureTaskPerformance persists a non-LLM post-task ReflectionMetrics record (duration, packages/files touched, verification command + scope, retry/rework count) and emits ids/counts-only `reflection:captured` run-audit telemetry; populates performanceSummary/latestReflection. diff --git a/AGENTS.md b/AGENTS.md index b57742214d..6bac24003a 100644 --- a/AGENTS.md +++ b/AGENTS.md @@ -220,6 +220,7 @@ Scoped exception (FN-5819): shared-branch-group members (`branchContext.assignme ### Run Audit - FN-7158: agent performance reflections emit `reflection:generated`, `reflection:skipped`, and `reflection:failed` with ids/counts/outcomes-only metadata; never persist reflection prose or prompt text in run-audit. +- FN-7528: a deterministic, non-LLM post-task performance capture (`AgentReflectionService.captureTaskPerformance`) runs once per completed task and emits `reflection:captured` with ids/counts/outcomes-only metadata (`retryReworkCount?`, `filesTouchedCount?`, `packagesTouchedCount?`, `verificationFileScoped?`, `durationMs?`); never persists `verificationScopeReason` free-text or summary prose in run-audit. - FN-7011: self-healing emits `task:reconcile-engine-downtime-active-timing` when startup recovery shifts active task segment anchors to exclude proven engine-process downtime, and `task:reconcile-engine-downtime-active-timing-no-action` when no active task qualifies. - FN-5419: git run-audit now includes `pull:fast-forward` and `stash:pop-conflict`; dashboard git surfaces now include the extended `POST /api/git/pull` integration-worktree path plus companion `POST /api/git/stash-resolve`, `POST /api/git/stash-drop`, and `POST /api/git/stash-apply` routes. - FN-6292: self-healing emits `task:reconcile-dependency-blocking-lease` when it rebounds an in-progress holder whose stale file-scope lease blocks an unmet dependency, and `task:reconcile-dependency-blocking-lease-no-action` when triple-proof blocks that backward move. diff --git a/docs/diagnostics.md b/docs/diagnostics.md index 8f32af2551..e381393d93 100644 --- a/docs/diagnostics.md +++ b/docs/diagnostics.md @@ -19,12 +19,22 @@ Agent reflection generation emits one run-audit event for every `AgentReflection - Run-audit events (`database` domain, target `agentId`): - `reflection:generated` metadata: `{ agentId, trigger, taskId?, reflectionId, tasksCompleted?, tasksFailed?, avgDurationMs?, commonErrorCount, insightCount, suggestedImprovementCount }`. - - `reflection:skipped` metadata: `{ agentId, trigger, taskId?, reason: "no-history" }`. + - `reflection:skipped` metadata: `{ agentId, trigger, taskId?, reason: "no-history" | "not-completed" }`. - `reflection:failed` metadata: `{ agentId, trigger, taskId?, errorClass }`. - Trigger taxonomy is preserved from `ReflectionTrigger`: `manual`, `periodic`, `post-task`, and `user-requested`. - The events use synthetic run context with phase `reflection` and source equal to the trigger so they correlate in the run-audit stream without requiring caller-specific wiring. - Guardrail: reflection diagnostics persist IDs, counts, reasons, and error classes only; never prompt text, reflection summaries, insight strings, suggested-improvement text, or free-form trigger details. +### Post-task performance capture (`reflection:captured`, FN-7528) + +`AgentReflectionService.captureTaskPerformance` is a deterministic, non-LLM counterpart to `generateReflection`: it runs once per completed task at the executor completion seam (`TaskExecutor.signalTaskComplete`), guarded by `reflectionService` presence, `settings.reflectionEnabled`, and an assigned agent id. It never calls the model provider and persists a compact structured `post-task` `ReflectionMetrics` record — duration, packages/files touched, verification command(s) + file-scoped-vs-broader classification, and retry/rework count — sourced only from the completed `Task` record. Fields whose source is unavailable are omitted, never fabricated. + +- Run-audit event (`database` domain, target `agentId`): + - `reflection:captured` metadata: `{ agentId, trigger: "post-task", taskId?, reflectionId, retryReworkCount?, filesTouchedCount?, packagesTouchedCount?, verificationFileScoped?, durationMs? }`. + - Skipped/failed captures reuse the existing `reflection:skipped` (`reason: "no-history" | "not-completed"`) and `reflection:failed` (`errorClass`) event types above. +- Guardrail: capture telemetry stays ids/counts/outcomes-only — `verificationScopeReason` free-text, the deterministic one-line `summary`, and any prompt/reflection prose never reach run-audit metadata (they are stored only in the `ReflectionMetrics`/`AgentReflection` record itself). +- Capture is best-effort and fire-and-forget: a capture failure never blocks or fails task completion, and an in-memory per-taskId guard prevents duplicate captures across the executor's several completion call sites (fresh completion, duplicate in-review re-entry, auto-recovery, paused-after-completion finalize, retry-completed). + ## Insight run sweeper (`[insight-sweeper]`) The dashboard insight router runs stale-run recovery sweeps for `project_insight_runs` rows stuck in `pending`/`running` without a live controller owner. diff --git a/packages/core/src/__tests__/reflection-store.test.ts b/packages/core/src/__tests__/reflection-store.test.ts index be1fbf7797..8616793cc1 100644 --- a/packages/core/src/__tests__/reflection-store.test.ts +++ b/packages/core/src/__tests__/reflection-store.test.ts @@ -421,6 +421,102 @@ describe("ReflectionStore", () => { }); }); + // FNXC:AgentReflection 2026-07-04-00:00: + // FN-7528 adds a compact structured post-task ReflectionMetrics snapshot (duration, packages/files + // touched, verification command/scope, retry/rework count). The store persists `metrics` verbatim, + // so these tests assert the extended fields survive a create -> read round-trip untouched, and that + // a single captured record is enough to make getLatestReflection/getPerformanceSummary meaningful. + describe("extended post-task metrics (FN-7528)", () => { + it("round-trips the extended structured metrics fields through createReflection/getReflections", async () => { + const created = await store.createReflection({ + agentId: "agent-structured", + trigger: "post-task", + taskId: "FN-7528", + metrics: { + tasksCompleted: 1, + tasksFailed: 0, + durationMs: 45_000, + durationDrivers: ["retries:1", "verification-broad"], + packagesTouched: ["@fusion/core", "@fusion/engine"], + filesTouchedCount: 3, + verificationCommands: ["pnpm --filter @fusion/core exec vitest run src/foo.test.ts"], + retryReworkCount: 1, + verificationFileScoped: false, + verificationScopeReason: "whole-package test script has no file-scoped filter", + }, + insights: [], + suggestedImprovements: [], + summary: "Completed FN-7528 in 45s with one retry.", + }); + + expect(created.metrics).toEqual({ + tasksCompleted: 1, + tasksFailed: 0, + durationMs: 45_000, + durationDrivers: ["retries:1", "verification-broad"], + packagesTouched: ["@fusion/core", "@fusion/engine"], + filesTouchedCount: 3, + verificationCommands: ["pnpm --filter @fusion/core exec vitest run src/foo.test.ts"], + retryReworkCount: 1, + verificationFileScoped: false, + verificationScopeReason: "whole-package test script has no file-scoped filter", + }); + + const [reflection] = await store.getReflections("agent-structured", 1); + expect(reflection.metrics).toEqual(created.metrics); + }); + + it("yields a non-null, meaningful getLatestReflection/getPerformanceSummary from a single captured record", async () => { + const agentId = "agent-structured-meaningful"; + await store.createReflection({ + agentId, + trigger: "post-task", + taskId: "FN-9001", + metrics: { + tasksCompleted: 1, + tasksFailed: 0, + durationMs: 12_000, + retryReworkCount: 0, + verificationFileScoped: true, + }, + insights: [], + suggestedImprovements: [], + summary: "Completed FN-9001 in 12s with no retries.", + }); + + const latest = await store.getLatestReflection(agentId); + expect(latest).not.toBeNull(); + expect(latest?.metrics.durationMs).toBe(12_000); + + const summary = await store.getPerformanceSummary(agentId); + expect(summary.totalTasksCompleted).toBe(1); + expect(summary.totalTasksFailed).toBe(0); + expect(summary.successRate).toBe(1); + expect(summary.recentReflectionCount).toBe(1); + }); + + it("omits unavailable fields rather than persisting fabricated placeholders", async () => { + const agentId = "agent-structured-omitted"; + const created = await store.createReflection({ + agentId, + trigger: "post-task", + taskId: "FN-9002", + metrics: { + tasksCompleted: 1, + tasksFailed: 0, + // packagesTouched/verificationCommands intentionally omitted (source unavailable) + }, + insights: [], + suggestedImprovements: [], + summary: "Completed FN-9002; verification source unavailable.", + }); + + expect(created.metrics.packagesTouched).toBeUndefined(); + expect(created.metrics.verificationCommands).toBeUndefined(); + expect(created.metrics.verificationScopeReason).toBeUndefined(); + }); + }); + describe("deleteReflections", () => { it("removes the agent reflection file", async () => { const agentId = "agent-delete"; diff --git a/packages/core/src/types.ts b/packages/core/src/types.ts index d91473b24c..e00612cb5e 100644 --- a/packages/core/src/types.ts +++ b/packages/core/src/types.ts @@ -7319,7 +7319,17 @@ export interface AgentStats { /** Trigger source for an agent self-reflection run */ export type ReflectionTrigger = "periodic" | "post-task" | "manual" | "user-requested"; -/** Quantitative snapshot captured by a reflection */ +/** + * FNXC:AgentReflection 2026-07-04-00:00: + * FN-7528 adds a deterministic, non-LLM post-task performance capture that runs on every + * completed task (guarded by settings.reflectionEnabled), distinct from the LLM-backed + * generateReflection path. These extra fields are a compact structured snapshot — duration + * drivers, packages/files touched, verification command(s)/scope, and retry/rework count. + * All fields are optional (backward-compatible with existing JSONL records) and outcome-only: + * no free-form prose, prompt text, or reflection narrative is ever stored here or emitted to + * run-audit (FN-7158 ids/counts/outcomes-only contract). Omit a field rather than fabricate it + * when its source data is unavailable. + */ export interface ReflectionMetrics { /** Tasks completed in the analysis window */ tasksCompleted?: number; @@ -7333,6 +7343,22 @@ export interface ReflectionMetrics { errorCount?: number; /** Recurring error patterns */ commonErrors?: string[]; + /** Single task's wall-clock duration in milliseconds (distinct from the aggregate avgDurationMs) */ + durationMs?: number; + /** Short deterministic labels describing what drove the duration (e.g. "retries:2", "rework:1", "verification-broad") — never free-form prose */ + durationDrivers?: string[]; + /** Package names derived from touched file paths (e.g. "@fusion/core" or "packages/core") */ + packagesTouched?: string[]; + /** Count of files touched, when available */ + filesTouchedCount?: number; + /** Verification command(s) recorded for the task */ + verificationCommands?: string[]; + /** reworkCount + retry/recovery count */ + retryReworkCount?: number; + /** True when verification was file-scoped, false when broader/full-suite */ + verificationFileScoped?: boolean; + /** Short reason label when verification scope was broader (e.g. "whole-package test script has no file-scoped filter"); omitted when file-scoped */ + verificationScopeReason?: string; } /** A persisted self-reflection generated by an agent */ diff --git a/packages/engine/src/__tests__/agent-reflection.test.ts b/packages/engine/src/__tests__/agent-reflection.test.ts index 3221832ed1..bb7de76985 100644 --- a/packages/engine/src/__tests__/agent-reflection.test.ts +++ b/packages/engine/src/__tests__/agent-reflection.test.ts @@ -108,6 +108,7 @@ function createMockDeps() { const taskStore = { listTasks: vi.fn().mockResolvedValue([makeTask()]), recordRunAuditEvent: vi.fn(), + getTask: vi.fn().mockResolvedValue(makeTask()), } as any; const reflectionStore = { @@ -535,6 +536,207 @@ describe("AgentReflectionService", () => { }); }); + // FNXC:AgentReflection 2026-07-04-00:00: + // FN-7528 exercises the deterministic, non-LLM post-task capture path: no createFnAgent/promptWithFallback + // call, a `post-task` record with structured metrics, and ids/counts/outcomes-only `reflection:captured` + // telemetry (never verificationScopeReason free-text, summary prose, or prompt text). + describe("captureTaskPerformance", () => { + it("persists a post-task record with structured fields sourced from the completed task, without calling the model provider", async () => { + const { agentStore, taskStore, reflectionStore } = createMockDeps(); + taskStore.getTask.mockResolvedValue(makeTask({ + id: "FN-7528", + column: "done", + assignedAgentId: "agent-1", + createdAt: "2026-04-08T00:00:00.000Z", + updatedAt: "2026-04-08T00:00:45.000Z", + recoveryRetryCount: 2, + modifiedFiles: ["packages/core/src/foo.ts", "packages/engine/src/bar.ts"], + log: [ + { + timestamp: "2026-04-08T00:00:40.000Z", + action: "[verification] Running deterministic verification (test: pnpm --filter @fusion/core exec vitest run src/foo.test.ts, build: pnpm build)", + }, + ], + })); + + const service = new AgentReflectionService({ agentStore, taskStore, reflectionStore, rootDir: tempRoot }); + const reflection = await service.captureTaskPerformance("agent-1", "FN-7528"); + + expect(reflection).not.toBeNull(); + expect(mockedCreateFnAgent).not.toHaveBeenCalled(); + expect(mockedPromptWithFallback).not.toHaveBeenCalled(); + expect(reflectionStore.createReflection).toHaveBeenCalledWith(expect.objectContaining({ + agentId: "agent-1", + trigger: "post-task", + taskId: "FN-7528", + insights: [], + suggestedImprovements: [], + metrics: expect.objectContaining({ + tasksCompleted: 1, + tasksFailed: 0, + durationMs: 45_000, + retryReworkCount: 2, + filesTouchedCount: 2, + packagesTouched: ["packages/core", "packages/engine"], + verificationCommands: [ + "test: pnpm --filter @fusion/core exec vitest run src/foo.test.ts", + "build: pnpm build", + ], + }), + })); + expect(reflection?.metrics.verificationFileScoped).toBe(true); + expect(reflection?.metrics.verificationScopeReason).toBeUndefined(); + }); + + it("aggregates workflow step rework cycles (RETHINK/rework) alongside recoveryRetryCount into retryReworkCount and durationDrivers", async () => { + const { agentStore, taskStore, reflectionStore } = createMockDeps(); + taskStore.getTask.mockResolvedValue(makeTask({ + id: "FN-7528-rework", + column: "done", + recoveryRetryCount: 1, + })); + taskStore.loadWorkflowRunStepInstances = vi.fn().mockReturnValue([ + { taskId: "FN-7528-rework", runId: "FN-7528-rework:run", foreachNodeId: "n1", stepIndex: 0, reworkCount: 2 }, + { taskId: "FN-7528-rework", runId: "FN-7528-rework:run", foreachNodeId: "n1", stepIndex: 1, reworkCount: 1 }, + ]); + + const service = new AgentReflectionService({ agentStore, taskStore, reflectionStore, rootDir: tempRoot }); + const reflection = await service.captureTaskPerformance("agent-1", "FN-7528-rework"); + + expect(taskStore.loadWorkflowRunStepInstances).toHaveBeenCalledWith("FN-7528-rework", "FN-7528-rework:run"); + // recoveryRetryCount(1) + workflowReworkCount(2+1=3) = 4 + expect(reflection?.metrics.retryReworkCount).toBe(4); + expect(reflection?.metrics.durationDrivers).toContain("retries:1"); + expect(reflection?.metrics.durationDrivers).toContain("rework:3"); + }); + + it("classifies a broad/whole-suite verification command as not file-scoped, with a reason", async () => { + const { agentStore, taskStore, reflectionStore } = createMockDeps(); + taskStore.getTask.mockResolvedValue(makeTask({ + id: "FN-7529", + column: "done", + log: [ + { + timestamp: "2026-04-08T00:00:40.000Z", + action: "[verification] Running deterministic verification (test: pnpm test:full)", + }, + ], + })); + + const service = new AgentReflectionService({ agentStore, taskStore, reflectionStore, rootDir: tempRoot }); + const reflection = await service.captureTaskPerformance("agent-1", "FN-7529"); + + expect(reflection?.metrics.verificationFileScoped).toBe(false); + expect(reflection?.metrics.verificationScopeReason).toBeTruthy(); + expect(reflection?.metrics.durationDrivers).toContain("verification-broad"); + }); + + it("omits fields whose source is unavailable rather than fabricating values", async () => { + const { agentStore, taskStore, reflectionStore } = createMockDeps(); + taskStore.getTask.mockResolvedValue(makeTask({ + id: "FN-7530", + column: "done", + modifiedFiles: undefined, + log: [], + })); + + const service = new AgentReflectionService({ agentStore, taskStore, reflectionStore, rootDir: tempRoot }); + const reflection = await service.captureTaskPerformance("agent-1", "FN-7530"); + + expect(reflection).not.toBeNull(); + expect(reflection?.metrics.packagesTouched).toBeUndefined(); + expect(reflection?.metrics.filesTouchedCount).toBeUndefined(); + expect(reflection?.metrics.verificationCommands).toBeUndefined(); + expect(reflection?.metrics.verificationFileScoped).toBeUndefined(); + expect(reflection?.metrics.verificationScopeReason).toBeUndefined(); + expect(reflection?.metrics.retryReworkCount).toBeUndefined(); + }); + + it("returns null and emits reflection:skipped with not-completed when the task is not resolvable to a terminal outcome", async () => { + const { agentStore, taskStore, reflectionStore } = createMockDeps(); + taskStore.getTask.mockResolvedValue(makeTask({ id: "FN-7531", column: "in-progress" })); + + const service = new AgentReflectionService({ agentStore, taskStore, reflectionStore, rootDir: tempRoot }); + const reflection = await service.captureTaskPerformance("agent-1", "FN-7531"); + + expect(reflection).toBeNull(); + expect(reflectionStore.createReflection).not.toHaveBeenCalled(); + expect(taskStore.recordRunAuditEvent).toHaveBeenCalledWith(expect.objectContaining({ + mutationType: "reflection:skipped", + metadata: expect.objectContaining({ reason: "not-completed" }), + })); + }); + + it("returns null and emits reflection:skipped with no-history when the task cannot be found", async () => { + const { agentStore, taskStore, reflectionStore } = createMockDeps(); + taskStore.getTask.mockResolvedValue(null); + + const service = new AgentReflectionService({ agentStore, taskStore, reflectionStore, rootDir: tempRoot }); + const reflection = await service.captureTaskPerformance("agent-1", "FN-missing"); + + expect(reflection).toBeNull(); + expect(taskStore.recordRunAuditEvent).toHaveBeenCalledWith(expect.objectContaining({ + mutationType: "reflection:skipped", + metadata: expect.objectContaining({ reason: "no-history" }), + })); + }); + + it("emits ids/counts/outcomes-only reflection:captured telemetry (no prose, reason free-text, or prompt text)", async () => { + const { agentStore, taskStore, reflectionStore } = createMockDeps(); + taskStore.getTask.mockResolvedValue(makeTask({ + id: "FN-7532", + column: "done", + recoveryRetryCount: 1, + modifiedFiles: ["packages/core/src/foo.ts"], + log: [ + { + timestamp: "2026-04-08T00:00:40.000Z", + action: "[verification] Running deterministic verification (test: pnpm test:full)", + }, + ], + })); + + const service = new AgentReflectionService({ agentStore, taskStore, reflectionStore, rootDir: tempRoot }); + await service.captureTaskPerformance("agent-1", "FN-7532"); + + expect(taskStore.recordRunAuditEvent).toHaveBeenCalledWith(expect.objectContaining({ + mutationType: "reflection:captured", + agentId: "agent-1", + taskId: "FN-7532", + metadata: expect.objectContaining({ + agentId: "agent-1", + trigger: "post-task", + taskId: "FN-7532", + retryReworkCount: 1, + filesTouchedCount: 1, + packagesTouchedCount: 1, + verificationFileScoped: false, + }), + })); + + const metadata = taskStore.recordRunAuditEvent.mock.calls[0][0].metadata; + expect(metadata).not.toHaveProperty("verificationScopeReason"); + expect(metadata).not.toHaveProperty("summary"); + expect(metadata).not.toHaveProperty("verificationCommands"); + expectNoReflectionProse(metadata); + }); + + it("stays best-effort: emits reflection:failed and returns null when reflectionStore.createReflection throws", async () => { + const { agentStore, taskStore, reflectionStore } = createMockDeps(); + taskStore.getTask.mockResolvedValue(makeTask({ id: "FN-7533", column: "done" })); + reflectionStore.createReflection.mockRejectedValue(new Error("disk unavailable")); + + const service = new AgentReflectionService({ agentStore, taskStore, reflectionStore, rootDir: tempRoot }); + const reflection = await service.captureTaskPerformance("agent-1", "FN-7533"); + + expect(reflection).toBeNull(); + expect(taskStore.recordRunAuditEvent).toHaveBeenCalledWith(expect.objectContaining({ + mutationType: "reflection:failed", + metadata: expect.objectContaining({ errorClass: "Error" }), + })); + }); + }); + describe("reflect_on_performance tool", () => { it("returns formatted text when reflection succeeds", async () => { const reflectionService = { diff --git a/packages/engine/src/__tests__/executor-post-task-reflection-capture.test.ts b/packages/engine/src/__tests__/executor-post-task-reflection-capture.test.ts new file mode 100644 index 0000000000..404fa8483d --- /dev/null +++ b/packages/engine/src/__tests__/executor-post-task-reflection-capture.test.ts @@ -0,0 +1,135 @@ +import { beforeEach, describe, expect, it, vi } from "vitest"; +import "./executor-test-helpers.js"; +import { TaskExecutor } from "../executor.js"; +import { createMockStore, resetExecutorMocks } from "./executor-test-helpers.js"; + +/** + * FNXC:AgentReflection 2026-07-04-00:00: + * FN-7528: `signalTaskComplete` is the single seam every executor completion call site routes + * through. These tests assert the deterministic, non-LLM post-task performance capture fires + * exactly once per completion (guarded by reflectionService/settings.reflectionEnabled/assigned + * agent id) and never blocks completion when capture fails. + */ +describe("TaskExecutor post-task reflection capture (FN-7528)", () => { + beforeEach(() => { + resetExecutorMocks(); + }); + + function makeTask(overrides: Record = {}) { + return { + id: "FN-7528", + description: "Test task", + column: "in-review", + dependencies: [], + steps: [], + currentStep: 0, + log: [], + assignedAgentId: "agent-1", + createdAt: new Date().toISOString(), + updatedAt: new Date().toISOString(), + ...overrides, + } as any; + } + + it("invokes reflectionService.captureTaskPerformance once when reflectionEnabled and an agent is assigned", async () => { + const store = createMockStore(); + store.getSettings.mockResolvedValue({ + maxConcurrent: 2, + maxWorktrees: 4, + pollIntervalMs: 15000, + groupOverlappingFiles: false, + autoMerge: false, + reflectionEnabled: true, + }); + + const captureTaskPerformance = vi.fn().mockResolvedValue(null); + const executor = new TaskExecutor(store as any, "/tmp/test", { + reflectionService: { captureTaskPerformance } as any, + }); + + const task = makeTask(); + (executor as any).signalTaskComplete(task); + // Fire-and-forget: flush the microtask queue. + await new Promise((resolve) => setImmediate(resolve)); + + expect(captureTaskPerformance).toHaveBeenCalledTimes(1); + expect(captureTaskPerformance).toHaveBeenCalledWith("agent-1", "FN-7528"); + }); + + it("does not capture a second time for the same task", async () => { + const store = createMockStore(); + store.getSettings.mockResolvedValue({ reflectionEnabled: true }); + + const captureTaskPerformance = vi.fn().mockResolvedValue(null); + const executor = new TaskExecutor(store as any, "/tmp/test", { + reflectionService: { captureTaskPerformance } as any, + }); + + const task = makeTask(); + (executor as any).signalTaskComplete(task); + (executor as any).signalTaskComplete(task); + await new Promise((resolve) => setImmediate(resolve)); + + expect(captureTaskPerformance).toHaveBeenCalledTimes(1); + }); + + it("skips capture when settings.reflectionEnabled is false", async () => { + const store = createMockStore(); + store.getSettings.mockResolvedValue({ reflectionEnabled: false }); + + const captureTaskPerformance = vi.fn().mockResolvedValue(null); + const executor = new TaskExecutor(store as any, "/tmp/test", { + reflectionService: { captureTaskPerformance } as any, + }); + + (executor as any).signalTaskComplete(makeTask()); + await new Promise((resolve) => setImmediate(resolve)); + + expect(captureTaskPerformance).not.toHaveBeenCalled(); + }); + + it("skips capture when no agent is assigned", async () => { + const store = createMockStore(); + store.getSettings.mockResolvedValue({ reflectionEnabled: true }); + + const captureTaskPerformance = vi.fn().mockResolvedValue(null); + const executor = new TaskExecutor(store as any, "/tmp/test", { + reflectionService: { captureTaskPerformance } as any, + }); + + (executor as any).signalTaskComplete(makeTask({ assignedAgentId: undefined })); + await new Promise((resolve) => setImmediate(resolve)); + + expect(captureTaskPerformance).not.toHaveBeenCalled(); + }); + + it("never blocks or fails completion when capture throws (best-effort)", async () => { + const store = createMockStore(); + store.getSettings.mockResolvedValue({ reflectionEnabled: true }); + + const captureTaskPerformance = vi.fn().mockRejectedValue(new Error("capture failed")); + const onComplete = vi.fn(); + const executor = new TaskExecutor(store as any, "/tmp/test", { + reflectionService: { captureTaskPerformance } as any, + onComplete, + }); + + expect(() => (executor as any).signalTaskComplete(makeTask())).not.toThrow(); + expect(onComplete).toHaveBeenCalledTimes(1); + await new Promise((resolve) => setImmediate(resolve)); + expect(captureTaskPerformance).toHaveBeenCalledTimes(1); + }); + + it("still forwards to the configured onComplete callback", async () => { + const store = createMockStore(); + store.getSettings.mockResolvedValue({ reflectionEnabled: true }); + + const onComplete = vi.fn(); + const executor = new TaskExecutor(store as any, "/tmp/test", { onComplete }); + + const task = makeTask(); + (executor as any).signalTaskComplete(task); + + expect(onComplete).toHaveBeenCalledWith(task); + }); +}); diff --git a/packages/engine/src/agent-reflection.ts b/packages/engine/src/agent-reflection.ts index 72c9317c46..12521e90f2 100644 --- a/packages/engine/src/agent-reflection.ts +++ b/packages/engine/src/agent-reflection.ts @@ -179,9 +179,222 @@ export class AgentReflectionService { } } + /** + * FNXC:AgentReflection 2026-07-04-00:00: + * FN-7528: deterministic, non-LLM post-task performance capture. Runs once per completed task + * (executor completion seam), producing a compact structured `ReflectionMetrics` snapshot without + * calling the model provider — no createFnAgent/promptWithFallback in this path. Sources data only + * from the completed Task record; any field whose source is unavailable is OMITTED rather than + * fabricated. Telemetry emitted via `reflection:captured`/`reflection:skipped` stays ids/counts/ + * outcomes-only (FN-7158): verificationScopeReason and summary text never reach run-audit metadata. + */ + async captureTaskPerformance( + agentId: string, + taskId: string, + options: { triggerDetail?: string } = {}, + ): Promise { + const trigger: ReflectionTrigger = "post-task"; + const runContext: EngineRunContext = { + runId: generateSyntheticRunId("reflection-capture", agentId), + agentId, + taskId, + phase: "reflection", + source: trigger, + }; + const auditor = createRunAuditor(this.taskStore, runContext); + + try { + const task = await this.taskStore.getTask(taskId); + if (!task) { + await this.emitReflectionAudit(auditor, "reflection:skipped", agentId, trigger, { taskId, ...options }, { + reason: "no-history", + }); + return null; + } + + const outcome = this.classifyOutcome(task); + if (!outcome || outcome === "stuck") { + await this.emitReflectionAudit(auditor, "reflection:skipped", agentId, trigger, { taskId, ...options }, { + reason: "not-completed", + }); + return null; + } + + const metrics = this.buildCapturedMetrics(taskId, task, outcome); + + const reflection = await this.reflectionStore.createReflection({ + agentId, + trigger, + triggerDetail: options.triggerDetail, + taskId, + metrics, + insights: [], + suggestedImprovements: [], + summary: this.buildCapturedSummary(task, outcome, metrics), + }); + + await this.emitReflectionAudit(auditor, "reflection:captured", agentId, trigger, { taskId, ...options }, { + reflectionId: reflection.id, + ...(metrics.retryReworkCount !== undefined ? { retryReworkCount: metrics.retryReworkCount } : {}), + ...(metrics.filesTouchedCount !== undefined ? { filesTouchedCount: metrics.filesTouchedCount } : {}), + ...(metrics.packagesTouched !== undefined ? { packagesTouchedCount: metrics.packagesTouched.length } : {}), + ...(metrics.verificationFileScoped !== undefined ? { verificationFileScoped: metrics.verificationFileScoped } : {}), + ...(metrics.durationMs !== undefined ? { durationMs: metrics.durationMs } : {}), + }); + + return reflection; + } catch (error) { + await this.emitReflectionAudit(auditor, "reflection:failed", agentId, trigger, { taskId, ...options }, { + errorClass: error instanceof Error ? error.name : typeof error, + }); + reflectionLog.error(`Failed to capture task performance for ${agentId}/${taskId}: ${(error as Error).message}`); + return null; + } + } + + /** + * Build the deterministic structured metrics snapshot for a single completed task. Omits fields + * whose source data is unavailable rather than fabricating values. + * + * FNXC:AgentReflection 2026-07-04-00:00: + * Code review (FN-7528) flagged that `retryReworkCount` only reflected `Task.recoveryRetryCount`, + * silently dropping workflow step RETHINK/rework cycles tracked per-step-instance + * (`WorkflowRunStepInstance.reworkCount`, keyed by taskId+runId). `captureTaskPerformance` has no + * real runId threaded through, so we probe the same `${taskId}:run` fallback literal the executor + * itself falls back to when no runId is threaded (see executor.ts loadWorkflowRunStepInstances call + * sites) and sum reworkCount across every persisted instance row for that task. `retryReworkCount` + * is now `recoveryRetryCount + workflowReworkCount`; either driver is surfaced individually in + * `durationDrivers` (`retries:N` / `rework:N`) so the two causes stay distinguishable. + */ + private buildCapturedMetrics(taskId: string, task: Task, outcome: "completed" | "failed"): ReflectionMetrics { + const durationMs = this.calculateDurationMs(task); + const recoveryRetryCount = task.recoveryRetryCount ?? 0; + const workflowReworkCount = this.sumWorkflowStepReworkCount(taskId); + const retryReworkCount = recoveryRetryCount + workflowReworkCount; + + const touchedFiles = task.mergeDetails?.landedFiles ?? task.modifiedFiles; + const filesTouchedCount = touchedFiles ? touchedFiles.length : undefined; + const packagesTouched = touchedFiles ? this.derivePackagesTouched(touchedFiles) : undefined; + + const verification = this.deriveVerificationInfo(task); + + const durationDrivers: string[] = []; + if (recoveryRetryCount > 0) durationDrivers.push(`retries:${recoveryRetryCount}`); + if (workflowReworkCount > 0) durationDrivers.push(`rework:${workflowReworkCount}`); + if (verification?.fileScoped === false) durationDrivers.push("verification-broad"); + + const metrics: ReflectionMetrics = { + tasksCompleted: outcome === "completed" ? 1 : 0, + tasksFailed: outcome === "failed" ? 1 : 0, + ...(durationMs !== undefined ? { durationMs } : {}), + ...(durationDrivers.length > 0 ? { durationDrivers } : {}), + ...(packagesTouched && packagesTouched.length > 0 ? { packagesTouched } : {}), + ...(filesTouchedCount !== undefined ? { filesTouchedCount } : {}), + ...(retryReworkCount > 0 ? { retryReworkCount } : {}), + ...(verification?.commands ? { verificationCommands: verification.commands } : {}), + ...(verification?.fileScoped !== undefined ? { verificationFileScoped: verification.fileScoped } : {}), + ...(verification?.scopeReason ? { verificationScopeReason: verification.scopeReason } : {}), + }; + + return metrics; + } + + /** Deterministic one-line summary describing the captured snapshot (no LLM involvement). */ + private buildCapturedSummary(task: Task, outcome: "completed" | "failed", metrics: ReflectionMetrics): string { + const parts: string[] = [`Task ${task.id} ${outcome}`]; + if (metrics.durationMs !== undefined) { + parts.push(`in ${Math.round(metrics.durationMs / 1000)}s`); + } + if (metrics.retryReworkCount) { + parts.push(`with ${metrics.retryReworkCount} retry/rework cycle(s)`); + } + return `${parts.join(" ")}.`; + } + + /** + * Sum `reworkCount` across every persisted `WorkflowRunStepInstance` row for this task (KTD-6), + * under the same `${taskId}:run` fallback runId literal used elsewhere when no real runId is + * threaded. Returns 0 (never fabricated) when the store lacks the method or the table/rows don't + * exist — additive bookkeeping, degrades silently like its call sites in executor.ts. + */ + private sumWorkflowStepReworkCount(taskId: string): number { + const store = this.taskStore as unknown as { + loadWorkflowRunStepInstances?: (taskId: string, runId: string) => Array<{ reworkCount?: number }>; + }; + if (typeof store.loadWorkflowRunStepInstances !== "function") return 0; + try { + const rows = store.loadWorkflowRunStepInstances(taskId, `${taskId}:run`); + if (!Array.isArray(rows) || rows.length === 0) return 0; + return rows.reduce((sum, row) => sum + (row.reworkCount ?? 0), 0); + } catch { + return 0; + } + } + + /** Map touched file paths to package identifiers (e.g. "packages/core/src/x.ts" -> "packages/core"). */ + private derivePackagesTouched(files: string[]): string[] { + const packages = new Set(); + for (const file of files) { + const match = /^packages\/([^/]+)\//.exec(file); + if (match) { + packages.add(`packages/${match[1]}`); + } + } + return Array.from(packages).sort(); + } + + /** + * Derive verification command(s) and file-scoped-vs-broader classification from the task's + * deterministic post-merge verification log entries (`[verification] Running deterministic + * verification (...)`, written by the executor). Returns undefined when no such entry exists — + * capture omits the field rather than guessing. + */ + private deriveVerificationInfo(task: Task): { commands: string[]; fileScoped?: boolean; scopeReason?: string } | undefined { + const entry = [...task.log].reverse().find((logEntry) => + /\[verification\] running deterministic verification/i.test(logEntry.action), + ); + if (!entry) { + return undefined; + } + + const match = /\(([^)]*)\)/.exec(entry.action); + if (!match || !match[1].trim()) { + return undefined; + } + + const commands = match[1] + .split(",") + .map((part) => part.trim()) + .filter(Boolean); + + if (commands.length === 0) { + return undefined; + } + + const broadPatterns = [ + /\btest:full\b/i, + /\bverify:workspace\b/i, + /\btest:workspace\b/i, + ]; + const isBroad = commands.some((command) => broadPatterns.some((pattern) => pattern.test(command))); + + if (isBroad) { + return { + commands, + fileScoped: false, + scopeReason: "configured test/build command runs the broader workspace suite rather than a file-scoped target", + }; + } + + // FNXC:AgentReflection 2026-07-04-00:00: Code review (FN-7528) flagged that non-broad commands + // left `verificationFileScoped` undefined instead of recording the positive classification; + // captured records must state true/false explicitly whenever a verification command is known. + return { commands, fileScoped: true }; + } + private async emitReflectionAudit( auditor: RunAuditor, - type: "reflection:generated" | "reflection:skipped" | "reflection:failed", + type: "reflection:generated" | "reflection:skipped" | "reflection:failed" | "reflection:captured", agentId: string, trigger: ReflectionTrigger, options: { taskId?: string; triggerDetail?: string }, diff --git a/packages/engine/src/executor.ts b/packages/engine/src/executor.ts index 9b2163348c..d274bdabb0 100644 --- a/packages/engine/src/executor.ts +++ b/packages/engine/src/executor.ts @@ -1667,6 +1667,14 @@ export class TaskExecutor { private resumingUnpaused = new Set(); /** Completed orphan recovery tasks currently running during startup. */ private recoveringCompleted = new Set(); + /** + * FNXC:AgentReflection 2026-07-04-00:00: + * FN-7528: taskIds for which a non-LLM post-task performance capture has already been fired via + * `signalTaskComplete`. `onComplete` fires from several completion call sites (fresh completion, + * duplicate in-review re-entry, auto-recovery, paused-after-completion finalize, retry-completed), + * so this in-memory guard keeps capture to once per completion instead of once per call site. + */ + private capturedReflectionTaskIds = new Set(); /** Tracks tasks whose workflow-rerun bounce is in flight (todo→in-progress). * Prevents the task:moved handler from dispatching execute() before the * bounce finishes its own dispatch. */ @@ -3403,6 +3411,43 @@ export class TaskExecutor { this.completedTaskWatchdogs.delete(taskId); } + /** + * FNXC:AgentReflection 2026-07-04-00:00: + * FN-7528: single seam for every `onComplete` call site. Fires the deterministic, non-LLM + * post-task performance capture (best-effort, fire-and-forget — a capture failure must never + * block or fail task completion) before forwarding to the configured `onComplete` callback. + * Capture is completion-gated: only runs once per taskId (see `capturedReflectionTaskIds`), + * guarded by `reflectionService` presence, `settings.reflectionEnabled`, and an assigned agent id + * mirroring the existing in-session reflection-tool guard. + */ + private signalTaskComplete(task: Task): void { + this.triggerPostTaskReflectionCapture(task); + this.options.onComplete?.(task); + } + + private triggerPostTaskReflectionCapture(task: Task): void { + const reflectionService = this.options.reflectionService; + if (!reflectionService) return; + + const assignedAgentId = task.assignedAgentId?.trim(); + if (!assignedAgentId) return; + + if (this.capturedReflectionTaskIds.has(task.id)) return; + this.capturedReflectionTaskIds.add(task.id); + + void (async () => { + try { + const settings = await this.store.getSettings(); + if (!settings.reflectionEnabled) return; + await reflectionService.captureTaskPerformance(assignedAgentId, task.id); + } catch (error) { + executorLog.warn( + `${task.id}: post-task performance capture failed (best-effort, non-blocking): ${error instanceof Error ? error.message : String(error)}`, + ); + } + })(); + } + private clearWorkflowRerunWatchdog(taskId: string): void { const handle = this.workflowRerunWatchdogs.get(taskId); if (!handle) return; @@ -3726,14 +3771,14 @@ export class TaskExecutor { if (liveTask.column === "in-review") { this.clearCompletedTaskWatchdog(task.id); - this.options.onComplete?.(liveTask); + this.signalTaskComplete(liveTask); return true; } const refreshedTask = await this.store.getTask(task.id); await this.handoffTaskToReview(refreshedTask ?? liveTask, "post-done-noncontinuable"); this.clearCompletedTaskWatchdog(task.id); - this.options.onComplete?.(refreshedTask ?? liveTask); + this.signalTaskComplete(refreshedTask ?? liveTask); return true; } @@ -4125,7 +4170,7 @@ export class TaskExecutor { this.clearCompletedTaskWatchdog(task.id); await this.store.logEntry(task.id, `Auto-recovered: task work was complete but stranded in ${originColumn} — moved to in-review`); executorLog.log(`✓ ${task.id} auto-recovered completed task → in-review`); - this.options.onComplete?.(task); + this.signalTaskComplete(task); return true; } catch (err: unknown) { this.recoveringCompleted.delete(task.id); @@ -9905,7 +9950,7 @@ export class TaskExecutor { await this.handoffTaskToReview(task, "step-session-completed"); this.clearCompletedTaskWatchdog(task.id); executorLog.log(`✓ ${task.id} completed (step-session) → in-review`); - this.options.onComplete?.(task); + this.signalTaskComplete(task); } else { const failedSteps = results.filter(r => !r.success); const errorSummary = failedSteps.map(r => `Step ${r.stepIndex}: ${r.error || "unknown error"}`).join("; "); @@ -10632,7 +10677,7 @@ export class TaskExecutor { this.markCompletionFinalized(task.id); await this.handoffTaskToReview(task, "paused-after-completion"); this.clearCompletedTaskWatchdog(task.id); - this.options.onComplete?.(task); + this.signalTaskComplete(task); } else { executorLog.log(`${task.id} paused (graceful session exit) — moving to todo`); await this.store.logEntry(task.id, "Execution paused — session preserved for resume, moved to todo"); @@ -10727,7 +10772,7 @@ export class TaskExecutor { await this.handoffTaskToReview(task, "fn_task_done"); this.clearCompletedTaskWatchdog(task.id); executorLog.log(`✓ ${task.id} completed → in-review`); - this.options.onComplete?.(task); + this.signalTaskComplete(task); } else { let taskDoneSessionRetries = 0; let retryAbortedDueToReclaim = false; @@ -11003,7 +11048,7 @@ export class TaskExecutor { await this.handoffTaskToReview(task, "fn_task_done-retry-completed"); this.clearCompletedTaskWatchdog(task.id); executorLog.log(`✓ ${task.id} completed on retry → in-review`); - this.options.onComplete?.(task); + this.signalTaskComplete(task); } else if (retryAbortedDueToReclaim) { // FN-4806: Worktree/branch was reclaimed mid-retry by an engine-side housekeeping path // (e.g. FN-4546 stale-active-branch reclaim, FN-4742 self-healing removals). This is NOT @@ -11132,7 +11177,7 @@ export class TaskExecutor { } } // Task finished successfully (just already moved), so call onComplete - this.options.onComplete?.(task); + this.signalTaskComplete(task); } else if (this.pausedAborted.has(task.id)) { // Task was paused mid-execution — clean up worktree and move to todo if (this.userCanceledTaskIds.has(task.id)) { @@ -11174,7 +11219,7 @@ export class TaskExecutor { */ this.markCompletionFinalized(task.id); await this.handoffTaskToReview(task, "paused-after-completion"); - this.options.onComplete?.(task); + this.signalTaskComplete(task); } else { executorLog.log(`${task.id} paused — moving to todo`); if (worktreePath && existsSync(worktreePath)) { diff --git a/packages/engine/src/run-audit.ts b/packages/engine/src/run-audit.ts index 57183db02f..75e87f759a 100644 --- a/packages/engine/src/run-audit.ts +++ b/packages/engine/src/run-audit.ts @@ -624,10 +624,39 @@ export type DatabaseMutationType = * errorClass: string; * } * ``` + * + * FNXC:AgentReflection 2026-07-04-00:00: + * FN-7528 adds a deterministic, non-LLM post-task performance capture (AgentReflectionService.captureTaskPerformance), + * distinct from the LLM-backed generateReflection above. `reflection:captured` fires once per completed task and stays + * ids/counts/outcomes-only: no free-form verificationScopeReason text, insight/summary prose, or prompt text. + * Metadata shape for `reflection:captured`: + * ```ts + * { + * agentId: string; + * trigger: "post-task"; + * taskId?: string; + * reflectionId: string; + * retryReworkCount?: number; + * filesTouchedCount?: number; + * packagesTouchedCount?: number; + * verificationFileScoped?: boolean; + * durationMs?: number; + * } + * ``` + * Metadata shape for a skipped capture (emitted via `reflection:skipped` with `reason: "not-completed"` or `"no-history"`): + * ```ts + * { + * agentId: string; + * trigger: "post-task"; + * taskId?: string; + * reason: "no-history" | "not-completed"; + * } + * ``` */ | "reflection:generated" | "reflection:skipped" | "reflection:failed" + | "reflection:captured" | "task:in-review-stall-deadlock-disposed" | "task:in-review-stall-terminal-provider-error" | "task:finalize-unproven-blocked"