@@ -1965,14 +1965,14 @@ static unsigned int GetBlockScriptFlags(const CBlockIndex& block_index, const Ch
1965
1965
}
1966
1966
1967
1967
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 ;
1976
1976
1977
1977
/* * Apply the effects of this block (with given index) on the UTXO set represented by coins.
1978
1978
* Validity checks that depend on the UTXO set are also done; ConnectBlock()
@@ -1986,7 +1986,7 @@ bool Chainstate::ConnectBlock(const CBlock& block, BlockValidationState& state,
1986
1986
uint256 block_hash{block.GetHash ()};
1987
1987
assert (*pindex->phashBlock == block_hash);
1988
1988
1989
- int64_t nTimeStart = GetTimeMicros ();
1989
+ int64_t time_start = GetTimeMicros ();
1990
1990
1991
1991
// Check it again in case a previous version let a bad block in
1992
1992
// NOTE: We don't currently (re-)invoke ContextualCheckBlock() or
@@ -2015,7 +2015,7 @@ bool Chainstate::ConnectBlock(const CBlock& block, BlockValidationState& state,
2015
2015
uint256 hashPrevBlock = pindex->pprev == nullptr ? uint256 () : pindex->pprev ->GetBlockHash ();
2016
2016
assert (hashPrevBlock == view.GetBestBlock ());
2017
2017
2018
- nBlocksTotal ++;
2018
+ num_blocks_total ++;
2019
2019
2020
2020
// Special case for the genesis block, skipping connection of its transactions
2021
2021
// (its coinbase is unspendable)
@@ -2056,8 +2056,9 @@ bool Chainstate::ConnectBlock(const CBlock& block, BlockValidationState& state,
2056
2056
}
2057
2057
}
2058
2058
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);
2061
2062
2062
2063
// Do not allow blocks that contain transactions which 'overwrite' older transactions,
2063
2064
// unless those are already completely spent.
@@ -2155,8 +2156,9 @@ bool Chainstate::ConnectBlock(const CBlock& block, BlockValidationState& state,
2155
2156
// Get the script flags for this block
2156
2157
unsigned int flags{GetBlockScriptFlags (*pindex, m_chainman)};
2157
2158
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);
2160
2162
2161
2163
CBlockUndo blockundo;
2162
2164
@@ -2240,8 +2242,9 @@ bool Chainstate::ConnectBlock(const CBlock& block, BlockValidationState& state,
2240
2242
}
2241
2243
UpdateCoins (tx, view, i == 0 ? undoDummy : blockundo.vtxundo .back (), pindex->nHeight );
2242
2244
}
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);
2245
2248
2246
2249
CAmount blockReward = nFees + GetBlockSubsidy (pindex->nHeight , m_params.GetConsensus ());
2247
2250
if (block.vtx [0 ]->GetValueOut () > blockReward) {
@@ -2253,8 +2256,9 @@ bool Chainstate::ConnectBlock(const CBlock& block, BlockValidationState& state,
2253
2256
LogPrintf (" ERROR: %s: CheckQueue failed\n " , __func__);
2254
2257
return state.Invalid (BlockValidationResult::BLOCK_CONSENSUS, " block-validation-failed" );
2255
2258
}
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);
2258
2262
2259
2263
if (fJustCheck )
2260
2264
return true ;
@@ -2263,8 +2267,9 @@ bool Chainstate::ConnectBlock(const CBlock& block, BlockValidationState& state,
2263
2267
return false ;
2264
2268
}
2265
2269
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);
2268
2273
2269
2274
if (!pindex->IsValid (BLOCK_VALID_SCRIPTS)) {
2270
2275
pindex->RaiseValidity (BLOCK_VALID_SCRIPTS);
@@ -2274,16 +2279,17 @@ bool Chainstate::ConnectBlock(const CBlock& block, BlockValidationState& state,
2274
2279
// add this block to the view's block chain
2275
2280
view.SetBestBlock (pindex->GetBlockHash ());
2276
2281
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);
2279
2285
2280
2286
TRACE6 (validation, block_connected,
2281
2287
block_hash.data (),
2282
2288
pindex->nHeight ,
2283
2289
block.vtx .size (),
2284
2290
nInputs,
2285
2291
nSigOpsCost,
2286
- nTime5 - nTimeStart // in microseconds (µs)
2292
+ time_5 - time_start // in microseconds (µs)
2287
2293
);
2288
2294
2289
2295
return true ;
@@ -2590,7 +2596,7 @@ bool Chainstate::DisconnectTip(BlockValidationState& state, DisconnectedBlockTra
2590
2596
return error (" DisconnectTip(): Failed to read block" );
2591
2597
}
2592
2598
// Apply the block atomically to the chain state.
2593
- int64_t nStart = GetTimeMicros ();
2599
+ int64_t time_start = GetTimeMicros ();
2594
2600
{
2595
2601
CCoinsViewCache view (&CoinsTip ());
2596
2602
assert (view.GetBestBlock () == pindexDelete->GetBlockHash ());
@@ -2599,7 +2605,7 @@ bool Chainstate::DisconnectTip(BlockValidationState& state, DisconnectedBlockTra
2599
2605
bool flushed = view.Flush ();
2600
2606
assert (flushed);
2601
2607
}
2602
- LogPrint (BCLog::BENCH, " - Disconnect block: %.2fms\n " , (GetTimeMicros () - nStart ) * MILLI);
2608
+ LogPrint (BCLog::BENCH, " - Disconnect block: %.2fms\n " , (GetTimeMicros () - time_start ) * MILLI);
2603
2609
2604
2610
{
2605
2611
// 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
2639
2645
return true ;
2640
2646
}
2641
2647
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 ;
2647
2653
2648
2654
struct PerBlockConnectTrace {
2649
2655
CBlockIndex* pindex = nullptr ;
@@ -2698,7 +2704,7 @@ bool Chainstate::ConnectTip(BlockValidationState& state, CBlockIndex* pindexNew,
2698
2704
2699
2705
assert (pindexNew->pprev == m_chain.Tip ());
2700
2706
// Read block from disk.
2701
- int64_t nTime1 = GetTimeMicros ();
2707
+ int64_t time_1 = GetTimeMicros ();
2702
2708
std::shared_ptr<const CBlock> pthisBlock;
2703
2709
if (!pblock) {
2704
2710
std::shared_ptr<CBlock> pblockNew = std::make_shared<CBlock>();
@@ -2712,9 +2718,10 @@ bool Chainstate::ConnectTip(BlockValidationState& state, CBlockIndex* pindexNew,
2712
2718
}
2713
2719
const CBlock& blockConnecting = *pthisBlock;
2714
2720
// 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);
2718
2725
{
2719
2726
CCoinsViewCache view (&CoinsTip ());
2720
2727
bool rv = ConnectBlock (blockConnecting, state, pindexNew, view);
@@ -2724,20 +2731,23 @@ bool Chainstate::ConnectTip(BlockValidationState& state, CBlockIndex* pindexNew,
2724
2731
InvalidBlockFound (pindexNew, state);
2725
2732
return error (" %s: ConnectBlock %s failed, %s" , __func__, pindexNew->GetBlockHash ().ToString (), state.ToString ());
2726
2733
}
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);
2730
2738
bool flushed = view.Flush ();
2731
2739
assert (flushed);
2732
2740
}
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);
2735
2744
// Write the chain state to disk, if necessary.
2736
2745
if (!FlushStateToDisk (state, FlushStateMode::IF_NEEDED)) {
2737
2746
return false ;
2738
2747
}
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);
2741
2751
// Remove conflicting transactions from the mempool.;
2742
2752
if (m_mempool) {
2743
2753
m_mempool->removeForBlock (blockConnecting.vtx , pindexNew->nHeight );
@@ -2747,9 +2757,11 @@ bool Chainstate::ConnectTip(BlockValidationState& state, CBlockIndex* pindexNew,
2747
2757
m_chain.SetTip (*pindexNew);
2748
2758
UpdateTip (pindexNew);
2749
2759
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);
2753
2765
2754
2766
connectTrace.BlockConnected (pindexNew, std::move (pthisBlock));
2755
2767
return true ;
0 commit comments