From ffe15405b46bca44f1d79d1530a47bfb22c6a0ae Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Bastian=20K=C3=B6cher?= Date: Thu, 8 Oct 2020 20:40:27 +0200 Subject: [PATCH] Fixes logging of target names with dashes (#7281) * Fixes logging of target names with dashes There was a bug in tracing-core which resulted in not supporting dashes in target names. This was fixed upstream. Besides that a test was added to ensure that we don't break this again. * Extend test --- Cargo.lock | 19 ++++++----- client/cli/src/lib.rs | 33 +++++++++++++++++++- client/tracing/Cargo.toml | 6 ++-- primitives/io/Cargo.toml | 2 +- primitives/runtime-interface/test/Cargo.toml | 2 +- primitives/tracing/Cargo.toml | 22 ++++++------- 6 files changed, 59 insertions(+), 25 deletions(-) diff --git a/Cargo.lock b/Cargo.lock index 1617c891bc4de..c3ee635c37897 100644 --- a/Cargo.lock +++ b/Cargo.lock @@ -9390,12 +9390,13 @@ checksum = "e987b6bf443f4b5b3b6f38704195592cca41c5bb7aedd3c3693c7081f8289860" [[package]] name = "tracing" -version = "0.1.19" +version = "0.1.21" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "6d79ca061b032d6ce30c660fded31189ca0b9922bf483cd70759f13a2d86786c" +checksum = "b0987850db3733619253fe60e17cb59b82d37c7e6c0236bb81e4d6b87c879f27" dependencies = [ "cfg-if", "log", + "pin-project-lite", "tracing-attributes", "tracing-core", ] @@ -9413,9 +9414,9 @@ dependencies = [ [[package]] name = "tracing-core" -version = "0.1.16" +version = "0.1.17" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "5bcf46c1f1f06aeea2d6b81f3c863d0930a596c86ad1920d4e5bad6dd1d7119a" +checksum = "f50de3927f93d202783f4513cda820ab47ef17f624b03c096e86ef00c67e6b5f" dependencies = [ "lazy_static", ] @@ -9433,9 +9434,9 @@ dependencies = [ [[package]] name = "tracing-serde" -version = "0.1.1" +version = "0.1.2" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "b6ccba2f8f16e0ed268fc765d9b7ff22e965e7185d32f8f1ec8294fe17d86e79" +checksum = "fb65ea441fbb84f9f6748fd496cf7f63ec9af5bca94dd86456978d055e8eb28b" dependencies = [ "serde", "tracing-core", @@ -9443,9 +9444,9 @@ dependencies = [ [[package]] name = "tracing-subscriber" -version = "0.2.10" +version = "0.2.13" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "f7b33f8b2ef2ab0c3778c12646d9c42a24f7772bee4cdafc72199644a9f58fdc" +checksum = "4ef0a5e15477aa303afbfac3a44cba9b6430fdaad52423b1e6c0dbbe28c3eedd" dependencies = [ "ansi_term 0.12.1", "chrono", @@ -9456,6 +9457,8 @@ dependencies = [ "serde_json", "sharded-slab", "smallvec 1.4.1", + "thread_local", + "tracing", "tracing-core", "tracing-log", "tracing-serde", diff --git a/client/cli/src/lib.rs b/client/cli/src/lib.rs index bd71c50fb70ea..dd96cdd7836ab 100644 --- a/client/cli/src/lib.rs +++ b/client/cli/src/lib.rs @@ -333,10 +333,11 @@ pub fn init_logger( mod tests { use super::*; use tracing::{metadata::Kind, subscriber::Interest, Callsite, Level, Metadata}; + use std::{process::Command, env}; #[test] fn test_logger_filters() { - let test_pattern = "afg=debug,sync=trace,client=warn,telemetry"; + let test_pattern = "afg=debug,sync=trace,client=warn,telemetry,something-with-dash=error"; init_logger(&test_pattern, Default::default(), Default::default()).unwrap(); tracing::dispatcher::get_default(|dispatcher| { @@ -369,6 +370,36 @@ mod tests { assert!(test_filter("client", Level::WARN)); assert!(test_filter("telemetry", Level::TRACE)); + assert!(test_filter("something-with-dash", Level::ERROR)); }); } + + const EXPECTED_LOG_MESSAGE: &'static str = "yeah logging works as expected"; + + #[test] + fn dash_in_target_name_works() { + let executable = env::current_exe().unwrap(); + let output = Command::new(executable) + .env("ENABLE_LOGGING", "1") + .args(&["--nocapture", "log_something_with_dash_target_name"]) + .output() + .unwrap(); + + let output = String::from_utf8(output.stderr).unwrap(); + assert!(output.contains(EXPECTED_LOG_MESSAGE)); + } + + /// This is no actual test, it will be used by the `dash_in_target_name_works` test. + /// The given test will call the test executable to only execute this test that + /// will only print `EXPECTED_LOG_MESSAGE` through logging while using a target + /// name that contains a dash. This ensures that targets names with dashes work. + #[test] + fn log_something_with_dash_target_name() { + if env::var("ENABLE_LOGGING").is_ok() { + let test_pattern = "test-target=info"; + init_logger(&test_pattern, Default::default(), Default::default()).unwrap(); + + log::info!(target: "test-target", "{}", EXPECTED_LOG_MESSAGE); + } + } } diff --git a/client/tracing/Cargo.toml b/client/tracing/Cargo.toml index 37b8cb4792824..35db326c94929 100644 --- a/client/tracing/Cargo.toml +++ b/client/tracing/Cargo.toml @@ -20,8 +20,8 @@ rustc-hash = "1.1.0" serde = "1.0.101" serde_json = "1.0.41" slog = { version = "2.5.2", features = ["nested-values"] } -tracing = "0.1.19" -tracing-core = "0.1.13" -tracing-subscriber = "0.2.10" +tracing = "0.1.21" +tracing-core = "0.1.17" +tracing-subscriber = "0.2.13" sp-tracing = { version = "2.0.0", path = "../../primitives/tracing" } sc-telemetry = { version = "2.0.0", path = "../telemetry" } diff --git a/primitives/io/Cargo.toml b/primitives/io/Cargo.toml index 70a78f99d5dae..d2dd0a7c64a42 100644 --- a/primitives/io/Cargo.toml +++ b/primitives/io/Cargo.toml @@ -30,7 +30,7 @@ log = { version = "0.4.8", optional = true } futures = { version = "0.3.1", features = ["thread-pool"], optional = true } parking_lot = { version = "0.10.0", optional = true } tracing = { version = "0.1.19", default-features = false } -tracing-core = { version = "0.1.15", default-features = false} +tracing-core = { version = "0.1.17", default-features = false} [features] default = ["std"] diff --git a/primitives/runtime-interface/test/Cargo.toml b/primitives/runtime-interface/test/Cargo.toml index 0fd61f7bcea8a..d802f9cb6b39a 100644 --- a/primitives/runtime-interface/test/Cargo.toml +++ b/primitives/runtime-interface/test/Cargo.toml @@ -21,4 +21,4 @@ sp-runtime = { version = "2.0.0", path = "../../runtime" } sp-core = { version = "2.0.0", path = "../../core" } sp-io = { version = "2.0.0", path = "../../io" } tracing = "0.1.19" -tracing-core = "0.1.15" +tracing-core = "0.1.17" diff --git a/primitives/tracing/Cargo.toml b/primitives/tracing/Cargo.toml index a1d89af58c019..1000952b39fd4 100644 --- a/primitives/tracing/Cargo.toml +++ b/primitives/tracing/Cargo.toml @@ -20,23 +20,23 @@ targets = ["x86_64-unknown-linux-gnu", "wasm32-unknown-unknown"] [dependencies] sp-std = { version = "2.0.0", path = "../std", default-features = false} codec = { version = "1.3.1", package = "parity-scale-codec", default-features = false, features = ["derive"]} -tracing = { version = "0.1.19", default-features = false } -tracing-core = { version = "0.1.16", default-features = false } +tracing = { version = "0.1.21", default-features = false } +tracing-core = { version = "0.1.17", default-features = false } log = { version = "0.4.8", optional = true } tracing-subscriber = { version = "0.2.10", optional = true, features = ["tracing-log"] } [features] default = [ "std" ] with-tracing = [ - "codec/derive", - "codec/full", + "codec/derive", + "codec/full", ] std = [ - "with-tracing", - "tracing/std", - "tracing-core/std", - "codec/std", - "sp-std/std", - "log", - "tracing-subscriber", + "with-tracing", + "tracing/std", + "tracing-core/std", + "codec/std", + "sp-std/std", + "log", + "tracing-subscriber", ]