Repository navigation
feat(tui): show when each tool call ran (opt-in timestamp on tool rows) - #1480
svetlovtech wants to merge 23 commits into
Conversation
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.
[Medium impact] No outstanding review finding blocks merging. SummaryThe PR preserves tool completion times and durations across session history and TUI rendering, adds opt-in timing badges, and places the clock before the tool name. No new issue requiring a review comment was established. Reviews (13) · Last reviewed commit: "feat(tui): move the tool row timestamp t..." · Reviewed by Greptile |
Comments Outside DiffThese findings could not be posted inline.
|
Core port of the tool row timestamp feature (1jehuang#1454): - jcode-config-types: display.show_tool_timestamp (strictly opt-in, default false) and display.timestamp_tz. The offset parser accepts "UTC+3", "utc-5", "UTC+0", "UTC+05:30" or a bare "3"; empty/"local"/ "system" and any garbage fall back to the machine timezone so a typo never breaks rendering. Unit tests pin both opt-in defaults and the offset grammar. - jcode-session-types: RenderedMessage carries the stored wall-clock timestamp; jcode-base render fills it from StoredMessage.timestamp. - jcode-tui-messages: DisplayMessage carries it (from_rendered_message passes it through). - jcode-tui: the tool row renderer appends an opt-in " · HH:MM:SS" suffix after the token count (and any duration badge). The stamp honors display.timestamp_tz via a fixed offset or the local timezone. The clock span is always neutral blue-grey rgb(120,130,145): it never inherits duration severity color, so a slow call cannot make the timestamp read as an error. The suffix width is reserved up front so the stamp survives summary truncation at narrow widths. - Tests: ui_tests/tool_time_badge.rs covers render-when-enabled, absence by default, the UTC+3 configured offset (including day-boundary arithmetic), neutral color across duration severities, narrow-width survival, and garbage-tz fallback; existing DisplayMessage literals gained the new field.
- HistoryMessage (sync wire) carries timestamp and tool_duration_ms beside tool_data; older payloads omit both (serde default) - remote history reconstruction maps them onto restored rows - fmt pass on touched files; duration regression suite green WIP continuation of 70cb394 by the coordinator after the agent session dropped.
The ToolDone event carries no wall-clock time, so the live row stamps itself with the completion time; the stored session timestamp takes over on the next history reload. Matches the duration-badge behavior of showing the badge the moment the event lands.
One page covering both opt-in badges: config keys, where the data comes from, the fixed-offset timestamp_tz grammar and its fallback behavior, the neutral clock color rationale, and narrow-terminal suffix behavior.
a6afa4b to
a31838f
Compare
- Local tool completion now stamps both the measured duration and the completion time on the live row (timing variant of the replace helper), matching the ToolDone path (finding 1) - Message cache key includes show_tool_timestamp and timestamp_tz so a config flip invalidates cached tool rows (finding 3) - Test config guard distinguishes an originally-unset JCODE_HOME from an empty value: restoring "" pointed JCODE_HOME at the cwd and leaked host files into test results (finding 5) Reviewed non-goals: - finding 2 (expanded compacted history): the loader goes through the same render path that already carries msg.timestamp; the cited lines belong to a legacy fallback that no longer executes on this branch - finding 4 (specialized cards): scheduled/todo/memory cards are planner messages without measured timing; no badge by design - finding 6 (clock skew on live stamp): server-side timestamps would require a wire extension; the reload path replaces the live stamp with the authoritative stored value, which bounds the skew window
Three hop tests close the coverage gap between the storage and render ends of the 1jehuang#1454 plumbing: - jcode-base: StoredMessage.timestamp survives render_messages and its own wire serialization (the persisted-session path). - jcode-tui-messages: RenderedMessage -> DisplayMessage keeps the stamp and the measured duration. - jcode-app-core: agent.get_history() delivers both to the History payload on a real tool-result row. The app-core fixture initially asserted the stamp on an assistant text row, which the render layer intentionally does not carry; tool-result rows are the row kind that gets timestamp + duration.
…tz edges - The local manual tool path (e.g. /tools manual runs) replaced the row without the timing variant, so its live row showed no duration badge or completion stamp even though the measured duration was at hand; use replace_latest_tool_display_message_with_duration like the other completion paths. - Pin the MessageCacheContext config sensitivity with a test: flipping show_tool_timestamp or timestamp_tz must produce a distinct cache key so cached tool rows re-render under the new config. - Extend the timestamp_tz parser tests: UTC+14/utc-14 valid, UTC+15 rejected, minute overflow rejected, sign-only and non-numeric digits fall back to local.
…edOffset Property check over the timestamp_tz grammar's output space: the render path feeds timestamp_fixed_offset_secs() straight into FixedOffset::east_opt, so each accepted value must survive that call and format as HH:MM:SS. chrono joins as a dev-dependency only.
The SDK path in the turn loop replaced the tool row without timing, so SDK-executed tools showed no stamp even though the completion wall-clock time is known locally. There is no locally measured duration for these rows (the SDK ran the tool remotely), so only the timestamp is set; duration stays None until the authoritative reload.
Greptile P2 (both inline findings on state_ui_messages): the message cache keys rows by stable_cache_hash, which deliberately excludes metadata - so a timing-only update (title and content identical) kept the badge-less cached render even though the body cache was invalidated. tool_duration_ms and timestamp now hash into the key.
|
Want your agent to iterate on Greptile's feedback? Try greploops. |
…80-resolve # Conflicts: # Cargo.lock # crates/jcode-app-core/src/agent_tests.rs # crates/jcode-config-types/src/display.rs # crates/jcode-protocol/Cargo.toml
…open, current, merge-clean
…ntlns Greptile follow-ups on 1jehuang#1480: - rewind undo, rewind N and the local compacted-history window rebuild DisplayMessages from rendered messages, but dropped timestamp and tool_duration_ms, so badges vanished after those operations. Both mappers now copy the rendered fields. - removes throwaway println! diagnostics from badge tests; assertions already include the rendered row in their messages.
…into feat/issue-1454-tool-timestamp
Merges upstream master (wire/events.rs split, model_context restructure) and re-applies this PR's surface: ToolDone.duration_ms on the new wire layout, timestamp/tool_duration_ms in rebuilt DisplayMessage paths, and RenderedMessage timing in the ProviderNative render arm.
…timing fields after upstream merge
Greptile P2 on 1jehuang#1480: a provider-native search followed by more output in the same assistant response inherited the assistant message's timestamp, so earlier searches appeared to finish at response end. The items carry no wall-clock time of their own; leaving the field None hides the badge instead of showing a wrong clock.
…provider-native Second Greptile P2: the previous fix landed on the wrong arm. Ordinary ToolResult rows must preserve the stored completion time (the badge is the whole point of the feature); only provider-native items, which carry no wall-clock time of their own, stay unstamped.
The stamp now leads the row - "HH:MM:SS icon tool summary · 223 tok · 2m 3s" - so rows read clock-first when scanning. Only the duration badge stays on the right with the token count. Layout matches the fork's rendering: neutral blue-grey clock, tighter gap between the stamp and the status icon, and the summary budget accounts for the saved space.
Closes #1454. Stacked on #1478 (that one must land first; this branch sits directly on its tip).
Problem
When scanning a transcript there is no way to tell when a tool call executed. This matters when resuming a session after a break, when checking whether a row predates an edit to the code, or when correlating a tool result with external events (a deploy, a log line, a timer). The data already exists -
StoredMessage.timestampis recorded for every message - but it never reaches the transcript row.Fix
Render the wall-clock time of day on each completed tool row, at the left edge, before the tool name:
Why the left edge (changed from the earlier right-side draft): when scanning
a column of tool rows, a fixed-position clock on the left is dramatically easier
to read than a right-aligned one. On the right it shares space with the token
count and duration suffix, so its x-position drifts row to row as output sizes
vary; on the left every stamp sits at exactly the same column, letting the eye
run straight down the timeline. It also groups time with the tool identity
("when" + "what") while the right side stays reserved for measurements
("how big", "how long"), and frees the right suffix from carrying three
competing badges in narrow terminals.
display.show_tool_timestamp(defaultfalse): strictly opt-in, missing key means off.display.timestamp_tz(defaultlocal):UTC+3,utc-5,UTC+0,UTC+05:30, or a bare3selects a fixed offset (remote/devcontainer setups where the machine TZ differs); anything else -Moscow,UTC+99- falls back to local so a typo never breaks rendering. Both behaviors pinned by unit tests.protocol::HistoryMessagegains optionaltimestamp+tool_duration_mswithserde(default, skip_serializing_if); legacy payloads decode unchanged (wire test pins roundtrip and legacy default). The live getters, the persisted-session fallback, and the TUI History/CompactedHistory mappers pass it through, so reloaded transcripts show the same stamp the picker preview shows.rgb(120,130,145): it never inherits duration severity color, so a slow call cannot make the timestamp read as an error state.21:51:28Z->00:51:28).ToolDonecarries no wall-clock time by design); duration badge from feat(tui): show how long each tool call took on the tool row #1478 still lands instantly.Verification
cargo test -p jcode-tui --lib tool_time_badgecargo test -p jcode-tui --lib tool_durationcargo test -p jcode-config-types --libcargo test -p jcode-protocolcargo test -p jcode-harness-api-server --libcargo test -p jcode-app-core --lib historycargo check --workspace --all-targetscargo fmton touched crates--alldiffs pre-exist on master:jev.rs,provider/mod.rs,allocator.rs)cargo clippyon touched cratesPre-existing flakes, unrelated:
benchmark_resume_loading_reports_timings(session-list cache/env race across parallel test threads, upstream f781fcd; green single-threaded) andjcode-baseauth tests that read ambientOPENAI_API_KEY-style env vars (green with keys unset). Full-suite runs (validation pass):jcode-tui --lib -- --test-threads=12417 passed / 4 failed andjcode-app-core --lib1418 passed / 2 failed; every failure is an env-pollution or shared-state flake that passes in isolation with provider keys unset (tui_openai_compatible*,test_model_picker_copilot*- hydrates the host's persisted model catalog, also fails onfeat/issue-1453-tool-durationwithout this branch,background_task_wake*,debug_tool_selfdev_reload*).Validation round (follow-up commits)
9b6d10304adds three hop tests pinning every timestamp hop: StoredMessage.timestamp survivesrender_messages+ its wire serialization (jcode-base), the RenderedMessage -> DisplayMessage conversion keeps stamp and duration (jcode-tui-messages), andagent.get_history()delivers both on a real tool-result row (jcode-app-core).6e926a2f6stamps manually-executed local tool rows (the/toolsmanual path used the plain replace helper, so its live row skipped both badges), pinsMessageCacheContextconfig sensitivity (ashow_tool_timestamp/timestamp_tzflip must not serve cached rows), and extendstimestamp_tzparser tests with boundary cases:UTC+14/utc-14valid,UTC+15rejected,:60minutes rejected, sign-only/non-numeric fall back to local.ca0fd1f7fproperty-checks that every offset accepted by the parser maps onto a realchrono::FixedOffsetand formats as HH:MM:SS (the render path feeds the parser output straight intoFixedOffset::east_opt); chrono added as a dev-dependency only.5feebf1e9stamps SDK-executed tool rows with their completion wall-clock time via the timing replace helper (the SDK path was the last plain-replace caller); no duration is claimed for these rows because the SDK ran the tool remotely - duration stays None until the authoritative reload.How it works
docs/TOOL_ROW_BADGES.mddocuments both badges, thetimestamp_tzgrammar, the neutral clock color rationale, and narrow-terminal behavior.