-
Notifications
You must be signed in to change notification settings - Fork 28
fix: prevent ANSI escape sequences leaking into file log span fields #815
New issue
Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.
By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.
Already on GitHub? Sign in to your account
Changes from all commits
File filter
Filter by extension
Conversations
Jump to
Diff view
Diff view
There are no files selected for viewing
| Original file line number | Diff line number | Diff line change |
|---|---|---|
|
|
@@ -7,9 +7,10 @@ use std::fmt; | |
| use nu_ansi_term::{Color, Style}; | ||
| use tracing_core::{Event, Level, Subscriber}; | ||
| use tracing_subscriber::{ | ||
| field::MakeVisitor, | ||
| fmt::{ | ||
| FmtContext, FormattedFields, | ||
| format::{FormatEvent, FormatFields, Writer}, | ||
| format::{self, FormatEvent, FormatFields, Writer}, | ||
| time::{FormatTime, SystemTime}, | ||
| }, | ||
| registry::LookupSpan, | ||
|
|
@@ -208,3 +209,144 @@ where | |
| writeln!(writer) | ||
| } | ||
| } | ||
|
|
||
| /// Field formatter for the file logging layer. | ||
| /// | ||
| /// This type exists solely to give the file layer a separate | ||
| /// `FormattedFields<FileFields>` cache slot in the span extensions type-map, | ||
| /// distinct from the console layer's default `FormattedFields<DefaultFields>`. | ||
| /// Without this, the console layer (ANSI-enabled) caches span fields first, | ||
| /// and the file layer reuses those ANSI-contaminated fields. | ||
| pub struct FileFields; | ||
|
|
||
| impl<'writer> MakeVisitor<Writer<'writer>> for FileFields { | ||
| type Visitor = format::DefaultVisitor<'writer>; | ||
|
|
||
| fn make_visitor(&self, target: Writer<'writer>) -> Self::Visitor { | ||
| format::DefaultFields::new().make_visitor(target) | ||
| } | ||
| } | ||
|
|
||
| #[cfg(test)] | ||
| mod tests { | ||
| use std::sync::{Arc, Mutex}; | ||
|
|
||
| use tracing_subscriber::{fmt, layer::SubscriberExt}; | ||
|
|
||
| use super::*; | ||
|
|
||
| /// ANSI escape sequence prefix. Any output destined for a plain-text file | ||
| /// must never contain this byte sequence. | ||
| const ANSI_ESCAPE: &[u8] = b"\x1b["; | ||
|
|
||
| /// Returns true if the byte slice contains an ANSI escape sequence. | ||
| fn contains_ansi(bytes: &[u8]) -> bool { | ||
| bytes | ||
| .windows(ANSI_ESCAPE.len()) | ||
| .any(|window| window == ANSI_ESCAPE) | ||
| } | ||
|
|
||
| /// Helper: build a shared in-memory buffer suitable as a `MakeWriter`. | ||
| fn shared_buffer() -> Arc<Mutex<Vec<u8>>> { | ||
| Arc::new(Mutex::new(Vec::new())) | ||
| } | ||
|
|
||
| /// Verifies that the `FileFields` fix prevents ANSI escape sequences from | ||
| /// leaking into file layer output when two layers share a registry. | ||
| /// | ||
| /// Setup mirrors production: a console layer (ANSI-enabled, `DefaultFields`) | ||
| /// and a file layer (ANSI-disabled, `FileFields`). Both are attached to the | ||
| /// same `Registry`. Because `FileFields` has a distinct `TypeId` from | ||
| /// `DefaultFields`, each layer gets its own `FormattedFields<_>` cache slot | ||
| /// in the span extensions. The file layer therefore never reads the | ||
| /// console layer's ANSI-contaminated cached fields. | ||
| /// | ||
|
Comment on lines
+254
to
+263
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. Outstanding test documentation. These doc comments explain the production scenario, the fix mechanism, and the expected behavior. This will be invaluable for future maintainers who wonder "why does |
||
| /// This test PASSES with the fix (`FileFields`) in place. | ||
| #[test] | ||
| fn test_file_fields_no_ansi_leak_in_span_fields() { | ||
| // Arrange | ||
| let console_buf = shared_buffer(); | ||
| let file_buf = shared_buffer(); | ||
|
|
||
| let console_writer = console_buf.clone(); | ||
| let file_writer = file_buf.clone(); | ||
|
|
||
| // Console layer: ANSI enabled, uses default DefaultFields (implicit). | ||
| let console_layer = | ||
| fmt::layer() | ||
| .with_ansi(true) | ||
| .with_writer(move || -> Box<dyn std::io::Write> { | ||
| Box::new(MockWriter(console_writer.clone())) | ||
| }); | ||
|
|
||
| // File layer: ANSI disabled, uses FileFields for a distinct cache slot. | ||
| let file_layer = fmt::layer() | ||
| .with_ansi(false) | ||
| .fmt_fields(FileFields) | ||
| .with_writer(move || -> Box<dyn std::io::Write> { | ||
| Box::new(MockWriter(file_writer.clone())) | ||
| }); | ||
|
|
||
| let subscriber = tracing_subscriber::registry() | ||
| .with(console_layer) | ||
| .with(file_layer); | ||
|
|
||
| // Act | ||
| tracing::subscriber::with_default(subscriber, || { | ||
| let span = tracing::info_span!("test_span", some_field = "hello_world"); | ||
| let _guard = span.enter(); | ||
| tracing::info!("message inside span"); | ||
| }); | ||
|
|
||
| // Assert -- file buffer must not contain ANSI escape sequences | ||
| let file_output = file_buf.lock().unwrap(); | ||
| let file_str = String::from_utf8_lossy(&file_output); | ||
|
|
||
| assert!( | ||
| !file_output.is_empty(), | ||
| "File layer should have captured output" | ||
| ); | ||
| assert!( | ||
| !contains_ansi(&file_output), | ||
| "File layer output must not contain ANSI escape sequences.\n\ | ||
| File output was:\n{file_str}" | ||
| ); | ||
|
|
||
| // The file output should contain the span field value in plain text | ||
| assert!( | ||
| file_str.contains("some_field"), | ||
| "File layer output should contain the span field name 'some_field'.\n\ | ||
| File output was:\n{file_str}" | ||
| ); | ||
|
|
||
| // Assert -- console buffer SHOULD contain ANSI (confirms both layers work) | ||
| let console_output = console_buf.lock().unwrap(); | ||
| assert!( | ||
| !console_output.is_empty(), | ||
| "Console layer should have captured output" | ||
| ); | ||
| assert!( | ||
| contains_ansi(&console_output), | ||
| "Console layer output should contain ANSI escape sequences, \ | ||
| confirming the console layer is ANSI-enabled." | ||
| ); | ||
| } | ||
|
Comment on lines
+266
to
+333
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. Well-structured regression test. This test follows AAA pattern perfectly:
The assertion messages are particularly good - they include the actual output for debugging. The negative assertion (console SHOULD have ANSI) is a smart addition that verifies both layers are working. |
||
|
|
||
| // ==================== Test helpers ==================== | ||
|
|
||
| /// A writer that appends to a shared `Vec<u8>` buffer. | ||
| /// Implements `std::io::Write` so it can be used with `fmt::layer().with_writer()`. | ||
| struct MockWriter(Arc<Mutex<Vec<u8>>>); | ||
|
|
||
| impl std::io::Write for MockWriter { | ||
| fn write(&mut self, buf: &[u8]) -> std::io::Result<usize> { | ||
| let mut lock = self.0.lock().unwrap(); | ||
| lock.extend_from_slice(buf); | ||
| Ok(buf.len()) | ||
| } | ||
|
|
||
| fn flush(&mut self) -> std::io::Result<()> { | ||
| Ok(()) | ||
| } | ||
| } | ||
| } | ||
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Excellent implementation. This is a textbook example of using Rust's type system to solve a caching problem. The distinct
TypeIdgives each layer its ownFormattedFields<_>cache slot while delegating actual formatting logic toDefaultFields. Zero runtime overhead.There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
thanks claude lol