From cef3ff50b4eaa44c0bd83bae0b91f9d7bdf18e64 Mon Sep 17 00:00:00 2001 From: Lucio Franco Date: Wed, 26 Nov 2025 14:52:40 -0800 Subject: [PATCH 1/3] [spr] changes to main this commit is based on Created using jj-spr 0.1.0 [skip ci] --- Cargo.lock | 133 +------- apps/framework-cli/Cargo.toml | 21 +- apps/framework-cli/src/cli/logger.rs | 478 +++++++++++---------------- apps/framework-cli/src/main.rs | 5 +- 4 files changed, 203 insertions(+), 434 deletions(-) diff --git a/Cargo.lock b/Cargo.lock index aa23183992..f481594a9d 100644 --- a/Cargo.lock +++ b/Cargo.lock @@ -2775,12 +2775,6 @@ dependencies = [ "num-bigint", "num-traits", "openssl", - "opentelemetry 0.29.1", - "opentelemetry-appender-tracing", - "opentelemetry-http 0.29.0", - "opentelemetry-otlp 0.29.0", - "opentelemetry-semantic-conventions", - "opentelemetry_sdk 0.29.0", "pbkdf2", "percent-encoding", "petgraph 0.8.3", @@ -3115,32 +3109,6 @@ dependencies = [ "thiserror 1.0.69", ] -[[package]] -name = "opentelemetry" -version = "0.29.1" -source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "9e87237e2775f74896f9ad219d26a2081751187eb7c9f5c58dde20a23b95d16c" -dependencies = [ - "futures-core", - "futures-sink", - "js-sys", - "pin-project-lite", - "thiserror 2.0.17", - "tracing", -] - -[[package]] -name = "opentelemetry-appender-tracing" -version = "0.29.1" -source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "e716f864eb23007bdd9dc4aec381e188a1cee28eecf22066772b5fd822b9727d" -dependencies = [ - "opentelemetry 0.29.1", - "tracing", - "tracing-core", - "tracing-subscriber", -] - [[package]] name = "opentelemetry-http" version = "0.26.0" @@ -3150,22 +3118,8 @@ dependencies = [ "async-trait", "bytes", "http 1.3.1", - "opentelemetry 0.26.0", - "reqwest 0.12.23", -] - -[[package]] -name = "opentelemetry-http" -version = "0.29.0" -source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "46d7ab32b827b5b495bd90fa95a6cb65ccc293555dcc3199ae2937d2d237c8ed" -dependencies = [ - "async-trait", - "bytes", - "http 1.3.1", - "opentelemetry 0.29.1", + "opentelemetry", "reqwest 0.12.23", - "tracing", ] [[package]] @@ -3177,10 +3131,10 @@ dependencies = [ "async-trait", "futures-core", "http 1.3.1", - "opentelemetry 0.26.0", - "opentelemetry-http 0.26.0", - "opentelemetry-proto 0.26.1", - "opentelemetry_sdk 0.26.0", + "opentelemetry", + "opentelemetry-http", + "opentelemetry-proto", + "opentelemetry_sdk", "prost", "reqwest 0.12.23", "thiserror 1.0.69", @@ -3188,32 +3142,14 @@ dependencies = [ "tonic", ] -[[package]] -name = "opentelemetry-otlp" -version = "0.29.0" -source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "d899720fe06916ccba71c01d04ecd77312734e2de3467fd30d9d580c8ce85656" -dependencies = [ - "futures-core", - "http 1.3.1", - "opentelemetry 0.29.1", - "opentelemetry-http 0.29.0", - "opentelemetry-proto 0.29.0", - "opentelemetry_sdk 0.29.0", - "prost", - "serde_json", - "thiserror 2.0.17", - "tokio", -] - [[package]] name = "opentelemetry-prometheus" version = "0.17.0" source = "git+https://github.com/open-telemetry/opentelemetry-rust.git?rev=e911383#e91138351a689cd21923c15eb48f5fbc95ded807" dependencies = [ "once_cell", - "opentelemetry 0.26.0", - "opentelemetry_sdk 0.26.0", + "opentelemetry", + "opentelemetry_sdk", "prometheus", "protobuf 2.28.0", ] @@ -3224,33 +3160,12 @@ version = "0.26.1" source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "c9d3968ce3aefdcca5c27e3c4ea4391b37547726a70893aab52d3de95d5f8b34" dependencies = [ - "opentelemetry 0.26.0", - "opentelemetry_sdk 0.26.0", - "prost", - "tonic", -] - -[[package]] -name = "opentelemetry-proto" -version = "0.29.0" -source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "8c40da242381435e18570d5b9d50aca2a4f4f4d8e146231adb4e7768023309b3" -dependencies = [ - "base64 0.22.1", - "hex", - "opentelemetry 0.29.1", - "opentelemetry_sdk 0.29.0", + "opentelemetry", + "opentelemetry_sdk", "prost", - "serde", "tonic", ] -[[package]] -name = "opentelemetry-semantic-conventions" -version = "0.29.0" -source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "84b29a9f89f1a954936d5aa92f19b2feec3c8f3971d3e96206640db7f9706ae3" - [[package]] name = "opentelemetry_sdk" version = "0.26.0" @@ -3263,7 +3178,7 @@ dependencies = [ "futures-util", "glob", "once_cell", - "opentelemetry 0.26.0", + "opentelemetry", "percent-encoding", "rand 0.8.5", "serde_json", @@ -3272,26 +3187,6 @@ dependencies = [ "tokio-stream", ] -[[package]] -name = "opentelemetry_sdk" -version = "0.29.0" -source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "afdefb21d1d47394abc1ba6c57363ab141be19e27cc70d0e422b7f303e4d290b" -dependencies = [ - "futures-channel", - "futures-executor", - "futures-util", - "glob", - "opentelemetry 0.29.1", - "percent-encoding", - "rand 0.9.2", - "serde_json", - "thiserror 2.0.17", - "tokio", - "tokio-stream", - "tracing", -] - [[package]] name = "ordered-float" version = "2.10.1" @@ -5348,10 +5243,10 @@ dependencies = [ "itertools 0.13.0", "lru", "mockall", - "opentelemetry 0.26.0", - "opentelemetry-otlp 0.26.0", + "opentelemetry", + "opentelemetry-otlp", "opentelemetry-prometheus", - "opentelemetry_sdk 0.26.0", + "opentelemetry_sdk", "parking_lot", "pid", "pin-project", @@ -5388,7 +5283,7 @@ dependencies = [ "async-trait", "derive_builder", "derive_more", - "opentelemetry 0.26.0", + "opentelemetry", "prost", "prost-types", "serde_json", diff --git a/apps/framework-cli/Cargo.toml b/apps/framework-cli/Cargo.toml index 2d3a86015e..5bdac67763 100644 --- a/apps/framework-cli/Cargo.toml +++ b/apps/framework-cli/Cargo.toml @@ -35,7 +35,7 @@ convert_case = "0.6.0" humantime = "2.1.0" uuid = { version = "1.6", features = ["v4", "serde"] } serde_json = { version = "1.0.133", features = ["preserve_order"] } -serde_urlencoded = "0.7" +serde_urlencoded = "0.7" semver = "1.0" base64 = "0.22.0" async-recursion = "1.1.0" @@ -84,23 +84,6 @@ logos = "0.15.0" # Monitoring tracing = "0.1.40" tracing-subscriber = { version = "0.3", features = ["env-filter", "json", "fmt"] } -opentelemetry_sdk = { version = "0.29.0", features = [ - "logs", - "metrics", - "trace", - "rt-tokio", -] } -opentelemetry-semantic-conventions = "0.29" -opentelemetry = "0.29" -opentelemetry-appender-tracing = "0.29.0" -opentelemetry-otlp = { version = "0.29.0", default-features = false, features = [ - "logs", - "metrics", - "trace", - "http-json", - "tokio", -] } -opentelemetry-http = { version = "0.29.0", features = ["reqwest"] } prometheus-client = "0.23" serde_yaml = "0.9.34" temporal-sdk-core = { git = "https://github.com/temporalio/sdk-core.git", rev = "b94b2fc172c2740705b3454a0e04b856fe426233" } @@ -136,4 +119,4 @@ walkdir = "2" used_linker = [] [package.metadata.cargo-machete] -ignored = ["opentelemetry-http", "prost-types", "rustpython-ast"] +ignored = ["prost-types", "rustpython-ast"] diff --git a/apps/framework-cli/src/cli/logger.rs b/apps/framework-cli/src/cli/logger.rs index f5e60520a9..da6a939c0d 100644 --- a/apps/framework-cli/src/cli/logger.rs +++ b/apps/framework-cli/src/cli/logger.rs @@ -8,13 +8,12 @@ //! The logging system is built using `tracing-subscriber` layers: //! - **EnvFilter Layer**: Provides `RUST_LOG` support for module-level filtering //! - **Format Layer**: Either legacy (fern-compatible) or modern (tracing native) format -//! - **OTEL Layer**: Optional OpenTelemetry export for observability platforms //! //! ## Components //! //! - `LoggerLevel`: An enumeration representing the different levels of logging: DEBUG, INFO, WARN, and ERROR. //! - `LogFormat`: Either Text or JSON output format. -//! - `LoggerSettings`: A struct that holds the settings for the logger, including format, level, and export options. +//! - `LoggerSettings`: A struct that holds the settings for the logger, including format, level, and output options. //! - `setup_logging`: A function used to set up the logging system with the provided settings. //! - `LegacyFormatLayer`: Custom layer that matches the old fern format exactly (for backward compatibility). //! @@ -38,8 +37,6 @@ //! - **Date-based file rotation**: Daily log files in `~/.moose/YYYY-MM-DD-cli.log` //! - **Automatic cleanup**: Deletes logs older than 7 days //! - **Session ID tracking**: Optional per-session identifier in logs -//! - **Machine ID tracking**: Included in every log event -//! - **OpenTelemetry export**: Optional OTLP/HTTP JSON export to observability platforms //! - **Configurable outputs**: File and/or stdout //! //! ## Environment Variables @@ -49,7 +46,6 @@ //! - `MOOSE_LOGGER__LEVEL`: Log level (DEBUG, INFO, WARN, ERROR) //! - `MOOSE_LOGGER__STDOUT`: Output to stdout vs file (default: `false`) //! - `MOOSE_LOGGER__FORMAT`: Text or JSON (default: Text) -//! - `MOOSE_LOGGER__EXPORT_TO`: OTEL endpoint URL //! - `MOOSE_LOGGER__INCLUDE_SESSION_ID`: Include session ID in logs (default: `false`) //! //! ## Usage @@ -81,13 +77,6 @@ //! fern-based log format (e.g., Boreal/hosting_telemetry). The modern format can be enabled //! via environment variable once downstream consumers are ready. -use hyper::Uri; -use opentelemetry::KeyValue; -use opentelemetry_appender_tracing::layer::OpenTelemetryTracingBridge; -use opentelemetry_otlp::{Protocol, WithExportConfig}; -use opentelemetry_sdk::logs::{BatchLogProcessor, SdkLoggerProvider}; -use opentelemetry_sdk::Resource; -use opentelemetry_semantic_conventions::resource::SERVICE_NAME; use serde::Deserialize; use std::env; use std::fmt; @@ -150,9 +139,6 @@ pub struct LoggerSettings { #[serde(default = "default_log_format")] pub format: LogFormat, - #[serde(deserialize_with = "parsing_url", default = "Option::default")] - pub export_to: Option, - #[serde(default = "default_include_session_id")] pub include_session_id: bool, @@ -160,14 +146,6 @@ pub struct LoggerSettings { pub use_tracing_format: bool, } -fn parsing_url<'de, D>(deserializer: D) -> Result, D::Error> -where - D: serde::Deserializer<'de>, -{ - let s: Option = Option::deserialize(deserializer)?; - Ok(s.and_then(|s| s.parse().ok())) -} - fn default_log_file() -> String { DEFAULT_LOG_FILE_FORMAT.to_string() } @@ -202,7 +180,6 @@ impl Default for LoggerSettings { level: default_log_level(), stdout: default_log_stdout(), format: default_log_format(), - export_to: None, include_session_id: default_include_session_id(), use_tracing_format: default_use_tracing_format(), } @@ -255,109 +232,168 @@ fn clean_old_logs() { } } -// Error that rolls up all the possible errors that can occur during logging setup -#[derive(thiserror::Error, Debug)] -pub enum LoggerError { - #[error("Error setting up OTEL logger: {0}")] - OtelSetup(String), +/// Trait for formatting log events. Implementations are monomorphized, +/// allowing the compiler to inline the format logic directly into `on_event`. +/// +/// Formatters write directly to the provided writer to avoid intermediate allocations. +trait LegacyFormatter { + fn write_event( + &self, + writer: &mut W, + level: &Level, + target: &str, + event: &Event<'_>, + ) -> std::io::Result<()>; } -/// Custom fields that get injected into every log event +/// Text formatter matching fern's text format exactly #[derive(Clone)] -struct CustomFields { - session_id: String, - #[allow(dead_code)] // Will be used when OTEL support is re-enabled - machine_id: String, -} - -/// Layer that formats logs to match the legacy fern format exactly -struct LegacyFormatLayer { - writer: W, - format: LogFormat, +struct TextFormatter { include_session_id: bool, - custom_fields: CustomFields, + session_id: String, } -impl LegacyFormatLayer { - fn new( - writer: W, - format: LogFormat, - include_session_id: bool, - custom_fields: CustomFields, - ) -> Self { +impl TextFormatter { + fn new(include_session_id: bool, session_id: String) -> Self { Self { - writer, - format, include_session_id, - custom_fields, + session_id, } } +} - fn format_text(&self, level: &Level, target: &str, message: &str) -> String { - // Match current fern text format exactly - format!( - "[{} {}{} - {}] {}", +impl LegacyFormatter for TextFormatter { + #[inline] + fn write_event( + &self, + writer: &mut W, + level: &Level, + target: &str, + event: &Event<'_>, + ) -> std::io::Result<()> { + // Write prefix: [timestamp LEVEL - target] + write!( + writer, + "[{} {}", humantime::format_rfc3339_seconds(SystemTime::now()), level, - if self.include_session_id { - format!(" {}", self.custom_fields.session_id) - } else { - String::new() - }, - target, - message - ) + )?; + + if self.include_session_id { + write!(writer, " {}", self.session_id)?; + } + + write!(writer, " - {}] ", target)?; + + // Write message directly without intermediate String + let mut visitor = DirectWriteVisitor { writer }; + event.record(&mut visitor); + + writeln!(writer) } +} + +/// JSON formatter matching fern's JSON format exactly +#[derive(Clone)] +struct JsonFormatter { + include_session_id: bool, + session_id: String, +} - fn format_json(&self, level: &Level, target: &str, message: &str) -> String { - // Match current fern JSON format exactly - let mut log_json = serde_json::json!({ +impl JsonFormatter { + fn new(include_session_id: bool, session_id: String) -> Self { + Self { + include_session_id, + session_id, + } + } +} + +impl LegacyFormatter for JsonFormatter { + #[inline] + fn write_event( + &self, + writer: &mut W, + level: &Level, + target: &str, + event: &Event<'_>, + ) -> std::io::Result<()> { + // Extract message first since it appears in the middle of the JSON object + let mut message_visitor = MessageVisitor::default(); + event.record(&mut message_visitor); + + // Build JSON object - serde_json handles escaping correctly + let mut log_entry = serde_json::json!({ "timestamp": chrono::Utc::now().to_rfc3339(), "severity": level.to_string(), "target": target, - "message": message, + "message": message_visitor.message, }); if self.include_session_id { - log_json["session_id"] = - serde_json::Value::String(self.custom_fields.session_id.clone()); + log_entry["session_id"] = serde_json::Value::String(self.session_id.clone()); } - serde_json::to_string(&log_json) - .expect("formatting `serde_json::Value` with string keys never fails") + serde_json::to_writer(&mut *writer, &log_entry).map_err(std::io::Error::other)?; + writeln!(writer) + } +} + +/// Layer that formats logs to match the legacy fern format exactly. +/// +/// Generic over the formatter type `F`, enabling monomorphization so the +/// compiler can inline the format logic directly into `on_event`. +struct LegacyFormatLayer { + writer: W, + formatter: F, +} + +impl LegacyFormatLayer { + fn new(writer: W, formatter: F) -> Self { + Self { writer, formatter } } } -impl Layer for LegacyFormatLayer +impl Layer for LegacyFormatLayer where S: Subscriber + for<'a> LookupSpan<'a>, W: for<'writer> MakeWriter<'writer> + 'static, + F: LegacyFormatter + 'static, { fn on_event(&self, event: &Event<'_>, _ctx: Context<'_, S>) { - // Extract metadata let metadata = event.metadata(); - let level = metadata.level(); - let target = metadata.target(); + let mut writer = self.writer.make_writer(); - // Extract message using visitor - let mut visitor = MessageVisitor::default(); - event.record(&mut visitor); - let message = visitor.message; + // Write directly to output, avoiding intermediate allocations + let _ = self + .formatter + .write_event(&mut writer, metadata.level(), metadata.target(), event); + } +} - // Format based on LogFormat - let output = if self.format == LogFormat::Text { - self.format_text(level, target, &message) - } else { - self.format_json(level, target, &message) - }; +/// Visitor that writes the message field directly to a writer, avoiding intermediate allocation. +/// +/// For string messages (the common case), writes directly without any allocation. +/// For debug-formatted messages, uses a small stack buffer to strip surrounding quotes. +struct DirectWriteVisitor<'a, W> { + writer: &'a mut W, +} - // Write to output - let mut writer = self.writer.make_writer(); - let _ = writer.write_all(output.as_bytes()); - let _ = writer.write_all(b"\n"); +impl Visit for DirectWriteVisitor<'_, W> { + fn record_debug(&mut self, field: &Field, value: &dyn fmt::Debug) { + if field.name() == "message" { + let _ = write!(self.writer, "{:?}", value); + } + } + + fn record_str(&mut self, field: &Field, value: &str) { + if field.name() == "message" { + let _ = self.writer.write_all(value.as_bytes()); + } } } +/// Visitor that extracts the message into a String (used for JSON where we need the value mid-output). #[derive(Default)] struct MessageVisitor { message: String, @@ -367,10 +403,12 @@ impl Visit for MessageVisitor { fn record_debug(&mut self, field: &Field, value: &dyn fmt::Debug) { if field.name() == "message" { self.message = format!("{:?}", value); - // Remove surrounding quotes from debug format - if self.message.starts_with('"') && self.message.ends_with('"') { - self.message = self.message[1..self.message.len() - 1].to_string(); - } + } + } + + fn record_str(&mut self, field: &Field, value: &str) { + if field.name() == "message" { + self.message = value.to_string(); } } } @@ -412,252 +450,104 @@ fn create_rolling_file_appender(date_format: &str) -> DateBasedWriter { DateBasedWriter::new(date_format.to_string()) } -/// Creates an OpenTelemetry layer for log export -/// -/// This function sets up OTLP log export using opentelemetry-appender-tracing. -/// It creates a LoggerProvider with a batch processor and OTLP exporter. -fn create_otel_layer( - endpoint: &Uri, - session_id: &str, - machine_id: &str, -) -> Result, LoggerError> { - use crate::utilities::decode_object; - use serde_json::Value; - use std::env::VarError; - - // Create base resource attributes - let mut resource_attributes = vec![ - KeyValue::new(SERVICE_NAME, "moose-cli"), - KeyValue::new("session_id", session_id.to_string()), - KeyValue::new("machine_id", machine_id.to_string()), - ]; - - // Add labels from MOOSE_METRIC__LABELS environment variable - match env::var("MOOSE_METRIC__LABELS") { - Ok(base64) => match decode_object::decode_base64_to_json(&base64) { - Ok(Value::Object(labels)) => { - for (key, value) in labels { - if let Some(value_str) = value.as_str() { - resource_attributes.push(KeyValue::new(key, value_str.to_string())); - } - } - } - Ok(_) => warn!("Unexpected value for MOOSE_METRIC_LABELS"), - Err(e) => { - warn!("Error decoding MOOSE_METRIC_LABELS: {}", e); - } - }, - Err(VarError::NotPresent) => {} - Err(VarError::NotUnicode(e)) => { - warn!("MOOSE_METRIC__LABELS is not unicode: {:?}", e); - } - } - - // Create resource with all attributes - let resource = Resource::builder() - .with_attributes(resource_attributes) - .build(); - - // Build OTLP log exporter - let exporter = opentelemetry_otlp::LogExporter::builder() - .with_http() - .with_protocol(Protocol::HttpJson) - .with_endpoint(endpoint.to_string()) - .build() - .map_err(|e| LoggerError::OtelSetup(format!("Failed to build OTLP exporter: {}", e)))?; - - // Create logger provider with batch processor - let provider = SdkLoggerProvider::builder() - .with_resource(resource) - .with_log_processor(BatchLogProcessor::builder(exporter).build()) - .build(); - - // Create the tracing bridge layer - Ok(OpenTelemetryTracingBridge::new(&provider)) -} - -pub fn setup_logging(settings: &LoggerSettings, machine_id: &str) -> Result<(), LoggerError> { +pub fn setup_logging(settings: &LoggerSettings) { clean_old_logs(); let session_id = CONTEXT.get(CTX_SESSION_ID).unwrap(); - // Create custom fields for use in formatters - let custom_fields = CustomFields { - session_id: session_id.to_string(), - machine_id: machine_id.to_string(), - }; - // Setup logging based on format type if settings.use_tracing_format { // Modern format using tracing built-ins - setup_modern_format(settings, session_id, machine_id) + setup_modern_format(settings); } else { // Legacy format matching fern exactly - setup_legacy_format(settings, session_id, machine_id, custom_fields) + setup_legacy_format(settings, session_id); } } -fn setup_modern_format( - settings: &LoggerSettings, - session_id: &str, - machine_id: &str, -) -> Result<(), LoggerError> { +fn setup_modern_format(settings: &LoggerSettings) { let env_filter = EnvFilter::try_from_default_env() .unwrap_or_else(|_| EnvFilter::new(settings.level.to_tracing_level().to_string())); - // Setup with or without OTEL based on configuration - if let Some(endpoint) = &settings.export_to { - let otel_layer = create_otel_layer(endpoint, session_id, machine_id)?; - - if settings.stdout { - let format_layer = tracing_subscriber::fmt::layer() - .with_writer(std::io::stdout) - .with_target(true) - .with_level(true); - - if settings.format == LogFormat::Json { - tracing_subscriber::registry() - .with(otel_layer) - .with(env_filter) - .with(format_layer.json()) - .init(); - } else { - tracing_subscriber::registry() - .with(otel_layer) - .with(env_filter) - .with(format_layer.compact()) - .init(); - } + if settings.stdout { + let format_layer = tracing_subscriber::fmt::layer() + .with_writer(std::io::stdout) + .with_target(true) + .with_level(true); + + if settings.format == LogFormat::Json { + tracing_subscriber::registry() + .with(env_filter) + .with(format_layer.json()) + .init(); } else { - let file_appender = create_rolling_file_appender(&settings.log_file_date_format); - let format_layer = tracing_subscriber::fmt::layer() - .with_writer(file_appender) - .with_target(true) - .with_level(true); - - if settings.format == LogFormat::Json { - tracing_subscriber::registry() - .with(otel_layer) - .with(env_filter) - .with(format_layer.json()) - .init(); - } else { - tracing_subscriber::registry() - .with(otel_layer) - .with(env_filter) - .with(format_layer.compact()) - .init(); - } + tracing_subscriber::registry() + .with(env_filter) + .with(format_layer.compact()) + .init(); } } else { - // No OTEL export - if settings.stdout { - let format_layer = tracing_subscriber::fmt::layer() - .with_writer(std::io::stdout) - .with_target(true) - .with_level(true); - - if settings.format == LogFormat::Json { - tracing_subscriber::registry() - .with(env_filter) - .with(format_layer.json()) - .init(); - } else { - tracing_subscriber::registry() - .with(env_filter) - .with(format_layer.compact()) - .init(); - } + let file_appender = create_rolling_file_appender(&settings.log_file_date_format); + let format_layer = tracing_subscriber::fmt::layer() + .with_writer(file_appender) + .with_target(true) + .with_level(true); + + if settings.format == LogFormat::Json { + tracing_subscriber::registry() + .with(env_filter) + .with(format_layer.json()) + .init(); } else { - let file_appender = create_rolling_file_appender(&settings.log_file_date_format); - let format_layer = tracing_subscriber::fmt::layer() - .with_writer(file_appender) - .with_target(true) - .with_level(true); - - if settings.format == LogFormat::Json { - tracing_subscriber::registry() - .with(env_filter) - .with(format_layer.json()) - .init(); - } else { - tracing_subscriber::registry() - .with(env_filter) - .with(format_layer.compact()) - .init(); - } + tracing_subscriber::registry() + .with(env_filter) + .with(format_layer.compact()) + .init(); } } - - Ok(()) } -fn setup_legacy_format( - settings: &LoggerSettings, - _session_id: &str, - _machine_id: &str, - custom_fields: CustomFields, -) -> Result<(), LoggerError> { +fn setup_legacy_format(settings: &LoggerSettings, session_id: &str) { let env_filter = EnvFilter::try_from_default_env() .unwrap_or_else(|_| EnvFilter::new(settings.level.to_tracing_level().to_string())); - // Setup with or without OTEL based on configuration - if let Some(_endpoint) = &settings.export_to { - if settings.stdout { - let legacy_layer = LegacyFormatLayer::new( - std::io::stdout, - settings.format.clone(), - settings.include_session_id, - custom_fields, - ); - + // Branch on format type at setup time to get monomorphized Layer implementations. + // Each branch creates a concrete formatter type, enabling the compiler to inline + // the format logic directly into on_event. + match (&settings.format, settings.stdout) { + (LogFormat::Text, true) => { + let formatter = TextFormatter::new(settings.include_session_id, session_id.to_string()); + let legacy_layer = LegacyFormatLayer::new(std::io::stdout, formatter); tracing_subscriber::registry() .with(env_filter) .with(legacy_layer) .init(); - } else { + } + (LogFormat::Text, false) => { + let formatter = TextFormatter::new(settings.include_session_id, session_id.to_string()); let file_appender = create_rolling_file_appender(&settings.log_file_date_format); - let legacy_layer = LegacyFormatLayer::new( - file_appender, - settings.format.clone(), - settings.include_session_id, - custom_fields, - ); - + let legacy_layer = LegacyFormatLayer::new(file_appender, formatter); tracing_subscriber::registry() .with(env_filter) .with(legacy_layer) .init(); } - } else { - // No OTEL export - if settings.stdout { - let legacy_layer = LegacyFormatLayer::new( - std::io::stdout, - settings.format.clone(), - settings.include_session_id, - custom_fields.clone(), - ); - + (LogFormat::Json, true) => { + let formatter = JsonFormatter::new(settings.include_session_id, session_id.to_string()); + let legacy_layer = LegacyFormatLayer::new(std::io::stdout, formatter); tracing_subscriber::registry() .with(env_filter) .with(legacy_layer) .init(); - } else { + } + (LogFormat::Json, false) => { + let formatter = JsonFormatter::new(settings.include_session_id, session_id.to_string()); let file_appender = create_rolling_file_appender(&settings.log_file_date_format); - let legacy_layer = LegacyFormatLayer::new( - file_appender, - settings.format.clone(), - settings.include_session_id, - custom_fields, - ); - + let legacy_layer = LegacyFormatLayer::new(file_appender, formatter); tracing_subscriber::registry() .with(env_filter) .with(legacy_layer) .init(); } } - - Ok(()) } diff --git a/apps/framework-cli/src/main.rs b/apps/framework-cli/src/main.rs index 66aada6f27..4a9b36de60 100644 --- a/apps/framework-cli/src/main.rs +++ b/apps/framework-cli/src/main.rs @@ -51,10 +51,11 @@ fn main() -> ExitCode { cli::settings::init_config_file().expect("Failed to init config file"); let config = cli::settings::read_settings().expect("Failed to read settings"); - let machine_id = utilities::machine_id::get_or_create_machine_id(); // Setup logging - cli::logger::setup_logging(&config.logger, &machine_id).expect("Failed to setup logging"); + cli::logger::setup_logging(&config.logger); + + let machine_id = utilities::machine_id::get_or_create_machine_id(); // Parse CLI arguments let cli_result = match cli::Cli::try_parse() { From 32e4116200359ff3c7ad21ff5349d6e3658df4d9 Mon Sep 17 00:00:00 2001 From: Lucio Franco Date: Tue, 2 Dec 2025 08:54:14 -0800 Subject: [PATCH 2/3] fix ansi in file bug Created using jj-spr 0.1.0 --- apps/framework-cli/src/cli/logger.rs | 5 ++++- 1 file changed, 4 insertions(+), 1 deletion(-) diff --git a/apps/framework-cli/src/cli/logger.rs b/apps/framework-cli/src/cli/logger.rs index f0eedb0df1..7c6ee89ba6 100644 --- a/apps/framework-cli/src/cli/logger.rs +++ b/apps/framework-cli/src/cli/logger.rs @@ -504,12 +504,15 @@ fn setup_modern_format(settings: &LoggerSettings) { .init(); } } else { + // For file output, explicitly disable ANSI codes regardless of no_ansi setting. + // Files are not terminals and don't render colors. tracing-subscriber defaults + // to ANSI=true, so we must explicitly set it to false for file writers. let file_appender = create_rolling_file_appender(&settings.log_file_date_format); let format_layer = tracing_subscriber::fmt::layer() .with_writer(file_appender) .with_target(true) .with_level(true) - .with_ansi(ansi_enabled); + .with_ansi(false); if settings.format == LogFormat::Json { tracing_subscriber::registry() From 72a4a86b49b9da5f2fb2bef1bcc850134f655a73 Mon Sep 17 00:00:00 2001 From: Lucio Franco Date: Tue, 2 Dec 2025 12:03:51 -0800 Subject: [PATCH 3/3] make writer most testable and actually test it Created using jj-spr 0.1.0 --- .../framework-cli/src/cli/display/terminal.rs | 138 ++++++++++++++++-- 1 file changed, 122 insertions(+), 16 deletions(-) diff --git a/apps/framework-cli/src/cli/display/terminal.rs b/apps/framework-cli/src/cli/display/terminal.rs index 573c4fe5ef..1886357bd8 100644 --- a/apps/framework-cli/src/cli/display/terminal.rs +++ b/apps/framework-cli/src/cli/display/terminal.rs @@ -206,9 +206,14 @@ impl StyledText { /// write_styled_line(&styled, "Operation completed successfully", false)?; /// # Ok::<(), std::io::Error>(()) /// ``` -pub fn write_styled_line(styled_text: &StyledText, message: &str, no_ansi: bool) -> IoResult<()> { - let mut stdout = stdout(); - +/// Internal helper that writes a styled action line to any writer. +/// This allows for testing by capturing output to a buffer. +fn write_styled_line_to( + writer: &mut W, + styled_text: &StyledText, + message: &str, + no_ansi: bool, +) -> IoResult<()> { // Ensure action is exactly ACTION_WIDTH characters, right-aligned // Use character-aware truncation to avoid panics on multi-byte UTF-8 characters let truncated_action = if styled_text.text.chars().count() > ACTION_WIDTH { @@ -226,37 +231,42 @@ pub fn write_styled_line(styled_text: &StyledText, message: &str, no_ansi: bool) if !no_ansi { // Apply foreground color if let Some(color) = styled_text.foreground { - execute!(stdout, SetForegroundColor(color))?; + execute!(writer, SetForegroundColor(color))?; } // Apply background color if let Some(color) = styled_text.background { - execute!(stdout, SetBackgroundColor(color))?; + execute!(writer, SetBackgroundColor(color))?; } // Apply bold if styled_text.bold { - execute!(stdout, SetAttribute(Attribute::Bold))?; + execute!(writer, SetAttribute(Attribute::Bold))?; } } // Write the styled, right-aligned action text - execute!(stdout, Print(&padded_action))?; + execute!(writer, Print(&padded_action))?; // Reset styling before writing the message (only if ANSI was applied) if !no_ansi { - execute!(stdout, ResetColor)?; + execute!(writer, ResetColor)?; if styled_text.bold { - execute!(stdout, SetAttribute(Attribute::Reset))?; + execute!(writer, SetAttribute(Attribute::Reset))?; } } // Write separator and message - execute!(stdout, Print(" "), Print(message), Print("\n"))?; + execute!(writer, Print(" "), Print(message), Print("\n"))?; Ok(()) } +pub fn write_styled_line(styled_text: &StyledText, message: &str, no_ansi: bool) -> IoResult<()> { + let mut stdout = stdout(); + write_styled_line_to(&mut stdout, styled_text, message, no_ansi) +} + #[cfg(test)] mod tests { use super::*; @@ -330,13 +340,109 @@ mod tests { let _styled = StyledText::from_str(""); // Just test that empty text doesn't panic } - // Note: write_styled_line is difficult to test without mocking stdout, - // but we can test that it doesn't panic with various inputs + // Tests that actually verify ANSI codes are present/absent in output + // by using write_styled_line_to with a buffer + + #[test] + fn test_write_styled_line_with_ansi_contains_escape_codes() { + let mut buffer = Vec::new(); + let styled = StyledText::from_str("Test").green().bold(); + + // no_ansi = false means ANSI codes SHOULD be present + write_styled_line_to(&mut buffer, &styled, "test message", false).unwrap(); + let output = String::from_utf8(buffer).unwrap(); + + // Check for ANSI escape code prefix (\x1b[ or ESC[) + assert!( + output.contains("\x1b["), + "Output with no_ansi=false should contain ANSI escape codes. Got: {:?}", + output + ); + } + #[test] - fn test_write_styled_line_doesnt_panic() { + fn test_write_styled_line_without_ansi_no_escape_codes() { + let mut buffer = Vec::new(); let styled = StyledText::from_str("Test").green().bold(); - // This test mainly ensures the function signature is correct - // and doesn't panic during compilation - let _ = write_styled_line(&styled, "test message", false); + + // no_ansi = true means ANSI codes should NOT be present + write_styled_line_to(&mut buffer, &styled, "test message", true).unwrap(); + let output = String::from_utf8(buffer).unwrap(); + + // Verify no ANSI escape codes + assert!( + !output.contains("\x1b["), + "Output with no_ansi=true should NOT contain ANSI escape codes. Got: {:?}", + output + ); + + // Verify the actual text content is still there + assert!(output.contains("Test"), "Should contain the action text"); + assert!( + output.contains("test message"), + "Should contain the message" + ); + } + + #[test] + fn test_write_styled_line_bold_ansi_code() { + let mut buffer = Vec::new(); + let styled = StyledText::from_str("Bold").bold(); + + write_styled_line_to(&mut buffer, &styled, "message", false).unwrap(); + let output = String::from_utf8(buffer).unwrap(); + + // Bold is attribute 1, should see \x1b[1m + assert!(output.contains("\x1b[1m"), "Should contain bold ANSI code"); + } + + #[test] + fn test_write_styled_line_all_styles_no_ansi_verified() { + // Verify that ALL color/style combinations produce NO ANSI codes with no_ansi=true + let test_cases = vec![ + ("Cyan", StyledText::from_str("Cyan").cyan()), + ("Green", StyledText::from_str("Green").green()), + ("Yellow", StyledText::from_str("Yellow").yellow()), + ("Red", StyledText::from_str("Red").red()), + ("OnGreen", StyledText::from_str("OnGreen").on_green()), + ("Bold", StyledText::from_str("Bold").bold()), + ("Combined", StyledText::from_str("Combined").green().bold()), + ]; + + for (name, styled) in test_cases { + let mut buffer = Vec::new(); + write_styled_line_to(&mut buffer, &styled, "message", true).unwrap(); + let output = String::from_utf8(buffer).unwrap(); + + assert!( + !output.contains("\x1b["), + "Style '{}' should not produce ANSI codes with no_ansi=true. Got: {:?}", + name, + output + ); + } + } + + #[test] + fn test_write_styled_line_all_styles_with_ansi_verified() { + // Verify that color/style combinations DO produce ANSI codes with no_ansi=false + let test_cases = vec![ + ("Cyan", StyledText::from_str("Cyan").cyan()), + ("Green", StyledText::from_str("Green").green()), + ("Bold", StyledText::from_str("Bold").bold()), + ]; + + for (name, styled) in test_cases { + let mut buffer = Vec::new(); + write_styled_line_to(&mut buffer, &styled, "message", false).unwrap(); + let output = String::from_utf8(buffer).unwrap(); + + assert!( + output.contains("\x1b["), + "Style '{}' should produce ANSI codes with no_ansi=false. Got: {:?}", + name, + output + ); + } } }