tracing: tracking issue for tracing 0.2 breaking changes

[hawkw]

Feature Request

Crates

• tracing

Motivation

In order to reduce churn throughout the ecosystem, we intend to synchronize the tokio 0.3 and tracing-core 0.2 releases. When we release tracing-core 0.2, updating tracing to use the new tracing-core will be a breaking change, so we should make other breaking API changes in tracing at the same time.

This issue tracks breaking tracing changes that we want to make in 0.2.

tracing-attributes changes

• Make instrument fields opt-in rather than opt-out (instrument macro: omit self by default #651, etc)
• Replace empty field shorthand with local variable shorthand for consistency with function-like macros (needs issue)

tracing main crate API changes

• Make Entered !Send (tracing: Entered guards should be !Send #698)
• Remove Into<Option<Id>> impl for by-value Spans (fixes "Tried to clone Id(1), but no span exists with that ID" when setting parent span #688)
• Remove legacy macro syntax (after deprecating it in a point release, see tracing: deprecate outdated macro syntax #674)
• Try to figure out more consistent macro syntax? (API inconsistency between event and span argument order #456)

[kaimast]

This bug's description should probably be updated as tokio is on version 1.15 now.

[yshui]

I want to nominate #2332

[safinaskar]

@hawkw , @davidbarsky , how transition will happen? Let's assume you released tracing 0.2. I wrote some application and some of my dependencies migrated to 0.2, some - not. How logging in such application (with dependencies) will work? Will it work at all? What will happen with global variables and constants, such as tracing::level_filters::STATIC_MAX_LEVEL? They will now exist in final binary 2 times: one from tracing 0.1.x and one from tracing 0.2.x, right?

Now let's consider my actual scenario. I have application. I use many dependencies, such as tokio, tokio-tungstenite, reqwest, etc. I enabled tracing in my application and I noticed that all these dependencies start to spam my logs. I don't like this, so I disabled this so:

tracing = { version = "0.1.40", features = ["max_level_info", "release_max_level_info"] }

Unfortunately, some of my dependencies log using log crate, so I had to also add log to my Cargo.toml (despite the fact that I don't use log in my main.rs) so:

log = { version = "0.4.20", features = ["max_level_off", "release_max_level_off"] }

Okay, so these two lines disabled spamming from my dependencies. So far, so good. Now imagine you released tracing 0.2. Some of my dependencies migrated to tracing 0.2, some - not. Some still use crate log. I still want to disable spam from my dependencies. But now my final binary has two copies of tracing::level_filters::STATIC_MAX_LEVEL! And I need to somehow set both! So I have to write to my Cargo.toml something like this (?):

# Let's disable "trace" and "debug" levels for both "tracing" versions
# Will this work at all, eh?
tracing = { version = "0.1", features = ["max_level_info", "release_max_level_info"] }
tracing = { version = "0.2", features = ["max_level_info", "release_max_level_info"] }

Unfortunately, I think this will simply not work

[davidbarsky]

@hawkw , @davidbarsky , how transition will happen? Let's assume you released tracing 0.2. I wrote some application and some of my dependencies migrated to 0.2, some - not. How logging in such application (with dependencies) will work? Will it work at all?

@safinaskar We're planning to do a semver-trick-style approach. log does something similar.

What will happen with global variables and constants, such as tracing::level_filters::STATIC_MAX_LEVEL? They will now exist in final binary 2 times: one from tracing 0.1.x and one from tracing 0.2.x, right?

Yes, but I don't expect that this will be a substantial issue.

Now let's consider my actual scenario. I have application. I use many dependencies, such as tokio, tokio-tungstenite, reqwest, etc. I enabled tracing in my application and I noticed that all these dependencies start to spam my logs. I don't like this, so I disabled this so:

tracing = { version = "0.1.40", features = ["max_level_info", "release_max_level_info"] }

Generally speaking, we recommended filtering using tracing-subscriber's filtering options instead of the compile-time filters—these are extremely heavyweight.

Unfortunately, some of my dependencies log using log crate, so I had to also add log to my Cargo.toml (despite the fact that I don't use log in my main.rs) so:

log = { version = "0.4.20", features = ["max_level_off", "release_max_level_off"] }

Note that you can filter using the aforementioned filters earlier.

Okay, so these two lines disabled spamming from my dependencies. So far, so good. Now imagine you released tracing 0.2. Some of my dependencies migrated to tracing 0.2, some - not. Some still use crate log. I still want to disable spam from my dependencies. But now my final binary has two copies of tracing::level_filters::STATIC_MAX_LEVEL! And I need to somehow set both! So I have to write to my Cargo.toml something like this (?):

# Let's disable "trace" and "debug" levels for both "tracing" versions

# Will this work at all, eh?

tracing = { version = "0.1", features = ["max_level_info", "release_max_level_info"] }

tracing = { version = "0.2", features = ["max_level_info", "release_max_level_info"] }

Unfortunately, I think this will simply not work

We're planning on making the compile-time filter flags be set via RUSTFLAGS, but if you plan on having both tracing 0.1 and 0.2 in your Cargo.toml, you'll need to rename one. Does this help answer your questions?

[safinaskar]

we recommended filtering using tracing-subscriber's filtering options

?!?!? So compile time filtering are slower than other methods?! I thought that compile time means fast

Does this help answer your questions?

Yes, thanks a lot

[davidbarsky]

?!?!? So compile time filtering are slower than other methods?! I thought that compile time means fast

No, I meant that compile-time filtering is an extremely brute-force approach for filtering. Runtime filtering with tracing is designed to be extremely efficient, as it compiles down to a branch + atomic load for disabled spans/events. I only recommend using compile-time filtering once you've benchmarked your system and found that runtime filtering is inadequate for your purposes.