subscriber/fmt: address UX issues in defaults #1781

ishitatsuyuki · 2021-12-16T12:19:28Z

The removal of env-filter from the default features in 0.3.0 has caused a lot of developer frustration.

This PR addresses all of the issue I'm aware of, except #1329, in individual commits.

See the commit message for notes on the implementation and the related issues.

ishitatsuyuki · 2021-12-16T14:59:41Z

I removed the one related to #1329 from the changelist:

It's a breaking change, which should be better to merged separately
It didn't change the fmt() function, so it actually didn't do what it says

It looks like fixing #1329 would be harder after all due to the signature complexity, so I'm backing that out for now.

hawkw · 2021-12-18T05:54:52Z

Thanks for taking the time to work on this!

I'm not sure if the approach used here is really the best way to fix these problems, however. Rather than printing a warning when RUST_LOG is set, but the env_filter feature flag is not enabled, what if we used the approach I suggested in #1697 (comment) --- using the Targets filter (which is not feature-flagged) instead of EnvFilter when env_filter is not enabled. That way, we would still transparently support filtering in most cases. Since EnvFilter is a superset of Targets, we could perhaps print a warning if the environment variable contained filtering expressions not supported by Targets (e.g. span field filters).

ishitatsuyuki · 2021-12-18T06:09:08Z

Oh, interesting. I'll look into this later.

ishitatsuyuki · 2021-12-18T07:41:50Z

Uh oh, looks like this would also be a breaking change because how filters and other things are completely hardcoded into the type parameters:

pub struct SubscriberBuilder<N = DefaultFields, E = Format<Full>, F = LevelFilter, W = fn() -> Stdout>

I wonder if we can change this in a way that leaks less implementation details? Ideally, we would want the default SubscriberBuilder to pick between one of LevelFilter, Targets and EnvFilter, but in the current state we have to statically code it to one of the options.

hawkw · 2021-12-18T20:00:28Z

Uh oh, looks like this would also be a breaking change because how filters and other things are completely hardcoded into the type parameters:

You're right that changing the filter to Targets in functions that return a Subscriber or SubscriberBuilder would be a
breaking change.

I was thinking that we would do this specifically for the tracing_subscriber::fmt::init function, which doesn't return a SubscriberBuilder --- instead, it just sets the default subscriber. It wouldn't be a breaking change to change the type of the subscriber builder that's constructed internally inside of that function. Since this function is intended to "just work" out of the box, and provide reasonable defaults for use-cases which don't require particular configuration, I think it's important for it to always honor RUST_LOG if it's set, so we should have that function just fall back to Targets if EnvFilter is not available.

For other functions, which return a builder, it's much more difficult to change them, because of the type signatures. Fortunately, users should only be using these functions if they do need to configure the subscriber differently than the default, so in that case, if we make sure it's very obvious what you get when you call tracing_subscriber::fmt or tracing_subscriber::fmt::Subscriber::builder(), it's okay to have to add the filter manually. Therefore, I think the best solution in that case is to improve the documentation, and maybe also to use your original idea of printing a warning if RUST_LOG is set but the builder isn't configured with a Targets or EnvFilter in the SubscriberBuilder::init() function.

What do you think?

hawkw · 2021-12-28T18:36:32Z

ping @ishitatsuyuki --- are you still planning on working on this? What do you think of my suggestions from #1781 (comment)? If you don't have the time to make that change, I'm happy to make those additional changes on top of this PR, but I'd like to get this merged at some point soon.

The previous implementation would fall back to "NOTHING" instead, which was a poor default. Close tokio-rs#735

…is not enabled Close tokio-rs#1697

ishitatsuyuki · 2021-12-29T06:30:00Z

Sorry for the review request noise, I had to change the base branch as Targets was only on the v0.1.x branch.

I implemented your idea directly into the try_init() function. I also considered adding helper functions in Targets, but I found it quite awkward to do since dealing with environment variable requires gating behind std, and printing parse errors like EnvFilter does also requires std.

hawkw

Overall, this looks like the right approach. I left some style suggestions.

Also, I think rustfmt needs to be run on this branch to make CI pass.

Once that's all addressed, I'll be very happy to merge this! Thanks!

hawkw · 2021-12-29T17:38:05Z

tracing-subscriber/src/fmt/mod.rs

@@ -297,6 +297,8 @@
 //!     https://docs.rs/tracing/latest/tracing/trait.Subscriber.html
 //! [`tracing`]: https://crates.io/crates/tracing
 //! [`fmt::format`]: mod@crate::fmt::format
+#[cfg(not(feature = "env-filter"))]
+use core::str::FromStr;


nit, take it or leave it: we don't need to import this from core here, since this whole module requires the std feature. importing it from core. this is fine either way, though.

tracing-subscriber/src/fmt/mod.rs

hawkw · 2021-12-29T17:53:02Z

tracing-subscriber/src/fmt/mod.rs

+        Err(std::env::VarError::NotPresent) => {crate::filter::Targets::new()}
+        Err(e) => {
+            eprintln!("Ignoring `RUST_LOG`: {:?}", e);
+            crate::filter::Targets::new()
+        }
+    }.with_default(crate::fmt::Subscriber::DEFAULT_MAX_LEVEL);


calling with_default on the result of the match will set the default max level in all cases, even if the filter parsed from the env var had a default level. for example, if the user runs a program with RUST_LOG=debug,foo=trace, where Debug is the default level, this will overwrite the Debug default with Info. instead, I think we should only overwrite the default max level when no filter was parsed from the env var:

Suggested change

Err(std::env::VarError::NotPresent) => {crate::filter::Targets::new()}

Err(e) => {

eprintln!("Ignoring `RUST_LOG`: {:?}", e);

crate::filter::Targets::new()

}

}.with_default(crate::fmt::Subscriber::DEFAULT_MAX_LEVEL);

Err(std::env::VarError::NotPresent) => {

crate::filter::Targets::new().with_default(crate::fmt::Subscriber::DEFAULT_MAX_LEVEL)

}

Err(e) => {

eprintln!("Ignoring `RUST_LOG`: {:?}", e);

crate::filter::Targets::new().with_default(crate::fmt::Subscriber::DEFAULT_MAX_LEVEL)

}

};

hawkw · 2021-12-29T17:54:36Z

tracing-subscriber/src/fmt/mod.rs

+    #[cfg(not(feature = "env-filter"))]
+        let targets = match std::env::var("RUST_LOG") {
+        Ok(var) => {
+            crate::filter::Targets::from_str(&var).map_err(|e|{eprintln!("Ignoring `RUST_LOG`: {:?}", e);}).unwrap_or_default()


if we get an error here, the env variable is set, but it couldn't be parsed successfully. i think it would be nice if the error message also included the value of the env var, so the user can see the whole string that wasn't parsed:

Suggested change

crate::filter::Targets::from_str(&var).map_err(|e|{eprintln!("Ignoring `RUST_LOG`: {:?}", e);}).unwrap_or_default()

crate::filter::Targets::from_str(&var).map_err(|e|{eprintln!("Ignoring `RUST_LOG={:?}`: {:?}", var, e);}).unwrap_or_default()

also, i think this error implements fmt::Display, so the message we print might look a little nicer if we used Display here:

Suggested change

crate::filter::Targets::from_str(&var).map_err(|e|{eprintln!("Ignoring `RUST_LOG`: {:?}", e);}).unwrap_or_default()

crate::filter::Targets::from_str(&var).map_err(|e|{eprintln!("Ignoring `RUST_LOG`: {}", e);}).unwrap_or_default()

Signed-off-by: Eliza Weisman <[email protected]>

tracing-subscriber/src/filter/env/mod.rs

@marienz

# 0.3.5 (Dec 29, 2021) This release re-enables `RUST_LOG` filtering in `tracing_subscriber::fmt`'s default initialization methods, and adds an `OffsetLocalTime` formatter for using local timestamps with the `time` crate. ### Added - **fmt**: Added `OffsetLocalTime` formatter to `fmt::time` for formatting local timestamps with a fixed offset ([#1772]) ### Fixed - **fmt**: Added a `Targets` filter to `fmt::init()` and `fmt::try_init()` when the "env-filter" feature is disabled, so that `RUST_LOG` is still honored ([#1781]) Thanks to @marienz and @ishitatsuyuki for contributing to this release! [#1772]: #1772 [#1781]: #1781

@marienz

# 0.3.5 (Dec 29, 2021) This release re-enables `RUST_LOG` filtering in `tracing_subscriber::fmt`'s default initialization methods, and adds an `OffsetLocalTime` formatter for using local timestamps with the `time` crate. ### Added - **fmt**: Added `OffsetLocalTime` formatter to `fmt::time` for formatting local timestamps with a fixed offset ([#1772]) ### Fixed - **fmt**: Added a `Targets` filter to `fmt::init()` and `fmt::try_init()` when the "env-filter" feature is disabled, so that `RUST_LOG` is still honored ([#1781]) Thanks to @marienz and @ishitatsuyuki for contributing to this release! [#1772]: #1772 [#1781]: #1781

…t enabled(tokio-rs#1781) The removal of `env-filter` from the default features in 0.3.0 has caused a lot of developer frustration. This PR changes `tracing_subscriber::fmt::init()` and `try_init` to fall back to adding a `Targets` filter parsed from the `RUST_LOG` environment variable, rather than a `LevelFilter` with the default max level. This way, `RUST_LOG`-based filtering will still "just work" out of the box with the default initialization functions, regardless of whether or not `EnvFilter` is enabled. Closes tokio-rs#1697 Co-authored-by: Eliza Weisman <[email protected]>

@marienz

# 0.3.5 (Dec 29, 2021) This release re-enables `RUST_LOG` filtering in `tracing_subscriber::fmt`'s default initialization methods, and adds an `OffsetLocalTime` formatter for using local timestamps with the `time` crate. ### Added - **fmt**: Added `OffsetLocalTime` formatter to `fmt::time` for formatting local timestamps with a fixed offset ([tokio-rs#1772]) ### Fixed - **fmt**: Added a `Targets` filter to `fmt::init()` and `fmt::try_init()` when the "env-filter" feature is disabled, so that `RUST_LOG` is still honored ([tokio-rs#1781]) Thanks to @marienz and @ishitatsuyuki for contributing to this release! [tokio-rs#1772]: tokio-rs#1772 [tokio-rs#1781]: tokio-rs#1781

ishitatsuyuki requested review from davidbarsky, hawkw and a team as code owners December 16, 2021 12:19

ishitatsuyuki force-pushed the fmt-defaults branch from cac6151 to 0c4c57e Compare December 16, 2021 14:57

ishitatsuyuki added 2 commits December 29, 2021 15:08

subscriber: use INFO as the default log level in EnvFilter

2da6cc5

The previous implementation would fall back to "NOTHING" instead, which was a poor default. Close tokio-rs#735

subscriber: Use Targets for the default subscriber if env-filter …

e61ebff

…is not enabled Close tokio-rs#1697

ishitatsuyuki force-pushed the fmt-defaults branch from 0c4c57e to e61ebff Compare December 29, 2021 06:26

ishitatsuyuki requested review from carllerche, jtescher and yaahc as code owners December 29, 2021 06:26

ishitatsuyuki changed the base branch from master to v0.1.x December 29, 2021 06:26

hawkw approved these changes Dec 29, 2021

View reviewed changes

hawkw added 3 commits December 29, 2021 11:20

Update tracing-subscriber/src/fmt/mod.rs

e6ea46c

fixup

cbae80f

Signed-off-by: Eliza Weisman <[email protected]>

remove subscriber builder max level filtering

7a494bb

Signed-off-by: Eliza Weisman <[email protected]>

hawkw reviewed Dec 29, 2021

View reviewed changes

tracing-subscriber/src/filter/env/mod.rs Outdated Show resolved Hide resolved

Update tracing-subscriber/src/filter/env/mod.rs

52c2a4b

hawkw merged commit c60c530 into tokio-rs:v0.1.x Dec 29, 2021

hawkw mentioned this pull request Dec 30, 2021

subscriber: prepare to release 0.3.5 #1810

Merged

davidbarsky mentioned this pull request Mar 24, 2022

tracing-subscriber 0.3.1 does not respect RUST_LOG #1697

Closed

davidbarsky mentioned this pull request Sep 26, 2023

chore: backport roughly a year's worth of changes #2728

Merged

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

subscriber/fmt: address UX issues in defaults #1781

subscriber/fmt: address UX issues in defaults #1781

ishitatsuyuki commented Dec 16, 2021 •

edited

Loading

ishitatsuyuki commented Dec 16, 2021

hawkw commented Dec 18, 2021

ishitatsuyuki commented Dec 18, 2021

ishitatsuyuki commented Dec 18, 2021

hawkw commented Dec 18, 2021

hawkw commented Dec 28, 2021

ishitatsuyuki commented Dec 29, 2021

hawkw left a comment

hawkw Dec 29, 2021

hawkw Dec 29, 2021

hawkw Dec 29, 2021

hawkw Dec 29, 2021

	crate::filter::Targets::from_str(&var).map_err(\|e\|{eprintln!("Ignoring `RUST_LOG`: {:?}", e);}).unwrap_or_default()
	crate::filter::Targets::from_str(&var).map_err(\|e\|{eprintln!("Ignoring `RUST_LOG={:?}`: {:?}", var, e);}).unwrap_or_default()

subscriber/fmt: address UX issues in defaults #1781

subscriber/fmt: address UX issues in defaults #1781

Conversation

ishitatsuyuki commented Dec 16, 2021 • edited Loading

ishitatsuyuki commented Dec 16, 2021

hawkw commented Dec 18, 2021

ishitatsuyuki commented Dec 18, 2021

ishitatsuyuki commented Dec 18, 2021

hawkw commented Dec 18, 2021

hawkw commented Dec 28, 2021

ishitatsuyuki commented Dec 29, 2021

hawkw left a comment

Choose a reason for hiding this comment

hawkw Dec 29, 2021

Choose a reason for hiding this comment

hawkw Dec 29, 2021

Choose a reason for hiding this comment

hawkw Dec 29, 2021

Choose a reason for hiding this comment

hawkw Dec 29, 2021

Choose a reason for hiding this comment

ishitatsuyuki commented Dec 16, 2021 •

edited

Loading