romanz / electrs

An efficient re-implementation of Electrum Server in Rust
MIT License
1.02k stars 373 forks source link

Wallets connecting but getting no response #976

Closed ArmanTheParman closed 6 months ago

ArmanTheParman commented 6 months ago

Describe the bug I have included electrs into Parmanode. It installs as standalone or inside a docker container (my custom dockerfile). I have it working fine on a Linux PC. Stuggling today to connect wallets. The index is sync'd. Both sparrow and electrs do not receive a response via tcp or ssl, or tor/tcp. The log file in TRACE mode shows - 3: recv {"jsonrpc":"2.0","method":"server.version","params":["Sparrow","1.4"],"id":1} Then recv: Ping(some long number) Then Pong{exaclty the number above} A new block some more ping and pongs and that's it.

On the wallet side, there is not indication of a successful connection. Electrum has a red circle. Sparrow says "connecting..." There was a moment when I did get a connection, and then i added a tor server, connected fine. Then removed tor. Now I can't get it working again, even if I reinstall tor.

Electrs version 10.1

To Reproduce Steps to reproduce the behavior: Install parmanode on a Pi4 64 bit, 4Mb, Raspbian OS 64 bit. Install electrs docker version from the Parmanode menu. Check electrs log that it's running fine (from parmanode menu -- it runs a docker exec -it electrs bash tail -f custom_file, the file is the recipient of a standard output redirection (>), from the command running electrs executable inside the container. Then try to connect a wallet - fails.

Expected behavior Wallet should connect.

Configuration

nothing special in toml file, no issues connecting to bitcoind. also curl to bitcoind no issues. The port is 127.0.0.1:50005, to avoid conflict to any concurrent fulcrum installation. port 50006 is reserved for SSL, following your nginx stream instructions. ``` type error message here ```

Environment variables: ELECTRS_X=Y;... Arguments: --foo

Electrum client 4.4.4 Additional context Identical code on a Linux desktop PC works fine. The issue is on this raspberry pi, and it has been working previously. I don't think it has anything to do with the installation itself, but possible something in the configuration, or maybe some hardware incompatibility? Maybe it has something to do with the stress on the mempool right now? I tried in bitcoin conf maxmempool=5, but no help.

romanz commented 6 months ago

Thanks for reporting the issue! Would it please be possible to attach the relevant log (with RUST_LOG=electrs=DEBUG verbosity)?

romanz commented 6 months ago

What happens when you send a JSON-RPC request via netcat:

echo '{"jsonrpc": "2.0", "method": "server.version", "params": ["test", "1.4"], "id": 0}' | netcat 127.0.0.1 50005
ArmanTheParman commented 6 months ago

No problem!

This is the log with verbosity set to DEBUG:

[2023-12-18T15:22:18.930Z DEBUG bitcoincore_rpc] JSON-RPC request: getmempoolentry ["a2c0ea277bc5f15401bebd92c292ca0f1231aea4b551a07e8e8e3aa1992ee7b2"]
[2023-12-18T15:22:18.935Z DEBUG bitcoincore_rpc] JSON-RPC request: getmempoolentry ["8b9a85d8dae4944370cae1a9753766925f69c008bda44b4d4574cdc12c01f15b"]
[2023-12-18T15:22:18.937Z DEBUG bitcoincore_rpc] JSON-RPC request: getmempoolentry ["264067ce1a28130a408761b1367501efdb1823d47d07f3f5f720ebf383b7f41e"]
[2023-12-18T15:22:18.939Z DEBUG bitcoincore_rpc] JSON-RPC request: getmempoolentry ["0684f1e24672cf7bbb40796b4a9038f5da86e18f1e422908e0154837a2a91859"]
[2023-12-18T15:22:20.945Z DEBUG electrs::mempool] 66643 mempool txs: 66643 added, 0 removed
[2023-12-18T15:22:30.946Z DEBUG electrs::p2p] got 1 new headers
[2023-12-18T15:22:30.946Z INFO  electrs::index] indexing 1 blocks: [821787..821787]
[2023-12-18T15:22:30.946Z DEBUG electrs::p2p] loading 1 blocks
[2023-12-18T15:22:31.011Z DEBUG electrs::index] writing 9424 funding and 6763 spending rows from 4569 transactions, 1 blocks
[2023-12-18T15:22:31.043Z INFO  electrs::chain] chain updated: tip=00000000000000000003e2fbf78642faa225ec9e6d4306fab95aa7ef7121ae24, height=821787
[2023-12-18T15:22:31.045Z DEBUG electrs::p2p] got 0 new headers
[2023-12-18T15:22:31.045Z DEBUG electrs::db] flushing DB column families
[2023-12-18T15:22:31.379Z INFO  electrs::db] starting config compaction
[2023-12-18T15:22:31.455Z INFO  electrs::db] starting headers compaction
[2023-12-18T15:22:37.250Z INFO  electrs::db] starting txid compaction
[2023-12-18T15:23:22.479Z DEBUG electrs::server] 0: recv {"jsonrpc": "2.0", "method": "server.version", "params": ["test", "1.4"], "id": 0}
[2023-12-18T15:23:31.766Z DEBUG electrs::server] 0: disconnected
[2023-12-18T15:28:00.348Z DEBUG electrs::server] 1: recv {"jsonrpc":"2.0","method":"server.version","id":0,"params":["electrum/4.4.4","1.4"]}
[2023-12-18T15:28:26.097Z DEBUG electrs::p2p] peer inventory: [Block(0x00000000000000000000bccee0d9e168a887cb8736e38b7fd1f303b6ab17a204)]
[2023-12-18T15:28:26.931Z DEBUG electrs::server] 2: recv {"jsonrpc": "2.0", "method": "server.version", "params": ["test", "1.4"], "id": 0}

the netcat pipe command does not give the prompt back, as though it's stuck waiting for electrs to reply. You can see in the debug log that the message was receieved, but no response given.

ArmanTheParman commented 6 months ago

If there's anything else i can do to assist with debugging, let me know.

romanz commented 6 months ago

From the logs, it seems that electrs has started full DB compaction, which is expected to take quite a while. Could you please let it run for a few hours and see how if the RPC becomes responsive after the compaction is over?

ArmanTheParman commented 6 months ago

Sure, I'll start it up now. What is compaction for and do I need it, and is it optional? I've never noticed it before, but must admit, never looked closely. It'll be good if I can read some details about it, especially if it affects rpc connections, and then I can inform the user in my software.

ArmanTheParman commented 6 months ago

I'm pleased to report that waiting for DB compaction worked, and both Electrum and Sparrow can connect to electrs! Any electrs resources I can read about db compaction?

romanz commented 6 months ago

RocksDB (which is used for storing and querying electrs' index) is using compaction for maintaining its LSM storage. In order to allow fast initial sync, electrs disable compaction during the first time it runs (and syncs the whole blockchain), but after the sync is over, it does a full compaction of the DB to allow fast index lookups. Usually it takes at least an hour to perform this step, during which the RPC server is expected to be unresponsive.

romanz commented 6 months ago

@ArmanTheParman just from curiousity, how much time did the compaction take?

ArmanTheParman commented 6 months ago

It's hard to know, I left if on overnight.

On Sat, 23 Dec 2023, 12:57 am Roman Zeyde, @.***> wrote:

@ArmanTheParman https://github.com/ArmanTheParman just from curiousity, how much time did the compaction take?

— Reply to this email directly, view it on GitHub https://github.com/romanz/electrs/issues/976#issuecomment-1867718579, or unsubscribe https://github.com/notifications/unsubscribe-auth/ASQCCX32RRUBLADV63LDLPTYKWGWJAVCNFSM6AAAAABAYMHM2GVHI2DSMVQWIX3LMV43OSLTON2WKQ3PNVWWK3TUHMYTQNRXG4YTQNJXHE . You are receiving this because you were mentioned.Message ID: @.***>

romanz commented 6 months ago

Could you please take a look at the logs?

It should be the duration between starting config compaction and finished full compaction messages.

ArmanTheParman commented 6 months ago

3:24 starting config compaction 3:24 starting headers compaction 3:25 starting txID compaction 3:53 starting funding compaction 4:57 starting spending compaction 6:53 finished full compaction

romanz commented 6 months ago

:+1: