Logging decorator instead of LoggingBackend, filtering logs

src/main/scala/units/ConsensusClient.scala

@@ -15,8 +15,8 @@ import monix.execution.{CancelableFuture, Scheduler}
 import net.ceedubs.ficus.Ficus.*
 import org.slf4j.LoggerFactory
 import sttp.client3.HttpClientSyncBackend
-import units.client.engine.{EngineApiClient, HttpEngineApiClient}
-import units.client.{JwtAuthenticationBackend, LoggingBackend}
+import units.client.JwtAuthenticationBackend
+import units.client.engine.{EngineApiClient, HttpEngineApiClient, LoggedEngineApiClient}
 import units.network.*
 
 import java.util.concurrent.ConcurrentHashMap
@@ -106,18 +106,20 @@ class ConsensusClientDependencies(context: ExtensionContext) extends AutoCloseab
   val globalScheduler: Scheduler     = monix.execution.Scheduler.global
   val eluScheduler: SchedulerService = Scheduler.singleThread("el-updater", reporter = { e => log.warn("Exception in ELUpdater", e) })
 
-  private val httpClientBackend = new LoggingBackend(HttpClientSyncBackend())
-  val engineApiClient = new HttpEngineApiClient(
-    config,
-    config.jwtSecretFile match {
-      case Some(secretFile) =>
-        val src = Source.fromFile(secretFile)
-        try new JwtAuthenticationBackend(src.getLines().next(), httpClientBackend)
-        finally src.close()
-      case _ =>
-        log.warn("JWT secret is not set")
-        httpClientBackend
-    }
+  private val httpClientBackend = HttpClientSyncBackend()
+  val engineApiClient = new LoggedEngineApiClient(
+    new HttpEngineApiClient(
+      config,
+      config.jwtSecretFile match {
+        case Some(secretFile) =>
+          val src = Source.fromFile(secretFile)
+          try new JwtAuthenticationBackend(src.getLines().next(), httpClientBackend)
+          finally src.close()
+        case _ =>
+          log.warn("JWT secret is not set")
+          httpClientBackend
+      }
+    )
   )
 
   val allChannels     = new DefaultChannelGroup(GlobalEventExecutor.INSTANCE)

src/main/scala/units/client/engine/EngineApiClient.scala

@@ -28,7 +28,7 @@ trait EngineApiClient {
 
   def getBlockByHash(hash: BlockHash): Job[Option[EcBlock]]
 
-  def getBlockByHashJson(hash: BlockHash, fullTxs: Boolean = false): Job[Option[JsObject]]
+  def getBlockByHashJson(hash: BlockHash): Job[Option[JsObject]]
 
   def getLastExecutionBlock: Job[EcBlock]
 

src/main/scala/units/client/engine/HttpEngineApiClient.scala

@@ -85,12 +85,12 @@ class HttpEngineApiClient(val config: ClientConfig, val backend: SttpBackend[Ide
   }
 
   def getBlockByHash(hash: BlockHash): Job[Option[EcBlock]] = {
-    sendRequest[GetBlockByHashRequest, EcBlock](GetBlockByHashRequest(hash, fullTxs = false))
+    sendRequest[GetBlockByHashRequest, EcBlock](GetBlockByHashRequest(hash))
       .leftMap(err => ClientError(s"Error getting block by hash $hash: $err"))
   }
 
-  def getBlockByHashJson(hash: BlockHash, fullTxs: Boolean = false): Job[Option[JsObject]] = {
-    sendRequest[GetBlockByHashRequest, JsObject](GetBlockByHashRequest(hash, fullTxs))
+  def getBlockByHashJson(hash: BlockHash): Job[Option[JsObject]] = {
+    sendRequest[GetBlockByHashRequest, JsObject](GetBlockByHashRequest(hash))
       .leftMap(err => ClientError(s"Error getting block json by hash $hash: $err"))
   }
 

src/main/scala/units/client/engine/LoggedEngineApiClient.scala

@@ -0,0 +1,79 @@
+package units.client.engine
+
+import com.wavesplatform.utils.LoggerFacade
+import org.slf4j.LoggerFactory
+import play.api.libs.json.JsObject
+import units.client.engine.EngineApiClient.PayloadId
+import units.client.engine.LoggedEngineApiClient.excludedJsonFields
+import units.client.engine.model.*
+import units.eth.EthAddress
+import units.{BlockHash, Job}
+
+import java.util.concurrent.ThreadLocalRandom
+import scala.util.chaining.scalaUtilChainingOps
+
+class LoggedEngineApiClient(underlying: EngineApiClient) extends EngineApiClient {
+  protected val log = LoggerFacade(LoggerFactory.getLogger(underlying.getClass))
+
+  override def forkChoiceUpdate(blockHash: BlockHash, finalizedBlockHash: BlockHash): Job[String] =
+    wrap(s"forkChoiceUpdate($blockHash, f=$finalizedBlockHash)", underlying.forkChoiceUpdate(blockHash, finalizedBlockHash))
+
+  override def forkChoiceUpdateWithPayloadId(
+      lastBlockHash: BlockHash,
+      finalizedBlockHash: BlockHash,
+      unixEpochSeconds: Long,
+      suggestedFeeRecipient: EthAddress,
+      prevRandao: String,
+      withdrawals: Vector[Withdrawal]
+  ): Job[PayloadId] = wrap(
+    s"forkChoiceUpdateWithPayloadId(l=$lastBlockHash, f=$finalizedBlockHash, ts=$unixEpochSeconds, m=$suggestedFeeRecipient, " +
+      s"r=$prevRandao, w={${withdrawals.mkString(", ")}}",
+    underlying.forkChoiceUpdateWithPayloadId(lastBlockHash, finalizedBlockHash, unixEpochSeconds, suggestedFeeRecipient, prevRandao, withdrawals)
+  )
+
+  override def getPayload(payloadId: PayloadId): Job[JsObject] =
+    wrap(s"getPayload($payloadId)", underlying.getPayload(payloadId), filteredJson)
+
+  override def applyNewPayload(payload: JsObject): Job[Option[BlockHash]] =
+    wrap(s"applyNewPayload(${filteredJson(payload)})", underlying.applyNewPayload(payload), _.fold("None")(_.toString))
+
+  override def getPayloadBodyByHash(hash: BlockHash): Job[Option[JsObject]] =
+    wrap(s"getPayloadBodyByHash($hash)", underlying.getPayloadBodyByHash(hash), _.fold("None")(filteredJson))
+
+  override def getBlockByNumber(number: BlockNumber): Job[Option[EcBlock]] =
+    wrap(s"getBlockByNumber($number)", underlying.getBlockByNumber(number), _.fold("None")(_.toString))
+
+  override def getBlockByHash(hash: BlockHash): Job[Option[EcBlock]] =
+    wrap(s"getBlockByHash($hash)", underlying.getBlockByHash(hash), _.fold("None")(_.toString))
+
+  override def getBlockByHashJson(hash: BlockHash): Job[Option[JsObject]] =
+    wrap(s"getBlockByHashJson($hash)", underlying.getBlockByHashJson(hash), _.fold("None")(filteredJson))
+
+  override def getLastExecutionBlock: Job[EcBlock] =
+    wrap("getLastExecutionBlock", underlying.getLastExecutionBlock)
+
+  override def blockExists(hash: BlockHash): Job[Boolean] =
+    wrap(s"blockExists($hash)", underlying.blockExists(hash))
+
+  override def getLogs(hash: BlockHash, topic: String): Job[List[GetLogsResponseEntry]] =
+    wrap(s"getLogs($hash, t=$topic)", underlying.getLogs(hash, topic), _.mkString("{", ", ", "}"))
+
+  protected def wrap[R](method: String, f: => Job[R], toMsg: R => String = (_: R).toString): Job[R] = {
+    val currRequestId = ThreadLocalRandom.current().nextInt(10000, 100000).toString
+    log.debug(s"[$currRequestId] $method")
+
+    f.tap {
+      case Left(e)  => log.debug(s"[$currRequestId] Error: ${e.message}")
+      case Right(r) => log.debug(s"[$currRequestId] Success: ${toMsg(r)}")
+    }
+  }
+
+  private def filteredJson(jsObject: JsObject): String = JsObject(
+    jsObject.fields.filterNot { case (k, _) => excludedJsonFields.contains(k) }
+  ).toString()
+}
+
+object LoggedEngineApiClient {
+  private val excludedJsonFields =
+    Set("transactions", "logsBloom", "stateRoot", "gasLimit", "gasUsed", "baseFeePerGas", "excessBlobGas")
+}

src/main/scala/units/client/engine/model/EcBlock.scala

@@ -25,7 +25,10 @@ case class EcBlock(
     gasLimit: Long,
     gasUsed: Long,
     withdrawals: Vector[Withdrawal]
-) extends L2BlockLike
+) extends L2BlockLike {
+  override def toString: String =
+    s"EcBlock($hash, p=$parentHash, h=$height, t=$timestamp, m=$minerRewardL2Address, w={${withdrawals.mkString(", ")}})"
+}
 
 object EcBlock {
   implicit val reads: Reads[EcBlock] = (

src/main/scala/units/client/engine/model/GetBlockByHashRequest.scala

@@ -1,15 +1,15 @@
 package units.client.engine.model
 
-import units.BlockHash
 import play.api.libs.json.{Json, Writes}
+import units.BlockHash
 
-case class GetBlockByHashRequest(hash: BlockHash, fullTxs: Boolean)
+case class GetBlockByHashRequest(hash: BlockHash)
 object GetBlockByHashRequest {
   implicit val writes: Writes[GetBlockByHashRequest] = (o: GetBlockByHashRequest) => {
     Json.obj(
       "jsonrpc" -> "2.0",
       "method"  -> "eth_getBlockByHash",
-      "params"  -> Json.arr(o.hash, o.fullTxs),
+      "params"  -> Json.arr(o.hash, false),
       "id"      -> 1
     )
   }

src/main/scala/units/client/engine/model/GetLogsResponseEntry.scala

@@ -1,7 +1,7 @@
 package units.client.engine.model
 
-import units.eth.EthAddress
 import play.api.libs.json.{Json, Reads}
+import units.eth.EthAddress
 
 /** @param topics
   *   List of hex values
@@ -10,7 +10,9 @@ case class GetLogsResponseEntry(
     address: EthAddress,
     data: String,        // Bytes
     topics: List[String] // TODO type
-)
+) {
+  override def toString: String = s"Log($data)"
+}
 
 object GetLogsResponseEntry {
   implicit val getLogsResponseEntryReads: Reads[GetLogsResponseEntry] = Json.reads

src/test/scala/units/client/TestEcClients.scala

@@ -73,7 +73,7 @@ class TestEcClients private (
     */
   def fullValidatedBlocks: Set[BlockHash] = getLogsCalls.get()
 
-  val engineApi = LoggedEngineApiClient {
+  val engineApi = new LoggedEngineApiClient(
     new EngineApiClient {
       override def forkChoiceUpdate(blockHash: BlockHash, finalizedBlockHash: BlockHash): Job[String] = {
         knownBlocks.get().get(blockHash) match {
@@ -157,7 +157,7 @@ class TestEcClients private (
         } yield b.ecBlock
       }.asRight
 
-      override def getBlockByHashJson(hash: BlockHash, fullTxs: Boolean): Job[Option[JsObject]] =
+      override def getBlockByHashJson(hash: BlockHash): Job[Option[JsObject]] =
         notImplementedMethodJob("getBlockByHashJson")
 
       override def getLastExecutionBlock: Job[EcBlock] = currChain.head.asRight
@@ -170,7 +170,7 @@ class TestEcClients private (
         logs.get().getOrElse(request, throw notImplementedCase("call setBlockLogs"))
       }.asRight
     }
-  }
+  )
 
   protected def notImplementedMethodJob[A](text: String): Job[A] = throw new NotImplementedMethod(text)
   protected def notImplementedCase(text: String): Throwable      = new NotImplementedCase(text)