diff --git a/Cargo.lock b/Cargo.lock index 1c2a9608f24967544450c6f411e0fa1d5b0ce3f3..a2c0c6904c55359b2556986daab42c1064a443f3 100644 --- a/Cargo.lock +++ b/Cargo.lock @@ -1974,6 +1974,9 @@ source = "registry+https://github.com/rust-lang/crates.io-index" name = "lazy_static" version = "1.4.0" source = "registry+https://github.com/rust-lang/crates.io-index" +dependencies = [ + "spin 0.5.2 (registry+https://github.com/rust-lang/crates.io-index)", +] [[package]] name = "lazycell" @@ -3148,6 +3151,7 @@ dependencies = [ "substrate-inherents 2.0.0", "substrate-primitives 2.0.0", "substrate-state-machine 2.0.0", + "tracing 0.1.10 (registry+https://github.com/rust-lang/crates.io-index)", ] [[package]] @@ -5447,6 +5451,7 @@ dependencies = [ "substrate-service 2.0.0", "substrate-state-machine 2.0.0", "substrate-telemetry 2.0.0", + "substrate-tracing 2.0.0", "tempdir 0.3.7 (registry+https://github.com/rust-lang/crates.io-index)", "time 0.1.42 (registry+https://github.com/rust-lang/crates.io-index)", "tokio 0.1.22 (registry+https://github.com/rust-lang/crates.io-index)", @@ -6257,6 +6262,7 @@ dependencies = [ "substrate-session 2.0.0", "substrate-telemetry 2.0.0", "substrate-test-runtime-client 2.0.0", + "substrate-tracing 2.0.0", "substrate-transaction-pool 2.0.0", "substrate-transaction-pool-runtime-api 2.0.0", "sysinfo 0.9.6 (registry+https://github.com/rust-lang/crates.io-index)", @@ -6264,6 +6270,7 @@ dependencies = [ "tokio 0.1.22 (registry+https://github.com/rust-lang/crates.io-index)", "tokio-executor 0.1.8 (registry+https://github.com/rust-lang/crates.io-index)", "tokio-timer 0.2.11 (registry+https://github.com/rust-lang/crates.io-index)", + "tracing 0.1.10 (registry+https://github.com/rust-lang/crates.io-index)", ] [[package]] @@ -6428,6 +6435,17 @@ dependencies = [ "substrate-test-runtime 2.0.0", ] +[[package]] +name = "substrate-tracing" +version = "2.0.0" +dependencies = [ + "log 0.4.8 (registry+https://github.com/rust-lang/crates.io-index)", + "parking_lot 0.9.0 (registry+https://github.com/rust-lang/crates.io-index)", + "substrate-telemetry 2.0.0", + "tracing 0.1.10 (registry+https://github.com/rust-lang/crates.io-index)", + "tracing-core 0.1.7 (registry+https://github.com/rust-lang/crates.io-index)", +] + [[package]] name = "substrate-transaction-graph" version = "2.0.0" @@ -6938,6 +6956,35 @@ dependencies = [ "serde 1.0.102 (registry+https://github.com/rust-lang/crates.io-index)", ] +[[package]] +name = "tracing" +version = "0.1.10" +source = "registry+https://github.com/rust-lang/crates.io-index" +dependencies = [ + "cfg-if 0.1.10 (registry+https://github.com/rust-lang/crates.io-index)", + "spin 0.5.2 (registry+https://github.com/rust-lang/crates.io-index)", + "tracing-attributes 0.1.5 (registry+https://github.com/rust-lang/crates.io-index)", + "tracing-core 0.1.7 (registry+https://github.com/rust-lang/crates.io-index)", +] + +[[package]] +name = "tracing-attributes" +version = "0.1.5" +source = "registry+https://github.com/rust-lang/crates.io-index" +dependencies = [ + "quote 1.0.2 (registry+https://github.com/rust-lang/crates.io-index)", + "syn 1.0.8 (registry+https://github.com/rust-lang/crates.io-index)", +] + +[[package]] +name = "tracing-core" +version = "0.1.7" +source = "registry+https://github.com/rust-lang/crates.io-index" +dependencies = [ + "lazy_static 1.4.0 (registry+https://github.com/rust-lang/crates.io-index)", + "spin 0.5.2 (registry+https://github.com/rust-lang/crates.io-index)", +] + [[package]] name = "traitobject" version = "0.1.0" @@ -8142,6 +8189,9 @@ dependencies = [ "checksum tokio-udp 0.1.5 (registry+https://github.com/rust-lang/crates.io-index)" = "f02298505547f73e60f568359ef0d016d5acd6e830ab9bc7c4a5b3403440121b" "checksum tokio-uds 0.2.5 (registry+https://github.com/rust-lang/crates.io-index)" = "037ffc3ba0e12a0ab4aca92e5234e0dedeb48fddf6ccd260f1f150a36a9f2445" "checksum toml 0.5.5 (registry+https://github.com/rust-lang/crates.io-index)" = "01d1404644c8b12b16bfcffa4322403a91a451584daaaa7c28d3152e6cbc98cf" +"checksum tracing 0.1.10 (registry+https://github.com/rust-lang/crates.io-index)" = "ff4e4f59e752cb3beb5b61c6d5e11191c7946231ba84faec2902c9efdd8691c5" +"checksum tracing-attributes 0.1.5 (registry+https://github.com/rust-lang/crates.io-index)" = "a4263b12c3d3c403274493eb805966093b53214124796552d674ca1dd5d27c2b" +"checksum tracing-core 0.1.7 (registry+https://github.com/rust-lang/crates.io-index)" = "bc913647c520c959b6d21e35ed8fa6984971deca9f0a2fcb8c51207e0c56af1d" "checksum traitobject 0.1.0 (registry+https://github.com/rust-lang/crates.io-index)" = "efd1f82c56340fdf16f2a953d7bda4f8fdffba13d93b00844c25572110b26079" "checksum trie-bench 0.16.3 (registry+https://github.com/rust-lang/crates.io-index)" = "d14da20d0549737c88299aee9e7b46098c30dd2af7cbca0518bdd420f3766191" "checksum trie-db 0.16.0 (registry+https://github.com/rust-lang/crates.io-index)" = "784a9813d23f18bccab728ab039c39b8a87d0d6956dcdece39e92f5cffe5076e" diff --git a/Cargo.toml b/Cargo.toml index 6de062dc92861733c52fcafdbe566f205e9fc935..785492e282b90fbe268366b1177b4243b161fe81 100644 --- a/Cargo.toml +++ b/Cargo.toml @@ -28,6 +28,7 @@ members = [ "client/executor/runtime-test", "client/finality-grandpa", "client/header-metadata", + "client/tracing", "client/keystore", "client/network", "client/offchain", diff --git a/client/cli/Cargo.toml b/client/cli/Cargo.toml index 366a314c8b6ae9b3fcc88522eee7fbd4e459cd12..af3be8dc941b000d79df4af7173d8cdd56c21ebb 100644 --- a/client/cli/Cargo.toml +++ b/client/cli/Cargo.toml @@ -34,6 +34,7 @@ keyring = { package = "substrate-keyring", path = "../../primitives/keyring" } names = "0.11.0" structopt = "0.3.3" rpassword = "4.0.1" +substrate-tracing = { package = "substrate-tracing", path = "../tracing" } [dev-dependencies] tempdir = "0.3.7" diff --git a/client/cli/src/lib.rs b/client/cli/src/lib.rs index 3f8ecb8f904c53837750a76910f3a7741c2c1847..f841591dc9596f59132ed9cd4dbd45e825314ad8 100644 --- a/client/cli/src/lib.rs +++ b/client/cli/src/lib.rs @@ -205,7 +205,6 @@ where ); panic_handler::set(version.support_url, &full_version); - let matches = CoreParams::<CC, RP>::clap() .name(version.executable_name) .author(version.author) @@ -216,7 +215,6 @@ where .setting(AppSettings::SubcommandsNegateReqs) .get_matches_from(args); let cli_args = CoreParams::<CC, RP>::from_clap(&matches); - init_logger(cli_args.get_log_filter().as_ref().map(|v| v.as_ref()).unwrap_or("")); fdlimit::raise_fd_limit(); @@ -846,6 +844,9 @@ where config.telemetry_endpoints = Some(TelemetryEndpoints::new(cli.telemetry_endpoints)); } + config.tracing_targets = cli.tracing_targets.into(); + config.tracing_receiver = cli.tracing_receiver.into(); + // Imply forced authoring on --dev config.force_authoring = cli.shared_params.dev || cli.force_authoring; @@ -901,6 +902,8 @@ fn init_logger(pattern: &str) { builder.filter(Some("ws"), log::LevelFilter::Off); builder.filter(Some("hyper"), log::LevelFilter::Warn); builder.filter(Some("cranelift_wasm"), log::LevelFilter::Warn); + // Always log the special target `substrate_tracing`, overrides global level + builder.filter(Some("substrate_tracing"), log::LevelFilter::Info); // Enable info for others. builder.filter(None, log::LevelFilter::Info); diff --git a/client/cli/src/params.rs b/client/cli/src/params.rs index f9b36e9a7f7715f388877cdbe294ae9f53a6ff11..5ebedf664b4ae6edb7873d3bfc5b4dbf936b1a9c 100644 --- a/client/cli/src/params.rs +++ b/client/cli/src/params.rs @@ -259,6 +259,24 @@ pub struct TransactionPoolParams { pub pool_kbytes: usize, } +arg_enum! { + #[allow(missing_docs)] + #[derive(Debug, Copy, Clone, PartialEq, Eq)] + pub enum TracingReceiver { + Log, + Telemetry, + } +} + +impl Into<substrate_tracing::TracingReceiver> for TracingReceiver { + fn into(self) -> substrate_tracing::TracingReceiver { + match self { + TracingReceiver::Log => substrate_tracing::TracingReceiver::Log, + TracingReceiver::Telemetry => substrate_tracing::TracingReceiver::Telemetry, + } + } +} + /// Execution strategies parameters. #[derive(Debug, StructOpt, Clone)] pub struct ExecutionStrategies { @@ -491,6 +509,20 @@ pub struct RunCmd { #[structopt(long = "force-authoring")] pub force_authoring: bool, + /// Comma separated list of targets for tracing + #[structopt(long = "tracing-targets", value_name = "TARGETS")] + pub tracing_targets: Option<String>, + + /// Receiver to process tracing messages + #[structopt( + long = "tracing-receiver", + value_name = "RECEIVER", + possible_values = &TracingReceiver::variants(), + case_insensitive = true, + default_value = "Log" + )] + pub tracing_receiver: TracingReceiver, + /// Specify custom keystore path. #[structopt(long = "keystore-path", value_name = "PATH", parse(from_os_str))] pub keystore_path: Option<PathBuf>, diff --git a/client/service/Cargo.toml b/client/service/Cargo.toml index 0c7636cefac7fb3cdb3d1e326ec5ddd1fbbb1c40..ae04da8c26476c268674242f52ea6e6fc6f76856 100644 --- a/client/service/Cargo.toml +++ b/client/service/Cargo.toml @@ -50,6 +50,8 @@ rpc = { package = "substrate-rpc", path = "../rpc" } tel = { package = "substrate-telemetry", path = "../telemetry" } offchain = { package = "substrate-offchain", path = "../offchain" } parity-multiaddr = { package = "parity-multiaddr", version = "0.5.0" } +substrate-tracing = { package = "substrate-tracing", path = "../tracing" } +tracing = "0.1.10" [dev-dependencies] substrate-test-runtime-client = { path = "../../test/utils/runtime/client" } diff --git a/client/service/src/builder.rs b/client/service/src/builder.rs index 9d2b1ebb8f1aa87838bc06561d1ba54f7da8f4ba..9f624139e1d5651ebf4e2d629d5075eeea4fa5bb 100644 --- a/client/service/src/builder.rs +++ b/client/service/src/builder.rs @@ -35,7 +35,7 @@ use futures03::{ StreamExt as _, TryStreamExt as _, }; use keystore::{Store as Keystore}; -use log::{info, warn}; +use log::{info, warn, error}; use network::{FinalityProofProvider, OnDemand, NetworkService, NetworkStateInfo, DhtEvent}; use network::{config::BoxFinalityProofRequestBuilder, specialization::NetworkSpecialization}; use parking_lot::{Mutex, RwLock}; @@ -1130,6 +1130,17 @@ ServiceBuilder< telemetry }); + // Instrumentation + if let Some(tracing_targets) = config.tracing_targets.as_ref() { + let subscriber = substrate_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), + } + } + Ok(Service { client, network, diff --git a/client/service/src/config.rs b/client/service/src/config.rs index e9f002c21f4423e8982c4a9286ac35432d380834..27f26820d105a330ed4b301a32ab72c6843b43c3 100644 --- a/client/service/src/config.rs +++ b/client/service/src/config.rs @@ -98,6 +98,10 @@ pub struct Configuration<C, G, E = NoExtension> { /// /// Should only be set when `node` is running development mode. pub dev_key_seed: Option<String>, + /// Tracing targets + pub tracing_targets: Option<String>, + /// Tracing receiver + pub tracing_receiver: substrate_tracing::TracingReceiver, } /// Configuration of the database of the client. @@ -156,6 +160,8 @@ impl<C, G, E> Configuration<C, G, E> where disable_grandpa: false, keystore_password: None, dev_key_seed: None, + tracing_targets: Default::default(), + tracing_receiver: Default::default(), }; configuration.network.boot_nodes = configuration.chain_spec.boot_nodes().to_vec(); diff --git a/client/service/test/src/lib.rs b/client/service/test/src/lib.rs index 878e3e3c4a592919b3fc3020f9d1c6ef952f6eae..2d1517fd8e844b27e5bb7f8817156216e2939cbd 100644 --- a/client/service/test/src/lib.rs +++ b/client/service/test/src/lib.rs @@ -198,6 +198,8 @@ fn node_config<G, E: Clone> ( force_authoring: false, disable_grandpa: false, dev_key_seed: key_seed, + tracing_targets: None, + tracing_receiver: Default::default(), } } diff --git a/client/tracing/Cargo.toml b/client/tracing/Cargo.toml new file mode 100644 index 0000000000000000000000000000000000000000..25a1a7331be5a316ba5a0706cbe548337eb315be --- /dev/null +++ b/client/tracing/Cargo.toml @@ -0,0 +1,16 @@ +[package] +name = "substrate-tracing" +version = "2.0.0" +license = "GPL-3.0" +authors = ["Parity Technologies <admin@parity.io>"] +edition = "2018" + +[dependencies] +log = { version = "0.4.8" } +parking_lot = "0.9.0" +tracing-core = "0.1.7" + +substrate-telemetry = { path = "../telemetry" } + +[dev-dependencies] +tracing = "0.1.10" diff --git a/client/tracing/src/lib.rs b/client/tracing/src/lib.rs new file mode 100644 index 0000000000000000000000000000000000000000..d6fc4a6418dfb2b96867d48db45c2c1b657e14d6 --- /dev/null +++ b/client/tracing/src/lib.rs @@ -0,0 +1,198 @@ +// Copyright 2019 Parity Technologies (UK) Ltd. +// This file is part of Substrate. + +// Substrate is free software: you can redistribute it and/or modify +// it under the terms of the GNU General Public License as published by +// the Free Software Foundation, either version 3 of the License, or +// (at your option) any later version. + +// Substrate is distributed in the hope that it will be useful, +// but WITHOUT ANY WARRANTY; without even the implied warranty of +// MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the +// GNU General Public License for more details. + +// You should have received a copy of the GNU General Public License +// along with Substrate. If not, see <http://www.gnu.org/licenses/>. + +//! Instrumentation implementation for substrate. +//! +//! This crate is unstable and the API and usage may change. +//! +//! # Usage +//! +//! Monitor performance throughout the codebase via the creation of `Span`s. +//! A span is set in the following way: +//! ``` +//! let span = tracing::span!(tracing::Level::INFO, "my_span_name"); +//! let _enter = span.enter(); +//! ``` +//! To begin timing, a span must be entered. When the span is dropped, the execution time +//! is recorded and details sent to the `Receiver` which defines how to process it. +//! +//! Currently we provide `Log` (default) and `Telemetry` variants for `Receiver` + +use std::collections::HashMap; +use std::sync::atomic::{AtomicU64, Ordering}; +use std::time::{Duration, Instant}; + +use parking_lot::Mutex; +use tracing_core::{event::Event, Level, metadata::Metadata, span::{Attributes, Id, Record}, subscriber::Subscriber}; + +use substrate_telemetry::{telemetry, SUBSTRATE_INFO}; + +/// Used to configure how to receive the metrics +#[derive(Debug, Clone)] +pub enum TracingReceiver { + /// Output to logger + Log, + /// Output to telemetry + Telemetry, +} + +impl Default for TracingReceiver { + fn default() -> Self { + Self::Log + } +} + +#[derive(Debug)] +struct SpanDatum { + id: u64, + name: &'static str, + target: String, + level: Level, + line: u32, + start_time: Instant, + overall_time: Duration, +} + +/// Responsible for assigning ids to new spans, which are not re-used. +pub struct ProfilingSubscriber { + next_id: AtomicU64, + targets: Vec<(String, Level)>, + receiver: TracingReceiver, + span_data: Mutex<HashMap<u64, SpanDatum>>, +} + +impl ProfilingSubscriber { + /// Takes a `Receiver` and a comma separated list of targets, + /// either with a level "paint=trace" + /// or without "paint". + pub fn new(receiver: TracingReceiver, targets: &String) -> Self { + let targets: Vec<_> = targets.split(',').map(|s| parse_target(s)).collect(); + ProfilingSubscriber { + next_id: AtomicU64::new(1), + targets, + receiver, + span_data: Mutex::new(HashMap::new()), + } + } +} + +// Default to TRACE if no level given or unable to parse Level +// We do not support a global `Level` currently +fn parse_target(s: &str) -> (String, Level) { + match s.find("=") { + Some(i) => { + let target = s[0..i].to_string(); + if s.len() > i { + let level = s[i + 1..s.len()].parse::<Level>().unwrap_or(Level::TRACE); + (target, level) + } else { + (target, Level::TRACE) + } + } + None => (s.to_string(), Level::TRACE) + } +} + +impl Subscriber for ProfilingSubscriber { + fn enabled(&self, metadata: &Metadata<'_>) -> bool { + for t in &self.targets { + if metadata.target().starts_with(t.0.as_str()) && metadata.level() <= &t.1 { + log::debug!("Enabled target: {}, level: {}", metadata.target(), metadata.level()); + return true; + } else { + log::debug!("Disabled target: {}, level: {}", metadata.target(), metadata.level()); + } + } + false + } + + fn new_span(&self, attrs: &Attributes<'_>) -> Id { + let id = self.next_id.fetch_add(1, Ordering::Relaxed); + let span_datum = SpanDatum { + id: id, + name: attrs.metadata().name(), + target: attrs.metadata().target().to_string(), + level: attrs.metadata().level().clone(), + line: attrs.metadata().line().unwrap_or(0), + start_time: Instant::now(), + overall_time: Duration::from_nanos(0), + }; + self.span_data.lock().insert(id, span_datum); + Id::from_u64(id) + } + + fn record(&self, _span: &Id, _values: &Record<'_>) {} + + fn record_follows_from(&self, _span: &Id, _follows: &Id) {} + + fn event(&self, _event: &Event<'_>) {} + + fn enter(&self, span: &Id) { + let mut span_data = self.span_data.lock(); + let start_time = Instant::now(); + if let Some(mut s) = span_data.get_mut(&span.into_u64()) { + s.start_time = start_time; + } else { + log::warn!("Tried to enter span {:?} that has already been closed!", span); + } + } + + fn exit(&self, span: &Id) { + let mut span_data = self.span_data.lock(); + let end_time = Instant::now(); + if let Some(mut s) = span_data.get_mut(&span.into_u64()) { + s.overall_time = end_time - s.start_time + s.overall_time; + } + } + + fn try_close(&self, span: Id) -> bool { + let mut span_data = self.span_data.lock(); + if let Some(data) = span_data.remove(&span.into_u64()) { + self.send_span(data); + }; + true + } +} + +impl ProfilingSubscriber { + fn send_span(&self, span_datum: SpanDatum) { + match self.receiver { + TracingReceiver::Log => print_log(span_datum), + TracingReceiver::Telemetry => send_telemetry(span_datum), + } + } +} + +fn print_log(span_datum: SpanDatum) { + let message = format!( + "Tracing: {} {}: {}, line: {}, time: {} ns", + span_datum.level, + span_datum.target, + span_datum.name, + span_datum.line, + span_datum.overall_time.as_nanos() + ); + log::info!(target: "substrate_tracing", "{}", message); +} + +fn send_telemetry(span_datum: SpanDatum) { + telemetry!(SUBSTRATE_INFO; "tracing.profiling"; + "name" => span_datum.name, + "target" => span_datum.target, + "line" => span_datum.line, + "time" => span_datum.overall_time.as_nanos(), + ); +} diff --git a/palette/support/Cargo.toml b/palette/support/Cargo.toml index 07d0fee96ea9452098ffaa464591e2e1685fc336..b2a631a8fbbc04e85f6e6269517e8eb5cde91137 100644 --- a/palette/support/Cargo.toml +++ b/palette/support/Cargo.toml @@ -21,6 +21,7 @@ once_cell = { version = "0.2.4", default-features = false, optional = true } state-machine = { package = "substrate-state-machine", path = "../../primitives/state-machine", optional = true } bitmask = { version = "0.5.0", default-features = false } impl-trait-for-tuples = "0.1.3" +tracing = { version = "0.1.10", optional = true } [dev-dependencies] pretty_assertions = "0.6.1" @@ -29,6 +30,7 @@ palette-system = { path = "../system" } [features] default = ["std"] std = [ + "tracing", "once_cell", "bitmask/std", "serde", diff --git a/palette/support/src/dispatch.rs b/palette/support/src/dispatch.rs index e53ce1cabca5f22c049af6177b5eed31c9b8263a..ea13d385ef0b82da3d68ccd327175a955c2cbcda 100644 --- a/palette/support/src/dispatch.rs +++ b/palette/support/src/dispatch.rs @@ -861,7 +861,15 @@ macro_rules! decl_module { $crate::sr_primitives::traits::OnInitialize<$trait_instance::BlockNumber> for $module<$trait_instance$(, $instance)?> where $( $other_where_bounds )* { - fn on_initialize(_block_number_not_used: $trait_instance::BlockNumber) { $( $impl )* } + fn on_initialize(_block_number_not_used: $trait_instance::BlockNumber) { + use $crate::rstd::if_std; + if_std! { + use $crate::tracing; + let span = tracing::span!(tracing::Level::INFO, "on_initialize"); + let _enter = span.enter(); + } + { $( $impl )* } + } } }; @@ -875,7 +883,15 @@ macro_rules! decl_module { $crate::sr_primitives::traits::OnInitialize<$trait_instance::BlockNumber> for $module<$trait_instance$(, $instance)?> where $( $other_where_bounds )* { - fn on_initialize($param: $param_ty) { $( $impl )* } + fn on_initialize($param: $param_ty) { + use $crate::rstd::if_std; + if_std! { + use $crate::tracing; + let span = tracing::span!(tracing::Level::INFO, "on_initialize"); + let _enter = span.enter(); + } + { $( $impl )* } + } } }; @@ -899,7 +915,15 @@ macro_rules! decl_module { $crate::sr_primitives::traits::OnFinalize<$trait_instance::BlockNumber> for $module<$trait_instance$(, $instance)?> where $( $other_where_bounds )* { - fn on_finalize(_block_number_not_used: $trait_instance::BlockNumber) { $( $impl )* } + fn on_finalize(_block_number_not_used: $trait_instance::BlockNumber) { + use $crate::rstd::if_std; + if_std! { + use $crate::tracing; + let span = tracing::span!(tracing::Level::INFO, "on_finalize"); + let _enter = span.enter(); + } + { $( $impl )* } + } } }; @@ -913,7 +937,15 @@ macro_rules! decl_module { $crate::sr_primitives::traits::OnFinalize<$trait_instance::BlockNumber> for $module<$trait_instance$(, $instance)?> where $( $other_where_bounds )* { - fn on_finalize($param: $param_ty) { $( $impl )* } + fn on_finalize($param: $param_ty) { + use $crate::rstd::if_std; + if_std! { + use $crate::tracing; + let span = tracing::span!(tracing::Level::INFO, "on_finalize"); + let _enter = span.enter(); + } + { $( $impl )* } + } } }; @@ -1009,9 +1041,16 @@ macro_rules! decl_module { $vis fn $name( $origin: $origin_ty $(, $param: $param_ty )* ) -> $crate::dispatch::DispatchResult<$error_type> { - { $( $impl )* } - // May be unreachable. - Ok(()) + use $crate::rstd::if_std; + if_std! { + use $crate::tracing; + let span = tracing::span!(tracing::Level::INFO, stringify!($name)); + let _enter = span.enter(); + } + { + { $( $impl )* } + Ok(()) + } } }; @@ -1028,7 +1067,13 @@ macro_rules! decl_module { ) => { $(#[doc = $doc_attr])* $vis fn $name($origin: $origin_ty $(, $param: $param_ty )* ) -> $result { - $( $impl )* + use $crate::rstd::if_std; + if_std! { + use $crate::tracing; + let span = tracing::span!(tracing::Level::INFO, stringify!($name)); + let _enter = span.enter(); + } + { $( $impl )* } } }; diff --git a/palette/support/src/lib.rs b/palette/support/src/lib.rs index b6578a56fd5716cc0ce357a038f6d2e3a19ea6e9..1921d8037045f7632d2f8ca74413f44c1f51e3fd 100644 --- a/palette/support/src/lib.rs +++ b/palette/support/src/lib.rs @@ -23,6 +23,8 @@ extern crate self as palette_support; #[macro_use] extern crate bitmask; +#[cfg(feature = "std")] +pub extern crate tracing; #[cfg(feature = "std")] pub use serde;