Automatic wallet rescan skipped after abort #24487

I ran bitcoin-qt with an old wallet, causing it to rescan, then stopped it with a SIGINT signal, resulting in the following log. Nothing unexpected, so far:

2022-03-05T16:01:03Z init message: Loading wallet…
2022-03-05T16:01:03Z BerkeleyEnvironment::Open: LogDir=…/.bitcoin/database ErrorFile=…/.bitcoin/db.log
2022-03-05T15:57:18Z [walletname.dat] Wallet File Version = 159900
2022-03-05T15:57:18Z [walletname.dat] Keys: 2397 plaintext, 0 encrypted, 2397 w/ metadata, 2397 total. Unknown wallet records: 0
2022-03-05T15:57:18Z [walletname.dat] Wallet completed loading in              65ms
2022-03-05T15:57:18Z init message: Rescanning…
2022-03-05T15:57:18Z [walletname.dat] Rescanning last 134072 blocks (from block 591711)...
2022-03-05T15:57:18Z [walletname.dat] Rescan started from block 000000000000000000075fcc1872da61f45bcfd0e0bb36b7c8cb45e7a328ad41...
2022-03-05T15:58:18Z [walletname.dat] Still rescanning. At block 593552. Progress=0.632716
2022-03-05T15:59:18Z [walletname.dat] Still rescanning. At block 595458. Progress=0.638084
2022-03-05T15:59:37Z [walletname.dat] Rescan interrupted by shutdown request at block 596080. Progress=0.639932
2022-03-05T15:59:37Z Error: Failed to rescan the wallet during initialization
2022-03-05T15:59:41Z GUI: initializeResult : Initialization result:  false
2022-03-05T15:59:41Z GUI: requestShutdown : Requesting shutdown
2022-03-05T15:59:41Z GUI: Running Shutdown in thread
2022-03-05T15:59:41Z Shutdown: In progress...
2022-03-05T15:59:41Z scheduler thread exit
2022-03-05T15:59:42Z Shutdown: done
2022-03-05T15:59:42Z GUI: Shutdown finished
2022-03-05T15:59:42Z GUI: ~InitExecutor : Stopping thread
2022-03-05T15:59:42Z GUI: ~InitExecutor : Stopped thread

However, the next time it was launched, the rescan didn't continue, nor did it start over. It seems to have been skipped?

2022-03-05T16:01:03Z init message: Loading wallet…
2022-03-05T16:01:03Z BerkeleyEnvironment::Open: LogDir=…/.bitcoin/database ErrorFile=…/.bitcoin/db.log
2022-03-05T16:01:03Z [walletname.dat] Wallet File Version = 159900
2022-03-05T16:01:03Z [walletname.dat] Keys: 2397 plaintext, 0 encrypted, 2397 w/ metadata, 2397 total. Unknown wallet records: 0
2022-03-05T16:01:03Z [walletname.dat] Wallet completed loading in              91ms
2022-03-05T16:01:03Z [walletname.dat] setKeyPool.size() = 2000
2022-03-05T16:01:03Z [walletname.dat] mapWallet.size() = 378
2022-03-05T16:01:03Z [walletname.dat] m_address_book.size() = 183
2022-03-05T16:01:03Z Loaded 2 addresses from "anchors.dat"

I didn't investigate deeply, but could it be that despite the failed rescan, the new tip block was stored in the wallet? if so, this would be confusing.

I would guess that because the signals are subscribed before the rescan (in CWallet::AttachChain), when the chain tip changes during rescan,

CMainSignals::ChainStateFlushed → CWallet::chainStateFlushed

which invokes WriteBestBlock, even though the rescan doesn't complete.

(...) when the chain tip changes during rescan (...)

I think that it wouldn't even be necessary that the chain tip changes during the rescan (which would only occasionally cause chainStateFlushed), but SIGINT causes the chainStateFlushed signal itself during Shutdown.

I think that it wouldn't even be necessary that the chain tip changes during the rescan

Good point!

I guess, strictly, the signal should only cause a best block update if the last best block matches the last chain tip. But it's more straightforward to implement in terms of a boolean in_sync that gets set when already in sync with the chain, or on successful rescan. But maybe there's other options as well.

I haven't looked how the indexes handle this situation.

Edit: added 23.0 milestone, I think this is a sufficiently serious issue because it might result in perceived (fixable by requesting an explicit rescan) missing funds.

I haven't looked how the indexes handle this situation.

I don't know much about the wallet but I recently spent some time looking at index stability in this and similar situations: The indexes do pretty much what you suggested, they have a bool m_synced and don't process chainStateFlushed or blockConnected callbacks unless synced successfully.

I could locally reproduce that blocks are skipped if a rescan is aborted and agree that it would be good to fix this.

Hmm, this is probably a longstanding bug, but worth fixing. It would be good to ignore both flushed and connected notifications while the wallet is syncing. Ignoring connected notifications might be tricky because there could be a race condition where a new block is connected at the end of the sync and the notification is ignored. But ignoring flush notifications might be pretty safe and easy since wallet will flush (write best block locator) at the end of rescanning anyway.

The best longer term fix for this IMO would be to use CallFunctionInValidationInterfaceQueue to register for notifications. Registering for notifications at the correct place in the queue avoids both opposite problems where:

1. Registering for notifications happens too early so spurious connected and flushed notifications are received during the sync and need to be filtered out.
2. Or registering for notifications happens too late, so connected or flushed notifications are missed at the end of the sync.

1772a1e4ea9240868efc50ffef46a35078c0da53 from #24230 implements this CallFunctionInValidationInterfaceQueue sync strategy for indexes and #15719 implements it for wallets, but at this point I would probably abandon #15719 or rebase it on #24230.

While I think we should fix this, it's likely been an issue for a really long time now and so isn't really something that we should try to fix for 23.0.

Ok, yes, I assumed it was a recent regression, removed the milestone.

I opened #24984 to fix this.