From 273a2ba4df89a38f7593664cadda17e49743c00d Mon Sep 17 00:00:00 2001 From: Trezy Date: Mon, 13 Apr 2026 14:15:24 -0500 Subject: [PATCH] feat: display plugin logs in event logs ui --- src/plugin/host/bindings.rs | 6 +- src/plugin/host/logging.rs | 55 +++++++++++++-- tests/plugin_logging.rs | 97 +++++++++++++++++++++++++++ web/src/app/dashboard/events/page.tsx | 20 ++++++ 4 files changed, 169 insertions(+), 9 deletions(-) create mode 100644 tests/plugin_logging.rs diff --git a/src/plugin/host/bindings.rs b/src/plugin/host/bindings.rs index 7a60b9c..92778fe 100644 --- a/src/plugin/host/bindings.rs +++ b/src/plugin/host/bindings.rs @@ -175,9 +175,11 @@ fn host_log( let level = std::str::from_utf8(&mem_data[level_start..level_end]).unwrap_or("info"); let msg = std::str::from_utf8(&mem_data[msg_start..msg_end]).unwrap_or(""); - let plugin_id = &caller.data().plugin_id; + let plugin_id = caller.data().plugin_id.clone(); + let db = caller.data().db.clone(); + let db_backend = caller.data().db_backend; let log_level: super::LogLevel = level.parse().unwrap_or_default(); - super::log(plugin_id, log_level, msg); + super::log(&plugin_id, log_level, msg, db, db_backend); } /// Host function: get a secret value by name diff --git a/src/plugin/host/logging.rs b/src/plugin/host/logging.rs index db051d1..c1f0f2e 100644 --- a/src/plugin/host/logging.rs +++ b/src/plugin/host/logging.rs @@ -25,14 +25,54 @@ impl FromStr for LogLevel { } } -/// Log a message from a plugin -pub fn log(plugin_id: &str, level: LogLevel, message: &str) { +/// Log a message from a plugin. +/// +/// Always emits to `tracing`. If `db` is `Some`, also spawns a detached task +/// that writes the event to the `event_logs` table so it appears in the +/// Event Logs UI. The spawned task is fire-and-forget; errors are logged by +/// `event_log::log_event` but not returned to the caller. +pub fn log( + plugin_id: &str, + level: LogLevel, + message: &str, + db: Option, + db_backend: crate::db::DatabaseBackend, +) { match level { LogLevel::Debug => debug!(plugin = %plugin_id, "{}", message), LogLevel::Info => info!(plugin = %plugin_id, "{}", message), LogLevel::Warn => warn!(plugin = %plugin_id, "{}", message), LogLevel::Error => error!(plugin = %plugin_id, "{}", message), } + + let Some(db) = db else { return }; + + let severity = match level { + LogLevel::Debug | LogLevel::Info => crate::event_log::Severity::Info, + LogLevel::Warn => crate::event_log::Severity::Warn, + LogLevel::Error => crate::event_log::Severity::Error, + }; + let level_str = match level { + LogLevel::Debug => "debug", + LogLevel::Info => "info", + LogLevel::Warn => "warn", + LogLevel::Error => "error", + }; + + let event = crate::event_log::EventLog { + event_type: "plugin.log".to_string(), + severity, + actor_did: None, + subject: Some(plugin_id.to_string()), + detail: serde_json::json!({ + "level": level_str, + "message": message, + }), + }; + + tokio::spawn(async move { + crate::event_log::log_event(&db, event, db_backend).await; + }); } #[cfg(test)] @@ -61,10 +101,11 @@ mod tests { #[test] fn test_log_does_not_panic() { - // Verify log() runs without panicking for each level - log("test-plugin", LogLevel::Debug, "debug message"); - log("test-plugin", LogLevel::Info, "info message"); - log("test-plugin", LogLevel::Warn, "warn message"); - log("test-plugin", LogLevel::Error, "error message"); + // With db=None, only the tracing path runs. Verifies each level does not panic. + let backend = crate::db::DatabaseBackend::Sqlite; + log("test-plugin", LogLevel::Debug, "debug message", None, backend); + log("test-plugin", LogLevel::Info, "info message", None, backend); + log("test-plugin", LogLevel::Warn, "warn message", None, backend); + log("test-plugin", LogLevel::Error, "error message", None, backend); } } diff --git a/tests/plugin_logging.rs b/tests/plugin_logging.rs new file mode 100644 index 0000000..35127fd --- /dev/null +++ b/tests/plugin_logging.rs @@ -0,0 +1,97 @@ +//! Integration tests for plugin logging -> event_logs persistence. +//! +//! Requires TEST_DATABASE_URL to be set (see CLAUDE.md "Testing" section). + +mod common; + +use common::db::{test_backend, test_pool, truncate_all}; +use happyview::db::adapt_sql; +use happyview::plugin::host::{LogLevel, log}; +use serde_json::Value; +use serial_test::serial; + +/// Wait briefly for detached `tokio::spawn` tasks to flush writes. +/// The log() function spawns fire-and-forget tasks; we need to yield +/// until they complete before querying. +async fn flush_spawned_tasks() { + for _ in 0..20 { + tokio::task::yield_now().await; + tokio::time::sleep(tokio::time::Duration::from_millis(25)).await; + } +} + +#[tokio::test] +#[serial] +async fn plugin_log_writes_all_four_levels_to_event_logs() { + let pool = test_pool().await; + let backend = test_backend(); + truncate_all(&pool).await; + + log("my-plugin", LogLevel::Debug, "dbg msg", Some(pool.clone()), backend); + log("my-plugin", LogLevel::Info, "info msg", Some(pool.clone()), backend); + log("my-plugin", LogLevel::Warn, "warn msg", Some(pool.clone()), backend); + log("my-plugin", LogLevel::Error, "err msg", Some(pool.clone()), backend); + + flush_spawned_tasks().await; + + let sql = adapt_sql( + "SELECT severity, subject, detail FROM event_logs WHERE event_type = ? ORDER BY created_at ASC", + backend, + ); + let rows: Vec<(String, Option, String)> = sqlx::query_as(&sql) + .bind("plugin.log") + .fetch_all(&pool) + .await + .expect("failed to query event_logs"); + + assert_eq!(rows.len(), 4, "expected 4 plugin.log rows, got {}", rows.len()); + + // Severity mapping: Debug->info, Info->info, Warn->warn, Error->error + let severities: Vec<&str> = rows.iter().map(|(s, _, _)| s.as_str()).collect(); + assert_eq!(severities, vec!["info", "info", "warn", "error"]); + + // All rows should have subject = plugin id + for (_, subject, _) in &rows { + assert_eq!(subject.as_deref(), Some("my-plugin")); + } + + // detail.level preserves the original level; detail.message carries the message + let details: Vec = rows + .iter() + .map(|(_, _, d)| serde_json::from_str(d).expect("detail not valid JSON")) + .collect(); + + assert_eq!(details[0]["level"], "debug"); + assert_eq!(details[0]["message"], "dbg msg"); + assert_eq!(details[1]["level"], "info"); + assert_eq!(details[1]["message"], "info msg"); + assert_eq!(details[2]["level"], "warn"); + assert_eq!(details[2]["message"], "warn msg"); + assert_eq!(details[3]["level"], "error"); + assert_eq!(details[3]["message"], "err msg"); +} + +#[tokio::test] +#[serial] +async fn plugin_log_with_none_db_does_not_write_event_log() { + let pool = test_pool().await; + let backend = test_backend(); + truncate_all(&pool).await; + + // db=None: should only emit to tracing, not persist. + log("silent-plugin", LogLevel::Info, "should not persist", None, backend); + + flush_spawned_tasks().await; + + let sql = adapt_sql( + "SELECT COUNT(*) FROM event_logs WHERE event_type = ?", + backend, + ); + let count: i64 = sqlx::query_scalar(&sql) + .bind("plugin.log") + .fetch_one(&pool) + .await + .expect("failed to count event_logs"); + + assert_eq!(count, 0); +} diff --git a/web/src/app/dashboard/events/page.tsx b/web/src/app/dashboard/events/page.tsx index 94f082b..0bebfaf 100644 --- a/web/src/app/dashboard/events/page.tsx +++ b/web/src/app/dashboard/events/page.tsx @@ -69,6 +69,8 @@ const KNOWN_KEYS = [ "caller_did", "duration_ms", "response_size", + "message", + "level", ] as const; function EventDetailBody({ event }: { event: EventLogEntry }) { @@ -131,6 +133,23 @@ function EventDetailBody({ event }: { event: EventLogEntry }) { )} + {/* Plugin log message */} + {d.message != null && ( +
+
+ Message + {d.level != null && ( + + {String(d.level)} + + )} +
+

+ {String(d.message)} +

+
+ )} + {/* Error section */} {d.error != null && (
@@ -375,6 +394,7 @@ export default function EventsPage() { { label: "Script", value: "script" }, { label: "Admin", value: "admin" }, { label: "Backfill", value: "backfill" }, + { label: "Plugin", value: "plugin" }, ], }, }, -- 2.51.2