Synchronization appears to be stuck

[mrzool]

Expected Behavior

The synchronization progress indicator should advance.

Current Behavior

The synchronization progress indicator has been stuck for over 16 hours at 60.98%. Quitting and starting the app again doesn't help.

Steps to Reproduce

I just open the app and look at the indicator in the top right corner.

Context (Environment)

I'm on an M1 MacBook running Big Sur 11.6.2.

Logs

bob-debug-main.txt

Screencap

[rithvikvibhu]

Hey @mrzool did it ever progress > 61%?

[mrzool]

I let it run for a couple of more days, then gave up. Didn't look like it would ever get unstuck. I also uninstalled the wallet after realizing it took over 9GB of storage space on my MacBook — not sure how that came to be. I'm just glad I didn't send my coins to it.

[rithvikvibhu]

Bob Wallet runs a full node that downloads the entire blockchain, which it > 13 GB right now. (It also has SPV mode that only downloads block headers and takes only a few MB of storage - fyi if you want to give it a try anytime)

Btw, have you tried the chrome extension? It's similar to how MetaMask works, syncs almost instantly, and doesn't download the whole blockchain.
https://bobwallet.io

[mrzool]

Btw, have you tried the chrome extension? It's similar to how MetaMask works, syncs almost instantly, and doesn't download the whole blockchain.

That sounds more reasonable... I'll give it a try, thanks for the tip.

[rithvikvibhu]

Going through the logs again and this part sticks out (trimmed a few unrelated lines):

[D:2022-01-23T15:45:46Z] (wallet) Adding block: 63898.
[D:2022-01-23T15:45:46Z] (node-http) Request for method=GET path=/ (127.0.0.1).
[D:2022-01-23T15:45:46Z] (chain) Memory: rss=1916mb, js-heap=49/69mb native-heap=1846mb
[I:2022-01-23T15:45:46Z] (chain) Block 00000000000000001aec04d20afd9c8302c973f46e79c62d69ad0dfb053fd7b2 (63898) added to chain (size=129087 txs=72 time=337.386666).
[D:2022-01-23T15:45:46Z] (chain) Retargetting to: 00000000000000041ad000000000000000000000000000000000000000000000 (0x19041ad0).
[D:2022-01-23T15:45:46Z] (wallet) Adding block: 63899.
[D:2022-01-23T15:45:46Z] (node-http) Request for method=GET path=/ (127.0.0.1).
[D:2022-01-23T15:45:46Z] (chain) Memory: rss=1942mb, js-heap=48/69mb native-heap=1872mb
[I:2022-01-23T15:45:46Z] (chain) Block 0000000000000000f77ac4743f99f5786ef90fdf7bf67a9b134e9ebdad048bfd (63899) added to chain (size=45851 txs=58 time=116.5195).
[D:2022-01-23T15:45:46Z] (chain) Retargetting to: 00000000000000041e8100000000000000000000000000000000000000000000 (0x19041e81).

[restart Bob I guess]

[I:2022-01-23T21:21:58Z] (blockstore) Opening FileBlockStore...
[I:2022-01-23T21:21:58Z] (chain) Chain is loading.
[I:2022-01-23T21:21:58Z] (chain) Checkpoints are enabled.
[I:2022-01-23T21:21:58Z] (chaindb) Opening ChainDB...
[D:2022-01-23T21:21:58Z] (chain-migrations) There are no migrations pending. last id: 2
[D:2022-01-23T21:21:58Z] (chain-migrations) Last migration 2, last available migration: 2
[I:2022-01-23T21:21:58Z] (chain-migrations) There are 0 migrations.
[I:2022-01-23T21:21:58Z] (chaindb) ChainDB successfully loaded.
[I:2022-01-23T21:21:58Z] (chaindb) Chain State: hash=000000000000000134f2cea1fff0b95bd0896087bc38da2f0c42c2bfa6892b22 tx=3744994 coin=2506178 value=373874337.947004 burned=21046347.96623.
[I:2022-01-23T21:21:58Z] (chaindb) Tree Root: 14d0499262bd6b7b335229edcec890c17ee835f82c6e2dac799d70f4b3ddc2f5.
[I:2022-01-23T21:21:58Z] (chain) Chain Height: 63900
[D:2022-01-23T21:21:58Z] (chain) Memory: rss=646mb, js-heap=16/32mb native-heap=614mb
[I:2022-01-23T21:21:58Z] (chain) Synchronized Tree Root: 14d0499262bd6b7b335229edcec890c17ee835f82c6e2dac799d70f4b3ddc2f5.
[D:2022-01-23T21:21:58Z] (chain) Memory: rss=647mb, js-heap=16/32mb native-heap=615mb
[I:2022-01-23T21:21:58Z] (mempool) Mempool loaded (maxsize=97656.25kb).
[I:2022-01-23T21:21:58Z] (miner) Miner loaded (flags=mined by hsd).
[W:2022-01-23T21:21:58Z] (miner) No reward address is set for miner!
[I:2022-01-23T21:21:58Z] (net) Pool loaded (maxpeers=4).
[I:2022-01-23T21:21:58Z] (net) Pool identity key: anhlcpbkvyb2tvbits2rec7pykdwdlfxsz6k4zl3o5lq2avvdot5y.
[I:2022-01-23T21:21:58Z] (wallet) Opening WalletDB...
[D:2022-01-23T21:21:58Z] (wallet-migrations) There are no migrations pending. last id: 1
[D:2022-01-23T21:21:58Z] (wallet-migrations) Last migration 1, last available migration: 1
[I:2022-01-23T21:21:58Z] (wallet-migrations) There are 0 migrations.
[I:2022-01-23T21:21:58Z] (wallet) Added 804 hashes to WalletDB filter.
[I:2022-01-23T21:21:58Z] (wallet) Added 0 outpoints to WalletDB filter.
[I:2022-01-23T21:21:58Z] (wallet) Added 0 names to WalletDB filter.
[I:2022-01-23T21:21:58Z] (wallet) WalletDB loaded (depth=2, height=0, start=0).
[I:2022-01-23T21:21:58Z] (wallet) Resyncing from server...
[I:2022-01-23T21:21:58Z] (wallet) Sending filter to server (5.1418256759643555mb).
[I:2022-01-23T21:21:58Z] (wallet) Syncing state from height 63899.
[I:2022-01-23T21:21:58Z] (wallet) Rolled back to same height (63899).
[I:2022-01-23T21:21:58Z] (wallet) WalletDB is scanning 1 blocks.
[I:2022-01-23T21:21:58Z] (chaindb) Scanning from block 0000000000000000f77ac4743f99f5786ef90fdf7bf67a9b134e9ebdad048bfd.
[I:2022-01-23T21:21:58Z] (wallet) Wallet opened (primary).
[I:2022-01-23T21:21:58Z] (wallet) Loaded primary wallet (id=primary, wid=0, address=hs1...)
[I:2022-01-23T21:21:58Z] (wallet-http) Wallet HTTP server listening on 127.0.0.1 (port=12039).
[I:2022-01-23T21:21:58Z] (node-http) Node HTTP server listening on 127.0.0.1 (port=12037).
[W:2022-01-23T21:21:58Z] (node) Warning: worker pool is disabled.
[W:2022-01-23T21:21:58Z] (node) Verification will be slow.
[I:2022-01-23T21:21:58Z] (node) Node is loaded.
[I:2022-01-23T21:21:58Z] (chaindb) Scanning block 0000000000000000f77ac4743f99f5786ef90fdf7bf67a9b134e9ebdad048bfd (63899).
[D:2022-01-23T21:21:58Z] (wallet) Adding block: 63899.
[W:2022-01-23T21:21:58Z] (wallet) Already saw WalletDB block (63899).
[E:2022-01-23T21:21:58Z] (node) Block not found.
    at ChainDB.scan (/Applications/Bob.app/Contents/Resources/app.asar/node_modules/hsd/lib/blockchain/chaindb.js:1489:17)
    at async Chain.scan (/Applications/Bob.app/Contents/Resources/app.asar/node_modules/hsd/lib/blockchain/chain.js:2055:14)
    at async WalletDB.scan (/Applications/Bob.app/Contents/Resources/app.asar/node_modules/hsd/lib/wallet/walletdb.js:509:7)
    at async WalletDB.syncNode (/Applications/Bob.app/Contents/Resources/app.asar/node_modules/hsd/lib/wallet/walletdb.js:408:7)
    at async /Applications/Bob.app/Contents/Resources/app.asar/node_modules/hsd/lib/wallet/walletdb.js:126:9

And then it gives up syncing.

@pinheadmz maybe block 63899 was not saved in FileBlockStore when Bob closed?

[pinheadmz]

Wow that's bad! Possibly fixed by handshake-org/hsd#650 I wonder if this user had a full-disk crash as that block was being added? We may need to examine the atomicity when saving ChainEntries and Blocks - looks like somehow this chainDB expects a block to have been saved.

[rithvikvibhu]

Fixed in #521, tested by ~4 people, and will be part of the next release.