From 2e11ae89dc13e55c3162b9e7d7af6a1fe531df62 Mon Sep 17 00:00:00 2001
From: =?UTF-8?q?Bastian=20K=C3=B6cher?= <git@kchr.de>
Date: Wed, 25 Oct 2023 00:30:48 +0200
Subject: [PATCH] basic-authorship: Improve time recording and logging (#2010)
---
.../basic-authorship/src/basic_authorship.rs | 19 ++++++++++++++-----
1 file changed, 14 insertions(+), 5 deletions(-)
diff --git a/substrate/client/basic-authorship/src/basic_authorship.rs b/substrate/client/basic-authorship/src/basic_authorship.rs
index 57c2996ab40..4db2de61cb4 100644
--- a/substrate/client/basic-authorship/src/basic_authorship.rs
+++ b/substrate/client/basic-authorship/src/basic_authorship.rs
@@ -334,7 +334,7 @@ where
deadline: time::Instant,
block_size_limit: Option<usize>,
) -> Result<Proposal<Block, PR::Proof>, sp_blockchain::Error> {
- let propose_with_timer = time::Instant::now();
+ let block_timer = time::Instant::now();
let mut block_builder =
self.client.new_block_at(self.parent_hash, inherent_digests, PR::ENABLED)?;
@@ -343,7 +343,6 @@ where
// TODO call `after_inherents` and check if we should apply extrinsincs here
// <https://github.com/paritytech/substrate/pull/14275/>
- let block_timer = time::Instant::now();
let end_reason =
self.apply_extrinsics(&mut block_builder, deadline, block_size_limit).await?;
let (block, storage_changes, proof) = block_builder.build()?.into_inner();
@@ -352,7 +351,7 @@ where
let proof =
PR::into_proof(proof).map_err(|e| sp_blockchain::Error::Application(Box::new(e)))?;
- self.print_summary(&block, end_reason, block_took, propose_with_timer.elapsed());
+ self.print_summary(&block, end_reason, block_took, block_timer.elapsed());
Ok(Proposal { block, proof, storage_changes })
}
@@ -443,6 +442,11 @@ where
let pending_tx = if let Some(pending_tx) = pending_iterator.next() {
pending_tx
} else {
+ debug!(
+ target: LOG_TARGET,
+ "No more transactions, proceeding with proposing."
+ );
+
break EndProposingReason::NoMoreTransactions
};
@@ -539,19 +543,24 @@ where
}
/// Prints a summary and does telemetry + metrics.
+ ///
+ /// - `block`: The block that was build.
+ /// - `end_reason`: Why did we stop producing the block?
+ /// - `block_took`: How long did it took to produce the actual block?
+ /// - `propose_took`: How long did the entire proposing took?
fn print_summary(
&self,
block: &Block,
end_reason: EndProposingReason,
block_took: time::Duration,
- propose_with_took: time::Duration,
+ propose_took: time::Duration,
) {
let extrinsics = block.extrinsics();
self.metrics.report(|metrics| {
metrics.number_of_transactions.set(extrinsics.len() as u64);
metrics.block_constructed.observe(block_took.as_secs_f64());
metrics.report_end_proposing_reason(end_reason);
- metrics.create_block_proposal_time.observe(propose_with_took.as_secs_f64());
+ metrics.create_block_proposal_time.observe(propose_took.as_secs_f64());
});
let extrinsics_summary = if extrinsics.is_empty() {
--
GitLab