From e4b900e6231d1b5fcc7531d552f6ec29d3867f9a Mon Sep 17 00:00:00 2001 From: Vyatcheslav Suharnikov Date: Wed, 25 Dec 2024 12:52:50 +0400 Subject: [PATCH] Debug logs (3) --- .../com/wavesplatform/mining/Miner.scala | 43 ++++++++++--------- .../microblocks/MicroBlockMinerImpl.scala | 2 +- .../wavesplatform/state/StateSnapshot.scala | 32 ++++++++++++++ .../state/diffs/BlockDiffer.scala | 30 ++++++++++--- 4 files changed, 80 insertions(+), 27 deletions(-) diff --git a/node/src/main/scala/com/wavesplatform/mining/Miner.scala b/node/src/main/scala/com/wavesplatform/mining/Miner.scala index 04530c5b5d..121e105344 100644 --- a/node/src/main/scala/com/wavesplatform/mining/Miner.scala +++ b/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) diff --git a/node/src/main/scala/com/wavesplatform/mining/microblocks/MicroBlockMinerImpl.scala b/node/src/main/scala/com/wavesplatform/mining/microblocks/MicroBlockMinerImpl.scala index 29fb35820a..fb70f58b95 100644 --- a/node/src/main/scala/com/wavesplatform/mining/microblocks/MicroBlockMinerImpl.scala +++ b/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")) diff --git a/node/src/main/scala/com/wavesplatform/state/StateSnapshot.scala b/node/src/main/scala/com/wavesplatform/state/StateSnapshot.scala index 10ec4fba43..d859eefb34 100644 --- a/node/src/main/scala/com/wavesplatform/state/StateSnapshot.scala +++ b/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 { diff --git a/node/src/main/scala/com/wavesplatform/state/diffs/BlockDiffer.scala b/node/src/main/scala/com/wavesplatform/state/diffs/BlockDiffer.scala index 4ef4ac02d2..e6441b8255 100644 --- a/node/src/main/scala/com/wavesplatform/state/diffs/BlockDiffer.scala +++ b/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(