Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

basic-authorship: Improve time recording and logging #2010

Merged
merged 2 commits into from
Oct 24, 2023
Merged

basic-authorship: Improve time recording and logging #2010

Changes from all commits
Commits
Show all changes
2 commits
Select commit Hold shift + click to select a range
65734ba
basic-authorship: Improve time recording and logging
bkchr Oct 24, 2023
6fae5ef
Merge branch 'master' into bkchr-basic-authorship-improvements
bkchr Oct 24, 2023
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
19 changes: 14 additions & 5 deletions substrate/client/basic-authorship/src/basic_authorship.rs
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -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)?;

Expand All @@ -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();
Expand All @@ -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 })
}

Expand Down Expand Up @@ -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
};

Expand Down Expand Up @@ -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,
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

this could be info!'ed too

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I mean this is only includes the storage proof extraction, not really something we also need to print. IMO.

) {
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() {
Expand Down