diff --git a/src/validation.cpp b/src/validation.cpp --- a/src/validation.cpp +++ b/src/validation.cpp @@ -56,6 +56,9 @@ #error "Bitcoin cannot be compiled without assertions." #endif +#define MICRO 0.000001 +#define MILLI 0.001 + /** * Global state */ @@ -1588,6 +1591,7 @@ 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 @@ -1627,6 +1631,8 @@ return true; } + nBlocksTotal++; + bool fScriptChecks = true; if (!hashAssumeValid.IsNull()) { // We've been configured with the hash of a block which has been @@ -1664,8 +1670,9 @@ int64_t nTime1 = GetTimeMicros(); nTimeCheck += nTime1 - nTimeStart; - LogPrint(BCLog::BENCH, " - Sanity checks: %.2fms [%.2fs]\n", - 0.001 * (nTime1 - nTimeStart), nTimeCheck * 0.000001); + LogPrint(BCLog::BENCH, " - 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. If such @@ -1733,8 +1740,9 @@ int64_t nTime2 = GetTimeMicros(); nTimeForks += nTime2 - nTime1; - LogPrint(BCLog::BENCH, " - Fork checks: %.2fms [%.2fs]\n", - 0.001 * (nTime2 - nTime1), nTimeForks * 0.000001); + LogPrint(BCLog::BENCH, " - Fork checks: %.2fms [%.2fs (%.2fms/blk)]\n", + MILLI * (nTime2 - nTime1), nTimeForks * MICRO, + nTimeForks * MILLI / nBlocksTotal); CBlockUndo blockundo; @@ -1834,12 +1842,12 @@ int64_t nTime3 = GetTimeMicros(); nTimeConnect += nTime3 - nTime2; LogPrint(BCLog::BENCH, - " - 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); + " - 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); Amount blockReward = nFees + GetBlockSubsidy(pindex->nHeight, consensusParams); @@ -1858,11 +1866,12 @@ int64_t nTime4 = GetTimeMicros(); nTimeVerify += nTime4 - nTime2; - LogPrint(BCLog::BENCH, - " - 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::BENCH, + " - 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); if (fJustCheck) { return true; @@ -1887,13 +1896,15 @@ int64_t nTime5 = GetTimeMicros(); nTimeIndex += nTime5 - nTime4; - LogPrint(BCLog::BENCH, " - Index writing: %.2fms [%.2fs]\n", - 0.001 * (nTime5 - nTime4), nTimeIndex * 0.000001); + LogPrint(BCLog::BENCH, " - Index writing: %.2fms [%.2fs (%.2fms/blk)]\n", + MILLI * (nTime5 - nTime4), nTimeIndex * MICRO, + nTimeIndex * MILLI / nBlocksTotal); int64_t nTime6 = GetTimeMicros(); nTimeCallbacks += nTime6 - nTime5; - LogPrint(BCLog::BENCH, " - Callbacks: %.2fms [%.2fs]\n", - 0.001 * (nTime6 - nTime5), nTimeCallbacks * 0.000001); + LogPrint(BCLog::BENCH, " - Callbacks: %.2fms [%.2fs (%.2fms/blk)]\n", + MILLI * (nTime6 - nTime5), nTimeCallbacks * MICRO, + nTimeCallbacks * MILLI / nBlocksTotal); // If we just activated the replay protection with that block, it means // transaction in the mempool are now invalid. As a result, we need to clear @@ -2185,7 +2196,7 @@ } LogPrint(BCLog::BENCH, "- Disconnect block: %.2fms\n", - (GetTimeMicros() - nStart) * 0.001); + (GetTimeMicros() - nStart) * MILLI); // Write the chain state to disk, if necessary. if (!FlushStateToDisk(config.GetChainParams(), state, @@ -2417,7 +2428,7 @@ nTimeReadFromDisk += nTime2 - nTime1; int64_t nTime3; LogPrint(BCLog::BENCH, " - Load block from disk: %.2fms [%.2fs]\n", - (nTime2 - nTime1) * 0.001, nTimeReadFromDisk * 0.000001); + (nTime2 - nTime1) * MILLI, nTimeReadFromDisk * MICRO); { CCoinsViewCache view(pcoinsTip.get()); bool rv = ConnectBlock(config, blockConnecting, state, pindexNew, view); @@ -2445,16 +2456,19 @@ nTime3 = GetTimeMicros(); nTimeConnectTotal += nTime3 - nTime2; - LogPrint(BCLog::BENCH, " - Connect total: %.2fms [%.2fs]\n", - (nTime3 - nTime2) * 0.001, nTimeConnectTotal * 0.000001); + LogPrint(BCLog::BENCH, + " - Connect total: %.2fms [%.2fs (%.2fms/blk)]\n", + (nTime3 - nTime2) * MILLI, nTimeConnectTotal * MICRO, + nTimeConnectTotal * MILLI / nBlocksTotal); bool flushed = view.Flush(); assert(flushed); } int64_t nTime4 = GetTimeMicros(); nTimeFlush += nTime4 - nTime3; - LogPrint(BCLog::BENCH, " - Flush: %.2fms [%.2fs]\n", - (nTime4 - nTime3) * 0.001, nTimeFlush * 0.000001); + LogPrint(BCLog::BENCH, " - Flush: %.2fms [%.2fs (%.2fms/blk)]\n", + (nTime4 - nTime3) * MILLI, nTimeFlush * MICRO, + nTimeFlush * MILLI / nBlocksTotal); // Write the chain state to disk, if necessary. if (!FlushStateToDisk(config.GetChainParams(), state, @@ -2464,8 +2478,10 @@ int64_t nTime5 = GetTimeMicros(); nTimeChainState += nTime5 - nTime4; - LogPrint(BCLog::BENCH, " - Writing chainstate: %.2fms [%.2fs]\n", - (nTime5 - nTime4) * 0.001, nTimeChainState * 0.000001); + LogPrint(BCLog::BENCH, + " - Writing chainstate: %.2fms [%.2fs (%.2fms/blk)]\n", + (nTime5 - nTime4) * MILLI, nTimeChainState * MICRO, + nTimeChainState * MILLI / nBlocksTotal); // Remove conflicting transactions from the mempool.; g_mempool.removeForBlock(blockConnecting.vtx, pindexNew->nHeight); @@ -2476,10 +2492,13 @@ int64_t nTime6 = GetTimeMicros(); nTimePostConnect += nTime6 - nTime5; nTimeTotal += nTime6 - nTime1; - LogPrint(BCLog::BENCH, " - Connect postprocess: %.2fms [%.2fs]\n", - (nTime6 - nTime5) * 0.001, nTimePostConnect * 0.000001); - LogPrint(BCLog::BENCH, "- Connect block: %.2fms [%.2fs]\n", - (nTime6 - nTime1) * 0.001, nTimeTotal * 0.000001); + LogPrint(BCLog::BENCH, + " - Connect postprocess: %.2fms [%.2fs (%.2fms/blk)]\n", + (nTime6 - nTime5) * MILLI, nTimePostConnect * MICRO, + nTimePostConnect * MILLI / nBlocksTotal); + LogPrint(BCLog::BENCH, "- Connect block: %.2fms [%.2fs (%.2fms/blk)]\n", + (nTime6 - nTime1) * MILLI, nTimeTotal * MICRO, + nTimeTotal * MILLI / nBlocksTotal); connectTrace.BlockConnected(pindexNew, std::move(pthisBlock)); return true; @@ -5474,7 +5493,7 @@ 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); + (mid - start) * MICRO, (last - mid) * MICRO); } catch (const std::exception &e) { LogPrintf("Failed to dump mempool: %s. Continuing anyway.\n", e.what()); }