Show completion timestamps after successful TUI turns (#43558)

## What changed

Replace horizontal turn separators with dim completion metadata after the final answer, including plain conversational answers. Show local completion times such as `done 2:32 PM`, adding the date for other days and the year for other years. Retain `Worked for` durations above sixty seconds and runtime metrics, and wrap metadata on narrow terminals.

Restore saved completion metadata when resuming conversations or loading older history. Keep each footer after its turn's items and deduplicate it across repeated notifications and overlapping pages. Only live completions fall back to the current time when a saved timestamp is unavailable. Failed, interrupted, and in-progress turns do not receive success footers.

Avoid submitting queued input or emitting completion notifications while replaying history.

## Testing

Add unit and snapshot coverage for timestamp formatting, duration thresholds, muted styling, narrow layouts, live and replayed completions, missing metadata, and pagination boundaries with overlapping pages.

GitOrigin-RevId: 308c35c6720720da43c9a391aa5a68c1b231c9a5
This commit is contained in:
Felipe Coury
2026-09-07 19:01:08 +00:00
committed by copyberry
parent 769a6a5bcd
commit 333c41eef6
42 changed files with 1112 additions and 202 deletions
@@ -0,0 +1,35 @@
//! Group older history items at successful turn boundaries before projecting transcript cells.
//! A page splitting a turn only adds completion metadata when it contains that turn's last item.
use codex_app_server_protocol::ThreadItem;
use codex_app_server_protocol::Turn;
use codex_app_server_protocol::TurnStatus;
use std::collections::HashMap;
pub(super) fn group_completed_turn_items(
items: Vec<ThreadItem>,
turns: &[Turn],
) -> Vec<(Vec<ThreadItem>, Option<&Turn>)> {
let completed_boundaries: HashMap<_, _> = turns
.iter()
.filter(|turn| turn.status == TurnStatus::Completed)
.filter_map(|turn| turn.items.last().map(|item| (item.id(), turn)))
.collect();
let mut groups = Vec::new();
let mut pending = Vec::new();
for item in items {
let completed_turn = completed_boundaries.get(item.id()).copied();
pending.push(item);
if completed_turn.is_some() {
groups.push((std::mem::take(&mut pending), completed_turn));
}
}
if !pending.is_empty() {
groups.push((pending, None));
}
groups
}
#[cfg(test)]
#[path = "history_completion_tests.rs"]
mod tests;
@@ -0,0 +1,75 @@
//! Pagination boundaries preserve grouped item rendering and attach completion metadata once.
use super::*;
use codex_app_server_protocol::TurnItemsView;
use pretty_assertions::assert_eq;
fn turn(id: &str, status: TurnStatus, item_ids: &[&str]) -> Turn {
Turn {
id: id.to_string(),
items: item_ids
.iter()
.map(|id| ThreadItem::UserMessage {
id: id.to_string(),
client_id: None,
content: Vec::new(),
})
.collect(),
items_view: TurnItemsView::Summary,
status,
error: None,
started_at: None,
completed_at: Some(1_700_000_000),
duration_ms: Some(125_000),
}
}
#[test]
fn split_turn_only_completes_on_the_page_with_its_last_item() {
let turns = vec![turn(
"turn",
TurnStatus::Completed,
&["first", "second", "last"],
)];
assert_eq!(
group_completed_turn_items(turns[0].items[1..].to_vec(), &turns),
vec![(turns[0].items[1..].to_vec(), Some(&turns[0]))],
);
assert_eq!(
group_completed_turn_items(turns[0].items[..1].to_vec(), &turns),
vec![(turns[0].items[..1].to_vec(), None)],
);
}
#[test]
fn multiple_turns_keep_item_groups_and_completion_order() {
let turns = vec![
turn("first", TurnStatus::Completed, &["a", "b"]),
turn("second", TurnStatus::Completed, &["c", "d"]),
];
let items = turns.iter().flat_map(|turn| turn.items.clone()).collect();
assert_eq!(
group_completed_turn_items(items, &turns),
vec![
(turns[0].items.clone(), Some(&turns[0])),
(turns[1].items.clone(), Some(&turns[1])),
],
);
}
#[test]
fn unsuccessful_and_running_turns_do_not_create_completion_boundaries() {
let turns = vec![
turn("failed", TurnStatus::Failed, &["a"]),
turn("interrupted", TurnStatus::Interrupted, &["b"]),
turn("running", TurnStatus::InProgress, &["c"]),
];
let items = turns
.iter()
.flat_map(|turn| turn.items.clone())
.collect::<Vec<_>>();
assert_eq!(
group_completed_turn_items(items.clone(), &turns),
vec![(items, None)],
);
}
+20 -7
View File
@@ -13,6 +13,9 @@ use crate::thread_transcript::thread_items_to_transcript_cells;
use codex_app_server_protocol::ClientRequest;
use codex_app_server_protocol::ThreadItemsListResponse;
#[path = "history_completion.rs"]
mod completion;
impl App {
/// Start one bounded page request shared by scrollback refill and the transcript overlay.
pub(crate) fn request_older_history_page(
@@ -183,6 +186,23 @@ impl App {
}
}
items.retain(|item| !hidden_item_ids.contains(item.id()));
let mut cells = Vec::new();
for (items, completed_turn) in completion::group_completed_turn_items(items, &turns) {
cells.extend(thread_items_to_transcript_cells(
Some(thread_id),
&cwd,
items,
visibility,
Some(&self.config),
));
if let Some(turn) = completed_turn
&& let Some(completion) = self
.chat_widget
.completion_cell(turn, Some(ReplayKind::ResumeInitialMessages))
{
cells.push(Arc::new(completion));
}
}
{
let mut store = store.lock().await;
turns.retain_mut(|turn| {
@@ -199,13 +219,6 @@ impl App {
});
store.turns.splice(0..0, turns);
}
let cells = thread_items_to_transcript_cells(
Some(thread_id),
&cwd,
items,
visibility,
Some(&self.config),
);
if self.backtrack.overlay_preview_active {
self.backtrack.nth_user_message = self.backtrack.nth_user_message.saturating_add(
cells
+2
View File
@@ -34,6 +34,8 @@ mod misalignment_policy;
mod model_catalog;
#[path = "tests/model_defaults_tests.rs"]
mod model_defaults;
#[path = "tests/pagination_completion_tests.rs"]
mod pagination_completion_tests;
#[path = "tests/patch_approval_tests.rs"]
mod patch_approval_tests;
#[path = "tests/permission_shortcuts_tests.rs"]
@@ -0,0 +1,169 @@
//! Completed older pages keep each footer after its answer, including overlapping pages.
use super::session_lifecycle_requests::start_recording_app_server;
use super::*;
use app_test_support::create_fake_paginated_rollout;
use app_test_support::rollout_path;
use chrono::TimeZone;
use codex_app_server_protocol::ThreadItemsListResponse;
use codex_protocol::items::AgentMessageContent;
use codex_protocol::items::AgentMessageItem;
use codex_protocol::items::TurnItem;
use codex_protocol::items::UserMessageItem;
use codex_protocol::protocol::ItemCompletedEvent;
use codex_protocol::protocol::TurnCompleteEvent;
use codex_protocol::user_input::UserInput as CoreUserInput;
use codex_state::SqliteConfig;
#[tokio::test]
async fn older_pagination_completion_footers_follow_answers_without_overlap_duplicates()
-> Result<()> {
let mut app = make_test_app().await;
let codex_home = tempdir()?;
app.config.codex_home = codex_home.path().to_path_buf().abs();
app.config.sqlite = SqliteConfig::new_for_testing(codex_home.path().abs());
app.local_settings.tui.terminal_resize_reflow_max_rows = Some(2);
let completed_at = chrono::Local
.with_ymd_and_hms(
/*year*/ 2000, /*month*/ 9, /*day*/ 6, /*hour*/ 14,
/*min*/ 32, /*sec*/ 0,
)
.single()
.expect("unambiguous local completion time");
let timestamp = completed_at.to_rfc3339();
let filename_timestamp = "2000-09-06T14-32-00";
let thread_id = create_fake_paginated_rollout(
codex_home.path(),
filename_timestamp,
&timestamp,
"completed pagination",
Some(app.config.model_provider_id.as_str()),
/*git_info*/ None,
)
.map_err(|error| color_eyre::eyre::eyre!(error))?;
let path = rollout_path(codex_home.path(), filename_timestamp, &thread_id);
let thread_id = ThreadId::from_string(&thread_id)?;
let mut records = std::fs::read_to_string(&path)?
.lines()
.take(/*n*/ 1)
.map(serde_json::from_str::<serde_json::Value>)
.collect::<Result<Vec<_>, _>>()?;
for (index, name) in ["Oldest", "Middle", "Newest"].into_iter().enumerate() {
let turn_id = format!("turn-{index}");
let finished = completed_at.timestamp() + index as i64 * 60;
let mut events = vec![EventMsg::TurnStarted(TurnStartedEvent {
turn_id: turn_id.clone(),
trace_id: None,
started_at: Some(finished - 125),
model_context_window: None,
collaboration_mode_kind: Default::default(),
})];
let items = [
TurnItem::UserMessage(UserMessageItem {
id: format!("prompt-{index}"),
client_id: None,
content: vec![CoreUserInput::Text {
text: format!("{name} prompt"),
text_elements: Vec::new(),
}],
}),
TurnItem::AgentMessage(AgentMessageItem {
id: format!("answer-{index}"),
content: vec![AgentMessageContent::Text {
text: format!("{name} answer"),
}],
phase: None,
memory_citation: None,
delivery: None,
questions: None,
}),
];
events.extend(items.into_iter().map(|item| {
EventMsg::ItemCompleted(ItemCompletedEvent {
thread_id,
turn_id: turn_id.clone(),
item,
started_at_ms: None,
completed_at_ms: finished * 1_000,
})
}));
events.push(EventMsg::TurnComplete(TurnCompleteEvent {
turn_id,
last_agent_message: Some(format!("{name} answer")),
error: None,
started_at: Some(finished - 125),
completed_at: Some(finished),
duration_ms: Some(125_000),
time_to_first_token_ms: None,
}));
for event in events {
records.push(serde_json::json!({
"timestamp": timestamp,
"ordinal": records.len(),
"type": "event_msg",
"payload": event,
}));
}
}
let records = records
.iter()
.map(ToString::to_string)
.collect::<Vec<_>>()
.join("\n");
std::fs::write(path, format!("{records}\n"))?;
let (mut app_server, _requests, proxy) = start_recording_app_server(
&app.config,
/*blocked_thread_list*/ None,
/*failed_thread_name*/ None,
)
.await?;
let started = app_server
.resume_thread(
&app.local_settings,
app.config.clone(),
thread_id,
crate::app_server_session::ResumeModelSettings::RestoreFromThread,
)
.await?;
app.enqueue_primary_thread_session(started.session, started.turns)
.await?;
// Snapshot only the prepended pages; the newest turn is already hydrated in the store.
app.local_settings.tui.terminal_resize_reflow_max_rows = None;
let mut tui = crate::tui::test_support::make_test_tui()?;
app.open_transcript_overlay(&mut tui);
let mut overlapping_answer = None;
let mut snapshots = Vec::new();
for limit in [1, 100] {
let cursor = app_server
.begin_older_history_page(thread_id)
.expect("older page");
let mut page: ThreadItemsListResponse = app_server
.thread_items_page(
thread_id,
/*turn_id*/ None,
Some(cursor.clone()),
limit,
)
.await?;
if let Some(answer) = overlapping_answer.take() {
// The later response repeats the preceding page's completed answer.
page.data.insert(/*index*/ 0, answer);
} else {
overlapping_answer = page.data.first().cloned();
}
app.handle_older_history_page(&mut tui, &mut app_server, thread_id, &cursor, Ok(page))
.await?;
snapshots.push(
app.render_transcript_lines_for_reflow(/*width*/ 80)
.lines
.iter()
.map(rendered_line_text)
.collect::<Vec<_>>()
.join("\n"),
);
}
insta::assert_snapshot!(snapshots.join("\n\n--- next overlapping page ---\n\n"));
app_server.shutdown().await?;
proxy.await??;
Ok(())
}
+10 -3
View File
@@ -2,6 +2,7 @@ use super::*;
use crate::app::safety_buffering::SafetyBufferedRetry;
use crate::app::session_lifecycle::ThreadAttachPresentation;
use crate::chatwidget::UserMessage;
use crate::chatwidget::tests::helpers::normalize_completion_timestamps;
use codex_app_server_client::AppServerEvent;
use codex_app_server_protocol::ModelSafetyBufferingUpdatedNotification;
use codex_model_provider_info::ModelProviderInfo;
@@ -894,9 +895,15 @@ goals = true
let mut replayed_history = String::new();
while let Ok(event) = app_event_rx.try_recv() {
if let AppEvent::InsertHistoryCell(cell) = event {
replayed_history.push_str(&lines_to_single_string(
&cell.transcript_lines(/*width*/ 80),
));
let rendered = lines_to_single_string(&cell.transcript_lines(/*width*/ 80));
if cell
.as_any()
.is::<crate::history_cell::FinalMessageSeparator>()
{
replayed_history.push_str(&normalize_completion_timestamps(rendered));
} else {
replayed_history.push_str(&rendered);
}
}
}
assert_eq!(
@@ -0,0 +1,26 @@
---
source: tui/src/app/tests/pagination_completion_tests.rs
expression: "snapshots.join(\"\\n\\n--- next overlapping page ---\\n\\n\")"
---
Earlier messages are available — press ctrl + t to view the full transcript
• Middle answer
Worked for 2m 5s · done Sep 6, 2000 at 2:33 PM
--- next overlapping page ---
› Oldest prompt
• Oldest answer
Worked for 2m 5s · done Sep 6, 2000 at 2:32 PM
› Middle prompt
• Middle answer
Worked for 2m 5s · done Sep 6, 2000 at 2:33 PM
@@ -4,4 +4,4 @@ expression: rendered_retry
---
› Handle the safety-buffered request
Keep the accepted steer
⚠ Full-history hydration is deprecated for paginated threads; omit `includeTurns` or set it to `false`, then page with `thread/turns/list` and `thread/items/list`.• done
⚠ Full-history hydration is deprecated for paginated threads; omit `includeTurns` or set it to `false`, then page with `thread/turns/list` and `thread/items/list`.• done done [completion time]
+1 -5
View File
@@ -405,6 +405,7 @@ use self::rate_limits::is_app_server_cyber_policy_error;
mod recap;
mod reset_credits;
pub(crate) use self::rate_limits::limit_label_for_window;
mod completion;
mod reasoning_shortcuts;
mod rendering;
mod replay;
@@ -1196,7 +1197,6 @@ impl ChatWidget {
fn flush_active_cell(&mut self) {
if let Some(active) = self.transcript.take_active_cell() {
self.transcript.needs_final_message_separator = true;
self.app_event_tx.send(AppEvent::InsertHistoryCell(active));
self.request_pending_usage_output_insertion();
}
@@ -1242,7 +1242,6 @@ impl ChatWidget {
if !self.has_active_stream_tail() {
self.flush_active_cell();
}
self.transcript.needs_final_message_separator = true;
} else if !keep_placeholder_header_active
&& self
.transcript
@@ -1351,9 +1350,6 @@ impl ChatWidget {
display.remote_image_urls,
));
}
// User messages reset separator state so the next agent response doesn't add a stray break.
self.transcript.needs_final_message_separator = false;
}
/// Exit the UI immediately without waiting for shutdown.
@@ -10,7 +10,6 @@ impl ChatWidget {
let Some(wait) = self.unified_exec_wait_streak.take() else {
return;
};
self.transcript.needs_final_message_separator = true;
let cell = history_cell::new_unified_exec_interaction(wait.command_display, String::new());
self.app_event_tx
.send(AppEvent::InsertHistoryCell(Box::new(cell)));
@@ -422,7 +421,6 @@ impl ChatWidget {
);
let completed = orphan.complete_call(&id, output, duration);
debug_assert!(completed, "new orphan exec cell should contain {id}");
self.transcript.needs_final_message_separator = true;
self.app_event_tx
.send(AppEvent::InsertHistoryCell(Box::new(orphan)));
self.request_redraw();
@@ -448,8 +446,6 @@ impl ChatWidget {
}
}
}
// Mark that actual work was done (command executed)
self.transcript.had_work_activity = true;
if is_user_shell {
self.maybe_send_next_queued_input();
}
+53
View File
@@ -0,0 +1,53 @@
//! Completion metadata for live and restored turns. Saved timestamps are authoritative;
//! only a live completion may fall back to the local clock. Labels are deduplicated per thread.
use super::*;
impl ChatWidget {
pub(crate) fn completion_cell(
&mut self,
turn: &Turn,
replay_kind: Option<ReplayKind>,
) -> Option<history_cell::FinalMessageSeparator> {
if self
.turn_lifecycle
.rendered_completion_turn_ids
.contains(&turn.id)
{
return None;
}
let elapsed_seconds = turn
.duration_ms
.and_then(|duration| u64::try_from(duration).ok())
.map(|duration| duration / 1_000)
.or_else(|| {
if replay_kind.is_none() {
self.bottom_pane
.status_elapsed()
.map(|elapsed| elapsed.as_secs())
} else {
None
}
})
.filter(|seconds| *seconds > 60);
let completed_at = turn
.completed_at
.and_then(|timestamp| chrono::DateTime::from_timestamp(timestamp, /*nsecs*/ 0))
.map(|timestamp| timestamp.with_timezone(&Local))
.or_else(|| replay_kind.is_none().then(Local::now));
if completed_at.is_none() && elapsed_seconds.is_none() {
return None;
}
self.turn_lifecycle
.rendered_completion_turn_ids
.insert(turn.id.clone());
let cell = history_cell::FinalMessageSeparator::new(
elapsed_seconds,
/*runtime_metrics*/ None,
);
Some(match completed_at {
Some(completed_at) => cell.with_completed_at(completed_at),
None => cell,
})
}
}
@@ -81,7 +81,6 @@ impl ChatWidget {
}
self.flush_completed_command_activity();
self.bump_active_cell_revision();
self.transcript.needs_final_message_separator = true;
self.app_event_tx
.send(AppEvent::InsertHistoryCell(Box::new(completed_cell)));
self.request_pending_usage_output_insertion();
@@ -101,7 +100,6 @@ impl ChatWidget {
&& let Some(cell) = self.active_hook_cell.take()
{
self.bump_active_cell_revision();
self.transcript.needs_final_message_separator = true;
self.app_event_tx
.send(AppEvent::InsertHistoryCell(Box::new(cell)));
self.request_pending_usage_output_insertion();
@@ -463,7 +463,6 @@ impl ChatWidget {
}
}
self.transcript.needs_final_message_separator = false;
(true, Some(op))
}
+2 -1
View File
@@ -330,9 +330,10 @@ impl ChatWidget {
);
}
self.last_non_retry_error = None;
let completion = self.completion_cell(&notification.turn, replay_kind);
self.on_task_complete(
last_agent_message.map(|(_, _, text)| text),
notification.turn.duration_ms,
completion,
replay_kind.is_some(),
);
}
+14 -13
View File
@@ -6,22 +6,10 @@
use super::*;
impl ChatWidget {
/// Flush prior activity and preserve its separator before live or replayed assistant text.
/// Flush prior activity before live or replayed assistant text.
pub(super) fn prepare_assistant_message(&mut self) {
// Before starting an agent stream, flush any active exec cell group.
self.flush_unified_exec_wait_streak();
self.flush_active_cell();
// If the previous turn inserted non-stream history (exec output, patch status, MCP
// calls), render a separator before starting the next streamed assistant message.
if self.transcript.needs_final_message_separator && self.transcript.had_work_activity {
self.add_to_history(history_cell::FinalMessageSeparator::new(
/*elapsed_seconds*/ None, /*runtime_metrics*/ None,
));
self.transcript.needs_final_message_separator = false;
} else if self.transcript.needs_final_message_separator {
// Reset the flag even if we don't show separator (no work was done)
self.transcript.needs_final_message_separator = false;
}
}
/// Replay a subset of initial events into the UI to seed the transcript when
@@ -40,6 +28,14 @@ impl ChatWidget {
}))
.collect::<Vec<_>>();
for (turn, hidden_nested_review_turn) in turns.into_iter().zip(hidden_nested_review_turns) {
// Defer completed metadata-only turns until their page loads. Active
// turns must restore their lifecycle even before any items are available.
if turn.status == TurnStatus::Completed
&& turn.items_view == codex_app_server_protocol::TurnItemsView::NotLoaded
&& turn.items.is_empty()
{
continue;
}
let Turn {
id: turn_id,
items_view: _,
@@ -76,6 +72,11 @@ impl ChatWidget {
{
error = None;
}
if hidden_nested_review_turn {
self.turn_lifecycle
.rendered_completion_turn_ids
.insert(turn_id.clone());
}
if matches!(
status,
TurnStatus::Completed | TurnStatus::Interrupted | TurnStatus::Failed
@@ -1,6 +1,6 @@
---
source: tui/src/chatwidget/tests.rs
expression: term.backend().vt100().screen().contents()
source: tui/src/chatwidget/tests/status_and_layout.rs
expression: "normalize_completion_timestamps(&\n(normalize_snapshot_paths(term.backend().vt100().screen().contents())))"
---
@@ -34,7 +34,6 @@ expression: term.backend().vt100().screen().contents()
• -- Indented code block (4 spaces)
@@ -51,3 +50,4 @@ expression: term.backend().vt100().screen().contents()
"path": "C:\\Program Files\\App",
"regex": "^foo.*(bar)?$"
}
done [completion time]
@@ -0,0 +1,7 @@
---
source: tui/src/chatwidget/tests/completion_styling_tests.rs
expression: normalize_completion_timestamps(& (text))
---
• The change is ready.
Worked for [duration] · done [completion time]
@@ -0,0 +1,10 @@
---
source: tui/src/chatwidget/tests/completion_styling_tests.rs
expression: normalize_completion_timestamps(& (text))
---
• Ran echo ready
└ ready
• The change is ready.
Worked for [duration] · done [completion time]
@@ -0,0 +1,13 @@
---
source: tui/src/chatwidget/tests/completion_styling_tests.rs
expression: "&transcript"
---
› done Sep 6, 2000 at 2:32 PM
• done Sep 6, 2000 at 2:32 PM
└ done Sep 6, 2000 at 2:32 PM
The job was done Sep 6, 2000 at 2:32 PM
done Sep 6, 2000 at 2:32 PM is the expected text
Worked for 2m 5s · done Sep 6, 2000 at 2:32 PM is quoted
done 3:24 PM
Worked for 1h 2m 3s · done Sep 6, 2000 at 2:32 PM
@@ -1,12 +1,10 @@
---
source: tui/src/chatwidget/tests/exec_flow.rs
expression: combined
expression: normalize_completion_timestamps(& (combined))
---
• Ran echo preparing
└ preparing
────────────────────────────────────────────────────────────────────────────────
• Final response.
─ Worked for 2m 05s ────────────────────────────────────────────────────────────
Worked for [duration] · done [completion time]
@@ -0,0 +1,10 @@
---
source: tui/src/chatwidget/tests/history_replay.rs
expression: "normalize_completion_timestamps(& (render_bottom_popup(&chat, 80)))"
---
• Working (0s • esc to interrupt)
› Ask Codex to do anything
gpt-5.6-sol default · /tmp/project
@@ -1,7 +1,8 @@
---
source: tui/src/chatwidget/tests/slash_commands.rs
expression: "cells.iter().map(|cell|\nlines_to_single_string(cell).trim().to_string()).collect::<Vec<_>>().join(\"\\n\")"
expression: "normalize_completion_timestamps(&\n(cells.iter().map(|cell|\nlines_to_single_string(cell).trim().to_string()).collect::<Vec<_>>().join(\"\\n\")))"
---
done [completion time]
• Saved conversation to conversation.md
• Copied conversation to clipboard
■ Copy failed: clipboard unavailable
@@ -1,8 +1,10 @@
---
source: tui/src/chatwidget/tests.rs
expression: combined
source: tui/src/chatwidget/tests/exec_flow.rs
expression: normalize_completion_timestamps(& (combined))
---
↳ Interacted with background terminal · just fix
└ pwd
• Waited for background terminal · just fix
done [completion time]
@@ -1,7 +1,9 @@
---
source: tui/src/chatwidget/tests.rs
expression: combined
source: tui/src/chatwidget/tests/exec_flow.rs
expression: normalize_completion_timestamps(& (combined))
---
• Waited for background terminal · cargo test -p codex-core
• Final response.
done [completion time]
@@ -1,7 +1,9 @@
---
source: tui/src/chatwidget/tests.rs
expression: combined
source: tui/src/chatwidget/tests/exec_flow.rs
expression: normalize_completion_timestamps(& (combined))
---
• Waited for background terminal · cargo test -p codex-core
• Streaming response.
done [completion time]
@@ -1,5 +1,7 @@
---
source: tui/src/chatwidget/tests.rs
expression: combined
source: tui/src/chatwidget/tests/exec_flow.rs
expression: normalize_completion_timestamps(& (combined))
---
• Waited for background terminal · just fix
done [completion time]
+3 -1
View File
@@ -207,7 +207,7 @@ macro_rules! assert_chatwidget_snapshot {
settings.bind(|| {
insta::assert_snapshot!(
format!("codex_tui__chatwidget__tests__{}", $name),
&($value),
$value,
@$snapshot
);
});
@@ -240,6 +240,8 @@ mod bedrock_catalog_tests;
mod collaboration_catalog_tests;
#[path = "tests/compaction_tests.rs"]
mod compaction_tests;
#[path = "tests/completion_styling_tests.rs"]
mod completion_styling;
mod composer_submission;
#[path = "tests/config_errors_tests.rs"]
mod config_errors;
@@ -824,7 +824,11 @@ async fn live_app_server_turn_completed_clears_working_status_after_answer_item(
/*replay_kind*/ None,
);
assert!(drain_insert_history(&mut rx).is_empty());
let completion_cells = drain_insert_history(&mut rx)
.iter()
.map(|lines| normalize_completion_timestamps(lines_to_single_string(lines).trim()))
.collect::<Vec<_>>();
assert_eq!(completion_cells, vec!["done [completion time]"]);
assert!(!chat.bottom_pane.is_task_running());
assert!(chat.bottom_pane.status_widget().is_none());
assert_eq!(
@@ -0,0 +1,241 @@
//! Exercises completion metadata through live notifications and restored turn history.
use super::*;
use chrono::Local;
use chrono::TimeZone;
use pretty_assertions::assert_eq;
const COMPLETED_AT: i64 = 1_700_000_000;
fn completed_turn(duration_ms: Option<i64>, completed_at: Option<i64>) -> AppServerTurn {
AppServerTurn {
completed_at,
items: vec![AppServerThreadItem::AgentMessage {
id: "answer-1".to_string(),
text: "The change is ready.".to_string(),
phase: Some(MessagePhase::FinalAnswer),
memory_citation: None,
delivery: None,
questions: None,
}],
..app_server_turn(
"turn-1",
AppServerTurnStatus::Completed,
duration_ms,
/*error*/ None,
)
}
}
fn complete_turn(chat: &mut ChatWidget, turn: AppServerTurn) {
chat.handle_server_notification(
ServerNotification::TurnCompleted(TurnCompletedNotification {
thread_id: chat.thread_id.map(|id| id.to_string()).unwrap_or_default(),
turn,
}),
/*replay_kind*/ None,
);
}
fn completion_labels(rx: &mut tokio::sync::mpsc::UnboundedReceiver<AppEvent>) -> String {
std::iter::from_fn(|| rx.try_recv().ok())
.filter_map(|event| match event {
AppEvent::InsertHistoryCell(cell)
if cell.as_any().is::<history_cell::FinalMessageSeparator>() =>
{
let label = lines_to_single_string(&cell.raw_lines()).trim().to_string();
(!label.is_empty()).then_some(label)
}
_ => None,
})
.collect::<Vec<_>>()
.join("\n")
}
fn saved_completion_label() -> String {
Local
.timestamp_opt(COMPLETED_AT, /*nsecs*/ 0)
.unwrap()
.format("done %b %-d, %Y at %-I:%M %p")
.to_string()
}
#[tokio::test]
async fn completion_follows_plain_and_streamed_tool_answers() {
for streamed in [false, true] {
let (mut chat, mut rx, _ops) = make_chatwidget_manual(/*model_override*/ None).await;
handle_turn_started(&mut chat, "turn-1");
if streamed {
let command = begin_exec(&mut chat, "command-1", "echo ready");
end_exec(&mut chat, command, "ready", "", /*exit_code*/ 0);
handle_agent_message_delta(&mut chat, "The change is ready.\n");
chat.run_commit_tick();
}
complete_turn(&mut chat, completed_turn(Some(125_000), Some(COMPLETED_AT)));
let text = drain_insert_history(&mut rx)
.iter()
.map(|lines| lines_to_single_string(lines))
.collect::<String>();
assert_chatwidget_snapshot!(
if streamed {
"completion_after_streamed_tool_answer"
} else {
"completion_after_plain_answer"
},
normalize_completion_timestamps(text),
);
}
}
#[tokio::test]
async fn completion_live_applies_duration_threshold_and_preserves_timestamp_fallback() {
for (duration_ms, completed_at, prefix) in [
(598, Some(COMPLETED_AT), ""),
(1_000, Some(COMPLETED_AT), ""),
(60_000, Some(COMPLETED_AT), ""),
(60_999, Some(COMPLETED_AT), ""),
(61_000, Some(COMPLETED_AT), "Worked for 1m 1s · "),
(125_000, Some(COMPLETED_AT), "Worked for 2m 5s · "),
(1_000, None, ""),
] {
let (mut chat, mut rx, _ops) = make_chatwidget_manual(/*model_override*/ None).await;
handle_turn_started(&mut chat, "turn-1");
let turn = completed_turn(Some(duration_ms), completed_at);
let before = Local::now();
complete_turn(&mut chat, turn.clone());
let after = Local::now();
let possible = [before, after].map(|time| {
let time = if completed_at.is_some() {
saved_completion_label()
} else {
time.format("done %-I:%M %p").to_string()
};
format!("{prefix}{time}")
});
let label = completion_labels(&mut rx);
assert!(possible.contains(&label), "{label:?}");
complete_turn(&mut chat, turn);
assert_eq!(completion_labels(&mut rx), "");
}
}
#[tokio::test]
async fn completion_replay_preserves_metadata_and_input_without_live_side_effects() {
let done = saved_completion_label();
for (duration_ms, completed_at, expected) in [
(
Some(125_000),
Some(COMPLETED_AT),
format!("Worked for 2m 5s · {done}"),
),
(None, None, String::new()),
(Some(598), Some(COMPLETED_AT), done.clone()),
(Some(60_000), Some(COMPLETED_AT), done.clone()),
(
Some(61_000),
Some(COMPLETED_AT),
format!("Worked for 1m 1s · {done}"),
),
(Some(60_000), None, String::new()),
(Some(125_000), None, "Worked for 2m 5s".to_string()),
] {
for replay_kind in [
ReplayKind::ResumeInitialMessages,
ReplayKind::ThreadSnapshot,
] {
let (mut chat, mut rx, mut op_rx) =
make_chatwidget_manual(/*model_override*/ None).await;
chat.thread_id = Some(ThreadId::new());
handle_turn_started(&mut chat, "turn-1");
if matches!(replay_kind, ReplayKind::ThreadSnapshot) {
chat.queue_user_message("Continue".into());
}
let queued_input = chat.input_queue.queued_user_messages.clone();
while op_rx.try_recv().is_ok() {}
let mut turn = completed_turn(duration_ms, completed_at);
chat.replay_thread_turns(vec![turn.clone()], replay_kind);
assert_eq!(completion_labels(&mut rx), expected);
assert_matches!(chat.pending_notification, None);
assert_eq!(chat.input_queue.queued_user_messages, queued_input);
assert_matches!(op_rx.try_recv(), Err(TryRecvError::Empty));
// An empty replay label must not suppress later authoritative live metadata.
chat.input_queue.queued_user_messages.clear();
turn.completed_at = Some(COMPLETED_AT);
complete_turn(&mut chat, turn.clone());
assert_eq!(
completion_labels(&mut rx),
if expected.is_empty() { &done } else { "" }
);
complete_turn(&mut chat, turn);
assert_eq!(completion_labels(&mut rx), "");
}
}
}
#[tokio::test]
async fn completion_replay_waits_for_older_turn_items_to_load() {
let (mut chat, mut rx, _ops) = make_chatwidget_manual(/*model_override*/ None).await;
let older_completed_at = COMPLETED_AT - 86_400;
let mut older = completed_turn(Some(125_000), Some(older_completed_at));
older.id = "older-turn".to_string();
let mut unloaded = older.clone();
unloaded.items_view = codex_app_server_protocol::TurnItemsView::NotLoaded;
unloaded.items.clear();
let newer = completed_turn(Some(1_000), Some(COMPLETED_AT));
chat.replay_thread_turns(vec![unloaded, newer], ReplayKind::ResumeInitialMessages);
assert_eq!(completion_labels(&mut rx), saved_completion_label());
chat.replay_thread_turns(vec![older], ReplayKind::ThreadSnapshot);
let older_time = Local
.timestamp_opt(older_completed_at, /*nsecs*/ 0)
.unwrap()
.format("done %b %-d, %Y at %-I:%M %p");
assert_eq!(
completion_labels(&mut rx),
format!("Worked for 2m 5s · {older_time}"),
);
}
#[tokio::test]
async fn completion_failed_and_interrupted_turns_do_not_report_success() {
for status in [
AppServerTurnStatus::Failed,
AppServerTurnStatus::Interrupted,
] {
for replay_kind in [None, Some(ReplayKind::ResumeInitialMessages)] {
let (mut chat, mut rx, _ops) = make_chatwidget_manual(/*model_override*/ None).await;
let mut turn = completed_turn(Some(125_000), Some(COMPLETED_AT));
turn.status = status.clone();
turn.error = (status == AppServerTurnStatus::Failed).then(|| AppServerTurnError {
misalignment: None,
message: "The task failed.".to_string(),
codex_error_info: None,
additional_details: None,
});
if let Some(replay_kind) = replay_kind {
chat.replay_thread_turns(vec![turn], replay_kind);
} else {
handle_turn_started(&mut chat, "turn-1");
complete_turn(&mut chat, turn);
}
assert_eq!(completion_labels(&mut rx), "");
assert!(!chat.bottom_pane.is_task_running());
}
}
}
#[test]
fn completion_snapshot_normalization_is_explicit_and_line_scoped() {
let timestamp = "Sep 6, 2000 at 2:32 PM";
let transcript = format!(
"› done {timestamp}\n• done {timestamp}\n └ done {timestamp}\n The job was done {timestamp}\n done {timestamp} is the expected text\n Worked for 2m 5s · done {timestamp} is quoted\n\n done 3:24 PM\n Worked for 1h 2m 3s · done {timestamp}\n"
);
assert_chatwidget_snapshot!("completion_like_transcript_text", &transcript);
assert_eq!(
normalize_completion_timestamps(&transcript),
"› done Sep 6, 2000 at 2:32 PM\n• done Sep 6, 2000 at 2:32 PM\n └ done Sep 6, 2000 at 2:32 PM\n The job was done Sep 6, 2000 at 2:32 PM\n done Sep 6, 2000 at 2:32 PM is the expected text\n Worked for 2m 5s · done Sep 6, 2000 at 2:32 PM is quoted\n\n done [completion time]\n Worked for [duration] · done [completion time]\n"
);
}
+23 -8
View File
@@ -847,7 +847,7 @@ async fn unified_exec_end_after_task_complete_is_suppressed() {
drain_insert_history(&mut rx);
chat.on_task_complete(
/*last_agent_message*/ None, /*duration_ms*/ None, /*from_replay*/ false,
/*last_agent_message*/ None, /*completion*/ None, /*from_replay*/ false,
);
end_exec(&mut chat, begin, "", "", /*exit_code*/ 0);
@@ -863,7 +863,7 @@ async fn unified_exec_interaction_after_task_complete_is_suppressed() {
let (mut chat, mut rx, _op_rx) = make_chatwidget_manual(/*model_override*/ None).await;
chat.on_task_started();
chat.on_task_complete(
/*last_agent_message*/ None, /*duration_ms*/ None, /*from_replay*/ false,
/*last_agent_message*/ None, /*completion*/ None, /*from_replay*/ false,
);
terminal_interaction(&mut chat, "call-1", "proc-1", "ls\n");
@@ -891,7 +891,10 @@ async fn unified_exec_wait_after_final_agent_message_snapshot() {
.iter()
.map(|lines| lines_to_single_string(lines))
.collect::<String>();
assert_chatwidget_snapshot!("unified_exec_wait_after_final_agent_message", combined);
assert_chatwidget_snapshot!(
"unified_exec_wait_after_final_agent_message",
normalize_completion_timestamps(combined)
);
}
#[tokio::test]
@@ -915,7 +918,10 @@ async fn unified_exec_wait_before_streamed_agent_message_snapshot() {
.iter()
.map(|lines| lines_to_single_string(lines))
.collect::<String>();
assert_chatwidget_snapshot!("unified_exec_wait_before_streamed_agent_message", combined);
assert_chatwidget_snapshot!(
"unified_exec_wait_before_streamed_agent_message",
normalize_completion_timestamps(combined)
);
}
#[tokio::test]
@@ -952,10 +958,13 @@ async fn final_worked_for_uses_cumulative_turn_duration_snapshot() {
.map(|lines| lines_to_single_string(lines))
.collect::<String>();
assert!(
combined.contains("Worked for 2m 05s"),
combined.contains("Worked for 2m 5s"),
"expected final separator to use cumulative turn duration, got:\n{combined}"
);
assert_chatwidget_snapshot!("final_worked_for_uses_cumulative_turn_duration", combined);
assert_chatwidget_snapshot!(
"final_worked_for_uses_cumulative_turn_duration",
normalize_completion_timestamps(combined)
);
}
}
@@ -1027,7 +1036,10 @@ async fn unified_exec_waiting_multiple_empty_snapshots() {
.iter()
.map(|lines| lines_to_single_string(lines))
.collect::<String>();
assert_chatwidget_snapshot!("unified_exec_waiting_multiple_empty_after", combined);
assert_chatwidget_snapshot!(
"unified_exec_waiting_multiple_empty_after",
normalize_completion_timestamps(combined)
);
}
#[tokio::test]
@@ -1107,7 +1119,10 @@ async fn unified_exec_non_empty_then_empty_snapshots() {
combined.push('\n');
}
combined.push_str(&post);
assert_chatwidget_snapshot!("unified_exec_non_empty_then_empty_after", combined);
assert_chatwidget_snapshot!(
"unified_exec_non_empty_then_empty_after",
normalize_completion_timestamps(combined)
);
}
#[tokio::test]
@@ -1724,3 +1724,25 @@ pub(super) async fn assert_hook_events_snapshot(
.collect::<String>();
assert_chatwidget_snapshot!(snapshot_name, combined);
}
/// Normalize complete footer lines only, in snapshots that opt into clock normalization.
pub(crate) fn normalize_completion_timestamps(value: impl std::fmt::Display) -> String {
static COMPLETION_FOOTER: std::sync::LazyLock<regex_lite::Regex> = std::sync::LazyLock::new(
|| {
regex_lite::Regex::new(r"(?m)^(?P<indent>[ \t]*)(?P<duration>Worked for (?:[0-9]+h )?(?:[0-9]+m )?[0-9]+s · )?done (?:[A-Z][a-z]{2} [0-9]{1,2}(?:, [0-9]{4})? at )?[0-9]{1,2}:[0-9]{2} (?:AM|PM)(?P<padding>[ \t]*)$")
.expect("valid completion footer pattern")
},
);
COMPLETION_FOOTER
.replace_all(&value.to_string(), |captures: &regex_lite::Captures<'_>| {
let indent = &captures["indent"];
let padding = &captures["padding"];
let duration = if captures.name("duration").is_some() {
"Worked for [duration] · "
} else {
""
};
format!("{indent}{duration}done [completion time]{padding}")
})
.into_owned()
}
@@ -1508,29 +1508,51 @@ async fn thread_snapshot_replayed_turn_started_marks_task_running() {
#[tokio::test]
async fn replayed_in_progress_turn_marks_task_running() {
let (mut chat, mut rx, _op_rx) = make_chatwidget_manual(/*model_override*/ None).await;
chat.replay_thread_turns(
vec![AppServerTurn {
id: "turn-1".to_string(),
items_view: codex_app_server_protocol::TurnItemsView::Full,
items: Vec::new(),
status: AppServerTurnStatus::InProgress,
error: None,
started_at: None,
completed_at: None,
duration_ms: None,
}],
for replay_kind in [
ReplayKind::ResumeInitialMessages,
);
ReplayKind::ThreadSnapshot,
] {
for items_view in [
codex_app_server_protocol::TurnItemsView::Full,
codex_app_server_protocol::TurnItemsView::NotLoaded,
] {
let (mut chat, mut rx, mut op_rx) =
make_chatwidget_manual(/*model_override*/ None).await;
chat.thread_id = Some(ThreadId::new());
chat.replay_thread_turns(
vec![AppServerTurn {
items_view,
..app_server_turn(
"turn-1",
AppServerTurnStatus::InProgress,
/*duration_ms*/ None,
/*error*/ None,
)
}],
replay_kind,
);
assert!(drain_insert_history(&mut rx).is_empty());
assert!(chat.bottom_pane.is_task_running());
let status = chat
.bottom_pane
.status_widget()
.expect("status indicator should be visible");
assert_eq!(status.header(), "Working");
assert!(drain_insert_history(&mut rx).is_empty());
assert_eq!(
(
chat.bottom_pane.is_task_running(),
chat.turn_lifecycle.last_turn_id.as_deref(),
),
(true, Some("turn-1")),
);
assert_chatwidget_snapshot!(
"replayed_in_progress_turn",
normalize_snapshot_paths(render_bottom_popup(&chat, /*width*/ 80)),
);
chat.handle_key_event(KeyEvent::new(KeyCode::Char('c'), KeyModifiers::CONTROL));
assert_matches!(op_rx.try_recv(), Ok(Op::Interrupt));
assert!(
std::iter::from_fn(|| rx.try_recv().ok())
.all(|event| !matches!(event, AppEvent::Exit(_)))
);
}
}
}
#[tokio::test]
@@ -935,7 +935,7 @@ async fn plan_implementation_popup_skips_when_messages_queued() {
chat.on_task_complete(
Some("Plan details".to_string()),
/*duration_ms*/ None,
/*completion*/ None,
/*from_replay*/ false,
);
@@ -963,7 +963,7 @@ async fn plan_implementation_popup_skips_without_proposed_plan() {
}],
});
chat.on_task_complete(
/*last_agent_message*/ None, /*duration_ms*/ None, /*from_replay*/ false,
/*last_agent_message*/ None, /*completion*/ None, /*from_replay*/ false,
);
let popup = render_bottom_popup(&chat, /*width*/ 80);
@@ -985,7 +985,7 @@ async fn plan_implementation_popup_shows_after_proposed_plan_output() {
chat.on_plan_delta("- Step 1\n- Step 2\n".to_string());
chat.on_plan_item_completed("- Step 1\n- Step 2\n".to_string());
chat.on_task_complete(
/*last_agent_message*/ None, /*duration_ms*/ None, /*from_replay*/ false,
/*last_agent_message*/ None, /*completion*/ None, /*from_replay*/ false,
);
let popup = render_bottom_popup(&chat, /*width*/ 80);
@@ -1028,7 +1028,7 @@ async fn plan_implementation_popup_skips_when_steer_follows_proposed_plan() {
complete_user_message(&mut chat, "user-1", "Please continue.");
chat.on_task_complete(
/*last_agent_message*/ None, /*duration_ms*/ None, /*from_replay*/ false,
/*last_agent_message*/ None, /*completion*/ None, /*from_replay*/ false,
);
let popup = render_bottom_popup(&chat, /*width*/ 80);
@@ -1075,7 +1075,7 @@ async fn plan_implementation_popup_shows_after_new_plan_follows_steer() {
.to_string(),
);
chat.on_task_complete(
/*last_agent_message*/ None, /*duration_ms*/ None, /*from_replay*/ false,
/*last_agent_message*/ None, /*completion*/ None, /*from_replay*/ false,
);
let popup = render_bottom_popup(&chat, /*width*/ 80);
@@ -1104,7 +1104,7 @@ async fn plan_implementation_popup_skips_when_rate_limit_prompt_pending() {
});
chat.on_rate_limit_snapshot(Some(snapshot(/*percent*/ 92.0)));
chat.on_task_complete(
/*last_agent_message*/ None, /*duration_ms*/ None, /*from_replay*/ false,
/*last_agent_message*/ None, /*completion*/ None, /*from_replay*/ false,
);
let popup = render_bottom_popup(&chat, /*width*/ 80);
@@ -2437,11 +2437,13 @@ async fn slash_export_opens_destination_picker() {
let cells = drain_insert_history(&mut rx);
assert_chatwidget_snapshot!(
"slash_export_completion_message",
cells
.iter()
.map(|cell| lines_to_single_string(cell).trim().to_string())
.collect::<Vec<_>>()
.join("\n"),
normalize_completion_timestamps(
cells
.iter()
.map(|cell| lines_to_single_string(cell).trim().to_string())
.collect::<Vec<_>>()
.join("\n")
),
);
}
@@ -2532,7 +2532,6 @@ async fn added_history_uses_pet_adjusted_terminal_width() {
chat.add_to_history(WidthCell(std::sync::Arc::clone(&width)));
assert_eq!(width.load(std::sync::atomic::Ordering::Relaxed), 69);
assert!(chat.transcript.needs_final_message_separator);
let backend = VT100Backend::new(/*width*/ 80, /*height*/ 4);
let mut terminal = crate::custom_terminal::Terminal::with_options(backend).expect("terminal");
terminal.set_viewport_area(Rect::new(
@@ -3332,7 +3331,7 @@ async fn completed_turn_refreshes_estimated_thread_cost() {
));
chat.on_task_complete(
/*last_agent_message*/ None, /*duration_ms*/ None, /*from_replay*/ false,
/*last_agent_message*/ None, /*completion*/ None, /*from_replay*/ false,
);
let request_id = std::iter::from_fn(|| rx.try_recv().ok())
@@ -3384,7 +3383,7 @@ async fn completed_turn_refreshes_credits_only_terminal_title() {
));
chat.on_task_complete(
/*last_agent_message*/ None, /*duration_ms*/ None, /*from_replay*/ false,
/*last_agent_message*/ None, /*completion*/ None, /*from_replay*/ false,
);
let request_id = std::iter::from_fn(|| rx.try_recv().ok())
@@ -4518,7 +4517,7 @@ async fn runtime_metrics_websocket_timing_logs_and_final_separator_sums_totals()
assert!(second_log.contains("TTFT: 80ms (iapi)"));
chat.on_task_complete(
/*last_agent_message*/ None, /*duration_ms*/ None, /*from_replay*/ false,
/*last_agent_message*/ None, /*completion*/ None, /*from_replay*/ false,
);
let mut final_separator = None;
while let Ok(event) = rx.try_recv() {
@@ -5729,7 +5728,9 @@ printf 'fenced within fenced\n'
assert_chatwidget_snapshot!(
"chatwidget_markdown_code_blocks_vt100_snapshot",
normalize_snapshot_paths(term.backend().vt100().screen().contents())
normalize_completion_timestamps(normalize_snapshot_paths(
term.backend().vt100().screen().contents()
))
);
}
@@ -105,7 +105,6 @@ impl ChatWidget {
if !handled {
self.add_to_history(history_cell::new_web_search_call(call_id, query, action));
}
self.transcript.had_work_activity = true;
}
pub(super) fn on_collab_event(&mut self, cell: PlainHistoryCell) {
@@ -160,8 +159,6 @@ impl ChatWidget {
if matches!(status, codex_app_server_protocol::PatchApplyStatus::Failed) {
self.add_to_history(history_cell::new_patch_apply_failure(String::new()));
}
// Mark that actual work was done (patch applied)
self.transcript.had_work_activity = true;
}
pub(crate) fn handle_mcp_tool_call_started_now(&mut self, item: ThreadItem) {
@@ -251,8 +248,6 @@ impl ChatWidget {
if let Some(extra) = extra_cell {
self.add_boxed_history(extra);
}
// Mark that actual work was done (MCP tool call)
self.transcript.had_work_activity = true;
}
pub(crate) fn handle_queued_item_started_now(&mut self, item: ThreadItem) {
@@ -49,10 +49,6 @@ pub(super) struct TranscriptState {
pub(super) latest_proposed_plan_markdown: Option<String>,
/// Whether this turn already produced a copyable response.
pub(super) saw_copy_source_this_turn: bool,
/// Whether the next streamed assistant content should be preceded by a final message separator.
pub(super) needs_final_message_separator: bool,
/// Whether the current turn performed "work" (exec commands, MCP tool calls, patch applications).
pub(super) had_work_activity: bool,
/// Whether the current turn emitted a plan update.
pub(super) saw_plan_update_this_turn: bool,
/// Whether the current turn emitted a proposed plan item that has not been superseded by a
@@ -109,7 +105,6 @@ impl TranscriptState {
self.last_completed_agent_message = None;
self.saw_plan_update_this_turn = false;
self.saw_plan_item_this_turn = false;
self.had_work_activity = false;
self.latest_proposed_plan_markdown = None;
self.plan_delta_buffer.clear();
self.plan_item_active = false;
@@ -12,6 +12,8 @@ pub(super) struct TurnLifecycleState {
pub(super) agent_turn_running: bool,
pub(super) last_turn_id: Option<String>,
pub(super) budget_limited_turn_ids: HashSet<String>,
/// Completion labels already inserted into this thread's visible history.
pub(super) rendered_completion_turn_ids: HashSet<String>,
pub(super) goal_status_active_turn_started_at: Option<Instant>,
}
@@ -22,6 +24,7 @@ impl TurnLifecycleState {
agent_turn_running: false,
last_turn_id: None,
budget_limited_turn_ids: HashSet::new(),
rendered_completion_turn_ids: HashSet::new(),
goal_status_active_turn_started_at: None,
}
}
@@ -49,6 +52,7 @@ impl TurnLifecycleState {
self.finish();
self.last_turn_id = None;
self.budget_limited_turn_ids.clear();
self.rendered_completion_turn_ids.clear();
}
pub(super) fn set_prevent_idle_sleep(&mut self, enabled: bool) {
+28 -43
View File
@@ -1,7 +1,7 @@
//! Agent turn lifecycle and runtime bookkeeping for `ChatWidget`.
//!
//! This module owns task start/completion state, runtime metrics, plan updates,
//! and final-message separator handling.
//! and completion metadata rendering.
use super::*;
@@ -113,7 +113,7 @@ impl ChatWidget {
pub(super) fn on_task_complete(
&mut self,
last_agent_message: Option<String>,
duration_ms: Option<i64>,
completion: Option<history_cell::FinalMessageSeparator>,
from_replay: bool,
) {
self.input_queue.submit_pending_steers_after_interrupt = false;
@@ -154,31 +154,19 @@ impl ChatWidget {
self.flush_unified_exec_wait_streak();
if !from_replay {
self.collect_runtime_metrics_delta();
let runtime_metrics =
(!self.turn_runtime_metrics.is_empty()).then_some(self.turn_runtime_metrics);
let show_work_separator = self.transcript.had_work_activity
&& (self.transcript.needs_final_message_separator || runtime_metrics.is_some());
if show_work_separator || runtime_metrics.is_some() {
let elapsed_seconds = if show_work_separator {
duration_ms
.and_then(|duration_ms| u64::try_from(duration_ms).ok())
.map(|duration_ms| duration_ms / 1_000)
.or_else(|| {
self.bottom_pane
.status_elapsed()
.map(|elapsed| elapsed.as_secs())
})
} else {
None
};
self.add_to_history(history_cell::FinalMessageSeparator::new(
elapsed_seconds,
runtime_metrics,
));
}
self.turn_runtime_metrics = RuntimeMetricsSummary::default();
self.transcript.needs_final_message_separator = false;
self.transcript.had_work_activity = false;
}
let runtime_metrics = (!from_replay && !self.turn_runtime_metrics.is_empty())
.then_some(self.turn_runtime_metrics);
if let Some(completion) = completion {
self.add_to_history(completion.with_runtime_metrics(runtime_metrics));
} else if let Some(runtime_metrics) = runtime_metrics {
self.add_to_history(history_cell::FinalMessageSeparator::new(
/*elapsed_seconds*/ None,
Some(runtime_metrics),
));
}
self.turn_runtime_metrics = RuntimeMetricsSummary::default();
if !from_replay {
self.request_status_line_branch_refresh();
self.request_status_line_git_summary_refresh();
self.refresh_thread_usage_after_turn();
@@ -213,23 +201,20 @@ impl ChatWidget {
if !from_replay {
self.transcript.saw_plan_item_this_turn = false;
}
// If there is a queued user message, send exactly one now to begin the next turn.
let follow_up_started = self.maybe_send_next_queued_input();
let active_goal_continuing = self
.current_goal_status
.as_ref()
.is_some_and(GoalStatusState::is_active);
// Emit a notification when the agent is truly waiting for the user.
// Queued follow-up input and active goal continuation both start the
// next turn immediately, so notifying at that boundary would feel like
// a false "needs attention".
if !follow_up_started && !active_goal_continuing {
self.notify(Notification::AgentTurnComplete {
response: notification_response,
});
if !from_replay {
// Emit a notification only when the live agent is waiting for the user.
let follow_up_started = self.maybe_send_next_queued_input();
let active_goal_continuing = self
.current_goal_status
.as_ref()
.is_some_and(GoalStatusState::is_active);
if !follow_up_started && !active_goal_continuing {
self.notify(Notification::AgentTurnComplete {
response: notification_response,
});
}
self.maybe_show_pending_rate_limit_prompt();
}
self.maybe_show_pending_rate_limit_prompt();
}
pub(super) fn maybe_prompt_plan_implementation(&mut self) {
+83 -47
View File
@@ -1,19 +1,28 @@
//! Turn separators and runtime-metrics labels for transcript history.
//! Subtle completion timestamps, elapsed durations, and runtime metrics for transcript history.
use super::*;
use chrono::DateTime;
use chrono::Datelike;
use chrono::Local;
use chrono::NaiveDate;
#[derive(Debug)]
/// A visual divider between turns, optionally showing how long the assistant "worked for".
/// Completion metadata shown after the assistant's final response.
///
/// This separator is only emitted for turns that performed concrete work (e.g., running commands,
/// applying patches, making MCP tool calls), so purely conversational turns do not show an empty
/// divider.
/// The timestamp records when the turn actually finished, including when restored from history.
/// Times use a twelve-hour clock; other local days include the date and other years include the year.
/// Durations are shown only above sixty seconds; shorter turns still show their timestamp.
/// Absent metadata occupies no transcript rows.
/// The display date is fixed at construction so crossing midnight cannot invalidate cached heights;
/// restoring the conversation constructs new cells and refreshes whether the timestamp needs a date.
#[derive(Debug)]
pub struct FinalMessageSeparator {
elapsed_seconds: Option<u64>,
runtime_metrics: Option<RuntimeMetricsSummary>,
completed_at: Option<DateTime<Local>>,
display_date: NaiveDate,
}
impl FinalMessageSeparator {
/// Creates a separator; completed turns should pass protocol turn duration when available.
/// Creates completion metadata using the protocol turn duration when available.
pub(crate) fn new(
elapsed_seconds: Option<u64>,
runtime_metrics: Option<RuntimeMetricsSummary>,
@@ -21,58 +30,85 @@ impl FinalMessageSeparator {
Self {
elapsed_seconds,
runtime_metrics,
completed_at: None,
display_date: Local::now().date_naive(),
}
}
pub(crate) fn with_completed_at(mut self, completed_at: DateTime<Local>) -> Self {
self.completed_at = Some(completed_at);
self
}
pub(crate) fn with_runtime_metrics(
mut self,
runtime_metrics: Option<RuntimeMetricsSummary>,
) -> Self {
self.runtime_metrics = runtime_metrics;
self
}
fn label(&self, today: NaiveDate) -> Option<String> {
let mut label_parts = Vec::new();
if let Some(elapsed_seconds) = self.elapsed_seconds.filter(|seconds| *seconds > 60) {
let hours = elapsed_seconds / 3_600;
let minutes = (elapsed_seconds % 3_600) / 60;
let seconds = elapsed_seconds % 60;
let elapsed = if hours > 0 {
format!("{hours}h {minutes}m {seconds}s")
} else if minutes > 0 {
format!("{minutes}m {seconds}s")
} else {
format!("{seconds}s")
};
label_parts.push(format!("Worked for {elapsed}"));
}
if let Some(completed_at) = self.completed_at {
let format = if completed_at.date_naive() == today {
"done %-I:%M %p"
} else if completed_at.year() == today.year() {
"done %b %-d at %-I:%M %p"
} else {
"done %b %-d, %Y at %-I:%M %p"
};
label_parts.push(completed_at.format(format).to_string());
}
if let Some(metrics_label) = self.runtime_metrics.and_then(runtime_metrics_label) {
label_parts.push(metrics_label);
}
(!label_parts.is_empty()).then(|| label_parts.join(" · "))
}
}
impl HistoryCell for FinalMessageSeparator {
fn display_lines(&self, width: u16) -> Vec<Line<'static>> {
let mut label_parts = Vec::new();
if let Some(elapsed_seconds) = self
.elapsed_seconds
.filter(|seconds| *seconds > 60)
.map(crate::status_indicator_widget::fmt_elapsed_compact)
{
label_parts.push(format!("Worked for {elapsed_seconds}"));
if width == 0 {
return Vec::new();
}
if let Some(metrics_label) = self.runtime_metrics.and_then(runtime_metrics_label) {
label_parts.push(metrics_label);
}
if label_parts.is_empty() {
return vec![Line::from_iter(["─".repeat(width as usize).dim()])];
}
let label = format!("─ {} ─", label_parts.join(" • "));
let (label, _suffix, label_width) = take_prefix_by_width(&label, width as usize);
vec![
Line::from_iter([
label,
"─".repeat((width as usize).saturating_sub(label_width)),
])
.dim(),
]
self.label(self.display_date)
.map(|label| {
let indent = if width > 2 { " " } else { "" };
let options = textwrap::Options::new(usize::from(width))
.initial_indent(indent)
.subsequent_indent(indent);
textwrap::wrap(&label, options)
.into_iter()
.map(|line| Line::from(line.into_owned()).dim())
.collect()
})
.unwrap_or_default()
}
fn raw_lines(&self) -> Vec<Line<'static>> {
let mut label_parts = Vec::new();
if let Some(elapsed_seconds) = self
.elapsed_seconds
.filter(|seconds| *seconds > 60)
.map(crate::status_indicator_widget::fmt_elapsed_compact)
{
label_parts.push(format!("Worked for {elapsed_seconds}"));
}
if let Some(metrics_label) = self.runtime_metrics.and_then(runtime_metrics_label) {
label_parts.push(metrics_label);
}
if label_parts.is_empty() {
Vec::new()
} else {
vec![Line::from(label_parts.join(" • "))]
}
self.label(self.display_date)
.map(|label| vec![Line::from(label)])
.unwrap_or_default()
}
}
#[cfg(test)]
#[path = "separators_tests.rs"]
mod tests;
pub(crate) fn runtime_metrics_label(summary: RuntimeMetricsSummary) -> Option<String> {
let mut parts = Vec::new();
if summary.tool_calls.count > 0 {
@@ -0,0 +1,168 @@
//! Completion metadata rendering, date selection, and muted styling coverage.
use super::*;
use chrono::NaiveDateTime;
use chrono::TimeZone;
use chrono::Timelike;
use codex_otel::RuntimeMetricTotals;
use pretty_assertions::assert_eq;
use ratatui::buffer::Buffer;
use ratatui::layout::Rect;
fn completed_at() -> DateTime<Local> {
let datetime = NaiveDateTime::parse_from_str("2000-09-06 14:32:00", "%Y-%m-%d %H:%M:%S")
.expect("valid completion time");
Local
.from_local_datetime(&datetime)
.single()
.expect("unambiguous completion time")
}
#[test]
fn completion_label_shows_duration_only_above_sixty_seconds() {
let completed_at = completed_at();
let labels = [
None,
Some(0),
Some(12),
Some(60),
Some(61),
Some(125),
Some(3_605),
]
.into_iter()
.map(|elapsed_seconds| {
FinalMessageSeparator::new(elapsed_seconds, /*runtime_metrics*/ None)
.with_completed_at(completed_at)
.label(completed_at.date_naive())
.expect("completion label")
})
.collect::<Vec<_>>();
insta::assert_snapshot!(labels.join("\n"), @"
done 2:32 PM
done 2:32 PM
done 2:32 PM
done 2:32 PM
Worked for 1m 1s · done 2:32 PM
Worked for 2m 5s · done 2:32 PM
Worked for 1h 0m 5s · done 2:32 PM
");
}
#[test]
fn completion_label_includes_date_when_viewed_on_another_day() {
let completed_at = completed_at();
let cell = FinalMessageSeparator::new(
/*elapsed_seconds*/ Some(125),
/*runtime_metrics*/ None,
)
.with_completed_at(completed_at);
let tomorrow = completed_at.date_naive().succ_opt().expect("next day");
insta::assert_snapshot!(cell.label(tomorrow).expect("completion label"), @"Worked for 2m 5s · done Sep 6 at 2:32 PM");
let next_year = tomorrow.with_year(/*year*/ 2001).expect("valid next year");
insta::assert_snapshot!(cell.label(next_year).expect("completion label"), @"Worked for 2m 5s · done Sep 6, 2000 at 2:32 PM");
}
#[test]
fn completion_uses_twelve_hour_time_at_midnight_noon_and_afternoon() {
let labels = [0, 12, 15].map(|hour| {
let completed_at = completed_at().with_hour(hour).expect("valid hour");
FinalMessageSeparator::new(/*elapsed_seconds*/ None, /*runtime_metrics*/ None)
.with_completed_at(completed_at)
.label(completed_at.date_naive())
.expect("completion label")
});
insta::assert_snapshot!(labels.join("\n"), @"
done 12:32 AM
done 12:32 PM
done 3:32 PM
");
}
#[test]
fn completion_without_metadata_has_no_visible_or_raw_lines() {
let cell =
FinalMessageSeparator::new(/*elapsed_seconds*/ None, /*runtime_metrics*/ None);
assert_eq!(cell.display_lines(/*width*/ 80), Vec::<Line>::new());
assert_eq!(cell.raw_lines(), Vec::<Line>::new());
}
#[test]
fn completion_without_timestamp_retains_known_elapsed_duration() {
let cell = FinalMessageSeparator::new(
/*elapsed_seconds*/ Some(125),
/*runtime_metrics*/ None,
);
insta::assert_snapshot!(cell.raw_lines()[0].to_string(), @"Worked for 2m 5s");
}
#[test]
fn completion_wraps_metadata_and_preserves_unwrapped_raw_text() {
let cell = FinalMessageSeparator::new(
/*elapsed_seconds*/ Some(125),
/*runtime_metrics*/ None,
)
.with_completed_at(completed_at())
.with_runtime_metrics(Some(RuntimeMetricsSummary {
tool_calls: RuntimeMetricTotals {
count: 3,
duration_ms: 2_450,
},
..RuntimeMetricsSummary::default()
}));
let lines = cell.display_lines(/*width*/ 24);
let rendered = lines.iter().map(ToString::to_string).collect::<Vec<_>>();
insta::assert_snapshot!(rendered.join("\n"), @"
Worked for 2m 5s ·
done Sep 6, 2000 at
2:32 PM · Local tools:
3 calls (2.5s)
");
insta::assert_snapshot!(cell.raw_lines()[0].to_string(), @"Worked for 2m 5s · done Sep 6, 2000 at 2:32 PM · Local tools: 3 calls (2.5s)");
for width in [0, 1, 5, 24] {
assert!(
cell.display_lines(width)
.iter()
.all(|line| line.width() <= usize::from(width))
);
}
}
#[test]
fn completion_renders_with_dim_default_colors() {
let cell: Box<dyn HistoryCell> = Box::new(
FinalMessageSeparator::new(/*elapsed_seconds*/ None, /*runtime_metrics*/ None)
.with_completed_at(completed_at()),
);
let area = Rect::new(
/*x*/ 0, /*y*/ 0, /*width*/ 80, /*height*/ 1,
);
let mut buffer = Buffer::empty(area);
cell.render(area, &mut buffer);
let text_width = cell.display_lines(area.width)[0].width();
let styles = (0..text_width)
.map(|x| {
let rendered = &buffer[(x as u16, 0)];
(rendered.fg, rendered.bg, rendered.modifier)
})
.collect::<Vec<_>>();
assert_eq!(
styles,
vec![(Color::Reset, Color::Reset, Modifier::DIM); text_width]
);
}
#[test]
fn completion_rendering_uses_the_captured_display_date() {
let completed_at = completed_at();
let mut cell =
FinalMessageSeparator::new(/*elapsed_seconds*/ None, /*runtime_metrics*/ None)
.with_completed_at(completed_at);
cell.display_date = completed_at.date_naive();
insta::assert_snapshot!(cell.display_lines(/*width*/ 80)[0].to_string(), @" done 2:32 PM");
assert_eq!(cell.raw_lines(), vec![Line::from("done 2:32 PM")]);
}
+2 -2
View File
@@ -598,7 +598,7 @@ fn unified_exec_interaction_cell_renders_wait() {
}
#[test]
fn final_message_separator_hides_short_worked_label_and_includes_runtime_metrics() {
fn final_message_separator_preserves_runtime_metrics_for_short_turns() {
let summary = RuntimeMetricsSummary {
tool_calls: RuntimeMetricTotals {
count: 3,
@@ -633,7 +633,7 @@ fn final_message_separator_hides_short_worked_label_and_includes_runtime_metrics
let rendered = render_lines(&cell.display_lines(/*width*/ 600));
assert_eq!(rendered.len(), 1);
assert!(!rendered[0].contains("Worked for"));
assert!(rendered[0].starts_with(" Local tools:"));
assert!(rendered[0].contains("Local tools: 3 calls (2.5s)"));
assert!(rendered[0].contains("Inference: 2 calls (1.2s)"));
assert!(rendered[0].contains("WebSocket: 1 events send (700ms)"));