diff --git a/collator/src/collator/do_collate.rs b/collator/src/collator/do_collate.rs index 962a85ef8..c40be83ed 100644 --- a/collator/src/collator/do_collate.rs +++ b/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; diff --git a/collator/src/collator/mod.rs b/collator/src/collator/mod.rs index eed8fc21a..c2975a9be 100644 --- a/collator/src/collator/mod.rs +++ b/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, 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(); diff --git a/collator/src/manager/mod.rs b/collator/src/manager/mod.rs index dabc39f9d..dec3a15fa 100644 --- a/collator/src/manager/mod.rs +++ b/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 diff --git a/scripts/gen-dashboard.py b/scripts/gen-dashboard.py index 1c2378287..98df52d09 100644 --- a/scripts/gen-dashboard.py +++ b/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) diff --git a/util/src/lib.rs b/util/src/lib.rs index 1bd937454..75320e1b8 100644 --- a/util/src/lib.rs +++ b/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; diff --git a/util/src/metrics/histogram_guard.rs b/util/src/metrics/histogram_guard.rs index 55efd693d..39d1a6a93 100644 --- a/util/src/metrics/histogram_guard.rs +++ b/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()); + } +}