diff --git a/docs/task-management.md b/docs/task-management.md index b6b1c2ba8..55186f685 100644 --- a/docs/task-management.md +++ b/docs/task-management.md @@ -217,6 +217,10 @@ The task detail modal exposes multiple tabs: - **Log** — task event history - **Changes** — merge diff/change summary - **Workflow** — workflow step results (pass/fail/skip) +- **Stats** — execution timing + token usage breakdown + - `Total execution time` prefers durable wall-clock execution window (`executionStartedAt` → `executionCompletedAt`) + - Fallback order for legacy tasks: `timedExecutionMs` when present, otherwise `[timing]` log sum + workflow runtime + - Workflow runtime is shown as a separate metric and is not double-counted into totals when `timedExecutionMs` is already available - **Comments** — collaboration thread + steering controls - **Model** — per-task model overrides and thinking level diff --git a/packages/dashboard/app/components/TaskCard.tsx b/packages/dashboard/app/components/TaskCard.tsx index 33858e532..1168de319 100644 --- a/packages/dashboard/app/components/TaskCard.tsx +++ b/packages/dashboard/app/components/TaskCard.tsx @@ -13,7 +13,7 @@ import { getFreshBatchData } from "../hooks/useBatchBadgeFetch"; import { useTaskDiffStats } from "../hooks/useTaskDiffStats"; import { isTaskStuck } from "../utils/taskStuck"; import { getUnifiedTaskProgress } from "../utils/taskProgress"; -import { getTimedDurationMs } from "../utils/taskTiming"; +import { getEndToEndDurationMs, getTimedDurationMs, getWorkflowRuntimeMs, parseTimestampToMs } from "../utils/taskTiming"; import type { ToastType } from "../hooks/useToast"; import { useConfirm } from "../hooks/useConfirm"; @@ -124,12 +124,6 @@ function getTaskStatusLabel(status: string): string { return status; } -function parseTimestampToMs(value?: string): number | null { - if (!value) return null; - const parsed = Date.parse(value); - return Number.isFinite(parsed) ? parsed : null; -} - function getDoneCompletionMs(task: Task): number | null { const completionMs = parseTimestampToMs(task.columnMovedAt ?? task.updatedAt); if (completionMs == null) return null; @@ -153,13 +147,8 @@ function getInProgressElapsedMs(task: Task, nowMs: number): number | null { // timer reflects how long the task actually took, not just the time spent // inside instrumented code paths. Returns null on legacy tasks that completed // before `executionStartedAt` was tracked, so callers can fall back. -function getEndToEndDurationMs(task: Task, nowMs: number): number | null { - const startedMs = parseTimestampToMs(task.executionStartedAt); - if (startedMs == null) return null; - - const completedMs = parseTimestampToMs(task.executionCompletedAt); - const endMs = completedMs != null && completedMs >= startedMs ? completedMs : nowMs; - return Math.max(0, endMs - startedMs); +function getTaskEndToEndDurationMs(task: Task, nowMs: number): number | null { + return getEndToEndDurationMs(task.executionStartedAt, task.executionCompletedAt, nowMs); } function getInReviewCompletionMs(task: Task): number | null { @@ -176,7 +165,7 @@ function getMergeElapsedMs(task: Task, nowMs: number): number | null { } function getActiveMergeTotalMs(task: Task, nowMs: number): number | null { - const endToEndMs = getEndToEndDurationMs(task, nowMs); + const endToEndMs = getTaskEndToEndDurationMs(task, nowMs); if (endToEndMs != null) { return endToEndMs; } @@ -190,43 +179,17 @@ function getActiveMergeTotalMs(task: Task, nowMs: number): number | null { return mergeElapsedMs; } -// Mirrors summarizeWorkflowTiming in TaskTokenStatsPanel: completed steps use -// completedAt-startedAt; in-progress steps contribute live elapsed (now-startedAt). -function getWorkflowRuntimeMs(task: Task, nowMs: number): number | null { - const results = task.workflowStepResults; - if (!results || results.length === 0) return null; - - let total = 0; - let counted = 0; - for (const step of results) { - if (!step.startedAt) continue; - const startedMs = parseTimestampToMs(step.startedAt); - if (startedMs == null) continue; - - let endMs: number; - if (step.completedAt) { - const completedMs = parseTimestampToMs(step.completedAt); - if (completedMs == null || completedMs < startedMs) continue; - endMs = completedMs; - } else { - endMs = Math.max(startedMs, nowMs); - } - total += endMs - startedMs; - counted += 1; - } - return counted > 0 ? total : null; -} function getInstrumentedDurationMs(task: Task, nowMs: number): number | null { - // Prefer the server-aggregated `timedExecutionMs` (populated for slim board - // listings, where `task.log` is stripped to keep the wire payload small). - // Fall back to client-side parsing of the full log for the detail-modal - // path where the slim aggregate is absent but the log is loaded. - const timed = - typeof task.timedExecutionMs === "number" - ? task.timedExecutionMs - : getTimedDurationMs(task.log); - const workflow = getWorkflowRuntimeMs(task, nowMs); + // Prefer server aggregate when present: it is the canonical persisted runtime + // and may already include workflow execution. Avoid adding workflow runtime + // again in that case. + if (typeof task.timedExecutionMs === "number") { + return task.timedExecutionMs; + } + + const timed = getTimedDurationMs(task.log); + const workflow = getWorkflowRuntimeMs(task.workflowStepResults, nowMs); if (timed == null && workflow == null) return null; return (timed ?? 0) + (workflow ?? 0); } @@ -777,7 +740,7 @@ function TaskCardComponent({ const merging = task.status != null && ACTIVE_MERGE_STATUSES.has(task.status); if (task.column === "in-progress") { - const endToEndMs = getEndToEndDurationMs(task, Date.now()); + const endToEndMs = getTaskEndToEndDurationMs(task, Date.now()); const elapsedMs = getInProgressElapsedMs(task, Date.now()); const instrumentedMs = getInstrumentedDurationMs(task, Date.now()); if (endToEndMs == null && elapsedMs == null && instrumentedMs == null) { @@ -786,7 +749,7 @@ function TaskCardComponent({ } if (!merging && task.column === "in-review") { - const endToEndMs = getEndToEndDurationMs(task, Date.now()); + const endToEndMs = getTaskEndToEndDurationMs(task, Date.now()); const instrumentedMs = getInstrumentedDurationMs(task, Date.now()); if (endToEndMs == null && instrumentedMs == null) { return; @@ -833,7 +796,7 @@ function TaskCardComponent({ // in-progress, never reset on retry-loop bounces). Fall back to the // columnMovedAt heuristic for legacy tasks predating the new field. const elapsedMs = - getEndToEndDurationMs(task, timeIndicatorNowMs) + getTaskEndToEndDurationMs(task, timeIndicatorNowMs) ?? getInProgressElapsedMs(task, timeIndicatorNowMs) ?? getInstrumentedDurationMs(task, timeIndicatorNowMs); if (elapsedMs == null) { @@ -855,7 +818,7 @@ function TaskCardComponent({ // in-review and done: show wall-clock end-to-end runtime. Falls back to // the instrumented `[timing]` aggregate for tasks completed before // `executionStartedAt`/`executionCompletedAt` were tracked. - const endToEndMs = getEndToEndDurationMs(task, timeIndicatorNowMs); + const endToEndMs = getTaskEndToEndDurationMs(task, timeIndicatorNowMs); const totalMs = endToEndMs ?? getInstrumentedDurationMs(task, timeIndicatorNowMs); if (totalMs == null) { return null; diff --git a/packages/dashboard/app/components/TaskTokenStatsPanel.tsx b/packages/dashboard/app/components/TaskTokenStatsPanel.tsx index fbece97b1..75646bde1 100644 --- a/packages/dashboard/app/components/TaskTokenStatsPanel.tsx +++ b/packages/dashboard/app/components/TaskTokenStatsPanel.tsx @@ -1,5 +1,5 @@ import type { Task, TaskTokenUsage, WorkflowStepResult } from "@fusion/core"; -import { extractTimingEvents, type TimingEvent } from "../utils/taskTiming"; +import { extractTimingEvents, getEndToEndDurationMs, getTimedDurationMs, getWorkflowRuntimeMs, type TimingEvent } from "../utils/taskTiming"; import "./TaskTokenStatsPanel.css"; interface TaskTokenStatsPanelProps { @@ -26,6 +26,8 @@ interface TaskTokenStatsPanelProps { | "assignedAgentId" | "blockedBy" | "sessionFile" + | "executionStartedAt" + | "executionCompletedAt" >; } @@ -71,7 +73,6 @@ function summarizeWorkflowTiming(results: WorkflowStepResult[]): WorkflowTimingS if (Number.isNaN(startedMs)) { return null; } - // Completed step → use completedAt. In-progress step → live elapsed. let endMs: number; if (step.completedAt) { const completedMs = new Date(step.completedAt).getTime(); @@ -89,7 +90,7 @@ function summarizeWorkflowTiming(results: WorkflowStepResult[]): WorkflowTimingS }) .filter((value): value is { name: string; durationMs: number } => value !== null); - const totalDurationMs = timedResults.reduce((sum, step) => sum + step.durationMs, 0); + const totalDurationMs = getWorkflowRuntimeMs(results, nowMs) ?? 0; const longestStep = timedResults.reduce<{ name: string; durationMs: number } | undefined>((longest, step) => { if (!longest || step.durationMs > longest.durationMs) { return step; @@ -105,10 +106,14 @@ function summarizeWorkflowTiming(results: WorkflowStepResult[]): WorkflowTimingS } export function TaskTokenStatsPanel({ tokenUsage, loading, task }: TaskTokenStatsPanelProps) { + const nowMs = Date.now(); const timingEvents = extractTimingEvents(task?.log ?? []); const timedTimingEvents = timingEvents.filter((event) => typeof event.durationMs === "number"); const logTimingDurationMs = timedTimingEvents.reduce((sum, event) => sum + (event.durationMs ?? 0), 0); - const totalTimingDurationMs = Math.max(logTimingDurationMs, task?.timedExecutionMs ?? 0); + const parsedTimingDurationMs = getTimedDurationMs(task?.log) ?? 0; + const totalTimingDurationMs = typeof task?.timedExecutionMs === "number" + ? task.timedExecutionMs + : Math.max(logTimingDurationMs, parsedTimingDurationMs); const longestTimingEvent = timedTimingEvents.reduce((longest, event) => { if (!longest || (event.durationMs ?? 0) > (longest.durationMs ?? 0)) { return event; @@ -117,6 +122,15 @@ export function TaskTokenStatsPanel({ tokenUsage, loading, task }: TaskTokenStat }, undefined); const workflowTiming = summarizeWorkflowTiming(task?.workflowStepResults ?? []); + const endToEndDurationMs = getEndToEndDurationMs(task?.executionStartedAt, task?.executionCompletedAt, nowMs); + // Canonical fallback order for Task Detail Stats total runtime: + // 1) durable wall-clock execution window (`executionStartedAt` → `executionCompletedAt`), + // 2) server aggregate `timedExecutionMs` when present, + // 3) legacy local aggregate (`[timing]` sum + workflow runtime). + // This avoids double counting when workflow timings appear in both `[timing]` + // logs and `workflowStepResults`. + const totalExecutionMs = endToEndDurationMs + ?? (typeof task?.timedExecutionMs === "number" ? task.timedExecutionMs : totalTimingDurationMs + workflowTiming.totalDurationMs); const taskStepCount = task?.steps?.length ?? 0; return ( @@ -144,7 +158,7 @@ export function TaskTokenStatsPanel({ tokenUsage, loading, task }: TaskTokenStat
Total execution time - {formatDuration(totalTimingDurationMs + workflowTiming.totalDurationMs)} + {formatDuration(totalExecutionMs)}
diff --git a/packages/dashboard/app/components/__tests__/TaskDetailModal.rendering.test.tsx b/packages/dashboard/app/components/__tests__/TaskDetailModal.rendering.test.tsx index 7a20256bf..1cfdf0935 100644 --- a/packages/dashboard/app/components/__tests__/TaskDetailModal.rendering.test.tsx +++ b/packages/dashboard/app/components/__tests__/TaskDetailModal.rendering.test.tsx @@ -1409,5 +1409,43 @@ describe("TaskDetailModal", () => { }); }); + it("renders corrected stats timing totals in Stats tab", () => { + render( + , + ); + + fireEvent.click(screen.getByRole("button", { name: "Stats" })); + + const totalMetric = screen.getByText("Total execution time").closest(".task-token-stats-panel__metric"); + const workflowMetric = screen.getByText("Workflow runtime").closest(".task-token-stats-panel__metric"); + + expect(totalMetric).toHaveTextContent("4m 0s"); + expect(screen.getByText("Timed duration").closest(".task-token-stats-panel__metric")).toHaveTextContent("2m 0s"); + expect(workflowMetric).toHaveTextContent("1m 0s"); + }); }); diff --git a/packages/dashboard/app/components/__tests__/TaskTokenStatsPanel.test.tsx b/packages/dashboard/app/components/__tests__/TaskTokenStatsPanel.test.tsx index 6f56c04ce..f43a98fd0 100644 --- a/packages/dashboard/app/components/__tests__/TaskTokenStatsPanel.test.tsx +++ b/packages/dashboard/app/components/__tests__/TaskTokenStatsPanel.test.tsx @@ -133,4 +133,85 @@ describe("TaskTokenStatsPanel", () => { expect(screen.getByText("Timed duration")).toBeInTheDocument(); expect(screen.getAllByText("4m 0s").length).toBeGreaterThan(0); }); + + it("uses end-to-end execution window for total execution time when available", () => { + render( + , + ); + + expect(screen.getByText("Total execution time")).toBeInTheDocument(); + expect(screen.getByText("5m 0s")).toBeInTheDocument(); + }); + + it("does not double count workflow runtime when timedExecutionMs is present", () => { + render( + , + ); + + const metric = screen.getByText("Total execution time").closest(".task-token-stats-panel__metric"); + expect(metric).toHaveTextContent("2m 0s"); + expect(screen.getByText("Workflow runtime").closest(".task-token-stats-panel__metric")).toHaveTextContent("1m 0s"); + }); + + it("uses legacy timed plus workflow fallback when end-to-end and timedExecutionMs are unavailable", () => { + render( + , + ); + + const metric = screen.getByText("Total execution time").closest(".task-token-stats-panel__metric"); + expect(metric).toHaveTextContent("3m 0s"); + }); }); diff --git a/packages/dashboard/app/utils/taskTiming.ts b/packages/dashboard/app/utils/taskTiming.ts index 4d367e638..9777d19a7 100644 --- a/packages/dashboard/app/utils/taskTiming.ts +++ b/packages/dashboard/app/utils/taskTiming.ts @@ -1,4 +1,4 @@ -import type { TaskLogEntry } from "@fusion/core"; +import type { TaskLogEntry, WorkflowStepResult } from "@fusion/core"; export interface TimingEvent { timestamp: string; @@ -47,3 +47,48 @@ export function getTimedDurationMs(logEntries: TaskLogEntry[] | undefined): numb } return counted > 0 ? total : null; } + +export function parseTimestampToMs(value?: string): number | null { + if (!value) return null; + const parsed = Date.parse(value); + return Number.isFinite(parsed) ? parsed : null; +} + +export function getWorkflowRuntimeMs(results: WorkflowStepResult[] | undefined, nowMs: number): number | null { + if (!results || results.length === 0) return null; + + let total = 0; + let counted = 0; + for (const step of results) { + if (!step.startedAt) continue; + const startedMs = parseTimestampToMs(step.startedAt); + if (startedMs == null) continue; + + let endMs: number; + if (step.completedAt) { + const completedMs = parseTimestampToMs(step.completedAt); + if (completedMs == null || completedMs < startedMs) continue; + endMs = completedMs; + } else { + endMs = Math.max(startedMs, nowMs); + } + + total += endMs - startedMs; + counted += 1; + } + + return counted > 0 ? total : null; +} + +export function getEndToEndDurationMs( + executionStartedAt: string | undefined, + executionCompletedAt: string | undefined, + nowMs: number, +): number | null { + const startedMs = parseTimestampToMs(executionStartedAt); + if (startedMs == null) return null; + + const completedMs = parseTimestampToMs(executionCompletedAt); + const endMs = completedMs != null && completedMs >= startedMs ? completedMs : nowMs; + return Math.max(0, endMs - startedMs); +}