mirror of
https://github.com/block/goose.git
synced 2026-06-02 06:19:33 +02:00
refactor(logging): consolidate logging setup into shared helper in goose crate (#8817)
Signed-off-by: Rodolfo Olivieri <rolivier@redhat.com> Signed-off-by: Douwe Osinga <douwe@squareup.com> Co-authored-by: Douwe Osinga <douwe@squareup.com>
This commit is contained in:
Generated
+1
-2
@@ -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",
|
||||
|
||||
@@ -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 }
|
||||
|
||||
@@ -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());
|
||||
}
|
||||
}
|
||||
|
||||
@@ -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 }
|
||||
|
||||
@@ -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(())
|
||||
}
|
||||
|
||||
@@ -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"] }
|
||||
|
||||
@@ -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<impl SubscriberInitExt + Send + Sync + 'static> {
|
||||
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<Box<dyn Layer<Registry> + 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.
|
||||
|
||||
Reference in New Issue
Block a user