sp_tracing/
lib.rs

1// This file is part of Substrate.
2
3// Copyright (C) Parity Technologies (UK) Ltd.
4// SPDX-License-Identifier: Apache-2.0
5
6// Licensed under the Apache License, Version 2.0 (the "License");
7// you may not use this file except in compliance with the License.
8// You may obtain a copy of the License at
9//
10// 	http://www.apache.org/licenses/LICENSE-2.0
11//
12// Unless required by applicable law or agreed to in writing, software
13// distributed under the License is distributed on an "AS IS" BASIS,
14// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
15// See the License for the specific language governing permissions and
16// limitations under the License.
17
18//! Substrate tracing primitives and macros.
19//!
20//! To trace functions or individual code in Substrate, this crate provides [`within_span`]
21//! and [`enter_span`]. See the individual docs for how to use these macros.
22//!
23//! Note that to allow traces from wasm execution environment there are
24//! 2 reserved identifiers for tracing `Field` recording, stored in the consts:
25//! `WASM_TARGET_KEY` and `WASM_NAME_KEY` - if you choose to record fields, you
26//! must ensure that your identifiers do not clash with either of these.
27//!
28//! Additionally, we have a const: `WASM_TRACE_IDENTIFIER`, which holds a span name used
29//! to signal that the 'actual' span name and target should be retrieved instead from
30//! the associated Fields mentioned above.
31//!
32//! Note: The `tracing` crate requires trace metadata to be static. This does not work
33//! for wasm code in substrate, as it is regularly updated with new code from on-chain
34//! events. The workaround for this is for the wasm tracing wrappers to put the
35//! `name` and `target` data in the `values` map (normally they would be in the static
36//! metadata assembled at compile time).
37
38#![cfg_attr(not(feature = "std"), no_std)]
39
40extern crate alloc;
41
42#[cfg(feature = "std")]
43pub use tracing;
44pub use tracing::{
45	debug, debug_span, error, error_span, event, info, info_span, span, trace, trace_span, warn,
46	warn_span, Level, Span,
47};
48
49#[cfg(feature = "std")]
50pub use tracing_subscriber;
51
52pub use crate::types::{
53	WasmEntryAttributes, WasmFieldName, WasmFields, WasmLevel, WasmMetadata, WasmValue,
54	WasmValuesSet,
55};
56#[cfg(feature = "std")]
57pub use crate::types::{WASM_NAME_KEY, WASM_TARGET_KEY, WASM_TRACE_IDENTIFIER};
58
59/// Tracing facilities and helpers.
60///
61/// This is modeled after the `tracing`/`tracing-core` interface and uses that more or
62/// less directly for the native side. Because of certain optimisations the these crates
63/// have done, the wasm implementation diverges slightly and is optimised for that use
64/// case (like being able to cross the wasm/native boundary via scale codecs).
65///
66/// One of said optimisations is that all macros will yield to a `noop` in non-std unless
67/// the `with-tracing` feature is explicitly activated. This allows you to just use the
68/// tracing wherever you deem fit and without any performance impact by default. Only if
69/// the specific `with-tracing`-feature is activated on this crate will it actually include
70/// the tracing code in the non-std environment.
71///
72/// Because of that optimisation, you should not use the `span!` and `span_*!` macros
73/// directly as they yield nothing without the feature present. Instead you should use
74/// `enter_span!` and `within_span!` – which would strip away even any parameter conversion
75/// you do within the span-definition (and thus optimise your performance). For your
76/// convenience you directly specify the `Level` and name of the span or use the full
77/// feature set of `span!`/`span_*!` on it:
78///
79/// # Example
80///
81/// ```rust
82/// sp_tracing::enter_span!(sp_tracing::Level::TRACE, "fn wide span");
83/// {
84/// 		sp_tracing::enter_span!(sp_tracing::trace_span!("outer-span"));
85/// 		{
86/// 			sp_tracing::enter_span!(sp_tracing::Level::TRACE, "inner-span");
87/// 			// ..
88/// 		}  // inner span exists here
89/// 	} // outer span exists here
90///
91/// sp_tracing::within_span! {
92/// 		sp_tracing::debug_span!("debug-span", you_can_pass="any params");
93///     1 + 1;
94///     // some other complex code
95/// } // debug span ends here
96/// ```
97///
98///
99/// # Setup
100///
101/// This project only provides the macros and facilities to manage tracing
102/// it doesn't implement the tracing subscriber or backend directly – that is
103/// up to the developer integrating it into a specific environment. In native
104/// this can and must be done through the regular `tracing`-facilities, please
105/// see their documentation for details.
106///
107/// On the wasm-side we've adopted a similar approach of having a global
108/// `TracingSubscriber` that the macros call and that does the actual work
109/// of tracking. To provide your tracking, you must implement `TracingSubscriber`
110/// and call `set_tracing_subscriber` at the very beginning of your execution –
111/// the default subscriber is doing nothing, so any spans or events happening before
112/// will not be recorded!
113mod types;
114
115/// Try to init a simple tracing subscriber with log compatibility layer.
116///
117/// Ignores any error. Useful for testing.
118#[cfg(feature = "std")]
119pub fn try_init_simple() {
120	let _ = tracing_subscriber::fmt()
121		.with_env_filter(tracing_subscriber::EnvFilter::from_default_env())
122		.with_writer(std::io::stderr)
123		.try_init();
124}
125
126/// Init a tracing subscriber for logging in tests.
127///
128/// Be aware that this enables `TRACE` by default. It also ignores any error
129/// while setting up the logger.
130///
131/// The logs are not shown by default, logs are only shown when the test fails
132/// or if [`nocapture`](https://doc.rust-lang.org/cargo/commands/cargo-test.html#display-options)
133/// is being used.
134#[cfg(feature = "std")]
135pub fn init_for_tests() {
136	let _ = tracing_subscriber::fmt()
137		.with_max_level(tracing::Level::TRACE)
138		.with_test_writer()
139		.try_init();
140}
141
142/// Runs given code within a tracing span, measuring it's execution time.
143///
144/// If tracing is not enabled, the code is still executed. Pass in level and name or
145/// use any valid `sp_tracing::Span`followed by `;` and the code to execute,
146///
147/// # Example
148///
149/// ```
150/// sp_tracing::within_span! {
151///     sp_tracing::Level::TRACE,
152///     "test-span";
153///     1 + 1;
154///     // some other complex code
155/// }
156///
157/// sp_tracing::within_span! {
158///     sp_tracing::span!(sp_tracing::Level::WARN, "warn-span", you_can_pass="any params");
159///     1 + 1;
160///     // some other complex code
161/// }
162///
163/// sp_tracing::within_span! {
164///     sp_tracing::debug_span!("debug-span", you_can_pass="any params");
165///     1 + 1;
166///     // some other complex code
167/// }
168/// ```
169#[cfg(any(feature = "std", feature = "with-tracing"))]
170#[macro_export]
171macro_rules! within_span {
172	(
173		$span:expr;
174		$( $code:tt )*
175	) => {
176		$span.in_scope(||
177			{
178				$( $code )*
179			}
180		)
181	};
182	(
183		$lvl:expr,
184		$name:expr;
185		$( $code:tt )*
186	) => {
187		{
188			$crate::within_span!($crate::span!($lvl, $name); $( $code )*)
189		}
190	};
191}
192
193#[cfg(all(not(feature = "std"), not(feature = "with-tracing")))]
194#[macro_export]
195macro_rules! within_span {
196	(
197		$span:stmt;
198		$( $code:tt )*
199	) => {
200		$( $code )*
201	};
202	(
203		$lvl:expr,
204		$name:expr;
205		$( $code:tt )*
206	) => {
207		$( $code )*
208	};
209}
210
211/// Enter a span - noop for `no_std` without `with-tracing`
212#[cfg(all(not(feature = "std"), not(feature = "with-tracing")))]
213#[macro_export]
214macro_rules! enter_span {
215	( $lvl:expr, $name:expr ) => {};
216	( $name:expr ) => {}; // no-op
217}
218
219/// Enter a span.
220///
221/// The span will be valid, until the scope is left. Use either level and name
222/// or pass in any valid `sp_tracing::Span` for extended usage. The span will
223/// be exited on drop – which is at the end of the block or to the next
224/// `enter_span!` calls, as this overwrites the local variable. For nested
225/// usage or to ensure the span closes at certain time either put it into a block
226/// or use `within_span!`
227///
228/// # Example
229///
230/// ```
231/// sp_tracing::enter_span!(sp_tracing::Level::TRACE, "test-span");
232/// // previous will be dropped here
233/// sp_tracing::enter_span!(
234/// 	sp_tracing::span!(sp_tracing::Level::DEBUG, "debug-span", params="value"));
235/// sp_tracing::enter_span!(sp_tracing::info_span!("info-span",  params="value"));
236///
237/// {
238/// 		sp_tracing::enter_span!(sp_tracing::Level::TRACE, "outer-span");
239/// 		{
240/// 			sp_tracing::enter_span!(sp_tracing::Level::TRACE, "inner-span");
241/// 			// ..
242/// 		}  // inner span exists here
243/// 	} // outer span exists here
244/// ```
245#[cfg(any(feature = "std", feature = "with-tracing"))]
246#[macro_export]
247macro_rules! enter_span {
248	( $span:expr ) => {
249		// Calling this twice in a row will overwrite (and drop) the earlier
250		// that is a _documented feature_!
251		let __within_span__ = $span;
252		let __tracing_guard__ = __within_span__.enter();
253	};
254	( $lvl:expr, $name:expr ) => {
255		$crate::enter_span!($crate::span!($lvl, $name))
256	};
257}