diff --git a/Cargo.lock b/Cargo.lock index 5f07da681f..f1d8564f7c 100644 --- a/Cargo.lock +++ b/Cargo.lock @@ -4606,6 +4606,7 @@ dependencies = [ "tokio-util", "tower-http", "tracing", + "tracing-appender", "tracing-futures", "tracing-opentelemetry", "tracing-subscriber", @@ -4684,7 +4685,6 @@ dependencies = [ "tokio", "tokio-util", "tracing", - "tracing-appender", "tracing-subscriber", "url", "urlencoding", @@ -4776,7 +4776,6 @@ dependencies = [ "tower", "tower-http", "tracing", - "tracing-appender", "tracing-subscriber", "url", "utoipa 4.2.3", diff --git a/crates/goose-cli/Cargo.toml b/crates/goose-cli/Cargo.toml index 85cd99eb4c..38b0957b5f 100644 --- a/crates/goose-cli/Cargo.toml +++ b/crates/goose-cli/Cargo.toml @@ -43,7 +43,6 @@ rustyline = "18.0.0" tracing = { workspace = true } chrono = { workspace = true } tracing-subscriber = { workspace = true, features = ["env-filter", "fmt", "json", "time"] } -tracing-appender = { workspace = true } shlex = "1.3.0" async-trait = { workspace = true } base64 = { workspace = true } diff --git a/crates/goose-cli/src/logging.rs b/crates/goose-cli/src/logging.rs index f6cf0d9602..68d435c3c2 100644 --- a/crates/goose-cli/src/logging.rs +++ b/crates/goose-cli/src/logging.rs @@ -1,99 +1,41 @@ -use anyhow::{Context, Result}; +use anyhow::Result; use std::sync::Once; -use tracing_appender::rolling::Rotation; -use tracing_subscriber::{ - filter::LevelFilter, fmt, layer::SubscriberExt, util::SubscriberInitExt, EnvFilter, Layer, - Registry, -}; - -#[cfg(feature = "otel")] -use goose::otel::otlp; -use goose::tracing::langfuse_layer; // Used to ensure we only set up tracing once static INIT: Once = Once::new(); -fn default_env_filter() -> EnvFilter { - EnvFilter::new("") - // Keep goose and MCP logs visible without verbose debug payloads. - .add_directive("mcp_client=info".parse().unwrap()) - .add_directive("goose=info".parse().unwrap()) - .add_directive("goose_cli=info".parse().unwrap()) - .add_directive(LevelFilter::WARN.into()) -} - -/// Sets up the logging infrastructure for the application. -/// This includes: -/// - File-based logging with JSON formatting (DEBUG level) -/// - No console output (all logs go to files only) -/// - Optional Langfuse integration (DEBUG level) +/// Sets up the logging infrastructure for the CLI. +/// Logs go to a JSON file only (no console output). pub fn setup_logging(name: Option<&str>) -> Result<()> { setup_logging_internal(name, false) } -/// Internal function that allows bypassing the Once check for testing fn setup_logging_internal(name: Option<&str>, force: bool) -> Result<()> { let mut result = Ok(()); let mut setup = || { result = (|| { - let log_dir = goose::logging::prepare_log_directory("cli", true)?; - let timestamp = chrono::Local::now().format("%Y%m%d_%H%M%S").to_string(); - let log_filename = if let Some(n) = name { - format!("{}-{}.log", timestamp, n) - } else { - format!("{}.log", timestamp) + use tracing_subscriber::util::SubscriberInitExt; + + let config = goose::logging::LoggingConfig { + component: "cli", + name, + extra_directives: &["goose_cli=info"], + console: false, + json: true, }; - let file_appender = tracing_appender::rolling::RollingFileAppender::new( - Rotation::NEVER, // we do manual rotation via file naming and cleanup_old_logs - log_dir, - log_filename, - ); - - // Create JSON file logging layer with all logs (DEBUG and above) - let file_layer = fmt::layer() - .with_target(true) - .with_level(true) - .with_writer(file_appender) - .with_ansi(false) - .json(); - - // Base filter - let env_filter = - EnvFilter::try_from_default_env().unwrap_or_else(|_| default_env_filter()); - - // Start building the subscriber - let mut layers = vec![ - file_layer.with_filter(env_filter).boxed(), - // Console logging disabled for CLI - all logs go to files only - ]; - - #[cfg(feature = "otel")] - if !force { - layers.extend(otlp::init_otlp_layers(goose::config::Config::global())); - } - - if let Some(langfuse) = langfuse_layer::create_langfuse_observer() { - layers.push(langfuse.with_filter(LevelFilter::DEBUG).boxed()); - } - - // Build the subscriber - let subscriber = Registry::default().with(layers); + let subscriber = goose::logging::build_logging_subscriber(&config)?; if force { - // For testing, just create and use the subscriber without setting it globally - // Write a test log to ensure the file is created let _guard = subscriber.set_default(); tracing::warn!("Test log entry from setup"); tracing::info!("Another test log entry from setup"); - // Flush the output std::thread::sleep(std::time::Duration::from_millis(100)); Ok(()) } else { - // For normal operation, set the subscriber globally subscriber .try_init() - .context("Failed to set global subscriber")?; + .map_err(|e| anyhow::anyhow!("Failed to set global subscriber: {}", e))?; Ok(()) } })(); @@ -110,7 +52,7 @@ fn setup_logging_internal(name: Option<&str>, force: bool) -> Result<()> { #[cfg(test)] mod tests { - use super::*; + use goose::tracing::langfuse_layer; use std::env; use tempfile::TempDir; @@ -131,7 +73,6 @@ mod tests { assert!(log_dir.exists()); assert!(log_dir.is_dir()); - // Verify directory structure let path_components: Vec<_> = log_dir.components().collect(); assert!(path_components.iter().any(|c| c.as_os_str() == "goose")); assert!(path_components.iter().any(|c| c.as_os_str() == "logs")); @@ -142,7 +83,6 @@ mod tests { async fn test_langfuse_layer_creation() { let _temp_dir = setup_temp_home(); - // Store original environment variables (both sets) let original_vars = [ ("LANGFUSE_PUBLIC_KEY", env::var("LANGFUSE_PUBLIC_KEY").ok()), ("LANGFUSE_SECRET_KEY", env::var("LANGFUSE_SECRET_KEY").ok()), @@ -157,31 +97,25 @@ mod tests { ), ]; - // Clear all Langfuse environment variables for (var, _) in &original_vars { env::remove_var(var); } - // Test without any environment variables assert!(langfuse_layer::create_langfuse_observer().is_none()); - // Test with standard Langfuse variables env::set_var("LANGFUSE_PUBLIC_KEY", "test_public_key"); env::set_var("LANGFUSE_SECRET_KEY", "test_secret_key"); assert!(langfuse_layer::create_langfuse_observer().is_some()); - // Clear and test with init project variables env::remove_var("LANGFUSE_PUBLIC_KEY"); env::remove_var("LANGFUSE_SECRET_KEY"); env::set_var("LANGFUSE_INIT_PROJECT_PUBLIC_KEY", "test_public_key"); env::set_var("LANGFUSE_INIT_PROJECT_SECRET_KEY", "test_secret_key"); assert!(langfuse_layer::create_langfuse_observer().is_some()); - // Test fallback behavior env::remove_var("LANGFUSE_INIT_PROJECT_PUBLIC_KEY"); assert!(langfuse_layer::create_langfuse_observer().is_none()); - // Restore original environment variables for (var, value) in original_vars { match value { Some(val) => env::set_var(var, val), @@ -190,13 +124,18 @@ mod tests { } } - #[test] - fn test_default_filter_avoids_debug_by_default() { - let filter = super::default_env_filter().to_string(); - assert!(!filter.contains("mcp_client=debug")); - assert!(!filter.contains("goose=debug")); - assert!(filter.contains("mcp_client=info")); - assert!(filter.contains("goose=info")); - assert!(filter.contains("goose_cli=info")); + #[tokio::test] + async fn test_default_filter_avoids_debug_by_default() { + // The shared helper honours RUST_LOG; without it the defaults apply. + // We just smoke-check that building the subscriber doesn't panic. + let _temp_dir = setup_temp_home(); + let config = goose::logging::LoggingConfig { + component: "cli-test", + name: None, + extra_directives: &["goose_cli=info"], + console: false, + json: true, + }; + assert!(goose::logging::build_logging_subscriber(&config).is_ok()); } } diff --git a/crates/goose-server/Cargo.toml b/crates/goose-server/Cargo.toml index e55474052e..47f10e249c 100644 --- a/crates/goose-server/Cargo.toml +++ b/crates/goose-server/Cargo.toml @@ -51,7 +51,6 @@ serde_json = { workspace = true, features = ["preserve_order"] } futures = { workspace = true } tracing = { workspace = true } tracing-subscriber = { workspace = true, features = ["env-filter", "fmt", "json", "time"] } -tracing-appender = { workspace = true } tokio-stream = { workspace = true } anyhow = { workspace = true } bytes = { workspace = true } diff --git a/crates/goose-server/src/logging.rs b/crates/goose-server/src/logging.rs index 412d943946..88af03127c 100644 --- a/crates/goose-server/src/logging.rs +++ b/crates/goose-server/src/logging.rs @@ -1,71 +1,17 @@ use anyhow::Result; -use tracing_appender::rolling::Rotation; -use tracing_subscriber::{ - filter::LevelFilter, fmt, layer::SubscriberExt, util::SubscriberInitExt, EnvFilter, Layer, - Registry, -}; +use tracing_subscriber::util::SubscriberInitExt; -#[cfg(feature = "otel")] -use goose::otel::otlp; -use goose::tracing::langfuse_layer; - -/// Sets up the logging infrastructure for the application. -/// This includes: -/// - File-based logging with JSON formatting (DEBUG level) -/// - Console output for development (INFO level) -/// - Optional Langfuse integration (DEBUG level) +/// Sets up the logging infrastructure for the server. +/// Logs go to a JSON file and a pretty console layer on stderr. pub fn setup_logging(name: Option<&str>) -> Result<()> { - let log_dir = goose::logging::prepare_log_directory("server", true)?; - let timestamp = chrono::Local::now().format("%Y%m%d_%H%M%S").to_string(); - let log_filename = if let Some(n) = name { - format!("{}-{}.log", timestamp, n) - } else { - format!("{}.log", timestamp) + let config = goose::logging::LoggingConfig { + component: "server", + name, + extra_directives: &["goose_server=info", "tower_http=info"], + console: true, + json: false, }; - let file_appender = - tracing_appender::rolling::RollingFileAppender::new(Rotation::NEVER, log_dir, log_filename); - - // Create JSON file logging layer - let file_layer = fmt::layer() - .with_target(true) - .with_level(true) - .with_writer(file_appender) - .with_ansi(false) - .with_file(true); - - let base_env_filter = EnvFilter::try_from_default_env().unwrap_or_else(|_| { - EnvFilter::new("") - .add_directive("mcp_client=info".parse().unwrap()) - .add_directive("goose=info".parse().unwrap()) - .add_directive("goose_server=info".parse().unwrap()) - .add_directive("tower_http=info".parse().unwrap()) - .add_directive(LevelFilter::WARN.into()) - }); - - let console_layer = fmt::layer() - .with_writer(std::io::stderr) - .with_target(true) - .with_level(true) - .with_file(true) - .with_ansi(false) - .with_line_number(true) - .pretty(); - - let mut layers = vec![ - file_layer.with_filter(base_env_filter.clone()).boxed(), - console_layer.with_filter(base_env_filter).boxed(), - ]; - - #[cfg(feature = "otel")] - layers.extend(otlp::init_otlp_layers(goose::config::Config::global())); - - if let Some(langfuse) = langfuse_layer::create_langfuse_observer() { - layers.push(langfuse.with_filter(LevelFilter::DEBUG).boxed()); - } - - let subscriber = Registry::default().with(layers); - + let subscriber = goose::logging::build_logging_subscriber(&config)?; subscriber.try_init()?; - Ok(()) } diff --git a/crates/goose/Cargo.toml b/crates/goose/Cargo.toml index c0759e5e33..3b49beced2 100644 --- a/crates/goose/Cargo.toml +++ b/crates/goose/Cargo.toml @@ -102,7 +102,7 @@ url = { workspace = true } axum = { workspace = true, features = ["ws"] } webbrowser = { workspace = true } tracing = { workspace = true } -tracing-subscriber = { workspace = true } +tracing-subscriber = { workspace = true, features = ["env-filter", "fmt", "json", "time"] } tracing-futures = { workspace = true } tracing-opentelemetry = { workspace = true, optional = true } opentelemetry = { workspace = true, optional = true } @@ -194,6 +194,7 @@ sec1 = { version = "0.7", default-features = false, features = ["der", "pkcs8"], goose-acp-macros = { path = "../goose-acp-macros" } tower-http = { workspace = true, features = ["cors"] } http-body-util = "0.1.3" +tracing-appender.workspace = true process-wrap = { version = "9.1.0", features = ["std"] } nostr = { version = "0.44.2", features = ["nip44"] } nostr-sdk = { version = "0.44.1", features = ["nip44"] } diff --git a/crates/goose/src/logging.rs b/crates/goose/src/logging.rs index 380c5dd395..9e7c425de0 100644 --- a/crates/goose/src/logging.rs +++ b/crates/goose/src/logging.rs @@ -3,6 +3,109 @@ use anyhow::{Context, Result}; use std::fs; use std::path::PathBuf; use std::time::{Duration, SystemTime}; +use tracing_appender::rolling::Rotation; +use tracing_subscriber::{ + filter::LevelFilter, fmt, layer::SubscriberExt, util::SubscriberInitExt, EnvFilter, Layer, + Registry, +}; + +/// Configuration for the shared logging setup. +pub struct LoggingConfig<'a> { + /// Component name used for the log directory (e.g. "cli", "server"). + pub component: &'a str, + /// Optional session/run name appended to the log filename. + pub name: Option<&'a str>, + /// Additional `EnvFilter` directives beyond the defaults (e.g. "goose_server=info"). + /// Only applied when `RUST_LOG` is **not** set. + pub extra_directives: &'a [&'a str], + /// Whether to emit a pretty console layer to stderr in addition to the file layer. + pub console: bool, + /// Whether the file layer should use JSON formatting. When false, uses plain text + /// with source file path included. + pub json: bool, +} + +/// Build the `EnvFilter`. If `RUST_LOG` is set, use it as-is. Otherwise build a +/// default filter and append the caller's extra directives. +fn build_env_filter(extra_directives: &[&str]) -> EnvFilter { + if let Ok(filter) = EnvFilter::try_from_default_env() { + return filter; + } + + let mut filter = EnvFilter::new("") + .add_directive("mcp_client=info".parse().unwrap()) + .add_directive("goose=info".parse().unwrap()) + .add_directive(LevelFilter::WARN.into()); + + for directive in extra_directives { + if let Ok(d) = directive.parse() { + filter = filter.add_directive(d); + } + } + filter +} + +/// Set up file-based (and optionally console) tracing for a goose component. +/// +/// This is the shared implementation used by both `goose-cli` and `goose-server`. +/// Call `try_init` on the returned subscriber — callers are responsible for the +/// `Once`-guard or direct init as appropriate for their use case. +pub fn build_logging_subscriber( + config: &LoggingConfig<'_>, +) -> Result { + let log_dir = prepare_log_directory(config.component, true)?; + let timestamp = chrono::Local::now().format("%Y%m%d_%H%M%S").to_string(); + let log_filename = match config.name { + Some(n) => format!("{}-{}.log", timestamp, n), + None => format!("{}.log", timestamp), + }; + + let file_appender = + tracing_appender::rolling::RollingFileAppender::new(Rotation::NEVER, log_dir, log_filename); + + let env_filter = build_env_filter(config.extra_directives); + + let mut layers: Vec + Send + Sync>> = if config.json { + let file_layer = fmt::layer() + .with_target(true) + .with_level(true) + .with_writer(file_appender) + .with_ansi(false) + .json(); + vec![file_layer.with_filter(env_filter.clone()).boxed()] + } else { + let file_layer = fmt::layer() + .with_target(true) + .with_level(true) + .with_writer(file_appender) + .with_ansi(false) + .with_file(true); + vec![file_layer.with_filter(env_filter.clone()).boxed()] + }; + + if config.console { + let console_layer = fmt::layer() + .with_writer(std::io::stderr) + .with_target(true) + .with_level(true) + .with_file(true) + .with_ansi(false) + .with_line_number(true) + .pretty(); + layers.push(console_layer.with_filter(env_filter).boxed()); + } + + #[cfg(feature = "otel")] + layers.extend(crate::otel::otlp::init_otlp_layers( + crate::config::Config::global(), + )); + + if let Some(langfuse) = crate::tracing::langfuse_layer::create_langfuse_observer() { + layers.push(langfuse.with_filter(LevelFilter::DEBUG).boxed()); + } + + Ok(Registry::default().with(layers)) +} /// Returns the directory where log files should be stored for a specific component. /// Creates the directory structure if it doesn't exist.