ChainSafe · wemeetagain · Sep 29, 2023 · Sep 27, 2023
@@ -25,7 +25,7 @@ export function createMetrics(
   const lodestar = createLodestarMetrics(register, opts.metadata, anchorState);
 
   const genesisTime = anchorState.genesisTime;
-  const validatorMonitor = createValidatorMonitor(lodestar, config, genesisTime, logger);
+  const validatorMonitor = createValidatorMonitor(lodestar, config, genesisTime, logger, opts);
   // Register a single collect() function to run all validatorMonitor metrics
   lodestar.validatorMonitor.validatorsConnected.addCollect(() => {
     const clockSlot = getCurrentSlot(config, genesisTime);

@@ -1,4 +1,5 @@
 import {HttpMetricsServerOpts} from "./server/index.js";
+import {ValidatorMonitorOpts} from "./validatorMonitor.js";
 
 export type LodestarMetadata = {
   /** "v0.16.0/developer/feature-1/ac99f2b5" */
@@ -9,11 +10,12 @@ export type LodestarMetadata = {
   network: string;
 };
 
-export type MetricsOptions = HttpMetricsServerOpts & {
-  enabled: boolean;
-  /** Optional metadata to send to Prometheus */
-  metadata?: LodestarMetadata;
-};
+export type MetricsOptions = ValidatorMonitorOpts &
+  HttpMetricsServerOpts & {
+    enabled: boolean;
+    /** Optional metadata to send to Prometheus */
+    metadata?: LodestarMetadata;
+  };
 
 export const defaultMetricsOptions: MetricsOptions = {
   enabled: false,

@@ -9,7 +9,7 @@ import {
   getBlockRootAtSlot,
   ParticipationFlags,
 } from "@lodestar/state-transition";
-import {Logger, MapDef, MapDefMax, toHex} from "@lodestar/utils";
+import {LogData, LogHandler, LogLevel, Logger, MapDef, MapDefMax, toHex} from "@lodestar/utils";
 import {RootHex, allForks, altair, deneb} from "@lodestar/types";
 import {ChainConfig, ChainForkConfig} from "@lodestar/config";
 import {ForkSeq, INTERVALS_PER_SLOT, MIN_ATTESTATION_INCLUSION_DELAY, SLOTS_PER_EPOCH} from "@lodestar/params";
@@ -76,6 +76,11 @@ export type ValidatorMonitor = {
   scrapeMetrics(slotClock: Slot): void;
 };
 
+export type ValidatorMonitorOpts = {
+  /** Log validator monitor events as info */
+  validatorMonitorLogs?: boolean;
+};
+
 /** Information required to reward some validator during the current and previous epoch. */
 type ValidatorStatus = {
   /** True if the validator has been slashed, ever. */
@@ -136,7 +141,7 @@ type EpochSummary = {
   /** The delay between when the attestation should have been produced and when it was observed. */
   attestationMinDelay: Seconds | null;
   /** The number of times a validators attestation was seen in an aggregate. */
-  attestationAggregateIncusions: number;
+  attestationAggregateInclusions: number;
   /** The number of times a validators attestation was seen in a block. */
   attestationBlockInclusions: number;
   /** The minimum observed inclusion distance for an attestation for this epoch.. */
@@ -176,7 +181,7 @@ function getEpochSummary(validator: MonitoredValidator, epoch: Epoch): EpochSumm
     summary = {
       attestations: 0,
       attestationMinDelay: null,
-      attestationAggregateIncusions: 0,
+      attestationAggregateInclusions: 0,
       attestationBlockInclusions: 0,
       attestationMinBlockInclusionDistance: null,
       blocks: 0,
@@ -239,8 +244,14 @@ export function createValidatorMonitor(
   metrics: LodestarMetrics,
   config: ChainForkConfig,
   genesisTime: number,
-  logger: Logger
+  logger: Logger,
+  opts: ValidatorMonitorOpts
 ): ValidatorMonitor {
+  const log: LogHandler = (message: string, context?: LogData) => {
+    const logLevel = opts.validatorMonitorLogs ? LogLevel.info : LogLevel.debug;
+    logger[logLevel](message, context);
+  };
+
   /** The validators that require additional monitoring. */
   const validators = new MapDef<ValidatorIndex, MonitoredValidator>(() => ({
     summaries: new Map<Epoch, EpochSummary>(),
@@ -345,8 +356,8 @@ export function createValidatorMonitor(
         }
 
         if (!summary.isPrevSourceAttester || !summary.isPrevTargetAttester || !summary.isPrevHeadAttester) {
-          logger.debug("Failed attestation in previous epoch", {
-            validatorIndex: index,
+          log("Failed attestation in previous epoch", {
+            validator: index,
             prevEpoch: currentEpoch - 1,
             isPrevSourceAttester: summary.isPrevSourceAttester,
             isPrevHeadAttester: summary.isPrevHeadAttester,
@@ -411,13 +422,13 @@ export function createValidatorMonitor(
         if (validator) {
           metrics.validatorMonitor.unaggregatedAttestationSubmittedSentPeers.observe(sentPeers);
           metrics.validatorMonitor.unaggregatedAttestationDelaySeconds.observe({src: OpSource.api}, delaySec);
-          logger.debug("Local validator published unaggregated attestation", {
-            validatorIndex: index,
+          log("Published unaggregated attestation", {
+            validator: index,
             slot: data.slot,
             committeeIndex: data.index,
             subnet,
             sentPeers,
-            delaySec,
+            delaySec: delaySec.toFixed(4),
           });
 
           const attestationSummary = validator.attestations
@@ -461,12 +472,12 @@ export function createValidatorMonitor(
         const validator = validators.get(index);
         if (validator) {
           metrics.validatorMonitor.aggregatedAttestationDelaySeconds.observe({src: OpSource.api}, delaySec);
-          logger.debug("Local validator published aggregated attestation", {
-            validatorIndex: index,
+          log("Published aggregated attestation", {
+            validator: index,
             slot: data.slot,
             committeeIndex: data.index,
             sentPeers,
-            delaySec,
+            delaySec: delaySec.toFixed(4),
           });
 
           validator.attestations
@@ -481,15 +492,15 @@ export function createValidatorMonitor(
       const src = OpSource.gossip;
       const data = indexedAttestation.data;
       const epoch = computeEpochAtSlot(data.slot);
-      // Returns the duration between when a `AggregateAndproof` with `data` could be produced (2/3rd through the slot) and `seenTimestamp`.
+      // Returns the duration between when a `AggregateAndProof` with `data` could be produced (2/3rd through the slot) and `seenTimestamp`.
       const delaySec = seenTimestampSec - (genesisTime + (data.slot + 2 / 3) * config.SECONDS_PER_SLOT);
 
       const aggregatorIndex = signedAggregateAndProof.message.aggregatorIndex;
-      const validtorAggregator = validators.get(aggregatorIndex);
-      if (validtorAggregator) {
+      const validatorAggregator = validators.get(aggregatorIndex);
+      if (validatorAggregator) {
         metrics.validatorMonitor.aggregatedAttestationTotal.inc({src});
         metrics.validatorMonitor.aggregatedAttestationDelaySeconds.observe({src}, delaySec);
-        const summary = getEpochSummary(validtorAggregator, epoch);
+        const summary = getEpochSummary(validatorAggregator, epoch);
         summary.aggregates += 1;
         summary.aggregateMinDelay = Math.min(delaySec, summary.aggregateMinDelay ?? Infinity);
       }
@@ -500,11 +511,12 @@ export function createValidatorMonitor(
           metrics.validatorMonitor.attestationInAggregateTotal.inc({src});
           metrics.validatorMonitor.attestationInAggregateDelaySeconds.observe({src}, delaySec);
           const summary = getEpochSummary(validator, epoch);
-          summary.attestationAggregateIncusions += 1;
-          logger.debug("Local validator attestation is included in AggregatedAndProof", {
-            validatorIndex: index,
+          summary.attestationAggregateInclusions += 1;
+          log("Attestation is included in aggregate", {
+            validator: index,
             slot: data.slot,
             committeeIndex: data.index,
+            aggregatorIndex,
           });
 
           validator.attestations
@@ -562,8 +574,8 @@ export function createValidatorMonitor(
               attestationSlot: indexedAttestation.data.slot,
             });
 
-          logger.debug("Local validator attestation is included in block", {
-            validatorIndex: index,
+          log("Attestation is included in block", {
+            validator: index,
             slot: data.slot,
             committeeIndex: data.index,
             inclusionDistance,
@@ -627,8 +639,12 @@ export function createValidatorMonitor(
         for (const [index, validator] of validators.entries()) {
           const flags = parseParticipationFlags(previousEpochParticipation.get(index));
           const attestationSummary = validator.attestations.get(prevEpoch)?.get(prevEpochTargetRoot);
-          metrics.validatorMonitor.prevEpochAttestationSummary.inc({
-            summary: renderAttestationSummary(config, rootCache, attestationSummary, flags),
+          const summary = renderAttestationSummary(config, rootCache, attestationSummary, flags);
+          metrics.validatorMonitor.prevEpochAttestationSummary.inc({summary});
+          log("Previous epoch attestation", {
+            validator: index,
+            epoch: prevEpoch,
+            summary,
           });
         }
       }
@@ -639,9 +655,15 @@ export function createValidatorMonitor(
           const validator = validators.get(validatorIndex);
           if (validator) {
             // If expected proposer is a tracked validator
-            const summary = validator.summaries.get(prevEpoch);
-            metrics.validatorMonitor.prevEpochBlockProposalSummary.inc({
-              summary: renderBlockProposalSummary(config, rootCache, summary, SLOTS_PER_EPOCH * prevEpoch + slotIndex),
+            const epochSummary = validator.summaries.get(prevEpoch);
+            const proposalSlot = SLOTS_PER_EPOCH * prevEpoch + slotIndex;
+            const summary = renderBlockProposalSummary(config, rootCache, epochSummary, proposalSlot);
+            metrics.validatorMonitor.prevEpochBlockProposalSummary.inc({summary});
+            log("Previous epoch block proposal", {
+              validator: validatorIndex,
+              slot: proposalSlot,
+              epoch: prevEpoch,
+              summary,
             });
           }
         }
@@ -698,7 +720,9 @@ export function createValidatorMonitor(
         metrics.validatorMonitor.prevEpochAttestations.observe(summary.attestations);
         if (summary.attestationMinDelay !== null)
           metrics.validatorMonitor.prevEpochAttestationsMinDelaySeconds.observe(summary.attestationMinDelay);
-        metrics.validatorMonitor.prevEpochAttestationAggregateInclusions.observe(summary.attestationAggregateIncusions);
+        metrics.validatorMonitor.prevEpochAttestationAggregateInclusions.observe(
+          summary.attestationAggregateInclusions
+        );
         metrics.validatorMonitor.prevEpochAttestationBlockInclusions.observe(summary.attestationBlockInclusions);
         if (summary.attestationMinBlockInclusionDistance !== null) {
           metrics.validatorMonitor.prevEpochAttestationBlockMinInclusionDistance.observe(

@@ -169,6 +169,7 @@ export async function beaconHandlerInit(args: BeaconArgs & GlobalArgs) {
   beaconNodeOptions.set({chain: {persistInvalidSszObjectsDir: beaconPaths.persistInvalidSszObjectsDir}});
   // Add metrics metadata to show versioning + network info in Prometheus + Grafana
   beaconNodeOptions.set({metrics: {metadata: {version, commit, network}}});
+  beaconNodeOptions.set({metrics: {validatorMonitorLogs: args.validatorMonitorLogs}});
   // Add detailed version string for API node/version endpoint
   beaconNodeOptions.set({api: {version}});
 

@@ -20,6 +20,7 @@ type BeaconExtraArgs = {
   peerStoreDir?: string;
   persistNetworkIdentity?: boolean;
   private?: boolean;
+  validatorMonitorLogs?: boolean;
   attachToGlobalThis?: boolean;
 };
 
@@ -120,6 +121,11 @@ export const beaconExtraOptions: CliCommandOptions<BeaconExtraArgs> = {
     type: "boolean",
   },
 
+  validatorMonitorLogs: {
+    description: "Log validator monitor events as info. This requires metrics to be enabled.",
+    type: "boolean",
+  },
+
   attachToGlobalThis: {
     hidden: true,
     description: "Attach the beacon node to `globalThis`. Useful to inspect a running beacon node.",