Review metrics (#4475)

* Review metrics

* Update PrepareNextSlot mocks

packages/beacon-node/src/api/impl/validator/index.ts

@@ -217,7 +217,7 @@ export function getValidatorApi({chain, config, logger, metrics, network, sync}:
       // forkChoice.updateTime() might have already been called by the onSlot clock
       // handler, in which case this should just return.
       chain.forkChoice.updateTime(slot);
-      chain.forkChoice.updateHead();
+      chain.recomputeForkChoiceHead();
 
       timer = metrics?.blockProductionTime.startTimer();
       const block = await assembleBlock(

packages/beacon-node/src/chain/blocks/importBlock.ts

@@ -146,10 +146,10 @@ export async function importBlock(
     // Note: in-lined code from previos handler of ChainEvent.checkpoint
     this.logger.verbose("Checkpoint processed", toCheckpointHex(cp));
 
-    this.metrics?.currentValidators.set(
-      {status: "active"},
-      checkpointState.epochCtx.currentShuffling.activeIndices.length
-    );
+    const activeValidatorsCount = checkpointState.epochCtx.currentShuffling.activeIndices.length;
+    this.metrics?.currentActiveValidators.set(activeValidatorsCount);
+    this.metrics?.currentValidators.set({status: "active"}, activeValidatorsCount);
+
     const parentBlockSummary = this.forkChoice.getBlock(checkpointState.latestBlockHeader.parentRoot);
 
     if (parentBlockSummary) {
@@ -175,18 +175,17 @@ export async function importBlock(
 
   // Emit ChainEvent.forkChoiceHead event
   const oldHead = this.forkChoice.getHead();
-  const newHead = this.forkChoice.updateHead();
+  const newHead = this.recomputeForkChoiceHead();
   const currFinalizedEpoch = this.forkChoice.getFinalizedCheckpoint().epoch;
 
   if (newHead.blockRoot !== oldHead.blockRoot) {
     // new head
     pendingEvents.push(ChainEvent.forkChoiceHead, newHead);
-    this.metrics?.forkChoiceChangedHead.inc();
+    this.metrics?.forkChoice.changedHead.inc();
 
     const distance = this.forkChoice.getCommonAncestorDistance(oldHead, newHead);
     if (distance !== null) {
       // chain reorg
-      this.metrics?.forkChoiceReorg.inc();
       this.logger.verbose("Chain reorg", {
         depth: distance,
         previousHead: oldHead.blockRoot,
@@ -196,9 +195,11 @@ export async function importBlock(
         newHeadParent: newHead.parentRoot,
         newSlot: newHead.slot,
       });
+
       pendingEvents.push(ChainEvent.forkChoiceReorg, newHead, oldHead, distance);
-      this.metrics?.forkChoiceReorg.inc();
-      this.metrics?.forkChoiceReorgDistance.observe(distance);
+
+      this.metrics?.forkChoice.reorg.inc();
+      this.metrics?.forkChoice.reorgDistance.observe(distance);
     }
 
     // Lightclient server support (only after altair)

packages/beacon-node/src/chain/bls/multithread/index.ts

@@ -357,6 +357,7 @@ export class BlsMultiThreadWorkerPool implements IBlsVerifier {
       const latencyToWorkerSec = Number(workerStartNs - jobStartNs) / 1e9;
       const latencyFromWorkerSec = Number(jobEndNs - workerEndNs) / 1e9;
 
+      this.metrics?.blsThreadPool.timePerSigSet.observe(workerJobTimeSec / startedSigSets);
       this.metrics?.blsThreadPool.jobsWorkerTime.inc({workerId}, workerJobTimeSec);
       this.metrics?.blsThreadPool.latencyToWorker.observe(latencyToWorkerSec);
       this.metrics?.blsThreadPool.latencyFromWorker.observe(latencyFromWorkerSec);

packages/beacon-node/src/chain/bls/singleThread.ts

@@ -13,19 +13,25 @@ export class BlsSingleThreadVerifier implements IBlsVerifier {
 
   async verifySignatureSets(sets: ISignatureSet[]): Promise<boolean> {
     this.metrics?.bls.aggregatedPubkeys.inc(getAggregatedPubkeysCount(sets));
-    const timer = this.metrics?.blsThreadPool.mainThreadDurationInThreadPool.startTimer();
-
-    try {
-      return verifySignatureSetsMaybeBatch(
-        sets.map((set) => ({
-          publicKey: getAggregatedPubkey(set),
-          message: set.signingRoot,
-          signature: set.signature,
-        }))
-      );
-    } finally {
-      if (timer) timer();
-    }
+
+    const setsAggregated = sets.map((set) => ({
+      publicKey: getAggregatedPubkey(set),
+      message: set.signingRoot,
+      signature: set.signature,
+    }));
+
+    // Count time after aggregating
+    const startNs = process.hrtime.bigint();
+
+    const isValid = verifySignatureSetsMaybeBatch(setsAggregated);
+
+    // Don't use a try/catch, only count run without exceptions
+    const endNs = process.hrtime.bigint();
+    const totalSec = Number(startNs - endNs) / 1e9;
+    this.metrics?.blsThreadPool.mainThreadDurationInThreadPool.observe(totalSec);
+    this.metrics?.blsThreadPool.mainThreadDurationInThreadPool.observe(totalSec / sets.length);
+
+    return isValid;
   }
 
   async close(): Promise<void> {

packages/beacon-node/src/chain/chain.ts

@@ -222,8 +222,7 @@ export class BeaconChain implements IBeaconChain {
       clock.currentSlot,
       cachedState,
       opts,
-      this.justifiedBalancesGetter.bind(this),
-      metrics
+      this.justifiedBalancesGetter.bind(this)
     );
     const regen = new QueuedStateRegenerator({
       config,
@@ -357,6 +356,20 @@ export class BeaconChain implements IBeaconChain {
     };
   }
 
+  recomputeForkChoiceHead(): ProtoBlock {
+    this.metrics?.forkChoice.requests.inc();
+    const timer = this.metrics?.forkChoice.findHead.startTimer();
+
+    try {
+      return this.forkChoice.updateHead();
+    } catch (e) {
+      this.metrics?.forkChoice.errors.inc();
+      throw e;
+    } finally {
+      timer?.();
+    }
+  }
+
   /**
    * Returns Promise that resolves either on block found or once 1 slot passes.
    * Used to handle unknown block root for both unaggregated and aggregated attestations.

packages/beacon-node/src/chain/forkChoice/index.ts

@@ -18,7 +18,6 @@ import {
 
 import {computeAnchorCheckpoint} from "../initState.js";
 import {ChainEventEmitter} from "../emitter.js";
-import {IMetrics} from "../../metrics/index.js";
 import {ChainEvent} from "../emitter.js";
 import {GENESIS_SLOT} from "../../constants/index.js";
 
@@ -33,8 +32,7 @@ export function initializeForkChoice(
   currentSlot: Slot,
   state: CachedBeaconStateAllForks,
   opts: ForkChoiceOpts,
-  justifiedBalancesGetter: JustifiedBalancesGetter,
-  metrics?: IMetrics | null
+  justifiedBalancesGetter: JustifiedBalancesGetter
 ): ForkChoice {
   const {blockHeader, checkpoint} = computeAnchorCheckpoint(config, state);
   const finalizedCheckpoint = {...checkpoint};
@@ -90,7 +88,6 @@ export function initializeForkChoice(
       currentSlot
     ),
 
-    opts,
-    metrics
+    opts
   );
 }

packages/beacon-node/src/chain/interface.ts

@@ -4,7 +4,7 @@ import {IBeaconConfig} from "@lodestar/config";
 import {CompositeTypeAny, TreeView, Type} from "@chainsafe/ssz";
 import {ILogger} from "@lodestar/utils";
 
-import {IForkChoice} from "@lodestar/fork-choice";
+import {IForkChoice, ProtoBlock} from "@lodestar/fork-choice";
 import {IEth1ForBlockProduction} from "../eth1/index.js";
 import {IExecutionEngine, IExecutionBuilder} from "../execution/index.js";
 import {IBeaconClock} from "./clock/interface.js";
@@ -113,6 +113,8 @@ export interface IBeaconChain {
 
   getStatus(): phase0.Status;
 
+  recomputeForkChoiceHead(): ProtoBlock;
+
   waitForBlockOfAttestation(slot: Slot, root: RootHex): Promise<boolean>;
 
   updateBeaconProposerData(epoch: Epoch, proposers: ProposerPreparationData[]): Promise<void>;

packages/beacon-node/src/chain/prepareNextSlot.ts

@@ -72,7 +72,7 @@ export class PrepareNextSlotScheduler {
       await sleep(slotMs - slotMs / SCHEDULER_LOOKAHEAD_FACTOR, this.signal);
 
       // calling updateHead() here before we produce a block to reduce reorg possibility
-      const {slot: headSlot, blockRoot: headRoot} = this.chain.forkChoice.updateHead();
+      const {slot: headSlot, blockRoot: headRoot} = this.chain.recomputeForkChoiceHead();
 
       // PS: previously this was comparing slots, but that gave no leway on the skipped
       // slots on epoch bounday. Making it more fluid.

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

@@ -25,7 +25,7 @@ export function createMetrics(
   const genesisTime = anchorState.genesisTime;
   const validatorMonitor = createValidatorMonitor(lodestar, config, genesisTime, logger);
   // Register a single collect() function to run all validatorMonitor metrics
-  lodestar.validatorMonitor.validatorsTotal.addCollect(() => {
+  lodestar.validatorMonitor.validatorsConnected.addCollect(() => {
     const clockSlot = getCurrentSlot(config, genesisTime);
     validatorMonitor.scrapeMetrics(clockSlot);
   });