client/beefy: fix metrics

client/beefy/src/import.rs

@@ -35,7 +35,7 @@ use sc_consensus::{BlockCheckParams, BlockImport, BlockImportParams, ImportResul
 use crate::{
 	communication::notification::BeefyVersionedFinalityProofSender,
 	justification::{decode_and_verify_finality_proof, BeefyVersionedFinalityProof},
-	metric_set,
+	metric_inc,
 	metrics::Metrics,
 	LOG_TARGET,
 };
@@ -153,15 +153,15 @@ where
 						.notify(|| Ok::<_, ()>(proof))
 						.expect("forwards closure result; the closure always returns Ok; qed.");
 
-					metric_inc!(self, beefy_block_import_good_justification);
+					metric_inc!(self, beefy_good_justification_imports);
 				} else {
 					debug!(
 						target: LOG_TARGET,
 						"🥩 error decoding justification: {:?} for imported block {:?}",
 						encoded,
 						number,
 					);
-					metric_inc!(self, beefy_block_import_bad_justification);
+					metric_inc!(self, beefy_bad_justification_imports);
 				}
 			},
 			_ => (),

client/beefy/src/metrics.rs

@@ -26,8 +26,6 @@ pub struct Metrics {
 	pub beefy_validator_set_id: Gauge<U64>,
 	/// Total number of votes sent by this node
 	pub beefy_votes_sent: Counter<U64>,
-	/// Most recent concluded voting round
-	pub beefy_round_concluded: Gauge<U64>,
 	/// Best block finalized by BEEFY
 	pub beefy_best_block: Gauge<U64>,
 	/// Next block BEEFY should vote on
@@ -38,24 +36,28 @@ pub struct Metrics {
 	pub beefy_no_session_initialized: Counter<U64>,
 	/// Number of times no Authority public key found in store
 	pub beefy_no_authority_found_in_store: Counter<U64>,
-	/// Number of Buffered votes
-	pub beefy_buffered_votes: Counter<U64>,
-	/// Number of times Buffered votes is full
-	pub beefy_buffered_votes_full: Counter<U64>,
-	/// Number of Buffered justifications
-	pub beefy_buffered_justifications: Counter<U64>,
-	/// Number of times Buffered justifications is full
-	pub beefy_buffered_justifications_full: Counter<U64>,
+	/// Number of currently buffered votes
+	pub beefy_buffered_votes: Gauge<U64>,
+	/// Number of valid but stale votes received
+	pub beefy_stale_votes: Counter<U64>,
+	/// Number of votes dropped due to full buffers
+	pub beefy_buffered_votes_dropped: Counter<U64>,
+	/// Number of currently buffered justifications
+	pub beefy_buffered_justifications: Gauge<U64>,
+	/// Number of valid but stale justifications received
+	pub beefy_stale_justifications: Counter<U64>,
+	/// Number of valid justifications successfully imported
+	pub beefy_imported_justifications: Counter<U64>,
+	/// Number of justifications dropped due to full buffers
+	pub beefy_buffered_justifications_dropped: Counter<U64>,
 	/// Trying to set Best Beefy block to old block
 	pub beefy_best_block_to_old_block: Gauge<U64>,
 	/// Number of Successful handled votes
 	pub beefy_successful_handled_votes: Counter<U64>,
-	/// Number of Successful votes
-	pub beefy_successful_votes: Counter<U64>,
-	/// Number of Bad Justification imports
-	pub beefy_bad_justification_imports: Gauge<U64>,
 	/// Number of Good Justification imports
-	pub beefy_good_justification_imports: Gauge<U64>,
+	pub beefy_good_justification_imports: Counter<U64>,
+	/// Number of Bad Justification imports
+	pub beefy_bad_justification_imports: Counter<U64>,
 	/// Number of Successful Justification respond request
 	pub beefy_successful_justification_respond_request: Counter<U64>,
 	/// Number of Failed Justification respond request
@@ -86,13 +88,6 @@ impl Metrics {
 				Counter::new("substrate_beefy_votes_sent", "Number of votes sent by this node")?,
 				registry,
 			)?,
-			beefy_round_concluded: register(
-				Gauge::new(
-					"substrate_beefy_round_concluded",
-					"Voting round, that has been concluded",
-				)?,
-				registry,
-			)?,
 			beefy_best_block: register(
 				Gauge::new("substrate_beefy_best_block", "Best block finalized by BEEFY")?,
 				registry,
@@ -108,10 +103,10 @@ impl Metrics {
 				)?,
 				registry,
 			)?,
-			beefy_voting_with_no_session_initialized: register(
+			beefy_no_session_initialized: register(
 				Counter::new(
-					"substrate_voting_with_no_session_initialized",
-					"Number of validator's trying to vote with no session initialized",
+					"substrate_beefy_no_session_initialized",
+					"Number of times trying to vote with no session initialized",
 				)?,
 				registry,
 			)?,
@@ -123,27 +118,48 @@ impl Metrics {
 				registry,
 			)?,
 			beefy_buffered_votes: register(
-				Counter::new("substrate_beefy_buffered_votes", "Number of Buffered votes")?,
+				Gauge::new("substrate_beefy_buffered_votes", "Number of currently buffered votes")?,
 				registry,
 			)?,
-			beefy_buffered_votes_full: register(
+			beefy_stale_votes: register(
 				Counter::new(
-					"substrate_beefy_buffered_votes_full",
-					"Number of times Buffered votes is full",
+					"substrate_beefy_stale_votes",
+					"Number of valid but stale votes received",
 				)?,
 				registry,
 			)?,
-			beefy_buffered_justifications: register(
+			beefy_buffered_votes_dropped: register(
 				Counter::new(
+					"substrate_beefy_buffered_votes_dropped",
+					"Number of votes dropped due to full buffers",
+				)?,
+				registry,
+			)?,
+			beefy_buffered_justifications: register(
+				Gauge::new(
 					"substrate_beefy_buffered_justifications",
-					"Number of Buffered justifications",
+					"Number of currently buffered justifications",
+				)?,
+				registry,
+			)?,
+			beefy_stale_justifications: register(
+				Counter::new(
+					"substrate_beefy_stale_justifications",
+					"Number of valid but stale justifications received",
+				)?,
+				registry,
+			)?,
+			beefy_imported_justifications: register(
+				Counter::new(
+					"substrate_beefy_imported_justifications",
+					"Number of valid justifications successfully imported",
 				)?,
 				registry,
 			)?,
-			beefy_buffered_justifications_full: register(
+			beefy_buffered_justifications_dropped: register(
 				Counter::new(
-					"substrate_beefy_buffered_justifications_full",
-					"Number of times Buffered justifications is full",
+					"substrate_beefy_buffered_justifications_dropped",
+					"Number of justifications dropped due to full buffers",
 				)?,
 				registry,
 			)?,
@@ -161,24 +177,20 @@ impl Metrics {
 				)?,
 				registry,
 			)?,
-			beefy_successful_votes: register(
-				Counter::new("substrate_beefy_successful_votes", "Number of Successful votes")?,
+			beefy_good_justification_imports: register(
+				Counter::new(
+					"substrate_beefy_good_justification_imports",
+					"Number of Good Justification imports",
+				)?,
 				registry,
 			)?,
 			beefy_bad_justification_imports: register(
-				Gauge::new(
+				Counter::new(
 					"substrate_beefy_bad_justification_imports",
 					"Number of Bad Justification imports",
 				)?,
 				registry,
 			)?,
-			beefy_good_justification_imports: register(
-				Gauge::new(
-					"substrate_beefy_good_justification_imports",
-					"Number of Good Justification imports",
-				)?,
-				registry,
-			)?,
 			beefy_successful_justification_respond_request: register(
 				Counter::new(
 					"substrate_beefy_successful_justification_respond_request",
@@ -254,7 +266,6 @@ macro_rules! metric_inc {
 	}};
 }
 
-#[cfg(test)]
 #[macro_export]
 macro_rules! metric_get {
 	($self:ident, $m:ident) => {{

client/beefy/src/worker.rs

@@ -24,7 +24,7 @@ use crate::{
 	error::Error,
 	justification::BeefyVersionedFinalityProof,
 	keystore::BeefyKeystore,
-	metric_inc, metric_set,
+	metric_get, metric_inc, metric_set,
 	metrics::Metrics,
 	round::Rounds,
 	BeefyVoterLinks, LOG_TARGET,
@@ -494,22 +494,24 @@ where
 				false,
 			)?,
 			RoundAction::Enqueue => {
-				metric_inc!(self, beefy_buffered_votes);
 				debug!(target: LOG_TARGET, "🥩 Buffer vote for round: {:?}.", block_num);
 				if self.pending_votes.len() < MAX_BUFFERED_VOTE_ROUNDS {
 					let votes_vec = self.pending_votes.entry(block_num).or_default();
-					if votes_vec.try_push(vote).is_err() {
+					if votes_vec.try_push(vote).is_ok() {
+						metric_inc!(self, beefy_buffered_votes);
+					} else {
 						warn!(
 							target: LOG_TARGET,
 							"🥩 Buffer vote dropped for round: {:?}", block_num
-						)
+						);
+						metric_inc!(self, beefy_buffered_votes_dropped);
 					}
 				} else {
-					metric_inc!(self, beefy_buffered_votes_dropped);
 					warn!(target: LOG_TARGET, "🥩 Buffer vote dropped for round: {:?}.", block_num);
+					metric_inc!(self, beefy_buffered_votes_dropped);
 				}
 			},
-			RoundAction::Drop => (),
+			RoundAction::Drop => metric_inc!(self, beefy_stale_votes),
 		};
 		Ok(())
 	}
@@ -533,10 +535,10 @@ where
 				self.finalize(justification)?
 			},
 			RoundAction::Enqueue => {
-				metric_inc!(self, beefy_buffered_justifications);
 				debug!(target: LOG_TARGET, "🥩 Buffer justification for round: {:?}.", block_num);
 				if self.pending_justifications.len() < MAX_BUFFERED_JUSTIFICATIONS {
 					self.pending_justifications.entry(block_num).or_insert(justification);
+					metric_inc!(self, beefy_buffered_justifications);
 				} else {
 					metric_inc!(self, beefy_buffered_justifications_dropped);
 					warn!(
@@ -545,7 +547,7 @@ where
 					);
 				}
 			},
-			RoundAction::Drop => (),
+			RoundAction::Drop => metric_inc!(self, beefy_stale_justifications),
 		};
 		Ok(())
 	}
@@ -578,8 +580,6 @@ where
 				let finality_proof =
 					VersionedFinalityProof::V1(SignedCommitment { commitment, signatures });
 
-				metric_set!(self, beefy_round_concluded, block_num);
-
 				info!(
 					target: LOG_TARGET,
 					"🥩 Round #{} concluded, finality_proof: {:?}.", round.1, finality_proof
@@ -657,6 +657,7 @@ where
 				.expect("forwards closure result; the closure always returns Ok; qed.");
 		} else {
 			debug!(target: LOG_TARGET, "🥩 Can't set best beefy to older: {}", block_num);
+			metric_set!(self, beefy_best_block_to_old_block, block_num);
 		}
 		Ok(())
 	}
@@ -688,19 +689,23 @@ where
 			let justifs_to_handle = to_process_for(&mut self.pending_justifications, interval, _ph);
 			for (num, justification) in justifs_to_handle.into_iter() {
 				debug!(target: LOG_TARGET, "🥩 Handle buffered justification for: {:?}.", num);
+				metric_inc!(self, beefy_imported_justifications);
 				if let Err(err) = self.finalize(justification) {
 					error!(target: LOG_TARGET, "🥩 Error finalizing block: {}", err);
 				}
 			}
+			metric_set!(self, beefy_buffered_justifications, self.pending_justifications.len());
 			// Possibly new interval after processing justifications.
 			interval = self.voting_oracle().accepted_interval(best_grandpa)?;
 		}
 
 		// Process pending votes.
 		if !self.pending_votes.is_empty() {
+			let mut processed = 0u64;
 			let votes_to_handle = to_process_for(&mut self.pending_votes, interval, _ph);
 			for (num, votes) in votes_to_handle.into_iter() {
 				debug!(target: LOG_TARGET, "🥩 Handle buffered votes for: {:?}.", num);
+				processed += votes.len() as u64;
 				for v in votes.into_iter() {
 					if let Err(err) = self.handle_vote(
 						(v.commitment.payload, v.commitment.block_number),
@@ -711,6 +716,10 @@ where
 					};
 				}
 			}
+			if let Some(previous) = metric_get!(self, beefy_buffered_votes) {
+				previous.sub(processed);
+				metric_set!(self, beefy_buffered_votes, previous.get());
+			}
 		}
 		Ok(())
 	}
@@ -829,8 +838,6 @@ where
 
 		self.gossip_engine.gossip_message(topic::<B>(), encoded_message, false);
 
-		metric_inc!(self, beefy_self_votes);
-
 		Ok(())
 	}