Skip to content

Commit

Permalink
subscriber: directives: accept legit log level names in mixed case (e…
Browse files Browse the repository at this point in the history
…nv_logger compat) (#1126)

Hi Folks,

This PR is about behavior compatibility with the `env_logger` and `log`
crates. There are references in the `tracing-subscriber` docs noting
some level of partial compatibility with `env_logger`, but it is not
clear to me the extent to which that is a priority.

If the intention is to keep the projects close in behavior where there
is overlap in the representations of logging directive strings, then
this PR is a step toward better compatibility.

On the other hand, if such compatibility is more of a short-term
nice-to-have than a long-term objective, then this PR might be a step in
the wrong direction. If so, please feel free to reject it. I happened to
notice the behavior difference (described below) while working on
something else, and just thought I'd bring it up for discussion.

On the *other* other hand, it is clear that some significant effort
*has* been expended to have compatibly parsed logging directive strings.
Which leads me to read the regex code modified in the second commit of
this PR as possibly introducing a level of compatibility that was
deliberately omitted; the existing regex was clearly structured to
accept *only* all uppercase OR *only* all lowercase log level names. So
I'm getting mixed signals :-)

In the end, regardless of the specific outcome of this PR, understanding
the degree to which `env_logger` compatibility is wanted would be useful
to know in general.

For my own use, `env_logger` compatibility is not something I need.


## Motivation

Logging directive strings parsed to create
`tracing_subscriber::filter::env::Directive`s are currently accepted as
all-lower-case or all-upper-case representations of the log level names
(like "info" and "INFO"), but mixed case representation (like "Info",
"iNfo", and "infO") are rejected.

This behavior is divergent with that of the `env_logger` crate, which
accepts the mixed case names. The `env_logger` crate gets the behavior
of parsing mixed case log level names from the underlying `log` crate,
so there may be an element of user expectations involved in that regard,
too, with `log` users expecting that case-insensitive log level names
will be accepted.

Accepting mixed case names would bring the behavior of the
`tracing_subscriber` crate back into alignment those other crates in
this regard.


## Solution

Accept mixed case names for log levels in directive strings.

This PR includes two commits:

   1. The first adds unit tests that demonstrate the mixed case logging
   level names being rejected.

   2. The second introduces an adjustment to `DIRECTIVE_RE` that accepts
   mixed case logging level names. With this change, the tests again all
   pass.

* [1 of 2]: subscriber: add more parse_directives* tests

These test parse_directives() against strings that contain only a
legit log level name. The variants that submit the mixed case forms
are currently failing:

    $ cargo test --lib 'filter::env::directive::test::parse_directives_'
    ...
    failures:
        filter::env::directive::test::parse_directives_global_bare_warn_mixed
        filter::env::directive::test::parse_directives_ralith_mixed

    test result: FAILED. 12 passed; 2 failed; 0 ignored; 0 measured; 61 filtered out

Fix to come in a follow-up commit.

Co-authored-by: Eliza Weisman <eliza@buoyant.io>
 Signed-off-by: Alan D. Salewski <ads@salewski.email>

* [2 of 2]: subscriber: directives: accept log levels in mixed case

Fix issue demonstrated by unit tests in commit f607b7f. With
this commit, the unit tests all pass.

The 'DIRECTIVE_RE' regex now uses a case-insensitive, non-capturing
subgroup when matching log level names in logging directive
strings. This allows correctly capturing not only, e.g., "info" and
"INFO" (both of which were also accepted previously), but also
"Info" and other combinations of mixed case variations for the legit
log level names.

This change makes the behavior of tracing-subscriber more consistent
with that of the `env_logger` crate, which also accepts mixed case
variations of the log level names.

Co-authored-by: Eliza Weisman <eliza@buoyant.io>
 Signed-off-by: Alan D. Salewski <ads@salewski.email>
  • Loading branch information
salewski authored and hawkw committed Dec 14, 2020
1 parent 199aa1a commit 0b35268
Showing 1 changed file with 65 additions and 2 deletions.
67 changes: 65 additions & 2 deletions tracing-subscriber/src/filter/env/directive.rs
Original file line number Diff line number Diff line change
Expand Up @@ -178,13 +178,17 @@ impl FromStr for Directive {
lazy_static! {
static ref DIRECTIVE_RE: Regex = Regex::new(
r"(?x)
^(?P<global_level>trace|TRACE|debug|DEBUG|info|INFO|warn|WARN|error|ERROR|off|OFF|[0-5])$ |
^(?P<global_level>(?i:trace|debug|info|warn|error|off|[0-5]))$ |
# ^^^.
# `note: we match log level names case-insensitively
^
(?: # target name or span name
(?P<target>[\w:-]+)|(?P<span>\[[^\]]*\])
){1,2}
(?: # level or nothing
=(?P<level>trace|TRACE|debug|DEBUG|info|INFO|warn|WARN|error|ERROR|off|OFF|[0-5])?
=(?P<level>(?i:trace|debug|info|warn|error|off|[0-5]))?
# ^^^.
# `note: we match log level names case-insensitively
)?
$
"
Expand Down Expand Up @@ -831,6 +835,32 @@ mod test {
assert_eq!(dirs[1].in_span, None);
}

#[test]
fn parse_directives_ralith_uc() {
let dirs = parse_directives("common=INFO,server=DEBUG");
assert_eq!(dirs.len(), 2, "\nparsed: {:#?}", dirs);
assert_eq!(dirs[0].target, Some("common".to_string()));
assert_eq!(dirs[0].level, LevelFilter::INFO);
assert_eq!(dirs[0].in_span, None);

assert_eq!(dirs[1].target, Some("server".to_string()));
assert_eq!(dirs[1].level, LevelFilter::DEBUG);
assert_eq!(dirs[1].in_span, None);
}

#[test]
fn parse_directives_ralith_mixed() {
let dirs = parse_directives("common=iNfo,server=dEbUg");
assert_eq!(dirs.len(), 2, "\nparsed: {:#?}", dirs);
assert_eq!(dirs[0].target, Some("common".to_string()));
assert_eq!(dirs[0].level, LevelFilter::INFO);
assert_eq!(dirs[0].in_span, None);

assert_eq!(dirs[1].target, Some("server".to_string()));
assert_eq!(dirs[1].level, LevelFilter::DEBUG);
assert_eq!(dirs[1].in_span, None);
}

#[test]
fn parse_directives_valid() {
let dirs = parse_directives("crate1::mod1=error,crate1::mod2,crate2=debug,crate3=off");
Expand Down Expand Up @@ -1003,6 +1033,39 @@ mod test {
assert_eq!(dirs[1].in_span, None);
}

// helper function for tests below
fn test_parse_bare_level(directive_to_test: &str, level_expected: LevelFilter) {
let dirs = parse_directives(directive_to_test);
assert_eq!(
dirs.len(),
1,
"\ninput: \"{}\"; parsed: {:#?}",
directive_to_test,
dirs
);
assert_eq!(dirs[0].target, None);
assert_eq!(dirs[0].level, level_expected);
assert_eq!(dirs[0].in_span, None);
}

#[test]
fn parse_directives_global_bare_warn_lc() {
// test parse_directives with no crate, in isolation, all lowercase
test_parse_bare_level("warn", LevelFilter::WARN);
}

#[test]
fn parse_directives_global_bare_warn_uc() {
// test parse_directives with no crate, in isolation, all uppercase
test_parse_bare_level("WARN", LevelFilter::WARN);
}

#[test]
fn parse_directives_global_bare_warn_mixed() {
// test parse_directives with no crate, in isolation, mixed case
test_parse_bare_level("wArN", LevelFilter::WARN);
}

#[test]
fn parse_directives_valid_with_spans() {
let dirs = parse_directives("crate1::mod1[foo]=error,crate1::mod2[bar],crate2[baz]=debug");
Expand Down

0 comments on commit 0b35268

Please sign in to comment.