search

sparrowwallet / sparrow

Desktop Bitcoin Wallet focused on security and privacy. Free and open source.
https://sparrowwallet.com/
Apache License 2.0
1.34k stars 190 forks source link

RPC connection to Bitcoin Core gets bad syncing info #342

Open steliosrammos opened 2 years ago

steliosrammos commented 2 years ago

When testing the connection to my own node the logs show the following output:

Connecting to Bitcoin Core node at http://192.168.0.103:8332...
The connection to the Bitcoin Core node was successful, but it is still syncing and cannot be used yet.
Currently 99% completed to date 2021/12/06 00:20

If I attempt to actually connect to it, it will restart the bitcoin daemon and start the syncing again from where Sparrow thought it left off. If I attempt again it repeats that behaviour even if the node has fully synced in the meantime. Eventually Sparrow will fail connecting to the node.

craigraw commented 2 years ago

If I attempt to actually connect to it, it will restart the bitcoin daemon

This is surprising. @shesek any thoughts here?

shesek commented 2 years ago

What does 'attempt to actually connect' mean exactly?

There's nothing in BWT that would restart the node. Can you show the Bitcoin Core logs around where it gets restarted?

Also, there's nothing that remembers how far re-syncing succeeded to continue from there following a restart. It considers every address that was previously imported as fully synced, so it will either rescan since the rescan_since parameter or not rescan at all. (If Bitcoin Core shuts down while rescanning, BWT won't be able to tell that it happened and won't resume the sync, unless the force_rescan option is enabled.)

steliosrammos commented 2 years ago

The phrasing was a little ambiguous. It all happens after clicking the Test Connection in the settings.

Here are the logs after clicking Test Connection:

2021-12-07T13:44:59Z UpdateTip: new best=00000000000000000006bf92c8f8cf45266190e4541f18572db711eaf884d74c height=713038 version=0x20400000 log2_work=93.215331 tx=693040264 date='2021-12-07T13:44:14Z' progress=1.000000 cache=64.4MiB(534677txo)
2021-12-07T13:47:49Z Socks5() connect to tbx6gmzydn2mgm3syotpzikzimu3e2jbuxwbgoalye6r3fpqsxiv2rad.onion:8333 failed: host unreachable
2021-12-07T13:48:42Z Socks5() connect to 105.213.82.15:8333 failed: connection refused
2021-12-07T13:49:41Z Socks5() connect to 2804:14d:7e26:90e0:1c7c:33ca:898e:2b5f:8333 failed: general failure
2021-12-07T13:56:07Z UpdateTip: new best=00000000000000000003d4bc1a82942d0adee59f40b8f2a61ccd969663984782 height=713039 version=0x20008000 log2_work=93.215343 tx=693043824 date='2021-12-07T13:55:31Z' progress=1.000000 cache=65.5MiB(544380txo)
2021-12-07T13:57:25Z Using BerkeleyDB version Berkeley DB 4.8.30: (April  9, 2010)
2021-12-07T13:57:25Z Using wallet /home/stelios/.bitcoin/sparrow/wallet.dat
2021-12-07T13:57:25Z BerkeleyEnvironment::Open: LogDir=/home/stelios/.bitcoin/sparrow/database ErrorFile=/home/stelios/.bitcoin/sparrow/db.log

2021-12-07T13:57:26Z Bitcoin Core version v0.21.1 (release build)
2021-12-07T13:57:26Z InitParameterInteraction: parameter interaction: -proxy set -> setting -upnp=0
2021-12-07T13:57:26Z InitParameterInteraction: parameter interaction: -proxy set -> setting -discover=0
2021-12-07T13:57:26Z Assuming ancestors of block 0000000000000000000b9d2ec5a352ecba0592946514a92f14319dc2b367fc72 have valid signatures.
2021-12-07T13:57:26Z Setting nMinimumChainWork=00000000000000000000000000000000000000001533efd8d716a517fe2c5008
2021-12-07T13:57:26Z Using the 'standard' SHA256 implementation
2021-12-07T13:57:26Z Default data directory /.bitcoin
2021-12-07T13:57:26Z Using data directory /home/stelios/.bitcoin
2021-12-07T13:57:26Z Config file: /home/stelios/.bitcoin/bitcoin.conf
2021-12-07T13:57:26Z Config file arg: bind="127.0.0.1"
2021-12-07T13:57:26Z Config file arg: blockfilterindex="1"
2021-12-07T13:57:26Z Config file arg: dbcache="2048"
2021-12-07T13:57:26Z Config file arg: listen="1"
2021-12-07T13:57:26Z Config file arg: proxy="127.0.0.1:9050"
2021-12-07T13:57:26Z Config file arg: rpcallowip="192.168.0.0/24"
2021-12-07T13:57:26Z Config file arg: rpcallowip="************"
2021-12-07T13:57:26Z Config file arg: rpcbind=****
2021-12-07T13:57:26Z Config file arg: rpcbind=****
2021-12-07T13:57:26Z Config file arg: rpcpassword=****
2021-12-07T13:57:26Z Config file arg: rpcport="8332"
2021-12-07T13:57:26Z Config file arg: rpcuser=****
2021-12-07T13:57:26Z Config file arg: server="1"
2021-12-07T13:57:26Z Config file arg: txindex="1"
2021-12-07T13:57:26Z Config file arg: zmqpubrawblock="tcp://127.0.0.1:28332"
2021-12-07T13:57:26Z Config file arg: zmqpubrawtx="tcp://127.0.0.1:28333"
2021-12-07T13:57:26Z Command-line arg: datadir="/home/stelios/.bitcoin"
2021-12-07T13:57:26Z Using at most 125 automatic connections (1024 file descriptors available)
2021-12-07T13:57:26Z Using 16 MiB out of 32/2 requested for signature cache, able to store 524288 elements
2021-12-07T13:57:26Z Using 16 MiB out of 32/2 requested for script execution cache, able to store 524288 elements
2021-12-07T13:57:26Z Script verification uses 3 additional threads
2021-12-07T13:57:26Z scheduler thread start
2021-12-07T13:57:26Z HTTP: creating work queue of depth 16
2021-12-07T13:57:26Z Config options rpcuser and rpcpassword will soon be deprecated. Locally-run instances may remove rpcuser to use cookie-based auth, or may be replaced with rpcauth. Please see share/rpcauth for rpcauth auth generation.
2021-12-07T13:57:26Z HTTP: starting 4 worker threads
2021-12-07T13:57:26Z Using wallet directory /home/stelios/.bitcoin
2021-12-07T13:57:26Z init message: Verifying wallet(s)...
2021-12-07T13:57:26Z init message: Loading banlist...
2021-12-07T13:57:26Z SetNetworkActive: true
2021-12-07T13:57:26Z Using /16 prefix for IP bucketing
2021-12-07T13:57:26Z Cache configuration:
2021-12-07T13:57:26Z * Using 2.0 MiB for block index database
2021-12-07T13:57:26Z * Using 127.8 MiB for transaction index database
2021-12-07T13:57:26Z * Using 111.8 MiB for basic block filter index database
2021-12-07T13:57:26Z * Using 8.0 MiB for chain state database
2021-12-07T13:57:26Z * Using 774.5 MiB for in-memory UTXO set (plus up to 286.1 MiB of unused mempool space)
2021-12-07T13:57:26Z init message: Loading block index...
2021-12-07T13:57:26Z Switching active chainstate to Chainstate [ibd] @ height -1 (null)
2021-12-07T13:57:26Z Opening LevelDB in /home/stelios/.bitcoin/blocks/index
2021-12-07T13:57:26Z Opened LevelDB successfully
2021-12-07T13:57:26Z Using obfuscation key for /home/stelios/.bitcoin/blocks/index: 0000000000000000
2021-12-07T13:57:39Z LoadBlockIndexDB: last block file = 2835
2021-12-07T13:57:39Z LoadBlockIndexDB: last block file info: CBlockFileInfo(blocks=14, size=15520009, heights=713023...713036, time=2021-12-07...2021-12-07)
2021-12-07T13:57:39Z Checking all blk files are present...
2021-12-07T13:57:40Z Opening LevelDB in /home/stelios/.bitcoin/chainstate
2021-12-07T13:57:42Z Opened LevelDB successfully
2021-12-07T13:57:42Z Using obfuscation key for /home/stelios/.bitcoin/chainstate: 755412512e017e20
2021-12-07T13:57:42Z Loaded best chain: hashBestChain=0000000000000000000175b46eab85d7e83248a80b1d6ca04e6215e97ef30858 height=712963 date=2021-12-06T23:59:13Z progress=0.999745
2021-12-07T13:57:42Z init message: Rewinding blocks...
2021-12-07T13:57:43Z FlushStateToDisk: write coins cache to disk (0 coins, 0kB) started
2021-12-07T13:57:43Z FlushStateToDisk: write coins cache to disk (0 coins, 0kB) completed (0.00s)
2021-12-07T13:57:43Z init message: Verifying blocks...
2021-12-07T13:57:43Z Verifying last 6 blocks at level 3
2021-12-07T13:57:43Z [0%]...[16%]...[33%]...[50%]...[66%]...[83%]...[99%]...[DONE].
2021-12-07T13:57:59Z No coin database inconsistencies in last 6 blocks (11730 transactions)
2021-12-07T13:57:59Z  block index           33187ms
2021-12-07T13:57:59Z Opening LevelDB in /home/stelios/.bitcoin/indexes/txindex
2021-12-07T13:58:03Z Opened LevelDB successfully
2021-12-07T13:58:03Z Using obfuscation key for /home/stelios/.bitcoin/indexes/txindex: 0000000000000000
2021-12-07T13:58:03Z txindex thread start
2021-12-07T13:58:03Z txindex is enabled at height 712963
2021-12-07T13:58:03Z txindex thread exit
2021-12-07T13:58:03Z Opening LevelDB in /home/stelios/.bitcoin/indexes/blockfilter/basic/db
2021-12-07T13:58:03Z Opened LevelDB successfully
2021-12-07T13:58:03Z Using obfuscation key for /home/stelios/.bitcoin/indexes/blockfilter/basic/db: 0000000000000000
2021-12-07T13:58:03Z basic block filter index thread start
2021-12-07T13:58:03Z loadblk thread start
2021-12-07T13:58:03Z block tree size = 713039
2021-12-07T13:58:03Z nBestHeight = 712963
2021-12-07T13:58:03Z basic block filter index is enabled at height 712963
2021-12-07T13:58:03Z basic block filter index thread exit
2021-12-07T13:58:03Z torcontrol thread start
2021-12-07T13:58:03Z Bound to 127.0.0.1:8333
2021-12-07T13:58:03Z Bound to 127.0.0.1:8334
2021-12-07T13:58:03Z init message: Loading P2P addresses...
2021-12-07T13:58:03Z tor: Got service ID o62v62qytdydsrvpdr6ladvx6a4fzxr4uightqjsok5p7zjzmqtqx6ad, advertising service o62v62qytdydsrvpdr6ladvx6a4fzxr4uightqjsok5p7zjzmqtqx6ad.onion:8333
2021-12-07T13:58:03Z AddLocal(o62v62qytdydsrvpdr6ladvx6a4fzxr4uightqjsok5p7zjzmqtqx6ad.onion:8333,4)
2021-12-07T13:58:04Z Loaded 66554 addresses from peers.dat  1001ms
2021-12-07T13:58:04Z ERROR: DeserializeFileDB: Failed to open file /home/stelios/.bitcoin/anchors.dat
2021-12-07T13:58:04Z 0 block-relay-only anchors will be tried for connections.
2021-12-07T13:58:04Z init message: Starting network threads...
2021-12-07T13:58:04Z net thread start
2021-12-07T13:58:04Z dnsseed thread start
2021-12-07T13:58:04Z init message: Done loading
2021-12-07T13:58:04Z Waiting 300 seconds before querying DNS seeds.
2021-12-07T13:58:04Z addcon thread start
2021-12-07T13:58:04Z opencon thread start
2021-12-07T13:58:04Z msghand thread start
2021-12-07T13:58:07Z UpdateTip: new best=00000000000000000005af8cddb0e21716a8f33f831ef3497a0a8777dbfeb270 height=712964 version=0x20c00000 log2_work=93.214440 tx=692898231 date='2021-12-07T00:41:25Z' progress=0.999758 cache=1.8MiB(15987txo)
2021-12-07T13:58:10Z UpdateTip: new best=000000000000000000076b7ffd29596a73991ceeeb3fe19dfcf20d727f064e2f height=712965 version=0x27ffe004 log2_work=93.214452 tx=692901134 date='2021-12-07T00:46:28Z' progress=0.999759 cache=3.7MiB(32626txo)

After looking at those more closely, the block height rollback is most likely because Bitcoin Core shuts down abruptly and cannot flush the last blocks from the cache to the disk. But Bitcoin Core should not shut down because of Sparrow trying to establish an RPC connection.

Sparrow error for this test: 

Could not connect:

Check if Bitcoin Core is running, and the authentication details are correct.

See https://sparrowwallet.com/docs/connect-node.html

The authentication details are correct.

Some more info that could be relevant: I am running Bitcoin Core on a Rpi4 in the same network. Also worth noting, the /home/stelios/.bitcoin/sparrow/database directory is empty on the RPi4 and there is no /home/stelios/.bitcoin/sparrow/db.log file. So I guess Bitcoin Core crashing is related to that. Hope this helps!