tokio-rs / tracing

Application level tracing for Rust.
https://tracing.rs
MIT License
5.33k stars 697 forks source link

[doc] it's unclear how multiple EnvFilter directives are applied #2731

Open lilydjwg opened 11 months ago

lilydjwg commented 11 months ago

Bug Report

Version

tracing-subscriber 0.3.17

Description

I'm trying to understand how multiple EnvFilter directives are applied but failed to find anything related in the docs, except an example:

  • warn,tokio::net=info will enable all spans and events that:
    • are at the level warn or above, or
    • have the tokio::net target at the level info or above.

But this is descriptive---it describes what a specific configuration does, but what about others? Especially, what about warn,tokio::net=error? Will an event be output when any one of the directive matches? Or the most specific one matches? Or all of them?

I know I can write code to find out (I did). So I'm filing a documentation bug, not a code one.

kaffarell commented 10 months ago

I think it's very clear, there is a big explanation on top and 4 examples below, I didn't have any trouble understanding it. The only thing we could change is "maximum verbosity level" -> "minimum log level", which is IMO easier to understand. What do you think is missing here?

lilydjwg commented 10 months ago

a big explanation on top

which talks a lot about how a single directive is written and interpreted, but only says multiple directives can be comma-separated.

4 examples below

Three others have only one directive, which is irrelative about the interpretation of multiple directives.

With regard to warn,tokio::net=error, should a tokio::net log with level warn be shown because it matches the first directive? The quoted example uses the word or, and in programming languages A or B is true when either A or B is true.

kaffarell commented 10 months ago

Oh, yes I get your point. Theoretically this filter warn,tokio::net=error would be redundand, a minimum level of warn is lower than error, so tokio::net with level warn will be shown.

Do you think adding and explaining this example is enough or do we need a more detailed explanation?

lilydjwg commented 10 months ago

Theoretically this filter warn,tokio::net=error would be redundand

But it actually behaves like the most specific one wins, except that how specificity is determined is also unclear sometimes, given a log could match a target or a span, or multiple directives matching different fields or different regexes of a single field....

do we need a more detailed explanation?

Yes, definitely. The syntax is so versatile that we need a definition on how it works.

kaffarell commented 9 months ago

I see, I just tried it with an example and I also got weird results. For example:

tracing_subscriber::registry()
    .with(fmt::layer())
    .with(EnvFilter::new("warn,tokio::net=error"))
    .init();

tracing::trace!("log in trace");
tracing::debug!("log in debug");
tracing::info!("log in info");
tracing::warn!("log in warn");
tracing::error!("log in error");

tracing::trace!(target: "tokio::net", "log in trace");
tracing::debug!(target: "tokio::net", "log in debug");
tracing::info!(target: "tokio::net", "log in info");
tracing::warn!(target: "tokio::net", "log in warn");
tracing::error!(target: "tokio::net", "log in error");

Output:

2023-11-13T08:56:54.310819Z  WARN rust_test: log in warn
2023-11-13T08:56:54.310848Z ERROR rust_test: log in error
2023-11-13T08:56:54.310856Z ERROR tokio::net: log in error

This does not matche the 'or' as described in the documentation here. Though this happens only when using multiple filters that are redundant ( and thus actually useless ). I wonder if this behavior is intended and the documentation is slightly wrong @hawkw?

DDtKey commented 2 months ago

I was just passing by, but the behavior itself seems logical to me and is clearly users may rely on this

The example is quite simple: I want to enable DEBUG (or INFO) for everything, but specific targets produce too many events on this level, so I move only them to ERROR level

So I hope it's documentation issue. Otherwise a fix of that might broke a lot of expectations.