rpi_extensions/
event_log.rs

1//! P3 — JSONL event journal.
2//!
3//! Opt-in via `RPI_EVENT_LOG=1`. When enabled, every extension **event-handler
4//! invocation** (the observe fan-out in [`dispatch_to_handlers`] and the
5//! veto-aware lifecycle dispatch in
6//! [`dispatch_lifecycle_event`](crate::dispatch_lifecycle_event)) is recorded as
7//! one JSON line, so a user can answer "why didn't my extension run?" and audit
8//! handler behavior after the fact.
9//!
10//! Off by default (zero disk writes / zero overhead when disabled — the global
11//! logger resolves to a no-op). One file, append-only:
12//! `$RPI_EVENT_LOG_PATH`, else `<root>/logs/events.jsonl`, where `<root>` is
13//! `$RPI_CODING_AGENT_DIR`'s parent (i.e. `~/.rpi`) or `~/.rpi`.
14//!
15//! [`dispatch_to_handlers`]: crate::translate::dispatch_to_handlers
16
17use std::fs::OpenOptions;
18use std::io::{BufWriter, Write};
19use std::path::PathBuf;
20use std::sync::{Mutex, OnceLock, RwLock};
21use std::time::{SystemTime, UNIX_EPOCH};
22
23use serde::Serialize;
24
25/// One recorded handler invocation.
26#[derive(Serialize)]
27struct EventLogEntry<'a> {
28    /// Unix epoch milliseconds (no chrono dep; a consumer can format it).
29    ts_ms: u64,
30    /// The event tag (`Debug` form, e.g. `BeforeTuiStart`, `MessageEnd`).
31    event: String,
32    /// The owning extension's display name.
33    plugin: &'a str,
34    /// `Continue` | `Error` | `Abort` | `Timeout` | `Panic` | `JoinFailed`.
35    result: &'a str,
36    duration_ms: u64,
37    #[serde(skip_serializing_if = "Option::is_none")]
38    detail: Option<String>,
39}
40
41/// A best-effort append-only JSONL sink. `writer` is `None` when logging is
42/// disabled (env gate off, or the file could not be opened).
43pub struct EventLogger {
44    writer: Option<Mutex<BufWriter<std::fs::File>>>,
45}
46
47impl EventLogger {
48    /// A disabled logger (no file).
49    pub fn disabled() -> Self {
50        Self { writer: None }
51    }
52
53    /// Open (create + append) an explicit path. Used by tests and by
54    /// [`from_env`](Self::from_env).
55    pub fn open(path: PathBuf) -> Self {
56        if let Some(parent) = path.parent() {
57            let _ = std::fs::create_dir_all(parent);
58        }
59        match OpenOptions::new().create(true).append(true).open(&path) {
60            Ok(file) => Self {
61                writer: Some(Mutex::new(BufWriter::new(file))),
62            },
63            Err(error) => {
64                tracing::warn!(path = %path.display(), %error, "could not open event log");
65                Self { writer: None }
66            }
67        }
68    }
69
70    /// Resolve the log from the environment (`RPI_EVENT_LOG=1`). Disabled when
71    /// the gate is off or no path can be resolved.
72    pub fn from_env() -> Self {
73        if std::env::var("RPI_EVENT_LOG").ok().as_deref() != Some("1") {
74            return Self::disabled();
75        }
76        match log_path() {
77            Some(path) => Self::open(path),
78            None => Self::disabled(),
79        }
80    }
81
82    /// Whether this logger will actually write.
83    pub fn enabled(&self) -> bool {
84        self.writer.is_some()
85    }
86
87    /// Append one entry (best-effort; write errors are swallowed — logging must
88    /// never break a dispatch).
89    fn record(
90        &self,
91        event: &str,
92        plugin: &str,
93        result: &'static str,
94        duration_ms: u64,
95        detail: Option<String>,
96    ) {
97        let Some(writer) = &self.writer else {
98            return;
99        };
100        let entry = EventLogEntry {
101            ts_ms: now_ms(),
102            event: event.to_string(),
103            plugin,
104            result,
105            duration_ms,
106            detail,
107        };
108        // A poisoned lock (a panic mid-write) must not kill logging.
109        let mut guard = match writer.lock() {
110            Ok(guard) => guard,
111            Err(poisoned) => poisoned.into_inner(),
112        };
113        let _ = serde_json::to_writer(&mut *guard, &entry);
114        let _ = guard.write_all(b"\n");
115        let _ = guard.flush();
116    }
117}
118
119fn now_ms() -> u64 {
120    SystemTime::now()
121        .duration_since(UNIX_EPOCH)
122        .map(|d| d.as_millis() as u64)
123        .unwrap_or(0)
124}
125
126/// Resolve the event-log path (`$RPI_EVENT_LOG_PATH`, else
127/// `<root>/logs/events.jsonl`, where `<root>` is `$RPI_CODING_AGENT_DIR`'s
128/// parent or `~/.rpi`). Public so `rpi events tail` can find the same file the
129/// logger writes.
130pub fn event_log_path() -> Option<PathBuf> {
131    if let Some(path) = std::env::var_os("RPI_EVENT_LOG_PATH") {
132        return Some(PathBuf::from(path));
133    }
134    let root = if let Some(agent) = std::env::var_os("RPI_CODING_AGENT_DIR") {
135        // The override is the *agent* dir (`~/.rpi/agent`); logs live in the
136        // parent (`~/.rpi/logs`). A parentless override falls back to itself.
137        let agent = PathBuf::from(agent);
138        agent.parent().map(PathBuf::from).unwrap_or(agent)
139    } else {
140        dirs::home_dir()?.join(".rpi")
141    };
142    Some(root.join("logs").join("events.jsonl"))
143}
144
145/// Internal alias for [`event_log_path`].
146fn log_path() -> Option<PathBuf> {
147    event_log_path()
148}
149
150/// The process-global event logger slot. Initialized lazily from the
151/// environment on first use; a test may replace it via
152/// `set_event_logger_for_test`.
153fn global() -> &'static RwLock<Option<EventLogger>> {
154    static GLOBAL: OnceLock<RwLock<Option<EventLogger>>> = OnceLock::new();
155    GLOBAL.get_or_init(|| RwLock::new(Some(EventLogger::from_env())))
156}
157
158/// Record one handler invocation on the global logger. No-op when logging is
159/// disabled (the common case).
160pub fn log_handler_invocation(
161    tag: rpi_plugin_sdk::EventTag,
162    plugin: &str,
163    result: &'static str,
164    duration_ms: u64,
165    detail: Option<String>,
166) {
167    let guard = match global().read() {
168        Ok(guard) => guard,
169        Err(poisoned) => poisoned.into_inner(),
170    };
171    if let Some(logger) = guard.as_ref() {
172        if logger.enabled() {
173            logger.record(&format!("{tag:?}"), plugin, result, duration_ms, detail);
174        }
175    }
176}
177
178/// Test-only: install an explicit logger (replacing the env-derived default).
179/// Callers must restore [`EventLogger::disabled`] when done to avoid leaking the
180/// sink into other tests.
181#[cfg(test)]
182pub(crate) fn set_event_logger_for_test(logger: EventLogger) {
183    let mut guard = match global().write() {
184        Ok(guard) => guard,
185        Err(poisoned) => poisoned.into_inner(),
186    };
187    *guard = Some(logger);
188}
189
190#[cfg(test)]
191mod tests {
192    use super::*;
193
194    #[test]
195    fn records_jsonl_lines_and_is_noop_when_disabled() {
196        let dir = tempfile::tempdir().unwrap();
197        let path = dir.path().join("events.jsonl");
198
199        // Disabled logger writes nothing.
200        let disabled = EventLogger::disabled();
201        assert!(!disabled.enabled());
202        disabled.record("X", "p", "Continue", 0, None);
203
204        // An explicit logger appends one JSON line per record.
205        let logger = EventLogger::open(path.clone());
206        assert!(logger.enabled());
207        logger.record(
208            "BeforeTuiStart",
209            "rpc-ext",
210            "Abort",
211            42,
212            Some("connect failed".into()),
213        );
214        logger.record("MessageEnd", "logger-ext", "Continue", 1, None);
215
216        let text = std::fs::read_to_string(&path).unwrap();
217        let lines: Vec<&str> = text.lines().collect();
218        assert_eq!(lines.len(), 2);
219        let first: serde_json::Value = serde_json::from_str(lines[0]).unwrap();
220        assert_eq!(first["event"], "BeforeTuiStart");
221        assert_eq!(first["plugin"], "rpc-ext");
222        assert_eq!(first["result"], "Abort");
223        assert_eq!(first["duration_ms"], 42);
224        assert_eq!(first["detail"], "connect failed");
225        assert!(first["ts_ms"].is_u64());
226        let second: serde_json::Value = serde_json::from_str(lines[1]).unwrap();
227        assert_eq!(second["event"], "MessageEnd");
228        // Omitted `detail` must not appear.
229        assert!(second.get("detail").is_none());
230    }
231}
rpi_extensions/event_log.rs

rpi_extensions/
event_log.rs
