Backing and collator protocol traces including para-id (#2620)

* improve backing/provisioner spans

* span for collation requests

* add para_id to unbacked candidate spans

* differentiate validation-construction and find-assignment in selection

* better find-assignment spans

* organize unbacked-candidate spans directly under job root

* Update node/core/provisioner/src/lib.rs

Co-authored-by: Andronik Ordian <write@reusable.software>

Co-authored-by: Andronik Ordian <write@reusable.software>
This commit is contained in:
Robert Habermeier
2021-03-14 11:51:14 -05:00
committed by GitHub
parent bdb3256396
commit 94d50afd4e
5 changed files with 111 additions and 32 deletions
+58 -22
View File
@@ -417,8 +417,9 @@ async fn validate_and_make_available(
let v = {
let _span = span.as_ref().map(|s| {
s.child_builder("request-validation")
.with_pov(&pov)
.build()
.with_pov(&pov)
.with_para_id(candidate.descriptor().para_id)
.build()
});
request_candidate_validation(&mut tx_from, candidate.descriptor.clone(), pov.clone()).await?
};
@@ -611,6 +612,7 @@ impl CandidateBackingJob {
async fn validate_and_second(
&mut self,
parent_span: &jaeger::Span,
root_span: &jaeger::Span,
candidate: &CandidateReceipt,
pov: Arc<PoV>,
) -> Result<(), Error> {
@@ -623,7 +625,13 @@ impl CandidateBackingJob {
}
let candidate_hash = candidate.hash();
let span = self.get_unbacked_validation_child(parent_span, candidate_hash);
let mut span = self.get_unbacked_validation_child(
root_span,
candidate_hash,
candidate.descriptor().para_id,
);
span.as_mut().map(|s| s.add_follows_from(parent_span));
tracing::debug!(
target: LOG_TARGET,
@@ -745,17 +753,17 @@ impl CandidateBackingJob {
Ok(summary)
}
#[tracing::instrument(level = "trace", skip(self, span), fields(subsystem = LOG_TARGET))]
async fn process_msg(&mut self, span: &jaeger::Span, msg: CandidateBackingMessage) -> Result<(), Error> {
#[tracing::instrument(level = "trace", skip(self, root_span), fields(subsystem = LOG_TARGET))]
async fn process_msg(&mut self, root_span: &jaeger::Span, msg: CandidateBackingMessage) -> Result<(), Error> {
match msg {
CandidateBackingMessage::Second(_relay_parent, candidate, pov) => {
CandidateBackingMessage::Second(relay_parent, candidate, pov) => {
let _timer = self.metrics.time_process_second();
let span = span.child_builder("second")
let span = root_span.child_builder("second")
.with_stage(jaeger::Stage::CandidateBacking)
.with_pov(&pov)
.with_candidate(&candidate.hash())
.with_relay_parent(&_relay_parent)
.with_relay_parent(&relay_parent)
.build();
// Sanity check that candidate is from our assignment.
@@ -772,20 +780,20 @@ impl CandidateBackingJob {
if !self.issued_statements.contains(&candidate_hash) {
let pov = Arc::new(pov);
self.validate_and_second(&span, &candidate, pov).await?;
self.validate_and_second(&span, &root_span, &candidate, pov).await?;
}
}
}
CandidateBackingMessage::Statement(_relay_parent, statement) => {
let _timer = self.metrics.time_process_statement();
let span = span.child_builder("statement")
let span = root_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 {
match self.maybe_validate_and_import(&span, &root_span, statement).await {
Err(Error::ValidationFailed(_)) => return Ok(()),
Err(e) => return Err(e),
Ok(()) => (),
@@ -865,12 +873,17 @@ impl CandidateBackingJob {
async fn maybe_validate_and_import(
&mut self,
parent_span: &jaeger::Span,
root_span: &jaeger::Span,
statement: SignedFullStatement,
) -> Result<(), Error> {
if let Some(summary) = self.import_statement(&statement, parent_span).await? {
if let Statement::Seconded(_) = statement.payload() {
if Some(summary.group_id) == self.assignment {
let span = self.get_unbacked_validation_child(parent_span, summary.candidate);
let span = self.get_unbacked_validation_child(
root_span,
summary.candidate,
summary.group_id,
);
self.kick_off_validation_work(summary, span).await?;
}
@@ -910,11 +923,23 @@ impl CandidateBackingJob {
}
/// Insert or get the unbacked-span for the given candidate hash.
fn insert_or_get_unbacked_span(&mut self, parent_span: &jaeger::Span, hash: CandidateHash) -> Option<&jaeger::Span> {
fn insert_or_get_unbacked_span(
&mut self,
parent_span: &jaeger::Span,
hash: CandidateHash,
para_id: Option<ParaId>
) -> 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(|| {
parent_span.child_with_candidate("unbacked-candidate", &hash)
let s = parent_span.child_builder("unbacked-candidate").with_candidate(&hash);
let s = if let Some(para_id) = para_id {
s.with_para_id(para_id)
} else {
s
};
s.build()
});
Some(span)
} else {
@@ -922,8 +947,13 @@ impl CandidateBackingJob {
}
}
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)
fn get_unbacked_validation_child(
&mut self,
parent_span: &jaeger::Span,
hash: CandidateHash,
para_id: ParaId,
) -> Option<jaeger::Span> {
self.insert_or_get_unbacked_span(parent_span, hash, Some(para_id))
.map(|span| {
span.child_builder("validation")
.with_candidate(&hash)
@@ -938,7 +968,7 @@ impl CandidateBackingJob {
hash: CandidateHash,
validator: ValidatorIndex,
) -> Option<jaeger::Span> {
self.insert_or_get_unbacked_span(parent_span, hash).map(|span| {
self.insert_or_get_unbacked_span(parent_span, hash, None).map(|span| {
span.child_builder("import-statement")
.with_candidate(&hash)
.with_validator_index(validator)
@@ -1055,8 +1085,7 @@ impl util::JobTrait for CandidateBackingJob {
};
drop(_span);
let _span = span.child("calc-validator-groups");
let mut assignments_span = span.child("compute-assignments");
let mut groups = HashMap::new();
@@ -1085,11 +1114,18 @@ impl util::JobTrait for CandidateBackingJob {
};
let (assignment, required_collator) = match assignment {
None => (None, None),
Some((assignment, required_collator)) => (Some(assignment), required_collator),
None => {
assignments_span.add_string_tag("assigned", "false");
(None, None)
}
Some((assignment, required_collator)) => {
assignments_span.add_string_tag("assigned", "true");
assignments_span.add_para_id(assignment);
(Some(assignment), required_collator)
}
};
drop(_span);
drop(assignments_span);
let _span = span.child("wait-for-job");
let (background_tx, background_rx) = mpsc::channel(16);