From 6c2a3a2baeaa738d91ddf1545904e891f205a98d Mon Sep 17 00:00:00 2001 From: Affaan Mustafa Date: Tue, 24 Mar 2026 03:39:53 -0700 Subject: [PATCH] feat(ecc2): add tool call logging and history --- ecc2/src/observability/mod.rs | 146 +++++++++++++++++++++++++++++++--- ecc2/src/session/manager.rs | 39 +++++++++ ecc2/src/session/store.rs | 92 +++++++++++++++++++++ ecc2/src/tui/dashboard.rs | 77 +++++++++++++++--- 4 files changed, 335 insertions(+), 19 deletions(-) diff --git a/ecc2/src/observability/mod.rs b/ecc2/src/observability/mod.rs index 5f7a9645..39128e2e 100644 --- a/ecc2/src/observability/mod.rs +++ b/ecc2/src/observability/mod.rs @@ -1,4 +1,4 @@ -use anyhow::Result; +use anyhow::{bail, Result}; use serde::{Deserialize, Serialize}; use crate::session::store::StateStore; @@ -14,6 +14,26 @@ pub struct ToolCallEvent { } impl ToolCallEvent { + pub fn new( + session_id: impl Into, + tool_name: impl Into, + input_summary: impl Into, + output_summary: impl Into, + duration_ms: u64, + ) -> Self { + let tool_name = tool_name.into(); + let input_summary = input_summary.into(); + + Self { + session_id: session_id.into(), + risk_score: Self::compute_risk(&tool_name, &input_summary), + tool_name, + input_summary, + output_summary: output_summary.into(), + duration_ms, + } + } + /// Compute risk score based on tool type and input patterns. pub fn compute_risk(tool_name: &str, input: &str) -> f64 { let mut score: f64 = 0.0; @@ -43,12 +63,120 @@ impl ToolCallEvent { } } -pub fn log_tool_call(db: &StateStore, event: &ToolCallEvent) -> Result<()> { - db.send_message( - &event.session_id, - "observability", - &serde_json::to_string(event)?, - "tool_call", - )?; - Ok(()) +#[derive(Debug, Clone, Serialize, Deserialize, PartialEq)] +pub struct ToolLogEntry { + pub id: i64, + pub session_id: String, + pub tool_name: String, + pub input_summary: String, + pub output_summary: String, + pub duration_ms: u64, + pub risk_score: f64, + pub timestamp: String, +} + +#[derive(Debug, Clone, Serialize, Deserialize, PartialEq)] +pub struct ToolLogPage { + pub entries: Vec, + pub page: u64, + pub page_size: u64, + pub total: u64, +} + +pub struct ToolLogger<'a> { + db: &'a StateStore, +} + +impl<'a> ToolLogger<'a> { + pub fn new(db: &'a StateStore) -> Self { + Self { db } + } + + pub fn log(&self, event: &ToolCallEvent) -> Result { + let timestamp = chrono::Utc::now().to_rfc3339(); + + self.db.insert_tool_log( + &event.session_id, + &event.tool_name, + &event.input_summary, + &event.output_summary, + event.duration_ms, + event.risk_score, + ×tamp, + ) + } + + pub fn query(&self, session_id: &str, page: u64, page_size: u64) -> Result { + if page_size == 0 { + bail!("page_size must be greater than 0"); + } + + self.db.query_tool_logs(session_id, page.max(1), page_size) + } +} + +pub fn log_tool_call(db: &StateStore, event: &ToolCallEvent) -> Result { + ToolLogger::new(db).log(event) +} + +#[cfg(test)] +mod tests { + use super::{ToolCallEvent, ToolLogger}; + use crate::session::store::StateStore; + use crate::session::{Session, SessionMetrics, SessionState}; + use std::path::PathBuf; + + fn test_db_path() -> PathBuf { + std::env::temp_dir().join(format!("ecc2-observability-{}.db", uuid::Uuid::new_v4())) + } + + fn test_session(id: &str) -> Session { + let now = chrono::Utc::now(); + + Session { + id: id.to_string(), + task: "test task".to_string(), + agent_type: "claude".to_string(), + state: SessionState::Pending, + pid: None, + worktree: None, + created_at: now, + updated_at: now, + metrics: SessionMetrics::default(), + } + } + + #[test] + fn compute_risk_caps_high_risk_bash_commands() { + let score = ToolCallEvent::compute_risk("Bash", "sudo rm -rf /tmp --force"); + assert_eq!(score, 1.0); + } + + #[test] + fn logger_persists_entries_and_paginates() -> anyhow::Result<()> { + let db_path = test_db_path(); + let db = StateStore::open(&db_path)?; + db.insert_session(&test_session("sess-1"))?; + + let logger = ToolLogger::new(&db); + + logger.log(&ToolCallEvent::new("sess-1", "Read", "first", "ok", 5))?; + logger.log(&ToolCallEvent::new("sess-1", "Write", "second", "ok", 15))?; + logger.log(&ToolCallEvent::new("sess-1", "Bash", "third", "ok", 25))?; + + let first_page = logger.query("sess-1", 1, 2)?; + assert_eq!(first_page.total, 3); + assert_eq!(first_page.entries.len(), 2); + assert_eq!(first_page.entries[0].tool_name, "Bash"); + assert_eq!(first_page.entries[1].tool_name, "Write"); + + let second_page = logger.query("sess-1", 2, 2)?; + assert_eq!(second_page.total, 3); + assert_eq!(second_page.entries.len(), 1); + assert_eq!(second_page.entries[0].tool_name, "Read"); + + std::fs::remove_file(&db_path).ok(); + + Ok(()) + } } diff --git a/ecc2/src/session/manager.rs b/ecc2/src/session/manager.rs index 07538d8e..67099780 100644 --- a/ecc2/src/session/manager.rs +++ b/ecc2/src/session/manager.rs @@ -9,6 +9,7 @@ use super::runtime::capture_command_output; use super::store::StateStore; use super::{Session, SessionMetrics, SessionState}; use crate::config::Config; +use crate::observability::{log_tool_call, ToolCallEvent, ToolLogEntry, ToolLogPage, ToolLogger}; use crate::worktree; pub async fn create_session( @@ -36,6 +37,44 @@ pub async fn stop_session(db: &StateStore, id: &str) -> Result<()> { stop_session_with_options(db, id, true).await } +pub fn record_tool_call( + db: &StateStore, + session_id: &str, + tool_name: &str, + input_summary: &str, + output_summary: &str, + duration_ms: u64, +) -> Result { + let session = db + .get_session(session_id)? + .ok_or_else(|| anyhow::anyhow!("Session not found: {session_id}"))?; + + let event = ToolCallEvent::new( + session.id.clone(), + tool_name, + input_summary, + output_summary, + duration_ms, + ); + let entry = log_tool_call(db, &event)?; + db.increment_tool_calls(&session.id)?; + + Ok(entry) +} + +pub fn query_tool_calls( + db: &StateStore, + session_id: &str, + page: u64, + page_size: u64, +) -> Result { + let session = db + .get_session(session_id)? + .ok_or_else(|| anyhow::anyhow!("Session not found: {session_id}"))?; + + ToolLogger::new(db).query(&session.id, page, page_size) +} + pub async fn resume_session(db: &StateStore, id: &str) -> Result { let session = resolve_session(db, id)?; diff --git a/ecc2/src/session/store.rs b/ecc2/src/session/store.rs index bb6af18e..a547ac2a 100644 --- a/ecc2/src/session/store.rs +++ b/ecc2/src/session/store.rs @@ -3,6 +3,8 @@ use rusqlite::{Connection, OptionalExtension}; use std::path::{Path, PathBuf}; use std::time::Duration; +use crate::observability::{ToolLogEntry, ToolLogPage}; + use super::output::{OutputLine, OutputStream, OUTPUT_BUFFER_LIMIT}; use super::{Session, SessionMetrics, SessionState}; @@ -216,6 +218,14 @@ impl StateStore { Ok(()) } + pub fn increment_tool_calls(&self, session_id: &str) -> Result<()> { + self.conn.execute( + "UPDATE sessions SET tool_calls = tool_calls + 1, updated_at = ?1 WHERE id = ?2", + rusqlite::params![chrono::Utc::now().to_rfc3339(), session_id], + )?; + Ok(()) + } + pub fn list_sessions(&self) -> Result> { let mut stmt = self.conn.prepare( "SELECT id, task, agent_type, state, pid, worktree_path, worktree_branch, worktree_base, @@ -348,6 +358,88 @@ impl StateStore { Ok(lines) } + + pub fn insert_tool_log( + &self, + session_id: &str, + tool_name: &str, + input_summary: &str, + output_summary: &str, + duration_ms: u64, + risk_score: f64, + timestamp: &str, + ) -> Result { + self.conn.execute( + "INSERT INTO tool_log (session_id, tool_name, input_summary, output_summary, duration_ms, risk_score, timestamp) + VALUES (?1, ?2, ?3, ?4, ?5, ?6, ?7)", + rusqlite::params![ + session_id, + tool_name, + input_summary, + output_summary, + duration_ms, + risk_score, + timestamp, + ], + )?; + + Ok(ToolLogEntry { + id: self.conn.last_insert_rowid(), + session_id: session_id.to_string(), + tool_name: tool_name.to_string(), + input_summary: input_summary.to_string(), + output_summary: output_summary.to_string(), + duration_ms, + risk_score, + timestamp: timestamp.to_string(), + }) + } + + pub fn query_tool_logs( + &self, + session_id: &str, + page: u64, + page_size: u64, + ) -> Result { + let page = page.max(1); + let offset = (page - 1) * page_size; + + let total: u64 = self.conn.query_row( + "SELECT COUNT(*) FROM tool_log WHERE session_id = ?1", + rusqlite::params![session_id], + |row| row.get(0), + )?; + + let mut stmt = self.conn.prepare( + "SELECT id, session_id, tool_name, input_summary, output_summary, duration_ms, risk_score, timestamp + FROM tool_log + WHERE session_id = ?1 + ORDER BY timestamp DESC, id DESC + LIMIT ?2 OFFSET ?3", + )?; + + let entries = stmt + .query_map(rusqlite::params![session_id, page_size, offset], |row| { + Ok(ToolLogEntry { + id: row.get(0)?, + session_id: row.get(1)?, + tool_name: row.get(2)?, + input_summary: row.get::<_, Option>(3)?.unwrap_or_default(), + output_summary: row.get::<_, Option>(4)?.unwrap_or_default(), + duration_ms: row.get::<_, Option>(5)?.unwrap_or_default(), + risk_score: row.get::<_, Option>(6)?.unwrap_or_default(), + timestamp: row.get(7)?, + }) + })? + .collect::, _>>()?; + + Ok(ToolLogPage { + entries, + page, + page_size, + total, + }) + } } #[cfg(test)] diff --git a/ecc2/src/tui/dashboard.rs b/ecc2/src/tui/dashboard.rs index 38efd539..a86f052f 100644 --- a/ecc2/src/tui/dashboard.rs +++ b/ecc2/src/tui/dashboard.rs @@ -11,6 +11,7 @@ use tokio::sync::broadcast; use super::widgets::{budget_state, format_currency, format_token_count, BudgetState, TokenMeter}; use crate::config::{Config, PaneLayout}; +use crate::observability::ToolLogEntry; use crate::session::output::{OutputEvent, OutputLine, SessionOutputStore, OutputStream, OUTPUT_BUFFER_LIMIT}; use crate::session::store::StateStore; use crate::session::{Session, SessionMetrics, SessionState, WorktreeInfo}; @@ -21,6 +22,7 @@ const OUTPUT_PANE_PERCENT: u16 = 70; const MIN_PANE_SIZE_PERCENT: u16 = 20; const MAX_PANE_SIZE_PERCENT: u16 = 80; const PANE_RESIZE_STEP_PERCENT: u16 = 5; +const MAX_LOG_ENTRIES: u64 = 12; pub struct Dashboard { db: StateStore, @@ -29,6 +31,7 @@ pub struct Dashboard { output_rx: broadcast::Receiver, sessions: Vec, session_output_cache: HashMap>, + logs: Vec, selected_pane: Pane, selected_session: usize, show_help: bool, @@ -99,6 +102,7 @@ impl Dashboard { output_rx, sessions, session_output_cache: HashMap::new(), + logs: Vec::new(), selected_pane: Pane::Sessions, selected_session: 0, show_help: false, @@ -109,6 +113,7 @@ impl Dashboard { session_table_state, }; dashboard.sync_selected_output(); + dashboard.refresh_logs(); dashboard } @@ -300,15 +305,26 @@ impl Dashboard { } fn render_log(&self, frame: &mut Frame, area: Rect) { - let content = if let Some(session) = self.sessions.get(self.selected_session) { - format!( - "Split-pane grid layout reserved this pane for observability.\n\nSelected session: {}\nState: {}\n\nTool call history lands in the follow-on logging PR.", - &session.id[..8.min(session.id.len())], - session.state - ) + let content = if self.sessions.get(self.selected_session).is_none() { + "No session selected.".to_string() + } else if self.logs.is_empty() { + "No tool logs available for this session yet.".to_string() } else { - "Split-pane grid layout reserved this pane for observability.\n\nNo session selected." - .to_string() + self.logs + .iter() + .map(|entry| { + format!( + "[{}] {} | {}ms | risk {:.0}%\ninput: {}\noutput: {}", + self.short_timestamp(&entry.timestamp), + entry.tool_name, + entry.duration_ms, + entry.risk_score * 100.0, + self.log_field(&entry.input_summary), + self.log_field(&entry.output_summary) + ) + }) + .collect::>() + .join("\n\n") }; let paragraph = Paragraph::new(content) @@ -318,6 +334,7 @@ impl Dashboard { .title(" Log ") .border_style(self.pane_border_style(Pane::Log)), ) + .scroll((self.output_scroll_offset as u16, 0)) .wrap(Wrap { trim: false }); frame.render_widget(paragraph, area); } @@ -426,6 +443,7 @@ impl Dashboard { self.sync_selection(); self.reset_output_view(); self.sync_selected_output(); + self.refresh_logs(); } Pane::Output => { let max_scroll = self.max_output_scroll(); @@ -441,7 +459,10 @@ impl Dashboard { } } Pane::Metrics => {} - Pane::Log => {} + Pane::Log => { + self.output_follow = false; + self.output_scroll_offset = self.output_scroll_offset.saturating_add(1); + } Pane::Sessions => {} } } @@ -453,6 +474,7 @@ impl Dashboard { self.sync_selection(); self.reset_output_view(); self.sync_selected_output(); + self.refresh_logs(); } Pane::Output => { if self.output_follow { @@ -463,7 +485,10 @@ impl Dashboard { self.output_scroll_offset = self.output_scroll_offset.saturating_sub(1); } Pane::Metrics => {} - Pane::Log => {} + Pane::Log => { + self.output_follow = false; + self.output_scroll_offset = self.output_scroll_offset.saturating_sub(1); + } } } @@ -517,6 +542,7 @@ impl Dashboard { self.sync_selection_by_id(selected_id.as_deref()); self.ensure_selected_pane_visible(); self.sync_selected_output(); + self.refresh_logs(); } fn sync_selection(&mut self) { @@ -597,6 +623,21 @@ impl Dashboard { self.output_scroll_offset = 0; } + fn refresh_logs(&mut self) { + let Some(session_id) = self.selected_session_id().map(ToOwned::to_owned) else { + self.logs.clear(); + return; + }; + + match self.db.query_tool_logs(&session_id, 1, MAX_LOG_ENTRIES) { + Ok(page) => self.logs = page.entries, + Err(error) => { + tracing::warn!("Failed to load tool logs: {error}"); + self.logs.clear(); + } + } + } + fn aggregate_usage(&self) -> AggregateUsage { let total_tokens = self .sessions @@ -767,6 +808,21 @@ impl Dashboard { } } + fn log_field<'a>(&self, value: &'a str) -> &'a str { + let trimmed = value.trim(); + if trimmed.is_empty() { + "n/a" + } else { + trimmed + } + } + + fn short_timestamp(&self, timestamp: &str) -> String { + chrono::DateTime::parse_from_rfc3339(timestamp) + .map(|value| value.format("%H:%M:%S").to_string()) + .unwrap_or_else(|_| timestamp.to_string()) + } + #[cfg(test)] fn aggregate_cost_summary_text(&self) -> String { self.aggregate_cost_summary().0 @@ -1135,6 +1191,7 @@ mod tests { output_rx, sessions, session_output_cache: HashMap::new(), + logs: Vec::new(), selected_pane: Pane::Sessions, selected_session, show_help: false,