search

lightningnetwork / lnd

Lightning Network Daemon ⚡️
MIT License
7.69k stars 2.08k forks source link

[bug]: All channels inactive after restart: Unable to retrieve mempool txs #7778

Closed Asara closed 1 year ago

Asara commented 1 year ago

Background

After restarting my lnd node, it seems to be unable to pull data from bitcoind. I have tried with two different bitcoin nodes, both of which have been synced and are able to service other lnd nodes.

Your environment

lncli version 0.16.3-beta commit=v0.16.3-beta 6.3.0-1-armmp-lpae #1 SMP Debian 6.3.7-1 (2023-06-12) armv7l GNU/Linux

Steps to reproduce

Restart lnd

Expected behaviour

The server syncs chain state and then connects to channels

Actual behaviour

2023-06-19 23:59:05.154 [INF] LTND: Waiting for chain backend to finish sync, start_height=795134           
2023-06-19 23:59:56.718 [INF] LNWL: Started rescan from block 000000000000000000003c4f88f639857342b68d8aa10a4fa3ae81
0ed2fcb749 (height 795068) for 183 addresses                                                                        
2023-06-20 00:00:35.083 [ERR] LNWL: Unable to complete chain rescan: error reading json reply: unexpected EOF
2023-06-20 00:03:24.996 [WRN] LNWL: unable to fetch transaction c6caca7a713fd44a00186a294f9b654499b2324c1201163fe678
11a0f3956a25 for mempool: -5: No such mempool or blockchain transaction. Use gettransaction for wallet transactions.
....
more unable to fetch transactions (most of which have been RBF)
...
2023-06-20 01:01:42.979 [INF] LNWL: Started polling mempool to cache new transactions                       
2023-06-20 01:03:02.600 [ERR] LNWL: Unable to retrieve mempool txs: error reading json reply: unexpected EOF
2023-06-20 01:03:37.511 [ERR] LNWL: Unable to retrieve mempool txs: error reading json reply: unexpected EOF

With the unexpected EOF just happening forever.

I've had the lnd node running for about 24 hours since the restart and it is still just showing EOF approximately every minute or two.

GeorgeTsagk commented 1 year ago

Hey @Asara

Would you mind sharing your configured max mempool size?

Asara commented 1 year ago

I haven't set the mempool on bitcoind specifically, so the default of 300.

I can bump that up to see if it helps though.

yyforyongyu commented 1 year ago

Fixed by #7767

GeorgeTsagk commented 1 year ago

Won't close this yet, will wait for PR to be merged

saubyk commented 1 year ago

closing this issue as the pr is merged

Asara commented 1 year ago

Built 0.16.4-beta.rc1 off the tag and I am now getting the following error on startup:

2023-06-25 21:02:13.694 [ERR] LNWL: Unable to get raw mempool txs: error reading json reply: unexpected EOF
2023-06-25 21:02:13.699 [ERR] LTND: unable to create partial chain control: unable to connect to bitcoind: error reading json reply: unexpected EOF
2023-06-25 21:02:13.749 [ERR] LTND: Shutting down because error in main method: error creating wallet config: unable to create partial chain control: unable to connect to bitcoind: error reading json reply: unexpected EOF
2023-06-25 21:02:13.842 [INF] LTND: Shutdown complete

error creating wallet config: unable to create partial chain control: unable to connect to bitcoind: error reading json reply: unexpected EOF
yyforyongyu commented 1 year ago

which bitcoind version are you using @Asara ?

Asara commented 1 year ago

Bitcoin Core version v22.0.0 bitcoind/unstable,now 22.0-1 from the debian repos.

Asara commented 1 year ago

Same issue with the uploaded 0.16.4-beta.rc1 release binaries.

yyforyongyu commented 1 year ago

@Asara Could you restart your node with --debuglevel=trace and post all the logs here?

Asara commented 1 year ago 
:~$ lnd --wtclient.active --debuglevel=trace
2023-06-27 09:28:17.040 [INF] LTND: Version: 0.16.4-beta.rc1 commit=v0.16.4-beta.rc1, build=production, logging=default, debuglevel=trace
2023-06-27 09:28:17.042 [INF] LTND: Active chain: Bitcoin (network=mainnet)
2023-06-27 09:28:17.149 [DBG] VRPC: Versioner RPC server successfully registered with root gRPC server
2023-06-27 09:28:17.150 [DBG] RRPC: Router RPC server successfully register with root gRPC server
2023-06-27 09:28:17.151 [DBG] NTFR: ChainNotifier RPC server successfully register with root gRPC server
2023-06-27 09:28:17.153 [DBG] NTFR: ChainKit RPC server successfully register with root gRPC server
2023-06-27 09:28:17.154 [DBG] NRPC: Neutrino RPC server successfully register with root gRPC server
2023-06-27 09:28:17.156 [DBG] ARPC: Autopilot RPC server successfully register with root gRPC server
2023-06-27 09:28:17.158 [DBG] IRPC: Invoices RPC server successfully registered with root gRPC server
2023-06-27 09:28:17.159 [DBG] SGNR: Signer RPC server successfully register with root gRPC server
2023-06-27 09:28:17.161 [DBG] WLKT: WalletKit RPC server successfully registered with root gRPC server
2023-06-27 09:28:17.161 [DBG] PRPC: Peers RPC server successfully register with root gRPC server
2023-06-27 09:28:17.163 [INF] RPCS: RPC server listening on 127.0.0.1:10009
2023-06-27 09:28:17.168 [DBG] VRPC: Versioner REST server successfully registered with root REST server
2023-06-27 09:28:17.176 [DBG] RRPC: Router REST server successfully registered with root REST server
2023-06-27 09:28:17.178 [DBG] NTFR: ChainNotifier REST server successfully registered with root REST server
2023-06-27 09:28:17.198 [DBG] NTFR: ChainKit REST server successfully registered with root REST server
2023-06-27 09:28:17.203 [DBG] NRPC: Neutrino REST server successfully registered with root REST server
2023-06-27 09:28:17.207 [DBG] ARPC: Autopilot REST server successfully registered with root REST server
2023-06-27 09:28:17.211 [DBG] IRPC: Invoices REST server successfully registered with root REST server
2023-06-27 09:28:17.215 [DBG] SGNR: Signer REST server successfully registered with root REST server
2023-06-27 09:28:17.220 [DBG] WLKT: WalletKit REST server successfully registered with root REST server
2023-06-27 09:28:17.223 [DBG] PRPC: Peers REST server successfully registered with root REST server
2023-06-27 09:28:17.228 [INF] RPCS: gRPC proxy started at 127.0.0.1:8080
2023-06-27 09:28:17.232 [INF] LTND: Opening the main database, this might take a few minutes...
2023-06-27 09:28:17.235 [INF] LTND: Opening bbolt database, sync_freelist=false, auto_compact=false
2023-06-27 09:28:45.367 [INF] LTND: Creating local graph and channel state DB instances
2023-06-27 09:28:45.420 [DBG] CHDB: Populating in-memory channel graph, this might take a while...
2023-06-27 09:28:58.444 [DBG] CHDB: Finished populating in-memory channel graph (took 13.001937941s, num_node_features=14901, num_nodes=14489, num_channels=129290)
2023-06-27 09:28:58.445 [INF] CHDB: Checking for schema update: latest_version=29, db_version=29
2023-06-27 09:28:58.446 [INF] CHDB: Checking for optional update: prune_revocation_log=false, db_version=empty
2023-06-27 09:28:58.451 [INF] LTND: Database(s) now open (time_to_open=41.214135473s)!
2023-06-27 09:28:58.452 [INF] LTND: Attempting automatic wallet unlock with password provided in file
2023-06-27 09:29:11.123 [INF] LNWL: Opened wallet
2023-06-27 09:29:12.066 [INF] CHRE: Primary chain is set to: bitcoin
2023-06-27 09:29:12.158 [DBG] LNWL: Loading mempool spends...
2023-06-27 09:29:48.114 [ERR] LNWL: Unable to get raw mempool txs: error reading json reply: unexpected EOF
2023-06-27 09:29:48.117 [ERR] LTND: unable to create partial chain control: unable to connect to bitcoind: error reading json reply: unexpected EOF
2023-06-27 09:29:48.123 [ERR] LTND: Shutting down because error in main method: error creating wallet config: unable to create partial chain control: unable to connect to bitcoind: error reading json reply: unexpected EOF
2023-06-27 09:29:48.270 [INF] LTND: Shutdown complete

error creating wallet config: unable to create partial chain control: unable to connect to bitcoind: error reading json reply: unexpected EOF
yyforyongyu commented 1 year ago

If you run bitcoin-cli getmempoolinfo what's the result? Also what's your lnd conf?

Asara commented 1 year ago 
~$ bitcoin-cli -rpcconnect=192.168.0.12 getblockchaininfo
{
  "chain": "main",
  "blocks": 796160,
  "headers": 796160,
  "bestblockhash": "0000000000000000000020cee047789df420b25477264ddda7fe53363f337ca1",
  "difficulty": 52350439455487.47,
  "mediantime": 1687873981,
  "verificationprogress": 0.9999993352088989,
  "initialblockdownload": false,
  "chainwork": "00000000000000000000000000000000000000004d01217935c0c54bb7189f37",
  "size_on_disk": 557858450317,
  "pruned": false,
  "softforks": {
    "bip34": {
      "type": "buried",
      "active": true,
      "height": 227931
    },
    "bip66": {
      "type": "buried",
      "active": true,
      "height": 363725
    },
    "bip65": {
      "type": "buried",
      "active": true,
      "height": 388381
    },
    "csv": {
      "type": "buried",
      "active": true,
      "height": 419328
    },
    "segwit": {
      "type": "buried",
      "active": true,
      "height": 481824
    },
    "taproot": {
      "type": "bip9",
      "bip9": {
        "status": "active",
        "start_time": 1619222400,
        "timeout": 1628640000,
        "since": 709632,
        "min_activation_height": 709632
      },
      "height": 709632,
      "active": true
    }
  },
  "warnings": ""
}

and my lnd.conf

[Application Options]
datadir=~/.lnd/data
logdir=~/.lnd/logs
maxlogfiles=3
maxlogfilesize=10
tlscertpath=~/.lnd/tls.cert
tlskeypath=~/.lnd/tls.key
listen=localhost
rpclisten=localhost:10009
restlisten=localhost:8080
maxpendingchannels=10
nat=false
accept-keysend=true
[Bitcoin]
bitcoin.active=1
bitcoin.node=bitcoind
bitcoin.mainnet=true
bitcoin.defaultchanconfs=3
bitcoin.basefee=1000
bitcoin.feerate=10
bitcoin.timelockdelta=40

[Bitcoind]
bitcoind.rpchost=192.168.0.12:8332
bitcoind.rpcuser=bitcoin
bitcoind.zmqpubrawblock=tcp://192.168.0.12:28332
bitcoind.zmqpubrawtx=tcp://192.168.0.12:28333

[protocol]
protocol.wumbo-channels=true

[Tor]
tor.active=true
tor.v3=true
tor.streamisolation=true
Roasbeef commented 1 year ago

@Asara do you have debug logs for bitcoind available on start up?

Asara commented 1 year ago

Sorry, do you mean logs for bitcoind while bitcoind is starting up, or logs from bitcoind while lnd is starting up? Also if its for bitcoind, what debug flags would you like on it?

saubyk commented 1 year ago 

~$ bitcoin-cli -rpcconnect=192.168.0.12 getblockchaininfo
{

Hi @Asara can you please run getmempoolinfo instead as requested by @yyforyongyu, and post the result? Thanks

Asara commented 1 year ago

Woops. Sorry about that.

~$ bitcoin-cli -rpcconnect=192.168.0.12 getmempoolinfo
{
  "loaded": true,
  "size": 137739,
  "bytes": 48758997,
  "usage": 296628432,
  "total_fee": 4.63707778,
  "maxmempool": 300000000,
  "mempoolminfee": 0.00007852,
  "minrelaytxfee": 0.00001000,
  "unbroadcastcount": 0
}
Asara commented 1 year ago

Any other info I can get y'all for some assistance?

yyforyongyu commented 1 year ago

@Asara Maybe you could do the following to help with the debugging process,

  1. stop your lnd
  2. stop your bitcoind
  3. now start your bitcoind -debug=1
  4. and start your lnd --debuglevel=trace

Once you see the error which caused lnd to stop, you can stop bitcoind and share both the debug logs - debug.log for bitcoind and lnd.log for lnd here so we can further analyze what's wrong.

Asara commented 1 year ago

I think we can close this. Not sure what happened but setting debug logs started having the node sync properly. I disabled debug logging and it is still syncing... so maybe it was just a heisenbug.

Thanks for the help along the way friends!