fix: prevent ANSI escape sequences leaking into file log span fields#815
Conversation
|
Claude finished @shane-moore's task in 1m 59s —— View job Code Review CompleteTasks
Critical Issue: Wrong Base BranchThis PR is targeting
This PR contains 33 commits merging multiple unrelated PRs and features into Action Required: Close this PR and create a new one targeting Review of the Logging Fix (Commit a02fd41)The actual logging fix is well-implemented and addresses the root cause effectively. Here's my detailed review: ✅ Strengths
Minor Observations
Security & Performance
Code QualityThe code follows Rust best practices:
SummaryThe logging fix itself is excellent and ready to merge. However, this PR cannot be merged in its current state because:
Recommended Action:
The logging fix code quality is excellent - it just needs to be in the right PR targeting the right branch. |
|
Claude finished @shane-moore's task in 1m 1s —— View job Code Review CompleteTasks
SummaryThis PR effectively solves the ANSI escape sequence leak issue by introducing a separate cache slot for the file logging layer. The solution is clean, well-documented, and includes comprehensive regression testing. I have a few suggestions for consideration: Detailed Review✅ Strengths
🔍 Observations & Suggestions
🎯 Production Usage (
|
| /// 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; |
There was a problem hiding this comment.
Excellent implementation. This is a textbook example of using Rust's type system to solve a caching problem. The distinct TypeId gives each layer its own FormattedFields<_> cache slot while delegating actual formatting logic to DefaultFields. Zero runtime overhead.
| /// 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. | ||
| /// |
There was a problem hiding this comment.
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 FileFields exist?"
| 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." | ||
| ); | ||
| } |
There was a problem hiding this comment.
Well-structured regression test. This test follows AAA pattern perfectly:
- Arrange: Sets up production-like scenario with two layers
- Act: Logs with span fields
- Assert: Verifies file has no ANSI, console has ANSI
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.
Merge Queue StatusRule:
This pull request spent 10 minutes 20 seconds in the queue, including 9 minutes 11 seconds running CI. Required conditions to merge
|
Issue Addressed
Closes #812
Proposed Changes
FileFieldsmarker type that gives the file logging layer its own span field cache slot intracing-subscriber's extensions type-map, preventing the console layer's ANSI-formatted cached fields
from being reused by the file layer
share a registry
Additional Info
tracing-subscribercaches formatted span fields perTypeIdviaFormattedFields<N>. Both the consoleand file layers were using the implicit default
N = DefaultFields, sharing one cache slot. The consolelayer (ANSI-enabled by default) formatted first, caching italic/dimmed styled field names. The file layer
found the cache populated and reused those ANSI-contaminated fields, even with
.with_ansi(false)FileFieldsdelegates toDefaultFieldsfor formatting but has a distinctTypeId, soFormattedFields<FileFields>gets its own cache entry. The file layer's.with_ansi()setting nowcorrectly controls its own field formatting