electrs: Bug: electrs terminates with "Address already in use (os error 98)"

Describe the bug After upgrade to electrs 0.9.0 (from 0.8.6), the database migration is successful. But electrs terminates regularly (around 2 minutes after restart), after utilizing 100% CPU, with error messages: Address already in use (os error 98) or JSON-RPC error: transport error: Couldn't connect to host: Cannot assign requested address (os error 99)

Electrs version 0.9.0

Configuration

# Bitcoin Core settings
network = "bitcoin"
daemon_dir= "/var/lib/bitcoin"
daemon_rpc_addr = "127.0.0.1:8332"

# Electrs settings
electrum_rpc_addr = "127.0.0.1:50001"
db_dir = "/var/lib/electrs/db"
index_lookup_limit = 1000

# Logging
verbose = 2
timestamp = true
rust_backtrace = true

Error log

Oct 07 17:58:33 nuc systemd[1]: Started Electrs daemon.
Oct 07 17:58:33 nuc electrs[7361]: Config { network: Bitcoin, db_path: "/var/lib/electrs/db/bitcoin", daemon_dir: "/var/lib/bitcoin", daemon_auth: UserPass("sensitive", "<sensitive>"), daemon_rpc_addr: V4(127.0.0.1:8332), daemon_p2p_addr: V4(127.0.0.1:8333), electrum_rpc_addr: V4(127.0.0.1:50001), monitoring_addr: V4(127.0.0.1:4224), wait_duration: 10s, jsonrpc_timeout: 15s, index_batch_size: 10, index_lookup_limit: Some(1000), auto_reindex: true, ignore_mempool: false, sync_once: false, server_banner: "Welcome to electrs 0.9.0 (Electrum Rust Server)!", args: [] }
Oct 07 17:58:33 nuc electrs[7361]: [2021-10-07T15:58:33.748Z INFO  electrs::db] "/var/lib/electrs/db/bitcoin": 132 SST files, 31.88136245 GB, 3.971850754 Grows
Oct 07 17:58:37 nuc electrs[7361]: [2021-10-07T15:58:37.183Z INFO  electrs::chain] loading 703965 headers, tip=000000000000000000086d6c9d2a042e8a6a8b0a64aec0aafd2b331428a1c2f7
Oct 07 17:58:40 nuc electrs[7361]: [2021-10-07T15:58:40.738Z INFO  electrs::chain] chain updated: tip=000000000000000000086d6c9d2a042e8a6a8b0a64aec0aafd2b331428a1c2f7, height=703965
Oct 07 17:58:40 nuc electrs[7361]: [2021-10-07T15:58:40.804Z INFO  electrs::index] indexing 6 blocks: [703966..703971]
Oct 07 17:58:41 nuc electrs[7361]: [2021-10-07T15:58:41.172Z INFO  electrs::chain] chain updated: tip=00000000000000000007549cac7664af5f2185862738e08805d1b440a0567181, height=703971
Oct 07 17:59:45 nuc electrs[7361]: [2021-10-07T15:59:45.539Z INFO  electrs::db] closing DB at /var/lib/electrs/db/bitcoin
Oct 07 17:59:45 nuc electrs[7361]: Error: server failed
Oct 07 17:59:45 nuc electrs[7361]: Caused by:
Oct 07 17:59:45 nuc electrs[7361]:     Address already in use (os error 98)
Oct 07 17:59:45 nuc systemd[1]: electrs.service: Main process exited, code=exited, status=1/FAILURE
Oct 07 17:59:45 nuc systemd[1]: electrs.service: Failed with result 'exit-code'.

and sometimes

Oct 07 17:20:41 nuc electrs[8135]: Error: daemon not available
Oct 07 17:20:41 nuc electrs[8135]: Caused by:
Oct 07 17:20:41 nuc electrs[8135]:     JSON-RPC error: transport error: Couldn't connect to host: Cannot assign requested address (os error 99)
Oct 07 17:20:41 nuc systemd[1]: electrs.service: Main process exited, code=exited, status=1/FAILURE
Oct 07 17:20:41 nuc systemd[1]: electrs.service: Failed with result 'exit-code'.

System running electrs Deployment method: manual Operating System: Ubuntu 18.04.6 LTS Kernel: Linux 4.15.0-159-generic Architecture: x86-64

About this issue

Original URL
State: open
Created 3 years ago
Comments: 17 (11 by maintainers)

Commits related to this issue

Don't connect twice to bitcoind It was added when JSON RPC was using a persistent connection, disconnecting after full compaction (which took a while). Now, p2p handling is running in a separate thr... — committed to romanz/electrs by romanz 3 years ago

Most upvoted comments

Could you run lsof -i :50001 under root to check if it’s actually electrs trying to bind multiple times?

Kixunil on Oct 7, 2021

I lowered index_lookup_limit to 100 for now (not sure if that could help?)

It is used to prevent loading “too popular addresses” (having more than index_lookup_limit funding transactions), e.g. https://blockstream.info/address/1CK6KHY6MHgYvmRQ4PAafKYDrg1ejbH1cE.

romanz on Oct 8, 2021

It seems to come from here: https://github.com/rust-bitcoin/rust-bitcoincore-rpc/blob/27d354338e8da01b2f79e7e34eb42732859ebe7b/client/src/client.rs#L1151

Could you please see if electrs works with --ignore-mempool? It should result in much less RPCs to bitcoind.

romanz on Oct 7, 2021

Thanks for responding so fast! That’s a very long log, but I’ll break it down. First a whole lot of this:

Oct 07 20:42:28 nuc electrs[9103]: [2021-10-07T18:42:28.186Z DEBUG bitcoincore_rpc::client] JSON-RPC request: getmempoolentry ["1ba8cb5f2703efceea50cfa1afd24820866cdbc719e8272de5cb99b68d8a3ed4"]
Oct 07 20:42:28 nuc electrs[9103]: [2021-10-07T18:42:28.187Z DEBUG bitcoincore_rpc::client] JSON-RPC request: getmempoolentry ["ca3583c1a4ce1234e436c4cd986b7145412970ccea788570cd34233033168c9e"]
Oct 07 20:42:28 nuc electrs[9103]: [2021-10-07T18:42:28.189Z DEBUG bitcoincore_rpc::client] JSON-RPC request: getmempoolentry ["7a2bff1398054e7da388fd6aad816d3a6820088d5bef8c8f15d07c91af0b349d"]
Oct 07 20:42:28 nuc electrs[9103]: [2021-10-07T18:42:28.190Z DEBUG bitcoincore_rpc::client] JSON-RPC request: getmempoolentry ["f61085f5bc5d4d3a382a44bd60865d586cbb9912ed3bbec3ac5f1af782dd3146"]
Oct 07 20:42:28 nuc electrs[9103]: [2021-10-07T18:42:28.194Z DEBUG bitcoincore_rpc::client] JSON-RPC request: getrawtransaction ["d94ed837cf0eb4e9e854661b46df64af654052464c2767e3160ab4ca70804a94",false]
Oct 07 20:42:28 nuc electrs[9103]: [2021-10-07T18:42:28.196Z DEBUG bitcoincore_rpc::client] JSON-RPC request: getrawtransaction ["686d3d1ff17b610bf112ff46e0b4f338a0be308b890ce6a6758cda78f1e03ea3",false]
Oct 07 20:42:28 nuc electrs[9103]: [2021-10-07T18:42:28.196Z DEBUG bitcoincore_rpc::client] JSON-RPC request: getrawtransaction ["ffce1d6188c1ebbab7d9acff692d4e590393d53f5ddf380028511e82dccc6206",false]
Oct 07 20:42:28 nuc electrs[9103]: [2021-10-07T18:42:28.200Z DEBUG bitcoincore_rpc::client] JSON-RPC request: getrawtransaction ["905fa25df1d76e31b8dfbc4c7562a77430bb030f6ae9b0a4f64f0d62d927b4ae",false]
Oct 07 20:42:28 nuc electrs[9103]: [2021-10-07T18:42:28.201Z DEBUG bitcoincore_rpc::client] JSON-RPC request: getmempoolentry ["d94ed837cf0eb4e9e854661b46df64af654052464c2767e3160ab4ca70804a94"]
Oct 07 20:42:28 nuc electrs[9103]: [2021-10-07T18:42:28.203Z DEBUG bitcoincore_rpc::client] JSON-RPC request: getmempoolentry ["686d3d1ff17b610bf112ff46e0b4f338a0be308b890ce6a6758cda78f1e03ea3"]
Oct 07 20:42:28 nuc electrs[9103]: [2021-10-07T18:42:28.207Z DEBUG bitcoincore_rpc::client] JSON-RPC request: getmempoolentry ["905fa25df1d76e31b8dfbc4c7562a77430bb030f6ae9b0a4f64f0d62d927b4ae"]
Oct 07 20:42:28 nuc electrs[9103]: [2021-10-07T18:42:28.208Z DEBUG bitcoincore_rpc::client] JSON-RPC request: getmempoolentry ["ffce1d6188c1ebbab7d9acff692d4e590393d53f5ddf380028511e82dccc6206"]
Oct 07 20:42:28 nuc electrs[9103]: [2021-10-07T18:42:28.211Z DEBUG bitcoincore_rpc::client] JSON-RPC request: getrawtransaction ["551263f171860ccf136d0fa8af62b5904fabc232a5947f7d69af587f264e7304",false]
Oct 07 20:42:28 nuc electrs[9103]: [2021-10-07T18:42:28.214Z DEBUG bitcoincore_rpc::client] JSON-RPC request: getrawtransaction ["28812c751286e0bf0af67597a8735f7df22d5c14aa9d8a4e15d0a563ca08e96e",false]
Oct 07 20:42:28 nuc electrs[9103]: [2021-10-07T18:42:28.216Z DEBUG bitcoincore_rpc::client] JSON-RPC request: getrawtransaction ["7266e71d70ce3de4f055a869f708d4e55157ea359db1096c19eb6002cfea3db6",false]
Oct 07 20:42:28 nuc electrs[9103]: [2021-10-07T18:42:28.216Z DEBUG bitcoincore_rpc::client] JSON-RPC request: getrawtransaction ["5d79d4c0f40410141eca2e7e63a5d504367d14d0ef324afd12bb70b5afa6370d",false]
Oct 07 20:42:28 nuc electrs[9103]: [2021-10-07T18:42:28.218Z DEBUG bitcoincore_rpc::client] JSON-RPC request: getmempoolentry ["551263f171860ccf136d0fa8af62b5904fabc232a5947f7d69af587f264e7304"]
Oct 07 20:42:28 nuc electrs[9103]: [2021-10-07T18:42:28.221Z DEBUG bitcoincore_rpc::client] JSON-RPC request: getmempoolentry ["28812c751286e0bf0af67597a8735f7df22d5c14aa9d8a4e15d0a563ca08e96e"]
Oct 07 20:42:28 nuc electrs[9103]: [2021-10-07T18:42:28.224Z DEBUG bitcoincore_rpc::client] JSON-RPC request: getmempoolentry ["7266e71d70ce3de4f055a869f708d4e55157ea359db1096c19eb6002cfea3db6"]
Oct 07 20:42:28 nuc electrs[9103]: [2021-10-07T18:42:28.225Z DEBUG bitcoincore_rpc::client] JSON-RPC request: getmempoolentry ["5d79d4c0f40410141eca2e7e63a5d504367d14d0ef324afd12bb70b5afa6370d"]
Oct 07 20:42:56 nuc systemd-journald[443]: Suppressed 17605 messages from electrs.service

Then a whole lot of that:

Oct 07 20:42:56 nuc electrs[9103]: [2021-10-07T18:42:56.139Z DEBUG bitcoincore_rpc::client] JSON-RPC failed parsing reply of getrawtransaction: JsonRpc(Transport(SocketError(Os { code: 99, kind: AddrNotAvailable, message: "Cannot assign requested address" })))
Oct 07 20:42:56 nuc electrs[9103]: [2021-10-07T18:42:56.140Z DEBUG bitcoincore_rpc::client] JSON-RPC request: getmempoolentry ["5802d02cfeac620ca58b14d44521707b9584a7d370fc1fe84e9769b7eeb6a59a"]
Oct 07 20:42:56 nuc electrs[9103]: [2021-10-07T18:42:56.143Z DEBUG bitcoincore_rpc::client] JSON-RPC failed parsing reply of getrawtransaction: JsonRpc(Transport(SocketError(Os { code: 99, kind: AddrNotAvailable, message: "Cannot assign requested address" })))
Oct 07 20:42:56 nuc electrs[9103]: [2021-10-07T18:42:56.143Z DEBUG bitcoincore_rpc::client] JSON-RPC request: getmempoolentry ["dbf2a8556d98fc60ba85e3a77d8fab541b45790d2490b2f1a4c253459f863cb3"]
Oct 07 20:42:56 nuc electrs[9103]: [2021-10-07T18:42:56.143Z DEBUG bitcoincore_rpc::client] JSON-RPC request: getmempoolentry ["513251e6c7f6d70119e78bb6412f43d924619e92085251f591f765737d3fca5f"]
Oct 07 20:42:56 nuc electrs[9103]: [2021-10-07T18:42:56.145Z DEBUG bitcoincore_rpc::client] JSON-RPC failed parsing reply of getrawtransaction: JsonRpc(Transport(SocketError(Os { code: 99, kind: AddrNotAvailable, message: "Cannot assign requested address" })))
Oct 07 20:42:56 nuc electrs[9103]: [2021-10-07T18:42:56.145Z DEBUG bitcoincore_rpc::client] JSON-RPC request: getmempoolentry ["7c654492a8339a777ef8cd7f494e9ad5176fc5d5bfa28810dd02dddbd821b929"]
Oct 07 20:42:56 nuc electrs[9103]: [2021-10-07T18:42:56.151Z DEBUG bitcoincore_rpc::client] JSON-RPC failed parsing reply of getmempoolentry: JsonRpc(Transport(SocketError(Os { code: 99, kind: AddrNotAvailable, message: "Cannot assign requested address" })))
Oct 07 20:42:56 nuc electrs[9103]: [2021-10-07T18:42:56.151Z DEBUG bitcoincore_rpc::client] JSON-RPC request: getrawtransaction ["3b560a34d49adad1d716ca4ff0b0c274988b001bdc572d817a2af1404d414d1e",false]
Oct 07 20:42:56 nuc electrs[9103]: [2021-10-07T18:42:56.155Z DEBUG bitcoincore_rpc::client] JSON-RPC failed parsing reply of getmempoolentry: JsonRpc(Transport(SocketError(Os { code: 99, kind: AddrNotAvailable, message: "Cannot assign requested address" })))
Oct 07 20:42:56 nuc electrs[9103]: [2021-10-07T18:42:56.155Z DEBUG bitcoincore_rpc::client] JSON-RPC request: getrawtransaction ["31b9ecc9b39ee62bccb24c2bc74b1d695582e4e2cb5c7b021ae83d16ec4ffc55",false]
Oct 07 20:42:56 nuc electrs[9103]: [2021-10-07T18:42:56.155Z DEBUG bitcoincore_rpc::client] JSON-RPC request: getrawtransaction ["1fbdca7fb477a99227504206d938a7e7645516febcaad896662b01dfafdaedf2",false]
Oct 07 20:42:56 nuc electrs[9103]: [2021-10-07T18:42:56.158Z DEBUG bitcoincore_rpc::client] JSON-RPC failed parsing reply of getmempoolentry: JsonRpc(Transport(SocketError(Os { code: 99, kind: AddrNotAvailable, message: "Cannot assign requested address" })))
Oct 07 20:42:56 nuc electrs[9103]: [2021-10-07T18:42:56.159Z DEBUG bitcoincore_rpc::client] JSON-RPC request: getrawtransaction ["826ce4f9c5e1d13e74ba89cdca2d6c47a6ffe4c8c319d9c4c11d87878683d7be",false]
Oct 07 20:42:56 nuc electrs[9103]: [2021-10-07T18:42:56.162Z DEBUG bitcoincore_rpc::client] JSON-RPC failed parsing reply of getrawtransaction: JsonRpc(Transport(SocketError(Os { code: 99, kind: AddrNotAvailable, message: "Cannot assign requested address" })))
Oct 07 20:42:56 nuc electrs[9103]: [2021-10-07T18:42:56.162Z DEBUG bitcoincore_rpc::client] JSON-RPC request: getmempoolentry ["3b560a34d49adad1d716ca4ff0b0c274988b001bdc572d817a2af1404d414d1e"]
Oct 07 20:42:56 nuc electrs[9103]: [2021-10-07T18:42:56.166Z DEBUG bitcoincore_rpc::client] JSON-RPC failed parsing reply of getrawtransaction: JsonRpc(Transport(SocketError(Os { code: 99, kind: AddrNotAvailable, message: "Cannot assign requested address" })))
Oct 07 20:42:56 nuc electrs[9103]: [2021-10-07T18:42:56.166Z DEBUG bitcoincore_rpc::client] JSON-RPC request: getmempoolentry ["1fbdca7fb477a99227504206d938a7e7645516febcaad896662b01dfafdaedf2"]
Oct 07 20:42:56 nuc electrs[9103]: [2021-10-07T18:42:56.166Z DEBUG bitcoincore_rpc::client] JSON-RPC request: getmempoolentry ["31b9ecc9b39ee62bccb24c2bc74b1d695582e4e2cb5c7b021ae83d16ec4ffc55"]

florianfink on Oct 7, 2021

Definitely no other instance of electrs running. I stopped the service, replaced the binary, restarted it. Then, the database migration took place successfully (size of ./db/bitcoin is around 30G, that should be ok?) Also, I get the same error after reboot. And it worked perfectly using the 0.8.6 binary - haven’t changed anything else.

florianfink on Oct 7, 2021