@@ -1965,14 +1965,14 @@ static unsigned int GetBlockScriptFlags(const CBlockIndex& block_index, const Ch
19651965}
19661966
19671967
1968- static int64_t nTimeCheck = 0 ;
1969- static int64_t nTimeForks = 0 ;
1970- static int64_t nTimeConnect = 0 ;
1971- static int64_t nTimeVerify = 0 ;
1972- static int64_t nTimeUndo = 0 ;
1973- static int64_t nTimeIndex = 0 ;
1974- static int64_t nTimeTotal = 0 ;
1975- static int64_t nBlocksTotal = 0 ;
1968+ static int64_t time_check = 0 ;
1969+ static int64_t time_forks = 0 ;
1970+ static int64_t time_connect = 0 ;
1971+ static int64_t time_verify = 0 ;
1972+ static int64_t time_undo = 0 ;
1973+ static int64_t time_index = 0 ;
1974+ static int64_t time_total = 0 ;
1975+ static int64_t num_blocks_total = 0 ;
19761976
19771977/* * Apply the effects of this block (with given index) on the UTXO set represented by coins.
19781978 * Validity checks that depend on the UTXO set are also done; ConnectBlock()
@@ -1986,7 +1986,7 @@ bool Chainstate::ConnectBlock(const CBlock& block, BlockValidationState& state,
19861986 uint256 block_hash{block.GetHash ()};
19871987 assert (*pindex->phashBlock == block_hash);
19881988
1989- int64_t nTimeStart = GetTimeMicros ();
1989+ int64_t time_start = GetTimeMicros ();
19901990
19911991 // Check it again in case a previous version let a bad block in
19921992 // NOTE: We don't currently (re-)invoke ContextualCheckBlock() or
@@ -2015,7 +2015,7 @@ bool Chainstate::ConnectBlock(const CBlock& block, BlockValidationState& state,
20152015 uint256 hashPrevBlock = pindex->pprev == nullptr ? uint256 () : pindex->pprev ->GetBlockHash ();
20162016 assert (hashPrevBlock == view.GetBestBlock ());
20172017
2018- nBlocksTotal ++;
2018+ num_blocks_total ++;
20192019
20202020 // Special case for the genesis block, skipping connection of its transactions
20212021 // (its coinbase is unspendable)
@@ -2056,8 +2056,9 @@ bool Chainstate::ConnectBlock(const CBlock& block, BlockValidationState& state,
20562056 }
20572057 }
20582058
2059- int64_t nTime1 = GetTimeMicros (); nTimeCheck += nTime1 - nTimeStart;
2060- LogPrint (BCLog::BENCH, " - Sanity checks: %.2fms [%.2fs (%.2fms/blk)]\n " , MILLI * (nTime1 - nTimeStart), nTimeCheck * MICRO, nTimeCheck * MILLI / nBlocksTotal);
2059+ int64_t time_1 = GetTimeMicros ();
2060+ time_check += time_1 - time_start;
2061+ LogPrint (BCLog::BENCH, " - Sanity checks: %.2fms [%.2fs (%.2fms/blk)]\n " , MILLI * (time_1 - time_start), time_check * MICRO, time_check * MILLI / num_blocks_total);
20612062
20622063 // Do not allow blocks that contain transactions which 'overwrite' older transactions,
20632064 // unless those are already completely spent.
@@ -2155,8 +2156,9 @@ bool Chainstate::ConnectBlock(const CBlock& block, BlockValidationState& state,
21552156 // Get the script flags for this block
21562157 unsigned int flags{GetBlockScriptFlags (*pindex, m_chainman)};
21572158
2158- int64_t nTime2 = GetTimeMicros (); nTimeForks += nTime2 - nTime1;
2159- LogPrint (BCLog::BENCH, " - Fork checks: %.2fms [%.2fs (%.2fms/blk)]\n " , MILLI * (nTime2 - nTime1), nTimeForks * MICRO, nTimeForks * MILLI / nBlocksTotal);
2159+ int64_t time_2 = GetTimeMicros ();
2160+ time_forks += time_2 - time_1;
2161+ LogPrint (BCLog::BENCH, " - Fork checks: %.2fms [%.2fs (%.2fms/blk)]\n " , MILLI * (time_2 - time_1), time_forks * MICRO, time_forks * MILLI / num_blocks_total);
21602162
21612163 CBlockUndo blockundo;
21622164
@@ -2240,8 +2242,9 @@ bool Chainstate::ConnectBlock(const CBlock& block, BlockValidationState& state,
22402242 }
22412243 UpdateCoins (tx, view, i == 0 ? undoDummy : blockundo.vtxundo .back (), pindex->nHeight );
22422244 }
2243- int64_t nTime3 = GetTimeMicros (); nTimeConnect += nTime3 - nTime2;
2244- LogPrint (BCLog::BENCH, " - 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);
2245+ int64_t time_3 = GetTimeMicros ();
2246+ time_connect += time_3 - time_2;
2247+ LogPrint (BCLog::BENCH, " - Connect %u transactions: %.2fms (%.3fms/tx, %.3fms/txin) [%.2fs (%.2fms/blk)]\n " , (unsigned )block.vtx .size (), MILLI * (time_3 - time_2), MILLI * (time_3 - time_2) / block.vtx .size (), nInputs <= 1 ? 0 : MILLI * (time_3 - time_2) / (nInputs-1 ), time_connect * MICRO, time_connect * MILLI / num_blocks_total);
22452248
22462249 CAmount blockReward = nFees + GetBlockSubsidy (pindex->nHeight , m_params.GetConsensus ());
22472250 if (block.vtx [0 ]->GetValueOut () > blockReward) {
@@ -2253,8 +2256,9 @@ bool Chainstate::ConnectBlock(const CBlock& block, BlockValidationState& state,
22532256 LogPrintf (" ERROR: %s: CheckQueue failed\n " , __func__);
22542257 return state.Invalid (BlockValidationResult::BLOCK_CONSENSUS, " block-validation-failed" );
22552258 }
2256- int64_t nTime4 = GetTimeMicros (); nTimeVerify += nTime4 - nTime2;
2257- 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);
2259+ int64_t time_4 = GetTimeMicros ();
2260+ time_verify += time_4 - time_2;
2261+ LogPrint (BCLog::BENCH, " - Verify %u txins: %.2fms (%.3fms/txin) [%.2fs (%.2fms/blk)]\n " , nInputs - 1 , MILLI * (time_4 - time_2), nInputs <= 1 ? 0 : MILLI * (time_4 - time_2) / (nInputs-1 ), time_verify * MICRO, time_verify * MILLI / num_blocks_total);
22582262
22592263 if (fJustCheck )
22602264 return true ;
@@ -2263,8 +2267,9 @@ bool Chainstate::ConnectBlock(const CBlock& block, BlockValidationState& state,
22632267 return false ;
22642268 }
22652269
2266- int64_t nTime5 = GetTimeMicros (); nTimeUndo += nTime5 - nTime4;
2267- LogPrint (BCLog::BENCH, " - Write undo data: %.2fms [%.2fs (%.2fms/blk)]\n " , MILLI * (nTime5 - nTime4), nTimeUndo * MICRO, nTimeUndo * MILLI / nBlocksTotal);
2270+ int64_t time_5 = GetTimeMicros ();
2271+ time_undo += time_5 - time_4;
2272+ LogPrint (BCLog::BENCH, " - Write undo data: %.2fms [%.2fs (%.2fms/blk)]\n " , MILLI * (time_5 - time_4), time_undo * MICRO, time_undo * MILLI / num_blocks_total);
22682273
22692274 if (!pindex->IsValid (BLOCK_VALID_SCRIPTS)) {
22702275 pindex->RaiseValidity (BLOCK_VALID_SCRIPTS);
@@ -2274,16 +2279,17 @@ bool Chainstate::ConnectBlock(const CBlock& block, BlockValidationState& state,
22742279 // add this block to the view's block chain
22752280 view.SetBestBlock (pindex->GetBlockHash ());
22762281
2277- int64_t nTime6 = GetTimeMicros (); nTimeIndex += nTime6 - nTime5;
2278- LogPrint (BCLog::BENCH, " - Index writing: %.2fms [%.2fs (%.2fms/blk)]\n " , MILLI * (nTime6 - nTime5), nTimeIndex * MICRO, nTimeIndex * MILLI / nBlocksTotal);
2282+ int64_t time_6 = GetTimeMicros ();
2283+ time_index += time_6 - time_5;
2284+ LogPrint (BCLog::BENCH, " - Index writing: %.2fms [%.2fs (%.2fms/blk)]\n " , MILLI * (time_6 - time_5), time_index * MICRO, time_index * MILLI / num_blocks_total);
22792285
22802286 TRACE6 (validation, block_connected,
22812287 block_hash.data (),
22822288 pindex->nHeight ,
22832289 block.vtx .size (),
22842290 nInputs,
22852291 nSigOpsCost,
2286- nTime5 - nTimeStart // in microseconds (µs)
2292+ time_5 - time_start // in microseconds (µs)
22872293 );
22882294
22892295 return true ;
@@ -2590,7 +2596,7 @@ bool Chainstate::DisconnectTip(BlockValidationState& state, DisconnectedBlockTra
25902596 return error (" DisconnectTip(): Failed to read block" );
25912597 }
25922598 // Apply the block atomically to the chain state.
2593- int64_t nStart = GetTimeMicros ();
2599+ int64_t time_start = GetTimeMicros ();
25942600 {
25952601 CCoinsViewCache view (&CoinsTip ());
25962602 assert (view.GetBestBlock () == pindexDelete->GetBlockHash ());
@@ -2599,7 +2605,7 @@ bool Chainstate::DisconnectTip(BlockValidationState& state, DisconnectedBlockTra
25992605 bool flushed = view.Flush ();
26002606 assert (flushed);
26012607 }
2602- LogPrint (BCLog::BENCH, " - Disconnect block: %.2fms\n " , (GetTimeMicros () - nStart ) * MILLI);
2608+ LogPrint (BCLog::BENCH, " - Disconnect block: %.2fms\n " , (GetTimeMicros () - time_start ) * MILLI);
26032609
26042610 {
26052611 // Prune locks that began at or after the tip should be moved backward so they get a chance to reorg
@@ -2639,11 +2645,11 @@ bool Chainstate::DisconnectTip(BlockValidationState& state, DisconnectedBlockTra
26392645 return true ;
26402646}
26412647
2642- static int64_t nTimeReadFromDiskTotal = 0 ;
2643- static int64_t nTimeConnectTotal = 0 ;
2644- static int64_t nTimeFlush = 0 ;
2645- static int64_t nTimeChainState = 0 ;
2646- static int64_t nTimePostConnect = 0 ;
2648+ static int64_t time_read_from_disk_total = 0 ;
2649+ static int64_t time_connect_total = 0 ;
2650+ static int64_t time_flush = 0 ;
2651+ static int64_t time_chainstate = 0 ;
2652+ static int64_t time_post_connect = 0 ;
26472653
26482654struct PerBlockConnectTrace {
26492655 CBlockIndex* pindex = nullptr ;
@@ -2698,7 +2704,7 @@ bool Chainstate::ConnectTip(BlockValidationState& state, CBlockIndex* pindexNew,
26982704
26992705 assert (pindexNew->pprev == m_chain.Tip ());
27002706 // Read block from disk.
2701- int64_t nTime1 = GetTimeMicros ();
2707+ int64_t time_1 = GetTimeMicros ();
27022708 std::shared_ptr<const CBlock> pthisBlock;
27032709 if (!pblock) {
27042710 std::shared_ptr<CBlock> pblockNew = std::make_shared<CBlock>();
@@ -2712,9 +2718,10 @@ bool Chainstate::ConnectTip(BlockValidationState& state, CBlockIndex* pindexNew,
27122718 }
27132719 const CBlock& blockConnecting = *pthisBlock;
27142720 // Apply the block atomically to the chain state.
2715- int64_t nTime2 = GetTimeMicros (); nTimeReadFromDiskTotal += nTime2 - nTime1;
2716- int64_t nTime3;
2717- LogPrint (BCLog::BENCH, " - Load block from disk: %.2fms [%.2fs (%.2fms/blk)]\n " , (nTime2 - nTime1) * MILLI, nTimeReadFromDiskTotal * MICRO, nTimeReadFromDiskTotal * MILLI / nBlocksTotal);
2721+ int64_t time_2 = GetTimeMicros ();
2722+ time_read_from_disk_total += time_2 - time_1;
2723+ int64_t time_3;
2724+ LogPrint (BCLog::BENCH, " - Load block from disk: %.2fms [%.2fs (%.2fms/blk)]\n " , (time_2 - time_1) * MILLI, time_read_from_disk_total * MICRO, time_read_from_disk_total * MILLI / num_blocks_total);
27182725 {
27192726 CCoinsViewCache view (&CoinsTip ());
27202727 bool rv = ConnectBlock (blockConnecting, state, pindexNew, view);
@@ -2724,20 +2731,23 @@ bool Chainstate::ConnectTip(BlockValidationState& state, CBlockIndex* pindexNew,
27242731 InvalidBlockFound (pindexNew, state);
27252732 return error (" %s: ConnectBlock %s failed, %s" , __func__, pindexNew->GetBlockHash ().ToString (), state.ToString ());
27262733 }
2727- nTime3 = GetTimeMicros (); nTimeConnectTotal += nTime3 - nTime2;
2728- assert (nBlocksTotal > 0 );
2729- LogPrint (BCLog::BENCH, " - Connect total: %.2fms [%.2fs (%.2fms/blk)]\n " , (nTime3 - nTime2) * MILLI, nTimeConnectTotal * MICRO, nTimeConnectTotal * MILLI / nBlocksTotal);
2734+ time_3 = GetTimeMicros ();
2735+ time_connect_total += time_3 - time_2;
2736+ assert (num_blocks_total > 0 );
2737+ LogPrint (BCLog::BENCH, " - Connect total: %.2fms [%.2fs (%.2fms/blk)]\n " , (time_3 - time_2) * MILLI, time_connect_total * MICRO, time_connect_total * MILLI / num_blocks_total);
27302738 bool flushed = view.Flush ();
27312739 assert (flushed);
27322740 }
2733- int64_t nTime4 = GetTimeMicros (); nTimeFlush += nTime4 - nTime3;
2734- LogPrint (BCLog::BENCH, " - Flush: %.2fms [%.2fs (%.2fms/blk)]\n " , (nTime4 - nTime3) * MILLI, nTimeFlush * MICRO, nTimeFlush * MILLI / nBlocksTotal);
2741+ int64_t time_4 = GetTimeMicros ();
2742+ time_flush += time_4 - time_3;
2743+ LogPrint (BCLog::BENCH, " - Flush: %.2fms [%.2fs (%.2fms/blk)]\n " , (time_4 - time_3) * MILLI, time_flush * MICRO, time_flush * MILLI / num_blocks_total);
27352744 // Write the chain state to disk, if necessary.
27362745 if (!FlushStateToDisk (state, FlushStateMode::IF_NEEDED)) {
27372746 return false ;
27382747 }
2739- int64_t nTime5 = GetTimeMicros (); nTimeChainState += nTime5 - nTime4;
2740- LogPrint (BCLog::BENCH, " - Writing chainstate: %.2fms [%.2fs (%.2fms/blk)]\n " , (nTime5 - nTime4) * MILLI, nTimeChainState * MICRO, nTimeChainState * MILLI / nBlocksTotal);
2748+ int64_t time_5 = GetTimeMicros ();
2749+ time_chainstate += time_5 - time_4;
2750+ LogPrint (BCLog::BENCH, " - Writing chainstate: %.2fms [%.2fs (%.2fms/blk)]\n " , (time_5 - time_4) * MILLI, time_chainstate * MICRO, time_chainstate * MILLI / num_blocks_total);
27412751 // Remove conflicting transactions from the mempool.;
27422752 if (m_mempool) {
27432753 m_mempool->removeForBlock (blockConnecting.vtx , pindexNew->nHeight );
@@ -2747,9 +2757,11 @@ bool Chainstate::ConnectTip(BlockValidationState& state, CBlockIndex* pindexNew,
27472757 m_chain.SetTip (*pindexNew);
27482758 UpdateTip (pindexNew);
27492759
2750- int64_t nTime6 = GetTimeMicros (); nTimePostConnect += nTime6 - nTime5; nTimeTotal += nTime6 - nTime1;
2751- LogPrint (BCLog::BENCH, " - Connect postprocess: %.2fms [%.2fs (%.2fms/blk)]\n " , (nTime6 - nTime5) * MILLI, nTimePostConnect * MICRO, nTimePostConnect * MILLI / nBlocksTotal);
2752- LogPrint (BCLog::BENCH, " - Connect block: %.2fms [%.2fs (%.2fms/blk)]\n " , (nTime6 - nTime1) * MILLI, nTimeTotal * MICRO, nTimeTotal * MILLI / nBlocksTotal);
2760+ int64_t time_6 = GetTimeMicros ();
2761+ time_post_connect += time_6 - time_5;
2762+ time_total += time_6 - time_1;
2763+ LogPrint (BCLog::BENCH, " - Connect postprocess: %.2fms [%.2fs (%.2fms/blk)]\n " , (time_6 - time_5) * MILLI, time_post_connect * MICRO, time_post_connect * MILLI / num_blocks_total);
2764+ LogPrint (BCLog::BENCH, " - Connect block: %.2fms [%.2fs (%.2fms/blk)]\n " , (time_6 - time_1) * MILLI, time_total * MICRO, time_total * MILLI / num_blocks_total);
27532765
27542766 connectTrace.BlockConnected (pindexNew, std::move (pthisBlock));
27552767 return true ;
0 commit comments