Debug logs (3)

node/src/main/scala/com/wavesplatform/mining/Miner.scala

@@ -34,6 +34,7 @@ import java.time.LocalTime
 import scala.concurrent.duration.*
 
 trait Miner {
+  // None if mining from genesis or after rollback
   def scheduleMining(blockchain: Option[Blockchain] = None): Unit
 }
 
@@ -154,7 +155,7 @@ class MinerImpl(
         .map { initSnapshot =>
           val r1 = TxStateSnapshotHashBuilder.createHashFromSnapshot(initSnapshot, None).createHash(prevHash)
           val r2 = TxStateSnapshotHashBuilder.createHashFromSnapshot(initSnapshot, None).createHash(prevHash)
-          log.debug(s"packTransactionsForKeyBlock: consistency check=$r1 vs $r2, initSnapshot=$initSnapshot")
+          log.debug(s"packTransactionsForKeyBlock: consistency check=$r1 vs $r2, initSnapshot=$initSnapshot, prevHash=$prevHash")
 
           r1
         }
@@ -210,25 +211,25 @@ class MinerImpl(
           Some(blockchainUpdater.lastStateHash(Some(reference)))
         else None
       (unconfirmed, totalConstraint, stateHash) = packTransactionsForKeyBlock(account.toAddress, reference, prevStateHash)
-      block <- {
-        log.debug(s"Forging data: prevStateHash=$prevStateHash, stateHash=$stateHash, unconfirmed=${unconfirmed.size}")
-        Block
-          .buildAndSign(
-            version,
-            blockTime,
-            reference,
-            consensusData.baseTarget,
-            consensusData.generationSignature,
-            unconfirmed,
-            account,
-            blockFeatures(version),
-            blockRewardVote(version),
-            if (blockchainUpdater.supportsLightNodeBlockFields(height + 1)) stateHash else None,
-            None
-          )
-          .leftMap(_.err)
-      }
-    } yield (block, totalConstraint))
+      block <- Block
+        .buildAndSign(
+          version,
+          blockTime,
+          reference,
+          consensusData.baseTarget,
+          consensusData.generationSignature,
+          unconfirmed,
+          account,
+          blockFeatures(version),
+          blockRewardVote(version),
+          if (blockchainUpdater.supportsLightNodeBlockFields(height + 1)) stateHash else None,
+          None
+        )
+        .leftMap(_.err)
+    } yield {
+      log.debug(s"Forged block: stateHash=$stateHash, txs=${block.transactionData.size}, prevStateHash=$prevStateHash")
+      (block, totalConstraint)
+    })
   }
 
   private def checkQuorumAvailable(): Either[String, Int] =
@@ -297,7 +298,7 @@ class MinerImpl(
           case Some(value) =>
             def waitUntilBlockAppended(block: BlockId): Task[Unit] =
               if (blockchainUpdater.contains(block)) Task.unit
-              else Task.defer(waitUntilBlockAppended(block)).delayExecution(1 seconds)
+              else Task.defer(waitUntilBlockAppended(block)).delayExecution(1 seconds) // TODO 1 second?
 
             waitUntilBlockAppended(value.lastBlockId.get)
 

node/src/main/scala/com/wavesplatform/mining/microblocks/MicroBlockMinerImpl.scala

@@ -53,7 +53,7 @@ class MicroBlockMinerImpl(
         case Retry =>
           Task
             .defer(generateMicroBlockSequence(account, accumulatedBlock, restTotalConstraint, lastMicroBlock))
-            .delayExecution(1 second)
+            .delayExecution((settings.microBlockInterval / 2).max(1.millis))
         case Stop =>
           setDebugState(MinerDebugInfo.MiningBlocks)
           Task(log.debug("MicroBlock mining completed, block is full"))

node/src/main/scala/com/wavesplatform/state/StateSnapshot.scala

@@ -66,6 +66,38 @@ case class StateSnapshot(
 
   lazy val hashString: String =
     Integer.toHexString(hashCode())
+
+  override def toString: String = List(
+    if (transactions.isEmpty) None else Some(s"txn: {${transactions.keys.mkString(", ")}}"),
+    toStr("b", balances),
+    toStr("lb", leaseBalances),
+    toStr("ass", assetStatics),
+    toStr("av", assetVolumes),
+    toStr("a", assetNamesAndDescriptions),
+    toStr("as", assetScripts),
+    toStr("s", sponsorships),
+    toStr("nl", newLeases),
+    toStr("cl", cancelledLeases),
+    toStr("a", aliases),
+    toStr("o", orderFills),
+    toStr("acs", accountScripts),
+    toStr("ad", accountData),
+    toStr("sr", scriptResults),
+    toStr("et", ethereumTransactionMeta),
+    Some(s"sc: $scriptsComplexity"),
+    toStr("e", erc20Addresses)
+  ).flatten.mkString("StateSnapshot(", ", ", ")")
+
+  private def toStr[K, V](fieldName: String, value: Map[K, V]): Option[String] =
+    if (value.isEmpty) None
+    else
+      Some(
+        value
+          .map { case (k, v) =>
+            s"$k: $v"
+          }
+          .mkString(s"$fieldName={", ", ", "}")
+      )
 }
 
 object StateSnapshot {

node/src/main/scala/com/wavesplatform/state/diffs/BlockDiffer.scala

@@ -1,5 +1,6 @@
 package com.wavesplatform.state.diffs
 
+import scala.util.chaining.*
 import cats.implicits.{catsSyntaxOption, catsSyntaxSemigroup, toFoldableOps}
 import cats.syntax.either.*
 import com.typesafe.scalalogging.Logger
@@ -117,7 +118,9 @@ object BlockDiffer {
       enableExecutionLog: Boolean,
       txSignParCheck: Boolean
   ): TracedResult[ValidationError, Result] = {
-    logger.debug(s"BlockDiffer.fromBlockTraced(maybePrevBlock=${maybePrevBlock.map(_.id())}, block=${block.id()})")
+    logger.debug(
+      s"BlockDiffer.fromBlockTraced(maybePrevBlock=${maybePrevBlock.map(_.id())}, block=${block.id()}, snapshot.isDefined=${snapshot.isDefined})"
+    )
     val stateHeight        = blockchain.height
     val heightWithNewBlock = stateHeight + 1
 
@@ -248,7 +251,9 @@ object BlockDiffer {
       verify: Boolean,
       enableExecutionLog: Boolean
   ): TracedResult[ValidationError, Result] = {
-    logger.debug(s"BlockDiffer.fromMicroBlockTraced: prevBlockTimestamp=$prevBlockTimestamp, snapshot.totalBlockId=${snapshot.map(_.totalBlockId)}, verify=$verify")
+    logger.debug(
+      s"BlockDiffer.fromMicroBlockTraced: prevBlockTimestamp=$prevBlockTimestamp, snapshot.totalBlockId=${snapshot.map(_.totalBlockId)}, verify=$verify"
+    )
 
     for {
       // microblocks are processed within block which is next after 40-only-block which goes on top of activated height
@@ -347,8 +352,6 @@ object BlockDiffer {
     val blockGenerator  = blockchain.lastBlockHeader.get.header.generator.toAddress
     val rideV6Activated = blockchain.isFeatureActivated(BlockchainFeatures.RideV6)
 
-    logger.debug(s"BlockDiffer.apply: blockchain.lastBlockTimestamp=$timestamp, lastBlockHeader.id=${blockchain.lastBlockHeader.map(_.id())}")
-
     val txDiffer = TransactionDiffer(prevBlockTimestamp, timestamp, verify, enableExecutionLog = enableExecutionLog) _
 
     if (verify && txSignParCheck)
@@ -357,6 +360,11 @@ object BlockDiffer {
     prepareCaches(blockGenerator, txs, loadCacheData)
 
     val initStateHash = computeInitialStateHash(blockchain, initSnapshot, prevStateHash)
+    logger.debug(
+      s"BlockDiffer.apply: blockchain.lastBlockTimestamp=$timestamp, prevBlockTimestamp=$prevBlockTimestamp, lastBlockHeader.id=${blockchain.lastBlockHeader
+        .map(_.id())}, prevStateHash=$prevStateHash, initStateHash=$initStateHash, initSnapshot=$initSnapshot"
+    )
+
     txs
       .foldLeft(TracedResult(Result(initSnapshot, 0L, 0L, initConstraint, initSnapshot, initStateHash).asRight[ValidationError])) {
         case (acc @ TracedResult(Left(_), _, _), _) => acc
@@ -392,7 +400,7 @@ object BlockDiffer {
 
                 val newSnapshot = currSnapshot |+| resultTxSnapshot.withTransaction(txInfoWithFee)
 
-                Result(
+                val r = Result(
                   newSnapshot,
                   carryFee + txFeeInfo.carry,
                   currTotalFee + txFeeInfo.wavesFee,
@@ -402,6 +410,11 @@ object BlockDiffer {
                     .createHashFromSnapshot(resultTxSnapshot, Some(TxStatusInfo(txInfo.transaction.id(), txInfo.status)))
                     .createHash(prevStateHash)
                 )
+
+                logger.debug(
+                  s"BlockDiffer.apply after txSnapshot=$txSnapshot: computedStateHash=${r.computedStateHash}, snapshot=${r.snapshot}, c=${r.carry}, tf=${r.totalFee}"
+                )
+                r
               }
             }
           }
@@ -416,6 +429,13 @@ object BlockDiffer {
               )
           })
       }
+      .tap { res =>
+        res.map { res =>
+          logger.debug(
+            s"BlockDiffer.apply res: computedStateHash=${res.computedStateHash}, keyBlockSnapshot=${res.keyBlockSnapshot}, snapshot=${res.snapshot}, c=${res.carry}, tf=${res.totalFee}"
+          )
+        }
+      }
   }
 
   private[this] def apply(