feat(collator): add more collation metrics and histogram guard with l…

…abels

collator/src/collator/do_collate.rs

@@ -15,7 +15,7 @@ use super::types::{CachedMempoolAnchor, SpecialOrigin};
 use super::CollatorStdImpl;
 use crate::collator::execution_manager::ExecutionManager;
 use crate::collator::types::{
-    ParsedMessage, BlockCollationData, Dequeued, McData, PreparedInMsg, PreparedOutMsg, PrevData,
+    BlockCollationData, Dequeued, McData, ParsedMessage, PreparedInMsg, PreparedOutMsg, PrevData,
     ShardDescriptionExt,
 };
 use crate::internal_queue::types::InternalMessageKey;

collator/src/collator/mod.rs

@@ -7,6 +7,7 @@ use everscale_types::models::*;
 use everscale_types::prelude::HashBytes;
 use futures_util::future::{BoxFuture, Future};
 use tycho_block_util::state::{MinRefMcStateTracker, ShardStateStuff};
+use tycho_util::metrics::HistogramGuardWithLabels;
 use tycho_util::FastHashMap;
 
 use self::types::{CachedMempoolAnchor, CollatorStats, McData, PrevData, WorkingState};
@@ -375,6 +376,11 @@ impl CollatorStdImpl {
     /// Update McData in working state
     #[tracing::instrument(skip_all, fields(block_id = %self.next_block_id_short))]
     fn update_mc_data(&mut self, mc_state: ShardStateStuff) -> Result<()> {
+        let labels = [("workchain", self.shard_id.workchain().to_string())];
+
+        let _histogram =
+            HistogramGuardWithLabels::begin("tycho_collator_update_mc_data_time", &labels);
+
         let mc_state_block_id_short = mc_state.block_id().as_short_id();
 
         let new_mc_data = McData::build(mc_state)?;
@@ -469,6 +475,11 @@ impl CollatorStdImpl {
     async fn import_next_anchor(&mut self) -> Result<(Arc<MempoolAnchor>, bool)> {
         // TODO: make real implementation
 
+        let labels = [("workchain", self.shard_id.workchain().to_string())];
+
+        let _histogram =
+            HistogramGuardWithLabels::begin("tycho_collator_import_next_anchor_time", &labels);
+
         // TODO: use get_next_anchor() only once
         let next_anchor = if let Some(prev_anchor_id) = self.last_imported_anchor_id {
             self.mpool_adapter.get_next_anchor(prev_anchor_id).await?
@@ -606,6 +617,13 @@ impl CollatorStdImpl {
             "Check if can collate next master block",
         );
 
+        let labels = [("workchain", self.shard_id.workchain().to_string())];
+
+        let _histogram = HistogramGuardWithLabels::begin(
+            "tycho_collator_try_collate_next_master_block_time",
+            &labels,
+        );
+
         if self.has_internals().is_none() {
             self.load_has_internals().await?;
         }
@@ -652,6 +670,13 @@ impl CollatorStdImpl {
             "Check if can collate next shard block",
         );
 
+        let labels = [("workchain", self.shard_id.workchain().to_string())];
+
+        let _histogram = HistogramGuardWithLabels::begin(
+            "tycho_collator_try_collate_next_shard_block_without_do_collate_time",
+            &labels,
+        );
+
         if self.has_internals().is_none() {
             self.load_has_internals().await?;
         }
@@ -730,6 +755,7 @@ impl CollatorStdImpl {
             None
         };
 
+        drop(_histogram);
         // collate block if has internals or externals
         if (has_internals || has_externals) && !force_mc_block_by_uncommitted_chain {
             let next_chain_time = self.get_last_imported_anchor_chain_time();

collator/src/manager/mod.rs

@@ -8,6 +8,7 @@ use everscale_crypto::ed25519::KeyPair;
 use everscale_types::models::{BlockId, BlockIdShort, ShardIdent};
 use tycho_block_util::block::ValidatorSubsetInfo;
 use tycho_block_util::state::{MinRefMcStateTracker, ShardStateStuff};
+use tycho_util::metrics::HistogramGuard;
 use tycho_util::FastHashMap;
 
 use self::types::{
@@ -530,6 +531,8 @@ where
             "Trying to refresh collation sessions by mc state for block...",
         );
 
+        let _histogram = HistogramGuard::begin("tycho_collator_refresh_collation_sessions_time");
+
         // TODO: Possibly we have already updated collation sessions for this master block,
         //      because we may have collated it by ourselves before receiving it from the blockchain
         //      or because we have received it from the blockchain before we collated it
@@ -863,6 +866,9 @@ where
             "Start processing block candidate",
         );
 
+        let _histogram =
+            HistogramGuard::begin("tycho_collator_process_collated_block_candidate_time");
+
         // find session related to this block by shard
         let session_info = self
             .active_collation_sessions
@@ -1039,6 +1045,10 @@ where
         // Then we can collate master block if interval elapsed or have "force" flag in every shards.
         // We should take the max of first chain times that meet master block collation condition from each shard.
 
+        let _histogram = HistogramGuard::begin(
+            "tycho_collator_update_last_collated_chain_time_and_check_should_collate_mc_block_time",
+        );
+
         let last_collated_chain_times = self
             .last_collated_chain_times_by_shards
             .entry(shard_id)
@@ -1209,6 +1219,8 @@ where
     ) -> Result<()> {
         // TODO: make real implementation
 
+        let _histogram = HistogramGuard::begin("tycho_collator_enqueue_mc_block_collation_time");
+
         // get masterchain collator if exists
         let Some(mc_collator) = self.active_collators.get(&ShardIdent::MASTERCHAIN) else {
             bail!("Masterchain collator is not started yet!");
@@ -1285,6 +1297,8 @@ where
             validation_result.is_valid(),
         );
 
+        let _histogram = HistogramGuard::begin("tycho_collator_process_validated_block_time");
+
         // execute required actions if block invalid
         if !validation_result.is_valid() {
             // TODO: implement more graceful reaction on invalid block

scripts/gen-dashboard.py

@@ -431,6 +431,33 @@ def collator_do_collate() -> RowPanel:
         create_heatmap_panel(
             "tycho_collator_adapter_on_block_accepted_time", "on_block_accepted"
         ),
+        create_heatmap_panel(
+            "tycho_collator_update_mc_data_time", "update mc data"
+        ),
+        create_heatmap_panel(
+            "tycho_collator_import_next_anchor_time", "import next anchor"
+        ),
+        create_heatmap_panel(
+            "tycho_collator_try_collate_next_master_block_time", "collate next master block"
+        ),
+        create_heatmap_panel(
+            "tycho_collator_try_collate_next_shard_block_without_do_collate_time", "collate next shard block"
+        ),
+        create_heatmap_panel(
+            "tycho_collator_refresh_collation_sessions_time", "refresh collation sessions"
+        ),
+        create_heatmap_panel(
+            "tycho_collator_process_collated_block_candidate_time", "process collated block candidate"
+        ),
+        create_heatmap_panel(
+            "tycho_collator_update_last_collated_chain_time_and_check_should_collate_mc_block_time", "update last collated chain time and check should collate mc block"
+        ),
+        create_heatmap_panel(
+            "tycho_collator_enqueue_mc_block_collation_time", "enqueue mc block collation"
+        ),
+        create_heatmap_panel(
+            "tycho_collator_process_validated_block_time", "process validated block"
+        ),
     ]
     return create_row("Collator Do Collate", metrics)
 

util/src/lib.rs

@@ -34,7 +34,7 @@ pub mod test {
 
 pub mod metrics {
     pub use self::gauge_guard::GaugeGuard;
-    pub use self::histogram_guard::HistogramGuard;
+    pub use self::histogram_guard::{HistogramGuard, HistogramGuardWithLabels};
     pub use self::metrics_loop::spawn_metrics_loop;
 
     mod gauge_guard;

util/src/metrics/histogram_guard.rs

@@ -20,3 +20,35 @@ impl Drop for HistogramGuard {
         metrics::histogram!(self.name).record(self.started_at.elapsed());
     }
 }
+
+#[must_use = "The guard is used to update the histogram when it is dropped"]
+pub struct HistogramGuardWithLabels<'a, T: 'static>
+where
+    &'a T: metrics::IntoLabels,
+{
+    name: &'static str,
+    started_at: Instant,
+    labels: &'a T,
+}
+
+impl<'a, T> HistogramGuardWithLabels<'a, T>
+where
+    &'a T: metrics::IntoLabels,
+{
+    pub fn begin(name: &'static str, labels: &'a T) -> Self {
+        Self {
+            name,
+            started_at: Instant::now(),
+            labels,
+        }
+    }
+}
+
+impl<'a, T> Drop for HistogramGuardWithLabels<'a, T>
+where
+    &'a T: metrics::IntoLabels,
+{
+    fn drop(&mut self) {
+        metrics::histogram!(self.name, self.labels).record(self.started_at.elapsed());
+    }
+}