From 677a82c4fd8972c24b145b76e401548c2dd6bdb9 Mon Sep 17 00:00:00 2001 From: Tryanks Date: Sun, 4 Oct 2026 21:36:52 +0800 Subject: [PATCH] perf: compact thread logs at turn end under a layout epoch A thread's log is rewritten with only the last cumulative turn diff per turn and with adjacent deltas of one item merged. The rules live in core and follow the fold's own decisions; a rewrite is installed only when the compacted records fold equal to the originals, private continuation state included, and only from a strict read of the file. Rewriting renumbers records, so a session cursor is now a layout epoch and a position. The epoch is the log's first line and is replaced with the body in one rename. A resident log keeps the layout it was loaded in, so connected clients are not disturbed; a cursor from another layout gets a baseline that replaces what the client holds in one step. Compaction runs in the store writer's order after a turn completes and before a log leaves residency, and a background pass at startup rewrites existing cold logs. The first rewrite keeps the original as .jsonl.orig until the next start. PROTOCOL_VERSION 10. Closes #522 --- crates/app/src/main.rs | 10 +- crates/client/src/lib.rs | 43 +- crates/core/src/session.rs | 58 +- crates/core/src/session/compaction.rs | 522 ++++++++++++ crates/headless/src/main.rs | 1 + crates/protocol/src/event.rs | 49 +- crates/protocol/src/lib.rs | 8 +- crates/protocol/src/query.rs | 13 +- crates/protocol/src/tests.rs | 81 +- crates/protocol/src/wire.rs | 6 + crates/runtime/src/app/compaction.rs | 197 +++++ crates/runtime/src/app/events.rs | 17 +- crates/runtime/src/app/history.rs | 181 ++-- crates/runtime/src/app/lifecycle.rs | 1 + crates/runtime/src/app/mod.rs | 18 +- crates/runtime/src/app/options.rs | 5 +- crates/runtime/src/app/orchestrate.rs | 59 +- crates/runtime/src/app/sessions.rs | 82 +- crates/runtime/src/app/store_write.rs | 121 ++- crates/runtime/src/app/test_support.rs | 13 + crates/runtime/src/app/tests.rs | 696 ++++++++++++++-- crates/runtime/src/pipe.rs | 12 +- crates/runtime/src/pipe_p4b_tests.rs | 11 +- .../runtime/src/terminal_replication_tests.rs | 3 + crates/services/src/export.rs | 156 ++-- crates/services/src/store.rs | 101 ++- crates/services/src/store/compaction.rs | 470 +++++++++++ crates/ui/src/chat/model.rs | 50 +- crates/ui/src/shell.rs | 35 +- crates/ui/src/store/history.rs | 14 + crates/ui/src/store/intents.rs | 20 +- crates/ui/src/store/mod.rs | 781 ++++++++++++++---- crates/ui/src/store/terminal.rs | 3 + 33 files changed, 3323 insertions(+), 514 deletions(-) create mode 100644 crates/core/src/session/compaction.rs create mode 100644 crates/runtime/src/app/compaction.rs create mode 100644 crates/services/src/store/compaction.rs diff --git a/crates/app/src/main.rs b/crates/app/src/main.rs index 83dcd71b8..d0c101ee0 100644 --- a/crates/app/src/main.rs +++ b/crates/app/src/main.rs @@ -187,6 +187,7 @@ fn start_local(store: SessionStore) -> (SpawnedHost, HostMux) { let mut host_services = HostServices { background_startup_probes: true, ai_title_generation: true, + compact_existing_logs: true, ..HostServices::default() }; match mcp_host::Host::bind() { @@ -250,6 +251,7 @@ impl LocalKernel { if let Err(error) = self.control_link.subscribe(tcode_protocol::Subscription { topic: topic.clone(), after: None, + epoch: None, }) { log::error!("could not request local settings: {}", error.message); return settings::Settings::default(); @@ -271,9 +273,11 @@ impl LocalKernel { Err(_) => break settings::Settings::default(), } }; - let _ = self - .control_link - .unsubscribe(tcode_protocol::Subscription { topic, after: None }); + let _ = self.control_link.unsubscribe(tcode_protocol::Subscription { + topic, + after: None, + epoch: None, + }); result } } diff --git a/crates/client/src/lib.rs b/crates/client/src/lib.rs index 867f1356c..5f3dce858 100644 --- a/crates/client/src/lib.rs +++ b/crates/client/src/lib.rs @@ -703,18 +703,20 @@ impl HostLink { self.send_payload(self.next_id(), ClientPayload::Unsubscribe(subscription)) } - /// Advance replay memory only after the store has applied these records. Sending - /// the latest subscription also updates native/browser transport replay caches. - /// The host returns an empty tail when the store is already up to date. - pub fn update_after(&self, topic: &Topic, after: u64) -> Result<(), ProtocolError> { + /// Advance replay memory to position `after` of layout `epoch` only after + /// the store has applied these records. Sending the latest subscription also + /// updates native/browser transport replay caches. The host returns an empty + /// tail when the store is already up to date. + pub fn update_after(&self, topic: &Topic, epoch: u64, after: u64) -> Result<(), ProtocolError> { let subscription = { let mut topics = self.inner.subscribed_topics.lock().unwrap(); let Some(subscription) = topics.get_mut(topic) else { return Ok(()); }; - if subscription.after == Some(after) { + if (subscription.epoch, subscription.after) == (Some(epoch), Some(after)) { return Ok(()); } + subscription.epoch = Some(epoch); subscription.after = Some(after); subscription.clone() }; @@ -804,6 +806,7 @@ impl HostLink { ClientPayload::Unsubscribe(Subscription { topic: topic.clone(), after: None, + epoch: None, }), ); } @@ -1305,6 +1308,7 @@ mod tests { session_id: "one".into(), }, after: None, + epoch: None, }; link.subscribe(subscription.clone()).unwrap(); outgoing.try_recv().unwrap(); @@ -1328,14 +1332,15 @@ mod tests { let reply = EventEnvelope { request_id: Some(request.id), topic: subscription.topic, - event: ServerEvent::SessionSnapshot { + event: ServerEvent::SessionSnapshot(tcode_protocol::SessionWindow { + epoch: 0, total: 0, total_turns: 0, truncated: false, from: 0, end: 0, records: vec![], - }, + }), }; assert!(link.subscription_reply_is_current(&reply)); } @@ -1385,14 +1390,19 @@ mod tests { link.subscribe(Subscription { topic: topic.clone(), after: None, + epoch: None, }) .unwrap(); outgoing.try_recv().unwrap(); - link.update_after(&topic, 7).unwrap(); + link.update_after(&topic, 2, 7).unwrap(); let updated = tcode_protocol::decode_client_line(&outgoing.try_recv().unwrap()).unwrap(); assert!(matches!( updated.payload, - ClientPayload::Subscribe(Subscription { after: Some(7), .. }) + ClientPayload::Subscribe(Subscription { + after: Some(7), + epoch: Some(2), + .. + }) )); link.set_connection_state(ConnectionState::Reconnecting { attempt: 1, @@ -1404,18 +1414,23 @@ mod tests { let queued_reply = EventEnvelope { request_id: Some(replay.id), topic: topic.clone(), - event: ServerEvent::SessionSnapshot { + event: ServerEvent::SessionSnapshot(tcode_protocol::SessionWindow { + epoch: 0, total: 0, total_turns: 0, truncated: false, from: 0, end: 0, records: vec![], - }, + }), }; assert!(link.subscription_reply_is_current(&queued_reply)); - link.unsubscribe(Subscription { topic, after: None }) - .unwrap(); + link.unsubscribe(Subscription { + topic, + after: None, + epoch: None, + }) + .unwrap(); assert!(!link.subscription_reply_is_current(&queued_reply)); assert!(link.inner.subscription_requests.lock().unwrap().is_empty()); outgoing.try_recv().unwrap(); @@ -1487,11 +1502,13 @@ mod tests { link.subscribe(Subscription { after: None, + epoch: None, topic: Topic::Index, }) .unwrap(); link.subscribe(Subscription { after: None, + epoch: None, topic: Topic::Index, }) .unwrap(); diff --git a/crates/core/src/session.rs b/crates/core/src/session.rs index bbd2b62c8..a231626a2 100644 --- a/crates/core/src/session.rs +++ b/crates/core/src/session.rs @@ -15,6 +15,10 @@ use serde::{Deserialize, Serialize}; use crate::git::merge_file_changes_by_path; +mod compaction; + +pub use compaction::{CompactedRecord, compact_records}; + /// Claude Code's own prompt for resuming work after a usage-window reset. pub const RESUME_PROMPT: &str = "Continue from where you left off."; @@ -169,7 +173,7 @@ impl From for StoredEvent { } /// One renderable row in the chat timeline. -#[derive(Debug, Clone)] +#[derive(Debug, Clone, PartialEq)] pub struct TimelineEntry { /// Provider item id (or a synthetic id for errors). pub id: String, @@ -181,7 +185,7 @@ pub struct TimelineEntry { } /// Per-turn ("Work Log" section) metadata folded from turn lifecycle events. -#[derive(Debug, Clone, Default)] +#[derive(Debug, Clone, Default, PartialEq)] pub struct TurnMeta { /// Provider-native id for this turn, used to attach replacement turn-diff /// snapshots without relying on ambient "current turn" state during replay. @@ -243,7 +247,7 @@ impl TurnTiming { /// turn, intersected with the turn's own `TurnStarted`..`TurnCompleted` bounds. /// Only the current turn can have items in flight, so one accumulator is /// enough; it resets whenever a turn opens. -#[derive(Debug, Clone, Default)] +#[derive(Debug, Clone, Default, PartialEq)] struct ToolClock { /// Item ids currently known to be in progress. open: HashSet, @@ -408,13 +412,13 @@ fn tool_is_active(lifecycle: ToolLifecycle, state: ToolState) -> bool { } } -#[derive(Debug, Clone)] +#[derive(Debug, Clone, PartialEq)] pub struct TurnChangeSet { pub changes: Vec, pub completeness: ChangeCompleteness, } -#[derive(Debug, Clone)] +#[derive(Debug, Clone, PartialEq)] pub enum EntryContent { Item(ItemContent), /// A user message injected into an already-open turn. Provider-originated @@ -472,7 +476,7 @@ pub enum SteeringStatus { /// A proposed plan captured this session (Codex plan item / Claude /// `ExitPlanMode`). Streaming deltas accumulate into `markdown`; a `ProposedPlan` /// event replaces it with the final text. -#[derive(Debug, Clone, Default)] +#[derive(Debug, Clone, Default, PartialEq)] pub struct ProposedPlan { pub item_id: String, pub markdown: String, @@ -502,8 +506,10 @@ pub struct RunningTurn { pub started_at: Option, } -/// Folded view of a session's event history. -#[derive(Debug, Clone, Default)] +/// Folded view of a session's event history. Two timelines are equal only +/// when every later event folds the same onto both, so equality covers the +/// private state the fold continues from, not just what renders. +#[derive(Debug, Clone, Default, PartialEq)] pub struct Timeline { /// Top-level entries are shared so virtualized UI snapshots can retain a /// turn without cloning its potentially large message, command-output, and @@ -646,12 +652,7 @@ impl Timeline { /// Apply one event recorded at `ts` (unix ms). Mutates in place. pub fn apply_at(&mut self, ts: Option, event: &AgentEvent) { - // Every timestamped event inside the open turn raises the turn's - // watermark, not just tool lifecycle ones: a completion stamped before - // any of them means the wall clock regressed, and the breakdown is - // withheld rather than guessed at. The completion itself is excluded — - // it is what gets compared against the watermark. - if self.turn_is_open() && !matches!(event, AgentEvent::TurnCompleted { .. }) { + if self.watermarks(event) { self.tool_clock.observe(ts); } match event { @@ -754,10 +755,7 @@ impl Timeline { completeness, } => { let turn = self - .turns - .iter() - .position(|turn| turn.provider_turn_id.as_deref() == Some(turn_id.as_str())) - .or(self.current_turn) + .provider_turn(turn_id) .unwrap_or_else(|| self.push_turn(ts)); if !turn_id.is_empty() { self.turns[turn].provider_turn_id = Some(turn_id.clone()); @@ -772,10 +770,7 @@ impl Timeline { checkpoint_id, } => { let turn = self - .turns - .iter() - .position(|turn| turn.provider_turn_id.as_deref() == Some(turn_id.as_str())) - .or(self.current_turn) + .provider_turn(turn_id) .unwrap_or_else(|| self.push_turn(ts)); self.turns[turn].provider_turn_id = Some(turn_id.clone()); self.turns[turn].provider_checkpoint_id = Some(checkpoint_id.clone()); @@ -1069,6 +1064,25 @@ impl Timeline { } } + /// Whether `event`'s time raises the open turn's clock watermark. Every + /// timestamped event inside the open turn does, not just tool lifecycle + /// ones: a completion stamped before any of them means the wall clock + /// regressed, and the breakdown is withheld rather than guessed at. The + /// completion itself is excluded — it is what gets compared against the + /// watermark. + fn watermarks(&self, event: &AgentEvent) -> bool { + self.turn_is_open() && !matches!(event, AgentEvent::TurnCompleted { .. }) + } + + /// The turn a provider-addressed record lands on: the first turn carrying + /// `turn_id`, else the current one. `None` means the record opens a turn. + fn provider_turn(&self, turn_id: &str) -> Option { + self.turns + .iter() + .position(|turn| turn.provider_turn_id.as_deref() == Some(turn_id)) + .or(self.current_turn) + } + /// Whether the current turn is still accumulating. A turn is finished once /// a `TurnCompleted` has been folded, which records a status even when the /// event carried no timestamp to store as `end_ts`; both must be checked or diff --git a/crates/core/src/session/compaction.rs b/crates/core/src/session/compaction.rs new file mode 100644 index 000000000..14d328e4d --- /dev/null +++ b/crates/core/src/session/compaction.rs @@ -0,0 +1,522 @@ +use std::collections::HashSet; + +use agent::AgentEvent; + +use super::{StoredEvent, Timeline}; + +/// One record of a compacted event log, in log order. +#[derive(Debug, Clone, PartialEq)] +pub enum CompactedRecord { + /// The original record at this index, unchanged. + Kept(usize), + /// Adjacent deltas of one item merged into the first of them: its time, + /// all of their text. + Merged(Box), +} + +/// What folding one record did that compaction has to account for. +#[derive(Debug, Clone, Copy, Default)] +struct Note { + /// It moved the open turn's clock watermark; a record compaction may + /// leave out only ever raises it. + raises: bool, + /// It lifts any lower watermark to the one the whole log had reached + /// before it, before anything reads the clock: the fold watermarks it, and + /// its time is no earlier than that watermark. + repairs: bool, + /// A turn-changes snapshot that a later snapshot replaces on the same + /// turn lifetime, and whose fold does nothing else: it lands on an + /// existing turn without renaming it. + superseded: bool, +} + +/// A record of the compacted log: an original record plus the deltas merged +/// into it. +struct Out { + index: usize, + merged: Vec, + text_len: usize, +} + +impl Out { + fn new(records: &[StoredEvent], index: usize) -> Self { + Self { + index, + merged: Vec::new(), + text_len: delta_text(&records[index]).len(), + } + } +} + +/// Compact a whole event log so that it folds exactly as `records` do, +/// including the state later records continue from: +/// +/// * a turn-changes snapshot goes when a later snapshot lands on the same turn +/// lifetime (a rewind ends a lifetime even when the turn's index is reused), +/// since each snapshot replaces the turn's changes wholesale, unless it is +/// the snapshot that opened or renamed that turn; +/// * deltas of one item and kind merge into the first of them, up to +/// `max_merged_text` bytes of text per record, when nothing but dropped +/// snapshots stands between them, so compacting a compacted log changes +/// nothing. +/// +/// Every timestamped record of an open turn raises its clock watermark, so a +/// record compaction removes may leave the compacted fold's watermark behind. +/// That is accepted only when the next record kept lifts both folds to the same +/// watermark before the clock is read; otherwise the removed records stay. +/// +/// A result as long as `records` means nothing compacts. +pub fn compact_records(records: &[StoredEvent], max_merged_text: usize) -> Vec { + let notes = notes(records); + let mut out: Vec = Vec::with_capacity(records.len()); + // Records left out since the last record kept, and whether both folds' + // watermarks still agree. + let mut pending: Vec = Vec::new(); + let mut in_sync = true; + for (index, record) in records.iter().enumerate() { + let note = notes[index]; + if merges(records, &out, index, max_merged_text) { + let run = out.last_mut().expect("a merge continues a kept record"); + run.merged.push(index); + run.text_len += delta_text(record).len(); + } else if !note.superseded { + if !in_sync && !note.repairs { + restore(records, &mut out, &pending, ¬es); + } + pending.clear(); + in_sync = true; + out.push(Out::new(records, index)); + continue; + } + pending.push(index); + in_sync &= !note.raises; + } + if !in_sync { + restore(records, &mut out, &pending, ¬es); + } + out.into_iter() + .map(|out| { + if out.merged.is_empty() { + return CompactedRecord::Kept(out.index); + } + let mut head = records[out.index].clone(); + if let AgentEvent::Delta { text, .. } = &mut head.event { + for &index in &out.merged { + text.push_str(delta_text(&records[index])); + } + } + CompactedRecord::Merged(Box::new(head)) + }) + .collect() +} + +/// Fold `records` once, noting for each what compaction needs from the fold's +/// own decisions: which turn a snapshot lands on and how the clock moves. +fn notes(records: &[StoredEvent]) -> Vec { + let mut fold = Timeline::default(); + let mut notes = vec![Note::default(); records.len()]; + // A serial per turn the fold holds, so a turn index reused after a rewind + // is a different lifetime. + let mut lifetimes: Vec = Vec::new(); + let mut next_lifetime = 0; + // (record, lifetime, removable) for every turn-changes snapshot. + let mut snapshots: Vec<(usize, u64, bool)> = Vec::new(); + for (index, record) in records.iter().enumerate() { + let watermark = fold.tool_clock.clock; + let target = match &record.event { + AgentEvent::TurnChangesUpdated { turn_id, .. } => { + let turn = fold.provider_turn(turn_id); + let removable = turn.is_some_and(|turn| { + turn_id.is_empty() + || fold.turns[turn].provider_turn_id.as_deref() == Some(turn_id) + }); + Some((turn, removable)) + } + _ => None, + }; + notes[index].repairs = fold.watermarks(&record.event) + && record + .ts + .is_some_and(|ts| watermark.is_none_or(|watermark| ts >= watermark)); + fold.apply_stored(record); + notes[index].raises = fold.tool_clock.clock != watermark; + lifetimes.truncate(fold.turns.len()); + while lifetimes.len() < fold.turns.len() { + lifetimes.push(next_lifetime); + next_lifetime += 1; + } + if let Some((turn, removable)) = target { + let turn = turn.unwrap_or(fold.turns.len() - 1); + snapshots.push((index, lifetimes[turn], removable)); + } + } + let mut replaced = HashSet::new(); + for &(index, lifetime, removable) in snapshots.iter().rev() { + notes[index].superseded = !replaced.insert(lifetime) && removable; + } + notes +} + +/// Whether record `index` is a delta continuing the run the last kept record +/// opened: that record is a delta of the same item and kind, and the merged +/// text stays within `max_merged_text`. Every record since the last kept one +/// was merged into it or dropped, so nothing the fold reads stands between. +fn merges(records: &[StoredEvent], out: &[Out], index: usize, max_merged_text: usize) -> bool { + let Some(run) = out.last() else { + return false; + }; + let ( + AgentEvent::Delta { + item_id, + kind, + text, + .. + }, + AgentEvent::Delta { + item_id: run_item, + kind: run_kind, + .. + }, + ) = (&records[index].event, &records[run.index].event) + else { + return false; + }; + item_id == run_item && kind == run_kind && run.text_len + text.len() <= max_merged_text +} + +/// Keep records left out since the last kept one, because the record after +/// them cannot lift the compacted fold's watermark: the last of them, when it +/// can lift the watermark itself, or else all of them. The deltas among them +/// are the whole tail of the last kept record's run. +fn restore(records: &[StoredEvent], out: &mut Vec, pending: &[usize], notes: &[Note]) { + let Some(&last) = pending.last() else { + return; + }; + let run = out + .last_mut() + .expect("records are left out after a kept one"); + let restored = if notes[last].repairs { + if run.merged.pop_if(|merged| *merged == last).is_some() { + run.text_len -= delta_text(&records[last]).len(); + } + &pending[pending.len() - 1..] + } else { + run.merged.clear(); + run.text_len = delta_text(&records[run.index]).len(); + pending + }; + out.extend(restored.iter().map(|&index| Out::new(records, index))); +} + +fn delta_text(record: &StoredEvent) -> &str { + match &record.event { + AgentEvent::Delta { text, .. } => text, + _ => "", + } +} + +#[cfg(test)] +mod tests { + use agent::{ + ChangeCompleteness, DeltaKind, FileChange, FileChangeKind, ItemContent, RewindMode, + ThreadItem, TurnStatus, + }; + + use super::*; + use crate::session::TurnTiming; + + fn at(ts: u64, event: AgentEvent) -> StoredEvent { + StoredEvent { + ts: Some(ts), + event, + elided: None, + } + } + + fn started(turn: &str) -> AgentEvent { + AgentEvent::TurnStarted { + turn_id: turn.into(), + } + } + + fn completed(turn: &str) -> AgentEvent { + AgentEvent::TurnCompleted { + turn_id: turn.into(), + status: TurnStatus::Completed, + usage: None, + } + } + + fn checkpoint(turn: &str, checkpoint: &str) -> AgentEvent { + AgentEvent::TurnCheckpoint { + turn_id: turn.into(), + checkpoint_id: checkpoint.into(), + } + } + + fn rewind(checkpoint: &str) -> AgentEvent { + AgentEvent::RewindCompleted { + checkpoint_id: checkpoint.into(), + mode: RewindMode::Conversation, + prefill: None, + } + } + + /// A snapshot of the turn's net changes: one file whose diff is `diff`. + fn changes(turn: &str, diff: &str) -> AgentEvent { + AgentEvent::TurnChangesUpdated { + turn_id: turn.into(), + changes: vec![FileChange { + path: "f".into(), + kind: FileChangeKind::Modify, + diff: Some(diff.into()), + }], + completeness: ChangeCompleteness::Exact, + } + } + + /// Streamed text of the assistant message `m`. + fn delta(text: &str) -> AgentEvent { + AgentEvent::Delta { + item_id: "m".into(), + kind: DeltaKind::AssistantText, + text: text.into(), + } + } + + fn message(id: &str, text: &str) -> AgentEvent { + AgentEvent::ItemCompleted(ThreadItem { + id: id.into(), + parent_item_id: None, + content: ItemContent::AssistantMessage { text: text.into() }, + }) + } + + fn user(id: &str) -> AgentEvent { + AgentEvent::ItemCompleted(ThreadItem { + id: id.into(), + parent_item_id: None, + content: ItemContent::UserMessage { + text: id.into(), + context_len: None, + attachments: Vec::new(), + }, + }) + } + + fn keep(log: &[StoredEvent], indices: &[usize]) -> Vec { + indices.iter().map(|index| log[*index].clone()).collect() + } + + #[test] + fn compaction_drops_and_merges_only_what_the_fold_lets_go() { + let reused_id = vec![ + at(1, started("x")), + at(2, changes("x", "a")), + at(3, message("m1", "one")), + at(4, completed("x")), + at(5, started("x")), + // Lands on the first turn named x, replacing record 1 there. + at(6, changes("x", "b")), + // Names no turn, so lands on the current one; replaced by record 8. + at(7, changes("", "c")), + at(8, message("m2", "two")), + at(9, changes("", "d")), + at(10, message("m3", "three")), + at(11, completed("x")), + ]; + let opens_turn = vec![ + at(1, changes("x", "a")), + at(2, message("m1", "one")), + at(3, changes("x", "b")), + at(4, message("m2", "two")), + ]; + let names_turn = vec![ + at(1, started("t")), + // No turn is named x yet: lands on the current turn and names it. + at(2, changes("x", "a")), + at(3, message("m1", "one")), + at(4, completed("t")), + at(5, started("u")), + // Finds the first turn by the name record 1 gave it. + at(6, changes("x", "b")), + at(7, message("m2", "two")), + at(8, completed("u")), + ]; + let rewound = vec![ + at(1, user("u1")), + at(2, started("t1")), + at(3, checkpoint("t1", "c1")), + at(4, completed("t1")), + at(5, user("u2")), + at(6, started("t2")), + at(7, checkpoint("t2", "c2")), + at(8, changes("t2", "a")), + at(9, message("m1", "one")), + at(10, completed("t2")), + // Drops the second turn; the next user message reopens index 1. + at(11, rewind("c2")), + at(12, user("u3")), + at(13, started("t3")), + at(14, changes("t3", "b")), + at(15, message("m2", "two")), + at(16, changes("t3", "c")), + at(17, message("m3", "three")), + at(18, completed("t3")), + ]; + let empty_completion = vec![ + at(1, started("t")), + at(2, delta("Hel")), + at(3, delta("lo")), + at(4, message("m", "")), + at(5, completed("t")), + ]; + let separated = vec![ + at(1, started("t")), + at(2, delta("a")), + at(3, changes("t", "x")), + at(4, delta("b")), + at(5, changes("t", "y")), + at(6, message("m", "ab")), + at(7, completed("t")), + ]; + let late_changes = vec![ + at(1, started("t")), + at(2, changes("t", "a")), + at(3, message("m", "done")), + at(4, completed("t")), + at(5, changes("t", "b")), + ]; + let open_tail = vec![at(10, started("t")), at(20, delta("a")), at(40, delta("b"))]; + let longer_open_tail = vec![ + at(10, started("t")), + at(20, delta("a")), + at(30, delta("b")), + at(40, delta("c")), + ]; + let over_bound = vec![ + at(1, started("t")), + at(2, delta("aaaa")), + at(3, delta("bbbb")), + at(4, delta("cccc")), + at(5, delta("dd")), + at(6, message("m", "aaaabbbbccccdd")), + ]; + let cases = [ + ( + "a reused turn id lands on its first turn", + keep(&reused_id, &[0, 2, 3, 4, 5, 7, 8, 9, 10]), + reused_id, + ), + ( + "a snapshot that opens its turn stays", + opens_turn.clone(), + opens_turn, + ), + ( + "a snapshot that names its turn stays", + names_turn.clone(), + names_turn, + ), + ( + "a rewind ends a turn's lifetime though its index is reused", + keep( + &rewound, + &[0, 1, 2, 3, 4, 5, 6, 7, 8, 9, 10, 11, 12, 14, 15, 16, 17], + ), + rewound, + ), + ( + "deltas a completion without text relies on are merged, not dropped", + vec![ + empty_completion[0].clone(), + at(2, delta("Hello")), + empty_completion[3].clone(), + empty_completion[4].clone(), + ], + empty_completion, + ), + ( + "deltas a dropped snapshot separated merge", + vec![ + separated[0].clone(), + at(2, delta("ab")), + separated[4].clone(), + separated[5].clone(), + separated[6].clone(), + ], + separated, + ), + ( + "a snapshot after its turn completed replaces the earlier one", + keep(&late_changes, &[0, 2, 3, 4]), + late_changes, + ), + ( + "the last delta of an open turn alone holds its clock", + open_tail.clone(), + open_tail, + ), + ( + "an open turn's earlier deltas still merge", + vec![ + longer_open_tail[0].clone(), + at(20, delta("ab")), + longer_open_tail[3].clone(), + ], + longer_open_tail, + ), + ( + "a run longer than the bound splits", + vec![ + over_bound[0].clone(), + at(2, delta("aaaabbbb")), + at(4, delta("ccccdd")), + over_bound[5].clone(), + ], + over_bound, + ), + ]; + for (label, expected, log) in cases { + let compacted: Vec = compact_records(&log, 8) + .into_iter() + .map(|record| match record { + CompactedRecord::Kept(index) => log[index].clone(), + CompactedRecord::Merged(record) => *record, + }) + .collect(); + assert_eq!(compacted, expected, "{label}"); + assert_eq!( + Timeline::fold_stored(&compacted), + Timeline::fold_stored(&log), + "{label}" + ); + assert_eq!( + compact_records(&compacted, 8).len(), + compacted.len(), + "{label}: a compacted log compacts no further" + ); + } + } + + /// Folds are equal only when every later record folds the same onto + /// both, so the open turn's clock counts though nothing renders it. + #[test] + fn equal_folds_include_the_open_turns_clock() { + let log = [at(10, started("t")), at(20, delta("a")), at(40, delta("b"))]; + let merged = [at(10, started("t")), at(20, delta("ab"))]; + let (log, merged) = (Timeline::fold_stored(&log), Timeline::fold_stored(&merged)); + assert_eq!(log.entries, merged.entries); + assert_eq!(log.turns, merged.turns); + assert_ne!(log, merged); + + let finish = |mut fold: Timeline| { + fold.apply_at(Some(30), &completed("t")); + fold.turns[0].timing + }; + // A completion stamped before work the turn already recorded has no + // trustworthy breakdown. + assert_eq!(finish(log), None); + assert_eq!(finish(merged), Some(TurnTiming::new(20, 0))); + } +} diff --git a/crates/headless/src/main.rs b/crates/headless/src/main.rs index ed2492e32..bba37d97e 100644 --- a/crates/headless/src/main.rs +++ b/crates/headless/src/main.rs @@ -118,6 +118,7 @@ fn serve_command(args: &[String]) -> Result<(), String> { let mut services = HostServices { background_startup_probes: true, ai_title_generation: true, + compact_existing_logs: true, ..HostServices::default() }; if let Ok(mut mcp_host) = mcp_host::Host::bind() { diff --git a/crates/protocol/src/event.rs b/crates/protocol/src/event.rs index 80fb782a6..201f7d50f 100644 --- a/crates/protocol/src/event.rs +++ b/crates/protocol/src/event.rs @@ -35,6 +35,28 @@ pub enum Topic { ExternalImport { project_id: String }, } +/// Records standing for the log cursors `from..end` of the log's layout +/// `epoch`. The host may merge or drop records whose effect a later record in +/// the log repeats, so `records` can be shorter than the range. +/// +/// A cursor is a position in one layout: rewriting a log renumbers its +/// records under a new epoch, and a position is meaningless in any other. +#[derive(Debug, Clone, PartialEq, Serialize, Deserialize)] +pub struct SessionWindow { + pub epoch: u64, + pub from: u64, + pub end: u64, + pub records: Vec, + #[serde(default)] + pub total: u64, + /// Absolute turn count keeps turn-addressed actions correct in a window. + #[serde(default)] + pub total_turns: u64, + /// The byte budget reduced this reply below the requested record count. + #[serde(default)] + pub truncated: bool, +} + #[derive(Debug, Clone, PartialEq, Serialize, Deserialize)] pub struct EventEnvelope { /// Present only on subscription replies; mux routes these to their requester. @@ -62,7 +84,12 @@ pub enum ServerEvent { session_id: String, request: crate::PreviewRequest, }, - SessionEvent(StoredEvent), + /// The record appended at `position` of the log's layout `epoch`. + SessionEvent { + epoch: u64, + position: u64, + record: StoredEvent, + }, SessionStatusReplaced(SessionStatus), ProvidersReplaced(ProvidersStatus), GitStatusReplaced(GitStatusStatus), @@ -112,22 +139,10 @@ pub enum ServerEvent { /// the reviewer judged the flag not a false positive. draft: String, }, - /// Records standing for the log cursors `from..end`. The host may merge - /// or drop records whose effect a later record in the log repeats, so - /// `records` can be shorter than the range. - SessionSnapshot { - from: u64, - end: u64, - records: Vec, - #[serde(default)] - total: u64, - /// Absolute turn count keeps turn-addressed actions correct in a window. - #[serde(default)] - total_turns: u64, - /// The byte budget reduced this reply below the requested record count. - #[serde(default)] - truncated: bool, - }, + /// The reply to a subscription: records continuing the cursor it named, + /// or a baseline that replaces every record the client holds when the + /// cursor is not in the layout the host serves. + SessionSnapshot(SessionWindow), SessionHistoryError(crate::ProtocolError), IndexSnapshot(IndexSnapshot), SettingsSnapshot(Settings), diff --git a/crates/protocol/src/lib.rs b/crates/protocol/src/lib.rs index f0d5f0025..a948de105 100644 --- a/crates/protocol/src/lib.rs +++ b/crates/protocol/src/lib.rs @@ -18,7 +18,7 @@ pub use event::{ GitStatusStatus, IndexSnapshot, IndexSummary, MergeWorktreeFailure, NoticeSeverity, ProviderVersionStatus, ProvidersStatus, QueuedMessageStatus, RuntimeEffect, RuntimeError, RuntimeNotice, RuntimeNotification, RuntimeOperationId, RuntimeToast, ServerEvent, - SessionEventRecord, SessionStatus, TcodeUpdateStatus, TerminalContextStatus, + SessionEventRecord, SessionStatus, SessionWindow, TcodeUpdateStatus, TerminalContextStatus, TerminalSplitStatus, TerminalStatus, Topic, }; pub use query::{ @@ -41,8 +41,10 @@ pub use wire::{ // the requests it waits on in the session status; version 8 adds the Cursor // and Grok provider kinds, which an older peer cannot decode because // `ProviderKind` has no unknown fallback; version 9 replaces the single-thread -// archive, unarchive and delete commands with batched ones. -pub const PROTOCOL_VERSION: u32 = 9; +// archive, unarchive and delete commands with batched ones; version 10 places +// every session log cursor in a layout epoch, since a compacted log renumbers +// its records. +pub const PROTOCOL_VERSION: u32 = 10; #[cfg(test)] mod tests; diff --git a/crates/protocol/src/query.rs b/crates/protocol/src/query.rs index 0de9a50f1..6f8732535 100644 --- a/crates/protocol/src/query.rs +++ b/crates/protocol/src/query.rs @@ -14,9 +14,12 @@ pub enum Query { /// Read the agent host's system grants without requesting access. ComputerUsePermissions, Ping, - /// Records strictly before the absolute event cursor, oldest first. + /// Records strictly before the cursor `before` of layout `epoch`, oldest + /// first. A cursor in another layout than the host serves is answered + /// with [`QueryResponse::SessionHistoryReset`]. SessionHistoryPage { session_id: String, + epoch: u64, before: u64, limit: u32, }, @@ -110,14 +113,18 @@ pub enum QueryResponse { Hosting(HostingState), ComputerUsePermissions(tcode_core::permissions::ComputerUsePermissions), Pong, - /// Records standing for the log cursors `from..end`, with the same - /// merging as [`crate::ServerEvent::SessionSnapshot`]. + /// Records standing for the log cursors `from..end` of layout `epoch`, + /// with the same merging as [`crate::SessionWindow`]. SessionHistoryPage { + epoch: u64, records: Vec, from: u64, end: u64, truncated: bool, }, + /// A baseline replacing every record the client holds: the page asked + /// for a layout the host no longer serves. + SessionHistoryReset(crate::SessionWindow), ActiveWorkspace(Vec), IconImages { directory: PathBuf, diff --git a/crates/protocol/src/tests.rs b/crates/protocol/src/tests.rs index d93e37552..d7afe2473 100644 --- a/crates/protocol/src/tests.rs +++ b/crates/protocol/src/tests.rs @@ -100,19 +100,27 @@ fn event_envelopes_keep_stored_record_shape_and_optional_request_id() { topic: Topic::SessionEvents { session_id: "session-1".into(), }, - event: ServerEvent::SessionEvent(SessionEventRecord { - ts: Some(123), - event: AgentEvent::TurnStarted { - turn_id: "turn-1".into(), + event: ServerEvent::SessionEvent { + epoch: 2, + position: 40, + record: SessionEventRecord { + ts: Some(123), + event: AgentEvent::TurnStarted { + turn_id: "turn-1".into(), + }, + elided: None, }, - elided: None, - }), + }, }; let expected = json!({ "topic": {"type": "session_events", "content": {"session_id": "session-1"}}, "event": { "type": "session_event", - "content": {"ts": 123, "event": {"type": "turn_started", "turn_id": "turn-1"}}, + "content": { + "epoch": 2, + "position": 40, + "record": {"ts": 123, "event": {"type": "turn_started", "turn_id": "turn-1"}}, + }, }, }); assert_eq!(serde_json::to_value(&envelope).unwrap(), expected); @@ -171,7 +179,8 @@ fn older_messages_default_new_optional_fields() { subscription, Subscription { topic: Topic::Index, - after: None + after: None, + epoch: None, } ); let index: IndexSnapshot = @@ -812,16 +821,18 @@ fn thread_export_and_project_creation_use_their_documented_wire_shapes() { #[test] fn history_paging_literal_json_contract() { - let query = r#"{"type":"session_history_page","content":{"session_id":"thread","before":1800,"limit":200}}"#; + let query = r#"{"type":"session_history_page","content":{"session_id":"thread","epoch":3,"before":1800,"limit":200}}"#; assert_eq!( serde_json::from_str::(query).unwrap(), Query::SessionHistoryPage { session_id: "thread".into(), + epoch: 3, before: 1800, limit: 200 } ); let response = QueryResponse::SessionHistoryPage { + epoch: 3, records: vec![], from: 1600, end: 1800, @@ -829,32 +840,64 @@ fn history_paging_literal_json_contract() { }; assert_eq!( serde_json::to_string(&response).unwrap(), - r#"{"type":"session_history_page","content":{"records":[],"from":1600,"end":1800,"truncated":true}}"# + r#"{"type":"session_history_page","content":{"epoch":3,"records":[],"from":1600,"end":1800,"truncated":true}}"# ); - let snapshot = ServerEvent::SessionSnapshot { - from: 1800, - end: 2000, + let window = SessionWindow { + epoch: 4, + from: 1200, + end: 1400, records: vec![], - total: 2000, + total: 1400, total_turns: 0, truncated: false, }; assert_eq!( - serde_json::to_string(&snapshot).unwrap(), - r#"{"type":"session_snapshot","content":{"from":1800,"end":2000,"records":[],"total":2000,"total_turns":0,"truncated":false}}"# + serde_json::to_string(&QueryResponse::SessionHistoryReset(window.clone())).unwrap(), + r#"{"type":"session_history_reset","content":{"epoch":4,"from":1200,"end":1400,"records":[],"total":1400,"total_turns":0,"truncated":false}}"# + ); + assert_eq!( + serde_json::to_string(&ServerEvent::SessionSnapshot(window)).unwrap(), + r#"{"type":"session_snapshot","content":{"epoch":4,"from":1200,"end":1400,"records":[],"total":1400,"total_turns":0,"truncated":false}}"# ); assert!(matches!( serde_json::from_str::( - r#"{"type":"session_snapshot","content":{"from":0,"end":0,"records":[]}}"# + r#"{"type":"session_snapshot","content":{"epoch":0,"from":0,"end":0,"records":[]}}"# ) .unwrap(), - ServerEvent::SessionSnapshot { + ServerEvent::SessionSnapshot(SessionWindow { total: 0, total_turns: 0, truncated: false, .. - } + }) )); + assert!( + serde_json::from_str::( + r#"{"type":"session_snapshot","content":{"from":0,"end":0,"records":[]}}"# + ) + .is_err(), + "a window names the layout its cursors are in" + ); + let resume = r#"{"topic":{"type":"session_events","content":{"session_id":"thread"}},"after":1400,"epoch":4}"#; + let subscription = Subscription { + topic: Topic::SessionEvents { + session_id: "thread".into(), + }, + after: Some(1400), + epoch: Some(4), + }; + assert_eq!(serde_json::to_string(&subscription).unwrap(), resume); + assert_eq!( + serde_json::from_str::( + r#"{"topic":{"type":"session_events","content":{"session_id":"thread"}},"after":1400}"# + ) + .unwrap(), + Subscription { + epoch: None, + ..subscription + }, + "a position without its layout decodes as no resumable cursor" + ); } #[test] diff --git a/crates/protocol/src/wire.rs b/crates/protocol/src/wire.rs index d2d06df44..3e222fb70 100644 --- a/crates/protocol/src/wire.rs +++ b/crates/protocol/src/wire.rs @@ -59,8 +59,14 @@ pub enum HostMessage { #[derive(Debug, Clone, PartialEq, Eq, Serialize, Deserialize)] pub struct Subscription { pub topic: Topic, + /// For [`Topic::SessionEvents`], the log position the client holds + /// records up to, in layout `epoch`. The host continues from it only when + /// `epoch` is the layout it serves; otherwise, and without an epoch, it + /// sends a baseline. #[serde(default)] pub after: Option, + #[serde(default, skip_serializing_if = "Option::is_none")] + pub epoch: Option, } /// Encode one NDJSON record, including its trailing newline. diff --git a/crates/runtime/src/app/compaction.rs b/crates/runtime/src/app/compaction.rs new file mode 100644 index 000000000..1e9368885 --- /dev/null +++ b/crates/runtime/src/app/compaction.rs @@ -0,0 +1,197 @@ +use std::collections::VecDeque; +use std::sync::atomic::{AtomicBool, Ordering}; + +use tcode_services::store::{CompactOutcome, CompactRejection, MalformedLine}; + +use super::*; + +/// One log compaction queued in the store writer, which runs it in the +/// writer's order: every append queued before it is in the log it reads, and +/// none queued after it can land between its read and its rename. +pub(super) struct CompactionRequest { + /// Set when the request became moot before the writer reached it: a later + /// request for the same log covers it, or the background pass's log + /// became resident. + pub(super) withdrawn: AtomicBool, + /// Part of the background pass over existing logs, which leaves a log an + /// earlier run already rewrote to the live triggers. + pub(super) pass: bool, +} + +/// What the store writer did with a [`CompactionRequest`]. +pub(super) enum Compacted { + Skipped, + Done(CompactOutcome), +} + +#[derive(Default)] +pub(super) struct Compactions { + /// The request queued for each log, until the writer reports it done. + queued: HashMap>, + /// The background pass over existing logs, while it runs. + pass: Option, +} + +/// Compacts the logs that existed at startup one at a time, so it never holds +/// more than one log in memory and never delays the writer by more than one +/// compaction. +struct CompactionPass { + remaining: VecDeque, + started: Instant, + rewritten: usize, + unchanged: usize, + rejected: usize, + skipped: usize, + bytes_before: u64, + bytes_after: u64, +} + +impl AppState { + /// Compact a session's log once every write queued so far is in it. A + /// request still queued for the log is withdrawn: this one runs later and + /// covers everything that one would have. + pub(super) fn schedule_compaction(&mut self, session_id: &str, cx: &mut HostCx) { + self.queue_compaction(session_id, false, cx); + } + + fn queue_compaction(&mut self, session_id: &str, pass: bool, cx: &mut HostCx) { + let request = Arc::new(CompactionRequest { + withdrawn: AtomicBool::new(false), + pass, + }); + if let Some(earlier) = self + .compactions + .queued + .insert(session_id.to_string(), request.clone()) + { + earlier.withdrawn.store(true, Ordering::Relaxed); + } + self.enqueue_store_write( + StoreWrite::CompactLog { + id: session_id.to_string(), + request, + }, + cx, + ); + } + + /// A log that became resident is compacted by its turns and its release; + /// rewriting it now would only renumber it for the next load. + pub(super) fn withdraw_pass_compaction(&mut self, session_id: &str) { + if let Some(request) = self.compactions.queued.get(session_id) + && request.pass + { + request.withdrawn.store(true, Ordering::Relaxed); + self.compactions.queued.remove(session_id); + } + } + + /// Delete what earlier runs' compactions left behind, then compact the + /// existing logs in the background. Runs once the host has started, before + /// anything in this run can compact: the originals this run keeps must + /// survive until the next start. + pub(crate) fn start_log_compaction(&mut self, cx: &mut HostCx) { + self.enqueue_store_write(StoreWrite::DiscardCompactionLeftovers, cx); + self.compactions.pass = Some(CompactionPass { + remaining: self.sessions.iter().map(|meta| meta.id.clone()).collect(), + started: Instant::now(), + rewritten: 0, + unchanged: 0, + rejected: 0, + skipped: 0, + bytes_before: 0, + bytes_after: 0, + }); + self.continue_compaction_pass(cx); + } + + pub(super) fn stop_compaction_pass(&mut self) { + self.compactions.pass = None; + } + + /// Queue the next cold log of the pass, or end the pass. + fn continue_compaction_pass(&mut self, cx: &mut HostCx) { + loop { + let Some(pass) = self.compactions.pass.as_mut() else { + return; + }; + let Some(session_id) = pass.remaining.pop_front() else { + let pass = self.compactions.pass.take().expect("checked above"); + log::info!( + "compacted existing logs in {:.1?}: {} rewritten ({} -> {} bytes), {} unchanged, {} rejected, {} skipped as open or rewritten by an earlier run", + pass.started.elapsed(), + pass.rewritten, + pass.bytes_before, + pass.bytes_after, + pass.unchanged, + pass.rejected, + pass.skipped, + ); + return; + }; + let cold = !self.event_records.contains_key(&session_id) + && self.resident(&session_id).is_none() + && !self.compactions.queued.contains_key(&session_id); + if cold { + self.queue_compaction(&session_id, true, cx); + return; + } + if let Some(pass) = self.compactions.pass.as_mut() { + pass.skipped += 1; + } + } + } + + pub(super) fn compaction_finished( + &mut self, + session_id: String, + request: Arc, + compacted: Compacted, + cx: &mut HostCx, + ) { + if self + .compactions + .queued + .get(&session_id) + .is_some_and(|queued| Arc::ptr_eq(queued, &request)) + { + self.compactions.queued.remove(&session_id); + } + if let Compacted::Done(CompactOutcome::Rejected(rejection)) = &compacted { + match rejection { + CompactRejection::Malformed { line, reason } => log::warn!( + "left {session_id}.jsonl uncompacted: line {line} is {}", + match reason { + MalformedLine::NotUtf8 => "not UTF-8", + MalformedLine::Truncated => "cut short", + MalformedLine::Blank => "blank", + MalformedLine::Unparseable => "not a record", + } + ), + CompactRejection::Gate => log::warn!( + "left {session_id}.jsonl uncompacted: the compacted records fold differently" + ), + CompactRejection::Io(error) if error.kind() != std::io::ErrorKind::NotFound => { + log::warn!("could not compact {session_id}.jsonl: {error}") + } + CompactRejection::Io(_) => {} + } + } + if !request.pass { + return; + } + if let Some(pass) = self.compactions.pass.as_mut() { + match compacted { + Compacted::Skipped => pass.skipped += 1, + Compacted::Done(CompactOutcome::Rewritten { before, after }) => { + pass.rewritten += 1; + pass.bytes_before += before; + pass.bytes_after += after; + } + Compacted::Done(CompactOutcome::Unchanged) => pass.unchanged += 1, + Compacted::Done(CompactOutcome::Rejected(_)) => pass.rejected += 1, + } + } + self.continue_compaction_pass(cx); + } +} diff --git a/crates/runtime/src/app/events.rs b/crates/runtime/src/app/events.rs index e42950dd9..50e0ccc12 100644 --- a/crates/runtime/src/app/events.rs +++ b/crates/runtime/src/app/events.rs @@ -512,17 +512,19 @@ impl AppState { event: event.clone(), elided: None, }; + let end = self.resident_log(session_id).end(); self.emit_domain( Topic::SessionEvents { session_id: session_id.to_string(), }, - ServerEvent::SessionEvent(history::wire_record(&record).into_owned()), + ServerEvent::SessionEvent { + epoch: end.epoch, + position: end.position as u64, + record: history::wire_record(&record).into_owned(), + }, cx, ); - self.event_records - .entry(session_id.to_string()) - .or_insert_with(|| SessionLog::load(&self.store, session_id)) - .push(record); + self.resident_log(session_id).push(record); self.enqueue_store_write( StoreWrite::AppendEvent { id: session_id.to_string(), @@ -531,6 +533,11 @@ impl AppState { }, cx, ); + // A completed turn is an opportunity, not a seal: records that arrive + // later still append in order, and a later compaction takes them. + if matches!(event, AgentEvent::TurnCompleted { .. }) { + self.schedule_compaction(session_id, cx); + } if let Some(session) = self.resident_mut(session_id) { session.timeline.apply_at(Some(ts), event); } else { diff --git a/crates/runtime/src/app/history.rs b/crates/runtime/src/app/history.rs index 67b949e02..2ddadcf4a 100644 --- a/crates/runtime/src/app/history.rs +++ b/crates/runtime/src/app/history.rs @@ -4,7 +4,7 @@ use std::borrow::Cow; use std::ops::Range; use tcode_protocol::{ HostMessage, MAX_SESSION_HISTORY_BYTES, OUTPUT_PREVIEW_BYTES, SESSION_HISTORY_RECORDS, - SESSION_WINDOW_BYTES, + SESSION_WINDOW_BYTES, SessionWindow, }; /// Count serialized bytes without allocating a copy of a large record. @@ -206,6 +206,15 @@ fn wire_window( Ok(Window { range, records }) } +/// A position in one layout of a session's log. Rewriting the JSONL +/// renumbers its records under a new epoch, so a position alone does not say +/// which record it is. +#[derive(Debug, Clone, Copy, PartialEq, Eq)] +pub(super) struct LogCursor { + pub(super) epoch: u64, + pub(super) position: usize, +} + /// The complete event log of one session, held in memory while the session /// is resident so history windows cost the page rather than a re-parse of the /// JSONL, plus the fold that decides where each window may start. @@ -217,8 +226,14 @@ fn wire_window( /// and the store writer has flushed every append queued from it /// ([`AppState::release_stale_session_logs`]): until then the log, not the /// JSONL, is the whole conversation. +/// +/// A resident log keeps the layout it was loaded in. Compaction rewrites the +/// JSONL beneath it without touching it, so its positions, its fold and every +/// client cursor into it stay valid; the rewritten layout is served once the +/// log is next loaded, and cursors into the old one get a baseline then. #[derive(Clone)] pub(super) struct SessionLog { + epoch: u64, records: Vec, /// Indices of the records that opened a turn in `fold`, ascending. turn_starts: Vec, @@ -226,17 +241,19 @@ pub(super) struct SessionLog { /// can tell whether it opens a turn, and cloned by timeline loads instead /// of folding the records again. fold: Timeline, - /// The length flushed by the release barrier in flight, if any. - release_barrier: Option, + /// The end flushed by the release barrier in flight, if any. + release_barrier: Option, } impl SessionLog { pub(super) fn load(store: &SessionStore, session_id: &str) -> Self { - Self::from_records(store.read_events(session_id)) + let log = store.read_log(session_id); + Self::new(log.epoch, log.records) } - pub(super) fn from_records(records: impl IntoIterator) -> Self { + pub(super) fn new(epoch: u64, records: impl IntoIterator) -> Self { let mut log = Self { + epoch, records: Vec::new(), turn_starts: Vec::new(), fold: Timeline::default(), @@ -248,6 +265,18 @@ impl SessionLog { log } + pub(super) fn epoch(&self) -> u64 { + self.epoch + } + + /// The cursor just past the last record. + pub(super) fn end(&self) -> LogCursor { + LogCursor { + epoch: self.epoch, + position: self.records.len(), + } + } + pub(super) fn push(&mut self, record: SessionEventRecord) { let turns = self.fold.turns.len(); self.fold.apply_at(record.ts, &record.event); @@ -281,36 +310,55 @@ impl SessionLog { } impl AppState { + /// The session's cached log, loaded from the JSONL when nothing is cached + /// yet. From then until it is released it is the whole conversation, in + /// the layout it was loaded in. + pub(super) fn resident_log(&mut self, session_id: &str) -> &mut SessionLog { + if !self.event_records.contains_key(session_id) { + let log = SessionLog::load(&self.store, session_id); + self.cache_log(session_id.to_string(), log); + } + self.event_records + .get_mut(session_id) + .expect("cached above") + } + + /// Cache a log read from the JSONL. A rewrite of a cached log would + /// only renumber it for the next load, so the background pass leaves it + /// to the live triggers. + pub(super) fn cache_log(&mut self, session_id: String, log: SessionLog) { + self.withdraw_pass_compaction(&session_id); + self.event_records.insert(session_id, log); + } + /// The session's log, cached for the resident session it belongs to. A /// non-resident session is read cold and not retained, so paging it never /// grows the cache. fn history_log(&mut self, session_id: &str) -> std::borrow::Cow<'_, SessionLog> { - if !self.event_records.contains_key(session_id) { - let log = SessionLog::load(&self.store, session_id); - if self.resident(session_id).is_none() { - return std::borrow::Cow::Owned(log); - } - self.event_records.insert(session_id.to_string(), log); + if !self.event_records.contains_key(session_id) && self.resident(session_id).is_none() { + return std::borrow::Cow::Owned(SessionLog::load(&self.store, session_id)); } - std::borrow::Cow::Borrowed(&self.event_records[session_id]) + std::borrow::Cow::Borrowed(self.resident_log(session_id)) } /// Queue a store-writer barrier for every cached log whose session left /// residency, and drop the log once the barrier echoes: a cold read after /// that sees every append the log had accepted. Appends that race the - /// barrier re-arm it. + /// barrier re-arm it. The log is compacted first, so a turn that never + /// completed is compacted too, and the next load serves that layout. pub(super) fn release_stale_session_logs(&mut self, cx: &mut HostCx) { - let stale: Vec<(String, usize)> = self + let stale: Vec<(String, LogCursor)> = self .event_records .iter() .filter(|(id, log)| log.release_barrier.is_none() && self.resident(id).is_none()) - .map(|(id, log)| (id.clone(), log.records.len())) + .map(|(id, log)| (id.clone(), log.end())) .collect(); for (session_id, flushed) in stale { self.event_records .get_mut(&session_id) .expect("stale log collected above") .release_barrier = Some(flushed); + self.schedule_compaction(&session_id, cx); let (completion, completed) = smol::channel::bounded(1); self.enqueue_store_write(StoreWrite::Flush(completion), cx); let host_cx = cx.clone(); @@ -323,7 +371,7 @@ impl AppState { return; }; log.release_barrier = None; - let appended_since = log.records.len() != flushed; + let appended_since = log.end() != flushed; if state.resident(&session_id).is_some() { return; } @@ -337,6 +385,9 @@ impl AppState { } } + /// The window answering a subscription: the records from its cursor on + /// when the cursor is in the layout this host serves, otherwise a + /// baseline that replaces whatever the client holds. pub(crate) fn session_events_snapshot( &mut self, subscription: &tcode_protocol::Subscription, @@ -345,39 +396,20 @@ impl AppState { unreachable!() }; let log = self.history_log(session_id); - let records = log.records(); - let total = records.len(); - let total_turns = log.fold().turns.len() as u64; - let after = subscription.after.filter(|after| *after <= total as u64); - let from = after.map_or_else( - || log.turn_aligned_start(total.saturating_sub(400)), - |after| after as usize, - ); + let after = subscription.after.filter(|after| { + subscription.epoch == Some(log.epoch) && *after <= log.records.len() as u64 + }); let empty = HostMessage::Event(EventEnvelope { request_id: Some(u64::MAX), topic: subscription.topic.clone(), - event: ServerEvent::SessionSnapshot { - from: u64::MAX, - end: u64::MAX, - records: vec![], - total: u64::MAX, - total_turns: u64::MAX, - truncated: false, - }, + event: ServerEvent::SessionSnapshot(empty_window()), }); - let overhead = serde_json::to_vec(&empty) - .expect("serializable snapshot") - .len() - + 1; - match wire_window(records, from..total, after.is_none(), overhead) { - Ok(window) => ServerEvent::SessionSnapshot { - from: window.range.start as u64, - end: window.range.end as u64, - truncated: window.range.len() < total - from, - records: window.records, - total: total as u64, - total_turns, - }, + match session_window( + &log, + after.map(|after| after as usize), + wire_overhead(&empty), + ) { + Ok(window) => ServerEvent::SessionSnapshot(window), Err(error) => ServerEvent::SessionHistoryError(error), } } @@ -385,10 +417,19 @@ impl AppState { pub(crate) fn session_history_page( &mut self, session_id: &str, + epoch: u64, before: u64, limit: u32, ) -> Result { let log = self.history_log(session_id); + if epoch != log.epoch { + let empty = HostMessage::QueryResult { + id: u64::MAX, + result: Ok(QueryResponse::SessionHistoryReset(empty_window())), + }; + return session_window(&log, None, wire_overhead(&empty)) + .map(QueryResponse::SessionHistoryReset); + } let records = log.records(); let end = before.min(records.len() as u64) as usize; let count = (limit as usize).clamp(1, SESSION_HISTORY_RECORDS); @@ -396,15 +437,16 @@ impl AppState { let empty = HostMessage::QueryResult { id: u64::MAX, result: Ok(QueryResponse::SessionHistoryPage { + epoch: u64::MAX, records: vec![], from: u64::MAX, end: u64::MAX, truncated: false, }), }; - let overhead = serde_json::to_vec(&empty).expect("serializable page").len() + 1; - let window = wire_window(records, requested.clone(), true, overhead)?; + let window = wire_window(records, requested.clone(), true, wire_overhead(&empty))?; Ok(QueryResponse::SessionHistoryPage { + epoch: log.epoch, from: window.range.start as u64, end: window.range.end as u64, truncated: window.range.len() < requested.len(), @@ -445,3 +487,48 @@ impl AppState { Ok(QueryResponse::ItemOutput(output)) } } + +/// The bytes a reply spends besides its records, measured on `empty`, a reply +/// without records whose numbers are as long as any reply's. +fn wire_overhead(empty: &HostMessage) -> usize { + serde_json::to_vec(empty).expect("serializable reply").len() + 1 +} + +/// The records from cursor `after` to the end, or without one a baseline: the +/// tail from a turn start about [`BASELINE_RECORDS`] records back, cut to the +/// byte budget from its newest end. +fn session_window( + log: &SessionLog, + after: Option, + overhead: usize, +) -> Result { + let total = log.records.len(); + let from = + after.unwrap_or_else(|| log.turn_aligned_start(total.saturating_sub(BASELINE_RECORDS))); + let window = wire_window(&log.records, from..total, after.is_none(), overhead)?; + Ok(SessionWindow { + epoch: log.epoch, + from: window.range.start as u64, + end: window.range.end as u64, + truncated: window.range.len() < total - from, + records: window.records, + total: total as u64, + total_turns: log.fold.turns.len() as u64, + }) +} + +/// How far back a baseline reaches before its turn start and byte budget. +const BASELINE_RECORDS: usize = 400; + +/// A window without records whose numbers are as long as any window's. +fn empty_window() -> SessionWindow { + SessionWindow { + epoch: u64::MAX, + from: u64::MAX, + end: u64::MAX, + records: vec![], + total: u64::MAX, + total_turns: u64::MAX, + truncated: false, + } +} diff --git a/crates/runtime/src/app/lifecycle.rs b/crates/runtime/src/app/lifecycle.rs index 1ea43f7a6..68970a87c 100644 --- a/crates/runtime/src/app/lifecycle.rs +++ b/crates/runtime/src/app/lifecycle.rs @@ -359,6 +359,7 @@ impl AppState { /// Shut down every provider process before the application exits. pub fn shutdown_all(&mut self, cx: &mut HostCx) { + self.stop_compaction_pass(); for id in self .mcp .computer_use_registrations diff --git a/crates/runtime/src/app/mod.rs b/crates/runtime/src/app/mod.rs index 53bc4d200..1d0bc4ed4 100644 --- a/crates/runtime/src/app/mod.rs +++ b/crates/runtime/src/app/mod.rs @@ -228,6 +228,7 @@ mod acp; mod active_session; mod approvals; mod command_validation; +mod compaction; mod events; mod git; mod history; @@ -261,7 +262,7 @@ use providers::{ }; pub use sessions::ResidentSessions; pub(crate) use snapshots::DomainDiff; -use store_write::{StoreWrite, run_store_write}; +use store_write::{StoreWrite, StoreWriter}; /// The result of a provider version check. #[derive(Debug, Clone, Default)] @@ -389,6 +390,7 @@ pub struct AppState { /// Resident sessions' event logs; see [`SessionLog`] for what is cached /// and when it is dropped. event_records: HashMap, + compactions: compaction::Compactions, /// Composer-draft review notes, keyed by session id (in-memory only). review_comment_drafts: HashMap>, /// A restart-continuity marker taken at launch (see `tcode_services::relaunch`). @@ -536,6 +538,7 @@ impl AppState { timeline_load_generations: HashMap::new(), subscriptions: HashSet::new(), event_records: HashMap::new(), + compactions: Default::default(), review_comment_drafts: HashMap::new(), pending_relaunch, external_imports: HashMap::new(), @@ -551,15 +554,16 @@ impl AppState { fn start_store_writer(&mut self, cx: &mut HostCx) { if let Some(writes) = self.store_write_receiver.take() { - let store = self.store.clone(); - let settings_store = self.settings_store.clone(); - let terminal_preferences_path = self.terminal_preferences_path.clone(); + let mut writer = StoreWriter::new( + self.store.clone(), + self.settings_store.clone(), + self.terminal_preferences_path.clone(), + ); let failures = self.store_write_failures.clone(); + let host_cx = cx.clone(); HostCx::spawn_detached(cx, async move { while let Ok(write) = writes.recv().await { - if let Some(failure) = - run_store_write(&store, &settings_store, &terminal_preferences_path, write) - { + if let Some(failure) = writer.run(write, &host_cx).await { let _ = failures.send(failure).await; } } diff --git a/crates/runtime/src/app/options.rs b/crates/runtime/src/app/options.rs index 7c732475f..4181be677 100644 --- a/crates/runtime/src/app/options.rs +++ b/crates/runtime/src/app/options.rs @@ -293,14 +293,15 @@ impl AppState { Topic::SessionEvents { session_id: session_id.clone(), }, - ServerEvent::SessionSnapshot { + ServerEvent::SessionSnapshot(tcode_protocol::SessionWindow { + epoch: 0, total: 0, total_turns: 0, truncated: false, from: 0, end: 0, records: Vec::new(), - }, + }), cx, ); self.refresh_session_git_branch(session_id.clone(), cwd, cx); diff --git a/crates/runtime/src/app/orchestrate.rs b/crates/runtime/src/app/orchestrate.rs index 3b6186ea4..5a8cbc07b 100644 --- a/crates/runtime/src/app/orchestrate.rs +++ b/crates/runtime/src/app/orchestrate.rs @@ -867,20 +867,19 @@ impl AppState { let _ = reply.try_send(Ok(result)); return; } - let store = self.store.clone(); + let folds: Vec<_> = unloaded + .into_iter() + .map(|id| { + let fold = self.folded_log(&id, cx); + (id, fold) + }) + .collect(); let host_cx = cx.clone(); HostCx::spawn_detached(cx, async move { - let timelines = host_cx - .unblock(move || { - unloaded - .into_iter() - .map(|id| { - let timeline = Timeline::fold_events(store.read_events(&id)); - (id, timeline) - }) - .collect::>() - }) - .await; + let mut timelines = HashMap::new(); + for (id, fold) in folds { + timelines.insert(id, fold.await); + } let result = host_cx .enqueue_and_wait(move |state, _| { state.orchestrate_status_json(&children, &timelines) @@ -910,13 +909,10 @@ impl AppState { let _ = reply.try_send(result); return; } - let store = self.store.clone(); + let fold = self.folded_log(&thread_id, cx); let host_cx = cx.clone(); HostCx::spawn_detached(cx, async move { - let read_id = thread_id.clone(); - let timeline = host_cx - .unblock(move || Timeline::fold_events(store.read_events(&read_id))) - .await; + let timeline = fold.await; let result = host_cx .enqueue_and_wait(move |state, _| { let timeline = state.loaded_child_timeline(&thread_id).unwrap_or(&timeline); @@ -928,6 +924,28 @@ impl AppState { }); } + /// The pure fold of a session's whole log. A cached log already holds + /// every record accepted for it, appends still queued for disk included; + /// otherwise the JSONL is read once everything queued before now is + /// written. + pub(super) fn folded_log(&mut self, session_id: &str, cx: &mut HostCx) -> HostTask { + if let Some(log) = self.event_records.get(session_id) { + let fold = log.fold().clone(); + return cx.spawn_background(async move { fold }); + } + let (completion, written) = smol::channel::bounded(1); + self.enqueue_store_write(StoreWrite::Flush(completion), cx); + let store = self.store.clone(); + let read_id = session_id.to_string(); + let host_cx = cx.clone(); + cx.spawn_background(async move { + let _ = written.recv().await; + host_cx + .unblock(move || Timeline::fold_events(store.read_events(&read_id))) + .await + }) + } + pub(super) fn loaded_child_timeline(&self, session_id: &str) -> Option<&Timeline> { self.resident(session_id).map(|child| &child.timeline) } @@ -1047,13 +1065,10 @@ impl AppState { // attention. let auto_archive = child.archive_on_complete && matches!(status, TurnStatus::Completed); let result_max_chars = child.result_max_chars; - let store = self.store.clone(); + let fold = self.folded_log(&child_id, cx); let host_cx = cx.clone(); HostCx::spawn_detached(cx, async move { - let read_id = child_id.clone(); - let timeline = host_cx - .unblock(move || Timeline::fold_events(store.read_events(&read_id))) - .await; + let timeline = fold.await; host_cx.enqueue(move |state, cx| { let child_still_exists = state.sessions.iter().any(|meta| { meta.id == child_id diff --git a/crates/runtime/src/app/sessions.rs b/crates/runtime/src/app/sessions.rs index 2288b17d4..01c9ae102 100644 --- a/crates/runtime/src/app/sessions.rs +++ b/crates/runtime/src/app/sessions.rs @@ -1004,6 +1004,7 @@ impl AppState { session_id: fork.id.clone(), }, after: None, + epoch: None, }) { cx.emit(HostEvent::Domain(snapshot)); @@ -1471,18 +1472,23 @@ impl AppState { { active.draft = false; let meta = active.meta.clone(); + let epoch = self + .event_records + .get(&meta.id) + .map_or(0, SessionLog::epoch); self.emit_domain( Topic::SessionEvents { session_id: meta.id.clone(), }, - ServerEvent::SessionSnapshot { + ServerEvent::SessionSnapshot(tcode_protocol::SessionWindow { + epoch, total: 0, total_turns: 0, truncated: false, from: 0, end: 0, records: Vec::new(), - }, + }), cx, ); self.enqueue_store_write( @@ -1530,36 +1536,34 @@ impl AppState { // snapshot that answers the subscription needs it in the same turn; // a background session parses off the mailbox and caches on completion. let cached = match target { - TimelineLoadTarget::Active { .. } => Some( - self.event_records - .entry(session_id.clone()) - .or_insert_with(|| SessionLog::load(&self.store, &session_id)), - ), - TimelineLoadTarget::Background => self.event_records.get_mut(&session_id), + TimelineLoadTarget::Active { .. } => Some(&*self.resident_log(&session_id)), + TimelineLoadTarget::Background => self.event_records.get(&session_id), } - .map(|log| (log.records().len(), log.fold().clone())); + .map(|log| (log.end(), log.fold().clone())); + let (mark_idle, load_branch) = match target { + TimelineLoadTarget::Active { mark_idle } => (mark_idle, true), + TimelineLoadTarget::Background => (true, false), + }; let store = self.store.clone(); let host_cx = cx.clone(); HostCx::spawn_detached(cx, async move { let read_id = session_id.clone(); - let (timeline, folded, loaded, git_branch) = { - let (mut timeline, folded, loaded) = match cached { - Some((folded, fold)) => (fold, folded, None), - None => { - let log = SessionLog::load(&store, &read_id); - (log.fold().clone(), log.records().len(), Some(log)) + let (timeline, folded, loaded, git_branch) = host_cx + .unblock(move || { + let (mut timeline, folded, loaded) = match cached { + Some((folded, fold)) => (fold, folded, None), + None => { + let log = SessionLog::load(&store, &read_id); + (log.fold().clone(), log.end(), Some(log)) + } + }; + if mark_idle { + timeline.mark_idle(); } - }; - let (mark_idle, load_branch) = match target { - TimelineLoadTarget::Active { mark_idle } => (mark_idle, true), - TimelineLoadTarget::Background => (true, false), - }; - if mark_idle { - timeline.mark_idle(); - } - let git_branch = load_branch.then(|| read_git_branch(&cwd)); - (timeline, folded, loaded, git_branch) - }; + let git_branch = load_branch.then(|| read_git_branch(&cwd)); + (timeline, folded, loaded, git_branch) + }) + .await; host_cx.enqueue(move |state, cx| { let generation_matches = state.timeline_load_generations.get(&session_id).copied() == Some(generation); @@ -1576,17 +1580,27 @@ impl AppState { } // An append during the parse already loaded and extended its // own copy; that one carries the newer records. - if let Some(loaded) = loaded { - state - .event_records - .entry(session_id.clone()) - .or_insert(loaded); + if let Some(loaded) = loaded + && !state.event_records.contains_key(&session_id) + { + state.cache_log(session_id.clone(), loaded); } let mut timeline = timeline; - // Records appended while the fold ran continue the same log. if let Some(log) = state.event_records.get(&session_id) { - for record in log.records().iter().skip(folded) { - timeline.apply_at(record.ts, &record.event); + if log.epoch() == folded.epoch { + // Records appended while the fold ran continue the + // same layout. + for record in log.records().iter().skip(folded.position) { + timeline.apply_at(record.ts, &record.event); + } + } else { + // The cached copy was loaded after a rewrite renumbered + // the log, so `folded` says nothing about which of its + // records the fold covered; its own fold covers them all. + timeline = log.fold().clone(); + if mark_idle { + timeline.mark_idle(); + } } } if let Some(session) = state.resident_mut(&session_id) { diff --git a/crates/runtime/src/app/store_write.rs b/crates/runtime/src/app/store_write.rs index 9aa5b5162..90bd1acc2 100644 --- a/crates/runtime/src/app/store_write.rs +++ b/crates/runtime/src/app/store_write.rs @@ -1,4 +1,8 @@ +use std::sync::atomic::Ordering; + +use super::compaction::{Compacted, CompactionRequest}; use super::*; +use tcode_services::store::{CompactOutcome, CompactRejection}; pub(super) enum StoreWrite { AppendEvent { @@ -36,16 +40,128 @@ pub(super) enum StoreWrite { value: Option, }, ClearProfileSecrets(String), + /// Rewrite one log compacted, unless the request was withdrawn. + CompactLog { + id: String, + request: Arc, + }, + /// Delete the originals and temporary files earlier runs' compactions + /// left beside the logs. + DiscardCompactionLeftovers, Flush(smol::channel::Sender<()>), } +/// Runs every queued write, one at a time in queue order. +pub(super) struct StoreWriter { + store: SessionStore, + settings_store: SettingsStore, + terminal_preferences_path: PathBuf, + /// Logs compacted in this run with nothing written to them since, which + /// another compaction would leave as they are. + compacted: HashSet, +} + +impl StoreWriter { + pub(super) fn new( + store: SessionStore, + settings_store: SettingsStore, + terminal_preferences_path: PathBuf, + ) -> Self { + Self { + store, + settings_store, + terminal_preferences_path, + compacted: HashSet::new(), + } + } + + /// Run one write. Compaction's reading, folding and syncing happen on the + /// blocking pool and are awaited here, so the writes queued behind it + /// still wait for it while the executor thread stays free. + pub(super) async fn run( + &mut self, + write: StoreWrite, + host_cx: &HostCx, + ) -> Option> { + match write { + StoreWrite::CompactLog { id, request } => { + self.compact(id, request, host_cx).await; + None + } + StoreWrite::DiscardCompactionLeftovers => { + let store = self.store.clone(); + host_cx + .unblock(move || store.discard_compaction_leftovers()) + .await + .err() + .map(|err| Err(format!("failed to delete compaction leftovers: {err}"))) + } + write => { + match &write { + StoreWrite::AppendEvent { id, .. } | StoreWrite::WriteEventLog { id, .. } => { + self.compacted.remove(id); + } + StoreWrite::CloneEvents { dst, .. } => { + self.compacted.remove(dst); + } + StoreWrite::RemoveSessions(ids) => { + for id in ids { + self.compacted.remove(id); + } + } + _ => {} + } + run_store_write( + &self.store, + &self.settings_store, + &self.terminal_preferences_path, + write, + ) + } + } + } + + async fn compact(&mut self, id: String, request: Arc, host_cx: &HostCx) { + let compacted = if request.withdrawn.load(Ordering::Relaxed) || self.compacted.contains(&id) + { + Compacted::Skipped + } else { + let store = self.store.clone(); + let read_id = id.clone(); + let pass = request.pass; + host_cx + .unblock(move || { + if pass && store.log_epoch(&read_id) > 0 { + Compacted::Skipped + } else { + Compacted::Done(store.compact_log(&read_id)) + } + }) + .await + }; + // A failed read or write may succeed next time; anything else would + // come out the same until the log is written to. + if let Compacted::Done(outcome) = &compacted { + let retry = matches!( + outcome, + CompactOutcome::Rejected(CompactRejection::Io(error)) + if error.kind() != std::io::ErrorKind::NotFound + ); + if !retry { + self.compacted.insert(id.clone()); + } + } + host_cx.enqueue(move |state, cx| state.compaction_finished(id, request, compacted, cx)); + } +} + pub(super) fn atomic_write(path: PathBuf, bytes: Vec) -> std::io::Result<()> { let tmp = path.with_extension("json.tmp"); fs::write(&tmp, bytes)?; fs::rename(tmp, path) } -pub(super) fn run_store_write( +fn run_store_write( store: &SessionStore, settings_store: &SettingsStore, terminal_preferences_path: &Path, @@ -155,5 +271,8 @@ pub(super) fn run_store_write( let _ = completion.try_send(()); None } + StoreWrite::CompactLog { .. } | StoreWrite::DiscardCompactionLeftovers => { + unreachable!("run by StoreWriter::run") + } } } diff --git a/crates/runtime/src/app/test_support.rs b/crates/runtime/src/app/test_support.rs index e4f8857a5..ea504f22b 100644 --- a/crates/runtime/src/app/test_support.rs +++ b/crates/runtime/src/app/test_support.rs @@ -154,6 +154,19 @@ impl TestAppContext { } } + /// Block until background work queues a completion on the mailbox, + /// without running it. + pub(super) fn wait_for_mailbox(&self) { + let deadline = Instant::now() + Duration::from_secs(5); + while self.mailbox_rx.is_empty() { + assert!( + Instant::now() < deadline, + "background work did not complete within five seconds" + ); + std::thread::sleep(Duration::from_millis(1)); + } + } + /// Drain and decode every NDJSON line emitted by the host so tests assert /// on the same serialized traffic consumed by production clients. pub(super) fn drain_outgoing(&mut self) -> Vec { diff --git a/crates/runtime/src/app/tests.rs b/crates/runtime/src/app/tests.rs index 5d38b3d6d..03b9ec40f 100644 --- a/crates/runtime/src/app/tests.rs +++ b/crates/runtime/src/app/tests.rs @@ -3,7 +3,7 @@ use super::*; use super::{active_session::*, events::*, orchestrate::*, providers::*}; use tcode_core::settings::{SettingsPatch, ThemeMode}; -use tcode_protocol::{Command, CommandResponse, HostMessage}; +use tcode_protocol::{Command, CommandResponse, HostMessage, Subscription}; #[test] fn permission_relaunch_marker_requires_screen_access_only_for_computer_use() { for screen_recording in [false, true] { @@ -1122,10 +1122,13 @@ fn scripted_provider_connects_command_launch_and_agent_event_paths() { message, HostMessage::Event(EventEnvelope { request_id: None, topic: Topic::SessionEvents { .. }, - event: ServerEvent::SessionEvent(SessionEventRecord { - event: AgentEvent::TurnStarted { turn_id }, + event: ServerEvent::SessionEvent { + record: SessionEventRecord { + event: AgentEvent::TurnStarted { turn_id }, + .. + }, .. - }), + }, .. }) if turn_id == "scripted-turn" ))); @@ -4943,10 +4946,13 @@ fn model_fallback_stops_active_session_when_abort_on_model_fallback_is_enabled() message, HostMessage::Event(EventEnvelope { topic: Topic::SessionEvents { .. }, - event: ServerEvent::SessionEvent(SessionEventRecord { - event: AgentEvent::TurnCompleted { turn_id, status: TurnStatus::Interrupted, .. }, + event: ServerEvent::SessionEvent { + record: SessionEventRecord { + event: AgentEvent::TurnCompleted { turn_id, status: TurnStatus::Interrupted, .. }, + .. + }, .. - }), + }, .. }) if turn_id == "turn-fallback" ))); @@ -5455,6 +5461,7 @@ fn subscribing_readopts_an_uncommitted_draft_before_its_idle_reaper() { session_id: id.clone(), }, after: None, + epoch: None, }; state.subscribe(&subscription, cx); state.unsubscribe(&subscription, cx); @@ -7076,6 +7083,7 @@ fn mux_clients_target_independent_drafts_and_receive_only_their_session_tail() { session_id: id.clone(), }, after: None, + epoch: None, }) .unwrap(); id @@ -7136,7 +7144,7 @@ fn mux_clients_target_independent_drafts_and_receive_only_their_session_tail() { session_id: id.clone() } ); - records += usize::from(matches!(event.event, ServerEvent::SessionEvent(_))); + records += usize::from(matches!(event.event, ServerEvent::SessionEvent { .. })); } assert_eq!(records, 3); link.subscribe(Subscription { @@ -7144,11 +7152,14 @@ fn mux_clients_target_independent_drafts_and_receive_only_their_session_tail() { session_id: id.clone(), }, after: Some(1), + epoch: Some(0), }) .unwrap(); link.command_blocking(Command::ClearRelaunchMarker).unwrap(); let snapshot = events.try_recv().unwrap(); - let ServerEvent::SessionSnapshot { from, records, .. } = snapshot.event else { + let ServerEvent::SessionSnapshot(tcode_protocol::SessionWindow { from, records, .. }) = + snapshot.event + else { panic!("expected tail") }; assert_eq!(from, 1); @@ -7162,11 +7173,12 @@ fn mux_clients_target_independent_drafts_and_receive_only_their_session_tail() { session_id: id.clone(), }, after: Some(99), + epoch: Some(0), }) .unwrap(); link.command_blocking(Command::ClearRelaunchMarker).unwrap(); assert!( - matches!(events.try_recv().unwrap().event, ServerEvent::SessionSnapshot { from: 0, records, .. } if records.len() == 3) + matches!(events.try_recv().unwrap().event, ServerEvent::SessionSnapshot(tcode_protocol::SessionWindow { from: 0, records, .. }) if records.len() == 3) ); } assert!( @@ -7195,12 +7207,13 @@ fn session_history_snapshot_pages_and_absolute_tail_cursors() { .collect(); state .event_records - .insert("large".into(), SessionLog::from_records(records.clone())); + .insert("large".into(), SessionLog::new(0, records.clone())); let subscription = tcode_protocol::Subscription { topic: Topic::SessionEvents { session_id: "large".into(), }, after: None, + epoch: None, }; let snapshot = state.subscription_snapshot(&subscription).unwrap(); assert!( @@ -7209,13 +7222,13 @@ fn session_history_snapshot_pages_and_absolute_tail_cursors() { .len() <= tcode_protocol::MAX_SESSION_HISTORY_BYTES ); - let ServerEvent::SessionSnapshot { + let ServerEvent::SessionSnapshot(tcode_protocol::SessionWindow { from, records: tail, total, truncated, .. - } = snapshot.event + }) = snapshot.event else { panic!("snapshot") }; @@ -7229,7 +7242,8 @@ fn session_history_snapshot_pages_and_absolute_tail_cursors() { from, end, truncated, - } = state.session_history_page("large", before, 200).unwrap() + .. + } = state.session_history_page("large", 0, before, 200).unwrap() else { panic!("page") }; @@ -7244,14 +7258,15 @@ fn session_history_snapshot_pages_and_absolute_tail_cursors() { let snapshot = state .subscription_snapshot(&tcode_protocol::Subscription { after: Some(after), + epoch: Some(0), ..subscription.clone() }) .unwrap(); - let ServerEvent::SessionSnapshot { + let ServerEvent::SessionSnapshot(tcode_protocol::SessionWindow { from, records: tail, .. - } = snapshot.event + }) = snapshot.event else { panic!("tail") }; @@ -7320,7 +7335,7 @@ fn history_snapshot_and_pages_start_at_turn_boundaries() { assert_eq!(turn_starts, [0, 303, 606, 909, 1212]); state .event_records - .insert("streamed".into(), SessionLog::from_records(records.clone())); + .insert("streamed".into(), SessionLog::new(0, records.clone())); let snapshot = state .subscription_snapshot(&tcode_protocol::Subscription { @@ -7328,9 +7343,12 @@ fn history_snapshot_and_pages_start_at_turn_boundaries() { session_id: "streamed".into(), }, after: None, + epoch: None, }) .unwrap(); - let ServerEvent::SessionSnapshot { from, .. } = snapshot.event else { + let ServerEvent::SessionSnapshot(tcode_protocol::SessionWindow { from, .. }) = + snapshot.event + else { panic!("snapshot") }; assert_eq!( @@ -7343,7 +7361,10 @@ fn history_snapshot_and_pages_start_at_turn_boundaries() { end, records: page, truncated, - } = state.session_history_page("streamed", from, 200).unwrap() + .. + } = state + .session_history_page("streamed", 0, from, 200) + .unwrap() else { panic!("page") }; @@ -7424,14 +7445,15 @@ fn history_pages_of_an_opened_session_parse_the_log_once() { session_id: "paged".into(), }, after: None, + epoch: None, }) .unwrap(); - let ServerEvent::SessionSnapshot { + let ServerEvent::SessionSnapshot(tcode_protocol::SessionWindow { from, records, total_turns, .. - } = snapshot.event + }) = snapshot.event else { panic!("snapshot") }; @@ -7456,7 +7478,7 @@ fn history_pages_of_an_opened_session_parse_the_log_once() { from, end, .. - } = state.session_history_page("paged", before, 200).unwrap() + } = state.session_history_page("paged", 0, before, 200).unwrap() else { panic!("page") }; @@ -7465,8 +7487,8 @@ fn history_pages_of_an_opened_session_parse_the_log_once() { before = from; } assert_eq!( - format!("{:?}", Timeline::fold_events(loaded).entries), - format!("{:?}", Timeline::fold_events(records).entries), + Timeline::fold_events(loaded), + Timeline::fold_events(records), "merged deltas fold as the log does" ); }); @@ -7493,7 +7515,7 @@ fn session_log_follows_residency_and_flushes_before_release() { let reads_before_open = store.event_reads(); let (commands, _actor) = smol::channel::unbounded(); - state.update(cx, |state, cx| { + let released = state.update(cx, |state, cx| { state.select_session("resident", cx); state.record_event( "resident", @@ -7514,14 +7536,15 @@ fn session_log_follows_residency_and_flushes_before_release() { session_id: "resident".into(), }, after: Some(persisted), + epoch: Some(0), }) .unwrap(); - let ServerEvent::SessionSnapshot { + let ServerEvent::SessionSnapshot(tcode_protocol::SessionWindow { records, total, total_turns, .. - } = snapshot.event + }) = snapshot.event else { panic!("snapshot") }; @@ -7530,7 +7553,7 @@ fn session_log_follows_residency_and_flushes_before_release() { matches!(&records[..], [record] if matches!(&record.event, AgentEvent::ItemCompleted(item) if item.id == "user-late")) ); let QueryResponse::SessionHistoryPage { from, records, .. } = state - .session_history_page("resident", persisted + 1, 1) + .session_history_page("resident", 0, persisted + 1, 1) .unwrap() else { panic!("page") @@ -7554,18 +7577,574 @@ fn session_log_follows_residency_and_flushes_before_release() { state.event_records.contains_key("resident"), "the log outlives residency until the store writer flushed its appends" ); + state.event_records["resident"].fold().clone() }); cx.run_until(|state| !state.event_records.contains_key("resident")); state.update(cx, |state, _| { assert!(!state.event_records.contains_key("resident")); + // Release compacts the log, so the conversation, not its record + // count, is what the next cold open must find. assert_eq!( - state.store.read_events("resident").len() as u64, - persisted + 1 + Timeline::fold_events(state.store.read_events("resident")), + released ); }); assert_eq!(store.event_reads() - reads_before_open, 2); } +/// Send `payload` through the host pipe as client message `id`, and return +/// every message the host serialized since the last drain, once it parked. +fn through_pipe( + state: &TestEntity, + cx: &mut TestAppContext, + id: u64, + payload: tcode_protocol::ClientPayload, +) -> Vec { + state.update(cx, |state, host_cx| { + crate::pipe::handle_client_message( + &mut state.host, + host_cx, + tcode_protocol::ClientMessage { + id, + key: None, + payload, + }, + ) + }); + cx.run_until_parked(); + cx.drain_outgoing() +} + +fn subscribe_events( + session_id: &str, + after: Option, + epoch: Option, +) -> tcode_protocol::ClientPayload { + tcode_protocol::ClientPayload::Subscribe(Subscription { + topic: Topic::SessionEvents { + session_id: session_id.into(), + }, + after, + epoch, + }) +} + +fn history_page(session_id: &str, epoch: u64, before: u64) -> tcode_protocol::ClientPayload { + tcode_protocol::ClientPayload::Query(tcode_protocol::Query::SessionHistoryPage { + session_id: session_id.into(), + epoch, + before, + limit: 200, + }) +} + +/// The window answering subscription request `id`. +fn window_reply(messages: &[HostMessage], id: u64) -> tcode_protocol::SessionWindow { + messages + .iter() + .find_map(|message| match message { + HostMessage::Event(EventEnvelope { + request_id: Some(request), + event: ServerEvent::SessionSnapshot(window), + .. + }) if *request == id => Some(window.clone()), + _ => None, + }) + .expect("a window answers the subscription") +} + +fn query_reply(messages: &[HostMessage], id: u64) -> QueryResponse { + messages + .iter() + .find_map(|message| match message { + HostMessage::QueryResult { id: reply, result } if *reply == id => { + Some(result.clone().expect("query succeeds")) + } + _ => None, + }) + .expect("the query is answered") +} + +/// The live records among `messages`, with the cursor each was sent at. +fn live_records(messages: &[HostMessage]) -> Vec<(u64, u64, SessionEventRecord)> { + messages + .iter() + .filter_map(|message| match message { + HostMessage::Event(EventEnvelope { + request_id: None, + event: + ServerEvent::SessionEvent { + epoch, + position, + record, + }, + .. + }) => Some((*epoch, *position, record.clone())), + _ => None, + }) + .collect() +} + +fn open_stored_session(store: &SessionStore, id: &str) -> SessionMeta { + let mut meta = SessionMeta::new(ProviderKind::ClaudeCode, store.root().clone(), None); + meta.id = id.into(); + store.upsert_metas([&meta]).unwrap(); + meta +} + +/// A cursor is a position in one layout. Against a log rewritten under a new +/// epoch, a position from the old layout, even one the new layout still has, +/// or a position without its layout gets a baseline that replaces what the +/// client holds, never records continuing from that position. +#[test] +fn a_cursor_from_another_layout_gets_a_baseline() { + let cx = &mut TestAppContext::default(); + let store = TestStore::new("layout-cursors"); + open_stored_session(&store, "rewritten"); + let conversation = Timeline::fold_events(persist_streamed_turns(&store, "rewritten", 3)); + assert!(matches!( + store.compact_log("rewritten"), + tcode_services::store::CompactOutcome::Rewritten { .. } + )); + assert_eq!(store.log_epoch("rewritten"), 1); + let total = store.read_events("rewritten").len() as u64; + let state = cx.new_entity(TestClientState::new((*store).clone())); + for (id, (label, after, epoch, continues)) in [ + ( + "a position the new layout still has", + Some(4), + Some(0), + false, + ), + ("the new layout's end", Some(total), Some(0), false), + ("a position without its layout", Some(4), None, false), + ("a position in the served layout", Some(4), Some(1), true), + ( + "a position past the served end", + Some(total + 1), + Some(1), + false, + ), + ] + .into_iter() + .enumerate() + { + let id = id as u64 + 1; + let replies = through_pipe(&state, cx, id, subscribe_events("rewritten", after, epoch)); + let window = window_reply(&replies, id); + assert_eq!( + (window.epoch, window.end, window.total), + (1, total, total), + "{label}" + ); + if continues { + assert_eq!(window.from, 4, "{label}"); + } else { + assert_eq!(window.from, 0, "{label}: a baseline"); + assert_eq!( + Timeline::fold_stored(&window.records), + conversation, + "{label}" + ); + } + } + + let replies = through_pipe(&state, cx, 10, history_page("rewritten", 0, 4)); + let QueryResponse::SessionHistoryReset(window) = query_reply(&replies, 10) else { + panic!("a page in the old layout gets a baseline") + }; + assert_eq!((window.epoch, window.from, window.end), (1, 0, total)); + let replies = through_pipe(&state, cx, 11, history_page("rewritten", 1, total)); + assert!(matches!( + query_reply(&replies, 11), + QueryResponse::SessionHistoryPage { epoch: 1, from: 0, end, .. } if end == total + )); +} + +/// A resident log keeps the layout it was loaded in while compaction rewrites +/// its JSONL: subscribers keep receiving, resuming and paging in that layout +/// and see every record once, appends after the rewrite land in the rewritten +/// JSONL in order, and the next load serves the rewritten layout, folding +/// exactly as the resident log did. +#[test] +fn a_resident_log_keeps_its_layout_while_its_jsonl_is_rewritten() { + let cx = &mut TestAppContext::default(); + let store = TestStore::new("resident-layout"); + open_stored_session(&store, "pinned"); + let persisted = persist_streamed_turns(&store, "pinned", 2).len() as u64; + let state = cx.new_entity(TestClientState::new((*store).clone())); + let first = window_reply( + &through_pipe(&state, cx, 1, subscribe_events("pinned", None, None)), + 1, + ); + let second = window_reply( + &through_pipe(&state, cx, 2, subscribe_events("pinned", None, None)), + 2, + ); + for window in [&first, &second] { + assert_eq!((window.epoch, window.from, window.end), (0, 0, persisted)); + } + + let message = |id: &str, text: &str| { + AgentEvent::ItemCompleted(ThreadItem { + id: id.into(), + parent_item_id: None, + content: ItemContent::AssistantMessage { text: text.into() }, + }) + }; + let delta = |item: &str| AgentEvent::Delta { + item_id: item.into(), + kind: agent::DeltaKind::AssistantText, + text: "word ".into(), + }; + let mut turn = vec![AgentEvent::TurnStarted { + turn_id: "turn-2".into(), + }]; + turn.extend((0..20).map(|_| delta("answer-2"))); + turn.push(message("answer-2", &"word ".repeat(20))); + turn.push(AgentEvent::TurnCompleted { + turn_id: "turn-2".into(), + status: TurnStatus::Completed, + usage: None, + }); + state.update(cx, |state, cx| { + for event in &turn { + state.record_event("pinned", event, cx); + } + }); + cx.run_until(|state| state.store.log_epoch("pinned") == 1); + let late = [ + AgentEvent::TurnChangesUpdated { + turn_id: "turn-2".into(), + changes: agent::file_changes_from_unified_diff( + "diff --git a/f b/f\n--- a/f\n+++ b/f\n@@ -1 +1 @@\n-a\n+b\n", + ) + .unwrap(), + completeness: agent::ChangeCompleteness::Exact, + }, + AgentEvent::TurnStarted { + turn_id: "turn-3".into(), + }, + delta("answer-3"), + ]; + state.update(cx, |state, cx| { + for event in &late { + state.record_event("pinned", event, cx); + } + }); + cx.run_until_parked(); + let live = live_records(&cx.drain_outgoing()); + let end = persisted + (turn.len() + late.len()) as u64; + assert_eq!( + live.iter() + .map(|(epoch, position, _)| (*epoch, *position)) + .collect::>(), + (persisted..end) + .map(|position| (0, position)) + .collect::>(), + "live records keep the resident layout's positions across the rewrite" + ); + let resident = state.read(|state| state.event_records["pinned"].fold().clone()); + let mut held = first.records.clone(); + held.extend(live.into_iter().map(|(_, _, record)| record)); + assert_eq!(Timeline::fold_stored(&held), resident); + assert_eq!( + Timeline::fold_events(store.read_events("pinned")), + resident, + "the appends after the rewrite landed in it, in order" + ); + + let resumed = window_reply( + &through_pipe( + &state, + cx, + 3, + subscribe_events("pinned", Some(end), Some(0)), + ), + 3, + ); + assert_eq!( + ( + resumed.epoch, + resumed.from, + resumed.end, + resumed.records.len() + ), + (0, end, end, 0) + ); + let resumed = window_reply( + &through_pipe( + &state, + cx, + 4, + subscribe_events("pinned", Some(persisted), Some(0)), + ), + 4, + ); + assert_eq!( + (resumed.epoch, resumed.from, resumed.end), + (0, persisted, end) + ); + let mut held = second.records.clone(); + held.extend(resumed.records); + assert_eq!(Timeline::fold_stored(&held), resident); + assert!(matches!( + query_reply(&through_pipe(&state, cx, 5, history_page("pinned", 0, persisted)), 5), + QueryResponse::SessionHistoryPage { epoch: 0, end, .. } if end == persisted + )); + + through_pipe( + &state, + cx, + 6, + tcode_protocol::ClientPayload::Unsubscribe(Subscription { + topic: Topic::SessionEvents { + session_id: "pinned".into(), + }, + after: None, + epoch: None, + }), + ); + cx.run_until(|state| !state.event_records.contains_key("pinned")); + let reopened = window_reply( + &through_pipe( + &state, + cx, + 7, + subscribe_events("pinned", Some(end), Some(0)), + ), + 7, + ); + assert_ne!( + reopened.epoch, 0, + "a cursor into the released layout resets" + ); + assert_eq!(reopened.epoch, store.log_epoch("pinned")); + assert!(reopened.total < end); + assert_eq!( + state.read(|state| state.event_records["pinned"].fold().clone()), + resident + ); +} + +/// A background timeline load that read the JSONL before a rewrite, and +/// finishes after the rewritten layout was cached, must not skip records by +/// its own count: those are positions in another layout. +#[test] +fn a_timeline_load_from_before_a_rewrite_does_not_skip_by_its_count() { + let cx = &mut TestAppContext::default(); + let store = TestStore::new("timeline-load-rewrite"); + let meta = open_stored_session(&store, "background"); + persist_streamed_turns(&store, "background", 2); + let state = cx.new_entity(TestClientState::new((*store).clone())); + state.update(cx, |state, cx| state.load_background_session(meta, cx)); + cx.wait_for_mailbox(); + assert!(matches!( + store.compact_log("background"), + tcode_services::store::CompactOutcome::Rewritten { .. } + )); + state.update(cx, |state, cx| { + state.record_event( + "background", + &AgentEvent::ItemCompleted(ThreadItem { + id: "after-the-rewrite".into(), + parent_item_id: None, + content: ItemContent::AssistantMessage { + text: "late".into(), + }, + }), + cx, + ) + }); + cx.run_until_parked(); + state.read(|state| { + let timeline = &state.resident("background").unwrap().timeline; + assert!( + timeline + .entries + .iter() + .any(|entry| entry.id == "after-the-rewrite") + ); + assert_eq!(timeline.turns.len(), 2); + }); +} + +/// A crash can stop a rewrite at any step. Production startup leaves every log +/// complete in the layout its header names, deletes the originals and +/// temporary files earlier runs left, and keeps the originals its own +/// rewrites make until the next start, which rewrites nothing again. +#[test] +fn startup_recovers_logs_from_every_step_a_rewrite_can_stop_at() { + use crate::pipe::{HostServices, spawn_host}; + let root = TestStore::new("compaction-crash"); + let path = |name: String| root.root().join(name); + let mut conversations = HashMap::new(); + let mut originals = HashMap::new(); + for id in ["temporary-left", "original-linked", "renamed"] { + open_stored_session(&root, id); + conversations.insert( + id, + Timeline::fold_events(persist_streamed_turns(&root, id, 2)), + ); + originals.insert(id, std::fs::read(path(format!("{id}.jsonl"))).unwrap()); + } + let partial = b"{\"layout_epoch\":1}\n{\"ts\":1,\"event\""; + // Stopped after writing its temporary file. + std::fs::write(path("temporary-left.jsonl.compacting".into()), partial).unwrap(); + // Stopped after also keeping the original, before the rename. + std::fs::write(path("original-linked.jsonl.compacting".into()), partial).unwrap(); + std::fs::hard_link( + path("original-linked.jsonl".into()), + path("original-linked.jsonl.orig".into()), + ) + .unwrap(); + // Renamed; the original beside it is an earlier run's. + assert!(matches!( + root.compact_log("renamed"), + tcode_services::store::CompactOutcome::Rewritten { .. } + )); + std::fs::write(path("renamed.jsonl.orig.tmp".into()), partial).unwrap(); + let renamed = std::fs::read(path("renamed.jsonl".into())).unwrap(); + + let start = || { + spawn_host( + (*root).clone(), + HostServices { + compact_existing_logs: true, + ..HostServices::default() + }, + ) + .unwrap() + }; + let host = start(); + let deadline = Instant::now() + Duration::from_secs(5); + while ["temporary-left", "original-linked"] + .iter() + .any(|id| root.log_epoch(id) != 1) + { + assert!(Instant::now() < deadline, "the pass compacts the cold logs"); + std::thread::sleep(Duration::from_millis(5)); + } + host.shutdown_blocking().unwrap(); + let mut leftovers: Vec = std::fs::read_dir(root.root()) + .unwrap() + .filter_map(|entry| entry.unwrap().file_name().into_string().ok()) + .filter(|name| !name.ends_with(".jsonl") && name.contains(".jsonl")) + .collect(); + leftovers.sort(); + assert_eq!( + leftovers, + ["original-linked.jsonl.orig", "temporary-left.jsonl.orig"], + "this run's originals stay; earlier runs' and every temporary file are gone" + ); + for id in ["temporary-left", "original-linked"] { + assert_eq!( + std::fs::read(path(format!("{id}.jsonl.orig"))).unwrap(), + originals[id] + ); + } + assert_eq!( + std::fs::read(path("renamed.jsonl".into())).unwrap(), + renamed + ); + + let host = start(); + let link = host.link(); + for id in ["temporary-left", "original-linked", "renamed"] { + let log = root.read_log(id); + assert_eq!(log.epoch, 1, "{id}"); + assert_eq!( + Timeline::fold_events(log.records), + conversations[id], + "{id}" + ); + link.subscribe(Subscription { + topic: Topic::SessionEvents { + session_id: id.into(), + }, + after: None, + epoch: None, + }) + .unwrap(); + } + link.command_blocking(Command::ClearRelaunchMarker).unwrap(); + let mut served = HashMap::new(); + while let Ok(envelope) = link.events().try_recv() { + if let (Topic::SessionEvents { session_id }, ServerEvent::SessionSnapshot(window)) = + (envelope.topic, envelope.event) + { + served.insert(session_id, window.epoch); + } + } + assert_eq!( + served, + HashMap::from([ + ("temporary-left".to_string(), 1), + ("original-linked".to_string(), 1), + ("renamed".to_string(), 1), + ]) + ); + smol::block_on(host.update_state_for_test(|state, cx| { + state.record_event( + "renamed", + &AgentEvent::ItemCompleted(ThreadItem { + id: "after-restart".into(), + parent_item_id: None, + content: ItemContent::AssistantMessage { + text: "appended".into(), + }, + }), + cx, + ) + })) + .unwrap(); + host.shutdown_blocking().unwrap(); + assert!( + std::fs::read_dir(root.root()) + .unwrap() + .filter_map(|entry| entry.unwrap().file_name().into_string().ok()) + .all(|name| name.ends_with(".jsonl") || !name.contains(".jsonl")), + "the second start deleted the first start's originals" + ); + for id in ["temporary-left", "original-linked"] { + assert_eq!(root.log_epoch(id), 1, "{id} is not rewritten again"); + } + let renamed = root.read_events("renamed"); + assert!(matches!( + &renamed.last().unwrap().event, + AgentEvent::ItemCompleted(item) if item.id == "after-restart" + )); + assert_eq!( + Timeline::fold_events(renamed[..renamed.len() - 1].to_vec()), + conversations["renamed"] + ); +} + +/// The background pass compacts the logs nobody has open without caching +/// them, and leaves an open log to the live triggers: it is compacted once it +/// is released. +#[test] +fn the_background_pass_leaves_open_logs_to_their_release() { + let cx = &mut TestAppContext::default(); + let store = TestStore::new("compaction-pass"); + for id in ["cold", "open"] { + open_stored_session(&store, id); + persist_streamed_turns(&store, id, 2); + } + let state = cx.new_entity(TestClientState::new((*store).clone())); + state.update(cx, |state, cx| { + state.select_session("open", cx); + state.start_log_compaction(cx); + }); + cx.run_until(|state| state.store.log_epoch("cold") == 1); + state.read(|state| { + assert_eq!(state.store.log_epoch("open"), 0); + assert!(!state.event_records.contains_key("cold")); + }); + state.update(cx, |state, cx| state.park_active(cx)); + cx.run_until(|state| state.store.log_epoch("open") == 1); +} + #[test] fn history_byte_budget_preserves_contiguous_records_and_reports_shrinking() { let cx = &mut TestAppContext::default(); @@ -7583,12 +8162,13 @@ fn history_byte_budget_preserves_contiguous_records_and_reports_shrinking() { .collect(); state .event_records - .insert("large".into(), SessionLog::from_records(records.clone())); + .insert("large".into(), SessionLog::new(0, records.clone())); let subscription = tcode_protocol::Subscription { topic: Topic::SessionEvents { session_id: "large".into(), }, after: None, + epoch: None, }; let mut snapshot = state.subscription_snapshot(&subscription).unwrap(); snapshot.request_id = Some(u64::MAX); @@ -7598,18 +8178,20 @@ fn history_byte_budget_preserves_contiguous_records_and_reports_shrinking() { .len() <= tcode_protocol::MAX_SESSION_HISTORY_BYTES ); - let ServerEvent::SessionSnapshot { + let ServerEvent::SessionSnapshot(tcode_protocol::SessionWindow { from, records: tail, truncated, .. - } = snapshot.event + }) = snapshot.event else { panic!("snapshot") }; assert!(truncated); assert_eq!(tail, records[from as usize..]); - let response = state.session_history_page("large", 10, u32::MAX).unwrap(); + let response = state + .session_history_page("large", 0, 10, u32::MAX) + .unwrap(); let line = tcode_protocol::encode_line(&HostMessage::QueryResult { id: u64::MAX, result: Ok(response.clone()), @@ -7630,15 +8212,16 @@ fn history_byte_budget_preserves_contiguous_records_and_reports_shrinking() { let snapshot = state .subscription_snapshot(&tcode_protocol::Subscription { after: Some(0), + epoch: Some(0), ..subscription }) .unwrap(); - let ServerEvent::SessionSnapshot { + let ServerEvent::SessionSnapshot(tcode_protocol::SessionWindow { from, records: tail, truncated, .. - } = snapshot.event + }) = snapshot.event else { panic!("tail") }; @@ -7651,9 +8234,12 @@ fn history_byte_budget_preserves_contiguous_records_and_reports_shrinking() { }; state .event_records - .insert("large".into(), SessionLog::from_records(records)); + .insert("large".into(), SessionLog::new(0, records)); assert_eq!( - state.session_history_page("large", 10, 1).unwrap_err().code, + state + .session_history_page("large", 0, 10, 1) + .unwrap_err() + .code, "history_record_too_large" ); }); @@ -8035,10 +8621,14 @@ fn history_paging_bench() { session_id: "bench".into(), }, after: None, + epoch: None, }) .unwrap(); let snapshot_elapsed = started.elapsed(); - let ServerEvent::SessionSnapshot { from, total, .. } = snapshot.event else { + let ServerEvent::SessionSnapshot(tcode_protocol::SessionWindow { + epoch, from, total, .. + }) = snapshot.event + else { panic!("snapshot") }; eprintln!("snapshot: {snapshot_elapsed:?} (from {from} of {total} records)"); @@ -8049,6 +8639,7 @@ fn history_paging_bench() { let QueryResponse::SessionHistoryPage { from, records, .. } = state .session_history_page( "bench", + epoch, before, tcode_protocol::SESSION_HISTORY_RECORDS as u32, ) @@ -8221,16 +8812,19 @@ fn history_sends_output_previews_and_reads_whole_outputs_on_request() { state.update(cx, |state, _| { state .event_records - .insert("outputs".into(), SessionLog::from_records(records.clone())); + .insert("outputs".into(), SessionLog::new(0, records.clone())); let snapshot = state .subscription_snapshot(&tcode_protocol::Subscription { topic: Topic::SessionEvents { session_id: "outputs".into(), }, after: None, + epoch: None, }) .unwrap(); - let ServerEvent::SessionSnapshot { records: sent, .. } = snapshot.event else { + let ServerEvent::SessionSnapshot(tcode_protocol::SessionWindow { records: sent, .. }) = + snapshot.event + else { panic!("snapshot") }; let AgentEvent::ItemCompleted(ThreadItem { @@ -8319,9 +8913,9 @@ fn superseded_turn_changes_cross_without_diffs() { state.update(cx, |state, _| { state .event_records - .insert("changes".into(), SessionLog::from_records(records.clone())); + .insert("changes".into(), SessionLog::new(0, records.clone())); let QueryResponse::SessionHistoryPage { records: sent, .. } = - state.session_history_page("changes", 4, 200).unwrap() + state.session_history_page("changes", 0, 4, 200).unwrap() else { panic!("page") }; @@ -8330,10 +8924,7 @@ fn superseded_turn_changes_cross_without_diffs() { }; assert!(changes.iter().all(|change| change.diff.is_none())); assert_eq!(sent[3], records[3]); - assert_eq!( - format!("{:?}", Timeline::fold_events(sent).turns), - format!("{:?}", Timeline::fold_events(records).turns) - ); + assert_eq!(Timeline::fold_events(sent), Timeline::fold_events(records)); }); } @@ -8356,25 +8947,26 @@ fn history_windows_are_byte_budgeted() { state.update(cx, |state, _| { state .event_records - .insert("wide".into(), SessionLog::from_records(records.clone())); + .insert("wide".into(), SessionLog::new(0, records.clone())); let mut snapshot = state .subscription_snapshot(&tcode_protocol::Subscription { topic: Topic::SessionEvents { session_id: "wide".into(), }, after: None, + epoch: None, }) .unwrap(); snapshot.request_id = Some(u64::MAX); let line = tcode_protocol::encode_line(&HostMessage::Event(snapshot.clone())).unwrap(); assert!(line.len() <= tcode_protocol::SESSION_WINDOW_BYTES); - let ServerEvent::SessionSnapshot { + let ServerEvent::SessionSnapshot(tcode_protocol::SessionWindow { from, end, records: sent, truncated, .. - } = snapshot.event + }) = snapshot.event else { panic!("snapshot") }; @@ -8389,12 +8981,12 @@ fn history_windows_are_byte_budgeted() { }; state .event_records - .insert("wide".into(), SessionLog::from_records(huge)); + .insert("wide".into(), SessionLog::new(0, huge)); let QueryResponse::SessionHistoryPage { from, records: sent, .. - } = state.session_history_page("wide", 200, 200).unwrap() + } = state.session_history_page("wide", 0, 200, 200).unwrap() else { panic!("page") }; diff --git a/crates/runtime/src/pipe.rs b/crates/runtime/src/pipe.rs index 440b96fd5..d7c121d91 100644 --- a/crates/runtime/src/pipe.rs +++ b/crates/runtime/src/pipe.rs @@ -22,6 +22,9 @@ pub struct HostServices { pub background_startup_probes: bool, /// Generate AI-authored titles for new threads and explicit regeneration. pub ai_title_generation: bool, + /// Delete what earlier runs' log compactions left behind, then compact + /// the logs that existed at startup, one at a time in the background. + pub compact_existing_logs: bool, /// URL/tokens and the broker receiver stay host-side. Requests reach /// subscribed WebViews through the preview reverse-RPC topic. pub preview: Option, @@ -142,6 +145,9 @@ pub fn spawn_host(store: SessionStore, mut services: HostServices) -> std::io::R state.refresh_provider_usage(&mut cx); state.refresh_provider_status(&mut cx); } + if services.compact_existing_logs { + state.start_log_compaction(&mut cx); + } state.sync_terminal_handles(); let _ = ready_tx.send(()); smol::block_on(host_loop(state, cx, client_rx, mailbox_rx)); @@ -586,10 +592,11 @@ fn dispatch_query( match query { Query::SessionHistoryPage { session_id, + epoch, before, limit, } => { - let result = app.session_history_page(&session_id, before, limit); + let result = app.session_history_page(&session_id, epoch, before, limit); cx.spawn_background(async move { result }) } Query::Hosting { .. } => cx.spawn_background(async { @@ -1134,6 +1141,7 @@ mod tests { session_id: meta.id.clone(), }, after: None, + epoch: None, }) .expect("subscribe to the session"); @@ -1263,6 +1271,7 @@ mod tests { let link = host.link(); link.subscribe(Subscription { after: None, + epoch: None, topic: Topic::Index, }) .unwrap(); @@ -1397,6 +1406,7 @@ mod tests { link.subscribe(Subscription { after: None, + epoch: None, topic: Topic::Index, }) .expect("send subscription"); diff --git a/crates/runtime/src/pipe_p4b_tests.rs b/crates/runtime/src/pipe_p4b_tests.rs index 5a7afeec8..38ba6495b 100644 --- a/crates/runtime/src/pipe_p4b_tests.rs +++ b/crates/runtime/src/pipe_p4b_tests.rs @@ -48,6 +48,7 @@ pub(super) fn fixture() -> (SpawnedHost, HostMux, HostLink, String) { session_id: session_id.clone(), }, after: None, + epoch: None, }) .unwrap(); (host, mux, link, session_id) @@ -71,6 +72,7 @@ fn preview_mux_request_reply_first_responder_and_no_subscriber_timeout() { session_id: session_id.clone(), }, after: None, + epoch: None, }) .unwrap(); client.command_blocking(Command::OpenLatestSession).unwrap(); // subscription barrier @@ -289,6 +291,7 @@ fn import_status_survives_clients_and_gates_new_runs_by_lifecycle() { let events = link.events(); link.subscribe(Subscription { after: None, + epoch: None, topic: Topic::ExternalImport { project_id: project_id.clone(), }, @@ -363,6 +366,7 @@ fn import_status_survives_clients_and_gates_new_runs_by_lifecycle() { let late_events = late.events(); late.subscribe(Subscription { after: None, + epoch: None, topic: Topic::ExternalImport { project_id: project_id.clone(), }, @@ -417,7 +421,11 @@ fn import_finalizes_the_index_before_finished_even_after_the_initiator_disconnec }, ] { watcher - .subscribe(Subscription { after: None, topic }) + .subscribe(Subscription { + after: None, + epoch: None, + topic, + }) .unwrap(); } next(&events, |event| { @@ -504,6 +512,7 @@ fn content_search_is_host_owned_and_survives_appends_limits_and_blank_queries() )]; link.subscribe(Subscription { after: None, + epoch: None, topic: Topic::ExternalImport { project_id: project_id.clone(), }, diff --git a/crates/runtime/src/terminal_replication_tests.rs b/crates/runtime/src/terminal_replication_tests.rs index 0a66db232..83d477c63 100644 --- a/crates/runtime/src/terminal_replication_tests.rs +++ b/crates/runtime/src/terminal_replication_tests.rs @@ -31,6 +31,7 @@ impl Replica { link.subscribe(Subscription { topic: Topic::Terminal { terminal_id }, after: None, + epoch: None, }) .unwrap(); let ServerEvent::TerminalFrame { frame, .. } = next(&events, |event| { @@ -428,6 +429,7 @@ fn two_mux_clients_share_one_grid_and_one_pty() { terminal_id: session.terminal_id, }, after: None, + epoch: None, }) .unwrap(); let mut rejoined = Replica::attach(&second_link, second.events.clone(), session.terminal_id); @@ -455,6 +457,7 @@ fn two_mux_clients_share_one_grid_and_one_pty() { session_id: session.session_id.clone(), }, after: None, + epoch: None, }) .unwrap(); session diff --git a/crates/services/src/export.rs b/crates/services/src/export.rs index 9aacf8a1f..7b4650f7f 100644 --- a/crates/services/src/export.rs +++ b/crates/services/src/export.rs @@ -265,14 +265,15 @@ mod tests { use std::path::PathBuf; use agent::{ - AgentEvent, ItemContent, ItemStatus, PlanStep, PlanStepStatus, ProviderKind, ThreadItem, - TurnStatus, + AgentEvent, DeltaKind, ItemContent, ItemStatus, PlanStep, PlanStepStatus, ProviderKind, + ThreadItem, TurnStatus, }; use tcode_core::project::Project; use tcode_protocol::{ExternalThread, SourceTool}; use super::*; use crate::import::{ImportedThread, prepare_import}; + use crate::store::CompactOutcome; fn temp_root(label: &str) -> PathBuf { std::env::temp_dir().join(format!("tcode-export-{label}-{}", uuid::Uuid::new_v4())) @@ -352,76 +353,95 @@ mod tests { meta } + /// A rewritten log exports its records without the store's layout + /// header, so the export imports like any other. #[test] fn jsonl_export_import_round_trips_folded_timeline() { - let source_root = temp_root("source"); - let destination_root = temp_root("destination"); - let source = SessionStore::open_at(source_root.clone()).unwrap(); - let destination = SessionStore::open_at(destination_root.clone()).unwrap(); - let meta = fixture(&source); - let export_path = source_root.join("thread.jsonl"); - fs::write( - &export_path, - render_thread(&source, &meta, ThreadExportFormat::Jsonl).unwrap(), - ) - .unwrap(); - let exported = fs::read_to_string(&export_path).unwrap(); - let header: serde_json::Value = - serde_json::from_str(exported.lines().next().unwrap()).unwrap(); - assert_eq!(header["type"], "tcode_thread"); - assert_eq!(header["version"], 1); - assert_eq!(header["attachments"], "references_only"); - assert_eq!(header["redaction"], "none"); - assert_eq!( - exported.split_once('\n').unwrap().1.as_bytes(), - source.read_event_log(&meta.id).unwrap() - ); - - let project = Project::from_root(PathBuf::from("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/restored/project")); - let thread = ExternalThread { - source: SourceTool::T3Code, - file: export_path, - external_id: "tcode:session-export-1".into(), - title_hint: None, - last_active_ms: 0, - }; - let ImportedThread { - meta: restored, - event_log, - } = prepare_import(&project, &thread, &HashSet::new()).expect("a Tcode export must import"); - destination - .write_event_log(&restored.id, &event_log) + for rewritten in [false, true] { + let source_root = temp_root("source"); + let destination_root = temp_root("destination"); + let source = SessionStore::open_at(source_root.clone()).unwrap(); + let destination = SessionStore::open_at(destination_root.clone()).unwrap(); + let meta = fixture(&source); + if rewritten { + for (offset, text) in ["The ", "project ", "builds."].iter().enumerate() { + let delta = AgentEvent::Delta { + item_id: "assistant-2".into(), + kind: DeltaKind::AssistantText, + text: (*text).into(), + }; + source + .append_event(&meta.id, 2_000 + offset as u64, &delta) + .unwrap(); + } + let finished = item( + "assistant-2", + ItemContent::AssistantMessage { + text: "The project builds.".into(), + }, + ); + source.append_event(&meta.id, 2_003, &finished).unwrap(); + assert!(matches!( + source.compact_log(&meta.id), + CompactOutcome::Rewritten { .. } + )); + } + let export_path = source_root.join("thread.jsonl"); + fs::write( + &export_path, + render_thread(&source, &meta, ThreadExportFormat::Jsonl).unwrap(), + ) .unwrap(); - assert_ne!(restored.id, meta.id); - assert_eq!(restored.cwd, project.root); - assert_eq!(restored.project_id.as_deref(), Some(project.id.as_str())); - assert_eq!( - restored.imported_from.as_deref(), - Some("tcode:session-export-1") - ); - assert_eq!( - destination.read_event_log(&restored.id).unwrap(), - source.read_event_log(&meta.id).unwrap() - ); - let source_timeline = Timeline::fold_events(source.read_events(&meta.id)); - let restored_timeline = Timeline::fold_events(destination.read_events(&restored.id)); - let summarize = |timeline: &Timeline| { - timeline - .entries - .iter() - .map(|entry| (entry.turn, format!("{:?}", entry.content))) - .collect::>() - }; - assert_eq!(summarize(&source_timeline), summarize(&restored_timeline)); - assert_eq!(source_timeline.plan_steps, restored_timeline.plan_steps); - assert_eq!( - source_timeline.plan_explanation, - restored_timeline.plan_explanation - ); - assert_eq!(source_timeline.turns.len(), restored_timeline.turns.len()); + let exported = fs::read_to_string(&export_path).unwrap(); + let header: serde_json::Value = + serde_json::from_str(exported.lines().next().unwrap()).unwrap(); + assert_eq!(header["type"], "tcode_thread"); + assert_eq!(header["version"], 1); + assert_eq!(header["attachments"], "references_only"); + assert_eq!(header["redaction"], "none"); + let records = exported.split_once('\n').unwrap().1; + assert_eq!(records.as_bytes(), source.read_event_log(&meta.id).unwrap()); + assert!( + records.lines().all(|line| parse_stored_line(line).is_ok()), + "every exported line after the export header is a record" + ); - let _ = fs::remove_dir_all(source_root); - let _ = fs::remove_dir_all(destination_root); + let project = Project::from_root(PathBuf::from("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/restored/project")); + let thread = ExternalThread { + source: SourceTool::T3Code, + file: export_path, + external_id: "tcode:session-export-1".into(), + title_hint: None, + last_active_ms: 0, + }; + let ImportedThread { + meta: restored, + event_log, + } = prepare_import(&project, &thread, &HashSet::new()) + .expect("a Tcode export must import"); + destination + .write_event_log(&restored.id, &event_log) + .unwrap(); + assert_ne!(restored.id, meta.id); + assert_eq!(restored.cwd, project.root); + assert_eq!(restored.project_id.as_deref(), Some(project.id.as_str())); + assert_eq!( + restored.imported_from.as_deref(), + Some("tcode:session-export-1") + ); + assert_eq!( + fs::read(destination_root.join(format!("{}.jsonl", restored.id))).unwrap(), + records.as_bytes(), + "an imported log starts a layout of its own" + ); + assert_eq!( + Timeline::fold_events(destination.read_events(&restored.id)), + Timeline::fold_events(source.read_events(&meta.id)) + ); + + let _ = fs::remove_dir_all(source_root); + let _ = fs::remove_dir_all(destination_root); + } } #[test] diff --git a/crates/services/src/store.rs b/crates/services/src/store.rs index b1b8390b6..9ac62fb9a 100644 --- a/crates/services/src/store.rs +++ b/crates/services/src/store.rs @@ -2,7 +2,10 @@ //! //! Layout (under the platform data dir, e.g. `~/Library/Application Support/tcode/`): //! * `sessions.json` — an [`IndexFile`] containing projects and sessions. -//! * `.jsonl` — append-only `{ ts, event }` records. +//! * `.jsonl` — append-only `{ ts, event }` records. A log that +//! [`SessionStore::compact_log`] rewrote begins with a layout header line; +//! a log without one is layout epoch 0. +//! * `.jsonl.orig` — the log as it was before its first rewrite. //! //! Replay accepts timestamped records and legacy bare [`AgentEvent`] lines, //! then folds [`StoredEvent`]s into a [`tcode_core::session::Timeline`]. @@ -18,6 +21,39 @@ use serde::{Deserialize, Serialize}; use tcode_core::project::{IndexFile, Project, SessionMeta, migrate_index}; use tcode_core::session::StoredEvent; +mod compaction; + +pub use compaction::{CompactOutcome, CompactRejection, MalformedLine}; + +/// The first line of a rewritten log. It lives in the log itself so the +/// records and the epoch they belong to are replaced in one rename and can +/// never disagree after a crash. It is neither an envelope nor a bare event, +/// so it parses as no record. +#[derive(Serialize, Deserialize)] +struct LayoutHeader { + /// How many times the log's records were rewritten in place. + layout_epoch: u64, +} + +/// The layout epoch a log's first line declares, if it is a header. +fn layout_epoch(first_line: &str) -> Option { + serde_json::from_str::(first_line) + .ok() + .map(|header| header.layout_epoch) +} + +/// How many of the log's bytes its layout header line takes; 0 without one. +fn header_len(bytes: &[u8]) -> usize { + let first = bytes + .split(|byte| *byte == b'\n') + .next() + .unwrap_or_default(); + match std::str::from_utf8(first).ok().and_then(layout_epoch) { + Some(_) => (first.len() + 1).min(bytes.len()), + None => 0, + } +} + /// On-disk envelope wrapping each event with its record time. Kept private: /// callers deal in [`StoredEvent`] (which tolerates the legacy bare form). #[derive(Deserialize)] @@ -51,6 +87,15 @@ pub fn encode_event_log<'a>( Ok(log) } +/// A session's event log as one read of its file saw it. +#[derive(Debug, Default)] +pub struct EventLog { + /// The layout `records` are positioned in: the epoch the log's header + /// declares, or 0 for a log without one. + pub epoch: u64, + pub records: Vec, +} + /// Cheap, cloneable handle to the on-disk data directory. #[derive(Debug, Clone)] pub struct SessionStore { @@ -103,10 +148,19 @@ impl SessionStore { self.root.join(format!("{id}.jsonl")) } - /// Read the native event-log bytes without parsing or normalizing them. + fn original_events_path(&self, id: &str) -> PathBuf { + self.root.join(format!("{id}.jsonl.orig")) + } + + /// Read the native event-log records' bytes without parsing or + /// normalizing them. The layout header is the store's, not a record, so + /// it is left out. pub fn read_event_log(&self, id: &str) -> std::io::Result> { match fs::read(self.events_path(id)) { - Ok(bytes) => Ok(bytes), + Ok(mut bytes) => { + bytes.drain(..header_len(&bytes)); + Ok(bytes) + } Err(error) if error.kind() == std::io::ErrorKind::NotFound => Ok(Vec::new()), Err(error) => Err(error), } @@ -362,30 +416,44 @@ impl SessionStore { /// (`{"ts":…,"event":…}`) or a legacy bare event (`{"type":…}`), so logs /// written before the envelope format still replay (with `ts == None`). pub fn read_events(&self, id: &str) -> Vec { + self.read_log(id).records + } + + /// [`SessionStore::read_events`] with the layout the records are in. Both + /// come from one open file, so a rewrite renamed over the log meanwhile + /// cannot pair one layout's epoch with the other's records. + pub fn read_log(&self, id: &str) -> EventLog { #[cfg(any(test, feature = "test-support"))] self.event_reads .fetch_add(1, std::sync::atomic::Ordering::Relaxed); - let path = self.events_path(id); - let Ok(file) = File::open(&path) else { - return Vec::new(); + let mut log = EventLog::default(); + let Ok(file) = File::open(self.events_path(id)) else { + return log; }; - let mut events = Vec::new(); - for line in BufReader::new(file).lines() { + for (number, line) in BufReader::new(file).lines().enumerate() { let Ok(line) = line else { break }; let trimmed = line.trim(); if trimmed.is_empty() { continue; } + if number == 0 + && let Some(epoch) = layout_epoch(trimmed) + { + log.epoch = epoch; + continue; + } match parse_stored_line(trimmed) { - Ok(stored) => events.push(stored), + Ok(stored) => log.records.push(stored), Err(err) => log::warn!("skipping unparseable event in {id}.jsonl: {err}"), } } - events + log } /// Atomically clone one session's append-only event log. A missing source /// is an empty transcript and therefore succeeds without creating a file. + /// The copy is byte for byte, layout header included: it starts in the + /// layout its records are already in. pub fn clone_events(&self, src_id: &str, dst_id: &str) -> std::io::Result<()> { let src = self.events_path(src_id); let data = match fs::read(src) { @@ -400,7 +468,8 @@ impl SessionStore { } /// Remove sessions from the index with one index write, then delete their - /// event logs. Every log is attempted; the first failure is returned. + /// event logs and the originals kept from before a rewrite. Every file is + /// attempted; the first failure is returned. pub fn remove_sessions(&self, ids: &[String]) -> std::io::Result<()> { let removed: HashSet<&str> = ids.iter().map(String::as_str).collect(); let mut file = self.read_file(); @@ -409,11 +478,13 @@ impl SessionStore { self.persist_index(&file)?; let mut result = Ok(()); for id in removed { - match fs::remove_file(self.events_path(id)) { - Err(err) if err.kind() != std::io::ErrorKind::NotFound && result.is_ok() => { - result = Err(err); + for path in [self.events_path(id), self.original_events_path(id)] { + match fs::remove_file(path) { + Err(err) if err.kind() != std::io::ErrorKind::NotFound && result.is_ok() => { + result = Err(err); + } + _ => {} } - _ => {} } } result diff --git a/crates/services/src/store/compaction.rs b/crates/services/src/store/compaction.rs new file mode 100644 index 000000000..5b816eb3b --- /dev/null +++ b/crates/services/src/store/compaction.rs @@ -0,0 +1,470 @@ +use std::fs::{self, File}; +use std::io::{BufRead, BufReader, Write}; +use std::ops::Range; +use std::path::Path; + +use tcode_core::session::{CompactedRecord, StoredEvent, Timeline, compact_records}; +use tcode_protocol::{MAX_SESSION_HISTORY_BYTES, SESSION_WINDOW_BYTES}; + +use super::{LayoutHeader, SessionStore, encode_record, layout_epoch, parse_stored_line}; + +/// The most delta text one merged record carries: no more than one history +/// reply aims for, so a merged record never crowds out its neighbours. +const MAX_MERGED_TEXT: usize = SESSION_WINDOW_BYTES; + +// JSON escapes a control character as six bytes, so even the worst merged +// text crosses as one history reply. +const _: () = assert!(6 * MAX_MERGED_TEXT < MAX_SESSION_HISTORY_BYTES); + +#[derive(Debug)] +pub enum CompactOutcome { + /// The log now holds the compacted records under the next layout epoch: + /// `before` bytes became `after`. + Rewritten { before: u64, after: u64 }, + /// Nothing compacts; the log was not touched. + Unchanged, + /// The log was left byte for byte as it was. + Rejected(CompactRejection), +} + +#[derive(Debug)] +pub enum CompactRejection { + /// A line of the log is not a complete record: `line` is 1-based. + Malformed { + line: usize, + reason: MalformedLine, + }, + /// The compacted records do not fold as the log does. + Gate, + Io(std::io::Error), +} + +#[derive(Debug)] +pub enum MalformedLine { + NotUtf8, + /// The log does not end in a line break: its last write was cut short. + Truncated, + Blank, + Unparseable, +} + +/// A log read strictly: every line is a record, except a layout header first. +struct StrictLog { + epoch: u64, + records: Vec, + /// Where each record's line sits in the log, line break excluded. + lines: Vec>, +} + +impl SessionStore { + /// Rewrite a session's log so that it holds fewer records that fold + /// exactly as the old ones do ([`compact_records`]), as a whole new file + /// renamed over the old one. Any line that is not a complete record + /// leaves the log untouched, as does a result that does not fold equal + /// to the log. The first rewrite keeps the log as it was in + /// `.jsonl.orig`, and every rewrite bumps the layout epoch. + /// + /// Appends that land between the read and the rename are lost, so the + /// caller must not run it beside a writer of the same log. + pub fn compact_log(&self, id: &str) -> CompactOutcome { + let path = self.events_path(id); + let bytes = match fs::read(&path) { + Ok(bytes) => bytes, + Err(error) => return CompactOutcome::Rejected(CompactRejection::Io(error)), + }; + let log = match read_strict(&bytes) { + Ok(log) => log, + Err((line, reason)) => { + return CompactOutcome::Rejected(CompactRejection::Malformed { line, reason }); + } + }; + let original = Timeline::fold_stored(&log.records); + let compacted = compact_records(&log.records, MAX_MERGED_TEXT); + if compacted.len() == log.records.len() { + return CompactOutcome::Unchanged; + } + + let epoch = log.epoch + 1; + let mut body = serde_json::to_vec(&LayoutHeader { + layout_epoch: epoch, + }) + .expect("serializable header"); + body.push(b'\n'); + let mut fold = Timeline::default(); + for record in &compacted { + match record { + CompactedRecord::Kept(index) => { + body.extend_from_slice(&bytes[log.lines[*index].clone()]); + fold.apply_stored(&log.records[*index]); + } + // The gate folds what will be read back, not what was meant. + CompactedRecord::Merged(merged) => { + let line = match encode_stored(merged) { + Ok(line) => line, + Err(error) => return CompactOutcome::Rejected(CompactRejection::Io(error)), + }; + let Ok(read_back) = parse_stored_line(&line) else { + return CompactOutcome::Rejected(CompactRejection::Gate); + }; + body.extend_from_slice(line.as_bytes()); + fold.apply_stored(&read_back); + } + } + body.push(b'\n'); + } + if fold != original { + return CompactOutcome::Rejected(CompactRejection::Gate); + } + if let Err(error) = self.install_compacted(id, &body, log.epoch == 0) { + return CompactOutcome::Rejected(CompactRejection::Io(error)); + } + CompactOutcome::Rewritten { + before: bytes.len() as u64, + after: body.len() as u64, + } + } + + /// The layout epoch the session's log declares, read from its first line + /// alone: 0 for a log never rewritten, or one that is missing. + pub fn log_epoch(&self, id: &str) -> u64 { + let Ok(file) = File::open(self.events_path(id)) else { + return 0; + }; + let mut first = String::new(); + match BufReader::new(file).read_line(&mut first) { + Ok(_) => layout_epoch(first.trim()).unwrap_or(0), + Err(_) => 0, + } + } + + /// Delete what rewrites leave beside the logs: the originals they kept, + /// and the temporary files of rewrites a crash cut short. An original is + /// kept until the next successful start, so this runs before the run + /// rewrites anything; it would delete the run's own originals after that. + /// Every file is attempted; the first failure is returned. + pub fn discard_compaction_leftovers(&self) -> std::io::Result<()> { + let mut result = Ok(()); + for entry in fs::read_dir(&self.root)? { + let path = entry?.path(); + let leftover = path + .file_name() + .and_then(|name| name.to_str()) + .is_some_and(|name| { + [".jsonl.orig", ".jsonl.compacting", ".jsonl.orig.tmp"] + .iter() + .any(|suffix| name.ends_with(suffix)) + }); + if leftover + && let Err(error) = fs::remove_file(&path) + && error.kind() != std::io::ErrorKind::NotFound + && result.is_ok() + { + result = Err(error); + } + } + result + } + + /// Durably replace the log with `body`, first keeping the log as it is + /// now as the original when asked to and none is kept yet. + fn install_compacted(&self, id: &str, body: &[u8], keep_original: bool) -> std::io::Result<()> { + let path = self.events_path(id); + let temporary = path.with_extension("jsonl.compacting"); + let installed = (|| { + let mut file = File::create(&temporary)?; + file.write_all(body)?; + file.sync_all()?; + drop(file); + if keep_original { + keep(&path, &self.original_events_path(id))?; + sync_directory(&self.root)?; + } + fs::rename(&temporary, &path)?; + sync_directory(&self.root) + })(); + if installed.is_err() { + let _ = fs::remove_file(&temporary); + } + installed + } +} + +/// Keep `path` as it is now at `original`, unless an original is already +/// there: an earlier rewrite that never got to its rename already kept the +/// log, and nothing has been rewritten since. +fn keep(path: &Path, original: &Path) -> std::io::Result<()> { + match fs::hard_link(path, original) { + Ok(()) => Ok(()), + Err(error) if error.kind() == std::io::ErrorKind::AlreadyExists => Ok(()), + // A file system without hard links gets a copy instead. + Err(_) => { + let copy = original.with_extension("orig.tmp"); + fs::copy(path, ©)?; + File::open(©)?.sync_all()?; + fs::rename(copy, original) + } + } +} + +/// Make the directory's entries durable: a rename is not until its directory +/// is synced. Windows offers no directory handle to sync. +fn sync_directory(directory: &Path) -> std::io::Result<()> { + #[cfg(unix)] + File::open(directory)?.sync_all()?; + #[cfg(not(unix))] + let _ = directory; + Ok(()) +} + +/// Encode a record in the form it was read in: an envelope, or the legacy +/// bare event when it has no time. +fn encode_stored(record: &StoredEvent) -> std::io::Result { + match record.ts { + Some(ts) => encode_record(ts, &record.event), + None => serde_json::to_string(&record.event) + .map_err(|e| std::io::Error::new(std::io::ErrorKind::InvalidData, e)), + } +} + +/// Read `bytes` whole, or name the first line (1-based) that is not a record. +fn read_strict(bytes: &[u8]) -> Result { + let text = std::str::from_utf8(bytes).map_err(|error| { + let line = bytes[..error.valid_up_to()] + .iter() + .filter(|byte| **byte == b'\n') + .count(); + (line + 1, MalformedLine::NotUtf8) + })?; + let mut log = StrictLog { + epoch: 0, + records: Vec::new(), + lines: Vec::new(), + }; + let mut start = 0; + for (number, line) in text.split_inclusive('\n').enumerate() { + let range = start..start + line.len(); + start = range.end; + let Some(line) = line.strip_suffix('\n') else { + return Err((number + 1, MalformedLine::Truncated)); + }; + let trimmed = line.trim(); + if trimmed.is_empty() { + return Err((number + 1, MalformedLine::Blank)); + } + if number == 0 + && let Some(epoch) = layout_epoch(trimmed) + { + log.epoch = epoch; + continue; + } + let record = + parse_stored_line(trimmed).map_err(|_| (number + 1, MalformedLine::Unparseable))?; + log.records.push(record); + log.lines.push(range.start..range.end - 1); + } + Ok(log) +} + +#[cfg(test)] +mod tests { + use agent::{AgentEvent, DeltaKind, ItemContent, ThreadItem, TurnStatus}; + + use super::*; + + fn temp_store() -> SessionStore { + let root = std::env::temp_dir().join(format!("tcode-compact-{}", uuid::Uuid::new_v4())); + SessionStore::open_at(root).unwrap() + } + + fn at(ts: u64, event: AgentEvent) -> StoredEvent { + StoredEvent { + ts: Some(ts), + event, + elided: None, + } + } + + /// A turn whose answer streamed as three deltas, from `ts` on. + fn streamed_turn(ts: u64) -> Vec { + let delta = |text: &str| AgentEvent::Delta { + item_id: format!("answer-{ts}"), + kind: DeltaKind::AssistantText, + text: text.into(), + }; + vec![ + at( + ts, + AgentEvent::TurnStarted { + turn_id: format!("turn-{ts}"), + }, + ), + at(ts + 1, delta("one ")), + at(ts + 2, delta("two ")), + at(ts + 3, delta("three")), + at( + ts + 4, + AgentEvent::ItemCompleted(ThreadItem { + id: format!("answer-{ts}"), + parent_item_id: None, + content: ItemContent::AssistantMessage { + text: "one two three".into(), + }, + }), + ), + at( + ts + 5, + AgentEvent::TurnCompleted { + turn_id: format!("turn-{ts}"), + status: TurnStatus::Completed, + usage: None, + }, + ), + ] + } + + fn append(store: &SessionStore, id: &str, records: &[StoredEvent]) { + for record in records { + store + .append_event(id, record.ts.unwrap(), &record.event) + .unwrap(); + } + } + + /// The tolerant reader skips what it cannot parse; a rewrite from such a + /// read would silently delete those lines. + #[test] + fn a_log_with_any_line_that_is_not_a_record_is_left_untouched() { + let turn = streamed_turn(1); + let records = + crate::store::encode_event_log(turn.iter().map(|r| (r.ts.unwrap(), &r.event))).unwrap(); + // The six records with `line` inserted before the record at `index`. + let inserted = |index: usize, line: &[u8]| -> Vec { + let at = records + .split_inclusive(|byte| *byte == b'\n') + .take(index) + .map(<[u8]>::len) + .sum(); + [&records[..at], line, &records[at..]].concat() + }; + let class = |reason: &MalformedLine| match reason { + MalformedLine::NotUtf8 => "not UTF-8", + MalformedLine::Truncated => "truncated", + MalformedLine::Blank => "blank", + MalformedLine::Unparseable => "unparseable", + }; + let cases = [ + ( + "cut short", + records[..records.len() - 1].to_vec(), + 6, + "truncated", + ), + ( + "unknown event", + inserted(2, b"{\"ts\":9,\"event\":{\"type\":\"not_an_event\"}}\n"), + 3, + "unparseable", + ), + ("blank line", inserted(1, b"\n"), 2, "blank"), + ("not UTF-8", inserted(1, &[0xff]), 2, "not UTF-8"), + ( + "layout header after the first line", + inserted(1, b"{\"layout_epoch\":3}\n"), + 2, + "unparseable", + ), + ]; + for (label, log, expected_line, expected_class) in cases { + let store = temp_store(); + fs::write(store.events_path("s"), &log).unwrap(); + match store.compact_log("s") { + CompactOutcome::Rejected(CompactRejection::Malformed { line, reason }) => { + assert_eq!( + (line, class(&reason)), + (expected_line, expected_class), + "{label}" + ); + } + outcome => panic!("{label}: {outcome:?}"), + } + assert_eq!(fs::read(store.events_path("s")).unwrap(), log, "{label}"); + let files: Vec<_> = fs::read_dir(store.root()).unwrap().collect(); + assert_eq!(files.len(), 1, "{label}: nothing but the log"); + fs::remove_dir_all(store.root()).unwrap(); + } + } + + /// A rewritten log carries its layout epoch in a first line that every + /// reader of records skips; appends continue after it, and a clone starts + /// in the same layout. + #[test] + fn a_rewritten_log_reads_appends_and_clones_under_its_layout_header() { + let store = temp_store(); + let turn = streamed_turn(1); + append(&store, "s", &turn); + assert!(matches!( + store.compact_log("s"), + CompactOutcome::Rewritten { .. } + )); + let next = streamed_turn(10); + append(&store, "s", &next[..1]); + + let mut merged = turn[1].clone(); + merged.event = AgentEvent::Delta { + item_id: "answer-1".into(), + kind: DeltaKind::AssistantText, + text: "one two three".into(), + }; + let expected = vec![ + turn[0].clone(), + merged, + turn[4].clone(), + turn[5].clone(), + next[0].clone(), + ]; + assert_eq!(store.read_events("s"), expected); + let log = fs::read_to_string(store.events_path("s")).unwrap(); + assert_eq!(log.lines().next(), Some(r#"{"layout_epoch":1}"#)); + assert_eq!( + store.read_event_log("s").unwrap(), + log.split_once('\n').unwrap().1.as_bytes() + ); + + store.clone_events("s", "fork").unwrap(); + assert_eq!(fs::read(store.events_path("fork")).unwrap(), log.as_bytes()); + assert_eq!(store.read_events("fork"), expected); + fs::remove_dir_all(store.root()).unwrap(); + } + + /// The log as it was before its first rewrite is kept beside it; later + /// rewrites never replace it, and removing the session removes it. + #[test] + fn the_first_rewrite_keeps_the_original_until_the_session_is_removed() { + let store = temp_store(); + append(&store, "s", &streamed_turn(1)); + let original = fs::read(store.events_path("s")).unwrap(); + assert!(matches!( + store.compact_log("s"), + CompactOutcome::Rewritten { .. } + )); + assert_eq!(store.log_epoch("s"), 1); + append(&store, "s", &streamed_turn(10)); + assert!(matches!( + store.compact_log("s"), + CompactOutcome::Rewritten { .. } + )); + assert_eq!(store.log_epoch("s"), 2); + let compacted = fs::read(store.events_path("s")).unwrap(); + assert!(matches!(store.compact_log("s"), CompactOutcome::Unchanged)); + assert_eq!(fs::read(store.events_path("s")).unwrap(), compacted); + assert_eq!(fs::read(store.original_events_path("s")).unwrap(), original); + + store.remove_sessions(&["s".to_string()]).unwrap(); + assert_eq!( + fs::read_dir(store.root()).unwrap().count(), + 1, + "only the index" + ); + fs::remove_dir_all(store.root()).unwrap(); + } +} diff --git a/crates/ui/src/chat/model.rs b/crates/ui/src/chat/model.rs index fe68ff591..5e35478d8 100644 --- a/crates/ui/src/chat/model.rs +++ b/crates/ui/src/chat/model.rs @@ -1402,7 +1402,9 @@ pub(crate) enum ListSync { /// spliced in where they stand, which is how the list keeps the reader's /// anchor across a steer landing mid-turn or a page arriving above. Rows /// that vanish or trade places reset the list, except inside the partial -/// first turn, whose entries a page may merge or shift. +/// first turn, whose entries a page may merge or shift, and above every row +/// that survives: a baseline replacing the held records can start later than +/// the pages the client had loaded. fn list_sync_with<'a>( old: &[TimelineRow], new_len: usize, @@ -1438,11 +1440,13 @@ fn list_sync_with<'a>( let mut splices: Vec<(Range, usize)> = Vec::new(); let mut remeasure = Vec::new(); let mut carried = Vec::new(); + let mut aligned = false; let (mut i, mut j) = (0, 0); while i < old.len() || j < new_len { if i < old.len() && j < new_len { let (old_row, new_row) = (&old[i], new_at(j)); if old_row.identity == new_row.identity { + aligned = true; if old_row.content != new_row.content || old_row.entry_count != new_row.entry_count { remeasure.push(j); @@ -1476,7 +1480,21 @@ fn list_sync_with<'a>( || row.part != RowPart::Segment }; if !replaceable(&old[i]) { - return ListSync::Reset { count: new_len }; + let below_survives = old[i..] + .iter() + .any(|row| new_pos.contains_key(&row.identity)); + if aligned || j > 0 || !below_survives { + return ListSync::Reset { count: new_len }; + } + let start = i; + while !new_pos.contains_key(&old[i].identity) { + i += 1; + } + match splices.last_mut() { + Some((dropped, 0)) if dropped.end == start => dropped.end = i, + _ => splices.push((start..i, 0)), + } + continue; } let start = i; while i < old.len() && !new_pos.contains_key(&old[i].identity) && replaceable(&old[i]) { @@ -1887,6 +1905,34 @@ mod tests { ) }], }); + scenarios.push(Scenario { + name: "baseline after loaded pages", + initial: Snapshot::new( + 4, + vec![ + entry("paged", assistant("an earlier page")), + at_turn(entry("paged-later", assistant("a later page")), 1), + at_turn(entry("kept-user", user_item("question")), 2), + at_turn(entry("kept", assistant("answer")), 2), + at_turn(entry("newest", assistant("latest")), 3), + ], + ), + steps: vec![Step { + continuity: TimelineContinuity::PartialFirstTurn, + ..step( + "drop the pages above the baseline", + Snapshot::new( + 2, + vec![ + entry("kept-user", user_item("question")), + entry("kept", assistant("answer")), + at_turn(entry("newest", assistant("latest")), 1), + ], + ), + incremental(vec![(0..2, 0)], vec![]), + ) + }], + }); for (name, continuity, expected) in [ ( "merge inside partial turn", diff --git a/crates/ui/src/shell.rs b/crates/ui/src/shell.rs index 699df4f9c..98c6c536f 100644 --- a/crates/ui/src/shell.rs +++ b/crates/ui/src/shell.rs @@ -2764,14 +2764,15 @@ mod tests { Topic::SessionEvents { session_id: "thread-a".into(), }, - ServerEvent::SessionSnapshot { + ServerEvent::SessionSnapshot(tcode_protocol::SessionWindow { + epoch: 0, from: 0, end: 0, records: Vec::new(), total: 0, total_turns: 0, truncated: false, - }, + }), ), ] { host.incoming @@ -2904,7 +2905,8 @@ mod tests { Topic::SessionEvents { session_id: "thread-a".into(), }, - ServerEvent::SessionSnapshot { + ServerEvent::SessionSnapshot(tcode_protocol::SessionWindow { + epoch: 0, from: 1800, end: 2000, records: (0..200) @@ -2918,7 +2920,7 @@ mod tests { total: 2000, total_turns: 1, truncated: false, - }, + }), ), ] { host.incoming @@ -3059,14 +3061,15 @@ mod tests { Topic::SessionEvents { session_id: "thread-a".into(), }, - ServerEvent::SessionSnapshot { + ServerEvent::SessionSnapshot(tcode_protocol::SessionWindow { + epoch: 0, from: 0, end: 0, records: Vec::new(), total: 0, total_turns: 0, truncated: false, - }, + }), ), ] { host.incoming @@ -3352,14 +3355,15 @@ mod tests { Topic::SessionEvents { session_id: "thread-a".into(), }, - ServerEvent::SessionSnapshot { + ServerEvent::SessionSnapshot(tcode_protocol::SessionWindow { + epoch: 0, total: 0, total_turns: 0, truncated: false, from: 0, end: 0, records: vec![], - }, + }), ), ] { host.incoming @@ -3511,14 +3515,15 @@ mod tests { Topic::SessionEvents { session_id: session.into(), }, - ServerEvent::SessionSnapshot { + ServerEvent::SessionSnapshot(tcode_protocol::SessionWindow { + epoch: 0, total: 0, total_turns: 0, truncated: false, from: 0, end: 0, records: vec![], - }, + }), ), ] { host.incoming @@ -3648,14 +3653,15 @@ mod tests { topic: Topic::SessionEvents { session_id: "thread-a".into(), }, - event: ServerEvent::SessionSnapshot { + event: ServerEvent::SessionSnapshot(tcode_protocol::SessionWindow { + epoch: 0, total: 0, total_turns: 0, truncated: false, from: 0, end: 0, records: vec![], - }, + }), })) .unwrap(), ) @@ -4961,7 +4967,8 @@ mod tests { Topic::SessionEvents { session_id: session.into(), }, - ServerEvent::SessionSnapshot { + ServerEvent::SessionSnapshot(tcode_protocol::SessionWindow { + epoch: 0, total: 0, total_turns: 0, truncated: false, @@ -4980,7 +4987,7 @@ mod tests { } .into(), ], - }, + }), ), ]; for (topic, event) in events { diff --git a/crates/ui/src/store/history.rs b/crates/ui/src/store/history.rs index 86439cbad..4128bd71a 100644 --- a/crates/ui/src/store/history.rs +++ b/crates/ui/src/store/history.rs @@ -71,6 +71,7 @@ impl WorkspaceStore { } let session_id = self.selected_session_id.clone().expect("selected history"); let before = self.session_from[&session_id]; + let epoch = self.session_epoch[&session_id]; let generation = self.selection_generation; let host = self.host.clone(); self.history_error = None; @@ -78,6 +79,7 @@ impl WorkspaceStore { let result = host .query(Query::SessionHistoryPage { session_id: session_id.clone(), + epoch, before, limit: tcode_protocol::SESSION_HISTORY_RECORDS as u32, }) @@ -86,7 +88,19 @@ impl WorkspaceStore { if store.selection_generation != generation { return false; } + let held_epoch = store.session_epoch.get(&session_id).copied(); match result { + // The held records moved to another layout while the + // request was out; its positions mean nothing there. + Ok(QueryResponse::SessionHistoryPage { epoch, .. }) if Some(epoch) != held_epoch => {} + Ok(QueryResponse::SessionHistoryReset(window)) => { + if Some(window.epoch) != held_epoch { + let topic = tcode_protocol::Topic::SessionEvents { + session_id: session_id.clone(), + }; + store.apply_session_window(&topic, &window); + } + } Ok(QueryResponse::SessionHistoryPage { records, from, end, .. }) if from < before diff --git a/crates/ui/src/store/intents.rs b/crates/ui/src/store/intents.rs index 7bb51b376..7b02e36d7 100644 --- a/crates/ui/src/store/intents.rs +++ b/crates/ui/src/store/intents.rs @@ -255,9 +255,11 @@ impl WorkspaceStore { }, tcode_protocol::Topic::GitStatus { session_id }, ] { - let _ = self - .host - .unsubscribe(tcode_protocol::Subscription { topic, after: None }); + let _ = self.host.unsubscribe(tcode_protocol::Subscription { + topic, + after: None, + epoch: None, + }); } } self.session_status_replica = None; @@ -295,7 +297,9 @@ impl WorkspaceStore { .unwrap_or_default(); self.session_records.entry(session_id.clone()).or_default(); self.session_replica = None; - let after = self.session_end.get(&session_id).copied(); + // A position is a cursor only with the layout it is in. + let epoch = self.session_epoch.get(&session_id).copied(); + let after = epoch.and(self.session_end.get(&session_id).copied()); for topic in [ tcode_protocol::Topic::SessionStatus { session_id: session_id.clone(), @@ -317,12 +321,10 @@ impl WorkspaceStore { { continue; } + let events = matches!(topic, tcode_protocol::Topic::SessionEvents { .. }); let _ = self.host.subscribe(tcode_protocol::Subscription { - after: if matches!(topic, tcode_protocol::Topic::SessionEvents { .. }) { - after - } else { - None - }, + after: after.filter(|_| events), + epoch: epoch.filter(|_| events), topic, }); } diff --git a/crates/ui/src/store/mod.rs b/crates/ui/src/store/mod.rs index bcd65699e..236e7d2e0 100644 --- a/crates/ui/src/store/mod.rs +++ b/crates/ui/src/store/mod.rs @@ -27,7 +27,7 @@ use tcode_protocol::{ Command, CommandResponse, EventEnvelope, ExternalImportStatus, ExternalThread, GitDiffResult, GitDiffScope, GitStatusStatus, IndexSummary, PathEntry, ProtocolError, ProviderVersionStatus, ProvidersStatus, Query, QueryResponse, RecentDir, ServerEvent, SessionSearchHit, SessionStatus, - Subscription, TerminalFrame, Topic, + SessionWindow, Subscription, TerminalFrame, Topic, }; pub(crate) mod terminal; pub(crate) use terminal::ClientTerminal; @@ -173,6 +173,8 @@ pub struct WorkspaceStore { /// records, so the range can be longer than the records. session_from: HashMap, session_end: HashMap, + /// The layout `session_from` and `session_end` are positions in. + session_epoch: HashMap, selection_generation: u64, session_turn_offset: usize, history_task: Option>, @@ -351,6 +353,7 @@ impl WorkspaceStore { session_records: HashMap::new(), session_from: HashMap::new(), session_end: HashMap::new(), + session_epoch: HashMap::new(), selection_generation: 0, session_turn_offset: 0, history_task: None, @@ -383,6 +386,7 @@ impl WorkspaceStore { for topic in &seed_topics { if let Err(error) = host.subscribe(Subscription { after: None, + epoch: None, topic: topic.clone(), }) { log::error!("failed to subscribe to {topic:?}: {}", error.message); @@ -391,6 +395,7 @@ impl WorkspaceStore { let _ = host.subscribe(Subscription { topic: Topic::RuntimeEvents, after: None, + epoch: None, }); let events = host.events(); #[cfg(not(target_family = "wasm"))] @@ -991,76 +996,55 @@ impl WorkspaceStore { { self.history_error = Some(history::history_error_message(error.clone())); } + (Topic::SessionEvents { session_id }, ServerEvent::SessionSnapshot(window)) => { + if self.selected_session_id.as_ref() == Some(session_id) { + self.apply_session_window(&envelope.topic, window); + } + } ( Topic::SessionEvents { session_id }, - ServerEvent::SessionSnapshot { - from, - end, - records, - total, - total_turns, - .. + ServerEvent::SessionEvent { + epoch, + position, + record, }, ) => { if self.selected_session_id.as_ref() != Some(session_id) { return; } - let held = self.session_records.entry(session_id.clone()).or_default(); - let start = self.session_from.entry(session_id.clone()).or_insert(*from); - let held_end = self.session_end.entry(session_id.clone()).or_insert(*from); - if *from == 0 { - held.clear(); - *start = 0; - *held_end = 0; - } else if *from != *held_end { - held.clear(); - self.session_from.remove(session_id); - self.session_end.remove(session_id); - self.session_replica = None; - self.hydrated_sessions.remove(session_id); - self.baseline_topics.remove(&envelope.topic); - self.session_catching_up = false; - let _ = self.host.subscribe(Subscription { - topic: envelope.topic.clone(), - after: None, - }); - return; - } - if records.is_empty() && *from != 0 && self.session_replica.is_some() { - self.baseline_topics.insert(envelope.topic.clone()); - self.hydrated_sessions.insert(session_id.clone()); + let (Some(&held_epoch), Some(&held_end)) = ( + self.session_epoch.get(session_id), + self.session_end.get(session_id), + ) else { return; - } - held.extend(records.iter().cloned()); - *held_end = *end; - let after = *end; - self.session_catching_up = after < *total; - let _ = self.host.update_after(&envelope.topic, after); + }; if self.session_catching_up { return; } - let mut timeline = self.fold_held_records(session_id); - self.baseline_topics.insert(envelope.topic.clone()); - self.hydrated_sessions.insert(session_id.clone()); - self.session_turn_offset = - (*total_turns as usize).saturating_sub(timeline.turns.len()); - self.settle_running_turn(&mut timeline); - self.session_replica = Some((session_id.clone(), timeline)); - } - (Topic::SessionEvents { session_id }, ServerEvent::SessionEvent(record)) => { - if self.selected_session_id.as_ref() != Some(session_id) { + if *epoch < held_epoch || (*epoch == held_epoch && *position < held_end) { + // From a layout the client already left, or already held. return; } - if self.session_catching_up || !self.session_from.contains_key(session_id) { + if (*epoch, *position) != (held_epoch, held_end) { + // Past a gap, or in a layout the client has not seen: the + // host answers the held cursor with what continues it, or + // with a baseline. + self.session_catching_up = true; + let _ = self.host.subscribe(Subscription { + topic: envelope.topic.clone(), + after: Some(held_end), + epoch: Some(held_epoch), + }); return; } self.session_records .entry(session_id.clone()) .or_default() .push(record.clone()); - let after = self.session_end.get(session_id).map_or(0, |end| end + 1); - self.session_end.insert(session_id.clone(), after); - let _ = self.host.update_after(&envelope.topic, after); + self.session_end.insert(session_id.clone(), held_end + 1); + let _ = self + .host + .update_after(&envelope.topic, held_epoch, held_end + 1); // A new turn means the user moved on; the recovery card for the // stopped one is stale. if matches!(record.event, agent::AgentEvent::TurnStarted { .. }) { @@ -1331,6 +1315,49 @@ impl WorkspaceStore { .is_some_and(|status| status.turn_running) } + /// Apply a window of the selected session's log. Records continuing the + /// held cursor extend the held records; any other window is a baseline + /// that replaces them, older pages included. The replica changes once the + /// records reach the log's end, and in one step, so the conversation never + /// renders empty between the old records and the new. + fn apply_session_window(&mut self, topic: &Topic, window: &SessionWindow) { + let Topic::SessionEvents { session_id } = topic else { + return; + }; + let continues = self.session_epoch.get(session_id) == Some(&window.epoch) + && self.session_end.get(session_id) == Some(&window.from); + if continues + && window.records.is_empty() + && window.from != 0 + && self.session_replica.is_some() + { + self.session_catching_up = false; + self.baseline_topics.insert(topic.clone()); + self.hydrated_sessions.insert(session_id.clone()); + return; + } + let held = self.session_records.entry(session_id.clone()).or_default(); + if !continues { + held.clear(); + self.session_from.insert(session_id.clone(), window.from); + self.session_epoch.insert(session_id.clone(), window.epoch); + } + held.extend(window.records.iter().cloned()); + self.session_end.insert(session_id.clone(), window.end); + self.session_catching_up = window.end < window.total; + let _ = self.host.update_after(topic, window.epoch, window.end); + if self.session_catching_up { + return; + } + let mut timeline = self.fold_held_records(session_id); + self.baseline_topics.insert(topic.clone()); + self.hydrated_sessions.insert(session_id.clone()); + self.session_turn_offset = + (window.total_turns as usize).saturating_sub(timeline.turns.len()); + self.settle_running_turn(&mut timeline); + self.session_replica = Some((session_id.clone(), timeline)); + } + fn fold_held_records(&self, session_id: &str) -> Timeline { Timeline::fold_stored(self.session_records.get(session_id).into_iter().flatten()) } @@ -2196,6 +2223,7 @@ impl WorkspaceStore { pub fn watch_external_import(&self, project_id: &str) { if let Err(error) = self.host.subscribe(Subscription { after: None, + epoch: None, topic: Topic::ExternalImport { project_id: project_id.to_string(), }, @@ -2207,6 +2235,7 @@ impl WorkspaceStore { pub fn unwatch_external_import(&mut self, project_id: &str) { let _ = self.host.unsubscribe(Subscription { after: None, + epoch: None, topic: Topic::ExternalImport { project_id: project_id.to_string(), }, @@ -2914,7 +2943,9 @@ mod tests { session::{ReviewComment, ReviewSide}, settings::{Settings, ThemeMode}, }; - use tcode_protocol::{Command, EventEnvelope, ServerEvent, SessionEventRecord, Topic}; + use tcode_protocol::{ + Command, EventEnvelope, QueryResponse, ServerEvent, SessionEventRecord, Topic, + }; use tcode_runtime::host::HostEvent; use tcode_runtime::pipe::{HostServices, SpawnedHost, spawn_host}; use tcode_services::store::SessionStore; @@ -3312,14 +3343,15 @@ mod tests { topic: Topic::SessionEvents { session_id: "one".into(), }, - event: ServerEvent::SessionSnapshot { + event: ServerEvent::SessionSnapshot(tcode_protocol::SessionWindow { + epoch: 0, total: 0, total_turns: 0, truncated: false, from: 0, end: 0, records: vec![], - }, + }), }, cx, ); @@ -3388,14 +3420,15 @@ mod tests { topic: Topic::SessionEvents { session_id: "large".into(), }, - event: ServerEvent::SessionSnapshot { + event: ServerEvent::SessionSnapshot(tcode_protocol::SessionWindow { + epoch: 0, from: 1800, end: 2000, records, total: 2000, total_turns: 500, truncated: false, - }, + }), }, cx, ); @@ -3425,14 +3458,15 @@ mod tests { &EventEnvelope { request_id: None, topic: topic.clone(), - event: ServerEvent::SessionSnapshot { + event: ServerEvent::SessionSnapshot(tcode_protocol::SessionWindow { + epoch: 0, from: 2000, end: 2000, records: vec![], total: 2000, total_turns: 500, truncated: false, - }, + }), }, cx, ); @@ -3486,18 +3520,21 @@ mod tests { event, }; store.apply_domain_event( - &event(ServerEvent::SessionSnapshot { - from: 10, - end: 20, - records: vec![StoredEvent { - ts: Some(1), - event: tool.clone(), - elided: Some(700_000), - }], - total: 20, - total_turns: 1, - truncated: false, - }), + &event(ServerEvent::SessionSnapshot( + tcode_protocol::SessionWindow { + epoch: 0, + from: 10, + end: 20, + records: vec![StoredEvent { + ts: Some(1), + event: tool.clone(), + elided: Some(700_000), + }], + total: 20, + total_turns: 1, + truncated: false, + }, + )), cx, ); assert_eq!( @@ -3509,12 +3546,14 @@ mod tests { Some(Some(700_000)) ); store.apply_domain_event( - &event(ServerEvent::SessionEvent( - agent::AgentEvent::TurnStarted { + &event(ServerEvent::SessionEvent { + epoch: 0, + position: 20, + record: agent::AgentEvent::TurnStarted { turn_id: "next".into(), } .into(), - )), + }), cx, ); assert_eq!(store.session_end["merged"], 21); @@ -3579,7 +3618,8 @@ mod tests { topic: Topic::SessionEvents { session_id: "large".into(), }, - event: ServerEvent::SessionSnapshot { + event: ServerEvent::SessionSnapshot(tcode_protocol::SessionWindow { + epoch: 0, from: 1800, end: 2000, records: (0..200) @@ -3593,7 +3633,7 @@ mod tests { total: 2000, total_turns: 1, truncated: false, - }, + }), }, cx, ); @@ -3696,6 +3736,7 @@ mod tests { tcode_protocol::encode_line(&tcode_protocol::HostMessage::QueryResult { id: request.id, result: Ok(tcode_protocol::QueryResponse::SessionHistoryPage { + epoch: 0, records, from: before - 200, end: before, @@ -3738,6 +3779,259 @@ mod tests { }); } + /// A baseline in a new layout replaces the held records, older pages + /// included, in one step: the conversation never renders empty and nothing + /// is requested again. A page or a live record from the layout it left, + /// arriving after it, is discarded; a live record past a gap asks the host + /// to continue the held cursor; a page answered with a baseline installs it. + #[gpui::test] + fn records_from_a_left_layout_are_discarded_after_a_baseline(cx: &mut TestAppContext) { + use tcode_core::session::StoredEvent; + use tcode_protocol::{ClientPayload, HostMessage, Query, SessionWindow, Subscription}; + let status = draft_status(); + let (to_host, outgoing) = async_channel::unbounded(); + let (incoming, from_host) = async_channel::unbounded(); + let link = tcode_client::HostLink::new(to_host, from_host); + let pump_link = link.clone(); + let executor = cx.background_executor.clone(); + let _pump = cx.background_executor.spawn(async move { + pump_link + .pump_with_timer(|| executor.timer(std::time::Duration::from_millis(25))) + .await; + }); + let workspace = cx.new(|cx| { + WorkspaceStore::new_attached(link, WorkspaceAttachment::Local, None, None, false, cx) + }); + let topic = Topic::SessionEvents { + session_id: "thread".into(), + }; + let turns = |range: std::ops::Range| -> Vec { + range + .flat_map(|turn| { + [ + AgentEvent::TurnStarted { + turn_id: turn.to_string(), + }, + AgentEvent::ItemCompleted(ThreadItem { + id: format!("answer-{turn}"), + parent_item_id: None, + content: ItemContent::AssistantMessage { + text: format!("answer {turn}"), + }, + }), + AgentEvent::TurnCompleted { + turn_id: turn.to_string(), + status: TurnStatus::Completed, + usage: None, + }, + ] + .map(StoredEvent::from) + }) + .collect() + }; + let envelope = |event| EventEnvelope { + request_id: None, + topic: topic.clone(), + event, + }; + let live = |epoch, position, turn: usize| { + envelope(ServerEvent::SessionEvent { + epoch, + position, + record: AgentEvent::TurnStarted { + turn_id: turn.to_string(), + } + .into(), + }) + }; + let sent = |outgoing: &async_channel::Receiver| -> Vec { + std::iter::from_fn(|| outgoing.try_recv().ok()) + .map(|line| tcode_protocol::decode_client_line(&line).unwrap().payload) + .collect() + }; + let answer = |request: u64, result| { + incoming + .try_send( + tcode_protocol::encode_line(&HostMessage::QueryResult { + id: request, + result: Ok(result), + }) + .unwrap(), + ) + .unwrap(); + }; + + workspace.update(cx, |store, cx| { + store.select_session("thread".into()); + store.session_status_replica = Some(status); + store.apply_domain_event( + &envelope(ServerEvent::SessionSnapshot(SessionWindow { + epoch: 0, + from: 300, + end: 600, + records: turns(100..200), + total: 600, + total_turns: 200, + truncated: false, + })), + cx, + ); + }); + sent(&outgoing); + workspace.update(cx, |store, cx| store.update_history_window(1., cx)); + cx.run_until_parked(); + let page = outgoing + .try_recv() + .map(|line| tcode_protocol::decode_client_line(&line).unwrap()) + .unwrap(); + assert!(matches!( + page.payload, + ClientPayload::Query(Query::SessionHistoryPage { + epoch: 0, + before: 300, + .. + }) + )); + + let baseline = turns(150..200); + workspace.update(cx, |store, cx| { + store.apply_domain_event( + &envelope(ServerEvent::SessionSnapshot(SessionWindow { + epoch: 1, + from: 150, + end: 300, + records: baseline.clone(), + total: 300, + total_turns: 200, + truncated: false, + })), + cx, + ); + assert!(!store.session_loading(), "the conversation stays on screen"); + assert_eq!( + store.with_active_timeline(|timeline| timeline.turns.len()), + Some(50) + ); + assert_eq!(store.session_turn_offset, 150); + assert_eq!(store.session_records["thread"], baseline); + assert_eq!( + (store.session_epoch["thread"], store.session_from["thread"]), + (1, 150) + ); + }); + assert_eq!( + sent(&outgoing), + [ClientPayload::Subscribe(Subscription { + topic: topic.clone(), + after: Some(300), + epoch: Some(1), + })], + "the baseline is the reply; the cursor moves to its end" + ); + + answer( + page.id, + tcode_protocol::QueryResponse::SessionHistoryPage { + epoch: 0, + records: turns(0..100), + from: 0, + end: 300, + truncated: false, + }, + ); + cx.run_until_parked(); + workspace.update(cx, |store, cx| { + assert_eq!( + store.session_records["thread"], baseline, + "the old page is dropped" + ); + assert_eq!(store.session_from["thread"], 150); + assert_eq!(store.history_error(), None); + store.apply_domain_event(&live(0, 600, 600), cx); + assert_eq!( + store.session_end["thread"], 300, + "a record of the old layout" + ); + store.apply_domain_event(&live(1, 300, 300), cx); + assert_eq!(store.session_end["thread"], 301); + store.apply_domain_event(&live(1, 300, 300), cx); + assert_eq!(store.session_end["thread"], 301, "a record already held"); + }); + sent(&outgoing); + workspace.update(cx, |store, cx| { + store.apply_domain_event(&live(1, 305, 305), cx); + assert_eq!(store.session_end["thread"], 301); + }); + assert_eq!( + sent(&outgoing), + [ClientPayload::Subscribe(Subscription { + topic: topic.clone(), + after: Some(301), + epoch: Some(1), + })], + "a record past a gap asks for what continues the held cursor" + ); + + workspace.update(cx, |store, cx| { + store.apply_domain_event( + &envelope(ServerEvent::SessionSnapshot(SessionWindow { + epoch: 1, + from: 301, + end: 306, + records: turns(301..306)[..5].to_vec(), + total: 306, + total_turns: 202, + truncated: false, + })), + cx, + ); + assert_eq!(store.session_end["thread"], 306); + }); + cx.executor() + .advance_clock(std::time::Duration::from_millis(250)); + cx.run_until_parked(); + sent(&outgoing); + workspace.update(cx, |store, cx| store.update_history_window(1., cx)); + cx.run_until_parked(); + let page = outgoing + .try_recv() + .map(|line| tcode_protocol::decode_client_line(&line).unwrap()) + .unwrap(); + assert!(matches!( + page.payload, + ClientPayload::Query(Query::SessionHistoryPage { + epoch: 1, + before: 150, + .. + }) + )); + let reset = turns(20..50); + answer( + page.id, + tcode_protocol::QueryResponse::SessionHistoryReset(SessionWindow { + epoch: 2, + from: 60, + end: 150, + records: reset.clone(), + total: 150, + total_turns: 50, + truncated: false, + }), + ); + cx.run_until_parked(); + workspace.read_with(cx, |store, _| { + assert_eq!(store.session_records["thread"], reset); + assert_eq!( + ( + store.session_epoch["thread"], + store.session_from["thread"], + store.session_end["thread"] + ), + (2, 60, 150) + ); + }); + } + fn draft_status() -> tcode_protocol::SessionStatus { let root = scratch_root("tcode-draft-status-test"); let host = test_host(SessionStore::open_at(root.clone()).unwrap()); @@ -3810,14 +4104,15 @@ mod tests { topic: Topic::SessionEvents { session_id: session_id.into(), }, - event: ServerEvent::SessionSnapshot { + event: ServerEvent::SessionSnapshot(tcode_protocol::SessionWindow { + epoch: 0, from, end, records, total: end, total_turns: 1, truncated: from > 0, - }, + }), } } @@ -4041,14 +4336,15 @@ mod tests { Topic::SessionEvents { session_id: "one".into(), }, - ServerEvent::SessionSnapshot { + ServerEvent::SessionSnapshot(tcode_protocol::SessionWindow { + epoch: 0, from: 0, end: 0, records: vec![], total: 0, total_turns: 0, truncated: false, - }, + }), ), ]; store.apply_connection_state(ConnectionState::Reconnecting { @@ -4379,82 +4675,257 @@ mod tests { let _ = std::fs::remove_dir_all(&empty_root); } + /// A phone holds a cursor while its connection is down; meanwhile the + /// host releases the thread and compaction rewrites its log with fewer + /// records, yet more than the phone's position. Reconnecting replays the + /// stale cursor, and the phone must get a baseline in the new layout, not + /// the new layout's records spliced onto its old ones; live records and + /// earlier pages then continue in the new layout, each record once. #[gpui::test] - fn reconnect_and_mismatched_tail_preserve_exactly_one_copy_of_each_record( + fn reconnecting_with_a_cursor_into_a_rewritten_log_replaces_the_held_records( cx: &mut TestAppContext, ) { - let root = scratch_root("p4a-reconnect"); + use tcode_client::ConnectionState; + use tcode_core::session::{StoredEvent, Timeline}; + let root = scratch_root("stale-cursor"); let disk = SessionStore::open_at(root.clone()).unwrap(); let mut meta = SessionMeta::new(ProviderKind::Codex, root.clone(), None); - meta.id = "reconnect".into(); + meta.id = "stale".into(); disk.upsert_metas([&meta]).unwrap(); - let host = test_host(disk); - let workspace = cx.new(|cx| WorkspaceStore::new(host.link(), cx)); - workspace.update(cx, |store, _| store.select_session("reconnect".into())); - wait_until(cx, &workspace, "selected status", |cx| { - workspace.read_with(cx, |store, _| store.session_status_replica.is_some()) - }); - update_host!(&host, |state, cx| { - for (ts, text) in [(1, "one"), (2, "two"), (3, "three")] { - state.record_event_for_replica_test( - "reconnect", - ts, - &AgentEvent::Warning { - message: text.into(), + let delta = |item: &str, text: &str| AgentEvent::Delta { + item_id: item.into(), + kind: agent::DeltaKind::AssistantText, + text: text.into(), + }; + let turn = |index: usize, deltas: &[&str]| { + let answer = format!("answer-{index}"); + let mut events = vec![ + AgentEvent::ItemCompleted(ThreadItem { + id: format!("user-{index}"), + parent_item_id: None, + content: ItemContent::UserMessage { + text: format!("question {index}"), + context_len: None, + attachments: vec![], }, - cx, - ); - } + }), + AgentEvent::TurnStarted { + turn_id: format!("turn-{index}"), + }, + ]; + events.extend(deltas.iter().map(|text| delta(&answer, text))); + events.push(AgentEvent::ItemCompleted(ThreadItem { + id: answer, + parent_item_id: None, + content: ItemContent::AssistantMessage { + text: deltas.concat(), + }, + })); + events.push(AgentEvent::TurnCompleted { + turn_id: format!("turn-{index}"), + status: TurnStatus::Completed, + usage: None, + }); + events + }; + let mut log: Vec = Vec::new(); + let mut record = |event: AgentEvent| { + let stored = StoredEvent { + ts: Some(log.len() as u64 + 1), + event, + elided: None, + }; + log.push(stored.clone()); + stored + }; + // The phone sees the first turn while its answer streams. + let first_turn = turn(0, &["a", "b", "c"]); + for event in &first_turn[..4] { + let stored = record(event.clone()); + disk.append_event("stale", stored.ts.unwrap(), &stored.event) + .unwrap(); + } + + let host = test_host(disk.clone()); + let mux = tcode_traverse::HostMux::new(host.to_host.clone(), host.from_host.clone()); + let (to_host, outgoing) = async_channel::unbounded::(); + let (incoming, from_host) = async_channel::unbounded::(); + let link = tcode_client::HostLink::new(to_host, from_host); + smol::spawn({ + let link = link.clone(); + async move { link.pump().await } + }) + .detach(); + let dial = || { + let connection = mux.attach(); + let (outgoing, incoming) = (outgoing.clone(), incoming.clone()); + [ + smol::spawn(async move { + while let Ok(line) = outgoing.recv().await { + if connection.to_host.send(line).await.is_err() { + break; + } + } + }), + smol::spawn(async move { + while let Ok(line) = connection.from_host.recv().await { + if incoming.send(line).await.is_err() { + break; + } + } + }), + ] + }; + let connection = dial(); + let workspace = cx.new(|cx| WorkspaceStore::new(link.clone(), cx)); + workspace.update(cx, |store, _| store.select_session("stale".into())); + wait_until(cx, &workspace, "the streaming turn", |cx| { + workspace.read_with(cx, |store, _| { + store.session_end.get("stale") == Some(&4) && store.session_replica.is_some() + }) }); - wait_until(cx, &workspace, "three records", |cx| { - workspace.read_with(cx, |store, _| store.session_records["reconnect"].len() == 3) + + link.set_connection_state(ConnectionState::Reconnecting { + attempt: 1, + reason: None, }); - host.link() - .set_connection_state(tcode_client::ConnectionState::Reconnecting { - attempt: 1, - reason: None, - }); - host.link() - .set_connection_state(tcode_client::ConnectionState::Connected { path: None }); - command(&host, Command::ClearRelaunchMarker); - workspace.update(cx, |store, cx| { - store.drain_host_events_for_test(cx); - assert_eq!(store.session_records["reconnect"].len(), 3); - store.apply_domain_event( - &EventEnvelope { - request_id: None, - topic: Topic::SessionEvents { - session_id: "reconnect".into(), - }, - event: ServerEvent::SessionSnapshot { - total: 0, - total_turns: 0, - truncated: false, - from: 2, - end: 2, - records: vec![], - }, - }, - cx, + drop(connection); + // The turn finishes and many more follow while the phone is away. + let mut appended: Vec = + first_turn[4..].iter().cloned().map(&mut record).collect(); + for index in 1..=150 { + appended.extend(turn(index, &["x", "y", "z"]).into_iter().map(&mut record)); + } + let held_position = 4; + update_host!(&host, move |state, cx| { + for stored in &appended { + state.record_event_for_replica_test("stale", stored.ts.unwrap(), &stored.event, cx); + } + }); + // Another device's page request in the phone's layout tells when the + // host has released the log it pinned and serves the rewritten one. + let probe = { + let connection = mux.attach(); + let probe = tcode_client::HostLink::new(connection.to_host, connection.from_host); + smol::spawn({ + let probe = probe.clone(); + async move { probe.pump().await } + }) + .detach(); + probe + }; + let deadline = std::time::Instant::now() + std::time::Duration::from_secs(10); + loop { + let page = smol::block_on(probe.query(tcode_protocol::Query::SessionHistoryPage { + session_id: "stale".into(), + epoch: 0, + before: held_position, + limit: 1, + })); + if matches!(page, Ok(QueryResponse::SessionHistoryReset(_))) { + break; + } + assert!( + std::time::Instant::now() < deadline, + "the released log is served in its rewritten layout" ); + std::thread::sleep(std::time::Duration::from_millis(5)); + } + let rewritten = disk.read_log("stale"); + assert!( + (held_position as usize) < rewritten.records.len() + && rewritten.records.len() < log.len(), + "the rewritten layout is shorter but still holds the phone's position" + ); + let conversation = Timeline::fold_stored(&log); + + let _connection = dial(); + link.set_connection_state(ConnectionState::Connected { path: None }); + wait_until(cx, &workspace, "a baseline in the rewritten layout", |cx| { + workspace.read_with(cx, |store, _| { + store.session_epoch.get("stale") == Some(&rewritten.epoch) + && !store.session_catching_up + }) + }); + workspace.read_with(cx, |store, _| { assert!( - store.session_replica.is_none(), - "invalid tail must request a full replacement" + store.session_from["stale"] > 0, + "the baseline is a recent window" ); + assert_eq!(store.session_end["stale"], rewritten.records.len() as u64); }); - wait_until( - cx, - &workspace, - "full replacement after invalid tail", - |cx| workspace.read_with(cx, |store, _| store.session_records["reconnect"].len() == 3), + // Earlier pages continue from the baseline in its layout. (The store's + // own page task awaits a reply the host thread delivers, which the + // test scheduler forbids; the store's handling of pages is covered + // against a scripted host.) + let (mut held, mut before) = workspace.read_with(cx, |store, _| { + ( + store.session_records["stale"].clone(), + store.session_from["stale"], + ) + }); + while before > 0 { + let Ok(QueryResponse::SessionHistoryPage { + epoch, + records, + from, + end, + .. + }) = smol::block_on(link.query(tcode_protocol::Query::SessionHistoryPage { + session_id: "stale".into(), + epoch: rewritten.epoch, + before, + limit: 200, + })) + else { + panic!("a page in the served layout") + }; + assert_eq!((epoch, end), (rewritten.epoch, before)); + held.splice(0..0, records); + before = from; + } + assert_eq!( + Timeline::fold_stored(&held), + conversation, + "the baseline and every page continue the rewritten layout" ); + + update_host!(&host, |state, cx| { + state.record_event_for_replica_test( + "stale", + 1_000_000, + &AgentEvent::ItemCompleted(ThreadItem { + id: "live".into(), + parent_item_id: None, + content: ItemContent::AssistantMessage { + text: "after the reconnect".into(), + }, + }), + cx, + ) + }); + link.set_connection_state(ConnectionState::Reconnecting { + attempt: 2, + reason: None, + }); + link.set_connection_state(ConnectionState::Connected { path: None }); + // An ack is a FIFO fence through the mux and the host: the replayed + // subscription was answered before it. + link.command_blocking(Command::ClearRelaunchMarker).unwrap(); + let end = rewritten.records.len() as u64 + 1; + wait_until(cx, &workspace, "the live record", |cx| { + workspace.read_with(cx, |store, _| store.session_end["stale"] == end) + }); workspace.read_with(cx, |store, _| { assert_eq!( - store.session_records["reconnect"] + store.session_records["stale"] .iter() - .map(|record| record.ts) - .collect::>(), - vec![Some(1), Some(2), Some(3)] + .filter(|record| matches!( + &record.event, + AgentEvent::ItemCompleted(item) if item.id == "live" + )) + .count(), + 1 ); let subscription = store .host @@ -4462,9 +4933,15 @@ mod tests { .into_iter() .find(|sub| matches!(sub.topic, Topic::SessionEvents { .. })) .unwrap(); - assert_eq!(subscription.after, Some(3)); + assert_eq!( + (subscription.epoch, subscription.after), + (Some(rewritten.epoch), Some(end)), + "the transport replays the cursor in the new layout" + ); }); - shutdown_test_host(&host); + link.shutdown_blocking().unwrap(); + host.to_host.close(); + host.stopped.recv_blocking().unwrap(); let _ = std::fs::remove_dir_all(&root); } @@ -5014,6 +5491,7 @@ mod tests { session_id: second.id.clone(), }, after: None, + epoch: None, }) .unwrap(); for (session_id, text) in [ @@ -5127,20 +5605,15 @@ mod tests { }); let session_id = meta.id.clone(); - update_host!(&host, move |_state, cx| { - cx.emit(HostEvent::Domain(EventEnvelope { - request_id: None, - topic: Topic::SessionEvents { - session_id: session_id.clone(), + update_host!(&host, move |state, cx| { + state.record_event_for_replica_test( + &session_id, + 1, + &AgentEvent::TurnStarted { + turn_id: "turn-next".into(), }, - event: ServerEvent::SessionEvent(SessionEventRecord { - ts: None, - event: AgentEvent::TurnStarted { - turn_id: "turn-next".into(), - }, - elided: None, - }), - })); + cx, + ); }); wait_until( cx, diff --git a/crates/ui/src/store/terminal.rs b/crates/ui/src/store/terminal.rs index b5953b9ae..88d2449c8 100644 --- a/crates/ui/src/store/terminal.rs +++ b/crates/ui/src/store/terminal.rs @@ -231,6 +231,7 @@ impl WorkspaceStore { let _ = self.host.unsubscribe(Subscription { topic: Topic::Terminal { terminal_id: *id }, after: None, + epoch: None, }); } self.terminals.clear(); @@ -249,6 +250,7 @@ impl WorkspaceStore { let _ = self.host.unsubscribe(Subscription { topic: Topic::Terminal { terminal_id: *id }, after: None, + epoch: None, }); false }); @@ -265,6 +267,7 @@ impl WorkspaceStore { let _ = self.host.subscribe(Subscription { topic: Topic::Terminal { terminal_id: id }, after: None, + epoch: None, }); } }