sc_tracing_proc_macro/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
18use proc_macro::TokenStream;
19use proc_macro2::Span;
20use proc_macro_crate::{crate_name, FoundCrate};
21use quote::quote;
22use syn::{Error, Expr, ItemFn, Path, Result};
23
24/// This prefixes all the log lines with `[<name>]` (after the timestamp). It works by making a
25/// tracing's span that is propagated to all the child calls and child tasks (futures) if they are
26/// spawned properly with the `SpawnHandle` (see `TaskManager` in sc-cli) or if the futures use
27/// `.in_current_span()` (see tracing-futures).
28///
29/// See Tokio's [tracing documentation](https://docs.rs/tracing-core/) and
30/// [tracing-futures documentation](https://docs.rs/tracing-futures/) for more details.
31///
32/// # Implementation notes
33///
34/// If there are multiple spans with a log prefix, only the latest will be shown.
35///
36/// # Example with a literal
37///
38/// ```ignore
39/// Builds a new service for a light client.
40/// #[sc_cli::prefix_logs_with("light")]
41/// pub fn new_light(config: Configuration) -> Result<TaskManager, ServiceError> {
42/// let (client, backend, keystore, mut task_manager, on_demand) =
43/// sc_service::new_light_parts::<Block, RuntimeApi, Executor>(&config)?;
44///
45/// ...
46/// }
47/// ```
48///
49/// Will produce logs that look like this:
50///
51/// ```text
52/// 2020-10-16 08:03:14 Substrate Node
53/// 2020-10-16 08:03:14 ✌️ version 2.0.0-47f7d3f2e-x86_64-linux-gnu
54/// 2020-10-16 08:03:14 ❤️ by Anonymous, 2017-2020
55/// 2020-10-16 08:03:14 📋 Chain specification: Local Testnet
56/// 2020-10-16 08:03:14 🏷 Node name: nice-glove-1401
57/// 2020-10-16 08:03:14 👤 Role: LIGHT
58/// 2020-10-16 08:03:14 💾 Database: RocksDb at /tmp/substrate95w2Dk/chains/local_testnet/db
59/// 2020-10-16 08:03:14 ⛓ Native runtime: node-template-1 (node-template-1.tx1.au1)
60/// 2020-10-16 08:03:14 [light] 🔨 Initializing Genesis block/state (state: 0x121d…8e36, header-hash: 0x24ef…8ff6)
61/// 2020-10-16 08:03:14 [light] Loading GRANDPA authorities from genesis on what appears to be first startup.
62/// 2020-10-16 08:03:15 [light] ⏱ Loaded block-time = 6000 milliseconds from genesis on first-launch
63/// 2020-10-16 08:03:15 [light] Using default protocol ID "sup" because none is configured in the chain specs
64/// 2020-10-16 08:03:15 [light] 🏷 Local node identity is: 12D3KooWHX4rkWT6a6N55Km7ZnvenGdShSKPkzJ3yj9DU5nqDtWR
65/// 2020-10-16 08:03:15 [light] 📦 Highest known block at #0
66/// 2020-10-16 08:03:15 [light] 〽️ Prometheus server started at 127.0.0.1:9615
67/// 2020-10-16 08:03:15 [light] Listening for new connections on 127.0.0.1:9944.
68/// ```
69///
70/// # Example using the actual node name
71///
72/// ```ignore
73/// Builds a new service for a light client.
74/// #[sc_cli::prefix_logs_with(config.network.node_name.as_str())]
75/// pub fn new_light(config: Configuration) -> Result<TaskManager, ServiceError> {
76/// let (client, backend, keystore, mut task_manager, on_demand) =
77/// sc_service::new_light_parts::<Block, RuntimeApi, Executor>(&config)?;
78///
79/// ...
80/// }
81/// ```
82///
83/// Will produce logs that look like this:
84///
85/// ```text
86/// 2020-10-16 08:12:57 Substrate Node
87/// 2020-10-16 08:12:57 ✌️ version 2.0.0-efb9b822a-x86_64-linux-gnu
88/// 2020-10-16 08:12:57 ❤️ by Anonymous, 2017-2020
89/// 2020-10-16 08:12:57 📋 Chain specification: Local Testnet
90/// 2020-10-16 08:12:57 🏷 Node name: open-harbor-1619
91/// 2020-10-16 08:12:57 👤 Role: LIGHT
92/// 2020-10-16 08:12:57 💾 Database: RocksDb at /tmp/substrate9T9Mtb/chains/local_testnet/db
93/// 2020-10-16 08:12:57 ⛓ Native runtime: node-template-1 (node-template-1.tx1.au1)
94/// 2020-10-16 08:12:58 [open-harbor-1619] 🔨 Initializing Genesis block/state (state: 0x121d…8e36, header-hash: 0x24ef…8ff6)
95/// 2020-10-16 08:12:58 [open-harbor-1619] Loading GRANDPA authorities from genesis on what appears to be first startup.
96/// 2020-10-16 08:12:58 [open-harbor-1619] ⏱ Loaded block-time = 6000 milliseconds from genesis on first-launch
97/// 2020-10-16 08:12:58 [open-harbor-1619] Using default protocol ID "sup" because none is configured in the chain specs
98/// 2020-10-16 08:12:58 [open-harbor-1619] 🏷 Local node identity is: 12D3KooWRzmYC8QTK1Pm8Cfvid3skTS4Hn54jc4AUtje8Rqbfgtp
99/// 2020-10-16 08:12:58 [open-harbor-1619] 📦 Highest known block at #0
100/// 2020-10-16 08:12:58 [open-harbor-1619] 〽️ Prometheus server started at 127.0.0.1:9615
101/// 2020-10-16 08:12:58 [open-harbor-1619] Listening for new connections on 127.0.0.1:9944.
102/// ```
103#[proc_macro_attribute]
104pub fn prefix_logs_with(arg: TokenStream, item: TokenStream) -> TokenStream {
105 // Ensure an argument was provided.
106 if arg.is_empty() {
107 return Error::new(
108 proc_macro2::Span::call_site(),
109 "missing argument: prefix. Example: prefix_logs_with(\"Relaychain\")",
110 )
111 .to_compile_error()
112 .into();
113 }
114
115 let prefix_expr = syn::parse_macro_input!(arg as Expr);
116 let item_fn = syn::parse_macro_input!(item as ItemFn);
117
118 // Resolve the proper sc_tracing path.
119 let crate_name = match resolve_sc_tracing() {
120 Ok(path) => path,
121 Err(err) => return err.to_compile_error().into(),
122 };
123
124 let syn::ItemFn { attrs, vis, sig, block } = item_fn;
125
126 (quote! {
127 #(#attrs)*
128 #vis #sig {
129 let span = #crate_name::tracing::info_span!(
130 #crate_name::logging::PREFIX_LOG_SPAN,
131 name = #prefix_expr,
132 );
133 let _enter = span.enter();
134
135 #block
136 }
137 })
138 .into()
139}
140
141/// Resolve the correct path for sc_tracing:
142/// - If `polkadot-sdk` is in scope, returns a Path corresponding to `polkadot_sdk::sc_tracing`
143/// - Otherwise, falls back to `sc_tracing`
144fn resolve_sc_tracing() -> Result<Path> {
145 match crate_name("polkadot-sdk") {
146 Ok(FoundCrate::Itself) => syn::parse_str("polkadot_sdk::sc_tracing"),
147 Ok(FoundCrate::Name(sdk_name)) => syn::parse_str(&format!("{}::sc_tracing", sdk_name)),
148 Err(_) => match crate_name("sc-tracing") {
149 Ok(FoundCrate::Itself) => syn::parse_str("sc_tracing"),
150 Ok(FoundCrate::Name(name)) => syn::parse_str(&name),
151 Err(e) => Err(syn::Error::new(Span::call_site(), e)),
152 },
153 }
154}