Skip to content

[tracing-subscriber][tracing] improve duplciate tracing situation a bit #3319

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

Open
wants to merge 3 commits into
base: main
Choose a base branch
from

Conversation

xMAC94x
Copy link

@xMAC94x xMAC94x commented Jun 19, 2025

Motivation

#1372 motived me, but sadly this is NOT a fix. just a warning.
I raised a question in discord and tried to improve the situation, however I figured out I couln't fix in easily, so at least i wanted to warn about it.

Solution

While coding I removed some implicit Deref usages, while nothing is wrong with it. I think that we prob stick to https://doc.rust-lang.org/std/ops/trait.Deref.html#when-to-implement-deref-or-derefmut and should remove this in a 0.4 at some point.

The warning to tracing is kept short, linking to tracing-subscriber because realistically most people are gonna use that and are suprised when tracing-subscriber doesn't follow what tracing promises.

@xMAC94x xMAC94x requested review from hawkw and a team as code owners June 19, 2025 09:42
@@ -1162,6 +1162,11 @@ impl Span {
/// span was created:
/// </pre>
///
/// <pre class="ignore" style="white-space:normal;font:inherit;">
/// <strong>Note</strong>: <a href="https://docs.rs/tracing-subscriber/latest/tracing_subscriber/fmt/struct.Subscriber.html"><code>FmtSubscriber</code></a> has a bug
/// where it duplicates span fiels because of its implementation. See details at: <a href="https://github.com/tokio-rs/tracing/issues/1372">Github</a>
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Suggested change
/// where it duplicates span fiels because of its implementation. See details at: <a href="https://github.com/tokio-rs/tracing/issues/1372">Github</a>
/// where it duplicates span fields because of its implementation. See details at: <a href="https://github.com/tokio-rs/tracing/issues/1372">Github</a>

Copy link
Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

fixed

Comment on lines 1165 to 1167
/// <pre class="ignore" style="white-space:normal;font:inherit;">
/// <strong>Note</strong>: <a href="https://docs.rs/tracing-subscriber/latest/tracing_subscriber/fmt/struct.Subscriber.html"><code>FmtSubscriber</code></a> has a bug
/// where it duplicates span fiels because of its implementation. See details at: <a href="https://github.com/tokio-rs/tracing/issues/1372">Github</a>
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This is definitely not a good thing for this note, just beforee it is another note which ends with : because right after it was supposed to be an example illustrating what the note was about. So you might want to move this further down.

Also this bug happens specifically only when someone uses multiple fmt layers, right? I think that's pretty important to mention, the note sounds like this happens every time but most users will never encounter this.

Copy link
Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

//[dependencies]
//tracing-subscriber = "0.3"
//tracing = "0.1"


fn main() {
    tracing_subscriber::fmt()
        .with_max_level(tracing::Level::TRACE)
        .init();

    let span = tracing::info_span!("request", duplicate = tracing::field::Empty);

    span.record("duplicate", &100);
    span.record("duplicate", &200);
    span.record("duplicate", tracing::field::Empty);
    span.record("duplicate", &300);

    // produces:
    // 2025-06-19T10:45:31.070903Z  INFO request{duplicate=100 duplicate=200  duplicate=300}: bbbb: some event!
    //                                           ^ first duplicate
    //                                                         ^ second duplcate
    //                                                                      ^ an additional space by the empty field
    //                                                                        ^ expected value here

    let _guard = span.enter();

    tracing::info!("some event!");
}

Copy link
Author

@xMAC94x xMAC94x Jun 19, 2025

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This is an other minimal example it can trigger the bug. no need for fancy layers.
It just appends... always to a simple String:
https://github.com/tokio-rs/tracing/blob/tracing-subscriber-0.3.19/tracing-subscriber/src/fmt/format/mod.rs#L246-L249

I moved the note to the bottom to not interfere with the :

Though in my code I also had multiple layers, because I think one will eventually need it when writing enterprise software.

… to not interupt the ":" in the note above.

There are several ways to trigger this, e.g.:
```rust
//[dependencies]
//tracing-subscriber = "0.3"
//tracing = "0.1"

fn main() {
    tracing_subscriber::fmt()
        .with_max_level(tracing::Level::TRACE)
        .init();

    let span = tracing::info_span!("request", duplicate = tracing::field::Empty);

    span.record("duplicate", &100);
    span.record("duplicate", &200);
    span.record("duplicate", tracing::field::Empty);
    span.record("duplicate", &300);

    // produces:
    // 2025-06-19T10:45:31.070903Z  INFO request{duplicate=100 duplicate=200  duplicate=300}: bbbb: some event!
    //                                           ^ first duplicate
    //                                                         ^ second duplcate
    //                                                                      ^ an additional space by the empty field
    //                                                                        ^ expected value here

    let _guard = span.enter();

    tracing::info!("some event!");
}

```
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

2 participants