Feat/tool call timestamps#913
Conversation
Each tool block (BlockTool + InlineTool) now renders `HH:MM:SS · 1.2s`
in the title row. Running tools tick the elapsed counter at 1Hz and
freeze on completion; tools running >=30s switch to theme.warning so
slow calls stand out at a glance.
- Add Locale.clockTime() for 24-hour HH:MM:SS formatting.
- Add useElapsed(part) hook: returns {start, ms, running}; live-ticks
only while status === "running" and cleans up the interval on
transition to completed/error.
- Gate visibility behind the existing showTimestamps toggle; default
flipped from "hide" -> "show". Toggle relabeled "Show tool timing"
and aliased to /timing in addition to /timestamps.
- Pending parts (no time.start yet) render no timing row, so the UX
stays clean during the brief pre-running window.
Tests: 2 new Locale.clockTime cases; existing TUI suite (157) still
passes; tsgo typecheck clean.
Aggregates duration across every ToolPart in the session — completed and error tools by (end - start), the currently running tool by (now - start), live-ticking once a second only while a tool is running. Renders under the existing Context block as '… in tools' (with a '(running)' suffix when active), hidden when zero.
Pulls SLOW_TOOL_MS, the Elapsed type, and the 'HH:MM:SS · running …' suffix builder into routes/session/timing.ts. Collapses three copies of the timing format string across InlineTool and BlockTool down to a single formatElapsed() call, and drops a redundant 'as ToolPart' cast in the sidebar — the part.type === 'tool' discriminant already narrows the union.
Feat/tool call timestamps
![claude[bot]](https://avatars.githubusercontent.com/in/1236702?s=60&v=4){kind=small}
|
Hey! Your PR title Please update it to start with one of:
Where See CONTRIBUTING.md for details. |
|
This PR doesn't fully meet our contributing guidelines and PR template. What needs to be fixed:
Please edit this PR description to address the above within 2 hours, or it will be automatically closed. If you believe this was flagged incorrectly, please let a maintainer know. |
|
👋 This PR was automatically closed by our quality checks. Common reasons:
If you believe this was a mistake, please open an issue explaining your intended contribution and a maintainer will help you. |
📝 WalkthroughWalkthroughThe PR adds elapsed-time display for tool execution in the Session UI. A new timing module defines formatting utilities and slow-tool thresholds. Per-tool timing is computed via a 1Hz polling hook ( ChangesTool Elapsed-Time Display in Session UI
Sequence Diagram(s)sequenceDiagram
participant ToolPart
participant useElapsed
participant InlineTool
participant Renderer
ToolPart->>useElapsed: check running state every 1s
useElapsed->>useElapsed: compute elapsed: running ? now-start : end-start
useElapsed->>InlineTool: return Elapsed object
InlineTool->>InlineTool: compute timingColor from SLOW_TOOL_MS threshold
InlineTool->>Renderer: render formatElapsed(elapsed) when timestamps enabled
sequenceDiagram
participant SessionMessages
participant ToolParts
participant Sidebar
participant Display
SessionMessages->>ToolParts: flatten all tool parts
ToolParts->>Sidebar: detect running state
Sidebar->>Sidebar: setInterval: update nowToolTime every 1s
Sidebar->>Sidebar: sum toolTime: running ? (now-start) + completed
Sidebar->>Display: show duration line with "(running)" flag
Estimated code review effort🎯 2 (Simple) | ⏱️ ~12 minutes Poem
🚥 Pre-merge checks | ✅ 4 | ❌ 1❌ Failed checks (1 warning)
✅ Passed checks (4 passed)
✏️ Tip: You can configure your own custom pre-merge checks in the settings. ✨ Finishing Touches🧪 Generate unit tests (beta)
Thanks for using CodeRabbit! It's free for OSS, and your support helps us grow. If you like it, consider giving us a shout-out. Comment |
|
👋 This PR was automatically closed by our quality checks. Common reasons:
If you believe this was a mistake, please open an issue explaining your intended contribution and a maintainer will help you. |
1 similar comment
|
👋 This PR was automatically closed by our quality checks. Common reasons:
If you believe this was a mistake, please open an issue explaining your intended contribution and a maintainer will help you. |
![coderabbitai[bot]](https://avatars.githubusercontent.com/in/347564?s=60&v=4){kind=small}
There was a problem hiding this comment.
Actionable comments posted: 2
🤖 Prompt for all review comments with AI agents
Verify each finding against current code. Fix only still-valid issues, skip the
rest with a brief reason, keep changes minimal, and validate.
Inline comments:
In `@packages/opencode/src/cli/cmd/tui/routes/session/index.tsx`:
- Around line 1698-1710: The elapsed can be negative on the pending→running
transition because now() may be older than s.time.start; fix by ensuring
computed ms is never negative: in the createMemo for Elapsed (the block using
part(), s.time.start and now()), clamp ms to Math.max(0, now() - s.time.start)
for the running case (or alternatively update the now signal when a part's
status changes to "running" inside the createEffect to setNow(Date.now()));
modify the logic in the createMemo/createEffect that references now, part(), and
s.time.start so the first rendered duration is non-negative.
In `@packages/opencode/src/cli/cmd/tui/routes/session/sidebar.tsx`:
- Around line 80-93: The running-time ticker can be stale until the first
interval tick; inside the createEffect that watches hasRunningTool(),
immediately seed nowToolTime() (call setNowToolTime(Date.now())) when a running
tool is detected before creating the setInterval, then create the interval as
before and keep the onCleanup(clearInterval) logic; update the createEffect
block around hasRunningTool(), nowToolTime, setNowToolTime, and the interval id
to ensure the first tick uses a fresh timestamp.
🪄 Autofix (Beta)
Fix all unresolved CodeRabbit comments on this PR:
- Push a commit to this branch (recommended)
- Create a new PR with the fixes
ℹ️ Review info
⚙️ Run configuration
Configuration used: Repository UI
Review profile: CHILL
Plan: Pro
Run ID: d935906f-6876-4b20-be3a-ed354fd2d574
📒 Files selected for processing (5)
packages/opencode/src/cli/cmd/tui/routes/session/index.tsxpackages/opencode/src/cli/cmd/tui/routes/session/sidebar.tsxpackages/opencode/src/cli/cmd/tui/routes/session/timing.tspackages/opencode/src/util/locale.tspackages/opencode/test/util/locale.test.ts
| const [now, setNow] = createSignal(Date.now()) | ||
| createEffect(() => { | ||
| if (part()?.state.status !== "running") return | ||
| const id = setInterval(() => setNow(Date.now()), 1000) | ||
| onCleanup(() => clearInterval(id)) | ||
| }) | ||
| return createMemo<Elapsed | undefined>(() => { | ||
| const p = part() | ||
| if (!p) return undefined | ||
| const s = p.state | ||
| if (s.status === "pending") return undefined | ||
| if (s.status === "running") return { start: s.time.start, ms: now() - s.time.start, running: true } | ||
| return { start: s.time.start, ms: s.time.end - s.time.start, running: false } |
There was a problem hiding this comment.
Prevent negative elapsed values on pending→running transition.
now may be older than s.time.start right after a tool starts, so the first rendered duration can go negative until the first 1s tick.
Suggested fix
function useElapsed(part: () => ToolPart | undefined) {
const [now, setNow] = createSignal(Date.now())
createEffect(() => {
if (part()?.state.status !== "running") return
+ setNow(Date.now())
const id = setInterval(() => setNow(Date.now()), 1000)
onCleanup(() => clearInterval(id))
})
return createMemo<Elapsed | undefined>(() => {
const p = part()
if (!p) return undefined
const s = p.state
if (s.status === "pending") return undefined
- if (s.status === "running") return { start: s.time.start, ms: now() - s.time.start, running: true }
- return { start: s.time.start, ms: s.time.end - s.time.start, running: false }
+ if (s.status === "running") return { start: s.time.start, ms: Math.max(0, now() - s.time.start), running: true }
+ return { start: s.time.start, ms: Math.max(0, s.time.end - s.time.start), running: false }
})
}🤖 Prompt for AI Agents
Verify each finding against current code. Fix only still-valid issues, skip the
rest with a brief reason, keep changes minimal, and validate.
In `@packages/opencode/src/cli/cmd/tui/routes/session/index.tsx` around lines 1698
- 1710, The elapsed can be negative on the pending→running transition because
now() may be older than s.time.start; fix by ensuring computed ms is never
negative: in the createMemo for Elapsed (the block using part(), s.time.start
and now()), clamp ms to Math.max(0, now() - s.time.start) for the running case
(or alternatively update the now signal when a part's status changes to
"running" inside the createEffect to setNow(Date.now())); modify the logic in
the createMemo/createEffect that references now, part(), and s.time.start so the
first rendered duration is non-negative.
| const [nowToolTime, setNowToolTime] = createSignal(Date.now()) | ||
| createEffect(() => { | ||
| if (!hasRunningTool()) return | ||
| const id = setInterval(() => setNowToolTime(Date.now()), 1000) | ||
| onCleanup(() => clearInterval(id)) | ||
| }) | ||
| const toolTime = createMemo(() => { | ||
| let ms = 0 | ||
| const tick = nowToolTime() | ||
| for (const part of toolParts()) { | ||
| const s = part.state | ||
| if (s.status === "running") ms += tick - s.time.start | ||
| else if (s.status === "completed" || s.status === "error") ms += s.time.end - s.time.start | ||
| } |
There was a problem hiding this comment.
Seed the running-time ticker immediately to avoid stale/negative totals.
When a tool starts after sidebar mount, nowToolTime() can be stale until the first interval tick, which can yield negative elapsed math (tick - start) transiently.
Suggested fix
const [nowToolTime, setNowToolTime] = createSignal(Date.now())
createEffect(() => {
if (!hasRunningTool()) return
+ setNowToolTime(Date.now())
const id = setInterval(() => setNowToolTime(Date.now()), 1000)
onCleanup(() => clearInterval(id))
})
const toolTime = createMemo(() => {
let ms = 0
const tick = nowToolTime()
for (const part of toolParts()) {
const s = part.state
- if (s.status === "running") ms += tick - s.time.start
- else if (s.status === "completed" || s.status === "error") ms += s.time.end - s.time.start
+ if (s.status === "running") ms += Math.max(0, tick - s.time.start)
+ else if (s.status === "completed" || s.status === "error") ms += Math.max(0, s.time.end - s.time.start)
}
return ms
})🤖 Prompt for AI Agents
Verify each finding against current code. Fix only still-valid issues, skip the
rest with a brief reason, keep changes minimal, and validate.
In `@packages/opencode/src/cli/cmd/tui/routes/session/sidebar.tsx` around lines 80
- 93, The running-time ticker can be stale until the first interval tick; inside
the createEffect that watches hasRunningTool(), immediately seed nowToolTime()
(call setNowToolTime(Date.now())) when a running tool is detected before
creating the setInterval, then create the interval as before and keep the
onCleanup(clearInterval) logic; update the createEffect block around
hasRunningTool(), nowToolTime, setNowToolTime, and the interval id to ensure the
first tick uses a fresh timestamp.
![cubic-dev-ai[bot]](https://avatars.githubusercontent.com/in/1082092?s=60&v=4){kind=small}
There was a problem hiding this comment.
4 issues found across 5 files
Prompt for AI agents (unresolved issues)
Check if these issues are valid — if so, understand the root cause of each and fix them. If appropriate, use sub-agents to investigate and fix each issue separately.
<file name="packages/opencode/src/cli/cmd/tui/routes/session/index.tsx">
<violation number="1" location="packages/opencode/src/cli/cmd/tui/routes/session/index.tsx:1709">
P2: Clamp elapsed to zero to prevent negative duration on first render. The `now` signal is seeded at mount time but `s.time.start` may be newer if the tool starts later, yielding a negative `ms` until the next interval tick. Use `Math.max(0, now() - s.time.start)`.</violation>
<violation number="2" location="packages/opencode/src/cli/cmd/tui/routes/session/index.tsx:1753">
P2: InlineTool spinner branch omits elapsed timing display</violation>
</file>
<file name="packages/opencode/src/util/locale.ts">
<violation number="1" location="packages/opencode/src/util/locale.ts:13">
P1: `clockTime` may render midnight as `24:00:00` because `hour12: false` alone does not guarantee a 0-23 hour cycle in Node.js ICU. Add `hourCycle: "h23"` to enforce standard 24-hour format.</violation>
</file>
<file name="packages/opencode/src/cli/cmd/tui/routes/session/sidebar.tsx">
<violation number="1" location="packages/opencode/src/cli/cmd/tui/routes/session/sidebar.tsx:91">
P2: Clamp to zero to prevent transient negative tool-time contribution. `nowToolTime()` is seeded at sidebar mount; if a tool starts later, `tick - s.time.start` can be negative until the interval fires. Use `Math.max(0, tick - s.time.start)`.</violation>
</file>
Reply with feedback, questions, or to request a fix.
Re-trigger cubic
|
|
||
| export function clockTime(input: number): string { | ||
| const date = new Date(input) | ||
| return date.toLocaleTimeString(undefined, { hour12: false, hour: "2-digit", minute: "2-digit", second: "2-digit" }) |
There was a problem hiding this comment.
P1: clockTime may render midnight as 24:00:00 because hour12: false alone does not guarantee a 0-23 hour cycle in Node.js ICU. Add hourCycle: "h23" to enforce standard 24-hour format.
Prompt for AI agents
Check if this issue is valid — if so, understand the root cause and fix it. At packages/opencode/src/util/locale.ts, line 13:
<comment>`clockTime` may render midnight as `24:00:00` because `hour12: false` alone does not guarantee a 0-23 hour cycle in Node.js ICU. Add `hourCycle: "h23"` to enforce standard 24-hour format.</comment>
<file context>
@@ -8,6 +8,11 @@ export namespace Locale {
+ export function clockTime(input: number): string {
+ const date = new Date(input)
+ return date.toLocaleTimeString(undefined, { hour12: false, hour: "2-digit", minute: "2-digit", second: "2-digit" })
+ }
+
</file context>
| error()?.includes("user dismissed"), | ||
| ) | ||
|
|
||
| const elapsed = useElapsed(() => props.part) |
There was a problem hiding this comment.
P2: InlineTool spinner branch omits elapsed timing display
Prompt for AI agents
Check if this issue is valid — if so, understand the root cause and fix it. At packages/opencode/src/cli/cmd/tui/routes/session/index.tsx, line 1753:
<comment>InlineTool spinner branch omits elapsed timing display</comment>
<file context>
@@ -1729,6 +1750,14 @@ function InlineTool(props: {
error()?.includes("user dismissed"),
)
+ const elapsed = useElapsed(() => props.part)
+ const timingVisible = createMemo(() => ctx.showTimestamps() && !!elapsed())
+ const timingColor = createMemo(() => {
</file context>
| if (!p) return undefined | ||
| const s = p.state | ||
| if (s.status === "pending") return undefined | ||
| if (s.status === "running") return { start: s.time.start, ms: now() - s.time.start, running: true } |
There was a problem hiding this comment.
P2: Clamp elapsed to zero to prevent negative duration on first render. The now signal is seeded at mount time but s.time.start may be newer if the tool starts later, yielding a negative ms until the next interval tick. Use Math.max(0, now() - s.time.start).
Prompt for AI agents
Check if this issue is valid — if so, understand the root cause and fix it. At packages/opencode/src/cli/cmd/tui/routes/session/index.tsx, line 1709:
<comment>Clamp elapsed to zero to prevent negative duration on first render. The `now` signal is seeded at mount time but `s.time.start` may be newer if the tool starts later, yielding a negative `ms` until the next interval tick. Use `Math.max(0, now() - s.time.start)`.</comment>
<file context>
@@ -1690,6 +1692,25 @@ function ToolTitle(props: { fallback: string; when: any; icon: string; children:
+ if (!p) return undefined
+ const s = p.state
+ if (s.status === "pending") return undefined
+ if (s.status === "running") return { start: s.time.start, ms: now() - s.time.start, running: true }
+ return { start: s.time.start, ms: s.time.end - s.time.start, running: false }
+ })
</file context>
| if (s.status === "running") return { start: s.time.start, ms: now() - s.time.start, running: true } | |
| if (s.status === "running") return { start: s.time.start, ms: Math.max(0, now() - s.time.start), running: true } |
| const tick = nowToolTime() | ||
| for (const part of toolParts()) { | ||
| const s = part.state | ||
| if (s.status === "running") ms += tick - s.time.start |
There was a problem hiding this comment.
P2: Clamp to zero to prevent transient negative tool-time contribution. nowToolTime() is seeded at sidebar mount; if a tool starts later, tick - s.time.start can be negative until the interval fires. Use Math.max(0, tick - s.time.start).
Prompt for AI agents
Check if this issue is valid — if so, understand the root cause and fix it. At packages/opencode/src/cli/cmd/tui/routes/session/sidebar.tsx, line 91:
<comment>Clamp to zero to prevent transient negative tool-time contribution. `nowToolTime()` is seeded at sidebar mount; if a tool starts later, `tick - s.time.start` can be negative until the interval fires. Use `Math.max(0, tick - s.time.start)`.</comment>
<file context>
@@ -62,6 +62,39 @@ export function Sidebar(props: { sessionID: string; overlay?: boolean }) {
+ const tick = nowToolTime()
+ for (const part of toolParts()) {
+ const s = part.state
+ if (s.status === "running") ms += tick - s.time.start
+ else if (s.status === "completed" || s.status === "error") ms += s.time.end - s.time.start
+ }
</file context>
| if (s.status === "running") ms += tick - s.time.start | |
| if (s.status === "running") ms += Math.max(0, tick - s.time.start) |
dev-punia-altimate
left a comment
dev-punia-altimate
left a comment
There was a problem hiding this comment.
Multi-Persona Review — Verdict: block
The PR introduces a critical bug in session-level tool timing calculation that could produce incorrect cumulative durations when multiple tools run simultaneously, and changes a user-facing default (timestamps from hide to show) without documented product approval, violating project compliance standards.
14/14 agents completed · 249s · 3 findings (1 critical, 1 high, 0 medium)
Critical
- [code-reviewer] The toolTime calculation uses Date.now() as a live tick for running tools, but does not account for the possibility that multiple tools may be running simultaneously and their start times may be from different epochs. This could lead to incorrect cumulative timing if tools start at different times and the live tick advances uniformly. →
packages/opencode/src/cli/cmd/tui/routes/session/sidebar.tsx:140- 💡 Instead of using a single nowToolTime signal for all tools, compute elapsed time per tool individually using their own start time and the current time, avoiding shared tick logic that assumes synchronized timing.
High
- [code-reviewer] The default value for 'timestamps' was changed from 'hide' to 'show'. While the PR claims this is intentional and user preferences persist, the CLAUDE.md in the project root (if present) may explicitly require backward-compatible defaults for UI settings unless explicitly approved by product. This change alters user experience without a documented product decision. →
packages/opencode/src/cli/cmd/tui/routes/session/index.tsx:154- 💡 Verify that a product decision or CLAUDE.md rule explicitly permits flipping the default from hide to show. If not, revert to 'hide' and document the change in a follow-up PR with product sign-off.
Low
- [code-reviewer] The useElapsed hook calls clearInterval(id) on cleanup, but does not check if id is defined before clearing. If the effect runs and immediately exits (e.g., if part() is undefined), id may be undefined, leading to a potential runtime warning or error in some environments. →
packages/opencode/src/cli/cmd/tui/routes/session/index.tsx:1750- 💡 Wrap clearInterval(id) in a conditional: if (id) clearInterval(id).
Multi-Persona Review · vllm:qwen3-next-80b (waves) + vllm-fallback (synth) ·
| @@ -107,6 +140,13 @@ export function Sidebar(props: { sessionID: string; overlay?: boolean }) { | |||
| <text fg={theme.textMuted}>{context()?.tokens ?? 0} tokens</text> | |||
There was a problem hiding this comment.
[CRITICAL · code-reviewer] The toolTime calculation uses Date.now() as a live tick for running tools, but does not account for the possibility that multiple tools may be running simultaneously and their start times may be from different epochs. This could lead to incorrect cumulative timing if tools start at different times and the live tick advances uniformly.
💡 Suggestion: Instead of using a single nowToolTime signal for all tools, compute elapsed time per tool individually using their own start time and the current time, avoiding shared tick logic that assumes synchronized timing.
Confidence: 90/100
| @@ -152,7 +154,7 @@ export function Session() { | |||
| const [sidebarOpen, setSidebarOpen] = createSignal(false) | |||
There was a problem hiding this comment.
[HIGH · code-reviewer] The default value for 'timestamps' was changed from 'hide' to 'show'. While the PR claims this is intentional and user preferences persist, the CLAUDE.md in the project root (if present) may explicitly require backward-compatible defaults for UI settings unless explicitly approved by product. This change alters user experience without a documented product decision.
💡 Suggestion: Verify that a product decision or CLAUDE.md rule explicitly permits flipping the default from hide to show. If not, revert to 'hide' and document the change in a follow-up PR with product sign-off.
Confidence: 70/100
| @@ -1729,6 +1750,14 @@ function InlineTool(props: { | |||
| error()?.includes("user dismissed"), | |||
There was a problem hiding this comment.
[LOW · code-reviewer] The useElapsed hook calls clearInterval(id) on cleanup, but does not check if id is defined before clearing. If the effect runs and immediately exits (e.g., if part() is undefined), id may be undefined, leading to a potential runtime warning or error in some environments.
💡 Suggestion: Wrap clearInterval(id) in a conditional: if (id) clearInterval(id).
Confidence: 85/100
|
@krishnaclouds Thanks for the contribution. Can you please address the code review comments? |
3 participants
Summary
Adds visibility into how long tool calls take inside the TUI — both per-call and at the session level.
What changed and why?
Test Plan
Checklist
Summary by cubic
Adds tool-call timing to the TUI: each call shows start time and elapsed duration, and the sidebar shows total time spent in tools. Timing is on by default and can be toggled with new slash commands.
New Features
HH:MM:SS · <duration>; live-ticks while running, freezes on completion./timingand/toggle-timing.Migration
Written for commit cb587c4. Summary will update on new commits.
Summary by CodeRabbit