crypto-power/cryptopower

dextest: btc restoration never finishes.

Closed this issue · 4 comments

Testing on dextest, so may not be a real problem, but may be.

Unable to restore a wallet on master, it gets stuck in this state:

image

Logs will show this error over and over:

2024-03-21 16:26:30.467 [ERR] BTC: Unable to process chain backend block connected notification: failed to store sync information 21f1333c7661fc4906f8153f03fa5c44ab750b68f2e9cd26c5b49fad5f71119b: failed to fetch block hash for height 1422: block not found
2024-03-21 16:26:45.480 [INF] BTC: Current sync progress update is on block 1424, target sync block is 1424
2024-03-21 16:27:00.493 [INF] BTC: Current sync progress update is on block 1425, target sync block is 1425
2024-03-21 16:27:15.504 [ERR] BTC: Unable to process chain backend block connected notification: failed to store sync information 6086127db16f0884c164275b5301aa9c44cd4b6ca3722860f936fe38abe0b502: failed to fetch block hash for height 1425: block not found
2024-03-21 16:27:15.504 [INF] BTC: Current sync progress update is on block 1426, target sync block is 1426

Was able to observe the same errors on testnet but without the stuck status.

2024-03-21 20:01:59.570 [INF] BTC: Started rescan from block 0000000000000001f4b8184d853bdfbf36048866b670a2029366cacab138704a (height 2582875) for 0 addresses
2024-03-21 20:01:59.570 [ERR] BTC: Neutrino rescan ended with error: rescan exited
2024-03-21 20:01:59.570 [INF] BTC: Catching up block hashes to height 2582876, this might take a while
2024-03-21 20:01:59.570 [INF] BTC: Current sync progress update is on block 2582876, target sync block is 2582888
2024-03-21 20:01:59.571 [INF] BTC: Done catching up block hashes
2024-03-21 20:01:59.571 [INF] BTC: Rescanned through block 0000000002e909fd2a10ec881affe354527b36eca04dd17e2199eb37d6bc452e (height 2582876)
2024-03-21 20:01:59.571 [INF] BTC: Current sync progress update is on block 2582888, target sync block is 2582888
2024-03-21 20:01:59.571 [INF] BTC: Subscribing wallet (bec) for transaction notifications
2024-03-21 20:02:00.647 [INF] SHWL: Set discovered accounts = true for wallet 1
2024-03-21 20:02:01.577 [ERR] BTC: updating syncedTo block failed: Error: failed to store sync information 000000000000000794b75c5810e374fd09dd9a4a57c9acabd448906ad8af05eb: failed to fetch block hash for height 2582887: block not found
2024-03-21 20:09:12.004 [ERR] BTC: updating syncedTo block failed: Error: failed to store sync information 00000000000000188c9c97985ec2f55f5f6bec62d64c6398c8f5febdddc48ac3: failed to fetch block hash for height 2582888: block not found
2024-03-21 20:09:12.004 [INF] BTC: Current sync progress update is on block 2582889, target sync block is 2582889
2024-03-21 20:09:54.929 [ERR] BTC: updating syncedTo block failed: Error: failed to store sync information 0000000000000001fca621083c80470ee09dafbd8c004d3ac6c2137a04d0e14e: failed to fetch block hash for height 2582889: block not found
2024-03-21 20:09:54.929 [INF] BTC: Current sync progress update is on block 2582890, target sync block is 2582890
2024-03-21 20:30:01.676 [ERR] BTC: updating syncedTo block failed: Error: failed to store sync information 000000000015113b2f8571b60a0083f78cb63dfb58a8a97ed7fb2b01f21a6d56: failed to fetch block hash for height 2582890: block not found
2024-03-21 20:30:01.676 [INF] BTC: Current sync progress update is on block 2582891, target sync block is 2582891
2024-03-21 20:37:07.183 [ERR] BTC: updating syncedTo block failed: Error: failed to store sync information 000000000000000a32bf07228860ccfbbc151604895d80b0c6421fd8c80d5aed: failed to fetch block hash for height 2582891: block not found
2024-03-21 20:37:07.183 [INF] BTC: Current sync progress update is on block 2582892, target sync block is 2582892
2024-03-21 20:56:50.145 [ERR] BTC: updating syncedTo block failed: Error: failed to store sync information 0000000022c6cf5f7d952fcef00187b65f602f7dd19437addbb0be705329b5f5: failed to fetch block hash for height 2582892: block not found
2024-03-21 20:56:50.145 [INF] BTC: Current sync progress update is on block 2582893, target sync block is 2582893
2024-03-21 20:58:30.846 [ERR] BTC: updating syncedTo block failed: Error: failed to store sync information 00000000000000245745b0c766f31eefb68659815497e00b7e9b1cd055b68800: failed to fetch block hash for height 2582893: block not found
2024-03-21 20:58:30.846 [INF] BTC: Current sync progress update is on block 2582894, target sync block is 2582894
2024-03-21 21:04:09.813 [ERR] BTC: updating syncedTo block failed: Error: failed to store sync information 000000000000000ecac067910bd15815af4eec6c548104da35e3ceade9c5427c: failed to fetch block hash for height 2582894: block not found
2024-03-21 21:04:09.813 [INF] BTC: Current sync progress update is on block 2582895, target sync block is 2582895

I think not syncing is because if there are less than 2k blocks, the chain.RescanFinished is not sent. I guess it it not considered rescan mode. As for the errors I removed some things that I don't think were needed and it seems to have cleared them up.

I'm still scratching my head about the wallet birthday. When do we need to set that? Seems the wallet should save that automatically but I guess it doesnt?

Seems the wallet should save that automatically but I guess it doesnt?

nope weirdly it doesn't

@dreacot @itswisdomagain I think I found a major flaw in btc and ltc. libwallet is listening to the same channel as btcwallet, so notifcations are only going to one or the other, not to both. It's random.

Please see the use of chainClient.Notifications():

us:

func (asset *Asset) handleNotifications() {
t := time.NewTicker(syncIntervalGap)
notificationsLoop:
for {
select {
case n, ok := <-asset.chainClient.Notifications():
if !ok {
continue notificationsLoop
}
switch n := n.(type) {
case chain.ClientConnected:
// Notification type sent is sent when the client connects or reconnects
// to the RPC server. It initialize the sync progress data report.
case chain.BlockConnected:
// Notification type is sent when a new block connects to the longest chain.
// Trigger the progress report only when the block to be reported
// is the best chaintip.
asset.updateSyncedToBlock(n.Height)
select {
case <-t.C:
// log sync progress always
asset.updateSyncProgress(n.Block.Height)
default:
}

btcwallet: https://github.com/btcsuite/btcwallet/blob/9a7dd2416f4ddad759330663d96ad98706d71f9e/wallet/chainntfns.go#L122-L166

But as you can see here in neutrino, its just a channel, it can only handle one "subscriber":
https://github.com/lightninglabs/neutrino/blob/43f5a588eb4a53cb36d118420e186629154086da/blockmanager.go#L2821-L2825
https://github.com/lightninglabs/neutrino/blob/43f5a588eb4a53cb36d118420e186629154086da/blockmanager.go#L193-L195

See 10 sends to 5 listeners will receive randomly: https://go.dev/play/p/VL_-NTmpJUK

I think we need to be getting notifications from btcwallet.