1use std::{
21 collections::HashMap,
22 sync::{
23 atomic::{AtomicU64, Ordering},
24 Arc,
25 },
26 time::Instant,
27};
28
29use codec::Encode;
30use parking_lot::Mutex;
31use tracing::{
32 dispatcher,
33 span::{Attributes, Id, Record},
34 Dispatch, Level, Subscriber,
35};
36
37use crate::{SpanDatum, TraceEvent, Values};
38use sc_client_api::BlockBackend;
39use sp_api::{Core, Metadata, ProvideRuntimeApi};
40use sp_blockchain::HeaderBackend;
41use sp_core::hexdisplay::HexDisplay;
42use sp_rpc::tracing::{BlockTrace, Span, TraceBlockResponse};
43use sp_runtime::{
44 generic::BlockId,
45 traits::{Block as BlockT, Header},
46};
47use sp_tracing::{WASM_NAME_KEY, WASM_TARGET_KEY, WASM_TRACE_IDENTIFIER};
48
49const DEFAULT_TARGETS: &str = "pallet,frame,state";
51const TRACE_TARGET: &str = "block_trace";
52const REQUIRED_EVENT_FIELD: &str = "method";
54
55pub type TraceBlockResult<T> = Result<T, Error>;
57
58#[derive(Debug, thiserror::Error)]
60#[allow(missing_docs)]
61#[non_exhaustive]
62pub enum Error {
63 #[error("Invalid block Id: {0}")]
64 InvalidBlockId(#[from] sp_blockchain::Error),
65 #[error("Missing block component: {0}")]
66 MissingBlockComponent(String),
67 #[error("Dispatch error: {0}")]
68 Dispatch(String),
69}
70
71struct BlockSubscriber {
72 targets: Vec<(String, Level)>,
73 next_id: AtomicU64,
74 spans: Mutex<HashMap<Id, SpanDatum>>,
75 events: Mutex<Vec<TraceEvent>>,
76}
77
78impl BlockSubscriber {
79 fn new(targets: &str) -> Self {
80 let next_id = AtomicU64::new(1);
81 let mut targets: Vec<_> = targets.split(',').map(crate::parse_target).collect();
82 targets.push((WASM_TRACE_IDENTIFIER.to_owned(), Level::TRACE));
85 BlockSubscriber {
86 targets,
87 next_id,
88 spans: Mutex::new(HashMap::new()),
89 events: Mutex::new(Vec::new()),
90 }
91 }
92}
93
94impl Subscriber for BlockSubscriber {
95 fn enabled(&self, metadata: &tracing::Metadata<'_>) -> bool {
96 if !metadata.is_span() && metadata.fields().field(REQUIRED_EVENT_FIELD).is_none() {
97 return false
98 }
99 for (target, level) in &self.targets {
100 if metadata.level() <= level && metadata.target().starts_with(target) {
101 return true
102 }
103 }
104 false
105 }
106
107 fn new_span(&self, attrs: &Attributes<'_>) -> Id {
108 let id = Id::from_u64(self.next_id.fetch_add(1, Ordering::Relaxed));
109 let mut values = Values::default();
110 attrs.record(&mut values);
111 let parent_id = attrs.parent().cloned();
112 let span = SpanDatum {
113 id: id.clone(),
114 parent_id,
115 name: attrs.metadata().name().to_owned(),
116 target: attrs.metadata().target().to_owned(),
117 level: *attrs.metadata().level(),
118 line: attrs.metadata().line().unwrap_or(0),
119 start_time: Instant::now(),
120 values,
121 overall_time: Default::default(),
122 };
123
124 self.spans.lock().insert(id.clone(), span);
125 id
126 }
127
128 fn record(&self, span: &Id, values: &Record<'_>) {
129 let mut span_data = self.spans.lock();
130 if let Some(s) = span_data.get_mut(span) {
131 values.record(&mut s.values);
132 }
133 }
134
135 fn record_follows_from(&self, _span: &Id, _follows: &Id) {
136 unimplemented!("record_follows_from is not implemented");
138 }
139
140 fn event(&self, event: &tracing::Event<'_>) {
141 let mut values = crate::Values::default();
142 event.record(&mut values);
143 let parent_id = event.parent().cloned();
144 let trace_event = TraceEvent {
145 name: event.metadata().name().to_owned(),
146 target: event.metadata().target().to_owned(),
147 level: *event.metadata().level(),
148 values,
149 parent_id,
150 };
151 self.events.lock().push(trace_event);
152 }
153
154 fn enter(&self, _id: &Id) {}
155
156 fn exit(&self, _span: &Id) {}
157}
158
159pub struct BlockExecutor<Block: BlockT, Client> {
165 client: Arc<Client>,
166 block: Block::Hash,
167 targets: Option<String>,
168 storage_keys: Option<String>,
169 methods: Option<String>,
170}
171
172impl<Block, Client> BlockExecutor<Block, Client>
173where
174 Block: BlockT + 'static,
175 Client: HeaderBackend<Block>
176 + BlockBackend<Block>
177 + ProvideRuntimeApi<Block>
178 + Send
179 + Sync
180 + 'static,
181 Client::Api: Metadata<Block>,
182{
183 pub fn new(
185 client: Arc<Client>,
186 block: Block::Hash,
187 targets: Option<String>,
188 storage_keys: Option<String>,
189 methods: Option<String>,
190 ) -> Self {
191 Self { client, block, targets, storage_keys, methods }
192 }
193
194 pub fn trace_block(&self) -> TraceBlockResult<TraceBlockResponse> {
198 tracing::debug!(target: "state_tracing", "Tracing block: {}", self.block);
199 let mut header = self
201 .client
202 .header(self.block)
203 .map_err(Error::InvalidBlockId)?
204 .ok_or_else(|| Error::MissingBlockComponent("Header not found".to_string()))?;
205 let extrinsics = self
206 .client
207 .block_body(self.block)
208 .map_err(Error::InvalidBlockId)?
209 .ok_or_else(|| Error::MissingBlockComponent("Extrinsics not found".to_string()))?;
210 tracing::debug!(target: "state_tracing", "Found {} extrinsics", extrinsics.len());
211 let parent_hash = *header.parent_hash();
212 header.digest_mut().logs.retain(|d| d.as_seal().is_none());
215 let block = Block::new(header, extrinsics);
216
217 let targets = if let Some(t) = &self.targets { t } else { DEFAULT_TARGETS };
218 let block_subscriber = BlockSubscriber::new(targets);
219 let dispatch = Dispatch::new(block_subscriber);
220
221 {
222 let dispatcher_span = tracing::debug_span!(
223 target: "state_tracing",
224 "execute_block",
225 extrinsics_len = block.extrinsics().len(),
226 );
227 let _guard = dispatcher_span.enter();
228 if let Err(e) = dispatcher::with_default(&dispatch, || {
229 let span = tracing::info_span!(target: TRACE_TARGET, "trace_block");
230 let _enter = span.enter();
231 self.client.runtime_api().execute_block(parent_hash, block)
232 }) {
233 return Err(Error::Dispatch(format!(
234 "Failed to collect traces and execute block: {}",
235 e
236 )))
237 }
238 }
239
240 let block_subscriber = dispatch.downcast_ref::<BlockSubscriber>().ok_or_else(|| {
241 Error::Dispatch(
242 "Cannot downcast Dispatch to BlockSubscriber after tracing block".to_string(),
243 )
244 })?;
245 let spans: Vec<_> = block_subscriber
246 .spans
247 .lock()
248 .drain()
249 .filter_map(|(_, s)| patch_and_filter(s, targets))
251 .collect();
252 let events: Vec<_> = block_subscriber
253 .events
254 .lock()
255 .drain(..)
256 .filter(|e| {
257 self.storage_keys
258 .as_ref()
259 .map(|keys| event_values_filter(e, "key", keys))
260 .unwrap_or(false)
261 })
262 .filter(|e| {
263 self.methods
264 .as_ref()
265 .map(|methods| event_values_filter(e, "method", methods))
266 .unwrap_or(false)
267 })
268 .map(|s| s.into())
269 .collect();
270 tracing::debug!(target: "state_tracing", "Captured {} spans and {} events", spans.len(), events.len());
271
272 Ok(TraceBlockResponse::BlockTrace(BlockTrace {
273 block_hash: block_id_as_string(BlockId::<Block>::Hash(self.block)),
274 parent_hash: block_id_as_string(BlockId::<Block>::Hash(parent_hash)),
275 tracing_targets: targets.to_string(),
276 storage_keys: self.storage_keys.clone().unwrap_or_default(),
277 methods: self.methods.clone().unwrap_or_default(),
278 spans,
279 events,
280 }))
281 }
282}
283
284fn event_values_filter(event: &TraceEvent, filter_kind: &str, values: &str) -> bool {
285 event
286 .values
287 .string_values
288 .get(filter_kind)
289 .map(|value| check_target(values, value, &event.level))
290 .unwrap_or(false)
291}
292
293fn patch_and_filter(mut span: SpanDatum, targets: &str) -> Option<Span> {
302 if span.name == WASM_TRACE_IDENTIFIER {
303 span.values.bool_values.insert("wasm".to_owned(), true);
304 if let Some(n) = span.values.string_values.remove(WASM_NAME_KEY) {
305 span.name = n;
306 }
307 if let Some(t) = span.values.string_values.remove(WASM_TARGET_KEY) {
308 span.target = t;
309 }
310 if !check_target(targets, &span.target, &span.level) {
311 return None
312 }
313 }
314 Some(span.into())
315}
316
317fn check_target(targets: &str, target: &str, level: &Level) -> bool {
319 for (t, l) in targets.split(',').map(crate::parse_target) {
320 if target.starts_with(t.as_str()) && level <= &l {
321 return true
322 }
323 }
324 false
325}
326
327fn block_id_as_string<T: BlockT>(block_id: BlockId<T>) -> String {
328 match block_id {
329 BlockId::Hash(h) => HexDisplay::from(&h.encode()).to_string(),
330 BlockId::Number(n) => HexDisplay::from(&n.encode()).to_string(),
331 }
332}