subscriber: warn if trying to enable a statically disabled level #990

jyn514 · 2020-09-26T22:39:27Z

Motivation

Fixes #975.

Solution

This implements the warning in tracing-subscriber only, as mentioned in #975 (comment). It warns whenever directives are parsed, including programmatically and through environment variables. It does not include the suggested new API which returns the filters that wouldn't be parsed.

List filters that would be ignored
Mention 'static max level'
Describe how to enable the logging

Example output:

$ RUST_LOG=off,debug,silenced[x]=trace cargo run -q
warning: some trace filter directives would enable traces that are disabled statically
 | `debug` would enable the DEBUG level for all targets
 | `silenced[x]=trace` would enable the TRACE level for the `silenced` target
 = note: the static max level is info
 = note: to enable DEBUG logging, remove the `max_level_info` feature

jyn514 · 2020-09-26T22:41:33Z

I'm not sure how to add tests for this ... the existing tests in tracing-subscriber/tests use mocks and don't touch stdout. Should I add some example binary crates and run those?

jyn514 · 2020-09-26T23:26:22Z

Originally this added a Copy impl for Level and LevelFilter, but that ran into a ton of warnings so I'm going to split it into a separate PR.

davidbarsky · 2020-10-05T11:48:55Z

tracing-subscriber/Cargo.toml

@@ -24,7 +24,7 @@ keywords = ["logging", "tracing", "metrics", "subscriber"]
 [features]

 default = ["env-filter", "smallvec", "fmt", "ansi", "chrono", "tracing-log", "json"]
-env-filter = ["matchers", "regex", "lazy_static"]
+env-filter = ["matchers", "regex", "lazy_static", "tracing"]


Not sure tracing needs to be another feature flag on this. I don't see this flag being used elsewhere and I think that a tracing dependency is a forgone conclusion for tracing-subscriber.

This won't compile without adding a tracing dependency:

error[E0433]: failed to resolve: use of undeclared type or module `tracing` --> tracing-subscriber/src/filter/env/mod.rs:245:13 | 245 | use tracing::level_filters::STATIC_MAX_LEVEL; | ^^^^^^^ use of undeclared type or module `tracing` error[E0433]: failed to resolve: use of undeclared type or module `tracing` --> tracing-subscriber/src/filter/env/mod.rs:245:13 | 245 | use tracing::level_filters::STATIC_MAX_LEVEL; | ^^^^^^^ use of undeclared type or module `tracing`

I'd like to hear what @hawkw says, but I'm not sure tracing merits being an optional dependency.

Oh I see, you want to make it always a dependency instead of optional. Sure, I can do that.

I think the tracing dependency should be optional and only enabled by the "env-filter" feature. Otherwise, there's no reason to depend on tracing --- the rest of the crate only uses tracing-core.

I think @davidbarsky misinterpreted this change as adding a new feature flag "tracing" that users could independently enable. That's not what this change is doing --- it simply makes the "env-filter" feature enable a dependency on tracing that isn't otherwise necessary.

IMO the original code was correct.

Ok, I reverted it to the original code.

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

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

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

davidbarsky · 2020-10-05T14:46:11Z

tracing-subscriber/Cargo.toml

@@ -24,7 +24,7 @@ keywords = ["logging", "tracing", "metrics", "subscriber"]
 [features]

 default = ["env-filter", "smallvec", "fmt", "ansi", "chrono", "tracing-log", "json"]
-env-filter = ["matchers", "regex", "lazy_static"]
+env-filter = ["matchers", "regex", "lazy_static", "tracing"]


I'd like to hear what @hawkw says, but I'm not sure tracing merits being an optional dependency.

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

This implements the warning in `tracing-subscriber` only, as mentioned in tokio-rs#975 (comment). It warns whenever directives are parsed, including programmatically and through environment variables. It does not include the suggested new API which returns the filters that wouldn't be parsed. - List filters that would be ignored - Mention 'static max level' - Describe how to enable the logging Example output: ``` $ RUST_LOG=off,debug,silenced[x]=trace cargo run -q warning: some trace filter directives would enable traces that are disabled statically | `debug` would enable the DEBUG level for all targets | `silenced[x]=trace` would enable the TRACE level for the `silenced` target | the static max level is info note: to enable DEBUG logging, remove the `max_level_info` feature ``` Fixes: tokio-rs#975

Co-authored-by: David Barsky <me@davidbarsky.com>

- Make `tracing` mandatory - Group crate-public fields together

jyn514 · 2020-10-06T00:47:38Z

Rebased over master to get the test fix from #1016.

hawkw · 2020-10-01T18:29:06Z

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

+            eprintln!("warning: some trace filter directives would enable traces that are disabled statically");
+            for directive in disabled {
+                let target = if let Some(target) = &directive.target {
+                    format!("the `{}` target", target)
+                } else {
+                    "all targets".into()
+                };
+                let level = directive
+                    .level
+                    .clone()
+                    .into_level()
+                    .expect("=off would not have enabled any filters");
+                eprintln!(
+                    " | `{}` would enable the {} level for {}",
+                    directive, level, target
+                );
+            }
+            eprintln!(" | the static max level is {}", STATIC_MAX_LEVEL);
+            let help_msg = || {
+                let (feature, filter) = match STATIC_MAX_LEVEL.into_level() {
+                    Some(Level::TRACE) => unreachable!(
+                        "if the max level is trace, no static filtering features are enabled"
+                    ),
+                    Some(Level::DEBUG) => ("max_level_debug", Level::TRACE),
+                    Some(Level::INFO) => ("max_level_info", Level::DEBUG),
+                    Some(Level::WARN) => ("max_level_warn", Level::INFO),
+                    Some(Level::ERROR) => ("max_level_error", Level::WARN),
+                    None => return ("max_level_off", String::new()),
+                };
+                (feature, format!("{} ", filter))
+            };
+            let (feature, earlier_level) = help_msg();
+            eprintln!(
+                "note: to enable {}logging, remove the `{}` feature",
+                earlier_level, feature
+            );


FWIW, when I suggested output like

$ RUST_LOG=off,debug,silenced[x]=trace cargo run -q warning: some trace filter directives would enable traces that are disabled statically | `debug` would enable the DEBUG level for all targets | `silenced[x]=trace` would enable the TRACE level for the `silenced` target | the static max level is info note: to enable DEBUG logging, remove the `max_level_info` feature

i was trying to imitate the formatting used by rustc's error messages, since I know this feature was originally requested for rustc.

Since we already have the "ansi" feature flag for enabling colored terminal output via the ansi_term crate, we might want to try using the same colors and other formatting that the compiler uses, when that feature is enabled?

It would be fine to make this change in a follow up PR, rather than block merging this one --- it's just a thought.

What do you think?

For context, this is what rustc's diagnostics look like:

i was trying to imitate the formatting used by rustc's error messages, since I know this feature was originally requested for rustc.

I should probably work on colorizing bootstraps errors ... right now they're pretty inconsistent.

(-bash@build-server) ~/rustc $ rg println src/bootstrap/ src/bootstrap/config.rs 565: println!("failed to parse TOML configuration '{}': {}", file.display(), err); src/bootstrap/setup.rs 81: println!("error: unrecognized option '{}'", input.trim()); 82: println!("note: press Ctrl+C to exit");

What do you think?

this is beautiful <3

i might format "the static max level is XXX" as a note: but take it or leave it.

this looks rad!

jyn514 · 2020-10-06T23:07:07Z

Is this waiting on anything? I'd love to have it in rustc :)

jyn514 · 2020-10-06T23:07:33Z

I can squash the commit history if you like, not sure what the policy is for that.

hawkw

looks good to me!

hawkw · 2020-10-06T23:35:11Z

Is this waiting on anything? I'd love to have it in rustc :)

Nope, everything looks fine, I just had a bunch of other things to take care of. Happy to merge it now!

Note that the master branch currently has breaking changes for the upcomingtracing 0.2.x. If you want to see this in rustc tomorrow, we'll need to backport this to the v0.1.x branch as well. I'd recommend doing that by cherry-picking the merged commit on master.

I can squash the commit history if you like, not sure what the policy is for that.

We'll squash the PR when merging it. See https://github.com/tokio-rs/tracing/blob/master/CONTRIBUTING.md#commit-squashing :)

…io-rs#990) ## Motivation Fixes tokio-rs#975. ## Solution This implements the warning in `tracing-subscriber` only, as mentioned in tokio-rs#975 (comment). It warns whenever directives are parsed, including programmatically and through environment variables. It does not include the suggested new API which returns the filters that wouldn't be parsed. - List filters that would be ignored - Mention 'static max level' - Describe how to enable the logging Example output: ``` $ RUST_LOG=off,debug,silenced[x]=trace cargo run -q warning: some trace filter directives would enable traces that are disabled statically | `debug` would enable the DEBUG level for all targets | `silenced[x]=trace` would enable the TRACE level for the `silenced` target = note: the static max level is info = note: to enable DEBUG logging, remove the `max_level_info` feature ``` ![image](https://user-images.githubusercontent.com/23638587/95243324-77dc6a00-07de-11eb-8ed3-6ee2109940d4.png)

* upstream/master: subscriber: warn if trying to enable a statically disabled level (tokio-rs#990) subscriber: use macros for module declarations (tokio-rs#1009) chore: remove `stdlib.rs` (tokio-rs#1008) core: fix linked list tests reusing `Registration`s (tokio-rs#1016) subscriber: support dash in target names (tokio-rs#1012) docs: switch to intra-doc links in tracing-core (tokio-rs#1010) tracing-opentelemetry: implement additional record types (bool, i64, u64) (tokio-rs#1007) core: add intrusive linked list for callsite registry (tokio-rs#988) serde: allow tracing-serde to work on no_std. (tokio-rs#960) tracing: remove `Into<Option<Id>>` impl for `Span` (tokio-rs#1003) tracing: make `Entered` `!Send` (tokio-rs#1001) chore: fix nightly clippy warnings (tokio-rs#991) chore: bump all crate versions (tokio-rs#998) macros: fix the `tracing-macros` crate not compiling (tokio-rs#1000) tracing: prepare to release 0.1.21 (tokio-rs#997) core: prepare to release 0.1.17 (tokio-rs#996) subscriber: make `PartialOrd` & `Ord` impls more correct (tokio-rs#995) core, tracing: don't inline dispatcher::get_default (tokio-rs#994) core: make `Level` and `LevelFilter` `Copy` (tokio-rs#992)

The primary motivation is to get the changes from tokio-rs/tracing#990. Example output: ``` $ RUSTDOC_LOG=debug rustdoc +rustc2 warning: some trace filter directives would enable traces that are disabled statically | `debug` would enable the DEBUG level for all targets = note: the static max level is `info` = help: to enable DEBUG logging, remove the `max_level_info` feature ``` - Remove useless test This was testing for an ICE when passing `RUST_LOG=rustc_middle`. I noticed it because it started giving the tracing warning (because tests are not run with debug-logging enabled). Since this bug seems unlikely to re-occur, I just removed it altogether.

Upgrade to tracing-subscriber 0.2.13 The primary motivation is to get the changes from tokio-rs/tracing#990. Example output: ``` $ RUSTDOC_LOG=debug rustdoc +rustc2 warning: some trace filter directives would enable traces that are disabled statically | `debug` would enable the DEBUG level for all targets = note: the static max level is `info` = help: to enable DEBUG logging, remove the `max_level_info` feature ``` r? `@Mark-Simulacrum` cc `@hawkw` ❤️

…spatch-as-ref-tokio-rs#455 * upstream/master: (28 commits) opentelemetry: prepare for 0.8.0 release (tokio-rs#1036) docs: add favicon for extra pretty docs (tokio-rs#1033) subscriber: fix `reload` ergonomics (tokio-rs#1035) chore(deps): update crossbeam-channel requirement from 0.4.2 to 0.5.0 (tokio-rs#1031) opentelemetry: Assign default ids if missing (tokio-rs#1027) chore: remove deprecated add-path from CI (tokio-rs#1026) attributes: fix `#[instrument(err)]` in case of early returns (tokio-rs#1006) core: remove mandatory liballoc dependency with no-std (tokio-rs#1017) chore(deps): update cfg-if requirement from 0.1.10 to 1.0.0 (tokio-rs#1023) subscriber: warn if trying to enable a statically disabled level (tokio-rs#990) subscriber: use macros for module declarations (tokio-rs#1009) chore: remove `stdlib.rs` (tokio-rs#1008) core: fix linked list tests reusing `Registration`s (tokio-rs#1016) subscriber: support dash in target names (tokio-rs#1012) docs: switch to intra-doc links in tracing-core (tokio-rs#1010) tracing-opentelemetry: implement additional record types (bool, i64, u64) (tokio-rs#1007) core: add intrusive linked list for callsite registry (tokio-rs#988) serde: allow tracing-serde to work on no_std. (tokio-rs#960) tracing: remove `Into<Option<Id>>` impl for `Span` (tokio-rs#1003) tracing: make `Entered` `!Send` (tokio-rs#1001) ...

…cros * upstream/master: (30 commits) chore(deps): update pin-project requirement from 0.4 to 1.0 (tokio-rs#1038) chore: remove duplicated section from tracing/README.md (tokio-rs#1046) opentelemetry: prepare for 0.8.0 release (tokio-rs#1036) docs: add favicon for extra pretty docs (tokio-rs#1033) subscriber: fix `reload` ergonomics (tokio-rs#1035) chore(deps): update crossbeam-channel requirement from 0.4.2 to 0.5.0 (tokio-rs#1031) opentelemetry: Assign default ids if missing (tokio-rs#1027) chore: remove deprecated add-path from CI (tokio-rs#1026) attributes: fix `#[instrument(err)]` in case of early returns (tokio-rs#1006) core: remove mandatory liballoc dependency with no-std (tokio-rs#1017) chore(deps): update cfg-if requirement from 0.1.10 to 1.0.0 (tokio-rs#1023) subscriber: warn if trying to enable a statically disabled level (tokio-rs#990) subscriber: use macros for module declarations (tokio-rs#1009) chore: remove `stdlib.rs` (tokio-rs#1008) core: fix linked list tests reusing `Registration`s (tokio-rs#1016) subscriber: support dash in target names (tokio-rs#1012) docs: switch to intra-doc links in tracing-core (tokio-rs#1010) tracing-opentelemetry: implement additional record types (bool, i64, u64) (tokio-rs#1007) core: add intrusive linked list for callsite registry (tokio-rs#988) serde: allow tracing-serde to work on no_std. (tokio-rs#960) ...

…gger * upstream/master: (31 commits) chore: fix tracing-macros::dbg (tokio-rs#1054) chore(deps): update pin-project requirement from 0.4 to 1.0 (tokio-rs#1038) chore: remove duplicated section from tracing/README.md (tokio-rs#1046) opentelemetry: prepare for 0.8.0 release (tokio-rs#1036) docs: add favicon for extra pretty docs (tokio-rs#1033) subscriber: fix `reload` ergonomics (tokio-rs#1035) chore(deps): update crossbeam-channel requirement from 0.4.2 to 0.5.0 (tokio-rs#1031) opentelemetry: Assign default ids if missing (tokio-rs#1027) chore: remove deprecated add-path from CI (tokio-rs#1026) attributes: fix `#[instrument(err)]` in case of early returns (tokio-rs#1006) core: remove mandatory liballoc dependency with no-std (tokio-rs#1017) chore(deps): update cfg-if requirement from 0.1.10 to 1.0.0 (tokio-rs#1023) subscriber: warn if trying to enable a statically disabled level (tokio-rs#990) subscriber: use macros for module declarations (tokio-rs#1009) chore: remove `stdlib.rs` (tokio-rs#1008) core: fix linked list tests reusing `Registration`s (tokio-rs#1016) subscriber: support dash in target names (tokio-rs#1012) docs: switch to intra-doc links in tracing-core (tokio-rs#1010) tracing-opentelemetry: implement additional record types (bool, i64, u64) (tokio-rs#1007) core: add intrusive linked list for callsite registry (tokio-rs#988) ...

…spatch-as-owned-tokio-rs#455 * upstream/master: (34 commits) subscriber: remove TraceLogger (tokio-rs#1052) subscriber: make Registry::enter/exit much faster (tokio-rs#1058) chore(deps): update env_logger requirement from 0.7 to 0.8 (tokio-rs#1050) chore: fix tracing-macros::dbg (tokio-rs#1054) chore(deps): update pin-project requirement from 0.4 to 1.0 (tokio-rs#1038) chore: remove duplicated section from tracing/README.md (tokio-rs#1046) opentelemetry: prepare for 0.8.0 release (tokio-rs#1036) docs: add favicon for extra pretty docs (tokio-rs#1033) subscriber: fix `reload` ergonomics (tokio-rs#1035) chore(deps): update crossbeam-channel requirement from 0.4.2 to 0.5.0 (tokio-rs#1031) opentelemetry: Assign default ids if missing (tokio-rs#1027) chore: remove deprecated add-path from CI (tokio-rs#1026) attributes: fix `#[instrument(err)]` in case of early returns (tokio-rs#1006) core: remove mandatory liballoc dependency with no-std (tokio-rs#1017) chore(deps): update cfg-if requirement from 0.1.10 to 1.0.0 (tokio-rs#1023) subscriber: warn if trying to enable a statically disabled level (tokio-rs#990) subscriber: use macros for module declarations (tokio-rs#1009) chore: remove `stdlib.rs` (tokio-rs#1008) core: fix linked list tests reusing `Registration`s (tokio-rs#1016) subscriber: support dash in target names (tokio-rs#1012) ...

jyn514 requested review from hawkw and a team as code owners September 26, 2020 22:39

jyn514 force-pushed the warn-ignored branch from 8cb716b to b745d09 Compare September 26, 2020 22:40

jyn514 force-pushed the warn-ignored branch 3 times, most recently from cca54b5 to e1e58cb Compare September 26, 2020 23:25

jyn514 mentioned this pull request Sep 26, 2020

Make Level and LevelFilter Copy #992

Merged

davidbarsky reviewed Oct 5, 2020

View reviewed changes

jyn514 force-pushed the warn-ignored branch from 989ae34 to e2ddab4 Compare October 5, 2020 14:20

davidbarsky reviewed Oct 5, 2020

View reviewed changes

jyn514 and others added 6 commits October 5, 2020 20:47

Comment why this prints to stderr instead of a subscriber

edcf7c9

Fix silent rebase error caused by version bump

7c933d8

Improve comment about MakeWriter

54221b1

Co-authored-by: David Barsky <me@davidbarsky.com>

Address review comments

42e0de2

- Make `tracing` mandatory - Group crate-public fields together

rustfmt

acb197e

jyn514 force-pushed the warn-ignored branch from eb93223 to acb197e Compare October 6, 2020 00:47

hawkw reviewed Oct 6, 2020

View reviewed changes

jyn514 added 4 commits October 5, 2020 21:39

Use ANSI colors if enabled

69720f3

Make tracing optional again

5223e3e

rustfmt

929324d

prefix static max level with note:

990c050

hawkw approved these changes Oct 6, 2020

View reviewed changes

hawkw merged commit 1d901b3 into tokio-rs:master Oct 6, 2020

jyn514 deleted the warn-ignored branch October 7, 2020 00:03

jyn514 mentioned this pull request Oct 7, 2020

Backport #990 (subscriber: warn if trying to enable a statically disabled level) #1021

Merged

jyn514 mentioned this pull request Oct 7, 2020

Upgrade to tracing-subscriber 0.2.13 rust-lang/rust#77678

Merged

jyn514 mentioned this pull request Feb 23, 2021

Show a warning when a subscriber subscribes to a log level that is disabled at compile time #975

Closed

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

subscriber: warn if trying to enable a statically disabled level #990

subscriber: warn if trying to enable a statically disabled level #990

jyn514 commented Sep 26, 2020 •

edited

Loading

jyn514 commented Sep 26, 2020

jyn514 commented Sep 26, 2020

davidbarsky Oct 5, 2020

jyn514 Oct 5, 2020

davidbarsky Oct 5, 2020

jyn514 Oct 5, 2020

hawkw Oct 6, 2020

jyn514 Oct 6, 2020

davidbarsky Oct 5, 2020

jyn514 commented Oct 6, 2020

hawkw Oct 1, 2020

jyn514 Oct 6, 2020

jyn514 Oct 6, 2020

jyn514 Oct 6, 2020

hawkw Oct 6, 2020

hawkw Oct 6, 2020

jyn514 Oct 6, 2020

davidbarsky Oct 6, 2020

jyn514 commented Oct 6, 2020

jyn514 commented Oct 6, 2020

hawkw left a comment

hawkw commented Oct 6, 2020

subscriber: warn if trying to enable a statically disabled level #990

subscriber: warn if trying to enable a statically disabled level #990

Conversation

jyn514 commented Sep 26, 2020 • edited Loading

Motivation

Solution

jyn514 commented Sep 26, 2020

jyn514 commented Sep 26, 2020

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

jyn514 commented Oct 6, 2020

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

jyn514 commented Oct 6, 2020

jyn514 commented Oct 6, 2020

hawkw left a comment

Choose a reason for hiding this comment

hawkw commented Oct 6, 2020

jyn514 commented Sep 26, 2020 •

edited

Loading