Skip to main content

harness_loop/
replay.rs

1//! Session record + replay (DESIGN.md §15 v0.2+).
2//!
3//! Two halves:
4//! - [`SessionRecorder`] is a [`Hook`] that captures every lifecycle event
5//!   to a JSONL file. Wire it via `AgentLoop::with_hook` and you get a
6//!   complete trace of what the agent did.
7//! - [`read_session`] + [`replay_as_mock`] reconstruct a deterministic
8//!   `MockModel` from a recorded log so you can replay the run offline,
9//!   verify changes, or debug failures without rerunning against a real LLM.
10
11use harness_core::{
12    Action, CompactionStage, Event, Hook, HookOutcome, ModelOutput, ToolResult, World,
13};
14use serde::{Deserialize, Serialize};
15use std::fs::OpenOptions;
16use std::io::Write;
17use std::path::Path;
18use std::sync::Mutex;
19
20/// One event in the recorded session. Owned (no borrows) so it round-trips
21/// through serde without lifetime gymnastics.
22#[derive(Debug, Clone, Serialize, Deserialize)]
23#[serde(tag = "kind", rename_all = "snake_case")]
24pub enum SessionEvent {
25    Start {
26        ts_ms: i64,
27        source: String,
28    },
29    PreModel {
30        ts_ms: i64,
31        history_len: usize,
32        tools_count: usize,
33    },
34    PostModel {
35        ts_ms: i64,
36        output: ModelOutput,
37    },
38    PreTool {
39        ts_ms: i64,
40        action: Action,
41    },
42    PostTool {
43        ts_ms: i64,
44        call_id: String,
45        result: ToolResult,
46    },
47    Sensor {
48        ts_ms: i64,
49        id: String,
50        signals: usize,
51    },
52    PreCompact {
53        ts_ms: i64,
54        stage: CompactionStage,
55    },
56    PostCompact {
57        ts_ms: i64,
58        stage: CompactionStage,
59    },
60    Heartbeat {
61        ts_ms: i64,
62        iter: u32,
63    },
64    /// Budget ratio crossed a high-water threshold. Currently the loop only
65    /// fires this once, at the moment the iteration budget is exhausted and
66    /// the forced final-synthesis pass is about to run.
67    BudgetWarning {
68        ts_ms: i64,
69        ratio: f32,
70    },
71    End {
72        ts_ms: i64,
73    },
74}
75
76/// Hook that serialises every relevant lifecycle event into a JSONL file.
77///
78/// Failures (locked mutex, I/O errors) are logged via `tracing::warn` but
79/// never panic — recording is a best-effort observability layer, not a
80/// correctness path.
81pub struct SessionRecorder {
82    file: Mutex<std::fs::File>,
83}
84
85impl SessionRecorder {
86    /// Open the file for append (creating it if needed).
87    pub fn new(path: &Path) -> std::io::Result<Self> {
88        if let Some(parent) = path.parent() {
89            std::fs::create_dir_all(parent)?;
90        }
91        let f = OpenOptions::new().create(true).append(true).open(path)?;
92        Ok(Self {
93            file: Mutex::new(f),
94        })
95    }
96
97    fn write(&self, ev: &SessionEvent) {
98        let Ok(mut f) = self.file.lock() else {
99            return;
100        };
101        match serde_json::to_string(ev) {
102            Ok(s) => {
103                if let Err(e) = writeln!(f, "{s}") {
104                    tracing::warn!(error=%e, "session recorder write failed");
105                }
106            }
107            Err(e) => tracing::warn!(error=%e, "session recorder serialize failed"),
108        }
109    }
110}
111
112impl Hook for SessionRecorder {
113    fn name(&self) -> &str {
114        "session-recorder"
115    }
116    fn matches(&self, _ev: &Event<'_>) -> bool {
117        true
118    }
119
120    fn fire(&self, ev: &Event<'_>, world: &mut World) -> HookOutcome {
121        let ts = world.clock.now_ms();
122        let session_ev = match ev {
123            Event::SessionStart { source } => Some(SessionEvent::Start {
124                ts_ms: ts,
125                source: format!("{source:?}"),
126            }),
127            Event::PreModel { ctx } => Some(SessionEvent::PreModel {
128                ts_ms: ts,
129                history_len: ctx.history.len(),
130                tools_count: ctx.tools.len(),
131            }),
132            Event::PostModel { out } => Some(SessionEvent::PostModel {
133                ts_ms: ts,
134                output: (*out).clone(),
135            }),
136            Event::PreToolUse { action } => Some(SessionEvent::PreTool {
137                ts_ms: ts,
138                action: (*action).clone(),
139            }),
140            Event::PostToolUse { action, result } => Some(SessionEvent::PostTool {
141                ts_ms: ts,
142                call_id: action.call_id.clone(),
143                result: (*result).clone(),
144            }),
145            Event::PostSensor { sensor, signals } => Some(SessionEvent::Sensor {
146                ts_ms: ts,
147                id: (*sensor).clone(),
148                signals: signals.len(),
149            }),
150            Event::PreCompact { stage } => Some(SessionEvent::PreCompact {
151                ts_ms: ts,
152                stage: *stage,
153            }),
154            Event::PostCompact { stage } => Some(SessionEvent::PostCompact {
155                ts_ms: ts,
156                stage: *stage,
157            }),
158            Event::Heartbeat { iter } => Some(SessionEvent::Heartbeat {
159                ts_ms: ts,
160                iter: *iter,
161            }),
162            Event::BudgetWarning { ratio } => Some(SessionEvent::BudgetWarning {
163                ts_ms: ts,
164                ratio: *ratio,
165            }),
166            Event::SessionEnd => Some(SessionEvent::End { ts_ms: ts }),
167            _ => None,
168        };
169        if let Some(e) = session_ev {
170            self.write(&e);
171        }
172        HookOutcome::Allow
173    }
174}
175
176/// Read a recorded JSONL session log back into memory.
177///
178/// Tolerates malformed lines (logged, skipped) so a partially-corrupted log
179/// still yields usable replay material.
180pub fn read_session(path: &Path) -> std::io::Result<Vec<SessionEvent>> {
181    let content = std::fs::read_to_string(path)?;
182    let mut events = Vec::new();
183    for (i, line) in content.lines().enumerate() {
184        let line = line.trim();
185        if line.is_empty() {
186            continue;
187        }
188        match serde_json::from_str(line) {
189            Ok(e) => events.push(e),
190            Err(err) => tracing::warn!(line=i+1, error=%err, "session log line skipped"),
191        }
192    }
193    Ok(events)
194}
195
196/// Build a [`harness_models::MockModel`] that returns each recorded
197/// `PostModel` output in order. Pair with a fresh `AgentLoop` to replay the
198/// run.
199pub fn replay_as_mock(events: &[SessionEvent]) -> harness_models::MockModel {
200    use harness_models::{MockModel, MockResponse};
201    let mut m = MockModel::new().with_name("replay");
202    for e in events {
203        if let SessionEvent::PostModel { output, .. } = e {
204            m = m.script(MockResponse {
205                text: output.text.clone(),
206                tool_calls: output.tool_calls.clone(),
207                stop_reason: output.stop_reason,
208                input_tokens: output.usage.input_tokens,
209                output_tokens: output.usage.output_tokens,
210                reasoning: output.reasoning.clone(),
211                // Carried so a replay of an image-producing run reproduces
212                // the images too — otherwise "deterministic replay" would
213                // quietly mean "replay of the text only".
214                images: output.images.clone(),
215            });
216        }
217    }
218    m
219}
220
221/// Backwards-compatible alias.
222pub fn replay_as_mock_via_events(events: &[SessionEvent]) -> harness_models::MockModel {
223    replay_as_mock(events)
224}
225
226/// Stats from a single session — handy summary for the `harness trace` CLI.
227#[derive(Debug, Clone, Default)]
228pub struct SessionStats {
229    pub events: usize,
230    pub model_calls: usize,
231    pub tool_calls: usize,
232    pub iters: u32,
233    pub input_tokens: u32,
234    pub output_tokens: u32,
235    pub stages_run: usize,
236    pub duration_ms: i64,
237}
238
239impl SessionStats {
240    pub fn from(events: &[SessionEvent]) -> Self {
241        let mut s = Self {
242            events: events.len(),
243            ..Default::default()
244        };
245        let mut first_ts: Option<i64> = None;
246        let mut last_ts: Option<i64> = None;
247        for e in events {
248            let ts = match e {
249                SessionEvent::Start { ts_ms, .. }
250                | SessionEvent::PreModel { ts_ms, .. }
251                | SessionEvent::PostModel { ts_ms, .. }
252                | SessionEvent::PreTool { ts_ms, .. }
253                | SessionEvent::PostTool { ts_ms, .. }
254                | SessionEvent::Sensor { ts_ms, .. }
255                | SessionEvent::PreCompact { ts_ms, .. }
256                | SessionEvent::PostCompact { ts_ms, .. }
257                | SessionEvent::Heartbeat { ts_ms, .. }
258                | SessionEvent::BudgetWarning { ts_ms, .. }
259                | SessionEvent::End { ts_ms } => *ts_ms,
260            };
261            if first_ts.is_none() {
262                first_ts = Some(ts);
263            }
264            last_ts = Some(ts);
265
266            match e {
267                SessionEvent::PostModel { output, .. } => {
268                    s.model_calls += 1;
269                    s.input_tokens += output.usage.input_tokens;
270                    s.output_tokens += output.usage.output_tokens;
271                }
272                SessionEvent::PreTool { .. } => s.tool_calls += 1,
273                SessionEvent::PostCompact { .. } => s.stages_run += 1,
274                SessionEvent::Heartbeat { iter, .. } => s.iters = s.iters.max(*iter + 1),
275                _ => {}
276            }
277        }
278        s.duration_ms = match (first_ts, last_ts) {
279            (Some(a), Some(b)) => b - a,
280            _ => 0,
281        };
282        s
283    }
284}
285
286/// Multi-line, content-rich version of [`format_event_short`].
287///
288/// Surfaces what `format_event_short` hides: model text, full tool args,
289/// tool result preview, and failure reasons. Used by `harness trace --verbose`
290/// and by [`LiveProgressHook`] so operators can actually see what their agent
291/// is doing instead of guessing from `ok=false`.
292pub fn format_event_verbose(e: &SessionEvent) -> String {
293    match e {
294        SessionEvent::Start { source, .. } => format!("session start ({source})"),
295        SessionEvent::Heartbeat { iter, .. } => format!("iter {iter}"),
296        SessionEvent::PreModel {
297            history_len,
298            tools_count,
299            ..
300        } => format!("→ model (history={history_len}, tools={tools_count})"),
301        SessionEvent::PostModel { output, .. } => {
302            let mut out = format!(
303                "← model: {} tool_call(s) [{}/{} tok, stop={:?}]",
304                output.tool_calls.len(),
305                output.usage.input_tokens,
306                output.usage.output_tokens,
307                output.stop_reason,
308            );
309            if let Some(text) = output.text.as_deref().filter(|s| !s.is_empty()) {
310                out.push_str("\n  text: ");
311                out.push_str(&truncate(text, 400));
312            }
313            if let Some(reasoning) = output.reasoning.as_deref().filter(|s| !s.is_empty()) {
314                out.push_str("\n  reasoning: ");
315                out.push_str(&truncate(reasoning, 200));
316            }
317            out
318        }
319        SessionEvent::PreTool { action, .. } => {
320            let args = action.args.to_string();
321            format!("  → tool {} args={}", action.tool, truncate(&args, 240))
322        }
323        SessionEvent::PostTool {
324            call_id, result, ..
325        } => {
326            let preview = preview_tool_result(result);
327            format!(
328                "  ← tool {} ok={} {}",
329                call_id,
330                result.ok,
331                if preview.is_empty() {
332                    String::new()
333                } else {
334                    format!("\n      {preview}")
335                }
336            )
337        }
338        SessionEvent::Sensor { id, signals, .. } => {
339            format!("  ⚑ sensor {id}: {signals} signal(s)")
340        }
341        SessionEvent::PreCompact { stage, .. } => format!("  ⇩ pre-compact {stage:?}"),
342        SessionEvent::PostCompact { stage, .. } => format!("  ⇧ post-compact {stage:?}"),
343        SessionEvent::BudgetWarning { ratio, .. } => {
344            if *ratio >= 1.0 {
345                "≫ budget exhausted — forcing tool-less final-synthesis pass".into()
346            } else {
347                format!("≫ budget warning (used {:.0}%)", ratio * 100.0)
348            }
349        }
350        SessionEvent::End { .. } => "session end".into(),
351    }
352}
353
354/// Pull the most actionable text out of a [`ToolResult`] for human display.
355///
356/// For failures, prefer `errors`/`hint`/`message` keys if the tool returned a
357/// structured JSON payload (the multi-engine search tool in `investor-bot`
358/// follows this convention). Falls back to a truncated JSON dump.
359fn preview_tool_result(r: &ToolResult) -> String {
360    let v = &r.content;
361    if !r.ok {
362        // Try the common error-shape conventions first.
363        if let Some(errors) = v.get("errors").and_then(|x| x.as_array()) {
364            let joined: Vec<String> = errors
365                .iter()
366                .filter_map(|e| e.as_str().map(String::from))
367                .collect();
368            if !joined.is_empty() {
369                let hint = v
370                    .get("hint")
371                    .and_then(|x| x.as_str())
372                    .map(|h| format!(" | hint: {h}"))
373                    .unwrap_or_default();
374                return format!("errors=[{}]{hint}", truncate(&joined.join("; "), 240));
375            }
376        }
377        if let Some(msg) = v.get("message").and_then(|x| x.as_str()) {
378            return format!("message={}", truncate(msg, 240));
379        }
380        if let Some(err) = v.get("error").and_then(|x| x.as_str()) {
381            return format!("error={}", truncate(err, 240));
382        }
383    }
384    // Generic preview: serialize, trim, truncate.
385    let s = v.to_string();
386    if s == "null" || s == "{}" {
387        String::new()
388    } else {
389        format!("preview={}", truncate(&s, 240))
390    }
391}
392
393fn truncate(s: &str, max: usize) -> String {
394    // Char-wise truncation so we don't bisect a multibyte sequence.
395    let chars: Vec<char> = s.chars().collect();
396    if chars.len() <= max {
397        s.replace('\n', " ⏎ ")
398    } else {
399        let head: String = chars[..max].iter().collect();
400        format!(
401            "{}… ({} chars total)",
402            head.replace('\n', " ⏎ "),
403            chars.len()
404        )
405    }
406}
407
408/// Tiny helper used by the CLI: convert a single event to a single line of
409/// pretty-printed text (does NOT include the timestamp prefix).
410pub fn format_event_short(e: &SessionEvent) -> String {
411    match e {
412        SessionEvent::Start { source, .. } => format!("session start ({source})"),
413        SessionEvent::Heartbeat { iter, .. } => format!("iter {iter}"),
414        SessionEvent::PreModel {
415            history_len,
416            tools_count,
417            ..
418        } => {
419            format!("→ model (history={history_len}, tools={tools_count})")
420        }
421        SessionEvent::PostModel { output, .. } => {
422            let calls = output.tool_calls.len();
423            let txt = output
424                .text
425                .as_deref()
426                .unwrap_or("")
427                .chars()
428                .take(60)
429                .collect::<String>();
430            if calls > 0 {
431                format!(
432                    "← model: {} tool_call(s) [{}/{} tok]",
433                    calls, output.usage.input_tokens, output.usage.output_tokens
434                )
435            } else {
436                format!(
437                    "← model: {:?} [{}/{} tok]",
438                    txt, output.usage.input_tokens, output.usage.output_tokens
439                )
440            }
441        }
442        SessionEvent::PreTool { action, .. } => {
443            format!("  → tool {} args={}", action.tool, action.args)
444        }
445        SessionEvent::PostTool {
446            call_id, result, ..
447        } => {
448            format!("  ← tool {} ok={}", call_id, result.ok)
449        }
450        SessionEvent::Sensor { id, signals, .. } => format!("  ⚑ sensor {id}: {signals} signal(s)"),
451        SessionEvent::PreCompact { stage, .. } => format!("  ⇩ pre-compact {stage:?}"),
452        SessionEvent::PostCompact { stage, .. } => format!("  ⇧ post-compact {stage:?}"),
453        SessionEvent::BudgetWarning { ratio, .. } => {
454            format!("≫ budget warning (used {:.0}%)", ratio * 100.0)
455        }
456        SessionEvent::End { .. } => "session end".into(),
457    }
458}
459
460/// `Hook` that prints a verbose progress trace to stderr in real time.
461///
462/// Pair with `AgentLoop::with_hook(Arc::new(LiveProgressHook::default()))` to
463/// see model calls, tool calls, and tool results as they happen — instead of
464/// staring at a silent terminal for 60 seconds and then post-mortem'ing a JSONL
465/// file. Independent of `SessionRecorder`; both can be installed together.
466///
467/// Output is structured to be greppable: `[iter=N]` prefix on every line, and
468/// each line is one event. Writes go to stderr, so stdout stays clean for
469/// the final answer.
470#[derive(Default)]
471pub struct LiveProgressHook {
472    iter: std::sync::atomic::AtomicU32,
473}
474
475impl LiveProgressHook {
476    pub fn new() -> Self {
477        Self::default()
478    }
479}
480
481impl Hook for LiveProgressHook {
482    fn name(&self) -> &str {
483        "live-progress"
484    }
485    fn matches(&self, _ev: &Event<'_>) -> bool {
486        true
487    }
488    fn fire(&self, ev: &Event<'_>, world: &mut World) -> HookOutcome {
489        let ts = world.clock.now_ms();
490        let iter = self.iter.load(std::sync::atomic::Ordering::Relaxed);
491        // Reuse the recorder's projection + the verbose formatter so the
492        // live output is the same format you'd see post-mortem.
493        let session_ev = match ev {
494            Event::SessionStart { source } => Some(SessionEvent::Start {
495                ts_ms: ts,
496                source: format!("{source:?}"),
497            }),
498            Event::PreModel { ctx } => Some(SessionEvent::PreModel {
499                ts_ms: ts,
500                history_len: ctx.history.len(),
501                tools_count: ctx.tools.len(),
502            }),
503            Event::PostModel { out } => Some(SessionEvent::PostModel {
504                ts_ms: ts,
505                output: (*out).clone(),
506            }),
507            Event::PreToolUse { action } => Some(SessionEvent::PreTool {
508                ts_ms: ts,
509                action: (*action).clone(),
510            }),
511            Event::PostToolUse { action, result } => Some(SessionEvent::PostTool {
512                ts_ms: ts,
513                call_id: action.call_id.clone(),
514                result: (*result).clone(),
515            }),
516            Event::Heartbeat { iter: i } => {
517                self.iter.store(*i, std::sync::atomic::Ordering::Relaxed);
518                Some(SessionEvent::Heartbeat {
519                    ts_ms: ts,
520                    iter: *i,
521                })
522            }
523            Event::PreCompact { stage } => Some(SessionEvent::PreCompact {
524                ts_ms: ts,
525                stage: *stage,
526            }),
527            Event::PostCompact { stage } => Some(SessionEvent::PostCompact {
528                ts_ms: ts,
529                stage: *stage,
530            }),
531            Event::BudgetWarning { ratio } => Some(SessionEvent::BudgetWarning {
532                ts_ms: ts,
533                ratio: *ratio,
534            }),
535            Event::SessionEnd => Some(SessionEvent::End { ts_ms: ts }),
536            _ => None,
537        };
538        if let Some(e) = session_ev {
539            for line in format_event_verbose(&e).lines() {
540                eprintln!("[iter={iter}] {line}");
541            }
542        }
543        HookOutcome::Allow
544    }
545}
546
547#[cfg(test)]
548mod tests {
549    use super::*;
550
551    fn sample_log() -> Vec<SessionEvent> {
552        vec![
553            SessionEvent::Start {
554                ts_ms: 0,
555                source: "Startup".into(),
556            },
557            SessionEvent::Heartbeat { ts_ms: 1, iter: 0 },
558            SessionEvent::PreModel {
559                ts_ms: 2,
560                history_len: 1,
561                tools_count: 3,
562            },
563            SessionEvent::PostModel {
564                ts_ms: 100,
565                output: ModelOutput {
566                    text: Some("hi".into()),
567                    ..Default::default()
568                },
569            },
570            SessionEvent::End { ts_ms: 110 },
571        ]
572    }
573
574    #[test]
575    fn stats_compute_correctly() {
576        let s = SessionStats::from(&sample_log());
577        assert_eq!(s.events, 5);
578        assert_eq!(s.model_calls, 1);
579        assert_eq!(s.iters, 1);
580        assert_eq!(s.duration_ms, 110);
581    }
582
583    #[test]
584    fn round_trip_via_serde() {
585        let original = sample_log();
586        let json: Vec<String> = original
587            .iter()
588            .map(|e| serde_json::to_string(e).unwrap())
589            .collect();
590        let parsed: Vec<SessionEvent> = json
591            .iter()
592            .map(|s| serde_json::from_str::<SessionEvent>(s).unwrap())
593            .collect();
594        assert_eq!(parsed.len(), original.len());
595        assert!(
596            matches!(parsed[3], SessionEvent::PostModel { ref output, .. } if output.text.as_deref() == Some("hi"))
597        );
598    }
599}