More Interop Improvements (#2506)

* Fewer tx pool statistics

* Only emit synchronized event if synchronized status change, explicitly set synchronized to false in non-synced case

* Switch from interval to sequential payload and forkchoice logging after chain sync completed, added missing synchronized message

* Adjusted skeleton canonical chain fill status log interval

* Reduce RLPx server restarts in a post-Merge world

* Lint fix

* Test fixes

* Test fixes

packages/client/lib/client.ts

@@ -116,9 +116,6 @@ export class EthereumClient {
         `Server listener up transport=${details.transport} url=${details.url}`
       )
     })
-    this.config.events.on(Event.SYNC_SYNCHRONIZED, (height) => {
-      this.config.logger.info(`Synchronized blockchain at height=${height}`)
-    })
 
     await Promise.all(this.services.map((s) => s.open()))
 

packages/client/lib/net/peerpool.ts

@@ -1,3 +1,5 @@
+import { Hardfork } from '@ethereumjs/common'
+
 import { Event } from '../types'
 
 import { RlpxServer } from './server'
@@ -226,9 +228,13 @@ export class PeerPool {
    * Peer pool status check on a repeated interval
    */
   async _statusCheck() {
+    let NO_PEER_PERIOD_COUNT = 3
+    if (this.config.chainCommon.gteHardfork(Hardfork.Merge)) {
+      NO_PEER_PERIOD_COUNT = 6
+    }
     if (this.size === 0) {
       this.noPeerPeriods += 1
-      if (this.noPeerPeriods >= 3) {
+      if (this.noPeerPeriods >= NO_PEER_PERIOD_COUNT) {
         this.noPeerPeriods = 0
         const promises = this.config.servers.map(async (server) => {
           if (server instanceof RlpxServer) {

packages/client/lib/rpc/modules/engine.ts

@@ -463,6 +463,9 @@ export class Engine {
    */
   private async newPayload(params: [ExecutionPayload]): Promise<PayloadStatusV1> {
     const [payload] = params
+    if (this.config.synchronized) {
+      this.connectionManager.newPayloadLog()
+    }
     const { parentHash, blockHash } = payload
     const { block, error } = await assembleBlock(payload, this.chain)
     if (!block || error) {
@@ -653,6 +656,10 @@ export class Engine {
     const { headBlockHash, finalizedBlockHash, safeBlockHash } = params[0]
     const payloadAttributes = params[1]
 
+    if (this.config.synchronized) {
+      this.connectionManager.newForkchoiceLog()
+    }
+
     // It is possible that newPayload didn't start beacon sync as the payload it was asked to
     // evaluate didn't require syncing beacon. This can happen if the EL<>CL starts and CL
     // starts from a bit behind like how lodestar does
@@ -754,7 +761,16 @@ export class Engine {
           this.config.syncTargetHeight < headBlock.header.number) &&
         timeDiff < 30
       ) {
-        this.config.synchronized = true
+        if (!this.config.synchronized) {
+          // TODO: this has side effects if generalized by emitting SYNC_SYNCHRONIZED
+          // event, consolidate at some point
+          this.config.logger.info('*'.repeat(60))
+          this.config.logger.info(
+            `Synchronized blockchain at height=${this.chain.headers.height} 🎉`
+          )
+          this.config.logger.info('*'.repeat(60))
+          this.config.synchronized = true
+        }
         this.config.lastSyncDate = Date.now()
         this.config.syncTargetHeight = headBlock.header.number
         this.service.txPool.checkRunState()

packages/client/lib/rpc/util/CLConnectionManager.ts

@@ -107,11 +107,11 @@ export class CLConnectionManager {
       this.DEFAULT_CONNECTION_CHECK_INTERVAL
     )
     this._payloadLogInterval = setInterval(
-      this.payloadLog.bind(this),
+      this.lastPayloadLog.bind(this),
       this.DEFAULT_PAYLOAD_LOG_INTERVAL
     )
     this._forkchoiceLogInterval = setInterval(
-      this.forkchoiceLog.bind(this),
+      this.lastForkchoiceLog.bind(this),
       this.DEFAULT_FORKCHOICE_LOG_INTERVAL
     )
   }
@@ -258,32 +258,57 @@ export class CLConnectionManager {
   /**
    * Regular payload request logs
    */
-  private payloadLog() {
+  private lastPayloadLog() {
     if (this.connectionStatus !== ConnectionStatus.Connected) {
       return
     }
-    if (!this._lastPayload) {
-      this.config.logger.info('No consensus payload received yet')
-    } else {
-      this.config.logger.info(`Last consensus payload received  ${this._getPayloadLogMsg(
-        this._lastPayload
-      )}
-      `)
+    if (!this.config.synchronized) {
+      if (!this._lastPayload) {
+        this.config.logger.info('No consensus payload received yet')
+      } else {
+        const payloadMsg = this._getPayloadLogMsg(this._lastPayload)
+        this.config.logger.info(`Last consensus payload received  ${payloadMsg}`)
+      }
+    }
+  }
+
+  /**
+   * Externally triggered payload logs
+   */
+  public newPayloadLog() {
+    if (this._lastPayload) {
+      const payloadMsg = this._getPayloadLogMsg(this._lastPayload)
+      this.config.logger.info(`New consensus payload received  ${payloadMsg}`)
     }
   }
 
   /**
    * Regular forkchoice request logs
    */
-  private forkchoiceLog() {
+  private lastForkchoiceLog() {
     if (this.connectionStatus !== ConnectionStatus.Connected) {
       return
     }
-    if (!this._lastForkchoiceUpdate) {
-      this.config.logger.info('No consensus forkchoice update received yet')
-    } else {
+    if (!this.config.synchronized) {
+      if (!this._lastForkchoiceUpdate) {
+        this.config.logger.info('No consensus forkchoice update received yet')
+      } else {
+        this.config.logger.info(
+          `Last consensus forkchoice update ${this._getForkchoiceUpdateLogMsg(
+            this._lastForkchoiceUpdate
+          )}`
+        )
+      }
+    }
+  }
+
+  /**
+   * Externally triggered forkchoice log
+   */
+  public newForkchoiceLog() {
+    if (this._lastForkchoiceUpdate) {
       this.config.logger.info(
-        `Last consensus forkchoice update ${this._getForkchoiceUpdateLogMsg(
+        `New chain head set (forkchoice update) ${this._getForkchoiceUpdateLogMsg(
           this._lastForkchoiceUpdate
         )}`
       )

packages/client/lib/service/txpool.ts

@@ -144,7 +144,7 @@ export class TxPool {
   /**
    * Log pool statistics on the given interval
    */
-  private LOG_STATISTICS_INTERVAL = 20000 // ms
+  private LOG_STATISTICS_INTERVAL = 100000 // ms
 
   /**
    * Create new tx pool

packages/client/lib/sync/skeleton.ts

@@ -659,7 +659,7 @@ export class Skeleton extends MetaDBManager {
       // Delete skeleton block to clean up as we go, if block is fetched and chain is linked
       // it will be fetched from the chain without any issues
       await this.deleteBlock(block)
-      if (this.fillLogIndex >= 10) {
+      if (this.fillLogIndex >= 20) {
         this.config.logger.info(
           `Skeleton canonical chain fill status: canonicalHead=${canonicalHead} chainHead=${this.chain.blocks.height} subchainHead=${subchain.head}`
         )

packages/client/lib/sync/sync.ts

@@ -147,17 +147,19 @@ export abstract class Synchronizer {
     if (this.config.syncTargetHeight === undefined || this.config.syncTargetHeight === BigInt(0)) {
       return
     }
-    if (this.chain.headers.height >= this.config.syncTargetHeight) {
+    const height = this.chain.headers.height
+    if (height >= this.config.syncTargetHeight) {
       if (!this.config.synchronized) {
         const hash = this.chain.headers.latest?.hash()
+        this.config.synchronized = true
+        this.config.logger.info('*'.repeat(60))
         this.config.logger.info(
-          `Chain synchronized height=${this.chain.headers.height} hash=${short(hash!)}`
+          `Synchronized blockchain at height=${height} hash=${short(hash!)} 🎉`
         )
+        this.config.logger.info('*'.repeat(60))
       }
-      this.config.synchronized = true
+      this.config.events.emit(Event.SYNC_SYNCHRONIZED, height)
       this.config.lastSyncDate = Date.now()
-
-      this.config.events.emit(Event.SYNC_SYNCHRONIZED, this.chain.headers.height)
     }
   }