Merge #15901: wallet: log on rescan completion

1b602f6fe remove extraneous scope (andrewtoth)
6ad372a97 wallet: log on rescan completion (andrewtoth)

Pull request description:

  Currently there is nothing logged when a rescan completes successfully. This leaves the last log message something like:
  ```
   Still rescanning. At block 573037. Progress=0.998415
  ```
  It is unclear when the rescan actually finished. This adds a `Rescan completed.` message to make it more clear.

ACKs for commit 1b602f:
  Empact:
    utACK 1b602f6fed
  meshcollider:
    utACK 1b602f6fed

Tree-SHA512: 618d646a0f143c2372f1db91c14e7f677b39fb3a2957e887cbc349971c3e8953bc017e2028ac489368c20dbb9a7265c4c2d448c95de785366acfe0e576f1be66
This commit is contained in:
MeshCollider 2019-04-28 12:08:55 +12:00
commit bdd7217f2c
No known key found for this signature in database
GPG key ID: D300116E1C875A3D

View file

@ -1771,6 +1771,7 @@ int64_t CWallet::RescanFromTime(int64_t startTime, const WalletRescanReserver& r
CWallet::ScanResult CWallet::ScanForWalletTransactions(const uint256& start_block, const uint256& stop_block, const WalletRescanReserver& reserver, bool fUpdate) CWallet::ScanResult CWallet::ScanForWalletTransactions(const uint256& start_block, const uint256& stop_block, const WalletRescanReserver& reserver, bool fUpdate)
{ {
int64_t nNow = GetTime(); int64_t nNow = GetTime();
int64_t start_time = GetTimeMillis();
assert(reserver.isReserved()); assert(reserver.isReserved());
@ -1779,90 +1780,90 @@ CWallet::ScanResult CWallet::ScanForWalletTransactions(const uint256& start_bloc
WalletLogPrintf("Rescan started from block %s...\n", start_block.ToString()); WalletLogPrintf("Rescan started from block %s...\n", start_block.ToString());
fAbortRescan = false;
ShowProgress(strprintf("%s " + _("Rescanning..."), GetDisplayName()), 0); // show rescan progress in GUI as dialog or on splashscreen, if -rescan on startup
uint256 tip_hash;
// The way the 'block_height' is initialized is just a workaround for the gcc bug #47679 since version 4.6.0.
Optional<int> block_height = MakeOptional(false, int());
double progress_begin;
double progress_end;
{ {
fAbortRescan = false; auto locked_chain = chain().lock();
ShowProgress(strprintf("%s " + _("Rescanning..."), GetDisplayName()), 0); // show rescan progress in GUI as dialog or on splashscreen, if -rescan on startup if (Optional<int> tip_height = locked_chain->getHeight()) {
uint256 tip_hash; tip_hash = locked_chain->getBlockHash(*tip_height);
// The way the 'block_height' is initialized is just a workaround for the gcc bug #47679 since version 4.6.0. }
Optional<int> block_height = MakeOptional(false, int()); block_height = locked_chain->getBlockHeight(block_hash);
double progress_begin; progress_begin = chain().guessVerificationProgress(block_hash);
double progress_end; progress_end = chain().guessVerificationProgress(stop_block.IsNull() ? tip_hash : stop_block);
{ }
auto locked_chain = chain().lock(); double progress_current = progress_begin;
if (Optional<int> tip_height = locked_chain->getHeight()) { while (block_height && !fAbortRescan && !chain().shutdownRequested()) {
tip_hash = locked_chain->getBlockHash(*tip_height); if (*block_height % 100 == 0 && progress_end - progress_begin > 0.0) {
} ShowProgress(strprintf("%s " + _("Rescanning..."), GetDisplayName()), std::max(1, std::min(99, (int)((progress_current - progress_begin) / (progress_end - progress_begin) * 100))));
block_height = locked_chain->getBlockHeight(block_hash); }
progress_begin = chain().guessVerificationProgress(block_hash); if (GetTime() >= nNow + 60) {
progress_end = chain().guessVerificationProgress(stop_block.IsNull() ? tip_hash : stop_block); nNow = GetTime();
WalletLogPrintf("Still rescanning. At block %d. Progress=%f\n", *block_height, progress_current);
} }
double progress_current = progress_begin;
while (block_height && !fAbortRescan && !chain().shutdownRequested()) {
if (*block_height % 100 == 0 && progress_end - progress_begin > 0.0) {
ShowProgress(strprintf("%s " + _("Rescanning..."), GetDisplayName()), std::max(1, std::min(99, (int)((progress_current - progress_begin) / (progress_end - progress_begin) * 100))));
}
if (GetTime() >= nNow + 60) {
nNow = GetTime();
WalletLogPrintf("Still rescanning. At block %d. Progress=%f\n", *block_height, progress_current);
}
CBlock block; CBlock block;
if (chain().findBlock(block_hash, &block) && !block.IsNull()) { if (chain().findBlock(block_hash, &block) && !block.IsNull()) {
auto locked_chain = chain().lock(); auto locked_chain = chain().lock();
LOCK(cs_wallet); LOCK(cs_wallet);
if (!locked_chain->getBlockHeight(block_hash)) { if (!locked_chain->getBlockHeight(block_hash)) {
// Abort scan if current block is no longer active, to prevent // Abort scan if current block is no longer active, to prevent
// marking transactions as coming from the wrong block. // marking transactions as coming from the wrong block.
// TODO: This should return success instead of failure, see // TODO: This should return success instead of failure, see
// https://github.com/bitcoin/bitcoin/pull/14711#issuecomment-458342518 // https://github.com/bitcoin/bitcoin/pull/14711#issuecomment-458342518
result.last_failed_block = block_hash;
result.status = ScanResult::FAILURE;
break;
}
for (size_t posInBlock = 0; posInBlock < block.vtx.size(); ++posInBlock) {
SyncTransaction(block.vtx[posInBlock], block_hash, posInBlock, fUpdate);
}
// scan succeeded, record block as most recent successfully scanned
result.last_scanned_block = block_hash;
result.last_scanned_height = *block_height;
} else {
// could not scan block, keep scanning but record this block as the most recent failure
result.last_failed_block = block_hash; result.last_failed_block = block_hash;
result.status = ScanResult::FAILURE; result.status = ScanResult::FAILURE;
}
if (block_hash == stop_block) {
break; break;
} }
{ for (size_t posInBlock = 0; posInBlock < block.vtx.size(); ++posInBlock) {
auto locked_chain = chain().lock(); SyncTransaction(block.vtx[posInBlock], block_hash, posInBlock, fUpdate);
Optional<int> tip_height = locked_chain->getHeight(); }
if (!tip_height || *tip_height <= block_height || !locked_chain->getBlockHeight(block_hash)) { // scan succeeded, record block as most recent successfully scanned
// break successfully when rescan has reached the tip, or result.last_scanned_block = block_hash;
// previous block is no longer on the chain due to a reorg result.last_scanned_height = *block_height;
break; } else {
} // could not scan block, keep scanning but record this block as the most recent failure
result.last_failed_block = block_hash;
result.status = ScanResult::FAILURE;
}
if (block_hash == stop_block) {
break;
}
{
auto locked_chain = chain().lock();
Optional<int> tip_height = locked_chain->getHeight();
if (!tip_height || *tip_height <= block_height || !locked_chain->getBlockHeight(block_hash)) {
// break successfully when rescan has reached the tip, or
// previous block is no longer on the chain due to a reorg
break;
}
// increment block and verification progress // increment block and verification progress
block_hash = locked_chain->getBlockHash(++*block_height); block_hash = locked_chain->getBlockHash(++*block_height);
progress_current = chain().guessVerificationProgress(block_hash); progress_current = chain().guessVerificationProgress(block_hash);
// handle updated tip hash // handle updated tip hash
const uint256 prev_tip_hash = tip_hash; const uint256 prev_tip_hash = tip_hash;
tip_hash = locked_chain->getBlockHash(*tip_height); tip_hash = locked_chain->getBlockHash(*tip_height);
if (stop_block.IsNull() && prev_tip_hash != tip_hash) { if (stop_block.IsNull() && prev_tip_hash != tip_hash) {
// in case the tip has changed, update progress max // in case the tip has changed, update progress max
progress_end = chain().guessVerificationProgress(tip_hash); progress_end = chain().guessVerificationProgress(tip_hash);
}
} }
} }
ShowProgress(strprintf("%s " + _("Rescanning..."), GetDisplayName()), 100); // hide progress dialog in GUI }
if (block_height && fAbortRescan) { ShowProgress(strprintf("%s " + _("Rescanning..."), GetDisplayName()), 100); // hide progress dialog in GUI
WalletLogPrintf("Rescan aborted at block %d. Progress=%f\n", *block_height, progress_current); if (block_height && fAbortRescan) {
result.status = ScanResult::USER_ABORT; WalletLogPrintf("Rescan aborted at block %d. Progress=%f\n", *block_height, progress_current);
} else if (block_height && chain().shutdownRequested()) { result.status = ScanResult::USER_ABORT;
WalletLogPrintf("Rescan interrupted by shutdown request at block %d. Progress=%f\n", *block_height, progress_current); } else if (block_height && chain().shutdownRequested()) {
result.status = ScanResult::USER_ABORT; WalletLogPrintf("Rescan interrupted by shutdown request at block %d. Progress=%f\n", *block_height, progress_current);
} result.status = ScanResult::USER_ABORT;
} else {
WalletLogPrintf("Rescan completed in %15dms\n", GetTimeMillis() - start_time);
} }
return result; return result;
} }
@ -4245,7 +4246,6 @@ std::shared_ptr<CWallet> CWallet::CreateWalletFromFile(interfaces::Chain& chain,
} }
} }
nStart = GetTimeMillis();
{ {
WalletRescanReserver reserver(walletInstance.get()); WalletRescanReserver reserver(walletInstance.get());
if (!reserver.reserve() || (ScanResult::SUCCESS != walletInstance->ScanForWalletTransactions(locked_chain->getBlockHash(rescan_height), {} /* stop block */, reserver, true /* update */).status)) { if (!reserver.reserve() || (ScanResult::SUCCESS != walletInstance->ScanForWalletTransactions(locked_chain->getBlockHash(rescan_height), {} /* stop block */, reserver, true /* update */).status)) {
@ -4253,7 +4253,6 @@ std::shared_ptr<CWallet> CWallet::CreateWalletFromFile(interfaces::Chain& chain,
return nullptr; return nullptr;
} }
} }
walletInstance->WalletLogPrintf("Rescan completed in %15dms\n", GetTimeMillis() - nStart);
walletInstance->ChainStateFlushed(locked_chain->getTipLocator()); walletInstance->ChainStateFlushed(locked_chain->getTipLocator());
walletInstance->database->IncrementUpdateCounter(); walletInstance->database->IncrementUpdateCounter();