dmigwi / sample

0 stars 0 forks source link

[BTC]: App freezes when wallet recovery starts #532

Open dmigwi opened 1 year ago

dmigwi commented 1 year ago

The app freezes for a couple of seconds when btc wallet recovery starts

the freeze is first noticed when the log below appears

2023-01-05 10:49:32.838 [INF] BTC: Seed birthday surpassed, starting recovery of wallet from height=761408 hash=00000000000000000006e7f6c1f81641356b9354fba66f2c2ba560aa69e5ba10 with recovery-window=200

(Issue originally authored by: @Kennedy Izuegbu in gitlab.com)

dmigwi commented 1 year ago

i still reproduced this as of today, your wallet should be 100% previously synced.

quit the app, then open the wallet and watch the logs for when recovery starts, try doing something like sending funds, the app becomes unresponsive

By Kennedy Izuegbu on 2023-01-06T13:23:54 (imported from GitLab)

(Comment originally authored by: @Kennedy Izuegbu in gitlab.com)

dmigwi commented 1 year ago

I am taking a look at this

By Anthony Ademu on 2023-01-05T16:29:53 (imported from GitLab)

(Comment originally authored by: @Kennedy Izuegbu in gitlab.com)

dmigwi commented 1 year ago

I am unable to reproduce this issue

By Anthony Ademu on 2023-01-05T18:28:09 (imported from GitLab)

(Comment originally authored by: @Kennedy Izuegbu in gitlab.com)

dmigwi commented 1 year ago

https://pkg.go.dev/github.com/btcsuite/btcwallet/wallet#RecoveryManager

we have the option to create our own recovery manager to help in address discovery, it would also enable us to keep track of blocks that have been scanned and blocks that haven't been scanned

see if this would help

By Kennedy Izuegbu on 2023-01-13T17:21:51 (imported from GitLab)

(Comment originally authored by: @Kennedy Izuegbu in gitlab.com)

dmigwi commented 1 year ago

I have research it, I believe the recovery function logic is correct, It will start discovery the address from birthday block to the current block, then will set the birthday block to the current block, the problem is when updating the data into the database, it has kept the db locked for a long time

By Justin Do on 2023-01-13T17:21:51 (imported from GitLab)

(Comment originally authored by: @Kennedy Izuegbu in gitlab.com)

dmigwi commented 1 year ago

when recovery mode is enabled at line https://github.com/btcsuite/btcwallet/blob/c314de6995500686c93716037f2279128cc1e9e8/wallet/wallet.go#L668 it will restore all wallet addresses from birthday block and update to the database at the line https://github.com/btcsuite/btcwallet/blob/c314de6995500686c93716037f2279128cc1e9e8/wallet/wallet.go#L761 and bbotldb is locked and only unlocked when the process is complete, so it blocked all other wallet activity and caused a temporary freeze of the app

By Justin Do on 2023-01-13T09:40:01 (imported from GitLab)

(Comment originally authored by: @Kennedy Izuegbu in gitlab.com)

dmigwi commented 1 year ago

I have spent all day looking for a solution to this problem but currently there is no way we can tell if updating the database data in the recovery() function caused the database lock, so the idea is prevent wallet operations from happening during recovery, but I think it's a bad idea because it takes quite a while and the lock period is short

@dreacot @dmigwi @crux25 please go through the reason and let me know if you have any idea how to solve this issue

By Justin Do on 2023-01-13T17:09:07 (imported from GitLab)

(Comment originally authored by: @Kennedy Izuegbu in gitlab.com)

dmigwi commented 1 year ago

this might be difficult to replicate on master once this is merged https://code.cryptopower.dev/group/cryptopower/-/issues/1304

By Kennedy Izuegbu on 2023-03-29T09:21:15 (imported from GitLab)

(Comment originally authored by: @Kennedy Izuegbu in gitlab.com)

dmigwi commented 1 year ago

I have attempted replicate app slow down and haven't succeeded. I then decided to evaluate the code and understand how a block operation could happen. The whole recovery is run in a goroutine thus it can't be failure to use asynchronous processes to startup the app.

2023-03-29 01:36:07.158 [INF] BTC: Current sync progress update is on block 2426001, target sync block is 2426289
2023-03-29 01:36:08.066 [INF] BTC: RECOVERY MODE ENABLED -- rescanning for used addresses with recovery_window=200
2023-03-29 01:36:08.238 [INF] BTC: Seed birthday surpassed, starting recovery of wallet from height=2425219 hash=00000000000005d6451c58a8d709516f1c257a12a38d259f8f5a173d66cb709b with recovery-window=200
2023-03-29 01:36:08.248 [INF] BTC: Scanning 1071 blocks for recoverable addresses
2023-03-29 01:36:12.012 [INF] BTC: Fetching block height=2425703 hash=0000000000000028e446ec8e3813e73f25f4e80519aef4626468b3c7a3201c22
2023-03-29 01:36:12.830 [INF] BTC: Recovered addresses from blocks 2425219-2426289

What seems plausible is db access locking as earlier documented by @justindo below:

https://github.com/btcsuite/btcwallet/blob/c314de6995500686c93716037f2279128cc1e9e8/wallet/wallet.go#L761 and bbotldb is locked and only unlocked when the process is complete, so it blocked all other wallet activity and caused a temporary freeze of the app

from the bbolt db official documentation. Only a single write operation is allowed at a time and read operations also block a write operation. The recovery of scoped addresses happen inside managed write operation. This implies that execution of func (w *Wallet) recoverScopedAddresses( blocks all other write operation triggered asynchronously during the app startup on cryptopower side. This blocked write operations freeze the app.

Solutions

There isn't one wholesome solution, several minor improvements that will progressively improve on the app freeze.

(Comment originally authored by: @Kennedy Izuegbu in gitlab.com)

dmigwi commented 1 year ago

thanks for this detailed explanation, is it feasible to show an overlay/modal that says recovery is in progress for said wallet, the back button would still be active though so they can go to other wallets.

as stated in my original comment,

2023-01-05 10:49:32.838 [INF] BTC: Seed birthday surpassed, starting recovery of wallet from height=761408 hash=00000000000000000006e7f6c1f81641356b9354fba66f2c2ba560aa69e5ba10 with recovery-window=200

the block starts immediately this log appears and ends when the next log is printed, so the modal/overlay might be short lived.

that being said, it's an edge case scenario, so let's further observe it with the enhancements done in https://code.cryptopower.dev/group/cryptopower/-/merge_requests/1232

i'm moving to backlog

By Kennedy Izuegbu on 2023-03-29T14:53:01 (imported from GitLab)

(Comment originally authored by: @Kennedy Izuegbu in gitlab.com)

dmigwi commented 1 year ago

the block starts immediately this log appears and ends when the next log is printed, so the modal/overlay might be short lived.

What happens in between this is; blocks are collected together into a batch of 2,000 blocks or till the best block height is reached. From the code there is no any blocking code when this 2000 block are being pushed into an array.

The blocking is triggered when processing the batch of blocks begins. They are processed in a write operation that prevents further writes or reads operations once acquired. This is where the blocking happens, no other explanation makes sense IMO.

Have you been able to replicate this lately? I think several app improvements pushed lately have improved the situation.

By Migwi Ndung'u on 2023-03-29T15:04:36 (imported from GitLab)

(Comment originally authored by: @Kennedy Izuegbu in gitlab.com)

dmigwi commented 1 year ago

mentioned in issue #1233

By Kennedy Izuegbu on 2023-01-06T14:04:41 (imported from GitLab)

(Comment originally authored by: @Kennedy Izuegbu in gitlab.com)

dmigwi commented 1 year ago

unassigned @justindo

By Kennedy Izuegbu on 2023-03-28T15:00:43 (imported from GitLab)

(Comment originally authored by: @Kennedy Izuegbu in gitlab.com)

dmigwi commented 1 year ago

assigned to @dmigwi

By Kennedy Izuegbu on 2023-03-28T15:01:21 (imported from GitLab)

(Comment originally authored by: @Kennedy Izuegbu in gitlab.com)

dmigwi commented 1 year ago

changed the description

By Kennedy Izuegbu on 2023-01-05T09:54:35 (imported from GitLab)

(Comment originally authored by: @Kennedy Izuegbu in gitlab.com)

dmigwi commented 1 year ago

unassigned @dmigwi

By Migwi Ndung'u on 2023-03-28T17:22:27 (imported from GitLab)

(Comment originally authored by: @Kennedy Izuegbu in gitlab.com)

dmigwi commented 1 year ago

assigned to @justindo

By Justin Do on 2023-01-11T16:36:29 (imported from GitLab)

(Comment originally authored by: @Kennedy Izuegbu in gitlab.com)

dmigwi commented 1 year ago

assigned to @dmigwi

By Kennedy Izuegbu on 2023-03-29T09:20:29 (imported from GitLab)

(Comment originally authored by: @Kennedy Izuegbu in gitlab.com)