🤖 fix: start tool elapsed timers when execute() actually runs

src/browser/features/Messages/ToolMessage.tsx

@@ -63,8 +63,14 @@ export const ToolMessage: React.FC<ToolMessageProps> = ({
           toolCallId={toolCallId}
           // Workflow-specific
           workflowRunHint={message.workflowRun}
-          // Bash-specific
-          startedAt={message.timestamp}
+          // Elapsed timers (bash/advisor/task_await): start when execute() actually
+          // began running, not when the model emitted the call — parallel tool calls
+          // run sequentially, so queued calls must not accumulate elapsed time.
+          startedAt={message.executionStartedAt}
+          // Freshness lower bound (task/workflow discovery): when the model emitted the
+          // call. Unlike executionStartedAt this survives history replay of parts that
+          // predate execution-start tracking.
+          toolCallTimestamp={message.timestamp}
           // FileEdit-specific
           onReviewNote={onReviewNote}
           // ProposePlan-specific

src/browser/features/Tools/Shared/ElapsedTimeDisplay.tsx

@@ -10,6 +10,10 @@ interface ElapsedTimeDisplayProps {
 /**
  * Shared elapsed time display for tool headers.
  * Keeps requestAnimationFrame + per-second updates at the leaf so parent tool calls do not re-render.
+ *
+ * Renders nothing until `startedAt` is known: for tool calls, that is when execute()
+ * actually begins running. Parallel tool calls run sequentially, so a queued call has
+ * no start time yet and must not show a ticking timer (it could exceed its own timeout).
  */
 export const ElapsedTimeDisplay: React.FC<ElapsedTimeDisplayProps> = ({
   startedAt,
@@ -23,7 +27,7 @@ export const ElapsedTimeDisplay: React.FC<ElapsedTimeDisplayProps> = ({
   const baseStart = useRef(startedAt ?? Date.now());
 
   useEffect(() => {
-    if (!isActive) {
+    if (!isActive || startedAt === undefined) {
       elapsedRef.current = 0;
       if (frameRef.current !== null) {
         cancelAnimationFrame(frameRef.current);
@@ -32,7 +36,7 @@ export const ElapsedTimeDisplay: React.FC<ElapsedTimeDisplayProps> = ({
       return;
     }
 
-    baseStart.current = startedAt ?? Date.now();
+    baseStart.current = startedAt;
     let lastSecond = -1;
 
     const tick = () => {
@@ -60,7 +64,7 @@ export const ElapsedTimeDisplay: React.FC<ElapsedTimeDisplayProps> = ({
     };
   }, [isActive, startedAt]);
 
-  if (!isActive || elapsedRef.current === 0) {
+  if (!isActive || startedAt === undefined || elapsedRef.current === 0) {
     return null;
   }
 

src/browser/features/Tools/TaskToolCall.tsx

@@ -437,6 +437,8 @@ interface TaskToolCallProps {
   workspaceId?: string;
   toolCallId?: string;
   startedAt?: number;
+  /** When the model emitted the call; freshness fallback when startedAt is unknown. */
+  toolCallTimestamp?: number;
 }
 
 interface TaskToolDisplayEntry {
@@ -836,6 +838,7 @@ export const TaskToolCall: React.FC<TaskToolCallProps> = ({
   taskReportLinking,
   toolCallId,
   startedAt,
+  toolCallTimestamp,
 }) => {
   const errorResult = isToolErrorResult(result) ? result : null;
   const successResult: TaskToolSuccessResult | null =
@@ -869,7 +872,10 @@ export const TaskToolCall: React.FC<TaskToolCallProps> = ({
     requestedCandidateCount: requestedTaskGroupCount,
     requestedGroupKind: taskGroupKind,
     knownTaskIds: [...resultTaskIds, ...liveTaskIds, ...recoveredTaskIdsRef.current],
-    toolStartedAt: startedAt,
+    // Prefer the true execution start; fall back to the model-emission timestamp for
+    // parts without execution-start tracking (history replay). Both are valid lower
+    // bounds on when this call could have created child workspaces.
+    toolStartedAt: startedAt ?? toolCallTimestamp,
     workspaceMetadata,
   });
   if (recoveredWorkspaceEntries.length > 0) {

src/browser/features/Tools/WorkflowRunToolCall.tsx

@@ -79,6 +79,8 @@ interface WorkflowRunToolCallProps {
   workspaceId?: string;
   toolCallId?: string;
   startedAt?: number;
+  /** When the model emitted the call; freshness fallback when startedAt is unknown. */
+  toolCallTimestamp?: number;
   /** Which tool rendered this card; controls the header icon. */
   toolName?: "workflow_run" | "workflow_resume";
   /**
@@ -1159,10 +1161,14 @@ export const WorkflowRunToolCall: React.FC<WorkflowRunToolCallProps> = ({
   workspaceId,
   toolCallId,
   startedAt,
+  toolCallTimestamp,
   toolName = "workflow_run",
   knownRunId,
   workflowRunHint: explicitWorkflowRunHint,
 }) => {
+  // Freshness bound for run discovery: prefer the true execution start, but fall back to
+  // the model-emission timestamp for parts without execution-start tracking (history replay).
+  const discoveryFreshnessBound = startedAt ?? toolCallTimestamp;
   const apiState = useContext(APIContext);
   const commandRegistry = useOptionalCommandRegistry();
   const registerCommandSource = commandRegistry?.registerSource;
@@ -1395,7 +1401,11 @@ export const WorkflowRunToolCall: React.FC<WorkflowRunToolCallProps> = ({
     const discover = async () => {
       try {
         const runs = await apiState.api.workflows.listRuns({ workspaceId });
-        const foregroundRun = findForegroundWorkflowRun({ runs, args, startedAt });
+        const foregroundRun = findForegroundWorkflowRun({
+          runs,
+          args,
+          startedAt: discoveryFreshnessBound,
+        });
         if (!ignore && foregroundRun != null) {
           setRefreshedRun((current) => getNewestWorkflowRunSnapshot(current, foregroundRun));
         }
@@ -1412,7 +1422,7 @@ export const WorkflowRunToolCall: React.FC<WorkflowRunToolCallProps> = ({
       ignore = true;
       window.clearInterval(interval);
     };
-  }, [apiState?.api, args, runId, startedAt, status, workspaceId]);
+  }, [apiState?.api, args, runId, discoveryFreshnessBound, status, workspaceId]);
 
   const exactDiscoveryRunId = knownRunId ?? workflowRunHint?.runId;
 

src/browser/stores/WorkspaceStore.ts

@@ -897,6 +897,10 @@ export class WorkspaceStore {
       applyWorkspaceChatEventToAggregator(aggregator, data);
       this.states.bump(workspaceId);
     },
+    "tool-call-execution-start": (workspaceId, aggregator, data) => {
+      applyWorkspaceChatEventToAggregator(aggregator, data);
+      this.states.bump(workspaceId);
+    },
     "tool-call-delta": (workspaceId, aggregator, data) => {
       applyWorkspaceChatEventToAggregator(aggregator, data);
       this.scheduleStreamingStateBump(workspaceId);

src/browser/utils/messages/StreamingMessageAggregator.test.ts

@@ -1903,6 +1903,201 @@ describe("StreamingMessageAggregator", () => {
     });
   });
 
+  test("tool-call-execution-start stamps executionStartedAt onto the displayed tool row", () => {
+    const aggregator = new StreamingMessageAggregator(TEST_CREATED_AT);
+
+    startTestStream(aggregator, { messageId: "msg-1" });
+    startToolCall(aggregator, {
+      toolCallId: "tool-queued",
+      toolName: "bash",
+      args: { command: "echo hi" },
+      timestamp: 1_000,
+    });
+
+    // Queued behind a sibling: no execution start yet.
+    const queuedRow = aggregator
+      .getDisplayedMessages()
+      .find((m) => m.type === "tool" && m.toolCallId === "tool-queued");
+    expect(queuedRow?.type).toBe("tool");
+    expect(queuedRow?.type === "tool" ? queuedRow.executionStartedAt : null).toBeUndefined();
+
+    aggregator.handleToolCallExecutionStart({
+      type: "tool-call-execution-start",
+      workspaceId: TEST_WORKSPACE_ID,
+      messageId: "msg-1",
+      toolCallId: "tool-queued",
+      timestamp: 5_000,
+    });
+
+    const executingRow = aggregator
+      .getDisplayedMessages()
+      .find((m) => m.type === "tool" && m.toolCallId === "tool-queued");
+    expect(executingRow?.type === "tool" ? executingRow.executionStartedAt : undefined).toBe(5_000);
+  });
+
+  test("tool execution stats measure from execution start, not queue entry", () => {
+    const aggregator = new StreamingMessageAggregator(TEST_CREATED_AT);
+
+    startTestStream(aggregator, { messageId: "msg-1" });
+    // Two parallel tool calls emitted back-to-back; they execute sequentially.
+    startToolCall(aggregator, {
+      toolCallId: "tool-a",
+      toolName: "bash",
+      args: {},
+      timestamp: 1_000,
+    });
+    startToolCall(aggregator, {
+      toolCallId: "tool-b",
+      toolName: "bash",
+      args: {},
+      timestamp: 1_001,
+    });
+
+    aggregator.handleToolCallExecutionStart({
+      type: "tool-call-execution-start",
+      workspaceId: TEST_WORKSPACE_ID,
+      messageId: "msg-1",
+      toolCallId: "tool-a",
+      timestamp: 1_002,
+    });
+    endToolCall(aggregator, {
+      toolCallId: "tool-a",
+      toolName: "bash",
+      result: {},
+      timestamp: 5_000,
+    });
+    aggregator.handleToolCallExecutionStart({
+      type: "tool-call-execution-start",
+      workspaceId: TEST_WORKSPACE_ID,
+      messageId: "msg-1",
+      toolCallId: "tool-b",
+      timestamp: 5_001,
+    });
+    endToolCall(aggregator, {
+      toolCallId: "tool-b",
+      toolName: "bash",
+      result: {},
+      timestamp: 9_000,
+    });
+
+    const stats = aggregator.getActiveStreamTimingStats();
+    // A: 5000-1002, B: 9000-5001. Without execution-start re-anchoring, B would
+    // count from emission (9000-1001) and double-count A's run time.
+    expect(stats?.toolExecutionMs).toBe(3_998 + 3_999);
+  });
+
+  test("replayed tool-call-start merges executionStartedAt into an existing tool part", () => {
+    const aggregator = new StreamingMessageAggregator(TEST_CREATED_AT);
+
+    startTestStream(aggregator, { messageId: "msg-1" });
+    // Client saw the queued tool-call-start live (no execution start yet)...
+    startToolCall(aggregator, {
+      toolCallId: "tool-reconnect",
+      toolName: "bash",
+      args: { command: "echo hi" },
+      timestamp: 1_000,
+    });
+
+    // ...disconnected, execute() began, and the `since` replay re-sends the enriched start.
+    aggregator.handleToolCallStart({
+      type: "tool-call-start",
+      workspaceId: TEST_WORKSPACE_ID,
+      messageId: "msg-1",
+      toolCallId: "tool-reconnect",
+      toolName: "bash",
+      args: { command: "echo hi" },
+      tokens: 0,
+      timestamp: 1_000,
+      executionStartedAt: 6_000,
+      replay: true,
+    });
+
+    const row = aggregator
+      .getDisplayedMessages()
+      .find((m) => m.type === "tool" && m.toolCallId === "tool-reconnect");
+    expect(row?.type === "tool" ? row.executionStartedAt : undefined).toBe(6_000);
+
+    // The merge must also re-anchor timing stats: the tool's duration counts from
+    // execution start (6000), not the pre-disconnect emission seed (1000).
+    endToolCall(aggregator, {
+      toolCallId: "tool-reconnect",
+      toolName: "bash",
+      result: {},
+      timestamp: 9_000,
+    });
+    expect(aggregator.getActiveStreamTimingStats()?.toolExecutionMs).toBe(3_000);
+  });
+
+  test("stashes execution starts that arrive before their tool part exists", () => {
+    const aggregator = new StreamingMessageAggregator(TEST_CREATED_AT);
+
+    startTestStream(aggregator, { messageId: "msg-1" });
+    // Reconnect replay in progress: the live execution-start (not replay-buffered)
+    // arrives before the replayed tool-call-start creates the part.
+    aggregator.handleToolCallExecutionStart({
+      type: "tool-call-execution-start",
+      workspaceId: TEST_WORKSPACE_ID,
+      messageId: "msg-1",
+      toolCallId: "tool-race",
+      timestamp: 6_000,
+    });
+
+    // Replayed start without executionStartedAt (snapshot predates execute()).
+    aggregator.handleToolCallStart({
+      type: "tool-call-start",
+      workspaceId: TEST_WORKSPACE_ID,
+      messageId: "msg-1",
+      toolCallId: "tool-race",
+      toolName: "bash",
+      args: { command: "echo hi" },
+      tokens: 0,
+      timestamp: 1_000,
+      replay: true,
+    });
+
+    const row = aggregator
+      .getDisplayedMessages()
+      .find((m) => m.type === "tool" && m.toolCallId === "tool-race");
+    expect(row?.type === "tool" ? row.executionStartedAt : undefined).toBe(6_000);
+
+    // Timing stats must also anchor at execution start, not the replayed emission time.
+    endToolCall(aggregator, {
+      toolCallId: "tool-race",
+      toolName: "bash",
+      result: {},
+      timestamp: 9_000,
+    });
+    expect(aggregator.getActiveStreamTimingStats()?.toolExecutionMs).toBe(3_000);
+  });
+
+  test("fresh replayed tool-call-start seeds timing stats from executionStartedAt", () => {
+    const aggregator = new StreamingMessageAggregator(TEST_CREATED_AT);
+
+    startTestStream(aggregator, { messageId: "msg-1" });
+    // Full replay after reconnect: the client never saw the live start, and the
+    // replayed event already carries the true execution start.
+    aggregator.handleToolCallStart({
+      type: "tool-call-start",
+      workspaceId: TEST_WORKSPACE_ID,
+      messageId: "msg-1",
+      toolCallId: "tool-fresh-replay",
+      toolName: "bash",
+      args: { command: "echo hi" },
+      tokens: 0,
+      timestamp: 1_000,
+      executionStartedAt: 6_000,
+      replay: true,
+    });
+    endToolCall(aggregator, {
+      toolCallId: "tool-fresh-replay",
+      toolName: "bash",
+      result: {},
+      timestamp: 9_000,
+    });
+
+    expect(aggregator.getActiveStreamTimingStats()?.toolExecutionMs).toBe(3_000);
+  });
+
   test("keeps richer in-memory parts when append replay sends a stale duplicate", () => {
     const aggregator = new StreamingMessageAggregator(TEST_CREATED_AT);