feat(tui): show how long each tool call took on the tool row by svetlovtech · Pull Request #1478 · 1jehuang/jcode

svetlovtech · 2026-09-24T16:37:37Z

Closes #1453.

Problem

Tool rows show a token count for the output but nothing about how long the call took. A bash command that ran for a minute renders exactly like one that finished instantly. The agent loop already measures tool elapsed time (tool_elapsed is used for interrupt messages), and StoredMessage.tool_duration_ms is already recorded - it just never reaches the transcript row. On master:

✓ bash · acceptance test run · 223 tok

Fix

Carry the measured duration to the row and render a compact badge after the token count:

✓ bash · acceptance test run · 223 tok · 2m 3s

Placement note: the duration stays on the right with the measurements. When a
companion wall-clock stamp lands (see the follow-up PR), it goes to the left
edge instead of the right: a fixed-position clock reads far better in a column
of rows, and keeping "when" (left) separate from "how long" (right) lets each
side stay scannable. This PR deliberately keeps only the duration on the right
suffix so it composes with that follow-up without crowding.

ServerEvent::ToolDone gains optional duration_ms, measured server-side at the streaming loop, manual execute, and subagent paths. serde(default, skip_serializing_if) keeps the legacy wire shape byte-identical when the field is absent (roundtrip test pins this).
Stored tool_duration_ms is plumbed through RenderedMessage -> DisplayMessage so reloaded transcripts show the same badge as live rows.
Opt-in via display.show_tool_duration (default false): off by default, existing transcripts render exactly as before.
Compact buckets: 45ms (<1s; a bare 0.0s is noise), 42.3s, 2m 3s, 1h 05m.
Severity coloring mirrors the existing token-badge grading via a shared severity_badge_color helper: neutral < 10s, amber >= 10s, red >= 60s (tool_duration_severity in jcode-core).
The badge rides with the preserved right-side suffix: narrow terminals truncate the summary first (checked at 40/56/72/120 columns).

Independent of #1454 (timestamp stamp); that one stacks on top of this branch.

Verification

check	result
`cargo test -p jcode-tui --lib tool_duration`	6 passed, 0 failed
`cargo test -p jcode-protocol --lib tool_done_duration`	1 passed (serde legacy omission + roundtrip)
`cargo test -p jcode-core --lib tool_duration`	1 passed (severity boundaries 9_999/10_000/59_999/60_000)
`cargo check --all-targets`	0 errors
`cargo clippy --all-targets`	no new warnings vs base; one found during review and fixed (ndjson emitter now serializes `duration_ms` instead of dropping it)
`cargo fmt --all -- --check`	clean on all touched files (3 pre-existing fmt diffs in `jev.rs`, `provider/mod.rs`, `allocator.rs` exist on `master` itself; none of those files are touched here)

Full jcode-tui --lib run: 2457 passed with 7 pre-existing flaky failures that also fail on master (clipboard_helper x3, recent_project_review, smoothness_plain_text_commit, model_picker/copilot x3, cerebras_paste) - unchanged by this branch.

Notes / tradeoffs

Default remains off: this is a visible-per-row change, so it waits for an explicit config opt-in. Follow-up (not in this PR) could flip the default after the timestamp PR lands.
Severity reuses the token-badge palette via one shared helper so the two badges cannot drift apart.
Colors are the same constants the token badge already uses (neutral rgb(120,130,145), amber rgb(214,184,92), red rgb(224,118,118)).
Linux-only validation; no platform-specific code is touched.

ServerEvent::ToolDone gains an optional duration_ms measured server-side at the streaming loop, manual execute, and subagent paths. The field is serde(default, skip_serializing_if) so older servers can omit it and older clients ignore it; re-serialization drops the absent field so the legacy wire shape is unchanged (covered by a roundtrip test). Also plumbs the already-stored StoredMessage.tool_duration_ms through RenderedMessage -> DisplayMessage so reloaded transcripts carry it too. Closes 1jehuang#1453 (part 1/3: data path).

Each completed tool row now shows how long the call took after the token count: ' · 2m 3s'. Live rows get the duration from the ToolDone event; reloaded transcripts read it from the stored tool result. Compact buckets: milliseconds under a second ('45ms' - a bare '0.0s' is noise), tenths of a second up to a minute ('42.3s'), minutes + seconds from a minute ('2m 3s'), hours + minutes from an hour ('1h 05m'). The badge is color-graded like the token badge (new shared severity_badge_color helper + tool_duration_severity in jcode-core: Normal < 10s <= Warning < 60s <= Danger) so slow tools stand out while scanning. Suffix width is reserved before summary truncation so the badge survives narrow terminals. Closes 1jehuang#1453 (part 2/3: rendering + acceptance tests; part 3 is the test-mechanical DisplayMessage literal updates).

The duration badge becomes strictly opt-in per maintainer review: a new display.show_tool_duration key (serde default, off by default) controls whether completed tool rows render the compact ' · 2m 3s' badge. The message-line cache key now includes the flag so toggling config invalidates cached rows. Acceptance tests enable the flag via the tests_show_tool_duration_override and a new test pins the default-off behavior.

The ToolDone handler no longer discards duration_ms: the server-measured duration lands on the live DisplayMessage row immediately, so the badge shows without waiting for a history reload. Events without duration_ms (legacy server) keep rendering no badge. Timestamps are out of scope here and intentionally untouched.

The ndjson emitter destructured the new ToolDone field without serializing it, tripping an unused-variable warning and dropping useful data for ndjson consumers.

greptile-apps · 2026-09-24T17:06:11Z

Confidence Score: 5/5

[Medium impact] The outstanding badge gaps are non-blocking; they do not make the PR unsafe to merge.

Findings

Remote reload loses durations ▶
Transcript rebuilds erase badges ▶
Special cards omit durations ▶

Fix with agent prompt

### Issue 1
crates/jcode-tui/src/tui/app/remote/server_events.rs:undefined-2015
Remote history omits a tool's stored duration, and this reconstruction gives its row no duration. When badges are enabled, a badge visible during the live session disappears after reload. Preserve the duration in the history payload and reconstructed row.

### Issue 2
crates/jcode-tui/src/tui/app/commands.rs:undefined-2021
`/rewind undo`, `/rewind N`, and local compacted-history restoration rebuild tool rows without their stored durations. The measurements remain saved, but their badges disappear from the restored transcript.

### Issue 3
crates/jcode-tui/src/tui/ui_messages.rs:undefined-3853
Completed scheduled, todo, and memory-tool cards return from their specialized renderers before the duration badge is added. They remain badge-free even when badges are enabled and the rows contain measured durations.

---

For each issue above, determine whether it is valid and should be fixed. If so, fix it directly.

Summary

The PR carries measured tool durations through events and stored messages and adds an opt-in duration badge to TUI tool rows. Previously reported badge gaps remain on remote history reload, /rewind N, and specialized tool cards.

_{Reviews (5) · Last reviewed commit: "test: update DisplayMessage/ToolDone ini..." · Reviewed by Greptile}

greptile-apps · 2026-09-24T17:06:20Z

                                duration_secs: None,
                                title: None,
                                tool_data: msg.tool_data,
+                                tool_duration_ms: None,


Remote reload loses durations

Remote history omits a tool's stored duration, and this reconstruction gives its row no duration. When badges are enabled, a badge visible during the live session disappears after reload. Preserve the duration in the history payload and reconstructed row.

Artifacts

Rust remote-history duration contract harness

The authored source exercises stored rendering, history serialization, and remote-row reconstruction without changing tracked code.

Command to compile and run the remote-history duration harness

The authored shell command compiles the Rust harness and captures its before and after phases.

Stored and locally rendered duration before remote history

The executed before phase shows that both the stored message and local display row retain 48,300 ms.

Duration missing after remote history serialization and reconstruction

The executed after phase shows history JSON without a duration and a reconstructed row with `None`.

_{Ran code and verified through T-Rex}

Prompt To Fix With AI

This is a comment left during a code review. Path: crates/jcode-tui/src/tui/app/remote/server_events.rs Line: 1950 Comment: **Remote reload loses durations** Remote history omits a tool's stored duration, and this reconstruction gives its row no duration. When badges are enabled, a badge visible during the live session disappears after reload. Preserve the duration in the history payload and reconstructed row. --- For each issue above, determine whether it is valid and should be fixed. If so, fix it directly.

greptile-apps · 2026-09-24T17:06:20Z

                duration_secs: None,
                title: None,
                tool_data: rendered.tool_data,
+                tool_duration_ms: None,


Transcript rebuilds erase badges

/rewind undo, /rewind N, and local compacted-history restoration rebuild tool rows without their stored durations. The measurements remain saved, but their badges disappear from the restored transcript.

Artifacts

Authored Rust harness for local transcript rebuilds

The harness stores a timed tool result, invokes the three actual rebuild paths, and renders each resulting tool row; it defines the focused comparison.

Authored command for the before and after runs

The script compiles a temporary TUI source copy in each mode and runs the focused Cargo test; tracked source stays unchanged.

Authored temporary-source compiler wrapper

The wrapper directs the test compilation to the temporary source copy; neither comparison requires a tracked-code edit.

Before run: rebuilt tool rows have no duration badge

Running the focused test against the unchanged PR code showed `None` and no `48.3s` badge after all three rebuild paths; the defect reproduces.

After run: temporary duration-preserving mappings restore the badge

Running the same test with only the three mappings corrected in a temporary copy showed `Some(48300)` and `48.3s` in every rebuilt row; preserving the field resolves the defect.

_{Ran code and verified through T-Rex}

Prompt To Fix With AI

This is a comment left during a code review. Path: crates/jcode-tui/src/tui/app/commands.rs Line: 2021 Comment: **Transcript rebuilds erase badges** `/rewind undo`, `/rewind N`, and local compacted-history restoration rebuild tool rows without their stored durations. The measurements remain saved, but their badges disappear from the restored transcript. --- For each issue above, determine whether it is valid and should be fixed. If so, fix it directly.

greptile-apps · 2026-09-24T17:06:20Z

        UnicodeWidthStr::width(format!(" · {}", token_badge.label.as_str()).as_str());
+    // #1453: " · 2m 3s" (how long the call ran) rides with the token suffix
+    // when the stored tool result or the live event carries a duration.
+    let duration_suffix = tool_row_duration_suffix(msg);


Special cards omit durations

Completed scheduled, todo, and memory-tool cards return from their specialized renderers before the duration badge is added. They remain badge-free even when badges are enabled and the rows contain measured durations.

Artifacts

Authored rendered-card test source

The Rust test calls the real TUI renderer for an ordinary row and five special-card cases with the badge enabled and a stored duration.

Authored before-and-after test command

The command compiles a temporary source copy and runs the focused Rust test, applying an illustrative change only in after mode.

Temporary-source compiler wrapper

The wrapper points the test compilation at the temporary source copy so tracked files remain unchanged.

Rendered cards before the illustrative change

The passing unchanged-source test shows the ordinary row has `48.3s` while all five special cases lack it.

Rendered cards with a temporary illustrative change

The passing patched-copy test shows `48.3s` on all five special cases, demonstrating the missing badges can be rendered.

_{Ran code and verified through T-Rex}

Prompt To Fix With AI

This is a comment left during a code review. Path: crates/jcode-tui/src/tui/ui_messages.rs Line: 4027 Comment: **Special cards omit durations** Completed scheduled, todo, and memory-tool cards return from their specialized renderers before the duration badge is added. They remain badge-free even when badges are enabled and the rows contain measured durations. --- For each issue above, determine whether it is valid and should be fixed. If so, fix it directly.

greptile-apps · 2026-09-24T17:06:53Z

Comments Outside Diff

These findings could not be posted inline.

Structured renderer test fixtures replaced with generic tool messages ▶
- Bug
  - The goal-update and plan-update tests fail at their first card assertions, and 21 other tests in the focused renderer suite fail. The affected tests no longer exercise the specialized output their names and assertions specify.
- Cause
  - Since review SHA 05e464bc, tests.rs:1114 and :1232 discard the constructed structured content in favor of plain text. Additional changed fixtures substitute bash or simplified todo metadata for their specialized tool calls. The unchanged renderer consequently takes its generic path.
- Fix
  - Restore each test's structured output and matching tool-call metadata while retaining the newly required tool_duration_ms field; rerun the focused suite.

… path - Local tool completion (replace_latest path) now stamps the measured duration on the row, same as the ToolDone event path does - /rewind undo, /rewind N, and compacted-history restoration carry the stored duration back into rebuilt rows - ndjson tool_done omits duration_ms when unmeasured instead of emitting null, keeping the presence contract for consumers Reviewed findings 1 (remote HistoryMessage wire) is deliberate non-goal here: the wire extension belongs to the timestamp PR that stacks on this branch. Finding 4 (specialized cards) is not applicable: scheduled/todo/memory cards render through their own renderers and carry no measured duration.

svetlovtech · 2026-09-24T17:47:00Z

Greptile findings triaged (commit f1f83feb8 after fmt):

Fixed:

Issue 2 (local rows lacked durations): the SDK/local completion path now stamps the measured duration on the row via replace_latest_tool_display_message_with_duration, same as the ToolDone path.
Issue 3 (/rewind + compacted-history restore lost badges): rebuilt rows carry rendered.tool_duration_ms through.
Issue 5 (ndjson duration_ms":null): unmeasured events now omit the field entirely, preserving the presence contract for existing consumers.

Deliberate non-goals (explained):

Issue 1 (remote reload via HistoryMessage): valid observation, but the fix extends the HistoryMessage wire struct - that belongs to the timestamp PR stacked on this branch, which already carries that extension. Mixing wire changes here would widen this PR's scope.
Issue 4 (specialized cards): not applicable - scheduled/todo/memory cards render through their own renderers before the badge code and never carry a measured duration (they are planner messages, not measured tool calls).

All gates re-run after the fixes: fmt clean on touched files, check 0 errors, tests green.

Greptile P2: a local completion that only changed the duration (title and content identical) skipped the render-version bump, so the cached row kept rendering without the badge. The duration write now bumps display_messages_version itself. Also removes the throwaway println! from the ms-bucket test (AGENTS.md requires diagnostics to be removed before committing; the assertion messages already carry the rendered row).

…open, current, merge-clean

…ool-duration-work # Conflicts: # crates/jcode-protocol/src/wire.rs # crates/jcode-tui/src/tui/app/model_context.rs # crates/jcode-tui/src/tui/app/remote/server_events.rs # crates/jcode-tui/src/tui/app/tui_lifecycle_runtime.rs # crates/jcode-tui/src/tui/ui_messages/tests.rs # src/cli/commands.rs

Merges upstream master (wire/events.rs split) and re-applies this PR's surface: ToolDone.duration_ms on the new wire layout, the ndjson omit-when-unmeasured contract, tool_duration_ms in rebuilt DisplayMessage paths, and RenderedMessage timing in the ProviderNative render arm.

…ms after upstream merge

- mcp/mod.rs: re-export budget module + take_accept_large_output - mcp/tool.rs: take upstream wholesale (restores accept_large_output escape hatch + output budget fitting in create_mcp_tools) - mcp/client_http_tests.rs: drop stale copy upstream deleted - wire/events.rs: keep fork ToolDone.duration_ms (PR 1jehuang#1478 wire surface, serde-compatible) alongside upstream's restructured ServerEvent app-core suite: 1586 passed / 2 failed (the known sdk_socket ticket + the upstream-inherited wake race; both documented).

svetlovtech added 5 commits September 24, 2026 11:14

fix(cli): include tool_done duration_ms in ndjson event stream

84cc300

The ndjson emitter destructured the new ToolDone field without serializing it, tripping an unused-variable warning and dropping useful data for ndjson consumers.

greptile-apps Bot reviewed Sep 24, 2026

View reviewed changes

Comment thread crates/jcode-tui/src/tui/app/state_ui_messages.rs

Comment thread crates/jcode-tui/src/tui/ui_tests/tool_duration.rs Outdated

This was referenced Sep 24, 2026

TUI: show when each tool call ran (timestamp on tool rows) #1454

Open

feat(tui): show when each tool call ran (opt-in timestamp on tool rows) #1480

Open

1jehuang mentioned this pull request Sep 27, 2026

TUI: show how long each tool call took on the tool row #1453

Open

11 tasks done

svetlovtech pushed a commit to svetlovtech/jcode that referenced this pull request Oct 6, 2026

docs(plans): upstream PR status refresh - 1jehuang#1478/1jehuang#1480 …

bdf7a03

…open, current, merge-clean

svetlovtech added 3 commits October 14, 2026 22:35

test: update DisplayMessage/ToolDone initializers with tool_duration_…

8b5c267

…ms after upstream merge

Navigation Menu

Repository navigation

feat(tui): show how long each tool call took on the tool row - #1478

feat(tui): show how long each tool call took on the tool row#1478
svetlovtech wants to merge 10 commits into
1jehuang:masterfrom
svetlovtech:feat/issue-1453-tool-duration

svetlovtech commented Sep 24, 2026 •

edited

Loading

Uh oh!

greptile-apps Bot commented Sep 24, 2026 •

edited

Loading

Uh oh!

greptile-apps Bot Sep 24, 2026

Uh oh!

Uh oh!

greptile-apps Bot Sep 24, 2026

Uh oh!

greptile-apps Bot Sep 24, 2026

Uh oh!

Uh oh!

greptile-apps Bot commented Sep 24, 2026 •

edited

Loading

Uh oh!

svetlovtech commented Sep 24, 2026

Uh oh!

Uh oh!

Uh oh!

Reviewers

Assignees

Labels

Projects

Milestone

Development

Uh oh!

1 participant

Conversation

svetlovtech commented Sep 24, 2026 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Problem

Fix

Verification

Notes / tradeoffs

Uh oh!

greptile-apps Bot commented Sep 24, 2026 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Confidence Score: 5/5

Findings

Summary

Uh oh!

greptile-apps Bot Sep 24, 2026

Choose a reason for hiding this comment

Uh oh!

Uh oh!

greptile-apps Bot Sep 24, 2026

Choose a reason for hiding this comment

Uh oh!

greptile-apps Bot Sep 24, 2026

Choose a reason for hiding this comment

Uh oh!

Uh oh!

greptile-apps Bot commented Sep 24, 2026 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Comments Outside Diff

Uh oh!

svetlovtech commented Sep 24, 2026

Uh oh!

Uh oh!

Uh oh!

Reviewers

Assignees

Labels

Projects

Milestone

Development

Uh oh!

1 participant

svetlovtech commented Sep 24, 2026 •

edited

Loading

greptile-apps Bot commented Sep 24, 2026 •

edited

Loading

greptile-apps Bot commented Sep 24, 2026 •

edited

Loading