diff --git a/Cargo.lock b/Cargo.lock index d8602d2c6f3f0..38904fb98e727 100644 --- a/Cargo.lock +++ b/Cargo.lock @@ -3638,6 +3638,7 @@ dependencies = [ "sp-runtime", "sp-state-machine", "sp-timestamp", + "sp-tracing", "sp-transaction-pool", "sp-trie", "structopt", @@ -3830,13 +3831,13 @@ dependencies = [ name = "node-rpc-client" version = "2.0.0-rc6" dependencies = [ - "env_logger", "futures 0.1.29", "hyper 0.12.35", "jsonrpc-core-client", "log", "node-primitives", "sc-rpc", + "sp-tracing", ] [[package]] @@ -4871,7 +4872,6 @@ dependencies = [ name = "pallet-staking" version = "2.0.0-rc6" dependencies = [ - "env_logger", "frame-benchmarking", "frame-support", "frame-system", @@ -4893,6 +4893,7 @@ dependencies = [ "sp-staking", "sp-std", "sp-storage", + "sp-tracing", "static_assertions", "substrate-test-utils", ] @@ -6237,7 +6238,6 @@ dependencies = [ "bytes 0.5.6", "derive_more", "either", - "env_logger", "futures 0.3.5", "futures-timer 3.0.2", "libp2p", @@ -6257,6 +6257,7 @@ dependencies = [ "sp-blockchain", "sp-core", "sp-runtime", + "sp-tracing", "substrate-prometheus-endpoint", "substrate-test-runtime-client", ] @@ -6340,7 +6341,6 @@ dependencies = [ "bip39", "chrono", "derive_more", - "env_logger", "fdlimit", "futures 0.3.5", "hex", @@ -6378,6 +6378,9 @@ dependencies = [ "tempfile", "time", "tokio 0.2.22", + "tracing", + "tracing-log", + "tracing-subscriber", ] [[package]] @@ -6423,7 +6426,6 @@ name = "sc-client-db" version = "0.8.0-rc6" dependencies = [ "blake2-rfc", - "env_logger", "hash-db", "kvdb", "kvdb-memorydb", @@ -6446,6 +6448,7 @@ dependencies = [ "sp-keyring", "sp-runtime", "sp-state-machine", + "sp-tracing", "sp-trie", "substrate-prometheus-endpoint", "substrate-test-runtime-client", @@ -6467,7 +6470,6 @@ name = "sc-consensus-aura" version = "0.8.0-rc6" dependencies = [ "derive_more", - "env_logger", "futures 0.3.5", "futures-timer 3.0.2", "log", @@ -6494,6 +6496,7 @@ dependencies = [ "sp-keyring", "sp-runtime", "sp-timestamp", + "sp-tracing", "sp-version", "substrate-prometheus-endpoint", "substrate-test-runtime-client", @@ -6505,7 +6508,6 @@ name = "sc-consensus-babe" version = "0.8.0-rc6" dependencies = [ "derive_more", - "env_logger", "fork-tree", "futures 0.3.5", "futures-timer 3.0.2", @@ -6546,6 +6548,7 @@ dependencies = [ "sp-keyring", "sp-runtime", "sp-timestamp", + "sp-tracing", "sp-utils", "sp-version", "substrate-prometheus-endpoint", @@ -6599,7 +6602,6 @@ version = "0.8.0-rc6" dependencies = [ "assert_matches", "derive_more", - "env_logger", "futures 0.3.5", "jsonrpc-core", "jsonrpc-core-client", @@ -6720,6 +6722,7 @@ dependencies = [ "substrate-test-runtime", "test-case", "tracing", + "tracing-subscriber", "wasmi", "wat", ] @@ -6778,7 +6781,6 @@ version = "0.8.0-rc6" dependencies = [ "assert_matches", "derive_more", - "env_logger", "finality-grandpa", "fork-tree", "futures 0.3.5", @@ -6810,6 +6812,7 @@ dependencies = [ "sp-keyring", "sp-runtime", "sp-state-machine", + "sp-tracing", "sp-utils", "substrate-prometheus-endpoint", "substrate-test-runtime-client", @@ -6909,7 +6912,6 @@ dependencies = [ "bytes 0.5.6", "derive_more", "either", - "env_logger", "erased-serde", "fnv", "fork-tree", @@ -6946,6 +6948,7 @@ dependencies = [ "sp-keyring", "sp-runtime", "sp-test-primitives", + "sp-tracing", "sp-utils", "substrate-prometheus-endpoint", "substrate-test-runtime", @@ -6980,7 +6983,6 @@ dependencies = [ name = "sc-network-test" version = "0.8.0-rc6" dependencies = [ - "env_logger", "futures 0.3.5", "futures-timer 3.0.2", "libp2p", @@ -6997,6 +6999,7 @@ dependencies = [ "sp-consensus-babe", "sp-core", "sp-runtime", + "sp-tracing", "substrate-test-runtime", "substrate-test-runtime-client", "tempfile", @@ -7007,7 +7010,6 @@ name = "sc-offchain" version = "2.0.0-rc6" dependencies = [ "bytes 0.5.6", - "env_logger", "fnv", "futures 0.3.5", "futures-timer 3.0.2", @@ -7028,6 +7030,7 @@ dependencies = [ "sp-core", "sp-offchain", "sp-runtime", + "sp-tracing", "sp-transaction-pool", "sp-utils", "substrate-test-runtime-client", @@ -7216,7 +7219,6 @@ dependencies = [ name = "sc-service-test" version = "2.0.0-rc6" dependencies = [ - "env_logger", "fdlimit", "futures 0.1.29", "futures 0.3.5", @@ -7240,6 +7242,7 @@ dependencies = [ "sp-runtime", "sp-state-machine", "sp-storage", + "sp-tracing", "sp-transaction-pool", "sp-trie", "substrate-test-runtime", @@ -7252,7 +7255,6 @@ dependencies = [ name = "sc-state-db" version = "0.8.0-rc6" dependencies = [ - "env_logger", "log", "parity-scale-codec", "parity-util-mem", @@ -8427,6 +8429,7 @@ dependencies = [ "log", "rental", "tracing", + "tracing-subscriber", ] [[package]] @@ -8687,7 +8690,6 @@ dependencies = [ name = "substrate-frame-rpc-system" version = "2.0.0-rc6" dependencies = [ - "env_logger", "frame-system-rpc-runtime-api", "futures 0.3.5", "jsonrpc-core", @@ -8704,6 +8706,7 @@ dependencies = [ "sp-blockchain", "sp-core", "sp-runtime", + "sp-tracing", "sp-transaction-pool", "substrate-test-runtime-client", ] diff --git a/bin/node/bench/Cargo.toml b/bin/node/bench/Cargo.toml index 1914f460be0f1..ec797e32de3f2 100644 --- a/bin/node/bench/Cargo.toml +++ b/bin/node/bench/Cargo.toml @@ -31,6 +31,7 @@ sc-basic-authorship = { version = "0.8.0-rc6", path = "../../../client/basic-aut sp-inherents = { version = "2.0.0-rc6", path = "../../../primitives/inherents" } sp-finality-tracker = { version = "2.0.0-rc6", default-features = false, path = "../../../primitives/finality-tracker" } sp-timestamp = { version = "2.0.0-rc6", default-features = false, path = "../../../primitives/timestamp" } +sp-tracing = { version = "2.0.0-rc6", path = "../../../primitives/tracing" } hash-db = "0.15.2" tempfile = "3.1.0" fs_extra = "1" diff --git a/bin/node/bench/src/main.rs b/bin/node/bench/src/main.rs index 96ef1d920c1f5..46b659dd88387 100644 --- a/bin/node/bench/src/main.rs +++ b/bin/node/bench/src/main.rs @@ -79,7 +79,7 @@ fn main() { let opt = Opt::from_args(); if !opt.json { - sc_cli::init_logger(""); + sp_tracing::try_init_simple(); } let mut import_benchmarks = Vec::new(); diff --git a/bin/node/rpc-client/Cargo.toml b/bin/node/rpc-client/Cargo.toml index 698aa8f08aea5..92e1e1d3af15c 100644 --- a/bin/node/rpc-client/Cargo.toml +++ b/bin/node/rpc-client/Cargo.toml @@ -11,10 +11,10 @@ repository = "https://github.com/paritytech/substrate/" targets = ["x86_64-unknown-linux-gnu"] [dependencies] -env_logger = "0.7.0" futures = "0.1.29" hyper = "0.12.35" jsonrpc-core-client = { version = "14.2.0", default-features = false, features = ["http"] } log = "0.4.8" node-primitives = { version = "2.0.0-rc6", path = "../primitives" } +sp-tracing = { version = "2.0.0-rc6", path = "../../../primitives/tracing" } sc-rpc = { version = "2.0.0-rc6", path = "../../../client/rpc" } diff --git a/bin/node/rpc-client/src/main.rs b/bin/node/rpc-client/src/main.rs index eadd1c8d47247..31f1efa28ccd0 100644 --- a/bin/node/rpc-client/src/main.rs +++ b/bin/node/rpc-client/src/main.rs @@ -35,7 +35,7 @@ use jsonrpc_core_client::{ }; fn main() { - env_logger::init(); + sp_tracing::try_init_simple(); rt::run(rt::lazy(|| { let uri = "http://localhost:9933"; diff --git a/client/authority-discovery/Cargo.toml b/client/authority-discovery/Cargo.toml index e2be0f68e2318..651550fffb6d2 100644 --- a/client/authority-discovery/Cargo.toml +++ b/client/authority-discovery/Cargo.toml @@ -38,7 +38,7 @@ sp-runtime = { version = "2.0.0-rc6", path = "../../primitives/runtime" } sp-api = { version = "2.0.0-rc6", path = "../../primitives/api" } [dev-dependencies] -env_logger = "0.7.0" quickcheck = "0.9.0" +sp-tracing = { version = "2.0.0-rc6", path = "../../primitives/tracing" } sc-peerset = { version = "2.0.0-rc6", path = "../peerset" } substrate-test-runtime-client = { version = "2.0.0-rc6", path = "../../test-utils/runtime/client"} diff --git a/client/authority-discovery/src/worker/tests.rs b/client/authority-discovery/src/worker/tests.rs index 28192283054d1..f7b7dc41fee40 100644 --- a/client/authority-discovery/src/worker/tests.rs +++ b/client/authority-discovery/src/worker/tests.rs @@ -283,7 +283,7 @@ fn new_registers_metrics() { #[test] fn triggers_dht_get_query() { - let _ = ::env_logger::try_init(); + sp_tracing::try_init_simple(); let (_dht_event_tx, dht_event_rx) = channel(1000); // Generate authority keys @@ -321,7 +321,7 @@ fn triggers_dht_get_query() { #[test] fn publish_discover_cycle() { - let _ = ::env_logger::try_init(); + sp_tracing::try_init_simple(); // Node A publishing its address. diff --git a/client/cli/Cargo.toml b/client/cli/Cargo.toml index 6bee1afc5a909..933e18180a6f5 100644 --- a/client/cli/Cargo.toml +++ b/client/cli/Cargo.toml @@ -13,7 +13,6 @@ targets = ["x86_64-unknown-linux-gnu"] [dependencies] derive_more = "0.99.2" -env_logger = "0.7.0" log = "0.4.8" atty = "0.2.13" regex = "1.3.4" @@ -50,6 +49,9 @@ sc-tracing = { version = "2.0.0-rc6", path = "../tracing" } chrono = "0.4.10" parity-util-mem = { version = "0.7.0", default-features = false, features = ["primitive-types"] } serde = "1.0.111" +tracing = "0.1.10" +tracing-log = "0.1.1" +tracing-subscriber = "0.2.10" [target.'cfg(not(target_os = "unknown"))'.dependencies] rpassword = "4.0.1" diff --git a/client/cli/src/config.rs b/client/cli/src/config.rs index 6acb786cc1c23..43b755100244f 100644 --- a/client/cli/src/config.rs +++ b/client/cli/src/config.rs @@ -528,7 +528,7 @@ pub trait CliConfiguration: Sized { Ok(self.shared_params().log_filters().join(",")) } - /// Initialize substrate. This must be done only once. + /// Initialize substrate. This must be done only once per process. /// /// This method: /// @@ -537,10 +537,14 @@ pub trait CliConfiguration: Sized { /// 3. Raises the FD limit fn init(&self) -> Result<()> { let logger_pattern = self.log_filters()?; + let tracing_receiver = self.tracing_receiver()?; + let tracing_targets = self.tracing_targets()?; sp_panic_handler::set(&C::support_url(), &C::impl_version()); - init_logger(&logger_pattern); + if let Err(e) = init_logger(&logger_pattern, tracing_receiver, tracing_targets) { + log::warn!("💬 Problem initializing global logging framework: {:}", e) + } if let Some(new_limit) = fdlimit::raise_fd_limit() { if new_limit < RECOMMENDED_OPEN_FILE_DESCRIPTOR_LIMIT { diff --git a/client/cli/src/lib.rs b/client/cli/src/lib.rs index 1de74f087f8ee..f16d02cab51d5 100644 --- a/client/cli/src/lib.rs +++ b/client/cli/src/lib.rs @@ -32,10 +32,7 @@ pub use arg_enums::*; pub use commands::*; pub use config::*; pub use error::*; -use lazy_static::lazy_static; -use log::info; pub use params::*; -use regex::Regex; pub use runner::*; use sc_service::{Configuration, TaskExecutor}; pub use sc_service::{ChainSpec, Role}; @@ -46,6 +43,7 @@ use structopt::{ clap::{self, AppSettings}, StructOpt, }; +use tracing_subscriber::layer::SubscriberExt; /// Substrate client CLI /// @@ -228,79 +226,76 @@ pub trait SubstrateCli: Sized { fn native_runtime_version(chain_spec: &Box) -> &'static RuntimeVersion; } -/// Initialize the logger -pub fn init_logger(pattern: &str) { - use ansi_term::Colour; - - let mut builder = env_logger::Builder::new(); - // Disable info logging by default for some modules: - builder.filter(Some("ws"), log::LevelFilter::Off); - builder.filter(Some("yamux"), log::LevelFilter::Off); - builder.filter(Some("cranelift_codegen"), log::LevelFilter::Off); - builder.filter(Some("hyper"), log::LevelFilter::Warn); - builder.filter(Some("cranelift_wasm"), log::LevelFilter::Warn); - // Always log the special target `sc_tracing`, overrides global level - builder.filter(Some("sc_tracing"), log::LevelFilter::Trace); - // Enable info for others. - builder.filter(None, log::LevelFilter::Info); +/// Initialize the global logger +/// +/// This sets various global logging and tracing instances and thus may only be called once. +pub fn init_logger( + pattern: &str, + tracing_receiver: sc_tracing::TracingReceiver, + tracing_targets: Option, +) -> std::result::Result<(), String> { + if let Err(e) = tracing_log::LogTracer::init() { + return Err(format!( + "Registering Substrate logger failed: {:}!", e + )) + } + + let mut env_filter = tracing_subscriber::EnvFilter::default() + // Disable info logging by default for some modules. + .add_directive("ws=off".parse().expect("provided directive is valid")) + .add_directive("yamux=off".parse().expect("provided directive is valid")) + .add_directive("cranelift_codegen=off".parse().expect("provided directive is valid")) + // Set warn logging by default for some modules. + .add_directive("cranelife_wasm=warn".parse().expect("provided directive is valid")) + .add_directive("hyper=warn".parse().expect("provided directive is valid")) + // Always log the special target `sc_tracing`, overrides global level. + .add_directive("sc_tracing=trace".parse().expect("provided directive is valid")) + // Enable info for others. + .add_directive(tracing_subscriber::filter::LevelFilter::INFO.into()); if let Ok(lvl) = std::env::var("RUST_LOG") { - builder.parse_filters(&lvl); + if lvl != "" { + // We're not sure if log or tracing is available at this moment, so silently ignore the + // parse error. + if let Ok(directive) = lvl.parse() { + env_filter = env_filter.add_directive(directive); + } + } + } + + if pattern != "" { + // We're not sure if log or tracing is available at this moment, so silently ignore the + // parse error. + if let Ok(directive) = pattern.parse() { + env_filter = env_filter.add_directive(directive); + } } - builder.parse_filters(pattern); let isatty = atty::is(atty::Stream::Stderr); let enable_color = isatty; - builder.format(move |buf, record| { - let now = time::now(); - let timestamp = - time::strftime("%Y-%m-%d %H:%M:%S", &now).expect("Error formatting log timestamp"); - - let mut output = if log::max_level() <= log::LevelFilter::Info { - format!( - "{} {}", - Colour::Black.bold().paint(timestamp), - record.args(), - ) - } else { - let name = ::std::thread::current() - .name() - .map_or_else(Default::default, |x| { - format!("{}", Colour::Blue.bold().paint(x)) - }); - let millis = (now.tm_nsec as f32 / 1000000.0).floor() as usize; - let timestamp = format!("{}.{:03}", timestamp, millis); - format!( - "{} {} {} {} {}", - Colour::Black.bold().paint(timestamp), - name, - record.level(), - record.target(), - record.args() - ) - }; - - if !isatty && record.level() <= log::Level::Info && atty::is(atty::Stream::Stdout) { - // duplicate INFO/WARN output to console - println!("{}", output); + let subscriber = tracing_subscriber::FmtSubscriber::builder() + .with_env_filter(env_filter) + .with_target(false) + .with_ansi(enable_color) + .with_writer(std::io::stderr) + .compact() + .finish(); + + if let Some(tracing_targets) = tracing_targets { + let profiling = sc_tracing::ProfilingLayer::new(tracing_receiver, &tracing_targets); + + if let Err(e) = tracing::subscriber::set_global_default(subscriber.with(profiling)) { + return Err(format!( + "Registering Substrate tracing subscriber failed: {:}!", e + )) } - - if !enable_color { - output = kill_color(output.as_ref()); + } else { + if let Err(e) = tracing::subscriber::set_global_default(subscriber) { + return Err(format!( + "Registering Substrate tracing subscriber failed: {:}!", e + )) } - - writeln!(buf, "{}", output) - }); - - if builder.try_init().is_err() { - info!("💬 Not registering Substrate logger, as there is already a global logger registered!"); - } -} - -fn kill_color(s: &str) -> String { - lazy_static! { - static ref RE: Regex = Regex::new("\x1b\\[[^m]+m").expect("Error initializing color regex"); } - RE.replace_all(s, "").to_string() + Ok(()) } diff --git a/client/consensus/aura/Cargo.toml b/client/consensus/aura/Cargo.toml index b107499daf48b..9f6f00a621dd4 100644 --- a/client/consensus/aura/Cargo.toml +++ b/client/consensus/aura/Cargo.toml @@ -39,10 +39,10 @@ prometheus-endpoint = { package = "substrate-prometheus-endpoint", path = "../.. [dev-dependencies] sp-keyring = { version = "2.0.0-rc6", path = "../../../primitives/keyring" } +sp-tracing = { version = "2.0.0-rc6", path = "../../../primitives/tracing" } sc-executor = { version = "0.8.0-rc6", path = "../../executor" } sc-network = { version = "0.8.0-rc6", path = "../../network" } sc-network-test = { version = "0.8.0-rc6", path = "../../network/test" } sc-service = { version = "0.8.0-rc6", default-features = false, path = "../../service" } substrate-test-runtime-client = { version = "2.0.0-rc6", path = "../../../test-utils/runtime/client" } -env_logger = "0.7.0" tempfile = "3.1.0" diff --git a/client/consensus/aura/src/lib.rs b/client/consensus/aura/src/lib.rs index 4204028711328..d79caaa1d6ac5 100644 --- a/client/consensus/aura/src/lib.rs +++ b/client/consensus/aura/src/lib.rs @@ -991,7 +991,7 @@ mod tests { #[test] #[allow(deprecated)] fn authoring_blocks() { - let _ = env_logger::try_init(); + sp_tracing::try_init_simple(); let net = AuraTestNet::new(3); let peers = &[ diff --git a/client/consensus/babe/Cargo.toml b/client/consensus/babe/Cargo.toml index 5838567096706..836232dc90a3a 100644 --- a/client/consensus/babe/Cargo.toml +++ b/client/consensus/babe/Cargo.toml @@ -53,13 +53,13 @@ retain_mut = "0.1.1" [dev-dependencies] sp-keyring = { version = "2.0.0-rc6", path = "../../../primitives/keyring" } +sp-tracing = { version = "2.0.0-rc6", path = "../../../primitives/tracing" } sc-executor = { version = "0.8.0-rc6", path = "../../executor" } sc-network = { version = "0.8.0-rc6", path = "../../network" } sc-network-test = { version = "0.8.0-rc6", path = "../../network/test" } sc-service = { version = "0.8.0-rc6", default-features = false, path = "../../service" } substrate-test-runtime-client = { version = "2.0.0-rc6", path = "../../../test-utils/runtime/client" } sc-block-builder = { version = "0.8.0-rc6", path = "../../block-builder" } -env_logger = "0.7.0" rand_chacha = "0.2.2" tempfile = "3.1.0" diff --git a/client/consensus/babe/src/tests.rs b/client/consensus/babe/src/tests.rs index e302a3b3d0a61..87876be8ae456 100644 --- a/client/consensus/babe/src/tests.rs +++ b/client/consensus/babe/src/tests.rs @@ -347,7 +347,7 @@ impl TestNetFactory for BabeTestNet { #[test] #[should_panic] fn rejects_empty_block() { - env_logger::try_init().unwrap(); + sp_tracing::try_init_simple(); let mut net = BabeTestNet::new(3); let block_builder = |builder: BlockBuilder<_, _, _>| { builder.build().unwrap().block @@ -360,7 +360,7 @@ fn rejects_empty_block() { fn run_one_test( mutator: impl Fn(&mut TestHeader, Stage) + Send + Sync + 'static, ) { - let _ = env_logger::try_init(); + sp_tracing::try_init_simple(); let mutator = Arc::new(mutator) as Mutator; MUTATOR.with(|m| *m.borrow_mut() = mutator.clone()); @@ -489,7 +489,7 @@ fn rejects_missing_consensus_digests() { #[test] fn wrong_consensus_engine_id_rejected() { - let _ = env_logger::try_init(); + sp_tracing::try_init_simple(); let sig = AuthorityPair::generate().0.sign(b""); let bad_seal: Item = DigestItem::Seal([0; 4], sig.to_vec()); assert!(bad_seal.as_babe_pre_digest().is_none()); @@ -498,14 +498,14 @@ fn wrong_consensus_engine_id_rejected() { #[test] fn malformed_pre_digest_rejected() { - let _ = env_logger::try_init(); + sp_tracing::try_init_simple(); let bad_seal: Item = DigestItem::Seal(BABE_ENGINE_ID, [0; 64].to_vec()); assert!(bad_seal.as_babe_pre_digest().is_none()); } #[test] fn sig_is_not_pre_digest() { - let _ = env_logger::try_init(); + sp_tracing::try_init_simple(); let sig = AuthorityPair::generate().0.sign(b""); let bad_seal: Item = DigestItem::Seal(BABE_ENGINE_ID, sig.to_vec()); assert!(bad_seal.as_babe_pre_digest().is_none()); @@ -514,7 +514,7 @@ fn sig_is_not_pre_digest() { #[test] fn can_author_block() { - let _ = env_logger::try_init(); + sp_tracing::try_init_simple(); let keystore_path = tempfile::tempdir().expect("Creates keystore path"); let keystore = sc_keystore::Store::open(keystore_path.path(), None).expect("Creates keystore"); let pair = keystore.write().insert_ephemeral_from_seed::("//Alice") @@ -821,7 +821,7 @@ fn verify_slots_are_strictly_increasing() { #[test] fn babe_transcript_generation_match() { - let _ = env_logger::try_init(); + sp_tracing::try_init_simple(); let keystore_path = tempfile::tempdir().expect("Creates keystore path"); let keystore = sc_keystore::Store::open(keystore_path.path(), None).expect("Creates keystore"); let pair = keystore.write().insert_ephemeral_from_seed::("//Alice") diff --git a/client/consensus/manual-seal/Cargo.toml b/client/consensus/manual-seal/Cargo.toml index 8305f856e09a2..33f443bce9d12 100644 --- a/client/consensus/manual-seal/Cargo.toml +++ b/client/consensus/manual-seal/Cargo.toml @@ -22,28 +22,27 @@ parking_lot = "0.10.0" serde = { version = "1.0", features=["derive"] } assert_matches = "1.3.0" -sc-client-api = { path = "../../api", version = "2.0.0-rc5" } -sc-consensus-babe = { path = "../../consensus/babe", version = "0.8.0-rc5" } -sc-consensus-epochs = { path = "../../consensus/epochs", version = "0.8.0-rc5" } -sp-consensus-babe = { path = "../../../primitives/consensus/babe", version = "0.8.0-rc5" } -sc-keystore = { path = "../../keystore", version = "2.0.0-rc5" } +sc-client-api = { path = "../../api", version = "2.0.0-rc6" } +sc-consensus-babe = { path = "../../consensus/babe", version = "0.8.0-rc6" } +sc-consensus-epochs = { path = "../../consensus/epochs", version = "0.8.0-rc6" } +sp-consensus-babe = { path = "../../../primitives/consensus/babe", version = "0.8.0-rc6" } +sc-keystore = { path = "../../keystore", version = "2.0.0-rc6" } -sc-transaction-pool = { path = "../../transaction-pool", version = "2.0.0-rc5" } -sp-blockchain = { path = "../../../primitives/blockchain", version = "2.0.0-rc5" } -sp-consensus = { package = "sp-consensus", path = "../../../primitives/consensus/common", version = "0.8.0-rc5" } -sp-inherents = { path = "../../../primitives/inherents", version = "2.0.0-rc5" } -sp-runtime = { path = "../../../primitives/runtime", version = "2.0.0-rc5" } -sp-core = { path = "../../../primitives/core", version = "2.0.0-rc5" } -sp-api = { path = "../../../primitives/api", version = "2.0.0-rc5" } -sp-transaction-pool = { path = "../../../primitives/transaction-pool", version = "2.0.0-rc5" } +sc-transaction-pool = { path = "../../transaction-pool", version = "2.0.0-rc6" } +sp-blockchain = { path = "../../../primitives/blockchain", version = "2.0.0-rc6" } +sp-consensus = { package = "sp-consensus", path = "../../../primitives/consensus/common", version = "0.8.0-rc6" } +sp-inherents = { path = "../../../primitives/inherents", version = "2.0.0-rc6" } +sp-runtime = { path = "../../../primitives/runtime", version = "2.0.0-rc6" } +sp-core = { path = "../../../primitives/core", version = "2.0.0-rc6" } +sp-api = { path = "../../../primitives/api", version = "2.0.0-rc6" } +sp-transaction-pool = { path = "../../../primitives/transaction-pool", version = "2.0.0-rc6" } sp-timestamp = { path = "../../../primitives/timestamp", version = "2.0.0-rc6" } -prometheus-endpoint = { package = "substrate-prometheus-endpoint", path = "../../../utils/prometheus", version = "0.8.0-rc5" } +prometheus-endpoint = { package = "substrate-prometheus-endpoint", path = "../../../utils/prometheus", version = "0.8.0-rc6" } [dev-dependencies] tokio = { version = "0.2", features = ["rt-core", "macros"] } sc-basic-authorship = { path = "../../basic-authorship", version = "0.8.0-rc6" } substrate-test-runtime-client = { path = "../../../test-utils/runtime/client", version = "2.0.0-rc6" } substrate-test-runtime-transaction-pool = { path = "../../../test-utils/runtime/transaction-pool", version = "2.0.0-rc6" } -env_logger = "0.7.0" tempfile = "3.1.0" diff --git a/client/db/Cargo.toml b/client/db/Cargo.toml index bbe6f83f4c1d2..79b75582dc1cd 100644 --- a/client/db/Cargo.toml +++ b/client/db/Cargo.toml @@ -39,8 +39,8 @@ prometheus-endpoint = { package = "substrate-prometheus-endpoint", version = "0. [dev-dependencies] sp-keyring = { version = "2.0.0-rc6", path = "../../primitives/keyring" } +sp-tracing = { version = "2.0.0-rc6", path = "../../primitives/tracing" } substrate-test-runtime-client = { version = "2.0.0-rc6", path = "../../test-utils/runtime/client" } -env_logger = "0.7.0" quickcheck = "0.9" kvdb-rocksdb = "0.9.1" tempfile = "3" diff --git a/client/db/src/lib.rs b/client/db/src/lib.rs index 927df1c0a7d25..8196a750557a8 100644 --- a/client/db/src/lib.rs +++ b/client/db/src/lib.rs @@ -1958,7 +1958,7 @@ pub(crate) mod tests { #[test] fn delete_only_when_negative_rc() { - let _ = ::env_logger::try_init(); + sp_tracing::try_init_simple(); let key; let backend = Backend::::new_test(1, 0); diff --git a/client/db/src/storage_cache.rs b/client/db/src/storage_cache.rs index 434b301ed6240..0b4b6d4f88ef5 100644 --- a/client/db/src/storage_cache.rs +++ b/client/db/src/storage_cache.rs @@ -1024,7 +1024,7 @@ mod tests { #[test] fn simple_fork() { - let _ = ::env_logger::try_init(); + sp_tracing::try_init_simple(); let root_parent = H256::random(); let key = H256::random()[..].to_vec(); @@ -1245,7 +1245,7 @@ mod tests { #[test] fn fix_storage_mismatch_issue() { - let _ = ::env_logger::try_init(); + sp_tracing::try_init_simple(); let root_parent = H256::random(); let key = H256::random()[..].to_vec(); diff --git a/client/executor/Cargo.toml b/client/executor/Cargo.toml index 0b9829e6f342b..a60bff877d71e 100644 --- a/client/executor/Cargo.toml +++ b/client/executor/Cargo.toml @@ -47,6 +47,7 @@ sp-runtime = { version = "2.0.0-rc6", path = "../../primitives/runtime" } sp-tracing = { version = "2.0.0-rc6", path = "../../primitives/tracing" } sc-tracing = { version = "2.0.0-rc6", path = "../tracing" } tracing = "0.1.18" +tracing-subscriber = "0.2.10" [features] default = [ "std" ] diff --git a/client/executor/src/integration_tests/mod.rs b/client/executor/src/integration_tests/mod.rs index a9ac0d0f30c23..1c744f544b48f 100644 --- a/client/executor/src/integration_tests/mod.rs +++ b/client/executor/src/integration_tests/mod.rs @@ -30,6 +30,7 @@ use test_case::test_case; use sp_trie::{TrieConfiguration, trie_types::Layout}; use sp_wasm_interface::HostFunctions as _; use sp_runtime::traits::BlakeTwo256; +use tracing_subscriber::layer::SubscriberExt; use crate::WasmExecutionMethod; @@ -678,8 +679,11 @@ fn wasm_tracing_should_work(wasm_method: WasmExecutionMethod) { let handler = TestTraceHandler(traces.clone()); // Create subscriber with wasm_tracing disabled - let test_subscriber = sc_tracing::ProfilingSubscriber::new_with_handler( - Box::new(handler), "integration_test_span_target"); + let test_subscriber = tracing_subscriber::fmt().finish().with( + sc_tracing::ProfilingLayer::new_with_handler( + Box::new(handler), "integration_test_span_target" + ) + ); let _guard = tracing::subscriber::set_default(test_subscriber); diff --git a/client/finality-grandpa/Cargo.toml b/client/finality-grandpa/Cargo.toml index b73fbbd8d1728..60363544e3e4a 100644 --- a/client/finality-grandpa/Cargo.toml +++ b/client/finality-grandpa/Cargo.toml @@ -54,7 +54,7 @@ sp-keyring = { version = "2.0.0-rc6", path = "../../primitives/keyring" } substrate-test-runtime-client = { version = "2.0.0-rc6", path = "../../test-utils/runtime/client" } sp-consensus-babe = { version = "0.8.0-rc6", path = "../../primitives/consensus/babe" } sp-state-machine = { version = "0.8.0-rc6", path = "../../primitives/state-machine" } -env_logger = "0.7.0" +sp-tracing = { version = "2.0.0-rc6", path = "../../primitives/tracing" } tokio = { version = "0.2", features = ["rt-core"] } tempfile = "3.1.0" sp-api = { version = "2.0.0-rc6", path = "../../primitives/api" } diff --git a/client/finality-grandpa/src/communication/tests.rs b/client/finality-grandpa/src/communication/tests.rs index 6a1513769aa26..1a773acd6d0fb 100644 --- a/client/finality-grandpa/src/communication/tests.rs +++ b/client/finality-grandpa/src/communication/tests.rs @@ -361,7 +361,7 @@ fn good_commit_leads_to_relay() { #[test] fn bad_commit_leads_to_report() { - let _ = env_logger::try_init(); + sp_tracing::try_init_simple(); let private = [Ed25519Keyring::Alice, Ed25519Keyring::Bob, Ed25519Keyring::Charlie]; let public = make_ids(&private[..]); let voter_set = Arc::new(VoterSet::new(public.iter().cloned()).unwrap()); diff --git a/client/finality-grandpa/src/tests.rs b/client/finality-grandpa/src/tests.rs index 6e8def57f50ea..7e5282fe3e9f0 100644 --- a/client/finality-grandpa/src/tests.rs +++ b/client/finality-grandpa/src/tests.rs @@ -417,7 +417,7 @@ fn add_forced_change( #[test] fn finalize_3_voters_no_observers() { - let _ = env_logger::try_init(); + sp_tracing::try_init_simple(); let mut runtime = Runtime::new().unwrap(); let peers = &[Ed25519Keyring::Alice, Ed25519Keyring::Bob, Ed25519Keyring::Charlie]; let voters = make_ids(peers); @@ -522,7 +522,7 @@ fn finalize_3_voters_1_full_observer() { #[test] fn transition_3_voters_twice_1_full_observer() { - let _ = env_logger::try_init(); + sp_tracing::try_init_simple(); let peers_a = &[ Ed25519Keyring::Alice, Ed25519Keyring::Bob, @@ -792,7 +792,7 @@ fn sync_justifications_on_change_blocks() { #[test] fn finalizes_multiple_pending_changes_in_order() { - let _ = env_logger::try_init(); + sp_tracing::try_init_simple(); let mut runtime = Runtime::new().unwrap(); let peers_a = &[Ed25519Keyring::Alice, Ed25519Keyring::Bob, Ed25519Keyring::Charlie]; @@ -852,7 +852,7 @@ fn finalizes_multiple_pending_changes_in_order() { #[test] fn force_change_to_new_set() { - let _ = env_logger::try_init(); + sp_tracing::try_init_simple(); let mut runtime = Runtime::new().unwrap(); // two of these guys are offline. let genesis_authorities = &[ @@ -1014,7 +1014,7 @@ fn voter_persists_its_votes() { use futures::future; use sp_utils::mpsc::{tracing_unbounded, TracingUnboundedReceiver}; - let _ = env_logger::try_init(); + sp_tracing::try_init_simple(); let mut runtime = Runtime::new().unwrap(); // we have two authorities but we'll only be running the voter for alice @@ -1270,7 +1270,7 @@ fn voter_persists_its_votes() { #[test] fn finalize_3_voters_1_light_observer() { - let _ = env_logger::try_init(); + sp_tracing::try_init_simple(); let mut runtime = Runtime::new().unwrap(); let authorities = &[Ed25519Keyring::Alice, Ed25519Keyring::Bob, Ed25519Keyring::Charlie]; let voters = make_ids(authorities); @@ -1315,7 +1315,7 @@ fn finalize_3_voters_1_light_observer() { #[test] fn finality_proof_is_fetched_by_light_client_when_consensus_data_changes() { - let _ = ::env_logger::try_init(); + sp_tracing::try_init_simple(); let mut runtime = Runtime::new().unwrap(); let peers = &[Ed25519Keyring::Alice]; @@ -1345,7 +1345,7 @@ fn empty_finality_proof_is_returned_to_light_client_when_authority_set_is_differ // for debug: to ensure that without forced change light client will sync finality proof const FORCE_CHANGE: bool = true; - let _ = ::env_logger::try_init(); + sp_tracing::try_init_simple(); let mut runtime = Runtime::new().unwrap(); // two of these guys are offline. @@ -1409,7 +1409,7 @@ fn empty_finality_proof_is_returned_to_light_client_when_authority_set_is_differ #[test] fn voter_catches_up_to_latest_round_when_behind() { - let _ = env_logger::try_init(); + sp_tracing::try_init_simple(); let mut runtime = Runtime::new().unwrap(); let peers = &[Ed25519Keyring::Alice, Ed25519Keyring::Bob]; diff --git a/client/informant/Cargo.toml b/client/informant/Cargo.toml index 6e6dc01f91e53..e711384d7f5ba 100644 --- a/client/informant/Cargo.toml +++ b/client/informant/Cargo.toml @@ -20,6 +20,6 @@ sc-client-api = { version = "2.0.0-rc6", path = "../api" } sc-network = { version = "0.8.0-rc6", path = "../network" } sp-blockchain = { version = "2.0.0-rc6", path = "../../primitives/blockchain" } sp-runtime = { version = "2.0.0-rc6", path = "../../primitives/runtime" } -sp-utils = { version = "2.0.0-rc2", path = "../../primitives/utils" } -sp-transaction-pool = { version = "2.0.0-rc2", path = "../../primitives/transaction-pool" } +sp-utils = { version = "2.0.0-rc6", path = "../../primitives/utils" } +sp-transaction-pool = { version = "2.0.0-rc6", path = "../../primitives/transaction-pool" } wasm-timer = "0.2" diff --git a/client/light/Cargo.toml b/client/light/Cargo.toml index 23b306d178e37..e160526ce8d29 100644 --- a/client/light/Cargo.toml +++ b/client/light/Cargo.toml @@ -13,15 +13,15 @@ documentation = "https://docs.rs/sc-light" parking_lot = "0.10.0" lazy_static = "1.4.0" hash-db = "0.15.2" -sp-runtime = { version = "2.0.0-rc2", path = "../../primitives/runtime" } -sp-externalities = { version = "0.8.0-rc2", path = "../../primitives/externalities" } -sp-blockchain = { version = "2.0.0-rc2", path = "../../primitives/blockchain" } -sp-core = { version = "2.0.0-rc2", path = "../../primitives/core" } -sp-state-machine = { version = "0.8.0-rc2", path = "../../primitives/state-machine" } -sc-client-api = { version = "2.0.0-rc2", path = "../api" } -sp-api = { version = "2.0.0-rc2", path = "../../primitives/api" } +sp-runtime = { version = "2.0.0-rc6", path = "../../primitives/runtime" } +sp-externalities = { version = "0.8.0-rc6", path = "../../primitives/externalities" } +sp-blockchain = { version = "2.0.0-rc6", path = "../../primitives/blockchain" } +sp-core = { version = "2.0.0-rc6", path = "../../primitives/core" } +sp-state-machine = { version = "0.8.0-rc6", path = "../../primitives/state-machine" } +sc-client-api = { version = "2.0.0-rc6", path = "../api" } +sp-api = { version = "2.0.0-rc6", path = "../../primitives/api" } codec = { package = "parity-scale-codec", version = "1.3.4" } -sc-executor = { version = "0.8.0-rc2", path = "../executor" } +sc-executor = { version = "0.8.0-rc6", path = "../executor" } [features] default = [] diff --git a/client/network/Cargo.toml b/client/network/Cargo.toml index 7c06de7ccd1cb..c220728a4e4b4 100644 --- a/client/network/Cargo.toml +++ b/client/network/Cargo.toml @@ -69,12 +69,12 @@ features = ["identify", "kad", "mdns-async-std", "mplex", "noise", "ping", "requ [dev-dependencies] assert_matches = "1.3" -env_logger = "0.7.0" libp2p = { version = "0.28.1", default-features = false } quickcheck = "0.9.0" rand = "0.7.2" sp-keyring = { version = "2.0.0-rc6", path = "../../primitives/keyring" } sp-test-primitives = { version = "2.0.0-rc6", path = "../../primitives/test-primitives" } +sp-tracing = { version = "2.0.0-rc6", path = "../../primitives/tracing" } substrate-test-runtime = { version = "2.0.0-rc6", path = "../../test-utils/runtime" } substrate-test-runtime-client = { version = "2.0.0-rc6", path = "../../test-utils/runtime/client" } tempfile = "3.1.0" diff --git a/client/network/src/light_client_handler.rs b/client/network/src/light_client_handler.rs index 7f5ec54470e5d..c1ff14fc82a22 100644 --- a/client/network/src/light_client_handler.rs +++ b/client/network/src/light_client_handler.rs @@ -2004,7 +2004,7 @@ mod tests { #[test] fn send_receive_header() { - let _ = env_logger::try_init(); + sp_tracing::try_init_simple(); let chan = oneshot::channel(); let request = light::RemoteHeaderRequest { cht_root: Default::default(), diff --git a/client/network/src/protocol/sync/extra_requests.rs b/client/network/src/protocol/sync/extra_requests.rs index d025b86b2536f..df336c25339fd 100644 --- a/client/network/src/protocol/sync/extra_requests.rs +++ b/client/network/src/protocol/sync/extra_requests.rs @@ -463,7 +463,7 @@ mod tests { #[test] fn request_is_rescheduled_when_earlier_block_is_finalized() { - let _ = ::env_logger::try_init(); + sp_tracing::try_init_simple(); let mut finality_proofs = ExtraRequests::::new("test"); diff --git a/client/network/test/Cargo.toml b/client/network/test/Cargo.toml index fc6c47699fb8f..29b1139877208 100644 --- a/client/network/test/Cargo.toml +++ b/client/network/test/Cargo.toml @@ -28,8 +28,8 @@ sp-runtime = { version = "2.0.0-rc6", path = "../../../primitives/runtime" } sp-core = { version = "2.0.0-rc6", path = "../../../primitives/core" } sc-block-builder = { version = "0.8.0-rc6", path = "../../block-builder" } sp-consensus-babe = { version = "0.8.0-rc6", path = "../../../primitives/consensus/babe" } -env_logger = "0.7.0" substrate-test-runtime-client = { version = "2.0.0-rc6", path = "../../../test-utils/runtime/client" } substrate-test-runtime = { version = "2.0.0-rc6", path = "../../../test-utils/runtime" } tempfile = "3.1.0" +sp-tracing = { version = "2.0.0-rc6", path = "../../../primitives/tracing" } sc-service = { version = "0.8.0-rc6", default-features = false, features = ["test-helpers"], path = "../../service" } diff --git a/client/network/test/src/sync.rs b/client/network/test/src/sync.rs index 1cf2a8fee3798..86e274aae10eb 100644 --- a/client/network/test/src/sync.rs +++ b/client/network/test/src/sync.rs @@ -24,7 +24,7 @@ use sp_consensus::block_validation::Validation; use substrate_test_runtime::Header; fn test_ancestor_search_when_common_is(n: usize) { - let _ = ::env_logger::try_init(); + sp_tracing::try_init_simple(); let mut net = TestNet::new(3); net.peer(0).push_blocks(n, false); @@ -42,7 +42,7 @@ fn test_ancestor_search_when_common_is(n: usize) { #[test] fn sync_peers_works() { - let _ = ::env_logger::try_init(); + sp_tracing::try_init_simple(); let mut net = TestNet::new(3); block_on(futures::future::poll_fn::<(), _>(|cx| { @@ -58,7 +58,7 @@ fn sync_peers_works() { #[test] fn sync_cycle_from_offline_to_syncing_to_offline() { - let _ = ::env_logger::try_init(); + sp_tracing::try_init_simple(); let mut net = TestNet::new(3); for peer in 0..3 { // Offline, and not major syncing. @@ -113,7 +113,7 @@ fn sync_cycle_from_offline_to_syncing_to_offline() { #[test] fn syncing_node_not_major_syncing_when_disconnected() { - let _ = ::env_logger::try_init(); + sp_tracing::try_init_simple(); let mut net = TestNet::new(3); // Generate blocks. @@ -147,7 +147,7 @@ fn syncing_node_not_major_syncing_when_disconnected() { #[test] fn sync_from_two_peers_works() { - let _ = ::env_logger::try_init(); + sp_tracing::try_init_simple(); let mut net = TestNet::new(3); net.peer(1).push_blocks(100, false); net.peer(2).push_blocks(100, false); @@ -159,7 +159,7 @@ fn sync_from_two_peers_works() { #[test] fn sync_from_two_peers_with_ancestry_search_works() { - let _ = ::env_logger::try_init(); + sp_tracing::try_init_simple(); let mut net = TestNet::new(3); net.peer(0).push_blocks(10, true); net.peer(1).push_blocks(100, false); @@ -171,7 +171,7 @@ fn sync_from_two_peers_with_ancestry_search_works() { #[test] fn ancestry_search_works_when_backoff_is_one() { - let _ = ::env_logger::try_init(); + sp_tracing::try_init_simple(); let mut net = TestNet::new(3); net.peer(0).push_blocks(1, false); @@ -185,7 +185,7 @@ fn ancestry_search_works_when_backoff_is_one() { #[test] fn ancestry_search_works_when_ancestor_is_genesis() { - let _ = ::env_logger::try_init(); + sp_tracing::try_init_simple(); let mut net = TestNet::new(3); net.peer(0).push_blocks(13, true); @@ -214,7 +214,7 @@ fn ancestry_search_works_when_common_is_hundred() { #[test] fn sync_long_chain_works() { - let _ = ::env_logger::try_init(); + sp_tracing::try_init_simple(); let mut net = TestNet::new(2); net.peer(1).push_blocks(500, false); net.block_until_sync(); @@ -224,7 +224,7 @@ fn sync_long_chain_works() { #[test] fn sync_no_common_longer_chain_fails() { - let _ = ::env_logger::try_init(); + sp_tracing::try_init_simple(); let mut net = TestNet::new(3); net.peer(0).push_blocks(20, true); net.peer(1).push_blocks(20, false); @@ -242,7 +242,7 @@ fn sync_no_common_longer_chain_fails() { #[test] fn sync_justifications() { - let _ = ::env_logger::try_init(); + sp_tracing::try_init_simple(); let mut net = JustificationTestNet::new(3); net.peer(0).push_blocks(20, false); net.block_until_sync(); @@ -283,7 +283,7 @@ fn sync_justifications() { #[test] fn sync_justifications_across_forks() { - let _ = ::env_logger::try_init(); + sp_tracing::try_init_simple(); let mut net = JustificationTestNet::new(3); // we push 5 blocks net.peer(0).push_blocks(5, false); @@ -315,7 +315,7 @@ fn sync_justifications_across_forks() { #[test] fn sync_after_fork_works() { - let _ = ::env_logger::try_init(); + sp_tracing::try_init_simple(); let mut net = TestNet::new(3); net.peer(0).push_blocks(30, false); net.peer(1).push_blocks(30, false); @@ -338,7 +338,7 @@ fn sync_after_fork_works() { #[test] fn syncs_all_forks() { - let _ = ::env_logger::try_init(); + sp_tracing::try_init_simple(); let mut net = TestNet::new(4); net.peer(0).push_blocks(2, false); net.peer(1).push_blocks(2, false); @@ -356,7 +356,7 @@ fn syncs_all_forks() { #[test] fn own_blocks_are_announced() { - let _ = ::env_logger::try_init(); + sp_tracing::try_init_simple(); let mut net = TestNet::new(3); net.block_until_sync(); // connect'em net.peer(0).generate_blocks(1, BlockOrigin::Own, |builder| builder.build().unwrap().block); @@ -372,7 +372,7 @@ fn own_blocks_are_announced() { #[test] fn blocks_are_not_announced_by_light_nodes() { - let _ = ::env_logger::try_init(); + sp_tracing::try_init_simple(); let mut net = TestNet::new(0); // full peer0 is connected to light peer @@ -401,7 +401,7 @@ fn blocks_are_not_announced_by_light_nodes() { #[test] fn can_sync_small_non_best_forks() { - let _ = ::env_logger::try_init(); + sp_tracing::try_init_simple(); let mut net = TestNet::new(2); net.peer(0).push_blocks(30, false); net.peer(1).push_blocks(30, false); @@ -464,7 +464,7 @@ fn can_sync_small_non_best_forks() { #[test] fn can_not_sync_from_light_peer() { - let _ = ::env_logger::try_init(); + sp_tracing::try_init_simple(); // given the network with 1 full nodes (#0) and 1 light node (#1) let mut net = TestNet::new(1); @@ -497,7 +497,7 @@ fn can_not_sync_from_light_peer() { #[test] fn light_peer_imports_header_from_announce() { - let _ = ::env_logger::try_init(); + sp_tracing::try_init_simple(); fn import_with_announce(net: &mut TestNet, hash: H256) { net.peer(0).announce_block(hash, Vec::new()); @@ -530,7 +530,7 @@ fn light_peer_imports_header_from_announce() { #[test] fn can_sync_explicit_forks() { - let _ = ::env_logger::try_init(); + sp_tracing::try_init_simple(); let mut net = TestNet::new(2); net.peer(0).push_blocks(30, false); net.peer(1).push_blocks(30, false); @@ -584,7 +584,7 @@ fn can_sync_explicit_forks() { #[test] fn syncs_header_only_forks() { - let _ = env_logger::try_init(); + sp_tracing::try_init_simple(); let mut net = TestNet::new(0); net.add_full_peer_with_config(Default::default()); net.add_full_peer_with_config(FullPeerConfig { keep_blocks: Some(3), ..Default::default() }); @@ -602,7 +602,7 @@ fn syncs_header_only_forks() { #[test] fn does_not_sync_announced_old_best_block() { - let _ = ::env_logger::try_init(); + sp_tracing::try_init_simple(); let mut net = TestNet::new(3); let old_hash = net.peer(0).push_blocks(1, false); @@ -630,7 +630,7 @@ fn does_not_sync_announced_old_best_block() { #[test] fn full_sync_requires_block_body() { // Check that we don't sync headers-only in full mode. - let _ = ::env_logger::try_init(); + sp_tracing::try_init_simple(); let mut net = TestNet::new(2); net.peer(0).push_headers(1); @@ -649,7 +649,7 @@ fn full_sync_requires_block_body() { #[test] fn imports_stale_once() { - let _ = ::env_logger::try_init(); + sp_tracing::try_init_simple(); fn import_with_announce(net: &mut TestNet, hash: H256) { // Announce twice @@ -685,7 +685,7 @@ fn imports_stale_once() { #[test] fn can_sync_to_peers_with_wrong_common_block() { - let _ = env_logger::try_init(); + sp_tracing::try_init_simple(); let mut net = TestNet::new(2); net.peer(0).push_blocks(2, true); @@ -727,7 +727,7 @@ impl BlockAnnounceValidator for NewBestBlockAnnounceValidator { #[test] fn sync_blocks_when_block_announce_validator_says_it_is_new_best() { - let _ = env_logger::try_init(); + sp_tracing::try_init_simple(); log::trace!(target: "sync", "Test"); let mut net = TestNet::with_fork_choice(ForkChoiceStrategy::Custom(false)); net.add_full_peer_with_config(Default::default()); diff --git a/client/offchain/Cargo.toml b/client/offchain/Cargo.toml index 9f574ff9ebe46..2c5963e68d1a4 100644 --- a/client/offchain/Cargo.toml +++ b/client/offchain/Cargo.toml @@ -36,10 +36,10 @@ hyper = "0.13.2" hyper-rustls = "0.21.0" [dev-dependencies] -env_logger = "0.7.0" sc-client-db = { version = "0.8.0-rc6", default-features = true, path = "../db/" } sc-transaction-pool = { version = "2.0.0-rc6", path = "../../client/transaction-pool" } sp-transaction-pool = { version = "2.0.0-rc6", path = "../../primitives/transaction-pool" } +sp-tracing = { version = "2.0.0-rc6", path = "../../primitives/tracing" } substrate-test-runtime-client = { version = "2.0.0-rc6", path = "../../test-utils/runtime/client" } tokio = "0.2" lazy_static = "1.4.0" diff --git a/client/offchain/src/api.rs b/client/offchain/src/api.rs index a7ab07c549665..6fb1da19bf058 100644 --- a/client/offchain/src/api.rs +++ b/client/offchain/src/api.rs @@ -328,7 +328,7 @@ mod tests { } fn offchain_api() -> (Api, AsyncApi) { - let _ = env_logger::try_init(); + sp_tracing::try_init_simple(); let db = LocalStorage::new_test(); let mock = Arc::new(TestNetwork()); let shared_client = SharedClient::new(); diff --git a/client/offchain/src/lib.rs b/client/offchain/src/lib.rs index 89f2b7b8100b2..885294449fb95 100644 --- a/client/offchain/src/lib.rs +++ b/client/offchain/src/lib.rs @@ -281,7 +281,7 @@ mod tests { #[test] fn should_call_into_runtime_and_produce_extrinsic() { - let _ = env_logger::try_init(); + sp_tracing::try_init_simple(); let client = Arc::new(substrate_test_runtime_client::new()); let spawner = sp_core::testing::TaskExecutor::new(); diff --git a/client/service/Cargo.toml b/client/service/Cargo.toml index fc4d3298a41d5..370ee679154e3 100644 --- a/client/service/Cargo.toml +++ b/client/service/Cargo.toml @@ -68,7 +68,7 @@ sc-rpc-server = { version = "2.0.0-rc6", path = "../rpc-servers" } sc-rpc = { version = "2.0.0-rc6", path = "../rpc" } sc-block-builder = { version = "0.8.0-rc6", path = "../block-builder" } sp-block-builder = { version = "2.0.0-rc6", path = "../../primitives/block-builder" } -sc-informant = { version = "0.8.0-rc2", path = "../informant" } +sc-informant = { version = "0.8.0-rc6", path = "../informant" } sc-telemetry = { version = "2.0.0-rc6", path = "../telemetry" } sc-offchain = { version = "2.0.0-rc6", path = "../offchain" } prometheus-endpoint = { package = "substrate-prometheus-endpoint", path = "../../utils/prometheus", version = "0.8.0-rc6"} diff --git a/client/service/src/builder.rs b/client/service/src/builder.rs index 49f54365ddf37..25abfdffed845 100644 --- a/client/service/src/builder.rs +++ b/client/service/src/builder.rs @@ -36,7 +36,7 @@ use sp_consensus::{ use futures::{FutureExt, StreamExt, future::ready, channel::oneshot}; use jsonrpc_pubsub::manager::SubscriptionManager; use sc_keystore::Store as Keystore; -use log::{info, warn, error}; +use log::{info, warn}; use sc_network::config::{Role, FinalityProofProvider, OnDemand, BoxFinalityProofRequestBuilder}; use sc_network::NetworkService; use parking_lot::RwLock; @@ -572,17 +572,6 @@ pub fn spawn_tasks( )) }); - // Instrumentation - if let Some(tracing_targets) = config.tracing_targets.as_ref() { - let subscriber = sc_tracing::ProfilingSubscriber::new( - config.tracing_receiver, tracing_targets - ); - match tracing::subscriber::set_global_default(subscriber) { - Ok(_) => (), - Err(e) => error!(target: "tracing", "Unable to set global default subscriber {}", e), - } - } - // Spawn informant task spawn_handle.spawn("informant", sc_informant::build( client.clone(), diff --git a/client/service/test/Cargo.toml b/client/service/test/Cargo.toml index 03d5e264c85da..83dfa76b8999e 100644 --- a/client/service/test/Cargo.toml +++ b/client/service/test/Cargo.toml @@ -17,7 +17,6 @@ tempfile = "3.1.0" tokio = "0.1.22" futures01 = { package = "futures", version = "0.1.29" } log = "0.4.8" -env_logger = "0.7.0" fdlimit = "0.2.0" parking_lot = "0.10.0" sc-light = { version = "2.0.0-rc6", path = "../../light" } @@ -42,3 +41,4 @@ sc-block-builder = { version = "0.8.0-rc6", path = "../../block-builder" } sc-executor = { version = "0.8.0-rc6", path = "../../executor" } sp-panic-handler = { version = "2.0.0-rc6", path = "../../../primitives/panic-handler" } parity-scale-codec = "1.3.4" +sp-tracing = { version = "2.0.0-rc6", path = "../../../primitives/tracing" } diff --git a/client/service/test/src/client/mod.rs b/client/service/test/src/client/mod.rs index ea3eaa7ffbabf..34b063a3e3484 100644 --- a/client/service/test/src/client/mod.rs +++ b/client/service/test/src/client/mod.rs @@ -1206,7 +1206,7 @@ fn get_header_by_block_number_doesnt_panic() { #[test] fn state_reverted_on_reorg() { - let _ = env_logger::try_init(); + sp_tracing::try_init_simple(); let mut client = substrate_test_runtime_client::new(); let current_balance = |client: &substrate_test_runtime_client::TestClient| @@ -1266,7 +1266,7 @@ fn state_reverted_on_reorg() { #[test] fn doesnt_import_blocks_that_revert_finality() { - let _ = env_logger::try_init(); + sp_tracing::try_init_simple(); let tmp = tempfile::tempdir().unwrap(); // we need to run with archive pruning to avoid pruning non-canonical @@ -1467,7 +1467,7 @@ fn respects_block_rules() { #[test] fn returns_status_for_pruned_blocks() { - let _ = env_logger::try_init(); + sp_tracing::try_init_simple(); let tmp = tempfile::tempdir().unwrap(); // set to prune after 1 block @@ -1855,4 +1855,4 @@ fn reorg_triggers_a_notification_even_for_sources_that_should_not_trigger_notifi // We should have a tree route of the re-org let tree_route = notification.tree_route.unwrap(); assert_eq!(tree_route.enacted()[0].hash, b1.hash()); -} +} \ No newline at end of file diff --git a/client/service/test/src/lib.rs b/client/service/test/src/lib.rs index 0d589cee7e12d..cfe815f174fac 100644 --- a/client/service/test/src/lib.rs +++ b/client/service/test/src/lib.rs @@ -289,7 +289,7 @@ impl TestNet where )>, base_port: u16 ) -> TestNet { - let _ = env_logger::try_init(); + sp_tracing::try_init_simple(); fdlimit::raise_fd_limit(); let runtime = Runtime::new().expect("Error creating tokio runtime"); let mut net = TestNet { diff --git a/client/state-db/Cargo.toml b/client/state-db/Cargo.toml index f78e0ca505a61..7361ef0a8cb21 100644 --- a/client/state-db/Cargo.toml +++ b/client/state-db/Cargo.toml @@ -19,6 +19,3 @@ sp-core = { version = "2.0.0-rc6", path = "../../primitives/core" } codec = { package = "parity-scale-codec", version = "1.3.4", features = ["derive"] } parity-util-mem = { version = "0.7.0", default-features = false, features = ["primitive-types"] } parity-util-mem-derive = "0.1.0" - -[dev-dependencies] -env_logger = "0.7.0" diff --git a/client/tracing/Cargo.toml b/client/tracing/Cargo.toml index 40ab1bd460359..9444a9520f665 100644 --- a/client/tracing/Cargo.toml +++ b/client/tracing/Cargo.toml @@ -21,6 +21,5 @@ serde_json = "1.0.41" slog = { version = "2.5.2", features = ["nested-values"] } tracing = "0.1.18" tracing-subscriber = "0.2.10" -sp-tracing = { version = "2.0.0-rc2", path = "../../primitives/tracing" } - +sp-tracing = { version = "2.0.0-rc6", path = "../../primitives/tracing" } sc-telemetry = { version = "2.0.0-rc6", path = "../telemetry" } diff --git a/client/tracing/src/lib.rs b/client/tracing/src/lib.rs index f642b00720f1a..e509f2218a2ea 100644 --- a/client/tracing/src/lib.rs +++ b/client/tracing/src/lib.rs @@ -26,7 +26,6 @@ use rustc_hash::FxHashMap; use std::fmt; -use std::sync::atomic::{AtomicU64, Ordering}; use std::time::{Duration, Instant}; use parking_lot::Mutex; @@ -35,21 +34,18 @@ use tracing::{ event::Event, field::{Visit, Field}, Level, - metadata::Metadata, span::{Attributes, Id, Record}, subscriber::Subscriber, }; -use tracing_subscriber::CurrentSpan; +use tracing_subscriber::{CurrentSpan, layer::{Layer, Context}}; use sc_telemetry::{telemetry, SUBSTRATE_INFO}; use sp_tracing::proxy::{WASM_NAME_KEY, WASM_TARGET_KEY, WASM_TRACE_IDENTIFIER}; const ZERO_DURATION: Duration = Duration::from_nanos(0); -const PROXY_TARGET: &'static str = "sp_tracing::proxy"; /// Responsible for assigning ids to new spans, which are not re-used. -pub struct ProfilingSubscriber { - next_id: AtomicU64, +pub struct ProfilingLayer { targets: Vec<(String, Level)>, trace_handler: Box, span_data: Mutex>, @@ -216,12 +212,12 @@ impl slog::Value for Values { } } -impl ProfilingSubscriber { +impl ProfilingLayer { /// Takes a `TracingReceiver` and a comma separated list of targets, /// either with a level: "pallet=trace,frame=debug" /// or without: "pallet,frame" in which case the level defaults to `trace`. /// wasm_tracing indicates whether to enable wasm traces - pub fn new(receiver: TracingReceiver, targets: &str) -> ProfilingSubscriber { + pub fn new(receiver: TracingReceiver, targets: &str) -> Self { match receiver { TracingReceiver::Log => Self::new_with_handler(Box::new(LogTraceHandler), targets), TracingReceiver::Telemetry => Self::new_with_handler( @@ -237,11 +233,10 @@ impl ProfilingSubscriber { /// or without: "pallet" in which case the level defaults to `trace`. /// wasm_tracing indicates whether to enable wasm traces pub fn new_with_handler(trace_handler: Box, targets: &str) - -> ProfilingSubscriber + -> Self { let targets: Vec<_> = targets.split(',').map(|s| parse_target(s)).collect(); - ProfilingSubscriber { - next_id: AtomicU64::new(1), + Self { targets, trace_handler, span_data: Mutex::new(FxHashMap::default()), @@ -276,25 +271,14 @@ fn parse_target(s: &str) -> (String, Level) { } } -impl Subscriber for ProfilingSubscriber { - fn enabled(&self, metadata: &Metadata<'_>) -> bool { - if metadata.target() == PROXY_TARGET || self.check_target(metadata.target(), metadata.level()) { - log::debug!(target: "tracing", "Enabled target: {}, level: {}", metadata.target(), metadata.level()); - true - } else { - log::debug!(target: "tracing", "Disabled target: {}, level: {}", metadata.target(), metadata.level()); - false - } - } - - fn new_span(&self, attrs: &Attributes<'_>) -> Id { - let id = Id::from_u64(self.next_id.fetch_add(1, Ordering::Relaxed)); +impl Layer for ProfilingLayer { + fn new_span(&self, attrs: &Attributes<'_>, id: &Id, _ctx: Context) { let mut values = Values::default(); attrs.record(&mut values); // If this is a wasm trace, check if target/level is enabled if let Some(wasm_target) = values.string_values.get(WASM_TARGET_KEY) { if !self.check_target(wasm_target, attrs.metadata().level()) { - return id + return } } let span_datum = SpanDatum { @@ -309,19 +293,16 @@ impl Subscriber for ProfilingSubscriber { values, }; self.span_data.lock().insert(id.clone(), span_datum); - id } - fn record(&self, span: &Id, values: &Record<'_>) { + fn on_record(&self, span: &Id, values: &Record<'_>, _ctx: Context) { let mut span_data = self.span_data.lock(); if let Some(s) = span_data.get_mut(span) { values.record(&mut s.values); } } - fn record_follows_from(&self, _span: &Id, _follows: &Id) {} - - fn event(&self, event: &Event<'_>) { + fn on_event(&self, event: &Event<'_>, _ctx: Context) { let mut values = Values::default(); event.record(&mut values); let trace_event = TraceEvent { @@ -334,7 +315,7 @@ impl Subscriber for ProfilingSubscriber { self.trace_handler.handle_event(trace_event); } - fn enter(&self, span: &Id) { + fn on_enter(&self, span: &Id, _ctx: Context) { self.current_span.enter(span.clone()); let mut span_data = self.span_data.lock(); let start_time = Instant::now(); @@ -343,7 +324,7 @@ impl Subscriber for ProfilingSubscriber { } } - fn exit(&self, span: &Id) { + fn on_exit(&self, span: &Id, _ctx: Context) { self.current_span.exit(); let end_time = Instant::now(); let mut span_data = self.span_data.lock(); @@ -352,7 +333,7 @@ impl Subscriber for ProfilingSubscriber { } } - fn try_close(&self, span: Id) -> bool { + fn on_close(&self, span: Id, _ctx: Context) { let span_datum = { let mut span_data = self.span_data.lock(); span_data.remove(&span) @@ -373,7 +354,6 @@ impl Subscriber for ProfilingSubscriber { self.trace_handler.handle_span(span_datum); } }; - true } } @@ -458,6 +438,7 @@ impl TraceHandler for TelemetryTraceHandler { mod tests { use super::*; use std::sync::Arc; + use tracing_subscriber::layer::SubscriberExt; struct TestTraceHandler { spans: Arc>>, @@ -474,18 +455,24 @@ mod tests { } } - fn setup_subscriber() -> (ProfilingSubscriber, Arc>>, Arc>>) { + type TestSubscriber = tracing_subscriber::layer::Layered< + ProfilingLayer, + tracing_subscriber::fmt::Subscriber + >; + + fn setup_subscriber() -> (TestSubscriber, Arc>>, Arc>>) { let spans = Arc::new(Mutex::new(Vec::new())); let events = Arc::new(Mutex::new(Vec::new())); let handler = TestTraceHandler { spans: spans.clone(), events: events.clone(), }; - let test_subscriber = ProfilingSubscriber::new_with_handler( + let layer = ProfilingLayer::new_with_handler( Box::new(handler), "test_target" ); - (test_subscriber, spans, events) + let subscriber = tracing_subscriber::fmt().finish().with(layer); + (subscriber, spans, events) } #[test] diff --git a/frame/elections-phragmen/src/lib.rs b/frame/elections-phragmen/src/lib.rs index 93b11e8d95c57..372ae11b148ff 100644 --- a/frame/elections-phragmen/src/lib.rs +++ b/frame/elections-phragmen/src/lib.rs @@ -1398,7 +1398,7 @@ mod tests { assert!( Elections::members().iter().chain( Elections::runners_up().iter() - ).all(|(_, s)| *s != Zero::zero()) + ).all(|(_, s)| *s != u64::zero()) ); } @@ -1453,15 +1453,15 @@ mod tests { assert_eq!(Elections::term_duration(), 5); assert_eq!(Elections::election_rounds(), 0); - assert_eq!(Elections::members(), vec![]); - assert_eq!(Elections::runners_up(), vec![]); + assert!(Elections::members().is_empty()); + assert!(Elections::runners_up().is_empty()); - assert_eq!(Elections::candidates(), vec![]); + assert!(Elections::candidates().is_empty()); assert_eq!(>::decode_len(), None); assert!(Elections::is_candidate(&1).is_err()); - assert_eq!(all_voters(), vec![]); - assert_eq!(votes_of(&1), vec![]); + assert!(all_voters().is_empty()); + assert!(votes_of(&1).is_empty()); }); } @@ -1536,16 +1536,16 @@ mod tests { assert_eq!(Elections::desired_members(), 2); assert_eq!(Elections::election_rounds(), 0); - assert_eq!(Elections::members_ids(), vec![]); - assert_eq!(Elections::runners_up(), vec![]); - assert_eq!(Elections::candidates(), vec![]); + assert!(Elections::members_ids().is_empty()); + assert!(Elections::runners_up().is_empty()); + assert!(Elections::candidates().is_empty()); System::set_block_number(5); Elections::end_block(System::block_number()); - assert_eq!(Elections::members_ids(), vec![]); - assert_eq!(Elections::runners_up(), vec![]); - assert_eq!(Elections::candidates(), vec![]); + assert!(Elections::members_ids().is_empty()); + assert!(Elections::runners_up().is_empty()); + assert!(Elections::candidates().is_empty()); }); } @@ -1588,18 +1588,18 @@ mod tests { assert!(Elections::is_candidate(&2).is_ok()); assert_eq!(Elections::candidates(), vec![1, 2]); - assert_eq!(Elections::members_ids(), vec![]); - assert_eq!(Elections::runners_up(), vec![]); + assert!(Elections::members_ids().is_empty()); + assert!(Elections::runners_up().is_empty()); System::set_block_number(5); Elections::end_block(System::block_number()); assert!(Elections::is_candidate(&1).is_err()); assert!(Elections::is_candidate(&2).is_err()); - assert_eq!(Elections::candidates(), vec![]); + assert!(Elections::candidates().is_empty()); - assert_eq!(Elections::members_ids(), vec![]); - assert_eq!(Elections::runners_up(), vec![]); + assert!(Elections::members_ids().is_empty()); + assert!(Elections::runners_up().is_empty()); }); } @@ -1627,8 +1627,8 @@ mod tests { Elections::end_block(System::block_number()); assert_eq!(Elections::members_ids(), vec![5]); - assert_eq!(Elections::runners_up(), vec![]); - assert_eq!(Elections::candidates(), vec![]); + assert!(Elections::runners_up().is_empty()); + assert!(Elections::candidates().is_empty()); assert_noop!( submit_candidacy(Origin::signed(5)), @@ -1742,7 +1742,7 @@ mod tests { Elections::end_block(System::block_number()); assert_eq!(Elections::members_ids(), vec![4, 5]); - assert_eq!(Elections::candidates(), vec![]); + assert!(Elections::candidates().is_empty()); assert_ok!(vote(Origin::signed(3), vec![4, 5], 10)); }); @@ -1765,7 +1765,7 @@ mod tests { Elections::end_block(System::block_number()); assert_eq!(Elections::members_ids(), vec![4, 5]); - assert_eq!(Elections::candidates(), vec![]); + assert!(Elections::candidates().is_empty()); assert_ok!(vote(Origin::signed(3), vec![4, 5], 10)); assert_eq!(PRIME.with(|p| *p.borrow()), Some(4)); @@ -1791,7 +1791,7 @@ mod tests { Elections::end_block(System::block_number()); assert_eq!(Elections::members_ids(), vec![3, 5]); - assert_eq!(Elections::candidates(), vec![]); + assert!(Elections::candidates().is_empty()); assert_eq!(PRIME.with(|p| *p.borrow()), Some(5)); }); @@ -1876,7 +1876,7 @@ mod tests { assert_ok!(Elections::remove_voter(Origin::signed(2))); assert_eq_uvec!(all_voters(), vec![3]); - assert_eq!(votes_of(&2), vec![]); + assert!(votes_of(&2).is_empty()); assert_eq!(Elections::locked_stake_of(&2), 0); assert_eq!(balances(&2), (20, 0)); @@ -1898,7 +1898,7 @@ mod tests { assert_ok!(vote(Origin::signed(2), vec![5], 20)); assert_ok!(Elections::remove_voter(Origin::signed(2))); - assert_eq!(all_voters(), vec![]); + assert!(all_voters().is_empty()); assert_noop!(Elections::remove_voter(Origin::signed(2)), Error::::MustBeVoter); }); @@ -2008,7 +2008,7 @@ mod tests { assert_eq!(Elections::members_ids(), vec![4, 5]); assert_eq!(Elections::runners_up_ids(), vec![6]); - assert_eq!(Elections::candidates(), vec![]); + assert!(Elections::candidates().is_empty()); // all of them have a member or runner-up that they voted for. assert_eq!(Elections::is_defunct_voter(&votes_of(&5)), false); @@ -2044,7 +2044,7 @@ mod tests { Elections::end_block(System::block_number()); assert_eq!(Elections::members_ids(), vec![4, 5]); - assert_eq!(Elections::candidates(), vec![]); + assert!(Elections::candidates().is_empty()); assert_eq!(balances(&3), (28, 2)); assert_eq!(balances(&5), (45, 5)); @@ -2072,7 +2072,7 @@ mod tests { Elections::end_block(System::block_number()); assert_eq!(Elections::members_ids(), vec![4, 5]); - assert_eq!(Elections::candidates(), vec![]); + assert!(Elections::candidates().is_empty()); assert_eq!(balances(&4), (35, 5)); assert_eq!(balances(&5), (45, 5)); @@ -2113,9 +2113,9 @@ mod tests { Elections::end_block(System::block_number()); assert_eq!(Elections::members(), vec![(3, 30), (5, 20)]); - assert_eq!(Elections::runners_up(), vec![]); + assert!(Elections::runners_up().is_empty()); assert_eq_uvec!(all_voters(), vec![2, 3, 4]); - assert_eq!(Elections::candidates(), vec![]); + assert!(Elections::candidates().is_empty()); assert_eq!(>::decode_len(), None); assert_eq!(Elections::election_rounds(), 1); @@ -2180,9 +2180,9 @@ mod tests { System::set_block_number(5); Elections::end_block(System::block_number()); - assert_eq!(Elections::candidates(), vec![]); + assert!(Elections::candidates().is_empty()); assert_eq!(Elections::election_rounds(), 1); - assert_eq!(Elections::members_ids(), vec![]); + assert!(Elections::members_ids().is_empty()); assert_eq!( System::events().iter().last().unwrap().event, @@ -2293,7 +2293,7 @@ mod tests { System::set_block_number(10); Elections::end_block(System::block_number()); - assert_eq!(Elections::members_ids(), vec![]); + assert!(Elections::members_ids().is_empty()); assert_eq!(balances(&5), (47, 0)); }); @@ -2378,7 +2378,7 @@ mod tests { assert_eq!(Elections::members(), vec![(4, 40), (5, 50)]); assert_eq!(Elections::runners_up(), vec![(2, 20), (3, 30)]); // no new candidates but old members and runners-up are always added. - assert_eq!(Elections::candidates(), vec![]); + assert!(Elections::candidates().is_empty()); assert_eq!(Elections::election_rounds(), b / 5); assert_eq_uvec!(all_voters(), vec![2, 3, 4, 5]); }; @@ -2490,7 +2490,7 @@ mod tests { // meanwhile, no one cares to become a candidate again. System::set_block_number(10); Elections::end_block(System::block_number()); - assert_eq!(Elections::members_ids(), vec![]); + assert!(Elections::members_ids().is_empty()); assert_eq!(Elections::election_rounds(), 2); }); } @@ -2658,14 +2658,14 @@ mod tests { Elections::end_block(System::block_number()); assert_eq!(Elections::members_ids(), vec![4, 5]); - assert_eq!(Elections::runners_up_ids(), vec![]); + assert!(Elections::runners_up_ids().is_empty()); assert_ok!(Elections::renounce_candidacy(Origin::signed(4), Renouncing::Member)); assert_eq!(balances(&4), (38, 2)); // 2 is voting bond. // no replacement assert_eq!(Elections::members_ids(), vec![5]); - assert_eq!(Elections::runners_up_ids(), vec![]); + assert!(Elections::runners_up_ids().is_empty()); }) } @@ -2729,7 +2729,7 @@ mod tests { assert_ok!(Elections::renounce_candidacy(Origin::signed(5), Renouncing::Candidate(1))); assert_eq!(balances(&5), (50, 0)); - assert_eq!(Elections::candidates(), vec![]); + assert!(Elections::candidates().is_empty()); }) } @@ -2841,7 +2841,7 @@ mod tests { assert_eq!(Elections::members_ids(), vec![1, 4]); assert_eq!(Elections::runners_up_ids(), vec![2, 3]); - assert_eq!(Elections::candidates(), vec![]); + assert!(Elections::candidates().is_empty()); }) } } diff --git a/frame/elections/src/tests.rs b/frame/elections/src/tests.rs index 247b6272524b1..92f6e11252b05 100644 --- a/frame/elections/src/tests.rs +++ b/frame/elections/src/tests.rs @@ -46,14 +46,14 @@ fn params_should_work() { assert_eq!(Elections::voters(0), Vec::>::new()); assert_eq!(Elections::voter_info(1), None); - assert_eq!(Elections::all_approvals_of(&1), vec![]); + assert!(Elections::all_approvals_of(&1).is_empty()); }); } #[test] fn chunking_bool_to_flag_should_work() { ExtBuilder::default().build().execute_with(|| { - assert_eq!(Elections::bool_to_flag(vec![]), vec![]); + assert!(Elections::bool_to_flag(vec![]).is_empty()); assert_eq!(Elections::bool_to_flag(vec![false]), vec![0]); assert_eq!(Elections::bool_to_flag(vec![true]), vec![1]); assert_eq!(Elections::bool_to_flag(vec![true, true, true, true]), vec![15]); @@ -274,11 +274,11 @@ fn chunking_approval_storage_should_work() { assert_eq!(Elections::all_approvals_of(&2), vec![true]); // NOTE: these two are stored in mem differently though. - assert_eq!(Elections::all_approvals_of(&3), vec![]); - assert_eq!(Elections::all_approvals_of(&4), vec![]); + assert!(Elections::all_approvals_of(&3).is_empty()); + assert!(Elections::all_approvals_of(&4).is_empty()); assert_eq!(Elections::approvals_of((3, 0)), vec![0]); - assert_eq!(Elections::approvals_of((4, 0)), vec![]); + assert!(Elections::approvals_of((4, 0)).is_empty()); }); } @@ -385,7 +385,7 @@ fn voting_locking_stake_and_reserving_bond_works() { assert_ok!(Elections::submit_candidacy(Origin::signed(5), 0)); assert_eq!(balances(&2), (20, 0)); - assert_eq!(locks(&2), vec![]); + assert!(locks(&2).is_empty()); assert_ok!(Elections::set_approvals(Origin::signed(2), vec![], 0, 0, 15)); assert_eq!(balances(&2), (18, 2)); assert_eq!(locks(&2), vec![15]); @@ -401,7 +401,7 @@ fn voting_locking_stake_and_reserving_bond_works() { assert_ok!(Elections::retract_voter(Origin::signed(2), 0)); assert_eq!(balances(&2), (102, 0)); - assert_eq!(locks(&2), vec![]); + assert!(locks(&2).is_empty()); }); } diff --git a/frame/example/src/lib.rs b/frame/example/src/lib.rs index e2b00daf31cd7..0585307061bcd 100644 --- a/frame/example/src/lib.rs +++ b/frame/example/src/lib.rs @@ -843,7 +843,7 @@ mod tests { WatchDummy::(PhantomData).validate(&1, &call, &info, 150) .unwrap() .priority, - Bounded::max_value(), + u64::max_value(), ); assert_eq!( WatchDummy::(PhantomData).validate(&1, &call, &info, 250), diff --git a/frame/scored-pool/src/tests.rs b/frame/scored-pool/src/tests.rs index 9c0074ff6e689..44b71bc00ba47 100644 --- a/frame/scored-pool/src/tests.rs +++ b/frame/scored-pool/src/tests.rs @@ -153,7 +153,7 @@ fn unscored_entities_must_not_be_used_for_filling_members() { // then // the `None` candidates should not have been filled in - assert_eq!(ScoredPool::members(), vec![]); + assert!(ScoredPool::members().is_empty()); assert_eq!(MEMBERS.with(|m| m.borrow().clone()), ScoredPool::members()); }); } diff --git a/frame/staking/Cargo.toml b/frame/staking/Cargo.toml index 2d1487afb03df..bd64dbcb1d3e0 100644 --- a/frame/staking/Cargo.toml +++ b/frame/staking/Cargo.toml @@ -33,6 +33,7 @@ rand_chacha = { version = "0.2", default-features = false, optional = true } [dev-dependencies] sp-core = { version = "2.0.0-rc6", path = "../../primitives/core" } sp-storage = { version = "2.0.0-rc6", path = "../../primitives/storage" } +sp-tracing = { version = "2.0.0-rc6", path = "../../primitives/tracing" } pallet-balances = { version = "2.0.0-rc6", path = "../balances" } pallet-timestamp = { version = "2.0.0-rc6", path = "../timestamp" } pallet-staking-reward-curve = { version = "2.0.0-rc6", path = "../staking/reward-curve" } @@ -40,7 +41,6 @@ substrate-test-utils = { version = "2.0.0-rc6", path = "../../test-utils" } frame-benchmarking = { version = "2.0.0-rc6", path = "../benchmarking" } rand_chacha = { version = "0.2" } parking_lot = "0.10.2" -env_logger = "0.7.1" hex = "0.4" [features] diff --git a/frame/staking/src/mock.rs b/frame/staking/src/mock.rs index 31e41e21360a0..805df5d56f38e 100644 --- a/frame/staking/src/mock.rs +++ b/frame/staking/src/mock.rs @@ -452,7 +452,7 @@ impl ExtBuilder { MAX_ITERATIONS.with(|v| *v.borrow_mut() = self.max_offchain_iterations); } pub fn build(self) -> sp_io::TestExternalities { - let _ = env_logger::try_init(); + sp_tracing::try_init_simple(); self.set_associated_constants(); let mut storage = frame_system::GenesisConfig::default() .build_storage::() diff --git a/frame/staking/src/tests.rs b/frame/staking/src/tests.rs index 0f5d08a3a8ccc..3feebfbc8ace9 100644 --- a/frame/staking/src/tests.rs +++ b/frame/staking/src/tests.rs @@ -1734,7 +1734,7 @@ fn bond_with_duplicate_vote_should_be_ignored_by_npos_election() { .collect::>(), vec![(31, 1000), (21, 1000), (11, 1000)], ); - assert_eq!(>::iter().map(|(n, _)| n).collect::>(), vec![]); + assert!(>::iter().map(|(n, _)| n).collect::>().is_empty()); // give the man some money let initial_balance = 1000; @@ -1782,7 +1782,7 @@ fn bond_with_duplicate_vote_should_be_ignored_by_npos_election_elected() { .collect::>(), vec![(31, 100), (21, 1000), (11, 1000)], ); - assert_eq!(>::iter().map(|(n, _)| n).collect::>(), vec![]); + assert!(>::iter().map(|(n, _)| n).collect::>().is_empty()); // give the man some money let initial_balance = 1000; diff --git a/frame/sudo/src/tests.rs b/frame/sudo/src/tests.rs index 79424d2824f90..cba1e1cf60540 100644 --- a/frame/sudo/src/tests.rs +++ b/frame/sudo/src/tests.rs @@ -18,9 +18,9 @@ //! Tests for the module. use super::*; -use mock::{ +use mock::{ Sudo, SudoCall, Origin, Call, Test, new_test_ext, LoggerCall, Logger, System, TestEvent, -}; +}; use frame_support::{assert_ok, assert_noop}; #[test] @@ -28,8 +28,8 @@ fn test_setup_works() { // Environment setup, logger storage, and sudo `key` retrieval should work as expected. new_test_ext(1).execute_with(|| { assert_eq!(Sudo::key(), 1u64); - assert_eq!(Logger::i32_log(), vec![]); - assert_eq!(Logger::account_log(), vec![]); + assert!(Logger::i32_log().is_empty()); + assert!(Logger::account_log().is_empty()); }); } @@ -40,8 +40,8 @@ fn sudo_basics() { // A privileged function should work when `sudo` is passed the root `key` as `origin`. let call = Box::new(Call::Logger(LoggerCall::privileged_i32_log(42, 1_000))); assert_ok!(Sudo::sudo(Origin::signed(1), call)); - assert_eq!(Logger::i32_log(), vec![42i32]); - + assert_eq!(Logger::i32_log(), vec![42i32]); + // A privileged function should not work when `sudo` is passed a non-root `key` as `origin`. let call = Box::new(Call::Logger(LoggerCall::privileged_i32_log(42, 1_000))); assert_noop!(Sudo::sudo(Origin::signed(2), call), Error::::RequireSudo); @@ -58,7 +58,7 @@ fn sudo_emits_events_correctly() { let call = Box::new(Call::Logger(LoggerCall::privileged_i32_log(42, 1))); assert_ok!(Sudo::sudo(Origin::signed(1), call)); let expected_event = TestEvent::sudo(RawEvent::Sudid(Ok(()))); - assert!(System::events().iter().any(|a| a.event == expected_event)); + assert!(System::events().iter().any(|a| a.event == expected_event)); }) } @@ -68,16 +68,16 @@ fn sudo_unchecked_weight_basics() { // A privileged function should work when `sudo` is passed the root `key` as origin. let call = Box::new(Call::Logger(LoggerCall::privileged_i32_log(42, 1_000))); assert_ok!(Sudo::sudo_unchecked_weight(Origin::signed(1), call, 1_000)); - assert_eq!(Logger::i32_log(), vec![42i32]); + assert_eq!(Logger::i32_log(), vec![42i32]); // A privileged function should not work when called with a non-root `key`. let call = Box::new(Call::Logger(LoggerCall::privileged_i32_log(42, 1_000))); assert_noop!( - Sudo::sudo_unchecked_weight(Origin::signed(2), call, 1_000), + Sudo::sudo_unchecked_weight(Origin::signed(2), call, 1_000), Error::::RequireSudo, ); // `I32Log` is unchanged after unsuccessful call. - assert_eq!(Logger::i32_log(), vec![42i32]); + assert_eq!(Logger::i32_log(), vec![42i32]); // Controls the dispatched weight. let call = Box::new(Call::Logger(LoggerCall::privileged_i32_log(42, 1))); @@ -103,7 +103,7 @@ fn sudo_unchecked_weight_emits_events_correctly() { #[test] fn set_key_basics() { - new_test_ext(1).execute_with(|| { + new_test_ext(1).execute_with(|| { // A root `key` can change the root `key` assert_ok!(Sudo::set_key(Origin::signed(1), 2)); assert_eq!(Sudo::key(), 2u64); @@ -117,7 +117,7 @@ fn set_key_basics() { #[test] fn set_key_emits_events_correctly() { - new_test_ext(1).execute_with(|| { + new_test_ext(1).execute_with(|| { // Set block number to 1 because events are not emitted on block 0. System::set_block_number(1); @@ -138,8 +138,8 @@ fn sudo_as_basics() { // A privileged function will not work when passed to `sudo_as`. let call = Box::new(Call::Logger(LoggerCall::privileged_i32_log(42, 1_000))); assert_ok!(Sudo::sudo_as(Origin::signed(1), 2, call)); - assert_eq!(Logger::i32_log(), vec![]); - assert_eq!(Logger::account_log(), vec![]); + assert!(Logger::i32_log().is_empty()); + assert!(Logger::account_log().is_empty()); // A non-privileged function should not work when called with a non-root `key`. let call = Box::new(Call::Logger(LoggerCall::non_privileged_log(42, 1))); @@ -156,7 +156,7 @@ fn sudo_as_basics() { #[test] fn sudo_as_emits_events_correctly() { - new_test_ext(1).execute_with(|| { + new_test_ext(1).execute_with(|| { // Set block number to 1 because events are not emitted on block 0. System::set_block_number(1); diff --git a/frame/support/src/storage/mod.rs b/frame/support/src/storage/mod.rs index 717a9a29ad5f5..5ee144c79c4db 100644 --- a/frame/support/src/storage/mod.rs +++ b/frame/support/src/storage/mod.rs @@ -656,7 +656,7 @@ mod test { assert_eq!(MyStorage::final_prefix().to_vec(), k); // test iteration - assert_eq!(MyStorage::iter_values().collect::>(), vec![]); + assert!(MyStorage::iter_values().collect::>().is_empty()); unhashed::put(&[&k[..], &vec![1][..]].concat(), &1u64); unhashed::put(&[&k[..], &vec![1, 1][..]].concat(), &2u64); @@ -667,13 +667,13 @@ mod test { // test removal MyStorage::remove_all(); - assert_eq!(MyStorage::iter_values().collect::>(), vec![]); + assert!(MyStorage::iter_values().collect::>().is_empty()); // test migration unhashed::put(&[&k[..], &vec![1][..]].concat(), &1u32); unhashed::put(&[&k[..], &vec![8][..]].concat(), &2u32); - assert_eq!(MyStorage::iter_values().collect::>(), vec![]); + assert!(MyStorage::iter_values().collect::>().is_empty()); MyStorage::translate_values(|v: u32| Some(v as u64)); assert_eq!(MyStorage::iter_values().collect::>(), vec![1, 2]); MyStorage::remove_all(); diff --git a/frame/support/test/tests/decl_storage.rs b/frame/support/test/tests/decl_storage.rs index 9bdc4226263df..800ce459fed35 100644 --- a/frame/support/test/tests/decl_storage.rs +++ b/frame/support/test/tests/decl_storage.rs @@ -520,7 +520,7 @@ mod test_append_and_len { fn default_for_option() { TestExternalities::default().execute_with(|| { assert_eq!(OptionVec::get(), None); - assert_eq!(JustVec::get(), vec![]); + assert!(JustVec::get().is_empty()); }); } @@ -553,7 +553,7 @@ mod test_append_and_len { let key = JustVec::hashed_key(); // Set it to some invalid value. frame_support::storage::unhashed::put_raw(&key, &*b"1"); - assert_eq!(JustVec::get(), Vec::new()); + assert!(JustVec::get().is_empty()); assert_eq!(frame_support::storage::unhashed::get_raw(&key), Some(b"1".to_vec())); JustVec::append(1); @@ -600,7 +600,7 @@ mod test_append_and_len { fn len_works_ignores_default_assignment() { TestExternalities::default().execute_with(|| { // vec - assert_eq!(JustVec::get(), vec![]); + assert!(JustVec::get().is_empty()); assert_eq!(JustVec::decode_len(), None); assert_eq!(JustVecWithDefault::get(), vec![6, 9]); @@ -610,7 +610,7 @@ mod test_append_and_len { assert_eq!(OptionVec::decode_len(), None); // map - assert_eq!(MapVec::get(0), vec![]); + assert!(MapVec::get(0).is_empty()); assert_eq!(MapVec::decode_len(0), None); assert_eq!(MapVecWithDefault::get(0), vec![6, 9]); @@ -620,7 +620,7 @@ mod test_append_and_len { assert_eq!(OptionMapVec::decode_len(0), None); // Double map - assert_eq!(DoubleMapVec::get(0, 0), vec![]); + assert!(DoubleMapVec::get(0, 0).is_empty()); assert_eq!(DoubleMapVec::decode_len(0, 1), None); assert_eq!(DoubleMapVecWithDefault::get(0, 0), vec![6, 9]); diff --git a/primitives/consensus/slots/Cargo.toml b/primitives/consensus/slots/Cargo.toml index ada913b645c7b..fecd3e03d781b 100644 --- a/primitives/consensus/slots/Cargo.toml +++ b/primitives/consensus/slots/Cargo.toml @@ -13,7 +13,7 @@ targets = ["x86_64-unknown-linux-gnu"] [dependencies] codec = { package = "parity-scale-codec", version = "1.3.0", default-features = false, features = ["derive"] } -sp-runtime = { version = "2.0.0-rc2", default-features = false, path = "../../runtime" } +sp-runtime = { version = "2.0.0-rc6", default-features = false, path = "../../runtime" } [features] default = ["std"] diff --git a/primitives/tracing/Cargo.toml b/primitives/tracing/Cargo.toml index 136039475673a..889d116221b5f 100644 --- a/primitives/tracing/Cargo.toml +++ b/primitives/tracing/Cargo.toml @@ -15,7 +15,8 @@ targets = ["x86_64-unknown-linux-gnu"] tracing = { version = "0.1.18", optional = true } rental = { version = "0.5.5", optional = true } log = { version = "0.4.8", optional = true } +tracing-subscriber = { version = "0.2.10", optional = true, features = ["tracing-log"] } [features] default = [ "std" ] -std = [ "tracing", "rental", "log" ] +std = [ "tracing", "rental", "log", "tracing-subscriber" ] diff --git a/primitives/tracing/src/lib.rs b/primitives/tracing/src/lib.rs index e82d8861cd3f5..ec692b90dfdec 100644 --- a/primitives/tracing/src/lib.rs +++ b/primitives/tracing/src/lib.rs @@ -44,6 +44,13 @@ pub mod proxy; #[cfg(feature = "std")] use std::sync::atomic::{AtomicBool, Ordering}; +/// Try to init a simple tracing subscriber with log compatibility layer. +/// Ignores any error. Useful for testing. +#[cfg(feature = "std")] +pub fn try_init_simple() { + let _ = tracing_subscriber::fmt().with_writer(std::io::stderr).try_init(); +} + /// Flag to signal whether to run wasm tracing #[cfg(feature = "std")] static WASM_TRACING_ENABLED: AtomicBool = AtomicBool::new(false); @@ -114,4 +121,4 @@ pub fn wasm_tracing_enabled() -> bool { #[cfg(feature = "std")] pub fn set_wasm_tracing(b: bool) { WASM_TRACING_ENABLED.store(b, Ordering::Relaxed) -} \ No newline at end of file +} diff --git a/utils/frame/rpc/system/Cargo.toml b/utils/frame/rpc/system/Cargo.toml index 0f1e27efc7037..fc4774738b811 100644 --- a/utils/frame/rpc/system/Cargo.toml +++ b/utils/frame/rpc/system/Cargo.toml @@ -31,5 +31,5 @@ sc-rpc-api = { version = "0.8.0-rc6", path = "../../../../client/rpc-api" } [dev-dependencies] substrate-test-runtime-client = { version = "2.0.0-rc6", path = "../../../../test-utils/runtime/client" } -env_logger = "0.7.0" +sp-tracing = { version = "2.0.0-rc6", path = "../../../../primitives/tracing" } sc-transaction-pool = { version = "2.0.0-rc6", path = "../../../../client/transaction-pool" } diff --git a/utils/frame/rpc/system/src/lib.rs b/utils/frame/rpc/system/src/lib.rs index 2bb46369fea54..cefe39534a167 100644 --- a/utils/frame/rpc/system/src/lib.rs +++ b/utils/frame/rpc/system/src/lib.rs @@ -294,7 +294,7 @@ mod tests { #[test] fn should_return_next_nonce_for_some_account() { - let _ = env_logger::try_init(); + sp_tracing::try_init_simple(); // given let client = Arc::new(substrate_test_runtime_client::new()); @@ -333,7 +333,7 @@ mod tests { #[test] fn dry_run_should_deny_unsafe() { - let _ = env_logger::try_init(); + sp_tracing::try_init_simple(); // given let client = Arc::new(substrate_test_runtime_client::new()); @@ -356,7 +356,7 @@ mod tests { #[test] fn dry_run_should_work() { - let _ = env_logger::try_init(); + sp_tracing::try_init_simple(); // given let client = Arc::new(substrate_test_runtime_client::new()); @@ -388,7 +388,7 @@ mod tests { #[test] fn dry_run_should_indicate_error() { - let _ = env_logger::try_init(); + sp_tracing::try_init_simple(); // given let client = Arc::new(substrate_test_runtime_client::new());