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

.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

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;

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<CollatorId>,
 	/// Spans for all candidates that are not yet backable.
-	unbacked_candidates: HashMap<CandidateHash, JaegerSpan>,
+	unbacked_candidates: HashMap<CandidateHash, jaeger::Span>,
 	/// We issued `Seconded`, `Valid` or `Invalid` statements on about these candidates.
 	issued_statements: HashSet<CandidateHash>,
 	/// 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<Result<(), InvalidErasureRoot>, Error> {
 	let available_data = AvailableData {
 		pov,
@@ -383,7 +384,7 @@ struct BackgroundValidationParams<F> {
 	pov: Option<Arc<PoV>>,
 	validator_index: Option<ValidatorIndex>,
 	n_validators: usize,
-	span: Option<JaegerSpan>,
+	span: Option<jaeger::Span>,
 	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<PoV>,
 	) -> 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<Option<SignedFullStatement>, 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<Option<TableSummary>, 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<JaegerSpan>,
+		span: Option<jaeger::Span>,
 	) -> 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<JaegerSpan> {
-		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<jaeger::Span> {
+		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<JaegerSpan> {
+	) -> Option<jaeger::Span> {
 		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<JaegerSpan> {
+	fn remove_unbacked_span(&mut self, hash: &CandidateHash) -> Option<jaeger::Span> {
 		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<JaegerSpan>,
+		span: Arc<jaeger::Span>,
 		keystore: SyncCryptoStorePtr,
 		metrics: Metrics,
 		rx_to: mpsc::Receiver<Self::ToJob>,
@@ -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;
 

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<FromJobCommand>>,
-	span: &jaeger::JaegerSpan,
+	span: &jaeger::Span,
 ) -> Result<bool, Error> {
 	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<FromJobCommand>,
 ) -> Result<AvailabilityBitfield, Error> {
@@ -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<JaegerSpan>,
+		span: Arc<jaeger::Span>,
 		keystore: Self::RunArgs,
 		metrics: Self::Metrics,
 		_receiver: mpsc::Receiver<BitfieldSigningMessage>,
@@ -321,7 +321,7 @@ mod tests {
 
 			let future = construct_availability_bitfield(
 				relay_parent,
-				&jaeger::JaegerSpan::Disabled,
+				&jaeger::Span::Disabled,
 				validator_index,
 				&mut sender,
 			).fuse();

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<JaegerSpan>,
+		span: Arc<jaeger::Span>,
 		keystore: Self::RunArgs,
 		metrics: Self::Metrics,
 		receiver: mpsc::Receiver<CandidateSelectionMessage>,
@@ -104,7 +104,10 @@ impl JobTrait for CandidateSelectionJob {
 	) -> Pin<Box<dyn Future<Output = Result<(), Self::Error>> + 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),

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<JaegerSpan>,
+		span: Arc<jaeger::Span>,
 		_run_args: Self::RunArgs,
 		metrics: Self::Metrics,
 		receiver: mpsc::Receiver<ProvisionerMessage>,

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<JaegerSpan>,
-	span: JaegerSpan,
+	leaf_span: Arc<Span>,
+	span: Span,
 }