diff --git a/src/validation.cpp b/src/validation.cpp index 751ea5c0c25a4..3cfff75dbb40b 100644 --- a/src/validation.cpp +++ b/src/validation.cpp @@ -64,6 +64,9 @@ # error "Dash Core cannot be compiled without assertions." #endif +#define MICRO 0.000001 +#define MILLI 0.001 + /** * Global state */ @@ -1809,6 +1812,7 @@ static int64_t nTimeConnect = 0; static int64_t nTimeIndex = 0; static int64_t nTimeCallbacks = 0; static int64_t nTimeTotal = 0; +static int64_t nBlocksTotal = 0; /** Apply the effects of this block (with given index) on the UTXO set represented by coins. * Validity checks that depend on the UTXO set are also done; ConnectBlock() @@ -1853,6 +1857,8 @@ static bool ConnectBlock(const CBlock& block, CValidationState& state, CBlockInd return true; } + nBlocksTotal++; + bool fScriptChecks = true; if (!hashAssumeValid.IsNull()) { // We've been configured with the hash of a block which has been externally verified to have a valid history. @@ -1880,7 +1886,7 @@ static bool ConnectBlock(const CBlock& block, CValidationState& state, CBlockInd } int64_t nTime1 = GetTimeMicros(); nTimeCheck += nTime1 - nTimeStart; - LogPrint(BCLog::BENCHMARK, " - Sanity checks: %.2fms [%.2fs]\n", 0.001 * (nTime1 - nTimeStart), nTimeCheck * 0.000001); + LogPrint(BCLog::BENCHMARK, " - Sanity checks: %.2fms [%.2fs (%.2fms/blk)]\n", MILLI * (nTime1 - nTimeStart), nTimeCheck * MICRO, nTimeCheck * MILLI / nBlocksTotal); // Do not allow blocks that contain transactions which 'overwrite' older transactions, // unless those are already completely spent. @@ -1940,7 +1946,7 @@ static bool ConnectBlock(const CBlock& block, CValidationState& state, CBlockInd unsigned int flags = GetBlockScriptFlags(pindex, chainparams.GetConsensus()); int64_t nTime2 = GetTimeMicros(); nTimeForks += nTime2 - nTime1; - LogPrint(BCLog::BENCHMARK, " - Fork checks: %.2fms [%.2fs]\n", 0.001 * (nTime2 - nTime1), nTimeForks * 0.000001); + LogPrint(BCLog::BENCHMARK, " - Fork checks: %.2fms [%.2fs (%.2fms/blk)]\n", MILLI * (nTime2 - nTime1), nTimeForks * MICRO, nTimeForks * MILLI / nBlocksTotal); CBlockUndo blockundo; @@ -2100,12 +2106,12 @@ static bool ConnectBlock(const CBlock& block, CValidationState& state, CBlockInd pos.nTxOffset += ::GetSerializeSize(tx, SER_DISK, CLIENT_VERSION); } int64_t nTime3 = GetTimeMicros(); nTimeConnect += nTime3 - nTime2; - LogPrint(BCLog::BENCHMARK, " - Connect %u transactions: %.2fms (%.3fms/tx, %.3fms/txin) [%.2fs]\n", (unsigned)block.vtx.size(), 0.001 * (nTime3 - nTime2), 0.001 * (nTime3 - nTime2) / block.vtx.size(), nInputs <= 1 ? 0 : 0.001 * (nTime3 - nTime2) / (nInputs-1), nTimeConnect * 0.000001); + LogPrint(BCLog::BENCHMARK, " - Connect %u transactions: %.2fms (%.3fms/tx, %.3fms/txin) [%.2fs (%.2fms/blk)]\n", (unsigned)block.vtx.size(), MILLI * (nTime3 - nTime2), MILLI * (nTime3 - nTime2) / block.vtx.size(), nInputs <= 1 ? 0 : MILLI * (nTime3 - nTime2) / (nInputs-1), nTimeConnect * MICRO, nTimeConnect * MILLI / nBlocksTotal); if (!control.Wait()) return state.DoS(100, error("%s: CheckQueue failed", __func__), REJECT_INVALID, "block-validation-failed"); int64_t nTime4 = GetTimeMicros(); nTimeVerify += nTime4 - nTime2; - LogPrint(BCLog::BENCHMARK, " - Verify %u txins: %.2fms (%.3fms/txin) [%.2fs]\n", nInputs - 1, 0.001 * (nTime4 - nTime2), nInputs <= 1 ? 0 : 0.001 * (nTime4 - nTime2) / (nInputs-1), nTimeVerify * 0.000001); + LogPrint(BCLog::BENCHMARK, " - Verify %u txins: %.2fms (%.3fms/txin) [%.2fs (%.2fms/blk)]\n", nInputs - 1, MILLI * (nTime4 - nTime2), nInputs <= 1 ? 0 : MILLI * (nTime4 - nTime2) / (nInputs-1), nTimeVerify * MICRO, nTimeVerify * MILLI / nBlocksTotal); // DASH @@ -2143,7 +2149,7 @@ static bool ConnectBlock(const CBlock& block, CValidationState& state, CBlockInd } int64_t nTime5_1 = GetTimeMicros(); nTimeISFilter += nTime5_1 - nTime4; - LogPrint(BCLog::BENCHMARK, " - IS filter: %.2fms [%.2fs]\n", 0.001 * (nTime5_1 - nTime4), nTimeISFilter * 0.000001); + LogPrint(BCLog::BENCHMARK, " - IS filter: %.2fms [%.2fs]\n", MICRO * (nTime5_1 - nTime4), nTimeISFilter * MICRO, nTimeISFilter * MILLI / nBlocksTotal); // DASH : MODIFIED TO CHECK MASTERNODE PAYMENTS AND SUPERBLOCKS @@ -2152,14 +2158,14 @@ static bool ConnectBlock(const CBlock& block, CValidationState& state, CBlockInd std::string strError = ""; int64_t nTime5_2 = GetTimeMicros(); nTimeSubsidy += nTime5_2 - nTime5_1; - LogPrint(BCLog::BENCHMARK, " - GetBlockSubsidy: %.2fms [%.2fs]\n", 0.001 * (nTime5_2 - nTime5_1), nTimeSubsidy * 0.000001); + LogPrint(BCLog::BENCHMARK, " - GetBlockSubsidy: %.2fms [%.2fs (%.2fms/blk)]\n", MICRO * (nTime5_2 - nTime5_1), nTimeSubsidy * MICRO, nTimeSubsidy * MILLI / nBlocksTotal); if (!IsBlockValueValid(block, pindex->nHeight, blockReward, strError)) { return state.DoS(0, error("ConnectBlock(DASH): %s", strError), REJECT_INVALID, "bad-cb-amount"); } int64_t nTime5_3 = GetTimeMicros(); nTimeValueValid += nTime5_3 - nTime5_2; - LogPrint(BCLog::BENCHMARK, " - IsBlockValueValid: %.2fms [%.2fs]\n", 0.001 * (nTime5_3 - nTime5_2), nTimeValueValid * 0.000001); + LogPrint(BCLog::BENCHMARK, " - IsBlockValueValid: %.2fms [%.2fs (%.2fms/blk)]\n", MICRO * (nTime5_3 - nTime5_2), nTimeValueValid * MICRO, nTimeValueValid * MILLI / nBlocksTotal); if (!IsBlockPayeeValid(*block.vtx[0], pindex->nHeight, blockReward)) { return state.DoS(0, error("ConnectBlock(DASH): couldn't find masternode or superblock payments"), @@ -2167,7 +2173,7 @@ static bool ConnectBlock(const CBlock& block, CValidationState& state, CBlockInd } int64_t nTime5_4 = GetTimeMicros(); nTimePayeeValid += nTime5_4 - nTime5_3; - LogPrint(BCLog::BENCHMARK, " - IsBlockPayeeValid: %.2fms [%.2fs]\n", 0.001 * (nTime5_4 - nTime5_3), nTimePayeeValid * 0.000001); + LogPrint(BCLog::BENCHMARK, " - IsBlockPayeeValid: %.2fms [%.2fs (%.2fms/blk)]\n", MICRO * (nTime5_4 - nTime5_3), nTimePayeeValid * MICRO, nTimePayeeValid * MILLI / nBlocksTotal); if (!ProcessSpecialTxsInBlock(block, pindex, state, fJustCheck, fScriptChecks)) { return error("ConnectBlock(DASH): ProcessSpecialTxsInBlock for block %s failed with %s", @@ -2175,10 +2181,10 @@ static bool ConnectBlock(const CBlock& block, CValidationState& state, CBlockInd } int64_t nTime5_5 = GetTimeMicros(); nTimeProcessSpecial += nTime5_5 - nTime5_4; - LogPrint(BCLog::BENCHMARK, " - ProcessSpecialTxsInBlock: %.2fms [%.2fs]\n", 0.001 * (nTime5_5 - nTime5_4), nTimeProcessSpecial * 0.000001); + LogPrint(BCLog::BENCHMARK, " - ProcessSpecialTxsInBlock: %.2fms [%.2fs (%.2fms/blk)]\n", MICRO * (nTime5_5 - nTime5_4), nTimeProcessSpecial * MICRO, nTimeProcessSpecial * MILLI / nBlocksTotal); int64_t nTime5 = GetTimeMicros(); nTimeDashSpecific += nTime5 - nTime4; - LogPrint(BCLog::BENCHMARK, " - Dash specific: %.2fms [%.2fs]\n", 0.001 * (nTime5 - nTime4), nTimeDashSpecific * 0.000001); + LogPrint(BCLog::BENCHMARK, " - Dash specific: %.2fms [%.2fs (%.2fms/blk)]\n", MICRO * (nTime5 - nTime4), nTimeDashSpecific * MICRO, nTimeDashSpecific * MILLI / nBlocksTotal); // END DASH @@ -2230,12 +2236,12 @@ static bool ConnectBlock(const CBlock& block, CValidationState& state, CBlockInd view.SetBestBlock(pindex->GetBlockHash()); int64_t nTime6 = GetTimeMicros(); nTimeIndex += nTime6 - nTime5; - LogPrint(BCLog::BENCHMARK, " - Index writing: %.2fms [%.2fs]\n", 0.001 * (nTime6 - nTime5), nTimeIndex * 0.000001); + LogPrint(BCLog::BENCHMARK, " - Index writing: %.2fms [%.2fs (%.2fms/blk)]\n", MILLI * (nTime6 - nTime5), nTimeIndex * MICRO, nTimeIndex * MILLI / nBlocksTotal); evoDb->WriteBestBlock(pindex->GetBlockHash()); int64_t nTime7 = GetTimeMicros(); nTimeCallbacks += nTime7 - nTime6; - LogPrint(BCLog::BENCHMARK, " - Callbacks: %.2fms [%.2fs]\n", 0.001 * (nTime7 - nTime6), nTimeCallbacks * 0.000001); + LogPrint(BCLog::BENCHMARK, " - Callbacks: %.2fms [%.2fs (%.2fms/blk)]\n", MILLI * (nTime7 - nTime6), nTimeCallbacks * MICRO, nTimeCallbacks * MILLI / nBlocksTotal); return true; } @@ -2467,7 +2473,7 @@ bool static DisconnectTip(CValidationState& state, const CChainParams& chainpara assert(flushed); dbTx->Commit(); } - LogPrint(BCLog::BENCHMARK, "- Disconnect block: %.2fms\n", (GetTimeMicros() - nStart) * 0.001); + LogPrint(BCLog::BENCHMARK, "- Disconnect block: %.2fms\n", (GetTimeMicros() - nStart) * MILLI); // Write the chain state to disk, if necessary. if (!FlushStateToDisk(chainparams, state, FLUSH_STATE_IF_NEEDED)) return false; @@ -2588,7 +2594,7 @@ bool static ConnectTip(CValidationState& state, const CChainParams& chainparams, // Apply the block atomically to the chain state. int64_t nTime2 = GetTimeMicros(); nTimeReadFromDisk += nTime2 - nTime1; int64_t nTime3; - LogPrint(BCLog::BENCHMARK, " - Load block from disk: %.2fms [%.2fs]\n", (nTime2 - nTime1) * 0.001, nTimeReadFromDisk * 0.000001); + LogPrint(BCLog::BENCHMARK, " - Load block from disk: %.2fms [%.2fs]\n", (nTime2 - nTime1) * MILLI, nTimeReadFromDisk * MICRO); { auto dbTx = evoDb->BeginTransaction(); @@ -2601,18 +2607,18 @@ bool static ConnectTip(CValidationState& state, const CChainParams& chainparams, return error("ConnectTip(): ConnectBlock %s failed with %s", pindexNew->GetBlockHash().ToString(), FormatStateMessage(state)); } nTime3 = GetTimeMicros(); nTimeConnectTotal += nTime3 - nTime2; - LogPrint(BCLog::BENCHMARK, " - Connect total: %.2fms [%.2fs]\n", (nTime3 - nTime2) * 0.001, nTimeConnectTotal * 0.000001); + LogPrint(BCLog::BENCHMARK, " - Connect total: %.2fms [%.2fs (%.2fms/blk)]\n", (nTime3 - nTime2) * MILLI, nTimeConnectTotal * MICRO, nTimeConnectTotal * MILLI / nBlocksTotal); bool flushed = view.Flush(); assert(flushed); dbTx->Commit(); } int64_t nTime4 = GetTimeMicros(); nTimeFlush += nTime4 - nTime3; - LogPrint(BCLog::BENCHMARK, " - Flush: %.2fms [%.2fs]\n", (nTime4 - nTime3) * 0.001, nTimeFlush * 0.000001); + LogPrint(BCLog::BENCHMARK, " - Flush: %.2fms [%.2fs (%.2fms/blk)]\n", (nTime4 - nTime3) * MILLI, nTimeFlush * MICRO, nTimeFlush * MILLI / nBlocksTotal); // Write the chain state to disk, if necessary. if (!FlushStateToDisk(chainparams, state, FLUSH_STATE_IF_NEEDED)) return false; int64_t nTime5 = GetTimeMicros(); nTimeChainState += nTime5 - nTime4; - LogPrint(BCLog::BENCHMARK, " - Writing chainstate: %.2fms [%.2fs]\n", (nTime5 - nTime4) * 0.001, nTimeChainState * 0.000001); + LogPrint(BCLog::BENCHMARK, " - Writing chainstate: %.2fms [%.2fs (%.2fms/blk)]\n", (nTime5 - nTime4) * MILLI, nTimeChainState * MICRO, nTimeChainState * MILLI / nBlocksTotal); // Remove conflicting transactions from the mempool.; mempool.removeForBlock(blockConnecting.vtx, pindexNew->nHeight); disconnectpool.removeForBlock(blockConnecting.vtx); @@ -2620,8 +2626,8 @@ bool static ConnectTip(CValidationState& state, const CChainParams& chainparams, UpdateTip(pindexNew, chainparams); int64_t nTime6 = GetTimeMicros(); nTimePostConnect += nTime6 - nTime5; nTimeTotal += nTime6 - nTime1; - LogPrint(BCLog::BENCHMARK, " - Connect postprocess: %.2fms [%.2fs]\n", (nTime6 - nTime5) * 0.001, nTimePostConnect * 0.000001); - LogPrint(BCLog::BENCHMARK, "- Connect block: %.2fms [%.2fs]\n", (nTime6 - nTime1) * 0.001, nTimeTotal * 0.000001); + LogPrint(BCLog::BENCHMARK, " - Connect postprocess: %.2fms [%.2fs (%.2fms/blk)]\n", (nTime6 - nTime5) * MILLI, nTimePostConnect * MICRO, nTimePostConnect * MILLI / nBlocksTotal); + LogPrint(BCLog::BENCHMARK, "- Connect block: %.2fms [%.2fs (%.2fms/blk)]\n", (nTime6 - nTime1) * MILLI, nTimeTotal * MICRO, nTimeTotal * MILLI / nBlocksTotal); connectTrace.BlockConnected(pindexNew, std::move(pthisBlock)); return true; @@ -4754,7 +4760,7 @@ bool DumpMempool(void) file.fclose(); RenameOver(GetDataDir() / "mempool.dat.new", GetDataDir() / "mempool.dat"); int64_t last = GetTimeMicros(); - LogPrintf("Dumped mempool: %gs to copy, %gs to dump\n", (mid-start)*0.000001, (last-mid)*0.000001); + LogPrintf("Dumped mempool: %gs to copy, %gs to dump\n", (mid-start)*MICRO, (last-mid)*MICRO); } catch (const std::exception& e) { LogPrintf("Failed to dump mempool: %s. Continuing anyway.\n", e.what()); return false;