adding timestamp for blocks checked and highest, so we can monitor ho… (#10691)

* adding timestamp for blocks checked and highest, so we can monitor how long ago the block we are using was produced

* adding logs for connecting disputeGame with withdrawalHash

* imporved logs

* adding details on logs for wd-mon and faultproof-wd-mon

* adding extra information for wd-mon also for valid withdrawal

* Update packages/chain-mon/src/wd-mon/service.ts
Co-authored-by: coderabbitai[bot] <136622811+coderabbitai[bot]@users.noreply.github.com>

* Update packages/chain-mon/src/faultproof-wd-mon/service.ts
Co-authored-by: coderabbitai[bot] <136622811+coderabbitai[bot]@users.noreply.github.com>

* fixing object

* improved logs and metrics for wd mon

* added extra logging information and fixing bugs on initial block number

---------
Co-authored-by: coderabbitai[bot] <136622811+coderabbitai[bot]@users.noreply.github.com>

packages/chain-mon/src/faultproof-wd-mon/service.ts

@@ -33,6 +33,8 @@ type Options = {
 type Metrics = {
   highestCheckedBlockNumber: Gauge
   highestKnownBlockNumber: Gauge
+  highestCheckedBlockTimestamp: Gauge
+  highestKnownBlockTimestamp: Gauge
   withdrawalsValidated: Gauge
   invalidProposalWithdrawals: Gauge
   invalidProofWithdrawals: Gauge
@@ -50,11 +52,13 @@ type State = {
     withdrawalHash: string
     senderAddress: string
     disputeGame: ethers.Contract
+    event: ethers.Event
   }>
   invalidProofWithdrawals: Array<{
     withdrawalHash: string
     senderAddress: string
     disputeGame: ethers.Contract
+    event: ethers.Event
   }>
 }
 
@@ -133,11 +137,22 @@ export class FaultProofWithdrawalMonitor extends BaseServiceV2<
           desc: 'Highest L1 block number that we have searched.',
           labels: ['type'],
         },
+        highestCheckedBlockTimestamp: {
+          type: Gauge,
+          desc: 'Timestamp of the highest L1 block number that we have searched.',
+          labels: ['type'],
+        },
         highestKnownBlockNumber: {
           type: Gauge,
           desc: 'Highest L1 block number that we have seen.',
           labels: ['type'],
         },
+        highestKnownBlockTimestamp: {
+          type: Gauge,
+          desc: 'Timestamp of the highest L1 block number that we have seen.',
+          labels: ['type'],
+        },
+
         invalidProposalWithdrawals: {
           type: Gauge,
           desc: 'Number of withdrawals against invalid proposals.',
@@ -212,6 +227,22 @@ export class FaultProofWithdrawalMonitor extends BaseServiceV2<
       this.state.highestUncheckedBlockNumber =
         DEFAULT_STARTING_BLOCK_NUMBERS[l2ChainId] || 0
     }
+    this.logger.info(
+      `initialized starting at block number ${this.state.highestUncheckedBlockNumber}`
+    )
+
+    //make sure the highestUncheckedBlockNumber is not higher than the latest block number on chain
+    const latestL1BlockNumber =
+      await this.options.l1RpcProvider.getBlockNumber()
+
+    this.state.highestUncheckedBlockNumber = Math.min(
+      this.state.highestUncheckedBlockNumber,
+      latestL1BlockNumber
+    )
+
+    this.logger.info(
+      `starting at block number ${this.state.highestUncheckedBlockNumber}`
+    )
 
     // Default state is that forgeries have not been detected.
     this.state.forgeryDetected = false
@@ -247,6 +278,14 @@ export class FaultProofWithdrawalMonitor extends BaseServiceV2<
       const disputeGameAddress = disputeGame.address
       const isGameBlacklisted =
         this.state.portal.disputeGameBlacklist(disputeGameAddress)
+      const event = disputeGameData.event
+      const block = await event.getBlock()
+      const ts =
+        dateformat(
+          new Date(block.timestamp * 1000),
+          'mmmm dS, yyyy, h:MM:ss TT',
+          true
+        ) + ' UTC'
 
       if (isGameBlacklisted) {
         this.state.invalidProposalWithdrawals.splice(i, 1)
@@ -254,18 +293,57 @@ export class FaultProofWithdrawalMonitor extends BaseServiceV2<
         const status = await disputeGame.status()
         if (status === GameStatus.CHALLENGER_WINS) {
           this.state.invalidProposalWithdrawals.splice(i, 1)
+          this.logger.info(
+            `withdrawalHash not seen on L2 - game correctly resolved`,
+            {
+              withdrawalHash: event.args.withdrawalHash,
+              provenAt: ts,
+              disputeGameAddress: disputeGame.address,
+              blockNumber: block.number,
+              transaction: event.transactionHash,
+            }
+          )
         } else if (status === GameStatus.DEFENDER_WINS) {
+          this.logger.error(
+            `withdrawalHash not seen on L2 - forgery detected`,
+            {
+              withdrawalHash: event.args.withdrawalHash,
+              provenAt: ts,
+              disputeGameAddress: disputeGame.address,
+              blockNumber: block.number,
+              transaction: event.transactionHash,
+            }
+          )
           this.state.forgeryDetected = true
           this.metrics.isDetectingForgeries.set(
             Number(this.state.forgeryDetected)
           )
+        } else {
+          this.logger.warn(
+            `withdrawalHash not seen on L2 - game still IN_PROGRESS`,
+            {
+              withdrawalHash: event.args.withdrawalHash,
+              provenAt: ts,
+              disputeGameAddress: disputeGame.address,
+              blockNumber: block.number,
+              transaction: event.transactionHash,
+            }
+          )
         }
       }
     }
-    // Get the latest L1 block number.
     let latestL1BlockNumber: number
+    let latestL1Block: ethers.providers.Block
+    let highestUncheckedBlock: ethers.providers.Block
     try {
+      // Get the latest L1 block number.
       latestL1BlockNumber = await this.options.l1RpcProvider.getBlockNumber()
+      latestL1Block = await this.options.l1RpcProvider.getBlock(
+        latestL1BlockNumber
+      )
+      highestUncheckedBlock = await this.options.l1RpcProvider.getBlock(
+        this.state.highestUncheckedBlockNumber
+      )
     } catch (err) {
       // Log the issue so we can debug it.
       this.logger.error(`got error when connecting to node`, {
@@ -285,10 +363,22 @@ export class FaultProofWithdrawalMonitor extends BaseServiceV2<
     }
 
     // Update highest block number metrics so we can keep track of how the service is doing.
-    this.metrics.highestKnownBlockNumber.set(latestL1BlockNumber)
     this.metrics.highestCheckedBlockNumber.set(
+      { type: 'L1' },
       this.state.highestUncheckedBlockNumber
     )
+    this.metrics.highestKnownBlockNumber.set(
+      { type: 'L1' },
+      latestL1BlockNumber
+    )
+    this.metrics.highestCheckedBlockTimestamp.set(
+      { type: 'L1' },
+      highestUncheckedBlock.timestamp
+    )
+    this.metrics.highestKnownBlockTimestamp.set(
+      { type: 'L1' },
+      latestL1Block.timestamp
+    )
 
     // Check if the RPC provider is behind us for some reason. Can happen occasionally,
     // particularly if connected to an RPC provider that load balances over multiple nodes that
@@ -310,6 +400,9 @@ export class FaultProofWithdrawalMonitor extends BaseServiceV2<
     this.logger.info(`checking recent blocks`, {
       fromBlockNumber: this.state.highestUncheckedBlockNumber,
       toBlockNumber,
+      latestL1BlockNumber,
+      percentageDone:
+        Math.floor((toBlockNumber / latestL1BlockNumber) * 100) + '% done',
     })
 
     // Query for WithdrawalProven events within the specified block range.
@@ -371,6 +464,10 @@ export class FaultProofWithdrawalMonitor extends BaseServiceV2<
             // Unlike below we don't grab the timestamp here because it adds an unnecessary request.
             this.logger.info(`valid withdrawal`, {
               withdrawalHash: event.args.withdrawalHash,
+              provenAt: ts,
+              disputeGameAddress: disputeGame.address,
+              blockNumber: block.number,
+              transaction: event.transactionHash,
             })
 
             // Bump the withdrawals metric so we can keep track.
@@ -379,10 +476,16 @@ export class FaultProofWithdrawalMonitor extends BaseServiceV2<
             this.state.invalidProofWithdrawals.push(disputeGameData)
 
             // Uh oh!
-            this.logger.error(`withdrawalHash not seen on L2`, {
+            this.logger.error(
+              `withdrawalHash not seen on L2 - forgery detected`,
+              {
                 withdrawalHash: event.args.withdrawalHash,
                 provenAt: ts,
-            })
+                disputeGameAddress: disputeGame.address,
+                blockNumber: block.number,
+                transaction: event.transactionHash,
+              }
+            )
 
             // Change to forgery state.
             this.state.forgeryDetected = true
@@ -392,9 +495,10 @@ export class FaultProofWithdrawalMonitor extends BaseServiceV2<
           }
         } else {
           this.state.invalidProposalWithdrawals.push(disputeGameData)
-          this.logger.info(`invalid proposal`, {
+          this.logger.warn(`invalid proposal`, {
             withdrawalHash: event.args.withdrawalHash,
             provenAt: ts,
+            disputeGameAddress: disputeGame.address,
           })
         }
       }
@@ -410,18 +514,20 @@ export class FaultProofWithdrawalMonitor extends BaseServiceV2<
    * @param event The event containing the withdrawal hash.
    * @returns An array of objects containing the withdrawal hash, sender address, and dispute game address.
    */
-  async getWithdrawalDisputeGames(event: ethers.Event): Promise<
+  async getWithdrawalDisputeGames(event_in: ethers.Event): Promise<
     Array<{
       withdrawalHash: string
       senderAddress: string
       disputeGame: ethers.Contract
+      event: ethers.Event
     }>
   > {
-    const withdrawalHash = event.args.withdrawalHash
+    const withdrawalHash = event_in.args.withdrawalHash
     const disputeGameMap: Array<{
       withdrawalHash: string
       senderAddress: string
       disputeGame: ethers.Contract
+      event: ethers.Event
     }> = []
 
     const numProofSubmitter = await this.state.portal.numProofSubmitters(
@@ -450,6 +556,7 @@ export class FaultProofWithdrawalMonitor extends BaseServiceV2<
           withdrawalHash,
           senderAddress: proofSubmitter,
           disputeGame: disputeGame_,
+          event: event_in,
         })
       })
     )

packages/chain-mon/src/wd-mon/service.ts

@@ -30,6 +30,7 @@ type Metrics = {
   withdrawalsValidated: Gauge
   isDetectingForgeries: Gauge
   nodeConnectionFailures: Gauge
+  detectedForgeries: Gauge
 }
 
 type State = {
@@ -110,6 +111,11 @@ export class WithdrawalMonitor extends BaseServiceV2<Options, Metrics, State> {
           desc: 'Number of times node connection has failed',
           labels: ['layer', 'section'],
         },
+        detectedForgeries: {
+          type: Gauge,
+          desc: 'detected forged withdrawals',
+          labels: ['withdrawalHash', 'provenAt', 'blockNumber', 'transaction'],
+        },
       },
     })
   }
@@ -223,6 +229,9 @@ export class WithdrawalMonitor extends BaseServiceV2<Options, Metrics, State> {
     this.logger.info(`checking recent blocks`, {
       fromBlockNumber: this.state.highestUncheckedBlockNumber,
       toBlockNumber,
+      latestL1BlockNumber,
+      percentageDone:
+        Math.floor((toBlockNumber / latestL1BlockNumber) * 100) + '% done',
     })
 
     // Query for WithdrawalProven events within the specified block range.
@@ -257,39 +266,50 @@ export class WithdrawalMonitor extends BaseServiceV2<Options, Metrics, State> {
       const hash = event.args.withdrawalHash
       const exists = await this.state.messenger.sentMessages(hash)
 
+      const block = await event.getBlock()
+      const ts = `${dateformat(
+        new Date(block.timestamp * 1000),
+        'mmmm dS, yyyy, h:MM:ss TT',
+        true
+      )} UTC`
+
       // Hopefully the withdrawal exists!
       if (exists) {
         // Unlike below we don't grab the timestamp here because it adds an unnecessary request.
         this.logger.info(`valid withdrawal`, {
           withdrawalHash: event.args.withdrawalHash,
+          provenAt: ts,
+          blockNumber: block.number,
+          transaction: event.transactionHash,
         })
 
         // Bump the withdrawals metric so we can keep track.
         this.metrics.withdrawalsValidated.inc()
       } else {
         // Grab and format the timestamp so it's clear how much time is left.
-        const block = await event.getBlock()
-        const ts = `${dateformat(
-          new Date(block.timestamp * 1000),
-          'mmmm dS, yyyy, h:MM:ss TT',
-          true
-        )} UTC`
 
         // Uh oh!
         this.logger.error(`withdrawalHash not seen on L2`, {
           withdrawalHash: event.args.withdrawalHash,
-          provenAt: ts,
+          provenAt:
+            dateformat(
+              new Date(block.timestamp * 1000),
+              'mmmm dS, yyyy, h:MM:ss TT',
+              true
+            ) + ' UTC',
+          blockNumber: block.number.toString(),
+          transaction: event.transactionHash,
         })
 
         // Change to forgery state.
         this.state.forgeryDetected = true
         this.metrics.isDetectingForgeries.set(1)
-
-        // Return early so that we never increment the highest unchecked block number and therefore
-        // will continue to loop on this forgery indefinitely. We probably want to change this
-        // behavior at some point so that we keep scanning for additional forgeries since the
-        // existence of one forgery likely implies the existence of many others.
-        return sleep(this.options.sleepTimeMs)
+        this.metrics.detectedForgeries.inc({
+          withdrawalHash: hash,
+          provenAt: ts,
+          blockNumber: block.number.toString(),
+          transaction: event.transactionHash,
+        })
       }
     }