feat(ecc2): add tool call logging and history

This commit is contained in:
Affaan Mustafa
2026-03-24 03:39:53 -07:00
parent adaeab9dba
commit 6c2a3a2bae
4 changed files with 335 additions and 19 deletions

View File

@@ -1,4 +1,4 @@
use anyhow::Result; use anyhow::{bail, Result};
use serde::{Deserialize, Serialize}; use serde::{Deserialize, Serialize};
use crate::session::store::StateStore; use crate::session::store::StateStore;
@@ -14,6 +14,26 @@ pub struct ToolCallEvent {
} }
impl ToolCallEvent { impl ToolCallEvent {
pub fn new(
session_id: impl Into<String>,
tool_name: impl Into<String>,
input_summary: impl Into<String>,
output_summary: impl Into<String>,
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. /// Compute risk score based on tool type and input patterns.
pub fn compute_risk(tool_name: &str, input: &str) -> f64 { pub fn compute_risk(tool_name: &str, input: &str) -> f64 {
let mut score: f64 = 0.0; let mut score: f64 = 0.0;
@@ -43,12 +63,120 @@ impl ToolCallEvent {
} }
} }
pub fn log_tool_call(db: &StateStore, event: &ToolCallEvent) -> Result<()> { #[derive(Debug, Clone, Serialize, Deserialize, PartialEq)]
db.send_message( pub struct ToolLogEntry {
&event.session_id, pub id: i64,
"observability", pub session_id: String,
&serde_json::to_string(event)?, pub tool_name: String,
"tool_call", pub input_summary: String,
)?; pub output_summary: String,
Ok(()) pub duration_ms: u64,
pub risk_score: f64,
pub timestamp: String,
}
#[derive(Debug, Clone, Serialize, Deserialize, PartialEq)]
pub struct ToolLogPage {
pub entries: Vec<ToolLogEntry>,
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<ToolLogEntry> {
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,
&timestamp,
)
}
pub fn query(&self, session_id: &str, page: u64, page_size: u64) -> Result<ToolLogPage> {
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<ToolLogEntry> {
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(())
}
} }

View File

@@ -9,6 +9,7 @@ use super::runtime::capture_command_output;
use super::store::StateStore; use super::store::StateStore;
use super::{Session, SessionMetrics, SessionState}; use super::{Session, SessionMetrics, SessionState};
use crate::config::Config; use crate::config::Config;
use crate::observability::{log_tool_call, ToolCallEvent, ToolLogEntry, ToolLogPage, ToolLogger};
use crate::worktree; use crate::worktree;
pub async fn create_session( 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 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<ToolLogEntry> {
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<ToolLogPage> {
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<String> { pub async fn resume_session(db: &StateStore, id: &str) -> Result<String> {
let session = resolve_session(db, id)?; let session = resolve_session(db, id)?;

View File

@@ -3,6 +3,8 @@ use rusqlite::{Connection, OptionalExtension};
use std::path::{Path, PathBuf}; use std::path::{Path, PathBuf};
use std::time::Duration; use std::time::Duration;
use crate::observability::{ToolLogEntry, ToolLogPage};
use super::output::{OutputLine, OutputStream, OUTPUT_BUFFER_LIMIT}; use super::output::{OutputLine, OutputStream, OUTPUT_BUFFER_LIMIT};
use super::{Session, SessionMetrics, SessionState}; use super::{Session, SessionMetrics, SessionState};
@@ -216,6 +218,14 @@ impl StateStore {
Ok(()) 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<Vec<Session>> { pub fn list_sessions(&self) -> Result<Vec<Session>> {
let mut stmt = self.conn.prepare( let mut stmt = self.conn.prepare(
"SELECT id, task, agent_type, state, pid, worktree_path, worktree_branch, worktree_base, "SELECT id, task, agent_type, state, pid, worktree_path, worktree_branch, worktree_base,
@@ -348,6 +358,88 @@ impl StateStore {
Ok(lines) 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<ToolLogEntry> {
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<ToolLogPage> {
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<String>>(3)?.unwrap_or_default(),
output_summary: row.get::<_, Option<String>>(4)?.unwrap_or_default(),
duration_ms: row.get::<_, Option<u64>>(5)?.unwrap_or_default(),
risk_score: row.get::<_, Option<f64>>(6)?.unwrap_or_default(),
timestamp: row.get(7)?,
})
})?
.collect::<Result<Vec<_>, _>>()?;
Ok(ToolLogPage {
entries,
page,
page_size,
total,
})
}
} }
#[cfg(test)] #[cfg(test)]

View File

@@ -11,6 +11,7 @@ use tokio::sync::broadcast;
use super::widgets::{budget_state, format_currency, format_token_count, BudgetState, TokenMeter}; use super::widgets::{budget_state, format_currency, format_token_count, BudgetState, TokenMeter};
use crate::config::{Config, PaneLayout}; use crate::config::{Config, PaneLayout};
use crate::observability::ToolLogEntry;
use crate::session::output::{OutputEvent, OutputLine, SessionOutputStore, OutputStream, OUTPUT_BUFFER_LIMIT}; use crate::session::output::{OutputEvent, OutputLine, SessionOutputStore, OutputStream, OUTPUT_BUFFER_LIMIT};
use crate::session::store::StateStore; use crate::session::store::StateStore;
use crate::session::{Session, SessionMetrics, SessionState, WorktreeInfo}; 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 MIN_PANE_SIZE_PERCENT: u16 = 20;
const MAX_PANE_SIZE_PERCENT: u16 = 80; const MAX_PANE_SIZE_PERCENT: u16 = 80;
const PANE_RESIZE_STEP_PERCENT: u16 = 5; const PANE_RESIZE_STEP_PERCENT: u16 = 5;
const MAX_LOG_ENTRIES: u64 = 12;
pub struct Dashboard { pub struct Dashboard {
db: StateStore, db: StateStore,
@@ -29,6 +31,7 @@ pub struct Dashboard {
output_rx: broadcast::Receiver<OutputEvent>, output_rx: broadcast::Receiver<OutputEvent>,
sessions: Vec<Session>, sessions: Vec<Session>,
session_output_cache: HashMap<String, Vec<OutputLine>>, session_output_cache: HashMap<String, Vec<OutputLine>>,
logs: Vec<ToolLogEntry>,
selected_pane: Pane, selected_pane: Pane,
selected_session: usize, selected_session: usize,
show_help: bool, show_help: bool,
@@ -99,6 +102,7 @@ impl Dashboard {
output_rx, output_rx,
sessions, sessions,
session_output_cache: HashMap::new(), session_output_cache: HashMap::new(),
logs: Vec::new(),
selected_pane: Pane::Sessions, selected_pane: Pane::Sessions,
selected_session: 0, selected_session: 0,
show_help: false, show_help: false,
@@ -109,6 +113,7 @@ impl Dashboard {
session_table_state, session_table_state,
}; };
dashboard.sync_selected_output(); dashboard.sync_selected_output();
dashboard.refresh_logs();
dashboard dashboard
} }
@@ -300,15 +305,26 @@ impl Dashboard {
} }
fn render_log(&self, frame: &mut Frame, area: Rect) { fn render_log(&self, frame: &mut Frame, area: Rect) {
let content = if let Some(session) = self.sessions.get(self.selected_session) { let content = if self.sessions.get(self.selected_session).is_none() {
format!( "No session selected.".to_string()
"Split-pane grid layout reserved this pane for observability.\n\nSelected session: {}\nState: {}\n\nTool call history lands in the follow-on logging PR.", } else if self.logs.is_empty() {
&session.id[..8.min(session.id.len())], "No tool logs available for this session yet.".to_string()
session.state
)
} else { } else {
"Split-pane grid layout reserved this pane for observability.\n\nNo session selected." self.logs
.to_string() .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::<Vec<_>>()
.join("\n\n")
}; };
let paragraph = Paragraph::new(content) let paragraph = Paragraph::new(content)
@@ -318,6 +334,7 @@ impl Dashboard {
.title(" Log ") .title(" Log ")
.border_style(self.pane_border_style(Pane::Log)), .border_style(self.pane_border_style(Pane::Log)),
) )
.scroll((self.output_scroll_offset as u16, 0))
.wrap(Wrap { trim: false }); .wrap(Wrap { trim: false });
frame.render_widget(paragraph, area); frame.render_widget(paragraph, area);
} }
@@ -426,6 +443,7 @@ impl Dashboard {
self.sync_selection(); self.sync_selection();
self.reset_output_view(); self.reset_output_view();
self.sync_selected_output(); self.sync_selected_output();
self.refresh_logs();
} }
Pane::Output => { Pane::Output => {
let max_scroll = self.max_output_scroll(); let max_scroll = self.max_output_scroll();
@@ -441,7 +459,10 @@ impl Dashboard {
} }
} }
Pane::Metrics => {} Pane::Metrics => {}
Pane::Log => {} Pane::Log => {
self.output_follow = false;
self.output_scroll_offset = self.output_scroll_offset.saturating_add(1);
}
Pane::Sessions => {} Pane::Sessions => {}
} }
} }
@@ -453,6 +474,7 @@ impl Dashboard {
self.sync_selection(); self.sync_selection();
self.reset_output_view(); self.reset_output_view();
self.sync_selected_output(); self.sync_selected_output();
self.refresh_logs();
} }
Pane::Output => { Pane::Output => {
if self.output_follow { if self.output_follow {
@@ -463,7 +485,10 @@ impl Dashboard {
self.output_scroll_offset = self.output_scroll_offset.saturating_sub(1); self.output_scroll_offset = self.output_scroll_offset.saturating_sub(1);
} }
Pane::Metrics => {} 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.sync_selection_by_id(selected_id.as_deref());
self.ensure_selected_pane_visible(); self.ensure_selected_pane_visible();
self.sync_selected_output(); self.sync_selected_output();
self.refresh_logs();
} }
fn sync_selection(&mut self) { fn sync_selection(&mut self) {
@@ -597,6 +623,21 @@ impl Dashboard {
self.output_scroll_offset = 0; 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 { fn aggregate_usage(&self) -> AggregateUsage {
let total_tokens = self let total_tokens = self
.sessions .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)] #[cfg(test)]
fn aggregate_cost_summary_text(&self) -> String { fn aggregate_cost_summary_text(&self) -> String {
self.aggregate_cost_summary().0 self.aggregate_cost_summary().0
@@ -1135,6 +1191,7 @@ mod tests {
output_rx, output_rx,
sessions, sessions,
session_output_cache: HashMap::new(), session_output_cache: HashMap::new(),
logs: Vec::new(),
selected_pane: Pane::Sessions, selected_pane: Pane::Sessions,
selected_session, selected_session,
show_help: false, show_help: false,