From 49c6aa9a76c023681e2370345b22161b7fe80586 Mon Sep 17 00:00:00 2001 From: Bernhard Schuster Date: Fri, 19 Feb 2021 15:19:43 +0100 Subject: [PATCH] feat/jaeger: more spans, more stages (#2477) * feat/jaeger: more spans, more stages Stage numbers are still arbitrarily picked. * feat/jaeger: additional spans * chore/spellcheck: improve the dictionary * fix/jaeger JaegerSpan -> jaeger::Span --- polkadot/.config/lingua.dic | 4 + polkadot/node/core/av-store/src/tests.rs | 6 +- polkadot/node/core/backing/src/lib.rs | 67 +++++++++----- .../node/core/bitfield-signing/src/lib.rs | 10 +-- .../node/core/candidate-selection/src/lib.rs | 39 +++++--- polkadot/node/core/provisioner/src/lib.rs | 4 +- polkadot/node/jaeger/src/lib.rs | 88 ++++++++++++++----- .../availability-distribution/src/lib.rs | 13 +-- .../availability-distribution/src/tests.rs | 12 +-- .../network/availability-recovery/src/lib.rs | 6 ++ .../availability-recovery/src/tests.rs | 18 ++-- .../network/bitfield-distribution/src/lib.rs | 8 +- polkadot/node/network/bridge/src/lib.rs | 16 ++-- .../collator-protocol/src/collator_side.rs | 4 +- .../collator-protocol/src/validator_side.rs | 4 +- .../node/network/pov-distribution/src/lib.rs | 7 +- .../network/pov-distribution/src/tests.rs | 6 +- polkadot/node/network/protocol/src/lib.rs | 14 +-- .../network/statement-distribution/src/lib.rs | 21 +++-- polkadot/node/overseer/src/lib.rs | 22 ++--- polkadot/node/subsystem-util/src/lib.rs | 15 ++-- polkadot/node/subsystem/src/lib.rs | 8 +- 22 files changed, 249 insertions(+), 143 deletions(-) diff --git a/polkadot/.config/lingua.dic b/polkadot/.config/lingua.dic index 99cda05831..dcba9b0611 100644 --- a/polkadot/.config/lingua.dic +++ b/polkadot/.config/lingua.dic @@ -37,6 +37,7 @@ instantiate/B intrinsic/MS intrinsics io +jaeger/MS js keccak256/M KSM/S @@ -68,6 +69,7 @@ struct/MS subsystem/MS subsystems' taskmanager/MS +TCP teleport/RG teleportation/SM teleporter/SM @@ -76,6 +78,8 @@ testnet/MS trie/MS trustless/Y ubuntu/M +UDP +UI union/MSG unservable/B validator/SM diff --git a/polkadot/node/core/av-store/src/tests.rs b/polkadot/node/core/av-store/src/tests.rs index f97da3ff5b..1d75e2b9be 100644 --- a/polkadot/node/core/av-store/src/tests.rs +++ b/polkadot/node/core/av-store/src/tests.rs @@ -31,7 +31,7 @@ use polkadot_primitives::v1::{ }; use polkadot_node_subsystem_util::TimeoutExt; use polkadot_subsystem::{ - ActiveLeavesUpdate, errors::RuntimeApiError, JaegerSpan, messages::AllMessages, + ActiveLeavesUpdate, errors::RuntimeApiError, jaeger, messages::AllMessages, }; use polkadot_node_subsystem_test_helpers as test_helpers; use sp_keyring::Sr25519Keyring; @@ -240,7 +240,7 @@ fn runtime_api_error_does_not_stop_the_subsystem() { overseer_signal( &mut virtual_overseer, OverseerSignal::ActiveLeaves(ActiveLeavesUpdate { - activated: vec![(new_leaf, Arc::new(JaegerSpan::Disabled))].into(), + activated: vec![(new_leaf, Arc::new(jaeger::Span::Disabled))].into(), deactivated: vec![].into(), }), ).await; @@ -885,7 +885,7 @@ async fn import_leaf( overseer_signal( virtual_overseer, OverseerSignal::ActiveLeaves(ActiveLeavesUpdate { - activated: vec![(new_leaf, Arc::new(JaegerSpan::Disabled))].into(), + activated: vec![(new_leaf, Arc::new(jaeger::Span::Disabled))].into(), deactivated: vec![].into(), }), ).await; diff --git a/polkadot/node/core/backing/src/lib.rs b/polkadot/node/core/backing/src/lib.rs index 5a83bd5e6d..1ceff2d145 100644 --- a/polkadot/node/core/backing/src/lib.rs +++ b/polkadot/node/core/backing/src/lib.rs @@ -35,7 +35,8 @@ use polkadot_node_primitives::{ Statement, SignedFullStatement, ValidationResult, }; use polkadot_subsystem::{ - JaegerSpan, PerLeafSpan, + PerLeafSpan, Stage, + jaeger, messages::{ AllMessages, AvailabilityStoreMessage, CandidateBackingMessage, CandidateSelectionMessage, CandidateValidationMessage, PoVDistributionMessage, ProvisionableData, @@ -134,7 +135,7 @@ struct CandidateBackingJob { /// The collator required to author the candidate, if any. required_collator: Option, /// Spans for all candidates that are not yet backable. - unbacked_candidates: HashMap, + unbacked_candidates: HashMap, /// We issued `Seconded`, `Valid` or `Invalid` statements on about these candidates. issued_statements: HashSet, /// These candidates are undergoing validation in the background. @@ -294,7 +295,7 @@ async fn make_pov_available( candidate_hash: CandidateHash, validation_data: polkadot_primitives::v1::PersistedValidationData, expected_erasure_root: Hash, - span: Option<&JaegerSpan>, + span: Option<&jaeger::Span>, ) -> Result, Error> { let available_data = AvailableData { pov, @@ -383,7 +384,7 @@ struct BackgroundValidationParams { pov: Option>, validator_index: Option, n_validators: usize, - span: Option, + span: Option, make_command: F, } @@ -415,7 +416,11 @@ async fn validate_and_make_available( }; let v = { - let _span = span.as_ref().map(|s| s.child("request-validation")); + let _span = span.as_ref().map(|s| { + s.child_builder("request-validation") + .with_pov(&pov) + .build() + }); request_candidate_validation(&mut tx_from, candidate.descriptor.clone(), pov.clone()).await? }; @@ -513,7 +518,7 @@ impl CandidateBackingJob { #[tracing::instrument(level = "trace", skip(self), fields(subsystem = LOG_TARGET))] async fn handle_validated_candidate_command( &mut self, - parent_span: &JaegerSpan, + parent_span: &jaeger::Span, command: ValidatedCandidateCommand, ) -> Result<(), Error> { let candidate_hash = command.candidate_hash(); @@ -609,7 +614,7 @@ impl CandidateBackingJob { #[tracing::instrument(level = "trace", skip(self, parent_span, pov), fields(subsystem = LOG_TARGET))] async fn validate_and_second( &mut self, - parent_span: &JaegerSpan, + parent_span: &jaeger::Span, candidate: &CandidateReceipt, pov: Arc, ) -> Result<(), Error> { @@ -649,7 +654,7 @@ impl CandidateBackingJob { async fn sign_import_and_distribute_statement( &mut self, statement: Statement, - parent_span: &JaegerSpan, + parent_span: &jaeger::Span, ) -> Result, Error> { if let Some(signed_statement) = self.sign_statement(statement).await { self.import_statement(&signed_statement, parent_span).await?; @@ -682,7 +687,7 @@ impl CandidateBackingJob { async fn import_statement( &mut self, statement: &SignedFullStatement, - parent_span: &JaegerSpan, + parent_span: &jaeger::Span, ) -> Result, Error> { tracing::debug!( target: LOG_TARGET, @@ -745,11 +750,18 @@ impl CandidateBackingJob { } #[tracing::instrument(level = "trace", skip(self, span), fields(subsystem = LOG_TARGET))] - async fn process_msg(&mut self, span: &JaegerSpan, msg: CandidateBackingMessage) -> Result<(), Error> { + async fn process_msg(&mut self, span: &jaeger::Span, msg: CandidateBackingMessage) -> Result<(), Error> { match msg { - CandidateBackingMessage::Second(_, candidate, pov) => { + CandidateBackingMessage::Second(_relay_parent, candidate, pov) => { let _timer = self.metrics.time_process_second(); + let span = span.child_builder("second") + .with_stage(jaeger::Stage::CandidateBacking) + .with_pov(&pov) + .with_candidate(&candidate.hash()) + .with_relay_parent(&_relay_parent) + .build(); + // Sanity check that candidate is from our assignment. if Some(candidate.descriptor().para_id) != self.assignment { return Ok(()); @@ -768,8 +780,13 @@ impl CandidateBackingJob { } } } - CandidateBackingMessage::Statement(_, statement) => { + CandidateBackingMessage::Statement(_relay_parent, statement) => { let _timer = self.metrics.time_process_statement(); + let span = span.child_builder("statement") + .with_stage(jaeger::Stage::CandidateBacking) + .with_candidate(&statement.payload().candidate_hash()) + .with_relay_parent(&_relay_parent) + .build(); self.check_statement_signature(&statement)?; match self.maybe_validate_and_import(&span, statement).await { @@ -801,7 +818,7 @@ impl CandidateBackingJob { async fn kick_off_validation_work( &mut self, summary: TableSummary, - span: Option, + span: Option, ) -> Result<(), Error> { let candidate_hash = summary.candidate; @@ -851,7 +868,7 @@ impl CandidateBackingJob { #[tracing::instrument(level = "trace", skip(self, parent_span), fields(subsystem = LOG_TARGET))] async fn maybe_validate_and_import( &mut self, - parent_span: &JaegerSpan, + parent_span: &jaeger::Span, statement: SignedFullStatement, ) -> Result<(), Error> { if let Some(summary) = self.import_statement(&statement, parent_span).await? { @@ -896,7 +913,7 @@ impl CandidateBackingJob { } /// Insert or get the unbacked-span for the given candidate hash. - fn insert_or_get_unbacked_span(&mut self, parent_span: &JaegerSpan, hash: CandidateHash) -> Option<&JaegerSpan> { + fn insert_or_get_unbacked_span(&mut self, parent_span: &jaeger::Span, hash: CandidateHash) -> Option<&jaeger::Span> { if !self.backed.contains(&hash) { // only add if we don't consider this backed. let span = self.unbacked_candidates.entry(hash).or_insert_with(|| { @@ -908,16 +925,22 @@ impl CandidateBackingJob { } } - fn get_unbacked_validation_child(&mut self, parent_span: &JaegerSpan, hash: CandidateHash) -> Option { - self.insert_or_get_unbacked_span(parent_span, hash).map(|span| span.child_with_candidate("validation", &hash)) + fn get_unbacked_validation_child(&mut self, parent_span: &jaeger::Span, hash: CandidateHash) -> Option { + self.insert_or_get_unbacked_span(parent_span, hash) + .map(|span| { + span.child_builder("validation") + .with_candidate(&hash) + .with_stage(Stage::CandidateBacking) + .build() + }) } fn get_unbacked_statement_child( &mut self, - parent_span: &JaegerSpan, + parent_span: &jaeger::Span, hash: CandidateHash, validator: ValidatorIndex, - ) -> Option { + ) -> Option { self.insert_or_get_unbacked_span(parent_span, hash).map(|span| { span.child_builder("import-statement") .with_candidate(&hash) @@ -926,7 +949,7 @@ impl CandidateBackingJob { }) } - fn remove_unbacked_span(&mut self, hash: &CandidateHash) -> Option { + fn remove_unbacked_span(&mut self, hash: &CandidateHash) -> Option { self.unbacked_candidates.remove(hash) } @@ -966,7 +989,7 @@ impl util::JobTrait for CandidateBackingJob { #[tracing::instrument(skip(span, keystore, metrics, rx_to, tx_from), fields(subsystem = LOG_TARGET))] fn run( parent: Hash, - span: Arc, + span: Arc, keystore: SyncCryptoStorePtr, metrics: Metrics, rx_to: mpsc::Receiver, @@ -1379,7 +1402,7 @@ mod tests { virtual_overseer.send(FromOverseer::Signal( OverseerSignal::ActiveLeaves(ActiveLeavesUpdate::start_work( test_state.relay_parent, - Arc::new(JaegerSpan::Disabled), + Arc::new(jaeger::Span::Disabled), ))) ).await; diff --git a/polkadot/node/core/bitfield-signing/src/lib.rs b/polkadot/node/core/bitfield-signing/src/lib.rs index 1c5721a42d..f337db4091 100644 --- a/polkadot/node/core/bitfield-signing/src/lib.rs +++ b/polkadot/node/core/bitfield-signing/src/lib.rs @@ -23,7 +23,7 @@ use futures::{channel::{mpsc, oneshot}, lock::Mutex, prelude::*, future, Future}; use sp_keystore::{Error as KeystoreError, SyncCryptoStorePtr}; use polkadot_node_subsystem::{ - jaeger, PerLeafSpan, JaegerSpan, + jaeger, PerLeafSpan, messages::{ AllMessages, AvailabilityStoreMessage, BitfieldDistributionMessage, BitfieldSigningMessage, RuntimeApiMessage, RuntimeApiRequest, @@ -75,7 +75,7 @@ async fn get_core_availability( core: CoreState, validator_idx: ValidatorIndex, sender: &Mutex<&mut mpsc::Sender>, - span: &jaeger::JaegerSpan, + span: &jaeger::Span, ) -> Result { if let CoreState::Occupied(core) = core { let _span = span.child("query-chunk-availability"); @@ -132,7 +132,7 @@ async fn get_availability_cores( #[tracing::instrument(level = "trace", skip(sender, span), fields(subsystem = LOG_TARGET))] async fn construct_availability_bitfield( relay_parent: Hash, - span: &jaeger::JaegerSpan, + span: &jaeger::Span, validator_idx: ValidatorIndex, sender: &mut mpsc::Sender, ) -> Result { @@ -218,7 +218,7 @@ impl JobTrait for BitfieldSigningJob { #[tracing::instrument(skip(span, keystore, metrics, _receiver, sender), fields(subsystem = LOG_TARGET))] fn run( relay_parent: Hash, - span: Arc, + span: Arc, keystore: Self::RunArgs, metrics: Self::Metrics, _receiver: mpsc::Receiver, @@ -321,7 +321,7 @@ mod tests { let future = construct_availability_bitfield( relay_parent, - &jaeger::JaegerSpan::Disabled, + &jaeger::Span::Disabled, validator_index, &mut sender, ).fuse(); diff --git a/polkadot/node/core/candidate-selection/src/lib.rs b/polkadot/node/core/candidate-selection/src/lib.rs index daee7d530d..58ef93fb9a 100644 --- a/polkadot/node/core/candidate-selection/src/lib.rs +++ b/polkadot/node/core/candidate-selection/src/lib.rs @@ -25,7 +25,7 @@ use futures::{ }; use sp_keystore::SyncCryptoStorePtr; use polkadot_node_subsystem::{ - jaeger, JaegerSpan, PerLeafSpan, + jaeger, PerLeafSpan, errors::ChainApiError, messages::{ AllMessages, CandidateBackingMessage, CandidateSelectionMessage, CollatorProtocolMessage, @@ -96,7 +96,7 @@ impl JobTrait for CandidateSelectionJob { #[tracing::instrument(skip(keystore, metrics, receiver, sender), fields(subsystem = LOG_TARGET))] fn run( relay_parent: Hash, - span: Arc, + span: Arc, keystore: Self::RunArgs, metrics: Self::Metrics, receiver: mpsc::Receiver, @@ -104,7 +104,10 @@ impl JobTrait for CandidateSelectionJob { ) -> Pin> + Send>> { let span = PerLeafSpan::new(span, "candidate-selection"); async move { - let _span = span.child("query-runtime"); + let _span = span.child_builder("query-runtime") + .with_relay_parent(&relay_parent) + .with_stage(jaeger::Stage::CandidateSelection) + .build(); let (groups, cores) = futures::try_join!( try_runtime_api!(request_validator_groups(relay_parent, &mut sender).await), try_runtime_api!(request_from_runtime( @@ -118,7 +121,10 @@ impl JobTrait for CandidateSelectionJob { let cores = try_runtime_api!(cores); drop(_span); - let _span = span.child("find-assignment"); + let _span = span.child_builder("find-assignment") + .with_relay_parent(&relay_parent) + .with_stage(jaeger::Stage::CandidateSelection) + .build(); let n_cores = cores.len(); @@ -172,8 +178,11 @@ impl CandidateSelectionJob { } } - async fn run_loop(&mut self, span: &jaeger::JaegerSpan) -> Result<(), Error> { - let span = span.child("run-loop"); + async fn run_loop(&mut self, span: &jaeger::Span) -> Result<(), Error> { + let span = span.child_builder("run-loop") + .with_stage(jaeger::Stage::CandidateSelection) + .build(); + loop { match self.receiver.next().await { Some(CandidateSelectionMessage::Collation( @@ -185,14 +194,22 @@ impl CandidateSelectionJob { self.handle_collation(relay_parent, para_id, collator_id).await; } Some(CandidateSelectionMessage::Invalid( - _, + _relay_parent, candidate_receipt, )) => { - let _span = span.child("handle-invalid"); + let _span = span.child_builder("handle-invalid") + .with_stage(jaeger::Stage::CandidateSelection) + .with_candidate(&candidate_receipt.hash()) + .with_relay_parent(&_relay_parent) + .build(); self.handle_invalid(candidate_receipt).await; } - Some(CandidateSelectionMessage::Seconded(_, statement)) => { - let _span = span.child("handle-seconded"); + Some(CandidateSelectionMessage::Seconded(_relay_parent, statement)) => { + let _span = span.child_builder("handle-seconded") + .with_stage(jaeger::Stage::CandidateSelection) + .with_candidate(&statement.payload().candidate_hash()) + .with_relay_parent(&_relay_parent) + .build(); self.handle_seconded(statement).await; } None => break, @@ -514,7 +531,7 @@ mod tests { }; preconditions(&mut job); - let span = jaeger::JaegerSpan::Disabled; + let span = jaeger::Span::Disabled; let (_, job_result) = futures::executor::block_on(future::join( test(to_job_tx, from_job_rx), job.run_loop(&span), diff --git a/polkadot/node/core/provisioner/src/lib.rs b/polkadot/node/core/provisioner/src/lib.rs index 4b85f6ec5b..da7f040699 100644 --- a/polkadot/node/core/provisioner/src/lib.rs +++ b/polkadot/node/core/provisioner/src/lib.rs @@ -25,7 +25,7 @@ use futures::{ prelude::*, }; use polkadot_node_subsystem::{ - errors::{ChainApiError, RuntimeApiError}, PerLeafSpan, JaegerSpan, + errors::{ChainApiError, RuntimeApiError}, PerLeafSpan, jaeger, messages::{ AllMessages, CandidateBackingMessage, ChainApiMessage, ProvisionableData, ProvisionerInherentData, ProvisionerMessage, @@ -141,7 +141,7 @@ impl JobTrait for ProvisioningJob { #[tracing::instrument(skip(span, _run_args, metrics, receiver, sender), fields(subsystem = LOG_TARGET))] fn run( relay_parent: Hash, - span: Arc, + span: Arc, _run_args: Self::RunArgs, metrics: Self::Metrics, receiver: mpsc::Receiver, diff --git a/polkadot/node/jaeger/src/lib.rs b/polkadot/node/jaeger/src/lib.rs index cc264609f7..1c9985da74 100644 --- a/polkadot/node/jaeger/src/lib.rs +++ b/polkadot/node/jaeger/src/lib.rs @@ -125,8 +125,8 @@ impl JaegerConfigBuilder { /// This just works as auxiliary structure to easily store both. #[derive(Debug)] pub struct PerLeafSpan { - leaf_span: Arc, - span: JaegerSpan, + leaf_span: Arc, + span: Span, } impl PerLeafSpan { @@ -135,7 +135,7 @@ impl PerLeafSpan { /// Takes the `leaf_span` that is created by the overseer per leaf and a name for a child span. /// Both will be stored in this object, while the child span is implicitly accessible by using the /// [`Deref`](std::ops::Deref) implementation. - pub fn new(leaf_span: Arc, name: &'static str) -> Self { + pub fn new(leaf_span: Arc, name: &'static str) -> Self { let span = leaf_span.child(name); Self { @@ -145,16 +145,16 @@ impl PerLeafSpan { } /// Returns the leaf span. - pub fn leaf_span(&self) -> &Arc { + pub fn leaf_span(&self) -> &Arc { &self.leaf_span } } /// Returns a reference to the child span. impl std::ops::Deref for PerLeafSpan { - type Target = JaegerSpan; + type Target = Span; - fn deref(&self) -> &JaegerSpan { + fn deref(&self) -> &Span { &self.span } } @@ -169,15 +169,24 @@ impl std::ops::Deref for PerLeafSpan { #[repr(u8)] #[non_exhaustive] pub enum Stage { - Backing = 1, - Availability = 2, - // TODO expand this + CandidateSelection = 1, + CandidateBacking = 2, + StatementDistribution = 3, + PoVDistribution = 4, + AvailabilityDistribution = 5, + AvailabilityRecovery = 6, + BitfieldDistribution = 7, + // Expand as needed, numbers should be ascending according to the stage + // through the inclusion pipeline, or according to the descriptions + // in [the path of a para chain block] + // (https://polkadot.network/the-path-of-a-parachain-block/) + // see [issue](https://github.com/paritytech/polkadot/issues/2389) } /// Builder pattern for children and root spans to unify /// information annotations. pub struct SpanBuilder { - span: JaegerSpan, + span: Span, } impl SpanBuilder { @@ -196,8 +205,8 @@ impl SpanBuilder { /// Attach a candidate stage. /// Should always come with a `CandidateHash`. #[inline(always)] - pub fn with_candidate_stage(mut self, stage: Stage) -> Self { - self.span.add_string_tag("candidate-stage", &format!("{}", stage as u8)); + pub fn with_stage(mut self, stage: Stage) -> Self { + self.span.add_stage(stage); self } @@ -228,9 +237,15 @@ impl SpanBuilder { self } + #[inline(always)] + pub fn with_pov(mut self, pov: &PoV) -> Self { + self.span.add_pov(pov); + self + } + /// Complete construction. #[inline(always)] - pub fn build(self) -> JaegerSpan { + pub fn build(self) -> Span { self.span } } @@ -239,14 +254,14 @@ impl SpanBuilder { /// A wrapper type for a span. /// /// Handles running with and without jaeger. -pub enum JaegerSpan { +pub enum Span { /// Running with jaeger being enabled. Enabled(mick_jaeger::Span), /// Running with jaeger disabled. Disabled, } -impl JaegerSpan { +impl Span { /// Derive a child span from `self`. pub fn child(&self, name: &'static str) -> Self { match self { @@ -276,6 +291,18 @@ impl JaegerSpan { self.child_builder(name).with_candidate(candidate_hash).build() } + /// Add candidate stage annotation. + pub fn add_stage(&mut self, stage: Stage) { + self.add_string_tag("candidate-stage", &format!("{}", stage as u8)); + } + + pub fn add_pov(&mut self, pov: &PoV) { + if self.is_enabled() { + // avoid computing the pov hash if jaeger is not enabled + self.add_string_tag("pov", &format!("{:?}", pov.hash())); + } + } + /// Add an additional tag to the span. pub fn add_string_tag(&mut self, tag: &str, value: &str) { match self { @@ -291,15 +318,24 @@ impl JaegerSpan { _ => {}, } } + + /// Helper to check whether jaeger is enabled + /// in order to avoid computational overhead. + pub const fn is_enabled(&self) -> bool { + match self { + Span::Enabled(_) => true, + _ => false, + } + } } -impl std::fmt::Debug for JaegerSpan { +impl std::fmt::Debug for Span { fn fmt(&self, f: &mut std::fmt::Formatter) -> std::fmt::Result { write!(f, "") } } -impl From> for JaegerSpan { +impl From> for Span { fn from(src: Option) -> Self { if let Some(span) = src { Self::Enabled(span) @@ -309,15 +345,15 @@ impl From> for JaegerSpan { } } -impl From for JaegerSpan { +impl From for Span { fn from(src: mick_jaeger::Span) -> Self { Self::Enabled(src) } } /// Shortcut for [`hash_span`] with the hash of the `Candidate` block. -pub fn candidate_hash_span(candidate_hash: &CandidateHash, span_name: &'static str) -> JaegerSpan { - let mut span: JaegerSpan = INSTANCE.read_recursive() +pub fn candidate_hash_span(candidate_hash: &CandidateHash, span_name: &'static str) -> Span { + let mut span: Span = INSTANCE.read_recursive() .span(|| { candidate_hash.0 }, span_name).into(); span.add_string_tag("candidate-hash", &format!("{:?}", candidate_hash.0)); @@ -326,8 +362,12 @@ pub fn candidate_hash_span(candidate_hash: &CandidateHash, span_name: &'static s /// Shortcut for [`hash_span`] with the hash of the `PoV`. #[inline(always)] -pub fn pov_span(pov: &PoV, span_name: &'static str) -> JaegerSpan { - INSTANCE.read_recursive().span(|| { pov.hash() }, span_name).into() +pub fn pov_span(pov: &PoV, span_name: &'static str) -> Span { + let mut span: Span = INSTANCE.read_recursive() + .span(|| { pov.hash() }, span_name).into(); + + span.add_pov(pov); + span } /// Creates a `Span` referring to the given hash. All spans created with [`hash_span`] with the @@ -335,8 +375,8 @@ pub fn pov_span(pov: &PoV, span_name: &'static str) -> JaegerSpan { /// /// This span automatically has the `relay-parent` tag set. #[inline(always)] -pub fn hash_span(hash: &Hash, span_name: &'static str) -> JaegerSpan { - let mut span: JaegerSpan = INSTANCE.read_recursive().span(|| { *hash }, span_name).into(); +pub fn hash_span(hash: &Hash, span_name: &'static str) -> Span { + let mut span: Span = INSTANCE.read_recursive().span(|| { *hash }, span_name).into(); span.add_string_tag("relay-parent", &format!("{:?}", hash)); span } diff --git a/polkadot/node/network/availability-distribution/src/lib.rs b/polkadot/node/network/availability-distribution/src/lib.rs index e8caf0371f..798bc2570d 100644 --- a/polkadot/node/network/availability-distribution/src/lib.rs +++ b/polkadot/node/network/availability-distribution/src/lib.rs @@ -45,7 +45,7 @@ use polkadot_subsystem::messages::{ NetworkBridgeMessage, RuntimeApiMessage, RuntimeApiRequest, NetworkBridgeEvent }; use polkadot_subsystem::{ - jaeger, errors::{ChainApiError, RuntimeApiError}, PerLeafSpan, + jaeger, errors::{ChainApiError, RuntimeApiError}, PerLeafSpan, Stage, ActiveLeavesUpdate, FromOverseer, OverseerSignal, SpawnedSubsystem, Subsystem, SubsystemContext, SubsystemError, }; use std::collections::{HashMap, HashSet}; @@ -166,7 +166,7 @@ struct PerCandidate { live_in: HashSet, /// A Jaeger span relating to this candidate. - span: jaeger::JaegerSpan, + span: jaeger::Span, } impl PerCandidate { @@ -185,7 +185,7 @@ impl PerCandidate { fn drop_span_after_own_availability(&mut self) { if let Some(validator_index) = self.validator_index { if self.message_vault.contains_key(&validator_index) { - self.span = jaeger::JaegerSpan::Disabled; + self.span = jaeger::Span::Disabled; } } } @@ -251,7 +251,7 @@ impl ProtocolState { span: if validator_index.is_some() { jaeger::candidate_hash_span(&receipt_hash, "pending-availability") } else { - jaeger::JaegerSpan::Disabled + jaeger::Span::Disabled }, }) } else { @@ -262,7 +262,10 @@ impl ProtocolState { }; // Create some span that will make it able to switch between the candidate and relay parent span. - let span = per_relay_parent.span.child_with_candidate("live-candidate", &receipt_hash); + let span = per_relay_parent.span.child_builder("live-candidate") + .with_candidate(&receipt_hash) + .with_stage(Stage::AvailabilityDistribution) + .build(); candidate_entry.span.add_follows_from(&span); candidate_entry.live_in.insert(relay_parent); } diff --git a/polkadot/node/network/availability-distribution/src/tests.rs b/polkadot/node/network/availability-distribution/src/tests.rs index 59ae6ebc2a..fc3f653e44 100644 --- a/polkadot/node/network/availability-distribution/src/tests.rs +++ b/polkadot/node/network/availability-distribution/src/tests.rs @@ -59,7 +59,7 @@ fn make_per_candidate() -> PerCandidate { validators: Vec::new(), validator_index: None, descriptor: Default::default(), - span: jaeger::JaegerSpan::Disabled, + span: jaeger::Span::Disabled, } } @@ -1018,13 +1018,13 @@ fn clean_up_receipts_cache_unions_ancestors_and_view() { state.per_relay_parent.insert(hash_a, PerRelayParent { ancestors: vec![hash_b], live_candidates: HashSet::new(), - span: PerLeafSpan::new(Arc::new(jaeger::JaegerSpan::Disabled), "test"), + span: PerLeafSpan::new(Arc::new(jaeger::Span::Disabled), "test"), }); state.per_relay_parent.insert(hash_c, PerRelayParent { ancestors: Vec::new(), live_candidates: HashSet::new(), - span: PerLeafSpan::new(Arc::new(jaeger::JaegerSpan::Disabled), "test"), + span: PerLeafSpan::new(Arc::new(jaeger::Span::Disabled), "test"), }); state.clean_up_live_under_cache(); @@ -1048,13 +1048,13 @@ fn remove_relay_parent_only_removes_per_candidate_if_final() { state.per_relay_parent.insert(hash_a, PerRelayParent { ancestors: vec![], live_candidates: std::iter::once(candidate_hash_a).collect(), - span: PerLeafSpan::new(Arc::new(jaeger::JaegerSpan::Disabled), "test"), + span: PerLeafSpan::new(Arc::new(jaeger::Span::Disabled), "test"), }); state.per_relay_parent.insert(hash_b, PerRelayParent { ancestors: vec![], live_candidates: std::iter::once(candidate_hash_a).collect(), - span: PerLeafSpan::new(Arc::new(jaeger::JaegerSpan::Disabled), "test"), + span: PerLeafSpan::new(Arc::new(jaeger::Span::Disabled), "test"), }); state.per_candidate.insert(candidate_hash_a, { @@ -1099,7 +1099,7 @@ fn add_relay_parent_includes_all_live_candidates() { None, candidates, vec![ancestor_a], - PerLeafSpan::new(Arc::new(jaeger::JaegerSpan::Disabled), "test"), + PerLeafSpan::new(Arc::new(jaeger::Span::Disabled), "test"), ); assert!( diff --git a/polkadot/node/network/availability-recovery/src/lib.rs b/polkadot/node/network/availability-recovery/src/lib.rs index 114bbd48a4..db57f18643 100644 --- a/polkadot/node/network/availability-recovery/src/lib.rs +++ b/polkadot/node/network/availability-recovery/src/lib.rs @@ -37,6 +37,7 @@ use polkadot_subsystem::{ SubsystemContext, SubsystemResult, SubsystemError, Subsystem, SpawnedSubsystem, FromOverseer, OverseerSignal, ActiveLeavesUpdate, errors::RecoveryError, + jaeger, messages::{ AvailabilityStoreMessage, AvailabilityRecoveryMessage, AllMessages, NetworkBridgeMessage, NetworkBridgeEvent, @@ -664,6 +665,9 @@ async fn handle_recover( ) -> error::Result<()> { let candidate_hash = receipt.hash(); + let mut span = jaeger::candidate_hash_span(&candidate_hash, "availbility-recovery"); + span.add_stage(jaeger::Stage::AvailabilityRecovery); + if let Some(result) = state.availability_lru.get(&candidate_hash) { if let Err(e) = response_sender.send(result.clone()) { tracing::warn!( @@ -680,12 +684,14 @@ async fn handle_recover( return Ok(()); } + let _span = span.child("not-cached"); let session_info = request_session_info_ctx( state.live_block_hash, session_index, ctx, ).await?.await.map_err(error::Error::CanceledSessionInfo)??; + let _span = span.child("session-info-ctx-received"); match session_info { Some(session_info) => { launch_interaction( diff --git a/polkadot/node/network/availability-recovery/src/tests.rs b/polkadot/node/network/availability-recovery/src/tests.rs index 8a7c255ce9..40b708d387 100644 --- a/polkadot/node/network/availability-recovery/src/tests.rs +++ b/polkadot/node/network/availability-recovery/src/tests.rs @@ -30,7 +30,7 @@ use polkadot_primitives::v1::{ use polkadot_erasure_coding::{branches, obtain_chunks_v1 as obtain_chunks}; use polkadot_node_subsystem_util::TimeoutExt; use polkadot_subsystem_testhelpers as test_helpers; -use polkadot_subsystem::{messages::{RuntimeApiMessage, RuntimeApiRequest, NetworkBridgeEvent}, JaegerSpan}; +use polkadot_subsystem::{messages::{RuntimeApiMessage, RuntimeApiRequest, NetworkBridgeEvent}, jaeger}; type VirtualOverseer = test_helpers::TestSubsystemContextHandle; @@ -537,7 +537,7 @@ fn availability_is_recovered_from_chunks_if_no_group_provided() { overseer_signal( &mut virtual_overseer, OverseerSignal::ActiveLeaves(ActiveLeavesUpdate { - activated: smallvec![(test_state.current.clone(), Arc::new(JaegerSpan::Disabled))], + activated: smallvec![(test_state.current.clone(), Arc::new(jaeger::Span::Disabled))], deactivated: smallvec![], }), ).await; @@ -601,7 +601,7 @@ fn availability_is_recovered_from_chunks_even_if_backing_group_supplied_if_chunk overseer_signal( &mut virtual_overseer, OverseerSignal::ActiveLeaves(ActiveLeavesUpdate { - activated: smallvec![(test_state.current.clone(), Arc::new(JaegerSpan::Disabled))], + activated: smallvec![(test_state.current.clone(), Arc::new(jaeger::Span::Disabled))], deactivated: smallvec![], }), ).await; @@ -664,7 +664,7 @@ fn bad_merkle_path_leads_to_recovery_error() { overseer_signal( &mut virtual_overseer, OverseerSignal::ActiveLeaves(ActiveLeavesUpdate { - activated: smallvec![(test_state.current.clone(), Arc::new(JaegerSpan::Disabled))], + activated: smallvec![(test_state.current.clone(), Arc::new(jaeger::Span::Disabled))], deactivated: smallvec![], }), ).await; @@ -719,7 +719,7 @@ fn wrong_chunk_index_leads_to_recovery_error() { overseer_signal( &mut virtual_overseer, OverseerSignal::ActiveLeaves(ActiveLeavesUpdate { - activated: smallvec![(test_state.current.clone(), Arc::new(JaegerSpan::Disabled))], + activated: smallvec![(test_state.current.clone(), Arc::new(jaeger::Span::Disabled))], deactivated: smallvec![], }), ).await; @@ -790,7 +790,7 @@ fn invalid_erasure_coding_leads_to_invalid_error() { overseer_signal( &mut virtual_overseer, OverseerSignal::ActiveLeaves(ActiveLeavesUpdate { - activated: smallvec![(test_state.current.clone(), Arc::new(JaegerSpan::Disabled))], + activated: smallvec![(test_state.current.clone(), Arc::new(jaeger::Span::Disabled))], deactivated: smallvec![], }), ).await; @@ -831,7 +831,7 @@ fn fast_path_backing_group_recovers() { overseer_signal( &mut virtual_overseer, OverseerSignal::ActiveLeaves(ActiveLeavesUpdate { - activated: smallvec![(test_state.current.clone(), Arc::new(JaegerSpan::Disabled))], + activated: smallvec![(test_state.current.clone(), Arc::new(jaeger::Span::Disabled))], deactivated: smallvec![], }), ).await; @@ -876,7 +876,7 @@ fn wrong_data_from_fast_path_peer_leads_to_punishment() { overseer_signal( &mut virtual_overseer, OverseerSignal::ActiveLeaves(ActiveLeavesUpdate { - activated: smallvec![(test_state.current.clone(), Arc::new(JaegerSpan::Disabled))], + activated: smallvec![(test_state.current.clone(), Arc::new(jaeger::Span::Disabled))], deactivated: smallvec![], }), ).await; @@ -921,7 +921,7 @@ fn no_answers_in_fast_path_causes_chunk_requests() { overseer_signal( &mut virtual_overseer, OverseerSignal::ActiveLeaves(ActiveLeavesUpdate { - activated: smallvec![(test_state.current.clone(), Arc::new(JaegerSpan::Disabled))], + activated: smallvec![(test_state.current.clone(), Arc::new(jaeger::Span::Disabled))], deactivated: smallvec![], }), ).await; diff --git a/polkadot/node/network/bitfield-distribution/src/lib.rs b/polkadot/node/network/bitfield-distribution/src/lib.rs index 9413d691e7..ee36b68834 100644 --- a/polkadot/node/network/bitfield-distribution/src/lib.rs +++ b/polkadot/node/network/bitfield-distribution/src/lib.rs @@ -29,6 +29,7 @@ use polkadot_subsystem::messages::*; use polkadot_subsystem::{ PerLeafSpan, ActiveLeavesUpdate, FromOverseer, OverseerSignal, SpawnedSubsystem, Subsystem, SubsystemContext, SubsystemResult, + jaeger, }; use polkadot_node_subsystem_util::metrics::{self, prometheus}; use polkadot_primitives::v1::{Hash, SignedAvailabilityBitfield, SigningContext, ValidatorId}; @@ -402,6 +403,7 @@ where .child_builder("msg-received") .with_peer_id(&origin) .with_claimed_validator_index(message.signed_availability.validator_index()) + .with_stage(jaeger::Stage::BitfieldDistribution) .build(); let validator_set = &job_data.validator_set; @@ -775,7 +777,7 @@ mod test { use std::time::Duration; use assert_matches::assert_matches; use polkadot_node_network_protocol::{view, ObservedRole, our_view}; - use polkadot_subsystem::JaegerSpan; + use polkadot_subsystem::jaeger; macro_rules! launch { ($fut:expr) => { @@ -807,7 +809,7 @@ mod test { }, message_received_from_peer: hashmap!{}, message_sent_to_peer: hashmap!{}, - span: PerLeafSpan::new(Arc::new(JaegerSpan::Disabled), "test"), + span: PerLeafSpan::new(Arc::new(jaeger::Span::Disabled), "test"), }, }, peer_views: peers @@ -841,7 +843,7 @@ mod test { one_per_validator: hashmap!{}, message_received_from_peer: hashmap!{}, message_sent_to_peer: hashmap!{}, - span: PerLeafSpan::new(Arc::new(JaegerSpan::Disabled), "test"), + span: PerLeafSpan::new(Arc::new(jaeger::Span::Disabled), "test"), }) }).collect(); diff --git a/polkadot/node/network/bridge/src/lib.rs b/polkadot/node/network/bridge/src/lib.rs index 945a56a6b0..9c4414994e 100644 --- a/polkadot/node/network/bridge/src/lib.rs +++ b/polkadot/node/network/bridge/src/lib.rs @@ -25,7 +25,7 @@ use futures::prelude::*; use polkadot_subsystem::{ ActiveLeavesUpdate, Subsystem, SubsystemContext, SpawnedSubsystem, SubsystemError, - SubsystemResult, JaegerSpan, + SubsystemResult, jaeger, }; use polkadot_subsystem::messages::{ NetworkBridgeMessage, AllMessages, AvailabilityDistributionMessage, @@ -155,7 +155,7 @@ where let mut event_stream = bridge.network_service.event_stream().fuse(); // Most recent heads are at the back. - let mut live_heads: Vec<(Hash, Arc)> = Vec::with_capacity(MAX_VIEW_HEADS); + let mut live_heads: Vec<(Hash, Arc)> = Vec::with_capacity(MAX_VIEW_HEADS); let mut local_view = View::default(); let mut finalized_number = 0; @@ -419,7 +419,7 @@ fn construct_view(live_heads: impl DoubleEndedIterator, finalized_n async fn update_our_view( net: &mut impl Network, ctx: &mut impl SubsystemContext, - live_heads: &[(Hash, Arc)], + live_heads: &[(Hash, Arc)], local_view: &mut View, finalized_number: BlockNumber, validation_peers: &HashMap, @@ -873,7 +873,7 @@ mod tests { let head = Hash::repeat_byte(1); virtual_overseer.send( FromOverseer::Signal(OverseerSignal::ActiveLeaves( - ActiveLeavesUpdate::start_work(head, Arc::new(JaegerSpan::Disabled)), + ActiveLeavesUpdate::start_work(head, Arc::new(jaeger::Span::Disabled)), )) ).await; @@ -928,7 +928,7 @@ mod tests { virtual_overseer.send( FromOverseer::Signal(OverseerSignal::ActiveLeaves( - ActiveLeavesUpdate::start_work(hash_a, Arc::new(JaegerSpan::Disabled)), + ActiveLeavesUpdate::start_work(hash_a, Arc::new(jaeger::Span::Disabled)), )) ).await; @@ -990,7 +990,7 @@ mod tests { // This should trigger the view update to our peers. virtual_overseer.send( FromOverseer::Signal(OverseerSignal::ActiveLeaves( - ActiveLeavesUpdate::start_work(hash_a, Arc::new(JaegerSpan::Disabled)), + ActiveLeavesUpdate::start_work(hash_a, Arc::new(jaeger::Span::Disabled)), )) ).await; @@ -1180,7 +1180,7 @@ mod tests { virtual_overseer.send( FromOverseer::Signal(OverseerSignal::ActiveLeaves( - ActiveLeavesUpdate::start_work(hash_a, Arc::new(JaegerSpan::Disabled)), + ActiveLeavesUpdate::start_work(hash_a, Arc::new(jaeger::Span::Disabled)), )) ).await; @@ -1372,7 +1372,7 @@ mod tests { ).await; virtual_overseer.send( FromOverseer::Signal(OverseerSignal::ActiveLeaves( - ActiveLeavesUpdate::start_work(hash_b, Arc::new(JaegerSpan::Disabled)), + ActiveLeavesUpdate::start_work(hash_b, Arc::new(jaeger::Span::Disabled)), )) ).await; diff --git a/polkadot/node/network/collator-protocol/src/collator_side.rs b/polkadot/node/network/collator-protocol/src/collator_side.rs index 83fb9e6e5a..f69b5df15b 100644 --- a/polkadot/node/network/collator-protocol/src/collator_side.rs +++ b/polkadot/node/network/collator-protocol/src/collator_side.rs @@ -869,7 +869,7 @@ mod tests { ValidatorIndex, GroupRotationInfo, AuthorityDiscoveryId, SessionIndex, SessionInfo, }; - use polkadot_subsystem::{ActiveLeavesUpdate, messages::{RuntimeApiMessage, RuntimeApiRequest}, JaegerSpan}; + use polkadot_subsystem::{ActiveLeavesUpdate, messages::{RuntimeApiMessage, RuntimeApiRequest}, jaeger}; use polkadot_node_subsystem_util::TimeoutExt; use polkadot_subsystem_testhelpers as test_helpers; use polkadot_node_network_protocol::{view, our_view}; @@ -1125,7 +1125,7 @@ mod tests { overseer_signal( virtual_overseer, OverseerSignal::ActiveLeaves(ActiveLeavesUpdate { - activated: [(test_state.relay_parent, Arc::new(JaegerSpan::Disabled))][..].into(), + activated: [(test_state.relay_parent, Arc::new(jaeger::Span::Disabled))][..].into(), deactivated: [][..].into(), }), ).await; diff --git a/polkadot/node/network/collator-protocol/src/validator_side.rs b/polkadot/node/network/collator-protocol/src/validator_side.rs index b6b3635b54..a3a8216e5f 100644 --- a/polkadot/node/network/collator-protocol/src/validator_side.rs +++ b/polkadot/node/network/collator-protocol/src/validator_side.rs @@ -28,7 +28,7 @@ use polkadot_primitives::v1::{ Id as ParaId, CandidateReceipt, CollatorId, Hash, PoV, }; use polkadot_subsystem::{ - jaeger, PerLeafSpan, JaegerSpan, + jaeger, PerLeafSpan, FromOverseer, OverseerSignal, SubsystemContext, messages::{ AllMessages, CandidateSelectionMessage, CollatorProtocolMessage, NetworkBridgeMessage, @@ -598,7 +598,7 @@ async fn handle_our_view_change( ) -> Result<()> { let old_view = std::mem::replace(&mut state.view, view); - let added: HashMap> = state.view + let added: HashMap> = state.view .span_per_head() .iter() .filter(|v| !old_view.contains(&v.0)) diff --git a/polkadot/node/network/pov-distribution/src/lib.rs b/polkadot/node/network/pov-distribution/src/lib.rs index ac650fd784..137009d014 100644 --- a/polkadot/node/network/pov-distribution/src/lib.rs +++ b/polkadot/node/network/pov-distribution/src/lib.rs @@ -28,6 +28,7 @@ use polkadot_primitives::v1::{ use polkadot_subsystem::{ ActiveLeavesUpdate, OverseerSignal, SubsystemContext, SubsystemResult, SubsystemError, Subsystem, FromOverseer, SpawnedSubsystem, + jaeger, messages::{ PoVDistributionMessage, AllMessages, NetworkBridgeMessage, NetworkBridgeEvent, }, @@ -154,7 +155,11 @@ async fn handle_signal( OverseerSignal::ActiveLeaves(ActiveLeavesUpdate { activated, deactivated }) => { let _timer = state.metrics.time_handle_signal(); - for (relay_parent, _span) in activated { + for (relay_parent, span) in activated { + let _span = span.child_builder("pov-dist") + .with_stage(jaeger::Stage::PoVDistribution) + .build(); + match request_validators_ctx(relay_parent, ctx).await { Ok(vals_rx) => { let n_validators = match vals_rx.await? { diff --git a/polkadot/node/network/pov-distribution/src/tests.rs b/polkadot/node/network/pov-distribution/src/tests.rs index 96822e7946..8cf37dfad8 100644 --- a/polkadot/node/network/pov-distribution/src/tests.rs +++ b/polkadot/node/network/pov-distribution/src/tests.rs @@ -28,7 +28,7 @@ use polkadot_primitives::v1::{ AuthorityDiscoveryId, BlockData, CoreState, GroupRotationInfo, Id as ParaId, ScheduledCore, ValidatorIndex, SessionIndex, SessionInfo, }; -use polkadot_subsystem::{messages::{RuntimeApiMessage, RuntimeApiRequest}, JaegerSpan}; +use polkadot_subsystem::{messages::{RuntimeApiMessage, RuntimeApiRequest}, jaeger}; use polkadot_node_subsystem_test_helpers as test_helpers; use polkadot_node_subsystem_util::TimeoutExt; use polkadot_node_network_protocol::{view, our_view}; @@ -277,7 +277,7 @@ fn ask_validators_for_povs() { overseer_signal( &mut virtual_overseer, OverseerSignal::ActiveLeaves(ActiveLeavesUpdate { - activated: [(test_state.relay_parent, Arc::new(JaegerSpan::Disabled))][..].into(), + activated: [(test_state.relay_parent, Arc::new(jaeger::Span::Disabled))][..].into(), deactivated: [][..].into(), }), ).await; @@ -449,7 +449,7 @@ fn ask_validators_for_povs() { overseer_signal( &mut virtual_overseer, OverseerSignal::ActiveLeaves(ActiveLeavesUpdate { - activated: [(next_leaf, Arc::new(JaegerSpan::Disabled))][..].into(), + activated: [(next_leaf, Arc::new(jaeger::Span::Disabled))][..].into(), deactivated: [current.clone()][..].into(), }) ).await; diff --git a/polkadot/node/network/protocol/src/lib.rs b/polkadot/node/network/protocol/src/lib.rs index 62f9f2a1d3..2f7547f2de 100644 --- a/polkadot/node/network/protocol/src/lib.rs +++ b/polkadot/node/network/protocol/src/lib.rs @@ -25,7 +25,7 @@ use std::{fmt, collections::HashMap}; pub use sc_network::PeerId; #[doc(hidden)] -pub use polkadot_node_jaeger::JaegerSpan; +pub use polkadot_node_jaeger as jaeger; #[doc(hidden)] pub use std::sync::Arc; @@ -118,16 +118,16 @@ macro_rules! impl_try_from { /// Specialized wrapper around [`View`]. /// -/// Besides the access to the view itself, it also gives access to the [`JaegerSpan`] per leave/head. +/// Besides the access to the view itself, it also gives access to the [`jaeger::Span`] per leave/head. #[derive(Debug, Clone, Default)] pub struct OurView { view: View, - span_per_head: HashMap>, + span_per_head: HashMap>, } impl OurView { /// Creates a new instance. - pub fn new(heads: impl IntoIterator)>, finalized_number: BlockNumber) -> Self { + pub fn new(heads: impl IntoIterator)>, finalized_number: BlockNumber) -> Self { let state_per_head = heads.into_iter().collect::>(); Self { @@ -142,7 +142,7 @@ impl OurView { /// Returns the span per head map. /// /// For each head there exists one span in this map. - pub fn span_per_head(&self) -> &HashMap> { + pub fn span_per_head(&self) -> &HashMap> { &self.span_per_head } } @@ -161,7 +161,7 @@ impl std::ops::Deref for OurView { } } -/// Construct a new [`OurView`] with the given chain heads, finalized number 0 and disabled [`JaegerSpan`]'s. +/// Construct a new [`OurView`] with the given chain heads, finalized number 0 and disabled [`jaeger::Span`]'s. /// /// NOTE: Use for tests only. /// @@ -176,7 +176,7 @@ impl std::ops::Deref for OurView { macro_rules! our_view { ( $( $hash:expr ),* $(,)? ) => { $crate::OurView::new( - vec![ $( $hash.clone() ),* ].into_iter().map(|h| (h, $crate::Arc::new($crate::JaegerSpan::Disabled))), + vec![ $( $hash.clone() ),* ].into_iter().map(|h| (h, $crate::Arc::new($crate::jaeger::Span::Disabled))), 0, ) }; diff --git a/polkadot/node/network/statement-distribution/src/lib.rs b/polkadot/node/network/statement-distribution/src/lib.rs index 1f9c90c5aa..ba22d3e172 100644 --- a/polkadot/node/network/statement-distribution/src/lib.rs +++ b/polkadot/node/network/statement-distribution/src/lib.rs @@ -25,6 +25,7 @@ use polkadot_subsystem::{ Subsystem, SubsystemResult, SubsystemContext, SpawnedSubsystem, ActiveLeavesUpdate, FromOverseer, OverseerSignal, PerLeafSpan, + jaeger, messages::{ AllMessages, NetworkBridgeMessage, StatementDistributionMessage, CandidateBackingMessage, RuntimeApiMessage, RuntimeApiRequest, NetworkBridgeEvent, @@ -516,10 +517,10 @@ async fn circulate_statement_and_dependents( None => return, }; - let _span = active_head.span.child_with_candidate( - "circulate-statement", - &statement.payload().candidate_hash() - ); + let _span = active_head.span.child_builder("circulate-statement") + .with_candidate(&statement.payload().candidate_hash()) + .with_stage(jaeger::Stage::StatementDistribution) + .build(); // First circulate the statement directly to all peers needing it. // The borrow of `active_head` needs to encompass only this (Rust) statement. @@ -533,10 +534,14 @@ async fn circulate_statement_and_dependents( } }; + let _span = _span.child("send-to-peers"); // Now send dependent statements to all peers needing them, if any. if let Some((candidate_hash, peers_needing_dependents)) = outputs { for peer in peers_needing_dependents { if let Some(peer_data) = peers.get_mut(&peer) { + let _span_loop = _span.child_builder("to-peer") + .with_peer_id(&peer) + .build(); // defensive: the peer data should always be some because the iterator // of peers is derived from the set of peers. send_statements_about( @@ -1071,7 +1076,7 @@ mod tests { use sp_keystore::{CryptoStore, SyncCryptoStorePtr, SyncCryptoStore}; use sc_keystore::LocalKeystore; use polkadot_node_network_protocol::{view, ObservedRole, our_view}; - use polkadot_subsystem::JaegerSpan; + use polkadot_subsystem::jaeger; #[test] fn active_head_accepts_only_2_seconded_per_validator() { @@ -1112,7 +1117,7 @@ mod tests { let mut head_data = ActiveHeadData::new( validators, session_index, - PerLeafSpan::new(Arc::new(JaegerSpan::Disabled), "test"), + PerLeafSpan::new(Arc::new(jaeger::Span::Disabled), "test"), ); let keystore: SyncCryptoStorePtr = Arc::new(LocalKeystore::in_memory()); @@ -1374,7 +1379,7 @@ mod tests { let mut data = ActiveHeadData::new( validators, session_index, - PerLeafSpan::new(Arc::new(JaegerSpan::Disabled), "test"), + PerLeafSpan::new(Arc::new(jaeger::Span::Disabled), "test"), ); let noted = data.note_statement(block_on(SignedFullStatement::sign( @@ -1627,7 +1632,7 @@ mod tests { let test_fut = async move { // register our active heads. handle.send(FromOverseer::Signal(OverseerSignal::ActiveLeaves(ActiveLeavesUpdate { - activated: vec![(hash_a, Arc::new(JaegerSpan::Disabled))].into(), + activated: vec![(hash_a, Arc::new(jaeger::Span::Disabled))].into(), deactivated: vec![].into(), }))).await; diff --git a/polkadot/node/overseer/src/lib.rs b/polkadot/node/overseer/src/lib.rs index 3d18ac737a..cd9f1d4f1d 100644 --- a/polkadot/node/overseer/src/lib.rs +++ b/polkadot/node/overseer/src/lib.rs @@ -90,7 +90,7 @@ use polkadot_subsystem::messages::{ }; pub use polkadot_subsystem::{ Subsystem, SubsystemContext, OverseerSignal, FromOverseer, SubsystemError, SubsystemResult, - SpawnedSubsystem, ActiveLeavesUpdate, DummySubsystem, JaegerSpan, jaeger, + SpawnedSubsystem, ActiveLeavesUpdate, DummySubsystem, jaeger, }; use polkadot_node_subsystem_util::{TimeoutExt, metrics::{self, prometheus}, metered, Metronome}; use polkadot_node_primitives::SpawnNamed; @@ -580,8 +580,8 @@ pub struct Overseer { /// External listeners waiting for a hash to be in the active-leave set. activation_external_listeners: HashMap>>>, - /// Stores the [`JaegerSpan`] per active leaf. - span_per_active_leaf: HashMap>, + /// Stores the [`jaeger::Span`] per active leaf. + span_per_active_leaf: HashMap>, /// A set of leaves that `Overseer` starts working with. /// @@ -1913,7 +1913,7 @@ where } #[tracing::instrument(level = "trace", skip(self), fields(subsystem = LOG_TARGET))] - fn on_head_activated(&mut self, hash: &Hash, parent_hash: Option) -> Arc { + fn on_head_activated(&mut self, hash: &Hash, parent_hash: Option) -> Arc { self.metrics.on_head_activated(); if let Some(listeners) = self.activation_external_listeners.remove(hash) { for listener in listeners { @@ -2026,7 +2026,7 @@ mod tests { use futures::{executor, pin_mut, select, FutureExt, pending}; use polkadot_primitives::v1::{BlockData, CollatorPair, PoV, CandidateHash}; - use polkadot_subsystem::{messages::RuntimeApiRequest, messages::NetworkBridgeEvent, JaegerSpan}; + use polkadot_subsystem::{messages::RuntimeApiRequest, messages::NetworkBridgeEvent, jaeger}; use polkadot_node_primitives::{CollationResult, CollationGenerationConfig}; use polkadot_node_network_protocol::{PeerId, UnifiedReputationChange}; use polkadot_node_subsystem_util::metered; @@ -2393,14 +2393,14 @@ mod tests { let expected_heartbeats = vec![ OverseerSignal::ActiveLeaves(ActiveLeavesUpdate::start_work( first_block_hash, - Arc::new(JaegerSpan::Disabled), + Arc::new(jaeger::Span::Disabled), )), OverseerSignal::ActiveLeaves(ActiveLeavesUpdate { - activated: [(second_block_hash, Arc::new(JaegerSpan::Disabled))].as_ref().into(), + activated: [(second_block_hash, Arc::new(jaeger::Span::Disabled))].as_ref().into(), deactivated: [first_block_hash].as_ref().into(), }), OverseerSignal::ActiveLeaves(ActiveLeavesUpdate { - activated: [(third_block_hash, Arc::new(JaegerSpan::Disabled))].as_ref().into(), + activated: [(third_block_hash, Arc::new(jaeger::Span::Disabled))].as_ref().into(), deactivated: [second_block_hash].as_ref().into(), }), ]; @@ -2489,8 +2489,8 @@ mod tests { let expected_heartbeats = vec![ OverseerSignal::ActiveLeaves(ActiveLeavesUpdate { activated: [ - (first_block_hash, Arc::new(JaegerSpan::Disabled)), - (second_block_hash, Arc::new(JaegerSpan::Disabled)), + (first_block_hash, Arc::new(jaeger::Span::Disabled)), + (second_block_hash, Arc::new(jaeger::Span::Disabled)), ].as_ref().into(), ..Default::default() }), @@ -2577,7 +2577,7 @@ mod tests { let expected_heartbeats = vec![ OverseerSignal::ActiveLeaves(ActiveLeavesUpdate { activated: [ - (imported_block.hash, Arc::new(JaegerSpan::Disabled)), + (imported_block.hash, Arc::new(jaeger::Span::Disabled)), ].as_ref().into(), ..Default::default() }), diff --git a/polkadot/node/subsystem-util/src/lib.rs b/polkadot/node/subsystem-util/src/lib.rs index 1eee4cc7f7..eb044a7711 100644 --- a/polkadot/node/subsystem-util/src/lib.rs +++ b/polkadot/node/subsystem-util/src/lib.rs @@ -29,7 +29,7 @@ use polkadot_node_subsystem::{ messages::{AllMessages, RuntimeApiMessage, RuntimeApiRequest, RuntimeApiSender, BoundToRelayParent}, FromOverseer, SpawnedSubsystem, Subsystem, SubsystemContext, SubsystemError, SubsystemResult, }; -use polkadot_node_jaeger::JaegerSpan; +use polkadot_node_jaeger as jaeger; use futures::{channel::{mpsc, oneshot}, prelude::*, select, stream::Stream}; use futures_timer::Delay; use parity_scale_codec::Encode; @@ -481,7 +481,7 @@ pub trait JobTrait: Unpin { /// The job should be ended when `receiver` returns `None`. fn run( parent: Hash, - span: Arc, + span: Arc, run_args: Self::RunArgs, metrics: Self::Metrics, receiver: mpsc::Receiver, @@ -552,7 +552,7 @@ impl Jobs { fn spawn_job( &mut self, parent_hash: Hash, - span: Arc, + span: Arc, run_args: Job::RunArgs, metrics: Job::Metrics, ) -> Result<(), Error> { @@ -1045,9 +1045,10 @@ mod tests { use super::*; use executor::block_on; use thiserror::Error; + use polkadot_node_jaeger as jaeger; use polkadot_node_subsystem::{ messages::{AllMessages, CandidateSelectionMessage}, ActiveLeavesUpdate, FromOverseer, OverseerSignal, - SpawnedSubsystem, JaegerSpan, + SpawnedSubsystem, }; use assert_matches::assert_matches; use futures::{channel::mpsc, executor, StreamExt, future, Future, FutureExt, SinkExt}; @@ -1089,7 +1090,7 @@ mod tests { // this function is in charge of creating and executing the job's main loop fn run( _: Hash, - _: Arc, + _: Arc, run_args: Self::RunArgs, _metrics: Self::Metrics, receiver: mpsc::Receiver, @@ -1173,7 +1174,7 @@ mod tests { test_harness(true, |mut overseer_handle, err_rx| async move { overseer_handle .send(FromOverseer::Signal(OverseerSignal::ActiveLeaves( - ActiveLeavesUpdate::start_work(relay_parent, Arc::new(JaegerSpan::Disabled)), + ActiveLeavesUpdate::start_work(relay_parent, Arc::new(jaeger::Span::Disabled)), ))) .await; assert_matches!( @@ -1202,7 +1203,7 @@ mod tests { test_harness(true, |mut overseer_handle, err_rx| async move { overseer_handle .send(FromOverseer::Signal(OverseerSignal::ActiveLeaves( - ActiveLeavesUpdate::start_work(relay_parent, Arc::new(JaegerSpan::Disabled)), + ActiveLeavesUpdate::start_work(relay_parent, Arc::new(jaeger::Span::Disabled)), ))) .await; diff --git a/polkadot/node/subsystem/src/lib.rs b/polkadot/node/subsystem/src/lib.rs index ad049bf39d..a48eaee028 100644 --- a/polkadot/node/subsystem/src/lib.rs +++ b/polkadot/node/subsystem/src/lib.rs @@ -51,18 +51,18 @@ const ACTIVE_LEAVES_SMALLVEC_CAPACITY: usize = 8; /// Note that the activated and deactivated fields indicate deltas, not complete sets. #[derive(Clone, Default)] pub struct ActiveLeavesUpdate { - /// New relay chain block hashes of interest and their associated [`JaegerSpan`]. + /// New relay chain block hashes of interest and their associated [`jaeger::Span`]. /// /// NOTE: Each span should only be kept active as long as the leaf is considered active and should be dropped /// when the leaf is deactivated. - pub activated: SmallVec<[(Hash, Arc); ACTIVE_LEAVES_SMALLVEC_CAPACITY]>, + pub activated: SmallVec<[(Hash, Arc); ACTIVE_LEAVES_SMALLVEC_CAPACITY]>, /// Relay chain block hashes no longer of interest. pub deactivated: SmallVec<[Hash; ACTIVE_LEAVES_SMALLVEC_CAPACITY]>, } impl ActiveLeavesUpdate { /// Create a ActiveLeavesUpdate with a single activated hash - pub fn start_work(hash: Hash, span: Arc) -> Self { + pub fn start_work(hash: Hash, span: Arc) -> Self { Self { activated: [(hash, span)][..].into(), ..Default::default() } } @@ -90,7 +90,7 @@ impl PartialEq for ActiveLeavesUpdate { impl fmt::Debug for ActiveLeavesUpdate { fn fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result { - struct Activated<'a>(&'a [(Hash, Arc)]); + struct Activated<'a>(&'a [(Hash, Arc)]); impl fmt::Debug for Activated<'_> { fn fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result { f.debug_list().entries(self.0.iter().map(|e| e.0)).finish()