diff options
author | MarcoFalke <falke.marco@gmail.com> | 2021-12-13 15:07:11 +0100 |
---|---|---|
committer | MarcoFalke <falke.marco@gmail.com> | 2021-12-13 15:07:17 +0100 |
commit | 767c012665953557ad02f731a84c6d10907a46af (patch) | |
tree | 57721f5c1120e3bbd954643b59b1cc942fe2cb59 | |
parent | bf66e258a84e18935fde3ebb9a4b0392bf883222 (diff) | |
parent | 50209a42ad05e92ad0945fa104c65d2b1f2a2c1c (diff) |
Merge bitcoin/bitcoin#23738: validation, log: improve logging of ChainstateManager snapshot persistance
50209a42ad05e92ad0945fa104c65d2b1f2a2c1c validation, doc: remove TODO comment (Jon Atack)
8e37fa83934ad47a4a73c326213e2073dfc35e29 validation, log: improve logging in FlushSnapshotToDisk() (Jon Atack)
271252c0bda5779a255f23a73ceb6f722559f0d1 validation, log: extract FlushSnapshotToDisk() function (Jon Atack)
Pull request description:
Use the `LOG_TIME_MILLIS_WITH_CATEGORY_MSG_ONCE` macro to improve the logging of ChainstateManager snapshot persistance, log task start and completion separately and no longer manually track the duration, as suggested by Marco Falke in https://github.com/bitcoin/bitcoin/pull/22872#discussion_r715571280.
Extract the flushing into one function, which clarifies the logic, extends the improved logging to both flushing call sites, and allows logging the prefix `FlushSnapshotToDisk`, which is similar to `FlushStateToDisk`.
before
```
[snapshot] flushing coins cache (0 MB)... done (0.00ms)
[snapshot] flushing snapshot chainstate to disk
```
after
```
FlushSnapshotToDisk: flushing coins cache (0 MB) started
...
FlushSnapshotToDisk: completed (0.00ms)
FlushSnapshotToDisk: saving snapshot chainstate (0 MB) started
...
FlushSnapshotToDisk: completed (0.00ms)
```
The logging can be observed in the output of
```
./src/test/test_bitcoin -t validation_chainstate_tests -- DEBUG_LOG_OUT
```
Top commit has no ACKs.
Tree-SHA512: 5d954cd8c7455f8625152a43663a237f04717bb834aed62925a56e17c711fca6ccfc03783970b6b0bde44f64617d804b423a7048287c06ee816db36247acf272
-rw-r--r-- | src/validation.cpp | 26 |
1 files changed, 15 insertions, 11 deletions
diff --git a/src/validation.cpp b/src/validation.cpp index d4203de56a..861831444a 100644 --- a/src/validation.cpp +++ b/src/validation.cpp @@ -4840,6 +4840,17 @@ bool ChainstateManager::ActivateSnapshot( return true; } +static void FlushSnapshotToDisk(CCoinsViewCache& coins_cache, bool snapshot_loaded) +{ + LOG_TIME_MILLIS_WITH_CATEGORY_MSG_ONCE( + strprintf("%s (%.2f MB)", + snapshot_loaded ? "saving snapshot chainstate" : "flushing coins cache", + coins_cache.DynamicMemoryUsage() / (1000 * 1000)), + BCLog::LogFlags::ALL); + + coins_cache.Flush(); +} + bool ChainstateManager::PopulateAndValidateSnapshot( CChainState& snapshot_chainstate, CAutoFile& coins_file, @@ -4877,7 +4888,6 @@ bool ChainstateManager::PopulateAndValidateSnapshot( uint64_t coins_left = metadata.m_coins_count; LogPrintf("[snapshot] loading coins from snapshot %s\n", base_blockhash.ToString()); - int64_t flush_now{0}; int64_t coins_processed{0}; while (coins_left > 0) { @@ -4921,19 +4931,14 @@ bool ChainstateManager::PopulateAndValidateSnapshot( const auto snapshot_cache_state = WITH_LOCK(::cs_main, return snapshot_chainstate.GetCoinsCacheSizeState()); - if (snapshot_cache_state >= - CoinsCacheSizeState::CRITICAL) { - LogPrintf("[snapshot] flushing coins cache (%.2f MB)... ", /* Continued */ - coins_cache.DynamicMemoryUsage() / (1000 * 1000)); - flush_now = GetTimeMillis(); - + if (snapshot_cache_state >= CoinsCacheSizeState::CRITICAL) { // This is a hack - we don't know what the actual best block is, but that // doesn't matter for the purposes of flushing the cache here. We'll set this // to its correct value (`base_blockhash`) below after the coins are loaded. coins_cache.SetBestBlock(GetRandHash()); - coins_cache.Flush(); - LogPrintf("done (%.2fms)\n", GetTimeMillis() - flush_now); + // No need to acquire cs_main since this chainstate isn't being used yet. + FlushSnapshotToDisk(coins_cache, /*snapshot_loaded=*/false); } } } @@ -4963,9 +4968,8 @@ bool ChainstateManager::PopulateAndValidateSnapshot( coins_cache.DynamicMemoryUsage() / (1000 * 1000), base_blockhash.ToString()); - LogPrintf("[snapshot] flushing snapshot chainstate to disk\n"); // No need to acquire cs_main since this chainstate isn't being used yet. - coins_cache.Flush(); // TODO: if #17487 is merged, add erase=false here for better performance. + FlushSnapshotToDisk(coins_cache, /*snapshot_loaded=*/true); assert(coins_cache.GetBestBlock() == base_blockhash); |