Add more metrics to the import queue (#7207)

substrate/primitives/consensus/common/src/import_queue.rs

@@ -288,5 +288,9 @@ pub(crate) fn import_single_block_metered<B: BlockT, V: Verifier<B>, Transaction
 	}
 	import_block.allow_missing_state = block.allow_missing_state;
 
-	import_handler(import_handle.import_block(import_block.convert_transaction(), cache))
+	let imported = import_handle.import_block(import_block.convert_transaction(), cache);
+	if let Some(metrics) = metrics.as_ref() {
+		metrics.report_verification_and_import(started.elapsed());
+	}
+	import_handler(imported)
 }

substrate/primitives/consensus/common/src/import_queue/basic_queue.rs

@@ -292,6 +292,7 @@ impl<B: BlockT, Transaction: Send> BlockImportWorker<B, Transaction> {
 		number: NumberFor<B>,
 		finality_proof: Vec<u8>
 	) {
+		let started = wasm_timer::Instant::now();
 		let result = self.finality_proof_import.as_mut().map(|finality_proof_import| {
 			finality_proof_import.import_finality_proof(hash, number, finality_proof, verifier)
 				.map_err(|e| {
@@ -305,6 +306,10 @@ impl<B: BlockT, Transaction: Send> BlockImportWorker<B, Transaction> {
 				})
 		}).unwrap_or(Err(()));
 
+		if let Some(metrics) = self.metrics.as_ref() {
+			metrics.finality_proof_import_time.observe(started.elapsed().as_secs_f64());
+		}
+
 		trace!(target: "sync", "Imported finality proof for {}/{}", number, hash);
 		self.result_sender.finality_proof_imported(who, (hash, number), result);
 	}
@@ -316,6 +321,7 @@ impl<B: BlockT, Transaction: Send> BlockImportWorker<B, Transaction> {
 		number: NumberFor<B>,
 		justification: Justification
 	) {
+		let started = wasm_timer::Instant::now();
 		let success = self.justification_import.as_mut().map(|justification_import| {
 			justification_import.import_justification(hash, number, justification)
 				.map_err(|e| {
@@ -331,6 +337,10 @@ impl<B: BlockT, Transaction: Send> BlockImportWorker<B, Transaction> {
 				}).is_ok()
 		}).unwrap_or(false);
 
+		if let Some(metrics) = self.metrics.as_ref() {
+			metrics.justification_import_time.observe(started.elapsed().as_secs_f64());
+		}
+
 		self.result_sender.justification_imported(who, &hash, number, success);
 	}
 }

substrate/primitives/consensus/common/src/metrics.rs

@@ -16,7 +16,9 @@
 
 //! Metering tools for consensus
 
-use prometheus_endpoint::{register, U64, Registry, PrometheusError, Opts, CounterVec, HistogramVec, HistogramOpts};
+use prometheus_endpoint::{
+	register, U64, Registry, PrometheusError, Opts, CounterVec, Histogram, HistogramVec, HistogramOpts
+};
 
 use sp_runtime::traits::{Block as BlockT, NumberFor};
 
@@ -27,6 +29,9 @@ use crate::import_queue::{BlockImportResult, BlockImportError};
 pub(crate) struct Metrics {
 	pub import_queue_processed: CounterVec<U64>,
 	pub block_verification_time: HistogramVec,
+	pub block_verification_and_import_time: Histogram,
+	pub finality_proof_import_time: Histogram,
+	pub justification_import_time: Histogram,
 }
 
 impl Metrics {
@@ -43,12 +48,39 @@ impl Metrics {
 				HistogramVec::new(
 					HistogramOpts::new(
 						"block_verification_time",
-						"Histogram of time taken to import blocks",
+						"Time taken to verify blocks",
 					),
 					&["result"],
 				)?,
 				registry,
 			)?,
+			block_verification_and_import_time: register(
+				Histogram::with_opts(
+					HistogramOpts::new(
+						"block_verification_and_import_time",
+						"Time taken to verify and import blocks",
+					),
+				)?,
+				registry,
+			)?,
+			finality_proof_import_time: register(
+				Histogram::with_opts(
+					HistogramOpts::new(
+						"finality_proof_import_time",
+						"Time taken to import finality proofs",
+					),
+				)?,
+				registry,
+			)?,
+			justification_import_time: register(
+				Histogram::with_opts(
+					HistogramOpts::new(
+						"justification_import_time",
+						"Time taken to import justifications",
+					),
+				)?,
+				registry,
+			)?,
 		})
 	}
 
@@ -77,4 +109,8 @@ impl Metrics {
 			&[if success { "success" } else { "verification_failed" }]
 		).observe(time.as_secs_f64());
 	}
+
+	pub fn report_verification_and_import(&self, time: std::time::Duration) {
+		self.block_verification_and_import_time.observe(time.as_secs_f64());
+	}
 }