feat: track epoch transition steps time in metrics

packages/beacon-node/src/metrics/metrics/lodestar.ts

@@ -286,6 +286,56 @@ export function createLodestarMetrics(
       help: "Time to call commit after process a single epoch transition in seconds",
       buckets: [0.01, 0.05, 0.1, 0.2, 0.5, 0.75, 1],
     }),
+    epochTransitionBeforeProcessEpochTime: register.histogram({
+      name: "lodestar_stfn_epoch_transition_before_process_epoch_seconds",
+      help: "Time to call beforeProcessEpoch before process a single epoch transition in seconds",
+      buckets: [0.01, 0.05, 0.1, 0.2, 0.5, 0.75, 1],
+    }),
+    epochTransitionAfterProcessEpochTime: register.histogram({
+      name: "lodestar_stfn_epoch_transition_after_process_epoch_seconds",
+      help: "Time to call afterProcessEpoch after process a single epoch transition in seconds",
+      buckets: [0.01, 0.05, 0.1, 0.2, 0.5, 0.75, 1],
+    }),
+    epochTransitionJustificationAndFinalizationTime: register.histogram({
+      name: "lodestar_stfn_epoch_transition_justification_and_finalization_seconds",
+      help: "Time to process justification and finalization in seconds",
+      buckets: [0.01, 0.05, 0.1, 0.2, 0.5, 0.75, 1],
+    }),
+    epochTransitionInactivityUpdatesTime: register.histogram({
+      name: "lodestar_stfn_epoch_transition_inactivity_updates_seconds",
+      help: "Time to process inactivity updates in seconds",
+      buckets: [0.01, 0.05, 0.1, 0.2, 0.5, 0.75, 1],
+    }),
+    epochTransitionRewardsAndPenaltiesTime: register.histogram({
+      name: "lodestar_stfn_epoch_transition_rewards_and_penalties_seconds",
+      help: "Time to process rewards and penalties in seconds",
+      buckets: [0.01, 0.05, 0.1, 0.2, 0.5, 0.75, 1],
+    }),
+    epochTransitionRegistryUpdatesTime: register.histogram({
+      name: "lodestar_stfn_epoch_transition_registry_updates_seconds",
+      help: "Time to process registry updates in seconds",
+      buckets: [0.01, 0.05, 0.1, 0.2, 0.5, 0.75, 1],
+    }),
+    epochTransitionSlashingsTime: register.histogram({
+      name: "lodestar_stfn_epoch_transition_slashings_seconds",
+      help: "Time to process slashings in seconds",
+      buckets: [0.01, 0.05, 0.1, 0.2, 0.5, 0.75, 1],
+    }),
+    epochTransitionEffectiveBalanceUpdatesTime: register.histogram({
+      name: "lodestar_stfn_epoch_transition_effective_balance_updates_seconds",
+      help: "Time to process effective balance updates in seconds",
+      buckets: [0.01, 0.05, 0.1, 0.2, 0.5, 0.75, 1],
+    }),
+    epochTransitionParticipationFlagUpdatesTime: register.histogram({
+      name: "lodestar_stfn_epoch_transition_participation_flag_updates_seconds",
+      help: "Time to process participation flag updates in seconds",
+      buckets: [0.01, 0.05, 0.1, 0.2, 0.5, 0.75, 1],
+    }),
+    epochTransitionSyncCommitteeUpdatesTime: register.histogram({
+      name: "lodestar_stfn_epoch_transition_sync_committee_updates_seconds",
+      help: "Time to process sync committee updates in seconds",
+      buckets: [0.01, 0.05, 0.1, 0.2, 0.5, 0.75, 1],
+    }),
     processBlockTime: register.histogram({
       name: "lodestar_stfn_process_block_seconds",
       help: "Time to process a single block in seconds",

packages/state-transition/src/epoch/index.ts

@@ -12,6 +12,7 @@ import {
   CachedBeaconStatePhase0,
   EpochTransitionCache,
 } from "../types.js";
+import {BeaconStateTransitionMetrics} from "../metrics.js";
 import {processEffectiveBalanceUpdates} from "./processEffectiveBalanceUpdates.js";
 import {processEth1DataReset} from "./processEth1DataReset.js";
 import {processHistoricalRootsUpdate} from "./processHistoricalRootsUpdate.js";
@@ -50,7 +51,12 @@ export {computeUnrealizedCheckpoints} from "./computeUnrealizedCheckpoints.js";
 const maxValidatorsPerStateSlashing = SLOTS_PER_EPOCH * MAX_ATTESTER_SLASHINGS * MAX_VALIDATORS_PER_COMMITTEE;
 const maxSafeValidators = Math.floor(Number.MAX_SAFE_INTEGER / MAX_EFFECTIVE_BALANCE);
 
-export function processEpoch(fork: ForkSeq, state: CachedBeaconStateAllForks, cache: EpochTransitionCache): void {
+export function processEpoch(
+  fork: ForkSeq,
+  state: CachedBeaconStateAllForks,
+  cache: EpochTransitionCache,
+  metrics?: BeaconStateTransitionMetrics | null
+): void {
   // state.slashings is initially a Gwei (BigInt) vector, however since Nov 2023 it's converted to UintNum64 (number) vector in the state transition because:
   //  - state.slashings[nextEpoch % EPOCHS_PER_SLASHINGS_VECTOR] is reset per epoch in processSlashingsReset()
   //  - max slashed validators per epoch is SLOTS_PER_EPOCH * MAX_ATTESTER_SLASHINGS * MAX_VALIDATORS_PER_COMMITTEE which is 32 * 2 * 2048 = 131072 on mainnet
@@ -59,19 +65,31 @@ export function processEpoch(fork: ForkSeq, state: CachedBeaconStateAllForks, ca
     throw new Error("Lodestar does not support this network, parameters don't fit number value inside state.slashings");
   }
 
+  let timer = metrics?.epochTransitionJustificationAndFinalizationTime.startTimer();
   processJustificationAndFinalization(state, cache);
+  timer?.();
   if (fork >= ForkSeq.altair) {
+    timer = metrics?.epochTransitionInactivityUpdatesTime.startTimer();
     processInactivityUpdates(state as CachedBeaconStateAltair, cache);
+    timer?.();
   }
   // processRewardsAndPenalties() is 2nd step in the specs, we optimize to do it
   // after processSlashings() to update balances only once
   // processRewardsAndPenalties(state, cache);
+  timer = metrics?.epochTransitionRegistryUpdatesTime.startTimer();
   processRegistryUpdates(state, cache);
+  timer?.();
   // accumulate slashing penalties and only update balances once in processRewardsAndPenalties()
+  timer = metrics?.epochTransitionSlashingsTime.startTimer();
   const slashingPenalties = processSlashings(state, cache, false);
+  timer?.();
+  timer = metrics?.epochTransitionRewardsAndPenaltiesTime.startTimer();
   processRewardsAndPenalties(state, cache, slashingPenalties);
+  timer?.();
   processEth1DataReset(state, cache);
+  timer = metrics?.epochTransitionEffectiveBalanceUpdatesTime.startTimer();
   processEffectiveBalanceUpdates(state, cache);
+  timer?.();
   processSlashingsReset(state, cache);
   processRandaoMixesReset(state, cache);
 
@@ -84,7 +102,11 @@ export function processEpoch(fork: ForkSeq, state: CachedBeaconStateAllForks, ca
   if (fork === ForkSeq.phase0) {
     processParticipationRecordUpdates(state as CachedBeaconStatePhase0);
   } else {
+    timer = metrics?.epochTransitionParticipationFlagUpdatesTime.startTimer();
     processParticipationFlagUpdates(state as CachedBeaconStateAltair);
+    timer?.();
+    timer = metrics?.epochTransitionSyncCommitteeUpdatesTime.startTimer();
     processSyncCommitteeUpdates(state as CachedBeaconStateAltair);
+    timer?.();
   }
 }

packages/state-transition/src/metrics.ts

@@ -5,6 +5,16 @@ import {AttesterStatus} from "./util/attesterStatus.js";
 export type BeaconStateTransitionMetrics = {
   epochTransitionTime: Histogram;
   epochTransitionCommitTime: Histogram;
+  epochTransitionBeforeProcessEpochTime: Histogram;
+  epochTransitionAfterProcessEpochTime: Histogram;
+  epochTransitionJustificationAndFinalizationTime: Histogram;
+  epochTransitionInactivityUpdatesTime: Histogram;
+  epochTransitionRewardsAndPenaltiesTime: Histogram;
+  epochTransitionRegistryUpdatesTime: Histogram;
+  epochTransitionSlashingsTime: Histogram;
+  epochTransitionEffectiveBalanceUpdatesTime: Histogram;
+  epochTransitionParticipationFlagUpdatesTime: Histogram;
+  epochTransitionSyncCommitteeUpdatesTime: Histogram;
   processBlockTime: Histogram;
   processBlockCommitTime: Histogram;
   stateHashTreeRootTime: Histogram;

packages/state-transition/src/stateTransition.ts

@@ -164,14 +164,17 @@ function processSlotsWithTransientCache(
       const fork = postState.config.getForkSeq(postState.slot);
 
       const epochTransitionTimer = metrics?.epochTransitionTime.startTimer();
-
+      const beforeProcessEpochTimer = metrics?.epochTransitionBeforeProcessEpochTime.startTimer();
       const epochTransitionCache = beforeProcessEpoch(postState, epochTransitionCacheOpts);
+      beforeProcessEpochTimer?.();
       processEpoch(fork, postState, epochTransitionCache);
       const {currentEpoch, statuses, balances} = epochTransitionCache;
       metrics?.registerValidatorStatuses(currentEpoch, statuses, balances);
 
       postState.slot++;
+      const afterProcessEpochTimer = metrics?.epochTransitionAfterProcessEpochTime.startTimer();
       postState.epochCtx.afterProcessEpoch(postState, epochTransitionCache);
+      afterProcessEpochTimer?.();
 
       // Running commit here is not strictly necessary. The cost of running commit twice (here + after process block)
       // Should be negligible but gives better metrics to differentiate the cost of it for block and epoch proc.