Skip to content

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

Merged
ThomasK33 merged 7 commits into
mainfrom
execution-timing-h9xd
Jul 13, 2026
Merged

🤖 fix: start tool elapsed timers when execute() actually runs#3716
ThomasK33 merged 7 commits into
mainfrom
execution-timing-h9xd

Conversation

@ThomasK33

Copy link
Copy Markdown
Member

Summary

Tool-call elapsed timers in the chat UI now start when the tool's execute() actually begins running instead of when the model emits the tool call, so queued parallel tool calls no longer display elapsed times exceeding their own timeout.

Background

Providers may plan several tool calls in parallel, but mux serializes their execute() handlers via withSequentialExecution. The UI anchored each tool's elapsed timer on the dynamic-tool part timestamp (set when the tool-call stream part is processed), so every queued sibling ticked while waiting for the lock — producing confusing displays like timeout: 25s • 51s on tools that had not started running yet.

Implementation

  • withSequentialExecution accepts an optional onExecutionStart(toolCallId) callback invoked immediately after the execution lock is acquired, just before the wrapped execute() runs.
  • StreamManager uses that callback to stamp a new persisted executionStartedAt field on the dynamic-tool part and emit a new tool-call-execution-start chat event. A pending map handles the race where execute() begins before the fullStream consumer stores the part (same pattern as pending workflow-run attachments). Replayed tool-call-start events carry executionStartedAt so reconnects don't reset timers.
  • Frontend: the aggregator applies the event to the tool part, ToolMessage passes executionStartedAt (instead of message.timestamp) as startedAt, and ElapsedTimeDisplay renders nothing until a real execution start exists.

Resulting UX: queued tools show only their timeout (no ticking counter); the currently-executing tool counts from its true start; completed bash durations are unchanged (wall_duration_ms from the tool result).

Validation

  • New withSequentialExecution test proves a queued sibling's execution start is not reported until the lock is released.
  • New StreamManager tests cover both event orderings (part stored first vs. execute() winning the race).
  • New aggregator test verifies tool-call-execution-start stamps executionStartedAt onto displayed tool rows.

Risks

Low. The new event is additive; unknown event types are ignored by older consumers, and executionStartedAt is optional everywhere. The main behavior change is intentional: executing-timer display now requires the execution-start signal, so pre-existing history rows without it simply show no elapsed ticker while pending (they previously showed a misleading one). Live per-turn tool-time stats (pendingToolStarts / sessionTimingService) intentionally still measure from tool-call-start and are unaffected.


Generated with mux • Model: anthropic:claude-fable-5 • Thinking: xhigh • Cost: $30.52

Parallel tool calls are serialized by withSequentialExecution, so a queued
tool's elapsed timer (anchored at the model-emission timestamp) could exceed
its own timeout before it ever ran.

- withSequentialExecution now accepts an onExecutionStart callback fired
  after the execution lock is acquired
- StreamManager stamps executionStartedAt on the dynamic-tool part and emits
  a new tool-call-execution-start event (with a pending map for the race
  where execute() begins before the fullStream consumer stores the part);
  replayed tool-call-start events carry executionStartedAt
- Frontend aggregator applies the event; ToolMessage passes
  executionStartedAt as startedAt, and ElapsedTimeDisplay stays hidden until
  a real execution start exists
@ThomasK33

Copy link
Copy Markdown
Member Author

@codex review

@chatgpt-codex-connector chatgpt-codex-connector Bot left a comment

Copy link
Copy Markdown

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

💡 Codex Review

Here are some automated review suggestions for this pull request.

Reviewed commit: 43e657cb3f

ℹ️ About Codex in GitHub

Your team has set up Codex to review pull requests in this repo. Reviews are triggered when you

  • Open a pull request for review
  • Mark a draft as ready
  • Comment "@codex review".

If Codex has suggestions, it will comment; otherwise it will react with 👍.

Codex can also answer questions or update the PR. Try commenting "@codex address that feedback".

Comment thread src/node/services/streamManager.ts
Comment thread src/browser/utils/messages/StreamingMessageAggregator.ts Outdated
…s bounds

TaskToolCall best-of recovery and WorkflowRunToolCall foreground run discovery
used the startedAt prop as a created-after lower bound. Now that startedAt is
the execution start (absent on history-replayed parts), fall back to the
model-emission timestamp so recovery keeps working for replayed history.
Fixes tests/ui/tasks/bestOfProgress.test.ts CI failure.
- replayStream: replay input-available dynamic-tool parts whose
  executionStartedAt is newer than the reconnect cursor, so the enriched
  tool-call-start reaches the renderer
- StreamingMessageAggregator: merge replayed executionStartedAt into an
  existing tool part instead of dropping the event as a duplicate
@ThomasK33

Copy link
Copy Markdown
Member Author

@codex review

@chatgpt-codex-connector chatgpt-codex-connector Bot left a comment

Copy link
Copy Markdown

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

💡 Codex Review

Here are some automated review suggestions for this pull request.

Reviewed commit: 350efa5cb3

ℹ️ About Codex in GitHub

Your team has set up Codex to review pull requests in this repo. Reviews are triggered when you

  • Open a pull request for review
  • Mark a draft as ready
  • Comment "@codex review".

If Codex has suggestions, it will comment; otherwise it will react with 👍.

Codex can also answer questions or update the PR. Try commenting "@codex address that feedback".

Comment thread src/node/services/aiService.ts
StreamingMessageAggregator summed per-tool durations from tool-call-start,
so serialized parallel siblings double-counted queue wait (inflating tool
time and deflating derived streaming/tok-s stats). tool-call-execution-start
now re-anchors pendingToolStarts at the true execution start.

Backend SessionTimingService is intentionally unchanged: it measures wall
segments (open while any call is outstanding), so sibling queue wait
coincides with the running sibling's execution and is not over-counted.
@ThomasK33

Copy link
Copy Markdown
Member Author

@codex review

@chatgpt-codex-connector chatgpt-codex-connector Bot left a comment

Copy link
Copy Markdown

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

💡 Codex Review

Here are some automated review suggestions for this pull request.

Reviewed commit: 78fa812464

ℹ️ About Codex in GitHub

Your team has set up Codex to review pull requests in this repo. Reviews are triggered when you

  • Open a pull request for review
  • Mark a draft as ready
  • Comment "@codex review".

If Codex has suggestions, it will comment; otherwise it will react with 👍.

Codex can also answer questions or update the PR. Try commenting "@codex address that feedback".

Comment thread src/browser/utils/messages/StreamingMessageAggregator.ts Outdated
…eview)

Replayed tool-call-start events carrying executionStartedAt now update
pendingToolStarts in both aggregator paths: the duplicate-merge branch
re-anchors the pre-disconnect emission seed, and fresh replayed parts seed
directly from the execution start. Extracted shared reanchorPendingToolStart
helper used by handleToolCallExecutionStart too.
@ThomasK33

Copy link
Copy Markdown
Member Author

@codex review

@chatgpt-codex-connector chatgpt-codex-connector Bot left a comment

Copy link
Copy Markdown

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

💡 Codex Review

Here are some automated review suggestions for this pull request.

Reviewed commit: 7a2f2a2647

ℹ️ About Codex in GitHub

Your team has set up Codex to review pull requests in this repo. Reviews are triggered when you

  • Open a pull request for review
  • Mark a draft as ready
  • Comment "@codex review".

If Codex has suggestions, it will comment; otherwise it will react with 👍.

Codex can also answer questions or update the PR. Try commenting "@codex address that feedback".

Comment thread src/browser/utils/messages/StreamingMessageAggregator.ts Outdated
… review)

tool-call-execution-start is not replay-buffered, so during a reconnect
replay it can arrive before the replayed tool-call-start creates the part.
Instead of dropping it, stash messageId->toolCallId->timestamp and fold it
into handleToolCallStart (part field + pendingToolStarts anchor); cleared
in cleanupStreamState.
@ThomasK33

Copy link
Copy Markdown
Member Author

@codex review

@chatgpt-codex-connector chatgpt-codex-connector Bot left a comment

Copy link
Copy Markdown

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

💡 Codex Review

Here are some automated review suggestions for this pull request.

Reviewed commit: 2397d0d2d1

ℹ️ About Codex in GitHub

Your team has set up Codex to review pull requests in this repo. Reviews are triggered when you

  • Open a pull request for review
  • Mark a draft as ready
  • Comment "@codex review".

If Codex has suggestions, it will comment; otherwise it will react with 👍.

Codex can also answer questions or update the PR. Try commenting "@codex address that feedback".

Comment thread src/node/services/streamManager.ts Outdated
handleToolExecutionStart used raw Date.now(), which can be <= the
monotonicized tool-call part timestamp in the same millisecond; the
reconnect replay repair predicate (executionStartedAt > cursor) would
then never fire for clients that disconnected right after tool-call-start.
Use nextPartTimestamp() so execution starts are strictly ordered after
prior part timestamps.
@ThomasK33

Copy link
Copy Markdown
Member Author

@codex review

@chatgpt-codex-connector

Copy link
Copy Markdown

Codex Review: Didn't find any major issues. Can't wait for the next one!

Reviewed commit: 4e8b995f29

ℹ️ About Codex in GitHub

Your team has set up Codex to review pull requests in this repo. Reviews are triggered when you

  • Open a pull request for review
  • Mark a draft as ready
  • Comment "@codex review".

If Codex has suggestions, it will comment; otherwise it will react with 👍.

Codex can also answer questions or update the PR. Try commenting "@codex address that feedback".

@ThomasK33 ThomasK33 added this pull request to the merge queue Jul 13, 2026
Merged via the queue into main with commit 370cb3b Jul 13, 2026
24 checks passed
@ThomasK33 ThomasK33 deleted the execution-timing-h9xd branch July 13, 2026 10:50
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

1 participant