diff --git a/CHANGELOG.md b/CHANGELOG.md index 1996ff3..b19e044 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -4,6 +4,25 @@ All notable changes to this project are documented here. The format follows [Keep a Changelog](https://keepachangelog.com/en/1.1.0/), and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0.html). +## [1.0.1] — 2026-08-21 + +### Fixed + +- Span fields no longer carry ANSI escape codes into files or colourless + consoles. The escape codes were coming from span-field *caching*: the + layer's own ANSI flag — which defaulted on — decides how a span's fields are + rendered into the cache every event then prints verbatim, and the sinks only + ever set the flag on the event format. Found live: a web service's + per-request span (`http_request{method=…}`) arrived in its log file wrapped + in italic/dim codes with colour configured off everywhere. + + The file sinks also get their own cache now (a distinct field-formatter + type), so a *coloured* console beside a text file cannot bleed escape codes + into it either — previously the two shared one cache and whichever layer + formatted a span first decided what the other printed, which is why services + had to switch console colour off to protect their files. Both regressions + are pinned by tests that fail against the previous release. + ## [1.0.0] — 2026-08-21 The stability release. From here, a breaking change to anything public is a diff --git a/Cargo.toml b/Cargo.toml index d43605e..500cc8f 100644 --- a/Cargo.toml +++ b/Cargo.toml @@ -1,6 +1,6 @@ [package] name = "stratify" -version = "1.0.0" +version = "1.0.1" edition = "2021" rust-version = "1.88.0" description = "Layered configuration and structured logging for Rust services: pluggable sources, priority merging, typed access, and a tracing facade" diff --git a/src/logging/sinks.rs b/src/logging/sinks.rs index 4098d99..c14a47d 100644 --- a/src/logging/sinks.rs +++ b/src/logging/sinks.rs @@ -36,6 +36,29 @@ impl Sink { } } +/// `DefaultFields` under a different type, so file sinks get their own span +/// cache. +/// +/// `tracing-subscriber` formats a span's fields once per *field-formatter +/// type* and caches the result in the span's extensions. With every text sink +/// on `DefaultFields`, they all share one cache, so whichever layer touches a +/// span first decides — with its own ANSI setting — what every other layer +/// prints for that span. That is how a coloured console used to write escape +/// codes into the log file. A distinct type is a distinct cache slot: file +/// sinks always cache plain, and the console is free to colour its own. +#[derive(Default)] +pub(super) struct PlainFields(fmt::format::DefaultFields); + +impl<'writer> fmt::FormatFields<'writer> for PlainFields { + fn format_fields( + &self, + writer: fmt::format::Writer<'writer>, + fields: R, + ) -> std::fmt::Result { + self.0.format_fields(writer, fields) + } +} + /// The console sink, using the built-in layout. /// /// Returns nothing when a caller-supplied formatter is in play; that case is @@ -66,6 +89,11 @@ where layer: Some( fmt::layer() .with_writer(writer.clone()) + // On the *layer*, not only the format: the layer's flag is + // what controls how span fields are cached into the span's + // extensions, and the cached string is printed verbatim by + // every event that closes over the span. + .with_ansi(config.use_color) .event_format(WithGlobals { inner: built_in, prefix: globals.to_string(), @@ -96,6 +124,9 @@ where layer: Some( fmt::layer() .with_writer(writer.clone()) + // Plain span cache: a custom formatter styles its own line, + // and the `SpanScope` it receives is rendered from this cache. + .with_ansi(false) .event_format(WithGlobals { inner: BoxedFormat(format), prefix: globals.to_string(), @@ -209,11 +240,20 @@ where .with_target(true) .with_timer(Timestamp(config.timestamp)); - Some(fmt::layer().with_writer(writer).event_format(WithGlobals { - inner: built_in, - prefix: globals.to_string(), - redact: redact.to_vec(), - })) + Some( + fmt::layer() + .with_writer(writer) + // `PlainFields` gives this sink its own span cache, and the layer + // flag keeps that cache free of escape codes, so a coloured + // console beside this file cannot bleed ANSI into it. + .fmt_fields(PlainFields::default()) + .with_ansi(false) + .event_format(WithGlobals { + inner: built_in, + prefix: globals.to_string(), + redact: redact.to_vec(), + }), + ) } /// The file sink in plain text, using a caller-supplied formatter. @@ -236,11 +276,18 @@ where return None; } let format = format?; - Some(fmt::layer().with_writer(writer).event_format(WithGlobals { - inner: BoxedFormat(format), - prefix: globals.to_string(), - redact: redact.to_vec(), - })) + Some( + fmt::layer() + .with_writer(writer) + // Same reasoning as `file_text`: own cache, kept plain. + .fmt_fields(PlainFields::default()) + .with_ansi(false) + .event_format(WithGlobals { + inner: BoxedFormat(format), + prefix: globals.to_string(), + redact: redact.to_vec(), + }), + ) } /// Reproduce a per-sink filter, or one that admits everything. diff --git a/tests/stream_a_file_format.rs b/tests/stream_a_file_format.rs index 9ba08ad..cc7af82 100644 --- a/tests/stream_a_file_format.rs +++ b/tests/stream_a_file_format.rs @@ -9,7 +9,7 @@ use std::fs; use std::path::PathBuf; -use stratify::logging::{FileConfig, FileFormat}; +use stratify::logging::{ConsoleConfig, FileConfig, FileFormat}; use tracing::subscriber::with_default; fn scratch(label: &str) -> PathBuf { @@ -131,3 +131,83 @@ fn json_format_is_still_available_explicitly() { let _ = fs::remove_dir_all(&dir); } + +#[test] +fn span_fields_in_the_file_carry_no_ansi_even_with_color_off_everywhere() { + // Arrange: every sink colourless — the configuration a service captured + // into Log Analytics runs. Span fields used to arrive with italic/dim + // escape codes anyway, because the *layer's* ANSI flag, not the event + // format's, decides how span fields are cached, and it defaulted on. + let dir = std::env::temp_dir().join(format!("lk-ansi-off-{}", std::process::id())); + let _ = fs::remove_dir_all(&dir); + let (subscriber, handle) = stratify::logging::builder() + .with_filter(stratify::logging::EnvFilter::new("info")) + .console(ConsoleConfig::default().with_color(false)) + .file(FileConfig::new(dir.to_string_lossy().to_string()).with_format(FileFormat::Text)) + .build() + .expect("builds"); + + // Act: the event fires inside a span carrying fields, which is what the + // per-request middleware of a web service produces on every line. + with_default(subscriber, || { + let span = tracing::info_span!("http_request", method = "GET", path = "/health"); + let _entered = span.enter(); + tracing::info!(latency = 3, "finished"); + }); + handle.flush(); + drop(handle); + + // Assert + let entry = fs::read_dir(&dir) + .expect("directory") + .filter_map(Result::ok) + .next() + .expect("a log file"); + let body = fs::read_to_string(entry.path()).expect("readable"); + let _ = fs::remove_dir_all(&dir); + + assert!(body.contains("http_request"), "the span renders: {body}"); + assert!( + !body.contains('\u{1b}'), + "no escape codes anywhere in the file: {body:?}" + ); +} + +#[test] +fn a_colored_console_cannot_bleed_ansi_into_the_file() { + // Arrange: console colour *on*, beside a text file. These used to share + // one span-field cache, so whichever layer formatted a span first decided + // what the other printed — the reason services had to turn console colour + // off to protect their files. The file sink now has its own cache. + let dir = std::env::temp_dir().join(format!("lk-ansi-bleed-{}", std::process::id())); + let _ = fs::remove_dir_all(&dir); + let (subscriber, handle) = stratify::logging::builder() + .with_filter(stratify::logging::EnvFilter::new("info")) + .console(ConsoleConfig::default().with_color(true)) + .file(FileConfig::new(dir.to_string_lossy().to_string()).with_format(FileFormat::Text)) + .build() + .expect("builds"); + + // Act + with_default(subscriber, || { + let span = tracing::info_span!("http_request", method = "GET"); + let _entered = span.enter(); + tracing::info!("finished"); + }); + handle.flush(); + drop(handle); + + // Assert + let entry = fs::read_dir(&dir) + .expect("directory") + .filter_map(Result::ok) + .next() + .expect("a log file"); + let body = fs::read_to_string(entry.path()).expect("readable"); + let _ = fs::remove_dir_all(&dir); + + assert!( + !body.contains('\u{1b}'), + "console colour must stay out of the file: {body:?}" + ); +}