feat(web): show tool call duration in the detail dialog (#1036)

* refactor(web): export formatDuration for reuse

* feat(web): show tool call duration in the detail dialog

Show a completed tool's execution duration at the top of its detail
dialog. The value is derived from the Claude entry's own timestamps
(the execution machine's wall clock) rather than the hub's
message-receive time, and is used only when both the tool_use and
tool_result entries carry a real timestamp — otherwise it falls back to
the hub receive times on both sides, so the two clocks are never mixed.
Running/pending tools show nothing, the running-state live timer is
unchanged, and clock skew is guarded against. Reuses the existing
formatDuration formatter. No schema changes.

* fix(web): backfill hub startedAt on reorder so duration isn't 0.0s

When a tool_result entry is reduced before its tool_use, the tool block
is created from the result, so the hub startedAt is the result receive
time. The tool_use path only lowered the exec start, not the hub
startedAt, so a timestamp-less pair (no exec duration available) fell
back to startedAt === completedAt and the detail dialog showed 0.0s.
Lower the hub startedAt to the earlier tool_use receive time as well.
This commit is contained in:
Junmo Kim
2026-07-16 12:32:00 +08:00
committed by GitHub
parent f457156bd1
commit 2ce6d3ef3a
23 changed files with 652 additions and 8 deletions
+9
View File
@@ -16,6 +16,8 @@ import { getToolPresentation } from '@/components/ToolCard/knownTools'
import { getToolFullViewComponent, getToolViewComponent } from '@/components/ToolCard/views/_all'
import { getToolResultViewComponent } from '@/components/ToolCard/views/_results'
import { formatTaskChildLabel, TaskStateIcon } from '@/components/ToolCard/helpers'
import { toolDurationMs } from '@/components/ToolCard/toolDuration'
import { formatDuration } from '@/chat/presentation'
import type { TerminalToolDisplayMode } from '@/hooks/useTerminalToolDisplayMode'
import { usePointerFocusRing } from '@/hooks/usePointerFocusRing'
import { getInputStringAny, truncate } from '@/lib/toolInputUtils'
@@ -222,9 +224,16 @@ export function ToolDetailDialogContent(props: {
const isQuestionToolWithAnswers = isQuestionTool
&& permission?.answers
&& Object.keys(permission.answers).length > 0
const durationMs = toolDurationMs(props.block.tool)
return (
<div className="mt-3 flex max-h-[75vh] flex-col gap-4 overflow-auto">
{durationMs != null ? (
<div className="flex items-center gap-2 text-xs">
<span className="font-medium text-[var(--app-hint)]">{t('tool.duration')}</span>
<span className="font-mono text-[var(--app-hint)]">{formatDuration(durationMs)}</span>
</div>
) : null}
<div>
<div className="mb-1 text-xs font-medium text-[var(--app-hint)]">
{isQuestionToolWithAnswers ? t('tool.questionsAnswers') : t('tool.input')}
@@ -22,6 +22,8 @@ function makeToolBlock(id: string, name: string, input: unknown = {}): ToolCallB
createdAt: 1,
startedAt: 1,
completedAt: 2,
execStartedAt: null,
execCompletedAt: null,
description: null,
result: { content: 'done' },
permission: undefined,
@@ -20,6 +20,8 @@ function makeUpdatePlanBlock(input: unknown, result?: unknown): ToolCallBlock {
createdAt: 0,
startedAt: 0,
completedAt: 0,
execStartedAt: null,
execCompletedAt: null,
description: null,
result
},
@@ -32,6 +32,8 @@ function makeTool(id: string, name: string, input: unknown = {}): ToolCallBlock
createdAt: 1,
startedAt: 1,
completedAt: 2,
execStartedAt: null,
execCompletedAt: null,
description: null,
result: null,
permission: undefined,
@@ -0,0 +1,124 @@
import { describe, expect, it } from 'vitest'
import { render, screen } from '@testing-library/react'
import type { ReactElement } from 'react'
import type { ChatToolCall, ToolCallBlock } from '@/chat/types'
import { ToolDetailDialogContent } from '@/components/ToolCard/ToolCard'
import { I18nProvider } from '@/lib/i18n-context'
function renderWithI18n(ui: ReactElement) {
return render(<I18nProvider>{ui}</I18nProvider>)
}
function makeBlock(tool: Partial<ChatToolCall>): ToolCallBlock {
return {
kind: 'tool-call',
id: 'tool-1',
localId: null,
createdAt: 0,
tool: {
id: 'tool-1',
name: 'Bash',
state: 'completed',
input: { command: 'ls' },
createdAt: 0,
startedAt: 0,
completedAt: 0,
execStartedAt: null,
execCompletedAt: null,
description: null,
result: 'ok',
...tool,
},
children: [],
}
}
describe('ToolDetailDialogContent — duration row', () => {
it('shows a Duration row for a completed tool', () => {
renderWithI18n(<ToolDetailDialogContent block={makeBlock({ state: 'completed', startedAt: 1000, completedAt: 3500 })} metadata={null} />)
expect(screen.getByText('Duration')).toBeTruthy()
expect(screen.getByText('2.5s')).toBeTruthy()
})
it('shows a Duration row for an error tool that completed', () => {
renderWithI18n(<ToolDetailDialogContent block={makeBlock({ state: 'error', startedAt: 1000, completedAt: 1800 })} metadata={null} />)
expect(screen.getByText('Duration')).toBeTruthy()
expect(screen.getByText('0.8s')).toBeTruthy()
})
it('does not show a Duration row while running (no completedAt)', () => {
renderWithI18n(<ToolDetailDialogContent block={makeBlock({ state: 'running', startedAt: 1000, completedAt: null })} metadata={null} />)
expect(screen.queryByText('Duration')).toBeNull()
})
it('does not show a Duration row on clock skew (completedAt precedes startedAt)', () => {
renderWithI18n(<ToolDetailDialogContent block={makeBlock({ state: 'completed', startedAt: 3500, completedAt: 1000 })} metadata={null} />)
expect(screen.queryByText('Duration')).toBeNull()
})
it('does not show a Duration row while pending (no startedAt, no completedAt)', () => {
renderWithI18n(<ToolDetailDialogContent block={makeBlock({ state: 'pending', startedAt: null, completedAt: null })} metadata={null} />)
expect(screen.queryByText('Duration')).toBeNull()
})
it('coexists with the Trace section summary on a completed Task tool call', () => {
// Task/CodexAgent tool calls render their own Trace section summary
// (children count/tokens/duration, self-reported by the tool result) in
// the same dialog. This guards against the two duration sources
// (hub wall-clock vs. tool-self-reported) silently clashing or crashing
// when both are present.
const child = makeBlock({ id: 'child-1', name: 'Read', state: 'completed' })
const block: ToolCallBlock = {
kind: 'tool-call',
id: 'task-1',
localId: null,
createdAt: 0,
children: [child],
tool: {
id: 'task-1',
name: 'Task',
state: 'completed',
input: { subagent_type: 'Explore' },
createdAt: 0,
startedAt: 1000,
completedAt: 3500,
execStartedAt: null,
execCompletedAt: null,
description: null,
result: { totalDurationMs: 2400, totalTokens: 1000, totalToolUseCount: 1 },
},
}
renderWithI18n(<ToolDetailDialogContent block={block} metadata={null} />)
expect(screen.getByText('Duration')).toBeTruthy()
expect(screen.getByText('2.5s')).toBeTruthy()
expect(screen.getByText('Trace')).toBeTruthy()
})
it('prefers the claude execution-machine timestamps over hub receive time when both are present', () => {
// Hub receipt shows an inflated 2.5s window (hub queue/transport
// overhead); the claude entries themselves show the true 2.0s.
renderWithI18n(<ToolDetailDialogContent block={makeBlock({
state: 'completed',
startedAt: 1000,
completedAt: 3500,
execStartedAt: 1100,
execCompletedAt: 3100,
})} metadata={null} />)
expect(screen.getByText('Duration')).toBeTruthy()
expect(screen.getByText('2.0s')).toBeTruthy()
})
it('falls back to the hub receive time when exec timestamps are absent (non-Claude agent, no regression)', () => {
renderWithI18n(<ToolDetailDialogContent block={makeBlock({
state: 'completed',
startedAt: 1000,
completedAt: 3500,
execStartedAt: null,
execCompletedAt: null,
})} metadata={null} />)
expect(screen.getByText('Duration')).toBeTruthy()
expect(screen.getByText('2.5s')).toBeTruthy()
})
})
@@ -0,0 +1,123 @@
import { describe, expect, it } from 'vitest'
import type { ChatToolCall } from '@/chat/types'
import { toolDurationMs } from '@/components/ToolCard/toolDuration'
function makeTool(overrides: Partial<ChatToolCall>): ChatToolCall {
return {
id: 'tool-1',
name: 'Bash',
state: 'completed',
input: {},
createdAt: 0,
startedAt: 0,
completedAt: 0,
execStartedAt: null,
execCompletedAt: null,
description: null,
...overrides,
}
}
describe('toolDurationMs', () => {
it('returns completedAt - startedAt for a completed tool', () => {
const tool = makeTool({ state: 'completed', startedAt: 100, completedAt: 2600 })
expect(toolDurationMs(tool)).toBe(2500)
})
it('returns a duration for an error tool that has completedAt', () => {
const tool = makeTool({ state: 'error', startedAt: 100, completedAt: 900 })
expect(toolDurationMs(tool)).toBe(800)
})
it('falls back to createdAt when startedAt is null', () => {
const tool = makeTool({ state: 'completed', startedAt: null, createdAt: 100, completedAt: 2600 })
expect(toolDurationMs(tool)).toBe(2500)
})
it('returns null while running (completedAt is null)', () => {
const tool = makeTool({ state: 'running', startedAt: 100, completedAt: null })
expect(toolDurationMs(tool)).toBeNull()
})
it('returns null while pending (no startedAt, no completedAt)', () => {
const tool = makeTool({ state: 'pending', startedAt: null, completedAt: null })
expect(toolDurationMs(tool)).toBeNull()
})
it('returns null when completedAt precedes startedAt (clock skew, no negative)', () => {
const tool = makeTool({ state: 'completed', startedAt: 2600, completedAt: 100 })
expect(toolDurationMs(tool)).toBeNull()
})
it('returns 0 for an instantaneous tool (completedAt equals startedAt)', () => {
const tool = makeTool({ state: 'completed', startedAt: 500, completedAt: 500 })
expect(toolDurationMs(tool)).toBe(0)
})
describe('exec-timestamp (claude entry-side) preference', () => {
it('prefers execStartedAt/execCompletedAt over the hub-received startedAt/completedAt', () => {
// hub receipt shows an inflated 2.5s window, but the claude entries
// themselves (execStartedAt/execCompletedAt) show the true 2.0s.
const tool = makeTool({
state: 'completed',
startedAt: 100,
completedAt: 2600,
execStartedAt: 200,
execCompletedAt: 2200,
})
expect(toolDurationMs(tool)).toBe(2000)
})
it('falls back to startedAt/completedAt when exec fields are null (non-Claude agent, no regression)', () => {
const tool = makeTool({
state: 'completed',
startedAt: 100,
completedAt: 2600,
execStartedAt: null,
execCompletedAt: null,
})
expect(toolDurationMs(tool)).toBe(2500)
})
it('uses hub times on BOTH sides when only execStartedAt is present (no mixed-clock subtraction)', () => {
// Real Claude exec start but a hub-synthesized completion (e.g. a
// denied/timed-out tool). Mixing 2200 - 200 would fabricate 2000;
// both-or-neither falls back to the hub pair (2600 - 100 = 2500).
const tool = makeTool({
state: 'completed',
startedAt: 100,
completedAt: 2600,
execStartedAt: 200,
execCompletedAt: null,
})
expect(toolDurationMs(tool)).toBe(2500)
})
it('uses hub times on BOTH sides when only execCompletedAt is present', () => {
const tool = makeTool({
state: 'completed',
startedAt: 100,
completedAt: 2600,
execStartedAt: null,
execCompletedAt: 2200,
})
expect(toolDurationMs(tool)).toBe(2500)
})
it('returns null when execCompletedAt precedes execStartedAt (clock skew, no negative)', () => {
const tool = makeTool({
state: 'completed',
startedAt: 100,
completedAt: 2600,
execStartedAt: 2200,
execCompletedAt: 200,
})
expect(toolDurationMs(tool)).toBeNull()
})
it('returns null while running even if execStartedAt is set (no execCompletedAt yet)', () => {
const tool = makeTool({ state: 'running', startedAt: 100, execStartedAt: 200, completedAt: null, execCompletedAt: null })
expect(toolDurationMs(tool)).toBeNull()
})
})
})
@@ -0,0 +1,27 @@
import type { ChatToolCall } from '@/chat/types'
/**
* Wall-clock duration of a tool call in milliseconds, or null when it cannot be
* derived. Uses the Claude entry's own execution-machine timestamps
* (`execStartedAt`/`execCompletedAt`) — which reflect the true tool execution
* time without the hub receive/queue overhead — but only when *both* are
* present. This both-or-neither rule is deliberate: mixing one real Claude
* timestamp with one hub-received time subtracts two different clocks and
* silently yields a wrong duration (positive skew inflates it; only negative
* skew is caught by the guard below). When either exec timestamp is missing
* (e.g. a hub-synthesized tool_result for a denied/timed-out/cancelled tool, a
* malformed entry, or a non-Claude agent flavor), we fall back to the hub
* receive times on *both* sides so the subtraction stays clock-consistent.
* Returns null for pending/running tools (no completed end) and guards against
* clock skew where the end precedes the start.
*/
export function toolDurationMs(tool: ChatToolCall): number | null {
const useExec = tool.execStartedAt != null && tool.execCompletedAt != null
const end = useExec ? tool.execCompletedAt : tool.completedAt
if (end == null) return null
const start = useExec ? tool.execStartedAt : (tool.startedAt ?? tool.createdAt)
if (start == null) return null
const duration = end - start
if (duration < 0) return null
return duration
}
@@ -63,6 +63,8 @@ function makeChild(
createdAt: 1000,
startedAt: 1000,
completedAt: 2000,
execStartedAt: null,
execCompletedAt: null,
description: null,
result: null,
},
@@ -88,6 +90,8 @@ function makeTaskBlock(
createdAt: 1000,
startedAt: 1000,
completedAt: 2000,
execStartedAt: null,
execCompletedAt: null,
description: null,
result,
},
@@ -113,6 +117,8 @@ function makeCodexAgentBlock(
createdAt: 1000,
startedAt: 1000,
completedAt: 2000,
execStartedAt: null,
execCompletedAt: null,
description: null,
result,
},
@@ -138,6 +144,8 @@ function makeAgentBlock(
createdAt: 1000,
startedAt: 1000,
completedAt: 2000,
execStartedAt: null,
execCompletedAt: null,
description: null,
result,
},
@@ -181,6 +181,8 @@ describe('dialog result formatting', () => {
createdAt: 0,
startedAt: null,
completedAt: 0,
execStartedAt: null,
execCompletedAt: null,
description: null
}
}
@@ -238,6 +240,8 @@ describe('Codex agent result formatting', () => {
createdAt: 0,
startedAt: null,
completedAt: 0,
execStartedAt: null,
execCompletedAt: null,
description: null
}
}
@@ -332,6 +336,8 @@ describe('Codex agent result formatting', () => {
createdAt: 0,
startedAt: 0,
completedAt: null,
execStartedAt: null,
execCompletedAt: null,
description: null
}
}
@@ -365,6 +371,8 @@ describe('read file result formatting', () => {
createdAt: 0,
startedAt: null,
completedAt: 0,
execStartedAt: null,
execCompletedAt: null,
description: null
}
}